Logging and debugging refined.

1 files changed, 99 insertions, 91 deletions

diff --git a/main.c b/main.c
index eba154e..157ecbb 100644
--- a/main.c
+++ b/main.c
@@ -49,6 +49,8 @@
 
 #define LOCKFILE "/var/run/usbmuxd.lock"
 
+#define THREAD (unsigned int)pthread_self()
+
 static int quit_flag = 0;
 static int fsock = -1;
 static int verbose = DEBUG_LEVEL;
@@ -86,6 +88,44 @@ static int device_count = 0;
 static pthread_mutex_t usbmux_mutex = PTHREAD_MUTEX_INITIALIZER;
 static pthread_mutex_t usb_mutex = PTHREAD_MUTEX_INITIALIZER;
 
+/**
+ * logs a message to syslog when running as daemon or to stdout/stderr when
+ * running in foreground.
+ * @param prio The logging priority.
+ * @param format The message to be printed.
+ */
+static void logmsg(int prio, char *format, ...)
+{
+    va_list args;
+    va_start(args, format);
+
+    if (!foreground) {
+	// daemon. log using syslog.
+	vsyslog(prio, format, args);
+    } else {
+	// running in foreground. log to stdout/stderr.
+	char msgbuf[256];
+	FILE *lfp = stdout;
+	switch(prio) {
+	    case LOG_EMERG:
+	    case LOG_ALERT:
+	    case LOG_CRIT:
+	    case LOG_ERR:
+	    case LOG_WARNING:
+		lfp = stderr;
+		break;
+	    default:
+		lfp = stdout;
+	}
+	strcpy(msgbuf, "usbmuxd: ");
+	vsnprintf(msgbuf+9, 244, format, args);
+	strcat(msgbuf, "\n");
+	fputs(msgbuf, lfp);
+    }
+
+    va_end(args);
+}
+
 #ifdef DEBUG
 /**
  * for debugging purposes.
@@ -147,18 +187,18 @@ static int usbmuxd_get_request(int fd, void **data, size_t len)
 	*data = malloc(pktlen);
     } else if (len < pktlen) {
 	// target buffer is to small to hold this packet! fix it!
-	if (verbose >= 2) fprintf(stderr, "%s: WARNING -- packet (%d) is larger than target buffer (%d)! Truncating.\n", __func__, pktlen, len);
+	if (verbose >= 2) logmsg(LOG_WARNING, "%s: WARNING -- packet (%d) is larger than target buffer (%d)! Truncating.", __func__, pktlen, len);
 	pktlen = len;
     }
 
     recv_len = recv_buf(fd, *data, pktlen);
     if ((recv_len > 0) && (recv_len < pktlen)) {
-	if (verbose >= 2) fprintf(stderr, "%s: Uh-oh, we got less than the packet's size, %d instead of %d...\n", __func__, recv_len, pktlen);
+	if (verbose >= 2) logmsg(LOG_WARNING, "%s: Uh-oh, we got less than the packet's size, %d instead of %d...", __func__, recv_len, pktlen);
     }
 
 #ifdef DEBUG
     if (*data && (recv_len > 0) && verbose >= 4) {
-	if (verbose >= 3) fprintf(stderr, "%s: received:\n", __func__);
+	fprintf(stderr, "%s: received:\n", __func__);
 	print_buffer(stderr, *data, recv_len);
     }
 #endif
@@ -186,7 +226,7 @@ static int usbmuxd_send_result(int fd, uint32_t tag, uint32_t result_code)
     res.header.tag = tag;
     res.result = result_code;
 
-    if (verbose >= 4) fprintf(stderr, "%s: tag=%d result=%d\n", __func__, res.header.tag, res.result);
+    if (verbose >= 4) logmsg(LOG_NOTICE, "%s: tag=%d result=%d", __func__, res.header.tag, res.result);
 
     ret = send_buf(fd, &res, sizeof(res));
     fsync(fd); // let's get it sent
@@ -214,7 +254,7 @@ static void *usbmuxd_client_reader_thread(void *arg)
     int result;
 
     if (!arg) {
-	if (verbose >= 2) fprintf(stderr, "%s: invalid client_data supplied!\n", __func__);
+	if (verbose >= 2) logmsg(LOG_ERR, "%s: invalid client_data supplied!", __func__);
 	cdata->reader_dead = 1;
 	return NULL;
     }
@@ -223,13 +263,13 @@ static void *usbmuxd_client_reader_thread(void *arg)
 
     cdata->reader_dead = 0;
 
-    if (verbose >= 2) fprintf(stderr, "%s[%d:%d]: started\n", __func__, cdata->dev->device_id, cdata->dev->use_count);
+    if (verbose >= 3) logmsg(LOG_NOTICE, "%s[%d:%d]: started", __func__, cdata->dev->device_id, cdata->dev->use_count);
 
     while (!quit_flag && !cdata->reader_quit) {
 	result = check_fd(cdata->socket, FD_WRITE, DEFAULT_TIMEOUT);
 	if (result <= 0) {
 	    if (result < 0) {
-		if (verbose >= 2) fprintf(stderr, "%s: select error: %s\n", __func__, strerror(errno));
+		if (verbose >= 2) logmsg(LOG_ERR, "%s: select error: %s", __func__, strerror(errno));
 	    }
 	    continue;
 	}
@@ -237,7 +277,7 @@ static void *usbmuxd_client_reader_thread(void *arg)
 	rlen = 0;
 	err = iphone_mux_recv_timeout(cdata->muxclient, rbuffer, rbuffersize, &rlen, DEFAULT_TIMEOUT);
 	if (err != 0) {
-	    if (verbose >= 2) fprintf(stderr, "%s[%d:%d]: encountered USB read error: %d\n", __func__, cdata->dev->device_id, cdata->dev->use_count, err);
+	    if (verbose >= 2) logmsg(LOG_ERR, "%s[%d:%d]: encountered USB read error: %d", __func__, cdata->dev->device_id, cdata->dev->use_count, err);
 	    break;
 	}
 
@@ -245,7 +285,7 @@ static void *usbmuxd_client_reader_thread(void *arg)
 	while (rlen > 0) {
     	    len = send_buf(cdata->socket, cursor, rlen);
 	    if (len <= 0) {
-		fprintf(stderr, "Error: send returned %d\n", len);
+		logmsg(LOG_ERR, "%s: Error: send returned %d", __func__, len);
 		err = 1;
 		break;
 	    }
@@ -255,13 +295,13 @@ static void *usbmuxd_client_reader_thread(void *arg)
 	    cursor += len;
 	}
 	if (err != 0) {
-	    fprintf(stderr, "Error when writing to client...\n");
+	    logmsg(LOG_ERR, "%s: Error when writing to client...", __func__);
 	    break;
 	}
 	fsync(cdata->socket);
     }
 
-    if (verbose >= 2) fprintf(stderr, "%s[%d:%d]: terminated\n", __func__, cdata->dev->device_id, cdata->dev->use_count);
+    if (verbose >= 3) logmsg(LOG_NOTICE, "%s[%d:%d]: terminated", __func__, cdata->dev->device_id, cdata->dev->use_count);
 
     cdata->reader_dead = 1;
 
@@ -289,21 +329,21 @@ static int usbmuxd_handleConnectResult(struct client_data *cdata)
     iphone_error_t err;
 
     if (!cdata) {
-	if (verbose >= 2) fprintf(stderr, "%s: Invalid client_data provided!\n", __func__);
+	if (verbose >= 2) logmsg(LOG_ERR, "%s: Invalid client_data provided!", __func__);
 	return -EINVAL;
     }
 
     result = check_fd(cdata->socket, FD_WRITE, DEFAULT_TIMEOUT);
     if (result <= 0) {
 	if (result < 0) {
-	    if (verbose >= 2) fprintf(stderr, "%s: select error: %s\n", __func__, strerror(errno));
+	    if (verbose >= 2) logmsg(LOG_ERR, "%s: select error: %s", __func__, strerror(errno));
 	    return result;
 	}
     } else {
 	result = 0;
 	err = iphone_mux_recv_timeout(cdata->muxclient, buffer, maxlen, &rlen, 100);
 	if (err != 0) {
-	    if (verbose >= 2) fprintf(stderr, "%s: encountered USB read error: %d\n", __func__, err);
+	    if (verbose >= 2) logmsg(LOG_ERR, "%s: encountered USB read error: %d", __func__, err);
 	    usbmuxd_send_result(cdata->socket, cdata->tag, -err);
 	    return err;
 	} else {
@@ -311,7 +351,7 @@ static int usbmuxd_handleConnectResult(struct client_data *cdata)
 		if ((buffer[0] == 1) && (rlen > 20) && !memcmp(buffer+1, "handleConnectResult:", 20)) {
 		    // hm... we got an error message!
 		    buffer[rlen] = 0;
-		    if (verbose >= 1) fprintf(stderr, "%s: %s\n", __func__, buffer+22);
+		    if (verbose >= 1) logmsg(LOG_ERR, "%s: %s\n", __func__, buffer+22);
 
 		    if (sscanf(buffer+22, "%s - %d\n", err_type, &err_code) == 2) {
 			usbmuxd_send_result(cdata->socket, cdata->tag, err_code);
@@ -352,26 +392,26 @@ static void *usbmuxd_client_handler_thread(void *arg)
     iphone_error_t err;
 
     if (!arg) {
-	if (verbose >= 3) fprintf(stderr, "%s: invalid client_data provided!\n", __func__);
+	if (verbose >= 2) logmsg(LOG_ERR, "%s: invalid client_data provided!", __func__);
 	return NULL;
     }
 
     cdata = (struct client_data*)arg;
 
-    if (verbose >= 2) fprintf(stderr, "%s[%d:%d]: started\n", __func__, cdata->dev->device_id,cdata->dev->use_count);
+    if (verbose >= 3) logmsg(LOG_NOTICE, "%s[%d:%d]: started", __func__, cdata->dev->device_id,cdata->dev->use_count);
 
     if (usbmuxd_handleConnectResult(cdata)) {
-	if (verbose >= 3) fprintf(stderr, "handleConnectResult: Error\n");
+	if (verbose >= 3) logmsg(LOG_ERR, "handleConnectResult: Error");
 	goto leave;
     } else {
-    	if (verbose >= 3) fprintf(stderr, "handleConnectResult: Success\n");
+    	if (verbose >= 3) logmsg(LOG_NOTICE, "handleConnectResult: Success");
     }
 
     // starting mux reader thread
     cdata->reader_quit = 0;
     cdata->reader_dead = 0;
     if (pthread_create(&cdata->reader, NULL, usbmuxd_client_reader_thread, cdata) != 0) {
-	if (verbose >= 2) fprintf(stderr, "%s: could not start client_reader thread\n", __func__);
+	if (verbose >= 2) logmsg(LOG_ERR, "%s: could not start client_reader thread", __func__);
 	cdata->reader = 0;
     }
 
@@ -379,7 +419,7 @@ static void *usbmuxd_client_handler_thread(void *arg)
 	result = check_fd(cdata->socket, FD_READ, DEFAULT_TIMEOUT);
 	if (result <= 0) {
 	    if (result < 0) {
-		if (verbose >= 3) fprintf(stderr, "%s: Error: checkfd: %s\n", __func__, strerror(errno));
+		if (verbose >= 3) logmsg(LOG_ERR, "%s: Error: checkfd: %s", __func__, strerror(errno));
 	    }
 	    continue;
 	}
@@ -391,7 +431,7 @@ static void *usbmuxd_client_handler_thread(void *arg)
 	     break;
 	}
 	if (len < 0) {
-	    if (verbose >= 2) fprintf(stderr, "%s[%d:%d]: Error: recv: %s\n", __func__, cdata->dev->device_id, cdata->dev->use_count, strerror(errno));
+	    if (verbose >= 2) logmsg(LOG_ERR, "%s[%d:%d]: Error: recv: %s", __func__, cdata->dev->device_id, cdata->dev->use_count, strerror(errno));
 	    break;
 	}
 
@@ -404,7 +444,7 @@ static void *usbmuxd_client_handler_thread(void *arg)
 	    if (err == IPHONE_E_TIMEOUT) {
 		// some kind of timeout... just be patient and retry.
 	    } else if (err != IPHONE_E_SUCCESS) {
-		if (verbose >= 2) fprintf(stderr, "%s[%d:%d]: USB write error: %d\n", __func__, cdata->dev->device_id, cdata->dev->use_count, err);
+		if (verbose >= 2) logmsg(LOG_ERR, "%s[%d:%d]: USB write error: %d", __func__, cdata->dev->device_id, cdata->dev->use_count, err);
 		len = -1;
 		break;
 	    }
@@ -422,7 +462,7 @@ static void *usbmuxd_client_handler_thread(void *arg)
 
 leave:
     // cleanup
-    if (verbose >= 3) fprintf(stderr, "%s[%d:%d]: terminating\n", __func__, cdata->dev->device_id, cdata->dev->use_count);
+    if (verbose >= 3) logmsg(LOG_NOTICE, "%s[%d:%d]: terminating", __func__, cdata->dev->device_id, cdata->dev->use_count);
     if (cdata->reader != 0) {
 	cdata->reader_quit = 1;
 	pthread_join(cdata->reader, NULL);
@@ -430,7 +470,7 @@ leave:
 
     cdata->handler_dead = 1;
 
-    if (verbose >= 3) fprintf(stderr, "%s[%d:%d]: terminated\n", __func__, cdata->dev->device_id, cdata->dev->use_count);
+    if (verbose >= 3) logmsg(LOG_NOTICE, "%s[%d:%d]: terminated", __func__, cdata->dev->device_id, cdata->dev->use_count);
     return NULL;
 }
 
@@ -444,13 +484,13 @@ static void *usbmuxd_bulk_reader_thread(void *arg)
     int err;
 
     if (!arg) {
-	if (verbose >= 3) fprintf(stderr, "%s: Invalid client_data provided\n", __func__);
+	if (verbose >= 2) logmsg(LOG_ERR, "%s: Invalid client_data provided", __func__);
 	return NULL;
     }
 
     cur_dev = (struct device_info*)arg;
 
-    if (verbose >= 5) fprintf(stderr, "%s: started\n", __func__);
+    if (verbose >= 3) logmsg(LOG_NOTICE, "%s: started", __func__);
 
     while (!quit_flag && cur_dev) {
 
@@ -462,12 +502,12 @@ static void *usbmuxd_bulk_reader_thread(void *arg)
 	pthread_mutex_unlock(&cur_dev->mutex);
 
 	if ((err = iphone_mux_pullbulk(cur_dev->phone)) < 0) {
-	    if (verbose >= 1) fprintf(stderr, "%s: error %d when reading from device\n", __func__, err);
+	    if (verbose >= 1) logmsg(LOG_ERR, "%s: error %d when reading from device", __func__, err);
 	    break;
 	}
     }
 
-    if (verbose >= 0) fprintf(stderr, "%s: terminated\n", __func__);
+    if (verbose >= 3) logmsg(LOG_NOTICE, "%s: terminated", __func__);
 
     return NULL;
 }
@@ -498,24 +538,24 @@ static void *usbmuxd_client_init_thread(void *arg)
     struct device_info *cur_dev = NULL;
 
     if (!arg) {
-	if (verbose >= 1) fprintf(stderr, "%s: invalid client_data provided!\n", __func__);
+	if (verbose >= 1) logmsg(LOG_ERR, "%s[%x]: invalid client_data provided!", __func__, THREAD);
 	return NULL;
     }
 
     cdata = (struct client_data*)arg;
     cdata->dead = 0;
     
-    if (verbose >= 2) fprintf(stderr, "%s: started (fd=%d)\n", __func__, cdata->socket);
+    if (verbose >= 3) logmsg(LOG_NOTICE, "%s[%x]: started (fd=%d)", __func__, THREAD, cdata->socket);
 
     if ((recv_len = usbmuxd_get_request(cdata->socket, (void**)&s_req, 0)) <= 0) {
-        if (verbose >= 2) fprintf(stderr, "%s: No scan packet received, error %s\n", __func__, strerror(errno));
+        if (verbose >= 2) logmsg(LOG_ERR, "%s[%x]: No scan packet received, error %s", __func__, THREAD, strerror(errno));
 	goto leave;
     }
 
     if ((recv_len == sizeof(struct usbmuxd_scan_request)) && (s_req->header.length == sizeof(struct usbmuxd_scan_request))
 	&& (s_req->header.reserved == 0) && (s_req->header.type == USBMUXD_SCAN)) {
     	// send success response
-	if (verbose >= 3) fprintf(stderr, "%s: Got scan packet!\n", __func__);
+	if (verbose >= 3) logmsg(LOG_NOTICE, "%s[%x]: Got scan packet!", __func__, THREAD);
 	usbmuxd_send_result(cdata->socket, s_req->header.tag, 0);
     } else if ((recv_len == sizeof(struct usbmuxd_connect_request)) && (s_req->header.type == USBMUXD_CONNECT)) {
 	c_req = (struct usbmuxd_connect_request*)s_req;
@@ -523,7 +563,7 @@ static void *usbmuxd_client_init_thread(void *arg)
 	goto connect;
     } else {
 	// send error response and exit
-        if (verbose >= 2) fprintf(stderr, "%s: Invalid scan packet received.\n", __func__);
+        if (verbose >= 2) logmsg(LOG_ERR, "%s[%x]: Invalid scan packet received.", __func__, THREAD);
 	// TODO is this required?!
 	usbmuxd_send_result(cdata->socket, s_req->header.tag, EINVAL);
 	goto leave;
@@ -532,14 +572,14 @@ static void *usbmuxd_client_init_thread(void *arg)
     pthread_mutex_lock(&usb_mutex);
     // gather data about all iPhones/iPods attached
    
-    if (verbose >= 5) fprintf(stderr, "%s: usb init\n", __func__);
+    if (verbose >= 5) logmsg(LOG_DEBUG, "%s[%x]: usb init", __func__, THREAD);
     usb_init();
-    if (verbose >= 5) fprintf(stderr, "%s: usb find busses\n", __func__);
+    if (verbose >= 5) logmsg(LOG_DEBUG, "%s[%x]: usb find busses", __func__, THREAD);
     usb_find_busses();
-    if (verbose >= 5) fprintf(stderr, "%s: usb find devices\n", __func__);
+    if (verbose >= 5) logmsg(LOG_DEBUG, "%s[%x]: usb find devices", __func__, THREAD);
     usb_find_devices();
 
-    if (verbose >= 2) fprintf(stderr, "%s: Looking for attached devices...\n", __func__);
+    if (verbose >= 2) logmsg(LOG_NOTICE, "%s[%x]: Looking for attached devices...", __func__, THREAD);
 
     for (bus = usb_get_busses(); bus; bus = bus->next) {
 	for (dev = bus->devices; dev; dev = dev->next) {
@@ -547,7 +587,7 @@ static void *usbmuxd_client_init_thread(void *arg)
 		&& dev->descriptor.idProduct >= 0x1290
 		&& dev->descriptor.idProduct <= 0x1293)
 	    {
-		if (verbose >= 1) fprintf(stderr, "%s: Found device on bus %d, id %d\n", __func__, bus->location, dev->devnum);
+		if (verbose >= 1) logmsg(LOG_NOTICE, "%s[%x]: Found device on bus %d, id %d", __func__, THREAD, bus->location, dev->devnum);
 		found++;
 
 		// construct packet
@@ -573,7 +613,7 @@ static void *usbmuxd_client_init_thread(void *arg)
 
 		// send it
 		if (send_buf(cdata->socket, &dev_info_rec, sizeof(dev_info_rec)) <= 0) {
-		    if (verbose >= 3) fprintf(stderr, "%s: Error: Could not send device info: %s\n", __func__, strerror(errno));
+		    if (verbose >= 3) logmsg(LOG_ERR, "%s[%x]: Error: Could not send device info: %s", __func__, THREAD, strerror(errno));
 		    found--;
 		}
 	    }
@@ -582,27 +622,27 @@ static void *usbmuxd_client_init_thread(void *arg)
     pthread_mutex_unlock(&usb_mutex);
 
     if (found <= 0) {
-	if (verbose >= 1) fprintf(stderr, "%s: No attached iPhone/iPod devices found.\n", __func__);
+	if (verbose >= 1) logmsg(LOG_NOTICE, "%s[%x]: No attached iPhone/iPod devices found.", __func__, THREAD);
 	goto leave;
     }
 
-    if (verbose >= 2) fprintf(stderr, "%s: Waiting for connect request\n", __func__);
+    if (verbose >= 3) logmsg(LOG_NOTICE, "%s[%x]: Waiting for connect request", __func__, THREAD);
 
     // now wait for connect request
     //memset(&c_req, 0, sizeof(c_req));
     if ((recv_len = usbmuxd_get_request(cdata->socket, (void**)&c_req, 0)) <= 0) {
-	if (verbose >= 3) fprintf(stderr, "%s: Did not receive any connect request.\n", __func__);
+	if (verbose >= 3) logmsg(LOG_NOTICE, "%s[%x]: Did not receive any connect request.", __func__, THREAD);
 	goto leave;
     }
 
 connect:
 
     if (c_req->header.type != USBMUXD_CONNECT) {
-	if (verbose >= 2) fprintf(stderr, "%s: Unexpected packet of type %d received.\n", __func__, c_req->header.type);
+	if (verbose >= 2) logmsg(LOG_ERR, "%s[%x]: Unexpected packet of type %d received.", __func__, THREAD, c_req->header.type);
 	goto leave;
     }
 
-    if (verbose >= 3) fprintf(stderr, "%s: Setting up connection to usb device #%d on port %d\n", __func__, c_req->device_id, ntohs(c_req->tcp_dport));
+    if (verbose >= 3) logmsg(LOG_NOTICE, "%s[%x]: Setting up connection to usb device #%d on port %d", __func__, THREAD, c_req->device_id, ntohs(c_req->tcp_dport));
 
     // find the device, and open usb connection
     pthread_mutex_lock(&usbmux_mutex);
@@ -623,20 +663,20 @@ connect:
     }
     if (!phone) {
 	// if not found, make a new connection
-	if (verbose >= 2) fprintf(stderr, "%s: creating new usb connection, device_id=%d\n", __func__, c_req->device_id);
+	if (verbose >= 2) logmsg(LOG_NOTICE, "%s[%x]: creating new usb connection, device_id=%d", __func__, THREAD, c_req->device_id);
 
 	pthread_mutex_lock(&usb_mutex);
 	if (iphone_get_specific_device(0, c_req->device_id, &phone) != IPHONE_E_SUCCESS) {
 	    pthread_mutex_unlock(&usb_mutex);
     	    pthread_mutex_unlock(&usbmux_mutex);
-	    if (verbose >= 1) fprintf(stderr, "%s: device_id %d could not be opened\n", __func__, c_req->device_id);
+	    if (verbose >= 1) logmsg(LOG_ERR, "%s[%x]: device_id %d could not be opened", __func__, THREAD, c_req->device_id);
 	    usbmuxd_send_result(cdata->socket, c_req->header.tag, ENODEV);
 	    goto leave;
 	}
 	pthread_mutex_unlock(&usb_mutex);
 	
 	// create device object
-	if (verbose >= 3) fprintf(stderr, "%s: add to device list\n", __func__);
+	if (verbose >= 3) logmsg(LOG_DEBUG, "%s[%x]: add to device list", __func__, THREAD);
 	cur_dev = (struct device_info*)malloc(sizeof(struct device_info));
 	memset(cur_dev, 0, sizeof(struct device_info));
 	cur_dev->use_count = 1;
@@ -646,7 +686,7 @@ connect:
 	pthread_mutex_init(&cur_dev->mutex, NULL);
 	pthread_mutex_init(&cur_dev->writer_mutex, NULL);
 
-	if (verbose >= 3) fprintf(stderr, "%s: device_count = %d\n", __func__, device_count);
+	if (verbose >= 3) logmsg(LOG_DEBUG, "%s[%x]: device_count = %d", __func__, THREAD, device_count);
 
 	// add to list of devices
 	devices = (struct device_info**)realloc(devices, sizeof(struct device_info*) * (device_count+1));
@@ -655,7 +695,7 @@ connect:
 	    device_count++;
 	}
     } else {
-	if (verbose >= 3) fprintf(stderr, "%s: reusing usb connection, device_id=%d\n", __func__, c_req->device_id);
+	if (verbose >= 2) logmsg(LOG_NOTICE, "%s[%x]: reusing usb connection, device_id=%d", __func__, THREAD, c_req->device_id);
     }
     pthread_mutex_unlock(&usbmux_mutex);
 
@@ -666,7 +706,7 @@ connect:
 
     if (res != 0) {
 	usbmuxd_send_result(cdata->socket, c_req->header.tag, res);
-	if (verbose >= 1) fprintf(stderr, "%s: mux_new_client returned %d, aborting.\n", __func__, res);
+	if (verbose >= 1) logmsg(LOG_ERR, "%s[%x]: mux_new_client returned %d, aborting.", __func__, THREAD, res);
 	goto leave;
     }
 
@@ -682,7 +722,7 @@ connect:
     cdata->tag = c_req->header.tag;
     cdata->dev = cur_dev;
     if (pthread_create(&cdata->handler, NULL, usbmuxd_client_handler_thread, cdata) != 0) {
-	if (verbose >= 3) fprintf(stderr, "%s: could not create usbmuxd_client_handler_thread!\n", __func__);
+	if (verbose >= 1) logmsg(LOG_ERR, "%s[%x]: could not create usbmuxd_client_handler_thread!", __func__, THREAD);
 	cdata->handler = 0;
 	goto leave;
     }
@@ -692,7 +732,7 @@ connect:
     	pthread_join(cdata->handler, NULL);
     }
     
-    if (verbose >= 2) fprintf(stderr, "%s: closing connection\n", __func__);
+    if (verbose >= 2) logmsg(LOG_NOTICE, "%s[%x]: closing connection", __func__, THREAD);
 
     // time to clean up
     if (cdata && cdata->muxclient) { // should be non-NULL
@@ -700,7 +740,7 @@ connect:
     }
 
 leave:
-    if (verbose >= 2) fprintf(stderr, "%s: terminating\n", __func__);
+    if (verbose >= 3) logmsg(LOG_NOTICE, "%s[%x]: terminating", __func__, THREAD);
 
     if (s_req) {
 	free(s_req);
@@ -715,15 +755,15 @@ leave:
     if (cur_dev) {
 	pthread_mutex_lock(&cur_dev->mutex);
 	if (cur_dev->use_count > 1) {
-	    if (verbose >= 0) fprintf(stderr, "%s: decreasing device use count (from %d to %d)\n", __func__, cur_dev->use_count, cur_dev->use_count-1);
+	    if (verbose >= 2) logmsg(LOG_NOTICE, "%s[%x]: decreasing device use count (from %d to %d)", __func__, THREAD, cur_dev->use_count, cur_dev->use_count-1);
 	    cur_dev->use_count--;
 	    pthread_mutex_unlock(&cur_dev->mutex);
 	} else {
-	    if (verbose >= 3) fprintf(stderr, "%s: last client disconnected, cleaning up\n", __func__);
+	    if (verbose >= 2) logmsg(LOG_NOTICE, "%s[%x]: last client disconnected, cleaning up", __func__, THREAD);
 	    cur_dev->use_count = 0;
 	    pthread_mutex_unlock(&cur_dev->mutex);
 	    if (cur_dev->bulk_reader != 0) {
-		fprintf(stderr, "%s: joining bulk_reader...\n", __func__);
+		if (verbose >= 3) logmsg(LOG_NOTICE, "%s[%x]: joining bulk_reader...", __func__, THREAD);
 		pthread_join(cur_dev->bulk_reader, NULL);
 	    }
 	    pthread_mutex_lock(&usb_mutex);
@@ -758,7 +798,7 @@ leave:
     cdata->dead = 1;
     close(cdata->socket);
     
-    if (verbose >= 5) fprintf(stderr, "%s: terminated\n", __func__);
+    if (verbose >= 3) logmsg(LOG_NOTICE, "%s[%x]: terminated", __func__, THREAD);
 
     return NULL;
 }
@@ -819,38 +859,6 @@ static void clean_exit(int sig)
     quit_flag = 1;
 }
 
-static void logmsg(int prio, char *format, ...)
-{
-    va_list args;
-    va_start(args, format);
-
-    if (!foreground) {
-	// daemon. log using syslog.
-	vsyslog(prio, format, args);
-    } else {
-	// running in foreground. log to stdout/stderr.
-	char msgbuf[256];
-	FILE *lfp = stdout;
-	switch(prio) {
-	    case LOG_EMERG:
-	    case LOG_ALERT:
-	    case LOG_CRIT:
-	    case LOG_ERR:
-	    case LOG_WARNING:
-		lfp = stderr;
-		break;
-	    default:
-		lfp = stdout;
-	}
-	strcpy(msgbuf, "usbmuxd: ");
-	vsnprintf(msgbuf+9, 244, format, args);
-	strcat(msgbuf, "\n");
-	fputs(msgbuf, lfp);
-    }
-
-    va_end(args);
-}
-
 static void usage()
 {
     printf("usage: usbmuxd [options]\n");
@@ -1107,7 +1115,7 @@ int main(int argc, char **argv)
     if (verbose >= 3) logmsg(LOG_NOTICE, "terminating");
 
     // preparing for shutdown: wait for child threads to terminate (if any)
-    if (verbose >= 2) fprintf(stderr, "usbmuxd: waiting for child threads to terminate...\n");
+    if (verbose >= 2) logmsg(LOG_NOTICE, "waiting for child threads to terminate...");
     for (i = 0; i < children_capacity; i++) {
         if (children[i] != NULL) {
 	    pthread_join(children[i]->thread, NULL);