Add configurable log_level system setting (#9185)

* Add configurable log_level system setting

Minz_Log currently only distinguishes 'production' (errors and
warnings only) from any other environment (everything, including
debug messages), with no granularity in between.

Introduce an optional 'log_level' system setting (error, warning,
notice, info, or debug) that overrides the verbosity implied by
'environment'. It defaults to an empty string, which preserves the
exact current behaviour.

Fixes #7594

* Slight rewrite

---------

Co-authored-by: Alexandre Alapetite <alexandre@alapetite.fr>

config.default.php

@@ -9,6 +9,12 @@ return [
 	#	or to `production` to get only the most important messages.
 	'environment' => 'production',
 
+	# Minimum severity of the messages written to `./data/users/*/log.txt`, overriding the
+	#	verbosity implied by `environment` above. One of `error`, `warning`, `notice`, `info`, `debug`,
+	#	from the least to the most verbose. Leave empty (`''`) to keep the default behaviour:
+	#	`warning` (i.e. only errors and warnings) when `environment` is `production`, `debug` otherwise.
+	'log_level' => '',
+
 	# Used to make crypto more unique. Generated during install.
 	'salt' => '',
 

docs/en/admins/17_configs_not_ui.md

@@ -24,6 +24,14 @@ It does not have any effect for choosing the release channels.
 
 `'environment'` default value `'production'`
 
+#### System config: log_level
+
+Minimum severity of the messages written to the log files, overriding the verbosity implied by `environment` above.
+
+One of `'error'`, `'warning'`, `'notice'`, `'info'`, or `'debug'`, from the least to the most verbose.
+
+`'log_level'` default value `''` (empty), meaning: `'warning'` when `environment` is `'production'`, `'debug'` otherwise.
+
 #### System config: base_url
 
 This option is displayed in Administration -> System configuration, but is not editable there.

docs/en/admins/logs_and_errors.md

@@ -16,6 +16,10 @@ FreshRSS logs are located in:
 
 More logs can be generated by enabling `'environment' => 'development'` (default: `'production'`), in `./FreshRSS/data/config.php`
 
+For finer control, set `'log_level'` in the same file to one of `'error'`, `'warning'`, `'notice'`, `'info'`, or `'debug'`
+(from the least to the most verbose). It overrides the verbosity implied by `environment`,
+e.g. `'log_level' => 'notice'` keeps errors, warnings and notices while still discarding the more chatty `info`/`debug` messages.
+
 ## Error Message
 
 If there is an 'Application Problem' or 'Fatal Error', then a HTTP 500 error message is shown with more information.

lib/Minz/Configuration.php

@@ -9,6 +9,7 @@ declare(strict_types=1);
  * @property bool $disable_update
  * @property string $environment
  * @property array<string,bool> $extensions_enabled
+ * @property ''|'error'|'warning'|'notice'|'info'|'debug' $log_level
  * @property-read string $mailer
  * @property-read array{'hostname':string,'host':string,'auth':bool,'username':string,'password':string,
  *  'secure':string,'auto_tls':bool,'port':int,'from':string} $smtp

lib/Minz/Log.php

@@ -10,12 +10,25 @@ declare(strict_types=1);
  * The Minz_Log class is used to log errors and warnings
  */
 class Minz_Log {
+	/**
+	 * Syslog priority corresponding to each value accepted by the `log_level` system setting,
+	 * from the most to the least severe.
+	 * @var array<string,int>
+	 */
+	private const LOG_LEVELS = [
+		'error' => LOG_ERR,
+		'warning' => LOG_WARNING,
+		'notice' => LOG_NOTICE,
+		'info' => LOG_INFO,
+		'debug' => LOG_DEBUG,
+	];
+
 	/**
 	 * Enregistre un message dans un fichier de log spécifique
 	 * Message non loggué si
 	 * 	- environment = SILENT
-	 * 	- level = LOG_WARNING et environment = PRODUCTION
-	 * 	- level = LOG_NOTICE et environment = PRODUCTION
+	 * 	- level est moins sévère que le seuil déterminé par `log_level`,
+	 * 	  ou par défaut par `environment` (PRODUCTION ne garde que warning et error)
 	 * @param string $information message d'erreur / information à enregistrer
 	 * @param int $level niveau d'erreur https://www.php.net/function.syslog
 	 * @param string $file_name fichier de log
@@ -23,38 +36,37 @@ class Minz_Log {
 	 */
 	public static function record(string $information, int $level, ?string $file_name = null): void {
 		$env = getenv('FRESHRSS_ENV');
-		if ($env == '') {
-			try {
-				$conf = Minz_Configuration::get('system');
+		$log_level = '';
+		try {
+			$conf = Minz_Configuration::get('system');
+			$log_level = $conf->log_level;
+			if ($env == '') {
 				$env = $conf->environment;
-			} catch (Minz_ConfigurationException $e) {
+			}
+		} catch (Minz_ConfigurationException $e) {
+			if ($env == '') {
 				$env = 'production';
 			}
 		}
+		if ($log_level === '' || !isset(self::LOG_LEVELS[$log_level])) {
+			$log_level = match ($env) {
+				'silent' => 'error',
+				'production' => 'warning',
+				default => 'debug',
+			};
+		}
 
-		if (! ($env === 'silent' || ($env === 'production' && ($level >= LOG_NOTICE)))) {
+		if (! ($env === 'silent' || $level > self::LOG_LEVELS[$log_level])) {
 			$username = Minz_User::name() ?? Minz_User::INTERNAL_USER;
 			if ($file_name == null) {
 				$file_name = join_path(USERS_PATH, $username, LOG_FILENAME);
 			}
 
-			switch ($level) {
-				case LOG_ERR:
-					$level_label = 'error';
-					break;
-				case LOG_WARNING:
-					$level_label = 'warning';
-					break;
-				case LOG_NOTICE:
-					$level_label = 'notice';
-					break;
-				case LOG_DEBUG:
-					$level_label = 'debug';
-					break;
-				default:
-					$level = LOG_INFO;
-					$level_label = 'info';
+			$level_labels = array_flip(self::LOG_LEVELS);
+			if (!isset($level_labels[$level])) {
+				$level = LOG_INFO;
 			}
+			$level_label = $level_labels[$level];
 
 			$log = '[' . date('r') . '] [' . $level_label . '] --- ' . str_replace(["\r", "\n"], ' ', $information) . "\n";
 

tests/lib/Minz/LogTest.php

@@ -0,0 +1,102 @@
+<?php
+declare(strict_types=1);
+use PHPUnit\Framework\TestCase;
+
+class LogTest extends TestCase {
+	private string $logFile = '';
+
+	#[\Override]
+	protected function setUp(): void {
+		$this->logFile = self::createTempFile('freshrss-log-test-');
+		putenv('FRESHRSS_ENV=development');
+	}
+
+	#[\Override]
+	protected function tearDown(): void {
+		putenv('FRESHRSS_ENV');
+		@unlink($this->logFile);
+	}
+
+	private static function createTempFile(string $prefix): string {
+		$path = tempnam(sys_get_temp_dir(), $prefix);
+		if ($path === false) {
+			throw new RuntimeException('Could not create a temporary file for the test');
+		}
+		return $path;
+	}
+
+	/** @return list<string> */
+	private function loggedLines(): array {
+		$content = @file_get_contents($this->logFile);
+		return $content === false || $content === '' ? [] : explode("\n", rtrim($content, "\n"));
+	}
+
+	public function testDevelopmentEnvironmentLogsDebugMessages(): void {
+		Minz_Log::debug('some debug message', $this->logFile);
+
+		self::assertCount(1, $this->loggedLines());
+	}
+
+	public function testProductionEnvironmentDiscardsDebugAndNoticeMessages(): void {
+		putenv('FRESHRSS_ENV=production');
+
+		Minz_Log::debug('discarded', $this->logFile);
+		Minz_Log::notice('discarded too', $this->logFile);
+		Minz_Log::warning('kept', $this->logFile);
+		Minz_Log::error('kept too', $this->logFile);
+
+		$lines = $this->loggedLines();
+		self::assertCount(2, $lines);
+		self::assertStringContainsString('[warning]', $lines[0]);
+		self::assertStringContainsString('[error]', $lines[1]);
+	}
+
+	public function testSilentEnvironmentDiscardsEverything(): void {
+		putenv('FRESHRSS_ENV=silent');
+
+		Minz_Log::error('should not be written', $this->logFile);
+
+		self::assertSame([], $this->loggedLines());
+	}
+
+	public function testLogLevelOverridesEnvironmentVerbosity(): void {
+		$this->withSystemConf(['environment' => 'development', 'log_level' => 'notice'], function (): void {
+			Minz_Log::debug('discarded, too verbose for notice', $this->logFile);
+			Minz_Log::notice('kept, matches the threshold', $this->logFile);
+			Minz_Log::error('kept, more severe than the threshold', $this->logFile);
+		});
+
+		$lines = $this->loggedLines();
+		self::assertCount(2, $lines);
+		self::assertStringContainsString('[notice]', $lines[0]);
+		self::assertStringContainsString('[error]', $lines[1]);
+	}
+
+	public function testLogLevelCanRelaxProductionVerbosity(): void {
+		$this->withSystemConf(['environment' => 'production', 'log_level' => 'info'], function (): void {
+			Minz_Log::debug('discarded, more verbose than info', $this->logFile);
+			Minz_Log::record('kept, an info message', LOG_INFO, $this->logFile);
+		});
+
+		self::assertCount(1, $this->loggedLines());
+	}
+
+	/**
+	 * Temporarily registers a `system` configuration namespace so that `log_level` can be exercised,
+	 * then restores the previous state to avoid leaking configuration into other tests.
+	 * @param array<string,mixed> $overrides
+	 */
+	private function withSystemConf(array $overrides, callable $test): void {
+		putenv('FRESHRSS_ENV');	// Let Minz_Log fall back to the registered `system` configuration.
+
+		$configFile = self::createTempFile('freshrss-config-test-');
+		file_put_contents($configFile, '<?php return ' . var_export($overrides, true) . ';');
+
+		Minz_Configuration::register('system', $configFile, FRESHRSS_PATH . '/config.default.php');
+		try {
+			$test();
+		} finally {
+			@unlink($configFile);
+		}
+	}
+}