ignoring push_data: Decode(InvalidCrc), module: gateway

[btcdevit1]

Ive installed gateway-rs on an Multitech MTCDT-246A . everythings seems fine but in the logs i see only

ignoring push_data: Decode(InvalidCrc), module: gateway

One Lora Node is active but i dont see any data transfers. (joining messages etc)

[djieno]

Same here on a gateway-rs https://github.com/helium/gateway-rs/releases/tag/v1.0.0-alpha.21

in mikrotik wap_lr8_kit in gateway-rs logging

[madninja]

make sure your packet forwarder is configured correctly? Your spreadsheet/tool is maybe not something that is the right wire protocol?

[lthiery]

My best guess is that the packet forwarder on the MTCDT is using the CRC field in an unexpected way. The GWMP specification we are using expects a number to represent CRC status. Perhaps this packet forwarder is writing a string? If you can share the raw UDP frame, I can look into it more.

[djieno]

I used tcpdump

@madninja routeros in mikrotik

[lthiery]

@djieno can you copy paste the frame from 15:15:09:121632 in text? that way i can work on it easily

[lthiery]

"stat": -1 is valid so its curious why the decode isn't working

[djieno]

@lthiery https://pastebin.com/kcVXtP7d

15:15:09.121632 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto UDP (17), length 273) 10.1.1.87.36320 > amd1.lan.1680: [udp sum ok] UDP, length 245 0x0000: 4500 0111 0000 4000 4011 2328 0a01 0157 E.....@.@.#(...W 0x0010: 0a01 015c 8de0 0690 00fd a1bf 0201 0900 ............... 0x0020: 3730 3920 5a00 4800 7b22 7278 706b 223a 709.Z.H.{"rxpk": 0x0030: 5b7b 2263 6861 6e22 3a32 2c22 636f 6472 [{"chan":2,"codr 0x0040: 223a 2234 2f35 222c 2264 6174 6122 3a22 ":"4/5","data":" 0x0050: 514a 6369 4143 6141 6870 7047 567a 2f2f QJciACaAhppGVz// 0x0060: 6269 4532 3043 7575 222c 2264 6174 7222 biE20Cuu","datr" 0x0070: 3a22 5346 3132 4257 3132 3522 2c22 6672 :"SF12BW125","fr 0x0080: 6571 223a 3836 382e 3530 3030 3030 2c22 eq":868.500000," 0x0090: 6c73 6e72 223a 2d31 382e 3530 3030 3030 lsnr":-18.500000 0x00a0: 2c22 6d6f 6475 223a 224c 4f52 4122 2c22 ,"modu":"LORA"," 0x00b0: 7266 6368 223a 312c 2272 7373 6922 3a2d rfch":1,"rssi":- 0x00c0: 3131 352c 2273 697a 6522 3a31 382c 2273 115,"size":18,"s 0x00d0: 7461 7422 3a2d 312c 2274 696d 6522 3a22 tat":-1,"time":" 0x00e0: 3230 3231 2d31 312d 3132 5431 353a 3135 2021-11-12T15:15 0x00f0: 3a30 372e 3737 3337 3439 5a22 2c22 746d :07.773749Z","tm 0x0100: 7374 223a 3139 3534 3337 3335 3234 7d5d st":1954373524}] 0x0110: 7d } 15:15:09.122530 IP (tos 0x0, ttl 64, id 40107, offset 0, flags [DF], proto UDP (17), length 32) amd1.lan.1680 > 10.1.1.87.36320: [udp sum ok] UDP, length 4 0x0000: 4500 0020 9cab 4000 4011 876d 0a01 015c E.....@.@..m...\ 0x0010: 0a01 0157 0690 8de0 000c 49af 0201 0901 ...W......I.....

[djieno]

docker gateway-rs level debug INFO uplink @4239916148 us, 868.10 MHz, Ok(DataRate(SF12, BW125)), snr: -13.75, rssi: -117, len: 30 from MacAddress(37:30:39:20:5A:00:48:00), module: gateway DEBG send frame=Data { stream_id: StreamId(1) } DEBG received frame=WindowUpdate { stream_id: StreamId(1), size_increment: 158 } DEBG received frame=WindowUpdate { stream_id: StreamId(0), size_increment: 158 } DEBG received frame=Data { stream_id: StreamId(1) }

tcpdump -i enp2s0 udp port 1680 -Avvv ..............709 Z.H.{"rxpk":[{"chan":0,"codr":"4/5","data":"QLTWCyYAegMCcWhlxhXX8apeuqPbDzgG04rj+mf9","datr":"SF12BW125","freq":868.100000,"lsnr":-13.750000,"modu":"LORA","rfch":1,"rssi":-117,"size":30,"stat" :1,"time":"2021-11-12T15:53:13.308738Z","tmst":4239916148}]}
15:53:14.668513 IP (tos 0x0, ttl 64, id 59017, offset 0, flags [DF], proto UDP (17), length 32)
amd1.lan.1680 > 10.1.1.87.36320: [udp sum ok] UDP, length 4
E.. ..@.@.=.
..\
..W......B.....

[lthiery]

@djieno the frame you provided via pastebin was just fine. Looking at your original logs, it looks like some push_data frames are good and some are bad. Can you try to sample a known bad frame for me?

[djieno]

@lthiery I think here are some bad ones https://pastebin.com/LATYFtk3

[lthiery]

@djieno It takes me quite a bit of time to reformat those traces into something I can work with. Can you enable timestamps in gateway-rs and try to find the matching failed frame by timestamp?

In your settings.toml

[log]
timestamp = false

[djieno]

@lthiery yeah that seems much easier to folow. https://pastebin.com/NpeBECFT

https://pastebin.com/wyhzggbn

[lthiery]

I think I understand now. I thought the deserialization (decode) was failing, but in fact, we are throwing away the packet simply because the CRC check doesn't say OK, which is expected behavior. I think the error message needs some work though as it doesn't communicate that very well IMO

[djieno]

OK do you need some more logs? If you want, I'm happy to help if you have a new build/nightly. I wonder if anything goes through.

If I check https://explorer.helium.com/hotspots/13Ki4qyMdPhkM1S9EjocZuvqE3ekGsGtr5cvEZNqXWnq3DB9y5V/activity it shows no activity.

[lthiery]

@djieno well the logs in this ticket are basically a non-issue as RF frames with bad CRC checks don't get forwarded. No need to dig any deeper than that for now.

But you are getting RF frames with good CRC checks. Are they from your own devices?

[djieno]

@lthiery No, they're not. I will switch one on to see possible differences.

I noticed that whenever a log entry in the mikrotik arrives it's 'ok' in the gateway-rs logging about 2sec later

Nov 12 20:02:54.849 INFO uplink @2040246892 us, 868.10 MHz, Ok(DataRate(SF11, BW125)), snr: -15.5, rssi: -117, len: 15 from MacAddress(37:30:39:20:5A:00:48:00), module: gateway Nov 12 20:02:54.850 DEBG send frame=Data { stream_id: StreamId(1) } Nov 12 20:02:55.018 DEBG received frame=WindowUpdate { stream_id: StreamId(1), size_increment: 158 } Nov 12 20:02:55.018 DEBG received frame=WindowUpdate { stream_id: StreamId(0), size_increment: 158 } Nov 12 20:02:55.018 DEBG received frame=Data { stream_id: StreamId(1) } Nov 12 20:03:47.740 INFO uplink @2093117780 us, 867.10 MHz, Ok(DataRate(SF12, BW125)), snr: -7.5, rssi: -116, len: 19 from MacAddress(37:30:39:20:5A:00:48:00), module: gateway Nov 12 20:03:47.741 DEBG send frame=Data { stream_id: StreamId(1) } Nov 12 20:03:47.909 DEBG received frame=WindowUpdate { stream_id: StreamId(1), size_increment: 159 } Nov 12 20:03:47.910 DEBG received frame=WindowUpdate { stream_id: StreamId(0), size_increment: 159 } Nov 12 20:03:47.910 DEBG received frame=Data { stream_id: StreamId(1) } Nov 12 20:03:57.254 WARN ignoring push_data: Decode(InvalidCrc), module: gateway < I didn't see this coming as a log entry from mikrotik. Could it be some keep alive ?

these kept coming when I there was a relative quiet/no mikrotik log lines Nov 12 20:07:31.862 WARN ignoring push_data: Decode(InvalidCrc), module: gateway Nov 12 20:07:36.711 WARN ignoring push_data: Decode(InvalidCrc), module: gateway Nov 12 20:07:42.719 WARN ignoring push_data: Decode(InvalidCrc), module: gateway Nov 12 20:08:05.577 WARN ignoring push_data: Decode(InvalidCrc), module: gateway Nov 12 20:08:50.580 WARN ignoring push_data: Decode(InvalidCrc), module: gateway Nov 12 20:08:55.583 WARN ignoring push_data: Decode(InvalidCrc), module: gateway

The mikrotik+gateway-rs has never been successfully active. Do you see traffic in your backend since it's not showing any data in 'explorer....' ?

[lthiery]

Nov 12 20:03:57.254 WARN ignoring push_data: Decode(InvalidCrc), module: gateway < I didn't see this coming as a log entry from mikrotik. Could it be some keep alive ?

The Decode(InvalidCrc) means that the RF packet had a CRC error and so it wasn't decoded properly. Basically, it's a noisy/corrupt radio packet that is being dropped.

You are likely see data from another network which is why you are not routing it nor earning data credits. If you look at the DevAddr column, that basically confirms this as you can decode the NetID from those and none of them are the Helium NetID. More on that here.

You could try bring your own LoRaWAN device and connect it to Helium Console to test things out.

[djieno]

I will do that tomorrow. Great stuff ! Thanks @lthiery

[djieno]

This issue has been explained and can be closed. I will open another issue since 'not matter what' my setup - mikrotik + gateway-rs will not transfer any 'data' using helium devices.