desktopui_DocViewing failure: Cannot open doc in 45 secs [40950995]

Obsolete

Bug

Status Update

No update yet.

Description

[Deleted User]

created issue #1

Aug 30, 2012 11:30PM

desktopui_DocViewing fails every once in a while. The logs suggest that chrome could not successfully open the doc in 45 secs.

http://atlantis2.mtv.corp.google.com/results/571913-chromeos-test/chromeos1-rack3-host8/desktopui_DocViewing/

08/30 15:48:37 ERROR|base_utils:0113| [stderr] Some features may not be available.
08/30 15:48:38 ERROR|base_utils:0113| [stderr] 2012-08-30 15:48:38,612 DEBUG Started http server at "chrome/test/data".
08/30 15:48:38 ERROR|base_utils:0113| [stderr] [ RUN ] doc_viewing.DocViewingTest.testOpenOfficeFiles: "Test we can open office files from the file manager."
08/30 15:49:01 ERROR|base_utils:0113| [stderr] 2012-08-30 15:49:01,415 DEBUG WaitUntil(pyauto.py:1498 GetActiveTabTitle()) still waiting. Expecting worldhistory.docx. Last returned Document viewing.
08/30 15:50:20 ERROR|base_utils:0113| [stderr] [4329:4329:0830/155020:1342415164:ERROR:pyautolib.cc(139)] Error during automation: Chrome automation timed out after 45 seconds for {"frame_xpath": "", "javascript": "\n pyautoAPI.executeDefaultTask()\n ", "command": "ExecuteJavascript", "tab_index": 0, "windex": 0}
08/30 15:50:20 ERROR|base_utils:0113| [stderr] [ ERROR ] doc_viewing.DocViewingTest.testOpenOfficeFiles
08/30 15:50:20 ERROR|base_utils:0113| [stderr]
08/30 15:50:20 ERROR|base_utils:0113| [stderr] ======================================================================
08/30 15:50:20 ERROR|base_utils:0113| [stderr] ERROR: doc_viewing.DocViewingTest.testOpenOfficeFiles: "Test we can open office files from the file manager."
08/30 15:50:20 ERROR|base_utils:0113| [stderr] ----------------------------------------------------------------------
08/30 15:50:20 ERROR|base_utils:0113| [stderr] Traceback (most recent call last):
08/30 15:50:20 ERROR|base_utils:0113| [stderr] File "/usr/local/autotest/deps/chrome_test/test_src/chrome/test/functional/doc_viewing.py", line 65, in testOpenOfficeFiles
08/30 15:50:20 ERROR|base_utils:0113| [stderr] file_browser.ExecuteDefaultTask()
08/30 15:50:20 ERROR|base_utils:0113| [stderr] File "/usr/local/autotest/deps/chrome_test/test_src/chrome/test/functional/../pyautolib/chromeos/file_browser.py", line 81, in ExecuteDefaultTask
08/30 15:50:20 ERROR|base_utils:0113| [stderr] self.executor.Execute(script)
08/30 15:50:20 ERROR|base_utils:0113| [stderr] File "/usr/local/autotest/deps/chrome_test/test_src/chrome/test/functional/../pyautolib/pyauto.py", line 1003, in Execute
08/30 15:50:20 ERROR|base_utils:0113| [stderr] self.frame_xpath)
08/30 15:50:20 ERROR|base_utils:0113| [stderr] File "/usr/local/autotest/deps/chrome_test/test_src/chrome/test/functional/../pyautolib/pyauto.py", line 3911, in ExecuteJavascript
08/30 15:50:20 ERROR|base_utils:0113| [stderr] result = self._GetResultFromJSONRequest(cmd_dict)['result']
08/30 15:50:20 ERROR|base_utils:0113| [stderr] File "/usr/local/autotest/deps/chrome_test/test_src/chrome/test/functional/../pyautolib/pyauto.py", line 1117, in _GetResultFromJSONRequest
08/30 15:50:20 ERROR|base_utils:0113| [stderr] raise AutomationCommandTimeout(ret_dict['error'])
08/30 15:50:20 ERROR|base_utils:0113| [stderr] AutomationCommandTimeout: Chrome automation timed out after 45 seconds for {"frame_xpath": "", "javascript": "\n pyautoAPI.executeDefaultTask()\n ", "command": "ExecuteJavascript", "tab_index": 0, "windex": 0}
08/30 15:50:20 ERROR|base_utils:0113| [stderr]

Comments

[Deleted User] <[Deleted User]> #2Sep 26, 2012 05:18PM

[Empty comment from Monorail migration]

[Deleted User] <[Deleted User]> #3Sep 26, 2012 05:19PM

[Empty comment from Monorail migration]

di...@chromium.org <di...@chromium.org> #4Sep 26, 2012 11:26PM

Just hit this again.

https://uberchromegw.corp.google.com/i/chromeos/builders/stumpy%20canary/builds/1934
-->

http://atlantis4.mtv.corp.google.com/results/703793-chromeos-test/chromeos-rack8c-host3/

[Deleted User] <[Deleted User]> #5Sep 27, 2012 12:17AM

Can you tell if this is caused by flakiness in NaCl? There have been no changes to the extension that is the CWS since M21 - 2.2.45.1.

https://chrome.google.com/webstore/detail/gbkeegbaiigmenfmjfclcdgdpimamgkj

be...@google.com <be...@google.com> #6Sep 28, 2012 04:58PM

[Empty comment from Monorail migration]

so...@chromium.org <so...@chromium.org> #7Sep 28, 2012 09:29PM

This has been failing a lot on canaries and closing the tree -- see

http://cautotest/results/dashboard/waterfall_index.html

so...@chromium.org <so...@chromium.org> #8Sep 28, 2012 09:29PM

Can you find someone to look into this?

be...@google.com <be...@google.com> #9Oct 1, 2012 03:08PM

Assigned to ze...@chromium.org.

Zel - can you traige?

ze...@chromium.org <ze...@chromium.org> #10Oct 1, 2012 08:33PM

Reassigned to rk...@chromium.org.

[Empty comment from Monorail migration]

ro...@chromium.org <ro...@chromium.org> #11Oct 4, 2012 08:52AM

One more instance:

http://chromegw/i/chromeos/builders/kiev%20canary/builds/816 -->

http://atlantis4.mtv.corp.google.com/results/740848-chromeos-test/chromeos2-row5-rack7-host4/

[Deleted User] <[Deleted User]> #12Oct 4, 2012 05:50PM

[Empty comment from Monorail migration]

be...@chromium.org <be...@chromium.org> #13Oct 8, 2012 05:24PM

This test is failing consistently on R23.

Example:

http://atlantis4.mtv.corp.google.com/results/762535-chromeos-test/chromeos-rack8a-host4/desktopui_DocViewing/status

be...@chromium.org <be...@chromium.org> #14Oct 8, 2012 05:24PM

[Empty comment from Monorail migration]

rk...@chromium.org <rk...@chromium.org> #15Oct 8, 2012 08:14PM

I believe this is related to the issue we have with the NaCl sanity test. Neither of these tests are able to load their NaCl extensions after James's CL (

https://chromiumcodereview.appspot.com/10949017) had landed. I did revert the CL but we've had to reland it again since it contains changes crucial to NPAPI plugin handling on Windows 8.

James is looking into figuring out why the CL is preventing these tests from working. We have verified that the extensions _do load and work fine when done manually. This is under investigation but I don't believe that this is really a release blocker. If the fail on the BVT's is an issue, we can simply disable it for now considering it is a known issue.

[Deleted User] <[Deleted User]> #16Oct 8, 2012 10:33PM

Discussed with patricia@ - will set test as experimental for now.

https://crbug.com/chromium/154696 filed to track that action.

va...@chromium.org <va...@chromium.org> #17Oct 13, 2012 05:36AM

failed again on kiev:

http://chromegw/i/chromeos/builders/kiev%20canary/builds/854

jr...@chromium.org <jr...@chromium.org> #18Oct 22, 2012 07:00PM

[Empty comment from Monorail migration]

[Deleted User] <[Deleted User]> #19Oct 22, 2012 11:53PM

Reassigned to sa...@chromium.org.

[Empty comment from Monorail migration]

sa...@chromium.org <sa...@chromium.org> #20Oct 23, 2012 12:03AM

Reassigned to rk...@chromium.org.

I inherited the task to mark the test as experimental because I was the sheriff/gardener today, not because I know anything about this :) Resetting owner to rkc@

rk...@chromium.org <rk...@chromium.org> #21Oct 23, 2012 12:10AM

Reassigned to sa...@chromium.org.

Just marking it as experimental is the correct solution at this post. People are working on revamping our tests at the moment anyway.

Feel free to mark this as WontFix or Fixed once the test is marked as experimental (not sure if it is, I didn't see a CL attached to this bug).

[Deleted User] <[Deleted User]> #22Oct 23, 2012 04:24PM

[Empty comment from Monorail migration]

[Deleted User] <[Deleted User]> #23Oct 23, 2012 04:26PM

Happened again on:

"stumpy-r24 build, R24-3080.0.0, running on stumpy"

Test fail screenshot attached. Screenshot shows a file present.

test-fail-screenshot-0.png

181 KB

View

Download

[Deleted User] <[Deleted User]> #24Oct 23, 2012 05:06PM

Reassigned to rk...@chromium.org.

The experimental label is for tests that may not yet be stable enough for the BVT, not for ignoring tests that aren't being actively investigated.

If a test has been adequately replaced by other tests it should be removed from the bvt entirely.

[Deleted User] <[Deleted User]> #25Oct 23, 2012 06:29PM

Reassigned to ka...@chromium.org.

Assigning back to kaznacheev, git says he is the most qualified to look at this.

[Deleted User] <[Deleted User]> #26Oct 23, 2012 06:45PM

Happened again on "stumpy-r24 build, R24-3081.0.0, running on stumpy".

Failure screenshot shows a different file this time.

test-fail-screenshot-0.png

181 KB

View

Download

mk...@chromium.org <mk...@chromium.org> #27Oct 23, 2012 10:08PM

This seems to have broken the tree again:

http://chromegw/i/chromeos/builders/x86-alex%20canary/builds/2741. See

https://crbug.com/chromium/35648 for why an "experimental" autotest still broke the tree.

I see the following in

http://atlantis4.mtv.corp.google.com/results/851577-chromeos-test/chromeos2-row1-rack7-host10/desktopui_DocViewing/debug/desktopui_DocViewing.DEBUG:
10/23 13:27:46.839 ERROR|base_utils:0113| [stderr] 2012-10-23 13:27:46,838 DEBUG WaitUntil(pyauto.py:1494 GetActiveTabTitle()) still waiting. Expecting chapt13.pptx. Last returned Quickoffice Viewer.

What's strange to me is that it looks like there was also an issue taking a screenshot:
10/23 13:27:53.113 INFO |cros_ui_te:0357| Saving screenshot to /usr/local/autotest/results/default/desktopui_DocViewing/results/test-fail-screenshot-0.png.
10/23 13:27:53.115 DEBUG|base_utils:0081| Running 'DISPLAY=:0.0 XAUTHORITY=/home/chronos/.Xauthority /usr/local/bin/import -window root /usr/local/autotest/results/default/desktopui_DocViewing/results/test-fail-screenshot-0.png'
10/23 13:27:53.488 ERROR|base_utils:0113| [stderr] XIO: fatal IO error 11 (Resource temporarily unavailable) on X server ":0.0"
10/23 13:27:53.492 ERROR|base_utils:0113| [stderr] after 19 requests (19 known processed) with 0 events remaining.
Not sure if that should be filed as a separate bug.

mk...@chromium.org <mk...@chromium.org> #28Oct 23, 2012 10:10PM

[Empty comment from Monorail migration]

ka...@chromium.org <ka...@chromium.org> #29Oct 29, 2012 08:33PM

[Empty comment from Monorail migration]

[Deleted User] <[Deleted User]> #30Oct 30, 2012 05:26PM

Again:

http://atlantis4.mtv.corp.google.com/results/898748-chromeos-test/chromeos1-rack8c-host6/desktopui_DocViewing/

[ RUN ] doc_viewing.DocViewingTest.testOpenOfficeFiles: "Test we can open office files from the file manager."
2012-10-30 02:48:35,053 DEBUG WaitUntil(file_browser.py:183 return self._ui_test.WaitUntil(lambda: _IsInitialized())) still waiting. Expecting True. Last returned False.
2012-10-30 02:48:43,415 DEBUG WaitUntil(pyauto.py:1494 GetActiveTabTitle()) still waiting. Expecting wghstyle.doc. Last returned Downloads.
2012-10-30 02:48:48,455 DEBUG WaitUntil(pyauto.py:1494 GetActiveTabTitle()) still waiting. Expecting wghstyle.doc. Last returned Downloads.
2012-10-30 02:48:53,495 DEBUG WaitUntil(pyauto.py:1494 GetActiveTabTitle()) still waiting. Expecting wghstyle.doc. Last returned Downloads.
2012-10-30 02:48:58,533 DEBUG WaitUntil(pyauto.py:1494 GetActiveTabTitle()) still waiting. Expecting wghstyle.doc. Last returned Downloads.
2012-10-30 02:49:03,571 DEBUG WaitUntil(pyauto.py:1494 GetActiveTabTitle()) still waiting. Expecting wghstyle.doc. Last returned Downloads.
2012-10-30 02:49:08,608 DEBUG WaitUntil(pyauto.py:1494 GetActiveTabTitle()) still waiting. Expecting wghstyle.doc. Last returned Downloads.
2012-10-30 02:49:13,394 DEBUG WaitUntil(pyauto.py:1494 GetActiveTabTitle()) still waiting. Expecting wghstyle.doc. Last returned Downloads.
2012-10-30 02:49:18,433 DEBUG WaitUntil(pyauto.py:1494 GetActiveTabTitle()) still waiting. Expecting wghstyle.doc. Last returned Downloads.
[ FAILED ] doc_viewing.DocViewingTest.testOpenOfficeFiles

======================================================================
FAIL: doc_viewing.DocViewingTest.testOpenOfficeFiles: "Test we can open office files from the file manager."
----------------------------------------------------------------------

AssertionError: "wghstyle.doc" does not open.

[Deleted User] <[Deleted User]> #31Oct 30, 2012 09:51PM

And again.

http://cautotest/tko/retrieve_logs.cgi?job=/results/901499-chromeos-test/chromeos1-rack8b-host7/desktopui_DocViewing

AssertionError: "Jingjing Wang.ppt" does not open.

[Deleted User] <[Deleted User]> #32Oct 31, 2012 03:31PM

http://cautotest/tko/retrieve_logs.cgi?job=/results/902963-chromeos-test/chromeos2-row3-rack6-host1/desktopui_DocViewing

AutomationCommandTimeout: Chrome automation timed out after 45 seconds for {"frame_xpath": "", "javascript": "\n pyautoAPI.executeDefaultTask()\n ", "command": "ExecuteJavascript", "tab_index": 0, "windex": 0}

ka...@chromium.org <ka...@chromium.org> #33Dec 19, 2012 08:05AM

Reassigned to Deleted User.

I have no idea how to repro this. Lets check if this still occurs.

[Deleted User] <[Deleted User]> #34Dec 19, 2012 04:46PM

Status: Won't Fix (Obsolete)

No longer seeing this with the new Chrome Office Viewer 2.5.72.1.

Google Chrome 25.0.1363.0 (Official Build 173396) canary
Platform 3417.0.0 (Official Build) canary-channel stumpy

bu...@chromium.org <bu...@chromium.org> #35Mar 10, 2013 07:00PM

[Empty comment from Monorail migration]

la...@google.com <la...@google.com> #36Mar 11, 2013 12:59AM

[Empty comment from Monorail migration]

rk...@chromium.org <rk...@chromium.org> #37May 7, 2019 07:50PM

[Empty comment from Monorail migration]

is...@google.com <is...@google.com> #38May 7, 2019 07:50PM

This issue was migrated from

crbug.com/chromium/154063?no_tracker_redirect=1

[Monorail mergedwith:

crbug.com/chromium/217529,

crbug.com/chromium/217716]
[Monorail components added to Component Tags custom field.]

Issue 40950995

Description

Issue summary

Comments

[Deleted User] <[Deleted User]> #2Sep 26, 2012 05:18PM

[Deleted User] <[Deleted User]> #3Sep 26, 2012 05:19PM

di...@chromium.org <di...@chromium.org> #4Sep 26, 2012 11:26PM

[Deleted User] <[Deleted User]> #5Sep 27, 2012 12:17AM

be...@google.com <be...@google.com> #6Sep 28, 2012 04:58PM

so...@chromium.org <so...@chromium.org> #7Sep 28, 2012 09:29PM

so...@chromium.org <so...@chromium.org> #8Sep 28, 2012 09:29PM

be...@google.com <be...@google.com> #9Oct 1, 2012 03:08PM

ze...@chromium.org <ze...@chromium.org> #10Oct 1, 2012 08:33PM

ro...@chromium.org <ro...@chromium.org> #11Oct 4, 2012 08:52AM

[Deleted User] <[Deleted User]> #12Oct 4, 2012 05:50PM

be...@chromium.org <be...@chromium.org> #13Oct 8, 2012 05:24PM

be...@chromium.org <be...@chromium.org> #14Oct 8, 2012 05:24PM

rk...@chromium.org <rk...@chromium.org> #15Oct 8, 2012 08:14PM

[Deleted User] <[Deleted User]> #16Oct 8, 2012 10:33PM

va...@chromium.org <va...@chromium.org> #17Oct 13, 2012 05:36AM

jr...@chromium.org <jr...@chromium.org> #18Oct 22, 2012 07:00PM

[Deleted User] <[Deleted User]> #19Oct 22, 2012 11:53PM

sa...@chromium.org <sa...@chromium.org> #20Oct 23, 2012 12:03AM

rk...@chromium.org <rk...@chromium.org> #21Oct 23, 2012 12:10AM

[Deleted User] <[Deleted User]> #22Oct 23, 2012 04:24PM

[Deleted User] <[Deleted User]> #23Oct 23, 2012 04:26PM

[Deleted User] <[Deleted User]> #24Oct 23, 2012 05:06PM

[Deleted User] <[Deleted User]> #25Oct 23, 2012 06:29PM

[Deleted User] <[Deleted User]> #26Oct 23, 2012 06:45PM

mk...@chromium.org <mk...@chromium.org> #27Oct 23, 2012 10:08PM

mk...@chromium.org <mk...@chromium.org> #28Oct 23, 2012 10:10PM

ka...@chromium.org <ka...@chromium.org> #29Oct 29, 2012 08:33PM

[Deleted User] <[Deleted User]> #30Oct 30, 2012 05:26PM

[Deleted User] <[Deleted User]> #31Oct 30, 2012 09:51PM

[Deleted User] <[Deleted User]> #32Oct 31, 2012 03:31PM

ka...@chromium.org <ka...@chromium.org> #33Dec 19, 2012 08:05AM

[Deleted User] <[Deleted User]> #34Dec 19, 2012 04:46PM

bu...@chromium.org <bu...@chromium.org> #35Mar 10, 2013 07:00PM

la...@google.com <la...@google.com> #36Mar 11, 2013 12:59AM

rk...@chromium.org <rk...@chromium.org> #37May 7, 2019 07:50PM

is...@google.com <is...@google.com> #38May 7, 2019 07:50PM

Add comment

Issue metadata