I've set up a Mosquitto broker for MQTT communications, but I can't even get it to work properly out of the box. After connecting and waiting for a bit the server resets the clients connection and displays 'Socket error on client .. , disconnecting.'
I've pretty much ruled out a client's fault as the error persists on using two different (MQTT.fx and mqtt-spy) client software.
Connection-timeout: 30
Keep-alive interval: 30
Mosquitto runs on the latest version (mosquitto version 1.4.2) and on stock configuration.
I perform the following actions:
EDIT:
Running through the code
static void loop_handle_reads_writes(struct mosquitto_db *db, struct pollfd *pollfds)
{
[...]
if(pollfds[context->pollfd_index].revents & POLLIN){
if(_mosquitto_packet_read(db, context)){
do_disconnect(db, context); <-- Line that causes disconnection
continue;
}
}
}
[...]
void do_disconnect(struct mosquitto_db *db, struct mosquitto *context)
{
char *id;
if(context->state == mosq_cs_disconnected){
return;
}
[...]
{
if(db->config->connection_messages == true){
if(context->id){
id = context->id;
}else{
id = "<unknown>";
}
if(context->state != mosq_cs_disconnecting){
_mosquitto_log_printf(NULL, MOSQ_LOG_NOTICE, "Socket error on client %s, disconnecting.", id);
}else{
_mosquitto_log_printf(NULL, MOSQ_LOG_NOTICE, "Client %s disconnected.", id);
}
}
mqtt3_context_disconnect(db, context);
[...]
if(context->clean_session){
mosquitto__add_context_to_disused(db, context);
if(context->id){
HASH_DELETE(hh_id, db->contexts_by_id, context);
_mosquitto_free(context->id);
context->id = NULL;
}
}
context->state = mosq_cs_disconnected;
}
}
Console log:
1433171947: New connection from 192.168.2.5 on port 1883.
1433171947: New client connected from 192.168.2.5 as testuser (c1, k30, u'testuser').
1433171947: Sending CONNACK to testuser (0, 0)
1433171954: Received PUBLISH from testuser (d0, q1, r1, m1, 'test', ... (4 bytes))
1433171954: Sending PUBACK to testuser (Mid: 1)
1433171984: Received PINGREQ from testuser
1433171984: Sending PINGRESP to testuser
1433172003: Socket error on client testuser, disconnecting.
Here are some packet captures of the 13 frames exchanged and the connection reset causing the socket error.
Server (192.168.2.15) capture transcript:
No. Time Source Destination Protocol Length Info
129 14.587072000 192.168.2.5 192.168.2.15 TCP 62 55176 > ibm-mqisdp [SYN] Seq=0 Win=8192 Len=0 MSS=1460 SACK_PERM=1
Frame 129: 62 bytes on wire (496 bits), 62 bytes captured (496 bits) on interface 0
Ethernet II, Src: Cisco-Li_21:62:a7 (00:1e:e5:21:62:a7), Dst: NX_6a:d6:31 (00:0c:29:6a:d6:31)
Internet Protocol Version 4, Src: 192.168.2.5 (192.168.2.5), Dst: 192.168.2.15 (192.168.2.15)
Transmission Control Protocol, Src Port: 55176 (55176), Dst Port: ibm-mqisdp (1883), Seq: 0, Len: 0
No. Time Source Destination Protocol Length Info
131 14.587250000 192.168.2.5 192.168.2.15 TCP 60 55176 > ibm-mqisdp [ACK] Seq=1 Ack=1 Win=17424 Len=0
Frame 131: 60 bytes on wire (480 bits), 60 bytes captured (480 bits) on interface 0
Ethernet II, Src: Cisco-Li_21:62:a7 (00:1e:e5:21:62:a7), Dst: NX_6a:d6:31 (00:0c:29:6a:d6:31)
Internet Protocol Version 4, Src: 192.168.2.5 (192.168.2.5), Dst: 192.168.2.15 (192.168.2.15)
Transmission Control Protocol, Src Port: 55176 (55176), Dst Port: ibm-mqisdp (1883), Seq: 1, Ack: 1, Len: 0
No. Time Source Destination Protocol Length Info
132 14.589586000 192.168.2.5 192.168.2.15 TCP 92 55176 > ibm-mqisdp [PSH, ACK] Seq=1 Ack=1 Win=17424 Len=38
Frame 132: 92 bytes on wire (736 bits), 92 bytes captured (736 bits) on interface 0
Ethernet II, Src: Cisco-Li_21:62:a7 (00:1e:e5:21:62:a7), Dst: NX_6a:d6:31 (00:0c:29:6a:d6:31)
Internet Protocol Version 4, Src: 192.168.2.5 (192.168.2.5), Dst: 192.168.2.15 (192.168.2.15)
Transmission Control Protocol, Src Port: 55176 (55176), Dst Port: ibm-mqisdp (1883), Seq: 1, Ack: 1, Len: 38
Data (38 bytes)
0000 10 24 00 04 4d 51 54 54 04 c2 00 1e 00 08 74 65 .$..MQTT......te
0010 73 74 75 73 65 72 00 08 74 65 73 74 75 73 65 72 stuser..testuser
0020 00 04 6d 61 72 79 ..mary
No. Time Source Destination Protocol Length Info
135 14.590183000 192.168.2.5 192.168.2.15 TCP 60 55176 > ibm-mqisdp [ACK] Seq=39 Ack=5 Win=17420 Len=0
Frame 135: 60 bytes on wire (480 bits), 60 bytes captured (480 bits) on interface 0
Ethernet II, Src: Cisco-Li_21:62:a7 (00:1e:e5:21:62:a7), Dst: NX_6a:d6:31 (00:0c:29:6a:d6:31)
Internet Protocol Version 4, Src: 192.168.2.5 (192.168.2.5), Dst: 192.168.2.15 (192.168.2.15)
Transmission Control Protocol, Src Port: 55176 (55176), Dst Port: ibm-mqisdp (1883), Seq: 39, Ack: 5, Len: 0
No. Time Source Destination Protocol Length Info
144 21.534467000 192.168.2.5 192.168.2.15 TCP 68 55176 > ibm-mqisdp [PSH, ACK] Seq=39 Ack=5 Win=17420 Len=14
Frame 144: 68 bytes on wire (544 bits), 68 bytes captured (544 bits) on interface 0
Ethernet II, Src: Cisco-Li_21:62:a7 (00:1e:e5:21:62:a7), Dst: NX_6a:d6:31 (00:0c:29:6a:d6:31)
Internet Protocol Version 4, Src: 192.168.2.5 (192.168.2.5), Dst: 192.168.2.15 (192.168.2.15)
Transmission Control Protocol, Src Port: 55176 (55176), Dst Port: ibm-mqisdp (1883), Seq: 39, Ack: 5, Len: 14
Data (14 bytes)
0000 33 0c 00 04 74 65 73 74 00 01 74 65 73 74 3...test..test
No. Time Source Destination Protocol Length Info
146 21.534941000 192.168.2.5 192.168.2.15 TCP 60 55176 > ibm-mqisdp [ACK] Seq=53 Ack=9 Win=17416 Len=0
Frame 146: 60 bytes on wire (480 bits), 60 bytes captured (480 bits) on interface 0
Ethernet II, Src: Cisco-Li_21:62:a7 (00:1e:e5:21:62:a7), Dst: NX_6a:d6:31 (00:0c:29:6a:d6:31)
Internet Protocol Version 4, Src: 192.168.2.5 (192.168.2.5), Dst: 192.168.2.15 (192.168.2.15)
Transmission Control Protocol, Src Port: 55176 (55176), Dst Port: ibm-mqisdp (1883), Seq: 53, Ack: 9, Len: 0
No. Time Source Destination Protocol Length Info
184 51.556401000 192.168.2.5 192.168.2.15 TCP 60 55176 > ibm-mqisdp [PSH, ACK] Seq=53 Ack=9 Win=17416 Len=2
Frame 184: 60 bytes on wire (480 bits), 60 bytes captured (480 bits) on interface 0
Ethernet II, Src: Cisco-Li_21:62:a7 (00:1e:e5:21:62:a7), Dst: NX_6a:d6:31 (00:0c:29:6a:d6:31)
Internet Protocol Version 4, Src: 192.168.2.5 (192.168.2.5), Dst: 192.168.2.15 (192.168.2.15)
Transmission Control Protocol, Src Port: 55176 (55176), Dst Port: ibm-mqisdp (1883), Seq: 53, Ack: 9, Len: 2
Data (2 bytes)
0000 c0 00 ..
No. Time Source Destination Protocol Length Info
187 51.850874000 192.168.2.5 192.168.2.15 TCP 60 [TCP Retransmission] 55176 > ibm-mqisdp [PSH, ACK] Seq=53 Ack=9 Win=17416 Len=2
Frame 187: 60 bytes on wire (480 bits), 60 bytes captured (480 bits) on interface 0
Ethernet II, Src: Cisco-Li_21:62:a7 (00:1e:e5:21:62:a7), Dst: NX_6a:d6:31 (00:0c:29:6a:d6:31)
Internet Protocol Version 4, Src: 192.168.2.5 (192.168.2.5), Dst: 192.168.2.15 (192.168.2.15)
Transmission Control Protocol, Src Port: 55176 (55176), Dst Port: ibm-mqisdp (1883), Seq: 53, Ack: 9, Len: 2
Data (2 bytes)
0000 c0 00 ..
No. Time Source Destination Protocol Length Info
190 52.452535000 192.168.2.5 192.168.2.15 TCP 60 [TCP Retransmission] 55176 > ibm-mqisdp [PSH, ACK] Seq=53 Ack=9 Win=17416 Len=2
Frame 190: 60 bytes on wire (480 bits), 60 bytes captured (480 bits) on interface 0
Ethernet II, Src: Cisco-Li_21:62:a7 (00:1e:e5:21:62:a7), Dst: NX_6a:d6:31 (00:0c:29:6a:d6:31)
Internet Protocol Version 4, Src: 192.168.2.5 (192.168.2.5), Dst: 192.168.2.15 (192.168.2.15)
Transmission Control Protocol, Src Port: 55176 (55176), Dst Port: ibm-mqisdp (1883), Seq: 53, Ack: 9, Len: 2
Data (2 bytes)
0000 c0 00 ..
No. Time Source Destination Protocol Length Info
197 53.655674000 192.168.2.5 192.168.2.15 TCP 60 [TCP Retransmission] 55176 > ibm-mqisdp [PSH, ACK] Seq=53 Ack=9 Win=17416 Len=2
Frame 197: 60 bytes on wire (480 bits), 60 bytes captured (480 bits) on interface 0
Ethernet II, Src: Cisco-Li_21:62:a7 (00:1e:e5:21:62:a7), Dst: NX_6a:d6:31 (00:0c:29:6a:d6:31)
Internet Protocol Version 4, Src: 192.168.2.5 (192.168.2.5), Dst: 192.168.2.15 (192.168.2.15)
Transmission Control Protocol, Src Port: 55176 (55176), Dst Port: ibm-mqisdp (1883), Seq: 53, Ack: 9, Len: 2
Data (2 bytes)
0000 c0 00 ..
No. Time Source Destination Protocol Length Info
201 56.056945000 192.168.2.5 192.168.2.15 TCP 60 [TCP Retransmission] 55176 > ibm-mqisdp [PSH, ACK] Seq=53 Ack=9 Win=17416 Len=2
Frame 201: 60 bytes on wire (480 bits), 60 bytes captured (480 bits) on interface 0
Ethernet II, Src: Cisco-Li_21:62:a7 (00:1e:e5:21:62:a7), Dst: NX_6a:d6:31 (00:0c:29:6a:d6:31)
Internet Protocol Version 4, Src: 192.168.2.5 (192.168.2.5), Dst: 192.168.2.15 (192.168.2.15)
Transmission Control Protocol, Src Port: 55176 (55176), Dst Port: ibm-mqisdp (1883), Seq: 53, Ack: 9, Len: 2
Data (2 bytes)
0000 c0 00 ..
No. Time Source Destination Protocol Length Info
213 60.854141000 192.168.2.5 192.168.2.15 TCP 60 [TCP Retransmission] 55176 > ibm-mqisdp [PSH, ACK] Seq=53 Ack=9 Win=17416 Len=2
Frame 213: 60 bytes on wire (480 bits), 60 bytes captured (480 bits) on interface 0
Ethernet II, Src: Cisco-Li_21:62:a7 (00:1e:e5:21:62:a7), Dst: NX_6a:d6:31 (00:0c:29:6a:d6:31)
Internet Protocol Version 4, Src: 192.168.2.5 (192.168.2.5), Dst: 192.168.2.15 (192.168.2.15)
Transmission Control Protocol, Src Port: 55176 (55176), Dst Port: ibm-mqisdp (1883), Seq: 53, Ack: 9, Len: 2
Data (2 bytes)
0000 c0 00 ..
No. Time Source Destination Protocol Length Info
233 70.449632000 192.168.2.5 192.168.2.15 TCP 60 55176 > ibm-mqisdp [RST, ACK] Seq=55 Ack=9 Win=0 Len=0
Frame 233: 60 bytes on wire (480 bits), 60 bytes captured (480 bits) on interface 0
Ethernet II, Src: Cisco-Li_21:62:a7 (00:1e:e5:21:62:a7), Dst: NX_6a:d6:31 (00:0c:29:6a:d6:31)
Internet Protocol Version 4, Src: 192.168.2.5 (192.168.2.5), Dst: 192.168.2.15 (192.168.2.15)
Transmission Control Protocol, Src Port: 55176 (55176), Dst Port: ibm-mqisdp (1883), Seq: 55, Ack: 9, Len: 0
Client (192.168.2.5) capture transcript:
No. Time Source Destination Protocol Length Info
174 5.754193000 192.168.2.5 192.168.2.15 TCP 62 55176→1883 [SYN] Seq=0 Win=8192 Len=0 MSS=1460 SACK_PERM=1
Frame 174: 62 bytes on wire (496 bits), 62 bytes captured (496 bits) on interface 0
Ethernet II, Src: Cisco-Li_21:62:a7 (00:1e:e5:21:62:a7), Dst: NX_6a:d6:31 (00:0c:29:6a:d6:31)
Internet Protocol Version 4, Src: 192.168.2.5 (192.168.2.5), Dst: 192.168.2.15 (192.168.2.15)
Transmission Control Protocol, Src Port: 55176 (55176), Dst Port: 1883 (1883), Seq: 0, Len: 0
No. Time Source Destination Protocol Length Info
176 5.754376000 192.168.2.5 192.168.2.15 TCP 54 55176→1883 [ACK] Seq=1 Ack=1 Win=17424 Len=0
Frame 176: 54 bytes on wire (432 bits), 54 bytes captured (432 bits) on interface 0
Ethernet II, Src: Cisco-Li_21:62:a7 (00:1e:e5:21:62:a7), Dst: NX_6a:d6:31 (00:0c:29:6a:d6:31)
Internet Protocol Version 4, Src: 192.168.2.5 (192.168.2.5), Dst: 192.168.2.15 (192.168.2.15)
Transmission Control Protocol, Src Port: 55176 (55176), Dst Port: 1883 (1883), Seq: 1, Ack: 1, Len: 0
No. Time Source Destination Protocol Length Info
177 5.756658000 192.168.2.5 192.168.2.15 TCP 92 55176→1883 [PSH, ACK] Seq=1 Ack=1 Win=17424 Len=38
Frame 177: 92 bytes on wire (736 bits), 92 bytes captured (736 bits) on interface 0
Ethernet II, Src: Cisco-Li_21:62:a7 (00:1e:e5:21:62:a7), Dst: NX_6a:d6:31 (00:0c:29:6a:d6:31)
Internet Protocol Version 4, Src: 192.168.2.5 (192.168.2.5), Dst: 192.168.2.15 (192.168.2.15)
Transmission Control Protocol, Src Port: 55176 (55176), Dst Port: 1883 (1883), Seq: 1, Ack: 1, Len: 38
Data (38 bytes)
0000 10 24 00 04 4d 51 54 54 04 c2 00 1e 00 08 74 65 .$..MQTT......te
0010 73 74 75 73 65 72 00 08 74 65 73 74 75 73 65 72 stuser..testuser
0020 00 04 6d 61 72 79 ..mary
No. Time Source Destination Protocol Length Info
180 5.757101000 192.168.2.5 192.168.2.15 TCP 54 55176→1883 [ACK] Seq=39 Ack=5 Win=17420 Len=0
Frame 180: 54 bytes on wire (432 bits), 54 bytes captured (432 bits) on interface 0
Ethernet II, Src: Cisco-Li_21:62:a7 (00:1e:e5:21:62:a7), Dst: NX_6a:d6:31 (00:0c:29:6a:d6:31)
Internet Protocol Version 4, Src: 192.168.2.5 (192.168.2.5), Dst: 192.168.2.15 (192.168.2.15)
Transmission Control Protocol, Src Port: 55176 (55176), Dst Port: 1883 (1883), Seq: 39, Ack: 5, Len: 0
No. Time Source Destination Protocol Length Info
393 12.701517000 192.168.2.5 192.168.2.15 TCP 68 55176→1883 [PSH, ACK] Seq=39 Ack=5 Win=17420 Len=14
Frame 393: 68 bytes on wire (544 bits), 68 bytes captured (544 bits) on interface 0
Ethernet II, Src: Cisco-Li_21:62:a7 (00:1e:e5:21:62:a7), Dst: NX_6a:d6:31 (00:0c:29:6a:d6:31)
Internet Protocol Version 4, Src: 192.168.2.5 (192.168.2.5), Dst: 192.168.2.15 (192.168.2.15)
Transmission Control Protocol, Src Port: 55176 (55176), Dst Port: 1883 (1883), Seq: 39, Ack: 5, Len: 14
Data (14 bytes)
0000 33 0c 00 04 74 65 73 74 00 01 74 65 73 74 3...test..test
No. Time Source Destination Protocol Length Info
395 12.701938000 192.168.2.5 192.168.2.15 TCP 54 55176→1883 [ACK] Seq=53 Ack=9 Win=17416 Len=0
Frame 395: 54 bytes on wire (432 bits), 54 bytes captured (432 bits) on interface 0
Ethernet II, Src: Cisco-Li_21:62:a7 (00:1e:e5:21:62:a7), Dst: NX_6a:d6:31 (00:0c:29:6a:d6:31)
Internet Protocol Version 4, Src: 192.168.2.5 (192.168.2.5), Dst: 192.168.2.15 (192.168.2.15)
Transmission Control Protocol, Src Port: 55176 (55176), Dst Port: 1883 (1883), Seq: 53, Ack: 9, Len: 0
No. Time Source Destination Protocol Length Info
1192 42.723471000 192.168.2.5 192.168.2.15 TCP 56 55176→1883 [PSH, ACK] Seq=53 Ack=9 Win=17416 Len=2
Frame 1192: 56 bytes on wire (448 bits), 56 bytes captured (448 bits) on interface 0
Ethernet II, Src: Cisco-Li_21:62:a7 (00:1e:e5:21:62:a7), Dst: NX_6a:d6:31 (00:0c:29:6a:d6:31)
Internet Protocol Version 4, Src: 192.168.2.5 (192.168.2.5), Dst: 192.168.2.15 (192.168.2.15)
Transmission Control Protocol, Src Port: 55176 (55176), Dst Port: 1883 (1883), Seq: 53, Ack: 9, Len: 2
Data (2 bytes)
0000 c0 00 ..
No. Time Source Destination Protocol Length Info
1205 43.017917000 192.168.2.5 192.168.2.15 TCP 56 [TCP Retransmission] 55176→1883 [PSH, ACK] Seq=53 Ack=9 Win=17416 Len=2
Frame 1205: 56 bytes on wire (448 bits), 56 bytes captured (448 bits) on interface 0
Ethernet II, Src: Cisco-Li_21:62:a7 (00:1e:e5:21:62:a7), Dst: NX_6a:d6:31 (00:0c:29:6a:d6:31)
Internet Protocol Version 4, Src: 192.168.2.5 (192.168.2.5), Dst: 192.168.2.15 (192.168.2.15)
Transmission Control Protocol, Src Port: 55176 (55176), Dst Port: 1883 (1883), Seq: 53, Ack: 9, Len: 2
Data (2 bytes)
0000 c0 00 ..
No. Time Source Destination Protocol Length Info
1213 43.619506000 192.168.2.5 192.168.2.15 TCP 56 [TCP Retransmission] 55176→1883 [PSH, ACK] Seq=53 Ack=9 Win=17416 Len=2
Frame 1213: 56 bytes on wire (448 bits), 56 bytes captured (448 bits) on interface 0
Ethernet II, Src: Cisco-Li_21:62:a7 (00:1e:e5:21:62:a7), Dst: NX_6a:d6:31 (00:0c:29:6a:d6:31)
Internet Protocol Version 4, Src: 192.168.2.5 (192.168.2.5), Dst: 192.168.2.15 (192.168.2.15)
Transmission Control Protocol, Src Port: 55176 (55176), Dst Port: 1883 (1883), Seq: 53, Ack: 9, Len: 2
Data (2 bytes)
0000 c0 00 ..
No. Time Source Destination Protocol Length Info
1236 44.822621000 192.168.2.5 192.168.2.15 TCP 56 [TCP Retransmission] 55176→1883 [PSH, ACK] Seq=53 Ack=9 Win=17416 Len=2
Frame 1236: 56 bytes on wire (448 bits), 56 bytes captured (448 bits) on interface 0
Ethernet II, Src: Cisco-Li_21:62:a7 (00:1e:e5:21:62:a7), Dst: NX_6a:d6:31 (00:0c:29:6a:d6:31)
Internet Protocol Version 4, Src: 192.168.2.5 (192.168.2.5), Dst: 192.168.2.15 (192.168.2.15)
Transmission Control Protocol, Src Port: 55176 (55176), Dst Port: 1883 (1883), Seq: 53, Ack: 9, Len: 2
Data (2 bytes)
0000 c0 00 ..
No. Time Source Destination Protocol Length Info
1273 47.224018000 192.168.2.5 192.168.2.15 TCP 56 [TCP Retransmission] 55176→1883 [PSH, ACK] Seq=53 Ack=9 Win=17416 Len=2
Frame 1273: 56 bytes on wire (448 bits), 56 bytes captured (448 bits) on interface 0
Ethernet II, Src: Cisco-Li_21:62:a7 (00:1e:e5:21:62:a7), Dst: NX_6a:d6:31 (00:0c:29:6a:d6:31)
Internet Protocol Version 4, Src: 192.168.2.5 (192.168.2.5), Dst: 192.168.2.15 (192.168.2.15)
Transmission Control Protocol, Src Port: 55176 (55176), Dst Port: 1883 (1883), Seq: 53, Ack: 9, Len: 2
Data (2 bytes)
0000 c0 00 ..
No. Time Source Destination Protocol Length Info
1462 52.021241000 192.168.2.5 192.168.2.15 TCP 56 [TCP Retransmission] 55176→1883 [PSH, ACK] Seq=53 Ack=9 Win=17416 Len=2
Frame 1462: 56 bytes on wire (448 bits), 56 bytes captured (448 bits) on interface 0
Ethernet II, Src: Cisco-Li_21:62:a7 (00:1e:e5:21:62:a7), Dst: NX_6a:d6:31 (00:0c:29:6a:d6:31)
Internet Protocol Version 4, Src: 192.168.2.5 (192.168.2.5), Dst: 192.168.2.15 (192.168.2.15)
Transmission Control Protocol, Src Port: 55176 (55176), Dst Port: 1883 (1883), Seq: 53, Ack: 9, Len: 2
Data (2 bytes)
0000 c0 00 ..
No. Time Source Destination Protocol Length Info
1713 61.616726000 192.168.2.5 192.168.2.15 TCP 54 55176→1883 [RST, ACK] Seq=55 Ack=9 Win=0 Len=0
Frame 1713: 54 bytes on wire (432 bits), 54 bytes captured (432 bits) on interface 0
Ethernet II, Src: Cisco-Li_21:62:a7 (00:1e:e5:21:62:a7), Dst: NX_6a:d6:31 (00:0c:29:6a:d6:31)
Internet Protocol Version 4, Src: 192.168.2.5 (192.168.2.5), Dst: 192.168.2.15 (192.168.2.15)
Transmission Control Protocol, Src Port: 55176 (55176), Dst Port: 1883 (1883), Seq: 55, Ack: 9, Len: 0
The most likely reason for a failure in _mosquitto_packet_read()
is that the remote side closed the connection and hence reading wasn't possible. If do_disconnect()
is getting to the point you mention, the socket is essentially still open from the point of view of the broker.
I have just tried to reproduce this problem using the client code below (you will need Paho Python installed, pip install paho-mqtt
).
import paho.mqtt.client as paho
mqtt = paho.Client(client_id="testuser", clean_session=True)
mqtt.username_pw_set("testuser", "password")
mqtt.connect("localhost", 1883, 30)
mqtt.publish("test", "test", qos=1, retain=True)
mqtt.loop_forever()
The log I got from the broker was:
1433245884: New connection from ::1 on port 1883.
1433245884: New client connected from ::1 as testuser (c1, k30, u'testuser').
1433245884: Sending CONNACK to testuser (0, 0)
1433245884: Received PUBLISH from testuser (d0, q1, r1, m1, 'test', ... (4 bytes))
1433245884: Sending PUBACK to testuser (Mid: 1)
1433245915: Received PINGREQ from testuser
1433245915: Sending PINGRESP to testuser
1433245945: Received PINGREQ from testuser
1433245945: Sending PINGRESP to testuser
1433245975: Received PINGREQ from testuser
1433245975: Sending PINGRESP to testuser
...
Could you please try this on your system to compare?