Websocat in servermode eating a CPU core after closing TCP socket

[vi]

Websocat in servermode eating a CPU core after closing TCP socket

[vi]

What is the websocat command line? Is there -E option? Maybe autoreconnect: is in effect?

[therealprof]

I'm using websocat -vvv -s 8090:

Listening on ws://127.0.0.1:8090/
[INFO  websocat::lints] Auto-inserting the line mode
[DEBUG websocat] Done third phase of interpreting options.
[DEBUG websocat] Done fourth phase of interpreting options.
[DEBUG websocat] Preparation done. Now actually starting.
[INFO  websocat::sessionserve] Serving Message2Line(WsServer(TcpListen(V4(127.0.0.1:8090)))) to BroadcastReuser(Line2Message(Stdio)) with Options { websocket_text_mode: true, websocket_protocol: None, udp_oneshot_mode: false, unidirectional: false, unidirectional_reverse: false, exit_on_eof: true, oneshot: false, unlink_unix_socket: false, exec_args: [], ws_c_uri: "ws://0.0.0.0/", linemode_strip_newlines: false, linemode_strict: false, origin: None, custom_headers: [], websocket_version: None, websocket_dont_close: false, one_message: false, no_auto_linemode: false, buffer_size: 65536, broadcast_queue_len: 16, read_debt_handling: Warn, linemode_zero_terminated: false, restrict_uri: None, serve_static_files: [], exec_set_env: false, reuser_send_zero_msg_on_disconnect: false, process_zero_sighup: false, process_exit_sighup: false, socks_destination: None, auto_socks5: None, socks5_bind_script: None, tls_domain: None, tls_insecure: false, max_parallel_conns: None }

[therealprof]

These are the last lines of output:

[INFO  websocat::ws_server_peer] Upgraded
[INFO  websocat::broadcast_reuse_peer] Reusing
[TRACE websocat::my_copy] poll
[TRACE websocat::my_copy] poll
[TRACE websocat::my_copy] poll
[DEBUG websocat::ws_peer] drop WsWriteWrapper
websocat: WebSocketError: WebSocket data frame error

[vi]

Is it reproducible when using websocat ws://127.0.0.1:8090 as a client and interrupting it with Ctrl+C? What platform is it on? Linux,Windows,Mac,Other?

Debugging output for myself when I start server, connect with another websocat, then terminate it:

$ websocat -vvv -s 8090
Listening on ws://127.0.0.1:8090/
[INFO  websocat::lints] Auto-inserting the line mode
[DEBUG websocat] Done third phase of interpreting options.
[DEBUG websocat] Done fourth phase of interpreting options.
[DEBUG websocat] Preparation done. Now actually starting.
[INFO  websocat::sessionserve] Serving Message2Line(WsServer(TcpListen(V4(127.0.0.1:8090)))) to BroadcastReuser(Line2Message(Stdio)) with Options { websocket_text_mode: true, websocket_protocol: None, udp_oneshot_mode: false, unidirectional: false, unidirectional_reverse: false, exit_on_eof: true, oneshot: false, unlink_unix_socket: false, exec_args: [], ws_c_uri: "ws://0.0.0.0/", linemode_strip_newlines: false, linemode_strict: false, origin: None, custom_headers: [], websocket_version: None, websocket_dont_close: false, one_message: false, no_auto_linemode: false, buffer_size: 65536, broadcast_queue_len: 16, read_debt_handling: Warn, linemode_zero_terminated: false, restrict_uri: None, serve_static_files: [], exec_set_env: false, reuser_send_zero_msg_on_disconnect: false, process_zero_sighup: false, process_exit_sighup: false, socks_destination: None, auto_socks5: None, socks5_bind_script: None, tls_domain: None, tls_insecure: false, max_parallel_conns: None }
[INFO  websocat::net_peer] Incoming TCP connection from Some(V4(127.0.0.1:47864))
[DEBUG websocat::sessionserve] Underlying connection established
[INFO  websocat::sessionserve] Serving 1 ongoing connections
[INFO  websocat::ws_server_peer] Incoming connection to websocket: /
[DEBUG websocat::ws_server_peer] Incoming { version: Http11, subject: (Get, AbsolutePath("/")), headers: Headers { Host: 127.0.0.1:8090
, Connection: Upgrade
, Upgrade: websocket
, Sec-WebSocket-Version: 13
, Sec-WebSocket-Key: smVW/7cfNRxR3xDJ6S6a+Q==
, } }
[DEBUG websocat::ws_server_peer] Headers { }
[DEBUG websocat::ws_server_peer] Headers { Sec-WebSocket-Accept: y+RH4hFg6GFtCQKH//rfTJpuqZ8=
, Connection: Upgrade
, Upgrade: websocket
, }
[INFO  websocat::ws_server_peer] Upgraded
[INFO  websocat::broadcast_reuse_peer] Initializing
[INFO  websocat::stdio_peer] get_stdio_peer (async)
[INFO  websocat::stdio_peer] Setting stdin to nonblocking mode
[INFO  websocat::stdio_peer] Installing signal handler
[DEBUG websocat::ws_peer] incoming text
asdf
[DEBUG websocat::ws_peer] incoming text
safddsf
[DEBUG websocat::ws_peer] incoming None
[DEBUG websocat::my_copy] BrokenPipe: read_done
[DEBUG websocat::my_copy] done
[INFO  websocat::sessionserve] Forward finished
[INFO  websocat::sessionserve] Forward shutdown finished
[INFO  websocat::sessionserve] One of directions finished
[DEBUG websocat::ws_peer] drop WsWriteWrapper

[therealprof]

Is it reproducible when using websocat ws://127.0.0.1:8090 as a client and interrupting it with Ctrl+C?

Yes.

What platform is it on? Linux,Windows,Mac,Other?

Mac

[vi]

Seems to be not reproducible on Linux; I'll try on Mac later.

Which version of Websocat do you use? 1.3.0? Is it also reproducible with 1.2.0 or 1.1.0?

[therealprof]

I haven't tried older versions, only 1.3.0. I also tried bumping all dependencies (except hyper which is API incompatible) but no change.

[vi]

Tried on Mac myself for 1.3.0 and 1.2.0 and can't easily reproduce it.

Are you building websocat yourself or using Github release?

[therealprof]

cargo installed it.

[therealprof]

Same behaviour with websocat_mac downloaded from GitHub, though.

[vi]

Is it the same for https://github.com/vi/websocat/releases/download/v1.3.0/websocat_mac?

Looks like yes...

[vi]

Does it accept new connections while busy looping after bug?

[vi]

Is it the same for older websocat like https://github.com/vi/websocat/releases/download/v1.1.0/websocat_mac

[vi]

Can you try to dtruss it? Which syscalls are invoked before and when it is busy looping?

[therealprof]

Same thing for v1.1.0. But I'm afraid I don't really have time to deeply analyse it right now.

[vi]

What version of OS X?

We can analyse it later; I'm not sure how to address it by myself (I'm not a Mac user in general).

One of experiments: running websocat -t -E tcp-l:127.0.0.1:8090 - (i.e. just a TCP server, not WebSocket server) and checking if the bug can be still triggered.

[therealprof]

macOS 10.12.6

[therealprof]

websocat -t -E tcp-l:127.0.0.1:8090 - -> same problem

[vi]

So the problem seems to be independent of WebSockets.

Can you try running this TCP echo server: https://github.com/tokio-rs/tokio/blob/master/examples/echo.rs and checking if has the problem (not necessary now, when you have time for this). If needed I can make a pre-built version.