Page 1 of 1

Websocket server Failed to read header byte (socket FD invalid)

Posted: Sun Jan 08, 2023 11:44 am
by dizcza
I'm trying to publish json data to all connected clients from my ESP32 board.

When I open the server page from Firefox, I see the following logs:

Code: Select all

opened [object WebSocket]
The connection to ws://192.168.3.62/ was interrupted while the page was loading.
And the corresponding logs on the ESP side:

Code: Select all

I (7024) ws_echo_server: Starting server on port: '80'
I (7034) ws_echo_server: Registering URI handlers
D (7034) httpd: httpd_thread: web server started
D (7034) httpd: httpd_server: doing select maxfd+1 = 56
D (7044) httpd_uri: httpd_register_uri_handler: [0] installed /
I (7044) ws_echo_server: Websocket server started
I (7054) bsp: httpd-my timer started
D (17234) httpd: httpd_server: processing listen socket 54
D (17234) httpd: httpd_accept_conn: newfd = 57
D (17244) httpd_sess: httpd_sess_new: fd = 57
I (17244) ws_echo_server: Handle hd=0x3ffc5bcc: opening websocket fd=57
D (17244) httpd_sess: httpd_sess_new: active sockets: 1
D (17254) httpd: httpd_accept_conn: complete
D (17254) httpd: httpd_server: doing select maxfd+1 = 58
D (17264) httpd: httpd_process_session: processing socket 57
D (17274) httpd_sess: httpd_sess_process: httpd_req_new
D (17274) httpd_parse: httpd_req_new: New request, has WS? No, sd->ws_handler valid? No, sd->ws_close? No
D (17284) httpd_txrx: httpd_recv_with_opt: requested length = 128
D (17294) httpd_txrx: httpd_recv_with_opt: received length = 128
D (17294) httpd_parse: read_block: received HTTP request block size = 128
D (17304) httpd_parse: cb_url: message begin
D (17304) httpd_parse: cb_url: processing url = /
D (17314) httpd_parse: verify_url: received URI = /
D (17314) httpd_parse: cb_header_field: headers begin
D (17324) httpd_txrx: httpd_unrecv: length = 112
D (17324) httpd_parse: pause_parsing: paused
D (17334) httpd_parse: cb_header_field: processing field = Host
D (17334) httpd_txrx: httpd_recv_with_opt: requested length = 128
D (17344) httpd_txrx: httpd_recv_with_opt: pending length = 112
D (17354) httpd_parse: read_block: received HTTP request block size = 112
D (17354) httpd_parse: continue_parsing: skip pre-parsed data of size = 5
D (17364) httpd_parse: continue_parsing: un-paused
D (17364) httpd_parse: cb_header_value: processing value = 192.168.3.62
D (17374) httpd_parse: cb_header_field: processing field = User-Agent
D (17384) httpd_parse: cb_header_value: processing value = Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:108.0) Gecko/20100101 Firefox/108.0
D (17394) httpd_parse: parse_block: parsed block size = 112
D (17404) httpd_txrx: httpd_recv_with_opt: requested length = 128
D (17404) httpd_txrx: httpd_recv_with_opt: received length = 128
D (17414) httpd_parse: read_block: received HTTP request block size = 128
D (17414) httpd_parse: cb_header_field: processing field = Accept
D (17424) httpd_parse: cb_header_value: processing value = text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,*/*;q=0.8
D (17434) httpd_parse: cb_header_field: processing field = Accept-Language
D (17444) httpd_parse: cb_header_value: processing value = en-US,en;q=0.5
D (17454) httpd_parse: parse_block: parsed block size = 240
D (17454) httpd_txrx: httpd_recv_with_opt: requested length = 128
D (17464) httpd_txrx: httpd_recv_with_opt: received length = 88
D (17474) httpd_parse: read_block: received HTTP request block size = 88
D (17474) httpd_parse: cb_header_field: processing field = Accept-Encoding
D (17484) httpd_parse: cb_header_value: processing value = gzip, deflate
D (17494) httpd_parse: cb_header_field: processing field = Connection
D (17494) httpd_parse: cb_header_value: processing value = keep-alive
D (17504) httpd_parse: cb_header_field: processing field = Upgrade-Insecure-Requests
D (17514) httpd_parse: cb_header_value: processing value = 1
D (17514) httpd_parse: cb_headers_complete: bytes read     = 344
D (17524) httpd_parse: cb_headers_complete: content length = 0
D (17524) httpd_parse: pause_parsing: paused
D (17534) httpd_parse: cb_no_body: message complete
D (17534) httpd_parse: httpd_parse_req: parsing complete
D (17544) httpd_uri: httpd_uri: request for / with type 1
D (17544) httpd_uri: httpd_find_uri_handler: [0] = /
I (17554) ws_echo_server: Handshake done, the new connection was opened
D (17564) httpd_txrx: httpd_send_all: sent = 64
D (17564) httpd_txrx: httpd_send_all: sent = 2
D (17574) httpd_txrx: httpd_send_all: sent = 1224
D (17574) httpd_sess: httpd_sess_process: httpd_req_delete
D (17584) httpd_sess: httpd_sess_process: success
D (17584) httpd: httpd_server: doing select maxfd+1 = 58
D (17594) httpd: httpd_server: processing listen socket 54
D (17594) httpd: httpd_accept_conn: newfd = 58
D (17604) httpd_sess: httpd_sess_new: fd = 58
I (17604) ws_echo_server: Handle hd=0x3ffc5bcc: opening websocket fd=58
D (17614) httpd_sess: httpd_sess_new: active sockets: 2
D (17614) httpd: httpd_accept_conn: complete
D (17624) httpd: httpd_server: doing select maxfd+1 = 59
D (17624) httpd: httpd_process_session: processing socket 58
D (17634) httpd_sess: httpd_sess_process: httpd_req_new
D (17634) httpd_parse: httpd_req_new: New request, has WS? No, sd->ws_handler valid? No, sd->ws_close? No
D (17644) httpd_txrx: httpd_recv_with_opt: requested length = 128
D (17654) httpd_txrx: httpd_recv_with_opt: received length = 128
D (17664) httpd_parse: read_block: received HTTP request block size = 128
D (17664) httpd_parse: cb_url: message begin
D (17674) httpd_parse: cb_url: processing url = /
D (17674) httpd_parse: verify_url: received URI = /
D (17684) httpd_parse: cb_header_field: headers begin
D (17684) httpd_txrx: httpd_unrecv: length = 112
D (17694) httpd_parse: pause_parsing: paused
D (17694) httpd_parse: cb_header_field: processing field = Host
D (17704) httpd_txrx: httpd_recv_with_opt: requested length = 128
D (17704) httpd_txrx: httpd_recv_with_opt: pending length = 112
D (17714) httpd_parse: read_block: received HTTP request block size = 112
D (17724) httpd_parse: continue_parsing: skip pre-parsed data of size = 5
D (17724) httpd_parse: continue_parsing: un-paused
D (17734) httpd_parse: cb_header_value: processing value = 192.168.3.62
D (17744) httpd_parse: cb_header_field: processing field = User-Agent
D (17744) httpd_parse: cb_header_value: processing value = Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:108.0) Gecko/20100101 Firefox/108.0
D (17754) httpd_parse: parse_block: parsed block size = 112
D (17764) httpd_txrx: httpd_recv_with_opt: requested length = 128
D (17774) httpd_txrx: httpd_recv_with_opt: received length = 128
D (17774) httpd_parse: read_block: received HTTP request block size = 128
D (17784) httpd_parse: cb_header_field: processing field = Accept
D (17784) httpd_parse: cb_header_value: processing value = */*
D (17794) httpd_parse: cb_header_field: processing field = Accept-Language
D (17804) httpd_parse: cb_header_value: processing value = en-US,en;q=0.5
D (17804) httpd_parse: cb_header_field: processing field = Accept-Encoding
D (17814) httpd_parse: cb_header_value: processing value = gzip, deflate
D (17824) httpd_parse: cb_header_field: processing field = Sec-WebSocket-Version
D (17834) httpd_parse: cb_header_value: processing value = 13
D (17834) httpd_parse: cb_header_field: processing field = Origin
D (17844) httpd_parse: cb_header_value: processing value = http://192.168.
D (17844) httpd_parse: parse_block: parsed block size = 240
D (17854) httpd_txrx: httpd_recv_with_opt: requested length = 128
D (17864) httpd_txrx: httpd_recv_with_opt: received length = 128
D (17864) httpd_parse: read_block: received HTTP request block size = 128
D (17874) httpd_parse: cb_header_value: processing value = 3.62
D (17884) httpd_parse: cb_header_field: processing field = Sec-WebSocket-Extensions
D (17884) httpd_parse: cb_header_value: processing value = permessage-deflate
D (17894) httpd_parse: cb_header_field: processing field = Sec-WebSocket-Key
D (17904) httpd_parse: cb_header_value: processing value = TcVmVF5xRAjn3b2GxQEH8g==
D (17914) httpd_parse: cb_header_field: processing field = Connection
D (17914) httpd_parse: cb_header_value: processing value = keep-alive, Upgrade
D (17924) httpd_parse: parse_block: parsed block size = 368
D (17924) httpd_txrx: httpd_recv_with_opt: requested length = 128
D (17934) httpd_txrx: httpd_recv_with_opt: received length = 67
D (17944) httpd_parse: read_block: received HTTP request block size = 67
D (17944) httpd_parse: cb_header_value: processing value = 
D (17954) httpd_parse: cb_header_field: processing field = Pragma
D (17964) httpd_parse: cb_header_value: processing value = no-cache
D (17964) httpd_parse: cb_header_field: processing field = Cache-Control
D (17974) httpd_parse: cb_header_value: processing value = no-cache
D (17974) httpd_parse: cb_header_field: processing field = Upgrade
D (17984) httpd_parse: cb_header_value: processing value = websocket
D (17994) httpd_parse: cb_headers_complete: bytes read     = 453
D (17994) httpd_parse: cb_headers_complete: content length = 0
D (18004) httpd_parse: cb_headers_complete: Got an upgrade request
D (18014) httpd_parse: pause_parsing: paused
D (18014) httpd_parse: cb_no_body: message complete
D (18014) httpd_parse: httpd_parse_req: parsing complete
D (18024) httpd_uri: httpd_uri: request for / with type 1
D (18034) httpd_uri: httpd_find_uri_handler: [0] = /
D (18034) httpd_uri: httpd_uri: Responding WS handshake to sock 58
D (18044) httpd_ws: httpd_ws_respond_server_handshake: Server key before encoding: TcVmVF5xRAjn3b2GxQEH8g==258EAFA5-E914-47DA-95CA-C5AB0DC85B11
I (18054) ws_echo_server: Client type=1 fd=57
I (18054) ws_echo_server: Client type=1 fd=58
D (18064) httpd_ws: httpd_ws_respond_server_handshake: Generated server key: 9W/eJ2hmKdrS0FawDB2hNRayfUU=
I (18074) ws_echo_server: Handshake done, the new connection was opened
D (18084) httpd_txrx: httpd_send_all: sent = 64
W (18084) wifi:<ba-add>idx:0 (ifx:0, 60:aa:ef:13:aa:68), tid:0, ssn:31, winSize:64
D (18094) httpd_txrx: httpd_send_all: sent = 2
D (18094) httpd_txrx: httpd_send_all: sent = 1224
D (18104) httpd_sess: httpd_sess_process: httpd_req_delete
D (18104) httpd_sess: httpd_sess_process: success
D (18114) httpd: httpd_server: doing select maxfd+1 = 59
D (18114) httpd: httpd_process_session: processing socket 58
D (18124) httpd_sess: httpd_sess_process: httpd_req_new
D (18124) httpd_parse: httpd_req_new: New request, has WS? Yes, sd->ws_handler valid? Yes, sd->ws_close? No
D (18134) httpd_txrx: httpd_recv_with_opt: requested length = 1
D (18144) httpd_txrx: httpd_recv_with_opt: received length = 0
W (18154) httpd_ws: httpd_ws_get_frame_type: Failed to read header byte (socket FD invalid), closing socket now
D (18164) httpd_parse: httpd_req_new: New WS request from existing socket, ws_type=8
D (18174) httpd_sess: httpd_sess_process: httpd_req_delete
D (18174) httpd_parse: httpd_req_cleanup: Try closing WS connection at FD: 58
D (18184) httpd_sess: httpd_sess_process: success
D (18184) httpd: httpd_server: doing select maxfd+1 = 59
D (18194) httpd: httpd_server: processing ctrl message
D (18194) httpd: httpd_process_ctrl_msg: work
D (18204) httpd_sess: httpd_sess_delete: fd = 58
I (18204) ws_echo_server: Handle hd=0x3ffc5bcc: closing websocket fd=58
D (18214) httpd_sess: httpd_sess_delete: active sockets: 1
D (18224) httpd: httpd_server: doing select maxfd+1 = 58
I (19054) ws_echo_server: Client type=1 fd=57
I (20054) ws_echo_server: Client type=1 fd=57
I (21054) ws_echo_server: Client type=1 fd=57
I (22054) ws_echo_server: Client type=1 fd=57
I (23054) ws_echo_server: Client type=1 fd=57
I (24054) ws_echo_server: Client type=1 fd=57
I (25054) ws_echo_server: Client type=1 fd=57
I (26054) ws_echo_server: Client type=1 fd=57
I (27054) ws_echo_server: Client type=1 fd=57
So only one HTTP client is opened, and WS client (descriptor) is closed immediately.

There is a line in the logs

Code: Select all

W (18154) httpd_ws: httpd_ws_get_frame_type: Failed to read header byte (socket FD invalid), closing socket now
and I don't know how to fix it.

The full project code is here: https://github.com/dizcza/ws_echo_server

In the end, I want to see how the random numbers are updated on the page each second without reloading the page. The HTLM file is in the repo as well: https://github.com/dizcza/ws_echo_serve ... /root.html

----

The issue is somewhat similar to viewtopic.php?f=13&t=16501&start=10 in a way that Firefox opens two websockets per connection if I'm not mistaken. But the discussion in the pointed link eventually drifted to another issue and the error was not solved for browsers. I need browsers to work with the ESP webserver.