I have a GSM application connecting to MQTT that worked previously refuse to work when I picked it up again to improve on it.
To make sure there isnt a problem in my firmware I'm trying to get the GSM fundamentals course to run as well but im still running into a problem.
Running lesson4, ex1 solution without any changes, apart from adding logging levels, I get this output:
*** Booting nRF Connect SDK v2.5.0 ***
[00:00:00.305,328] <inf> Lesson4_Exercise1: Initializing modem library
[00:00:00.554,870] <inf> Lesson4_Exercise1: Connecting to LTE network
[00:00:03.210,174] <inf> Lesson4_Exercise1: RRC mode: Connected
[00:00:04.364,013] <inf> Lesson4_Exercise1: Network registration status: Connected - home network
[00:00:04.364,135] <inf> Lesson4_Exercise1: Connected to LTE network
[00:00:41.129,943] <inf> Lesson4_Exercise1: IPv4 Address found 91.121.93.94
[00:00:41.130,371] <inf> Lesson4_Exercise1: Connection to broker using mqtt_connect
[00:00:41.130,645] <dbg> net_mqtt_sock_tcp: mqtt_client_tcp_connect: (0x2000d2d8): Created socket 0
[00:00:41.484,771] <dbg> net_mqtt_sock_tcp: mqtt_client_tcp_connect: (0x2000d2d8): Connect completed
[00:00:41.484,802] <dbg> net_mqtt_enc: connect_request_encode: Encoding Protocol Description.
4d 51 54 54 |MQTT
[00:00:41.484,832] <dbg> net_mqtt_enc: pack_utf8_str: (0x2000d2d8): >> str_size:00000006 cur:0x2000dd37, end:0x2000ddb2
[00:00:41.484,863] <dbg> net_mqtt_enc: pack_uint16: (0x2000d2d8): >> val:0004 cur:0x2000dd37, end:0x2000ddb2
[00:00:41.484,863] <dbg> net_mqtt_enc: connect_request_encode: (0x2000d2d8): Encoding Protocol Version 04.
[00:00:41.484,893] <dbg> net_mqtt_enc: pack_uint8: (0x2000d2d8): >> val:04 cur:0x2000dd3d, end:0x2000ddb2
[00:00:41.484,893] <dbg> net_mqtt_enc: pack_uint8: (0x2000d2d8): >> val:00 cur:0x2000dd3e, end:0x2000ddb2
[00:00:41.484,924] <dbg> net_mqtt_enc: connect_request_encode: (0x2000d2d8): Encoding Keep Alive Time 003c.
[00:00:41.484,924] <dbg> net_mqtt_enc: pack_uint16: (0x2000d2d8): >> val:003c cur:0x2000dd3f, end:0x2000ddb2
[00:00:41.484,954] <dbg> net_mqtt_enc: connect_request_encode: Encoding Client Id.
6e 72 66 2d 33 35 31 35 31 36 31 37 32 36 38 37 |nrf-3515 16172687
37 38 32 |782
[00:00:41.484,985] <dbg> net_mqtt_enc: pack_utf8_str: (0x2000d2d8): >> str_size:00000015 cur:0x2000dd41, end:0x2000ddb2
[00:00:41.484,985] <dbg> net_mqtt_enc: pack_uint16: (0x2000d2d8): >> val:0013 cur:0x2000dd41, end:0x2000ddb2
[00:00:41.485,015] <dbg> net_mqtt_enc: mqtt_encode_fixed_header: (0x2000d2d8): << msg type:0x10 length:0x0000001f
[00:00:41.485,046] <dbg> net_mqtt_enc: packet_length_encode: (0x2000d2d8): >> length:0x0000001f cur:(nil), end:(nil)
[00:00:41.485,046] <dbg> net_mqtt_enc: mqtt_encode_fixed_header: (0x2000d2d8): Fixed header length = 02
[00:00:41.485,076] <dbg> net_mqtt_enc: pack_uint8: (0x2000d2d8): >> val:10 cur:0x2000dd35, end:0x2000ddb2
[00:00:41.485,076] <dbg> net_mqtt_enc: packet_length_encode: (0x2000d2d8): >> length:0x0000001f cur:0x2000dd36, end:0x2000ddb2
[00:00:41.485,565] <inf> net_mqtt: Connect completed
[00:00:48.783,111] <inf> Lesson4_Exercise1: Publishing: Hi from the nRF91 Series device
[00:00:48.783,142] <inf> Lesson4_Exercise1: to topic: devacademy/publish/topic len: 24
[00:00:48.783,172] <dbg> net_mqtt: mqtt_publish: (0x2000d380): [CID 0x2000d430]:[State 0x02]: >> Topic size 0x00000018, Data size 0x0000001f
[00:00:48.783,203] <dbg> net_mqtt: mqtt_publish: (0x2000d380): [CID 0x2000d430]:[State 0x02]: << result 0xffffff80
[00:00:48.783,203] <inf> Lesson4_Exercise1: Failed to send message, -128
[00:00:58.672,515] <inf> Lesson4_Exercise1: Publishing: Hi from the nRF91 Series device
[00:00:58.672,546] <inf> Lesson4_Exercise1: to topic: devacademy/publish/topic len: 24
[00:00:58.672,576] <dbg> net_mqtt: mqtt_publish: (0x2000d380): [CID 0x2000d430]:[State 0x02]: >> Topic size 0x00000018, Data size 0x0000001f
[00:00:58.672,607] <dbg> net_mqtt: mqtt_publish: (0x2000d380): [CID 0x2000d430]:[State 0x02]: << result 0xffffff80
[00:00:58.672,607] <inf> Lesson4_Exercise1: Failed to send message, -128
[00:01:41.485,717] <err> Lesson4_Exercise1: Error in mqtt_live: -128
[00:01:41.485,717] <inf> Lesson4_Exercise1: Disconnecting MQTT client
[00:01:41.485,748] <err> Lesson4_Exercise1: Could not disconnect MQTT client: -128
[00:01:41.485,778] <inf> Lesson4_Exercise1: Reconnecting in 60 seconds...
It seems to me that the mqtt_event_handler function does not get called, leading me to suspect there is a socket problem somewhere? I did add tracing prints to try and see where my problem is but the event handler never seemed to fire?
Also looking at my personal mqtt brokers logs, the DK definitely connects to the broker, but does not seem to initiate a connection:
Heres a normal connection from an NRF device connecting via Wifi:
2024-06-06T13:23:47: New connection from XXX.XXX.XXX.XXX:44540 on port 1883. 2024-06-06T13:23:47: New client connected from XXX.XXX.XXX.XXX:44540 as XXXXXXXX (p2, c1, k10, u'XXXXXXX').
The 9160 DK only initiates a new connection but the client connection does not seem to occur.
I'm using SDKv2.5.0 if that makes a difference although ive always used it.
Edited for better formatting.
