Merge pull request #15965 from owncloud/conditional-logging

Conditional logging
This commit is contained in:
Thomas Müller 2015-05-19 12:00:19 +02:00
commit a52afb040a
6 changed files with 156 additions and 50 deletions

View File

@ -486,6 +486,27 @@ $CONFIG = array(
*/ */
'loglevel' => 2, 'loglevel' => 2,
/**
* Log condition for log level increase based on conditions. Once one of these
* conditions is met, the required log level is set to debug. This allows to
* debug specific requests, users or apps
*
* Supported conditions:
* - ``shared_secret``: if a request parameter with the name `log_secret` is set to
* this value the condition is met
* - ``users``: if the current request is done by one of the specified users,
* this condition is met
* - ``apps``: if the log message is invoked by one of the specified apps,
* this condition is met
*
* Defaults to an empty array.
*/
'log.condition' => [
'shared_secret' => '57b58edb6637fe3059b3595cf9c41b9',
'users' => ['sample-user'],
'apps' => ['files'],
],
/** /**
* This uses PHP.date formatting; see http://php.net/manual/en/function.date.php * This uses PHP.date formatting; see http://php.net/manual/en/function.date.php
*/ */

View File

@ -28,6 +28,7 @@
namespace OC; namespace OC;
use \OCP\ILogger; use \OCP\ILogger;
use OCP\Security\StringUtils;
/** /**
* logging utilities * logging utilities
@ -41,15 +42,29 @@ use \OCP\ILogger;
class Log implements ILogger { class Log implements ILogger {
/** @var string */
private $logger; private $logger;
/** @var SystemConfig */
private $config;
/** @var boolean|null cache the result of the log condition check for the request */
private $logConditionSatisfied = null;
/** /**
* @param string $logger The logger that should be used * @param string $logger The logger that should be used
* @param SystemConfig $config the system config object
*/ */
public function __construct($logger=null) { public function __construct($logger=null, SystemConfig $config=null) {
// FIXME: Add this for backwards compatibility, should be fixed at some point probably
if($config === null) {
$config = \OC::$server->getSystemConfig();
}
$this->config = $config;
// FIXME: Add this for backwards compatibility, should be fixed at some point probably // FIXME: Add this for backwards compatibility, should be fixed at some point probably
if($logger === null) { if($logger === null) {
$this->logger = 'OC_Log_'.ucfirst(\OC_Config::getValue('log_type', 'owncloud')); $this->logger = 'OC_Log_'.ucfirst($this->config->getValue('log_type', 'owncloud'));
call_user_func(array($this->logger, 'init')); call_user_func(array($this->logger, 'init'));
} else { } else {
$this->logger = $logger; $this->logger = $logger;
@ -158,8 +173,22 @@ class Log implements ILogger {
* @param array $context * @param array $context
*/ */
public function log($level, $message, array $context = array()) { public function log($level, $message, array $context = array()) {
$minLevel = min($this->config->getValue('loglevel', \OC_Log::WARN), \OC_Log::ERROR);
$logCondition = $this->config->getValue('log.condition', []);
if (isset($context['app'])) { if (isset($context['app'])) {
$app = $context['app']; $app = $context['app'];
/**
* check log condition based on the context of each log message
* once this is met -> change the required log level to debug
*/
if(!empty($logCondition)
&& isset($logCondition['apps'])
&& in_array($app, $logCondition['apps'], true)) {
$minLevel = \OC_Log::DEBUG;
}
} else { } else {
$app = 'no app in context'; $app = 'no app in context';
} }
@ -172,7 +201,45 @@ class Log implements ILogger {
// interpolate replacement values into the message and return // interpolate replacement values into the message and return
$message = strtr($message, $replace); $message = strtr($message, $replace);
$logger = $this->logger; /**
call_user_func(array($logger, 'write'), $app, $message, $level); * check for a special log condition - this enables an increased log on
* a per request/user base
*/
if($this->logConditionSatisfied === null) {
// default to false to just process this once per request
$this->logConditionSatisfied = false;
if(!empty($logCondition)) {
// check for secret token in the request
if(isset($logCondition['shared_secret'])) {
$request = \OC::$server->getRequest();
// if token is found in the request change set the log condition to satisfied
if($request && StringUtils::equals($request->getParam('log_secret'), $logCondition['shared_secret'])) {
$this->logConditionSatisfied = true;
}
}
// check for user
if(isset($logCondition['users'])) {
$user = \OC::$server->getUserSession()->getUser();
// if the user matches set the log condition to satisfied
if($user !== null && in_array($user->getUID(), $logCondition['users'], true)) {
$this->logConditionSatisfied = true;
}
}
}
}
// if log condition is satisfied change the required log level to DEBUG
if($this->logConditionSatisfied) {
$minLevel = \OC_Log::DEBUG;
}
if ($level >= $minLevel) {
$logger = $this->logger;
call_user_func(array($logger, 'write'), $app, $message, $level);
}
} }
} }

View File

@ -39,10 +39,7 @@ class OC_Log_Errorlog {
* @param int $level * @param int $level
*/ */
public static function write($app, $message, $level) { public static function write($app, $message, $level) {
$minLevel = min(OC_Config::getValue("loglevel", OC_Log::WARN), OC_Log::ERROR); error_log('[owncloud]['.$app.']['.$level.'] '.$message);
if ($level >= $minLevel) {
error_log('[owncloud]['.$app.'] '.$message);
}
} }
} }

View File

@ -69,40 +69,40 @@ class OC_Log_Owncloud {
* @param int $level * @param int $level
*/ */
public static function write($app, $message, $level) { public static function write($app, $message, $level) {
$minLevel=min(OC_Config::getValue( "loglevel", OC_Log::WARN ), OC_Log::ERROR); $config = \OC::$server->getSystemConfig();
if($level>=$minLevel) {
// default to ISO8601 // default to ISO8601
$format = OC_Config::getValue('logdateformat', 'c'); $format = $config->getValue('logdateformat', 'c');
$logtimezone=OC_Config::getValue( "logtimezone", 'UTC' ); $logtimezone = $config->getValue( "logtimezone", 'UTC' );
try { try {
$timezone = new DateTimeZone($logtimezone); $timezone = new DateTimeZone($logtimezone);
} catch (Exception $e) { } catch (Exception $e) {
$timezone = new DateTimeZone('UTC'); $timezone = new DateTimeZone('UTC');
} }
$time = new DateTime(null, $timezone); $time = new DateTime(null, $timezone);
$request = \OC::$server->getRequest(); $request = \OC::$server->getRequest();
$reqId = $request->getId(); $reqId = $request->getId();
$remoteAddr = $request->getRemoteAddress(); $remoteAddr = $request->getRemoteAddress();
// remove username/passwords from URLs before writing the to the log file // remove username/passwords from URLs before writing the to the log file
$time = $time->format($format); $time = $time->format($format);
if($minLevel == OC_Log::DEBUG) { $minLevel=min($config->getValue( "loglevel", OC_Log::WARN ), OC_Log::ERROR);
$url = isset($_SERVER['REQUEST_URI']) ? $_SERVER['REQUEST_URI'] : '--'; if($minLevel == OC_Log::DEBUG) {
$method = isset($_SERVER['REQUEST_METHOD']) ? $_SERVER['REQUEST_METHOD'] : '--'; $url = isset($_SERVER['REQUEST_URI']) ? $_SERVER['REQUEST_URI'] : '--';
$entry = compact('reqId', 'remoteAddr', 'app', 'message', 'level', 'time', 'method', 'url'); $method = isset($_SERVER['REQUEST_METHOD']) ? $_SERVER['REQUEST_METHOD'] : '--';
} $entry = compact('reqId', 'remoteAddr', 'app', 'message', 'level', 'time', 'method', 'url');
else { }
$entry = compact('reqId', 'remoteAddr', 'app', 'message', 'level', 'time'); else {
} $entry = compact('reqId', 'remoteAddr', 'app', 'message', 'level', 'time');
$entry = json_encode($entry); }
$handle = @fopen(self::$logFile, 'a'); $entry = json_encode($entry);
@chmod(self::$logFile, 0640); $handle = @fopen(self::$logFile, 'a');
if ($handle) { @chmod(self::$logFile, 0640);
fwrite($handle, $entry."\n"); if ($handle) {
fclose($handle); fwrite($handle, $entry."\n");
} else { fclose($handle);
// Fall back to error_log } else {
error_log($entry); // Fall back to error_log
} error_log($entry);
} }
} }

View File

@ -47,10 +47,7 @@ class OC_Log_Syslog {
* @param int $level * @param int $level
*/ */
public static function write($app, $message, $level) { public static function write($app, $message, $level) {
$minLevel = min(OC_Config::getValue("loglevel", OC_Log::WARN), OC_Log::ERROR); $syslog_level = self::$levels[$level];
if ($level >= $minLevel) { syslog($syslog_level, '{'.$app.'} '.$message);
$syslog_level = self::$levels[$level];
syslog($syslog_level, '{'.$app.'} '.$message);
}
} }
} }

View File

@ -21,14 +21,38 @@ class Logger extends TestCase {
parent::setUp(); parent::setUp();
self::$logs = array(); self::$logs = array();
$this->logger = new Log('Test\Logger'); $this->config = $this->getMockBuilder(
'\OC\SystemConfig')
->disableOriginalConstructor()
->getMock();
$this->logger = new Log('Test\Logger', $this->config);
} }
public function testInterpolation() { public function testInterpolation() {
$logger = $this->logger; $logger = $this->logger;
$logger->info('{Message {nothing} {user} {foo.bar} a}', array('user' => 'Bob', 'foo.bar' => 'Bar')); $logger->warning('{Message {nothing} {user} {foo.bar} a}', array('user' => 'Bob', 'foo.bar' => 'Bar'));
$expected = array('1 {Message {nothing} Bob Bar a}'); $expected = array('2 {Message {nothing} Bob Bar a}');
$this->assertEquals($expected, $this->getLogs());
}
public function testAppCondition() {
$this->config->expects($this->any())
->method('getValue')
->will(($this->returnValueMap([
['loglevel', \OC_Log::WARN, \OC_Log::WARN],
['log.condition', [], ['apps' => ['files']]]
])));
$logger = $this->logger;
$logger->info('Don\'t display info messages');
$logger->info('Show info messages of files app', ['app' => 'files']);
$logger->warning('Show warning messages of other apps');
$expected = [
'1 Show info messages of files app',
'2 Show warning messages of other apps',
];
$this->assertEquals($expected, $this->getLogs()); $this->assertEquals($expected, $this->getLogs());
} }