Open myzhang1029 opened 5 months ago
Okay #31 is probably not the cause. New observation: the tasks get orphaned only when iperf3
closes the connection, so the two problems mentioned here might be the same one.
It was noted that the loss of waker is easier to reproduce with iperf3 --bidir
over public internet. penguin
also breaks it: WARNING: Size of data read does not correspond to offered length
This specific bug is because the server iperf3
I am using does not support --bidir
. It still reveals some problems about our implementation of Rst
(it does not seem to propagate properly). Probably the cause.
2024-03-24T20:52:34.801760Z ERROR penguin_mux::stream: Polling write 25153
2024-03-24T20:52:34.866441Z ERROR process_message:close_port: penguin_mux::inner: No writer to wake at port 36990
2024-03-24T20:52:34.866484Z DEBUG process_message:close_port: penguin_mux::inner: freed connection 36990 -> 20252
2024-03-24T20:52:34.866532Z ERROR process_message:close_port: penguin_mux::inner: Bogus free 36990 -> 20252
2024-03-24T20:52:34.866568Z ERROR process_message:close_port: penguin_mux::inner: Bogus free 36990 -> 20252
2024-03-24T20:52:34.866601Z ERROR process_message:close_port: penguin_mux::inner: Bogus free 36990 -> 20252
2024-03-24T20:52:34.866636Z ERROR process_message:close_port: penguin_mux::inner: Bogus free 36990 -> 20252
2024-03-24T20:52:34.866681Z ERROR process_message:close_port: penguin_mux::inner: Bogus free 36990 -> 20252
2024-03-24T20:52:34.866715Z ERROR process_message:close_port: penguin_mux::inner: Bogus free 36990 -> 20252
2024-03-24T20:52:34.866748Z ERROR process_message:close_port: penguin_mux::inner: Bogus free 36990 -> 20252
2024-03-24T20:52:34.866782Z ERROR process_message:close_port: penguin_mux::inner: Bogus free 36990 -> 20252
2024-03-24T20:52:34.945912Z ERROR process_message:close_port: penguin_mux::inner: Bogus free 36990 -> 20252
2024-03-24T20:52:34.946020Z ERROR process_message:close_port: penguin_mux::inner: Bogus free 36990 -> 20252
2024-03-24T20:52:34.946075Z ERROR process_message:close_port: penguin_mux::inner: Bogus free 36990 -> 20252
2024-03-24T20:52:34.946127Z ERROR process_message:close_port: penguin_mux::inner: Bogus free 36990 -> 20252
2024-03-24T20:52:34.946178Z ERROR process_message:close_port: penguin_mux::inner: Bogus free 36990 -> 20252
2024-03-24T20:52:34.946229Z ERROR process_message:close_port: penguin_mux::inner: Bogus free 36990 -> 20252
2024-03-24T20:52:34.946279Z ERROR process_message:close_port: penguin_mux::inner: Bogus free 36990 -> 20252
2024-03-24T20:52:34.946345Z ERROR process_message:close_port: penguin_mux::inner: Bogus free 36990 -> 20252
2024-03-24T20:52:34.946396Z ERROR process_message:close_port: penguin_mux::inner: Bogus free 36990 -> 20252
2024-03-24T20:52:34.946514Z ERROR process_message:close_port: penguin_mux::inner: Bogus free 36990 -> 20252
2024-03-24T20:52:34.946568Z ERROR process_message:close_port: penguin_mux::inner: Bogus free 36990 -> 20252
2024-03-24T20:52:34.946620Z ERROR process_message:close_port: penguin_mux::inner: Bogus free 36990 -> 20252
2024-03-24T20:52:34.946668Z ERROR process_message:close_port: penguin_mux::inner: Bogus free 36990 -> 20252
2024-03-24T20:52:34.946716Z ERROR process_message:close_port: penguin_mux::inner: Bogus free 36990 -> 20252
2024-03-24T20:52:34.947179Z ERROR penguin_mux::stream: Port dropped: 48196 -> 63288
2024-03-24T20:52:34.947281Z ERROR penguin_mux::inner: Dropped 48196 -> 63288
2024-03-24T20:52:34.947379Z ERROR close_port: penguin_mux::inner: No writer to wake at port 48196
2024-03-24T20:52:34.947390Z DEBUG close_port: penguin_mux::inner: freed connection 48196 -> 63288
2024-03-24T20:52:34.947480Z ERROR penguin_mux::stream: Polling write 25153
2024-03-24T20:52:34.947550Z ERROR penguin_mux::stream: Port dropped: 25153 -> 49143
2024-03-24T20:52:34.947575Z ERROR penguin_mux::inner: Dropped 25153 -> 49143
2024-03-24T20:52:34.947629Z ERROR close_port: penguin_mux::inner: No writer to wake at port 25153
2024-03-24T20:52:34.947637Z DEBUG close_port: penguin_mux::inner: freed connection 25153 -> 49143
And using tokio_unstable
named tasks does show that the task losing the waker is the one getting Rst
floods.
Noticed that the corresponding MuxStream
was never Drop
ped.
I'm starting to think that using LockedWebSocket
itself is wrong. When multiple tasks poll AsyncRW and get proxied to poll_x of the web socket, only the last one will be woken if the result is Pending
. I'll need to restructure it to use message passing to/from a dedicated task for correct behaviour.
iperf3
almost always causes aBroken pipe (os error 32)
or aSocket is not connected (os error 57)
Upon exit, it causes an excessive amount ofRst
server -> client.Occasionally
tokio-console
displays atasks have lost their waker
from one ofdepending on if I ran
iperf3
on a direct remote orproxychains4 iperf3
on a socks remote. Most likely due toAtomicWaker
being overwritten.None of these happen when forwarding regular traffic like HTTP(S) and SSH.