Permaorange (test) Halting on failure while running ['python2.7', 'mach', '--log-no-times', 'gradle', 'app:testAutomationDebugUnitTest']

RESOLVED FIXED in Firefox 51

Status

()

P1
normal
RESOLVED FIXED
2 years ago
2 years ago

People

(Reporter: intermittent-bug-filer, Assigned: Grisha)

Tracking

unspecified
Firefox 52
Points:
---
Dependency tree / graph
Bug Flags:
in-testsuite +

Firefox Tracking Flags

(fennec51+, firefox50 unaffected, firefox51 fixed, firefox52 fixed)

Details

(Whiteboard: [MobileAS])

Attachments

(1 attachment)

(Reporter)

Description

2 years ago
treeherder
Filed by: philringnalda [at] gmail.com

https://treeherder.mozilla.org/logviewer.html#?job_id=3454637&repo=autoland

https://queue.taskcluster.net/v1/task/EJ-VOFkOSqSo8VBjq7IK4Q/runs/0/artifacts/public%2Flogs%2Flive_backing.log

Apparently something on autoland didn't like something being merged to it.
Blocks: 1302602
Hidden on all trunk trees, in anticipation of that getting merged back around and spreading the burn everywhere else.
https://public-artifacts.taskcluster.net/EJ-VOFkOSqSo8VBjq7IK4Q/0/public/android/unittest/automationDebug/index.html

2 failures:
* BrowserProviderHistoryTest. testHistoryExpirationNormalOld
* BrowserProviderHistoryTest. testHistoryVisitAggregates
I see those failures locally too.

@grisha: Do you have time looking into why this is happening? Did we change anything regarding history?
Flags: needinfo?(gkruglov)
Priority: -- → P1
tracking-fennec: --- → ?
(Assignee)

Comment 4

2 years ago
(In reply to Sebastian Kaspari (:sebastian) from comment #3)
> I see those failures locally too.
> 
> @grisha: Do you have time looking into why this is happening? Did we change
> anything regarding history?

I don't believe anything changed. Seeing those failures locally as well. I'll investigate.
Comment hidden (mozreview-request)
(Assignee)

Updated

2 years ago
Whiteboard: [MobileAS]

Comment 8

2 years ago
mozreview-review
Comment on attachment 8794378 [details]
Bug 1302601 - Fix broken tests - poor method override

https://reviewboard.mozilla.org/r/80864/#review79524
Attachment #8794378 - Flags: review?(ahunt) → review+
(Assignee)

Updated

2 years ago
Assignee: nobody → gkruglov
Status: NEW → ASSIGNED

Comment 9

2 years ago
Pushed by gkruglov@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/b451b91d4b46
Fix broken tests - poor method override r=ahunt

Comment 10

2 years ago
bugherder
https://hg.mozilla.org/mozilla-central/rev/b451b91d4b46
Status: ASSIGNED → RESOLVED
Last Resolved: 2 years ago
status-firefox52: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → Firefox 52
status-firefox50: --- → unaffected
status-firefox51: --- → affected

Comment 11

2 years ago
bugherderuplift
https://hg.mozilla.org/releases/mozilla-aurora/rev/82908a457460
status-firefox51: affected → fixed
Flags: in-testsuite+
This is still failing on Trunk and Aurora.
https://treeherder.mozilla.org/#/jobs?repo=mozilla-central&filter-searchStr=tc(test)&exclusion_profile=false
Status: RESOLVED → REOPENED
status-firefox51: fixed → affected
status-firefox52: fixed → affected
Flags: needinfo?(gkruglov)
Resolution: FIXED → ---
Target Milestone: Firefox 52 → ---
(Assignee)

Comment 13

2 years ago
Test failures I'm seeing now are different, seem to now resolve around managing SQL connections.

testGetRecentHistoryVisitsForGUID

java.lang.RuntimeException: java.util.concurrent.ExecutionException: java.lang.IllegalStateException: Illegal connection pointer 1. Current pointers for thread Thread[pool-571-thread-1,5,main] []
	at org.robolectric.shadows.ShadowSQLiteConnection$Connections.execute(ShadowSQLiteConnection.java:469)
	at org.robolectric.shadows.ShadowSQLiteConnection$Connections.prepareStatement(ShadowSQLiteConnection.java:388)
	at org.robolectric.shadows.ShadowSQLiteConnection.nativePrepareStatement(ShadowSQLiteConnection.java:79)
	at android.database.sqlite.SQLiteConnection.nativePrepareStatement(SQLiteConnection.java)
	at android.database.sqlite.SQLiteConnection.acquirePreparedStatement(SQLiteConnection.java:889)
	at android.database.sqlite.SQLiteConnection.execute(SQLiteConnection.java:548)
	at android.database.sqlite.SQLiteSession.beginTransactionUnchecked(SQLiteSession.java:323)
	at android.database.sqlite.SQLiteSession.beginTransaction(SQLiteSession.java:298)
	at android.database.sqlite.SQLiteDatabase.beginTransaction(SQLiteDatabase.java:505)
	at android.database.sqlite.SQLiteDatabase.beginTransaction(SQLiteDatabase.java:416)
	at org.mozilla.gecko.db.AbstractTransactionalProvider.beginWrite(AbstractTransactionalProvider.java:121)
	at org.mozilla.gecko.db.BrowserProvider.insertHistory(BrowserProvider.java:1595)
	at org.mozilla.gecko.db.BrowserProvider.insertInTransaction(BrowserProvider.java:624)
	at org.mozilla.gecko.db.AbstractTransactionalProvider.insert(AbstractTransactionalProvider.java:210)
	at org.robolectric.shadows.ShadowContentProviderClient.insert(ShadowContentProviderClient.java:67)
	at android.content.ContentProviderClient.insert(ContentProviderClient.java)
	at org.mozilla.gecko.sync.repositories.android.VisitsHelperTest.testGetRecentHistoryVisitsForGUID(VisitsHelperTest.java:70)


Another failure of the same test, different stack trace:
testGetRecentHistoryVisitsForGUID

android.database.sqlite.SQLiteCantOpenDatabaseException: Cannot open SQLite connection
	at org.robolectric.shadows.ShadowSQLiteConnection$Connections.getSqliteException(ShadowSQLiteConnection.java:481)
	at org.robolectric.shadows.ShadowSQLiteConnection$Connections.execute(ShadowSQLiteConnection.java:464)
	at org.robolectric.shadows.ShadowSQLiteConnection$Connections.open(ShadowSQLiteConnection.java:365)
	at org.robolectric.shadows.ShadowSQLiteConnection.nativeOpen(ShadowSQLiteConnection.java:73)
	at android.database.sqlite.SQLiteConnection.nativeOpen(SQLiteConnection.java)
	at android.database.sqlite.SQLiteConnection.open(SQLiteConnection.java:209)
	at android.database.sqlite.SQLiteConnection.open(SQLiteConnection.java:193)
	at android.database.sqlite.SQLiteConnectionPool.openConnectionLocked(SQLiteConnectionPool.java:463)
	at android.database.sqlite.SQLiteConnectionPool.open(SQLiteConnectionPool.java:185)
	at android.database.sqlite.SQLiteConnectionPool.open(SQLiteConnectionPool.java:177)
	at android.database.sqlite.SQLiteDatabase.openInner(SQLiteDatabase.java:806)
	at android.database.sqlite.SQLiteDatabase.open(SQLiteDatabase.java:791)
	at android.database.sqlite.SQLiteDatabase.openDatabase(SQLiteDatabase.java:694)
	at android.app.ContextImpl.openOrCreateDatabase(ContextImpl.java:1142)
	at android.content.ContextWrapper.openOrCreateDatabase(ContextWrapper.java:267)
	at android.database.sqlite.SQLiteOpenHelper.getDatabaseLocked(SQLiteOpenHelper.java:223)
	at android.database.sqlite.SQLiteOpenHelper.getWritableDatabase(SQLiteOpenHelper.java:163)
	at org.mozilla.gecko.db.AbstractPerProfileDatabaseProvider.getWritableDatabase(AbstractPerProfileDatabaseProvider.java:61)
	at org.mozilla.gecko.db.AbstractTransactionalProvider.insert(AbstractTransactionalProvider.java:207)
	at org.robolectric.shadows.ShadowContentProviderClient.insert(ShadowContentProviderClient.java:67)
	at android.content.ContentProviderClient.insert(ContentProviderClient.java)
	at org.mozilla.gecko.sync.repositories.android.VisitsHelperTest.testGetRecentHistoryVisitsForGUID(VisitsHelperTest.java:70)


testDatabaseIsQueriesForNormalRequestsWithNetworkSkipped

android.database.sqlite.SQLiteCantOpenDatabaseException: Cannot open SQLite connection
	at org.robolectric.shadows.ShadowSQLiteConnection$Connections.getSqliteException(ShadowSQLiteConnection.java:481)
	at org.robolectric.shadows.ShadowSQLiteConnection$Connections.execute(ShadowSQLiteConnection.java:464)
	at org.robolectric.shadows.ShadowSQLiteConnection$Connections.open(ShadowSQLiteConnection.java:365)
	at org.robolectric.shadows.ShadowSQLiteConnection.nativeOpen(ShadowSQLiteConnection.java:73)
	at android.database.sqlite.SQLiteConnection.nativeOpen(SQLiteConnection.java)
	at android.database.sqlite.SQLiteConnection.open(SQLiteConnection.java:209)
	at android.database.sqlite.SQLiteConnection.open(SQLiteConnection.java:193)
	at android.database.sqlite.SQLiteConnectionPool.openConnectionLocked(SQLiteConnectionPool.java:463)
	at android.database.sqlite.SQLiteConnectionPool.open(SQLiteConnectionPool.java:185)
	at android.database.sqlite.SQLiteConnectionPool.open(SQLiteConnectionPool.java:177)
	at android.database.sqlite.SQLiteDatabase.openInner(SQLiteDatabase.java:806)
	at android.database.sqlite.SQLiteDatabase.open(SQLiteDatabase.java:791)
	at android.database.sqlite.SQLiteDatabase.openDatabase(SQLiteDatabase.java:694)
	at android.database.sqlite.SQLiteOpenHelper.getDatabaseLocked(SQLiteOpenHelper.java:234)
	at android.database.sqlite.SQLiteOpenHelper.getReadableDatabase(SQLiteOpenHelper.java:187)
	at org.mozilla.gecko.db.AbstractPerProfileDatabaseProvider.getReadableDatabase(AbstractPerProfileDatabaseProvider.java:43)
	at org.mozilla.gecko.db.BrowserProvider.query(BrowserProvider.java:1228)
	at org.robolectric.shadows.ShadowContentResolver.query(ShadowContentResolver.java:156)
	at android.content.ContentResolver.query(ContentResolver.java)
	at org.mozilla.gecko.db.LocalBrowserDB.getFaviconURLFromPageURL(LocalBrowserDB.java:1247)
	at org.mozilla.gecko.icons.loader.LegacyLoader.loadBitmapFromDatabase(LegacyLoader.java:61)
	at org.mozilla.gecko.icons.loader.TestLegacyLoader.testDatabaseIsQueriesForNormalRequestsWithNetworkSkipped(TestLegacyLoader.java:42)

Comment 14

2 years ago
(In reply to :Grisha Kruglov from comment #13)
> Test failures I'm seeing now are different, seem to now resolve around
> managing SQL connections.
> 
> testGetRecentHistoryVisitsForGUID

I found that if I disable TestLegacyLoader.* locally, testGetRecentHistoryVisitsForGUID starts working again.

I've managed to hackily get TestLegacyLoader.* working (with testGetRecentHistoryVisitsForGUID also succeeding) by manually forcing GeckoProfile initilisation as part of the test, but I don't really understand why it isn't working by default yet.

I.e. adding the following to each test in TestLegacyLoader makes things work:
       File profileDir = dirContainingProfile.newFolder();
       GeckoProfile profile = GeckoProfile.get(RuntimeEnvironment.application.getApplicationContext(), "profileName", profileDir);
       BrowserDB db = BrowserDB.from(profile);
(Assignee)

Comment 15

2 years ago
Narrowing this down further, TestLegacyLoader#testDatabaseIsQueriesForNormalRequestsWithNetworkSkipped is what trips everything else up, and more specifically it seems to be this call:
final IconResponse response = loader.load(request);

Comment 16

2 years ago
(In reply to :Grisha Kruglov from comment #15)
> Narrowing this down further,
> TestLegacyLoader#testDatabaseIsQueriesForNormalRequestsWithNetworkSkipped is
> what trips everything else up, and more specifically it seems to be this
> call:
> final IconResponse response = loader.load(request);

The difference between this test and other tests is:
- Other tests-
- Create new BrowserProvider
- Query using one of the BrowserContractHelper.***_URI
-- These are built using PARAM_PROFILE == Constants.DEFAULT_PROFILE == "default"
-- We pass this URI to BrowserProvider, and we end up opening a DB based on the URI in AbstractTransactionalProvider
-- So we open a DB for the given profile name
-- Which calls AbstractTransactionDatabaseProivder.getWritableDatabase (or Readable...), which opens a db path based on the profile name.

- LegacyLoader -
- Calls into Favicon code
- Which grabs BrowserDB directly from GeckoProfile
-- But GeckoProfile hasn't been initialised
-- So we have a null profile
-- Which LocalBrowserDB can't handle

I.e. LegacyLoader depends on GeckoProfile being initialised correctly (not a valid assumption in a test). We would either have to convert this test to a robocop test, or ensure GeckoProfile is initialised (which the first 2 lines of my code in comment #14 would do), or read the expected data via a ContentProvider (which I think would miss the point of this test), or rewrite LegacyLoader to read from the ContentProvider using a URI instead of trying to access BrowserDB.
(Assignee)

Comment 17

2 years ago
(In reply to Andrzej Hunt :ahunt from comment #16)
> - LegacyLoader -
> - Calls into Favicon code
> - Which grabs BrowserDB directly from GeckoProfile
> -- But GeckoProfile hasn't been initialised
> -- So we have a null profile
> -- Which LocalBrowserDB can't handle
> 
> I.e. LegacyLoader depends on GeckoProfile being initialised correctly (not a
> valid assumption in a test). We would either have to convert this test to a
> robocop test, or ensure GeckoProfile is initialised (which the first 2 lines
> of my code in comment #14 would do), or read the expected data via a
> ContentProvider (which I think would miss the point of this test), or
> rewrite LegacyLoader to read from the ContentProvider using a URI instead of
> trying to access BrowserDB.

I don't think we have a "null profile" in this case. You can see that when this test runs, a "default" GeckoProfile gets initialized (see GeckoProfile#initFromArgs) and cached (see https://dxr.mozilla.org/mozilla-central/source/mobile/android/geckoview/src/main/java/org/mozilla/gecko/GeckoProfile.java#250).

As such, it makes sense that you can run TestLegacyLoader tests in isolation using Android Studio without any hiccups.

I imagine that if you modify your GeckoProfile initialization snippet from Comment 14 with profile name="default", you will have the exact same problems.

I wonder if "resetting" the GeckoProfile singleton will help at all before the tests are run.
(Assignee)

Comment 18

2 years ago
Indeed, if I poke at GeckoProfile.sProfileCache via reflections right before that loader.load call in testDatabaseIsQueriesForNormalRequestsWithNetworkSkipped, I see that when running tests locally there are already 2 profiles present in the profile cache, and one of them is a "default" profile.
(Assignee)

Updated

2 years ago
See Also: → bug 1305615
(Assignee)

Comment 19

2 years ago
Couldn't push a patch for a review against this bug, so I filed a follow-up Bug 1305615.
Flags: needinfo?(gkruglov)
Status: REOPENED → RESOLVED
Last Resolved: 2 years ago2 years ago
status-firefox51: affected → fixed
status-firefox52: affected → fixed
Depends on: 1305615
Resolution: --- → FIXED
Target Milestone: --- → Firefox 52
Blocks: 1305615
No longer depends on: 1305615
tracking-fennec: ? → 51+

Updated

2 years ago
Iteration: --- → 1.5
Keywords: intermittent-failure
You need to log in before you can comment on or make changes to this bug.