fix: disable log buffering and add more requests stats (#10622)

fixes #10621 also add request start timestamp
openfoodfacts · Jul 30, 2024 · 000ead2 · 000ead2
1 parent 574d600
commit 000ead2
Show file tree

Hide file tree

Showing 8 changed files with 18 additions and 11 deletions.
diff --git a/conf/obf-log.conf b/conf/obf-log.conf
@@ -9,27 +9,27 @@ log4perl.PatternLayout.cspec.J = sub { my $context = Log::Log4perl::MDC->get_con
 log4perl.appender.LOGFILE=Log::Log4perl::Appender::File
 log4perl.appender.LOGFILE.filename=/srv/obf/logs/log4perl.log
 log4perl.appender.LOGFILE.mode=append
-log4perl.appender.LOGFILE.autoflush=0
+log4perl.appender.LOGFILE.autoflush=1
 log4perl.appender.LOGFILE.layout=PatternLayout
 log4perl.appender.LOGFILE.layout.ConversionPattern=[%d] %F %L %c %S %m{chomp}%n
 
 log4perl.appender.MONGODB_LOGFILE=Log::Log4perl::Appender::File
 log4perl.appender.MONGODB_LOGFILE.filename=/srv/obf/logs/mongodb_log4perl.log
 log4perl.appender.MONGODB_LOGFILE.mode=append
-log4perl.appender.MONGODB_LOGFILE.autoflush=0
+log4perl.appender.MONGODB_LOGFILE.autoflush=1
 log4perl.appender.MONGODB_LOGFILE.layout=PatternLayout
 log4perl.appender.MONGODB_LOGFILE.layout.ConversionPattern=[%d] %F %L %c %S %m{chomp}%n
 
 log4perl.appender.RATELIMITER_LOGFILE=Log::Log4perl::Appender::File
 log4perl.appender.RATELIMITER_LOGFILE.filename=/srv/obf/logs/ratelimiter_log4perl.log
 log4perl.appender.RATELIMITER_LOGFILE.mode=append
-log4perl.appender.RATELIMITER_LOGFILE.autoflush=0
+log4perl.appender.RATELIMITER_LOGFILE.autoflush=1
 log4perl.appender.RATELIMITER_LOGFILE.layout=PatternLayout
 log4perl.appender.RATELIMITER_LOGFILE.layout.ConversionPattern=[%d] %F %L %c %S %m{chomp}%n
 
 log4perl.appender.REQUESTSTATS_LOGFILE=Log::Log4perl::Appender::File
 log4perl.appender.REQUESTSTATS_LOGFILE.filename=/srv/obf/logs/requeststats_log4perl.log
 log4perl.appender.REQUESTSTATS_LOGFILE.mode=append
-log4perl.appender.REQUESTSTATS_LOGFILE.autoflush=0
+log4perl.appender.REQUESTSTATS_LOGFILE.autoflush=1
 log4perl.appender.REQUESTSTATS_LOGFILE.layout=PatternLayout
 log4perl.appender.REQUESTSTATS_LOGFILE.layout.ConversionPattern=%J %n
diff --git a/conf/off-log.conf b/conf/off-log.conf
@@ -9,27 +9,28 @@ log4perl.PatternLayout.cspec.J = sub { my $context = Log::Log4perl::MDC->get_con
 log4perl.appender.LOGFILE=Log::Log4perl::Appender::File
 log4perl.appender.LOGFILE.filename=/srv/off/logs/log4perl.log
 log4perl.appender.LOGFILE.mode=append
-log4perl.appender.LOGFILE.autoflush=0
+# note: autoflush=0 results in multiple log entries being mixed (probably because there are several Apache processes writing to the same file)
+log4perl.appender.LOGFILE.autoflush=1
 log4perl.appender.LOGFILE.layout=PatternLayout
 log4perl.appender.LOGFILE.layout.ConversionPattern=[%d] %F %L %c %S %m{chomp}%n
 
 log4perl.appender.MONGODB_LOGFILE=Log::Log4perl::Appender::File
 log4perl.appender.MONGODB_LOGFILE.filename=/srv/off/logs/mongodb_log4perl.log
 log4perl.appender.MONGODB_LOGFILE.mode=append
-log4perl.appender.MONGODB_LOGFILE.autoflush=0
+log4perl.appender.MONGODB_LOGFILE.autoflush=1
 log4perl.appender.MONGODB_LOGFILE.layout=PatternLayout
 log4perl.appender.MONGODB_LOGFILE.layout.ConversionPattern=[%d] %F %L %c %S %m{chomp}%n
 
 log4perl.appender.RATELIMITER_LOGFILE=Log::Log4perl::Appender::File
 log4perl.appender.RATELIMITER_LOGFILE.filename=/srv/off/logs/ratelimiter_log4perl.log
 log4perl.appender.RATELIMITER_LOGFILE.mode=append
-log4perl.appender.RATELIMITER_LOGFILE.autoflush=0
+log4perl.appender.RATELIMITER_LOGFILE.autoflush=1
 log4perl.appender.RATELIMITER_LOGFILE.layout=PatternLayout
 log4perl.appender.RATELIMITER_LOGFILE.layout.ConversionPattern=[%d] %F %L %c %S %m{chomp}%n
 
 log4perl.appender.REQUESTSTATS_LOGFILE=Log::Log4perl::Appender::File
 log4perl.appender.REQUESTSTATS_LOGFILE.filename=/srv/off/logs/requeststats_log4perl.log
 log4perl.appender.REQUESTSTATS_LOGFILE.mode=append
-log4perl.appender.REQUESTSTATS_LOGFILE.autoflush=0
+log4perl.appender.REQUESTSTATS_LOGFILE.autoflush=1
 log4perl.appender.REQUESTSTATS_LOGFILE.layout=PatternLayout
 log4perl.appender.REQUESTSTATS_LOGFILE.layout.ConversionPattern=%J %n
diff --git a/conf/off-minion_log.conf b/conf/off-minion_log.conf
@@ -5,6 +5,6 @@ log4perl.PatternLayout.cspec.S = sub { my $context = Log::Log4perl::MDC->get_con
 log4perl.appender.LOGFILE=Log::Log4perl::Appender::File
 log4perl.appender.LOGFILE.filename=/srv/off/logs/minion_log4perl.log
 log4perl.appender.LOGFILE.mode=append
-log4perl.appender.LOGFILE.autoflush=0
+log4perl.appender.LOGFILE.autoflush=1
 log4perl.appender.LOGFILE.layout=PatternLayout
 log4perl.appender.LOGFILE.layout.ConversionPattern=[%r] %F %L %c %S %m{chomp}%n
diff --git a/conf/off-pro-log.conf b/conf/off-pro-log.conf
@@ -5,6 +5,6 @@ log4perl.PatternLayout.cspec.S = sub { my $context = Log::Log4perl::MDC->get_con
 log4perl.appender.LOGFILE=Log::Log4perl::Appender::File
 log4perl.appender.LOGFILE.filename=/mnt/off-pro/logs/off-pro/log4perl.log
 log4perl.appender.LOGFILE.mode=append
-log4perl.appender.LOGFILE.autoflush=0
+log4perl.appender.LOGFILE.autoflush=1
 log4perl.appender.LOGFILE.layout=PatternLayout
 log4perl.appender.LOGFILE.layout.ConversionPattern=[%d] %F %L %c %S %m{chomp}%n
diff --git a/conf/off-pro-minion_log.conf b/conf/off-pro-minion_log.conf
@@ -5,6 +5,6 @@ log4perl.PatternLayout.cspec.S = sub { my $context = Log::Log4perl::MDC->get_con
 log4perl.appender.LOGFILE=Log::Log4perl::Appender::File
 log4perl.appender.LOGFILE.filename=/mnt/off-pro/logs/off-pro/minion_log4perl.log
 log4perl.appender.LOGFILE.mode=append
-log4perl.appender.LOGFILE.autoflush=0
+log4perl.appender.LOGFILE.autoflush=1
 log4perl.appender.LOGFILE.layout=PatternLayout
 log4perl.appender.LOGFILE.layout.ConversionPattern=[%r] %F %L %c %S %m{chomp}%n
diff --git a/lib/ProductOpener/Display.pm b/lib/ProductOpener/Display.pm
@@ -978,6 +978,8 @@ CSS
 		}
 	) if $log->is_debug();
 
+	set_request_stats_value($request_ref->{stats}, "cc", $request_ref->{cc});
+	set_request_stats_value($request_ref->{stats}, "lc", $request_ref->{lc});
 	set_request_stats_value($request_ref->{stats}, "hostname", $hostname);
 	set_request_stats_value($request_ref->{stats}, "original_query_string", $request_ref->{original_query_string});
 	set_request_stats_value($request_ref->{stats}, "ip", remote_addr());

diff --git a/lib/ProductOpener/RequestStats.pm b/lib/ProductOpener/RequestStats.pm
@@ -38,6 +38,8 @@ sub init_request_stats() {
 
 	my $stats_ref = {};
 	set_request_stats_time_start($stats_ref, "request");
+	set_request_stats_value($stats_ref, "request_t", time());
+	set_request_stats_value($stats_ref, "pid", $$);
 	return $stats_ref;
 }
 

diff --git a/lib/ProductOpener/Routing.pm b/lib/ProductOpener/Routing.pm
@@ -358,6 +358,8 @@ sub api_route($request_ref, @components) {
 
 	set_request_stats_value($request_ref->{stats}, "route", "api");
 	set_request_stats_value($request_ref->{stats}, "api_action", $request_ref->{api_action});
+	set_request_stats_value($request_ref->{stats}, "api_method", $request_ref->{api_method});
+	set_request_stats_value($request_ref->{stats}, "api_version", $request_ref->{api_version});
 
 	return 1;
 }