search

chirpstack / chirpstack-docker

Setup ChirpStack using Docker Compose
https://www.chirpstack.io/
MIT License
273 stars 316 forks source link

gRPC Stream - Stream Device Event Hanging #72

Closed JTuckerBCAE closed 1 year ago

JTuckerBCAE commented 1 year ago

Hi,

I am using an almost direct clone of this repo to test some LoRa nodes. The only configuration I have made is to use au915_0 in the gateway-bridge configuration.

Most is working fine, I have a gateway and 2 devices configured (1 ABP, 1 OTAA). Except, the sockets on the events and LoRaWAN Frames tabs are continually buffering. These buffer indefinitely unless the connection to the server is lost, when that connection is lost the events appear as expected. When connection is regained the socket returns to buffering indefinitely.

When inspecting the logs and databases it appears that all the data is there and that it is only the socket that is failing.

I am using nginx as a reverse proxy, however the same issue is produced when not used with the proxy

UI does not change from this state in normal operation

image

UI after connection loss and reconnect

image

Inspect Console (~3 mins between start and error)

image

Stack Trace

2023-01-10T05:22:13.354544Z TRACE chirpstack::downlink::scheduler: class_b_c_scheduler_loop completed successfully
2023-01-10T05:22:14.036390Z DEBUG http{method="GET" uri=/ version=HTTP/1.0}: chirpstack::api: Started processing request
2023-01-10T05:22:14.036418Z  INFO http{method="GET" uri=/ version=HTTP/1.0}: chirpstack::api: Finished processing request status="200" latency=38.95µs
2023-01-10T05:22:14.045064Z TRACE chirpstack::api::internal: DropReceiver drop method called
2023-01-10T05:22:14.045081Z DEBUG chirpstack::api::internal: Client disconnected
2023-01-10T05:22:14.057941Z DEBUG http{method="GET" uri=/static/js/main.c173e3dd.js version=HTTP/1.0}: chirpstack::api: Started processing request
2023-01-10T05:22:14.057965Z  INFO http{method="GET" uri=/static/js/main.c173e3dd.js version=HTTP/1.0}: chirpstack::api: Finished processing request status="200" latency=32.348µs
2023-01-10T05:22:14.332342Z TRACE chirpstack::downlink::scheduler: Starting multicast-group queue scheduler loop run
2023-01-10T05:22:14.332354Z TRACE chirpstack::downlink::scheduler: Getting schedulable multicast-group queue items
2023-01-10T05:22:14.333336Z TRACE chirpstack::downlink::scheduler: Got this number of multicast-group queue items count=0
2023-01-10T05:22:14.333347Z TRACE chirpstack::downlink::scheduler: Multicast-group queue scheduler run completed successfully
2023-01-10T05:22:14.355539Z TRACE chirpstack::downlink::scheduler: Starting class_b_c_scheduler_loop run
2023-01-10T05:22:14.355548Z TRACE chirpstack::downlink::scheduler: Getting devices that have schedulable queue-items
2023-01-10T05:22:14.356632Z TRACE chirpstack::downlink::scheduler: Got this number of devices with schedulable queue-items device_count=0
2023-01-10T05:22:14.356642Z TRACE chirpstack::downlink::scheduler: class_b_c_scheduler_loop completed successfully
2023-01-10T05:22:14.827903Z DEBUG http{method="GET" uri=/static/css/main.d189f327.css version=HTTP/1.0}: chirpstack::api: Started processing request
2023-01-10T05:22:14.827932Z  INFO http{method="GET" uri=/static/css/main.d189f327.css version=HTTP/1.0}: chirpstack::api: Finished processing request status="200" latency=39.365µs
2023-01-10T05:22:15.015556Z DEBUG chirpstack::eventlog: Channel has been closed, returning
2023-01-10T05:22:15.031874Z DEBUG http{method="GET" uri=/static/js/main.c173e3dd.js.map version=HTTP/1.0}: chirpstack::api: Started processing request
2023-01-10T05:22:15.031902Z  INFO http{method="GET" uri=/static/js/main.c173e3dd.js.map version=HTTP/1.0}: chirpstack::api: Finished processing request status="200" latency=36.85µs
2023-01-10T05:22:15.072129Z DEBUG gRPC{uri=/api.InternalService/Profile}: chirpstack::api: Started processing request
2023-01-10T05:22:15.073232Z  INFO gRPC{uri=/api.InternalService/Profile}: chirpstack::api: Finished processing request status="200" latency=1.110249ms
2023-01-10T05:22:15.170309Z DEBUG http{method="GET" uri=/static/css/main.d189f327.css.map version=HTTP/1.0}: chirpstack::api: Started processing request
2023-01-10T05:22:15.170335Z  INFO http{method="GET" uri=/static/css/main.d189f327.css.map version=HTTP/1.0}: chirpstack::api: Finished processing request status="200" latency=38.082µs
2023-01-10T05:22:15.203923Z DEBUG gRPC{uri=/api.InternalService/Settings}: chirpstack::api: Started processing request
2023-01-10T05:22:15.203978Z  INFO gRPC{uri=/api.InternalService/Settings}: chirpstack::api: Finished processing request status="200" latency=62.116µs
2023-01-10T05:22:15.222153Z DEBUG gRPC{uri=/api.TenantService/Get}: chirpstack::api: Started processing request
2023-01-10T05:22:15.223206Z  INFO gRPC{uri=/api.TenantService/Get}: chirpstack::api: Finished processing request status="200" latency=1.057478ms
2023-01-10T05:22:15.243003Z DEBUG gRPC{uri=/api.TenantService/Get}: chirpstack::api: Started processing request
2023-01-10T05:22:15.244127Z  INFO gRPC{uri=/api.TenantService/Get}: chirpstack::api: Finished processing request status="200" latency=1.129669ms
2023-01-10T05:22:15.266493Z DEBUG http{method="GET" uri=/icon.png version=HTTP/1.0}: chirpstack::api: Started processing request
2023-01-10T05:22:15.266520Z  INFO http{method="GET" uri=/icon.png version=HTTP/1.0}: chirpstack::api: Finished processing request status="200" latency=36.067µs
2023-01-10T05:22:15.301306Z DEBUG gRPC{uri=/api.ApplicationService/Get}: chirpstack::api: Started processing request
2023-01-10T05:22:15.303169Z  INFO gRPC{uri=/api.ApplicationService/Get}: chirpstack::api: Finished processing request status="200" latency=1.869528ms
2023-01-10T05:22:15.321412Z DEBUG http{method="GET" uri=/logo.png version=HTTP/1.0}: chirpstack::api: Started processing request
2023-01-10T05:22:15.321439Z  INFO http{method="GET" uri=/logo.png version=HTTP/1.0}: chirpstack::api: Finished processing request status="200" latency=36.468µs
2023-01-10T05:22:15.336175Z TRACE chirpstack::downlink::scheduler: Starting multicast-group queue scheduler loop run
2023-01-10T05:22:15.336183Z TRACE chirpstack::downlink::scheduler: Getting schedulable multicast-group queue items
2023-01-10T05:22:15.336212Z DEBUG gRPC{uri=/api.DeviceService/Get}: chirpstack::api: Started processing request
2023-01-10T05:22:15.337139Z TRACE chirpstack::downlink::scheduler: Got this number of multicast-group queue items count=0
2023-01-10T05:22:15.337150Z TRACE chirpstack::downlink::scheduler: Multicast-group queue scheduler run completed successfully
2023-01-10T05:22:15.339681Z  INFO gRPC{uri=/api.DeviceService/Get}: chirpstack::api: Finished processing request status="200" latency=3.471485ms
2023-01-10T05:22:15.357016Z TRACE chirpstack::downlink::scheduler: Starting class_b_c_scheduler_loop run
2023-01-10T05:22:15.357025Z TRACE chirpstack::downlink::scheduler: Getting devices that have schedulable queue-items
2023-01-10T05:22:15.358173Z TRACE chirpstack::downlink::scheduler: Got this number of devices with schedulable queue-items device_count=0
2023-01-10T05:22:15.358183Z TRACE chirpstack::downlink::scheduler: class_b_c_scheduler_loop completed successfully
2023-01-10T05:22:15.372525Z DEBUG gRPC{uri=/api.DeviceProfileService/Get}: chirpstack::api: Started processing request
2023-01-10T05:22:15.375163Z  INFO gRPC{uri=/api.DeviceProfileService/Get}: chirpstack::api: Finished processing request status="200" latency=2.642662ms
2023-01-10T05:22:15.432077Z DEBUG gRPC{uri=/api.InternalService/StreamDeviceEvents}: chirpstack::api: Started processing request
2023-01-10T05:22:15.433064Z  INFO gRPC{uri=/api.InternalService/StreamDeviceEvents}: chirpstack::api: Finished processing request status="200" latency=992.707µs
2023-01-10T05:22:15.433395Z TRACE chirpstack::eventlog: Event-log received from stream key=up id=1673318457975-0
2023-01-10T05:22:15.433476Z TRACE chirpstack::api::internal: Message received from Redis Stream channel
2023-01-10T05:22:16.338168Z TRACE chirpstack::downlink::scheduler: Starting multicast-group queue scheduler loop run

chirpstack-gateway-brigde.toml

[integration.mqtt.auth.generic]
servers=["tcp://mosquitto:1883"]
username=""
password=""

[integration.mqtt]
event_topic_template="au915_0/gateway/{{ .GatewayID }}/event/{{ .EventType }}"
state_topic_template="au915_0/gateway/{{ .GatewayID }}/state/{{ .StateType }}"
command_topic_template="au915_0/gateway/{{ .GatewayID }}/command/#"

chirpstack.toml

[logging]

  level="info"

[postgresql]

  dsn="postgres://chirpstack:chirpstack@$POSTGRESQL_HOST/chirpstack?sslmode=disable"

  max_open_connections=10

  min_idle_connections=0

[redis]

  servers=[
    "redis://$REDIS_HOST/",
  ]

  tls_enabled=false

  cluster=false

[network]

  net_id="000000"

  # regions commented out to make help debugging
  enabled_regions=[
    # "as923",
    # "as923_2",
    # "as923_3",
    # "as923_4",
    "au915_0",
    # "cn470_10",
    # "cn779",
    # "eu433",
    # "eu868",
    # "in865",
    # "ism2400",
    # "kr920",
    # "ru864",
    # "us915_0",
    # "us915_1",
  ]

# API interface configuration.
[api]

  bind="0.0.0.0:8080"

  secret="REDACTED"

[integration]
  enabled=["mqtt"]

  [integration.mqtt]
    server="tcp://mosquitto:1883/"
    json=true
JTuckerBCAE commented 1 year ago

Turns out it was a proxy issue, nginx needs to pass gRPC to /api.

I am still unsure why this issue persists when bypassing the proxy but, there shouldn't be a case where I am using this without the proxy.

location ^~ /api { 
    grpc_pass grpc://chirpstack:8080; 
}

see https://github.com/chirpstack/chirpstack/issues/75

mjlaurent6 commented 1 year ago

Hi @JTuckerBCAE, just want to ask where did you put the nginx.conf ? is it under new folder called .nginx ? I am not really familiar with NGINX setup on docker. and how did you include the nginx conf under docker-compose ? is it automatic ?