Context Deadline Exceeded

ChirpStack Application Server
1

Hello,

I will describe my situation and then describe my problem.

So the architecture of my network is:
Untitled Diagram

On RPI Gateway Bridge, LoRa Server and LoRa App Server is installed. Everything was worked for few days until I add static routers and static domain_name_servers in /etc/dhcpcd.conf (The was static IP before) and made apt-get update/upgrade. After adding static routers and DNS RPI gets Internet access (which I need) but something on LoRa Server stops working. After that I could see only dashboard tab on LoRa App Server Api and have Context Deadline Exceeded error.

Here are logs from LoRa Server:

wrz 29 19:20:48 raspberrypi chirpstack-network-server[2223]: time=“2020-09-29T19:20:48+02:00” level=info msg=“gateway/mqtt: gateway stats packet received” gateway_id=70b3d5b020030d6e stats_id=ec7acb32-7848-4a11-aaa5-7998c7484124
wrz 29 19:20:48 raspberrypi chirpstack-network-server[2223]: time=“2020-09-29T19:20:48+02:00” level=info msg=“gateway updated” ctx_id=ec7acb32-7848-4a11-aaa5-7998c7484124 gateway_id=70b3d5b020030d6e
wrz 29 19:20:48 raspberrypi chirpstack-network-server[2223]: time=“2020-09-29T19:20:48+02:00” level=info msg=“gateway/mqtt: publishing gateway command” command=config gateway_id=70b3d5b020030d6e qos=0 topic=gateway/70b3d5b020030d6e/command/config
wrz 29 19:20:48 raspberrypi chirpstack-network-server[2223]: time=“2020-09-29T19:20:48+02:00” level=warning msg=“creating insecure application-server client” server=“localhost:8001”
wrz 29 19:20:48 raspberrypi chirpstack-network-server[2223]: time=“2020-09-29T19:20:48+02:00” level=error msg=“uplink: processing uplink frame error” ctx_id=a5d2eea1-e2cb-4715-8058-51a04e9d518f error=“get application-server client error: create application-server api client error: dial application-server api error: context deadline exceeded”
wrz 29 19:20:50 raspberrypi chirpstack-network-server[2223]: time=“2020-09-29T19:20:50+02:00” level=info msg=“gateway/mqtt: uplink frame received” gateway_id=70b3d5b020030d6e uplink_id=d0194695-f4ac-4858-a6a3-16cce116e1a4
wrz 29 19:20:51 raspberrypi chirpstack-network-server[2223]: time=“2020-09-29T19:20:51+02:00” level=info msg=“uplink: frame(s) collected” ctx_id=e116249f-a50f-4e52-8e92-a0abbcbc7068 mtype=UnconfirmedDataUp uplink_ids=“[d0194695-f4ac-4858-a6a3-16cce116e1a4]”
wrz 29 19:20:51 raspberrypi chirpstack-network-server[2223]: time=“2020-09-29T19:20:51+02:00” level=warning msg=“get device-sessions for dev_addr error: object does not exist” ctx_id=e116249f-a50f-4e52-8e92-a0abbcbc7068 dev_addr=e2d3f4e7 dev_eui=1f55a7da3ac30475
wrz 29 19:20:53 raspberrypi chirpstack-network-server[2223]: time=“2020-09-29T19:20:53+02:00” level=error msg=“gateway: handle gateway stats error” ctx_id=ec7acb32-7848-4a11-aaa5-7998c7484124 error=“get application-server client error: get application-server client error: create application-server api client error: dial application-server api error: context deadline exceeded”
wrz 29 19:20:53 raspberrypi chirpstack-network-server[2223]: time=“2020-09-29T19:20:53+02:00” level=warning msg=“creating insecure application-server client” server=“localhost:8001”
wrz 29 19:20:57 raspberrypi chirpstack-network-server[2223]: time=“2020-09-29T19:20:57+02:00” level=info msg=“gateway/mqtt: uplink frame received” gateway_id=70b3d5b020030d6e uplink_id=4c4e6252-ccd2-4c03-938d-d63fa2385407
wrz 29 19:20:58 raspberrypi chirpstack-network-server[2223]: time=“2020-09-29T19:20:58+02:00” level=info msg=“uplink: frame(s) collected” ctx_id=6065c0fb-964e-46d9-bcd4-71c181928295 mtype=UnconfirmedDataUp uplink_ids=“[4c4e6252-ccd2-4c03-938d-d63fa2385407]”
wrz 29 19:20:58 raspberrypi chirpstack-network-server[2223]: time=“2020-09-29T19:20:58+02:00” level=warning msg=“get device-sessions for dev_addr error: object does not exist” ctx_id=6065c0fb-964e-46d9-bcd4-71c181928295 dev_addr=e2d3f4e7 dev_eui=1f55a7da3ac30475
wrz 29 19:20:58 raspberrypi chirpstack-network-server[2223]: time=“2020-09-29T19:20:58+02:00” level=error msg=“uplink: processing uplink frame error” ctx_id=e116249f-a50f-4e52-8e92-a0abbcbc7068 error=“get application-server client error: create application-server api client error: dial application-server api error: context deadline exceeded”
wrz 29 19:20:58 raspberrypi chirpstack-network-server[2223]: time=“2020-09-29T19:20:58+02:00” level=warning msg=“creating insecure application-server client” server=“localhost:8001”
wrz 29 19:21:03 raspberrypi chirpstack-network-server[2223]: time=“2020-09-29T19:21:03+02:00” level=error msg=“uplink: processing uplink frame error” ctx_id=6065c0fb-964e-46d9-bcd4-71c181928295 error=“get application-server client error: create application-server api client error: dial application-server api error: context deadline exceeded”
wrz 29 19:21:05 raspberrypi chirpstack-network-server[2223]: time=“2020-09-29T19:21:05+02:00” level=info msg=“gateway/mqtt: uplink frame received” gateway_id=70b3d5b020030d6e uplink_id=9bb2f237-b990-48ce-adef-ec553101c800
wrz 29 19:21:05 raspberrypi chirpstack-network-server[2223]: time=“2020-09-29T19:21:05+02:00” level=info msg=“uplink: frame(s) collected” ctx_id=c7293966-d259-462b-9e50-260cb27b5cff mtype=UnconfirmedDataUp uplink_ids=“[9bb2f237-b990-48ce-adef-ec553101c800]”
wrz 29 19:21:05 raspberrypi chirpstack-network-server[2223]: time=“2020-09-29T19:21:05+02:00” level=warning msg=“get device-sessions for dev_addr error: object does not exist” ctx_id=c7293966-d259-462b-9e50-260cb27b5cff dev_addr=e2d3f4e7 dev_eui=1f55a7da3ac30475
wrz 29 19:21:05 raspberrypi chirpstack-network-server[2223]: time=“2020-09-29T19:21:05+02:00” level=warning msg=“creating insecure application-server client” server=“localhost:8001”

Logs from LoRa App Server:

wrz 29 18:51:57 raspberrypi chirpstack-application-server[2104]: time=“2020-09-29T18:51:57+02:00” level=info msg=“integration/mqtt: connected to mqtt broker”
wrz 29 18:51:57 raspberrypi chirpstack-application-server[2104]: time=“2020-09-29T18:51:57+02:00” level=info msg=“integration/mqtt: subscribing to tx topic” qos=0 topic=application/+/device/+/command/down
wrz 29 18:51:57 raspberrypi chirpstack-application-server[2104]: time=“2020-09-29T18:51:57+02:00” level=info msg=“api/as: starting application-server api” bind=“0.0.0.0:8001” ca_cert= tls_cert= tls_key=
wrz 29 18:51:57 raspberrypi chirpstack-application-server[2104]: time=“2020-09-29T18:51:57+02:00” level=info msg=“api/external: starting api server” bind=“0.0.0.0:8080” tls-cert= tls-key=
wrz 29 18:51:57 raspberrypi chirpstack-application-server[2104]: time=“2020-09-29T18:51:57+02:00” level=info msg=“api/external: registering rest api handler and documentation endpoint” path=/api
wrz 29 18:51:57 raspberrypi chirpstack-application-server[2104]: time=“2020-09-29T18:51:57+02:00” level=info msg=“api/js: starting join-server api” bind=“0.0.0.0:8003” ca_cert= tls_cert= tls_key=
wrz 29 18:58:28 raspberrypi chirpstack-application-server[2104]: time=“2020-09-29T18:58:28+02:00” level=info msg=“finished unary call with code OK” ctx_id=9aae843b-dca6-429a-a021-831838cc3f1c grpc.code=OK grpc.method=List grpc.service=api.ApplicationService grpc.start_time=“2020-09-29T18:58:28+02:00” grpc.time_ms=36.105 peer.address=“127.0.0.1:52580” span.kind=server system=grpc
wrz 29 18:58:30 raspberrypi chirpstack-application-server[2104]: time=“2020-09-29T18:58:30+02:00” level=info msg=“finished unary call with code OK” ctx_id=a46d3696-4a8c-4869-a674-6b62509f7a8c grpc.code=OK grpc.method=Get grpc.service=api.ApplicationService grpc.start_time=“2020-09-29T18:58:30+02:00” grpc.time_ms=9.705 peer.address=“127.0.0.1:52580” span.kind=server system=grpc
wrz 29 18:58:30 raspberrypi chirpstack-application-server[2104]: time=“2020-09-29T18:58:30+02:00” level=info msg=“finished unary call with code OK” ctx_id=3a9383b8-e9da-4302-9d82-e53575caf71b grpc.code=OK grpc.method=List grpc.service=api.DeviceService grpc.start_time=“2020-09-29T18:58:30+02:00” grpc.time_ms=83.132 peer.address=“127.0.0.1:52604” span.kind=server system=grpc
wrz 29 18:58:33 raspberrypi chirpstack-application-server[2104]: time=“2020-09-29T18:58:33+02:00” level=info msg=“finished unary call with code OK” ctx_id=56984908-0d25-4663-ad0e-599dbc579f23 grpc.code=OK grpc.method=Get grpc.service=api.ApplicationService grpc.start_time=“2020-09-29T18:58:33+02:00” grpc.time_ms=15.871 peer.address=“127.0.0.1:52580” span.kind=server system=grpc
wrz 29 18:58:33 raspberrypi chirpstack-application-server[2104]: time=“2020-09-29T18:58:33+02:00” level=warning msg=“creating insecure network-server client” server=“localhost:8000”
wrz 29 18:58:35 raspberrypi chirpstack-application-server[2104]: time=“2020-09-29T18:58:35+02:00” level=info msg=“finished unary call with code OK” ctx_id=5fe530b2-118c-4a20-a9db-b64bd5dfc000 grpc.code=OK grpc.method=List grpc.service=api.DeviceProfileService grpc.start_time=“2020-09-29T18:58:35+02:00” grpc.time_ms=37.368 peer.address=“127.0.0.1:52592” span.kind=server system=grpc
wrz 29 18:58:38 raspberrypi chirpstack-application-server[2104]: time=“2020-09-29T18:58:38+02:00” level=warning msg=“creating insecure network-server client” server=“localhost:8000”
wrz 29 18:58:38 raspberrypi chirpstack-application-server[2104]: time=“2020-09-29T18:58:38+02:00” level=error msg=“finished unary call with code Unknown” ctx_id=005d2b06-fda2-4cbd-b6ad-d8029d598372 error=“rpc error: code = Unknown desc = context deadline exceeded” grpc.code=Unknown grpc.method=Get grpc.service=api.DeviceService grpc.start_time=“2020-09-29T18:58:33+02:00” grpc.time_ms=5024.499 peer.address=“127.0.0.1:52604” span.kind=server system=grpc
wrz 29 18:58:39 raspberrypi chirpstack-application-server[2104]: time=“2020-09-29T18:58:39+02:00” level=info msg=“finished unary call with code OK” ctx_id=592d7eb0-a6ff-4549-97ba-8c666ce22fbb grpc.code=OK grpc.method=List grpc.service=api.ApplicationService grpc.start_time=“2020-09-29T18:58:39+02:00” grpc.time_ms=17.523 peer.address=“127.0.0.1:52580” span.kind=server system=grpc
wrz 29 18:58:40 raspberrypi chirpstack-application-server[2104]: time=“2020-09-29T18:58:40+02:00” level=info msg=“finished unary call with code OK” ctx_id=7361019d-b75b-4b5a-8bcf-a7a7b0cf89ef grpc.code=OK grpc.method=Get grpc.service=api.ApplicationService grpc.start_time=“2020-09-29T18:58:40+02:00” grpc.time_ms=7.832 peer.address=“127.0.0.1:52580” span.kind=server system=grpc
wrz 29 18:58:40 raspberrypi chirpstack-application-server[2104]: time=“2020-09-29T18:58:40+02:00” level=info msg=“finished unary call with code OK” ctx_id=47e9e301-3060-4c8f-afae-9d48a7d7b1d1 grpc.code=OK grpc.method=List grpc.service=api.DeviceService grpc.start_time=“2020-09-29T18:58:40+02:00” grpc.time_ms=21.197 peer.address=“127.0.0.1:52604” span.kind=server system=grpc
wrz 29 18:58:43 raspberrypi chirpstack-application-server[2104]: time=“2020-09-29T18:58:43+02:00” level=error msg=“finished unary call with code Unknown” ctx_id=b82634fe-b88d-4904-bdf8-27f98421da54 error=“rpc error: code = Unknown desc = context deadline exceeded” grpc.code=Unknown grpc.method=Get grpc.service=api.DeviceProfileService grpc.start_time=“2020-09-29T18:58:36+02:00” grpc.time_ms=7584.793 peer.address=“127.0.0.1:52592” span.kind=server system=grpc
wrz 29 18:58:45 raspberrypi chirpstack-application-server[2104]: time=“2020-09-29T18:58:45+02:00” level=info msg=“finished unary call with code OK” ctx_id=fcc2f3be-047d-4977-8de5-e296971972dc grpc.code=OK grpc.method=List grpc.service=api.DeviceService grpc.start_time=“2020-09-29T18:58:45+02:00” grpc.time_ms=18.597 peer.address=“127.0.0.1:52604” span.kind=server system=grpc
wrz 29 18:58:45 raspberrypi chirpstack-application-server[2104]: time=“2020-09-29T18:58:45+02:00” level=info msg=“finished unary call with code OK” ctx_id=6c9e8911-39d5-46c8-993b-a54be7d87274 grpc.code=OK grpc.method=List grpc.service=api.DeviceService grpc.start_time=“2020-09-29T18:58:45+02:00” grpc.time_ms=19.254 peer.address=“127.0.0.1:52604” span.kind=server system=grpc

LoRa Gateway Bridge logs:

wrz 29 19:23:49 raspberrypi chirpstack-gateway-bridge[2029]: time=“2020-09-29T19:23:49+02:00” level=info msg=“integration/mqtt: publishing event” event=up qos=0 topic=gateway/70b3d5b020030d6e/event/up uplink_id=97da2fc7-93d9-4f0a-bcf1-2d1124c92c9c
wrz 29 19:23:56 raspberrypi chirpstack-gateway-bridge[2029]: time=“2020-09-29T19:23:56+02:00” level=info msg=“integration/mqtt: publishing event” event=up qos=0 topic=gateway/70b3d5b020030d6e/event/up uplink_id=1cf6c116-cc2d-4b75-8729-232dccdf4689
wrz 29 19:24:03 raspberrypi chirpstack-gateway-bridge[2029]: time=“2020-09-29T19:24:03+02:00” level=info msg=“integration/mqtt: publishing event” event=up qos=0 topic=gateway/70b3d5b020030d6e/event/up uplink_id=9437a96f-1395-4f0b-8ccc-34c4982e1de0
wrz 29 19:24:10 raspberrypi chirpstack-gateway-bridge[2029]: time=“2020-09-29T19:24:10+02:00” level=info msg=“integration/mqtt: publishing event” event=up qos=0 topic=gateway/70b3d5b020030d6e/event/up uplink_id=fccc8dd6-869f-4981-a431-bf55fdfeaa10
wrz 29 19:24:17 raspberrypi chirpstack-gateway-bridge[2029]: time=“2020-09-29T19:24:17+02:00” level=info msg=“integration/mqtt: publishing event” event=up qos=0 topic=gateway/70b3d5b020030d6e/event/up uplink_id=4903b0ee-81fb-459e-97b5-c9e48e07653c
wrz 29 19:24:18 raspberrypi chirpstack-gateway-bridge[2029]: time=“2020-09-29T19:24:18+02:00” level=info msg=“integration/mqtt: publishing event” event=stats qos=0 stats_id=2f6621bf-4c5d-42bd-8fed-79c67d72b144 topic=gateway/70b3d5b020030d6e/event/stats
wrz 29 19:24:18 raspberrypi chirpstack-gateway-bridge[2029]: time=“2020-09-29T19:24:18+02:00” level=info msg=“integration/mqtt: gateway configuration received” topic=gateway/70b3d5b020030d6e/command/config
wrz 29 19:24:25 raspberrypi chirpstack-gateway-bridge[2029]: time=“2020-09-29T19:24:25+02:00” level=info msg=“integration/mqtt: publishing event” event=up qos=0 topic=gateway/70b3d5b020030d6e/event/up uplink_id=424d91ad-1224-4a89-bb84-4d0284262172
wrz 29 19:24:32 raspberrypi chirpstack-gateway-bridge[2029]: time=“2020-09-29T19:24:32+02:00” level=info msg=“integration/mqtt: publishing event” event=up qos=0 topic=gateway/70b3d5b020030d6e/event/up uplink_id=11069b65-63ec-44f0-b336-fdd575866b55
wrz 29 19:24:39 raspberrypi chirpstack-gateway-bridge[2029]: time=“2020-09-29T19:24:39+02:00” level=info msg=“integration/mqtt: publishing event” event=up qos=0 topic=gateway/70b3d5b020030d6e/event/up uplink_id=ad6d17dd-8b5b-4fcc-b970-f0d9fb555b9c
wrz 29 19:24:46 raspberrypi chirpstack-gateway-bridge[2029]: time=“2020-09-29T19:24:46+02:00” level=info msg=“integration/mqtt: publishing event” event=up qos=0 topic=gateway/70b3d5b020030d6e/event/up uplink_id=af9df7b3-a025-4369-a571-157817e21365
wrz 29 19:24:48 raspberrypi chirpstack-gateway-bridge[2029]: time=“2020-09-29T19:24:48+02:00” level=info msg=“integration/mqtt: publishing event” event=stats qos=0 stats_id=21e3ccc0-f203-4272-a88a-c4660a479ed4 topic=gateway/70b3d5b020030d6e/event/stats
wrz 29 19:24:48 raspberrypi chirpstack-gateway-bridge[2029]: time=“2020-09-29T19:24:48+02:00” level=info msg=“integration/mqtt: gateway configuration received” topic=gateway/70b3d5b020030d6e/command/config
wrz 29 19:24:53 raspberrypi chirpstack-gateway-bridge[2029]: time=“2020-09-29T19:24:53+02:00” level=info msg=“integration/mqtt: publishing event” event=up qos=0 topic=gateway/70b3d5b020030d6e/event/up uplink_id=4b08d6e9-fcc2-453b-a776-12cf81bdcc48
wrz 29 19:25:00 raspberrypi chirpstack-gateway-bridge[2029]: time=“2020-09-29T19:25:00+02:00” level=info msg=“integration/mqtt: publishing event” event=up qos=0 topic=gateway/70b3d5b020030d6e/event/up uplink_id=b4592635-0b8e-49de-af69-8a2ebc6d06dc
wrz 29 19:25:07 raspberrypi chirpstack-gateway-bridge[2029]: time=“2020-09-29T19:25:07+02:00” level=info msg=“integration/mqtt: publishing event” event=up qos=0 topic=gateway/70b3d5b020030d6e/event/up uplink_id=141611e7-3c48-4808-b8a7-84db850882fa
wrz 29 19:25:15 raspberrypi chirpstack-gateway-bridge[2029]: time=“2020-09-29T19:25:15+02:00” level=info msg=“integration/mqtt: publishing event” event=up qos=0 topic=gateway/70b3d5b020030d6e/event/up uplink_id=fff7d5fe-77e1-42c0-a3e2-b55ba9cf60ef
wrz 29 19:25:18 raspberrypi chirpstack-gateway-bridge[2029]: time=“2020-09-29T19:25:18+02:00” level=info msg=“integration/mqtt: publishing event” event=stats qos=0 stats_id=a0a13c67-35a5-4595-b061-abb4752ab157 topic=gateway/70b3d5b020030d6e/event/stats
wrz 29 19:25:18 raspberrypi chirpstack-gateway-bridge[2029]: time=“2020-09-29T19:25:18+02:00” level=info msg=“integration/mqtt: gateway configuration received” topic=gateway/70b3d5b020030d6e/command/config
wrz 29 19:25:22 raspberrypi chirpstack-gateway-bridge[2029]: time=“2020-09-29T19:25:22+02:00” level=info msg=“integration/mqtt: publishing event” event=up qos=0 topic=gateway/70b3d5b020030d6e/event/up uplink_id=4583c40a-ef6d-4046-b401-c4b761cc493f

Thanks in advice.

2

You might want to

  1. Check the sd-card
  2. check your system-load. (htop)
  3. check the postgresql database. (explain/analyze)
    We had an Issue where some queries (Device-Profiles) were taking way too long.
    There might be an Index missing or something went wrong while upgrading.
    I never got to implement a proper solution, after a pg_dump and pg_restore of the app server the Issue went away.
    https://github.com/brocaar/chirpstack-application-server/blob/master/internal/storage/device_profile.go#L355
    https://github.com/brocaar/chirpstack-application-server/blob/master/internal/storage/device_profile.go#L388
    https://thoughtbot.com/blog/reading-an-explain-analyze-query-plan
3

I checked sd-card and system-load and all looks ok, so then I decided to change architecture and connect LoRa Gateway directly to my Internet Gateway with DHCP and also change RPI for DHCP instead of Static IP. After that everything started to work.

Then I changed architecture and I connected back LoRa Gateway to RPI via ethernet. LoRa Gw-Bridge, LoRa Server and LoRa App Server started work well (I can read packets in NodeRed and in File) but when I log in to LoRa App Server Api I still can’t reach any tabs except dashboard and there is context deadline exceeded (code: 2) error.

Edit: After RPI reboot it stopped working again.

4

So the situation is as follows.

When LoRa Gateway and RPI (LoRa Gw-Bridge, LoRa Server and LoRa App Server) are connected separately to Internet gateway everything work perfect.

When I connect LoRa Gateway directly to RPI (without Internet connection) everything work well.

When I connect LoRa Gateway directly to RPI (with Internet connection on RPI and LoRa Gateway):

  • RPI have access to LoRa Gateway and Internet.
  • LoRa Gateway have access to RPI and Internet.
  • Just dashboard works on LoRa App Server Api.
  • I can’t see any data via Node Red and in file.
  • All logs are same as in 1st post.
5

Hi did you ever get a solution to this? Sounds the same as an issue I am experiencing.