[GH-ISSUE #1118] OnCalendar grace time does not apply to the first expected check #776

Closed
opened 2026-02-25 23:43:33 +03:00 by kerem · 19 comments
Owner

Originally created by @agross on GitHub (Jan 24, 2025).
Original GitHub issue: https://github.com/healthchecks/healthchecks/issues/1118

Hello,

I've configured my first OnCalendar check yesterday.

The expression is Mon..Fri *-*-* 05..18:0/10:00. The server sending notifications has its timezone set to UTC and the grace time is 1 hour.

Image

My expectation is that the first notification should arrive at 05:00 but can be up to 1 hour late before the check goes down. Unfortunately, this does not seem to be the case. Today, I was notified because the first OK arrived at 2025-01-24T05:00:08.117457+00:00, which is not too late given the 1-hour grace time.

Image

The times shown in the table above are UTC.

Originally created by @agross on GitHub (Jan 24, 2025). Original GitHub issue: https://github.com/healthchecks/healthchecks/issues/1118 Hello, I've configured my first `OnCalendar` check yesterday. The expression is `Mon..Fri *-*-* 05..18:0/10:00`. The server sending notifications has its timezone set to `UTC` and the grace time is 1 hour. <img width="400" alt="Image" src="https://github.com/user-attachments/assets/90a902c8-8515-4552-9ecd-9c8e4f72ac67" /> My expectation is that the first notification should arrive at 05:00 but can be up to 1 hour late before the check goes down. Unfortunately, this does not seem to be the case. Today, I was notified because the first `OK` arrived at 2025-01-24T05:00:08.117457+00:00, which is not too late given the 1-hour grace time. <img width="401" alt="Image" src="https://github.com/user-attachments/assets/47fa7015-65b9-4ba4-8568-e79d1c499e90" /> The times shown in the table above are UTC.
kerem closed this issue 2026-02-25 23:43:33 +03:00
Author
Owner

@cuu508 commented on GitHub (Jan 24, 2025):

If this was on healthchecks.io, can you please send me the check's UUID to contact at healthchecks.io?

The ping logs table has a timezone selector buttons at the top right corner – is the display timezone set to UTC (and not Browser's time zone)?

<!-- gh-comment-id:2612037273 --> @cuu508 commented on GitHub (Jan 24, 2025): If this was on healthchecks.io, can you please send me the check's UUID to contact at healthchecks.io? The ping logs table has a timezone selector buttons at the top right corner – is the display timezone set to UTC (and not Browser's time zone)?
Author
Owner

@agross commented on GitHub (Jan 24, 2025):

If this was on healthchecks.io

I host healthchecks locally, running the latest docker image.

is the display timezone set to UTC (and not Browser's time zone)?

The times shown in the table above are UTC.

Screenshot of the notification causing the OK:

Image
<!-- gh-comment-id:2612041414 --> @agross commented on GitHub (Jan 24, 2025): > If this was on healthchecks.io I host healthchecks locally, running the latest docker image. > is the display timezone set to UTC (and not Browser's time zone)? The times shown in the table above are UTC. Screenshot of the notification causing the `OK`: <img width="299" alt="Image" src="https://github.com/user-attachments/assets/ccd73cb8-e81c-4cae-8f47-c8c548aff4fa" />
Author
Owner

@cuu508 commented on GitHub (Jan 24, 2025):

OK, in that case, that does look wrong, and either I'm missing something or there's a bug somewhere.

I haven't been able to reproduce this. Can you try and produce reliable reproduction steps for me? Does this also happen if you set the schedule so the next expected ping is only a little bit in the future? For example, if the time is 10:10 UTC currently, can you trigger the issue if you set the schedule to 10:15:00, send one ping and then wait 5 minutes?

<!-- gh-comment-id:2612145427 --> @cuu508 commented on GitHub (Jan 24, 2025): OK, in that case, that does look wrong, and either I'm missing something or there's a bug somewhere. I haven't been able to reproduce this. Can you try and produce reliable reproduction steps for me? Does this also happen if you set the schedule so the next expected ping is only a little bit in the future? For example, if the time is 10:10 UTC currently, can you trigger the issue if you set the schedule to `10:15:00`, send one ping and then wait 5 minutes?
Author
Owner

@agross commented on GitHub (Jan 24, 2025):

In the meantime, I've recreated the ping on healthchecks.io; the ID is 5b13c8f6-527c-4dba-b55e-a44476e37b29. With the slight difference in the Mon-Sat OnCalendar expression, we'll see it fail tomorrow morning.

<!-- gh-comment-id:2612199017 --> @agross commented on GitHub (Jan 24, 2025): In the meantime, I've recreated the ping on healthchecks.io; the ID is `5b13c8f6-527c-4dba-b55e-a44476e37b29`. With the slight difference in the Mon-Sat OnCalendar expression, we'll see it fail tomorrow morning.
Author
Owner

@agross commented on GitHub (Jan 27, 2025):

Unfortunately, it didn’t reproduce on healthchecks.io. I've now reconfigured to use our self-hosted instance and I'll post updates here if it starts to fail again.

<!-- gh-comment-id:2615010896 --> @agross commented on GitHub (Jan 27, 2025): Unfortunately, it didn’t reproduce on healthchecks.io. I've now reconfigured to use our self-hosted instance and I'll post updates here if it starts to fail again.
Author
Owner

@agross commented on GitHub (Jan 28, 2025):

Well, it happened again today on the self-hosted instance. In the meantime I changed the grace time to 45 minutes. It seems that the OnCalendar expression is considered late starting 4:00 UTC (invisible in the log), turns down at 4:45 UTC and the server running the action at 5:00 UTC makes the check up again.

The expression is (and was): Mon..Fri *-*-* 05..18:0/10:00 with Server's Time Zone == UTC.

Am I right to assume the "Server" above the machine executing pings? Or is it the server running the healthchecks instance, i.e. evaluating OnCalendar expression?

Image
<!-- gh-comment-id:2618619115 --> @agross commented on GitHub (Jan 28, 2025): Well, it happened again today on the self-hosted instance. In the meantime I changed the grace time to 45 minutes. It seems that the OnCalendar expression is considered `late` starting 4:00 UTC (invisible in the log), turns `down` at 4:45 UTC and the server running the action at 5:00 UTC makes the check `up` again. The expression is (and was): `Mon..Fri *-*-* 05..18:0/10:00` with Server's Time Zone == UTC. Am I right to assume the "Server" above the machine executing pings? Or is it the server running the healthchecks instance, i.e. evaluating `OnCalendar` expression? <img width="402" alt="Image" src="https://github.com/user-attachments/assets/0bcd0f2d-f22d-4581-b950-f40174da2574" />
Author
Owner

@cuu508 commented on GitHub (Jan 28, 2025):

Am I right to assume the "Server" above the machine executing pings?

Yes, it's the timezone of the machine sending pings.

Would you be able to produce reliable reproduction steps for me? Or give me access to a machine (say, a throwaway VM in one of the public clouds) where you've reproduced the issue?

<!-- gh-comment-id:2618742840 --> @cuu508 commented on GitHub (Jan 28, 2025): > Am I right to assume the "Server" above the machine executing pings? Yes, it's the timezone of the machine sending pings. Would you be able to produce reliable reproduction steps for me? Or give me access to a machine (say, a throwaway VM in one of the public clouds) where you've reproduced the issue?
Author
Owner

@agross commented on GitHub (Jan 28, 2025):

Yes, it's the timezone of the machine sending pings.

It rather looks like the machine running healthchecks given the 1-hour offset. Why would the healthcheck turn down at 4:45 UTC when the OnCalendar expression specifies 5-18 (and UTC as the time zone)?

The server sending pings is configured for UTC (timedatectl) and the server receiving pings runs in the Europe/Berlin time zone. Regardless, the timestamps in the receiving server's log make sense, e.g. 5:45 in Europe/Berlin is 4:45 UTC as shown below:

Jan 28 05:45:00 web docker[2284]: app-1  | a161c3a2-e22f-4265-9453-c351071ef5fd goes down
Jan 28 06:00:11 web docker[2284]: app-1  | [pid: 10|app: 0|req: 6187/24731] 172.18.0.8 () {40 vars in 627 bytes} [Tue Jan 28 06:00:11 2025] POST /ping/a161c3a2-e22f-4265-9453-c351071ef5fd => generated 2 bytes in 26 msecs (HTTP/1.1 200) 11 headers in 387 bytes (1 switches on core 0)
Jan 28 06:00:12 web docker[2284]: app-1  | a161c3a2-e22f-4265-9453-c351071ef5fd goes up

Or give me access to a machine

Would you like SSH access or access to the healthchecks instance?

<!-- gh-comment-id:2618810393 --> @agross commented on GitHub (Jan 28, 2025): > Yes, it's the timezone of the machine sending pings. It rather looks like the machine running healthchecks given the 1-hour offset. Why would the healthcheck turn `down` at 4:45 UTC when the OnCalendar expression specifies `5-18` (and UTC as the time zone)? The server sending pings is configured for UTC (`timedatectl`) and the server receiving pings runs in the Europe/Berlin time zone. Regardless, the timestamps in the receiving server's log make sense, e.g. 5:45 in Europe/Berlin is 4:45 UTC as shown below: ``` Jan 28 05:45:00 web docker[2284]: app-1 | a161c3a2-e22f-4265-9453-c351071ef5fd goes down Jan 28 06:00:11 web docker[2284]: app-1 | [pid: 10|app: 0|req: 6187/24731] 172.18.0.8 () {40 vars in 627 bytes} [Tue Jan 28 06:00:11 2025] POST /ping/a161c3a2-e22f-4265-9453-c351071ef5fd => generated 2 bytes in 26 msecs (HTTP/1.1 200) 11 headers in 387 bytes (1 switches on core 0) Jan 28 06:00:12 web docker[2284]: app-1 | a161c3a2-e22f-4265-9453-c351071ef5fd goes up ``` > Or give me access to a machine Would you like SSH access or access to the healthchecks instance?
Author
Owner

@agross commented on GitHub (Jan 28, 2025):

Interesting, the preview timestamps equal if I select the server's time zone.

Image

If I select another time zone like Riga, the times start to differ.

Next elapse: | Tue 2025-01-28 14:20:00 EET
   (in UTC): | Tue 2025-01-28 13:20:00 CET
<!-- gh-comment-id:2618841967 --> @agross commented on GitHub (Jan 28, 2025): Interesting, the preview timestamps equal if I select the server's time zone. <img width="789" alt="Image" src="https://github.com/user-attachments/assets/f3049478-8bc3-432d-8216-290614838f51" /> If I select another time zone like Riga, the times start to differ. ``` Next elapse: | Tue 2025-01-28 14:20:00 EET (in UTC): | Tue 2025-01-28 13:20:00 CET ```
Author
Owner

@cuu508 commented on GitHub (Jan 28, 2025):

the server receiving pings runs in the Europe/Berlin time zone

You previously mentioned you are running Healthchecks using docker.

  • Is Europe/Berlin the time zone set in the host system, or in the docker container?
  • If it's the latter, how did you set the timezone for the container? Did you pass some additional env variables to the container?
  • How does the command line for starting the container look? And, if you're using Docker Compose, how does the docker-compose.yml look?

Interesting, the preview timestamps equal if I select the server's time zone.

You're on to something here, this is definitely not right.

<!-- gh-comment-id:2619031269 --> @cuu508 commented on GitHub (Jan 28, 2025): > the server receiving pings runs in the Europe/Berlin time zone You previously mentioned you are running Healthchecks using docker. * Is Europe/Berlin the time zone set in the host system, or in the docker container? * If it's the latter, how did you set the timezone for the container? Did you pass some additional env variables to the container? * How does the command line for starting the container look? And, if you're using Docker Compose, how does the docker-compose.yml look? > Interesting, the preview timestamps equal if I select the server's time zone. You're on to something here, this is definitely not right.
Author
Owner

@cuu508 commented on GitHub (Jan 28, 2025):

I can reproduce the incorrect "Expected Ping Dates" preview if I set TIME_ZONE = "Europe/Berlin" in local_settings.py:

Image

Have you by any chance changed Django's TIME_ZONE setting?

<!-- gh-comment-id:2619043405 --> @cuu508 commented on GitHub (Jan 28, 2025): I can reproduce the incorrect "Expected Ping Dates" preview if I set `TIME_ZONE = "Europe/Berlin"` in `local_settings.py`: ![Image](https://github.com/user-attachments/assets/9cd6d93e-8d29-4348-81c1-a5f15a07a97d) Have you by any chance changed Django's `TIME_ZONE` setting?
Author
Owner

@agross commented on GitHub (Jan 28, 2025):

Have you by any chance changed Django's TIME_ZONE setting?

I've mounted /etc/localtime:/etc/localtime, so both the host and the container share the same time zone.

$ date
Tue 28 Jan 2025 02:49:36 PM CET

$ docker exec healthchecks-app-1 date
Tue Jan 28 14:49:40 CET 2025
<!-- gh-comment-id:2619061242 --> @agross commented on GitHub (Jan 28, 2025): > Have you by any chance changed Django's TIME_ZONE setting? I've mounted `/etc/localtime:/etc/localtime`, so both the host and the container share the same time zone. ```sh $ date Tue 28 Jan 2025 02:49:36 PM CET $ docker exec healthchecks-app-1 date Tue Jan 28 14:49:40 CET 2025 ```
Author
Owner

@agross commented on GitHub (Jan 28, 2025):

After removing the mount the preview feature works as expected. Is healthchecks required to run in UTC?

<!-- gh-comment-id:2619079596 --> @agross commented on GitHub (Jan 28, 2025): After removing the mount the preview feature works as expected. Is healthchecks required to run in UTC?
Author
Owner

@cuu508 commented on GitHub (Jan 28, 2025):

The timezone of the OS (or the container) should not matter. For example, on my local development machine, the timezone is Europe/Riga, and on the server serving healthchecks.io it is set to Europe/Berlin (because that happens to be Hetzner's default).

What matters is that Django's TIME_ZONE setting is "UTC". The code that handles datetime arithmetic is written with assumption that internally we will be using UTC timestamps.

What puzzles me is how in your case setting the container's timezone influenced the time zone that the Django code uses.

Could you do the following experiment:

  • Drop into python shell inside the container:
docker-compose exec healthchecks /opt/healthchecks/manage.py shell
  • Inside the shell paste the following and see what comes back:
from django.conf import settings
print(settings.TIME_ZONE)
<!-- gh-comment-id:2619165331 --> @cuu508 commented on GitHub (Jan 28, 2025): The timezone of the OS (or the container) should not matter. For example, on my local development machine, the timezone is `Europe/Riga`, and on the server serving healthchecks.io it is set to `Europe/Berlin` (because that happens to be Hetzner's default). What matters is that Django's [TIME_ZONE](https://docs.djangoproject.com/en/5.1/ref/settings/#std-setting-TIME_ZONE) setting is "UTC". The code that handles datetime arithmetic is written with assumption that internally we will be using UTC timestamps. What puzzles me is how in your case setting the container's timezone influenced the time zone that the Django code uses. Could you do the following experiment: * Drop into python shell inside the container: ``` docker-compose exec healthchecks /opt/healthchecks/manage.py shell ``` * Inside the shell paste the following and see what comes back: ``` from django.conf import settings print(settings.TIME_ZONE) ```
Author
Owner

@cuu508 commented on GitHub (Jan 28, 2025):

I mounted /etc/localtime like you did and now see the same problem. I'll play with it.

<!-- gh-comment-id:2619227080 --> @cuu508 commented on GitHub (Jan 28, 2025): I mounted `/etc/localtime` like you did and now see the same problem. I'll play with it.
Author
Owner

@agross commented on GitHub (Jan 28, 2025):

I tried both /etc/localtime mount situations and in both cases Django's time zone is UTC.

<!-- gh-comment-id:2619253088 --> @agross commented on GitHub (Jan 28, 2025): I tried both /etc/localtime mount situations and in both cases Django's time zone is UTC.
Author
Owner

@cuu508 commented on GitHub (Jan 28, 2025):

After some time diving through Django sources, I narrowed down the problem to the following snippet:

from datetime import datetime, UTC
import zoneinfo
datetime.now(tz=zoneinfo.ZoneInfo("UTC")).isoformat()
datetime.now(tz=UTC).isoformat()

Inside container with a mounted /etc/localtime this produces:

'2025-01-28T18:01:03.432466+02:00'
'2025-01-28T16:01:04.138036+00:00'

On the host system the same snippet produces:

'2025-01-28T16:01:14.601574+00:00'
'2025-01-28T16:01:15.153605+00:00'

So, inside the container, zoneinfo.ZoneInfo("UTC") is somehow messed up. Reading zoneinfo docs, the zoneinfo module uses system's time zone database. It is usually at /usr/share/zoneinfo.

If we look at ls -la /etc/localtime we see it is a symlink to /usr/share/zoneinfo/Etc/UTC.

I guess what happens is, when you mount your host system's timezone file over /etc/localtime inside the container, it also affects /usr/share/zoneinfo/Etc/UTC inside the container.

Which leads to messed up ZoneInfo("UTC") instances. Which then leads to incorrect date formatting in Django templates.

I think the straightforward fix would be not to mount /etc/localtime inside the container, and let it default to UTC.

<!-- gh-comment-id:2619455516 --> @cuu508 commented on GitHub (Jan 28, 2025): After some time diving through Django sources, I narrowed down the problem to the following snippet: ``` from datetime import datetime, UTC import zoneinfo datetime.now(tz=zoneinfo.ZoneInfo("UTC")).isoformat() datetime.now(tz=UTC).isoformat() ``` Inside container with a mounted `/etc/localtime` this produces: ``` '2025-01-28T18:01:03.432466+02:00' '2025-01-28T16:01:04.138036+00:00' ``` On the host system the same snippet produces: ``` '2025-01-28T16:01:14.601574+00:00' '2025-01-28T16:01:15.153605+00:00' ``` So, inside the container, `zoneinfo.ZoneInfo("UTC")` is somehow messed up. Reading [zoneinfo docs](https://docs.python.org/3/library/zoneinfo.html), the zoneinfo module uses system's time zone database. It is usually at `/usr/share/zoneinfo`. If we look at `ls -la /etc/localtime` we see it is a symlink to `/usr/share/zoneinfo/Etc/UTC`. I guess what happens is, when you mount your host system's timezone file over `/etc/localtime` inside the container, it also affects `/usr/share/zoneinfo/Etc/UTC` inside the container. Which leads to messed up `ZoneInfo("UTC") ` instances. Which then leads to incorrect date formatting in Django templates. I think the straightforward fix would be not to mount `/etc/localtime` inside the container, and let it default to UTC.
Author
Owner

@agross commented on GitHub (Jan 28, 2025):

I think the straightforward fix would be not to mount /etc/localtime inside the container, and let it default to UTC.

Yes, I think so too and this is also what I changed in my setup. Hopefully, the check will stay up, we'll know tomorrow ;-)

Perhaps a bit of documentation in the compose file to make that explicit can help as well.

Thank you for your support regarding this issue and for creating healthchecks in the first place!

<!-- gh-comment-id:2619528816 --> @agross commented on GitHub (Jan 28, 2025): > I think the straightforward fix would be not to mount /etc/localtime inside the container, and let it default to UTC. Yes, I think so too and this is also what I changed in my setup. Hopefully, the check will stay up, we'll know tomorrow ;-) Perhaps a bit of documentation in the compose file to make that explicit can help as well. Thank you for your support regarding this issue and for creating healthchecks in the first place!
Author
Owner

@cuu508 commented on GitHub (Jan 30, 2025):

I added a system check which inspects settings.TIME_ZONE and prints an error message if it does not have the expected "UTC" value. This should guard against users setting TIME_ZONE in local_settings.py.

I'm not sure about adding a note about the /etc/localtime pitfall. This is not Healthchecks-specific. If you mount non-UTC timezone file over /etc/localtime you will have system-wide issues. For example, TZ=UTC date command will print a non-UTC time. Users can break their systems in all kinds of creative ways, it seems futile and out of scope for Healthchecks to warn against them.

FWIW I added a comment in a StackOverflow answer here: https://stackoverflow.com/a/67054850/5821

<!-- gh-comment-id:2624387650 --> @cuu508 commented on GitHub (Jan 30, 2025): I added a system check which inspects `settings.TIME_ZONE` and prints an error message if it does not have the expected "UTC" value. This should guard against users setting `TIME_ZONE` in `local_settings.py`. I'm not sure about adding a note about the `/etc/localtime` pitfall. This is not Healthchecks-specific. If you mount non-UTC timezone file over `/etc/localtime` you will have system-wide issues. For example, `TZ=UTC date` command will print a non-UTC time. Users can break their systems in all kinds of creative ways, it seems futile and out of scope for Healthchecks to warn against them. FWIW I added a comment in a StackOverflow answer here: https://stackoverflow.com/a/67054850/5821
Sign in to join this conversation.
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference
starred/healthchecks#776
No description provided.