Angular application started polluting logs with exception.

[glani]

Bug report

Describe the bug

The simple angular application started polluting logs.

To Reproduce

app.module.ts

in AppModule

export const initializer1 =
  (
  ): (() => Promise<boolean>) =>
    async () => {
      const supabase = createClient(
        'url',
        'key',
        {
          auth: {
            debug: true,
          }
        }
      );
      supabase.auth.onAuthStateChange(() => {});

      return true;
    };

{
      provide: APP_INITIALIZER,
      useFactory: initializer1,
      multi: true,
    },

Expected behavior

No errors in Zone or opportunity to customize showing exceptions.

Screenshots

If applicable, add screenshots to help explain your problem.

System information

• OS: macOS, centos
• Browser chrome
• Version of supabase-js: [^2.39.12]
• Version of Node.js: [e.g. 20.10.0]

Additional context

Debug output in the browser console from GoTrue

GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.619Z #_acquireLock begin -1 render-document-frontend-impl.ts:80 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.619Z #onAuthStateChange() registered callback with id 83bf91bd-ddb2-4add-803e-0e3b2cf2b78d render-document-frontend-impl.ts:89 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.619Z #onAuthStateChange() registered callback with id a347217b-4993-4ee7-af13-921531e6c12e core.mjs:26656 Angular is running in development mode. GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.643Z #_acquireLock lock acquired for storage key sb-guksenxnyizhahqwwusz-auth-token GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.644Z #_initialize() begin is PKCE flow false GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.644Z #_recoverAndRefresh() begin GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.644Z #_recoverAndRefresh() session from storage null GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.644Z #_recoverAndRefresh() session is not valid GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.644Z #_recoverAndRefresh() end GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.644Z #_handleVisibilityChange() GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.644Z #_onVisibilityChanged(true) visibilityState visible GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.644Z #_stopAutoRefresh() GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.645Z #_startAutoRefresh() GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.645Z #_initialize() end GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.645Z #_acquireLock lock released for storage key sb-guksenxnyizhahqwwusz-auth-token GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.645Z #_acquireLock end GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.645Z #_acquireLock begin -1 GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.646Z #_acquireLock begin -1 GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.646Z #_acquireLock begin -1 GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.658Z #_autoRefreshTokenTick() begin GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.658Z #_acquireLock begin 0 GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.690Z #_acquireLock lock acquired for storage key sb-guksenxnyizhahqwwusz-auth-token GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.690Z #_useSession begin GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.691Z #loadSession() begin GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.691Z #getSession() session from storage null GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.691Z #loadSession() end GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.691Z #_acquireLock lock released for storage key sb-guksenxnyizhahqwwusz-auth-token GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.691Z INITIAL_SESSION callback id 83bf91bd-ddb2-4add-803e-0e3b2cf2b78d session null GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.691Z #_useSession end GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.691Z #_acquireLock end zone.js:1043 Unhandled Promise rejection: Acquiring an exclusive Navigator LockManager lock "lock:sb-guksenxnyizhahqwwusz-auth-token" immediately failed ; Zone: ; Task: null ; Value: Error: Acquiring an exclusive Navigator LockManager lock "lock:sb-guksenxnyizhahqwwusz-auth-token" immediately failed at locks.js:93:23 at Generator.next () at asyncGeneratorStep (asyncToGenerator.js:3:1) at _next (asyncToGenerator.js:22:1) at asyncToGenerator.js:27:1 at new ZoneAwarePromise (zone.js:1411:21) at asyncToGenerator.js:19:1 at locks.js:113:6 Error: Acquiring an exclusive Navigator LockManager lock "lock:sb-guksenxnyizhahqwwusz-auth-token" immediately failed at https://app.dev.cp.ccwar.io/vendor.js:4186:19 at Generator.next () at asyncGeneratorStep (https://app.dev.cp.ccwar.io/vendor.js:92879:24) at _next (https://app.dev.cp.ccwar.io/vendor.js:92898:9) at https://app.dev.cp.ccwar.io/vendor.js:92903:7 at new ZoneAwarePromise (https://app.dev.cp.ccwar.io/polyfills.js:1360:21) at https://app.dev.cp.ccwar.io/vendor.js:92895:12 at https://app.dev.cp.ccwar.io/vendor.js:4206:21 api.onUnhandledError @ zone.js:1043 handleUnhandledRejection @ zone.js:1068 api.microtaskDrainDone @ zone.js:1062 drainMicroTaskQueue @ zone.js:588 Promise.then (async) nativeScheduleMicroTask @ zone.js:557 scheduleMicroTask @ zone.js:568 resolvePromise @ zone.js:1209 (anonymous) @ zone.js:1100 (anonymous) @ zone.js:1116 asyncGeneratorStep @ asyncToGenerator.js:6 _next @ asyncToGenerator.js:22 (anonymous) @ asyncToGenerator.js:27 ZoneAwarePromise @ zone.js:1411 (anonymous) @ asyncToGenerator.js:19 (anonymous) @ locks.js:113 Show 15 more frames Show less GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.725Z #_acquireLock end GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.725Z auto refresh token tick lock not available GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.745Z #_acquireLock lock acquired for storage key sb-guksenxnyizhahqwwusz-auth-token GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.745Z #_useSession begin GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.745Z #loadSession() begin GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.746Z #getSession() session from storage null GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.746Z #loadSession() end GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.746Z #_acquireLock lock released for storage key sb-guksenxnyizhahqwwusz-auth-token GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.746Z INITIAL_SESSION callback id a347217b-4993-4ee7-af13-921531e6c12e session null GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.746Z #_useSession end GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.746Z #_acquireLock end GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.767Z #_acquireLock lock acquired for storage key sb-guksenxnyizhahqwwusz-auth-token GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.767Z #_useSession begin GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.767Z #loadSession() begin GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.767Z #getSession() session from storage null GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.767Z #loadSession() end GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.767Z #_useSession end GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.767Z #_acquireLock lock released for storage key sb-guksenxnyizhahqwwusz-auth-token GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.768Z #_acquireLock end VM5217:5407 page lang detection: 3.60888671875 ms GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.864Z #_acquireLock begin -1 GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.866Z #_acquireLock begin -1 GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.891Z #_acquireLock lock acquired for storage key sb-guksenxnyizhahqwwusz-auth-token GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.891Z #_useSession begin GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.891Z #loadSession() begin GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.891Z #getSession() session from storage null GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.891Z #loadSession() end GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.891Z #_useSession end GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.891Z #_acquireLock lock released for storage key sb-guksenxnyizhahqwwusz-auth-token GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.891Z #_acquireLock end GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.893Z #_acquireLock lock acquired for storage key sb-guksenxnyizhahqwwusz-auth-token GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.893Z #_useSession begin GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.894Z #loadSession() begin GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.894Z #getSession() session from storage null GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.894Z #loadSession() end GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.894Z #_useSession end GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.894Z #_acquireLock lock released for storage key sb-guksenxnyizhahqwwusz-auth-token GoTrueClient.js:131 GoTrueClient@0 (2.62.0) 2023-12-23T09:37:44.894Z #_acquireLock end

[Unkn0wn0x]

Are there any updates on this? It's flooding my Sentry instance on every visibility change of the window / tab of my application.

[Klunk75]

Hi there, after some test I found that the issue should be related to the merge of this Pull Request in @supabase/gotrue-js version 2.62.0: https://github.com/supabase/gotrue-js/pull/807 If you try to downgrade @supabase/gotrue-js to version 2.61.0 (the previous one), the problem should disappear. Please Supabase Team can you check and try to solve this issue? Thank you!

Paolo

[davidboothe]

~nother solution to this is to tell angular to run the create script outside of angular.~

~https://github.com/angular/angular-cli/issues/26395#issuecomment-1840806880~

this.supabase = this.ngZone.runOutsideAngular(() => createClient(environment.supabase.url, environment.supabase.key));

~I don't know if this is just hiding the real issue or not, but my logs are a little cleaner. This also seems required for later versions of angular where SSR is enabled.~

ignore this comment. I still eventually see this error log after enough time

[nowfred]

Those logs appear when you set 'debug' to 'true' - you shouldn't need that on unless you are debugging specific aspects of the supabase client connection.

Remove this part of your init:

{
  auth: {
    debug: true,
  }
}

and the logs will disappear...?

[glani]

@nowfred debug true shows the auth flow. The exception is still in place.

[nowfred]

@nowfred debug true shows the auth flow. The exception is still in place.

Lol of course my bad - I came across this because we are debugging potentially related lock collision issues. Will update if I have something useful beyond misreading your initial question.

[hf]

OK so the issue here is really the console.error invocation, not that this is malfunctioning. Will track down why it's logged like so and move it to console.warn or .log.

[hf]

There's a block that should properly handle this and not log the error. There may be something funky going on with your transpilation environment maybe, as the condition:

      if (e.isAcquireTimeout || e instanceof LockAcquireTimeoutError) {
        this._debug('auto refresh token tick lock not available')
      } else {
        throw e
      }

Does not re-throw the error. Anyone able to add a comment in your setup to se what's the type of the error thrown here and what properties it has?

https://github.com/supabase/gotrue-js/blob/master/src/GoTrueClient.ts#L2117-L2121

[glani]

Consider that it happens once in SPA when page is loading

waiting for fix:

For prod build we use this post-install hook:

const fs = require('fs');

const filesToFix = [
  'node_modules/@supabase/gotrue-js/dist/main/lib/locks.js',
  'node_modules/@supabase/gotrue-js/dist/module/lib/locks.js',
];

filesToFix.forEach((fileToFix) => {
  fs.readFile(fileToFix, 'utf8', function (err, data) {
    if (err) {
      return console.log(err);
    }
    const re = new RegExp(/\s+throw new NavigatorLockAcquireTimeoutError/, "g");
    let result = data.replace(re,
      '\n// hide error\n//throw new NavigatorLockAcquireTimeoutError',
    );
    if (result !== data) {
      console.log(`Replaced successfully in ${fileToFix}`);
      fs.writeFile(fileToFix, result, 'utf8', function (err) {
        if (err) return console.log(err);
      });
    } else {
      console.warn(`No Replacement found in ${fileToFix}`);

    }
  });
});

[hf]

I also see a lot of Generator.next which unfortunately points to using generators instead of Promises, so the issue may be coming because it really is an unhandled promise rejection; but it's lifted somehow into a generator Promise implementation.

[hf]

Probably related to this bug / report: https://github.com/angular/angular/issues/51328

[filippo-brigati]

I solved it temporarily by downgrading supabase gotrue, just add this in the package.json

"overrides": { "@supabase/gotrue-js": "2.54.2" }

[nicetomytyuk]

The only workaround I've found for now with the latest supabase-js version is:

"overrides": { "@supabase/supabase-js": { "@supabase/auth-js": "2.61.0" } }