Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Metrics stream not closing connections #1430

Closed
DangerPete opened this issue Nov 25, 2016 · 9 comments
Closed

Metrics stream not closing connections #1430

DangerPete opened this issue Nov 25, 2016 · 9 comments
Labels
bug metrics

Comments

@DangerPete
Copy link

Hi,

Way back in the day an issue was raised whereby connections to the metric stream were being held open when no command data was available: #85
Since the rewrite of the HystrixMetricsStreamServlet it would appear that this behaviour has slipped back in.
If no data is available the onNext of the subscriber in HystrixSampleSseServlet is never called, and hence the connection is never checked, thus connections are held forever.

This can be replicated using the hystrix example webapp by just curling the metrics stream upon app start up.

[norvalp@mbp ~]$ curl http://localhost:8989/hystrix-examples-webapp/hystrix.stream
^C
[norvalp@mbp ~]$ curl http://localhost:8989/hystrix-examples-webapp/hystrix.stream
^C
[norvalp@mbp ~]$ curl http://localhost:8989/hystrix-examples-webapp/hystrix.stream
^C
[norvalp@mbp ~]$ curl http://localhost:8989/hystrix-examples-webapp/hystrix.stream
^C
[norvalp@mbp ~]$ curl http://localhost:8989/hystrix-examples-webapp/hystrix.stream
^C
[norvalp@mbp ~]$ curl http://localhost:8989/hystrix-examples-webapp/hystrix.stream
<html>
<head>
<meta http-equiv="Content-Type" content="text/html; charset=ISO-8859-1"/>
<title>Error 503 MaxConcurrentConnections reached: 5</title>
</head>
<body><h2>HTTP ERROR 503</h2>
<p>Problem accessing /hystrix-examples-webapp/hystrix.stream. Reason:
<pre>    MaxConcurrentConnections reached: 5</pre></p><hr /><i><small>Powered by Jetty://</small></i><br/>
<br/>
<br/>
<br/>
<br/>
<br/>
<br/>
<br/>
<br/>
<br/>
<br/>
<br/>
<br/>
<br/>
<br/>
<br/>
<br/>
<br/>
<br/>
<br/>

</body>
</html>
[norvalp@mbp ~]$
@mattnelson
Copy link

Came here to report this same issue, netstat is showing the sockets in a CLOSE_WAIT state indicating that the server is the culprit.

Proto Recv-Q Send-Q Local Address           Foreign Address         State       PID/Program name
tcp        1      0 192.168.1.26:8080       192.168.1.2:41290       CLOSE_WAIT  -
tcp        1      0 192.168.1.26:8080       192.168.1.2:41382       CLOSE_WAIT  -
tcp        1      0 192.168.1.26:8080       192.168.1.2:41572       CLOSE_WAIT  -
tcp        1      0 192.168.1.26:8080       192.168.1.2:41478       CLOSE_WAIT  -
tcp        1      0 192.168.1.26:8080       192.168.1.2:41196       CLOSE_WAIT  -

@mattrjacobs
Copy link
Contributor

I'll investigate

@mattrjacobs
Copy link
Contributor

I just added this branch with some printlns to the stream servlet: https://github.com/mattrjacobs/Hystrix/tree/understand-1430-regression

When I run the Jetty server in hystrix-examples-webapp, it's behaving the way I expect.

I'm able to run curls against that server, and the server properly cleans up when the client process ends. Is there anything different about this attempt at a reproduction and your cases, @DangerPete / @mattnelson ?

Sample server output when I repeatedly start a curl and terminate with Ctrl+C:

1481568960959 : 1603081228@qtp-1695903109-7 Number of connections : 1
1481568961964 : RxIoScheduler-6 Caught IOException, can release the server thread
1481568961965 : RxIoScheduler-6 Caught IOException, can release the server thread
1481568961965 : RxIoScheduler-6 Caught IOException, can release the server thread
1481568961966 : RxIoScheduler-6 Caught IOException, can release the server thread
1481568962240 : 1603081228@qtp-1695903109-7 Number of connections : 1
1481568963245 : RxIoScheduler-7 Caught IOException, can release the server thread
1481568963246 : RxIoScheduler-7 Caught IOException, can release the server thread
1481568963246 : RxIoScheduler-7 Caught IOException, can release the server thread
1481568963246 : RxIoScheduler-7 Caught IOException, can release the server thread
1481568963247 : RxIoScheduler-7 Caught IOException, can release the server thread
1481568963793 : 1603081228@qtp-1695903109-7 Number of connections : 1
1481568964298 : RxIoScheduler-6 Caught IOException, can release the server thread
1481568964299 : RxIoScheduler-6 Caught IOException, can release the server thread
1481568964299 : RxIoScheduler-6 Caught IOException, can release the server thread
1481568964299 : RxIoScheduler-6 Caught IOException, can release the server thread
1481568964300 : RxIoScheduler-6 Caught IOException, can release the server thread
1481568964799 : RxIoScheduler-6 Caught IOException, can release the server thread

@mattnelson
Copy link

What version of jetty is hystrix-examples-webapp using? I am using 9.3 which, from what I've seen , appears to have some different connection handling compared to previous versions.

@mattrjacobs
Copy link
Contributor

It was using whatever the stock Gradle Jetty plugin was using, which wasn't clear. I switched to use Gretty and was able to choose between Jetty 7/8/9 and Tomcat 7/8. All of them worked locally as expected.

Are you able to replicate those findings? The Gretty config is pushed to my personal fork: https://github.com/mattrjacobs/Hystrix/tree/understand-1430-regression

@mattnelson
Copy link

I was able to recreate the error by loading the hystrix stream before calling the demo page. This lines up with what I've been seeing on our services as well. Since we are using turbine to aggregate as soon as the service is UP, turbine begins to aggregate. It isn't until the first command is executed that the stream recovers and closes the abandoned connections.

curl logs

shell@laptop:~$ curl http://localhost:8989/hystrix-examples-webapp/hystrix.stream
^C
shell@laptop:~$ curl http://localhost:8989/hystrix-examples-webapp/hystrix.stream
^C
shell@laptop:~$ curl http://localhost:8989/hystrix-examples-webapp/hystrix.stream
^C
shell@laptop:~$ curl http://localhost:8989/hystrix-examples-webapp/hystrix.stream
^C
shell@laptop:~$ curl http://localhost:8989/hystrix-examples-webapp/hystrix.stream
^C
shell@laptop:~$ curl http://localhost:8989/hystrix-examples-webapp/hystrix.stream
<html>
<head>
<meta http-equiv="Content-Type" content="text/html; charset=UTF-8"/>
<title>Error 503 MaxConcurrentConnections reached: 5</title>
</head>
<body><h2>HTTP ERROR 503</h2>
<p>Problem accessing /hystrix-examples-webapp/hystrix.stream. Reason:
<pre>    MaxConcurrentConnections reached: 5</pre></p><hr><i><small>Powered by Jetty://</small></i><hr/>

</body>
</html>

server logs

1481587635168 : qtp381708767-13 Number of connections : 1
1481587641770 : qtp381708767-16 Number of connections : 2
1481587646671 : qtp381708767-19 Number of connections : 3
1481587649998 : qtp381708767-21 Number of connections : 4
1481587651377 : qtp381708767-22 Number of connections : 5
1481587652810 : qtp381708767-33 Number of connections : 6
1481587689262 : RxIoScheduler-2 Caught IOException, can release the server thread
1481587689262 : RxIoScheduler-3 Caught IOException, can release the server thread
1481587689262 : RxIoScheduler-2 Caught IOException, can release the server thread
1481587689263 : RxIoScheduler-3 Caught IOException, can release the server thread
1481587689263 : RxIoScheduler-2 Caught IOException, can release the server thread
1481587689263 : RxIoScheduler-3 Caught IOException, can release the server thread
1481587689263 : RxIoScheduler-2 Caught IOException, can release the server thread
1481587689263 : RxIoScheduler-3 Caught IOException, can release the server thread
1481587689264 : RxIoScheduler-4 Caught IOException, can release the server thread
1481587689264 : RxIoScheduler-4 Caught IOException, can release the server thread
1481587689264 : RxIoScheduler-4 Caught IOException, can release the server thread
1481587689265 : RxIoScheduler-5 Caught IOException, can release the server thread
1481587689265 : RxIoScheduler-4 Caught IOException, can release the server thread
1481587689265 : RxIoScheduler-5 Caught IOException, can release the server thread
1481587689265 : RxIoScheduler-5 Caught IOException, can release the server thread
1481587689265 : RxIoScheduler-5 Caught IOException, can release the server thread
1481587689266 : RxIoScheduler-6 Caught IOException, can release the server thread
1481587689266 : RxIoScheduler-6 Caught IOException, can release the server thread
1481587689266 : RxIoScheduler-6 Caught IOException, can release the server thread
1481587689267 : RxIoScheduler-6 Caught IOException, can release the server thread
1481587689693 : RxIoScheduler-5 Caught IOException, can release the server thread
1481587689693 : RxIoScheduler-5 Caught IOException, can release the server thread
1481587689693 : RxIoScheduler-5 Caught IOException, can release the server thread
1481587689694 : RxIoScheduler-5 Caught IOException, can release the server thread
1481587689694 : RxIoScheduler-5 Caught IOException, can release the server thread
1481587689694 : RxIoScheduler-5 Caught IOException, can release the server thread
1481587689694 : RxIoScheduler-5 Caught IOException, can release the server thread
1481587699973 : qtp381708767-33 Number of connections : 1
1481587701475 : RxIoScheduler-4 Caught IOException, can release the server thread
1481587701475 : RxIoScheduler-4 Caught IOException, can release the server thread
1481587701476 : RxIoScheduler-4 Caught IOException, can release the server thread
1481587701476 : RxIoScheduler-4 Caught IOException, can release the server thread
1481587701476 : RxIoScheduler-4 Caught IOException, can release the server thread
1481587701477 : RxIoScheduler-4 Caught IOException, can release the server thread

mattrjacobs added a commit that referenced this issue Dec 14, 2016
@mattrjacobs
Merge pull request #1442 from mattrjacobs/fix-1430
11ca011 
Fix #1430 by detecting case when client connect/disconnects before me…
@mattrjacobs
Copy link
Contributor

Didn't realize merging that would close the issue. Reopening until the release happens and the fix is verified. Thanks for the help in getting to a repro case.

@mattrjacobs mattrjacobs reopened this Dec 14, 2016
@mrotteveel
Copy link

When can we expect a new release?

@mattrjacobs
Copy link
Contributor

Just released 1.5.9

@mattnelson mattnelson mentioned this issue Aug 2, 2017
Open
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug metrics
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@mattrjacobs @mattnelson @mrotteveel @DangerPete