[Libwebsockets] Dummy http server URL modification

Jukka Marin jukka.marin at jmp.fi
Fri Jun 24 12:34:20 CEST 2022


On Thu, Mar 24, 2022 at 06:28:52PM +0000, Andy Green wrote:
> >I'm using lws as a websocket and http server.  Now I need to implement
> >a "default path" for the html files if the http client isn't recognized.
> >For known clients, the server has separate directories, but for unknown
> >clients, it needs to use a common default path.
> >I'm using lws '3.1.99 unknown-build-hash' at the moment.  I wonder if
> >what I'm trying to do works better in 4.x?
> 
> You should update to current stable (v4.3-stable) anyway, nobody has time to
> support older versions.
> 
> Your approach of messing with the copy of the url you're given doesn't sound
> good... the simplest way is probably to redirect the "unknown clients" to
> what you want them to fetch instead.
> 
> You can see an example in minimal-http-server-tls.

Thank you.  I'm finally trying to upgrade lws to version 4.3.2, but
for some reason, my ws client no longer connects to the remote server
(which I have no other access to).  I have tried to compare my code to
minimal-ws-client-ping.c, and tried to "update" my code, but still no
LWS_CALLBACK_CLIENT_ESTABLISHED is seen by the callback.

I have a separate process for the ws client (no threads) with the
event loop in my code, trying to add and remove fd's to my own array
in the lws callback, but I don't think I'm getting the LWS_CALLBACK_ADD_POLL_FD
and LWS_CALLBACK_DEL_POLL_FD calls from lws 4.3.2.

This is what I get in the logs (including some messages from my own code):

09:55:33.462 WSC:N Using LWS '4.3.2-v4.3.2'
09:55:33.464 WSC:D [2022/06/24 12:55:33:4640] D: _realloc: size 7296: context<0a>
09:55:33.464 WSC:N [2022/06/24 12:55:33:4643] N: lws_create_context: LWS: 4.3.2-v4.3.2, NET CLI SRV H1 H2 WS ConMon IPv6-absent<0a>
09:55:33.464 WSC:I [2022/06/24 12:55:33:4643] I: lws_create_context: Event loop: poll<0a>
09:55:33.464 WSC:D [2022/06/24 12:55:33:4647] D: _realloc: size 64: lws_smd_register<0a>
09:55:33.464 WSC:I [2022/06/24 12:55:33:4648] I: lws_smd_register: peer 0x55cc987ba760 (count 1) registered<0a>
09:55:33.464 WSC:D [2022/06/24 12:55:33:4648] D: _realloc: size 40: fds table<0a>
09:55:33.464 WSC:I [2022/06/24 12:55:33:4649] I: lws_create_context: ctx:  6104B (2008 ctx + pt(1 thr x 4096)), pt-fds: 5, fdmap: 40<0a>
09:55:33.464 WSC:I [2022/06/24 12:55:33:4649] I: lws_create_context:  http: ah_data: 4096, ah: 984, max count 5<0a>
09:55:33.465 WSC:D [2022/06/24 12:55:33:4650] D: _realloc: size 40: lws_lookup<0a>
09:55:33.465 WSC:I [2022/06/24 12:55:33:4650] I: lws_plat_init:  mem: platform fd map:    40 B<0a>
09:55:33.465 WSC:D [2022/06/24 12:55:33:4652] D: _realloc: size 1192: __lws_wsi_create_with_role<0a>
09:55:33.465 WSC:D [2022/06/24 12:55:33:4653] D: : lws_role_transition: wsistate 0x200, ops pipe<0a>
09:55:33.465 WSC:N [2022/06/24 12:55:33:4653] N: __lws_lc_tag:  ++ [wsi|0|pipe] (1)<0a>
09:55:33.465 WSC:D [2022/06/24 12:55:33:4654] D: [wsi|0|pipe]: __insert_wsi_socket_into_fds: tsi=0, sock=12, pos-in-fds=0<0a>
09:55:33.465 WSC:I [2022/06/24 12:55:33:4656] I: rops_pt_init_destroy_netlink: creating netlink skt<0a>
09:55:33.465 WSC:D [2022/06/24 12:55:33:4656] D: _realloc: size 1192: __lws_wsi_create_with_role<0a>
09:55:33.465 WSC:D [2022/06/24 12:55:33:4657] D: : lws_role_transition: wsistate 0x200, ops netlink<0a>
09:55:33.465 WSC:N [2022/06/24 12:55:33:4658] N: __lws_lc_tag:  ++ [vh|0|netlink] (1)<0a>
09:55:33.465 WSC:D [2022/06/24 12:55:33:4659] D: [vh|0|netlink]: __insert_wsi_socket_into_fds: tsi=0, sock=13, pos-in-fds=1<0a>
09:55:33.466 WSC:D [2022/06/24 12:55:33:4660] D: rops_pt_init_destroy_netlink: starting netlink coldplug wait<0a>
09:55:33.466 WSC:I [2022/06/24 12:55:33:4660] I: lws_context_init_ssl_library:  Compiled with OpenSSL support<0a>
09:55:33.466 WSC:I [2022/06/24 12:55:33:4661] I: lws_context_init_ssl_library: Doing SSL library init<0a>
09:55:33.475 WSC:I [2022/06/24 12:55:33:4758] I: lws_server_get_canonical_hostname:  canonical_hostname = foobar<0a>
09:55:33.475 WSC:D [2022/06/24 12:55:33:4759] D: _realloc: size 888: lws_create_vhost<0a>
09:55:33.476 WSC:N [2022/06/24 12:55:33:4760] N: __lws_lc_tag:  ++ [vh|1|default||-1] (2)<0a>
09:55:33.476 WSC:D [2022/06/24 12:55:33:4760] D: _realloc: size 112: vh plugin table<0a>
09:55:33.476 WSC:D [2022/06/24 12:55:33:4761] D: _realloc: size 24: same vh list<0a>
09:55:33.476 WSC:I [2022/06/24 12:55:33:4761] I: [vh|1|default||-1]: lws_create_vhost: Creating Vhost 'default' (serving disabled), 1 protocols, IPv6 off<0a>
09:55:33.477 WSC:D [2022/06/24 12:55:33:4774] D: _realloc: size 72: client ctx tcr<0a>
09:55:33.477 WSC:I [2022/06/24 12:55:33:4774] I: lws_tls_client_create_vhost_context: vh default: created new client ctx 0<0a>
09:55:33.477 WSC:I [2022/06/24 12:55:33:4775] I: created client ssl context for default<0a>
09:55:33.477 WSC:D callback_cloud: reason 21  CloudConnected 0
09:55:33.477 WSC:I [2022/06/24 12:55:33:4776] I: lws_create_context:  mem: per-conn:         1192 bytes + protocol rx buf<0a>
09:55:33.477 WSC:I [2022/06/24 12:55:33:4777] I: lws_plat_drop_app_privileges: not changing group<0a>
09:55:33.477 WSC:I [2022/06/24 12:55:33:4778] I: lws_plat_drop_app_privileges: not changing user<0a>
09:55:33.477 WSC:D [2022/06/24 12:55:33:4778] D: lws_cancel_service: <0a>
09:55:33.477 WSC:W WS_Client_Process: new alarm minimum grace time 19 s
09:55:33.478 WSC:N WS_Client_Process: trying to connect to cloud
09:55:33.478 WSC:N Connecting to wss://foo.bar.fi:443/ws (wss=1)
09:55:33.478 WSC:I [2022/06/24 12:55:33:4785] I: lws_protocol_init: <0a>
09:55:33.478 WSC:D [2022/06/24 12:55:33:4785] D: [vh|1|default||-1]: lws_protocol_init_vhost: not instantiating protocol_v1<0a>
09:55:33.478 WSC:I [2022/06/24 12:55:33:4786] I: [vh|1|default||-1]: lws_protocol_init_vhost: init default.protocol_v1<0a>
09:55:33.478 WSC:D callback_cloud: reason 27  CloudConnected 0
09:55:33.478 WSC:D [2022/06/24 12:55:33:4786] D: _realloc: size 1192: __lws_wsi_create_with_role<0a>
09:55:33.478 WSC:D [2022/06/24 12:55:33:4788] D: : lws_role_transition: wsistate 0x200, ops (unset)<0a>
09:55:33.478 WSC:D [2022/06/24 12:55:33:4788] D: : lws_vhost_bind_wsi: vh default: wsi none/none, count_bound_wsi 1<0a>
09:55:33.478 WSC:D [2022/06/24 12:55:33:4789] D: _realloc: size 328: client ws struct<0a>
09:55:33.478 WSC:D [2022/06/24 12:55:33:4789] D: : lws_role_transition: wsistate 0x10000200, ops h1<0a>
09:55:33.479 WSC:I [2022/06/24 12:55:33:4789] I: : lws_client_connect_via_info: role binding to h1<0a>
09:55:33.479 WSC:I [2022/06/24 12:55:33:4790] I: : lws_client_connect_via_info: vh default protocol binding to protocol_v1<0a>
09:55:33.479 WSC:D [2022/06/24 12:55:33:4790] D: : lws_ensure_user_space: protocol pss 0, user_space=(nil)<0a>
09:55:33.479 WSC:D callback_cloud: reason 85  CloudConnected 0
09:55:33.479 WSC:I [2022/06/24 12:55:33:4791] I: : lws_client_connect_via_info: : h1 protocol_v1 entry<0a>
09:55:33.479 WSC:D [2022/06/24 12:55:33:4792] D: _realloc: size 180: client stash<0a>
09:55:33.479 WSC:N [2022/06/24 12:55:33:4792] N: __lws_lc_tag:  ++ [wsicli|0|WS/h1/default/foo.bar.fi] (1)<0a>
09:55:33.479 WSC:I [2022/06/24 12:55:33:4793] I: lws_header_table_attach: [wsicli|0|WS/h1/default/foo.bar.fi]: ah (nil) (tsi 0, count = 0) in<0a>
09:55:33.479 WSC:D [2022/06/24 12:55:33:4793] D: _realloc: size 984: ah struct<0a>
09:55:33.479 WSC:D [2022/06/24 12:55:33:4794] D: _realloc: size 4096: ah data<0a>
09:55:33.479 WSC:I [2022/06/24 12:55:33:4794] I: _lws_create_ah: created ah 0x55cc9885c3a0 (size 4096): pool length 1<0a>
09:55:33.479 WSC:I [2022/06/24 12:55:33:4795] I: lws_header_table_attach: did attach wsi [wsicli|0|WS/h1/default/foo.bar.fi]: ah 0x55cc9885c3a0: count 1 (on exit)<0a>
09:55:33.479 WSC:D [2022/06/24 12:55:33:4796] D: [wsicli|0|WS/h1/default/foo.bar.fi]: __lws_set_timeout: 10 secs, reason 25<0a>
09:55:33.479 WSC:D [2022/06/24 12:55:33:4796] D: [wsicli|0|WS/h1/default/foo.bar.fi]: lws_http_client_connect_via_info2: stash 0x55cc9885c2e0<0a>
09:55:33.479 WSC:D [2022/06/24 12:55:33:4797] D: _realloc: size 26: strdup<0a>
09:55:33.479 WSC:D [2022/06/24 12:55:33:4798] D: [wsicli|0|WS/h1/default/foo.bar.fi]: lws_client_connect_2_dnsreq: new conn on no pipeline flag<0a>
09:55:33.479 WSC:D [2022/06/24 12:55:33:4798] D: [wsicli|0|WS/h1/default/foo.bar.fi]: lwsi_set_state: lwsi_set_state 0x10000200 -> 0x10000201<0a>
09:55:33.479 WSC:I [2022/06/24 12:55:33:4799] I: [wsicli|0|WS/h1/default/foo.bar.fi]: lws_client_connect_2_dnsreq: lookup foo.bar.fi:443<0a>
09:55:33.485 WSC:I [2022/06/24 12:55:33:4851] I: [wsicli|0|WS/h1/default/foo.bar.fi]: lws_getaddrinfo46: getaddrinfo 'foo.bar.fi' says 0<0a>
09:55:33.485 WSC:I [2022/06/24 12:55:33:4852] I: [wsicli|0|WS/h1/default/foo.bar.fi]: lws_sort_dns: sort_dns: 0x55cc987ba710<0a>
09:55:33.485 WSC:D [2022/06/24 12:55:33:4852] D: _realloc: size 104: lws_sort_dns<0a>
09:55:33.485 WSC:I [2022/06/24 12:55:33:4852] I: [wsicli|0|WS/h1/default/foo.bar.fi]: lws_sort_dns: unsorted entry (af 2) 11.22.33.44<0a>
09:55:33.485 WSC:I [2022/06/24 12:55:33:4853] I: [wsicli|0|WS/h1/default/foo.bar.fi]: lws_sort_dns_dump: 1: (2)11.22.33.44, gw (0)(unset), idi: 0, lbl: 0, prec: 0<0a>
09:55:33.485 WSC:I [2022/06/24 12:55:33:4853] I: [wsicli|0|WS/h1/default/foo.bar.fi]: lws_client_connect_3_connect: peer_route_uidx 0<0a>
09:55:33.485 WSC:D [2022/06/24 12:55:33:4854] D: [wsicli|0|WS/h1/default/foo.bar.fi]: lws_client_connect_3_connect: WAITING_CONNECT<0a>
09:55:33.485 WSC:D [2022/06/24 12:55:33:4854] D: [wsicli|0|WS/h1/default/foo.bar.fi]: lwsi_set_state: lwsi_set_state 0x10000201 -> 0x10000202<0a>
09:55:33.485 WSC:D [2022/06/24 12:55:33:4854] D: [wsicli|0|WS/h1/default/foo.bar.fi]: __insert_wsi_socket_into_fds: tsi=0, sock=14, pos-in-fds=2<0a>
09:55:33.485 WSC:D [2022/06/24 12:55:33:4855] D: [wsicli|0|WS/h1/default/foo.bar.fi]: _lws_change_pollfd: fd 14 events 1 -> 1<0a>
09:55:33.485 WSC:D [2022/06/24 12:55:33:4855] D: [wsicli|0|WS/h1/default/foo.bar.fi]: __lws_set_timeout: 20 secs, reason 2<0a>
09:55:33.485 WSC:D callback_cloud: reason 105  CloudConnected 0
09:55:33.485 WSC:D [2022/06/24 12:55:33:4856] D: [wsicli|0|WS/h1/default/foo.bar.fi]: lws_client_connect_3_connect: connect: fd 14 errno: 115<0a>
09:55:33.485 WSC:D [2022/06/24 12:55:33:4856] D: [wsicli|0|WS/h1/default/foo.bar.fi]: _lws_change_pollfd: fd 14 events 1 -> 5<0a>
09:55:33.485 WSC:D [2022/06/24 12:55:33:4857] D: [wsicli|0|WS/h1/default/foo.bar.fi]: lws_client_connect_via_info: adoption cb 19 to h1 protocol_v1<0a>
09:55:33.485 WSC:D callback_cloud: reason 19  CloudConnected 0
09:55:33.485 WSC:N lws_client_connect_via_info 1 wsiCloud 0x55cc9885bce0
09:55:33.485 WSC:N WS_Client_Process: WCConnect returned 0, wsiCloud 0x55cc9885bce0
09:55:33.485 WSC:I wc_client_command_process: got Cmd periodic cid  unicast 1
09:55:33.498 WSC:D [2022/06/24 12:55:33:4988] D: [wsicli|0|WS/h1/default/foo.bar.fi]: _lws_change_pollfd: fd 14 events 5 -> 5<0a>
09:55:38.952 WSC:I wc_client_command_process: got Cmd connected cid 00000000-0000-4001-8000-00000A030033 unicast 1
09:55:38.956 WSC:D [2022/06/24 12:55:38:9564] D: [wsicli|0|WS/h1/default/foo.bar.fi]: _lws_change_pollfd: fd 14 events 5 -> 5<0a>
09:56:00.055 WSC:I wc_client_command_process: got Cmd periodic cid  unicast 1
09:56:00.064 WSC:D [2022/06/24 12:56:00:0643] D: [wsicli|0|WS/h1/default/foo.bar.fi]: _lws_change_pollfd: fd 14 events 5 -> 5<0a>
09:56:34.108 WSC:W WS_Client_Process: connection timed out, state 1, retrying soon
09:56:35.110 WSC:D [2022/06/24 12:56:35:1102] D: [wsicli|0|WS/h1/default/foo.bar.fi]: _lws_change_pollfd: fd 14 events 5 -> 5<0a>
09:56:36.111 WSC:W WS_Client_Process: still in CANCEL state, wsiCloud 0x55cc9885bce0
09:56:36.111 WSC:D [2022/06/24 12:56:36:1116] D: [wsicli|0|WS/h1/default/foo.bar.fi]: _lws_change_pollfd: fd 14 events 5 -> 5<0a>
09:56:37.113 WSC:W WS_Client_Process: still in CANCEL state, wsiCloud 0x55cc9885bce0
09:56:37.113 WSC:D [2022/06/24 12:56:37:1131] D: [wsicli|0|WS/h1/default/foo.bar.fi]: _lws_change_pollfd: fd 14 events 5 -> 5<0a>
09:56:38.114 WSC:W WS_Client_Process: still in CANCEL state, wsiCloud 0x55cc9885bce0
09:56:38.114 WSC:D [2022/06/24 12:56:38:1147] D: [wsicli|0|WS/h1/default/foo.bar.fi]: _lws_change_pollfd: fd 14 events 5 -> 5<0a>
09:56:39.116 WSC:W WS_Client_Process: still in CANCEL state, wsiCloud 0x55cc9885bce0
09:56:39.116 WSC:D [2022/06/24 12:56:39:1162] D: [wsicli|0|WS/h1/default/foo.bar.fi]: _lws_change_pollfd: fd 14 events 5 -> 5<0a>

The final log entries indicate that my code is trying to cancel/disconnect
the ws connection by calling lws_callback_on_writable() and returning -1
in the callback - but the callback is never called (well, maybe because
the connection isn't up yet?).

Am I supposed to get the LWS_CALLBACK_(ADD|DEL|CHANGE_MODE)_POLL_FD
calls in the callback or is lws 4.3.2 using threads to handle everything
internally?  I assume I should be receiving _some_ callbacks, at least,
in addition to 21 (LWS_CALLBACK_OPENSSL_LOAD_EXTRA_CLIENT_VERIFY_CERTS),
27 (LWS_CALLBACK_PROTOCOL_INIT), 85 (LWS_CALLBACK_CLIENT_HTTP_BIND_PROTOCOL),
105 (LWS_CALLBACK_CONNECTING) and 19 (LWS_CALLBACK_SERVER_NEW_CLIENT_INSTANTIATED)
which are visible in the log.

So WHAT am I doing wrong? :-)

Usually, posting a question oublicly helps me to find the problem on my own,
but I'm not sure if it works this time..

Thank you!

  -jm


More information about the Libwebsockets mailing list