[Libwebsockets] Logging WS HS

Olivier Langlois olivier at olivierlanglois.net
Sun Mar 1 18:41:21 CET 2020


On Sun, 2020-02-23 at 17:02 -0500, Olivier Langlois wrote:
> On Sun, 2020-02-16 at 18:12 +0000, Andy Green wrote:
> > > You don't need that info when developing a server but when
> > > developing a
> > > client to use a service that you don't control, you are
> > > vulnerable to
> > > unannounced server changes. One day the HS works. Then it
> > > doesn't. With
> > > those logs, a simple glance at the logs would show what has
> > > changed and
> > > we aren't talking about multi-MB logs. It is 1-2 hundred extra
> > > bytes.
> > > IMHO, this is something that even lightweight systems could
> > > afford.
> > > 
> > > Another scenario that would be interesting to have some more help
> > > from
> > > lws is when the server returns a HTTP error code during the WS
> > > HS. ie:
> > > I get a 503. I suspect that along with it, in the reply body, the
> > > server provides some useful info such as: 'Service disabled for
> > > maintenance. Service resuming expected at HH:MM'. Recuperating
> > > those
> > > messages is something that I would like lws to help with.
> > 
> > Feel free to propose a patch, but at that point, it's http body,
> > unrelated to ws protocol, so this is probably a job about generic
> > handling of http bodies for 4xx / 5xx... not sure if it already
> > appears at the cb or the transaction is abandoned.
> 
> Andy,
> 
> I think that I have found a way to do it without any modification on
> the lws side (well almost).
> 
> I need to test this option to validate that it works but I'm not
> seeing
> why it wouldn't. FYI, my server is using chunked encoding.
> 
> In my callback:
> 
>      case LWS_CALLBACK_CLIENT_FILTER_PRE_ESTABLISH: {
>           int code = lws_hdr_http_response(wsi);
>           if (code == 503) {
>               char buf[4096];
>               char *ptr = buf;
>               int len = sizeof(buf);
>               lws_http_client_read(wsi, &ptr, &len);
>           }
>         }
>         break;
>       case LWS_CALLBACK_RECEIVE_CLIENT_HTTP_READ:
>           INFO2("HTTP 503 reply body:\n%.*s", len, (const char *)in);
>         break;
> 
Ok, the service that I am connecting to did enter in maintenance,
started to send out 503s and this made me realize that my new solution
didn't work. For ws connections, no callbacks are made. I had to modify
furhter lws_client_interpret_server_handshake() to achieve what I want.

The patch isn't tested when 503s are received but I'm sharing it so
that you can see what I'm proposing ASAP.

There is a lot of changed lines but it is not as bad as it seems. In a
nutshell, here are the proposed changes:

1. Move down the if (!wsi->do_ws) and change it for a if (wsi->do_ws)
{} else {} so that content-length related HTTP headers are processed
for ws connections as well.
2. Move down the call to lws_ensure_user_space() in the HTTP only block
so that it isn't called twice for ws connections.
3. The bulk of the other line changes are simply for changing the code
indentation...

>From 29943a0df1a55a02e82adaffb8d36a4d4504e2fe Mon Sep 17 00:00:00 2001
From: Olivier Langlois <olivier at trillion01.com>
Date: Sun, 1 Mar 2020 12:24:29 -0500
Subject: [PATCH] Process HTTP headers related to content length for ws
 connections

and make 1 callback before continuing to the ws upgrade code.
This gives one last opportunity to ws protocols to inspect server reply
before the ws upgrade code discard it. ie: download reply body in case
of any other response code than 101.
---
 lib/roles/http/client/client-http.c | 175 +++++++++++++++-------------
 1 file changed, 94 insertions(+), 81 deletions(-)

diff --git a/lib/roles/http/client/client-http.c
b/lib/roles/http/client/client-http.c
index cba95eee..2462bfc1 100644
--- a/lib/roles/http/client/client-http.c
+++ b/lib/roles/http/client/client-http.c
@@ -735,72 +735,113 @@ lws_client_interpret_server_handshake(struct lws
*wsi)
 		return 0;
 	}
 
-	if (!wsi->do_ws) {
+	/* if h1 KA is allowed, enable the queued pipeline guys */
 
-		/* if h1 KA is allowed, enable the queued pipeline guys
*/
+	if (!wsi->client_h2_alpn && !wsi->client_mux_substream) {
+		/* ie, coming to this for the first time */
+		if (wsi->http.conn_type == HTTP_CONNECTION_KEEP_ALIVE)
+			wsi->keepalive_active = 1;
+		else {
+			/*
+			 * Ugh... now the main http connection has seen
+			 * both sides, we learn the server doesn't
+			 * support keepalive.
+			 *
+			 * That means any guys queued on us are going
+			 * to have to be restarted from connect2 with
+			 * their own connections.
+			 */
 
-		if (!wsi->client_h2_alpn && !wsi->client_mux_substream) 
{
-			/* ie, coming to this for the first time */
-			if (wsi->http.conn_type ==
HTTP_CONNECTION_KEEP_ALIVE)
-				wsi->keepalive_active = 1;
-			else {
-				/*
-				 * Ugh... now the main http connection
has seen
-				 * both sides, we learn the server
doesn't
-				 * support keepalive.
-				 *
-				 * That means any guys queued on us are
going
-				 * to have to be restarted from
connect2 with
-				 * their own connections.
-				 */
-
-				/*
-				 * stick around telling any new guys
they can't
-				 * pipeline to this server
-				 */
-				wsi->keepalive_rejected = 1;
-
-				lws_vhost_lock(wsi->vhost);
-				lws_start_foreach_dll_safe(struct
lws_dll2 *,
-							   d, d1,
-				  wsi->dll2_cli_txn_queue_owner.head) {
-					struct lws *ww =
lws_container_of(d,
-						struct lws,
-						dll2_cli_txn_queue);
-
-					/* remove him from our queue */
-					lws_dll2_remove(&ww-
>dll2_cli_txn_queue);
-					/* give up on pipelining */
-					ww->client_pipeline = 0;
-
-					/* go back to "trying to
connect" state */
-					lws_role_transition(ww,
LWSIFR_CLIENT,
-							    LRS_UNCONNE
CTED,
+			/*
+			 * stick around telling any new guys they can't
+			 * pipeline to this server
+			 */
+			wsi->keepalive_rejected = 1;
+
+			lws_vhost_lock(wsi->vhost);
+			lws_start_foreach_dll_safe(struct lws_dll2 *,
+						   d, d1,
+			  wsi->dll2_cli_txn_queue_owner.head) {
+				struct lws *ww = lws_container_of(d,
+					struct lws,
+					dll2_cli_txn_queue);
+
+				/* remove him from our queue */
+				lws_dll2_remove(&ww-
>dll2_cli_txn_queue);
+				/* give up on pipelining */
+				ww->client_pipeline = 0;
+
+				/* go back to "trying to connect" state
*/
+				lws_role_transition(ww, LWSIFR_CLIENT,
+						    LRS_UNCONNECTED,
 #if defined(LWS_ROLE_H1)
-							    &role_ops_h
1);
+						    &role_ops_h1);
 #else
 #if defined (LWS_ROLE_H2)
-							    &role_ops_h
2);
+						    &role_ops_h2);
 #else
-							    &role_ops_r
aw);
+						    &role_ops_raw);
 #endif
 #endif
-					ww->user_space = NULL;
-				} lws_end_foreach_dll_safe(d, d1);
-				lws_vhost_unlock(wsi->vhost);
-			}
+				ww->user_space = NULL;
+			} lws_end_foreach_dll_safe(d, d1);
+			lws_vhost_unlock(wsi->vhost);
 		}
+	}
 
 #ifdef LWS_WITH_HTTP_PROXY
-		wsi->http.perform_rewrite = 0;
-		if (lws_hdr_total_length(wsi,
WSI_TOKEN_HTTP_CONTENT_TYPE)) {
-			if (!strncmp(lws_hdr_simple_ptr(wsi,
-						WSI_TOKEN_HTTP_CONTENT_
TYPE),
-						"text/html", 9))
-				wsi->http.perform_rewrite = 0;
-		}
+	wsi->http.perform_rewrite = 0;
+	if (lws_hdr_total_length(wsi, WSI_TOKEN_HTTP_CONTENT_TYPE)) {
+		if (!strncmp(lws_hdr_simple_ptr(wsi,
+					WSI_TOKEN_HTTP_CONTENT_TYPE),
+					"text/html", 9))
+			wsi->http.perform_rewrite = 0;
+	}
 #endif
 
+	/* he may choose to send us stuff in chunked transfer-coding */
+	wsi->chunked = 0;
+	wsi->chunk_remaining = 0; /* ie, next thing is chunk size */
+	if (lws_hdr_total_length(wsi,
+				WSI_TOKEN_HTTP_TRANSFER_ENCODING)) {
+		wsi->chunked = !strcmp(lws_hdr_simple_ptr(wsi,
+				       WSI_TOKEN_HTTP_TRANSFER_ENCODING
),
+					"chunked");
+		/* first thing is hex, after payload there is crlf */
+		wsi->chunk_parser = ELCP_HEX;
+	}
+
+	wsi->http.content_length_given = 0;
+	if (lws_hdr_total_length(wsi, WSI_TOKEN_HTTP_CONTENT_LENGTH)) {
+		wsi->http.rx_content_length =
+				atoll(lws_hdr_simple_ptr(wsi,
+					WSI_TOKEN_HTTP_CONTENT_LENGTH))
;
+		lwsl_info("%s: incoming content length %llu\n",
+			    __func__, (unsigned long long)
+				    wsi->http.rx_content_length);
+		wsi->http.rx_content_remain =
+				wsi->http.rx_content_length;
+		wsi->http.content_length_given = 1;
+	} else { /* can't do 1.1 without a content length or chunked */
+		if (!wsi->chunked)
+			wsi->http.conn_type = HTTP_CONNECTION_CLOSE;
+		lwsl_debug("%s: no content length\n", __func__);
+	}
+
+	if (wsi->do_ws) {
+		/*
+		 * Give one last opportunity to ws protocols to inspect
server reply
+		 * before the ws upgrade code discard it. ie: download
reply body in case
+		 * of any other response code than 101.
+		 */
+		if (w->protocol->callback(w,
+					  LWS_CALLBACK_ESTABLISHED_CLIE
NT_HTTP,
+					  w->user_space, NULL, 0)) {
+
+			cce = "HS: disallowed by client filter";
+			goto bail2;
+		}
+	} else {
 		/* allocate the per-connection user memory (if any) */
 		if (lws_ensure_user_space(wsi)) {
 			lwsl_err("Problem allocating wsi user mem\n");
@@ -808,34 +849,6 @@ lws_client_interpret_server_handshake(struct lws
*wsi)
 			goto bail2;
 		}
 
-		/* he may choose to send us stuff in chunked transfer-
coding */
-		wsi->chunked = 0;
-		wsi->chunk_remaining = 0; /* ie, next thing is chunk
size */
-		if (lws_hdr_total_length(wsi,
-					WSI_TOKEN_HTTP_TRANSFER_ENCODIN
G)) {
-			wsi->chunked = !strcmp(lws_hdr_simple_ptr(wsi,
-					       WSI_TOKEN_HTTP_TRANSFER_
ENCODING),
-						"chunked");
-			/* first thing is hex, after payload there is
crlf */
-			wsi->chunk_parser = ELCP_HEX;
-		}
-
-		wsi->http.content_length_given = 0;
-		if (lws_hdr_total_length(wsi,
WSI_TOKEN_HTTP_CONTENT_LENGTH)) {
-			wsi->http.rx_content_length =
-					atoll(lws_hdr_simple_ptr(wsi,
-						WSI_TOKEN_HTTP_CONTENT_
LENGTH));
-			lwsl_info("%s: incoming content length %llu\n",
-				    __func__, (unsigned long long)
-					    wsi-
>http.rx_content_length);
-			wsi->http.rx_content_remain =
-					wsi->http.rx_content_length;
-			wsi->http.content_length_given = 1;
-		} else { /* can't do 1.1 without a content length or
chunked */
-			if (!wsi->chunked)
-				wsi->http.conn_type =
HTTP_CONNECTION_CLOSE;
-			lwsl_debug("%s: no content length\n",
__func__);
-		}
 
 		/*
 		 * we seem to be good to go, give client last chance to
check
-- 
2.25.0




More information about the Libwebsockets mailing list