dev/core#1943 add functionality to add civicrm log into Drupal access log

[sunilpawar]

Overview

Currently We have Setting to log CiviCRM Error Log to Drupal Access Log, but functionality in code is not present.

Current behaviour

Code not present of Functionality present at /civicrm/admin/setting/debug?reset=1, Enable Drupal Watchdog Logging

Proposed behaviour

After changes, it will start logging into Drupal log if Enable Drupal Watchdog Logging is enabled

https://lab.civicrm.org/dev/core/-/issues/1943

[civibot]

(Standard links)

• If this is your first pull-request for CiviCRM, please browse CONTRIBUTING.md for information about the development and testing processes.
• If you are reviewing this pull-request, you may wish to consult the test sites and the Review Standards (long template, short template).

[demeritcowboy]

Thanks for the patch. This would always log with priority "debug". I think it should use the log function like \Drupal::logger('civicrm')->log($priority ?? \Drupal\Core\Logger\RfcLogLevel::DEBUG, '%message', ['%message' => $message])

The '%' part is just to make it the same as drupal 7. Could also be \Drupal::logger('civicrm')->log($priority ?? \Drupal\Core\Logger\RfcLogLevel::DEBUG, $message, []).

I see the note on line 585. I'm not sure what the situation it talks about is but I guess it means you can't put this in the UF class instead so yes it has to go here.

[sunilpawar]

thanks @demeritcowboy , updated patch..

[demeritcowboy]

• General standards
  • [r-explain] PASS
    • Minor note: It's not "access logs" which is something else in drupal but it's clear what it means later (/admin/reports/dblog).
  • [r-user] PASS
  • [r-doc] PASS
  • [r-run] PASS
    • Works like in drupal 7 now.
• Developer standards
  • [r-tech] PASS
    • As noted it would be better to put these in the UF classes but the comment on line 585 says that sometimes breaks.
    • Out of scope and I haven't tested or investigated but for calls that go through \Civi::log() instead of calling debug_log_message() directly, you shouldn't need this since you should be able to add any other PSR logger (e.g. drupal's logger) to the logging listeners via config.
  • [r-code] PASS
  • [r-maint] N/A
    • Difficult to write a test.
  • [r-test] Pending
    • Tests are still running.

[seamuslee001]

Thanks @demeritcowboy @sunilpawar

[totten]

@sunilpawar @demeritcowboy:

(1) Are y'all sure that the pass-thru of $priority is right here? The thing is that PSR-3 and PEAR have different constants for log-levels/log-priorities. (PSR-3 uses strings; PEAR uses ints.) Observe that:

• In CRM_Core_Error_Log, it uses an array-map to ensure that it gives a PEAR-style value.
• Line 568 above passes $priority into a PEAR logger... so it had better be a PEAR-style value.
• The docblock therefore seems wrong - ie $prioritity is numeric. (The docblock inLog_file::log() is also wrong... but if you drill-down to Log_file::log() => Log::_format() => Log::priorityToString(), it really does expect PEAR's numeric constants.)

I'm pretty sure this would need to reverse the mapping.

(2) There is a pre-existing issue (not the fault of this PR, but relevant to note) that the relationship between CRM_Core_Error_Log (Civi's PSR-3 stub) and CRM_Core_Error::debug_log_message() (Civi's PEAR wrapper) is bit off - IMHO, it's backwards. The relevance is that the current chain (CRM_Core_Error_Log => CRM_Core_Error => D8 Log) produces lossy a conversion. Without the structure of $message and $context, it'll be impossible to have something in the D8 realm to Nice Things (like pretty-printing, categorizing, translating). If the chain were setup better, then it wouldn't lose anything.

(Again, that's not the fault of this PR...)

[demeritcowboy]

It worked when I tested it with different errors. But you made me look and it turns out the DbLog class which is the implementation that ends up getting used doesn't use PSR levels, it uses RFC levels, which are ints. RfcLoggerTrait and DbLog. You know that saying about the great thing about standards...

[totten]

Aaaah, you're right. That's wild!

I guess it works because RfcLogLevels numerically match the PEAR levels. (Which makes sense - they're both following RFC-5424's numbers.)

I had some trouble believing that DbLog would break PSR-3 compliance by requiring ints. It turns out that we've got middle-man here: Drupal::logger() returns an instance of LoggerChannel, which has a normalization mechanism and accepts either the ints or the strings. Then it gives a normalized int to DbLog.