From db60a2942eed420d693edea15e1db982184ff03d Mon Sep 17 00:00:00 2001 From: fatbob313 Date: Fri, 29 Jan 2010 18:50:38 +0000 Subject: [PATCH] Logging fixes --- src/channel.c | 4 ++-- src/client.c | 40 ++++++++------------------------ src/log.c | 54 +++++++++++++++++++++++++++++++------------- src/log.h | 2 ++ src/messagehandler.c | 14 +++--------- 5 files changed, 54 insertions(+), 60 deletions(-) diff --git a/src/channel.c b/src/channel.c index db5cfaa..c308dc4 100644 --- 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 68252dc..a1f957d 100644 --- 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 f4a0ea1..2739641 100644 --- 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 c724158..3d74722 100644 --- 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 708c33c..3901eb3 100644 --- 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; -- 2.30.2