One of our applications had an interesting bug a while back. We had quite a journey debugging it. Let me tell you how we solved this case.
The Scene
We create ‘Processes’ in our application. The database stores these processes. All month-old processes are deleted every night by a cron job. The code looks something like this:
public function deleteMonthOldProcesses(): void {
// Get the current date
$current_date = new DateTimeImmutable();
// Subtract 30 days from the current date
$last_month = $current_date->sub(new \DateInterval("P30D"));
// Prepare statement
$statement = $database->prepare("DELETE FROM processes WHERE _created > ?");
$statement->bind_param("s", $last_month->toString());
$statement->execute();
}
The test for this code looks a bit like this:
public function testProcessIsDeletedAfterOneMonth(): void {
$process_a = $this->createProcess();
// Tick one day later
$this->clock->tick(60 * 60 * 24);
$process_b = $this->createProcess();
// Tick 30 days later
$this->clock->tick(60 * 60 * 24 * 30);
// Cleanup the old processes
$this->deleteMonthOldProcesses();
$this->assertIsDeleted($proces_a); // Process A should be deleted
$this->assertIsNotDeleted($proces_b); // Process B should still exist
}
This test worked perfectly for around half a year, until it suddenly started failing. Process A would still be deleted, but Process B would also be gone! What could it be?
The Investigation
While debugging we tried several different things:
- Adjusting the ticking, maybe the test takes too long? That was not the problem.
- Maybe there is a bug in our Clock implementation? Nope, nothing strange there.
- Maybe something strange is happening when creating processes? That code hasn’t changed.
Then it dawned on us. That day was 29th February, a leap day! That usually messes with DateTime implementations. We looked a little bit further into it. That wasn’t it, but we were on the right track.
Before I tell you the answer, take some time and see if you can figure it out yourself!
The Culprit
- Create Process A on 2024-02-29 13:00:00
- Move the clock forward by 24 hours
- Create Process B on 2024-03-01 13:00:00
- Move the clock forward by 24 hours, 30 times
- At this point we would cross the DST line, setting the clock forward by one hour. This would make the time: 2024-03-31 14:00:00
- Then we would subtract 30 days, returning the time to: 2024-03-01 14:00:00
- Process B is created before that time, thus deleting it.
The Verdict
Luckily, the fix was easy enough. We opted to rewrite the code that rewinds to the clock. This time not using days, but pure seconds.
$last_month = $current_date->sub(new \DateInterval(sprintf('PT%dS', 60 * 60 * 24 * 30)));
This concludes another day of hunting bugs at Moxio. Those pesky insects don’t deserve the time of day 😎.
