[Libwebsockets] HS: UPGRADE malformed

Andy Green andy at warmcat.com
Sat May 4 09:39:07 CEST 2019



On 03/05/2019 22:18, Paolo Denti wrote:
> Andy
> this is the not working full header parsing (I just changed host name in 
> the log)
> 
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOKEN_NAME_PART 'C' 0x43 (role=0x10000000) wsi->lextable_pos=0
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOKEN_NAME_PART 'o' 0x6F (role=0x10000000) wsi->lextable_pos=117
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOKEN_NAME_PART 'n' 0x6E (role=0x10000000) wsi->lextable_pos=124
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOKEN_NAME_PART 'n' 0x6E (role=0x10000000) wsi->lextable_pos=131
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOKEN_NAME_PART 'e' 0x65 (role=0x10000000) wsi->lextable_pos=138
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOKEN_NAME_PART 'c' 0x63 (role=0x10000000) wsi->lextable_pos=139
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOKEN_NAME_PART 't' 0x74 (role=0x10000000) wsi->lextable_pos=140
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOKEN_NAME_PART 'i' 0x69 (role=0x10000000) wsi->lextable_pos=141
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOKEN_NAME_PART 'o' 0x6F (role=0x10000000) wsi->lextable_pos=148
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOKEN_NAME_PART 'n' 0x6E (role=0x10000000) wsi->lextable_pos=149
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOKEN_NAME_PART ':' 0x3A (role=0x10000000) wsi->lextable_pos=150
> PARSER: known hdr 4
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOK_(4) ' '
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOK_(4) 'u'
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOK_(4) 'p'
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOK_(4) 'g'
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOK_(4) 'r'
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOK_(4) 'a'
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOK_(4) 'd'
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOK_(4) 'e'
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOK_(4) '
> '
> PARSER: *
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOKEN_SKIPPING_SAW_CR '
> 

> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOKEN_NAME_PART 'C' 0x43 (role=0x10000000) wsi->lextable_pos=0
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOKEN_NAME_PART 'o' 0x6F (role=0x10000000) wsi->lextable_pos=117
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOKEN_NAME_PART 'n' 0x6E (role=0x10000000) wsi->lextable_pos=124
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOKEN_NAME_PART 'n' 0x6E (role=0x10000000) wsi->lextable_pos=131
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOKEN_NAME_PART 'e' 0x65 (role=0x10000000) wsi->lextable_pos=138
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOKEN_NAME_PART 'c' 0x63 (role=0x10000000) wsi->lextable_pos=139
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOKEN_NAME_PART 't' 0x74 (role=0x10000000) wsi->lextable_pos=140
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOKEN_NAME_PART 'i' 0x69 (role=0x10000000) wsi->lextable_pos=141
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOKEN_NAME_PART 'o' 0x6F (role=0x10000000) wsi->lextable_pos=148
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOKEN_NAME_PART 'n' 0x6E (role=0x10000000) wsi->lextable_pos=149
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOKEN_NAME_PART ':' 0x3A (role=0x10000000) wsi->lextable_pos=150
> PARSER: known hdr 4
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOK_(4) ' '
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOK_(4) 'c'
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOK_(4) 'l'
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOK_(4) 'o'
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOK_(4) 's'
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOK_(4) 'e'
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOK_(4) '
> '
> PARSER: *
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOKEN_SKIPPING_SAW_CR '
> 
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOKEN_NAME_PART '
> ' 0x0D (role=0x10000000) wsi->lextable_pos=0
> DEBUG: 0x559119c38a30: SSL_read says 1
> PARSER: WSI_TOKEN_NAME_PART '
> i->lextable_pos=238
> PARSER: known hdr 8
> PARSER: v00 hdrs done
> ERR: CLIENT_CONNECTION_ERROR: HS: UPGRADE malformed
> INFO: closing connection (prot dumb-increment-protocol) due to bail2 
> connection error: HS: UPGRADE malformed
> INFO: __lws_close_free_wsi: 0x559119c38a30: caller: c hs interp

Thanks.  From the log, what's happening is the server is sending two 
Connection: headers... one says "upgrade" and the other says "close".

I reproduced it with this on the minimal examples

diff --git 
a/minimal-examples/ws-client/minimal-ws-client-rx/minimal-ws-client.c 
b/minimal-examples/ws-client/minimal-ws-client-rx/minimal-ws-client.c
index 849eab68c..8254680b1 100644
--- a/minimal-examples/ws-client/minimal-ws-client-rx/minimal-ws-client.c
+++ b/minimal-examples/ws-client/minimal-ws-client-rx/minimal-ws-client.c
@@ -124,6 +124,11 @@ int main(int argc, const char **argv)
         i.protocol = protocols[0].name; /* "dumb-increment-protocol" */
         i.pwsi = &client_wsi;

+       i.protocol = "lws-minimal";
+       i.address = "127.0.0.1";
+       i.port = 7681;
+       i.ssl_connection = 0;
+
         if (lws_cmdline_option(argc, argv, "--h2"))
                 i.alpn = "h2";

diff --git 
a/minimal-examples/ws-server/minimal-ws-server/protocol_lws_minimal.c 
b/minimal-examples/ws-server/minimal-ws-server/protocol_lws_minimal.c
index 3c8160b1c..228fddae7 100644
--- a/minimal-examples/ws-server/minimal-ws-server/protocol_lws_minimal.c
+++ b/minimal-examples/ws-server/minimal-ws-server/protocol_lws_minimal.c
@@ -69,6 +69,7 @@ callback_minimal(struct lws *wsi, enum 
lws_callback_reasons reason,
                         (struct per_vhost_data__minimal *)
                         lws_protocol_vh_priv_get(lws_get_vhost(wsi),
                                         lws_get_protocol(wsi));
+       struct lws_process_html_args *args;
         int m;

         switch (reason) {
@@ -81,6 +82,17 @@ callback_minimal(struct lws *wsi, enum 
lws_callback_reasons reason,
                 vhd->vhost = lws_get_vhost(wsi);
                 break;

+       case LWS_CALLBACK_ADD_HEADERS:
+               args = (struct lws_process_html_args *)in;
+
+               if (lws_add_http_header_by_name(wsi,
+                       (unsigned char *)"connection:",
+                       (unsigned char *)"close", 5,
+                       (unsigned char **)&args->p,
+                       (unsigned char *)args->p + args->max_len))
+                               return 1;
+               break;
+
         case LWS_CALLBACK_ESTABLISHED:


lws does what it should do in terms of header coalescing, it produces 
the overall connection header 'Upgrade,  close'.

But the code in lws that specifically checks the tokens in the 
connection string doesn't restrict its check for "upgrade" to just the 7 
characters of the first token, it checks against the whole "Upgrade, 
close" string.  There are very very few servers that produce anything 
except "upgrade" (that's what is shown in RFC6455, and the mixing of old 
and new connection tokens is not discussed there), so this bug 
introduced in v3.1 didn't have any chance to make a problem until now.

I pushed a patch on v3.1-stable and master to correct it... I'm pretty 
sure upgrading to that will solve it for you.

-Andy


More information about the Libwebsockets mailing list