gphotos-sync: Debug logging error after 'Null response in mediaItems.batchGet' message

Looks like this warning is handled gracefully, but the following debug logging causes a fatal error as the message cannot be formatted:

01-03 19:32:49 WARNING  Null response in mediaItems.batchGet dict_keys(['***JUNK REMOVED***'])
--- Logging error ---
Traceback (most recent call last):
  File "/usr/lib64/python3.7/logging/__init__.py", line 1025, in emit
    msg = self.format(record)
  File "/usr/lib64/python3.7/logging/__init__.py", line 869, in format
    return fmt.format(record)
  File "/usr/lib64/python3.7/logging/__init__.py", line 608, in format
    record.message = record.getMessage()
  File "/usr/lib64/python3.7/logging/__init__.py", line 369, in getMessage
    msg = msg % self.args
TypeError: not all arguments converted during string formatting
Call stack:
  File "/home/raintonr/.local/share/virtualenvs/gphotos-sync-jdyTJ4d7/bin/gphotos-sync", line 8, in <module>
    sys.exit(main())
  File "/home/raintonr/.local/share/virtualenvs/gphotos-sync-jdyTJ4d7/lib/python3.7/site-packages/gphotos/Main.py", line 412, in main
    GooglePhotosSyncMain().main()
  File "/home/raintonr/.local/share/virtualenvs/gphotos-sync-jdyTJ4d7/lib/python3.7/site-packages/gphotos/Main.py", line 398, in main
    self.start(args)
  File "/home/raintonr/.local/share/virtualenvs/gphotos-sync-jdyTJ4d7/lib/python3.7/site-packages/gphotos/Main.py", line 351, in start
    self.do_sync(args)
  File "/home/raintonr/.local/share/virtualenvs/gphotos-sync-jdyTJ4d7/lib/python3.7/site-packages/gphotos/Main.py", line 338, in do_sync
    self.google_photos_down.download_photo_media()
  File "/home/raintonr/.local/share/virtualenvs/gphotos-sync-jdyTJ4d7/lib/python3.7/site-packages/gphotos/GooglePhotosDownload.py", line 145, in download_photo_media
    self.download_batch(batch)
  File "/home/raintonr/.local/share/virtualenvs/gphotos-sync-jdyTJ4d7/lib/python3.7/site-packages/gphotos/GooglePhotosDownload.py", line 177, in download_batch
    i, str(r_json), str(result)
Message: 'Null response in mediaItems.batchGetfor item &d in\n\n %s \n\n which is \n%s'
Arguments: (0, "{'mediaItemResults': [{'status': {'code': 3, 'message': 'Invalid media item ID.'}}]}", "{'status': {'code': 3, 'message': 'Invalid media item ID.'}}")
01-03 19:32:49 WARNING  Downloaded 0 Items, Failed 0, Already Downloaded 10282
01-03 19:32:49 WARNING  Done.

About this issue

Original URL
State: closed
Created 4 years ago
Comments: 25 (20 by maintainers)

Commits related to this issue

fix #179 bad debug statement — committed to gilesknap/gphotos-sync by gilesknap 4 years ago

Most upvoted comments

@gilesknap - yes, sorry I became busy with other projects. Will run a few tests with dates in the range currently being skipped and email you some logs. Soon(ish) I hope.

raintonr on Feb 16, 2020

(I must have accidentally closed this - reopenning)

Your latest log is enlightening.

gphotos-sync indexing does continue to run after the bad ID is seen and the Google API does continue to respond with ‘nextPageToken’ multiple times, however, all of the responses contain no media items (possibly just a nextPageToken - this sometimes happens in other peoples libraries and is recoverable since usually, subsequent responses do have contents)

So the theory that the Google Session is getting in a bad state after seeing the bad ID seems plausable. Usually Bad IDs can be removed using the productUrl but this is not working in your case.

I think the next thing to do is to get a detailed log of the requests and responses and file a bug with Google.

I’ll have to update the code to add the ability to make such logs. (but its a generally useful feature).

I’ll try to get this done in the next few days.

gilesknap on Jan 7, 2020