SASL `AUTH_ANON` failing in 4.3.1 and embedded daemon.

[brett-smith]

It looks like #214 or #215 might have broken anonymous SASL authentication. As far as I can make out, only with the EmbeddedDBusDaemon though.

We are seeing the following with 4.3.1-SNAPSHOT builds.

org.freedesktop.dbus.exceptions.AuthenticationException: Failed to authenticate
	at org.freedesktop.dbus.connections.transports.AbstractTransport.authenticate(AbstractTransport.java:200)
	at org.freedesktop.dbus.connections.transports.AbstractTransport.internalConnect(AbstractTransport.java:174)
	at org.freedesktop.dbus.connections.transports.AbstractTransport.connect(AbstractTransport.java:133)
	at org.freedesktop.dbus.connections.transports.TransportBuilder.build(TransportBuilder.java:339)
	at org.freedesktop.dbus.connections.AbstractConnection.<init>(AbstractConnection.java:117)
	at org.freedesktop.dbus.connections.impl.DBusConnection.<init>(DBusConnection.java:85)

The dbus daemon log ...

01 Jul 2023 22:50:41,620 [EmbeddedDBusDaemon-unix:path=/tmp/logonbox-vpn-client/dbus-78677877848674888367] TRACE SASL  - Mode: SERVER AUTH state: INITIAL_STATE
01 Jul 2023 22:50:41,651 [EmbeddedDBusDaemon-unix:path=/tmp/logonbox-vpn-client/dbus-78677877848674888367] TRACE SASL  - Mode: SERVER AUTH state: WAIT_AUTH
01 Jul 2023 22:50:41,651 [EmbeddedDBusDaemon-unix:path=/tmp/logonbox-vpn-client/dbus-78677877848674888367] TRACE SASL  - received: AUTH
01 Jul 2023 22:50:41,652 [EmbeddedDBusDaemon-unix:path=/tmp/logonbox-vpn-client/dbus-78677877848674888367] TRACE SASL$Command  - Creating command from: [AUTH]
01 Jul 2023 22:50:41,653 [EmbeddedDBusDaemon-unix:path=/tmp/logonbox-vpn-client/dbus-78677877848674888367] TRACE SASL$Command  - Created command: Command(AUTH, 0, null)
01 Jul 2023 22:50:41,653 [EmbeddedDBusDaemon-unix:path=/tmp/logonbox-vpn-client/dbus-78677877848674888367] TRACE SASL  - sending: REJECTED EXTERNAL

01 Jul 2023 22:50:41,653 [EmbeddedDBusDaemon-unix:path=/tmp/logonbox-vpn-client/dbus-78677877848674888367] TRACE SASL  - Mode: SERVER AUTH state: WAIT_AUTH
01 Jul 2023 22:50:41,673 [EmbeddedDBusDaemon-unix:path=/tmp/logonbox-vpn-client/dbus-78677877848674888367] TRACE SASL  - received: AUTH EXTERNAL 353031
01 Jul 2023 22:50:41,673 [EmbeddedDBusDaemon-unix:path=/tmp/logonbox-vpn-client/dbus-78677877848674888367] TRACE SASL$Command  - Creating command from: [AUTH, EXTERNAL, 353031]
01 Jul 2023 22:50:41,673 [EmbeddedDBusDaemon-unix:path=/tmp/logonbox-vpn-client/dbus-78677877848674888367] TRACE SASL$Command  - Created command: Command(AUTH, 1, 353031)
01 Jul 2023 22:50:41,674 [EmbeddedDBusDaemon-unix:path=/tmp/logonbox-vpn-client/dbus-78677877848674888367] TRACE SASL  - sending: REJECTED EXTERNAL

01 Jul 2023 22:50:41,674 [EmbeddedDBusDaemon-unix:path=/tmp/logonbox-vpn-client/dbus-78677877848674888367] TRACE SASL  - Mode: SERVER AUTH state: WAIT_AUTH
01 Jul 2023 22:50:41,689 [EmbeddedDBusDaemon-unix:path=/tmp/logonbox-vpn-client/dbus-78677877848674888367] DEBUG EmbeddedDBusDaemon  - Connection closed
org.freedesktop.dbus.exceptions.SocketClosedException: Stream unexpectedly short (broken pipe)
	at org.freedesktop.dbus.connections.SASL.receive(SASL.java:260)
	at org.freedesktop.dbus.connections.SASL.auth(SASL.java:645)
	at org.freedesktop.dbus.connections.transports.AbstractTransport.authenticate(AbstractTransport.java:199)
	at org.freedesktop.dbus.connections.transports.AbstractTransport.internalConnect(AbstractTransport.java:174)
	at org.freedesktop.dbus.connections.transports.AbstractTransport.listen(AbstractTransport.java:165)
	at org.freedesktop.dbus.bin.EmbeddedDBusDaemon.startListening(EmbeddedDBusDaemon.java:213)
	at org.freedesktop.dbus.bin.EmbeddedDBusDaemon.startInForeground(EmbeddedDBusDaemon.java:73)
	at java.base/java.lang.Thread.run(Thread.java:1623)

And the client log ...

01 Jul 2023 22:23:26,562 [main] INFO  TransportBuilder  - Using transport dbus-java-transport-native-unixsocket for address unix:path=/tmp/logonbox-vpn-client/dbus-75837068818375697071,guid=060f2c0ffa22cd08d9e769b1e9a662d1
01 Jul 2023 22:23:26,563 [main] TRACE SASL  - Mode: CLIENT AUTH state: INITIAL_STATE
01 Jul 2023 22:23:26,565 [main] TRACE SASL  - sending: AUTH

01 Jul 2023 22:23:26,566 [main] TRACE SASL  - Mode: CLIENT AUTH state: WAIT_DATA
01 Jul 2023 22:23:26,567 [main] TRACE SASL  - received: REJECTED EXTERNAL
01 Jul 2023 22:23:26,567 [main] TRACE SASL$Command  - Creating command from: [REJECTED, EXTERNAL]
01 Jul 2023 22:23:26,568 [main] TRACE SASL$Command  - Created command: Command(REJECTED, 1, null)
01 Jul 2023 22:23:26,569 [main] TRACE SASL  - sending: AUTH EXTERNAL 353031

01 Jul 2023 22:23:26,569 [main] TRACE SASL  - Mode: CLIENT AUTH state: WAIT_DATA
01 Jul 2023 22:23:26,576 [main] TRACE SASL  - received: REJECTED EXTERNAL
01 Jul 2023 22:23:26,577 [main] TRACE SASL$Command  - Creating command from: [REJECTED, EXTERNAL]
01 Jul 2023 22:23:26,577 [main] TRACE SASL$Command  - Created command: Command(REJECTED, 1, null)
01 Jul 2023 22:23:26,578 [main] DEBUG DBusConnection  - Error creating transport
org.freedesktop.dbus.exceptions.AuthenticationException: Failed to authenticate
	at org.freedesktop.dbus.connections.transports.AbstractTransport.authenticate(AbstractTransport.java:200)

Edit: It appears this may not be happening everywhere. I have this reproduced on Mac OS at the moment, but windows seems OK. I can't think why this would be! The one thing I do know is that is has broken somewhere between 4.2.1 and 4.3.1-SNAPSHOT. Will update with further details if i get them.

Edit: Stranger and stranger. It appears to be OK if the broker and the client are both root (perhaps just need to be same user).

Edit: Changed my mind about #214 and #215. I've revert all those commits, and it still happens. So I suspect it may be something earlier. I'll keep bisecting.

Edit: Not got to it yet, despite trrying a number of different SASL related commits.

Edit: Ah ha! Got it. It was commit fe43125. I'll post back when I understand more what that was all about.

Edit: Well I'm baffled. It's definitely that commit that changed the behavior, but I can't see what is causing it.

[Prototik]

Are you sure both client & server running under the same user uid? I can see client tries to authenticate with uid of 501, is the server up and running with this uid as well?

Wait, I just read title. In the provided logs no anonymous auth is being used, it uses EXTERNAL auth.
In order to force it to be anonymous auth you should use smth like this:

builder.transportConfig().configureSasl().withAuthMode(TransportBuilder.SaslAuthMode.AUTH_ANONYMOUS);

[brett-smith]

That doesn't seem to have made any difference. I'm not able to get full logs again at the moment, but I'll post back later in the day when I have them.

With version 4.2.1 though (and every version prior to fe43125), I have never had to set the auth mode on the client side of the connection.

On the broker side, I just did this ..

daemon = new EmbeddedDBusDaemon(listenBusAddress);
daemon.setSaslAuthMode(SaslAuthMode.AUTH_ANONYMOUS);
daemon.startInBackground();

and it just worked.

[Prototik]

I mean that code for server side for sure, not for client. But I use DirectConnection directly, without a wrapper of EmbeddedDBusDaemon.

[hypfvieh]

This seems to be an issue with setting up the SaslAuthMode on both client and server side.
The SaslConfig object is created multiple times. While the setter will update the first object, this isn't the object passed to the SASL class.

I investigated this and fixed the builder setup.
Additionally the auth mode was overwritten by the transport. This was implemented to ensure that the default auth mode works for the used transport. There were some checks which were useless (comparing the already changed SaslConfig with a "new" SaslConfig) and therefore the auth mode was always reset to "default" (EXTERNAL when using unix sockets). I fixed that as well.

Please try again with the latest changes.
btw. I'm not sure, but usually GitHub-Actions should now deploy to maven central snapshot repo when I update the master branch.

[brett-smith]

Perfect, that has done the trick. I'm now seeing ANONYMOUS mentioned in the SASL logs, and all clients regardless get authenticated regardless of user ID.

Thanks once more for your time.

And yes! Maven snapshot repositories are definitely there. I wiped my local repository and rebuilt, and saw that all dbus-java modules were pulled from oss-snapshots. This will be very useful in the future, so thanks for doing that.

[hypfvieh]

I guess this one if fixed for a while - closing it. If still not working, please re-open