watchdog() (in includes/bootstrap.inc, not watchdog.module since we no longer have such a module) should be able to avoid invoking hook_watchdog() implementations when the level of the event is lower than a system-defined logging level, i.e. with a WATCHDOG_* constant higher than this level, due to the actual values of these constants.

This would reduce some long-standing performance issues with useless logging. Without going into per-source or per-implementation settings, and without defining a UI, it could be made 100% compatible with the current situation while still fixing this bug:

- define a watchdog_minimum_level variable in settings.php, defaulting to WATCHDOG_DEBUG to keep all events by default
- only invoke the hook for events above that level

That way existing code would not be affected, but sites with watchdog chatter issues could reduce the "noise" and increase performance.

CommentFileSizeAuthor
#21 0001-Issue-1268636-by-fgm-Ignore-watchdog-calls-below-the.patch5.76 KBfgm
#19 watchdog_reporting_level-1268636-19.patch7.7 KBfgm
#19 interdiff.txt1.85 KBfgm
#16 0001-Issue-1268636-by-fgm-Ignore-watchdog-calls-below-the.patch8.91 KBfgm
#14 0001-Issue-1268636-by-fgm-Ignore-watchdog-calls-below-the.patch8.93 KBfgm
#13 0001-Issue-1268636-by-fgm-Ignore-watchdog-calls-below-the.patch9.11 KBfgm
#12 0001-Issue-1268636-by-fgm-Ignore-watchdog-calls-below-the.patch9.11 KBfgm
#9 0001-Issue-1268636-by-fgm-Ignore-watchdog-calls-below-the.patch7.42 KBfgm
#7 0001-Issue-1268636-by-fgm-Ignore-watchdog-calls-below-the.patch6.55 KBfgm
#3 watchdog_limit-1268636-4.patch5.73 KBfgm
#1 watchdog_limit-1268636-1.patch2 KBfgm
Support from Acquia helps fund testing for Drupal Acquia logo

Comments

fgm’s picture

fgm
Primary language French
Location Paris, France
CreditAttribution: fgm commented
Status: Active » Needs review
FileSize
watchdog_limit-1268636-1.patch2 KB

Patch fixes this.

The test for the severity level is not at the first line as could be expected, to prevent errors in variable_get() from occurring outside the loop detection.

Damien Tournoud’s picture

Damien Tournoud CreditAttribution: Damien Tournoud commented
Version: 7.x-dev » 8.x-dev
Component: watchdog.module » base system
Category: bug » feature
Issue tags: +Needs tests, +Needs backport to D7

I can see this being useful, but there is no bug to fix in there :)

If we could add a test to it (by extending the existing DBLog tests), I can see this getting in, and eventually backported.

fgm’s picture

fgm
Primary language French
Location Paris, France
CreditAttribution: fgm commented
FileSize
watchdog_limit-1268636-4.patch5.73 KB

Rerolled for d8 with a dblog-independent test.

fgm’s picture

fgm
Primary language French
Location Paris, France
CreditAttribution: fgm commented

Also consider that RFC 3164 §1.1 third paragraph implies that some way to configure such reporting is indeed required

Devices MUST be configured with rules for displaying and/or forwarding the event messages.

Since which we do not currently really honor this, it is a RFC-compliance bug, IMHO.

sun’s picture

sun
Primary language German
Location Karlsruhe
CreditAttribution: sun commented

IMHO, this is application-level logic.

Since that may sound ambiguous: In this case, dblog.module is one of the possible logging applications. So if dblog is too slow or whatever to cope with these messages, then it should expose such a configuration option.

Compared to that, I'm pretty sure that you can inject a watchdog() call into every single function that Drupal invokes, and while only having syslog.module enabled, you won't see a measurable difference in performance. (at the very least, that's how syslog is supposed to work...)

fgm’s picture

fgm
Primary language French
Location Paris, France
CreditAttribution: fgm commented

Obviously any watchdog implementation can, and probably should, filter ; and some, like syslog on a properly setup configuration, will not add excessive load to a system.

However, this still means a round of module_iimplements()/module_invoke() within core, plus the extra pre-filtering logic in any implementation, in addition to the likely variability in implementations of filtering by all such modules, while bringing the feature to core can both :

- "cut the flow" higher up and avoid running this code,
- offer a unified way of filtering based on an existing standard we already chose to apply - for better or worse - when RFC3164 was chosen for the Drupal 4.6 watchdog severity levels.

fgm’s picture

fgm
Primary language French
Location Paris, France
CreditAttribution: fgm commented
FileSize
0001-Issue-1268636-by-fgm-Ignore-watchdog-calls-below-the.patch6.55 KB

Rerolled against today's dev version.

fgm’s picture

fgm
Primary language French
Location Paris, France
CreditAttribution: fgm commented
Status: Needs review » Needs work

Should use config now that it's landed, not variables.

fgm’s picture

fgm
Primary language French
Location Paris, France
CreditAttribution: fgm commented
Status: Needs work » Needs review
FileSize
0001-Issue-1268636-by-fgm-Ignore-watchdog-calls-below-the.patch7.42 KB

Rerolled to use config, and added UI on logging settings.

Lars Toomre’s picture

Lars Toomre CreditAttribution: Lars Toomre commented
Status: Needs review » Needs work 
+++ b/core/includes/bootstrap.incundefined
@@ -1592,6 +1593,10 @@ function watchdog($type, $message, $variables = array(), $severity = WATCHDOG_NO
   if (!$in_error_state && function_exists('module_implements')) {
+    if ($severity > variable_get('watchdog_limit', WATCHDOG_DEBUG)) {
+      return;
+    }

Shouldn't this also be converted to use new config system?

fgm’s picture

fgm
Primary language French
Location Paris, France
CreditAttribution: fgm commented

Indeed. And this also needs

  • to be changed in core/modules/system/system.test
  • to include the default value in core/modules/system/config/system.logging.xml
fgm’s picture

fgm
Primary language French
Location Paris, France
CreditAttribution: fgm commented
FileSize
0001-Issue-1268636-by-fgm-Ignore-watchdog-calls-below-the.patch9.11 KB

Rerolled accordingly. test module is still using a variable for its state information, but the config info is now using config.

fgm’s picture

fgm
Primary language French
Location Paris, France
CreditAttribution: fgm commented
Status: Needs work » Needs review
FileSize
0001-Issue-1268636-by-fgm-Ignore-watchdog-calls-below-the.patch9.11 KB

Rerolled accordingly. test module is still using a variable for its state information, but the config info is now using config.

fgm’s picture

fgm
Primary language French
Location Paris, France
CreditAttribution: fgm commented
FileSize
0001-Issue-1268636-by-fgm-Ignore-watchdog-calls-below-the.patch8.93 KB

No idea why default.settings.php is set to 0755 in core, but this patch should not be touching it.

Lars Toomre’s picture

Lars Toomre CreditAttribution: Lars Toomre commented
Status: Needs review » Needs work 
+++ b/core/modules/system/system.admin.incundefined
@@ -1631,14 +1631,41 @@ function system_logging_settings() {
+    '#default_value' => $config->get('watchdog_limit') ?: WATCHDOG_DEBUG,

This looks like you are missing something...

+++ b/core/modules/system/system.testundefined
@@ -2903,3 +2903,107 @@ class SystemIndexPhpTest extends DrupalWebTestCase {
+  /**
+   * watchdog_test_watchdog() stores is state in a variable.

Should be 'its' instead of 'is'.

+++ b/core/modules/system/system.testundefined
@@ -2903,3 +2903,107 @@ class SystemIndexPhpTest extends DrupalWebTestCase {
+  /**
+   * Test the default and non-default behaviours

Should be 'behaviors.' (American english and a period). There is another patch that recently corrected the spelling of behavior throughout core.

fgm’s picture

fgm
Primary language French
Location Paris, France
CreditAttribution: fgm commented
Status: Needs work » Needs review
FileSize
0001-Issue-1268636-by-fgm-Ignore-watchdog-calls-below-the.patch8.91 KB

Good catches. I thought I had fixed them all.

Status: Needs review » Needs work
Issue tags: -Performance, -Needs tests, -Needs backport to D7

The last submitted patch, 0001-Issue-1268636-by-fgm-Ignore-watchdog-calls-below-the.patch, failed testing.

fgm’s picture

fgm
Primary language French
Location Paris, France
CreditAttribution: fgm commented
Status: Needs work » Needs review
Issue tags: +Performance, +Needs tests, +Needs backport to D7

#16: 0001-Issue-1268636-by-fgm-Ignore-watchdog-calls-below-the.patch queued for re-testing.

fgm’s picture

fgm
Primary language French
Location Paris, France
CreditAttribution: fgm commented
FileSize
interdiff.txt1.85 KB
watchdog_reporting_level-1268636-19.patch7.7 KB

Minor changes:
- moved comment about WATCHDOG_DEBUG to config file, not settings form
- added missing EOF new line
- do not include a final dot removal in a @see in system_performance_settings() which is outside the scope of the patch.

nod_’s picture

nod_
Primary language French
Location Lille
CreditAttribution: nod_ commented
Status: Needs review » Needs work

not XML anymore :p

fgm’s picture

fgm
Primary language French
Location Paris, France
CreditAttribution: fgm commented
Status: Needs work » Needs review
FileSize
0001-Issue-1268636-by-fgm-Ignore-watchdog-calls-below-the.patch5.76 KB

Rerolled for the new config format.

ZenDoodles’s picture

ZenDoodles CreditAttribution: ZenDoodles commented
Status: Needs review » Needs work

I've reviewed this twice now. Unfortunately due to stupidity far exceeding even *my* norms, those reviews have not actually been posted. I'm sorry I don't have time to do over it again.

The short version:

  1. This is a feature request. Backporting to D7 seems dubious.
  2. I'd like to see sun's comment addressed.
  3. Beware premature optimization. Is there data to support that this really is an issue (in core)?
  4. The comments and description strings need work. I had suggestions. They are gone.
  5. There is a new test module here, but there are no tests. (Also, I think we already have hook_watchdog in a watchdog test module).

Okay, 2 and 3 are either closely related or the same. On the other hand, I think you might be able to make a case for this as a feature w/o performance as the primary argument.

Also, any thoughts on a follow-up issue for making watchdog level a bitmask like php error levels?

ZenDoodles’s picture

ZenDoodles CreditAttribution: ZenDoodles commented
Status: Needs work » Needs review
Issue tags: -Needs backport to D7 +API change

Also, this impacts hook_watchdog() and should be documented as such.

ZenDoodles’s picture

ZenDoodles CreditAttribution: ZenDoodles commented
Status: Needs review » Needs work

Bah

fgm’s picture

fgm
Primary language French
Location Paris, France
CreditAttribution: fgm commented

I'll answer in more detail when I can, but for now, performance is indeed the primary motivation for this, based on actual sites in production. DBLog is a known source of DB load, and many not-so-large sites do not want to deploy tools around syslog, or mongodb_watchdog/redis_watchdog, so such a setting provides them with an easy way to keep using DBLog and its built-in reports, while still not suffering too much load from it.

This type of problem may not be adequately by performance tests on a normal core distribution because most of the issues making this a necessity arise because of poorly developed contrib or, worse, custom modules and themes, which cause far more watchdog entries than core ever will. But if others used to working on site load can chime in, I am pretty sure they will confirm having observed this.

Version: 8.0.x-dev » 8.1.x-dev

Drupal 8.0.6 was released on April 6 and is the final bugfix release for the Drupal 8.0.x series. Drupal 8.0.x will not receive any further development aside from security fixes. Drupal 8.1.0-rc1 is now available and sites should prepare to update to 8.1.0.

Bug reports should be targeted against the 8.1.x-dev branch from now on, and new development or disruptive changes should be targeted against the 8.2.x-dev branch. For more information see the Drupal 8 minor version schedule and the Allowed changes during the Drupal 8 release cycle.

fgm’s picture

fgm
Primary language French
Location Paris, France
CreditAttribution: fgm at OSInet commented
Version: 8.1.x-dev » 8.2.x-dev
Issue summary: View changes

Bumping to current version.

MongoDB now implements it on its own in mongodb_watchdog 8.x-2.x, but I maintain we should have a standard way to do this in core.

ndobromirov’s picture

ndobromirov CreditAttribution: ndobromirov commented

+1 on #27.

Version: 8.2.x-dev » 8.3.x-dev

Drupal 8.2.0-beta1 was released on August 3, 2016, which means new developments and disruptive changes should now be targeted against the 8.3.x-dev branch. For more information see the Drupal 8 minor version schedule and the Allowed changes during the Drupal 8 release cycle.

Version: 8.3.x-dev » 8.4.x-dev

Drupal 8.3.0-alpha1 will be released the week of January 30, 2017, which means new developments and disruptive changes should now be targeted against the 8.4.x-dev branch. For more information see the Drupal 8 minor version schedule and the Allowed changes during the Drupal 8 release cycle.

Version: 8.4.x-dev » 8.5.x-dev

Drupal 8.4.0-alpha1 will be released the week of July 31, 2017, which means new developments and disruptive changes should now be targeted against the 8.5.x-dev branch. For more information see the Drupal 8 minor version schedule and the Allowed changes during the Drupal 8 release cycle.

Version: 8.5.x-dev » 8.6.x-dev

Drupal 8.5.0-alpha1 will be released the week of January 17, 2018, which means new developments and disruptive changes should now be targeted against the 8.6.x-dev branch. For more information see the Drupal 8 minor version schedule and the Allowed changes during the Drupal 8 release cycle.

mxr576’s picture

mxr576
Primary language Hungarian
Location Hungary
CreditAttribution: mxr576 at Pronovix commented

+1 It would be really great to see something like this in the core.

Version: 8.6.x-dev » 8.7.x-dev

Drupal 8.6.0-alpha1 will be released the week of July 16, 2018, which means new developments and disruptive changes should now be targeted against the 8.7.x-dev branch. For more information see the Drupal 8 minor version schedule and the Allowed changes during the Drupal 8 release cycle.

fgm’s picture

fgm
Primary language French
Location Paris, France
CreditAttribution: fgm at OSInet commented
Related issues: +#1408208: Enable users to determine which types of log messages get written to dblog/syslog. Right now it's all or nothing.

@mxr576 this appears to be in the process of being addressed in #1408208: Enable users to determine which types of log messages get written to dblog/syslog. Right now it's all or nothing..

Loparev’s picture

Loparev CreditAttribution: Loparev commented

Let's review the patch from the Enable users to determine which types of log messages get written to dblog/syslog. Right now it's all or nothing?

Version: 8.7.x-dev » 8.8.x-dev

Drupal 8.7.0-alpha1 will be released the week of March 11, 2019, which means new developments and disruptive changes should now be targeted against the 8.8.x-dev branch. For more information see the Drupal 8 minor version schedule and the Allowed changes during the Drupal 8 release cycle.

Version: 8.8.x-dev » 8.9.x-dev

Drupal 8.8.0-alpha1 will be released the week of October 14th, 2019, which means new developments and disruptive changes should now be targeted against the 8.9.x-dev branch. (Any changes to 8.9.x will also be committed to 9.0.x in preparation for Drupal 9’s release, but some changes like significant feature additions will be deferred to 9.1.x.). For more information see the Drupal 8 and 9 minor version schedule and the Allowed changes during the Drupal 8 and 9 release cycles.

Version: 8.9.x-dev » 9.1.x-dev

Drupal 8.9.0-beta1 was released on March 20, 2020. 8.9.x is the final, long-term support (LTS) minor release of Drupal 8, which means new developments and disruptive changes should now be targeted against the 9.1.x-dev branch. For more information see the Drupal 8 and 9 minor version schedule and the Allowed changes during the Drupal 8 and 9 release cycles.

Version: 9.1.x-dev » 9.2.x-dev

Drupal 9.1.0-alpha1 will be released the week of October 19, 2020, which means new developments and disruptive changes should now be targeted for the 9.2.x-dev branch. For more information see the Drupal 9 minor version schedule and the Allowed changes during the Drupal 9 release cycle.

Version: 9.2.x-dev » 9.3.x-dev

Drupal 9.2.0-alpha1 will be released the week of May 3, 2021, which means new developments and disruptive changes should now be targeted for the 9.3.x-dev branch. For more information see the Drupal core minor version schedule and the Allowed changes during the Drupal core release cycle.

Version: 9.3.x-dev » 9.4.x-dev

Drupal 9.3.0-rc1 was released on November 26, 2021, which means new developments and disruptive changes should now be targeted for the 9.4.x-dev branch. For more information see the Drupal core minor version schedule and the Allowed changes during the Drupal core release cycle.

Version: 9.4.x-dev » 9.5.x-dev

Drupal 9.4.0-alpha1 was released on May 6, 2022, which means new developments and disruptive changes should now be targeted for the 9.5.x-dev branch. For more information see the Drupal core minor version schedule and the Allowed changes during the Drupal core release cycle.

Version: 9.5.x-dev » 10.1.x-dev

Drupal 9.5.0-beta2 and Drupal 10.0.0-beta2 were released on September 29, 2022, which means new developments and disruptive changes should now be targeted for the 10.1.x-dev branch. For more information see the Drupal core minor version schedule and the Allowed changes during the Drupal core release cycle.

Version: 10.1.x-dev » 11.x-dev

Drupal core is moving towards using a “main” branch. As an interim step, a new 11.x branch has been opened, as Drupal.org infrastructure cannot currently fully support a branch named main. New developments and disruptive changes should now be targeted for the 11.x branch, which currently accepts only minor-version allowed changes. For more information, see the Drupal core minor version schedule and the Allowed changes during the Drupal core release cycle.