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.
Comments
Comment #1
fgmPatch 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.
Comment #2
Damien Tournoud CreditAttribution: Damien Tournoud commentedI 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.
Comment #3
fgmRerolled for d8 with a dblog-independent test.
Comment #4
fgmAlso consider that RFC 3164 §1.1 third paragraph implies that some way to configure such reporting is indeed required
Since which we do not currently really honor this, it is a RFC-compliance bug, IMHO.
Comment #5
sunIMHO, 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...)
Comment #6
fgmObviously 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.
Comment #7
fgmRerolled against today's dev version.
Comment #8
fgmShould use config now that it's landed, not variables.
Comment #9
fgmRerolled to use config, and added UI on logging settings.
Comment #10
Lars Toomre CreditAttribution: Lars Toomre commentedShouldn't this also be converted to use new config system?
Comment #11
fgmIndeed. And this also needs
Comment #12
fgmRerolled accordingly. test module is still using a variable for its state information, but the config info is now using config.
Comment #13
fgmRerolled accordingly. test module is still using a variable for its state information, but the config info is now using config.
Comment #14
fgmNo idea why default.settings.php is set to 0755 in core, but this patch should not be touching it.
Comment #15
Lars Toomre CreditAttribution: Lars Toomre commentedThis looks like you are missing something...
Should be 'its' instead of 'is'.
Should be 'behaviors.' (American english and a period). There is another patch that recently corrected the spelling of behavior throughout core.
Comment #16
fgmGood catches. I thought I had fixed them all.
Comment #18
fgm#16: 0001-Issue-1268636-by-fgm-Ignore-watchdog-calls-below-the.patch queued for re-testing.
Comment #19
fgmMinor 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.
Comment #20
nod_not XML anymore :p
Comment #21
fgmRerolled for the new config format.
Comment #22
ZenDoodles CreditAttribution: ZenDoodles commentedI'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:
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?
Comment #23
ZenDoodles CreditAttribution: ZenDoodles commentedAlso, this impacts hook_watchdog() and should be documented as such.
Comment #24
ZenDoodles CreditAttribution: ZenDoodles commentedBah
Comment #25
fgmI'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.
Comment #27
fgmBumping 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.
Comment #28
ndobromirov CreditAttribution: ndobromirov commented+1 on #27.
Comment #33
mxr576+1 It would be really great to see something like this in the core.
Comment #35
fgm@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..
Comment #36
Loparev CreditAttribution: Loparev commentedLet'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?