Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Websocket closed unexpectedly #1727

Closed
licaon-kter opened this issue Sep 23, 2019 · 8 comments
Closed

Websocket closed unexpectedly #1727

licaon-kter opened this issue Sep 23, 2019 · 8 comments

Comments

@licaon-kter
Copy link
Contributor

licaon-kter commented Sep 23, 2019

HEAD (cd5dacb), Firefox 69

To Reproduce
Steps to reproduce the behavior:

  1. Login
  2. Open a MUC
  3. Scroll back to old messages
  4. Read

Expected behaviour
Be able to read old messages.

Actual behaviour
Read for a while, then see the whole view reloading, member list reappears and you are scrolled down to the bottom

Firefox log says:

DEBUG: Websocket open converse-core.js:290:21
...
ERROR: Websocket closed unexpectedly converse-core.js:283:17
    log converse-core.js:283
    error converse-core.js:298
    _onClose websocket.js:352
DEBUG: WebSockets _doDisconnect was called converse-core.js:290:21
DEBUG: Websocket open converse-core.js:290:21

Config:

allow_chat_pending_contacts: true,
allow_non_roster_messaging: true,
allow_registration: false,
authentication: 'login',
auto_join_on_invite: true,
auto_login: true,
auto_reconnect: true,
debug: false,
csi_waiting_time: 60,
default_domain: 'mydomain.tld',
enable_muc_push: true,
enable_smacks: true,
locked_domain: 'mydomain.tld',
message_archiving: 'always',
muc_show_join_leave: false,
muc_show_disconnection_status: false,
omemo_default: true,
show_desktop_notifications: 'all',
view_mode: 'fullscreen',
websocket_url: 'wss://mydomain.tld/ws',
whitelisted_plugins: []

There no errors logged in ejabberd logs.

/LE: Can repro with Vivaldi Snapshot too, the member list reappears too but the view is not reset the same, it keeps its scroll position.

/LE2: I'm now thinking that #1697 is also a consequence of this

@licaon-kter
Copy link
Contributor Author

Still seeing this with HEAD

09:08:11.613  ERROR: xc.devicelists is undefined 2 log.js:64:19
    log log.js:64
    error log.js:81
    mE omemo.js:424
    run core.js:1257
    _dataRecv core.js:2519
    forEachChild core.js:309
    _dataRecv core.js:2508
    _onMessage websocket.js:506
    onmessage websocket.js:277

09:10:18.145  ERROR: Websocket closed unexpectedly log.js:64:19
    log log.js:64
    error log.js:81
    error core.js:1314
    _onClose websocket.js:359
    onclose websocket.js:159

09:10:18.877 Uncaught TypeError: t is null
    onChallenge core.js:3380
    _attemptSASLAuth core.js:2700
    authenticate core.js:2657
    _connect_cb core.js:2612
    _onInitialMessage websocket.js:265
    onmessage websocket.js:161
core.js:3380:19
    onChallenge core.js:3380
    _attemptSASLAuth core.js:2700
    authenticate core.js:2657
    _connect_cb core.js:2612
    _onInitialMessage websocket.js:265
    onmessage websocket.js:161

09:10:48.728  ERROR: WebSocket stream error: connection-timeout - Idle connection log.js:64:19
    log log.js:64
    error log.js:81
    error core.js:1314
    _checkStreamError websocket.js:129
    _onMessage websocket.js:492
    onmessage websocket.js:277

The connection to wss://mydomain.tld/ws was interrupted while the page was loading.

Then this keeps repeating....
09:31:49.659 Uncaught TypeError: t is null
    onChallenge core.js:3380
    _attemptSASLAuth core.js:2700
    authenticate core.js:2657
    _connect_cb core.js:2612
    _onInitialMessage websocket.js:265
    onmessage websocket.js:161
    _connect websocket.js:161
    connect core.js:1775
    connect connection.js:105
    Nc core.js:1157
    login core.js:1119
    login core.js:537
    reconnect connection.js:125
    Lodash 5
    reconnect core.js:401
    onDisconnected connection.js:236
    onConnectStatusChanged connection.js:281
    _changeConnectStatus core.js:2387
    _doDisconnect core.js:2428
    _checkStreamError websocket.js:133
    _onMessage websocket.js:492
    onmessage websocket.js:277
    _replaceMessageHandler websocket.js:277
    _onInitialMessage websocket.js:262
    onmessage websocket.js:161
    _connect websocket.js:161
    connect core.js:1775
    connect connection.js:105
    Nc core.js:1157
    login core.js:1119
    login core.js:537
    reconnect connection.js:125
    Lodash 5
    reconnect core.js:401
    onDisconnected connection.js:236
    onConnectStatusChanged connection.js:281
    _changeConnectStatus core.js:2387
    _doDisconnect core.js:2428
    _checkStreamError websocket.js:133
    _onMessage websocket.js:492
    onmessage websocket.js:277
    _replaceMessageHandler websocket.js:277
    _onInitialMessage websocket.js:262
    onmessage websocket.js:161
    _connect websocket.js:161
    connect core.js:1775
    connect connection.js:105
core.js:3380:19
    onChallenge core.js:3380
    _attemptSASLAuth core.js:2700
    authenticate core.js:2657
    _connect_cb core.js:2612
    _onInitialMessage websocket.js:265
    onmessage websocket.js:161
    (Async: EventHandlerNonNull)
    _connect websocket.js:161
    connect core.js:1775
    connect connection.js:105
    Nc core.js:1157
    login core.js:1119
    login core.js:537
    InterpretGeneratorResume self-hosted:1483
    AsyncFunctionNext self-hosted:689
    (Async: async)
    reconnect connection.js:125
    InterpretGeneratorResume self-hosted:1483
    AsyncFunctionNext self-hosted:689
    Lodash 5
    reconnect core.js:401
    onDisconnected connection.js:236
    onConnectStatusChanged connection.js:281
    _changeConnectStatus core.js:2387
    _doDisconnect core.js:2428
    _checkStreamError websocket.js:133
    _onMessage websocket.js:492
    onmessage websocket.js:277
    (Async: EventHandlerNonNull)
    _replaceMessageHandler websocket.js:277
    _onInitialMessage websocket.js:262
    onmessage websocket.js:161
    (Async: EventHandlerNonNull)
    _connect websocket.js:161
    connect core.js:1775
    connect connection.js:105
    Nc core.js:1157
    login core.js:1119
    login core.js:537
    InterpretGeneratorResume self-hosted:1483
    AsyncFunctionNext self-hosted:689
    (Async: async)
    reconnect connection.js:125
    InterpretGeneratorResume self-hosted:1483
    AsyncFunctionNext self-hosted:689
    Lodash 5
    reconnect core.js:401
    onDisconnected connection.js:236
    onConnectStatusChanged connection.js:281
    _changeConnectStatus core.js:2387
    _doDisconnect core.js:2428
    _checkStreamError websocket.js:133
    _onMessage websocket.js:492
    onmessage websocket.js:277
    (Async: EventHandlerNonNull)
    _replaceMessageHandler websocket.js:277
    _onInitialMessage websocket.js:262
    onmessage websocket.js:161
    (Async: EventHandlerNonNull)
    _connect websocket.js:161
    connect core.js:1775
    connect connection.js:105

Basically I connect, Firefox private tab, and after 2 mins it's disconnected.

I need to reload the page and retype user/pass to relogin.

@jcbrand
Copy link
Member

jcbrand commented Mar 16, 2021

I had a look on your server and get the same error.

Honestly, I don't think this is a Converse issue, looks more like something on Ejabberd's side.

I could maybe look into why Converse doesn't properly reconnect and login again after the websocket connection drops, but I don't see any indication that it's Converse's fault that it drops in the first place.

 ERROR: Websocket closed unexpectedly log.js:64:19
    log log.js:64
    error log.js:81
    error core.js:1079
    _onClose websocket.js:359
    onclose websocket.js:159
    (Async: EventHandlerNonNull)
    _connect websocket.js:159
    connect core.js:1775
    connect connection.js:105
    Pc core.js:922
    login core.js:878
    login core.js:341
    connect loginpanel.js:158
    authenticate loginpanel.js:150
    i element.js:136
    (Async: EventListener.handleEvent)
    delegate element.js:141
    delegateEvents element.js:98
    connectedCallback element.js:48
    __insert parts.js:207
    __commitNode parts.js:214
    __commitTemplateResult parts.js:249
    commit parts.js:189
    pc render.js:44
    render controlbox.js:47
    initialize controlbox.js:19
    connectedCallback element.js:45
    __insert parts.js:207
    __commitNode parts.js:214
    __commitTemplateResult parts.js:249
    commit parts.js:189
    Of repeat.js:29
    Rf repeat.js:400
    commit parts.js:177
    update template-instance.js:40
    __commitTemplateResult parts.js:239
    commit parts.js:189
    pc render.js:44

@licaon-kter
Copy link
Contributor Author

licaon-kter commented Mar 16, 2021

websockets server config

  -
    port: 5443
    module: ejabberd_http
    request_handlers:
      "/ws": ejabberd_http_ws
      "/http-bind": mod_bosh
    tls: true
    protocol_options: 'TLS_OPTIONS'
    dhfile: 'DH_FILE'
    ciphers: 'TLS_CIPHERS'

All the other settings are not modified so (in theory are) at their defaults: https://docs.ejabberd.im/archive/20_04/toplevel/#websocket-origin

When it disconnects, server side it logs:

[info] <0.1860.0>@mod_stream_mgmt:transition_to_pending:459 (websocket|<0.1859.0>) Closing c2s connection for user@mydomain.tld/converse.js-95488804: Connection failed: connection closed; waiting 300 seconds for stream resumption

But after disconnect, each time the console logs a new Uncaught TypeError: t is null error block, server logs another line like this:

[info] <0.300.0>@ejabberd_listener:273 (<0.1998.0>) Accepted connection hidden_by_ejabberd -> 127.0.0.1:5443

@weiss Help?

@jcbrand
Copy link
Member

jcbrand commented Mar 16, 2021

Screen Shot 2021-03-16 at 11 11 56

Looks like the websocket connection drops exactly one minute after the last stanza

@licaon-kter
Copy link
Contributor Author

Yup, server log confirms it.

Bumping and reloading (not yet restarted) the config of websockets_ping_interval to 180 secs does not seem to help.

@licaon-kter
Copy link
Contributor Author

Ok, the branch reconnects, but after a while (was idle for an hour, switched to other pages, etc) it still broke:

Uncaught TypeError: can't access dead object
    t core.js:1104
    _attemptSASLAuth core.js:2708
    authenticate core.js:2664
    _connect_cb core.js:2619
    _onInitialMessage websocket.js:265
    onmessage websocket.js:161
    _connect websocket.js:161
    connect core.js:1782
    connect connection.js:105
    connect core.js:922
    attemptNonPreboundSession core.js:884
    login core.js:342
    reconnect connection.js:125
    reconnect core.js:207
    onDisconnected connection.js:236
    onConnectStatusChanged connection.js:281
    _changeConnectStatus core.js:2394
    _doDisconnect core.js:2435
    _onClose websocket.js:360
    onclose websocket.js:159
    _connect websocket.js:159
    connect core.js:1782
    connect connection.js:105
    connect core.js:922
    attemptNonPreboundSession core.js:884
    login core.js:342
    reconnect connection.js:125
    reconnect core.js:207
    onDisconnected connection.js:236
    onConnectStatusChanged connection.js:281
    _changeConnectStatus core.js:2394
    _doDisconnect core.js:2435
    _onClose websocket.js:360
    onclose websocket.js:159
    _connect websocket.js:159
    connect core.js:1782
    connect connection.js:105
    connect core.js:922
    attemptNonPreboundSession core.js:884
    login core.js:342
    reconnect connection.js:125
    reconnect core.js:207
    onDisconnected connection.js:236
    onConnectStatusChanged connection.js:281
    _changeConnectStatus core.js:2394
    _doDisconnect core.js:2435
    _onClose websocket.js:360
    onclose websocket.js:159
core.js:1104:18
    t core.js:1104
    _attemptSASLAuth core.js:2708
    authenticate core.js:2664
    _connect_cb core.js:2619
    _onInitialMessage websocket.js:265
    onmessage websocket.js:161
    (Async: EventHandlerNonNull)
    _connect websocket.js:161
    connect core.js:1782
    connect connection.js:105
    AsyncFunctionNext self-hosted:690
    (Async: async)
    connect core.js:922
    attemptNonPreboundSession core.js:884
    login core.js:342
    AsyncFunctionNext self-hosted:690
    (Async: async)
    reconnect connection.js:125
    AsyncFunctionNext self-hosted:690
    (Async: async)
    reconnect core.js:207
    onDisconnected connection.js:236
    onConnectStatusChanged connection.js:281
    _changeConnectStatus core.js:2394
    _doDisconnect core.js:2435
    _onClose websocket.js:360
    onclose websocket.js:159
    (Async: EventHandlerNonNull)
    _connect websocket.js:159
    connect core.js:1782
    connect connection.js:105
    AsyncFunctionNext self-hosted:690
    (Async: async)
    connect core.js:922
    attemptNonPreboundSession core.js:884
    login core.js:342
    AsyncFunctionNext self-hosted:690
    (Async: async)
    reconnect connection.js:125
    AsyncFunctionNext self-hosted:690
    (Async: async)
    reconnect core.js:207
    onDisconnected connection.js:236
    onConnectStatusChanged connection.js:281
    _changeConnectStatus core.js:2394
    _doDisconnect core.js:2435
    _onClose websocket.js:360
    onclose websocket.js:159
    (Async: EventHandlerNonNull)
    _connect websocket.js:159
    connect core.js:1782
    connect connection.js:105
    AsyncFunctionNext self-hosted:690
    (Async: async)
    connect core.js:922
    attemptNonPreboundSession core.js:884
    login core.js:342
    AsyncFunctionNext self-hosted:690
    (Async: async)
    reconnect connection.js:125
    AsyncFunctionNext self-hosted:690
    (Async: async)
    reconnect core.js:207
    onDisconnected connection.js:236
    onConnectStatusChanged connection.js:281
    _changeConnectStatus core.js:2394
    _doDisconnect core.js:2435
    _onClose websocket.js:360
    onclose websocket.js:159

@member7me
Copy link
Contributor

Hi. I have similar problem. In my case Websocket closing connection or lock stanzas. Can't solve it for a while. Decision for me was - to turn off websocket due to malfunction. And enable BOSH (it's working good).
Maybe problem is in ejabberd? Some websocket bug was fixed in last release processone/ejabberd#3515
Did someone check?

@licaon-kter
Copy link
Contributor Author

Using ejabberd HEAD and conversejs HEAD here, do retry, as it seems to reconnect as needed.

@jcbrand jcbrand closed this as completed Apr 11, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

3 participants