UNIX socket vs localhost performance differences

[fpagliughi]

After implementing the UNIX-domain socket support, I was surprised at the difference in performance between the UNIX sockets and TCP over localhost. I would normally expect a 20-50% improvement with UNIX sockets, but was seeing substantially more than that with the Paho client - like a 90% drop in latency for small that just emit a few messages and close.

So as a quick test to compare performance, I created a simple MQTT client to (1) create a client, (2) connect, (3) publish a single 1kB messages, and then (4) disconnect. I then ran it with a locahost TCP URL and then a UNIX socket URL. Here's how a few runs compared, with all times given in milliseconds:

$ ./pubtime mqtt://localhost:1883

Create,Connect,Publish,Disconnect, Total
 3.262, 12.038,  0.894,     0.270, 16.471
 0.636, 10.710,  0.344,     0.125, 11.817
 0.620, 10.724,  0.256,     0.166, 11.768
 0.647, 10.688,  0.284,     0.120, 11.742
 0.665, 10.628,  0.256,     0.122, 11.674
 0.680, 10.699,  0.328,     0.095, 11.805
 0.650, 11.067,  0.977,     0.324, 13.024
 0.626, 10.741,  0.282,     0.126, 11.778


$ ./pubtime unix:///tmp/mosquitto.sock

Create,Connect,Publish,Disconnect, Total
 0.713,  0.390,  0.280,     0.144, 1.529
 0.697,  0.386,  0.309,     0.128, 1.523
 0.670,  0.311,  0.308,     0.111, 1.403
 4.095,  1.418,  0.773,     0.263, 6.557
 0.634,  0.374,  0.246,     0.114, 1.371
 3.351,  1.198,  0.841,     0.200, 5.598
 0.631,  0.384,  0.296,     0.050, 1.364
 0.706,  0.405,  0.272,     0.153, 1.538

So the major performance difference appears to be the call to connect!

Some info and disclaimers:

• The test used the Paho C++ v1.5.0 client, which is just a thin wrapper around this library
• The connect and publish times are the full, round-trip time to complete and receive the CONNACK and PUBACK, respectively
• This was run on a modern/fast laptop running Linux Mint 21 (Ubuntu 22.04)
• All of these were run using Mosquitto v2.0.20 as the broker on the local machine.

[fpagliughi]

As a sanity check, I also ran wireshark during a localhost test. It showed a 0.093ms response time for the connect call, as the difference in the timestamps between the CONNECT and CONNACK packets.

"171","98.265568050","127.0.0.1","127.0.0.1","MQTT","80","Connect Command"
"173","98.265661491","127.0.0.1","127.0.0.1","MQTT","70","Connect Ack"

So the 10ms client time is not from the server being slow to respond.

[fpagliughi]

Here is a log dump of a TCP run...

=====================================
                   Trace Output
Product name: Eclipse Paho Asynchronous MQTT C Client Library
Version: 1.3.14
Build level: 2025-01-12T20:58:56Z
OpenSSL version: OpenSSL 3.0.2 15 Mar 2022
OpenSSL flags: compiler: gcc -fPIC -pthread -m64 -Wa,--noexecstack -Wall -Wa,--noexecstack -g -O2 -ffile-prefix-map=/build/openssl-aGUoHt/openssl-3.0.2=. -flto=auto -ffat-lto-objects -flto=auto -ffat-lto-objects -fstack-protector-strong -Wformat -Werror=format-security -DOPENSSL_TLS_SECURITY_LEVEL=2 -DOPENSSL_USE_NODELETE -DL_ENDIAN -DOPENSSL_PIC -DOPENSSL_BUILDING_OPENSSL -DNDEBUG -Wdate-time -D_FORTIFY_SOURCE=2
OpenSSL build timestamp: built on: Tue Aug 20 17:27:32 2024 UTC
OpenSSL platform: platform: debian-amd64
OpenSSL directory: OPENSSLDIR: "/usr/lib/ssl"
/proc/version: Linux version 6.8.0-51-generic (buildd@lcy02-amd64-057) (x86_64-linux-gnu-gcc-12 (Ubuntu 12.3.0-1ubuntu1~22.04) 12.3.0, GNU ld (GNU Binutils for Ubuntu) 2.38) #52~22.04.1-Ubuntu SMP PREEMPT_DYNAMIC Mon Dec  9 15:00:52 UTC 2

=========================================================
20250115 171432.391 0 commands restored for client 
20250115 171432.391 0 queued messages restored for client 
20250115 171432.392 Connecting to serverURI localhost:1883 with MQTT version 4
20250115 171432.393 New socket 3 for localhost:1883, port 1883
20250115 171432.393 Connect pending
20250115 171432.393 Waiting on send_cond
20250115 171432.403 Done waiting on send_cond         <--- ***** This is the 10ms delay! *****
20250115 171432.403 Waiting on send_cond
20250115 171432.403 Return code 0 from poll
20250115 171432.403 m->c->connect_state = 1
20250115 171432.403 3  -> CONNECT version 4 clean: 1 (0)
20250115 171432.404 Return code 1 from poll
20250115 171432.404 m->c->connect_state = 4
20250115 171432.404 queueChar: index is now 1, headerlen 1
20250115 171432.404 queueChar: index is now 2, headerlen 2
20250115 171432.404 3  <- CONNACK rc: 0
20250115 171432.404 0 inflight messages deleted for client 
20250115 171432.404 0 responses removed for client 
20250115 171432.404 Calling connect success for client 
20250115 171432.404 Done waiting on send_cond
20250115 171432.404 Waiting on send_cond
20250115 171432.404 Done waiting on send_cond
20250115 171432.404 3  -> PUBLISH msgid: 1 qos: 1 retained: 0 rc 0 payload len(1024): aaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
20250115 171432.405 Waiting on send_cond
20250115 171432.405 Return code 1 from poll
20250115 171432.405 m->c->connect_state = 0
20250115 171432.405 queueChar: index is now 1, headerlen 1
20250115 171432.405 queueChar: index is now 2, headerlen 2
20250115 171432.405 3  <- PUBACK msgid: 1
20250115 171432.405 PUBACK received from client  for message id 1 - removing publication
20250115 171432.405 Calling publish success for client 
20250115 171432.405 Done waiting on send_cond
20250115 171432.405 Waiting on send_cond
20250115 171432.405 Done waiting on send_cond
20250115 171432.405 3  -> DISCONNECT (0)
20250115 171432.405 Removed socket 3
20250115 171432.405 Removed socket 3
20250115 171432.405 0 inflight messages deleted for client 
20250115 171432.405 0 responses removed for client 
20250115 171432.405 Calling disconnect complete for client 
20250115 171432.405 Waiting on send_cond
20250115 171432.405 Return code 1 from poll
20250115 171432.406 Could not find client corresponding to socket 3
Create,Connect,Publish,Disconnect,Total
4.545,12.766,1.078,0.531,18.927
20250115 171432.406 0 inflight messages deleted for client 
20250115 171432.406 0 responses removed for client 
20250115 171432.406 0 responses removed for client 
20250115 171432.406 0 commands removed for client 
20250115 171432.406 Removed client  from bstate->clients, socket 0
20250115 171432.406 Conn_count is 0
20250115 171432.406 sleeping
20250115 171432.416 Done waiting on send_cond

This seems to be the main delay: The connect is waiting on a condition variable that probably isn't being signaled and instead is likely waiting on a 10ms timeout to continue (from above):

20250115 171432.393 Connect pending
20250115 171432.393 Waiting on send_cond
20250115 171432.403 Done waiting on send_cond         <--- ***** This is the 10ms delay! *****

The UNIX socket run doesn't have that delay (partial log dump):

20250115 172257.715 Connecting to serverURI /tmp/mosquitto.sock with MQTT version 4
20250115 172257.715 New UNIX socket 3 for /tmp/mosquitto.sock
20250115 172257.715 3  -> CONNECT version 4 clean: 1 (0)
20250115 172257.715 Waiting on send_cond
20250115 172257.715 Return code 1 from poll
20250115 172257.715 m->c->connect_state = 4
20250115 172257.715 queueChar: index is now 1, headerlen 1
20250115 172257.715 queueChar: index is now 2, headerlen 2
20250115 172257.715 3  <- CONNACK rc: 0
20250115 172257.715 0 inflight messages deleted for client 
20250115 172257.715 0 responses removed for client 
20250115 172257.715 Calling connect success for client 
20250115 172257.715 Done waiting on send_cond
20250115 172257.715 Waiting on send_cond
20250115 172257.715 Done waiting on send_cond