chrome: runaway log message fill /var |
|||||||||||
Issue description
I left a machine (chromeos4-row8-rack10-host13, sentry) with R59 idle, /var got full:
CHROMEOS_RELEASE_APPID={E020B8D4-CA96-4599-84DA-5017455418AE}
CHROMEOS_BOARD_APPID={E020B8D4-CA96-4599-84DA-5017455418AE}
CHROMEOS_CANARY_APPID={90F229CE-83E2-4FAF-8479-E368A34938B1}
DEVICETYPE=CHROMEBOOK
CHROMEOS_ARC_VERSION=3861378
CHROMEOS_ARC_ANDROID_SDK_VERSION=25
GOOGLE_RELEASE=9415.0.0
CHROMEOS_DEVSERVER=
CHROMEOS_RELEASE_BUILDER_PATH=sentry-release/R59-9415.0.0
The reason is /var/log/chrome:
lrwxrwxrwx. 1 chronos chronos 38 Jun 8 13:18 chrome -> /var/log/chrome/chrome_20170608-131823
-rw-r--r--. 1 chronos chronos 2219008000 Jun 22 10:04 chrome_20170608-131823
Looking in the file, it is filled due to 2 messages:
cut -d ']' -f 1 chrome_20170608-131823 | cut -d ':' -f 5 | sort | uniq -c | sort -r
9731696 instance_holder.h(67)
9731681 event_rewriter_chromeos.cc(390)
1669 gaia_screen_handler.cc(457)
11 arc_util.cc(48)
6 name_value_pairs_parser.cc(55)
4 service_manager.cc(480)
4 device_event_log_impl.cc(137)
The file is file with these 2 messages, write over 40x per second:
[1160:1160:0622/094918.551771:ERROR:event_rewriter_chromeos.cc(390)] Device ID 6 is unknown.
[1160:1160:0622/094918.552811:VERBOSE1:instance_holder.h(67)] Instance for arc::mojom::AudioInstance::NotifyVolumeState not available.
The file is not removed or trimmed by /usr/sbin/chromeos-cleanup-logs, as it is still in use.
We need to:
- prevent chrome from writing these messages
- chromeos-cleanup-logs should trim the log file(s) more through-fully.
,
Jun 22 2017
Elijah, can you find an owner for this? It seems pretty bad. I don't think we changed anything here recently in mustash land.
,
Jun 23 2017
(hmmm Why are we always dumping arc logs at vlog=1 level ?)
,
Jun 23 2017
We set the flag (thank you, Luis, for help me find this): https://chromium.git.corp.google.com/chromiumos/platform2/+/3a5d607d1c2d425562dabb5e44821f6f73129363/login_manager/chrome_setup.cc#428
,
Jun 24 2017
Luis, can you look at the instance_holder one at least? Seems like something is repeatedly trying to get an interface that doesn't exist. Can we either fix this broken pattern or reduce/remove the log? +kpschoedel for the event rewriter log (cursory git blame implicates you)
,
Jun 26 2017
#5 — There are two preconditions for the ‘Device ID’ message: 1. Processing a keystroke (one for each message, so, something is handing it keystrokes at that rate). 2. |ui::InputDeviceManager| does not include that device in |GetKeyboardDevices()|, or (probably less likely) does not exist. I've been away from this for a couple years, but my first guess would be an input device, maybe a simulated volume key, that is not correctly registered with InputManager and is repeating continuously.
,
Jun 26 2017
Mitigation for the audio bridge spam: https://chromium-review.googlesource.com/c/549195/ Although there's probably something else that needs to be fixed to avoid spamming ArcAudioBridge::SendVolumeState() to begin with.
,
Jun 26 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/a986cb967239b43e68109063b8a4a8174d9d4149 commit a986cb967239b43e68109063b8a4a8174d9d4149 Author: Luis Hector Chavez <lhchavez@google.com> Date: Mon Jun 26 23:49:40 2017 arc: Avoid logspam in the audio bridge This mitigates a runaway logging loop by avoiding to acquire the instance when we know it won't be possible to acquire. BUG= 736011 TEST=Could not repro, but it should produce less spam Change-Id: I24642d799baebf7ea1a8dd5abcc759e97c2efc37 Reviewed-on: https://chromium-review.googlesource.com/549195 Commit-Queue: Luis Hector Chavez <lhchavez@chromium.org> Reviewed-by: Hidehiko Abe <hidehiko@chromium.org> Cr-Commit-Position: refs/heads/master@{#482470} [modify] https://crrev.com/a986cb967239b43e68109063b8a4a8174d9d4149/components/arc/audio/arc_audio_bridge.cc [modify] https://crrev.com/a986cb967239b43e68109063b8a4a8174d9d4149/components/arc/audio/arc_audio_bridge.h
,
Jun 29 2017
Someone (not me, possibly ARC) should identify (a) why there are continuously repeating volume keystrokes, and/or (b) why the source device isn't correctly described by InputDeviceManager.
,
Jun 29 2018
This issue has been Available for over a year. If it's no longer important or seems unlikely to be fixed, please consider closing it out. If it is important, please re-triage the issue. Sorry for the inconvenience if the bug really should have been left as Available. For more details visit https://www.chromium.org/issue-tracking/autotriage - Your friendly Sheriffbot
,
Jun 29 2018
,
Aug 3
This bug has an owner, thus, it's been triaged. Changing status to "assigned".
,
Sep 8
|
|||||||||||
►
Sign in to add a comment |
|||||||||||
Comment 1 by gwendal@chromium.org
, Jun 22 2017112 KB
112 KB View Download