Refactor logging and add logfile support

idevicerestore will now also create a logfile automatically, unless
disabled with --logfile=NONE.

1 files changed, 64 insertions, 66 deletions

diff --git a/src/fdr.c b/src/fdr.c
index ca9b7c7..378d4f9 100644
--- a/src/fdr.c
+++ b/src/fdr.c
@@ -66,7 +66,7 @@ int fdr_connect(idevice_t device, fdr_type_t type, fdr_client_t* fdr)
 
 	*fdr = NULL;
 
-	debug("Connecting to FDR client at port %u\n", port);
+	logger(LL_DEBUG, "Connecting to FDR client at port %u\n", port);
 
 	for (i = 1; i <= attempts; i++) {
 		device_error = idevice_connect(device, port, &connection);
@@ -75,17 +75,17 @@ int fdr_connect(idevice_t device, fdr_type_t type, fdr_client_t* fdr)
 		}
 
 		if (i >= attempts) {
-			error("ERROR: Unable to connect to FDR client (%d)\n", device_error);
+			logger(LL_ERROR, "Unable to connect to FDR client (%d)\n", device_error);
 			return -1;
 		}
 
 		sleep(2);
-		debug("Retrying connection...\n");
+		logger(LL_DEBUG, "Retrying connection...\n");
 	}
 
 	fdr_client_t fdr_loc = calloc(1, sizeof(struct fdr_client));
 	if (!fdr_loc) {
-		error("ERROR: Unable to allocate memory\n");
+		logger(LL_ERROR, "Unable to allocate memory\n");
 		return -1;
 	}
 	fdr_loc->connection = connection;
@@ -138,7 +138,7 @@ int fdr_poll_and_handle_message(fdr_client_t fdr)
 	uint16_t cmd;
 
 	if (!fdr) {
-		error("ERROR: Invalid FDR client\n");
+		logger(LL_ERROR, "Invalid FDR client\n");
 		return -1;
 	}
 
@@ -149,32 +149,32 @@ int fdr_poll_and_handle_message(fdr_client_t fdr)
 	if (device_error == IDEVICE_E_SUCCESS && bytes != sizeof(cmd))
 #endif
 	{
-		debug("FDR %p timeout waiting for command\n", fdr);
+		logger(LL_DEBUG, "FDR %p timeout waiting for command\n", fdr);
 		return 0;
 	}
 	else if (device_error != IDEVICE_E_SUCCESS) {
 		if (fdr->connection) {
-			error("ERROR: Unable to receive message from FDR %p (%d). %u/%u bytes\n", fdr, device_error, bytes, (uint32_t)sizeof(cmd));
+			logger(LL_ERROR, "Unable to receive message from FDR %p (%d). %u/%u bytes\n", fdr, device_error, bytes, (uint32_t)sizeof(cmd));
 		}
 		return -1;
 	}
 
 	if (cmd == FDR_SYNC_MSG) {
-		debug("FDR %p got sync message\n", fdr);
+		logger(LL_DEBUG, "FDR %p got sync message\n", fdr);
 		return fdr_handle_sync_cmd(fdr);
 	}
 
 	if (cmd == FDR_PROXY_MSG) {
-		debug("FDR %p got proxy message\n", fdr);
+		logger(LL_DEBUG, "FDR %p got proxy message\n", fdr);
 		return fdr_handle_proxy_cmd(fdr);
 	}
 
 	if (cmd == FDR_PLIST_MSG) {
-		debug("FDR %p got plist message\n", fdr);
+		logger(LL_DEBUG, "FDR %p got plist message\n", fdr);
 		return fdr_handle_plist_cmd(fdr);
 	}
 
-	error("WARNING: FDR %p received unknown packet %#x of size %u\n", fdr, cmd, bytes);
+	logger(LL_WARNING, "FDR %p received unknown packet %#x of size %u\n", fdr, cmd, bytes);
 	return 0;
 }
 
@@ -184,14 +184,14 @@ void *fdr_listener_thread(void *cdata)
 	int res;
 
 	while (fdr && fdr->connection) {
-		debug("FDR %p waiting for message...\n", fdr);
+		logger(LL_DEBUG, "FDR %p waiting for message...\n", fdr);
 		res = fdr_poll_and_handle_message(fdr);
 		if (fdr->type == FDR_CTRL && res >= 0)
 			continue; // main thread should always retry
 		if (res != 0)
 			break;
 	}
-	debug("FDR %p terminating...\n", fdr);
+	logger(LL_DEBUG, "FDR %p terminating...\n", fdr);
 	fdr_free(fdr);
 	return (void *)(intptr_t)res;
 }
@@ -204,26 +204,26 @@ static int fdr_receive_plist(fdr_client_t fdr, plist_t* data)
 
 	device_error = idevice_connection_receive(fdr->connection, (char*)&len, sizeof(len), &bytes);
 	if (device_error != IDEVICE_E_SUCCESS) {
-		error("ERROR: Unable to receive packet length from FDR (%d)\n", device_error);
+		logger(LL_ERROR, "Unable to receive packet length from FDR (%d)\n", device_error);
 		return -1;
 	}
 
 	buf = calloc(1, len);
 	if (!buf) {
-		error("ERROR: Unable to allocate memory for FDR receive buffer\n");
+		logger(LL_ERROR, "Unable to allocate memory for FDR receive buffer\n");
 		return -1;
 	}
 
 	device_error = idevice_connection_receive(fdr->connection, buf, len, &bytes);
 	if (device_error != IDEVICE_E_SUCCESS) {
-		error("ERROR: Unable to receive data from FDR\n");
+		logger(LL_ERROR, "Unable to receive data from FDR\n");
 		free(buf);
 		return -1;
 	}
 	plist_from_bin(buf, bytes, data);
 	free(buf);
 
-	debug("FDR Received %d bytes\n", bytes);
+	logger(LL_DEBUG, "FDR Received %d bytes\n", bytes);
 
 	return 0;
 }
@@ -241,12 +241,11 @@ static int fdr_send_plist(fdr_client_t fdr, plist_t data)
 	if (!buf)
 		return -1;
 
-	debug("FDR sending %d bytes:\n", len);
-	if (idevicerestore_debug)
-		debug_plist(data);
+	logger(LL_DEBUG, "FDR sending %d bytes:\n", len);
+	logger_dump_plist(LL_DEBUG, data, 1);
 	device_error = idevice_connection_send(fdr->connection, (char *)&len, sizeof(len), &bytes);
 	if (device_error != IDEVICE_E_SUCCESS || bytes != sizeof(len)) {
-		error("ERROR: FDR unable to send data length. (%d) Sent %u of %u bytes.\n",
+		logger(LL_ERROR, "FDR unable to send data length. (%d) Sent %u of %u bytes.\n",
 		      device_error, bytes, (uint32_t)sizeof(len));
 		free(buf);
 		return -1;
@@ -254,12 +253,12 @@ static int fdr_send_plist(fdr_client_t fdr, plist_t data)
 	device_error = idevice_connection_send(fdr->connection, buf, len, &bytes);
 	free(buf);
 	if (device_error != IDEVICE_E_SUCCESS || bytes != len) {
-		error("ERROR: FDR unable to send data (%d). Sent %u of %u bytes.\n",
+		logger(LL_ERROR, "FDR unable to send data (%d). Sent %u of %u bytes.\n",
 		      device_error, bytes, len);
 		return -1;
 	}
 
-	debug("FDR Sent %d bytes\n", bytes);
+	logger(LL_DEBUG, "FDR Sent %d bytes\n", bytes);
 	return 0;
 }
 
@@ -270,18 +269,18 @@ static int fdr_ctrl_handshake(fdr_client_t fdr)
 	plist_t dict, node;
 	int res;
 
-	debug("About to do ctrl handshake\n");
+	logger(LL_DEBUG, "About to do ctrl handshake\n");
 
 	ctrlprotoversion = 2;
 
 	device_error = idevice_connection_send(fdr->connection, CTRLCMD, len, &bytes);
 	if (device_error != IDEVICE_E_SUCCESS || bytes != len) {
-		debug("Hmm... looks like the device doesn't like the newer protocol, using the old one\n");
+		logger(LL_DEBUG, "Hmm... looks like the device doesn't like the newer protocol, using the old one\n");
 		ctrlprotoversion = 1;
 		len = sizeof(HELLOCTRLCMD);
 		device_error = idevice_connection_send(fdr->connection, HELLOCTRLCMD, len, &bytes);
 		if (device_error != IDEVICE_E_SUCCESS || bytes != len) {
-			error("ERROR: FDR unable to send BeginCtrl. Sent %u of %u bytes.\n", bytes, len);
+			logger(LL_ERROR, "FDR unable to send BeginCtrl. Sent %u of %u bytes.\n", bytes, len);
 			return -1;
 		}
 	}
@@ -293,21 +292,20 @@ static int fdr_ctrl_handshake(fdr_client_t fdr)
 		res = fdr_send_plist(fdr, dict);
 		plist_free(dict);
 		if (res) {
-			error("ERROR: FDR could not send Begin command.\n");
+			logger(LL_ERROR, "FDR could not send Begin command.\n");
 			return -1;
 		}
 
 		if (fdr_receive_plist(fdr, &dict)) {
-			error("ERROR: FDR did not get Begin command reply.\n");
+			logger(LL_ERROR, "FDR did not get Begin command reply.\n");
 			return -1;
 		}
-		if (idevicerestore_debug)
-			debug_plist(dict);
+		logger_dump_plist(LL_DEBUG, dict, 1);
 		node = plist_dict_get_item(dict, "ConnPort");
 		if (node && plist_get_node_type(node) == PLIST_UINT) {
 			plist_get_uint_val(node, &conn_port);
 		} else {
-			error("ERROR: Could not get FDR ConnPort value\n");
+			logger(LL_ERROR, "Could not get FDR ConnPort value\n");
 			return -1;
 		}
 
@@ -321,26 +319,26 @@ static int fdr_ctrl_handshake(fdr_client_t fdr)
 		bytes = 0;
 		device_error = idevice_connection_receive(fdr->connection, buf, 10, &bytes);
 		if (device_error != IDEVICE_E_SUCCESS) {
-			error("ERROR: Could not receive reply to HelloCtrl command\n");
+			logger(LL_ERROR, "Could not receive reply to HelloCtrl command\n");
 			return -1;
 		}
 		if (memcmp(buf, "HelloCtrl", 10) != 0) {
 			buf[9] = '\0';
-			error("ERROR: Did not receive HelloCtrl as reply, but %s\n", buf);
+			logger(LL_ERROR, "Did not receive HelloCtrl as reply, but %s\n", buf);
 			return -1;
 		}
 
 		bytes = 0;
 		device_error = idevice_connection_receive(fdr->connection, (char*)&cport, 2, &bytes);
 		if (device_error != IDEVICE_E_SUCCESS) {
-			error("ERROR: Failed to receive conn port\n");
+			logger(LL_ERROR, "Failed to receive conn port\n");
 			return -1;
 		}
 
 		conn_port = le16toh(cport);
 	}
 
-	debug("Ctrl handshake done (ConnPort = %" PRIu64 ")\n", (uint64_t)conn_port);
+	logger(LL_DEBUG, "Ctrl handshake done (ConnPort = %" PRIu64 ")\n", (uint64_t)conn_port);
 
 	return 0;
 }
@@ -353,13 +351,13 @@ static int fdr_sync_handshake(fdr_client_t fdr)
 
 	device_error = idevice_connection_send(fdr->connection, HELLOCMD, len, &bytes);
 	if (device_error != IDEVICE_E_SUCCESS || bytes != len) {
-		error("ERROR: FDR unable to send Hello. Sent %u of %u bytes.\n", bytes, len);
+		logger(LL_ERROR, "FDR unable to send Hello. Sent %u of %u bytes.\n", bytes, len);
 		return -1;
 	}
 
 	if (ctrlprotoversion == 2) {
 		if (fdr_receive_plist(fdr, &reply)) {
-			error("ERROR: FDR did not get HelloConn reply.\n");
+			logger(LL_ERROR, "FDR did not get HelloConn reply.\n");
 			return -1;
 		}
 		char* identifier = NULL;
@@ -382,13 +380,13 @@ static int fdr_sync_handshake(fdr_client_t fdr)
 			if (identifier) {
 				free(identifier);
 			}
-			error("ERROR: Did not receive HelloConn reply...\n");
+			logger(LL_ERROR, "Did not receive HelloConn reply...\n");
 			return -1;
 		}
 		free(cmd);
 
 		if (identifier) {
-			debug("Got device identifier %s\n", identifier);
+			logger(LL_DEBUG, "Got device identifier %s\n", identifier);
 			free(identifier);
 		}
 
@@ -398,12 +396,12 @@ static int fdr_sync_handshake(fdr_client_t fdr)
 		bytes = 0;
 		device_error = idevice_connection_receive(fdr->connection, buf, 10, &bytes);
 		if (device_error != IDEVICE_E_SUCCESS) {
-			error("ERROR: Could not receive reply to HelloConn command\n");
+			logger(LL_ERROR, "Could not receive reply to HelloConn command\n");
 			return -1;
 		}
 		if (memcmp(buf, "HelloConn", 10) != 0) {
 			buf[9] = '\0';
-			error("ERROR: Did not receive HelloConn as reply, but %s\n", buf);
+			logger(LL_ERROR, "Did not receive HelloConn as reply, but %s\n", buf);
 			return -1;
 		}
 	}
@@ -422,18 +420,18 @@ static int fdr_handle_sync_cmd(fdr_client_t fdr_ctrl)
 
 	device_error = idevice_connection_receive(fdr_ctrl->connection, buf, sizeof(buf), &bytes);
 	if (device_error != IDEVICE_E_SUCCESS || bytes != 2) {
-		error("ERROR: Unexpected data from FDR\n");
+		logger(LL_ERROR, "Unexpected data from FDR\n");
 		return -1;
 	}
 	/* Open a new connection and wait for messages on it */
 	if (fdr_connect(fdr_ctrl->device, FDR_CONN, &fdr)) {
-		error("ERROR: Failed to connect to FDR port\n");
+		logger(LL_ERROR, "Failed to connect to FDR port\n");
 		return -1;
 	}
-	debug("FDR connected in reply to sync message, starting command thread\n");
+	logger(LL_DEBUG, "FDR connected in reply to sync message, starting command thread\n");
 	res = thread_new(&fdr_thread, fdr_listener_thread, fdr);
 	if(res) {
-		error("ERROR: Failed to start FDR command thread\n");
+		logger(LL_ERROR, "Failed to start FDR command thread\n");
 		fdr_free(fdr);
 	}
 	return res;
@@ -445,12 +443,12 @@ static int fdr_handle_plist_cmd(fdr_client_t fdr)
 	plist_t dict;
 
 	if (fdr_receive_plist(fdr, &dict)) {
-		error("ERROR: FDR %p could not receive plist command.\n", fdr);
+		logger(LL_ERROR, "FDR %p could not receive plist command.\n", fdr);
 		return -1;
 	}
 	plist_t node = plist_dict_get_item(dict, "Command");
 	if (!node || (plist_get_node_type(node) != PLIST_STRING)) {
-		error("ERROR: FDR %p Could not find Command in plist command\n", fdr);
+		logger(LL_ERROR, "FDR %p Could not find Command in plist command\n", fdr);
 		plist_free(dict);
 		return -1;
 	}
@@ -459,7 +457,7 @@ static int fdr_handle_plist_cmd(fdr_client_t fdr)
 	plist_free(dict);
 
 	if (!command) {
-		info("FDR %p received empty plist command\n", fdr);
+		logger(LL_INFO, "FDR %p received empty plist command\n", fdr);
 		return -1;
 	}
 
@@ -469,12 +467,12 @@ static int fdr_handle_plist_cmd(fdr_client_t fdr)
 		res = fdr_send_plist(fdr, dict);
 		plist_free(dict);
 		if (res) {
-			error("ERROR: FDR %p could not send Ping command reply.\n", fdr);
+			logger(LL_ERROR, "FDR %p could not send Ping command reply.\n", fdr);
 			free(command);
 			return -1;
 		}
 	} else {
- 		error("WARNING: FDR %p received unknown plist command: %s\n", fdr, command);
+		logger(LL_WARNING, "FDR %p received unknown plist command: %s\n", fdr, command);
 		free(command);
 		return -1;
 	}
@@ -495,17 +493,17 @@ static int fdr_handle_proxy_cmd(fdr_client_t fdr)
 
 	buf = malloc(bufsize);
 	if (!buf) {
-		error("ERROR: %s: malloc failed\n", __func__);
+		logger(LL_ERROR, "%s: malloc failed\n", __func__);
 		return -1;
 	}
 
 	device_error = idevice_connection_receive(fdr->connection, buf, bufsize, &bytes);
 	if (device_error != IDEVICE_E_SUCCESS) {
 		free(buf);
-		error("ERROR: FDR %p failed to read data for proxy command\n", fdr);
+		logger(LL_ERROR, "FDR %p failed to read data for proxy command\n", fdr);
 		return -1;
 	}
-	debug("Got proxy command with %u bytes\n", bytes);
+	logger(LL_DEBUG, "Got proxy command with %u bytes\n", bytes);
 
 	/* Just return success here unconditionally because we don't know
 	 * anything else and we will eventually abort on failure anyway */
@@ -513,13 +511,13 @@ static int fdr_handle_proxy_cmd(fdr_client_t fdr)
 	device_error = idevice_connection_send(fdr->connection, (char *)&ack, sizeof(ack), &sent);
 	if (device_error != IDEVICE_E_SUCCESS || sent != sizeof(ack)) {
 		free(buf);
-		error("ERROR: FDR %p unable to send ack. Sent %u of %u bytes.\n",
+		logger(LL_ERROR, "FDR %p unable to send ack. Sent %u of %u bytes.\n",
 		      fdr, sent, (uint32_t)sizeof(ack));
 		return -1;
 	}
 
 	if (bytes < 3) {
-		debug("FDR %p proxy command data too short, retrying\n", fdr);
+		logger(LL_DEBUG, "FDR %p proxy command data too short, retrying\n", fdr);
 		return fdr_poll_and_handle_message(fdr);
 	}
 
@@ -527,7 +525,7 @@ static int fdr_handle_proxy_cmd(fdr_client_t fdr)
 	device_error = idevice_connection_send(fdr->connection, buf, bytes, &sent);
 	if (device_error != IDEVICE_E_SUCCESS || sent != bytes) {
 		free(buf);
-		error("ERROR: FDR %p unable to send data. Sent %u of %u bytes.\n",
+		logger(LL_ERROR, "FDR %p unable to send data. Sent %u of %u bytes.\n",
 		      fdr, sent, bytes);
 		return -1;
 	}
@@ -539,7 +537,7 @@ static int fdr_handle_proxy_cmd(fdr_client_t fdr)
 		port = be16toh(*p);
 		buf[bytes - 2] = '\0';
 		host = strdup(&buf[3]);
-		debug("FDR %p Proxy connect request to %s:%u\n", fdr, host, port);
+		logger(LL_DEBUG, "FDR %p Proxy connect request to %s:%u\n", fdr, host, port);
 	}
 
 	if (!host || !buf[2]) {
@@ -553,7 +551,7 @@ static int fdr_handle_proxy_cmd(fdr_client_t fdr)
 	free(host);
 	if (sockfd < 0) {
 		free(buf);
-		error("ERROR: Failed to connect socket: %s\n", strerror(errno));
+		logger(LL_ERROR, "Failed to connect socket: %s\n", strerror(errno));
 		return -1;
 	}
 
@@ -567,16 +565,16 @@ static int fdr_handle_proxy_cmd(fdr_client_t fdr)
 		if (device_error == IDEVICE_E_SUCCESS && !bytes)
 #endif
 		{
-			//debug("WARNING: Timeout waiting for proxy payload. %p\n", fdr);
+			//logger(LL_DEBUG, "Timeout waiting for proxy payload. %p\n", fdr);
 		}
 		else if (device_error != IDEVICE_E_SUCCESS) {
-			error("ERROR: FDR %p Unable to receive proxy payload (%d)\n", fdr, device_error);
+			logger(LL_ERROR, "FDR %p Unable to receive proxy payload (%d)\n", fdr, device_error);
 			res = -1;
 			break;
 		}
 		if (bytes) {
-			debug("FDR %p got payload of %u bytes, now trying to proxy it\n", fdr, bytes);
-			debug("Sending %u bytes of data\n", bytes);
+			logger(LL_DEBUG, "FDR %p got payload of %u bytes, now trying to proxy it\n", fdr, bytes);
+			logger(LL_DEBUG, "Sending %u bytes of data\n", bytes);
 			sent = 0;
 			while (sent < bytes) {
 				int s = socket_send(sockfd, buf + sent, bytes - sent);
@@ -586,7 +584,7 @@ static int fdr_handle_proxy_cmd(fdr_client_t fdr)
 				sent += s;
 			}
 			if (sent != bytes) {
-				error("ERROR: Sending proxy payload failed: %s. Sent %u of %u bytes. \n", strerror(errno), sent, bytes);
+				logger(LL_ERROR, "Sending proxy payload failed: %s. Sent %u of %u bytes. \n", strerror(errno), sent, bytes);
 				socket_close(sockfd);
 				res = -1;
 				break;
@@ -599,14 +597,14 @@ static int fdr_handle_proxy_cmd(fdr_client_t fdr)
 			res = 1;
 			break;
 		} else if (bytes_ret < 0) {
-			error("ERROR: FDR %p receiving proxy payload failed: %d (%s)\n",
+			logger(LL_ERROR, "FDR %p receiving proxy payload failed: %d (%s)\n",
 			      fdr, bytes_ret, strerror(-bytes_ret));
 			break;
 		}
 
 		bytes = bytes_ret;
 		if (bytes) {
-			debug("FDR %p Received %u bytes reply data,%s sending to device\n",
+			logger(LL_DEBUG, "FDR %p Received %u bytes reply data,%s sending to device\n",
 			      fdr, bytes, (bytes ? "" : " not"));
 
 			sent = 0;
@@ -619,7 +617,7 @@ static int fdr_handle_proxy_cmd(fdr_client_t fdr)
 				sent += s;
 			}
 			if (device_error != IDEVICE_E_SUCCESS || bytes != sent) {
-				error("ERROR: FDR %p unable to send data (%d). Sent %u of %u bytes.\n", fdr, device_error, sent, bytes);
+				logger(LL_ERROR, "FDR %p unable to send data (%d). Sent %u of %u bytes.\n", fdr, device_error, sent, bytes);
 				res = -1;
 				break;
 			}