Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Write all log output to stderr (do not pollute stdout) #1337

Merged
merged 2 commits into from
Oct 21, 2022
Merged

Write all log output to stderr (do not pollute stdout) #1337

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
08c69a2
Write all log output to stderr (do not pollute stdout)
aryoda Oct 18, 2022
2e44f98
Merge branch 'master' into PR/log_only_to_stderr
emtiu Oct 21, 2022
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions CHANGES
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@ Upcoming Release
* GUI change: Remove Exit button from the toolbar (#172)
* GUI change: Define accelerator keys for menu bar and tabs, as well as toolbar shortcuts (#1104)
* Desktop integration: Update .desktop file to mark Back In Time as a single main window program (#1258)
* Improvement: Write all log output to stderr; do not pollute stdout with INFO and WARNING messages anymore (#1337)
* Bugfix: AttributeError in "Diff Options" dialog (#898)
* Bugfix: Settings GUI: "Save password to Keyring" was disabled due to "no appropriate keyring found" (#1321)
* Bugfix: Back in Time did not start with D-Bus error
Expand Down
10 changes: 6 additions & 4 deletions common/logger.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -23,8 +23,8 @@
import tools
import bcolors

DEBUG = False
APP_NAME = 'backintime'
DEBUG = False # Set to "True" when passing "--debug" as cmd arg
APP_NAME = 'backintime' # TODO Duplicated code (see Config.APP_NAME)

def openlog():
name = os.getenv('LOGNAME', 'unknown')
Expand Down Expand Up @@ -55,14 +55,16 @@ def warning(msg , parent = None, traceDepth = 0):
def info(msg , parent = None, traceDepth = 0):
if DEBUG:
msg = '%s %s' %(_debugHeader(parent, traceDepth), msg)
print('%sINFO%s: %s' %(bcolors.OKGREEN, bcolors.ENDC, msg), file=sys.stdout)
print('%sINFO%s: %s' %(bcolors.OKGREEN, bcolors.ENDC, msg), file=sys.stderr)
for line in tools.wrapLine(msg):
syslog.syslog(syslog.LOG_INFO, 'INFO: ' + line)

def debug(msg, parent = None, traceDepth = 0):
if DEBUG:
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I would revert that if.

def debug()
    if not DEBUG:
        return

In that case you can save the indention of the following lines.
Clearer code IMHO.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ah, I see. Yes, would be possible, but why change existing code that works ;-)

msg = '%s %s' %(_debugHeader(parent, traceDepth), msg)
print('%sDEBUG%s: %s' %(bcolors.OKBLUE, bcolors.ENDC, msg), file = sys.stdout)
# Why does this code differ from eg. "error()"
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

In error() an error message is written to syslog no matter if debug mode is on or not. But if DEBUG then debug infos are added to the error messgae.

In debug() there is no need to add debug infos to the message because the message itself is of type DEBUG.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

What is irritating to me is that DEBUG is not a severity threshold for logging but a flag to inject additional call stack information ("_debugHeader") but for a single severity level debug() it is also a threshold.
I do not know any logging framework that works like that (and don't understand why this makes sense).
Perhaps the idea was to work like -v vs. -vv verbosity switches (the more "v"s the chattier is the output ;-)

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Maybe we misunderstand here each other? e.g. in Python's own logging package logging.DEBUG is a threshold.
But you are deeper in that part of the code. It was just a quick and dirty night shift thought. 😄

# (where the following lines are NOT part of the "if")?
print('%sDEBUG%s: %s' %(bcolors.OKBLUE, bcolors.ENDC, msg), file=sys.stderr)
for line in tools.wrapLine(msg):
syslog.syslog(syslog.LOG_DEBUG, 'DEBUG: %s' %line)

Expand Down
12 changes: 9 additions & 3 deletions common/test/test_backintime.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -127,14 +127,17 @@ def test_local_snapshot_is_successful(self):
Back In Time comes with ABSOLUTELY NO WARRANTY.
This is free software, and you are welcome to redistribute it
under certain conditions; type `backintime --license' for details.
''', re.MULTILINE))

INFO: Lock
# The log output completely goes to stderr
self.assertRegex(error.decode(), re.compile(r'''INFO: Lock
INFO: Take a new snapshot. Profile: 1 Main profile
INFO: Call rsync to take the snapshot
INFO: Save config file
INFO: Save permissions
INFO: Create info file
INFO: Unlock''', re.MULTILINE))
INFO: Unlock
''', re.MULTILINE))

# get snapshot id
subprocess.check_output(["./backintime",
Expand Down Expand Up @@ -167,8 +170,11 @@ def test_local_snapshot_is_successful(self):
This is free software, and you are welcome to redistribute it
under certain conditions; type `backintime --license' for details.

''', re.MULTILINE))

INFO: Restore: /tmp/test/testfile to: /tmp/restored.*''', re.MULTILINE))
# The log output completely goes to stderr
self.assertRegex(error.decode(), re.compile(r'''INFO: Restore: /tmp/test/testfile to: /tmp/restored.*''',
re.MULTILINE))

# verify that files restored are the same as those backed up
subprocess.check_output(["diff",
Expand Down