Error="rpc error: code = Canceled desc = context canceled" grpc.code=Canceled grpc.duration="873.008µs"

I’m working on creating a bespoke application server for v3. I’ve created a gRPC server for the new application server, that uses services defined in as.proto. I’m receiving frames via gateways/gateway bridges and via the BE Interface for roaming.
The routing profile used for my devices references the ‘as_id’ which is the IP and PORT of the gRPC server.

When receiving frames via the gateways/gateway bridges, there are no errors. the AS gRPC server is handling the GatewayStatsRequests and UplinkDataRequests without error.

When frames are received via the BE Interface, I’m seeing an error in the Home Network Server logs.

Jun 01 15:46:13 ip-172-31-22-105 chirpstack-network-server[134575]: time=“2023-06-01T15:46:13.351405699Z” level=info msg=“api/roaming: returned response” ctx_id=760c8b2d-0544-4fc8-b91d-1ef7ef2ce7b0 message_type=PRStartAns receiver_id=XXXXXX result_code=Success sender_id=XXXXXX transaction_id=54190594
Jun 01 15:46:13 ip-172-31-22-105 chirpstack-network-server[134575]: time=“2023-06-01T15:46:13.351771897Z” level=info msg=“finished client unary call” ctx_id=760c8b2d-0544-4fc8-b91d-1ef7ef2ce7b0 error=“rpc error: code = Canceled desc = context canceled” grpc.code=Canceled grpc.duration=“873.008µs” grpc.method=HandleUplinkData grpc.service=as.ApplicationServerService span.kind=client system=grpc
Jun 01 15:46:13 ip-172-31-22-105 chirpstack-network-server[134575]: time=“2023-06-01T15:46:13.351802658Z” level=error msg=“publish uplink data to application-server error” ctx_id=760c8b2d-0544-4fc8-b91d-1ef7ef2ce7b0 error=“rpc error: code = Canceled desc = context canceled”
Jun 01 15:46:13 ip-172-31-22-105 chirpstack-network-server[134575]: time=“2023-06-01T15:46:13.453267082Z” level=info msg=“storage: downlink-frame saved” ctx_id=760c8b2d-0544-4fc8-b91d-1ef7ef2ce7b0 token=30220
Jun 01 15:46:13 ip-172-31-22-105 chirpstack-network-server[134575]: time=“2023-06-01T15:46:13.453809334Z” level=info msg=“device-session saved” ctx_id=760c8b2d-0544-4fc8-b91d-1ef7ef2ce7b0 dev_addr=XXXXXX dev_eui=2133320102868407
Jun 01 15:46:13 ip-172-31-22-105 chirpstack-network-server[134575]: time=“2023-06-01T15:46:13.455850242Z” level=info msg=“lorawan/backend: finished backend api call” message_type=XmitDataReq protocol_version=1.0 receiver_id=e00070 result_code=Success sender_id=c0005f transaction_id=272744330

NOTE- NetIDs and DevAddresses replaced with XXX’s

This seems to imply that there was an error sending the data via the HandleUplinkData call, yet the AS gRPC server did receive the data OK:

UplinkDataRequest: {“rx_info”:[{“gateway_id”:{“type”:“Buffer”,“data”:[255,42,55,191]},“time”:null,“time_since_gps_epoch”:null,“rssi”:-48,“lora_snr”:8.5,“channel”:0,“rf_chain”:0,“board”:0,“antenna”:0,“location”:{“latitude”:51.82591811996969,“longitude”:-0.92083888053894044,“altitude”:0,“source”:“UNKNOWN”,“accuracy”:0},“fine_timestamp_type”:“NONE”,“context”:{“type”:“Buffer”,“data”:[10,8,192,238,64,255,255,42,55,191,40,208,255,255,255,255,255,255,255,255,1,49,0,0,0,0,0,0,33,64,64,1,90,18,9,201,56,89,175,183,105,73,64,17,1,0,0,0,76,239,190,191,122,4,200,4,215,12,130,1,16,251,117,208,35,230,233,77,127,138,97,216,215,10,35,72,75,136,1,2]},“uplink_id”:{“type”:“Buffer”,“data”:},“crc_status”:“CRC_OK”}],“dev_eui”:{“type”:“Buffer”,“data”:[33,51,50,1,2,134,132,7]},“join_eui”:{“type”:“Buffer”,“data”:[0,0,0,0,0,0,0,0]},“f_cnt”:675,“f_port”:2,“adr”:true,“dr”:0,“tx_info”:{“frequency”:868100000,“modulation”:“LORA”,“lora_modulation_info”:{“bandwidth”:125,“spreading_factor”:12,“code_rate”:“4/5”,“polarization_inversion”:true},“modulation_info”:“lora_modulation_info”},“data”:{“type”:“Buffer”,“data”:[31,59,43,175]},“device_activation_context”:null,“confirmed_uplink”:true}

Is this error erroneous and thus can be safely ignored, or is it of concern and needs to be resolved?

server error” ctx_id=760c8b2d-0544-4fc8-b91d-1ef7ef2ce7b0 error=“rpc error: code = Canceled desc = context canceled”

It could mean that your AS implementation took too long to respond to the request. E.g. you are processing the request before responding.

Thank you Orne, that was my first thought as the duration in the error was always over > 650ms, but we’re not doing any processing in our tests, just logging the output.