rsync - Nov 2003 - rsync --daemon and logfile that can't be created

If the rsyncd.conf has a line such as:

log file = /var/log/rsync/log

and /var/log/rsync doesn't exist or isn't a directory (or the log file
can't be opened for any other reason), then there's no warning
whatsoever, as rsync forks itself into the background before checking
the config, opening the log file, etc.

Worse still, it gets a SIGSEGV, and dumps core. Here's a strace from a
fairly recent CVS:

15154 umask(022)                        = 0
15154 open("/var/log/rsync/log",
O_WRONLY|O_APPEND|O_CREAT|O_LARGEFILE, 0666) = -1 ENOTDIR (Not a directory)
15154 umask(0)                          = 022
15154 umask(022)                        = 0
15154 open("/var/log/rsync/log",
O_WRONLY|O_APPEND|O_CREAT|O_LARGEFILE, 0666) = -1 ENOTDIR (Not a directory)
15154 umask(0)                          = 022
15154 getpid()                          = 15154
15154 time(NULL)                        = 1069070906
15154 --- SIGSEGV (Segmentation fault) @ 0 (0) ---
15154 +++ killed by SIGSEGV +++
15153 --- SIGCHLD (Child exited) @ 0 (0) ---
15153 waitpid(-1, [WIFSIGNALED(s) && WTERMSIG(s) == SIGSEGV &&
WCOREDUMP(s)], WNOHANG) = 15154
15153 waitpid(-1, 0xbffff864, WNOHANG)  = -1 ECHILD (No child processes)
15153 sigreturn()                       = ? (mask now [])
15153 exit_group(0)                     = ?

1) It's a bother that it first daemonizes itself and then checks the
   config etc., giving no feedback whatsoever that it's not running.

2) core dumps are never good :-(


Here'a a proposed patch to fallback to syslog if opening the log file
fails:

--- ../cvstree/rsync/log.c	2003-03-25 03:28:54.000000000 +0100
+++ ./log.c	2003-11-17 13:31:15.000000000 +0100
@@ -134,9 +134,9 @@
 
 static void logit(int priority, char *buf)
 {
-	if (logfname) {
-		if (!logfile)
-			log_open();
+	if (logfname && !logfile)
+                log_open();
+        if (logfile) {
 		fprintf(logfile,"%s [%d] %s", 
 			timestring(time(NULL)), (int)getpid(), buf);
 		fflush(logfile);
@@ -164,9 +164,11 @@
 	if (logfname) {
 		if (*logfname) {
 			log_open();
-			return;
+			if (logfile)
+                            return;
+                        /* fall back to syslog if opening log file fails */
 		}
-		logfname = NULL;
+                logfname = NULL;
 	}
 
 #ifdef LOG_NDELAY
@@ -191,6 +193,12 @@
 		int old_umask = umask(022 | orig_umask);
 		logfile = fopen(logfname, "a");
 		umask(old_umask);
+                if (!logfile) {
+                    char buf[512];
+                    sprintf(buf, "logfile %.400s could not be opened,
errno %d", logfname, errno);
+                    logfname = NULL;
+                    logit(LOG_ERR, buf);
+                }
 	}
 }
 


Paul Slootman

On Mon, Nov 17, 2003 at 01:35:09PM +0100, Paul Slootman
wrote:
> If the rsyncd.conf has a line such as:
> 
> log file = /var/log/rsync/log
> 
> and /var/log/rsync doesn't exist or isn't a directory (or the log
file
> can't be opened for any other reason), then there's no warning
> whatsoever, as rsync forks itself into the background before checking
> the config, opening the log file, etc.
> 
> Worse still, it gets a SIGSEGV, and dumps core. Here's a strace from a
> fairly recent CVS:
> 
> 15154 umask(022)                        = 0
> 15154 open("/var/log/rsync/log",
O_WRONLY|O_APPEND|O_CREAT|O_LARGEFILE, 0666) = -1 ENOTDIR (Not a directory)
> 15154 umask(0)                          = 022
> 15154 umask(022)                        = 0
> 15154 open("/var/log/rsync/log",
O_WRONLY|O_APPEND|O_CREAT|O_LARGEFILE, 0666) = -1 ENOTDIR (Not a directory)
> 15154 umask(0)                          = 022
> 15154 getpid()                          = 15154
> 15154 time(NULL)                        = 1069070906
> 15154 --- SIGSEGV (Segmentation fault) @ 0 (0) ---
> 15154 +++ killed by SIGSEGV +++
> 15153 --- SIGCHLD (Child exited) @ 0 (0) ---
> 15153 waitpid(-1, [WIFSIGNALED(s) && WTERMSIG(s) == SIGSEGV
&& WCOREDUMP(s)], WNOHANG) = 15154
> 15153 waitpid(-1, 0xbffff864, WNOHANG)  = -1 ECHILD (No child processes)
> 15153 sigreturn()                       = ? (mask now [])
> 15153 exit_group(0)                     = ?
> 
> 1) It's a bother that it first daemonizes itself and then checks the
>    config etc., giving no feedback whatsoever that it's not running.
True.
> 2) core dumps are never good :-(
Also true.
> Here'a a proposed patch to fallback to syslog if opening the log file
> fails:
Much better would be to test the status of open() in openlog
and if there is an error kick out a message and exit.  If
log_init() were called just a little earlier in
clientserver.c:daemon_main(), specifically before closing
stderr then the error message could be sent to stderr.

That would be much better, and simpler than assuming syslog
is available as a fallback.

Perhaps someone more familiar with the daemon code could
consider this.