AUTO_DATE_RANGE missing nightly data
bhammack opened this issue · 12 comments
Hey there, love the project.
I'm experiencing an issue where the fetcher does not pull data on a routine basis. This seems to occur every night from ~18:45 to 00:00 the following day local time (23:45 - 05:00 UTC, container time), despite the usage of AUTO_DATE_RANGE. Below is a copy of my docker-compose.yml configuration for the service, as well as a snapshot in Grafana indicating the data gaps. The data for these time periods is present and visible in the FitBit app. This does not appear to be an issue with the host, as restarting the container will back-fill the data by 24 hours. Logs do not appear to contain any errors.
Any ideas why this may be the case, and how to fix it?
Docker compose
fitbit:
image: thisisarpanghosh/fitbit-fetch-data:latest
container_name: fitbit
restart: unless-stopped
volumes:
- ./configs/fitbit/logs:/app/logs
- ./configs/fitbit/tokens:/app/tokens
- /etc/timezone:/etc/timezone:ro
- /etc/localtime:/etc/localtime:ro
environment:
- FITBIT_LOG_FILE_PATH=/app/logs/fitbit.log
- TOKEN_FILE_PATH=/app/tokens/fitbit.token
- OVERWRITE_LOG_FILE=True
- FITBIT_LANGUAGE='en_US'
- INFLUXDB_VERSION = 1 # supported values are 1 and 2
- INFLUXDB_HOST=influxdb # for influxdb 1.x
- INFLUXDB_PORT=8086 # for influxdb 1.x
- INFLUXDB_USERNAME=fitbit_user # for influxdb 1.x
- INFLUXDB_PASSWORD=fitbit_password # for influxdb 1.x
- INFLUXDB_DATABASE=fitbit_database # for influxdb 1.x
- CLIENT_ID=${FITBIT_CLIENT_ID}
- CLIENT_SECRET=${FITBIT_CLIENT_SECRET}
- DEVICENAME='Inspire3'
- AUTO_DATE_RANGE=TrueGrafana
This is an unusual one in a while. During that period ( 18:45-00:00 ), can you keep an eye on the docker logs to see if the requests are being requested like the following ( which by default scheduled every 3 minute with schedule.every(3).minutes.do( lambda : get_intraday_data_limit_1d(end_date_str, [('heart','HeartRate_Intraday','1sec'),('steps','Steps_Intraday','1min')] )) )
Expected log every 3 minute with default settings
fitbit-fetch-data | 2024-02-26 11:32:12,480 - DEBUG - Running job Job(interval=3, unit=minutes, do=<lambda>, args=(), kwargs={})
fitbit-fetch-data | 2024-02-26 11:32:12,481 - DEBUG - Requesting data from fitbit via Url : https://api.fitbit.com/1/user/-/activities/heart/date/2024-02-26/1d/1sec.json
fitbit-fetch-data | 2024-02-26 11:32:12,486 - DEBUG - Starting new HTTPS connection (1): api.fitbit.com:443
fitbit-fetch-data | 2024-02-26 11:32:12,778 - DEBUG - https://api.fitbit.com:443 "GET /1/user/-/activities/heart/date/2024-02-26/1d/1sec.json HTTP/1.1" 200 None
fitbit-fetch-data | 2024-02-26 11:32:12,953 - INFO - Recorded HeartRate_Intraday intraday for date 2024-02-26
fitbit-fetch-data | 2024-02-26 11:32:12,954 - DEBUG - Requesting data from fitbit via Url : https://api.fitbit.com/1/user/-/activities/steps/date/2024-02-26/1d/1min.json
fitbit-fetch-data | 2024-02-26 11:32:12,955 - DEBUG - Starting new HTTPS connection (1): api.fitbit.com:443
fitbit-fetch-data | 2024-02-26 11:32:13,164 - DEBUG - https://api.fitbit.com:443 "GET /1/user/-/activities/steps/date/2024-02-26/1d/1min.json HTTP/1.1" 200 None
fitbit-fetch-data | 2024-02-26 11:32:13,185 - INFO - Recorded Steps_Intraday intraday for date 2024-02-26
fitbit-fetch-data | 2024-02-26 11:32:13,750 - DEBUG - http://influxdb:8086 "POST /write?db=HealthStats HTTP/1.1" 204 0
fitbit-fetch-data | 2024-02-26 11:32:13,750 - INFO - Successfully updated influxdb database with new points
Let me know and we can try figuring the issue out. Thank you.
There appears nominal log events during the blackout period 23:45 - 05:00 UTC, excerpt below. Is it possible there is just no data returned from FitBit API during this period?
2024-02-26 03:38:08,624 - DEBUG - Running job Job(interval=3, unit=minutes, do=<lambda>, args=(), kwargs={})
2024-02-26 03:38:08,624 - DEBUG - Requesting data from fitbit via Url : https://api.fitbit.com/1/user/-/activities/heart/date/2024-02-26/1d/1sec.json
2024-02-26 03:38:08,625 - DEBUG - Starting new HTTPS connection (1): api.fitbit.com:443
2024-02-26 03:38:09,118 - DEBUG - https://api.fitbit.com:443 "GET /1/user/-/activities/heart/date/2024-02-26/1d/1sec.json HTTP/1.1" 200 None
2024-02-26 03:38:09,121 - INFO - Recorded HeartRate_Intraday intraday for date 2024-02-26
2024-02-26 03:38:09,122 - DEBUG - Requesting data from fitbit via Url : https://api.fitbit.com/1/user/-/activities/steps/date/2024-02-26/1d/1min.json
2024-02-26 03:38:09,124 - DEBUG - Starting new HTTPS connection (1): api.fitbit.com:443
2024-02-26 03:38:09,693 - DEBUG - https://api.fitbit.com:443 "GET /1/user/-/activities/steps/date/2024-02-26/1d/1min.json HTTP/1.1" 200 None
2024-02-26 03:38:09,736 - INFO - Recorded Steps_Intraday intraday for date 2024-02-26
2024-02-26 03:38:09,890 - DEBUG - http://influxdb:8086 "POST /write?db=fitbit_database HTTP/1.1" 204 0
2024-02-26 03:38:09,891 - INFO - Successfully updated influxdb database with new points
2024-02-26 03:41:10,065 - DEBUG - Running job Job(interval=3, unit=minutes, do=<lambda>, args=(), kwargs={})
2024-02-26 03:41:10,065 - DEBUG - Requesting data from fitbit via Url : https://api.fitbit.com/1/user/-/activities/heart/date/2024-02-26/1d/1sec.json
2024-02-26 03:41:10,066 - DEBUG - Starting new HTTPS connection (1): api.fitbit.com:443
2024-02-26 03:41:10,882 - DEBUG - https://api.fitbit.com:443 "GET /1/user/-/activities/heart/date/2024-02-26/1d/1sec.json HTTP/1.1" 200 None
2024-02-26 03:41:10,884 - INFO - Recorded HeartRate_Intraday intraday for date 2024-02-26
2024-02-26 03:41:10,885 - DEBUG - Requesting data from fitbit via Url : https://api.fitbit.com/1/user/-/activities/steps/date/2024-02-26/1d/1min.json
2024-02-26 03:41:10,886 - DEBUG - Starting new HTTPS connection (1): api.fitbit.com:443
2024-02-26 03:41:11,637 - DEBUG - https://api.fitbit.com:443 "GET /1/user/-/activities/steps/date/2024-02-26/1d/1min.json HTTP/1.1" 200 None
2024-02-26 03:41:11,677 - INFO - Recorded Steps_Intraday intraday for date 2024-02-26
2024-02-26 03:41:11,834 - DEBUG - http://influxdb:8086 "POST /write?db=fitbit_database HTTP/1.1" 204 0
2024-02-26 03:41:11,835 - INFO - Successfully updated influxdb database with new points
2024-02-26 03:42:41,923 - DEBUG - Running job Job(interval=20, unit=minutes, do=get_battery_level, args=(), kwargs={})
2024-02-26 03:42:41,924 - DEBUG - Requesting data from fitbit via Url : https://api.fitbit.com/1/user/-/devices.json
2024-02-26 03:42:41,925 - DEBUG - Starting new HTTPS connection (1): api.fitbit.com:443
2024-02-26 03:42:42,612 - DEBUG - https://api.fitbit.com:443 "GET /1/user/-/devices.json HTTP/1.1" 200 None
2024-02-26 03:42:42,614 - INFO - Recorded battery level for 'Inspire3'
2024-02-26 03:42:42,628 - DEBUG - http://influxdb:8086 "POST /write?db=fitbit_database HTTP/1.1" 204 0
2024-02-26 03:42:42,628 - INFO - Successfully updated influxdb database with new points
2024-02-26 03:44:12,711 - DEBUG - Running job Job(interval=3, unit=minutes, do=<lambda>, args=(), kwargs={})
2024-02-26 03:44:12,712 - DEBUG - Requesting data from fitbit via Url : https://api.fitbit.com/1/user/-/activities/heart/date/2024-02-26/1d/1sec.json
2024-02-26 03:44:12,713 - DEBUG - Starting new HTTPS connection (1): api.fitbit.com:443
2024-02-26 03:44:13,040 - DEBUG - https://api.fitbit.com:443 "GET /1/user/-/activities/heart/date/2024-02-26/1d/1sec.json HTTP/1.1" 200 None
2024-02-26 03:44:13,043 - INFO - Recorded HeartRate_Intraday intraday for date 2024-02-26
2024-02-26 03:44:13,043 - DEBUG - Requesting data from fitbit via Url : https://api.fitbit.com/1/user/-/activities/steps/date/2024-02-26/1d/1min.json
2024-02-26 03:44:13,045 - DEBUG - Starting new HTTPS connection (1): api.fitbit.com:443
2024-02-26 03:44:13,355 - DEBUG - https://api.fitbit.com:443 "GET /1/user/-/activities/steps/date/2024-02-26/1d/1min.json HTTP/1.1" 200 None
2024-02-26 03:44:13,398 - INFO - Recorded Steps_Intraday intraday for date 2024-02-26
The time in the log should be in your local timezone as you mounted the local time and timezone. So check in that period and see if you find the same.
Your internet connection is stable throughout?
My apologies - to clarify, my host and docker container both are in UTC. Only my browser view (and the Grafana screenshot) are in EST.
cat /etc/timezone
Etc/UTCHere is a recent screenshot where I have standardized Grafana to show UTC.
And an excerpt from the logs during the black-out
2024-02-27 01:05:51,135 - DEBUG - Running job Job(interval=3, unit=minutes, do=<lambda>, args=(), kwargs={})
2024-02-27 01:05:51,136 - DEBUG - Requesting data from fitbit via Url : https://api.fitbit.com/1/user/-/activities/heart/date/2024-02-27/1d/1sec.json
2024-02-27 01:05:51,137 - DEBUG - Starting new HTTPS connection (1): api.fitbit.com:443
2024-02-27 01:05:51,400 - DEBUG - https://api.fitbit.com:443 "GET /1/user/-/activities/heart/date/2024-02-27/1d/1sec.json HTTP/1.1" 200 None
2024-02-27 01:05:51,402 - INFO - Recorded HeartRate_Intraday intraday for date 2024-02-27
2024-02-27 01:05:51,402 - DEBUG - Requesting data from fitbit via Url : https://api.fitbit.com/1/user/-/activities/steps/date/2024-02-27/1d/1min.json
2024-02-27 01:05:51,403 - DEBUG - Starting new HTTPS connection (1): api.fitbit.com:443
2024-02-27 01:05:51,771 - DEBUG - https://api.fitbit.com:443 "GET /1/user/-/activities/steps/date/2024-02-27/1d/1min.json HTTP/1.1" 200 None
2024-02-27 01:05:51,828 - INFO - Recorded Steps_Intraday intraday for date 2024-02-27
2024-02-27 01:05:52,006 - DEBUG - http://influxdb:8086 "POST /write?db=fitbit_database HTTP/1.1" 204 0
2024-02-27 01:05:52,007 - INFO - Successfully updated influxdb database with new points
2024-02-27 01:08:52,179 - DEBUG - Running job Job(interval=3, unit=minutes, do=<lambda>, args=(), kwargs={})
2024-02-27 01:08:52,180 - DEBUG - Requesting data from fitbit via Url : https://api.fitbit.com/1/user/-/activities/heart/date/2024-02-27/1d/1sec.json
2024-02-27 01:08:52,181 - DEBUG - Starting new HTTPS connection (1): api.fitbit.com:443
2024-02-27 01:08:52,696 - DEBUG - https://api.fitbit.com:443 "GET /1/user/-/activities/heart/date/2024-02-27/1d/1sec.json HTTP/1.1" 200 None
2024-02-27 01:08:52,697 - INFO - Recorded HeartRate_Intraday intraday for date 2024-02-27
2024-02-27 01:08:52,697 - DEBUG - Requesting data from fitbit via Url : https://api.fitbit.com/1/user/-/activities/steps/date/2024-02-27/1d/1min.json
2024-02-27 01:08:52,698 - DEBUG - Starting new HTTPS connection (1): api.fitbit.com:443
2024-02-27 01:08:53,107 - DEBUG - https://api.fitbit.com:443 "GET /1/user/-/activities/steps/date/2024-02-27/1d/1min.json HTTP/1.1" 200 None
2024-02-27 01:08:53,195 - INFO - Recorded Steps_Intraday intraday for date 2024-02-27
2024-02-27 01:08:53,441 - DEBUG - http://influxdb:8086 "POST /write?db=fitbit_database HTTP/1.1" 204 0
2024-02-27 01:08:53,441 - INFO - Successfully updated influxdb database with new points
Thank you @bhammack for reporting the issue.
I looked into it and found the issue going on here. Interestingly, I never thought about such a scenario before.
The script considers you and your server in the same timezone, and it decides the date for the data fetching based on the server/containers' timezone. But here you are in UTC-5 and your server/container in UTC.
The script fetches heart rate and steps data every 3 minutes for the whole day ( based on the current Date of the server ). Now, if you think about it, your date and the server's date stay in sync until it's 7 PM for you ( given you are in UTC-5 ). Before that, the server fetches the data for the current date and localizes it to your time zone, so everything updates perfectly. After that, the server's date is the next date relative to yours. so after 7 PM your time, the script will try fetching data for the next day ( as the date is now changed for the server ) and your data for the current day will not update anymore. So it will leave a gap post 7 PM for you until 23:59, every day. The issue will be resolved if you change your server time to your current timezone. But given that it's a potential issue with the script, I took some time to fix and refactor the code.
I have released a new version today ( the docker container was updated too ), with this issue fixed, where you can manually supply your timezone with TZ identifiers from here. I recommend you simply leave it to the default Automatic setting ( it will fetch your current timezone from your Fitbit profile ). Check the new docker-compose.yml file and update your stack accordingly. Afterward, run a docker compose pull and docker compose down && docker compose up -d to restart the container. Your token files will be reused and you won't have to go through the initial setup process again.
Let me know here if that fixed your problem and I will close this issue. Thank you for bringing this to my attention. It's an edge case that should have been considered while writing the code.
Awesome thanks for the deep dive here! I really appreciate the quick turn around and fix! I've updated my container with the latest image and will monitor it for the next 24 hours to ensure there is no data gaps.
My Pleasure. Let me know by tomorrow, and I can close this issue!
Hello @bhammack , I was just wondering if you have an update on if the fix worked for you so that I can close this issue.
Hey sorry for the delay, I did not have access to my fitbit most of Thursday to verify.
It looks like it's working great! However, looking at last night's stats for HR, I see a small gap (local time 23:51 - 00:00). I can't recall removing the device, and it may be due to user error. I'll monitor it again for tonight to get a second verification.
@bhammack I hope everything is working as expected now? Do you see any unexpected gaps anymore?
Yes, seems there's still a small gap starting from 23:52:55 to 00:00 the following day.
Thank you again @bhammack for this. Without you I would never notice such small gaps leading to solving the issue with my code. I thought about it and it made sense, so I checked my own Grafana, and seen similar data missing every day around 12 for a few minutes.
Let's see what's going on here. Fitbit app syncs around every 10-15 minutes in background but this depends on phone model ( ios, android ), batter saving mode etc. So it's not very predictable. So we can clearly see here is a delay between your real time data and synced data in fitbit's server. As the script fetches the data from the fitbit's server ( and not from the device itself ), the update always lags behind a little even though the script pulls the data ( HR and steps ) every 3 minutes from fitbit's server.
Now your script is synced with your time ( from your time zone variable, set automatically ). So suppose it fetches data in 3 minutes interval on ...... 23:50, 23:53, 23:56, 23:59 (3rd April 2024) and 00:02, 00:05, 00:08 ..... (4th April 2024) but the Fitbit app syncs your data with server on 23:52 (3rd April 2024) and 00:07 (4th April 2024). With this scenario, your 3rd April data will be stuck with 23:52 as the script won't be able to update it anymore. Your next-day data will start filling from 00:00 again.
I hope you understood the underlaying issue. I have made adjustments in the script with a comment referring back to this issue. That will fetch the previous day's HR and steps data to fill any such gaps hourly. The new docker image is already available for that patch. you can follow the above instructions to update the container.
Also note that sometimes, there can be a few minutes of data missing in Fitbit database itself. for example, for 2024-03-03, I have 23:59 missing on their database which may lead to a tiny gap. This has nothing to do about the script. You can use this tool to see your data after you authorize it [ use this endpoint - /1/user/-/activities/heart/date/{date}/1d/{detail-level}.json ] : https://dev.fitbit.com/build/reference/web-api/explore/
Hopefully, that will fix this issue once and for all! Thanks again!