From: stephan Date: Wed, 4 Mar 2026 21:16:36 +0000 (+0000) Subject: Add some debugging output to opfs and track down the breakage to the initial WebLock... X-Git-Tag: major-release~100^2~19 X-Git-Url: http://git.ipfire.org/gitweb.cgi?a=commitdiff_plain;h=671a6f83f455991801efa25a030d375e23f7023f;p=thirdparty%2Fsqlite.git Add some debugging output to opfs and track down the breakage to the initial WebLock request, which is never reaching its callback. Still broken, but this is progress. FossilOrigin-Name: 62fc8b35aeec75f5648b3daa24162c638999d447aa874bdfcbac1431c5c97b6f --- diff --git a/ext/wasm/api/sqlite3-opfs-async-proxy.c-pp.js b/ext/wasm/api/sqlite3-opfs-async-proxy.c-pp.js index c9bd620fa5..f682c4ce42 100644 --- a/ext/wasm/api/sqlite3-opfs-async-proxy.c-pp.js +++ b/ext/wasm/api/sqlite3-opfs-async-proxy.c-pp.js @@ -620,11 +620,12 @@ const installAsyncProxy = function(){ const view = state.sabOPView; const slock = state.lock; const lockType = Atomics.load(view, slock.type); - - await navigator.locks.request('sqlite3-vfs-opfs:'+args[0], { + warn("handleLockRequest()", args, lockType); + navigator.locks.request('sqlite3-vfs-opfs:'+args[0], { mode: (lockType===state.sq3Codes.SQLITE_LOCK_EXCLUSIVE) ? 'exclusive' : 'shared' }, async (wl)=>{ + warn("handleLockRequest() starting lock", args, lockType); /** A. Tell the C-side we have the browser lock. We use the same handshake slot, but a specific 'Granted' value. @@ -642,6 +643,7 @@ const installAsyncProxy = function(){ Atomics.store(view, slock.atomicsHandshake, 0); Atomics.notify(view, lock.atomicsHandshake); }); + warn("handleLockRequest() ending", args, lockType); }; const waitLoop = async function f(){ @@ -679,6 +681,7 @@ const installAsyncProxy = function(){ continue; } const opId = Atomics.exchange(state.sabOPView, opIds.whichOp, 0); + warn("opId =",opId, opIds); if( opId===opIds.lockControl ){ handleLockRequest(); continue; diff --git a/ext/wasm/api/sqlite3-vfs-opfs-wl.c-pp.js b/ext/wasm/api/sqlite3-vfs-opfs-wl.c-pp.js index 4b2094ee81..6b18a38691 100644 --- a/ext/wasm/api/sqlite3-vfs-opfs-wl.c-pp.js +++ b/ext/wasm/api/sqlite3-vfs-opfs-wl.c-pp.js @@ -60,13 +60,14 @@ const installOpfsWlVfs = async function callee(options){ options = opfsUtil.initOptions(options, callee); if( !options ) return sqlite3; const capi = sqlite3.capi, - debug = sqlite3.config.debug, + debug = (...args)=>sqlite3.config.warn("opfs-wl:",...args), state = opfsUtil.createVfsState('opfs-wl', options), opfsVfs = state.vfs, metrics = opfsVfs.metrics.counters, mTimeStart = opfsVfs.mTimeStart, mTimeEnd = opfsVfs.mTimeEnd, __openFiles = opfsVfs.__openFiles; + debug("state",JSON.stringify(state,false,' ')); /* At this point, createVfsState() has populated state and opfsVfs with any code common to both the "opfs" and "opfs-wl" VFSes. Now comes the VFS-dependent work... */ @@ -75,6 +76,7 @@ const installOpfsWlVfs = async function callee(options){ mTimeStart('xLock'); ++metrics.xLock.count; const f = __openFiles[pFile]; + debug("xLock()",f,lockType); let rc = 0; /* See notes in sqlite3-vfs-opfs.c-pp.js. */ if( f.lockType ) { @@ -89,10 +91,13 @@ const installOpfsWlVfs = async function callee(options){ Atomics.store(view, state.lock.type, lockType); Atomics.store(view, state.opIds.whichOp, state.opIds.lockControl); Atomics.notify(state.sabOPView, state.opIds.whichOp) + debug("xLock waiting..."); while('not-equal'!==Atomics.wait(view, state.lock.atomicsHandshake, 0)){ /* Loop is a workaround for environment-specific quirks. See notes in similar loops. */ + debug("xLock still waiting..."); } + debug("xLock done waiting"); f.lockType = lockType; }catch(e){ sqlite3.config.error("xLock(",arguments,") failed", e, f); @@ -103,6 +108,7 @@ const installOpfsWlVfs = async function callee(options){ return rc; }, xUnlock: function(pFile,lockType){ + debug("xUnlock()",f,lockType); mTimeStart('xUnlock'); ++metrics.xUnlock.count; const f = __openFiles[pFile]; diff --git a/ext/wasm/tests/opfs/concurrency/test.js b/ext/wasm/tests/opfs/concurrency/test.js index c2932290b7..9208ff47fc 100644 --- a/ext/wasm/tests/opfs/concurrency/test.js +++ b/ext/wasm/tests/opfs/concurrency/test.js @@ -120,15 +120,15 @@ const optArgs = function(obj){ const li = []; for(const k of [ - 'interval','iterations','unlock-asap', - 'verbose','vfs','workers', + 'interval', 'iterations', 'unlock-asap', + 'verbose', 'vfs', 'workers' ]){ if( obj.hasOwnProperty(k) ) li.push(k+'='+obj[k]); } return li.join('&'); }; for(const opt of [ - {interval: 500, workers: 3, iterations: 30, vfs: 'opfs-wl'}, + {interval: 500, workers: 2, iterations: 30, vfs: 'opfs-wl', verbose: 2}, {interval: 1000, workers: 5, iterations: 30}, {interval: 500, workers: 5, iterations: 30}, {interval: 250, workers: 3, iterations: 30}, @@ -154,7 +154,7 @@ + '&opfs-unlock-asap='+options.unlockAsap ); for(let i = 0; i < options.workerCount; ++i){ - stdout("Launching worker..."); + stdout("Launching worker...", i, ); workers.push(new Worker( workers.uri+'&workerId='+(i+1)+( (i || options.noUnlink) ? '' : '&unlink-db' diff --git a/ext/wasm/tests/opfs/concurrency/worker.js b/ext/wasm/tests/opfs/concurrency/worker.js index f68bf3516b..b4cb5a30a4 100644 --- a/ext/wasm/tests/opfs/concurrency/worker.js +++ b/ext/wasm/tests/opfs/concurrency/worker.js @@ -36,8 +36,7 @@ globalThis.sqlite3InitModule().then(async function(sqlite3){ count: 0 }); const finish = ()=>{ - if(db){ - if(!db.pointer) return; + if(db?.pointer){ db.close(); } if(interval.error){ @@ -71,7 +70,7 @@ globalThis.sqlite3InitModule().then(async function(sqlite3){ const maxIterations = urlArgs.has('iterations') ? (+urlArgs.get('iterations') || 10) : 10; - stdout("Starting interval-based db updates with delay of",interval.delay,"ms."); + stdout("Starting",maxIterations,"interval-based db updates with delay of",interval.delay,"ms."); const doWork = async ()=>{ const tm = new Date().getTime(); ++interval.count; @@ -86,39 +85,32 @@ globalThis.sqlite3InitModule().then(async function(sqlite3){ }catch(e){ interval.error = e; } + stdout("doWork()",prefix,"error ",interval.error); }; - if(1){/*use setInterval()*/ - setTimeout(async function timer(){ - await doWork(); - if(interval.error || maxIterations === interval.count){ - finish(); - }else{ - setTimeout(timer, interval.delay); - } - }, interval.delay); - }else{ - /*This approach provides no concurrency whatsoever: each worker - is run to completion before any others can work.*/ - let i; - for(i = 0; i < maxIterations; ++i){ - await doWork(); - if(interval.error) break; - await wait(interval.ms); + setTimeout(async function timer(){ + await doWork(); + if(interval.error || maxIterations === interval.count){ + finish(); + }else{ + setTimeout(timer, interval.delay); } - finish(); - } + }, interval.delay); }/*run()*/; globalThis.onmessage = function({data}){ switch(data.type){ - case 'run': run().catch((e)=>{ + case 'run': + run().catch((e)=>{ if(!interval.error) interval.error = e; + }).catch(e=>{ + /* Don't do this in finally() - it fires too soon. */ finish(); + throw e; }); - break; - default: - stderr("Unhandled message type '"+data.type+"'."); - break; + break; + default: + stderr("Unhandled message type '"+data.type+"'."); + break; } }; }); diff --git a/manifest b/manifest index fa51c7fc6c..68ce7cc015 100644 --- a/manifest +++ b/manifest @@ -1,5 +1,5 @@ -C Get\sopfs-wl\splugged\sin\sto\sthe\sconcurrency\stester.\sSomewhat\sironically,\sall\scompeting\sworkers\sfail\swith\slocking\serrors\swhile\sworker\s1\sis\sbusy\srunning\soff\sthe\srails\ssomewhere.\sStashing\sfor\scloser\sinvestigation\slater. -D 2026-03-04T20:33:21.840 +C Add\ssome\sdebugging\soutput\sto\sopfs\sand\strack\sdown\sthe\sbreakage\sto\sthe\sinitial\sWebLock\srequest,\swhich\sis\snever\sreaching\sits\scallback.\sStill\sbroken,\sbut\sthis\sis\sprogress. +D 2026-03-04T21:16:36.068 F .fossil-settings/binary-glob 61195414528fb3ea9693577e1980230d78a1f8b0a54c78cf1b9b24d0a409ed6a x F .fossil-settings/empty-dirs dbb81e8fc0401ac46a1491ab34a7f2c7c0452f2f06b54ebb845d024ca8283ef1 F .fossil-settings/ignore-glob 35175cdfcf539b2318cb04a9901442804be81cd677d8b889fcc9149c21f239ea @@ -594,11 +594,11 @@ F ext/wasm/api/sqlite3-api-oo1.c-pp.js 45454631265d9ce82685f1a64e1650ee19c8e121c F ext/wasm/api/sqlite3-api-prologue.js 98fedc159c9239b226d19567d7172300dee5ffce176e5fa2f62dd1f17d088385 F ext/wasm/api/sqlite3-api-worker1.c-pp.js 1041dd645e8e821c082b628cd8d9acf70c667430f9d45167569633ffc7567938 F ext/wasm/api/sqlite3-license-version-header.js 98d90255a12d02214db634e041c8e7f2f133d9361a8ebf000ba9c9af4c6761cc -F ext/wasm/api/sqlite3-opfs-async-proxy.c-pp.js f0a2aa8712211ff9db2ef548ae8b676be3e7c82f61586d03fd8317fbc95bbedd +F ext/wasm/api/sqlite3-opfs-async-proxy.c-pp.js 792a18708a6207d9bf274b04dcddd06fd805e93d1b7f716230df3c745f2800ee F ext/wasm/api/sqlite3-vfs-helper.c-pp.js 3f828cc66758acb40e9c5b4dcfd87fd478a14c8fb7f0630264e6c7fa0e57515d F ext/wasm/api/sqlite3-vfs-kvvfs.c-pp.js a61dd2b4d919d2d5d83c5c7e49b89ecbff2525ff81419f6a6dbaecaf3819c490 F ext/wasm/api/sqlite3-vfs-opfs-sahpool.c-pp.js 1575ea6bbcf2da1e6df6892c17521a0c1c1c199a672e9090176ea0b88de48bd9 -F ext/wasm/api/sqlite3-vfs-opfs-wl.c-pp.js 62d41024ad20c388c022f032d3f25838809cb00915ebeb97b598b9f370fba2c3 +F ext/wasm/api/sqlite3-vfs-opfs-wl.c-pp.js 1e6e087a89e9cd202d457c84dae29fa4808612ff9f37210c383eb6bbab3dfd34 F ext/wasm/api/sqlite3-vfs-opfs.c-pp.js 50a955ef393722d498177ad09c9e2d05bbe8dccae4c40c501482a860ca30017d F ext/wasm/api/sqlite3-vtab-helper.c-pp.js 366596d8ff73d4cefb938bbe95bc839d503c3fab6c8335ce4bf52f0d8a7dee81 F ext/wasm/api/sqlite3-wasm.c 45bb20e19b245136711f9b78584371233975811b6560c29ed9b650e225417e29 @@ -646,8 +646,8 @@ F ext/wasm/tester1-worker.c-pp.html d0032241d0b24d996cf1c4dd0dde364189693af9b5c9 F ext/wasm/tester1.c-pp.html 52d88fe2c6f21a046030a36410b4839b632f4424028197a45a3d5669ea724ddb F ext/wasm/tester1.c-pp.js 6b946cd6d4da130dbae4a401057716d27117ca02cad2ea8c29ae9c46c675d618 F ext/wasm/tests/opfs/concurrency/index.html 657578a6e9ce1e9b8be951549ed93a6a471f4520a99e5b545928668f4285fb5e -F ext/wasm/tests/opfs/concurrency/test.js 2150850176a1ffbe7f6b19f5cf5db9c77290764d6d54430b2796b6512b676a4a -F ext/wasm/tests/opfs/concurrency/worker.js 537e11f86fdc5d5bc64032aaa48cd027a2f8cf4b020aca6c3c012fec85da2eb1 +F ext/wasm/tests/opfs/concurrency/test.js b80e17488a8e4d5500deaf68f73a7298d7d351f74bb952691a4e7b6c02a5643b +F ext/wasm/tests/opfs/concurrency/worker.js de0be3be41da20e6639cdea10467fb5d9cdf540e711b403728a08d99bbb82ee6 F ext/wasm/tests/opfs/sahpool/digest-worker.js b0ab6218588f1f0a6d15a363b493ceaf29bfb87804d9e0165915a9996377cf79 F ext/wasm/tests/opfs/sahpool/digest.html 206d08a34dc8bd570b2581d3d9ab3ecad3201b516a598dd096dcf3cf8cd81df8 F ext/wasm/tests/opfs/sahpool/index.html be736567fd92d3ecb9754c145755037cbbd2bca01385e2732294b53f4c842328 @@ -2191,8 +2191,8 @@ F tool/warnings-clang.sh bbf6a1e685e534c92ec2bfba5b1745f34fb6f0bc2a362850723a9ee F tool/warnings.sh d924598cf2f55a4ecbc2aeb055c10bd5f48114793e7ba25f9585435da29e7e98 F tool/win/sqlite.vsix deb315d026cc8400325c5863eef847784a219a2f F tool/winmain.c 00c8fb88e365c9017db14c73d3c78af62194d9644feaf60e220ab0f411f3604c -P 5978ee4902e4223fed6b95bd2d8f489bb300af8b762650e7113d1f3e97519d88 -R 0cf8357d9b35fb1b75ea83762f01c38b +P 3b27310aa29ea84f459974981a600301abac5c705029a289d3872ecacf231da3 +R 5c13d459ac5b107e6cc5943524da9a40 U stephan -Z eba11c8254e99ee26ae9feba85ef81c4 +Z 9fafbc035e4ee3a2d442f9b59c8a5807 # Remove this line to create a well-formed Fossil manifest. diff --git a/manifest.uuid b/manifest.uuid index 15d2b8cd82..6c88a8044b 100644 --- a/manifest.uuid +++ b/manifest.uuid @@ -1 +1 @@ -3b27310aa29ea84f459974981a600301abac5c705029a289d3872ecacf231da3 +62fc8b35aeec75f5648b3daa24162c638999d447aa874bdfcbac1431c5c97b6f