Layer/Agent can't handle large PUT request

[aviramha]

User runs steal on a rest service written in Go + macOS that receives a big PUT request.
The request gets stuck and rest of the stuff gets timeout (kafka, etc).

Possible issues:

1. maybe we have some blocking logic so it can't answer health check / do anything else while accepting?
2. maybe it's writing/receiving a lot of data causing a busy loop not giving time for other threads to run?
3. ??

[t4lz]

Is it possible to get the logs from that failure?
Is there any information about the application?
Does sending small PUT requests work?

So far I can't reproduce this bug. I can send huge PUT requests and they go through:

% cat target/universal-apple-darwin/debug/libmirrord_layer.dylib | curl -T - localhost:30001/                                                                                                                           
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100  206M    0     3    0  206M      0  2272k --:--:--  0:01:33 --:--:--     0
PUT%                                                                                                                                                                                                                                                                                                                       

I printed the layer's binary and uploaded that with PUT, while stealing with mirrord.

In the logs/output of the app running with mirrord I can see all the data coming in:

2023-02-15T14:06:42.119425Z TRACE ThreadId(06) handle_daemon_message: mirrord_layer: enter daemon_message=TcpSteal(Data(TcpData { connection_id: 1, bytes (length): 4096 }))
2023-02-15T14:06:42.119441Z TRACE ThreadId(06) handle_daemon_message:handle_daemon_message: mirrord_layer::tcp: enter daemon_message=TcpSteal(Data(TcpData { connection_id: 1, bytes (length): 4096 })) Data(TcpData { connection_id: 1, bytes (length): 4096 })
2023-02-15T14:06:42.119459Z TRACE ThreadId(06) handle_daemon_message:handle_daemon_message:handle_new_data: mirrord_layer::tcp_steal: enter daemon_message=TcpSteal(Data(TcpData { connection_id: 1, bytes (length): 4096 })) Data(TcpData { connection_id: 1, bytes (length): 4096 }) data=1
2023-02-15T14:06:42.119501Z TRACE ThreadId(06) handle_daemon_message:handle_daemon_message:handle_new_data: mirrord_layer::tcp_steal: handle_new_data -> writing 4096 bytes to id 1 daemon_message=TcpSteal(Data(TcpData { connection_id: 1, bytes (length): 4096 })) Data(TcpData { connection_id: 1, bytes (length): 4096 }) data=1
2023-02-15T14:06:42.119541Z TRACE ThreadId(06) handle_daemon_message:handle_daemon_message:handle_new_data: mirrord_layer::tcp_steal: exit daemon_message=TcpSteal(Data(TcpData { connection_id: 1, bytes (length): 4096 })) Data(TcpData { connection_id: 1, bytes (length): 4096 }) data=1
2023-02-15T14:06:42.119565Z DEBUG ThreadId(06) handle_daemon_message:handle_daemon_message: mirrord_layer::tcp: handle_incoming_message -> handled Ok(
    (),
) daemon_message=TcpSteal(Data(TcpData { connection_id: 1, bytes (length): 4096 })) Data(TcpData { connection_id: 1, bytes (length): 4096 })
2023-02-15T14:06:42.119595Z TRACE ThreadId(06) handle_daemon_message:handle_daemon_message: mirrord_layer::tcp: exit daemon_message=TcpSteal(Data(TcpData { connection_id: 1, bytes (length): 4096 })) Data(TcpData { connection_id: 1, bytes (length): 4096 })
2023-02-15T14:06:42.119619Z TRACE ThreadId(06) handle_daemon_message: mirrord_layer: exit daemon_message=TcpSteal(Data(TcpData { connection_id: 1, bytes (length): 4096 }))
2023-02-15T14:06:42.119640Z TRACE ThreadId(06) next: mirrord_layer::tcp_steal: enter
2023-02-15T14:06:42.119654Z TRACE ThreadId(06) next: mirrord_layer::tcp_steal: exit
2023-02-15T14:06:42.119682Z TRACE ThreadId(06) handle_daemon_message: mirrord_layer: enter daemon_message=TcpSteal(Data(TcpData { connection_id: 1, bytes (length): 4096 }))
2023-02-15T14:06:42.119703Z TRACE ThreadId(06) handle_daemon_message:handle_daemon_message: mirrord_layer::tcp: enter daemon_message=TcpSteal(Data(TcpData { connection_id: 1, bytes (length): 4096 })) Data(TcpData { connection_id: 1, bytes (length): 4096 })
2023-02-15T14:06:42.119729Z TRACE ThreadId(06) handle_daemon_message:handle_daemon_message:handle_new_data: mirrord_layer::tcp_steal: enter daemon_message=TcpSteal(Data(TcpData { connection_id: 1, bytes (length): 4096 })) Data(TcpData { connection_id: 1, bytes (length): 4096 }) data=1
2023-02-15T14:06:42.119750Z TRACE ThreadId(06) handle_daemon_message:handle_daemon_message:handle_new_data: mirrord_layer::tcp_steal: handle_new_data -> writing 4096 bytes to id 1 daemon_message=TcpSteal(Data(TcpData { connection_id: 1, bytes (length): 4096 })) Data(TcpData { connection_id: 1, bytes (length): 4096 }) data=1
2023-02-15T14:06:42.119782Z TRACE ThreadId(06) handle_daemon_message:handle_daemon_message:handle_new_data: mirrord_layer::tcp_steal: exit daemon_message=TcpSteal(Data(TcpData { connection_id: 1, bytes (length): 4096 })) Data(TcpData { connection_id: 1, bytes (length): 4096 }) data=1
2023-02-15T14:06:42.119807Z DEBUG ThreadId(06) handle_daemon_message:handle_daemon_message: mirrord_layer::tcp: handle_incoming_message -> handled Ok(
    (),
) daemon_message=TcpSteal(Data(TcpData { connection_id: 1, bytes (length): 4096 })) Data(TcpData { connection_id: 1, bytes (length): 4096 })
2023-02-15T14:06:42.119823Z TRACE ThreadId(06) handle_daemon_message:handle_daemon_message: mirrord_layer::tcp: exit daemon_message=TcpSteal(Data(TcpData { connection_id: 1, bytes (length): 4096 })) Data(TcpData { connection_id: 1, bytes (length): 4096 })
2023-02-15T14:06:42.119840Z TRACE ThreadId(06) handle_daemon_message: mirrord_layer: exit daemon_message=TcpSteal(Data(TcpData { connection_id: 1, bytes (length): 4096 }))

...

And the local app prints all that data.
I get back a response and can keep sending requests.

Do we have some more information to work with on this issue?

[aviramha]

Solved with #1092