[Libwebsockets] output.c: lws_issue_raw handle_truncated_send instead of assert(0)

Derald D. Woods woods.technical at gmail.com
Wed Apr 22 03:14:21 CEST 2015


This was resolved by the Trac Ticket 111 @ 
https://libwebsockets.org/trac/libwebsockets/ticket/111

On 04/14/2015 02:37 PM, Derald Woods wrote:
> On Fri, Apr 10, 2015 at 6:45 PM, Andy Green <andy at warmcat.com 
> <mailto:andy at warmcat.com>> wrote:
>
>
>
>     On 11 April 2015 00:21:34 GMT+08:00, Derald Woods
>     <woods.technical at gmail.com <mailto:woods.technical at gmail.com>> wrote:
>     >Hello Andy,
>     >
>     >The following patch allows code, that I am working with, to survive
>     >browser
>     >refreshes while streaming larger chunks of data (~500k). SSL is
>     enabled
>     >on
>     >the connections. I have not observed any side-effects or bad
>     behavior.
>     >The
>     >'partial send' actually completes. The application is 'best-effort'
>     >delivery on the network. I am continuing my verifications, but this
>     >appears
>     >to do the right thing for my use-case.
>     >
>     >Your thoughts? Corrections? Warnings?
>
>     Something else is wrong if you end up there... basically while you
>     have a truncated send pending, there should be no way to send
>     something new.
>
>     The code in the service loop enforces that; it won't call back as
>     writeable while a truncated send is pending.  And you should only
>     be sending something new (ending up at lws_issue_raw) in the
>     writeable callback.
>
>     You are illegally sending something new outside of the writeable
>     callback?  Or the library itself has a problem with its
>     enforcement (I would have expected to get more complaints about
>     hitting the assert...)
>
>
> Here is the callback snippet:
>
>         case LWS_CALLBACK_SERVER_WRITEABLE:
>             pss->total = 0;
>             do {
>                 n = libwebsocket_write(wsi, data, length, 
> LWS_WRITE_BINARY);
>                 if (n < 0) {
>                     return -1;
>                 }
>                 pss->total += n;
>                 if (lws_partial_buffered(wsi) || 
> lws_send_pipe_choked(wsi)) {
>                     sprintf(msg, "lws writing (%d)", n);
>                     LOG(msg);
> libwebsocket_callback_on_writable(context, wsi);
>                     break;
>                 }
>             } while (pss->total < length);
>             break;
>
>
> I get a consistent stream of data, that appears to run fine until a 
> refresh and/or move to another page. Here is a shortened log:
>
>
> [1429033993:2218] INFO: lws_calllback_as_writeable: 0xa9e3a458 
> (user=0xa9e39128)
> [1429033993:2230] INFO: ***** a9e3a458 new partial sent 0 from 460810 
> total
> "2015-04-14 12:53:13","protocol/my","lws writing 
> (460800)","protocol/my.cpp:my_callback():112"
> [1429033993:2634] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033993:3037] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033993:3433] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033993:3434] INFO: lws_calllback_as_writeable: 0xa9e14028 
> (user=0xa9e39340)
> [1429033993:3435] INFO: lws_calllback_as_writeable: 0xa9e1c948 
> (user=0xa9e27b10)
> [1429033993:3833] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033993:4233] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033993:4633] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033993:5032] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033993:5431] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033993:5434] INFO: lws_calllback_as_writeable: 0xa9e14028 
> (user=0xa9e39340)
> [1429033993:5435] INFO: lws_calllback_as_writeable: 0xa9e1c948 
> (user=0xa9e27b10)
> [1429033993:5831] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033993:6231] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033993:6631] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033993:7032] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033993:7432] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033993:7434] INFO: lws_calllback_as_writeable: 0xa9e14028 
> (user=0xa9e39340)
> [1429033993:7435] INFO: lws_calllback_as_writeable: 0xa9e1c948 
> (user=0xa9e27b10)
> [1429033993:7832] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033993:8231] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033993:8632] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033993:9032] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033993:9432] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033993:9434] INFO: lws_calllback_as_writeable: 0xa9e14028 
> (user=0xa9e39340)
> [1429033993:9436] INFO: lws_calllback_as_writeable: 0xa9e1c948 
> (user=0xa9e27b10)
> [1429033993:9832] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033994:0231] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033994:0631] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033994:1032] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033994:1432] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033994:1434] INFO: lws_calllback_as_writeable: 0xa9e14028 
> (user=0xa9e39340)
> [1429033994:1435] INFO: lws_calllback_as_writeable: 0xa9e1c948 
> (user=0xa9e27b10)
> [1429033994:1832] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033994:2230] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033994:2632] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033994:3028] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033994:3426] INFO: ***** a9e3a458 partial send moved on by 460810 
> (vs 460810)
> [1429033994:3428] INFO: ***** a9e3a458 partial send completed
> [1429033994:3429] INFO: lws_calllback_as_writeable: 0xa9e3a458 
> (user=0xa9e39128)
> [1429033994:3440] INFO: ***** a9e3a458 new partial sent 0 from 460810 
> total
> "2015-04-14 12:53:14","protocol/my","lws writing 
> (460800)","protocol/my.cpp:my_callback():112"
> [1429033994:3453] INFO: lws_calllback_as_writeable: 0xa9e14028 
> (user=0xa9e39340)
> [1429033994:3456] INFO: lws_calllback_as_writeable: 0xa9e1c948 
> (user=0xa9e27b10)
> [1429033994:3842] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033994:4246] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033994:4644] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033994:5043] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033994:5442] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033994:5453] INFO: lws_calllback_as_writeable: 0xa9e14028 
> (user=0xa9e39340)
> [1429033994:5455] INFO: lws_calllback_as_writeable: 0xa9e1c948 
> (user=0xa9e27b10)
> [1429033994:5842] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033994:6241] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033994:6642] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033994:7042] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033994:7442] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033994:7453] INFO: lws_calllback_as_writeable: 0xa9e14028 
> (user=0xa9e39340)
> [1429033994:7455] INFO: lws_calllback_as_writeable: 0xa9e1c948 
> (user=0xa9e27b10)
> [1429033994:7841] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033994:8241] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033994:8642] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033994:9042] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033994:9442] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033994:9453] INFO: lws_calllback_as_writeable: 0xa9e14028 
> (user=0xa9e39340)
> [1429033994:9456] INFO: lws_calllback_as_writeable: 0xa9e1c948 
> (user=0xa9e27b10)
> [1429033994:9841] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033995:0241] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033995:0642] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033995:1042] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033995:1441] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033995:1453] INFO: lws_calllback_as_writeable: 0xa9e14028 
> (user=0xa9e39340)
> [1429033995:1455] INFO: lws_calllback_as_writeable: 0xa9e1c948 
> (user=0xa9e27b10)
> [1429033995:1841] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033995:2241] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033995:2641] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033995:3042] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033995:3441] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033995:3454] INFO: lws_calllback_as_writeable: 0xa9e14028 
> (user=0xa9e39340)
> [1429033995:3456] INFO: lws_calllback_as_writeable: 0xa9e1c948 
> (user=0xa9e27b10)
> [1429033995:3841] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033995:4237] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033995:4636] INFO: ***** a9e3a458 partial send moved on by 460810 
> (vs 460810)
> [1429033995:4637] INFO: ***** a9e3a458 partial send completed
> [1429033995:4637] INFO: lws_calllback_as_writeable: 0xa9e3a458 
> (user=0xa9e39128)
> [1429033995:4650] INFO: ***** a9e3a458 new partial sent 0 from 460810 
> total
> "2015-04-14 12:53:15","protocol/my","lws writing 
> (460800)","protocol/my.cpp:my_callback():112"
> [1429033995:5046] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033995:5154] DEBUG: libwebsocket_read: read_ok
> [1429033995:5163] INFO: ***** a9e3a458 partial send moved on by 0 (vs 
> 460810)
> [1429033995:5165] ERR: ****** a9e3a458 Sending new, pending truncated ...
> my_app: /src/libwebsockets/lib/output.c:112: lws_issue_raw: Assertion 
> `0' failed.
>
> Any additional thoughts? Maybe a different approach?
>
> I just need to send a fixed size block of data. My patch simply 
> allowed the app to survive. I have not observed any leaks or cpu 
> spikes with the small patch.
>
>     -Andy
>
>     >---8<-----------------------------------------------------------------------
>     >diff --git a/lib/output.c b/lib/output.c
>     >index b914f28..9e07ae5 100644
>     >--- a/lib/output.c
>     >+++ b/lib/output.c
>     >@@ -109,7 +109,8 @@ int lws_issue_raw(struct libwebsocket *wsi,
>     >unsigned
>     >char *buf, size_t len)
>     >                 wsi->truncated_send_len +
>     >                 wsi->truncated_send_offset))) {
>     >       lwsl_err("****** %x Sending new, pending truncated ...\n",
>     wsi);
>     >-        assert(0);
>     >+        n = 0;
>     >+        goto handle_truncated_send;
>     >     }
>     >
>     >     m = lws_ext_callback_for_each_active(wsi,
>     >---8<-----------------------------------------------------------------------
>
>
>
>
> -- 
> Derald D. Woods
> [Ecclesiastes 12:13] "...: Fear God, and keep his commandments: for 
> this is the whole duty of man."
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://libwebsockets.org/pipermail/libwebsockets/attachments/20150421/2dbd7206/attachment-0001.html>


More information about the Libwebsockets mailing list