From 5cb688ed29996985359dde707d601aa94ff4345d Mon Sep 17 00:00:00 2001 From: Vladimir Davydov <vdavydov@tarantool.org> Date: Fri, 2 Sep 2022 15:05:55 +0300 Subject: [PATCH] Revert "log: free resources while event loop is running" This reverts commit 0c3f9b37cd19f6f0731dbc7ce1fc7a6bb65fd406. If log_destroy and log_boot use the same fd (STDERR_FILENO), say() called after say_logger_free() will write to a closed fd. What's worse, the fd may be reused, in which case say() will write to a completely unrelated file or socket (maybe a data file!). This is what happened with flightrec - flightrec finalization info message was written to an xlog file. Let's move say_logger_free() back to where it belongs - after other subsystem has been finalized. Reopens #4450 Needed for https://github.com/tarantool/tarantool-ee/issues/223 NO_DOC=bug fix NO_TEST=revert NO_CHANGELOG=unreleased --- .../unreleased/gh-4450-logger-sigsegv.md | 4 -- src/lib/core/say.c | 17 +------ src/main.cc | 2 +- test/app-tap/gh-4450-log-rotate-exit.test.lua | 46 ------------------- test/app-tap/suite.ini | 2 +- 5 files changed, 4 insertions(+), 67 deletions(-) delete mode 100644 changelogs/unreleased/gh-4450-logger-sigsegv.md delete mode 100755 test/app-tap/gh-4450-log-rotate-exit.test.lua diff --git a/changelogs/unreleased/gh-4450-logger-sigsegv.md b/changelogs/unreleased/gh-4450-logger-sigsegv.md deleted file mode 100644 index 3b898a605a..0000000000 --- a/changelogs/unreleased/gh-4450-logger-sigsegv.md +++ /dev/null @@ -1,4 +0,0 @@ -## bugfix/core - -* Fix potential nil dereference and crash in case of an active - log rotation during the program exit stage (gh-4450). diff --git a/src/lib/core/say.c b/src/lib/core/say.c index 942f7c8222..143128636d 100644 --- a/src/lib/core/say.c +++ b/src/lib/core/say.c @@ -279,7 +279,7 @@ log_rotate(struct log *log) if (pm_atomic_load(&log->type) != SAY_LOGGER_FILE) return 0; - ERROR_INJECT(ERRINJ_LOG_ROTATE, { usleep(1000); }); + ERROR_INJECT(ERRINJ_LOG_ROTATE, { usleep(10); }); int fd = open(log->path, O_WRONLY | O_APPEND | O_CREAT, S_IRUSR | S_IWUSR | S_IRGRP); @@ -762,24 +762,11 @@ say_logger_init(const char *init_str, int level, int nonblock, panic("failed to initialize logging subsystem"); } -/* - * Logger uses events loop and to free resources we need - * to wait until logs rotation is complete. Thus make sure - * this routine is called before events loop is finished. - */ void say_logger_free(void) { - if (say_logger_initialized()) { + if (say_logger_initialized()) log_destroy(&log_std); - /* - * Once destroyed switch to boot logger - * because boot logger is safe to use - * anytime and might be suitable for - * debugging. - */ - log_default = &log_boot; - } } /** {{{ Formatters */ diff --git a/src/main.cc b/src/main.cc index daacf13f4e..a7ce115614 100644 --- a/src/main.cc +++ b/src/main.cc @@ -145,7 +145,6 @@ on_shutdown_f(va_list ap) diag_log(); diag_clear(diag_get()); } - say_logger_free(); ev_break(loop(), EVBREAK_ALL); return 0; } @@ -588,6 +587,7 @@ tarantool_free(void) memtx_tx_manager_free(); coll_free(); systemd_free(); + say_logger_free(); fiber_free(); memory_free(); random_free(); diff --git a/test/app-tap/gh-4450-log-rotate-exit.test.lua b/test/app-tap/gh-4450-log-rotate-exit.test.lua deleted file mode 100755 index a1ca9abee2..0000000000 --- a/test/app-tap/gh-4450-log-rotate-exit.test.lua +++ /dev/null @@ -1,46 +0,0 @@ -#!/usr/bin/env tarantool - -local tap = require('tap') -local test = tap.test("gh-4450-log-rotate-exit") -local fio = require('fio') -local tarantool_bin = arg[-1] - -test:plan(1) - -local function run_script(code) - local dir = fio.tempdir() - local script_path = fio.pathjoin(dir, 'gh-4450-script.lua') - local script = fio.open(script_path, - {'O_CREAT', 'O_WRONLY', 'O_APPEND'}, - tonumber('0777', 8)) - script:write(code) - script:close() - local output_file = fio.pathjoin(fio.cwd(), 'gh-4450-out.txt') - local cmd = [[/bin/sh -c 'cd "%s" && "%s" ./gh-4450-script.lua 0> %s 2> %s']] - local code = os.execute( - string.format(cmd, dir, tarantool_bin, output_file, output_file) - ) - fio.rmtree(dir) - local out_fd = fio.open(output_file, {'O_RDONLY'}) - local output = out_fd:read(100000) - out_fd:close() - return code, output -end - --- --- gh-4382: an error in main script should be handled gracefully, --- with proper logging. --- -local code = "log = require('log')\n" -code = code .. "box.cfg{log = 'gh-4550.log'}\n" -code = code .. "box.error.injection.set('ERRINJ_LOG_ROTATE', true)\n" -code = code .. "log.rotate()\n" -code = code .. "os.exit()\n" -local _, output = run_script(code) - -test:diag(output) -test:ok(not string.find(output, "SEGV_MAPERR"), - "program exited without SEGV_MAPERR") - -test:check() -os.exit(0) diff --git a/test/app-tap/suite.ini b/test/app-tap/suite.ini index e550dbb9d6..4af18fb465 100644 --- a/test/app-tap/suite.ini +++ b/test/app-tap/suite.ini @@ -4,7 +4,7 @@ description = application server tests (TAP) lua_libs = lua/require_mod.lua lua/serializer_test.lua lua/process_timeout.lua is_parallel = True use_unix_sockets_iproto = True -release_disabled = gh-5040-inter-mode-isatty-via-errinj.test.lua gh-2717-no-quit-sigint.test.lua gh-4450-log-rotate-exit.test.lua +release_disabled = gh-5040-inter-mode-isatty-via-errinj.test.lua gh-2717-no-quit-sigint.test.lua fragile = { "retries": 10, "tests": { -- GitLab