Skip to content

Commit

Permalink
Increase log event padding
Browse files Browse the repository at this point in the history
  • Loading branch information
Johann Bahl committed Oct 18, 2023
1 parent 5939f1f commit 66bef16
Show file tree
Hide file tree
Showing 6 changed files with 113 additions and 113 deletions.
2 changes: 1 addition & 1 deletion src/backy/backup.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -667,7 +667,7 @@ async def _pull_metadata(self, api: APIClient):
log.warning("pull-error", exc_info=True)
remote_revs = []
log.debug(
"pull-found-matching-server",
"pull-found-revs",
revs=len(remote_revs),
)

Expand Down
8 changes: 7 additions & 1 deletion src/backy/logging.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -11,13 +11,15 @@

import structlog

from backy import utils

try:
import colorama
except ImportError:
colorama = None

_MISSING = "{who} requires the {package} package installed."
_EVENT_WIDTH = 30 # pad the event name to so many characters
_EVENT_WIDTH = 35 # pad the event name to so many characters

if sys.stderr.isatty() and colorama:
COLORIZED_TTY_OUTPUT = True
Expand Down Expand Up @@ -228,6 +230,10 @@ def write(line):
+ RESET_ALL
+ " "
)
if len(subsystem + event) > self._pad_event and hasattr(
utils, "log_data"
):
raise RuntimeWarning("logline to long: " + subsystem + event)

logger_name = event_dict.pop("logger", None)
if logger_name is not None:
Expand Down
10 changes: 2 additions & 8 deletions src/backy/scheduler.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -225,16 +225,10 @@ async def run_forever(self):
self.update_status("finished")

async def pull_metadata(self):
try:
await self.backup.pull_metadata(self.daemon.peers, self.taskid)
except Exception:
self.log.exception("pull-metadata-failed")
await self.backup.pull_metadata(self.daemon.peers, self.taskid)

async def push_metadata(self):
try:
await self.backup.push_metadata(self.daemon.peers, self.taskid)
except Exception:
self.log.exception("push-metadata-failed")
await self.backup.push_metadata(self.daemon.peers, self.taskid)

async def run_backup(self, tags):
self.log.info("backup-started", tags=", ".join(tags))
Expand Down
116 changes: 58 additions & 58 deletions src/backy/tests/test_client.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -166,12 +166,12 @@ async def test_cli_run(daemon, cli_client, monkeypatch):
assert (
Ellipsis(
"""\
... D ~[ABCD] api/new-conn path='/v1/jobs/test01/run' query=''
... D ~cli[ABCD] api/auth-passed \n\
... I ~cli[ABCD] api/run-job \n\
... I ~cli[ABCD] api/get-job name='test01'
... D ~cli[ABCD] api/request-result status_code=202
... I - CLIClient/triggered-run job='test01'
... D ~[ABCD] api/new-conn path='/v1/jobs/test01/run' query=''
... D ~cli[ABCD] api/auth-passed \n\
... I ~cli[ABCD] api/run-job \n\
... I ~cli[ABCD] api/get-job name='test01'
... D ~cli[ABCD] api/request-result status_code=202
... I - CLIClient/triggered-run job='test01'
"""
)
== utils.log_data
Expand All @@ -189,13 +189,13 @@ async def test_cli_run_missing(daemon, cli_client):
assert (
Ellipsis(
"""\
... D ~[ABCD] api/new-conn path='/v1/jobs/aaaa/run' query=''
... D ~cli[ABCD] api/auth-passed \n\
... I ~cli[ABCD] api/run-job \n\
... I ~cli[ABCD] api/get-job name='aaaa'
... W ~cli[ABCD] api/get-job-not-found name='aaaa'
... D ~cli[ABCD] api/request-result status_code=404
... E - CLIClient/unknown-job job='aaaa'
... D ~[ABCD] api/new-conn path='/v1/jobs/aaaa/run' query=''
... D ~cli[ABCD] api/auth-passed \n\
... I ~cli[ABCD] api/run-job \n\
... I ~cli[ABCD] api/get-job name='aaaa'
... W ~cli[ABCD] api/get-job-not-found name='aaaa'
... D ~cli[ABCD] api/request-result status_code=404
... E - CLIClient/unknown-job job='aaaa'
"""
)
== utils.log_data
Expand All @@ -216,22 +216,22 @@ async def test_cli_runall(daemon, cli_client, monkeypatch):
assert (
Ellipsis(
"""\
... D ~[ABCD] api/new-conn path='/v1/jobs' query=''
... D ~cli[ABCD] api/auth-passed \n\
... I ~cli[ABCD] api/get-jobs \n\
... D ~cli[ABCD] api/request-result response=...
... D ~[ABCD] api/new-conn path='/v1/jobs/test01/run' query=''
... D ~cli[ABCD] api/auth-passed \n\
... I ~cli[ABCD] api/run-job \n\
... I ~cli[ABCD] api/get-job name='test01'
... D ~cli[ABCD] api/request-result status_code=202
... I - CLIClient/triggered-run job='test01'
... D ~[ABCD] api/new-conn path='/v1/jobs/foo00/run' query=''
... D ~cli[ABCD] api/auth-passed \n\
... I ~cli[ABCD] api/run-job \n\
... I ~cli[ABCD] api/get-job name='foo00'
... D ~cli[ABCD] api/request-result status_code=202
... I - CLIClient/triggered-run job='foo00'
... D ~[ABCD] api/new-conn path='/v1/jobs' query=''
... D ~cli[ABCD] api/auth-passed \n\
... I ~cli[ABCD] api/get-jobs \n\
... D ~cli[ABCD] api/request-result response=...
... D ~[ABCD] api/new-conn path='/v1/jobs/test01/run' query=''
... D ~cli[ABCD] api/auth-passed \n\
... I ~cli[ABCD] api/run-job \n\
... I ~cli[ABCD] api/get-job name='test01'
... D ~cli[ABCD] api/request-result status_code=202
... I - CLIClient/triggered-run job='test01'
... D ~[ABCD] api/new-conn path='/v1/jobs/foo00/run' query=''
... D ~cli[ABCD] api/auth-passed \n\
... I ~cli[ABCD] api/run-job \n\
... I ~cli[ABCD] api/get-job name='foo00'
... D ~cli[ABCD] api/request-result status_code=202
... I - CLIClient/triggered-run job='foo00'
"""
)
== utils.log_data
Expand All @@ -249,12 +249,12 @@ async def test_cli_reload(daemon, cli_client, monkeypatch):
assert (
Ellipsis(
"""\
... I - CLIClient/reloading-daemon \n\
... D ~[ABCD] api/new-conn path='/v1/reload' query=''
... D ~cli[ABCD] api/auth-passed \n\
... I ~cli[ABCD] api/reload-daemon \n\
... D ~cli[ABCD] api/request-result status_code=204
... I - CLIClient/reloaded-daemon \n\
... I - CLIClient/reloading-daemon \n\
... D ~[ABCD] api/new-conn path='/v1/reload' query=''
... D ~cli[ABCD] api/auth-passed \n\
... I ~cli[ABCD] api/reload-daemon \n\
... D ~cli[ABCD] api/request-result status_code=204
... I - CLIClient/reloaded-daemon \n\
"""
)
== utils.log_data
Expand All @@ -270,11 +270,11 @@ async def test_cli_check_ok(daemon, cli_client):
assert (
Ellipsis(
"""\
... D ~[ABCD] api/new-conn path='/v1/status' query='filter='
... D ~cli[ABCD] api/auth-passed \n\
... I ~cli[ABCD] api/get-status filter=''
... D ~cli[ABCD] api/request-result response=...
... I - CLIClient/check-exit exitcode=0 jobs=2
... D ~[ABCD] api/new-conn path='/v1/status' query='filter='
... D ~cli[ABCD] api/auth-passed \n\
... I ~cli[ABCD] api/get-status filter=''
... D ~cli[ABCD] api/request-result response=...
... I - CLIClient/check-exit exitcode=0 jobs=2
"""
)
== utils.log_data
Expand All @@ -296,12 +296,12 @@ async def test_cli_check_too_old(daemon, clock, cli_client, log):
assert (
Ellipsis(
"""\
... D ~[ABCD] api/new-conn path='/v1/status' query='filter='
... D ~cli[ABCD] api/auth-passed \n\
... I ~cli[ABCD] api/get-status filter=''
... D ~cli[ABCD] api/request-result response=...
... C test01 CLIClient/check-sla-violation last_time='2015-08-30 07:06:47+00:00' sla_overdue=172800.0
... I - CLIClient/check-exit exitcode=2 jobs=2
... D ~[ABCD] api/new-conn path='/v1/status' query='filter='
... D ~cli[ABCD] api/auth-passed \n\
... I ~cli[ABCD] api/get-status filter=''
... D ~cli[ABCD] api/request-result response=...
... C test01 CLIClient/check-sla-violation last_time='2015-08-30 07:06:47+00:00' sla_overdue=172800.0
... I - CLIClient/check-exit exitcode=2 jobs=2
"""
)
== utils.log_data
Expand All @@ -323,12 +323,12 @@ async def test_cli_check_manual_tags(daemon, cli_client, log):
assert (
Ellipsis(
"""\
... D ~[ABCD] api/new-conn path='/v1/status' query='filter='
... D ~cli[ABCD] api/auth-passed \n\
... I ~cli[ABCD] api/get-status filter=''
... D ~cli[ABCD] api/request-result response=...
... I test01 CLIClient/check-manual-tags manual_tags='manual:test'
... I - CLIClient/check-exit exitcode=0 jobs=2
... D ~[ABCD] api/new-conn path='/v1/status' query='filter='
... D ~cli[ABCD] api/auth-passed \n\
... I ~cli[ABCD] api/get-status filter=''
... D ~cli[ABCD] api/request-result response=...
... I test01 CLIClient/check-manual-tags manual_tags='manual:test'
... I - CLIClient/check-exit exitcode=0 jobs=2
"""
)
== utils.log_data
Expand All @@ -347,12 +347,12 @@ async def test_cli_check_quarantine(daemon, cli_client, log):
assert (
Ellipsis(
"""\
... D ~[ABCD] api/new-conn path='/v1/status' query='filter='
... D ~cli[ABCD] api/auth-passed \n\
... I ~cli[ABCD] api/get-status filter=''
... D ~cli[ABCD] api/request-result response=...
... W test01 CLIClient/check-quarantined reports=1
... I - CLIClient/check-exit exitcode=1 jobs=2
... D ~[ABCD] api/new-conn path='/v1/status' query='filter='
... D ~cli[ABCD] api/auth-passed \n\
... I ~cli[ABCD] api/get-status filter=''
... D ~cli[ABCD] api/request-result response=...
... W test01 CLIClient/check-quarantined reports=1
... I - CLIClient/check-exit exitcode=1 jobs=2
"""
)
== utils.log_data
Expand Down
40 changes: 20 additions & 20 deletions src/backy/tests/test_daemon.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -337,44 +337,44 @@ async def wait_for_job_finished():
assert (
Ellipsis(
"""\
... D test01[...] job/loop-started \n\
... D test01[...] quarantine/scan entries=0
... I test01[...] job/waiting next_tags='daily' next_time='2015-09-02 07:32:51'
... E test01[...] job/exception exception_class='builtins.Exception' exception_msg=''
... D test01[...] job/loop-started \n\
... D test01[...] quarantine/scan entries=0
... I test01[...] job/waiting next_tags='daily' next_time='2015-09-02 07:32:51'
... E test01[...] job/exception exception_class='builtins.Exception' exception_msg=''
exception>\tTraceback (most recent call last):
exception>\t File "/.../src/backy/scheduler.py", line ..., in run_forever
exception>\t await self.run_backup(next_tags)
exception>\t File "/.../src/backy/tests/test_daemon.py", line ..., in failing_coroutine
exception>\t raise Exception()
exception>\tException
... W test01[...] job/backoff backoff=120
... D test01[...] quarantine/scan entries=0
... I test01[...] job/waiting next_tags='daily' next_time='2015-09-01 09:08:47'
... E test01[...] job/exception exception_class='builtins.Exception' exception_msg=''
... W test01[...] job/backoff backoff=120
... D test01[...] quarantine/scan entries=0
... I test01[...] job/waiting next_tags='daily' next_time='2015-09-01 09:08:47'
... E test01[...] job/exception exception_class='builtins.Exception' exception_msg=''
exception>\tTraceback (most recent call last):
exception>\t File "/.../src/backy/scheduler.py", line ..., in run_forever
exception>\t await self.run_backup(next_tags)
exception>\t File "/.../src/backy/tests/test_daemon.py", line ..., in failing_coroutine
exception>\t raise Exception()
exception>\tException
... W test01[...] job/backoff backoff=240
... D test01[...] quarantine/scan entries=0
... I test01[...] job/waiting next_tags='daily' next_time='2015-09-01 09:10:47'
... E test01[...] job/exception exception_class='builtins.Exception' exception_msg=''
... W test01[...] job/backoff backoff=240
... D test01[...] quarantine/scan entries=0
... I test01[...] job/waiting next_tags='daily' next_time='2015-09-01 09:10:47'
... E test01[...] job/exception exception_class='builtins.Exception' exception_msg=''
exception>\tTraceback (most recent call last):
exception>\t File "/.../src/backy/scheduler.py", line ..., in run_forever
exception>\t await self.run_backup(next_tags)
exception>\t File "/.../src/backy/tests/test_daemon.py", line ..., in failing_coroutine
exception>\t raise Exception()
exception>\tException
... W test01[...] job/backoff backoff=480
... D test01[...] quarantine/scan entries=0
... I test01[...] job/waiting next_tags='daily' next_time='2015-09-01 09:14:47'
... I test01[...] backup/pull-start \n\
... I test01[...] backup/push-start \n\
... I test01[...] job/stop \n\
... D test01[...] quarantine/scan entries=0
... I test01[...] job/waiting next_tags='daily' next_time='2015-09-02 07:32:51'
... W test01[...] job/backoff backoff=480
... D test01[...] quarantine/scan entries=0
... I test01[...] job/waiting next_tags='daily' next_time='2015-09-01 09:14:47'
... I test01[...] backup/pull-start \n\
... I test01[...] backup/push-start \n\
... I test01[...] job/stop \n\
... D test01[...] quarantine/scan entries=0
... I test01[...] job/waiting next_tags='daily' next_time='2015-09-02 07:32:51'
"""
)
== utils.log_data
Expand Down
Loading

0 comments on commit 66bef16

Please sign in to comment.