New issue
Advanced search Search tips
Note: Color blocks (like or ) mean that a user may not be available. Tooltip shows the reason.

Issue 860647 link

Starred by 1 user

Issue metadata

Status: Verified
Owner:
Closed: Jul 10
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 1
Type: Bug
Flaky-Test: KeyboardOperations/FilesAppBrowserTest.Test/renameNewFolderDownloads_GuestMode

Blocking:
issue 836254



Sign in to add a comment

KeyboardOperations/FilesAppBrowserTest.Test/renameNewFolderDownloads_GuestMode is Flaky

Project Member Reported by Findit, Jul 6

Issue description

Labels: -Sheriff-Chromium OS-Linux
Owner: lucmult@chromium.org
Status: Assigned (was: Available)
[ RUN      ] KeyboardOperations/FilesAppBrowserTest.Test/renameNewFolderDownloads_GuestMode
[5696:5696:0706/045947.477526:WARNING:user_policy_manager_factory_chromeos.cc(209)] No policy loaded for known non-enterprise user
[5696:5696:0706/045947.833499:ERROR:cros_settings_provider.cc(30)] Ignoring the guest request to change: cros.system.timezone
[5696:5696:0706/045949.136432:INFO:file_manager_browsertest_base.cc(1004)] FileManagerBrowserTest::StartTest renameNewFolderDownloads
[5696:5696:0706/045950.444837:INFO:file_manager_browsertest_base.cc(1072)] renameNewFolderDownloads isInGuestMode: true
[5696:5717:0706/045956.597515:WARNING:simple_synchronous_entry.cc(1252)] Could not open platform files for entry.
../../chrome/browser/chromeos/file_manager/file_manager_browsertest_base.cc:1035: Failure
Failed
Failed 1 of 1 tests
Stack trace:
#0 0x000003f5e6c0 StackTraceGetter::CurrentStackTrace()
#1 0x000003f7f187 testing::internal::UnitTestImpl::CurrentOsStackTraceExceptTop()
#2 0x000003f7e5ed testing::internal::AssertHelper::operator=()
#3 0x000002770fa2 file_manager::FileManagerBrowserTestBase::RunTestMessageLoop()
#4 0x000002770d02 file_manager::FileManagerBrowserTestBase::StartTest()
#5 0x00000275d395 file_manager::FilesAppBrowserTest_Test_Test::RunTestOnMainThread()
#6 0x0000078ac5ee content::BrowserTestBase::ProxyRunTestOnMainThreadLoop()
#7 0x000000987bbd _ZN4base8internal13FunctorTraitsIM25RenderViewContextMenuBaseFvvEvE6InvokeIS4_P21RenderViewContextMenuJEEEvT_OT0_DpOT1_
#8 0x000000987b04 _ZN4base8internal12InvokeHelperILb0EvE8MakeItSoIM25RenderViewContextMenuBaseFvvEJP21RenderViewContextMenuEEEvOT_DpOT0_
#9 0x0000078ae8e5 _ZN4base8internal7InvokerINS0_9BindStateIMN7content15BrowserTestBaseEFvvEJNS0_17UnretainedWrapperIS4_EEEEEFvvEE7RunImplIRKS6_RKNSt3__15tupleIJS8_EEEJLm0EEEEvOT_OT0_NSF_16integer_sequenceImJXspT1_EEEE
#10 0x0000078ae82c _ZN4base8internal7InvokerINS0_9BindStateIMN7content15BrowserTestBaseEFvvEJNS0_17UnretainedWrapperIS4_EEEEEFvvEE3RunEPNS0_13BindStateBaseE
#11 0x00000097823d _ZNKR4base17RepeatingCallbackIFvvEE3RunEv
#12 0x00000683d740 ChromeBrowserMainParts::PreMainMessageLoopRunImpl()
#13 0x00000683b91e ChromeBrowserMainParts::PreMainMessageLoopRun()
#14 0x0000033a356a chromeos::ChromeBrowserMainPartsChromeos::PreMainMessageLoopRun()
#15 0x7f281d27802c content::BrowserMainLoop::PreMainMessageLoopRun()
#16 0x7f281bfd9e8d _ZN4base8internal13FunctorTraitsIMN7content12ChildProcessEFvvEvE6InvokeIS5_PS3_JEEEvT_OT0_DpOT1_
#17 0x7f281bfd9dd4 _ZN4base8internal12InvokeHelperILb0EvE8MakeItSoIMN7content12ChildProcessEFvvEJPS5_EEEvOT_DpOT0_
#18 0x7f281d27d8b5 _ZN4base8internal7InvokerINS0_9BindStateIMN7content15BrowserMainLoopEFivEJNS0_17UnretainedWrapperIS4_EEEEEFivEE7RunImplIRKS6_RKNSt3__15tupleIJS8_EEEJLm0EEEEiOT_OT0_NSF_16integer_sequenceImJXspT1_EEEE
#19 0x7f281d27d7fc _ZN4base8internal7InvokerINS0_9BindStateIMN7content15BrowserMainLoopEFivEJNS0_17UnretainedWrapperIS4_EEEEEFivEE3RunEPNS0_13BindStateBaseE
#20 0x7f281bee533d _ZNKR4base17RepeatingCallbackIFvvEE3RunEv
#21 0x7f281e0fab1d content::StartupTaskRunner::RunAllTasksNow()
#22 0x7f281d273730 content::BrowserMainLoop::CreateStartupTasks()
#23 0x7f281d27fe87 content::BrowserMainRunnerImpl::Initialize()
#24 0x7f281d26b9f9 content::BrowserMain()
#25 0x7f281f40fbb0 content::RunBrowserProcessMain()
#26 0x7f281f411fda content::ContentMainRunnerImpl::Run()
#27 0x7f281f4069b5 content::ContentServiceManagerMainDelegate::RunEmbedderProcess()
#28 0x7f281835e0b1 service_manager::Main()
#29 0x7f281f40cb55 content::ContentMain()
#30 0x0000078abb98 content::BrowserTestBase::SetUp()
#31 0x0000066e2382 InProcessBrowserTest::SetUp()
#32 0x0000022045ee extensions::ExtensionBrowserTest::SetUp()
#33 0x00000276c94c file_manager::FileManagerBrowserTestBase::SetUp()
#34 0x0000009d87be _ZN7testing8internal12InvokeHelperIRKNSt3__16vectorIPN12user_manager4UserENS2_9allocatorIS6_EEEENS2_5tupleIJEEEE12InvokeMethodIN8chromeos15MockUserManagerEMSH_KFSB_vEEESB_PT_T0_RKSD_
[5696:5696:0706/045958.923991:WARNING:event_router.cc(443)] Not all file watchers are removed. This can happen when the Files app is open during shutdown.
[5696:5707:0706/045959.076506:WARNING:discardable_shared_memory_manager.cc(431)] Some MojoDiscardableSharedMemoryManagerImpls are still alive. They will be leaked.
[5696:5923:0706/045959.077643:WARNING:internal_linux.cc(64)] Failed to read /proc/5725/stat
[5696:5924:0706/045959.080620:WARNING:internal_linux.cc(64)] Failed to read /proc/5766/stat
[5696:5696:0706/045959.152032:WARNING:pref_notifier_impl.cc(23)] Pref observer found at shutdown.
[5696:5696:0706/045959.152110:WARNING:pref_notifier_impl.cc(23)] Pref observer found at shutdown.
[  FAILED  ] KeyboardOperations/FilesAppBrowserTest.Test/renameNewFolderDownloads_GuestMode, where GetParam() = 16-byte object <08-F7 0D-0E 00-00 00-00 01-00 00-00 00-00 00-00> (13633 ms)

The culprit just reveals hidden errors. Moving to lucmult@ for further investigation.
Cc: sashab@chromium.org noel@chromium.org
Components: -Tests>Flaky Platform>Apps>FileManager
Labels: -OS-Linux Test-Flaky OS-Chrome
Status: Started (was: Assigned)
I'll investigate the issue for a bit and then revert the change, since it is't a crucial change.
Blocking: 836254
Resolving error in a promise.all chain is tricky.  Maybe revert and see if things improve, and work out the promise.all problem afterwards?   
I have reverted the original failure.

Thanks to the great noel@ who explained to me that GuestMode (which is an incognito) we don't have logs, so I'm debugging on the non-GuestMode.

I managed to get an error by running the test in debug and running several times in a row:

Command I used:
$ for i in {1..20}; do  mkcros && xvfb-run -s "-screen 0 1024x758x24"  ./out/cOS/browser_tests  --gtest_filter='KeyboardOperations/FilesAppBrowserTest.Test/renameNewFolderDownloads' 2>&1  |tee -a /tmp/bla.log |grep ' FAILED ' ; done


Failure found so far:
[226766:226766:0709/144438.831000:INFO:CONSOLE(12283)] "[object DOMException]", source: chrome-extension://hhaomjibdihmijegdhdafkllkbggdgoj/foreground/js/main_scripts.js (12283)                                                                                                       
[226766:226766:0709/144438.831516:INFO:CONSOLE(34071)] "name: NotFoundError msg: A requested file or directory could not be found at the time an operation was processed.", source: chrome-extension://hhaomjibdihmijegdhdafkllkbggdgoj/foreground/js/main_scripts.js (34071)           


I'm checking further this failure.
It turns out the error NotFound is for entry "/New Folder".

This error happens when "entry.getMetadata" is called after "/New Folder" has been already renamed to "/foo", thus the file system returns the "not found" error.

So, this error condition is sort of expected.

We have three options here.

1.  Don't add any logging and keep this failing silently and some issues with getMetadata can be tricky to find.

2.  Add logging as console.log(...) which doesn't make the test fail at all.

3.  Refactor prefetchMetadata and getMetadata to be able to be cancelled if the file has been renamed or deleted, but this seems a non-trivial change.
Flakiness fixed.
Screen Shot 2018-07-10 at 9.47.55 AM.png
208 KB View Download
Cc: lucmult@chromium.org
Owner: noel@chromium.org
#17 So console.error is overloaded in Files.App to log a message _and_ increase the window.JSErrorCount.  Tests call checkIfNoErrorsOccured() at the end of a test to check window.JSErrorCount.

And r572875 console.error logged entry.getMetadata errors, and that increased the window.JSErrorCount.  The entry.getMetadata "errors" were intermittent, due to metadata updates being in a queue whatever (a data race), causing flakey failures.

> "error condition is sort of expected"

Given metadata queueing and all, seems so.  The current bug is fixed, and the suggestions in #17 could be added to another bug to address the problems of metadata race conditions [1].

[1] seems sub-optimal to me from a test perspective - developer requests file metadata in a test, and might or might not get the right result depending on queueing => flakey test. 
Status: Fixed (was: Started)
The DirectoryTreeContextMenu/FilesAppBrowserTest.Test/dirCreateWithContextMenu flake reported crbug.com/836254#c95 was also caused by the current  issue 860647   aka "the error count is not 0".
Status: Verified (was: Fixed)
Picture looks good.
Screen Shot 2018-07-10 at 3.08.23 PM.png
849 KB View Download
^^^ aka flake leopard spots moving right towards /dev/null-land.

Sign in to add a comment