Mirrors/libwebsockets
1
0
Fork 0
mirror of https://github.com/warmcat/libwebsockets.git synced 2025-03-09 00:00:04 +01:00
Code Issues Releases Wiki Activity

logs: migrate ws extension code to contextual logging

Browse source
This commit is contained in:
Felipe Gasper 2021-10-13 02:03:56 -04:00 • committed by Andy Green
parent b53a09f61c
commit 7fb6a450e8
2 changed files with 55 additions and 57 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

91
lib/roles/ws/ext/extension-permessage-deflate.c
View file

@ -62,7 +62,7 @@ lws_extension_pmdeflate_restrict_args(struct lws *wsi,
if (extra < priv->args[PMD_RX_BUF_PWR2]) {
priv->args[PMD_RX_BUF_PWR2] = (unsigned char)extra;
lwsl_info(" Capping pmd rx to %d\n", 1 << extra);
lwsl_wsi_info(wsi, " Capping pmd rx to %d", 1 << extra);
}
}
@ -89,8 +89,7 @@ lws_extension_callback_pm_deflate(struct lws_context *context,
oa = in;
if (!oa->option_name)
break;
lwsl_ext("%s: named option set: %s\n", __func__,
oa->option_name);
lwsl_wsi_ext(wsi, "named option set: %s", oa->option_name);
for (n = 0; n < (int)LWS_ARRAY_SIZE(lws_ext_pm_deflate_options);
n++)
if (!strcmp(lws_ext_pm_deflate_options[n].name,
@ -105,7 +104,7 @@ lws_extension_callback_pm_deflate(struct lws_context *context,
case LWS_EXT_CB_OPTION_SET:
oa = in;
lwsl_ext("%s: option set: idx %d, %s, len %d\n", __func__,
lwsl_wsi_ext(wsi, "option set: idx %d, %s, len %d",
oa->option_index, oa->start, oa->len);
if (oa->start)
priv->args[oa->option_index] = (unsigned char)atoi(oa->start);
@ -134,8 +133,8 @@ lws_extension_callback_pm_deflate(struct lws_context *context,
n = (int)wsi->a.protocol->rx_buffer_size;
if (n < 128) {
lwsl_info(" permessage-deflate requires the protocol "
"(%s) to have an RX buffer >= 128\n",
lwsl_wsi_info(wsi, " permessage-deflate requires the protocol "
"(%s) to have an RX buffer >= 128",
wsi->a.protocol->name);
return -1;
}
@ -143,7 +142,7 @@ lws_extension_callback_pm_deflate(struct lws_context *context,
/* fill in **user */
priv = lws_zalloc(sizeof(*priv), "pmd priv");
*((void **)user) = priv;
lwsl_ext("%s: LWS_EXT_CB_*CONSTRUCT\n", __func__);
lwsl_wsi_ext(wsi, "LWS_EXT_CB_*CONSTRUCT");
memset(priv, 0, sizeof(*priv));
/* fill in pointer to options list */
@ -173,7 +172,7 @@ lws_extension_callback_pm_deflate(struct lws_context *context,
break;
case LWS_EXT_CB_DESTROY:
lwsl_ext("%s: LWS_EXT_CB_DESTROY\n", __func__);
lwsl_wsi_ext(wsi, "LWS_EXT_CB_DESTROY");
lws_free(priv->buf_rx_inflated);
lws_free(priv->buf_tx_deflated);
if (priv->rx_init)
@ -189,8 +188,8 @@ lws_extension_callback_pm_deflate(struct lws_context *context,
/*
* ie, we are INFLATING
*/
lwsl_ext(" %s: LWS_EXT_CB_PAYLOAD_RX: in %d, existing in %d\n",
__func__, pmdrx->eb_in.len, priv->rx.avail_in);
lwsl_wsi_ext(wsi, " LWS_EXT_CB_PAYLOAD_RX: in %d, existing in %d",
pmdrx->eb_in.len, priv->rx.avail_in);
/*
* If this frame is not marked as compressed,
@ -216,8 +215,8 @@ lws_extension_callback_pm_deflate(struct lws_context *context,
pmdrx->eb_out.len = 0;
lwsl_ext("%s: LWS_EXT_CB_PAYLOAD_RX: in %d, "
"existing avail in %d, pkt fin: %d\n", __func__,
lwsl_wsi_ext(wsi, "LWS_EXT_CB_PAYLOAD_RX: in %d, "
"existing avail in %d, pkt fin: %d",
pmdrx->eb_in.len, priv->rx.avail_in, wsi->ws->final);
/* if needed, initialize the inflator */
@ -225,7 +224,7 @@ lws_extension_callback_pm_deflate(struct lws_context *context,
if (!priv->rx_init) {
if (inflateInit2(&priv->rx,
-priv->args[PMD_SERVER_MAX_WINDOW_BITS]) != Z_OK) {
lwsl_err("%s: iniflateInit failed\n", __func__);
lwsl_wsi_err(wsi, "iniflateInit failed");
return PMDR_FAILED;
}
priv->rx_init = 1;
@ -235,7 +234,7 @@ lws_extension_callback_pm_deflate(struct lws_context *context,
(1 << priv->args[PMD_RX_BUF_PWR2])),
"pmd rx inflate buf");
if (!priv->buf_rx_inflated) {
lwsl_err("%s: OOM\n", __func__);
lwsl_wsi_err(wsi, "OOM");
return PMDR_FAILED;
}
}
@ -248,8 +247,8 @@ lws_extension_callback_pm_deflate(struct lws_context *context,
if (priv->rx.avail_in && pmdrx->eb_in.token &&
pmdrx->eb_in.len) {
lwsl_warn("%s: priv->rx.avail_in %d while getting new in\n",
__func__, priv->rx.avail_in);
lwsl_wsi_warn(wsi, "priv->rx.avail_in %d while getting new in",
priv->rx.avail_in);
// assert(0);
}
#endif
@ -277,7 +276,7 @@ lws_extension_callback_pm_deflate(struct lws_context *context,
wsi->ws->final &&
!wsi->ws->rx_packet_length &&
wsi->ws->pmd_trailer_application) {
lwsl_ext("%s: trailer apply 1\n", __func__);
lwsl_wsi_ext(wsi, "trailer apply 1");
was_fin = 1;
wsi->ws->pmd_trailer_application = 0;
priv->rx.next_in = trail;
@ -293,15 +292,15 @@ lws_extension_callback_pm_deflate(struct lws_context *context,
return PMDR_DID_NOTHING;
n = inflate(&priv->rx, was_fin ? Z_SYNC_FLUSH : Z_NO_FLUSH);
lwsl_ext("inflate ret %d, avi %d, avo %d, wsifinal %d\n", n,
lwsl_wsi_ext(wsi, "inflate ret %d, avi %d, avo %d, wsifinal %d", n,
priv->rx.avail_in, priv->rx.avail_out, wsi->ws->final);
switch (n) {
case Z_NEED_DICT:
case Z_STREAM_ERROR:
case Z_DATA_ERROR:
case Z_MEM_ERROR:
lwsl_err("%s: zlib error inflate %d: \"%s\"\n",
__func__, n, priv->rx.msg);
lwsl_wsi_err(wsi, "zlib error inflate %d: \"%s\"",
n, priv->rx.msg);
return PMDR_FAILED;
}
@ -313,7 +312,7 @@ lws_extension_callback_pm_deflate(struct lws_context *context,
((unsigned int)pmdrx->eb_in.len - (unsigned int)priv->rx.avail_in);
pmdrx->eb_in.len = (int)priv->rx.avail_in;
lwsl_debug("%s: %d %d %d %d %d\n", __func__,
lwsl_wsi_debug(wsi, "%d %d %d %d %d",
priv->rx.avail_in,
wsi->ws->final,
(int)wsi->ws->rx_packet_length,
@ -325,7 +324,7 @@ lws_extension_callback_pm_deflate(struct lws_context *context,
!wsi->ws->rx_packet_length &&
!was_fin &&
wsi->ws->pmd_trailer_application) {
lwsl_ext("%s: RX trailer apply 2\n", __func__);
lwsl_wsi_ext(wsi, "RX trailer apply 2");
/* we overallocated just for this situation where
* we might issue something */
@ -336,14 +335,14 @@ lws_extension_callback_pm_deflate(struct lws_context *context,
priv->rx.next_in = trail;
priv->rx.avail_in = sizeof(trail);
n = inflate(&priv->rx, Z_SYNC_FLUSH);
lwsl_ext("RX trailer infl ret %d, avi %d, avo %d\n",
lwsl_wsi_ext(wsi, "RX trailer infl ret %d, avi %d, avo %d",
n, priv->rx.avail_in, priv->rx.avail_out);
switch (n) {
case Z_NEED_DICT:
case Z_STREAM_ERROR:
case Z_DATA_ERROR:
case Z_MEM_ERROR:
lwsl_info("zlib error inflate %d: %s\n",
lwsl_wsi_info(wsi, "zlib error inflate %d: %s",
n, priv->rx.msg);
return -1;
}
@ -355,16 +354,16 @@ lws_extension_callback_pm_deflate(struct lws_context *context,
pmdrx->eb_out.token);
priv->count_rx_between_fin = priv->count_rx_between_fin + (size_t)pmdrx->eb_out.len;
lwsl_ext(" %s: RX leaving with new effbuff len %d, "
"rx.avail_in=%d, TOTAL RX since FIN %lu\n",
__func__, pmdrx->eb_out.len, priv->rx.avail_in,
lwsl_wsi_ext(wsi, " RX leaving with new effbuff len %d, "
"rx.avail_in=%d, TOTAL RX since FIN %lu",
pmdrx->eb_out.len, priv->rx.avail_in,
(unsigned long)priv->count_rx_between_fin);
if (was_fin) {
lwsl_ext("%s: was_fin\n", __func__);
lwsl_wsi_ext(wsi, "was_fin");
priv->count_rx_between_fin = 0;
if (priv->args[PMD_SERVER_NO_CONTEXT_TAKEOVER]) {
lwsl_ext("PMD_SERVER_NO_CONTEXT_TAKEOVER\n");
lwsl_wsi_ext(wsi, "PMD_SERVER_NO_CONTEXT_TAKEOVER");
(void)inflateEnd(&priv->rx);
priv->rx_init = 0;
}
@ -393,7 +392,7 @@ lws_extension_callback_pm_deflate(struct lws_context *context,
priv->args[PMD_MEM_LEVEL],
Z_DEFAULT_STRATEGY);
if (n != Z_OK) {
lwsl_ext("inflateInit2 failed %d\n", n);
lwsl_wsi_ext(wsi, "inflateInit2 failed %d", n);
return PMDR_FAILED;
}
priv->tx_init = 1;
@ -404,7 +403,7 @@ lws_extension_callback_pm_deflate(struct lws_context *context,
(1 << priv->args[PMD_TX_BUF_PWR2])),
"pmd tx deflate buf");
if (!priv->buf_tx_deflated) {
lwsl_err("%s: OOM\n", __func__);
lwsl_wsi_err(wsi, "OOM");
return PMDR_FAILED;
}
@ -415,8 +414,8 @@ lws_extension_callback_pm_deflate(struct lws_context *context,
assert(!priv->tx.avail_in);
priv->count_tx_between_fin = priv->count_tx_between_fin + (size_t)pmdrx->eb_in.len;
lwsl_ext("%s: TX: eb_in length %d, "
"TOTAL TX since FIN: %d\n", __func__,
lwsl_wsi_ext(wsi, "TX: eb_in length %d, "
"TOTAL TX since FIN: %d",
pmdrx->eb_in.len,
(int)priv->count_tx_between_fin);
priv->tx.next_in = (unsigned char *)pmdrx->eb_in.token;
@ -433,7 +432,7 @@ lws_extension_callback_pm_deflate(struct lws_context *context,
pen = pen | (unsigned int)penbits;
if (!priv->tx.avail_in && (len & LWS_WRITE_NO_FIN)) {
lwsl_ext("%s: no available in, pen: %u\n", __func__, pen);
lwsl_wsi_ext(wsi, "no available in, pen: %u", pen);
if (!pen)
return PMDR_DID_NOTHING;
@ -441,20 +440,20 @@ lws_extension_callback_pm_deflate(struct lws_context *context,
m = Z_NO_FLUSH;
if (!(len & LWS_WRITE_NO_FIN)) {
lwsl_ext("%s: deflate with SYNC_FLUSH, pkt len %d\n",
__func__, (int)wsi->ws->rx_packet_length);
lwsl_wsi_ext(wsi, "deflate with SYNC_FLUSH, pkt len %d",
(int)wsi->ws->rx_packet_length);
m = Z_SYNC_FLUSH;
}
n = deflate(&priv->tx, m);
if (n == Z_STREAM_ERROR) {
lwsl_notice("%s: Z_STREAM_ERROR\n", __func__);
lwsl_wsi_notice(wsi, "Z_STREAM_ERROR");
return PMDR_FAILED;
}
pen = (!priv->tx.avail_out) && n != Z_STREAM_END;
lwsl_ext("%s: deflate ret %d, len 0x%x\n", __func__, n,
lwsl_wsi_ext(wsi, "deflate ret %d, len 0x%x", n,
(unsigned int)len);
if ((len & 0xf) == LWS_WRITE_TEXT)
@ -467,8 +466,8 @@ lws_extension_callback_pm_deflate(struct lws_context *context,
if (m == Z_SYNC_FLUSH && !(len & LWS_WRITE_NO_FIN) && !pen &&
pmdrx->eb_out.len < 4) {
lwsl_err("%s: FAIL want to trim out length %d\n",
__func__, (int)pmdrx->eb_out.len);
lwsl_wsi_err(wsi, "FAIL want to trim out length %d",
(int)pmdrx->eb_out.len);
assert(0);
}
@ -476,7 +475,7 @@ lws_extension_callback_pm_deflate(struct lws_context *context,
m == Z_SYNC_FLUSH &&
!pen &&
pmdrx->eb_out.len >= 4) {
// lwsl_err("%s: Trimming 4 from end of write\n", __func__);
// lwsl_wsi_err(wsi, "Trimming 4 from end of write");
priv->tx.next_out -= 4;
priv->tx.avail_out += 4;
priv->count_tx_between_fin = 0;
@ -500,8 +499,8 @@ lws_extension_callback_pm_deflate(struct lws_context *context,
pmdrx->eb_out.len = lws_ptr_diff(priv->tx.next_out,
pmdrx->eb_out.token);
lwsl_ext(" TX rewritten with new eb_in len %d, "
"eb_out len %d, deflatePending %d\n",
lwsl_wsi_ext(wsi, " TX rewritten with new eb_in len %d, "
"eb_out len %d, deflatePending %d",
pmdrx->eb_in.len, pmdrx->eb_out.len, pen);
if (pmdrx->eb_in.len || pen)
@ -538,13 +537,13 @@ lws_extension_callback_pm_deflate(struct lws_context *context,
if (n == LWSWSOPC_TEXT_FRAME || n == LWSWSOPC_BINARY_FRAME)
*pmdrx->eb_in.token |= 0x40;
lwsl_ext("%s: PRESEND compressed: ws frame 0x%02X, len %d\n",
__func__, ((*pmdrx->eb_in.token) & 0xff),
lwsl_wsi_ext(wsi, "PRESEND compressed: ws frame 0x%02X, len %d",
((*pmdrx->eb_in.token) & 0xff),
pmdrx->eb_in.len);
if (((*pmdrx->eb_in.token) & 0x80) && /* fin */
priv->args[PMD_CLIENT_NO_CONTEXT_TAKEOVER]) {
lwsl_debug("PMD_CLIENT_NO_CONTEXT_TAKEOVER\n");
lwsl_wsi_debug(wsi, "PMD_CLIENT_NO_CONTEXT_TAKEOVER");
(void)deflateEnd(&priv->tx);
priv->tx_init = 0;
}

21
lib/roles/ws/ext/extension.c
View file

@ -30,7 +30,7 @@ void
lws_context_init_extensions(const struct lws_context_creation_info *info,
struct lws_context *context)
{
lwsl_info(" LWS_MAX_EXTENSIONS_ACTIVE: %u\n", LWS_MAX_EXTENSIONS_ACTIVE);
lwsl_cx_info(context, " LWS_MAX_EXTENSIONS_ACTIVE: %u", LWS_MAX_EXTENSIONS_ACTIVE);
}
enum lws_ext_option_parser_states {
@ -56,7 +56,7 @@ lws_ext_parse_options(const struct lws_extension *ext, struct lws *wsi,
while (opts[count_options].name)
count_options++;
while (len) {
lwsl_ext("'%c' %d", *in, leap);
lwsl_wsi_ext(wsi, "'%c' %d", *in, leap);
switch (leap) {
case LEAPS_SEEK_NAME:
if (*in == ' ')
@ -83,12 +83,12 @@ lws_ext_parse_options(const struct lws_extension *ext, struct lws *wsi,
n++;
continue;
}
lwsl_ext(" m=%d, n=%d, w=%d\n", m, n, w);
lwsl_wsi_ext(wsi, " m=%d, n=%d, w=%d", m, n, w);
if (*in == opts[n].name[w]) {
if (!opts[n].name[w + 1]) {
oa.option_index = (int)n;
lwsl_ext("hit %d\n",
lwsl_wsi_ext(wsi, "hit %d",
oa.option_index);
leap = LEAPS_SEEK_VAL;
if (len == 1)
@ -98,7 +98,7 @@ lws_ext_parse_options(const struct lws_extension *ext, struct lws *wsi,
} else {
match_map &= (unsigned int)~(1 << n);
if (!match_map) {
lwsl_ext("empty match map\n");
lwsl_wsi_ext(wsi, "empty match map");
return -1;
}
}
@ -200,7 +200,7 @@ int lws_ext_cb_active(struct lws *wsi, int reason, void *arg, int len)
lws_get_context(wsi), wsi->ws->active_extensions[n],
wsi, (enum lws_extension_callback_reasons)reason, wsi->ws->act_ext_user[n], arg, (size_t)len);
if (m < 0) {
lwsl_ext("Ext '%s' failed to handle callback %d!\n",
lwsl_wsi_ext(wsi, "Ext '%s' failed to handle callback %d!",
wsi->ws->active_extensions[n]->name, reason);
return -1;
}
@ -229,7 +229,7 @@ int lws_ext_cb_all_exts(struct lws_context *context, struct lws *wsi,
m = ext->callback(context, ext, wsi, (enum lws_extension_callback_reasons)reason,
(void *)(lws_intptr_t)n, arg, (size_t)len);
if (m < 0) {
lwsl_ext("Ext '%s' failed to handle callback %d!\n",
lwsl_wsi_ext(wsi, "Ext '%s' failed to handle callback %d!",
wsi->ws->active_extensions[n]->name, reason);
return -1;
}
@ -284,7 +284,7 @@ lws_issue_raw_ext_access(struct lws *wsi, unsigned char *buf, size_t len)
if (ebuf.len) {
n = lws_issue_raw(wsi, ebuf.token, (size_t)ebuf.len);
if (n < 0) {
lwsl_info("closing from ext access\n");
lwsl_wsi_info(wsi, "closing from ext access");
return -1;
}
@ -292,8 +292,7 @@ lws_issue_raw_ext_access(struct lws *wsi, unsigned char *buf, size_t len)
if (wsi->ws->clean_buffer)
len = (size_t)n;
lwsl_ext("%s: written %d bytes to client\n",
__func__, n);
lwsl_wsi_ext(wsi, "written %d bytes to client", n);
}
/* no extension has more to spill? Then we can go */
@ -315,7 +314,7 @@ lws_issue_raw_ext_access(struct lws *wsi, unsigned char *buf, size_t len)
/* no we could add more, lets's do that */
continue;
lwsl_debug("choked\n");
lwsl_wsi_debug(wsi, "choked");
/*
* Yes, he's choked. Don't spill the rest now get a callback