Skip to content

Commit 4cce983

Browse files
photonlibosColdwingslihuiba
authored
[Backport][0.7 to 0.6] | | fix(alog): prevent child deadlock on rotation lock across fork() (#1573) (#1575) (#1577) (#1579) (#1582)
* [Backport][0.8 to 0.7] | fix(alog): prevent child deadlock on rotation lock across fork() (#1573) (#1575) (#1577) (#1579) * fix(alog): prevent child deadlock on rotation lock across fork() (#1573) (#1575) (#1577) The log rotation mutex was a function-local static in write(). If fork() happened while another thread was rotating, the child inherited the mutex permanently locked and deadlocked on its next rotation. Hoist the lock to file scope and serialize it against fork() with pthread_atfork(): prepare acquires it (waiting out any in-flight rotation), and both parent and child release it afterwards. Add a fork-during-rotation regression test. Co-authored-by: Coldwings <coldwings@me.com> * Update alog.cpp --------- Co-authored-by: Coldwings <coldwings@me.com> * Update test_alog.cpp * Update test_alog.cpp --------- Co-authored-by: Coldwings <coldwings@me.com> Co-authored-by: Huiba Li <huiba.lhb@alibaba-inc.com>
1 parent 70d0ba1 commit 4cce983

2 files changed

Lines changed: 59 additions & 1 deletion

File tree

common/alog.cpp

Lines changed: 16 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -24,6 +24,7 @@ limitations under the License.
2424
#include <mutex>
2525
#include <condition_variable>
2626
#include <unistd.h>
27+
#include <pthread.h>
2728
#include <sys/types.h>
2829
#include <sys/stat.h>
2930
#include <fcntl.h>
@@ -231,6 +232,21 @@ struct tm* alog_update_time(time_t now0) {
231232
return &alog_time;
232233
}
233234

235+
// Protects log file rotation. It used to be a function-local static in
236+
// write(), but if fork() happened while a thread was rotating, the child
237+
// would inherit the mutex in locked state forever. So it is hoisted here
238+
// and serialized against fork() with pthread_atfork(): prepare acquires
239+
// the lock (waiting for any in-flight rotation), and both parent and
240+
// child release it after fork().
241+
static mutex log_file_lock;
242+
243+
__attribute__((constructor))
244+
static void __register_log_file_lock_atfork() {
245+
pthread_atfork([] { log_file_lock.lock(); },
246+
[] { log_file_lock.unlock(); },
247+
[] { log_file_lock.unlock(); });
248+
}
249+
234250
class LogOutputFile final : public BaseLogOutput {
235251
public:
236252
uint64_t log_file_size_limit = 0;
@@ -261,7 +277,6 @@ class LogOutputFile final : public BaseLogOutput {
261277
if (log_file_name && log_file_size_limit) {
262278
log_file_size += length;
263279
if (log_file_size > log_file_size_limit) {
264-
static mutex log_file_lock;
265280
lock_guard<mutex> guard(log_file_lock);
266281
if (log_file_size > log_file_size_limit) {
267282
log_file_rotate();

common/test/test_alog.cpp

Lines changed: 43 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -22,9 +22,13 @@ limitations under the License.
2222
#include "photon/thread/thread.h"
2323
#include <chrono>
2424
#include <vector>
25+
#include <atomic>
26+
#include <thread>
2527
#include <stdint.h>
2628
#include <unistd.h>
2729
#include <fcntl.h>
30+
#include <sys/wait.h>
31+
#include <signal.h>
2832

2933
class LogOutputTest : public ILogOutput {
3034
public:
@@ -172,6 +176,45 @@ TEST(ALog, log_to_file) {
172176
::close(fd);
173177
}
174178

179+
static bool wait_child_exited(pid_t pid, int timeout_sec) {
180+
for (int i = 0; i < timeout_sec * 100; ++i) {
181+
int st;
182+
if (::waitpid(pid, &st, WNOHANG) == pid)
183+
return WIFEXITED(st) && WEXITSTATUS(st) == 0;
184+
::usleep(10 * 1000);
185+
}
186+
::kill(pid, SIGKILL);
187+
::waitpid(pid, nullptr, 0);
188+
return false;
189+
}
190+
191+
TEST(ALog, fork_during_rotation) {
192+
const char* fn = "/tmp/test_alog_fork.log";
193+
// minimum rotate limit is 1MB
194+
ASSERT_EQ(0, log_output_file(fn, 1024 * 1024, 3));
195+
DEFER(log_output_file_close());
196+
// keep triggering rotation in background, so that fork() below
197+
// is likely to happen while the rotation lock is held
198+
std::atomic<bool> stop{false};
199+
std::thread writer([&] {
200+
while (!stop)
201+
LOG_INFO("background writer keeps rotating the log file, padding padding padding padding");
202+
});
203+
DEFER({ stop = true; writer.join(); });
204+
for (int i = 0; i < 8; ++i) {
205+
pid_t pid = fork();
206+
ASSERT_GE(pid, 0);
207+
if (pid == 0) {
208+
// child: write enough to trigger a rotation of its own;
209+
// it deadlocks here if the rotation lock was inherited locked
210+
for (int j = 0; j < 16 * 1024; ++j)
211+
LOG_INFO("child writer must not deadlock on the rotation lock, padding padding padding");
212+
::_exit(0);
213+
}
214+
EXPECT_TRUE(wait_child_exited(pid, 10)) << "child " << pid << " deadlocked";
215+
}
216+
}
217+
175218
TEST(ALog, float_point)
176219
{
177220
log_output = &log_output_test;

0 commit comments

Comments
 (0)