Add some diagnostics, shorten timeouts and set so_linger of zero whenever a write...

diff --git a/dacp.c b/dacp.c
index 04821650daa4e2ed7db5d5b4661ca121d431eeec..f1c91e48c9d6c8a9b40aaa22656cadebb2328ddd 100644 (file)
--- a/dacp.c
+++ b/dacp.c
@@ -127,9 +127,9 @@ void addrinfo_cleanup(void *arg) {
 }
 
 void mutex_lock_cleanup(void *arg) {
-  // debug(1, "mutex lock cleanup called.");
   pthread_mutex_t *m = (pthread_mutex_t *)arg;
-  pthread_mutex_unlock(m);
+  if (pthread_mutex_unlock(m))
+       debug(1,"Error releasing mutex.");
 }
 
 void connect_cleanup(void *arg) {
@@ -193,6 +193,7 @@ int dacp_send_command(const char *command, char **body, ssize_t *bodysize) {
     // debug(1,"Error %d \"%s\" at getaddrinfo.",ires,gai_strerror(ires));
     response.code = 498; // Bad Address information for the DACP server
   } else {
+    uint64_t start_time = get_absolute_time_in_fp();
     pthread_cleanup_push(addrinfo_cleanup, (void *)&res);
     // only do this one at a time -- not sure it is necessary, but better safe than sorry
 
@@ -200,7 +201,6 @@ int dacp_send_command(const char *command, char **body, ssize_t *bodysize) {
     // int mutex_reply = pthread_mutex_lock(&dacp_conversation_lock);
     if (mutex_reply == 0) {
       pthread_cleanup_push(mutex_lock_cleanup, (void *)&dacp_conversation_lock);
-      // debug(1,"dacp_conversation_lock acquired for command \"%s\".",command);
 
       // make a socket:
       sockfd = socket(res->ai_family, res->ai_socktype, res->ai_protocol);
@@ -213,8 +213,8 @@ int dacp_send_command(const char *command, char **body, ssize_t *bodysize) {
         // debug(2, "dacp_send_command: open socket %d.",sockfd);
 
         struct timeval tv;
-        tv.tv_sec = 2;
-        tv.tv_usec = 0;
+        tv.tv_sec = 0;
+        tv.tv_usec = 80000;
         if (setsockopt(sockfd, SOL_SOCKET, SO_RCVTIMEO, (const char *)&tv, sizeof tv) == -1)
           debug(1, "dacp_send_command: error %d setting receive timeout.", errno);
         if (setsockopt(sockfd, SOL_SOCKET, SO_SNDTIMEO, (const char *)&tv, sizeof tv) == -1)
@@ -223,7 +223,7 @@ int dacp_send_command(const char *command, char **body, ssize_t *bodysize) {
         // connect!
         // debug(1, "DACP socket created.");
         if (connect(sockfd, res->ai_addr, res->ai_addrlen) < 0) {
-          // debug(2, "dacp_send_command: connect failed with errno %d.", errno);
+          debug(3, "dacp_send_command: connect failed with errno %d.", errno);
           response.code = 496; // Can't connect to the DACP server
         } else {
           // debug(1,"DACP connect succeeded.");
@@ -233,13 +233,26 @@ int dacp_send_command(const char *command, char **body, ssize_t *bodysize) {
                    command, dacp_server.ip_string, dacp_server.port, dacp_server.active_remote_id);
 
           // Send command
-          // debug(3,"dacp_send_command: connect message: \"%s\".",message);
-          if (send(sockfd, message, strlen(message), 0) != (ssize_t)strlen(message)) {
-            debug(1, "dacp_send_command: send failed.");
+          debug(3,"dacp_send_command: \"%s\".",command);
+          ssize_t wresp = send(sockfd, message, strlen(message), 0);
+          if (wresp == -1) {
+                                               char errorstring[1024];
+                                               strerror_r(errno, (char *)errorstring, sizeof(errorstring));
+                                               debug(2, "dacp_send_command: write error %d: \"%s\".", errno, (char *)errorstring);
+                                               struct linger so_linger;
+                                               so_linger.l_onoff = 1; // "true"
+                                               so_linger.l_linger = 0;
+                                               int err = setsockopt(sockfd, SOL_SOCKET, SO_LINGER, &so_linger, sizeof so_linger);
+                                               if (err)
+                                                       debug(1, "Could not set the dacp socket to abort due to a write error on closing.");
+                                       }         
+          if (wresp != (ssize_t)strlen(message)) {
+            // debug(1, "dacp_send_command: send failed.");
             response.code = 493; // Client failed to send a message
 
           } else {
 
+
             response.body = malloc(2048); // it can resize this if necessary
             response.malloced_size = 2048;
             pthread_cleanup_push(malloc_cleanup, response.body);
@@ -256,11 +269,21 @@ int dacp_send_command(const char *command, char **body, ssize_t *bodysize) {
               const char *data = buffer;
               if (setsockopt(sockfd, SOL_SOCKET, SO_RCVTIMEO, (const char *)&tv, sizeof tv) == -1)
                 debug(1, "dacp_send_command: error %d setting receive timeout.", errno);
-              int ndata = recv(sockfd, buffer, sizeof(buffer), 0);
+              ssize_t ndata = recv(sockfd, buffer, sizeof(buffer), 0);
               // debug(3, "Received %d bytes: \"%s\".", ndata, buffer);
               if (ndata <= 0) {
-                // debug(1, "dacp_send_command -- error receiving response for command \"%s\".",
-                //      command);
+               if (ndata == -1) {
+                                                                       char errorstring[1024];
+                                                                       strerror_r(errno, (char *)errorstring, sizeof(errorstring));                            
+                       debug(2, "dacp_send_command: receiving error %d: \"%s\".", errno,(char *)errorstring);
+                                                                       struct linger so_linger;
+                                                                       so_linger.l_onoff = 1; // "true"
+                                                                       so_linger.l_linger = 0;
+                                                                       int err = setsockopt(sockfd, SOL_SOCKET, SO_LINGER, &so_linger, sizeof so_linger);
+                                                                       if (err)
+                                                                               debug(1, "Could not set the dacp socket to abort due to a read error on closing.");
+               }
+              
                 free(response.body);
                 response.body = NULL;
                 response.malloced_size = 0;
@@ -308,6 +331,9 @@ int dacp_send_command(const char *command, char **body, ssize_t *bodysize) {
     }
     pthread_cleanup_pop(1); // this should free the addrinfo
     // freeaddrinfo(res);
+               uint64_t et = get_absolute_time_in_fp() - start_time;
+               et = (et * 1000000) >> 32; // microseconds
+               debug(2,"dacp_send_command: %f seconds, response code %d, command \"%s\".",(1.0 * et) / 1000000, response.code, command);
   }
   *body = response.body;
   *bodysize = response.size;
@@ -829,6 +855,8 @@ void dacp_monitor_start() {
   rc = pthread_mutex_init(&dacp_conversation_lock, &mta);
   if (rc)
     debug(1, "Error creating the DACP Conversation Lock Mutex Init");
+  else
+       debug(1, "DACP Conversation Lock Mutex Init");
 
   rc = pthread_mutexattr_destroy(&mta);
   if (rc)
@@ -864,6 +892,7 @@ void dacp_monitor_stop() {
   pthread_cancel(dacp_monitor_thread);
   pthread_join(dacp_monitor_thread, NULL);
   pthread_mutex_destroy(&dacp_server_information_lock);
+  debug(1, "DACP Conversation Lock Mutex Destroyed");
   pthread_mutex_destroy(&dacp_conversation_lock);
 }