[Libwebsockets] Connection issue since uWebSockets server starts accepting permessage-deflate; client_no_context_takeover extensions

Olivier Langlois olivier at olivierlanglois.net
Thu Nov 12 20:57:13 CET 2020


I have recompiled lws in Debug to get more details about my problem...
Not what I was looking for but maybe worth sharing...

I get this trace with the debug build:
[2020-11-12 14:29:46] INFO WSCONT/log_emit_function 76192:  permessage-
deflate requires the protocol (kraken-priv) to have an RX buffer >= 128

The weird thing is that this trace is enabled in the Release build but
doesn't appear in the release run.

This tells me that

context->pt_serv_buf_size
or
wsi->protocol->rx_buffer_size

is assigned a different value in debug than in release build.

This is unexpected...

I think that I did found my problem...

It comes from the fact that I derived my code from
lws_minimal_client_echo.c

where:

#define RING_DEPTH 1024

#define LWS_PLUGIN_PROTOCOL_MINIMAL_CLIENT_ECHO \
	{ \
		"lws-minimal-client-echo", \
		callback_minimal_client_echo, \
		sizeof(struct per_session_data__minimal_client_echo),
\
		1024, \
		0, NULL, 0 \
	}

I did 2 consecutive changes spaced by some period of time so they went
unnoticed.

First, I did observeve that the protocol rx_buffer_size was the same
value than RING_DEPTH, therefore, I did set my protocol rx_buffer_size
to RING_DEPTH.

Next, I did figured that my application wasn't sending out that much
messages therefore, I did change my RING_DEPTH value to 16...

This makes my lws usage incredibly inefficient as my callback is called
for every 16 bytes received and also pmd ext code doesn't like the
value at all... 

On Thu, 2020-11-12 at 10:26 -0500, Olivier Langlois wrote:
> Maybe something relevant to my problem. I took the code directly from
> lws client example and there is this code that I don't quite fully
> understand the implications...
> 
>     if (pss->write_consume_pending) {
>         /* perform the deferred fifo consume */
>         lws_ring_consume_single_tail(pss->ring, &pss->tail, 1);
>         pss->write_consume_pending = 0;
>     }
> ...
>     /*
>      * Workaround deferred deflate in pmd extension by only
>      * consuming the fifo entry when we are certain it has been
>      * fully deflated at the next WRITABLE callback.  You only need
>      * this if you're using pmd.
>      */
>     pss->write_consume_pending = 1;
>     lws_callback_on_writable(wsi);
> 
> On Thu, 2020-11-12 at 10:12 -0500, Olivier Langlois wrote:
> > Hi,
> > 
> > I have a lws client app that did work flawlessly for months.
> > Yesterday,
> > the protocol server got upgraded and the only difference that I can
> > see
> > is that now they are accepting ws extensions that my client did
> > always
> > offer.
> > 
> > The server is using https://github.com/uNetworking/uWebSockets
> > at least v.0.17.6 as can be seen in the server reply header
> > https://github.com/uNetworking/uWebSockets/releases/tag/v0.17.6
> > 
> > before yesterday upgrade, I suppose that they were using an older
> > release not supporting those extensions as the only mention of
> > uWbeSockets in the header was:
> > WebSocket-Server: uWebSockets
> > 
> > Here is the sequence of events:
> > 1. WS HS completes successfully
> > 2. Server sends a greeting message
> > 3. LWS client sends back 2 messages which are written successfully
> > 4. I would expect a server reply instead but I get
> > 
> > [2020-11-12 09:46:02] INFO WSCONT/log_emit_function 66220:
> > lws_ws_handshake_client: client_rx_sm exited, DROPPING 32
> > 
> > I will continue investigating but does someone has any idea what
> > 'client_rx_sm exited, DROPPING 32' means?
> > 
> > Here are the relevant collected debug logs:
> > [2020-11-12 09:46:01] INFO WSCONT/log_emit_function 66220: client
> > request:
> > GET / HTTP/1.1
> > Pragma: no-cache
> > Cache-Control: no-cache
> > Host: ws-auth.kraken.com:443
> > Upgrade: websocket
> > Connection: Upgrade
> > Sec-WebSocket-Key: SSG1YjpFWcFcL0qQD6BWpA==
> > Sec-WebSocket-Extensions: permessage-deflate;
> > client_no_context_takeover; client_max_window_bits
> > Sec-WebSocket-Version: 13
> > 
> > [2020-11-12 09:46:02] INFO WSCONT/log_emit_function 66220: Server
> > reply:
> > HTTP/1.1 101 Switching Protocols
> > Date: Thu, 12 Nov 2020 14:46:02 GMT
> > Connection: upgrade
> > Upgrade: websocket
> > Sec-WebSocket-Accept: nY2mx8XMJCxUurJJOWwZy2MsIpg=
> > Sec-WebSocket-Extensions: permessage-deflate;
> > client_no_context_takeover
> > uWebSockets: 17
> > CF-Cache-Status: DYNAMIC
> > Expect-CT: max-age=604800, report-
> > uri="https://report-uri.cloudflare.com/cdn-cgi/beacon/expect-ct"
> > Server: cloudflare
> > CF-RAY: 5f110a463ebc3fab-YUL
> > 
> > 
> > [2020-11-12 09:46:02] INFO WSBASE/callback
> > LWS_CALLBACK_ESTABLISHED_CLIENT_HTTP: 66220
> > [2020-11-12 09:46:02] INFO WSCONT/log_emit_function 66220: checking
> > client ext permessage-deflate
> > 
> > [2020-11-12 09:46:02] INFO WSCONT/log_emit_function 66220:
> > instantiating client ext permessage-deflate
> > 
> > [2020-11-12 09:46:02] INFO WSBASE/callback
> > LWS_CALLBACK_CLIENT_ESTABLISHED: 66220
> > [2020-11-12 09:46:02] DBUG WSBASE/client_receive
> > LWS_CALLBACK_CLIENT_RECEIVE:   16 (rpp    80, first 1, final 0, bin
> > 0)
> > [2020-11-12 09:46:02] DBUG WSBASE/client_receive partial packet:
> > {"connectionID":
> > [2020-11-12 09:46:02] DBUG WSBASE/client_receive
> > LWS_CALLBACK_CLIENT_RECEIVE:   16 (rpp    64, first 0, final 0, bin
> > 0)
> > [2020-11-12 09:46:02] DBUG WSBASE/client_receive partial packet:
> > {"connectionID":1727580561052006
> > [2020-11-12 09:46:02] DBUG WSBASE/client_receive
> > LWS_CALLBACK_CLIENT_RECEIVE:   16 (rpp    48, first 0, final 0, bin
> > 0)
> > [2020-11-12 09:46:02] DBUG WSBASE/client_receive partial packet:
> > {"connectionID":17275805610520064599,"event":"sy
> > [2020-11-12 09:46:02] DBUG WSBASE/client_receive
> > LWS_CALLBACK_CLIENT_RECEIVE:   16 (rpp    32, first 0, final 0, bin
> > 0)
> > [2020-11-12 09:46:02] DBUG WSBASE/client_receive partial packet:
> > {"connectionID":17275805610520064599,"event":"systemStatus","sta
> > [2020-11-12 09:46:02] DBUG WSBASE/client_receive
> > LWS_CALLBACK_CLIENT_RECEIVE:   16 (rpp    16, first 0, final 0, bin
> > 0)
> > [2020-11-12 09:46:02] DBUG WSBASE/client_receive partial packet:
> > {"connectionID":17275805610520064599,"event":"systemStatus","status
> > ":
> > "o
> > nline","v
> > [2020-11-12 09:46:02] DBUG WSBASE/client_receive
> > LWS_CALLBACK_CLIENT_RECEIVE:   16 (rpp     0, first 0, final 1, bin
> > 0)
> > [2020-11-12 09:46:02] INFO KRAKENWS/processSystemStatus 66220
> > Connection 17275805610520064599 with Kraken v1.4.1 status: online
> > [2020-11-12 09:46:02] DBUG KRAKENWS/Initial Received signal
> > CLIENT_ESTABLISHED in state initial
> > [2020-11-12 09:46:02] DBUG WSBASE/sendPayload Added a 112 msg with
> > lws_ring_insert(). ring_free_num: 15
> > [2020-11-12 09:46:02] DBUG WSBASE/sendPayload Added a 128 msg with
> > lws_ring_insert(). ring_free_num: 14
> > [2020-11-12 09:46:02] DBUG WSBASE/client_writeable
> > LWS_CALLBACK_CLIENT_WRITEABLE
> > [2020-11-12 09:46:02] DBUG WSBASE/client_writeable wrote 112:
> > flags:
> > 0x0 first: 1 final 1
> > [2020-11-12 09:46:02] DBUG WSBASE/client_writeable
> > LWS_CALLBACK_CLIENT_WRITEABLE
> > [2020-11-12 09:46:02] DBUG WSBASE/client_writeable wrote 128:
> > flags:
> > 0x0 first: 1 final 1
> > [2020-11-12 09:46:02] DBUG WSBASE/client_writeable
> > LWS_CALLBACK_CLIENT_WRITEABLE
> > [2020-11-12 09:46:02] DBUG WSBASE/client_writeable nothing in ring
> > [2020-11-12 09:46:02] INFO WSCONT/log_emit_function 66220:
> > lws_ws_handshake_client: client_rx_sm exited, DROPPING 32
> > 
> > [2020-11-12 09:46:02] INFO WSBASE/client_closed
> > LWS_CALLBACK_CLIENT_CLOSED: 66220
> > 
> > P.S.: I am still with lws v3.2.2
> > 
> > Thx,
> > Olivier
> > 
> > _______________________________________________
> > Libwebsockets mailing list
> > Libwebsockets at ml.libwebsockets.org
> > https://libwebsockets.org/mailman/listinfo/libwebsockets
> 
> 
> _______________________________________________
> Libwebsockets mailing list
> Libwebsockets at ml.libwebsockets.org
> https://libwebsockets.org/mailman/listinfo/libwebsockets




More information about the Libwebsockets mailing list