From 0a817747316c94ea5455ca6833ac4fefb2bd9890 Mon Sep 17 00:00:00 2001 From: Simo Piiroinen Date: Tue, 12 Feb 2019 09:50:01 +0200 Subject: [PATCH] [logging] Add enablers for exposing call stack When debugging complex issues it can be helpful know also which thread is emitting the diagnostic message and the code path that led to the situation. This is meant to be used as a development time debugging feature and thus requires enabling during build time - otherwise all related code is excluded from usb-moded binary. Signed-off-by: Simo Piiroinen --- src/usb_moded-android.c | 22 ++++++ src/usb_moded-appsync-dbus.c | 18 +++++ src/usb_moded-appsync.c | 30 ++++++++ src/usb_moded-common.c | 34 +++++++++ src/usb_moded-config.c | 88 +++++++++++++++++++++++ src/usb_moded-configfs.c | 62 ++++++++++++++++ src/usb_moded-control.c | 34 +++++++++ src/usb_moded-dbus.c | 38 ++++++++++ src/usb_moded-devicelock.c | 30 ++++++++ src/usb_moded-dsme.c | 62 ++++++++++++++++ src/usb_moded-dyn-config.c | 10 +++ src/usb_moded-log.c | 133 +++++++++++++++++++++++++++++++++-- src/usb_moded-log.h | 17 +++++ src/usb_moded-mac.c | 6 ++ src/usb_moded-modesetting.c | 36 ++++++++++ src/usb_moded-modules.c | 14 ++++ src/usb_moded-network.c | 44 ++++++++++++ src/usb_moded-sigpipe.c | 10 +++ src/usb_moded-ssu.c | 8 +++ src/usb_moded-systemd.c | 6 ++ src/usb_moded-trigger.c | 10 +++ src/usb_moded-udev.c | 28 ++++++++ src/usb_moded-worker.c | 66 +++++++++++++++++ src/usb_moded.c | 46 ++++++++++++ 24 files changed, 845 insertions(+), 7 deletions(-) diff --git a/src/usb_moded-android.c b/src/usb_moded-android.c index d903291..b726c10 100644 --- a/src/usb_moded-android.c +++ b/src/usb_moded-android.c @@ -63,6 +63,8 @@ static int android_probed = -1; static bool android_write_file(const char *path, const char *text) { + LOG_REGISTER_CONTEXT; + bool ack = false; if( !path || !text ) @@ -86,6 +88,8 @@ android_write_file(const char *path, const char *text) bool android_in_use(void) { + LOG_REGISTER_CONTEXT; + if( android_probed < 0 ) log_debug("android_in_use() called before android_probe()"); @@ -95,6 +99,8 @@ android_in_use(void) static bool android_probe(void) { + LOG_REGISTER_CONTEXT; + if( android_probed <= 0 ) { android_probed = access(ANDROID0_ENABLE, F_OK) == 0; log_warning("ANDROID0 %sdetected", android_probed ? "" : "not "); @@ -108,6 +114,8 @@ android_probe(void) gchar * android_get_serial(void) { + LOG_REGISTER_CONTEXT; + static const char path[] = "/proc/cmdline"; static const char find[] = "androidboot.serialno="; static const char pbrk[] = " \t\r\n,"; @@ -157,6 +165,8 @@ android_get_serial(void) bool android_init_values(void) { + LOG_REGISTER_CONTEXT; + gchar *text; if( !android_probe() ) @@ -217,6 +227,8 @@ android_init_values(void) bool android_set_enabled(bool enable) { + LOG_REGISTER_CONTEXT; + bool ack = false; if( android_in_use() ) { const char *val = enable ? "1" : "0"; @@ -233,6 +245,8 @@ android_set_enabled(bool enable) bool android_set_charging_mode(void) { + LOG_REGISTER_CONTEXT; + bool ack = false; if( !android_in_use() ) @@ -262,6 +276,8 @@ android_set_charging_mode(void) bool android_set_function(const char *function) { + LOG_REGISTER_CONTEXT; + bool ack = false; if( !function ) @@ -293,6 +309,8 @@ android_set_function(const char *function) bool android_set_productid(const char *id) { + LOG_REGISTER_CONTEXT; + bool ack = false; if( id && android_in_use() ) { @@ -316,6 +334,8 @@ android_set_productid(const char *id) bool android_set_vendorid(const char *id) { + LOG_REGISTER_CONTEXT; + bool ack = false; if( id && android_in_use() ) { char str[16]; @@ -338,6 +358,8 @@ android_set_vendorid(const char *id) bool android_set_attr(const char *function, const char *attr, const char *value) { + LOG_REGISTER_CONTEXT; + bool ack = false; if( function && attr && value && android_in_use() ) { diff --git a/src/usb_moded-appsync-dbus.c b/src/usb_moded-appsync-dbus.c index 042f4c5..9be0f6d 100644 --- a/src/usb_moded-appsync-dbus.c +++ b/src/usb_moded-appsync-dbus.c @@ -64,6 +64,8 @@ static gboolean dbus_connection_disc = FALSE; // got disconnected static void dbusappsync_release_name(void) { + LOG_REGISTER_CONTEXT; + /* Drop the service name - if we have it */ if( dbus_connection_ses && dbus_connection_name ) { @@ -96,6 +98,8 @@ static void dbusappsync_release_name(void) static gboolean dbusappsync_obtain_name(void) { + LOG_REGISTER_CONTEXT; + DBusError error = DBUS_ERROR_INIT; int ret; @@ -150,6 +154,8 @@ static gboolean dbusappsync_obtain_name(void) static DBusHandlerResult dbusappsync_msg_handler(DBusConnection *const connection, DBusMessage *const msg, gpointer const user_data) { + LOG_REGISTER_CONTEXT; + DBusHandlerResult status = DBUS_HANDLER_RESULT_NOT_YET_HANDLED; int type = dbus_message_get_type(msg); const char *interface = dbus_message_get_interface(msg); @@ -221,6 +227,8 @@ static DBusHandlerResult dbusappsync_msg_handler(DBusConnection *const connectio */ static DBusHandlerResult dbusappsync_handle_disconnect(DBusConnection *conn, DBusMessage *msg, void *user_data) { + LOG_REGISTER_CONTEXT; + if( dbus_message_is_signal(msg, DBUS_INTERFACE_LOCAL, "Disconnected") ) { log_warning("disconnected from session bus - expecting restart/stop soon\n"); @@ -235,6 +243,8 @@ static DBusHandlerResult dbusappsync_handle_disconnect(DBusConnection *conn, DBu */ static void dbusappsync_cleanup_connection(void) { + LOG_REGISTER_CONTEXT; + if( dbus_connection_ses != 0 ) { /* Remove message filters */ @@ -259,6 +269,8 @@ static void dbusappsync_cleanup_connection(void) */ gboolean dbusappsync_init_connection(void) { + LOG_REGISTER_CONTEXT; + gboolean result = FALSE; DBusError error = DBUS_ERROR_INIT; @@ -316,6 +328,8 @@ gboolean dbusappsync_init_connection(void) */ gboolean dbusappsync_init(void) { + LOG_REGISTER_CONTEXT; + gboolean status = FALSE; if( !dbusappsync_init_connection() ) @@ -336,6 +350,8 @@ gboolean dbusappsync_init(void) */ void dbusappsync_cleanup(void) { + LOG_REGISTER_CONTEXT; + dbusappsync_cleanup_connection(); // NOP } @@ -345,6 +361,8 @@ void dbusappsync_cleanup(void) */ int dbusappsync_launch_app(char *launch) { + LOG_REGISTER_CONTEXT; + int ret = -1; // assume failure if( dbus_connection_ses == 0 ) diff --git a/src/usb_moded-appsync.c b/src/usb_moded-appsync.c index 79d4bb8..8715614 100644 --- a/src/usb_moded-appsync.c +++ b/src/usb_moded-appsync.c @@ -82,6 +82,8 @@ static int appsync_no_dbus = 1; // always disabled static void appsync_free_elem(list_elem_t *elem) { + LOG_REGISTER_CONTEXT; + g_free(elem->name); g_free(elem->launch); g_free(elem->mode); @@ -90,12 +92,16 @@ static void appsync_free_elem(list_elem_t *elem) static void appsync_free_elem_cb(gpointer elem, gpointer user_data) { + LOG_REGISTER_CONTEXT; + (void)user_data; appsync_free_elem(elem); } void appsync_free_appsync_list(void) { + LOG_REGISTER_CONTEXT; + if( appsync_sync_list != 0 ) { /*g_list_free_full(appsync_sync_list, appsync_free_elem); */ @@ -108,11 +114,15 @@ void appsync_free_appsync_list(void) static gint appsync_list_sort_func(gconstpointer a, gconstpointer b) { + LOG_REGISTER_CONTEXT; + return strcasecmp( (char*)a, (char*)b ); } void appsync_read_list(int diag) { + LOG_REGISTER_CONTEXT; + GDir *confdir = 0; const gchar *dirname; @@ -160,6 +170,8 @@ void appsync_read_list(int diag) static list_elem_t *appsync_read_file(const gchar *filename, int diag) { + LOG_REGISTER_CONTEXT; + gchar *full_filename = NULL; GKeyFile *settingsfile = NULL; list_elem_t *list_item = NULL; @@ -215,6 +227,8 @@ static list_elem_t *appsync_read_file(const gchar *filename, int diag) /* @return 0 on succes, 1 if there is a failure */ int appsync_activate_sync(const char *mode) { + LOG_REGISTER_CONTEXT; + GList *iter; int count = 0; @@ -316,6 +330,8 @@ int appsync_activate_sync(const char *mode) int appsync_activate_sync_post(const char *mode) { + LOG_REGISTER_CONTEXT; + GList *iter; log_debug("activate post sync"); @@ -374,6 +390,8 @@ int appsync_activate_sync_post(const char *mode) int appsync_mark_active(const gchar *name, int post) { + LOG_REGISTER_CONTEXT; + int ret = -1; // assume name not found int missing = 0; @@ -417,6 +435,8 @@ int appsync_mark_active(const gchar *name, int post) #ifdef APP_SYNC_DBUS static gboolean appsync_enumerate_usb_cb(gpointer data) { + LOG_REGISTER_CONTEXT; + (void)data; appsync_enumerate_usb_id = 0; log_debug("handling enumeration timeout"); @@ -427,6 +447,8 @@ static gboolean appsync_enumerate_usb_cb(gpointer data) static void appsync_start_enumerate_usb_timer(void) { + LOG_REGISTER_CONTEXT; + log_debug("scheduling enumeration timeout"); if( appsync_enumerate_usb_id ) g_source_remove(appsync_enumerate_usb_id), appsync_enumerate_usb_id = 0; @@ -441,6 +463,8 @@ static void appsync_start_enumerate_usb_timer(void) static void appsync_cancel_enumerate_usb_timer(void) { + LOG_REGISTER_CONTEXT; + if( appsync_enumerate_usb_id ) { log_debug("canceling enumeration timeout"); @@ -450,6 +474,8 @@ static void appsync_cancel_enumerate_usb_timer(void) static void appsync_enumerate_usb(void) { + LOG_REGISTER_CONTEXT; + struct timeval tv; log_debug("Enumerating"); @@ -469,6 +495,8 @@ static void appsync_enumerate_usb(void) void appsync_stop_apps(int post) { + LOG_REGISTER_CONTEXT; + GList *iter = 0; for( iter = appsync_sync_list; iter; iter = g_list_next(iter) ) @@ -487,6 +515,8 @@ void appsync_stop_apps(int post) int appsync_stop(gboolean force) { + LOG_REGISTER_CONTEXT; + /* If force arg is used, stop all applications that * could have been started by usb-moded */ if(force) diff --git a/src/usb_moded-common.c b/src/usb_moded-common.c index 01b6799..414637c 100644 --- a/src/usb_moded-common.c +++ b/src/usb_moded-common.c @@ -68,6 +68,8 @@ gchar *common_get_mode_list (mode_list_type_t type); const char *cable_state_repr(cable_state_t state) { + LOG_REGISTER_CONTEXT; + static const char * const lut[CABLE_STATE_NUMOF] = { [CABLE_STATE_UNKNOWN] = "unknown", [CABLE_STATE_DISCONNECTED] = "disconnected", @@ -159,6 +161,8 @@ static const modemapping_t common_modemapping[] = const char * common_map_mode_to_hardware(const char *internal_mode) { + LOG_REGISTER_CONTEXT; + const char *hardware_mode = 0; for( size_t i = 0; common_modemapping[i].internal_mode; ++i ) { @@ -173,6 +177,8 @@ common_map_mode_to_hardware(const char *internal_mode) const char * common_map_mode_to_external(const char *internal_mode) { + LOG_REGISTER_CONTEXT; + const char *external_mode = 0; for( size_t i = 0; common_modemapping[i].internal_mode; ++i ) { @@ -192,6 +198,8 @@ common_map_mode_to_external(const char *internal_mode) */ void common_send_supported_modes_signal(void) { + LOG_REGISTER_CONTEXT; + gchar *mode_list = common_get_mode_list(SUPPORTED_MODES_LIST); umdbus_send_supported_modes_signal(mode_list); g_free(mode_list); @@ -201,6 +209,8 @@ void common_send_supported_modes_signal(void) */ void common_send_available_modes_signal(void) { + LOG_REGISTER_CONTEXT; + gchar *mode_list = common_get_mode_list(AVAILABLE_MODES_LIST); umdbus_send_available_modes_signal(mode_list); g_free(mode_list); @@ -210,6 +220,8 @@ void common_send_available_modes_signal(void) */ void common_send_hidden_modes_signal(void) { + LOG_REGISTER_CONTEXT; + gchar *mode_list = config_get_hidden_modes(); umdbus_send_hidden_modes_signal(mode_list); g_free(mode_list); @@ -219,6 +231,8 @@ void common_send_hidden_modes_signal(void) */ void common_send_whitelisted_modes_signal(void) { + LOG_REGISTER_CONTEXT; + gchar *mode_list = config_get_mode_whitelist(); umdbus_send_whitelisted_modes_signal(mode_list); g_free(mode_list); @@ -237,6 +251,8 @@ void common_send_whitelisted_modes_signal(void) */ static void common_write_to_sysfs_file(const char *path, const char *text) { + LOG_REGISTER_CONTEXT; + int fd = -1; if (!path || !text) @@ -276,6 +292,8 @@ static void common_write_to_sysfs_file(const char *path, const char *text) */ void common_acquire_wakelock(const char *wakelock_name) { + LOG_REGISTER_CONTEXT; + char buff[256]; snprintf(buff, sizeof buff, "%s %lld", wakelock_name, @@ -293,6 +311,8 @@ void common_acquire_wakelock(const char *wakelock_name) */ void common_release_wakelock(const char *wakelock_name) { + LOG_REGISTER_CONTEXT; + #if VERBOSE_WAKELOCKING log_debug("common_release_wakelock %s", wakelock_name); #endif @@ -310,6 +330,8 @@ int common_system_(const char *file, int line, const char *func, const char *command) { + LOG_REGISTER_CONTEXT; + log_debug("EXEC %s; from %s:%d: %s()", command, file, line, func); @@ -327,6 +349,8 @@ FILE * common_popen_(const char *file, int line, const char *func, const char *command, const char *type) { + LOG_REGISTER_CONTEXT; + log_debug("EXEC %s; from %s:%d: %s()", command, file, line, func); @@ -336,6 +360,8 @@ common_popen_(const char *file, int line, const char *func, waitres_t common_wait(unsigned tot_ms, bool (*ready_cb)(void *aptr), void *aptr) { + LOG_REGISTER_CONTEXT; + struct timespec ts; waitres_t res = WAIT_FAILED; @@ -384,6 +410,8 @@ common_wait(unsigned tot_ms, bool (*ready_cb)(void *aptr), void *aptr) bool common_msleep_(const char *file, int line, const char *func, unsigned msec) { + LOG_REGISTER_CONTEXT; + log_debug("SLEEP %u.%03u seconds; from %s:%d: %s()", msec / 1000u, msec % 1000u,file, line, func); return common_wait(msec, 0, 0) == WAIT_TIMEOUT; @@ -396,6 +424,8 @@ common_msleep_(const char *file, int line, const char *func, unsigned msec) /* check if a mode is in a list */ static bool common_mode_in_list(const char *mode, char * const *modes) { + LOG_REGISTER_CONTEXT; + int i; if (!modes) @@ -417,6 +447,8 @@ static bool common_mode_in_list(const char *mode, char * const *modes) */ int common_valid_mode(const char *mode) { + LOG_REGISTER_CONTEXT; + int valid = 1; /* MODE_ASK, MODE_CHARGER and MODE_CHARGING_FALLBACK are not modes that are settable seen their special 'internal' status * so we only check the modes that are announed outside. Only exception is the built in MODE_CHARGING */ @@ -455,6 +487,8 @@ int common_valid_mode(const char *mode) */ gchar *common_get_mode_list(mode_list_type_t type) { + LOG_REGISTER_CONTEXT; + GString *mode_list_str = g_string_new(NULL); gchar *hidden_modes_value = 0; diff --git a/src/usb_moded-config.c b/src/usb_moded-config.c index a3109d4..eceabef 100644 --- a/src/usb_moded-config.c +++ b/src/usb_moded-config.c @@ -109,6 +109,8 @@ int config_is_roaming_not_allowed (void); static int config_validate_ip(const char *ipadd) { + LOG_REGISTER_CONTEXT; + unsigned int b1, b2, b3, b4; unsigned char c; @@ -125,6 +127,8 @@ static int config_validate_ip(const char *ipadd) char *config_find_mounts(void) { + LOG_REGISTER_CONTEXT; + char *ret = NULL; @@ -139,52 +143,72 @@ char *config_find_mounts(void) int config_find_sync(void) { + LOG_REGISTER_CONTEXT; + return config_get_conf_int(FS_SYNC_ENTRY, FS_SYNC_KEY); } char * config_find_alt_mount(void) { + LOG_REGISTER_CONTEXT; + return config_get_conf_string(ALT_MOUNT_ENTRY, ALT_MOUNT_KEY); } char * config_find_udev_path(void) { + LOG_REGISTER_CONTEXT; + return config_get_conf_string(UDEV_PATH_ENTRY, UDEV_PATH_KEY); } char * config_find_udev_subsystem(void) { + LOG_REGISTER_CONTEXT; + return config_get_conf_string(UDEV_PATH_ENTRY, UDEV_SUBSYSTEM_KEY); } char * config_check_trigger(void) { + LOG_REGISTER_CONTEXT; + return config_get_conf_string(TRIGGER_ENTRY, TRIGGER_PATH_KEY); } char * config_get_trigger_subsystem(void) { + LOG_REGISTER_CONTEXT; + return config_get_conf_string(TRIGGER_ENTRY, TRIGGER_UDEV_SUBSYSTEM); } char * config_get_trigger_mode(void) { + LOG_REGISTER_CONTEXT; + return config_get_conf_string(TRIGGER_ENTRY, TRIGGER_MODE_KEY); } char * config_get_trigger_property(void) { + LOG_REGISTER_CONTEXT; + return config_get_conf_string(TRIGGER_ENTRY, TRIGGER_PROPERTY_KEY); } char * config_get_trigger_value(void) { + LOG_REGISTER_CONTEXT; + return config_get_conf_string(TRIGGER_ENTRY, TRIGGER_PROPERTY_VALUE_KEY); } static char * config_get_network_ip(void) { + LOG_REGISTER_CONTEXT; + char * ip = config_get_kcmdline_string(NETWORK_IP_KEY); if (ip != NULL) if(!config_validate_ip(ip)) @@ -195,11 +219,15 @@ static char * config_get_network_ip(void) static char * config_get_network_interface(void) { + LOG_REGISTER_CONTEXT; + return config_get_conf_string(NETWORK_ENTRY, NETWORK_INTERFACE_KEY); } static char * config_get_network_gateway(void) { + LOG_REGISTER_CONTEXT; + char * gw = config_get_kcmdline_string(NETWORK_GATEWAY_KEY); if (gw != NULL) return gw; @@ -209,6 +237,8 @@ static char * config_get_network_gateway(void) static char * config_get_network_netmask(void) { + LOG_REGISTER_CONTEXT; + char * netmask = config_get_kcmdline_string(NETWORK_NETMASK_KEY); if (netmask != NULL) return netmask; @@ -218,12 +248,16 @@ static char * config_get_network_netmask(void) static char * config_get_network_nat_interface(void) { + LOG_REGISTER_CONTEXT; + return config_get_conf_string(NETWORK_ENTRY, NETWORK_NAT_INTERFACE_KEY); } /* create basic conffile with sensible defaults */ static void config_create_conf_file(void) { + LOG_REGISTER_CONTEXT; + GKeyFile *settingsfile; gchar *keyfile; int dir = 1; @@ -254,6 +288,8 @@ static void config_create_conf_file(void) static int config_get_conf_int(const gchar *entry, const gchar *key) { + LOG_REGISTER_CONTEXT; + GKeyFile *settingsfile; gboolean test = FALSE; gchar **keys, **origkeys; @@ -287,6 +323,8 @@ static int config_get_conf_int(const gchar *entry, const gchar *key) static char * config_get_conf_string(const gchar *entry, const gchar *key) { + LOG_REGISTER_CONTEXT; + GKeyFile *settingsfile; gboolean test = FALSE; gchar **keys, **origkeys, *tmp_char = NULL; @@ -324,6 +362,8 @@ static char * config_get_conf_string(const gchar *entry, const gchar *key) static char * config_get_kcmdline_string(const char *entry) { + LOG_REGISTER_CONTEXT; + int fd; char cmdLine[1024]; char *ret = NULL; @@ -400,6 +440,8 @@ static char * config_get_kcmdline_string(const char *entry) char * config_get_mode_setting(void) { + LOG_REGISTER_CONTEXT; + char *mode = 0; /* Kernel command line can be used to override settings */ @@ -425,6 +467,8 @@ char * config_get_mode_setting(void) */ int config_value_changed(GKeyFile *settingsfile, const char *entry, const char *key, const char *new_value) { + LOG_REGISTER_CONTEXT; + char *old_value = g_key_file_get_string(settingsfile, entry, key, NULL); int changed = (g_strcmp0(old_value, new_value) != 0); g_free(old_value); @@ -433,6 +477,8 @@ int config_value_changed(GKeyFile *settingsfile, const char *entry, const char * set_config_result_t config_set_config_setting(const char *entry, const char *key, const char *value) { + LOG_REGISTER_CONTEXT; + GKeyFile *settingsfile; gboolean test = FALSE; set_config_result_t ret = SET_CONFIG_ERROR; @@ -469,6 +515,8 @@ set_config_result_t config_set_config_setting(const char *entry, const char *key set_config_result_t config_set_mode_setting(const char *mode) { + LOG_REGISTER_CONTEXT; + if (strcmp(mode, MODE_ASK) && common_valid_mode(mode)) return SET_CONFIG_ERROR; return config_set_config_setting(MODE_SETTING_ENTRY, MODE_SETTING_KEY, mode); @@ -478,6 +526,8 @@ set_config_result_t config_set_mode_setting(const char *mode) * new string of hidden modes when adding one, otherwise it will remove one */ static char * config_make_modes_string(const char *key, const char *mode_name, int include) { + LOG_REGISTER_CONTEXT; + char *modes_new = 0; char *modes_old = 0; gchar **modes_arr = 0; @@ -537,6 +587,8 @@ static char * config_make_modes_string(const char *key, const char *mode_name, i set_config_result_t config_set_hide_mode_setting(const char *mode) { + LOG_REGISTER_CONTEXT; + set_config_result_t ret = SET_CONFIG_UNCHANGED; char *hidden_modes = config_make_modes_string(MODE_HIDE_KEY, mode, 1); @@ -558,6 +610,8 @@ set_config_result_t config_set_hide_mode_setting(const char *mode) set_config_result_t config_set_unhide_mode_setting(const char *mode) { + LOG_REGISTER_CONTEXT; + set_config_result_t ret = SET_CONFIG_UNCHANGED; char *hidden_modes = config_make_modes_string(MODE_HIDE_KEY, mode, 0); @@ -579,6 +633,8 @@ set_config_result_t config_set_unhide_mode_setting(const char *mode) set_config_result_t config_set_mode_whitelist(const char *whitelist) { + LOG_REGISTER_CONTEXT; + set_config_result_t ret = config_set_config_setting(MODE_SETTING_ENTRY, MODE_WHITELIST_KEY, whitelist); if(ret == SET_CONFIG_UPDATED) { @@ -609,6 +665,8 @@ set_config_result_t config_set_mode_whitelist(const char *whitelist) set_config_result_t config_set_mode_in_whitelist(const char *mode, int allowed) { + LOG_REGISTER_CONTEXT; + set_config_result_t ret = SET_CONFIG_UNCHANGED; char *whitelist = config_make_modes_string(MODE_WHITELIST_KEY, mode, allowed); @@ -628,6 +686,8 @@ set_config_result_t config_set_mode_in_whitelist(const char *mode, int allowed) */ set_config_result_t config_set_network_setting(const char *config, const char *setting) { + LOG_REGISTER_CONTEXT; + GKeyFile *settingsfile; gboolean test = FALSE; gchar *keyfile; @@ -676,6 +736,8 @@ set_config_result_t config_set_network_setting(const char *config, const char *s char * config_get_network_setting(const char *config) { + LOG_REGISTER_CONTEXT; + char * ret = 0; mode_list_elem_t *data; @@ -737,6 +799,8 @@ char * config_get_network_setting(const char *config) static void config_merge_key(GKeyFile *dest, GKeyFile *srce, const char *grp, const char *key) { + LOG_REGISTER_CONTEXT; + gchar *val = g_key_file_get_value(srce, grp, key, 0); if( val ) { log_debug("[%s] %s = %s", grp, key, val); @@ -755,6 +819,8 @@ static void config_merge_key(GKeyFile *dest, GKeyFile *srce, static void config_merge_group(GKeyFile *dest, GKeyFile *srce, const char *grp) { + LOG_REGISTER_CONTEXT; + gchar **key = g_key_file_get_keys(srce, grp, 0, 0); if( key ) { for( size_t i = 0; key[i]; ++i ) @@ -771,6 +837,8 @@ static void config_merge_group(GKeyFile *dest, GKeyFile *srce, */ static void config_merge_file(GKeyFile *dest, GKeyFile *srce) { + LOG_REGISTER_CONTEXT; + gchar **grp = g_key_file_get_groups(srce, 0); if( grp ) { @@ -790,6 +858,8 @@ static void config_merge_file(GKeyFile *dest, GKeyFile *srce) */ static int config_glob_error_cb(const char *path, int err) { + LOG_REGISTER_CONTEXT; + log_debug("%s: glob: %s", path, g_strerror(err)); return 0; } @@ -801,6 +871,8 @@ static int config_glob_error_cb(const char *path, int err) */ static GKeyFile *config_read_ini_files(void) { + LOG_REGISTER_CONTEXT; + static const char pattern[] = CONFIG_FILE_DIR"/*.ini"; GKeyFile *ini = g_key_file_new(); @@ -842,6 +914,8 @@ static GKeyFile *config_read_ini_files(void) */ int config_merge_conf_file(void) { + LOG_REGISTER_CONTEXT; + GString *keyfile_string = NULL; GKeyFile *settingsfile,*tempfile; int ret = 0; @@ -881,6 +955,8 @@ int config_merge_conf_file(void) char * config_get_android_manufacturer(void) { + LOG_REGISTER_CONTEXT; + #ifdef USE_MER_SSU /* If SSU can provide manufacturer name, use it. Otherwise fall * back to using the name specified in configuration files. */ @@ -896,11 +972,15 @@ char * config_get_android_manufacturer(void) char * config_get_android_vendor_id(void) { + LOG_REGISTER_CONTEXT; + return config_get_conf_string(ANDROID_ENTRY, ANDROID_VENDOR_ID_KEY); } char * config_get_android_product(void) { + LOG_REGISTER_CONTEXT; + #ifdef USE_MER_SSU /* If SSU can provide device model name, use it. Otherwise fall * back to using the name specified in configuration files. */ @@ -916,19 +996,27 @@ char * config_get_android_product(void) char * config_get_android_product_id(void) { + LOG_REGISTER_CONTEXT; + return config_get_conf_string(ANDROID_ENTRY, ANDROID_PRODUCT_ID_KEY); } char * config_get_hidden_modes(void) { + LOG_REGISTER_CONTEXT; + return config_get_conf_string(MODE_SETTING_ENTRY, MODE_HIDE_KEY); } char * config_get_mode_whitelist(void) { + LOG_REGISTER_CONTEXT; + return config_get_conf_string(MODE_SETTING_ENTRY, MODE_WHITELIST_KEY); } int config_is_roaming_not_allowed(void) { + LOG_REGISTER_CONTEXT; + return config_get_conf_int(NETWORK_ENTRY, NO_ROAMING_KEY); } diff --git a/src/usb_moded-configfs.c b/src/usb_moded-configfs.c index 5c458a8..d852283 100644 --- a/src/usb_moded-configfs.c +++ b/src/usb_moded-configfs.c @@ -112,6 +112,8 @@ static int configfs_probed = -1; static int configfs_file_type(const char *path) { + LOG_REGISTER_CONTEXT; + int type = -1; if( !path ) @@ -130,6 +132,8 @@ static int configfs_file_type(const char *path) static const char * configfs_function_path(char *buff, size_t size, const char *func, ...) { + LOG_REGISTER_CONTEXT; + char *pos = buff; char *end = buff + size; @@ -150,12 +154,16 @@ configfs_function_path(char *buff, size_t size, const char *func, ...) static const char * configfs_unit_path(char *buff, size_t size, const char *func, const char *unit) { + LOG_REGISTER_CONTEXT; + return configfs_function_path(buff, size, func, unit, NULL); } static const char * configfs_config_path(char *buff, size_t size, const char *func) { + LOG_REGISTER_CONTEXT; + snprintf(buff, size, "%s/%s", CONFIGFS_CONFIG, func); return buff; } @@ -163,6 +171,8 @@ configfs_config_path(char *buff, size_t size, const char *func) static bool configfs_mkdir(const char *path) { + LOG_REGISTER_CONTEXT; + bool ack = false; if( mkdir(path, 0775) == -1 && errno != EEXIST ) { @@ -184,6 +194,8 @@ configfs_mkdir(const char *path) static bool configfs_rmdir(const char *path) { + LOG_REGISTER_CONTEXT; + bool ack = false; if( rmdir(path) == -1 && errno != ENOENT ) { @@ -200,6 +212,8 @@ configfs_rmdir(const char *path) static const char * configfs_register_function(const char *function) { + LOG_REGISTER_CONTEXT; + const char *res = 0; static char fpath[256]; @@ -220,6 +234,8 @@ configfs_register_function(const char *function) static bool configfs_unregister_function(const char *function) { + LOG_REGISTER_CONTEXT; + bool ack = false; char fpath[256]; @@ -239,6 +255,8 @@ configfs_unregister_function(const char *function) static const char * configfs_add_unit(const char *function, const char *unit) { + LOG_REGISTER_CONTEXT; + const char *res = 0; static char upath[256]; @@ -258,6 +276,8 @@ configfs_add_unit(const char *function, const char *unit) static bool configfs_remove_unit(const char *function, const char *unit) { + LOG_REGISTER_CONTEXT; + bool ack = false; static char upath[256]; @@ -277,6 +297,8 @@ configfs_remove_unit(const char *function, const char *unit) static bool configfs_enable_function(const char *function) { + LOG_REGISTER_CONTEXT; + bool ack = false; const char *fpath = configfs_register_function(function); @@ -316,6 +338,8 @@ configfs_enable_function(const char *function) static bool configfs_disable_function(const char *function) { + LOG_REGISTER_CONTEXT; + bool ack = false; char cpath[256]; @@ -341,6 +365,8 @@ configfs_disable_function(const char *function) static bool configfs_disable_all_functions(void) { + LOG_REGISTER_CONTEXT; + bool ack = false; DIR *dir = 0; @@ -372,6 +398,8 @@ configfs_disable_all_functions(void) static char *configfs_strip(char *str) { + LOG_REGISTER_CONTEXT; + unsigned char *src = (unsigned char *)str; unsigned char *dst = (unsigned char *)str; @@ -391,6 +419,8 @@ static char *configfs_strip(char *str) bool configfs_in_use(void) { + LOG_REGISTER_CONTEXT; + if( configfs_probed < 0 ) log_debug("configfs_in_use() called before configfs_probe()"); return configfs_probed > 0; @@ -399,6 +429,8 @@ configfs_in_use(void) static bool configfs_probe(void) { + LOG_REGISTER_CONTEXT; + if( configfs_probed <= 0 ) { configfs_probed = access(CONFIGFS_GADGET, F_OK) == 0; log_warning("CONFIGFS %sdetected", configfs_probed ? "" : "not "); @@ -409,6 +441,8 @@ configfs_probe(void) static const char * configfs_udc_enable_value(void) { + LOG_REGISTER_CONTEXT; + static bool probed = false; static char *value = 0; @@ -437,6 +471,8 @@ configfs_udc_enable_value(void) static bool configfs_write_file(const char *path, const char *text) { + LOG_REGISTER_CONTEXT; + bool ack = false; int fd = -1; @@ -477,6 +513,8 @@ configfs_write_file(const char *path, const char *text) static bool configfs_read_file(const char *path, char *buff, size_t size) { + LOG_REGISTER_CONTEXT; + bool ack = false; int fd = -1; @@ -515,6 +553,8 @@ configfs_read_file(const char *path, char *buff, size_t size) static bool configfs_read_udc(char *buff, size_t size) { + LOG_REGISTER_CONTEXT; + return configfs_read_file(CONFIGFS_UDC, buff, size); } #endif @@ -522,6 +562,8 @@ configfs_read_udc(char *buff, size_t size) static bool configfs_write_udc(const char *text) { + LOG_REGISTER_CONTEXT; + bool ack = false; char prev[64]; @@ -544,6 +586,8 @@ configfs_write_udc(const char *text) bool configfs_set_udc(bool enable) { + LOG_REGISTER_CONTEXT; + log_debug("UDC - %s", enable ? "ENABLE" : "DISABLE"); const char *value = ""; @@ -559,6 +603,8 @@ configfs_set_udc(bool enable) bool configfs_init_values(void) { + LOG_REGISTER_CONTEXT; + if( !configfs_probe() ) goto EXIT; @@ -622,6 +668,8 @@ configfs_init_values(void) bool configfs_set_charging_mode(void) { + LOG_REGISTER_CONTEXT; + bool ack = false; if( !configfs_set_function("mass_storage") ) @@ -647,6 +695,8 @@ configfs_set_charging_mode(void) bool configfs_set_productid(const char *id) { + LOG_REGISTER_CONTEXT; + bool ack = false; if( id && configfs_in_use() ) { @@ -673,6 +723,8 @@ configfs_set_productid(const char *id) bool configfs_set_vendorid(const char *id) { + LOG_REGISTER_CONTEXT; + bool ack = false; if( id && configfs_in_use() ) { @@ -699,6 +751,8 @@ configfs_set_vendorid(const char *id) static const char * configfs_map_function(const char *func) { + LOG_REGISTER_CONTEXT; + if( func == 0 ) ; else if( !strcmp(func, "mass_storage") ) @@ -721,6 +775,8 @@ configfs_map_function(const char *func) bool configfs_set_function(const char *func) { + LOG_REGISTER_CONTEXT; + bool ack = false; if( !configfs_in_use() ) @@ -753,6 +809,8 @@ configfs_set_function(const char *func) bool configfs_add_mass_storage_lun(int lun) { + LOG_REGISTER_CONTEXT; + bool ack = false; if( !configfs_in_use() ) @@ -769,6 +827,8 @@ configfs_add_mass_storage_lun(int lun) bool configfs_remove_mass_storage_lun(int lun) { + LOG_REGISTER_CONTEXT; + bool ack = false; if( !configfs_in_use() ) @@ -785,6 +845,8 @@ configfs_remove_mass_storage_lun(int lun) bool configfs_set_mass_storage_attr(int lun, const char *attr, const char *value) { + LOG_REGISTER_CONTEXT; + bool ack = false; if( !configfs_in_use() ) diff --git a/src/usb_moded-control.c b/src/usb_moded-control.c index 514870d..4dab271 100644 --- a/src/usb_moded-control.c +++ b/src/usb_moded-control.c @@ -99,6 +99,8 @@ static cable_state_t control_cable_state = CABLE_STATE_UNKNOWN; void control_rethink_usb_charging_fallback(void) { + LOG_REGISTER_CONTEXT; + /* Cable must be connected to a pc */ if( control_get_cable_state() != CABLE_STATE_PC_CONNECTED ) goto EXIT; @@ -125,11 +127,15 @@ control_rethink_usb_charging_fallback(void) const char *control_get_external_mode(void) { + LOG_REGISTER_CONTEXT; + return control_external_mode ?: MODE_UNDEFINED; } static void control_set_external_mode(const char *mode) { + LOG_REGISTER_CONTEXT; + gchar *previous = control_external_mode; if( !g_strcmp0(previous, mode) ) goto EXIT; @@ -167,12 +173,16 @@ static void control_set_external_mode(const char *mode) void control_clear_external_mode(void) { + LOG_REGISTER_CONTEXT; + g_free(control_external_mode), control_external_mode = 0; } static void control_update_external_mode(void) { + LOG_REGISTER_CONTEXT; + const char *internal_mode = control_get_usb_mode(); const char *external_mode = common_map_mode_to_external(internal_mode); @@ -181,11 +191,15 @@ static void control_update_external_mode(void) const char *control_get_target_mode(void) { + LOG_REGISTER_CONTEXT; + return control_target_mode ?: MODE_UNDEFINED; } static void control_set_target_mode(const char *mode) { + LOG_REGISTER_CONTEXT; + gchar *previous = control_target_mode; if( !g_strcmp0(previous, mode) ) goto EXIT; @@ -204,6 +218,8 @@ static void control_set_target_mode(const char *mode) void control_clear_target_mode(void) { + LOG_REGISTER_CONTEXT; + g_free(control_target_mode), control_target_mode = 0; } @@ -215,11 +231,15 @@ void control_clear_target_mode(void) */ const char * control_get_usb_mode(void) { + LOG_REGISTER_CONTEXT; + return control_internal_mode; } void control_clear_internal_mode(void) { + LOG_REGISTER_CONTEXT; + g_free(control_internal_mode), control_internal_mode = 0; } @@ -230,6 +250,8 @@ void control_clear_internal_mode(void) */ void control_set_usb_mode(const char *mode) { + LOG_REGISTER_CONTEXT; + gchar *previous = control_internal_mode; if( !g_strcmp0(previous, mode) ) goto EXIT; @@ -259,6 +281,8 @@ void control_set_usb_mode(const char *mode) */ void control_mode_switched(const char *mode) { + LOG_REGISTER_CONTEXT; + /* Update state data - without retriggering the worker thread */ if( g_strcmp0(control_internal_mode, mode) ) { @@ -281,6 +305,8 @@ void control_mode_switched(const char *mode) */ void control_select_usb_mode(void) { + LOG_REGISTER_CONTEXT; + char *mode_to_set = 0; if( usbmoded_get_rescue_mode() ) { @@ -337,6 +363,8 @@ void control_select_usb_mode(void) */ void control_set_cable_state(cable_state_t cable_state) { + LOG_REGISTER_CONTEXT; + cable_state_t prev = control_cable_state; control_cable_state = cable_state; @@ -370,11 +398,15 @@ void control_set_cable_state(cable_state_t cable_state) */ cable_state_t control_get_cable_state(void) { + LOG_REGISTER_CONTEXT; + return control_cable_state; } void control_clear_cable_state(void) { + LOG_REGISTER_CONTEXT; + control_cable_state = CABLE_STATE_UNKNOWN; } @@ -384,6 +416,8 @@ void control_clear_cable_state(void) */ bool control_get_connection_state(void) { + LOG_REGISTER_CONTEXT; + bool connected = false; switch( control_get_cable_state() ) { case CABLE_STATE_CHARGER_CONNECTED: diff --git a/src/usb_moded-dbus.c b/src/usb_moded-dbus.c index b7db115..63856e8 100644 --- a/src/usb_moded-dbus.c +++ b/src/usb_moded-dbus.c @@ -219,6 +219,8 @@ static const char umdbus_introspect_usbmoded[] = */ static void umdbus_send_config_signal(const char *section, const char *key, const char *value) { + LOG_REGISTER_CONTEXT; + DBusMessage* msg = 0; if( !section || !key || !value ) { @@ -258,6 +260,8 @@ static void umdbus_send_config_signal(const char *section, const char *key, cons static DBusHandlerResult umdbus_msg_handler(DBusConnection *const connection, DBusMessage *const msg, gpointer const user_data) { + LOG_REGISTER_CONTEXT; + DBusHandlerResult status = DBUS_HANDLER_RESULT_NOT_YET_HANDLED; DBusMessage *reply = 0; const char *interface = dbus_message_get_interface(msg); @@ -657,6 +661,8 @@ static DBusHandlerResult umdbus_msg_handler(DBusConnection *const connection, DB DBusConnection *umdbus_get_connection(void) { + LOG_REGISTER_CONTEXT; + DBusConnection *connection = 0; if( umdbus_connection ) connection = dbus_connection_ref(umdbus_connection); @@ -672,6 +678,8 @@ DBusConnection *umdbus_get_connection(void) */ gboolean umdbus_init_connection(void) { + LOG_REGISTER_CONTEXT; + gboolean status = FALSE; DBusError error = DBUS_ERROR_INIT; @@ -710,6 +718,8 @@ gboolean umdbus_init_connection(void) */ gboolean umdbus_init_service(void) { + LOG_REGISTER_CONTEXT; + gboolean status = FALSE; DBusError error = DBUS_ERROR_INIT; int ret; @@ -741,6 +751,8 @@ gboolean umdbus_init_service(void) */ static void umdbus_cleanup_service(void) { + LOG_REGISTER_CONTEXT; + if( !umdbus_service_name_acquired ) goto EXIT; @@ -763,6 +775,8 @@ static void umdbus_cleanup_service(void) */ void umdbus_cleanup(void) { + LOG_REGISTER_CONTEXT; + /* clean up system bus connection */ if (umdbus_connection != NULL) { @@ -784,6 +798,8 @@ void umdbus_cleanup(void) */ static int umdbus_send_signal_ex(const char *signal_type, const char *content) { + LOG_REGISTER_CONTEXT; + int result = 1; DBusMessage* msg = 0; @@ -845,6 +861,8 @@ static int umdbus_send_signal_ex(const char *signal_type, const char *content) */ static void umdbus_send_legacy_signal(const char *state_ind) { + LOG_REGISTER_CONTEXT; + umdbus_send_signal_ex(USB_MODE_SIGNAL_NAME, state_ind); } @@ -854,6 +872,8 @@ static void umdbus_send_legacy_signal(const char *state_ind) */ void umdbus_send_current_state_signal(const char *state_ind) { + LOG_REGISTER_CONTEXT; + umdbus_send_signal_ex(USB_MODE_CURRENT_STATE_SIGNAL_NAME, state_ind); umdbus_send_legacy_signal(state_ind); @@ -865,6 +885,8 @@ void umdbus_send_current_state_signal(const char *state_ind) */ void umdbus_send_target_state_signal(const char *state_ind) { + LOG_REGISTER_CONTEXT; + umdbus_send_signal_ex(USB_MODE_TARGET_STATE_SIGNAL_NAME, state_ind); } @@ -875,6 +897,8 @@ void umdbus_send_target_state_signal(const char *state_ind) */ void umdbus_send_event_signal(const char *state_ind) { + LOG_REGISTER_CONTEXT; + umdbus_send_signal_ex(USB_MODE_EVENT_SIGNAL_NAME, state_ind); umdbus_send_legacy_signal(state_ind); @@ -889,6 +913,8 @@ void umdbus_send_event_signal(const char *state_ind) */ int umdbus_send_error_signal(const char *error) { + LOG_REGISTER_CONTEXT; + return umdbus_send_signal_ex(USB_MODE_ERROR_SIGNAL_NAME, error); } @@ -901,6 +927,8 @@ int umdbus_send_error_signal(const char *error) */ int umdbus_send_supported_modes_signal(const char *supported_modes) { + LOG_REGISTER_CONTEXT; + return umdbus_send_signal_ex(USB_MODE_SUPPORTED_MODES_SIGNAL_NAME, supported_modes); } @@ -913,6 +941,8 @@ int umdbus_send_supported_modes_signal(const char *supported_modes) */ int umdbus_send_available_modes_signal(const char *available_modes) { + LOG_REGISTER_CONTEXT; + return umdbus_send_signal_ex(USB_MODE_AVAILABLE_MODES_SIGNAL_NAME, available_modes); } @@ -925,6 +955,8 @@ int umdbus_send_available_modes_signal(const char *available_modes) */ int umdbus_send_hidden_modes_signal(const char *hidden_modes) { + LOG_REGISTER_CONTEXT; + return umdbus_send_signal_ex(USB_MODE_HIDDEN_MODES_SIGNAL_NAME, hidden_modes); } @@ -936,6 +968,8 @@ int umdbus_send_hidden_modes_signal(const char *hidden_modes) */ int umdbus_send_whitelisted_modes_signal(const char *whitelist) { + LOG_REGISTER_CONTEXT; + return umdbus_send_signal_ex(USB_MODE_WHITELISTED_MODES_SIGNAL_NAME, whitelist); } @@ -946,6 +980,8 @@ int umdbus_send_whitelisted_modes_signal(const char *whitelist) */ static void umdbus_get_name_owner_cb(DBusPendingCall *pc, void *aptr) { + LOG_REGISTER_CONTEXT; + usb_moded_get_name_owner_fn cb = aptr; DBusMessage *rsp = 0; @@ -995,6 +1031,8 @@ gboolean umdbus_get_name_owner_async(const char *name, usb_moded_get_name_owner_fn cb, DBusPendingCall **ppc) { + LOG_REGISTER_CONTEXT; + gboolean ack = FALSE; DBusMessage *req = 0; DBusPendingCall *pc = 0; diff --git a/src/usb_moded-devicelock.c b/src/usb_moded-devicelock.c index bd2efa5..a86ad97 100644 --- a/src/usb_moded-devicelock.c +++ b/src/usb_moded-devicelock.c @@ -101,6 +101,8 @@ static gboolean devicelock_is_available = FALSE; static const char * devicelock_state_repr(devicelock_state_t state) { + LOG_REGISTER_CONTEXT; + const char *repr = "DEVICELOCK_"; switch( state ) @@ -125,6 +127,8 @@ devicelock_state_repr(devicelock_state_t state) */ bool devicelock_have_export_permission(void) { + LOG_REGISTER_CONTEXT; + bool unlocked = (devicelock_state == DEVICELOCK_UNLOCKED); return unlocked; @@ -136,6 +140,8 @@ bool devicelock_have_export_permission(void) static void devicelock_state_changed(devicelock_state_t state) { + LOG_REGISTER_CONTEXT; + if( devicelock_state == state ) goto EXIT; @@ -154,6 +160,8 @@ static DBusPendingCall *devicelock_state_query_pc = 0; static void devicelock_state_cancel(void) { + LOG_REGISTER_CONTEXT; + if( devicelock_state_query_pc ) { dbus_pending_call_cancel(devicelock_state_query_pc); dbus_pending_call_unref(devicelock_state_query_pc), @@ -163,6 +171,8 @@ static void devicelock_state_cancel(void) static void devicelock_state_query_cb(DBusPendingCall *pending, void *aptr) { + LOG_REGISTER_CONTEXT; + DBusMessage *rsp = 0; dbus_int32_t dta = DEVICELOCK_UNDEFINED; DBusError err = DBUS_ERROR_INIT; @@ -206,6 +216,8 @@ static void devicelock_state_query_cb(DBusPendingCall *pending, void *aptr) static void devicelock_state_query(void) { + LOG_REGISTER_CONTEXT; + DBusMessage *req = NULL; DBusPendingCall *pc = 0; @@ -249,6 +261,8 @@ static void devicelock_state_query(void) static void devicelock_state_signal(DBusMessage *msg) { + LOG_REGISTER_CONTEXT; + DBusError err = DBUS_ERROR_INIT; dbus_int32_t dta = DEVICELOCK_LOCKED; @@ -272,6 +286,8 @@ static void devicelock_state_signal(DBusMessage *msg) static void devicelock_available_changed(const char *owner) { + LOG_REGISTER_CONTEXT; + gboolean is_available = (owner && *owner); if( devicelock_is_available != is_available ) { @@ -293,6 +309,8 @@ static DBusPendingCall *devicelock_available_pc = 0; static void devicelock_available_cb(const char *owner) { + LOG_REGISTER_CONTEXT; + devicelock_available_changed(owner); dbus_pending_call_unref(devicelock_available_pc), @@ -301,6 +319,8 @@ static void devicelock_available_cb(const char *owner) static void devicelock_available_cancel(void) { + LOG_REGISTER_CONTEXT; + if( devicelock_available_pc ) { dbus_pending_call_cancel(devicelock_available_pc); @@ -311,6 +331,8 @@ static void devicelock_available_cancel(void) static void devicelock_available_query(void) { + LOG_REGISTER_CONTEXT; + devicelock_available_cancel(); log_debug("querying %s name owner", DEVICELOCK_SERVICE); @@ -322,6 +344,8 @@ static void devicelock_available_query(void) static void devicelock_name_owner_signal(DBusMessage *msg) { + LOG_REGISTER_CONTEXT; + DBusError err = DBUS_ERROR_INIT; const char *name = 0; const char *prev = 0; @@ -350,6 +374,8 @@ static void devicelock_name_owner_signal(DBusMessage *msg) static DBusHandlerResult devicelock_dbus_filter_cb(DBusConnection *con, DBusMessage *msg, void *aptr) { + LOG_REGISTER_CONTEXT; + (void)con; (void)aptr; @@ -376,6 +402,8 @@ devicelock_dbus_filter_cb(DBusConnection *con, DBusMessage *msg, void *aptr) bool devicelock_start_listener(void) { + LOG_REGISTER_CONTEXT; + bool ack = false; log_debug("starting devicelock listener"); @@ -412,6 +440,8 @@ devicelock_start_listener(void) void devicelock_stop_listener(void) { + LOG_REGISTER_CONTEXT; + log_debug("stopping devicelock listener"); /* Do note leave pending queries behind */ diff --git a/src/usb_moded-dsme.c b/src/usb_moded-dsme.c index ddf278c..990be4f 100644 --- a/src/usb_moded-dsme.c +++ b/src/usb_moded-dsme.c @@ -151,6 +151,8 @@ static bool dsme_shutdown_state = false; static const char * dsme_state_repr(dsme_state_t state) { + LOG_REGISTER_CONTEXT; + const char *repr = "DSME_STATE_UNKNOWN"; for( size_t i = 0; i < G_N_ELEMENTS(dsme_states); ++i ) { @@ -168,6 +170,8 @@ dsme_state_repr(dsme_state_t state) static dsme_state_t dsme_state_parse(const char *name) { + LOG_REGISTER_CONTEXT; + dsme_state_t state = DSME_STATE_NOT_SET; for( size_t i = 0; i < G_N_ELEMENTS(dsme_states); ++i ) { @@ -185,6 +189,8 @@ dsme_state_parse(const char *name) static void dsme_state_update(dsme_state_t state) { + LOG_REGISTER_CONTEXT; + /* Handle state change */ if( dsme_state_val != state ) { log_debug("dsme_state: %s -> %s", @@ -224,6 +230,8 @@ dsme_state_update(dsme_state_t state) static bool dsme_state_is_shutdown(void) { + LOG_REGISTER_CONTEXT; + return dsme_shutdown_state; } @@ -234,6 +242,8 @@ dsme_state_is_shutdown(void) static bool dsme_state_is_user(void) { + LOG_REGISTER_CONTEXT; + return dsme_user_state; } @@ -254,6 +264,8 @@ static guint dsme_socket_iowatch = 0; static bool dsme_socket_send_message(gpointer msg) { + LOG_REGISTER_CONTEXT; + bool res = false; if( !dsme_socket_con ) { @@ -280,6 +292,8 @@ dsme_socket_send_message(gpointer msg) static void dsme_socket_processwd_pong(void) { + LOG_REGISTER_CONTEXT; + DSM_MSGTYPE_PROCESSWD_PONG msg = DSME_MSG_INIT(DSM_MSGTYPE_PROCESSWD_PONG); @@ -293,6 +307,8 @@ dsme_socket_processwd_pong(void) static void dsme_socket_processwd_init(void) { + LOG_REGISTER_CONTEXT; + DSM_MSGTYPE_PROCESSWD_CREATE msg = DSME_MSG_INIT(DSM_MSGTYPE_PROCESSWD_CREATE); @@ -306,6 +322,8 @@ dsme_socket_processwd_init(void) static void dsme_socket_processwd_quit(void) { + LOG_REGISTER_CONTEXT; + DSM_MSGTYPE_PROCESSWD_DELETE msg = DSME_MSG_INIT(DSM_MSGTYPE_PROCESSWD_DELETE); @@ -319,6 +337,8 @@ dsme_socket_processwd_quit(void) static void dsme_socket_query_state(void) { + LOG_REGISTER_CONTEXT; + DSM_MSGTYPE_STATE_QUERY msg = DSME_MSG_INIT(DSM_MSGTYPE_STATE_QUERY); @@ -338,6 +358,8 @@ dsme_socket_recv_cb(GIOChannel *source, GIOCondition condition, gpointer data) { + LOG_REGISTER_CONTEXT; + gboolean keep_going = TRUE; dsmemsg_generic_t *msg = 0; @@ -401,6 +423,8 @@ dsme_socket_recv_cb(GIOChannel *source, static bool dsme_socket_is_connected(void) { + LOG_REGISTER_CONTEXT; + return dsme_socket_iowatch; } @@ -411,6 +435,8 @@ dsme_socket_is_connected(void) static bool dsme_socket_connect(void) { + LOG_REGISTER_CONTEXT; + GIOChannel *iochan = NULL; /* No new connections during shutdown */ @@ -465,6 +491,8 @@ dsme_socket_connect(void) static void dsme_socket_disconnect(void) { + LOG_REGISTER_CONTEXT; + if( dsme_socket_iowatch ) { log_debug("Removing DSME socket notifier"); g_source_remove(dsme_socket_iowatch); @@ -497,6 +525,8 @@ static DBusConnection *dsme_dbus_con = NULL; static void dsme_dbus_device_state_update(const char *state) { + LOG_REGISTER_CONTEXT; + dsme_state_update(dsme_state_parse(state)); } @@ -505,6 +535,8 @@ static DBusPendingCall *dsme_dbus_device_state_query_pc = 0; static void dsme_dbus_device_state_query_cb(DBusPendingCall *pending, void *aptr) { + LOG_REGISTER_CONTEXT; + DBusMessage *rsp = 0; const char *dta = 0; DBusError err = DBUS_ERROR_INIT; @@ -546,6 +578,8 @@ dsme_dbus_device_state_query_cb(DBusPendingCall *pending, void *aptr) static void dsme_dbus_device_state_query(void) { + LOG_REGISTER_CONTEXT; + DBusMessage *req = NULL; DBusPendingCall *pc = 0; @@ -587,6 +621,8 @@ dsme_dbus_device_state_query(void) static void dsme_dbus_device_state_cancel(void) { + LOG_REGISTER_CONTEXT; + if( dsme_dbus_device_state_query_pc ) { dbus_pending_call_cancel(dsme_dbus_device_state_query_pc); dbus_pending_call_unref(dsme_dbus_device_state_query_pc), @@ -597,6 +633,8 @@ dsme_dbus_device_state_cancel(void) static void dsme_dbus_device_state_signal(DBusMessage *msg) { + LOG_REGISTER_CONTEXT; + DBusError err = DBUS_ERROR_INIT; const char *dta = 0; @@ -624,12 +662,16 @@ static gchar *dsme_dbus_name_owner_val = 0; static bool dsme_dbus_name_owner_available(void) { + LOG_REGISTER_CONTEXT; + return dsme_dbus_name_owner_val != 0; } static void dsme_dbus_name_owner_update(const char *owner) { + LOG_REGISTER_CONTEXT; + if( owner && !*owner ) owner = 0; @@ -656,6 +698,8 @@ static DBusPendingCall *dsme_dbus_name_owner_query_pc = 0; static void dsme_dbus_name_owner_query_cb(const char *owner) { + LOG_REGISTER_CONTEXT; + dsme_dbus_name_owner_update(owner); dbus_pending_call_unref(dsme_dbus_name_owner_query_pc), @@ -665,6 +709,8 @@ dsme_dbus_name_owner_query_cb(const char *owner) static void dsme_dbus_name_owner_query(void) { + LOG_REGISTER_CONTEXT; + dsme_dbus_name_owner_cancel(); umdbus_get_name_owner_async(DSME_DBUS_SERVICE, @@ -675,6 +721,8 @@ dsme_dbus_name_owner_query(void) static void dsme_dbus_name_owner_cancel(void) { + LOG_REGISTER_CONTEXT; + if( dsme_dbus_name_owner_query_pc ) { dbus_pending_call_cancel(dsme_dbus_name_owner_query_pc); @@ -686,6 +734,8 @@ dsme_dbus_name_owner_cancel(void) static void dsme_dbus_name_owner_signal(DBusMessage *msg) { + LOG_REGISTER_CONTEXT; + DBusError err = DBUS_ERROR_INIT; const char *name = 0; const char *prev = 0; @@ -714,6 +764,8 @@ dsme_dbus_name_owner_signal(DBusMessage *msg) static DBusHandlerResult dsme_dbus_filter_cb(DBusConnection *con, DBusMessage *msg, void *user_data) { + LOG_REGISTER_CONTEXT; + (void)con; (void)user_data; @@ -736,6 +788,8 @@ dsme_dbus_filter_cb(DBusConnection *con, DBusMessage *msg, void *user_data) static bool dsme_dbus_init(void) { + LOG_REGISTER_CONTEXT; + bool ack = false; /* Get connection ref */ @@ -770,6 +824,8 @@ dsme_dbus_init(void) static void dsme_dbus_quit(void) { + LOG_REGISTER_CONTEXT; + /* Cancel any pending dbus queries */ dsme_dbus_name_owner_cancel(); dsme_dbus_device_state_cancel(); @@ -804,12 +860,16 @@ dsme_dbus_quit(void) gboolean dsme_listener_start(void) { + LOG_REGISTER_CONTEXT; + return dsme_dbus_init(); } void dsme_listener_stop(void) { + LOG_REGISTER_CONTEXT; + dsme_dbus_quit(); dsme_socket_disconnect(); } @@ -821,5 +881,7 @@ dsme_listener_stop(void) gboolean dsme_in_user_state(void) { + LOG_REGISTER_CONTEXT; + return dsme_state_is_user(); } diff --git a/src/usb_moded-dyn-config.c b/src/usb_moded-dyn-config.c index c769fb8..e7d99cf 100644 --- a/src/usb_moded-dyn-config.c +++ b/src/usb_moded-dyn-config.c @@ -50,6 +50,8 @@ static mode_list_elem_t *dynconfig_read_mode_file(const gchar *filename); void dynconfig_free_list_item(mode_list_elem_t *list_item) { + LOG_REGISTER_CONTEXT; + if( list_item ) { free(list_item->mode_name); free(list_item->mode_module); @@ -76,6 +78,8 @@ void dynconfig_free_list_item(mode_list_elem_t *list_item) void dynconfig_free_mode_list(GList *modelist) { + LOG_REGISTER_CONTEXT; + if(modelist) { g_list_foreach(modelist, (GFunc) dynconfig_free_list_item, NULL); @@ -86,6 +90,8 @@ void dynconfig_free_mode_list(GList *modelist) static gint dynconfig_compare_modes(gconstpointer a, gconstpointer b) { + LOG_REGISTER_CONTEXT; + mode_list_elem_t *aa = (mode_list_elem_t *)a; mode_list_elem_t *bb = (mode_list_elem_t *)b; @@ -94,6 +100,8 @@ static gint dynconfig_compare_modes(gconstpointer a, gconstpointer b) GList *dynconfig_read_mode_list(int diag) { + LOG_REGISTER_CONTEXT; + GDir *confdir; GList *modelist = NULL; const gchar *dirname; @@ -130,6 +138,8 @@ GList *dynconfig_read_mode_list(int diag) static mode_list_elem_t *dynconfig_read_mode_file(const gchar *filename) { + LOG_REGISTER_CONTEXT; + bool success = false; GKeyFile *settingsfile = g_key_file_new(); mode_list_elem_t *list_item = NULL; diff --git a/src/usb_moded-log.c b/src/usb_moded-log.c index b86cf77..b64e3c3 100644 --- a/src/usb_moded-log.c +++ b/src/usb_moded-log.c @@ -30,7 +30,10 @@ #include #include +#include +#include #include +#include /* ========================================================================= * * Prototypes @@ -64,6 +67,105 @@ static int log_type = LOG_TO_STDERR; static bool log_lineinfo = false; static struct timeval log_begtime = { 0, 0 }; +/* ========================================================================= * + * CONTEXT STACK + * ========================================================================= */ + +#if LOG_ENABLE_CONTEXT +typedef struct context_entry_t +{ + const char *func; + bool done; +} context_entry_t; + +typedef struct context_stack_t +{ + context_entry_t stk[256]; + int sp; + int id; +} context_stack_t; + +static int context_count = 0; +static __thread context_stack_t *context_stack = 0; + +static bool log_entry = false; +static bool log_leave = false; + +static void +context_write(int tab, const char *msg) +{ + int tag = 0; + if( context_stack ) { + tag = context_stack->id; + if( tab < 0 && context_stack->sp > 0 ) + tab = context_stack->sp; + } + tab = (tab <= 0) ? 0 : (tab * 4); + char *txt = 0; + int len = asprintf(&txt, "T%d %*s%s\n", + tag, + tab, "", + msg); + if( len > 0 ) { + if( write(STDERR_FILENO, txt, len) == - 1 ) { + // this is debug logging - do not really care + } + free(txt); + } +} + +static void +context_flush(void) +{ + for( int i = 0; i < context_stack->sp; ++i ) { + char msg[256]; + if( context_stack->stk[i].done ) + continue; + context_stack->stk[i].done = true; + if( log_leave ) + snprintf(msg, sizeof msg, "%s() { ...", + context_stack->stk[i].func); + else + snprintf(msg, sizeof msg, "%s()", + context_stack->stk[i].func); + context_write(i, msg); + } +} + +const char * +context_enter(const char *func) +{ + if( !context_stack ) { + context_stack = calloc(1, sizeof *context_stack); + context_stack->id = ++context_count; + } + + context_stack->stk[context_stack->sp].func = func; + context_stack->stk[context_stack->sp].done = false; + context_stack->sp += 1; + + if( log_entry ) + context_flush(); + + return func; +} + +void +context_leave(void *aptr) +{ + const char *func = *(const char **)aptr; + assert( context_stack->sp > 0 ); + context_stack->sp -= 1; + + if( log_leave && context_stack->stk[context_stack->sp].done ) { + char msg[256]; + snprintf(msg, sizeof msg, "} %s()", func); + context_write(-1, msg); + } + assert( context_stack->stk[context_stack->sp].func == func ); +} +#endif + /* ========================================================================= * * Functions * ========================================================================= */ @@ -104,6 +206,9 @@ static void log_gettime(struct timeval *tv) void log_emit_va(const char *file, const char *func, int line, int lev, const char *fmt, va_list va) { int saved = errno; + char lineinfo[128] = ""; + char timeinfo[32] = ""; + char levelinfo[8] = ""; if( log_p(lev) ) { switch( log_type ) @@ -119,17 +224,20 @@ void log_emit_va(const char *file, const char *func, int line, int lev, const ch /* 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); + snprintf(lineinfo, sizeof lineinfo, + "%s:%d: %s(): ", file, line, func); } else { - fprintf(stderr, "%s: ", log_get_name()); + snprintf(lineinfo, sizeof lineinfo, + "%s: ", log_get_name()); } #if LOG_ENABLE_TIMESTAMPS { struct timeval tv; log_gettime(&tv); - fprintf(stderr, "%3ld.%03ld ", + snprintf(timeinfo, sizeof timeinfo, + "%3ld.%03ld ", (long)tv.tv_sec, (long)tv.tv_usec/1000); } @@ -147,15 +255,26 @@ void log_emit_va(const char *file, const char *func, int line, int lev, const ch case LOG_INFO: tag = "I:"; break; case LOG_DEBUG: tag = "D:"; break; } - fprintf(stderr, "%s ", tag); + snprintf(levelinfo, sizeof levelinfo, + "%s ", tag); } #endif { // squeeze whitespace like syslog does - char buf[1024]; + char msg[512]; errno = saved; - vsnprintf(buf, sizeof buf - 1, fmt, va); - fprintf(stderr, "%s\n", log_strip(buf)); + vsnprintf(msg, sizeof msg, fmt, va); + log_strip(msg); +#if LOG_ENABLE_CONTEXT + char buf[1024]; + snprintf(buf, sizeof buf, "%s%s%s%s", + lineinfo, timeinfo, levelinfo, msg); + context_flush(); + context_write(-1, buf); +#else + fprintf(stderr, "%s%s%s%s\n", + lineinfo, timeinfo, levelinfo, msg); +#endif } break; diff --git a/src/usb_moded-log.h b/src/usb_moded-log.h index 0b37a38..79ad469 100644 --- a/src/usb_moded-log.h +++ b/src/usb_moded-log.h @@ -36,6 +36,7 @@ # define LOG_ENABLE_DEBUG 01 # define LOG_ENABLE_TIMESTAMPS 01 # define LOG_ENABLE_LEVELTAGS 01 +# define LOG_ENABLE_CONTEXT 0 enum { @@ -49,6 +50,22 @@ enum LOG_MAX_LEVEL = LOG_DEBUG, }; +/* ========================================================================= * + * CONTEXT STACK + * ========================================================================= */ + +# if LOG_ENABLE_CONTEXT +const char *context_enter(const char *func); +void context_leave(void *aptr); + +# define LOG_REGISTER_CONTEXT\ + __attribute__((cleanup(context_leave))) const char *qqq =\ + context_enter(__func__) +#else +# define LOG_REGISTER_CONTEXT\ + do{}while(0) +#endif + /* ========================================================================= * * Prototypes * ========================================================================= */ diff --git a/src/usb_moded-mac.c b/src/usb_moded-mac.c index 2669c4e..2550051 100644 --- a/src/usb_moded-mac.c +++ b/src/usb_moded-mac.c @@ -45,6 +45,8 @@ char *mac_read_mac (void); static void mac_random_ether_addr(unsigned char *addr) { + LOG_REGISTER_CONTEXT; + FILE *random; size_t count = 0; @@ -63,6 +65,8 @@ static void mac_random_ether_addr(unsigned char *addr) void mac_generate_random_mac (void) { + LOG_REGISTER_CONTEXT; + unsigned char addr[6]; int i; FILE *g_ether; @@ -88,6 +92,8 @@ void mac_generate_random_mac (void) char * mac_read_mac(void) { + LOG_REGISTER_CONTEXT; + FILE *g_ether; char *mac = NULL, *ret = NULL; size_t read = 0; diff --git a/src/usb_moded-modesetting.c b/src/usb_moded-modesetting.c index b309ade..6c4d639 100644 --- a/src/usb_moded-modesetting.c +++ b/src/usb_moded-modesetting.c @@ -84,6 +84,8 @@ static GHashTable *tracked_values = 0; static void modesetting_track_value(const char *path, const char *text) { + LOG_REGISTER_CONTEXT; + if( !tracked_values || !path ) goto EXIT; @@ -98,6 +100,8 @@ static void modesetting_track_value(const char *path, const char *text) void modesetting_verify_values(void) { + LOG_REGISTER_CONTEXT; + GHashTableIter iter; gpointer key, value; @@ -138,6 +142,8 @@ void modesetting_verify_values(void) static char *modesetting_strip(char *str) { + LOG_REGISTER_CONTEXT; + unsigned char *src = (unsigned char *)str; unsigned char *dst = (unsigned char *)str; @@ -156,6 +162,8 @@ static char *modesetting_strip(char *str) static char *modesetting_read_from_file(const char *path, size_t maxsize) { + LOG_REGISTER_CONTEXT; + int fd = -1; ssize_t done = 0; char *data = 0; @@ -192,6 +200,8 @@ static char *modesetting_read_from_file(const char *path, size_t maxsize) int modesetting_write_to_file_real(const char *file, int line, const char *func, const char *path, const char *text) { + LOG_REGISTER_CONTEXT; + int err = -1; int fd = -1; size_t todo = 0; @@ -288,6 +298,8 @@ char *modesetting_mountdev(const char *mountpoint); bool modesetting_is_mounted(const char *mountpoint) { + LOG_REGISTER_CONTEXT; + char cmd[256]; snprintf(cmd, sizeof cmd, "/bin/mountpoint -q '%s'", mountpoint); return common_system(cmd) == 0; @@ -295,6 +307,8 @@ bool modesetting_is_mounted(const char *mountpoint) bool modesetting_mount(const char *mountpoint) { + LOG_REGISTER_CONTEXT; + char cmd[256]; snprintf(cmd, sizeof cmd, "/bin/mount '%s'", mountpoint); return common_system(cmd) == 0; @@ -302,6 +316,8 @@ bool modesetting_mount(const char *mountpoint) bool modesetting_unmount(const char *mountpoint) { + LOG_REGISTER_CONTEXT; + char cmd[256]; snprintf(cmd, sizeof cmd, "/bin/umount '%s'", mountpoint); return common_system(cmd) == 0; @@ -309,6 +325,8 @@ bool modesetting_unmount(const char *mountpoint) gchar *modesetting_mountdev(const char *mountpoint) { + LOG_REGISTER_CONTEXT; + char *res = 0; FILE *fh = 0; struct mntent *me; @@ -335,6 +353,8 @@ gchar *modesetting_mountdev(const char *mountpoint) static void modesetting_free_storage_info(storage_info_t *info) { + LOG_REGISTER_CONTEXT; + if( info ) { for( size_t i = 0; info[i].si_mountpoint; ++i ) { g_free(info[i].si_mountpoint); @@ -347,6 +367,8 @@ modesetting_free_storage_info(storage_info_t *info) static storage_info_t * modesetting_get_storage_info(size_t *pcount) { + LOG_REGISTER_CONTEXT; + bool ack = false; storage_info_t *info = 0; size_t count = 0; @@ -407,6 +429,8 @@ modesetting_get_storage_info(size_t *pcount) static bool modesetting_enter_mass_storage_mode(mode_list_elem_t *data) { + LOG_REGISTER_CONTEXT; + bool ack = false; size_t count = 0; storage_info_t *info = 0; @@ -543,6 +567,8 @@ static bool modesetting_enter_mass_storage_mode(mode_list_elem_t *data) static int modesetting_leave_mass_storage_mode(mode_list_elem_t *data) { + LOG_REGISTER_CONTEXT; + (void)data; bool ack = false; @@ -638,6 +664,8 @@ static int modesetting_leave_mass_storage_mode(mode_list_elem_t *data) static void modesetting_report_mass_storage_blocker(const char *mountpoint, int try) { + LOG_REGISTER_CONTEXT; + FILE *stream = 0; gchar *lsof_command = 0; int count = 0; @@ -673,6 +701,8 @@ static void modesetting_report_mass_storage_blocker(const char *mountpoint, int bool modesetting_enter_dynamic_mode(void) { + LOG_REGISTER_CONTEXT; + bool ack = false; mode_list_elem_t *data; @@ -823,6 +853,8 @@ bool modesetting_enter_dynamic_mode(void) void modesetting_leave_dynamic_mode(void) { + LOG_REGISTER_CONTEXT; + log_debug("DYNAMIC MODE: CLEANUP"); mode_list_elem_t *data; @@ -923,6 +955,8 @@ void modesetting_leave_dynamic_mode(void) */ void modesetting_init(void) { + LOG_REGISTER_CONTEXT; + if( !tracked_values ) { tracked_values = g_hash_table_new_full(g_str_hash, g_str_equal, g_free, g_free); @@ -933,6 +967,8 @@ void modesetting_init(void) */ void modesetting_quit(void) { + LOG_REGISTER_CONTEXT; + if( tracked_values ) { g_hash_table_unref(tracked_values), tracked_values = 0; } diff --git a/src/usb_moded-modules.c b/src/usb_moded-modules.c index fb54921..e65c28f 100644 --- a/src/usb_moded-modules.c +++ b/src/usb_moded-modules.c @@ -72,6 +72,8 @@ static struct kmod_ctx *modules_ctx = 0; static bool modules_have_module(const char *module) { + LOG_REGISTER_CONTEXT; + // TODO: not fully untested due to lack of suitable hw bool ack = false; @@ -96,6 +98,8 @@ static bool modules_have_module(const char *module) bool modules_in_use(void) { + LOG_REGISTER_CONTEXT; + if( modules_probed < 0 ) log_debug("modules_in_use() called before modules_probe()"); @@ -104,6 +108,8 @@ bool modules_in_use(void) static bool modules_probe(void) { + LOG_REGISTER_CONTEXT; + static const char * const lut[] = { MODULE_MASS_STORAGE, MODULE_FILE_STORAGE, @@ -132,6 +138,8 @@ static bool modules_probe(void) /* kmod module init */ bool modules_init(void) { + LOG_REGISTER_CONTEXT; + bool ack = false; if( !modules_ctx ) { @@ -153,6 +161,8 @@ bool modules_init(void) /* kmod module cleanup */ void modules_quit(void) { + LOG_REGISTER_CONTEXT; + if( modules_ctx ) kmod_unref(modules_ctx), modules_ctx = 0; } @@ -165,6 +175,8 @@ void modules_quit(void) */ int modules_load_module(const char *module) { + LOG_REGISTER_CONTEXT; + int ret = 0; const int probe_flags = KMOD_PROBE_APPLY_BLACKLIST; @@ -235,6 +247,8 @@ int modules_load_module(const char *module) */ int modules_unload_module(const char *module) { + LOG_REGISTER_CONTEXT; + int ret = 0; struct kmod_module *mod; diff --git a/src/usb_moded-network.c b/src/usb_moded-network.c index 034adda..cffb6f8 100644 --- a/src/usb_moded-network.c +++ b/src/usb_moded-network.c @@ -112,6 +112,8 @@ static const char default_interface[] = "usb0"; static void network_free_ipforward_data (ipforward_data_t *ipforward) { + LOG_REGISTER_CONTEXT; + if(ipforward) { if(ipforward->dns1) @@ -127,6 +129,8 @@ static void network_free_ipforward_data (ipforward_data_t *ipforward) /* This function checks if the configured interface exists */ static int network_check_interface(char *interface) { + LOG_REGISTER_CONTEXT; + int ret = -1; if(interface) @@ -141,6 +145,8 @@ static int network_check_interface(char *interface) static char* network_get_interface(mode_list_elem_t *data) { + LOG_REGISTER_CONTEXT; + (void)data; // FIXME: why is this passed in the 1st place? char *interface = 0; @@ -176,6 +182,8 @@ static char* network_get_interface(mode_list_elem_t *data) */ static int network_set_usb_ip_forward(mode_list_elem_t *data, ipforward_data_t *ipforward) { + LOG_REGISTER_CONTEXT; + char *interface, *nat_interface; char command[128]; @@ -217,6 +225,8 @@ static int network_set_usb_ip_forward(mode_list_elem_t *data, ipforward_data_t * */ static void network_clean_usb_ip_forward(void) { + LOG_REGISTER_CONTEXT; + #ifdef CONNMAN connman_reset_state(); #endif @@ -232,6 +242,8 @@ static void network_clean_usb_ip_forward(void) */ static int get_roaming(void) { + LOG_REGISTER_CONTEXT; + int ret = 0, type; DBusError error; DBusMessage *msg = NULL, *reply; @@ -304,6 +316,8 @@ static int get_roaming(void) */ static int resolv_conf_dns(ipforward_data_t *ipforward) { + LOG_REGISTER_CONTEXT; + FILE *resolv; int i = 0, count = 0; char *line = NULL, **tokens; @@ -343,6 +357,8 @@ static int resolv_conf_dns(ipforward_data_t *ipforward) static int network_checklink(void) { + LOG_REGISTER_CONTEXT; + int ret = -1; char dest[sizeof UDHCP_CONFIG_PATH + 1]; size_t len = readlink(UDHCP_CONFIG_LINK, dest, sizeof dest - 1); @@ -361,6 +377,8 @@ static int network_checklink(void) */ static int network_write_udhcpd_conf(ipforward_data_t *ipforward, mode_list_elem_t *data) { + LOG_REGISTER_CONTEXT; + FILE *conffile; char *ip, *interface, *netmask; char *ipstart, *ipend; @@ -473,6 +491,8 @@ static int network_write_udhcpd_conf(ipforward_data_t *ipforward, mode_list_elem */ static gboolean connman_try_set_tethering(DBusConnection *connection, const char *path, gboolean on) { + LOG_REGISTER_CONTEXT; + gboolean ok = FALSE; DBusMessage *message = dbus_message_new_method_call(CONNMAN_SERVICE, path, CONNMAN_TECH_INTERFACE, "SetProperty"); if (message) @@ -520,6 +540,8 @@ static gboolean connman_try_set_tethering(DBusConnection *connection, const char gboolean connman_set_tethering(const char *path, gboolean on) { + LOG_REGISTER_CONTEXT; + gboolean ok = FALSE; DBusError error; DBusConnection *connection; @@ -558,6 +580,8 @@ gboolean connman_set_tethering(const char *path, gboolean on) */ static char * connman_parse_manager_reply(DBusMessage *reply, const char *req_service) { + LOG_REGISTER_CONTEXT; + DBusMessageIter iter, subiter, origiter; int type; char *service; @@ -597,6 +621,8 @@ static char * connman_parse_manager_reply(DBusMessage *reply, const char *req_se static int connman_fill_connection_data(DBusMessage *reply, ipforward_data_t *ipforward) { + LOG_REGISTER_CONTEXT; + DBusMessageIter array_iter, dict_iter, inside_dict_iter, variant_iter; DBusMessageIter sub_array_iter, string_iter; int type, next; @@ -715,6 +741,8 @@ static int connman_fill_connection_data(DBusMessage *reply, ipforward_data_t *ip */ static int connman_set_cellular_online(DBusConnection *dbus_conn_connman, const char *service, int retry) { + LOG_REGISTER_CONTEXT; + DBusMessage *msg = NULL, *reply; DBusError error; int ret = 0; @@ -770,6 +798,8 @@ static int connman_set_cellular_online(DBusConnection *dbus_conn_connman, const */ static int connman_wifi_power_control(DBusConnection *dbus_conn_connman, int on) { + LOG_REGISTER_CONTEXT; + static int wifistatus = 0; int type = 0; char *string; @@ -832,6 +862,8 @@ static int connman_wifi_power_control(DBusConnection *dbus_conn_connman, int on) static int connman_get_connection_data(ipforward_data_t *ipforward) { + LOG_REGISTER_CONTEXT; + DBusConnection *dbus_conn_connman = NULL; DBusMessage *msg = NULL, *reply = NULL; DBusError error; @@ -893,6 +925,8 @@ static int connman_get_connection_data(ipforward_data_t *ipforward) static int connman_reset_state(void) { + LOG_REGISTER_CONTEXT; + DBusConnection *dbus_conn_connman = NULL; DBusError error; @@ -918,6 +952,8 @@ static int connman_reset_state(void) */ int network_set_up_dhcpd(mode_list_elem_t *data) { + LOG_REGISTER_CONTEXT; + ipforward_data_t *ipforward = NULL; int ret = 1; @@ -962,6 +998,8 @@ int network_set_up_dhcpd(mode_list_elem_t *data) static int append_variant(DBusMessageIter *iter, const char *property, int type, const char *value) { + LOG_REGISTER_CONTEXT; + DBusMessageIter variant; const char *type_str; @@ -998,6 +1036,8 @@ static int append_variant(DBusMessageIter *iter, const char *property, */ int network_up(mode_list_elem_t *data) { + LOG_REGISTER_CONTEXT; + char *ip = NULL, *gateway = NULL; int ret = -1; @@ -1164,6 +1204,8 @@ int network_up(mode_list_elem_t *data) */ int network_down(mode_list_elem_t *data) { + LOG_REGISTER_CONTEXT; + #if CONNMAN_WORKS_BETTER DBusConnection *dbus_conn_connman = NULL; DBusMessage *msg = NULL, *reply = NULL; @@ -1236,6 +1278,8 @@ int network_down(mode_list_elem_t *data) */ int network_update(void) { + LOG_REGISTER_CONTEXT; + if( control_get_cable_state() == CABLE_STATE_PC_CONNECTED ) { mode_list_elem_t *data = worker_get_usb_mode_data(); if( data && data->network ) { diff --git a/src/usb_moded-sigpipe.c b/src/usb_moded-sigpipe.c index 45c5e0c..c464c7d 100644 --- a/src/usb_moded-sigpipe.c +++ b/src/usb_moded-sigpipe.c @@ -61,6 +61,8 @@ sigpipe_read_signal_cb(GIOChannel *channel, GIOCondition condition, gpointer data) { + LOG_REGISTER_CONTEXT; + gboolean keep_watch = FALSE; int fd, rc, sig; @@ -99,6 +101,8 @@ sigpipe_read_signal_cb(GIOChannel *channel, static void sigpipe_trap_signal_cb(int sig) { + LOG_REGISTER_CONTEXT; + /* NOTE: This function *MUST* be kept async-signal-safe! */ static volatile int exit_tries = 0; @@ -139,6 +143,8 @@ sigpipe_trap_signal_cb(int sig) static bool sigpipe_crate_pipe(void) { + LOG_REGISTER_CONTEXT; + bool res = false; GIOChannel *chn = 0; int pfd[2] = { -1, -1 }; @@ -171,6 +177,8 @@ sigpipe_crate_pipe(void) static void sigpipe_trap_signals(void) { + LOG_REGISTER_CONTEXT; + static const int sig[] = { SIGINT, @@ -193,6 +201,8 @@ sigpipe_trap_signals(void) bool sigpipe_init(void) { + LOG_REGISTER_CONTEXT; + bool success = false; if( !sigpipe_crate_pipe() ) diff --git a/src/usb_moded-ssu.c b/src/usb_moded-ssu.c index e46c147..4f1ca7e 100644 --- a/src/usb_moded-ssu.c +++ b/src/usb_moded-ssu.c @@ -57,6 +57,8 @@ static gboolean ssu_intialized = FALSE; /** Atexit callback for releasing cached ssu-sysinfo handle */ static void ssu_free_handle(void) { + LOG_REGISTER_CONTEXT; + /* Make sure instance does not get created on exit path */ ssu_intialized = TRUE; @@ -71,6 +73,8 @@ static void ssu_free_handle(void) */ static ssusysinfo_t *ssu_get_handle(void) { + LOG_REGISTER_CONTEXT; + /* Attempt only once */ if( !ssu_intialized ) { ssu_intialized = TRUE; @@ -89,6 +93,8 @@ static ssusysinfo_t *ssu_get_handle(void) gchar * ssu_get_manufacturer_name(void) { + LOG_REGISTER_CONTEXT; + gchar *res = 0; const char *val = ssusysinfo_device_manufacturer(ssu_get_handle()); if( val && strcmp(val, "UNKNOWN") ) @@ -106,6 +112,8 @@ ssu_get_manufacturer_name(void) gchar * ssu_get_product_name(void) { + LOG_REGISTER_CONTEXT; + gchar *res = 0; const char *val = ssusysinfo_device_pretty_name(ssu_get_handle()); if( val && strcmp(val, "UNKNOWN") ) diff --git a/src/usb_moded-systemd.c b/src/usb_moded-systemd.c index e09980f..8e87a42 100644 --- a/src/usb_moded-systemd.c +++ b/src/usb_moded-systemd.c @@ -63,6 +63,8 @@ static DBusConnection *systemd_con = NULL; // method = StartUnit or StopUnit gboolean systemd_control_service(const char *name, const char *method) { + LOG_REGISTER_CONTEXT; + DBusMessage *req = NULL; DBusMessage *rsp = NULL; DBusError err = DBUS_ERROR_INIT; @@ -142,6 +144,8 @@ gboolean systemd_control_service(const char *name, const char *method) gboolean systemd_control_start(void) { + LOG_REGISTER_CONTEXT; + gboolean ack = FALSE; log_debug("starting systemd control"); @@ -162,6 +166,8 @@ systemd_control_start(void) void systemd_control_stop(void) { + LOG_REGISTER_CONTEXT; + log_debug("stopping systemd control"); if(systemd_con) diff --git a/src/usb_moded-trigger.c b/src/usb_moded-trigger.c index 9a25760..7e0ef42 100644 --- a/src/usb_moded-trigger.c +++ b/src/usb_moded-trigger.c @@ -63,6 +63,8 @@ static gchar *trigger_udev_sysname = 0; static void trigger_udev_error_cb (gpointer data) { + LOG_REGISTER_CONTEXT; + (void)data; log_debug("trigger watch destroyed\n!"); @@ -73,6 +75,8 @@ static void trigger_udev_error_cb (gpointer data) bool trigger_init(void) { + LOG_REGISTER_CONTEXT; + bool ack = false; gchar *devpath = 0; @@ -165,6 +169,8 @@ bool trigger_init(void) static gboolean trigger_udev_input_cb(GIOChannel *iochannel G_GNUC_UNUSED, GIOCondition cond, gpointer data G_GNUC_UNUSED) { + LOG_REGISTER_CONTEXT; + struct udev_device *dev; if(cond & G_IO_IN) @@ -203,6 +209,8 @@ static gboolean trigger_udev_input_cb(GIOChannel *iochannel G_GNUC_UNUSED, GIOCo void trigger_stop(void) { + LOG_REGISTER_CONTEXT; + if(trigger_udev_watch_id) { g_source_remove(trigger_udev_watch_id); @@ -224,6 +232,8 @@ void trigger_stop(void) static void trigger_parse_udev_properties(struct udev_device *dev) { + LOG_REGISTER_CONTEXT; + char *trigger_property = 0; char *trigger_value = 0; char *trigger_mode = 0; diff --git a/src/usb_moded-udev.c b/src/usb_moded-udev.c index b2aedea..d66fb48 100644 --- a/src/usb_moded-udev.c +++ b/src/usb_moded-udev.c @@ -90,6 +90,8 @@ static gint umudev_cable_state_timer_delay = -1; static gboolean umudev_cable_state_timer_cb(gpointer aptr) { + LOG_REGISTER_CONTEXT; + (void)aptr; umudev_cable_state_timer_id = 0; umudev_cable_state_timer_delay = -1; @@ -102,6 +104,8 @@ static gboolean umudev_cable_state_timer_cb(gpointer aptr) static void umudev_cable_state_stop_timer(void) { + LOG_REGISTER_CONTEXT; + if( umudev_cable_state_timer_id ) { log_debug("cancel delayed transfer to: %s", cable_state_repr(umudev_cable_state_current)); @@ -113,6 +117,8 @@ static void umudev_cable_state_stop_timer(void) static void umudev_cable_state_start_timer(gint delay) { + LOG_REGISTER_CONTEXT; + if( umudev_cable_state_timer_delay != delay ) { umudev_cable_state_stop_timer(); } @@ -130,6 +136,8 @@ static void umudev_cable_state_start_timer(gint delay) static bool umudev_cable_state_connected(void) { + LOG_REGISTER_CONTEXT; + bool connected = false; switch( umudev_cable_state_get() ) { default: @@ -144,11 +152,15 @@ umudev_cable_state_connected(void) static cable_state_t umudev_cable_state_get(void) { + LOG_REGISTER_CONTEXT; + return umudev_cable_state_active; } static void umudev_cable_state_set(cable_state_t state) { + LOG_REGISTER_CONTEXT; + umudev_cable_state_stop_timer(); if( umudev_cable_state_active == state ) @@ -169,6 +181,8 @@ static void umudev_cable_state_set(cable_state_t state) static void umudev_cable_state_changed(void) { + LOG_REGISTER_CONTEXT; + /* The rest of usb-moded separates charger * and pc connection states... make single * state tracking compatible with that. */ @@ -212,6 +226,8 @@ static void umudev_cable_state_changed(void) static void umudev_cable_state_from_udev(cable_state_t curr) { + LOG_REGISTER_CONTEXT; + cable_state_t prev = umudev_cable_state_current; umudev_cable_state_current = curr; @@ -260,6 +276,8 @@ static void umudev_cable_state_from_udev(cable_state_t curr) static void umudev_io_error_cb(gpointer data) { + LOG_REGISTER_CONTEXT; + (void)data; /* we do not want to restart when we try to clean up */ @@ -273,6 +291,8 @@ static void umudev_io_error_cb(gpointer data) static gboolean umudev_io_input_cb(GIOChannel *iochannel, GIOCondition cond, gpointer data) { + LOG_REGISTER_CONTEXT; + (void)iochannel; (void)data; @@ -324,6 +344,8 @@ static gboolean umudev_io_input_cb(GIOChannel *iochannel, GIOCondition cond, gpo static void umudev_parse_properties(struct udev_device *dev, bool initial) { + LOG_REGISTER_CONTEXT; + (void)initial; /* udev properties we are interested in */ @@ -429,6 +451,8 @@ static void umudev_parse_properties(struct udev_device *dev, bool initial) static int umudev_score_as_power_supply(const char *syspath) { + LOG_REGISTER_CONTEXT; + int score = 0; struct udev_device *dev = 0; const char *sysname = 0; @@ -478,6 +502,8 @@ static int umudev_score_as_power_supply(const char *syspath) gboolean umudev_init(void) { + LOG_REGISTER_CONTEXT; + gboolean success = FALSE; char *configured_device = NULL; @@ -606,6 +632,8 @@ gboolean umudev_init(void) void umudev_quit(void) { + LOG_REGISTER_CONTEXT; + umudev_in_cleanup = true; log_debug("HWhal cleanup\n"); diff --git a/src/usb_moded-worker.c b/src/usb_moded-worker.c index 4487d61..e93bb3f 100644 --- a/src/usb_moded-worker.c +++ b/src/usb_moded-worker.c @@ -121,12 +121,16 @@ static volatile bool worker_bailout_handled = false; static bool worker_thread_p(void) { + LOG_REGISTER_CONTEXT; + return worker_thread_id && worker_thread_id == pthread_self(); } bool worker_bailing_out(void) { + LOG_REGISTER_CONTEXT; + // ref: see common_msleep_() return (worker_thread_p() && worker_bailout_requested && @@ -167,11 +171,15 @@ static bool worker_mtp_service_started = false; static bool worker_mode_is_mtp_mode(const char *mode) { + LOG_REGISTER_CONTEXT; + return mode && !strcmp(mode, "mtp_mode"); } static bool worker_is_mtpd_running(void) { + LOG_REGISTER_CONTEXT; + /* ep0 becomes available when /dev/mtp is mounted. * * ep1, ep2, ep3 exist while mtp daemon is running, @@ -200,6 +208,8 @@ static bool worker_is_mtpd_running(void) static bool worker_mtpd_running_p(void *aptr) { + LOG_REGISTER_CONTEXT; + (void)aptr; return worker_is_mtpd_running(); } @@ -207,6 +217,8 @@ worker_mtpd_running_p(void *aptr) static bool worker_mtpd_stopped_p(void *aptr) { + LOG_REGISTER_CONTEXT; + (void)aptr; return !worker_is_mtpd_running(); } @@ -214,6 +226,8 @@ worker_mtpd_stopped_p(void *aptr) static bool worker_stop_mtpd(void) { + LOG_REGISTER_CONTEXT; + bool ack = false; if( !worker_mtp_service_started && worker_mtpd_stopped_p(0) ) { @@ -247,6 +261,8 @@ worker_stop_mtpd(void) static bool worker_start_mtpd(void) { + LOG_REGISTER_CONTEXT; + bool ack = false; if( worker_mtpd_running_p(0) ) { @@ -279,6 +295,8 @@ worker_start_mtpd(void) static bool worker_switch_to_charging(void) { + LOG_REGISTER_CONTEXT; + bool ack = true; if( android_set_charging_mode() ) @@ -314,6 +332,8 @@ static char *worker_kernel_module = NULL; */ const char * worker_get_kernel_module(void) { + LOG_REGISTER_CONTEXT; + return worker_kernel_module ?: MODULE_NONE; } @@ -324,6 +344,8 @@ const char * worker_get_kernel_module(void) */ bool worker_set_kernel_module(const char *module) { + LOG_REGISTER_CONTEXT; + bool ack = false; if( !module ) @@ -355,6 +377,8 @@ bool worker_set_kernel_module(const char *module) void worker_clear_kernel_module(void) { + LOG_REGISTER_CONTEXT; + free(worker_kernel_module), worker_kernel_module = 0; } @@ -372,6 +396,8 @@ static mode_list_elem_t *worker_mode_data = NULL; */ mode_list_elem_t *worker_get_usb_mode_data(void) { + LOG_REGISTER_CONTEXT; + return worker_mode_data; } @@ -382,6 +408,8 @@ mode_list_elem_t *worker_get_usb_mode_data(void) */ void worker_set_usb_mode_data(mode_list_elem_t *data) { + LOG_REGISTER_CONTEXT; + worker_mode_data = data; } @@ -402,12 +430,16 @@ static gchar *worker_activated_mode = NULL; static const char * worker_get_activated_mode_locked(void) { + LOG_REGISTER_CONTEXT; + return worker_activated_mode ?: MODE_UNDEFINED; } static bool worker_set_activated_mode_locked(const char *mode) { + LOG_REGISTER_CONTEXT; + bool changed = false; const char *prev = worker_get_activated_mode_locked(); @@ -426,12 +458,16 @@ worker_set_activated_mode_locked(const char *mode) static const char * worker_get_requested_mode_locked(void) { + LOG_REGISTER_CONTEXT; + return worker_requested_mode ?: MODE_UNDEFINED; } static bool worker_set_requested_mode_locked(const char *mode) { + LOG_REGISTER_CONTEXT; + bool changed = false; const char *prev = worker_get_requested_mode_locked(); @@ -449,6 +485,8 @@ worker_set_requested_mode_locked(const char *mode) void worker_request_hardware_mode(const char *mode) { + LOG_REGISTER_CONTEXT; + WORKER_LOCKED_ENTER; if( !worker_set_requested_mode_locked(mode) ) @@ -463,6 +501,8 @@ void worker_request_hardware_mode(const char *mode) void worker_clear_hardware_mode(void) { + LOG_REGISTER_CONTEXT; + WORKER_LOCKED_ENTER; g_free(worker_requested_mode), worker_requested_mode = 0; WORKER_LOCKED_LEAVE; @@ -471,6 +511,8 @@ void worker_clear_hardware_mode(void) static void worker_execute(void) { + LOG_REGISTER_CONTEXT; + WORKER_LOCKED_ENTER; const char *activated = worker_get_activated_mode_locked(); @@ -503,6 +545,8 @@ worker_execute(void) void worker_switch_to_mode(const char *mode) { + LOG_REGISTER_CONTEXT; + const char *override = 0; /* set return to 1 to be sure to error out if no matching mode is found either */ @@ -654,6 +698,8 @@ static guint worker_add_iowatch(int fd, bool close_on_unref, GIOCondition cnd, GIOFunc io_cb, gpointer aptr) { + LOG_REGISTER_CONTEXT; + guint wid = 0; GIOChannel *chn = 0; @@ -676,6 +722,8 @@ worker_add_iowatch(int fd, bool close_on_unref, static void *worker_thread_cb(void *aptr) { + LOG_REGISTER_CONTEXT; + (void)aptr; /* Async cancellation, but disabled */ @@ -721,6 +769,8 @@ static void *worker_thread_cb(void *aptr) static gboolean worker_notify_cb(GIOChannel *chn, GIOCondition cnd, gpointer data) { + LOG_REGISTER_CONTEXT; + (void)data; gboolean keep_going = FALSE; @@ -785,6 +835,8 @@ worker_notify_cb(GIOChannel *chn, GIOCondition cnd, gpointer data) static bool worker_start_thread(void) { + LOG_REGISTER_CONTEXT; + bool ack = false; int err = pthread_create(&worker_thread_id, 0, worker_thread_cb, 0); if( err ) { @@ -802,6 +854,8 @@ worker_start_thread(void) static void worker_stop_thread(void) { + LOG_REGISTER_CONTEXT; + if( !worker_thread_id ) goto EXIT; @@ -838,6 +892,8 @@ worker_stop_thread(void) static void worker_delete_eventfd(void) { + LOG_REGISTER_CONTEXT; + if( worker_req_evfd != -1 ) close(worker_req_evfd), worker_req_evfd = -1; @@ -851,6 +907,8 @@ worker_delete_eventfd(void) static bool worker_create_eventfd(void) { + LOG_REGISTER_CONTEXT; + bool ack = false; /* Setup notify pipeline */ @@ -878,6 +936,8 @@ worker_create_eventfd(void) bool worker_init(void) { + LOG_REGISTER_CONTEXT; + bool ack = false; if( !worker_create_eventfd() ) @@ -898,6 +958,8 @@ worker_init(void) void worker_quit(void) { + LOG_REGISTER_CONTEXT; + worker_stop_thread(); worker_delete_eventfd(); } @@ -905,6 +967,8 @@ worker_quit(void) void worker_wakeup(void) { + LOG_REGISTER_CONTEXT; + worker_bailout_requested = true; uint64_t cnt = 1; @@ -916,6 +980,8 @@ worker_wakeup(void) static void worker_notify(void) { + LOG_REGISTER_CONTEXT; + uint64_t cnt = 1; if( write(worker_rsp_evfd, &cnt, sizeof cnt) == -1 ) { log_err("failed to signal handled: %m"); diff --git a/src/usb_moded.c b/src/usb_moded.c index 3902182..725a689 100644 --- a/src/usb_moded.c +++ b/src/usb_moded.c @@ -153,12 +153,16 @@ static GList *usbmoded_modelist = 0; GList * usbmoded_get_modelist(void) { + LOG_REGISTER_CONTEXT; + return usbmoded_modelist; } void usbmoded_load_modelist(void) { + LOG_REGISTER_CONTEXT; + if( !usbmoded_modelist ) { log_notice("load modelist"); usbmoded_modelist = dynconfig_read_mode_list(usbmoded_get_diag_mode()); @@ -168,6 +172,8 @@ usbmoded_load_modelist(void) void usbmoded_free_modelist(void) { + LOG_REGISTER_CONTEXT; + if( usbmoded_modelist ) { log_notice("free modelist"); dynconfig_free_mode_list(usbmoded_modelist), @@ -189,11 +195,15 @@ static bool usbmoded_rescue_mode = false; bool usbmoded_get_rescue_mode(void) { + LOG_REGISTER_CONTEXT; + return usbmoded_rescue_mode; } void usbmoded_set_rescue_mode(bool rescue_mode) { + LOG_REGISTER_CONTEXT; + if( usbmoded_rescue_mode != rescue_mode ) { log_info("rescue_mode: %d -> %d", usbmoded_rescue_mode, rescue_mode); usbmoded_rescue_mode = rescue_mode; @@ -213,11 +223,15 @@ static bool usbmoded_diag_mode = false; bool usbmoded_get_diag_mode(void) { + LOG_REGISTER_CONTEXT; + return usbmoded_diag_mode; } void usbmoded_set_diag_mode(bool diag_mode) { + LOG_REGISTER_CONTEXT; + if( usbmoded_diag_mode != diag_mode ) { log_info("diag_mode: %d -> %d", usbmoded_diag_mode, diag_mode); usbmoded_diag_mode = diag_mode; @@ -244,6 +258,8 @@ static int usbmoded_cable_connection_delay = CABLE_CONNECTION_DELAY_DEFAULT; void usbmoded_set_cable_connection_delay(int delay_ms) { + LOG_REGISTER_CONTEXT; + if( delay_ms > CABLE_CONNECTION_DELAY_MAXIMUM ) delay_ms = CABLE_CONNECTION_DELAY_MAXIMUM; if( delay_ms < 0 ) @@ -262,6 +278,8 @@ usbmoded_set_cable_connection_delay(int delay_ms) int usbmoded_get_cable_connection_delay(void) { + LOG_REGISTER_CONTEXT; + return usbmoded_cable_connection_delay; } @@ -281,6 +299,8 @@ static guint usbmoded_allow_suspend_timer_id = 0; */ static gboolean usbmoded_allow_suspend_timer_cb(gpointer aptr) { + LOG_REGISTER_CONTEXT; + (void)aptr; usbmoded_allow_suspend_timer_id = 0; @@ -297,6 +317,8 @@ static gboolean usbmoded_allow_suspend_timer_cb(gpointer aptr) */ void usbmoded_allow_suspend(void) { + LOG_REGISTER_CONTEXT; + if( usbmoded_allow_suspend_timer_id ) { g_source_remove(usbmoded_allow_suspend_timer_id), usbmoded_allow_suspend_timer_id = 0; @@ -320,6 +342,8 @@ void usbmoded_allow_suspend(void) */ void usbmoded_delay_suspend(void) { + LOG_REGISTER_CONTEXT; + /* Use of automatically terminating wakelocks also means we need * to renew the wakelock when extending the suspend delay. */ common_acquire_wakelock(USB_MODED_WAKELOCK_STATE_CHANGE); @@ -344,6 +368,8 @@ void usbmoded_delay_suspend(void) */ bool usbmoded_can_export(void) { + LOG_REGISTER_CONTEXT; + bool can_export = true; #ifdef MEEGOLOCK @@ -376,12 +402,16 @@ static bool usbmoded_init_done_reached = false; */ bool usbmoded_init_done_p(void) { + LOG_REGISTER_CONTEXT; + return usbmoded_init_done_reached; } /** Update cached init-done-reached state */ void usbmoded_set_init_done(bool reached) { + LOG_REGISTER_CONTEXT; + if( usbmoded_init_done_reached != reached ) { usbmoded_init_done_reached = reached; log_warning("init_done -> %s", @@ -392,6 +422,8 @@ void usbmoded_set_init_done(bool reached) /** Check whether init-done flag file exists */ void usbmoded_probe_init_done(void) { + LOG_REGISTER_CONTEXT; + usbmoded_set_init_done(access(usbmoded_init_done_flagfile, F_OK) == 0); } @@ -403,6 +435,8 @@ void usbmoded_probe_init_done(void) */ void usbmoded_exit_mainloop(int exitcode) { + LOG_REGISTER_CONTEXT; + /* In case multiple exit request get done, retain the * highest exit code used. */ if( usbmoded_exitcode < exitcode ) @@ -422,6 +456,8 @@ void usbmoded_exit_mainloop(int exitcode) void usbmoded_handle_signal(int signum) { + LOG_REGISTER_CONTEXT; + log_debug("handle signal: %s\n", strsignal(signum)); if( signum == SIGTERM ) @@ -449,6 +485,8 @@ void usbmoded_handle_signal(int signum) /* Prepare usb-moded for running the mainloop */ static bool usbmoded_init(void) { + LOG_REGISTER_CONTEXT; + bool ack = false; /* Check if we are in mid-bootup */ @@ -609,6 +647,8 @@ static bool usbmoded_init(void) */ static void usbmoded_cleanup(void) { + LOG_REGISTER_CONTEXT; + /* Stop the worker thread first to avoid confusion about shared * resources we are just about to release. */ worker_quit(); @@ -741,11 +781,15 @@ static const char usbmoded_short_options[] = "aifsTlDdhrnvm:b:Q"; /* Display usbmoded_usage information */ static void usbmoded_usage(void) { + LOG_REGISTER_CONTEXT; + fprintf(stdout, "%s", usbmoded_usage_info); } static void usbmoded_parse_options(int argc, char* argv[]) { + LOG_REGISTER_CONTEXT; + /* Parse the command-line options */ for( ;; ) { int opt = getopt_long(argc, argv, @@ -824,6 +868,8 @@ static void usbmoded_parse_options(int argc, char* argv[]) int main(int argc, char* argv[]) { + LOG_REGISTER_CONTEXT; + /* Library init calls that should be made before * using library functionality. */