875631 - Intermittent test_bug600307-DBOps.html | Item deleted in case 1 - got value, expected null

Status: RESOLVED WORKSFORME

(Core :: DOM: Core & HTML, defect)

Description

[Phil Ringnalda (:philor)]

https://tbpl.mozilla.org/php/getParsedLog.php?id=23345835&tree=Mozilla-Inbound
Rev4 MacOSX Lion 10.7 mozilla-inbound opt test mochitest-4 on 2013-05-23 21:30:02 PDT for push 454f2e5ff75f
slave: talos-r4-lion-073

21:32:15     INFO -  192 INFO TEST-PASS | /tests/dom/tests/mochitest/localstorage/test_bug600307-DBOps.html | Basic delete 2 works
21:32:15     INFO -  193 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/tests/mochitest/localstorage/test_bug600307-DBOps.html | Item deleted in case 1 - got value, expected null

Comment 1

[Honza Bambas (:mayhemer)]

This could be some SQLite issue...

To describe the failing test:
- we set a key in an empty localStorage, value is "value"
- we flush cache to the database and reload the cache from database again
- we change the key's value to "value2" (cached value is changed and flush is scheduled)
- we remove the key (cached value is removed and flush is scheduled)
- assuming flush didn't happen so far (very likely), we flush all changes now manually and reload the cache again from the database
- key now must not be present

The failure here is that we unexpectedly find the key with the first value "value", so it appears like the second flush made on the background thread r/w connection has not been propagated so that the main thread r/o connection that (with some probability) did the database load didn't see the most recent changes.  Still the same problem as I had with even a more complex test case that I've rather removed (was not needed anyway).

This test is relatively important and tests a realistic use case, however, execution of the test is yet not that realistic.  We may add a short timeout before we do the reload to let sqlite sync.

What do you think Marco?

Comment 2

[Marco Bonardo [:mak]]

(In reply to Honza Bambas (:mayhemer) from comment #1)
> The failure here is that we unexpectedly find the key with the first value
> "value", so it appears like the second flush made on the background thread
> r/w connection has not been propagated so that the main thread r/o
> connection that (with some probability) did the database load didn't see the
> most recent changes.

In WAL mode the connections are totally concurrent, the main-thread connection won't wait for the background connection even if the background operation already started, cause it can just read from the previous WAL checkpoint.
Though, I thought we had proper monitoring in the service, so that the main-thread waits if a flush did not finish? In such a case I wonder if the main-thread may still end up using the previous checkpoint even if the flush completed, maybe cause the previous checkpoint was being merged yet.

Comment 3

[Ed Morley [:emorley]]

(OrangeWFM for bugs not modified in > 2 months)