Conditional logging #15965

Merged
merged 2 commits into from May 19, 2015

Conversation

Projects
None yet
9 participants
@MorrisJobke
Member

MorrisJobke commented Apr 30, 2015

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 (setting log_condition in config.php):
- 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

  • requires #15958 (which is included here to easiely test this)

This would be really helpful to debug bigger installations where enabling a higher log level isn't a option because of the huge amount of log messages. cc @felixboehm @butonic

cc @nickvergessen @PVince81 @rullzer @Xenopathic @Raydiation @DeepDiver1975

@MorrisJobke

This comment has been minimized.

Show comment
Hide comment
@MorrisJobke

MorrisJobke Apr 30, 2015

Member
Member

MorrisJobke commented Apr 30, 2015

@MorrisJobke

This comment has been minimized.

Show comment
Hide comment
@MorrisJobke

MorrisJobke Apr 30, 2015

Member

I used the internal \OC\SystemConfig here to not run into cyclic conditions here. As this is the logger I want to reduce the needed bootstrapped system to a minimum. Otherwise it could be possible to no able to log, because the injected object couldn't be build. The system config was also required previously. And as this is an internal class I think this is not a problem. Opinions?

Member

MorrisJobke commented Apr 30, 2015

I used the internal \OC\SystemConfig here to not run into cyclic conditions here. As this is the logger I want to reduce the needed bootstrapped system to a minimum. Otherwise it could be possible to no able to log, because the injected object couldn't be build. The system config was also required previously. And as this is an internal class I think this is not a problem. Opinions?

@felixboehm

This comment has been minimized.

Show comment
Hide comment
@felixboehm

felixboehm Apr 30, 2015

Contributor

Awesome stuff, logfiles often are so big and this really helps

Contributor

felixboehm commented Apr 30, 2015

Awesome stuff, logfiles often are so big and this really helps

@karlitschek

This comment has been minimized.

Show comment
Hide comment
@karlitschek

karlitschek Apr 30, 2015

Member

nice idea 👍

Member

karlitschek commented Apr 30, 2015

nice idea 👍

@DeepDiver1975 DeepDiver1975 added this to the 8.1-current milestone May 4, 2015

@DeepDiver1975

This comment has been minimized.

Show comment
Hide comment
@DeepDiver1975

DeepDiver1975 May 4, 2015

Member

rebased after merge of #15958

Member

DeepDiver1975 commented May 4, 2015

rebased after merge of #15958

@DeepDiver1975

This comment has been minimized.

Show comment
Hide comment
@DeepDiver1975

DeepDiver1975 May 4, 2015

Member

@MorrisJobke unit tests are broken

Test\Logger::testInterpolation
Failed asserting that two arrays are equal.
--- Expected
+++ Actual
@@ @@
 Array (
-    0 => '1 {Message {nothing} Bob Bar a}'
 )

/var/jenkins/workspace/pull-request-analyser-ng-simple@3/label/SLAVE/tests/lib/logger.php:32
Member

DeepDiver1975 commented May 4, 2015

@MorrisJobke unit tests are broken

Test\Logger::testInterpolation
Failed asserting that two arrays are equal.
--- Expected
+++ Actual
@@ @@
 Array (
-    0 => '1 {Message {nothing} Bob Bar a}'
 )

/var/jenkins/workspace/pull-request-analyser-ng-simple@3/label/SLAVE/tests/lib/logger.php:32
@MorrisJobke

This comment has been minimized.

Show comment
Hide comment
@MorrisJobke

MorrisJobke May 4, 2015

Member

I added a unit test for the app condition.

Member

MorrisJobke commented May 4, 2015

I added a unit test for the app condition.

@MorrisJobke

This comment has been minimized.

Show comment
Hide comment
Member

MorrisJobke commented May 8, 2015

@LukasReschke

This comment has been minimized.

Show comment
Hide comment
@LukasReschke

LukasReschke May 8, 2015

Member

"want"

Member

LukasReschke commented May 8, 2015

"want"

config/config.sample.php
+ * debug specific requests, users or apps
+ *
+ * Supported conditions:
+ * - ``secret``: if a request parameter with the name `log_secret` is set to

This comment has been minimized.

@LukasReschke

LukasReschke May 8, 2015

Member

shared_secret?

@LukasReschke

LukasReschke May 8, 2015

Member

shared_secret?

config/config.sample.php
+ *
+ * Defaults to an empty array.
+ */
+'log_condition' => [

This comment has been minimized.

@LukasReschke

LukasReschke May 8, 2015

Member

I prefer something like log.condition 🙈

@LukasReschke

LukasReschke May 8, 2015

Member

I prefer something like log.condition 🙈

lib/private/log.php
+ */
+ if(!empty($logCondition)
+ && isset($logCondition['apps'])
+ && in_array($app, $logCondition['apps'])) {

This comment has been minimized.

@LukasReschke

LukasReschke May 8, 2015

Member

Always use the third strict parameter for in_array. Thanks.

@LukasReschke

LukasReschke May 8, 2015

Member

Always use the third strict parameter for in_array. Thanks.

lib/private/log.php
+ $request = \OC::$server->getRequest();
+
+ // if token is found in the request change set the log condition to satisfied
+ if($request && $request->getParam('log_secret') === $logCondition['secret']) {

This comment has been minimized.

@LukasReschke

LukasReschke May 8, 2015

Member

I'd prefer if we would use a header for something like this. Params seem rather error prone to me. \OCP\IRequest::getHeader

@LukasReschke

LukasReschke May 8, 2015

Member

I'd prefer if we would use a header for something like this. Params seem rather error prone to me. \OCP\IRequest::getHeader

This comment has been minimized.

@LukasReschke

LukasReschke May 8, 2015

Member

Also for security purposes to ensure a constant time comparison use \OC\Security\StringUtils::equals

@LukasReschke

LukasReschke May 8, 2015

Member

Also for security purposes to ensure a constant time comparison use \OC\Security\StringUtils::equals

This comment has been minimized.

@butonic

butonic May 8, 2015

Member

I would prefer if it was possible to combine app and user filers: only log file cache operations for user a.

Am 8. Mai 2015 13:58:49 MESZ, schrieb Lukas Reschke notifications@github.com:

  •    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['secret'])) {
    
  •                $request = \OC::$server->getRequest();
    
  •                // if token is found in the request change set the log
    
    condition to satisfied
  •                if($request && $request->getParam('log_secret') ===
    
    $logCondition['secret']) {

Also for security purposes to ensure a constant time comparison use
\OC\Security\StringUtils::equals


Reply to this email directly or view it on GitHub:
https://github.com/owncloud/core/pull/15965/files#r29933978

Diese Nachricht wurde von meinem Android-Mobiltelefon mit K-9 Mail gesendet.

@butonic

butonic May 8, 2015

Member

I would prefer if it was possible to combine app and user filers: only log file cache operations for user a.

Am 8. Mai 2015 13:58:49 MESZ, schrieb Lukas Reschke notifications@github.com:

  •    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['secret'])) {
    
  •                $request = \OC::$server->getRequest();
    
  •                // if token is found in the request change set the log
    
    condition to satisfied
  •                if($request && $request->getParam('log_secret') ===
    
    $logCondition['secret']) {

Also for security purposes to ensure a constant time comparison use
\OC\Security\StringUtils::equals


Reply to this email directly or view it on GitHub:
https://github.com/owncloud/core/pull/15965/files#r29933978

Diese Nachricht wurde von meinem Android-Mobiltelefon mit K-9 Mail gesendet.

This comment has been minimized.

@DeepDiver1975

DeepDiver1975 May 8, 2015

Member

I'd prefer if we would use a header for something like this. Params seem rather error prone to me. \OCP\IRequest::getHeader

I guess the idea is to append this parameter to any page load in the browser - not that easy if we use headers ....

@DeepDiver1975

DeepDiver1975 May 8, 2015

Member

I'd prefer if we would use a header for something like this. Params seem rather error prone to me. \OCP\IRequest::getHeader

I guess the idea is to append this parameter to any page load in the browser - not that easy if we use headers ....

This comment has been minimized.

@MorrisJobke

MorrisJobke May 8, 2015

Member

I would prefer if it was possible to combine app and user filers: only log file cache operations for user a.

We either decide on "AND" or "OR" ... otherwise it will get very complex.

@MorrisJobke

MorrisJobke May 8, 2015

Member

I would prefer if it was possible to combine app and user filers: only log file cache operations for user a.

We either decide on "AND" or "OR" ... otherwise it will get very complex.

This comment has been minimized.

@LukasReschke

LukasReschke May 8, 2015

Member

I guess the idea is to append this parameter to any page load in the browser - not that easy if we use headers ....

One shall use an interception proxy for this 🙈
2015-05-08_14-07-53

/me hides again ;-)

@LukasReschke

LukasReschke May 8, 2015

Member

I guess the idea is to append this parameter to any page load in the browser - not that easy if we use headers ....

One shall use an interception proxy for this 🙈
2015-05-08_14-07-53

/me hides again ;-)

lib/private/log.php
+ $user = \OC::$server->getUserSession()->getUser();
+
+ // if the user matches set the log condition to satisfied
+ if($user !== null && in_array($user->getUID(), $logCondition['users'])) {

This comment has been minimized.

@LukasReschke

LukasReschke May 8, 2015

Member

in_array always with strict parameter. Thanks :)

@LukasReschke

LukasReschke May 8, 2015

Member

in_array always with strict parameter. Thanks :)

+ $minLevel=min($config->getValue( "loglevel", OC_Log::WARN ), OC_Log::ERROR);
+ if($minLevel == OC_Log::DEBUG) {
+ $url = isset($_SERVER['REQUEST_URI']) ? $_SERVER['REQUEST_URI'] : '--';
+ $method = isset($_SERVER['REQUEST_METHOD']) ? $_SERVER['REQUEST_METHOD'] : '--';

This comment has been minimized.

@LukasReschke

LukasReschke May 8, 2015

Member

While already at it can we adjust this to the IRequest methods as well?

@LukasReschke

LukasReschke May 8, 2015

Member

While already at it can we adjust this to the IRequest methods as well?

This comment has been minimized.

@MorrisJobke

MorrisJobke May 8, 2015

Member

I just touched the intendation here. I would like to not touch the logic in here even more.

@MorrisJobke

MorrisJobke May 8, 2015

Member

I just touched the intendation here. I would like to not touch the logic in here even more.

This comment has been minimized.

@LukasReschke

LukasReschke May 8, 2015

Member

Lazy slacker! ;-)

@LukasReschke

LukasReschke May 8, 2015

Member

Lazy slacker! ;-)

Move log level check to logger parent class
* remove duplicate code from child classes
@MorrisJobke

This comment has been minimized.

Show comment
Hide comment
@MorrisJobke

MorrisJobke May 8, 2015

Member

Do we want to use a header or not?

Member

MorrisJobke commented May 8, 2015

Do we want to use a header or not?

@MorrisJobke

This comment has been minimized.

Show comment
Hide comment
@MorrisJobke

MorrisJobke May 8, 2015

Member

BTW: all the other comments are addressed.

Member

MorrisJobke commented May 8, 2015

BTW: all the other comments are addressed.

config/config.sample.php
+ * Defaults to an empty array.
+ */
+'log.condition' => [
+ 'secret' => '57b58edb6637fe3059b3595cf9c41b9',

This comment has been minimized.

@LukasReschke

LukasReschke May 8, 2015

Member

Erm? 🙈

@LukasReschke

LukasReschke May 8, 2015

Member

Erm? 🙈

This comment has been minimized.

@LukasReschke

LukasReschke May 8, 2015

Member

Now doc and content is not the same anymore 🙈

@LukasReschke

LukasReschke May 8, 2015

Member

Now doc and content is not the same anymore 🙈

This comment has been minimized.

@MorrisJobke

MorrisJobke May 8, 2015

Member

Oh ... forgot that one

@MorrisJobke

MorrisJobke May 8, 2015

Member

Oh ... forgot that one

Conditional logging
 * 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 (setting `log_condition` in `config.php`):
    - `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
 * fix unit test and add app log condition test
@scrutinizer-notifier

This comment has been minimized.

Show comment
Hide comment
@owncloud-bot

This comment has been minimized.

Show comment
Hide comment
@owncloud-bot

owncloud-bot May 18, 2015

Contributor

Refer to this link for build results (access rights to CI server needed):
https://ci.owncloud.org//job/pull-request-analyser-ng-simple/12374/
🚀 Test PASSed.🚀
chuck

Contributor

owncloud-bot commented May 18, 2015

Refer to this link for build results (access rights to CI server needed):
https://ci.owncloud.org//job/pull-request-analyser-ng-simple/12374/
🚀 Test PASSed.🚀
chuck

@MorrisJobke

This comment has been minimized.

Show comment
Hide comment
@rullzer

This comment has been minimized.

Show comment
Hide comment
@rullzer

rullzer May 19, 2015

Contributor

Working very nice!
I would like to see a header as well (maybe different PR, if it is to much work since this should get in). So debugging the OCS API etc becomes a bit easier.

As mentioned on IRC the call_user_func stuff makes me cry. But also that should be addressed in another PR.

👍 !

Contributor

rullzer commented May 19, 2015

Working very nice!
I would like to see a header as well (maybe different PR, if it is to much work since this should get in). So debugging the OCS API etc becomes a bit easier.

As mentioned on IRC the call_user_func stuff makes me cry. But also that should be addressed in another PR.

👍 !

@@ -39,10 +39,7 @@ public static function init() {
* @param int $level
*/
public static function write($app, $message, $level) {
- $minLevel = min(OC_Config::getValue("loglevel", OC_Log::WARN), OC_Log::ERROR);
- if ($level >= $minLevel) {

This comment has been minimized.

@DeepDiver1975

DeepDiver1975 May 19, 2015

Member

why was this removed? @MorrisJobke THX

@DeepDiver1975

DeepDiver1975 May 19, 2015

Member

why was this removed? @MorrisJobke THX

@DeepDiver1975

This comment has been minimized.

Show comment
Hide comment
Member

DeepDiver1975 commented May 19, 2015

👍

DeepDiver1975 added a commit that referenced this pull request May 19, 2015

@DeepDiver1975 DeepDiver1975 merged commit a52afb0 into master May 19, 2015

1 check passed

default Build finished.
Details

@DeepDiver1975 DeepDiver1975 deleted the conditional-logging branch May 19, 2015

mmattel added a commit to mmattel/core that referenced this pull request May 22, 2015

@butonic butonic referenced this pull request in owncloud/documentation Sep 6, 2016

Closed

[admin] document conditional logging #2608

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment