You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@trafficserver.apache.org by wk...@apache.org on 2022/12/29 16:34:20 UTC
[trafficserver] branch master updated: Fix crashes at shutdown due to references to stale debug control registry. (#9272)
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 eabc29ef0 Fix crashes at shutdown due to references to stale debug control registry. (#9272)
eabc29ef0 is described below
commit eabc29ef0ba1393019116598843e464e1da0f390
Author: Walt Karas <wk...@yahoo-inc.com>
AuthorDate: Thu Dec 29 10:34:14 2022 -0600
Fix crashes at shutdown due to references to stale debug control registry. (#9272)
* Fix crashes at shutdown due to references to stale debug control registry.
Adds reference count for references to registry. The registry is deleted only when the reference count goes to zero.
* Add delay before starting trafficserver in tsapi Au test.
The opening of the cleartext TCP port for listening fails intermittently with a delay beforehand.
Co-authored-by: Walt Karas <wk...@yahooinc.com>
---
doc/developer-guide/api/functions/TSDebug.en.rst | 3 +
doc/developer-guide/debugging/debug-tags.en.rst | 14 ++-
include/ts/ts.h | 8 ++
include/tscore/DbgCtl.h | 10 ++-
include/tscpp/api/Cleanup.h | 11 +++
src/traffic_server/InkAPI.cc | 10 ++-
src/tscore/DbgCtl.cc | 100 ++++++++++++++++++---
tests/gold_tests/pluginTest/TSVConnFd/TSVConnFd.cc | 4 +-
.../polite_hook_wait/polite_hook_wait.cc | 3 +-
tests/gold_tests/pluginTest/tsapi/test_tsapi.cc | 7 +-
tests/gold_tests/pluginTest/tsapi/tsapi.test.py | 12 ++-
11 files changed, 156 insertions(+), 26 deletions(-)
diff --git a/doc/developer-guide/api/functions/TSDebug.en.rst b/doc/developer-guide/api/functions/TSDebug.en.rst
index a12551001..9a458bfd0 100644
--- a/doc/developer-guide/api/functions/TSDebug.en.rst
+++ b/doc/developer-guide/api/functions/TSDebug.en.rst
@@ -40,6 +40,7 @@ Synopsis
.. type:: TSDbgCtl
.. function:: void TSDbg(const TSDbgCtl * ctlptr, const char * format, ...)
.. function:: const TSDbgCtl * TSDbgCtlCreate(const char * tag)
+.. function:: void TSDbgCtlDestroy(const TSDbgCtl * dbg_ctl)
.. function:: void TSDebug(const char * tag, const char * format, ...)
.. function:: int TSIsDbgCtlSet(const TSDbgCtl * ctlptr)
.. function:: int TSIsDebugTagSet(const char * tag)
@@ -86,6 +87,8 @@ trafficserver.out
:func:`TSDbgCtlCreate` creates a debug control, associated with the
debug :arg:`tag`, and returns a const pointer to it.
+:func:`TSDbgCtlDestroy` destroys a debug control, pointed to by :arg:`dbg_ctl`.
+
:func:`TSIsDbgCtlSet` returns non-zero if the given debug control, pointed to by :arg:`ctlptr`, is
enabled.
diff --git a/doc/developer-guide/debugging/debug-tags.en.rst b/doc/developer-guide/debugging/debug-tags.en.rst
index 9cd45392d..d15d4c33a 100644
--- a/doc/developer-guide/debugging/debug-tags.en.rst
+++ b/doc/developer-guide/debugging/debug-tags.en.rst
@@ -32,11 +32,14 @@ traces in your plugin. In this macro:
- ``...`` are variables for ``format_str`` in the standard ``printf``
style.
-``void TSDbgCtlCreate (const char *tag)`` returns a (const) pointer to
+``TSDbgCtlCreate (const char *tag)`` returns a (const) pointer to
``TSDbgCtl``. The ``TSDbgCtl`` control is enabled when debug output is
-enabled globally by configuaration, and ``tag`` matches a configured
+enabled globally by configuration, and ``tag`` matches a configured
regular expression.
+``TSDbgCtlDestroy (TSDbgCtl const *dbg_ctl)`` destroys a debug control
+created by ``TSDbgCtlCreast()``.
+
The deprecated API
``void TSDebug (const char *tag, const char *format_str, ...)`` also
outputs traces. In this API:
@@ -81,6 +84,8 @@ Example:
TSDbg(my_dbg_ctl, "Starting my-plugin at %d", the_time);
...
TSDbg(my_dbg_ctl, "Later on in my-plugin");
+ ...
+ TSDbgCtlDestroy(my_dbg_ctl);
The statement ``"Starting my-plugin at <time>"`` appears whenever you
@@ -94,7 +99,10 @@ If your plugin is a C++ plugin, the above example can be written as:
.. code-block:: cpp
- static auto my_dbg_ctl = TSDbgCtlCreate("my-plugin"); // Non-local variable.
+ #include <tscpp/api/Cleanup.h>
+ ...
+ static TSDbgCtlUniqPtr my_dbg_ctl_guard{TSDbgCtlCreate("my-plugin")}; // Non-local variable.
+ TSDbgCtl const * const my_dbg_ctl{my_dbg_ctl_guard.get()}; // Non-local variable.
...
TSDbg(my_dbg_ctl, "Starting my-plugin at %d", the_time);
...
diff --git a/include/ts/ts.h b/include/ts/ts.h
index 66af0983d..80c61b30f 100644
--- a/include/ts/ts.h
+++ b/include/ts/ts.h
@@ -2228,6 +2228,14 @@ extern char ts_new_debug_on_flag_; /* Do not use directly. */
*/
tsapi TSDbgCtl const *TSDbgCtlCreate(char const *tag);
+/**
+ Destroy (dereference) a debug control object previously created
+ with TSDbgCtlCreate().
+
+ @param dbg_ctl pointer to debug control object.
+ */
+tsapi void TSDbgCtlDestroy(TSDbgCtl const *dbg_ctl);
+
void _TSDbg(const char *tag, const char *format_str, ...) TS_PRINTFLIKE(2, 3); /* Not for direct use. */
/* --------------------------------------------------------------------------
diff --git a/include/tscore/DbgCtl.h b/include/tscore/DbgCtl.h
index be5b7db4b..f7b2f59ad 100644
--- a/include/tscore/DbgCtl.h
+++ b/include/tscore/DbgCtl.h
@@ -33,7 +33,9 @@ public:
// Tag is a debug tag. Debug output associated with this control will be output when debug output
// is enabled globally, and the tag matches the configured debug tag regular expression.
//
- DbgCtl(char const *tag) : _ptr(_get_ptr(tag)) {}
+ DbgCtl(char const *tag) : _ptr{_new_reference(tag)} {}
+
+ ~DbgCtl() { _rm_reference(); }
TSDbgCtl const *
ptr() const
@@ -48,9 +50,13 @@ public:
private:
TSDbgCtl const *const _ptr;
- static const TSDbgCtl *_get_ptr(char const *tag);
+ static const TSDbgCtl *_new_reference(char const *tag);
+
+ static void _rm_reference();
class _RegistryAccessor;
friend TSDbgCtl const *TSDbgCtlCreate(char const *tag);
+
+ friend void TSDbgCtlDestroy(TSDbgCtl const *dbg_ctl);
};
diff --git a/include/tscpp/api/Cleanup.h b/include/tscpp/api/Cleanup.h
index ab383a5ec..b70ccfe3d 100644
--- a/include/tscpp/api/Cleanup.h
+++ b/include/tscpp/api/Cleanup.h
@@ -100,6 +100,17 @@ struct TSIOBufferReaderDeleter {
};
using TSIOBufferReaderUniqPtr = std::unique_ptr<std::remove_pointer_t<TSIOBufferReader>, TSIOBufferReaderDeleter>;
+// Deleter and unique pointer for TSDbgCtl const.
+//
+struct TSDbgCtlDeleter {
+ void
+ operator()(TSDbgCtl const *ptr)
+ {
+ TSDbgCtlDestroy(ptr);
+ }
+};
+using TSDbgCtlUniqPtr = std::unique_ptr<TSDbgCtl const, TSDbgCtlDeleter>;
+
class TxnAuxDataMgrBase
{
protected:
diff --git a/src/traffic_server/InkAPI.cc b/src/traffic_server/InkAPI.cc
index 15ed96267..f25aa232f 100644
--- a/src/traffic_server/InkAPI.cc
+++ b/src/traffic_server/InkAPI.cc
@@ -10463,5 +10463,13 @@ TSDbgCtlCreate(char const *tag)
sdk_assert(tag != nullptr);
sdk_assert(*tag != '\0');
- return DbgCtl::_get_ptr(tag);
+ return DbgCtl::_new_reference(tag);
+}
+
+tsapi void
+TSDbgCtlDestroy(TSDbgCtl const *dbg_ctl)
+{
+ sdk_assert(dbg_ctl != nullptr);
+
+ DbgCtl::_rm_reference();
}
diff --git a/src/tscore/DbgCtl.cc b/src/tscore/DbgCtl.cc
index e6195867a..2bdaf76a9 100644
--- a/src/tscore/DbgCtl.cc
+++ b/src/tscore/DbgCtl.cc
@@ -22,15 +22,15 @@
*/
#include <mutex>
-#include <atomic>
#include <set>
#include <cstring>
+#include <atomic>
#include <tscore/ink_assert.h>
#include <tscore/Diags.h>
// The resistry of fast debug controllers has a ugly implementation to handle the whole-program initialization
-// order problem with C++.
+// and destruction order problem with C++.
//
class DbgCtl::_RegistryAccessor
{
@@ -44,35 +44,83 @@ private:
};
public:
- _RegistryAccessor() : _lg(data().mtx) {}
-
using Set = std::set<TSDbgCtl, TagCmp>;
- struct Data {
- std::mutex mtx;
+ class Registry
+ {
+ public:
Set set;
- ~Data()
+ private:
+ Registry() = default;
+
+ // Mutex must be locked before this is called.
+ //
+ ~Registry()
{
for (auto &ctl : set) {
delete[] ctl.tag;
}
+ _mtx.unlock();
}
+
+ std::mutex _mtx;
+
+ friend class DbgCtl::_RegistryAccessor;
};
- static Data &
+ _RegistryAccessor()
+ {
+ if (!_registry_instance) {
+ Registry *expected{nullptr};
+ Registry *r{new Registry};
+ if (!_registry_instance.compare_exchange_strong(expected, r)) {
+ r->_mtx.lock();
+ delete r;
+ }
+ }
+ _registry_instance.load()->_mtx.lock();
+ _mtx_is_locked = true;
+ }
+
+ ~_RegistryAccessor()
+ {
+ if (_mtx_is_locked) {
+ _registry_instance.load()->_mtx.unlock();
+ }
+ }
+
+ // This is not static so it can't be called with the registry mutex is unlocked. It should not be called
+ // after registry is deleted.
+ //
+ Registry &
data()
{
- static Data d;
- return d;
+ return *_registry_instance;
+ }
+
+ void
+ delete_registry()
+ {
+ auto r = _registry_instance.load();
+ ink_assert(r != nullptr);
+ _registry_instance = nullptr;
+ delete r;
+ _mtx_is_locked = false;
}
+ // Reference count of references to Registry.
+ //
+ inline static std::atomic<unsigned> registry_reference_count{0};
+
private:
- std::lock_guard<std::mutex> _lg;
+ bool _mtx_is_locked{false};
+
+ inline static std::atomic<Registry *> _registry_instance{nullptr};
};
TSDbgCtl const *
-DbgCtl::_get_ptr(char const *tag)
+DbgCtl::_new_reference(char const *tag)
{
ink_assert(tag != nullptr);
@@ -80,6 +128,14 @@ DbgCtl::_get_ptr(char const *tag)
ctl.tag = tag;
+ // DbgCtl instances may be declared as static objects in the destructors of objects not destoyed till program exit.
+ // So, we must handle the case where the construction of such instances of DbgCtl overlaps with the destruction of
+ // other instances of DbgCtl. That is why it is important to make sure the reference count is non-zero before
+ // constructing _RegistryAccessor. The _RegistryAccessor constructor is thereby able to assume that, if it creates
+ // the Registry, the new Registry will not be destroyed before the mutex in the new Registry is locked.
+
+ ++_RegistryAccessor::registry_reference_count;
+
_RegistryAccessor ra;
auto &d{ra.data()};
@@ -93,7 +149,7 @@ DbgCtl::_get_ptr(char const *tag)
ink_assert(sz > 0);
{
- char *t = new char[sz + 1]; // Deleted by ~Data().
+ char *t = new char[sz + 1]; // Deleted by ~Registry().
std::memcpy(t, tag, sz + 1);
ctl.tag = t;
}
@@ -106,6 +162,20 @@ DbgCtl::_get_ptr(char const *tag)
return &*res.first;
}
+void
+DbgCtl::_rm_reference()
+{
+ _RegistryAccessor ra;
+
+ ink_assert(ra.registry_reference_count != 0);
+
+ --ra.registry_reference_count;
+
+ if (0 == ra.registry_reference_count) {
+ ra.delete_registry();
+ }
+}
+
void
DbgCtl::update()
{
@@ -113,6 +183,10 @@ DbgCtl::update()
_RegistryAccessor ra;
+ if (!ra.registry_reference_count) {
+ return;
+ }
+
auto &d{ra.data()};
for (auto &i : d.set) {
diff --git a/tests/gold_tests/pluginTest/TSVConnFd/TSVConnFd.cc b/tests/gold_tests/pluginTest/TSVConnFd/TSVConnFd.cc
index 586947ffe..526199d8d 100644
--- a/tests/gold_tests/pluginTest/TSVConnFd/TSVConnFd.cc
+++ b/tests/gold_tests/pluginTest/TSVConnFd/TSVConnFd.cc
@@ -31,6 +31,7 @@
#include <tscpp/api/Cleanup.h>
using atscppapi::TSContUniqPtr;
+using atscppapi::TSDbgCtlUniqPtr;
/*
Plugin for testing TSVConnFdCreate().
@@ -427,7 +428,8 @@ Send_to_vconn::_cont_func(TSCont cont, TSEvent event, void *edata)
return 0;
}
-auto dbg_ctl{TSDbgCtlCreate(PIName)};
+TSDbgCtlUniqPtr dbg_ctl_guard{TSDbgCtlCreate(PIName)};
+TSDbgCtl const * const dbg_ctl{dbg_ctl_guard.get()};
// Delete file whose path is specified in the constructor when the instance is destroyed.
//
diff --git a/tests/gold_tests/pluginTest/polite_hook_wait/polite_hook_wait.cc b/tests/gold_tests/pluginTest/polite_hook_wait/polite_hook_wait.cc
index bba59407c..b9ff36bd4 100644
--- a/tests/gold_tests/pluginTest/polite_hook_wait/polite_hook_wait.cc
+++ b/tests/gold_tests/pluginTest/polite_hook_wait/polite_hook_wait.cc
@@ -40,7 +40,8 @@ namespace
{
char PIName[] = PINAME;
-auto dbg_ctl{TSDbgCtlCreate(PIName)};
+atscppapi::TSDbgCtlUniqPtr dbg_ctl_guard{TSDbgCtlCreate(PIName)};
+TSDbgCtl const * const dbg_ctl{dbg_ctl_guard.get()};
enum Test_step
{
diff --git a/tests/gold_tests/pluginTest/tsapi/test_tsapi.cc b/tests/gold_tests/pluginTest/tsapi/test_tsapi.cc
index a65d9dbe1..f64b3b071 100644
--- a/tests/gold_tests/pluginTest/tsapi/test_tsapi.cc
+++ b/tests/gold_tests/pluginTest/tsapi/test_tsapi.cc
@@ -26,6 +26,7 @@
#include <bitset>
#include <tscpp/util/PostScript.h>
+#include <tscpp/api/Cleanup.h>
#include <ts/ts.h>
#include <ts/remap.h>
@@ -40,9 +41,11 @@ namespace
{
char PIName[] = PINAME;
-auto dbg_ctl = TSDbgCtlCreate(PIName);
+atscppapi::TSDbgCtlUniqPtr dbg_ctl_guard{TSDbgCtlCreate(PIName)};
+TSDbgCtl const * const dbg_ctl{dbg_ctl_guard.get()};
-auto off_dbg_ctl = TSDbgCtlCreate("yada-yada-yada");
+atscppapi::TSDbgCtlUniqPtr off_dbg_ctl_guard{TSDbgCtlCreate("yada-yada-yada")};
+TSDbgCtl const * const off_dbg_ctl{off_dbg_ctl_guard.get()};
// NOTE: It's important to flush this after writing so that a gold test using this plugin can examine the log before TS
// terminates.
diff --git a/tests/gold_tests/pluginTest/tsapi/tsapi.test.py b/tests/gold_tests/pluginTest/tsapi/tsapi.test.py
index cf79fff09..fda52288e 100644
--- a/tests/gold_tests/pluginTest/tsapi/tsapi.test.py
+++ b/tests/gold_tests/pluginTest/tsapi/tsapi.test.py
@@ -73,10 +73,16 @@ ts.Disk.remap_config.AddLine(
"map https://myhost.test:123 http://127.0.0.1:{0} @plugin={1} @plugin={1}".format(server.Variables.Port, f"{plugin_name}.so")
)
+# For some reason, without this delay, traffic_server cannot reliably open the cleartext port for listening without an
+# error.
+#
+tr = Test.AddTestRun()
+tr.Processes.Default.Command = "sleep 3"
+tr.Processes.Default.ReturnCode = 0
+
tr = Test.AddTestRun()
-# Probe server port to check if ready.
-tr.Processes.Default.StartBefore(server, ready=When.PortOpen(server.Variables.Port))
-tr.Processes.Default.StartBefore(Test.Processes.ts)
+tr.Processes.Default.StartBefore(server)
+tr.Processes.Default.StartBefore(ts)
#
tr.Processes.Default.Command = (
'curl --verbose --ipv4 --header "Host: mYhOsT.teSt" hTtP://loCalhOst:{}/'.format(ts.Variables.port)