MQTT socket error after around a minute of connection

ᴘᴀɴᴀʏɪᴏᴛɪs picture ᴘᴀɴᴀʏɪᴏᴛɪs · Jun 1, 2015 · Viewed 9.8k times · Source

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:

  1. Connect
  2. Send a test message 'test' on topic 'test'
  3. Wait
  4. Socket error

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

Answer

ralight picture ralight · Jun 2, 2015

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?