Onpremise: Sentry stops processing when it receives too much events
Version Information
Version: Sentry 20.10.1
Steps to Reproduce
Nothing specific. we were using it normally and suddenly it happened.
I think an event peak or event flooding may be caused this problem.
Expected Result
Sentry should keep receiving events from clients (android devices, PHP backend) and process them without any interruption.
The system resources are good enough I think: a CentOS 7 server with 32 CPU cores and 62GB of RAM.
Actual Result
After processing some event batches, it stops working. It works for about ~ 5 mins and then doesn't process new events.
I tried this solution, but it didn't work. It got back to the previous situation after processing a couple of events.
Logs
For better logging, I stopped the Nginx service so Sentry does not accept any new event and these logs are about the previously received events which are processing now.
Kafka Groups:
root@b14e16de2cf4:/# kafka-consumer-groups --bootstrap-server 127.0.0.1:9092 --group snuba-consumers -describe
GROUP TOPIC PARTITION CURRENT-OFFSET LOG-END-OFFSET LAG CONSUMER-ID HOST CLIENT-ID
snuba-consumers ingest-sessions 0 83426343 83426343 0 rdkafka-fd1d74cd-86e4-47a4-827a-bfb246a6f8b7 /192.168.160.1 rdkafka
snuba-consumers outcomes 0 79425566 79425580 14 rdkafka-0fee7a20-5070-4805-95c0-1d7f2b51e82e /192.168.160.1 rdkafka
snuba-consumers events 0 77363710 77363727 17 rdkafka-e7d90b5b-7306-4402-a858-b51301b5f81c /192.168.160.1 rdkafka
root@b14e16de2cf4:/# kafka-consumer-groups --bootstrap-server 127.0.0.1:9092 --group ingest-consumer -describe
GROUP TOPIC PARTITION CURRENT-OFFSET LOG-END-OFFSET LAG CONSUMER-ID HOST CLIENT-ID
ingest-consumer ingest-events 0 79827107 79827107 0 rdkafka-f2d70605-525a-4f45-8a8b-caeac70da32e /192.168.160.1 rdkafka
ingest-consumer ingest-transactions 0 1136694 1136694 0 rdkafka-f2d70605-525a-4f45-8a8b-caeac70da32e /192.168.160.1 rdkafka
ingest-consumer ingest-attachments 0 - 0 - rdkafka-f2d70605-525a-4f45-8a8b-caeac70da32e /192.168.160.1 rdkafka
root@b14e16de2cf4:/# kafka-consumer-groups --bootstrap-server 127.0.0.1:9092 --group snuba-post-processor -describe
GROUP TOPIC PARTITION CURRENT-OFFSET LOG-END-OFFSET LAG CONSUMER-ID HOST CLIENT-ID
snuba-post-processor events 0 77370427 77370446 19 rdkafka-7beb855f-b80c-4414-857c-1a12cb243bb1 /192.168.160.1 rdkafka
root@b14e16de2cf4:/# kafka-consumer-groups --bootstrap-server 127.0.0.1:9092 --group snuba-replacers -describe
GROUP TOPIC PARTITION CURRENT-OFFSET LOG-END-OFFSET LAG CONSUMER-ID HOST CLIENT-ID
snuba-replacers event-replacements 0 - 20 - rdkafka-84a8edfe-4bb1-4d9c-940c-123bf128c973 /192.168.160.1 rdkafka
Docker Logs:
[root@footballi-5 sentry-onpromise]# docker-compose logs --tail 30
Attaching to sentry_onpremise_nginx_1, sentry_onpremise_sentry-cleanup_1, sentry_onpremise_web_1, sentry_onpremise_worker_1, sentry_onpremise_post-process-forwarder_1, sentry_onpremise_ingest-consumer_1, sentry_onpremise_cron_1, sentry_onpremise_snuba-transactions-consumer_1, sentry_onpremise_snuba-cleanup_1, sentry_onpremise_snuba-sessions-consumer_1, sentry_onpremise_snuba-replacer_1, sentry_onpremise_relay_1, sentry_onpremise_snuba-api_1, sentry_onpremise_snuba-outcomes-consumer_1, sentry_onpremise_snuba-consumer_1, sentry_onpremise_kafka_1, sentry_onpremise_smtp_1, sentry_onpremise_zookeeper_1, sentry_onpremise_clickhouse_1, sentry_onpremise_postgres_1, sentry_onpremise_memcached_1, sentry_onpremise_redis_1, sentry_onpremise_symbolicator-cleanup_1, sentry_onpremise_symbolicator_1
cron_1 | return ctx.invoke(self.callback, **ctx.params)
cron_1 | File "/usr/local/lib/python2.7/site-packages/click/core.py", line 610, in invoke
cron_1 | return callback(*args, **kwargs)
cron_1 | File "/usr/local/lib/python2.7/site-packages/click/decorators.py", line 21, in new_func
cron_1 | return f(get_current_context(), *args, **kwargs)
cron_1 | File "/usr/local/lib/python2.7/site-packages/sentry/runner/decorators.py", line 68, in inner
cron_1 | return ctx.invoke(f, *args, **kwargs)
cron_1 | File "/usr/local/lib/python2.7/site-packages/click/core.py", line 610, in invoke
cron_1 | return callback(*args, **kwargs)
cron_1 | File "/usr/local/lib/python2.7/site-packages/click/decorators.py", line 21, in new_func
cron_1 | return f(get_current_context(), *args, **kwargs)
cron_1 | File "/usr/local/lib/python2.7/site-packages/sentry/runner/decorators.py", line 29, in inner
cron_1 | configure()
cron_1 | File "/usr/local/lib/python2.7/site-packages/sentry/runner/__init__.py", line 129, in configure
cron_1 | configure(ctx, py, yaml, skip_service_validation)
cron_1 | File "/usr/local/lib/python2.7/site-packages/sentry/runner/settings.py", line 158, in configure
cron_1 | skip_service_validation=skip_service_validation,
cron_1 | File "/usr/local/lib/python2.7/site-packages/sentry/runner/initializer.py", line 346, in initialize_app
cron_1 | setup_services(validate=not skip_service_validation)
cron_1 | File "/usr/local/lib/python2.7/site-packages/sentry/runner/initializer.py", line 388, in setup_services
cron_1 | service.validate()
cron_1 | File "/usr/local/lib/python2.7/site-packages/sentry/utils/services.py", line 105, in <lambda>
cron_1 | context[key] = (lambda f: lambda *a, **k: getattr(self, f)(*a, **k))(key)
cron_1 | File "/usr/local/lib/python2.7/site-packages/sentry/buffer/redis.py", line 69, in validate
cron_1 | raise InvalidConfiguration(six.text_type(e))
cron_1 | sentry.exceptions.InvalidConfiguration: Redis is loading the dataset in memory
cron_1 | 19:14:20 [WARNING] sentry.utils.geo: settings.GEOIP_PATH_MMDB not configured.
cron_1 | /usr/local/lib/python2.7/site-packages/OpenSSL/crypto.py:12: CryptographyDeprecationWarning: Python 2 is no longer supported by the Python core team. Support for it is now deprecated in cryptography, and will be removed in a future release.
cron_1 | from cryptography import x509
cron_1 | 19:14:25 [INFO] sentry.plugins.github: apps-not-configured
clickhouse_1 | Processing configuration file '/etc/clickhouse-server/config.xml'.
clickhouse_1 | Merging configuration file '/etc/clickhouse-server/config.d/docker_related_config.xml'.
clickhouse_1 | Merging configuration file '/etc/clickhouse-server/config.d/sentry.xml'.
clickhouse_1 | Include not found: clickhouse_remote_servers
clickhouse_1 | Include not found: clickhouse_compression
clickhouse_1 | Logging trace to /var/log/clickhouse-server/clickhouse-server.log
clickhouse_1 | Logging errors to /var/log/clickhouse-server/clickhouse-server.err.log
clickhouse_1 | Processing configuration file '/etc/clickhouse-server/users.xml'.
clickhouse_1 | Include not found: networks
clickhouse_1 | Saved preprocessed configuration to '/var/lib/clickhouse//preprocessed_configs/users.xml'.
clickhouse_1 | Processing configuration file '/etc/clickhouse-server/config.xml'.
clickhouse_1 | Merging configuration file '/etc/clickhouse-server/config.d/docker_related_config.xml'.
clickhouse_1 | Merging configuration file '/etc/clickhouse-server/config.d/sentry.xml'.
clickhouse_1 | Include not found: clickhouse_remote_servers
clickhouse_1 | Include not found: clickhouse_compression
clickhouse_1 | Saved preprocessed configuration to '/var/lib/clickhouse//preprocessed_configs/config.xml'.
ingest-consumer_1 | 19:36:57 [INFO] batching-kafka-consumer: Flushing 100 items (from {(u'ingest-events', 0): [79825950L, 79826049L]}): forced:False size:True time:False
ingest-consumer_1 | 19:36:59 [WARNING] sentry.ingest.ingest_consumer: pre-process-forwarder detected a duplicated event with id:3a84abffcadc45fc807ff61b8bc912bd for project:12.
ingest-consumer_1 | 19:36:59 [INFO] batching-kafka-consumer: Worker flush took 1604ms
ingest-consumer_1 | 19:36:59 [INFO] batching-kafka-consumer: Flushing 100 items (from {(u'ingest-events', 0): [79826050L, 79826149L]}): forced:False size:True time:False
ingest-consumer_1 | 19:37:00 [WARNING] sentry.ingest.ingest_consumer: pre-process-forwarder detected a duplicated event with id:51b54d6514064515b14a1dd2c7889c84 for project:12.
ingest-consumer_1 | 19:37:01 [INFO] batching-kafka-consumer: Worker flush took 1679ms
ingest-consumer_1 | 19:37:01 [INFO] batching-kafka-consumer: Flushing 100 items (from {(u'ingest-events', 0): [79826150L, 79826249L]}): forced:False size:True time:False
ingest-consumer_1 | 19:37:03 [INFO] batching-kafka-consumer: Worker flush took 1725ms
ingest-consumer_1 | 19:37:03 [INFO] batching-kafka-consumer: Flushing 100 items (from {(u'ingest-events', 0): [79826250L, 79826349L]}): forced:False size:True time:False
ingest-consumer_1 | 19:37:03 [WARNING] sentry.ingest.ingest_consumer: pre-process-forwarder detected a duplicated event with id:b3fba181b6604f418bcde1232defe0d0 for project:12.
ingest-consumer_1 | 19:37:04 [INFO] batching-kafka-consumer: Worker flush took 1582ms
ingest-consumer_1 | 19:37:04 [INFO] batching-kafka-consumer: Flushing 100 items (from {(u'ingest-events', 0): [79826350L, 79826449L]}): forced:False size:True time:False
ingest-consumer_1 | 19:37:06 [INFO] batching-kafka-consumer: Worker flush took 1468ms
ingest-consumer_1 | 19:37:06 [INFO] batching-kafka-consumer: Flushing 100 items (from {(u'ingest-events', 0): [79826450L, 79826549L]}): forced:False size:True time:False
ingest-consumer_1 | 19:37:06 [WARNING] sentry.ingest.ingest_consumer: pre-process-forwarder detected a duplicated event with id:337d1352f6d74f31a6e52328930fc463 for project:12.
ingest-consumer_1 | 19:37:07 [INFO] batching-kafka-consumer: Worker flush took 1455ms
ingest-consumer_1 | 19:37:08 [INFO] batching-kafka-consumer: Flushing 100 items (from {(u'ingest-events', 0): [79826550L, 79826649L]}): forced:False size:True time:False
ingest-consumer_1 | 19:37:10 [INFO] batching-kafka-consumer: Worker flush took 1696ms
ingest-consumer_1 | 19:37:11 [INFO] batching-kafka-consumer: Flushing 100 items (from {(u'ingest-events', 0): [79826650L, 79826749L]}): forced:False size:True time:False
ingest-consumer_1 | 19:37:11 [WARNING] sentry.ingest.ingest_consumer: pre-process-forwarder detected a duplicated event with id:d26bc43c82d14a9b95eafd88828d3509 for project:12.
ingest-consumer_1 | 19:37:13 [INFO] batching-kafka-consumer: Worker flush took 1930ms
ingest-consumer_1 | 19:37:13 [INFO] batching-kafka-consumer: Flushing 100 items (from {(u'ingest-events', 0): [79826750L, 79826849L]}): forced:False size:True time:False
ingest-consumer_1 | 19:37:15 [INFO] batching-kafka-consumer: Worker flush took 1506ms
ingest-consumer_1 | 19:37:15 [INFO] batching-kafka-consumer: Flushing 100 items (from {(u'ingest-events', 0): [79826850L, 79826949L]}): forced:False size:True time:False
ingest-consumer_1 | 19:37:17 [INFO] batching-kafka-consumer: Worker flush took 1735ms
ingest-consumer_1 | 19:37:17 [INFO] batching-kafka-consumer: Flushing 100 items (from {(u'ingest-events', 0): [79826950L, 79827049L]}): forced:False size:True time:False
ingest-consumer_1 | 19:37:18 [WARNING] sentry.ingest.ingest_consumer: pre-process-forwarder detected a duplicated event with id:b253ee14d3e94037807e2d795a810f5b for project:12.
ingest-consumer_1 | 19:37:18 [INFO] batching-kafka-consumer: Worker flush took 1509ms
ingest-consumer_1 | 19:37:19 [INFO] batching-kafka-consumer: Flushing 57 items (from {(u'ingest-events', 0): [79827050L, 79827106L]}): forced:False size:False time:True
ingest-consumer_1 | 19:37:20 [INFO] batching-kafka-consumer: Worker flush took 810ms
kafka_1 | [main] INFO org.apache.zookeeper.ZooKeeper - Client environment:user.home=/root
kafka_1 | [main] INFO org.apache.zookeeper.ZooKeeper - Client environment:user.dir=/
kafka_1 | [main] INFO org.apache.zookeeper.ZooKeeper - Client environment:os.memory.free=947MB
kafka_1 | [main] INFO org.apache.zookeeper.ZooKeeper - Client environment:os.memory.max=14274MB
kafka_1 | [main] INFO org.apache.zookeeper.ZooKeeper - Client environment:os.memory.total=962MB
kafka_1 | [main] INFO org.apache.zookeeper.ZooKeeper - Initiating client connection, connectString=zookeeper:2181 sessionTimeout=40000 watcher=io.confluent.admin.utils.ZookeeperConnectionWatcher@cc34f4d
kafka_1 | [main] INFO org.apache.zookeeper.common.X509Util - Setting -D jdk.tls.rejectClientInitiatedRenegotiation=true to disable client-initiated TLS renegotiation
kafka_1 | [main] INFO org.apache.zookeeper.ClientCnxnSocket - jute.maxbuffer value is 4194304 Bytes
kafka_1 | [main] INFO org.apache.zookeeper.ClientCnxn - zookeeper.request.timeout value is 0. feature enabled=
kafka_1 | [main-SendThread(zookeeper:2181)] INFO org.apache.zookeeper.ClientCnxn - Opening socket connection to server zookeeper/192.168.160.8:2181. Will not attempt to authenticate using SASL (unknown error)
kafka_1 | [main-SendThread(zookeeper:2181)] INFO org.apache.zookeeper.ClientCnxn - Socket connection established, initiating session, client: /192.168.160.10:38444, server: zookeeper/192.168.160.8:2181
kafka_1 | [main-SendThread(zookeeper:2181)] INFO org.apache.zookeeper.ClientCnxn - Session establishment complete on server zookeeper/192.168.160.8:2181, sessionid = 0x102bd2ae8b50000, negotiated timeout = 40000
kafka_1 | [main] INFO org.apache.zookeeper.ZooKeeper - Session: 0x102bd2ae8b50000 closed
kafka_1 | [main-EventThread] INFO org.apache.zookeeper.ClientCnxn - EventThread shut down for session: 0x102bd2ae8b50000
kafka_1 | ===> Launching ...
kafka_1 | ===> Launching kafka ...
kafka_1 | [2021-02-12 19:14:08,313] INFO Registered kafka:type=kafka.Log4jController MBean (kafka.utils.Log4jControllerRegistration$)
kafka_1 | [2021-02-12 19:14:09,058] WARN The package io.confluent.support.metrics.collectors.FullCollector for collecting the full set of support metrics could not be loaded, so we are reverting to anonymous, basic metric collection. If you are a Confluent customer, please refer to the Confluent Platform documentation, section Proactive Support, on how to activate full metrics collection. (io.confluent.support.metrics.KafkaSupportConfig)
kafka_1 | [2021-02-12 19:14:09,059] WARN The support metrics collection feature ("Metrics") of Proactive Support is disabled. (io.confluent.support.metrics.SupportedServerStartable)
kafka_1 | [2021-02-12 19:14:10,142] INFO Starting the log cleaner (kafka.log.LogCleaner)
kafka_1 | [2021-02-12 19:14:10,252] INFO [kafka-log-cleaner-thread-0]: Starting (kafka.log.LogCleaner)
kafka_1 | [2021-02-12 19:14:10,747] INFO Awaiting socket connections on 0.0.0.0:9092. (kafka.network.Acceptor)
kafka_1 | [2021-02-12 19:14:10,819] INFO [SocketServer brokerId=1001] Created data-plane acceptor and processors for endpoint : EndPoint(0.0.0.0,9092,ListenerName(PLAINTEXT),PLAINTEXT) (kafka.network.SocketServer)
kafka_1 | [2021-02-12 19:14:10,821] INFO [SocketServer brokerId=1001] Started 1 acceptor threads for data-plane (kafka.network.SocketServer)
kafka_1 | [2021-02-12 19:14:10,986] INFO Creating /brokers/ids/1001 (is it secure? false) (kafka.zk.KafkaZkClient)
kafka_1 | [2021-02-12 19:14:11,028] INFO Stat of the created znode at /brokers/ids/1001 is: 1340,1340,1613157251017,1613157251017,1,0,0,72828535981801473,180,0,1340
kafka_1 | (kafka.zk.KafkaZkClient)
kafka_1 | [2021-02-12 19:14:11,030] INFO Registered broker 1001 at path /brokers/ids/1001 with addresses: ArrayBuffer(EndPoint(kafka,9092,ListenerName(PLAINTEXT),PLAINTEXT)), czxid (broker epoch): 1340 (kafka.zk.KafkaZkClient)
kafka_1 | [2021-02-12 19:14:11,400] INFO [/config/changes-event-process-thread]: Starting (kafka.common.ZkNodeChangeNotificationListener$ChangeEventProcessThread)
kafka_1 | [2021-02-12 19:14:11,535] INFO [SocketServer brokerId=1001] Started data-plane processors for 1 acceptors (kafka.network.SocketServer)
nginx_1 | 192.168.160.1 - - [12/Feb/2021:19:29:16 +0000] "POST /api/12/envelope/ HTTP/1.1" 200 2 "-" "sentry.java.android/3.2.0" "-"
nginx_1 | 192.168.160.1 - - [12/Feb/2021:19:29:16 +0000] "POST /api/12/envelope/ HTTP/1.1" 200 2 "-" "sentry.java.android/3.2.0" "-"
nginx_1 | 192.168.160.1 - - [12/Feb/2021:19:29:16 +0000] "POST /api/12/envelope/ HTTP/1.1" 200 2 "-" "sentry.java.android/3.2.0" "-"
nginx_1 | 192.168.160.1 - - [12/Feb/2021:19:29:16 +0000] "POST /api/12/envelope/ HTTP/1.1" 200 2 "-" "sentry.java.android/3.2.0" "-"
nginx_1 | 192.168.160.1 - - [12/Feb/2021:19:29:17 +0000] "POST /api/12/envelope/ HTTP/1.1" 200 41 "-" "sentry.java.android/3.2.0" "-"
nginx_1 | 192.168.160.1 - - [12/Feb/2021:19:29:17 +0000] "POST /api/12/envelope/ HTTP/1.1" 200 41 "-" "sentry.java.android/3.2.0" "-"
nginx_1 | 192.168.160.1 - - [12/Feb/2021:19:29:17 +0000] "POST /api/12/envelope/ HTTP/1.1" 200 2 "-" "sentry.java.android/3.2.0" "-"
nginx_1 | 192.168.160.1 - - [12/Feb/2021:19:29:17 +0000] "POST /api/12/envelope/ HTTP/1.1" 200 2 "-" "sentry.java.android/3.2.0" "-"
nginx_1 | 192.168.160.1 - - [12/Feb/2021:19:29:17 +0000] "POST /api/12/envelope/ HTTP/1.1" 200 41 "-" "sentry.java.android/3.2.0" "-"
nginx_1 | 192.168.160.1 - - [12/Feb/2021:19:29:17 +0000] "POST /api/12/envelope/ HTTP/1.1" 200 41 "-" "sentry.java.android/3.2.0" "-"
nginx_1 | 192.168.160.1 - - [12/Feb/2021:19:29:17 +0000] "POST /api/12/envelope/ HTTP/1.1" 200 2 "-" "sentry.java.android/3.2.0" "-"
nginx_1 | 192.168.160.1 - - [12/Feb/2021:19:29:17 +0000] "POST /api/12/envelope/ HTTP/1.1" 200 41 "-" "sentry.java.android/3.2.0" "-"
nginx_1 | 192.168.160.1 - - [12/Feb/2021:19:29:17 +0000] "POST /api/12/envelope/ HTTP/1.1" 200 2 "-" "sentry.java.android/3.2.0" "-"
nginx_1 | 192.168.160.1 - - [12/Feb/2021:19:29:17 +0000] "POST /api/12/envelope/ HTTP/1.1" 200 2 "-" "sentry.java.android/3.2.0" "-"
nginx_1 | 192.168.160.1 - - [12/Feb/2021:19:29:17 +0000] "POST /api/12/envelope/ HTTP/1.1" 200 2 "-" "sentry.java.android/3.2.0" "-"
nginx_1 | 192.168.160.1 - - [12/Feb/2021:19:29:17 +0000] "POST /api/12/envelope/ HTTP/1.1" 200 41 "-" "sentry.java.android/3.2.0" "-"
nginx_1 | 192.168.160.1 - - [12/Feb/2021:19:29:17 +0000] "POST /api/12/envelope/ HTTP/1.1" 200 41 "-" "sentry.java.android/3.2.0" "-"
nginx_1 | 192.168.160.1 - - [12/Feb/2021:19:29:17 +0000] "POST /api/12/envelope/ HTTP/1.1" 200 2 "-" "sentry.java.android/3.2.0" "-"
nginx_1 | 192.168.160.1 - - [12/Feb/2021:19:29:17 +0000] "POST /api/12/envelope/ HTTP/1.1" 200 2 "-" "sentry.java.android/3.2.0" "-"
nginx_1 | 192.168.160.1 - - [12/Feb/2021:19:29:17 +0000] "POST /api/12/envelope/ HTTP/1.1" 200 41 "-" "sentry.java.android/3.2.0" "-"
nginx_1 | 192.168.160.1 - - [12/Feb/2021:19:29:17 +0000] "POST /api/12/envelope/ HTTP/1.1" 200 2 "-" "sentry.java.android/3.2.0" "-"
nginx_1 | 192.168.160.1 - - [12/Feb/2021:19:29:17 +0000] "POST /api/12/envelope/ HTTP/1.1" 200 2 "-" "sentry.java.android/3.2.0" "-"
nginx_1 | 192.168.160.1 - - [12/Feb/2021:19:29:17 +0000] "POST /api/12/envelope/ HTTP/1.1" 200 41 "-" "sentry.java.android/3.2.0" "-"
nginx_1 | 192.168.160.1 - - [12/Feb/2021:19:29:17 +0000] "POST /api/12/envelope/ HTTP/1.1" 200 2 "-" "sentry.java.android/3.2.0" "-"
nginx_1 | 192.168.160.1 - - [12/Feb/2021:19:29:17 +0000] "POST /api/12/envelope/ HTTP/1.1" 200 2 "-" "sentry.java.android/3.2.0" "-"
nginx_1 | 192.168.160.1 - - [12/Feb/2021:19:29:17 +0000] "POST /api/12/envelope/ HTTP/1.1" 200 41 "-" "sentry.java.android/3.2.0" "-"
nginx_1 | 192.168.160.1 - - [12/Feb/2021:19:29:17 +0000] "POST /api/12/envelope/ HTTP/1.1" 200 2 "-" "sentry.java.android/3.2.0" "-"
nginx_1 | 192.168.160.1 - - [12/Feb/2021:19:29:17 +0000] "POST /api/12/envelope/ HTTP/1.1" 200 2 "-" "sentry.java.android/3.2.0" "-"
nginx_1 | 192.168.160.1 - - [12/Feb/2021:19:29:17 +0000] "POST /api/12/envelope/ HTTP/1.1" 200 2 "-" "sentry.java.android/3.2.0" "-"
nginx_1 | 192.168.160.1 - - [12/Feb/2021:19:29:17 +0000] "POST /api/12/envelope/ HTTP/1.1" 200 41 "-" "sentry.java.android/3.2.0" "-"
redis_1 | 19:C 12 Feb 2021 19:34:38.650 * DB saved on disk
redis_1 | 19:C 12 Feb 2021 19:34:38.872 * RDB: 82 MB of memory used by copy-on-write
redis_1 | 1:M 12 Feb 2021 19:34:39.225 * Background saving terminated with success
redis_1 | 1:M 12 Feb 2021 19:35:40.024 * 10000 changes in 60 seconds. Saving...
redis_1 | 1:M 12 Feb 2021 19:35:40.321 * Background saving started by pid 20
redis_1 | 20:C 12 Feb 2021 19:38:40.404 * DB saved on disk
redis_1 | 20:C 12 Feb 2021 19:38:40.628 * RDB: 84 MB of memory used by copy-on-write
redis_1 | 1:M 12 Feb 2021 19:38:40.928 * Background saving terminated with success
redis_1 | 1:M 12 Feb 2021 19:39:41.045 * 10000 changes in 60 seconds. Saving...
redis_1 | 1:M 12 Feb 2021 19:39:41.314 * Background saving started by pid 21
redis_1 | 21:C 12 Feb 2021 19:42:29.104 * DB saved on disk
redis_1 | 21:C 12 Feb 2021 19:42:29.333 * RDB: 87 MB of memory used by copy-on-write
redis_1 | 1:M 12 Feb 2021 19:42:29.676 * Background saving terminated with success
redis_1 | 1:M 12 Feb 2021 19:43:30.076 * 10000 changes in 60 seconds. Saving...
redis_1 | 1:M 12 Feb 2021 19:43:30.324 * Background saving started by pid 22
redis_1 | 22:C 12 Feb 2021 19:46:27.997 * DB saved on disk
redis_1 | 22:C 12 Feb 2021 19:46:28.173 * RDB: 98 MB of memory used by copy-on-write
redis_1 | 1:M 12 Feb 2021 19:46:28.506 * Background saving terminated with success
redis_1 | 1:M 12 Feb 2021 19:47:29.085 * 10000 changes in 60 seconds. Saving...
redis_1 | 1:M 12 Feb 2021 19:47:29.345 * Background saving started by pid 23
redis_1 | 23:C 12 Feb 2021 19:50:24.542 * DB saved on disk
redis_1 | 23:C 12 Feb 2021 19:50:24.748 * RDB: 97 MB of memory used by copy-on-write
redis_1 | 1:M 12 Feb 2021 19:50:25.043 * Background saving terminated with success
redis_1 | 1:M 12 Feb 2021 19:51:26.047 * 10000 changes in 60 seconds. Saving...
redis_1 | 1:M 12 Feb 2021 19:51:26.297 * Background saving started by pid 24
redis_1 | 24:C 12 Feb 2021 19:54:18.938 * DB saved on disk
redis_1 | 24:C 12 Feb 2021 19:54:19.176 * RDB: 106 MB of memory used by copy-on-write
redis_1 | 1:M 12 Feb 2021 19:54:19.579 * Background saving terminated with success
redis_1 | 1:M 12 Feb 2021 19:55:20.060 * 10000 changes in 60 seconds. Saving...
redis_1 | 1:M 12 Feb 2021 19:55:20.337 * Background saving started by pid 25
post-process-forwarder_1 | return ctx.invoke(self.callback, **ctx.params)
post-process-forwarder_1 | File "/usr/local/lib/python2.7/site-packages/click/core.py", line 610, in invoke
post-process-forwarder_1 | return callback(*args, **kwargs)
post-process-forwarder_1 | File "/usr/local/lib/python2.7/site-packages/click/decorators.py", line 21, in new_func
post-process-forwarder_1 | return f(get_current_context(), *args, **kwargs)
post-process-forwarder_1 | File "/usr/local/lib/python2.7/site-packages/sentry/runner/decorators.py", line 68, in inner
post-process-forwarder_1 | return ctx.invoke(f, *args, **kwargs)
post-process-forwarder_1 | File "/usr/local/lib/python2.7/site-packages/click/core.py", line 610, in invoke
post-process-forwarder_1 | return callback(*args, **kwargs)
post-process-forwarder_1 | File "/usr/local/lib/python2.7/site-packages/click/decorators.py", line 21, in new_func
post-process-forwarder_1 | return f(get_current_context(), *args, **kwargs)
post-process-forwarder_1 | File "/usr/local/lib/python2.7/site-packages/sentry/runner/decorators.py", line 29, in inner
post-process-forwarder_1 | configure()
post-process-forwarder_1 | File "/usr/local/lib/python2.7/site-packages/sentry/runner/__init__.py", line 129, in configure
post-process-forwarder_1 | configure(ctx, py, yaml, skip_service_validation)
post-process-forwarder_1 | File "/usr/local/lib/python2.7/site-packages/sentry/runner/settings.py", line 158, in configure
post-process-forwarder_1 | skip_service_validation=skip_service_validation,
post-process-forwarder_1 | File "/usr/local/lib/python2.7/site-packages/sentry/runner/initializer.py", line 346, in initialize_app
post-process-forwarder_1 | setup_services(validate=not skip_service_validation)
post-process-forwarder_1 | File "/usr/local/lib/python2.7/site-packages/sentry/runner/initializer.py", line 388, in setup_services
post-process-forwarder_1 | service.validate()
post-process-forwarder_1 | File "/usr/local/lib/python2.7/site-packages/sentry/utils/services.py", line 105, in <lambda>
post-process-forwarder_1 | context[key] = (lambda f: lambda *a, **k: getattr(self, f)(*a, **k))(key)
post-process-forwarder_1 | File "/usr/local/lib/python2.7/site-packages/sentry/buffer/redis.py", line 69, in validate
post-process-forwarder_1 | raise InvalidConfiguration(six.text_type(e))
post-process-forwarder_1 | sentry.exceptions.InvalidConfiguration: Redis is loading the dataset in memory
post-process-forwarder_1 | 19:14:20 [WARNING] sentry.utils.geo: settings.GEOIP_PATH_MMDB not configured.
post-process-forwarder_1 | /usr/local/lib/python2.7/site-packages/OpenSSL/crypto.py:12: CryptographyDeprecationWarning: Python 2 is no longer supported by the Python core team. Support for it is now deprecated in cryptography, and will be removed in a future release.
post-process-forwarder_1 | from cryptography import x509
post-process-forwarder_1 | 19:14:25 [INFO] sentry.plugins.github: apps-not-configured
postgres_1 | ERROR: duplicate key value violates unique constraint "sentry_eventuser_project_id_hash_377a63c0_uniq"
postgres_1 | DETAIL: Key (project_id, hash)=(12, a78145615c8ff9728e20375691ed6bf3) already exists.
postgres_1 | STATEMENT: INSERT INTO "sentry_eventuser" ("project_id", "hash", "ident", "email", "username", "name", "ip_address", "date_added") VALUES (12, 'a78145615c8ff9728e20375691ed6bf3', '4243c47f4bb15c1a', NULL, NULL, NULL, NULL, '2021-02-12T19:56:56.477085+00:00'::timestamptz) RETURNING "sentry_eventuser"."id"
postgres_1 | ERROR: duplicate key value violates unique constraint "sentry_eventuser_project_id_hash_377a63c0_uniq"
postgres_1 | DETAIL: Key (project_id, hash)=(12, 71f885f31e82e30210a838f34259fc6e) already exists.
postgres_1 | STATEMENT: INSERT INTO "sentry_eventuser" ("project_id", "hash", "ident", "email", "username", "name", "ip_address", "date_added") VALUES (12, '71f885f31e82e30210a838f34259fc6e', 'e81c75efba622bf9', NULL, NULL, NULL, NULL, '2021-02-12T19:56:56.743816+00:00'::timestamptz) RETURNING "sentry_eventuser"."id"
postgres_1 | ERROR: duplicate key value violates unique constraint "sentry_eventuser_project_id_hash_377a63c0_uniq"
postgres_1 | DETAIL: Key (project_id, hash)=(12, 8640bb707c468ee2f88d76ff5a59214d) already exists.
postgres_1 | STATEMENT: INSERT INTO "sentry_eventuser" ("project_id", "hash", "ident", "email", "username", "name", "ip_address", "date_added") VALUES (12, '8640bb707c468ee2f88d76ff5a59214d', '25f5f3fd54063d7e', NULL, NULL, NULL, NULL, '2021-02-12T19:56:56.953067+00:00'::timestamptz) RETURNING "sentry_eventuser"."id"
postgres_1 | ERROR: duplicate key value violates unique constraint "sentry_eventuser_project_id_hash_377a63c0_uniq"
postgres_1 | DETAIL: Key (project_id, hash)=(12, 7baaa30dee6e99c7401006df79a76c77) already exists.
postgres_1 | STATEMENT: INSERT INTO "sentry_eventuser" ("project_id", "hash", "ident", "email", "username", "name", "ip_address", "date_added") VALUES (12, '7baaa30dee6e99c7401006df79a76c77', '2c83567f63c97d3b', NULL, NULL, NULL, NULL, '2021-02-12T19:56:56.994660+00:00'::timestamptz) RETURNING "sentry_eventuser"."id"
postgres_1 | ERROR: duplicate key value violates unique constraint "sentry_eventuser_project_id_hash_377a63c0_uniq"
postgres_1 | DETAIL: Key (project_id, hash)=(12, a8efd51f1965aa195611afbbb0aa7b61) already exists.
postgres_1 | STATEMENT: INSERT INTO "sentry_eventuser" ("project_id", "hash", "ident", "email", "username", "name", "ip_address", "date_added") VALUES (12, 'a8efd51f1965aa195611afbbb0aa7b61', 'ce71c55e8dc2bde7', NULL, NULL, NULL, NULL, '2021-02-12T19:56:57.002745+00:00'::timestamptz) RETURNING "sentry_eventuser"."id"
postgres_1 | ERROR: duplicate key value violates unique constraint "sentry_eventuser_project_id_hash_377a63c0_uniq"
postgres_1 | DETAIL: Key (project_id, hash)=(12, cc528626dc0c3f6556c3be16d80f88cb) already exists.
postgres_1 | STATEMENT: INSERT INTO "sentry_eventuser" ("project_id", "hash", "ident", "email", "username", "name", "ip_address", "date_added") VALUES (12, 'cc528626dc0c3f6556c3be16d80f88cb', 'bdb1de7743bfe82f', NULL, NULL, NULL, NULL, '2021-02-12T19:56:57.226516+00:00'::timestamptz) RETURNING "sentry_eventuser"."id"
postgres_1 | ERROR: duplicate key value violates unique constraint "sentry_eventuser_project_id_hash_377a63c0_uniq"
postgres_1 | DETAIL: Key (project_id, hash)=(12, b984a860f283e15d8a4ecec371ab62d3) already exists.
postgres_1 | STATEMENT: INSERT INTO "sentry_eventuser" ("project_id", "hash", "ident", "email", "username", "name", "ip_address", "date_added") VALUES (12, 'b984a860f283e15d8a4ecec371ab62d3', '6a549302fa49d3c9', NULL, NULL, NULL, NULL, '2021-02-12T19:56:57.886066+00:00'::timestamptz) RETURNING "sentry_eventuser"."id"
postgres_1 | ERROR: duplicate key value violates unique constraint "sentry_eventuser_project_id_hash_377a63c0_uniq"
postgres_1 | DETAIL: Key (project_id, hash)=(12, 8b64ecd0f0e3aa5487d52c9a6a238d63) already exists.
postgres_1 | STATEMENT: INSERT INTO "sentry_eventuser" ("project_id", "hash", "ident", "email", "username", "name", "ip_address", "date_added") VALUES (12, '8b64ecd0f0e3aa5487d52c9a6a238d63', '9a7e6df56ea05ae6', NULL, NULL, NULL, NULL, '2021-02-12T19:56:58.042870+00:00'::timestamptz) RETURNING "sentry_eventuser"."id"
postgres_1 | ERROR: duplicate key value violates unique constraint "sentry_eventuser_project_id_hash_377a63c0_uniq"
postgres_1 | DETAIL: Key (project_id, hash)=(12, 291318c073b4f0327156f0ab1e0bcdcc) already exists.
postgres_1 | STATEMENT: INSERT INTO "sentry_eventuser" ("project_id", "hash", "ident", "email", "username", "name", "ip_address", "date_added") VALUES (12, '291318c073b4f0327156f0ab1e0bcdcc', '4d1ab49342d1cbfc', NULL, NULL, NULL, NULL, '2021-02-12T19:56:58.109684+00:00'::timestamptz) RETURNING "sentry_eventuser"."id"
postgres_1 | ERROR: duplicate key value violates unique constraint "sentry_eventuser_project_id_hash_377a63c0_uniq"
postgres_1 | DETAIL: Key (project_id, hash)=(12, f346d3063916872f659425c1ed48c3bf) already exists.
postgres_1 | STATEMENT: INSERT INTO "sentry_eventuser" ("project_id", "hash", "ident", "email", "username", "name", "ip_address", "date_added") VALUES (12, 'f346d3063916872f659425c1ed48c3bf', '6afb64d837343aa6', NULL, NULL, NULL, NULL, '2021-02-12T19:56:58.192577+00:00'::timestamptz) RETURNING "sentry_eventuser"."id"
sentry-cleanup_1 | SHELL=/bin/bash
sentry-cleanup_1 | BASH_ENV=/container.env
sentry-cleanup_1 | 0 0 * * * gosu sentry sentry cleanup --days 90 > /proc/1/fd/1 2>/proc/1/fd/2
relay_1 | 2021-02-12T19:14:39Z [relay_server::endpoints::common] ERROR: error handling request: failed to queue envelope
relay_1 | caused by: Too many events (event_buffer_size reached)
relay_1 | 2021-02-12T19:14:39Z [relay_server::endpoints::common] ERROR: error handling request: failed to queue envelope
relay_1 | caused by: Too many events (event_buffer_size reached)
relay_1 | 2021-02-12T19:14:39Z [relay_server::endpoints::common] ERROR: error handling request: failed to queue envelope
relay_1 | caused by: Too many events (event_buffer_size reached)
relay_1 | 2021-02-12T19:14:39Z [relay_server::endpoints::common] ERROR: error handling request: failed to queue envelope
relay_1 | caused by: Too many events (event_buffer_size reached)
relay_1 | 2021-02-12T19:14:39Z [relay_server::endpoints::common] ERROR: error handling request: failed to queue envelope
relay_1 | caused by: Too many events (event_buffer_size reached)
relay_1 | 2021-02-12T19:14:39Z [relay_server::endpoints::common] ERROR: error handling request: failed to queue envelope
relay_1 | caused by: Too many events (event_buffer_size reached)
relay_1 | 2021-02-12T19:14:39Z [relay_server::endpoints::common] ERROR: error handling request: failed to queue envelope
relay_1 | caused by: Too many events (event_buffer_size reached)
relay_1 | 2021-02-12T19:14:39Z [relay_server::endpoints::common] ERROR: error handling request: failed to queue envelope
relay_1 | caused by: Too many events (event_buffer_size reached)
relay_1 | 2021-02-12T19:14:39Z [relay_server::endpoints::common] ERROR: error handling request: failed to queue envelope
relay_1 | caused by: Too many events (event_buffer_size reached)
relay_1 | 2021-02-12T19:14:39Z [relay_server::endpoints::common] ERROR: error handling request: failed to queue envelope
relay_1 | caused by: Too many events (event_buffer_size reached)
relay_1 | 2021-02-12T19:14:39Z [relay_server::endpoints::common] ERROR: error handling request: failed to queue envelope
relay_1 | caused by: Too many events (event_buffer_size reached)
relay_1 | 2021-02-12T19:14:39Z [relay_server::endpoints::common] ERROR: error handling request: failed to queue envelope
relay_1 | caused by: Too many events (event_buffer_size reached)
relay_1 | 2021-02-12T19:14:39Z [relay_server::endpoints::common] ERROR: error handling request: failed to queue envelope
relay_1 | caused by: Too many events (event_buffer_size reached)
relay_1 | 2021-02-12T19:14:39Z [relay_server::endpoints::common] ERROR: error handling request: failed to queue envelope
relay_1 | caused by: Too many events (event_buffer_size reached)
relay_1 | 2021-02-12T19:14:39Z [relay_server::endpoints::common] ERROR: error handling request: failed to queue envelope
relay_1 | caused by: Too many events (event_buffer_size reached)
smtp_1 | + sed -ri '
smtp_1 | s/^#?(dc_local_interfaces)=.*/\1='\''0.0.0.0 ; ::0'\''/;
smtp_1 | s/^#?(dc_other_hostnames)=.*/\1='\'''\''/;
smtp_1 | s/^#?(dc_relay_nets)=.*/\1='\''0.0.0.0\/0'\''/;
smtp_1 | s/^#?(dc_eximconfig_configtype)=.*/\1='\''internet'\''/;
smtp_1 | ' /etc/exim4/update-exim4.conf.conf
smtp_1 | + update-exim4.conf -v
smtp_1 | using non-split configuration scheme from /etc/exim4/exim4.conf.template
smtp_1 | 269 LOG: MAIN
smtp_1 | 269 exim 4.92 daemon started: pid=269, no queue runs, listening for SMTP on port 25 (IPv6 and IPv4)
snuba-outcomes-consumer_1 | 2021-02-12 19:56:29,573 Completed processing <Batch: 23 messages, open for 0.89 seconds>.
snuba-outcomes-consumer_1 | 2021-02-12 19:56:30,466 Completed processing <Batch: 32 messages, open for 0.89 seconds>.
snuba-outcomes-consumer_1 | 2021-02-12 19:56:31,246 Completed processing <Batch: 17 messages, open for 0.78 seconds>.
snuba-outcomes-consumer_1 | 2021-02-12 19:56:33,018 Completed processing <Batch: 21 messages, open for 1.77 seconds>.
snuba-outcomes-consumer_1 | 2021-02-12 19:56:34,579 Completed processing <Batch: 9 messages, open for 1.56 seconds>.
snuba-outcomes-consumer_1 | 2021-02-12 19:56:36,095 Completed processing <Batch: 23 messages, open for 1.51 seconds>.
snuba-outcomes-consumer_1 | 2021-02-12 19:56:37,381 Completed processing <Batch: 13 messages, open for 1.28 seconds>.
snuba-outcomes-consumer_1 | 2021-02-12 19:56:38,391 Completed processing <Batch: 28 messages, open for 1.01 seconds>.
snuba-outcomes-consumer_1 | 2021-02-12 19:56:39,176 Completed processing <Batch: 16 messages, open for 0.78 seconds>.
snuba-outcomes-consumer_1 | 2021-02-12 19:56:39,986 Completed processing <Batch: 21 messages, open for 0.81 seconds>.
snuba-outcomes-consumer_1 | 2021-02-12 19:56:40,781 Completed processing <Batch: 24 messages, open for 0.79 seconds>.
snuba-outcomes-consumer_1 | 2021-02-12 19:56:41,546 Completed processing <Batch: 22 messages, open for 0.77 seconds>.
snuba-outcomes-consumer_1 | 2021-02-12 19:56:42,349 Completed processing <Batch: 27 messages, open for 0.80 seconds>.
snuba-outcomes-consumer_1 | 2021-02-12 19:56:43,120 Completed processing <Batch: 27 messages, open for 0.77 seconds>.
snuba-outcomes-consumer_1 | 2021-02-12 19:56:43,885 Completed processing <Batch: 26 messages, open for 0.76 seconds>.
snuba-outcomes-consumer_1 | 2021-02-12 19:56:44,713 Completed processing <Batch: 20 messages, open for 0.83 seconds>.
snuba-outcomes-consumer_1 | 2021-02-12 19:56:45,517 Completed processing <Batch: 27 messages, open for 0.80 seconds>.
snuba-outcomes-consumer_1 | 2021-02-12 19:56:46,895 Completed processing <Batch: 14 messages, open for 1.38 seconds>.
snuba-outcomes-consumer_1 | 2021-02-12 19:56:47,750 Completed processing <Batch: 32 messages, open for 0.85 seconds>.
snuba-outcomes-consumer_1 | 2021-02-12 19:56:49,154 Completed processing <Batch: 20 messages, open for 1.40 seconds>.
snuba-outcomes-consumer_1 | 2021-02-12 19:56:50,141 Completed processing <Batch: 26 messages, open for 0.99 seconds>.
snuba-outcomes-consumer_1 | 2021-02-12 19:56:51,053 Completed processing <Batch: 9 messages, open for 0.91 seconds>.
snuba-outcomes-consumer_1 | 2021-02-12 19:56:52,000 Completed processing <Batch: 13 messages, open for 0.95 seconds>.
snuba-outcomes-consumer_1 | 2021-02-12 19:56:52,846 Completed processing <Batch: 20 messages, open for 0.85 seconds>.
snuba-outcomes-consumer_1 | 2021-02-12 19:56:53,884 Completed processing <Batch: 18 messages, open for 1.04 seconds>.
snuba-outcomes-consumer_1 | 2021-02-12 19:56:54,693 Completed processing <Batch: 18 messages, open for 0.81 seconds>.
snuba-outcomes-consumer_1 | 2021-02-12 19:56:55,489 Completed processing <Batch: 20 messages, open for 0.80 seconds>.
snuba-outcomes-consumer_1 | 2021-02-12 19:56:56,271 Completed processing <Batch: 23 messages, open for 0.78 seconds>.
snuba-outcomes-consumer_1 | 2021-02-12 19:56:57,038 Completed processing <Batch: 26 messages, open for 0.77 seconds>.
snuba-outcomes-consumer_1 | 2021-02-12 19:56:58,318 Completed processing <Batch: 26 messages, open for 1.28 seconds>.
snuba-consumer_1 | 2021-02-12 19:56:24,765 Completed processing <Batch: 24 messages, open for 0.82 seconds>.
snuba-consumer_1 | 2021-02-12 19:56:25,612 Completed processing <Batch: 28 messages, open for 0.85 seconds>.
snuba-consumer_1 | 2021-02-12 19:56:26,435 Completed processing <Batch: 26 messages, open for 0.82 seconds>.
snuba-consumer_1 | 2021-02-12 19:56:27,248 Completed processing <Batch: 30 messages, open for 0.81 seconds>.
snuba-consumer_1 | 2021-02-12 19:56:28,042 Completed processing <Batch: 25 messages, open for 0.79 seconds>.
snuba-consumer_1 | 2021-02-12 19:56:28,901 Completed processing <Batch: 23 messages, open for 0.86 seconds>.
snuba-consumer_1 | 2021-02-12 19:56:29,877 Completed processing <Batch: 20 messages, open for 0.97 seconds>.
snuba-consumer_1 | 2021-02-12 19:56:33,018 Completed processing <Batch: 21 messages, open for 3.14 seconds>.
snuba-consumer_1 | 2021-02-12 19:56:35,023 Completed processing <Batch: 43 messages, open for 2.00 seconds>.
snuba-consumer_1 | 2021-02-12 19:56:37,711 Completed processing <Batch: 26 messages, open for 2.69 seconds>.
snuba-consumer_1 | 2021-02-12 19:56:38,681 Completed processing <Batch: 46 messages, open for 0.97 seconds>.
snuba-consumer_1 | 2021-02-12 19:56:39,546 Completed processing <Batch: 19 messages, open for 0.86 seconds>.
snuba-consumer_1 | 2021-02-12 19:56:40,341 Completed processing <Batch: 21 messages, open for 0.79 seconds>.
snuba-consumer_1 | 2021-02-12 19:56:41,143 Completed processing <Batch: 21 messages, open for 0.80 seconds>.
snuba-consumer_1 | 2021-02-12 19:56:41,973 Completed processing <Batch: 28 messages, open for 0.83 seconds>.
snuba-consumer_1 | 2021-02-12 19:56:42,802 Completed processing <Batch: 29 messages, open for 0.83 seconds>.
snuba-consumer_1 | 2021-02-12 19:56:43,597 Completed processing <Batch: 27 messages, open for 0.79 seconds>.
snuba-cleanup_1 | SHELL=/bin/bash
snuba-cleanup_1 | BASH_ENV=/container.env
snuba-cleanup_1 | */5 * * * * gosu snuba snuba cleanup --dry-run False > /proc/1/fd/1 2>/proc/1/fd/2
snuba-cleanup_1 | 2021-02-12 19:15:03,279 Dropped 0 partitions on None
snuba-cleanup_1 | 2021-02-12 19:20:03,634 Dropped 0 partitions on None
snuba-cleanup_1 | 2021-02-12 19:25:03,770 Dropped 0 partitions on None
snuba-cleanup_1 | 2021-02-12 19:30:03,491 Dropped 0 partitions on None
snuba-cleanup_1 | 2021-02-12 19:35:03,388 Dropped 0 partitions on None
snuba-cleanup_1 | 2021-02-12 19:40:05,326 Dropped 0 partitions on None
snuba-cleanup_1 | 2021-02-12 19:45:03,474 Dropped 0 partitions on None
snuba-cleanup_1 | 2021-02-12 19:50:03,822 Dropped 0 partitions on None
snuba-cleanup_1 | 2021-02-12 19:55:03,686 Dropped 0 partitions on None
snuba-consumer_1 | 2021-02-12 19:56:44,733 Completed processing <Batch: 28 messages, open for 1.13 seconds>.
snuba-consumer_1 | 2021-02-12 19:56:45,546 Completed processing <Batch: 29 messages, open for 0.81 seconds>.
snuba-consumer_1 | 2021-02-12 19:56:46,948 Completed processing <Batch: 14 messages, open for 1.40 seconds>.
snuba-consumer_1 | 2021-02-12 19:56:47,860 Completed processing <Batch: 32 messages, open for 0.91 seconds>.
snuba-consumer_1 | 2021-02-12 19:56:49,820 Completed processing <Batch: 24 messages, open for 1.96 seconds>.
snuba-consumer_1 | 2021-02-12 19:56:51,527 Completed processing <Batch: 26 messages, open for 1.71 seconds>.
snuba-consumer_1 | 2021-02-12 19:56:53,171 Completed processing <Batch: 27 messages, open for 1.64 seconds>.
snuba-consumer_1 | 2021-02-12 19:56:54,076 Completed processing <Batch: 33 messages, open for 0.90 seconds>.
snuba-consumer_1 | 2021-02-12 19:56:54,918 Completed processing <Batch: 19 messages, open for 0.84 seconds>.
snuba-consumer_1 | 2021-02-12 19:56:55,720 Completed processing <Batch: 22 messages, open for 0.80 seconds>.
snuba-consumer_1 | 2021-02-12 19:56:56,520 Completed processing <Batch: 25 messages, open for 0.80 seconds>.
snuba-consumer_1 | 2021-02-12 19:56:57,329 Completed processing <Batch: 27 messages, open for 0.81 seconds>.
snuba-consumer_1 | 2021-02-12 19:56:58,159 Completed processing <Batch: 28 messages, open for 0.83 seconds>.
snuba-sessions-consumer_1 | 2021-02-12 19:28:42,988 Completed processing <Batch: 102 messages, open for 0.78 seconds>.
snuba-sessions-consumer_1 | 2021-02-12 19:28:43,767 Completed processing <Batch: 105 messages, open for 0.78 seconds>.
snuba-sessions-consumer_1 | 2021-02-12 19:28:44,542 Completed processing <Batch: 101 messages, open for 0.77 seconds>.
snuba-sessions-consumer_1 | 2021-02-12 19:28:45,315 Completed processing <Batch: 102 messages, open for 0.77 seconds>.
snuba-sessions-consumer_1 | 2021-02-12 19:28:46,698 Completed processing <Batch: 60 messages, open for 1.38 seconds>.
snuba-sessions-consumer_1 | 2021-02-12 19:28:47,607 Completed processing <Batch: 180 messages, open for 0.91 seconds>.
snuba-sessions-consumer_1 | 2021-02-12 19:28:49,699 Completed processing <Batch: 36 messages, open for 2.09 seconds>.
snuba-sessions-consumer_1 | 2021-02-12 19:28:51,883 Completed processing <Batch: 256 messages, open for 2.18 seconds>.
snuba-sessions-consumer_1 | 2021-02-12 19:28:53,394 Completed processing <Batch: 346 messages, open for 1.51 seconds>.
snuba-sessions-consumer_1 | 2021-02-12 19:28:54,733 Completed processing <Batch: 403 messages, open for 1.34 seconds>.
snuba-sessions-consumer_1 | 2021-02-12 19:28:55,821 Completed processing <Batch: 210 messages, open for 1.09 seconds>.
snuba-sessions-consumer_1 | 2021-02-12 19:28:57,807 Completed processing <Batch: 177 messages, open for 1.99 seconds>.
snuba-sessions-consumer_1 | 2021-02-12 19:28:58,644 Completed processing <Batch: 276 messages, open for 0.84 seconds>.
snuba-sessions-consumer_1 | 2021-02-12 19:28:59,422 Completed processing <Batch: 262 messages, open for 0.78 seconds>.
snuba-sessions-consumer_1 | 2021-02-12 19:29:00,198 Completed processing <Batch: 109 messages, open for 0.78 seconds>.
snuba-sessions-consumer_1 | 2021-02-12 19:29:00,981 Completed processing <Batch: 138 messages, open for 0.78 seconds>.
snuba-sessions-consumer_1 | 2021-02-12 19:29:01,757 Completed processing <Batch: 145 messages, open for 0.78 seconds>.
snuba-sessions-consumer_1 | 2021-02-12 19:29:02,526 Completed processing <Batch: 128 messages, open for 0.77 seconds>.
snuba-sessions-consumer_1 | 2021-02-12 19:29:03,301 Completed processing <Batch: 113 messages, open for 0.77 seconds>.
snuba-sessions-consumer_1 | 2021-02-12 19:29:04,073 Completed processing <Batch: 51 messages, open for 0.77 seconds>.
snuba-sessions-consumer_1 | 2021-02-12 19:29:04,871 Completed processing <Batch: 106 messages, open for 0.80 seconds>.
snuba-sessions-consumer_1 | 2021-02-12 19:29:06,028 Completed processing <Batch: 109 messages, open for 1.16 seconds>.
snuba-sessions-consumer_1 | 2021-02-12 19:29:08,681 Completed processing <Batch: 171 messages, open for 2.65 seconds>.
snuba-sessions-consumer_1 | 2021-02-12 19:29:10,407 Completed processing <Batch: 336 messages, open for 1.72 seconds>.
snuba-sessions-consumer_1 | 2021-02-12 19:29:11,806 Completed processing <Batch: 236 messages, open for 1.40 seconds>.
snuba-sessions-consumer_1 | 2021-02-12 19:29:12,958 Completed processing <Batch: 124 messages, open for 1.15 seconds>.
snuba-sessions-consumer_1 | 2021-02-12 19:29:14,071 Completed processing <Batch: 226 messages, open for 1.11 seconds>.
snuba-sessions-consumer_1 | 2021-02-12 19:29:15,377 Completed processing <Batch: 91 messages, open for 1.30 seconds>.
snuba-sessions-consumer_1 | 2021-02-12 19:29:16,651 Completed processing <Batch: 356 messages, open for 1.27 seconds>.
snuba-sessions-consumer_1 | 2021-02-12 19:29:18,315 Completed processing <Batch: 192 messages, open for 1.66 seconds>.
symbolicator-cleanup_1 | SHELL=/bin/bash
symbolicator-cleanup_1 | BASH_ENV=/container.env
symbolicator-cleanup_1 | 55 23 * * * gosu symbolicator symbolicator cleanup > /proc/1/fd/1 2>/proc/1/fd/2
snuba-replacer_1 | %3|1613157246.566|FAIL|rdkafka#consumer-1| [thrd:kafka:9092/bootstrap]: kafka:9092/bootstrap: Connect to ipv4#192.168.160.10:9092 failed: Connection refused (after 0ms in state CONNECT, 1 identical error(s) suppressed)
snuba-replacer_1 | 2021-02-12 19:14:12,619 Caught ConsumerError('KafkaError{code=COORDINATOR_LOAD_IN_PROGRESS,val=14,str="JoinGroup failed: Broker: Coordinator load in progress"}'), shutting down...
snuba-replacer_1 | Traceback (most recent call last):
snuba-replacer_1 | File "/usr/local/bin/snuba", line 33, in <module>
snuba-replacer_1 | sys.exit(load_entry_point('snuba', 'console_scripts', 'snuba')())
snuba-replacer_1 | File "/usr/local/lib/python3.8/site-packages/click/core.py", line 722, in __call__
snuba-replacer_1 | return self.main(*args, **kwargs)
snuba-replacer_1 | File "/usr/local/lib/python3.8/site-packages/click/core.py", line 697, in main
snuba-replacer_1 | rv = self.invoke(ctx)
snuba-replacer_1 | File "/usr/local/lib/python3.8/site-packages/click/core.py", line 1066, in invoke
snuba-replacer_1 | return _process_result(sub_ctx.command.invoke(sub_ctx))
snuba-replacer_1 | File "/usr/local/lib/python3.8/site-packages/click/core.py", line 895, in invoke
snuba-replacer_1 | return ctx.invoke(self.callback, **ctx.params)
snuba-replacer_1 | File "/usr/local/lib/python3.8/site-packages/click/core.py", line 535, in invoke
snuba-replacer_1 | return callback(*args, **kwargs)
snuba-replacer_1 | File "/usr/src/snuba/snuba/cli/replacer.py", line 133, in replacer
snuba-replacer_1 | replacer.run()
snuba-replacer_1 | File "/usr/src/snuba/snuba/utils/streams/processing/processor.py", line 109, in run
snuba-replacer_1 | self._run_once()
snuba-replacer_1 | File "/usr/src/snuba/snuba/utils/streams/processing/processor.py", line 139, in _run_once
snuba-replacer_1 | self.__message = self.__consumer.poll(timeout=1.0)
snuba-replacer_1 | File "/usr/src/snuba/snuba/utils/streams/backends/kafka.py", line 402, in poll
snuba-replacer_1 | raise ConsumerError(str(error))
snuba-replacer_1 | snuba.utils.streams.backends.abstract.ConsumerError: KafkaError{code=COORDINATOR_LOAD_IN_PROGRESS,val=14,str="JoinGroup failed: Broker: Coordinator load in progress"}
snuba-replacer_1 | + '[' r = - ']'
snuba-replacer_1 | + snuba replacer --help
snuba-replacer_1 | + set -- snuba replacer --storage events --auto-offset-reset=latest --max-batch-size 3
snuba-transactions-consumer_1 | 2021-02-12 19:56:33,005 Completed processing <Batch: 2 messages, open for 1.01 seconds>.
snuba-transactions-consumer_1 | 2021-02-12 19:56:33,854 Completed processing <Batch: 8 messages, open for 0.85 seconds>.
snuba-transactions-consumer_1 | 2021-02-12 19:56:34,756 Completed processing <Batch: 13 messages, open for 0.90 seconds>.
snuba-transactions-consumer_1 | 2021-02-12 19:56:36,086 Completed processing <Batch: 13 messages, open for 1.33 seconds>.
snuba-transactions-consumer_1 | 2021-02-12 19:56:36,912 Completed processing <Batch: 9 messages, open for 0.82 seconds>.
snuba-transactions-consumer_1 | 2021-02-12 19:56:37,712 Completed processing <Batch: 20 messages, open for 0.80 seconds>.
snuba-transactions-consumer_1 | 2021-02-12 19:56:38,515 Completed processing <Batch: 17 messages, open for 0.80 seconds>.
snuba-transactions-consumer_1 | 2021-02-12 19:56:39,325 Completed processing <Batch: 17 messages, open for 0.81 seconds>.
snuba-transactions-consumer_1 | 2021-02-12 19:56:40,095 Completed processing <Batch: 15 messages, open for 0.77 seconds>.
snuba-transactions-consumer_1 | 2021-02-12 19:56:40,853 Completed processing <Batch: 23 messages, open for 0.76 seconds>.
snuba-transactions-consumer_1 | 2021-02-12 19:56:41,606 Completed processing <Batch: 24 messages, open for 0.75 seconds>.
snuba-transactions-consumer_1 | 2021-02-12 19:56:42,366 Completed processing <Batch: 25 messages, open for 0.76 seconds>.
snuba-transactions-consumer_1 | 2021-02-12 19:56:43,145 Completed processing <Batch: 26 messages, open for 0.78 seconds>.
snuba-transactions-consumer_1 | 2021-02-12 19:56:43,920 Completed processing <Batch: 27 messages, open for 0.77 seconds>.
snuba-transactions-consumer_1 | 2021-02-12 19:56:44,701 Completed processing <Batch: 18 messages, open for 0.78 seconds>.
snuba-transactions-consumer_1 | 2021-02-12 19:56:45,497 Completed processing <Batch: 27 messages, open for 0.79 seconds>.
snuba-transactions-consumer_1 | 2021-02-12 19:56:46,881 Completed processing <Batch: 14 messages, open for 1.38 seconds>.
snuba-transactions-consumer_1 | 2021-02-12 19:56:47,726 Completed processing <Batch: 32 messages, open for 0.84 seconds>.
snuba-transactions-consumer_1 | 2021-02-12 19:56:48,580 Completed processing <Batch: 17 messages, open for 0.85 seconds>.
snuba-transactions-consumer_1 | 2021-02-12 19:56:49,809 Completed processing <Batch: 22 messages, open for 1.23 seconds>.
snuba-transactions-consumer_1 | 2021-02-12 19:56:50,672 Completed processing <Batch: 11 messages, open for 0.86 seconds>.
snuba-transactions-consumer_1 | 2021-02-12 19:56:51,522 Completed processing <Batch: 15 messages, open for 0.85 seconds>.
snuba-transactions-consumer_1 | 2021-02-12 19:56:52,397 Completed processing <Batch: 12 messages, open for 0.87 seconds>.
snuba-transactions-consumer_1 | 2021-02-12 19:56:53,165 Completed processing <Batch: 16 messages, open for 0.77 seconds>.
snuba-transactions-consumer_1 | 2021-02-12 19:56:54,032 Completed processing <Batch: 17 messages, open for 0.87 seconds>.
snuba-transactions-consumer_1 | 2021-02-12 19:56:54,821 Completed processing <Batch: 18 messages, open for 0.79 seconds>.
snuba-transactions-consumer_1 | 2021-02-12 19:56:55,585 Completed processing <Batch: 20 messages, open for 0.76 seconds>.
snuba-transactions-consumer_1 | 2021-02-12 19:56:56,383 Completed processing <Batch: 22 messages, open for 0.80 seconds>.
snuba-transactions-consumer_1 | 2021-02-12 19:56:57,160 Completed processing <Batch: 27 messages, open for 0.78 seconds>.
snuba-transactions-consumer_1 | 2021-02-12 19:56:57,914 Completed processing <Batch: 27 messages, open for 0.75 seconds>.
snuba-api_1 | python threads support enabled
snuba-api_1 | your server socket listen backlog is limited to 100 connections
snuba-api_1 | your mercy for graceful operations on workers is 60 seconds
snuba-api_1 | mapped 145808 bytes (142 KB) for 1 cores
snuba-api_1 | *** Operational MODE: single process ***
snuba-api_1 | initialized 38 metrics
snuba-api_1 | spawned uWSGI master process (pid: 1)
snuba-api_1 | spawned uWSGI worker 1 (pid: 15, cores: 1)
snuba-api_1 | metrics collector thread started
snuba-api_1 | WSGI app 0 (mountpoint='') ready in 1 seconds on interpreter 0x56311be2f970 pid: 15 (default app)
snuba-api_1 | ...The work of process 15 is done. Seeya!
snuba-api_1 | worker 1 killed successfully (pid: 15)
snuba-api_1 | Respawned uWSGI worker 1 (new pid: 20)
snuba-api_1 | WSGI app 0 (mountpoint='') ready in 2 seconds on interpreter 0x56311be2f970 pid: 20 (default app)
snuba-api_1 | ...The work of process 20 is done. Seeya!
snuba-api_1 | worker 1 killed successfully (pid: 20)
snuba-api_1 | Respawned uWSGI worker 1 (new pid: 23)
snuba-api_1 | WSGI app 0 (mountpoint='') ready in 2 seconds on interpreter 0x56311be2f970 pid: 23 (default app)
snuba-api_1 | ...The work of process 23 is done. Seeya!
snuba-api_1 | worker 1 killed successfully (pid: 23)
snuba-api_1 | Respawned uWSGI worker 1 (new pid: 26)
snuba-api_1 | WSGI app 0 (mountpoint='') ready in 1 seconds on interpreter 0x56311be2f970 pid: 26 (default app)
snuba-api_1 | ...The work of process 26 is done. Seeya!
snuba-api_1 | worker 1 killed successfully (pid: 26)
snuba-replacer_1 | + set gosu snuba snuba replacer --storage events --auto-offset-reset=latest --max-batch-size 3
snuba-replacer_1 | + exec gosu snuba snuba replacer --storage events --auto-offset-reset=latest --max-batch-size 3
snuba-replacer_1 | 2021-02-12 19:14:20,958 New partitions assigned: {Partition(topic=Topic(name='event-replacements'), index=0): 20}
snuba-api_1 | Respawned uWSGI worker 1 (new pid: 29)
snuba-api_1 | WSGI app 0 (mountpoint='') ready in 2 seconds on interpreter 0x56311be2f970 pid: 29 (default app)
snuba-api_1 | ...The work of process 29 is done. Seeya!
snuba-api_1 | worker 1 killed successfully (pid: 29)
snuba-api_1 | Respawned uWSGI worker 1 (new pid: 32)
snuba-api_1 | WSGI app 0 (mountpoint='') ready in 1 seconds on interpreter 0x56311be2f970 pid: 32 (default app)
worker_1 | %3|1613159644.552|FAIL|rdkafka#producer-2| [thrd:kafka:9092/bootstrap]: kafka:9092/1001: 1 request(s) timed out: disconnect (after 142135ms in state UP, 1 identical error(s) suppressed)
worker_1 | %5|1613159644.764|REQTMOUT|rdkafka#producer-2| [thrd:kafka:9092/bootstrap]: kafka:9092/1001: Timed out ProduceRequest in flight (after 1632ms, timeout #0)
worker_1 | %4|1613159644.764|REQTMOUT|rdkafka#producer-2| [thrd:kafka:9092/bootstrap]: kafka:9092/1001: Timed out 1 in-flight, 0 retry-queued, 0 out-queue, 0 partially-sent requests
worker_1 | %5|1613159644.793|REQTMOUT|rdkafka#producer-1| [thrd:kafka:9092/bootstrap]: kafka:9092/1001: Timed out ProduceRequest in flight (after 1661ms, timeout #0)
worker_1 | %4|1613159644.793|REQTMOUT|rdkafka#producer-1| [thrd:kafka:9092/bootstrap]: kafka:9092/1001: Timed out 1 in-flight, 0 retry-queued, 0 out-queue, 0 partially-sent requests
worker_1 | %3|1613159644.793|FAIL|rdkafka#producer-1| [thrd:kafka:9092/bootstrap]: kafka:9092/1001: 1 request(s) timed out: disconnect (after 386355ms in state UP, 1 identical error(s) suppressed)
worker_1 | %5|1613159645.102|REQTMOUT|rdkafka#producer-1| [thrd:kafka:9092/bootstrap]: kafka:9092/1001: Timed out ProduceRequest in flight (after 1780ms, timeout #0)
worker_1 | %5|1613159645.102|REQTMOUT|rdkafka#producer-1| [thrd:kafka:9092/bootstrap]: kafka:9092/1001: Timed out ProduceRequest in flight (after 1564ms, timeout #1)
worker_1 | %4|1613159645.102|REQTMOUT|rdkafka#producer-1| [thrd:kafka:9092/bootstrap]: kafka:9092/1001: Timed out 2 in-flight, 0 retry-queued, 0 out-queue, 0 partially-sent requests
worker_1 | %3|1613159645.102|FAIL|rdkafka#producer-1| [thrd:kafka:9092/bootstrap]: kafka:9092/1001: 2 request(s) timed out: disconnect (after 381341ms in state UP)
worker_1 | 19:54:11 [INFO] sentry: post_process.skipped (reason=u'missing_cache' cache_key=u'e:830279c5486145a788ac2dfe08f1ae84:12')
worker_1 | 19:54:11 [INFO] sentry: post_process.skipped (reason=u'missing_cache' cache_key=u'e:3726f9809ca1495291f1cb6ca7210bfb:12')
worker_1 | 19:54:28 [WARNING] sentry.tasks.release_registry: Release registry URL is not specified, skipping the task.
worker_1 | 19:54:28 [INFO] sentry: post_process.skipped (reason=u'missing_cache' cache_key=u'e:d404c6cdce2a45d5913a91fe2ec85630:12')
worker_1 | /usr/local/lib/python2.7/site-packages/urllib3/connectionpool.py:847: InsecureRequestWarning: Unverified HTTPS request is being made. Adding certificate verification is strongly advised. See: https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings
worker_1 | InsecureRequestWarning)
worker_1 | /usr/local/lib/python2.7/site-packages/urllib3/connectionpool.py:847: InsecureRequestWarning: Unverified HTTPS request is being made. Adding certificate verification is strongly advised. See: https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings
worker_1 | InsecureRequestWarning)
worker_1 | /usr/local/lib/python2.7/site-packages/urllib3/connectionpool.py:847: InsecureRequestWarning: Unverified HTTPS request is being made. Adding certificate verification is strongly advised. See: https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings
worker_1 | InsecureRequestWarning)
worker_1 | /usr/local/lib/python2.7/site-packages/urllib3/connectionpool.py:847: InsecureRequestWarning: Unverified HTTPS request is being made. Adding certificate verification is strongly advised. See: https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings
worker_1 | InsecureRequestWarning)
worker_1 | /usr/local/lib/python2.7/site-packages/urllib3/connectionpool.py:847: InsecureRequestWarning: Unverified HTTPS request is being made. Adding certificate verification is strongly advised. See: https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings
worker_1 | InsecureRequestWarning)
worker_1 | /usr/local/lib/python2.7/site-packages/urllib3/connectionpool.py:847: InsecureRequestWarning: Unverified HTTPS request is being made. Adding certificate verification is strongly advised. See: https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings
worker_1 | InsecureRequestWarning)
worker_1 | /usr/local/lib/python2.7/site-packages/urllib3/connectionpool.py:847: InsecureRequestWarning: Unverified HTTPS request is being made. Adding certificate verification is strongly advised. See: https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings
worker_1 | InsecureRequestWarning)
worker_1 | /usr/local/lib/python2.7/site-packages/urllib3/connectionpool.py:847: InsecureRequestWarning: Unverified HTTPS request is being made. Adding certificate verification is strongly advised. See: https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings
worker_1 | InsecureRequestWarning)
zookeeper_1 | CONFLUENT_PLATFORM_LABEL=
zookeeper_1 | CONFLUENT_SUPPORT_METRICS_ENABLE=false
zookeeper_1 | CONFLUENT_VERSION=5.5.0
zookeeper_1 | CUB_CLASSPATH=/etc/confluent/docker/docker-utils.jar
zookeeper_1 | HOME=/root
zookeeper_1 | HOSTNAME=8bbb41b85c5e
zookeeper_1 | KAFKA_VERSION=
zookeeper_1 | LANG=C.UTF-8
zookeeper_1 | PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
zookeeper_1 | PWD=/
zookeeper_1 | PYTHON_PIP_VERSION=8.1.2
zookeeper_1 | PYTHON_VERSION=2.7.9-1
zookeeper_1 | SCALA_VERSION=2.12
zookeeper_1 | SHLVL=1
zookeeper_1 | ZOOKEEPER_CLIENT_PORT=2181
zookeeper_1 | ZOOKEEPER_LOG4J_ROOT_LOGLEVEL=WARN
zookeeper_1 | ZOOKEEPER_TOOLS_LOG4J_LOGLEVEL=WARN
zookeeper_1 | ZULU_OPENJDK_VERSION=8=8.38.0.13
zookeeper_1 | _=/usr/bin/env
zookeeper_1 | ===> User
zookeeper_1 | uid=0(root) gid=0(root) groups=0(root)
zookeeper_1 | ===> Configuring ...
zookeeper_1 | ===> Running preflight checks ...
zookeeper_1 | ===> Check if /var/lib/zookeeper/data is writable ...
zookeeper_1 | ===> Check if /var/lib/zookeeper/log is writable ...
zookeeper_1 | ===> Launching ...
zookeeper_1 | ===> Launching zookeeper ...
zookeeper_1 | [2021-02-12 19:14:05,787] WARN Either no config or no quorum defined in config, running in standalone mode (org.apache.zookeeper.server.quorum.QuorumPeerMain)
zookeeper_1 | [2021-02-12 19:14:06,000] WARN o.e.j.s.ServletContextHandler@4d95d2a2{/,null,UNAVAILABLE} contextPath ends with /* (org.eclipse.jetty.server.handler.ContextHandler)
zookeeper_1 | [2021-02-12 19:14:06,000] WARN Empty contextPath (org.eclipse.jetty.server.handler.ContextHandler)
web_1 | your server socket listen backlog is limited to 100 connections
web_1 | your mercy for graceful operations on workers is 60 seconds
web_1 | setting request body buffering size to 65536 bytes
web_1 | mapped 1924224 bytes (1879 KB) for 12 cores
web_1 | *** Operational MODE: preforking+threaded ***
web_1 | spawned uWSGI master process (pid: 18)
web_1 | spawned uWSGI worker 1 (pid: 23, cores: 4)
web_1 | spawned uWSGI worker 2 (pid: 24, cores: 4)
web_1 | spawned uWSGI worker 3 (pid: 25, cores: 4)
web_1 | spawned uWSGI http 1 (pid: 26)
web_1 | 19:14:26 [WARNING] sentry.utils.geo: settings.GEOIP_PATH_MMDB not configured.
web_1 | 19:14:26 [WARNING] sentry.utils.geo: settings.GEOIP_PATH_MMDB not configured.
web_1 | 19:14:26 [WARNING] sentry.utils.geo: settings.GEOIP_PATH_MMDB not configured.
web_1 | /usr/local/lib/python2.7/site-packages/OpenSSL/crypto.py:12: CryptographyDeprecationWarning: Python 2 is no longer supported by the Python core team. Support for it is now deprecated in cryptography, and will be removed in a future release.
web_1 | from cryptography import x509
web_1 | /usr/local/lib/python2.7/site-packages/OpenSSL/crypto.py:12: CryptographyDeprecationWarning: Python 2 is no longer supported by the Python core team. Support for it is now deprecated in cryptography, and will be removed in a future release.
web_1 | from cryptography import x509
web_1 | /usr/local/lib/python2.7/site-packages/OpenSSL/crypto.py:12: CryptographyDeprecationWarning: Python 2 is no longer supported by the Python core team. Support for it is now deprecated in cryptography, and will be removed in a future release.
web_1 | from cryptography import x509
web_1 | 19:14:31 [INFO] sentry.plugins.github: apps-not-configured
web_1 | 19:14:31 [INFO] sentry.plugins.github: apps-not-configured
web_1 | 19:14:31 [INFO] sentry.plugins.github: apps-not-configured
web_1 | WSGI app 0 (mountpoint='') ready in 6 seconds on interpreter 0x55dd946a1fd0 pid: 24 (default app)
web_1 | WSGI app 0 (mountpoint='') ready in 7 seconds on interpreter 0x55dd946a1fd0 pid: 23 (default app)
web_1 | WSGI app 0 (mountpoint='') ready in 7 seconds on interpreter 0x55dd946a1fd0 pid: 25 (default app)
web_1 | /usr/local/lib/python2.7/site-packages/sentry/models/project.py:184: DeprecationWarning: Project.callsign is deprecated. Use Group.get_short_id() instead.
web_1 | "Project.callsign is deprecated. Use Group.get_short_id() instead.", DeprecationWarning
web_1 | /usr/local/lib/python2.7/site-packages/sentry/models/project.py:184: DeprecationWarning: Project.callsign is deprecated. Use Group.get_short_id() instead.
web_1 | "Project.callsign is deprecated. Use Group.get_short_id() instead.", DeprecationWarning
web_1 | [uwsgi-http key: 127.0.0.1 client_addr: 192.168.160.1 client_port: 5332] hr_write(): Broken pipe [plugins/http/http.c line 565]
Needs More Information
erfansahaf
All 19 comments
@erfansahaf - from the logs you shared, seems like Redis is your main bottleneck along with Relay (and potentially Kafka too).
That said, I'm not sure I understand what you expect from the Sentry team as a solution. As with any system, you'll need to find and fix the bottlenecks instead of the system magically and intelligently expanding to utilize all your available hardware resources.
/cc @jan-auer in case I misinterpret Relay logs
BYK
on 12 Feb 2021
@BYK I'm saying that it was working fine and we didn't have any breaking change in our releases. Everything was normal. I was wondering is it a known bug/issue or it's just my problem because of the low resource for such a load? I'm asking this because one friend of mine had the same problem with the same behavior even on a better resource.
I want to clear my expectation with the Sentry, so I can decide to whether contributing to the source code or migrating to the Sentry As A Service product.
erfansahaf
on 12 Feb 2021
@erfansahaf There's no known issues at this point, although I can point out a few starting points:
sentry.exceptions.InvalidConfiguration: Redis is loading the dataset in memory: I've seen this happen in local development. When the Redis dataset grows in size, restarting the Redis server takes considerable time. However, the Docker compose setup does not wait for Redis to become available, so you will see this error until Redis is available. The workaround for this is to start Redis early, wait until it responds, and then start everything else.Too many events (event_buffer_size reached): This happens either if Relay is too slow, or more likely, if Relay cannot obtain information from Sentry web. Since Redis is not responding in this log and Redis is required for this, this is likely the root cause. Relay then starts buffering up events, and eventually the buffer is full.Broker: Coordinator load in progress: Similarly, here it just looks like container startup is taking too long.
If you've been running Sentry for a while without restarting the Kafka and Redis containers, then this may explain your sudden failures.
jan-auer
on 15 Feb 2021
🚀1
@jan-auer Thanks for your explanation.
I have other questions:
Since the Redis, Kafka, and Postgres data are persisted on disk, does restart help at all? I think the restart thing is not the case because after happening this failure, I did multiple restarts but nothing changed.
When the Redis container is up, it fills the memory and enforces the OS to use Swap which makes the system slow. Why would Redis use 64GB of ram? How can I _SAFELY_ clean it up?
Is there any estimate about how many events Sentry can receive and process per hour with a specific configuration?
erfansahaf
on 15 Feb 2021
@erfansahaf
Is there any estimate about how many events Sentry can receive and process per hour with a specific configuration?
I've tested Sentry on a Google Compute Engine unit with 4 cores and 8 GB RAM. I sent it ~10k simple events in about 10-15 minutes (no stacktrace, no attachments, no minidumps etc.) and that was enough to saturate all the CPUs and the web UI became a bit sluggish but still responsive. Does that give you some idea?
Why would Redis use 64GB of ram? How can I SAFELY clean it up?
Redis is used both as a cache and celery task queue. I think if you upgrade to a later version, its usage may be reduced due to some optimizations put in place (they should be already enabled on the version you are using but I'm not entirely sure so wouldn't hurt using the latest version at this point).
You may consider introducing RabbitMQ as your task queue which would reduce the load on Redis but will add more complexity to your system.
BYK
on 15 Feb 2021
@BYK
I've tested Sentry on a Google Compute Engine unit with 4 cores and 8 GB RAM. I sent it ~10k simple events in about 10-15 minutes
So when I'm running it on a dedicated server with 8 times better resources (64 GB RAM, 32 CPU cores), I can expect it to receive 80k events in 10-15 mins or 320k events in an hour. There is something wrong with my stack cause it can not even handle 200K events per hour.
Redis is used both as a cache and celery task queue.
With that being said, if I flush the Redis database, all the queued jobs should be deleted and it should be able to continue to process newly received events. Right?
erfansahaf
on 16 Feb 2021
Hi @erfansahaf
Why would Redis use 64GB of ram? How can I SAFELY clean it up?
Besides what was already mentioned, Redis is used to store event payload (and attachments for native events) during processing and those are removed at the end of processing in post_process_group tasks.
I'd suggest you configure Redis maxmemory to something reasonable with regard to available resources to prevent cascading failure and OOM of other containers as well. With the default maxmemory-policy as noeviction this should propagate backpressure to the ingestion and backlog in Kafka.
You can set the maxmemory on running instance from redis-cli with e.g. config set maxmemory 32gb.
beezz
on 16 Feb 2021
I've noticed that Redis gets filled over time, not just with a peak.
Look at this image from the stats section:
Only 100k events have sent to the Sentry in an hour, but it couldn't process them at that moment and it's processing them now. So it's kinda lagging 3-4 hours in processing.
I think we have a performance issue here since I had flushed the Redis database and reset the Kafka groups but after a couple of hours, the Redis has got filled again:
127.0.0.1:6379> info keyspace
# Keyspace
db0:keys=107729,expires=107721,avg_ttl=84099292
db1:keys=7,expires=2,avg_ttl=21470
It's too strange. I didn't have this issue before and it was working perfectly fine with even 200k events per hour.
erfansahaf
on 17 Feb 2021
@erfansahaf if it is just a processing speed issue, I think you may benefit from this solution: https://develop.sentry.dev/self-hosted/troubleshooting/#workers
BYK
on 17 Feb 2021
@BYK Since the system Load Average is about 40 with 32 cores (over used), adding a new worker doesn't make sense.
Is there any way to delete all stored events and transaction but keeping the projects, users and other settings?
erfansahaf
on 17 Feb 2021
@BYK Since the system Load Average is about 40 with 32 cores (over used), adding a new worker doesn't make sense.
Adding a dedicated worker may still help processing events faster as it won't be blocked by other tasks. It is worth a try really.
BYK
on 17 Feb 2021
@BYK Nothing changed about the lagging issue. It just doubled the CPU load average. Can I run a worker service on another machine and link it to the current Sentry stack so the CPU is not affected by this worker?
erfansahaf
on 18 Feb 2021
@erfansahaf did you just spin up a new worker without any dedicated queues or did you split up event processing queue from the others?
Can I run a worker service on another machine and link it to the current Sentry stack so the CPU is not affected by this worker?
As long as it can reach all the same services (Postgres, Redis, Kafka, Snuba, etc.) you can run it wherever you need to :)
BYK
on 18 Feb 2021
@BYK I added a new worker service for just the event processing queue.
I get back to my previous question, so is there any way to delete all saved/processed events? Want a fresh Sentry with the same projects and configuration but without events/transactions.
erfansahaf
on 18 Feb 2021
@erfansahaf this should provide you what you want: https://develop.sentry.dev/self-hosted/backup/#quick-backup
BYK
on 18 Feb 2021
@BYK Can I take a quick backup on the 20.10.1 and restore it on 21.2.0? Or there is a big major change in the exported files?
erfansahaf
on 21 Feb 2021
Can I take a quick backup on the
20.10.1and restore it on21.2.0?
No, you should restore into a clean 20.10.1 install, and then upgrade to 21.2.0. From the docs:
We strongly recommended that you restore your backup on the same version of Sentry on a fresh install (empty database but migrations are run). Otherwise, you are very likely to hit errors and may corrupt your database.
chadwhitacre
on 24 Feb 2021
🚀1
@erfansahaf is there anything more that could be done in this issue or can we close it?
BYK
on 3 Mar 2021
Let's close it for now. I will reopen the issue if I found something relevant.
erfansahaf
on 3 Mar 2021
❤1
Was this page helpful?
0 / 5 - 0 ratings
Related issues
TheRatG
路
4Comments
harshulj
路
3Comments
kh0r
路
5Comments
meriturva
路
6Comments
rmisyurev
路
4Comments