From b9a16b92f08e69c196408fc95291bcc3ee783c6e Mon Sep 17 00:00:00 2001
From: Philipp Schafft <lion@lion.leolix.org>
Date: Mon, 7 Mar 2022 11:19:21 +0000
Subject: [PATCH] Update: Improved debug logging for connection and socket
 handling

---
 src/client.c       | 17 +++++++++++------
 src/connection.c   |  4 +++-
 src/listensocket.c |  8 ++++----
 3 files changed, 18 insertions(+), 11 deletions(-)

diff --git a/src/client.c b/src/client.c
index f9eead46..7edb5ada 100644
--- a/src/client.c
+++ b/src/client.c
@@ -175,10 +175,11 @@ int client_create(client_t **c_ptr, connection_t *con, http_parser_t *parser)
 
     listener_real = listensocket_get_listener(con->listensocket_real);
     listener_effective = listensocket_get_listener(con->listensocket_effective);
-    ICECAST_LOG_DEBUG("Client %p created on connection %p (connection ID: %llu, socket real: %p \"%H\", socket effective: %p \"%H\")",
-            client, con, (long long unsigned int)con->id,
+    ICECAST_LOG_DEBUG("Client %p created on connection %p (connection ID: %llu, sock=%R, socket real: %p (%#H), socket effective: %p (%#H); global: %d of %d)",
+            client, con, (long long unsigned int)con->id, con->sock,
             con->listensocket_real, con->listensocket_real ? listener_real->id : NULL,
-            con->listensocket_effective, con->listensocket_effective ? listener_effective->id : NULL
+            con->listensocket_effective, con->listensocket_effective ? listener_effective->id : NULL,
+            global.clients, config->client_limit
             );
     listensocket_release_listener(con->listensocket_effective);
     listensocket_release_listener(con->listensocket_real);
@@ -260,8 +261,9 @@ static inline void client_reuseconnection(client_t *client) {
         return;
     }
 
+    ICECAST_LOG_DEBUG("Reusing connection %p (connection ID: %llu, sock=%R) of old client %p", con, (long long unsigned int)con->id, con->sock, client);
     con = connection_create(con->sock, con->listensocket_real, con->listensocket_effective, strdup(con->ip));
-    client->con->sock = -1; /* TODO: do not use magic */
+    client->con->sock = SOCK_ERROR;
 
     /* handle to keep the TLS connection */
     if (client->con->tls) {
@@ -294,9 +296,12 @@ static inline void client_reuseconnection(client_t *client) {
 
 void client_destroy(client_t *client)
 {
-    ICECAST_LOG_DEBUG("Called to destory client %p", client);
-    if (client == NULL)
+    if (client == NULL) {
+        ICECAST_LOG_ERROR("Called with client=NULL. This is a BUG.");
         return;
+    }
+
+    ICECAST_LOG_DEBUG("Called to destory client %p on connection %p (connection ID: %llu, sock=%R)", client, client->con, (long long unsigned int)client->con->id, client->con->sock);
 
     fastevent_emit(FASTEVENT_TYPE_CLIENT_DESTROY, FASTEVENT_FLAG_MODIFICATION_ALLOWED, FASTEVENT_DATATYPE_CLIENT, client);
 
diff --git a/src/connection.c b/src/connection.c
index 7c7a9066..7d926d48 100644
--- a/src/connection.c
+++ b/src/connection.c
@@ -1767,10 +1767,12 @@ void connection_close(connection_t *con)
     if (!con)
         return;
 
+    ICECAST_LOG_DEBUG("Closing connection %p (connection ID: %llu, sock=%R)", con, (long long unsigned int)con->id, con->sock);
+
     fastevent_emit(FASTEVENT_TYPE_CONNECTION_DESTROY, FASTEVENT_FLAG_MODIFICATION_ALLOWED, FASTEVENT_DATATYPE_CONNECTION, con);
 
     tls_unref(con->tls);
-    if (con->sock != -1) /* TODO: do not use magic */
+    if (con->sock != SOCK_ERROR)
         sock_close(con->sock);
     if (con->ip)
         free(con->ip);
diff --git a/src/listensocket.c b/src/listensocket.c
index ab2fd1cb..381dbece 100644
--- a/src/listensocket.c
+++ b/src/listensocket.c
@@ -774,17 +774,17 @@ connection_t *              listensocket_accept(listensocket_t *self, listensock
         return NULL;
     }
 
+    ICECAST_LOG_DEBUG("Client (sock=%R, ip=%#H) on socket %p (%#H).", sock, ip, self, self->listener->id);
+
     if (strncmp(ip, "::ffff:", 7) == 0) {
         memmove(ip, ip+7, strlen(ip+7)+1);
     }
 
-    ICECAST_LOG_DEBUG("Client on socket %p \"%H\".", self, self->listener->id);
-
     if (self->listener->on_behalf_of) {
-        ICECAST_LOG_DEBUG("This socket is acting on behalf of \"%H\"", self->listener->on_behalf_of);
+        ICECAST_LOG_DEBUG("This socket is acting on behalf of %#H", self->listener->on_behalf_of);
         effective = listensocket_container_get_by_id(container, self->listener->on_behalf_of);
         if (!effective) {
-            ICECAST_LOG_ERROR("Can not find listen socket with ID \"%H\". Will continue on behalf of myself.", self->listener->on_behalf_of);
+            ICECAST_LOG_ERROR("Can not find listen socket with ID %#H. Will continue on behalf of myself.", self->listener->on_behalf_of);
         }
     }