Repository navigation
Log - #100
Merged
Merged
Log#100
Conversation
Review follow-ups on the size based log rotation:
Rotation recreates the log file, and it was created with 0666 & ~umask,
so a private 0600 log file became world readable on the first rotation.
The mode is now taken from the file being replaced, right before it is
renamed, and the fresh file is created with it through O_CREAT|O_EXCL
plus fchmod, which also means a file that already exists is never
chmod'ed behind the user's back.
The handle was closed before the rename. On POSIX that is unnecessary,
and it dropped every log once the path could not be opened again while
the open handle could still write: permissions tightened under a
running process (file 0400, directory 0500), privileges dropped, ... A
rotation now renames the open file, and only closes the old handle once
the fresh one is open; if the path can not be reopened, the backup is
moved back and the handle keeps appending, so nothing is lost either
way. Windows still closes first, because an opened file can not be
renamed there, but it reopens immediately so the log that triggered the
rotation is not dropped.
Backups were probed as 1, 2, 3... which assumed contiguous numbering.
A partly failed shift leaves a hole (".1", ".3", ".4"), and cleaning up
from the first missing index never reached the files above it: they
survived forever after the limit was lowered. The directory is now
listed and every existing backup is shifted or removed, which also
keeps --log_rotate_max_backups from costing one rename() per index. A
directory that can not be listed (writable but not readable) falls back
to a bounded probe, so rotation keeps working there too.
The cached file size was only resynced when the file was opened, so a
short write or a failed flush left it behind the real size for the rest
of the process and postponed every later rotation. The size is re-read
after such a failure, and the sticky error flag is cleared so the next
log gets a chance to be written.
shift_failure_keeps_the_newest_backup counted logs to cross the
rotation threshold, which depends on the length of the source path in
every log header: with a longer checkout the third batch rotated twice
and the preserved backup was pruned, failing the test. The rotation
tests now watch the file (waiting for a rotation, for the file to grow)
instead of counting, so they no longer depend on where the tree lives.
Verified by running them from a checkout path about 50 characters
longer, where all of them pass.
New tests: rotation keeps the file mode, logs keep being written when
the path can not be reopened, and backups left above a hole are removed.
Follow-up on the review of the log rotation: GetLastSystemErrorCode() was passed as the last argument of the same call that builds the message, so the error code could be read after the formatting had already touched errno, which is exactly what the comment on BackOffAfterFailedRotation() warns about. The reopen failure also read errno only after moving the backup back, so a failing rollback replaced the reason the reopen failed, and the Windows branch read GetLastError() after reopening the handle, whose fallback to ".\debug.log" usually succeeds and wipes the error that matters. Every failure site now captures the code in a statement of its own, before formatting the message and before any recovery step. huge_max_backups_shifts_only_existing_backups assumed that 2500 logs cross the threshold exactly twice, which needs a log header shorter than 259 bytes: the header carries the path of the source file, so on a deeper checkout the third rotation happened, ".3" appeared and the test failed, the same trap the review found in shift_failure_keeps_the_newest_backup(). It now writes until ".2" appears, which is two rotations by construction, and the check that there is no ".3" follows from that instead of from a byte estimate. Verified from a checkout whose path is about 50 characters longer than the one used so far (headers of about 1150 bytes per log): the whole rotation suite passes there, and the full test_butil run is unchanged apart from the pre-existing StackTraceTest.find_symbol failure. Note on the drain added to LogRotationTest::SetUp() earlier: it waits for six 50ms samples of a stable file size, not for a single stat(), so it costs about 300ms per rotation test even when the async queue is already empty.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
No description provided.