security_StatefulPermissions failure |
|||||||||||
Issue description
This is happening quite frequently. See issue 604606.
The log shows what directory was being examined, but the auto-bug-filer (above issue) doesn't include that information. This is on samus.
When fixing this failure, please also fix the test so that it prints the name of the file/directory that failed. (Or open another bug to do that.)
08/23 06:05:08.706 DEBUG| base_utils:0185| Running 'su -s /bin/sh -c 'find /mnt/stateful_partition -path /mnt/stateful_partition/encrypted/var/lib/metrics/uma-events -prune -o -path /mnt/stateful_partition/encrypted/var/lock -prune -o -path /mnt/stateful_partition/encrypted/var/log/asan -prune -o -path /mnt/stateful_partition/unencrypted/preserve/log -prune -o -path /mnt/stateful_partition/encrypted/var/cache/edb -prune -o -path /mnt/stateful_partition/encrypted/var/lib/gentoo -prune -o -path /mnt/stateful_partition/encrypted/var/log/portage -prune -o -path /mnt/stateful_partition/dev_image -prune -o -path /mnt/stateful_partition/var_overlay -prune -o -path /mnt/stateful_partition/encrypted/var/tmp -o -writable -ls -o -user cros-disks -ls 2>/dev/null;echo EOF' cros-disks'
08/23 06:05:08.718 DEBUG| base_utils:0185| Running 'logger "autotest finished iteration /usr/local/autotest/results/default/security_StatefulPermissions/sysinfo/iteration.1"'
08/23 06:05:08.722 WARNI| test:0606| Autotest caught exception when running test:
Traceback (most recent call last):
File "/usr/local/autotest/common_lib/test.py", line 600, in _exec
_call_test_function(self.execute, *p_args, **p_dargs)
File "/usr/local/autotest/common_lib/test.py", line 804, in _call_test_function
return func(*args, **dargs)
File "/usr/local/autotest/common_lib/test.py", line 461, in execute
dargs)
File "/usr/local/autotest/common_lib/test.py", line 347, in _call_run_once_with_retry
postprocess_profiled_run, args, dargs)
File "/usr/local/autotest/common_lib/test.py", line 376, in _call_run_once
self.run_once(*args, **dargs)
File "/usr/local/autotest/tests/security_StatefulPermissions/security_StatefulPermissions.py", line 249, in run_once
raise error.TestFail("Unexpected files/perms in stateful")
TestFail: Unexpected files/perms in stateful
08/23 06:05:08.724 DEBUG| logging_manager:0627| Logging subprocess finished
08/23 06:05:08.725 DEBUG| logging_manager:0627| Logging subprocess finished
,
Sep 9 2016
cc'ing last person that worked on the test
,
Sep 9 2016
The failure due to android created files has been fix in issue 637868 since 8740.0.0 on Aug 25, 2016. There has been no new occurrence after Aug 23 (Comment 93) in the auto-filed issue 604606. The name of the file/directory that failed is logged in client.0.DEBUG. Sep 3 (Comment 94) in issue 604606 is a different failure related to: /mnt/stateful_partition/encrypted/var/log/metrics/uma-events I'll take a closer look.
,
Sep 9 2016
Thank you for taking a look, Ben!
,
Sep 19 2016
+ben, based on comment #3, is this fixed ?
,
Sep 19 2016
Not yet. Here is the current status: * crbug.com/604606#c93 is fixed * crbug.com/604606#c94 failure due to /mnt/stateful_partition/encrypted/var/log/metrics/uma-events https://chromium-review.googlesource.com/#/c/382683/ can mask the failure but I haven't figured out how the test failed exactly. I'd like to find the root cause before landing that patch. * crbug.com/604606#c95 is a different failure due to /mnt/stateful_partition/var_new/run/brltty/BrlAPI /mnt/stateful_partition/var_new/tmp Still need to figure out who created those files.
,
Oct 27 2016
We no longer see the "Unexpected files/perms in stateful" failure in M56. (Still happens in M55 as recently as 8872.25.0). Ben, do you still want to investigate this failure more, or have you already looked into this issue?
,
Nov 18 2016
OK this is still flaky. See lulu-release build 580, and the test log here: https://pantheon.corp.google.com/storage/browser/chromeos-autotest-results/86078404-chromeos-test/chromeos4-row6-rack3-host5/security_StatefulPermissions/debug/?pli=1 Again in this case there is some exception happening, but the test is not reporting anything useful. It should at least not say "Unexpected files/perms ..." because it's not true (or if it's true, it's not printing them as it ought to) 11/17 01:10:50.070 DEBUG| base_utils:0185| Running 'su -s /bin/sh -c 'find /mnt/stateful_partition -path /mnt/stateful_partition/encrypted/var/lib/metrics/uma-events -prune -o -path /mnt/stateful_partition/encrypted/var/lock -prune -o -path /mnt/stateful_partition/encrypted/var/log/asan -prune -o -path /mnt/stateful_partition/unencrypted/preserve/log -prune -o -path /mnt/stateful_partition/encrypted/var/cache/edb -prune -o -path /mnt/stateful_partition/encrypted/var/lib/gentoo -prune -o -path /mnt/stateful_partition/encrypted/var/log/portage -prune -o -path /mnt/stateful_partition/dev_image -prune -o -path /mnt/stateful_partition/var_overlay -prune -o -path /mnt/stateful_partition/encrypted/var/tmp -o -writable -ls -o -user cros-disks -ls 2>/dev/null;echo EOF' cros-disks' 11/17 01:10:50.081 DEBUG| base_utils:0185| Running 'logger "autotest finished iteration /usr/local/autotest/results/default/security_StatefulPermissions/sysinfo/iteration.1"' 11/17 01:10:50.088 WARNI| test:0606| Autotest caught exception when running test: <stack trace omitted> File "/usr/local/autotest/tests/security_StatefulPermissions/security_StatefulPermissions.py", line 276, in run_once raise error.TestFail("Unexpected files/perms in stateful") TestFail: Unexpected files/perms in stateful
,
Nov 18 2016
Flaky test has resurfaced. I raised priority because we really need to get these out of the way for waterfall health.
,
Nov 18 2016
Wait. Maybe this one is not flaky. I found something else, at the beginning of the log for setzer-release 583 https://pantheon.corp.google.com/storage/browser/chromeos-autotest-results/86078897-chromeos-test/chromeos4-row8-rack8-host3/security_StatefulPermissions/debug/ 11/17 01:00:27.560 DEBUG| base_utils:0185| Running 'find /mnt/stateful_partition -user imageloaderd -ls' 11/17 01:00:29.139 ERROR|security_StatefulP:0210| 72286 4 drwxr-xr-x 3 imageloaderd imageloaderd 4096 Nov 17 00:57 /mnt/stateful_partition/encrypted/var/lib/imageloader 72287 4 drwxr-xr-x 3 imageloaderd imageloaderd 4096 Nov 17 00:57 /mnt/stateful_partition/encrypted/var/lib/imageloader/PepperFlashPlayer 72288 4 drwxr-xr-x 2 imageloaderd imageloaderd 4096 Nov 17 00:57 /mnt/stateful_partition/encrypted/var/lib/imageloader/PepperFlashPlayer/23.0.0.207 72290 4 -rw-r--r-- 1 imageloaderd imageloaderd 71 Nov 17 00:57 /mnt/stateful_partition/encrypted/var/lib/imageloader/PepperFlashPlayer/23.0.0.207/imageloader.sig.1 72289 4 -rw-r--r-- 1 imageloaderd imageloaderd 219 Nov 17 00:57 /mnt/stateful_partition/encrypted/var/lib/imageloader/PepperFlashPlayer/23.0.0.207/imageloader.json 72293 4 -rw-r--r-- 1 imageloaderd imageloaderd 66 Nov 17 00:57 /mnt/stateful_partition/encrypted/var/lib/imageloader/PepperFlashPlayer/23.0.0.207/manifest.fingerprint 72291 4 -rw-r--r-- 1 imageloaderd imageloaderd 227 Nov 17 00:57 /mnt/stateful_partition/encrypted/var/lib/imageloader/PepperFlashPlayer/23.0.0.207/table 72292 14976 -rw-r--r-- 1 imageloaderd imageloaderd 15335424 Nov 17 00:57 /mnt/stateful_partition/encrypted/var/lib/imageloader/PepperFlashPlayer/23.0.0.207/image.squash 72294 4 -rw------- 1 imageloaderd imageloaderd 10 Nov 17 00:57 /mnt/stateful_partition/encrypted/var/lib/imageloader/PepperFlashPlayer/latest-version This is produced by this code: unexpected_owners = self.owners_lacking_coverage() if unexpected_owners: testfail = True for o in unexpected_owners: self.log_owned_files(o) so the test continues, but fails later. I argue that it should fail immediately---this is not a compiler. In any case the error could be reported better, and again at the end.
,
Nov 18 2016
For instance, on August 23 this was the only error message: 08/23 13:39:12.369 DEBUG| base_utils:0185| Running 'find /mnt/stateful_partition -user 665368 -ls' 08/23 13:39:12.567 ERROR|security_StatefulP:0183| 390462 4 drwxr-x--x 6 665368 665368 4096 Aug 23 13:28 https://pantheon.corp.google.com/storage/browser/chromeos-autotest-results/74223244-chromeos-test/chromeos4-row2-rack10-host9/security_StatefulPermissions/debug/
,
Jan 21 2017
See the autofiled bug 604606 for plenty of failures. The failure from #10 popped up a few times recently, blocking the Chrome PFQ. And the client.ERROR file seems clear enough [1]. e.g. this: https://pantheon.corp.google.com/storage/browser/chromeos-autotest-results/97076669-chromeos-test/chromeos4-row2-rack3-host4/debug/ has: 01/20 14:47:57.625 ERROR|security_StatefulP:0210| 63998 4 drwxr-xr-x 3 imageloaderd imageloaderd 4096 Jan 20 14:22 /mnt/stateful_partition/encrypted/var/lib/imageloader 64032 4 drwxr-xr-x 3 imageloaderd imageloaderd 4096 Jan 20 14:22 /mnt/stateful_partition/encrypted/var/lib/imageloader/PepperFlashPlayer 64033 4 drwxr-xr-x 2 imageloaderd imageloaderd 4096 Jan 20 14:22 /mnt/stateful_partition/encrypted/var/lib/imageloader/PepperFlashPlayer/24.0.0.207 64037 15040 -rw-r--r-- 1 imageloaderd imageloaderd 15400960 Jan 20 14:22 /mnt/stateful_partition/encrypted/var/lib/imageloader/PepperFlashPlayer/24.0.0.207/image.squash 64035 4 -rw-r--r-- 1 imageloaderd imageloaderd 70 Jan 20 14:22 /mnt/stateful_partition/encrypted/var/lib/imageloader/PepperFlashPlayer/24.0.0.207/imageloader.sig.1 64036 4 -rw-r--r-- 1 imageloaderd imageloaderd 227 Jan 20 14:22 /mnt/stateful_partition/encrypted/var/lib/imageloader/PepperFlashPlayer/24.0.0.207/table 64034 4 -rw-r--r-- 1 imageloaderd imageloaderd 219 Jan 20 14:22 /mnt/stateful_partition/encrypted/var/lib/imageloader/PepperFlashPlayer/24.0.0.207/imageloader.json 64038 4 -rw-r--r-- 1 imageloaderd imageloaderd 66 Jan 20 14:22 /mnt/stateful_partition/encrypted/var/lib/imageloader/PepperFlashPlayer/24.0.0.207/manifest.fingerprint 64039 4 -rw------- 1 imageloaderd imageloaderd 10 Jan 20 14:22 /mnt/stateful_partition/encrypted/var/lib/imageloader/PepperFlashPlayer/latest-version 01/20 14:47:59.915 ERROR| parallel:0026| child process failed Is there any reason we aren't adding /encrypted/var/lib/imageloader to the test whitelist? I'll upload a change to do that shortly. -- [1] At least, it does to me. But for some reason this has still sat around for >3 months (see comment #8), so maybe it's not to someone else. Any suggestions on improving that?
,
Jan 21 2017
,
Jan 21 2017
Brian, no, I don't see any reason not to fix it as you propose. Thank you for your initiative.
,
Jan 21 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromiumos/third_party/autotest/+/73b69267f4369b6619cdcea1e1bb3953de3b0075 commit 73b69267f4369b6619cdcea1e1bb3953de3b0075 Author: Brian Norris <briannorris@chromium.org> Date: Sat Jan 21 01:04:53 2017 security_StatefulPermissions: add exceptions for imageloader files These are sometimes created by the FlashPlayer upgrade scripts, apparently. BUG= chromium:640412 TEST=`test_that ... security_StatefulPermissions` Change-Id: I287265517f3e90e5cad03baaa800d8903a5744f7 Signed-off-by: Brian Norris <briannorris@chromium.org> Reviewed-on: https://chromium-review.googlesource.com/431113 Reviewed-by: Greg Kerr <kerrnel@chromium.org> [modify] https://crrev.com/73b69267f4369b6619cdcea1e1bb3953de3b0075/client/site_tests/security_StatefulPermissions/security_StatefulPermissions.py
,
Jan 22 2017
OK, if I've read the bug appropriately, all flakes were actually real failures. I'm also not sure, but I think the test failures have become a tiny bit easier to drill down to on the waterfall within the last months? Is there something that should be improved for this test's output? I'm not sure we can fit the entirety of the ERROR details (file info) in a TestFail() string. (One thing that could help: if someone has been CC'd to an auto-filed bug like bug 604606, they should actually get emails for updates! I haven't gotten a single update, though I've been on it for months. I think I'd be more motivated to notice and fix problems if I got updates...) Anyway, I think this bug is basically done. If someone has more thoughts, feel free to reopen or file a new bug.
,
Jan 23 2017
Issue 683446 has been merged into this issue.
,
Jan 23 2017
Thanks for fixing. I don't see new instances.
,
Jan 23 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromiumos/third_party/autotest/+/3aafd8bc608054a47b602684c96446c7333877fb commit 3aafd8bc608054a47b602684c96446c7333877fb Author: Brian Norris <briannorris@chromium.org> Date: Sat Jan 21 01:04:53 2017 security_StatefulPermissions: add exceptions for imageloader files These are sometimes created by the FlashPlayer upgrade scripts, apparently. BUG= chromium:640412 TEST=`test_that ... security_StatefulPermissions` Change-Id: I287265517f3e90e5cad03baaa800d8903a5744f7 Signed-off-by: Brian Norris <briannorris@chromium.org> Reviewed-on: https://chromium-review.googlesource.com/431113 Reviewed-by: Greg Kerr <kerrnel@chromium.org> (cherry picked from commit 73b69267f4369b6619cdcea1e1bb3953de3b0075) Reviewed-on: https://chromium-review.googlesource.com/431302 Reviewed-by: Ilja H. Friedel <ihf@chromium.org> Tested-by: Ilja H. Friedel <ihf@chromium.org> [modify] https://crrev.com/3aafd8bc608054a47b602684c96446c7333877fb/client/site_tests/security_StatefulPermissions/security_StatefulPermissions.py
,
Jan 23 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromiumos/third_party/autotest/+/3aafd8bc608054a47b602684c96446c7333877fb commit 3aafd8bc608054a47b602684c96446c7333877fb Author: Brian Norris <briannorris@chromium.org> Date: Sat Jan 21 01:04:53 2017 security_StatefulPermissions: add exceptions for imageloader files These are sometimes created by the FlashPlayer upgrade scripts, apparently. BUG= chromium:640412 TEST=`test_that ... security_StatefulPermissions` Change-Id: I287265517f3e90e5cad03baaa800d8903a5744f7 Signed-off-by: Brian Norris <briannorris@chromium.org> Reviewed-on: https://chromium-review.googlesource.com/431113 Reviewed-by: Greg Kerr <kerrnel@chromium.org> (cherry picked from commit 73b69267f4369b6619cdcea1e1bb3953de3b0075) Reviewed-on: https://chromium-review.googlesource.com/431302 Reviewed-by: Ilja H. Friedel <ihf@chromium.org> Tested-by: Ilja H. Friedel <ihf@chromium.org> [modify] https://crrev.com/3aafd8bc608054a47b602684c96446c7333877fb/client/site_tests/security_StatefulPermissions/security_StatefulPermissions.py |
|||||||||||
►
Sign in to add a comment |
|||||||||||
Comment 1 by tienchang@chromium.org
, Sep 9 2016