From owner-freebsd-standards@FreeBSD.ORG Wed Oct 6 17:30:27 2004 Return-Path: Delivered-To: freebsd-standards@hub.freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id C42F516A4CE for ; Wed, 6 Oct 2004 17:30:27 +0000 (GMT) Received: from freefall.freebsd.org (freefall.freebsd.org [216.136.204.21]) by mx1.FreeBSD.org (Postfix) with ESMTP id A43D543D31 for ; Wed, 6 Oct 2004 17:30:27 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (gnats@localhost [127.0.0.1]) i96HURtK081257 for ; Wed, 6 Oct 2004 17:30:27 GMT (envelope-from gnats@freefall.freebsd.org) Received: (from gnats@localhost) by freefall.freebsd.org (8.12.11/8.12.11/Submit) id i96HURuw081255; Wed, 6 Oct 2004 17:30:27 GMT (envelope-from gnats) Resent-Date: Wed, 6 Oct 2004 17:30:27 GMT Resent-Message-Id: <200410061730.i96HURuw081255@freefall.freebsd.org> Resent-From: FreeBSD-gnats-submit@FreeBSD.org (GNATS Filer) Resent-To: freebsd-standards@FreeBSD.org Resent-Reply-To: FreeBSD-gnats-submit@FreeBSD.org, Dan Nelson Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id D829316A4CE for ; Wed, 6 Oct 2004 17:23:41 +0000 (GMT) Received: from dan.emsphone.com (dan.emsphone.com [199.67.51.101]) by mx1.FreeBSD.org (Postfix) with ESMTP id 6497243D45 for ; Wed, 6 Oct 2004 17:23:41 +0000 (GMT) (envelope-from dan@dan.emsphone.com) Received: (from dan@localhost) by dan.emsphone.com (8.12.11/8.12.11) id i96HNeT0099891; Wed, 6 Oct 2004 12:23:40 -0500 (CDT) (envelope-from dan) Message-Id: <200410061723.i96HNeT0099891@dan.emsphone.com> Date: Wed, 6 Oct 2004 12:23:40 -0500 (CDT) From: Dan Nelson To: FreeBSD-gnats-submit@FreeBSD.org X-Send-Pr-Version: 3.113 Subject: standards/72394: [PATCH] syslog is not thread-safe X-BeenThere: freebsd-standards@freebsd.org X-Mailman-Version: 2.1.1 Precedence: list List-Id: Standards compliance List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 06 Oct 2004 17:30:27 -0000 >Number: 72394 >Category: standards >Synopsis: [PATCH] syslog is not thread-safe >Confidential: no >Severity: non-critical >Priority: low >Responsible: freebsd-standards >State: open >Quarter: >Keywords: >Date-Required: >Class: sw-bug >Submitter-Id: current-users >Arrival-Date: Wed Oct 06 17:30:26 GMT 2004 >Closed-Date: >Last-Modified: >Originator: Dan Nelson >Release: FreeBSD 5.3-BETA7 i386 >Organization: The Allant Group, Inc. >Environment: System: FreeBSD dan.emsphone.com 5.3-BETA7 FreeBSD 5.3-BETA7 #361: Tue Oct 5 16:17:41 CDT 2004 zsh@dan.emsphone.com:/usr/src/sys/i386/compile/DANSMP i386 >Description: The syslog functions are not in the list of thread-unsafe functions at http://www.opengroup.org/onlinepubs/009695399/functions/xsh_chap02_09.html#tag_02_09_01 , so they are supposed to be safe. The log fd is not locked, though, so simultanteous calls to openlog/syslog/closelog may result in lost entries or lost fds. >How-To-Repeat: Compile this with kse or thr threads, run it, and count how many log entries end up in /var/log/messages. You may end up with missing lines, or kernel messages saying "unp_connect(): lost race to another thread". The closelog() forces an openlog() on the next call to syslog(). A more likely failure case would be if someone bounced syslogd, which will force every process with an open log fd to reopen it. If openlog/closelog is never called from within a thread and the fd stays open, syslog() itself is already thread-safe. #include #include #include void *logit(void *arg) { char *threadnum = arg; int i; for (i = 0; i < 100; i++) { syslog(LOG_WARNING, "I'm thread %s, log entry %03d", threadnum, i+1); closelog(); } return 0; } int main(void) { pthread_t t1, t2; pthread_create(&t1, NULL, &logit, "1"); pthread_create(&t2, NULL, &logit, "2"); pthread_join(t1, NULL); pthread_join(t2, NULL); syslog(LOG_WARNING, "Done"); return 0; } >Fix: Index: lib/libc/gen/syslog.c =================================================================== RCS file: /home/ncvs/src/lib/libc/gen/syslog.c,v retrieving revision 1.30 diff -u -p -r1.30 syslog.c --- lib/libc/gen/syslog.c 10 May 2004 17:12:52 -0000 1.30 +++ lib/libc/gen/syslog.c 6 Oct 2004 17:05:42 -0000 @@ -48,6 +48,7 @@ __FBSDID("$FreeBSD: src/lib/libc/gen/sys #include #include #include +#include #include #include #include @@ -62,10 +63,20 @@ __FBSDID("$FreeBSD: src/lib/libc/gen/sys static int LogFile = -1; /* fd for log */ static int connected; /* have done connect */ static int opened; /* have done openlog() */ -static int LogStat = 0; /* status bits, set by openlog() */ +static int LogStat; /* status bits, set by openlog() */ static const char *LogTag = NULL; /* string to tag the entry with */ static int LogFacility = LOG_USER; /* default facility code */ static int LogMask = 0xff; /* mask of priorities to be logged */ +static pthread_mutex_t syslog_mutex = PTHREAD_MUTEX_INITIALIZER; + +#define THREAD_LOCK() \ + do { \ + if (__isthreaded) _pthread_mutex_lock(&syslog_mutex); \ + } while(0) +#define THREAD_UNLOCK() \ + do { \ + if (__isthreaded) _pthread_mutex_unlock(&syslog_mutex); \ + } while(0) static void disconnectlog(void); /* disconnect from syslogd */ static void connectlog(void); /* (re)connect to syslogd */ @@ -141,11 +152,15 @@ vsyslog(pri, fmt, ap) pri &= LOG_PRIMASK|LOG_FACMASK; } + saved_errno = errno; + + THREAD_LOCK(); + /* Check priority against setlogmask values. */ - if (!(LOG_MASK(LOG_PRI(pri)) & LogMask)) + if (!(LOG_MASK(LOG_PRI(pri)) & LogMask)) { + THREAD_UNLOCK(); return; - - saved_errno = errno; + } /* Set default facility if none specified. */ if ((pri & LOG_FACMASK) == 0) @@ -155,8 +170,10 @@ vsyslog(pri, fmt, ap) tbuf_cookie.base = tbuf; tbuf_cookie.left = sizeof(tbuf); fp = fwopen(&tbuf_cookie, writehook); - if (fp == NULL) + if (fp == NULL) { + THREAD_UNLOCK(); return; + } /* Build the message. */ (void)time(&now); @@ -186,6 +203,7 @@ vsyslog(pri, fmt, ap) fmt_fp = fwopen(&fmt_cookie, writehook); if (fmt_fp == NULL) { fclose(fp); + THREAD_UNLOCK(); return; } @@ -243,8 +261,10 @@ vsyslog(pri, fmt, ap) if (!opened) openlog(LogTag, LogStat | LOG_NDELAY, 0); connectlog(); - if (send(LogFile, tbuf, cnt, 0) >= 0) + if (send(LogFile, tbuf, cnt, 0) >= 0) { + THREAD_UNLOCK(); return; + } /* * If the send() failed, the odds are syslogd was restarted. @@ -252,8 +272,10 @@ vsyslog(pri, fmt, ap) */ disconnectlog(); connectlog(); - if (send(LogFile, tbuf, cnt, 0) >= 0) + if (send(LogFile, tbuf, cnt, 0) >= 0) { + THREAD_UNLOCK(); return; + } /* * Output the message to the console; try not to block @@ -274,6 +296,7 @@ vsyslog(pri, fmt, ap) (void)_writev(fd, iov, 2); (void)_close(fd); } + THREAD_UNLOCK(); } static void disconnectlog() @@ -332,6 +355,7 @@ openlog(ident, logstat, logfac) const char *ident; int logstat, logfac; { + THREAD_LOCK(); if (ident != NULL) LogTag = ident; LogStat = logstat; @@ -342,15 +366,18 @@ openlog(ident, logstat, logfac) connectlog(); opened = 1; /* ident and facility has been set */ + THREAD_UNLOCK(); } void closelog() { + THREAD_LOCK(); (void)_close(LogFile); LogFile = -1; LogTag = NULL; connected = 0; + THREAD_UNLOCK(); } /* setlogmask -- set the log mask level */ @@ -360,8 +387,10 @@ setlogmask(pmask) { int omask; + THREAD_LOCK(); omask = LogMask; if (pmask != 0) LogMask = pmask; + THREAD_UNLOCK(); return (omask); } >Release-Note: >Audit-Trail: >Unformatted: