Deadlock in photo download flow.

[peterjdolan]

When I run gphotos-sync, it reaches the "Done" state, but then hangs until I interrupt the process. At that point, the stack trace seems to indicate a threading deadlock, probably related to a future's exception not being handled appropriately. I may have time to take a look at the code to try to debug it, but not for some time.

Example console output:

05-17 15:02:05 WARNING  gphotos-sync 3.2.1 2024-05-17 15:02:03.747257 
05-17 15:02:07 WARNING  Indexing Google Photos Files ... 
05-17 15:02:08 WARNING  indexed 0 items 
05-17 15:02:34 WARNING  Downloading Photos ... 
05-17 15:11:55 ERROR    
Process failed. 
Traceback (most recent call last):
  File "/home/peter/.local/share/virtualenvs/gphotos-sync-QkASRHkU/lib/python3.11/site-packages/gphotos_sync/__main__.py", line 510, in main
    self.start(args)
  File "/home/peter/.local/share/virtualenvs/gphotos-sync-QkASRHkU/lib/python3.11/site-packages/gphotos_sync/__main__.py", line 450, in start
    self.do_sync(args)
  File "/home/peter/.local/share/virtualenvs/gphotos-sync-QkASRHkU/lib/python3.11/site-packages/gphotos_sync/__main__.py", line 418, in do_sync
    files_downloaded = self.google_photos_down.download_photo_media()
                       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/peter/.local/share/virtualenvs/gphotos-sync-QkASRHkU/lib/python3.11/site-packages/gphotos_sync/GooglePhotosDownload.py", line 178, in download_photo_media
    self.do_download_complete(futures_left)
  File "/home/peter/.local/share/virtualenvs/gphotos-sync-QkASRHkU/lib/python3.11/site-packages/gphotos_sync/GooglePhotosDownload.py", line 326, in do_download_complete
    e = future.exception(timeout=timeout)
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/concurrent/futures/_base.py", line 494, in exception
    raise TimeoutError()
TimeoutError
05-17 15:11:55 WARNING  Done. 


^CException ignored in: <module 'threading' from '/usr/lib/python3.11/threading.py'>
Traceback (most recent call last):
  File "/usr/lib/python3.11/threading.py", line 1553, in _shutdown
    atexit_call()
  File "/usr/lib/python3.11/concurrent/futures/thread.py", line 31, in _python_exit
    t.join()
  File "/usr/lib/python3.11/threading.py", line 1112, in join
    self._wait_for_tstate_lock()
  File "/usr/lib/python3.11/threading.py", line 1132, in _wait_for_tstate_lock
    if lock.acquire(block, timeout):
       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
KeyboardInterrupt:

Another example console output:

05-17 15:16:58 WARNING  gphotos-sync 3.2.1 2024-05-17 15:16:58.223474 
05-17 15:16:58 WARNING  Indexing Google Photos Files ... 
05-17 15:16:59 WARNING  indexed 0 items 
05-17 15:17:02 WARNING  Downloading Photos ... 
05-17 15:18:02 ERROR    
Process failed. 
Traceback (most recent call last):
  File "/home/peter/.local/share/virtualenvs/gphotos-sync-QkASRHkU/lib/python3.11/site-packages/gphotos_sync/__main__.py", line 510, in main
    self.start(args)
  File "/home/peter/.local/share/virtualenvs/gphotos-sync-QkASRHkU/lib/python3.11/site-packages/gphotos_sync/__main__.py", line 450, in start
    self.do_sync(args)
  File "/home/peter/.local/share/virtualenvs/gphotos-sync-QkASRHkU/lib/python3.11/site-packages/gphotos_sync/__main__.py", line 418, in do_sync
    files_downloaded = self.google_photos_down.download_photo_media()
                       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/peter/.local/share/virtualenvs/gphotos-sync-QkASRHkU/lib/python3.11/site-packages/gphotos_sync/GooglePhotosDownload.py", line 178, in download_photo_media
    self.do_download_complete(futures_left)
  File "/home/peter/.local/share/virtualenvs/gphotos-sync-QkASRHkU/lib/python3.11/site-packages/gphotos_sync/GooglePhotosDownload.py", line 326, in do_download_complete
    e = future.exception(timeout=timeout)
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/concurrent/futures/_base.py", line 494, in exception
    raise TimeoutError()
TimeoutError
05-17 15:18:02 WARNING  Done. 
^CException ignored in: <module 'threading' from '/usr/lib/python3.11/threading.py'>
Traceback (most recent call last):
  File "/usr/lib/python3.11/threading.py", line 1553, in _shutdown
    atexit_call()
  File "/usr/lib/python3.11/concurrent/futures/thread.py", line 31, in _python_exit
    t.join()
  File "/usr/lib/python3.11/threading.py", line 1112, in join
    self._wait_for_tstate_lock()
  File "/usr/lib/python3.11/threading.py", line 1132, in _wait_for_tstate_lock
    if lock.acquire(block, timeout):
       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
KeyboardInterrupt:

[gilesknap]

Hmmm this is an interesting one that I have not seen.

May be a little challenging for me to debug without being able to reproduce it myself, so if you can investigate that would be great.

Thanks for the report.