[Libwebsockets] libwebsockets-test-client timeout error

Andy Green andy at warmcat.com
Mon Apr 4 11:07:33 CEST 2016



On April 4, 2016 4:49:55 PM GMT+08:00, Jun MA <mj.saber1990 at gmail.com> wrote:
>Hi Andy,
>
>Thank you so much for your quick reply!
>I compiled zlib myself and then compiled lws with
>-DCMAKE_OSX_ARCHITECTURES:STRING=x86_64 and it succeeded.

Not sure why that magic is needed, it's not needed in, eg, Linux.

But you're working... that's good.

>However, I run into another problem when playing with
>libwebsockets-test-echo.
>I started libwebsockets-test-echo server locally, and run
>libwebsockets-test-echo --client localhost --port 7681, and
>libwebsockets-test-echo server aborted saying Assertion failed:
>((int)pss->len == -1), function callback_echo, file
>/Users/jun.ma/workspace/libwebsockets/test-server/test-echo.c, line
>109.

It again does not occur on Linux.

$ libwebsockets-test-echo --client localhost --port 7681
[2016/03/04 16:58:53:4749] NOTICE: Built to support client operations
[2016/03/04 16:58:53:4749] NOTICE: Built to support server operations
lwsts[16804]: libwebsockets test server echo - license LGPL2.1+SLE
lwsts[16804]: (C) Copyright 2010-2016 Andy Green <andy at warmcat.com>
lwsts[16804]: Running in client mode
lwsts[16804]: Initial logging level 7
lwsts[16804]: Libwebsockets version: 1.7.0 agreen at build.warmcat.com-v1.7.0-98-ge599b4d
lwsts[16804]: IPV6 not compiled in
lwsts[16804]: libev support not compiled in
lwsts[16804]: libuv support not compiled in
lwsts[16804]:  Threads: 1 each 100000 fds
lwsts[16804]:  mem: platform fd map: 800000 bytes
lwsts[16804]: Creating Vhost 'default' port -1, 1 protocols
lwsts[16804]:  mem: per-conn:          432 bytes + protocol rx buf
lwsts[16804]:  canonical_hostname = build.warmcat.com
lwsts[16804]: Client connecting to localhost:7681....
lwsts[16804]: checking client ext permessage-deflate
lwsts[16804]: instantiating client ext permessage-deflate
lwsts[16804]:    ok
lwsts[16804]: Client TX: hello from libwebsockets-test-echo client pid 16804 index 0
lwsts[16804]: Client RX: hello from libwebsockets-test-echo client pid 16804 index 0
lwsts[16804]: Client TX: hello from libwebsockets-test-echo client pid 16804 index 1
lwsts[16804]: Client RX: hello from libwebsockets-test-echo client pid 16804 index 1
lwsts[16804]: Client TX: hello from libwebsockets-test-echo client pid 16804 index 2
lwsts[16804]: Client RX: hello from libwebsockets-test-echo client pid 16804 index 2
lwsts[16804]: Client TX: hello from libwebsockets-test-echo client pid 16804 index 3
lwsts[16804]: Client RX: hello from libwebsockets-test-echo client pid 16804 index 3
...

Patches welcome if you have some mac-specific problem.

-Andy

>Here is the full trace of echo server:
>
>[2016/03/04 01:36:23:5729] NOTICE: Built to support client operations
>[2016/03/04 01:36:23:5729] NOTICE: Built to support server operations
>Apr  4 01:36:23  lwsts[3906] <Notice>: libwebsockets test server echo -
>license LGPL2.1+SLE
>Apr  4 01:36:23  lwsts[3906] <Notice>: (C) Copyright 2010-2016 Andy
>Green <andy at warmcat.com>
>Apr  4 01:36:23  lwsts[3906] <Notice>: Running in server mode
>Apr  4 01:36:23  lwsts[3906] <Notice>: Initial logging level 65535
>Apr  4 01:36:23  lwsts[3906] <Notice>: Libwebsockets version: 1.7.5
>jun.ma at MacBook-Pro-2-v1.7.5
>Apr  4 01:36:23  lwsts[3906] <Notice>: IPV6 not compiled in
>Apr  4 01:36:23  lwsts[3906] <Notice>: libev support not compiled in
>Apr  4 01:36:23  lwsts[3906] <Info>:  LWS_DEF_HEADER_LEN    : 1024
>Apr  4 01:36:23  lwsts[3906] <Info>:  LWS_MAX_PROTOCOLS     : 5
>Apr  4 01:36:23  lwsts[3906] <Info>:  LWS_MAX_SMP           : 32
>Apr  4 01:36:23  lwsts[3906] <Info>:  SPEC_LATEST_SUPPORTED : 13
>Apr  4 01:36:23  lwsts[3906] <Info>:  sizeof (*info)        : 216
>Apr  4 01:36:23  lwsts[3906] <Info>:  SYSTEM_RANDOM_FILEPATH:
>'/dev/urandom'
>Apr  4 01:36:23  lwsts[3906] <Info>:  default timeout (secs): 20
>Apr  4 01:36:23  lwsts[3906] <Notice>:  Threads: 1 each 256 fds
>Apr  4 01:36:23  lwsts[3906] <Info>:  mem: context:         10536 bytes
>(6440 ctx + (1 thr x 4096))
>Apr  4 01:36:23  lwsts[3906] <Info>:  mem: http hdr rsvd:   67712 bytes
>(1 thr x (1024 + 3208) x 16))
>Apr  4 01:36:23  lwsts[3906] <Info>:  mem: pollfd map:       2048
>Apr  4 01:36:23  lwsts[3906] <Notice>:  mem: platform fd map:  2048
>bytes
>Apr  4 01:36:23  lwsts[3906] <Info>:  LWS_MAX_EXTENSIONS_ACTIVE: 2
>Apr  4 01:36:23  lwsts[3906] <Notice>:  mem: per-conn:          368
>bytes + protocol rx buf
>Apr  4 01:36:23  lwsts[3906] <Notice>:  canonical_hostname =
>MacBook-Pro-2
>Apr  4 01:36:23  lwsts[3906] <Debug>: insert_wsi_socket_into_fds:
>0x7f9080500430: tsi=0, sock=6, pos-in-fds=1
>Apr  4 01:36:23  lwsts[3906] <Notice>:  Listening on port 7681
>Apr  4 01:36:36  lwsts[3906] <Debug>: accepted new conn  port 55715 on
>fd=7
>Apr  4 01:36:36  lwsts[3906] <Info>: Accepted 0x7f9080500760 to tsi 0
>Apr  4 01:36:36  lwsts[3906] <Debug>: lws_adopt_socket: new wsi
>0x7f9080500760
>Apr  4 01:36:36  lwsts[3906] <Debug>: insert_wsi_socket_into_fds:
>0x7f9080500760: tsi=0, sock=7, pos-in-fds=2
>Apr  4 01:36:36  lwsts[3906] <Info>: lws_header_table_attach: wsi
>0x7f9080500760: ah 0x0 (tsi 0)
>Apr  4 01:36:36  lwsts[3906] <Info>: lws_header_table_attach: wsi
>0x7f9080500760: ah 0x7f908080c400: count 1 (on exit)
>Apr  4 01:36:36  lwsts[3906] <Debug>: lws_server_socket_service:
>0x7f9080500760: rxpos:0 rxlen:0
>Apr  4 01:36:36  lwsts[3906] <Debug>: lws_server_socket_service: wsi
>0x7f9080500760, ah->rxlen = 325
>
>Apr  4 01:36:36  lwsts[3906] <Debug>: lws_read: incoming len 325
>Apr  4 01:36:36  lwsts[3906] <Debug>: issuing 325 bytes to parser
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'G' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'E' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'T' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART ' ' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: known hdr 0
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(0) '/'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(0) ' '
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(15) 'H'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(15) 'T'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(15) 'T'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(15) 'P'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(15) '/'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(15) '1'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(15) '.'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(15) '1'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(15) '
>	'
>Apr  4 01:36:36  lwsts[3906] <Debug>: *
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_SKIPPING_SAW_CR '
>	'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'P' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'r' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'a' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'g' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'm' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'a' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART ':' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: known hdr 23
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(23) ' '
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(23) 'n'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(23) 'o'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(23) '-'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(23) 'c'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(23) 'a'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(23) 'c'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(23) 'h'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(23) 'e'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(23) '
>	'
>Apr  4 01:36:36  lwsts[3906] <Debug>: *
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_SKIPPING_SAW_CR '
>	'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'C' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'a' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'c' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'h' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'e' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART '-' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'C' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'o' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'n' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 't' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'r' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'o' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'l' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART ':' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: known hdr 24
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(24) ' '
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(24) 'n'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(24) 'o'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(24) '-'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(24) 'c'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(24) 'a'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(24) 'c'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(24) 'h'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(24) 'e'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(24) '
>	'
>Apr  4 01:36:36  lwsts[3906] <Debug>: *
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_SKIPPING_SAW_CR '
>	'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'H' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'o' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 's' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 't' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART ':' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: known hdr 3
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(3) ' '
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(3) 'l'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(3) 'o'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(3) 'c'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(3) 'a'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(3) 'l'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(3) 'h'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(3) 'o'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(3) 's'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(3) 't'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(3) ':'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(3) '7'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(3) '6'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(3) '8'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(3) '1'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(3) '
>	'
>Apr  4 01:36:36  lwsts[3906] <Debug>: *
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_SKIPPING_SAW_CR '
>	'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'U' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'p' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'g' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'r' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'a' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'd' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'e' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART ':' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: known hdr 5
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(5) ' '
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(5) 'w'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(5) 'e'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(5) 'b'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(5) 's'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(5) 'o'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(5) 'c'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(5) 'k'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(5) 'e'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(5) 't'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(5) '
>	'
>Apr  4 01:36:36  lwsts[3906] <Debug>: *
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_SKIPPING_SAW_CR '
>	'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'C' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'o' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'n' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'n' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'e' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'c' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 't' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'i' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'o' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'n' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART ':' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: known hdr 4
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(4) ' '
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(4) 'U'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(4) 'p'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(4) 'g'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(4) 'r'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(4) 'a'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(4) 'd'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(4) 'e'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(4) '
>	'
>Apr  4 01:36:36  lwsts[3906] <Debug>: *
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_SKIPPING_SAW_CR '
>	'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'S' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'e' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'c' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART '-' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'W' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'e' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'b' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'S' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'o' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'c' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'k' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'e' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 't' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART '-' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'K' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'e' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'y' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART ':' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: known hdr 32
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(32) ' '
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(32) 'M'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(32) 'v'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(32) 'W'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(32) 'b'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(32) 'r'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(32) 'i'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(32) '2'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(32) '0'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(32) '8'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(32) 'A'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(32) 'm'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(32) 'D'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(32) 'r'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(32) 'G'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(32) '8'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(32) '0'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(32) 'w'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(32) 'y'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(32) 'B'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(32) 'K'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(32) 'I'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(32) 'w'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(32) '='
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(32) '='
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(32) '
>	'
>Apr  4 01:36:36  lwsts[3906] <Debug>: *
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_SKIPPING_SAW_CR '
>	'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'O' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'r' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'i' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'g' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'i' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'n' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART ':' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: known hdr 6
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(6) ' '
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(6) 'h'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(6) 't'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(6) 't'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(6) 'p'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(6) ':'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(6) '/'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(6) '/'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(6) 'l'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(6) 'o'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(6) 'c'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(6) 'a'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(6) 'l'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(6) 'h'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(6) 'o'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(6) 's'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(6) 't'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(6) ':'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(6) '7'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(6) '6'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(6) '8'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(6) '1'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(6) '
>	'
>Apr  4 01:36:36  lwsts[3906] <Debug>: *
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_SKIPPING_SAW_CR '
>	'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'S' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'e' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'c' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART '-' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'W' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'e' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'b' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'S' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'o' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'c' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'k' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'e' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 't' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART '-' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'E' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'x' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 't' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'e' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'n' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 's' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'i' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'o' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'n' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 's' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART ':' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: known hdr 9
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) ' '
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'p'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'e'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'r'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'm'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'e'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 's'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 's'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'a'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'g'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'e'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) '-'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'd'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'e'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'f'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'l'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'a'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 't'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'e'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) ';'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) ' '
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'c'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'l'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'i'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'e'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'n'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 't'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) '_'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'n'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'o'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) '_'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'c'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'o'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'n'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 't'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'e'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'x'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 't'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) '_'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 't'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'a'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'k'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'e'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'o'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'v'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'e'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'r'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) ';'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) ' '
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'c'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'l'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'i'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'e'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'n'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 't'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) '_'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'm'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'a'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'x'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) '_'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'w'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'i'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'n'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'd'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'o'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'w'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) '_'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'b'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 'i'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 't'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) 's'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(9) '
>	'
>Apr  4 01:36:36  lwsts[3906] <Debug>: *
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_SKIPPING_SAW_CR '
>	'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'S' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'e' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'c' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART '-' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'W' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'e' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'b' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'S' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'o' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'c' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'k' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'e' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 't' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART '-' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'V' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'e' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'r' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 's' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'i' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'o' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART 'n' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART ':' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: known hdr 33
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(33) ' '
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(33) '1'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(33) '3'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOK_(33) '
>	'
>Apr  4 01:36:36  lwsts[3906] <Debug>: *
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_SKIPPING_SAW_CR '
>	'
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART '
>	' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_NAME_PART '
>	' (mode=0)
>Apr  4 01:36:36  lwsts[3906] <Debug>: known hdr 8
>Apr  4 01:36:36  lwsts[3906] <Debug>: v13 hdrs completed
>Apr  4 01:36:36  lwsts[3906] <Debug>: lws_handshake_server: lws_parse
>sees parsing complete
>Apr  4 01:36:36  lwsts[3906] <Debug>: lws_handshake_server:
>wsi->more_rx_waiting=0
>Apr  4 01:36:36  lwsts[3906] <Info>: Upgrade to ws
>Apr  4 01:36:36  lwsts[3906] <Info>: defaulting to prot 0 handler
>Apr  4 01:36:36  lwsts[3906] <Info>: lws_ensure_user_space:
>0x7f9080500760 protocol 0x104d2a5e0
>Apr  4 01:36:36  lwsts[3906] <Debug>: lws_parse calling handshake_04
>Apr  4 01:36:36  lwsts[3906] <Info>: lws_ensure_user_space:
>0x7f9080500760 protocol 0x104d2a5e0
>Apr  4 01:36:36  lwsts[3906] <Info>: lws_ensure_user_space:
>0x7f9080500760 protocol pss 1080, user_space=-2130697728
>Apr  4 01:36:36  lwsts[3906] <Debug>: WSI_TOKEN_EXTENSIONS =
>'permessage-deflate; client_no_context_takeover;
>client_max_window_bits'
>Apr  4 01:36:36  lwsts[3906] <Debug>:
>lws_extension_callback_pm_deflate: LWS_EXT_CB_*CONSTRUCT
>Apr  4 01:36:36  lwsts[3906] <Error>:    ok
>Apr  4 01:36:36  lwsts[3906] <Debug>: count_act_ext <- 1
>Apr  4 01:36:36  lwsts[3906] <Debug>: issuing resp pkt 175 len
>Apr  4 01:36:36  lwsts[3906] <Info>: lws_handshake_server:
>0x7f9080500760: inheriting ah in ws mode (rxpos:0, rxlen:325)
>Apr  4 01:36:36  lwsts[3906] <Debug>: lws_union_transition:
>0x7f9080500760: mode 3
>Apr  4 01:36:36  lwsts[3906] <Info>: Allocating RX buffer 1040
>Apr  4 01:36:36  lwsts[3906] <Debug>: accepted v13 connection
>Apr  4 01:36:36  lwsts[3906] <Debug>: lws_read: thinks we have used 0
>Apr  4 01:36:36  lwsts[3906] <Info>: lws_read: read_ok, used 325
>Apr  4 01:36:36  lwsts[3906] <Info>: lws_header_table_detach: wsi
>0x7f9080500760: ah 0x7f908080c400 (tsi=0, count = 1)
>Apr  4 01:36:37  lwsts[3906] <Debug>: lws_read: incoming len 67
>Apr  4 01:36:37  lwsts[3906] <Debug>: lws_interpret_incoming_packet:
>received 67 byte packet
>Apr  4 01:36:37  lwsts[3906] <Debug>: spill on
>Apr  4 01:36:37  lwsts[3906] <Debug>: lws_rx_sm: passing 61 to ext
>Apr  4 01:36:37  lwsts[3906] <Debug>: 
>lws_extension_callback_pm_deflate: LWS_EXT_CB_PAYLOAD_RX: in 61,
>existing in 0
>Apr  4 01:36:37  lwsts[3906] <Debug>: inflate ret 0, avi 0, avo 965,
>wsifinal 1
>Apr  4 01:36:37  lwsts[3906] <Debug>: RX APPEND_TRAILER-DO
>Apr  4 01:36:37  lwsts[3906] <Debug>: RX trailer inf returned 0, avi 0,
>avo 965
>Apr  4 01:36:37  lwsts[3906] <Debug>:  
>lws_extension_callback_pm_deflate: RX leaving with new effbuff len 59,
>ret 0, rx.avail_in=0, TOTAL RX since FIN 59
>Apr  4 01:36:37  lwsts[3906] <Info>: lws_is_final_fragment: final 1, rx
>pk length 0, draining 0
>Apr  4 01:36:37  lwsts[3906] <Info>: +++ test-echo: RX len 59 final 1,
>pss->len=0
>Assertion failed: ((int)pss->len == -1), function callback_echo, file
>/Users/jun.ma/workspace/libwebsockets/test-server/test-echo.c, line
>109.



>[1]    3906 abort      /usr/local/bin/libwebsockets-test-echo -d65535
>
>And trace of echo client:
>
>[2016/03/04 01:36:36:8867] NOTICE: Built to support client operations
>[2016/03/04 01:36:36:8867] NOTICE: Built to support server operations
>Apr  4 01:36:36  lwsts[3912] <Notice>: libwebsockets test server echo -
>license LGPL2.1+SLE
>Apr  4 01:36:36  lwsts[3912] <Notice>: (C) Copyright 2010-2016 Andy
>Green <andy at warmcat.com>
>Apr  4 01:36:36  lwsts[3912] <Notice>: Running in client mode
>Apr  4 01:36:36  lwsts[3912] <Info>: requiring server cert validation
>against
>/usr/local/share/libwebsockets-test-server/libwebsockets-test-server.pem
>Apr  4 01:36:36  lwsts[3912] <Notice>: Initial logging level 65535
>Apr  4 01:36:36  lwsts[3912] <Notice>: Libwebsockets version: 1.7.5
>jun.ma at MacBook-Pro-2-v1.7.5
>Apr  4 01:36:36  lwsts[3912] <Notice>: IPV6 not compiled in
>Apr  4 01:36:36  lwsts[3912] <Notice>: libev support not compiled in
>Apr  4 01:36:36  lwsts[3912] <Info>:  LWS_DEF_HEADER_LEN    : 1024
>Apr  4 01:36:36  lwsts[3912] <Info>:  LWS_MAX_PROTOCOLS     : 5
>Apr  4 01:36:36  lwsts[3912] <Info>:  LWS_MAX_SMP           : 32
>Apr  4 01:36:36  lwsts[3912] <Info>:  SPEC_LATEST_SUPPORTED : 13
>Apr  4 01:36:36  lwsts[3912] <Info>:  sizeof (*info)        : 216
>Apr  4 01:36:36  lwsts[3912] <Info>:  SYSTEM_RANDOM_FILEPATH:
>'/dev/urandom'
>Apr  4 01:36:36  lwsts[3912] <Info>:  default timeout (secs): 20
>Apr  4 01:36:36  lwsts[3912] <Notice>:  Threads: 1 each 256 fds
>Apr  4 01:36:36  lwsts[3912] <Info>:  mem: context:         10536 bytes
>(6440 ctx + (1 thr x 4096))
>Apr  4 01:36:36  lwsts[3912] <Info>:  mem: http hdr rsvd:   67712 bytes
>(1 thr x (1024 + 3208) x 16))
>Apr  4 01:36:36  lwsts[3912] <Info>:  mem: pollfd map:       2048
>Apr  4 01:36:36  lwsts[3912] <Notice>:  mem: platform fd map:  2048
>bytes
>Apr  4 01:36:36  lwsts[3912] <Info>:  LWS_MAX_EXTENSIONS_ACTIVE: 2
>Apr  4 01:36:36  lwsts[3912] <Notice>:  mem: per-conn:          368
>bytes + protocol rx buf
>Apr  4 01:36:36  lwsts[3912] <Notice>:  canonical_hostname =
>MacBook-Pro-2
>Apr  4 01:36:36  lwsts[3912] <Notice>: Client connecting to
>localhost:7681....
>Apr  4 01:36:36  lwsts[3912] <Info>: lws_header_table_attach: wsi
>0x7ff948d00300: ah 0x0 (tsi 0)
>Apr  4 01:36:36  lwsts[3912] <Info>: lws_header_table_attach: wsi
>0x7ff948d00300: ah 0x7ff949806a00: count 1 (on exit)
>Apr  4 01:36:36  lwsts[3912] <Debug>: lws_client_connect: direct conn
>Apr  4 01:36:36  lwsts[3912] <Debug>: lws_client_connect_2
>Apr  4 01:36:36  lwsts[3912] <Debug>: lws_client_connect_2: address
>localhost
>Apr  4 01:36:36  lwsts[3912] <Debug>: insert_wsi_socket_into_fds:
>0x7ff948d00300: tsi=0, sock=8, pos-in-fds=1
>Apr  4 01:36:36  lwsts[3912] <Debug>: nonblocking connect retry
>Apr  4 01:36:36  lwsts[3912] <Debug>: lws_client_connect_2
>Apr  4 01:36:36  lwsts[3912] <Debug>: lws_client_connect_2: address
>localhost
>Apr  4 01:36:36  lwsts[3912] <Debug>: connected
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'H' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'T' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'T' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'P' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART '/' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART '1' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART '.' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART '1' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART ' ' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: known hdr 15
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(15) '1'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(15) '0'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(15) '1'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(15) ' '
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(15) 'S'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(15) 'w'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(15) 'i'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(15) 't'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(15) 'c'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(15) 'h'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(15) 'i'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(15) 'n'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(15) 'g'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(15) ' '
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(15) 'P'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(15) 'r'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(15) 'o'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(15) 't'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(15) 'o'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(15) 'c'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(15) 'o'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(15) 'l'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(15) 's'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(15) '
>	'
>Apr  4 01:36:36  lwsts[3912] <Debug>: *
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_SKIPPING_SAW_CR '
>	'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'U' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'p' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'g' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'r' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'a' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'd' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'e' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART ':' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: known hdr 5
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(5) ' '
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(5) 'W'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(5) 'e'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(5) 'b'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(5) 'S'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(5) 'o'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(5) 'c'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(5) 'k'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(5) 'e'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(5) 't'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(5) '
>	'
>Apr  4 01:36:36  lwsts[3912] <Debug>: *
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_SKIPPING_SAW_CR '
>	'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'C' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'o' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'n' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'n' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'e' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'c' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 't' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'i' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'o' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'n' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART ':' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: known hdr 4
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(4) ' '
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(4) 'U'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(4) 'p'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(4) 'g'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(4) 'r'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(4) 'a'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(4) 'd'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(4) 'e'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(4) '
>	'
>Apr  4 01:36:36  lwsts[3912] <Debug>: *
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_SKIPPING_SAW_CR '
>	'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'S' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'e' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'c' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART '-' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'W' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'e' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'b' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'S' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'o' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'c' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'k' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'e' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 't' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART '-' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'A' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'c' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'c' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'e' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'p' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 't' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART ':' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: known hdr 13
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(13) ' '
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(13) 'w'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(13) 'D'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(13) 'f'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(13) 't'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(13) '3'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(13) 'A'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(13) '+'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(13) 'V'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(13) 'V'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(13) 'o'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(13) 'j'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(13) 'b'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(13) 'R'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(13) 'G'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(13) 'y'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(13) 'D'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(13) 'u'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(13) 'W'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(13) 'j'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(13) 'h'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(13) '5'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(13) 'A'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(13) '4'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(13) '8'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(13) 'l'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(13) 'J'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(13) 'M'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(13) '='
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(13) '
>	'
>Apr  4 01:36:36  lwsts[3912] <Debug>: *
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_SKIPPING_SAW_CR '
>	'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'S' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'e' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'c' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART '-' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'W' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'e' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'b' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'S' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'o' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'c' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'k' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'e' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 't' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART '-' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'E' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'x' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 't' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'e' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'n' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 's' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'i' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'o' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 'n' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART 's' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART ':' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: known hdr 9
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(9) ' '
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(9) 'p'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(9) 'e'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(9) 'r'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(9) 'm'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(9) 'e'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(9) 's'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(9) 's'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(9) 'a'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(9) 'g'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(9) 'e'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(9) '-'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(9) 'd'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(9) 'e'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(9) 'f'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(9) 'l'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(9) 'a'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(9) 't'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(9) 'e'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOK_(9) '
>	'
>Apr  4 01:36:36  lwsts[3912] <Debug>: *
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_SKIPPING_SAW_CR '
>	'
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART '
>	' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: WSI_TOKEN_NAME_PART '
>	' (mode=13)
>Apr  4 01:36:36  lwsts[3912] <Debug>: known hdr 8
>Apr  4 01:36:36  lwsts[3912] <Debug>: v13 hdrs completed
>Apr  4 01:36:36  lwsts[3912] <Debug>: lws_client_int_s_hs: no protocol
>list
>Apr  4 01:36:36  lwsts[3912] <Info>: lws_client_int_s_hs:
>WSI_TOKEN_PROTOCOL is null
>Apr  4 01:36:36  lwsts[3912] <Notice>: checking client ext
>permessage-deflate
>Apr  4 01:36:36  lwsts[3912] <Notice>: instantiating client ext
>permessage-deflate
>Apr  4 01:36:36  lwsts[3912] <Debug>:
>lws_extension_callback_pm_deflate: LWS_EXT_CB_*CONSTRUCT
>Apr  4 01:36:36  lwsts[3912] <Error>:    ok
>Apr  4 01:36:36  lwsts[3912] <Debug>: _lws_rx_flow_control: no pending
>change
>Apr  4 01:36:36  lwsts[3912] <Info>: lws_ensure_user_space:
>0x7ff948d00300 protocol 0x10349b5e0
>Apr  4 01:36:36  lwsts[3912] <Info>: lws_header_table_detach: wsi
>0x7ff948d00300: ah 0x7ff949806a00 (tsi=0, count = 1)
>Apr  4 01:36:36  lwsts[3912] <Debug>: lws_union_transition:
>0x7ff948d00300: mode 4
>Apr  4 01:36:36  lwsts[3912] <Info>: Allocating client RX buffer 1040
>Apr  4 01:36:36  lwsts[3912] <Debug>: handshake OK for protocol
>Apr  4 01:36:36  lwsts[3912] <Debug>: Client has connected
>Apr  4 01:36:37  lwsts[3912] <Debug>: lws_calllback_as_writeable:
>0x7ff948d00300 (user=0x7ff94a800000)
>Apr  4 01:36:37  lwsts[3912] <Notice>: Client TX: hello from
>libwebsockets-test-echo client pid 3912 index 0
>Apr  4 01:36:37  lwsts[3912] <Debug>:
>lws_extension_callback_pm_deflate: TX: eff_buf length 59
>Apr  4 01:36:37  lwsts[3912] <Debug>: tx held 4
>Apr  4 01:36:37  lwsts[3912] <Debug>:   TX rewritten with new effbuff
>len 61, ret 0
>Apr  4 01:36:37  lwsts[3912] <Debug>:
>lws_extension_callback_pm_deflate: tx opcode 0xC1
>Apr  4 01:36:37  lwsts[3912] <Debug>: written 67 bytes to client
>Apr  4 01:36:37  lwsts[3912] <Debug>: _lws_rx_flow_control: no pending
>change
>Apr  4 01:36:37  lwsts[3912] <Info>: service_fd: closing due to 0
>length read
>Apr  4 01:36:37  lwsts[3912] <Debug>: Close and handled
>Apr  4 01:36:37  lwsts[3912] <Info>: lws_close_free_wsi: shutting down
>connection: 0x7ff948d00300
>Apr  4 01:36:37  lwsts[3912] <Info>: service_fd: closing due to 0
>length read
>Apr  4 01:36:37  lwsts[3912] <Debug>: Close and handled
>Apr  4 01:36:37  lwsts[3912] <Info>: lws_close_free_wsi: real
>just_kill_connection: 0x7ff948d00300
>Apr  4 01:36:37  lwsts[3912] <Info>: remove_wsi_socket_from_fds:
>wsi=0x7ff948d00300, sock=8, fds pos=1, end guy pos=2, endfd=0
>Apr  4 01:36:37  lwsts[3912] <Debug>: calling back CLOSED
>Apr  4 01:36:37  lwsts[3912] <Debug>: closed
>Apr  4 01:36:37  lwsts[3912] <Debug>:
>lws_extension_callback_pm_deflate: LWS_EXT_CB_DESTROY
>Apr  4 01:36:37  lwsts[3912] <Info>: lws_header_table_detach: wsi
>0x7ff948d00300: ah 0x0 (tsi=0, count = 0)
>Apr  4 01:36:37  lwsts[3912] <Debug>: lws_free_wsi: 0x7ff948d00300,
>remaining wsi 0
>Apr  4 01:36:37  lwsts[3912] <Notice>: Client connecting to
>localhost:7681....
>Apr  4 01:36:37  lwsts[3912] <Info>: lws_header_table_attach: wsi
>0x7ff94a3001c0: ah 0x0 (tsi 0)
>Apr  4 01:36:37  lwsts[3912] <Info>: lws_header_table_attach: wsi
>0x7ff94a3001c0: ah 0x7ff949806a00: count 1 (on exit)
>Apr  4 01:36:37  lwsts[3912] <Debug>: lws_client_connect: direct conn
>Apr  4 01:36:37  lwsts[3912] <Debug>: lws_client_connect_2
>Apr  4 01:36:37  lwsts[3912] <Debug>: lws_client_connect_2: address
>localhost
>Apr  4 01:36:37  lwsts[3912] <Debug>: insert_wsi_socket_into_fds:
>0x7ff94a3001c0: tsi=0, sock=8, pos-in-fds=1
>Apr  4 01:36:37  lwsts[3912] <Debug>: nonblocking connect retry
>Apr  4 01:36:37  lwsts[3912] <Debug>: lws_client_connect_2
>Apr  4 01:36:37  lwsts[3912] <Debug>: lws_client_connect_2: address
>localhost
>Apr  4 01:36:37  lwsts[3912] <Debug>: Connect failed errno=61
>Apr  4 01:36:37  lwsts[3912] <Info>: lws_close_free_wsi: shutting down
>connection: 0x7ff94a3001c0
>Apr  4 01:36:37  lwsts[3912] <Debug>: closing: shutdown ret 57
>Apr  4 01:36:37  lwsts[3912] <Debug>: closed
>Apr  4 01:36:37  lwsts[3912] <Debug>: lws_client_connect_2
>Apr  4 01:36:37  lwsts[3912] <Debug>: lws_client_connect_2: address
>localhost
>Apr  4 01:36:37  lwsts[3912] <Debug>: Connect failed errno=22
>Apr  4 01:36:37  lwsts[3912] <Info>: lws_close_free_wsi: real
>just_kill_connection: 0x7ff94a3001c0
>Apr  4 01:36:37  lwsts[3912] <Info>: remove_wsi_socket_from_fds:
>wsi=0x7ff94a3001c0, sock=8, fds pos=1, end guy pos=2, endfd=0
>Apr  4 01:36:37  lwsts[3912] <Debug>: Connection closed before server
>reply
>Apr  4 01:36:37  lwsts[3912] <Debug>: closed
>Apr  4 01:36:37  lwsts[3912] <Info>: lws_header_table_detach: wsi
>0x7ff94a3001c0: ah 0x7ff949806a00 (tsi=0, count = 1)
>Apr  4 01:36:37  lwsts[3912] <Debug>: lws_free_wsi: 0x7ff94a3001c0,
>remaining wsi 0
>Apr  4 01:36:37  lwsts[3912] <Debug>: closed
>
>I’m using v1.7.5 tag.
>
>Thanks,
>Jun
>> On Apr 3, 2016, at 6:15 PM, Andy Green <andy at warmcat.com> wrote:
>> 
>> 
>> 
>> On 04/04/2016 09:05 AM, Jun MA wrote:
>>> Hi guys,
>>> 
>>> I’m new to lws and I met some issue when start playing with it. Hope
>you guys can help me out.
>>> I ran libwebsockets-test-server on my local machine and I can
>connect to it by web browser(127.0.0.1:7681), but when I tried
>'libwebsockets-test-client localhost’, I got following messages:
>> 
>> Okay...
>> 
>>> [2016/03/03 17:45:36:4491] NOTICE: libwebsockets test client -
>license LGPL2.1+SLE
>>> [2016/03/03 17:45:36:4491] NOTICE: (C) Copyright 2010-2016 Andy
>Green <andy at warmcat.com>
>>> [2016/03/03 17:45:36:4491] NOTICE: Initial logging level 7
>>> [2016/03/03 17:45:36:4491] NOTICE: Libwebsockets version: 1.7.0
>jun.ma at MacBook-Pro-2.local-v1.7.0-97-g0d0124a
>>> [2016/03/03 17:45:36:4491] NOTICE: IPV6 not compiled in
>>> [2016/03/03 17:45:36:4492] NOTICE: libev support not compiled in
>>> [2016/03/03 17:45:36:4492] NOTICE: libuv support not compiled in
>>> [2016/03/03 17:45:36:4492] NOTICE:  Threads: 1 each 2560 fds
>>> [2016/03/03 17:45:36:4492] NOTICE:  mem: platform fd map: 10240
>bytes
>>> [2016/03/03 17:45:36:4493] NOTICE: Creating Vhost 'default' port -1,
>2 protocols
>>> [2016/03/03 17:45:36:4493] NOTICE:  mem: per-conn:          332
>bytes + protocol rx buf
>>> [2016/03/03 17:45:36:4493] NOTICE:  canonical_hostname =
>MacBook-Pro-2.local
>>> [2016/03/03 17:45:36:4493] NOTICE: using  mode (ws)
>>> [2016/03/03 17:45:36:4493] NOTICE: dumb: connecting
>>> [2016/03/03 17:45:36:4840] NOTICE: mirror: connecting
>>> [2016/03/03 17:45:57:0946] NOTICE: wsi 0x7c150920: TIMEDOUT WAITING
>on 2 (did hdr 0, ah 0x7ba2f098, wl 0, pfd events 0)
>>> [2016/03/03 17:45:57:0947] ERR: mirror:
>LWS_CALLBACK_CLIENT_CONNECTION_ERROR
>> 
>> It works OK here on Linux, one (unrelated) patch ahead at
>e599b4d16cb2.
>> 
>> $ libwebsockets-test-client localhost
>> [2016/03/04 09:08:04:0394] NOTICE: libwebsockets test client -
>license LGPL2.1+SLE
>> [2016/03/04 09:08:04:0394] NOTICE: (C) Copyright 2010-2016 Andy Green
><andy at warmcat.com <mailto:andy at warmcat.com>>
>> [2016/03/04 09:08:04:0394] NOTICE: Initial logging level 7
>> [2016/03/04 09:08:04:0395] NOTICE: Libwebsockets version: 1.7.0
>agreen at build.warmcat.com
><mailto:agreen at build.warmcat.com>-v1.7.0-98-ge599b4d
>> [2016/03/04 09:08:04:0395] NOTICE: IPV6 not compiled in
>> [2016/03/04 09:08:04:0395] NOTICE: libev support not compiled in
>> [2016/03/04 09:08:04:0395] NOTICE: libuv support not compiled in
>> [2016/03/04 09:08:04:0396] NOTICE:  Threads: 1 each 100000 fds
>> [2016/03/04 09:08:04:0408] NOTICE:  mem: platform fd map: 800000
>bytes
>> [2016/03/04 09:08:04:0409] NOTICE: Creating Vhost 'default' port -1,
>2 protocols
>> [2016/03/04 09:08:04:0409] NOTICE:  mem: per-conn:          432 bytes
>+ protocol rx buf
>> [2016/03/04 09:08:04:0409] NOTICE:  canonical_hostname =
>build.warmcat.com <http://build.warmcat.com/>
>> [2016/03/04 09:08:04:0409] NOTICE: using  mode (ws)
>> [2016/03/04 09:08:04:0409] NOTICE: dumb: connecting
>> [2016/03/04 09:08:04:0416] NOTICE: mirror: connecting
>> [2016/03/04 09:08:04:0424] NOTICE: mirror:
>LWS_CALLBACK_CLIENT_ESTABLISHED
>> [2016/03/04 09:08:04:5832] NOTICE: mirror: LWS_CALLBACK_CLOSED
>mirror_lifetime=0
>> [2016/03/04 09:08:06:0366] NOTICE: mirror: connecting
>> [2016/03/04 09:08:06:0372] NOTICE: mirror:
>LWS_CALLBACK_CLIENT_ESTABLISHED
>> [2016/03/04 09:08:06:9602] NOTICE: mirror: LWS_CALLBACK_CLOSED
>mirror_lifetime=0
>> [2016/03/04 09:08:08:0626] NOTICE: mirror: connecting
>> [2016/03/04 09:08:08:0632] NOTICE: mirror:
>LWS_CALLBACK_CLIENT_ESTABLISHED
>> [2016/03/04 09:08:08:6234] NOTICE: mirror: LWS_CALLBACK_CLOSED
>mirror_lifetime=0
>> ^C
>> 
>> 
>> You should probably look at the logging on the server side to see
>what it thinks is happening, if you built with DEBUG target you can
>increase the logging with, eg, -d79 or -d65535
>> 
>>> [2016/03/03 17:45:57:0948] NOTICE: lws_header_table_detach: wsi
>0x7c150920: ah held 21s, ah.rxpos 0, ah.rxlen 0, mode/state 10
>4,wsi->more_rx_waiting 0
>>> [2016/03/03 17:45:57:0948] NOTICE: wsi 0x7af507e0: TIMEDOUT WAITING
>on 2 (did hdr 0, ah 0x7ba2e400, wl 0, pfd events 0)
>>> [2016/03/03 17:45:57:0948] ERR: dumb:
>LWS_CALLBACK_CLIENT_CONNECTION_ERROR
>>> [2016/03/03 17:45:57:0948] NOTICE: lws_header_table_detach: wsi
>0x7af507e0: ah held 21s, ah.rxpos 0, ah.rxlen 0, mode/state 10
>4,wsi->more_rx_waiting 0
>>> [2016/03/03 17:45:57:0948] NOTICE: dumb: connecting
>>> [2016/03/03 17:45:57:1273] NOTICE: mirror: connecting
>>> [2016/03/03 17:46:18:2726] NOTICE: wsi 0x7c250740: TIMEDOUT WAITING
>on 2 (did hdr 0, ah 0x7ba2f098, wl 0, pfd events 0)
>>> [2016/03/03 17:46:18:2727] ERR: mirror:
>LWS_CALLBACK_CLIENT_CONNECTION_ERROR
>>> [2016/03/03 17:46:18:2728] NOTICE: lws_header_table_detach: wsi
>0x7c250740: ah held 21s, ah.rxpos 0, ah.rxlen 0, mode/state 10
>4,wsi->more_rx_waiting 0
>>> [2016/03/03 17:46:18:2728] NOTICE: wsi 0x7c250500: TIMEDOUT WAITING
>on 2 (did hdr 0, ah 0x7ba2e400, wl 0, pfd events 0)
>>> [2016/03/03 17:46:18:2728] ERR: dumb:
>LWS_CALLBACK_CLIENT_CONNECTION_ERROR
>>> [2016/03/03 17:46:18:2728] NOTICE: lws_header_table_detach: wsi
>0x7c250500: ah held 21s, ah.rxpos 0, ah.rxlen 0, mode/state 10
>4,wsi->more_x_waiting 0
>>> 
>>> I’m using mac os el capitan x86_64, I’m not sure if this is related
>but I do have a hard time trying to compile this library.
>>> If I built the make file by using cmake -DLWS_WITH_SSL=0, when
>making the file, I got the following:
>> 
>> Again there are no build problems on Linux / current master here,
>with a fresh build dir and cmake .. -DLWS_WITH_SSL=0
>> 
>>> Undefined symbols for architecture x86_64:
>>>  "_deflate", referenced from:
>>>      _lws_extension_callback_pm_deflate in
>extension-permessage-deflate.c.o
>>>     (maybe you meant: _lws_ext_pm_deflate_options,
>_lws_extension_callback_pm_deflate )
>>>  "_deflateEnd", referenced from:
>>>      _lws_extension_callback_pm_deflate in
>extension-permessage-deflate.c.o
>>>  "_deflateInit2_", referenced from:
>>>      _lws_extension_callback_pm_deflate in
>extension-permessage-deflate.c.o
>>>  "_inflate", referenced from:
>>>      _lws_extension_callback_pm_deflate in
>extension-permessage-deflate.c.o
>>>  "_inflateEnd", referenced from:
>>>      _lws_extension_callback_pm_deflate in
>extension-permessage-deflate.c.o
>>>  "_inflateInit2_", referenced from:
>>>      _lws_extension_callback_pm_deflate in
>extension-permessage-deflate.c.o
>>> ld: symbol(s) not found for architecture x86_64
>>> clang: error: linker command failed with exit code 1 (use -v to see
>invocation)
>>> make[2]: *** [lib/libwebsockets.7.dylib] Error 1
>>> make[1]: *** [CMakeFiles/websockets_shared.dir/all] Error 2
>>> make: *** [all] Error 2
>> 
>> Actually we autobuild against Mac using Travis and a variety of cmake
>options, and there are no problems there either.
>> 
>> https://travis-ci.org/warmcat/libwebsockets
><https://travis-ci.org/warmcat/libwebsockets>
>> 
>>> I tried cmake -DLWS_WITH_SSL=0
>-DCMAKE_OSX_ARCHITECTURES:STRING=x86_64, same error.
>>> So I had to use cmake -DLWS_WITH_SSL=0
>-DCMAKE_OSX_ARCHITECTURES:STRING=i386 to by pass this error message.
>>> I’m not sure if this is related but this is the only thing I did so
>far.
>>> 
>>> Looking forward any suggestion, thank you all in advance.
>> 
>> It looks like you needed to make sure zlib or zlib "devel package"
>whatever that looks like on OSX is installed for... maybe 64-bit zlib.
>> 
>> -Andy
>> 
>>> Bests,
>>> Jun
>>> _______________________________________________
>>> Libwebsockets mailing list
>>> Libwebsockets at ml.libwebsockets.org
><mailto:Libwebsockets at ml.libwebsockets.org>
>>> http://libwebsockets.org/mailman/listinfo/libwebsockets
><http://libwebsockets.org/mailman/listinfo/libwebsockets>




More information about the Libwebsockets mailing list