Bug 154657

Summary: (Rare) storage/indexeddb/modern/autoincrement-abort.html flaky on mac-wk1
Product: WebKit Reporter: Ryan Haddad <ryanhaddad>
Component: WebCore Misc.Assignee: Nobody <webkit-unassigned>
Status: RESOLVED FIXED    
Severity: Normal CC: beidson
Priority: P2    
Version: WebKit Nightly Build   
Hardware: Unspecified   
OS: Unspecified   
Bug Depends on:    
Bug Blocks: 154968    

Description Ryan Haddad 2016-02-24 14:51:18 PST
storage/indexeddb/modern/autoincrement-abort.html flaky on mac-wk1

The test is intermittently timing out on mac-wk1

Most recent timeout:
<https://build.webkit.org/builders/Apple%20El%20Capitan%20Release%20WK1%20(Tests)/builds/3755>

Flakiness dashboard:
<http://webkit-test-results.webkit.org/dashboards/flakiness_dashboard.html#showAllRuns=true&tests=storage%2Findexeddb%2Fmodern%2Fautoincrement-abort.html>

--- /Volumes/Data/slave/elcapitan-release-tests-wk1/build/layout-test-results/storage/indexeddb/modern/autoincrement-abort-expected.txt
+++ /Volumes/Data/slave/elcapitan-release-tests-wk1/build/layout-test-results/storage/indexeddb/modern/autoincrement-abort-actual.txt
@@ -1,3 +1,4 @@
+FAIL: Timed out waiting for notifyDone to be called
 This test creates a new database with an objectstore that autoincrements. It then puts some things in that object store, checking the keys that were used. But it then aborts that transaction. Then it opens a new one and puts something in it, double checking that the key generator was reverted when the above transaction was aborted.
 
 On success, you will see a series of "PASS" messages, followed by "TEST COMPLETE".
@@ -16,24 +17,4 @@
 Key used for put was 4
 Key used for put was 5
 Key used for put was 6
-readwrite transaction abort
-Opening readwrite transaction to make sure the key generator had successfully reverted
-Key used for put was 1
-Key used for put was 2
-Key used for put was 3
-Key used for put was 4
-Key used for put was 5
-Key used for put was 6
-readwrite transaction complete
-Opening readwrite transaction to make sure the key generator picks up where it should've left off
-Key used for put was 7
-Key used for put was 8
-Key used for put was 9
-Key used for put was 10
-Key used for put was 11
-Key used for put was 12
-readwrite transaction complete
-PASS successfullyParsed is true
 
-TEST COMPLETE
-
Comment 1 Brady Eidson 2016-04-25 14:06:23 PDT
According to the dashboard, this timeout is fairly rare.
Comment 2 Brady Eidson 2016-05-03 15:17:48 PDT
This is, indeed, rare. It happens on any given bot once every 2-3 weeks.
Comment 3 Brady Eidson 2016-06-03 12:39:19 PDT
This test is super rare, indeed.

Hasn't occurred on a Mac bot since 5/21, which is before my 5/27 date where I expected a lot of tests to be much more reliable due to http://trac.webkit.org/changeset/201461

Occurred on EFL on 5/28 with 201492 :( weird...
Comment 4 Brady Eidson 2016-06-24 10:18:34 PDT
Hasn't occurred on a Mac bot since 6/8, and that was the leaks bot.

The leaks bot timed out and actually gave us a logging dump that I'd implemented a long time ago.

Jumping to the end of the logging dump I see something *very* peculiar:

...
+UniqueIDBDatabaseConnection::didAbortTransaction -  - 140734713535744
+UniqueIDBDatabase::invokeOperationAndTransactionTimer()
+(main) UniqueIDBDatabase::operationAndTransactionTimerFired
+(main) UniqueIDBDatabase::handleDatabaseOperations - There are 1520145168 pending
...

Weird things:
1 - The didAbortTransaction line should have an IDBResourceIdentifier outputted, between the "-  -" dashes. It doesn't.
IDBResourceIdentifier can't actually output *nothing* like that - it's loggingString method has to print brackets. Bizarre.

2 - The transaction identifier - 140734713535744 - is *HUGE*.
Transaction ids start at 0. No way it got that huge.

3 - "handleDatabaseOperations - There are 1520145168 pending"
Nope, nope, nope. No way.

Something is getting into a bonkers state.
Comment 5 Brady Eidson 2016-06-24 10:19:29 PDT
More weirdness in the logs:

+(main) UniqueIDBDatabase::handleDatabaseOperations - There are 1520149760 pending
+UniqueIDBDatabase::handleDatabaseOperations - Popped an operation, now there are 1520149760 pending

Nope - Can't start at a number, pop one off, then have the same number.  o_O
Comment 6 Brady Eidson 2016-06-24 10:20:16 PDT
+IDBOpenDBRequest::onDeleteDatabaseSuccess() - current version is 140734713537488


Nope.
Comment 7 Brady Eidson 2016-07-04 22:14:22 PDT
This hasn't happened on any of the Mac bots in a month.

Closing.