Logging details

[zxcat]

First Thanks for a great tool! I just started to use it and almost ready to switch from restic+rusticprofile to rustic even though it doesn't support all the features I use.
I have several things to discuss about logging, idk, are there bugs or features and also have questions about current decisions.

1. Rustic doesn't fully log summary:

   rustic/src/commands/backup.rs

   Lines 239 to 240 in 73d6b20

   	println!(
   	"Added to the repo: {} (raw: {})",

   
   For me it seems like a bug, because I use this info from restic log in additional scripts. Is there reasons for print-only some info?

2. It's expected that "Log output should be either stderr or file" as said in overwork logging and log levels #209. But now if user enables log-level="debug" + log-file="some", there are both stderr output and file write, so he has to rustic … 2> /dev/nul

3. Added/modified items are only visible with debug log level and not visible with default info. This info seems valuable for me to show on info log level as restic does (and also rsync, btw). As for "unchanged" items, there is also an idea behind restic solution to show them by default. This gives a complete filelist of the current snapshot. Personally I filter out "unchanged" items from my logs, but in some use cases it seems valuable.

4. Logs contains too much noise. I don't think timestamp on every line is useful on levels above debug. It's enough to timestamp start/end + maybe some important phases.
   Also new items prepended with [DEBUG] (1) rustic_core::archiver::tree_archiver:, which is consequence of p.3., and will auto-fix if move files output to info level.

5. Logging ignored items is a great decision for debug, thank you! It's right there it should.

6. Is there some logic behind current log levels? Are they final or just a draft?

7. Possible solution for pp.3-4 is a custom log format so user can configure what he want to see. But maybe it's too complex for now.

8. It seems useful to me to still print some info even if log-file was set (in addition to p.2.), but allow --quiet mode to disable this. E.g. I log info level to file but still can see warnings+progress+summary onscreen. Not sure is it a good idea, it's better to check best practices.

9. I keep some logs for a while to be able to analyze them later. Logs rotation seems not the right thing to add. But there are simpler solutions:

   1. no changes needed, user have to pass correct log name from wrapper script to rustic. that's all.
   2. there can be custom run-after script as described in Per source hooks in the config file #902 (comment), which filters and renames log to proper name.
   3. support some format syntax in log-file, like log-file = "/path/backup-%PROFILE-%Y-%m-%d_%H-%M-%S.log" (post-*-command already support substitution). This seems most simple for end user and keeps config clear.

What do you think?

[aawsome]

I'll start with some points:

1. The reason why rustic only prints some information is that in fact all information is stored within the snapshots. You can run rustic snapshots --long or --json to see the stored information. To get full information from the backup command you can use the --json option, but then you have to parse the json.

2. Actually I thought it would be that only warnings and errors are also printed to stderr if you choose to use a log file. It that is not the case, this is a bug we introduced during the refactoring...

3. See 1), this information is stored in the snapshots.

[zxcat]

thanks, it becomes more clear now.

1. snapshots --long/--json, seems good enough. it would even better with some kind of run-after option.
2. it's a bug. maybe current code checks if any log-level passed instead of checking is it warn/err.
3. this point is still under a question. Assume there was fatal error during backup so there is no snapshot to watch in to get files info. Logs is a thing especially for such case: user can detect which file caused the problem (or at least understand what happened before fail), maybe other reasons. But currently files list is only visible with debug level. Will warning/error logs output be enough in such case?

[zxcat]

2. @aawsome please check Fix term log level limiter when log-file option set #913, which fixes this bug.