queue time

[petrhud]

Why does the log show the queue time? Shouldn't it show the start or end time instead? And why is the queue time different?

[marcpope]

queue time: that is when it was added to the queue, the job may not start right away depending on how many slots are available
started at: should be when the job gets picked up and starts running

[petrhud]

Thank you for your reply. But I still think the time is wrong. For example, right now the log shows the time as April 1 at 9:31. But the actual time is the system time on Ubuntu. So the time when this log entry appeared should have been 7:31.

[marcpope]

Thanks for reporting this. There were two issues here:

1. Job list was showing queue time instead of completion time

The Status tab's recent jobs list was displaying started_at (with a fallback to queued_at) for all jobs — including finished ones. This has been fixed to show completed_at for finished jobs, which is the more useful timestamp.

2. Time may appear wrong if your timezone isn't set

BBS stores all timestamps in UTC and converts them to your local timezone for display. If the time looks off, check your timezone setting:

Profile (top-right menu) → Timezone dropdown → select your timezone and save.

We also just added a 24-hour time format option in the same profile page if you prefer that over the AM/PM format.

[marcpope]

Follow-up: I see your timezone is set correctly to Europe/Prague. The time discrepancy was not a timezone issue — it was because the Status tab was displaying the queued_at time instead of the completed_at time for finished jobs. Since jobs can sit in the queue briefly before running, the queued time is always a bit earlier than completion.

This has been fixed — the job list now shows the completion time for finished jobs. The fix is available now if you update your server.

[petrhud]

Thank you very much for the information. But I still don’t quite understand. The agent update job ran. I see that it was queued at 5:01:47 PM, started at 5:02:09 PM, and finished at 7:02:09 PM. It took 2 hours. Why?

[marcpope]

We found the root cause of the duration issue. On servers where PHP's timezone differs from MySQL's (e.g. PHP set to Europe/Prague while MySQL uses UTC), the duration calculation was mixing timezones — strtotime() in PHP interpreted both timestamps in PHP's local timezone, but started_at was stored in UTC by MySQL. This caused durations to be off by the timezone offset (e.g. +2 hours for CEST).

Fixed in v2.20.1 by using MySQL's TIMESTAMPDIFF() for all duration calculations, which keeps everything in the same timezone. Also fixed completed_at being written using PHP's date() instead of MySQL's NOW().

Additionally, the 24-hour time format conversion was missing the g:i:s A pattern used on the queue detail page, which caused times to display in a broken mixed format. That's fixed too.

Timezones were added after the application was built and finding all the instances have taken a great deal of time to fix. Thanks for reporting it. It may not show up on that old log entry, you probably have to wait for the next one to see the time correctred.

[petrhud]

It's still not right. The backup started at 6:21:19 and finished at 6:22:50. I can see in the log that it wasn't complete until two hours later. So the time is still off by two hours.

[marcpope]

Found the deeper issue. The previous fix only addressed the duration calculation, but date() calls throughout PHP were still using the server's local timezone (Europe/Prague = UTC+2) while MySQL stores everything in UTC. This caused started_at, completed_at, and other timestamps to be written 2 hours ahead.

The fix: we now force date_default_timezone_set('UTC') at the PHP entry point so all date() calls match MySQL. This is a one-line fix that resolves every instance.

This will be in the next release. To update, go to Settings > Updates or pull the latest Docker image.

[petrhud]

Thank you. I updated to the new version, but the time correction didn't work. I started the job at 6:07:19, but it shows 8:07:19.

[petrhud]

In addition, I checked the server log and found an incorrect time there as well. Job 385, which I mentioned above, is shown as two hours earlier in the server log.

[marcpope]

Found the remaining issue — MySQL itself was also using the server's local timezone. Our previous fix only forced PHP to UTC, but MySQL's NOW() and CURRENT_TIMESTAMP were still returning Europe/Prague time. So timestamps were stored 2 hours ahead, then TimeHelper added another 2 hours for display = 4 hours total offset, or 2 hours depending on which code path wrote the timestamp.

The fix: every MySQL connection now runs SET time_zone = '+00:00' on connect, forcing MySQL sessions to UTC too. Combined with the PHP UTC fix, all timestamps everywhere are now consistent.

This fix is in the latest code. To update:

• Bare metal: Go to Settings > Updates and click Check for Updates
• Docker: Pull the latest image

New jobs after updating will show correct times. Old timestamps in the database may still be off by your timezone offset — those were written before the fix.

[marcpope]

v2.22.1 is now released with the complete timezone fix — both PHP and MySQL are now forced to UTC on every request and connection. We believe this fully squashes the time display issues, but please let us know if you still see incorrect times after updating. New jobs should show correct times immediately; old timestamps in the database from before the fix may still be off.

To update:

• Bare metal: Go to Settings > Updates and click Check for Updates
• Docker: Pull the latest image

Thanks for your patience reporting this — it took a few rounds to catch every layer.

[petrhud]

Thank you for the corrections. Everything looks fine now. But the time in the system log is still off by two hours.

root@backup:/var/log# cat bbs-scheduler.log
2026-04-04 08:17:01 Executing server-side: job #408 (break_lock)
2026-04-04 08:17:02 Server-side break_lock job #408: completed
2026-04-04 08:19:01 Sent: job #409 (backup) to agent #30
2026-04-04 08:22:01 Executing server-side: job #410 (prune)
2026-04-04 08:22:11 Server-side prune job #410: completed
2026-04-04 08:25:01 Executing server-side: job #412 (prune)
2026-04-04 08:25:07 Server-side prune job #412: completed
2026-04-04 08:25:08 Removed 1 pruned archive(s) from DB for repo #43
root@backup:/var/log# date
Sat Apr 4 10:25:45 CEST 2026

[marcpope]

Moving to issues. system log off by 2 hours, checking it.