Tobias Ulmer wrote:
> On Tue, Sep 22, 2015 at 11:46:08AM -0400, Ted Unangst wrote:
> > Todd C. Miller wrote:
> > > On Mon, 21 Sep 2015 20:13:05 -0400, "Ted Unangst" wrote:
> > >
> > > > We can put a "long" poll() in front of pcap to wait until there are
> > > > packets
> > > > (maybe never if you aren't using pf logging), and then let the timeout
> > > > work
> > > > it's magic.
> > >
> > > This:
> > >
> > > > + if (poll(&pfd, 1, INFTIM) == 1) {
> > >
> > > will also match POLLHUP and POLLERR which doesn't appear to be what
> > > you want. You need to explicitly check for pfd.revents & POLLIN.
> >
> > poll, you sneaky bastard. I wonder if this program could also benefit from
> > handling signals via kevent, but that's a bigger change.
> >
>
> WIP:
Do you have an udpated version of this? I let it drop, but I think we should
try moving ahead.
>
> Index: pflogd.c
> ===================================================================
> RCS file: /home/vcs/cvs/openbsd/src/sbin/pflogd/pflogd.c,v
> retrieving revision 1.51
> diff -u -p -r1.51 pflogd.c
> --- pflogd.c 7 Feb 2015 02:09:13 -0000 1.51
> +++ pflogd.c 23 Sep 2015 03:47:37 -0000
> @@ -32,6 +32,7 @@
>
> #include <sys/types.h>
> #include <sys/ioctl.h>
> +#include <sys/event.h>
> #include <sys/stat.h>
> #include <sys/socket.h>
> #include <net/if.h>
> @@ -57,8 +58,6 @@ int Debug = 0;
> static int snaplen = DEF_SNAPLEN;
> static int cur_snaplen = DEF_SNAPLEN;
>
> -volatile sig_atomic_t gotsig_close, gotsig_alrm, gotsig_hup, gotsig_usr1;
> -
> char *filename = PFLOGD_LOG_FILE;
> char *interface = PFLOGD_DEFAULT_IF;
> char *filter = NULL;
> @@ -66,7 +65,6 @@ char *filter = NULL;
> char errbuf[PCAP_ERRBUF_SIZE];
>
> int log_debug = 0;
> -unsigned int delay = FLUSH_DELAY;
>
> char *copy_argv(char * const *);
> void dump_packet(u_char *, const struct pcap_pkthdr *, const u_char *);
> @@ -81,10 +79,6 @@ int reset_dump(int);
> int scan_dump(FILE *, off_t);
> int set_snaplen(int);
> void set_suspended(int);
> -void sig_alrm(int);
> -void sig_usr1(int);
> -void sig_close(int);
> -void sig_hup(int);
> void usage(void);
>
> static int try_reset_dump(int);
> @@ -95,6 +89,7 @@ static int buflen = 0; /* allocated s
> static char *buffer = NULL; /* packet buffer */
> static char *bufpos = NULL; /* position in buffer */
> static int bufleft = 0; /* bytes left in buffer */
> +static int buftimer = 0; /* periodic buffer flush on/off */
>
> /* if error, stop logging but count dropped packets */
> static int suspended = -1;
> @@ -162,30 +157,6 @@ usage(void)
> }
>
> void
> -sig_close(int sig)
> -{
> - gotsig_close = 1;
> -}
> -
> -void
> -sig_hup(int sig)
> -{
> - gotsig_hup = 1;
> -}
> -
> -void
> -sig_alrm(int sig)
> -{
> - gotsig_alrm = 1;
> -}
> -
> -void
> -sig_usr1(int sig)
> -{
> - gotsig_usr1 = 1;
> -}
> -
> -void
> set_pcap_filter(void)
> {
> struct bpf_program bprog;
> @@ -224,7 +195,7 @@ if_exists(char *ifname)
> int
> init_pcap(void)
> {
> - hpcap = pcap_open_live(interface, snaplen, 1, PCAP_TO_MS, errbuf);
> + hpcap = pcap_open_live(interface, snaplen, 1, 0, errbuf);
> if (hpcap == NULL) {
> logmsg(LOG_ERR, "Failed to initialize: %s", errbuf);
> return (-1);
> @@ -439,6 +410,7 @@ void
> dump_packet_nobuf(u_char *user, const struct pcap_pkthdr *h, const u_char
> *sp)
> {
> FILE *f = (FILE *)user;
> + fprintf(stderr, "%s called\n", __func__);
>
> if (suspended) {
> packets_dropped++;
> @@ -453,7 +425,7 @@ dump_packet_nobuf(u_char *user, const st
> ftruncate(fileno(f), pos - sizeof(*h))) {
> logmsg(LOG_ERR, "Write failed, corrupted logfile!");
> set_suspended(1);
> - gotsig_close = 1;
> + raise(SIGTERM);
> return;
> }
> goto error;
> @@ -499,6 +471,7 @@ flush_buffer(FILE *f)
> bufpos = buffer;
> bufleft = buflen;
> bufpkt = 0;
> + buftimer = 0;
>
> return (0);
> }
> @@ -512,6 +485,7 @@ purge_buffer(void)
> bufpos = buffer;
> bufleft = buflen;
> bufpkt = 0;
> + buftimer = 0;
> }
>
> /* append packet to the buffer, flushing if necessary */
> @@ -521,6 +495,8 @@ dump_packet(u_char *user, const struct p
> FILE *f = (FILE *)user;
> size_t len = sizeof(*h) + h->caplen;
>
> + fprintf(stderr, "%s called\n", __func__);
> +
> if (len < sizeof(*h) || h->caplen > (size_t)cur_snaplen) {
> logmsg(LOG_NOTICE, "invalid size %zu (%d/%d), packet dropped",
> len, cur_snaplen, snaplen);
> @@ -553,6 +529,7 @@ dump_packet(u_char *user, const struct p
> bufpos += len;
> bufleft -= len;
> bufpkt++;
> + buftimer = 1;
>
> return;
> }
> @@ -575,6 +552,9 @@ main(int argc, char **argv)
> int ch, np, ret, Xflag = 0;
> pcap_handler phandler = dump_packet;
> const char *errstr = NULL;
> + int kq, pcap_fd, nchanges;
> + int delay = FLUSH_DELAY * 1000;
> + struct kevent ev[6];
>
> ret = 0;
>
> @@ -586,7 +566,7 @@ main(int argc, char **argv)
> Debug = 1;
> break;
> case 'd':
> - delay = strtonum(optarg, 5, 60*60, &errstr);
> + delay = strtonum(optarg, 5, 60*60, &errstr) * 1000;
> if (errstr)
> usage();
> break;
> @@ -657,16 +637,13 @@ main(int argc, char **argv)
>
> setproctitle("[initializing]");
> /* Process is now unprivileged and inside a chroot */
> - signal(SIGTERM, sig_close);
> - signal(SIGINT, sig_close);
> - signal(SIGQUIT, sig_close);
> - signal(SIGALRM, sig_alrm);
> - signal(SIGUSR1, sig_usr1);
> - signal(SIGHUP, sig_hup);
> - alarm(delay);
>
> - buffer = malloc(PFLOGD_BUFSIZE);
> + if ((kq = kqueue()) < 0) {
> + logmsg(LOG_ERR, "Kqueue failed");
> + exit(1);
> + }
>
> + buffer = malloc(PFLOGD_BUFSIZE);
> if (buffer == NULL) {
> logmsg(LOG_WARNING, "Failed to allocate output buffer");
> phandler = dump_packet_nobuf;
> @@ -674,6 +651,7 @@ main(int argc, char **argv)
> bufleft = buflen = PFLOGD_BUFSIZE;
> bufpos = buffer;
> bufpkt = 0;
> + buftimer = 0;
> }
>
> if (reset_dump(Xflag) < 0) {
> @@ -685,42 +663,98 @@ main(int argc, char **argv)
> } else if (Xflag)
> return (0);
>
> + if ((pcap_fd = pcap_get_selectable_fd(hpcap)) < 0) {
> + logmsg(LOG_ERR, "pcap_get_selectable_fd failed");
> + exit(1);
> + }
> + EV_SET(&ev[0], pcap_fd, EVFILT_READ, EV_ADD | EV_CLEAR, 0, 0, NULL);
> +
> + signal(SIGTERM, SIG_IGN);
> + EV_SET(&ev[1], SIGTERM, EVFILT_SIGNAL, EV_ADD, 0, 0, NULL);
> + signal(SIGINT, SIG_IGN);
> + EV_SET(&ev[2], SIGINT, EVFILT_SIGNAL, EV_ADD, 0, 0, NULL);
> + signal(SIGQUIT, SIG_IGN);
> + EV_SET(&ev[3], SIGQUIT, EVFILT_SIGNAL, EV_ADD, 0, 0, NULL);
> + signal(SIGUSR1, SIG_IGN);
> + EV_SET(&ev[4], SIGUSR1, EVFILT_SIGNAL, EV_ADD, 0, 0, NULL);
> + signal(SIGHUP, SIG_IGN);
> + EV_SET(&ev[5], SIGHUP, EVFILT_SIGNAL, EV_ADD, 0, 0, NULL);
> + nchanges = 6;
> +
> +
> while (1) {
> - np = pcap_dispatch(hpcap, PCAP_NUM_PKTS,
> - phandler, (u_char *)dpcap);
> - if (np < 0) {
> - if (!if_exists(interface)) {
> - logmsg(LOG_NOTICE, "interface %s went away",
> - interface);
> - ret = -1;
> + int events;
> + fprintf(stderr, "main loop (nchanges=%d)...\n", nchanges);
> + events = kevent(kq, ev, nchanges, ev, 1, NULL);
> + nchanges = 0;
> + fprintf(stderr, "kevent returns %d\n", events);
> + if (events == 0) /* timeout */
> + continue;
> + if (events < 0) {
> + logmsg(LOG_ERR, "event loop error");
> + break;
> + }
> +
> + if (ev->filter == EVFILT_SIGNAL) {
> + fprintf(stderr, "received signal %d\n", (int)ev->ident);
> + if (ev->ident == SIGTERM || ev->ident == SIGINT
> + || ev->ident == SIGQUIT) {
> + fprintf(stderr, "leaving main loop\n");
> break;
> }
> - logmsg(LOG_NOTICE, "%s", pcap_geterr(hpcap));
> - }
>
> - if (gotsig_close)
> - break;
> - if (gotsig_hup) {
> - if (reset_dump(0)) {
> - logmsg(LOG_ERR,
> - "Logging suspended: open error");
> - set_suspended(1);
> + if (ev->ident == SIGHUP) {
> + fprintf(stderr, "got SIGHUP\n");
> + if (reset_dump(0)) {
> + logmsg(LOG_ERR,
> + "Logging suspended: open error");
> + set_suspended(1);
> + }
> + }
> +
> + if (ev->ident == SIGUSR1) {
> + fprintf(stderr, "got SIGUSR1\n");
> + log_pcap_stats();
> + }
> + } else if (ev->filter == EVFILT_READ) {
> + fprintf(stderr, "pcap data available\n");
> + np = pcap_dispatch(hpcap, PCAP_NUM_PKTS, phandler,
> (u_char *)dpcap);
> + fprintf(stderr, "pcap_dispatch returned %d\n", np);
> + if (np < 0) {
> + if (!if_exists(interface)) {
> + logmsg(LOG_NOTICE,
> + "interface %s went away",
> interface);
> + ret = -1;
> + break;
> + }
> + logmsg(LOG_NOTICE, "%s", pcap_geterr(hpcap));
> }
> - gotsig_hup = 0;
> - }
>
> - if (gotsig_alrm) {
> - if (dpcap)
> + if (buftimer) {
> + fprintf(stderr, "arming timer\n");
> + EV_SET(&ev[nchanges], 0, EVFILT_TIMER,
> + EV_ADD | EV_ENABLE, 0, delay, NULL);
> + nchanges++;
> + }
> + } else if (ev->filter == EVFILT_TIMER) {
> + fprintf(stderr, "EVFILT_TIMER event\n");
> + if (dpcap) {
> + fprintf(stderr, "calling flush_buffer()\n");
> flush_buffer(dpcap);
> - else
> - gotsig_hup = 1;
> - gotsig_alrm = 0;
> - alarm(delay);
> - }
> + } else {
> + if (reset_dump(0)) {
> + logmsg(LOG_ERR,
> + "Logging suspended: open error");
> + set_suspended(1);
> + }
> + }
>
> - if (gotsig_usr1) {
> - log_pcap_stats();
> - gotsig_usr1 = 0;
> + if (!buftimer) {
> + fprintf(stderr, "disarming timer\n");
> + EV_SET(&ev[nchanges], 0, EVFILT_TIMER,
> + EV_ADD | EV_DISABLE, 0, delay, NULL);
> + nchanges++;
> + }
> }
> }
>
> Index: pflogd.h
> ===================================================================
> RCS file: /home/vcs/cvs/openbsd/src/sbin/pflogd/pflogd.h,v
> retrieving revision 1.4
> diff -u -p -r1.4 pflogd.h
> --- pflogd.h 21 Sep 2010 05:56:58 -0000 1.4
> +++ pflogd.h 23 Sep 2015 03:47:37 -0000
> @@ -20,7 +20,6 @@
> #include <pcap.h>
>
> #define DEF_SNAPLEN 160 /* pfloghdr + ip hdr + proto hdr fit
> usually */
> -#define PCAP_TO_MS 500 /* pcap read timeout (ms) */
> #define PCAP_NUM_PKTS 1000 /* max number of packets to process at each
> loop */
> #define PCAP_OPT_FIL 1 /* filter optimization */
> #define FLUSH_DELAY 60 /* flush delay */