A stress test on my SMTP server show me an unknow error #456
Comments
|
(a) the (netif) |
|
Thanks for (b), I'm currently try to stress test and use |
|
Come back with few outcomes. I tried to use However, with the help from @icristescu and the great tool from @zshipko (see And it seems that we found a correlation between our The comment above the function seems clear that a dragon is here! At this stage, I don't really know what we need to do but it seems clear that the problem is systemic where |
|
I'm not sure how memtrace adds sources to allocations. What is a thing is that |
|
So, thinking out loud - if the Lwt tasks are a bottleneck, eventually we should revise the design. I had in my head for some time (similar to what UNIX does), what about:
|
It seems that in my context, I need to investigate deeper because between my SMTP stack and |
|
Just to be clear, this graph comes from
It seems clear that allocations from |
|
Come back with some news, the problem about the
So I updated my workflow to count fibers and it seems that:
Now the question is to find the execution path where something never terminate and keep the given |
|
A get some outcomes, it seems that some fibers does not terminates and all of them correspond to a So we can start to figure out which execution path we took from these packets and find our infinite loop! |
|
@dinosaure that's a very interesting clue! Do you think we're receiving RST packets and then getting stuck handling them? Perhaps the TCP stack is sending addtional data by mistake after the send direction has been officially closed with FIN, prompting the remote to send back a RST, causing us to get stuck? It might be worth looking at some packet traces with wireshark to look for anomalies. Maybe it's 2 bugs: 1 bug causing the remote to send a RST as an error, and bug 2 in our handling of RST? |
|
This is finally the context where the fiber never terminates (note that the client use the Unix socket): The last packet is the packet where the fiber never terminates. |
|
With the really nice help of @djs55, we figure out that something bad happens when the connection want to be closed. We discovered some spurious A possible explanation exists (but I'm not confident with the reality). The fact is that my client did not close properly the connection and when it terminates, it seems that the kernel (it's a simple Unix socket) decides to craft the RST packet for us (from So I decided to fix my client and properly close the connection and the situation is worse. Now, the client wants to send an I will try to figure out why such packet appears from the client now. |
|
I found the issue FINALLY 🎉 ! It seems that this specific line never terminates: mirage-tcpip/src/tcp/segment.ml Line 221 in 3e9c163 I don't really know what that means... |
|
It seems that this is not the only path where the fiber can block, I found some situation where it reaches this point: mirage-tcpip/src/tcp/segment.ml Lines 206 to 207 in 3e9c163 And the fiber never terminates in this situation too. |
|
So I can confirm that this is where we have our memory leak (/cc @hannesm) as far your application does not leak. An hot fix about that is: diff --git a/src/tcp/segment.ml b/src/tcp/segment.ml
index 0394c5fa..466ec30a 100644
--- a/src/tcp/segment.ml
+++ b/src/tcp/segment.ml
@@ -204,7 +204,9 @@ module Rx(Time:Mirage_time.S) = struct
in
tx_ack <&> urx_inform
| `ChallengeAck ->
- send_challenge_ack q
+ if Lwt_mvar.is_empty q.rx_data
+ then send_challenge_ack q
+ else Lwt.return_unit
| `Drop ->
Lwt.return_unit
| `Reset ->
@@ -218,7 +220,9 @@ module Rx(Time:Mirage_time.S) = struct
in
txalert (Window.ack_serviced q.wnd) >>= fun () ->
(* Use the fin path to inform the application of end of stream *)
- Lwt_mvar.put q.rx_data (None, Some Sequence.zero)
+ if Lwt_mvar.is_empty q.rx_data
+ then Lwt_mvar.put q.rx_data (None, Some Sequence.zero)
+ else Lwt.return_unit
end
(* Transmitted segments are sent in-order, and may also be markedHowever, I still have some leaks in some context, at least I got one. If someone who knows better about |
|
Thanks for the investigations @dinosaure. I've to pass on the current TCP stack / what the segment module is doing. If your patch fixes the memory issue you encounter, I'd be in favour to push and release that. |
|
I need to investigate more (but I will do next week probably - vacation) because |
|
I can confirm that the current patch fix the memory leak for |
|
My last experiment show that we still have a leak on
Some is about ACK, some about [FIN, PSH, ACK] [TCP segment of a reassembled PDU] and all of them come from On the application level, I can assert that every EDIT: I generated few graph like below for my module and none of them leak a memory like That mostly mean that at one point, |
|
Wow! This is an extremely well done investigation. Much appreciation to you @dinosaure for your tenaciousness. It's been a long time since I saw this code so please pardon my slowness. My first thought was that the RST path had been very under-tested so it's not surprising that there are problems. There may be more than one leak here but the one you identified when multiple valid RST segments are received, is definitely a problem. The suggested fix of checking if the rx_data mvar is empty before putting it will probably not always work. It will only work if the RST segments are timed so that the second and later ones are prevented from causing the mvar put because the first has not yet been taken. If the RST segment arrivals are timed so the mvar put from the first RST gets processed, which means that the thread that takes the mvar terminates, and then after that if a valid RST arrives causing a put, the mvar would never get read and it would be a leak. I think the fix should involve the state machine where once one valid RST segment is accepted no further RSTs should be accepted. Would it be possible for you to test the following changes. There are two changes below, could you try them separately too? Unfortunately I don't have a functioning environment for mirage right now. |
|
Hi @balrajsingh, Firstly, thank you for your time to help us to investigate this memory leak. It's not easy to go deeper in this codebase. From what you explain, I think you highlight the reason about why, even with my initial patch, I still continue to have the memory leak. Then, I relaunched my huge test (which is: send ONE MILLION emails to the server) with your patch and it's seems that we don't have any memory leaks 🎉 ! I get an other problem (which is more about the time spent to try a connection which is long and put a pressure on the GC which is not allowed to release resource until we fail) but it's no more about So really thank you to help us about that because it unlock us about sustainability of many of our services (such as the SMTP service). Hope that this patch will solve the issue discovered by @hannesm before too. I will definitely propose a PR to integrate your patch (with you as an author) and cut a release. WDYT? And again, big thanks! |
|
Hooray! That is most excellent @dinosaure. It's really great to hear that it worked. Yes please do propose a PR, I feel quite comfortable with fixing the multiple valid RST problem in this way. About memory use when lots of connections are being tried, and re-tried when some fail due to packet loss, that is just the way that this design works. It does try to delay creating all the required threads and data structures till a connection is almost ready to be in the Established state, but still the minimum that it allocates for each connection as it attempts to reach the Established state will add up. We may need some clever design improvement to somehow not use any memory at all till the connection is fully ready to be Established. At the same time, it could just be considered one of the capacity limits for this stack - as long as the limit is high enough it is probably ok. |
|
Thanks everybody for this fix 👍! |
CHANGES: * Fix memory leak in processing RST packets (mirage/mirage-tcpip#460 @balrajsingh, reported in mirage/mirage-tcpip#456 by @dinosaure) * Move module types (IP, UDP, TCP, STACK, ICMP) into tcpip core library (mirage/mirage-tcpip#463 @hannesm) * API breakage: Tcpip_checksum is now part of tcpip.checksum (used to be part of tcpip mirage/mirage-tcpip#463 @hannesm) * API breakage: tcpip.unix has been removed (mirage/mirage-tcpip#463 @hannesm) * Use Lwt.pause instead of deprecated Lwt_{unix,main}.yield (mirage/mirage-tcpip#461 @dinosaure)
CHANGES: * Fix memory leak in processing RST packets (mirage/mirage-tcpip#460 @balrajsingh, reported in mirage/mirage-tcpip#456 by @dinosaure) * Move module types (IP, UDP, TCP, STACK, ICMP) into tcpip core library (mirage/mirage-tcpip#463 @hannesm) * API breakage: Tcpip_checksum is now part of tcpip.checksum (used to be part of tcpip mirage/mirage-tcpip#463 @hannesm) * API breakage: tcpip.unix has been removed (mirage/mirage-tcpip#463 @hannesm) * Use Lwt.pause instead of deprecated Lwt_{unix,main}.yield (mirage/mirage-tcpip#461 @dinosaure)
When I try to stress-test my SMTP server which mostly retransmit an incoming email to an other point, I got this error message:
I'm not sure about what such error refers, someone knows about such error? And in which context it appears? Currently, you can reproduce it with these unikernels: https://github.com/dinosaure/ptt/tree/master/unikernel
Btw, is it possible to test locally without Solo5 the
mirage-tcpipstack (not the unix/socket one)?The text was updated successfully, but these errors were encountered: