Fix logging data context to file

It was only logged when an exception was provided or when using
logData (which is not being much used)

Only tested with file write logger, but shouldn't work differently.

Crash reporters always had the context.

Signed-off-by: Thomas Citharel <[email protected]>

lib/private/Log.php

@@ -15,6 +15,7 @@
  * @author Olivier Paroz <[email protected]>
  * @author Robin Appelman <[email protected]>
  * @author Roeland Jago Douma <[email protected]>
+ * @author Thomas Citharel <[email protected]>
  * @author Thomas Müller <[email protected]>
  * @author Victor Dubiniuk <[email protected]>
  *
@@ -211,7 +212,9 @@ public function log(int $level, string $message, array $context = []) {
 
 		try {
 			if ($level >= $minLevel) {
-				$this->writeLog($app, $message, $level);
+				$contextWithMessage = $context;
+				$contextWithMessage['message'] = $message;
+				$this->writeLog($app, $contextWithMessage, $level);
 
 				if ($this->crashReporters !== null) {
 					$messageContext = array_merge(

lib/private/Log/LogDetails.php

@@ -5,6 +5,7 @@
  * @author Arthur Schiwon <[email protected]>
  * @author Christoph Wurst <[email protected]>
  * @author Julius Härtl <[email protected]>
+ * @author Thomas Citharel <[email protected]>
  *
  * @license GNU AGPL version 3 or any later version
  *
@@ -90,8 +91,9 @@ public function logDetails(string $app, $message, int $level): array {
 				$entry['exception'] = $message;
 				$entry['message'] = $message['CustomMessage'] !== '--' ? $message['CustomMessage'] : $message['Message'];
 			} else {
-				$entry['data'] = $message;
 				$entry['message'] = $message['message'] ?? '(no message provided)';
+				unset($message['message']);
+				$entry['data'] = $message;
 			}
 		}
 

tests/lib/Log/FileTest.php

@@ -1,5 +1,7 @@
 <?php
 /**
+ *
+ * @author Thomas Citharel <[email protected]>
  *
  * This library is free software; you can redistribute it and/or
  * modify it under the terms of the GNU AFFERO GENERAL PUBLIC LICENSE
@@ -18,6 +20,7 @@
 namespace Test\Log;
 
 use OC\Log\File;
+use OCP\IConfig;
 use OCP\ILogger;
 use Test\TestCase;
 
@@ -36,7 +39,7 @@ protected function setUp(): void {
 		$config = \OC::$server->getSystemConfig();
 		$this->restore_logfile = $config->getValue("logfile");
 		$this->restore_logdateformat = $config->getValue('logdateformat');
-		
+
 		$config->setValue("logfile", $config->getValue('datadirectory') . "/logtest.log");
 		$this->logFile = new File($config->getValue('datadirectory') . '/logtest.log', '', $config);
 	}
@@ -55,7 +58,28 @@ protected function tearDown(): void {
 		$this->logFile = new File($this->restore_logfile, '', $config);
 		parent::tearDown();
 	}
-
+
+	public function testLogging() {
+		$config = \OC::$server->get(IConfig::class);
+		# delete old logfile
+		unlink($config->getSystemValue('logfile'));
+
+		# set format & write log line
+		$config->setSystemValue('logdateformat', 'u');
+		$this->logFile->write('code', ['something' => 'extra', 'message' => 'Testing logging'], ILogger::ERROR);
+
+		# read log line
+		$handle = @fopen($config->getSystemValue('logfile'), 'r');
+		$line = fread($handle, 1000);
+		fclose($handle);
+
+		# check log has data content
+		$values = (array) json_decode($line, true);
+		$this->assertArrayNotHasKey('message', $values['data']);
+		$this->assertEquals('extra', $values['data']['something']);
+		$this->assertEquals('Testing logging', $values['message']);
+	}
+
 	public function testMicrosecondsLogTimestamp() {
 		$config = \OC::$server->getConfig();
 		# delete old logfile
@@ -69,7 +93,7 @@ public function testMicrosecondsLogTimestamp() {
 		$handle = @fopen($config->getSystemValue('logfile'), 'r');
 		$line = fread($handle, 1000);
 		fclose($handle);
-		
+
 		# check timestamp has microseconds part
 		$values = (array) json_decode($line);
 		$microseconds = $values['time'];

tests/lib/Log/LogTest.php

@@ -0,0 +1,61 @@
+<?php
+/**
+ * @copyright Copyright (c) 2022 Thomas Citharel <[email protected]>
+ *
+ * @author Thomas Citharel <[email protected]>
+ *
+ * @license GNU AGPL version 3 or any later version
+ *
+ * This program is free software: you can redistribute it and/or modify
+ * it under the terms of the GNU Affero General Public License as
+ * published by the Free Software Foundation, either version 3 of the
+ * License, or (at your option) any later version.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+ * GNU Affero General Public License for more details.
+ *
+ * You should have received a copy of the GNU Affero General Public License
+ * along with this program.  If not, see <http://www.gnu.org/licenses/>.
+ *
+ */
+
+namespace Test\Log;
+
+use OC\Log;
+use OC\Log\File;
+use OC\Log\LogFactory;
+use OC\SystemConfig;
+use OCP\ILogger;
+use OCP\IServerContainer;
+use OCP\Log\IWriter;
+use PHPUnit\Framework\MockObject\MockObject;
+use Test\TestCase;
+
+/**
+ * Class LogFactoryTest
+ *
+ * @package Test\Log
+ */
+class LogTest extends TestCase {
+	/** @var IWriter|MockObject */
+	protected $writer;
+
+	/** @var SystemConfig|MockObject */
+	protected $systemConfig;
+
+	protected Log $logFile;
+
+	protected function setUp(): void {
+		parent::setUp();
+		$this->writer = $this->createMock(IWriter::class);
+		$this->systemConfig = $this->createMock(SystemConfig::class);
+		$this->logFile = new Log($this->writer, $this->systemConfig);
+	}
+
+	public function testLogging(): void {
+		$this->writer->expects($this->once())->method('write')->with('no app in context', ['something' => 'extra', 'message' => 'Testing logging']);
+		$this->logFile->error('Testing logging', ['something' => 'extra']);
+	}
+}