fix: never persist a half-built user on first login
This commit is contained in:
@@ -4,8 +4,8 @@ declare(strict_types=1);
|
|||||||
|
|
||||||
namespace App\Logger;
|
namespace App\Logger;
|
||||||
|
|
||||||
use App\Entity\LogEntry;
|
use Doctrine\DBAL\Connection;
|
||||||
use Doctrine\ORM\EntityManagerInterface;
|
use Doctrine\DBAL\Types\Types;
|
||||||
use Monolog\Handler\AbstractProcessingHandler;
|
use Monolog\Handler\AbstractProcessingHandler;
|
||||||
use Monolog\Level;
|
use Monolog\Level;
|
||||||
use Monolog\LogRecord;
|
use Monolog\LogRecord;
|
||||||
@@ -13,30 +13,40 @@ use Monolog\LogRecord;
|
|||||||
/**
|
/**
|
||||||
* Monolog handler that persists log entries to the database.
|
* Monolog handler that persists log entries to the database.
|
||||||
*
|
*
|
||||||
* Writes log records to the LogEntry entity, replacing message placeholders
|
* Writes log records to the log_entry table, replacing message placeholders
|
||||||
* with context values. Includes channel, context, and extra data for auditing.
|
* with context values. Includes channel, context, and extra data for auditing.
|
||||||
* Only processes INFO level and above to avoid storing debug messages.
|
* Only processes INFO level and above to avoid storing debug messages.
|
||||||
|
*
|
||||||
|
* The write goes through the DBAL connection rather than the EntityManager on purpose. A log record
|
||||||
|
* can be emitted at any point, including halfway through somebody else's unit of work, and an
|
||||||
|
* EntityManager flush would write out whatever that unit of work has pending so far — which is how
|
||||||
|
* a half-built User once reached the database with a NULL password. Staying out of the UnitOfWork
|
||||||
|
* also keeps logging alive after a failed flush has closed the EntityManager, which is exactly when
|
||||||
|
* there is something worth logging.
|
||||||
|
*
|
||||||
|
* Reads still go through the LogEntry entity and its repository.
|
||||||
*/
|
*/
|
||||||
class DatabaseHandler extends AbstractProcessingHandler
|
class DatabaseHandler extends AbstractProcessingHandler
|
||||||
{
|
{
|
||||||
public function __construct(private readonly EntityManagerInterface $entityManager)
|
public function __construct(private readonly Connection $connection)
|
||||||
{
|
{
|
||||||
parent::__construct(Level::Info);
|
parent::__construct(Level::Info);
|
||||||
}
|
}
|
||||||
|
|
||||||
protected function write(LogRecord $record): void
|
protected function write(LogRecord $record): void
|
||||||
{
|
{
|
||||||
$message = $this->replacePlaceHolder($record);
|
$this->connection->insert('log_entry', [
|
||||||
|
'channel' => $record->channel,
|
||||||
$logEntry = new LogEntry($record->channel, $message);
|
'message' => $this->replacePlaceHolder($record),
|
||||||
$logEntry
|
'context' => $record->context,
|
||||||
->setContext($record->context)
|
'extra' => $record->extra,
|
||||||
->setExtra($record->extra)
|
'error_code' => $record->extra['error_code'] ?? null,
|
||||||
->setErrorCode($record->extra['error_code'] ?? null)
|
'created_at' => new \DateTimeImmutable('now'),
|
||||||
;
|
], [
|
||||||
|
'context' => Types::JSON,
|
||||||
$this->entityManager->persist($logEntry);
|
'extra' => Types::JSON,
|
||||||
$this->entityManager->flush();
|
'created_at' => Types::DATETIME_IMMUTABLE,
|
||||||
|
]);
|
||||||
}
|
}
|
||||||
|
|
||||||
private function replacePlaceHolder(LogRecord $record): string
|
private function replacePlaceHolder(LogRecord $record): string
|
||||||
|
|||||||
@@ -106,13 +106,7 @@ class BpnAuthenticator extends AbstractLoginFormAuthenticator implements Authent
|
|||||||
|
|
||||||
$userRepository = $this->entityManager->getRepository(User::class);
|
$userRepository = $this->entityManager->getRepository(User::class);
|
||||||
|
|
||||||
if (null === $user = $userRepository->findOneBy(['email' => $email])) {
|
$user = $userRepository->findOneBy(['email' => $email]) ?? new User($email);
|
||||||
$user = new User($email);
|
|
||||||
|
|
||||||
$this->entityManager->persist($user);
|
|
||||||
}
|
|
||||||
|
|
||||||
$this->syncFromCrm($user, $crmAttributes);
|
|
||||||
|
|
||||||
$user
|
$user
|
||||||
->setPassword($encryptedPassword)
|
->setPassword($encryptedPassword)
|
||||||
@@ -124,6 +118,13 @@ class BpnAuthenticator extends AbstractLoginFormAuthenticator implements Authent
|
|||||||
->setProfileComplete($this->completenessChecker->isComplete($personalData))
|
->setProfileComplete($this->completenessChecker->isComplete($personalData))
|
||||||
;
|
;
|
||||||
|
|
||||||
|
$this->syncFromCrm($user, $crmAttributes);
|
||||||
|
|
||||||
|
// Registered only once it is fully populated: syncFromCrm() logs on a channel that writes
|
||||||
|
// to the database, and an account already managed at that point would be flushed
|
||||||
|
// half-built — which is how a NULL password used to reach the user table. A no-op for an
|
||||||
|
// account that came from the repository.
|
||||||
|
$this->entityManager->persist($user);
|
||||||
$this->entityManager->flush();
|
$this->entityManager->flush();
|
||||||
|
|
||||||
return $user;
|
return $user;
|
||||||
|
|||||||
@@ -0,0 +1,153 @@
|
|||||||
|
<?php
|
||||||
|
|
||||||
|
declare(strict_types=1);
|
||||||
|
|
||||||
|
namespace App\Tests\Logger;
|
||||||
|
|
||||||
|
use App\Entity\LogEntry;
|
||||||
|
use App\Logger\DatabaseHandler;
|
||||||
|
use Doctrine\DBAL\Connection;
|
||||||
|
use Doctrine\ORM\Mapping\ClassMetadata;
|
||||||
|
use Doctrine\ORM\Mapping\Driver\AttributeDriver;
|
||||||
|
use Doctrine\ORM\Mapping\UnderscoreNamingStrategy;
|
||||||
|
use Doctrine\Persistence\Mapping\RuntimeReflectionService;
|
||||||
|
use Doctrine\Persistence\ObjectManager;
|
||||||
|
use Monolog\Level;
|
||||||
|
use Monolog\LogRecord;
|
||||||
|
use PHPUnit\Framework\TestCase;
|
||||||
|
|
||||||
|
/**
|
||||||
|
* The handler writes through the DBAL connection instead of the EntityManager, so the column names
|
||||||
|
* are spelled out by hand here and can drift away from the LogEntry mapping. These tests pin them
|
||||||
|
* to the mapping, and pin the handler to the connection.
|
||||||
|
*/
|
||||||
|
class DatabaseHandlerTest extends TestCase
|
||||||
|
{
|
||||||
|
public function testTheHandlerStaysOutOfTheUnitOfWork(): void
|
||||||
|
{
|
||||||
|
// A log record can be emitted halfway through somebody else's unit of work. Flushing an
|
||||||
|
// EntityManager here would write out whatever that unit of work has pending, which is how
|
||||||
|
// a half-built User once reached the database with a NULL password.
|
||||||
|
$parameters = (new \ReflectionMethod(DatabaseHandler::class, '__construct'))->getParameters();
|
||||||
|
|
||||||
|
foreach ($parameters as $parameter) {
|
||||||
|
$type = $parameter->getType();
|
||||||
|
|
||||||
|
self::assertInstanceOf(\ReflectionNamedType::class, $type);
|
||||||
|
self::assertNotSame(ObjectManager::class, $type->getName());
|
||||||
|
self::assertFalse(
|
||||||
|
is_a($type->getName(), ObjectManager::class, true),
|
||||||
|
'the handler must not be able to flush anybody else’s entities',
|
||||||
|
);
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
public function testTheWrittenColumnsMatchTheLogEntryMapping(): void
|
||||||
|
{
|
||||||
|
$handler = new DatabaseHandler($this->connection($table, $data, $types));
|
||||||
|
|
||||||
|
$handler->handle($this->record('auth', 'Login', ['email' => '[email protected]']));
|
||||||
|
|
||||||
|
$metadata = $this->logEntryMetadata();
|
||||||
|
|
||||||
|
self::assertSame($metadata->getTableName(), $table);
|
||||||
|
self::assertSame([], array_diff(array_keys($data), $metadata->getColumnNames()));
|
||||||
|
|
||||||
|
// Everything the table requires has to be supplied: no default fills these in, and the id
|
||||||
|
// is the only column the database generates itself.
|
||||||
|
$required = array_diff($metadata->getColumnNames(), ['id']);
|
||||||
|
foreach ($required as $column) {
|
||||||
|
self::assertArrayHasKey($column, $data);
|
||||||
|
}
|
||||||
|
|
||||||
|
self::assertSame([], array_diff(array_keys($types), array_keys($data)));
|
||||||
|
}
|
||||||
|
|
||||||
|
public function testTheRecordIsWrittenAsIs(): void
|
||||||
|
{
|
||||||
|
$handler = new DatabaseHandler($this->connection($table, $data, $types));
|
||||||
|
|
||||||
|
$handler->handle($this->record('bpn', 'Request failed', ['request_id' => 'r-1'], ['error_code' => '853']));
|
||||||
|
|
||||||
|
self::assertSame('bpn', $data['channel']);
|
||||||
|
self::assertSame('Request failed', $data['message']);
|
||||||
|
self::assertSame(['request_id' => 'r-1'], $data['context']);
|
||||||
|
self::assertSame(['error_code' => '853'], $data['extra']);
|
||||||
|
self::assertSame('853', $data['error_code']);
|
||||||
|
self::assertInstanceOf(\DateTimeImmutable::class, $data['created_at']);
|
||||||
|
}
|
||||||
|
|
||||||
|
public function testPlaceholdersAreReplacedFromTheContext(): void
|
||||||
|
{
|
||||||
|
$handler = new DatabaseHandler($this->connection($table, $data, $types));
|
||||||
|
|
||||||
|
$handler->handle($this->record('core', 'Booking {id} confirmed', ['id' => '4711']));
|
||||||
|
|
||||||
|
self::assertSame('Booking 4711 confirmed', $data['message']);
|
||||||
|
}
|
||||||
|
|
||||||
|
public function testAnErrorCodeIsOptional(): void
|
||||||
|
{
|
||||||
|
$handler = new DatabaseHandler($this->connection($table, $data, $types));
|
||||||
|
|
||||||
|
$handler->handle($this->record('core', 'Login'));
|
||||||
|
|
||||||
|
self::assertNull($data['error_code']);
|
||||||
|
}
|
||||||
|
|
||||||
|
public function testDebugRecordsAreNotWritten(): void
|
||||||
|
{
|
||||||
|
$connection = $this->createMock(Connection::class);
|
||||||
|
$connection->expects(self::never())->method('insert');
|
||||||
|
|
||||||
|
$handler = new DatabaseHandler($connection);
|
||||||
|
|
||||||
|
$handler->handle($this->record('core', 'Noise', level: Level::Debug));
|
||||||
|
}
|
||||||
|
|
||||||
|
/**
|
||||||
|
* @param array<string, mixed>|null $data
|
||||||
|
* @param array<string, mixed>|null $types
|
||||||
|
*/
|
||||||
|
private function connection(?string &$table, ?array &$data, ?array &$types): Connection
|
||||||
|
{
|
||||||
|
$connection = $this->createMock(Connection::class);
|
||||||
|
$connection
|
||||||
|
->method('insert')
|
||||||
|
->willReturnCallback(
|
||||||
|
static function (string $insertTable, array $insertData, array $insertTypes) use (&$table, &$data, &$types): int {
|
||||||
|
$table = $insertTable;
|
||||||
|
$data = $insertData;
|
||||||
|
$types = $insertTypes;
|
||||||
|
|
||||||
|
return 1;
|
||||||
|
}
|
||||||
|
)
|
||||||
|
;
|
||||||
|
|
||||||
|
return $connection;
|
||||||
|
}
|
||||||
|
|
||||||
|
/**
|
||||||
|
* @param array<string, mixed> $context
|
||||||
|
* @param array<string, mixed> $extra
|
||||||
|
*/
|
||||||
|
private function record(string $channel, string $message, array $context = [], array $extra = [], Level $level = Level::Info): LogRecord
|
||||||
|
{
|
||||||
|
return new LogRecord(new \DateTimeImmutable(), $channel, $level, $message, $context, $extra);
|
||||||
|
}
|
||||||
|
|
||||||
|
/**
|
||||||
|
* @return ClassMetadata<LogEntry>
|
||||||
|
*/
|
||||||
|
private function logEntryMetadata(): ClassMetadata
|
||||||
|
{
|
||||||
|
/** @var ClassMetadata<LogEntry> $metadata */
|
||||||
|
$metadata = new ClassMetadata(LogEntry::class, new UnderscoreNamingStrategy(CASE_LOWER, true));
|
||||||
|
$metadata->initializeReflection(new RuntimeReflectionService());
|
||||||
|
|
||||||
|
(new AttributeDriver([dirname(__DIR__, 2).'/src/Entity']))->loadMetadataForClass(LogEntry::class, $metadata);
|
||||||
|
|
||||||
|
return $metadata;
|
||||||
|
}
|
||||||
|
}
|
||||||
@@ -56,7 +56,7 @@ class BpnAuthenticatorTest extends TestCase
|
|||||||
|
|
||||||
$user = $this->loadUser($authenticator);
|
$user = $this->loadUser($authenticator);
|
||||||
|
|
||||||
self::assertNull($persisted, 'an existing account must not be persisted again');
|
self::assertSame($existing, $persisted, 'a login must not create a second account');
|
||||||
self::assertSame(
|
self::assertSame(
|
||||||
['ROLE_USER', Role::TEAMER, Role::pending(Role::GROUPS_ADMIN)],
|
['ROLE_USER', Role::TEAMER, Role::pending(Role::GROUPS_ADMIN)],
|
||||||
$user->getRoles(),
|
$user->getRoles(),
|
||||||
@@ -159,6 +159,27 @@ class BpnAuthenticatorTest extends TestCase
|
|||||||
self::assertSame(['ROLE_USER', Role::CUSTOMER], $this->loadUser($authenticator)->getRoles());
|
self::assertSame(['ROLE_USER', Role::CUSTOMER], $this->loadUser($authenticator)->getRoles());
|
||||||
}
|
}
|
||||||
|
|
||||||
|
public function testANewAccountIsOnlyRegisteredOnceItCarriesItsPassword(): void
|
||||||
|
{
|
||||||
|
$persisted = null;
|
||||||
|
$persistedPassword = null;
|
||||||
|
|
||||||
|
// A degraded payload is what makes syncFromCrm() log, and that log write reaches the
|
||||||
|
// database. An account registered before the profile is complete would be written out
|
||||||
|
// half-built, and the user table rejects it: password is NOT NULL.
|
||||||
|
$authenticator = $this->authenticator(
|
||||||
|
$this->crmAttributes([], [], selectionGroups: []),
|
||||||
|
null,
|
||||||
|
$persisted,
|
||||||
|
$persistedPassword,
|
||||||
|
);
|
||||||
|
|
||||||
|
$this->loadUser($authenticator);
|
||||||
|
|
||||||
|
self::assertInstanceOf(User::class, $persisted);
|
||||||
|
self::assertSame('encrypted', $persistedPassword);
|
||||||
|
}
|
||||||
|
|
||||||
/**
|
/**
|
||||||
* @param string[] $roles
|
* @param string[] $roles
|
||||||
* @param string[] $hotelCodes
|
* @param string[] $hotelCodes
|
||||||
@@ -175,8 +196,12 @@ class BpnAuthenticatorTest extends TestCase
|
|||||||
return $attributes;
|
return $attributes;
|
||||||
}
|
}
|
||||||
|
|
||||||
private function authenticator(CrmAttributes $crmAttributes, ?User $existing, ?User &$persisted): BpnAuthenticator
|
private function authenticator(
|
||||||
{
|
CrmAttributes $crmAttributes,
|
||||||
|
?User $existing,
|
||||||
|
?User &$persisted,
|
||||||
|
?string &$persistedPassword = null,
|
||||||
|
): BpnAuthenticator {
|
||||||
$personalData = new PersonalData();
|
$personalData = new PersonalData();
|
||||||
$personalData->personId = 42;
|
$personalData->personId = 42;
|
||||||
$personalData->addressId = 4711;
|
$personalData->addressId = 4711;
|
||||||
@@ -192,8 +217,11 @@ class BpnAuthenticatorTest extends TestCase
|
|||||||
$entityManager->method('getRepository')->willReturn($repository);
|
$entityManager->method('getRepository')->willReturn($repository);
|
||||||
$entityManager
|
$entityManager
|
||||||
->method('persist')
|
->method('persist')
|
||||||
->willReturnCallback(static function (object $entity) use (&$persisted): void {
|
->willReturnCallback(static function (object $entity) use (&$persisted, &$persistedPassword): void {
|
||||||
$persisted = $entity;
|
$persisted = $entity;
|
||||||
|
// Snapshot rather than a reference: what matters is what the account looked like
|
||||||
|
// at the moment it was registered, not what it grew into afterwards.
|
||||||
|
$persistedPassword = $entity instanceof User ? $entity->getPassword() : null;
|
||||||
})
|
})
|
||||||
;
|
;
|
||||||
|
|
||||||
|
|||||||
Reference in New Issue
Block a user