Closed Bug 856129 Opened 12 years ago Closed 12 years ago

Intermittent testNewTab | Exception caught - java.lang.NumberFormatException: unable to parse 'null' as integer

Categories

(Firefox for Android Graveyard :: General, defect)

Product:
Firefox for Android Graveyard
Component:
General
Platform:
x86_64
Android
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

(firefox24 fixed, firefox25 fixed)

Status:
RESOLVED FIXED
Milestone:
Firefox 25
Tracking Flags:
Tracking Status
firefox24 --- fixed
firefox25 --- fixed

People

(Reporter: RyanVM, Assigned: gbrown)

References

Details

(Keywords: intermittent-failure)

Attachments

(1 file, 1 obsolete file)

increase wait for RobocopUtils.runOnUIThreadSync
981 bytes, patch
cpeterson
: review+
Details | Diff | Splinter Review
https://tbpl.mozilla.org/php/getParsedLog.php?id=21250364&tree=Mozilla-Inbound Android Tegra 250 mozilla-inbound opt test robocop-1 on 2013-03-29 09:15:07 PDT for push 952a136276e9 slave: tegra-082 0 INFO SimpleTest START 1 INFO TEST-START | testNewTab 2 INFO TEST-PASS | testNewTab | Checking elements - all elements present 3 INFO TEST-PASS | testNewTab | Initial number of tabs correct - 1 should equal 1 4 INFO TEST-PASS | testNewTab | checking that tabs clicked - tabs element clicked 5 INFO TEST-PASS | testNewTab | waiting for add tab view - add tab view available 6 INFO TEST-PASS | testNewTab | checking that add_tab clicked - add_tab element clicked 7 INFO TEST-PASS | testNewTab | Number of tabs increased - 2 should equal 2 8 INFO TEST-PASS | testNewTab | checking that tabs clicked - tabs element clicked 9 INFO TEST-PASS | testNewTab | waiting for add tab view - add tab view available 10 INFO TEST-PASS | testNewTab | checking that add_tab clicked - add_tab element clicked time-out waiting for UI thread Dumping ALL the threads! Thread[Binder Thread #3,5,main] dalvik.system.NativeStart.run(Native Method) Thread[Binder Thread #2,5,main] dalvik.system.NativeStart.run(Native Method) Thread[Timer-0,5,main] java.lang.Object.wait(Native Method) java.lang.Object.wait(Object.java:326) java.util.Timer$TimerImpl.run(Timer.java:243) Thread[AsyncTask #2,5,main] java.lang.Object.wait(Native Method) java.lang.Thread.parkFor(Thread.java:1535) java.lang.LangAccessImpl.parkFor(LangAccessImpl.java:48) sun.misc.Unsafe.park(Unsafe.java:317) java.util.concurrent.locks.LockSupport.park(LockSupport.java:131) java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1996) java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:359) java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1001) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1061) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:561) java.lang.Thread.run(Thread.java:1096) Thread[AsyncTask #5,5,main] java.lang.Object.wait(Native Method) java.lang.Thread.parkFor(Thread.java:1535) java.lang.LangAccessImpl.parkFor(LangAccessImpl.java:48) sun.misc.Unsafe.park(Unsafe.java:317) java.util.concurrent.locks.LockSupport.park(LockSupport.java:131) java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1996) java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:359) java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1001) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1061) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:561) java.lang.Thread.run(Thread.java:1096) Thread[Compiler,5,system] dalvik.system.NativeStart.run(Native Method) Thread[Signal Catcher,5,system] dalvik.system.NativeStart.run(Native Method) Thread[HeapWorker,5,system] java.lang.Object.wait(Native Method) java.lang.Thread.parkFor(Thread.java:1535) java.lang.LangAccessImpl.parkFor(LangAccessImpl.java:48) sun.misc.Unsafe.park(Unsafe.java:317) java.util.concurrent.locks.LockSupport.park(LockSupport.java:131) java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:790) java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:823) java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1153) java.util.concurrent.locks.ReentrantLock$FairSync.lock(ReentrantLock.java:200) java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:261) android.database.sqlite.SQLiteDatabase.lock(SQLiteDatabase.java:375) android.database.sqlite.SQLiteProgram.close(SQLiteProgram.java:291) android.database.sqlite.SQLiteQuery.close(SQLiteQuery.java:133) android.database.sqlite.SQLiteCursor.close(SQLiteCursor.java:502) android.database.sqlite.SQLiteCursor.finalize(SQLiteCursor.java:587) dalvik.system.NativeStart.run(Native Method) Thread[Filter,5,main] java.lang.Object.wait(Native Method) java.lang.Thread.parkFor(Thread.java:1535) java.lang.LangAccessImpl.parkFor(LangAccessImpl.java:48) sun.misc.Unsafe.park(Unsafe.java:317) java.util.concurrent.locks.LockSupport.park(LockSupport.java:131) java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:790) java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:823) java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1153) java.util.concurrent.locks.ReentrantLock$FairSync.lock(ReentrantLock.java:200) java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:261) android.database.sqlite.SQLiteDatabase.lock(SQLiteDatabase.java:375) android.database.sqlite.SQLiteDatabase.addSQLiteClosable(SQLiteDatabase.java:297) android.database.sqlite.SQLiteProgram.<init>(SQLiteProgram.java:62) android.database.sqlite.SQLiteQuery.<init>(SQLiteQuery.java:46) android.database.sqlite.SQLiteDirectCursorDriver.query(SQLiteDirectCursorDriver.java:42) android.database.sqlite.SQLiteDatabase.rawQueryWithFactory(SQLiteDatabase.java:1345) android.database.sqlite.SQLiteQueryBuilder.query(SQLiteQueryBuilder.java:330) org.mozilla.fennec.db.BrowserProvider.query(BrowserProvider.java:2639) android.content.ContentProvider$Transport.query(ContentProvider.java:163) android.content.ContentResolver.query(ContentResolver.java:245) org.mozilla.gecko.db.LocalBrowserDB.filterAllSites(LocalBrowserDB.java:177) org.mozilla.gecko.db.LocalBrowserDB.filterAllSites(LocalBrowserDB.java:145) org.mozilla.gecko.db.LocalBrowserDB.filter(LocalBrowserDB.java:224) org.mozilla.gecko.db.BrowserDB.filter(BrowserDB.java:131) org.mozilla.gecko.AllPagesTab$4.runQuery(AllPagesTab.java:222) android.widget.CursorAdapter.runQueryOnBackgroundThread(CursorAdapter.java:309) android.widget.CursorFilter.performFiltering(CursorFilter.java:49) android.widget.Filter$RequestHandler.handleMessage(Filter.java:234) android.os.Handler.dispatchMessage(Handler.java:99) android.os.Looper.loop(Looper.java:123) android.os.HandlerThread.run(HandlerThread.java:60) Thread[Instr: org.mozilla.fennec.FennecInstrumentationTestRunner,5,main] dalvik.system.VMStack.getThreadStackTrace(Native Method) java.lang.Thread.getStackTrace(Thread.java:788) java.lang.Thread.getAllStackTraces(Thread.java:669) org.mozilla.fennec.FennecNativeDriver.logAllStackTraces(FennecNativeDriver.java:411) org.mozilla.fennec.RobocopUtils.runOnUiThreadSync(RobocopUtils.java:37) org.mozilla.fennec.FennecNativeElement.getText(FennecNativeElement.java:68) org.mozilla.fennec.tests.testNewTab.testNewTab(testNewTab.java:49) java.lang.reflect.Method.invokeNative(Native Method) java.lang.reflect.Method.invoke(Method.java:521) android.test.InstrumentationTestCase.runMethod(InstrumentationTestCase.java:204) android.test.InstrumentationTestCase.runTest(InstrumentationTestCase.java:194) android.test.ActivityInstrumentationTestCase2.runTest(ActivityInstrumentationTestCase2.java:186) org.mozilla.fennec.tests.BaseTest.runTest(BaseTest.java:125) junit.framework.TestCase.runBare(TestCase.java:127) junit.framework.TestResult$1.protect(TestResult.java:106) junit.framework.TestResult.runProtected(TestResult.java:124) junit.framework.TestResult.run(TestResult.java:109) junit.framework.TestCase.run(TestCase.java:118) android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:169) android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:154) android.test.InstrumentationTestRunner.onStart(InstrumentationTestRunner.java:520) android.app.Instrumentation$InstrumentationThread.run(Instrumentation.java:1447) Thread[Thread-17,5,main] dalvik.system.NativeStart.run(Native Method) Thread[AsyncTask #1,5,main] java.lang.Object.wait(Native Method) java.lang.Thread.parkFor(Thread.java:1535) java.lang.LangAccessImpl.parkFor(LangAccessImpl.java:48) sun.misc.Unsafe.park(Unsafe.java:317) java.util.concurrent.locks.LockSupport.park(LockSupport.java:131) java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1996) java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:359) java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1001) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1061) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:561) java.lang.Thread.run(Thread.java:1096) Thread[AsyncTask #3,5,main] java.lang.Object.wait(Native Method) java.lang.Thread.parkFor(Thread.java:1535) java.lang.LangAccessImpl.parkFor(LangAccessImpl.java:48) sun.misc.Unsafe.park(Unsafe.java:317) java.util.concurrent.locks.LockSupport.park(LockSupport.java:131) java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:790) java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:823) java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1153) java.util.concurrent.locks.ReentrantLock$FairSync.lock(ReentrantLock.java:200) java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:261) android.database.sqlite.SQLiteDatabase.lock(SQLiteDatabase.java:375) android.database.sqlite.SQLiteQuery.fillWindow(SQLiteQuery.java:61) android.database.sqlite.SQLiteCursor.fillWindow(SQLiteCursor.java:283) android.database.sqlite.SQLiteCursor.getCount(SQLiteCursor.java:264) android.content.ContentResolver.query(ContentResolver.java:251) org.mozilla.gecko.db.LocalBrowserDB.readingListItemsExist(LocalBrowserDB.java:459) org.mozilla.gecko.db.LocalBrowserDB.getBookmarksInFolder(LocalBrowserDB.java:386) org.mozilla.gecko.db.BrowserDB.getBookmarksInFolder(BrowserDB.java:185) org.mozilla.gecko.BookmarksTab$BookmarksQueryTask.doInBackground(BookmarksTab.java:368) org.mozilla.gecko.BookmarksTab$BookmarksQueryTask.doInBackground(BookmarksTab.java:355) android.os.AsyncTask$2.call(AsyncTask.java:185) java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:305) java.util.concurrent.FutureTask.run(FutureTask.java:137) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1068) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:561) java.lang.Thread.run(Thread.java:1096) Thread[GeckoBackgroundThread,5,main] android.database.sqlite.SQLiteStatement.native_execute(Native Method) android.database.sqlite.SQLiteStatement.execute(SQLiteStatement.java:55) android.database.sqlite.SQLiteDatabase.updateWithOnConflict(SQLiteDatabase.java:1692) android.database.sqlite.SQLiteDatabase.update(SQLiteDatabase.java:1622) org.mozilla.fennec.db.BrowserProvider.updateHistory(BrowserProvider.java:2927) org.mozilla.fennec.db.BrowserProvider.updateInTransaction(BrowserProvider.java:2353) org.mozilla.fennec.db.BrowserProvider.update(BrowserProvider.java:2286) android.content.ContentProvider$Transport.update(ContentProvider.java:204) android.content.ContentResolver.update(ContentResolver.java:707) org.mozilla.gecko.db.LocalBrowserDB.updateHistoryTitle(LocalBrowserDB.java:275) org.mozilla.gecko.db.BrowserDB.updateHistoryTitle(BrowserDB.java:147) org.mozilla.gecko.GlobalHistory.update(GlobalHistory.java:131) org.mozilla.gecko.GeckoAppShell$16.run(GeckoAppShell.java:1881) android.os.Handler.handleCallback(Handler.java:587) android.os.Handler.dispatchMessage(Handler.java:92) android.os.Looper.loop(Looper.java:123) org.mozilla.gecko.util.GeckoBackgroundThread.run(GeckoBackgroundThread.java:32) Thread[JDWP,5,system] dalvik.system.NativeStart.run(Native Method) Thread[AsyncTask #4,5,main] java.lang.Object.wait(Native Method) java.lang.Thread.parkFor(Thread.java:1535) java.lang.LangAccessImpl.parkFor(LangAccessImpl.java:48) sun.misc.Unsafe.park(Unsafe.java:317) java.util.concurrent.locks.LockSupport.park(LockSupport.java:131) java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1996) java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:359) java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1001) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1061) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:561) java.lang.Thread.run(Thread.java:1096) Thread[main,5,main] java.lang.Object.wait(Native Method) java.lang.Thread.parkFor(Thread.java:1535) java.lang.LangAccessImpl.parkFor(LangAccessImpl.java:48) sun.misc.Unsafe.park(Unsafe.java:317) java.util.concurrent.locks.LockSupport.park(LockSupport.java:131) java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:790) java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:823) java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1153) java.util.concurrent.locks.ReentrantLock$FairSync.lock(ReentrantLock.java:200) java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:261) android.database.sqlite.SQLiteDatabase.lock(SQLiteDatabase.java:375) android.database.sqlite.SQLiteProgram.close(SQLiteProgram.java:291) android.database.sqlite.SQLiteQuery.close(SQLiteQuery.java:133) android.database.sqlite.SQLiteCursor.close(SQLiteCursor.java:502) android.database.CursorWrapper.close(CursorWrapper.java:45) android.content.ContentResolver$CursorWrapperInner.close(ContentResolver.java:1355) android.database.CursorWrapper.close(CursorWrapper.java:45) org.mozilla.gecko.AllPagesTab.destroy(AllPagesTab.java:158) org.mozilla.gecko.AwesomeBarTabs.destroy(AwesomeBarTabs.java:299) org.mozilla.gecko.AwesomeBar.onDestroy(AwesomeBar.java:488) android.app.ActivityThread.performDestroyActivity(ActivityThread.java:3642) android.app.ActivityThread.handleDestroyActivity(ActivityThread.java:3673) android.app.ActivityThread.access$2900(ActivityThread.java:125) android.app.ActivityThread$H.handleMessage(ActivityThread.java:2066) android.os.Handler.dispatchMessage(Handler.java:99) android.os.Looper.loop(Looper.java:123) android.app.ActivityThread.main(ActivityThread.java:4627) java.lang.reflect.Method.invokeNative(Native Method) java.lang.reflect.Method.invoke(Method.java:521) com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:868) com.android.internal.os.ZygoteInit.main(ZygoteInit.java:626) dalvik.system.NativeStart.main(Native Method) Thread[Binder Thread #1,5,main] dalvik.system.NativeStart.run(Native Method) Thread[GeckoANRReporter,5,main] java.lang.Object.wait(Native Method) java.lang.Object.wait(Object.java:288) android.os.MessageQueue.next(MessageQueue.java:146) android.os.Looper.loop(Looper.java:110) org.mozilla.gecko.ANRReporter$1.run(ANRReporter.java:102) java.lang.Thread.run(Thread.java:1096) Thread[Gecko,5,main] org.mozilla.gecko.mozglue.GeckoLoader.nativeRun(Native Method) org.mozilla.gecko.GeckoAppShell.runGecko(GeckoAppShell.java:290) org.mozilla.gecko.GeckoThread.run(GeckoThread.java:104) Thread[RefQueueWorker@org.apache.http.impl.conn.tsccm.ConnPoolByRoute@485ecd80,5,main] java.lang.Object.wait(Native Method) java.lang.Object.wait(Object.java:326) java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:107) java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:80) org.apache.http.impl.conn.tsccm.RefQueueWorker.run(RefQueueWorker.java:102) java.lang.Thread.run(Thread.java:1096) getText: Text is null for view 2131165249 Exception caught during test! java.lang.NumberFormatException: unable to parse 'null' as integer at java.lang.Integer.parseInt(Integer.java:406) at java.lang.Integer.parseInt(Integer.java:382) at org.mozilla.fennec.tests.testNewTab.testNewTab(testNewTab.java:50) at java.lang.reflect.Method.invokeNative(Native Method) at java.lang.reflect.Method.invoke(Method.java:521) at android.test.InstrumentationTestCase.runMethod(InstrumentationTestCase.java:204) at android.test.InstrumentationTestCase.runTest(InstrumentationTestCase.java:194) at android.test.ActivityInstrumentationTestCase2.runTest(ActivityInstrumentationTestCase2.java:186) at org.mozilla.fennec.tests.BaseTest.runTest(BaseTest.java:125) 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:520) at android.app.Instrumentation$InstrumentationThread.run(Instrumentation.java:1447) 11 INFO TEST-UNEXPECTED-FAIL | testNewTab | Exception caught - java.lang.NumberFormatException: unable to parse 'null' as integer 12 INFO TEST-END | testNewTab | finished in 43915ms 13 INFO TEST-START | Shutdown 14 INFO Passed: 9 15 INFO Failed: 1 16 INFO Todo: 0 17 INFO SimpleTest FINISHED
Is this a test race condition where addTab() thinks the DOMContentLoaded has been fired, but the tabs_count UI element has not been updated yet? Also, if I enable Android's "Don't keep activities" developer option, I see that testNewTab's `activity` variable is onDestroyed() after each addTab() call. Could this be a contributing problem?
Notice that BrowserProvider.updateHistory is doing sql work in a background thread in most of the recent traces. Several also have DB access on the main thread -- bug 856621 probably -- but not all. For example, Comment 26. The test failure is a result of the time-out waiting for the UI thread which is "only" 3000 ms. I wonder if increasing the timeout in RobocopUtils.runOnUiThreadSync would resolve some of these failures (maybe our responsiveness expectation is not reasonable when considered over thousands of test runs).
As expressed in Comment 26, I wonder if some of these intermittent failures can be avoided with a longer timeout, and if our current responsiveness expectations are unreasonable, given aging test devices and the inevitability of timing variation over thousands of test runs.
Assignee: nobody → gbrown
Attachment #774734 - Flags: review?(cpeterson)
Sorry - wrong attachment. Corrected now.
Attachment #774734 - Attachment is obsolete: true
Attachment #774734 - Flags: review?(cpeterson)
Attachment #774740 - Flags: review?(cpeterson)
Comment on attachment 774740 [details] [diff] [review] increase wait for RobocopUtils.runOnUIThreadSync Review of attachment 774740 [details] [diff] [review]: ----------------------------------------------------------------- LGTM. Alternately, you might also consider swapping the order in which textNewTab.java.in loads robocop_blank_01.html and robocop_blank_02.html. I wouldn't expect that to fix the test, but it might give us data about whether the test failure is related to the file robocop_blank_02.html or just whichever file is loaded second. Curiously, robocop_blank_02.html is "less blank" than robocop_blank_01.html because it includes an embedded data:image favicon. Maybe the data:image decode time is causing problems or delays.
Attachment #774740 - Flags: review?(cpeterson) → review+
Great observations Chris - thanks. I will just try this for now, but follow-up on your idea if / when this bug is re-opened. https://hg.mozilla.org/integration/mozilla-inbound/rev/50434a448009
https://hg.mozilla.org/mozilla-central/rev/50434a448009
Status: NEW → RESOLVED
Closed: 12 years ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 25
Product: Firefox for Android → Firefox for Android Graveyard
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: