Devices are missing OTAA RX2 SF12?

[Smeedy]

Hi there,

So I've ditched the default Lorank8 install and switched to this project (kudos!) for provisioning a couple of gateways. But since the upgrade all the nodes are missing the OTAA activations. I see the activation on the Handler logs (running own stack), but they are not being picked up in the RX2 window as it seems. Nodes are programmed to listen to OTAA RX2/SF12 and gateways are running an LTE Dongle.

Am I missing something obvious? I can isolate the phenomenon to the upgrade as the old setup still works, and a spare Conduit also checks out.

Good work, keep it up! Martijn

[matthijskooijman]

Nice to hear our work is of use to you :-)

AFAICS our gateways are handling OTAA just fine. A first thought that springs to mind is an incompatible SF setting for RX2, but that's something between the node and the server, the gateway should just do whatever it's told.

Another thought could be additional latency from the LTE dongle, but that would also show up in the old setup (assuming that is also using the dongle). Also, with joins and RX2, there is a 6 second window IIRC, so that should be plenty...

One thing you could try is update the actual forwarder to a more recent version, since this is just some version I compiled a while ago. IIRC the README of this repo has info on how to compile a new version.

[Smeedy]

Hi Matthijs, thanks for the hints. The stack can use a brush-up, so I'll take this up with the guy responsible for the ECS TTN stack. I will report back.

cheers, Martijn

[Smeedy]

Seems like I was chasing the wrong ghost here. The nodes are indeed receiving on RX1/SF10/868.1, but are still missing the activation. The dev_addr are indeed handed out, and the Handler/Broker logs on the server-side v2.9.4 private stack also check out. Nothing special there.

This is the MQTT log on all activity for the application EUI:

Client mosqsub|4345-Antares.lo received PINGRESP
Client mosqsub|4345-Antares.lo received PUBLISH (d0, q0, r0, m0, 'tst-xxxxxx/devices/xx-xxxxxx-012/events/activations', ... (360 bytes))
tst-xxxxxx/devices/xx-xxxxxx-012/events/activations {"app_eui":"70B3XXXXXXXXC9","dev_eui":"XXXXXXXXXXXXX012","dev_addr":"260002D7","metadata":{"time":"2018-10-04T07:31:12.278351133Z","frequency":868.1,"modulation":"LORA","data_rate":"SF10BW125","airtime":206848000,"coding_rate":"4/5","gateways":[{"gtw_id":"eui-XXXXXXXXXX0001","timestamp":387188868,"time":"","channel":0,"rssi":-54,"snr":14,"rf_chain":1}]}}
Client mosqsub|4345-Antares.lo sending PINGREQ
Client mosqsub|4345-Antares.lo received PINGRESP
Client mosqsub|4345-Antares.lo received PUBLISH (d0, q0, r0, m0, 'tst-xxxxxx/devices/xx-xxxxxx-012/events/activations', ... (362 bytes))
tst-xxxxxx/devices/xx-xxxxxx-012/events/activations {"app_eui":"70B3XXXXXXXXC9","dev_eui":"XXXXXXXXXXXXX012","dev_addr":"26000F61","metadata":{"time":"2018-10-04T07:32:12.289628889Z","frequency":868.1,"modulation":"LORA","data_rate":"SF10BW125","airtime":206848000,"coding_rate":"4/5","gateways":[{"gtw_id":"eui-XXXXXXXXXX0001","timestamp":447198588,"time":"","channel":0,"rssi":-48,"snr":10.8,"rf_chain":1}]}}

Thought it was due to some timing issues due to LTE, but this particular gateway (I have 6 of them) is now on the bench connected to LAN ethernet, so i can rule out any timing concerns. Still the same issues. When I activate a spare MultiTech Conduit using the Kersing mp installer in the room which also forwards to our tst private stack, everything checks out.

The installs on the Lorank8 gateways are from a fork from this project. Nothing fancy there I think, I only disabled the USB dongle config since I am using a mini-router.

I did noticed something off when resetting the IC888a:

root@ksp-gateway-1:/opt/ttn-gateway# ./ResetIC880A
gpio/direction: No such file or directory
gpio/set-value: No such file or directory
gpio/set-value: No such file or directory
gpio/set-value: No such file or directory

Are we missing some init for the /dev to be populated? Also, could this be a mjs_gateway_configuration/cdist/conf/files/forwarder/mp_pkt_fwd version mismatch?

Thanks for your thoughts, Martijn

[Smeedy]

Additionally some logs which also makes me wonder:

Oct 04 10:09:08 ksp-gateway-1 mp_pkt_fwd[2470]: 10:09:08  INFO: Found 1 servers in array.
Oct 04 10:09:08 ksp-gateway-1 mp_pkt_fwd[2470]: 10:09:08  INFO: Server 0 configured to "router.eu.thethings.network"
Oct 04 10:09:08 ksp-gateway-1 mp_pkt_fwd[2470]: 10:09:08  INFO: Server 1 configured to "router.iot.xxxxxxxx"
Oct 04 10:09:08 ksp-gateway-1 mp_pkt_fwd[2470]: 10:09:08  INFO: Server 2 configured to "router.iot.tst.aws.xxxx-xxx.com"
Oct 04 10:09:08 ksp-gateway-1 mp_pkt_fwd[2470]: 10:09:08  INFO: packets received with a valid CRC will be forwarded
Oct 04 10:09:08 ksp-gateway-1 mp_pkt_fwd[2470]: 10:09:08  INFO: packets received with a CRC error will NOT be forwarded
Oct 04 10:09:08 ksp-gateway-1 mp_pkt_fwd[2470]: 10:09:08  INFO: packets received with no CRC will be forwarded
Oct 04 10:09:08 ksp-gateway-1 mp_pkt_fwd[2470]: 10:09:08  INFO: Reference latitude is configured to 52.xxxx deg
Oct 04 10:09:08 ksp-gateway-1 mp_pkt_fwd[2470]: 10:09:08  INFO: Reference longitude is configured to 6.xxxx deg
Oct 04 10:09:08 ksp-gateway-1 mp_pkt_fwd[2470]: 10:09:08  INFO: Reference altitude is configured to 16 meters
Oct 04 10:09:08 ksp-gateway-1 mp_pkt_fwd[2470]: 10:09:08  INFO: GPS is disabled
Oct 04 10:09:08 ksp-gateway-1 mp_pkt_fwd[2470]: 10:09:08  INFO: Upstream data is enabled
Oct 04 10:09:09 ksp-gateway-1 mp_pkt_fwd[2470]: 10:09:08  INFO: Downstream data is enabled
Oct 04 10:09:09 ksp-gateway-1 mp_pkt_fwd[2470]: 10:09:08  INFO: Ghoststream data is disabled
Oct 04 10:09:09 ksp-gateway-1 mp_pkt_fwd[2470]: 10:09:08  INFO: Radiostream data is enabled
Oct 04 10:09:09 ksp-gateway-1 mp_pkt_fwd[2470]: 10:09:08  INFO: Statusstream data is enabled
Oct 04 10:09:09 ksp-gateway-1 mp_pkt_fwd[2470]: 10:09:08  INFO: Beacon is disabled
Oct 04 10:09:09 ksp-gateway-1 mp_pkt_fwd[2470]: 10:09:08  INFO: Packet logger is disabled
Oct 04 10:09:09 ksp-gateway-1 mp_pkt_fwd[2470]: 10:09:08  INFO: Flush output after statistic is disabled
Oct 04 10:09:09 ksp-gateway-1 mp_pkt_fwd[2470]: 10:09:08  INFO: Flush after each line of output is disabled
Oct 04 10:09:09 ksp-gateway-1 mp_pkt_fwd[2470]: 10:09:08  INFO: Watchdog is disabled
Oct 04 10:09:09 ksp-gateway-1 mp_pkt_fwd[2470]: 10:09:08  INFO: [Transports] Initializing protocol for 3 servers
Oct 04 10:09:09 ksp-gateway-1 mp_pkt_fwd[2470]: 10:09:08  INFO: [TTN] server "router.eu.thethings.network" connected
Oct 04 10:09:09 ksp-gateway-1 mp_pkt_fwd[2470]: 10:09:08  INFO: Successfully contacted server router.iot.xxxxxxxx
Oct 04 10:09:09 ksp-gateway-1 mp_pkt_fwd[2470]: 10:09:08  INFO: Successfully contacted server router.iot.tst.aws.xxxx-xxx.com
Oct 04 10:09:09 ksp-gateway-1 mp_pkt_fwd[2470]: 10:09:08  INFO: [main] Starting the concentrator
Oct 04 10:09:09 ksp-gateway-1 mp_pkt_fwd[2470]: ERROR: Failed to load fw 1
Oct 04 10:09:09 ksp-gateway-1 mp_pkt_fwd[2470]: ERROR: Version of calibration firmware not expected, actual:0 expected:2
Oct 04 10:09:09 ksp-gateway-1 mp_pkt_fwd[2470]: 10:09:09  ERROR: [main] failed to start the concentrator

Still the gw seems to function as we see packets coming by. Still it is limping as it seems.

[matthijskooijman]

Are we missing some init for the /dev to be populated? Also, could this be a mjs_gateway_configuration/cdist/conf/files/forwarder/mp_pkt_fwd version mismatch?

The errors suggest to me that the GPIO pin is not available or perhaps a driver is not loaded. This GPIO pin is used to force a reset of the IC880A board, since it does not have a proper power-on-reset. My experience is that when this reset does not happen, the forwarder fails to start entirely, which I think is also visible in your logs "failed to start the concentrator".

I would then expect no packets to be forwarded by this gateway at all. Are you sure that the uplink and downlink traffic you're seeing actually goes through this Lorank gateway? Could it be that there is some other (distant?) gateway that receives the uplink and then fails to send to downlink somehow?