[Libwebsockets] Missing callback on connection failure?

Fabian Kurz fabian at fkurz.net
Thu Jul 14 07:20:06 CEST 2016


Hello,

while using libwebsockets (2.0.0) as a client, on very rare
occasions my program would "hang up" while trying to establish
a SSL connection to the server.

It turned out that the client program still called lws_service()
as usual and it returned as it should, but apparently it missed a
callback to tell it that something bad happened. 

Normally, if something is wrong with the server (no connection
at all, it doesn't speak websocket or SSL, e. g. during deployment
of a new version on the server), I get either
LWS_CALLBACK_CLIENT_CONNECTION_ERROR or LWS_CALLBACK_CLOSED,
which my client handles properly and then tries to re-connect.

During those connection failures which caused the hang up, the only
callback I finally got was LWS_CALLBACK_WSI_DESTROY. I was able
to reproduce this a few times with full logging enabled and the
resulting log file is attached. It always happened while something
was going on at the server - most likely it was restarted exactly
at the moment of the connection attempt.

Is this the intended behaviour, or should I get a callback to
LWS_CALLBACK_CLIENT_CONNECTION_ERROR if this happens?

Thanks and best regards,
Fabian

-- 
Fabian Kurz, DJ1YFK      Munich, Germany
fabian at fkurz.net         +49 176 24079617
https://fkurz.net/       http://lcwo.net/
-------------- next part --------------
[2016/07/13 09:47:11:8542] NOTICE: Initial logging level 991
[2016/07/13 09:47:11:8542] NOTICE: Libwebsockets version: 2.0.0 user at host-
[2016/07/13 09:47:11:8543] NOTICE: IPV6 not compiled in
[2016/07/13 09:47:11:8543] NOTICE: libev support not compiled in
[2016/07/13 09:47:11:8543] NOTICE: libuv support not compiled in
[2016/07/13 09:47:11:8543] INFO:  LWS_DEF_HEADER_LEN    : 1024
[2016/07/13 09:47:11:8543] INFO:  LWS_MAX_PROTOCOLS     : 5
[2016/07/13 09:47:11:8543] INFO:  LWS_MAX_SMP           : 32
[2016/07/13 09:47:11:8544] INFO:  SPEC_LATEST_SUPPORTED : 13
[2016/07/13 09:47:11:8544] INFO:  sizeof (*info)        : 304
[2016/07/13 09:47:11:8544] INFO:  SYSTEM_RANDOM_FILEPATH: '/dev/urandom'
[2016/07/13 09:47:11:8544] INFO:  default timeout (secs): 20
[2016/07/13 09:47:11:8545] NOTICE:  Threads: 1 each 1024 fds
[2016/07/13 09:47:11:8545] INFO:  mem: context:          9520 bytes (5424 ctx + (1 thr x 4096))
[2016/07/13 09:47:11:8545] INFO:  mem: http hdr rsvd:   68224 bytes (1 thr x (1024 + 3240) x 16))
[2016/07/13 09:47:11:8545] INFO:  mem: pollfd map:       8192
[2016/07/13 09:47:11:8546] NOTICE:  mem: platform fd map:  8192 bytes
[2016/07/13 09:47:11:8546] NOTICE:  Compiled with OpenSSL support
[2016/07/13 09:47:11:8584] NOTICE: Creating Vhost 'default' port -1, 1 protocols
[2016/07/13 09:47:11:8588] INFO:  LWS_MAX_EXTENSIONS_ACTIVE: 2
[2016/07/13 09:47:11:8589] NOTICE:  mem: per-conn:          488 bytes + protocol rx buf
[2016/07/13 09:47:11:8590] NOTICE:  canonical_hostname = hostname
[2016/07/13 09:47:11:8591] DEBUG: lws_union_transition: 0x7033a401dad0: mode 1
[2016/07/13 09:47:11:8592] INFO: lws_header_table_attach: wsi 0x7033a401dad0: ah (nil) (tsi 0)
[2016/07/13 09:47:11:8593] INFO: lws_header_table_attach: wsi 0x7033a401dad0: ah 0x7033a40008c0: count 1 (on exit)
[2016/07/13 09:47:11:8594] CLIENT: lws_client_connect: direct conn
[2016/07/13 09:47:11:8595] CLIENT: lws_client_connect_2
[2016/07/13 09:47:11:8595] CLIENT: lws_client_connect_2: address my.peer.address.invalid
[2016/07/13 09:47:11:9247] DEBUG: insert_wsi_socket_into_fds: 0x7033a401dad0: tsi=0, sock=8, pos-in-fds=1
[2016/07/13 09:47:11:9248] DEBUG: lws_set_timeout: 0x7033a401dad0: 20 secs
[2016/07/13 09:47:11:9250] CLIENT: nonblocking connect retry
[2016/07/13 09:47:11:9352] NOTICE: lws_protocol_init
[2016/07/13 09:47:11:9706] DEBUG: fd=8, revents=4
[2016/07/13 09:47:11:9707] CLIENT: lws_client_connect_2
[2016/07/13 09:47:11:9707] CLIENT: lws_client_connect_2: address my.peer.address.invalid
[2016/07/13 09:47:11:9713] CLIENT: connected
[2016/07/13 09:47:11:9715] DEBUG: lws_set_timeout: 0x7033a401dad0: 20 secs
[2016/07/13 09:47:11:9717] DEBUG: fd=8, revents=1
[2016/07/13 09:47:12:1064] DEBUG: fd=8, revents=1
[2016/07/13 09:47:12:1066] DEBUG: lws_set_timeout: 0x7033a401dad0: 20 secs
[2016/07/13 09:47:12:1068] DEBUG: ERROR writing to client socket
[2016/07/13 09:47:12:1069] INFO: lws_close_free_wsi: real just_kill_connection: 0x7033a401dad0 (sockfd 8)
[2016/07/13 09:47:12:1070] INFO: remove_wsi_socket_from_fds: removing same prot wsi 0x7033a401dad0
[2016/07/13 09:47:12:1070] INFO: remove_wsi_socket_from_fds: wsi=0x7033a401dad0, sock=8, fds pos=1, end guy pos=2, endfd=0
[2016/07/13 09:47:12:1071] DEBUG: not calling back closed mode=13 state=7
[2016/07/13 09:47:12:1073] ERR: [ws_callback] LWS_CALLBACK_WSI_DESTROY was called
[2016/07/13 09:47:12:1077] INFO: lws_header_table_detach: wsi 0x7033a401dad0: ah 0x7033a40008c0 (tsi=0, count = 1)
[2016/07/13 09:47:12:1078] DEBUG: lws_free_wsi: 0x7033a401dad0, remaining wsi 0


More information about the Libwebsockets mailing list