feat: comprehensive audit log

This commit is contained in:
fromme committed 2026-09-18 11:16:57 +02:00
1 parent 867bd413c8
commit 02e0d672bd
20 files changed
+932 -82

No files matched your search

+20 -5
View File
@@ -1,6 +1,21 @@
monolog:
channels: # To see all channels, run bin/console debug:autowiring logger
- deprecation # Deprecations are logged in the dedicated "deprecation" channel when it exists
- audit # Who did what to a booking or a resource -- see App\Service\AuditLogger
handlers:
# The audit trail is kept in every environment, on its own file and for 30 days. It is
# deliberately not routed through the handlers below: those are fingers_crossed in prod,
# which means records are dropped unless an error happens to flush the buffer -- fine for
# debug noise, useless for a trail that has to be complete. Hence the plain handler, and
# hence "!audit" on the others so the same record is not duplicated into them.
audit:
type: rotating_file
path: "%kernel.logs_dir%/audit.%kernel.environment%.log"
max_files: 30
level: info
channels: [audit]
formatter: monolog.formatter.json
when@dev:
monolog:
@@ -9,11 +24,11 @@ when@dev:
type: stream
path: "%kernel.logs_dir%/%kernel.environment%.log"
level: debug
channels: ["!event"]
channels: ["!event", "!audit"]
console:
type: console
process_psr_3_messages: false
channels: ["!event", "!doctrine", "!console"]
channels: ["!event", "!doctrine", "!console", "!audit"]
when@test:
monolog:
@@ -23,7 +38,7 @@ when@test:
action_level: error
handler: nested
excluded_http_codes: [404, 405]
channels: ["!event"]
channels: ["!event", "!audit"]
nested:
type: stream
path: "%kernel.logs_dir%/%kernel.environment%.log"
@@ -37,7 +52,7 @@ when@prod:
action_level: error
handler: nested
excluded_http_codes: [404, 405]
channels: ["!deprecation"]
channels: ["!deprecation", "!audit"]
buffer_size: 50 # How many messages should be saved? Prevent memory leaks
nested:
type: stream
@@ -47,7 +62,7 @@ when@prod:
console:
type: console
process_psr_3_messages: false
channels: ["!event", "!doctrine"]
channels: ["!event", "!doctrine", "!audit"]
deprecation:
type: stream
channels: [deprecation]
+7
View File
@@ -19,6 +19,13 @@ services:
App\:
resource: '../src/'
# The audit trail writes to its own channel, never to the default one: the rotating
# audit.*.log is the record of who moved what, and mixing framework noise into it (or the
# trail into the framework log) would defeat both.
App\Service\AuditLogger:
arguments:
$logger: '@monolog.logger.audit'
# The myep OAuth2 client. Endpoint URLs are configuration rather than constants (same as
# myep-team), so dev, staging and production differ by .env alone. Empty credentials are a
# valid state: the login page then says the client is not registered yet instead of bouncing
@@ -9,8 +9,8 @@ use App\Enum\ResourceType;
use App\Form\Admin\ResourceFormType;
use App\Htmx\HxRedirectResponse;
use App\Security\Role;
use App\Service\AuditLogger;
use Doctrine\ORM\EntityManagerInterface;
use Psr\Log\LoggerInterface;
use Symfony\Bundle\FrameworkBundle\Controller\AbstractController;
use Symfony\Component\HttpFoundation\Request;
use Symfony\Component\HttpFoundation\Response;
@@ -22,7 +22,7 @@ final class CreateController extends AbstractController
{
public function __construct(
private readonly EntityManagerInterface $em,
private readonly LoggerInterface $logger,
private readonly AuditLogger $audit,
) {
}
@@ -43,12 +43,7 @@ final class CreateController extends AbstractController
$this->em->persist($resource);
$this->em->flush();
$this->logger->info('Admin created a resource.', [
'admin' => $this->getUser()?->getUserIdentifier(),
'resource_id' => $resource->getId(),
'type' => $type->value,
'label' => $resource->getLabel(),
]);
$this->audit->resourceCreated($resource);
$this->addFlash('success', \sprintf('%s angelegt.', $resource->getLabel()));
return new HxRedirectResponse($this->generateUrl('app_admin_resource'));
@@ -12,8 +12,8 @@ use App\Htmx\HxRedirectResponse;
use App\Repository\BookingRepository;
use App\Security\Role;
use Doctrine\DBAL\LockMode;
use App\Service\AuditLogger;
use Doctrine\ORM\EntityManagerInterface;
use Psr\Log\LoggerInterface;
use Symfony\Bundle\FrameworkBundle\Controller\AbstractController;
use Symfony\Component\HttpFoundation\Request;
use Symfony\Component\HttpFoundation\Response;
@@ -38,7 +38,7 @@ final class DeleteController extends AbstractController
public function __construct(
private readonly EntityManagerInterface $em,
private readonly BookingRepository $bookings,
private readonly LoggerInterface $logger,
private readonly AuditLogger $audit,
) {
}
@@ -61,8 +61,10 @@ final class DeleteController extends AbstractController
$this->denyUnlessCsrfValid($request, $tokenId);
$id = $resource->getId();
// Snapshotted before the delete: afterwards the entity no longer knows its own id.
$id = (int) $resource->getId();
$label = $resource->getLabel();
$type = $resource->getType();
$deleted = $this->em->wrapInTransaction(function () use ($resource): int {
$this->em->lock($resource, LockMode::PESSIMISTIC_WRITE);
@@ -87,12 +89,7 @@ final class DeleteController extends AbstractController
return (int) $deleted;
});
$this->logger->info('Admin deleted a resource.', [
'admin' => $this->getUser()?->getUserIdentifier(),
'resource_id' => $id,
'label' => $label,
'bookings_deleted' => $deleted,
]);
$this->audit->resourceDeleted($id, $label, $type, $deleted);
$this->addFlash('success', $deleted > 0
? \sprintf('%s und %d Buchungen gelöscht.', $label, $deleted)
@@ -9,8 +9,8 @@ use App\Form\Admin\ResourceFormType;
use App\Htmx\HxRedirectResponse;
use App\Repository\BookingRepository;
use App\Security\Role;
use App\Service\AuditLogger;
use Doctrine\ORM\EntityManagerInterface;
use Psr\Log\LoggerInterface;
use Symfony\Bundle\FrameworkBundle\Controller\AbstractController;
use Symfony\Component\HttpFoundation\Request;
use Symfony\Component\HttpFoundation\Response;
@@ -31,7 +31,7 @@ final class EditController extends AbstractController
public function __construct(
private readonly EntityManagerInterface $em,
private readonly BookingRepository $bookings,
private readonly LoggerInterface $logger,
private readonly AuditLogger $audit,
) {
}
@@ -49,13 +49,7 @@ final class EditController extends AbstractController
if ($form->isSubmitted() && $form->isValid()) {
$this->em->flush();
$this->logger->info('Admin edited a resource.', [
'admin' => $this->getUser()?->getUserIdentifier(),
'resource_id' => $resource->getId(),
'label' => $resource->getLabel(),
'group' => $resource->getGroup()?->getLabel(),
'active' => $resource->isActive(),
]);
$this->audit->resourceUpdated($resource, $wasActive);
$remaining = $wasActive && !$resource->isActive()
? $this->bookings->countFromDate($resource, new \DateTimeImmutable('today'))
@@ -10,8 +10,8 @@ use App\Form\Admin\ResourceGroupFormType;
use App\Htmx\HxRedirectResponse;
use App\Repository\ResourceGroupRepository;
use App\Security\Role;
use App\Service\AuditLogger;
use Doctrine\ORM\EntityManagerInterface;
use Psr\Log\LoggerInterface;
use Symfony\Bundle\FrameworkBundle\Controller\AbstractController;
use Symfony\Component\HttpFoundation\Request;
use Symfony\Component\HttpFoundation\Response;
@@ -24,7 +24,7 @@ final class CreateController extends AbstractController
public function __construct(
private readonly EntityManagerInterface $em,
private readonly ResourceGroupRepository $groups,
private readonly LoggerInterface $logger,
private readonly AuditLogger $audit,
) {
}
@@ -45,12 +45,7 @@ final class CreateController extends AbstractController
$this->em->persist($group);
$this->em->flush();
$this->logger->info('Admin created a resource group.', [
'admin' => $this->getUser()?->getUserIdentifier(),
'group_id' => $group->getId(),
'type' => $type->value,
'label' => $group->getLabel(),
]);
$this->audit->resourceGroupCreated($group);
$this->addFlash('success', \sprintf('%s angelegt.', $group->getLabel()));
return new HxRedirectResponse($this->generateUrl('app_admin_resource'));
@@ -9,8 +9,8 @@ use App\Entity\ResourceGroup;
use App\Htmx\HxRedirectResponse;
use App\Repository\ResourceRepository;
use App\Security\Role;
use App\Service\AuditLogger;
use Doctrine\ORM\EntityManagerInterface;
use Psr\Log\LoggerInterface;
use Symfony\Bundle\FrameworkBundle\Controller\AbstractController;
use Symfony\Component\HttpFoundation\Request;
use Symfony\Component\HttpFoundation\Response;
@@ -31,7 +31,7 @@ final class DeleteController extends AbstractController
public function __construct(
private readonly EntityManagerInterface $em,
private readonly ResourceRepository $resources,
private readonly LoggerInterface $logger,
private readonly AuditLogger $audit,
) {
}
@@ -51,11 +51,7 @@ final class DeleteController extends AbstractController
$this->denyUnlessCsrfValid($request, 'delete-resource-group-'.$group->getId());
$this->logger->info('Admin deleted a resource group.', [
'admin' => $this->getUser()?->getUserIdentifier(),
'group_id' => $group->getId(),
'label' => $group->getLabel(),
]);
$this->audit->resourceGroupDeleted((int) $group->getId(), $group->getLabel(), $group->getType());
$label = $group->getLabel();
$this->em->remove($group);
@@ -8,8 +8,8 @@ use App\Entity\ResourceGroup;
use App\Form\Admin\ResourceGroupFormType;
use App\Htmx\HxRedirectResponse;
use App\Security\Role;
use App\Service\AuditLogger;
use Doctrine\ORM\EntityManagerInterface;
use Psr\Log\LoggerInterface;
use Symfony\Bundle\FrameworkBundle\Controller\AbstractController;
use Symfony\Component\HttpFoundation\Request;
use Symfony\Component\HttpFoundation\Response;
@@ -21,7 +21,7 @@ final class EditController extends AbstractController
{
public function __construct(
private readonly EntityManagerInterface $em,
private readonly LoggerInterface $logger,
private readonly AuditLogger $audit,
) {
}
@@ -36,12 +36,7 @@ final class EditController extends AbstractController
if ($form->isSubmitted() && $form->isValid()) {
$this->em->flush();
$this->logger->info('Admin edited a resource group.', [
'admin' => $this->getUser()?->getUserIdentifier(),
'group_id' => $group->getId(),
'label' => $group->getLabel(),
'position' => $group->getPosition(),
]);
$this->audit->resourceGroupUpdated($group);
$this->addFlash('success', \sprintf('%s gespeichert.', $group->getLabel()));
return new HxRedirectResponse($this->generateUrl('app_admin_resource'));
+3 -14
View File
@@ -12,7 +12,6 @@ use App\Htmx\HxTrait;
use App\Security\Role;
use App\Service\BoardContextFactory;
use App\Service\BookingManager;
use Psr\Log\LoggerInterface;
use Symfony\Bundle\FrameworkBundle\Controller\AbstractController;
use Symfony\Component\HttpFoundation\Request;
use Symfony\Component\HttpFoundation\Response;
@@ -28,7 +27,6 @@ final class ReleaseController extends AbstractController
public function __construct(
private readonly BoardContextFactory $boardContext,
private readonly BookingManager $manager,
private readonly LoggerInterface $logger,
) {
}
@@ -57,18 +55,9 @@ final class ReleaseController extends AbstractController
$holder = $booking->getUser();
$onBehalf = !$booking->belongsTo($this->currentUser());
if ($onBehalf) {
// The row is about to be deleted, so without this line nothing records that an
// administrator freed somebody else's desk.
$this->logger->info('Admin released a booking on behalf of another user.', [
'admin' => $this->currentUser()->getEmail(),
'holder' => $holder->getEmail(),
'resource' => $label,
'date' => $date->format('Y-m-d'),
'time' => (string) $booking->getTimeRange(),
]);
}
// The release itself is audited from BookingManager, which is also where the row still
// exists to be described. An administrator freeing somebody else's desk needs nothing
// extra here: the record carries the holder, and the actor comes from the token.
$this->manager->release($booking);
$this->addFlash('success', $onBehalf
+2 -11
View File
@@ -10,7 +10,6 @@ use App\Entity\BookingSeries;
use App\Htmx\HxTrait;
use App\Security\Role;
use App\Service\BookingManager;
use Psr\Log\LoggerInterface;
use Symfony\Bundle\FrameworkBundle\Controller\AbstractController;
use Symfony\Component\HttpFoundation\Request;
use Symfony\Component\HttpFoundation\Response;
@@ -24,7 +23,6 @@ final class EndController extends AbstractController
public function __construct(
private readonly BookingManager $manager,
private readonly LoggerInterface $logger,
) {
}
@@ -45,17 +43,10 @@ final class EndController extends AbstractController
$this->denyUnlessCsrfValid($request, 'end-series-'.$series->getId());
// Only the flash still cares who the series belongs to; the audit record is written
// from BookingManager and names holder and actor by itself.
$onBehalf = $series->getUser()->getId() !== $this->currentUser()->getId();
if ($onBehalf) {
$this->logger->info('Admin ended a series on behalf of another user.', [
'admin' => $this->currentUser()->getEmail(),
'holder' => $series->getUser()->getEmail(),
'resource' => $series->getResource()->getLabel(),
'series' => $series->getId(),
]);
}
$removed = $this->manager->endSeries($series, new \DateTimeImmutable('today'));
$this->addFlash('success', $onBehalf
@@ -0,0 +1,55 @@
<?php
declare(strict_types=1);
namespace App\EventListener;
use App\Entity\User;
use App\Service\AuditLogger;
use Symfony\Component\EventDispatcher\Attribute\AsEventListener;
use Symfony\Component\Security\Http\Event\LoginSuccessEvent;
use Symfony\Component\Security\Http\Event\LogoutEvent;
/**
* The two ends of a session, audited from the firewall rather than from a controller.
*
* Neither end has a controller to hang this on: the callback route is intercepted by
* EpAuthenticator and /logout by the firewall's logout listener, and both controllers do nothing
* but throw. The events are also the only hook that would still fire if a second authenticator
* were ever added.
*
* Refused sign-ins are NOT here. They are audited from EpAuthenticator, which is the only place
* that knows *why* one was refused -- by the time a failure event is dispatched the reason has
* been flattened into a German message meant for the login page.
*/
final readonly class AuditSessionListener
{
public function __construct(private AuditLogger $audit)
{
}
#[AsEventListener(event: LoginSuccessEvent::class)]
public function onLoginSuccess(LoginSuccessEvent $event): void
{
$user = $event->getUser();
if ($user instanceof User) {
$this->audit->signedIn($user);
}
}
/**
* The token is still in place while this event is dispatched -- LogoutListener clears it
* afterwards -- but the account is read off the event rather than off the token store all
* the same, so the record stays complete if that order ever changes.
*/
#[AsEventListener(event: LogoutEvent::class)]
public function onLogout(LogoutEvent $event): void
{
$user = $event->getToken()?->getUser();
if ($user instanceof User) {
$this->audit->signedOut($user);
}
}
}
+61
View File
@@ -0,0 +1,61 @@
<?php
declare(strict_types=1);
namespace App\Logger;
use App\Entity\User;
use Monolog\Attribute\AsMonologProcessor;
use Monolog\LogRecord;
use Symfony\Bundle\SecurityBundle\Security;
/**
* Stamps every audit record with who caused it.
*
* The actor lives in `extra` rather than in the context each call site passes, because it is the
* one field that is true of every audit record and that no call site should be able to forget or
* get wrong -- it is read from the token, not from an argument. What a call site does pass is the
* *subject*: whose booking, which resource. When those two differ, the record shows an
* administrator acting on somebody else's behalf without anybody having to say so.
*
* Bound to the audit channel alone: the framework log has no use for it, and enriching every
* Doctrine record with a security lookup would be a needless cost.
*/
#[AsMonologProcessor(channel: 'audit')]
final readonly class AuditActorProcessor
{
/** Console commands and the message worker have no token; they still write bookings. */
public const SYSTEM = 'system';
/** Reachable only before the firewall has a user -- login, and errors on public routes. */
public const ANONYMOUS = 'anonymous';
public function __construct(private Security $security)
{
}
public function __invoke(LogRecord $record): LogRecord
{
$record->extra['actor'] = $this->actor();
return $record;
}
private function actor(): string
{
$user = $this->security->getUser();
if ($user instanceof User) {
return $user->getEmail();
}
// The user is asked for first and the SAPI only afterwards, so that a console command
// running with a token -- a future import, say -- is still attributed to whoever it runs
// as, rather than swallowed by a blanket "cli means system" check.
if (null !== $user) {
return $user->getUserIdentifier();
}
return 'cli' === \PHP_SAPI ? self::SYSTEM : self::ANONYMOUS;
}
}
+23
View File
@@ -9,6 +9,7 @@ use App\Repository\UserRepository;
use App\Security\OAuth2\AuthorizationRequestException;
use App\Security\OAuth2\EpClient;
use App\Security\OAuth2\UserinfoUnavailableException;
use App\Service\AuditLogger;
use Doctrine\ORM\EntityManagerInterface;
use League\OAuth2\Client\Provider\Exception\IdentityProviderException;
use Psr\Log\LoggerInterface;
@@ -42,6 +43,7 @@ class EpAuthenticator extends AbstractAuthenticator
private readonly EntityManagerInterface $em,
private readonly UrlGeneratorInterface $urlGenerator,
private readonly LoggerInterface $logger,
private readonly AuditLogger $audit,
) {
}
@@ -56,6 +58,10 @@ class EpAuthenticator extends AbstractAuthenticator
$accessToken = $this->client->fetchAccessToken($request);
} catch (AuthorizationRequestException|IdentityProviderException $e) {
$this->logger->error('Login via myep failed: no access token', ['exception' => $e]);
// Audited here rather than from a failure event: this is the only point that still
// knows why the sign-in did not happen. Downstream there is only the German message
// the login page shows.
$this->audit->signInRefused('no_access_token');
throw new CustomUserMessageAuthenticationException('Anmeldung über myep fehlgeschlagen.');
}
@@ -64,6 +70,7 @@ class EpAuthenticator extends AbstractAuthenticator
$userinfo = $this->client->fetchUserinfo($accessToken);
} catch (UserinfoUnavailableException $e) {
$this->logger->error('Login via myep failed: userinfo unreadable', ['exception' => $e]);
$this->audit->signInRefused('userinfo_unreadable');
throw new CustomUserMessageAuthenticationException('Anmeldung über myep fehlgeschlagen.');
}
@@ -74,6 +81,7 @@ class EpAuthenticator extends AbstractAuthenticator
$email = $userinfo['email'] ?? null;
if (!\is_string($email) || '' === $email) {
$this->logger->error('Login via myep failed: userinfo carried no email claim');
$this->audit->signInRefused('no_email_claim');
throw new CustomUserMessageAuthenticationException('Anmeldung über myep fehlgeschlagen.');
}
@@ -81,6 +89,7 @@ class EpAuthenticator extends AbstractAuthenticator
$roles = Role::eligibleOnly($this->claimedRoles($userinfo));
if ([] === $roles) {
$this->logger->info('Login via myep refused: no eligible role', ['email' => $email]);
$this->audit->signInRefused('no_eligible_role', $email);
throw new CustomUserMessageAuthenticationException(
'Für E&P Platz ist eine Mitarbeiter- oder Administrator-Rolle erforderlich.',
@@ -154,6 +163,7 @@ class EpAuthenticator extends AbstractAuthenticator
private function createOrUpdate(string $email, string $name, array $roles): User
{
$user = $this->users->findOneBy(['email' => $email]);
$isNew = null === $user;
if (null === $user) {
$user = new User($email, $name);
@@ -162,11 +172,24 @@ class EpAuthenticator extends AbstractAuthenticator
$user->setName($name);
}
// Filtered the same way the claim was, so the comparison below is between two sets of
// the same shape -- getRoles() would add ROLE_USER to one side and not the other.
$previousRoles = Role::eligibleOnly($user->getRoles());
// myep leads: a role it no longer reports is withdrawn here, not kept because it was
// granted once.
$user->setRoles($roles);
$this->em->flush();
// After the flush, so nothing is recorded that a failing write would have undone. Both
// records show "anonymous" as their actor, correctly: they happen while the person is
// being authenticated and before any token exists, which is why they name the account.
if ($isNew) {
$this->audit->accountProvisioned($user);
} elseif ($previousRoles !== $roles) {
$this->audit->rolesChanged($user, $previousRoles, $roles);
}
return $user;
}
}
+269
View File
@@ -0,0 +1,269 @@
<?php
declare(strict_types=1);
namespace App\Service;
use App\Entity\Booking;
use App\Entity\BookingSeries;
use App\Entity\Resource;
use App\Entity\ResourceGroup;
use App\Entity\User;
use App\Enum\ResourceType;
use App\Model\SeriesResult;
use App\Model\TimeRange;
use Psr\Log\LoggerInterface;
/**
* The audit trail: one method per thing that can happen to a booking, a resource, or a session.
*
* Why a service rather than a LoggerInterface in every controller. The records are only worth
* keeping if they are uniform -- the same wording and the same context keys for the same event,
* whichever route reached it -- and that is not something a dozen scattered `$logger->info()`
* calls hold on to. Naming the events here also makes the list of what is audited readable in
* one place, so a new write that nobody logged is a visible gap rather than an invisible one.
*
* Messages are English, like every other developer-facing string in this project: an audit log
* is read by whoever is investigating, not by the person who was booking a desk.
*
* The acting user is NOT passed in. AuditActorProcessor takes it from the security token and
* puts it in `extra.actor`, so no call site can log the wrong one. What the context carries is
* the subject -- `holder` for a booking -- and a record whose holder is not its actor is an
* administrator having acted for somebody else.
*
* Level is info throughout: an audit record is a fact, not a problem. Something that *is* a
* problem belongs in the framework log, which is what the default channel is for -- a refused
* sign-in is audited here *and* logged with its exception there, because the two readers want
* different things from it.
*/
final readonly class AuditLogger
{
public function __construct(private LoggerInterface $logger)
{
}
public function bookingCreated(Booking $booking): void
{
$this->logger->info('Booking created.', $this->booking($booking));
}
/**
* One record for the series, not one per occurrence: the occurrences are the same act, and
* a year of weekly bookings would otherwise bury everything else in the file. The individual
* days stay recoverable -- the series id is on every booking record that follows.
*/
public function seriesCreated(SeriesResult $result): void
{
$series = $result->series;
$this->logger->info('Booking series created.', [
'series_id' => $series->getId(),
'holder' => $series->getUser()->getEmail(),
'resource' => $series->getResource()->getLabel(),
'resource_id' => $series->getResource()->getId(),
'rule' => $series->getRule()->value,
'start_date' => $series->getStartDate()->format('Y-m-d'),
'end_date' => $series->getEndDate()->format('Y-m-d'),
'time' => self::clock($series->getTimeRange()),
'bookings_created' => $result->createdCount(),
// The days the series could not have, so a later "why is Tuesday missing" has an
// answer without reconstructing what was booked at the time.
'skipped_dates' => array_keys($result->skipped),
]);
}
public function bookingRescheduled(Booking $booking, TimeRange $previous): void
{
$this->logger->info('Booking rescheduled.', $this->booking($booking) + [
'previous_time' => self::clock($previous),
]);
}
/**
* Called before the row goes, since afterwards there is nothing left to describe it.
*/
public function bookingReleased(Booking $booking): void
{
$this->logger->info('Booking released.', $this->booking($booking));
}
/**
* The id is passed rather than read off the series, because ending one can delete it and
* Doctrine nulls the identifier of a deleted entity (UnitOfWork::executeDeletions) -- asking
* the series for its own id afterwards yields null exactly on the records that matter most.
*/
public function seriesEnded(BookingSeries $series, ?int $seriesId, \DateTimeImmutable $from, int $removed): void
{
$this->logger->info('Booking series ended.', [
'series_id' => $seriesId,
'holder' => $series->getUser()->getEmail(),
'resource' => $series->getResource()->getLabel(),
'resource_id' => $series->getResource()->getId(),
'ended_from' => $from->format('Y-m-d'),
'bookings_removed' => $removed,
]);
}
public function signedIn(User $user): void
{
$this->logger->info('User signed in.', [
'account' => $user->getEmail(),
'roles' => $user->getRoles(),
]);
}
/**
* The account is named separately from the actor because a refused sign-in has no token
* behind it -- the actor of these records is always "anonymous", and on the paths that fail
* before the userinfo response is read there is not even an email to name.
*
* @param string $reason a short English tag, not a message: these are counted and filtered,
* and the user-facing German explanation says nothing to whoever reads
* the trail. The exception detail stays in the framework log.
*/
public function signInRefused(string $reason, ?string $email = null): void
{
$this->logger->info('Sign-in refused.', [
'account' => $email,
'reason' => $reason,
]);
}
public function signedOut(User $user): void
{
$this->logger->info('User signed out.', [
'account' => $user->getEmail(),
]);
}
/**
* First sign-in: myep authenticates the person, and this is the moment ephub gains a row for
* them. Audited because it is the only place an account comes into existence -- nobody
* creates one by hand.
*/
public function accountProvisioned(User $user): void
{
$this->logger->info('User account provisioned.', [
'account' => $user->getEmail(),
'roles' => $user->getRoles(),
]);
}
/**
* Roles follow myep on every sign-in, so a person can gain or lose administrative access
* without anybody here doing anything. That is worth a record of its own: it is the one
* change to an account that alters what its holder may do.
*
* @param list<string> $previous
* @param list<string> $current
*/
public function rolesChanged(User $user, array $previous, array $current): void
{
$this->logger->info('User roles changed.', [
'account' => $user->getEmail(),
'previous_roles' => $previous,
'roles' => $current,
]);
}
public function resourceCreated(Resource $resource): void
{
$this->logger->info('Resource created.', $this->resource($resource));
}
public function resourceUpdated(Resource $resource, bool $wasActive): void
{
$this->logger->info('Resource updated.', $this->resource($resource) + [
// Retiring and reactivating are ordinary edits to the form and to the database, but
// not to the people whose bookings they affect, so the transition is spelled out
// rather than left to be diffed out of two consecutive records.
'was_active' => $wasActive,
]);
}
/**
* Takes a snapshot rather than the entity: by the time a deletion is worth recording, the
* entity no longer has an id to read.
*/
public function resourceDeleted(int $id, string $label, ResourceType $type, int $bookingsDeleted): void
{
$this->logger->info('Resource deleted.', [
'resource' => $label,
'resource_id' => $id,
'type' => $type->value,
'bookings_deleted' => $bookingsDeleted,
]);
}
public function resourceGroupCreated(ResourceGroup $group): void
{
$this->logger->info('Resource group created.', $this->group($group));
}
public function resourceGroupUpdated(ResourceGroup $group): void
{
$this->logger->info('Resource group updated.', $this->group($group));
}
public function resourceGroupDeleted(int $id, string $label, ResourceType $type): void
{
$this->logger->info('Resource group deleted.', [
'group' => $label,
'group_id' => $id,
'type' => $type->value,
]);
}
/**
* @return array<string, mixed>
*/
private function booking(Booking $booking): array
{
return [
'booking_id' => $booking->getId(),
'holder' => $booking->getUser()->getEmail(),
'resource' => $booking->getResource()->getLabel(),
'resource_id' => $booking->getResource()->getId(),
'date' => $booking->getDate()->format('Y-m-d'),
'time' => self::clock($booking->getTimeRange()),
'series_id' => $booking->getSeries()?->getId(),
];
}
/**
* Clock times rather than (string) $time: TimeRange's own string form is the German one the
* UI shows ("ganztägig"), and an audit record is read by whoever is investigating. This also
* keeps every record's time in one shape, which "all day" would not be.
*/
private static function clock(TimeRange $time): string
{
return $time->start().'-'.$time->end();
}
/**
* @return array<string, mixed>
*/
private function resource(Resource $resource): array
{
return [
'resource' => $resource->getLabel(),
'resource_id' => $resource->getId(),
'type' => $resource->getType()->value,
'group' => $resource->getGroup()?->getLabel(),
'active' => $resource->isActive(),
];
}
/**
* @return array<string, mixed>
*/
private function group(ResourceGroup $group): array
{
return [
'group' => $group->getLabel(),
'group_id' => $group->getId(),
'type' => $group->getType()->value,
'position' => $group->getPosition(),
];
}
}
+30 -3
View File
@@ -43,6 +43,7 @@ final readonly class BookingManager
public function __construct(
private EntityManagerInterface $em,
private BookingRepository $bookings,
private AuditLogger $audit,
) {
}
@@ -54,7 +55,7 @@ final readonly class BookingManager
// All day is the default, as it was before ranges existed.
$time ??= TimeRange::wholeDay();
return $this->em->wrapInTransaction(function () use ($user, $resource, $date, $time): Booking {
$booking = $this->em->wrapInTransaction(function () use ($user, $resource, $date, $time): Booking {
$this->em->lock($resource, LockMode::PESSIMISTIC_WRITE);
$this->assertFree($resource, $date, $time);
@@ -65,6 +66,13 @@ final readonly class BookingManager
return $booking;
});
// Audited outside the transaction, here and below: a record of a write that was rolled
// back afterwards would be worse than no record, and a refused booking throws before
// ever reaching this line.
$this->audit->bookingCreated($booking);
return $booking;
}
/**
@@ -76,7 +84,7 @@ final readonly class BookingManager
*/
public function bookSeries(BookingSeries $series): SeriesResult
{
return $this->em->wrapInTransaction(function () use ($series): SeriesResult {
$result = $this->em->wrapInTransaction(function () use ($series): SeriesResult {
$resource = $series->getResource();
$user = $series->getUser();
$time = $series->getTimeRange();
@@ -108,6 +116,10 @@ final readonly class BookingManager
return new SeriesResult($series, $created, $skipped);
});
$this->audit->seriesCreated($result);
return $result;
}
/**
@@ -115,6 +127,8 @@ final readonly class BookingManager
*/
public function reschedule(Booking $booking, TimeRange $time): void
{
$previous = $booking->getTimeRange();
$this->em->wrapInTransaction(function () use ($booking, $time): void {
$resource = $booking->getResource();
$this->em->lock($resource, LockMode::PESSIMISTIC_WRITE);
@@ -124,10 +138,15 @@ final readonly class BookingManager
$booking->changeTime($time);
$this->em->flush();
});
$this->audit->bookingRescheduled($booking, $previous);
}
public function release(Booking $booking): void
{
// Before the flush, while the booking still knows its own id.
$this->audit->bookingReleased($booking);
$this->em->remove($booking);
$this->em->flush();
}
@@ -140,7 +159,11 @@ final readonly class BookingManager
*/
public function endSeries(BookingSeries $series, \DateTimeImmutable $from): int
{
return $this->em->wrapInTransaction(function () use ($series, $from): int {
// Read before the transaction: ending a series can delete it, and a deleted entity no
// longer knows its own id.
$seriesId = $series->getId();
$removed = $this->em->wrapInTransaction(function () use ($series, $from): int {
$from = $from->setTime(0, 0);
$removed = 0;
@@ -159,6 +182,10 @@ final readonly class BookingManager
return $removed;
});
$this->audit->seriesEnded($series, $seriesId, $from, $removed);
return $removed;
}
/**
@@ -0,0 +1,67 @@
<?php
declare(strict_types=1);
namespace App\Tests\Controller\Security;
use App\Entity\User;
use Doctrine\ORM\EntityManagerInterface;
use Monolog\Handler\TestHandler;
use Monolog\Logger;
use Symfony\Bundle\FrameworkBundle\KernelBrowser;
use Symfony\Bundle\FrameworkBundle\Test\WebTestCase;
/**
* Signing out through the real firewall, rather than by calling the listener.
*
* The listener itself is unit-tested; what this pins down is the wiring -- that the listener is
* reached at all on a firewall-dispatched event, which no unit test can show. A TestHandler is
* pushed onto the audit channel so the assertion reads the records instead of the rotating file.
*/
class LogoutAuditTest extends WebTestCase
{
private KernelBrowser $client;
private EntityManagerInterface $em;
private TestHandler $auditRecords;
protected function setUp(): void
{
$this->client = self::createClient(server: ['HTTPS' => true]);
$this->client->disableReboot();
$this->em = self::getContainer()->get(EntityManagerInterface::class);
$this->em->getConnection()->beginTransaction();
$this->auditRecords = new TestHandler();
$audit = self::getContainer()->get('monolog.logger.audit');
\assert($audit instanceof Logger);
$audit->pushHandler($this->auditRecords);
}
protected function tearDown(): void
{
$this->em->getConnection()->rollBack();
parent::tearDown();
}
public function testSigningOutIsAudited(): void
{
$user = new User('[email protected]', 'Anna');
$user->setRoles(['ROLE_EMPLOYEE']);
$this->em->persist($user);
$this->em->flush();
$this->client->loginUser($user);
$this->client->request('GET', '/logout');
self::assertResponseRedirects();
$records = array_values(array_filter(
$this->auditRecords->getRecords(),
static fn ($record): bool => 'User signed out.' === $record->message,
));
self::assertCount(1, $records);
self::assertSame('[email protected]', $records[0]->context['account']);
self::assertSame('[email protected]', $records[0]->extra['actor']);
}
}
@@ -0,0 +1,50 @@
<?php
declare(strict_types=1);
namespace App\Tests\EventListener;
use App\Entity\User;
use App\EventListener\AuditSessionListener;
use App\Service\AuditLogger;
use Monolog\Handler\TestHandler;
use Monolog\Logger;
use PHPUnit\Framework\TestCase;
use Symfony\Component\HttpFoundation\Request;
use Symfony\Component\Security\Core\Authentication\Token\UsernamePasswordToken;
use Symfony\Component\Security\Http\Event\LogoutEvent;
/**
* Signing out has no controller behind it -- the firewall intercepts /logout -- so the record
* has to come off the event, and it has to survive the token being on its way out.
*/
class AuditSessionListenerTest extends TestCase
{
public function testSigningOutIsRecordedAgainstTheAccountThatHeldTheSession(): void
{
$handler = new TestHandler();
$listener = new AuditSessionListener(new AuditLogger(new Logger('audit', [$handler])));
$user = new User('[email protected]', 'Anna');
$listener->onLogout(new LogoutEvent(new Request(), new UsernamePasswordToken($user, 'main', $user->getRoles())));
$record = $handler->getRecords()[0];
self::assertSame('User signed out.', $record->message);
self::assertSame('[email protected]', $record->context['account']);
}
/**
* /logout is public, so it can be reached without a session at all -- that is not an event
* worth a record, and it must not be an error either.
*/
public function testSigningOutWithoutATokenRecordsNothing(): void
{
$handler = new TestHandler();
$listener = new AuditSessionListener(new AuditLogger(new Logger('audit', [$handler])));
$listener->onLogout(new LogoutEvent(new Request(), null));
self::assertSame([], $handler->getRecords());
}
}
+52
View File
@@ -0,0 +1,52 @@
<?php
declare(strict_types=1);
namespace App\Tests\Logger;
use App\Entity\User;
use App\Logger\AuditActorProcessor;
use Monolog\Level;
use Monolog\LogRecord;
use PHPUnit\Framework\TestCase;
use Symfony\Bundle\SecurityBundle\Security;
/**
* The actor is the one field an audit record cannot be allowed to get wrong, so it is taken from
* the token rather than from any call site -- which is what these cover.
*/
class AuditActorProcessorTest extends TestCase
{
public function testTheActorIsTheSignedInUsersEmailAddress(): void
{
$record = $this->process(new User('[email protected]', 'Admin'));
self::assertSame('[email protected]', $record->extra['actor']);
}
/**
* PHPUnit runs under the CLI SAPI, which is the same context a console command or the
* message worker writes from -- so this is the system branch, not the anonymous one.
*/
public function testAWriteWithNoUserBehindItIsAttributedToTheSystem(): void
{
$record = $this->process(null);
self::assertSame(AuditActorProcessor::SYSTEM, $record->extra['actor']);
}
private function process(?User $user): LogRecord
{
$security = $this->createStub(Security::class);
$security->method('getUser')->willReturn($user);
$processor = new AuditActorProcessor($security);
return $processor(new LogRecord(
new \DateTimeImmutable(),
'audit',
Level::Info,
'Booking created.',
));
}
}
+93
View File
@@ -11,8 +11,12 @@ use App\Security\OAuth2\AuthorizationRequestException;
use App\Security\OAuth2\EpClient;
use App\Security\OAuth2\UserinfoUnavailableException;
use App\Security\Role;
use App\Service\AuditLogger;
use Doctrine\ORM\EntityManagerInterface;
use League\OAuth2\Client\Token\AccessToken;
use Monolog\Handler\TestHandler;
use Monolog\Logger;
use Monolog\LogRecord;
use Psr\Log\NullLogger;
use Symfony\Bundle\FrameworkBundle\Test\KernelTestCase;
use Symfony\Component\HttpFoundation\Request;
@@ -29,12 +33,14 @@ use Symfony\Component\Security\Http\Authenticator\Passport\Badge\UserBadge;
class EpAuthenticatorTest extends KernelTestCase
{
private EntityManagerInterface $em;
private TestHandler $auditRecords;
protected function setUp(): void
{
self::bootKernel();
$this->em = self::getContainer()->get(EntityManagerInterface::class);
$this->em->getConnection()->beginTransaction();
$this->auditRecords = new TestHandler();
}
protected function tearDown(): void
@@ -189,6 +195,79 @@ class EpAuthenticatorTest extends KernelTestCase
->authenticate(new Request());
}
public function testAFirstSignInIsAudited(): void
{
$this->authenticate(['email' => '[email protected]', 'roles' => ['ROLE_EMPLOYEE']]);
$record = $this->audited('User account provisioned.');
self::assertSame('[email protected]', $record->context['account']);
self::assertContains(Role::EMPLOYEE, $record->context['roles']);
}
/**
* Roles follow myep on every sign-in, so somebody can lose administrative access without
* anybody here doing anything -- which is exactly the kind of change the trail is for.
*/
public function testAWithdrawnRoleIsAudited(): void
{
$existing = new User('[email protected]', 'Chef');
$existing->setRoles([Role::EMPLOYEE, Role::ADMIN]);
$this->em->persist($existing);
$this->em->flush();
$this->authenticate(['email' => '[email protected]', 'roles' => ['ROLE_EMPLOYEE']]);
$record = $this->audited('User roles changed.');
self::assertSame([Role::EMPLOYEE, Role::ADMIN], $record->context['previous_roles']);
self::assertSame([Role::EMPLOYEE], $record->context['roles']);
}
public function testASignInThatChangesNothingIsNotAuditedAsARoleChange(): void
{
$existing = new User('[email protected]', 'Anna');
$existing->setRoles([Role::EMPLOYEE]);
$this->em->persist($existing);
$this->em->flush();
$this->authenticate(['email' => '[email protected]', 'roles' => ['ROLE_EMPLOYEE']]);
self::assertFalse($this->auditRecords->hasInfoThatContains('User roles changed.'));
self::assertFalse($this->auditRecords->hasInfoThatContains('User account provisioned.'));
}
/**
* The reason is the point: by the time the failure reaches the login page it is one German
* sentence, whatever went wrong.
*/
public function testARefusedSignInIsAuditedWithWhyItWasRefused(): void
{
try {
$this->authenticate(['email' => '[email protected]', 'roles' => ['ROLE_CUSTOMER']]);
} catch (CustomUserMessageAuthenticationException) {
}
$record = $this->audited('Sign-in refused.');
self::assertSame('no_eligible_role', $record->context['reason']);
self::assertSame('[email protected]', $record->context['account']);
}
public function testAFailureBeforeTheUserIsKnownIsAuditedWithoutAnAccount(): void
{
try {
$this->authenticator(throwOnToken: new AuthorizationRequestException('state mismatch'))
->authenticate(new Request());
} catch (CustomUserMessageAuthenticationException) {
}
$record = $this->audited('Sign-in refused.');
self::assertSame('no_access_token', $record->context['reason']);
self::assertNull($record->context['account']);
}
public function testItOnlyFiresOnTheCallbackRoute(): void
{
$authenticator = $this->authenticator();
@@ -246,6 +325,20 @@ class EpAuthenticatorTest extends KernelTestCase
$this->em,
self::getContainer()->get(UrlGeneratorInterface::class),
new NullLogger(),
new AuditLogger(new Logger('audit', [$this->auditRecords])),
);
}
/** The one audit record carrying this message. */
private function audited(string $message): LogRecord
{
$records = array_values(array_filter(
$this->auditRecords->getRecords(),
static fn (LogRecord $record): bool => $message === $record->message,
));
self::assertCount(1, $records, \sprintf('Expected exactly one "%s" audit record.', $message));
return $records[0];
}
}
+179
View File
@@ -0,0 +1,179 @@
<?php
declare(strict_types=1);
namespace App\Tests\Service;
use App\Entity\Booking;
use App\Entity\BookingSeries;
use App\Entity\Resource;
use App\Entity\ResourceGroup;
use App\Entity\User;
use App\Enum\RecurrenceRule;
use App\Enum\ResourceType;
use App\Model\SeriesResult;
use App\Model\TimeRange;
use App\Service\AuditLogger;
use Monolog\Handler\TestHandler;
use Monolog\LogRecord;
use Monolog\Logger;
use PHPUnit\Framework\TestCase;
/**
* What the trail has to say, rather than that it says something: an audit record is only useful
* if it names the holder and the resource, since the actor beside it is what makes an
* administrator acting for somebody else visible at all.
*/
class AuditLoggerTest extends TestCase
{
private TestHandler $handler;
private AuditLogger $audit;
protected function setUp(): void
{
$this->handler = new TestHandler();
$this->audit = new AuditLogger(new Logger('audit', [$this->handler]));
}
public function testACreatedBookingIsRecordedWithItsHolderAndResource(): void
{
$this->audit->bookingCreated($this->booking());
$record = $this->record();
self::assertSame('Booking created.', $record->message);
self::assertSame('[email protected]', $record->context['holder']);
self::assertSame('D1', $record->context['resource']);
self::assertSame('2026-09-18', $record->context['date']);
self::assertSame('09:00-13:00', $record->context['time']);
}
public function testARescheduledBookingKeepsTheSpanItCameFrom(): void
{
$booking = $this->booking();
$previous = $booking->getTimeRange();
$booking->changeTime(TimeRange::fromMinutes(600, 900));
$this->audit->bookingRescheduled($booking, $previous);
$record = $this->record();
self::assertSame('Booking rescheduled.', $record->message);
self::assertSame('09:00-13:00', $record->context['previous_time']);
self::assertSame('10:00-15:00', $record->context['time']);
}
/**
* A series is one record, not one per occurrence -- otherwise a year of weekly bookings
* buries every other event in the file.
*/
public function testASeriesIsRecordedOnceWithTheDaysItCouldNotHave(): void
{
$series = new BookingSeries(
$this->user(),
$this->resource(),
RecurrenceRule::WEEKLY,
new \DateTimeImmutable('2026-09-18'),
new \DateTimeImmutable('2026-10-02'),
TimeRange::fromMinutes(540, 780),
);
$this->audit->seriesCreated(new SeriesResult($series, [$this->booking()], ['2026-09-25' => 'taken']));
$records = $this->handler->getRecords();
self::assertCount(1, $records);
self::assertSame('Booking series created.', $records[0]->message);
self::assertSame(1, $records[0]->context['bookings_created']);
self::assertSame(['2026-09-25'], $records[0]->context['skipped_dates']);
}
/**
* Ending a series can delete it, and Doctrine nulls the id of a deleted entity -- so the id
* is passed in, and the record must use the one it was given.
*/
public function testAnEndedSeriesIsRecordedWithTheIdItHadBeforeItWasDeleted(): void
{
$series = new BookingSeries(
$this->user(),
$this->resource(),
RecurrenceRule::WEEKLY,
new \DateTimeImmutable('2026-09-18'),
new \DateTimeImmutable('2026-10-02'),
TimeRange::fromMinutes(540, 780),
);
$this->audit->seriesEnded($series, 42, new \DateTimeImmutable('2026-09-25'), 2);
$record = $this->record();
self::assertSame(42, $record->context['series_id']);
self::assertSame('2026-09-25', $record->context['ended_from']);
self::assertSame(2, $record->context['bookings_removed']);
}
public function testRetiringAResourceIsRecordedAsTheTransitionItIs(): void
{
$resource = $this->resource();
$resource->setGroup(new ResourceGroup(ResourceType::DESK, 'Room 1'));
$resource->setActive(false);
$this->audit->resourceUpdated($resource, true);
$record = $this->record();
self::assertSame('Resource updated.', $record->message);
self::assertTrue($record->context['was_active']);
self::assertFalse($record->context['active']);
self::assertSame('Room 1', $record->context['group']);
}
public function testADeletedResourceIsRecordedWithHowManyBookingsWentWithIt(): void
{
$this->audit->resourceDeleted(7, 'D1', ResourceType::DESK, 3);
$record = $this->record();
self::assertSame('Resource deleted.', $record->message);
self::assertSame(7, $record->context['resource_id']);
self::assertSame(3, $record->context['bookings_deleted']);
}
public function testASignInAndASignOutAreBothRecordedAgainstTheAccount(): void
{
$this->audit->signedIn($this->user());
$this->audit->signedOut($this->user());
$records = $this->handler->getRecords();
self::assertSame('User signed in.', $records[0]->message);
self::assertSame('[email protected]', $records[0]->context['account']);
self::assertSame('User signed out.', $records[1]->message);
self::assertSame('[email protected]', $records[1]->context['account']);
}
private function record(): LogRecord
{
return $this->handler->getRecords()[0];
}
private function booking(): Booking
{
return new Booking(
$this->user(),
$this->resource(),
new \DateTimeImmutable('2026-09-18'),
TimeRange::fromMinutes(540, 780),
);
}
private function user(): User
{
return new User('[email protected]', 'Holder');
}
private function resource(): Resource
{
return new Resource(ResourceType::DESK, 'D1');
}
}