diff --git a/lib/core-net/client/connect.c b/lib/core-net/client/connect.c index c26419a18..b1a521f23 100644 --- a/lib/core-net/client/connect.c +++ b/lib/core-net/client/connect.c @@ -41,7 +41,7 @@ lws_http_client_connect_via_info2(struct lws *wsi) struct client_info_stash *stash = wsi->stash; int n; - lwsl_debug("%s: %s (stash %p)\n", __func__, lws_lc_tag(&wsi->lc), stash); + lwsl_wsi_debug(wsi, "stash %p", stash); if (!stash) return wsi; @@ -249,7 +249,7 @@ lws_client_connect_via_info(const struct lws_client_connect_info *i) #endif if (!wsi->a.vhost) { - lwsl_err("%s: No vhost in the context\n", __func__); + lwsl_wsi_err(wsi, "No vhost in the context"); goto bail; } @@ -266,7 +266,7 @@ lws_client_connect_via_info(const struct lws_client_connect_info *i) goto bail; } - lwsl_info("%s: role binding to %s\n", __func__, wsi->role_ops->name); + lwsl_wsi_info(wsi, "role binding to %s", wsi->role_ops->name); /* * PHASE 4: fill up the wsi with stuff from the connect_info as far as @@ -302,16 +302,16 @@ lws_client_connect_via_info(const struct lws_client_connect_info *i) } if (local) { - lwsl_info("%s: vh %s protocol binding to %s\n", __func__, + lwsl_wsi_info(wsi, "vh %s protocol binding to %s\n", wsi->a.vhost->name, local); p = lws_vhost_name_to_protocol(wsi->a.vhost, local); if (p) lws_bind_protocol(wsi, p, __func__); else - lwsl_info("%s: unknown protocol %s\n", __func__, local); + lwsl_wsi_info(wsi, "unknown protocol %s", local); - lwsl_info("%s: %s: %s %s entry\n", - __func__, lws_wsi_tag(wsi), wsi->role_ops->name, + lwsl_wsi_info(wsi, "%s: %s %s entry", + lws_wsi_tag(wsi), wsi->role_ops->name, wsi->a.protocol ? wsi->a.protocol->name : "none"); } @@ -329,7 +329,7 @@ lws_client_connect_via_info(const struct lws_client_connect_info *i) wsi->tls.use_ssl = (unsigned int)i->ssl_connection; #else if (i->ssl_connection & LCCSCF_USE_SSL) { - lwsl_err("%s: lws not configured for tls\n", __func__); + lwsl_wsi_err(wsi, "lws not configured for tls"); goto bail; } #endif diff --git a/lib/core-net/client/connect2.c b/lib/core-net/client/connect2.c index 4680ccad5..95fb14d43 100644 --- a/lib/core-net/client/connect2.c +++ b/lib/core-net/client/connect2.c @@ -104,12 +104,12 @@ lws_getaddrinfo46(struct lws *wsi, const char *ads, struct addrinfo **result) #endif #if 0 - lwsl_debug("%s: asking to recheck CPD in 1s\n", __func__); + lwsl_wsi_debug(wsi, "asking to recheck CPD in 1s"); lws_system_cpd_start_defer(wsi->a.context, LWS_US_PER_SEC); #endif } - lwsl_info("%s: getaddrinfo '%s' says %d\n", __func__, ads, n); + lwsl_wsi_info(wsi, "getaddrinfo '%s' says %d", ads, n); #if defined(LWS_WITH_SYS_METRICS) if (n < 0) { @@ -177,7 +177,7 @@ lws_client_connect_2_dnsreq(struct lws *wsi) /* we only pipeline connections that said it was okay */ if (!wsi->client_pipeline) { - lwsl_debug("%s: new conn on no pipeline flag\n", __func__); + lwsl_wsi_debug(wsi, "new conn on no pipeline flag"); goto solo; } @@ -200,7 +200,7 @@ lws_client_connect_2_dnsreq(struct lws *wsi) case ACTIVE_CONNS_SOLO: break; case ACTIVE_CONNS_MUXED: - lwsl_notice("%s: ACTIVE_CONNS_MUXED\n", __func__); + lwsl_wsi_notice(wsi, "ACTIVE_CONNS_MUXED"); if (lwsi_role_h2(wsi)) { if (wsi->a.protocol->callback(wsi, @@ -215,8 +215,9 @@ lws_client_connect_2_dnsreq(struct lws *wsi) return wsi; case ACTIVE_CONNS_QUEUED: - lwsl_debug("%s: ACTIVE_CONNS_QUEUED st 0x%x: \n", __func__, - lwsi_state(wsi)); + lwsl_wsi_debug(wsi, "ACTIVE_CONNS_QUEUED st 0x%x: ", + lwsi_state(wsi)); + if (lwsi_state(wsi) == LRS_UNCONNECTED) { if (lwsi_role_h2(w)) lwsi_set_state(wsi, @@ -245,7 +246,7 @@ solo: lws_dll2_is_detached(&wsi->dll_cli_active_conns)) { lws_context_lock(wsi->a.context, __func__); lws_vhost_lock(wsi->a.vhost); - lwsl_info("%s: adding active conn %s\n", __func__, lws_wsi_tag(wsi)); + lwsl_wsi_info(wsi, "adding as active conn"); /* caution... we will have to unpick this on oom4 path */ lws_dll2_add_head(&wsi->dll_cli_active_conns, &wsi->a.vhost->dll_cli_active_conns_owner); @@ -284,7 +285,7 @@ solo: if (wsi->ipv6 && iface && inet_pton(AF_INET, iface, &addr.sin_addr) == 1) { - lwsl_notice("%s: client connection forced to IPv4\n", __func__); + lwsl_wsi_notice(wsi, "client connection forced to IPv4"); wsi->ipv6 = 0; } #endif @@ -308,7 +309,7 @@ solo: /* Priority 2: Connect to SOCK5 Proxy */ } else if (wsi->a.vhost->socks_proxy_port) { - lwsl_client("Sending SOCKS Greeting\n"); + lwsl_wsi_client(wsi, "Sending SOCKS Greeting"); adsin = wsi->a.vhost->socks_proxy_address; port = (int)wsi->a.vhost->socks_proxy_port; #endif @@ -326,7 +327,7 @@ solo: */ lwsi_set_state(wsi, LRS_WAITING_DNS); - lwsl_info("%s: %s: lookup %s:%u\n", __func__, wsi->lc.gutag, adsin, port); + lwsl_wsi_info(wsi, "lookup %s:%u", adsin, port); wsi->conn_port = (uint16_t)port; #if !defined(LWS_WITH_SYS_ASYNC_DNS) diff --git a/lib/core-net/client/connect3.c b/lib/core-net/client/connect3.c index 6bfd94cb9..8b3b35622 100644 --- a/lib/core-net/client/connect3.c +++ b/lib/core-net/client/connect3.c @@ -35,7 +35,7 @@ lws_client_conn_wait_timeout(lws_sorted_usec_list_t *sul) * connection before giving up on it and retrying. */ - lwsl_info("%s: connect wait timeout has fired\n", __func__); + lwsl_wsi_info(wsi, "connect wait timeout has fired"); lws_client_connect_3_connect(wsi, NULL, NULL, 0, NULL); } @@ -51,9 +51,9 @@ lws_client_dns_retry_timeout(lws_sorted_usec_list_t *sul) * isn't officially used until we connected somewhere. */ - lwsl_info("%s: dns retry\n", __func__); + lwsl_wsi_info(wsi, "dns retry"); if (!lws_client_connect_2_dnsreq(wsi)) - lwsl_notice("%s: DNS lookup failed\n", __func__); + lwsl_wsi_notice(wsi, "DNS lookup failed"); } /* @@ -87,18 +87,16 @@ lws_client_connect_check(struct lws *wsi) */ #if !defined(WIN32) - if (!getsockopt(wsi->desc.sockfd, SOL_SOCKET, SO_ERROR, - &e, &sl)) { + if (!getsockopt(wsi->desc.sockfd, SOL_SOCKET, SO_ERROR, &e, &sl)) { en = LWS_ERRNO; if (!e) { - lwsl_debug("%s: getsockopt check: conn OK errno %d\n", - __func__, en); + lwsl_wsi_debug(wsi, "getsockopt: conn OK errno %d", en); return LCCCR_CONNECTED; } - lwsl_notice("%s: getsockopt fd %d says err %d\n", __func__, - wsi->desc.sockfd, e); + lwsl_wsi_notice(wsi, "getsockopt fd %d says err %d", + wsi->desc.sockfd, e); } #else @@ -114,18 +112,18 @@ lws_client_connect_check(struct lws *wsi) if (en == WSAEALREADY) { /* reset the POLLOUT wait */ if (lws_change_pollfd(wsi, 0, LWS_POLLOUT)) - lwsl_notice("pollfd failed\n"); + lwsl_wsi_notice(wsi, "pollfd failed"); } if (!en || en == WSAEINVAL || en == WSAEWOULDBLOCK || en == WSAEALREADY) { - lwsl_debug("%s: errno %d\n", __func__, en); + lwsl_wsi_debug(wsi, "errno %d", en); return LCCCR_CONTINUE; } #endif - lwsl_notice("%s: connect check take as FAILED: errno %d\n", __func__, en); + lwsl_wsi_notice(wsi, "connect check take as FAILED: errno %d", en); return LCCCR_FAILED; } @@ -195,7 +193,7 @@ lws_client_connect_3_connect(struct lws *wsi, const char *ads, !wsi->dns_sorted_list.count && /* there's no results */ !lws_socket_is_valid(wsi->desc.sockfd) && /* no attempt ongoing */ !wsi->speculative_connect_owner.count /* no spec attempt */ ) { - lwsl_notice("%s: dns lookup failed %d\n", __func__, n); + lwsl_wsi_notice(wsi, "dns lookup failed %d", n); /* * DNS lookup itself failed... let's try again until we @@ -235,8 +233,8 @@ lws_client_connect_3_connect(struct lws *wsi, const char *ads, case LCCCR_CONTINUE: return NULL; default: - lwsl_debug("%s: getsockopt check: conn fail: errno %d\n", - __func__, LWS_ERRNO); + lwsl_wsi_debug(wsi, "getsockopt check: conn fail: errno %d", + LWS_ERRNO); lws_metrics_caliper_report(wsi->cal_conn, METRES_NOGO); goto try_next_dns_result_fds; } @@ -251,7 +249,7 @@ lws_client_connect_3_connect(struct lws *wsi, const char *ads, strncpy(sau.sun_path, ads, sizeof(sau.sun_path)); sau.sun_path[sizeof(sau.sun_path) - 1] = '\0'; - lwsl_info("%s: Unix skt: %s\n", __func__, ads); + lwsl_wsi_info(wsi, "Unix skt: %s", ads); if (sau.sun_path[0] == '@') sau.sun_path[0] = '\0'; @@ -262,7 +260,7 @@ lws_client_connect_3_connect(struct lws *wsi, const char *ads, #if defined(LWS_WITH_SYS_ASYNC_DNS) if (n == LADNS_RET_FAILED) { - lwsl_notice("%s: adns failed %s\n", __func__, ads); + lwsl_wsi_notice(wsi, "adns failed %s", ads); /* * Caller that is giving us LADNS_RET_FAILED will deal * with cleanup @@ -295,7 +293,7 @@ next_dns_result: wsi->sa46_peer = curr->dest; #if defined(LWS_WITH_NETLINK) wsi->peer_route_uidx = curr->uidx; - lwsl_info("%s: peer_route_uidx %d\n", __func__, wsi->peer_route_uidx); + lwsl_wsi_info(wsi, "peer_route_uidx %d", wsi->peer_route_uidx); #endif lws_free(curr); @@ -338,7 +336,7 @@ ads_known: } if (!lws_socket_is_valid(wsi->desc.sockfd)) { - lwsl_warn("Unable to open socket\n"); + lwsl_wsi_warn(wsi, "Unable to open socket"); goto try_next_dns_result; } @@ -348,17 +346,16 @@ ads_known: #else 0)) { #endif - lwsl_err("Failed to set wsi socket options\n"); + lwsl_wsi_err(wsi, "Failed to set wsi socket options"); goto try_next_dns_result_closesock; } /* apply requested socket options */ if (lws_plat_set_socket_options_ip(wsi->desc.sockfd, wsi->c_pri, wsi->flags)) - lwsl_warn("%s: %s: unable to set ip options\n", - __func__, wsi->lc.gutag); + lwsl_wsi_warn(wsi, "unable to set ip options"); - lwsl_debug("%s: %s: WAITING_CONNECT\n", __func__, wsi->lc.gutag); + lwsl_wsi_debug(wsi, "WAITING_CONNECT"); lwsi_set_state(wsi, LRS_WAITING_CONNECT); if (wsi->a.context->event_loop_ops->sock_accept) @@ -447,7 +444,7 @@ ads_known: user_callback_handle_rxflow(wsi->a.protocol->callback, wsi, LWS_CALLBACK_CONNECTING, wsi->user_space, (void *)(intptr_t)wsi->desc.sockfd, 0)) { - lwsl_info("%s: CONNECTION CB closed\n", __func__); + lwsl_wsi_info(wsi, "CONNECTION CB closed"); goto failed1; } @@ -481,7 +478,8 @@ ads_known: errno_copy = 999; #endif - lwsl_debug("%s: connect: fd %d errno: %d\n", __func__, wsi->desc.sockfd, errno_copy); + lwsl_wsi_debug(wsi, "connect: fd %d errno: %d", + wsi->desc.sockfd, errno_copy); if (errno_copy && errno_copy != LWS_EALREADY && @@ -582,7 +580,7 @@ conn_good: #endif lws_sa46_write_numeric_address(&wsi->sa46_local, buf, sizeof(buf)); - lwsl_info("%s: %s: source ads %s\n", __func__, wsi->lc.gutag, buf); + lwsl_wsi_info(wsi, "source ads %s", buf); #endif } #endif @@ -596,7 +594,8 @@ conn_good: wsi->a.protocol->callback(wsi, LWS_CALLBACK_WSI_CREATE, wsi->user_space, NULL, 0); - lwsl_debug("%s: going into connect_4\n", __func__); + lwsl_wsi_debug(wsi, "going into connect_4"); + return lws_client_connect_4_established(wsi, NULL, plen); oom4: @@ -641,7 +640,7 @@ connect_to: /* * It looks like the sul_connect_timeout fired */ - lwsl_info("%s: abandoning connect due to timeout\n", __func__); + lwsl_wsi_info(wsi, "abandoning connect due to timeout"); try_next_dns_result_fds: lws_pt_lock(pt, __func__); diff --git a/lib/core-net/client/connect4.c b/lib/core-net/client/connect4.c index 8e13dc03e..40471f823 100644 --- a/lib/core-net/client/connect4.c +++ b/lib/core-net/client/connect4.c @@ -62,7 +62,7 @@ lws_client_connect_4_established(struct lws *wsi, struct lws *wsi_piggyback, if (!cpa) goto failed; - lwsl_info("%s: going via proxy\n", __func__); + lwsl_wsi_info(wsi, "going via proxy"); plen = lws_snprintf((char *)pt->serv_buf, 256, "CONNECT %s:%u HTTP/1.1\x0d\x0a" @@ -99,7 +99,7 @@ lws_client_connect_4_established(struct lws *wsi, struct lws *wsi_piggyback, (unsigned int)plen, MSG_NOSIGNAL); if (n < 0) { - lwsl_debug("ERROR writing to proxy socket\n"); + lwsl_wsi_debug(wsi, "ERROR writing to proxy socket"); cce = "proxy write failed"; goto failed; } @@ -158,11 +158,11 @@ send_hs: */ lws_callback_on_writable(wsi_piggyback); - lwsl_info("%s: %s: waiting to send hdrs (par state 0x%x)\n", - __func__, wsi->lc.gutag, lwsi_state(wsi_piggyback)); + lwsl_wsi_info(wsi, "waiting to send hdrs (par state 0x%x)", + lwsi_state(wsi_piggyback)); } else { - lwsl_info("%s: %s: %s %s client created own conn " - "(raw %d) vh %sm st 0x%x\n", __func__, wsi->lc.gutag, + lwsl_wsi_info(wsi, "%s %s client created own conn " + "(raw %d) vh %sm st 0x%x", wsi->role_ops->name, wsi->a.protocol->name, rawish, wsi->a.vhost->name, lwsi_state(wsi)); @@ -200,12 +200,10 @@ send_hs: case CCTLS_RETURN_DONE: break; case CCTLS_RETURN_RETRY: - lwsl_debug("%s: create_tls RETRY\n", - __func__); + lwsl_wsi_debug(wsi, "create_tls RETRY"); return wsi; default: - lwsl_debug("%s: create_tls FAIL\n", - __func__); + lwsl_wsi_debug(wsi, "create_tls FAIL"); goto failed; } @@ -216,9 +214,8 @@ send_hs: * LRS_H2_WAITING_TO_SEND_HEADERS already. */ - lwsl_notice("%s: %s: tls established st 0x%x, " - "client_h2_alpn %d\n", __func__, - wsi->lc.gutag, lwsi_state(wsi), + lwsl_wsi_notice(wsi, "tls established st 0x%x, " + "client_h2_alpn %d", lwsi_state(wsi), wsi->client_h2_alpn); if (lwsi_state(wsi) != @@ -249,7 +246,7 @@ send_hs: (enum lws_callback_reasons)m, wsi->user_space, NULL, 0); if (n < 0) { - lwsl_info("RAW_PROXY_CLI_ADOPT err\n"); + lwsl_wsi_info(wsi, "RAW_PROXY_CLI_ADOPT err"); goto failed; } } @@ -264,8 +261,7 @@ send_hs: return wsi; } #endif - lwsl_info("%s: settings LRS_MQTTC_IDLE\n", - __func__); + lwsl_wsi_info(wsi, "settings LRS_MQTTC_IDLE"); lwsi_set_state(wsi, LRS_MQTTC_IDLE); /* @@ -282,8 +278,7 @@ send_hs: pfd.events = LWS_POLLIN; pfd.revents = LWS_POLLOUT; - lwsl_info("%s: going to service fd\n", - __func__); + lwsl_wsi_info(wsi, "going to service fd"); n = lws_service_fd(wsi->a.context, &pfd); if (n < 0) { cce = "first service failed"; @@ -295,7 +290,7 @@ send_hs: return wsi; } #endif - lwsl_info("%s: setting ESTABLISHED\n", __func__); + lwsl_wsi_info(wsi, "setting ESTABLISHED"); lwsi_set_state(wsi, LRS_ESTABLISHED); return wsi; diff --git a/lib/core-net/close.c b/lib/core-net/close.c index 31533977e..d2ade62c0 100644 --- a/lib/core-net/close.c +++ b/lib/core-net/close.c @@ -257,7 +257,7 @@ __lws_free_wsi(struct lws *wsi) if (wsi->a.context->event_loop_ops->destroy_wsi) wsi->a.context->event_loop_ops->destroy_wsi(wsi); - lwsl_debug("%s: tsi fds count %d\n", __func__, + lwsl_wsi_debug(wsi, "tsi fds count %d\n", wsi->a.context->pt[(int)wsi->tsi].fds_count); /* confirm no sul left scheduled in wsi itself */ @@ -281,8 +281,8 @@ lws_remove_child_from_any_parent(struct lws *wsi) pwsi = &wsi->parent->child_list; while (*pwsi) { if (*pwsi == wsi) { - lwsl_info("%s: detach %s from parent %s\n", __func__, - lws_wsi_tag(wsi), lws_wsi_tag(wsi->parent)); + lwsl_wsi_info(wsi, "detach from parent %s", + lws_wsi_tag(wsi->parent)); if (wsi->parent->a.protocol) wsi->parent->a.protocol->callback(wsi, @@ -296,7 +296,7 @@ lws_remove_child_from_any_parent(struct lws *wsi) pwsi = &(*pwsi)->sibling_list; } if (!seen) - lwsl_err("%s: failed to detach from parent\n", __func__); + lwsl_wsi_err(wsi, "failed to detach from parent"); wsi->parent = NULL; } @@ -355,12 +355,12 @@ __lws_close_free_wsi(struct lws *wsi, enum lws_close_status reason, if (!wsi) return; - lwsl_info("%s: %s: caller: %s\n", __func__, lws_wsi_tag(wsi), caller); + lwsl_wsi_info(wsi, "caller: %s", caller); lws_access_log(wsi); if (!lws_dll2_is_detached(&wsi->dll_buflist)) - lwsl_info("%s: going down with stuff in buflist\n", __func__); + lwsl_wsi_info(wsi, "going down with stuff in buflist"); context = wsi->a.context; pt = &context->pt[(int)wsi->tsi]; @@ -500,7 +500,7 @@ __lws_close_free_wsi(struct lws *wsi, enum lws_close_status reason, lws_callback_on_writable(wsi); return; } - lwsl_info("%s: %s: end LRS_FLUSHING_BEFORE_CLOSE\n", __func__, lws_wsi_tag(wsi)); + lwsl_wsi_info(wsi, " end LRS_FLUSHING_BEFORE_CLOSE"); goto just_kill_connection; default: if (lws_has_buffered_out(wsi) @@ -509,7 +509,7 @@ __lws_close_free_wsi(struct lws *wsi, enum lws_close_status reason, wsi->http.comp_ctx.may_have_more #endif ) { - lwsl_info("%s: %s: LRS_FLUSHING_BEFORE_CLOSE\n", __func__, lws_wsi_tag(wsi)); + lwsl_wsi_info(wsi, "LRS_FLUSHING_BEFORE_CLOSE"); lwsi_set_state(wsi, LRS_FLUSHING_BEFORE_CLOSE); __lws_set_timeout(wsi, PENDING_FLUSH_STORED_SEND_BEFORE_CLOSE, 5); @@ -547,15 +547,15 @@ __lws_close_free_wsi(struct lws *wsi, enum lws_close_status reason, if (lws_rops_fidx(wsi->role_ops, LWS_ROPS_close_via_role_protocol) && lws_rops_func_fidx(wsi->role_ops, LWS_ROPS_close_via_role_protocol). close_via_role_protocol(wsi, reason)) { - lwsl_info("%s: clsoe_via_role took over: %s (sockfd %d)\n", __func__, - lws_wsi_tag(wsi), wsi->desc.sockfd); + lwsl_wsi_info(wsi, "close_via_role took over (sockfd %d)", + wsi->desc.sockfd); return; } just_kill_connection: - lwsl_debug("%s: real just_kill_connection A: %s (sockfd %d)\n", __func__, - lws_wsi_tag(wsi), wsi->desc.sockfd); + lwsl_wsi_debug(wsi, "real just_kill_connection A: (sockfd %d)", + wsi->desc.sockfd); #if defined(LWS_WITH_THREADPOOL) lws_threadpool_wsi_closing(wsi); @@ -621,8 +621,8 @@ just_kill_connection: !wsi->close_is_redirect) { static const char _reason[] = "closed before established"; - lwsl_debug("%s: closing in unestablished state 0x%x\n", - __func__, lwsi_state(wsi)); + lwsl_wsi_debug(wsi, "closing in unestablished state 0x%x", + lwsi_state(wsi)); wsi->socket_is_permanently_unusable = 1; lws_inform_client_conn_fail(wsi, @@ -667,7 +667,7 @@ just_kill_connection: } } if (n) - lwsl_debug("closing: shutdown (state 0x%x) ret %d\n", + lwsl_wsi_debug(wsi, "closing: shutdown (state 0x%x) ret %d", lwsi_state(wsi), LWS_ERRNO); /* @@ -693,8 +693,8 @@ just_kill_connection: #endif } - lwsl_info("%s: real just_kill_connection: %s (sockfd %d)\n", __func__, - lws_wsi_tag(wsi), wsi->desc.sockfd); + lwsl_wsi_info(wsi, "real just_kill_connection: sockfd %d\n", + wsi->desc.sockfd); #ifdef LWS_WITH_HUBBUB if (wsi->http.rw) { @@ -756,7 +756,7 @@ just_kill_connection: */ ccb = 1; - lwsl_info("%s: %s: cce=%d\n", __func__, lws_wsi_tag(wsi), ccb); + lwsl_wsi_info(wsi, "cce=%d", ccb); pro = wsi->a.protocol; @@ -796,7 +796,7 @@ async_close: #if defined(LWS_WITH_SECURE_STREAMS) if (wsi->for_ss) { - lwsl_debug("%s: for_ss\n", __func__); + lwsl_wsi_debug(wsi, "for_ss"); /* * We were adopted for a particular ss, but, eg, we may not * have succeeded with the connection... we are closing which is @@ -877,11 +877,10 @@ __lws_close_free_wsi_final(struct lws *wsi) if (!wsi->shadow && lws_socket_is_valid(wsi->desc.sockfd) && !lws_ssl_close(wsi)) { - lwsl_debug("%s: wsi %s: fd %d\n", __func__, lws_wsi_tag(wsi), - wsi->desc.sockfd); + lwsl_wsi_debug(wsi, "fd %d", wsi->desc.sockfd); n = compatible_close(wsi->desc.sockfd); if (n) - lwsl_debug("closing: close ret %d\n", LWS_ERRNO); + lwsl_wsi_debug(wsi, "closing: close ret %d", LWS_ERRNO); __remove_wsi_socket_from_fds(wsi); if (lws_socket_is_valid(wsi->desc.sockfd)) @@ -902,7 +901,7 @@ __lws_close_free_wsi_final(struct lws *wsi) wsi->close_is_redirect = 0; - lwsl_info("%s: picking up redirection", __func__); + lwsl_wsi_info(wsi, "picking up redirection"); lws_role_transition(wsi, LWSIFR_CLIENT, LRS_UNCONNECTED, &role_ops_h1); @@ -935,7 +934,7 @@ __lws_close_free_wsi_final(struct lws *wsi) #endif if (lws_header_table_attach(wsi, 0)) { - lwsl_err("failed to get ah\n"); + lwsl_wsi_err(wsi, "failed to get ah"); return; } // } @@ -953,7 +952,8 @@ __lws_close_free_wsi_final(struct lws *wsi) &vh); if (vh) { if (!vh->count_bound_wsi && vh->grace_after_unref) { - lwsl_info("%s: %s: in use\n", __func__, vh->lc.gutag); + lwsl_wsi_info(wsi, "%s in use\n", + vh->lc.gutag); lws_sul_cancel(&vh->sul_unref); } vh->count_bound_wsi++; diff --git a/lib/core-net/output.c b/lib/core-net/output.c index a8ff396ad..447834207 100644 --- a/lib/core-net/output.c +++ b/lib/core-net/output.c @@ -119,7 +119,7 @@ lws_issue_raw(struct lws *wsi, unsigned char *buf, size_t len) else m = (unsigned int)lws_ssl_capable_write(wsi, buf, n); - lwsl_info("%s: ssl_capable_write (%d) says %d\n", __func__, n, m); + lwsl_wsi_info(wsi, "ssl_capable_write (%d) says %d", n, m); /* something got written, it can have been truncated now */ wsi->could_have_pending = 1; diff --git a/lib/core-net/pollfd.c b/lib/core-net/pollfd.c index b98d16a7e..90e8a96f5 100644 --- a/lib/core-net/pollfd.c +++ b/lib/core-net/pollfd.c @@ -61,7 +61,7 @@ _lws_change_pollfd(struct lws *wsi, int _and, int _or, struct lws_pollargs *pa) * to cancel service */ - lwsl_debug("%s: using leave_pollout_active\n", __func__); + lwsl_wsi_debug(wsi, "using leave_pollout_active"); return 0; } @@ -147,8 +147,8 @@ _lws_change_pollfd(struct lws *wsi, int _and, int _or, struct lws_pollargs *pa) pfd = &pt->fds[wsi->position_in_fds_table]; pa->fd = wsi->desc.sockfd; - lwsl_debug("%s: %s: fd %d events %d -> %d\n", __func__, lws_wsi_tag(wsi), - pa->fd, pfd->events, (pfd->events & ~_and) | _or); + lwsl_wsi_debug(wsi, "fd %d events %d -> %d", pa->fd, pfd->events, + (pfd->events & ~_and) | _or); pa->prev_events = pfd->events; pa->events = pfd->events = (short)((pfd->events & ~_and) | _or); @@ -250,12 +250,12 @@ __dump_fds(struct lws_context_per_thread *pt, const char *s) { unsigned int n; - lwsl_warn("%s: fds_count %u, %s\n", __func__, pt->fds_count, s); + lwsl_cx_warn(pt->context, "fds_count %u, %s", pt->fds_count, s); for (n = 0; n < pt->fds_count; n++) { struct lws *wsi = wsi_from_fd(pt->context, pt->fds[n].fd); - lwsl_warn(" %d: fd %d, wsi %s, pos_in_fds: %d\n", + lwsl_cx_warn(pt->context, " %d: fd %d, wsi %s, pos_in_fds: %d", n + 1, pt->fds[n].fd, lws_wsi_tag(wsi), wsi ? wsi->position_in_fds_table : -1); } @@ -277,19 +277,19 @@ __insert_wsi_socket_into_fds(struct lws_context *context, struct lws *wsi) lws_pt_assert_lock_held(pt); - lwsl_debug("%s: %s: tsi=%d, sock=%d, pos-in-fds=%d\n", - __func__, lws_wsi_tag(wsi), wsi->tsi, wsi->desc.sockfd, pt->fds_count); + lwsl_wsi_debug(wsi, "tsi=%d, sock=%d, pos-in-fds=%d", + wsi->tsi, wsi->desc.sockfd, pt->fds_count); if ((unsigned int)pt->fds_count >= context->fd_limit_per_thread) { - lwsl_err("Too many fds (%d vs %d)\n", context->max_fds, - context->fd_limit_per_thread ); + lwsl_cx_err(context, "Too many fds (%d vs %d)", context->max_fds, + context->fd_limit_per_thread); return 1; } #if !defined(_WIN32) if (!wsi->a.context->max_fds_unrelated_to_ulimit && wsi->desc.sockfd - lws_plat_socket_offset() >= (int)context->max_fds) { - lwsl_err("Socket fd %d is too high (%d) offset %d\n", + lwsl_cx_err(context, "Socket fd %d is too high (%d) offset %d", wsi->desc.sockfd, context->max_fds, lws_plat_socket_offset()); return 1; diff --git a/lib/core-net/route.c b/lib/core-net/route.c index a7d9cc4c4..d1c652c2c 100644 --- a/lib/core-net/route.c +++ b/lib/core-net/route.c @@ -57,14 +57,14 @@ _lws_routing_entry_dump(struct lws_context *cx, lws_route_t *rou) "gw: %s, ", sa); } - lwsl_info(" %s ifidx: %d, pri: %d, proto: %d\n", fin, + lwsl_cx_info(cx, " %s ifidx: %d, pri: %d, proto: %d\n", fin, rou->if_idx, rou->priority, rou->proto); } void _lws_routing_table_dump(struct lws_context *cx) { - lwsl_info("%s\n", __func__); + lwsl_cx_info(cx, "\n"); lws_start_foreach_dll(struct lws_dll2 *, d, lws_dll2_get_head(&cx->routing_table)) { lws_route_t *rou = lws_container_of(d, lws_route_t, list); diff --git a/lib/core-net/service.c b/lib/core-net/service.c index 01e3d3c61..cc57d7c1c 100644 --- a/lib/core-net/service.c +++ b/lib/core-net/service.c @@ -398,8 +398,7 @@ lws_buflist_aware_read(struct lws_context_per_thread *pt, struct lws *wsi, ebuf->token = ep; ebuf->len = n = lws_ssl_capable_read(wsi, ep, (size_t)e); - lwsl_debug("%s: %s: %s: ssl_capable_read %d\n", __func__, - lws_wsi_tag(wsi), hint, ebuf->len); + lwsl_wsi_debug(wsi, "%s: ssl_capable_read %d", hint, ebuf->len); if (!bns && /* only acknowledge error when we handled buflist content */ n == LWS_SSL_CAPABLE_ERROR) { diff --git a/lib/core-net/state.c b/lib/core-net/state.c index 2063f06b9..8eabce2bd 100644 --- a/lib/core-net/state.c +++ b/lib/core-net/state.c @@ -74,10 +74,10 @@ _report(lws_state_manager_t *mgr, int a, int b) /* a dependency took responsibility for retry */ #if (_LWS_ENABLED_LOGS & LLL_INFO) - lwsl_info("%s: %s: %s: rejected '%s' -> '%s'\n", - __func__, mgr->name, l->name, - _systnm(mgr, a, temp8), - _systnm(mgr, b, temp8)); + lwsl_cx_info(mgr->context, "%s: %s: rejected '%s' -> '%s'", + mgr->name, l->name, + _systnm(mgr, a, temp8), + _systnm(mgr, b, temp8)); #endif return 1; @@ -99,7 +99,8 @@ _lws_state_transition(lws_state_manager_t *mgr, int target) return 1; #if (_LWS_ENABLED_LOGS & LLL_DEBUG) - lwsl_debug("%s: %s: changed %d '%s' -> %d '%s'\n", __func__, mgr->name, + if (mgr->context) + lwsl_cx_debug(mgr->context, "%s: changed %d '%s' -> %d '%s'", mgr->name, mgr->state, _systnm(mgr, mgr->state, temp8), target, _systnm(mgr, target, temp8)); #endif @@ -110,7 +111,7 @@ _lws_state_transition(lws_state_manager_t *mgr, int target) _report(mgr, target, target); #if defined(LWS_WITH_SYS_SMD) - if (mgr->smd_class) + if (mgr->smd_class && mgr->context) (void)lws_smd_msg_printf(mgr->context, mgr->smd_class, "{\"state\":\"%s\"}", mgr->state_names[target]); @@ -135,7 +136,7 @@ lws_state_transition_steps(lws_state_manager_t *mgr, int target) n = _lws_state_transition(mgr, mgr->state + 1); #if (_LWS_ENABLED_LOGS & LLL_INFO) - lwsl_info("%s: %s -> %s\n", __func__, _systnm(mgr, i, temp8), + lwsl_cx_info(mgr->context, "%s -> %s", _systnm(mgr, i, temp8), _systnm(mgr, mgr->state, temp8)); #endif diff --git a/lib/core-net/vhost.c b/lib/core-net/vhost.c index 3f1dd32af..949b4b437 100644 --- a/lib/core-net/vhost.c +++ b/lib/core-net/vhost.c @@ -465,7 +465,7 @@ lws_protocol_init_vhost(struct lws_vhost *vh, int *any) || !vh->pvo #endif ) { - lwsl_info("init %s.%s", vh->name, + lwsl_vhost_info(vh, "init %s.%s", vh->name, vh->protocols[n].name); if (vh->protocols[n].callback((struct lws *)lwsa, LWS_CALLBACK_PROTOCOL_INIT, NULL, @@ -479,8 +479,8 @@ lws_protocol_init_vhost(struct lws_vhost *vh, int *any) lws_free(vh->protocol_vh_privs[n]); vh->protocol_vh_privs[n] = NULL; } - lwsl_err("%s: protocol %s failed init\n", - __func__, vh->protocols[n].name); + lwsl_vhost_err(vh, "protocol %s failed init", + vh->protocols[n].name); return 1; } @@ -507,7 +507,7 @@ lws_protocol_init(struct lws_context *context) context->doing_protocol_init = 1; - lwsl_info("%s\n", __func__); + lwsl_cx_info(context, "\n"); while (vh) { @@ -517,7 +517,7 @@ lws_protocol_init(struct lws_context *context) goto next; if (lws_protocol_init_vhost(vh, &any)) { - lwsl_warn("%s: init vhost %s failed\n", __func__, vh->name); + lwsl_vhost_warn(vh, "init vhost %s failed", vh->name); r = -1; } next: @@ -527,7 +527,7 @@ next: context->doing_protocol_init = 0; if (r) - lwsl_warn("%s: some protocols did not init\n", __func__); + lwsl_cx_warn(context, "some protocols did not init"); if (!context->protocol_init_done) { @@ -896,7 +896,7 @@ lws_create_vhost(struct lws_context *context, #ifdef LWS_WITH_UNIX_SOCK if (LWS_UNIX_SOCK_ENABLED(vh)) { - lwsl_info("Creating Vhost '%s' path \"%s\", %d protocols\n", + lwsl_vhost_info(vh, "Creating '%s' path \"%s\", %d protocols", vh->name, vh->iface, vh->count_protocols); } else #endif @@ -912,14 +912,14 @@ lws_create_vhost(struct lws_context *context, lws_snprintf(buf, sizeof(buf), "port %u", info->port); break; } - lwsl_info("Creating Vhost '%s' %s, %d protocols, IPv6 %s\n", + lwsl_vhost_info(vh, "Creating Vhost '%s' %s, %d protocols, IPv6 %s", vh->name, buf, vh->count_protocols, LWS_IPV6_ENABLED(vh) ? "on" : "off"); } mounts = info->mounts; while (mounts) { (void)mount_protocols[0]; - lwsl_info(" mounting %s%s to %s\n", + lwsl_vhost_info(vh, " mounting %s%s to %s", mount_protocols[mounts->origin_protocol], mounts->origin ? mounts->origin : "none", mounts->mountpoint); @@ -996,12 +996,12 @@ lws_create_vhost(struct lws_context *context, #endif if (lws_fi(&vh->fic, "vh_create_ssl_srv") || lws_context_init_server_ssl(info, vh)) { - lwsl_err("%s: lws_context_init_server_ssl failed\n", __func__); + lwsl_vhost_err(vh, "lws_context_init_server_ssl failed"); goto bail1; } if (lws_fi(&vh->fic, "vh_create_ssl_cli") || lws_context_init_client_ssl(info, vh)) { - lwsl_err("%s: lws_context_init_client_ssl failed\n", __func__); + lwsl_vhost_err(vh, "lws_context_init_client_ssl failed"); goto bail1; } #if defined(LWS_WITH_SERVER) @@ -1012,7 +1012,7 @@ lws_create_vhost(struct lws_context *context, n = _lws_vhost_init_server(info, vh); lws_context_unlock(context); if (n < 0) { - lwsl_err("init server failed\n"); + lwsl_vhost_err(vh, "init server failed\n"); goto bail1; } #endif @@ -1039,7 +1039,7 @@ lws_create_vhost(struct lws_context *context, if (context->protocol_init_done) if (lws_fi(&vh->fic, "vh_create_protocol_init") || lws_protocol_init(context)) { - lwsl_err("%s: lws_protocol_init failed\n", __func__); + lwsl_vhost_err(vh, "lws_protocol_init failed"); goto bail1; } @@ -1088,7 +1088,7 @@ lws_cancel_service(struct lws_context *context) if (context->service_no_longer_possible) return; - lwsl_debug("%s\n", __func__); + lwsl_cx_debug(context, "\n"); for (m = 0; m < context->count_threads; m++) { if (pt->pipe_wsi) @@ -1289,7 +1289,7 @@ lws_vhost_destroy1(struct lws_vhost *vh) { struct lws_context *context = vh->context; - lwsl_info("%s\n", __func__); + lwsl_vhost_info(vh, "\n"); lws_context_lock(context, "vhost destroy 1"); /* ---------- context { */ @@ -1436,7 +1436,7 @@ __lws_vhost_destroy2(struct lws_vhost *vh) while (n < vh->count_protocols) { wsi.a.protocol = protocol; - lwsl_debug("%s: protocol destroy\n", __func__); + lwsl_vhost_debug(vh, "protocol destroy"); if (protocol->callback) protocol->callback(&wsi, LWS_CALLBACK_PROTOCOL_DESTROY, @@ -1530,7 +1530,7 @@ __lws_vhost_destroy2(struct lws_vhost *vh) if (LWS_UNIX_SOCK_ENABLED(vh)) { n = unlink(vh->iface); if (n) - lwsl_info("Closing unix socket %s: errno %d\n", + lwsl_vhost_info(vh, "Closing unix socket %s: errno %d\n", vh->iface, errno); } #endif diff --git a/lib/core-net/wsi-timeout.c b/lib/core-net/wsi-timeout.c index 44da7c44d..1f4ea8d29 100644 --- a/lib/core-net/wsi-timeout.c +++ b/lib/core-net/wsi-timeout.c @@ -136,8 +136,7 @@ __lws_set_timeout(struct lws *wsi, enum pending_timeout reason, int secs) &wsi->sul_timeout, ((lws_usec_t)secs) * LWS_US_PER_SEC); - lwsl_debug("%s: %s: %d secs, reason %d\n", __func__, lws_wsi_tag(wsi), - secs, reason); + lwsl_wsi_debug(wsi, "%d secs, reason %d\n", secs, reason); wsi->pending_timeout = (char)reason; } @@ -168,7 +167,7 @@ lws_set_timeout(struct lws *wsi, enum pending_timeout reason, int secs) // assert(!secs || !wsi->mux_stream_immortal); if (secs && wsi->mux_stream_immortal) - lwsl_err("%s: on immortal stream %d %d\n", __func__, reason, secs); + lwsl_wsi_err(wsi, "on immortal stream %d %d", reason, secs); lws_pt_lock(pt, __func__); __lws_set_timeout(wsi, reason, secs); diff --git a/lib/core-net/wsi.c b/lib/core-net/wsi.c index bb64a1fc3..68578ea18 100644 --- a/lib/core-net/wsi.c +++ b/lib/core-net/wsi.c @@ -47,7 +47,7 @@ void lwsi_set_state(struct lws *wsi, lws_wsi_state_t lrs) wsi->wsistate = (old & (unsigned int)(~LRS_MASK)) | lrs; - lwsl_debug("lwsi_set_state 0x%lx -> 0x%lx)", + lwsl_wsi_debug(wsi, "lwsi_set_state 0x%lx -> 0x%lx)", (unsigned long)old, (unsigned long)wsi->wsistate); } #endif @@ -73,7 +73,7 @@ lws_vhost_bind_wsi(struct lws_vhost *vh, struct lws *wsi) #if defined(LWS_WITH_TLS_JIT_TRUST) if (!vh->count_bound_wsi && vh->grace_after_unref) { - lwsl_info("%s: %s: in use\n", __func__, vh->lc.gutag); + lwsl_wsi_info(wsi, "in use"); lws_sul_cancel(&vh->sul_unref); } #endif @@ -81,7 +81,7 @@ lws_vhost_bind_wsi(struct lws_vhost *vh, struct lws *wsi) vh->count_bound_wsi++; lws_context_unlock(vh->context); /* } context ---------- */ - lwsl_debug("%s: vh %s: wsi %s/%s, count_bound_wsi %d\n", __func__, + lwsl_wsi_debug(wsi, "vh %s: wsi %s/%s, count_bound_wsi %d\n", vh->name, wsi->role_ops ? wsi->role_ops->name : "none", wsi->a.protocol ? wsi->a.protocol->name : "none", vh->count_bound_wsi); @@ -110,7 +110,7 @@ __lws_vhost_unbind_wsi(struct lws *wsi) lws_tls_jit_trust_vh_start_grace(vh); #endif - lwsl_debug("%s: vh %s: count_bound_wsi %d\n", __func__, + lwsl_wsi_debug(wsi, "vh %s: count_bound_wsi %d", vh->name, vh->count_bound_wsi); lws_vhost_unlock(vh); @@ -392,7 +392,7 @@ lws_rx_flow_control(struct lws *wsi, int _enable) lwsi_role_h2_ENCAPSULATION(wsi)) return 0; // !!! - lwsl_info("%s: %s 0x%x\n", __func__, lws_wsi_tag(wsi), _enable); + lwsl_wsi_info(wsi, "0x%x", _enable); if (!(_enable & LWS_RXFLOW_REASON_APPLIES)) { /* @@ -506,13 +506,13 @@ __lws_rx_flow_control(struct lws *wsi) wsi->rxflow_change_to &= (~LWS_RXFLOW_PENDING_CHANGE) & 3; - lwsl_info("rxflow: %s change_to %d\n", lws_wsi_tag(wsi), - wsi->rxflow_change_to & LWS_RXFLOW_ALLOW); + lwsl_wsi_info(wsi, "rxflow: change_to %d", + wsi->rxflow_change_to & LWS_RXFLOW_ALLOW); /* adjust the pollfd for this wsi */ if (wsi->rxflow_change_to & LWS_RXFLOW_ALLOW) { - lwsl_info("%s: reenable POLLIN\n", __func__); + lwsl_wsi_info(wsi, "reenable POLLIN"); // lws_buflist_describe(&wsi->buflist, NULL, __func__); if (__lws_change_pollfd(wsi, 0, LWS_POLLIN)) { lwsl_info("%s: fail\n", __func__); @@ -549,8 +549,7 @@ lws_ensure_user_space(struct lws *wsi) return 1; } } else - lwsl_debug("%s: %s protocol pss %lu, user_space=%p\n", __func__, - lws_wsi_tag(wsi), + lwsl_wsi_debug(wsi, "protocol pss %lu, user_space=%p", (long)wsi->a.protocol->per_session_data_size, wsi->user_space); return 0; @@ -622,8 +621,8 @@ lws_role_transition(struct lws *wsi, enum lwsi_role role, enum lwsi_state state, #if (_LWS_ENABLED_LOGS & LLL_DEBUG) if (wsi->role_ops) name = wsi->role_ops->name; - lwsl_debug("%s: %s: wsistate 0x%lx, ops %s\n", __func__, - lws_wsi_tag(wsi), (unsigned long)wsi->wsistate, name); + lwsl_wsi_debug(wsi, "wsistate 0x%lx, ops %s", + (unsigned long)wsi->wsistate, name); #endif } @@ -1013,7 +1012,7 @@ _lws_generic_transaction_completed_active_conn(struct lws **_wsi, char take_vh_l * Nothing pipelined... we should hang around a bit * in case something turns up... otherwise we'll close */ - lwsl_info("%s: nothing pipelined waiting\n", __func__); + lwsl_wsi_info(wsi, "nothing pipelined waiting"); lwsi_set_state(wsi, LRS_IDLING); lws_set_timeout(wsi, PENDING_TIMEOUT_CLIENT_CONN_IDLE, @@ -1132,8 +1131,7 @@ _lws_generic_transaction_completed_active_conn(struct lws **_wsi, char take_vh_l /* after the first one, they can only be coming from the queue */ wnew->transaction_from_pipeline_queue = 1; - lwsl_notice("%s: pipeline queue passed %s on to queued %s\n", - __func__, lws_wsi_tag(wsi), lws_wsi_tag(wnew)); + lwsl_wsi_notice(wsi, " pipeline queue passed -> %s", lws_wsi_tag(wnew)); *_wsi = wnew; /* inform caller we swapped */ @@ -1153,8 +1151,8 @@ lws_raw_transaction_completed(struct lws *wsi) * Defer the close until the last part of the partial is sent. * */ - lwsl_debug("%s: %s: deferring due to partial\n", __func__, - lws_wsi_tag(wsi)); + + lwsl_wsi_debug(wsi, "deferring due to partial"); wsi->close_when_buffered_out_drained = 1; lws_callback_on_writable(wsi); @@ -1233,8 +1231,8 @@ lws_http_close_immortal(struct lws *wsi) wsi->mux_stream_immortal = 0; nwsi = lws_get_network_wsi(wsi); - lwsl_debug("%s: %s %s %d\n", __func__, lws_wsi_tag(wsi), lws_wsi_tag(nwsi), - nwsi->immortal_substream_count); + lwsl_wsi_debug(wsi, "%s (%d)", lws_wsi_tag(nwsi), + nwsi->immortal_substream_count); assert(nwsi->immortal_substream_count); nwsi->immortal_substream_count--; if (!nwsi->immortal_substream_count) @@ -1259,7 +1257,7 @@ lws_mux_mark_immortal(struct lws *wsi) && !wsi->client_mux_substream #endif ) { - lwsl_err("%s: not h2 substream\n", __func__); + lwsl_wsi_err(wsi, "not h2 substream"); return; } @@ -1267,8 +1265,8 @@ lws_mux_mark_immortal(struct lws *wsi) if (!nwsi) return; - lwsl_debug("%s: %s %s %d\n", __func__, lws_wsi_tag(wsi), lws_wsi_tag(nwsi), - nwsi->immortal_substream_count); + lwsl_wsi_debug(wsi, "%s (%d)\n", lws_wsi_tag(nwsi), + nwsi->immortal_substream_count); wsi->mux_stream_immortal = 1; assert(nwsi->immortal_substream_count < 255); /* largest count */ @@ -1315,8 +1313,8 @@ lws_wsi_client_stash_item(struct lws *wsi, int stash_idx, int hdr_idx) void lws_wsi_mux_insert(struct lws *wsi, struct lws *parent_wsi, unsigned int sid) { - lwsl_info("%s: %s, par %s: assign sid %d (curr %d)\n", __func__, - lws_wsi_tag(wsi), lws_wsi_tag(parent_wsi), sid, wsi->mux.my_sid); + lwsl_wsi_info(wsi, "par %s: assign sid %d (curr %d)", + lws_wsi_tag(parent_wsi), sid, wsi->mux.my_sid); if (wsi->mux.my_sid && wsi->mux.my_sid != (unsigned int)sid) assert(0); @@ -1373,7 +1371,7 @@ lws_wsi_mux_close_children(struct lws *wsi, int reason) w = &wsi->mux.child_list; while (*w) { - lwsl_info(" closing child %s\n", lws_wsi_tag(*w)); + lwsl_wsi_info((*w), " closing child"); /* disconnect from siblings */ wsi2 = (*w)->mux.sibling_list; assert (wsi2 != *w); @@ -1398,8 +1396,8 @@ lws_wsi_mux_sibling_disconnect(struct lws *wsi) wsi2 = (*w)->mux.sibling_list; (*w)->mux.sibling_list = NULL; *w = wsi2; - lwsl_debug(" %s disentangled from sibling %s\n", - lws_wsi_tag(wsi), lws_wsi_tag(wsi2)); + lwsl_wsi_debug(wsi, " disentangled from sibling %s", + lws_wsi_tag(wsi2)); break; } } lws_end_foreach_llp(w, mux.sibling_list); @@ -1417,9 +1415,9 @@ lws_wsi_mux_dump_waiting_children(struct lws *wsi) wsi = wsi->mux.child_list; while (wsi) { - lwsl_info(" %c %s: sid %u: 0x%x %s %s\n", + lwsl_wsi_info(wsi, " %c sid %u: 0x%x %s %s", wsi->mux.requested_POLLOUT ? '*' : ' ', - lws_wsi_tag(wsi), wsi->mux.my_sid, lwsi_state(wsi), + wsi->mux.my_sid, lwsi_state(wsi), wsi->role_ops->name, wsi->a.protocol ? wsi->a.protocol->name : "noprotocol"); @@ -1439,8 +1437,8 @@ lws_wsi_mux_mark_parents_needing_writeable(struct lws *wsi) wsi2 = wsi; while (wsi2) { wsi2->mux.requested_POLLOUT = 1; - lwsl_info("%s: mark: %s, sid %u, pending writable\n", - __func__, lws_wsi_tag(wsi2), wsi2->mux.my_sid); + lwsl_wsi_info(wsi2, "sid %u, pending writable", + wsi2->mux.my_sid); wsi2 = wsi2->mux.parent_wsi; } @@ -1454,8 +1452,7 @@ lws_wsi_mux_move_child_to_tail(struct lws **wsi2) while (w) { if (!w->mux.sibling_list) { /* w is the current last */ - lwsl_debug("w=%s, *wsi2 = %s\n", lws_wsi_tag(w), - lws_wsi_tag(*wsi2)); + lwsl_wsi_debug(w, "*wsi2 = %s\n", lws_wsi_tag(*wsi2)); if (w == *wsi2) /* we are already last */ break; @@ -1591,8 +1588,7 @@ lws_wsi_mux_apply_queue(struct lws *wsi) #if defined(LWS_ROLE_H2) if (lwsi_role_http(wsi) && lwsi_state(w) == LRS_H2_WAITING_TO_SEND_HEADERS) { - lwsl_info("%s: cli pipeq %s to be h2\n", __func__, - lws_wsi_tag(w)); + lwsl_wsi_info(w, "cli pipeq to be h2"); lwsi_set_state(w, LRS_H1C_ISSUE_HANDSHAKE2); @@ -1607,8 +1603,7 @@ lws_wsi_mux_apply_queue(struct lws *wsi) #if defined(LWS_ROLE_MQTT) if (lwsi_role_mqtt(wsi) && lwsi_state(wsi) == LRS_ESTABLISHED) { - lwsl_info("%s: cli pipeq %s to be mqtt\n", __func__, - lws_wsi_tag(w)); + lwsl_wsi_info(w, "cli pipeq to be mqtt\n"); /* remove ourselves from client queue */ lws_dll2_remove(&w->dll2_cli_txn_queue); diff --git a/lib/core/context.c b/lib/core/context.c index 869c45af9..0b9a22489 100644 --- a/lib/core/context.c +++ b/lib/core/context.c @@ -137,7 +137,7 @@ lws_state_notify_protocol_init(struct lws_state_manager *mgr, if (target == LWS_SYSTATE_IFACE_COLDPLUG && context->netlink && !context->nl_initial_done) { - lwsl_info("%s: waiting for netlink coldplug\n", __func__); + lwsl_cx_info(context, "waiting for netlink coldplug"); return 1; } @@ -158,8 +158,8 @@ lws_state_notify_protocol_init(struct lws_state_manager *mgr, context->pss_policies && ab0 && ab1 && !lws_system_blob_get_size(ab0) && lws_system_blob_get_size(ab1)) { - lwsl_info("%s: AUTH1 state triggering api.amazon.com auth\n", - __func__); + lwsl_cx_info(context, + "AUTH1 state triggering api.amazon.com auth"); /* * Start trying to acquire it if it's not already in progress * returns nonzero if we determine it's not needed @@ -197,7 +197,7 @@ lws_state_notify_protocol_init(struct lws_state_manager *mgr, if (context->hss_fetch_policy) return 1; - lwsl_debug("%s: starting policy fetch\n", __func__); + lwsl_cx_debug(context, "starting policy fetch"); /* * Start trying to acquire it if it's not already in progress * returns nonzero if we determine it's not needed @@ -221,7 +221,7 @@ lws_state_notify_protocol_init(struct lws_state_manager *mgr, if (target != LWS_SYSTATE_POLICY_VALID) return 0; - lwsl_info("%s: doing protocol init on POLICY_VALID\n", __func__); + lwsl_cx_info(context, "doing protocol init on POLICY_VALID\n"); return lws_protocol_init(context); } @@ -777,9 +777,9 @@ lws_create_context(const struct lws_context_creation_info *info) #endif /* network */ - lwsl_notice("LWS: %s, %s%s", library_version, opts_str, s); + lwsl_cx_notice(context, "LWS: %s, %s%s", library_version, opts_str, s); #if defined(LWS_WITH_NETWORK) - lwsl_info("Event loop: %s", plev->ops->name); + lwsl_cx_info(context, "Event loop: %s", plev->ops->name); #endif /* @@ -812,8 +812,8 @@ lws_create_context(const struct lws_context_creation_info *info) context->ss_proxy_port = info->ss_proxy_port; context->ss_proxy_address = info->ss_proxy_address; if (context->ss_proxy_bind && context->ss_proxy_address) - lwsl_notice("%s: using ss proxy bind '%s', port %d, ads '%s'\n", - __func__, context->ss_proxy_bind, context->ss_proxy_port, + lwsl_cx_notice(context, "ss proxy bind '%s', port %d, ads '%s'", + context->ss_proxy_bind, context->ss_proxy_port, context->ss_proxy_address); #endif @@ -823,7 +823,7 @@ lws_create_context(const struct lws_context_creation_info *info) #if defined(LWS_ROLE_WS) && defined(LWS_WITHOUT_EXTENSIONS) if (info->extensions) - lwsl_warn("%s: LWS_WITHOUT_EXTENSIONS but extensions ptr set\n", __func__); + lwsl_cx_warn(context, "WITHOUT_EXTENSIONS but exts ptr set"); #endif #endif /* network */ @@ -932,13 +932,14 @@ lws_create_context(const struct lws_context_creation_info *info) #ifndef LWS_NO_DAEMONIZE if (pid_daemon) { context->started_with_parent = pid_daemon; - lwsl_info(" Started with daemon pid %u\n", (unsigned int)pid_daemon); + lwsl_cx_info(context, " Started with daemon pid %u", + (unsigned int)pid_daemon); } #endif #if defined(__ANDROID__) n = getrlimit(RLIMIT_NOFILE, &rt); if (n == -1) { - lwsl_err("Get RLIMIT_NOFILE failed!\n"); + lwsl_cx_err(context, "Get RLIMIT_NOFILE failed!"); goto free_context_fail2; } @@ -953,8 +954,7 @@ lws_create_context(const struct lws_context_creation_info *info) context->max_fds = 2560; if (l > 10000000) - lwsl_warn("%s: unreasonable ulimit -n workaround\n", - __func__); + lwsl_cx_warn(context, "unreasonable ulimit -n workaround"); else if (l != -1l) context->max_fds = (unsigned int)l; @@ -962,8 +962,7 @@ lws_create_context(const struct lws_context_creation_info *info) #endif if ((int)context->max_fds < 0 || lws_fi(&context->fic, "ctx_createfail_maxfds")) { - lwsl_err("%s: problem getting process max files\n", - __func__); + lwsl_cx_err(context, "problem getting process max files"); goto free_context_fail2; } @@ -1053,7 +1052,7 @@ lws_create_context(const struct lws_context_creation_info *info) if (!lws_smd_register(context, context, 0, LWSSMDCL_NETWORK, lws_system_smd_cb)) { - lwsl_err("%s: early smd register failed\n", __func__); + lwsl_cx_err(context, "early smd register failed"); } /* user smd participant */ @@ -1062,7 +1061,7 @@ lws_create_context(const struct lws_context_creation_info *info) !lws_smd_register(context, info->early_smd_opaque, 0, info->early_smd_class_filter, info->early_smd_cb)) { - lwsl_err("%s: early smd register failed\n", __func__); + lwsl_cx_err(context, "early smd register failed"); } #endif @@ -1132,7 +1131,7 @@ lws_create_context(const struct lws_context_creation_info *info) } if (!info->ka_interval && info->ka_time > 0) { - lwsl_err("info->ka_interval can't be 0 if ka_time used\n"); + lwsl_cx_err(context, "info->ka_interval can't be 0 if ka_time used"); goto free_context_fail; } @@ -1164,13 +1163,13 @@ lws_create_context(const struct lws_context_creation_info *info) #if defined(LWS_WITH_SYS_FAULT_INJECTION) lws_free(context->pt[0].fds); #endif - lwsl_err("OOM allocating %d fds\n", context->max_fds); + lwsl_cx_err(context, "OOM allocating %d fds\n", context->max_fds); goto free_context_fail; } #endif - lwsl_info(" ctx: %5luB (%ld ctx + pt(%ld thr x %d)), " - "pt-fds: %d, fdmap: %d\n", + lwsl_cx_info(context, "ctx: %5luB (%ld ctx + pt(%ld thr x %d)), " + "pt-fds: %d, fdmap: %d", (long)sizeof(struct lws_context) + (context->count_threads * context->pt_serv_buf_size), (long)sizeof(struct lws_context), @@ -1179,7 +1178,7 @@ lws_create_context(const struct lws_context_creation_info *info) context->fd_limit_per_thread, n); #if defined(LWS_ROLE_H1) || defined(LWS_ROLE_H2) - lwsl_info(" http: ah_data: %u, ah: %lu, max count %u\n", + lwsl_cx_info(context, " http: ah_data: %u, ah: %lu, max count %u", context->max_http_header_data, (long)sizeof(struct allocated_headers), context->max_http_header_pool); @@ -1310,8 +1309,7 @@ lws_create_context(const struct lws_context_creation_info *info) else vh = lws_create_vhost(context, &ii); if (!vh) { - lwsl_err("%s: failed to create system vhost\n", - __func__); + lwsl_cx_err(context, "failed to create system vhost"); goto bail_libuv_aware; } @@ -1319,7 +1317,7 @@ lws_create_context(const struct lws_context_creation_info *info) if (lws_protocol_init_vhost(vh, NULL) || lws_fi(&context->fic, "ctx_createfail_sys_vh_init")) { - lwsl_err("%s: failed to init system vhost\n", __func__); + lwsl_cx_err(context, "failed to init system vhost"); goto bail_libuv_aware; } #if defined(LWS_WITH_SYS_ASYNC_DNS) @@ -1366,7 +1364,7 @@ lws_create_context(const struct lws_context_creation_info *info) if (!lws_check_opt(info->options, LWS_SERVER_OPTION_EXPLICIT_VHOSTS)) { if (!lws_create_vhost(context, info) || lws_fi(&context->fic, "ctx_createfail_def_vh")) { - lwsl_err("Failed to create default vhost\n"); + lwsl_cx_err(context, "Failed to create default vhost"); #if defined(LWS_WITH_PEER_LIMITS) lws_free_set_NULL(context->pl_hash_table); @@ -1405,7 +1403,7 @@ lws_create_context(const struct lws_context_creation_info *info) if (lws_ss_policy_set(context, "hardcoded") || lws_fi(&context->fic, "ctx_createfail_ss_pol3")) { - lwsl_err("%s: policy set failed\n", __func__); + lwsl_cx_err(context, "policy set failed"); goto bail_libuv_aware; } } @@ -1415,7 +1413,7 @@ lws_create_context(const struct lws_context_creation_info *info) if (lws_ss_policy_set(context, "hardcoded") || lws_fi(&context->fic, "ctx_createfail_ss_pol3")) { - lwsl_err("%s: policy set failed\n", __func__); + lwsl_cx_err(context, "policy set failed"); goto bail_libuv_aware; } } @@ -1424,7 +1422,7 @@ lws_create_context(const struct lws_context_creation_info *info) lws_context_init_extensions(info, context); - lwsl_info(" mem: per-conn: %5lu bytes + protocol rx buf\n", + lwsl_cx_info(context, " mem: per-conn: %5lu bytes + protocol rx buf", (unsigned long)sizeof(struct lws)); /* @@ -1480,7 +1478,8 @@ bail_libuv_aware: #if defined(LWS_WITH_NETWORK) fail_event_libs: - lwsl_err("Requested event library support not configured\n"); + if (context) + lwsl_cx_err(context, "Requested event library support not configured"); #endif #if defined(LWS_WITH_NETWORK) @@ -1556,7 +1555,7 @@ lws_system_cpd_set(struct lws_context *cx, lws_cpd_result_t result) return; #if !defined(LWS_WITH_NO_LOGS) - lwsl_notice("%s: setting CPD result %s\n", __func__, cname[result]); + lwsl_cx_notice(cx, "setting CPD result %s", cname[result]); #endif cx->captive_portal_detect = (uint8_t)result; @@ -1724,7 +1723,7 @@ lws_context_destroy(struct lws_context *context) lws_context_lock(context, __func__); context->inside_context_destroy = 1; - lwsl_info("%s: destroy_state %d\n", __func__, context->destroy_state); + lwsl_cx_info(context, "destroy_state %d", context->destroy_state); switch (context->destroy_state) { case LWSCD_NO_DESTROY: @@ -1732,7 +1731,7 @@ lws_context_destroy(struct lws_context *context) * We're getting started */ - lwsl_info("%s: starting context destroy flow\n", __func__); + lwsl_cx_info(context, "starting context destroy flow"); context->being_destroyed = 1; #if defined(LWS_WITH_NETWORK) @@ -1750,7 +1749,7 @@ lws_context_destroy(struct lws_context *context) vh = context->vhost_list; while (vh) { - lwsl_info("%s: vh %s start close\n", __func__, vh->name); + lwsl_vhost_info(vh, "start close"); vh1 = vh->vhost_next; lws_vhost_destroy1(vh); vh = vh1; @@ -1801,8 +1800,9 @@ lws_context_destroy(struct lws_context *context) if (wsi) { - lwsl_debug("%s: pt %d: closing wsi %p: role %s\n", - __func__, n, wsi, wsi->role_ops->name); + lwsl_cx_debug(context, + "pt %d: closing wsi %p: role %s", + n, wsi, wsi->role_ops->name); lws_close_free_wsi(wsi, LWS_CLOSE_STATUS_NOSTATUS_CONTEXT_DESTROY, @@ -1827,8 +1827,8 @@ lws_context_destroy(struct lws_context *context) */ if (context->event_loop_ops->destroy_pt) { - lwsl_info("%s: calling evlib destroy_pt %d\n", - __func__, n); + lwsl_cx_info(context, + "calling evlib destroy_pt %d\n", n); context->event_loop_ops->destroy_pt(context, n); } @@ -1840,7 +1840,7 @@ next: if (deferred_pt) { context->destroy_state = LWSCD_PT_WAS_DEFERRED; - lwsl_notice("%s: destroy from inside service\n", __func__); + lwsl_cx_notice(context, "destroy from inside service"); lws_cancel_service(context); goto bail; } @@ -1868,8 +1868,7 @@ next: #if defined(LWS_WITH_NETWORK) if (context->event_loop_ops->destroy_context1) { - lwsl_info("%s: do evlib destroy_context1 and wait\n", - __func__); + lwsl_cx_info(context, "do evlib destroy_context1 and wait"); context->event_loop_ops->destroy_context1(context); goto bail; @@ -1880,7 +1879,7 @@ next: * now ourselves... */ - lwsl_info("%s: manually destroying pts\n", __func__); + lwsl_cx_info(context, "manually destroying pts"); pt = context->pt; for (n = 0; n < context->count_threads; n++, pt++) { @@ -1899,8 +1898,7 @@ next: !context->pt[n].event_loop_pt_unused) alive++; - lwsl_info("%s: PT_WAIT_ALL_DESTROYED: %d alive\n", __func__, - alive); + lwsl_cx_info(context, "PT_WAIT_ALL_DESTROYED: %d alive", alive); if (alive) break; @@ -2000,7 +1998,7 @@ next: while (pt->http.ah_list) _lws_destroy_ah(pt, pt->http.ah_list); #endif - lwsl_info("%s: pt destroy %d\n", __func__, n); + lwsl_cx_info(context, "pt destroy %d", n); lws_pt_destroy(pt); } #endif /* NETWORK */ @@ -2012,14 +2010,15 @@ next: if (context->pt[0].event_loop_foreign && context->event_loop_ops->destroy_context1) { - lwsl_info("%s: leaving final context destruction" - " for final call\n", __func__); + lwsl_cx_info(context, + "leaving final context destruction" + " for final call"); goto bail; } if (context->event_loop_ops->destroy_context1 && !context->pt[0].event_loop_foreign) { - lwsl_notice("%s: waiting for internal loop exit\n", __func__); + lwsl_cx_notice(context, "waiting for internal loop exit"); goto bail; } @@ -2065,7 +2064,7 @@ next: pt->destroy_self = 0; pt->is_destroyed = 1; - lwsl_info("%s: pt %d fully destroyed\n", __func__, + lwsl_cx_info(context, "pt %d fully destroyed", (int)(pt - pt->context->pt)); } diff --git a/lib/plat/unix/unix-caps.c b/lib/plat/unix/unix-caps.c index 054e3d138..2f38854d5 100644 --- a/lib/plat/unix/unix-caps.c +++ b/lib/plat/unix/unix-caps.c @@ -125,11 +125,11 @@ lws_plat_drop_app_privileges(struct lws_context *context, int actually_drop) g = getgrnam(context->groupname); if (g) { #endif - lwsl_info("%s: group %s -> gid %u\n", __func__, + lwsl_cx_info(context, "group %s -> gid %u", context->groupname, g->gr_gid); context->gid = g->gr_gid; } else { - lwsl_err("%s: unknown groupname '%s'\n", __func__, + lwsl_cx_err(context, "unknown groupname '%s'", context->groupname); return 1; @@ -150,10 +150,10 @@ lws_plat_drop_app_privileges(struct lws_context *context, int actually_drop) #endif context->uid = p->pw_uid; - lwsl_info("%s: username %s -> uid %u\n", __func__, + lwsl_cx_info(context, "username %s -> uid %u", context->username, (unsigned int)p->pw_uid); } else { - lwsl_err("%s: unknown username %s\n", __func__, + lwsl_cx_err(context, "unknown username %s", context->username); return 1; @@ -175,23 +175,22 @@ lws_plat_drop_app_privileges(struct lws_context *context, int actually_drop) g = getgrgid(context->gid); if (!g) { #endif - lwsl_err("%s: cannot find name for gid %d\n", - __func__, context->gid); + lwsl_cx_err(context, "cannot find name for gid %d", + context->gid); return 1; } if (setgid(context->gid)) { - lwsl_err("%s: setgid: %s failed\n", __func__, - strerror(LWS_ERRNO)); + lwsl_cx_err(context, "setgid: %s failed", + strerror(LWS_ERRNO)); return 1; } - lwsl_notice("%s: effective group '%s'\n", __func__, - g->gr_name); + lwsl_cx_notice(context, "effective group '%s'", g->gr_name); } else - lwsl_info("%s: not changing group\n", __func__); + lwsl_cx_info(context, "not changing group"); /* if he gave us the uid or we have it from the username, set it */ @@ -206,8 +205,8 @@ lws_plat_drop_app_privileges(struct lws_context *context, int actually_drop) p = getpwuid(context->uid); if (!p) { #endif - lwsl_err("%s: getpwuid: unable to find uid %d\n", - __func__, context->uid); + lwsl_cx_err(context, "getpwuid: unable to find uid %d", + context->uid); return 1; } @@ -224,13 +223,13 @@ lws_plat_drop_app_privileges(struct lws_context *context, int actually_drop) return 1; if (setuid(context->uid)) { - lwsl_err("%s: setuid: %s failed\n", __func__, - strerror(LWS_ERRNO)); + lwsl_cx_err(context, "setuid: %s failed", + strerror(LWS_ERRNO)); return 1; } else - lwsl_notice("%s: effective user '%s'\n", - __func__, p->pw_name); + lwsl_cx_notice(context, "effective user '%s'", + p->pw_name); #if defined(LWS_HAVE_SYS_CAPABILITY_H) && defined(LWS_HAVE_LIBCAP) _lws_plat_apply_caps(CAP_EFFECTIVE, context->caps, @@ -239,12 +238,12 @@ lws_plat_drop_app_privileges(struct lws_context *context, int actually_drop) if (context->count_caps) { int n; for (n = 0; n < context->count_caps; n++) - lwsl_notice(" RETAINING CAP %d\n", + lwsl_cx_notice(context, " RETAINING CAP %d", (int)context->caps[n]); } #endif } else - lwsl_info("%s: not changing user\n", __func__); + lwsl_cx_info(context, "not changing user"); return 0; } diff --git a/lib/plat/unix/unix-init.c b/lib/plat/unix/unix-init.c index 64cec8a53..8621640a6 100644 --- a/lib/plat/unix/unix-init.c +++ b/lib/plat/unix/unix-init.c @@ -131,12 +131,12 @@ lws_plat_init(struct lws_context *context, context->max_fds, "lws_lookup"); if (!context->lws_lookup) { - lwsl_err("%s: OOM on alloc lws_lookup array for %d conn\n", - __func__, context->max_fds); + lwsl_cx_err(context, "OOM on alloc lws_lookup array for %d conn", + context->max_fds); return 1; } - lwsl_info(" mem: platform fd map: %5lu B\n", + lwsl_cx_info(context, " mem: platform fd map: %5lu B", (unsigned long)(sizeof(struct lws *) * context->max_fds)); #endif #if defined(LWS_WITH_FILE_OPS) diff --git a/lib/roles/http/server/server.c b/lib/roles/http/server/server.c index 4b61922b6..ea68f849f 100644 --- a/lib/roles/http/server/server.c +++ b/lib/roles/http/server/server.c @@ -3276,7 +3276,8 @@ lws_server_get_canonical_hostname(struct lws_context *context, lws_strncpy((char *)context->canonical_hostname, "unknown", sizeof(context->canonical_hostname)); - lwsl_info(" canonical_hostname = %s\n", context->canonical_hostname); + lwsl_cx_info(context, " canonical_hostname = %s\n", + context->canonical_hostname); #else (void)context; #endif diff --git a/lib/roles/netlink/ops-netlink.c b/lib/roles/netlink/ops-netlink.c index 8a9d0265d..9aa1028ee 100644 --- a/lib/roles/netlink/ops-netlink.c +++ b/lib/roles/netlink/ops-netlink.c @@ -41,7 +41,7 @@ #define RTA_ALIGNTO 4U //#define lwsl_netlink lwsl_notice -#define lwsl_netlink lwsl_info +#define lwsl_cx_netlink lwsl_cx_info static void lws_netlink_coldplug_done_cb(lws_sorted_usec_list_t *sul) @@ -91,7 +91,7 @@ rops_handle_POLLIN_netlink(struct lws_context_per_thread *pt, struct lws *wsi, n = (unsigned int)recvmsg(wsi->desc.sockfd, &msg, 0); if ((int)n < 0) { - lwsl_notice("%s: recvmsg failed\n", __func__); + lwsl_cx_notice(cx, "recvmsg failed"); return LWS_HPI_RET_PLEASE_CLOSE_ME; } @@ -115,7 +115,7 @@ rops_handle_POLLIN_netlink(struct lws_context_per_thread *pt, struct lws *wsi, struct rtattr *attribute; unsigned int len; - lwsl_netlink("%s: RTM %d\n", __func__, h->nlmsg_type); + lwsl_cx_netlink(cx, "RTM %d", h->nlmsg_type); memset(&robj, 0, sizeof(robj)); robj.if_idx = -1; @@ -138,11 +138,11 @@ rops_handle_POLLIN_netlink(struct lws_context_per_thread *pt, struct lws *wsi, /* loop over all attributes for the NEWLINK message */ for (attribute = IFLA_RTA(ifi); RTA_OK(attribute, len); attribute = RTA_NEXT(attribute, len)) { - lwsl_netlink("%s: if attr %d\n", __func__, + lwsl_cx_netlink(cx, "if attr %d", (int)attribute->rta_type); switch(attribute->rta_type) { case IFLA_IFNAME: - lwsl_netlink("NETLINK ifidx %d : %s\n", + lwsl_cx_netlink(cx, "NETLINK ifidx %d : %s", ifi->ifi_index, (char *)RTA_DATA(attribute)); break; @@ -151,8 +151,8 @@ rops_handle_POLLIN_netlink(struct lws_context_per_thread *pt, struct lws *wsi, } /* switch */ } /* for loop */ - lwsl_netlink("%s: NEWLINK ifi_index %d, flags 0x%x\n", - __func__, ifi->ifi_index, ifi->ifi_flags); + lwsl_cx_netlink(cx, "NEWLINK ifi_index %d, flags 0x%x", + ifi->ifi_index, ifi->ifi_flags); /* * Despite "New"link this is actually telling us there @@ -164,8 +164,8 @@ rops_handle_POLLIN_netlink(struct lws_context_per_thread *pt, struct lws *wsi, * Interface is down, so scrub all routes that * applied to it */ - lwsl_netlink("%s: NEWLINK: ifdown %d\n", - __func__, ifi->ifi_index); + lwsl_cx_netlink(cx, "NEWLINK: ifdown %d", + ifi->ifi_index); lws_pt_lock(pt, __func__); _lws_route_table_ifdown(pt, ifi->ifi_index); lws_pt_unlock(pt); @@ -188,7 +188,7 @@ rops_handle_POLLIN_netlink(struct lws_context_per_thread *pt, struct lws *wsi, ra = (struct rtattr *)IFA_RTA(ifam); ra_len = (unsigned int)IFA_PAYLOAD(h); - lwsl_netlink("%s: %s\n", __func__, + lwsl_cx_netlink(cx, "%s", h->nlmsg_type == RTM_NEWADDR ? "NEWADDR" : "DELADDR"); @@ -201,7 +201,7 @@ rops_handle_POLLIN_netlink(struct lws_context_per_thread *pt, struct lws *wsi, case RTM_NEWROUTE: case RTM_DELROUTE: - lwsl_netlink("%s: %s\n", __func__, + lwsl_cx_netlink(cx, "%s", h->nlmsg_type == RTM_NEWROUTE ? "NEWROUTE" : "DELROUTE"); @@ -212,23 +212,23 @@ rops_handle_POLLIN_netlink(struct lws_context_per_thread *pt, struct lws *wsi, case RTM_DELNEIGH: case RTM_NEWNEIGH: - lwsl_netlink("%s: %s\n", __func__, - h->nlmsg_type == RTM_NEWNEIGH ? "NEWNEIGH" : - "DELNEIGH"); + lwsl_cx_netlink(cx, "%s", h->nlmsg_type == + RTM_NEWNEIGH ? "NEWNEIGH" : + "DELNEIGH"); #if !defined(LWS_WITH_NO_LOGS) && defined(_DEBUG) nd = (struct ndmsg *)rm; - lwsl_netlink("%s: fam %u, ifidx %u, flags 0x%x\n", - __func__, nd->ndm_family, nd->ndm_ifindex, + lwsl_cx_netlink(cx, "fam %u, ifidx %u, flags 0x%x", + nd->ndm_family, nd->ndm_ifindex, nd->ndm_flags); #endif ra = (struct rtattr *)RTM_RTA(rm); ra_len = (unsigned int)RTM_PAYLOAD(h); for ( ; RTA_OK(ra, ra_len); ra = RTA_NEXT(ra, ra_len)) { - lwsl_netlink("%s: atr %d\n", __func__, ra->rta_type); + lwsl_cx_netlink(cx, "atr %d", ra->rta_type); switch (ra->rta_type) { case NDA_DST: - lwsl_netlink("%s: dst len %d\n", - __func__, ra->rta_len); + lwsl_cx_netlink(cx, "dst len %d", + ra->rta_len); break; } } @@ -238,7 +238,7 @@ rops_handle_POLLIN_netlink(struct lws_context_per_thread *pt, struct lws *wsi, continue; default: - lwsl_netlink("%s: *** Unknown RTM_%d\n", __func__, + lwsl_cx_netlink(cx, "*** Unknown RTM_%d", h->nlmsg_type); continue; } /* switch */ @@ -255,14 +255,14 @@ rops_handle_POLLIN_netlink(struct lws_context_per_thread *pt, struct lws *wsi, rm->rtm_family); robj.src_len = rm->rtm_src_len; lws_sa46_write_numeric_address(&robj.src, buf, sizeof(buf)); - lwsl_netlink("%s: RTA_SRC: %s\n", __func__, buf); + lwsl_cx_netlink(cx, "RTA_SRC: %s", buf); break; case RTA_DST: lws_sa46_copy_address(&robj.dest, RTA_DATA(ra), rm->rtm_family); robj.dest_len = rm->rtm_dst_len; lws_sa46_write_numeric_address(&robj.dest, buf, sizeof(buf)); - lwsl_netlink("%s: RTA_DST: %s\n", __func__, buf); + lwsl_cx_netlink(cx, "RTA_DST: %s", buf); break; case RTA_GATEWAY: lws_sa46_copy_address(&robj.gateway, @@ -275,7 +275,7 @@ rops_handle_POLLIN_netlink(struct lws_context_per_thread *pt, struct lws *wsi, case RTA_IIF: /* int: input interface index */ case RTA_OIF: /* int: output interface index */ robj.if_idx = *(int *)RTA_DATA(ra); - lwsl_netlink("%s: ifidx %d\n", __func__, robj.if_idx); + lwsl_cx_netlink(cx, "ifidx %d", robj.if_idx); break; case RTA_PRIORITY: /* int: priority of route */ p = RTA_DATA(ra); @@ -292,8 +292,8 @@ rops_handle_POLLIN_netlink(struct lws_context_per_thread *pt, struct lws *wsi, break; default: - lwsl_info("%s: unknown attr type %d\n", - __func__, ra->rta_type); + lwsl_cx_info(cx, "unknown attr type %d", + ra->rta_type); break; } } /* for */ @@ -308,7 +308,7 @@ second_half: /* * This will also take down wsi marked as using it */ - lwsl_netlink("%s: DELROUTE: if_idx %d\n", __func__, + lwsl_cx_netlink(cx, "DELROUTE: if_idx %d", robj.if_idx); lws_pt_lock(pt, __func__); _lws_route_remove(pt, &robj, 0); @@ -317,7 +317,7 @@ second_half: case RTM_NEWROUTE: - lwsl_netlink("%s: NEWROUTE rtm_type %d\n", __func__, + lwsl_cx_netlink(cx, "NEWROUTE rtm_type %d", rm->rtm_type); /* @@ -336,7 +336,7 @@ second_half: goto ana; case RTM_DELADDR: - lwsl_notice("%s: DELADDR\n", __func__); + lwsl_cx_notice(cx, "DELADDR"); #if defined(_DEBUG) _lws_routing_entry_dump(cx, &robj); #endif @@ -348,7 +348,7 @@ second_half: case RTM_NEWADDR: - lwsl_netlink("%s: NEWADDR\n", __func__); + lwsl_cx_netlink(cx, "NEWADDR"); ana: /* @@ -373,7 +373,7 @@ ana: rou = lws_malloc(sizeof(*rou), __func__); if (!rou) { - lwsl_err("%s: oom\n", __func__); + lwsl_cx_err(cx, "oom"); return LWS_HPI_RET_HANDLED; } @@ -388,7 +388,8 @@ ana: rou->uidx = _lws_route_get_uidx(cx); lws_dll2_add_tail(&rou->list, &cx->routing_table); - lwsl_info("%s: route list size %u\n", __func__, cx->routing_table.count); + lwsl_cx_info(cx, "route list size %u", + cx->routing_table.count); _lws_route_pt_close_unroutable(pt); @@ -490,7 +491,7 @@ rops_pt_init_destroy_netlink(struct lws_context *context, /* we can only have one netlink socket */ return 0; - lwsl_info("%s: creating netlink skt\n", __func__); + lwsl_cx_info(context, "creating netlink skt"); /* * We want a netlink socket per pt as well @@ -505,7 +506,7 @@ rops_pt_init_destroy_netlink(struct lws_context *context, wsi->desc.sockfd = socket(AF_NETLINK, SOCK_RAW, NETLINK_ROUTE); if (wsi->desc.sockfd == LWS_SOCK_INVALID) { - lwsl_err("unable to open netlink\n"); + lwsl_cx_err(context, "unable to open netlink"); goto bail1; } @@ -526,7 +527,7 @@ rops_pt_init_destroy_netlink(struct lws_context *context, if (lws_fi(&context->fic, "netlink_bind") || bind(wsi->desc.sockfd, (struct sockaddr*)&sanl, sizeof(sanl)) < 0) { - lwsl_warn("%s: netlink bind failed\n", __func__); + lwsl_cx_warn(context, "netlink bind failed"); ret = 0; /* some systems deny access, just ignore */ goto bail2; } @@ -570,8 +571,8 @@ rops_pt_init_destroy_netlink(struct lws_context *context, n = (int)sendmsg(wsi->desc.sockfd, (struct msghdr *)&msg, 0); if (n < 0) { - lwsl_notice("%s: rt dump req failed... permissions? errno %d\n", - __func__, LWS_ERRNO); + lwsl_cx_notice(context, "rt dump req failed... permissions? errno %d", + LWS_ERRNO); } /* @@ -581,7 +582,7 @@ rops_pt_init_destroy_netlink(struct lws_context *context, * cull any ongoing connections as unroutable otherwise */ - lwsl_debug("%s: starting netlink coldplug wait\n", __func__); + lwsl_cx_debug(context, "starting netlink coldplug wait"); return 0; diff --git a/lib/roles/raw-file/ops-raw-file.c b/lib/roles/raw-file/ops-raw-file.c index 2b60be522..37e21256b 100644 --- a/lib/roles/raw-file/ops-raw-file.c +++ b/lib/roles/raw-file/ops-raw-file.c @@ -33,7 +33,7 @@ rops_handle_POLLIN_raw_file(struct lws_context_per_thread *pt, struct lws *wsi, if (pollfd->revents & LWS_POLLOUT) { n = lws_callback_as_writeable(wsi); if (lws_change_pollfd(wsi, LWS_POLLOUT, 0)) { - lwsl_info("failed at set pollfd\n"); + lwsl_wsi_info(wsi, "failed at set pollfd"); return LWS_HPI_RET_WSI_ALREADY_DIED; } if (n) @@ -44,7 +44,7 @@ rops_handle_POLLIN_raw_file(struct lws_context_per_thread *pt, struct lws *wsi, if (user_callback_handle_rxflow(wsi->a.protocol->callback, wsi, LWS_CALLBACK_RAW_RX_FILE, wsi->user_space, NULL, 0)) { - lwsl_debug("raw rx callback closed it\n"); + lwsl_wsi_debug(wsi, "raw rx callback closed it"); return LWS_HPI_RET_PLEASE_CLOSE_ME; } } diff --git a/lib/roles/raw-skt/ops-raw-skt.c b/lib/roles/raw-skt/ops-raw-skt.c index ff01fd3ff..fd4fd341a 100644 --- a/lib/roles/raw-skt/ops-raw-skt.c +++ b/lib/roles/raw-skt/ops-raw-skt.c @@ -55,8 +55,7 @@ rops_handle_POLLIN_raw_skt(struct lws_context_per_thread *pt, struct lws *wsi, #if defined(LWS_WITH_SERVER) if (!lwsi_role_client(wsi) && lwsi_state(wsi) != LRS_ESTABLISHED) { - lwsl_debug("%s: %s: wsistate 0x%x\n", __func__, lws_wsi_tag(wsi), - (int)wsi->wsistate); + lwsl_wsi_debug(wsi, "wsistate 0x%x\n", (int)wsi->wsistate); if (lwsi_state(wsi) != LRS_SSL_INIT) if (lws_server_socket_service_ssl(wsi, @@ -72,8 +71,7 @@ rops_handle_POLLIN_raw_skt(struct lws_context_per_thread *pt, struct lws *wsi, !(wsi->favoured_pollin && (pollfd->revents & pollfd->events & LWS_POLLOUT))) { - lwsl_debug("%s: POLLIN: %s, state 0x%x\n", __func__, - lws_wsi_tag(wsi), lwsi_state(wsi)); + lwsl_wsi_debug(wsi, "POLLIN: state 0x%x", lwsi_state(wsi)); switch (lwsi_state(wsi)) { @@ -122,7 +120,7 @@ rops_handle_POLLIN_raw_skt(struct lws_context_per_thread *pt, struct lws *wsi, case 0: if (wsi->unix_skt) break; - lwsl_info("%s: read 0 len\n", __func__); + lwsl_wsi_info(wsi, "read 0 len"); wsi->seen_zero_length_recv = 1; if (lws_change_pollfd(wsi, LWS_POLLIN, 0)) goto fail; @@ -156,7 +154,7 @@ rops_handle_POLLIN_raw_skt(struct lws_context_per_thread *pt, struct lws *wsi, post_rx: #endif if (n < 0) { - lwsl_info("LWS_CALLBACK_RAW_RX_fail\n"); + lwsl_wsi_info(wsi, "LWS_CALLBACK_RAW_RX_fail"); goto fail; } diff --git a/lib/secure-streams/secure-streams-client.c b/lib/secure-streams/secure-streams-client.c index b5f7e0825..756b65e23 100644 --- a/lib/secure-streams/secure-streams-client.c +++ b/lib/secure-streams/secure-streams-client.c @@ -149,7 +149,7 @@ lws_sspc_sul_retry_cb(lws_sorted_usec_list_t *sul) return; } - lwsl_notice("%s\n", h->cwsi->lc.gutag); + lwsl_sspc_notice(h, "%s", h->cwsi->lc.gutag); } static int @@ -171,7 +171,7 @@ lws_sspc_serialize_metadata(lws_sspc_handle_t *h, lws_sspc_metadata_t *md, } else { - lwsl_info("%s: sending metadata\n", __func__); + lwsl_sspc_info(h, "sending metadata"); p[0] = LWSSS_SER_TXPRE_METADATA; txc = (int)strlen(md->name); @@ -216,7 +216,7 @@ callback_sspc_client(struct lws *wsi, enum lws_callback_reasons reason, break; case LWS_CALLBACK_CLIENT_CONNECTION_ERROR: - lwsl_warn("%s: CONNECTION_ERROR\n", __func__); + lwsl_wsi_warn(wsi, "CONNECTION_ERROR"); #if defined(LWS_WITH_SYS_METRICS) /* * If any hanging caliper measurement, dump it, and free any tags @@ -232,7 +232,7 @@ callback_sspc_client(struct lws *wsi, enum lws_callback_reasons reason, case LWS_CALLBACK_RAW_CONNECTED: if (!h || lws_fi(&h->fic, "sspc_fail_on_linkup")) return -1; - lwsl_info("%s: CONNECTED (%s)\n", __func__, h->ssi.streamtype); + lwsl_sspc_info(h, "CONNECTED (%s)", h->ssi.streamtype); h->state = LPCSCLI_SENDING_INITIAL_TX; /* @@ -252,18 +252,18 @@ callback_sspc_client(struct lws *wsi, enum lws_callback_reasons reason, /* * our ss proxy Unix Domain socket has closed... */ - lwsl_info("%s: LWS_CALLBACK_RAW_CLOSE: %s proxy conn down, sspc h %s\n", - __func__, lws_wsi_tag(wsi), lws_sspc_tag(h)); if (!h) { - lwsl_info("%s: no sspc on client proxy link close\n", __func__); + lwsl_info("%s: no sspc on client proxy link close", __func__); break; } + lwsl_sspc_info(h, "LWS_CALLBACK_RAW_CLOSE: proxy conn down, wsi %s", + lws_wsi_tag(wsi)); lws_dsh_destroy(&h->dsh); if (h->ss_dangling_connected && h->ssi.state) { lws_ss_state_return_t ret_state; - lwsl_notice("%s: setting _DISCONNECTED\n", __func__); + lwsl_sspc_notice(h, "setting _DISCONNECTED"); h->ss_dangling_connected = 0; h->prev_ss_state = LWSSSCS_DISCONNECTED; ret_state = h->ssi.state(ss_to_userobj(h), NULL, @@ -289,7 +289,6 @@ callback_sspc_client(struct lws *wsi, enum lws_callback_reasons reason, /* * ie, the proxy has sent us something */ - lwsl_info("%s: RAW_RX: rx %d\n", __func__, (int)len); if (!h || !h->cwsi) { lwsl_info("%s: rx when client ss destroyed\n", __func__); @@ -297,8 +296,10 @@ callback_sspc_client(struct lws *wsi, enum lws_callback_reasons reason, return -1; } + lwsl_sspc_info(h, "%s: RAW_RX: rx %d\n", __func__, (int)len); + if (!len) { - lwsl_notice("%s: RAW_RX: zero len\n", __func__); + lwsl_sspc_notice(h, "RAW_RX: zero len"); return -1; } @@ -345,8 +346,8 @@ callback_sspc_client(struct lws *wsi, enum lws_callback_reasons reason, if (!h) break; - lwsl_debug("%s: WRITEABLE %s, state %d\n", __func__, - wsi->lc.gutag, h->state); + lwsl_sspc_debug(h, "WRITEABLE %s, state %d", + wsi->lc.gutag, h->state); /* * Management of ss timeout can happen any time and doesn't @@ -422,13 +423,13 @@ callback_sspc_client(struct lws *wsi, enum lws_callback_reasons reason, if (n < 0) goto metadata_hangup; - lwsl_debug("(local_conn) metadata\n"); + lwsl_sspc_debug(h, "(local_conn) metadata"); goto req_write_and_issue; } if (h->pending_writeable_len) { - lwsl_debug("(local_conn) PAYLOAD_LENGTH_HINT %u", + lwsl_sspc_debug(h, "(local_conn) PAYLOAD_LENGTH_HINT %u", (unsigned int)h->writeable_len); s[0] = LWSSS_SER_TXPRE_PAYLOAD_LENGTH_HINT; lws_ser_wu16be(&s[1], 4); @@ -439,12 +440,12 @@ callback_sspc_client(struct lws *wsi, enum lws_callback_reasons reason, } if (h->conn_req_state >= LWSSSPC_ONW_ONGOING) { - lwsl_info("%s: conn_req_state %d\n", __func__, + lwsl_sspc_info(h, "conn_req_state %d", h->conn_req_state); break; } - lwsl_info("%s: (local_conn) onward connect\n", __func__); + lwsl_sspc_info(h, "(local_conn) onward connect"); h->conn_req_state = LWSSSPC_ONW_ONGOING; @@ -484,8 +485,8 @@ callback_sspc_client(struct lws *wsi, enum lws_callback_reasons reason, } if (h->pending_writeable_len) { - lwsl_info("%s: PAYLOAD_LENGTH_HINT %u\n", - __func__, (unsigned int)h->writeable_len); + lwsl_sspc_info(h, "PAYLOAD_LENGTH_HINT %u", + (unsigned int)h->writeable_len); s[0] = LWSSS_SER_TXPRE_PAYLOAD_LENGTH_HINT; lws_ser_wu16be(&s[1], 4); lws_ser_wu32be(&s[3], (uint32_t)h->writeable_len); @@ -496,8 +497,8 @@ callback_sspc_client(struct lws *wsi, enum lws_callback_reasons reason, /* we can't write anything if we don't have credit */ if (!h->ignore_txc && h->txc.tx_cr <= 0) { - lwsl_info("%s: WRITEABLE / OPERATIONAL:" - " lack credit (%d)\n", __func__, + lwsl_sspc_info(h, "WRITEABLE / OPERATIONAL:" + " lack credit (%d)", h->txc.tx_cr); // break; } @@ -559,7 +560,7 @@ do_write: else n = lws_write(wsi, (uint8_t *)cp, (unsigned int)n, LWS_WRITE_RAW); if (n < 0) { - lwsl_notice("%s: WRITEABLE: %d\n", __func__, n); + lwsl_sspc_notice(h, "WRITEABLE: %d", n); goto hangup; } @@ -574,7 +575,7 @@ do_write: return lws_callback_http_dummy(wsi, reason, user, in, len); metadata_hangup: - lwsl_err("%s: metadata too large\n", __func__); + lwsl_sspc_err(h, "metadata too large"); hangup: lws_free(pkt); @@ -824,8 +825,7 @@ lws_sspc_request_tx_len(lws_sspc_handle_t *h, unsigned long len) if (!h) return LWSSSSRET_OK; - lwsl_notice("%s: setting %s writeable_len %u\n", __func__, h->lc.gutag, - (unsigned int)len); + lwsl_sspc_notice(h, "setting writeable_len %u", (unsigned int)len); h->writeable_len = len; h->pending_writeable_len = 1; @@ -877,7 +877,8 @@ lws_sspc_rideshare(struct lws_sspc_handle *h) */ if (h->parser.rideshare[0]) { - lwsl_info("%s: parser %s\n", __func__, h->parser.rideshare); + lwsl_sspc_info(h, "parser %s", h->parser.rideshare); + return h->parser.rideshare; } @@ -886,7 +887,7 @@ lws_sspc_rideshare(struct lws_sspc_handle *h) */ if (h->rideshare_list[0]) { - lwsl_info("%s: tx list %s\n", __func__, + lwsl_sspc_info(h, "tx list %s", &h->rideshare_list[h->rideshare_ofs[h->rsidx]]); return &h->rideshare_list[h->rideshare_ofs[h->rsidx]]; } @@ -895,7 +896,7 @@ lws_sspc_rideshare(struct lws_sspc_handle *h) * ... otherwise default to our stream type name */ - lwsl_info("%s: def %s\n", __func__, h->ssi.streamtype); + lwsl_sspc_info(h, "def %s\n", h->ssi.streamtype); return h->ssi.streamtype; } @@ -935,7 +936,7 @@ _lws_sspc_set_metadata(struct lws_sspc_handle *h, const char *name, else md = lws_malloc(sizeof(*md) + len, "set metadata"); if (!md) { - lwsl_err("%s: OOM\n", __func__); + lwsl_sspc_err(h, "OOM"); return 1; } @@ -953,10 +954,10 @@ _lws_sspc_set_metadata(struct lws_sspc_handle *h, const char *name, lws_dll2_add_tail(&md->list, &h->metadata_owner); if (len) { - lwsl_info("%s: set metadata %s\n", __func__, name); - lwsl_hexdump_info(value, len); + lwsl_sspc_info(h, "set metadata %s", name); + lwsl_hexdump_sspc_info(h, value, len); } else - lwsl_info("%s: serializing tx cr adj %d\n", __func__, + lwsl_sspc_info(h, "serializing tx cr adj %d", (int)tx_cr_adjust); if (h->cwsi) @@ -1005,7 +1006,7 @@ lws_sspc_get_metadata(struct lws_sspc_handle *h, const char *name, int lws_sspc_add_peer_tx_credit(struct lws_sspc_handle *h, int32_t bump) { - lwsl_notice("%s: %d\n", __func__, bump); + lwsl_sspc_notice(h, "%d\n", bump); return _lws_sspc_set_metadata(h, "", NULL, 0, (int)bump); } diff --git a/lib/secure-streams/secure-streams-serialize.c b/lib/secure-streams/secure-streams-serialize.c index 967ff06e1..241085a55 100644 --- a/lib/secure-streams/secure-streams-serialize.c +++ b/lib/secure-streams/secure-streams-serialize.c @@ -132,7 +132,7 @@ lws_ss_serialize_state_transition(lws_sspc_handle_t *h, lws_ss_conn_states_t *state, int new_state) { #if defined(_DEBUG) - lwsl_info("%s -> %s", sn[*state], sn[new_state]); + lwsl_sspc_info(h, "%s -> %s", sn[*state], sn[new_state]); #endif *state = (lws_ss_conn_states_t)new_state; } @@ -402,7 +402,7 @@ lws_ss_deserialize_parse(struct lws_ss_serialization_parser *par, if (client) goto hangup; par->ps = RPAR_TYPE; - lwsl_notice("%s: DESTROYING\n", __func__); + lwsl_cx_notice(context, "DESTROYING"); goto hangup; case LWSSS_SER_TXPRE_ONWARD_CONNECT: @@ -413,7 +413,7 @@ lws_ss_deserialize_parse(struct lws_ss_serialization_parser *par, goto hangup; par->ps = RPAR_TYPE; - lwsl_notice("%s: ONWARD_CONNECT\n", __func__); + lwsl_cx_notice(context, "ONWARD_CONNECT"); /* * Shrug it off if we are already connecting or @@ -539,8 +539,8 @@ lws_ss_deserialize_parse(struct lws_ss_serialization_parser *par, break; default: - lwsl_notice("%s: bad type 0x%x\n", __func__, - par->type); + lwsl_cx_notice(context, "bad type 0x%x", + par->type); goto hangup; } break; @@ -722,7 +722,7 @@ payload_ff: hss = proxy_pss_to_ss_h(pss); if (hss) - lwsl_info("C2P RX: len %d", (int)n); + lwsl_ss_info(hss, "C2P RX: len %d", (int)n); p = pre; pre[0] = LWSSS_SER_TXPRE_TX_PAYLOAD; @@ -739,7 +739,7 @@ payload_ff: lws_fi(&hss->fic, "ssproxy_dsh_c2p_pay_oom")) || lws_dsh_alloc_tail(dsh, KIND_C_TO_P, pre, 23, cp, (unsigned int)n)) { - lwsl_err("unable to alloc in dsh 3\n"); + lwsl_ss_err(hss, "unable to alloc in dsh 3"); return LWSSSSRET_DISCONNECT_ME; } @@ -754,13 +754,12 @@ payload_ff: * Pass whatever payload we have to ss user */ - lwsl_info("%s: P2C RX: len %d\n", __func__, - (int)n); - h = lws_container_of(par, lws_sspc_handle_t, parser); h->txc.peer_tx_cr_est -= n; + lwsl_sspc_info(h, "P2C RX: len %d", (int)n); + if (ssi->rx && client_pss_to_sspc_h(pss, ssi)) { /* we still have an sspc handle */ int ret; @@ -1155,14 +1154,18 @@ payload_ff: break; /* we think we got all the value */ - if (client) - lwsl_notice("%s: RX METADATA %s\n", __func__, - par->metadata_name); - else { - lwsl_info("%s: RPAR_METADATA_VALUE for %s (len %d)\n", - __func__, par->ssmd->name, - (int)par->ssmd->length); - lwsl_hexdump_info(par->ssmd->value__may_own_heap, par->ssmd->length); + if (client) { + h = lws_container_of(par, lws_sspc_handle_t, parser); + lwsl_sspc_notice(h, "RX METADATA %s", + par->metadata_name); + } else { + lwsl_ss_info(proxy_pss_to_ss_h(pss), + "RPAR_METADATA_VALUE for %s (len %d)", + par->ssmd->name, + (int)par->ssmd->length); + lwsl_hexdump_ss_info(proxy_pss_to_ss_h(pss), + par->ssmd->value__may_own_heap, + par->ssmd->length); } par->ps = RPAR_TYPE; break; @@ -1426,7 +1429,7 @@ payload_ff: break; case LWSSSCS_CONNECTED: - lwsl_info("CONNECTED %s", + lwsl_sspc_info(h, "CONNECTED %s", ssi->streamtype); if (*state == LPCSCLI_OPERATIONAL) /* @@ -1450,8 +1453,8 @@ payload_ff: goto hangup; #if defined(_DEBUG) - lwsl_info("%s: forwarding proxied state %s\n", - __func__, lws_ss_state_name(par->ctr)); + lwsl_sspc_info(h, "forwarding proxied state %s", + lws_ss_state_name(par->ctr)); #endif if (par->ctr == LWSSSCS_CREATING) { @@ -1508,7 +1511,7 @@ swallow: hangup: - lwsl_notice("%s: hangup\n", __func__); + lwsl_cx_notice(context, "hangup"); return LWSSSSRET_DISCONNECT_ME; } diff --git a/lib/secure-streams/secure-streams.c b/lib/secure-streams/secure-streams.c index edd9fe258..d8b4b161b 100644 --- a/lib/secure-streams/secure-streams.c +++ b/lib/secure-streams/secure-streams.c @@ -331,14 +331,14 @@ lws_ss_check_next_state_ss(lws_ss_handle_t *ss, uint8_t *prevstate, if (cs >= LWS_ARRAY_SIZE(ss_state_txn_validity)) { /* we don't recognize this state as usable */ - lwsl_err("bad new state %u", cs); + lwsl_ss_err(ss, "bad new state %u", cs); assert(0); return 1; } if (*prevstate >= LWS_ARRAY_SIZE(ss_state_txn_validity)) { /* existing state is broken */ - lwsl_err("bad existing state %u", + lwsl_ss_err(ss, "bad existing state %u", (unsigned int)*prevstate); assert(0); return 1; @@ -346,7 +346,7 @@ lws_ss_check_next_state_ss(lws_ss_handle_t *ss, uint8_t *prevstate, if (ss_state_txn_validity[*prevstate] & (1u << cs)) { - lwsl_notice("%s -> %s", + lwsl_ss_notice(ss, "%s -> %s", lws_ss_state_name((int)*prevstate), lws_ss_state_name((int)cs)); @@ -356,7 +356,7 @@ lws_ss_check_next_state_ss(lws_ss_handle_t *ss, uint8_t *prevstate, return 0; } - lwsl_err("transition from %s -> %s is illegal", + lwsl_ss_err(ss, "transition from %s -> %s is illegal", lws_ss_state_name((int)*prevstate), lws_ss_state_name((int)cs)); @@ -935,7 +935,7 @@ lws_ss_create(struct lws_context *context, int tsi, const lws_ss_info_t *ssi, pol = lws_ss_policy_lookup(context, ssi->streamtype); #endif if (!pol) { - lwsl_info("%s: unknown stream type %s\n", __func__, + lwsl_cx_info(context, "unknown stream type %s", ssi->streamtype); return 1; } @@ -1056,7 +1056,7 @@ lws_ss_create(struct lws_context *context, int tsi, const lws_ss_info_t *ssi, h->metadata = (lws_ss_metadata_t *)p; p += pol->metadata_count * sizeof(lws_ss_metadata_t); - lwsl_info("%s: %s metadata count %d\n", __func__, + lwsl_cx_info(context, "%s metadata count %d", pol->streamtype, pol->metadata_count); } @@ -1113,7 +1113,7 @@ lws_ss_create(struct lws_context *context, int tsi, const lws_ss_info_t *ssi, lws_smd_ss_cb); if (!h->u.smd.smd_peer) goto late_bail; - lwsl_info("%s: registered SS SMD\n", __func__); + lwsl_cx_info(context, "registered SS SMD"); } #endif @@ -1123,7 +1123,7 @@ lws_ss_create(struct lws_context *context, int tsi, const lws_ss_info_t *ssi, struct lws_context_creation_info i; struct lws_vhost *vho = NULL; - lwsl_info("%s: creating server\n", __func__); + lwsl_cx_info(context, "creating server"); if (h->policy->endpoint && h->policy->endpoint[0] == '!') { @@ -1196,7 +1196,7 @@ lws_ss_create(struct lws_context *context, int tsi, const lws_ss_info_t *ssi, if (!lws_fi(&ssi->fic, "ss_srv_vh_fail")) vho = lws_create_vhost(context, &i); if (!vho) { - lwsl_err("%s: failed to create vh", __func__); + lwsl_cx_err(context, "failed to create vh"); goto late_bail; } @@ -1209,11 +1209,11 @@ extant: vho->ss_handle = h; r = lws_ss_event_helper(h, LWSSSCS_CREATING); - lwsl_info("%s: CREATING returned status %d\n", __func__, (int)r); + lwsl_cx_info(context, "CREATING returned status %d", (int)r); if (r == LWSSSSRET_DESTROY_ME) goto late_bail; - lwsl_notice("%s: created server %s\n", __func__, + lwsl_cx_notice(context, "created server %s", h->policy->streamtype); return 0; @@ -1239,7 +1239,7 @@ extant: #endif r = lws_ss_event_helper(h, LWSSSCS_CREATING); - lwsl_info("%s: CREATING returned status %d\n", __func__, (int)r); + lwsl_ss_info(h, "CREATING returned status %d", (int)r); if (r == LWSSSSRET_DESTROY_ME) { #if defined(LWS_WITH_SERVER) || defined(LWS_WITH_SYS_SMD) diff --git a/lib/secure-streams/system/captive-portal-detect/captive-portal-detect.c b/lib/secure-streams/system/captive-portal-detect/captive-portal-detect.c index 04900f077..37d23adb3 100644 --- a/lib/secure-streams/system/captive-portal-detect/captive-portal-detect.c +++ b/lib/secure-streams/system/captive-portal-detect/captive-portal-detect.c @@ -41,7 +41,7 @@ ss_cpd_state(void *userobj, void *sh, lws_ss_constate_t state, ss_cpd_t *m = (ss_cpd_t *)userobj; struct lws_context *cx = (struct lws_context *)m->opaque_data; - lwsl_info("%s: %s, ord 0x%x\n", __func__, lws_ss_state_name((int)state), + lwsl_ss_info(m->ss, "%s, ord 0x%x\n", lws_ss_state_name((int)state), (unsigned int)ack); switch (state) { @@ -85,12 +85,12 @@ int lws_ss_sys_cpd(struct lws_context *cx) { if (cx->ss_cpd) { - lwsl_notice("%s: CPD already ongoing\n", __func__); + lwsl_cx_notice(cx, "CPD already ongoing"); return 0; } if (lws_ss_create(cx, 0, &ssi_cpd, cx, &cx->ss_cpd, NULL, NULL)) { - lwsl_info("%s: Create stream failed (policy?)\n", __func__); + lwsl_cx_info(cx, "Create stream failed (policy?)"); return 1; } diff --git a/lib/system/smd/smd.c b/lib/system/smd/smd.c index 241d60828..c5aea5187 100644 --- a/lib/system/smd/smd.c +++ b/lib/system/smd/smd.c @@ -43,8 +43,8 @@ lws_smd_msg_alloc(struct lws_context *ctx, lws_smd_class_t _class, size_t len) /* only allow it if someone wants to consume this class of event */ if (!(ctx->smd._class_filter & _class)) { - lwsl_info("%s: rejecting class 0x%x as no participant wants it\n", - __func__, (unsigned int)_class); + lwsl_cx_info(ctx, "rejecting class 0x%x as no participant wants", + (unsigned int)_class); return NULL; } @@ -171,9 +171,8 @@ _lws_smd_msg_destroy(struct lws_context *cx, lws_smd_t *smd, lws_smd_msg_t *msg) lws_smd_peer_t *xpr = lws_container_of(p, lws_smd_peer_t, list); if (xpr->tail == msg) { - lwsl_err("%s: peer %p has msg %p " - "we are about to destroy as tail\n", - __func__, xpr, msg); + lwsl_cx_err(cx, "peer %p has msg %p " + "we are about to destroy as tail", xpr, msg); #if !defined(LWS_PLAT_FREERTOS) assert(0); #endif @@ -185,7 +184,7 @@ _lws_smd_msg_destroy(struct lws_context *cx, lws_smd_t *smd, lws_smd_msg_t *msg) * We have fully delivered the message now, it * can be unlinked and destroyed */ - lwsl_info("%s: destroy msg %p\n", __func__, msg); + lwsl_cx_info(cx, "destroy msg %p", msg); lws_dll2_remove(&msg->list); lws_free(msg); } @@ -201,8 +200,8 @@ _lws_smd_msg_send(struct lws_context *ctx, void *pay, struct lws_smd_peer *exc) LWS_SMD_SS_RX_HEADER_LEN_EFF - sizeof(*msg)); if (ctx->smd.owner_messages.count >= ctx->smd_queue_depth) { - lwsl_warn("%s: rejecting message on queue depth %d\n", - __func__, (int)ctx->smd.owner_messages.count); + lwsl_cx_warn(ctx, "rejecting message on queue depth %d", + (int)ctx->smd.owner_messages.count); /* reject the message due to max queue depth reached */ return 1; } @@ -528,8 +527,8 @@ _lws_smd_msg_deliver_peer(struct lws_context *ctx, lws_smd_peer_t *pr) msg = lws_container_of(pr->tail, lws_smd_msg_t, list); - lwsl_smd("%s: deliver cl 0x%x, len %d, refc %d, to peer %p\n", - __func__, (unsigned int)msg->_class, (int)msg->length, + lwsl_cx_info(ctx, "deliver cl 0x%x, len %d, refc %d, to peer %p", + (unsigned int)msg->_class, (int)msg->length, (int)msg->refcount, pr); pr->cb(pr->opaque, msg->_class, msg->timestamp, @@ -640,7 +639,7 @@ lws_smd_register(struct lws_context *ctx, void *opaque, int flags, lws_mutex_unlock(ctx->smd.lock_messages); /* messages ------- */ - lwsl_info("%s: peer %p (count %u) registered\n", __func__, pr, + lwsl_cx_info(ctx, "peer %p (count %u) registered", pr, (unsigned int)ctx->smd.owner_peers.count); if (!ctx->smd.delivering) @@ -655,7 +654,7 @@ lws_smd_unregister(struct lws_smd_peer *pr) lws_smd_t *smd = lws_container_of(pr->list.owner, lws_smd_t, owner_peers); lws_mutex_lock(smd->lock_peers); /* +++++++++++++++++++++++++++ peers */ - lwsl_notice("%s: destroying peer %p\n", __func__, pr); + lwsl_cx_notice(pr->ctx, "destroying peer %p", pr); _lws_smd_peer_destroy(pr); lws_mutex_unlock(smd->lock_peers); /* ------------------------- peers */ } @@ -686,8 +685,8 @@ lws_smd_message_pending(struct lws_context *ctx) lws_smd_msg_t *msg = lws_container_of(p, lws_smd_msg_t, list); if ((lws_now_usecs() - msg->timestamp) > ctx->smd_ttl_us) { - lwsl_warn("%s: timing out queued message %p\n", - __func__, msg); + lwsl_cx_warn(ctx, "timing out queued message %p", + msg); /* * We're forcibly yanking this guy, we can expect that diff --git a/lib/tls/openssl/openssl-tls.c b/lib/tls/openssl/openssl-tls.c index a387e9d25..bdefd12c2 100644 --- a/lib/tls/openssl/openssl-tls.c +++ b/lib/tls/openssl/openssl-tls.c @@ -124,26 +124,26 @@ lws_context_init_ssl_library(struct lws_context *cx, { #ifdef USE_WOLFSSL #ifdef USE_OLD_CYASSL - lwsl_info(" Compiled with CyaSSL support\n"); + lwsl_cx_info(cx, " Compiled with CyaSSL support"); #else - lwsl_info(" Compiled with wolfSSL support\n"); + lwsl_cx_info(cx, " Compiled with wolfSSL support"); #endif #else #if defined(LWS_WITH_BORINGSSL) - lwsl_info(" Compiled with BoringSSL support\n"); + lwsl_cx_info(cx, " Compiled with BoringSSL support"); #else - lwsl_info(" Compiled with OpenSSL support\n"); + lwsl_cx_info(cx, " Compiled with OpenSSL support"); #endif #endif if (!lws_check_opt(info->options, LWS_SERVER_OPTION_DO_SSL_GLOBAL_INIT)) { - lwsl_info(" SSL disabled: no " - "LWS_SERVER_OPTION_DO_SSL_GLOBAL_INIT\n"); + lwsl_cx_info(cx, " SSL disabled: no " + "LWS_SERVER_OPTION_DO_SSL_GLOBAL_INIT"); return 0; } /* basic openssl init */ - lwsl_info("Doing SSL library init\n"); + lwsl_cx_info(cx, "Doing SSL library init"); #if OPENSSL_VERSION_NUMBER < 0x10100000L SSL_library_init(); diff --git a/plugins/protocol_lws_openmetrics_export.c b/plugins/protocol_lws_openmetrics_export.c index ba79fef33..0fe216ada 100644 --- a/plugins/protocol_lws_openmetrics_export.c +++ b/plugins/protocol_lws_openmetrics_export.c @@ -626,7 +626,7 @@ callback_lws_openmetrics_prox_agg(struct lws *wsi, } } else { lwsl_warn("%s: proxy-side-bind-name required\n", __func__); - return 1; + return 0; } break; @@ -802,7 +802,7 @@ callback_lws_openmetrics_prox_server(struct lws *wsi, } } else { lwsl_warn("%s: proxy-side-bind-name required\n", __func__); - return 1; + return 0; } break; @@ -972,9 +972,9 @@ callback_lws_openmetrics_prox_client(struct lws *wsi, /* the proxy server uri */ if (lws_pvo_get_str(in, "ws-server-uri", &cp)) { - lwsl_err("%s: ws-server-uri pvo required\n", __func__); + lwsl_warn("%s: ws-server-uri pvo required\n", __func__); - return 1; + return 0; } lws_strncpy(vhd->ws_server_uri, cp, sizeof(vhd->ws_server_uri)); diff --git a/plugins/raw-proxy/protocol_lws_raw_proxy.c b/plugins/raw-proxy/protocol_lws_raw_proxy.c index c0b1ceaa5..91d676d10 100644 --- a/plugins/raw-proxy/protocol_lws_raw_proxy.c +++ b/plugins/raw-proxy/protocol_lws_raw_proxy.c @@ -194,10 +194,10 @@ callback_raw_proxy(struct lws *wsi, enum lws_callback_reasons reason, if (!vhd) return 0; if (lws_pvo_get_str(in, "onward", &cp)) { - lwsl_err("%s: vh %s: pvo 'onward' required\n", __func__, + lwsl_warn("%s: vh %s: pvo 'onward' required\n", __func__, lws_get_vhost_name(lws_get_vhost(wsi))); - return -1; + return 0; } lws_tokenize_init(&ts, cp, LWS_TOKENIZE_F_DOT_NONTERM | LWS_TOKENIZE_F_MINUS_NONTERM |