[Libwebsockets] close changes between 2.2 and 2.3 stable

Andy Green andy at warmcat.com
Thu Aug 24 15:44:10 CEST 2017



On 08/24/2017 09:16 PM, Mario Theodoridis wrote:
> Hello everyone,
> 
> i just upgraded to the v2.3-stable branch from v2.2-stable and am 
> noticing some changes on the close behaviour of lwsws.
> 
> I have the following code in my callback
> 
>      ....snip...
>      case LWS_CALLBACK_RECEIVE:
>          stat = handleRequest(s, in, len);
>          if (stat != LWS_CLOSE_STATUS_NOSTATUS) {
>              lws_close_reason(wsi, stat, CLOSE_ERROR, CLOSE_ERROR_LEN);
>              return -1;
>          }
>          break;
>      ....snip...
>      return 0;
> 
> 
> In 2.2 this replied with a close and things worked. In 2.3 the close 
> frame is never sent and the connection seems to just get closed instead.
>
> Am i doing my closes wrong, or is there something else i need to make 
> this work again?
> 
> 2.2 server log looks like
> 
> interpret_incoming_packet has bailed
> sending close indication...
> lws_set_timeout: 0x987ecc8: 1 secs
> sent close indication, awaiting ack
> lws_uv_idle: done stop
> lws_read: incoming len 28  state 9
> lws_interpret_incoming_packet: received 28 byte packet
> spill on lws-regibox-protocol
> seen client close ack
> interpret_incoming_packet has bailed
> lws_close_free_wsi: shutting down connection: 0x987ecc8 (sock 11, state 9)
> lws_close_free_wsi: real just_kill_connection: 0x987ecc8 (sockfd 11)
> remove_wsi_socket_from_fds: removing same prot wsi 0x987ecc8
> have prev 0x984a1bc, setting him to our next (nil)
> remove_wsi_socket_from_fds: wsi=0x987ecc8, sock=11, fds pos=2, end guy 
> pos=3, endfd=0
> lws_close_free_wsi: doing LWS_CALLBACK_HTTP_DROP_PROTOCOL for 0x987ecc8 
> prot lws-regibox-protocol
> callback_lws_regibox: LWS_OTHER_code 50
> calling back CLOSED
> closeCon: LWS_CALLBACK_CLOSED
> lws_close_free_wsi: lws_libuv_closehandle: wsi 0x987ecc8
> ah det due to close
> lws_header_table_detach: wsi 0x987ecc8: ah (nil) (tsi=0, count = 0)
> lws_header_table_detach: wsi 0x987ecc8: ah (nil) (tsi=0, count = 0)
> lws_free_wsi: 0x987ecc8, remaining wsi 2
> lws_uv_idle: done stop

The main difference is this:

https://github.com/warmcat/libwebsockets/commit/3b0066cb3fec6baee98a3dcb2cecf11463453ed5

Basically before that patch, we just always dumbly try to send the close 
packet when the we try to close the connection.  That doesn't take into 
account the connection state; but if we couldn't send it or the close 
packet sequence was bad the connection would anyway close.

After the patch the close packet observes the same "wait until writable" 
rules as any other write.  A timeout will just close it if it takes too 
long to get a chance to write it.

This became necessary because with lws-meta protocol, there is a parent 
wsi that actually has the tcp connection, and multiple child wsi that 
multiplex their different protocol traffic on the same parent 
connection.  In the case a child is closing, he can't just randomly dump 
his close packet on the tcp connection without taking care of the parent 
mux state.  Since the child will only hear he can write when the parent 
mux state is good for it, the patch takes care of that problem.

> while 2.3 looks like
> 
> 
> interpret_incoming_packet has bailed
> lws_close_free_wsi: 0x9d48b90
> sending close indication...
> waiting for chance to send close

This is the action of the patch returning us to the event loop before 
sending.

> lws_set_timeout: 0x9d48b90: 2 secs
> xxx
> sending close packet

It looks like we do send it...

> lws_set_timeout: 0x9d48b90: 1 secs
> sent close indication, awaiting ack

... but we don't get any reply

> lws_uv_timeout_cb

These come at once per second, so we wait more than one second.

> lws_uv_timeout_cb
> wsi 0x9d48b90: TIMEDOUT WAITING on 6 (did hdr 1, ah (nil), wl 0, pfd 
> events 5) 1503579082 vs 1503579081
> lws_close_free_wsi: 0x9d48b90
> lws_close_free_wsi: real just_kill_connection: 0x9d48b90 (sockfd 15)
> lws_same_vh_protocol_remove: removing same prot wsi 0x9d48b90
> have prev 0x9d1b374, setting him to our next (nil)
> remove_wsi_socket_from_fds: wsi=0x9d48b90, sock=15, fds pos=2, end guy 
> pos=3, endfd=0
> lws_close_free_wsi: doing LWS_CALLBACK_HTTP_DROP_PROTOCOL for 0x9d48b90 
> prot lws-regibox-protocol
> callback_lws_regibox: LWS_OTHER_code 50
> calling back CLOSED
> closeCon: LWS_CALLBACK_CLOSED
> lws_close_free_wsi: lws_libuv_closehandle: wsi 0x9d48b90
> ah det due to close
> lws_free_wsi: 0x9d48b90, remaining wsi 2
> 
> I already diffed the 2 branches, but was a little overwhelmed with the 
> code changes to find an answer there.

The relevant changes are in the patch above, assuming that's related to it.

Can you tell what the client thinks happened, in terms of if it received 
the close packet from the server?

-Andy

> 



More information about the Libwebsockets mailing list