This is an automated email from the ASF dual-hosted git repository. zwoop pushed a commit to branch master in repository https://gitbox.apache.org/repos/asf/trafficserver.git
The following commit(s) were added to refs/heads/master by this push: new 4ba6a7fb2d Remove obsolete debug output calls in 18 source files. (#11307) 4ba6a7fb2d is described below commit 4ba6a7fb2d7cef58a44fec247e5dcabec1e42622 Author: Walt Karas <wka...@yahooinc.com> AuthorDate: Tue May 14 16:33:21 2024 -0400 Remove obsolete debug output calls in 18 source files. (#11307) In the src/proxy tree. --- src/proxy/CacheControl.cc | 24 +++++++++----- src/proxy/FetchSM.cc | 42 +++++++++++++---------- src/proxy/HostStatus.cc | 49 +++++++++++++++------------ src/proxy/ParentSelectionStrategy.cc | 12 +++++-- src/proxy/ProtocolProbeSessionAccept.cc | 35 ++++++++++++-------- src/proxy/ReverseProxy.cc | 15 ++++++--- src/proxy/Transform.cc | 57 ++++++++++++++++++-------------- src/proxy/http3/Http09App.cc | 15 ++++++--- src/proxy/http3/Http3App.cc | 29 ++++++++++------ src/proxy/http3/Http3Frame.cc | 8 ++++- src/proxy/http3/Http3FrameCollector.cc | 8 ++++- src/proxy/http3/Http3FrameDispatcher.cc | 17 +++++++--- src/proxy/http3/Http3HeaderFramer.cc | 8 ++++- src/proxy/http3/Http3HeaderVIOAdaptor.cc | 19 +++++++---- src/proxy/http3/Http3SessionAccept.cc | 18 ++++++---- src/proxy/http3/Http3SettingsHandler.cc | 14 +++++--- src/proxy/http3/Http3Transaction.cc | 21 ++++++++---- src/proxy/http3/QPACK.cc | 10 ++++-- 18 files changed, 259 insertions(+), 142 deletions(-) diff --git a/src/proxy/CacheControl.cc b/src/proxy/CacheControl.cc index 844aed2aeb..a539b560cb 100644 --- a/src/proxy/CacheControl.cc +++ b/src/proxy/CacheControl.cc @@ -41,11 +41,13 @@ #include "../iocore/cache/P_Cache.h" #include "tsutil/Regex.h" -static const char modulePrefix[] = "[CacheControl]"; +namespace +{ +const char modulePrefix[] = "[CacheControl]"; #define TWEAK_CACHE_RESPONSES_TO_COOKIES "cache-responses-to-cookies" -static const char *CC_directive_str[CC_NUM_TYPES] = { +const char *CC_directive_str[CC_NUM_TYPES] = { "INVALID", "REVALIDATE_AFTER", "NEVER_CACHE", @@ -58,11 +60,17 @@ static const char *CC_directive_str[CC_NUM_TYPES] = { // "CACHE_AUTH_CONTENT" }; -using CC_table = ControlMatcher<CacheControlRecord, CacheControlResult>; +Ptr<ProxyMutex> reconfig_mutex; + +DbgCtl dbg_ctl_v_http3{"v_http3"}; +DbgCtl dbg_ctl_http3{"http3"}; +DbgCtl dbg_ctl_cache_control{"cache_control"}; + +} // end anonymous namespace // Global Ptrs -static Ptr<ProxyMutex> reconfig_mutex; -CC_table *CacheControlTable = nullptr; +using CC_table = ControlMatcher<CacheControlRecord, CacheControlResult>; +CC_table *CacheControlTable = nullptr; // struct CC_FreerContinuation // Continuation to free old cache control lists after @@ -75,7 +83,7 @@ struct CC_FreerContinuation : public Continuation { int freeEvent(int /* event ATS_UNUSED */, Event * /* e ATS_UNUSED */) { - Debug("cache_control", "Deleting old table"); + Dbg(dbg_ctl_cache_control, "Deleting old table"); delete p; delete this; return EVENT_DONE; @@ -144,7 +152,7 @@ reloadCacheControl() CC_table *newTable; - Debug("cache_control", "%s updated, reloading", ts::filename::CACHE); + Dbg(dbg_ctl_cache_control, "%s updated, reloading", ts::filename::CACHE); eventProcessor.schedule_in(new CC_FreerContinuation(CacheControlTable), CACHE_CONTROL_TIMEOUT, ET_CALL); newTable = new CC_table("proxy.config.cache.control.filename", modulePrefix, &http_dest_tags); ink_atomic_swap(&CacheControlTable, newTable); @@ -437,6 +445,6 @@ CacheControlRecord::UpdateMatch(CacheControlResult *result, RequestData *rdata) crtc_debug[0] = 0; } - Debug("cache_control", "Matched with for %s at line %d%s", CC_directive_str[this->directive], this->line_num, crtc_debug); + Dbg(dbg_ctl_cache_control, "Matched with for %s at line %d%s", CC_directive_str[this->directive], this->line_num, crtc_debug); } } diff --git a/src/proxy/FetchSM.cc b/src/proxy/FetchSM.cc index 22ad8e72a5..09d8e96d0d 100644 --- a/src/proxy/FetchSM.cc +++ b/src/proxy/FetchSM.cc @@ -33,13 +33,19 @@ ClassAllocator<FetchSM> FetchSMAllocator("FetchSMAllocator"); +namespace +{ +DbgCtl dbg_ctl{DEBUG_TAG}; + +} // end anonymous namespace + void FetchSM::cleanUp() { - Debug(DEBUG_TAG, "[%s] calling cleanup", __FUNCTION__); + Dbg(dbg_ctl, "[%s] calling cleanup", __FUNCTION__); if (!ink_atomic_cas(&destroyed, false, true)) { - Debug(DEBUG_TAG, "Error: Double delete on FetchSM, this:%p", this); + Dbg(dbg_ctl, "Error: Double delete on FetchSM, this:%p", this); return; } @@ -67,7 +73,7 @@ FetchSM::httpConnect() const char *tag = pi ? pi->getPluginTag() : "fetchSM"; int64_t id = pi ? pi->getPluginId() : 0; - Debug(DEBUG_TAG, "[%s] calling httpconnect write pi=%p tag=%s id=%" PRId64, __FUNCTION__, pi, tag, id); + Dbg(dbg_ctl, "[%s] calling httpconnect write pi=%p tag=%s id=%" PRId64, __FUNCTION__, pi, tag, id); TSHttpConnectOptions options{.connect_type = TS_CONNECT_PLUGIN, .addr = &_addr.sa, .tag = tag, @@ -76,7 +82,7 @@ FetchSM::httpConnect() .buffer_water_mark = TS_IOBUFFER_WATER_MARK_PLUGIN_VC_DEFAULT}; http_vc = PluginHttpConnectInternal(&options); if (http_vc == nullptr) { - Debug(DEBUG_TAG, "Not ready to use"); + Dbg(dbg_ctl, "Not ready to use"); if (contp) { if (fetch_flags & TS_FETCH_FLAGS_STREAM) { return InvokePluginExt(TS_EVENT_ERROR); @@ -199,8 +205,8 @@ FetchSM::check_for_field_value(const char *name, size_t name_len, char const *va if (ret) { for (Str *f = slist.head; f != nullptr; f = f->next) { if (f->len == value_len && 0 == strncasecmp(f->str, value, value_len)) { - Debug(DEBUG_TAG, "[%s] field '%.*s', value '%.*s'", __FUNCTION__, static_cast<int>(name_len), name, - static_cast<int>(value_len), value); + Dbg(dbg_ctl, "[%s] field '%.*s', value '%.*s'", __FUNCTION__, static_cast<int>(name_len), name, static_cast<int>(value_len), + value); zret = true; break; } @@ -316,9 +322,9 @@ FetchSM::InvokePluginExt(int fetch_event) goto out; } - Debug(DEBUG_TAG, "[%s] chunked:%d, content_len: %" PRId64 ", received_len: %" PRId64 ", avail: %" PRId64 "", __FUNCTION__, - resp_is_chunked, resp_content_length, resp_received_body_len, - resp_is_chunked > 0 ? chunked_handler.chunked_reader->read_avail() : resp_reader->read_avail()); + Dbg(dbg_ctl, "[%s] chunked:%d, content_len: %" PRId64 ", received_len: %" PRId64 ", avail: %" PRId64 "", __FUNCTION__, + resp_is_chunked, resp_content_length, resp_received_body_len, + resp_is_chunked > 0 ? chunked_handler.chunked_reader->read_avail() : resp_reader->read_avail()); if (resp_is_chunked > 0) { if (!chunked_handler.chunked_reader->read_avail()) { @@ -396,7 +402,7 @@ FetchSM::get_info_from_buffer(IOBufferReader *reader) reader->skip_empty_blocks(); read_avail = reader->read_avail(); - Debug(DEBUG_TAG, "[%s] total avail %" PRId64, __FUNCTION__, read_avail); + Dbg(dbg_ctl, "[%s] total avail %" PRId64, __FUNCTION__, read_avail); if (!read_avail) { client_bytes = 0; return; @@ -494,7 +500,7 @@ FetchSM::get_info_from_buffer(IOBufferReader *reader) void FetchSM::process_fetch_read(int event) { - Debug(DEBUG_TAG, "[%s] I am here read", __FUNCTION__); + Dbg(dbg_ctl, "[%s] I am here read", __FUNCTION__); int64_t bytes; int bytes_used; int64_t total_bytes_copied = 0; @@ -504,18 +510,18 @@ FetchSM::process_fetch_read(int event) // duplicate the bytes for backward compatibility with TSFetchUrl() if (!(fetch_flags & TS_FETCH_FLAGS_STREAM)) { bytes = resp_reader->read_avail(); - Debug(DEBUG_TAG, "[%s] number of bytes in read ready %" PRId64, __FUNCTION__, bytes); + Dbg(dbg_ctl, "[%s] number of bytes in read ready %" PRId64, __FUNCTION__, bytes); while (total_bytes_copied < bytes) { int64_t actual_bytes_copied; actual_bytes_copied = resp_buffer->write(resp_reader, bytes, 0); - Debug(DEBUG_TAG, "[%s] copied %" PRId64 " bytes", __FUNCTION__, actual_bytes_copied); + Dbg(dbg_ctl, "[%s] copied %" PRId64 " bytes", __FUNCTION__, actual_bytes_copied); if (actual_bytes_copied <= 0) { break; } total_bytes_copied += actual_bytes_copied; } - Debug(DEBUG_TAG, "[%s] total copied %" PRId64 " bytes", __FUNCTION__, total_bytes_copied); + Dbg(dbg_ctl, "[%s] total copied %" PRId64 " bytes", __FUNCTION__, total_bytes_copied); resp_reader->consume(total_bytes_copied); } @@ -544,7 +550,7 @@ FetchSM::process_fetch_read(int event) get_info_from_buffer(resp_reader); InvokePlugin(callback_events.success_event_id, (void *)this); } - Debug(DEBUG_TAG, "[%s] received EOS", __FUNCTION__); + Dbg(dbg_ctl, "[%s] received EOS", __FUNCTION__); cleanUp(); break; case TS_EVENT_ERROR: @@ -561,7 +567,7 @@ FetchSM::process_fetch_read(int event) void FetchSM::process_fetch_write(int event) { - Debug(DEBUG_TAG, "[%s] calling process write", __FUNCTION__); + Dbg(dbg_ctl, "[%s] calling process write", __FUNCTION__); switch (event) { case TS_EVENT_VCONN_WRITE_COMPLETE: req_finished = true; @@ -589,7 +595,7 @@ FetchSM::process_fetch_write(int event) int FetchSM::fetch_handler(int event, void *edata) { - Debug(DEBUG_TAG, "[%s] calling fetch_plugin", __FUNCTION__); + Dbg(dbg_ctl, "[%s] calling fetch_plugin", __FUNCTION__); if (edata == read_vio) { process_fetch_read(event); @@ -681,7 +687,7 @@ FetchSM::ext_write_data(const void *data, size_t len) } req_buffer->write(data, len); - Debug(DEBUG_TAG, "[%s] re-enabling write_vio, header_done %u", __FUNCTION__, header_done); + Dbg(dbg_ctl, "[%s] re-enabling write_vio, header_done %u", __FUNCTION__, header_done); write_vio->reenable(); if (fetch_flags & TS_FETCH_FLAGS_NEWLOCK) { diff --git a/src/proxy/HostStatus.cc b/src/proxy/HostStatus.cc index b1e0bb3463..31406b1e09 100644 --- a/src/proxy/HostStatus.cc +++ b/src/proxy/HostStatus.cc @@ -42,6 +42,8 @@ struct HostCmdInfo { int time{0}; }; +DbgCtl dbg_ctl_host_statuses{"host_statuses"}; + } // namespace swoc::Rv<YAML::Node> server_get_status(std::string_view const id, YAML::Node const ¶ms); @@ -182,7 +184,7 @@ void HostStatus::loadRecord(std::string_view name, HostStatRec &h) { HostStatRec *host_stat = nullptr; - Debug("host_statuses", "loading host status record for %.*s", int(name.size()), name.data()); + Dbg(dbg_ctl_host_statuses, "loading host status record for %.*s", int(name.size()), name.data()); ink_rwlock_wrlock(&host_status_rwlock); { auto it = hosts_statuses.find(std::string(name)); @@ -213,7 +215,8 @@ HostStatus::setHostStatus(const std::string_view name, TSHostStatus status, cons hosts_statuses.emplace(name, host_stat); } if (reason & Reason::ACTIVE) { - Debug("host_statuses", "for host %.*s set status: %s, Reason:ACTIVE", int(name.size()), name.data(), HostStatusNames[status]); + Dbg(dbg_ctl_host_statuses, "for host %.*s set status: %s, Reason:ACTIVE", int(name.size()), name.data(), + HostStatusNames[status]); if (status == TSHostStatus::TS_HOST_STATUS_DOWN) { host_stat->active_marked_down = time(0); host_stat->active_down_time = down_time; @@ -227,7 +230,8 @@ HostStatus::setHostStatus(const std::string_view name, TSHostStatus status, cons } } if (reason & Reason::LOCAL) { - Debug("host_statuses", "for host %.*s set status: %s, Reason:LOCAL", int(name.size()), name.data(), HostStatusNames[status]); + Dbg(dbg_ctl_host_statuses, "for host %.*s set status: %s, Reason:LOCAL", int(name.size()), name.data(), + HostStatusNames[status]); if (status == TSHostStatus::TS_HOST_STATUS_DOWN) { host_stat->local_marked_down = time(0); host_stat->local_down_time = down_time; @@ -241,7 +245,8 @@ HostStatus::setHostStatus(const std::string_view name, TSHostStatus status, cons } } if (reason & Reason::MANUAL) { - Debug("host_statuses", "for host %.*s set status: %s, Reason:MANUAL", int(name.size()), name.data(), HostStatusNames[status]); + Dbg(dbg_ctl_host_statuses, "for host %.*s set status: %s, Reason:MANUAL", int(name.size()), name.data(), + HostStatusNames[status]); if (status == TSHostStatus::TS_HOST_STATUS_DOWN) { host_stat->manual_marked_down = time(0); host_stat->manual_down_time = down_time; @@ -255,8 +260,8 @@ HostStatus::setHostStatus(const std::string_view name, TSHostStatus status, cons } } if (reason & Reason::SELF_DETECT) { - Debug("host_statuses", "for host %.*s set status: %s, Reason:SELF_DETECT", int(name.size()), name.data(), - HostStatusNames[status]); + Dbg(dbg_ctl_host_statuses, "for host %.*s set status: %s, Reason:SELF_DETECT", int(name.size()), name.data(), + HostStatusNames[status]); if (status == TSHostStatus::TS_HOST_STATUS_DOWN) { host_stat->self_detect_marked_down = time(0); host_stat->reasons |= Reason::SELF_DETECT; @@ -271,10 +276,10 @@ HostStatus::setHostStatus(const std::string_view name, TSHostStatus status, cons if (host_stat->reasons == 0) { host_stat->status = TSHostStatus::TS_HOST_STATUS_UP; } - Debug("host_statuses", "reasons: %d, status: %s", host_stat->reasons, HostStatusNames[host_stat->status]); + Dbg(dbg_ctl_host_statuses, "reasons: %d, status: %s", host_stat->reasons, HostStatusNames[host_stat->status]); } else { host_stat->status = status; - Debug("host_statuses", "reasons: %d, status: %s", host_stat->reasons, HostStatusNames[host_stat->status]); + Dbg(dbg_ctl_host_statuses, "reasons: %d, status: %s", host_stat->reasons, HostStatusNames[host_stat->status]); } } ink_rwlock_unlock(&host_status_rwlock); @@ -343,24 +348,24 @@ HostStatus::getHostStatus(const std::string_view name) unsigned int reasons = _status->reasons; if ((_status->reasons & Reason::ACTIVE) && _status->active_down_time > 0) { if ((_status->active_down_time + _status->active_marked_down) < now) { - Debug("host_statuses", "name: %.*s, now: %ld, down_time: %d, marked_down: %ld, reason: %s", int(name.size()), name.data(), - now, _status->active_down_time, _status->active_marked_down, Reason::ACTIVE_REASON); + Dbg(dbg_ctl_host_statuses, "name: %.*s, now: %ld, down_time: %d, marked_down: %ld, reason: %s", int(name.size()), + name.data(), now, _status->active_down_time, _status->active_marked_down, Reason::ACTIVE_REASON); setHostStatus(name, TSHostStatus::TS_HOST_STATUS_UP, 0, Reason::ACTIVE); reasons ^= Reason::ACTIVE; } } if ((_status->reasons & Reason::LOCAL) && _status->local_down_time > 0) { if ((_status->local_down_time + _status->local_marked_down) < now) { - Debug("host_statuses", "name: %.*s, now: %ld, down_time: %d, marked_down: %ld, reason: %s", int(name.size()), name.data(), - now, _status->local_down_time, _status->local_marked_down, Reason::LOCAL_REASON); + Dbg(dbg_ctl_host_statuses, "name: %.*s, now: %ld, down_time: %d, marked_down: %ld, reason: %s", int(name.size()), + name.data(), now, _status->local_down_time, _status->local_marked_down, Reason::LOCAL_REASON); setHostStatus(name, TSHostStatus::TS_HOST_STATUS_UP, 0, Reason::LOCAL); reasons ^= Reason::LOCAL; } } if ((_status->reasons & Reason::MANUAL) && _status->manual_down_time > 0) { if ((_status->manual_down_time + _status->manual_marked_down) < now) { - Debug("host_statuses", "name: %.*s, now: %ld, down_time: %d, marked_down: %ld, reason: %s", int(name.size()), name.data(), - now, _status->manual_down_time, _status->manual_marked_down, Reason::MANUAL_REASON); + Dbg(dbg_ctl_host_statuses, "name: %.*s, now: %ld, down_time: %d, marked_down: %ld, reason: %s", int(name.size()), + name.data(), now, _status->manual_down_time, _status->manual_marked_down, Reason::MANUAL_REASON); setHostStatus(name, TSHostStatus::TS_HOST_STATUS_UP, 0, Reason::MANUAL); reasons ^= Reason::MANUAL; } @@ -435,7 +440,7 @@ server_get_status(std::string_view id, YAML::Node const ¶ms) HostStatus &hs = HostStatus::instance(); host_rec = hs.getHostStatus(name); if (host_rec == nullptr) { - Debug("host_statuses", "no record for %s was found", name.c_str()); + Dbg(dbg_ctl_host_statuses, "no record for %s was found", name.c_str()); errorList.push_back("no record for " + name + " was found"); continue; } else { @@ -444,7 +449,7 @@ server_get_status(std::string_view id, YAML::Node const ¶ms) host[HOST_NAME_KEY] = name; host[STATUS_KEY] = s.str(); statusList.push_back(host); - Debug("host_statuses", "hostname: %s, status: %s", name.c_str(), s.str().c_str()); + Dbg(dbg_ctl_host_statuses, "hostname: %s, status: %s", name.c_str(), s.str().c_str()); } } } else { // return all host statuses. @@ -459,7 +464,7 @@ server_get_status(std::string_view id, YAML::Node const ¶ms) } } } catch (std::exception const &ex) { - Debug("host_statuses", "Got an error decoding the parameters: %s", ex.what()); + Dbg(dbg_ctl_host_statuses, "Got an error decoding the parameters: %s", ex.what()); errorList.push_back("Error decoding parameters : " + std::string(ex.what())); } @@ -473,7 +478,7 @@ server_get_status(std::string_view id, YAML::Node const ¶ms) swoc::Rv<YAML::Node> server_set_status(std::string_view id, YAML::Node const ¶ms) { - Debug("host_statuses", "id=%s", id.data()); + Dbg(dbg_ctl_host_statuses, "id=%s", id.data()); namespace err = rpc::handlers::errors; swoc::Rv<YAML::Node> resp; @@ -484,8 +489,8 @@ server_set_status(std::string_view id, YAML::Node const ¶ms) for (auto const &name : cmdInfo.hosts) { HostStatus &hs = HostStatus::instance(); std::string statName = stat_prefix + name; - Debug("host_statuses", "marking server %s : %s", name.c_str(), - (cmdInfo.type == TSHostStatus::TS_HOST_STATUS_UP ? "up" : "down")); + Dbg(dbg_ctl_host_statuses, "marking server %s : %s", name.c_str(), + (cmdInfo.type == TSHostStatus::TS_HOST_STATUS_UP ? "up" : "down")); hs.setHostStatus(name.c_str(), cmdInfo.type, cmdInfo.time, cmdInfo.reasonType); } } else { @@ -493,10 +498,10 @@ server_set_status(std::string_view id, YAML::Node const ¶ms) } // schedule a write to the persistent store. - Debug("host_statuses", "updating persistent store"); + Dbg(dbg_ctl_host_statuses, "updating persistent store"); eventProcessor.schedule_imm(HostStatusSync::new_instance(), ET_TASK); } catch (std::exception const &ex) { - Debug("host_statuses", "Got an error HostCmdInfo decoding: %s", ex.what()); + Dbg(dbg_ctl_host_statuses, "Got an error HostCmdInfo decoding: %s", ex.what()); resp.errata() .assign(std::error_code{rpc::handlers::errors::Codes::SERVER}) .note("Error found during host status set: {}", ex.what()); diff --git a/src/proxy/ParentSelectionStrategy.cc b/src/proxy/ParentSelectionStrategy.cc index d105d0cf01..2bc532bef9 100644 --- a/src/proxy/ParentSelectionStrategy.cc +++ b/src/proxy/ParentSelectionStrategy.cc @@ -23,6 +23,12 @@ #include "proxy/ParentSelection.h" +namespace +{ +DbgCtl dbg_ctl_parent_select{"parent_select"}; + +} // end anonymous namespace + void ParentSelectionStrategy::markParentDown(ParentResult *result, unsigned int fail_threshold, unsigned int retry_time) { @@ -83,7 +89,7 @@ ParentSelectionStrategy::markParentDown(ParentResult *result, unsigned int fail_ old_count = pRec->failCount.fetch_add(1, std::memory_order_relaxed); } - Debug("parent_select", "Parent fail count increased to %d for %s:%d", old_count + 1, pRec->hostname, pRec->port); + Dbg(dbg_ctl_parent_select, "Parent fail count increased to %d for %s:%d", old_count + 1, pRec->hostname, pRec->port); new_fail_count = old_count + 1; } @@ -91,8 +97,8 @@ ParentSelectionStrategy::markParentDown(ParentResult *result, unsigned int fail_ Note("Failure threshold met failcount:%d >= threshold:%d, http parent proxy %s:%d marked down with request: %s", new_fail_count, fail_threshold, pRec->hostname, pRec->port, result->url); pRec->available = false; - Debug("parent_select", "Parent %s:%d marked unavailable, pRec->available=%d", pRec->hostname, pRec->port, - pRec->available.load()); + Dbg(dbg_ctl_parent_select, "Parent %s:%d marked unavailable, pRec->available=%d", pRec->hostname, pRec->port, + pRec->available.load()); } } diff --git a/src/proxy/ProtocolProbeSessionAccept.cc b/src/proxy/ProtocolProbeSessionAccept.cc index 6da06ec578..66fe9f624f 100644 --- a/src/proxy/ProtocolProbeSessionAccept.cc +++ b/src/proxy/ProtocolProbeSessionAccept.cc @@ -29,7 +29,9 @@ #include "iocore/net/NetVConnection.h" #include "proxy/http/HttpConfig.h" -static bool +namespace +{ +bool proto_is_http2(IOBufferReader *reader) { char buf[HTTP2_CONNECTION_PREFACE_LEN]; @@ -48,6 +50,11 @@ proto_is_http2(IOBufferReader *reader) return memcmp(HTTP2_CONNECTION_PREFACE, buf, nbytes) == 0; } +DbgCtl dbg_ctl_proxyprotocol{"proxyprotocol"}; +DbgCtl dbg_ctl_http{"http"}; + +} // end anonymous namespace + struct ProtocolProbeTrampoline : public Continuation, public ProtocolProbeSessionAcceptEnums { static const size_t minimum_read_size = 1; static const unsigned buffer_size_index = BUFFER_SIZE_INDEX_4K; @@ -103,28 +110,28 @@ struct ProtocolProbeTrampoline : public Continuation, public ProtocolProbeSessio pp_ipmap = probeParent->proxy_protocol_ipmap; if (netvc->get_is_proxy_protocol() && netvc->get_proxy_protocol_version() == ProxyProtocolVersion::UNDEFINED) { - Debug("proxyprotocol", "ioCompletionEvent: proxy protocol is enabled on this port"); + Dbg(dbg_ctl_proxyprotocol, "ioCompletionEvent: proxy protocol is enabled on this port"); if (pp_ipmap->count() > 0) { - Debug("proxyprotocol", "ioCompletionEvent: proxy protocol has a configured allowlist of trusted IPs - checking"); + Dbg(dbg_ctl_proxyprotocol, "ioCompletionEvent: proxy protocol has a configured allowlist of trusted IPs - checking"); if (!pp_ipmap->contains(swoc::IPAddr(netvc->get_remote_addr()))) { - Debug("proxyprotocol", - "ioCompletionEvent: Source IP is NOT in the configured allowlist of trusted IPs - closing connection"); + Dbg(dbg_ctl_proxyprotocol, + "ioCompletionEvent: Source IP is NOT in the configured allowlist of trusted IPs - closing connection"); goto done; } else { char new_host[INET6_ADDRSTRLEN]; - Debug("proxyprotocol", "ioCompletionEvent: Source IP [%s] is trusted in the allowlist for proxy protocol", - ats_ip_ntop(netvc->get_remote_addr(), new_host, sizeof(new_host))); + Dbg(dbg_ctl_proxyprotocol, "ioCompletionEvent: Source IP [%s] is trusted in the allowlist for proxy protocol", + ats_ip_ntop(netvc->get_remote_addr(), new_host, sizeof(new_host))); } } else { - Debug("proxyprotocol", - "ioCompletionEvent: proxy protocol DOES NOT have a configured allowlist of trusted IPs but proxy protocol is " - "ernabled on this port - processing all connections"); + Dbg(dbg_ctl_proxyprotocol, + "ioCompletionEvent: proxy protocol DOES NOT have a configured allowlist of trusted IPs but proxy protocol is " + "ernabled on this port - processing all connections"); } if (netvc->has_proxy_protocol(reader)) { - Debug("proxyprotocol", "ioCompletionEvent: http has proxy protocol header"); + Dbg(dbg_ctl_proxyprotocol, "ioCompletionEvent: http has proxy protocol header"); } else { - Debug("proxyprotocol", "ioCompletionEvent: proxy protocol was enabled, but Proxy Protocol header was not present"); + Dbg(dbg_ctl_proxyprotocol, "ioCompletionEvent: proxy protocol was enabled, but Proxy Protocol header was not present"); } } // end of Proxy Protocol processing @@ -186,11 +193,11 @@ ProtocolProbeSessionAccept::mainEvent(int event, void *data) HttpConfig::release(param); if (!probe->reader->is_read_avail_more_than(0)) { - Debug("http", "probe needs data, read.."); + Dbg(dbg_ctl_http, "probe needs data, read.."); vio = netvc->do_io_read(probe, BUFFER_SIZE_FOR_INDEX(ProtocolProbeTrampoline::buffer_size_index), probe->iobuf); vio->reenable(); } else { - Debug("http", "probe already has data, call ioComplete directly.."); + Dbg(dbg_ctl_http, "probe already has data, call ioComplete directly.."); vio = netvc->do_io_read(this, 0, nullptr); probe->ioCompletionEvent(VC_EVENT_READ_COMPLETE, (void *)vio); } diff --git a/src/proxy/ReverseProxy.cc b/src/proxy/ReverseProxy.cc index 85a917809b..796e7eca66 100644 --- a/src/proxy/ReverseProxy.cc +++ b/src/proxy/ReverseProxy.cc @@ -42,8 +42,15 @@ #include "proxy/http/remap/UrlRewrite.h" #include "proxy/http/remap/UrlMapping.h" +namespace +{ +Ptr<ProxyMutex> reconfig_mutex; + +DbgCtl dbg_ctl_url_rewrite{"url_rewrite"}; + +} // end anonymous namespace + // Global Ptrs -static Ptr<ProxyMutex> reconfig_mutex; UrlRewrite *rewrite_table = nullptr; thread_local PluginThreadContext *pluginThreadContext = nullptr; @@ -134,7 +141,7 @@ reloadUrlRewrite() UrlRewrite *newTable, *oldTable; Note("%s loading ...", ts::filename::REMAP); - Debug("url_rewrite", "%s updated, reloading...", ts::filename::REMAP); + Dbg(dbg_ctl_url_rewrite, "%s updated, reloading...", ts::filename::REMAP); newTable = new UrlRewrite(); if (newTable->load()) { static const char *msg_format = "%s finished loading"; @@ -150,14 +157,14 @@ reloadUrlRewrite() // Release the old one oldTable->release(); - Debug("url_rewrite", msg_format, ts::filename::REMAP); + Dbg(dbg_ctl_url_rewrite, msg_format, ts::filename::REMAP); Note(msg_format, ts::filename::REMAP); return true; } else { static const char *msg_format = "%s failed to load"; delete newTable; - Debug("url_rewrite", msg_format, ts::filename::REMAP); + Dbg(dbg_ctl_url_rewrite, msg_format, ts::filename::REMAP); Error(msg_format, ts::filename::REMAP); return false; } diff --git a/src/proxy/Transform.cc b/src/proxy/Transform.cc index d3fa39432e..60af2983a1 100644 --- a/src/proxy/Transform.cc +++ b/src/proxy/Transform.cc @@ -67,6 +67,13 @@ TransformProcessor transformProcessor; +namespace +{ +DbgCtl dbg_ctl_transform{"transform"}; +DbgCtl dbg_ctl_http_trans{"http_trans"}; + +} // end anonymous namespace + /*------------------------------------------------------------------------- -------------------------------------------------------------------------*/ @@ -141,7 +148,7 @@ TransformTerminus::handle_event(int event, void * /* edata ATS_UNUSED */) val = ink_atomic_increment(&m_event_count, -1); - Debug("transform", "[TransformTerminus::handle_event] event_count %d", m_event_count); + Dbg(dbg_ctl_transform, "[TransformTerminus::handle_event] event_count %d", m_event_count); if (val <= 0) { ink_assert(!"not reached"); @@ -151,15 +158,15 @@ TransformTerminus::handle_event(int event, void * /* edata ATS_UNUSED */) if (m_closed != 0 && m_tvc->m_closed != 0) { if (m_deletable) { - Debug("transform", "TransformVConnection destroy [0x%lx]", (long)m_tvc); + Dbg(dbg_ctl_transform, "TransformVConnection destroy [0x%lx]", (long)m_tvc); delete m_tvc; return 0; } } else if (m_write_vio.op == VIO::WRITE) { if (m_read_vio.op == VIO::NONE) { if (!m_called_user) { - Debug("transform", "TransformVConnection calling user: %d %d [0x%lx] [0x%lx]", m_event_count, event, (long)m_tvc, - (long)m_tvc->m_cont); + Dbg(dbg_ctl_transform, "TransformVConnection calling user: %d %d [0x%lx] [0x%lx]", m_event_count, event, (long)m_tvc, + (long)m_tvc->m_cont); m_called_user = 1; // It is our belief this is safe to pass a reference, i.e. its scope @@ -278,7 +285,7 @@ TransformTerminus::do_io_read(Continuation *c, int64_t nbytes, MIOBuffer *buf) if (ink_atomic_increment(&m_event_count, 1) < 0) { ink_assert(!"not reached"); } - Debug("transform", "[TransformTerminus::do_io_read] event_count %d", m_event_count); + Dbg(dbg_ctl_transform, "[TransformTerminus::do_io_read] event_count %d", m_event_count); this_ethread()->schedule_imm_local(this); @@ -303,7 +310,7 @@ TransformTerminus::do_io_write(Continuation *c, int64_t nbytes, IOBufferReader * if (ink_atomic_increment(&m_event_count, 1) < 0) { ink_assert(!"not reached"); } - Debug("transform", "[TransformTerminus::do_io_write] event_count %d", m_event_count); + Dbg(dbg_ctl_transform, "[TransformTerminus::do_io_write] event_count %d", m_event_count); this_ethread()->schedule_imm_local(this); @@ -367,11 +374,11 @@ TransformTerminus::reenable(VIO *vio) if (ink_atomic_increment(&m_event_count, 1) < 0) { ink_assert(!"not reached"); } - Debug("transform", "[TransformTerminus::reenable] event_count %d", m_event_count); + Dbg(dbg_ctl_transform, "[TransformTerminus::reenable] event_count %d", m_event_count); this_ethread()->schedule_imm_local(this); } else { - Debug("transform", "[TransformTerminus::reenable] skipping due to " - "pending events"); + Dbg(dbg_ctl_transform, "[TransformTerminus::reenable] skipping due to " + "pending events"); } } @@ -396,7 +403,7 @@ TransformVConnection::TransformVConnection(Continuation *cont, APIHook *hooks) xform = (INKVConnInternal *)hooks->m_cont; xform->do_io_transform(&m_terminus); - Debug("transform", "TransformVConnection create [0x%lx]", (long)this); + Dbg(dbg_ctl_transform, "TransformVConnection create [0x%lx]", (long)this); } /*------------------------------------------------------------------------- @@ -428,7 +435,7 @@ TransformVConnection::handle_event(int /* event ATS_UNUSED */, void * /* edata A VIO * TransformVConnection::do_io_read(Continuation *c, int64_t nbytes, MIOBuffer *buf) { - Debug("transform", "TransformVConnection do_io_read: 0x%lx [0x%lx]", (long)c, (long)this); + Dbg(dbg_ctl_transform, "TransformVConnection do_io_read: 0x%lx [0x%lx]", (long)c, (long)this); return m_terminus.do_io_read(c, nbytes, buf); } @@ -439,7 +446,7 @@ TransformVConnection::do_io_read(Continuation *c, int64_t nbytes, MIOBuffer *buf VIO * TransformVConnection::do_io_write(Continuation *c, int64_t nbytes, IOBufferReader *buf, bool /* owner ATS_UNUSED */) { - Debug("transform", "TransformVConnection do_io_write: 0x%lx [0x%lx]", (long)c, (long)this); + Dbg(dbg_ctl_transform, "TransformVConnection do_io_write: 0x%lx [0x%lx]", (long)c, (long)this); return m_transform->do_io_write(c, nbytes, buf); } @@ -450,7 +457,7 @@ TransformVConnection::do_io_write(Continuation *c, int64_t nbytes, IOBufferReade void TransformVConnection::do_io_close(int error) { - Debug("transform", "TransformVConnection do_io_close: %d [0x%lx]", error, (long)this); + Dbg(dbg_ctl_transform, "TransformVConnection do_io_close: %d [0x%lx]", error, (long)this); if (m_closed != 0) { return; @@ -474,7 +481,7 @@ TransformVConnection::do_io_shutdown(ShutdownHowTo_t howto) { ink_assert(howto == IO_SHUTDOWN_WRITE); - Debug("transform", "TransformVConnection do_io_shutdown: %d [0x%lx]", howto, (long)this); + Dbg(dbg_ctl_transform, "TransformVConnection do_io_shutdown: %d [0x%lx]", howto, (long)this); m_transform->do_io_shutdown(howto); } @@ -601,7 +608,7 @@ NullTransform::NullTransform(ProxyMutex *_mutex) { SET_HANDLER(&NullTransform::handle_event); - Debug("transform", "NullTransform create [0x%lx]", (long)this); + Dbg(dbg_ctl_transform, "NullTransform create [0x%lx]", (long)this); } /*------------------------------------------------------------------------- @@ -622,11 +629,11 @@ NullTransform::handle_event(int event, void *edata) { handle_event_count(event); - Debug("transform", "[NullTransform::handle_event] event count %d", m_event_count); + Dbg(dbg_ctl_transform, "[NullTransform::handle_event] event count %d", m_event_count); if (m_closed) { if (m_deletable) { - Debug("transform", "NullTransform destroy: %" PRId64 " [%p]", m_output_vio ? m_output_vio->ndone : 0, this); + Dbg(dbg_ctl_transform, "NullTransform destroy: %" PRId64 " [%p]", m_output_vio ? m_output_vio->ndone : 0, this); delete this; } } else { @@ -681,10 +688,10 @@ NullTransform::handle_event(int event, void *edata) } if (towrite > 0) { - Debug("transform", - "[NullTransform::handle_event] " - "writing %" PRId64 " bytes to output", - towrite); + Dbg(dbg_ctl_transform, + "[NullTransform::handle_event] " + "writing %" PRId64 " bytes to output", + towrite); m_output_buf->write(m_write_vio.get_reader(), towrite); m_write_vio.get_reader()->consume(towrite); @@ -758,7 +765,7 @@ RangeTransform::RangeTransform(ProxyMutex *mut, RangeRecord *ranges, int num_fie SET_HANDLER(&RangeTransform::handle_event); m_num_chars_for_cl = num_chars_for_int(m_range_content_length); - Debug("http_trans", "RangeTransform creation finishes"); + Dbg(dbg_ctl_http_trans, "RangeTransform creation finishes"); } /*------------------------------------------------------------------------- @@ -782,9 +789,9 @@ RangeTransform::handle_event(int event, void *edata) if (m_closed) { if (m_deletable) { if (m_output_vc != nullptr) { - Debug("http_trans", "RangeTransform destroy: %p ndone=%" PRId64, this, m_output_vio ? m_output_vio->ndone : 0); + Dbg(dbg_ctl_http_trans, "RangeTransform destroy: %p ndone=%" PRId64, this, m_output_vio ? m_output_vio->ndone : 0); } else { - Debug("http_trans", "RangeTransform destroy"); + Dbg(dbg_ctl_http_trans, "RangeTransform destroy"); } delete this; } @@ -909,7 +916,7 @@ RangeTransform::transform_to_range() add_boundary(true); } - Debug("http_trans", "total bytes of Range response body is %" PRId64, m_done); + Dbg(dbg_ctl_http_trans, "total bytes of Range response body is %" PRId64, m_done); m_output_vio->nbytes = m_done; m_output_vio->reenable(); diff --git a/src/proxy/http3/Http09App.cc b/src/proxy/http3/Http09App.cc index e6bf6fbbd2..32c6cafe07 100644 --- a/src/proxy/http3/Http09App.cc +++ b/src/proxy/http3/Http09App.cc @@ -34,8 +34,15 @@ #include "proxy/http3/Http3Session.h" #include "proxy/http3/Http3Transaction.h" -static constexpr char debug_tag[] = "quic_simple_app"; -static constexpr char debug_tag_v[] = "v_quic_simple_app"; +namespace +{ +constexpr char debug_tag[] = "quic_simple_app"; +constexpr char debug_tag_v[] = "v_quic_simple_app"; + +DbgCtl dbg_ctl{debug_tag}; +DbgCtl dbg_ctl_v{debug_tag_v}; + +} // end anonymous namespace Http09App::Http09App(NetVConnection *client_vc, QUICConnection *qc, IpAllow::ACL &&session_acl, const HttpSessionAccept::Options &options) @@ -89,13 +96,13 @@ Http09App::on_stream_close(QUICStream &stream) int Http09App::main_event_handler(int event, Event *data) { - Debug(debug_tag_v, "[%s] %s (%d)", this->_qc->cids().data(), get_vc_event_name(event), event); + Dbg(dbg_ctl_v, "[%s] %s (%d)", this->_qc->cids().data(), get_vc_event_name(event), event); VIO *vio = reinterpret_cast<VIO *>(data->cookie); QUICStreamVCAdapter *adapter = static_cast<QUICStreamVCAdapter *>(vio->vc_server); if (adapter == nullptr) { - Debug(debug_tag, "[%s] Unknown Stream", this->_qc->cids().data()); + Dbg(dbg_ctl, "[%s] Unknown Stream", this->_qc->cids().data()); return -1; } diff --git a/src/proxy/http3/Http3App.cc b/src/proxy/http3/Http3App.cc index 7226b08d49..e24f90e9ea 100644 --- a/src/proxy/http3/Http3App.cc +++ b/src/proxy/http3/Http3App.cc @@ -41,8 +41,15 @@ #include "proxy/http3/Http3SettingsHandler.h" #include "proxy/http3/Http3SettingsFramer.h" -static constexpr char debug_tag[] = "http3"; -static constexpr char debug_tag_v[] = "v_http3"; +namespace +{ +constexpr char debug_tag[] = "http3"; +constexpr char debug_tag_v[] = "v_http3"; + +DbgCtl dbg_ctl{debug_tag}; +DbgCtl dbg_ctl_v{debug_tag_v}; + +} // end anonymous namespace Http3App::Http3App(NetVConnection *client_vc, QUICConnection *qc, IpAllow::ACL &&session_acl, const HttpSessionAccept::Options &options) @@ -130,13 +137,13 @@ Http3App::on_stream_close(QUICStream &stream) int Http3App::main_event_handler(int event, Event *data) { - Debug(debug_tag_v, "[%s] %s (%d)", this->_qc->cids().data(), get_vc_event_name(event), event); + Dbg(dbg_ctl_v, "[%s] %s (%d)", this->_qc->cids().data(), get_vc_event_name(event), event); VIO *vio = reinterpret_cast<VIO *>(data->cookie); QUICStreamVCAdapter *adapter = static_cast<QUICStreamVCAdapter *>(vio->vc_server); if (adapter == nullptr) { - Debug(debug_tag, "[%s] Unknown Stream", this->_qc->cids().data()); + Dbg(dbg_ctl, "[%s] Unknown Stream", this->_qc->cids().data()); return -1; } @@ -203,9 +210,9 @@ Http3App::create_uni_stream(QUICStreamId &new_stream_id, Http3StreamType type) if (error == nullptr) { this->_local_uni_stream_map.insert(std::make_pair(new_stream_id, type)); - Debug("http3", "[%" PRIu64 "] %s stream is created", new_stream_id, Http3DebugNames::stream_type(type)); + Dbg(dbg_ctl, "[%" PRIu64 "] %s stream is created", new_stream_id, Http3DebugNames::stream_type(type)); } else { - Debug("http3", "Could not create %s stream", Http3DebugNames::stream_type(type)); + Dbg(dbg_ctl, "Could not create %s stream", Http3DebugNames::stream_type(type)); } return error; @@ -224,7 +231,7 @@ Http3App::_handle_uni_stream_on_read_ready(int /* event */, VIO *vio) vio->get_reader()->read(&buf, 1); type = Http3Stream::type(&buf); - Debug("http3", "[%" PRIu64 "] %s stream is opened", adapter->stream().id(), Http3DebugNames::stream_type(type)); + Dbg(dbg_ctl, "[%" PRIu64 "] %s stream is opened", adapter->stream().id(), Http3DebugNames::stream_type(type)); auto ret = this->_remote_uni_stream_map.insert(std::make_pair(adapter->stream().id(), type)); if (!ret.second) { @@ -242,13 +249,13 @@ Http3App::_handle_uni_stream_on_read_ready(int /* event */, VIO *vio) } else if (this->_control_stream_id != adapter->stream().id()) { error = std::make_unique<Http3Error>(Http3ErrorClass::CONNECTION, Http3ErrorCode::H3_STREAM_CREATION_ERROR, "Only one control stream per peer is permitted"); - Debug("http3", "CONTROL stream [%" PRIu64 "] error: %hu, %s", this->_control_stream_id, error->get_code(), error->msg); + Dbg(dbg_ctl, "CONTROL stream [%" PRIu64 "] error: %hu, %s", this->_control_stream_id, error->get_code(), error->msg); break; } uint64_t nread = 0; error = this->_control_stream_dispatcher.on_read_ready(adapter->stream().id(), type, *vio->get_reader(), nread); if (error && error->cls != Http3ErrorClass::UNDEFINED) { - Debug("http3", "CONTROL stream [%" PRIu64 "] error: %hu, %s", this->_control_stream_id, error->get_code(), error->msg); + Dbg(dbg_ctl, "CONTROL stream [%" PRIu64 "] error: %hu, %s", this->_control_stream_id, error->get_code(), error->msg); } // The sender MUST NOT close the control stream, and the receiver MUST NOT request that the sender close the control stream. // If either control stream is closed at any point, this MUST be treated as a connection error of type @@ -258,7 +265,7 @@ Http3App::_handle_uni_stream_on_read_ready(int /* event */, VIO *vio) case Http3StreamType::PUSH: { error = std::make_unique<Http3Error>(Http3ErrorClass::CONNECTION, Http3ErrorCode::H3_STREAM_CREATION_ERROR, "Only servers can push"); - Debug("http3", "PUSH stream [%" PRIu64 "] error: %hu, %s", adapter->stream().id(), error->get_code(), error->msg); + Dbg(dbg_ctl, "PUSH stream [%" PRIu64 "] error: %hu, %s", adapter->stream().id(), error->get_code(), error->msg); // if a server receives a client-initiated push stream, this MUST be treated as a connection error of type // H3_STREAM_CREATION_ERROR break; @@ -273,7 +280,7 @@ Http3App::_handle_uni_stream_on_read_ready(int /* event */, VIO *vio) // processing. If reading is aborted, the recipient SHOULD use the H3_STREAM_CREATION_ERROR error code or a reserved error code // (Section 8.1). The recipient MUST NOT consider unknown stream types to be a connection error of any kind. error = std::make_unique<Http3Error>(Http3ErrorClass::STREAM, Http3ErrorCode::H3_STREAM_CREATION_ERROR, "Stream type unkown"); - Debug("http3", "UNKNOWN stream [%" PRIu64 "] error: %hu, %s", adapter->stream().id(), error->get_code(), error->msg); + Dbg(dbg_ctl, "UNKNOWN stream [%" PRIu64 "] error: %hu, %s", adapter->stream().id(), error->get_code(), error->msg); break; } default: diff --git a/src/proxy/http3/Http3Frame.cc b/src/proxy/http3/Http3Frame.cc index cecb3f50f1..c429919217 100644 --- a/src/proxy/http3/Http3Frame.cc +++ b/src/proxy/http3/Http3Frame.cc @@ -31,8 +31,14 @@ ClassAllocator<Http3DataFrame> http3DataFrameAllocator("http3DataFrameAlloca ClassAllocator<Http3HeadersFrame> http3HeadersFrameAllocator("http3HeadersFrameAllocator"); ClassAllocator<Http3SettingsFrame> http3SettingsFrameAllocator("http3SettingsFrameAllocator"); +namespace +{ constexpr int HEADER_OVERHEAD = 10; // This should work as long as a payload length is less than 64 bits +DbgCtl dbg_ctl_http3_frame_factory{"http3_frame_factory"}; + +} // end anonymous namespace + // // Static functions // @@ -419,7 +425,7 @@ Http3FrameFactory::create(const uint8_t *buf, size_t len) return Http3FrameUPtr(frame, &Http3FrameDeleter::delete_settings_frame); default: // Unknown frame - Debug("http3_frame_factory", "Unknown frame type %hhx", static_cast<uint8_t>(type)); + Dbg(dbg_ctl_http3_frame_factory, "Unknown frame type %hhx", static_cast<uint8_t>(type)); frame = http3FrameAllocator.alloc(); new (frame) Http3Frame(buf, len); return Http3FrameUPtr(frame, &Http3FrameDeleter::delete_frame); diff --git a/src/proxy/http3/Http3FrameCollector.cc b/src/proxy/http3/Http3FrameCollector.cc index 998e02bffb..864fe2ac97 100644 --- a/src/proxy/http3/Http3FrameCollector.cc +++ b/src/proxy/http3/Http3FrameCollector.cc @@ -25,6 +25,12 @@ #include "proxy/http3/Http3DebugNames.h" +namespace +{ +DbgCtl dbg_ctl_http3{"http3"}; + +} // end anonymous namespace + Http3ErrorUPtr Http3FrameCollector::on_write_ready(QUICStreamId stream_id, MIOBuffer &writer, size_t &nwritten, bool &all_done) { @@ -41,7 +47,7 @@ Http3FrameCollector::on_write_ready(QUICStreamId stream_id, MIOBuffer &writer, s auto b = frame->to_io_buffer_block(); len = writer.write(b.get(), INT64_MAX, 0); nwritten += len; - Debug("http3", "[TX] [%" PRIu64 "] | %s size=%zu", stream_id, Http3DebugNames::frame_type(frame->type()), len); + Dbg(dbg_ctl_http3, "[TX] [%" PRIu64 "] | %s size=%zu", stream_id, Http3DebugNames::frame_type(frame->type()), len); } all_done &= g->is_done(); diff --git a/src/proxy/http3/Http3FrameDispatcher.cc b/src/proxy/http3/Http3FrameDispatcher.cc index 19acf264f6..ae1a6e4771 100644 --- a/src/proxy/http3/Http3FrameDispatcher.cc +++ b/src/proxy/http3/Http3FrameDispatcher.cc @@ -28,6 +28,13 @@ #include "proxy/http3/Http3DebugNames.h" +namespace +{ +DbgCtl dbg_ctl_v_http3{"v_http3"}; +DbgCtl dbg_ctl_http3{"http3"}; + +} // end anonymous namespace + // // Frame Dispatcher // @@ -53,13 +60,13 @@ Http3FrameDispatcher::on_read_ready(QUICStreamId stream_id, Http3StreamType stre uint8_t head[16]; auto p = reader.memcpy(head, 16); int64_t read_len = p - reinterpret_cast<char *>(head); - Debug("v_http3", "reading H3 frame: state=%d read_len=%" PRId64, this->_reading_state, read_len); + Dbg(dbg_ctl_v_http3, "reading H3 frame: state=%d read_len=%" PRId64, this->_reading_state, read_len); if (this->_reading_state == READING_TYPE_LEN) { if (read_len >= 1) { this->_reading_frame_type_len = QUICVariableInt::size(head); this->_reading_state = READING_LENGTH_LEN; - Debug("v_http3", "type_len=%" PRId64, this->_reading_frame_type_len); + Dbg(dbg_ctl_v_http3, "type_len=%" PRId64, this->_reading_frame_type_len); } else { break; } @@ -69,7 +76,7 @@ Http3FrameDispatcher::on_read_ready(QUICStreamId stream_id, Http3StreamType stre if (read_len >= this->_reading_frame_type_len + 1) { this->_reading_frame_length_len = QUICVariableInt::size(head + this->_reading_frame_type_len); this->_reading_state = READING_PAYLOAD_LEN; - Debug("v_http3", "length_len=%" PRId64, this->_reading_frame_length_len); + Dbg(dbg_ctl_v_http3, "length_len=%" PRId64, this->_reading_frame_length_len); } else { break; } @@ -79,7 +86,7 @@ Http3FrameDispatcher::on_read_ready(QUICStreamId stream_id, Http3StreamType stre if (read_len >= this->_reading_frame_type_len + this->_reading_frame_length_len) { size_t dummy; QUICVariableInt::decode(this->_reading_frame_payload_len, dummy, head + this->_reading_frame_type_len); - Debug("v_http3", "payload_len=%" PRId64, this->_reading_frame_payload_len); + Dbg(dbg_ctl_v_http3, "payload_len=%" PRId64, this->_reading_frame_payload_len); this->_reading_state = READING_PAYLOAD; } else { break; @@ -104,7 +111,7 @@ Http3FrameDispatcher::on_read_ready(QUICStreamId stream_id, Http3StreamType stre // Dispatch Http3FrameType type = frame->type(); - Debug("http3", "[RX] [%" PRIu64 "] | %s size=%zu", stream_id, Http3DebugNames::frame_type(type), frame_len); + Dbg(dbg_ctl_http3, "[RX] [%" PRIu64 "] | %s size=%zu", stream_id, Http3DebugNames::frame_type(type), frame_len); std::vector<Http3FrameHandler *> handlers = this->_handlers[static_cast<uint8_t>(type)]; for (auto h : handlers) { error = h->handle_frame(frame, frame_count - 1, stream_type); diff --git a/src/proxy/http3/Http3HeaderFramer.cc b/src/proxy/http3/Http3HeaderFramer.cc index 6a23a74937..7480a7f1d4 100644 --- a/src/proxy/http3/Http3HeaderFramer.cc +++ b/src/proxy/http3/Http3HeaderFramer.cc @@ -30,6 +30,12 @@ #include "proxy/http3/Http3Frame.h" #include "proxy/http3/Http3Transaction.h" +namespace +{ +DbgCtl dbg_ctl_http3_trans{"http3_trans"}; + +} // end anonymous namespace + Http3HeaderFramer::Http3HeaderFramer(Http3Transaction *transaction, VIO *source, QPACK *qpack, uint64_t stream_id) : _transaction(transaction), _source_vio(source), _qpack(qpack), _stream_id(stream_id) { @@ -109,7 +115,7 @@ Http3HeaderFramer::_generate_header_block() case PARSE_RESULT_CONT: break; default: - Debug("http3_trans", "Ignore invalid headers"); + Dbg(dbg_ctl_http3_trans, "Ignore invalid headers"); break; } } diff --git a/src/proxy/http3/Http3HeaderVIOAdaptor.cc b/src/proxy/http3/Http3HeaderVIOAdaptor.cc index 8dd59a1b70..5c9e174f27 100644 --- a/src/proxy/http3/Http3HeaderVIOAdaptor.cc +++ b/src/proxy/http3/Http3HeaderVIOAdaptor.cc @@ -27,6 +27,13 @@ #include "iocore/eventsystem/VIO.h" #include "proxy/hdrs/HTTP.h" +namespace +{ +DbgCtl dbg_ctl_http3{"http3"}; +DbgCtl dbg_ctl_v_http3{"v_http3"}; + +} // end anonymous namespace + Http3HeaderVIOAdaptor::Http3HeaderVIOAdaptor(VIO *sink, HTTPType http_type, QPACK *qpack, uint64_t stream_id) : _sink_vio(sink), _qpack(qpack), _stream_id(stream_id) { @@ -58,9 +65,9 @@ Http3HeaderVIOAdaptor::handle_frame(std::shared_ptr<const Http3Frame> frame, int // When decoding is not blocked, continuation should be called directly? } else if (res == 1) { // Decoding is blocked. - Debug("http3", "Decoding is blocked. DecodeRequest is scheduled"); + Dbg(dbg_ctl_http3, "Decoding is blocked. DecodeRequest is scheduled"); } else if (res < 0) { - Debug("http3", "Error on decoding header (%d)", res); + Dbg(dbg_ctl_http3, "Error on decoding header (%d)", res); } else { ink_abort("should not be here"); } @@ -79,13 +86,13 @@ Http3HeaderVIOAdaptor::event_handler(int event, Event *data) { switch (event) { case QPACK_EVENT_DECODE_COMPLETE: - Debug("v_http3", "%s (%d)", "QPACK_EVENT_DECODE_COMPLETE", event); + Dbg(dbg_ctl_v_http3, "%s (%d)", "QPACK_EVENT_DECODE_COMPLETE", event); if (this->_on_qpack_decode_complete()) { // If READ_READY event is scheduled, should it be canceled? } break; case QPACK_EVENT_DECODE_FAILED: - Debug("v_http3", "%s (%d)", "QPACK_EVENT_DECODE_FAILED", event); + Dbg(dbg_ctl_v_http3, "%s (%d)", "QPACK_EVENT_DECODE_FAILED", event); // FIXME: handle error break; } @@ -100,12 +107,12 @@ Http3HeaderVIOAdaptor::_on_qpack_decode_complete() constexpr static bool NON_TRAILER = false; if (!HeaderValidator::is_h2_h3_header_valid(this->_header, http_hdr_type_get(this->_header.m_http) == HTTP_TYPE_RESPONSE, NON_TRAILER)) { - Debug("http3", "Header is invalid"); + Dbg(dbg_ctl_http3, "Header is invalid"); return -1; } int res = this->_hvc.convert(this->_header, 3, 1); if (res != 0) { - Debug("http3", "PARSE_RESULT_ERROR"); + Dbg(dbg_ctl_http3, "PARSE_RESULT_ERROR"); return -1; } diff --git a/src/proxy/http3/Http3SessionAccept.cc b/src/proxy/http3/Http3SessionAccept.cc index 458a523dc4..5725322662 100644 --- a/src/proxy/http3/Http3SessionAccept.cc +++ b/src/proxy/http3/Http3SessionAccept.cc @@ -32,6 +32,12 @@ #include "proxy/http3/Http09App.h" #include "proxy/http3/Http3App.h" +namespace +{ +DbgCtl dbg_ctl_http3{"http3"}; + +} // end anonymous namespace + Http3SessionAccept::Http3SessionAccept(const HttpSessionAccept::Options &_o) : SessionAccept(nullptr), options(_o) { SET_HANDLER(&Http3SessionAccept::mainEvent); @@ -52,7 +58,7 @@ Http3SessionAccept::accept(NetVConnection *netvc, MIOBuffer *iobuf, IOBufferRead // RFC9114, section 3.2-2: Client must send the SNI extension. if (auto sni = netvc->get_service<TLSSNISupport>(); !sni || sni->get_sni_server_name()[0] == '\0') { ip_port_text_buffer ipb; - Debug("http3", "SNI not found in connection from %s.", ats_ip_nptop(client_ip, ipb, sizeof(ipb))); + Dbg(dbg_ctl_http3, "SNI not found in connection from %s.", ats_ip_nptop(client_ip, ipb, sizeof(ipb))); return false; } @@ -60,19 +66,19 @@ Http3SessionAccept::accept(NetVConnection *netvc, MIOBuffer *iobuf, IOBufferRead QUICConnection *qc = netvc->get_service<QUICSupport>()->get_quic_connection(); - if (is_debug_tag_set("http3")) { + if (dbg_ctl_http3.on()) { ip_port_text_buffer ipb; - Debug("http3", "[%s] accepted connection from %s transport type = %d", qc->cids().data(), - ats_ip_nptop(client_ip, ipb, sizeof(ipb)), netvc->attributes); + DbgPrint(dbg_ctl_http3, "[%s] accepted connection from %s transport type = %d", qc->cids().data(), + ats_ip_nptop(client_ip, ipb, sizeof(ipb)), netvc->attributes); } std::string_view alpn = qc->negotiated_application_name(); if (IP_PROTO_TAG_HTTP_QUIC.compare(alpn) == 0 || IP_PROTO_TAG_HTTP_QUIC_D29.compare(alpn) == 0) { - Debug("http3", "[%s] start HTTP/0.9 app (ALPN=%.*s)", qc->cids().data(), static_cast<int>(alpn.length()), alpn.data()); + Dbg(dbg_ctl_http3, "[%s] start HTTP/0.9 app (ALPN=%.*s)", qc->cids().data(), static_cast<int>(alpn.length()), alpn.data()); new Http09App(netvc, qc, std::move(session_acl), this->options); } else if (IP_PROTO_TAG_HTTP_3.compare(alpn) == 0 || IP_PROTO_TAG_HTTP_3_D29.compare(alpn) == 0) { - Debug("http3", "[%s] start HTTP/3 app (ALPN=%.*s)", qc->cids().data(), static_cast<int>(alpn.length()), alpn.data()); + Dbg(dbg_ctl_http3, "[%s] start HTTP/3 app (ALPN=%.*s)", qc->cids().data(), static_cast<int>(alpn.length()), alpn.data()); Http3App *app = new Http3App(netvc, qc, std::move(session_acl), this->options); app->start(); diff --git a/src/proxy/http3/Http3SettingsHandler.cc b/src/proxy/http3/Http3SettingsHandler.cc index 603c40dc52..b00e1fb866 100644 --- a/src/proxy/http3/Http3SettingsHandler.cc +++ b/src/proxy/http3/Http3SettingsHandler.cc @@ -23,6 +23,12 @@ #include "proxy/http3/Http3SettingsHandler.h" +namespace +{ +DbgCtl dbg_ctl_http3{"http3"}; + +} // end anonymous namespace + // // SETTINGS frame handler // @@ -53,28 +59,28 @@ Http3SettingsHandler::handle_frame(std::shared_ptr<const Http3Frame> frame, int3 uint64_t header_table_size = settings_frame->get(Http3SettingsId::HEADER_TABLE_SIZE); this->_session->remote_qpack()->update_max_table_size(header_table_size); - Debug("http3", "SETTINGS_HEADER_TABLE_SIZE: %" PRId64, header_table_size); + Dbg(dbg_ctl_http3, "SETTINGS_HEADER_TABLE_SIZE: %" PRId64, header_table_size); } if (settings_frame->contains(Http3SettingsId::MAX_FIELD_SECTION_SIZE)) { uint64_t max_field_section_size = settings_frame->get(Http3SettingsId::MAX_FIELD_SECTION_SIZE); this->_session->remote_qpack()->update_max_field_section_size(max_field_section_size); - Debug("http3", "SETTINGS_MAX_FIELD_SECTION_SIZE: %" PRId64, max_field_section_size); + Dbg(dbg_ctl_http3, "SETTINGS_MAX_FIELD_SECTION_SIZE: %" PRId64, max_field_section_size); } if (settings_frame->contains(Http3SettingsId::QPACK_BLOCKED_STREAMS)) { uint64_t qpack_blocked_streams = settings_frame->get(Http3SettingsId::QPACK_BLOCKED_STREAMS); this->_session->remote_qpack()->update_max_blocking_streams(qpack_blocked_streams); - Debug("http3", "SETTINGS_QPACK_BLOCKED_STREAMS: %" PRId64, qpack_blocked_streams); + Dbg(dbg_ctl_http3, "SETTINGS_QPACK_BLOCKED_STREAMS: %" PRId64, qpack_blocked_streams); } if (settings_frame->contains(Http3SettingsId::NUM_PLACEHOLDERS)) { uint64_t num_placeholders = settings_frame->get(Http3SettingsId::NUM_PLACEHOLDERS); // TODO: update settings for priority tree - Debug("http3", "SETTINGS_NUM_PLACEHOLDERS: %" PRId64, num_placeholders); + Dbg(dbg_ctl_http3, "SETTINGS_NUM_PLACEHOLDERS: %" PRId64, num_placeholders); } return Http3ErrorUPtr(nullptr); diff --git a/src/proxy/http3/Http3Transaction.cc b/src/proxy/http3/Http3Transaction.cc index 687d64989b..ab6f2350bf 100644 --- a/src/proxy/http3/Http3Transaction.cc +++ b/src/proxy/http3/Http3Transaction.cc @@ -35,13 +35,20 @@ #define NetVC2QUICCon(netvc) netvc->get_service<QUICSupport>()->get_quic_connection() -#define Http3TransDebug(fmt, ...) \ - Debug("http3_trans", "[%s] [%" PRIx32 "] " fmt, NetVC2QUICCon(this->_proxy_ssn->get_netvc())->cids().data(), \ - this->get_transaction_id(), ##__VA_ARGS__) +#define Http3TransDebug(fmt, ...) \ + Dbg(dbg_ctl_http3_trans, "[%s] [%" PRIx32 "] " fmt, NetVC2QUICCon(this->_proxy_ssn->get_netvc())->cids().data(), \ + this->get_transaction_id(), ##__VA_ARGS__) -#define Http3TransVDebug(fmt, ...) \ - Debug("v_http3_trans", "[%s] [%" PRIx32 "] " fmt, NetVC2QUICCon(this->_proxy_ssn->get_netvc())->cids().data(), \ - this->get_transaction_id(), ##__VA_ARGS__) +#define Http3TransVDebug(fmt, ...) \ + Dbg(dbg_ctl_v_http3_trans, "[%s] [%" PRIx32 "] " fmt, NetVC2QUICCon(this->_proxy_ssn->get_netvc())->cids().data(), \ + this->get_transaction_id(), ##__VA_ARGS__) + +namespace +{ +DbgCtl dbg_ctl_http3_trans{"http3_trans"}; +DbgCtl dbg_ctl_v_http3_trans{"v_http3_trans"}; + +} // end anonymous namespace // static void // dump_io_buffer(IOBufferReader *reader) @@ -50,7 +57,7 @@ // uint8_t msg[1024] = {0}; // int64_t msg_len = 1024; // int64_t read_len = debug_reader->read(msg, msg_len); -// Debug("v_http3_trans", "len=%" PRId64 "\n%s\n", read_len, msg); +// Dbg(dbg_ctl_v_http3_trans, "len=%" PRId64 "\n%s\n", read_len, msg); // } // diff --git a/src/proxy/http3/QPACK.cc b/src/proxy/http3/QPACK.cc index 0919718678..a8b0e8116b 100644 --- a/src/proxy/http3/QPACK.cc +++ b/src/proxy/http3/QPACK.cc @@ -27,8 +27,14 @@ #include "tscore/ink_defs.h" #include "tscore/ink_memory.h" -#define QPACKDebug(fmt, ...) Debug("qpack", "[%s] " fmt, this->_qc->cids().data(), ##__VA_ARGS__) -#define QPACKDTDebug(fmt, ...) Debug("qpack", "" fmt, ##__VA_ARGS__) +#define QPACKDebug(fmt, ...) Dbg(dbg_ctl_qpack, "[%s] " fmt, this->_qc->cids().data(), ##__VA_ARGS__) +#define QPACKDTDebug(fmt, ...) Dbg(dbg_ctl_qpack, "" fmt, ##__VA_ARGS__) + +namespace +{ +DbgCtl dbg_ctl_qpack{"qpack"}; + +} // end anonymous namespace // qpack-05 Appendix A. const QPACK::Header QPACK::StaticTable::STATIC_HEADER_FIELDS[] = {