"logfile /dev/stdout" doesn't work (reliably) #324

multi-io · 2023-04-09T00:54:56Z

Checklist

I'm reporting a bug
I've searched the bugtracker for similar issues, including closed ones.

What did you do?

Put "logfile /dev/stdout" in the config to output all logs to stdout

What happened?

rsnapshot encountered an error! The program was invoked with these options:
/usr/bin/rsnapshot -c /rsnapshot.conf sync

ERROR: /rsnapshot.conf on line 128:
ERROR: logfile /dev/stdout - logfile /dev/stdout exists, but is not a file
ERROR: ---------------------------------------------------------------------
ERROR: Errors were found in /rsnapshot.conf,
ERROR: rsnapshot can not continue. If you think an entry looks right, make
ERROR: sure you don't have spaces where only tabs should be.

What did you expect to happen

rsnapshot should work and log to stdout.

My configuration

config_version 1.2
snapshot_root /host/mnt/backup1/testbackup/
no_create_root 1
cmd_cp /bin/cp
cmd_rm /bin/rm
cmd_rsync /usr/bin/rsync
cmd_logger /usr/bin/logger
cmd_du /usr/bin/du
retain daily 2
retain weekly 2
retain monthly 1
verbose 2
loglevel 4
logfile /dev/stdout
lockfile /var/run/rsnapshot.pid
exclude /host/dev/**
exclude /host/mnt/**
exclude /host/media/**
exclude /host/tickhome/**
exclude /host/shares/**
exclude /host/var/chroots/ub1204/sys/**
exclude /host/var/chroots/ub1204/proc/**
exclude /host/dos/**
exclude /host/proc/**
exclude /host/run/**
exclude /host/swapfile*
exclude /host/sys/**
exclude /host/tmp/**
exclude /host/var/lib/docker/overlay2/**
link_dest 1
sync_first 1
backup /host/usr/lib/gnupg/ usrlibgnupg/

Environment

OS: Ubuntu 22.04.2 LTS
Filesystem: ext4

Other information

The test at

rsnapshot/rsnapshot-program.pl

Line 1429 in 87f2c12

elsif ((-e "$value") && (!-f "$value") && (!-p "$value")) {

checks whether the configured logfile, if it exists, is either a regular file or a named pipe, and reports the error above if it's neither. /dev/stdout is usually a symlink to a symlink to a character device representing the terminal (or whatever stdout is redirected to) -- but even the terminal character device still functions perfectly fine as a log output file. I can make it work if I just remove the whole if branch (

rsnapshot/rsnapshot-program.pl

Lines 1429 to 1432 in 87f2c12

 elsif ((-e "$value") && (!-f "$value") && (!-p "$value")) { 

 config_err($file_line_num, "$line - logfile $value exists, but is not a file"); 

 next; 

 }

). I think this might even be the solution -- it looks like any problem with the log file will be detected around

rsnapshot/rsnapshot-program.pl

Line 2246 in 87f2c12

$result = open(LOG, ">> $config_vars{'logfile'}");

once it tries to log anything.

I think the -p test might follow symlinks automatically and test whatever file/pipe/device they ultimately point to, so it may return 1 (true) if stdout is redirected to a regular file or a pipe, making the configuration work without modifications to the program in that particular case.

sgpinkus · 2023-04-13T07:20:28Z

Almost the same output is directed to stdout as to logfile. I can see it's a bit different, but is this not sufficient?

DrHyde · 2023-04-15T14:24:07Z

Almost the same output is directed to stdout as to logfile. I can see it's a bit different, but is this not sufficient?

That depends on the loglevel and verbose settings. @multi-io if you play around with the verbose config option is that sufficient to get what you want on STDOUT? FWIW I have:

verbose    2
loglevel   4

and while STDOUT just has minimal errors for machines that were down when it tried to take a backup:

----------------------------------------------------------------------------
rsnapshot encountered an error! The program was invoked with these options:
/usr/local/bin/rsnapshot -c /usr/local/etc/rsnapshot.conf daily 
----------------------------------------------------------------------------
ERROR: /usr/local/bin/rsync returned 30 while processing [email protected]:/home/
ERROR: /usr/local/bin/rsync returned 30 while processing [email protected]:/home/
ERROR: /usr/local/bin/rsync returned 30 while processing [email protected]:/home/

there's a lot more detail in the log file.

[2023-04-14T23:00:00] /usr/local/bin/rsnapshot -c /usr/local/etc/rsnapshot.conf daily: started
[2023-04-14T23:00:00] Setting locale to POSIX "C"
[2023-04-14T23:00:00] echo 14960 > /var/run/rsnapshot.pid
[2023-04-14T23:00:00] mv /Volumes/Backup/snapshots/daily.6/ /Volumes/Backup/snapshots/_delete.14960/
[2023-04-14T23:00:00] mv /Volumes/Backup/snapshots/daily.5/ /Volumes/Backup/snapshots/daily.6/
[2023-04-14T23:00:00] mv /Volumes/Backup/snapshots/daily.4/ /Volumes/Backup/snapshots/daily.5/
... and so on ...
[2023-04-15T03:34:51] /usr/local/bin/rsync -aS --delete --numeric-ids --delete-excluded --timeout=300 --exclude=/proc/ --exclude=/dev/ --exclude=/lost+found/ --exclude=/sys/ --rsh=/usr/bin/ssh [email protected]:/home/ /Volumes/Backup/snapshots/daily.0/dev-freebsd.local-home/
[2023-04-15T03:40:52] [Receiver] io timeout after 301 seconds -- exiting
[2023-04-15T03:40:52] rsync error: timeout in data send/receive (code 30) at io.c(200) [Receiver=3.2.7]
[2023-04-15T03:40:52] /usr/local/bin/rsnapshot -c /usr/local/etc/rsnapshot.conf daily: ERROR: /usr/local/bin/rsync returned 30 while processing [email protected]:/home/
...
[2023-04-15T03:52:54] rm -f /var/run/rsnapshot.pid
[2023-04-15T03:52:54] /bin/rm -rf /Volumes/Backup/snapshots/_delete.14960
[2023-04-15T04:17:56] /usr/local/bin/rsnapshot -c /usr/local/etc/rsnapshot.conf daily: ERROR: /usr/local/bin/rsnapshot -c /usr/local/etc/rsnapshot.conf daily: completed, but with some errors

djk20 · 2023-04-16T03:03:05Z

I don't think it makes sense to use stdout as the logfile, unless there is some unusual use case that I am not aware of. I use a very similar approach to David Cantrell, but if you want more output to stdout and less output to log file then you could use something like verbose 4 loglevel 2 Personally I prefer to have minimal information in stdout (so it is easier to see errors and exceptions, when they happen) and more information in the log file (so I can look at the log file if there is something I want to investigate). I can't understand with rsnapshot why you would want to mix stdout and logfile both into stdout. But you are welcome to try to explain why you want that if you have a good reason.

…

On Sun, 16 Apr 2023 at 00:24, David Cantrell ***@***.***> wrote: Almost the same output is directed to stdout as to logfile. I can see it's a bit different, but is this not sufficient? That depends on the loglevel and verbose settings. @multi-io <https://github.com/multi-io> if you play around with the verbose config option is that sufficient to get what you want on STDOUT? FWIW I have: verbose 2 loglevel 4 and while STDOUT just has minimal errors for machines that were down when it tried to take a backup: ---------------------------------------------------------------------------- rsnapshot encountered an error! The program was invoked with these options: /usr/local/bin/rsnapshot -c /usr/local/etc/rsnapshot.conf daily ---------------------------------------------------------------------------- ERROR: /usr/local/bin/rsync returned 30 while processing ***@***.***:/home/ ERROR: /usr/local/bin/rsync returned 30 while processing ***@***.***:/home/ ERROR: /usr/local/bin/rsync returned 30 while processing ***@***.***:/home/ there's a lot more detail in the log file. [2023-04-14T23:00:00] /usr/local/bin/rsnapshot -c /usr/local/etc/rsnapshot.conf daily: started [2023-04-14T23:00:00] Setting locale to POSIX "C" [2023-04-14T23:00:00] echo 14960 > /var/run/rsnapshot.pid [2023-04-14T23:00:00] mv /Volumes/Backup/snapshots/daily.6/ /Volumes/Backup/snapshots/_delete.14960/ [2023-04-14T23:00:00] mv /Volumes/Backup/snapshots/daily.5/ /Volumes/Backup/snapshots/daily.6/ [2023-04-14T23:00:00] mv /Volumes/Backup/snapshots/daily.4/ /Volumes/Backup/snapshots/daily.5/ ... and so on ... [2023-04-15T03:34:51] /usr/local/bin/rsync -aS --delete --numeric-ids --delete-excluded --timeout=300 --exclude=/proc/ --exclude=/dev/ --exclude=/lost+found/ --exclude=/sys/ --rsh=/usr/bin/ssh ***@***.***:/home/ /Volumes/Backup/snapshots/daily.0/dev-freebsd.local-home/ [2023-04-15T03:40:52] [Receiver] io timeout after 301 seconds -- exiting [2023-04-15T03:40:52] rsync error: timeout in data send/receive (code 30) at io.c(200) [Receiver=3.2.7] [2023-04-15T03:40:52] /usr/local/bin/rsnapshot -c /usr/local/etc/rsnapshot.conf daily: ERROR: /usr/local/bin/rsync returned 30 while processing ***@***.***:/home/ ... [2023-04-15T03:52:54] rm -f /var/run/rsnapshot.pid [2023-04-15T03:52:54] /bin/rm -rf /Volumes/Backup/snapshots/_delete.14960 [2023-04-15T04:17:56] /usr/local/bin/rsnapshot -c /usr/local/etc/rsnapshot.conf daily: ERROR: /usr/local/bin/rsnapshot -c /usr/local/etc/rsnapshot.conf daily: completed, but with some errors — Reply to this email directly, view it on GitHub <#324 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AAPTLCQUPUU7IZGTBXDAAVTXBKVRLANCNFSM6AAAAAAWXYWUEA> . You are receiving this because you are subscribed to this thread.Message ID: ***@***.***>

-- David Keegel ***@***.***>

multi-io · 2023-04-21T11:21:08Z

Well, I'm running rsnapshot in a container and I basically don't want it to write any logfiles at all. It makes more sense to log to stdout, where a logging agent can pick it up.

DrHyde · 2023-04-21T18:05:14Z

Have you tried just turning up verbose as suggested, and not setting logfile?

djk20 · 2023-04-22T02:11:05Z

The important part here is not setting logfile in rsnapshot config if you don't want it to write any logfiles at all. Just remove the "logfile /dev/stdout" from your config (or comment it out). If you want stdout to have the same level of logging which would by default go to a logfile, then set "verbose 3" (instead of the default "verbose 2") to control the level of logging to stdout. If logfile is not defined, then it doesn't matter what loglevel is set to (although if you like belt and braces you could put "loglevel 0" to highlight that you don't want to write anything to a log file because you are just logging to stdout).

…

On Sat, 22 Apr 2023 at 04:05, David Cantrell ***@***.***> wrote: Have you tried just turning up verbose as suggested, and not setting logfile? — Reply to this email directly, view it on GitHub <#324 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AAPTLCSAHWYJHBJ4ZDMQTN3XCLD6LANCNFSM6AAAAAAWXYWUEA> . You are receiving this because you commented.Message ID: ***@***.***>

-- David Keegel ***@***.***>

multi-io added the bug label Apr 9, 2023

multi-io mentioned this issue Apr 9, 2023

Remove test if logfile is a regular file or a pipe to support logfile /dev/stdout #325

Open

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

"logfile /dev/stdout" doesn't work (reliably) #324

"logfile /dev/stdout" doesn't work (reliably) #324

multi-io commented Apr 9, 2023 •

edited

sgpinkus commented Apr 13, 2023

DrHyde commented Apr 15, 2023

djk20 commented Apr 16, 2023 via email

multi-io commented Apr 21, 2023

DrHyde commented Apr 21, 2023

djk20 commented Apr 22, 2023 via email

"logfile /dev/stdout" doesn't work (reliably) #324

"logfile /dev/stdout" doesn't work (reliably) #324

Comments

multi-io commented Apr 9, 2023 • edited

Checklist

What did you do?

What happened?

rsnapshot encountered an error! The program was invoked with these options: /usr/bin/rsnapshot -c /rsnapshot.conf sync

What did you expect to happen

My configuration

Environment

Other information

sgpinkus commented Apr 13, 2023

DrHyde commented Apr 15, 2023

djk20 commented Apr 16, 2023 via email

multi-io commented Apr 21, 2023

DrHyde commented Apr 21, 2023

djk20 commented Apr 22, 2023 via email

multi-io commented Apr 9, 2023 •

edited

rsnapshot encountered an error! The program was invoked with these options:
/usr/bin/rsnapshot -c /rsnapshot.conf sync