From 16596db60f50f7a2f26b1e45158d41df037b88c3 Mon Sep 17 00:00:00 2001 From: asomers Date: Mon, 1 Jul 2013 21:20:17 +0000 Subject: [PATCH] Add syslog(3) support to devd(8). sbin/devd/devd.cc All output will now go to syslog(3) if devd is daemonized, or stderr if it's running in the foreground. sbin/devd/devd.8 Remove the "-D" flag. Filtering messages by priority now happens in the usual syslog way. For performance reasons, a few extra-verbose debugging statements are now conditional on the "-d" (do not daemonize) flag. etc/syslog.conf etc/newsyslog.conf Direct messages from devd(8) to /var/log/devd.log, but leave it disabled by default Reviewed by: eadler Approved by: gibbs (co-mentor) MFC after: never (removed a command-line option from devd) --- etc/newsyslog.conf | 1 + etc/syslog.conf | 4 +++ sbin/devd/devd.8 | 6 ++-- sbin/devd/devd.cc | 90 +++++++++++++++++++++++++++++----------------- 4 files changed, 65 insertions(+), 36 deletions(-) diff --git a/etc/newsyslog.conf b/etc/newsyslog.conf index 76e07070bb1f..9572f84efd1c 100644 --- a/etc/newsyslog.conf +++ b/etc/newsyslog.conf @@ -32,6 +32,7 @@ /var/log/monthly.log 640 12 * $M1D0 JN /var/log/pflog 600 3 100 * JB /var/run/pflogd.pid /var/log/ppp.log root:network 640 3 100 * JC +/var/log/devd.log 644 3 100 * JC /var/log/security 600 10 100 * JC /var/log/sendmail.st 640 10 * 168 BN /var/log/utx.log 644 3 * @01T05 B diff --git a/etc/syslog.conf b/etc/syslog.conf index 242d27aff75b..702bd664215d 100644 --- a/etc/syslog.conf +++ b/etc/syslog.conf @@ -13,6 +13,7 @@ mail.info /var/log/maillog lpr.info /var/log/lpd-errs ftp.info /var/log/xferlog cron.* /var/log/cron +!-devd *.=debug /var/log/debug.log *.emerg * # uncomment this to log all writes to /dev/console to /var/log/console.log @@ -27,6 +28,9 @@ cron.* /var/log/cron # news.crit /var/log/news/news.crit # news.err /var/log/news/news.err # news.notice /var/log/news/news.notice +# Uncomment this if you wish to see messages produced by devd +# !devd +# *.>=info /var/log/devd.log !ppp *.* /var/log/ppp.log !* diff --git a/sbin/devd/devd.8 b/sbin/devd/devd.8 index 8e332366dc9e..1869de62f07a 100644 --- a/sbin/devd/devd.8 +++ b/sbin/devd/devd.8 @@ -33,7 +33,7 @@ .Nd "device state change daemon" .Sh SYNOPSIS .Nm -.Op Fl Ddn +.Op Fl dn .Op Fl f Ar file .Op Fl l Ar num .Sh DESCRIPTION @@ -44,10 +44,8 @@ kernel events happen. .Pp The following options are accepted. .Bl -tag -width ".Fl f Ar file" -.It Fl D -Enable debugging messages. .It Fl d -Run in the foreground instead of becoming a daemon. +Run in the foreground instead of becoming a daemon and log additional information for debugging. .It Fl f Ar file Use configuration file .Ar file diff --git a/sbin/devd/devd.cc b/sbin/devd/devd.cc index b2275898dfcd..367349369c1f 100644 --- a/sbin/devd/devd.cc +++ b/sbin/devd/devd.cc @@ -87,6 +87,7 @@ __FBSDID("$FreeBSD$"); #include #include #include +#include #include #include @@ -114,13 +115,13 @@ static const char detach = '-'; static struct pidfh *pfh; -int Dflag; int dflag; int nflag; static volatile sig_atomic_t romeo_must_die = 0; static const char *configfile = CF; +static void devdlog(int priority, const char* message, ...); static void event_loop(void); static void usage(void); @@ -243,8 +244,7 @@ bool action::do_action(config &c) { string s = c.expand_string(_cmd.c_str()); - if (Dflag) - fprintf(stderr, "Executing '%s'\n", s.c_str()); + devdlog(LOG_NOTICE, "Executing '%s'\n", s.c_str()); my_system(s.c_str()); return (true); } @@ -268,9 +268,16 @@ match::do_match(config &c) const string &value = c.get_variable(_var); bool retval; - if (Dflag) - fprintf(stderr, "Testing %s=%s against %s, invert=%d\n", + /* + * This function gets called WAY too often to justify calling syslog() + * each time, even at LOG_DEBUG. Because if syslogd isn't running, it + * can consume excessive amounts of systime inside of connect(). Only + * log when we're in -d mode. + */ + if (dflag) { + devdlog(LOG_DEBUG, "Testing %s=%s against %s, invert=%d\n", _var.c_str(), value.c_str(), _re.c_str(), _inv); + } retval = (regexec(&_regex, value.c_str(), 0, NULL, 0) == 0); if (_inv == 1) @@ -322,8 +329,7 @@ media::do_match(config &c) value = c.get_variable("device-name"); if (value.empty()) value = c.get_variable("subsystem"); - if (Dflag) - fprintf(stderr, "Testing media type of %s against 0x%x\n", + devdlog(LOG_DEBUG, "Testing media type of %s against 0x%x\n", value.c_str(), _type); retval = false; @@ -335,13 +341,11 @@ media::do_match(config &c) if (ioctl(s, SIOCGIFMEDIA, (caddr_t)&ifmr) >= 0 && ifmr.ifm_status & IFM_AVALID) { - if (Dflag) - fprintf(stderr, "%s has media type 0x%x\n", + devdlog(LOG_DEBUG, "%s has media type 0x%x\n", value.c_str(), IFM_TYPE(ifmr.ifm_active)); retval = (IFM_TYPE(ifmr.ifm_active) == _type); } else if (_type == -1) { - if (Dflag) - fprintf(stderr, "%s has unknown media type\n", + devdlog(LOG_DEBUG, "%s has unknown media type\n", value.c_str()); retval = true; } @@ -374,8 +378,14 @@ var_list::is_set(const string &var) const void var_list::set_variable(const string &var, const string &val) { - if (Dflag) - fprintf(stderr, "setting %s=%s\n", var.c_str(), val.c_str()); + /* + * This function gets called WAY too often to justify calling syslog() + * each time, even at LOG_DEBUG. Because if syslogd isn't running, it + * can consume excessive amounts of systime inside of connect(). Only + * log when we're in -d mode. + */ + if (dflag) + devdlog(LOG_DEBUG, "setting %s=%s\n", var.c_str(), val.c_str()); _vars[var] = val; } @@ -393,8 +403,7 @@ config::reset(void) void config::parse_one_file(const char *fn) { - if (Dflag) - fprintf(stderr, "Parsing %s\n", fn); + devdlog(LOG_DEBUG, "Parsing %s\n", fn); yyin = fopen(fn, "r"); if (yyin == NULL) err(1, "Cannot open config file %s", fn); @@ -411,8 +420,7 @@ config::parse_files_in_dir(const char *dirname) struct dirent *dp; char path[PATH_MAX]; - if (Dflag) - fprintf(stderr, "Parsing files in %s\n", dirname); + devdlog(LOG_DEBUG, "Parsing files in %s\n", dirname); dirp = opendir(dirname); if (dirp == NULL) return; @@ -539,8 +547,7 @@ config::push_var_table() vl = new var_list(); _var_list_table.push_back(vl); - if (Dflag) - fprintf(stderr, "Pushing table\n"); + devdlog(LOG_DEBUG, "Pushing table\n"); } void @@ -548,8 +555,7 @@ config::pop_var_table() { delete _var_list_table.back(); _var_list_table.pop_back(); - if (Dflag) - fprintf(stderr, "Popping table\n"); + devdlog(LOG_DEBUG, "Popping table\n"); } void @@ -731,8 +737,7 @@ config::find_and_execute(char type) s = "detach"; break; } - if (Dflag) - fprintf(stderr, "Processing %s event\n", s); + devdlog(LOG_DEBUG, "Processing %s event\n", s); for (i = l->begin(); i != l->end(); ++i) { if ((*i)->matches(*this)) { (*i)->run(*this); @@ -750,8 +755,7 @@ process_event(char *buffer) char *sp; sp = buffer + 1; - if (Dflag) - fprintf(stderr, "Processing event '%s'\n", buffer); + devdlog(LOG_DEBUG, "Processing event '%s'\n", buffer); type = *buffer++; cfg.push_var_table(); // No match doesn't have a device, and the format is a little @@ -843,6 +847,8 @@ notify_clients(const char *data, int len) --num_clients; close(*i); i = clients.erase(i); + devdlog(LOG_WARNING, "notify_clients: write() failed; " + "dropping unresponsive client\n"); } else ++i; } @@ -871,6 +877,8 @@ check_clients(void) --num_clients; close(*i); i = clients.erase(i); + devdlog(LOG_NOTICE, "check_clients: " + "dropping disconnected client\n"); } else ++i; } @@ -923,8 +931,7 @@ event_loop(void) rv = select(fd + 1, &fds, &fds, &fds, &tv); // No events -> we've processed all pending events if (rv == 0) { - if (Dflag) - fprintf(stderr, "Calling daemon\n"); + devdlog(LOG_DEBUG, "Calling daemon\n"); cfg.remove_pidfile(); cfg.open_pidfile(); daemon(0, 0); @@ -967,6 +974,11 @@ event_loop(void) if (FD_ISSET(fd, &fds)) { rv = read(fd, buffer, sizeof(buffer) - 1); if (rv > 0) { + if (rv == sizeof(buffer) - 1) { + devdlog(LOG_WARNING, "Warning: " + "available event data exceeded " + "buffer space\n"); + } notify_clients(buffer, rv); buffer[rv] = '\0'; while (buffer[--rv] == '\n') @@ -1078,10 +1090,27 @@ gensighand(int) romeo_must_die = 1; } +/* + * Local logging function. Prints to syslog if we're daemonized; syslog + * otherwise. + */ +static void +devdlog(int priority, const char* fmt, ...) +{ + va_list argp; + + va_start(argp, fmt); + if (dflag) + vfprintf(stderr, fmt, argp); + else + vsyslog(priority, fmt, argp); + va_end(argp); +} + static void usage() { - fprintf(stderr, "usage: %s [-Ddn] [-l connlimit] [-f file]\n", + fprintf(stderr, "usage: %s [-dn] [-l connlimit] [-f file]\n", getprogname()); exit(1); } @@ -1111,11 +1140,8 @@ main(int argc, char **argv) int ch; check_devd_enabled(); - while ((ch = getopt(argc, argv, "Ddf:l:n")) != -1) { + while ((ch = getopt(argc, argv, "df:l:n")) != -1) { switch (ch) { - case 'D': - Dflag++; - break; case 'd': dflag++; break;