From 342f4e929888c0aaa088e39fb98a74957bf45fa7 Mon Sep 17 00:00:00 2001 From: Martin Szulecki Date: Tue, 12 Jan 2010 19:09:36 +0100 Subject: 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. --- src/AFC.c | 109 +++++++++++++++++++++----------------------- src/InstallationProxy.c | 40 ++++++++-------- src/MobileSync.c | 6 +-- src/NotificationProxy.c | 24 +++++----- src/SBServices.c | 12 ++--- src/debug.c | 70 ++++++++++++++++++++-------- src/debug.h | 20 ++++++-- src/device_link_service.c | 16 +++---- src/iphone.c | 26 +++++------ src/lockdown.c | 106 +++++++++++++++++++++--------------------- src/property_list_service.c | 20 ++++---- src/userpref.c | 4 +- 12 files changed, 247 insertions(+), 206 deletions(-) diff --git a/src/AFC.c b/src/AFC.c index fe8e1af..d430e08 100644 --- a/src/AFC.c +++ b/src/AFC.c @@ -36,7 +36,7 @@ static const int MAXIMUM_PACKET_SIZE = (2 << 15); */ static void afc_lock(afc_client_t client) { - log_debug_msg("%s: Locked\n", __func__); + debug_info("Locked"); g_mutex_lock(client->mutex); } @@ -46,7 +46,7 @@ static void afc_lock(afc_client_t client) */ static void afc_unlock(afc_client_t client) { - log_debug_msg("%s: Unlocked\n", __func__); + debug_info("Unlocked"); g_mutex_unlock(client->mutex); } @@ -155,12 +155,11 @@ static afc_error_t afc_dispatch_packet(afc_client_t client, const char *data, ui if (client->afc_packet->this_length != client->afc_packet->entire_length) { offset = client->afc_packet->this_length - sizeof(AFCPacket); - log_debug_msg("%s: Offset: %i\n", __func__, offset); + debug_info("Offset: %i", offset); if ((length) < (client->afc_packet->entire_length - client->afc_packet->this_length)) { - log_debug_msg("%s: Length did not resemble what it was supposed", __func__); - log_debug_msg("to based on the packet.\n"); - log_debug_msg("%s: length minus offset: %i\n", __func__, length - offset); - log_debug_msg("%s: rest of packet: %i\n", __func__, client->afc_packet->entire_length - client->afc_packet->this_length); + debug_info("Length did not resemble what it was supposed to based on packet"); + debug_info("length minus offset: %i", length - offset); + debug_info("rest of packet: %i\n", client->afc_packet->entire_length - client->afc_packet->this_length); return AFC_E_INTERNAL_ERROR; } @@ -182,10 +181,10 @@ static afc_error_t afc_dispatch_packet(afc_client_t client, const char *data, ui } *bytes_sent += sent; - log_debug_msg("%s: sent the first now go with the second\n", __func__); - log_debug_msg("%s: Length: %i\n", __func__, length - offset); - log_debug_msg("%s: Buffer: \n", __func__); - log_debug_buffer(data + offset, length - offset); + debug_info("sent the first now go with the second"); + debug_info("Length: %i", length - offset); + debug_info("Buffer: "); + debug_buffer(data + offset, length - offset); sent = 0; iphone_device_send(client->connection, data + offset, length - offset, &sent); @@ -193,11 +192,10 @@ static afc_error_t afc_dispatch_packet(afc_client_t client, const char *data, ui *bytes_sent = sent; return AFC_E_SUCCESS; } else { - log_debug_msg("%s: doin things the old way\n", __func__); - log_debug_msg("%s: packet length = %i\n", __func__, client->afc_packet->this_length); + debug_info("doin things the old way"); + debug_info("packet length = %i", client->afc_packet->this_length); - log_debug_buffer((char*)client->afc_packet, sizeof(AFCPacket)); - log_debug_msg("\n"); + debug_buffer((char*)client->afc_packet, sizeof(AFCPacket)); /* send AFC packet header */ AFCPacket_to_LE(client->afc_packet); @@ -209,10 +207,9 @@ static afc_error_t afc_dispatch_packet(afc_client_t client, const char *data, ui *bytes_sent += sent; /* send AFC packet data (if there's data to send) */ if (length > 0) { - log_debug_msg("%s: packet data follows\n", __func__); + debug_info("packet data follows"); - log_debug_buffer(data, length); - log_debug_msg("\n"); + debug_buffer(data, length); iphone_device_send(client->connection, data, length, &sent); *bytes_sent += sent; } @@ -244,36 +241,36 @@ static afc_error_t afc_receive_data(afc_client_t client, char **dump_here, uint3 iphone_device_recv(client->connection, (char*)&header, sizeof(AFCPacket), bytes_recv); AFCPacket_from_LE(&header); if (*bytes_recv == 0) { - log_debug_msg("%s: Just didn't get enough.\n", __func__); + debug_info("Just didn't get enough."); *dump_here = NULL; return AFC_E_MUX_ERROR; } else if (*bytes_recv < sizeof(AFCPacket)) { - log_debug_msg("%s: Did not even get the AFCPacket header\n", __func__); + debug_info("Did not even get the AFCPacket header"); *dump_here = NULL; return AFC_E_MUX_ERROR; } /* check if it's a valid AFC header */ if (strncmp(header.magic, AFC_MAGIC, AFC_MAGIC_LEN)) { - log_debug_msg("%s: Invalid AFC packet received (magic != " AFC_MAGIC ")!\n", __func__); + debug_info("Invalid AFC packet received (magic != " AFC_MAGIC ")!"); } /* check if it has the correct packet number */ if (header.packet_num != client->afc_packet->packet_num) { /* otherwise print a warning but do not abort */ - log_debug_msg("%s: ERROR: Unexpected packet number (%lld != %lld) aborting.\n", __func__, header.packet_num, client->afc_packet->packet_num); + debug_info("ERROR: Unexpected packet number (%lld != %lld) aborting.", header.packet_num, client->afc_packet->packet_num); *dump_here = NULL; return AFC_E_OP_HEADER_INVALID; } /* then, read the attached packet */ if (header.this_length < sizeof(AFCPacket)) { - log_debug_msg("%s: Invalid AFCPacket header received!\n", __func__); + debug_info("Invalid AFCPacket header received!"); *dump_here = NULL; return AFC_E_OP_HEADER_INVALID; } else if ((header.this_length == header.entire_length) && header.entire_length == sizeof(AFCPacket)) { - log_debug_msg("%s: Empty AFCPacket received!\n", __func__); + debug_info("Empty AFCPacket received!"); *dump_here = NULL; *bytes_recv = 0; if (header.operation == AFC_OP_DATA) { @@ -283,14 +280,14 @@ static afc_error_t afc_receive_data(afc_client_t client, char **dump_here, uint3 } } - log_debug_msg("%s: received AFC packet, full len=%lld, this len=%lld, operation=0x%llx\n", __func__, header.entire_length, header.this_length, header.operation); + debug_info("received AFC packet, full len=%lld, this len=%lld, operation=0x%llx", header.entire_length, header.this_length, header.operation); entire_len = (uint32_t)header.entire_length - sizeof(AFCPacket); this_len = (uint32_t)header.this_length - sizeof(AFCPacket); /* this is here as a check (perhaps a different upper limit is good?) */ if (entire_len > (uint32_t)MAXIMUM_PACKET_SIZE) { - fprintf(stderr, "%s: entire_len is larger than MAXIMUM_PACKET_SIZE, (%d > %d)!\n", __func__, entire_len, MAXIMUM_PACKET_SIZE); + fprintf(stderr, "%s: entire_len is larger than MAXIMUM_PACKET_SIZE, (%d > %d)!", __func__, entire_len, MAXIMUM_PACKET_SIZE); } *dump_here = (char*)malloc(entire_len); @@ -299,12 +296,12 @@ static afc_error_t afc_receive_data(afc_client_t client, char **dump_here, uint3 if (*bytes_recv <= 0) { free(*dump_here); *dump_here = NULL; - log_debug_msg("%s: Did not get packet contents!\n", __func__); + debug_info("Did not get packet contents!"); return AFC_E_NOT_ENOUGH_DATA; } else if (*bytes_recv < this_len) { free(*dump_here); *dump_here = NULL; - log_debug_msg("%s: Could not receive this_len=%d bytes\n", __func__, this_len); + debug_info("Could not receive this_len=%d bytes", this_len); return AFC_E_NOT_ENOUGH_DATA; } } @@ -315,13 +312,13 @@ static afc_error_t afc_receive_data(afc_client_t client, char **dump_here, uint3 while (current_count < entire_len) { iphone_device_recv(client->connection, (*dump_here)+current_count, entire_len - current_count, bytes_recv); if (*bytes_recv <= 0) { - log_debug_msg("%s: Error receiving data (recv returned %d)\n", __func__, *bytes_recv); + debug_info("Error receiving data (recv returned %d)", *bytes_recv); break; } current_count += *bytes_recv; } if (current_count < entire_len) { - log_debug_msg("%s: WARNING: could not receive full packet (read %s, size %d)\n", __func__, current_count, entire_len); + debug_info("WARNING: could not receive full packet (read %s, size %d)", current_count, entire_len); } } @@ -329,14 +326,14 @@ static afc_error_t afc_receive_data(afc_client_t client, char **dump_here, uint3 param1 = *(uint64_t*)(*dump_here); } - log_debug_msg("%s: packet data size = %i\n", __func__, current_count); - log_debug_msg("%s: packet data follows\n", __func__); - log_debug_buffer(*dump_here, current_count); + debug_info("packet data size = %i", current_count); + debug_info("packet data follows"); + debug_buffer(*dump_here, current_count); /* check operation types */ if (header.operation == AFC_OP_STATUS) { /* status response */ - log_debug_msg("%s: got a status response, code=%lld\n", __func__, param1); + debug_info("got a status response, code=%lld", param1); if (param1 != AFC_E_SUCCESS) { /* error status */ @@ -347,21 +344,21 @@ static afc_error_t afc_receive_data(afc_client_t client, char **dump_here, uint3 } } else if (header.operation == AFC_OP_DATA) { /* data response */ - log_debug_msg("%s: got a data response\n", __func__); + debug_info("got a data response"); } else if (header.operation == AFC_OP_FILE_OPEN_RES) { /* file handle response */ - log_debug_msg("%s: got a file handle response, handle=%lld\n", __func__, param1); + debug_info("got a file handle response, handle=%lld", param1); } else if (header.operation == AFC_OP_FILE_TELL_RES) { /* tell response */ - log_debug_msg("%s: got a tell response, position=%lld\n", __func__, param1); + debug_info("got a tell response, position=%lld", param1); } else { /* unknown operation code received */ free(*dump_here); *dump_here = NULL; *bytes_recv = 0; - log_debug_msg("%s: WARNING: Unknown operation code received 0x%llx param1=%lld\n", __func__, header.operation, param1); - fprintf(stderr, "%s: WARNING: Unknown operation code received 0x%llx param1=%lld\n", __func__, (long long)header.operation, (long long)param1); + debug_info("WARNING: Unknown operation code received 0x%llx param1=%lld", header.operation, param1); + fprintf(stderr, "%s: WARNING: Unknown operation code received 0x%llx param1=%lld", __func__, (long long)header.operation, (long long)param1); return AFC_E_OP_NOT_SUPPORTED; } @@ -728,7 +725,7 @@ afc_file_open(afc_client_t client, const char *filename, free(data); if (ret != AFC_E_SUCCESS) { - log_debug_msg("%s: Didn't receive a response to the command\n", __func__); + debug_info("Didn't receive a response to the command"); afc_unlock(client); return AFC_E_NOT_ENOUGH_DATA; } @@ -743,7 +740,7 @@ afc_file_open(afc_client_t client, const char *filename, return ret; } - log_debug_msg("%s: Didn't get any further data\n", __func__); + debug_info("Didn't get any further data"); afc_unlock(client); @@ -770,14 +767,14 @@ afc_file_read(afc_client_t client, uint64_t handle, char *data, uint32_t length, if (!client || !client->afc_packet || !client->connection || handle == 0) return AFC_E_INVALID_ARGUMENT; - log_debug_msg("%s: called for length %i\n", __func__, length); + debug_info("called for length %i", length); afc_lock(client); // Looping here to get around the maximum amount of data that // afc_receive_data can handle while (current_count < length) { - log_debug_msg("%s: current count is %i but length is %i\n", __func__, current_count, length); + debug_info("current count is %i but length is %i", current_count, length); // Send the read command AFCFilePacket *packet = (AFCFilePacket *) malloc(sizeof(AFCFilePacket)); @@ -794,8 +791,8 @@ afc_file_read(afc_client_t client, uint64_t handle, char *data, uint32_t length, } // Receive the data ret = afc_receive_data(client, &input, &bytes_loc); - log_debug_msg("%s: afc_receive_data returned error: %d\n", __func__, ret); - log_debug_msg("%s: bytes returned: %i\n", __func__, bytes_loc); + debug_info("afc_receive_data returned error: %d", ret); + debug_info("bytes returned: %i", bytes_loc); if (ret != AFC_E_SUCCESS) { afc_unlock(client); return ret; @@ -808,7 +805,7 @@ afc_file_read(afc_client_t client, uint64_t handle, char *data, uint32_t length, return ret; } else { if (input) { - log_debug_msg("%s: %d\n", __func__, bytes_loc); + debug_info("%d", bytes_loc); memcpy(data + current_count, input, (bytes_loc > length) ? length : bytes_loc); free(input); input = NULL; @@ -816,7 +813,7 @@ afc_file_read(afc_client_t client, uint64_t handle, char *data, uint32_t length, } } } - log_debug_msg("%s: returning current_count as %i\n", __func__, current_count); + debug_info("returning current_count as %i", current_count); afc_unlock(client); *bytes_read = current_count; @@ -849,7 +846,7 @@ afc_file_write(afc_client_t client, uint64_t handle, const char *data, uint32_t afc_lock(client); - log_debug_msg("%s: Write length: %i\n", __func__, length); + debug_info("Write length: %i", length); // Divide the file into segments. for (i = 0; i < segments; i++) { @@ -909,7 +906,7 @@ afc_file_write(afc_client_t client, uint64_t handle, const char *data, uint32_t ret = afc_receive_data(client, &acknowledgement, &bytes_loc); afc_unlock(client); if (ret != AFC_E_SUCCESS) { - log_debug_msg("%s: uh oh?\n", __func__); + debug_info("uh oh?"); } else { free(acknowledgement); } @@ -933,7 +930,7 @@ afc_error_t afc_file_close(afc_client_t client, uint64_t handle) afc_lock(client); - log_debug_msg("%s: File handle %i\n", __func__, handle); + debug_info("File handle %i", handle); // Send command memcpy(buffer, &handle, sizeof(uint64_t)); @@ -981,7 +978,7 @@ afc_error_t afc_file_lock(afc_client_t client, uint64_t handle, afc_lock_op_t op afc_lock(client); - log_debug_msg("%s: file handle %i\n", __func__, handle); + debug_info("file handle %i", handle); // Send command memcpy(buffer, &handle, sizeof(uint64_t)); @@ -995,13 +992,13 @@ afc_error_t afc_file_lock(afc_client_t client, uint64_t handle, afc_lock_op_t op if (ret != AFC_E_SUCCESS) { afc_unlock(client); - log_debug_msg("%s: could not send lock command\n", __func__); + debug_info("could not send lock command"); return AFC_E_UNKNOWN_ERROR; } // Receive the response ret = afc_receive_data(client, &buffer, &bytes); if (buffer) { - log_debug_buffer(buffer, bytes); + debug_buffer(buffer, bytes); free(buffer); } afc_unlock(client); @@ -1214,9 +1211,9 @@ afc_error_t afc_make_link(afc_client_t client, afc_link_type_t linktype, const c afc_lock(client); - log_debug_msg("%s: link type: %lld\n", __func__, type); - log_debug_msg("%s: target: %s, length:%d\n", __func__, target, strlen(target)); - log_debug_msg("%s: linkname: %s, length:%d\n", __func__, linkname, strlen(linkname)); + debug_info("link type: %lld", type); + debug_info("target: %s, length:%d", target, strlen(target)); + debug_info("linkname: %s, length:%d", linkname, strlen(linkname)); // Send command memcpy(send, &type, 8); diff --git a/src/InstallationProxy.c b/src/InstallationProxy.c index 6b267c4..8b53a2d 100644 --- a/src/InstallationProxy.c +++ b/src/InstallationProxy.c @@ -41,7 +41,7 @@ struct instproxy_status_data { */ static void instproxy_lock(instproxy_client_t client) { - log_debug_msg("InstallationProxy: Locked\n"); + debug_info("InstallationProxy: Locked"); g_mutex_lock(client->mutex); } @@ -51,7 +51,7 @@ static void instproxy_lock(instproxy_client_t client) */ static void instproxy_unlock(instproxy_client_t client) { - log_debug_msg("InstallationProxy: Unlocked\n"); + debug_info("InstallationProxy: Unlocked"); g_mutex_unlock(client->mutex); } @@ -131,7 +131,7 @@ instproxy_error_t instproxy_client_free(instproxy_client_t client) property_list_service_client_free(client->parent); client->parent = NULL; if (client->status_updater) { - log_debug_msg("joining status_updater"); + debug_info("joining status_updater"); g_thread_join(client->status_updater); } if (client->mutex) { @@ -174,7 +174,7 @@ instproxy_error_t instproxy_browse(instproxy_client_t client, instproxy_apptype_ p_apptype = plist_new_string("User"); break; default: - log_debug_msg("%s: unknown apptype %d given, using INSTPROXY_APPTYPE_USER instead\n", __func__, apptype); + debug_info("unknown apptype %d given, using INSTPROXY_APPTYPE_USER instead", apptype); p_apptype = plist_new_string("User"); break; } @@ -187,7 +187,7 @@ instproxy_error_t instproxy_browse(instproxy_client_t client, instproxy_apptype_ res = instproxy_error(property_list_service_send_xml_plist(client->parent, dict)); plist_free(dict); if (res != INSTPROXY_E_SUCCESS) { - log_debug_msg("%s: could not send plist\n", __func__); + debug_info("could not send plist"); goto leave_unlock; } @@ -223,7 +223,7 @@ instproxy_error_t instproxy_browse(instproxy_client_t client, instproxy_apptype_ if (!strcmp(status, "BrowsingApplications")) { browsing = 1; } else if (!strcmp(status, "Complete")) { - log_debug_msg("%s: Browsing applications completed\n"); + debug_info("Browsing applications completed"); res = INSTPROXY_E_SUCCESS; } free(status); @@ -264,7 +264,7 @@ static instproxy_error_t instproxy_perform_operation(instproxy_client_t client, res = instproxy_error(property_list_service_receive_plist_with_timeout(client->parent, &dict, 30000)); instproxy_unlock(client); if (res != INSTPROXY_E_SUCCESS) { - log_debug_msg("%s: could not receive plist, error %d\n", __func__, res); + debug_info("could not receive plist, error %d", res); break; } if (dict) { @@ -279,7 +279,7 @@ static instproxy_error_t instproxy_perform_operation(instproxy_client_t client, char *err_msg = NULL; plist_get_string_val(err, &err_msg); if (err_msg) { - log_debug_msg("%s(%s): ERROR: %s\n", __func__, operation, err_msg); + debug_info("(%s): ERROR: %s", operation, err_msg); free(err_msg); } #endif @@ -303,9 +303,9 @@ static instproxy_error_t instproxy_perform_operation(instproxy_client_t client, int percent; plist_get_uint_val(npercent, &val); percent = val; - log_debug_msg("%s(%s): %s (%d%%)\n", __func__, operation, status_msg, percent); + debug_info("(%s): %s (%d%%)", operation, status_msg, percent); } else { - log_debug_msg("%s(%s): %s\n", __func__, operation, status_msg); + debug_info("(%s): %s", operation, status_msg); } #endif free(status_msg); @@ -338,7 +338,7 @@ static gpointer instproxy_status_updater(gpointer arg) /* cleanup */ instproxy_lock(data->client); - log_debug_msg("%s: done, cleaning up.\n", __func__); + debug_info("done, cleaning up."); if (data->operation) { free(data->operation); } @@ -408,11 +408,11 @@ static instproxy_error_t instproxy_install_or_upgrade(instproxy_client_t client, return INSTPROXY_E_INVALID_ARG; } if (sinf && (plist_get_node_type(sinf) != PLIST_DATA)) { - log_debug_msg("%s(%s): ERROR: sinf data is not a PLIST_DATA node!\n", __func__, command); + debug_info("(%s): ERROR: sinf data is not a PLIST_DATA node!", command); return INSTPROXY_E_INVALID_ARG; } if (metadata && (plist_get_node_type(metadata) != PLIST_DATA)) { - log_debug_msg("%s(%s): ERROR: metadata is not a PLIST_DATA node!\n", __func__, command); + debug_info("(%s): ERROR: metadata is not a PLIST_DATA node!", command); return INSTPROXY_E_INVALID_ARG; } @@ -439,7 +439,7 @@ static instproxy_error_t instproxy_install_or_upgrade(instproxy_client_t client, plist_free(dict); if (res != INSTPROXY_E_SUCCESS) { - log_debug_msg("%s: could not send plist, error %d\n", __func__, res); + debug_info("could not send plist, error %d", res); return res; } @@ -532,7 +532,7 @@ instproxy_error_t instproxy_uninstall(instproxy_client_t client, const char *app plist_free(dict); if (res != INSTPROXY_E_SUCCESS) { - log_debug_msg("%s: could not send plist, error %d\n", __func__, res); + debug_info("could not send plist, error %d", res); return res; } @@ -567,13 +567,13 @@ instproxy_error_t instproxy_lookup_archives(instproxy_client_t client, plist_t * plist_free(dict); if (res != INSTPROXY_E_SUCCESS) { - log_debug_msg("%s: could not send plist, error %d\n", __func__, res); + debug_info("could not send plist, error %d", res); goto leave_unlock; } res = instproxy_error(property_list_service_receive_plist(client->parent, result)); if (res != INSTPROXY_E_SUCCESS) { - log_debug_msg("%s: could not receive plist, error %d\n", __func__, res); + debug_info("could not receive plist, error %d", res); goto leave_unlock; } @@ -640,7 +640,7 @@ instproxy_error_t instproxy_archive(instproxy_client_t client, const char *appid plist_free(dict); if (res != INSTPROXY_E_SUCCESS) { - log_debug_msg("%s: could not send plist, error %d\n", __func__, res); + debug_info("could not send plist, error %d", res); return res; } return instproxy_create_status_updater(client, status_cb, "Archive"); @@ -686,7 +686,7 @@ instproxy_error_t instproxy_restore(instproxy_client_t client, const char *appid plist_free(dict); if (res != INSTPROXY_E_SUCCESS) { - log_debug_msg("%s: could not send plist, error %d\n", __func__, res); + debug_info("could not send plist, error %d", res); return res; } return instproxy_create_status_updater(client, status_cb, "Restore"); @@ -732,7 +732,7 @@ instproxy_error_t instproxy_remove_archive(instproxy_client_t client, const char plist_free(dict); if (res != INSTPROXY_E_SUCCESS) { - log_debug_msg("%s: could not send plist, error %d\n", __func__, res); + debug_info("could not send plist, error %d", res); return res; } return instproxy_create_status_updater(client, status_cb, "RemoveArchive"); diff --git a/src/MobileSync.c b/src/MobileSync.c index ef3571a..97a1320 100644 --- a/src/MobileSync.c +++ b/src/MobileSync.c @@ -77,7 +77,7 @@ mobilesync_error_t mobilesync_client_new(iphone_device_t device, int dst_port, /* perform handshake */ ret = mobilesync_error(device_link_service_version_exchange(dlclient, MSYNC_VERSION_INT1, MSYNC_VERSION_INT2)); if (ret != MOBILESYNC_E_SUCCESS) { - log_debug_msg("%s: version exchange failed, error %d\n", __func__, ret); + debug_info("version exchange failed, error %d", ret); mobilesync_client_free(client_loc); return ret; } @@ -116,7 +116,7 @@ mobilesync_error_t mobilesync_recv(mobilesync_client_t client, plist_t * plist) char *XMLContent = NULL; uint32_t length = 0; plist_to_xml(*plist, &XMLContent, &length); - log_debug_msg("%s: plist size: %i\nbuffer :\n%s\n", __func__, length, XMLContent); + debug_info("plist size: %i\nbuffer :\n%s", length, XMLContent); free(XMLContent); #endif return ret; @@ -141,7 +141,7 @@ mobilesync_error_t mobilesync_send(mobilesync_client_t client, plist_t plist) char *XMLContent = NULL; uint32_t length = 0; plist_to_xml(plist, &XMLContent, &length); - log_debug_msg("%s: plist size: %i\nbuffer :\n%s\n", __func__, length, XMLContent); + debug_info("plist size: %i\nbuffer :\n%s", length, XMLContent); free(XMLContent); #endif return mobilesync_error(device_link_service_send(client->parent, plist)); diff --git a/src/NotificationProxy.c b/src/NotificationProxy.c index 1b13a29..f526f70 100644 --- a/src/NotificationProxy.c +++ b/src/NotificationProxy.c @@ -41,7 +41,7 @@ struct np_thread { */ static void np_lock(np_client_t client) { - log_debug_msg("NP: Locked\n"); + debug_info("NP: Locked"); g_mutex_lock(client->mutex); } @@ -51,7 +51,7 @@ static void np_lock(np_client_t client) */ static void np_unlock(np_client_t client) { - log_debug_msg("NP: Unlocked\n"); + debug_info("NP: Unlocked"); g_mutex_unlock(client->mutex); } @@ -131,7 +131,7 @@ np_error_t np_client_free(np_client_t client) property_list_service_client_free(client->parent); client->parent = NULL; if (client->notifier) { - log_debug_msg("joining np callback\n"); + debug_info("joining np callback"); g_thread_join(client->notifier); } if (client->mutex) { @@ -170,7 +170,7 @@ np_error_t np_post_notification(np_client_t client, const char *notification) plist_free(dict); if (res != NP_E_SUCCESS) { - log_debug_msg("%s: Error sending XML plist to device!\n", __func__); + debug_info("Error sending XML plist to device!"); } np_unlock(client); @@ -198,7 +198,7 @@ np_error_t np_observe_notification( np_client_t client, const char *notification np_error_t res = np_error(property_list_service_send_xml_plist(client->parent, dict)); if (res != NP_E_SUCCESS) { - log_debug_msg("%s: Error sending XML plist to device!\n", __func__); + debug_info("Error sending XML plist to device!"); } plist_free(dict); @@ -266,7 +266,7 @@ static int np_get_notification(np_client_t client, char **notification) property_list_service_receive_plist_with_timeout(client->parent, &dict, 500); if (!dict) { - log_debug_msg("NotificationProxy: no notification received!\n"); + debug_info("NotificationProxy: no notification received!"); res = 0; } else { char *cmd_value = NULL; @@ -287,14 +287,14 @@ static int np_get_notification(np_client_t client, char **notification) res = -2; if (name_value_node && name_value) { *notification = name_value; - log_debug_msg("%s: got notification %s\n", __func__, name_value); + debug_info("got notification %s\n", __func__, name_value); res = 0; } } else if (cmd_value && !strcmp(cmd_value, "ProxyDeath")) { - log_debug_msg("%s: ERROR: NotificationProxy died!\n", __func__); + debug_info("ERROR: NotificationProxy died!"); res = -1; } else if (cmd_value) { - log_debug_msg("%d: unknown NotificationProxy command '%s' received!\n", __func__); + debug_info("unknown NotificationProxy command '%s' received!", cmd_value); res = -1; } else { res = -2; @@ -321,7 +321,7 @@ gpointer np_notifier( gpointer arg ) if (!npt) return NULL; - log_debug_msg("%s: starting callback.\n", __func__); + debug_info("starting callback."); while (npt->client->parent) { np_get_notification(npt->client, ¬ification); if (notification) { @@ -364,7 +364,7 @@ np_error_t np_set_notify_callback( np_client_t client, np_notify_cb_t notify_cb np_lock(client); if (client->notifier) { - log_debug_msg("%s: callback already set, removing\n"); + debug_info("callback already set, removing\n"); property_list_service_client_t parent = client->parent; client->parent = NULL; g_thread_join(client->notifier); @@ -384,7 +384,7 @@ np_error_t np_set_notify_callback( np_client_t client, np_notify_cb_t notify_cb } } } else { - log_debug_msg("%s: no callback set\n", __func__); + debug_info("no callback set"); } np_unlock(client); diff --git a/src/SBServices.c b/src/SBServices.c index 2b65785..9589ec2 100644 --- a/src/SBServices.c +++ b/src/SBServices.c @@ -35,7 +35,7 @@ */ static void sbs_lock(sbservices_client_t client) { - log_debug_msg("SBServices: Locked\n"); + debug_info("SBServices: Locked"); g_mutex_lock(client->mutex); } @@ -45,7 +45,7 @@ static void sbs_lock(sbservices_client_t client) */ static void sbs_unlock(sbservices_client_t client) { - log_debug_msg("SBServices: Unlocked\n"); + debug_info("SBServices: Unlocked"); g_mutex_unlock(client->mutex); } @@ -99,7 +99,7 @@ sbservices_error_t sbservices_get_icon_state(sbservices_client_t client, plist_t sbs_lock(client); if (property_list_service_send_binary_plist(client->parent, dict) != PROPERTY_LIST_SERVICE_E_SUCCESS) { - log_debug_msg("%s: could not send plist\n", __func__); + debug_info("could not send plist"); goto leave_unlock; } plist_free(dict); @@ -108,7 +108,7 @@ sbservices_error_t sbservices_get_icon_state(sbservices_client_t client, plist_t if (property_list_service_receive_plist(client->parent, state) == PROPERTY_LIST_SERVICE_E_SUCCESS) { res = SBSERVICES_E_SUCCESS; } else { - log_debug_msg("%s: could not get icon state!\n", __func__); + debug_info("could not get icon state!"); if (*state) { plist_free(*state); *state = NULL; @@ -137,7 +137,7 @@ sbservices_error_t sbservices_set_icon_state(sbservices_client_t client, plist_t sbs_lock(client); if (property_list_service_send_binary_plist(client->parent, dict) != IPHONE_E_SUCCESS) { - log_debug_msg("%s: could not send plist\n", __func__); + debug_info("could not send plist"); goto leave_unlock; } // NO RESPONSE @@ -164,7 +164,7 @@ sbservices_error_t sbservices_get_icon_pngdata(sbservices_client_t client, const sbs_lock(client); if (property_list_service_send_binary_plist(client->parent, dict) != PROPERTY_LIST_SERVICE_E_SUCCESS) { - log_debug_msg("%s: could not send plist\n", __func__); + debug_info("could not send plist"); goto leave_unlock; } plist_free(dict); diff --git a/src/debug.c b/src/debug.c index 78f3a17..1f9aff1 100644 --- a/src/debug.c +++ b/src/debug.c @@ -1,6 +1,6 @@ /* * debug.c - * contains utilitary methos for logging and debugging + * contains utilitary functions for debugging * * Copyright (c) 2008 Jonathan Beck All Rights Reserved. * @@ -18,14 +18,18 @@ * License along with this library; if not, write to the Free Software * Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA */ + #include +#define _GNU_SOURCE 1 +#define __USE_GNU 1 #include #include +#include #include "debug.h" #include "libiphone/libiphone.h" -int toto_debug = 0; +int debug_level = 0; /** * Sets the level of debugging. Currently the only acceptable values are 0 and @@ -35,33 +39,63 @@ int toto_debug = 0; */ void iphone_set_debug_level(int level) { - toto_debug = level; + debug_level = level; } -void log_debug_msg(const char *format, ...) +static void debug_print_line(const char *func, const char *file, int line, const char *buffer) { -#ifndef STRIP_DEBUG_CODE + char *str_time = NULL; + char *header = NULL; + time_t the_time; + + time(&the_time); + str_time = g_new0 (gchar, 255); + strftime(str_time, 254, "%H:%M:%S", localtime (&the_time)); + + /* generate header text */ + asprintf(&header, "%s %s %s:%d", str_time, file, func, line); + free (str_time); + + /* always in light green */ + printf ("%s\n", header); + + /* different colors according to the severity */ + printf ("%s\n", buffer); + + /* flush this output, as we need to debug */ + fflush (stdout); + + free (header); +} +inline void debug_info_real(const char *func, const char *file, int line, const char *format, ...) +{ +#ifndef STRIP_DEBUG_CODE va_list args; - /* run the real fprintf */ - va_start(args, format); + char *buffer = NULL; - if (toto_debug) - vfprintf(stderr, format, args); + if (!debug_level) + return; + /* run the real fprintf */ + va_start(args, format); + vasprintf(&buffer, format, args); va_end(args); + debug_print_line(func, file, line, buffer); + + free(buffer); #endif } -inline void log_debug_buffer(const char *data, const int length) +inline void debug_buffer(const char *data, const int length) { #ifndef STRIP_DEBUG_CODE int i; int j; unsigned char c; - if (toto_debug) { + if (debug_level) { for (i = 0; i < length; i += 16) { fprintf(stderr, "%04x: ", i); for (j = 0; j < 16; j++) { @@ -89,16 +123,14 @@ inline void log_debug_buffer(const char *data, const int length) #endif } -inline void dump_debug_buffer(const char *file, const char *data, const int length) +inline void debug_buffer_to_file(const char *file, const char *data, const int length) { #ifndef STRIP_DEBUG_CODE - /* run the real fprintf */ - if (toto_debug) { - FILE *my_ssl_packet = fopen(file, "w+"); - fwrite(data, 1, length, my_ssl_packet); - fflush(my_ssl_packet); - fprintf(stderr, "%s: Wrote SSL packet to drive, too.\n", __func__); - fclose(my_ssl_packet); + if (debug_level) { + FILE *f = fopen(file, "w+"); + fwrite(data, 1, length, f); + fflush(f); + fclose(f); } #endif } diff --git a/src/debug.h b/src/debug.h index 398508e..f99089d 100644 --- a/src/debug.h +++ b/src/debug.h @@ -1,6 +1,6 @@ /* * debug.h - * contains utilitary methos for logging and debugging + * contains utilitary functions for debugging * * Copyright (c) 2008 Jonathan Beck All Rights Reserved. * @@ -24,8 +24,20 @@ #include -G_GNUC_INTERNAL inline void log_debug_msg(const char *format, ...); -G_GNUC_INTERNAL inline void log_debug_buffer(const char *data, const int length); -G_GNUC_INTERNAL inline void dump_debug_buffer(const char *file, const char *data, const int length); +#if defined(__STDC_VERSION__) && __STDC_VERSION__ >= 199901L && !defined(STRIP_DEBUG_CODE) +#define debug_info(...) debug_info_real (__func__, __FILE__, __LINE__, __VA_ARGS__) +#elif defined(__GNUC__) && __GNUC__ >= 3 && !defined(STRIP_DEBUG_CODE) +#define debug_info(...) debug_info_real (__FUNCTION__, __FILE__, __LINE__, __VA_ARGS__) +#else +#define debug_info(...) +#endif + +G_GNUC_INTERNAL inline void debug_info_real(const char *func, + const char *file, + int line, + const char *format, ...); + +G_GNUC_INTERNAL inline void debug_buffer(const char *data, const int length); +G_GNUC_INTERNAL inline void debug_buffer_to_file(const char *file, const char *data, const int length); #endif diff --git a/src/device_link_service.c b/src/device_link_service.c index b1106fe..e1155a5 100644 --- a/src/device_link_service.c +++ b/src/device_link_service.c @@ -149,13 +149,13 @@ device_link_service_error_t device_link_service_version_exchange(device_link_ser /* receive DLMessageVersionExchange from device */ if (property_list_service_receive_plist(client->parent, &array) != PROPERTY_LIST_SERVICE_E_SUCCESS) { - log_debug_msg("%s: Did not receive initial message from device!\n", __func__); + debug_info("Did not receive initial message from device!"); err = DEVICE_LINK_SERVICE_E_MUX_ERROR; goto leave; } msg = device_link_service_get_message(array); if (!msg || strcmp(msg, "DLMessageVersionExchange")) { - log_debug_msg("%s: Did not receive DLMessageVersionExchange from device!\n", __func__); + debug_info("Did not receive DLMessageVersionExchange from device!"); err = DEVICE_LINK_SERVICE_E_PLIST_ERROR; goto leave; } @@ -164,7 +164,7 @@ device_link_service_error_t device_link_service_version_exchange(device_link_ser /* get major and minor version number */ if (plist_array_get_size(array) < 3) { - log_debug_msg("%s: DLMessageVersionExchange has unexpected format!\n", __func__); + debug_info("DLMessageVersionExchange has unexpected format!"); err = DEVICE_LINK_SERVICE_E_PLIST_ERROR; goto leave; } @@ -179,11 +179,11 @@ device_link_service_error_t device_link_service_version_exchange(device_link_ser plist_get_uint_val(min, &vminor); } if (vmajor > version_major) { - log_debug_msg("%s: Version mismatch: device=(%lld,%lld) > expected=(%lld,%lld)\n", __func__, vmajor, vminor, version_major, version_minor); + debug_info("Version mismatch: device=(%lld,%lld) > expected=(%lld,%lld)", vmajor, vminor, version_major, version_minor); err = DEVICE_LINK_SERVICE_E_BAD_VERSION; goto leave; } else if ((vmajor == version_major) && (vminor > version_minor)) { - log_debug_msg("%s: WARNING: Version mismatch: device=(%lld,%lld) > expected=(%lld,%lld)\n", __func__, vmajor, vminor, version_major, version_minor); + debug_info("WARNING: Version mismatch: device=(%lld,%lld) > expected=(%lld,%lld)", vmajor, vminor, version_major, version_minor); err = DEVICE_LINK_SERVICE_E_BAD_VERSION; goto leave; } @@ -194,7 +194,7 @@ device_link_service_error_t device_link_service_version_exchange(device_link_ser plist_array_append_item(array, plist_new_string("DLMessageVersionExchange")); plist_array_append_item(array, plist_new_string("DLVersionsOk")); if (property_list_service_send_binary_plist(client->parent, array) != PROPERTY_LIST_SERVICE_E_SUCCESS) { - log_debug_msg("%s: Error when sending DLVersionsOk", __func__); + debug_info("Error when sending DLVersionsOk"); err = DEVICE_LINK_SERVICE_E_MUX_ERROR; goto leave; } @@ -203,13 +203,13 @@ device_link_service_error_t device_link_service_version_exchange(device_link_ser /* receive DeviceReady message */ array = NULL; if (property_list_service_receive_plist(client->parent, &array) != PROPERTY_LIST_SERVICE_E_SUCCESS) { - log_debug_msg("%s: Error when receiving DLMessageDeviceReady!\n", __func__); + debug_info("Error when receiving DLMessageDeviceReady!"); err = DEVICE_LINK_SERVICE_E_MUX_ERROR; goto leave; } msg = device_link_service_get_message(array); if (!msg || strcmp(msg, "DLMessageDeviceReady")) { - log_debug_msg("%s: Did not get DLMessageDeviceReady!\n", __func__); + debug_info("Did not get DLMessageDeviceReady!"); err = DEVICE_LINK_SERVICE_E_PLIST_ERROR; goto leave; } diff --git a/src/iphone.c b/src/iphone.c index 7b21bb5..ce90299 100644 --- a/src/iphone.c +++ b/src/iphone.c @@ -60,7 +60,7 @@ iphone_error_t iphone_event_subscribe(iphone_event_cb_t callback, void *user_dat int res = usbmuxd_subscribe(usbmux_event_cb, user_data); if (res != 0) { event_cb = NULL; - log_debug_msg("%s: Error %d when subscribing usbmux event callback!\n", __func__, res); + debug_info("Error %d when subscribing usbmux event callback!", res); return IPHONE_E_UNKNOWN_ERROR; } return IPHONE_E_SUCCESS; @@ -77,7 +77,7 @@ iphone_error_t iphone_event_unsubscribe() event_cb = NULL; int res = usbmuxd_unsubscribe(); if (res != 0) { - log_debug_msg("%s: Error %d when unsubscribing usbmux event callback!\n", __func__, res); + debug_info("Error %d when unsubscribing usbmux event callback!", res); return IPHONE_E_UNKNOWN_ERROR; } return IPHONE_E_SUCCESS; @@ -100,7 +100,7 @@ iphone_error_t iphone_get_device_list(char ***devices, int *count) *count = 0; if (usbmuxd_get_device_list(&dev_list) < 0) { - log_debug_msg("%s: ERROR: usbmuxd is not running!\n", __func__); + debug_info("ERROR: usbmuxd is not running!\n", __func__); return IPHONE_E_NO_DEVICE; } @@ -216,7 +216,7 @@ iphone_error_t iphone_device_connect(iphone_device_t device, uint16_t dst_port, if (device->conn_type == CONNECTION_USBMUXD) { int sfd = usbmuxd_connect((uint32_t)(device->conn_data), dst_port); if (sfd < 0) { - log_debug_msg("%s: ERROR: Connecting to usbmuxd failed: %d (%s)\n", __func__, sfd, strerror(-sfd)); + debug_info("ERROR: Connecting to usbmuxd failed: %d (%s)", sfd, strerror(-sfd)); return IPHONE_E_UNKNOWN_ERROR; } iphone_connection_t new_connection = (iphone_connection_t)malloc(sizeof(struct iphone_connection_int)); @@ -225,7 +225,7 @@ iphone_error_t iphone_device_connect(iphone_device_t device, uint16_t dst_port, *connection = new_connection; return IPHONE_E_SUCCESS; } else { - log_debug_msg("%s: Unknown connection type %d\n", __func__, device->conn_type); + debug_info("Unknown connection type %d", device->conn_type); } return IPHONE_E_UNKNOWN_ERROR; @@ -248,7 +248,7 @@ iphone_error_t iphone_device_disconnect(iphone_connection_t connection) usbmuxd_disconnect((int)(connection->data)); result = IPHONE_E_SUCCESS; } else { - log_debug_msg("%s: Unknown connection type %d\n", __func__, connection->type); + debug_info("Unknown connection type %d", connection->type); } free(connection); return result; @@ -274,12 +274,12 @@ iphone_error_t iphone_device_send(iphone_connection_t connection, const char *da if (connection->type == CONNECTION_USBMUXD) { int res = usbmuxd_send((int)(connection->data), data, len, sent_bytes); if (res < 0) { - log_debug_msg("%s: ERROR: usbmuxd_send returned %d (%s)\n", __func__, res, strerror(-res)); + debug_info("ERROR: usbmuxd_send returned %d (%s)", res, strerror(-res)); return IPHONE_E_UNKNOWN_ERROR; } return IPHONE_E_SUCCESS; } else { - log_debug_msg("%s: Unknown connection type %d\n", __func__, connection->type); + debug_info("Unknown connection type %d", connection->type); } return IPHONE_E_UNKNOWN_ERROR; } @@ -308,12 +308,12 @@ iphone_error_t iphone_device_recv_timeout(iphone_connection_t connection, char * if (connection->type == CONNECTION_USBMUXD) { int res = usbmuxd_recv_timeout((int)(connection->data), data, len, recv_bytes, timeout); if (res < 0) { - log_debug_msg("%s: ERROR: usbmuxd_recv_timeout returned %d (%s)\n", __func__, res, strerror(-res)); + debug_info("ERROR: usbmuxd_recv_timeout returned %d (%s)", res, strerror(-res)); return IPHONE_E_UNKNOWN_ERROR; } return IPHONE_E_SUCCESS; } else { - log_debug_msg("%s: Unknown connection type %d\n", __func__, connection->type); + debug_info("Unknown connection type %d", connection->type); } return IPHONE_E_UNKNOWN_ERROR; } @@ -340,13 +340,13 @@ iphone_error_t iphone_device_recv(iphone_connection_t connection, char *data, ui if (connection->type == CONNECTION_USBMUXD) { int res = usbmuxd_recv((int)(connection->data), data, len, recv_bytes); if (res < 0) { - log_debug_msg("%s: ERROR: usbmuxd_recv returned %d (%s)\n", __func__, res, strerror(-res)); + debug_info("ERROR: usbmuxd_recv returned %d (%s)", res, strerror(-res)); return IPHONE_E_UNKNOWN_ERROR; } return IPHONE_E_SUCCESS; } else { - log_debug_msg("%s: Unknown connection type %d\n", __func__, connection->type); + debug_info("Unknown connection type %d", connection->type); } return IPHONE_E_UNKNOWN_ERROR; } @@ -360,7 +360,7 @@ iphone_error_t iphone_device_get_handle(iphone_device_t device, uint32_t *handle *handle = (uint32_t)device->conn_data; return IPHONE_E_SUCCESS; } else { - log_debug_msg("%s: Unknown connection type %d\n", __func__, device->conn_type); + debug_info("Unknown connection type %d", device->conn_type); } return IPHONE_E_UNKNOWN_ERROR; } 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); diff --git a/src/property_list_service.c b/src/property_list_service.c index b549cb4..e39c7bb 100644 --- a/src/property_list_service.c +++ b/src/property_list_service.c @@ -142,7 +142,7 @@ static property_list_service_error_t internal_plist_send(property_list_service_c } nlen = htonl(length); - log_debug_msg("%s: sending %d bytes\n", __func__, length); + debug_info("sending %d bytes", length); if (ssl_session) { bytes = gnutls_record_send(ssl_session, (const char*)&nlen, sizeof(nlen)); } else { @@ -155,17 +155,17 @@ static property_list_service_error_t internal_plist_send(property_list_service_c iphone_device_send(client->connection, content, length, (uint32_t*)&bytes); } if (bytes > 0) { - log_debug_msg("%s: sent %d bytes\n", __func__, bytes); - log_debug_buffer(content, bytes); + debug_info("sent %d bytes", bytes); + debug_buffer(content, bytes); if ((uint32_t)bytes == length) { res = PROPERTY_LIST_SERVICE_E_SUCCESS; } else { - log_debug_msg("%s: ERROR: Could not send all data (%d of %d)!\n", __func__, bytes, length); + debug_info("ERROR: Could not send all data (%d of %d)!", bytes, length); } } } if (bytes <= 0) { - log_debug_msg("%s: ERROR: sending to device failed.\n", __func__); + debug_info("ERROR: sending to device failed."); } free(content); @@ -274,16 +274,16 @@ static property_list_service_error_t internal_plist_recv_timeout(property_list_s } else { iphone_device_recv_timeout(client->connection, (char*)&pktlen, sizeof(pktlen), &bytes, timeout); } - log_debug_msg("%s: initial read=%i\n", __func__, bytes); + debug_info("initial read=%i", bytes); if (bytes < 4) { - log_debug_msg("%s: initial read failed!\n", __func__); + debug_info("initial read failed!"); return PROPERTY_LIST_SERVICE_E_MUX_ERROR; } else { if ((char)pktlen == 0) { /* prevent huge buffers */ uint32_t curlen = 0; char *content = NULL; pktlen = ntohl(pktlen); - log_debug_msg("%s: %d bytes following\n", __func__, pktlen); + debug_info("%d bytes following", pktlen); content = (char*)malloc(pktlen); while (curlen < pktlen) { @@ -296,10 +296,10 @@ static property_list_service_error_t internal_plist_recv_timeout(property_list_s res = PROPERTY_LIST_SERVICE_E_MUX_ERROR; break; } - log_debug_msg("%s: received %d bytes\n", __func__, bytes); + debug_info("received %d bytes", bytes); curlen += bytes; } - log_debug_buffer(content, pktlen); + debug_buffer(content, pktlen); if (!memcmp(content, "bplist00", 8)) { plist_from_bin(content, pktlen, plist); } else { diff --git a/src/userpref.c b/src/userpref.c index c677fda..6eff534 100644 --- a/src/userpref.c +++ b/src/userpref.c @@ -106,7 +106,7 @@ static int userpref_set_host_id(const char *host_id) key_file = g_key_file_new(); /* Store in config file */ - log_debug_msg("%s: setting hostID to %s\n", __func__, host_id); + debug_info("setting hostID to %s", host_id); g_key_file_set_value(key_file, "Global", "HostID", host_id); /* Write config file on disk */ @@ -155,7 +155,7 @@ void userpref_get_host_id(char **host_id) userpref_set_host_id(*host_id); } - log_debug_msg("%s: Using %s as HostID\n", __func__, *host_id); + debug_info("Using %s as HostID", *host_id); } /** Determines whether this iPhone has been connected to this system before. -- cgit v1.1-32-gdbae