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.

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

Prevent unnecessary linebreak in cache service logging #4601

Merged
merged 1 commit into from
Apr 11, 2022

Conversation

okurz
Copy link
Member

@okurz okurz commented Apr 9, 2022

The cache service log output looks like this:

[2021-05-20T06:08:43.0426 CEST] [info] Download of Tumbleweed.x86_64-1.0-virtualbox-Snapshot20210519.vagrant.virtualbox.box processed:
[info] [#51]
Cache size of "/var/lib/openqa/cache" is 17GiB, with limit 180GiB
[info] [#51]
Downloading "Tumbleweed.x86_64-1.0-virtualbox-Snapshot20210519.vagrant.virtualbox.box" from "http://openqa1-opensuse/tests/1750006/asset/other/Tumbleweed.x86_64-1.0-virtualbox-Snapshot20210519.vagrant.virtualbox.box"
[info] [#51]
Size of "/var/lib/openqa/cache/openqa1-opensuse/Tumbleweed.x86_64-1.0-virtualbox-Snapshot20210519.vagrant.virtualbox.box" is 312MiB, with ETag ""137afea0-5c2b8033306c0""
[info] [#51]
Download of "/var/lib/openqa/cache/openqa1-opensuse/Tumbleweed.x86_64-1.0-virtualbox-Snapshot20210519.vagrant.virtualbox.box" successful, new cache size is 19GiB

So there is a redundant linebreak after every [info] [#51] which we can prevent.

Verified in https://openqa.opensuse.org/tests/2291609/logfile?filename=autoinst-log.txt

Now the output looks like this:

[2022-04-11T15:46:27.882691+02:00] [info] Running on openqaworker7:10 (Linux 5.3.18-150300.59.60-default #1 SMP Fri Mar 18 18:37:08 UTC 2022 (79e1683) x86_64)
[2022-04-11T15:46:27.887980+02:00] [debug] Found ASSET_1, caching Tumbleweed.x86_64-1.0-libvirt-Snapshot20220410.vagrant.libvirt.box
[2022-04-11T15:46:27.895693+02:00] [info] Downloading Tumbleweed.x86_64-1.0-libvirt-Snapshot20220410.vagrant.libvirt.box, request #214 sent to Cache Service
[2022-04-11T15:46:38.061508+02:00] [info] Download of Tumbleweed.x86_64-1.0-libvirt-Snapshot20220410.vagrant.libvirt.box processed:
[info] [#214] Cache size of "/var/lib/openqa/cache" is 49 GiB, with limit 180 GiB
[info] [#214] Downloading "Tumbleweed.x86_64-1.0-libvirt-Snapshot20220410.vagrant.libvirt.box" from "[http://openqa1-opensuse/tests/2291609/asset/other/Tumbleweed.x86_64-1.0-libvirt-Snapshot20220410.vagrant.libvirt.box"](http://openqa1-opensuse/tests/2291609/asset/other/Tumbleweed.x86_64-1.0-libvirt-Snapshot20220410.vagrant.libvirt.box)
[info] [#214] Content of "/var/lib/openqa/cache/openqa1-opensuse/Tumbleweed.x86_64-1.0-libvirt-Snapshot20220410.vagrant.libvirt.box" has not changed, updating last use

[2022-04-11T15:46:38.070683+02:00] [debug] Found ASSET_2, caching Tumbleweed.x86_64-1.0-virtualbox-Snapshot20220410.vagrant.virtualbox.box
[2022-04-11T15:46:38.085512+02:00] [info] Downloading Tumbleweed.x86_64-1.0-virtualbox-Snapshot20220410.vagrant.virtualbox.box, request #215 sent to Cache Service
[2022-04-11T15:46:43.176128+02:00] [info] Download of Tumbleweed.x86_64-1.0-virtualbox-Snapshot20220410.vagrant.virtualbox.box processed:
[info] [#215] Cache size of "/var/lib/openqa/cache" is 49 GiB, with limit 180 GiB
[info] [#215] Downloading "Tumbleweed.x86_64-1.0-virtualbox-Snapshot20220410.vagrant.virtualbox.box" from "[http://openqa1-opensuse/tests/2291609/asset/other/Tumbleweed.x86_64-1.0-virtualbox-Snapshot20220410.vagrant.virtualbox.box"](http://openqa1-opensuse/tests/2291609/asset/other/Tumbleweed.x86_64-1.0-virtualbox-Snapshot20220410.vagrant.virtualbox.box)
[info] [#215] Content of "/var/lib/openqa/cache/openqa1-opensuse/Tumbleweed.x86_64-1.0-virtualbox-Snapshot20220410.vagrant.virtualbox.box" has not changed, updating last use

[2022-04-11T15:46:43.179827+02:00] [debug] Found ASSET_256, caching openSUSE-Tumbleweed-DVD-x86_64-Snapshot20220410-Media.iso.sha256
[2022-04-11T15:46:43.186029+02:00] [info] Downloading openSUSE-Tumbleweed-DVD-x86_64-Snapshot20220410-Media.iso.sha256, request #216 sent to Cache Service
[2022-04-11T15:46:53.336159+02:00] [info] Download of openSUSE-Tumbleweed-DVD-x86_64-Snapshot20220410-Media.iso.sha256 processed:
[info] [#216] Cache size of "/var/lib/openqa/cache" is 49 GiB, with limit 180 GiB
[info] [#216] Downloading "openSUSE-Tumbleweed-DVD-x86_64-Snapshot20220410-Media.iso.sha256" from "[http://openqa1-opensuse/tests/2291609/asset/other/openSUSE-Tumbleweed-DVD-x86_64-Snapshot20220410-Media.iso.sha256"](http://openqa1-opensuse/tests/2291609/asset/other/openSUSE-Tumbleweed-DVD-x86_64-Snapshot20220410-Media.iso.sha256)
[info] [#216] Content of "/var/lib/openqa/cache/openqa1-opensuse/openSUSE-Tumbleweed-DVD-x86_64-Snapshot20220410-Media.iso.sha256" has not changed, updating last use

[2022-04-11T15:46:53.339374+02:00] [debug] Found ISO, caching openSUSE-Tumbleweed-DVD-x86_64-Snapshot20220410-Media.iso
[2022-04-11T15:46:53.354556+02:00] [info] Downloading openSUSE-Tumbleweed-DVD-x86_64-Snapshot20220410-Media.iso, request #217 sent to Cache Service
[2022-04-11T15:47:03.546048+02:00] [info] Download of openSUSE-Tumbleweed-DVD-x86_64-Snapshot20220410-Media.iso processed:
[info] [#217] Cache size of "/var/lib/openqa/cache" is 49 GiB, with limit 180 GiB
[info] [#217] Downloading "openSUSE-Tumbleweed-DVD-x86_64-Snapshot20220410-Media.iso" from "[http://openqa1-opensuse/tests/2291609/asset/iso/openSUSE-Tumbleweed-DVD-x86_64-Snapshot20220410-Media.iso"](http://openqa1-opensuse/tests/2291609/asset/iso/openSUSE-Tumbleweed-DVD-x86_64-Snapshot20220410-Media.iso)
[info] [#217] Content of "/var/lib/openqa/cache/openqa1-opensuse/openSUSE-Tumbleweed-DVD-x86_64-Snapshot20220410-Media.iso" has not changed, updating last use

[2022-04-11T15:47:03.550593+02:00] [info] Rsync from 'rsync://openqa1-opensuse/tests' to '/var/lib/openqa/cache/openqa1-opensuse', request #218 sent to Cache Service
[2022-04-11T15:47:13.732660+02:00] [info] Output of rsync:

so no redundant linebreaks, no redundant markers, every line is properly prefixed and every block is terminated by a blank line.

Related progress issue: https://progress.opensuse.org/issues/92902

@codecov
Copy link

codecov bot commented Apr 9, 2022

Codecov Report

Merging #4601 (210dbf6) into master (badee12) will increase coverage by 0.00%.
The diff coverage is 100.00%.

@@           Coverage Diff           @@
##           master    #4601   +/-   ##
=======================================
  Coverage   97.99%   97.99%           
=======================================
  Files         375      375           
  Lines       34440    34442    +2     
=======================================
+ Hits        33748    33750    +2     
  Misses        692      692           
Impacted Files Coverage Δ
lib/OpenQA/CacheService/Task/Asset.pm 100.00% <100.00%> (ø)

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update badee12...210dbf6. Read the comment docs.

Copy link
Contributor

@Martchus Martchus left a comment

Choose a reason for hiding this comment

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

The log in the verification run now misses line breaks, e.g. look at this section:

[2022-04-09T18:45:07.696242+02:00] [info] Download of openSUSE-Tumbleweed-DVD-x86_64-Snapshot20220408-Media.iso.sha256 processed:
[info] [#710] Cache size of "/var/lib/openqa/cache" is 108 GiB, with limit 180 GiB [info] [#710] Downloading "openSUSE-Tumbleweed-DVD-x86_64-Snapshot20220408-Media.iso.sha256" from "[http://openqa1-opensuse/tests/2288695/asset/other/openSUSE-Tumbleweed-DVD-x86_64-Snapshot20220408-Media.iso.sha256"](http://openqa1-opensuse/tests/2288695/asset/other/openSUSE-Tumbleweed-DVD-x86_64-Snapshot20220408-Media.iso.sha256) [info] [#710] Content of "/var/lib/openqa/cache/openqa1-opensuse/openSUSE-Tumbleweed-DVD-x86_64-Snapshot20220408-Media.iso.sha256" has not changed, updating last use 
[2022-04-09T18:45:07.698938+02:00] [debug] Found HDD_1, caching opensuse-Tumbleweed-x86_64-20220408-textmode@64bit.qcow2

@okurz
Copy link
Member Author

okurz commented Apr 9, 2022

Hmpf, so what's the opposite of chomp to delete the first newline? :D

@okurz okurz marked this pull request as draft April 10, 2022 08:30
@okurz
Copy link
Member Author

okurz commented Apr 10, 2022

Also I hoped that a test would fail so that I could extend something.

@okurz okurz force-pushed the feature/log_no_newline_poo92902 branch 2 times, most recently from 7ae03d4 to efdfedc Compare April 11, 2022 13:12
@okurz
Copy link
Member Author

okurz commented Apr 11, 2022

Updated after pair-programming session with Martchus, hotpatched on w7 with:

curl -sS https://patch-diff.githubusercontent.com/raw/os-autoinst/openQA/pull/4601.patch | patch -p1 --directory=/usr/share/openqa

The cache service log output looks like this:

```
[2021-05-20T06:08:43.0426 CEST] [info] Download of Tumbleweed.x86_64-1.0-virtualbox-Snapshot20210519.vagrant.virtualbox.box processed:
[info] [os-autoinst#51]
Cache size of "/var/lib/openqa/cache" is 17GiB, with limit 180GiB
[info] [os-autoinst#51]
Downloading "Tumbleweed.x86_64-1.0-virtualbox-Snapshot20210519.vagrant.virtualbox.box" from "http://openqa1-opensuse/tests/1750006/asset/other/Tumbleweed.x86_64-1.0-virtualbox-Snapshot20210519.vagrant.virtualbox.box"
[info] [os-autoinst#51]
Size of "/var/lib/openqa/cache/openqa1-opensuse/Tumbleweed.x86_64-1.0-virtualbox-Snapshot20210519.vagrant.virtualbox.box" is 312MiB, with ETag ""137afea0-5c2b8033306c0""
[info] [os-autoinst#51]
Download of "/var/lib/openqa/cache/openqa1-opensuse/Tumbleweed.x86_64-1.0-virtualbox-Snapshot20210519.vagrant.virtualbox.box" successful, new cache size is 19GiB
```

So there is a redundant linebreak after every `[info] [os-autoinst#51]` which we can prevent.

Related progress issue: https://progress.opensuse.org/issues/92902
@okurz okurz force-pushed the feature/log_no_newline_poo92902 branch from efdfedc to 210dbf6 Compare April 11, 2022 13:33
@okurz
Copy link
Member Author

okurz commented Apr 11, 2022

Updated, see verified in https://openqa.opensuse.org/tests/2291609/logfile?filename=autoinst-log.txt

Now the output looks like this:

[2022-04-11T15:46:27.882691+02:00] [info] Running on openqaworker7:10 (Linux 5.3.18-150300.59.60-default #1 SMP Fri Mar 18 18:37:08 UTC 2022 (79e1683) x86_64)
[2022-04-11T15:46:27.887980+02:00] [debug] Found ASSET_1, caching Tumbleweed.x86_64-1.0-libvirt-Snapshot20220410.vagrant.libvirt.box
[2022-04-11T15:46:27.895693+02:00] [info] Downloading Tumbleweed.x86_64-1.0-libvirt-Snapshot20220410.vagrant.libvirt.box, request #214 sent to Cache Service
[2022-04-11T15:46:38.061508+02:00] [info] Download of Tumbleweed.x86_64-1.0-libvirt-Snapshot20220410.vagrant.libvirt.box processed:
[info] [#214] Cache size of "/var/lib/openqa/cache" is 49 GiB, with limit 180 GiB
[info] [#214] Downloading "Tumbleweed.x86_64-1.0-libvirt-Snapshot20220410.vagrant.libvirt.box" from "[http://openqa1-opensuse/tests/2291609/asset/other/Tumbleweed.x86_64-1.0-libvirt-Snapshot20220410.vagrant.libvirt.box"](http://openqa1-opensuse/tests/2291609/asset/other/Tumbleweed.x86_64-1.0-libvirt-Snapshot20220410.vagrant.libvirt.box)
[info] [#214] Content of "/var/lib/openqa/cache/openqa1-opensuse/Tumbleweed.x86_64-1.0-libvirt-Snapshot20220410.vagrant.libvirt.box" has not changed, updating last use

[2022-04-11T15:46:38.070683+02:00] [debug] Found ASSET_2, caching Tumbleweed.x86_64-1.0-virtualbox-Snapshot20220410.vagrant.virtualbox.box
[2022-04-11T15:46:38.085512+02:00] [info] Downloading Tumbleweed.x86_64-1.0-virtualbox-Snapshot20220410.vagrant.virtualbox.box, request #215 sent to Cache Service
[2022-04-11T15:46:43.176128+02:00] [info] Download of Tumbleweed.x86_64-1.0-virtualbox-Snapshot20220410.vagrant.virtualbox.box processed:
[info] [#215] Cache size of "/var/lib/openqa/cache" is 49 GiB, with limit 180 GiB
[info] [#215] Downloading "Tumbleweed.x86_64-1.0-virtualbox-Snapshot20220410.vagrant.virtualbox.box" from "[http://openqa1-opensuse/tests/2291609/asset/other/Tumbleweed.x86_64-1.0-virtualbox-Snapshot20220410.vagrant.virtualbox.box"](http://openqa1-opensuse/tests/2291609/asset/other/Tumbleweed.x86_64-1.0-virtualbox-Snapshot20220410.vagrant.virtualbox.box)
[info] [#215] Content of "/var/lib/openqa/cache/openqa1-opensuse/Tumbleweed.x86_64-1.0-virtualbox-Snapshot20220410.vagrant.virtualbox.box" has not changed, updating last use

[2022-04-11T15:46:43.179827+02:00] [debug] Found ASSET_256, caching openSUSE-Tumbleweed-DVD-x86_64-Snapshot20220410-Media.iso.sha256
[2022-04-11T15:46:43.186029+02:00] [info] Downloading openSUSE-Tumbleweed-DVD-x86_64-Snapshot20220410-Media.iso.sha256, request #216 sent to Cache Service
[2022-04-11T15:46:53.336159+02:00] [info] Download of openSUSE-Tumbleweed-DVD-x86_64-Snapshot20220410-Media.iso.sha256 processed:
[info] [#216] Cache size of "/var/lib/openqa/cache" is 49 GiB, with limit 180 GiB
[info] [#216] Downloading "openSUSE-Tumbleweed-DVD-x86_64-Snapshot20220410-Media.iso.sha256" from "[http://openqa1-opensuse/tests/2291609/asset/other/openSUSE-Tumbleweed-DVD-x86_64-Snapshot20220410-Media.iso.sha256"](http://openqa1-opensuse/tests/2291609/asset/other/openSUSE-Tumbleweed-DVD-x86_64-Snapshot20220410-Media.iso.sha256)
[info] [#216] Content of "/var/lib/openqa/cache/openqa1-opensuse/openSUSE-Tumbleweed-DVD-x86_64-Snapshot20220410-Media.iso.sha256" has not changed, updating last use

[2022-04-11T15:46:53.339374+02:00] [debug] Found ISO, caching openSUSE-Tumbleweed-DVD-x86_64-Snapshot20220410-Media.iso
[2022-04-11T15:46:53.354556+02:00] [info] Downloading openSUSE-Tumbleweed-DVD-x86_64-Snapshot20220410-Media.iso, request #217 sent to Cache Service
[2022-04-11T15:47:03.546048+02:00] [info] Download of openSUSE-Tumbleweed-DVD-x86_64-Snapshot20220410-Media.iso processed:
[info] [#217] Cache size of "/var/lib/openqa/cache" is 49 GiB, with limit 180 GiB
[info] [#217] Downloading "openSUSE-Tumbleweed-DVD-x86_64-Snapshot20220410-Media.iso" from "[http://openqa1-opensuse/tests/2291609/asset/iso/openSUSE-Tumbleweed-DVD-x86_64-Snapshot20220410-Media.iso"](http://openqa1-opensuse/tests/2291609/asset/iso/openSUSE-Tumbleweed-DVD-x86_64-Snapshot20220410-Media.iso)
[info] [#217] Content of "/var/lib/openqa/cache/openqa1-opensuse/openSUSE-Tumbleweed-DVD-x86_64-Snapshot20220410-Media.iso" has not changed, updating last use

[2022-04-11T15:47:03.550593+02:00] [info] Rsync from 'rsync://openqa1-opensuse/tests' to '/var/lib/openqa/cache/openqa1-opensuse', request #218 sent to Cache Service
[2022-04-11T15:47:13.732660+02:00] [info] Output of rsync:

so no redundant linebreaks, no redundant markers, every line is properly prefixed and every block is terminated by a blank line.

@okurz okurz marked this pull request as ready for review April 11, 2022 13:57
@mergify mergify bot merged commit 8b43321 into os-autoinst:master Apr 11, 2022
@okurz okurz deleted the feature/log_no_newline_poo92902 branch April 11, 2022 17:32
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants