1117230 - Updater runs during tests

Status: RESOLVED FIXED

(Firefox for Android Graveyard :: Testing, defect)

Description

[Richard Newman [:rnewman]]

01-02 13:11:52.051 D/GeckoToolbar(  505): onTabChanged: THUMBNAIL
01-02 13:11:52.051 D/GeckoBrowserApp(  505): BrowserApp.onTabChanged: 0: THUMBNAIL
01-02 13:11:52.746 I/UpdateService(  561): opening connection with url: https://aus4.mozilla.org/update/4/Fennec/37.0a1/20150102093802/Android_arm-eabi-gcc3/en-US/default/2.3.7/default/default/37.0a1/update.xml
01-02 13:11:52.831 D/GeckoToolbar(  505): onTabChanged: FAVICON
01-02 13:11:52.831 D/GeckoToolbarDisplayLayout(  505): Ignoring favicon: new image is identical to previous one.
01-02 13:11:52.852 D/GeckoBrowserApp(  505): BrowserApp.onTabChanged: 0: FAVICON
01-02 13:11:57.202 I/Robocop (  505): {"action":"log","message":"Fail: suggestionGroup is null.","time":1420233117180,"pid":null,"level":"info","source":"robocop","thread":null}
01-02 13:11:57.771 I/Robocop (  505): {"action":"log","message":"Fail: suggestionGroup is null.","time":1420233117730,"pid":null,"level":"info","source":"robocop","thread":null}
01-02 13:11:57.786 D/dalvikvm(  505): GC_CONCURRENT freed 784K, 47% free 3923K/7303K, external 1520K/1813K, paused 17ms+128ms
01-02 13:11:58.301 I/Robocop (  505): {"action":"log","message":"Fail: suggestionGroup is null.","time":1420233118277,"pid":null,"level":"info","source":"robocop","thread":null}
01-02 13:11:58.821 I/Robocop (  505): {"action":"log","message":"Fail: suggestionGroup is null.","time":1420233118813,"pid":null,"level":"info","source":"robocop","thread":null}
01-02 13:11:59.361 I/Robocop (  505): {"action":"log","message":"Fail: suggestionGroup is null.","time":1420233119353,"pid":null,"level":"info","source":"robocop","thread":null}
01-02 13:11:59.922 I/Robocop (  505): {"action":"log","message":"Fail: suggestionGroup is null.","time":1420233119900,"pid":null,"level":"info","source":"robocop","thread":null}
01-02 13:12:00.461 I/Robocop (  505): {"action":"log","message":"Fail: suggestionGroup is null.","time":1420233120452,"pid":null,"level":"info","source":"robocop","thread":null}
01-02 13:12:00.991 I/Robocop (  505): {"action":"log","message":"Fail: suggestionGroup is null.","time":1420233120969,"pid":null,"level":"info","source":"robocop","thread":null}
01-02 13:12:01.511 I/Robocop (  505): {"action":"log","message":"Fail: suggestionGroup is null.","time":1420233121504,"pid":null,"level":"info","source":"robocop","thread":null}
01-02 13:12:02.055 I/Robocop (  505): {"action":"log","message":"Fail: suggestionGroup is null.","time":1420233122043,"pid":null,"level":"info","source":"robocop","thread":null}
01-02 13:12:02.094 I/Robocop (  505): {"action":"log","message":"waitForCondition timeout after 5000 ms.","time":1420233122075,"pid":null,"level":"info","source":"robocop","thread":null}
01-02 13:12:02.141 I/Robocop (  505): {"message":"got false, expected true","time":1420233122106,"expected":"PASS","source":"robocop","status":"FAIL","test":"testSearchSuggestions","thread":null,"subtest":"Results for query 'f' matched expected suggestions","action":"test_status","pid":null}
01-02 13:12:02.732 D/dalvikvm(  505): GC_EXTERNAL_ALLOC freed 255K, 47% free 3908K/7303K, external 1508K/1813K, paused 296ms
01-02 13:12:02.901 I/Robocop (  505): {"action":"log","message":"Exception caught during test! - junit.framework.AssertionFailedError: TEST-UNEXPECTED-FAIL | testSearchSuggestions | Results for query 'f' matched expected suggestions - got false, expected true\n\tat junit.framework.Assert.fail(Assert.java:47)\n\tat org.mozilla.gecko.FennecMochitestAssert._logMochitestResult(FennecMochitestAssert.java:128)\n\tat org.mozilla.gecko.FennecMochitestAssert.ok(FennecMochitestAssert.java:150)\n\tat org.mozilla.gecko.FennecMochitestAssert.is(FennecMochitestAssert.java:156)\n\tat org.mozilla.gecko.tests.testSearchSuggestions.testSearchSuggestions(testSearchSuggestions.java:87)\n\tat java.lang.reflect.Method.invokeNative(Native Method)\n\tat java.lang.reflect.Method.invoke(Method.java:507)\n\tat android.test.InstrumentationTestCase.runMethod(InstrumentationTestCase.java:204)\n\tat android.test.InstrumentationTestCase.runTest(InstrumentationTestCase.java:194)\n\tat android.test.ActivityInstrumentationTestCase2.runTest(ActivityInstrumentationTestCase2.java:186)\n\tat org.mozilla.gecko.tests.BaseTest.runTest(BaseTest.java:159)\n\tat junit.framework.TestCase.runBare(TestCase.java:127)\n\tat junit.framework.TestResult$1.protect(TestResult.java:106)\n\tat junit.framework.TestResult.runProtected(TestResult.java:124)\n\tat junit.framework.TestResult.run(TestResult.java:109)\n\tat junit.framework.TestCase.run(TestCase.java:118)\n\tat android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:169)\n\tat android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:154)\n\tat android.test.InstrumentationTestRunner.onStart(InstrumentationTestRunner.java:529)\n\tat android.app.Instrumentation$InstrumentationThread.run(Instrumentation.java:1448)\n","time":1420233122828,"pid":null,"level":"error","source":"robocop","thread":null}
01-02 13:12:02.941 I/Robocop (  505): {"message":"junit.framework.AssertionFailedError: TEST-UNEXPECTED-FAIL | testSearchSuggestions | Results for query 'f' matched expected suggestions - got false, expected true","time":1420233122908,"expected":"PASS","source":"robocop","status":"FAIL","test":"testSearchSuggestions","thread":null,"subtest":"Exception caught","action":"test_status","pid":null}
01-02 13:12:02.971 I/Robocop (  505): {"message":"finished in 69683ms","time":1420233122947,"source":"robocop","status":"OK","test":"testSearchSuggestions","thread":null,"action":"test_end","pid":null}
01-02 13:12:02.994 I/Robocop (  505): {"action":"log","message":"TEST-START | Shutdown","time":1420233122995,"pid":null,"level":"info","source":"robocop","thread":null}
01-02 13:12:03.022 I/Robocop (  505): {"action":"log","message":"Passed: 4","time":1420233123000,"pid":null,"level":"info","source":"robocop","thread":null}
01-02 13:12:03.054 I/Robocop (  505): {"action":"log","message":"Failed: 2","time":1420233123046,"pid":null,"level":"info","source":"robocop","thread":null}
01-02 13:12:03.094 I/Robocop (  505): {"action":"log","message":"Todo: 0","time":1420233123055,"pid":null,"level":"info","source":"robocop","thread":null}
01-02 13:12:03.114 I/Robocop (  505): {"action":"log","message":"SimpleTest FINISHED","time":1420233123097,"pid":null,"level":"info","source":"robocop","thread":null}
01-02 13:12:03.412 I/GeckoDump(  505): Robocop:Quit received -- requesting quit
01-02 13:12:03.471 D/SntpClient(   64): request time failed: java.net.SocketTimeoutException: Try again

Comment 1

[Richard Newman [:rnewman]]

My guess is that making the updater configurable will also make it easier for us to stub this out, so taking a dep on Bug 792992.

Comment 2

[Richard Newman [:rnewman]]

Attachment: Allow for tests to disable the updater. v1

That notwithstanding, here's a hack.

Comment 3

[Richard Newman [:rnewman]]

(Imagine that has a @RobocopTarget in there.)

Comment 4

[Richard Newman [:rnewman]]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=90a31bdea32e

Comment 5

[Richard Newman [:rnewman]]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=a1e956d5a80c

Comment 6

[Richard Newman [:rnewman]]

Attachment: Allow for tests to disable the updater. v2

Cleaned up. Try build for 2.3 (the only place this seems to be necessary right now):

https://treeherder.mozilla.org/ui/#/jobs?repo=try&revision=f021efb6c4aa

Comment 7

[Richard Newman [:rnewman]]

All green!

Comment 8

[Richard Newman [:rnewman]]

https://hg.mozilla.org/integration/fx-team/rev/1774dfe83245

Comment 9

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/1774dfe83245

Comment 10

[Michael Comella (:mcomella) [NI reported issues only: ex-Mozilla]]

Note: I wonder if this has had any effect on 2.3 builds running on the try emulator to take longer than they need to.

Comment 11

[Richard Newman [:rnewman]]

(In reply to Michael Comella (:mcomella) from comment #10)
> Note: I wonder if this has had any effect on 2.3 builds running on the try
> emulator to take longer than they need to.

The updater running can't help!

Note that this bug only addresses Robocop tests; I imagine that the updater is still active in our other test suites. I hope that esawin addresses that part in Bug 792992.