Bug 154657 - (Rare) storage/indexeddb/modern/autoincrement-abort.html flaky on mac-wk1
Summary: (Rare) storage/indexeddb/modern/autoincrement-abort.html flaky on mac-wk1
Status: RESOLVED FIXED
Alias: None
Product: WebKit
Classification: Unclassified
Component: WebCore Misc. (show other bugs)
Version: WebKit Nightly Build
Hardware: Unspecified Unspecified
: P2 Normal
Assignee: Nobody
URL:
Keywords:
Depends on:
Blocks: 154968
  Show dependency treegraph
 
Reported: 2016-02-24 14:51 PST by Ryan Haddad
Modified: 2016-07-04 22:14 PDT (History)
1 user (show)

See Also:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
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.