twilio-voice.js icon indicating copy to clipboard operation
twilio-voice.js copied to clipboard

[BUG] AccessTokenInvalid for valid tokens

Open luddd3 opened this issue 3 years ago • 17 comments

  • [X] I have verified that the issue occurs with the latest twilio.js release and is not marked as a known issue in the CHANGELOG.md.
  • [X] I reviewed the Common Issues and open GitHub issues and verified that this report represents a potentially new issue.
  • [X] I verified that the Quickstart application works in my environment.
  • [X] I am not sharing any Personally Identifiable Information (PII) or sensitive account information (API keys, credentials, etc.) when reporting this issue.

I have a problem with some clients getting AccessTokenInvalid (20101) for perfectly valid tokens. The only thing I have found is that sometimes the clients have drifting clocks. E.g. a client clock is set to 2022-08-30T09:51:41.000Z and tries to use the following token (most fields redacted):

{
  "jti": "SK...-1661853237",
  "grants": {
    "identity": "....",
    "voice": {
      "incoming": {
        "allow": true
      },
      "outgoing": {
        "application_sid": "AP..."
      }
    }
  },
  "iat": 1661853237, // 2022-08-30T09:53:57.000Z
  "exp": 1661867637, // 2022-08-30T13:53:57.000Z
  "iss": "SK....",
  "sub": "AC...."
}

According to the client clock, the access token is not yet valid. Our servers sent the token to the client approximately 2022-08-30T09:53:57.995Z

A long shot, but is there any kind of limit on the number of AccessTokens for a specific client? This client had flaky internet and I created several new tokens for it.

Software versions:

  • [X] Browser(s): Electron 10.1.6
  • [X] Operating System: Mac OS X 10.16.0
  • [X] twilio.js: 2.1.1
  • [X] Third-party libraries (e.g., Angular, React, etc.): React

luddd3 avatar Aug 30 '22 12:08 luddd3

Hi @luddd3 , Twilio Developer Educator here.

How are you updating the clients' AccessTokens when their internet is flaky?

bld010 avatar Aug 30 '22 16:08 bld010

When a client reconnects, it sends a login-request to our back-end. The back-end generates a new token and calls device.updateToken() with the new token. If the device is in state 'unregistered', device.register() is called.

I have tested extensively during the day and can get AccessTokenInvalid regardless of any drifting clock. This is my minimally reproducible code:

import { Call, Device } from '@twilio/voice-sdk'

async function getToken(): Promise<string> {
  // fetch and return new valid token
}

const setupTwilio = (token): void => {
  const device = new Device(token, {
    edge: ['frankfurt', 'dublin', 'roaming'],
    logLevel: 1,
    codecPreferences: ['opus' as Call.Codec, 'pcmu' as Call.Codec],
    tokenRefreshMs: 40_000, // refresh 40 seconds before token expires, default is 10 seconds
    maxCallSignalingTimeoutMs: 25_000, // this opts in to Call reconnection instead of using only basic media reconnection
  })

  const updateToken = async () => {
    try {
      const token = await getToken()
      device.updateToken(token)
      if (device.state === 'unregistered') {
        await device.register()
      }
    } catch (err) {
      console.error(err.stack)
    }
  }

  device.on('error', function (err) {
    console.log('error', err)
    const code = err.code

    // Access token errors
    if (code >= 20101 && code <= 20160) {
      updateToken()
    }
  })

  device.on('tokenWillExpire', () => {
    updateToken()
  })

  device.on('registered', () => {
    console.log('registered!')
  })

  device.register()
}

async function main() {
  const token = await getToken()
  setupTwilio(token)
}
main()

I have tested the above code by:

  1. Start it
  2. Wait for 'registered'
  3. Turning off my internet connection
  4. Wait until several connection errors have appeared
  5. Start internet connection again

The above sequence will produce AccessTokenInvalid errors even though all tokens we generate are valid for 4 hours.

luddd3 avatar Aug 31 '22 16:08 luddd3

@mhuynh5757 Any insights here?

bld010 avatar Sep 07 '22 19:09 bld010

We are experiencing the same error, after analyzing Twilio websocket signalling channel it looks like token validation and registration is done via 2 separate messages and there seems to be a race condition.

Here is how succesfull registration looks like: Screenshot 2022-09-14 at 16 59 34

register is sent after listen reply is received.

Here is when error happens: Screenshot 2022-09-14 at 16 57 49

register is sent at the same time as listen and receives an error, which we assume happens because listen hasn't validated the token yet.

ostap0207 avatar Sep 14 '22 14:09 ostap0207

Hey everyone, apologies for the late response. Can you please provide all the logs you see from the browser console, along with all the websocket messages (similar to what @ostap0207 posted, but all)?

charliesantos avatar Sep 15 '22 16:09 charliesantos

Hi @charliesantos I have created a zip file which includes everything you will need to recreate the error. All you have to do is enter a valid access token in "main.js" and follow the steps in the readme:

twilio-bug.zip

I tried to include everything you asked for in "example" in the zip-file, but I just took screenshots of the websocket-traffic since I didn't find any easy way to save it in my current browser (Firefox).

luddd3 avatar Sep 19 '22 09:09 luddd3

We are facing the exact same problem! Any updates on this @charliesantos.

kamalbennani avatar Oct 24 '22 13:10 kamalbennani

Apologies for the delay. We are looking at it and still haven't found the root cause. Please bear with us in the meantime.

charliesantos avatar Oct 24 '22 17:10 charliesantos

I'm observing the same issue. When my PC goes in a suspended mode (i have 10 minutes timeout) and wakes up, there is a bunch of errors including AccessTokenInvalid in the log.

dimasikturbo avatar Dec 15 '22 09:12 dimasikturbo

Based on my logs to me this looked like a race condition between listen and register. register must only be processed after listen has finished, as the issue doesn't happen in this case.

ostap0207 avatar Dec 15 '22 11:12 ostap0207

Hey everyone, sorry for the late response. We're able to reproduce the issue and found the root cause. However, the fix is not pretty straightforward and might require some more thoughts on how we design the ideal solution. Basically, as you guys have observed, this is a race condition between listen and register signaling messages. As a workaround in the meantime, can you please try either of the following?

  1. Do not call register again if you already called register one time after initializing the device. The SDK already re-registers if necessary after signaling has reconnected. See code here https://github.com/twilio/twilio-voice.js/blob/master/lib/twilio/device.ts#L1189

OR

  1. If you detect AccessTokenInvalid error after calling device.register(), can you retry? Not ideal but it should work in the meantime.

Please let me know your thoughts

charliesantos avatar Jan 31 '24 23:01 charliesantos

I encountered this error specifically when handling incoming calls. Based on my experience, it was related to the identity parameter used while generating the access token.

For example, consider a scenario where we request a token with the identity set as Banana

public static function get_access_token($identity)
{
	self::__initiate();

	$accessToken = new AccessToken(
		static::$sid,
		static::$apiKey,
		static::$apiSecret,
		3600,
		$identity
	);

	$voiceGrant = new VoiceGrant();
	$voiceGrant->setOutgoingApplicationSid(static::$twimlSid);
	$voiceGrant->setIncomingAllow(true);
	
	$accessToken->addGrant($voiceGrant);
	$token = $accessToken->toJWT();

	return ['token' => $token, 'identity' => $identity];
	
}

// issue token
self::get_access_token('Banana')

If an incoming call is made to the client, and the identity in the request callback does not match one of the issued identities (in this case, Banana), an AccessTokenInvalid error will be thrown.

public static function get_voice_response($contact, $identity = null)
{
    self::__initiate();

    $response = new VoiceResponse();

    if ($contact == self::$callerId) {
        // If identity does not match 'Banana', the token will be invalid
        $dial = $response->dial('');
        $dial->client($identity); 
    } else {
        if (strlen($contact) < 10) {
            return $response->say('Invalid phone number');
        }

        $dial = $response->dial('', ['callerId' => static::$callerId]);
        if (preg_match("/^[\d\+\-\(\) ]+$/", $contact)) {
            $dial->number($contact);
        } else {
            $dial->client($contact);
        }
    }

    return $response;
}

ibnsultan avatar Aug 31 '24 10:08 ibnsultan

Experiencing this problem here. The JS SDK is basically unusable for me. I cannot even register a device using the access token generated from the backend, I've tried the retry method suggested here as well with no luck.

flygerian avatar Dec 01 '24 20:12 flygerian

@flygerian can you please submit a support ticket through your Twilio console account? This issue involves other Twilio teams outside of the SDK.

charliesantos avatar Dec 02 '24 17:12 charliesantos