Fix crashes at shutdown due to references to stale debug control registry.

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.
 

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);
        ...

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. */
 
 /* --------------------------------------------------------------------------

include/tscore/DbgCtl.h

@@ -33,7 +33,9 @@ class DbgCtl
   // 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 @@ class DbgCtl
 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);
 };

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:

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();
 }

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,42 +44,98 @@ class DbgCtl::_RegistryAccessor
   };
 
 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);
 
   TSDbgCtl ctl;
 
   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,13 +162,31 @@ 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()
 {
   ink_release_assert(diags() != nullptr);
 
   _RegistryAccessor ra;
 
+  if (!ra.registry_reference_count) {
+    return;
+  }
+
   auto &d{ra.data()};
 
   for (auto &i : d.set) {

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.
 //

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
 {

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.

tests/gold_tests/pluginTest/tsapi/tsapi.test.py

@@ -73,10 +73,16 @@
     "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)