OTAA Join Accept Message Decoding (Issue Help)

[LiyaoJiang1998]

Hi,

Pull Request:

• a small fix to the MHDR MalformedPacketException message string

Issue (Since there was no issue tab for this repo, I decided to post it here.):

I am using a end node device build using Dragino LoRa/GPS HAT + RPi 3 b+, I had successfully connected to a test RPi single channel gateway using ABP, and both the end device and gateway are on The Things Network.

Now, I am trying to connect my end node device to:

• Platform: The Actility ThingPark Platform, The ThingPark Platform only supports OTAA activation.
• Gateway: Cisco Wireless Gateway for LoRaWAN.

Since the device doesn't come with a DevEUI, AppEui and AppKey, I generated random DevEUI, AppEui and AppKey in The Things Network, and copied them in the dragino.ini.default config file using the OTAA mode. I copied the same keys, and added the end device to the Actility ThingPark Platform.

When I run the test.py hello world example, after the node sends the join request, the join request shows up in the Actility ThingPark Platform, and I can see the server sends a join accept message to the node. However, the node keeps giving error when decoding the join accpet message, and it never got to the point where it is registered (i.e it having the DevAddr).

Have anyone had success with the OTAA connection? Thanks in advance for sharing and helping!

Error Message Log in the next comment.

[LiyaoJiang1998]

Error Message Log:
Mode <- SLEEP
Mode <- FSK_STDBY
Mode <- SLEEP
Mode <- FSK_STDBY
Mode <- SLEEP
2019-07-19 09:33:59,863 - Dragino - 57 - DEBUG - Nonce = [71, 146]
2019-07-19 09:33:59,867 - DraginoConfig - 299 - INFO - Using OTAA mode
2019-07-19 09:33:59,868 - DraginoConfig - 340 - DEBUG - Converted 8/8 items
2019-07-19 09:33:59,868 - DraginoConfig - 340 - DEBUG - Converted 8/8 items
2019-07-19 09:33:59,869 - DraginoConfig - 340 - DEBUG - Converted 16/16 items
2019-07-19 09:33:59,869 - DraginoConfig - 307 - DEBUG - GPS Baud Rate: 9600
2019-07-19 09:33:59,870 - DraginoConfig - 308 - DEBUG - GPS Serial Port: /dev/serial0
2019-07-19 09:33:59,871 - DraginoConfig - 309 - DEBUG - GPS Serial Timeout: 1
2019-07-19 09:33:59,871 - DraginoConfig - 310 - DEBUG - GPS Wait Period: 10
2019-07-19 09:33:59,872 - DraginoConfig - 311 - DEBUG - Spreading factor: 7
2019-07-19 09:33:59,872 - DraginoConfig - 312 - DEBUG - Max Power: 0F
2019-07-19 09:33:59,872 - DraginoConfig - 313 - DEBUG - Output Power: 0E
2019-07-19 09:33:59,873 - DraginoConfig - 314 - DEBUG - Sync Word: 34
2019-07-19 09:33:59,873 - DraginoConfig - 315 - DEBUG - RX CRC: True
2019-07-19 09:33:59,873 - DraginoConfig - 316 - DEBUG - Frame Count Filename: .lora_fcount
2019-07-19 09:33:59,874 - DraginoConfig - 317 - DEBUG - Auth mode: OTTA
2019-07-19 09:33:59,874 - DraginoConfig - 323 - DEBUG - Device EUI: [0, 7, 32, 84, 154, 102, 170, 37]
2019-07-19 09:33:59,874 - DraginoConfig - 324 - DEBUG - App EUI: [112, 179, 213, 126, 208, 1, 247, 189]
2019-07-19 09:33:59,875 - DraginoConfig - 325 - DEBUG - App Key: [83, 70, 211, 48, 34, 43, 41, 24, 166, 252, 63, 235, 76, 67, 203, 92]
2019-07-19 09:33:59,875 - Dragino - 104 - INFO - Reading Frame count from: .lora_fcount
2019-07-19 09:33:59,876 - Dragino - 108 - INFO - Frame count = 0
2019-07-19 09:33:59,876 - Dragino - 73 - INFO - Frequency = 903.1
2019-07-19 09:33:59,879 - Dragino - 171 - DEBUG - Performing OTTA Join
2019-07-19 09:33:59,880 - Dragino - 175 - INFO - App key = [83, 70, 211, 48, 34, 43, 41, 24, 166, 252, 63, 235, 76, 67, 203, 92]
2019-07-19 09:33:59,880 - Dragino - 176 - INFO - App eui = [112, 179, 213, 126, 208, 1, 247, 189]
2019-07-19 09:33:59,881 - Dragino - 177 - INFO - Dev eui = [0, 7, 32, 84, 154, 102, 170, 37]
Mode <- STDBY
Mode <- TX
2019-07-19 09:33:59,946 - Dragino - 155 - DEBUG - TX Complete
Mode <- STDBY
Mode <- RXCONT
2019-07-19 10:17:30,748 - Dragino - 133 - DEBUG - Recieved message
payload: [189, 155, 42, 101, 179, 52, 101, 1, 74, 59, 57, 198, 149, 159, 168, 36, 215, 10, 3, 228, 209, 56, 68, 3, 241, 112, 34, 25, 181, 113, 51, 154, 171, 16, 8, 129, 226, 238, 75, 195, 201, 78, 103, 71, 64, 130, 207, 228, 65, 36, 114, 21, 143, 11, 231, 8, 155, 98, 53, 251, 248, 151, 133, 131, 139, 42, 71, 150, 15, 55, 23, 93, 227, 61, 2, 107, 50, 113, 246, 178, 48, 194, 146, 215, 13, 65, 13, 200, 76, 171, 97, 37, 216, 165, 31, 216, 89, 64, 87, 154, 73, 161, 60, 119, 234, 51, 68, 198, 128, 88, 58, 82, 19, 251, 7, 152]
Traceback (most recent call last):
  File "/home/pi/pedestrian-counter/src/dragino/SX127x/LoRa.py", line 157, in _dio0
    self.on_rx_done()
  File "/home/pi/pedestrian-counter/src/dragino/dragino.py", line 137, in on_rx_done
    lorawan.read(payload)
  File "/home/pi/pedestrian-counter/src/dragino/LoRaWAN/PhyPayload.py", line 20, in read
    self.mhdr = MHDR(packet[0])
  File "/home/pi/pedestrian-counter/src/dragino/LoRaWAN/MHDR.py", line 24, in __init__
    raise MalformedPacketException("Invalid major version %d"%mversion)
dragino.LoRaWAN.MalformedPacketException.MalformedPacketException: Invalid major version 1

2019-072019-07-19 10:51:20,632 - Dragino - 133 - DEBUG - Recieved message
payload: [26, 24, 122, 134, 203, 87, 187, 164, 167, 147, 23, 67, 42, 116, 221, 66, 101, 39, 190, 1, 118, 240, 212, 80, 128, 73, 151, 149, 136, 215, 133, 159, 247, 236, 236, 54, 70, 86, 28, 192, 191, 233, 229, 59, 143, 149, 53, 111, 94, 51, 188, 23, 255, 183, 4, 100, 71, 253, 106, 218, 215, 94, 232, 196, 29, 180, 216, 150, 7, 249, 156, 157, 143, 20, 145, 98, 78, 41, 27, 244, 86, 83, 82, 110, 170, 211, 107, 214, 200, 2, 146, 189, 127, 255, 186, 6, 252, 104, 19, 189, 16, 175, 26, 113, 128, 127, 33, 155, 103, 119, 35, 58, 183, 225, 243, 192, 196, 222, 147, 215, 226, 136, 205, 103, 205, 4, 160, 91, 77, 59, 238, 74, 77, 0, 169, 139, 207, 65, 28, 234, 251, 51, 47, 16, 128, 61, 63, 78, 84, 248, 134, 217, 209, 196, 46, 99, 172, 121, 155, 20]
Traceback (most recent call last):
  File "/home/pi/pedestrian-counter/src/dragino/SX127x/LoRa.py", line 157, in _dio0
    self.on_rx_done()
  File "/home/pi/pedestrian-counter/src/dragino/dragino.py", line 137, in on_rx_done
    lorawan.read(payload)
  File "/home/pi/pedestrian-counter/src/dragino/LoRaWAN/PhyPayload.py", line 20, in read
    self.mhdr = MHDR(packet[0])
  File "/home/pi/pedestrian-counter/src/dragino/LoRaWAN/MHDR.py", line 24, in __init__
    raise MalformedPacketException("Invalid major version %d"%mversion)
dragino.LoRaWAN.MalformedPacketException.MalformedPacketException: Invalid major version 2

[pjb304]

Hi,

Thanks for the pull request I'll try to get to it later this week. We mainly focus on ABP so the OTAA stuff hasn't been looked at in a while.

My memory is that OTAA worked when last tested using the things network as the server in the 868 region. I'll test this again later in the week.

Phil

[LiyaoJiang1998]

Hi Phil,

Thanks for the response! Btw, I am in Canada/US 915 region. Here is the Documentation for the Actility ThingPark that we use.

Also, when I search on the Internet, someone suggested for the other LIMC library, the APPEUI and DEVEUI are LSBF, and DEVKEY (AppKey) is MSBF.

So, I am wondering for this repo, am I supposed to use MSBF for all three of the AppEUI, DevEUI and AppKey?

Thanks! Liyao

[pjb304]

I had wondered if it was an 868 vs 915 issue but it doesn't feel like it.

I think it is MSB that's needed, definitely worth a try

[LiyaoJiang1998]

Yeah, I agree with you that 868 vs 915 should not be a issue, because I used this library with ABP on The Things Network and it worked with 915.

I've tried yesterday to change the order (LSB/MSB), and it didn't solve the issue.

[pjb304]

Thanks for the pull request as you can see I've combined it into the main repo.

I've just tested OTAA here and it's working absolutely fine

pi@penguin:~/dragino $ ./test.py
Mode <- SLEEP
Mode <- FSK_STDBY
Mode <- SLEEP
Mode <- FSK_STDBY
Mode <- SLEEP
2019-07-25 16:50:23,170 - Dragino - 57 - DEBUG - Nonce = [34, 175]
2019-07-25 16:50:23,178 - DraginoConfig - 299 - INFO - Using OTAA mode
2019-07-25 16:50:23,179 - DraginoConfig - 340 - DEBUG - Converted 8/8 items
2019-07-25 16:50:23,180 - DraginoConfig - 340 - DEBUG - Converted 8/8 items
2019-07-25 16:50:23,181 - DraginoConfig - 340 - DEBUG - Converted 16/16 items
2019-07-25 16:50:23,182 - DraginoConfig - 307 - DEBUG - GPS Baud Rate: 9600
2019-07-25 16:50:23,183 - DraginoConfig - 308 - DEBUG - GPS Serial Port: /dev/serial0
2019-07-25 16:50:23,185 - DraginoConfig - 309 - DEBUG - GPS Serial Timeout: 1
2019-07-25 16:50:23,186 - DraginoConfig - 310 - DEBUG - GPS Wait Period: 10
2019-07-25 16:50:23,186 - DraginoConfig - 311 - DEBUG - Spreading factor: 7
2019-07-25 16:50:23,187 - DraginoConfig - 312 - DEBUG - Max Power: 0F
2019-07-25 16:50:23,188 - DraginoConfig - 313 - DEBUG - Output Power: 0E
2019-07-25 16:50:23,188 - DraginoConfig - 314 - DEBUG - Sync Word: 34
2019-07-25 16:50:23,189 - DraginoConfig - 315 - DEBUG - RX CRC: True
2019-07-25 16:50:23,190 - DraginoConfig - 316 - DEBUG - Frame Count Filename: .lora_fcount
2019-07-25 16:50:23,190 - DraginoConfig - 317 - DEBUG - Auth mode: OTTA
2019-07-25 16:50:23,191 - DraginoConfig - 323 - DEBUG - Device EUI: [XX, XX, XX, XX, XX, XX, XX, XX]
2019-07-25 16:50:23,192 - DraginoConfig - 324 - DEBUG - App EUI: [XX, XX, XX, XX, XX, XX, XX, XX]
2019-07-25 16:50:23,192 - DraginoConfig - 325 - DEBUG - App Key: [XX, XX, XX, XX, XX, XX, XX, XX, XX, XX, XX, XX, XX, XX, XX, XX]
2019-07-25 16:50:23,193 - Dragino - 104 - INFO - Reading Frame count from: .lora_fcount
2019-07-25 16:50:23,194 - Dragino - 108 - INFO - Frame count = 6
2019-07-25 16:50:23,196 - Dragino - 73 - INFO - Frequency = 868.3
2019-07-25 16:50:23,200 - Dragino - 171 - DEBUG - Performing OTTA Join
2019-07-25 16:50:23,201 - Dragino - 175 - INFO - App key = [XX, XX, XX, XX, XX, XX, XX, XX, XX, XX, XX, XX, XX, XX, XX, XX]
2019-07-25 16:50:23,202 - Dragino - 176 - INFO - App eui = [XX, XX, XX, XX, XX, XX, XX, XX]
2019-07-25 16:50:23,202 - Dragino - 177 - INFO - Dev eui = [XX, XX, XX, XX, XX, XX, XX, XX]
Mode <- STDBY
Mode <- TX
Waiting
2019-07-25 16:50:23,268 - Dragino - 155 - DEBUG - TX Complete
Mode <- STDBY
Mode <- RXCONT
Waiting
Waiting
2019-07-25 16:50:28,341 - Dragino - 133 - DEBUG - Recieved message
2019-07-25 16:50:28,344 - Dragino - 141 - DEBUG - Join resp
2019-07-25 16:50:28,346 - Dragino - 145 - INFO - Device: [XX, XX, XX, XX]
2019-07-25 16:50:28,347 - Dragino - 147 - INFO - Network key: [XX, XX, XX, XX, XX, XX, XX, XX, XX, XX, XX, XX, XX, XX, XX, XX]
2019-07-25 16:50:28,349 - Dragino - 149 - INFO - APPS key: [XX, XX, XX, XX, XX, XX, XX, XX, XX, XX, XX, XX, XX, XX, XX, XX]
2019-07-25 16:50:29,214 - Dragino - 211 - DEBUG - Frame count 6
2019-07-25 16:50:29,216 - Dragino - 125 - DEBUG - Frame count 7 saved to .lora_fcount
Mode <- STDBY
2019-07-25 16:50:29,219 - Dragino - 215 - DEBUG - Packet = [64, 171, 39, 1, 38, 0, 6, 0, 1, 14, 22, 4, 187, 50, 29, 28, 13, 57, 79, 130, 236, 236, 206, 185]
Mode <- TX
2019-07-25 16:50:29,221 - Dragino - 219 - INFO - Succeeded on attempt 1/3
Sent message
2019-07-25 16:50:29,283 - Dragino - 155 - DEBUG - TX Complete
Mode <- STDBY
Mode <- RXCONT
2019-07-25 16:50:30,224 - Dragino - 211 - DEBUG - Frame count 7
2019-07-25 16:50:30,226 - Dragino - 125 - DEBUG - Frame count 8 saved to .lora_fcount
Mode <- STDBY
2019-07-25 16:50:30,229 - Dragino - 215 - DEBUG - Packet = [64, 171, 39, 1, 38, 0, 7, 0, 1, 138, 52, 9, 134, 10, 231, 55, 111, 229, 132, 12, 61, 138, 234, 85]
Mode <- TX
2019-07-25 16:50:30,231 - Dragino - 219 - INFO - Succeeded on attempt 1/3
Sent message
2019-07-25 16:50:30,293 - Dragino - 155 - DEBUG - TX Complete
Mode <- STDBY
Mode <- RXCONT
2019-07-25 16:50:31,234 - Dragino - 211 - DEBUG - Frame count 8
2019-07-25 16:50:31,235 - Dragino - 125 - DEBUG - Frame count 9 saved to .lora_fcount
Mode <- STDBY
2019-07-25 16:50:31,239 - Dragino - 215 - DEBUG - Packet = [64, 171, 39, 1, 38, 0, 8, 0, 1, 250, 111, 220, 194, 140, 177, 71, 184, 158, 242, 56, 166, 70, 194, 80]
Mode <- TX
2019-07-25 16:50:31,241 - Dragino - 219 - INFO - Succeeded on attempt 1/3
Sent message
2019-07-25 16:50:31,303 - Dragino - 155 - DEBUG - TX Complete
Mode <- STDBY
Mode <- RXCONT
2019-07-25 16:50:32,244 - Dragino - 211 - DEBUG - Frame count 9
2019-07-25 16:50:32,245 - Dragino - 125 - DEBUG - Frame count 10 saved to .lora_fcount
Mode <- STDBY
2019-07-25 16:50:32,249 - Dragino - 215 - DEBUG - Packet = [64, 171, 39, 1, 38, 0, 9, 0, 1, 149, 157, 14, 41, 2, 142, 107, 134, 146, 64, 160, 119, 146, 242, 188]
Mode <- TX
2019-07-25 16:50:32,251 - Dragino - 219 - INFO - Succeeded on attempt 1/3
Sent message
2019-07-25 16:50:32,313 - Dragino - 155 - DEBUG - TX Complete
Mode <- STDBY
Mode <- RXCONT
2019-07-25 16:50:33,254 - Dragino - 211 - DEBUG - Frame count 10
2019-07-25 16:50:33,255 - Dragino - 125 - DEBUG - Frame count 11 saved to .lora_fcount
Mode <- STDBY
2019-07-25 16:50:33,259 - Dragino - 215 - DEBUG - Packet = [64, 171, 39, 1, 38, 0, 10, 0, 1, 207, 228, 196, 72, 35, 71, 191, 159, 172, 107, 248, 123, 204, 81, 244]
Mode <- TX
2019-07-25 16:50:33,261 - Dragino - 219 - INFO - Succeeded on attempt 1/3
Sent message
2019-07-25 16:50:33,323 - Dragino - 155 - DEBUG - TX Complete
Mode <- STDBY
Mode <- RXCONT

My reading of https://lora-alliance.org/sites/default/files/2018-04/lorawantm_specification_-v1.1.pdf is that the only valid value for the MHDR_MAJOR field is 00 as 01,10, & 11 are reserved for future use. Which means that the check is doing exactly what it should - checking to see if the major version of LoRaWAN matches what it's written for and if not failing. As to why that bit is 1 and not 0 I'm afraid I don't know.

In TTN I can look at the data transmitted by the gateway as a response to the OTAA join and so can check that it's giving me what I expect. Is there the same thing in actility?

I'm afraid I'm not sure what your problem is and as I can't reproduce it I'm not sure I can be much help here. But feel free to bounce ideas off me, and if you need another code change I'll be happy to look at a PR.

[LiyaoJiang1998]

Thanks for testing the OTAA on The Things Network, I coudn't see the actual data in Actility which is a bit tricky. I will read the specification doc and see what happens then. Thanks for the help!