[B2G] Not possible to open (Error Unknown) and recovery a DB in Akami handset

RESOLVED FIXED

Status

()

Core
DOM
--
critical
RESOLVED FIXED
6 years ago
6 years ago

People

(Reporter: oteo, Assigned: fabrice)

Tracking

Trunk
ARM
Gonk (Firefox OS)
Points:
---

Firefox Tracking Flags

(Not tracked)

Details

Attachments

(1 attachment, 2 obsolete attachments)

(Reporter)

Description

6 years ago
User Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_7_2) AppleWebKit/534.51.22 (KHTML, like Gecko) Version/5.1.1 Safari/534.51.22

Steps to reproduce:

Open a DataBase in Akami handset.


Actual results:

Sometimes, Error Code 1 (Unknown) is fired and the only way to recover it is removing directly the database in the filesystem.
(Reporter)

Updated

6 years ago
Severity: normal → major
OS: Mac OS X → Gonk
Hardware: x86 → ARM
(Reporter)

Updated

6 years ago
Blocks: 709564
(Reporter)

Updated

6 years ago
Blocks: 699235
No longer blocks: 709564

Updated

6 years ago
Blocks: 712809
(Reporter)

Updated

6 years ago
Severity: major → critical
(Assignee)

Comment 1

6 years ago
Maria,

can you provide a test page?
Did this maybe get fixed with bug 726814? Or is this somehow different?
No longer blocks: 699235
(Reporter)

Comment 3

6 years ago
No, Ben is another failure.
(Assignee)

Comment 4

6 years ago
I did reproduce this bug by adding a bunch of contacts and then restarting.

The first restart was stuck in a loop like this one:
I/Gecko   (  514): OPENX   45  /data/b2g/mozilla/qc3pg70y.default/indexedDB/http+++localhost+6666/2919527460O5WBDD_yRretgsi.sqlite 0400102
I/Gecko   (  514): OPENX   46  /data/b2g/mozilla/qc3pg70y.default/indexedDB/http+++localhost+6666/2919527460O5WBDD_yRretgsi.sqlite-journal 0400102
I/Gecko   (  514): OPENX   46  /data/b2g/mozilla/qc3pg70y.default/indexedDB/http+++localhost+6666/2919527460O5WBDD_yRretgsi.sqlite-journal 0400102
I/Gecko   (  514): OPENX   46  /data/b2g/mozilla/qc3pg70y.default/indexedDB/http+++localhost+6666/2919527460O5WBDD_yRretgsi.sqlite 0400000
I/Gecko   (  514): OPENX   45  /data/b2g/mozilla/qc3pg70y.default/indexedDB/http+++localhost+6666/1502770231Csotncta.sqlite 0400102
I/Gecko   (  514): OPENX   46  /data/b2g/mozilla/qc3pg70y.default/indexedDB/http+++localhost+6666/1502770231Csotncta.sqlite-journal 0400102
I/Gecko   (  514): OPENX   46  /data/b2g/mozilla/qc3pg70y.default/indexedDB/http+++localhost+6666/1502770231Csotncta.sqlite-journal 0400102
I/Gecko   (  514): OPENX   46  /data/b2g/mozilla/qc3pg70y.default/indexedDB/http+++localhost+6666/1502770231Csotncta.sqlite 0400000
I/Gecko   (  514): OPENX   45  /data/b2g/mozilla/qc3pg70y.default/indexedDB/http+++localhost+6666/30115ssm.sqlite 0400102
I/Gecko   (  514): OPENX   46  /data/b2g/mozilla/qc3pg70y.default/indexedDB/http+++localhost+6666/30115ssm.sqlite-journal 0400102
I/Gecko   (  514): OPENX   46  /data/b2g/mozilla/qc3pg70y.default/indexedDB/http+++localhost+6666/30115ssm.sqlite-journal 0400102

I killed b2g again, and got the "error 1" :
    E/GeckoConsole(  567): [JavaScript Warning: "Unknown property 'transition-duration'.  Declaration dropped." {file: "http://localhost:6666/css/TIDHome.css" line: 43}]
    E/GeckoConsole(  567): [JavaScript Warning: "Error in parsing value for 'border-radius'.  Declaration dropped." {file: "http://localhost:6666/css/TIDHome.css" line: 151}]
    I/Gecko   (  567): OPENX   56  /data/b2g/mozilla/qc3pg70y.default/places.sqlite 0400000
    I/Gecko   (  567): OPENX   57  /data/b2g/mozilla/qc3pg70y.default/places.sqlite-wal 0400102
    I/Gecko   (  567): OPENX   58  /data/b2g/mozilla/qc3pg70y.default/webappsstore.sqlite 0400102
    I/Gecko   (  567): OPENX   62  /data/b2g/mozilla/qc3pg70y.default/chromeappsstore.sqlite 0400102
    E/GeckoConsole(  567): Content JS LOG at http://localhost:6666/People/script/owd_contacts.js:88 in openDB: Indexed DB is here
    I/Gecko   (  567): OPENX   66  /data/b2g/mozilla/qc3pg70y.default/indexedDB/http+++localhost+6666/30115ssm.sqlite 0400102
    I/Gecko   (  567): OPENX   67  /data/b2g/mozilla/qc3pg70y.default/indexedDB/http+++localhost+6666/30115ssm.sqlite-journal 0400000
    I/Gecko   (  567): OPENX   67  /data/b2g/mozilla/qc3pg70y.default/indexedDB/http+++localhost+6666/30115ssm.sqlite-journal 0400002
    E/GeckoConsole(  567): Content JS ERROR at http://localhost:6666/People/script/owd_contacts.js:100 in anonymous: Database error: 1
    E/GeckoConsole(  567): Content JS LOG at http://localhost:6666/People/script/owd_contacts.js:29 in populate: Populating contacts data base for demo!
    E/GeckoConsole(  567): Content JS ERROR at http://localhost:6666/script/owd_os.js:773 in anonymous: Upsss IndexedDB crashes!!
    I/GeckoDump(  567): ***OWD***: ------WebAPI event listeners-----
    I/GeckoDump(  567): ***OWD***: SMS received event listener added
    I/GeckoDump(  567): ***OWD***: ------END WebAPI event listeners-----
Status: UNCONFIRMED → NEW
Ever confirmed: true

Comment 5

6 years ago
Created attachment 597945 [details]
IDB Test case

IDB test case that inserts 15 records in a test DB. To get the IDB error, you have to run this test and reboot the device.
(Assignee)

Comment 6

6 years ago
This test fails also on firefox desktop, so it's not akami specific. It's either:
- a bug in the test itself
- a bug in our indexedDB implementation
    newTxn: function newTxn(txn_type, callback, oncompleteCb, onerrorCb) {
      <snip>
    },

    addRecord: function addRecord(id1, id2, id3, successCb, failureCb) {
      <snip>
      this.newTxn(IDBTransaction.READ_WRITE, function(txn, store, error) {
        var request = store.put(record);
        request.onsuccess = function(event) {
          txn.result = record;
        };
      }, failureCb);
    },

This testcase is passing in failureCB to newTxn as oncompleteCb.
Status: NEW → RESOLVED
Last Resolved: 6 years ago
Resolution: --- → INVALID

Comment 8

6 years ago
Created attachment 597983 [details]
IDB Test case v2
Attachment #597945 - Attachment is obsolete: true
(Assignee)

Comment 9

6 years ago
(In reply to Fernando Jiménez Moreno [:ferjm] from comment #8)
> Created attachment 597983 [details]
> IDB Test case v2

this test doesn't fail on the akami

Comment 10

6 years ago
Created attachment 598259 [details]
IDB Test case v3

Sorry to keep pushing on this. The previous test failed on akami when another IDB was opened before.
Here it goes another test case which let you open 2 different databases. In order to reproduce the error, you have to:

- Click 'OpenDB1' and 'OpenDB2'. It will open the database without any problem. Logcat result:
E/GeckoConsole(   82): Content JS LOG at http://localhost:6666/index.html:15 in openDB: **IDBTEST** Opening DB Test
E/GeckoConsole(   82): Content JS LOG at http://localhost:6666/index.html:30 in anonymous: **IDBTEST** onupgradeneeded 
E/GeckoConsole(   82): Content JS LOG at http://localhost:6666/index.html:20 in anonymous: **IDBTEST** Database opened Test
E/GeckoConsole(   82): Content JS LOG at http://localhost:6666/index.html:15 in openDB: **IDBTEST** Opening DB another db
E/GeckoConsole(   82): Content JS LOG at http://localhost:6666/index.html:30 in anonymous: **IDBTEST** onupgradeneeded 
E/GeckoConsole(   82): Content JS LOG at http://localhost:6666/index.html:20 in anonymous: **IDBTEST** Database opened another db

- Reboot the device.

- Click again both buttons. Nothing happens. It just get stacked on "Opening DB". Logcat result:
E/GeckoConsole(   82): Content JS LOG at http://localhost:6666/index.html:15 in openDB: **IDBTEST** Opening DB Test

- Reboot the device.
- Click button. An alert error showing error code 1 is shown. Logcat result:
E/GeckoConsole(   82): Content JS LOG at http://localhost:6666/index.html:15 in openDB: **IDBTEST** Opening DB Test
E/GeckoConsole(   82): Content JS LOG at http://localhost:6666/index.html:25 in anonymous: **IDBTEST** Error 1
E/GeckoConsole(   82): [JavaScript Error: "Couldn't play common dialog event sound: TypeError: Cc['@mozilla.org/sound;1'] is undefined" {file: "resource://gre/modules/CommonDialog.jsm" line: 213}]
E/GeckoConsole(   82): Content JS LOG at http://localhost:6666/index.html:15 in openDB: **IDBTEST** Opening DB another db
E/GeckoConsole(   82): Content JS LOG at http://localhost:6666/index.html:25 in anonymous: **IDBTEST** Error 1
E/GeckoConsole(   82): [JavaScript Error: "Couldn't play common dialog event sound: TypeError: Cc['@mozilla.org/sound;1'] is undefined" {file: "resource://gre/modules/CommonDialog.jsm" line: 213}]

Am I doing anything wrong?
Attachment #597983 - Attachment is obsolete: true
(Assignee)

Comment 11

6 years ago
I confirm that the testcase pass on desktop and fennec, but fails on the akami. Reopening and investigating
Status: RESOLVED → REOPENED
Resolution: INVALID → ---
Assignee: nobody → fabrice
(Assignee)

Comment 12

6 years ago
the SQlite error we get in this case at https://mxr.mozilla.org/mozilla-central/source/storage/src/mozStoragePrivateHelpers.cpp#69 is unfortunately SQLITE_ERROR ( = 1) which is some kind of catch-all error in sqlite.

I'm doing a debug build to backtrace from here.
(Assignee)

Comment 13

6 years ago
Here's a backtrace:

(gdb) bt
#0  0x82b89574 in mozilla::storage::convertResultCode (aSQLiteResultCode=<value optimized out>) at /home/fabrice/dev/b2g/inbound/storage/src/mozStoragePrivateHelpers.cpp:77
#1  0x82b7d860 in mozilla::storage::Connection::ExecuteSimpleSQL (this=<value optimized out>, aSQLStatement=<value optimized out>)
    at /home/fabrice/dev/b2g/inbound/storage/src/mozStorageConnection.cpp:1222
#2  0x827f814a in mozilla::dom::indexedDB::FileManager::Init (this=<value optimized out>, aDirectory=0x41a45230, aConnection=0x435cf470)
    at /home/fabrice/dev/b2g/inbound/dom/indexedDB/FileManager.cpp:96
#3  0x82818e34 in mozilla::dom::indexedDB::IndexedDatabaseManager::EnsureOriginIsInitialized (this=<value optimized out>, aOrigin=<value optimized out>, 
    aDirectory=<value optimized out>) at /home/fabrice/dev/b2g/inbound/dom/indexedDB/IndexedDatabaseManager.cpp:761
#4  0x82821902 in mozilla::dom::indexedDB::OpenDatabaseHelper::DoDatabaseWork (this=0x40311c10) at /home/fabrice/dev/b2g/inbound/dom/indexedDB/OpenDatabaseHelper.cpp:1625
#5  0x82822f12 in mozilla::dom::indexedDB::OpenDatabaseHelper::Run (this=0x40311c10) at /home/fabrice/dev/b2g/inbound/dom/indexedDB/OpenDatabaseHelper.cpp:2036
#6  0x82db7430 in nsThread::ProcessNextEvent (this=0x43c01680, mayWait=<value optimized out>, result=0x4439fe7f) at /home/fabrice/dev/b2g/inbound/xpcom/threads/nsThread.cpp:657
#7  0x82d814ee in NS_ProcessNextEvent_P (thread=0x43c01680, mayWait=true) at /home/fabrice/dev/b2g/inbound/objdir-prof-gonk/xpcom/build/nsThreadUtils.cpp:245
#8  0x82db79ae in nsThread::ThreadFunc (arg=<value optimized out>) at /home/fabrice/dev/b2g/inbound/xpcom/threads/nsThread.cpp:289
#9  0x8011d0b8 in _pt_root (arg=<value optimized out>) at /home/fabrice/dev/b2g/inbound/nsprpub/pr/src/pthreads/ptthread.c:187
#10 0xafd11c38 in __thread_entry (func=0x8011d051 <_pt_root>, arg=0x435cf240, tls=<value optimized out>) at bionic/libc/bionic/pthread.c:213
#11 0xafd117ec in pthread_create (thread_out=<value optimized out>, attr=0xbee7b384, start_routine=0x8011d051 <_pt_root>, arg=<value optimized out>)
    at bionic/libc/bionic/pthread.c:349
#12 0x00000000 in ?? ()
(Assignee)

Comment 14

6 years ago
ignore the previous backtrace, it's not where we crash.
(Assignee)

Comment 15

6 years ago
hm, actually this was the good stack, breaking when we hit SQLITE_ERROR:

#0  mozilla::storage::convertResultCode (aSQLiteResultCode=1148474480) at /home/fabrice/dev/b2g/inbound/storage/src/mozStoragePrivateHelpers.cpp:82
#1  0x82b7d4e0 in mozilla::storage::Connection::ExecuteSimpleSQL (this=<value optimized out>, aSQLStatement=<value optimized out>)
    at /home/fabrice/dev/b2g/inbound/storage/src/mozStorageConnection.cpp:1222
#2  0x827f7d32 in mozilla::dom::indexedDB::FileManager::Init (this=<value optimized out>, aDirectory=0x41b9d110, aConnection=0x43e6d390)
    at /home/fabrice/dev/b2g/inbound/dom/indexedDB/FileManager.cpp:96
#3  0x82818a1c in mozilla::dom::indexedDB::IndexedDatabaseManager::EnsureOriginIsInitialized (this=<value optimized out>, aOrigin=<value optimized out>, 
    aDirectory=<value optimized out>) at /home/fabrice/dev/b2g/inbound/dom/indexedDB/IndexedDatabaseManager.cpp:761
#4  0x828214ea in mozilla::dom::indexedDB::OpenDatabaseHelper::DoDatabaseWork (this=0x40411790) at /home/fabrice/dev/b2g/inbound/dom/indexedDB/OpenDatabaseHelper.cpp:1625
#5  0x82822afa in mozilla::dom::indexedDB::OpenDatabaseHelper::Run (this=0x40411790) at /home/fabrice/dev/b2g/inbound/dom/indexedDB/OpenDatabaseHelper.cpp:2036
#6  0x82db7088 in nsThread::ProcessNextEvent (this=0x41cf1380, mayWait=<value optimized out>, result=0x44745e7f) at /home/fabrice/dev/b2g/inbound/xpcom/threads/nsThread.cpp:657
#7  0x82d81146 in NS_ProcessNextEvent_P (thread=0x41cf1380, mayWait=true) at /home/fabrice/dev/b2g/inbound/objdir-prof-gonk/xpcom/build/nsThreadUtils.cpp:245
#8  0x82db7606 in nsThread::ThreadFunc (arg=<value optimized out>) at /home/fabrice/dev/b2g/inbound/xpcom/threads/nsThread.cpp:289
#9  0x8011d0b8 in _pt_root (arg=<value optimized out>) at /home/fabrice/dev/b2g/inbound/nsprpub/pr/src/pthreads/ptthread.c:187
#10 0xafd11c38 in __thread_entry (func=0x8011d051 <_pt_root>, arg=0x43e6d160, tls=<value optimized out>) at bionic/libc/bionic/pthread.c:213
#11 0xafd117ec in pthread_create (thread_out=<value optimized out>, attr=0xbea4f384, start_routine=0x8011d051 <_pt_root>, arg=<value optimized out>)
    at bionic/libc/bionic/pthread.c:349
#12 0x80118b32 in PR_Unlock (lock=0x4040c740) at /home/fabrice/dev/b2g/inbound/nsprpub/pr/src/pthreads/ptsynch.c:237
#13 0x82d83358 in mozilla::BlockingResourceBase::CheckAcquire (this=<value optimized out>, aCallContext=...)
    at /home/fabrice/dev/b2g/inbound/objdir-prof-gonk/xpcom/build/BlockingResourceBase.cpp:161

The SQL query that fails in Connection::ExecuteSimpleSQL is:
CREATE VIRTUAL TABLE fs USING filesystem;
(Assignee)

Comment 16

6 years ago
I traced the error in sqlite at:
http://mxr.mozilla.org/mozilla-central/source/db/sqlite3/src/sqlite3.c#90722
that calls into
http://mxr.mozilla.org/mozilla-central/source/db/sqlite3/src/sqlite3.c#94079
the sqlite3RunParser() method returns the following error message:
"table fs already exists"
I have an experiment to try. Please change 'fs' here:

https://mxr.mozilla.org/mozilla-central/source/storage/src/FileSystemModule.cpp#147

to something unlikely to conflict, something like 'moz_filesystem_virtual_table'.

Then see if this still happens? My bet is that it does, because there's no reason this should be specific to the akami. Worth a shot though.

I'll be back on Monday and can really dive in then.
(Assignee)

Comment 18

6 years ago
Ben, the query that fails is "CREATE VIRTUAL TABLE fs USING filesystem;", from
http://mxr.mozilla.org/mozilla-central/source/dom/indexedDB/FileManager.cpp#97
(In reply to Fabrice Desré [:fabrice] from comment #18)
> Ben, the query that fails is "CREATE VIRTUAL TABLE fs USING filesystem;",
> from
> http://mxr.mozilla.org/mozilla-central/source/dom/indexedDB/FileManager.
> cpp#97

Yes. Presumably it conflicts with the table name I suggested to change in comment 17.
(Assignee)

Comment 20

6 years ago
I can also reproduce the bug with fennec native running on an akami.
(Assignee)

Comment 21

6 years ago
So we hit a yaffs2 bug in readdir looping endlessly. There's a patch proposed at http://www.aleph1.co.uk/lurker/message/20081104.222059.30cf53c4.nl.html that is not applied to our yaffs2 source tree. I'm building with it applied now.
(Assignee)

Comment 22

6 years ago
Applying the patch at http://www.aleph1.co.uk/lurker/message/20081104.222059.30cf53c4.nl.html to boot/msm/fs/yaffs2/yaffs_vfs.c fixes the problem!
(Assignee)

Comment 23

6 years ago
fixed by https://github.com/andreasgal/B2G/commit/d8ef06a01536704d86bd5aac0a0be120df3ebe37
Status: REOPENED → RESOLVED
Last Resolved: 6 years ago6 years ago
Resolution: --- → FIXED
You need to log in before you can comment on or make changes to this bug.