Skip to content
Snippets Groups Projects
Commit 8f65507d authored by Ryan Gonzalez's avatar Ryan Gonzalez
Browse files

logger: Recreate output log files if they get deleted


Before writing a log line to the file, first check to make sure that
it's still around. If not, then just re-create it, so that clearing the
current logs out doesn't actually stop future logs from appearing.

This takes advantage of the existing fstat() setup that checks the file
size and swaps it out with stat() to be able to pick up on the file
going missing. (That change shouldn't introduce any notable race
conditions on the directory side, because srt-logger has already chdir'd
into the log file directly, and self->filename isn't a full path in the
first place.)

steamrt/tasks#487

Signed-off-by: default avatarRyan Gonzalez <ryan.gonzalez@collabora.com>
parent b03c2a25
Branches
Tags
1 merge request!740logger: Recreate output log files if they get deleted
Pipeline #97608 passed
...@@ -86,6 +86,7 @@ struct _SrtLogger { ...@@ -86,6 +86,7 @@ struct _SrtLogger {
gchar *new_filename; gchar *new_filename;
gchar *log_dir; gchar *log_dir;
gchar *terminal; gchar *terminal;
struct stat file_stat;
int child_ready_to_parent; int child_ready_to_parent;
int pipe_from_parent; int pipe_from_parent;
int original_stderr; int original_stderr;
...@@ -475,6 +476,11 @@ _srt_logger_setup (SrtLogger *self, ...@@ -475,6 +476,11 @@ _srt_logger_setup (SrtLogger *self,
"Unable to open \"%s\"", "Unable to open \"%s\"",
self->filename); self->filename);
if (fstat (self->file_fd, &self->file_stat) < 0)
return glnx_throw_errno_prefix (error,
"Unable to stat \"%s\"",
self->filename);
message = g_string_new (g_get_prgname ()); message = g_string_new (g_get_prgname ());
date_time = g_date_time_new_now_local (); date_time = g_date_time_new_now_local ();
timestamp = g_date_time_format (date_time, "%F %T%z"); timestamp = g_date_time_format (date_time, "%F %T%z");
...@@ -1020,6 +1026,7 @@ _srt_logger_try_rotate (SrtLogger *self, ...@@ -1020,6 +1026,7 @@ _srt_logger_try_rotate (SrtLogger *self,
struct flock exclusive_lock = EXCLUSIVE_LOCK; struct flock exclusive_lock = EXCLUSIVE_LOCK;
struct flock shared_lock = SHARED_LOCK; struct flock shared_lock = SHARED_LOCK;
glnx_autofd int new_fd = -1; glnx_autofd int new_fd = -1;
struct stat new_stat;
gboolean ret = FALSE; gboolean ret = FALSE;
g_debug ("Trying to rotate log file %s", self->filename); g_debug ("Trying to rotate log file %s", self->filename);
...@@ -1069,6 +1076,14 @@ _srt_logger_try_rotate (SrtLogger *self, ...@@ -1069,6 +1076,14 @@ _srt_logger_try_rotate (SrtLogger *self,
goto out; goto out;
} }
if (fstat (new_fd, &new_stat) < 0)
{
glnx_throw_errno_prefix (error,
"Unable to stat \"%s\"",
self->new_filename);
goto out;
}
if (TEMP_FAILURE_RETRY (rename (self->new_filename, self->filename)) != 0) if (TEMP_FAILURE_RETRY (rename (self->new_filename, self->filename)) != 0)
{ {
glnx_throw_errno_prefix (error, "Unable to rename %s to %s", glnx_throw_errno_prefix (error, "Unable to rename %s to %s",
...@@ -1078,6 +1093,7 @@ _srt_logger_try_rotate (SrtLogger *self, ...@@ -1078,6 +1093,7 @@ _srt_logger_try_rotate (SrtLogger *self,
glnx_close_fd (&self->file_fd); glnx_close_fd (&self->file_fd);
self->file_fd = g_steal_fd (&new_fd); self->file_fd = g_steal_fd (&new_fd);
memcpy (&self->file_stat, &new_stat, sizeof (new_stat));
ret = TRUE; ret = TRUE;
out: out:
...@@ -1198,20 +1214,49 @@ logger_process_complete_line (SrtLogger *self, ...@@ -1198,20 +1214,49 @@ logger_process_complete_line (SrtLogger *self,
if (self->file_fd >= 0 && level <= self->file_level) if (self->file_fd >= 0 && level <= self->file_level)
{ {
struct stat stat_buf; if (self->filename != NULL)
if (self->max_bytes > 0
&& self->filename != NULL
&& fstat (self->file_fd, &stat_buf) == 0
&& (stat_buf.st_size + len) > self->max_bytes)
{ {
g_autoptr(GError) local_error = NULL; gboolean log_file_still_exists = FALSE;
struct stat current_stat;
if (TEMP_FAILURE_RETRY (stat (self->filename, &current_stat)) == 0)
log_file_still_exists = _srt_is_same_stat (&current_stat,
&self->file_stat);
else if (errno != ENOENT)
_srt_log_warning ("Unable to stat log file: %s",
g_strerror (errno));
if (!_srt_logger_try_rotate (self, &local_error)) if (!log_file_still_exists)
{
/* The log file is either deleted or replaced, probably by a
* developer who wanted to clear the logs out. Re-create it now
* instead of staying silent. */
glnx_autofd int new_fd = -1;
g_autoptr(GError) local_error = NULL;
new_fd = TEMP_FAILURE_RETRY (open (self->filename,
OPEN_FLAGS,
0644));
if (new_fd < 0)
_srt_log_warning ("Unable to re-open log file: %s",
g_strerror (errno));
else if (!lock_output_file (self->filename, new_fd, &local_error))
_srt_log_warning ("Unable to re-lock log file: %s",
local_error->message);
else
self->file_fd = glnx_steal_fd (&new_fd);
}
else if (self->max_bytes > 0
&& (current_stat.st_size + len) > self->max_bytes)
{ {
_srt_log_warning ("Unable to rotate log file: %s", g_autoptr(GError) local_error = NULL;
local_error->message);
self->max_bytes = 0; if (!_srt_logger_try_rotate (self, &local_error))
{
_srt_log_warning ("Unable to rotate log file: %s",
local_error->message);
self->max_bytes = 0;
}
} }
} }
......
...@@ -677,6 +677,45 @@ class TestLogger(BaseTest): ...@@ -677,6 +677,45 @@ class TestLogger(BaseTest):
content = reader.read() content = reader.read()
self.assertIn(b'last message\n', content) self.assertIn(b'last message\n', content)
def test_reopen(self) -> None:
for replaced in False, True:
with tempfile.TemporaryDirectory() as tmpdir:
log_path = Path(tmpdir) / 'log'
proc = subprocess.Popen(
self.logger + [
'--filename', log_path.name,
'--log-directory', str(log_path.parent),
'--no-auto-terminal',
],
stdin=subprocess.PIPE,
stdout=STDERR_FILENO,
stderr=STDERR_FILENO,
)
with wrap_process_io(proc.stdin) as stdin:
stdin.write('first message\n')
stdin.flush()
while (not log_path.exists()
or 'first message' not in log_path.read_text()):
time.sleep(0.1)
if replaced:
tmp_path = log_path.with_suffix('.tmp')
tmp_path.touch()
tmp_path.rename(log_path)
else:
log_path.unlink()
stdin.write('second message\n')
stdin.flush()
proc.wait()
content = log_path.read_text()
self.assertIn('second message', content)
def test_stderr_only(self) -> None: def test_stderr_only(self) -> None:
proc = subprocess.Popen( proc = subprocess.Popen(
self.logger + [ self.logger + [
......
0% Loading or .
You are about to add 0 people to the discussion. Proceed with caution.
Please register or to comment