chromeos-cleanup-logs: fails to rotate logs since 3/21 |
||||
Issue descriptionReviewing disk qual data, I notice net.log is very large because LOG(INFO) is enabled. For instance, see https://pantheon.corp.google.com/storage/browser/chromeos-moblab-quanta/results/a0:00:ba:d0:0b:ad/72c91a7e2daa11e8a10e2e03a5ded476/153-moblab/192.168.231.102/ DUT is snappy test image R64-10176.76.0. I also see it on R65 release.
,
Apr 14 2018
Agreed, we can't debug problems without LOG(INFO). I guess net.log is about 2MB in hardware_StorageQualTrimStress.tar.. is this what the bug refers to? Most of the activity comes from chatter about wifi networks within range: 2.0M net.log 1.2M net.log-no_rep_ep 496K net.log-no_rep_ep-no_constructed_destroyed It's probably exacerbated by frequent scans. Maybe at some point we should reduce the loglevel of messages that involve wifi SSIDs that are not saved in the profile? Nearly all of our user reports concern SSIDs that the user has already connected to.
,
Apr 14 2018
273MB in ~10 days. [see crashinfo.192.168.231.102.tgz] I notice net.log is not under log rotation, like messages. Does it make sense to include net.log? 797886 "Rep ep updated..." 323795 "Constructed WiFi service " ... 70073 Scan on wlan0 from RequestScan 70588 ScanDone
,
Apr 14 2018
My net.log's do get rotated: https://chromium.googlesource.com/chromiumos/platform/init/+/master/chromeos-cleanup-logs#107
,
Apr 14 2018
Indeed, it is rotated, but not truncated. On my test machine: ls -l net*.log -rw-r--r--. 1 syslog root 4075446 Mar 21 14:05 net.1.log -rw-r--r--. 1 syslog root 4044052 Mar 20 14:04 net.2.log -rw-r--r--. 1 syslog root 3922113 Mar 19 14:03 net.3.log -rw-r--r--. 1 syslog root 3943684 Mar 18 14:01 net.4.log -rw-r--r--. 1 syslog root 4038903 Mar 17 13:59 net.5.log -rw-r--r--. 1 syslog root 4138444 Mar 16 13:55 net.6.log -rw-r--r--. 1 syslog root 4733726 Mar 13 17:03 net.7.log -rw-r--r--. 1 syslog root 91760122 Apr 13 17:58 net.log for i in net*.log ; do for j in tail head ; do echo -n "$i: $j: " ; $j -1 $i | cut -c '-50' ; done ; done net.1.log: tail: 2018-03-21T14:05:38.713982-07:00 INFO shill[2361]: net.1.log: head: 2018-03-20T14:05:05.410587-07:00 INFO shill[2361]: net.2.log: tail: 2018-03-20T14:04:05.410320-07:00 INFO shill[2361]: net.2.log: head: 2018-03-19T14:04:04.143553-07:00 INFO shill[2425]: net.3.log: tail: 2018-03-19T14:03:04.142849-07:00 INFO shill[2425]: net.3.log: head: 2018-03-18T14:02:36.162006-07:00 INFO shill[2425]: net.4.log: tail: 2018-03-18T14:01:36.159256-07:00 INFO shill[2425]: net.4.log: head: 2018-03-17T14:00:59.099683-07:00 INFO shill[2425]: net.5.log: tail: 2018-03-17T13:59:59.107588-07:00 INFO shill[2425]: net.5.log: head: 2018-03-16T13:56:12.247463-07:00 INFO shill[2439]: net.6.log: tail: 2018-03-16T13:55:12.245597-07:00 INFO shill[2439]: net.6.log: head: 2018-03-13T17:04:12.075540-07:00 INFO shill[2624]: net.7.log: tail: 2018-03-13T17:03:12.080826-07:00 INFO shill[2624]: net.7.log: head: 2018-03-11T17:03:42.151953-07:00 INFO shill[2496]: net.log: tail: 2018-04-13T18:01:57.372840-07:00 INFO shill[1372]: net.log: head: 2018-03-21T14:06:38.710759-07:00 INFO shill[2361]:
,
Apr 14 2018
Actually, it seems the rotation is not working anymore.
,
Apr 14 2018
from #5. I see chromeos-cleanup-logs periodically secluded, but does nothing after 03/21. /var/log/messages.1:2018-03-20T14:04:49.987816-07:00 INFO periodic_scheduler[8130]: cleanup_logs: job completed /var/log/messages.1:2018-03-21T14:06:20.787714-07:00 INFO periodic_scheduler[2931]: cleanup_logs: running /usr/sbin/chromeos-cleanup-logs /var/log/messages.2:2018-03-19T14:03:37.928374-07:00 INFO periodic_scheduler[1531]: cleanup_logs: job completed /var/log/messages.2:2018-03-20T14:04:49.832805-07:00 INFO periodic_scheduler[8007]: cleanup_logs: running /usr/sbin/chromeos-cleanup-logs /var/log/messages.3:2018-03-18T14:02:07.897128-07:00 INFO periodic_scheduler[6925]: cleanup_logs: job completed /var/log/messages.3:2018-03-19T14:03:37.799317-07:00 INFO periodic_scheduler[1374]: cleanup_logs: running /usr/sbin/chromeos-cleanup-logs /var/log/messages.4:2018-03-17T14:00:36.659616-07:00 INFO periodic_scheduler[12073]: cleanup_logs: job completed /var/log/messages.4:2018-03-18T14:02:07.762134-07:00 INFO periodic_scheduler[6802]: cleanup_logs: running /usr/sbin/chromeos-cleanup-logs /var/log/messages.5:2018-03-16T13:55:37.074441-07:00 INFO periodic_scheduler[3772]: cleanup_logs: job completed /var/log/messages.5:2018-03-17T14:00:36.499096-07:00 INFO periodic_scheduler[11950]: cleanup_logs: running /usr/sbin/chromeos-cleanup-logs /var/log/messages.6:2018-03-13T17:03:59.319758-07:00 INFO periodic_scheduler[12690]: cleanup_logs: job completed /var/log/messages.6:2018-03-16T13:55:36.907527-07:00 INFO periodic_scheduler[3644]: cleanup_logs: running /usr/sbin/chromeos-cleanup-logs /var/log/messages.7:2018-03-11T17:02:59.746431-07:00 INFO periodic_scheduler[15584]: cleanup_logs: job completed /var/log/messages.7:2018-03-13T17:03:59.126826-07:00 INFO periodic_scheduler[12563]: cleanup_logs: running /usr/sbin/chromeos-cleanup-logs /var/log/messages:2018-03-21T14:06:20.919776-07:00 INFO periodic_scheduler[3055]: cleanup_logs: job completed /var/log/messages:2018-03-22T14:08:52.088298-07:00 INFO periodic_scheduler[21312]: cleanup_logs: running /usr/sbin/chromeos-cleanup-logs /var/log/messages:2018-03-22T14:08:52.101680-07:00 INFO periodic_scheduler[21315]: cleanup_logs: job completed /var/log/messages:2018-03-23T14:10:26.635191-07:00 INFO periodic_scheduler[17372]: cleanup_logs: running /usr/sbin/chromeos-cleanup-logs /var/log/messages:2018-03-23T14:10:26.643427-07:00 INFO periodic_scheduler[17375]: cleanup_logs: job completed ... periodic_scheduler[5406]: cleanup_logs: running /usr/sbin/chromeos-cleanup-logs /var/log/messages:2018-04-11T14:51:39.613231-07:00 INFO periodic_scheduler[5409]: cleanup_logs: job completed /var/log/messages:2018-04-12T14:54:23.423365-07:00 INFO periodic_scheduler[15031]: cleanup_logs: running /usr/sbin/chromeos-cleanup-logs /var/log/messages:2018-04-12T14:54:23.426681-07:00 INFO periodic_scheduler[15034]: cleanup_logs: job completed
,
Apr 14 2018
On my machine, /var/lib/cleanup_logs_paused is present, it should have been removed once an autotest test is done.
,
Apr 14 2018
rm /var/lib/cleanup_logs_paused address the issue. I am guess I aborted an autotest job on 3/21 and the same thing happen during disk qual when the DUTs were unstable. |
||||
►
Sign in to add a comment |
||||
Comment 1 by kirtika@chromium.org
, Apr 14 2018