search

processone / ejabberd

Robust, Ubiquitous and Massively Scalable Messaging Platform (XMPP, MQTT, SIP Server)
https://www.process-one.net/en/ejabberd/
Other
6.06k stars 1.51k forks source link

ejabberd 23.01 mod_bosh; XEP-0124: Bidirectional-streams Over Synchronous HTTP (BOSH) is not working #3995

Closed cmeng-git closed 1 year ago

cmeng-git commented 1 year ago

Before creating a ticket, please consider if this should fit the discussion forum better: https://github.com/processone/ejabberd/discussions

Environment

ejabberd version: 23.01 Erlang version: Erlang/OTP 22 [erts-10.6.4] / Eshell V10.6.4 OS: Linux (Debian): Ubuntu 20.04 Installed from: source

Configuration (only if needed): grep -Ev '^$|^\s*#' ejabberd.yml

loglevel: 5
listen:
  -
    port: 5443
    ip: "::"
    module: ejabberd_http
    tls: true
    request_handlers:
      /admin: ejabberd_web_admin
      /api: mod_http_api
      /bosh: mod_bosh
      /captcha: ejabberd_captcha
      /upload: mod_http_upload
      ## /register: mod_register_web
      /xmpp: ejabberd_http_ws

modules:
  mod_bosh: {}```

## Errors from error.log/crash.log

No errors / No response

## Bug description
After upgraded ejabberd to version 23.01 (from version 20.12), decided to retest mod-bosh operation i.e.
XEP-0124: Bidirectional-streams Over Synchronous HTTP (BOSH)
support on the latest ejabberd 23.01, but found aTalk login using BOSH protocol is no further working.
below are the captured debug log from both aTalk logcat and ejaberd log. Based on the log info:

It was found that after aTalk has initialised a BOSH Session and received by ejabberd, there is no response received from ejabberd even after a 30 seconds wait, and the login on aTalk failed.

aTalk last BOSH protocol tested working was in Nov 2019.
Please advice how to proceed from here to find the actual root cause.  I still have the old ejabberd version 18.09 in /usr/local/lib/. Would you advice to revert to old version for reconfirmation; if so how do I revert to use the old version?

// =========== logcat on aTalk ============ 2023-02-18 09:28:36.016 5540-6349/org.atalk.android I/(ProtocolProviderServiceJabberImpl.java:1180)#connectAndLogin: Starting XMPP Connection...: null 2023-02-18 09:28:36.022 5540-6349/org.atalk.android I/aTalk: [160] org.igniterealtime.jbosh.BOSHClient.init() Starting with 1 request processors 2023-02-18 09:28:36.023 5540-6349/org.atalk.android D/SMACK: SENT (9):

2023-02-18 09:29:06.023 5540-6349/org.atalk.android E/(ProtocolProviderServiceJabberImpl.java:1210)#connectAndLogin: Encounter problem during XMPP Connection: No response received within reply timeout. Timeout was 30000ms (~30s). While waiting for SASL mechanisms stream feature from server [XMPPBOSHConnection[not-authenticated] (9)] 2023-02-18 09:29:06.023 5540-6349/org.atalk.android E/(ProtocolProviderServiceJabberImpl.java:768)#reRegister: Error ReRegistering: XMPPError: remote-server-timeout - wait [Encounter problem during XMPP Connection: No response received within reply timeout. Timeout was 30000ms (~30s). While waiting for SASL mechanisms stream feature from server [XMPPBOSHConnection[not-authenticated] (9)]] 2023-02-18 09:29:06.024 5540-6349/org.atalk.android D/(AbstractProtocolProviderService.java:140)#fireRegistrationStateChanged: The provider state changed: RegistrationState = Registering => RegistrationState = Connection Failed. Reason: XMPPError: remote-server-timeout - wait [Encounter problem during XMPP Connection: No response received within reply timeout. Timeout was 30000ms (~30s). While waiting for SASL mechanisms stream feature from server [XMPPBOSHConnection[not-authenticated] (9)]] 2023-02-18 09:29:06.024 5540-6349/org.atalk.android D/(ProtocolProviderServiceJabberImpl.java:749)#reRegister: SMACK: Trying to re-register account!

// =========== Log on ejabberd ============ 2023-02-18 09:27:45.619960+08:00 [debug] PROGRESS REPORT: application: stun started_at: ejabberd@localhost 2023-02-18 09:27:46.354357+08:00 [debug] All applications are intact 2023-02-18 09:28:36.737550+08:00 [info] (<0.696.0>) Accepted connection [::ffff:42.60.99.32]:52468 -> [::ffff:192.168.1.8]:5443 2023-02-18 09:28:36.739112+08:00 [debug] S: [{[<<"admin">>],ejabberd_web_admin}, {[<<"api">>],mod_http_api}, {[<<"bosh">>],mod_bosh}, {[<<"captcha">>],ejabberd_captcha}, {[<<"upload">>],mod_http_upload}, {[<<"xmpp">>],ejabberd_http_ws}]

2023-02-18 09:28:36.794292+08:00 [debug] ({tlssock,#Port<0.89>,#Ref<0.1466853312.1278869505.125137>}) http query: 'POST' <<"/http-bind">>

cmeng-git commented 1 year ago

Found aTalk is also having problem; aTalk BOSH source is not compatible with smack v4.4.6. After ported aTalk BOSH to be compatible with smack v4.4.6, BOSH is now tested working with an online free XMPP server i.e. trashserver.net

// ========= trashserver.net BOSH connection (aTalk logcat) ==========
2023-02-20 09:20:43.136 10338-10725/org.atalk.android D/SMACK: SENT (5): 
    <body ver='1.8' wait='60' xmpp:version='1.0' rid='4244244215175855' xmlns:xmpp='urn:xmpp:xbosh' hold='1' xml:lang='en' ack='1' to='trashserver.net' xmlns='http://jabber.org/protocol/httpbind'>
    </body>
2023-02-20 09:20:44.218 10338-10728/org.atalk.android D/SMACK: RECV (5): 
    <body xmpp:version='1.0' authid='6613043293285946933' xmlns='http://jabber.org/protocol/httpbind' sid='faed2331f9925b191d95aa6f57fb427da91d89c9' wait='60' ver='1.11' polling='2' inactivity='30' hold='1' xmpp:restartlogic='true' requests='2' secure='true' maxpause='120' xmlns:xmpp='urn:xmpp:xbosh' xmlns:stream='http://etherx.jabber.org/streams' from='trashserver.net'>
      <stream:features>
        <mechanisms xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>
          <mechanism>
            PLAIN
          </mechanism>
          <mechanism>
            SCRAM-SHA-1
          </mechanism>
        </mechanisms>
        <register xmlns='http://jabber.org/features/iq-register'/>
      </stream:features>
    </body>
2023-02-20 09:20:44.315 10338-10725/org.atalk.android D/SMACK: SENT (5): 
    <body rid='4244244215175856' sid='faed2331f9925b191d95aa6f57fb427da91d89c9' xmlns='http://jabber.org/protocol/httpbind'>
      <auth xmlns='urn:ietf:params:xml:ns:xmpp-sasl' mechanism='SCRAM-SHA-1'>
        bixhPWNtZW5nMUB0cmFzaHNlcnZlci5uZXQsbj1jbWVuZzEscj13aHNGdFU0fko+S0RlRmJTL0Y6Ty5hSnZ4PG5qYWFbeg==
      </auth>
    </body>

However aTalk is still having problem to make BOSH connection to ejabberd v23.01

// ========= ejabberd BOSH connection failed (aTalk logcat) ===========
2023-02-20 09:24:23.480 10338-10798/org.atalk.android D/SMACK: SENT (7): 
    <body ver='1.8' wait='60' xmpp:version='1.0' rid='5203705824475094' xmlns:xmpp='urn:xmpp:xbosh' hold='1' xml:lang='en' ack='1' to='atalk.sytes.net' xmlns='http://jabber.org/protocol/httpbind'>
    </body>
2023-02-20 09:24:23.583 10338-10829/org.atalk.android I/aTalk: [192] org.jivesoftware.smack.AbstractXMPPConnection.notifyConnectionError() Connection was already disconnected when attempting to handle org.igniterealtime.jbosh.BOSHException: Could not parse body:
    <?xml version='1.0'?>
    <!DOCTYPE html PUBLIC "-//W3C//DTD XHTML 1.0 Transitional//EN" "http://www.w3.org/TR/xhtml1/DTD/xhtml1-transitional.dtd">
    <html xmlns='http://www.w3.org/1999/xhtml' xml:lang='en' lang='en'><head><meta http-equiv='Content-Type' content='text/html; charset=utf-8'/></head><body><h1>404 Not Found</h1></body></html>
    org.igniterealtime.jbosh.BOSHException: Could not parse body:
    <?xml version='1.0'?>
    <!DOCTYPE html PUBLIC "-//W3C//DTD XHTML 1.0 Transitional//EN" "http://www.w3.org/TR/xhtml1/DTD/xhtml1-transitional.dtd">
    <html xmlns='http://www.w3.org/1999/xhtml' xml:lang='en' lang='en'><head><meta http-equiv='Content-Type' content='text/html; charset=utf-8'/></head><body><h1>404 Not Found</h1></body></html>
        at org.igniterealtime.jbosh.BodyParserXmlPull.parse(BodyParserXmlPull.java:132)
        at org.igniterealtime.jbosh.StaticBody.fromString(StaticBody.java:114)
        at org.igniterealtime.jbosh.ApacheHTTPResponse.awaitResponse(ApacheHTTPResponse.java:246)
        at org.igniterealtime.jbosh.ApacheHTTPResponse.getBody(ApacheHTTPResponse.java:192)
        at org.igniterealtime.jbosh.BOSHClient.processExchange(BOSHClient.java:1123)
        at org.igniterealtime.jbosh.BOSHClient.processMessages(BOSHClient.java:999)
        at org.igniterealtime.jbosh.BOSHClient.access$300(BOSHClient.java:100)
        at org.igniterealtime.jbosh.BOSHClient$RequestProcessor.run(BOSHClient.java:1728)
        at java.lang.Thread.run(Thread.java:1012)
     Caused by: java.lang.IllegalStateException: Root element was not 'body' in the 'http://jabber.org/protocol/httpbind' namespace.  (Was 'html' in 'http://www.w3.org/1999/xhtml')
        at org.igniterealtime.jbosh.BodyParserXmlPull.parse(BodyParserXmlPull.java:98)
        at org.igniterealtime.jbosh.StaticBody.fromString(StaticBody.java:114) 
        at org.igniterealtime.jbosh.ApacheHTTPResponse.awaitResponse(ApacheHTTPResponse.java:246) 
        at org.igniterealtime.jbosh.ApacheHTTPResponse.getBody(ApacheHTTPResponse.java:192) 
        at org.igniterealtime.jbosh.BOSHClient.processExchange(BOSHClient.java:1123) 
        at org.igniterealtime.jbosh.BOSHClient.processMessages(BOSHClient.java:999) 
        at org.igniterealtime.jbosh.BOSHClient.access$300(BOSHClient.java:100) 
        at org.igniterealtime.jbosh.BOSHClient$RequestProcessor.run(BOSHClient.java:1728) 
        at java.lang.Thread.run(Thread.java:1012) 
2023-02-20 09:24:23.584 10338-10798/org.atalk.android E/(ProtocolProviderServiceJabberImpl.java:1210)#connectAndLogin: Encounter problem during XMPP Connection:
    Timeout reached for the connection to null:-1.
2023-02-20 09:24:23.584 10338-10798/org.atalk.android E/(ProtocolProviderServiceJabberImpl.java:768)#reRegister: Error ReRegistering: XMPPError: remote-server-timeout - wait [Encounter problem during XMPP Connection:
    Timeout reached for the connection to null:-1.]
2023-02-20 09:24:23.585 10338-10798/org.atalk.android D/(AbstractProtocolProviderService.java:140)#fireRegistrationStateChanged: The provider state changed: RegistrationState = Registering => RegistrationState = Connection Failed. Reason: XMPPError: remote-server-timeout - wait [Encounter problem during XMPP Connection:
    Timeout reached for the connection to null:-1.]
2023-02-20 09:24:23.587 10338-10798/org.atalk.android D/(ProtocolProviderServiceJabberImpl.java:749)#reRegister: SMACK: Trying to re-register account!
// ========== ejabberd log traced (captured on reattempt) ======
2023-02-20 09:36:50.550883+08:00 [debug] S: [{[<<"admin">>],ejabberd_web_admin},
    {[<<"api">>],mod_http_api},
    {[<<"bosh">>],mod_bosh},
    {[<<"captcha">>],ejabberd_captcha},
    {[<<"upload">>],mod_http_upload},
    {[<<"xmpp">>],ejabberd_http_ws}]

2023-02-20 09:36:50.565783+08:00 [debug] ({tlssock,#Port<0.95>,#Ref<0.1700135346.2532179971.88024>}) http query: 'POST' <<"/http-bind">>
cmeng-git commented 1 year ago

Found the problem. It is aTalk bosh URL link incorrectly specified. The url link should be https://atalk.sytes.net:5443/bosh

It was incorrectly specified as https://atalk.sytes.net:5443/http-bind

Sorry for the inconvenience cause to your team.