Bug 4796: comm.cc !isOpen(conn->fd) assertion when rotating logs (#474)

This long-term solution overrides the short-term fix at 2cd72a2. Now,
debug.cc correctly maintains meta information associated with its file
descriptors.

IMO, the correct place for calling _db_init() is just after locking the
PID file because we want to log ASAP, but cache.log is a common resource
that requires protection. Thus, the two old _db_init() calls were both
excessive and misplaced:

* The first call happens too early, allowing another Squid instance to
  pollute cache.log with messages unrelated to the cache.log-owning
  instance (e.g., a "FATAL: Squid is already running" message when
  attempting to start another instance).

* The second call happens too late, missing earlier debugs() that ought
  to be written into cache.log (e.g., debugs() in comm_init()).

Fixing _db_init() calls led to adjustments like moving mainSetCwd() to
be called prior to the relocated _db_init(). However, these changes
should not affect chroot-sensitive code such as UseConfigRunners().

Some early debugs() messages are no longer written into cache.log:

* Exception messages like "Squid is already running" emitted by another
  Squid instance. This is an improvement: Messages about other instances
  do not belong to the cache.log locked by the running instance.

* Messages (mostly errors and warning) from "finalizeConfig" callers
  (e.g., "WARNING: mem-cache size is too small..."). This loss is
  regrettable. Long-term, these messages should be reported after
  configuration is finalized (TODO). Delayed reporting will also help
  when Squid starts rejecting invalid reconfigurations.

* Messages from a few early enter_suid()/leave_suid() calls, such as
  "enter_suid: PID" and "leave_suid: PID". This is an improvement: These
  debugging messages pollute cache.log.

* A few early SquidMain() messages emitted between parseConfigFile() and
  StartUsingConfig() (e.g., "Doing post-config initialization"). This is
  an improvement: These debugging messages pollute cache.log.

Also removed outdated 'TEST_ACCESS' hack for simplicity sake.

Also marked an old XXX: Chrooted SMP master process does not db_init().

diff --git a/src/cache_cf.cc b/src/cache_cf.cc
index 26c8ca6b5287b6ee2cc33d4a5cd4e5f2b7e94399..ff90b9f55bf1386a4a70d719b38bb735a1a12b2f 100644 (file)
--- a/src/cache_cf.cc
+++ b/src/cache_cf.cc
@@ -607,13 +607,6 @@ parseConfigFileOrThrow(const char *file_name)
      */
     configDoConfigure();
 
-    if (!Config.chroot_dir) {
-        leave_suid();
-        setUmask(Config.umask);
-        _db_init(Debug::cache_log, Debug::debugOptions);
-        enter_suid();
-    }
-
     if (opt_send_signal == -1) {
         Mgr::RegisterAction("config",
                             "Current Squid Configuration",

diff --git a/src/comm.cc b/src/comm.cc
index abbcbacf4a5e96dfed3026e5226b93c8275b8aac..804cf10ad2bef0ea40de4bf853ed02a23e4c9bde 100644 (file)
--- a/src/comm.cc
+++ b/src/comm.cc
@@ -1232,7 +1232,7 @@ commSetTcpKeepalive(int fd, int idle, int interval, int timeout)
 void
 comm_init(void)
 {
-    fd_table =(fde *) xcalloc(Squid_MaxFD, sizeof(fde));
+    assert(fd_table);
 
     /* make sure the accept() socket FIFO delay queue exists */
     Comm::AcceptLimiter::Instance();
@@ -1258,7 +1258,6 @@ comm_exit(void)
     delete TheHalfClosed;
     TheHalfClosed = NULL;
 
-    safe_free(fd_table);
     Comm::CallbackTableDestruct();
 }
 

diff --git a/src/debug.cc b/src/debug.cc
index 2bbdc37ba59b294a2b35060123374c8b579a4601..8ef89602fb50b4812627454ebee85e4bee115178 100644 (file)
--- a/src/debug.cc
+++ b/src/debug.cc
@@ -10,6 +10,7 @@
 
 #include "squid.h"
 #include "Debug.h"
+#include "fd.h"
 #include "ipc/Kids.h"
 #include "SquidTime.h"
 #include "util.h"
@@ -96,10 +97,15 @@ DebugFile::reset(FILE *newFile, const char *newName)
     // callers must use nullptr instead of the used-as-the-last-resort stderr
     assert(newFile != stderr || !stderr);
 
-    if (file_)
+    if (file_) {
+        fd_close(fileno(file_));
         fclose(file_);
+    }
     file_ = newFile; // may be nil
 
+    if (file_)
+        fd_open(fileno(file_), FD_LOG, Debug::cache_log);
+
     xfree(name);
     name = newName ? xstrdup(newName) : nullptr;
 

diff --git a/src/fde.cc b/src/fde.cc
index e4d492bb43186495d420d16a4d5e33bbc781ccb6..7f992d38ae582983bc61c18e08cc67563117eeb2 100644 (file)
--- a/src/fde.cc
+++ b/src/fde.cc
@@ -138,3 +138,10 @@ fde::remoteAddr() const
     return buf;
 }
 
+void
+fde::Init()
+{
+    assert(!Table);
+    Table = static_cast<fde *>(xcalloc(Squid_MaxFD, sizeof(fde)));
+}
+

diff --git a/src/fde.h b/src/fde.h
index c917e3577bf1cde313f729018b6f4b2bfd6d5dbb..bc9e0665bfed75d5709e518e10bc76c2ca9d9bf4 100644 (file)
--- a/src/fde.h
+++ b/src/fde.h
@@ -52,6 +52,13 @@ class fde
 {
 
 public:
+
+    // TODO: Merge with comm_init() to reduce initialization order dependencies.
+    /// Configures fd_table (a.k.a. fde::Table).
+    /// Call once, after learning the number of supported descriptors (i.e.
+    /// setMaxFD()) and before dereferencing fd_table (e.g., before Comm I/O).
+    static void Init();
+
     fde() {
         *ipaddr = 0;
         *desc = 0;

diff --git a/src/icmp/Makefile.am b/src/icmp/Makefile.am
index 89870e6f151e5d30caf4763c1b305bcdb6d6e14b..a5edcb54cd68e94575e279ac87d39a05a0ed5c19 100644 (file)
--- a/src/icmp/Makefile.am
+++ b/src/icmp/Makefile.am
@@ -40,6 +40,7 @@ COPIED_SOURCE= \
        globals.cc \
        SquidConfig.cc \
        SquidNew.cc \
+       stub_fd.cc \
        stub_HelperChildConfig.cc \
        stub_libmem.cc \
        stub_SBuf.cc \
@@ -101,6 +102,9 @@ SquidNew.cc: $(top_srcdir)/src/SquidNew.cc
 stub_HelperChildConfig.cc: $(top_srcdir)/src/tests/stub_HelperChildConfig.cc
        cp $(top_srcdir)/src/tests/stub_HelperChildConfig.cc $@
 
+stub_fd.cc: $(top_srcdir)/src/tests/stub_fd.cc STUB.h
+       cp $(top_srcdir)/src/tests/stub_fd.cc $@
+
 stub_libmem.cc: $(top_srcdir)/src/tests/stub_libmem.cc STUB.h
        cp $(top_srcdir)/src/tests/stub_libmem.cc $@
 

diff --git a/src/main.cc b/src/main.cc
index 18073111246a6177972239ab6e46423b5108c6fc..949386d02ac00613b4376bf4116e77b7881e7b29 100644 (file)
--- a/src/main.cc
+++ b/src/main.cc
@@ -1132,9 +1132,6 @@ mainSetCwd(void)
 static void
 mainInitialize(void)
 {
-    /* chroot if configured to run inside chroot */
-    mainSetCwd();
-
     if (opt_catch_signals) {
         squid_signal(SIGSEGV, death, SA_NODEFER | SA_RESETHAND);
         squid_signal(SIGBUS, death, SA_NODEFER | SA_RESETHAND);
@@ -1149,12 +1146,6 @@ mainInitialize(void)
     if (icpPortNumOverride != 1)
         Config.Port.icp = (unsigned short) icpPortNumOverride;
 
-    _db_init(Debug::cache_log, Debug::debugOptions);
-
-    // Do not register cache.log descriptor with Comm (for now).
-    // See https://bugs.squid-cache.org/show_bug.cgi?id=4796
-    // fd_open(fileno(debug_log), FD_LOG, Debug::cache_log);
-
     debugs(1, DBG_CRITICAL, "Starting Squid Cache version " << version_string << " for " << CONFIG_HOST_TYPE << "...");
     debugs(1, DBG_CRITICAL, "Service Name: " << service_name);
 
@@ -1443,12 +1434,57 @@ ConfigureCurrentKid(const CommandLine &cmdLine)
     }
 }
 
-static void StartUsingConfig()
+/// Start directing debugs() messages to the configured cache.log.
+/// Until this function is called, all allowed messages go to stderr.
+static void
+ConfigureDebugging()
+{
+    if (opt_no_daemon) {
+        fd_open(0, FD_LOG, "stdin");
+        fd_open(1, FD_LOG, "stdout");
+        fd_open(2, FD_LOG, "stderr");
+    }
+    // we should not create cache.log outside chroot environment, if any
+    // XXX: With Config.chroot_dir set, SMP master process never calls db_init().
+    if (!Config.chroot_dir || Chrooted)
+        _db_init(Debug::cache_log, Debug::debugOptions);
+}
+
+static void
+RunConfigUsers()
 {
     RunRegisteredHere(RegisteredRunner::claimMemoryNeeds);
     RunRegisteredHere(RegisteredRunner::useConfig);
 }
 
+static void
+StartUsingConfig()
+{
+    setMaxFD();
+    fde::Init();
+    const auto skipCwdAdjusting = IamMasterProcess() && InDaemonMode();
+    if (skipCwdAdjusting) {
+        ConfigureDebugging();
+        RunConfigUsers();
+    } else if (Config.chroot_dir) {
+        RunConfigUsers();
+        enter_suid();
+        // TODO: don't we need to RunConfigUsers() in the configured
+        // chroot environment?
+        mainSetCwd();
+        leave_suid();
+        ConfigureDebugging();
+    } else {
+        ConfigureDebugging();
+        RunConfigUsers();
+        enter_suid();
+        // TODO: since RunConfigUsers() may use a relative path, we
+        // need to change the process root first
+        mainSetCwd();
+        leave_suid();
+    }
+}
+
 int
 SquidMain(int argc, char **argv)
 {
@@ -1585,18 +1621,6 @@ SquidMain(int argc, char **argv)
     if (opt_send_signal == -1 && IamMasterProcess())
         Instance::ThrowIfAlreadyRunning();
 
-#if TEST_ACCESS
-
-    comm_init();
-
-    mainInitialize();
-
-    test_access();
-
-    return 0;
-
-#endif
-
     /* send signal to running copy and exit */
     if (opt_send_signal != -1) {
         /* chroot if configured to run inside chroot */
@@ -1628,9 +1652,6 @@ SquidMain(int argc, char **argv)
     enter_suid();
 
     if (opt_create_swap_dirs) {
-        /* chroot if configured to run inside chroot */
-        mainSetCwd();
-
         setEffectiveUser();
         debugs(0, DBG_CRITICAL, "Creating missing swap directories");
         Store::Root().create();
@@ -1642,18 +1663,9 @@ SquidMain(int argc, char **argv)
         CpuAffinityCheck();
     CpuAffinityInit();
 
-    setMaxFD();
-
     /* init comm module */
     comm_init();
 
-    if (opt_no_daemon) {
-        /* we have to init fdstat here. */
-        fd_open(0, FD_LOG, "stdin");
-        fd_open(1, FD_LOG, "stdout");
-        fd_open(2, FD_LOG, "stderr");
-    }
-
 #if USE_WIN32_SERVICE
 
     WIN32_svcstatusupdate(SERVICE_START_PENDING, 10000);

diff --git a/src/tests/testRock.cc b/src/tests/testRock.cc
index 7f93ac0dff726af988377f766d8be66c3f2930ca..d9634d31862fd6c50ddef882cb3f281c524e0a6e 100644 (file)
--- a/src/tests/testRock.cc
+++ b/src/tests/testRock.cc
@@ -9,6 +9,7 @@
 #include "squid.h"
 #include "ConfigParser.h"
 #include "DiskIO/DiskIOModule.h"
+#include "fde.h"
 #include "fs/rock/RockSwapDir.h"
 #include "globals.h"
 #include "HttpHeader.h"
@@ -142,6 +143,8 @@ testRock::commonInit()
 
     Mem::Init();
 
+    fde::Init();
+
     comm_init();
 
     httpHeaderInitModule(); /* must go before any header processing (e.g. the one in errorInitialize) */

diff --git a/src/tests/testUfs.cc b/src/tests/testUfs.cc
index e5728af5a7200e39c9558c70261546aae4e3a690..0071151870136c6f75358d3bdeae7e396665b7bf 100644 (file)
--- a/src/tests/testUfs.cc
+++ b/src/tests/testUfs.cc
@@ -8,6 +8,7 @@
 
 #include "squid.h"
 #include "DiskIO/DiskIOModule.h"
+#include "fde.h"
 #include "fs/ufs/UFSSwapDir.h"
 #include "globals.h"
 #include "HttpHeader.h"
@@ -72,6 +73,8 @@ testUfs::commonInit()
 
     Mem::Init();
 
+    fde::Init();
+
     comm_init();
 
     httpHeaderInitModule(); /* must go before any header processing (e.g. the one in errorInitialize) */