Refactor and unify internal debug system for ease of use and verbosity

This introduces a new debug_info macro which automatically prints
the calling function, file and line number information instead of
having that information passed to every old log_debug_msg call.

1 files changed, 53 insertions, 53 deletions

diff --git a/src/lockdown.c b/src/lockdown.c
index 5e0f579..7609426 100644
--- a/src/lockdown.c
+++ b/src/lockdown.c
@@ -99,7 +99,7 @@ static int lockdown_check_result(plist_t dict, const char *query_match)
                         } else if (!strcmp(result_value, "Failure")) {
                                 ret = RESULT_FAILURE;
                         } else {
-                                log_debug_msg("%s: ERROR: unknown result value '%s'\n", __func__, result_value);
+                                debug_info("ERROR: unknown result value '%s'", result_value);
                         }
                 }
                 if (result_value)
@@ -136,9 +136,9 @@ static ssize_t lockdownd_ssl_write(gnutls_transport_ptr_t transport, char *buffe
         uint32_t bytes = 0;
         lockdownd_client_t client;
         client = (lockdownd_client_t) transport;
-        log_debug_msg("%s: pre-send length = %zi\n", __func__, length);
+        debug_info("pre-send length = %zi", length);
         iphone_device_send(property_list_service_get_connection(client->parent), buffer, length, &bytes);
-        log_debug_msg("%s: post-send sent %i bytes\n", __func__, bytes);
+        debug_info("post-send sent %i bytes", bytes);
         return bytes;
 }
 
@@ -160,17 +160,17 @@ static ssize_t lockdownd_ssl_read(gnutls_transport_ptr_t transport, char *buffer
         client = (lockdownd_client_t) transport;
         char *recv_buffer;
 
-        log_debug_msg("%s: pre-read client wants %zi bytes\n", __func__, length);
+        debug_info("pre-read client wants %zi bytes", length);
 
         recv_buffer = (char *) malloc(sizeof(char) * this_len);
 
         /* repeat until we have the full data or an error occurs */
         do {
                 if ((res = iphone_device_recv(property_list_service_get_connection(client->parent), recv_buffer, this_len, (uint32_t*)&bytes)) != LOCKDOWN_E_SUCCESS) {
-                        log_debug_msg("%s: ERROR: iphone_device_recv returned %d\n", __func__, res);
+                        debug_info("ERROR: iphone_device_recv returned %d", res);
                         return res;
                 }
-                log_debug_msg("%s: post-read we got %i bytes\n", __func__, bytes);
+                debug_info("post-read we got %i bytes", bytes);
 
                 // increase read count
                 tbytes += bytes;
@@ -184,7 +184,7 @@ static ssize_t lockdownd_ssl_read(gnutls_transport_ptr_t transport, char *buffer
                 }
 
                 this_len = length - tbytes;
-                log_debug_msg("%s: re-read trying to read missing %i bytes\n", __func__, this_len);
+                debug_info("re-read trying to read missing %i bytes", this_len);
         } while (tbytes < length);
 
         if (recv_buffer) {
@@ -207,7 +207,7 @@ static lockdownd_error_t lockdownd_ssl_start_session(lockdownd_client_t client)
         uint32_t return_me = 0;
 
         // Set up GnuTLS...
-        log_debug_msg("%s: enabling SSL mode\n", __func__);
+        debug_info("enabling SSL mode");
         errno = 0;
         gnutls_global_init();
         gnutls_certificate_allocate_credentials(&client->ssl_certificate);
@@ -228,26 +228,26 @@ static lockdownd_error_t lockdownd_ssl_start_session(lockdownd_client_t client)
         }
         gnutls_credentials_set(client->ssl_session, GNUTLS_CRD_CERTIFICATE, client->ssl_certificate);   // this part is killing me.
 
-        log_debug_msg("%s: GnuTLS step 1...\n", __func__);
+        debug_info("GnuTLS step 1...");
         gnutls_transport_set_ptr(client->ssl_session, (gnutls_transport_ptr_t) client);
-        log_debug_msg("%s: GnuTLS step 2...\n", __func__);
+        debug_info("GnuTLS step 2...");
         gnutls_transport_set_push_function(client->ssl_session, (gnutls_push_func) & lockdownd_ssl_write);
-        log_debug_msg("%s: GnuTLS step 3...\n", __func__);
+        debug_info("GnuTLS step 3...");
         gnutls_transport_set_pull_function(client->ssl_session, (gnutls_pull_func) & lockdownd_ssl_read);
-        log_debug_msg("%s: GnuTLS step 4 -- now handshaking...\n", __func__);
+        debug_info("GnuTLS step 4 -- now handshaking...");
         if (errno)
-                log_debug_msg("%s: WARN: errno says %s before handshake!\n", __func__, strerror(errno));
+                debug_info("WARN: errno says %s before handshake!", strerror(errno));
         return_me = gnutls_handshake(client->ssl_session);
-        log_debug_msg("%s: GnuTLS handshake done...\n", __func__);
+        debug_info("GnuTLS handshake done...");
 
         if (return_me != GNUTLS_E_SUCCESS) {
-                log_debug_msg("%s: GnuTLS reported something wrong.\n", __func__);
+                debug_info("GnuTLS reported something wrong.");
                 gnutls_perror(return_me);
-                log_debug_msg("%s: oh.. errno says %s\n", __func__, strerror(errno));
+                debug_info("oh.. errno says %s", strerror(errno));
         } else {
                 client->ssl_enabled = 1;
                 ret = LOCKDOWN_E_SUCCESS;
-                log_debug_msg("%s: SSL mode enabled\n", __func__);
+                debug_info("SSL mode enabled");
         }
 
         return ret;
@@ -264,13 +264,13 @@ static lockdownd_error_t lockdownd_ssl_start_session(lockdownd_client_t client)
 static lockdownd_error_t lockdownd_ssl_stop_session(lockdownd_client_t client)
 {
         if (!client) {
-                log_debug_msg("%s: invalid argument!\n", __func__);
+                debug_info("invalid argument!");
                 return LOCKDOWN_E_INVALID_ARG;
         }
         lockdownd_error_t ret = LOCKDOWN_E_SUCCESS;
 
         if (client->ssl_enabled) {
-                log_debug_msg("%s: sending SSL close notify\n", __func__);
+                debug_info("sending SSL close notify");
                 gnutls_bye(client->ssl_session, GNUTLS_SHUT_RDWR);
         }
         if (client->ssl_session) {
@@ -285,7 +285,7 @@ static lockdownd_error_t lockdownd_ssl_stop_session(lockdownd_client_t client)
                 free(client->session_id);
         client->session_id = NULL;
 
-        log_debug_msg("%s: SSL mode disabled\n", __func__);
+        debug_info("SSL mode disabled");
 
         return ret;
 }
@@ -307,7 +307,7 @@ lockdownd_error_t lockdownd_stop_session(lockdownd_client_t client, const char *
                 return LOCKDOWN_E_INVALID_ARG;
 
         if (!session_id) {
-                log_debug_msg("%s: no session_id given, cannot stop session\n", __func__);
+                debug_info("no session_id given, cannot stop session");
                 return LOCKDOWN_E_INVALID_ARG;
         }
 
@@ -318,7 +318,7 @@ lockdownd_error_t lockdownd_stop_session(lockdownd_client_t client, const char *
         plist_dict_insert_item(dict,"Request", plist_new_string("StopSession"));
         plist_dict_insert_item(dict,"SessionID", plist_new_string(session_id));
 
-        log_debug_msg("%s: stopping session %s\n", __func__, session_id);
+        debug_info("stopping session %s", session_id);
 
         ret = lockdownd_send(client, dict);
 
@@ -328,13 +328,13 @@ lockdownd_error_t lockdownd_stop_session(lockdownd_client_t client, const char *
         ret = lockdownd_recv(client, &dict);
 
         if (!dict) {
-                log_debug_msg("%s: LOCKDOWN_E_PLIST_ERROR\n", __func__);
+                debug_info("LOCKDOWN_E_PLIST_ERROR");
                 return LOCKDOWN_E_PLIST_ERROR;
         }
 
         ret = LOCKDOWN_E_UNKNOWN_ERROR;
         if (lockdown_check_result(dict, "StopSession") == RESULT_SUCCESS) {
-                log_debug_msg("%s: success\n", __func__);
+                debug_info("success");
                 ret = LOCKDOWN_E_SUCCESS;
         }
         plist_free(dict);
@@ -480,7 +480,7 @@ lockdownd_error_t lockdownd_query_type(lockdownd_client_t client, char **type)
         plist_dict_add_label(dict, client->label);
         plist_dict_insert_item(dict,"Request", plist_new_string("QueryType"));
 
-        log_debug_msg("%s: called\n", __func__);
+        debug_info("called");
         ret = lockdownd_send(client, dict);
 
         plist_free(dict);
@@ -498,7 +498,7 @@ lockdownd_error_t lockdownd_query_type(lockdownd_client_t client, char **type)
                         plist_t type_node = plist_dict_get_item(dict, "Type");
                         plist_get_string_val(type_node, type);
                 }
-                log_debug_msg("%s: success with type %s\n", __func__, *type);
+                debug_info("success with type %s", *type);
                 ret = LOCKDOWN_E_SUCCESS;
         }
         plist_free(dict);
@@ -550,7 +550,7 @@ lockdownd_error_t lockdownd_get_value(lockdownd_client_t client, const char *dom
                 return ret;
 
         if (lockdown_check_result(dict, "GetValue") == RESULT_SUCCESS) {
-                log_debug_msg("%s: success\n", __func__);
+                debug_info("success");
                 ret = LOCKDOWN_E_SUCCESS;
         }
         if (ret != LOCKDOWN_E_SUCCESS) {
@@ -561,7 +561,7 @@ lockdownd_error_t lockdownd_get_value(lockdownd_client_t client, const char *dom
         plist_t value_node = plist_dict_get_item(dict, "Value");
 
         if (value_node) {
-                log_debug_msg("%s: has a value\n", __func__);
+                debug_info("has a value");
                 *value = plist_copy(value_node);
         }
 
@@ -613,7 +613,7 @@ lockdownd_error_t lockdownd_set_value(lockdownd_client_t client, const char *dom
                 return ret;
 
         if (lockdown_check_result(dict, "SetValue") == RESULT_SUCCESS) {
-                log_debug_msg("%s: success\n", __func__);
+                debug_info("success");
                 ret = LOCKDOWN_E_SUCCESS;
         }
 
@@ -670,7 +670,7 @@ lockdownd_error_t lockdownd_remove_value(lockdownd_client_t client, const char *
                 return ret;
 
         if (lockdown_check_result(dict, "RemoveValue") == RESULT_SUCCESS) {
-                log_debug_msg("%s: success\n", __func__);
+                debug_info("success");
                 ret = LOCKDOWN_E_SUCCESS;
         }
 
@@ -769,7 +769,7 @@ lockdownd_error_t lockdownd_client_new(iphone_device_t device, lockdownd_client_
 
         property_list_service_client_t plistclient = NULL;
         if (property_list_service_client_new(device, 0xf27e, &plistclient) != PROPERTY_LIST_SERVICE_E_SUCCESS) {
-                log_debug_msg("%s: could not connect to lockdownd (device %s)\n", __func__, device->uuid);
+                debug_info("could not connect to lockdownd (device %s)", device->uuid);
                 return LOCKDOWN_E_MUX_ERROR;
         }
 
@@ -818,11 +818,11 @@ lockdownd_error_t lockdownd_client_new_with_handshake(iphone_device_t device, lo
 
         /* perform handshake */
         if (LOCKDOWN_E_SUCCESS != lockdownd_query_type(client_loc, &type)) {
-                log_debug_msg("%s: QueryType failed in the lockdownd client.\n", __func__);
+                debug_info("QueryType failed in the lockdownd client.");
                 ret = LOCKDOWN_E_NOT_ENOUGH_DATA;
         } else {
                 if (strcmp("com.apple.mobile.lockdown", type)) {
-                        log_debug_msg("%s: Warning QueryType request returned \"%s\".\n", __func__, type);
+                        debug_info("Warning QueryType request returned \"%s\".", type);
                 }
                 if (type)
                         free(type);
@@ -830,9 +830,9 @@ lockdownd_error_t lockdownd_client_new_with_handshake(iphone_device_t device, lo
 
         ret = iphone_device_get_uuid(device, &client_loc->uuid);
         if (LOCKDOWN_E_SUCCESS != ret) {
-                log_debug_msg("%s: failed to get device uuid.\n", __func__);
+                debug_info("failed to get device uuid.");
         }
-        log_debug_msg("%s: device uuid: %s\n", __func__, client_loc->uuid);
+        debug_info("device uuid: %s", client_loc->uuid);
 
         userpref_get_host_id(&host_id);
         if (LOCKDOWN_E_SUCCESS == ret && !host_id) {
@@ -849,7 +849,7 @@ lockdownd_error_t lockdownd_client_new_with_handshake(iphone_device_t device, lo
                 ret = lockdownd_start_session(client_loc, host_id, NULL, NULL);
                 if (LOCKDOWN_E_SUCCESS != ret) {
                         ret = LOCKDOWN_E_SSL_ERROR;
-                        log_debug_msg("%s: SSL Session opening failed.\n", __func__);
+                        debug_info("SSL Session opening failed.");
                 }
 
                 if (host_id) {
@@ -892,10 +892,10 @@ static lockdownd_error_t lockdownd_do_pair(lockdownd_client_t client, char *host
 
         ret = lockdownd_get_device_public_key(client, &public_key);
         if (ret != LOCKDOWN_E_SUCCESS) {
-                log_debug_msg("%s: device refused to send public key.\n", __func__);
+                debug_info("device refused to send public key.");
                 return ret;
         }
-        log_debug_msg("%s: device public key follows:\n%s\n", __func__, public_key.data);
+        debug_info("device public key follows:\n%s", public_key.data);
 
         ret = lockdownd_gen_pair_cert(public_key, &device_cert, &host_cert, &root_cert);
         if (ret != LOCKDOWN_E_SUCCESS) {
@@ -944,7 +944,7 @@ static lockdownd_error_t lockdownd_do_pair(lockdownd_client_t client, char *host
 
         /* if pairing succeeded */
         if (ret == LOCKDOWN_E_SUCCESS) {
-                log_debug_msg("%s: %s success\n", __func__, verb);
+                debug_info("%s success", verb);
                 if (!strcmp("Unpair", verb)) {
                         /* remove public key from config */
                         userpref_remove_device_public_key(client->uuid);
@@ -953,7 +953,7 @@ static lockdownd_error_t lockdownd_do_pair(lockdownd_client_t client, char *host
                         userpref_set_device_public_key(client->uuid, public_key);
                 }
         } else {
-                log_debug_msg("%s: %s failure\n", __func__, verb);
+                debug_info("%s failure", verb);
                 plist_t error_node = NULL;
                 /* verify error condition */
                 error_node = plist_dict_get_item(dict, "Error");
@@ -1041,7 +1041,7 @@ lockdownd_error_t lockdownd_enter_recovery(lockdownd_client_t client)
         plist_dict_add_label(dict, client->label);
         plist_dict_insert_item(dict,"Request", plist_new_string("EnterRecovery"));
 
-        log_debug_msg("%s: telling device to enter recovery mode\n", __func__);
+        debug_info("telling device to enter recovery mode");
 
         ret = lockdownd_send(client, dict);
         plist_free(dict);
@@ -1050,7 +1050,7 @@ lockdownd_error_t lockdownd_enter_recovery(lockdownd_client_t client)
         ret = lockdownd_recv(client, &dict);
 
         if (lockdown_check_result(dict, "EnterRecovery") == RESULT_SUCCESS) {
-                log_debug_msg("%s: success\n", __func__);
+                debug_info("success");
                 ret = LOCKDOWN_E_SUCCESS;
         }
         plist_free(dict);
@@ -1077,7 +1077,7 @@ lockdownd_error_t lockdownd_goodbye(lockdownd_client_t client)
         plist_dict_add_label(dict, client->label);
         plist_dict_insert_item(dict,"Request", plist_new_string("Goodbye"));
 
-        log_debug_msg("%s: called\n", __func__);
+        debug_info("called");
 
         ret = lockdownd_send(client, dict);
         plist_free(dict);
@@ -1085,12 +1085,12 @@ lockdownd_error_t lockdownd_goodbye(lockdownd_client_t client)
 
         ret = lockdownd_recv(client, &dict);
         if (!dict) {
-                log_debug_msg("%s: did not get goodbye response back\n", __func__);
+                debug_info("did not get goodbye response back");
                 return LOCKDOWN_E_PLIST_ERROR;
         }
 
         if (lockdown_check_result(dict, "Goodbye") == RESULT_SUCCESS) {
-                log_debug_msg("%s: success\n", __func__);
+                debug_info("success");
                 ret = LOCKDOWN_E_SUCCESS;
         }
         plist_free(dict);
@@ -1294,7 +1294,7 @@ lockdownd_error_t lockdownd_start_session(lockdownd_client_t client, const char
                 if (enable_ssl && (plist_get_node_type(enable_ssl) == PLIST_BOOLEAN)) {
                         plist_get_bool_val(enable_ssl, &use_ssl);
                 }
-                log_debug_msg("%s: Session startup OK\n", __func__);
+                debug_info("Session startup OK");
 
                 if (ssl_enabled != NULL)
                         *ssl_enabled = use_ssl;
@@ -1305,13 +1305,13 @@ lockdownd_error_t lockdownd_start_session(lockdownd_client_t client, const char
                         plist_get_string_val(session_node, &client->session_id);
                 }
                 if (client->session_id) {
-                        log_debug_msg("%s: SessionID: %s\n", __func__, client->session_id);
+                        debug_info("SessionID: %s", client->session_id);
                         if (session_id != NULL)
                                 *session_id = strdup(client->session_id);
                 } else {
-                        log_debug_msg("%s: Failed to get SessionID!\n", __func__);
+                        debug_info("Failed to get SessionID!");
                 }
-                log_debug_msg("%s: Enable SSL Session: %s\n", __func__, (use_ssl?"true":"false"));
+                debug_info("Enable SSL Session: %s", (use_ssl?"true":"false"));
                 if (use_ssl) {
                         ret = lockdownd_ssl_start_session(client);
                 } else {
@@ -1434,13 +1434,13 @@ lockdownd_error_t lockdownd_activate(lockdownd_client_t client, plist_t activati
 
         ret = lockdownd_recv(client, &dict);
         if (!dict) {
-                log_debug_msg("%s: LOCKDOWN_E_PLIST_ERROR\n", __func__);
+                debug_info("LOCKDOWN_E_PLIST_ERROR");
                 return LOCKDOWN_E_PLIST_ERROR;
         }
 
         ret = LOCKDOWN_E_ACTIVATION_FAILED;
         if (lockdown_check_result(dict, "Activate") == RESULT_SUCCESS) {
-                log_debug_msg("%s: success\n", __func__);
+                debug_info("success");
                 ret = LOCKDOWN_E_SUCCESS;
         }
         plist_free(dict);
@@ -1477,13 +1477,13 @@ lockdownd_error_t lockdownd_deactivate(lockdownd_client_t client)
 
         ret = lockdownd_recv(client, &dict);
         if (!dict) {
-                log_debug_msg("%s: LOCKDOWN_E_PLIST_ERROR\n", __func__);
+                debug_info("LOCKDOWN_E_PLIST_ERROR");
                 return LOCKDOWN_E_PLIST_ERROR;
         }
 
         ret = LOCKDOWN_E_UNKNOWN_ERROR;
         if (lockdown_check_result(dict, "Deactivate") == RESULT_SUCCESS) {
-                log_debug_msg("%s: success\n", __func__);
+                debug_info("success");
                 ret = LOCKDOWN_E_SUCCESS;
         }
         plist_free(dict);