hermanho / MMM-GooglePhotos

Display your photos on MagicMirror from Google Photos.
MIT License
162 stars 62 forks source link

GooglePhotos stuck on Loading after latest upgrade (using oauth updated routines) #149

Closed andyb2000 closed 1 year ago

andyb2000 commented 1 year ago

Hi, First thanks for the latest update to comply with the Google OAUTH updates! Good work.

After carrying the upgrade out though I'm stuck on a "Loading" display, nothing else happens and I've left it like this for at least 30minutes to ensure it wasn't cache, etc.

No errors in console initially and it shows the scripts being loaded:

18.10.2022 22:44.16.527] [LOG] Starting MagicMirror: v2.21.0 [18.10.2022 22:44.16.542] [LOG] Loading config ... [18.10.2022 22:44.16.557] [LOG] Loading module helpers ... [18.10.2022 22:44.16.563] [LOG] No helper found for module: alert. [18.10.2022 22:44.16.567] [LOG] No helper found for module: clock. [18.10.2022 22:44.17.090] [LOG] Initializing new module helper ... [18.10.2022 22:44.17.095] [LOG] Module helper loaded: calendar [18.10.2022 22:44.17.666] [LOG] Initializing new module helper ... [18.10.2022 22:44.17.668] [LOG] Module helper loaded: MMM-Screencast [18.10.2022 22:44.17.679] [LOG] Initializing new module helper ... [18.10.2022 22:44.17.681] [LOG] Module helper loaded: MMM-VLC [18.10.2022 22:44.17.756] [LOG] Initializing new module helper ... [18.10.2022 22:44.17.758] [LOG] Module helper loaded: MMM-network-signal [18.10.2022 22:44.18.176] [LOG] Initializing new module helper ... [18.10.2022 22:44.18.179] [LOG] Module helper loaded: MMM-GooglePhotos [18.10.2022 22:44.18.269] [LOG] Initializing new module helper ... [18.10.2022 22:44.18.270] [LOG] Module helper loaded: MMM-Remote-Control [18.10.2022 22:44.18.275] [LOG] Initializing new module helper ... [18.10.2022 22:44.18.277] [LOG] Module helper loaded: MMM-NotificationTrigger [18.10.2022 22:44.18.278] [LOG] All module helpers loaded. [18.10.2022 22:44.18.467] [LOG] Starting server on port 8080 ... [18.10.2022 22:44.18.497] [LOG] Server started ... [18.10.2022 22:44.18.499] [LOG] Connecting socket for: calendar [18.10.2022 22:44.18.501] [LOG] Starting node helper for: calendar [18.10.2022 22:44.18.502] [LOG] Connecting socket for: MMM-Screencast [18.10.2022 22:44.18.504] [LOG] Connecting socket for: MMM-VLC [18.10.2022 22:44.18.506] [LOG] Starting node helper for: MMM-VLC [18.10.2022 22:44.18.510] [LOG] Connecting socket for: MMM-network-signal [18.10.2022 22:44.18.512] [LOG] MMM-network-signal helper started ... [18.10.2022 22:44.18.513] [LOG] Connecting socket for: MMM-GooglePhotos [18.10.2022 22:44.18.515] [LOG] Connecting socket for: MMM-Remote-Control [18.10.2022 22:44.18.517] [LOG] Starting node helper for: MMM-Remote-Control [18.10.2022 22:44.19.082] [LOG] Connecting socket for: MMM-NotificationTrigger [18.10.2022 22:44.19.090] [LOG] Sockets connected & modules started ... [18.10.2022 22:44.19.721] [LOG] Launching application.

After that I see status from other modules but nothing more from MMM-GooglePhotos. I've added debug to it so I can see more info, and this is the output when it fails and loops:

[18.10.2022 23:06.28.426] [LOG] [GPHOTOS] Image loading fails. Check your network.: https://lh3.googleusercontent.com/lr/AGiIYOVAxXHkeFFpMDZH6---CUT---=w800px-h600px [18.10.2022 23:06.28.429] [LOG] [GPHOTOS] num to ref: 40 , DesChunk: 40 , totalLength: 123 , Pntr: 0 [18.10.2022 23:06.28.433] [LOG] [GPHOTOS:AUTH] Token is alive. [18.10.2022 23:06.28.436] [LOG] [GPHOTOS:CORE] received: 40 to refresh [18.10.2022 23:06.28.707] [LOG] [GPHOTOS:CORE] AxiosError: Request failed with status code 400 [18.10.2022 23:06.28.711] [ERROR] (node:7629) UnhandledPromiseRejectionWarning: AxiosError: Request failed with status code 400 at settle (/home/pi/MagicMirror/modules/MMM-GooglePhotos/node_modules/axios/dist/node/axios.cjs:1268:12) at Unzip.handleStreamEnd (/home/pi/MagicMirror/modules/MMM-GooglePhotos/node_modules/axios/dist/node/axios.cjs:2446:11) at Unzip.emit (node:events:538:35) at endReadableNT (node:internal/streams/readable:1345:12) at process.processTicksAndRejections (node:internal/process/task_queues:83:21) [18.10.2022 23:06.28.716] [ERROR] (node:7629) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag--unhandled-rejections=strict(see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 12) (Obviously I cut the googleusercontent.com down and put ---CUT--- this was a full URL. If I copy+paste that URL into browser it fails with a 400 error also) That starts to loop quickly.

Checking the API console I can see the Photos Library API and if I look at errors by API method I can see them going up: (See attached screenshot) So the error is with "google.photos.library.v1.PhotosLibrary.BatchGetMediaItems" which appears to be the axios library?

Screenshot_20221018_231221

Any ideas on where to debug further?

Thanks in advance.

andyb2000 commented 1 year ago

And just like that, I found the issue!

[18.10.2022 23:06.28.426] [LOG] [GPHOTOS] Image loading fails. Check your network.: https://lh3.googleusercontent.com/lr/AGiIYOVAxXHkeFFpMDZH6---CUT---=w800px-h600px

Shows the width and height params being passed. This was the OLD method and included px (pixels) which if you now remove from the config file, it works fine.

So just be aware if anyone gets a 400 error it may be due to this! Sorry for the noise and thanks for the great work.