Websocket Connection not Establishing until Browser Refresh

rkennel commented 3 years ago

WebSocket connection does not establish when the web page first loads. If I do a refresh on the page, the websocket will connect and work appropriately.

Please let me know what info you need to help me debug. Below is my config

import { AuthService } from './modules/auth/auth.service';
import { InjectableRxStompConfig } from '@stomp/ng2-stompjs';

function getBrokerUrl(): string {
  const protocol = location.protocol === 'http:' ? 'ws://' : 'wss://';
  return protocol + location.host + '/websocket/websocket';
}

export const myRxStompConfig: InjectableRxStompConfig = {
  // Which server?
  brokerURL: getBrokerUrl(),

  // Headers
  // Typical keys: login, passcode, host
  connectHeaders: {
    Authorization: AuthService.getToken(),
  },

  // How often to heartbeat?
  // Interval in milliseconds, set to 0 to disable
  heartbeatIncoming: 0, // Typical value 0 - disabled
  heartbeatOutgoing: 20000, // Typical value 20000 - every 20 seconds

  // Wait in milliseconds before attempting auto reconnect
  // Set to 0 to disable
  // Typical value 500 (500 milli seconds)
  reconnectDelay: 200,

  // Will log diagnostics on console
  // It can be quite verbose, not recommended in production
  // Skip this key to stop logging to console
  debug: (msg: string): void => {
    // eslint-disable-next-line no-console
    console.log(new Date(), msg);
  },
};

https://github.com/rkennel/retroquest/tree/stomp

rkennel commented 3 years ago

Same issue in Chrome and Firefox

Chrome: Version 89.0.4389.128 (Official Build) (x86_64)
Firefox: 88.0 (64-bit)

kum-deepak commented 3 years ago

Please share your console output.

rkennel commented 3 years ago

TLDR It appears that the original request to connect does not send the authorization token but when I hit refresh in the browser it does. Not sure why because the config I have shown above indicates to add the header.

page load + me trying to trigger an action that sends a websocket

Console Output

Some cookies are misusing the recommended “SameSite“ attribute 3
Date Fri Apr 23 2021 08:40:21 GMT-0400 (Eastern Daylight Time)
 Opening Web Socket... my-rx-stomp.config.ts:34:12
Connected?:false team.page.ts:103:12
Date Fri Apr 23 2021 08:40:21 GMT-0400 (Eastern Daylight Time)
 Not connected, queueing my-rx-stomp.config.ts:34:12
Connected?:false team.page.ts:108:12
Date Fri Apr 23 2021 08:40:21 GMT-0400 (Eastern Daylight Time)
 Request to subscribe /topic/test/thoughts my-rx-stomp.config.ts:34:12
Date Fri Apr 23 2021 08:40:21 GMT-0400 (Eastern Daylight Time)
 Request to subscribe /topic/test/action-items my-rx-stomp.config.ts:34:12
Date Fri Apr 23 2021 08:40:21 GMT-0400 (Eastern Daylight Time)
 Request to subscribe /topic/test/column-titles my-rx-stomp.config.ts:34:12
Date Fri Apr 23 2021 08:40:21 GMT-0400 (Eastern Daylight Time)
 Request to subscribe /topic/test/end-retro my-rx-stomp.config.ts:34:12
Content Security Policy: Ignoring “'unsafe-inline'” within script-src: ‘strict-dynamic’ specified
Content Security Policy: Ignoring “https:” within script-src: ‘strict-dynamic’ specified
Content Security Policy: Ignoring “http:” within script-src: ‘strict-dynamic’ specified
Date Fri Apr 23 2021 08:40:21 GMT-0400 (Eastern Daylight Time)
 Web Socket Opened... my-rx-stomp.config.ts:34:12
Date Fri Apr 23 2021 08:40:21 GMT-0400 (Eastern Daylight Time)
 >>> CONNECT
Authorization:null
accept-version:1.0,1.1,1.2
heart-beat:20000,0

my-rx-stomp.config.ts:34:12
Date Fri Apr 23 2021 08:40:50 GMT-0400 (Eastern Daylight Time)
 Not connected, queueing my-rx-stomp.config.ts:34:12
Unhandled Promise rejection: Timeout ; Zone: <root> ; Task: Promise.then ; Value: Timeout undefined zone-evergreen.js:659

WS Response Messages

CONNECT
Authorization:null
accept-version:1.0,1.1,1.2
heart-beat:20000,0

After performing a browser refresh

Console Output

[WDS] Disconnected! vendor.js:103637:9
Date Fri Apr 23 2021 08:44:57 GMT-0400 (Eastern Daylight Time)
 Connection closed to ws://localhost:4200/websocket/websocket my-rx-stomp.config.ts:34:12
Date Fri Apr 23 2021 08:44:57 GMT-0400 (Eastern Daylight Time)
 STOMP: scheduling reconnection in 200ms my-rx-stomp.config.ts:34:12
Angular is running in development mode. Call enableProdMode() to enable production mode. core.js:27971
Date Fri Apr 23 2021 08:44:57 GMT-0400 (Eastern Daylight Time)
 Opening Web Socket... my-rx-stomp.config.ts:34:12
Connected?:false team.page.ts:103:12
Date Fri Apr 23 2021 08:44:57 GMT-0400 (Eastern Daylight Time)
 Not connected, queueing my-rx-stomp.config.ts:34:12
Connected?:false team.page.ts:108:12
Date Fri Apr 23 2021 08:44:57 GMT-0400 (Eastern Daylight Time)
 Request to subscribe /topic/test/thoughts my-rx-stomp.config.ts:34:12
Date Fri Apr 23 2021 08:44:57 GMT-0400 (Eastern Daylight Time)
 Request to subscribe /topic/test/action-items my-rx-stomp.config.ts:34:12
Date Fri Apr 23 2021 08:44:57 GMT-0400 (Eastern Daylight Time)
 Request to subscribe /topic/test/column-titles my-rx-stomp.config.ts:34:12
Date Fri Apr 23 2021 08:44:57 GMT-0400 (Eastern Daylight Time)
 Request to subscribe /topic/test/end-retro my-rx-stomp.config.ts:34:12
[WDS] Live Reloading enabled. client:52
Date Fri Apr 23 2021 08:44:57 GMT-0400 (Eastern Daylight Time)
 Web Socket Opened... my-rx-stomp.config.ts:34:12
Date Fri Apr 23 2021 08:44:57 GMT-0400 (Eastern Daylight Time)
 >>> CONNECT
Authorization:eyJhbGciOiJIUzUxMiJ9.eyJleHAiOjE2MTkzNTQ0MjEsInN1YiI6InRlc3QiLCJpc3MiOiJSZXRyb1F1ZXN0In0.dWU68yeTJCkTHAEyxFvCJB-UzasFiMBc0F-f6ClJIfC61UZ6CvSiLv8mdQmp453x-Z7ydryh8L-NEBK7dqkvpg
accept-version:1.0,1.1,1.2
heart-beat:20000,0

my-rx-stomp.config.ts:34:12
Date Fri Apr 23 2021 08:44:57 GMT-0400 (Eastern Daylight Time)
 Received data my-rx-stomp.config.ts:34:12
Date Fri Apr 23 2021 08:44:57 GMT-0400 (Eastern Daylight Time)
 <<< CONNECTED
user-name:test
heart-beat:0,0
version:1.2
content-length:0

my-rx-stomp.config.ts:34:12
Date Fri Apr 23 2021 08:44:57 GMT-0400 (Eastern Daylight Time)
 connected to server undefined my-rx-stomp.config.ts:34:12
Date Fri Apr 23 2021 08:44:57 GMT-0400 (Eastern Daylight Time)
 Will subscribe to /topic/test/thoughts my-rx-stomp.config.ts:34:12
Date Fri Apr 23 2021 08:44:57 GMT-0400 (Eastern Daylight Time)
 >>> SUBSCRIBE
id:sub-0
destination:/topic/test/thoughts

my-rx-stomp.config.ts:34:12
Date Fri Apr 23 2021 08:44:57 GMT-0400 (Eastern Daylight Time)
 Will subscribe to /topic/test/action-items my-rx-stomp.config.ts:34:12
Date Fri Apr 23 2021 08:44:57 GMT-0400 (Eastern Daylight Time)
 >>> SUBSCRIBE
id:sub-1
destination:/topic/test/action-items

my-rx-stomp.config.ts:34:12
Date Fri Apr 23 2021 08:44:57 GMT-0400 (Eastern Daylight Time)
 Will subscribe to /topic/test/column-titles my-rx-stomp.config.ts:34:12
Date Fri Apr 23 2021 08:44:57 GMT-0400 (Eastern Daylight Time)
 >>> SUBSCRIBE
id:sub-2
destination:/topic/test/column-titles

my-rx-stomp.config.ts:34:12
Date Fri Apr 23 2021 08:44:57 GMT-0400 (Eastern Daylight Time)
 Will subscribe to /topic/test/end-retro my-rx-stomp.config.ts:34:12
Date Fri Apr 23 2021 08:44:57 GMT-0400 (Eastern Daylight Time)
 >>> SUBSCRIBE
id:sub-3
destination:/topic/test/end-retro

my-rx-stomp.config.ts:34:12
Date Fri Apr 23 2021 08:44:57 GMT-0400 (Eastern Daylight Time)
 Will try sending  1 queued message(s) my-rx-stomp.config.ts:34:12
Date Fri Apr 23 2021 08:44:57 GMT-0400 (Eastern Daylight Time)
 Attempting to send [object Object] my-rx-stomp.config.ts:34:12
Date Fri Apr 23 2021 08:44:57 GMT-0400 (Eastern Daylight Time)
 >>> SEND
destination:/app/heartbeat/ping/test
content-length:2

my-rx-stomp.config.ts:34:12
Date Fri Apr 23 2021 08:45:18 GMT-0400 (Eastern Daylight Time)
 >>> SEND
destination:/app/test/thought/create
content-length:187

my-rx-stomp.config.ts:34:12
Date Fri Apr 23 2021 08:45:18 GMT-0400 (Eastern Daylight Time)
 Received data my-rx-stomp.config.ts:34:12
Date Fri Apr 23 2021 08:45:18 GMT-0400 (Eastern Daylight Time)
 <<< MESSAGE
content-length:211
message-id:f3618250-700b-3272-a005-7cb2e54fdc79-0
subscription:sub-0
content-type:application/json
destination:/topic/test/thoughts
content-length:211

my-rx-stomp.config.ts:34:12
Object { command: "MESSAGE", headers: {…}, _binaryBody: Uint8Array(211), isBinaryBody: true, escapeHeaderValues: true, skipContentLengthHeader: false, ack: ack(headers), nack: nack(headers) }
team.page.ts:127:16

WS Response Messages

CONNECT
Authorization:eyJhbGciOiJIUzUxMiJ9.eyJleHAiOjE2MTkzNTQ0MjEsInN1YiI6InRlc3QiLCJpc3MiOiJSZXRyb1F1ZXN0In0.dWU68yeTJCkTHAEyxFvCJB-UzasFiMBc0F-f6ClJIfC61UZ6CvSiLv8mdQmp453x-Z7ydryh8L-NEBK7dqkvpg
accept-version:1.0,1.1,1.2
heart-beat:20000,0

CONNECTED
version:1.2
heart-beat:0,0
user-name:test

SUBSCRIBE
id:sub-0
destination:/topic/test/thoughts

SUBSCRIBE
id:sub-1
destination:/topic/test/action-items

SUBSCRIBE
id:sub-2
destination:/topic/test/column-titles

SUBSCRIBE
id:sub-3
destination:/topic/test/end-retro

SEND
destination:/app/heartbeat/ping/test
content-length:2

SEND
destination:/app/test/thought/create
content-length:187

{"id":-1,"teamId":"test","topic":"title1","message":"Adding Thought","hearts":0,"discussed":false,"columnTitle":{"sorted":false,"id":1,"topic":"title1","title":"Title 1","teamId":"test"}}

MESSAGE
destination:/topic/test/thoughts
content-type:application/json
subscription:sub-0
message-id:f3618250-700b-3272-a005-7cb2e54fdc79-0
content-length:211

{"type":"put","payload":{"id":1,"message":"Adding Thought","hearts":0,"topic":"title1","discussed":false,"teamId":"test","columnTitle":{"id":1,"topic":"title1","title":"Title 1","teamId":"test"},"boardId":null}}

""

rkennel commented 3 years ago

Root cause appears to be because at the time RxStompConfig is set the authorization token is null. This is a race condition.

I tried resolving the problem by setting the connectHeader during the beforeConnect method but it has no impact because looking at the source code of RXStomp it does a copy (Object.assign) of the config object instead of a reference to the object.

Any suggestions as to how to solve this race condition?

kum-deepak commented 3 years ago

Is AuthService.getToken() an async method?

beforeConnect can be an async function, your code should resolve after the token has been obtained. Depending on your call signature you would need to use await or use a Promise.

Please share signature/code for AuthService.getToken() for me to help.

rkennel commented 3 years ago

I modified my RxStompConfig to look like the code below. The AuthService.getToken just reads synchronously from a cookie. The problem that I am having is that it appears at the time the config is read the token is null. modifying before connect to reset the header does not seem to have an effect. I am looking for a way to change the header confing during the beforeConnect method

RxStompConfig

import {AuthService} from './modules/auth/auth.service';
import {InjectableRxStompConfig} from '@stomp/ng2-stompjs';

class RetroQuestRxStompConfig extends InjectableRxStompConfig {

    // Which server?
    brokerURL = this.constructBrokerUrl();

    // Headers
    // Typical keys: login, passcode, host
    connectHeaders= this.constructConnectHeaders();

    // How often to heartbeat?
    // Interval in milliseconds, set to 0 to disable
    heartbeatIncoming = 0; // Typical value 0 - disabled
    heartbeatOutgoing = 20000; // Typical value 20000 - every 20 seconds

    // Wait in milliseconds before attempting auto reconnect
    // Set to 0 to disable
    // Typical value 500 (500 milli seconds)
    reconnectDelay: 200;

    debug = (msg: string): void => {
        // eslint-disable-next-line no-console
        console.trace(new Date(), msg);
    };

    beforeConnect= async () => {
        console.trace(new Date(), `BEFORE CONNECT`);
        this.connectHeaders=this.constructConnectHeaders();
        console.trace(this.connectHeaders);
    }

    constructBrokerUrl(): string {
        const protocol = location.protocol === 'http:' ? 'ws://' : 'wss://';
        return protocol + location.host + '/websocket/websocket';
    }

    constructConnectHeaders(){
        return {
            Authorization: `Bearer ${AuthService.getToken()}`
        };
    }
}

export const myRxStompConfig: InjectableRxStompConfig = new RetroQuestRxStompConfig();

AuthService.getToken()

  static getToken () {
    let token = null;
    const cookie = document.cookie;
    const keyIndex = cookie.indexOf(`${AuthService.tokenKey}=`);
    if (keyIndex >= 0) {
      const cookieMinusKey = cookie.substr(keyIndex + AuthService.tokenKey.length + 1);
      token = cookieMinusKey.split(';')[0];
    }
    return token;
  }

rkennel commented 3 years ago

Thanks for your assistance.

I was able to resolve by accessing the StompClient directly and inserting these two lines before attempting to publish a message. It would be nice to be able to dynamically change my headers but I don't know if my usage scenario is common or if this is a weird scenario. I can add a feature request if you think others might benefit from the feature.

    this.rxStompService.stompClient.connectHeaders = {
      Authorization: `Bearer ${AuthService.getToken()}`
    };
    this.rxStompService.stompClient.forceDisconnect();

stomp-js / ng2-stompjs