Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Scheduled Speedtests will always run one hour late #194

Closed
pchristod opened this issue Dec 5, 2022 · 53 comments · Fixed by #929
Closed

Scheduled Speedtests will always run one hour late #194

pchristod opened this issue Dec 5, 2022 · 53 comments · Fixed by #929
Assignees
Labels
🐛 bug Something isn't working

Comments

@pchristod
Copy link

Describe the bug
Hi,
hope you are doing well and thank you for this project! I started to set this up yesterday on my Synology NAS to replace Speedtest Tracker (the original) however I'm currently seeing an issue with the Speedtest scheduling. If I set this up via cron expression, basically the same as with the original Speedtest Tracker I'm seeing that it will always run 1 hour late. E.g. if I set this to 3 PM it will run at 4 PM and I can't seem to figure out why, so I'm thinking this is a Bug. To reproduce and show it on a Screenshot I had picked a simple time. Maybe something to do with the set Timezone?

To Reproduce
Steps to reproduce the behavior:

  1. Go to General Settings
  2. Set cron expression to something like '0 15 * * *'
  3. Wait for the schedule expected time
  4. See that the Test will not run until one our late

Expected behavior
Scheduled Tests should be run at the exact time I define them via cron expression

Screenshots
Error

Logs
No logs showing the actual run of the test, Logiles have the correct timestamp. Executing into the container will show the time is correct:

root@1bddb13f78d3:/var/www/html# date -d "$(curl -sI google.com| grep -i '^date:'|cut -d' ' -f2-)"
Mon Dec  5 18:55:23 CET 2022
root@1bddb13f78d3:/var/www/html# uptime
 18:55:26 up 235 days, 11:52,  0 users,  load average: 0.24, 0.39, 0.29
root@1bddb13f78d3:/var/www/html

Additional context
How I'm running the container:

docker run --restart=always --name=speedtest-tracker -d \
    -v /volume1/docker/speedtest-tracker:/config \
    -e "TZ=Europe/Berlin" \
    -e "PUID=1026" \
    -e "PGID=100" \
    -p 5811:80 \
    ghcr.io/alexjustesen/speedtest-tracker:latest
@alexdelprete
Copy link
Contributor

alexdelprete commented Dec 5, 2022

Can you click on the View on Speedtest.net link and verify that also on their site the test has been done at 16 instead of 15?

There was an issue in the past with the UTC and timezone, but it has been solved. You're using latest version right?

Times and speed values of speedtest-tracker and speedtest.net site should coincide: these are my latest tests, and times and values look correct.

image

image

@pchristod
Copy link
Author

pchristod commented Dec 5, 2022

Hey Alex,

I checked what you advised and it shows 16:00 as well:
Speedtest

Yep, I'm using the latest Image. I pulled it yesterday evening, Portainer shows Image was created on 3.12 around 3 PM which is after the latest Commit in this Repo.

Edit: What Timezone Setting are you using, I can try to switch and check if it is also 1 hour late? If so it would come down to my Timezone Setting.

@alexdelprete
Copy link
Contributor

This is my docker-compose file: for best-practice, I always set in every compose file the TZ env. variable and I also mount /etc/localtime, but if you checked that date/time inside the container is correct, that's not your issue.

version: '3.3'
services:
  speedtest-tracker:
    image: ghcr.io/alexjustesen/speedtest-tracker:v0.5.0
    container_name: speedtest-tracker
    restart: unless-stopped
    ports:
      - 8008:443
    environment:
      TZ: Europe/Rome
      PUID: 1000
      PGID: 1000
      DB_CONNECTION: mysql
      DB_HOST: mariadb.axel.dom
      DB_PORT: 3306
      DB_DATABASE: speedtest_tracker
      DB_USERNAME: xxxxxxxxxx
      DB_PASSWORD: **********
    volumes:
      - /etc/localtime:/etc/localtime:ro
      - $PWD/config:/config
      - $PWD/certs:/etc/ssl/web
    networks:
      - proxy

This is my TZ setting in speedtest-tracker:

image

@alexjustesen
Copy link
Owner

What do we think about dropping the timezone in the UI for just the system timezone? Right now the two are different but they probably shouldn't be.

@pchristod
Copy link
Author

Hi,
so I set the Timezone to yours and checked, same issue. As seen from my run command I'm also always setting the TZ directly as a habit. Strange stuff.

Since the time within the Container is accurate I'm not sure where this can even come from. Can I somehow output the cron entry in the Container to double check?

@alexdelprete
Copy link
Contributor

Just one other question Philipp: I only see one test

What do we think about dropping the timezone in the UI for just the system timezone? Right now the two are different but they probably shouldn't be.

I perfectly agree. It's redundant, if the system TZ is correctly configured. We should modify the proposed docker-compose.yml in the docs.

@alexdelprete
Copy link
Contributor

so I set the Timezone to yours and checked, same issue.

We're in the same TZ, I'm in Italy. :)

Can I somehow output the cron entry in the Container to double check?

Yes, that would've been my next suggestion: find the crontab config, I guess the system crontab is used, but @alexjustesen will confirm. In that case, from shell: crontab -e

@pchristod
Copy link
Author

pchristod commented Dec 5, 2022

so I set the Timezone to yours and checked, same issue.

We're in the same TZ, I'm in Italy. :)

Can I somehow output the cron entry in the Container to double check?

Yes, that would've been my next suggestion: find the crontab config, I guess the system crontab is used, but @alexjustesen will confirm. In that case, from shell: crontab -e

Haha yeah I know, I just wanted to replicate the exact (UI) setup of someone without problems to exclude any funky Bugs anyways :D
I see, I checked before with 'crontab -l', I think it pointed to a folder/file. However I'm not at my PC currently so I have to check later again.

About the Tests:
Yeah that's true, I deleted the other 4 for the Screenshot to have it show only the example I set up.

@alexdelprete
Copy link
Contributor

alexdelprete commented Dec 5, 2022

I checked before with 'crontab -l', I think it pointed to a folder/file

we need to check the contents of that file. ;)

Yeah that's true, I deleted the other 4 for the Screenshot to have it show only the example I set up.

Can you change the schedule so to do tests every 1h so we can see what happens with 2-3 tests?

Also, can you start a MANUAL test, so we can check the timestamp in the results list? So we're 100% sure it's a crontab issue.

@pchristod
Copy link
Author

Hey,

we need to check the contents of that file. ;)

so the content of crontab are actually as follows:

root@1bddb13f78d3:~# crontab -l
MAILTO=""
* * * * * webuser cd /var/www/html && php artisan schedule:run >> /dev/null 2>&1

Seems to point to some kind of scheduler, unfortunately I don't know much about it so someone would need to let me know what root file to check please.

Can you change the schedule so to do tests every 1h so we can see what happens with 2-3 tests?

Yes, I will set that up tomorrow morning and respond back later that day.

Also, can you start a MANUAL test, so we can check the timestamp in the results list? So we're 100% sure it's a crontab issue.

I ran a manual test at 0:07 and the time matches in the Results page (as well as Speedtest.net) so it seems to be only when it's done automatically per schedule.

@alexdelprete
Copy link
Contributor

I'm out of ideas, cron works fine here. @alexjustesen might suggest how to verify and debug the internal cron manager config.

@pchristod
Copy link
Author

Yes, that would certainly be helpful. I can check once I know what file :)
I'm also out of ideas currently.

Also as mentioned yesterday per your suggestion:
I set up my schedule today for 4 tests with the expression seen in the Screenshot. Results are ID 7-10.
Speedtest

@alexjustesen
Copy link
Owner

So the cron doesn't really care what time it is it's just told to run. Can you guys confirm what the offset of your timezone should be? There might be an issue with that.

I also never set the timezone at the container level so that everything is reported in GMT and I let the UI do the offsets.

@alexdelprete
Copy link
Contributor

We're both in CET timezone, that is GMT+1 now. Can't understand why I don't have this problem and he does, being in the same TZ.

What issue did you find? It's working fine here.

@alexjustesen
Copy link
Owner

alexjustesen commented Dec 17, 2022

Not a clue tbh if you're both in the same TZ, also isn't it like 5:30am there? The hell you doing up?

@alexdelprete
Copy link
Contributor

also isn't it like 5:30am there? The hell you doing up?

I had a bad flu...still recovering...was in bed for 2 days straight, can't sleep much...

@alexjustesen
Copy link
Owner

Well I hope you feel better man

@alexdelprete
Copy link
Contributor

alexdelprete commented Dec 17, 2022

Well I hope you feel better man

Yes I'm better, but the sleep cycle is messed up. :)

Thanks man.

@alexjustesen
Copy link
Owner

@pchristod do you have the timezone set on your host machine?

@pchristod
Copy link
Author

pchristod commented Dec 17, 2022

@alexjustesen Hi, yep Timezone is correct. Host machine is a Synology NAS using GMT+1 currently as per time.google.com

A quick test can be seen in my first post where system time within the Container is also the same as reported back by a curl to Google.

No idea why it's not working in my case tbh.

@alexjustesen
Copy link
Owner

Do me a favor and set your host tz back to GMT and let me know if anything changes

@bam7 bam7 mentioned this issue Dec 18, 2022
@bka-git
Copy link

bka-git commented Dec 22, 2022

Hi,
did have the same problem. When docker container created with '-e "TZ=Europe/Berlin"' and Timezone set to "Europe/Berlin" in "General -> Timezone" all my test results are one hour ahead.

After setting UTC in "General -> Timezone", all test results are shown correct.

Maybe this helps a bit
Bernhard

@pchristod
Copy link
Author

pchristod commented Dec 22, 2022

Hi,

sorry for the late reply. What @bka-git suggested does work, however this is just a workaround which would've always worked I guess since it moves just the clock back by 1 hour. It's adjusting around the problem and will also come with the downsides like showing the wrong times in the GUI.
Maybe the solution mentioned by @alexjustesen in the other issue to remove that feature completely from the GUI makes sense.

@alexjustesen
Copy link
Owner

Sounds like the simple fix is to drop the time zone as an admin panel option and to instead make this a container level environment variable

@alexdelprete
Copy link
Contributor

Sounds like the simple fix is to drop the time zone as an admin panel option and to instead make this a container level environment variable

I agree with this approach. In all my docker-compose files (I use a standard template), I always put the TZ env variable and also map this in volumes: /etc/localtime:/etc/localtime:ro. Usually TZ and that volume mapping are mutually exclusive, but in case the app is not configured correctly, I leave both to avoid as much as possible any timezone problems.

I still can't understand why this issue doesn't apply to me, but it applies someone else in the same timezone.

@alexjustesen alexjustesen self-assigned this Jan 4, 2023
@alexjustesen alexjustesen added the 🐛 bug Something isn't working label Jan 4, 2023
@alexjustesen alexjustesen modified the milestone: v0.11.0 Jan 4, 2023
@alexjustesen
Copy link
Owner

Only took at year but #929 should be merged this week to finally solve this issue 🤘

@alexdelprete
Copy link
Contributor

Removed /etc/localtime mapping and upgraded to 0.13.4: times in graphs (and results page) are 1h ahead.

image

Readded it and it looks good again.

image

@alexjustesen
Copy link
Owner

@alexdelprete you're UTC +1 right? So this makes sense because the scheduler isn't yet aware what your time zone is from the setting page.

@alexdelprete
Copy link
Contributor

@alexjustesen so the fix is not complete yet? I read it was supposed to fix the problem and no TZ or /etc/localtime should be needed anymore.

@alexjustesen
Copy link
Owner

@alexjustesen so the fix is not complete yet?

It's not merged yet so wouldn't be in a release yet.

@alexdelprete
Copy link
Contributor

It's not merged yet so wouldn't be in a release yet.

My bad. Since I upgraded to .4 I thought it was merged in that one. :)

Will test it when it's merged, thanks.

@alexjustesen
Copy link
Owner

Will test it when it's merged, thanks.

It'll probably hit a release come Wednesday or Thursday.

@alexjustesen
Copy link
Owner

@alexdelprete merged and a dev tag is currently building, feel free to test that out when it's done.

@alexdelprete
Copy link
Contributor

feel free to test that out when it's done.

tested it now, same issue: 1h ahead (it just ran a test, and it's 01.25 now)

image

@alexjustesen
Copy link
Owner

feel free to test that out when it's done.

tested it now, same issue: 1h ahead (it just ran a test, and it's 01.25 now)

Just to confirm you pulled the latest dev tagged version, set your time zone in the UI and it's still off?

Not at all what I experienced. I had a schedule set for 8pm (America/New_York) and it ran on the money.

@alexdelprete
Copy link
Contributor

alexdelprete commented Nov 28, 2023

Just to confirm you pulled the latest dev tagged version, set your time zone in the UI and it's still off?

  1. Obviusly I pulled the dev tag based on your indication.
  2. I removed /etc/localtime mapping from docker-compose.yml
  3. Rebuilt image and restarted
  4. Timezone has never changed in the settings: Europe/Rome
  5. Results are all +1h ahead. Last test has been made at 13.25 and it's reported as 14.25.

I noticed there's a new dev tag image available but I can't pull it, it returns an access denied error.

@ShlomiD83
Copy link

ShlomiD83 commented Nov 28, 2023

@alexjustesen

  1. I removed /etc/localtime mapping from docker-compose.yml
  2. I pulled the dev tag image
  3. Rebuilt the docker container
  4. set TZ to Asia/Jerusalem in the settings.

Now the results' time seems to be correct.
I'll have to check in a few hours & scheduled tests that the time remains correct.

@alexjustesen
Copy link
Owner

I noticed there's a new dev tag image available but I can't pull it, it returns an access denied error.

Is your source GHCR or Docker for the image?

@alexjustesen alexjustesen reopened this Nov 28, 2023
@alexdelprete
Copy link
Contributor

Is your source GHCR or Docker for the image?

GHCR.

@alexjustesen
Copy link
Owner

Building now so you can avoid whatever caused that error: https://github.com/alexjustesen/speedtest-tracker/releases/tag/v0.14.0-beta1

@alexdelprete
Copy link
Contributor

alexdelprete commented Nov 28, 2023

Pulled latest beta.

Same thing: last test was 14:25

image

@alexdelprete
Copy link
Contributor

alexdelprete commented Nov 28, 2023

Why don't you prepare a debug.php page in which it's shown what the app sees as time, the configured app Timezone, last result, etc.? so we can check internals, and what changes when I disable/enable /etc/localtime.

@alexjustesen
Copy link
Owner

Why don't you prepare a debug.php page

Already planned because your deployment isn't functioning like mine so something else is effecting this.

@alexjustesen
Copy link
Owner

alexjustesen commented Nov 28, 2023

For those off by an hour, are you setting a time zone in your database container/instance?

A comment by the author of #939 brought up that some people set the tz of the database as well.

@ShlomiD83
Copy link

For those off by an hour, are you setting a time zone in your database container/instance?

A comment by the author of #939 brought up that some people set the tz of the database as well.

My DB container does have a TZ env setting but my results are accurate at the moment.

@alexdelprete
Copy link
Contributor

alexdelprete commented Nov 28, 2023

For those off by an hour, are you setting a time zone in your database container/instance?

my MariaDB instance is not a docker container, it is the central db for my entire homelab, it's a debian lxc and the OS time settings are fine. I have at least 18 services using MariaDB and I don't have any time issues.

BTW: all DBs always uses UTC internally to avoid these kind of issues. And all apps should do the same. Local time is only to be managed at presentation layer. I wouldn't even bother having a TZ setting in the app, I would use the OS to set that, and just convert to UTC internally when saving data, and converting to OS timezone when presenting.

And btw: the fact that when I map /etc/localtime in the container the problem is solved, it means some function in PHP/Laravel actually uses OS timezone for its things, otherwise it wouldn't have any effect.

@alexjustesen
Copy link
Owner

As of v0.14.0-beta1 the scheduler is now time zone aware and will run based on the Time zone setting under Settings -> General.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
🐛 bug Something isn't working
Projects
None yet
Development

Successfully merging a pull request may close this issue.

7 participants