Mosquitto freezes when disconnects a client with a failing bridge configuration

[Rod-O]

Steps to reproduce:

• configure to bridge with TLS (I used azure iot hub)
• I set a wrong path for CA Cert
• start mosquitto - it will show ssl error on the bridge connection but it will start
• connect with a client
• close connection from the client
  FREEZE

[ralight]

I tried with this the following configuration:

listener 1883
  
connection tmo
address test.mosquitto.org:8883
capath /etc/ssl/certs
topic test in 1

Then running the broker as mosquitto -c m.conf -v the log looks like this:

1605306189: mosquitto version 1.6.12 starting
1605306189: Config loaded from b.conf.
1605306189: Opening ipv4 listen socket on port 1883.
1605306189: Opening ipv6 listen socket on port 1883.
1605306189: Connecting bridge tmo (test.mosquitto.org:8883)
1605306189: Bridge x250.tmo sending CONNECT
1605306189: mosquitto version 1.6.12 running
1605306189: Socket error on client local.x250.tmo, disconnecting.

I connected a client like this: mosquitto_sub -p 1883 -t \$SYS/broker/uptime -v

Which produced the log

1605306622: Connecting bridge tmo (test.mosquitto.org:8883)
1605306622: Bridge x250.tmo sending CONNECT
1605306623: New connection from 127.0.0.1 on port 1883.
1605306623: New client connected from 127.0.0.1 as mosq/MLiKqa19EDWvC5ROdL (p2, c1, k60).
1605306623: No will message specified.
1605306623: Sending CONNACK to mosq/MLiKqa19EDWvC5ROdL (0, 0)
1605306623: Received SUBSCRIBE from mosq/MLiKqa19EDWvC5ROdL
1605306623:     $SYS/broker/uptime (QoS 0)
1605306623: mosq/MLiKqa19EDWvC5ROdL 0 $SYS/broker/uptime
1605306623: Sending SUBACK to mosq/MLiKqa19EDWvC5ROdL
1605306623: Sending PUBLISH to mosq/MLiKqa19EDWvC5ROdL (d0, q0, r1, m0, '$SYS/broker/uptime', ... (9 bytes))

I then quit the client and reconnected it, giving this log:

1605306703: New connection from 127.0.0.1 on port 1883.
1605306703: New client connected from 127.0.0.1 as mosq/QdMDqKqTC3g2McxzXP (p2, c1, k60).
1605306703: No will message specified.
1605306703: Sending CONNACK to mosq/QdMDqKqTC3g2McxzXP (0, 0)
1605306703: Received SUBSCRIBE from mosq/QdMDqKqTC3g2McxzXP
1605306703:     $SYS/broker/uptime (QoS 0)
1605306703: mosq/QdMDqKqTC3g2McxzXP 0 $SYS/broker/uptime
1605306703: Sending SUBACK to mosq/QdMDqKqTC3g2McxzXP
1605306703: Sending PUBLISH to mosq/QdMDqKqTC3g2McxzXP (d0, q0, r1, m0, '$SYS/broker/uptime', ... (9 bytes))

So it didn't freeze for me. What am I doing differently to you?

[Rod-O]

I'm using a raspberry pi, I'm using a ca cert Get Outlook for Android<https://aka.ms/ghei36>

…

________________________________ From: Roger Light <[email protected]> Sent: Friday, November 13, 2020 5:36:49 PM To: eclipse/mosquitto <[email protected]> Cc: Rodolfo Ochoa <[email protected]>; Author <[email protected]> Subject: Re: [eclipse/mosquitto] Mosquitto freezes when disconnects a client with a failing bridge configuration (#1897) I tried with this the following configuration: listener 1883 connection tmo address test.mosquitto.org:8883 capath /etc/ssl/certs topic test in 1 Then running the broker as mosquitto -c m.conf -v the log looks like this: 1605306189: mosquitto version 1.6.12 starting 1605306189: Config loaded from b.conf. 1605306189: Opening ipv4 listen socket on port 1883. 1605306189: Opening ipv6 listen socket on port 1883. 1605306189: Connecting bridge tmo (test.mosquitto.org:8883) 1605306189: Bridge x250.tmo sending CONNECT 1605306189: mosquitto version 1.6.12 running 1605306189: Socket error on client local.x250.tmo, disconnecting. I connected a client like this: mosquitto_sub -p 1883 -t \$SYS/broker/uptime -v Which produced the log 1605306622: Connecting bridge tmo (test.mosquitto.org:8883) 1605306622: Bridge x250.tmo sending CONNECT 1605306623: New connection from 127.0.0.1 on port 1883. 1605306623: New client connected from 127.0.0.1 as mosq/MLiKqa19EDWvC5ROdL (p2, c1, k60). 1605306623: No will message specified. 1605306623: Sending CONNACK to mosq/MLiKqa19EDWvC5ROdL (0, 0) 1605306623: Received SUBSCRIBE from mosq/MLiKqa19EDWvC5ROdL 1605306623: $SYS/broker/uptime (QoS 0) 1605306623: mosq/MLiKqa19EDWvC5ROdL 0 $SYS/broker/uptime 1605306623: Sending SUBACK to mosq/MLiKqa19EDWvC5ROdL 1605306623: Sending PUBLISH to mosq/MLiKqa19EDWvC5ROdL (d0, q0, r1, m0, '$SYS/broker/uptime', ... (9 bytes)) I then quit the client and reconnected it, giving this log: 1605306703: New connection from 127.0.0.1 on port 1883. 1605306703: New client connected from 127.0.0.1 as mosq/QdMDqKqTC3g2McxzXP (p2, c1, k60). 1605306703: No will message specified. 1605306703: Sending CONNACK to mosq/QdMDqKqTC3g2McxzXP (0, 0) 1605306703: Received SUBSCRIBE from mosq/QdMDqKqTC3g2McxzXP 1605306703: $SYS/broker/uptime (QoS 0) 1605306703: mosq/QdMDqKqTC3g2McxzXP 0 $SYS/broker/uptime 1605306703: Sending SUBACK to mosq/QdMDqKqTC3g2McxzXP 1605306703: Sending PUBLISH to mosq/QdMDqKqTC3g2McxzXP (d0, q0, r1, m0, '$SYS/broker/uptime', ... (9 bytes)) So it didn't freeze for me. What am I doing differently to you? — You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub<#1897 (comment)>, or unsubscribe<https://github.com/notifications/unsubscribe-auth/AAB7OW5P4IPIR7C42R2XE3DSPWYIDANCNFSM4TVC4Y5A>.

[Rod-O]

Bridge configuration

connection azureiot-bridge
log_type all
address myHub.azure-devices.net:8883
remote_username myHub.azure-devices.net/1/?api-version=2018-06-30
remote_clientid 1

Wrong path:

bridge_cafile /etc/mosquitto/ca_cicates/IoTHubRootCA_Baltimore.pem
try_private false
cleansession true
start_type automatic
bridge_insecure false
bridge_protocol_version mqttv311

[Rod-O]

Error log:

1605543867: Connecting bridge (step 1) azureiot-bridge (myHub.azure-devices.net:8883)
1605543867: Connecting bridge (step 2) azureiot-bridge (myHub.azure-devices.net:8883)
1605543867: Error: Unable to load CA certificates, check bridge_cafile "/etc/mosquitto/ca_cicates/IoTHubRootCA_Baltimore.pem".
1605543867: OpenSSL Error: error:02001002:system library:fopen:No such file or directory
1605543867: OpenSSL Error: error:2006D080:BIO routines:BIO_new_file:no such file
1605543867: OpenSSL Error: error:0B084002:x509 certificate routines:X509_load_cert_crl_file:system lib

[karlp]

is this just another aspect of the bridge connection code being sync and blocking? see #1530 and others?

[Rod-O]

Yes, in my case, the thread consumes 100% of the processor, and the broker is unusable.
I think this happen AFTER I connect/disconnect a client to the broker.

[ralight]

Thanks for the good description. This was nothing to do with blocking connections. What was happening was on the error condition, the bridge wasn't being removed from the socket hash, then when a new client connected it would create a duplicate entry in the hash table and when we tried to iterate through the table it got stuck. I've made a fix, it'll be part of 1.6.13 and 2.0 in due course.

[ralight]

Closing thanks to the above fix.