[Backport][main to 0.9] | fix(alog): prevent child deadlock on rotation lock across fork() (#1573)

common/alog.cpp

@@ -24,6 +24,7 @@ limitations under the License.
 #include <mutex>
 #include <condition_variable>
 #include <unistd.h>
+#include <pthread.h>
 #include <sys/types.h>
 #include <sys/stat.h>
 #include <fcntl.h>
@@ -220,6 +221,21 @@ void LogFormatter::put_integer_dec(ALogBuffer& buf, ALogInteger x)
     }
 }
 
+// Protects log file rotation. It used to be a function-local static in
+// write(), but if fork() happened while a thread was rotating, the child
+// would inherit the mutex in locked state forever. So it is hoisted here
+// and serialized against fork() with pthread_atfork(): prepare acquires
+// the lock (waiting for any in-flight rotation), and both parent and
+// child release it after fork().
+static mutex log_file_lock;
+
+__attribute__((constructor))
+static void __register_log_file_lock_atfork() {
+    pthread_atfork([] { log_file_lock.lock(); },
+                   [] { log_file_lock.unlock(); },
+                   [] { log_file_lock.unlock(); });
+}
+
 class LogOutputFile final : public BaseLogOutput {
 public:
     uint64_t log_file_size_limit = 0;
@@ -250,7 +266,6 @@ class LogOutputFile final : public BaseLogOutput {
         if (log_file_name && log_file_size_limit) {
             log_file_size += length;
             if (log_file_size > log_file_size_limit) {
-                static mutex log_file_lock;
                 lock_guard<mutex> guard(log_file_lock);
                 if (log_file_size > log_file_size_limit) {
                     log_file_rotate();

common/test/test_alog.cpp

@@ -24,9 +24,13 @@ limitations under the License.
 #include <photon/net/utils-stdstring.h>
 #include <chrono>
 #include <vector>
+#include <atomic>
+#include <thread>
 #include <stdint.h>
 #include <unistd.h>
 #include <fcntl.h>
+#include <sys/wait.h>
+#include <signal.h>
 #include "../../test/ci-tools.h"
 #include "../../test/gtest.h"
 
@@ -177,6 +181,45 @@ TEST(ALog, log_to_file) {
     ::close(fd);
 }
 
+static bool wait_child_exited(pid_t pid, int timeout_sec) {
+    for (int i = 0; i < timeout_sec * 100; ++i) {
+        int st;
+        if (::waitpid(pid, &st, WNOHANG) == pid)
+            return WIFEXITED(st) && WEXITSTATUS(st) == 0;
+        ::usleep(10 * 1000);
+    }
+    ::kill(pid, SIGKILL);
+    ::waitpid(pid, nullptr, 0);
+    return false;
+}
+
+TEST(ALog, fork_during_rotation) {
+    const char* fn = "/tmp/test_alog_fork.log";
+    // minimum rotate limit is 1MB
+    ASSERT_EQ(0, log_output_file(fn, 1024 * 1024, 3));
+    DEFER(log_output_file_close());
+    // keep triggering rotation in background, so that fork() below
+    // is likely to happen while the rotation lock is held
+    std::atomic<bool> stop{false};
+    std::thread writer([&] {
+        while (!stop)
+            LOG_INFO("background writer keeps rotating the log file, padding padding padding padding");
+    });
+    DEFER({ stop = true; writer.join(); });
+    for (int i = 0; i < 8; ++i) {
+        pid_t pid = fork();
+        ASSERT_GE(pid, 0);
+        if (pid == 0) {
+            // child: write enough to trigger a rotation of its own;
+            // it deadlocks here if the rotation lock was inherited locked
+            for (int j = 0; j < 16 * 1024; ++j)
+                LOG_INFO("child writer must not deadlock on the rotation lock, padding padding padding");
+            ::_exit(0);
+        }
+        EXPECT_TRUE(wait_child_exited(pid, 10)) << "child " << pid << " deadlocked";
+    }
+}
+
 TEST(ALog, float_point)
 {
     log_output = &log_output_test;