From afed495c8737dc53c0394dfcf2895c42340c2880 Mon Sep 17 00:00:00 2001 From: Thomas Ries Date: Thu, 30 Dec 2004 12:54:29 +0000 Subject: [PATCH] - feature: remote TCP logging facility --- ChangeLog | 1 + README | 45 ++++--- config.h.in | 12 ++ configure.in | 1 + doc/siproxd.conf.example | 17 ++- src/log.c | 246 ++++++++++++++++++++++++++++++++++++--- src/log.h | 5 +- src/readconf.c | 1 + src/siproxd.c | 12 +- src/siproxd.h | 1 + src/sock.c | 4 +- 11 files changed, 305 insertions(+), 40 deletions(-) diff --git a/ChangeLog b/ChangeLog index 6a1ccdd..14274be 100644 --- a/ChangeLog +++ b/ChangeLog @@ -1,5 +1,6 @@ 0.5.10 ====== + 30-Dec-2004: - feature: remote TCP logging facility 29-Dec-2004: - feature: Outbound proxies configurable per domain 08-Dec-2004: - make install will set siproxd_passwd.cfg to -rw----- diff --git a/README b/README index 4124714..f9d663b 100644 --- a/README +++ b/README @@ -76,20 +76,39 @@ that you are using. You should also include your siproxd.conf. The easiest way to generate a debug log is: -1) make sure siproxd is not started as daemon. - -> 'daemonize = 0' in the config file. -2) start siproxd: - $ ./siproxd -d -1 2>debug.log -3) reproduce the error -4) include the file debug.log in your error report. + 1) make sure siproxd is not started as daemon. + -> 'daemonize = 0' in the config file. + 2) start siproxd: + $ ./siproxd -d -1 2>debug.log + 3) reproduce the error + 4) include the file debug.log in your error report. + +Since Version 0.5.10 there also exists the possibility to obtain +the debug log remote via TCP (useful if running siproxd on an embedded +system). To enable this feature, edit the configuration file and +set 'debug_port' to a free TCP port number (e.g. 5050). Then (after +starting siproxd) you can connect from any remote client to this +TCP port (e.g. using netcat) and all the debug output will be sent +via network: + 1) edit configuration file: + -> 'daemonize = 1' have siproxd started as daemon + -> 'silence_log' should be set to 1 + -> 'debug_pattern = -1' + -> 'debug_port = 5050' (or any other TCP port you like) + 2) have siproxd started the usual way + 3) connect from a remote machine and write into a file: + $ netcat > debug.log + 4) reproduce the error + 5) include the file debug.log in your error report. + If siproxd crashes, a stack backtrace usually is helpful to me: -1) start siproxd in the debugger (daemonize set to 0): - $ gdb ./src/siproxd - (gdb) set args -c /path/to/siproxd.conf - (gdb) run -2) reproduce the crash -3) use gdb to print the stack backtrace: + 1) start siproxd in the debugger (daemonize set to 0): + $ gdb ./src/siproxd + (gdb) set args -c /path/to/siproxd.conf + (gdb) run + 2) reproduce the crash + 3) use gdb to print the stack backtrace: (gdb) info thread ... (gdb) bt @@ -101,7 +120,7 @@ If siproxd crashes, a stack backtrace usually is helpful to me: rtld_fini=0x4000a350 <_dl_fini>, stack_end=0xbffffc4c) at ../sysdeps/generic/libc-start.c:78 (gdb) -4) copy-paste all the output and include it in your error report. + 4) copy-paste all the output and include it in your error report. diff --git a/config.h.in b/config.h.in index b544963..ca16b71 100644 --- a/config.h.in +++ b/config.h.in @@ -3,6 +3,9 @@ /* use custom firewall control module */ #undef CUSTOM_FWMODULE +/* Define to 1 if you have the `accept' function. */ +#undef HAVE_ACCEPT + /* Define to 1 if you have the `bind' function. */ #undef HAVE_BIND @@ -12,6 +15,9 @@ /* Define to 1 if you don't have `vprintf' but do have `_doprnt.' */ #undef HAVE_DOPRNT +/* Define to 1 if you have the `dprintf' function. */ +#undef HAVE_DPRINTF + /* Define to 1 if you have the header file. */ #undef HAVE_ERRNO_H @@ -72,6 +78,9 @@ /* Define to 1 if you have the `osipparser2' library (-losipparser2). */ #undef HAVE_LIBOSIPPARSER2 +/* Define to 1 if you have the `listen' function. */ +#undef HAVE_LISTEN + /* Define to 1 if you have the header file. */ #undef HAVE_MEMORY_H @@ -171,6 +180,9 @@ /* Define to 1 if you have the header file. */ #undef HAVE_VARARGS_H +/* Define to 1 if you have the `vdprintf' function. */ +#undef HAVE_VDPRINTF + /* Define to 1 if you have the `vfprintf' function. */ #undef HAVE_VFPRINTF diff --git a/configure.in b/configure.in index a35555c..3ca4574 100644 --- a/configure.in +++ b/configure.in @@ -366,6 +366,7 @@ AC_CHECK_FUNCS(getopt_long setsid syslog) AC_CHECK_FUNCS(getuid setuid getgid setgid getpwnam chroot) AC_CHECK_FUNCS(socket bind select read send sendto fcntl) AC_CHECK_FUNCS(strncpy strchr strstr sprintf vfprintf vsnprintf) +AC_CHECK_FUNCS(dprintf vdprintf listen accept) AC_CHECK_FUNCS(fgets sscanf) AC_CHECK_FUNCS(hstrerror,,AC_CHECK_LIB(resolv,hstrerror,[ AC_DEFINE_UNQUOTED(HAVE_HSTRERROR) diff --git a/doc/siproxd.conf.example b/doc/siproxd.conf.example index 260028c..22cb2ab 100644 --- a/doc/siproxd.conf.example +++ b/doc/siproxd.conf.example @@ -52,13 +52,13 @@ daemonize = 1 ###################################################################### # What shall I log to syslog? -# 0 - DEBUGs, INFOs, WARNINGs and ERRORs (this is the default) -# 1 - INFOs, WARNINGs and ERRORs +# 0 - DEBUGs, INFOs, WARNINGs and ERRORs +# 1 - INFOs, WARNINGs and ERRORs (this is the default) # 2 - WARNINGs and ERRORs # 3 - only ERRORs # 4 - absolutely nothing (be careful - you will have no way to # see what siproxd is doing - or NOT doing) -silence_log = 0 +silence_log = 1 ###################################################################### # Shall I log call establishment to syslog? @@ -154,6 +154,17 @@ default_expires = 600 # debug_level = 0x00000000 +###################################################################### +# TCP debug port +# +# You may connect to this port from a remote machine and +# receive the debug output. This allows bettwer creation of +# odebug output on embedded systems that do not have enough +# memory for large disk files. +# Port number 0 means this feature is disabled. +# +debug_port = 0 + ###################################################################### # Mask feature (experimental) # diff --git a/src/log.c b/src/log.c index 9241fc8..b119b42 100644 --- a/src/log.c +++ b/src/log.c @@ -20,7 +20,7 @@ #include "config.h" -//#include "log.h" +#include "log.h" #include #include @@ -30,19 +30,35 @@ #include #include +#include +#include +#include +#include +#include +//#include +#include + +#include + static char const ident[]="$Id$"; -static int log_to_stdout=0; +/* module local variables */ +static int log_to_stderr=0; static int debug_pattern=0; + +static int debug_listen_port=0; +static int debug_listen_fd=0; +static int debug_fd=0; +static char outbuf[512]; /* * What shall I log to syslog? - * 0 - DEBUGs, INFOs, WARNINGs and ERRORs (this is the default) - * 1 - INFOs, WARNINGs and ERRORs + * 0 - DEBUGs, INFOs, WARNINGs and ERRORs + * 1 - INFOs, WARNINGs and ERRORs (this is the default) * 2 - WARNINGs and ERRORs * 3 - only ERRORs * 4 - absolutely nothing */ -static int silence_level=0; +static int silence_level=1; /* * Mutex for threat synchronization when writing log data @@ -53,18 +69,137 @@ static pthread_mutex_t log_mutex = PTHREAD_MUTEX_INITIALIZER; void log_set_pattern(int pattern) { debug_pattern=pattern; + return; } int log_get_pattern(void) { return debug_pattern; } -void log_set_stdout(int tostdout) { - log_to_stdout=tostdout; +void log_set_stderr(int tostdout) { + log_to_stderr=tostdout; + return; } void log_set_silence(int level) { silence_level=level; + return; +} + +/* + * TCP logging + */ +void log_set_listen_port(int port){ + debug_listen_port = port; + log_tcp_listen(); + return; +} + +void log_tcp_listen(void) { + struct sockaddr_in my_addr; + int sts, on=1; + int flags; + + /* disabled in configuration? */ + if (debug_listen_port == 0) { + debug_listen_fd=-1; + return; + } + + /* ignore SIGPIPE of lost TCP connection */ + signal (SIGPIPE, SIG_IGN); + + memset(&my_addr, 0, sizeof(my_addr)); + my_addr.sin_family = AF_INET; + my_addr.sin_port = htons(debug_listen_port); + + debug_listen_fd=socket(PF_INET, SOCK_STREAM, IPPROTO_TCP); + INFO("DEBUG listener on TCP port %i",debug_listen_port); + if (debug_listen_fd < 0) { + ERROR("socket returned error [%i:%s]",errno, strerror(errno)); + return; + } + + if (setsockopt(debug_listen_fd, SOL_SOCKET, SO_REUSEADDR, &on , sizeof(on)) < 0) { + ERROR("socket returned error [%i:%s]",errno, strerror(errno)); + return; + } + + + sts=bind(debug_listen_fd, (struct sockaddr *)&my_addr, sizeof(my_addr)); + if (sts != 0) { + ERROR("bind returned error [%i:%s]",errno, strerror(errno)); + close(debug_listen_fd); + debug_listen_fd=-1; + return; + } + + /* set non-blocking */ + flags = fcntl(debug_listen_fd, F_GETFL); + if (flags < 0) { + ERROR("fcntl returned error [%i:%s]",errno, strerror(errno)); + close(debug_listen_fd); + debug_listen_fd=-1; + return; + } + if (fcntl(debug_listen_fd, F_SETFL, (long) flags | O_NONBLOCK) < 0) { + ERROR("fcntl returned error [%i:%s]",errno, strerror(errno)); + close(debug_listen_fd); + debug_listen_fd=-1; + return; + } + + listen (debug_listen_fd, 1); + return; +} + +void log_tcp_connect(void) { + int sts; + fd_set fdset; + struct timeval timeout; + int tmpfd; + + if (debug_listen_fd <= 0) return; + + timeout.tv_sec=0; + timeout.tv_usec=0; + + FD_ZERO(&fdset); + FD_SET (debug_listen_fd, &fdset); + + sts=select(debug_listen_fd+1, &fdset, NULL, NULL, &timeout); + if (sts > 0) { + if (debug_fd != 0) { + tmpfd=accept(debug_listen_fd, NULL, NULL); + close(tmpfd); + INFO("Rejected DEBUG TCP connection"); + } else { + debug_fd=accept(debug_listen_fd, NULL, NULL); + INFO("Accepted DEBUG TCP connection [fd=%i]", debug_fd); + } + } + + /* check the TCP connection */ + if (debug_fd > 0) { + timeout.tv_sec=0; + timeout.tv_usec=0; + + FD_ZERO(&fdset); + FD_SET (debug_fd, &fdset); + + sts=select(debug_fd+1, &fdset, NULL, NULL, &timeout); + if (sts > 0) { + char buf[32]; + sts = recv(debug_fd, buf, sizeof(buf), 0); + /* got disconnected? */ + if (sts == 0) { + close(debug_fd); + INFO("Disconnected DEBUG TCP connection [fd=%i]", debug_fd); + debug_fd=0; + } + } + } + return; } @@ -80,7 +215,6 @@ void log_debug(int class, char *file, int line, const char *format, ...) { struct tm *tim; char string[128]; - if ((debug_pattern & class) == 0) return; va_start(ap, format); @@ -89,7 +223,7 @@ void log_debug(int class, char *file, int line, const char *format, ...) { /* * DEBUG output is either STDOUT or SYSLOG, but not both */ - if (log_to_stdout) { + if (log_to_stderr) { /* not running as daemon - log to STDERR */ time(&t); tim=localtime(&t); @@ -103,6 +237,21 @@ void log_debug(int class, char *file, int line, const char *format, ...) { vsnprintf(string, sizeof(string), format, ap); syslog(LOG_USER|LOG_DEBUG, "%s:%i %s", file, line, string); } + /* + * Log to TCP + */ + if (debug_fd > 0) { + /* log to TCP socket */ + time(&t); + tim=localtime(&t); + snprintf(outbuf, sizeof(outbuf) ,"%2.2i:%2.2i:%2.2i %s:%i ", + tim->tm_hour, tim->tm_min, tim->tm_sec, file, line); + write(debug_fd, outbuf, strlen(outbuf)); + vsnprintf(outbuf, sizeof(outbuf) , format, ap); + write(debug_fd, outbuf, strlen(outbuf)); + snprintf(outbuf, sizeof(outbuf) ,"\n"); + write(debug_fd, outbuf, strlen(outbuf)); + } pthread_mutex_unlock(&log_mutex); va_end(ap); @@ -124,7 +273,7 @@ void log_error(char *file, int line, const char *format, ...) { * INFO, WARN, ERROR output is always to syslog and if not daemonized * st STDOUT as well. */ - if (log_to_stdout) { + if (log_to_stderr) { /* not running as daemon - log to STDERR */ time(&t); tim=localtime(&t); @@ -139,6 +288,21 @@ void log_error(char *file, int line, const char *format, ...) { vsnprintf(string, sizeof(string), format, ap); syslog(LOG_USER|LOG_WARNING, "%s:%i ERROR:%s", file, line, string); } + /* + * Log to TCP + */ + if (debug_fd > 0) { + /* log to TCP socket */ + time(&t); + tim=localtime(&t); + snprintf(outbuf, sizeof(outbuf) ,"%2.2i:%2.2i:%2.2i ERROR:%s:%i ", + tim->tm_hour, tim->tm_min, tim->tm_sec, file, line); + write(debug_fd, outbuf, strlen(outbuf)); + vsnprintf(outbuf, sizeof(outbuf) , format, ap); + write(debug_fd, outbuf, strlen(outbuf)); + snprintf(outbuf, sizeof(outbuf) ,"\n"); + write(debug_fd, outbuf, strlen(outbuf)); + } pthread_mutex_unlock(&log_mutex); va_end(ap); @@ -160,7 +324,7 @@ void log_warn(char *file, int line, const char *format, ...) { * INFO, WARN, ERROR output is always to syslog and if not daemonized * st STDOUT as well. */ - if (log_to_stdout) { + if (log_to_stderr) { /* not running as daemon - log to STDERR */ time(&t); tim=localtime(&t); @@ -175,6 +339,21 @@ void log_warn(char *file, int line, const char *format, ...) { vsnprintf(string, sizeof(string), format, ap); syslog(LOG_USER|LOG_NOTICE, "%s:%i WARNING:%s", file, line, string); } + /* + * Log to TCP + */ + if (debug_fd > 0) { + /* log to TCP socket */ + time(&t); + tim=localtime(&t); + snprintf(outbuf, sizeof(outbuf) ,"%2.2i:%2.2i:%2.2i WARNING:%s:%i ", + tim->tm_hour, tim->tm_min, tim->tm_sec, file, line); + write(debug_fd, outbuf, strlen(outbuf)); + vsnprintf(outbuf, sizeof(outbuf) , format, ap); + write(debug_fd, outbuf, strlen(outbuf)); + snprintf(outbuf, sizeof(outbuf) ,"\n"); + write(debug_fd, outbuf, strlen(outbuf)); + } pthread_mutex_unlock(&log_mutex); va_end(ap); @@ -196,7 +375,7 @@ void log_info(char *file, int line, const char *format, ...) { * INFO, WARN, ERROR output is always to syslog and if not daemonized * st STDOUT as well. */ - if (log_to_stdout) { + if (log_to_stderr) { /* not running as daemon - log to STDERR */ time(&t); tim=localtime(&t); @@ -211,6 +390,21 @@ void log_info(char *file, int line, const char *format, ...) { vsnprintf(string, sizeof(string), format, ap); syslog(LOG_USER|LOG_NOTICE, "%s:%i INFO:%s", file, line, string); } + /* + * Log to TCP + */ + if (debug_fd > 0) { + /* log to TCP socket */ + time(&t); + tim=localtime(&t); + snprintf(outbuf, sizeof(outbuf) ,"%2.2i:%2.2i:%2.2i INFO:%s:%i ", + tim->tm_hour, tim->tm_min, tim->tm_sec, file, line); + write(debug_fd, outbuf, strlen(outbuf)); + vsnprintf(outbuf, sizeof(outbuf) , format, ap); + write(debug_fd, outbuf, strlen(outbuf)); + snprintf(outbuf, sizeof(outbuf) ,"\n"); + write(debug_fd, outbuf, strlen(outbuf)); + } pthread_mutex_unlock(&log_mutex); va_end(ap); @@ -225,10 +419,14 @@ void log_dump_buffer(int class, char *file, int line, char tmp[8], tmplin1[80], tmplin2[80]; if ((debug_pattern & class) == 0) return; - if (!log_to_stdout) return; + if ((!log_to_stderr) && (debug_fd <= 0)) return; pthread_mutex_lock(&log_mutex); - fprintf(stderr,"---BUFFER DUMP follows---\n"); + if (log_to_stderr) fprintf(stderr, "---BUFFER DUMP follows---\n"); + if (debug_fd > 0) { + snprintf(outbuf, sizeof(outbuf) ,"---BUFFER DUMP follows---\n"); + write(debug_fd, outbuf, strlen(outbuf)); + } for (i=0; i 0) { + snprintf(outbuf, sizeof(outbuf) ," %-47.47s %-16.16s\n", + tmplin1, tmplin2); + write(debug_fd, outbuf, strlen(outbuf)); + } } - fprintf(stderr,"\n---end of BUFFER DUMP---\n"); - fflush(stderr); + if (log_to_stderr) { + fprintf(stderr,"\n---end of BUFFER DUMP---\n"); + fflush(stderr); + } + if (debug_fd > 0) { + snprintf(outbuf, sizeof(outbuf) ,"---end of BUFFER DUMP---\n"); + write(debug_fd, outbuf, strlen(outbuf)); + } pthread_mutex_unlock(&log_mutex); return; } + diff --git a/src/log.h b/src/log.h index 391f2f4..a3f39ea 100644 --- a/src/log.h +++ b/src/log.h @@ -38,8 +38,11 @@ void log_set_pattern(int pattern); int log_get_pattern(void); -void log_set_stdout(int tostdout); +void log_set_stderr(int tostdout); void log_set_silence(int level); +void log_set_listen_port(int port); +void log_tcp_listen(void); +void log_tcp_connect(void); #undef DEBUG #define DEBUG(F...) log_debug(1,__FILE__, __LINE__,F) diff --git a/src/readconf.c b/src/readconf.c index ac24a47..c471380 100644 --- a/src/readconf.c +++ b/src/readconf.c @@ -144,6 +144,7 @@ static int parse_config (FILE *configfile) { void *dest; } configoptions[] = { { "debug_level", TYP_INT4, &configuration.debuglevel }, + { "debug_port", TYP_INT4, &configuration.debugport }, { "sip_listen_port", TYP_INT4, &configuration.sip_listen_port }, { "daemonize", TYP_INT4, &configuration.daemonize }, { "silence_log", TYP_INT4, &configuration.silence_log }, diff --git a/src/siproxd.c b/src/siproxd.c index 6951b0b..d01d6ba 100644 --- a/src/siproxd.c +++ b/src/siproxd.c @@ -88,7 +88,7 @@ int main (int argc, char *argv[]) char *pidfilename=NULL; struct sigaction act; - log_set_stdout(1); + log_set_stderr(1); /* * setup signal handlers @@ -191,6 +191,7 @@ int main (int argc, char *argv[]) /* set debug level as desired */ log_set_pattern(configuration.debuglevel); + log_set_listen_port(configuration.debugport); /* change user and group IDs */ secure_enviroment(); @@ -202,7 +203,7 @@ int main (int argc, char *argv[]) setsid(); if (fork()!=0) exit(0); - log_set_stdout(0); + log_set_stderr(0); INFO("daemonized, pid=%i", getpid()); } @@ -255,11 +256,14 @@ int main (int argc, char *argv[]) */ while (!exit_program) { - DEBUGC(DBCLASS_BABBLE,"going into sip_wait\n"); + DEBUGC(DBCLASS_BABBLE,"going into sipsock_wait\n"); while (sipsock_wait()<=0) { /* got no input, here by timeout. do aging */ register_agemap(); + /* TCP log: check for a connection */ + log_tcp_connect(); + /* dump memory stats if requested to do so */ if (dmalloc_dump) { dmalloc_dump=0; @@ -276,7 +280,7 @@ int main (int argc, char *argv[]) } /* got input, process */ - DEBUGC(DBCLASS_BABBLE,"back from sip_wait"); + DEBUGC(DBCLASS_BABBLE,"back from sipsock_wait"); i=sipsock_read(&buff, sizeof(buff)-1, &ticket.from, &ticket.protocol); buff[i]='\0'; diff --git a/src/siproxd.h b/src/siproxd.h index 9a7b5a5..79690ae 100644 --- a/src/siproxd.h +++ b/src/siproxd.h @@ -57,6 +57,7 @@ typedef struct { */ struct siproxd_config { int debuglevel; + int debugport; char *inbound_if; char *outbound_if; int sip_listen_port; diff --git a/src/sock.c b/src/sock.c index f48bdfe..d9af8e8 100644 --- a/src/sock.c +++ b/src/sock.c @@ -68,7 +68,7 @@ int sipsock_listen (void) { } /* - * Wait for incoming SIP message. After a 5 sec timeout + * Wait for incoming SIP message. After a 2 sec timeout * this function returns with sts=0 * * RETURNS >0 if data received, =0 if nothing received /T/O), -1 on error @@ -78,7 +78,7 @@ int sipsock_wait(void) { fd_set fdset; struct timeval timeout; - timeout.tv_sec=5; + timeout.tv_sec=2; timeout.tv_usec=0; FD_ZERO(&fdset);