sabeechen / hassio-google-drive-backup

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

Error while backing up #1027

Open settingtea94 opened 2 months ago

settingtea94 commented 2 months ago

Copy the info from the previous page here

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.4.3 Supervisor Version: 2024.04.0 Supervisor Channel: stable Hassos Version: 12.2 Docker Version: 25.0.5 Architecture: amd64 Machine: generic-x86-64 Date: 2024-04-20T14:41:04.453687+00:00 Timezone: America/Toronto Failure Time: 2024-04-20T13:34:52.317150+00:00 Last Good Sync: 2024-04-20T13:34:42.237996+00:00 Next Sync: 2024-04-20T15:34:52.317150+00:00 Next Backup: 2024-04-21T04:00:00+00:00 Next Cache Warm: 2024-04-20T15:23:48.638456+00:00 Time Offset: 0.0

Exception:

  addon/backup/model/coordinator.py:198 (_sync)
  addon/backup/model/model.py:203 (sync)
  addon/backup/model/model.py:316 (_syncBackups)
  addon/backup/ha/hasource.py:280 (get)
  addon/backup/ha/harequests.py:34 (wrap_and_call)
  addon/backup/ha/harequests.py:135 (backups)
  addon/backup/ha/harequests.py:34 (wrap_and_call)
  addon/backup/ha/harequests.py:269 (_getHassioData)
  addon/backup/ha/harequests.py:225 (_validateHassioReply)
  /site-packages/aiohttp/client_reqrep.py:1059 (raise_for_status)
aiohttp.client_exceptions.ClientResponseError: 500, message='Internal Server Error', url=URL('http://supervisor/backups')

Backups:

 {
    "HomeAssistant": {
        "backups": 18,
        "retained": 0,
        "deletable": 18,
        "name": "HomeAssistant",
        "title": "Home Assistant",
        "latest": "2024-04-20T04:00:00Z",
        "max": 25,
        "enabled": true,
        "icon": "home-assistant",
        "ignored": 79,
        "detail": "",
        "size": "56.2 GB",
        "ignored_size": "71.3 GB"
    },
    "GoogleDrive": {
        "backups": 1,
        "retained": 0,
        "deletable": 1,
        "name": "GoogleDrive",
        "title": "Google Drive",
        "latest": "2024-04-20T04:00:00Z",
        "max": 1,
        "enabled": true,
        "icon": "google-drive",
        "ignored": 0,
        "detail": "alexxgergely@gmail.com",
        "size": "3.3 GB",
        "ignored_size": "0.0 B",
        "free_space": "1.2 GB"
    }
}
Config:
 {
    "Setting.MAX_BACKUPS_IN_HA": 25,
    "Setting.MAX_BACKUPS_IN_GOOGLE_DRIVE": 1,
    "Setting.DAYS_BETWEEN_BACKUPS": 1.0,
    "Setting.DELETE_BEFORE_NEW_BACKUP": true,
    "Setting.BACKUP_TIME_OF_DAY": "00:00",
    "Setting.GENERATIONAL_DAYS": 7,
    "Setting.GENERATIONAL_WEEKS": 4,
    "Setting.GENERATIONAL_MONTHS": 12,
    "Setting.GENERATIONAL_YEARS": 2,
    "Setting.GENERATIONAL_DAY_OF_WEEK": "sun",
    "Setting.GENERATIONAL_DELETE_EARLY": true,
    "Setting.SEND_ERROR_REPORTS": true
}
Addon Logs:
 04-20 06:48:29 INFO [backup.model.coordinator] Syncing Backups
04-20 06:48:39 ERROR [backup.model.coordinator] 
  addon/backup/model/coordinator.py:198 (_sync)
  addon/backup/model/model.py:203 (sync)
  addon/backup/model/model.py:316 (_syncBackups)
  addon/backup/ha/hasource.py:280 (get)
  addon/backup/ha/harequests.py:34 (wrap_and_call)
  addon/backup/ha/harequests.py:135 (backups)
  addon/backup/ha/harequests.py:34 (wrap_and_call)
  addon/backup/ha/harequests.py:269 (_getHassioData)
  addon/backup/ha/harequests.py:225 (_validateHassioReply)
  /site-packages/aiohttp/client_reqrep.py:1059 (raise_for_status)
aiohttp.client_exceptions.ClientResponseError: 500, message='Internal Server Error', url=URL('http://supervisor/backups')

04-20 06:48:39 INFO [backup.model.coordinator] I'll try again in 5 minutes, 20 seconds
04-20 06:48:40 DEBUG [backup.model.destinationprecache] Preemptively retrieving and caching info from the backup destination to avoid peak demand
04-20 06:54:00 DEBUG [backup.model.syncer] Sync requested by Coordinator
04-20 06:54:00 INFO [backup.model.coordinator] Syncing Backups
04-20 06:54:10 ERROR [backup.model.coordinator] 
  addon/backup/model/coordinator.py:198 (_sync)
  addon/backup/model/model.py:203 (sync)
  addon/backup/model/model.py:316 (_syncBackups)
  addon/backup/ha/hasource.py:280 (get)
  addon/backup/ha/harequests.py:34 (wrap_and_call)
  addon/backup/ha/harequests.py:135 (backups)
  addon/backup/ha/harequests.py:34 (wrap_and_call)
  addon/backup/ha/harequests.py:269 (_getHassioData)
  addon/backup/ha/harequests.py:225 (_validateHassioReply)
  /site-packages/aiohttp/client_reqrep.py:1059 (raise_for_status)
aiohttp.client_exceptions.ClientResponseError: 500, message='Internal Server Error', url=URL('http://supervisor/backups')

04-20 06:54:10 INFO [backup.model.coordinator] I'll try again in 10 minutes, 40 seconds
04-20 06:56:40 DEBUG [backup.model.destinationprecache] Preemptively retrieving and caching info from the backup destination to avoid peak demand
04-20 07:04:50 DEBUG [backup.model.syncer] Sync requested by Coordinator
04-20 07:04:50 INFO [backup.model.coordinator] Syncing Backups
04-20 07:05:00 ERROR [backup.model.coordinator] 
  addon/backup/model/coordinator.py:198 (_sync)
  addon/backup/model/model.py:203 (sync)
  addon/backup/model/model.py:316 (_syncBackups)
  addon/backup/ha/hasource.py:280 (get)
  addon/backup/ha/harequests.py:34 (wrap_and_call)
  addon/backup/ha/harequests.py:135 (backups)
  addon/backup/ha/harequests.py:34 (wrap_and_call)
  addon/backup/ha/harequests.py:269 (_getHassioData)
  addon/backup/ha/harequests.py:225 (_validateHassioReply)
  /site-packages/aiohttp/client_reqrep.py:1059 (raise_for_status)
aiohttp.client_exceptions.ClientResponseError: 500, message='Internal Server Error', url=URL('http://supervisor/backups')

04-20 07:05:00 INFO [backup.model.coordinator] I'll try again in 21 minutes, 20 seconds
04-20 07:21:41 DEBUG [backup.model.destinationprecache] Preemptively retrieving and caching info from the backup destination to avoid peak demand
04-20 07:26:20 DEBUG [backup.model.syncer] Sync requested by Coordinator
04-20 07:26:20 INFO [backup.model.coordinator] Syncing Backups
04-20 07:26:31 ERROR [backup.model.coordinator] 
  addon/backup/model/coordinator.py:198 (_sync)
  addon/backup/model/model.py:203 (sync)
  addon/backup/model/model.py:316 (_syncBackups)
  addon/backup/ha/hasource.py:280 (get)
  addon/backup/ha/harequests.py:34 (wrap_and_call)
  addon/backup/ha/harequests.py:135 (backups)
  addon/backup/ha/harequests.py:34 (wrap_and_call)
  addon/backup/ha/harequests.py:269 (_getHassioData)
  addon/backup/ha/harequests.py:225 (_validateHassioReply)
  /site-packages/aiohttp/client_reqrep.py:1059 (raise_for_status)
aiohttp.client_exceptions.ClientResponseError: 500, message='Internal Server Error', url=URL('http://supervisor/backups')

04-20 07:26:31 INFO [backup.model.coordinator] I'll try again in 42 minutes, 40 seconds
04-20 08:01:41 DEBUG [backup.model.destinationprecache] Preemptively retrieving and caching info from the backup destination to avoid peak demand
04-20 08:01:41 DEBUG [backup.drive.driverequests] Requesting refreshed Google Drive credentials
04-20 08:09:11 DEBUG [backup.model.syncer] Sync requested by Coordinator
04-20 08:09:11 INFO [backup.model.coordinator] Syncing Backups
04-20 08:09:22 ERROR [backup.model.coordinator] 
  addon/backup/model/coordinator.py:198 (_sync)
  addon/backup/model/model.py:203 (sync)
  addon/backup/model/model.py:316 (_syncBackups)
  addon/backup/ha/hasource.py:280 (get)
  addon/backup/ha/harequests.py:34 (wrap_and_call)
  addon/backup/ha/harequests.py:135 (backups)
  addon/backup/ha/harequests.py:34 (wrap_and_call)
  addon/backup/ha/harequests.py:269 (_getHassioData)
  addon/backup/ha/harequests.py:225 (_validateHassioReply)
  /site-packages/aiohttp/client_reqrep.py:1059 (raise_for_status)
aiohttp.client_exceptions.ClientResponseError: 500, message='Internal Server Error', url=URL('http://supervisor/backups')

04-20 08:09:22 INFO [backup.model.coordinator] I'll try again in 1 hours, 25 minutes, 20 seconds
04-20 09:33:42 DEBUG [backup.model.destinationprecache] Preemptively retrieving and caching info from the backup destination to avoid peak demand
04-20 09:33:42 DEBUG [backup.drive.driverequests] Requesting refreshed Google Drive credentials
04-20 09:34:42 DEBUG [backup.model.syncer] Sync requested by Coordinator
04-20 09:34:42 INFO [backup.model.coordinator] Syncing Backups
04-20 09:34:52 ERROR [backup.model.coordinator] 
  addon/backup/model/coordinator.py:198 (_sync)
  addon/backup/model/model.py:203 (sync)
  addon/backup/model/model.py:316 (_syncBackups)
  addon/backup/ha/hasource.py:280 (get)
  addon/backup/ha/harequests.py:34 (wrap_and_call)
  addon/backup/ha/harequests.py:135 (backups)
  addon/backup/ha/harequests.py:34 (wrap_and_call)
  addon/backup/ha/harequests.py:269 (_getHassioData)
  addon/backup/ha/harequests.py:225 (_validateHassioReply)
  /site-packages/aiohttp/client_reqrep.py:1059 (raise_for_status)
aiohttp.client_exceptions.ClientResponseError: 500, message='Internal Server Error', url=URL('http://supervisor/backups')

04-20 09:34:52 INFO [backup.model.coordinator] I'll try again in 2 hours
Supervisor Logs:
 2024-04-20 10:37:03.411 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API request running
2024-04-20 10:37:03.453 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API error: Cannot proxy websocket message of unsupported type: 257
2024-04-20 10:37:03.454 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API for 57e6a4ee_hydroqc closed
2024-04-20 10:37:03.474 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API request initialize
2024-04-20 10:37:03.475 INFO (MainThread) [supervisor.api.proxy] WebSocket access from 57e6a4ee_hydroqc
2024-04-20 10:37:03.481 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API request running
2024-04-20 10:37:03.498 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API error: Cannot proxy websocket message of unsupported type: 257
2024-04-20 10:37:03.498 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API for 57e6a4ee_hydroqc closed
2024-04-20 10:37:03.506 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API request initialize
2024-04-20 10:37:03.507 INFO (MainThread) [supervisor.api.proxy] WebSocket access from 57e6a4ee_hydroqc
2024-04-20 10:37:03.513 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API request running
2024-04-20 10:37:03.530 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API error: Cannot proxy websocket message of unsupported type: 257
2024-04-20 10:37:03.530 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API for 57e6a4ee_hydroqc closed
2024-04-20 10:37:04.536 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API request initialize
2024-04-20 10:37:04.539 INFO (MainThread) [supervisor.api.proxy] WebSocket access from 57e6a4ee_hydroqc
2024-04-20 10:37:04.547 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API request running
2024-04-20 10:37:04.566 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API error: Cannot proxy websocket message of unsupported type: 257
2024-04-20 10:37:04.566 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API for 57e6a4ee_hydroqc closed
2024-04-20 10:37:05.101 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API request initialize
2024-04-20 10:37:05.104 INFO (MainThread) [supervisor.api.proxy] WebSocket access from 57e6a4ee_hydroqc
2024-04-20 10:37:05.110 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API request running
2024-04-20 10:37:05.130 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API error: Cannot proxy websocket message of unsupported type: 257
2024-04-20 10:37:05.132 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API for 57e6a4ee_hydroqc closed
2024-04-20 10:37:05.151 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API request initialize
2024-04-20 10:37:05.154 INFO (MainThread) [supervisor.api.proxy] WebSocket access from 57e6a4ee_hydroqc
2024-04-20 10:37:05.165 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API request running
2024-04-20 10:37:05.256 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API error: Cannot proxy websocket message of unsupported type: 257
2024-04-20 10:37:05.256 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API for 57e6a4ee_hydroqc closed
2024-04-20 10:41:04.484 INFO (MainThread) [supervisor.api.middleware.security] /supervisor/logs access from cebe7a76_hassio_google_drive_backup
Home Assistant Core Logs:
     data = data.decode()
           ^^^^^^^^^^^^^
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xd3 in position 6: invalid continuation byte
2024-04-20 10:41:04.447 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback _SelectorDatagramTransport._read_ready()
Traceback (most recent call last):
  File "/config/custom_components/localtuya/discovery.py", line 65, in datagram_received
    data = decrypt_udp(data)
           ^^^^^^^^^^^^^^^^^
  File "/config/custom_components/localtuya/discovery.py", line 30, in decrypt_udp
    return _unpad(decryptor.update(message) + decryptor.finalize()).decode()
                                              ^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/cryptography/hazmat/primitives/ciphers/base.py", line 184, in finalize
    data = self._ctx.finalize()
           ^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/cryptography/hazmat/backends/openssl/ciphers.py", line 223, in finalize
    raise ValueError(
ValueError: The length of the provided data is not a multiple of the block length.

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.12/asyncio/events.py", line 88, in _run
    self._context.run(self._callback, *self._args)
  File "/usr/local/lib/python3.12/asyncio/selector_events.py", line 1238, in _read_ready
    self._protocol.datagram_received(data, addr)
  File "/config/custom_components/localtuya/discovery.py", line 67, in datagram_received
    data = data.decode()
           ^^^^^^^^^^^^^
UnicodeDecodeError: 'utf-8' codec can't decode byte 0x80 in position 5: invalid start byte
sabeechen commented 2 months ago

There is likely something in your supervisor logs that would explain what's causing this, but your supervisor logs are getting spammed with error messages from somewhere else many times a second:

�[32m2024-04-20 10:37:05.154 INFO (MainThread) [supervisor.api.proxy] WebSocket access from 57e6a4ee_hydroqc�[0m
�[32m2024-04-20 10:37:05.165 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API request running�[0m
�[32m2024-04-20 10:37:05.256 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API error: Cannot proxy websocket message of unsupported type: 257�[0m
�[32m2024-04-20 10:37:05.256 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API for 57e6a4ee_hydroqc closed�[0m