ulogd: restructures signal handling by self-pipe trick

ulogd had a critical bug that is calling Async-Signal-Unsafe functions
in signal hander context.
  - 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=0x7f3c3fd4b2c3 "/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=0x742500)
     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@entry=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@jp.fujitsu.com>

diff --git a/src/ulogd.c b/src/ulogd.c
index 958c30a2dbbaa0c266e2c340620654a20dc7b5e0..c8d9376e0b83492993c8465f6f824fb940d44fa5 100644 (file)
--- 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 */
@@ -386,6 +409,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);
 }