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