search

brocaar / chirpstack-network-server

ChirpStack Network Server is an open-source LoRaWAN network-server.
https://www.chirpstack.io
MIT License
1.49k stars 546 forks source link

Network server fails at api call to application server #479

Closed ghost closed 3 years ago

ghost commented 4 years ago

Is this a bug or a feature request?

bug

What did you expect?

Data send by device should trigger App Integration (HTTPs Request to my server). An Older version (January/February?) worked.

What happened?

Lora Device is an Arduino MKR1300 with up to date MKRWAN firmware and library. This device can Join, but data send from it won't be shown within Tab "Device Data" nor will it trigger HTTP App Integration ( https://example.com/lora/ ). Data from device will be shown in Applications/testapp/Devices/mkr1300 in the Tab "LoraWAN Frames"

Albeit the Device manages to join correctly, the Device listing within Applications shows: "Device last seen: n/a".

What version are your using?

Official ChirpStackOS 27.03.20 Self build ChirpStackOS 04.04.20

RAK 2245 Raspi3 Network via Ethernet

How can your issue be reproduced?

Just using a freshly installed ChirpStackOS with minimal configuration will do the trick.

Could you share your log output?

tail -f /var/log/messages | grep level=
Apr  7 00:27:18 raspberrypi3 user.info chirpstack-gateway-bridge[479]: time="2020-04-07T00:27:18Z" level=info msg="backend/concentratord: uplink event received" uplink_id=ad49f3e8-bc7c-4d4e-8714-8c2d7b854395
Apr  7 00:27:18 raspberrypi3 user.info chirpstack-gateway-bridge[479]: time="2020-04-07T00:27:18Z" level=info msg="integration/mqtt: publishing event" event=up qos=0 topic=gateway/b827ebfffe364960/event/up uplink_id=ad49f3e8-bc7c-4d4e-8714-8c2d7b854395
Apr  7 00:27:18 raspberrypi3 user.info chirpstack-network-server[364]: time="2020-04-07T00:27:18Z" level=info msg="gateway/mqtt: uplink frame received" gateway_id=b827ebfffe364960 uplink_id=ad49f3e8-bc7c-4d4e-8714-8c2d7b854395
Apr  7 00:27:18 raspberrypi3 user.info chirpstack-network-server[364]: time="2020-04-07T00:27:18Z" level=info msg="uplink: frame(s) collected" ctx_id=ce3d05c0-2e2f-475c-a7e8-c0f30e40c3ca mtype=UnconfirmedDataUp uplink_ids="[ad49f3e8-bc7c-4d4e-8714-8c2d7b854395]"
Apr  7 00:27:18 raspberrypi3 user.warn chirpstack-network-server[364]: time="2020-04-07T00:27:18Z" level=warning msg="creating insecure application-server client" server="localhost:8001"
Apr  7 00:27:20 raspberrypi3 user.info chirpstack-gateway-bridge[479]: time="2020-04-07T00:27:20Z" level=info msg="backend/concentratord: stats event received" stats_id=5eed6d5f-6251-49ff-a533-746a7beb5ec7
Apr  7 00:27:20 raspberrypi3 user.info chirpstack-gateway-bridge[479]: time="2020-04-07T00:27:20Z" level=info msg="integration/mqtt: publishing event" event=stats qos=0 stats_id=5eed6d5f-6251-49ff-a533-746a7beb5ec7 topic=gateway/b827ebfffe364960/event/stats
Apr  7 00:27:20 raspberrypi3 user.info chirpstack-network-server[364]: time="2020-04-07T00:27:20Z" level=info msg="gateway/mqtt: gateway stats packet received" gateway_id=b827ebfffe364960 stats_id=5eed6d5f-6251-49ff-a533-746a7beb5ec7
Apr  7 00:27:20 raspberrypi3 user.info chirpstack-network-server[364]: time="2020-04-07T00:27:20Z" level=info msg="gateway updated" ctx_id=5eed6d5f-6251-49ff-a533-746a7beb5ec7 gateway_id=b827ebfffe364960
Apr  7 00:27:23 raspberrypi3 user.err chirpstack-network-server[364]: time="2020-04-07T00:27:23Z" level=error msg="uplink: processing uplink frame error" ctx_id=ce3d05c0-2e2f-475c-a7e8-c0f30e40c3ca error="get application-server client error: create application-server api c
Apr  7 00:27:23 raspberrypi3 user.warn chirpstack-network-server[364]: time="2020-04-07T00:27:23Z" level=warning msg="creating insecure application-server client" server="localhost:8001"
Apr  7 00:27:27 raspberrypi3 user.info chirpstack-gateway-bridge[479]: time="2020-04-07T00:27:27Z" level=info msg="backend/concentratord: uplink event received" uplink_id=1a7c89af-cccd-4d9d-b41a-887796dd9600
Apr  7 00:27:27 raspberrypi3 user.info chirpstack-gateway-bridge[479]: time="2020-04-07T00:27:27Z" level=info msg="integration/mqtt: publishing event" event=up qos=0 topic=gateway/b827ebfffe364960/event/up uplink_id=1a7c89af-cccd-4d9d-b41a-887796dd9600
Apr  7 00:27:27 raspberrypi3 user.info chirpstack-network-server[364]: time="2020-04-07T00:27:27Z" level=info msg="gateway/mqtt: uplink frame received" gateway_id=b827ebfffe364960 uplink_id=1a7c89af-cccd-4d9d-b41a-887796dd9600
Apr  7 00:27:27 raspberrypi3 user.info chirpstack-network-server[364]: time="2020-04-07T00:27:27Z" level=info msg="uplink: frame(s) collected" ctx_id=de8ee52d-6cb7-41e8-b01d-64443f84db5e mtype=UnconfirmedDataUp uplink_ids="[1a7c89af-cccd-4d9d-b41a-887796dd9600]"
Apr  7 00:27:28 raspberrypi3 user.err chirpstack-network-server[364]: time="2020-04-07T00:27:28Z" level=error msg="gateway: handle gateway stats error" ctx_id=5eed6d5f-6251-49ff-a533-746a7beb5ec7 error="get application-server client error: get application-server client err
Apr  7 00:27:28 raspberrypi3 user.warn chirpstack-network-server[364]: time="2020-04-07T00:27:28Z" level=warning msg="creating insecure application-server client" server="localhost:8001"
Apr  7 00:27:33 raspberrypi3 user.err chirpstack-network-server[364]: time="2020-04-07T00:27:33Z" level=error msg="uplink: processing uplink frame error" ctx_id=de8ee52d-6cb7-41e8-b01d-64443f84db5e error="get application-server client error: create application-server api c
Apr  7 00:27:50 raspberrypi3 user.info chirpstack-gateway-bridge[479]: time="2020-04-07T00:27:50Z" level=info msg="backend/concentratord: stats event received" stats_id=ced23131-61d4-4bb5-b6c3-47acfb00d29a
Apr  7 00:27:50 raspberrypi3 user.info chirpstack-gateway-bridge[479]: time="2020-04-07T00:27:50Z" level=info msg="integration/mqtt: publishing event" event=stats qos=0 stats_id=ced23131-61d4-4bb5-b6c3-47acfb00d29a topic=gateway/b827ebfffe364960/event/stats
Apr  7 00:27:50 raspberrypi3 user.info chirpstack-network-server[364]: time="2020-04-07T00:27:50Z" level=info msg="gateway/mqtt: gateway stats packet received" gateway_id=b827ebfffe364960 stats_id=ced23131-61d4-4bb5-b6c3-47acfb00d29a
Apr  7 00:27:50 raspberrypi3 user.info chirpstack-network-server[364]: time="2020-04-07T00:27:50Z" level=info msg="gateway updated" ctx_id=ced23131-61d4-4bb5-b6c3-47acfb00d29a gateway_id=b827ebfffe364960
Apr  7 00:27:50 raspberrypi3 user.warn chirpstack-network-server[364]: time="2020-04-07T00:27:50Z" level=warning msg="creating insecure application-server client" server="localhost:8001"
Apr  7 00:27:55 raspberrypi3 user.err chirpstack-network-server[364]: time="2020-04-07T00:27:55Z" level=error msg="gateway: handle gateway stats error" ctx_id=ced23131-61d4-4bb5-b6c3-47acfb00d29a error="get application-server client error: get application-server client err

personal note

I like your project and somehow I feel bad for all the bug reports :( Please keep up your good work.

ghost commented 4 years ago

new testcase

Issuing a downlink message from ChirpStack Application to device (Base64 encoded) does nothing but spamming error messages into /var/log/messages

log

Apr  7 01:12:44 raspberrypi3 user.info chirpstack-network-server[362]: time="2020-04-07T01:12:44Z" level=info msg="finished unary call with code OK" ctx_id=57b8c81c-5f05-4e75-be53-813469110fe2 grpc.code=OK grpc.method=GetDeviceQueueItemsForDevEUI grpc.service=ns.NetworkServ
Apr  7 01:12:44 raspberrypi3 user.info chirpstack-application-server[338]: time="2020-04-07T01:12:44Z" level=info msg="finished client unary call" ctx_id=998e23f0-d7f2-4af1-8fd9-01f8638e29ca grpc.code=OK grpc.ctx_id=57b8c81c-5f05-4e75-be53-813469110fe2 grpc.duration=7.21278
Apr  7 01:12:44 raspberrypi3 user.info chirpstack-application-server[338]: time="2020-04-07T01:12:44Z" level=info msg="finished unary call with code OK" ctx_id=998e23f0-d7f2-4af1-8fd9-01f8638e29ca grpc.code=OK grpc.method=List grpc.service=api.DeviceQueueService grpc.start_
Apr  7 01:12:45 raspberrypi3 user.err chirpstack-network-server[362]: time="2020-04-07T01:12:45Z" level=error msg="schedule next device-queue item error" ctx_id=490c29f3-9f0e-4e1b-bdbe-9d87f9258ea3 dev_eui=a8610a3130357712 error="get device gateway RXInfoSet error: object 
Apr  7 01:12:46 raspberrypi3 user.err chirpstack-network-server[362]: time="2020-04-07T01:12:46Z" level=error msg="schedule next device-queue item error" ctx_id=678f138d-71a9-480b-a035-ed542594bdae dev_eui=a8610a3130357712 error="get device gateway RXInfoSet error: object 
Apr  7 01:12:47 raspberrypi3 user.err chirpstack-network-server[362]: time="2020-04-07T01:12:47Z" level=error msg="schedule next device-queue item error" ctx_id=32d53a19-361e-4d02-a990-ca9021cbd60d dev_eui=a8610a3130357712 error="get device gateway RXInfoSet error: object  
Apr  7 01:12:48 raspberrypi3 user.info chirpstack-gateway-bridge[476]: time="2020-04-07T01:12:48Z" level=info msg="backend/concentratord: stats event received" stats_id=c4ad6a2c-a46b-4430-a74a-5e6882964cf2                                                                    
Apr  7 01:12:48 raspberrypi3 user.info chirpstack-gateway-bridge[476]: time="2020-04-07T01:12:48Z" level=info msg="integration/mqtt: publishing event" event=stats qos=0 stats_id=c4ad6a2c-a46b-4430-a74a-5e6882964cf2 topic=gateway/b827ebfffe364960/event/stats                 
Apr  7 01:12:48 raspberrypi3 user.info chirpstack-network-server[362]: time="2020-04-07T01:12:48Z" level=info msg="gateway/mqtt: gateway stats packet received" gateway_id=b827ebfffe364960 stats_id=c4ad6a2c-a46b-4430-a74a-5e6882964cf2                                         
Apr  7 01:12:48 raspberrypi3 user.info chirpstack-network-server[362]: time="2020-04-07T01:12:48Z" level=info msg="gateway updated" ctx_id=c4ad6a2c-a46b-4430-a74a-5e6882964cf2 gateway_id=b827ebfffe364960                                                                       
Apr  7 01:12:48 raspberrypi3 user.warn chirpstack-network-server[362]: time="2020-04-07T01:12:48Z" level=warning msg="creating insecure application-server client" server="localhost:8001"                                                                                        
Apr  7 01:12:48 raspberrypi3 user.err chirpstack-network-server[362]: time="2020-04-07T01:12:48Z" level=error msg="schedule next device-queue item error" ctx_id=05690325-5455-46d0-a438-16820761e794 dev_eui=a8610a3130357712 error="get device gateway RXInfoSet error: object 
Apr  7 01:12:49 raspberrypi3 user.err chirpstack-network-server[362]: time="2020-04-07T01:12:49Z" level=error msg="schedule next device-queue item error" ctx_id=cfbe8cc3-97ba-4cfa-a13b-d19490a5bd0b dev_eui=a8610a3130357712 error="get device gateway RXInfoSet error: object  
Apr  7 01:12:50 raspberrypi3 user.err chirpstack-network-server[362]: time="2020-04-07T01:12:50Z" level=error msg="schedule next device-queue item error" ctx_id=2e426d29-e3eb-49c0-a760-af7ea7e007fc dev_eui=a8610a3130357712 error="get device gateway RXInfoSet error: object  
Apr  7 01:12:51 raspberrypi3 user.err chirpstack-network-server[362]: time="2020-04-07T01:12:51Z" level=error msg="schedule next device-queue item error" ctx_id=59094001-1471-4a1e-809e-f8e990cffbb7 dev_eui=a8610a3130357712 error="get device gateway RXInfoSet error: object  
Apr  7 01:12:52 raspberrypi3 user.err chirpstack-network-server[362]: time="2020-04-07T01:12:52Z" level=error msg="schedule next device-queue item error" ctx_id=111e44a4-94eb-4bf5-8c8b-649275d71702 dev_eui=a8610a3130357712 error="get device gateway RXInfoSet error: object  
Apr  7 01:12:53 raspberrypi3 user.err chirpstack-network-server[362]: time="2020-04-07T01:12:53Z" level=error msg="gateway: handle gateway stats error" ctx_id=c4ad6a2c-a46b-4430-a74a-5e6882964cf2 error="get application-server client error: get application-server client err 
Apr  7 01:12:53 raspberrypi3 user.err chirpstack-network-server[362]: time="2020-04-07T01:12:53Z" level=error msg="schedule next device-queue item error" ctx_id=7426d738-4ed3-46bc-987d-dc953b4b2a59 dev_eui=a8610a3130357712 error="get device gateway RXInfoSet error: object  
Apr  7 01:12:54 raspberrypi3 user.err chirpstack-network-server[362]: time="2020-04-07T01:12:54Z" level=error msg="schedule next device-queue item error" ctx_id=34b6739e-79eb-4638-a2d5-c3db536942c5 dev_eui=a8610a3130357712 error="get device gateway RXInfoSet error: object  
Apr  7 01:12:55 raspberrypi3 user.err chirpstack-network-server[362]: time="2020-04-07T01:12:55Z" level=error msg="schedule next device-queue item error" ctx_id=a6584ce3-018b-49c2-901c-9fc2eccd3f9a dev_eui=a8610a3130357712 error="get device gateway RXInfoSet error: object  
Apr  7 01:12:56 raspberrypi3 user.err chirpstack-network-server[362]: time="2020-04-07T01:12:56Z" level=error msg="schedule next device-queue item error" ctx_id=0b0b78a9-2858-48aa-8a3a-8814e550d28e dev_eui=a8610a3130357712 error="get device gateway RXInfoSet error: object
[...]

The error reports gets spammed endlessly afterwards.

suggestion for handling errors

If any services encounters an error, the retries should have a hard limit to prevent endless loops and also to prevent flooding the logfile.

brocaar commented 4 years ago

Have you turned on Class-C support in the device-profile?

ghost commented 4 years ago

Class C was used, that's correct and I configured an excessive time limit of 1 hour (is it unreasonably?). That's clearly on my side, but I still would suggest to add some error handling.

The error="get application-server client error: create application-server api c still remains with Class A

brocaar commented 3 years ago

This was a bit of a vague issue, there have been multiple reports and it was never very clear what was the cause. Some people had issues using Docker where others had not. There was a bugfix in gRPC and I have also reverted some code which could have triggered this issue. After this, the number of requests have dropped so I hope this solved the issue. Therefore I'm closing this issue.