conversejs/converse.js

Trouble with keepalive and prebind when open new browser tab and/or window

rheman opened this issue · 1 comments

rheman commented

Hi everyone,

Environment (please complete the following information):
conversejs 10.1.6
ejabberd 23.10
ubuntu 22.04

Here is my conversejs init config

authentication: 'prebind',
prebind_url: prebind_url,
auto_login: true,
keepalive: true,
auto_reconnect: true,
bosh_service_url: bosh_service_url,
loglevel: 'debug',
persistent_store: 'IndexedDB',

Everything work as expected, even when I reload the current page everything work as expected.

To Reproduce
The problem occurs when, from the current page, I open a link in a new browser tab or window.

  1. Log in
  2. From the current page, open a link in a new browser tab or window.

Describe the bug
I have something like an infinite loop. conversejs client get refresh, reload all the time and is therefore not usable.
In my JavaScript console I also have an infinite warning loop

Screenshots
We have an infinite repetition of the two interfaces below (infinite reload or refresh).

Screenshot from 2024-02-09 08-04-18

Screenshot from 2024-02-09 08-04-25

I got two different errors in my chrome browser console depending on the configuration of my ejabberd server.

  1. Ejabberd Config 1: resource_conflict: setresource
log.js:68  2024-02-10T15:05:49.224Z WARNING: Could not restore session for jid: kamga@pessek-ejabberd.com/conversejs Error message: _restore: no restoreable session. 
log.js:72  2024-02-10T15:05:49.226Z DEBUG: request id 83.1 state changed to 4
log.js:72  2024-02-10T15:05:49.226Z DEBUG: removing request
log.js:72  2024-02-10T15:05:49.226Z DEBUG: _throttledRequestHandler called with 0 requests
log.js:72  2024-02-10T15:05:49.226Z DEBUG: request id 83 should now be removed
log.js:72  2024-02-10T15:05:49.226Z DEBUG: request id 83.1 got 200
log.js:72  2024-02-10T15:05:49.226Z DEBUG: <body xmlns="http://jabber.org/protocol/httpbind"/>
log.js:72  2024-02-10T15:05:49.502Z DEBUG: Status changed to: ATTACHED
log.js:72  2024-02-10T15:05:49.502Z DEBUG: Reattached
log.js:72  2024-02-10T15:05:49.502Z DEBUG: no requests during idle cycle, sending blank request
log.js:72  2024-02-10T15:05:49.502Z DEBUG: _throttledRequestHandler called with 1 requests
log.js:72  2024-02-10T15:05:49.503Z DEBUG: request id 85.0 posting
log.js:72  2024-02-10T15:05:49.503Z DEBUG: request id 85.0 state changed to 1
log.js:72  2024-02-10T15:05:49.503Z DEBUG: <body rid="8956100288" xmlns="http://jabber.org/protocol/httpbind" sid="baa72e7d229c8a5331110fbee846c597e71318b3"/>
log.js:72  2024-02-10T15:05:49.512Z DEBUG: _throttledRequestHandler called with 1 requests
log.js:72  2024-02-10T15:05:49.512Z DEBUG: _processRequest: first request has readyState of 1
log.js:72  2024-02-10T15:05:49.513Z DEBUG: _throttledRequestHandler called with 1 requests
log.js:72  2024-02-10T15:05:49.513Z DEBUG: _processRequest: first request has readyState of 1
log.js:72  2024-02-10T15:05:49.519Z DEBUG: _throttledRequestHandler called with 1 requests
log.js:72  2024-02-10T15:05:49.520Z DEBUG: _processRequest: first request has readyState of 1
log.js:72  2024-02-10T15:05:49.620Z DEBUG: _throttledRequestHandler called with 2 requests
log.js:72  2024-02-10T15:05:49.620Z DEBUG: _processRequest: first request has readyState of 1
log.js:72  2024-02-10T15:05:49.620Z DEBUG: request id 86.0 posting
log.js:72  2024-02-10T15:05:49.620Z DEBUG: request id 86.0 state changed to 
log.js:72  2024-02-10T15:05:49.621Z DEBUG: <body rid="8956100289" xmlns="http://jabber.org/protocol/httpbind" sid="baa72e7d229c8a5331110fbee846c597e71318b3"><iq from="kamga@pessek-ejabberd.com/conversejs" to="pessek-ejabberd.com" type="get" xmlns="jabber:client" id="285310ac-f34c-41b7-aad3-b7c78e130f00:sendIQ"><query xmlns="http://jabber.org/protocol/disco#info"/></iq><iq from="kamga@pessek-ejabberd.com/conversejs" to="pessek-ejabberd.com" type="get" xmlns="jabber:client" id="144f64a7-a6b0-4f07-90ea-3b22e20fb1b8:sendIQ"><query xmlns="http://jabber.org/protocol/disco#info"/></iq><iq type="get" id="7292c460-54f7-461a-8e15-1c6d79875967:roster" xmlns="jabber:client"><query xmlns="jabber:iq:roster" ver="bffa7ec4540b95005cae275a752ad5d6645aceea"/></iq></body>
log.js:72  2024-02-10T15:05:49.663Z DEBUG: request id 85.1 state changed to 2
log.js:72  2024-02-10T15:05:49.663Z DEBUG: request id 85.1 state changed to 3
log.js:72  2024-02-10T15:05:49.664Z DEBUG: request id 86.1 state changed to 2
log.js:72  2024-02-10T15:05:49.664Z DEBUG: request id 86.1 state changed to 3
log.js:72  2024-02-10T15:05:49.664Z DEBUG: request id 86.1 state changed to 4
log.js:72  2024-02-10T15:05:49.664Z DEBUG: removing request
log.js:72  2024-02-10T15:05:49.664Z DEBUG: _throttledRequestHandler called with 1 requests
log.js:72  2024-02-10T15:05:49.664Z DEBUG: _processRequest: first request has readyState of 3
log.js:72  2024-02-10T15:05:49.664Z DEBUG: request id 86 should now be removed
log.js:72  2024-02-10T15:05:49.664Z DEBUG: _processRequest: first request has readyState of 3
log.js:72  2024-02-10T15:05:49.664Z DEBUG: request id 86.1 got 200
log.js:72  2024-02-10T15:05:49.665Z DEBUG: <body xmlns:stream="http://etherx.jabber.org/streams" xmlns="http://jabber.org/protocol/httpbind" type="terminate" condition="remote-stream-error"><stream:error><invalid-from xmlns="urn:ietf:params:xml:ns:xmpp-streams"/><text xmlns="urn:ietf:params:xml:ns:xmpp-streams" xml:lang="en">Improper 'from' attribute</text></stream:error></body>
log.js:72  2024-02-10T15:05:49.665Z DEBUG: Status changed to: CONNFAIL
log.js:72  2024-02-10T15:05:49.665Z DEBUG: _doDisconnect was called
log.js:72  2024-02-10T15:05:49.665Z DEBUG: Status changed to: DISCONNECTED
log.js:72  2024-02-10T15:05:49.665Z DEBUG: RECONNECTING: the connection has dropped, attempting to reconnect.
  1. Ejabberd Config 2: resource_conflict: closeold
log.js:68  2024-02-10T14:34:32.935Z WARNING: Could not restore session for jid: kamga@pessek-ejabberd.com/conversejs Error message: _restore: no restoreable session. 
log.js:72  2024-02-10T14:34:33.205Z DEBUG: Status changed to: ATTACHED
log.js:72  2024-02-10T14:34:33.206Z DEBUG: Reattached
log.js:72  2024-02-10T14:34:33.206Z DEBUG: no requests during idle cycle, sending blank request
log.js:72  2024-02-10T14:34:33.206Z DEBUG: _throttledRequestHandler called with 1 requests
log.js:72  2024-02-10T14:34:33.206Z DEBUG: request id 27.0 posting
log.js:72  2024-02-10T14:34:33.206Z DEBUG: request id 27.0 state changed to 1
log.js:72  2024-02-10T14:34:33.207Z DEBUG: <body rid="7557281811" xmlns="http://jabber.org/protocol/httpbind" sid="5dd83f8cf9fb543552ef6e992277591cd74418a0"/>
log.js:72  2024-02-10T14:34:33.219Z DEBUG: _throttledRequestHandler called with 1 requests
log.js:72  2024-02-10T14:34:33.220Z DEBUG: _processRequest: first request has readyState of 1
log.js:72  2024-02-10T14:34:33.220Z DEBUG: _throttledRequestHandler called with 1 requests
log.js:72  2024-02-10T14:34:33.221Z DEBUG: _processRequest: first request has readyState of 1
log.js:72  2024-02-10T14:34:33.230Z DEBUG: _throttledRequestHandler called with 1 requests
log.js:72  2024-02-10T14:34:33.231Z DEBUG: _processRequest: first request has readyState of 1
log.js:72  2024-02-10T14:34:33.331Z DEBUG: _throttledRequestHandler called with 2 requests
log.js:72  2024-02-10T14:34:33.331Z DEBUG: _processRequest: first request has readyState of 1
log.js:72  2024-02-10T14:34:33.331Z DEBUG: request id 28.0 posting
log.js:72  2024-02-10T14:34:33.331Z DEBUG: request id 28.0 state changed to 1
log.js:72  2024-02-10T14:34:33.332Z DEBUG: <body rid="7557281812" xmlns="http://jabber.org/protocol/httpbind" sid="5dd83f8cf9fb543552ef6e992277591cd74418a0"><iq from="kamga@pessek-ejabberd.com/conversejs" to="pessek-ejabberd.com" type="get" xmlns="jabber:client" id="6e5b4dc0-44a5-4087-be79-dc9421a34964:sendIQ"><query xmlns="http://jabber.org/protocol/disco#info"/></iq><iq from="kamga@pessek-ejabberd.com/conversejs" to="pessek-ejabberd.com" type="get" xmlns="jabber:client" id="01eee6ac-6892-4dc6-9518-854c35340647:sendIQ"><query xmlns="http://jabber.org/protocol/disco#info"/></iq><presence xmlns="jabber:client"><priority>0</priority><c xmlns="http://jabber.org/protocol/caps" hash="sha-1" node="https://conversejs.org" ver="bWAbgKReOpc5xmIvP67bt8JrPOE="/></presence></body>
log.js:72  2024-02-10T14:34:33.384Z DEBUG: request id 27.1 state changed to 2
log.js:72  2024-02-10T14:34:33.384Z DEBUG: request id 27.1 state changed to 3
log.js:72  2024-02-10T14:34:33.385Z DEBUG: request id 27.1 state changed to 4
log.js:72  2024-02-10T14:34:33.385Z DEBUG: removing request
log.js:72  2024-02-10T14:34:33.385Z DEBUG: _throttledRequestHandler called with 1 requests
log.js:72  2024-02-10T14:34:33.385Z DEBUG: _processRequest: first request has readyState of 1
log.js:72  2024-02-10T14:34:33.385Z DEBUG: request id 27 should now be removed
log.js:72  2024-02-10T14:34:33.385Z DEBUG: request id 27.1 got 200
log.js:72  2024-02-10T14:34:33.385Z DEBUG: <body xmlns="http://jabber.org/protocol/httpbind"/>
log.js:72  2024-02-10T14:34:33.386Z DEBUG: request id 28.1 state changed to 2
log.js:72  2024-02-10T14:34:33.387Z DEBUG: request id 28.1 state changed to 3
log.js:72  2024-02-10T14:34:33.387Z DEBUG: request id 28.1 state changed to 4
log.js:72  2024-02-10T14:34:33.387Z DEBUG: removing request
log.js:72  2024-02-10T14:34:33.387Z DEBUG: _throttledRequestHandler called with 0 requests
log.js:72  2024-02-10T14:34:33.387Z DEBUG: request id 28 should now be removed
log.js:72  2024-02-10T14:34:33.387Z DEBUG: request id 28.1 got 200
log.js:72  2024-02-10T14:34:33.387Z DEBUG: <body xmlns="http://jabber.org/protocol/httpbind"><iq xmlns="jabber:client" xml:lang="en" to="kamga@pessek-ejabberd.com/conversejs" from="pessek-ejabberd.com" type="result" id="6e5b4dc0-44a5-4087-be79-dc9421a34964:sendIQ"><query xmlns="http://jabber.org/protocol/disco#info"><identity type="pep" category="pubsub"/><identity name="ejabberd" type="im" category="server"/><feature var="http://jabber.org/protocol/commands"/><feature var="http://jabber.org/protocol/disco#info"/><feature var="http://jabber.org/protocol/disco#items"/><feature var="http://jabber.org/protocol/offline"/><feature var="http://jabber.org/protocol/pubsub"/><feature var="http://jabber.org/protocol/pubsub#access-authorize"/><feature var="http://jabber.org/protocol/pubsub#access-open"/><feature var="http://jabber.org/protocol/pubsub#access-presence"/><feature var="http://jabber.org/protocol/pubsub#access-whitelist"/><feature var="http://jabber.org/protocol/pubsub#auto-create"/><feature var="http://jabber.org/protocol/pubsub#auto-subscribe"/><feature var="http://jabber.org/protocol/pubsub#collections"/><feature var="http://jabber.org/protocol/pubsub#config-node"/><feature var="http://jabber.org/protocol/pubsub#config-node-max"/><feature var="http://jabber.org/protocol/pubsub#create-and-configure"/><feature var="http://jabber.org/protocol/pubsub#create-nodes"/><feature var="http://jabber.org/protocol/pubsub#delete-items"/><feature var="http://jabber.org/protocol/pubsub#delete-nodes"/><feature var="http://jabber.org/protocol/pubsub#filtered-notifications"/><feature var="http://jabber.org/protocol/pubsub#get-pending"/><feature var="http://jabber.org/protocol/pubsub#instant-nodes"/><feature var="http://jabber.org/protocol/pubsub#item-ids"/><feature var="http://jabber.org/protocol/pubsub#last-published"/><feature var="http://jabber.org/protocol/pubsub#manage-subscriptions"/><feature var="http://jabber.org/protocol/pubsub#member-affiliation"/><feature var="http://jabber.org/protocol/pubsub#modify-affiliations"/><feature var="http://jabber.org/protocol/pubsub#multi-items"/><feature var="http://jabber.org/protocol/pubsub#outcast-affiliation"/><feature var="http://jabber.org/protocol/pubsub#persistent-items"/><feature var="http://jabber.org/protocol/pubsub#presence-notifications"/><feature var="http://jabber.org/protocol/pubsub#presence-subscribe"/><feature var="http://jabber.org/protocol/pubsub#publish"/><feature var="http://jabber.org/protocol/pubsub#publish-only-affiliation"/><feature var="http://jabber.org/protocol/pubsub#publish-options"/><feature var="http://jabber.org/protocol/pubsub#publisher-affiliation"/><feature var="http://jabber.org/protocol/pubsub#purge-nodes"/><feature var="http://jabber.org/protocol/pubsub#retract-items"/><feature var="http://jabber.org/protocol/pubsub#retrieve-affiliations"/><feature var="http://jabber.org/protocol/pubsub#retrieve-default"/><feature var="http://jabber.org/protocol/pubsub#retrieve-items"/><feature var="http://jabber.org/protocol/pubsub#retrieve-subscriptions"/><feature var="http://jabber.org/protocol/pubsub#shim"/><feature var="http://jabber.org/protocol/pubsub#subscribe"/><feature var="http://jabber.org/protocol/pubsub#subscription-notifications"/><feature var="http://jabber.org/protocol/rsm"/><feature var="http://jabber.org/protocol/stats"/><feature var="iq"/><feature var="jabber:iq:last"/><feature var="jabber:iq:privacy"/><feature var="jabber:iq:register"/><feature var="jabber:iq:version"/><feature var="msgoffline"/><feature var="presence"/><feature var="urn:xmpp:blocking"/><feature var="urn:xmpp:carbons:2"/><feature var="urn:xmpp:carbons:rules:0"/><feature var="urn:xmpp:mam:0"/><feature var="urn:xmpp:mam:1"/><feature var="urn:xmpp:mam:2"/><feature var="urn:xmpp:mam:tmp"/><feature var="urn:xmpp:ping"/><feature var="urn:xmpp:time"/><feature var="vcard-temp"/><x xmlns="jabber:x:data" type="result"><field var="FORM_TYPE" type="hidden"><value>http://jabber.org/network/serverinfo</value></field></x></query></iq></body>
log.js:72  2024-02-10T14:34:33.388Z DEBUG: _throttledRequestHandler called with 0 requests
log.js:72  2024-02-10T14:34:33.489Z DEBUG: _throttledRequestHandler called with 1 requests
log.js:72  2024-02-10T14:34:33.489Z DEBUG: request id 29.0 posting
log.js:72  2024-02-10T14:34:33.489Z DEBUG: request id 29.0 state changed to 1
log.js:72  2024-02-10T14:34:33.489Z DEBUG: <body rid="7557281813" xmlns="http://jabber.org/protocol/httpbind" sid="5dd83f8cf9fb543552ef6e992277591cd74418a0"><iq from="kamga@pessek-ejabberd.com/conversejs" to="pessek-ejabberd.com" type="get" xmlns="jabber:client" id="618ae8ef-7c41-4ee8-8335-94c75cdf1094:sendIQ"><query xmlns="http://jabber.org/protocol/disco#items"/></iq></body>
log.js:72  2024-02-10T14:34:33.582Z DEBUG: request id 29.1 state changed to 2
log.js:72  2024-02-10T14:34:33.583Z DEBUG: request id 29.1 state changed to 3
log.js:72  2024-02-10T14:34:33.583Z DEBUG: request id 29.1 state changed to 4
log.js:72  2024-02-10T14:34:33.583Z DEBUG: removing request
log.js:72  2024-02-10T14:34:33.583Z DEBUG: _throttledRequestHandler called with 0 requests
log.js:72  2024-02-10T14:34:33.583Z DEBUG: request id 29 should now be removed
log.js:72  2024-02-10T14:34:33.583Z DEBUG: request id 29.1 got 200
log.js:72  2024-02-10T14:34:33.584Z DEBUG: Got responseText but no responseXML; attempting to parse it with DOMParser...
log.js:66  ERROR: invalid response received: This page contains the following errors:error on line 1 at column 196: Attribute type redefinedBelow is a rendering of the page up to the first error.
log.js:66  ERROR: responseText: <body type='terminate' condition='remote-stream-error' xmlns:stream='http://etherx.jabber.org/streams' type='terminate' condition='remote-stream-error' xmlns='http://jabber.org/protocol/httpbind'><iq xml:lang='en' to='kamga@pessek-ejabberd.com/conversejs' from='pessek-ejabberd.com' type='result' id='01eee6ac-6892-4dc6-9518-854c35340647:sendIQ' xmlns='jabber:client'><query xmlns='http://jabber.org/protocol/disco#info'><identity type='pep' category='pubsub'/><identity name='ejabberd' type='im' category='server'/><feature var='http://jabber.org/protocol/commands'/><feature var='http://jabber.org/protocol/disco#info'/><feature var='http://jabber.org/protocol/disco#items'/><feature var='http://jabber.org/protocol/offline'/><feature var='http://jabber.org/protocol/pubsub'/><feature var='http://jabber.org/protocol/pubsub#access-authorize'/><feature var='http://jabber.org/protocol/pubsub#access-open'/><feature var='http://jabber.org/protocol/pubsub#access-presence'/><feature var='http://jabber.org/protocol/pubsub#access-whitelist'/><feature var='http://jabber.org/protocol/pubsub#auto-create'/><feature var='http://jabber.org/protocol/pubsub#auto-subscribe'/><feature var='http://jabber.org/protocol/pubsub#collections'/><feature var='http://jabber.org/protocol/pubsub#config-node'/><feature var='http://jabber.org/protocol/pubsub#config-node-max'/><feature var='http://jabber.org/protocol/pubsub#create-and-configure'/><feature var='http://jabber.org/protocol/pubsub#create-nodes'/><feature var='http://jabber.org/protocol/pubsub#delete-items'/><feature var='http://jabber.org/protocol/pubsub#delete-nodes'/><feature var='http://jabber.org/protocol/pubsub#filtered-notifications'/><feature var='http://jabber.org/protocol/pubsub#get-pending'/><feature var='http://jabber.org/protocol/pubsub#instant-nodes'/><feature var='http://jabber.org/protocol/pubsub#item-ids'/><feature var='http://jabber.org/protocol/pubsub#last-published'/><feature var='http://jabber.org/protocol/pubsub#manage-subscriptions'/><feature var='http://jabber.org/protocol/pubsub#member-affiliation'/><feature var='http://jabber.org/protocol/pubsub#modify-affiliations'/><feature var='http://jabber.org/protocol/pubsub#multi-items'/><feature var='http://jabber.org/protocol/pubsub#outcast-affiliation'/><feature var='http://jabber.org/protocol/pubsub#persistent-items'/><feature var='http://jabber.org/protocol/pubsub#presence-notifications'/><feature var='http://jabber.org/protocol/pubsub#presence-subscribe'/><feature var='http://jabber.org/protocol/pubsub#publish'/><feature var='http://jabber.org/protocol/pubsub#publish-only-affiliation'/><feature var='http://jabber.org/protocol/pubsub#publish-options'/><feature var='http://jabber.org/protocol/pubsub#publisher-affiliation'/><feature var='http://jabber.org/protocol/pubsub#purge-nodes'/><feature var='http://jabber.org/protocol/pubsub#retract-items'/><feature var='http://jabber.org/protocol/pubsub#retrieve-affiliations'/><feature var='http://jabber.org/protocol/pubsub#retrieve-default'/><feature var='http://jabber.org/protocol/pubsub#retrieve-items'/><feature var='http://jabber.org/protocol/pubsub#retrieve-subscriptions'/><feature var='http://jabber.org/protocol/pubsub#shim'/><feature var='http://jabber.org/protocol/pubsub#subscribe'/><feature var='http://jabber.org/protocol/pubsub#subscription-notifications'/><feature var='http://jabber.org/protocol/rsm'/><feature var='http://jabber.org/protocol/stats'/><feature var='iq'/><feature var='jabber:iq:last'/><feature var='jabber:iq:privacy'/><feature var='jabber:iq:register'/><feature var='jabber:iq:version'/><feature var='msgoffline'/><feature var='presence'/><feature var='urn:xmpp:blocking'/><feature var='urn:xmpp:carbons:2'/><feature var='urn:xmpp:carbons:rules:0'/><feature var='urn:xmpp:mam:0'/><feature var='urn:xmpp:mam:1'/><feature var='urn:xmpp:mam:2'/><feature var='urn:xmpp:mam:tmp'/><feature var='urn:xmpp:ping'/><feature var='urn:xmpp:time'/><feature var='vcard-temp'/><x type='result' xmlns='jabber:x:data'><field var='FORM_TYPE' type='hidden'><value>http://jabber.org/network/serverinfo</value></field></x></query></iq><presence xml:lang='en' to='kamga@pessek-ejabberd.com/conversejs' from='kamga@pessek-ejabberd.com/conversejs' xmlns='jabber:client'><c xmlns='http://jabber.org/protocol/caps' hash='sha-1' node='https://conversejs.org' ver='bWAbgKReOpc5xmIvP67bt8JrPOE='/><x xmlns='vcard-temp:x:update'><photo>fde5b11cbad50c52376d5e3232cb6c5e138ba858</photo></x><priority>0</priority></presence><stream:error><conflict xmlns='urn:ietf:params:xml:ns:xmpp-streams'/><text xml:lang='en' xmlns='urn:ietf:params:xml:ns:xmpp-streams'>Replaced by new connection</text></stream:error></body>
bosh.js:97 Uncaught bad-format
	    at so.Request.getResponse (https://pessek-elgg431.com/cache/0/default/conversejs/dist/converse.min.js:2:120734)
	    at e._reqToData (https://pessek-elgg431.com/cache/0/default/conversejs/dist/converse.min.js:2:129733)
	    at Pl._dataRecv (https://pessek-elgg431.com/cache/0/default/conversejs/dist/converse.min.js:2:106010)
	    at e._onRequestStateChange (https://pessek-elgg431.com/cache/0/default/conversejs/dist/converse.min.js:2:127075)

regards,

rheman commented

I found the problem.
I have created a unique xmpp resource identifier for each browser tab and window.