Gateway doesn't recognize sleepy client

[szymonnnm]

Hello,

I've been playing recently with the MQTT-SN and so far the Gateway has been working wonderfully - I was able to correctly do a connect/publish/subscribe/disconnect cycle (like in MQTTSNPacket/samples/pub0sub1.c example) but now I've stumbled upon some behavior that I don't understand. The problem began when I tried to implement a sleepy device. The principle of operation I'm trying to use is simple:

• initialization - connect (will = 0, clean = 1), register topic, subscribe to other topic and then disconnect with duration field set to 60,
• periodically (every 30s) send PINGREQ packet and parse received data,
• on some external event, publish messages on previously registered topic (not relevant in this issue I think)

The problem is that the Gateway's response on my PINGREQ packets is always DISCONNECT because it doesn't recognize the client. I don't understand why it's hapenning. I'm attaching the logs from the gateway below. You can see there that:

• The IPv6 adress of the device and port is staying the same,
• The client ID is the same in the CONNECT message and in the PINGREQ message.
• The duration field in the DISCONNECT message is in fact 60
• The time interval between DISCONNECT and PINGREQ messages is 30 - it's less than the sleep duration so the Gateway should still "remember" the client, am I right?

20190625 121222.994   CONNECT           <---  bd8202e74fc686da                    16 04 04 01 00 0A 62 64 38 32 30 32 65 37 34 66 63 36 38 36 64 61
     PacketHandleTask gets CONNECT      from the client.
Client Status = Disconnected
20190625 121223.293   CONNECT           ===>  bd8202e74fc686da                    10 1C 00 04 4D 51 54 54 04 02 00 0A 00 10 62 64 38 32 30 32 65 37 34 66 63 36 38 36 64 61
20190625 121223.454   CONNACK           <===  bd8202e74fc686da                    20 02 00 00
     PacketHandleTask gets CONNACK      from the broker.
20190625 121223.454   CONNACK           --->  bd8202e74fc686da                    03 05 00
unicast sendto fd11:22::29c9:4f7c:a1a:a1eb%wpan0, port: 52000 length = 3

20190625 121223.485   REGISTER    0001  <---  bd8202e74fc686da                    1B 0A 00 00 00 01 65 6B 6F 72 61 75 2F 73 6F 61 70 5F 64 69 73 70 65 6E 73 65 72
     PacketHandleTask gets REGISTER  0001 from the client.
Client Status = Active
20190625 121223.486   REGACK      0001  --->  bd8202e74fc686da                    07 0B 00 01 00 01 00
unicast sendto fd11:22::29c9:4f7c:a1a:a1eb%wpan0, port: 52000 length = 7

20190625 121223.522   SUBSCRIBE   0001  <---  bd8202e74fc686da                    12 12 40 00 01 65 6B 6F 72 61 75 2F 63 6F 6E 66 69 67
     PacketHandleTask gets SUBSCRIBE  0001 from the client.
Client Status = Active
20190625 121223.523   SUBSCRIBE   0001  ===>  bd8202e74fc686da                    82 12 00 01 00 0D 65 6B 6F 72 61 75 2F 63 6F 6E 66 69 67 02
20190625 121223.674   SUBACK      0001  <===  bd8202e74fc686da                    90 03 00 01 02
     PacketHandleTask gets SUBACK  0001 from the broker.
20190625 121223.674   SUBACK      0001  --->  bd8202e74fc686da                    08 13 40 00 02 00 01 00
unicast sendto fd11:22::29c9:4f7c:a1a:a1eb%wpan0, port: 52000 length = 8
20190625 121223.702   DISCONNECT        <---  bd8202e74fc686da                    04 18 00 3C
     PacketHandleTask gets DISCONNECT      from the client.
20190625 121223.702   DISCONNECT        --->  bd8202e74fc686da                    02 18
unicast sendto fd11:22::29c9:4f7c:a1a:a1eb%wpan0, port: 52000 length = 2
Client Status = Asleep

20190625 121253.670   PINGREQ           <---  Unknown Client !                    12 16 62 64 38 32 30 32 65 37 34 66 63 36 38 36 64 61
Error: Client(fd11:22::29c9:4f7c:a1a:a1eb:52000) is not connecting. message has been discarded.

20190625 121255.684   SEARCHGW          <---  Client                              03 01 01
20190625 121255.684   GWINFO            --->  Clients                             03 02 01

20190625 121255.731   CONNECT           <---  bd8202e74fc686da                    16 04 04 01 00 0A 62 64 38 32 30 32 65 37 34 66 63 36 38 36 64 61
     PacketHandleTask gets CONNECT      from the client.
Client Status = Disconnected
20190625 121255.883   CONNECT           ===>  bd8202e74fc686da                    10 1C 00 04 4D 51 54 54 04 02 00 0A 00 10 62 64 38 32 30 32 65 37 34 66 63 36 38 36 64 61
20190625 121256.377   CONNACK           <===  bd8202e74fc686da                    20 02 00 00
     PacketHandleTask gets CONNACK      from the broker.
20190625 121256.377   CONNACK           --->  bd8202e74fc686da                    03 05 00
unicast sendto fd11:22::29c9:4f7c:a1a:a1eb%wpan0, port: 52000 length = 3

20190625 121256.415   REGISTER    0001  <---  bd8202e74fc686da                    1B 0A 00 00 00 01 65 6B 6F 72 61 75 2F 73 6F 61 70 5F 64 69 73 70 65 6E 73 65 72
     PacketHandleTask gets REGISTER  0001 from the client.
20190625 121256.415   REGACK      0001  --->  bd8202e74fc686da                    07 0B 00 01 00 01 00
unicast sendto fd11:22::29c9:4f7c:a1a:a1eb%wpan0, port: 52000 length = 7
Client Status = Active

20190625 121256.446   SUBSCRIBE   0001  <---  bd8202e74fc686da                    12 12 40 00 01 65 6B 6F 72 61 75 2F 63 6F 6E 66 69 67
     PacketHandleTask gets SUBSCRIBE  0001 from the client.
Client Status = Active
20190625 121256.446   SUBSCRIBE   0001  ===>  bd8202e74fc686da                    82 12 00 01 00 0D 65 6B 6F 72 61 75 2F 63 6F 6E 66 69 67 02
20190625 121256.599   SUBACK      0001  <===  bd8202e74fc686da                    90 03 00 01 02
     PacketHandleTask gets SUBACK  0001 from the broker.
20190625 121256.599   SUBACK      0001  --->  bd8202e74fc686da                    08 13 40 00 02 00 01 00
unicast sendto fd11:22::29c9:4f7c:a1a:a1eb%wpan0, port: 52000 length = 8
20190625 121256.632   DISCONNECT        <---  bd8202e74fc686da                    04 18 00 3C
     PacketHandleTask gets DISCONNECT      from the client.
20190625 121256.632   DISCONNECT        --->  bd8202e74fc686da                    02 18
unicast sendto fd11:22::29c9:4f7c:a1a:a1eb%wpan0, port: 52000 length = 2
Client Status = Asleep

20190625 121323.593   PINGREQ           <---  Unknown Client !                    12 16 62 64 38 32 30 32 65 37 34 66 63 36 38 36 64 61
Error: Client(fd11:22::29c9:4f7c:a1a:a1eb:52000) is not connecting. message has been discarded.

EDIT: I noticed that the version of the Gateway I was using was 1.0.1 (I am using RaspPIoT Border Router Demo from Nordic Semiconductors) so I've updated it to the newest version. Unfortunately, with 1.3.1 the problem still remains. I've edited the logs to those from 1.3.1 since they look nicer.

[szymonnnm]

Okay, I think I've solved it - it turned out that I had to set the Duration field in the CONNECT message to the same duration I'm using in DISCONNECT.

I misunderstood the MQTT-SN specification and thought that this field indicates the time of non-sleep connection i.e. between CONNECT and DISCONNECT so I kept it low.