search

sabeechen / hassio-google-drive-backup

Automatically create and sync Home Assistant backups into Google Drive
MIT License
3.21k stars 198 forks source link

The addon has made too many requests to Google drive #1007

Open rasbon94 opened 8 months ago

rasbon94 commented 8 months ago
Description:
If you have anything else that could help explain what happened, click "Markdown" above and write it here.

Addon version: 0.112.1 Home Assistant Version: 2024.3.1 Supervisor Version: 2024.03.1 Supervisor Channel: stable Hassos Version: 12.1 Docker Version: 24.0.7 Architecture: aarch64 Machine: raspberrypi4-64 Date: 2024-03-31T05:53:47.747263+00:00 Timezone: Europe/Copenhagen Failure Time: 2024-03-31T04:16:56.336212+00:00 Last Good Sync: 2024-03-31T04:15:53.310074+00:00 Next Sync: 2024-03-31T06:16:56.336212+00:00 Next Backup: 2024-04-01T01:00:00+00:00 Next Cache Warm: 2024-03-31T06:07:37.979188+00:00 Time Offset: 0.0

Exception:

  addon/backup/model/coordinator.py:198 (_sync)
  addon/backup/model/model.py:250 (sync)
  addon/backup/drive/drivesource.py:205 (save)
  addon/backup/drive/driverequests.py:238 (create)
  addon/backup/drive/driverequests.py:394 (retryRequest)
  addon/backup/util/backoff.py:37 (backoff)
  addon/backup/drive/driverequests.py:388 (retryRequest)
  addon/backup/creds/driverequester.py:47 (request)
backup.exceptions.exceptions.GoogleRateLimitError

Backups:

 {
    "HomeAssistant": {
        "backups": 2,
        "retained": 0,
        "deletable": 2,
        "name": "HomeAssistant",
        "title": "Home Assistant",
        "latest": "2024-03-31T01:00:00Z",
        "max": 2,
        "enabled": true,
        "icon": "home-assistant",
        "ignored": 17,
        "detail": "",
        "size": "189.2 MB",
        "ignored_size": "141.2 MB",
        "free_space": "18.4 GB"
    },
    "GoogleDrive": {
        "backups": 5,
        "retained": 0,
        "deletable": 5,
        "name": "GoogleDrive",
        "title": "Google Drive",
        "latest": "2024-03-30T02:00:00Z",
        "max": 5,
        "enabled": true,
        "icon": "google-drive",
        "ignored": 0,
        "detail": "rasbonhomeassistant@gmail.com",
        "size": "465.6 MB",
        "ignored_size": "0.0 B",
        "free_space": "467.8 MB"
    }
}
Config:
 {
    "Setting.MAX_BACKUPS_IN_HA": 2,
    "Setting.MAX_BACKUPS_IN_GOOGLE_DRIVE": 5,
    "Setting.DAYS_BETWEEN_BACKUPS": 1.0,
    "Setting.BACKUP_TIME_OF_DAY": "03:00"
}
Addon Logs:
 03-31 05:58:16 DEBUG [backup.model.destinationprecache] Preemptively retrieving and caching info from the backup destination to avoid peak demand
03-31 05:58:16 DEBUG [backup.drive.driverequests] Requesting refreshed Google Drive credentials
03-31 06:02:38 DEBUG [backup.model.syncer] Sync requested by Coordinator
03-31 06:02:38 INFO [backup.model.coordinator] Syncing Backups
03-31 06:02:38 INFO [backup.watcher] A backup directory file was modified, we'll check for new backups soon.
03-31 06:02:38 INFO [backup.drive.drivesource] Uploading 'Full Backup 2024-03-31 03:00:00' to Google Drive
03-31 06:02:38 DEBUG [backup.drive.driverequests] Attempting to resume a previously failed upload where we left off
03-31 06:02:38 ERROR [backup.drive.driverequests] The addon has made too many requests to Google Drive, and will back off: we'll retry in 2 seconds
03-31 06:02:40 ERROR [backup.drive.driverequests] The addon has made too many requests to Google Drive, and will back off: we'll retry in 4 seconds
03-31 06:02:44 ERROR [backup.drive.driverequests] The addon has made too many requests to Google Drive, and will back off: we'll retry in 8 seconds
03-31 06:02:52 ERROR [backup.drive.driverequests] The addon has made too many requests to Google Drive, and will back off: we'll retry in 16 seconds
03-31 06:03:08 ERROR [backup.drive.driverequests] The addon has made too many requests to Google Drive, and will back off: we'll retry in 32 seconds
03-31 06:03:40 ERROR [backup.model.coordinator] The addon has made too many requests to Google Drive, and will back off
03-31 06:03:40 INFO [backup.model.coordinator] I'll try again in 2 hours
03-31 06:03:41 DEBUG [backup.watcher] Checking backup source for changes...
03-31 06:15:42 INFO [backup.watcher] A backup directory file was modified, we'll check for new backups soon.
03-31 06:15:53 DEBUG [backup.watcher] Checking backup source for changes...
03-31 06:15:53 DEBUG [backup.model.syncer] Sync requested by Backup Directory Watcher
03-31 06:15:53 INFO [backup.model.coordinator] Syncing Backups
03-31 06:15:53 INFO [backup.watcher] A backup directory file was modified, we'll check for new backups soon.
03-31 06:15:53 INFO [backup.drive.drivesource] Uploading 'Full Backup 2024-03-31 03:00:00' to Google Drive
03-31 06:15:53 DEBUG [backup.drive.driverequests] Attempting to resume a previously failed upload where we left off
03-31 06:15:53 ERROR [backup.drive.driverequests] The addon has made too many requests to Google Drive, and will back off: we'll retry in 2 seconds
03-31 06:15:56 ERROR [backup.drive.driverequests] The addon has made too many requests to Google Drive, and will back off: we'll retry in 4 seconds
03-31 06:16:00 ERROR [backup.drive.driverequests] The addon has made too many requests to Google Drive, and will back off: we'll retry in 8 seconds
03-31 06:16:08 ERROR [backup.drive.driverequests] The addon has made too many requests to Google Drive, and will back off: we'll retry in 16 seconds
03-31 06:16:24 ERROR [backup.drive.driverequests] The addon has made too many requests to Google Drive, and will back off: we'll retry in 32 seconds
03-31 06:16:56 ERROR [backup.model.coordinator] The addon has made too many requests to Google Drive, and will back off
03-31 06:16:56 INFO [backup.model.coordinator] I'll try again in 2 hours
03-31 06:16:56 DEBUG [backup.watcher] Checking backup source for changes...
Supervisor Logs:
 2024-03-31 07:16:05.872 INFO (MainThread) [supervisor.resolution.checks.base] Run check for pwned/addon
2024-03-31 07:16:05.873 INFO (MainThread) [supervisor.resolution.checks.base] Run check for trust/supervisor
2024-03-31 07:16:05.890 INFO (MainThread) [supervisor.resolution.checks.base] Run check for docker_config/system
2024-03-31 07:16:05.891 INFO (MainThread) [supervisor.resolution.checks.base] Run check for multiple_data_disks/system
2024-03-31 07:16:05.891 INFO (MainThread) [supervisor.resolution.check] System checks complete
2024-03-31 07:16:05.891 INFO (MainThread) [supervisor.resolution.evaluate] Starting system evaluation with state running
2024-03-31 07:16:06.108 INFO (MainThread) [supervisor.resolution.evaluate] System evaluation complete
2024-03-31 07:16:06.109 INFO (MainThread) [supervisor.resolution.fixup] Starting system autofix at state running
2024-03-31 07:16:06.109 INFO (MainThread) [supervisor.resolution.fixup] System autofix complete
2024-03-31 07:16:31.506 INFO (MainThread) [supervisor.homeassistant.api] Updated Home Assistant API token
2024-03-31 07:16:38.433 INFO (MainThread) [supervisor.store.git] Update add-on https://github.com/zigbee2mqtt/hassio-zigbee2mqtt repository
2024-03-31 07:16:38.442 INFO (MainThread) [supervisor.store.git] Update add-on https://github.com/adamoutler/HassOSConfigurator repository
2024-03-31 07:16:38.449 INFO (MainThread) [supervisor.store.git] Update add-on https://github.com/esphome/home-assistant-addon repository
2024-03-31 07:16:38.457 INFO (MainThread) [supervisor.store.git] Update add-on https://github.com/adamoutler/HassOSArgonOneAddon repository
2024-03-31 07:16:38.468 INFO (MainThread) [supervisor.store.git] Update add-on https://github.com/hassio-addons/repository repository
2024-03-31 07:16:38.474 INFO (MainThread) [supervisor.store.git] Update add-on https://github.com/home-assistant/addons repository
2024-03-31 07:16:38.487 INFO (MainThread) [supervisor.store.git] Update add-on https://github.com/sabeechen/hassio-google-drive-backup repository
2024-03-31 07:16:40.533 INFO (MainThread) [supervisor.store] Loading add-ons from store: 89 all - 0 new - 0 remove
2024-03-31 07:16:40.533 INFO (MainThread) [supervisor.store] Loading add-ons from store: 89 all - 0 new - 0 remove
2024-03-31 07:18:31.583 WARNING (MainThread) [supervisor.addons.options] Unknown option 'homeassistant' for Zigbee2MQTT (45df7312_zigbee2mqtt)
2024-03-31 07:23:31.583 WARNING (MainThread) [supervisor.addons.options] Unknown option 'homeassistant' for Zigbee2MQTT (45df7312_zigbee2mqtt)
2024-03-31 07:28:31.582 WARNING (MainThread) [supervisor.addons.options] Unknown option 'homeassistant' for Zigbee2MQTT (45df7312_zigbee2mqtt)
2024-03-31 07:33:31.583 WARNING (MainThread) [supervisor.addons.options] Unknown option 'homeassistant' for Zigbee2MQTT (45df7312_zigbee2mqtt)
2024-03-31 07:38:31.584 WARNING (MainThread) [supervisor.addons.options] Unknown option 'homeassistant' for Zigbee2MQTT (45df7312_zigbee2mqtt)
2024-03-31 07:43:31.580 WARNING (MainThread) [supervisor.addons.options] Unknown option 'homeassistant' for Zigbee2MQTT (45df7312_zigbee2mqtt)
2024-03-31 07:46:31.817 INFO (MainThread) [supervisor.homeassistant.api] Updated Home Assistant API token
2024-03-31 07:48:31.583 WARNING (MainThread) [supervisor.addons.options] Unknown option 'homeassistant' for Zigbee2MQTT (45df7312_zigbee2mqtt)
2024-03-31 07:53:31.580 WARNING (MainThread) [supervisor.addons.options] Unknown option 'homeassistant' for Zigbee2MQTT (45df7312_zigbee2mqtt)
2024-03-31 07:53:47.776 INFO (MainThread) [supervisor.api.middleware.security] /supervisor/logs access from cebe7a76_hassio_google_drive_backup
Home Assistant Core Logs:
              ^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/tado/__init__.py", line 204, in update
    self.update_devices()
  File "/usr/src/homeassistant/homeassistant/components/tado/__init__.py", line 247, in update_devices
    devices = self.tado.get_devices()
              ^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/PyTado/interface.py", line 83, in get_devices
    return self.http.request(request)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/PyTado/http/http.py", line 116, in request
    self.__refresh_token()
  File "/usr/local/lib/python3.12/site-packages/PyTado/http/http.py", line 210, in __refresh_token
    response = self.session.request(
               ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/requests/sessions.py", line 589, in request
    resp = self.send(prep, **send_kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/requests/sessions.py", line 710, in send
    r = dispatch_hook("response", hooks, r, **kwargs)
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/requests/hooks.py", line 30, in dispatch_hook
    _hook_data = hook(hook_data, **kwargs)
                 ^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/PyTado/http/http.py", line 111, in __log_response
    f"Response:\n\tStatusCode: {response_status}\n\tData: {response.json()}"
                                                           ^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/requests/models.py", line 975, in json
    raise RequestsJSONDecodeError(e.msg, e.doc, e.pos)
requests.exceptions.JSONDecodeError: Expecting value: line 1 column 1 (char 0)
sabeechen commented 8 months ago

It looks like I'm occasionally above the "global" limit of queries Google allows per app, so this is something that effects all users. image In the past google has been kind about increasing the global quota for this app. Hopefully they'll be cool about it again.

In the meantime, the easiest way to work around this is to schedule your backup outside the global peak, you have yours scheduled right on top of it. Even moving it to 3:30 AM should be enough.

sabeechen commented 8 months ago

Interesting, I suspect the global spike in traffic last night was caused by the EU's DST shift forward. when 1am suddenly became 2am, twice as many backups got made at once in the affected timezones because many people choose to create backups on the hour.

rasbon94 commented 8 months ago

I moved the schedule forward by half an hour and i dont see the issue. From the graph it seems you are right with the shift forward in time.

Thanks for the support and for creating this wonderful addon.