This is an automated email from the ASF dual-hosted git repository.
wkaras 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 55f6901951 Remove deprecated debug output functions from 21 source
files. (#9683)
55f6901951 is described below
commit 55f6901951c9267aab2029ac8e2422e895e8dbb0
Author: Walt Karas <[email protected]>
AuthorDate: Wed Sep 13 10:00:16 2023 -0400
Remove deprecated debug output functions from 21 source files. (#9683)
---
iocore/net/NetHandler.h | 3 +
iocore/net/P_Net.h | 4 +-
iocore/net/P_NetAccept.h | 6 +-
iocore/net/P_SNIActionPerformer.h | 15 ++-
iocore/net/P_UDPNet.h | 9 +-
iocore/net/P_UnixNet.h | 6 +-
iocore/net/P_UnixNetVConnection.h | 13 +-
iocore/net/PollCont.cc | 23 +++-
iocore/net/QUICNetProcessor.cc | 21 ++-
iocore/net/QUICPacketHandler.cc | 35 ++---
iocore/net/SNIActionPerformer.cc | 12 +-
iocore/net/SNIActionPerformer.h | 4 +
iocore/net/SSLDiags.h | 8 +-
iocore/net/SSLNetVConnection.cc | 276 ++++++++++++++++++++------------------
iocore/net/SSLSNIConfig.cc | 9 +-
iocore/net/TLSSNISupport.cc | 11 +-
iocore/net/UnixNet.cc | 30 +++--
iocore/net/UnixNetAccept.cc | 15 ++-
iocore/net/UnixNetProcessor.cc | 28 ++--
iocore/net/UnixUDPConnection.cc | 11 +-
iocore/net/UnixUDPNet.cc | 104 +++++++-------
21 files changed, 376 insertions(+), 267 deletions(-)
diff --git a/iocore/net/NetHandler.h b/iocore/net/NetHandler.h
index 9103aeabd3..d218d8ccc6 100644
--- a/iocore/net/NetHandler.h
+++ b/iocore/net/NetHandler.h
@@ -223,6 +223,9 @@ public:
NetHandler();
+ inline static DbgCtl dbg_ctl_socket{"socket"};
+ inline static DbgCtl dbg_ctl_iocore_net{"iocore_net"};
+
private:
void _close_ne(NetEvent *ne, ink_hrtime now, int &handle_event, int &closed,
int &total_idle_time, int &total_idle_count);
diff --git a/iocore/net/P_Net.h b/iocore/net/P_Net.h
index 09c2fa1251..7516b106cd 100644
--- a/iocore/net/P_Net.h
+++ b/iocore/net/P_Net.h
@@ -108,9 +108,9 @@ static constexpr ts::ModuleVersion
NET_SYSTEM_MODULE_INTERNAL_VERSION(NET_SYSTEM
// For very verbose iocore debugging.
#ifndef DEBUG
-#define NetDebug(tag, fmt, ...)
+#define NetDbg(dbg_ctl, fmt, ...)
#else
-#define NetDebug(tag, fmt, ...) Debug(tag, fmt, ##__VA_ARGS__)
+#define NetDbg(dbg_ctl, fmt, ...) Dbg(dbg_ctl, fmt, ##__VA_ARGS__)
#endif
/// Default amount of buffer space to use for the initial read on an incoming
connection.
diff --git a/iocore/net/P_NetAccept.h b/iocore/net/P_NetAccept.h
index ddeeb8b5af..f44c70b517 100644
--- a/iocore/net/P_NetAccept.h
+++ b/iocore/net/P_NetAccept.h
@@ -76,7 +76,11 @@ struct NetAcceptAction : public Action, public RefCountObj {
return Action::operator=(acont);
}
- ~NetAcceptAction() override { Debug("net_accept", "NetAcceptAction dying"); }
+ ~NetAcceptAction() override
+ {
+ static DbgCtl dbg_ctl{"net_accept"};
+ Dbg(dbg_ctl, "NetAcceptAction dying");
+ }
};
//
diff --git a/iocore/net/P_SNIActionPerformer.h
b/iocore/net/P_SNIActionPerformer.h
index 88790cab80..cdfb39de7e 100644
--- a/iocore/net/P_SNIActionPerformer.h
+++ b/iocore/net/P_SNIActionPerformer.h
@@ -75,10 +75,10 @@ public:
if (ssl_vc) {
if (!enable_h2) {
ssl_vc->disableProtocol(TS_ALPN_PROTOCOL_INDEX_HTTP_2_0);
- Debug("ssl_sni", "H2 disabled, fqdn [%s]", servername);
+ Dbg(dbg_ctl_ssl_sni, "H2 disabled, fqdn [%s]", servername);
} else {
ssl_vc->enableProtocol(TS_ALPN_PROTOCOL_INDEX_HTTP_2_0);
- Debug("ssl_sni", "H2 enabled, fqdn [%s]", servername);
+ Dbg(dbg_ctl_ssl_sni, "H2 enabled, fqdn [%s]", servername);
}
}
return SSL_TLSEXT_ERR_OK;
@@ -179,7 +179,7 @@ public:
if (ssl_netvc) {
if (fnArrIndexes.empty()) {
ssl_netvc->set_tunnel_destination(destination, type,
!TLSTunnelSupport::PORT_IS_DYNAMIC, tunnel_prewarm);
- Debug("ssl_sni", "Destination now is [%s], fqdn [%s]",
destination.c_str(), servername);
+ Dbg(dbg_ctl_ssl_sni, "Destination now is [%s], fqdn [%s]",
destination.c_str(), servername);
} else {
bool port_is_dynamic = false;
auto fixed_dst{destination};
@@ -189,7 +189,8 @@ public:
fixed_dst = fix_destination[fnArrIndex](fixed_dst, var_start_pos,
ctx, ssl_netvc, port_is_dynamic);
}
ssl_netvc->set_tunnel_destination(fixed_dst, type, port_is_dynamic,
tunnel_prewarm);
- Debug("ssl_sni", "Destination now is [%s], configured [%s], fqdn
[%s]", fixed_dst.c_str(), destination.c_str(), servername);
+ Dbg(dbg_ctl_ssl_sni, "Destination now is [%s], configured [%s], fqdn
[%s]", fixed_dst.c_str(), destination.c_str(),
+ servername);
}
if (type == SNIRoutingType::BLIND) {
@@ -320,7 +321,7 @@ public:
{
auto ssl_vc = dynamic_cast<SSLNetVConnection *>(snis);
const char *servername = snis->get_sni_server_name();
- Debug("ssl_sni", "action verify param %d, fqdn [%s]", this->mode,
servername);
+ Dbg(dbg_ctl_ssl_sni, "action verify param %d, fqdn [%s]", this->mode,
servername);
setClientCertLevel(ssl_vc->ssl, this->mode);
ssl_vc->set_ca_cert_file(ca_file, ca_dir);
setClientCertCACerts(ssl_vc->ssl, ssl_vc->get_ca_cert_file(),
ssl_vc->get_ca_cert_dir());
@@ -388,7 +389,7 @@ public:
{
if (this->min_ver >= 0 || this->max_ver >= 0) {
const char *servername = snis->get_sni_server_name();
- Debug("ssl_sni", "TLSValidProtocol min=%d, max=%d, fqdn [%s]",
this->min_ver, this->max_ver, servername);
+ Dbg(dbg_ctl_ssl_sni, "TLSValidProtocol min=%d, max=%d, fqdn [%s]",
this->min_ver, this->max_ver, servername);
auto ssl_vc = dynamic_cast<SSLNetVConnection *>(snis);
ssl_vc->set_valid_tls_version_min(this->min_ver);
ssl_vc->set_valid_tls_version_max(this->max_ver);
@@ -396,7 +397,7 @@ public:
if (!unset) {
auto ssl_vc = dynamic_cast<SSLNetVConnection *>(snis);
const char *servername = snis->get_sni_server_name();
- Debug("ssl_sni", "TLSValidProtocol param 0%x, fqdn [%s]",
static_cast<unsigned int>(this->protocol_mask), servername);
+ Dbg(dbg_ctl_ssl_sni, "TLSValidProtocol param 0%x, fqdn [%s]",
static_cast<unsigned int>(this->protocol_mask), servername);
ssl_vc->set_valid_tls_protocols(protocol_mask,
TLSValidProtocols::max_mask);
Warning("valid_tls_versions_in is deprecated. Use
valid_tls_version_min_in and ivalid_tls_version_max_in instead.");
}
diff --git a/iocore/net/P_UDPNet.h b/iocore/net/P_UDPNet.h
index 190dad4292..ca97e5788d 100644
--- a/iocore/net/P_UDPNet.h
+++ b/iocore/net/P_UDPNet.h
@@ -231,9 +231,12 @@ public:
}
}
- if (s != now_slot)
- Debug("v_udpnet-service", "Advancing by (%d slots): behind by %" PRId64
" ms", s - now_slot,
- ink_hrtime_to_msec(t - delivery_time[now_slot]));
+ if (s != now_slot) {
+ static DbgCtl dbg_ctl{"v_udpnet-service"};
+ Dbg(dbg_ctl, "Advancing by (%d slots): behind by %" PRId64 " ms", s -
now_slot,
+ ink_hrtime_to_msec(t - delivery_time[now_slot]));
+ }
+
now_slot = s;
}
diff --git a/iocore/net/P_UnixNet.h b/iocore/net/P_UnixNet.h
index 36e8b78623..6dce358cc2 100644
--- a/iocore/net/P_UnixNet.h
+++ b/iocore/net/P_UnixNet.h
@@ -232,7 +232,8 @@ read_disable(NetHandler *nh, NetEvent *ne)
// Clear the next scheduled inactivity time, but don't clear
inactivity_timeout_in,
// so the current timeout is used when the NetEvent is reenabled and not
the default inactivity timeout
ne->next_inactivity_timeout_at = 0;
- Debug("socket", "read_disable updating inactivity_at %" PRId64 ",
NetEvent=%p", ne->next_inactivity_timeout_at, ne);
+ Dbg(NetHandler::dbg_ctl_socket, "read_disable updating inactivity_at %"
PRId64 ", NetEvent=%p", ne->next_inactivity_timeout_at,
+ ne);
}
ne->read.enabled = 0;
nh->read_ready_list.remove(ne);
@@ -255,7 +256,8 @@ write_disable(NetHandler *nh, NetEvent *ne)
// Clear the next scheduled inactivity time, but don't clear
inactivity_timeout_in,
// so the current timeout is used when the NetEvent is reenabled and not
the default inactivity timeout
ne->next_inactivity_timeout_at = 0;
- Debug("socket", "write_disable updating inactivity_at %" PRId64 ",
NetEvent=%p", ne->next_inactivity_timeout_at, ne);
+ Dbg(NetHandler::dbg_ctl_socket, "write_disable updating inactivity_at %"
PRId64 ", NetEvent=%p", ne->next_inactivity_timeout_at,
+ ne);
}
ne->write.enabled = 0;
nh->write_ready_list.remove(ne);
diff --git a/iocore/net/P_UnixNetVConnection.h
b/iocore/net/P_UnixNetVConnection.h
index f978c9e2dc..f453d01494 100644
--- a/iocore/net/P_UnixNetVConnection.h
+++ b/iocore/net/P_UnixNetVConnection.h
@@ -228,6 +228,9 @@ public:
private:
virtual void *_prepareForMigration();
virtual NetProcessor *_getNetProcessor();
+
+ inline static DbgCtl _dbg_ctl_socket{"socket"};
+ inline static DbgCtl _dbg_ctl_socket_mptcp{"socket_mptcp"};
};
extern ClassAllocator<UnixNetVConnection> netVCAllocator;
@@ -268,10 +271,10 @@ UnixNetVConnection::set_mptcp_state()
int mptcp_enabled_size = sizeof(mptcp_enabled);
if (0 == safe_getsockopt(con.fd, IPPROTO_TCP, MPTCP_ENABLED, (char
*)&mptcp_enabled, &mptcp_enabled_size)) {
- Debug("socket_mptcp", "MPTCP socket state: %d", mptcp_enabled);
+ Dbg(_dbg_ctl_socket_mptcp, "MPTCP socket state: %d", mptcp_enabled);
mptcp_state = mptcp_enabled > 0 ? true : false;
} else {
- Debug("socket_mptcp", "MPTCP failed getsockopt(): %s", strerror(errno));
+ Dbg(_dbg_ctl_socket_mptcp, "MPTCP failed getsockopt(): %s",
strerror(errno));
}
}
@@ -290,7 +293,7 @@ UnixNetVConnection::get_inactivity_timeout()
inline void
UnixNetVConnection::set_active_timeout(ink_hrtime timeout_in)
{
- Debug("socket", "Set active timeout=%" PRId64 ", NetVC=%p", timeout_in,
this);
+ Dbg(_dbg_ctl_socket, "Set active timeout=%" PRId64 ", NetVC=%p", timeout_in,
this);
active_timeout_in = timeout_in;
next_activity_timeout_at = (active_timeout_in > 0) ? ink_get_hrtime() +
timeout_in : 0;
}
@@ -298,7 +301,7 @@ UnixNetVConnection::set_active_timeout(ink_hrtime
timeout_in)
inline void
UnixNetVConnection::cancel_inactivity_timeout()
{
- Debug("socket", "Cancel inactive timeout for NetVC=%p", this);
+ Dbg(_dbg_ctl_socket, "Cancel inactive timeout for NetVC=%p", this);
inactivity_timeout_in = 0;
next_inactivity_timeout_at = 0;
}
@@ -306,7 +309,7 @@ UnixNetVConnection::cancel_inactivity_timeout()
inline void
UnixNetVConnection::cancel_active_timeout()
{
- Debug("socket", "Cancel active timeout for NetVC=%p", this);
+ Dbg(_dbg_ctl_socket, "Cancel active timeout for NetVC=%p", this);
active_timeout_in = 0;
next_activity_timeout_at = 0;
}
diff --git a/iocore/net/PollCont.cc b/iocore/net/PollCont.cc
index 66fab48b42..e08109c44d 100644
--- a/iocore/net/PollCont.cc
+++ b/iocore/net/PollCont.cc
@@ -25,6 +25,16 @@
#include "PollCont.h"
#include "P_Net.h"
+namespace
+{
+#ifdef DEBUG
+
+DbgCtl dbg_ctl_iocore_net_poll{"iocore_net_poll"};
+DbgCtl dbg_ctl_v_iocore_net_poll{"v_iocore_net_poll"};
+
+#endif
+} // end anonymous namespace
+
PollCont::PollCont(Ptr<ProxyMutex> &m, int pt)
: Continuation(m.get()), net_handler(nullptr), nextPollDescriptor(nullptr),
poll_timeout(pt)
{
@@ -66,9 +76,8 @@ PollCont::do_poll(ink_hrtime timeout)
* read or write) that need processing [ebalsa] */
if (likely(!net_handler->read_ready_list.empty() ||
!net_handler->write_ready_list.empty() ||
!net_handler->read_enable_list.empty() ||
!net_handler->write_enable_list.empty())) {
- NetDebug("iocore_net_poll", "rrq: %d, wrq: %d, rel: %d, wel: %d",
net_handler->read_ready_list.empty(),
- net_handler->write_ready_list.empty(),
net_handler->read_enable_list.empty(),
- net_handler->write_enable_list.empty());
+ NetDbg(dbg_ctl_iocore_net_poll, "rrq: %d, wrq: %d, rel: %d, wel: %d",
net_handler->read_ready_list.empty(),
+ net_handler->write_ready_list.empty(),
net_handler->read_enable_list.empty(), net_handler->write_enable_list.empty());
poll_timeout = 0; // poll immediately returns -- we have triggered stuff
// to process right now
} else if (timeout >= 0) {
@@ -81,15 +90,15 @@ PollCont::do_poll(ink_hrtime timeout)
#if TS_USE_EPOLL
pollDescriptor->result =
epoll_wait(pollDescriptor->epoll_fd,
pollDescriptor->ePoll_Triggered_Events, POLL_DESCRIPTOR_SIZE, poll_timeout);
- NetDebug("v_iocore_net_poll", "[PollCont::pollEvent] epoll_fd: %d, timeout:
%d, results: %d", pollDescriptor->epoll_fd,
- poll_timeout, pollDescriptor->result);
+ NetDbg(dbg_ctl_v_iocore_net_poll, "[PollCont::pollEvent] epoll_fd: %d,
timeout: %d, results: %d", pollDescriptor->epoll_fd,
+ poll_timeout, pollDescriptor->result);
#elif TS_USE_KQUEUE
struct timespec tv;
tv.tv_sec = poll_timeout / 1000;
tv.tv_nsec = 1000000 * (poll_timeout % 1000);
pollDescriptor->result =
kevent(pollDescriptor->kqueue_fd, nullptr, 0,
pollDescriptor->kq_Triggered_Events, POLL_DESCRIPTOR_SIZE, &tv);
- NetDebug("v_iocore_net_poll", "[PollCont::pollEvent] kqueue_fd: %d, timeout:
%d, results: %d", pollDescriptor->kqueue_fd,
- poll_timeout, pollDescriptor->result);
+ NetDbg(dbg_ctl_v_iocore_net_poll, "[PollCont::pollEvent] kqueue_fd: %d,
timeout: %d, results: %d", pollDescriptor->kqueue_fd,
+ poll_timeout, pollDescriptor->result);
#endif
}
diff --git a/iocore/net/QUICNetProcessor.cc b/iocore/net/QUICNetProcessor.cc
index f13fe3c3b3..5235b248bd 100644
--- a/iocore/net/QUICNetProcessor.cc
+++ b/iocore/net/QUICNetProcessor.cc
@@ -39,6 +39,15 @@
QUICNetProcessor quic_NetProcessor;
+namespace
+{
+
+DbgCtl dbg_ctl_quic_ps{"quic_ps"};
+DbgCtl dbg_ctl_udpnet{"udpnet"};
+DbgCtl dbg_ctl_iocore_net_processor{"iocore_net_processor"};
+
+} // end anonymous namespace
+
QUICNetProcessor::QUICNetProcessor() {}
QUICNetProcessor::~QUICNetProcessor()
@@ -68,7 +77,7 @@ QUICNetProcessor::start(int, size_t stacksize)
#ifdef TLS1_3_VERSION_DRAFT_TXT
// FIXME: remove this when TLS1_3_VERSION_DRAFT_TXT is removed
- Debug("quic_ps", "%s", TLS1_3_VERSION_DRAFT_TXT);
+ Dbg(dbg_ctl_quick_ps, "%s", TLS1_3_VERSION_DRAFT_TXT);
#endif
return 0;
@@ -107,7 +116,7 @@ QUICNetProcessor::allocate_vc(EThread *t)
Action *
QUICNetProcessor::connect_re(Continuation *cont, sockaddr const *remote_addr,
NetVCOptions const &opt)
{
- Debug("quic_ps", "connect to server");
+ Dbg(dbg_ctl_quick_ps, "connect to server");
EThread *t = cont->mutex->thread_holding;
ink_assert(t);
QUICNetVConnection *vc = static_cast<QUICNetVConnection
*>(this->allocate_vc(t));
@@ -124,7 +133,7 @@ QUICNetProcessor::connect_re(Continuation *cont, sockaddr
const *remote_addr, Ne
// Setup UDPConnection
UnixUDPConnection *con = new UnixUDPConnection(fd);
- Debug("quic_ps", "con=%p fd=%d", con, fd);
+ Dbg(dbg_ctl_quick_ps, "con=%p fd=%d", con, fd);
this->_rtable = new QUICResetTokenTable();
QUICPacketHandlerOut *packet_handler = new
QUICPacketHandlerOut(*this->_rtable);
@@ -139,7 +148,7 @@ QUICNetProcessor::connect_re(Continuation *cont, sockaddr
const *remote_addr, Ne
errno = 0;
int res = con->ep.start(pd, con, EVENTIO_READ);
if (res < 0) {
- Debug("udpnet", "Error: %s (%d)", strerror(errno), errno);
+ Dbg(dbg_ctl_udpnet, "Error: %s (%d)", strerror(errno), errno);
}
// Setup QUICNetVConnection
@@ -182,8 +191,8 @@ Action *
QUICNetProcessor::main_accept(Continuation *cont, SOCKET fd, AcceptOptions
const &opt)
{
// UnixNetProcessor *this_unp = static_cast<UnixNetProcessor *>(this);
- Debug("iocore_net_processor", "NetProcessor::main_accept - port
%d,recv_bufsize %d, send_bufsize %d, sockopt 0x%0x",
- opt.local_port, opt.recv_bufsize, opt.send_bufsize, opt.sockopt_flags);
+ Dbg(dbg_ctl_iocore_net_processor, "NetProcessor::main_accept - port
%d,recv_bufsize %d, send_bufsize %d, sockopt 0x%0x",
+ opt.local_port, opt.recv_bufsize, opt.send_bufsize, opt.sockopt_flags);
ProxyMutex *mutex = this_ethread()->mutex.get();
int accept_threads = opt.accept_threads; // might be changed.
diff --git a/iocore/net/QUICPacketHandler.cc b/iocore/net/QUICPacketHandler.cc
index dcb491d0f0..a0c1013a62 100644
--- a/iocore/net/QUICPacketHandler.cc
+++ b/iocore/net/QUICPacketHandler.cc
@@ -37,17 +37,22 @@
#include "QUICMultiCertConfigLoader.h"
#include "QUICTLS.h"
-static constexpr char debug_tag[] = "quic_sec";
-static constexpr char v_debug_tag[] = "v_quic_sec";
+namespace
+{
+
+DbgCtl dbg_ctl{"quic_sec"};
+DbgCtl dbg_ctl_v{"v_quic_sec"};
+DbgCtl dbg_ctl_quick_ph{"quic_ph"};
+
+} // end anonymous namespace
-#define QUICDebug(fmt, ...) Debug(debug_tag, fmt, ##__VA_ARGS__)
-#define QUICQCDebug(qc, fmt, ...) Debug(debug_tag, "[%s] " fmt,
qc->cids().data(), ##__VA_ARGS__)
+#define QUICDebug(fmt, ...) Dbg(dbg_ctl, fmt, ##__VA_ARGS__)
+#define QUICQCDebug(qc, fmt, ...) Dbg(dbg_ctl, "[%s] " fmt, qc->cids().data(),
##__VA_ARGS__)
// ["local dcid" - "local scid"]
-#define QUICPHDebug(dcid, scid, fmt, ...) \
- Debug(debug_tag, "[%08" PRIx32 "-%08" PRIx32 "] " fmt, dcid.h32(),
scid.h32(), ##__VA_ARGS__)
+#define QUICPHDebug(dcid, scid, fmt, ...) Dbg(dbg_ctl, "[%08" PRIx32 "-%08"
PRIx32 "] " fmt, dcid.h32(), scid.h32(), ##__VA_ARGS__)
#define QUICVPHDebug(dcid, scid, fmt, ...) \
- Debug(v_debug_tag, "[%08" PRIx32 "-%08" PRIx32 "] " fmt, dcid.h32(),
scid.h32(), ##__VA_ARGS__)
+ Dbg(dbg_ctl_v, "[%08" PRIx32 "-%08" PRIx32 "] " fmt, dcid.h32(), scid.h32(),
##__VA_ARGS__)
//
// QUICPacketHandler
@@ -102,7 +107,7 @@ QUICPacketHandler::_send_packet(UDPConnection *udp_con,
IpEndpoint &addr, Ptr<IO
{
UDPPacket *udp_packet = UDPPacket::new_UDPPacket(addr, 0, udp_payload);
- if (is_debug_tag_set(v_debug_tag)) {
+ if (dbg_ctl_v.on()) {
ip_port_text_buffer ipb;
QUICConnectionId dcid = QUICConnectionId::ZERO();
QUICConnectionId scid = QUICConnectionId::ZERO();
@@ -257,7 +262,7 @@ QUICPacketHandlerIn::_recv_packet(int event, UDPPacket
*udp_packet)
return;
}
- if (is_debug_tag_set(v_debug_tag)) {
+ if (dbg_ctl_v.on()) {
ip_port_text_buffer ipb_from;
ip_port_text_buffer ipb_to;
QUICVPHDebug(scid, dcid, "recv LH packet from %s to %s size=%" PRId64,
@@ -299,7 +304,7 @@ QUICPacketHandlerIn::_recv_packet(int event, UDPPacket
*udp_packet)
}
} else {
// TODO: lookup DCID by 5-tuple when ATS omits SCID
- if (is_debug_tag_set(v_debug_tag)) {
+ if (dbg_ctl_v.on()) {
ip_port_text_buffer ipb_from;
ip_port_text_buffer ipb_to;
QUICVPHDebug(scid, dcid, "recv SH packet from %s to %s size=%" PRId64,
@@ -339,7 +344,7 @@ QUICPacketHandlerIn::_recv_packet(int event, UDPPacket
*udp_packet)
this->_send_stateless_reset(dcid, params->instance_id(),
udp_packet->getConnection(), udp_packet->from, buf_len - 1);
udp_packet->free();
- if (is_debug_tag_set(debug_tag) && sent) {
+ if (dbg_ctl.on() && sent) {
QUICPHDebug(scid, dcid, "sent Stateless Reset : connection not found,
dcid=%s", dcid.hex().c_str());
}
@@ -350,7 +355,7 @@ QUICPacketHandlerIn::_recv_packet(int event, UDPPacket
*udp_packet)
this->_send_stateless_reset(dcid, params->instance_id(),
udp_packet->getConnection(), udp_packet->from, buf_len - 1);
udp_packet->free();
- if (is_debug_tag_set(debug_tag) && sent) {
+ if (dbg_ctl.on() && sent) {
QUICPHDebug(scid, dcid, "sent Stateless Reset : connection is already
closed, dcid=%s", dcid.hex().c_str());
}
@@ -367,7 +372,7 @@ QUICPacketHandlerIn::_recv_packet(int event, UDPPacket
*udp_packet)
QUICConnectionId original_cid = dcid;
QUICConnectionId peer_cid = scid;
- if (is_debug_tag_set("quic_sec")) {
+ if (dbg_ctl.on()) {
QUICPHDebug(peer_cid, original_cid, "client initial dcid=%s",
original_cid.hex().c_str());
}
@@ -555,7 +560,7 @@ QUICPacketHandlerOut::event_handler(int event, Event *data)
return EVENT_CONT;
}
default:
- Debug("quic_ph", "Unknown Event (%d)", event);
+ Dbg(dbg_ctl_quic_ph, "Unknown Event (%d)", event);
break;
}
@@ -576,7 +581,7 @@ QUICPacketHandlerOut::_recv_packet(int event, UDPPacket
*udp_packet)
const uint8_t *buf = reinterpret_cast<uint8_t *>(block->buf());
uint64_t buf_len = block->size();
- if (is_debug_tag_set(debug_tag)) {
+ if (dbg_ctl.on()) {
ip_port_text_buffer ipb_from;
ip_port_text_buffer ipb_to;
QUICQCDebug(this->_vc, "recv %s packet from %s to %s size=%" PRId64,
(QUICInvariants::is_long_header(buf) ? "LH" : "SH"),
diff --git a/iocore/net/SNIActionPerformer.cc b/iocore/net/SNIActionPerformer.cc
index 46445cf572..7d3f93ec88 100644
--- a/iocore/net/SNIActionPerformer.cc
+++ b/iocore/net/SNIActionPerformer.cc
@@ -46,9 +46,9 @@ ControlQUIC::SNIAction(TLSSNISupport *snis, const Context
&ctx) const
return SSL_TLSEXT_ERR_OK;
}
- if (is_debug_tag_set("ssl_sni")) {
+ if (dbg_ctl_ssl_sni.on()) {
const char *servername = quic_vc->get_server_name();
- Debug("ssl_sni", "Rejecting handshake due to QUIC being disabled for fqdn
[%s]", servername);
+ Dbg(dbg_ctl_ssl_sni, "Rejecting handshake due to QUIC being disabled for
fqdn [%s]", servername);
}
return SSL_TLSEXT_ERR_ALERT_FATAL;
@@ -84,11 +84,11 @@ SNI_IpAllow::load(swoc::TextView content, swoc::TextView
server_name)
while (!content.ltrim(delim).empty()) {
swoc::TextView token{content.take_prefix_at(delim)};
if (swoc::IPRange r; r.load(token)) {
- Debug("ssl_sni", "%.*s is not a valid format",
static_cast<int>(token.size()), token.data());
+ Dbg(dbg_ctl_ssl_sni, "%.*s is not a valid format",
static_cast<int>(token.size()), token.data());
break;
} else {
- Debug("ssl_sni", "%.*s added to the ip_allow token %.*s",
static_cast<int>(token.size()), token.data(),
- int(server_name.size()), server_name.data());
+ Dbg(dbg_ctl_ssl_sni, "%.*s added to the ip_allow token %.*s",
static_cast<int>(token.size()), token.data(),
+ int(server_name.size()), server_name.data());
ip_addrs.fill(r);
}
}
@@ -111,7 +111,7 @@ SNI_IpAllow::SNIAction(TLSSNISupport *snis,
ActionItem::Context const &ctx) cons
} else {
swoc::LocalBufferWriter<256> w;
w.print("{} is not allowed - denying connection\0", ip);
- Debug("ssl_sni", "%s", w.data());
+ Dbg(dbg_ctl_ssl_sni, "%s", w.data());
return SSL_TLSEXT_ERR_ALERT_FATAL;
}
}
diff --git a/iocore/net/SNIActionPerformer.h b/iocore/net/SNIActionPerformer.h
index ba40c73a26..d06e40df5d 100644
--- a/iocore/net/SNIActionPerformer.h
+++ b/iocore/net/SNIActionPerformer.h
@@ -34,6 +34,7 @@
#include <optional>
#include "TLSSNISupport.h"
#include "tscore/ink_inet.h"
+#include "ts/DbgCtl.h"
class ActionItem
{
@@ -66,4 +67,7 @@ public:
return false;
}
virtual ~ActionItem(){};
+
+protected:
+ inline static DbgCtl dbg_ctl_ssl_sni{"ssl_sni"};
};
diff --git a/iocore/net/SSLDiags.h b/iocore/net/SSLDiags.h
index 0301e9bc41..3c7aadddb1 100644
--- a/iocore/net/SSLDiags.h
+++ b/iocore/net/SSLDiags.h
@@ -40,10 +40,10 @@ void SSLDiagnostic(const SourceLocation &loc, bool debug,
SSLNetVConnection *vc,
const char *SSLErrorName(int ssl_error);
// Log a SSL network buffer. TAG must be a C-string literal debug tag.
-#define SSLDebugBufferPrint(TAG, BUFFER, BUFFER_LEN, MESSAGE) \
- do { \
- if (is_debug_tag_set(TAG)) \
- SSLDebugBufferPrint_(BUFFER, BUFFER_LEN, MESSAGE); \
+#define SSLDebugBufferPrint(DBG_CTL, BUFFER, BUFFER_LEN, MESSAGE) \
+ do { \
+ if ((DBG_CTL).on()) \
+ SSLDebugBufferPrint_(BUFFER, BUFFER_LEN, MESSAGE); \
} while (0)
void SSLDebugBufferPrint_(const char *buffer, unsigned buflen, const char
*message);
diff --git a/iocore/net/SSLNetVConnection.cc b/iocore/net/SSLNetVConnection.cc
index 3f732481ca..4e4fcdab6e 100644
--- a/iocore/net/SSLNetVConnection.cc
+++ b/iocore/net/SSLNetVConnection.cc
@@ -76,6 +76,20 @@ ClassAllocator<SSLNetVConnection>
sslNetVCAllocator("sslNetVCAllocator");
namespace
{
+DbgCtl dbg_ctl_ssl_early_data{"ssl_early_data"};
+DbgCtl dbg_ctl_ssl_early_data_show_received{"ssl_early_data_show_received"};
+DbgCtl dbg_ctl_ssl{"ssl"};
+DbgCtl dbg_ctl_v_ssl{"v_ssl"};
+DbgCtl dbg_ctl_ssl_error{"ssl.error"};
+DbgCtl dbg_ctl_ssl_error_accept{"ssl.error.accept"};
+DbgCtl dbg_ctl_ssl_error_connect{"ssl.error.connect"};
+DbgCtl dbg_ctl_ssl_error_write{"ssl.error.write"};
+DbgCtl dbg_ctl_ssl_error_read{"ssl.error.read"};
+DbgCtl dbg_ctl_ssl_shutdown{"ssl-shutdown"};
+DbgCtl dbg_ctl_ssl_alpn{"ssl_alpn"};
+DbgCtl dbg_ctl_ssl_origin_session_cache{"ssl.origin_session_cache"};
+DbgCtl dbg_ctl_proxyprotocol{"proxyprotocol"};
+
/// Callback to get two locks.
/// The lock for this continuation, and for the target continuation.
class ContWrapper : public Continuation
@@ -260,7 +274,7 @@ debug_certificate_name(const char *msg, X509_NAME *name)
long len;
char *ptr;
len = BIO_get_mem_data(bio, &ptr);
- Debug("ssl", "%s %.*s", msg, (int)len, ptr);
+ Dbg(dbg_ctl_ssl, "%s %.*s", msg, (int)len, ptr);
}
BIO_free(bio);
@@ -291,18 +305,20 @@ SSLNetVConnection::_ssl_read_from_net(EThread *lthread,
int64_t &ret)
amount_to_read = block_write_avail;
}
- Debug("ssl", "amount_to_read=%" PRId64, amount_to_read);
+ Dbg(dbg_ctl_ssl, "amount_to_read=%" PRId64, amount_to_read);
char *current_block = buf.writer()->end();
ink_release_assert(current_block != nullptr);
sslErr = this->_ssl_read_buffer(current_block, amount_to_read, nread);
- Debug("ssl", "nread=%" PRId64, nread);
+ Dbg(dbg_ctl_ssl, "nread=%" PRId64, nread);
switch (sslErr) {
case SSL_ERROR_NONE:
-
#if DEBUG
- SSLDebugBufferPrint("ssl_buff", current_block, nread, "SSL Read");
+ {
+ static DbgCtl dbg_ctl{"ssl_buff"};
+ SSLDebugBufferPrint(dbg_ctl, current_block, nread, "SSL Read");
+ }
#endif
ink_assert(nread);
bytes_read += nread;
@@ -313,21 +329,21 @@ SSLNetVConnection::_ssl_read_from_net(EThread *lthread,
int64_t &ret)
break;
case SSL_ERROR_WANT_WRITE:
event = SSL_WRITE_WOULD_BLOCK;
- Debug("ssl.error", "SSL_ERROR_WOULD_BLOCK(write)");
+ Dbg(dbg_ctl_ssl_error, "SSL_ERROR_WOULD_BLOCK(write)");
break;
case SSL_ERROR_WANT_READ:
event = SSL_READ_WOULD_BLOCK;
- Debug("ssl.error", "SSL_ERROR_WOULD_BLOCK(read)");
+ Dbg(dbg_ctl_ssl_error, "SSL_ERROR_WOULD_BLOCK(read)");
break;
#ifdef SSL_ERROR_WANT_CLIENT_HELLO_CB
case SSL_ERROR_WANT_CLIENT_HELLO_CB:
event = SSL_READ_WOULD_BLOCK;
- Debug("ssl.error", "SSL_ERROR_WOULD_BLOCK(read/client hello cb)");
+ Dbg(dbg_ctl_ssl_error, "SSL_ERROR_WOULD_BLOCK(read/client hello cb)");
break;
#endif
case SSL_ERROR_WANT_X509_LOOKUP:
event = SSL_READ_WOULD_BLOCK;
- Debug("ssl.error", "SSL_ERROR_WOULD_BLOCK(read/x509 lookup)");
+ Dbg(dbg_ctl_ssl_error, "SSL_ERROR_WOULD_BLOCK(read/x509 lookup)");
break;
case SSL_ERROR_SYSCALL:
if (nread != 0) {
@@ -335,7 +351,7 @@ SSLNetVConnection::_ssl_read_from_net(EThread *lthread,
int64_t &ret)
SSL_INCREMENT_DYN_STAT(ssl_error_syscall);
event = SSL_READ_ERROR;
ret = errno;
- Debug("ssl.error", "SSL_ERROR_SYSCALL, underlying IO error: %s",
strerror(errno));
+ Dbg(dbg_ctl_ssl_error, "SSL_ERROR_SYSCALL, underlying IO error: %s",
strerror(errno));
} else {
// then EOF observed, treat it as EOS
event = SSL_READ_EOS;
@@ -343,7 +359,7 @@ SSLNetVConnection::_ssl_read_from_net(EThread *lthread,
int64_t &ret)
break;
case SSL_ERROR_ZERO_RETURN:
event = SSL_READ_EOS;
- Debug("ssl.error", "SSL_ERROR_ZERO_RETURN");
+ Dbg(dbg_ctl_ssl_error, "SSL_ERROR_ZERO_RETURN");
break;
case SSL_ERROR_SSL:
default: {
@@ -358,7 +374,7 @@ SSLNetVConnection::_ssl_read_from_net(EThread *lthread,
int64_t &ret)
} // while
if (bytes_read > 0) {
- Debug("ssl", "bytes_read=%" PRId64, bytes_read);
+ Dbg(dbg_ctl_ssl, "bytes_read=%" PRId64, bytes_read);
s->vio.ndone += bytes_read;
this->netActivity(lthread);
@@ -374,7 +390,7 @@ SSLNetVConnection::_ssl_read_from_net(EThread *lthread,
int64_t &ret)
} else { // if( bytes_read > 0 )
#if defined(_DEBUG)
if (bytes_read == 0) {
- Debug("ssl", "bytes_read == 0");
+ Dbg(dbg_ctl_ssl, "bytes_read == 0");
}
#endif
}
@@ -406,8 +422,8 @@ SSLNetVConnection::read_raw_data()
NET_INCREMENT_DYN_STAT(net_calls_to_read_stat);
total_read += rattempted;
- Debug("ssl", "read_raw_data r=%" PRId64 " rattempted=%" PRId64 "
total_read=%" PRId64 " fd=%d", r, rattempted, total_read,
- con.fd);
+ Dbg(dbg_ctl_ssl, "read_raw_data r=%" PRId64 " rattempted=%" PRId64 "
total_read=%" PRId64 " fd=%d", r, rattempted, total_read,
+ con.fd);
// last read failed or was incomplete
if (r != rattempted || !b) {
break;
@@ -431,40 +447,40 @@ SSLNetVConnection::read_raw_data()
pp_ipmap = SSLConfigParams::proxy_protocol_ip_addrs;
if (this->get_is_proxy_protocol() && this->get_proxy_protocol_version() ==
ProxyProtocolVersion::UNDEFINED) {
- Debug("proxyprotocol", "proxy protocol is enabled on this port");
+ Dbg(dbg_ctl_proxyprotocol, "proxy protocol is enabled on this port");
if (pp_ipmap->count() > 0) {
- Debug("proxyprotocol", "proxy protocol has a configured allowlist of
trusted IPs - checking");
+ Dbg(dbg_ctl_proxyprotocol, "proxy protocol has a configured allowlist of
trusted IPs - checking");
// At this point, using get_remote_addr() will return the ip of the
// proxy source IP, not the Proxy Protocol client ip. Since we are
// checking the ip of the actual source of this connection, this is
// what we want now.
if (!pp_ipmap->contains(swoc::IPAddr(get_remote_addr()))) {
- Debug("proxyprotocol", "Source IP is NOT in the configured allowlist
of trusted IPs - closing connection");
+ Dbg(dbg_ctl_proxyprotocol, "Source IP is NOT in the configured
allowlist of trusted IPs - closing connection");
r = -ENOTCONN; // Need a quick close/exit here to refuse the
connection!!!!!!!!!
goto proxy_protocol_bypass;
} else {
char new_host[INET6_ADDRSTRLEN];
- Debug("proxyprotocol", "Source IP [%s] is in the trusted allowlist for
proxy protocol",
- ats_ip_ntop(this->get_remote_addr(), new_host,
sizeof(new_host)));
+ Dbg(dbg_ctl_proxyprotocol, "Source IP [%s] is in the trusted allowlist
for proxy protocol",
+ ats_ip_ntop(this->get_remote_addr(), new_host, sizeof(new_host)));
}
} else {
- Debug("proxyprotocol", "proxy protocol DOES NOT have a configured
allowlist of trusted IPs but "
- "proxy protocol is enabled on this port -
processing all connections");
+ Dbg(dbg_ctl_proxyprotocol, "proxy protocol DOES NOT have a configured
allowlist of trusted IPs but "
+ "proxy protocol is enabled on this port -
processing all connections");
}
auto const stored_r = r;
if (this->has_proxy_protocol(buffer, &r)) {
- Debug("proxyprotocol", "ssl has proxy protocol header");
- if (is_debug_tag_set("proxyprotocol")) {
+ Dbg(dbg_ctl_proxyprotocol, "ssl has proxy protocol header");
+ if (dbg_ctl_proxyprotocol.on()) {
IpEndpoint dst;
dst.sa = *(this->get_proxy_protocol_dst_addr());
ip_port_text_buffer ipb1;
ats_ip_nptop(&dst, ipb1, sizeof(ipb1));
- Debug("proxyprotocol", "ssl_has_proxy_v1, dest IP received [%s]",
ipb1);
+ DbgPrint(dbg_ctl_proxyprotocol, "ssl_has_proxy_v1, dest IP received
[%s]", ipb1);
}
} else {
- Debug("proxyprotocol", "proxy protocol was enabled, but Proxy Protocol
header was not present");
+ Dbg(dbg_ctl_proxyprotocol, "proxy protocol was enabled, but Proxy
Protocol header was not present");
// We are flexible with the Proxy Protocol designation. Maybe not all
// connections include Proxy Protocol. Revert to the stored value of r so
// we can process the bytes that are on the wire (likely a CLIENT_HELLO).
@@ -490,7 +506,7 @@ proxy_protocol_bypass:
this->handShakeBioStored = 0;
}
- Debug("ssl", "%p read r=%" PRId64 " total=%" PRId64 " bio=%d\n", this, r,
total_read, this->handShakeBioStored);
+ Dbg(dbg_ctl_ssl, "%p read r=%" PRId64 " total=%" PRId64 " bio=%d\n", this,
r, total_read, this->handShakeBioStored);
// check for errors
if (r <= 0) {
@@ -567,7 +583,7 @@ SSLNetVConnection::net_read_io(NetHandler *nh, EThread
*lthread)
if (sslClientRenegotiationAbort == true) {
this->read.triggered = 0;
readSignalError(nh, -ENET_SSL_FAILED);
- Debug("ssl", "client renegotiation setting read signal error");
+ Dbg(dbg_ctl_ssl, "client renegotiation setting read signal error");
return;
}
@@ -635,10 +651,10 @@ SSLNetVConnection::net_read_io(NetHandler *nh, EThread
*lthread)
} else if (ret == SSL_HANDSHAKE_WANT_READ || ret ==
SSL_HANDSHAKE_WANT_ACCEPT) {
if (SSLConfigParams::ssl_handshake_timeout_in > 0) {
double handshake_time = (static_cast<double>(ink_get_hrtime() -
this->get_tls_handshake_begin_time()) / 1000000000);
- Debug("ssl", "ssl handshake for vc %p, took %.3f seconds, configured
handshake_timer: %d", this, handshake_time,
- SSLConfigParams::ssl_handshake_timeout_in);
+ Dbg(dbg_ctl_ssl, "ssl handshake for vc %p, took %.3f seconds,
configured handshake_timer: %d", this, handshake_time,
+ SSLConfigParams::ssl_handshake_timeout_in);
if (handshake_time > SSLConfigParams::ssl_handshake_timeout_in) {
- Debug("ssl", "ssl handshake for vc %p, expired, release the
connection", this);
+ Dbg(dbg_ctl_ssl, "ssl handshake for vc %p, expired, release the
connection", this);
read.triggered = 0;
nh->read_ready_list.remove(this);
readSignalError(nh, ETIMEDOUT);
@@ -660,7 +676,7 @@ SSLNetVConnection::net_read_io(NetHandler *nh, EThread
*lthread)
nh->write_ready_list.remove(this);
writeReschedule(nh);
} else if (ret == EVENT_DONE) {
- Debug("ssl", "ssl handshake EVENT_DONE ntodo=%" PRId64, ntodo);
+ Dbg(dbg_ctl_ssl, "ssl handshake EVENT_DONE ntodo=%" PRId64, ntodo);
// If this was driven by a zero length read, signal complete when
// the handshake is complete. Otherwise set up for continuing read
// operations.
@@ -703,7 +719,7 @@ SSLNetVConnection::net_read_io(NetHandler *nh, EThread
*lthread)
if (bytes > 0) {
if (ret == SSL_READ_WOULD_BLOCK || ret == SSL_READ_READY) {
if (readSignalAndUpdate(VC_EVENT_READ_READY) != EVENT_CONT) {
- Debug("ssl", "readSignal != EVENT_CONT");
+ Dbg(dbg_ctl_ssl, "readSignal != EVENT_CONT");
return;
}
}
@@ -717,7 +733,7 @@ SSLNetVConnection::net_read_io(NetHandler *nh, EThread
*lthread)
case SSL_WRITE_WOULD_BLOCK:
case SSL_READ_WOULD_BLOCK:
if (lock.get_mutex() != s->vio.mutex.get()) {
- Debug("ssl", "mutex switched");
+ Dbg(dbg_ctl_ssl, "mutex switched");
if (ret == SSL_READ_WOULD_BLOCK) {
readReschedule(nh);
} else {
@@ -729,7 +745,7 @@ SSLNetVConnection::net_read_io(NetHandler *nh, EThread
*lthread)
// we will need to be retriggered to read from this socket again
read.triggered = 0;
nh->read_ready_list.remove(this);
- Debug("ssl", "read finished - would block");
+ Dbg(dbg_ctl_ssl, "read finished - would block");
break;
case SSL_READ_EOS:
@@ -740,19 +756,19 @@ SSLNetVConnection::net_read_io(NetHandler *nh, EThread
*lthread)
readSignalDone(VC_EVENT_EOS, nh);
if (bytes > 0) {
- Debug("ssl", "read finished - EOS");
+ Dbg(dbg_ctl_ssl, "read finished - EOS");
} else {
- Debug("ssl", "read finished - 0 useful bytes read, bytes used by SSL
layer");
+ Dbg(dbg_ctl_ssl, "read finished - 0 useful bytes read, bytes used by SSL
layer");
}
break;
case SSL_READ_COMPLETE:
readSignalDone(VC_EVENT_READ_COMPLETE, nh);
- Debug("ssl", "read finished - signal done");
+ Dbg(dbg_ctl_ssl, "read finished - signal done");
break;
case SSL_READ_ERROR:
this->read.triggered = 0;
readSignalError(nh, (ssl_read_errno) ? ssl_read_errno : -ENET_SSL_FAILED);
- Debug("ssl", "read finished - read error");
+ Dbg(dbg_ctl_ssl, "read finished - read error");
break;
}
}
@@ -776,14 +792,15 @@ SSLNetVConnection::load_buffer_and_write(int64_t towrite,
MIOBufferAccessor &buf
// reset sslTotalBytesSent upon inactivity for
SSL_DEF_TLS_RECORD_MSEC_THRESHOLD
sslTotalBytesSent = 0;
}
- Debug("ssl", "now=%" PRId64 " lastwrite=%" PRId64 "
msec_since_last_write=%d", now, sslLastWriteTime, msec_since_last_write);
+ Dbg(dbg_ctl_ssl, "now=%" PRId64 " lastwrite=%" PRId64 "
msec_since_last_write=%d", now, sslLastWriteTime,
+ msec_since_last_write);
}
if (HttpProxyPort::TRANSPORT_BLIND_TUNNEL == this->attributes) {
return this->super::load_buffer_and_write(towrite, buf, total_written,
needs);
}
- Debug("ssl", "towrite=%" PRId64, towrite);
+ Dbg(dbg_ctl_ssl, "towrite=%" PRId64, towrite);
do {
// What is remaining left in the next block?
@@ -829,7 +846,7 @@ SSLNetVConnection::load_buffer_and_write(int64_t towrite,
MIOBufferAccessor &buf
try_to_write = l;
num_really_written = 0;
- Debug("v_ssl", "b=%p l=%" PRId64, current_block, l);
+ Dbg(dbg_ctl_v_ssl, "b=%p l=%" PRId64, current_block, l);
err = this->_ssl_write_buffer(current_block, l, num_really_written);
// We wrote all that we thought we should
@@ -838,8 +855,8 @@ SSLNetVConnection::load_buffer_and_write(int64_t towrite,
MIOBufferAccessor &buf
buf.reader()->consume(num_really_written);
}
- Debug("ssl", "try_to_write=%" PRId64 " written=%" PRId64 "
total_written=%" PRId64, try_to_write, num_really_written,
- total_written);
+ Dbg(dbg_ctl_ssl, "try_to_write=%" PRId64 " written=%" PRId64 "
total_written=%" PRId64, try_to_write, num_really_written,
+ total_written);
NET_INCREMENT_DYN_STAT(net_calls_to_write_stat);
} while (num_really_written == try_to_write && total_written < towrite);
@@ -853,12 +870,12 @@ SSLNetVConnection::load_buffer_and_write(int64_t towrite,
MIOBufferAccessor &buf
} else {
switch (err) {
case SSL_ERROR_NONE:
- Debug("ssl", "SSL_write-SSL_ERROR_NONE");
+ Dbg(dbg_ctl_ssl, "SSL_write-SSL_ERROR_NONE");
break;
case SSL_ERROR_WANT_READ:
needs |= EVENTIO_READ;
num_really_written = -EAGAIN;
- Debug("ssl.error", "SSL_write-SSL_ERROR_WANT_READ");
+ Dbg(dbg_ctl_ssl_error, "SSL_write-SSL_ERROR_WANT_READ");
break;
case SSL_ERROR_WANT_WRITE:
#ifdef SSL_ERROR_WANT_CLIENT_HELLO_CB
@@ -870,7 +887,7 @@ SSLNetVConnection::load_buffer_and_write(int64_t towrite,
MIOBufferAccessor &buf
}
needs |= EVENTIO_WRITE;
num_really_written = -EAGAIN;
- Debug("ssl.error", "SSL_write-SSL_ERROR_WANT_WRITE");
+ Dbg(dbg_ctl_ssl_error, "SSL_write-SSL_ERROR_WANT_WRITE");
break;
}
case SSL_ERROR_SYSCALL:
@@ -878,12 +895,12 @@ SSLNetVConnection::load_buffer_and_write(int64_t towrite,
MIOBufferAccessor &buf
// we do with SSL_ERROR_SSL below, to indicate a connection error.
num_really_written = -EPIPE;
SSL_INCREMENT_DYN_STAT(ssl_error_syscall);
- Debug("ssl.error", "SSL_write-SSL_ERROR_SYSCALL");
+ Dbg(dbg_ctl_ssl_error, "SSL_write-SSL_ERROR_SYSCALL");
break;
// end of stream
case SSL_ERROR_ZERO_RETURN:
num_really_written = -errno;
- Debug("ssl.error", "SSL_write-SSL_ERROR_ZERO_RETURN");
+ Dbg(dbg_ctl_ssl_error, "SSL_write-SSL_ERROR_ZERO_RETURN");
break;
case SSL_ERROR_SSL:
default: {
@@ -919,13 +936,13 @@ SSLNetVConnection::do_io_close(int lerrno)
if (getSSLHandShakeComplete()) {
int shutdown_mode = SSL_get_shutdown(ssl);
- Debug("ssl-shutdown", "previous shutdown state 0x%x", shutdown_mode);
+ Dbg(dbg_ctl_ssl_shutdown, "previous shutdown state 0x%x", shutdown_mode);
int new_shutdown_mode = shutdown_mode | SSL_RECEIVED_SHUTDOWN;
if (new_shutdown_mode != shutdown_mode) {
// We do not need to sit around and wait for the client's close-notify
if
// they have not already sent it. We will still be standards compliant
- Debug("ssl-shutdown", "new SSL_set_shutdown 0x%x", new_shutdown_mode);
+ Dbg(dbg_ctl_ssl_shutdown, "new SSL_set_shutdown 0x%x",
new_shutdown_mode);
SSL_set_shutdown(ssl, new_shutdown_mode);
}
@@ -944,12 +961,12 @@ SSLNetVConnection::do_io_close(int lerrno)
if (do_shutdown) {
// Send the close-notify
int ret = SSL_shutdown(ssl);
- Debug("ssl-shutdown", "SSL_shutdown %s", (ret) ? "success" : "failed");
+ Dbg(dbg_ctl_ssl_shutdown, "SSL_shutdown %s", (ret) ? "success" :
"failed");
} else {
// Request a quiet shutdown to OpenSSL
SSL_set_quiet_shutdown(ssl, 1);
SSL_set_shutdown(ssl, SSL_RECEIVED_SHUTDOWN | SSL_SENT_SHUTDOWN);
- Debug("ssl-shutdown", "Enable quiet shutdown");
+ Dbg(dbg_ctl_ssl_shutdown, "Enable quiet shutdown");
}
}
}
@@ -1038,7 +1055,7 @@ int
SSLNetVConnection::sslStartHandShake(int event, int &err)
{
if (TSSystemState::is_ssl_handshaking_stopped()) {
- Debug("ssl", "Stopping handshake due to server shutting down.");
+ Dbg(dbg_ctl_ssl, "Stopping handshake due to server shutting down.");
return EVENT_ERROR;
}
if (this->get_tls_handshake_begin_time() == 0) {
@@ -1054,22 +1071,22 @@ SSLNetVConnection::sslStartHandShake(int event, int
&err)
IpEndpoint dst;
int namelen = sizeof(dst);
if (0 != safe_getsockname(this->get_socket(), &dst.sa, &namelen)) {
- Debug("ssl", "Failed to get dest ip, errno = [%d]", errno);
+ Dbg(dbg_ctl_ssl, "Failed to get dest ip, errno = [%d]", errno);
return EVENT_ERROR;
}
SSLCertContext *cc = lookup->find(dst);
- if (is_debug_tag_set("ssl")) {
+ if (dbg_ctl_ssl.on()) {
IpEndpoint src;
ip_port_text_buffer ipb1, ipb2;
int ip_len = sizeof(src);
if (0 != safe_getpeername(this->get_socket(), &src.sa, &ip_len)) {
- Debug("ssl", "Failed to get src ip, errno = [%d]", errno);
+ DbgPrint(dbg_ctl_ssl, "Failed to get src ip, errno = [%d]", errno);
return EVENT_ERROR;
}
ats_ip_nptop(&dst, ipb1, sizeof(ipb1));
ats_ip_nptop(&src, ipb2, sizeof(ipb2));
- Debug("ssl", "IP context is %p for [%s] -> [%s], default context %p",
cc, ipb2, ipb1, lookup->defaultContext());
+ DbgPrint(dbg_ctl_ssl, "IP context is %p for [%s] -> [%s], default
context %p", cc, ipb2, ipb1, lookup->defaultContext());
}
// Escape if this is marked to be a tunnel.
@@ -1118,7 +1135,7 @@ SSLNetVConnection::sslStartHandShake(int event, int &err)
SSL_CTX *clientCTX = nullptr;
// First Look to see if there are override parameters
- Debug("ssl", "Checking for outbound client cert override [%p]",
options.ssl_client_cert_name.get());
+ Dbg(dbg_ctl_ssl, "Checking for outbound client cert override [%p]",
options.ssl_client_cert_name.get());
if (options.ssl_client_cert_name) {
std::string certFilePath;
std::string keyFilePath;
@@ -1133,9 +1150,9 @@ SSLNetVConnection::sslStartHandShake(int event, int &err)
if (options.ssl_client_ca_cert_name) {
caCertFilePath =
Layout::get()->relative_to(params->clientCACertPath,
options.ssl_client_ca_cert_name);
}
- Debug("ssl", "Using outbound client cert `%s'",
options.ssl_client_cert_name.get());
+ Dbg(dbg_ctl_ssl, "Using outbound client cert `%s'",
options.ssl_client_cert_name.get());
} else {
- Debug("ssl", "Clearing outbound client cert");
+ Dbg(dbg_ctl_ssl, "Clearing outbound client cert");
}
sharedCTX =
params->getCTX(certFilePath, keyFilePath, caCertFilePath.empty() ?
params->clientCACertFilename : caCertFilePath.c_str(),
@@ -1198,9 +1215,9 @@ SSLNetVConnection::sslStartHandShake(int event, int &err)
ats_scoped_str &tlsext_host_name = this->options.sni_hostname ?
this->options.sni_hostname : this->options.sni_servername;
if (tlsext_host_name) {
if (SSL_set_tlsext_host_name(this->ssl, tlsext_host_name)) {
- Debug("ssl", "using SNI name '%s' for client handshake",
tlsext_host_name.get());
+ Dbg(dbg_ctl_ssl, "using SNI name '%s' for client handshake",
tlsext_host_name.get());
} else {
- Debug("ssl.error", "failed to set SNI name '%s' for client
handshake", tlsext_host_name.get());
+ Dbg(dbg_ctl_ssl_error, "failed to set SNI name '%s' for client
handshake", tlsext_host_name.get());
SSL_INCREMENT_DYN_STAT(ssl_sni_name_set_failure);
}
}
@@ -1210,8 +1227,8 @@ SSLNetVConnection::sslStartHandShake(int event, int &err)
if (int res = SSL_set_alpn_protos(this->ssl, reinterpret_cast<const
uint8_t *>(this->options.alpn_protos.data()),
this->options.alpn_protos.size());
res != 0) {
- Debug("ssl.error", "failed to set ALPN '%.*s' for client handshake",
static_cast<int>(this->options.alpn_protos.size()),
- this->options.alpn_protos.data());
+ Dbg(dbg_ctl_ssl_error, "failed to set ALPN '%.*s' for client
handshake",
+ static_cast<int>(this->options.alpn_protos.size()),
this->options.alpn_protos.data());
}
}
}
@@ -1237,7 +1254,7 @@ SSLNetVConnection::sslServerHandShakeEvent(int &err)
if (sslHandshakeHookState == HANDSHAKE_HOOKS_PRE) {
SSL_INCREMENT_DYN_STAT(ssl_total_attempts_handshake_count_in_stat);
if (!curHook) {
- Debug("ssl", "Initialize preaccept curHook from NULL");
+ Dbg(dbg_ctl_ssl, "Initialize preaccept curHook from NULL");
curHook = ssl_hooks->get(TSSslHookInternalID(TS_VCONN_START_HOOK));
} else {
curHook = curHook->next();
@@ -1272,7 +1289,7 @@ SSLNetVConnection::sslServerHandShakeEvent(int &err)
return EVENT_DONE;
}
- Debug("ssl", "Go on with the handshake state=%s",
get_ssl_handshake_hook_state_name(sslHandshakeHookState));
+ Dbg(dbg_ctl_ssl, "Go on with the handshake state=%s",
get_ssl_handshake_hook_state_name(sslHandshakeHookState));
// All the pre-accept hooks have completed, proceed with the actual accept.
if (this->handShakeReader) {
@@ -1285,7 +1302,7 @@ SSLNetVConnection::sslServerHandShakeEvent(int &err)
}
#endif
- Debug("ssl", "%p first read\n", this);
+ Dbg(dbg_ctl_ssl, "%p first read\n", this);
// Read from socket to fill in the BIO buffer with the
// raw handshake data before calling the ssl accept calls.
int retval = this->read_raw_data();
@@ -1355,14 +1372,14 @@ SSLNetVConnection::sslServerHandShakeEvent(int &err)
switch (ssl_error) {
case SSL_ERROR_NONE:
- if (is_debug_tag_set("ssl")) {
+ if (dbg_ctl_ssl.on()) {
#ifdef OPENSSL_IS_OPENSSL3
X509 *cert = SSL_get1_peer_certificate(ssl);
#else
X509 *cert = SSL_get_peer_certificate(ssl);
#endif
- Debug("ssl", "SSL server handshake completed successfully");
+ DbgPrint(dbg_ctl_ssl, "SSL server handshake completed successfully");
if (cert) {
debug_certificate_name("client certificate subject CN is",
X509_get_subject_name(cert));
debug_certificate_name("client certificate issuer CN is",
X509_get_issuer_name(cert));
@@ -1406,9 +1423,9 @@ SSLNetVConnection::sslServerHandShakeEvent(int &err)
}
this->set_negotiated_protocol_id({reinterpret_cast<const char
*>(proto), static_cast<size_t>(len)});
- Debug("ssl", "Origin selected next protocol '%.*s'", len, proto);
+ Dbg(dbg_ctl_ssl, "Origin selected next protocol '%.*s'", len, proto);
} else {
- Debug("ssl", "Origin did not select a next protocol");
+ Dbg(dbg_ctl_ssl, "Origin did not select a next protocol");
}
}
@@ -1528,7 +1545,7 @@ SSLNetVConnection::sslClientHandShakeEvent(int &err)
if (sslHandshakeHookState == HANDSHAKE_HOOKS_OUTBOUND_PRE) {
SSL_INCREMENT_DYN_STAT(ssl_total_attempts_handshake_count_out_stat);
if (!curHook) {
- Debug("ssl", "Initialize outbound connect curHook from NULL");
+ Dbg(dbg_ctl_ssl, "Initialize outbound connect curHook from NULL");
curHook =
ssl_hooks->get(TSSslHookInternalID(TS_VCONN_OUTBOUND_START_HOOK));
} else {
curHook = curHook->next();
@@ -1544,14 +1561,14 @@ SSLNetVConnection::sslClientHandShakeEvent(int &err)
ssl_error = this->_ssl_connect();
switch (ssl_error) {
case SSL_ERROR_NONE:
- if (is_debug_tag_set("ssl")) {
+ if (dbg_ctl_ssl.on()) {
#ifdef OPENSSL_IS_OPENSSL3
X509 *cert = SSL_get1_peer_certificate(ssl);
#else
X509 *cert = SSL_get_peer_certificate(ssl);
#endif
- Debug("ssl", "SSL client handshake completed successfully");
+ DbgPrint(dbg_ctl_ssl, "SSL client handshake completed successfully");
if (cert) {
debug_certificate_name("server certificate subject CN is",
X509_get_subject_name(cert));
@@ -1567,7 +1584,7 @@ SSLNetVConnection::sslClientHandShakeEvent(int &err)
if (len == 0) {
SSL_get0_next_proto_negotiated(ssl, &proto, &len);
}
- Debug("ssl_alpn", "Negotiated ALPN: %.*s", len, proto);
+ Dbg(dbg_ctl_ssl_alpn, "Negotiated ALPN: %.*s", len, proto);
this->set_negotiated_protocol_id({reinterpret_cast<const char *>(proto),
static_cast<size_t>(len)});
}
@@ -1582,19 +1599,19 @@ SSLNetVConnection::sslClientHandShakeEvent(int &err)
return EVENT_DONE;
case SSL_ERROR_WANT_WRITE:
- Debug("ssl.error", "SSL_ERROR_WANT_WRITE");
+ Dbg(dbg_ctl_ssl_error, "SSL_ERROR_WANT_WRITE");
return SSL_HANDSHAKE_WANT_WRITE;
case SSL_ERROR_WANT_READ:
- Debug("ssl.error", "SSL_ERROR_WANT_READ");
+ Dbg(dbg_ctl_ssl_error, "SSL_ERROR_WANT_READ");
return SSL_HANDSHAKE_WANT_READ;
#ifdef SSL_ERROR_WANT_CLIENT_HELLO_CB
case SSL_ERROR_WANT_CLIENT_HELLO_CB:
- Debug("ssl.error", "SSL_ERROR_WANT_CLIENT_HELLO_CB");
+ Dbg(dbg_ctl_ssl_error, "SSL_ERROR_WANT_CLIENT_HELLO_CB");
break;
#endif
case SSL_ERROR_WANT_X509_LOOKUP:
- Debug("ssl.error", "SSL_ERROR_WANT_X509_LOOKUP");
+ Dbg(dbg_ctl_ssl_error, "SSL_ERROR_WANT_X509_LOOKUP");
break;
case SSL_ERROR_WANT_ACCEPT:
@@ -1604,13 +1621,13 @@ SSLNetVConnection::sslClientHandShakeEvent(int &err)
break;
case SSL_ERROR_ZERO_RETURN:
- Debug("ssl.error", "EOS");
+ Dbg(dbg_ctl_ssl_error, "EOS");
return EVENT_ERROR;
case SSL_ERROR_SYSCALL:
err = errno;
SSL_INCREMENT_DYN_STAT(ssl_error_syscall);
- Debug("ssl.error", "syscall");
+ Dbg(dbg_ctl_ssl_error, "syscall");
return EVENT_ERROR;
break;
@@ -1622,14 +1639,14 @@ SSLNetVConnection::sslClientHandShakeEvent(int &err)
ERR_error_string_n(e, buf, sizeof(buf));
// FIXME -- This triggers a retry on cases of cert validation errors....
SSL_CLR_ERR_INCR_DYN_STAT(this, ssl_error_ssl, "SSL_ERROR_SSL errno=%d",
errno);
- Debug("ssl.error", "SSL_ERROR_SSL");
+ Dbg(dbg_ctl_ssl_error, "SSL_ERROR_SSL");
if (e) {
if (this->options.sni_servername) {
- Debug("ssl.error", "SSL connection failed for '%s': %s",
this->options.sni_servername.get(), buf);
+ Dbg(dbg_ctl_ssl_error, "SSL connection failed for '%s': %s",
this->options.sni_servername.get(), buf);
} else {
char buff[INET6_ADDRSTRLEN];
ats_ip_ntop(this->get_remote_addr(), buff, INET6_ADDRSTRLEN);
- Debug("ssl.error", "SSL connection failed for '%s': %s", buff, buf);
+ Dbg(dbg_ctl_ssl_error, "SSL connection failed for '%s': %s", buff,
buf);
}
}
return EVENT_ERROR;
@@ -1641,7 +1658,7 @@ SSLNetVConnection::sslClientHandShakeEvent(int &err)
void
SSLNetVConnection::reenable(NetHandler *nh, int event)
{
- Debug("ssl", "Handshake reenable from state=%s",
get_ssl_handshake_hook_state_name(sslHandshakeHookState));
+ Dbg(dbg_ctl_ssl, "Handshake reenable from state=%s",
get_ssl_handshake_hook_state_name(sslHandshakeHookState));
// Mark as error to stop the Handshake
if (event == TS_EVENT_ERROR) {
@@ -1677,7 +1694,7 @@ SSLNetVConnection::reenable(NetHandler *nh, int event)
// here in the reenable.
if (curHook != nullptr) {
curHook = curHook->next();
- Debug("ssl", "iterate from reenable curHook=%p", curHook);
+ Dbg(dbg_ctl_ssl, "iterate from reenable curHook=%p", curHook);
}
if (curHook != nullptr) {
// Invoke the hook and return, wait for next reenable
@@ -1693,11 +1710,11 @@ SSLNetVConnection::reenable(NetHandler *nh, int event)
} else if (sslHandshakeHookState == HANDSHAKE_HOOKS_SNI) {
curHook->invoke(TS_EVENT_SSL_SERVERNAME, this);
} else if (sslHandshakeHookState == HANDSHAKE_HOOKS_PRE) {
- Debug("ssl", "Reenable preaccept");
+ Dbg(dbg_ctl_ssl, "Reenable preaccept");
sslHandshakeHookState = HANDSHAKE_HOOKS_PRE_INVOKE;
ContWrapper::wrap(nh->mutex.get(), curHook->m_cont,
TS_EVENT_VCONN_START, this);
} else if (sslHandshakeHookState == HANDSHAKE_HOOKS_OUTBOUND_PRE) {
- Debug("ssl", "Reenable outbound connect");
+ Dbg(dbg_ctl_ssl, "Reenable outbound connect");
sslHandshakeHookState = HANDSHAKE_HOOKS_OUTBOUND_PRE_INVOKE;
ContWrapper::wrap(nh->mutex.get(), curHook->m_cont,
TS_EVENT_VCONN_OUTBOUND_START, this);
} else if (sslHandshakeHookState == HANDSHAKE_HOOKS_DONE) {
@@ -1707,7 +1724,7 @@ SSLNetVConnection::reenable(NetHandler *nh, int event)
ContWrapper::wrap(nh->mutex.get(), curHook->m_cont,
TS_EVENT_VCONN_CLOSE, this);
}
} else if (sslHandshakeHookState == HANDSHAKE_HOOKS_VERIFY_SERVER) {
- Debug("ssl", "ServerVerify");
+ Dbg(dbg_ctl_ssl, "ServerVerify");
ContWrapper::wrap(nh->mutex.get(), curHook->m_cont,
TS_EVENT_SSL_VERIFY_SERVER, this);
}
return;
@@ -1746,7 +1763,7 @@ SSLNetVConnection::reenable(NetHandler *nh, int event)
default:
break;
}
- Debug("ssl", "iterate from reenable curHook=%p %s", curHook,
get_ssl_handshake_hook_state_name(sslHandshakeHookState));
+ Dbg(dbg_ctl_ssl, "iterate from reenable curHook=%p %s", curHook,
get_ssl_handshake_hook_state_name(sslHandshakeHookState));
}
this->readReschedule(nh);
@@ -1759,7 +1776,7 @@ SSLNetVConnection::callHooks(TSEvent eventId)
ink_assert(eventId == TS_EVENT_SSL_CLIENT_HELLO || eventId ==
TS_EVENT_SSL_CERT || eventId == TS_EVENT_SSL_SERVERNAME ||
eventId == TS_EVENT_SSL_VERIFY_SERVER || eventId ==
TS_EVENT_SSL_VERIFY_CLIENT || eventId == TS_EVENT_VCONN_CLOSE ||
eventId == TS_EVENT_VCONN_OUTBOUND_CLOSE);
- Debug("ssl", "sslHandshakeHookState=%s eventID=%d",
get_ssl_handshake_hook_state_name(this->sslHandshakeHookState), eventId);
+ Dbg(dbg_ctl_ssl, "sslHandshakeHookState=%s eventID=%d",
get_ssl_handshake_hook_state_name(this->sslHandshakeHookState), eventId);
// Move state if it is appropriate
if (eventId == TS_EVENT_VCONN_CLOSE) {
@@ -1877,7 +1894,7 @@ SSLNetVConnection::callHooks(TSEvent eventId)
return true;
}
- Debug("ssl", "iterated to curHook=%p", curHook);
+ Dbg(dbg_ctl_ssl, "iterated to curHook=%p", curHook);
bool reenabled = true;
@@ -1897,7 +1914,7 @@ SSLNetVConnection::callHooks(TSEvent eventId)
reenabled =
(this->sslHandshakeHookState != HANDSHAKE_HOOKS_CERT_INVOKE &&
this->sslHandshakeHookState != HANDSHAKE_HOOKS_PRE_INVOKE &&
this->sslHandshakeHookState != HANDSHAKE_HOOKS_CLIENT_HELLO_INVOKE);
- Debug("ssl", "Called hook on state=%s reenabled=%d",
get_ssl_handshake_hook_state_name(sslHandshakeHookState), reenabled);
+ Dbg(dbg_ctl_ssl, "Called hook on state=%s reenabled=%d",
get_ssl_handshake_hook_state_name(sslHandshakeHookState), reenabled);
}
return reenabled;
@@ -1941,7 +1958,7 @@ SSLNetVConnection::increment_ssl_version_metric(int
version) const
break;
#endif
default:
- Debug("ssl", "Unrecognized SSL version %d", version);
+ Dbg(dbg_ctl_ssl, "Unrecognized SSL version %d", version);
break;
}
}
@@ -2067,17 +2084,18 @@ SSLNetVConnection::_lookupContextByIP()
ip_port_text_buffer ipb1;
ats_ip_nptop(&ip, ipb1, sizeof(ipb1));
cc = lookup->find(ip);
- if (is_debug_tag_set("proxyprotocol")) {
+ if (dbg_ctl_proxyprotocol.on()) {
IpEndpoint src;
ip_port_text_buffer ipb2;
int ip_len = sizeof(src);
if (0 != safe_getpeername(this->get_socket(), &src.sa, &ip_len)) {
- Debug("proxyprotocol", "Failed to get src ip, errno = [%d]", errno);
+ DbgPrint(dbg_ctl_proxyprotocol, "Failed to get src ip, errno = [%d]",
errno);
return nullptr;
}
ats_ip_nptop(&src, ipb2, sizeof(ipb2));
- Debug("proxyprotocol", "IP context is %p for [%s] -> [%s], default
context %p", cc, ipb2, ipb1, lookup->defaultContext());
+ DbgPrint(dbg_ctl_proxyprotocol, "IP context is %p for [%s] -> [%s],
default context %p", cc, ipb2, ipb1,
+ lookup->defaultContext());
}
} else if (0 == safe_getsockname(this->get_socket(), &ip.sa, &namelen)) {
cc = lookup->find(ip);
@@ -2199,7 +2217,7 @@ SSLNetVConnection::_ssl_accept()
#endif
if (had_error_on_reading_early_data) {
- Debug("ssl_early_data", "Error on reading early data: %d", ret);
+ Dbg(dbg_ctl_ssl_early_data, "Error on reading early data: %d", ret);
block->free();
break;
} else {
@@ -2212,9 +2230,9 @@ SSLNetVConnection::_ssl_accept()
this->_early_data_buf->append_block(block);
SSL_INCREMENT_DYN_STAT(ssl_early_data_received_count);
- if (is_debug_tag_set("ssl_early_data_show_received")) {
+ if (dbg_ctl_ssl_early_data_show_received.on()) {
std::string early_data_str(reinterpret_cast<char *>(block->buf()),
nread);
- Debug("ssl_early_data_show_received", "Early data buffer: \n%s",
early_data_str.c_str());
+ DbgPrint(dbg_ctl_ssl_early_data_show_received, "Early data buffer:
\n%s", early_data_str.c_str());
}
} else {
block->free();
@@ -2222,16 +2240,16 @@ SSLNetVConnection::_ssl_accept()
if (finished_reading_early_data) {
this->_early_data_finish = true;
- Debug("ssl_early_data", "SSL_READ_EARLY_DATA_FINISH: size = %lu",
nread);
+ Dbg(dbg_ctl_ssl_early_data, "SSL_READ_EARLY_DATA_FINISH: size =
%lu", nread);
if (this->_early_data_reader == nullptr ||
this->_early_data_reader->read_avail() == 0) {
- Debug("ssl_early_data", "no data in early data buffer");
+ Dbg(dbg_ctl_ssl_early_data, "no data in early data buffer");
ERR_clear_error();
ret = SSL_accept(ssl);
}
break;
}
- Debug("ssl_early_data", "SSL_READ_EARLY_DATA_SUCCESS: size = %lu",
nread);
+ Dbg(dbg_ctl_ssl_early_data, "SSL_READ_EARLY_DATA_SUCCESS: size = %lu",
nread);
}
}
} else {
@@ -2245,11 +2263,11 @@ SSLNetVConnection::_ssl_accept()
return SSL_ERROR_NONE;
}
ssl_error = SSL_get_error(ssl, ret);
- if (ssl_error == SSL_ERROR_SSL && is_debug_tag_set("ssl.error.accept")) {
+ if (ssl_error == SSL_ERROR_SSL && dbg_ctl_ssl_error_accept.on()) {
char buf[512];
unsigned long e = ERR_peek_last_error();
ERR_error_string_n(e, buf, sizeof(buf));
- Debug("ssl.error.accept", "SSL accept returned %d, ssl_error=%d,
ERR_get_error=%ld (%s)", ret, ssl_error, e, buf);
+ DbgPrint(dbg_ctl_ssl_error_accept, "SSL accept returned %d, ssl_error=%d,
ERR_get_error=%ld (%s)", ret, ssl_error, e, buf);
}
return ssl_error;
@@ -2269,7 +2287,7 @@ SSLNetVConnection::_ssl_connect()
std::string lookup_key;
swoc::bwprint(lookup_key, "{}:{}:{}", sni_addr.c_str(),
SSL_get_SSL_CTX(ssl), get_verify_str(ssl));
- Debug("ssl.origin_session_cache", "origin session cache lookup key =
%s", lookup_key.c_str());
+ Dbg(dbg_ctl_ssl_origin_session_cache, "origin session cache lookup key
= %s", lookup_key.c_str());
std::shared_ptr<SSL_SESSION> shared_sess = this->getOriginSession(ssl,
lookup_key);
@@ -2286,22 +2304,18 @@ SSLNetVConnection::_ssl_connect()
if (ret > 0) {
if (SSL_session_reused(ssl)) {
SSL_INCREMENT_DYN_STAT(ssl_origin_session_reused_count);
- if (is_debug_tag_set("ssl.origin_session_cache")) {
- Debug("ssl.origin_session_cache", "reused session to origin server");
- }
+ Dbg(dbg_ctl_ssl_origin_session_cache, "reused session to origin server");
} else {
- if (is_debug_tag_set("ssl.origin_session_cache")) {
- Debug("ssl.origin_session_cache", "new session to origin server");
- }
+ Dbg(dbg_ctl_ssl_origin_session_cache, "new session to origin server");
}
return SSL_ERROR_NONE;
}
int ssl_error = SSL_get_error(ssl, ret);
- if (ssl_error == SSL_ERROR_SSL && is_debug_tag_set("ssl.error.connect")) {
+ if (ssl_error == SSL_ERROR_SSL && dbg_ctl_ssl_error_connect.on()) {
char buf[512];
unsigned long e = ERR_peek_last_error();
ERR_error_string_n(e, buf, sizeof(buf));
- Debug("ssl.error.connect", "SSL connect returned %d, ssl_error=%d,
ERR_get_error=%ld (%s)", ret, ssl_error, e, buf);
+ DbgPrint(dbg_ctl_ssl_error_connect, "SSL connect returned %d,
ssl_error=%d, ERR_get_error=%ld (%s)", ret, ssl_error, e, buf);
}
return ssl_error;
@@ -2353,11 +2367,11 @@ SSLNetVConnection::_ssl_write_buffer(const void *buf,
int64_t nbytes, int64_t &n
return SSL_ERROR_NONE;
}
int ssl_error = SSL_get_error(ssl, ret);
- if (ssl_error == SSL_ERROR_SSL && is_debug_tag_set("ssl.error.write")) {
+ if (ssl_error == SSL_ERROR_SSL && dbg_ctl_ssl_error_write.on()) {
char tempbuf[512];
unsigned long e = ERR_peek_last_error();
ERR_error_string_n(e, tempbuf, sizeof(tempbuf));
- Debug("ssl.error.write", "SSL write returned %d, ssl_error=%d,
ERR_get_error=%ld (%s)", ret, ssl_error, e, tempbuf);
+ DbgPrint(dbg_ctl_ssl_error_write, "SSL write returned %d, ssl_error=%d,
ERR_get_error=%ld (%s)", ret, ssl_error, e, tempbuf);
}
return ssl_error;
}
@@ -2380,7 +2394,7 @@ SSLNetVConnection::_ssl_read_buffer(void *buf, int64_t
nbytes, int64_t &nread)
}
if (early_data_len > 0) {
- Debug("ssl_early_data", "Reading from early data buffer.");
+ Dbg(dbg_ctl_ssl_early_data, "Reading from early data buffer.");
this->_increment_early_data_len(this->_early_data_reader->read(buf,
nbytes < early_data_len ? nbytes : early_data_len));
if (nbytes < early_data_len) {
@@ -2398,7 +2412,7 @@ SSLNetVConnection::_ssl_read_buffer(void *buf, int64_t
nbytes, int64_t &nread)
if (early_data_enabled && !this->_early_data_finish) {
bool had_error_on_reading_early_data = false;
bool finished_reading_early_data = false;
- Debug("ssl_early_data", "More early data to read.");
+ Dbg(dbg_ctl_ssl_early_data, "More early data to read.");
ssl_error_t ssl_error = SSL_ERROR_NONE;
int ret;
#if HAVE_SSL_READ_EARLY_DATA
@@ -2437,22 +2451,22 @@ SSLNetVConnection::_ssl_read_buffer(void *buf, int64_t
nbytes, int64_t &nread)
#endif
if (had_error_on_reading_early_data) {
- Debug("ssl_early_data", "Error reading early data: %s",
ERR_error_string(ERR_get_error(), nullptr));
+ Dbg(dbg_ctl_ssl_early_data, "Error reading early data: %s",
ERR_error_string(ERR_get_error(), nullptr));
} else {
if ((nread = read_bytes) > 0) {
this->_increment_early_data_len(read_bytes);
SSL_INCREMENT_DYN_STAT(ssl_early_data_received_count);
- if (is_debug_tag_set("ssl_early_data_show_received")) {
+ if (dbg_ctl_ssl_early_data_show_received.on()) {
std::string early_data_str(reinterpret_cast<char *>(buf), nread);
- Debug("ssl_early_data_show_received", "Early data buffer: \n%s",
early_data_str.c_str());
+ DbgPrint(dbg_ctl_ssl_early_data_show_received, "Early data buffer:
\n%s", early_data_str.c_str());
}
}
if (finished_reading_early_data) {
this->_early_data_finish = true;
- Debug("ssl_early_data", "SSL_READ_EARLY_DATA_FINISH: size = %"
PRId64, nread);
+ Dbg(dbg_ctl_ssl_early_data, "SSL_READ_EARLY_DATA_FINISH: size = %"
PRId64, nread);
} else {
- Debug("ssl_early_data", "SSL_READ_EARLY_DATA_SUCCESS: size = %"
PRId64, nread);
+ Dbg(dbg_ctl_ssl_early_data, "SSL_READ_EARLY_DATA_SUCCESS: size = %"
PRId64, nread);
}
}
return ssl_error;
@@ -2466,11 +2480,11 @@ SSLNetVConnection::_ssl_read_buffer(void *buf, int64_t
nbytes, int64_t &nread)
return SSL_ERROR_NONE;
}
int ssl_error = SSL_get_error(ssl, ret);
- if (ssl_error == SSL_ERROR_SSL && is_debug_tag_set("ssl.error.read")) {
+ if (ssl_error == SSL_ERROR_SSL && dbg_ctl_ssl_error_read.on()) {
char tempbuf[512];
unsigned long e = ERR_peek_last_error();
ERR_error_string_n(e, tempbuf, sizeof(tempbuf));
- Debug("ssl.error.read", "SSL read returned %d, ssl_error=%d,
ERR_get_error=%ld (%s)", ret, ssl_error, e, tempbuf);
+ DbgPrint(dbg_ctl_ssl_error_read, "SSL read returned %d, ssl_error=%d,
ERR_get_error=%ld (%s)", ret, ssl_error, e, tempbuf);
}
return ssl_error;
@@ -2525,19 +2539,19 @@ SSLNetVConnection::update_early_data_config(uint32_t
max_early_data, uint32_t re
bool ret1 = false;
bool ret2 = false;
if ((ret1 = SSL_set_max_early_data(ssl, max_early_data)) == 1) {
- Debug("ssl_early_data", "SSL_set_max_early_data %u: success",
max_early_data);
+ Dbg(dbg_ctl_ssl_early_data, "SSL_set_max_early_data %u: success",
max_early_data);
} else {
- Debug("ssl_early_data", "SSL_set_max_early_data %u: failed",
max_early_data);
+ Dbg(dbg_ctl_ssl_early_data, "SSL_set_max_early_data %u: failed",
max_early_data);
}
if ((ret2 = SSL_set_recv_max_early_data(ssl, recv_max_early_data)) == 1) {
- Debug("ssl_early_data", "SSL_set_recv_max_early_data %u: success",
recv_max_early_data);
+ Dbg(dbg_ctl_ssl_early_data, "SSL_set_recv_max_early_data %u: success",
recv_max_early_data);
} else {
- Debug("ssl_early_data", "SSL_set_recv_max_early_data %u: failed",
recv_max_early_data);
+ Dbg(dbg_ctl_ssl_early_data, "SSL_set_recv_max_early_data %u: failed",
recv_max_early_data);
}
if (ret1 && ret2) {
- Debug("ssl_early_data", "Must disable anti-replay if 0-rtt is enabled.");
+ Dbg(dbg_ctl_ssl_early_data, "Must disable anti-replay if 0-rtt is
enabled.");
SSL_set_options(ssl, SSL_OP_NO_ANTI_REPLAY);
}
#else
diff --git a/iocore/net/SSLSNIConfig.cc b/iocore/net/SSLSNIConfig.cc
index 2cbe7c2dcf..e3aada4dc6 100644
--- a/iocore/net/SSLSNIConfig.cc
+++ b/iocore/net/SSLSNIConfig.cc
@@ -50,6 +50,9 @@
static constexpr int OVECSIZE{30};
+static DbgCtl dbg_ctl_ssl{"ssl"};
+static DbgCtl dbg_ctl_ssl_sni{"ssl_sni"};
+
////
// NamedElement
//
@@ -80,7 +83,7 @@ NamedElement::set_glob_name(std::string name)
while ((pos = name.find('*', pos)) != std::string::npos) {
name.replace(pos, 1, "(.{0,})");
}
- Debug("ssl_sni", "Regexed fqdn=%s", name.c_str());
+ Dbg(dbg_ctl_ssl_sni, "Regexed fqdn=%s", name.c_str());
set_regex_name(name);
}
@@ -118,7 +121,7 @@ SNIConfigParams::load_sni_config()
auto &ai = sni_action_list.emplace_back();
ai.set_glob_name(item.fqdn);
ai.inbound_port_ranges = item.inbound_port_ranges;
- Debug("ssl", "name: %s", item.fqdn.data());
+ Dbg(dbg_ctl_ssl, "name: %s", item.fqdn.data());
item.populate_sni_actions(ai.actions);
if (!set_next_hop_properties(item)) {
@@ -268,7 +271,7 @@ SNIConfig::startup()
int
SNIConfig::reconfigure()
{
- Debug("ssl", "Reload SNI file");
+ Dbg(dbg_ctl_ssl, "Reload SNI file");
SNIConfigParams *params = new SNIConfigParams;
bool retStatus = params->initialize();
diff --git a/iocore/net/TLSSNISupport.cc b/iocore/net/TLSSNISupport.cc
index 88378a8141..36a5377791 100644
--- a/iocore/net/TLSSNISupport.cc
+++ b/iocore/net/TLSSNISupport.cc
@@ -29,6 +29,13 @@
int TLSSNISupport::_ex_data_index = -1;
+namespace
+{
+
+DbgCtl dbg_ctl_ssl_sni{"ssl_sni"};
+
+} // end anonymous namespace
+
void
TLSSNISupport::initialize()
{
@@ -61,14 +68,14 @@ TLSSNISupport::perform_sni_action()
{
const char *servername = this->get_sni_server_name();
if (!servername) {
- Debug("ssl_sni", "No servername provided");
+ Dbg(dbg_ctl_ssl_sni, "No servername provided");
return SSL_TLSEXT_ERR_OK;
}
SNIConfig::scoped_config params;
auto const port{this->_get_local_port()};
if (auto const &actions = params->get({servername, std::strlen(servername)},
port); !actions.first) {
- Debug("ssl_sni", "%s:%i not available in the map", servername, port);
+ Dbg(dbg_ctl_ssl_sni, "%s:%i not available in the map", servername, port);
} else {
for (auto &&item : *actions.first) {
auto ret = item->SNIAction(this, actions.second);
diff --git a/iocore/net/UnixNet.cc b/iocore/net/UnixNet.cc
index 31bab7e230..44e1f3676b 100644
--- a/iocore/net/UnixNet.cc
+++ b/iocore/net/UnixNet.cc
@@ -41,6 +41,15 @@ NetHandler::Config NetHandler::global_config;
std::bitset<std::numeric_limits<unsigned int>::digits>
NetHandler::active_thread_types;
const std::bitset<NetHandler::CONFIG_ITEM_COUNT>
NetHandler::config_value_affects_per_thread_value{0x3};
+namespace
+{
+
+DbgCtl dbg_ctl_inactivity_cop{"inactivity_cop"};
+DbgCtl dbg_ctl_inactivity_cop_check{"inactivity_cop_check"};
+DbgCtl dbg_ctl_inactivity_cop_verbose{"inactivity_cop_verbose"};
+
+} // end anonymous namespace
+
NetHandler *
get_NetHandler(EThread *t)
{
@@ -74,7 +83,7 @@ public:
ink_hrtime now = ink_get_hrtime();
NetHandler &nh = *get_NetHandler(this_ethread());
- Debug("inactivity_cop_check", "Checking inactivity on Thread-ID #%d",
this_ethread()->id);
+ Dbg(dbg_ctl_inactivity_cop_check, "Checking inactivity on Thread-ID #%d",
this_ethread()->id);
// The rest NetEvents in cop_list which are not triggered between
InactivityCop runs.
// Use pop() to catch any closes caused by callbacks.
while (NetEvent *ne = nh.cop_list.pop()) {
@@ -93,8 +102,9 @@ public:
if (ne->default_inactivity_timeout_in == -1) {
// If no context-specific default inactivity timeout has been set by an
// override plugin, then use the global default.
- Debug("inactivity_cop", "vc: %p setting the global default inactivity
timeout of %d, next_inactivity_timeout_at: %" PRId64,
- ne, nh.config.default_inactivity_timeout,
ne->next_inactivity_timeout_at);
+ Dbg(dbg_ctl_inactivity_cop,
+ "vc: %p setting the global default inactivity timeout of %d,
next_inactivity_timeout_at: %" PRId64, ne,
+ nh.config.default_inactivity_timeout,
ne->next_inactivity_timeout_at);
ne->set_default_inactivity_timeout(HRTIME_SECONDS(nh.config.default_inactivity_timeout));
}
@@ -102,8 +112,8 @@ public:
// The event `EVENT_INACTIVITY_TIMEOUT` only be triggered if a read
// or write I/O operation was set by `do_io_read()` or `do_io_write()`.
if (ne->next_inactivity_timeout_at == 0 &&
ne->default_inactivity_timeout_in > 0 && (ne->read.enabled ||
ne->write.enabled)) {
- Debug("inactivity_cop", "vc: %p inactivity timeout not set, setting a
default of %d", ne,
- nh.config.default_inactivity_timeout);
+ Dbg(dbg_ctl_inactivity_cop, "vc: %p inactivity timeout not set,
setting a default of %d", ne,
+ nh.config.default_inactivity_timeout);
ne->use_default_inactivity_timeout = true;
ne->next_inactivity_timeout_at = ink_get_hrtime() +
ne->default_inactivity_timeout_in;
ne->inactivity_timeout_in = 0;
@@ -113,7 +123,7 @@ public:
if (ne->next_inactivity_timeout_at && ne->next_inactivity_timeout_at <
now) {
if (ne->is_default_inactivity_timeout()) {
// track the connections that timed out due to default inactivity
- Debug("inactivity_cop", "vc: %p timed out due to default inactivity
timeout", ne);
+ Dbg(dbg_ctl_inactivity_cop, "vc: %p timed out due to default
inactivity timeout", ne);
NET_INCREMENT_DYN_STAT(default_inactivity_timeout_count_stat);
}
if (nh.keep_alive_queue.in(ne)) {
@@ -122,12 +132,12 @@ public:
NET_SUM_DYN_STAT(keep_alive_queue_timeout_total_stat, diff);
NET_INCREMENT_DYN_STAT(keep_alive_queue_timeout_count_stat);
}
- Debug("inactivity_cop_verbose", "ne: %p now: %" PRId64 " timeout at:
%" PRId64 " timeout in: %" PRId64, ne,
- ink_hrtime_to_sec(now), ne->next_inactivity_timeout_at,
ne->inactivity_timeout_in);
+ Dbg(dbg_ctl_inactivity_cop_verbose, "ne: %p now: %" PRId64 " timeout
at: %" PRId64 " timeout in: %" PRId64, ne,
+ ink_hrtime_to_sec(now), ne->next_inactivity_timeout_at,
ne->inactivity_timeout_in);
ne->callback(VC_EVENT_INACTIVITY_TIMEOUT, e);
} else if (ne->next_activity_timeout_at && ne->next_activity_timeout_at
< now) {
- Debug("inactivity_cop_verbose", "active ne: %p now: %" PRId64 "
timeout at: %" PRId64 " timeout in: %" PRId64, ne,
- ink_hrtime_to_sec(now), ne->next_activity_timeout_at,
ne->active_timeout_in);
+ Dbg(dbg_ctl_inactivity_cop_verbose, "active ne: %p now: %" PRId64 "
timeout at: %" PRId64 " timeout in: %" PRId64, ne,
+ ink_hrtime_to_sec(now), ne->next_activity_timeout_at,
ne->active_timeout_in);
ne->callback(VC_EVENT_ACTIVE_TIMEOUT, e);
}
}
diff --git a/iocore/net/UnixNetAccept.cc b/iocore/net/UnixNetAccept.cc
index dac1091098..138208b6e7 100644
--- a/iocore/net/UnixNetAccept.cc
+++ b/iocore/net/UnixNetAccept.cc
@@ -30,6 +30,14 @@ using NetAcceptHandler = int (NetAccept::*)(int, void *);
int NetAccept::accept_till_done = 1;
+namespace
+{
+
+DbgCtl dbg_ctl_iocore_net{"iocore_net"};
+DbgCtl dbg_ctl_iocore_net_accept_start{"iocore_net_accept_start"};
+
+} // end anonymous namespace
+
static void
safe_delay(int msec)
{
@@ -163,7 +171,8 @@ NetAccept::init_accept_loop()
NetAccept *a = (i < n - 1) ? clone() : this;
snprintf(thr_name, MAX_THREAD_NAME_LENGTH, "[ACCEPT %d:%d]", i,
ats_ip_port_host_order(&server.accept_addr));
eventProcessor.spawn_thread(a, thr_name, stacksize);
- Debug("iocore_net_accept_start", "Created accept thread #%d for port %d",
i + 1, ats_ip_port_host_order(&server.accept_addr));
+ Dbg(dbg_ctl_iocore_net_accept_start, "Created accept thread #%d for port
%d", i + 1,
+ ats_ip_port_host_order(&server.accept_addr));
}
}
@@ -439,7 +448,7 @@ NetAccept::acceptFastEvent(int event, void *ep)
NET_SUM_DYN_STAT(net_connections_throttled_in_stat, 1);
continue;
}
- Debug("iocore_net", "accepted a new socket: %d", fd);
+ Dbg(dbg_ctl_iocore_net, "accepted a new socket: %d", fd);
NET_SUM_GLOBAL_DYN_STAT(net_tcp_accept_stat, 1);
if (opt.send_bufsize > 0) {
if (unlikely(SocketManager::set_sndbuf_size(fd, opt.send_bufsize))) {
@@ -468,7 +477,7 @@ NetAccept::acceptFastEvent(int event, void *ep)
}
// check return value from accept()
if (res < 0) {
- Debug("iocore_net", "received : %s", strerror(errno));
+ Dbg(dbg_ctl_iocore_net, "received : %s", strerror(errno));
res = -errno;
if (res == -EAGAIN || res == -ECONNABORTED
#if defined(__linux__)
diff --git a/iocore/net/UnixNetProcessor.cc b/iocore/net/UnixNetProcessor.cc
index 90dbf5f18d..87ed2035cb 100644
--- a/iocore/net/UnixNetProcessor.cc
+++ b/iocore/net/UnixNetProcessor.cc
@@ -49,11 +49,21 @@ net_next_connection_number()
NetProcessor::AcceptOptions const NetProcessor::DEFAULT_ACCEPT_OPTIONS;
+namespace
+{
+
+DbgCtl dbg_ctl_iocore_net_processor{"iocore_net_processor"};
+DbgCtl dbg_ctl_iocore_net_accept{"iocore_net_accept"};
+DbgCtl dbg_ctl_http_tproxy{"http_tproxy"};
+DbgCtl dbg_ctl_Socks{"Socks"};
+
+} // end anonymous namespace
+
Action *
UnixNetProcessor::accept(Continuation *cont, AcceptOptions const &opt)
{
- Debug("iocore_net_processor", "NetProcessor::accept - port %d,recv_bufsize
%d, send_bufsize %d, sockopt 0x%0x", opt.local_port,
- opt.recv_bufsize, opt.send_bufsize, opt.sockopt_flags);
+ Dbg(dbg_ctl_iocore_net_processor, "NetProcessor::accept - port
%d,recv_bufsize %d, send_bufsize %d, sockopt 0x%0x",
+ opt.local_port, opt.recv_bufsize, opt.send_bufsize, opt.sockopt_flags);
return accept_internal(cont, NO_FD, opt);
}
@@ -61,8 +71,8 @@ UnixNetProcessor::accept(Continuation *cont, AcceptOptions
const &opt)
Action *
UnixNetProcessor::main_accept(Continuation *cont, SOCKET fd, AcceptOptions
const &opt)
{
- Debug("iocore_net_processor", "NetProcessor::main_accept - port
%d,recv_bufsize %d, send_bufsize %d, sockopt 0x%0x",
- opt.local_port, opt.recv_bufsize, opt.send_bufsize, opt.sockopt_flags);
+ Dbg(dbg_ctl_iocore_net_processor, "NetProcessor::main_accept - port
%d,recv_bufsize %d, send_bufsize %d, sockopt 0x%0x",
+ opt.local_port, opt.recv_bufsize, opt.send_bufsize, opt.sockopt_flags);
return accept_internal(cont, fd, opt);
}
@@ -78,7 +88,7 @@ UnixNetProcessor::accept_internal(Continuation *cont, int fd,
AcceptOptions cons
NetAccept *na = createNetAccept(opt);
na->id = ink_atomic_increment(&net_accept_number, 1);
- Debug("iocore_net_accept", "creating new net accept number %d", na->id);
+ Dbg(dbg_ctl_iocore_net_accept, "creating new net accept number %d", na->id);
// Fill in accept thread from configuration if necessary.
if (opt.accept_threads < 0) {
@@ -108,11 +118,11 @@ UnixNetProcessor::accept_internal(Continuation *cont, int
fd, AcceptOptions cons
ats_ip_copy(&na->server.accept_addr, &accept_ip);
if (opt.f_inbound_transparent) {
- Debug("http_tproxy", "Marked accept server %p on port %d as inbound
transparent", na, opt.local_port);
+ Dbg(dbg_ctl_http_tproxy, "Marked accept server %p on port %d as inbound
transparent", na, opt.local_port);
}
if (opt.f_proxy_protocol) {
- Debug("http_tproxy", "Marked accept server %p on port %d for proxy
protocol", na, opt.local_port);
+ Dbg(dbg_ctl_http_tproxy, "Marked accept server %p on port %d for proxy
protocol", na, opt.local_port);
}
SessionAccept *sa = dynamic_cast<SessionAccept *>(cont);
@@ -194,7 +204,7 @@ UnixNetProcessor::connect_re(Continuation *cont, sockaddr
const *target, NetVCOp
if (using_socks) {
char buff[INET6_ADDRPORTSTRLEN];
- Debug("Socks", "Using Socks ip: %s", ats_ip_nptop(target, buff,
sizeof(buff)));
+ Dbg(dbg_ctl_Socks, "Using Socks ip: %s", ats_ip_nptop(target, buff,
sizeof(buff)));
socksEntry = socksAllocator.alloc();
// The socksEntry->init() will get the origin server addr by
vc->get_remote_addr(),
// and save it to socksEntry->req_data.dest_ip.
@@ -212,7 +222,7 @@ UnixNetProcessor::connect_re(Continuation *cont, sockaddr
const *target, NetVCOp
result = &socksEntry->action_;
vc->action_ = socksEntry;
} else {
- Debug("Socks", "Not Using Socks %d ", socks_conf_stuff->socks_needed);
+ Dbg(dbg_ctl_Socks, "Not Using Socks %d ", socks_conf_stuff->socks_needed);
vc->action_ = cont;
}
diff --git a/iocore/net/UnixUDPConnection.cc b/iocore/net/UnixUDPConnection.cc
index 92b9e60235..736b2ca6b1 100644
--- a/iocore/net/UnixUDPConnection.cc
+++ b/iocore/net/UnixUDPConnection.cc
@@ -32,6 +32,13 @@
#include "P_Net.h"
#include "P_UDPNet.h"
+namespace
+{
+
+DbgCtl dbg_ctl_udpnet{"udpnet"};
+
+} // end anonymous namespace
+
UnixUDPConnection::~UnixUDPConnection()
{
UDPPacket *p = nullptr;
@@ -49,7 +56,7 @@ UnixUDPConnection::~UnixUDPConnection()
callbackAction->cancel();
callbackAction = nullptr;
}
- Debug("udpnet", "Destroying udp port = %d", getPortNum());
+ Dbg(dbg_ctl_udpnet, "Destroying udp port = %d", getPortNum());
if (fd != NO_FD) {
SocketManager::close(fd);
}
@@ -79,7 +86,7 @@ UnixUDPConnection::callbackHandler(int event, void *data)
UDPPacket *p = nullptr;
SList(UDPPacket, alink) aq(inQueue.popall());
- Debug("udpnet", "UDPConnection::callbackHandler");
+ Dbg(dbg_ctl_udpnet, "UDPConnection::callbackHandler");
Queue<UDPPacket> result;
while ((p = aq.pop())) {
result.push(p);
diff --git a/iocore/net/UnixUDPNet.cc b/iocore/net/UnixUDPNet.cc
index 285e64d1e3..c8df421238 100644
--- a/iocore/net/UnixUDPNet.cc
+++ b/iocore/net/UnixUDPNet.cc
@@ -65,7 +65,13 @@ namespace
#ifdef HAVE_RECVMMSG
const uint32_t MAX_RECEIVE_MSG_PER_CALL{16}; //< VLEN parameter for the
recvmmsg call.
#endif
-}; // namespace
+
+DbgCtl dbg_ctl_udpnet{"udpnet"};
+DbgCtl dbg_ctl_udp_read{"udp-read"};
+DbgCtl dbg_ctl_udp_send{"udp-send"};
+DbgCtl dbg_ctl_iocore_udp_main{"iocore_udp_main-send"};
+
+} // end anonymous namespace
UDPPacket *
UDPPacket::new_UDPPacket()
@@ -423,7 +429,7 @@
UDPNetProcessorInternal::read_single_message_from_net(UDPNetHandler *nh, UDPConn
// truncated check
if (msg.msg_flags & MSG_TRUNC) {
- Debug("udp-read", "The UDP packet is truncated");
+ Dbg(dbg_ctl_udp_read, "The UDP packet is truncated");
}
safe_getsockname(xuc->getFd(), reinterpret_cast<struct sockaddr
*>(&toaddr), &toaddr_len);
@@ -442,8 +448,8 @@
UDPNetProcessorInternal::read_single_message_from_net(UDPNetHandler *nh, UDPConn
}
// If gro was used, then the kernel will tell us the size of each part
that was spliced together.
- Debug("udp-read", "Received %lld bytes. gso_size %lld (%s)",
static_cast<long long>(r), static_cast<long long>(gso_size),
- (gso_size > 0 ? "GRO" : "No GRO"));
+ Dbg(dbg_ctl_udp_read, "Received %lld bytes. gso_size %lld (%s)",
static_cast<long long>(r), static_cast<long long>(gso_size),
+ (gso_size > 0 ? "GRO" : "No GRO"));
IOBufferBlock *block;
int64_t remaining{r};
@@ -464,7 +470,7 @@
UDPNetProcessorInternal::read_single_message_from_net(UDPNetHandler *nh, UDPConn
block->next = nullptr;
}
}
- Debug("udp-read", "Creating packet");
+ Dbg(dbg_ctl_udp_read, "Creating packet");
// create packet
UDPPacket *p =
UDPPacket::new_incoming_UDPPacket(ats_ip_sa_cast(&fromaddr),
ats_ip_sa_cast(&toaddr), chain);
p->setConnection(uc);
@@ -479,7 +485,7 @@
UDPNetProcessorInternal::read_single_message_from_net(UDPNetHandler *nh, UDPConn
iters++;
} while (r > 0);
if (iters >= 1) {
- Debug("udp-read", "read %d at a time", iters);
+ Dbg(dbg_ctl_udp_read, "read %d at a time", iters);
}
// if not already on to-be-called-back queue, then add it.
if (!uc->onCallbackQueue) {
@@ -553,25 +559,25 @@
UDPNetProcessorInternal::read_multiple_messages_from_net(UDPNetHandler *nh, UDPC
const int return_val = SocketManager::recvmmsg(uc->getFd(), mmsg,
MAX_RECEIVE_MSG_PER_CALL, MSG_WAITFORONE, nullptr);
if (return_val <= 0) {
- Debug("udp-read", "Done. recvmmsg() ret is %d, errno %s", return_val,
strerror(errno));
+ Dbg(dbg_ctl_udp_read, "Done. recvmmsg() ret is %d, errno %s", return_val,
strerror(errno));
return;
}
- Debug("udp-read", "recvmmsg() read %d packets", return_val);
+ Dbg(dbg_ctl_udp_read, "recvmmsg() read %d packets", return_val);
Ptr<IOBufferBlock> chain, next_chain;
for (auto packet_num = 0; packet_num < return_val; packet_num++) {
gso_size = 0;
- Debug("udp-read", "Processing message %d from a total of %d", packet_num,
return_val);
+ Dbg(dbg_ctl_udp_read, "Processing message %d from a total of %d",
packet_num, return_val);
struct msghdr &mhdr = mmsg[packet_num].msg_hdr;
if (mhdr.msg_flags & MSG_TRUNC) {
- Debug("udp-read", "The UDP packet is truncated");
+ Dbg(dbg_ctl_udp_read, "The UDP packet is truncated");
break;
}
if (mhdr.msg_namelen <= 0) {
- Debug("udp-read", "Unable to get remote address from recvmmsg() for fd:
%d", uc->getFd());
+ Dbg(dbg_ctl_udp_read, "Unable to get remote address from recvmmsg() for
fd: %d", uc->getFd());
return;
}
@@ -596,8 +602,8 @@
UDPNetProcessorInternal::read_multiple_messages_from_net(UDPNetHandler *nh, UDPC
total_bytes_read += received;
// If gro was used, then the kernel will tell us the size of each part
that was spliced together.
- Debug("udp-read", "Received %lld bytes. gso_size %lld (%s)",
static_cast<long long>(received), static_cast<long long>(gso_size),
- (gso_size > 0 ? "GRO" : "No GRO"));
+ Dbg(dbg_ctl_udp_read, "Received %lld bytes. gso_size %lld (%s)",
static_cast<long long>(received),
+ static_cast<long long>(gso_size), (gso_size > 0 ? "GRO" : "No GRO"));
auto chain = buffer_chain[packet_num];
IOBufferBlock *block;
@@ -619,7 +625,7 @@
UDPNetProcessorInternal::read_multiple_messages_from_net(UDPNetHandler *nh, UDPC
block->next = nullptr;
}
}
- Debug("udp-read", "Creating packet");
+ Dbg(dbg_ctl_udp_read, "Creating packet");
// create packet
UDPPacket *p =
UDPPacket::new_incoming_UDPPacket(ats_ip_sa_cast(&fromaddr[packet_num]),
ats_ip_sa_cast(&toaddr[packet_num]), chain);
@@ -632,7 +638,7 @@
UDPNetProcessorInternal::read_multiple_messages_from_net(UDPNetHandler *nh, UDPC
next_chain = nullptr;
}
}
- Debug("udp-read", "Total bytes read %ld from %d packets.", total_bytes_read,
return_val);
+ Dbg(dbg_ctl_udp_read, "Total bytes read %ld from %d packets.",
total_bytes_read, return_val);
// if not already on to-be-called-back queue, then add it.
if (!uc->onCallbackQueue) {
@@ -1049,12 +1055,12 @@ UDPNetProcessor::CreateUDPSocket(int *resfd, sockaddr
const *remote_addr, Action
if (opt.socket_recv_bufsize > 0) {
if (unlikely(SocketManager::set_rcvbuf_size(fd, opt.socket_recv_bufsize)))
{
- Debug("udpnet", "set_dnsbuf_size(%d) failed", opt.socket_recv_bufsize);
+ Dbg(dbg_ctl_udpnet, "set_dnsbuf_size(%d) failed",
opt.socket_recv_bufsize);
}
}
if (opt.socket_send_bufsize > 0) {
if (unlikely(SocketManager::set_sndbuf_size(fd, opt.socket_send_bufsize)))
{
- Debug("udpnet", "set_dnsbuf_size(%d) failed", opt.socket_send_bufsize);
+ Dbg(dbg_ctl_udpnet, "set_dnsbuf_size(%d) failed",
opt.socket_send_bufsize);
}
}
@@ -1071,7 +1077,7 @@ UDPNetProcessor::CreateUDPSocket(int *resfd, sockaddr
const *remote_addr, Action
}
#endif
if (!succeeded) {
- Debug("udpnet", "setsockeopt for pktinfo failed");
+ Dbg(dbg_ctl_udpnet, "setsockeopt for pktinfo failed");
goto HardError;
}
} else if (opt.ip_family == AF_INET6) {
@@ -1087,7 +1093,7 @@ UDPNetProcessor::CreateUDPSocket(int *resfd, sockaddr
const *remote_addr, Action
}
#endif
if (!succeeded) {
- Debug("udpnet", "setsockeopt for pktinfo failed");
+ Dbg(dbg_ctl_udpnet, "setsockeopt for pktinfo failed");
goto HardError;
}
}
@@ -1095,23 +1101,23 @@ UDPNetProcessor::CreateUDPSocket(int *resfd, sockaddr
const *remote_addr, Action
if (local_addr.network_order_port() || !is_any_address) {
if (-1 == SocketManager::ink_bind(fd, &local_addr.sa,
ats_ip_size(&local_addr.sa))) {
char buff[INET6_ADDRPORTSTRLEN];
- Debug("udpnet", "ink bind failed on %s", ats_ip_nptop(local_addr, buff,
sizeof(buff)));
+ Dbg(dbg_ctl_udpnet, "ink bind failed on %s", ats_ip_nptop(local_addr,
buff, sizeof(buff)));
goto SoftError;
}
if (safe_getsockname(fd, &local_addr.sa, &local_addr_len) < 0) {
- Debug("udpnet", "CreateUdpsocket: getsockname didn't work");
+ Dbg(dbg_ctl_udpnet, "CreateUdpsocket: getsockname didn't work");
goto HardError;
}
}
*resfd = fd;
*status = nullptr;
- Debug("udpnet", "creating a udp socket port = %d, %d---success",
ats_ip_port_host_order(remote_addr),
- ats_ip_port_host_order(local_addr));
+ Dbg(dbg_ctl_udpnet, "creating a udp socket port = %d, %d---success",
ats_ip_port_host_order(remote_addr),
+ ats_ip_port_host_order(local_addr));
return true;
SoftError:
- Debug("udpnet", "creating a udp socket port = %d---soft failure",
ats_ip_port_host_order(local_addr));
+ Dbg(dbg_ctl_udpnet, "creating a udp socket port = %d---soft failure",
ats_ip_port_host_order(local_addr));
if (fd != -1) {
SocketManager::close(fd);
}
@@ -1119,7 +1125,7 @@ SoftError:
*status = nullptr;
return false;
HardError:
- Debug("udpnet", "creating a udp socket port = %d---hard failure",
ats_ip_port_host_order(local_addr));
+ Dbg(dbg_ctl_udpnet, "creating a udp socket port = %d---hard failure",
ats_ip_port_host_order(local_addr));
if (fd != -1) {
SocketManager::close(fd);
}
@@ -1164,7 +1170,7 @@ UDPNetProcessor::UDPBind(Continuation *cont, sockaddr
const *addr, int fd, int s
}
#endif
if (!succeeded) {
- Debug("udpnet", "setsockeopt for pktinfo failed");
+ Dbg(dbg_ctl_udpnet, "setsockeopt for pktinfo failed");
goto Lerror;
}
} else if (addr->sa_family == AF_INET6) {
@@ -1180,7 +1186,7 @@ UDPNetProcessor::UDPBind(Continuation *cont, sockaddr
const *addr, int fd, int s
}
#endif
if (!succeeded) {
- Debug("udpnet", "setsockeopt for pktinfo failed");
+ Dbg(dbg_ctl_udpnet, "setsockeopt for pktinfo failed");
goto Lerror;
}
}
@@ -1189,9 +1195,9 @@ UDPNetProcessor::UDPBind(Continuation *cont, sockaddr
const *addr, int fd, int s
if (G_udp_config.enable_gro) {
int gro = 1;
if (safe_setsockopt(fd, IPPROTO_UDP, UDP_GRO, (char *)&gro, sizeof(gro))
== 0) {
- Debug("udpnet", "setsockopt UDP_GRO ok");
+ Dbg(dbg_ctl_udpnet, "setsockopt UDP_GRO ok");
} else {
- Debug("udpnet", "setsockopt UDP_GRO. errno=%d", errno);
+ Dbg(dbg_ctl_udpnet, "setsockopt UDP_GRO. errno=%d", errno);
}
}
#endif
@@ -1208,31 +1214,31 @@ UDPNetProcessor::UDPBind(Continuation *cont, sockaddr
const *addr, int fd, int s
}
if (setsockopt_on(fd, SOL_SOCKET, SO_REUSEPORT) < 0) {
- Debug("udpnet", "setsockopt for SO_REUSEPORT failed");
+ Dbg(dbg_ctl_udpnet, "setsockopt for SO_REUSEPORT failed");
goto Lerror;
}
#ifdef SO_REUSEPORT_LB
if (setsockopt_on(fd, SOL_SOCKET, SO_REUSEPORT_LB) < 0) {
- Debug("udpnet", "setsockopt for SO_REUSEPORT_LB failed");
+ Dbg(dbg_ctl_udpnet, "setsockopt for SO_REUSEPORT_LB failed");
goto Lerror;
}
#endif
if (need_bind && (SocketManager::ink_bind(fd, addr, ats_ip_size(addr)) < 0))
{
- Debug("udpnet", "ink_bind failed");
+ Dbg(dbg_ctl_udpnet, "ink_bind failed");
goto Lerror;
}
// check this for GRO
if (recv_bufsize) {
if (unlikely(SocketManager::set_rcvbuf_size(fd, recv_bufsize))) {
- Debug("udpnet", "set_dnsbuf_size(%d) failed", recv_bufsize);
+ Dbg(dbg_ctl_udpnet, "set_dnsbuf_size(%d) failed", recv_bufsize);
}
}
if (send_bufsize) {
if (unlikely(SocketManager::set_sndbuf_size(fd, send_bufsize))) {
- Debug("udpnet", "set_dnsbuf_size(%d) failed", send_bufsize);
+ Dbg(dbg_ctl_udpnet, "set_dnsbuf_size(%d) failed", send_bufsize);
}
}
if (safe_getsockname(fd, &myaddr.sa, &myaddr_len) < 0) {
@@ -1240,7 +1246,7 @@ UDPNetProcessor::UDPBind(Continuation *cont, sockaddr
const *addr, int fd, int s
}
n = new UnixUDPConnection(fd);
- Debug("udpnet", "UDPNetProcessor::UDPBind: %p fd=%d", n, fd);
+ Dbg(dbg_ctl_udpnet, "UDPNetProcessor::UDPBind: %p fd=%d", n, fd);
n->setBinding(&myaddr.sa);
n->bindToThread(cont, cont->getThreadAffinity());
@@ -1255,7 +1261,7 @@ Lerror:
if (fd != NO_FD) {
SocketManager::close(fd);
}
- Debug("udpnet", "Error: %s (%d)", strerror(errno), errno);
+ Dbg(dbg_ctl_udpnet, "Error: %s (%d)", strerror(errno), errno);
cont->handleEvent(NET_EVENT_DATAGRAM_ERROR, nullptr);
return ACTION_IO_ERROR;
@@ -1299,7 +1305,7 @@ UDPQueue::service(UDPNetHandler *nh)
ink_assert(p->link.prev == nullptr);
ink_assert(p->link.next == nullptr);
// insert into our queue.
- Debug("udp-send", "Adding %p", p);
+ Dbg(dbg_ctl_udp_send, "Adding %p", p);
if (p->p.conn->lastPktStartTime == 0) {
pktSendStartTime = std::max(now, p->p.delivery_time);
} else {
@@ -1403,7 +1409,7 @@ UDPQueue::SendUDPPacket(UDPPacket *p)
int n, count = 0;
p->p.conn->lastSentPktStartTime = p->p.delivery_time;
- Debug("udp-send", "Sending %p", p);
+ Dbg(dbg_ctl_udp_send, "Sending %p", p);
msg.msg_control = nullptr;
msg.msg_controllen = 0;
@@ -1450,11 +1456,11 @@ UDPQueue::SendUDPPacket(UDPPacket *p)
++count;
if ((g_udp_numSendRetries > 0) && (count >= g_udp_numSendRetries)) {
// tried too many times; give up
- Debug("udpnet", "Send failed: too many retries");
+ Dbg(dbg_ctl_udpnet, "Send failed: too many retries");
return;
}
} else {
- Debug("udp-send", "Error: %s (%d)", strerror(errno), errno);
+ Dbg(dbg_ctl_udp_send, "Error: %s (%d)", strerror(errno), errno);
return;
}
}
@@ -1478,11 +1484,11 @@ UDPQueue::SendUDPPacket(UDPPacket *p)
++count;
if ((g_udp_numSendRetries > 0) && (count >= g_udp_numSendRetries))
{
// tried too many times; give up
- Debug("udpnet", "Send failed: too many retries");
+ Dbg(dbg_ctl_udpnet, "Send failed: too many retries");
return;
}
} else {
- Debug("udp-send", "Error: %s (%d)", strerror(errno), errno);
+ Dbg(dbg_ctl_udp_send, "Error: %s (%d)", strerror(errno), errno);
return;
}
}
@@ -1511,7 +1517,7 @@ UDPQueue::SendUDPPacket(UDPPacket *p)
if ((n >= 0) || (errno != EAGAIN)) {
// send succeeded or some random error happened.
if (n < 0) {
- Debug("udp-send", "Error: %s (%d)", strerror(errno), errno);
+ Dbg(dbg_ctl_udp_send, "Error: %s (%d)", strerror(errno), errno);
}
break;
@@ -1520,7 +1526,7 @@ UDPQueue::SendUDPPacket(UDPPacket *p)
++count;
if ((g_udp_numSendRetries > 0) && (count >= g_udp_numSendRetries)) {
// tried too many times; give up
- Debug("udpnet", "Send failed: too many retries");
+ Dbg(dbg_ctl_udpnet, "Send failed: too many retries");
break;
}
}
@@ -1656,15 +1662,15 @@ UDPQueue::SendMultipleUDPPackets(UDPPacket **p,
uint16_t n)
#ifdef SOL_UDP
if (use_udp_gso && errno == EIO) {
Warning("Disabling UDP GSO due to an error");
- Debug("udp-send", "Disabling UDP GSO due to an error");
+ Dbg(dbg_ctl_udp_send, "Disabling UDP GSO due to an error");
use_udp_gso = false;
return SendMultipleUDPPackets(p, n);
} else {
- Debug("udp-send", "udp_gso=%d res=%d errno=%d", use_udp_gso, res, errno);
+ Dbg(dbg_ctl_udp_send, "udp_gso=%d res=%d errno=%d", use_udp_gso, res,
errno);
return res;
}
#else
- Debug("udp-send", "res=%d errno=%d", res, errno);
+ Dbg(dbg_ctl_udp_send, "res=%d errno=%d", res, errno);
return res;
#endif
}
@@ -1673,7 +1679,7 @@ UDPQueue::SendMultipleUDPPackets(UDPPacket **p, uint16_t
n)
#ifdef SOL_UDP
if (use_udp_gso) {
ink_assert(res <= n);
- Debug("udp-send", "Sent %d messages by processing %d UDPPackets (GSO)",
res, n);
+ Dbg(dbg_ctl_udp_send, "Sent %d messages by processing %d UDPPackets
(GSO)", res, n);
} else {
#endif
int i = 0;
@@ -1685,7 +1691,7 @@ UDPQueue::SendMultipleUDPPackets(UDPPacket **p, uint16_t
n)
res -= (p[i]->p.chain.get()->size() / p[i]->p.segment_size) +
((p[i]->p.chain.get()->size() % p[i]->p.segment_size) != 0);
}
}
- Debug("udp-send", "Sent %d messages by processing %d UDPPackets", nmsg,
i);
+ Dbg(dbg_ctl_udp_send, "Sent %d messages by processing %d UDPPackets",
nmsg, i);
res = i;
#ifdef SOL_UDP
}
