That’s certainly the downlink data but the entire packet will start at 0 and end using a variable I can’t remember because I’ve only ever printed the payload I sent, not the entire incoming downlink.
It would help if you turned off confirmed uplinks so the logs are cluttered with the gateway sending the ACK - leaving aside the FUP.
This looks like it may be the culprit!
I have cleared the downlink queue for my device and unfortunately i still get the weird reponse.
Made sure the queue is empty using the cli:
▶ ttn-lw-cli end-devices downlink list <appId> <deviceId>
[]
I have also disabled the confirmed uplinks so i can provide a more clear gateway log. When i do this i obviously dont receive the downlink because it’s sent in the confirm. Here is the log:
2021-09-08T12:10:35.712590+00:00 klk-fevo-0300E6 lorafwd[928]: <6> | lora uplink (3A100043), payload 20 B, channel 867.9 MHz, crc ok, bw 125 kHz, sf 7, cr 4/5
2021-09-08T12:10:35.712669+00:00 klk-fevo-0300E6 lorafwd[928]: <6> | Unconfirmed Data Up, DevAddr 26011D91, FCtrl [ADR], FCnt 0, FPort 1
2021-09-08T12:10:35.712727+00:00 klk-fevo-0300E6 lorafwd[928]: <6> | - radio (00000004)
2021-09-08T12:10:35.712836+00:00 klk-fevo-0300E6 lorafwd[928]: <6> | - demodulator counter 458398067, UTC time 2021-09-08T12:10:35.698002Z, rssi -38 dB, snr 7.5< 9.5 <11.5 dB
2021-09-08T12:10:35.714519+00:00 klk-fevo-0300E6 lorafwd[928]: <6> Uplink message (BACF) sent
2021-09-08T12:10:35.716353+00:00 klk-fevo-0300E6 lorafwd[928]: <6> Received uplink message:
2021-09-08T12:10:35.716788+00:00 klk-fevo-0300E6 lorad[900]: <6> Sent 2 uplink messages
2021-09-08T12:10:35.717508+00:00 klk-fevo-0300E6 lorafwd[928]: <6> | lora uplink (3A100044), payload 20 B, channel 868.1 MHz, crc error, bw 125 kHz, sf 7, cr 4/5
2021-09-08T12:10:35.718210+00:00 klk-fevo-0300E6 lorafwd[928]: <6> | - radio (00000105)
2021-09-08T12:10:35.718919+00:00 klk-fevo-0300E6 lorafwd[928]: <6> | - demodulator counter 458398068, UTC time 2021-09-08T12:10:35.698003Z, rssi -91 dB, snr -7.75< -5.25 <-2.75 dB
2021-09-08T12:10:35.719318+00:00 klk-fevo-0300E6 lorafwd[928]: <6> Dropping message with invalid CRC
2021-09-08T12:10:35.763720+00:00 klk-fevo-0300E6 lorafwd[928]: <6> Uplink message (BACF) acknowledged in 49.1615 ms
2021-09-08T12:10:42.036391+00:00 klk-fevo-0300E6 lorafwd[928]: <6> Heartbeat (BC03) sent
2021-09-08T12:10:42.100121+00:00 klk-fevo-0300E6 lorafwd[928]: <6> Heartbeat (BC03) acknowledged in 63.7106 ms
2021-09-08T12:10:42.319388+00:00 klk-fevo-0300E6 lorafwd[928]: <6> Received uplink message:
2021-09-08T12:10:42.319526+00:00 klk-fevo-0300E6 lorafwd[928]: <6> | lora uplink (3A100045), payload 20 B, channel 867.9 MHz, crc error, bw 125 kHz, sf 7, cr 4/5
2021-09-08T12:10:42.319591+00:00 klk-fevo-0300E6 lorafwd[928]: <6> | - radio (00000004)
2021-09-08T12:10:42.319699+00:00 klk-fevo-0300E6 lorafwd[928]: <6> | - demodulator counter 465006787, UTC time 2021-09-08T12:10:42.306722Z, rssi -89 dB, snr -9.75< -5.25 <-1.5 dB
2021-09-08T12:10:42.319748+00:00 klk-fevo-0300E6 lorafwd[928]: <6> Dropping message with invalid CRC
2021-09-08T12:10:42.321531+00:00 klk-fevo-0300E6 lorafwd[928]: <6> Received uplink message:
2021-09-08T12:10:42.322009+00:00 klk-fevo-0300E6 lorafwd[928]: <6> | lora uplink (3A100046), payload 20 B, channel 868.1 MHz, crc ok, bw 125 kHz, sf 7, cr 4/5
2021-09-08T12:10:42.322410+00:00 klk-fevo-0300E6 lorafwd[928]: <6> | Unconfirmed Data Up, DevAddr 26011D91, FCtrl [ADR], FCnt 1, FPort 1
2021-09-08T12:10:42.322768+00:00 klk-fevo-0300E6 lorafwd[928]: <6> | - radio (00000105)
2021-09-08T12:10:42.323172+00:00 klk-fevo-0300E6 lorafwd[928]: <6> | - demodulator counter 465007068, UTC time 2021-09-08T12:10:42.307003Z, rssi -40 dB, snr 5.75< 10.25 <14.75 dB
2021-09-08T12:10:42.325182+00:00 klk-fevo-0300E6 lorafwd[928]: <6> Uplink message (BAD0) sent
2021-09-08T12:10:42.326012+00:00 klk-fevo-0300E6 lorad[900]: <6> Sent 3 uplink messages
2021-09-08T12:10:42.327675+00:00 klk-fevo-0300E6 lorafwd[928]: <6> Received uplink message:
2021-09-08T12:10:42.328156+00:00 klk-fevo-0300E6 lorafwd[928]: <6> | lora uplink (3A100047), payload 20 B, channel 868.3 MHz, crc error, bw 125 kHz, sf 7, cr 4/5
2021-09-08T12:10:42.328653+00:00 klk-fevo-0300E6 lorafwd[928]: <6> | - radio (00000106)
2021-09-08T12:10:42.329087+00:00 klk-fevo-0300E6 lorafwd[928]: <6> | - demodulator counter 465007076, UTC time 2021-09-08T12:10:42.307011Z, rssi -89 dB, snr -8.25< -5 <-2.25 dB
2021-09-08T12:10:42.329436+00:00 klk-fevo-0300E6 lorafwd[928]: <6> Dropping message with invalid CRC
2021-09-08T12:10:42.373923+00:00 klk-fevo-0300E6 lorafwd[928]: <6> Uplink message (BAD0) acknowledged in 48.7115 ms
It concerns me it keeps repeating: Dropping message with invalid CRC The messages are all delivered as expected though.
At this point it is really starting to look like my only option is to move away from The Things Network entirely. :c
The hex-decoded command received by the end-device is what the Network Server has sent on FPort 0 (MAC commands).
As you can see on the gateway log the packet has a size of 56 bytes while the hex-decoded is 43 bytes.
The difference corresponds to the LoRaWAN frame overhead which is 13 bytes.
Knowing this the received payload is valid and corresponds to MAC commands sent by the Network Server. At the end of this post I have put the how to decode these MAC commands.
As you can see the Network Server is creating the additional channels, setup the Rx windows parameters and instructing the end-device to use highest datarate and power on all setup channels.
As @descartes mentioned the end-device stack must be able to correctly handle these MAC commands in order to have everything work properly.
Therefore, I think that you have no other choice than update the firmware on your devices in order to be LoRaWAN compliant.
MAC commands decoding:
0503D2AD84 - RXParamSetupReq :
RX1DROffset: 0
RX2DataRate: 3
Frequency : D2AD84 -> 0x84ADD2 * 100 = 869.525 MHz
06 - DevStatusReq : No payload
0703184F8450 - NewChannelReq :
ChIndex : 03
Frequency : 184F84 -> 0x844F18 * 100 = 867.1 MHz
DRRange : 50 -> Max: DR_5, Min: DR_0
0704E8568450 - NewChannelReq :
ChIndex : 04
Frequency : E85684 -> 0x8456E8 * 100 = 867.3 MHz
DRRange : 50 -> Max: DR_5, Min: DR_0
0705B85E8450 - NewChannelReq :
ChIndex : 05
Frequency : B85E84 -> 0x845EB8 * 100 = 867.5 MHz
DRRange : 50 -> Max: DR_5, Min: DR_0
070688668450 - NewChannelReq :
ChIndex : 06
Frequency : 886684 -> 0x846688 * 100 = 867.7 MHz
DRRange : 50 -> Max: DR_5, Min: DR_0
0707586E8450 - NewChannelReq :
ChIndex : 07
Frequency : 586E84 -> 0x846E58 * 100 = 867.9 MHz
DRRange : 50 -> Max: DR_5, Min: DR_0
0350FF0003 - LinkADRReq :
DataRate_TXPower: 50 -> DR_5, TX_P_0: Max output power
ChMask : FF00 -> 00FF: 8 first channels enabled
Redundancy : 03 -> ChMaskCntl: 0, NbTrans: 3
0805 - RXTimingSetupReq:
RxTimingSettings: 05 -> RFU:0, Del:5 -> Rx1Delay is 5 seconds
Alright then. I want to thank you all for the incredible help. Wouldn’t have figured all this out without it!
This is a known issue - it’s no longer in the queue so it’s not something you can clear easily - I’ll get the commands sorted.
The magic flush command is:
ttn-lw-cli dev set $application $device --unset mac-state.pending-application-downlink
The invalid CRC comes about because your node is too close to the gateway, overloading the ftont end and bleeding over into false reception on a different channel, which ends up ~40 dB weaker and the 300uS difference in timing is little more than a rounding error.
You need to run spec compliant firmware with TTN but you also need your nodes you be a few meters away from the gateway so they don’t overload it.