warmcat / libwebsockets

canonical libwebsockets.org networking library
https://libwebsockets.org
Other
4.8k stars 1.49k forks source link

Connection closes when using lws_rx_flow_control #1558

Closed kcunningham closed 5 years ago

kcunningham commented 5 years ago

I commented about this in #1550, but realized that I'm not able to reopen the issue, so I'm making a new issue instead. Unfortunately, the issue in #1550 does not seem completely fixed. Previously the changes to use rx_flow_control were only added to the pmd bulk client. In that case, it seems to work correctly.

However, if the same changes are applied to both the pmd bulk client and server (or just the server), then the connection closes due to an error on the server side this time.

Patch here: pmd_bulk_flow_control_client_server.txt

Server output:

[2019/04/25 14:06:11:6829] USER: LWS_CALLBACK_SERVER_WRITEABLE: wrote 1024
[2019/04/25 14:06:11:6829] USER: LWS_CALLBACK_SERVER_WRITEABLE: wrote 1024
[2019/04/25 14:06:11:6830] USER: LWS_CALLBACK_SERVER_WRITEABLE: wrote 1024
[2019/04/25 14:06:11:6831] USER: LWS_CALLBACK_SERVER_WRITEABLE: wrote 1024
[2019/04/25 14:06:11:6832] USER: LWS_CALLBACK_SERVER_WRITEABLE: wrote 1024
[2019/04/25 14:06:11:6833] USER: LWS_CALLBACK_SERVER_WRITEABLE: wrote 1024
[2019/04/25 14:06:11:6833] USER: LWS_CALLBACK_SERVER_WRITEABLE: wrote 580
[2019/04/25 14:06:11:6845] USER: Timer called, disabling flow control
[2019/04/25 14:06:11:6845] USER: LWS_CALLBACK_RECEIVE: 1024 (pss->pos=2048, rpp     0, last 0)
[2019/04/25 14:06:11:6846] USER: Enabling flow control, setting timer
[2019/04/25 14:06:11:6896] USER: Timer called, disabling flow control
[2019/04/25 14:06:11:6896] USER: LWS_CALLBACK_RECEIVE: 1008 (pss->pos=3072, rpp    16, last 0)
[2019/04/25 14:06:11:6896] USER: Enabling flow control, setting timer
[2019/04/25 14:06:11:6896] USER: echo'd data doesn't match: 0xEE 0x6C (3073)
[2019/04/25 14:06:11:6896] NOTICE: 
[2019/04/25 14:06:11:6896] NOTICE: 0000: EE CE 20 3E 61 D4 83 A3 A3 D9 48 A4 D8 05 F5 51    .. >a.....H....Q
[2019/04/25 14:06:11:6897] NOTICE: 0010: 36 77 D8 25 FA 54 42 C6 B5 0E 68 75 12 8F 66 98    6w.%.TB...hu..f.
[2019/04/25 14:06:11:6897] NOTICE: 0020: 1C 96 54 85 D3 2F 4E 57 4E 89 89 0C 67 19 A3 3A    ..T../NWN...g..:
[2019/04/25 14:06:11:6897] NOTICE: 0030: 45 7F 96 1A 9C A4 61 35 5A 1D A2 D9 04 BB F2 76    E.....a5Z......v
[2019/04/25 14:06:11:6897] NOTICE: 0040: C5 47 1A B0 05 C1 17 13 C1 55 96 58 E9 6B 81 7B    .G.......U.X.k.{
[2019/04/25 14:06:11:6897] NOTICE: 0050: 7F AD 7C 78 13 EE 52 47 F9 03 C0 B3 3E F3 F8 3C    ..|x..RG....>..<
[2019/04/25 14:06:11:6897] NOTICE: 0060: 0A 4A 53 E0 90 E0 F7 A2 01 DD F7 EA EA 26 DB FD    .JS..........&..
[2019/04/25 14:06:11:6897] NOTICE: 0070: 44 90 8A 83 B6 9E C4 B5 47 1D 19 2C AE D5 1E 4A    D.......G..,...J
[2019/04/25 14:06:11:6897] NOTICE: 0080: F3 1D 54 9F E0 75 2B A3 77 38 F8 F5 D0 BD 76 1A    ..T..u+.w8....v.
[2019/04/25 14:06:11:6897] NOTICE: 0090: 5B 82 20 73 E1 69 AD BB 1C 9D 77 CC 40 14 58 99    [. s.i....w.@.X.
[2019/04/25 14:06:11:6897] NOTICE: 00A0: 53 61 40 3B 6B 5F 48 F1 E7 84 2B 92 AF 58 B0 6E    Sa@;k_H...+..X.n
[2019/04/25 14:06:11:6898] NOTICE: 00B0: 07 00 DC D0 68 D8 CA AF A6 18 3B 6D 5B 59 22 0F    ....h.....;m[Y".
[2019/04/25 14:06:11:6898] NOTICE: 00C0: 51 92 18 7C E4 0C 0B 65 F7 D3 EF EB 31 6D 37 07    Q..|...e....1m7.
[2019/04/25 14:06:11:6898] NOTICE: 00D0: 1F 31 17 D1 D9 85 81 76 78 98 32 CE 4F 67 7A 44    .1.....vx.2.OgzD
[2019/04/25 14:06:11:6898] NOTICE: 00E0: 82 A5 AA B2 15 53 84 7B 06 BE 4B 64 02 62 01 EA    .....S.{..Kd.b..
[2019/04/25 14:06:11:6898] NOTICE: 00F0: 30 F3 53 A9 EC 73 35 B1 E8 84 79 94 DB FB 77 B7    0.S..s5...y...w.
[2019/04/25 14:06:11:6898] NOTICE: 0100: 91 6A 0A 45 A6 EC DE EE 65 F8 7F CB 7B 0E 61 21    .j.E....e...{.a!
[2019/04/25 14:06:11:6898] NOTICE: 0110: 2C E4 42 F4 C4 EC 08 92 45 25 0A 31 3E 1D 4C C3    ,.B.....E%.1>.L.
[2019/04/25 14:06:11:6898] NOTICE: 0120: CC 4C 64 68 F8 8A 5E F8 B6 7D 24 EF A2 A5 9D 01    .Ldh..^..}$.....
[2019/04/25 14:06:11:6898] NOTICE: 0130: 86 AC 3D EC A8 30 1A DD B7 59 A5 30 B3 BC 6A 2B    ..=..0...Y.0..j+
[2019/04/25 14:06:11:6898] NOTICE: 0140: BD 0B 7A 46 C4 7D E3 5B 37 C2 89 4D 5A 59 93 34    ..zF.}.[7..MZY.4
[2019/04/25 14:06:11:6898] NOTICE: 0150: 5C 4E 5D 08 5F 07 12 74 26 FB 90 B5 27 BC 23 9C    \N]._..t&...'.#.
[2019/04/25 14:06:11:6898] NOTICE: 0160: 73 BB 11 0C DF 1E 6C FE 29 4F 91 F1 5C 94 EC 21    s.....l.)O..\..!
[2019/04/25 14:06:11:6899] NOTICE: 0170: 14 21 31 8F 09 F4 B3 67 8E 6E 2E A9 E0 C8 BB 1A    .!1....g.n......
[2019/04/25 14:06:11:6899] NOTICE: 0180: B5 FD 51 C5 9D 40 F0 94 36 0B 77 4C 21 DC 0D A9    ..Q..@..6.wL!...
[2019/04/25 14:06:11:6899] NOTICE: 0190: 30 25 D1 C0 22 FE 9D 5D F0 EC 96 27 3E D3 30 D5    0%.."..]...'>.0.
[2019/04/25 14:06:11:6899] NOTICE: 01A0: 0A D1 B1 15 A8 DB 16 6F 58 96 C1 25 45 24 6A 8E    .......oX..%E$j.
[2019/04/25 14:06:11:6899] NOTICE: 01B0: 89 57 A8 FA B2 A9 57 F4 88 A6 33 4B 7D 85 32 8F    .W....W...3K}.2.
[2019/04/25 14:06:11:6899] NOTICE: 01C0: 76 AC 94 CA 8A 43 C3 95 8A FA 05 0B B9 C9 F4 C3    v....C..........
[2019/04/25 14:06:11:6899] NOTICE: 01D0: 08 47 FD F2 C8 3E 87 0B C7 66 A2 49 F7 FD E8 89    .G...>...f.I....
[2019/04/25 14:06:11:6899] NOTICE: 01E0: AF 34 5D DE 97 09 5F 3C 6A 76 9B F9 28 EB 08 7E    .4]..._<jv..(..~
[2019/04/25 14:06:11:6899] NOTICE: 01F0: 67 6D 32 A7 97 A2 58 48 35 8E DE 31 A6 F2 A9 11    gm2...XH5..1....
[2019/04/25 14:06:11:6899] NOTICE: 0200: 8E 1E 9F 16 AD 2F 73 C0 EE 10 CB B4 92 A2 95 1E    ...../s.........
[2019/04/25 14:06:11:6899] NOTICE: 0210: 95 32 41 01 FC FF D9 B5 21 63 8F AC F3 73 7B 65    .2A.....!c...s{e
[2019/04/25 14:06:11:6900] NOTICE: 0220: 97 06 5C 65 58 A4 85 72 E4 24 92 5D DD 91 BA DB    ..\eX..r.$.]....
[2019/04/25 14:06:11:6900] NOTICE: 0230: 73 5B A3 EA 95 91 BC 79 44 40 C7 C6 C1 6B 3D 82    s[.....yD@...k=.
[2019/04/25 14:06:11:6900] NOTICE: 0240: 68 B8 AE C7 10 3A EE 78 6F 3E 92 5C F5 5A 1A 99    h....:.xo>.\.Z..
[2019/04/25 14:06:11:6900] NOTICE: 0250: 3D DA FF BF 8F A1 7B D7 9F 31 7E F1 50 68 04 15    =.....{..1~.Ph..
[2019/04/25 14:06:11:6900] NOTICE: 0260: 8A DC BB 38 40 43 60 38 86 50 F7 AE 20 99 CA AB    ...8@C`8.P.. ...
[2019/04/25 14:06:11:6900] NOTICE: 0270: A7 EE 6E 8A 76 79 80 9A AF EC 93 6A 9D DE 82 68    ..n.vy.....j...h
[2019/04/25 14:06:11:6900] NOTICE: 0280: 02 36 6F 93 C8 4D 3D 09 84 28 A6 9C BC 0E D3 B3    .6o..M=..(......
[2019/04/25 14:06:11:6900] NOTICE: 0290: 25 99 F9 FF 59 2C 6A 61 9C 8C CF 54 F2 FC B1 AF    %...Y,ja...T....
[2019/04/25 14:06:11:6900] NOTICE: 02A0: 87 DB BE 31 A0 69 03 CA 81 DD 73 1B FC 7E 18 11    ...1.i....s..~..
[2019/04/25 14:06:11:6900] NOTICE: 02B0: 9E 22 76 D6 CB A6 8F F8 38 E1 CF AF 20 22 FC 5F    ."v.....8... "._
[2019/04/25 14:06:11:6900] NOTICE: 02C0: 78 3B 30 B3 43 75 D8 0C 70 96 4F BC 66 C9 B9 00    x;0.Cu..p.O.f...
[2019/04/25 14:06:11:6900] NOTICE: 02D0: 88 B6 3E C5 9D 15 91 99 BC 28 44 3E C3 ED B5 CE    ..>......(D>....
[2019/04/25 14:06:11:6900] NOTICE: 02E0: EB AA A8 EE A6 A9 83 CA A2 2F 31 E3 E2 6F 07 AC    ........./1..o..
[2019/04/25 14:06:11:6901] NOTICE: 02F0: C4 6D FC F9 74 14 DF 0E 0A 58 3B F3 E1 BE 38 FC    .m..t....X;...8.
[2019/04/25 14:06:11:6901] NOTICE: 0300: 1E 78 DC 0C C9 B1 1B 3E FA 94 1F 43 CA 8D EC B1    .x.....>...C....
[2019/04/25 14:06:11:6901] NOTICE: 0310: 82 88 0B 15 25 EF A1 7F D6 D5 90 DB 8A F5 0F 51    ....%..........Q
[2019/04/25 14:06:11:6901] NOTICE: 0320: 79 8D 31 90 F1 A7 E6 E3 BA FB E2 A1 67 D0 C0 01    y.1.........g...
[2019/04/25 14:06:11:6901] NOTICE: 0330: 65 B5 DB 9B 9A F2 31 7E 89 7E A6 36 A6 E8 24 F6    e.....1~.~.6..$.
[2019/04/25 14:06:11:6901] NOTICE: 0340: BA 32 9C 91 1E 9D E3 D6 0E 3E 89 80 B9 63 FD E6    .2.......>...c..
[2019/04/25 14:06:11:6901] NOTICE: 0350: 97 71 14 9E 1F 46 4A C7 1E 8A 51 94 DF 30 14 ED    .q...FJ...Q..0..
[2019/04/25 14:06:11:6901] NOTICE: 0360: ED BD 5C 90 81 97 BB 3F EC 11 5F C2 72 5D 62 CA    ..\....?.._.r]b.
[2019/04/25 14:06:11:6901] NOTICE: 0370: 83 34 1E D6 80 83 15 73 C8 CC 26 74 23 0D 58 6B    .4.....s..&t#.Xk
[2019/04/25 14:06:11:6901] NOTICE: 0380: 54 C9 86 7D 35 E4 ED 00 C4 66 06 94 E7 34 5C F0    T..}5....f...4\.
[2019/04/25 14:06:11:6901] NOTICE: 0390: 05 CB 62 D5 35 D4 26 7D 1A B2 89 D3 89 81 21 71    ..b.5.&}......!q
[2019/04/25 14:06:11:6901] NOTICE: 03A0: 24 9F 18 8A 75 D3 0E B6 FA D9 DC 6F 44 7E C6 E9    $...u......oD~..
[2019/04/25 14:06:11:6902] NOTICE: 03B0: 4B 75 9F 9F B4 79 02 C4 7A C9 C7 72 F3 2A 4C 40    Ku...y..z..r.*L@
[2019/04/25 14:06:11:6902] NOTICE: 03C0: BD 61 E4 5F 6F E8 0F 00 9F 42 FD 3A 02 E3 FA EB    .a._o....B.:....
[2019/04/25 14:06:11:6902] NOTICE: 03D0: DC 26 30 B6 06 11 ED 16 FA FA 78 EA 06 39 36 F2    .&0.......x..96.
[2019/04/25 14:06:11:6902] NOTICE: 03E0: AF 9A A9 48 EA AF 24 CA FE 8B 7C 86 B8 6D 2A 01    ...H..$...|..m*.
[2019/04/25 14:06:11:6902] NOTICE: 
[2019/04/25 14:06:11:6902] NOTICE: LWS_CALLBACK_CLOSED

Client output:

[2019/04/25 14:06:10:6708] USER: Timer called, disabling flow control
[2019/04/25 14:06:10:6708] USER: LWS_CALLBACK_CLIENT_RECEIVE: 1024 (rpp     0, last 0)
[2019/04/25 14:06:10:6708] USER: Enabling flow control, setting timer
[2019/04/25 14:06:10:6715] NOTICE: LWS_CALLBACK_CLIENT_CLOSED
[2019/04/25 14:06:11:6727] NOTICE: callback_minimal_pmd_bulk: LWS_CALLBACK_USER
[2019/04/25 14:06:11:6743] USER: LWS_CALLBACK_CLIENT_RECEIVE: 1024 (rpp     0, last 0)
[2019/04/25 14:06:11:6743] USER: Enabling flow control, setting timer
[2019/04/25 14:06:11:6794] USER: Timer called, disabling flow control
[2019/04/25 14:06:11:6794] USER: LWS_CALLBACK_CLIENT_RECEIVE: 1024 (rpp     0, last 0)
[2019/04/25 14:06:11:6795] USER: Enabling flow control, setting timer
[2019/04/25 14:06:11:6795] NOTICE: lws_ws_handshake_client: trimming inside rxflow cache
[2019/04/25 14:06:11:6845] USER: Timer called, disabling flow control
[2019/04/25 14:06:11:6845] USER: LWS_CALLBACK_CLIENT_RECEIVE: 1024 (rpp     0, last 0)
[2019/04/25 14:06:11:6845] USER: Enabling flow control, setting timer
[2019/04/25 14:06:11:6845] NOTICE: lws_ws_handshake_client: trimming inside rxflow cache
[2019/04/25 14:06:11:6896] USER: Timer called, disabling flow control
[2019/04/25 14:06:11:6896] USER: LWS_CALLBACK_CLIENT_RECEIVE: 1024 (rpp     0, last 0)
[2019/04/25 14:06:11:6896] USER: Enabling flow control, setting timer
[2019/04/25 14:06:11:6903] NOTICE: LWS_CALLBACK_CLIENT_CLOSED
[2019/04/25 14:06:12:6915] NOTICE: callback_minimal_pmd_bulk: LWS_CALLBACK_USER

Let me know if you need any other information.

Thanks

lws-team commented 5 years ago

There's no need for a new issue... I saw your comment on the existing one and will look at it at some point, it makes no difference if it's open or closed.