Sentry closing connection (502) for small bursts from Java client

I’m running an on-premise Sentry instance set up using the Sentry docker installation. I also placed Caddy in front of it for simple SSL configuration and everything is going pretty well. However, one of my applications (Java SDK) often sends bursts of logs and I end up getting 502s from Sentry. It’s not insane traffic, but about 10 logs/sec max. I have 6 workers running and it’s on a fairly powerful EC2 instance. The logs always follow the same pattern. One EOF, followed by “read: connection reset by peer”. Here’s an example of the logs from Caddy, with public IPs obfuscated:

123.456.789.10 - - [31/Mar/2020:17:48:28 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:48:28 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:48:28 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:48:28 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:48:28 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:02 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:02 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:02 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:02 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:02 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:02 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:02 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:02 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:02 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:02 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:02 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:02 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:02 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:02 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:02 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:03 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:03 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:03 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:03 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:03 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
31/Mar/2020:17:49:03 +0000 [ERROR 502 /api/4/store/] EOF
123.456.789.10 - - [31/Mar/2020:17:49:03 +0000] "POST /api/4/store/ HTTP/1.1" 502 16
123.456.789.10 - - [31/Mar/2020:17:49:03 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:03 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:03 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:03 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:03 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:03 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:03 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:03 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:03 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:03 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:03 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:05 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:05 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
31/Mar/2020:17:49:05 +0000 [ERROR 502 /api/4/store/] read tcp 172.19.0.4:50192->172.19.0.6:9000: read: connection reset by peer
123.456.789.10 - - [31/Mar/2020:17:49:05 +0000] "POST /api/4/store/ HTTP/1.1" 502 16
123.456.789.10 - - [31/Mar/2020:17:49:05 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:05 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:05 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:05 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:05 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:05 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:05 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:05 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:05 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:05 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:05 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:07 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
123.456.789.10 - - [31/Mar/2020:17:49:07 +0000] "POST /api/4/store/ HTTP/1.1" 200 41

Has anyone ever seen this before? It sort of seems to be traffic related but the logs look nearly identical every time.

Upon further investigation, it seems like the web container is actually ok. The logs from sentry_web_1 during this time period are:

172.19.0.4 - - [31/Mar/2020:17:48:28 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:48:28 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:48:28 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:48:28 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:48:28 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:02 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:02 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:02 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:02 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:02 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:02 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:02 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:02 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:02 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:02 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:02 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:02 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:02 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:02 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:02 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:02 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:03 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:03 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:03 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:03 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:03 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:03 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:03 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:03 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:03 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:03 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:03 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:03 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:03 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:03 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:03 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:05 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:05 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:05 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:05 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:05 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:05 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:05 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:05 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:05 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:05 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:05 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:05 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:05 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:07 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"
172.19.0.4 - - [31/Mar/2020:17:49:07 +0000] "POST /api/4/store/ HTTP/1.1" 200 680 "-" "sentry-java/1.7.30-7a445"

Perhaps it’s an issue with Caddy, but I’ve used it in the same way for many projects and never seen this sort of problem. Since Caddy itself is reporting the hangup, it seems unlikely that it’s Caddy’s issue. But sentry_web_1 is the container bound to port 9000 and it’s not reporting 502s.

This might be the UWSGI process running in front of Sentry and talking to Caddy. How old is your instance as we had a few settings changed around this that might help.

Referring to this change specifically:

Hey @BYK! Thank you for the prompt response. I just created this instance this weekend. I do see the changes from that PR present in my config:

$ cat sentry.conf.py | grep http-chunked-input
"http-chunked-input": True, 

I’m almost wondering if this is working the other way for me. Perhaps I can try disabling it. Will do that temporarily and report back.

Edit: I tried reverting that change and rebooting, but still getting the same issue.

Oh wait, I think you are right. Right now we configure uwsgi to front all the requests w/o a reverse-proxy. I think removing these lines from your config should fix the issue:

Hey @BYK thanks again for the support here. That makes sense, but I can’t find a way to get this disabled and also work. For some reason, disabling the lines you highlighted causes the following error when starting the sentry_web Docker container:

18:02:14 [WARNING] sentry.utils.geo: settings.GEOIP_PATH_MMDB not configured.
18:02:20 [INFO] sentry.plugins.github: apps-not-configured
*** Starting uWSGI 2.0.18 (64bit) on [Sun Apr  5 18:02:20 2020] ***
compiled with version: 8.3.0 on 31 March 2020 19:34:22
os: Linux-4.15.0-1063-aws #67-Ubuntu SMP Mon Mar 2 07:24:29 UTC 2020
nodename: 8132d1c65fa1
machine: x86_64
clock source: unix
detected number of CPU cores: 2
current working directory: /
detected binary path: /usr/local/bin/uwsgi
!!! no internal routing support, rebuild with pcre support !!!
your memory page size is 4096 bytes
detected max file descriptor number: 1048576
lock engine: pthread robust mutexes
thunder lock: enabled
uWSGI http bound on 0.0.0.0:9000 fd 3
probably another instance of uWSGI is running on the same address (0.0.0.0:9000).
bind(): Address already in use [core/socket.c line 769]

I tried a few other configurations to try and drop uwsgi but I can’t get it to work. I think Caddy still needs uwsgi running as it doesn’t have built in wsgi support, so it needs to speak to something that speaks HTTP (ex. UWSGI).

Hi @jamiecounsell, I think you also need to remove the 'http': '%s:%s' % (SENTRY_WEB_HOST, SENTRY_WEB_PORT), line right above.

That said it is quite weird that it complains about address already being in use. I’m guessing you have no other modifications to the config file or the Docker image?

@BYK ok, that resolved the issue and it’s running now without uwsgi. That said, I still see 502s (different now though)

caddy_1    | 123.456.789.0 - - [20/Apr/2020:14:14:43 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
caddy_1    | 123.456.789.0 - - [20/Apr/2020:14:14:44 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
caddy_1    | 123.456.789.0 - - [20/Apr/2020:14:14:45 +0000] "POST /api/4/store/ HTTP/1.1" 200 41
caddy_1    | 123.456.789.0 - - [20/Apr/2020:14:15:10 +0000] "POST /api/5/store/ HTTP/1.1" 200 41
caddy_1    | 123.456.789.0 - - [20/Apr/2020:14:15:10 +0000] "POST /api/5/store/ HTTP/1.1" 200 41
caddy_1    | 123.456.789.0 - - [20/Apr/2020:14:15:12 +0000] "POST /api/5/store/ HTTP/1.1" 200 41
caddy_1    | 123.456.789.0 - - [20/Apr/2020:14:15:12 +0000] "POST /api/5/store/ HTTP/1.1" 200 41
caddy_1    | 20/Apr/2020:14:15:12 +0000 [ERROR 502 /api/5/store/] read tcp 172.18.0.20:41374->172.18.0.17:9000: read: connection reset by peer
caddy_1    | 123.456.789.0 - - [20/Apr/2020:14:15:12 +0000] "POST /api/5/store/ HTTP/1.1" 502 16
caddy_1    | 123.456.789.0 - - [20/Apr/2020:14:15:12 +0000] "POST /api/5/store/ HTTP/1.1" 200 41
caddy_1    | 123.456.789.0 - - [20/Apr/2020:14:15:12 +0000] "POST /api/5/store/ HTTP/1.1" 200 41
caddy_1    | 20/Apr/2020:14:15:12 +0000 [ERROR 502 /api/5/store/] read tcp 172.18.0.20:41394->172.18.0.17:9000: read: connection reset by peer
caddy_1    | 123.456.789.0 - - [20/Apr/2020:14:15:12 +0000] "POST /api/5/store/ HTTP/1.1" 502 16
caddy_1    | 123.456.789.0 - - [20/Apr/2020:14:15:12 +0000] "POST /api/5/store/ HTTP/1.1" 200 41
caddy_1    | 123.456.789.0 - - [20/Apr/2020:14:15:12 +0000] "POST /api/5/store/ HTTP/1.1" 200 41
caddy_1    | 123.456.789.0 - - [20/Apr/2020:14:15:13 +0000] "POST /api/5/store/ HTTP/1.1" 200 41
caddy_1    | 123.456.789.0 - - [20/Apr/2020:14:15:16 +0000] "POST /api/5/store/ HTTP/1.1" 200 41
caddy_1    | 123.456.789.0 - - [20/Apr/2020:14:15:16 +0000] "POST /api/5/store/ HTTP/1.1" 200 41
caddy_1    | 123.456.789.0 - - [20/Apr/2020:14:15:16 +0000] "POST /api/5/store/ HTTP/1.1" 200 41
caddy_1    | 123.456.789.0 - - [20/Apr/2020:14:15:16 +0000] "POST /api/5/store/ HTTP/1.1" 200 41
caddy_1    | 123.456.789.0 - - [20/Apr/2020:14:15:16 +0000] "POST /api/5/store/ HTTP/1.1" 200 41
caddy_1    | 123.456.789.0 - - [20/Apr/2020:14:15:16 +0000] "POST /api/5/store/ HTTP/1.1" 200 41
caddy_1    | 123.456.789.0 - - [20/Apr/2020:14:15:16 +0000] "POST /api/5/store/ HTTP/1.1" 200 41
caddy_1    | 123.456.789.0 - - [20/Apr/2020:14:15:17 +0000] "POST /api/5/store/ HTTP/1.1" 200 41
caddy_1    | 123.456.789.0 - - [20/Apr/2020:14:15:18 +0000] "POST /api/5/store/ HTTP/1.1" 200 41
caddy_1    | 123.456.789.0 - - [20/Apr/2020:14:15:19 +0000] "POST /api/5/store/ HTTP/1.1" 200 41
caddy_1    | 123.456.789.0 - - [20/Apr/2020:14:15:19 +0000] "POST /api/5/store/ HTTP/1.1" 200 41
caddy_1    | 123.456.789.0 - - [20/Apr/2020:14:15:24 +0000] "POST /api/5/store/ HTTP/1.1" 200 41
1 Like

@jamiecounsell recently we have introduced Nginx into our setup too and I made the following PR:

Can you let me know if any of those settings help your case? Especially disabling buffering may help. I guess Caddy has similar settings?