V2: Cannot get downlinks

cdupont commented 4 years ago

I set up a WaziDev with LMIC: https://github.com/Waziup/WaziDev/blob/master/examples/LoRa/LoRaWAN_LPP_LMIC/LoRaWAN_LPP_LMIC.ino#L99 I can receive downlink with this. However, with WaziGate, I cannot get it. I schedule a downlink in Chirpstack, it seems to leave after a message is received:

But I don't receive on the WaziDev. Here are the single_chan_pkt_fwd log (with debug level):

[     ] waiting for packets ...
[DEBUG] CRC is correct.
[DEBUG] Received: [64 63 20 1 38 128 0 0 1 138 162 125 67 253 76 41 67 252 64 26 145 68 162 148 170 226 215 131 161 57 174 15 230 24 60 217 37 248 25 195 192 141 164 174 192 76 173 182 111 180 82 73 244 254 132 4 88 74 5 237 162 167]
[DEBUG] LoRa flags cleared.
[DEBUG] Starting 'getRSSIpacket'.
[DEBUG] Starting 'getSNR'.
[VERBO] SNR value is 7.
[VERBO] RSSI packet value is -68.
[DEBUG] Starting 'getSNR'.
[VERBO] SNR value is 7.
[     ] rx: LoRa: 868.10 MHz, SF12 BW125 CR4/5, Data: QD8UASaAAAABiqJ9Q/1MKUP8QBqRRKKUquLXg6E5rg/mGDzZJfgZw8CNpK7ATK22b7RSSfT+hARYSgXtoqc=
[     ] received 1 packets, pushing to upstream ...
[DEBUG] (-> *) raw: "\x02zg\x00\xaaUZ\x00\x00\x00\x00\x00{\"rxpk\":[{\"tmst\":2153538574,\"chan\":0,\"rfch\":0,\"freq\":868.099975,\"stat\":1,\"modu\":\"LORA\",\"datr\":\"SF12BW125\",\"codr\":\"4/5\",\"lsnr\":7.0,\"rssi\":-68,\"size\":62,\"data\":\"QD8UASaAAAABiqJ9Q/1MKUP8QBqRRKKUquLXg6E5rg/mGDzZJfgZw8CNpK7ATK22b7RSSfT+hARYSgXtoqc=\"}]}\n"
[DEBUG] pkt json: {"rxpk":[{"tmst":2153538574,"chan":0,"rfch":0,"freq":868.099975,"stat":1,"modu":"LORA","datr":"SF12BW125","codr":"4/5","lsnr":7.0,"rssi":-68,"size":62,"data":"QD8UASaAAAABiqJ9Q/1MKUP8QBqRRKKUquLXg6E5rg/mGDzZJfgZw8CNpK7ATK22b7RSSfT+hARYSgXtoqc="}]} (err:<nil>)
[     ] (-> 172.18.0.2:1700) PushData: Token: 677A, Gateway ID: AA555A0000000000, 1 rx packets
[DEBUG] (<- 172.18.0.2:1700) raw: "\x02zg\x01"
[     ] (<- 172.18.0.2:1700) PushAck: Token: 677A
[VERBO] Channel changed to 0xd90666: 868.10 Mhz
[DEBUG] Starting 'receive'.
[DEBUG] Starting 'setPacketLength'.
[DEBUG] Packet length 255 has been successfully set.
[DEBUG] Receiving LoRa mode activated with success.
[     ] waiting for packets ...

It seems that the downlink is never received.

Here is the logs from chirpstack-gateway-bridge:

time="2020-08-07T13:51:05Z" level=info msg="integration/mqtt: connected to mqtt broker"
time="2020-08-07T14:16:24Z" level=info msg="integration/mqtt: publishing event" event=up qos=0 topic=gateway/aa555a0000000000/event/up uplink_id=2d8f2690-8bb9-4945-a013-53318b2ebdfb
time="2020-08-07T14:18:26Z" level=info msg="integration/mqtt: publishing event" event=up qos=0 topic=gateway/aa555a0000000000/event/up uplink_id=e37252c3-40c6-4802-97bd-500a3b3db9fe
time="2020-08-07T15:15:17Z" level=info msg="integration/mqtt: subscribing to topic" qos=0 topic="gateway/aa555a0000000000/command/#"
time="2020-08-07T15:16:17Z" level=info msg="integration/mqtt: unsubscribing from topic" topic="gateway/aa555a0000000000/command/#"
time="2020-08-07T15:16:31Z" level=info msg="integration/mqtt: publishing event" event=up qos=0 topic=gateway/aa555a0000000000/event/up uplink_id=a8116404-3f35-4d72-af50-8d6d7ff91db2
time="2020-08-07T15:43:18Z" level=info msg="integration/mqtt: publishing event" event=up qos=0 topic=gateway/aa555a0000000000/event/up uplink_id=1ddfaf57-6210-4a1c-bc32-7aca45aad4b2
time="2020-08-07T15:44:04Z" level=info msg="integration/mqtt: publishing event" event=up qos=0 topic=gateway/aa555a0000000000/event/up uplink_id=f7bab738-5974-4770-b3e6-1cce525e2de0
time="2020-08-07T15:51:10Z" level=info msg="integration/mqtt: publishing event" event=up qos=0 topic=gateway/aa555a0000000000/event/up uplink_id=28ea7427-7db7-4632-a7e4-2edb12453f5e

I find this line strange: integration/mqtt: unsubscribing from topic" topic="gateway/aa555a0000000000/command/#

On MQTT, there is some "command" publishes, but they don't seem to be related to downlinks:

$ mosquitto_sub -v -F %j -t "gateway/#"
{"tst":1596816434,"topic":"gateway/aa555a0000000000/event/up","qos":0,"retain":0,"payloadlen":143,"payload":"\u0010>@?\u0020\u0001&�\u0000\u0000\u0001��}C�L)C�@\u0026�D����׃�9�\u0015�\u0024<�%�\u0025������L��o�RI���\u0004XJ\u0005���\u0018\u0017\u0008����\u0003\u0026\u0009\u0008}\u0016\u0012\u0026\u00034/5\u0026:\u0010\u0008�UZ\u0000\u0000\u0000\u0000\u0000(���������\u00011\u0000\u0000\u0000\u0000\u0000\u0000\u0028@z\u0004��S�\u0001\u0016�)�k�RK��\u0018}#�&\u0008u�\u0001\u0002"}
{"tst":1596816435,"topic":"gateway/aa555a0000000000/command/down","qos":0,"retain":0,"payloadlen":110,"payload":"\u0010&`?\u0020\u0001&�,\u0000\u00007p6&�KRh\u0008�&�&�L��\u0026>զf���x�o\u0027\u0018.\u0010\u0008�UZ\u0000\u0000\u0000\u0000\u0000(����\u00030\u0014`\u0001�\u0001\u0004��SB\u0011\u0008}\u0016\u0012\u0026\u00034/5 \u0001r\u0004\u0010\u0002\u0008\u0001\u0024ز\u0003\u0034\u0016�X�l��@a���\u0012�\u0010�["}

The /command/down seems to be related to Acks (they are there even without downlinks).

cdupont commented 4 years ago

Might be related, I noted this in the Network server logs:

time="2020-08-10T14:34:54Z" level=info msg="gateway/mqtt: uplink frame received" gateway_id=aa555a0000000000 uplink_id=c23ec7c2-0b98-465a-856a-fe7da28f19cb
time="2020-08-10T14:34:54Z" level=info msg="uplink: frame(s) collected" ctx_id=295c4e68-eb6f-4ae9-bdc0-8450543376be mtype=UnconfirmedDataUp uplink_ids="[c23ec7c2-0b98-465a-856a-fe7da28f19cb]"
time="2020-08-10T14:34:54Z" level=error msg="get gateway error" ctx_id=295c4e68-eb6f-4ae9-bdc0-8450543376be error="get gateway error: object does not exist" gateway_id=aa555a0000000000
time="2020-08-10T14:34:54Z" level=info msg="sent uplink meta-data to network-controller" ctx_id=295c4e68-eb6f-4ae9-bdc0-8450543376be dev_eui=aa555a002601143f
time="2020-08-10T14:34:54Z" level=info msg="device gateway rx-info meta-data saved" ctx_id=295c4e68-eb6f-4ae9-bdc0-8450543376be dev_eui=aa555a002601143f
time="2020-08-10T14:34:54Z" level=info msg="device-session saved" ctx_id=295c4e68-eb6f-4ae9-bdc0-8450543376be dev_addr=2601143f dev_eui=aa555a002601143f
time="2020-08-10T14:34:54Z" level=info msg="finished streaming call with code OK" grpc.code=OK grpc.method=StreamFrameLogsForDevice grpc.service=ns.NetworkServerService grpc.start_time="2020-08-10T14:26:22Z" grpc.time_ms=512082.06 peer.address="172.18.0.4:55722" span.kind=server system=grpc
time="2020-08-10T14:34:54Z" level=info msg="finished client unary call" ctx_id=295c4e68-eb6f-4ae9-bdc0-8450543376be grpc.code=OK grpc.ctx_id=47ce4c24-a8da-4ff6-aa9f-58285007d293 grpc.duration=31.641394ms grpc.method=HandleUplinkData grpc.service=as.ApplicationServerService span.kind=client system=grpc
time="2020-08-10T14:34:55Z" level=info msg="device-queue deleted" ctx_id=295c4e68-eb6f-4ae9-bdc0-8450543376be id=60

It says: "get gateway error: object does not exist" gateway_id=aa555a0000000000 After that, it deletes the device-queue.

In fact, my gateway ID is aa55a00000000000 (missing a 5).

cdupont commented 4 years ago

I found a mismatch with the gateway ID in the conf, between here: https://github.com/Waziup/wazigate-lora/blob/v2/app/conf/wazigate-lora/chirpstack.json#L24 and here: https://github.com/Waziup/wazigate-lora/blob/v2/app/conf/single_chan_pkt_fwd/global_conf.json#L12

cdupont commented 4 years ago

https://forum.chirpstack.io/t/downlink-problem-gateway-bridge-does-not-subscribe-to-commands/8892

cdupont commented 4 years ago

Success today. Procedure is:

Create a LoRaWAN device on the gateway and make sure it receives packets
create an actuator on the gateway dashboard
change the actuator value on the Cloud dashboard
trigger a uplink on the WaziDev

The value should be received on the WaziDev.

Waziup / WaziGate

V2: Cannot get downlinks #81