diff --git a/src/usb_moded-dbus.c b/src/usb_moded-dbus.c index 8d5c5a3..d7911dd 100644 --- a/src/usb_moded-dbus.c +++ b/src/usb_moded-dbus.c @@ -54,7 +54,8 @@ extern gboolean rescue_mode; */ static void usb_moded_send_config_signal(const char *section, const char *key, const char *value) { - log_debug(USB_MODE_CONFIG_SIGNAL_NAME ": %s %s %s\n", section, key, value); + log_debug("broadcast signal %s(%s, %s, %s)\n", USB_MODE_CONFIG_SIGNAL_NAME, section, key, value); + if( !have_service_name ) { log_err("config notification without service: [%s] %s=%s", @@ -603,6 +604,8 @@ static int usb_moded_dbus_signal(const char *signal_type, const char *content) int result = 1; DBusMessage* msg = 0; + log_debug("broadcast signal %s(%s)\n", signal_type, content); + if( !have_service_name ) { log_err("sending signal without service: %s(%s)", diff --git a/src/usb_moded-log.c b/src/usb_moded-log.c index da2c5cd..06084ee 100644 --- a/src/usb_moded-log.c +++ b/src/usb_moded-log.c @@ -34,9 +34,10 @@ #include "usb_moded-log.h" -const char *log_name = ""; -int log_level = LOG_WARNING; -int log_type = LOG_TO_STDERR; +static const char *log_name = ""; +static int log_level = LOG_WARNING; +static int log_type = LOG_TO_STDERR; +static bool log_lineinfo = false; static char *strip(char *str) { @@ -71,10 +72,10 @@ static void log_gettime(struct timeval *tv) * @param fmt The message to be logged * @param va The stdarg variable list */ -void log_emit_va(int lev, const char *fmt, va_list va) +void log_emit_va(const char *file, const char *func, int line, int lev, const char *fmt, va_list va) { int saved = errno; - if( log_level >= lev ) + if( log_p(lev) ) { switch( log_type ) { @@ -85,7 +86,15 @@ void log_emit_va(int lev, const char *fmt, va_list va) case LOG_TO_STDERR: - fprintf(stderr, "%s: ", log_name); + if( log_get_lineinfo() ) { + /* Use gcc error like prefix for logging so + * that logs can be analyzed with jump to + * line parsing available in editors. */ + fprintf(stderr, "%s:%d: %s(): ", file, line, func); + } + else { + fprintf(stderr, "%s: ", log_get_name()); + } #if LOG_ENABLE_TIMESTAMPS { @@ -102,12 +111,12 @@ void log_emit_va(int lev, const char *fmt, va_list va) static const char *tag = "U:"; switch( lev ) { - case 2: tag = "C:"; break; - case 3: tag = "E:"; break; - case 4: tag = "W:"; break; - case 5: tag = "N:"; break; - case 6: tag = "I:"; break; - case 7: tag = "D:"; break; + case LOG_CRIT: tag = "C:"; break; + case LOG_ERR: tag = "E:"; break; + case LOG_WARNING: tag = "W:"; break; + case LOG_NOTICE: tag = "N:"; break; + case LOG_INFO: tag = "I:"; break; + case LOG_DEBUG: tag = "D:"; break; } fprintf(stderr, "%s ", tag); } @@ -129,18 +138,18 @@ void log_emit_va(int lev, const char *fmt, va_list va) errno = saved; } -void log_emit(int lev, const char *fmt, ...) +void log_emit_real(const char *file, const char *func, int line, int lev, const char *fmt, ...) { va_list va; va_start(va, fmt); - log_emit_va(lev, fmt, va); + log_emit_va(file, func, line, lev, fmt, va); va_end(va); } void log_debugf(const char *fmt, ...) { /* This goes always to stderr */ - if( log_type == LOG_TO_STDERR && log_level >= LOG_DEBUG ) + if( log_type == LOG_TO_STDERR && log_p(LOG_DEBUG) ) { va_list va; va_start(va, fmt); @@ -148,25 +157,90 @@ void log_debugf(const char *fmt, ...) va_end(va); } } -/** - * returns the currently set log level + +/** Get the currently set logging level * - * @return The current log level + * @return The current logging level */ -inline int log_get_level(void) +int log_get_level(void) { return log_level; } -/* Set the log level +/** Set the logging level * - * @param The wanted log level + * @param lev The wanted logging level */ -inline void log_set_level(int lev) +void log_set_level(int lev) { log_level = lev; } +/** Test if logging should be done at given level + * + * @param lev The logging level to query + * + * @return true if logging in the given level is allowed, false otherwise + */ +bool log_p(int lev) +{ + return lev <= log_level; +} + +/** Get the currently set logging type + * + * @return The current logging type + */ +int log_get_type(void) +{ + return log_type; +} + +/* Set the logging type + * + * @param type The wanted logging type + */ +void log_set_type(int type) +{ + log_type = type; +} + +/** Get the currently set logging name + * + * @return The current logging name + */ +const char *log_get_name(void) +{ + return log_name; +} + +/** Set the logging name + * + * @param name The wanted logging name + */ +void log_set_name(const char *name) +{ + log_name = name; +} + +/** Enable/disable the logging line info + * + * @param lineinfo true to enable line info, false to disable + */ +void log_set_lineinfo(bool lineinfo) +{ + log_lineinfo = lineinfo; +} + +/** Test if line info should be included in logging + * + * @return true when line info should be emitted, false otherwise + */ +bool log_get_lineinfo(void) +{ + return log_lineinfo; +} + /** Initialize logging */ void log_init(void) { diff --git a/src/usb_moded-log.h b/src/usb_moded-log.h index 73d0fb5..51f80fd 100644 --- a/src/usb_moded-log.h +++ b/src/usb_moded-log.h @@ -20,6 +20,7 @@ 02110-1301 USA */ +#include #include #include #include @@ -28,9 +29,6 @@ #include /* Logging functionality */ -extern const char *log_name; -extern int log_level; -extern int log_type; #define LOG_ENABLE_DEBUG 01 #define LOG_ENABLE_TIMESTAMPS 01 @@ -45,25 +43,38 @@ enum void log_set_level(int lev); int log_get_level(void); +int log_get_type(void); +void log_set_type(int type); +const char *log_get_name(void); +void log_set_name(const char *name); +void log_set_lineinfo(bool lineinfo); +bool log_get_lineinfo(void); void log_init(void); -void log_emit_va(int lev, const char *fmt, va_list va); -void log_emit(int lev, const char *fmt, ...) __attribute__((format(printf,2,3))); +void log_emit_va(const char *file, const char *func, int line, int lev, const char *fmt, va_list va); +void log_emit_real(const char *file, const char *func, int line, int lev, const char *fmt, ...) __attribute__((format(printf,5,6))); void log_debugf(const char *fmt, ...) __attribute__((format(printf,1,2))); +bool log_p(int lev); -#define log_crit(...) log_emit(2, __VA_ARGS__) -#define log_err(...) log_emit(3, __VA_ARGS__) -#define log_warning(...) log_emit(4, __VA_ARGS__) +#define log_emit(LEV, FMT, ARGS...) do {\ + if( log_p(LEV) ) {\ + log_emit_real(__FILE__,__FUNCTION__,__LINE__, LEV, FMT, ##ARGS);\ + }\ +} while(0) + +#define log_crit( FMT, ARGS...) log_emit(LOG_CRIT, FMT, ##ARGS) +#define log_err( FMT, ARGS...) log_emit(LOG_ERR, FMT, ##ARGS) +#define log_warning( FMT, ARGS...) log_emit(LOG_WARNING, FMT, ##ARGS) #if LOG_ENABLE_DEBUG -# define log_notice(...) log_emit(5, __VA_ARGS__) -# define log_info(...) log_emit(6, __VA_ARGS__) -# define log_debug(...) log_emit(7, __VA_ARGS__) +# define log_notice( FMT, ARGS...) log_emit(LOG_NOTICE, FMT, ##ARGS) +# define log_info( FMT, ARGS...) log_emit(LOG_INFO, FMT, ##ARGS) +# define log_debug( FMT, ARGS...) log_emit(LOG_DEBUG, FMT, ##ARGS) #else -# define log_notice(...) do{}while(0) -# define log_info(...) do{}while(0) -# define log_debug(...) do{}while(0) +# define log_notice( FMT, ARGS...) do{}while(0) +# define log_info( FMT, ARGS...) do{}while(0) +# define log_debug( FMT, ARGS...) do{}while(0) -# define log_debugf(...) do{}while(0) +# define log_debugf( FMT, ARGS...) do{}while(0) #endif diff --git a/src/usb_moded-modesetting.c b/src/usb_moded-modesetting.c index 520684b..ee53a63 100644 --- a/src/usb_moded-modesetting.c +++ b/src/usb_moded-modesetting.c @@ -30,6 +30,7 @@ #include #include #include +#include #include #include @@ -87,7 +88,7 @@ void usb_moded_mode_verify_values(void) * values used in configuration files vs what we get * back when reading from kernel interfaces. */ if( text && curr && !g_ascii_strcasecmp(text, curr) ) { - log_debug("unexpected change '%s' : '%s' -> '%s'", path, + log_debug("unexpected change '%s' : '%s' -> '%s' (case diff only)", path, text ?: "???", curr ?: "???"); } @@ -169,26 +170,35 @@ int write_to_file_real(const char *file, int line, const char *func, int fd = -1; size_t todo = 0; char *prev = 0; + bool clear = false; /* if either path or the text to be written are not there we return an error */ if(!text || !path) return err; - /* There are usb-moded configuration files and code that use - * "none" as a place-holder for no-function. Attempting to - * write that into sysfs leads to journal spamming due to - * EINVAL error return. Substituting "none" with an empty - * string avoids that. */ - if( !strcmp(path, "/sys/class/android_usb/android0/functions") && - !strcmp(text, "none") ) { - text = ""; + /* When attempting to clear ffs function list, writing an + * empty string is ignored and accomplishes nothing - while + * writing non-existing function clears the list but returns + * write error. + * + * Treat "none" (which is used as place-holder value in both + * configuration files and usb-moded sources) and "" similarly: + * - Write invalid function name to sysfs + * - Ignore resulting write error under default logging level + * - Assume reading from sysfs will result in empty string + */ + if( !strcmp(path, "/sys/class/android_usb/android0/functions") ) { + if( !strcmp(text, "") || !strcmp(text, "none") ) { + text = "none"; + clear = true; + } } /* If the file can be read, it also means we can later check that * the file retains the value we are about to write here. */ if( (prev = read_from_file(path, 0x1000)) ) - usb_moded_mode_track_value(path, text); + usb_moded_mode_track_value(path, clear ? "" : text); log_debug("%s:%d: %s(): WRITE '%s' : '%s' --> '%s'", file, line, func, @@ -208,7 +218,10 @@ int write_to_file_real(const char *file, int line, const char *func, ssize_t n = TEMP_FAILURE_RETRY(write(fd, text, todo)); if( n < 0 ) { - log_warning("write(%s): %m", path); + if( clear && errno == EINVAL ) + log_debug("write(%s): %m (expected failure)", path); + else + log_warning("write(%s): %m", path); goto cleanup; } todo -= n; diff --git a/src/usb_moded.c b/src/usb_moded.c index 9a1a31f..4ef4f63 100644 --- a/src/usb_moded.c +++ b/src/usb_moded.c @@ -70,10 +70,6 @@ static int usb_moded_exitcode = EXIT_FAILURE; static GMainLoop *usb_moded_mainloop = NULL; -extern const char *log_name; -extern int log_level; -extern int log_type; - gboolean rescue_mode = FALSE; gboolean diag_mode = FALSE; gboolean hw_fallback = FALSE; @@ -782,6 +778,7 @@ static void usage(void) " -f, --fallback \tassume always connected\n" " -s, --force-syslog \t\tlog to syslog\n" " -T, --force-stderr \t\tlog to stderr\n" + " -l, --log-line-info \t\tlog to stderr and show origin of logging\n" " -D, --debug \t\tturn on debug printing\n" " -d, --diag \t\tturn on diag mode\n" " -h, --help \t\tdisplay this help and exit\n" @@ -1198,6 +1195,7 @@ int main(int argc, char* argv[]) { "fallback", no_argument, 0, 'd' }, { "force-syslog", no_argument, 0, 's' }, { "force-stderr", no_argument, 0, 'T' }, + { "log-line-info", no_argument, 0, 'l' }, { "debug", no_argument, 0, 'D' }, { "diag", no_argument, 0, 'd' }, { "help", no_argument, 0, 'h' }, @@ -1209,14 +1207,14 @@ int main(int argc, char* argv[]) }; log_init(); - log_name = basename(*argv); + log_set_name(basename(*argv)); /* - - - - - - - - - - - - - - - - - - - * * OPTIONS * - - - - - - - - - - - - - - - - - - - */ /* Parse the command-line options */ - while ((opt = getopt_long(argc, argv, "aifsTDdhrnvm:", options, &opt_idx)) != -1) + while ((opt = getopt_long(argc, argv, "aifsTlDdhrnvm:", options, &opt_idx)) != -1) { switch (opt) { @@ -1230,17 +1228,22 @@ int main(int argc, char* argv[]) hw_fallback = TRUE; break; case 's': - log_type = LOG_TO_SYSLOG; + log_set_type(LOG_TO_SYSLOG); break; case 'T': - log_type = LOG_TO_STDERR; + log_set_type(LOG_TO_STDERR); break; case 'D': - log_level = LOG_DEBUG; + log_set_level(LOG_DEBUG); break; + case 'l': + log_set_type(LOG_TO_STDERR); + log_set_lineinfo(true); + break; + case 'd': diag_mode = TRUE; break; @@ -1279,7 +1282,7 @@ int main(int argc, char* argv[]) * - - - - - - - - - - - - - - - - - - - */ /* silence usb_moded_system() calls */ - if(log_type != LOG_TO_STDERR && log_level != LOG_DEBUG ) + if( log_get_type() != LOG_TO_STDERR && log_get_level() != LOG_DEBUG ) { freopen("/dev/null", "a", stdout); freopen("/dev/null", "a", stderr);