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 9cd7e5798 Remove deprecated debug output functions from 13 source
files. (#9676)
9cd7e5798 is described below
commit 9cd7e5798dca2ed299ecb998b369bda0ab084295
Author: Walt Karas <wka...@yahooinc.com>
AuthorDate: Fri May 12 22:10:08 2023 -0500
Remove deprecated debug output functions from 13 source files. (#9676)
---
include/tscore/Diags.h | 10 +++
iocore/eventsystem/ConfigProcessor.cc | 13 +++-
iocore/eventsystem/ConfigProcessor.h | 4 +-
iocore/eventsystem/RecProcess.cc | 28 +++----
iocore/eventsystem/RecRawStatsImpl.cc | 9 ++-
iocore/hostdb/HostDB.cc | 122 +++++++++++++++---------------
iocore/hostdb/HostFile.cc | 3 +-
iocore/hostdb/P_RefCountCache.h | 18 +++--
iocore/hostdb/P_RefCountCacheSerializer.h | 10 +--
iocore/hostdb/test_HostFile.cc | 11 ++-
iocore/net/P_SSLUtils.h | 1 +
iocore/net/SSLSecret.cc | 28 ++++---
iocore/net/SSLUtils.cc | 118 ++++++++++++++++-------------
iocore/net/Socks.cc | 89 ++++++++++++----------
14 files changed, 267 insertions(+), 197 deletions(-)
diff --git a/include/tscore/Diags.h b/include/tscore/Diags.h
index 5e2cbbaae..ca589c2f5 100644
--- a/include/tscore/Diags.h
+++ b/include/tscore/Diags.h
@@ -188,6 +188,16 @@ is_dbg_ctl_enabled(DbgCtl const &ctl)
} \
} while (false)
+// A BufferWriter version of Dbg().
+#define Dbg_bw(ctl__, fmt, ...)
\
+ do {
\
+ if (unlikely(diags()->on())) {
\
+ if (ctl__.ptr()->on) {
\
+ DbgPrint(ctl__, "%s", ts::bwprint(ts::bw_dbg, fmt,
__VA_ARGS__).c_str()); \
+ }
\
+ }
\
+ } while (false)
+
// A BufferWriter version of Debug().
#define Debug_bw(tag__, fmt, ...)
\
do {
\
diff --git a/iocore/eventsystem/ConfigProcessor.cc
b/iocore/eventsystem/ConfigProcessor.cc
index 664608e68..4bf072c94 100644
--- a/iocore/eventsystem/ConfigProcessor.cc
+++ b/iocore/eventsystem/ConfigProcessor.cc
@@ -29,6 +29,13 @@
ConfigProcessor configProcessor;
+namespace
+{
+
+DbgCtl dbg_ctl_config{"config"};
+
+}
+
class ConfigInfoReleaser : public Continuation
{
public:
@@ -81,8 +88,8 @@ ConfigProcessor::set(unsigned int id, ConfigInfo *info,
unsigned timeout_secs)
idx = id - 1;
old_info = infos[idx].exchange(info);
- Debug("config", "Set for slot %d 0x%" PRId64 " was 0x%" PRId64 " with ref
count %d", id, (int64_t)info, (int64_t)old_info,
- (old_info) ? old_info->refcount() : 0);
+ Dbg(dbg_ctl_config, "Set for slot %d 0x%" PRId64 " was 0x%" PRId64 " with
ref count %d", id, (int64_t)info, (int64_t)old_info,
+ (old_info) ? old_info->refcount() : 0);
if (old_info) {
// The ConfigInfoReleaser now takes our refcount, but
@@ -132,7 +139,7 @@ ConfigProcessor::release(unsigned int id, ConfigInfo *info)
if (info && info->refcount_dec() == 0) {
// When we release, we should already have replaced this object in the
index.
- Debug("config", "Release config %d 0x%" PRId64, id, (int64_t)info);
+ Dbg(dbg_ctl_config, "Release config %d 0x%" PRId64, id, (int64_t)info);
ink_release_assert(info != this->infos[idx]);
delete info;
}
diff --git a/iocore/eventsystem/ConfigProcessor.h
b/iocore/eventsystem/ConfigProcessor.h
index f5745e6c7..7053c809b 100644
--- a/iocore/eventsystem/ConfigProcessor.h
+++ b/iocore/eventsystem/ConfigProcessor.h
@@ -105,11 +105,13 @@ private:
{
ConfigUpdateHandler *self = static_cast<ConfigUpdateHandler *>(cookie);
- Debug("config", "%s(%s)", __PRETTY_FUNCTION__, name);
+ Dbg(_dbg_ctl, "%s(%s)", __PRETTY_FUNCTION__, name);
return ConfigScheduleUpdate<UpdateClass>(self->mutex);
}
Ptr<ProxyMutex> mutex;
+
+ inline static DbgCtl _dbg_ctl{"config"};
};
extern ConfigProcessor configProcessor;
diff --git a/iocore/eventsystem/RecProcess.cc b/iocore/eventsystem/RecProcess.cc
index fff53ca6a..7cc9dc22b 100644
--- a/iocore/eventsystem/RecProcess.cc
+++ b/iocore/eventsystem/RecProcess.cc
@@ -43,36 +43,38 @@ static Event *raw_stat_sync_cont_event;
static Event *config_update_cont_event;
static Event *sync_cont_event;
+static DbgCtl dbg_ctl_statsproc{"statsproc"};
+
//-------------------------------------------------------------------------
// Simple setters for the intervals to decouple this from the proxy
//-------------------------------------------------------------------------
void
RecProcess_set_raw_stat_sync_interval_ms(int ms)
{
- Debug("statsproc", "g_rec_raw_stat_sync_interval_ms -> %d", ms);
+ Dbg(dbg_ctl_statsproc, "g_rec_raw_stat_sync_interval_ms -> %d", ms);
g_rec_raw_stat_sync_interval_ms = ms;
if (raw_stat_sync_cont_event) {
- Debug("statsproc", "Rescheduling raw-stat syncer");
+ Dbg(dbg_ctl_statsproc, "Rescheduling raw-stat syncer");
raw_stat_sync_cont_event->schedule_every(HRTIME_MSECONDS(g_rec_raw_stat_sync_interval_ms));
}
}
void
RecProcess_set_config_update_interval_ms(int ms)
{
- Debug("statsproc", "g_rec_config_update_interval_ms -> %d", ms);
+ Dbg(dbg_ctl_statsproc, "g_rec_config_update_interval_ms -> %d", ms);
g_rec_config_update_interval_ms = ms;
if (config_update_cont_event) {
- Debug("statsproc", "Rescheduling config syncer");
+ Dbg(dbg_ctl_statsproc, "Rescheduling config syncer");
config_update_cont_event->schedule_every(HRTIME_MSECONDS(g_rec_config_update_interval_ms));
}
}
void
RecProcess_set_remote_sync_interval_ms(int ms)
{
- Debug("statsproc", "g_rec_remote_sync_interval_ms -> %d", ms);
+ Dbg(dbg_ctl_statsproc, "g_rec_remote_sync_interval_ms -> %d", ms);
g_rec_remote_sync_interval_ms = ms;
if (sync_cont_event) {
- Debug("statsproc", "Rescheduling remote syncer");
+ Dbg(dbg_ctl_statsproc, "Rescheduling remote syncer");
sync_cont_event->schedule_every(HRTIME_MSECONDS(g_rec_remote_sync_interval_ms));
}
}
@@ -86,7 +88,7 @@ struct raw_stat_sync_cont : public Continuation {
exec_callbacks(int /* event */, Event * /* e */)
{
RecExecRawStatSyncCbs();
- Debug("statsproc", "raw_stat_sync_cont() processed");
+ Dbg(dbg_ctl_statsproc, "raw_stat_sync_cont() processed");
return EVENT_CONT;
}
@@ -101,7 +103,7 @@ struct config_update_cont : public Continuation {
exec_callbacks(int /* event */, Event * /* e */)
{
RecExecConfigUpdateCbs(REC_PROCESS_UPDATE_REQUIRED);
- Debug("statsproc", "config_update_cont() processed");
+ Dbg(dbg_ctl_statsproc, "config_update_cont() processed");
return EVENT_CONT;
}
@@ -132,7 +134,7 @@ struct sync_cont : public Continuation {
{
RecSyncStatsFile();
- Debug("statsproc", "sync_cont() processed");
+ Dbg(dbg_ctl_statsproc, "sync_cont() processed");
return EVENT_CONT;
}
@@ -173,17 +175,17 @@ RecProcessStart()
return REC_ERR_OKAY;
}
- Debug("statsproc", "Starting sync continuations:");
+ Dbg(dbg_ctl_statsproc, "Starting sync continuations:");
raw_stat_sync_cont *rssc = new raw_stat_sync_cont(new_ProxyMutex());
- Debug("statsproc", "raw-stat syncer");
+ Dbg(dbg_ctl_statsproc, "raw-stat syncer");
raw_stat_sync_cont_event = eventProcessor.schedule_every(rssc,
HRTIME_MSECONDS(g_rec_raw_stat_sync_interval_ms), ET_TASK);
config_update_cont *cuc = new config_update_cont(new_ProxyMutex());
- Debug("statsproc", "config syncer");
+ Dbg(dbg_ctl_statsproc, "config syncer");
config_update_cont_event = eventProcessor.schedule_every(cuc,
HRTIME_MSECONDS(g_rec_config_update_interval_ms), ET_TASK);
sync_cont *sc = new sync_cont(new_ProxyMutex());
- Debug("statsproc", "remote syncer");
+ Dbg(dbg_ctl_statsproc, "remote syncer");
sync_cont_event = eventProcessor.schedule_every(sc,
HRTIME_MSECONDS(g_rec_remote_sync_interval_ms), ET_TASK);
g_started = true;
diff --git a/iocore/eventsystem/RecRawStatsImpl.cc
b/iocore/eventsystem/RecRawStatsImpl.cc
index 83796057f..7b69c383a 100644
--- a/iocore/eventsystem/RecRawStatsImpl.cc
+++ b/iocore/eventsystem/RecRawStatsImpl.cc
@@ -36,6 +36,9 @@ struct RecRawStatBlockOpsImpl : RecRawStatBlockOps {
int raw_stat_clear_sum(RecRawStatBlock *rsb, int id) override;
int raw_stat_get_total(RecRawStatBlock *rsb, int id, RecRawStat *total)
override;
int raw_stat_sync_to_global(RecRawStatBlock *rsb, int id) override;
+
+private:
+ inline static DbgCtl _dbg_ctl{"stats"};
};
RecRawStatBlock *
@@ -166,7 +169,7 @@
RecRawStatBlockOpsImpl::raw_stat_sync_to_global(RecRawStatBlock *rsb, int id)
int
RecRawStatBlockOpsImpl::raw_stat_clear(RecRawStatBlock *rsb, int id)
{
- Debug("stats", "raw_stat_clear(): rsb pointer:%p id:%d", rsb, id);
+ Dbg(_dbg_ctl, "raw_stat_clear(): rsb pointer:%p id:%d", rsb, id);
// the globals need to be reset too
// lock so the setting of the globals and last values are atomic
@@ -199,7 +202,7 @@ RecRawStatBlockOpsImpl::raw_stat_clear(RecRawStatBlock
*rsb, int id)
int
RecRawStatBlockOpsImpl::raw_stat_clear_sum(RecRawStatBlock *rsb, int id)
{
- Debug("stats", "raw_stat_clear_sum(): rsb pointer:%p id:%d", rsb, id);
+ Dbg(_dbg_ctl, "raw_stat_clear_sum(): rsb pointer:%p id:%d", rsb, id);
// the globals need to be reset too
// lock so the setting of the globals and last values are atomic
@@ -229,7 +232,7 @@ RecRawStatBlockOpsImpl::raw_stat_clear_sum(RecRawStatBlock
*rsb, int id)
int
RecRawStatBlockOpsImpl::raw_stat_clear_count(RecRawStatBlock *rsb, int id)
{
- Debug("stats", "raw_stat_clear_count(): rsb pointer:%p id:%d", rsb, id);
+ Dbg(_dbg_ctl, "raw_stat_clear_count(): rsb pointer:%p id:%d", rsb, id);
// the globals need to be reset too
// lock so the setting of the globals and last values are atomic
diff --git a/iocore/hostdb/HostDB.cc b/iocore/hostdb/HostDB.cc
index 1fd8c249b..a3c4a4494 100644
--- a/iocore/hostdb/HostDB.cc
+++ b/iocore/hostdb/HostDB.cc
@@ -80,6 +80,9 @@ ClassAllocator<HostDBContinuation>
hostDBContAllocator("hostDBContAllocator");
namespace
{
+DbgCtl dbg_ctl_hostdb{"hostdb"};
+DbgCtl dbg_ctl_dns_srv{"dns_srv"};
+
unsigned int
HOSTDB_CLIENT_IP_HASH(sockaddr const *lhs, IpAddr const &rhs)
{
@@ -458,7 +461,7 @@ HostDBCache::start(int flags)
Layout::relative_to(storage_path, sizeof(storage_path),
Layout::get()->prefix, storage_path);
}
- Debug("hostdb", "Storage path is %s", storage_path);
+ Dbg(dbg_ctl_hostdb, "Storage path is %s", storage_path);
if (access(storage_path, W_OK | R_OK) == -1) {
Warning("Unable to access() directory '%s': %d, %s", storage_path,
errno, strerror(errno));
@@ -469,8 +472,8 @@ HostDBCache::start(int flags)
char full_path[2 * PATH_NAME_MAX];
ink_filepath_make(full_path, 2 * PATH_NAME_MAX, storage_path,
hostdb_filename);
- Debug("hostdb", "Opening %s, partitions=%d storage_size=%" PRIu64 "
items=%d", full_path, hostdb_partitions, hostdb_max_size,
- hostdb_max_count);
+ Dbg(dbg_ctl_hostdb, "Opening %s, partitions=%d storage_size=%" PRIu64 "
items=%d", full_path, hostdb_partitions,
+ hostdb_max_size, hostdb_max_count);
int load_ret =
LoadRefCountCacheFromPath<HostDBRecord>(*this->refcountcache, full_path,
HostDBRecord::unmarshall);
if (load_ret != 0) {
Warning("Error loading cache from %s: %d", full_path, load_ret);
@@ -582,7 +585,7 @@ reply_to_cont(Continuation *cont, HostDBRecord *r, bool
is_srv = false)
hostDB.refcountcache->erase(r->key);
return false;
}
- Debug("hostdb", "hostname = %s", r->name());
+ Dbg(dbg_ctl_hostdb, "hostname = %s", r->name());
}
cont->handleEvent(is_srv ? EVENT_SRV_LOOKUP : EVENT_HOST_DB_LOOKUP, r);
@@ -666,16 +669,16 @@ probe(HostDBHash const &hash, bool ignore_timeout)
(record->is_ip_timeout() && record->serve_stale_but_revalidate())) {
HOSTDB_INCREMENT_DYN_STAT_THREAD(hostdb_total_serve_stale_stat,
this_ethread());
if (hostDB.is_pending_dns_for_hash(hash.hash)) {
- Debug("hostdb", "%s",
- ts::bwprint(ts::bw_dbg, "stale {} {} {}, using with pending
refresh", record->ip_age(),
- record->ip_timestamp.time_since_epoch(),
record->ip_timeout_interval)
- .c_str());
+ Dbg(dbg_ctl_hostdb, "%s",
+ ts::bwprint(ts::bw_dbg, "stale {} {} {}, using with pending
refresh", record->ip_age(),
+ record->ip_timestamp.time_since_epoch(),
record->ip_timeout_interval)
+ .c_str());
return record;
}
- Debug("hostdb", "%s",
- ts::bwprint(ts::bw_dbg, "stale {} {} {}, using while refresh",
record->ip_age(), record->ip_timestamp.time_since_epoch(),
- record->ip_timeout_interval)
- .c_str());
+ Dbg(dbg_ctl_hostdb, "%s",
+ ts::bwprint(ts::bw_dbg, "stale {} {} {}, using while refresh",
record->ip_age(), record->ip_timestamp.time_since_epoch(),
+ record->ip_timeout_interval)
+ .c_str());
HostDBContinuation *c = hostDBContAllocator.alloc();
HostDBContinuation::Options copt;
copt.host_res_style = record->af_family == AF_INET6 ? HOST_RES_IPV6_ONLY :
HOST_RES_IPV4_ONLY;
@@ -743,12 +746,12 @@ HostDBProcessor::getby(Continuation *cont,
cb_process_result_pfn cb_process_resu
if (!loop) {
// No retry -> final result. Return it.
if (hash.db_mark == HOSTDB_MARK_SRV) {
- Debug("hostdb", "immediate SRV answer for %.*s from hostdb",
int(hash.host_name.size()), hash.host_name.data());
- Debug("dns_srv", "immediate SRV answer for %.*s from hostdb",
int(hash.host_name.size()), hash.host_name.data());
+ Dbg(dbg_ctl_hostdb, "immediate SRV answer for %.*s from hostdb",
int(hash.host_name.size()), hash.host_name.data());
+ Dbg(dbg_ctl_dns_srv, "immediate SRV answer for %.*s from hostdb",
int(hash.host_name.size()), hash.host_name.data());
} else if (hash.host_name) {
- Debug("hostdb", "immediate answer for %.*s",
int(hash.host_name.size()), hash.host_name.data());
+ Dbg(dbg_ctl_hostdb, "immediate answer for %.*s",
int(hash.host_name.size()), hash.host_name.data());
} else {
- Debug("hostdb", "immediate answer for %s", hash.ip.isValid() ?
hash.ip.toString(ipb, sizeof ipb) : "<null>");
+ Dbg(dbg_ctl_hostdb, "immediate answer for %s", hash.ip.isValid() ?
hash.ip.toString(ipb, sizeof ipb) : "<null>");
}
HOSTDB_INCREMENT_DYN_STAT(hostdb_total_hits_stat);
if (cb_process_result) {
@@ -763,16 +766,16 @@ HostDBProcessor::getby(Continuation *cont,
cb_process_result_pfn cb_process_resu
}
}
if (hash.db_mark == HOSTDB_MARK_SRV) {
- Debug("hostdb", "delaying (force=%d) SRV answer for %.*s [timeout = %d]",
force_dns, int(hash.host_name.size()),
- hash.host_name.data(), opt.timeout);
- Debug("dns_srv", "delaying (force=%d) SRV answer for %.*s [timeout = %d]",
force_dns, int(hash.host_name.size()),
- hash.host_name.data(), opt.timeout);
+ Dbg(dbg_ctl_hostdb, "delaying (force=%d) SRV answer for %.*s [timeout =
%d]", force_dns, int(hash.host_name.size()),
+ hash.host_name.data(), opt.timeout);
+ Dbg(dbg_ctl_dns_srv, "delaying (force=%d) SRV answer for %.*s [timeout =
%d]", force_dns, int(hash.host_name.size()),
+ hash.host_name.data(), opt.timeout);
} else if (hash.host_name) {
- Debug("hostdb", "delaying (force=%d) answer for %.*s [timeout %d]",
force_dns, int(hash.host_name.size()),
- hash.host_name.data(), opt.timeout);
+ Dbg(dbg_ctl_hostdb, "delaying (force=%d) answer for %.*s [timeout %d]",
force_dns, int(hash.host_name.size()),
+ hash.host_name.data(), opt.timeout);
} else {
- Debug("hostdb", "delaying (force=%d) answer for %s [timeout %d]",
force_dns,
- hash.ip.isValid() ? hash.ip.toString(ipb, sizeof ipb) : "<null>",
opt.timeout);
+ Dbg(dbg_ctl_hostdb, "delaying (force=%d) answer for %s [timeout %d]",
force_dns,
+ hash.ip.isValid() ? hash.ip.toString(ipb, sizeof ipb) : "<null>",
opt.timeout);
}
Lretry:
@@ -923,12 +926,12 @@ HostDBContinuation::lookup_done(TextView query_name,
ts_seconds answer_ttl, SRVH
ink_assert(record);
if (query_name.empty()) {
if (is_byname()) {
- Debug("hostdb", "lookup_done() failed for '%.*s'",
int(hash.host_name.size()), hash.host_name.data());
+ Dbg(dbg_ctl_hostdb, "lookup_done() failed for '%.*s'",
int(hash.host_name.size()), hash.host_name.data());
} else if (is_srv()) {
- Debug("dns_srv", "SRV failed for '%.*s'", int(hash.host_name.size()),
hash.host_name.data());
+ Dbg(dbg_ctl_dns_srv, "SRV failed for '%.*s'",
int(hash.host_name.size()), hash.host_name.data());
} else {
ip_text_buffer b;
- Debug("hostdb", "failed for %s", hash.ip.toString(b, sizeof b));
+ Dbg(dbg_ctl_hostdb, "failed for %s", hash.ip.toString(b, sizeof b));
}
record->ip_timestamp = hostdb_current_timestamp;
record->ip_timeout_interval =
ts_seconds(std::clamp(hostdb_ip_fail_timeout_interval, 1u, HOST_DB_MAX_TTL));
@@ -968,13 +971,13 @@ HostDBContinuation::lookup_done(TextView query_name,
ts_seconds answer_ttl, SRVH
record->ip_timeout_interval = std::clamp(answer_ttl, ts_seconds(1),
ts_seconds(HOST_DB_MAX_TTL));
if (is_byname()) {
- Debug_bw("hostdb", "done {} TTL {}", hash.host_name, answer_ttl);
+ Dbg_bw(dbg_ctl_hostdb, "done {} TTL {}", hash.host_name, answer_ttl);
} else if (is_srv()) {
ink_assert(srv && srv->hosts.size() && srv->hosts.size() <=
hostdb_round_robin_max_count);
record->record_type = HostDBType::SRV;
} else {
- Debug_bw("hostdb", "done {} TTL {}", hash.host_name, answer_ttl);
+ Dbg_bw(dbg_ctl_hostdb, "done {} TTL {}", hash.host_name, answer_ttl);
record->record_type = HostDBType::HOST;
}
}
@@ -1064,7 +1067,7 @@ HostDBContinuation::dnsEvent(int event, HostEnt *e)
if (e && e->isNameError() && old_r) {
hostDB.refcountcache->erase(old_r->key);
old_r = nullptr;
- Debug("hostdb", "Removing the old record when the DNS lookup failed with
NXDOMAIN");
+ Dbg(dbg_ctl_hostdb, "Removing the old record when the DNS lookup failed
with NXDOMAIN");
}
int valid_records = 0;
@@ -1155,7 +1158,7 @@ HostDBContinuation::dnsEvent(int event, HostEnt *e)
}
}
// Archetypical example - "%zd" doesn't work on FreeBSD, "%ld"
doesn't work on Ubuntu, "%lld" doesn't work on Fedora.
- Debug_bw("dns_srv", "inserted SRV RR record [{}] into HostDB with
TTL: {} seconds", t->host, ttl);
+ Dbg_bw(dbg_ctl_dns_srv, "inserted SRV RR record [{}] into HostDB
with TTL: {} seconds", t->host, ttl);
}
} else { // Otherwise this is a regular dns response
unsigned idx = 0;
@@ -1237,13 +1240,13 @@ HostDBContinuation::dnsEvent(int event, HostEnt *e)
int
HostDBContinuation::iterateEvent(int event, Event *e)
{
- Debug("hostdb", "iterateEvent event=%d eventp=%p", event, e);
+ Dbg(dbg_ctl_hostdb, "iterateEvent event=%d eventp=%p", event, e);
ink_assert(!link.prev && !link.next);
EThread *t = e ? e->ethread : this_ethread();
MUTEX_TRY_LOCK(lock, action.mutex, t);
if (!lock.is_locked()) {
- Debug("hostdb", "iterateEvent event=%d eventp=%p: reschedule due to not
getting action mutex", event, e);
+ Dbg(dbg_ctl_hostdb, "iterateEvent event=%d eventp=%p: reschedule due to
not getting action mutex", event, e);
mutex->thread_holding->schedule_in(this, HOST_DB_RETRY_PERIOD);
return EVENT_CONT;
}
@@ -1271,12 +1274,12 @@ HostDBContinuation::iterateEvent(int event, Event *e)
if (current_iterate_pos < hostDB.refcountcache->partition_count()) {
// And reschedule ourselves to pickup the next bucket after
HOST_DB_RETRY_PERIOD.
- Debug("hostdb", "iterateEvent event=%d eventp=%p: completed current
iteration %ld of %ld", event, e, current_iterate_pos,
- hostDB.refcountcache->partition_count());
+ Dbg(dbg_ctl_hostdb, "iterateEvent event=%d eventp=%p: completed current
iteration %ld of %ld", event, e, current_iterate_pos,
+ hostDB.refcountcache->partition_count());
mutex->thread_holding->schedule_in(this, HOST_DB_ITERATE_PERIOD);
return EVENT_CONT;
} else {
- Debug("hostdb", "iterateEvent event=%d eventp=%p: completed FINAL
iteration %ld", event, e, current_iterate_pos);
+ Dbg(dbg_ctl_hostdb, "iterateEvent event=%d eventp=%p: completed FINAL
iteration %ld", event, e, current_iterate_pos);
// if there are no more buckets, then we're done.
action.continuation->handleEvent(EVENT_DONE, nullptr);
hostdb_cont_free(this);
@@ -1360,13 +1363,13 @@ HostDBContinuation::set_check_pending_dns()
this->setThreadAffinity(this_ethread());
if (q.in(this)) {
HOSTDB_INCREMENT_DYN_STAT(hostdb_insert_duplicate_to_pending_dns_stat);
- Debug("hostdb", "Skip the insertion of the same continuation to pending
dns");
+ Dbg(dbg_ctl_hostdb, "Skip the insertion of the same continuation to
pending dns");
return false;
}
HostDBContinuation *c = q.head;
for (; c; c = static_cast<HostDBContinuation *>(c->link.next)) {
if (hash.hash == c->hash.hash) {
- Debug("hostdb", "enqueuing additional request");
+ Dbg(dbg_ctl_hostdb, "enqueuing additional request");
q.enqueue(this);
return false;
}
@@ -1389,7 +1392,7 @@ HostDBContinuation::remove_and_trigger_pending_dns()
while (c) {
HostDBContinuation *n = static_cast<HostDBContinuation *>(c->link.next);
if (hash.hash == c->hash.hash) {
- Debug("hostdb", "dequeuing additional request");
+ Dbg(dbg_ctl_hostdb, "dequeuing additional request");
q.remove(c);
qq.enqueue(c);
}
@@ -1420,7 +1423,7 @@ HostDBContinuation::do_dns()
{
ink_assert(!action.cancelled);
if (is_byname()) {
- Debug("hostdb", "DNS %.*s", int(hash.host_name.size()),
hash.host_name.data());
+ Dbg(dbg_ctl_hostdb, "DNS %.*s", int(hash.host_name.size()),
hash.host_name.data());
IpAddr tip;
if (0 == tip.load(hash.host_name)) {
// Need to consider if this is necessary - could the record in
ResolveInfo be left null and
@@ -1468,11 +1471,11 @@ HostDBContinuation::do_dns()
}
pending_action = dnsProcessor.gethostbyname(this, hash.host_name, opt);
} else if (is_srv()) {
- Debug("dns_srv", "SRV lookup of %.*s", int(hash.host_name.size()),
hash.host_name.data());
+ Dbg(dbg_ctl_dns_srv, "SRV lookup of %.*s", int(hash.host_name.size()),
hash.host_name.data());
pending_action = dnsProcessor.getSRVbyname(this, hash.host_name, opt);
} else {
ip_text_buffer ipb;
- Debug("hostdb", "DNS IP %s", hash.ip.toString(ipb, sizeof ipb));
+ Dbg(dbg_ctl_hostdb, "DNS IP %s", hash.ip.toString(ipb, sizeof ipb));
pending_action = dnsProcessor.gethostbyaddr(this, &hash.ip, opt);
}
} else {
@@ -1513,9 +1516,9 @@ HostDBContinuation::backgroundEvent(int /* event
ATS_UNUSED */, Event * /* e ATS
updateHostFileConfig();
REC_ReadConfigString(path, "proxy.config.hostdb.host_file.path",
sizeof(path));
if (0 != strcasecmp(hostdb_hostfile_path.string(), path)) {
- Debug("hostdb", "%s",
- ts::bwprint(dbg, R"(Updating hosts file from "{}" to "{}")",
hostdb_hostfile_path.view(), ts::bwf::FirstOf(path, ""))
- .c_str());
+ Dbg(dbg_ctl_hostdb, "%s",
+ ts::bwprint(dbg, R"(Updating hosts file from "{}" to "{}")",
hostdb_hostfile_path.view(), ts::bwf::FirstOf(path, ""))
+ .c_str());
// path to hostfile changed
hostdb_hostfile_update_timestamp = TS_TIME_ZERO; // never updated from
this file
hostdb_hostfile_path = path;
@@ -1529,11 +1532,12 @@ HostDBContinuation::backgroundEvent(int /* event
ATS_UNUSED */, Event * /* e ATS
update_p = true; // same file but it's changed.
}
} else {
- Debug("hostdb", "%s", ts::bwprint(dbg, R"(Failed to stat host file
"{}" - {})", hostdb_hostfile_path.view(), ec).c_str());
+ Dbg(dbg_ctl_hostdb, "%s",
+ ts::bwprint(dbg, R"(Failed to stat host file "{}" - {})",
hostdb_hostfile_path.view(), ec).c_str());
}
}
if (update_p) {
- Debug("hostdb", "%s", ts::bwprint(dbg, R"(Updating from host file
"{}")", hostdb_hostfile_path.view()).c_str());
+ Dbg(dbg_ctl_hostdb, "%s", ts::bwprint(dbg, R"(Updating from host file
"{}")", hostdb_hostfile_path.view()).c_str());
UpdateHostsFile(hostdb_hostfile_path, hostdb_hostfile_check_interval);
}
}
@@ -1556,18 +1560,18 @@ HostDBRecord::select_best_http(ts_time now, ts_seconds
fail_window, sockaddr con
if (HostDBProcessor::hostdb_strict_round_robin) {
// Always select the next viable target - select failure means no valid
targets at all.
best_alive = best_any = this->select_next_rr(now, fail_window);
- Debug("hostdb", "Using strict round robin - index %d",
this->index_of(best_alive));
+ Dbg(dbg_ctl_hostdb, "Using strict round robin - index %d",
this->index_of(best_alive));
} else if (HostDBProcessor::hostdb_timed_round_robin > 0) {
auto ctime = rr_ctime.load(); // cache for atomic update.
auto ntime = ctime + ts_seconds(HostDBProcessor::hostdb_timed_round_robin);
// Check and update RR if it's time - this always yields a valid target if
there is one.
if (now > ntime && rr_ctime.compare_exchange_strong(ctime, ntime)) {
best_alive = best_any = this->select_next_rr(now, fail_window);
- Debug("hostdb", "Round robin timed interval expired - index %d",
this->index_of(best_alive));
+ Dbg(dbg_ctl_hostdb, "Round robin timed interval expired - index %d",
this->index_of(best_alive));
} else { // pick the current index, which may be dead.
best_any = &info[this->rr_idx()];
}
- Debug("hostdb", "Using timed round robin - index %d",
this->index_of(best_any));
+ Dbg(dbg_ctl_hostdb, "Using timed round robin - index %d",
this->index_of(best_any));
} else {
// Walk the entries and find the best (largest) hash.
unsigned int best_hash = 0; // any hash is better than this.
@@ -1578,7 +1582,7 @@ HostDBRecord::select_best_http(ts_time now, ts_seconds
fail_window, sockaddr con
best_hash = h;
}
}
- Debug("hostdb", "Using client affinity - index %d",
this->index_of(best_any));
+ Dbg(dbg_ctl_hostdb, "Using client affinity - index %d",
this->index_of(best_any));
}
// If there is a base choice, search for valid target starting there.
@@ -1854,7 +1858,7 @@ register_ShowHostDB(Continuation *c, HTTPHdr *h)
if (query && query_len && strstr(query, "json")) {
s->output_json = true;
}
- Debug("hostdb", "dumping all hostdb records");
+ Dbg(dbg_ctl_hostdb, "dumping all hostdb records");
SET_CONTINUATION_HANDLER(s, &ShowHostDB::showAll);
}
this_ethread()->schedule_imm(s);
@@ -2002,7 +2006,7 @@ UpdateHostsFile(swoc::file::path const &path, ts_seconds
interval)
// Test and set for update in progress.
bool flag = false;
if (!HostDBFileUpdateActive.compare_exchange_strong(flag, true)) {
- Debug("hostdb", "Skipped load of host file because update already in
progress");
+ Dbg(dbg_ctl_hostdb, "Skipped load of host file because update already in
progress");
return;
}
@@ -2111,7 +2115,7 @@ void
HostDBRecord::free()
{
if (_iobuffer_index >= 0) {
- Debug("hostdb", "freeing %d bytes at [%p]", (1 << (7 + _iobuffer_index)),
this);
+ Dbg(dbg_ctl_hostdb, "freeing %d bytes at [%p]", (1 << (7 +
_iobuffer_index)), this);
ioBufAllocator[_iobuffer_index].free_void(static_cast<void *>(this));
}
}
@@ -2130,8 +2134,8 @@ HostDBRecord::alloc(TextView query_name, unsigned int
rr_count, size_t srv_name_
self->_iobuffer_index = iobuffer_index;
self->_record_size = r_size;
- Debug("hostdb", "allocating %ld bytes for %.*s with %d RR records at [%p]",
r_size.value(), int(query_name.size()),
- query_name.data(), rr_count, self);
+ Dbg(dbg_ctl_hostdb, "allocating %ld bytes for %.*s with %d RR records at
[%p]", r_size.value(), int(query_name.size()),
+ query_name.data(), rr_count, self);
// where in our block of memory we are
int offset = sizeof(self_type);
@@ -2175,8 +2179,8 @@ HostDBRecord::serve_stale_but_revalidate() const
// hostdb_serve_stale_but_revalidate == number of seconds
// ip_age() is the number of seconds between now() and when the entry was
inserted
if ((ip_timeout_interval + ts_seconds(hostdb_serve_stale_but_revalidate)) >
ip_age()) {
- Debug_bw("hostdb", "serving stale entry for {}, TTL: {}, serve_stale_for:
{}, age: {} as requested by config", name(),
- ip_timeout_interval, hostdb_serve_stale_but_revalidate, ip_age());
+ Dbg_bw(dbg_ctl_hostdb, "serving stale entry for {}, TTL: {},
serve_stale_for: {}, age: {} as requested by config", name(),
+ ip_timeout_interval, hostdb_serve_stale_but_revalidate, ip_age());
return true;
}
@@ -2272,7 +2276,7 @@ ResolveInfo::resolve_immediate()
// nothing - already resolved.
} else if (IpAddr tmp; TS_SUCCESS == tmp.load(lookup_name)) {
ts::bwprint(ts::bw_dbg, "[resolve_immediate] success - FQDN '{}' is a
valid IP address.", lookup_name);
- Debug("hostdb", "%s", ts::bw_dbg.c_str());
+ Dbg(dbg_ctl_hostdb, "%s", ts::bw_dbg.c_str());
addr.assign(tmp);
resolved_p = true;
}
diff --git a/iocore/hostdb/HostFile.cc b/iocore/hostdb/HostFile.cc
index a791edcf1..9d259ee3a 100644
--- a/iocore/hostdb/HostFile.cc
+++ b/iocore/hostdb/HostFile.cc
@@ -86,7 +86,8 @@ ParseHostFile(swoc::file::path const &path, ts_seconds
interval)
{
std::shared_ptr<HostFile> hf;
- Debug_bw("hostdb", R"(Loading host file "{}")", path.view());
+ static DbgCtl dbg_ctl{"hostdb"};
+ Dbg_bw(dbg_ctl, R"(Loading host file "{}")", path.view());
if (!path.empty()) {
std::error_code ec;
diff --git a/iocore/hostdb/P_RefCountCache.h b/iocore/hostdb/P_RefCountCache.h
index 76b599e99..fba8e1156 100644
--- a/iocore/hostdb/P_RefCountCache.h
+++ b/iocore/hostdb/P_RefCountCache.h
@@ -148,9 +148,15 @@ struct RefCountCacheLinkage {
}
};
+class RefCountCacheBase
+{
+protected:
+ inline static DbgCtl dbg_ctl{"refcountcache"};
+};
+
// The RefCountCachePartition is simply a map of key -> Ptr<YourClass>
// We partition the cache to reduce lock contention
-template <class C> class RefCountCachePartition
+template <class C> class RefCountCachePartition : private RefCountCacheBase
{
public:
using hash_type = IntrusiveHashMap<RefCountCacheLinkage>;
@@ -219,7 +225,7 @@ RefCountCachePartition<C>::put(uint64_t key, C *item, int
size, int expire_time)
// if we are full, and can't make space-- then don't store the item
if (this->is_full() && !this->make_space_for(size)) {
- Debug("refcountcache", "partition %d is full-- not storing item key=%"
PRIu64, this->part_num, key);
+ Dbg(dbg_ctl, "partition %d is full-- not storing item key=%" PRIu64,
this->part_num, key);
this->metric_inc(refcountcache_total_failed_inserts_stat, 1);
return;
}
@@ -230,7 +236,7 @@ RefCountCachePartition<C>::put(uint64_t key, C *item, int
size, int expire_time)
// add expiry_entry to expiry queue, if the expire time is positive
(otherwise it means don't expire)
if (expire_time >= 0) {
- Debug("refcountcache", "partition %d adding entry with expire_time=%d\n",
this->part_num, expire_time);
+ Dbg(dbg_ctl, "partition %d adding entry with expire_time=%d\n",
this->part_num, expire_time);
PriorityQueueEntry<RefCountCacheHashEntry *> *expiry_entry =
expiryQueueEntry.alloc();
new ((void *)expiry_entry) PriorityQueueEntry<RefCountCacheHashEntry
*>(val);
expiry_queue.push(expiry_entry);
@@ -272,7 +278,7 @@
RefCountCachePartition<C>::dealloc_entry(hash_type::iterator ptr)
// remove from expiry queue
if (ptr->expiry_entry != nullptr) {
- Debug("refcountcache", "partition %d deleting item from expiry_queue
idx=%d", this->part_num, ptr->expiry_entry->index);
+ Dbg(dbg_ctl, "partition %d deleting item from expiry_queue idx=%d",
this->part_num, ptr->expiry_entry->index);
this->expiry_queue.erase(ptr->expiry_entry);
expiryQueueEntry.free(ptr->expiry_entry);
@@ -303,8 +309,8 @@ template <class C>
bool
RefCountCachePartition<C>::is_full() const
{
- Debug("refcountcache", "partition %d is full? items %d/%d size %" PRIu64
"/%" PRIu64 "\n\n", this->part_num, this->items,
- this->max_items, this->size, this->max_size);
+ Dbg(dbg_ctl, "partition %d is full? items %d/%d size %" PRIu64 "/%" PRIu64
"\n\n", this->part_num, this->items, this->max_items,
+ this->size, this->max_size);
return (this->max_items > 0 && this->items >= this->max_items) ||
(this->max_size > 0 && this->size >= this->max_size);
}
diff --git a/iocore/hostdb/P_RefCountCacheSerializer.h
b/iocore/hostdb/P_RefCountCacheSerializer.h
index 0418fdab6..fe9bc7681 100644
--- a/iocore/hostdb/P_RefCountCacheSerializer.h
+++ b/iocore/hostdb/P_RefCountCacheSerializer.h
@@ -38,7 +38,7 @@
//
// This way we only have to hold the lock on the partition for the
// time it takes to get Ptr<>s to all items in the partition
-template <class C> class RefCountCacheSerializer : public Continuation
+template <class C> class RefCountCacheSerializer : public Continuation,
private RefCountCacheBase
{
public:
size_t partition; // Current partition
@@ -96,7 +96,7 @@
RefCountCacheSerializer<C>::RefCountCacheSerializer(Continuation *acont, RefCoun
{
this->tmp_filename = this->filename + ".syncing"; // TODO tmp file extension
configurable?
- Debug("refcountcache", "started serializer %p", this);
+ Dbg(dbg_ctl, "started serializer %p", this);
SET_HANDLER(&RefCountCacheSerializer::initialize_storage);
eventProcessor.schedule_imm(this, ET_TASK);
}
@@ -114,7 +114,7 @@ template <class C>
RefCountCacheSerializer<C>::~RefCountCacheSerializer()
}
this->partition_items.clear();
- Debug("refcountcache", "finished serializer %p", this);
+ Dbg(dbg_ctl, "finished serializer %p", this);
// Note that we have to do the unlink before we send the completion event,
otherwise
// we could unlink the sync file out from under another serializer.
@@ -133,12 +133,12 @@ RefCountCacheSerializer<C>::copy_partition(int /* event
*/, Event *e)
Warning("Unable to finalize sync of cache to disk %s: %s",
this->filename.c_str(), strerror(-error));
}
- Debug("refcountcache", "RefCountCacheSync done");
+ Dbg(dbg_ctl, "RefCountCacheSync done");
delete this;
return EVENT_DONE;
}
- Debug("refcountcache", "sync partition=%ld/%ld", partition,
cache->partition_count());
+ Dbg(dbg_ctl, "sync partition=%ld/%ld", partition, cache->partition_count());
// copy the partition into our buffer, then we'll let `pauseEvent` write it
out
this->partition_items.reserve(cache->get_partition(partition).count());
cache->get_partition(partition).copy(this->partition_items);
diff --git a/iocore/hostdb/test_HostFile.cc b/iocore/hostdb/test_HostFile.cc
index c32a3f0bb..c21924159 100644
--- a/iocore/hostdb/test_HostFile.cc
+++ b/iocore/hostdb/test_HostFile.cc
@@ -31,8 +31,15 @@
#include "HostFile.h"
#include "P_HostDBProcessor.h"
+namespace
+{
+
+DbgCtl dbg_ctl_hostdb{"hostdb"};
+
const std::string_view hosts_data = "127.0.0.1 localhost\n::1
localhost\n1.2.3.4 host1\n4.3.2.1 host2 host3\n"_sv;
+} // end anonymous namespace
+
void
spit(const swoc::file::path &p, std::string_view data)
{
@@ -146,8 +153,8 @@ HostDBRecord::alloc(ts::TextView query_name, unsigned int
rr_count, size_t srv_n
self->_iobuffer_index = 0;
self->_record_size = r_size;
- Debug("hostdb", "allocating %ld bytes for %.*s with %d RR records at [%p]",
r_size.value(), int(query_name.size()),
- query_name.data(), rr_count, self);
+ Dbg(dbg_ctl_hostdb, "allocating %ld bytes for %.*s with %d RR records at
[%p]", r_size.value(), int(query_name.size()),
+ query_name.data(), rr_count, self);
// where in our block of memory we are
int offset = sizeof(self_type);
diff --git a/iocore/net/P_SSLUtils.h b/iocore/net/P_SSLUtils.h
index 752ff80c8..e9103fb9f 100644
--- a/iocore/net/P_SSLUtils.h
+++ b/iocore/net/P_SSLUtils.h
@@ -112,6 +112,7 @@ protected:
private:
virtual const char *_debug_tag() const;
+ virtual const DbgCtl &_dbg_ctl() const;
virtual bool _store_ssl_ctx(SSLCertLookup *lookup,
shared_SSLMultiCertConfigParams ssl_multi_cert_params);
bool _prep_ssl_ctx(const shared_SSLMultiCertConfigParams
&sslMultCertSettings, SSLMultiCertConfigLoader::CertLoadData &data,
std::set<std::string> &common_names,
std::unordered_map<int, std::set<std::string>> &unique_names);
diff --git a/iocore/net/SSLSecret.cc b/iocore/net/SSLSecret.cc
index 95052046a..f90db39a9 100644
--- a/iocore/net/SSLSecret.cc
+++ b/iocore/net/SSLSecret.cc
@@ -26,6 +26,14 @@
#include <utility>
+namespace
+{
+
+DbgCtl dbg_ctl_ssl_secret{"ssl_secret"};
+DbgCtl dbg_ctl_ssl_secret_err{"ssl_secret_err"};
+
+} // end anonymous namespace
+
// NOTE: The secret_map_mutex should not be held by the caller of this
// function. The implementation of this function may call a plugin's
// TS_EVENT_SSL_SECRET handler which in turn may grab a lock for
@@ -63,17 +71,17 @@ SSLSecret::loadSecret(const std::string &name1, const
std::string &name2, std::s
std::string
SSLSecret::loadFile(const std::string &name)
{
- Debug("ssl_secret", "SSLSecret::loadFile(%s)", name.c_str());
+ Dbg(dbg_ctl_ssl_secret, "SSLSecret::loadFile(%s)", name.c_str());
std::error_code error;
std::string const data = swoc::file::load(swoc::file::path(name), error);
if (error) {
- Debug("ssl_secret_err", "SSLSecret::loadFile(%s) failed error code=%d
message=%s", name.c_str(), error.value(),
- error.message().c_str());
+ Dbg(dbg_ctl_ssl_secret_err, "SSLSecret::loadFile(%s) failed error code=%d
message=%s", name.c_str(), error.value(),
+ error.message().c_str());
// Loading file failed
- Debug("ssl_secret", "Loading file: %s failed ", name.c_str());
+ Dbg(dbg_ctl_ssl_secret, "Loading file: %s failed ", name.c_str());
return std::string{};
}
- Debug("ssl_secret", "Secret data: %.50s", data.c_str());
+ Dbg(dbg_ctl_ssl_secret, "Secret data: %.50s", data.c_str());
if (SSLConfigParams::load_ssl_file_cb) {
SSLConfigParams::load_ssl_file_cb(name.c_str());
}
@@ -86,7 +94,7 @@ SSLSecret::setSecret(const std::string &name,
std::string_view data)
std::scoped_lock lock(secret_map_mutex);
secret_map[name] = std::string{data};
// The full secret data can be sensitive. Print only the first 50 bytes.
- Debug("ssl_secret", "Set secret for %s to %.*s", name.c_str(),
int(data.size() > 50 ? 50 : data.size()), data.data());
+ Dbg(dbg_ctl_ssl_secret, "Set secret for %s to %.*s", name.c_str(),
int(data.size() > 50 ? 50 : data.size()), data.data());
}
std::string
@@ -95,22 +103,22 @@ SSLSecret::getSecret(const std::string &name) const
std::scoped_lock lock(secret_map_mutex);
auto iter = secret_map.find(name);
if (secret_map.end() == iter) {
- Debug("ssl_secret", "Get secret for %s: not found", name.c_str());
+ Dbg(dbg_ctl_ssl_secret, "Get secret for %s: not found", name.c_str());
return std::string{};
}
if (iter->second.empty()) {
- Debug("ssl_secret", "Get secret for %s: empty", name.c_str());
+ Dbg(dbg_ctl_ssl_secret, "Get secret for %s: empty", name.c_str());
return std::string{};
}
// The full secret data can be sensitive. Print only the first 50 bytes.
- Debug("ssl_secret", "Get secret for %s: %.50s", name.c_str(),
iter->second.c_str());
+ Dbg(dbg_ctl_ssl_secret, "Get secret for %s: %.50s", name.c_str(),
iter->second.c_str());
return iter->second;
}
void
SSLSecret::getOrLoadSecret(const std::string &name1, const std::string &name2,
std::string &data1, std::string &data2)
{
- Debug("ssl_secret", "lookup up secrets for %s and %s", name1.c_str(),
name2.c_str());
+ Dbg(dbg_ctl_ssl_secret, "lookup up secrets for %s and %s", name1.c_str(),
name2.c_str());
{
std::scoped_lock lock(secret_map_mutex);
std::string *const data1ptr = &(secret_map[name1]);
diff --git a/iocore/net/SSLUtils.cc b/iocore/net/SSLUtils.cc
index 51a7c9924..9c9caef4e 100644
--- a/iocore/net/SSLUtils.cc
+++ b/iocore/net/SSLUtils.cc
@@ -105,6 +105,11 @@ static int ssl_vc_index = -1;
static ink_mutex *mutex_buf = nullptr;
static bool open_ssl_initialized = false;
+static DbgCtl dbg_ctl_ssl_load{"ssl_load"};
+static DbgCtl dbg_ctl_ssl_session_cache{"ssl.session_cache"};
+static DbgCtl dbg_ctl_ssl_error{"ssl.error"};
+static DbgCtl dbg_ctl_ssl_verify{"ssl_verify"};
+
/* Using pthread thread ID and mutex functions directly, instead of
* ATS this_ethread / ProxyMutex, so that other linked libraries
* may use pthreads and openssl without confusing us here. (TS-2271).
@@ -123,7 +128,8 @@ SSL_pthreads_thread_id(CRYPTO_THREADID *id)
static void
SSL_locking_callback(int mode, int type, const char *file, int line)
{
- Debug("v_ssl_lock", "file: %s line: %d type: %d", file, line, type);
+ DbgCtl dbg_ctl{"v_ssl_lock"};
+ Dbg(dbg_ctl, "file: %s line: %d type: %d", file, line, type);
ink_assert(type < CRYPTO_num_locks());
#ifdef OPENSSL_FIPS
@@ -138,7 +144,7 @@ SSL_locking_callback(int mode, int type, const char *file,
int line)
} else if (mode & CRYPTO_UNLOCK) {
ink_mutex_release(&mutex_buf[type]);
} else {
- Debug("ssl_load", "invalid SSL locking mode 0x%x", mode);
+ Dbg(dbg_ctl_ssl_load, "invalid SSL locking mode 0x%x", mode);
ink_assert(0);
}
}
@@ -210,7 +216,7 @@ ssl_new_cached_session(SSL *ssl, SSL_SESSION *sess)
SSLSessionID sid(id, len);
if (diags()->on()) {
- static DbgCtl dbg_ctl("ssl.session_cache.insert");
+ static DbgCtl dbg_ctl("ssl_session_cache.insert");
if (dbg_ctl.ptr()->on) {
char printable_buf[(len * 2) + 1];
@@ -253,7 +259,7 @@ ssl_rm_cached_session(SSL_CTX *ctx, SSL_SESSION *sess)
}
if (diags()->on()) {
- static DbgCtl dbg_ctl("ssl.session_cache.remove");
+ static DbgCtl dbg_ctl("ssl_session_cache.remove");
if (dbg_ctl.ptr()->on) {
char printable_buf[(len * 2) + 1];
sid.toString(printable_buf, sizeof(printable_buf));
@@ -268,12 +274,12 @@ ssl_rm_cached_session(SSL_CTX *ctx, SSL_SESSION *sess)
static int
ssl_verify_client_callback(int preverify_ok, X509_STORE_CTX *ctx)
{
- Debug("ssl_verify", "Callback: verify client cert");
+ Dbg(dbg_ctl_ssl_verify, "Callback: verify client cert");
auto *ssl = static_cast<SSL
*>(X509_STORE_CTX_get_ex_data(ctx, SSL_get_ex_data_X509_STORE_CTX_idx()));
SSLNetVConnection *netvc = SSLNetVCAccess(ssl);
if (!netvc || netvc->ssl != ssl) {
- Debug("ssl_verify", "ssl_verify_client_callback call back on stale netvc");
+ Dbg(dbg_ctl_ssl_verify, "ssl_verify_client_callback call back on stale
netvc");
return false;
}
@@ -305,14 +311,14 @@ ssl_client_hello_callback(SSL *s, int *al, void *arg)
// This error suggests either of these:
// 1) Call back on unsupported netvc -- Don't register callback
unnecessarily
// 2) Call back on stale netvc
- Debug("ssl.error", "ssl_client_hello_callback was called unexpectedly");
+ Dbg(dbg_ctl_ssl_error, "ssl_client_hello_callback was called
unexpectedly");
return SSL_CLIENT_HELLO_ERROR;
}
SSLNetVConnection *netvc = dynamic_cast<SSLNetVConnection *>(snis);
if (netvc) {
if (netvc->ssl != s) {
- Debug("ssl.error", "ssl_client_hello_callback call back on stale netvc");
+ Dbg(dbg_ctl_ssl_error, "ssl_client_hello_callback call back on stale
netvc");
return SSL_CLIENT_HELLO_ERROR;
}
@@ -341,14 +347,14 @@ ssl_client_hello_callback(const SSL_CLIENT_HELLO
*client_hello)
// This error suggests either of these:
// 1) Call back on unsupported netvc -- Don't register callback
unnecessarily
// 2) Call back on stale netvc
- Debug("ssl.error", "ssl_client_hello_callback was called unexpectedly");
+ Dbg(dbg_ctl_ssl_error, "ssl_client_hello_callback was called
unexpectedly");
return ssl_select_cert_error;
}
SSLNetVConnection *netvc = dynamic_cast<SSLNetVConnection *>(snis);
if (netvc) {
if (netvc->ssl != s) {
- Debug("ssl.error", "ssl_client_hello_callback call back on stale netvc");
+ Dbg(dbg_ctl_ssl_error, "ssl_client_hello_callback call back on stale
netvc");
return ssl_select_cert_error;
}
@@ -461,7 +467,7 @@ ssl_servername_callback(SSL *ssl, int *al, void *arg)
// This error suggests either of these:
// 1) Call back on unsupported netvc -- Don't register callback
unnecessarily
// 2) Call back on stale netvc
- Debug("ssl.error", "ssl_servername_callback was called unexpectedly");
+ Dbg(dbg_ctl_ssl_error, "ssl_servername_callback was called unexpectedly");
return SSL_TLSEXT_ERR_ALERT_FATAL;
}
@@ -557,7 +563,8 @@ SSLMultiCertConfigLoader::_enable_ktls(SSL_CTX *ctx)
#ifdef SSL_OP_ENABLE_KTLS
if (SSLConfigParams::ssl_ktls_enabled) {
if (SSL_CTX_set_options(ctx, SSL_OP_ENABLE_KTLS)) {
- Debug("ssl.ktls", "KTLS is enabled");
+ static DbgCtl dbg_ctl{"ssl.ktls"};
+ Dbg(dbg_ctl, "KTLS is enabled");
} else {
return false;
}
@@ -756,7 +763,7 @@ ssl_private_key_passphrase_callback_exec(char *buf, int
size, int rwflag, void *
*buf = 0;
passphrase_cb_userdata *ud = static_cast<passphrase_cb_userdata *>(userdata);
- Debug("ssl_load", "ssl_private_key_passphrase_callback_exec rwflag=%d
serverDialog=%s", rwflag, ud->_serverDialog);
+ Dbg(dbg_ctl_ssl_load, "ssl_private_key_passphrase_callback_exec rwflag=%d
serverDialog=%s", rwflag, ud->_serverDialog);
// only respond to reading private keys, not writing them (does ats even do
that?)
if (0 == rwflag) {
@@ -790,7 +797,7 @@ ssl_private_key_passphrase_callback_builtin(char *buf, int
size, int rwflag, voi
*buf = 0;
passphrase_cb_userdata *ud = static_cast<passphrase_cb_userdata *>(userdata);
- Debug("ssl_load", "ssl_private_key_passphrase_callback rwflag=%d
serverDialog=%s", rwflag, ud->_serverDialog);
+ Dbg(dbg_ctl_ssl_load, "ssl_private_key_passphrase_callback rwflag=%d
serverDialog=%s", rwflag, ud->_serverDialog);
// only respond to reading private keys, not writing them (does ats even do
that?)
if (0 == rwflag) {
@@ -922,7 +929,7 @@ SSLInitializeLibrary()
// After POST we don't have to lock for FIPS
int mode = FIPS_mode();
FIPS_mode_set(mode);
- Debug("ssl_load", "FIPS_mode: %d", mode);
+ Dbg(dbg_ctl_ssl_load, "FIPS_mode: %d", mode);
#endif
mutex_buf = static_cast<ink_mutex *>(OPENSSL_malloc(CRYPTO_num_locks() *
sizeof(ink_mutex)));
@@ -973,7 +980,7 @@ SSLPrivateKeyHandler(SSL_CTX *ctx, const SSLConfigParams
*params, const char *ke
pkey = ENGINE_load_private_key(e, keyPath, nullptr, nullptr);
if (pkey) {
if (!SSL_CTX_use_PrivateKey(ctx, pkey)) {
- Debug("ssl_load", "failed to load server private key from engine");
+ Dbg(dbg_ctl_ssl_load, "failed to load server private key from engine");
EVP_PKEY_free(pkey);
return false;
}
@@ -986,18 +993,18 @@ SSLPrivateKeyHandler(SSL_CTX *ctx, const SSLConfigParams
*params, const char *ke
scoped_BIO bio(BIO_new_mem_buf(secret_data, secret_data_len));
pkey = PEM_read_bio_PrivateKey(bio.get(), nullptr, nullptr, nullptr);
if (nullptr == pkey) {
- Debug("ssl_load", "failed to load server private key (%.*s) from %s",
secret_data_len < 50 ? secret_data_len : 50,
- secret_data, (!keyPath || keyPath[0] == '\0') ? "[empty key path]"
: keyPath);
+ Dbg(dbg_ctl_ssl_load, "failed to load server private key (%.*s) from
%s", secret_data_len < 50 ? secret_data_len : 50,
+ secret_data, (!keyPath || keyPath[0] == '\0') ? "[empty key path]" :
keyPath);
return false;
}
if (!SSL_CTX_use_PrivateKey(ctx, pkey)) {
- Debug("ssl_load", "failed to attach server private key loaded from %s",
- (!keyPath || keyPath[0] == '\0') ? "[empty key path]" : keyPath);
+ Dbg(dbg_ctl_ssl_load, "failed to attach server private key loaded from
%s",
+ (!keyPath || keyPath[0] == '\0') ? "[empty key path]" : keyPath);
EVP_PKEY_free(pkey);
return false;
}
if (e == nullptr && !SSL_CTX_check_private_key(ctx)) {
- Debug("ssl_load", "server private key does not match the certificate
public key");
+ Dbg(dbg_ctl_ssl_load, "server private key does not match the certificate
public key");
return false;
}
}
@@ -1051,7 +1058,7 @@ SSLMultiCertConfigLoader::check_server_cert_now(X509
*cert, const char *certname
return -5;
}
- Debug("ssl_load", "server certificate %s passed accessibility and date
checks", certname);
+ Dbg(dbg_ctl_ssl_load, "server certificate %s passed accessibility and date
checks", certname);
return 0; // all good
} /* CheckServerCertNow() */
@@ -1072,12 +1079,12 @@ asn1_strdup(ASN1_STRING *s)
static void
ssl_callback_info(const SSL *ssl, int where, int ret)
{
- Debug("ssl_load", "ssl_callback_info ssl: %p, where: %d, ret: %d, State:
%s", ssl, where, ret, SSL_state_string_long(ssl));
+ Dbg(dbg_ctl_ssl_load, "ssl_callback_info ssl: %p, where: %d, ret: %d, State:
%s", ssl, where, ret, SSL_state_string_long(ssl));
SSLNetVConnection *netvc = SSLNetVCAccess(ssl);
if (!netvc || netvc->ssl != ssl) {
- Debug("ssl.error", "ssl_callback_info call back on stale netvc");
+ Dbg(dbg_ctl_ssl_error, "ssl_callback_info call back on stale netvc");
return;
}
@@ -1104,12 +1111,12 @@ ssl_callback_info(const SSL *ssl, int where, int ret)
#ifdef TLS1_3_VERSION
// TLSv1.3 has no renegotiation.
if (SSL_version(ssl) >= TLS1_3_VERSION) {
- Debug("ssl_load", "TLSv1.3 has no renegotiation.");
+ Dbg(dbg_ctl_ssl_load, "TLSv1.3 has no renegotiation.");
return;
}
#endif
netvc->setSSLClientRenegotiationAbort(true);
- Debug("ssl_load", "ssl_callback_info trying to renegotiate from the
client");
+ Dbg(dbg_ctl_ssl_load, "ssl_callback_info trying to renegotiate from the
client");
}
}
if (where & SSL_CB_HANDSHAKE_DONE) {
@@ -1192,7 +1199,7 @@ setClientCertLevel(SSL *ssl, uint8_t certLevel)
ink_release_assert(!"Invalid client verify level");
}
- Debug("ssl_load", "setting cert level to %d", server_verify_client);
+ Dbg(dbg_ctl_ssl_load, "setting cert level to %d", server_verify_client);
SSL_set_verify(ssl, server_verify_client, ssl_verify_client_callback);
SSL_set_verify_depth(ssl, params->verify_depth); // might want to make
configurable at some point.
}
@@ -1267,8 +1274,8 @@
SSLMultiCertConfigLoader::init_server_ssl_ctx(CertLoadData const &data, const SS
ctx_type = (!generate_default_ctx && i < data.cert_type_list.size()) ?
data.cert_type_list[i] : SSLCertContextType::GENERIC;
- Debug("ssl_load", "Creating new context %p cert_count=%ld initial: %s",
ctx, cert_names_list.size(),
- cert_names_list[0].c_str());
+ Dbg(dbg_ctl_ssl_load, "Creating new context %p cert_count=%ld initial:
%s", ctx, cert_names_list.size(),
+ cert_names_list[0].c_str());
SSL_CTX_set_options(ctx, _params->ssl_ctx_options);
@@ -1293,7 +1300,7 @@
SSLMultiCertConfigLoader::init_server_ssl_ctx(CertLoadData const &data, const SS
}
#ifdef SSL_MODE_RELEASE_BUFFERS
- Debug("ssl_load", "enabling SSL_MODE_RELEASE_BUFFERS");
+ Dbg(dbg_ctl_ssl_load, "enabling SSL_MODE_RELEASE_BUFFERS");
SSL_CTX_set_mode(ctx, SSL_MODE_RELEASE_BUFFERS);
#endif
@@ -1399,11 +1406,11 @@ SSLMultiCertConfigLoader::_setup_session_cache(SSL_CTX
*ctx)
{
const SSLConfigParams *params = this->_params;
- Debug("ssl.session_cache",
- "ssl context=%p: using session cache options, enabled=%d, size=%d,
num_buckets=%d, "
- "skip_on_contention=%d, timeout=%d, auto_clear=%d",
- ctx, params->ssl_session_cache, params->ssl_session_cache_size,
params->ssl_session_cache_num_buckets,
- params->ssl_session_cache_skip_on_contention,
params->ssl_session_cache_timeout, params->ssl_session_cache_auto_clear);
+ Dbg(dbg_ctl_ssl_session_cache,
+ "ssl context=%p: using session cache options, enabled=%d, size=%d,
num_buckets=%d, "
+ "skip_on_contention=%d, timeout=%d, auto_clear=%d",
+ ctx, params->ssl_session_cache, params->ssl_session_cache_size,
params->ssl_session_cache_num_buckets,
+ params->ssl_session_cache_skip_on_contention,
params->ssl_session_cache_timeout, params->ssl_session_cache_auto_clear);
if (params->ssl_session_cache_timeout) {
SSL_CTX_set_timeout(ctx, params->ssl_session_cache_timeout);
@@ -1414,18 +1421,18 @@ SSLMultiCertConfigLoader::_setup_session_cache(SSL_CTX
*ctx)
switch (params->ssl_session_cache) {
case SSLConfigParams::SSL_SESSION_CACHE_MODE_OFF:
- Debug("ssl.session_cache", "disabling SSL session cache");
+ Dbg(dbg_ctl_ssl_session_cache, "disabling SSL session cache");
SSL_CTX_set_session_cache_mode(ctx, SSL_SESS_CACHE_OFF |
SSL_SESS_CACHE_NO_INTERNAL);
break;
case SSLConfigParams::SSL_SESSION_CACHE_MODE_SERVER_OPENSSL_IMPL:
- Debug("ssl.session_cache", "enabling SSL session cache with OpenSSL
implementation");
+ Dbg(dbg_ctl_ssl_session_cache, "enabling SSL session cache with OpenSSL
implementation");
SSL_CTX_set_session_cache_mode(ctx, SSL_SESS_CACHE_SERVER |
additional_cache_flags);
SSL_CTX_sess_set_cache_size(ctx, params->ssl_session_cache_size);
break;
case SSLConfigParams::SSL_SESSION_CACHE_MODE_SERVER_ATS_IMPL: {
- Debug("ssl.session_cache", "enabling SSL session cache with ATS
implementation");
+ Dbg(dbg_ctl_ssl_session_cache, "enabling SSL session cache with ATS
implementation");
/* Add all the OpenSSL callbacks */
SSL_CTX_sess_set_new_cb(ctx, ssl_new_cached_session);
SSL_CTX_sess_set_remove_cb(ctx, ssl_rm_cached_session);
@@ -1506,13 +1513,13 @@ SSLMultiCertConfigLoader::_setup_session_ticket(SSL_CTX
*ctx, const SSLMultiCert
// Session tickets are enabled by default. Disable if explicitly requested.
if (sslMultCertSettings->session_ticket_enabled == 0) {
SSL_CTX_set_options(ctx, SSL_OP_NO_TICKET);
- Debug("ssl_load", "ssl session ticket is disabled");
+ Dbg(dbg_ctl_ssl_load, "ssl session ticket is disabled");
}
#endif
#if defined(TLS1_3_VERSION) && !defined(LIBRESSL_VERSION_NUMBER) &&
!defined(OPENSSL_IS_BORINGSSL)
if (!(this->_params->ssl_ctx_options & SSL_OP_NO_TLSv1_3)) {
SSL_CTX_set_num_tickets(ctx, sslMultCertSettings->session_ticket_number);
- Debug("ssl_load", "ssl session ticket number set to %d",
sslMultCertSettings->session_ticket_number);
+ Dbg(dbg_ctl_ssl_load, "ssl session ticket number set to %d",
sslMultCertSettings->session_ticket_number);
}
#endif
return true;
@@ -1698,7 +1705,7 @@ SSLMultiCertConfigLoader::_prep_ssl_ctx(const
shared_SSLMultiCertConfigParams &s
if (0 > SSLMultiCertConfigLoader::check_server_cert_now(cert,
current_cert_name)) {
/* At this point, we know cert is bad, and we've already printed a
descriptive reason as to why cert is bad to the log file */
- Debug(this->_debug_tag(), "Marking certificate as NOT VALID: %s",
current_cert_name);
+ Dbg(this->_dbg_ctl(), "Marking certificate as NOT VALID: %s",
current_cert_name);
good_certs = false;
}
i++;
@@ -1862,7 +1869,7 @@
SSLMultiCertConfigLoader::_store_single_ssl_ctx(SSLCertLookup *lookup, const sha
// Index this certificate by the specified IP(v6) address. If the address is
"*", make it the default context.
if (sslMultCertSettings->addr) {
if (strcmp(sslMultCertSettings->addr, "*") == 0) {
- Debug("ssl_load", "Addr is '*'; setting %p to default", ctx.get());
+ Dbg(dbg_ctl_ssl_load, "Addr is '*'; setting %p to default", ctx.get());
if (lookup->insert(sslMultCertSettings->addr, SSLCertContext(ctx,
ctx_type, sslMultCertSettings, keyblock)) >= 0) {
inserted = true;
lookup->ssl_default = ctx;
@@ -1917,7 +1924,7 @@ ssl_extract_certificate(const matcher_line *line_info,
SSLMultiCertConfigParams
if (label == nullptr) {
continue;
}
- Debug("ssl_load", "Extracting certificate label: %s, value: %s", label,
value);
+ Dbg(dbg_ctl_ssl_load, "Extracting certificate label: %s, value: %s",
label, value);
if (strcasecmp(label, SSL_IP_TAG) == 0) {
sslMultCertSettings->addr = ats_strdup(value);
@@ -2024,7 +2031,7 @@ SSLMultiCertConfigLoader::load(SSLCertLookup *lookup)
const char *errPtr;
errPtr = parseConfigLine(line, &line_info, &sslCertTags);
- Debug("ssl_load", "currently parsing %s at line %d from config file:
%s", line, line_num, params->configFilePath);
+ Dbg(dbg_ctl_ssl_load, "currently parsing %s at line %d from config file:
%s", line, line_num, params->configFilePath);
if (errPtr != nullptr) {
Warning("%s: discarding %s entry at line %d: %s", __func__,
params->configFilePath, line_num, errPtr);
} else {
@@ -2299,11 +2306,11 @@
SSLMultiCertConfigLoader::load_certs_and_cross_reference_names(
ASN1_STRING *cn = X509_NAME_ENTRY_get_data(e);
subj_name = asn1_strdup(cn);
- Debug("ssl_load", "subj '%s' in certificate %s %p", subj_name.get(),
data.cert_names_list[i].c_str(), cert);
+ Dbg(dbg_ctl_ssl_load, "subj '%s' in certificate %s %p",
subj_name.get(), data.cert_names_list[i].c_str(), cert);
name_set.insert(subj_name.get());
}
if (name_set.empty()) {
- Debug("ssl_load", "no subj name in certificate %s",
data.cert_names_list[i].c_str());
+ Dbg(dbg_ctl_ssl_load, "no subj name in certificate %s",
data.cert_names_list[i].c_str());
}
}
@@ -2317,7 +2324,7 @@
SSLMultiCertConfigLoader::load_certs_and_cross_reference_names(
name = sk_GENERAL_NAME_value(names, i);
if (name->type == GEN_DNS) {
ats_scoped_str dns(asn1_strdup(name->d.dNSName));
- Debug("ssl_load", "inserting dns '%s' in certificate", dns.get());
+ Dbg(dbg_ctl_ssl_load, "inserting dns '%s' in certificate",
dns.get());
name_set.insert(dns.get());
}
}
@@ -2378,10 +2385,10 @@ SSLMultiCertConfigLoader::load_certs(SSL_CTX *ctx,
const std::vector<std::string
const SSLConfigParams *params, const
SSLMultiCertConfigParams *sslMultCertSettings)
{
if (SSLConfigParams::ssl_ocsp_enabled) {
- Debug("ssl_load", "SSL OCSP Stapling is enabled");
+ Dbg(dbg_ctl_ssl_load, "SSL OCSP Stapling is enabled");
SSL_CTX_set_tlsext_status_cb(ctx, ssl_callback_ocsp_stapling);
} else {
- Debug("ssl_load", "SSL OCSP Stapling is disabled");
+ Dbg(dbg_ctl_ssl_load, "SSL OCSP Stapling is disabled");
}
ink_assert(!cert_names_list.empty());
@@ -2410,7 +2417,7 @@ SSLMultiCertConfigLoader::load_certs(SSL_CTX *ctx, const
std::vector<std::string
return false;
}
- Debug("ssl_load", "for ctx=%p, using certificate %s", ctx,
cert_names_list[i].c_str());
+ Dbg(dbg_ctl_ssl_load, "for ctx=%p, using certificate %s", ctx,
cert_names_list[i].c_str());
if (!SSL_CTX_use_certificate(ctx, cert)) {
SSLError("Failed to assign cert from %s to SSL_CTX",
cert_names_list[i].c_str());
X509_free(cert);
@@ -2419,7 +2426,7 @@ SSLMultiCertConfigLoader::load_certs(SSL_CTX *ctx, const
std::vector<std::string
// Load up any additional chain certificates
if (!SSL_CTX_add_extra_chain_cert_bio(ctx, bio.get())) {
- Debug("ssl_load", "couldn't add chain to %p", ctx);
+ Dbg(dbg_ctl_ssl_load, "couldn't add chain to %p", ctx);
SSLError("failed to load intermediate certificate chain from %s",
cert_names_list[i].c_str());
return false;
}
@@ -2506,7 +2513,7 @@ SSLMultiCertConfigLoader::set_session_id_context(SSL_CTX
*ctx, const SSLConfigPa
}
if (nullptr != setting_cert) {
- Debug("ssl_load", "Using '%s' in hash for session id context",
sslMultCertSettings->cert.get());
+ Dbg(dbg_ctl_ssl_load, "Using '%s' in hash for session id context",
sslMultCertSettings->cert.get());
if (EVP_DigestUpdate(digest, sslMultCertSettings->cert,
strlen(setting_cert)) == 0) {
SSLError("EVP_DigestUpdate failed using '%s' in hash for session id
context", sslMultCertSettings->cert.get());
goto fail;
@@ -2553,6 +2560,13 @@ SSLMultiCertConfigLoader::_debug_tag() const
return "ssl";
}
+const DbgCtl &
+SSLMultiCertConfigLoader::_dbg_ctl() const
+{
+ static DbgCtl dc{_debug_tag()};
+ return dc;
+}
+
/**
Clear password in SSL_CTX
@static
diff --git a/iocore/net/Socks.cc b/iocore/net/Socks.cc
index ecb282d57..c60624e3a 100644
--- a/iocore/net/Socks.cc
+++ b/iocore/net/Socks.cc
@@ -45,6 +45,15 @@ socks_conf_struct *g_socks_conf_stuff = nullptr;
ClassAllocator<SocksEntry> socksAllocator("socksAllocator");
+namespace
+{
+
+DbgCtl dbg_ctl_Socks{"Socks"};
+DbgCtl dbg_ctl_SocksParent{"SocksParent"};
+DbgCtl dbg_ctl_SocksProxy{"SocksProxy"};
+
+} // end anonymous namespace
+
void
SocksEntry::init(Ptr<ProxyMutex> &m, SocksNetVC *vc, unsigned char
socks_support, unsigned char ver)
{
@@ -120,7 +129,7 @@ SocksEntry::findServer()
if (0 == ats_ip_pton(server_result.hostname, &server_addr)) {
ats_ip_port_cast(&server_addr) = htons(server_result.port);
} else {
- Debug("SocksParent", "Invalid parent server specified %s",
server_result.hostname);
+ Dbg(dbg_ctl_SocksParent, "Invalid parent server specified %s",
server_result.hostname);
}
break;
@@ -139,8 +148,8 @@ SocksEntry::findServer()
#endif // SOCKS_WITH_TS
char buff[INET6_ADDRSTRLEN];
- Debug("SocksParents", "findServer result: %s:%d",
ats_ip_ntop(&server_addr.sa, buff, sizeof(buff)),
- ats_ip_port_host_order(&server_addr));
+ Dbg(dbg_ctl_SocksParent, "findServer result: %s:%d",
ats_ip_ntop(&server_addr.sa, buff, sizeof(buff)),
+ ats_ip_port_host_order(&server_addr));
}
void
@@ -167,7 +176,7 @@ SocksEntry::free()
if (!action_.cancelled) {
if (lerrno || !netVConnection) {
- Debug("Socks", "retryevent: Sent errno %d to HTTP", lerrno);
+ Dbg(dbg_ctl_Socks, "retryevent: Sent errno %d to HTTP", lerrno);
NET_INCREMENT_DYN_STAT(socks_connections_unsuccessful_stat);
action_.continuation->handleEvent(NET_EVENT_OPEN_FAILED, (void
*)static_cast<intptr_t>(-lerrno));
} else {
@@ -175,7 +184,7 @@ SocksEntry::free()
netVConnection->do_io_write(this, 0, nullptr);
netVConnection->action_ = action_; // assign the original continuation
netVConnection->con.setRemote(&server_addr.sa);
- Debug("Socks", "Sent success to HTTP");
+ Dbg(dbg_ctl_Socks, "Sent success to HTTP");
NET_INCREMENT_DYN_STAT(socks_connections_successful_stat);
action_.continuation->handleEvent(NET_EVENT_OPEN, netVConnection);
}
@@ -209,12 +218,12 @@ SocksEntry::startEvent(int event, void *data)
}
char buff[INET6_ADDRPORTSTRLEN];
- Debug("Socks", "Failed to connect to %s", ats_ip_nptop(&server_addr.sa,
buff, sizeof(buff)));
+ Dbg(dbg_ctl_Socks, "Failed to connect to %s",
ats_ip_nptop(&server_addr.sa, buff, sizeof(buff)));
findServer();
if (!ats_is_ip(&server_addr)) {
- Debug("Socks", "Unable to open connection to the SOCKS server");
+ Dbg(dbg_ctl_Socks, "Unable to open connection to the SOCKS server");
lerrno = ESOCK_NO_SOCK_SERVER_CONN;
free();
return EVENT_CONT;
@@ -259,8 +268,6 @@ SocksEntry::mainEvent(int event, void *data)
if (auth_handler) {
n_bytes = invokeSocksAuthHandler(auth_handler, SOCKS_AUTH_OPEN, p);
} else {
- // Debug("Socks", " Got NET_EVENT_OPEN to SOCKS server");
-
p[n_bytes++] = version;
p[n_bytes++] = (socks_cmd == NORMAL_SOCKS) ? SOCKS_CONNECT : socks_cmd;
ts = ats_ip_port_cast(&target_addr);
@@ -276,7 +283,7 @@ SocksEntry::mainEvent(int event, void *data)
memcpy(p + n_bytes, &target_addr.sin6.sin6_addr, TS_IP6_SIZE);
n_bytes += TS_IP6_SIZE;
} else {
- Debug("Socks", "SOCKS supports only IP addresses.");
+ Dbg(dbg_ctl_Socks, "SOCKS supports only IP addresses.");
}
}
@@ -291,7 +298,7 @@ SocksEntry::mainEvent(int event, void *data)
p[n_bytes++] = 0; // nullptr
} else {
- Debug("Socks", "SOCKS v4 supports only IPv4 addresses.");
+ Dbg(dbg_ctl_Socks, "SOCKS v4 supports only IPv4 addresses.");
}
}
}
@@ -304,7 +311,6 @@ SocksEntry::mainEvent(int event, void *data)
}
netVConnection->do_io_write(this, n_bytes, reader, false);
- // Debug("Socks", "Sent the request to the SOCKS server");
ret = EVENT_CONT;
break;
@@ -328,7 +334,7 @@ SocksEntry::mainEvent(int event, void *data)
} else if (socks_cmd == NORMAL_SOCKS) {
n_bytes = (version == SOCKS5_VERSION) ? SOCKS5_REP_LEN : SOCKS4_REP_LEN;
} else {
- Debug("Socks", "Tunnelling the connection");
+ Dbg(dbg_ctl_Socks, "Tunnelling the connection");
// let the client handle the response
free();
break;
@@ -359,12 +365,12 @@ SocksEntry::mainEvent(int event, void *data)
reply_len = 7 + p[4];
break;
case SOCKS_ATYPE_IPV6:
- Debug("Socks", "Who is using IPv6 Addr?");
+ Dbg(dbg_ctl_Socks, "Who is using IPv6 Addr?");
reply_len = 22;
break;
default:
reply_len = INT_MAX;
- Debug("Socks", "Illegal address type(%d) in Socks server",
(int)p[3]);
+ Dbg(dbg_ctl_Socks, "Illegal address type(%d) in Socks server",
(int)p[3]);
}
if (vio->ndone >= reply_len) {
@@ -383,7 +389,6 @@ SocksEntry::mainEvent(int event, void *data)
timeout->cancel(this);
timeout = nullptr;
}
- // Debug("Socks", "Successfully read the reply from the SOCKS server");
p = reinterpret_cast<unsigned char *>(buf->start());
if (auth_handler) {
@@ -402,17 +407,17 @@ SocksEntry::mainEvent(int event, void *data)
bool success;
if (version == SOCKS5_VERSION) {
success = (p[0] == SOCKS5_VERSION && p[1] == SOCKS5_REQ_GRANTED);
- Debug("Socks", "received reply of length %" PRId64 " addr type %d",
((VIO *)data)->ndone, (int)p[3]);
+ Dbg(dbg_ctl_Socks, "received reply of length %" PRId64 " addr type
%d", ((VIO *)data)->ndone, (int)p[3]);
} else {
success = (p[0] == 0 && p[1] == SOCKS4_REQ_GRANTED);
}
// ink_assert(*(p) == 0);
if (!success) { // SOCKS request failed
- Debug("Socks", "Socks request denied %d", (int)*(p + 1));
+ Dbg(dbg_ctl_Socks, "Socks request denied %d", (int)*(p + 1));
lerrno = ESOCK_DENIED;
} else {
- Debug("Socks", "Socks request successful %d", (int)*(p + 1));
+ Dbg(dbg_ctl_Socks, "Socks request successful %d", (int)*(p + 1));
lerrno = 0;
}
free();
@@ -443,14 +448,14 @@ SocksEntry::mainEvent(int event, void *data)
case VC_EVENT_EOS:
case VC_EVENT_INACTIVITY_TIMEOUT:
case VC_EVENT_ACTIVE_TIMEOUT:
- Debug("Socks", "VC_EVENT error: %s", get_vc_event_name(event));
+ Dbg(dbg_ctl_Socks, "VC_EVENT error: %s", get_vc_event_name(event));
lerrno = ESOCK_NO_SOCK_SERVER_CONN;
free();
break;
default:
// BUGBUG:: could be active/inactivity timeout ...
ink_assert(!"bad case value");
- Debug("Socks", "Bad Case/Net Error Event");
+ Dbg(dbg_ctl_Socks, "Bad Case/Net Error Event");
lerrno = ESOCK_NO_SOCK_SERVER_CONN;
free();
break;
@@ -473,12 +478,12 @@ loadSocksConfiguration(socks_conf_struct
*socks_conf_stuff)
socks_conf_stuff->accept_enabled = 0; // initialize it INKqa08593
socks_conf_stuff->socks_needed =
REC_ConfigReadInteger("proxy.config.socks.socks_needed");
if (!socks_conf_stuff->socks_needed) {
- Debug("Socks", "Socks Turned Off");
+ Dbg(dbg_ctl_Socks, "Socks Turned Off");
return;
}
socks_conf_stuff->default_version =
REC_ConfigReadInteger("proxy.config.socks.socks_version");
- Debug("Socks", "Socks Version %d", socks_conf_stuff->default_version);
+ Dbg(dbg_ctl_Socks, "Socks Version %d", socks_conf_stuff->default_version);
if (socks_conf_stuff->default_version != 4 &&
socks_conf_stuff->default_version != 5) {
Error("SOCKS Config: Unsupported Version: %d. SOCKS Turned off",
socks_conf_stuff->default_version);
@@ -487,8 +492,8 @@ loadSocksConfiguration(socks_conf_struct *socks_conf_stuff)
socks_conf_stuff->server_connect_timeout =
REC_ConfigReadInteger("proxy.config.socks.server_connect_timeout");
socks_conf_stuff->socks_timeout =
REC_ConfigReadInteger("proxy.config.socks.socks_timeout");
- Debug("Socks", "server connect timeout: %d socks response timeout %d",
socks_conf_stuff->server_connect_timeout,
- socks_conf_stuff->socks_timeout);
+ Dbg(dbg_ctl_Socks, "server connect timeout: %d socks response timeout %d",
socks_conf_stuff->server_connect_timeout,
+ socks_conf_stuff->socks_timeout);
socks_conf_stuff->per_server_connection_attempts =
REC_ConfigReadInteger("proxy.config.socks.per_server_connection_attempts");
socks_conf_stuff->connection_attempts =
REC_ConfigReadInteger("proxy.config.socks.connection_attempts");
@@ -496,17 +501,17 @@ loadSocksConfiguration(socks_conf_struct
*socks_conf_stuff)
socks_conf_stuff->accept_enabled =
REC_ConfigReadInteger("proxy.config.socks.accept_enabled");
socks_conf_stuff->accept_port =
REC_ConfigReadInteger("proxy.config.socks.accept_port");
socks_conf_stuff->http_port =
REC_ConfigReadInteger("proxy.config.socks.http_port");
- Debug("SocksProxy",
- "Read SocksProxy info: accept_enabled = %d "
- "accept_port = %d http_port = %d",
- socks_conf_stuff->accept_enabled, socks_conf_stuff->accept_port,
socks_conf_stuff->http_port);
+ Dbg(dbg_ctl_SocksProxy,
+ "Read SocksProxy info: accept_enabled = %d "
+ "accept_port = %d http_port = %d",
+ socks_conf_stuff->accept_enabled, socks_conf_stuff->accept_port,
socks_conf_stuff->http_port);
#ifdef SOCKS_WITH_TS
SocksServerConfig::startup();
#endif
config_pathname =
RecConfigReadConfigPath("proxy.config.socks.socks_config_file");
- Debug("Socks", "Socks Config File: %s", (const char *)config_pathname);
+ Dbg(dbg_ctl_Socks, "Socks Config File: %s", (const char *)config_pathname);
if (!config_pathname) {
Error("SOCKS Config: could not read config file name. SOCKS Turned off");
@@ -534,7 +539,7 @@ loadSocksConfiguration(socks_conf_struct *socks_conf_stuff)
Error("SOCKS Config: Error while reading Socks auth info");
goto error;
}
- Debug("Socks", "Socks Turned on");
+ Dbg(dbg_ctl_Socks, "Socks Turned on");
return;
error:
@@ -561,7 +566,7 @@ loadSocksAuthInfo(swoc::TextView content, socks_conf_struct
*socks_stuff)
auto password = line.take_prefix_if(&isspace);
if (!user_name.empty() && !password.empty()) {
- Debug("Socks", "%s", swoc::bwprint(text, "Read auth credentials \"{}\"
: \"{}\"", user_name, password).c_str());
+ Dbg(dbg_ctl_Socks, "%s", swoc::bwprint(text, "Read auth credentials
\"{}\" : \"{}\"", user_name, password).c_str());
swoc::bwprint(socks_stuff->user_name_n_passwd, "{}{}{}{}",
char(user_name.size()), user_name, char(password.size()),
password);
}
@@ -621,16 +626,16 @@ socks5BasicAuthHandler(int event, unsigned char *p, void
(**h_ptr)(void))
if (p[0] == SOCKS5_VERSION) {
switch (p[1]) {
case 0: // no authentication required
- Debug("Socks", "No authentication required for Socks server");
+ Dbg(dbg_ctl_Socks, "No authentication required for Socks server");
// make sure this is ok for us. right now it is always ok for us.
*h_ptr = nullptr;
break;
case 2:
- Debug("Socks", "Socks server wants username/passwd");
+ Dbg(dbg_ctl_Socks, "Socks server wants username/passwd");
if (!pass_phrase) {
- Debug("Socks", "Buggy Socks server: asks for username/passwd "
- "when not supplied as an option");
+ Dbg(dbg_ctl_Socks, "Buggy Socks server: asks for username/passwd "
+ "when not supplied as an option");
ret = -1;
*h_ptr = nullptr;
} else {
@@ -640,19 +645,19 @@ socks5BasicAuthHandler(int event, unsigned char *p, void
(**h_ptr)(void))
break;
case 0xff:
- Debug("Socks", "None of the Socks authentications is acceptable "
- "to the server");
+ Dbg(dbg_ctl_Socks, "None of the Socks authentications is acceptable "
+ "to the server");
*h_ptr = nullptr;
ret = -1;
break;
default:
- Debug("Socks", "Unexpected Socks auth method (%d) from the server",
(int)p[1]);
+ Dbg(dbg_ctl_Socks, "Unexpected Socks auth method (%d) from the
server", (int)p[1]);
ret = -1;
break;
}
} else {
- Debug("Socks", "authEvent got wrong version %d from the Socks server",
(int)p[0]);
+ Dbg(dbg_ctl_Socks, "authEvent got wrong version %d from the Socks
server", (int)p[0]);
ret = -1;
}
@@ -696,12 +701,12 @@ socks5PasswdAuthHandler(int event, unsigned char *p, void
(**h_ptr)(void))
// NEC thinks it is 5 RFC seems to indicate 1.
switch (p[1]) {
case 0:
- Debug("Socks", "Username/Passwd succeeded");
+ Dbg(dbg_ctl_Socks, "Username/Passwd succeeded");
*h_ptr = nullptr;
break;
default:
- Debug("Socks", "Username/Passwd authentication failed ret_code: %d",
(int)p[1]);
+ Dbg(dbg_ctl_Socks, "Username/Passwd authentication failed ret_code: %d",
(int)p[1]);
ret = -1;
}
