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, 56 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);