Skip to content

Commit 1d8c73e

Browse files
psilabs-devDifegue
psilabs-dev
and
Difegue
committed
Fix issue Difegue#1406
Implement log rotating logger with RotatingLog Co-authored-by: Difegue <[email protected]>
1 parent 237b22f commit 1d8c73e

File tree

4 files changed

+769
-65
lines changed

4 files changed

+769
-65
lines changed

‎lib/LANraragi/Utils/Logging.pm‎

Lines changed: 146 additions & 65 deletions
Original file line numberDiff line numberDiff line change
@@ -5,19 +5,29 @@ use warnings;
55
use utf8;
66

77
use feature 'say';
8+
use feature 'isa';
89
use POSIX;
910
use FindBin;
11+
use Time::HiRes;
12+
use Config;
1013

1114
use Encode;
1215
use File::ReadBackwards;
1316
use Compress::Zlib;
17+
use Mojo::Log;
1418
use LANraragi::Model::Config;
19+
use LANraragi::Utils::RotatingLog;
1520
use LANraragi::Utils::Redis qw(redis_decode);
21+
use LANraragi::Utils::TempFolder qw(get_temp);
22+
23+
use constant IS_UNIX => ( $Config{osname} ne 'MSWin32' );
1624

1725
# Contains all functions related to logging.
1826
use Exporter 'import';
1927
our @EXPORT_OK = qw(get_logger get_plugin_logger get_logdir get_lines_from_file);
2028

29+
our %LOGGER_CACHE;
30+
2131
# Get the Log folder.
2232
sub get_logdir {
2333

@@ -31,89 +41,84 @@ sub get_logdir {
3141
return $log_folder;
3242
}
3343

34-
# Returns a Logger object with a custom name and a filename for the log file.
44+
# Returns a Mojo::Log object with a custom name and a filename for the log file.
3545
sub get_logger {
3646

3747
#Customize log file location and minimum log level
3848
my $pgname = $_[0];
3949
my $logfile = $_[1];
4050

41-
my $logpath = get_logdir . "/$logfile.log";
42-
43-
if ( -e $logpath && -s $logpath > 1048576 ) {
51+
my $logpath = get_logdir . "/$logfile.log";
52+
my $cache_key = "$logfile";
53+
my $log;
54+
55+
# Reuse cached logger if exists, otherwise clean cache and recreate
56+
my $cache_refresh_error;
57+
if ( exists $LOGGER_CACHE{$cache_key} && -e $logpath ) {
58+
$log = $LOGGER_CACHE{$cache_key};
59+
{
60+
local $@;
61+
eval {
62+
LANraragi::Utils::RotatingLog::refresh_logger_handle($log);
63+
};
64+
$cache_refresh_error = $@;
65+
}
66+
return get_log_context($log, $pgname) unless $cache_refresh_error;
4467

45-
# Rotate log if it's > 1MB
46-
say "Rotating logfile $logfile";
68+
# Invalidate cache and avoid returning a stale handle
69+
delete $LOGGER_CACHE{$cache_key};
70+
undef $log;
71+
}
4772

48-
# Based on Logfile::Rotate
49-
# Rotate existing logs
50-
for ( my $i = 7; $i > 1; $i-- ) {
51-
my $j = $i - 1;
52-
my $next = "$logpath.$i.gz";
53-
my $prev = "$logpath.$j.gz";
54-
if ( -r $prev && -f $prev ) {
55-
rename( $prev, $next ) or die "error: rename failed: ($prev,$next)";
56-
}
73+
# Create and cache logger with retry + backoff + jitter
74+
# Report the first logger init failure if exists
75+
my $tries = 0;
76+
my $first_error;
77+
while ( $tries < 3 ) {
78+
my $retry_error;
79+
{
80+
local $@;
81+
eval {
82+
$log = LANraragi::Utils::RotatingLog->new(
83+
path => $logpath,
84+
level => 'info',
85+
logfile => $logfile,
86+
tempdir => get_temp()
87+
);
88+
};
89+
$retry_error = $@;
5790
}
5891

59-
# Rotate current log and Gzip-it
60-
my $gz = gzopen( "$logpath.1.gz", "wb" ) or die "error: could not gzopen $logpath: $!";
92+
unless ( $retry_error ) {
93+
configure_logger( $log );
94+
$LOGGER_CACHE{$cache_key} = $log;
95+
last;
96+
}
6197

62-
open( my $handle, '<', $logpath ) or die "Couldn't open $logpath :" . $!;
63-
my $buffer;
64-
$gz->gzwrite($buffer) while read( $handle, $buffer, 4096 ) > 0;
65-
$gz->gzclose();
66-
close $handle;
98+
$first_error //= $retry_error;
99+
Time::HiRes::sleep(rand());
100+
$tries++;
67101

68-
unlink $logpath or die "error: could not delete $logpath: $!";
69102
}
70103

71-
my $log = Mojo::Log->new(
72-
path => $logpath,
73-
level => 'info'
74-
);
75-
76-
my $devmode = LANraragi::Model::Config->enable_devmode;
77-
78-
#Tell logger to store debug logs as well in debug mode
79-
if ($devmode) {
80-
$log->level('debug');
104+
# Fall back to Mojo::Log if retry doesn't work
105+
if ( !$log ) {
106+
$log = Mojo::Log->new(
107+
path => $logpath,
108+
level => 'info'
109+
);
110+
configure_logger( $log );
111+
$log->error("RotatingLog init failed, falling back to Mojo::Log. First error: $first_error");
112+
} elsif ( $tries > 0 ) {
113+
$log->warn("RotatingLog initialized after $tries failures. First error: $first_error");
81114
}
82115

83-
# Step down into trace if we're launched from npm run dev-server-verbose
84-
if ( $ENV{LRR_DEVSERVER} ) {
85-
$log->level('trace');
116+
# Report cache refresh error if exists
117+
if ( $cache_refresh_error ) {
118+
$log->error($cache_refresh_error);
86119
}
87120

88-
#Copy logged messages to STDOUT with the matching name
89-
$log->on(
90-
message => sub {
91-
my ( $time, $level, @lines ) = @_;
92-
93-
#Like with logging to file, debug logs are only printed in debug mode
94-
unless ( $devmode == 0 && ( $level eq 'debug' || $level eq 'trace' ) ) {
95-
print "[$pgname] [$level] ";
96-
say $lines[0];
97-
}
98-
}
99-
);
100-
101-
$log->format(
102-
sub {
103-
my ( $time, $level, @lines ) = @_;
104-
my $time2 = strftime( "%Y-%m-%d %H:%M:%S", localtime($time) );
105-
106-
my $logstring = join( "\n", @lines );
107-
108-
# We'd like to make sure we always show proper UTF-8.
109-
# redis_decode, while not initially designed for this, does the job.
110-
$logstring = redis_decode($logstring);
111-
112-
return "[$time2] [$pgname] [$level] $logstring\n";
113-
}
114-
);
115-
116-
return $log;
121+
return get_log_context($log, $pgname);
117122
}
118123

119124
sub get_plugin_logger {
@@ -151,4 +156,80 @@ sub get_lines_from_file {
151156

152157
}
153158

159+
# Provide logger with the required configs and formatting
160+
sub configure_logger {
161+
162+
my $logger = shift;
163+
164+
my $devmode = LANraragi::Model::Config->enable_devmode;
165+
166+
#Tell logger to store debug logs as well in debug mode
167+
if ($devmode) {
168+
$logger->level('debug');
169+
}
170+
171+
# Step down into trace if we're launched from npm run dev-server-verbose
172+
if ( $ENV{LRR_DEVSERVER} ) {
173+
$logger->level('trace');
174+
}
175+
176+
# Copy logged messages to STDOUT with the matching name
177+
$logger->on(
178+
message => sub {
179+
my ( $log, $level, @lines ) = @_;
180+
181+
# Like with logging to file, debug logs are only printed in debug mode
182+
unless ( $devmode == 0 && ( $level eq 'debug' || $level eq 'trace' ) ) {
183+
my $ns_label = '';
184+
if ( @lines && defined $lines[0] && $lines[0] =~ /^\[[^\]]+\]$/ ) {
185+
$ns_label = shift @lines;
186+
}
187+
if ($ns_label) {
188+
print "$ns_label [$level] ";
189+
} else {
190+
print "[$level] ";
191+
}
192+
say $lines[0] // '';
193+
}
194+
}
195+
);
196+
197+
$logger->format(
198+
sub {
199+
my ( $time, $level, @lines ) = @_;
200+
my $time2 = strftime( "%Y-%m-%d %H:%M:%S", localtime($time) );
201+
202+
my $ns_label = '';
203+
if ( @lines && defined $lines[0] && $lines[0] =~ /^\[[^\]]+\]$/ ) {
204+
$ns_label = shift @lines;
205+
}
206+
207+
my $logstring = join( "\n", @lines );
208+
209+
# We'd like to make sure we always show proper UTF-8.
210+
# redis_decode, while not initially designed for this, does the job.
211+
$logstring = redis_decode($logstring);
212+
213+
return $ns_label
214+
? "[$time2] $ns_label [$level] $logstring\n"
215+
: "[$time2] [$level] $logstring\n";
216+
}
217+
);
218+
}
219+
220+
sub get_log_context {
221+
my $log = shift;
222+
my $pgname = shift;
223+
224+
if ( $log isa 'LANraragi::Utils::RotatingLog' ) {
225+
return Mojo::Log->new(
226+
parent => $log,
227+
context => ["[$pgname]"],
228+
level => $log->level
229+
);
230+
} else {
231+
return $log->context("[$pgname]");
232+
}
233+
}
234+
154235
1;

0 commit comments

Comments
 (0)