From 42b25a4d3e2fe66f03cbd8c866d8af7bd4f6e5a7 Mon Sep 17 00:00:00 2001 From: mannol Date: Sun, 27 Apr 2014 19:21:26 +0200 Subject: Yeah many calls --- toxcore/DHT.c | 67 ++++++++-------------- toxcore/Makefile.inc | 2 + toxcore/Messenger.c | 46 ++++++--------- toxcore/assoc.c | 89 ++++++++++------------------ toxcore/assoc.h | 2 +- toxcore/logger.c | 159 +++++++++++++++++++++++++++++++++++++++++++++++++++ toxcore/logger.h | 86 ++++++++++++++++++++++++++++ toxcore/network.c | 153 ++++++++++++++++++------------------------------- toxcore/tox.c | 2 + toxcore/util.c | 84 --------------------------- toxcore/util.h | 7 --- 11 files changed, 379 insertions(+), 318 deletions(-) create mode 100644 toxcore/logger.c create mode 100644 toxcore/logger.h (limited to 'toxcore') diff --git a/toxcore/DHT.c b/toxcore/DHT.c index 1089e2ff..870e6ca2 100644 --- a/toxcore/DHT.c +++ b/toxcore/DHT.c @@ -27,6 +27,8 @@ #include "config.h" #endif +#include "logger.h" + #include "DHT.h" #ifdef ENABLE_ASSOC_DHT @@ -198,18 +200,12 @@ static int client_or_ip_port_in_list(Client_data *list, uint32_t length, uint8_t /* Refresh the client timestamp. */ if (ip_port.ip.family == AF_INET) { -#ifdef LOGGING - - if (!ipport_equal(&list[i].assoc4.ip_port, &ip_port)) { - size_t x; - x = sprintf(logbuffer, "coipil[%u]: switching ipv4 from %s:%u ", i, - ip_ntoa(&list[i].assoc4.ip_port.ip), ntohs(list[i].assoc4.ip_port.port)); - sprintf(logbuffer + x, "to %s:%u\n", - ip_ntoa(&ip_port.ip), ntohs(ip_port.port)); - loglog(logbuffer); - } - -#endif + LOGGER_SCOPE( if (!ipport_equal(&list[i].assoc4.ip_port, &ip_port)) { + LOGGER_INFO("coipil[%u]: switching ipv4 from %s:%u to %s:%u", i, + ip_ntoa(&list[i].assoc4.ip_port.ip), ntohs(list[i].assoc4.ip_port.port), + ip_ntoa(&ip_port.ip), ntohs(ip_port.port)); + } + ); if (LAN_ip(list[i].assoc4.ip_port.ip) != 0 && LAN_ip(ip_port.ip) == 0) return 1; @@ -217,19 +213,13 @@ static int client_or_ip_port_in_list(Client_data *list, uint32_t length, uint8_t list[i].assoc4.ip_port = ip_port; list[i].assoc4.timestamp = temp_time; } else if (ip_port.ip.family == AF_INET6) { - -#ifdef LOGGING - - if (!ipport_equal(&list[i].assoc6.ip_port, &ip_port)) { - size_t x; - x = sprintf(logbuffer, "coipil[%u]: switching ipv6 from %s:%u ", i, - ip_ntoa(&list[i].assoc6.ip_port.ip), ntohs(list[i].assoc6.ip_port.port)); - sprintf(logbuffer + x, "to %s:%u\n", - ip_ntoa(&ip_port.ip), ntohs(ip_port.port)); - loglog(logbuffer); - } - -#endif + + LOGGER_SCOPE( if (!ipport_equal(&list[i].assoc4.ip_port, &ip_port)) { + LOGGER_INFO("coipil[%u]: switching ipv6 from %s:%u to %s:%u", i, + ip_ntoa(&list[i].assoc6.ip_port.ip), ntohs(list[i].assoc6.ip_port.port), + ip_ntoa(&ip_port.ip), ntohs(ip_port.port)); + } + ); if (LAN_ip(list[i].assoc6.ip_port.ip) != 0 && LAN_ip(ip_port.ip) == 0) return 1; @@ -251,10 +241,9 @@ static int client_or_ip_port_in_list(Client_data *list, uint32_t length, uint8_t /* Initialize client timestamp. */ list[i].assoc4.timestamp = temp_time; memcpy(list[i].client_id, client_id, CLIENT_ID_SIZE); -#ifdef LOGGING - sprintf(logbuffer, "coipil[%u]: switching client_id (ipv4) \n", i); - loglog(logbuffer); -#endif + + LOGGER_DEBUG("coipil[%u]: switching client_id (ipv4)", i); + /* kill the other address, if it was set */ memset(&list[i].assoc6, 0, sizeof(list[i].assoc6)); return 1; @@ -262,10 +251,9 @@ static int client_or_ip_port_in_list(Client_data *list, uint32_t length, uint8_t /* Initialize client timestamp. */ list[i].assoc6.timestamp = temp_time; memcpy(list[i].client_id, client_id, CLIENT_ID_SIZE); -#ifdef LOGGING - sprintf(logbuffer, "coipil[%u]: switching client_id (ipv6) \n", i); - loglog(logbuffer); -#endif + + LOGGER_DEBUG("coipil[%u]: switching client_id (ipv6)", i); + /* kill the other address, if it was set */ memset(&list[i].assoc4, 0, sizeof(list[i].assoc4)); return 1; @@ -469,18 +457,11 @@ int get_close_nodes(DHT *dht, uint8_t *client_id, Node_format *nodes_list, sa_fa uint8_t num_found = Assoc_get_close_entries(dht->assoc, &request); if (!num_found) { -#ifdef LOGGING - loglog("get_close_nodes(): Assoc_get_close_entries() returned zero nodes.\n"); -#endif - + LOGGER_DEBUG("get_close_nodes(): Assoc_get_close_entries() returned zero nodes"); return get_somewhat_close_nodes(dht, client_id, nodes_list, sa_family, is_LAN, want_good); } - -#ifdef LOGGING - sprintf(logbuffer, "get_close_nodes(): Assoc_get_close_entries() returned %i 'direct' and %i 'indirect' nodes.\n", - request.count_good, num_found - request.count_good); - loglog(logbuffer); -#endif + + LOGGER_DEBUG("get_close_nodes(): Assoc_get_close_entries() returned %i 'direct' and %i 'indirect' nodes", request.count_good, num_found - request.count_good); uint8_t i, num_returned = 0; diff --git a/toxcore/Makefile.inc b/toxcore/Makefile.inc index 5e529267..5f9ab0d7 100644 --- a/toxcore/Makefile.inc +++ b/toxcore/Makefile.inc @@ -31,6 +31,8 @@ libtoxcore_la_SOURCES = ../toxcore/DHT.h \ ../toxcore/assoc.c \ ../toxcore/onion.h \ ../toxcore/onion.c \ + ../toxcore/logger.h \ + ../toxcore/logger.c \ ../toxcore/onion_announce.h \ ../toxcore/onion_announce.c \ ../toxcore/onion_client.h \ diff --git a/toxcore/Messenger.c b/toxcore/Messenger.c index db5390c0..2033e6a9 100644 --- a/toxcore/Messenger.c +++ b/toxcore/Messenger.c @@ -25,6 +25,7 @@ #include "config.h" #endif +#include "logger.h" #include "Messenger.h" #include "assoc.h" #include "network.h" @@ -2245,7 +2246,7 @@ void do_messenger(Messenger *m) #ifdef LOGGING if (unix_time() > lastdump + DUMPING_CLIENTS_FRIENDS_EVERY_N_SECONDS) { - loglog(" = = = = = = = = \n"); + #ifdef ENABLE_ASSOC_DHT Assoc_status(m->dht->assoc); #endif @@ -2254,12 +2255,10 @@ void do_messenger(Messenger *m) size_t c; for (c = 0; c < m->numchats; c++) { - loglog("---------------- \n"); Assoc_status(m->chats[c]->assoc); } } - loglog(" = = = = = = = = \n"); lastdump = unix_time(); uint32_t client, last_pinged; @@ -2276,14 +2275,12 @@ void do_messenger(Messenger *m) if (last_pinged > 999) last_pinged = 999; - snprintf(logbuffer, sizeof(logbuffer), "C[%2u] %s:%u [%3u] %s\n", - client, ip_ntoa(&assoc->ip_port.ip), ntohs(assoc->ip_port.port), - last_pinged, ID2String(cptr->client_id)); - loglog(logbuffer); + LOGGER_DEBUG("C[%2u] %s:%u [%3u] %s", + client, ip_ntoa(&assoc->ip_port.ip), ntohs(assoc->ip_port.port), + last_pinged, ID2String(cptr->client_id)); } } - - loglog(" = = = = = = = = \n"); + uint32_t friend, dhtfriend; @@ -2311,9 +2308,7 @@ void do_messenger(Messenger *m) dht2m[m2dht[friend]] = friend; if (m->numfriends != m->dht->num_friends) { - sprintf(logbuffer, "Friend num in DHT %u != friend num in msger %u\n", - m->dht->num_friends, m->numfriends); - loglog(logbuffer); + LOGGER_DEBUG("Friend num in DHT %u != friend num in msger %u\n", m->dht->num_friends, m->numfriends); } uint32_t ping_lastrecv; @@ -2334,14 +2329,11 @@ void do_messenger(Messenger *m) if (ping_lastrecv > 999) ping_lastrecv = 999; - snprintf(logbuffer, sizeof(logbuffer), "F[%2u:%2u] <%s> %02i [%03u] %s\n", - dht2m[friend], friend, msgfptr->name, msgfptr->crypt_connection_id, - ping_lastrecv, ID2String(msgfptr->client_id)); - loglog(logbuffer); + LOGGER_DEBUG("F[%2u:%2u] <%s> %02i [%03u] %s", + dht2m[friend], friend, msgfptr->name, msgfptr->crypt_connection_id, + ping_lastrecv, ID2String(msgfptr->client_id)); } else { - snprintf(logbuffer, sizeof(logbuffer), "F[--:%2u] %s\n", - friend, ID2String(dhtfptr->client_id)); - loglog(logbuffer); + LOGGER_DEBUG("F[--:%2u] %s", friend, ID2String(dhtfptr->client_id)); } for (client = 0; client < MAX_FRIEND_CLIENTS; client++) { @@ -2355,20 +2347,16 @@ void do_messenger(Messenger *m) if (last_pinged > 999) last_pinged = 999; - - snprintf(logbuffer, sizeof(logbuffer), "F[%2u] => C[%2u] %s:%u [%3u] %s\n", - friend, client, ip_ntoa(&assoc->ip_port.ip), - ntohs(assoc->ip_port.port), last_pinged, - ID2String(cptr->client_id)); - loglog(logbuffer); + + LOGGER_DEBUG("F[%2u] => C[%2u] %s:%u [%3u] %s", + friend, client, ip_ntoa(&assoc->ip_port.ip), + ntohs(assoc->ip_port.port), last_pinged, + ID2String(cptr->client_id)); } } } - - loglog(" = = = = = = = = \n"); } - -#endif +#endif /* LOGGING */ } /* diff --git a/toxcore/assoc.c b/toxcore/assoc.c index 2c1f0bad..c8f58c9c 100644 --- a/toxcore/assoc.c +++ b/toxcore/assoc.c @@ -3,6 +3,7 @@ #include "config.h" #endif +#include "logger.h" #include "DHT.h" #include "assoc.h" #include "ping.h" @@ -524,9 +525,7 @@ static void client_id_self_update(Assoc *assoc) assoc->self_hash = id_hash(assoc, assoc->self_client_id); } -#ifdef LOGGING - loglog("assoc: id is now set, purging cache of self-references...\n"); -#endif + LOGGER_DEBUG("id is now set, purging cache of self-references"); /* if we already added some (or loaded some) entries, * look and remove if we find a match @@ -821,10 +820,8 @@ Assoc *new_Assoc(size_t bits, size_t entries, uint8_t *public_id) entries_test = prime_upto_min9(entries_test - 1); if (entries_test != entries) { -#ifdef LOGGING - sprintf(logbuffer, "new_Assoc(): trimmed %i to %i.\n", (int)entries, (int)entries_test); - loglog(logbuffer); -#endif + + LOGGER_DEBUG("trimmed %i to %i.\n", (int)entries, (int)entries_test); entries = (size_t)entries_test; } } @@ -873,7 +870,7 @@ void Assoc_self_client_id_changed(Assoc *assoc, uint8_t *id) #ifdef LOGGING static char *idpart2str(uint8_t *id, size_t len); -#endif +#endif /* LOGGING */ /* refresh buckets */ void do_Assoc(Assoc *assoc, DHT *dht) @@ -929,53 +926,30 @@ void do_Assoc(Assoc *assoc, DHT *dht) break; } -#ifdef LOGGING - size_t total = 0, written = sprintf(logbuffer, "assoc: [%u] => ", - (uint32_t)(candidate % assoc->candidates_bucket_count)); - - if (written > 0) - total += written; - -#endif - if (seen) { IPPTsPng *ippts = seen->seen_family == AF_INET ? &seen->client.assoc4 : &seen->client.assoc6; -#ifdef LOGGING - written = sprintf(logbuffer + total, " S[%s...] %s:%u", idpart2str(seen->client.client_id, 8), - ip_ntoa(&ippts->ip_port.ip), htons(ippts->ip_port.port)); - - if (written > 0) - total += written; - -#endif + + LOGGER_DEBUG("[%u] => S[%s...] %s:%u", (uint32_t)(candidate % assoc->candidates_bucket_count), + idpart2str(seen->client.client_id, 8), ip_ntoa(&ippts->ip_port.ip), htons(ippts->ip_port.port)); + DHT_getnodes(dht, &ippts->ip_port, seen->client.client_id, target_id); seen->getnodes = unix_time(); } if (heard && (heard != seen)) { IP_Port *ipp = heard->heard_family == AF_INET ? &heard->assoc_heard4 : &heard->assoc_heard6; -#ifdef LOGGING - written = sprintf(logbuffer + total, " H[%s...] %s:%u", idpart2str(heard->client.client_id, 8), ip_ntoa(&ipp->ip), - htons(ipp->port)); - - if (written > 0) - total += written; - -#endif + + LOGGER_DEBUG("[%u] => H[%s...] %s:%u", (uint32_t)(candidate % assoc->candidates_bucket_count), + idpart2str(heard->client.client_id, 8), ip_ntoa(&ipp->ip), htons(ipp->port)); + DHT_getnodes(dht, ipp, heard->client.client_id, target_id); heard->getnodes = unix_time(); } - -#ifdef LOGGING - - if (!heard && !seen) - sprintf(logbuffer + total, "no nodes to talk to??\n"); - else - /* for arcane reasons, sprintf(str, "\n") doesn't function */ - sprintf(logbuffer + total, "%s", "\n"); - - loglog(logbuffer); -#endif + + LOGGER_SCOPE ( + if ( !heard && !seen ) + LOGGER_DEBUG("[%u] => no nodes to talk to??", (uint32_t)(candidate % assoc->candidates_bucket_count)); + ); } } @@ -1009,11 +983,11 @@ static char *idpart2str(uint8_t *id, size_t len) void Assoc_status(Assoc *assoc) { if (!assoc) { - loglog("Assoc status: no assoc\n"); + LOGGER_INFO("Assoc status: no assoc"); return; } - - loglog("[b:p] hash => [id...] used, seen, heard\n"); + + LOGGER_INFO("[b:p] hash => [id...] used, seen, heard"); size_t bid, cid, total = 0; @@ -1024,24 +998,23 @@ void Assoc_status(Assoc *assoc) Client_entry *entry = &bucket->list[cid]; if (entry->hash) { - sprintf(logbuffer, "[%3i:%3i] %08x => [%s...] %i, %i(%c), %i(%c)\n", - (int)bid, (int)cid, entry->hash, idpart2str(entry->client.client_id, 8), - entry->used_at ? (int)(unix_time() - entry->used_at) : 0, - entry->seen_at ? (int)(unix_time() - entry->seen_at) : 0, - entry->seen_at ? (entry->seen_family == AF_INET ? '4' : (entry->seen_family == AF_INET6 ? '6' : '?')) : '?', + total++; + + LOGGER_INFO("[%3i:%3i] %08x => [%s...] %i, %i(%c), %i(%c)\n", + (int)bid, (int)cid, entry->hash, idpart2str(entry->client.client_id, 8), + entry->used_at ? (int)(unix_time() - entry->used_at) : 0, + entry->seen_at ? (int)(unix_time() - entry->seen_at) : 0, + entry->seen_at ? (entry->seen_family == AF_INET ? '4' : (entry->seen_family == AF_INET6 ? '6' : '?')) : '?', entry->heard_at ? (int)(unix_time() - entry->heard_at) : 0, entry->heard_at ? (entry->heard_family == AF_INET ? '4' : (entry->heard_family == AF_INET6 ? '6' : '?')) : '?'); - loglog(logbuffer); - total++; } } } if (total) { - sprintf(logbuffer, "Total: %i entries, table usage %i%%.\n", (int)total, - (int)(total * 100 / (assoc->candidates_bucket_count * assoc->candidates_bucket_size))); - loglog(logbuffer); + LOGGER_INFO("Total: %i entries, table usage %i%%.\n", (int)total, + (int)(total * 100 / (assoc->candidates_bucket_count * assoc->candidates_bucket_size))); } } -#endif +#endif /* LOGGING */ diff --git a/toxcore/assoc.h b/toxcore/assoc.h index 9dbc75f2..0fdff4fe 100644 --- a/toxcore/assoc.h +++ b/toxcore/assoc.h @@ -98,6 +98,6 @@ void kill_Assoc(Assoc *assoc); #ifdef LOGGING void Assoc_status(Assoc *assoc); -#endif +#endif /* LOGGING */ #endif /* !__ASSOC_H__ */ diff --git a/toxcore/logger.c b/toxcore/logger.c new file mode 100644 index 00000000..e700fe71 --- /dev/null +++ b/toxcore/logger.c @@ -0,0 +1,159 @@ +/* logger.c + * + * Wrapping logger functions in nice macros + * + * Copyright (C) 2013 Tox project All Rights Reserved. + * + * This file is part of Tox. + * + * Tox is free software: you can redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation, either version 3 of the License, or + * (at your option) any later version. + * + * Tox is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License + * along with Tox. If not, see . + * + */ + +#ifdef HAVE_CONFIG_H +#include "config.h" +#endif /* HAVE_CONFIG_H */ + + +#include "logger.h" + +#ifdef LOGGING + +#include "network.h" /* for time */ + +#include +#include +#include +#include +#include +#include + +#if defined(_WIN32) || defined(__WIN32__) || defined (WIN32) +#define strerror_r(errno,buf,len) strerror_s(buf,len,errno) +#endif + +static struct logger_config { + FILE* log_file; + LoggerLevel level; + uint64_t start_time; /* Time when lib loaded */ +} +logger = { + NULL, + DEBUG, + 0 +}; + +void __attribute__((destructor)) terminate_logger() +{ + if ( !logger.log_file ) return; + + time_t tim = time(NULL); + + logger_write(ERROR, "============== Closing logger ==============\n" + "Time: %s", asctime(localtime(&tim))); + + fclose(logger.log_file); +} + +unsigned logger_get_pid() +{ + return + #if defined(_WIN32) || defined(__WIN32__) || defined (WIN32) + GetCurrentProcessId(); + #else + getpid(); + #endif +} + +const char* logger_stringify_level(LoggerLevel level) +{ + static const char* strings [] = + { + "INFO", + "DEBUG", + "WARNING", + "ERROR" + }; + + return strings[level]; +} + + +int logger_init(const char* file_name, LoggerLevel level) +{ + char* final_l = calloc(sizeof(char), strlen(file_name) + 32); + sprintf(final_l, "%s"/*.%u"*/, file_name, logger_get_pid()); + + if ( logger.log_file ) { + fprintf(stderr, "Error opening logger name: %s with level %d: already opened!\n", final_l, level); + free (final_l); + return -1; + } + + logger.log_file = fopen(final_l, "wb"); + + if ( logger.log_file == NULL ) { + char error[1000]; + if ( strerror_r(errno, error, 1000) == 0 ) + fprintf(stderr, "Error opening logger file: %s; info: %s\n", final_l, error); + else + fprintf(stderr, "Error opening logger file: %s\n", final_l); + + free (final_l); + return -1; + } + + + logger.level = level; + logger.start_time = current_time(); + + + time_t tim = time(NULL); + logger_write(ERROR, "============== Starting logger ==============\n" + "Time: %s", asctime(localtime(&tim))); + + + + free (final_l); + return 0; +} + + +void logger_write (LoggerLevel level, const char* format, ...) +{ + if (logger.log_file == NULL) { + /*fprintf(stderr, "Logger file is NULL!\n");*/ + return; + } + + if (logger.level > level) return; /* Don't print some levels xuh */ + + va_list _arg; + va_start (_arg, format); + vfprintf (logger.log_file, format, _arg); + va_end (_arg); + + fflush(logger.log_file); +} + +char* logger_timestr(char* dest) +{ + uint64_t diff = (current_time() - logger.start_time) / 1000; /* ms */ + sprintf(dest, "%"PRIu64"", diff); + + return dest; +} + + +#endif /* LOGGING */ \ No newline at end of file diff --git a/toxcore/logger.h b/toxcore/logger.h new file mode 100644 index 00000000..6c65850e --- /dev/null +++ b/toxcore/logger.h @@ -0,0 +1,86 @@ +/* logger.h + * + * Wrapping logger functions in nice macros + * + * Copyright (C) 2013 Tox project All Rights Reserved. + * + * This file is part of Tox. + * + * Tox is free software: you can redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation, either version 3 of the License, or + * (at your option) any later version. + * + * Tox is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License + * along with Tox. If not, see . + * + */ + + +#ifndef __TOXLOGGER +#define __TOXLOGGER + +// #define LOGGING + +#ifdef LOGGING +#include + +typedef enum _LoggerLevel +{ + INFO, + DEBUG, + WARNING, + ERROR +} LoggerLevel; + +/* + * Set 'level' as the lowest printable level + */ +int logger_init(const char* file_name, LoggerLevel level); +const char* logger_stringify_level(LoggerLevel level); +unsigned logger_get_pid(); +void logger_write (LoggerLevel level, const char* format, ...); +char* logger_timestr (char* dest); + +#if defined(_WIN32) || defined(__WIN32__) || defined (WIN32) +#define _SFILE (strrchr(__FILE__, '\\') ? strrchr(__FILE__, '\\') + 1 : __FILE__) +#else +#define _SFILE (strrchr(__FILE__, '/') ? strrchr(__FILE__, '/') + 1 : __FILE__) +#endif + +#define WRITE_FORMAT(__LEVEL__, format) char* the_str = calloc(sizeof(char), strlen(format)+ 500); sprintf(the_str, "[%u] [%s] [%s] [%s:%d %s()] %s\n", \ + logger_get_pid(), logger_stringify_level(__LEVEL__), logger_timestr(__time__), _SFILE, __LINE__, __func__, format) + +/* Use these macros */ + +#define LOGGER_INIT(name, level) logger_init(name, level); +#define LOGGER_INFO(format, ...) do { char __time__[20]; WRITE_FORMAT(INFO, format); logger_write( INFO, the_str, ##__VA_ARGS__ ); free(the_str); } while (0) +#define LOGGER_DEBUG(format, ...) do { char __time__[20]; WRITE_FORMAT(DEBUG, format); logger_write( DEBUG, the_str, ##__VA_ARGS__ ); free(the_str); } while (0) +#define LOGGER_WARNING(format, ...) do { char __time__[20]; WRITE_FORMAT(WARNING, format); logger_write( WARNING, the_str, ##__VA_ARGS__ ); free(the_str); } while (0) +#define LOGGER_ERROR(format, ...) do { char __time__[20]; WRITE_FORMAT(ERROR, format); logger_write( ERROR, the_str, ##__VA_ARGS__ ); free(the_str); } while (0) + +/* To do some checks or similar only when logging use this */ +#define LOGGER_SCOPE(__SCOPE_DO__) do { __SCOPE_DO__ } while(0) + +#else + + +#define LOGGER_INIT(name, level) +#define LOGGER_INFO(format, ...) +#define LOGGER_DEBUG(format, ...) +#define LOGGER_WARNING(format, ...) +#define LOGGER_ERROR(format, ...) + +#define LOGGER_SCOPE(__SCOPE_DO__) + +#endif /* LOGGING */ + + + + +#endif /* __TOXLOGGER */ \ No newline at end of file diff --git a/toxcore/network.c b/toxcore/network.c index 47afab8e..7262f352 100644 --- a/toxcore/network.c +++ b/toxcore/network.c @@ -29,6 +29,9 @@ #include "config.h" #endif +#define LOGGING +#include "logger.h" + #if !defined(_WIN32) && !defined(__WIN32__) && !defined (WIN32) #include #endif @@ -205,9 +208,32 @@ uint64_t random_64b(void) return randnum; } -#ifdef LOGGING -static void loglogdata(char *message, uint8_t *buffer, size_t buflen, IP_Port *ip_port, ssize_t res); -#endif +/* In case no logging */ +#ifndef LOGGING + +#define loglogdata(__message__, __buffer__, __buflen__, __ip_port__, __res__) + +#else + +#define data_0(__buflen__, __buffer__) __buflen__ > 4 ? ntohl(*(uint32_t *)&__buffer__[1]) : 0 +#define data_1(__buflen__, __buffer__) __buflen__ > 7 ? ntohl(*(uint32_t *)&__buffer__[5]) : 0 + +#define loglogdata(__message__, __buffer__, __buflen__, __ip_port__, __res__) \ + (__ip_port__) .ip; \ + if (__res__ < 0) /* Windows doesn't necessarily know %zu */ \ + LOGGER_INFO("[%2u] %s %3hu%c %s:%hu (%u: %s) | %04x%04x", \ + __buffer__[0], __message__, (__buflen__ < 999 ? (uint16_t)__buflen__ : 999), 'E', \ + ip_ntoa(&((__ip_port__).ip)), ntohs((__ip_port__).port), errno, strerror(errno), data_0(__buflen__, __buffer__), data_1(__buflen__, __buffer__)); \ + else if ((__res__ > 0) && ((size_t)__res__ <= __buflen__)) \ + LOGGER_INFO("[%2u] %s %3zu%c %s:%hu (%u: %s) | %04x%04x", \ + __buffer__[0], __message__, (__res__ < 999 ? (size_t)__res__ : 999), ((size_t)__res__ < __buflen__ ? '<' : '='), \ + ip_ntoa(&((__ip_port__).ip)), ntohs((__ip_port__).port), 0, "OK", data_0(__buflen__, __buffer__), data_1(__buflen__, __buffer__)); \ + else /* empty or overwrite */ \ + LOGGER_INFO("[%2u] %s %zu%c%zu %s:%hu (%u: %s) | %04x%04x", \ + __buffer__[0], __message__, (size_t)__res__, (!__res__ ? '!' : '>'), __buflen__, \ + ip_ntoa(&((__ip_port__).ip)), ntohs((__ip_port__).port), 0, "OK", data_0(__buflen__, __buffer__), data_1(__buflen__, __buffer__)); + +#endif /* LOGGING */ /* Basic network functions: * Function to send packet(data) of length length to ip_port. @@ -266,9 +292,9 @@ int sendpacket(Networking_Core *net, IP_Port ip_port, uint8_t *data, uint32_t le } int res = sendto(net->sock, (char *) data, length, 0, (struct sockaddr *)&addr, addrsize); -#ifdef LOGGING - loglogdata("O=>", data, length, &ip_port, res); -#endif + + loglogdata("O=>", data, length, ip_port, res); + if ((res >= 0) && ((uint32_t)res == length)) net->send_fail_eagain = 0; @@ -297,14 +323,10 @@ static int receivepacket(sock_t sock, IP_Port *ip_port, uint8_t *data, uint32_t int fail_or_len = recvfrom(sock, (char *) data, MAX_UDP_PACKET_SIZE, 0, (struct sockaddr *)&addr, &addrlen); if (fail_or_len <= 0) { -#ifdef LOGGING - - if ((fail_or_len < 0) && (errno != EWOULDBLOCK)) { - sprintf(logbuffer, "Unexpected error reading from socket: %u, %s\n", errno, strerror(errno)); - loglog(logbuffer); - } - -#endif + + LOGGER_SCOPE( if ((fail_or_len < 0) && (errno != EWOULDBLOCK)) + LOGGER_ERROR("Unexpected error reading from socket: %u, %s\n", errno, strerror(errno)); ); + return -1; /* Nothing received or empty packet. */ } @@ -329,9 +351,7 @@ static int receivepacket(sock_t sock, IP_Port *ip_port, uint8_t *data, uint32_t } else return -1; -#ifdef LOGGING - loglogdata("=>O", data, MAX_UDP_PACKET_SIZE, ip_port, *length); -#endif + loglogdata("=>O", data, MAX_UDP_PACKET_SIZE, *ip_port, *length); return 0; } @@ -354,10 +374,7 @@ void networking_poll(Networking_Core *net) if (length < 1) continue; if (!(net->packethandlers[data[0]].function)) { -#ifdef LOGGING - sprintf(logbuffer, "[%02u] -- Packet has no handler.\n", data[0]); - loglog(logbuffer); -#endif + LOGGER_WARNING("[%02u] -- Packet has no handler.\n", data[0]); continue; } @@ -460,22 +477,14 @@ int networking_wait_execute(uint8_t *data, long seconds, long microseconds) timeout.tv_usec = microseconds; } -#ifdef LOGGING - errno = 0; -#endif /* returns -1 on error, 0 on timeout, the socket on activity */ int res = select(nfds, &readfds, &writefds, &exceptfds, timeout_ptr); -#ifdef LOGGING - - /* only dump if not timeout */ - if (res) { - sprintf(logbuffer, "select(%d, %d): %d (%d, %s) - %d %d %d\n", microseconds, seconds, res, errno, - strerror(errno), FD_ISSET(s->sock, &readfds), FD_ISSET(s->sock, &writefds), - FD_ISSET(s->sock, &exceptfds)); - loglog(logbuffer); - } - -#endif + + LOGGER_SCOPE( + if (res) LOGGER_INFO("select(%d, %d): %d (%d, %s) - %d %d %d\n", microseconds, seconds, res, errno, + strerror(errno), FD_ISSET(s->sock, &readfds), FD_ISSET(s->sock, &writefds), + FD_ISSET(s->sock, &exceptfds)); + ); if (FD_ISSET(s->sock, &writefds)) { s->send_fail_reset = 1; @@ -628,20 +637,12 @@ Networking_Core *new_networking(IP ip, uint16_t port) } if (ip.family == AF_INET6) { + #ifdef LOGGING - int is_dualstack = -#endif - set_socket_dualstack(temp->sock); -#ifdef LOGGING - - if (is_dualstack) { - loglog("Dual-stack socket: enabled.\n"); - } else { - loglog("Dual-stack socket: Failed to enable, won't be able to receive from/send to IPv4 addresses.\n"); - } - -#endif - + int is_dualstack = +#endif /* LOGGING */ + set_socket_dualstack(temp->sock); + LOGGER_DEBUG( "Dual-stack socket: %s", is_dualstack ? "enabled" : "Failed to enable, won't be able to receive from/send to IPv4 addresses" ); /* multicast local nodes */ struct ipv6_mreq mreq; memset(&mreq, 0, sizeof(mreq)); @@ -649,21 +650,13 @@ Networking_Core *new_networking(IP ip, uint16_t port) mreq.ipv6mr_multiaddr.s6_addr[ 1] = 0x02; mreq.ipv6mr_multiaddr.s6_addr[15] = 0x01; mreq.ipv6mr_interface = 0; + #ifdef LOGGING - errno = 0; int res = -#endif - setsockopt(temp->sock, IPPROTO_IPV6, IPV6_ADD_MEMBERSHIP, (char *)&mreq, sizeof(mreq)); -#ifdef LOGGING - - if (res < 0) { - sprintf(logbuffer, "Failed to activate local multicast membership. (%u, %s)\n", - errno, strerror(errno)); - loglog(logbuffer); - } else - loglog("Local multicast group FF02::1 joined successfully.\n"); - -#endif +#endif /* LOGGING */ + setsockopt(temp->sock, IPPROTO_IPV6, IPV6_ADD_MEMBERSHIP, (char *)&mreq, sizeof(mreq)); + + LOGGER_DEBUG(res < 0 ? "Failed to activate local multicast membership. (%u, %s)" : "Local multicast group FF02::1 joined successfully", errno, strerror(errno) ); } /* a hanging program or a different user might block the standard port; @@ -691,13 +684,9 @@ Networking_Core *new_networking(IP ip, uint16_t port) if (!res) { temp->port = *portptr; -#ifdef LOGGING - loginit(temp->port); - - sprintf(logbuffer, "Bound successfully to %s:%u.\n", ip_ntoa(&ip), ntohs(temp->port)); - loglog(logbuffer); -#endif - + + LOGGER_DEBUG("Bound successfully to %s:%u", ip_ntoa(&ip), ntohs(temp->port)); + /* errno isn't reset on success, only set on failure, the failed * binds with parallel clients yield a -EPERM to the outside if * errno isn't cleared here */ @@ -1038,31 +1027,3 @@ int addr_resolve_or_parse_ip(const char *address, IP *to, IP *extra) return 1; }; - -#ifdef LOGGING -static char errmsg_ok[3] = "OK"; -static void loglogdata(char *message, uint8_t *buffer, size_t buflen, IP_Port *ip_port, ssize_t res) -{ - uint16_t port = ntohs(ip_port->port); - uint32_t data[2]; - data[0] = buflen > 4 ? ntohl(*(uint32_t *)&buffer[1]) : 0; - data[1] = buflen > 7 ? ntohl(*(uint32_t *)&buffer[5]) : 0; - - /* Windows doesn't necessarily know %zu */ - if (res < 0) { - snprintf(logbuffer, sizeof(logbuffer), "[%2u] %s %3hu%c %s:%hu (%u: %s) | %04x%04x\n", - buffer[0], message, (buflen < 999 ? (uint16_t)buflen : 999), 'E', - ip_ntoa(&ip_port->ip), port, errno, strerror(errno), data[0], data[1]); - } else if ((res > 0) && ((size_t)res <= buflen)) - snprintf(logbuffer, sizeof(logbuffer), "[%2u] %s %3zu%c %s:%hu (%u: %s) | %04x%04x\n", - buffer[0], message, (res < 999 ? (size_t)res : 999), ((size_t)res < buflen ? '<' : '='), - ip_ntoa(&ip_port->ip), port, 0, errmsg_ok, data[0], data[1]); - else /* empty or overwrite */ - snprintf(logbuffer, sizeof(logbuffer), "[%2u] %s %zu%c%zu %s:%hu (%u: %s) | %04x%04x\n", - buffer[0], message, (size_t)res, (!res ? '!' : '>'), buflen, - ip_ntoa(&ip_port->ip), port, 0, errmsg_ok, data[0], data[1]); - - logbuffer[sizeof(logbuffer) - 1] = 0; - loglog(logbuffer); -} -#endif diff --git a/toxcore/tox.c b/toxcore/tox.c index c07473dd..9b99174c 100644 --- a/toxcore/tox.c +++ b/toxcore/tox.c @@ -26,6 +26,7 @@ #endif #include "Messenger.h" +#include "logger.h" #define __TOX_DEFINED__ typedef struct Messenger Tox; @@ -773,6 +774,7 @@ int tox_isconnected(Tox *tox) */ Tox *tox_new(uint8_t ipv6enabled) { + LOGGER_INIT(LOGGER_OUTPUT_FILE, LOGGER_LEVEL); return new_messenger(ipv6enabled); } diff --git a/toxcore/util.c b/toxcore/util.c index d56c446e..edc611ec 100644 --- a/toxcore/util.c +++ b/toxcore/util.c @@ -134,87 +134,3 @@ int load_state(load_state_callback_func load_state_callback, void *outer, return length == 0 ? 0 : -1; }; - -#ifdef LOGGING -time_t starttime = 0; -size_t logbufferprelen = 0; -char *logbufferpredata = NULL; -char *logbufferprehead = NULL; -char logbuffer[512]; -static FILE *logfile = NULL; -void loginit(uint16_t port) -{ - if (logfile) - fclose(logfile); - - if (!starttime) { - unix_time_update(); - starttime = unix_time(); - } - - struct tm *tm = localtime(&starttime); - - /* "%F %T" might not be Windows compatible */ - if (strftime(logbuffer + 32, sizeof(logbuffer) - 32, "%F %T", tm)) - sprintf(logbuffer, "%u-%s.log", ntohs(port), logbuffer + 32); - else - sprintf(logbuffer, "%u-%lu.log", ntohs(port), starttime); - - logfile = fopen(logbuffer, "w"); - - if (logbufferpredata) { - if (logfile) - fprintf(logfile, "%s", logbufferpredata); - - free(logbufferpredata); - logbufferpredata = NULL; - } - -}; -void loglog(char *text) -{ - if (logfile) { - fprintf(logfile, "%4u %s", (uint32_t)(unix_time() - starttime), text); - fflush(logfile); - - return; - } - - /* log messages before file was opened: store */ - - size_t len = strlen(text); - - if (!starttime) { - unix_time_update(); - starttime = unix_time(); - - logbufferprelen = 1024 + len - (len % 1024); - logbufferpredata = malloc(logbufferprelen); - logbufferprehead = logbufferpredata; - } - - /* loginit() called meanwhile? (but failed to open) */ - if (!logbufferpredata) - return; - - if (len + (logbufferprehead - logbufferpredata) + 16U < logbufferprelen) { - size_t logpos = logbufferprehead - logbufferpredata; - size_t lennew = logbufferprelen * 1.4; - logbufferpredata = realloc(logbufferpredata, lennew); - logbufferprehead = logbufferpredata + logpos; - logbufferprelen = lennew; - } - - int written = sprintf(logbufferprehead, "%4u %s", (uint32_t)(unix_time() - starttime), text); - logbufferprehead += written; -} - -void logexit() -{ - if (logfile) { - fclose(logfile); - logfile = NULL; - } -}; -#endif - diff --git a/toxcore/util.h b/toxcore/util.h index ae364d52..e40b6968 100644 --- a/toxcore/util.h +++ b/toxcore/util.h @@ -45,11 +45,4 @@ typedef int (*load_state_callback_func)(void *outer, uint8_t *data, uint32_t len int load_state(load_state_callback_func load_state_callback, void *outer, uint8_t *data, uint32_t length, uint16_t cookie_inner); -#ifdef LOGGING -extern char logbuffer[512]; -void loginit(uint16_t port); -void loglog(char *text); -void logexit(); -#endif - #endif /* __UTIL_H__ */ -- cgit v1.2.3