Intermittent testAddSearchEngine | The number of search results has increased - got 4, expected 5

RESOLVED FIXED

Status

()

defect
RESOLVED FIXED
6 years ago
6 years ago

People

(Reporter: RyanVM, Unassigned)

Tracking

({intermittent-failure})

22 Branch
ARM
Android
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(Not tracked)

Details

Attachments

(1 attachment)

+++ This bug was initially created as a clone of Bug #869277 +++

Redux.

https://tbpl.mozilla.org/php/getParsedLog.php?id=22825279&tree=Mozilla-Inbound

Android 4.0 Panda mozilla-inbound opt test robocop-2 on 2013-05-10 09:48:21 PDT for push d72307b5972b
slave: panda-0587

0 INFO SimpleTest START
1 INFO TEST-START | testAddSearchEngine
EventExpecter: no longer listening for Gecko:Ready
2 INFO TEST-PASS | testAddSearchEngine | Awesomebar URL typed properly - http://mochi.test:8888/tests/robocop/robocop_blank_01.html should equal http://mochi.test:8888/tests/robocop/robocop_blank_01.html
EventExpecter: no longer listening for DOMContentLoaded
3 INFO TEST-PASS | testAddSearchEngine | Search engine number could be determined correctly - 4 should not equal -1
4 INFO TEST-PASS | testAddSearchEngine | Awesomebar URL typed properly - http://mochi.test:8888/tests/robocop/robocop_search.html should equal http://mochi.test:8888/tests/robocop/robocop_search.html
EventExpecter: no longer listening for DOMContentLoaded
Long Clicking at width = 20 and height = 66
5 INFO TEST-PASS | testAddSearchEngine | Waiting for the context menu to be opened - The context menu was opened
6 INFO TEST-PASS | testAddSearchEngine | Adding the search engine - The add serach engine pop-up has been cloesed
7 INFO TEST-PASS | testAddSearchEngine | Search engine number could be determined correctly - 4 should not equal -1
8 INFO TEST-UNEXPECTED-FAIL | testAddSearchEngine | The number of search results has increased - got 4, expected 5
Exception caught during test!
junit.framework.AssertionFailedError: 8 INFO TEST-UNEXPECTED-FAIL | testAddSearchEngine | The number of search results has increased - got 4, expected 5
	at junit.framework.Assert.fail(Assert.java:47)
	at org.mozilla.fennec.FennecMochitestAssert._logMochitestResult(FennecMochitestAssert.java:107)
	at org.mozilla.fennec.FennecMochitestAssert.ok(FennecMochitestAssert.java:136)
	at org.mozilla.fennec.FennecMochitestAssert.is(FennecMochitestAssert.java:142)
	at org.mozilla.fennec.tests.testAddSearchEngine.testAddSearchEngine(testAddSearchEngine.java:64)
	at java.lang.reflect.Method.invokeNative(Native Method)
	at java.lang.reflect.Method.invoke(Method.java:511)
	at android.test.InstrumentationTestCase.runMethod(InstrumentationTestCase.java:214)
	at android.test.InstrumentationTestCase.runTest(InstrumentationTestCase.java:199)
	at android.test.ActivityInstrumentationTestCase2.runTest(ActivityInstrumentationTestCase2.java:192)
	at org.mozilla.fennec.tests.BaseTest.runTest(BaseTest.java:129)
	at junit.framework.TestCase.runBare(TestCase.java:127)
	at junit.framework.TestResult$1.protect(TestResult.java:106)
	at junit.framework.TestResult.runProtected(TestResult.java:124)
	at junit.framework.TestResult.run(TestResult.java:109)
	at junit.framework.TestCase.run(TestCase.java:118)
	at android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:169)
	at android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:154)
	at android.test.InstrumentationTestRunner.onStart(InstrumentationTestRunner.java:545)
	at android.app.Instrumentation$InstrumentationThread.run(Instrumentation.java:1551)
9 INFO TEST-UNEXPECTED-FAIL | testAddSearchEngine | Exception caught - junit.framework.AssertionFailedError: 8 INFO TEST-UNEXPECTED-FAIL | testAddSearchEngine | The number of search results has increased - got 4, expected 5
10 INFO TEST-END | testAddSearchEngine | finished in 74744ms
11 INFO TEST-START | Shutdown
12 INFO Passed: 6
13 INFO Failed: 2
14 INFO Todo: 0
15 INFO SimpleTest FINISHED
Posted file logs
Logs when this is happening show an actual error when the search engine is supposed to be added. This may actually be a bug in the product.

Logs:
05-14 11:36:07.681 I/Robocop (12209): 5 INFO TEST-PASS | testAddSearchEngine | Waiting for the context menu to be opened - The context menu was opened
05-14 11:36:09.025 V/tiny_hw ( 2947): out_write(0xbaf0c8) opening PCM
05-14 11:36:09.048 W/InputManagerService( 3018): Window already focused, ignoring focus gain of: com.android.internal.view.IInputMethodClient$Stub$Proxy@4129d410
05-14 11:36:10.150 I/Gecko   (12209): leaving void mozilla::AndroidBridge::HandleGeckoMessage(const nsAString_internal&, nsAString_internal&)
05-14 11:36:10.353 I/Gecko   (12209): void mozilla::AndroidBridge::HandleGeckoMessage(const nsAString_internal&, nsAString_internal&)
05-14 11:36:10.408 D/dalvikvm( 3163): GC_EXPLICIT freed 684K, 10% free 8909K/9799K, paused 1ms+4ms
05-14 11:36:10.423 E/BinaryDictionaryGetter( 3163): Could not find a dictionary pack
05-14 11:36:10.423 E/ActivityThread( 3163): Failed to find provider info for com.android.inputmethod.latin.dictionarypack
05-14 11:36:10.650 E/libEGL  (12209): eglMakeCurrent:651 error 3009 (EGL_BAD_MATCH)
05-14 11:36:10.650 I/Gecko   (12209): WARNING: Failed to make GL context current!: file /home/adriantamas/mc/gfx/gl/GLContextProviderEGL.cpp, line 521
05-14 11:36:10.650 I/Gecko   (12209): EGL Error: 0x3009
05-14 11:36:10.705 D/GeckoLayerClient(12209): Window-size changed to (1280,236)
05-14 11:36:10.705 I/Gecko   (12209): nsWindow[0x62a69000]::Resize [0.000000 0.000000 1280.000000 236.000000] (repaint 0)
05-14 11:36:10.705 I/Gecko   (12209): nsWindow: 0x62a69000 OnSizeChanged [1280 236]
05-14 11:36:10.705 I/Gecko   (12209): nsWindow[0x6341a000]::Resize [0.000000 0.000000 1280.000000 236.000000] (repaint 0)
05-14 11:36:10.705 I/Gecko   (12209): nsWindow: 0x6341a000 OnSizeChanged [1280 236]
05-14 11:36:11.119 E/libEGL  (12209): eglMakeCurrent:696 error 3009 (EGL_BAD_MATCH)
05-14 11:36:11.119 I/Gecko   (12209): WARNING: Failed to make GL context current!: file /home/adriantamas/mc/gfx/gl/GLContextProviderEGL.cpp, line 521
05-14 11:36:11.119 I/Gecko   (12209): EGL Error: 0x3009
05-14 11:36:11.173 D/GeckoLayerClient(12209): Window-size changed to (1280,616)
05-14 11:36:11.173 I/Gecko   (12209): nsWindow[0x62a69000]::Resize [0.000000 0.000000 1280.000000 616.000000] (repaint 0)
05-14 11:36:11.173 I/Gecko   (12209): nsWindow: 0x62a69000 OnSizeChanged [1280 616]
05-14 11:36:11.173 I/Gecko   (12209): nsWindow[0x6341a000]::Resize [0.000000 0.000000 1280.000000 616.000000] (repaint 0)
05-14 11:36:11.181 I/Gecko   (12209): nsWindow: 0x6341a000 OnSizeChanged [1280 616]
05-14 11:36:12.040 V/tiny_hw ( 2947): out_standby(0xbaf0c8) closing PCM
05-14 11:36:13.072 V/tiny_hw ( 2947): out_write(0xbaf0c8) opening PCM
05-14 11:36:13.072 I/Gecko   (12209): leaving void mozilla::AndroidBridge::HandleGeckoMessage(const nsAString_internal&, nsAString_internal&)
05-14 11:36:13.205 I/Gecko   (12209): WARNING: The SQL statement 'SELECT favicon FROM history_with_favicons WHERE url = ?' could not be compiled due to an error: no such table: history_with_favicons: file /home/adriantamas/mc/storage/src/mozStorageConnection.cpp, line 868
05-14 11:36:13.205 I/Gecko   (12209): WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005: file /home/adriantamas/mc/storage/src/mozStorageConnection.cpp, line 1154
05-14 11:36:13.220 E/GeckoConsole(12209): [JavaScript Error: "NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [mozIStorageConnection.createStatement]" {file: "chrome://browser/content/browser.js" line: 6045}]
05-14 11:36:14.283 D/dalvikvm(12209): GC_CONCURRENT freed 666K, 13% free 8413K/9607K, paused 0ms+8ms
05-14 11:36:16.103 V/tiny_hw ( 2947): out_standby(0xbaf0c8) closing PCM
05-14 11:36:18.751 I/Robocop (12209): 6 INFO TEST-PASS | testAddSearchEngine | Adding the search engine - The add serach engine pop-up has been cloesed
05-14 11:36:18.751 D/Robocop (12209): waiting for SearchEngines:Data
05-14 11:36:18.751 I/ActivityManager( 3018): START {flg=0x40000000 cmp=org.mozilla.fennec_root/org.mozilla.gecko.AwesomeBar (has extras)} from pid 12209
[.....]
05-14 11:36:36.642 I/Robocop (12209): 8 INFO TEST-UNEXPECTED-FAIL | testAddSearchEngine | The number of search results has increased - got 4, expected 5
05-14 11:36:36.642 I/Robocop (12209): 7 INFO TEST-PASS | testAddSearchEngine | Search engine number could be determined correctly - 4 should not equal -1
05-14 11:36:36.689 D/dalvikvm(12209): GC_FOR_ALLOC freed 617K, 13% free 8428K/9607K, paused 43ms
05-14 11:36:36.697 I/dalvikvm-heap(12209): Grow heap (frag case) to 11.580MB for 3440656-byte allocation
05-14 11:36:36.736 D/dalvikvm(12209): GC_FOR_ALLOC freed 51K, 10% free 11737K/12999K, paused 37ms
05-14 11:36:36.767 I/Robocop (12209): Exception caught during test!
05-14 11:36:36.767 I/Robocop (12209): junit.framework.AssertionFailedError: 8 INFO TEST-UNEXPECTED-FAIL | testAddSearchEngine | The number of search results has increased - got 4, expected 5
05-14 11:36:36.767 I/Robocop (12209): 	at junit.framework.Assert.fail(Assert.java:47)
05-14 11:36:36.767 I/Robocop (12209): 	at org.mozilla.fennec_root.FennecMochitestAssert._logMochitestResult(FennecMochitestAssert.java:107)
05-14 11:36:36.767 I/Robocop (12209): 	at org.mozilla.fennec_root.FennecMochitestAssert.ok(FennecMochitestAssert.java:136)
05-14 11:36:36.767 I/Robocop (12209): 	at org.mozilla.fennec_root.FennecMochitestAssert.is(FennecMochitestAssert.java:142)
05-14 11:36:36.767 I/Robocop (12209): 	at org.mozilla.fennec_root.tests.testAddSearchEngine.testAddSearchEngine(testAddSearchEngine.java:64)
05-14 11:36:36.767 I/Robocop (12209): 	at java.lang.reflect.Method.invokeNative(Native Method)
05-14 11:36:36.767 I/Robocop (12209): 	at java.lang.reflect.Method.invoke(Method.java:511)
05-14 11:36:36.767 I/Robocop (12209): 	at android.test.InstrumentationTestCase.runMethod(InstrumentationTestCase.java:214)
05-14 11:36:36.767 I/Robocop (12209): 	at android.test.InstrumentationTestCase.runTest(InstrumentationTestCase.java:199)
05-14 11:36:36.767 I/Robocop (12209): 	at android.test.ActivityInstrumentationTestCase2.runTest(ActivityInstrumentationTestCase2.java:192)
05-14 11:36:36.767 I/Robocop (12209): 	at org.mozilla.fennec_root.tests.BaseTest.runTest(BaseTest.java:129)
05-14 11:36:36.767 I/Robocop (12209): 	at junit.framework.TestCase.runBare(TestCase.java:127)
05-14 11:36:36.767 I/Robocop (12209): 	at junit.framework.TestResult$1.protect(TestResult.java:106)
05-14 11:36:36.767 I/Robocop (12209): 	at junit.framework.TestResult.runProtected(TestResult.java:124)
05-14 11:36:36.767 I/Robocop (12209): 	at junit.framework.TestResult.run(TestResult.java:109)
05-14 11:36:36.767 I/Robocop (12209): 	at junit.framework.TestCase.run(TestCase.java:118)
05-14 11:36:36.767 I/Robocop (12209): 	at android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:169)
05-14 11:36:36.767 I/Robocop (12209): 	at android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:154)
05-14 11:36:36.767 I/Robocop (12209): 	at android.test.InstrumentationTestRunner.onStart(InstrumentationTestRunner.java:545)
05-14 11:36:36.767 I/Robocop (12209): 	at android.app.Instrumentation$InstrumentationThread.run(Instrumentation.java:1551)
05-14 11:36:36.767 I/Robocop (12209): 9 INFO TEST-UNEXPECTED-FAIL | testAddSearchEngine | Exception caught - junit.framework.AssertionFailedError: 8 INFO TEST-UNEXPECTED-FAIL | testAddSearchEngine | The number of search results has increased - got 4, expected 5
05-14 11:36:36.783 I/Robocop (12209): 10 INFO TEST-END | testAddSearchEngine | finished in 88681ms
05-14 11:36:36.783 I/Robocop (12209): 11 INFO TEST-START | Shutdown
05-14 11:36:36.783 I/Robocop (12209): 12 INFO Passed: 6
05-14 11:36:36.783 I/Robocop (12209): 13 INFO Failed: 2
05-14 11:36:36.783 I/Robocop (12209): 14 INFO Todo: 0


This is the error when Firefox ties to create the search engine using the addEngine function in /mobile/andoid/chrome/content/Browser.js:6045

05-14 11:36:13.205 I/Gecko   (12209): WARNING: The SQL statement 'SELECT favicon FROM history_with_favicons WHERE url = ?' could not be compiled due to an error: no such table: history_with_favicons: file /home/adriantamas/mc/storage/src/mozStorageConnection.cpp, line 868
05-14 11:36:13.205 I/Gecko   (12209): WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005: file /home/adriantamas/mc/storage/src/mozStorageConnection.cpp, line 1154
05-14 11:36:13.220 E/GeckoConsole(12209): [JavaScript Error: "NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [mozIStorageConnection.createStatement]" {file: "chrome://browser/content/browser.js" line: 6045}]
CC'ing brian for the error in comment 2; blame shows that he added the SQL statement to browser.js a while ago. No idea why it's failing now.
(In reply to Kartikaya Gupta (email:kats@mozilla.com) from comment #14)
> CC'ing brian for the error in comment 2; blame shows that he added the SQL
> statement to browser.js a while ago. No idea why it's failing now.

I followed-up with bnicholson today on irc; he does not know why it is failing but speculated, maybe there is a race with the db table creation? I sprinkled the test with long sleeps in a try run -- no improvement.
Depends on: 880599
Should be fixed by bug 880599.
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → FIXED
You need to log in before you can comment on or make changes to this bug.