Logging fixes

diff --git a/src/channel.c b/src/channel.c
index db5cfaa4c0e1e5aff595bd029be368dd0b784e20..c308dc4d403959ab02ce68bc22ce05c2d8573ba3 100644 (file)
--- a/src/channel.c
+++ b/src/channel.c
@@ -212,7 +212,7 @@ void Chan_init()
                        ch_dst = ch_itr;
                
                list_add_tail(&ch_dst->link_node, &ch_src->channel_links);
-               Log_info("Adding channel link %s -> %s", ch_src->name, ch_dst->name);
+               Log_info("Adding channel link '%s' -> '%s'", ch_src->name, ch_dst->name);
        }
 }
 
@@ -223,7 +223,7 @@ void Chan_free()
        
        list_iterate_safe(itr, save, &channels) {
                ch = list_get_entry(itr, channel_t, flatlist_node);
-               Log_debug("Free channel %s", ch->name);
+               Log_debug("Free channel '%s'", ch->name);
                free(ch->name);
                if (ch->desc)
                        free(ch->desc);

diff --git a/src/client.c b/src/client.c
index 68252dc13da5a03360ed9be17f515a2daedc831d..a1f957d9e4234922b008b639550e6cf4f79717ad 100644 (file)
--- a/src/client.c
+++ b/src/client.c
@@ -99,11 +99,7 @@ void Client_janitor()
                
                if (Timer_isElapsed(&c->lastActivity, 1000000LL * INACTICITY_TIMEOUT)) {
                        /* No activity from client - assume it is lost and close. */
-                       Log_info("Timeout, closing session %d - %s@%s:%d",
-                                        c->sessionId,
-                                        c->playerName,
-                                        inet_ntoa(c->remote_tcp.sin_addr),
-                                        ntohs(c->remote_tcp.sin_port));
+                       Log_info_client(c, "Timeout, closing.");
                        Client_free(c);
                }
        }
@@ -180,7 +176,8 @@ int Client_add(int fd, struct sockaddr_in *remote)
        memcpy(&newclient->remote_tcp, remote, sizeof(struct sockaddr_in));
        newclient->ssl = SSL_newconnection(newclient->tcpfd, &newclient->SSLready);
        if (newclient->ssl == NULL) {
-               Log_warn("SSL negotiation failed");
+               Log_warn("SSL negotiation failed with %s:%d", inet_ntoa(remote->sin_addr),
+                                ntohs(remote->sin_port));
                free(newclient);
                return -1;
        }
@@ -213,12 +210,6 @@ void Client_free(client_t *client)
        struct dlist *itr, *save;
        message_t *sendmsg;
 
-       Log_info("Disconnect session %d - %s@%s:%d",
-                        client->sessionId,
-                        client->playerName,
-                        inet_ntoa(client->remote_tcp.sin_addr),
-                        ntohs(client->remote_tcp.sin_port));
-
        if (client->authenticated) {
                int leave_id;
                leave_id = Chan_playerLeave(client);
@@ -330,7 +321,7 @@ int Client_read(client_t *client)
                                        client->msgsize = ntohl(msgLen);
                                }
                                if (client->msgsize > BUFSIZE - 6 && client->drainleft == 0) {
-                                       Log_warn("Too big message received (%d). Discarding.", client->msgsize);
+                                       Log_info_client(client, "Too big message received (%d bytes). Discarding.", client->msgsize);
                                        client->rxcount = client->msgsize = 0;
                                        client->drainleft = client->msgsize;
                                }
@@ -351,7 +342,7 @@ int Client_read(client_t *client)
                                return 0;
                        }
                        else if (SSL_get_error(client->ssl, rc) == SSL_ERROR_ZERO_RETURN) {
-                               Log_warn("Error: Zero return - closing");
+                               Log_info_client(client, "Connection closed by peer");
                                if (!client->shutdown_wait)
                                        Client_close(client);
                        }
@@ -360,14 +351,10 @@ int Client_read(client_t *client)
                                        /* Hmm. This is where we end up when the client closes its connection.
                                         * Kind of strange...
                                         */
-                                       Log_info("Connection closed by peer. Session %d - %s@%s:%d",
-                                                        client->sessionId,
-                                                        client->playerName,
-                                                        inet_ntoa(client->remote_tcp.sin_addr),
-                                                        ntohs(client->remote_tcp.sin_port));
+                                       Log_info_client(client, "Connection closed by peer");
                                }
                                else {
-                                       Log_warn("SSL error: %d - Closing connection.", SSL_get_error(client->ssl, rc));
+                                       Log_info_client(client, "SSL error: %d - Closing connection", SSL_get_error(client->ssl, rc));
                                }
                                Client_free(client);
                                return -1;
@@ -521,12 +508,7 @@ static bool_t checkDecrypt(client_t *client, const uint8_t *encrypted, uint8_t *
                        Timer_restart(&client->cryptState.tLastRequest);
                        
                        sendmsg = Msg_create(CryptSetup);
-                       Log_info("Requesting voice channel crypt resync. Session %d - %s@%s:%d",
-                                        client->sessionId,
-                                        client->playerName,
-                                        inet_ntoa(client->remote_tcp.sin_addr),
-                                        ntohs(client->remote_tcp.sin_port));
-               
+                       Log_info_client(client, "Requesting voice channel crypt resync");               
                        Client_send_message(client, sendmsg);
                }
        }
@@ -591,11 +573,7 @@ int Client_read_udp()
                        if (itr->remote_tcp.sin_addr.s_addr == from.sin_addr.s_addr) {
                                if (checkDecrypt(itr, encrypted, buffer, len)) {
                                        itr->key = key;
-                                       Log_info("New UDP connection from session %d - %s@%s:%d",
-                                                        itr->sessionId,
-                                                        itr->playerName,
-                                                        inet_ntoa(from.sin_addr),
-                                                        ntohs(from.sin_port));
+                                       Log_info_client(itr, "New UDP connection port %d", ntohs(from.sin_port));
                                        memcpy(&itr->remote_udp, &from, sizeof(struct sockaddr_in));
                                        break;
                                }

diff --git a/src/log.c b/src/log.c
index f4a0ea117233f9e8bdd7a97dc35861a6d3eaae8c..273964120b121d37c160408050fc0c06da57b3af 100644 (file)
--- a/src/log.c
+++ b/src/log.c
@@ -37,7 +37,7 @@
 
 #include "log.h"
 
-#define BUFSIZE 254
+#define STRSIZE 254
 
 static bool_t termprint;
 
@@ -58,14 +58,14 @@ void Log_free()
 void logthis(const char *logstring, ...)
 {
        va_list argp;
-       char buf[BUFSIZE + 2];
+       char buf[STRSIZE + 2];
        
        va_start(argp, logstring);
-       vsnprintf(&buf[0], BUFSIZE, logstring, argp);
+       vsnprintf(&buf[0], STRSIZE, logstring, argp);
        va_end(argp);
        strcat(buf, "\n");
        if (termprint)
-               fprintf(stderr, "%s", buf); /* XXX - other targets for logging */
+               fprintf(stderr, "%s", buf);
        else
                syslog(LOG_INFO, buf);
 }
@@ -73,16 +73,16 @@ void logthis(const char *logstring, ...)
 void Log_warn(const char *logstring, ...)
 {
        va_list argp;
-       char buf[BUFSIZE + 2];
+       char buf[STRSIZE + 2];
        int offset = 0;
        
        va_start(argp, logstring);
        offset = sprintf(buf, "WARN: ");
-       vsnprintf(&buf[offset], BUFSIZE - offset, logstring, argp);
+       vsnprintf(&buf[offset], STRSIZE - offset, logstring, argp);
        va_end(argp);
        strcat(buf, "\n");
        if (termprint)
-               fprintf(stderr, "%s", buf); /* XXX - other targets for logging */
+               fprintf(stderr, "%s", buf);
        else
                syslog(LOG_WARNING, buf);
 }
@@ -90,34 +90,56 @@ void Log_warn(const char *logstring, ...)
 void Log_info(const char *logstring, ...)
 {
        va_list argp;
-       char buf[BUFSIZE + 2];
+       char buf[STRSIZE + 2];
        int offset = 0;
        
        va_start(argp, logstring);
        offset = sprintf(buf, "INFO: ");
-       vsnprintf(&buf[offset], BUFSIZE - offset, logstring, argp);
+       vsnprintf(&buf[offset], STRSIZE - offset, logstring, argp);
        va_end(argp);
        strcat(buf, "\n");
        if (termprint)
-               fprintf(stderr, "%s", buf); /* XXX - other targets for logging */
+               fprintf(stderr, "%s", buf);
        else
                syslog(LOG_INFO, buf);
 }
+void Log_info_client(client_t *client, const char *logstring, ...)
+{
+       va_list argp;
+       char buf[STRSIZE + 2];
+       int offset = 0;
+       
+       va_start(argp, logstring);
+       offset = sprintf(buf, "INFO: ");
+       offset += vsnprintf(&buf[offset], STRSIZE - offset, logstring, argp);
+       va_end(argp);
+       offset += snprintf(&buf[offset], STRSIZE - offset, " - [%d] %s@%s:%d",
+                                          client->sessionId,
+                                          client->playerName,
+                                          inet_ntoa(client->remote_tcp.sin_addr),
+                                          ntohs(client->remote_tcp.sin_port));
+       strcat(buf, "\n");
+       if (termprint)
+               fprintf(stderr, "%s", buf);
+       else
+               syslog(LOG_INFO, buf);
+       
+}
 
 #ifdef DEBUG
 void Log_debug(const char *logstring, ...)
 {
        va_list argp;
-       char buf[BUFSIZE + 2];
+       char buf[STRSIZE + 2];
        int offset = 0;
        
        va_start(argp, logstring);
        offset = sprintf(buf, "DEBUG: ");
-       vsnprintf(&buf[offset], BUFSIZE - offset, logstring, argp);
+       vsnprintf(&buf[offset], STRSIZE - offset, logstring, argp);
        va_end(argp);
        strcat(buf, "\n");
        if (termprint)
-               fprintf(stderr, "%s", buf); /* XXX - other targets for logging */
+               fprintf(stderr, "%s", buf);
        else
                syslog(LOG_DEBUG, buf);
 }
@@ -126,15 +148,15 @@ void Log_debug(const char *logstring, ...)
 void Log_fatal(const char *logstring, ...)
 {
        va_list argp;
-       char buf[BUFSIZE + 2];
+       char buf[STRSIZE + 2];
        int offset = 0;
        va_start(argp, logstring);
        offset = sprintf(buf, "FATAL: ");
-       vsnprintf(&buf[offset], BUFSIZE - offset, logstring, argp);
+       vsnprintf(&buf[offset], STRSIZE - offset, logstring, argp);
        va_end(argp);
        strcat(buf, "\n");
        if (termprint)
-               fprintf(stderr, "%s", buf); /* XXX - other targets for logging */
+               fprintf(stderr, "%s", buf);
        else
                syslog(LOG_CRIT, buf);
        exit(1);

diff --git a/src/log.h b/src/log.h
index c724158fa65f07b87bbe70734b8cad4c82cb2950..3d74722e0b52503ce4ad63fbd73a69ddb16b230b 100644 (file)
--- a/src/log.h
+++ b/src/log.h
@@ -32,6 +32,7 @@
 #define LOG_H_2435642356
 
 #include "types.h"
+#include "client.h"
 
 #define doAssert(_cond_) do {                                  \
                if (!(_cond_)) {                                                                                                \
@@ -51,6 +52,7 @@ void Log_debug(const char *logstring, ...);
 
 void Log_warn(const char *logstring, ...);
 void Log_info(const char *logstring, ...);
+void Log_info_client(client_t *client, const char *logstring, ...);
 void Log_fatal(const char *logstring, ...);
 
 void Log_init(bool_t terminal);

diff --git a/src/messagehandler.c b/src/messagehandler.c
index 708c33c6ef2defbf24af0387c07e9d91fc15a881..3901eb31fa1eae0161f342e05c3a7a19afa8fb31 100644 (file)
--- a/src/messagehandler.c
+++ b/src/messagehandler.c
@@ -55,13 +55,7 @@ static void sendServerReject(client_t *client, const char *reason, MumbleProto__
        msg->payload.reject->has_type = true;
        Client_send_message(client, msg);
        
-       Log_info("Server reject reason: %s. Disconnecting session %d - %s@%s:%d",
-                        reason,
-                        client->sessionId,
-                        client->playerName,
-                        inet_ntoa(client->remote_tcp.sin_addr),
-                        ntohs(client->remote_tcp.sin_port));
-       
+       Log_info_client(client, "Server reject reason: %s", reason);
 }
 
 static void sendPermissionDenied(client_t *client, const char *reason)
@@ -256,7 +250,7 @@ void Mh_handle_message(client_t *client, message_t *msg)
                sendmsg->payload.serverSync->allow_html = true; /* Support this? */
                Client_send_message(client, sendmsg);
                
-               Log_info("User %s authenticated", client->playerName);
+               Log_info_client(client, "User %s authenticated", client->playerName);
                break;
                
        case Ping:
@@ -378,9 +372,7 @@ void Mh_handle_message(client_t *client, message_t *msg)
                                do {
                                        Chan_iterate(&ch_itr);
                                } while (ch_itr != NULL && ch_itr->id != msg->payload.textMessage->channel_id[i]);
-                               if (ch_itr == NULL)
-                                       Log_warn("Channel id %d not found - ignoring.", msg->payload.textMessage->channel_id[i]);
-                               else {
+                               if (ch_itr != NULL) {
                                        struct dlist *itr;
                                        list_iterate(itr, &ch_itr->clients) {
                                                client_t *c;