Hello, On Tue, 2016-02-02 at 23:01 +0900, Hironobu Ishii wrote: > ulogd had a critical bug that is calling Async-Signal-Unsafe > functions > in signal hander context. Thanks a lot for this detailed bug report and fix. I'm gonna apply it with minor white space fixes. BR, -- Eric. > - Most of libc functions like fopen(), malloc() are Async-Signal- > Unsafe. > So you should not call these functions in signal handler context. > - Calling pluginstances in signal handler context is danger. > For implementer of pluginstances, it is very hard to recognize > their > functions are called in signal handler context. > > To solve the issue, I restructured signal handling by self-pipe > trick. > For more detail on self-pipe trick, please see the following. > https://lwn.net/Articles/177897/ > > This patch will solve various symptoms like following. > - Deadlock > - Segmentation fault caused by libc management data corruption, > - Other unpredictable behavior. > > Deadlock example > ================ > This bug was already filed at: > https://bugzilla.netfilter.org/show_bug.cgi?id=1030 > > I also hit this bug. The backtrace of this issue is following. > In this case, main thread was calling ctime(), > and signal handler called localtime_r(). > That caused the dead lock while getting tzset_lock in __tz_convert(). > Because vsyslog() is Async-Signal-Unsafe function, we cannot call > this function in signal handler context. > > (gdb) bt > #0 __lll_lock_wait_private () at > ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:95 > #1 0x00007f3c3fc7e4ac in _L_lock_2462 () at tzset.c:621 > #2 0x00007f3c3fc7e2e7 in __tz_convert (timer=0x7f3c3ff8bf00 > <tzset_lock>, > timer@entry=0x7fffcfa923b8, use_localtime=use_localtime@entry=1, > tp=tp@entry=0x7fffcfa92400) at tzset.c:624 > #3 0x00007f3c3fc7c28d in __localtime_r (t=t@entry=0x7fffcfa923b8, > tp=tp@entry=0x7fffcfa92400) at localtime.c:32 > #4 0x00007f3c3fcbf1ba in __GI___vsyslog_chk (pri=<optimized out>, > flag=1, > fmt=0x406fa8 "signal received, calling pluginstances\n", > ap=0x7fffcfa924a0) > at ../misc/syslog.c:199 > #5 0x00000000004037b5 in __ulogd_log () > #6 0x00000000004047be in signal_handler () > #7 <signal handler called> > #8 0x00007f3c3fcb62f5 in __GI___xstat (vers=<optimized out>, > name=0x7f3c3fd4b2c3 "/etc/localtime", buf=0x7fffcfa92c10) > at ../sysdeps/unix/sysv/linux/wordsize-64/xstat.c:37 > #9 0x00007f3c3fc7e5f6 in __tzfile_read (file=file@entry=0x7f3c3fd4b > 2c3 "/etc/localtime", > extra=extra@entry=0, extrap=extrap@entry=0x0) at tzfile.c:170 > #10 0x00007f3c3fc7d954 in tzset_internal (always=<optimized out>, > explicit=explicit@entry=1) at tzset.c:444 > #11 0x00007f3c3fc7e303 in __tz_convert (timer=0x7fffcfa92d50, > use_localtime=use_localtime@entry=1, tp=tp@entry=0x7f3c3ff8ed80 > <_tmbuf>) > at tzset.c:629 > #12 0x00007f3c3fc7c2a1 in __GI_localtime (t=<optimized out>) at > localtime.c:42 > #13 0x00007f3c3fc7c1f9 in ctime (t=<optimized out>) at ctime.c:27 > #14 0x00007f3c3e180ec2 in ?? () > #15 0x0000000056a100c2 in ?? () > #16 0xf8570f79d4fc4200 in ?? () > #17 0x000000000209bec0 in ?? () > #18 0x00007f3c4059f1f8 in ?? () > #19 0x000000000000003c in ?? () > #20 0x0000000000404952 in ulogd_propagate_results () > #21 0x00007f3c3f9cc203 in ?? () > #22 0x0000000000000000 in ?? () > > Segmentation fault in free() > ============================ > From my experience, I think this was caused by some routine called > malloc()/free() in signal handler context. > By that, malloc() management data became inconsistent. > As a result, free() made a wrong dereference. > > Program terminated with signal SIGSEGV, Segmentation fault. > #0 __GI___libc_free (mem=0x7f430f011000) at malloc.c:2903 > 2903 if (chunk_is_mmapped(p)) /* release > mmapped memory. */ > (gdb) bt > #0 __GI___libc_free (mem=0x7f430f011000) at malloc.c:2903 > #1 0x00007f430e68affa in __GI__IO_free_backup_area (fp=fp@entry=0x7 > 42500) > at genops.c:210 > #2 0x00007f430e68a795 in _IO_new_file_overflow (f=0x742500, ch=-1) > at fileops.c:849 > #3 0x00007f430e689511 in _IO_new_file_xsputn (f=0x742500, > data=<optimized out>, n=15) > at fileops.c:1372 > #4 0x00007f430e65aa4d in _IO_vfprintf_internal (s=s@entry=0x742500, > format=<optimized out>, format@entry=0x7f430cbc4008 "%.15s %s > %s", > ap=ap@entry=0x7fff456ece38) at vfprintf.c:1635 > #5 0x00007f430e71d615 in ___fprintf_chk (fp=0x742500, flag=flag@ent > ry=1, > format=format@entry=0x7f430cbc4008 "%.15s %s %s") at > fprintf_chk.c:36 > #6 0x00007f430cbc3f04 in fprintf (__fmt=0x7f430cbc4008 "%.15s %s > %s", > __stream=<optimized out>) at /usr/include/bits/stdio2.h:97 > #7 _output_logemu (upi=0x74e5a0) at ulogd_output_LOGEMU.c:102 > #8 0x0000000000404952 in ulogd_propagate_results () > #9 0x00007f430e40f203 in interp_packet (ldata=0x7fff456ed060, > pf_family=2 '\002', > upi=0x74a6b0) at ulogd_inppkt_NFLOG.c:400 > #10 msg_cb (gh=<optimized out>, nfmsg=0x7f430efe2020, > nfa=0x7fff456ed060, data=0x74a6b0) > at ulogd_inppkt_NFLOG.c:483 > #11 0x00007f430e20a307 in __nflog_rcv_pkt (nlh=<optimized out>, > nfa=<optimized out>, > data=<optimized out>) at libnetfilter_log.c:160 > #12 0x00007f430e0056b7 in __nfnl_handle_msg (len=268, > nlh=0x7f430efe2010, h=0x74e8e0) > at libnfnetlink.c:1236 > #13 nfnl_handle_packet (h=0x74e8e0, buf=0x7f430efe2010 "\f\001", > len=<optimized out>) > at libnfnetlink.c:1256 > #14 0x00007f430e20a508 in nflog_handle_packet (h=<optimized out>, > buf=<optimized out>, > len=<optimized out>) at libnetfilter_log.c:323 > #15 0x00007f430e40eaed in nful_read_cb (fd=<optimized out>, > what=<optimized out>, > param=0x74a6b0) at ulogd_inppkt_NFLOG.c:463 > #16 0x0000000000404ee0 in ulogd_select_main () > #17 0x0000000000402b17 in main () > > Signed-off-by: Hironobu Ishii <ishii.hironobu@xxxxxxxxxxxxxx> > --- > src/ulogd.c | 132 > ++++++++++++++++++++++++++++++++++++++++++++++++++++++++---- > 1 file changed, 125 insertions(+), 7 deletions(-) > > diff --git a/src/ulogd.c b/src/ulogd.c > index 958c30a..4c76e43 100644 > --- a/src/ulogd.c > +++ b/src/ulogd.c > @@ -90,6 +90,29 @@ static int info_mode = 0; > static int verbose = 0; > static int created_pidfile = 0; > > +/* > + * Using self-pipe trick to handle signals safely. > + * (To avoid calling Async-Signal-Unsafe functions in signal > handler.) > + * > + * cf. https://lwn.net/Articles/177897/ > + * > + * Capacity of pipe(2) buffer is >= 4096. > + */ > +static int signal_channel[2] = { -1, -1 }; /* initialize with > invalid fd */ > +#define SIGNAL_RX_FD (signal_channel[0]) /* > main thread select() this fd */ > +#define SIGNAL_TX_FD (signal_channel[1]) /* > signal handler writes to this fd */ > + > +static void signal_handler(int signal); > +static void sigterm_handler_task(int signal); > +static void signal_handler_task(int signal); > + > +static int signal_channel_callback(int fd, unsigned int what, void > *data); > +static struct ulogd_fd signal_channel_ulogfd = { > + .when = ULOGD_FD_READ, > + .cb = &signal_channel_callback, > + .data = &signal_channel_ulogfd, > +}; > + > /* linked list for all registered plugins */ > static LLIST_HEAD(ulogd_plugins); > /* linked list for all plugins handle */ > @@ -387,6 +410,80 @@ void ulogd_register_plugin(struct ulogd_plugin > *me) > } > > /******************************************************************* > **** > + * UTILITY FUNCTIONS FOR SIGNAL HANDLING > + > ********************************************************************* > **/ > +static void call_signal_handler_tasks(int sig) > +{ > + /* Deliver signals */ > + switch (sig) { > + case SIGTERM: > + case SIGINT: > + sigterm_handler_task(sig); > + break; > + case SIGHUP: > + case SIGALRM: > + case SIGUSR1: > + case SIGUSR2: > + signal_handler_task(sig); > + break; > + default: > + break; > + } > +} > + > +static int signal_channel_callback(int fd, unsigned int what, void > *data) > +{ > + int ret; > + unsigned char c; > + > + while ((ret = read(fd, &c, 1)) > 0) { > + call_signal_handler_tasks((int)c); > + } > + return 0; > +} > + > +static int create_signal_channel(void) > +{ > + int ret; > + long flags; > + > + if ((ret = pipe(signal_channel)) < 0) > + return ret; > + > + /* SIGNAL_RX_FD, channel[0] */ > + if ((flags = fcntl(SIGNAL_RX_FD, F_GETFL)) < 0) > + goto err_exit; > + flags |= O_NONBLOCK; > + if ( fcntl(SIGNAL_RX_FD, F_SETFL, flags) < 0 ) > + goto err_exit; > + > + /* SIGNAL_TX_FD, channel[1] */ > + if ((flags = fcntl(SIGNAL_TX_FD, F_GETFL)) < 0) > + goto err_exit; > + flags |= O_NONBLOCK; > + if ( fcntl(SIGNAL_TX_FD, F_SETFL, flags) < 0 ) > + goto err_exit; > + > + /* register SIGNAL_RX_FD to ulogd */ > + signal_channel_ulogfd.fd = SIGNAL_RX_FD; > + ulogd_register_fd(&signal_channel_ulogfd); > + > + return 0; > + > +err_exit: > + if (SIGNAL_RX_FD >= 0) { > + (void)close(SIGNAL_RX_FD); > + SIGNAL_RX_FD = -1; > + } > + if (SIGNAL_TX_FD >= 0) { > + (void)close(SIGNAL_TX_FD); > + SIGNAL_TX_FD = -1; > + } > + return -1; > +} > + > + > +/******************************************************************* > **** > * MAIN PROGRAM > > ********************************************************************* > **/ > > @@ -925,7 +1022,6 @@ static void ulogd_main_loop(void) > struct timeval *next = NULL; > > while (1) { > - /* XXX: signal blocking? */ > if (next != NULL && !timerisset(next)) > next = ulogd_do_timer_run(&next_alarm); > else > @@ -1225,7 +1321,19 @@ static void stop_stack() > } > > > -static void sigterm_handler(int signal) > +/* This is a real SIGTERM, SIGINT, SIGHUP, SIGALRM, SIGUSR1, SIGUSR2 > handler */ > +static void signal_handler(int signal) > +{ > + unsigned char c = (unsigned char)signal; > + > + (void)write(SIGNAL_TX_FD, &c, 1); > +} > + > +/* This is NOT a real signal handler. > + * It is called in ulogd_main_loop() to avoid > + * calling Async-Signal-UnSafe functions in signal handler. > + */ > +static void sigterm_handler_task(int signal) > { > > ulogd_log(ULOGD_NOTICE, "Terminal signal received, > exiting\n"); > @@ -1255,7 +1363,12 @@ static void sigterm_handler(int signal) > exit(0); > } > > -static void signal_handler(int signal) > + > +/* This is NOT a real signal handler. > + * It is called in ulogd_main_loop() to avoid > + * calling Async-Signal-UnSafe functions in signal handler. > + */ > +static void signal_handler_task(int signal) > { > ulogd_log(ULOGD_NOTICE, "signal received, calling > pluginstances\n"); > > @@ -1269,7 +1382,7 @@ static void signal_handler(int signal) > fprintf(stderr, > "ERROR: can't open logfile > %s: %s\n", > ulogd_logfile, > strerror(errno)); > - sigterm_handler(signal); > + sigterm_handler_task(signal); > } > > } > @@ -1464,8 +1577,13 @@ int main(int argc, char* argv[]) > } > } > > - signal(SIGTERM, &sigterm_handler); > - signal(SIGINT, &sigterm_handler); > + if (create_signal_channel() < 0) { > + ulogd_log(ULOGD_FATAL, "can't create signal > channel\n"); > + warn_and_exit(daemonize); > + } > + > + signal(SIGTERM, &signal_handler); > + signal(SIGINT, &signal_handler); > signal(SIGHUP, &signal_handler); > signal(SIGALRM, &signal_handler); > signal(SIGUSR1, &signal_handler); > @@ -1477,6 +1595,6 @@ int main(int argc, char* argv[]) > ulogd_main_loop(); > > /* hackish, but result is the same */ > - sigterm_handler(SIGTERM); > + sigterm_handler_task(SIGTERM); > return(0); > } -- Eric Leblond <eric@xxxxxxxxx> -- To unsubscribe from this list: send the line "unsubscribe netfilter-devel" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html
