Debug idb hangs

.github/workflows/build-and-test.yaml

@@ -149,7 +149,7 @@ jobs:
 
           python build/test.py \
             --browsers "$browser" \
-            --reporters spec --spec-hide-passed \
+            --reporters spec --enable-logging v2 \
             ${{ matrix.extra_flags }}
 
       - name: Find coverage reports

lib/offline/indexeddb/storage_mechanism.js

@@ -46,12 +46,16 @@ shaka.offline.indexeddb.StorageMechanism = class {
     this.v5_ = null;
     /** @private {shaka.extern.EmeSessionStorageCell} */
     this.sessions_ = null;
+    /** @private {number} */
+    this.id_ = ++shaka.offline.indexeddb.StorageMechanism.nextid;
   }
 
   /**
    * @override
    */
   init() {
+    shaka.log.debug('STORAGE INSTANCE', this.id_, 'initializing');
+
     const name = shaka.offline.indexeddb.StorageMechanism.DB_NAME;
     const version = shaka.offline.indexeddb.StorageMechanism.VERSION;
 
@@ -61,6 +65,7 @@ shaka.offline.indexeddb.StorageMechanism = class {
     // called at all, so that this method doesn't hang forever.
     let timedOut = false;
     const timeOutTimer = new shaka.util.Timer(() => {
+      shaka.log.debug('STORAGE INSTANCE', this.id_, 'timed out');
       timedOut = true;
       p.reject(new shaka.util.Error(
           shaka.util.Error.Severity.CRITICAL,
@@ -71,6 +76,7 @@ shaka.offline.indexeddb.StorageMechanism = class {
 
     const open = window.indexedDB.open(name, version);
     open.onsuccess = (event) => {
+      shaka.log.debug('STORAGE INSTANCE', this.id_, 'success');
       if (timedOut) {
         // Too late, we have already given up on opening the storage mechanism.
         return;
@@ -90,10 +96,12 @@ shaka.offline.indexeddb.StorageMechanism = class {
       p.resolve();
     };
     open.onupgradeneeded = (event) => {
+      shaka.log.debug('STORAGE INSTANCE', this.id_, 'upgrading');
       // Add object stores for the latest version only.
       this.createStores_(open.result);
     };
     open.onerror = (event) => {
+      shaka.log.debug('STORAGE INSTANCE', this.id_, 'error', event.error);
       if (timedOut) {
         // Too late, we have already given up on opening the storage mechanism.
         return;
@@ -108,6 +116,21 @@ shaka.offline.indexeddb.StorageMechanism = class {
       // Firefox will raise an error on the main thread unless we stop it here.
       event.preventDefault();
     };
+    open.onblocked = (event) => {
+      shaka.log.debug('STORAGE INSTANCE', this.id_, 'blocked',
+          event.oldVersion, event.newVersion);
+      if (timedOut) {
+        // Too late, we have already given up on opening the storage mechanism.
+        return;
+      }
+      p.reject(new shaka.util.Error(
+          shaka.util.Error.Severity.CRITICAL,
+          shaka.util.Error.Category.STORAGE,
+          shaka.util.Error.Code.INDEXED_DB_BLOCKED,
+          event.oldVersion,
+          event.newVersion));
+      timeOutTimer.stop();
+    };
 
     return p;
   }
@@ -116,6 +139,7 @@ shaka.offline.indexeddb.StorageMechanism = class {
    * @override
    */
   async destroy() {
+    shaka.log.debug('STORAGE INSTANCE', this.id_, 'destroy');
     if (this.v1_) {
       await this.v1_.destroy();
     }
@@ -131,11 +155,16 @@ shaka.offline.indexeddb.StorageMechanism = class {
     if (this.sessions_) {
       await this.sessions_.destroy();
     }
+    shaka.log.debug('STORAGE INSTANCE', this.id_, 'destroy', 'cells done');
 
     // If we were never initialized, then |db_| will still be null.
     if (this.db_) {
+      shaka.log.debug('STORAGE INSTANCE', this.id_, 'destroy', 'DB close');
       this.db_.close();
+    } else {
+      shaka.log.debug('STORAGE INSTANCE', this.id_, 'destroy', 'no DB');
     }
+    shaka.log.debug('STORAGE INSTANCE', this.id_, 'destroy', 'complete');
   }
 
   /**
@@ -172,6 +201,7 @@ shaka.offline.indexeddb.StorageMechanism = class {
    * @override
    */
   async erase() {
+    shaka.log.debug('STORAGE INSTANCE', this.id_, 'erase');
     // Not all cells may have been created, so only destroy the ones that
     // were created.
     if (this.v1_) {
@@ -186,12 +216,21 @@ shaka.offline.indexeddb.StorageMechanism = class {
     if (this.v5_) {
       await this.v5_.destroy();
     }
+    /* FIXME: missing?
+    if (this.sessions_) {
+      await this.sessions_.destroy();
+    }
+    */
+    shaka.log.debug('STORAGE INSTANCE', this.id_, 'erase', 'cells done');
 
     // |db_| will only be null if the muxer was not initialized. We need to
     // close the connection in order delete the database without it being
     // blocked.
     if (this.db_) {
+      shaka.log.debug('STORAGE INSTANCE', this.id_, 'erase', 'DB close');
       this.db_.close();
+    } else {
+      shaka.log.debug('STORAGE INSTANCE', this.id_, 'erase', 'no DB');
     }
 
     await shaka.offline.indexeddb.StorageMechanism.deleteAll_();
@@ -202,6 +241,9 @@ shaka.offline.indexeddb.StorageMechanism = class {
     this.v2_ = null;
     this.v3_ = null;
     this.v5_ = null;
+    /* FIXME: missing?
+    this.sessions_ = null;
+    */
 
     await this.init();
   }
@@ -339,7 +381,12 @@ shaka.offline.indexeddb.StorageMechanism = class {
 
     const del = window.indexedDB.deleteDatabase(name);
     del.onblocked = (event) => {
-      shaka.log.warning('Deleting', name, 'is being blocked', event);
+      p.reject(new shaka.util.Error(
+          shaka.util.Error.Severity.CRITICAL,
+          shaka.util.Error.Category.STORAGE,
+          shaka.util.Error.Code.INDEXED_DB_BLOCKED,
+          event.oldVersion,
+          event.newVersion));
     };
     del.onsuccess = (event) => {
       p.resolve();
@@ -381,6 +428,8 @@ shaka.offline.indexeddb.StorageMechanism.V3_MANIFEST_STORE = 'manifest-v3';
 shaka.offline.indexeddb.StorageMechanism.V5_MANIFEST_STORE = 'manifest-v5';
 /** @const {string} */
 shaka.offline.indexeddb.StorageMechanism.SESSION_ID_STORE = 'session-ids';
+/** @type {number} */
+shaka.offline.indexeddb.StorageMechanism.nextid = 0;
 
 
 // Since this may be called before the polyfills remove indexeddb support from

lib/util/error.js

@@ -1015,11 +1015,7 @@ shaka.util.Error.Code = {
    */
   'INDEXED_DB_ERROR': 9001,
 
-  /**
-   * The storage operation was aborted.  Deprecated in favor of more general
-   * OPERATION_ABORTED.
-   */
-  'DEPRECATED_OPERATION_ABORTED': 9002,
+  // RETIRED: 'DEPRECATED_OPERATION_ABORTED': 9002,
 
   /**
    * The specified item was not found in the IndexedDB.
@@ -1097,9 +1093,19 @@ shaka.util.Error.Code = {
    * When attempting to open an indexedDB instance, nothing happened for long
    * enough for us to time out.  This keeps the storage mechanism from hanging
    * indefinitely, if neither the success nor error callbacks are called.
+   * <br> error.data[0] is the underlying error.
    */
   'INDEXED_DB_INIT_TIMED_OUT': 9017,
 
+  /**
+   * When attempting to open an indexedDB instance, the request was blocked
+   * because of another instance holding the database open.
+   * <br> error.data[0] is the old database version.
+   * <br> error.data[1] is the new database version.
+   */
+  'INDEXED_DB_BLOCKED': 9018,
+
+
   /**
    * CS IMA SDK, required for ad insertion, has not been included on the page.
    */

test/media/streaming_engine_unit.js

@@ -3996,6 +3996,12 @@ describe('StreamingEngine', () => {
   }
 
   describe('prefetch segments', () => {
+    let originalPrefetch;
+
+    beforeAll(() => {
+      originalPrefetch = shaka.media.SegmentPrefetch;
+    });
+
     beforeEach(() => {
       shaka.media.SegmentPrefetch = Util.spyFunc(
           jasmine.createSpy('SegmentPrefetch')
@@ -4013,6 +4019,10 @@ describe('StreamingEngine', () => {
       streamingEngine.configure(config);
     });
 
+    afterAll(() => {
+      shaka.media.SegmentPrefetch = originalPrefetch;
+    });
+
     it('should use prefetched segment without fetching again', async () => {
       streamingEngine.switchVariant(variant);
       await streamingEngine.start();
@@ -4080,6 +4090,12 @@ describe('StreamingEngine', () => {
     let altVariant;
     let segmentPrefetchesCreated;
 
+    let originalPrefetch;
+
+    beforeAll(() => {
+      originalPrefetch = shaka.media.SegmentPrefetch;
+    });
+
     beforeEach(() => {
       segmentPrefetchesCreated = 0;
       shaka.media.SegmentPrefetch = Util.spyFunc(
@@ -4101,6 +4117,10 @@ describe('StreamingEngine', () => {
       streamingEngine.configure(config);
     });
 
+    afterAll(() => {
+      shaka.media.SegmentPrefetch = originalPrefetch;
+    });
+
     it('should prefetch all audio variants for the language', async () => {
       const segmentType = shaka.net.NetworkingEngine.RequestType.SEGMENT;
       const context = {

test/offline/offline_integration.js

@@ -50,11 +50,15 @@ filterDescribe('Offline', supportsStorage, () => {
     eventManager.release();
 
     if (storage) {
+      console.log('After each (offline) destroying storage...');
       await storage.destroy();
+      console.log('After each (offline) destroyed.');
     }
 
     // Make sure we don't leave anything in storage after the test.
+    console.log('After each (offline) deleting storage...');
     await shaka.offline.Storage.deleteAll();
+    console.log('After each (offline) deleted.');
 
     if (player) {
       await player.destroy();
@@ -141,19 +145,31 @@ filterDescribe('Offline', supportsStorage, () => {
         shaka.test.TestScheme.setupPlayer(player, 'multidrm_no_init_data');
 
         storage.configure('offline.usePersistentLicense', false);
+        console.log('Storing content...');
         const content =
             await storage.store('test:multidrm_no_init_data').promise;
+        console.log('Stored.');
 
         const contentUri = content.offlineUri;
         goog.asserts.assert(
             contentUri, 'Stored content should have an offline uri.');
 
+        console.log('Loading content...');
         await player.load(contentUri);
+        console.log('Loaded.');
 
+        console.log('Playing...');
         await video.play();
+        console.log('Played.');
+        console.log('Playing to 3...');
         await playTo(/* end= */ 3, /* timeout= */ 20);
+        console.log('Played.');
+        console.log('Unloading...');
         await player.unload();
+        console.log('Unloaded.');
+        console.log('Removing content...');
         await storage.remove(contentUri);
+        console.log('Removed.');
       });
 
   /**