Logging errors in SamlauthEvents::USER_SYNC

Created on 8 November 2023, about 1 year ago

Problem/Motivation

I have implemented custom event subscription to SamlauthEvents::USER_SYNC as I need to do some custom checks and assignments before letting new user being created via saml login.

So in my callback I check two dates and If the dates are not equal, I want to log an error and then throw an exception and break the login and user creation.

But the log is not written to watchdog when the error is thrown.

Here's the code where the error should be logged and exception thrown

if ($event->isFirstLogin()) {
    if ($dateA != $dateB) {
      $this->logger->error('Denying SAML login. Date mismatch', []);
      throw new \RuntimeException('Could not complete user registration');
    }
}

When RuntimeException is thrown - does that somehow cancel the commit to db of the call to logger or what is going on ?

💬 Support request
Status

Active

Version

3.9

Component

Code

Created by

🇩🇰Denmark tbrix

Live updates comments and jobs are added and updated live.
Sign in to follow issues

Comments & Activities

  • Issue created by @tbrix
  • 🇳🇱Netherlands roderik Amsterdam,NL / Budapest,HU

    It would surprise me. The SamlauthEvents::USER_SYNC event is just dispatched in the middle of a long login procedure, which logs & throws exceptions for all over the place.

    So yes, your log should be logged. In fact the message in your RuntimeException should always get logged too.
    (The code is horrible to read because Drupal Core + Redirects == horrible side effects that need to be protected against... but... your exception should end up being passed to SamlController::handleExceptionInRenderContext(), which basically always should log the message.)

    So in short, I don't know what's going on there.

  • 🇳🇱Netherlands roderik Amsterdam,NL / Budapest,HU

    Oh, what I said isn't true. If you set the 'error_throw ' / "Bypass error handling'" config to TRUE, that method doesn't log.

    If that setting influences your message being logged, I'd like to know because then I need to do more testing / documenting.

  • 🇩🇰Denmark tbrix

    Thank you so much @rodrik for that quick response.

    If I check "Bypass error handling" the effect is that the RuntimeException is not logged. But no effect on the call to error log, whether its Bypassed or not. When unchecked the exception is logged, but not the logger error.

    No matter how, I cant seem to log en error in my callback with $this->logger->error, if I throw an exception afterwards.

  • 🇳🇱Netherlands roderik Amsterdam,NL / Budapest,HU

    OK, the effect on the RuntimeException is as expected, I guess.

    But this makes the weirdness more glaring. the RuntimeExcption message is logged, and that's just being done (in handleExceptionInRenderContext()) by some $this->logger->warning(), which should be completely equivalent to the log call you are doing. So why your earlier message is not logged just before that moment, is even more mysterious to me.

Production build 0.71.5 2024