Skip to content

gracefulClose stops servers due to a lot of TCP states #438

Description

@larskuhtz

We run a p2p network with Haskell nodes using network + tls + warp for the server and network + tls + http-client for the client components.

We observed that nodes that are using network version < 3.1.1.0 have been running without issues for weeks, while nodes that are using network >=3.1.1.0 are stopping to make and serve requests after running for a few days.

Bad nodes don't accept any incoming connections and fail to establish outgoing connections.

On the bad nodes there is no increase in memory consumption and CPU usage is low, since they are not doing anything useful without being able to make network connections. The number of open file descriptors is moderate, but many of the TCP sockets are in a CLOSE_WAIT state. Most of those sockets are not listed by lsof, but are only shown by netstat without an associated process.

The following are two typical TCP sessions:

No.	Time	Source	Destination	Protocol	Length	Info
28	2.100345	172.31.20.24	47.108.144.139	TCP	66	41372 → 9443 [FIN, ACK] Seq=1 Ack=1 Win=211 Len=0 TSval=2546593558 TSecr=1766578430
30	2.373855	47.108.144.139	172.31.20.24	TCP	198	9443 → 41372 [PSH, ACK] Seq=1 Ack=2 Win=227 Len=132 TSval=1766583433 TSecr=2546593558 [TCP segment of a reassembled PDU]
31	2.373887	172.31.20.24	47.108.144.139	TCP	54	41372 → 9443 [RST] Seq=2 Win=0 Len=0
32	2.373894	47.108.144.139	172.31.20.24	TCP	98	9443 → 41372 [PSH, ACK] Seq=133 Ack=2 Win=227 Len=32 TSval=1766583433 TSecr=2546593558 [TCP segment of a reassembled PDU]
33	2.373897	172.31.20.24	47.108.144.139	TCP	54	41372 → 9443 [RST] Seq=2 Win=0 Len=0
34	2.373899	47.108.144.139	172.31.20.24	TCP	84	9443 → 41372 [PSH, ACK] Seq=165 Ack=2 Win=227 Len=18 TSval=1766583433 TSecr=2546593558 [TCP segment of a reassembled PDU]
35	2.373901	172.31.20.24	47.108.144.139	TCP	54	41372 → 9443 [RST] Seq=2 Win=0 Len=0
36	2.373902	47.108.144.139	172.31.20.24	HTTP	66	HTTP/1.1 426 Upgrade Required          (text/plain)
37	2.373904	172.31.20.24	47.108.144.139	TCP	54	41372 → 9443 [RST] Seq=2 Win=0 Len=0
No.	Time	Source	Destination	Protocol	Length	Info
161	7.803316	47.245.52.190	172.31.20.24	TCP	74	43686 → 443 [SYN] Seq=0 Win=29200 Len=0 MSS=1460 SACK_PERM=1 TSval=2824405820 TSecr=0 WS=128
220	8.818459	47.245.52.190	172.31.20.24	TCP	74	[TCP Retransmission] 43686 → 443 [SYN] Seq=0 Win=29200 Len=0 MSS=1460 SACK_PERM=1 TSval=2824406835 TSecr=0 WS=128
244	10.834435	47.245.52.190	172.31.20.24	TCP	74	[TCP Retransmission] 43686 → 443 [SYN] Seq=0 Win=29200 Len=0 MSS=1460 SACK_PERM=1 TSval=2824408851 TSecr=0 WS=128

HTTP TCP sessions from other processes seem fine.

Activity

  1. larskuhtz commented on Mar 5, 2020

    @larskuhtz
    Author

    Please let me know what additional data would be helpful to diagnose the issue. I can provide larger TCP dumps and/or detailed netstat infos if needed. I can also provide direct ssh access to affected machines, if that's helpful for understanding or solving the issue.

  2. kazu-yamamoto commented on Mar 16, 2020

    @kazu-yamamoto
    Collaborator

    Sorry for the delay. This is probably due to gracefulClose. First of all, if you are using warp < 3.3.4, please upgrade to warp >= 3.3.5. Since 3.3.5, warp uses close() for HTTP/1.1 by default.

    Even if the problem continues, please check if HTTP/2 connections are used. If so, please use setGracefulCloseTimeout2 0 to disable gracefulClose for HTTP/2. If this fixes the problem, the source of bug is definitely gracefulClose. Timeout to close sockets is not handled correctly.

  3. fosskers commented on Mar 16, 2020

    @fosskers

    We are definitely using the newest warp, so we'll try it with setGracefulCloseTimeout.

  4. kazu-yamamoto commented on Mar 16, 2020

    @kazu-yamamoto
    Collaborator

    This article would help your understanding: https://kazu-yamamoto.hatenablog.jp/entry/2019/09/20/165939

  5. kazu-yamamoto commented on May 19, 2020

    @kazu-yamamoto
    Collaborator

    @larskuhtz Would you close this issue if already resolved?

  6. changed the title [-]Regression with version >= 3.1.1.0[/-] [+]gracefullclose stops servers due to a lot of TCP states[/+] on May 19, 2020
  7. kazu-yamamoto commented on May 19, 2020

    @kazu-yamamoto
    Collaborator

    I had the same experience. I will try to fix.

  8. fosskers commented on May 19, 2020

    @fosskers

    Thank you! Should the 3.1.1.x series be marked as deprecated on Hackage, once 3.1.2.0 is released?

  9. kazu-yamamoto commented on May 19, 2020

    @kazu-yamamoto
    Collaborator

    Yes. I will do so.

  10. kazu-yamamoto commented on May 19, 2020

    @kazu-yamamoto
    Collaborator

    @snoyberg I'm CC:ing to you here since the current approach of gracefulClose was suggested by you and this is relating to Warp.

    TCP and server: CLOSE_WAIT is the state that the TCP stack of the server received TCP FIN but not send TCP FIN. This means the server does not close(2) the socket yet. The TCP stack waits forever in this situation.

    Warp: When TCP FIN is received, connRecv returns "". serve in fork returns and then connClose is called. So far, so good. But gracefulClose cannot call close. Why?

    https://github.com/haskell/network/blob/master/Network/Socket/Shutdown.hs#L61

    I suspect two things:

    1. Asynchronous exception from Warp's time manager
    2. Callback is not fired by GHC TimerManager

    But I don't have any clues yet so far. Could you suggest anything?

    Note that shutdown can throw an exception.

  11. kazu-yamamoto commented on May 19, 2020

    @kazu-yamamoto
    Collaborator

    It might be wise if we call recvBufNoWait after shutdown for the case where FIN is already received. (Like C's do { } while () loop).

  12. changed the title [-]gracefullclose stops servers due to a lot of TCP states[/-] [+]gracefulClose stops servers due to a lot of TCP states[/+] on May 19, 2020
  13. snoyberg commented on May 20, 2020

    @snoyberg

    I think it was actually @nh2 who proposed the implementation of gracefulClose. Maybe he has some thoughts, I unfortunately don't.

  14. kazu-yamamoto commented on May 20, 2020

    @kazu-yamamoto
    Collaborator

    Approach 4 in this article (https://kazu-yamamoto.hatenablog.jp/entry/2019/09/20/165939) was proposed by you. :-)

  15. 29 remaining items

  16. kazu-yamamoto commented on Feb 17, 2021

    @kazu-yamamoto
    Collaborator

    @swamp-agr If you use Linux, please check net.ipv4.tcp_fin_timeout. The default value, 60 (second), might be too long for your use case. Also, please check net.ipv4.tcp_tw_reuse. This should be 1 for your case. The following settings for /etc/sysctl.conf would help:

    net.ipv4.tcp_tw_reuse = 1
    net.ipv4.tcp_fin_timeout = 30
    
  17. kazu-yamamoto commented on Feb 17, 2021

    @kazu-yamamoto
    Collaborator

    Note that tcp_tw_recycle would be also related. But this is a bit dangerous and was removed Linux 4.1.2.
    Anyway, please look into these parameters.

  18. swamp-agr commented on Feb 17, 2021

    @swamp-agr

    Issue reproduced even with these values:

    net.ipv4.tcp_tw_reuse=1
    net.ipv4.tcp_fin_timeout=15
    

    tcp_tw_recycle is indeed dangerous since enabling it make server suffers and drops connections. I think it is incompatible with NGINX keepalive setting for upstream server.

  19. swamp-agr commented on Feb 19, 2021

    @swamp-agr

    I think, the problem is not in close but in another place. I am not sure which one.
    Please let me know if I should open new issue or move to warp.

    Meantime I gathered two pictures (server is up and running and sockets started to leak).

    • Server is up and running:
      normal_sockets

    • Leaking sockets picture:
      leaking_sockets

    Screenshot 2021-02-19 at 21 19 21

  20. kazu-yamamoto commented on Feb 19, 2021

    @kazu-yamamoto
    Collaborator

    @swamp-agr If you believe this is a bug of Warp, please send this issue to Warp.

  21. swamp-agr commented on Feb 20, 2021

    @swamp-agr
    • Root cause found inside application code (as usual).
    • Handlers were running indefinitely. It causes warp to wait endlessly.
    • Client dropped connection.
    • NGINX closed socket from its side.
    • Warp still waits for application handler.

    With a constant RPS server accumulates stalled sockets.

    Expected Result: Application handler should finish its job. Warp should respond with close.
    Acutal Result: Application never stopped. Warp is waiting.

    You might close the issue.

  22. kazu-yamamoto commented on Feb 24, 2021

    @kazu-yamamoto
    Collaborator

    @swamp-agr I close this issue. Please bring this issue to Warp.

  23. nh2 commented on Nov 4, 2023

    @nh2
    Member

    @larskuhtz @swamp-agr

    The number of open file descriptors is moderate, but many of the TCP sockets are in a CLOSE_WAIT state. Most of those sockets are not listed by lsof, but are only shown by netstat without an associated process.

    I'm now hitting exactly that problem.

    I asked a question, and provided an answer, on how and why these process-less, FD-less CLOSE_WAITs exist:

    The answer is:

    A CLOSE_WAIT state without associated process occurs when a client waiting in the Linux kernel's listen() backlog queue disconnects before the user-space application accept()s it.

    I haven't figured out yet why my warp application stops accept()ing for multiple minutes, creating the CLOSE_WAITs.

  24. kazu-yamamoto commented on Nov 8, 2023

    @kazu-yamamoto
    Collaborator

    @nh2 Thank you for bringing this answer!

    And now I think I can answer your question.
    Callbacks for the IO and Timer managers MUST NOT be blocked.
    If they are blocked, the entire loops of the IO and Timer manager block are blocked.
    In this situation, any bad things can happen (including the non-accepting).
    If the callbacks can be blocked, we MUST use forkIO.
    That's why timeout calls forkIO if necessary.

    Originally, we tried to use the call back approach to avoid forking a new thread.
    But it is not avoidable to call forkIO in this approach.
    Thus, the timeout approach is better because forkIO is called only when it is necessary.

  25. nh2 commented on Nov 9, 2023

    @nh2
    Member

    Thus, the timeout approach is better because forkIO is called only when it is necessary.

    @kazu-yamamoto Just for me to get back into context:

    Where are those callbacks / is this something that was recently changed, or that you plan to change (e.g. open or already-closed issue or PR)?

    Because I'm still currently investigating what to do about those blocked accepts.

    Your explanation seems to fit my symptoms ("the entire loops of the IO and Timer manager block are blocked") because the process really seems to stop doing almost everything for a while -- not very good for my web server when it happens :D

  26. kazu-yamamoto commented on Nov 9, 2023

    @kazu-yamamoto
    Collaborator

    Where are those callbacks / is this something that was recently changed, or that you plan to change (e.g. open or already-closed issue or PR)?

    I guess that you are talking about the graceful close.
    Our final decision was to adopt the threadDelay approach.
    So, our gracefull close is NOT suffering from CLOSE_WAIT.

    See approach 3 in https://kazu-yamamoto.hatenablog.jp/entry/2019/09/20/165939
    Probably, I should update this article.

  27. nh2 commented on Nov 9, 2023

    @nh2
    Member

    So, our gracefull close is NOT suffering from CLOSE_WAIT.

    @kazu-yamamoto Because my server is suffering from 3000 CLOSE_WAITs a couple times per week; I'm on:

    network-3.1.2.9
    wai-3.2.3
    warp-3.3.23
    
  28. kazu-yamamoto commented on Nov 9, 2023

    @kazu-yamamoto
    Collaborator

    @nh2 Understood.
    If you stop using gracefulClose, does CLOSE_WAIT disappear?

  29. nh2 commented on Oct 21, 2024

    @nh2
    Member

    I haven't figured out yet why my warp application stops accept()ing for multiple minutes, creating the CLOSE_WAITs.

    An update on this:

    My application was calling unsafe FFI to process data coming from an mmap (to hash a 100 GB file). That is illegal, because unsafe foreign calls must only be used on extremely short-running functions. Otherwise the entire Haskell process blocks during GC. This happened to me, so my entire process blocked for 20 minutes (until the hashing of 100 GB completed).

    This of course caused my process to stop calling any function, including accept(), and thus the CLOSE_WAITs accumulated (I have automated HTTP monitoring that queries my server every second to see if it's still up; if it doesn't reply within a 2 second timeout, my monitoring client disconnets, and so its un-accept()ed connection sits in the kernel's listen queue as CLOSE_WAIT, and every second a new one got added).

    You can read more about it here:

    It was difficult to figure out because mmap access does not show up in strace. Avoid mmap when you can, it's invisible and thus hard to debug!

    Also scrutinise any libraries for unsafe calls, even if they only do memcpy; if they accept an arbitrary-sized ByteString, they will block your entire process until they are done.


    This does not imply that there are no further buts in network or warp, just that I found one certain cause of the Haskell process freezing that was a problem in my application.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

Labels

No labels
No labels

Type

No type

Projects

No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions