From 6a6d3eb24975fc7984dd1a80516aa94d5f68c700 Mon Sep 17 00:00:00 2001 From: Jose Andres Tejerina Date: Tue, 19 May 2026 12:09:30 -0300 Subject: [PATCH] fix: reduces update logs that contain no actual changes --- app/Audit/AbstractAuditLogFormatter.php | 53 ++++++++- app/Audit/AuditLogOtlpStrategy.php | 11 +- ...AbstractAuditLogFormatterDateNoiseTest.php | 108 ++++++++++++++++++ ...itLogFormatterHasMeaningfulChangesTest.php | 100 ++++++++++++++++ ...uditLogOtlpStrategyNoOpSuppressionTest.php | 93 +++++++++++++++ 5 files changed, 362 insertions(+), 3 deletions(-) create mode 100644 tests/Unit/Audit/AbstractAuditLogFormatterDateNoiseTest.php create mode 100644 tests/Unit/Audit/AbstractAuditLogFormatterHasMeaningfulChangesTest.php create mode 100644 tests/Unit/Audit/AuditLogOtlpStrategyNoOpSuppressionTest.php diff --git a/app/Audit/AbstractAuditLogFormatter.php b/app/Audit/AbstractAuditLogFormatter.php index 005d34575..86e88d0a9 100644 --- a/app/Audit/AbstractAuditLogFormatter.php +++ b/app/Audit/AbstractAuditLogFormatter.php @@ -22,6 +22,7 @@ abstract class AbstractAuditLogFormatter implements IAuditLogFormatter { protected ?AuditContext $ctx = null; protected string $event_type; + public const NO_CHANGES_REGISTERED_MESSAGE = 'properties without changes registered'; public function __construct(string $event_type) { @@ -178,21 +179,71 @@ protected function buildChangeDetails(array $change_set): string } if (empty($changed_fields)) { - return 'properties without changes registered'; + return self::NO_CHANGES_REGISTERED_MESSAGE; } $fields_summary = count($changed_fields) . ' field(s) modified: '; return $fields_summary . implode(' | ', $changed_fields); } + + final public function hasMeaningfulChanges(array $change_set): bool + { + $ignored_fields = $this->getIgnoredFields(); + + foreach ($change_set as $prop_name => $change_values) { + if (in_array($prop_name, $ignored_fields)) { + continue; + } + + $old_value = $change_values[0] ?? null; + $new_value = $change_values[1] ?? null; + + if ($this->formatFieldChange($prop_name, $old_value, $new_value) !== null) { + return true; + } + } + + return false; + } + protected function formatFieldChange(string $prop_name, $old_value, $new_value): ?string { + if ($this->valuesAreEffectivelyEqual($old_value, $new_value)) { + return null; + } + $old_display = $this->formatChangeValue($old_value); $new_display = $this->formatChangeValue($new_value); return sprintf("Property \"%s\" has changed from \"%s\" to \"%s\"", $prop_name, $old_display, $new_display); } + protected function valuesAreEffectivelyEqual($old_value, $new_value): bool + { + if ($old_value === $new_value) { + return true; + } + + if ($old_value instanceof \DateTimeInterface && $new_value instanceof \DateTimeInterface) { + if ($old_value->getTimestamp() === $new_value->getTimestamp()) { + return true; + } + + try { + return $old_value->format('U.u') === $new_value->format('U.u'); + } catch (\Throwable $e) { + return false; + } + } + + if ((is_scalar($old_value) || is_null($old_value)) && (is_scalar($new_value) || is_null($new_value))) { + return $this->formatChangeValue($old_value) === $this->formatChangeValue($new_value); + } + + return false; + } + /** * Format detailed message for many-to-many collection changes */ diff --git a/app/Audit/AuditLogOtlpStrategy.php b/app/Audit/AuditLogOtlpStrategy.php index 1da61a7d8..757994dab 100644 --- a/app/Audit/AuditLogOtlpStrategy.php +++ b/app/Audit/AuditLogOtlpStrategy.php @@ -50,7 +50,7 @@ public function audit($subject, array $change_set, string $event_type, AuditCon return; } Log::debug("AuditLogOtlpStrategy::audit", ['subject' => $subject, 'change_set' => $change_set, 'event_type' => $event_type]); - try { + try { $entity = $this->resolveAuditableEntity($subject); if (is_null($entity)) { Log::warning("AuditLogOtlpStrategy::audit subject not found"); @@ -62,6 +62,13 @@ public function audit($subject, array $change_set, string $event_type, AuditCon Log::warning("AuditLogOtlpStrategy::audit formatter not found"); return; } + if ($event_type === IAuditStrategy::EVENT_ENTITY_UPDATE + && !$formatter->hasMeaningfulChanges($change_set)) { + Log::debug("AuditLogOtlpStrategy::audit skipping no-op entity update", [ + 'subject_class' => is_object($subject) ? get_class($subject) : gettype($subject), + ]); + return; + } $description = $formatter->format($subject, $change_set); if(is_null($description)){ Log::warning("AuditLogOtlpStrategy::audit description is empty"); @@ -76,7 +83,7 @@ public function audit($subject, array $change_set, string $event_type, AuditCon job: $job, ); Log::debug("AuditLogOtlpStrategy::audit entry sent to OTEL", ["user_id" => $ctx->userId, "user_email" => $ctx->userEmail]); - + } catch (\Exception $ex) { Log::error('OTEL audit logging error: ' . $ex->getMessage(), [ 'exception' => $ex, diff --git a/tests/Unit/Audit/AbstractAuditLogFormatterDateNoiseTest.php b/tests/Unit/Audit/AbstractAuditLogFormatterDateNoiseTest.php new file mode 100644 index 000000000..4b5a3ee6a --- /dev/null +++ b/tests/Unit/Audit/AbstractAuditLogFormatterDateNoiseTest.php @@ -0,0 +1,108 @@ +publicBuildChangeDetails([ + 'submission_begin_date' => [$oldUtc, $newLocalSameSecond], + ]); + + $this->assertSame('properties without changes registered', $details); + $this->assertFalse($formatter->hasMeaningfulChanges([ + 'submission_begin_date' => [$oldUtc, $newLocalSameSecond], + ])); + } + + public function testBuildChangeDetailsIgnoresMultipleDateFieldsWithSameInstant(): void + { + $formatter = new ExposingAuditFormatter(IAuditStrategy::EVENT_ENTITY_UPDATE); + + $old = new DateTime('2025-07-02 07:00:00', new DateTimeZone('UTC')); + $newSame = new DateTime('2025-07-02 07:00:00', new DateTimeZone('UTC')); + + $details = $formatter->publicBuildChangeDetails([ + 'submission_begin_date' => [$old, $newSame], + 'submission_end_date' => [$old, $newSame], + 'selection_begin_date' => [$old, $newSame], + 'selection_end_date' => [$old, $newSame], + ]); + + $this->assertSame('properties without changes registered', $details); + } + + public function testBuildChangeDetailsStillShowsRealDateTimeChange(): void + { + $formatter = new ExposingAuditFormatter(IAuditStrategy::EVENT_ENTITY_UPDATE); + + $old = new DateTime('2026-01-02 03:04:05', new DateTimeZone('UTC')); + $new = new DateTime('2026-01-02 03:04:06', new DateTimeZone('UTC')); + + $details = $formatter->publicBuildChangeDetails([ + 'submission_begin_date' => [$old, $new], + ]); + + $this->assertStringContainsString('submission_begin_date', $details); + $this->assertStringContainsString('03:04:05', $details); + $this->assertStringContainsString('03:04:06', $details); + $this->assertTrue($formatter->hasMeaningfulChanges([ + 'submission_begin_date' => [$old, $new], + ])); + } + + public function testBuildChangeDetailsKeepsOtherNonDateChanges(): void + { + $formatter = new ExposingAuditFormatter(IAuditStrategy::EVENT_ENTITY_UPDATE); + + $oldUtc = new DateTime('2026-01-02 03:04:05', new DateTimeZone('UTC')); + $newLocalSameSecond = new DateTime('2026-01-02 00:04:05', new DateTimeZone('America/Argentina/Buenos_Aires')); + + $details = $formatter->publicBuildChangeDetails([ + 'submission_begin_date' => [$oldUtc, $newLocalSameSecond], + 'name' => ['Old', 'New'], + ]); + + $this->assertStringContainsString('1 field(s) modified', $details); + $this->assertStringContainsString('Property "name" has changed', $details); + $this->assertStringNotContainsString('submission_begin_date', $details); + } +} + +final class ExposingAuditFormatter extends AbstractAuditLogFormatter +{ + public function publicBuildChangeDetails(array $change_set): string + { + return $this->buildChangeDetails($change_set); + } + + public function format(mixed $subject, array $change_set): ?string + { + return null; + } +} diff --git a/tests/Unit/Audit/AbstractAuditLogFormatterHasMeaningfulChangesTest.php b/tests/Unit/Audit/AbstractAuditLogFormatterHasMeaningfulChangesTest.php new file mode 100644 index 000000000..a8e5e39fb --- /dev/null +++ b/tests/Unit/Audit/AbstractAuditLogFormatterHasMeaningfulChangesTest.php @@ -0,0 +1,100 @@ +assertFalse($formatter->hasMeaningfulChanges($changeSet)); + $this->assertSame(AbstractAuditLogFormatter::NO_CHANGES_REGISTERED_MESSAGE, $formatter->publicBuildChangeDetails($changeSet)); + } + + /** + * @dataProvider provideMeaningfulChangeSets + */ + public function testHasMeaningfulChangesReturnsTrueForRealChanges(array $changeSet): void + { + $formatter = new ExposingMeaningfulAuditFormatter(IAuditStrategy::EVENT_ENTITY_UPDATE); + $this->assertTrue($formatter->hasMeaningfulChanges($changeSet)); + $this->assertNotSame(AbstractAuditLogFormatter::NO_CHANGES_REGISTERED_MESSAGE, $formatter->publicBuildChangeDetails($changeSet)); + } + + public static function provideNoOpChangeSets(): array + { + $dtUtc = new DateTimeImmutable('2026-01-02 03:04:05', new DateTimeZone('UTC')); + $dtSameInstantOtherTz = new DateTimeImmutable('2026-01-02 00:04:05', new DateTimeZone('America/Argentina/Buenos_Aires')); + + return [ + 'same-string' => [[ + 'name' => ['abc', 'abc'], + ]], + 'same-bool' => [[ + 'is_enabled' => [true, true], + ]], + 'same-null' => [[ + 'submission_lock_down_presentation_status_date' => [null, null], + ]], + 'datetime-same-instant-different-tz' => [[ + 'submission_begin_date' => [$dtUtc, $dtSameInstantOtherTz], + ]], + ]; + } + + public static function provideMeaningfulChangeSets(): array + { + $dt1 = new DateTimeImmutable('2026-01-02 03:04:05', new DateTimeZone('UTC')); + $dt2 = new DateTimeImmutable('2026-01-02 03:04:06', new DateTimeZone('UTC')); + + return [ + 'string-changed' => [[ + 'name' => ['abc', 'def'], + ]], + 'bool-changed' => [[ + 'is_hidden' => [false, true], + ]], + 'null-to-value' => [[ + 'max_submission_allowed_per_user' => [null, 3], + ]], + 'datetime-changed' => [[ + 'submission_begin_date' => [$dt1, $dt2], + ]], + ]; + } +} + +final class ExposingMeaningfulAuditFormatter extends AbstractAuditLogFormatter +{ + public function publicBuildChangeDetails(array $change_set): string + { + return $this->buildChangeDetails($change_set); + } + + public function format(mixed $subject, array $change_set): ?string + { + return null; + } +} diff --git a/tests/Unit/Audit/AuditLogOtlpStrategyNoOpSuppressionTest.php b/tests/Unit/Audit/AuditLogOtlpStrategyNoOpSuppressionTest.php new file mode 100644 index 000000000..578466c95 --- /dev/null +++ b/tests/Unit/Audit/AuditLogOtlpStrategyNoOpSuppressionTest.php @@ -0,0 +1,93 @@ +audit( + subject: (object) ['id' => 1], + change_set: ['submission_begin_date' => [$dtUtc, $dtSameInstantOtherTz]], + event_type: IAuditStrategy::EVENT_ENTITY_UPDATE, + ctx: new AuditContext() + ); + + Bus::assertNotDispatched(EmitAuditLogJob::class); + } + + public function testAuditDispatchesWhenMeaningfulChangesExist(): void + { + Bus::fake(); + Config::set('opentelemetry.enabled', true); + + $formatterFactory = new class implements IAuditLogFormatterFactory { + public function make(AuditContext $ctx, mixed $subject, string $event_type): ?\App\Audit\IAuditLogFormatter + { + return new class($event_type) extends AbstractAuditLogFormatter { + public function format(mixed $subject, array $change_set): ?string + { + return 'ok'; + } + }; + } + }; + + $strategy = new AuditLogOtlpStrategy($formatterFactory); + + $strategy->audit( + subject: (object) ['id' => 1], + change_set: ['name' => ['a', 'b']], + event_type: IAuditStrategy::EVENT_ENTITY_UPDATE, + ctx: new AuditContext() + ); + + Bus::assertDispatched(EmitAuditLogJob::class); + } +} +