security.LogPerms fails due to /var/log/messages being owned by root rather than by syslog |
||||
Issue descriptionI've seen the security.LogPerms test fail a few times in the lab since I started running tast_Runner as part of bvt-perbuild: hana: http://pantheon/storage/browser/chromeos-autotest-results/177705382-chromeos-test/chromeos6-row4-rack3-host11/ nyan_blaze: http://pantheon/storage/browser/chromeos-autotest-results/177733314-chromeos-test/chromeos4-row7-rack7-host3/ Other runs for the same boards have all been successful. In both cases, it looks like /var/log/messages was owned by root rather than by the syslog user: 2018/02/18 21:43:48 Started test security.LogPerms 2018/02/18 21:43:48 [21:43:48.708] Error at log_perms.go:53: /var/log/messages not owned by syslog user (0 vs. 202) (I fixed a formatting error in the above message.) I added this test as a trivial copy of the security_SysLogPermissions Autotest client test, which mostly seems to pass, but I also see a /var/log/messages user ownership failure for that test on daisy at http://pantheon/storage/browser/chromeos-autotest-results/170425054-chromeos-test. Suspiciously, when I look at the log file updates collected by tast for the chromeos4-row7-rack7-host3 run, there are no updates to /var/log/messages, which is implausible given that tests that logged into Chrome were also executed. Autotest collected its own copy of the messages file, but it starts with a boot at 21:44:50, i.e. after this test finished running (the power.Reboot test later rebooted the system at 21:44:39, so the boot is expected). My suspicion is that /var/log/messages was actually in a bad state before the system was rebooted and probably not getting written to by rsyslogd. Any ideas about what could've caused this? The file looks like it's usually set up by the syslog job: pre-start script setup() { touch "$1" chown syslog "$1" } setup /var/log/messages setup /var/log/net.log setup /var/log/secure setup /var/log/boot.log setup /var/log/laptopmode.log setup /var/log/tlsdate.log setup /var/log/authpolicy.log end script The only other code that I'm aware of that messes with this file is chromeos-cleanup-logs, which moves it to messages.1, touches a new messages file, and then runs chmod and chown with --reference to make the new file match the old one. It seems implausible that both of these runs ran between the touch and chown commands, though, and that also wouldn't explain why the updates to the file didn't get collected.
,
Feb 21 2018
if it's hitting this race window, i'm surprised it doesn't also hit the race where the file doesn't exist at all we could make the rotate script be more atomic (touch & chown a tmp file before renaming it), but that wouldn't help with the missing scenario i suggest we just make the autotest slightly more forgiving to avoid unnecessary runtime overhead proposed: https://chromium-review.googlesource.com/928004
,
Feb 21 2018
I think it's reasonable to make the tests more robust, but I'm very skeptical that the tests' multiple failures have been due to running in this tiny window during rotation. Unfortunately, I don't have any good theories about what else could be happening. I can update security.LogPerms to log additional information on failure, I guess.
,
Feb 21 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromiumos/third_party/autotest/+/3a3770f8449071ded431ce059f1f63d93673f782 commit 3a3770f8449071ded431ce059f1f63d93673f782 Author: Mike Frysinger <vapier@chromium.org> Date: Wed Feb 21 17:11:27 2018 security_SysLogPermissions: handle rotation scenarios If chromeos-cleanup-logs is running, /var/log/messages might be in the middle of recreation, so don't fail if we hit those scenarios. BUG= chromium:813579 TEST=precq passes Change-Id: Ieb719a795ac9b4f902d6cb93e8713b2f482342c0 Reviewed-on: https://chromium-review.googlesource.com/928004 Commit-Ready: Mike Frysinger <vapier@chromium.org> Tested-by: Mike Frysinger <vapier@chromium.org> Reviewed-by: Dan Erat <derat@chromium.org> Reviewed-by: Jorge Lucangeli Obes <jorgelo@chromium.org> [modify] https://crrev.com/3a3770f8449071ded431ce059f1f63d93673f782/client/site_tests/security_SysLogPermissions/security_SysLogPermissions.py
,
Feb 22 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromiumos/platform/tast-tests/+/e17d6e12ed9b5a398cff1569c96e60a627fd861d commit e17d6e12ed9b5a398cff1569c96e60a627fd861d Author: Daniel Erat <derat@chromium.org> Date: Thu Feb 22 05:49:14 2018 tast-tests: Make security.LogPerms handle log rotation. Make the security.LogPerms local test avoid failure if /var/log/messages is missing or empty and owned by root. The file is briefly in both of these states while it's being rotated. Also update some errors in the security.LogPerms local test to be logged via Errorf rather than Error. BUG= chromium:813579 , chromium:814327 TEST=manual: test doesn't fail when messages is missing or empty and owned by root Change-Id: Iaae131234ee82051e4f07089876744cc28e18328 Reviewed-on: https://chromium-review.googlesource.com/928901 Tested-by: Dan Erat <derat@chromium.org> Reviewed-by: Eric Caruso <ejcaruso@chromium.org> [modify] https://crrev.com/e17d6e12ed9b5a398cff1569c96e60a627fd861d/src/chromiumos/tast/local/bundles/cros/security/log_perms.go
,
Feb 22 2018
I'll reopen this if I still see failures.
,
Feb 25 2018
Still failing intermittently on peach_pit. :-/ Presumably the file is owned by root and non-empty in some cases. I'll make the test log more details.
,
Feb 26 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromiumos/platform/tast-tests/+/e6ef8b098489f3f3edabb1dc75dfd6eb6fda2173 commit e6ef8b098489f3f3edabb1dc75dfd6eb6fda2173 Author: Daniel Erat <derat@chromium.org> Date: Mon Feb 26 17:37:46 2018 tast-tests: Make security.LogPerms write file list. Make the security.LogPerms local test write the output of "ls -la /var/log" to an output file to help figure out weird ownership of /var/log/messages. Also update power.CheckStatus to use ioutil.WriteFile rather than calling os.Create and Write separately. BUG= chromium:813579 TEST=ran both tests and checked results dir Change-Id: I14faab91530e061648478572368fc7a733e00a7a Reviewed-on: https://chromium-review.googlesource.com/936455 Commit-Queue: Dan Erat <derat@chromium.org> Tested-by: Dan Erat <derat@chromium.org> Trybot-Ready: Dan Erat <derat@chromium.org> Reviewed-by: Eric Caruso <ejcaruso@chromium.org> [modify] https://crrev.com/e6ef8b098489f3f3edabb1dc75dfd6eb6fda2173/src/chromiumos/tast/local/bundles/cros/power/check_status.go [modify] https://crrev.com/e6ef8b098489f3f3edabb1dc75dfd6eb6fda2173/src/chromiumos/tast/local/bundles/cros/security/log_perms.go
,
Feb 27 2018
I ah, don't know what's going on. How does syslog even write to it? I don't think this is a critical test so if you want to, like, TestNA it in this specific case, go ahead.
,
Feb 27 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromiumos/platform/tast-tests/+/e1f4ce3913b4aade5f10e434189e8a1060e05362 commit e1f4ce3913b4aade5f10e434189e8a1060e05362 Author: Daniel Erat <derat@chromium.org> Date: Tue Feb 27 15:53:24 2018 tast-tests: Make security.LogPerms permit root-owned file. Make security.LogPerms permit /var/log/messages to be owned by root, even if it's nonempty. This scenario happens in the lab and I have no idea why. BUG= chromium:813579 TEST=ran it Change-Id: I87968ab7ff5ad4080c38121f7f8f96427d7da6b8 Reviewed-on: https://chromium-review.googlesource.com/939046 Commit-Queue: Dan Erat <derat@chromium.org> Tested-by: Dan Erat <derat@chromium.org> Trybot-Ready: Dan Erat <derat@chromium.org> Reviewed-by: Jorge Lucangeli Obes <jorgelo@chromium.org> [modify] https://crrev.com/e1f4ce3913b4aade5f10e434189e8a1060e05362/src/chromiumos/tast/local/bundles/cros/security/log_perms.go
,
Feb 27 2018
> How does syslog even write to it? My guess would be that rsyslogd is opening it while it still has reasonable ownership and then something else comes along and chowns it to root.
,
Feb 27 2018
if rsyslog opened the file and someone chown-ed it later, it wouldn't break rsyslog from continuing to add content. question is who did that ... |
||||
►
Sign in to add a comment |
||||
Comment 1 by jorgelo@chromium.org
, Feb 20 2018