Skip to content

Show deprovisioning event and date in the audit log #635

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
kayjoosten wants to merge 5 commits into
base: main
Choose a base branch
from
Open

Show deprovisioning event and date in the audit log #635

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
5 commits
Select commit Hold shift + click to select a range
783a9a3
Show deprovisioning event and date in the audit log
kayjoosten Aug 5, 2026
15a31b2
Include deprovisioned entries in the RA audit log query
kayjoosten Aug 10, 2026
3ad99dd
Add dedicated command to backfill deprovisioned audit log entries
kayjoosten Sep 7, 2026
c834623
Make deprovisioned audit projection idempotent
kayjoosten Sep 8, 2026
4f34fa1
Refactor deprovisioned backfill command
kayjoosten Sep 8, 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 src/Surfnet/StepupMiddleware/ApiBundle/Identity/Entity/AuditLogEntry.php
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -38,6 +38,7 @@
use Surfnet\Stepup\Identity\Event\IdentityAccreditedAsRaForInstitutionEvent;
use Surfnet\Stepup\Identity\Event\IdentityCreatedEvent;
use Surfnet\Stepup\Identity\Event\IdentityEmailChangedEvent;
use Surfnet\Stepup\Identity\Event\IdentityForgottenEvent;
use Surfnet\Stepup\Identity\Event\IdentityRenamedEvent;
use Surfnet\Stepup\Identity\Event\PhonePossessionProvenAndVerifiedEvent;
use Surfnet\Stepup\Identity\Event\PhonePossessionProvenEvent;
Expand Down Expand Up @@ -87,6 +88,7 @@ class AuditLogEntry implements JsonSerializable
GssfPossessionProvenAndVerifiedEvent::class => 'possession_proven',
IdentityCreatedEvent::class => 'created',
IdentityEmailChangedEvent::class => 'email_changed',
IdentityForgottenEvent::class => 'deprovisioned',

@johanib johanib Aug 24, 2026

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

IdentityRestoredEvent has no counterpart, so the log can end on "deprovisioned" for a live identity

Identity::restore() emits IdentityRestoredEvent, but it is absent from both $eventActionMap and AuditLogRepository::$secondFactorEvents. After this change an identity that was forgotten and later restored shows a terminal deprovisioned entry with nothing after it, which reads as "this account is gone" when it isn't. Pre-existing gap, but this change is what makes it visible.

Suggested approach: consider adding IdentityRestoredEvent::class => 'restored' to both maps in this PR (it needs an RA translation too, alongside the one already in OpenConext/Stepup-RA#531), or open a follow-up issue so it isn't lost.

@johanib johanib Sep 7, 2026

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@kayjoosten sounds like out of scope? Can you check, maybe create new ticket and refine?

@kayjoosten kayjoosten Sep 8, 2026

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Out of scope for this PR. Follow-up is tracked in #637: it covers adding the IdentityRestoredEvent => restored mapping, exposing it in the audit-log query allowlist, and lining that up with the RA-side translation work in OpenConext/Stepup-RA#531.

IdentityRenamedEvent::class => 'renamed',
PhonePossessionProvenEvent::class => 'possession_proven',
PhonePossessionProvenAndVerifiedEvent::class => 'possession_proven',
Expand Down
19 changes: 17 additions & 2 deletions src/Surfnet/StepupMiddleware/ApiBundle/Identity/Projector/AuditLogProjector.php
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -62,7 +62,11 @@ public function handle(DomainMessage $domainMessage): void

switch (true) {
case $event instanceof IdentityForgottenEvent:
// Don't insert the IdentityForgottenEvent into the audit log, as we'd remove it immediately afterwards.
// Record the deprovisioning entry first so applyIdentityForgottenEvent's re-query of
// findByIdentityId() picks it up too. The actor name is intentionally anonymized,
// consistent with all other entries for a forgotten identity. Anonymizing first
// would query before this entry exists, leaving its actor name untouched.
$this->applyAuditableEvent($event, $domainMessage);

@johanib johanib Aug 24, 2026

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Backfilling via stepup:event:replay is not idempotent and will duplicate entries

applyAuditableEvent() assigns a fresh Uuid::uuid4() per invocation and there is no dedupe on (identityId, event, recordedOn). Unlike middleware:event:replay, the stepup:event:replay command recommended in the PR description does not wipe read tables, so every run adds another deprovisioned row for every past IdentityForgottenEvent. Running it twice, or running it after new deprovisionings have already been projected live, silently corrupts the audit log that RA(A)s are supposed to trust.

Suggested approach: either make the projector skip creating an entry when one already exists for this identity + event, or replace the free-form backfill instruction with a one-shot, guarded console command (or SQL migration) that inserts only missing rows. At minimum, document the "run exactly once, before the new code starts projecting live events" constraint prominently — a checklist item in a test plan is not enough for a production runbook.

@kayjoosten kayjoosten Sep 7, 2026

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Backfill suggestion will do

$this->applyIdentityForgottenEvent($event);
break;
// Finally apply the auditable event, most events are auditable this so first handle the unique variants
Expand All @@ -79,6 +83,17 @@ public function handle(DomainMessage $domainMessage): void
private function applyAuditableEvent(AuditableEvent $event, DomainMessage $domainMessage): void
{
$auditLogMetadata = $event->getAuditLogMetadata();
$recordedOn = new DateTime(new CoreDateTime($domainMessage->getRecordedOn()->toString()));

if ($event instanceof IdentityForgottenEvent
&& $this->auditLogRepository->hasDeprovisionedEntry(
$auditLogMetadata->identityId,
$event::class,
$recordedOn,
)
) {
return;
}

$metadata = $domainMessage->getMetadata()->serialize();
$entry = new AuditLogEntry();
Expand Down Expand Up @@ -109,7 +124,7 @@ private function applyAuditableEvent(AuditableEvent $event, DomainMessage $domai
$entry->identityId = (string)$auditLogMetadata->identityId;
$entry->identityInstitution = $auditLogMetadata->identityInstitution;
$entry->event = $event::class;
$entry->recordedOn = new DateTime(new CoreDateTime($domainMessage->getRecordedOn()->toString()));
$entry->recordedOn = $recordedOn;

if ($auditLogMetadata->secondFactorId instanceof SecondFactorId) {
$entry->secondFactorId = (string)$auditLogMetadata->secondFactorId;
Expand Down
25 changes: 25 additions & 0 deletions src/Surfnet/StepupMiddleware/ApiBundle/Identity/Repository/AuditLogRepository.php
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -21,6 +21,7 @@
use Doctrine\Bundle\DoctrineBundle\Repository\ServiceEntityRepository;
use Doctrine\ORM\Query;
use Doctrine\Persistence\ManagerRegistry;
use Surfnet\Stepup\DateTime\DateTime;
use Surfnet\Stepup\Identity\Event\AppointedAsRaaEvent;
use Surfnet\Stepup\Identity\Event\AppointedAsRaaForInstitutionEvent;
use Surfnet\Stepup\Identity\Event\AppointedAsRaEvent;
Expand All @@ -36,6 +37,7 @@
use Surfnet\Stepup\Identity\Event\IdentityAccreditedAsRaaForInstitutionEvent;
use Surfnet\Stepup\Identity\Event\IdentityAccreditedAsRaEvent;
use Surfnet\Stepup\Identity\Event\IdentityAccreditedAsRaForInstitutionEvent;
use Surfnet\Stepup\Identity\Event\IdentityForgottenEvent;
use Surfnet\Stepup\Identity\Event\PhonePossessionProvenAndVerifiedEvent;
use Surfnet\Stepup\Identity\Event\PhonePossessionProvenEvent;
use Surfnet\Stepup\Identity\Event\PhoneRecoveryTokenPossessionProvenEvent;
Expand All @@ -53,6 +55,7 @@
use Surfnet\Stepup\Identity\Event\YubikeyPossessionProvenAndVerifiedEvent;
use Surfnet\Stepup\Identity\Event\YubikeySecondFactorBootstrappedEvent;
use Surfnet\Stepup\Identity\Value\IdentityId;
use Surfnet\StepupMiddleware\ApiBundle\Doctrine\Type\DateTimeType;
use Surfnet\StepupMiddleware\ApiBundle\Exception\RuntimeException;
use Surfnet\StepupMiddleware\ApiBundle\Identity\Entity\AuditLogEntry;
use Surfnet\StepupMiddleware\ApiBundle\Identity\Query\SecondFactorAuditLogQuery;
Expand Down Expand Up @@ -104,6 +107,7 @@ public function __construct(ManagerRegistry $registry)
RecoveryTokenRevokedEvent::class,
PhoneRecoveryTokenPossessionProvenEvent::class,
CompliedWithRecoveryCodeRevocationEvent::class,
IdentityForgottenEvent::class,
];

/**
Expand Down Expand Up @@ -164,6 +168,27 @@ public function findByIdentityId(IdentityId $identityId): array
->getResult();
}

/**
* Whether an audit log entry already exists for the given identity, event FQCN and moment.
*
* Used by the deprovisioned-entry backfill to stay idempotent. recordedOn is stored with
* second precision, and an identity cannot be forgotten twice within the same second (a
* restore has to happen in between), so this uniquely identifies a single deprovisioning.
*/
public function hasDeprovisionedEntry(IdentityId $identityId, string $event, DateTime $recordedOn): bool
{
return (int)$this->createQueryBuilder('al')
->select('COUNT(al.id)')
->where('al.identityId = :identityId')
->andWhere('al.event = :event')
->andWhere('al.recordedOn = :recordedOn')
->setParameter('identityId', $identityId)
->setParameter('event', $event)
->setParameter('recordedOn', $recordedOn, DateTimeType::NAME)
->getQuery()
->getSingleScalarResult() > 0;
}

public function save(AuditLogEntry $entry): void
{
$entityManager = $this->getEntityManager();
Expand Down
139 changes: 139 additions & 0 deletions src/Surfnet/StepupMiddleware/ApiBundle/Tests/Identity/Projector/AuditLogProjectorTest.php
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -31,6 +31,7 @@
use PHPUnit\Framework\TestCase;
use Surfnet\Stepup\DateTime\DateTime as StepupDateTime;
use Surfnet\Stepup\Identity\AuditLog\Metadata;
use Surfnet\Stepup\Identity\Event\IdentityForgottenEvent;
use Surfnet\Stepup\Identity\Value\CommonName;
use Surfnet\Stepup\Identity\Value\IdentityId;
use Surfnet\Stepup\Identity\Value\Institution;
Expand Down Expand Up @@ -167,6 +168,144 @@ public function it_creates_entries_for_auditable_events(DomainMessage $message,
$this->assertEquals($expectedEntry, $actualEntry);
}

#[Test]
#[Group('api-projector')]
public function it_creates_a_deprovisioned_entry_and_anonymizes_the_identitys_other_entries(): void
{
$identityId = new IdentityId('abcd');
$institution = new Institution('efgh');

$existingEntry = new AuditLogEntry();
$existingEntry->id = 'existing-entry';
$existingEntry->identityId = $identityId;
$existingEntry->identityInstitution = $institution;
$existingEntry->actorCommonName = new CommonName(self::$actorCommonName);
$existingEntry->event = 'SomeEarlierEvent';
$existingEntry->recordedOn = new StepupDateTime(new CoreDateTime('1970-01-01H00:00:00.000'));

$entryWhereIdentityIsActor = new AuditLogEntry();
$entryWhereIdentityIsActor->id = 'actor-entry';
$entryWhereIdentityIsActor->identityId = new IdentityId('some-other-identity');
$entryWhereIdentityIsActor->identityInstitution = $institution;
$entryWhereIdentityIsActor->actorId = $identityId;
$entryWhereIdentityIsActor->actorCommonName = new CommonName(self::$actorCommonName);
$entryWhereIdentityIsActor->event = 'SomeEarlierEvent';
$entryWhereIdentityIsActor->recordedOn = new StepupDateTime(new CoreDateTime('1970-01-01H00:00:00.000'));

$repository = m::mock(AuditLogRepository::class);

$newEntry = null;
$repository->shouldReceive('hasDeprovisionedEntry')
->once()
->with(
$identityId,
IdentityForgottenEvent::class,
m::on(fn(StepupDateTime $actual): bool => $actual == new StepupDateTime(new CoreDateTime('1970-01-01H00:00:00.000'))),
)
->andReturnFalse();
$repository->shouldReceive('save')->once()->with($this->spy($newEntry));
/** @var null|AuditLogEntry $newEntry */

// The new entry is flushed (AuditLogRepository::save() flushes immediately) before this is
// called, so a real findByIdentityId() re-query picks it up alongside the pre-existing entry.
$repository->shouldReceive('findByIdentityId')->once()->with($identityId)
->andReturnUsing(function () use ($existingEntry, &$newEntry): array {
return [$existingEntry, $newEntry];
});
$repository->shouldReceive('findEntriesWhereIdentityIsActorOnly')->once()->with($identityId)
->andReturn([$entryWhereIdentityIsActor]);
$repository->shouldReceive('saveAll')->once()->with(
m::on(function (array $entries) use ($existingEntry, &$newEntry): bool {
return $entries === [$existingEntry, $newEntry];
}),
);
$repository->shouldReceive('saveAll')->once()->with([$entryWhereIdentityIsActor]);

$identityRepository = m::mock(IdentityRepository::class);

$projector = new AuditLogProjector($repository, $identityRepository);

$message = new DomainMessage(
'id',
0,
new MessageMetadata(),
new IdentityForgottenEvent($identityId, $institution),
BroadwayDateTime::fromString('1970-01-01H00:00:00.000'),
);

$projector->handle($message);

// A new "deprovisioned" audit log entry must have been created for the identity.
$this->assertNotNull($newEntry);
$this->assertSame((string)$identityId, $newEntry->identityId);
$this->assertSame($institution, $newEntry->identityInstitution);
$this->assertSame(IdentityForgottenEvent::class, $newEntry->event);

// Pre-existing entries for the identity must still be anonymized, same as before this change.
$this->assertEquals(CommonName::unknown(), $existingEntry->actorCommonName);
$this->assertEquals(CommonName::unknown(), $entryWhereIdentityIsActor->actorCommonName);

// The new "deprovisioned" entry is swept up by the same anonymization pass, since it belongs
// to the identity being forgotten.
$this->assertEquals(CommonName::unknown(), $newEntry->actorCommonName);
}

#[Test]
#[Group('api-projector')]
public function it_skips_creating_a_duplicate_deprovisioned_entry_but_still_anonymizes_existing_entries(): void
{
$identityId = new IdentityId('abcd');
$institution = new Institution('efgh');
$recordedOn = new StepupDateTime(new CoreDateTime('1970-01-01H00:00:00.000'));

$existingEntry = new AuditLogEntry();
$existingEntry->id = 'existing-entry';
$existingEntry->identityId = $identityId;
$existingEntry->identityInstitution = $institution;
$existingEntry->actorCommonName = new CommonName(self::$actorCommonName);
$existingEntry->event = IdentityForgottenEvent::class;
$existingEntry->recordedOn = $recordedOn;

$entryWhereIdentityIsActor = new AuditLogEntry();
$entryWhereIdentityIsActor->id = 'actor-entry';
$entryWhereIdentityIsActor->identityId = new IdentityId('some-other-identity');
$entryWhereIdentityIsActor->identityInstitution = $institution;
$entryWhereIdentityIsActor->actorId = $identityId;
$entryWhereIdentityIsActor->actorCommonName = new CommonName(self::$actorCommonName);
$entryWhereIdentityIsActor->event = 'SomeEarlierEvent';
$entryWhereIdentityIsActor->recordedOn = $recordedOn;

$repository = m::mock(AuditLogRepository::class);
$repository->shouldReceive('hasDeprovisionedEntry')
->once()
->with(
$identityId,
IdentityForgottenEvent::class,
m::on(fn(StepupDateTime $actual): bool => $actual == $recordedOn),
)
->andReturnTrue();
$repository->shouldNotReceive('save');
$repository->shouldReceive('findByIdentityId')->once()->with($identityId)->andReturn([$existingEntry]);
$repository->shouldReceive('findEntriesWhereIdentityIsActorOnly')->once()->with($identityId)
->andReturn([$entryWhereIdentityIsActor]);
$repository->shouldReceive('saveAll')->once()->with([$existingEntry]);
$repository->shouldReceive('saveAll')->once()->with([$entryWhereIdentityIsActor]);

$identityRepository = m::mock(IdentityRepository::class);

$projector = new AuditLogProjector($repository, $identityRepository);
$projector->handle(new DomainMessage(
'id',
0,
new MessageMetadata(),
new IdentityForgottenEvent($identityId, $institution),
BroadwayDateTime::fromString('1970-01-01H00:00:00.000'),
));

$this->assertEquals(CommonName::unknown(), $existingEntry->actorCommonName);
$this->assertEquals(CommonName::unknown(), $entryWhereIdentityIsActor->actorCommonName);
}

private function createAuditLogMetadata(
IdentityId $identityId,
Institution $institution,
Expand Down
Loading