Skip to content

Improve logging when handling users and institutions #236

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
phavekes wants to merge 2 commits into
base: main
Choose a base branch
from
Open

Improve logging when handling users and institutions #236

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
c5a3049
Improve logging when handling users and institutions
phavekes Apr 16, 2026
0029638
Make service function less complex
kayjoosten Apr 17, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 2 additions & 0 deletions .gitignore
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -87,3 +87,5 @@ local-php-security-checker
###> phpstan/phpstan ###
phpstan.neon
###< phpstan/phpstan ###

.phplint.cache/
107 changes: 68 additions & 39 deletions src/Surfnet/AzureMfa/Application/Service/AzureMfaService.php
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -24,6 +24,8 @@
use Surfnet\AzureMfa\Application\Exception\InvalidMfaAuthenticationContextException;
use Surfnet\AzureMfa\Application\Institution\Service\EmailDomainMatchingService;
use Surfnet\AzureMfa\Domain\EmailAddress;
use Surfnet\AzureMfa\Domain\Institution\ValueObject\IdentityProviderInterface;
use Surfnet\AzureMfa\Domain\Institution\ValueObject\Institution;
use Surfnet\AzureMfa\Domain\Exception\AzureADException;
use Surfnet\AzureMfa\Domain\Exception\InstitutionNotFoundException;
use Surfnet\AzureMfa\Domain\Exception\MailAttributeMismatchException;
Expand All @@ -33,6 +35,7 @@
use Surfnet\AzureMfa\Domain\UserStatus;
use Surfnet\AzureMfa\Infrastructure\Cache\IdentityProviderFactoryCache;
use Surfnet\SamlBundle\Entity\ServiceProvider;
use SAML2\Assertion;
use Surfnet\SamlBundle\Http\PostBinding;
use Surfnet\SamlBundle\SAML2\AuthnRequestFactory;
use Symfony\Component\HttpFoundation\Request;
Expand Down Expand Up @@ -64,7 +67,7 @@ public function __construct(
public function startRegistration(EmailAddress $emailAddress): User
{
// TODO: test attempts / blocked
$this->logger->info('Generating a new UserId based on the user email address');
$this->logger->info('Generating a new UserId based on the user email address '.$emailAddress->getEmailAddress());
$userId = UserId::generate($emailAddress);
$user = new User($userId, $emailAddress, UserStatus::pending());

Expand All @@ -76,55 +79,55 @@ public function startRegistration(EmailAddress $emailAddress): User

public function finishRegistration(UserId $userId): UserId
{
$this->logger->info('Finishing the registration');
$this->logger->info('Finishing the registration for userId '.$userId->getUserId());
/** @var User $user */
$user = $this->session->get('user');

if (!$userId->isEqual($user->getUserId())) {
throw new InvalidMfaAuthenticationContextException(
'Unknown registration context another process is started in the meantime'
'Unknown registration context another process is started in the meantime for userId '. $userId->getUserId()
);
}
$this->logger->info('Updating user session: removing');
$this->logger->info('removing user session for '.$userId->getUserId());
$this->session->remove('user');

return $userId;
}

public function startAuthentication(UserId $userId): User
{
$this->logger->info('Starting an authentication based on the provided UserId');
$this->logger->info('Starting an authentication based on the provided UserId:'.$userId->getUserId());
$user = new User($userId, $userId->getEmailAddress(), UserStatus::registered());

$this->logger->info('Updating user session: status registered');
$this->logger->info('Updating user session: status registered for userId:'.$userId->getUserId());
$this->session->set('user', $user);

return $user;
}

public function finishAuthentication(UserId $userId): UserId
{
$this->logger->info('Finishing the authentication');
$this->logger->info('Finishing the authenticationfor userId: '.$userId->getUserId());
/** @var User $user */
$user = $this->session->get('user');

if (!$userId->isEqual($user->getUserId())) {
throw new InvalidMfaAuthenticationContextException(
'Unknown authentication context another process is started in the meantime'
'Unknown authentication context another process is started in the meantime for userId:'.$userId->getUserId()
);
}

$this->logger->info('Updating user session: removing');
$this->logger->info('Removing user session for '.$userId->getUserId());
$this->session->remove('user');

return $userId;
}

public function createAuthnRequest(User $user, bool $forceAuthn = false): string
{
$this->logger->info('Creating a SAML2 AuthnRequest to send to the Azure MFA IdP');
$this->logger->info('Creating a SAML2 AuthnRequest to send to the Azure MFA IdP for user:'.$user->getEmailAddress()->getEmailAddress());

$this->logger->info('Retrieve the institution for the authenticating/registering user');
$this->logger->info('Retrieve the institution for the authenticating/registering user: '.$user->getEmailAddress()->getEmailAddress());
$institution = $this->matchingService->findInstitutionByEmail($user->getEmailAddress());
if (null === $institution) {
$message = sprintf(
Expand All @@ -146,13 +149,13 @@ public function createAuthnRequest(User $user, bool $forceAuthn = false): string

// Use email address as subject if not sending to an AzureAD IdP
if (!$azureMfaIdentityProvider->isAzureAD()) {
$this->logger->info('Setting the users email address as the Subject');
$this->logger->info('Setting the users email address '.$user->getEmailAddress()->getEmailAddress().' as the Subject for the request to '.$azureMfaIdentityProvider->getEntityId());
$authnRequest->setSubject($user->getEmailAddress()->getEmailAddress());
}

// Set authnContextClassRef to force MFA
$this->logger->info(
'Setting "http://schemas.microsoft.com/claims/multipleauthn" as the authentication context class reference'
'Setting "http://schemas.microsoft.com/claims/multipleauthn" as the authentication context class reference for the request to '.$azureMfaIdentityProvider->getEntityId()
);
$authnRequest->setAuthenticationContextClassRef('http://schemas.microsoft.com/claims/multipleauthn');

Expand Down Expand Up @@ -183,67 +186,93 @@ public function handleResponse(Request $request): User
assert($user instanceof User);

// Retrieve its institution and identity provider
$this->logger->info('Match the user email address to one of the registered institutions');
$this->logger->info('Match the user email address '.$user->getEmailAddress()->getEmailAddress().' to one of the registered institutions');
$institution = $this->matchingService->findInstitutionByEmail($user->getEmailAddress());
if (is_null($institution)) {
throw new AzureADException('The Institution could not be found using the users mail address');
}
$azureMfaIdentityProvider = $this->identityProviderCache->build($institution->getName());

$assertion = $this->processSamlResponse($request, $institution, $azureMfaIdentityProvider);
$attributes = $assertion->getAttributes();

$this->validateResponseAttributes($attributes, $institution, $azureMfaIdentityProvider, $user);

$this->logger->info(sprintf(
'The mail attribute in the response %s matched the email address of the registering/authenticating user: %s',
implode(', ', $attributes[self::SAML_EMAIL_ATTRIBUTE]),
$user->getEmailAddress()->getEmailAddress()
));

return $user;
}

private function processSamlResponse(
Request $request,
Institution $institution,
IdentityProviderInterface $azureMfaIdentityProvider,
): Assertion {
try {
$this->logger->info('Process the SAML Response');
$assertion = $this->postBinding->processResponse(
$request,
$azureMfaIdentityProvider,
$this->serviceProvider
);
return $this->postBinding->processResponse($request, $azureMfaIdentityProvider, $this->serviceProvider);
} catch (Exception $e) {
// If the signature validation fails, we try to rebuild the identity provider
// This will effectively refresh the metadata for the institution
// Todo: refactor this to be more robust, e.g. by checking the exception type
if (!$institution->supportsMetadataUpdate() || $e->getMessage() !== 'Unable to validate Signature') {
throw $e;
}
}

$this->logger->info(sprintf('Unable to validate signature refreshing metadata for %s', $institution->getName()->getInstitutionName()));

$azureMfaIdentityProvider = $this->identityProviderCache->rebuild($institution->getName());
$this->logger->info(sprintf('Unable to validate signature refreshing metadata for %s', $institution->getName()->getInstitutionName()));
$azureMfaIdentityProvider = $this->identityProviderCache->rebuild($institution->getName());

$this->logger->info('Reprocess the SAML Response after updating the metadata');
$assertion = $this->postBinding->processResponse(
$request,
$azureMfaIdentityProvider,
$this->serviceProvider
);
$this->logger->info('Reprocess the SAML Response from '.$institution->getName()->getInstitutionName().' after updating the metadata');
try {
return $this->postBinding->processResponse($request, $azureMfaIdentityProvider, $this->serviceProvider);
} catch (Exception $retryException) {
$this->logger->error(sprintf(
'Unable to validate signature after refreshing metadata for %s',
$institution->getName()->getInstitutionName()
));
throw $retryException;
}
}

$attributes = $assertion->getAttributes();

/**
* @param array<string, array<string>> $attributes
*/
private function validateResponseAttributes(
array $attributes,
Institution $institution,
IdentityProviderInterface $azureMfaIdentityProvider,
User $user,
): void {
// If the IDP was an AzureAD endpoint (the entityID or Issuer starts with https://login.microsoftonline.com/, or preferably an config parameter in institutions.yaml)
// the SAML response attribute 'http://schemas.microsoft.com/claims/authnmethodsreferences'
// should contain 'http://schemas.microsoft.com/claims/multipleauthn'
if ($azureMfaIdentityProvider->isAzureAD()) {
$this->logger->info('This is an AzureAD IdP. Validating authnmethodsreferences in the response.');
$this->logger->info($institution->getName()->getInstitutionName().' is an AzureAD IdP. Validating authnmethodsreferences in the response.');
if (!isset($attributes['http://schemas.microsoft.com/claims/authnmethodsreferences']) || !in_array('http://schemas.microsoft.com/claims/multipleauthn', $attributes['http://schemas.microsoft.com/claims/authnmethodsreferences'])) {
throw new AzureADException(
'No http://schemas.microsoft.com/claims/multipleauthn in authnmethodsreferences.'
'No http://schemas.microsoft.com/claims/multipleauthn in authnmethodsreferences response from '.$institution->getName()->getInstitutionName()
);
}
}

if (!isset($attributes[self::SAML_EMAIL_ATTRIBUTE])) {
throw new MissingMailAttributeException(
'The mail attribute in the Azure MFA assertion was missing'
'The mail attribute in the Azure MFA assertion from '.$institution->getName()->getInstitutionName().' was missing'
);
}

if (!in_array(strtolower($user->getEmailAddress()->getEmailAddress()), array_map('strtolower', $attributes[self::SAML_EMAIL_ATTRIBUTE]))) {
throw new MailAttributeMismatchException(
'The mail attribute from the Azure MFA assertion did not contain the email address provided during registration'
);
throw new MailAttributeMismatchException(sprintf(
'The mail attribute (%s) from the Azure MFA assertion from %s did not contain the email address provided during registration (%s)',
implode(', ', $attributes[self::SAML_EMAIL_ATTRIBUTE]),
$institution->getName()->getInstitutionName(),
strtolower($user->getEmailAddress()->getEmailAddress())
));
}

$this->logger->info('The mail attribute in the response matched the email address of the registering/authenticating user');
return $user;
}
}