Possible bug in openlog()

Possible bug in openlog()

[Dima Krasner]

[-- Attachment #1.1: Type: text/plain, Size: 507 bytes --]

Hi,

I think I found a bug in openlog() - it's racy. If syslogd is started after openlog() is called, there's a small chance that the socket will remain open, while connect() failed. Then, syslog() does not call openlog() again, because it only checks whether the socket file descriptor is valid.

Therefore, all syslog() messages are dropped silently and nothing gets logged. I attached a fix.

Can you merge it or provide feedback, please?

Thank you,
Dima

-- 
Dima Krasner, dimakrasner.com

[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #1.2: musl-syslog-retry.patch --]
[-- Type: text/x-diff; name="musl-syslog-retry.patch", Size: 617 bytes --]

diff -rup musl-1.0.4-orig/src/misc/syslog.c musl-1.0.4/src/misc/syslog.c
--- musl-1.0.4-orig/src/misc/syslog.c	2015-01-05 15:15:35.349015771 +0200
+++ musl-1.0.4/src/misc/syslog.c	2015-01-05 15:21:30.525024212 +0200
@@ -46,7 +46,11 @@ void closelog(void)
 static void __openlog()
 {
 	log_fd = socket(AF_UNIX, SOCK_DGRAM|SOCK_CLOEXEC, 0);
-	if (log_fd >= 0) connect(log_fd, (void *)&log_addr, sizeof log_addr);
+	if (log_fd < 0) return;
+	if (connect(log_fd, (void *)&log_addr, sizeof log_addr) < 0) {
+		close(log_fd);
+		log_fd = -1;
+	}
 }
 
 void openlog(const char *ident, int opt, int facility)

[-- Attachment #2: Type: application/pgp-signature, Size: 819 bytes --]

Possible bug in openlog()

[Dima Krasner]

[-- Attachment #1.1: Type: text/plain, Size: 507 bytes --]

Hi,

I think I found a bug in openlog() - it's racy. If syslogd is started after openlog() is called, there's a small chance that the socket will remain open, while connect() failed. Then, syslog() does not call openlog() again, because it only checks whether the socket file descriptor is valid.

Therefore, all syslog() messages are dropped silently and nothing gets logged. I attached a fix.

Can you merge it or provide feedback, please?

Thank you,
Dima

-- 
Dima Krasner, dimakrasner.com

[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #1.2: musl-syslog-retry.patch --]
[-- Type: text/x-diff; name="musl-syslog-retry.patch", Size: 617 bytes --]

diff -rup musl-1.0.4-orig/src/misc/syslog.c musl-1.0.4/src/misc/syslog.c
--- musl-1.0.4-orig/src/misc/syslog.c	2015-01-05 15:15:35.349015771 +0200
+++ musl-1.0.4/src/misc/syslog.c	2015-01-05 15:21:30.525024212 +0200
@@ -46,7 +46,11 @@ void closelog(void)
 static void __openlog()
 {
 	log_fd = socket(AF_UNIX, SOCK_DGRAM|SOCK_CLOEXEC, 0);
-	if (log_fd >= 0) connect(log_fd, (void *)&log_addr, sizeof log_addr);
+	if (log_fd < 0) return;
+	if (connect(log_fd, (void *)&log_addr, sizeof log_addr) < 0) {
+		close(log_fd);
+		log_fd = -1;
+	}
 }
 
 void openlog(const char *ident, int opt, int facility)

[-- Attachment #2: Type: application/pgp-signature, Size: 819 bytes --]

Re: Possible bug in openlog()

[Rich Felker]

On Mon, Jan 05, 2015 at 03:39:14PM +0200, Dima Krasner wrote:
> Hi,
> 
> I think I found a bug in openlog() - it's racy. If syslogd is
> started after openlog() is called, there's a small chance that the
> socket will remain open, while connect() failed. Then, syslog() does
> not call openlog() again, because it only checks whether the socket
> file descriptor is valid.
> 
> Therefore, all syslog() messages are dropped silently and nothing
> gets logged. I attached a fix.
> 
> Can you merge it or provide feedback, please?

Did you observe this in practice? All accesses to log_fd seem to be
made with the syslog lock held. If you think there's missing
synchronization somewhere please elaborate.

Rich

Re: Possible bug in openlog()

[Rich Felker]

On Mon, Jan 05, 2015 at 10:46:31AM -0500, Rich Felker wrote:
> On Mon, Jan 05, 2015 at 03:39:14PM +0200, Dima Krasner wrote:
> > Hi,
> > 
> > I think I found a bug in openlog() - it's racy. If syslogd is
> > started after openlog() is called, there's a small chance that the
> > socket will remain open, while connect() failed. Then, syslog() does
> > not call openlog() again, because it only checks whether the socket
> > file descriptor is valid.
> > 
> > Therefore, all syslog() messages are dropped silently and nothing
> > gets logged. I attached a fix.
> > 
> > Can you merge it or provide feedback, please?
> 
> Did you observe this in practice? All accesses to log_fd seem to be
> made with the syslog lock held. If you think there's missing
> synchronization somewhere please elaborate.

Hm, I think I misunderstood. I misread the bug report as an internal
data race, but the actual problem is that the connect fails spuriously
if syslogd is not running at the time. This is unfortunate; I expected
connect with SOCK_DGRAM unix sockets to work like it does for UDP,
where it doesn't care if the destination port is open at the time of
the connect.

In that case the patch you provided might be the best solution. I'll
look over it again. Thanks for reporting it.

Rich