From a4ccda2979396b71a6b9057ed7bb4a707d4045d7 Mon Sep 17 00:00:00 2001 From: stephan Date: Fri, 12 Jul 2024 13:51:40 +0000 Subject: [PATCH] Work around a difficult-to-trigger Atomics API message-passing quirk in the OPFS VFS which appears in rare instances in some browsers when running high I/O loads. This resolves [https://github.com/sqlite/sqlite-wasm/issues/12 | issue #12 of the npm distribution]. FossilOrigin-Name: c7519d98ff09ed96c3c6f2cccf16f8efa19133e12cbb077fc86526f0e81f0470 --- ext/wasm/api/sqlite3-opfs-async-proxy.js | 133 +---------------------- ext/wasm/api/sqlite3-vfs-opfs.c-pp.js | 22 +++- manifest | 16 +-- manifest.uuid | 2 +- 4 files changed, 28 insertions(+), 145 deletions(-) diff --git a/ext/wasm/api/sqlite3-opfs-async-proxy.js b/ext/wasm/api/sqlite3-opfs-async-proxy.js index 457b40603b..3e2b20ffb3 100644 --- a/ext/wasm/api/sqlite3-opfs-async-proxy.js +++ b/ext/wasm/api/sqlite3-opfs-async-proxy.js @@ -87,35 +87,6 @@ const installAsyncProxy = function(){ const log = (...args)=>logImpl(2, ...args); const warn = (...args)=>logImpl(1, ...args); const error = (...args)=>logImpl(0, ...args); - const metrics = Object.create(null); - metrics.reset = ()=>{ - let k; - const r = (m)=>(m.count = m.time = m.wait = 0); - for(k in state.opIds){ - r(metrics[k] = Object.create(null)); - } - let s = metrics.s11n = Object.create(null); - s = s.serialize = Object.create(null); - s.count = s.time = 0; - s = metrics.s11n.deserialize = Object.create(null); - s.count = s.time = 0; - }; - metrics.dump = ()=>{ - let k, n = 0, t = 0, w = 0; - for(k in state.opIds){ - const m = metrics[k]; - n += m.count; - t += m.time; - w += m.wait; - m.avgTime = (m.count && m.time) ? (m.time / m.count) : 0; - } - console.log(globalThis?.location?.href, - "metrics for",globalThis?.location?.href,":\n", - metrics, - "\nTotal of",n,"op(s) for",t,"ms", - "approx",w,"ms spent waiting on OPFS APIs."); - console.log("Serialization metrics:",metrics.s11n); - }; /** __openFiles is a map of sqlite3_file pointers (integers) to @@ -358,37 +329,6 @@ const installAsyncProxy = function(){ if(fh.readOnly) toss(opName+"(): File is read-only: "+fh.filenameAbs); }; - /** - We track 2 different timers: the "metrics" timer records how much - time we spend performing work. The "wait" timer records how much - time we spend waiting on the underlying OPFS timer. See the calls - to mTimeStart(), mTimeEnd(), wTimeStart(), and wTimeEnd() - throughout this file to see how they're used. - */ - const __mTimer = Object.create(null); - __mTimer.op = undefined; - __mTimer.start = undefined; - const mTimeStart = (op)=>{ - __mTimer.start = performance.now(); - __mTimer.op = op; - //metrics[op] || toss("Maintenance required: missing metrics for",op); - ++metrics[op].count; - }; - const mTimeEnd = ()=>( - metrics[__mTimer.op].time += performance.now() - __mTimer.start - ); - const __wTimer = Object.create(null); - __wTimer.op = undefined; - __wTimer.start = undefined; - const wTimeStart = (op)=>{ - __wTimer.start = performance.now(); - __wTimer.op = op; - //metrics[op] || toss("Maintenance required: missing metrics for",op); - }; - const wTimeEnd = ()=>( - metrics[__wTimer.op].wait += performance.now() - __wTimer.start - ); - /** Gets set to true by the 'opfs-async-shutdown' command to quit the wait loop. This is only intended for debugging purposes: we cannot @@ -399,37 +339,24 @@ const installAsyncProxy = function(){ /** Asynchronous wrappers for sqlite3_vfs and sqlite3_io_methods - methods, as well as helpers like mkdir(). Maintenance reminder: - members are in alphabetical order to simplify finding them. + methods, as well as helpers like mkdir(). */ const vfsAsyncImpls = { - 'opfs-async-metrics': async ()=>{ - mTimeStart('opfs-async-metrics'); - metrics.dump(); - storeAndNotify('opfs-async-metrics', 0); - mTimeEnd(); - }, 'opfs-async-shutdown': async ()=>{ flagAsyncShutdown = true; storeAndNotify('opfs-async-shutdown', 0); }, mkdir: async (dirname)=>{ - mTimeStart('mkdir'); let rc = 0; - wTimeStart('mkdir'); try { await getDirForFilename(dirname+"/filepart", true); }catch(e){ state.s11n.storeException(2,e); rc = state.sq3Codes.SQLITE_IOERR; - }finally{ - wTimeEnd(); } storeAndNotify('mkdir', rc); - mTimeEnd(); }, xAccess: async (filename)=>{ - mTimeStart('xAccess'); /* OPFS cannot support the full range of xAccess() queries sqlite3 calls for. We can essentially just tell if the file is accessible, but if it is then it's automatically writable @@ -442,26 +369,20 @@ const installAsyncProxy = function(){ accessible, non-0 means not accessible. */ let rc = 0; - wTimeStart('xAccess'); try{ const [dh, fn] = await getDirForFilename(filename); await dh.getFileHandle(fn); }catch(e){ state.s11n.storeException(2,e); rc = state.sq3Codes.SQLITE_IOERR; - }finally{ - wTimeEnd(); } storeAndNotify('xAccess', rc); - mTimeEnd(); }, xClose: async function(fid/*sqlite3_file pointer*/){ const opName = 'xClose'; - mTimeStart(opName); __implicitLocks.delete(fid); const fh = __openFiles[fid]; let rc = 0; - wTimeStart(opName); if(fh){ delete __openFiles[fid]; await closeSyncHandle(fh); @@ -473,15 +394,11 @@ const installAsyncProxy = function(){ state.s11n.serialize(); rc = state.sq3Codes.SQLITE_NOTFOUND; } - wTimeEnd(); storeAndNotify(opName, rc); - mTimeEnd(); }, xDelete: async function(...args){ - mTimeStart('xDelete'); const rc = await vfsAsyncImpls.xDeleteNoWait(...args); storeAndNotify('xDelete', rc); - mTimeEnd(); }, xDeleteNoWait: async function(filename, syncDir = 0, recursive = false){ /* The syncDir flag is, for purposes of the VFS API's semantics, @@ -497,7 +414,6 @@ const installAsyncProxy = function(){ is false. */ let rc = 0; - wTimeStart('xDelete'); try { while(filename){ const [hDir, filenamePart] = await getDirForFilename(filename, false); @@ -513,14 +429,11 @@ const installAsyncProxy = function(){ state.s11n.storeException(2,e); rc = state.sq3Codes.SQLITE_IOERR_DELETE; } - wTimeEnd(); return rc; }, xFileSize: async function(fid/*sqlite3_file pointer*/){ - mTimeStart('xFileSize'); const fh = __openFiles[fid]; let rc = 0; - wTimeStart('xFileSize'); try{ const sz = await (await getSyncHandle(fh,'xFileSize')).getSize(); state.s11n.serialize(Number(sz)); @@ -529,19 +442,15 @@ const installAsyncProxy = function(){ rc = GetSyncHandleError.convertRc(e,state.sq3Codes.SQLITE_IOERR); } await releaseImplicitLock(fh); - wTimeEnd(); storeAndNotify('xFileSize', rc); - mTimeEnd(); }, xLock: async function(fid/*sqlite3_file pointer*/, lockType/*SQLITE_LOCK_...*/){ - mTimeStart('xLock'); const fh = __openFiles[fid]; let rc = 0; const oldLockType = fh.xLock; fh.xLock = lockType; if( !fh.syncHandle ){ - wTimeStart('xLock'); try { await getSyncHandle(fh,'xLock'); __implicitLocks.delete(fid); @@ -550,18 +459,14 @@ const installAsyncProxy = function(){ rc = GetSyncHandleError.convertRc(e,state.sq3Codes.SQLITE_IOERR_LOCK); fh.xLock = oldLockType; } - wTimeEnd(); } storeAndNotify('xLock',rc); - mTimeEnd(); }, xOpen: async function(fid/*sqlite3_file pointer*/, filename, flags/*SQLITE_OPEN_...*/, opfsFlags/*OPFS_...*/){ const opName = 'xOpen'; - mTimeStart(opName); const create = (state.sq3Codes.SQLITE_OPEN_CREATE & flags); - wTimeStart('xOpen'); try{ let hDir, filenamePart; try { @@ -569,8 +474,6 @@ const installAsyncProxy = function(){ }catch(e){ state.s11n.storeException(1,e); storeAndNotify(opName, state.sq3Codes.SQLITE_NOTFOUND); - mTimeEnd(); - wTimeEnd(); return; } if( state.opfsFlags.OPFS_UNLINK_BEFORE_OPEN & opfsFlags ){ @@ -582,7 +485,6 @@ const installAsyncProxy = function(){ } } const hFile = await hDir.getFileHandle(filenamePart, {create}); - wTimeEnd(); const fh = Object.assign(Object.create(null),{ fid: fid, filenameAbs: filename, @@ -600,60 +502,47 @@ const installAsyncProxy = function(){ __openFiles[fid] = fh; storeAndNotify(opName, 0); }catch(e){ - wTimeEnd(); error(opName,e); state.s11n.storeException(1,e); storeAndNotify(opName, state.sq3Codes.SQLITE_IOERR); } - mTimeEnd(); }, xRead: async function(fid/*sqlite3_file pointer*/,n,offset64){ - mTimeStart('xRead'); let rc = 0, nRead; const fh = __openFiles[fid]; try{ - wTimeStart('xRead'); nRead = (await getSyncHandle(fh,'xRead')).read( fh.sabView.subarray(0, n), {at: Number(offset64)} ); - wTimeEnd(); if(nRead < n){/* Zero-fill remaining bytes */ fh.sabView.fill(0, nRead, n); rc = state.sq3Codes.SQLITE_IOERR_SHORT_READ; } }catch(e){ - if(undefined===nRead) wTimeEnd(); error("xRead() failed",e,fh); state.s11n.storeException(1,e); rc = GetSyncHandleError.convertRc(e,state.sq3Codes.SQLITE_IOERR_READ); } await releaseImplicitLock(fh); storeAndNotify('xRead',rc); - mTimeEnd(); }, xSync: async function(fid/*sqlite3_file pointer*/,flags/*ignored*/){ - mTimeStart('xSync'); const fh = __openFiles[fid]; let rc = 0; if(!fh.readOnly && fh.syncHandle){ try { - wTimeStart('xSync'); await fh.syncHandle.flush(); }catch(e){ state.s11n.storeException(2,e); rc = state.sq3Codes.SQLITE_IOERR_FSYNC; } - wTimeEnd(); } storeAndNotify('xSync',rc); - mTimeEnd(); }, xTruncate: async function(fid/*sqlite3_file pointer*/,size){ - mTimeStart('xTruncate'); let rc = 0; const fh = __openFiles[fid]; - wTimeStart('xTruncate'); try{ affirmNotRO('xTruncate', fh); await (await getSyncHandle(fh,'xTruncate')).truncate(size); @@ -663,33 +552,25 @@ const installAsyncProxy = function(){ rc = GetSyncHandleError.convertRc(e,state.sq3Codes.SQLITE_IOERR_TRUNCATE); } await releaseImplicitLock(fh); - wTimeEnd(); storeAndNotify('xTruncate',rc); - mTimeEnd(); }, xUnlock: async function(fid/*sqlite3_file pointer*/, lockType/*SQLITE_LOCK_...*/){ - mTimeStart('xUnlock'); let rc = 0; const fh = __openFiles[fid]; if( state.sq3Codes.SQLITE_LOCK_NONE===lockType && fh.syncHandle ){ - wTimeStart('xUnlock'); try { await closeSyncHandle(fh) } catch(e){ state.s11n.storeException(1,e); rc = state.sq3Codes.SQLITE_IOERR_UNLOCK; } - wTimeEnd(); } storeAndNotify('xUnlock',rc); - mTimeEnd(); }, xWrite: async function(fid/*sqlite3_file pointer*/,n,offset64){ - mTimeStart('xWrite'); let rc; const fh = __openFiles[fid]; - wTimeStart('xWrite'); try{ affirmNotRO('xWrite', fh); rc = ( @@ -703,9 +584,7 @@ const installAsyncProxy = function(){ rc = GetSyncHandleError.convertRc(e,state.sq3Codes.SQLITE_IOERR_WRITE); } await releaseImplicitLock(fh); - wTimeEnd(); storeAndNotify('xWrite',rc); - mTimeEnd(); } }/*vfsAsyncImpls*/; @@ -739,8 +618,6 @@ const installAsyncProxy = function(){ } }; state.s11n.deserialize = function(clear=false){ - ++metrics.s11n.deserialize.count; - const t = performance.now(); const argc = viewU8[0]; const rc = argc ? [] : null; if(argc){ @@ -765,12 +642,9 @@ const installAsyncProxy = function(){ } if(clear) viewU8[0] = 0; //log("deserialize:",argc, rc); - metrics.s11n.deserialize.time += performance.now() - t; return rc; }; state.s11n.serialize = function(...args){ - const t = performance.now(); - ++metrics.s11n.serialize.count; if(args.length){ //log("serialize():",args); const typeIds = []; @@ -801,7 +675,6 @@ const installAsyncProxy = function(){ }else{ viewU8[0] = 0; } - metrics.s11n.serialize.time += performance.now() - t; }; state.s11n.storeException = state.asyncS11nExceptions @@ -883,7 +756,6 @@ const installAsyncProxy = function(){ } }); initS11n(); - metrics.reset(); log("init state",state); wPost('opfs-async-inited'); waitLoop(); @@ -896,9 +768,6 @@ const installAsyncProxy = function(){ waitLoop(); } break; - case 'opfs-async-metrics': - metrics.dump(); - break; } }; wPost('opfs-async-loaded'); diff --git a/ext/wasm/api/sqlite3-vfs-opfs.c-pp.js b/ext/wasm/api/sqlite3-vfs-opfs.c-pp.js index f5c59b4009..a0a456dc50 100644 --- a/ext/wasm/api/sqlite3-vfs-opfs.c-pp.js +++ b/ext/wasm/api/sqlite3-vfs-opfs.c-pp.js @@ -445,7 +445,7 @@ const installOpfsVfs = function callee(options){ OPFS_UNLINK_BEFORE_OPEN: 0x02, /** If true, any async routine which implicitly acquires a sync - access handle (i.e. an OPFS lock) will release that locks at + access handle (i.e. an OPFS lock) will release that lock at the end of the call which acquires it. If false, such "autolocks" are not released until the VFS is idle for some brief amount of time. @@ -472,9 +472,23 @@ const installOpfsVfs = function callee(options){ Atomics.notify(state.sabOPView, state.opIds.whichOp) /* async thread will take over here */; const t = performance.now(); - Atomics.wait(state.sabOPView, state.opIds.rc, -1) - /* When this wait() call returns, the async half will have - completed the operation and reported its results. */; + while('not-equal'!==Atomics.wait(state.sabOPView, state.opIds.rc, -1)){ + /* + The reason for this loop is burried in the details of + a long discussion at: + + https://github.com/sqlite/sqlite-wasm/issues/12 + + Summary: in at least one browser flavor, under high loads, + this wait() call can, on rare occasion, end up returning + 'ok', which indicates that it's returning _without_ the + other half of the proxy having called Atomics.notify(). When + this happens, we just wait() again. + */ + } + /* When the above wait() call returns 'not-equal', the async + half will have completed the operation and reported its results + in the state.opIds.rc slot of the SAB. */ const rc = Atomics.load(state.sabOPView, state.opIds.rc); metrics[op].wait += performance.now() - t; if(rc && state.asyncS11nExceptions){ diff --git a/manifest b/manifest index 9c1ce72f76..870819f0f1 100644 --- a/manifest +++ b/manifest @@ -1,5 +1,5 @@ -C Improve\sthe\sJS-exception-to-C-result-code\sconversion\sto\saccount\sfor\sthe\scase\sof\sa\sfile\sdisappearing\swhile\sthe\sOPFS\sVFS\sis\swaiting\sto\sacquire\sa\slock\son\sit. -D 2024-06-17T13:06:53.510 +C Work\saround\sa\sdifficult-to-trigger\sAtomics\sAPI\smessage-passing\squirk\sin\sthe\sOPFS\sVFS\swhich\sappears\sin\srare\sinstances\sin\ssome\sbrowsers\swhen\srunning\shigh\sI/O\sloads.\sThis\sresolves\s[https://github.com/sqlite/sqlite-wasm/issues/12\s|\sissue\s#12\sof\sthe\snpm\sdistribution]. +D 2024-07-12T13:51:40.137 F .fossil-settings/empty-dirs dbb81e8fc0401ac46a1491ab34a7f2c7c0452f2f06b54ebb845d024ca8283ef1 F .fossil-settings/ignore-glob 35175cdfcf539b2318cb04a9901442804be81cd677d8b889fcc9149c21f239ea F LICENSE.md df5091916dbb40e6e9686186587125e1b2ff51f022cc334e886c19a0e9982724 @@ -614,10 +614,10 @@ F ext/wasm/api/sqlite3-api-oo1.js c373cc04625a96bd3f01ce8ebeac93a5d38dbda6215818 F ext/wasm/api/sqlite3-api-prologue.js b347a0c5350247f90174a0ad9b9e72a99a5f837f31f78f60fcdb829b2ca30b63 F ext/wasm/api/sqlite3-api-worker1.js 9704b77b5eb9d0d498ceeaf3e7a837021b14c52ac15d6556c7f97e278ec725c3 F ext/wasm/api/sqlite3-license-version-header.js 0c807a421f0187e778dc1078f10d2994b915123c1223fe752b60afdcd1263f89 -F ext/wasm/api/sqlite3-opfs-async-proxy.js e0106685187ab649191cdc96377029b2517371286b6ddc1cf9b696f97cb9242c +F ext/wasm/api/sqlite3-opfs-async-proxy.js dd4054e4f673027c330c96a04cf0a03b118156f01b076dc4e9d604dbdd7bfc51 F ext/wasm/api/sqlite3-vfs-helper.c-pp.js 3f828cc66758acb40e9c5b4dcfd87fd478a14c8fb7f0630264e6c7fa0e57515d F ext/wasm/api/sqlite3-vfs-opfs-sahpool.c-pp.js 8433ee332d5f5e39fb19427fccb7bad7f44aa99b5504daad3343fc128c311e78 -F ext/wasm/api/sqlite3-vfs-opfs.c-pp.js 6d3999f2dce2d50a7474e17b3e57f92c6e8ee8d228059aae1e5e0577f37f6a6c +F ext/wasm/api/sqlite3-vfs-opfs.c-pp.js bde8097f84bc6ada8d2c6a5a18b97019e1346a390749902e83724cb1bba3da53 F ext/wasm/api/sqlite3-vtab-helper.c-pp.js a2fcbc3fecdd0eea229283584ebc122f29d98194083675dbe5cb2cf3a17fe309 F ext/wasm/api/sqlite3-wasm.c 9267174b9b0591b4f71193542ab57adf95bb9415f7d3453acf4a8ca8052f5e6c F ext/wasm/api/sqlite3-worker1-promiser.c-pp.js 46f303ba8ddd1b2f0a391798837beddfa72e8c897038c8047eda49ce7d5ed46b @@ -2191,9 +2191,9 @@ F vsixtest/vsixtest.tcl 6a9a6ab600c25a91a7acc6293828957a386a8a93 F vsixtest/vsixtest.vcxproj.data 2ed517e100c66dc455b492e1a33350c1b20fbcdc F vsixtest/vsixtest.vcxproj.filters 37e51ffedcdb064aad6ff33b6148725226cd608e F vsixtest/vsixtest_TemporaryKey.pfx e5b1b036facdb453873e7084e1cae9102ccc67a0 -P a7cd07d96ef420bb1512e6d575bf756809561a536c627900d0eeac879f72e63b -Q +5bd9fd5f61e7cd1ed3b44c5cabc759c154c98eb40ad10d29e61f142aaa062ddf -R 550207f6bca7a5ea068833719511be9d +P d34e788044eec3bf90d6d2db5a2ce20b0b8aea926f776d21c2cb58124773e544 +Q +af41a1e6fc8b36e9bf65a5bb0154e1ce7eb99903cb5a3e4779322527c29d8780 +R 8e551aa869faf2023e5425f757cd3b4d U stephan -Z 56f6696bb5a6f7ff1003c5bbcec4bcd1 +Z da9f80bc86014305b702c29d9577ad17 # Remove this line to create a well-formed Fossil manifest. diff --git a/manifest.uuid b/manifest.uuid index a97d29c508..6e472ca685 100644 --- a/manifest.uuid +++ b/manifest.uuid @@ -1 +1 @@ -d34e788044eec3bf90d6d2db5a2ce20b0b8aea926f776d21c2cb58124773e544 \ No newline at end of file +c7519d98ff09ed96c3c6f2cccf16f8efa19133e12cbb077fc86526f0e81f0470 -- 2.47.2