Cannot connect to Openfire (TLS 1.3)

[netmikey]

Describe the bug Same issue as #592 when using starttls

Client Code

        this._client = client({
            service: 'xmpp://example.com:5222',
            resource: "some-resource",
            username: 'ANONYMOUS',
        });

Logs

status connecting xmpp://example.com:5222
status connect 
status opening 
status open <stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:client" from="example.com" id="1khlg8il52" xml:lang="en" version="1.0"/>
IN
<stream:features xmlns="http://etherx.jabber.org/streams"><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>PLAIN</mechanism><mechanism>ANONYMOUS</mechanism></mechanisms><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><ver xmlns="urn:xmpp:features:rosterver"/><c xmlns="http://jabber.org/protocol/caps" hash="sha-1" node="https://www.igniterealtime.org/projects/openfire/" ver="JiSz8RBGEqqFfx+GUdpJNXragQo="/></stream:features>
OUT
<starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>
IN
<proceed xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>
status opening 

TimeoutError
    at Timeout.<anonymous> (/node_modules/@xmpp/events/lib/promise.js:33:16)
    at listOnTimeout (internal/timers.js:549:17)
    at processTimers (internal/timers.js:492:7)
TimeoutError
    at Timeout.<anonymous> (/node_modules/@xmpp/events/lib/promise.js:33:16)
    at listOnTimeout (internal/timers.js:549:17)
    at processTimers (internal/timers.js:492:7)
(node:85777) UnhandledPromiseRejectionWarning: TimeoutError
    at Timeout.<anonymous> (/node_modules/@xmpp/events/lib/promise.js:33:16)
    at listOnTimeout (internal/timers.js:549:17)
    at processTimers (internal/timers.js:492:7)

Environment node v12.18.3 @xmpp/client v0.12.0 Server: Openfire 4.6.2, build b61bce3, configured with a valid TLS certificate for the domain I'm using. OS: macOS Catalina 10.15.7

As an additional note: when I connect Adium to that Openfire server, it also takes quite some time (~ 10-30sec) to establish the connection. I suppose this has to do with TLS checking / negotiation / whatever. Maybe the expected timeout just has to be raised?

[sonnyp]

xmpp.js default timeout is quite low at 2000ms we should probably raise it

But 10-30s seems unreasonable, any idea why it so slow?

Can you try this

client.timeout = 1000 * 60 // 1 minute

[netmikey]

Thanks for the hint!

First off: it looks like this is not related to #890.

I found that the reason my GUI clients "seem" to connect slowly is because of my setup where my Openfire server needs to load a bunch of users from a third party API in order to populate groups and roasters and that takes a couple of seconds when the first client connects. That doesn't seem to be related to this issue though.

I even tried to give it a timeout of 2 minutes, but it seems that it's stuck after the server's proceed message. Maybe there's something missing client side? Unfortunately, xmpp.js' debug component doesn't log the opening messages so I can't compare those to my other XMPP clients. Here's what I can compare:

xmpp.js:

status connecting xmpp://example.com:5222
status connect 
status opening 
status open <stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:client" from="example.com" id="14wt42x5gb" xml:lang="en" version="1.0"/>

IN
<stream:features xmlns="http://etherx.jabber.org/streams">
<starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>
<mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl">
<mechanism>PLAIN</mechanism>
<mechanism>ANONYMOUS</mechanism>
</mechanisms>
<compression xmlns="http://jabber.org/features/compress">
<method>zlib</method>
</compression>
<ver xmlns="urn:xmpp:features:rosterver"/>
<c xmlns="http://jabber.org/protocol/caps" hash="sha-1" node="https://www.igniterealtime.org/projects/openfire/" ver="PXeYICjasirLLF1A4CuJ8nUI6QI="/>
</stream:features>

OUT
<starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>

IN
<proceed xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>

status opening 

Psi:

OUT
<?xml version="1.0"?>
<stream:stream xmlns:stream="http://etherx.jabber.org/streams" to="example.com" version="1.0" xml:lang="en" xmlns:xml="http://www.w3.org/XML/1998/namespace" xmlns="jabber:client">

IN
<?xml version='1.0' encoding='UTF-8'?><stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:client" from="example.com" id="3jko8ht8qs" xml:lang="en" version="1.0">

<stream:features>
<starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>
<mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl">
<mechanism>PLAIN</mechanism>
<mechanism>ANONYMOUS</mechanism>
</mechanisms>
<compression xmlns="http://jabber.org/features/compress">
<method>zlib</method>
</compression>
<ver xmlns="urn:xmpp:features:rosterver"/>
<c xmlns="http://jabber.org/protocol/caps" hash="sha-1" node="https://www.igniterealtime.org/projects/openfire/" ver="PXeYICjasirLLF1A4CuJ8nUI6QI="/>
</stream:features>

OUT
<starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>

IN
<proceed xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>

OUT
<?xml version="1.0"?>

<stream:stream xmlns:stream="http://etherx.jabber.org/streams" to="example.com" version="1.0" xml:lang="en" xmlns:xml="http://www.w3.org/XML/1998/namespace" xmlns="jabber:client">

IN
<?xml version='1.0' encoding='UTF-8'?><stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:client" from="example.com" id="3jko8ht8qs" xml:lang="en" version="1.0">

[... stream continues here ...]

[sonnyp]

I can reproduce locally.

The same issue happens with direct TLS (service: "xmpps://localhost:5223",)

The issue does not happen with websocket (service: "ws://localhost:7070/ws/",) or secure websocket (service: "wss://localhost:7443/ws/",)

[sonnyp]

Unfortunately, xmpp.js' debug component doesn't log the stream:stream opening messages

You can do so with

xmpp.on("output", (data) => console.log("OUTPUT", data));

But I'm fairly confident the issue is related to tls instead.

[sonnyp]

I opened a topic on Openfire's community https://discourse.igniterealtime.org/t/help-xmpp-js-interoperate-with-openfire/89867

[netmikey]

Well, without starttls the xmpp:// connection to Openfire works. As a workaround, in my case, leaving out tls would be a viable solution (local area tcp, no confidential messages and only anonymous connections, so no credentials). However, I can't disable starttls support globally on the server because besides xmpp.js I do have a couple of authenticated regular clients. Is there a way to disable starttls on the xmpp.js client side?

[netmikey]

It seems like there's not a lot of drive from the Openfire community to push this forward.

@sonnyp Has there been any update on this from your side? Any other ideas? Maybe an idea on how to disable starttls on the xmpp.js client side as suggested above? I can help testing workarounds if you want. Unfortunately, I'm not knowledgable enough in the xmpp.js codebase to come up with a solution myself.

[sonnyp]

I don't have a solution for the TLS issue. You may find paid support for openfire https://www.igniterealtime.org/support/service_providers.jsp

Maybe an idea on how to disable starttls on the xmpp.js client side as suggested above?

Use @xmpp/client-core. Basically copy paste https://github.com/xmppjs/xmpp.js/blob/master/packages/client/index.js and remove @xmpp/starttls, @xmpp/tls, getDomain, (and anything else you don't need) from it.

[netmikey]

Thanks for your continued support, @sonnyp !

I've looked into this a bit more, here's what I found so far:

I don't think this is directly related to the raw low-level tls negotiation (after all, the actual implementation of the tls handshake is from nodejs on the client side and most probably the Java Virtual Machine on the Openfire server side. While not impossible, it is not very likely that these would be incompatible). The XMPP Specification describes in Section 5.4.3.3 point 3 that, after successful TLS negotiation, it is the initiating entity (the client in this case) who has to send the new <stream:stream> header. To see where we get stuck, I added a bunch of console outputs to @xmpp/starttls/client.js:

module.exports = function starttls({ streamFeatures }) {
  return streamFeatures.use("starttls", NS, async ({ entity }, next) => {
    const { socket } = entity;
    if (!canUpgrade(socket)) {
      return next();
    }

    await negotiate(entity);
    console.log('Upgrading now...');
    const tlsSocket = await upgrade(socket, { host: entity.options.domain });
    console.log('Got the tlsSocket, attaching it now...');
    entity._attachSocket(tlsSocket);

    console.log('Now restarting entity...');
    await entity.restart();
    console.log('Everything done!');
  });
};

Here's what I get at runtime:

status connecting xmpp://my-server:5222
status connect 
status opening 
status open <stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:client" from="my-server" id="3dwt29bofi" xml:lang="en" version="1.0"/>
IN
<stream:features xmlns="http://etherx.jabber.org/streams"><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>PLAIN</mechanism><mechanism>ANONYMOUS</mechanism><mechanism>SCRAM-SHA-1</mechanism><mechanism>CRAM-MD5</mechanism><mechanism>DIGEST-MD5</mechanism></mechanisms><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><ver xmlns="urn:xmpp:features:rosterver"/><register xmlns="http://jabber.org/features/iq-register"/><c xmlns="http://jabber.org/protocol/caps" hash="sha-1" node="https://www.igniterealtime.org/projects/openfire/" ver="R5VlkJvAupvLpTlV3X8ZXBqiZ+Q="/></stream:features>
OUT
<starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>
IN
<proceed xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>
Upgrading now...
Got the tlsSocket, attaching it now...
Now restarting entity...
status opening

So to me it clearly looks as if the TLS negotiation actually went through successfully, in fact if I dump the tlsSocket, it looks like a successfully established tls socket indeed. Following the Spec, I'm pretty sure I should see an "OUT" log with the <stream:stream> header after "status opening", but It's not showing up. Also, the final "Everything done!" log is never reached, so the entity.restart() promise never resolves... So right now, I'm guessing something in entity.restart() to be the culprit, and if it is, that would be a pure client thing...

What do you think?

[sonnyp]

You are debugging with starttls which I'm afraid will mislead you.

Debug with direct TLS instead service: "xmpps://..." openfire port may or may not be 5223

[netmikey]

status connecting xmpps://my-server:5223
status connect 
status opening 

So the behavior was the same. You were right about starttls confusing me: Trying to debug this with wireshark and the whole shebang, I stumbled upon another solution: disabling TLSv1.3 in Openfire also solves the problem. And sure enough, the same was true when re-testing it with starttls.

So maybe it is an incompatibility in the TLS implementations after all...

[netmikey]

While debugging TLS 1.3 handshakes with wireshark, I also found a workaround for this issue:

I turned on TLS debugging in nodejs and, captured the handshake in wireshark and debugged the xmpp.js and openfire code. Node's tls debug logging seems to indicate that (despite xmpp.js AND openfire both having finished their "tls-handshake" methods), part of the handshake seems to take place after xmpp.js sent the <stream> header:

status connecting xmpps://my-server:5223
TLS 77141: client _init handle? true
TLS 77141: client initRead handle? true buffered? false
status connect 
status opening 
writing header  <= <stream>...
TLS 77141: onkeylog
TLS 77141: onkeylog
TLS 77141: onkeylog
TLS 77141: onkeylog
TLS 77141: onkeylog
TLS 77141: client onhandshakedone
TLS 77141: client _finishInit handle? true alpn false servername false
returning promise after header written...
[stuck at this point, eventually times out]

The fact that TLS 1.3 moved the "session ticket" mechanism out of the handshake phase, doesn't really make things better (see this comment for a really good explanation).

Here's how it looks in wireshark:

Guessing that it must have something to do with the TLS 1.3 Handshake / Session Ticket racing the first packet in the encrypted channel, I simply added a packet with a single white space:

in @xmpp/connection/index.js' open method, around line 271:

await this.write(' '); // <= added this
await this.write(this.header(headerElement));

Funny enough, wireshark recognizes this as "whitespace keepalive" message within the XMPP protocol and... it solves that whole issue: just adding that single whitespace message, xmpp.js now connects to Openfire with TLS 1.3 just fine. Here's how it looks now:

status connecting xmpps://my-server:5223
TLS 77298: client _init handle? true
TLS 77298: client initRead handle? true buffered? false
status connect 
status opening 
writing whitespace keepalive
TLS 77298: onkeylog
TLS 77298: onkeylog
TLS 77298: onkeylog
TLS 77298: onkeylog
TLS 77298: onkeylog
TLS 77298: client onhandshakedone
TLS 77298: client _finishInit handle? true alpn false servername false
writing header  <= <stream>...
returning promise after header written...
status open <stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:client" from="my-server" id="3kxcaqv06v" xml:lang="en" version="1.0"/>
IN
<stream:features xmlns="http://etherx.jabber.org/streams">[...truncated for readability...]
OUT
<auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="ANONYMOUS"><hidden xmlns="xmpp.js"/></auth>
IN
<success xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/>
[... stream just goes on here...]

And in wireshark:

I think the impact of this one-liner is very minimal and it doesn't have side-effects other than making TLS 1.3 work. Do you think this could be added to xmpp.js?

[sonnyp]

Nice debugging work! Thanks for going through and sharing.

Do you think this could be added to xmpp.js?

Yes. I wished we could address the root cause, unfortunately I do not have the bandwidth to dig deeper and you've done great work on this issue already. Also, as you said, it comes at no cost so no reason not to improve interoperability :+1:

Feel free to to send a PR but please add a comment link to https://github.com/xmppjs/xmpp.js/issues/889#issuecomment-902686879

A test would be ideal but I'm happy to add it myself. In case you wanna give it a go:

git clone git@github.com:xmppjs/xmpp.js.git
cd xmpp.js
make
# add new test file `packages/connection/test/open.js`
npx ava packages/connection/test/open.js # run test

You can run make test to make sure there are no regressions. You can run make test-ci to run the full suite with integration tests (requires prosody).

But don't worry about the other tests, the PR will run through CI.

[netmikey]

I created #912 which doesn't break regression tests. It'd be great if you could take charge of the test.

[sonnyp]

Will do - thanks for the PR.

[sonnyp]

https://github.com/xmppjs/xmpp.js/releases/tag/v0.13.0

[guusdk]

For posterity: Openfire is tracking this issue as https://igniterealtime.atlassian.net/browse/OF-2435

Thanks for all of the debugging that went into this!