Hello
Similar to others, we have met the problem that Sentry will stop working with following symptons after we have upgrade into 20:
- Only
infolevel events are captured and displayed. Allerrorandfatallevel sentry event will not be displayed. - It is traffic volume related. With big sentry traffic, the problem will happend after 3 days around, with lower traffic, it might be a week.
- the way to turn Sentry back to service is to clear away volumes of
kafka,zookeeper, andredis, and run the install.sh again. With this approach, Sentry will back to serive, displaying capturederrorandfatallevel events until it next stop
Checking around forum, I guess the problem may be related to relay service, which failed to send request to web.
So I changed the logging level of relay service to TRACE and got following logs
relay logs
2020-08-30T09:49:11Z [relay::setup] INFO: launching relay from config folder /work/.relay
2020-08-30T09:49:11Z [relay::setup] INFO: relay mode: managed
2020-08-30T09:49:11Z [relay::setup] INFO: relay id: 02e827b1-ca56-4f33-9f97-4c00fdcacac7
2020-08-30T09:49:11Z [relay::setup] INFO: public key: FSQ5SkT2oFaroJN0eub5pWZmjitFA_Pzu739pCB5kNc
2020-08-30T09:49:11Z [relay::setup] INFO: log level: TRACE
2020-08-30T09:49:11Z [relay_server::actors::upstream] INFO: upstream relay started
2020-08-30T09:49:11Z [relay_server::actors::upstream] INFO: registering with upstream (http://web:9000/)
2020-08-30T09:49:11Z [relay_server::actors::outcome::processing] INFO: OutcomeProducer started.
2020-08-30T09:49:11Z [rdkafka::client] ERROR: librdkafka: Global error: BrokerTransportFailure (Local: Broker transport failure): kafka:9092/bootstrap: Connect to ipv4#192.168.128.10:9092 failed: Connection refused (after 21ms in state CONNECT)
2020-08-30T09:49:11Z [rdkafka::client] ERROR: librdkafka: Global error: AllBrokersDown (Local: All broker connections are down): 1/1 brokers are down
2020-08-30T09:49:11Z [relay_server::actors::events] INFO: starting 8 event processing workers
2020-08-30T09:49:11Z [rdkafka::client] ERROR: librdkafka: Global error: BrokerTransportFailure (Local: Broker transport failure): kafka:9092/bootstrap: Connect to ipv4#192.168.128.10:9092 failed: Connection refused (after 1ms in state CONNECT)
2020-08-30T09:49:11Z [rdkafka::client] ERROR: librdkafka: Global error: AllBrokersDown (Local: All broker connections are down): 1/1 brokers are down
2020-08-30T09:49:11Z [relay_server::service] INFO: spawning http server
2020-08-30T09:49:11Z [relay_server::service] INFO: listening on: http://0.0.0.0:3000/
2020-08-30T09:49:11Z [actix_net::server::server] INFO: Starting 8 workers
2020-08-30T09:49:11Z [relay_server::actors::store] INFO: store forwarder started
2020-08-30T09:49:11Z [relay_server::actors::project_redis] INFO: redis project cache started
2020-08-30T09:49:11Z [relay_server::actors::project_redis] INFO: redis project cache started
2020-08-30T09:49:11Z [relay_server::actors::project_redis] INFO: redis project cache started
2020-08-30T09:49:11Z [relay_server::actors::project_redis] INFO: redis project cache started
2020-08-30T09:49:11Z [relay_server::actors::project_redis] INFO: redis project cache started
2020-08-30T09:49:11Z [relay_server::actors::project_redis] INFO: redis project cache started
2020-08-30T09:49:11Z [relay_server::actors::project_redis] INFO: redis project cache started
2020-08-30T09:49:11Z [relay_server::actors::project_redis] INFO: redis project cache started
2020-08-30T09:49:11Z [actix_net::server::server] INFO: Starting server on 0.0.0.0:3000
2020-08-30T09:49:11Z [relay_server::actors::controller] INFO: relay server starting
2020-08-30T09:49:11Z [relay_server::actors::connector] INFO: metered connector started
2020-08-30T09:49:11Z [relay_server::actors::events] INFO: event manager started
2020-08-30T09:49:11Z [relay_server::actors::project_local] INFO: project local cache started
2020-08-30T09:49:11Z [relay_server::actors::project_upstream] INFO: project upstream cache started
2020-08-30T09:49:11Z [relay_server::actors::project_cache] INFO: project cache started
2020-08-30T09:49:11Z [relay_server::actors::project_keys] INFO: project cache started
2020-08-30T09:49:11Z [relay_server::actors::relays] INFO: key cache started
2020-08-30T09:49:14Z [relay_server::actors::upstream] ERROR: authentication encountered error: could not send request to upstream
caused by: Timeout while waiting for response
2020-08-30T09:49:14Z [relay_server::actors::upstream] DEBUG: scheduling authentication retry in 0 seconds
2020-08-30T09:49:14Z [relay_server::actors::upstream] INFO: registering with upstream (http://web:9000/)
2020-08-30T09:49:17Z [relay_server::actors::upstream] ERROR: authentication encountered error: could not send request to upstream
caused by: Timeout while waiting for response
2020-08-30T09:49:17Z [relay_server::actors::upstream] DEBUG: scheduling authentication retry in 1 seconds
2020-08-30T09:49:18Z [relay_server::actors::project] DEBUG: project 3 initialized without state
2020-08-30T09:49:18Z [relay_server::actors::project] DEBUG: project 3 state requested
2020-08-30T09:49:18Z [relay_server::actors::events] TRACE: queued event
2020-08-30T09:49:18Z [relay_server::actors::project] DEBUG: project 3 state request amended
2020-08-30T09:49:18Z [relay_server::actors::project_upstream] DEBUG: updating project states for 1/1 projects (attempt 1)
2020-08-30T09:49:18Z [relay_server::actors::project_upstream] DEBUG: sending request of size 1
2020-08-30T09:49:18Z [relay_server::actors::project_upstream] ERROR: error fetching project states: attempted to send request while not yet authenticated
2020-08-30T09:49:18Z [relay_server::actors::upstream] INFO: registering with upstream (http://web:9000/)
2020-08-30T09:49:19Z [relay_server::actors::project_upstream] DEBUG: updating project states for 1/1 projects (attempt 2)
2020-08-30T09:49:19Z [relay_server::actors::project_upstream] DEBUG: sending request of size 1
2020-08-30T09:49:19Z [relay_server::actors::project_upstream] ERROR: error fetching project states: attempted to send request while not yet authenticated
2020-08-30T09:49:21Z [relay_server::actors::project_upstream] DEBUG: updating project states for 1/1 projects (attempt 3)
2020-08-30T09:49:21Z [relay_server::actors::project_upstream] DEBUG: sending request of size 1
2020-08-30T09:49:21Z [relay_server::actors::project_upstream] ERROR: error fetching project states: attempted to send request while not yet authenticated
2020-08-30T09:49:21Z [relay_server::actors::upstream] ERROR: authentication encountered error: could not send request to upstream
caused by: Timeout while waiting for response
2020-08-30T09:49:21Z [relay_server::actors::upstream] DEBUG: scheduling authentication retry in 1 seconds
2020-08-30T09:49:23Z [relay_server::actors::upstream] INFO: registering with upstream (http://web:9000/)
2020-08-30T09:49:23Z [relay_server::actors::project_upstream] DEBUG: updating project states for 1/1 projects (attempt 4)
2020-08-30T09:49:23Z [relay_server::actors::project_upstream] DEBUG: sending request of size 1
2020-08-30T09:49:23Z [relay_server::actors::project_upstream] ERROR: error fetching project states: attempted to send request while not yet authenticated
2020-08-30T09:49:26Z [relay_server::actors::upstream] ERROR: authentication encountered error: could not send request to upstream
caused by: Timeout while waiting for response
2020-08-30T09:49:26Z [relay_server::actors::upstream] DEBUG: scheduling authentication retry in 2 seconds
2020-08-30T09:49:27Z [relay_server::actors::project_upstream] DEBUG: updating project states for 1/1 projects (attempt 5)
2020-08-30T09:49:27Z [relay_server::actors::project_upstream] DEBUG: sending request of size 1
2020-08-30T09:49:27Z [relay_server::actors::project_upstream] ERROR: error fetching project states: attempted to send request while not yet authenticated
2020-08-30T09:49:28Z [relay_server::actors::upstream] INFO: registering with upstream (http://web:9000/)
2020-08-30T09:49:31Z [relay_server::actors::upstream] ERROR: authentication encountered error: could not send request to upstream
caused by: Timeout while waiting for response
2020-08-30T09:49:31Z [relay_server::actors::upstream] DEBUG: scheduling authentication retry in 3 seconds
2020-08-30T09:49:32Z [relay_server::actors::project_upstream] DEBUG: updating project states for 1/1 projects (attempt 6)
2020-08-30T09:49:32Z [relay_server::actors::project_upstream] DEBUG: sending request of size 1
2020-08-30T09:49:32Z [relay_server::actors::project_upstream] ERROR: error fetching project states: attempted to send request while not yet authenticated
2020-08-30T09:49:34Z [relay_server::actors::upstream] INFO: registering with upstream (http://web:9000/)
2020-08-30T09:49:37Z [relay_server::actors::upstream] ERROR: authentication encountered error: could not send request to upstream
caused by: Timeout while waiting for response
2020-08-30T09:49:37Z [relay_server::actors::upstream] DEBUG: scheduling authentication retry in 5 seconds
2020-08-30T09:49:39Z [relay_server::actors::project_upstream] DEBUG: updating project states for 1/1 projects (attempt 7)
2020-08-30T09:49:39Z [relay_server::actors::project_upstream] DEBUG: sending request of size 1
2020-08-30T09:49:39Z [relay_server::actors::project_upstream] ERROR: error fetching project states: attempted to send request while not yet authenticated
2020-08-30T09:49:42Z [relay_server::actors::upstream] INFO: registering with upstream (http://web:9000/)
2020-08-30T09:49:45Z [relay_server::actors::upstream] ERROR: authentication encountered error: could not send request to upstream
caused by: Timeout while waiting for response
2020-08-30T09:49:45Z [relay_server::actors::upstream] DEBUG: scheduling authentication retry in 7 seconds
2020-08-30T09:49:51Z [relay_server::actors::project_upstream] DEBUG: updating project states for 0/0 projects (attempt 8)
2020-08-30T09:49:52Z [relay_server::actors::project] DEBUG: project 3 state requested
2020-08-30T09:49:52Z [relay_server::actors::events] TRACE: queued event
2020-08-30T09:49:52Z [relay_server::actors::project] DEBUG: project 3 state request amended
2020-08-30T09:49:52Z [relay_server::actors::project_upstream] DEBUG: updating project states for 1/1 projects (attempt 1)
2020-08-30T09:49:52Z [relay_server::actors::project_upstream] DEBUG: sending request of size 1
2020-08-30T09:49:52Z [relay_server::actors::project_upstream] ERROR: error fetching project states: attempted to send request while not yet authenticated
2020-08-30T09:49:53Z [relay_server::actors::upstream] INFO: registering with upstream (http://web:9000/)
2020-08-30T09:49:53Z [relay_server::actors::project_upstream] DEBUG: updating project states for 1/1 projects (attempt 2)
2020-08-30T09:49:53Z [relay_server::actors::project_upstream] DEBUG: sending request of size 1
2020-08-30T09:49:53Z [relay_server::actors::project_upstream] ERROR: error fetching project states: attempted to send request while not yet authenticated
2020-08-30T09:49:55Z [relay_server::actors::project_upstream] DEBUG: updating project states for 1/1 projects (attempt 3)
2020-08-30T09:49:55Z [relay_server::actors::project_upstream] DEBUG: sending request of size 1
2020-08-30T09:49:55Z [relay_server::actors::project_upstream] ERROR: error fetching project states: attempted to send request while not yet authenticated
2020-08-30T09:49:56Z [relay_server::actors::upstream] ERROR: authentication encountered error: could not send request to upstream
caused by: Timeout while waiting for response
2020-08-30T09:49:56Z [relay_server::actors::upstream] DEBUG: scheduling authentication retry in 11 seconds
2020-08-30T09:49:57Z [relay_server::actors::project_upstream] DEBUG: updating project states for 1/1 projects (attempt 4)
2020-08-30T09:49:57Z [relay_server::actors::project_upstream] DEBUG: sending request of size 1
2020-08-30T09:49:57Z [relay_server::actors::project_upstream] ERROR: error fetching project states: attempted to send request while not yet authenticated
2020-08-30T09:49:58Z [relay_server::actors::project] DEBUG: project 3 state request amended
2020-08-30T09:49:58Z [relay_server::actors::events] TRACE: queued event
2020-08-30T09:49:58Z [relay_server::actors::project] DEBUG: project 3 state request amended
2020-08-30T09:50:01Z [relay_server::actors::project_upstream] DEBUG: updating project states for 1/1 projects (attempt 5)
2020-08-30T09:50:01Z [relay_server::actors::project_upstream] DEBUG: sending request of size 1
2020-08-30T09:50:01Z [relay_server::actors::project_upstream] ERROR: error fetching project states: attempted to send request while not yet authenticated
2020-08-30T09:50:06Z [relay_server::actors::project_upstream] DEBUG: updating project states for 1/1 projects (attempt 6)
2020-08-30T09:50:06Z [relay_server::actors::project_upstream] DEBUG: sending request of size 1
2020-08-30T09:50:06Z [relay_server::actors::project_upstream] ERROR: error fetching project states: attempted to send request while not yet authenticated
2020-08-30T09:50:07Z [relay_server::actors::upstream] INFO: registering with upstream (http://web:9000/)
2020-08-30T09:50:10Z [relay_server::actors::upstream] ERROR: authentication encountered error: could not send request to upstream
caused by: Timeout while waiting for response
2020-08-30T09:50:10Z [relay_server::actors::upstream] DEBUG: scheduling authentication retry in 17 seconds
2020-08-30T09:50:14Z [relay_server::actors::project_upstream] DEBUG: updating project states for 1/1 projects (attempt 7)
2020-08-30T09:50:14Z [relay_server::actors::project_upstream] DEBUG: sending request of size 1
2020-08-30T09:50:14Z [relay_server::actors::project_upstream] ERROR: error fetching project states: attempted to send request while not yet authenticated
2020-08-30T09:50:25Z [relay_server::actors::project_upstream] DEBUG: updating project states for 0/0 projects (attempt 8)
2020-08-30T09:50:25Z [relay_server::actors::events] ERROR: error processing event: failed to resolve project information
caused by: failed to fetch project state from upstream
2020-08-30T09:50:25Z [relay_server::actors::events] ERROR: error processing event: failed to resolve project information
caused by: failed to fetch project state from upstream
2020-08-30T09:50:25Z [relay_server::actors::outcome::processing] TRACE: handling outcome
2020-08-30T09:50:25Z [relay_server::actors::outcome::processing] TRACE: Tracking kafka outcome: TrackRawOutcome { timestamp: "2020-08-30T09:50:25.764955Z", org_id: None, project_id: ProjectId(3), key_id: None, outcome: 3, reason: Some("internal"), event_id: Some(EventId(345b4e55-0290-4640-b689-fd8ff78119ef)), remote_addr: Some("10.255.255.154"), source: None }
2020-08-30T09:50:25Z [relay_server::actors::outcome::processing] TRACE: handling outcome
2020-08-30T09:50:25Z [relay_server::actors::outcome::processing] TRACE: Tracking kafka outcome: TrackRawOutcome { timestamp: "2020-08-30T09:50:25.764987Z", org_id: None, project_id: ProjectId(3), key_id: None, outcome: 3, reason: Some("internal"), event_id: Some(EventId(aa0cf1bd-5c07-45c1-9d34-49acdbc07cab)), remote_addr: Some("10.255.255.154"), source: None }
2020-08-30T09:50:27Z [relay_server::actors::upstream] INFO: registering with upstream (http://web:9000/)
So I guess maybe due to this authentication encountered error: could not send request to upstream results in error fetching project states: attempted to send request while not yet authenticated, the events are all queued up, until the resource was somehow eaten up.
To figure out, as relay service has web for upstream, so I added this dependency in docker-compose.yml as
relay:
<< : *restart_policy
image: '$RELAY_IMAGE'
volumes:
- type: bind
read_only: true
source: ./relay
target: /work/.relay
depends_on:
- kafka
- redis
- web
The I have following errors and it seems the problem is solved while I will wait for one week to see:
connection was reset
2020-08-30T10:28:47Z [relay::setup] INFO: launching relay from config folder /work/.relay
2020-08-30T10:28:47Z [relay::setup] INFO: relay mode: managed
2020-08-30T10:28:47Z [relay::setup] INFO: relay id: 02e827b1-ca56-4f33-9f97-4c00fdcacac7
2020-08-30T10:28:47Z [relay::setup] INFO: public key: FSQ5SkT2oFaroJN0eub5pWZmjitFA_Pzu739pCB5kNc
2020-08-30T10:28:47Z [relay::setup] INFO: log level: TRACE
2020-08-30T10:28:47Z [relay_server::actors::upstream] INFO: upstream relay started
2020-08-30T10:28:47Z [relay_server::actors::upstream] INFO: registering with upstream (http://web:9000/)
2020-08-30T10:28:47Z [rdkafka::client] ERROR: librdkafka: Global error: BrokerTransportFailure (Local: Broker transport failure): kafka:9092/bootstrap: Connect to ipv4#192.168.176.10:9092 failed: Connection refused (after 5ms in state CONNECT)
2020-08-30T10:28:47Z [rdkafka::client] ERROR: librdkafka: Global error: AllBrokersDown (Local: All broker connections are down): 1/1 brokers are down
2020-08-30T10:28:47Z [relay_server::actors::outcome::processing] INFO: OutcomeProducer started.
2020-08-30T10:28:47Z [relay_server::actors::events] INFO: starting 8 event processing workers
2020-08-30T10:28:47Z [rdkafka::client] ERROR: librdkafka: Global error: BrokerTransportFailure (Local: Broker transport failure): kafka:9092/bootstrap: Connect to ipv4#192.168.176.10:9092 failed: Connection refused (after 12ms in state CONNECT)
2020-08-30T10:28:47Z [rdkafka::client] ERROR: librdkafka: Global error: AllBrokersDown (Local: All broker connections are down): 1/1 brokers are down
2020-08-30T10:28:47Z [relay_server::service] INFO: spawning http server
2020-08-30T10:28:47Z [relay_server::service] INFO: listening on: http://0.0.0.0:3000/
2020-08-30T10:28:47Z [actix_net::server::server] INFO: Starting 8 workers
2020-08-30T10:28:47Z [relay_server::actors::store] INFO: store forwarder started
2020-08-30T10:28:47Z [relay_server::actors::project_redis] INFO: redis project cache started
2020-08-30T10:28:47Z [relay_server::actors::project_redis] INFO: redis project cache started
2020-08-30T10:28:47Z [relay_server::actors::project_redis] INFO: redis project cache started
2020-08-30T10:28:47Z [relay_server::actors::project_redis] INFO: redis project cache started
2020-08-30T10:28:47Z [relay_server::actors::project_redis] INFO: redis project cache started
2020-08-30T10:28:47Z [relay_server::actors::project_redis] INFO: redis project cache started
2020-08-30T10:28:47Z [relay_server::actors::project_redis] INFO: redis project cache started
2020-08-30T10:28:47Z [relay_server::actors::project_redis] INFO: redis project cache started
2020-08-30T10:28:47Z [actix_net::server::server] INFO: Starting server on 0.0.0.0:3000
2020-08-30T10:28:47Z [relay_server::actors::controller] INFO: relay server starting
2020-08-30T10:28:47Z [relay_server::actors::connector] INFO: metered connector started
2020-08-30T10:28:47Z [relay_server::actors::events] INFO: event manager started
2020-08-30T10:28:47Z [relay_server::actors::project_local] INFO: project local cache started
2020-08-30T10:28:47Z [relay_server::actors::project_upstream] INFO: project upstream cache started
2020-08-30T10:28:47Z [relay_server::actors::project_cache] INFO: project cache started
2020-08-30T10:28:47Z [relay_server::actors::project_keys] INFO: project cache started
2020-08-30T10:28:47Z [relay_server::actors::relays] INFO: key cache started
2020-08-30T10:28:47Z [relay_server::actors::upstream] ERROR: authentication encountered error: could not send request to upstream
caused by: Failed to connect to host: Connection refused (os error 111)
caused by: Connection refused (os error 111)
caused by: Connection refused (os error 111)
2020-08-30T10:28:47Z [relay_server::actors::upstream] DEBUG: scheduling authentication retry in 0 seconds
2020-08-30T10:28:47Z [relay_server::actors::upstream] INFO: registering with upstream (http://web:9000/)
2020-08-30T10:28:47Z [relay_server::actors::upstream] ERROR: authentication encountered error: could not send request to upstream
caused by: Failed to connect to host: Connection refused (os error 111)
caused by: Connection refused (os error 111)
caused by: Connection refused (os error 111)
2020-08-30T10:28:47Z [relay_server::actors::upstream] DEBUG: scheduling authentication retry in 1 seconds
2020-08-30T10:28:48Z [relay_server::actors::upstream] INFO: registering with upstream (http://web:9000/)
2020-08-30T10:28:48Z [relay_server::actors::upstream] ERROR: authentication encountered error: could not send request to upstream
caused by: Failed to connect to host: Connection refused (os error 111)
caused by: Connection refused (os error 111)
caused by: Connection refused (os error 111)
2020-08-30T10:28:48Z [relay_server::actors::upstream] DEBUG: scheduling authentication retry in 1 seconds
2020-08-30T10:28:50Z [relay_server::actors::upstream] INFO: registering with upstream (http://web:9000/)
2020-08-30T10:28:50Z [relay_server::actors::upstream] ERROR: authentication encountered error: could not send request to upstream
caused by: Failed to connect to host: Connection refused (os error 111)
caused by: Connection refused (os error 111)
caused by: Connection refused (os error 111)
2020-08-30T10:28:50Z [relay_server::actors::upstream] DEBUG: scheduling authentication retry in 2 seconds
2020-08-30T10:28:52Z [relay_server::actors::upstream] INFO: registering with upstream (http://web:9000/)
2020-08-30T10:28:56Z [relay_server::actors::upstream] DEBUG: got register challenge (token = DUiIvgwLcnLEn2YULXvO3z7bryMEZl6NEHROz3hBDmQrqTda0DqwaahwnomNk6V5pphlIAiNSZnwa-yeHHZuaA)
2020-08-30T10:28:56Z [relay_server::actors::upstream] DEBUG: sending register challenge response
2020-08-30T10:28:56Z [relay_server::actors::upstream] INFO: relay successfully registered with upstream
2020-08-30T10:29:01Z [relay_server::actors::project] DEBUG: project 3 initialized without state
2020-08-30T10:29:01Z [relay_server::actors::project] DEBUG: project 3 state requested
2020-08-30T10:29:01Z [relay_server::actors::events] TRACE: queued event
2020-08-30T10:29:01Z [relay_server::actors::project] DEBUG: project 3 state request amended
2020-08-30T10:29:01Z [relay_server::actors::project_upstream] DEBUG: updating project states for 1/1 projects (attempt 1)
2020-08-30T10:29:01Z [relay_server::actors::project_upstream] DEBUG: sending request of size 1
2020-08-30T10:29:01Z [relay_server::actors::project] DEBUG: project 3 state updated
2020-08-30T10:29:01Z [relay_server::actors::events] TRACE: processing json event
2020-08-30T10:29:01Z [relay_server::actors::events] TRACE: sending envelope to kafka
2020-08-30T10:29:01Z [relay_server::actors::store] TRACE: Sending event item of envelope to kafka
2020-08-30T10:29:52Z [relay_server::actors::events] TRACE: queued event
2020-08-30T10:29:52Z [relay_server::actors::events] TRACE: processing json event
2020-08-30T10:29:52Z [relay_server::actors::events] TRACE: sending envelope to kafka
2020-08-30T10:29:52Z [relay_server::actors::store] TRACE: Sending event item of envelope to kafka
2020-08-30T10:29:58Z [relay_server::actors::events] TRACE: queued event
2020-08-30T10:29:58Z [relay_server::actors::events] TRACE: processing json event
2020-08-30T10:29:58Z [relay_server::actors::events] TRACE: sending envelope to kafka
2020-08-30T10:29:58Z [relay_server::actors::store] TRACE: Sending event item of envelope to kafka
Please kindly check this issue