Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Log rotate #4032

Merged
merged 13 commits into from
Mar 15, 2024
Merged

Log rotate #4032

merged 13 commits into from
Mar 15, 2024

Conversation

dktapps
Copy link
Member

@dktapps dktapps commented Feb 10, 2021

Introduction

server.log is not rotated by default and grows unmanageably large, to the point where it's so huge that it's not possible to read it with any standard text editor anymore.

This PR implements automatic log rotation.

  • When the server.log reaches 32MB in size, it's moved to the log_archive folder of the server's data folder.
  • The archive's file name will look something like this: server.2024-03-15T15.26.24.0.log
  • The file's name contains the date and time when the file was archived. This may be useful if you're trying to find logs from a particular time frame.

This has several benefits:

  • Much more easily find logs from a particular time frame without scrolling through GBs of logs
  • Free up space without stopping the server - Archived log files log_archive/ can be safely deleted and/or modified while the server is running

Why not automatically compress the files?

The original version of this PR did exactly that, but it created various problems, such as the possibility of the logger stalling while compressing large log files, disk running out of space, etc.

If you want to automatically compress or clean up the log files yourself, I suggest an external cron job or disk watcher.

Relevant issues

Closes #4029.

Changes

Behavioural changes

Described above.

Tests

This can be seen in action using the following script. It will generate 4 log files in $PWD/testlogsarchive.

<?php

require 'vendor/autoload.php';

$logWriter = new \pocketmine\utils\MainLoggerThread("test.log", getcwd() . "/testlogsarchive");
$logWriter->start();


for($i = 0; $i < 512 * 1024; $i++){
	$logWriter->write(str_repeat("a", 256));
}
echo "Waiting for logger thread to stop...\n";
$logWriter->shutdown();
echo "Done.\n";

When the log file reaches 32 MB, it's automatically compressed using gzip and moved to the log_archive directory of the server data directory.
This is rather costly (200-400ms of CPU time on my i7-7700HQ), but since 32 MB log files shouldn't be achieved very often, this overhead shouldn't be an issue.
32 MB was chosen because this is still handleable by Windows Notepad (in case a user happens to double click we don't want their PC to melt down) and sufficiently small enough that compression won't block the logger for minutes at a time, but large enough to minimize disk wastage (partial sector allocations).
I do have some concerns about logs possibly not getting written if forced termination occurs (e.g. segfault). While these were already potential problems to begin with, a 0.3sec window for a fault to occur in means that a larger number of messages might disappear if a termination occurs.
@dktapps dktapps added Category: Core Related to internal functionality Type: Contribution labels Feb 10, 2021
@SOF3 SOF3 self-requested a review February 11, 2021 15:25
SOF3
SOF3 previously approved these changes Feb 24, 2021
@dktapps dktapps changed the base branch from master to next-minor December 29, 2021 22:01
@dktapps dktapps added Type: Enhancement Contributes features or other improvements to PocketMine-MP and removed Type: Contribution labels Nov 26, 2022
@dktapps dktapps added the Status: Blocked Depends on other changes which are yet to be completed label May 26, 2023
@dktapps
Copy link
Member Author

dktapps commented May 26, 2023

Blocked until pmmp/ext-pmmpthread#42 is resolved

@dktapps dktapps added this to the 5.1 milestone May 29, 2023
@dktapps dktapps modified the milestones: 5.2, 5.4 Jul 4, 2023
@dktapps dktapps modified the milestones: 5.4, 5.5 Aug 2, 2023
@dktapps dktapps modified the milestones: 5.5, 5.7 Sep 6, 2023
@dktapps dktapps modified the milestones: 5.8, 5.9 Nov 9, 2023
@dktapps
Copy link
Member Author

dktapps commented Nov 21, 2023

pmmp/ext-pmmpthread@b2b6100 should resolve the performance issue blocking this

we really need a logger context inside this thread ...
@dktapps
Copy link
Member Author

dktapps commented Nov 21, 2023

Another problem I hadn't foreseen: If a user with a very large log file (e.g. 50 GB) loads this code in their server, the MainLoggerThread will stall for several minutes as it compresses the old log file. This could cause loss of new logs, as the thread wouldn't be writing new log entries to the disk while this is happening.

We probably need an extra thread to solve this.

@dktapps dktapps modified the milestones: 5.9, 5.11 Dec 20, 2023
@dktapps dktapps modified the milestones: 5.11, 5.13 Mar 1, 2024
@dktapps
Copy link
Member Author

dktapps commented Mar 15, 2024

I'm thinking this would be OK if we were to get rid of the compression step. If we have the server move old logs to a new location and release them, external systems can handle cleaning them up, compressing them, or whatever else. The only thing we really need to do is release handles to the file(s) containing the archival logs, so that they can be processed by other tools without stopping the server.

@dktapps dktapps removed the Status: Blocked Depends on other changes which are yet to be completed label Mar 15, 2024
@dktapps dktapps merged commit 7148c7a into minor-next Mar 15, 2024
26 checks passed
@dktapps dktapps deleted the log-rotate branch March 15, 2024 16:44
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Category: Core Related to internal functionality Type: Enhancement Contributes features or other improvements to PocketMine-MP
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants