[mosquitto-dev] Problem with loop integration when using connect_async()

[Jason Heeris <jason.heeris@xxxxxxxxx>]

Hi all,

I'm trying to integrate the Mosquitto client API with the Libuv event 
loop. For
the most part it's gone fine - I can get the socket with 
mosquitto_socket(),
create a Libuv poll handle from it and get single threaded event driven 
code.
Even the most minimal example I could write is a bit lengthy, so I've 
put it up
on Gitlab here: https://gitlab.com/detly/mosquitto-test

The outline of what I'm doing is:

Before starting the loop:

- call mosquitto_new(), set up client details, call mosquitto_connect()

- get the socket with mosquitto_socket()

- create and start a libuv uv_poll_t with the socket, firing when the 
socket is
 readable or writable (initially)

- create and start a timer to call mosquitto_loop_misc() periodically

I then start the loop and:

- when the poll handler fires, call mosquitto_read(), and 
mosquitto_write() if
 mosquitto_wants_write() is true

- update the events I'm listening for based on mosquitto_wants_write()

- when the timer fires, call mosquitto_loop_misc()

This all works fine, and is what's in the Gitlab project. Here's what 
my logging
shows when I run it:

15:56:36 INFO ../main_poll_readwrite.c:188: Started MQTT bridge
15:56:36 DEBUG ../common.h:55: Client 101010101010101 sending CONNECT
15:56:36 INFO ../main_poll_readwrite.c:213: Running libuv loop
15:56:36 TRACE ../main_poll_readwrite.c:163: Handling timer
15:56:36 TRACE ../main_poll_readwrite.c:180: T: No write needed
15:56:36 TRACE ../main_poll_readwrite.c:108: Poll on mosquitto socket
15:56:36 TRACE ../main_poll_readwrite.c:123: Handling read on mosquitto 
socket
15:56:36 TRACE ../main_poll_readwrite.c:147: P: Waiting for write
15:56:36 TRACE ../main_poll_readwrite.c:108: Poll on mosquitto socket
15:56:36 TRACE ../main_poll_readwrite.c:134: Handling write on 
mosquitto socket
15:56:36 TRACE ../main_poll_readwrite.c:152: P: No write needed
15:56:36 TRACE ../main_poll_readwrite.c:108: Poll on mosquitto socket
15:56:36 TRACE ../main_poll_readwrite.c:123: Handling read on mosquitto 
socket
15:56:36 TRACE ../main_poll_readwrite.c:152: P: No write needed
15:56:36 TRACE ../main_poll_readwrite.c:108: Poll on mosquitto socket
15:56:36 TRACE ../main_poll_readwrite.c:123: Handling read on mosquitto 
socket
15:56:36 DEBUG ../common.h:55: Client 101010101010101 received CONNACK 
(0)
15:56:36 DEBUG ../common.h:19: Mosquitto connect callback called: 0
15:56:36 TRACE ../main_poll_readwrite.c:152: P: No write needed
15:56:38 TRACE ../main_poll_readwrite.c:163: Handling timer
15:56:38 TRACE ../main_poll_readwrite.c:180: T: No write needed
15:56:40 TRACE ../main_poll_readwrite.c:163: Handling timer
15:56:40 TRACE ../main_poll_readwrite.c:180: T: No write needed
15:56:42 TRACE ../main_poll_readwrite.c:163: Handling timer
15:56:42 TRACE ../main_poll_readwrite.c:180: T: No write needed

The only issue is that the mosquitto_connect() call is blocking. In 
theory, it
*can* return before the connection is actually established, and usually 
does - I
don't see the CONNACK until the first poll (write?) callback. That's 
fine. But
if I use eg. netem under Linux to silently drop packets, the connect 
call seems
to block indefinitely.

The docs say not to use mosquitto_connect_async() unless I'm using
mosquitto_loop_start(), but then I found a comment on
https://github.com/eclipse/mosquitto/issues/1791 which says that it's 
fine.

So I tried switching to that, but immediately encountered a problem 
where

- mosquitto_wants_write() always returns true, so my poll handler fires 
on every
 run of the libuv loop

- this never actually results in a connection anyway, eventually I get 
an error
 19 (keepalive) and the disconnect handler is called

My logs now look like:

16:11:02 INFO ../main_poll_readwrite.c:188: Started MQTT bridge
16:11:02 DEBUG ../common.h:55: Client 101010101010101 sending CONNECT
16:11:02 INFO ../main_poll_readwrite.c:213: Running libuv loop
16:11:02 TRACE ../main_poll_readwrite.c:163: Handling timer
16:11:02 TRACE ../main_poll_readwrite.c:175: T: Waiting for write
16:11:02 TRACE ../main_poll_readwrite.c:108: Poll on mosquitto socket
16:11:02 TRACE ../main_poll_readwrite.c:134: Handling write on 
mosquitto socket
16:11:02 TRACE ../main_poll_readwrite.c:147: P: Waiting for write
[repeats thousands of times]
16:11:11 TRACE ../main_poll_readwrite.c:108: Poll on mosquitto socket
16:11:11 DEBUG ../common.h:27: Mosquitto disconnect callback called: 19
16:11:11 ERROR ../main_poll_readwrite.c:118: Error servicing mosquitto 
loop: 19
16:11:11 TRACE ../main_poll_readwrite.c:134: Handling write on 
mosquitto socket
16:11:11 DEBUG ../common.h:27: Mosquitto disconnect callback called: 4
16:11:11 ERROR ../main_poll_readwrite.c:139: Error writing to mosquitto 
socket: 4

Now, my server uses TLS on port 8883 with a self-signed certificate 
(due to no
domain name) and username/password authentication. I tried to test this 
issue on
test.mosquitto.org but (a) I couldn't get TLS to work (maybe an expired
certificate?) and (b) it doesn't allow for username/password auth. 
Testing with
no encryption on 1883, I couldn't reproduce the issue, so I think it has
something to do with one of those extra factors.

Am I using mosquitto's socket API correctly here? Or can anyone else 
reproduce
this? I'd appreciate any advice.

(I'm using Mosquitto 1.6.12 from the PPA on Ubuntu 20.04 and Libuv 
1.34.2.)

Thanks,
Jason