LoRaWAN Sample - RX2 timeout on NUCLEO-WL55JC #76306

eblasband-zymbit · 2024-07-26T01:07:36Z

eblasband-zymbit
Jul 26, 2024

I am trying to use the NUCLEO-WL55JC development kit to connect and join a LoRaWAN network to send data. It seems no matter what I do I always get the same error when trying to join the network, specifically around recieving the join acceptance from the server. It seems to send the join request just fine but the accept transmission does not seem to be recieved at the edge node.

From server logs:

Unfortunately none of the following discussions have helped so far:

Setup:

Zephyr version: 3.7.0-rc1
Edge node: NUCLEO-WL55JC dev kit
Gateway: P-NUCLEO-LRWAN3
Both devices on my desk (close proximity)

Code:

Zephyr class_a sample or fuota sample

Modificaitons:

changing necessary dev_eui, join_eui, app_key, and region specific to my setup
Enbaled debug logging for Lora and LoraWAN

Error:

[00:00:00.000,000] <dbg> sx126x: sx126x_lora_init: Initializing sx126x
[00:00:00.000,000] <dbg> sx126x: SX126xReset: Resetting radio
[00:00:00.030,000] <dbg> sx126x: SX126xIoIrqInit: Configuring DIO IRQ callback
--- 4 messages dropped ---
[00:00:00.032,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x97 w. 4 bytes of data
--- 2 messages dropped ---
[00:00:00.034,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x89 w. 1 bytes of data
[00:00:00.042,000] <dbg> sx126x: SX126xIoRfSwitchInit: Configuring DIO2
[00:00:00.042,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x9d w. 1 bytes of data
--- 6 messages dropped ---
[00:00:00.047,000] <dbg> sx126x: SX126xReadRegisters: register_value
                                 fe                                               |.                
--- 30 messages dropped ---
[00:00:00.105,000] <dbg> sx126x: SX126xReadRegisters: register_value
                                 0c                                               |.                
--- 31 messages dropped ---
[00:00:00.117,000] <dbg> sx126x: SX126xWakeup: Device ready
--- 9 messages dropped ---
[00:00:00.119,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x98 w. 2 bytes of data
[00:00:00.126,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x86 w. 4 bytes of data
[00:00:00.127,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x80 w. 1 bytes of data
[00:00:00.128,000] <dbg> sx126x: SX126xSetOperatingMode: SetOperatingMode: STDBY_RC (1)
[00:00:00.128,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x8a w. 1 bytes of data
[00:00:00.129,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x8b w. 4 bytes of data
[00:00:00.130,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x8c w. 6 bytes of data
[00:00:00.132,000] <dbg> sx126x: SX126xReadRegisters: Reading 1 registers @ 0x889
[00:00:00.132,000] <dbg> sx126x: SX126xReadRegisters: register_value
                                 24                                               |$                
[00:00:00.132,000] <dbg> sx126x: SX126xWriteRegisters: Writing 1 registers @ 0x889: 0x24 , ...
[00:00:00.132,000] <dbg> sx126x: SX126xSetRfTxPower: power: 17
[00:00:00.132,000] <dbg> sx126x: SX126xReadRegisters: Reading 1 registers @ 0x8d8
[00:00:00.132,000] <dbg> sx126x: SX126xReadRegisters: register_value
                                 fe                                               |.                
[00:00:00.132,000] <dbg> sx126x: SX126xWriteRegisters: Writing 1 registers @ 0x8d8: 0xfe , ...
[00:00:00.132,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x95 w. 4 bytes of data
[00:00:00.133,000] <dbg> sx126x: SX126xWriteRegisters: Writing 1 registers @ 0x8e7: 0x38 , ...
[00:00:00.133,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x8e w. 2 bytes of data
[00:00:00.134,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x8c w. 6 bytes of data
[00:00:00.136,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x8 w. 8 bytes of data
[00:00:00.136,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x8c w. 6 bytes of data
[00:00:00.138,000] <dbg> sx126x: SX126xWriteBuffer: Writing buffers @ 0x0 (23 bytes)
[00:00:00.138,000] <dbg> sx126x: SX126xSetOperatingMode: SetOperatingMode: TX (4)
[00:00:00.138,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x83 w. 3 bytes of data
[00:00:00.143,000] <dbg> lorawan: lorawan_join: Network join request sent!
[00:00:00.966,000] <dbg> sx126x: sx126x_dio1_irq_work_handler: Processing DIO1 interrupt
[00:00:00.966,000] <dbg> sx126x: SX126xReadCommand: Issuing opcode 0x12 (data size: 2)
[00:00:00.966,000] <dbg> sx126x: SX126xReadCommand: -> status: 0xac
[00:00:00.966,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x2 w. 2 bytes of data
[00:00:00.966,000] <dbg> sx126x: SX126xSetOperatingMode: SetOperatingMode: STDBY_RC (1)
[00:00:00.966,000] <dbg> sx126x: SX126xAntSwOff: No antenna switch configured
[00:00:00.966,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x84 w. 1 bytes of data
[00:00:00.966,000] <dbg> sx126x: SX126xSetOperatingMode: SetOperatingMode: SLEEP (0)
[00:00:05.975,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x80 w. 1 bytes of data
[00:00:05.975,000] <dbg> sx126x: SX126xWakeup: Sending GET_STATUS
[00:00:05.975,000] <dbg> sx126x: SX126xWakeup: Waiting for device...
[00:00:05.977,000] <dbg> sx126x: SX126xWakeup: Device ready
[00:00:05.977,000] <dbg> sx126x: SX126xAntSwOn: No antenna switch configured
[00:00:05.978,000] <dbg> sx126x: SX126xSetOperatingMode: SetOperatingMode: STDBY_RC (1)
[00:00:05.978,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x86 w. 4 bytes of data
[00:00:05.979,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x9f w. 1 bytes of data
[00:00:05.980,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x80 w. 1 bytes of data
[00:00:05.981,000] <dbg> sx126x: SX126xSetOperatingMode: SetOperatingMode: STDBY_RC (1)
[00:00:05.981,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x8a w. 1 bytes of data
[00:00:05.983,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x8b w. 4 bytes of data
[00:00:05.984,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x8c w. 6 bytes of data
[00:00:05.985,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0xa0 w. 1 bytes of data
[00:00:05.986,000] <dbg> sx126x: SX126xWriteRegisters: Writing 1 registers @ 0x706: 0x18 , ...
[00:00:05.986,000] <dbg> sx126x: SX126xReadRegisters: Reading 1 registers @ 0x736
[00:00:05.986,000] <dbg> sx126x: SX126xReadRegisters: register_value
                                 09                                               |.                
[00:00:05.986,000] <dbg> sx126x: SX126xWriteRegisters: Writing 1 registers @ 0x736: 0x9 , ...
[00:00:05.986,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x8c w. 6 bytes of data
[00:00:05.987,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x8 w. 8 bytes of data
[00:00:05.988,000] <dbg> sx126x: SX126xSetOperatingMode: SetOperatingMode: RX (5)
[00:00:05.988,000] <dbg> sx126x: SX126xWriteRegisters: Writing 1 registers @ 0x8ac: 0x94 , ...
[00:00:05.988,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x82 w. 3 bytes of data
[00:00:06.091,000] <dbg> sx126x: sx126x_dio1_irq_work_handler: Processing DIO1 interrupt
[00:00:06.091,000] <dbg> sx126x: SX126xReadCommand: Issuing opcode 0x12 (data size: 2)
[00:00:06.091,000] <dbg> sx126x: SX126xReadCommand: -> status: 0xa6
[00:00:06.091,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x2 w. 2 bytes of data
[00:00:06.091,000] <dbg> sx126x: SX126xSetOperatingMode: SetOperatingMode: STDBY_RC (1)
[00:00:06.091,000] <dbg> sx126x: SX126xAntSwOff: No antenna switch configured
[00:00:06.091,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x84 w. 1 bytes of data
[00:00:06.091,000] <dbg> sx126x: SX126xSetOperatingMode: SetOperatingMode: SLEEP (0)
[00:00:06.993,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x80 w. 1 bytes of data
[00:00:06.993,000] <dbg> sx126x: SX126xWakeup: Sending GET_STATUS
[00:00:06.993,000] <dbg> sx126x: SX126xWakeup: Waiting for device...
[00:00:06.994,000] <dbg> sx126x: SX126xWakeup: Device ready
[00:00:06.994,000] <dbg> sx126x: SX126xAntSwOn: No antenna switch configured
[00:00:06.996,000] <dbg> sx126x: SX126xSetOperatingMode: SetOperatingMode: STDBY_RC (1)
[00:00:06.996,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x86 w. 4 bytes of data
[00:00:06.997,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x9f w. 1 bytes of data
[00:00:06.998,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x80 w. 1 bytes of data
[00:00:06.999,000] <dbg> sx126x: SX126xSetOperatingMode: SetOperatingMode: STDBY_RC (1)
[00:00:06.999,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x8a w. 1 bytes of data
[00:00:07.000,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x8b w. 4 bytes of data
[00:00:07.002,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x8c w. 6 bytes of data
[00:00:07.003,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0xa0 w. 1 bytes of data
[00:00:07.004,000] <dbg> sx126x: SX126xWriteRegisters: Writing 1 registers @ 0x706: 0x18 , ...
[00:00:07.004,000] <dbg> sx126x: SX126xReadRegisters: Reading 1 registers @ 0x736
[00:00:07.004,000] <dbg> sx126x: SX126xReadRegisters: register_value
                                 09                                               |.                
[00:00:07.004,000] <dbg> sx126x: SX126xWriteRegisters: Writing 1 registers @ 0x736: 0x9 , ...
[00:00:07.004,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x8c w. 6 bytes of data
[00:00:07.005,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x8 w. 8 bytes of data
[00:00:07.005,000] <dbg> sx126x: SX126xSetOperatingMode: SetOperatingMode: RX (5)
[00:00:07.005,000] <dbg> sx126x: SX126xWriteRegisters: Writing 1 registers @ 0x8ac: 0x94 , ...
[00:00:07.005,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x82 w. 3 bytes of data
[00:00:07.109,000] <dbg> sx126x: sx126x_dio1_irq_work_handler: Processing DIO1 interrupt
[00:00:07.109,000] <dbg> sx126x: SX126xReadCommand: Issuing opcode 0x12 (data size: 2)
[00:00:07.109,000] <dbg> sx126x: SX126xReadCommand: -> status: 0xa6
[00:00:07.109,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x2 w. 2 bytes of data
[00:00:07.109,000] <dbg> sx126x: SX126xSetOperatingMode: SetOperatingMode: STDBY_RC (1)
[00:00:07.109,000] <dbg> sx126x: SX126xAntSwOff: No antenna switch configured
[00:00:07.109,000] <dbg> sx126x: SX126xWriteCommand: Issuing opcode 0x84 w. 1 bytes of data
[00:00:07.109,000] <dbg> sx126x: SX126xSetOperatingMode: SetOperatingMode: SLEEP (0)
[00:00:07.111,000] <dbg> lorawan: mlme_confirm_handler: Received MlmeConfirm (for MlmeRequest 1)
[00:00:07.111,000] <err> lorawan: MlmeConfirm failed : Rx 2 timeout                                 <---------------Error
[00:00:07.115,000] <err> lorawan_class_a: lorawan_join_network failed: -116

Please let me know if there is something obvious I am mising or any help on additional places to look would be much appreciated.

UPDATE 7/26/24: I am able to run the LoRa P2P send and recieve samples successfully with 2 dev kits so that seems to rule out a hardware issue.

eblasband-zymbit · 2024-08-07T03:02:42Z

eblasband-zymbit
Aug 7, 2024
Author

Update: Tracked the issue down to something in the secure element code where it was failing to verify the cmac. Specifically here in soft-se.c:

if (SecureElementVerifyAesCmac(localBuffer, encJoinAcceptSize + JOIN_ACCEPT_MIC_COMPUTATION_OFFSET -LORAMAC_MHDR_FIELD_SIZE - LORAMAC_MIC_FIELD_SIZE, mic, J_S_INT_KEY) != SECURE_ELEMENT_SUCCESS)

But, this seemed odd so I flashed the same code on a different dev board and it worked successfully so closing this discussion based off that. Seems one of my boards got someting messed up.

0 replies

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

LoRaWAN Sample - RX2 timeout on NUCLEO-WL55JC #76306

Uh oh!

{{title}}

Uh oh!

Uh oh!

{{editor}}'s edit

{{editor}}'s edit

Uh oh!

Replies: 1 comment

Uh oh!

{{title}}

Uh oh!

Select a reply

Uh oh!

LoRaWAN Sample - RX2 timeout on NUCLEO-WL55JC #76306

Uh oh!

Uh oh!

eblasband-zymbit Jul 26, 2024

Replies: 1 comment

Uh oh!

eblasband-zymbit Aug 7, 2024 Author

eblasband-zymbit
Jul 26, 2024

eblasband-zymbit
Aug 7, 2024
Author