My favorites | Sign in
Project Home Downloads Wiki Issues Code Search
New issue   Search
for
  Advanced search   Search tips   Subscriptions
Issue 53140: PageCyclerDatabaseTest flaky on the mac with automation disconnect
8 people starred this issue and may be notified of changes. Back to list
 
Project Member Reported by thestig@chromium.org, Aug 23, 2010
Various Mac Perf bots have been unhappy on 6+ occasions:

http://build.chromium.org/buildbot/waterfall/builders/Mac10.5%20Perf(1)/builds/15916/steps/page_cycler_database/logs/stdio

[ RUN      ] PageCyclerDatabaseTest.DatabaseSelectTransactionsFile
[9912:267:0823/153605:28732935107029:INFO:/b/slave/chromium-rel-mac-builder/build/src/chrome/test/page_cycler/page_cycler_test.cc(151)] Buffer cache should be primed with 2 files.
[9912:267:0823/153641:28768316454098:ERROR:/b/slave/chromium-rel-mac-builder/build/src/chrome/test/automation/automation_proxy.cc(465)] Disconnecting channel after error!
/b/slave/chromium-rel-mac-builder/build/src/chrome/test/page_cycler/page_cycler_test.cc:253: Failure
Value of: tab->ExecuteAndExtractString(L"", L"window.domAutomationController.send(" L"JSON.stringify(__get_timings()));", &wcookie)
  Actual: false
Expected: true
[9912:267:0823/153641:28768316741532:ERROR:/b/slave/chromium-rel-mac-builder/build/src/chrome/test/automation/automation_proxy.cc(452)] Automation channel has been closed; dropping message!
/b/slave/chromium-rel-mac-builder/build/src/chrome/test/ui/ui_test.cc:423: Failure
Value of: automation()->SetFilteredInet(false)
  Actual: false
Expected: true
[9912:267:0823/153641:28768316866277:ERROR:/b/slave/chromium-rel-mac-builder/build/src/chrome/test/automation/automation_proxy.cc(452)] Automation channel has been closed; dropping message!
/b/slave/chromium-rel-mac-builder/build/src/chrome/test/ui/ui_test.cc:427: Failure
Value of: automation()->GetBrowserWindowCount(&window_count)
  Actual: false
Expected: true
[9912:267:0823/153641:28768316987464:ERROR:/b/slave/chromium-rel-mac-builder/build/src/chrome/test/automation/automation_proxy.cc(452)] Automation channel has been closed; dropping message!
/b/slave/chromium-rel-mac-builder/build/src/chrome/test/ui/ui_test.cc:448: Failure
Value of: browser_proxy.get()
  Actual: false
Expected: true
[  FAILED  ] PageCyclerDatabaseTest.DatabaseSelectTransactionsFile (36177 ms)

http://build.chromium.org/buildbot/waterfall/builders/Mac10.5%20Perf(1)/builds/15912/steps/page_cycler_database/logs/stdio

[ RUN      ] PageCyclerDatabaseReferenceTest.DatabaseInsertTransactionsFile
[7985:523:23179881523969:ERROR:/b/slave/chromium-rel-mac/build/src/chrome/browser/first_run.cc(118)] Not implemented reached in static bool FirstRun::ProcessMasterPreferences(const FilePath&, const FilePath&, FirstRun::MasterPrefs*)
[7954:267:0823/140333:23180125663822:INFO:/b/slave/chromium-rel-mac-builder/build/src/chrome/test/page_cycler/page_cycler_test.cc(151)] Buffer cache should be primed with 2 files.
[7954:267:0823/140417:23224026177040:ERROR:/b/slave/chromium-rel-mac-builder/build/src/chrome/test/automation/automation_proxy.cc(465)] Disconnecting channel after error!
/b/slave/chromium-rel-mac-builder/build/src/chrome/test/page_cycler/page_cycler_test.cc:253: Failure
Value of: tab->ExecuteAndExtractString(L"", L"window.domAutomationController.send(" L"JSON.stringify(__get_timings()));", &wcookie)
  Actual: false
Expected: true
[7954:267:0823/140417:23224026614926:ERROR:/b/slave/chromium-rel-mac-builder/build/src/chrome/test/automation/automation_proxy.cc(452)] Automation channel has been closed; dropping message!
/b/slave/chromium-rel-mac-builder/build/src/chrome/test/ui/ui_test.cc:423: Failure
Value of: automation()->SetFilteredInet(false)
  Actual: false
Expected: true
[7954:267:0823/140417:23224026784238:ERROR:/b/slave/chromium-rel-mac-builder/build/src/chrome/test/automation/automation_proxy.cc(452)] Automation channel has been closed; dropping message!
/b/slave/chromium-rel-mac-builder/build/src/chrome/test/ui/ui_test.cc:427: Failure
Value of: automation()->GetBrowserWindowCount(&window_count)
  Actual: false
Expected: true
[7954:267:0823/140417:23224026940396:ERROR:/b/slave/chromium-rel-mac-builder/build/src/chrome/test/automation/automation_proxy.cc(452)] Automation channel has been closed; dropping message!
/b/slave/chromium-rel-mac-builder/build/src/chrome/test/ui/ui_test.cc:448: Failure
Value of: browser_proxy.get()
  Actual: false
Expected: true
[  FAILED  ] PageCyclerDatabaseReferenceTest.DatabaseInsertTransactionsFile (44474 ms)

Aug 23, 2010
#1 thomasvl@chromium.org
I think this also showed up on windows today.
Aug 23, 2010
#2 d...@chromium.org
(No comment was entered for this change.)
Cc: d...@chromium.org
Aug 23, 2010
#3 d...@chromium.org
As far as I can tell, there's nothing wrong with the DB tests. It looks like a more general problem with how the page_cycler tests are setup and run. page_cycler_bloat-http runs into the same problem sometimes: http://build.chromium.org/buildbot/waterfall/builders/Mac10.6%20Perf(1)/builds/7009/steps/page_cycler_bloat-http/logs/stdio.
Aug 24, 2010
#4 phajdan.jr@chromium.org
(No comment was entered for this change.)
Labels: -Tests Tests-Disabled
Aug 24, 2010
#5 bugdroid1@gmail.com
The following revision refers to this bug:
    http://src.chromium.org/viewvc/chrome?view=rev&revision=57265 

------------------------------------------------------------------------
r57265 | dumi@chromium.org | 2010-08-24 17:29:50 -0700 (Tue, 24 Aug 2010) | 8 lines
Changed paths:
   M http://src.chromium.org/viewvc/chrome/trunk/src/chrome/test/page_cycler/page_cycler_test.cc?r1=57265&r2=57264

Disable page_cycler_database on Mac. It looks like the perf bots are
having some problems, and on Mac, those problems show up the most when
running this test suite.

TEST=none
BUG=53140

Review URL: http://codereview.chromium.org/3119042
------------------------------------------------------------------------

Aug 24, 2010
#6 bugdroid1@gmail.com
The following revision refers to this bug:
    http://src.chromium.org/viewvc/chrome?view=rev&revision=57270 

------------------------------------------------------------------------
r57270 | dumi@chromium.org | 2010-08-24 18:00:41 -0700 (Tue, 24 Aug 2010) | 7 lines
Changed paths:
   M http://src.chromium.org/viewvc/chrome/trunk/src/chrome/test/page_cycler/page_cycler_test.cc?r1=57270&r2=57269

Disable page_cycler_database everywhere.

TEST=none
BUG=53140
TBR=rohitrao

Review URL: http://codereview.chromium.org/3191025
------------------------------------------------------------------------

Aug 25, 2010
#7 rohitrao@chromium.org
We ended up having to disable this on all platforms in the end.  Same "stringify" problem everywhere.
Labels: -OS-Mac OS-All
Aug 26, 2010
#8 cmp@chromium.org
(cross-reference with  issue 53491 )
Aug 26, 2010
#9 phajdan.jr@chromium.org
All Tests-Disabled bugs need an owner. Feel free to reassign, but do not leave the owner field empty.
Status: Assigned
Owner: d...@chromium.org
Cc: -d...@chromium.org
Aug 27, 2010
#10 bugdroid1@gmail.com
The following revision refers to this bug:
    http://src.chromium.org/viewvc/chrome?view=rev&revision=57734 

------------------------------------------------------------------------
r57734 | chase@chromium.org | 2010-08-27 14:30:22 -0700 (Fri, 27 Aug 2010) | 10 lines
Changed paths:
   M http://src.chromium.org/viewvc/chrome/trunk/src/chrome/test/page_cycler/page_cycler_test.cc?r1=57734&r2=57733

Revert 57270 - Disable page_cycler_database everywhere.

TEST=none
BUG=53140
TBR=rohitrao

Review URL: http://codereview.chromium.org/3191025

TBR=dumi@chromium.org
Review URL: http://codereview.chromium.org/3282002
------------------------------------------------------------------------

Aug 27, 2010
#11 bugdroid1@gmail.com
The following revision refers to this bug:
    http://src.chromium.org/viewvc/chrome?view=rev&revision=57735 

------------------------------------------------------------------------
r57735 | chase@chromium.org | 2010-08-27 14:31:27 -0700 (Fri, 27 Aug 2010) | 11 lines
Changed paths:
   M http://src.chromium.org/viewvc/chrome/trunk/src/chrome/test/page_cycler/page_cycler_test.cc?r1=57735&r2=57734

Revert 57265 - Disable page_cycler_database on Mac. It looks like the perf bots are
having some problems, and on Mac, those problems show up the most when
running this test suite.

TEST=none
BUG=53140

Review URL: http://codereview.chromium.org/3119042

TBR=dumi@chromium.org
Review URL: http://codereview.chromium.org/3243006
------------------------------------------------------------------------

Sep 14, 2010
#12 asha...@chromium.org
Is it possible to resubmit my CL: http://codereview.chromium.org/3145006/show now that this test is disabled on Mac and Win?

Also, I can't seem to modify https://code.google.com/p/chromium/issues/detail?id=53491#makechanges. Can you assign that to me or delete that issue?
Sep 14, 2010
#13 cmp@chromium.org
> Is it possible to resubmit my CL: http://codereview.chromium.org/3145006/show now that this test is disabled on Mac and Win?

I don't see why disabling page_cycler_database would make the errors go away that CL caused in the other page cyclers.  Can you explain more if that's what you mean?

> Also, I can't seem to modify https://code.google.com/p/chromium/issues/detail?id=53491#makechanges. Can you assign that to me or delete that issue?

We shouldn't delete that issue.  It is tracking the work that your CL implements and the output showing the errors that show up on the bots.  I tried assigning it to you but got an error that issue owners must be project members.  (If you're not one, that explains why you can't make other changes to the bug.)  You should be able to add comments to 53491, though.
Sep 15, 2010
#14 asha...@chromium.org
Okay, I think I misunderstood what this CL did. I thought it fixed the broken-ness of the javascript readback function (tab->ExecuteAndExtractString()). 

I still don't understand why that function fails for the buildbot. It used to work fine on my machine (Ubuntu Linux).

Do you have a path to enabling my CL? I don't think the problem is with my CL. ExecuteAndExtractString() should return true (and does for me). It might be something with the buildbot or maybe some system-specific (Mac or Win) issue you are seeing.

I want to see my CL eventually hitting the trunk so let me know what I can do to help make it in.
Sep 15, 2010
#15 cmp@chromium.org
Please post comment 14 back to  issue 53491 , it's unrelated to this bug.  I'll follow up there.  Thanks.
Dec 16, 2010
#16 jor...@chromium.org
I believe dumi is no longer working on Chromium, so these may need to be re-assigned.
Status: Available
Cc: i...@chromium.org micha...@chromium.org
Dec 16, 2010
#17 jor...@chromium.org
(No comment was entered for this change.)
Owner: ---
Jun 15, 2011
#18 ian.chromium@gmail.com
(No comment was entered for this change.)
Cc: -ian.chromium@gmail.com ian@chromium.org
Sep 14, 2011
#19 j...@chromium.org
I encounter the same problem recently. After investigation, it's because we called __get_timings() too early. When page cycler called "__get_timings", the report.html was not finished yet, the test script was not parsed and executed, so calling __get_timings() could raise a exception (Uncaught ReferenceError: __get_timings is not defined) and cause DOM automation stuck, then make synchronous IPC timed-out.
It is possible since the automation call can be faster than page close (for test page of last iteration) and page load (for report.html). 

Since we can not get navigation notification of page done on the automation client side in this case (the navigation from the test page of last iteration to report.html automatically starts between the time of waiting for cookie __pc_done and the time of calling __get_timings, it's possibly done before to you call TabProxy::WaitForNavigation), we need to use other ways to make sure the test script(head.js) is loaded. It's OK in here to ignore the page loaded signal since we only care the functions in test script from this step.

To fix it, I suggestion two ways.
(1) Simple way, before calling __get_timing(), we wait for typeof(__get_timings) to return 'function', which means the test script is completed loaded. It only needs to add one sentence in page_cycler_test.cc.

(2) A little bit complicated way, adds a js variable "__results_done"  in head.js and waits for the variable to be 1 before calling __get_timings. It need to change both  page_cycler_test.cc and head.js.

I prefer way 1. A patch is on the way.

Owner: j...@chromium.org
Cc: tonyg@chromium.org
Sep 14, 2011
#20 j...@chromium.org
 Issue 67918  has been merged into this issue.
Cc: jor...@chromium.org h...@chromium.org
Sep 14, 2011
#21 j...@chromium.org
 Issue 73981  has been merged into this issue.
Cc: jeremy@chromium.org bauerb@chromium.org
Sep 14, 2011
#22 j...@chromium.org
 Issue 70858  has been merged into this issue.
Cc: d...@chromium.org nsylv...@chromium.org lzh...@chromium.org
Sep 18, 2011
#23 bugdroid1@chromium.org
The following revision refers to this bug:
    http://src.chromium.org/viewvc/chrome?view=rev&revision=101718

------------------------------------------------------------------------
r101718 | jnd@chromium.org | Sun Sep 18 19:48:11 PDT 2011

Changed paths:
 M http://src.chromium.org/viewvc/chrome/trunk/src/chrome/test/perf/page_cycler_test.cc?r1=101718&r2=101717&pathrev=101718
 M http://src.chromium.org/viewvc/chrome/trunk/src/tools/page_cycler/common/head.js?r1=101718&r2=101717&pathrev=101718

Wait for test script to be loaded before calling __get_timings by setting a variable to indicate that the result report page is loaded. See detailed analysis in crbug.com/53140.

BUG=53140
Review URL: http://codereview.chromium.org/7904005
------------------------------------------------------------------------
Sep 19, 2011
#24 bugdroid1@chromium.org
The following revision refers to this bug:
    http://src.chromium.org/viewvc/chrome?view=rev&revision=101778

------------------------------------------------------------------------
r101778 | cmp@chromium.org | Mon Sep 19 11:17:23 PDT 2011

Changed paths:
 M http://src.chromium.org/viewvc/chrome/trunk/src/chrome/test/perf/page_cycler_test.cc?r1=101778&r2=101777&pathrev=101778
 M http://src.chromium.org/viewvc/chrome/trunk/src/tools/page_cycler/common/head.js?r1=101778&r2=101777&pathrev=101778

Revert r101718 "wait for test script to be loaded"

This change broke all of the page cycler tests on the
chromium.perf waterfall.

TBR=jnd@chromium.org
BUG=53140
TEST=page cyclers work again

Review URL: http://codereview.chromium.org/7941010
------------------------------------------------------------------------
Sep 19, 2011
#25 bugdroid1@chromium.org
The following revision refers to this bug:
    http://src.chromium.org/viewvc/chrome?view=rev&revision=101798

------------------------------------------------------------------------
r101798 | cmp@chromium.org | Mon Sep 19 12:57:01 PDT 2011

Changed paths:
 M http://src.chromium.org/viewvc/chrome/trunk/src/chrome/test/perf/page_cycler_test.cc?r1=101798&r2=101797&pathrev=101798
 M http://src.chromium.org/viewvc/chrome/trunk/src/tools/page_cycler/common/head.js?r1=101798&r2=101797&pathrev=101798

Wait for test script to be loaded before calling __get_timings

Set a variable to indicate that the result report page
is loaded.  See detailed analysis in crbug.com/53140.
This is relanding r101718 after a revert at r101778.

BUG=53140
TBR=jnd@chromium.org
TEST=page cycler stays green

Review URL: http://codereview.chromium.org/7941015
------------------------------------------------------------------------
Sep 19, 2011
#27 bugdroid1@chromium.org
The following revision refers to this bug:
    http://src.chromium.org/viewvc/chrome?view=rev&revision=101892

------------------------------------------------------------------------
r101892 | jnd@chromium.org | Mon Sep 19 18:50:29 PDT 2011

Changed paths:
 M http://src.chromium.org/viewvc/chrome/trunk/deps/page_cycler/acid3/start.js?r1=101892&r2=101891&pathrev=101892

Clean variable __navigated_to_report when starting tests.

BUG=53140
TEST=page cycler
Review URL: http://codereview.chromium.org/7936007
------------------------------------------------------------------------
Oct 19, 2011
#28 j...@google.com
(No comment was entered for this change.)
Status: Fixed
Oct 13, 2012
#29 bugdroid1@chromium.org
This issue has been closed for some time. No one will pay attention to new comments.
If you are seeing this bug or have new data, please click New Issue to start a new bug.
Labels: Restrict-AddIssueComment-Commit
Nov 14, 2012
#30 bugdroid1@chromium.org
The following revision refers to this bug:
    http://goto.ext.google.com/viewvc/chrome-internal?view=rev&revision=17886

------------------------------------------------------------------------
r17886 | jnd@google.com | 2011-09-16T00:41:03.195299Z

------------------------------------------------------------------------
Nov 14, 2012
#31 bugdroid1@chromium.org
The following revision refers to this bug:
    http://goto.ext.google.com/viewvc/chrome-internal?view=rev&revision=17978

------------------------------------------------------------------------
r17978 | jnd@google.com | 2011-09-20T01:43:21.851874Z

------------------------------------------------------------------------
Nov 14, 2012
#32 bugdroid1@chromium.org
The following revision refers to this bug:
    http://goto.ext.google.com/viewvc/chrome-internal?view=rev&revision=18124

------------------------------------------------------------------------
r18124 | jnd@google.com | 2011-09-26T10:28:49.916975Z

------------------------------------------------------------------------
Mar 10, 2013
#33 bugdroid1@chromium.org
(No comment was entered for this change.)
Labels: -Area-Undefined -Tests-Disabled Cr-Tests-Disabled
Sign in to add a comment

Powered by Google Project Hosting