search

hermanho / MMM-GooglePhotos

Display your photos on MagicMirror from Google Photos.
MIT License
170 stars 65 forks source link

Problem with longer updateInterval #126

Open cweinhofer opened 2 years ago

cweinhofer commented 2 years ago

If I try to set updateInterval to something long like 30 or 60 minutes, the MM show the first photo for the set time and then starts rapidly scrolling through my photos (changing like every 10 sec) until I quit the MM and restart. However, everything works fine if I set a lower interval like 5 minutes.

PS - Is there a technical reason updateInterval is written like 1000 * 60 (as opposed to 60000) in the config or is it just stylistic?

eouia commented 2 years ago

1000 * 60 is more readable as 60 secs than 60000.

I doubt your scanInterval is shorter than updateInterval. when a new scan is performed, your photo list would be renewed. That makes your current photos being invalid.

One more reason; the life of a photo might be at longest 1 hour (not sure exactly)after its scan because Google doesn't want long lives of external usage of photos. So your next photo after 1 hour might be dead.

I'm not sure what exact reason at this moment, but my guess.

aneaville commented 2 years ago

I didn't expect 30 to 60 min refresh times, so this is new.

The module sends 20 minutes worth of pictures to the front end at a time. Since they are only good for 60 min, this makes sure the links are always 'fresh' and leaves enough room to keep working even something fails.

I suspect the issue is either:

  1. that when I calculate 20 min worth of pictures, that it comes up with 0 and doesn't refresh. You can try changing to send 60 min of pictures by changine line 46 in node_helper.js from case 'NEED_MORE_PICS': this.log("Used last pic in list") this.prepAndSendChunk(Math.ceil(20*60*1000/this.config.updateInterval))// 20min * 60s * 1000ms / updateinterval in ms break

to: case 'NEED_MORE_PICS': this.log("Used last pic in list") this.prepAndSendChunk(Math.ceil(60*60*1000/this.config.updateInterval))// 20min * 60s * 1000ms / updateinterval in ms break

  1. How many pictures do you have? are you using random or time sorting? and what is your scan interval? If using time sorting, its possible that the time method restarts to earliest picture every scan. If the scan happens before you show the next picture, it will always show the first time picture. This could be fixed by slowing down the scan_interval, or using the random sort.

If both these don't help and you'd like to debug further, please add "debug: true," to your config and lets see what the logs say.

cweinhofer commented 2 years ago

Thanks for the help. To answer your other questions: I have 270 photos showing randomly. I haven't done anything to alter scanInterval as I didn't see an option for that in the config.

In case there was a 60 min hard limit from the Google API end, I decided to set 'NEED_MORE_PICS' at 59*60*100 and then set updateInterval at 58*60*1000. That configuration seemed to work fine. So then I tried 60*60*1000 for both and everything started going wonky again. I didn't know which of them (or maybe both) didn't like the 60, so I'm running the MM again with debug: true in the config. Will the logs show in the terminal or is there a file somewhere I need to check?

I can live with the 58/59 if going over 60 creates a lot of extra work. This is a Christmas gift for my mom, so after Monday my access for running further tests will be significantly reduced.

PS - Just FYI, the reason I prefer longer interval times is because I find a picture changing every minute (or even 15 minutes) is kind of distracting. A longer interval time allows you to still display changing photos, but have it become part of the background of the room. For my personal MM (which just uses https://github.com/darickc/MMM-BackgroundSlideshow, I actually have an interval of 6 hrs.

cweinhofer commented 2 years ago

Here's the output from the terminal, from when I started the MM to when it starts to go crazy. I scrubbed the "googleusercontent" addresses because I was concerned that the long random text string might be a token of some sort, but let me know if you need them.

Thanks!

pi@Moms-Photo-Viewer:~ $ cd ~/MagicMirror/ && npm run start

> magicmirror@2.17.1 start /home/pi/MagicMirror
> ./run-start.sh $1

[24.12.2021 16:14.25.533] [LOG]   Starting MagicMirror: v2.17.1
[24.12.2021 16:14.25.558] [LOG]   Loading config ...
[24.12.2021 16:14.25.579] [LOG]   Loading module helpers ...
[24.12.2021 16:14.25.587] [LOG]   No helper found for module: clock.
[24.12.2021 16:14.26.647] [LOG]   Initializing new module helper ...
[24.12.2021 16:14.26.651] [LOG]   Module helper loaded: MMM-GooglePhotos
[24.12.2021 16:14.27.807] [LOG]   Initializing new module helper ...
[24.12.2021 16:14.27.813] [LOG]   Module helper loaded: MMM-3Day-Forecast
[24.12.2021 16:14.27.816] [LOG]   All module helpers loaded.
[24.12.2021 16:14.28.127] [LOG]   Starting server on port 8080 ... 
[24.12.2021 16:14.28.167] [LOG]   Server started ...
[24.12.2021 16:14.28.170] [LOG]   Connecting socket for: MMM-GooglePhotos
[24.12.2021 16:14.28.172] [LOG]   Connecting socket for: MMM-3Day-Forecast
[24.12.2021 16:14.28.174] [LOG]   MMM-3Day-Forecast helper, started...
[24.12.2021 16:14.28.175] [LOG]   Sockets connected & modules started ...
[24.12.2021 16:14.28.969] [LOG]   Launching application.
[24.12.2021 16:14.34.747] [LOG]   [GPHOTOS] Starting Initialization
[24.12.2021 16:14.34.750] [LOG]   [GPHOTOS] Getting album list
[24.12.2021 16:14.34.764] [LOG]   [GPHOTOS:AUTH] Token is expired.
[24.12.2021 16:14.35.156] [LOG]   [GPHOTOS:AUTH] Token is refreshed.
[24.12.2021 16:14.35.162] [LOG]   [GPHOTOS:CORE] Getting Album info chunks.
[24.12.2021 16:14.35.967] [LOG]   [GPHOTOS:AUTH] Token is alive.
[24.12.2021 16:14.35.971] [LOG]   [GPHOTOS:CORE] Getting Album info chunks.
[24.12.2021 16:14.37.039] [LOG]   [GPHOTOS] Finish Album scanning. Properly scanned : 1
[24.12.2021 16:14.37.059] [LOG]   [GPHOTOS] Initialized
[24.12.2021 16:14.37.071] [LOG]   [GPHOTOS] Initialization complete!
[24.12.2021 16:14.37.079] [LOG]   [GPHOTOS] Start first scanning.
[24.12.2021 16:14.37.083] [LOG]   [GPHOTOS] Start Album scanning
[24.12.2021 16:14.37.090] [LOG]   [GPHOTOS] Prepping to get photo list from 'Moms Photo Viewer'
[24.12.2021 16:14.37.100] [LOG]   [GPHOTOS:AUTH] Token is alive.
[24.12.2021 16:14.37.104] [LOG]   [GPHOTOS:CORE] Indexing photos now. total:  0
[24.12.2021 16:14.37.196] [LOG]   [GPHOTOS] successfully loaded cache of  269  photos
[24.12.2021 16:14.37.201] [LOG]   [GPHOTOS] num to ref:  5 , DesChunk:  5 , totalLength:  269 , Pntr:  0
[24.12.2021 16:14.37.210] [LOG]   [GPHOTOS:AUTH] Token is alive.
[24.12.2021 16:14.37.214] [LOG]   [GPHOTOS:CORE] received:  5  to refresh
[24.12.2021 16:14.37.620] [LOG]   [GPHOTOS] refreshed:  5 , totalLength:  269 , Pntr:  5
[24.12.2021 16:14.37.622] [LOG]   [GPHOTOS] just sent  5  more pics
[24.12.2021 16:14.38.080] [LOG]   [GPHOTOS] Image loaded: https://lh3.googleusercontent.com/lr/ <long random text string> =w1080-h1920
[24.12.2021 16:14.38.594] [LOG]   [GPHOTOS:CORE] Indexing photos now. total:  50
[24.12.2021 16:14.42.043] [LOG]   [GPHOTOS:CORE] Indexing photos now. total:  100
[24.12.2021 16:14.46.605] [LOG]   [GPHOTOS:CORE] Indexing photos now. total:  150
[24.12.2021 16:14.54.918] [LOG]   [GPHOTOS:CORE] Indexing photos now. total:  200
[24.12.2021 16:15.00.670] [LOG]   [GPHOTOS:CORE] Indexing photos now. total:  250
[24.12.2021 16:15.01.955] [LOG]   [GPHOTOS] Got 269 photo(s) from 'Moms Photo Viewer'
[24.12.2021 16:15.01.960] [LOG]   [GPHOTOS] Total indexed photos: 269
[24.12.2021 16:15.02.028] [LOG]   [GPHOTOS] Photo list cache saved
[24.12.2021 17:09.37.086] [LOG]   [GPHOTOS] Start Album scanning
[24.12.2021 17:09.37.090] [LOG]   [GPHOTOS] Prepping to get photo list from 'Moms Photo Viewer'
[24.12.2021 17:09.37.095] [LOG]   [GPHOTOS:AUTH] Token is alive.
[24.12.2021 17:09.37.097] [LOG]   [GPHOTOS:CORE] Indexing photos now. total:  0
[24.12.2021 17:09.38.560] [LOG]   [GPHOTOS:CORE] Indexing photos now. total:  50
[24.12.2021 17:09.39.943] [LOG]   [GPHOTOS:CORE] Indexing photos now. total:  100
[24.12.2021 17:10.00.651] [LOG]   [GPHOTOS:CORE] Error: Client network socket disconnected before secure TLS connection was established
[24.12.2021 17:10.00.658] [ERROR] (node:7225) UnhandledPromiseRejectionWarning: Error: Client network socket disconnected before secure TLS connection was established
    at connResetException (internal/errors.js:607:14)
    at TLSSocket.onConnectEnd (_tls_wrap.js:1544:19)
    at TLSSocket.emit (events.js:327:22)
    at endReadableNT (internal/streams/readable.js:1327:12)
    at processTicksAndRejections (internal/process/task_queues.js:80:21)
(Use `electron --trace-warnings ...` to show where the warning was created)
[24.12.2021 17:10.00.661] [ERROR] (node:7225) 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: 2)
[24.12.2021 17:10.00.663] [ERROR] (node:7225) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code.
[24.12.2021 17:14.37.292] [LOG]   [GPHOTOS] Image loading fails. Check your network.: https://lh3.googleusercontent.com/lr/ <long random text string> =w1080-h1920
[24.12.2021 17:14.37.294] [LOG]   [GPHOTOS] num to ref:  1 , DesChunk:  1 , totalLength:  269 , Pntr:  5
[24.12.2021 17:14.37.299] [LOG]   [GPHOTOS:AUTH] Token is expired.
[24.12.2021 17:14.37.460] [LOG]   [GPHOTOS:AUTH] Token is refreshed.
[24.12.2021 17:14.37.462] [LOG]   [GPHOTOS:CORE] received:  1  to refresh
[24.12.2021 17:14.38.032] [LOG]   [GPHOTOS] refreshed:  1 , totalLength:  269 , Pntr:  6
[24.12.2021 17:14.38.042] [LOG]   [GPHOTOS] just sent  1  more pics
[24.12.2021 17:14.38.067] [LOG]   [GPHOTOS] Used last pic in list
[24.12.2021 17:14.38.070] [LOG]   [GPHOTOS] num to ref:  1 , DesChunk:  1 , totalLength:  269 , Pntr:  6
[24.12.2021 17:14.38.080] [LOG]   [GPHOTOS:AUTH] Token is alive.
[24.12.2021 17:14.38.084] [LOG]   [GPHOTOS:CORE] received:  1  to refresh
[24.12.2021 17:14.38.440] [LOG]   [GPHOTOS] refreshed:  1 , totalLength:  269 , Pntr:  7
[24.12.2021 17:14.38.442] [LOG]   [GPHOTOS] just sent  1  more pics
[24.12.2021 17:14.38.451] [LOG]   [GPHOTOS] Used last pic in list
[24.12.2021 17:14.38.453] [LOG]   [GPHOTOS] num to ref:  1 , DesChunk:  1 , totalLength:  269 , Pntr:  7
[24.12.2021 17:14.38.458] [LOG]   [GPHOTOS:AUTH] Token is alive.
[24.12.2021 17:14.38.461] [LOG]   [GPHOTOS:CORE] received:  1  to refresh
[24.12.2021 17:14.38.619] [LOG]   [GPHOTOS] Image loaded: https://lh3.googleusercontent.com/lr/ <long random text string> =w1080-h1920
[24.12.2021 17:14.38.930] [LOG]   [GPHOTOS] refreshed:  1 , totalLength:  269 , Pntr:  8
[24.12.2021 17:14.38.932] [LOG]   [GPHOTOS] just sent  1  more pics
[24.12.2021 17:14.39.190] [LOG]   [GPHOTOS] Used last pic in list
[24.12.2021 17:14.39.194] [LOG]   [GPHOTOS] num to ref:  1 , DesChunk:  1 , totalLength:  269 , Pntr:  8
[24.12.2021 17:14.39.219] [LOG]   [GPHOTOS:AUTH] Token is alive.
[24.12.2021 17:14.39.222] [LOG]   [GPHOTOS:CORE] received:  1  to refresh
[24.12.2021 17:14.39.370] [LOG]   [GPHOTOS] Image loaded: https://lh3.googleusercontent.com/lr/ <long random text string> =w1080-h1920
[24.12.2021 17:14.39.649] [LOG]   [GPHOTOS] refreshed:  1 , totalLength:  269 , Pntr:  9
[24.12.2021 17:14.39.653] [LOG]   [GPHOTOS] just sent  1  more pics
[24.12.2021 17:14.39.718] [LOG]   [GPHOTOS] Used last pic in list
[24.12.2021 17:14.39.725] [LOG]   [GPHOTOS] num to ref:  1 , DesChunk:  1 , totalLength:  269 , Pntr:  9
[24.12.2021 17:14.39.764] [LOG]   [GPHOTOS:AUTH] Token is alive.
[24.12.2021 17:14.39.791] [LOG]   [GPHOTOS:CORE] received:  1  to refresh
[24.12.2021 17:14.39.865] [LOG]   [GPHOTOS] Image loaded: https://lh3.googleusercontent.com/lr/ <long random text string> =w1080-h1920
[24.12.2021 17:14.40.135] [LOG]   [GPHOTOS] Image loaded: https://lh3.googleusercontent.com/lr/ <long random text string> =w1080-h1920
[24.12.2021 17:14.40.441] [LOG]   [GPHOTOS] refreshed:  1 , totalLength:  269 , Pntr:  10
[24.12.2021 17:14.40.445] [LOG]   [GPHOTOS] just sent  1  more pics
[24.12.2021 17:14.40.484] [LOG]   [GPHOTOS] Used last pic in list
[24.12.2021 17:14.40.489] [LOG]   [GPHOTOS] num to ref:  1 , DesChunk:  1 , totalLength:  269 , Pntr:  10
[24.12.2021 17:14.40.527] [LOG]   [GPHOTOS:AUTH] Token is alive.
[24.12.2021 17:14.40.551] [LOG]   [GPHOTOS:CORE] received:  1  to refresh
[24.12.2021 17:14.40.964] [LOG]   [GPHOTOS] Image loaded: https://lh3.googleusercontent.com/lr/ <long random text string> =w1080-h1920
[24.12.2021 17:14.41.375] [LOG]   [GPHOTOS] refreshed:  1 , totalLength:  269 , Pntr:  11
[24.12.2021 17:14.41.391] [LOG]   [GPHOTOS] just sent  1  more pics
[24.12.2021 17:14.41.421] [LOG]   [GPHOTOS] Used last pic in list
[24.12.2021 17:14.41.431] [LOG]   [GPHOTOS] num to ref:  1 , DesChunk:  1 , totalLength:  269 , Pntr:  11
[24.12.2021 17:14.41.437] [LOG]   [GPHOTOS:AUTH] Token is alive.
[24.12.2021 17:14.41.462] [LOG]   [GPHOTOS:CORE] received:  1  to refresh
[24.12.2021 17:14.41.766] [LOG]   [GPHOTOS] Image loaded: https://lh3.googleusercontent.com/lr/ <long random text string> =w1080-h1920
[24.12.2021 17:14.42.065] [LOG]   [GPHOTOS] refreshed:  1 , totalLength:  269 , Pntr:  12
[24.12.2021 17:14.42.070] [LOG]   [GPHOTOS] just sent  1  more pics
[24.12.2021 17:14.42.270] [LOG]   [GPHOTOS] Used last pic in list
[24.12.2021 17:14.42.292] [LOG]   [GPHOTOS] num to ref:  1 , DesChunk:  1 , totalLength:  269 , Pntr:  12
[24.12.2021 17:14.42.299] [LOG]   [GPHOTOS:AUTH] Token is alive.
[24.12.2021 17:14.42.302] [LOG]   [GPHOTOS:CORE] received:  1  to refresh
[24.12.2021 17:14.42.761] [LOG]   [GPHOTOS] Image loaded: https://lh3.googleusercontent.com/lr/ <long random text string> =w1080-h1920
[24.12.2021 17:14.43.117] [LOG]   [GPHOTOS] refreshed:  1 , totalLength:  269 , Pntr:  13
[24.12.2021 17:14.43.125] [LOG]   [GPHOTOS] just sent  1  more pics
[24.12.2021 17:14.43.191] [LOG]   [GPHOTOS] Used last pic in list
[24.12.2021 17:14.43.218] [LOG]   [GPHOTOS] num to ref:  1 , DesChunk:  1 , totalLength:  269 , Pntr:  13
[24.12.2021 17:14.43.225] [LOG]   [GPHOTOS:AUTH] Token is alive.
[24.12.2021 17:14.43.242] [LOG]   [GPHOTOS:CORE] received:  1  to refresh
[24.12.2021 17:14.43.481] [LOG]   [GPHOTOS] Image loaded: https://lh3.googleusercontent.com/lr/ <long random text string> =w1080-h1920
[24.12.2021 17:14.43.657] [LOG]   [GPHOTOS] refreshed:  1 , totalLength:  269 , Pntr:  14
[24.12.2021 17:14.43.696] [LOG]   [GPHOTOS] just sent  1  more pics
[24.12.2021 17:14.43.720] [LOG]   [GPHOTOS] Used last pic in list
[24.12.2021 17:14.43.751] [LOG]   [GPHOTOS] num to ref:  1 , DesChunk:  1 , totalLength:  269 , Pntr:  14
[24.12.2021 17:14.43.766] [LOG]   [GPHOTOS:AUTH] Token is alive.
[24.12.2021 17:14.43.769] [LOG]   [GPHOTOS:CORE] received:  1  to refresh
[24.12.2021 17:14.44.207] [LOG]   [GPHOTOS] refreshed:  1 , totalLength:  269 , Pntr:  15
[24.12.2021 17:14.44.249] [LOG]   [GPHOTOS] just sent  1  more pics
[24.12.2021 17:14.44.309] [LOG]   [GPHOTOS] Used last pic in list
[24.12.2021 17:14.44.316] [LOG]   [GPHOTOS] num to ref:  1 , DesChunk:  1 , totalLength:  269 , Pntr:  15
[24.12.2021 17:14.44.327] [LOG]   [GPHOTOS:AUTH] Token is alive.
[24.12.2021 17:14.44.340] [LOG]   [GPHOTOS:CORE] received:  1  to refresh
[24.12.2021 17:14.44.452] [LOG]   [GPHOTOS] Image loaded: https://lh3.googleusercontent.com/lr/ <long random text string> =w1080-h1920
[24.12.2021 17:14.44.711] [LOG]   [GPHOTOS] Image loaded: https://lh3.googleusercontent.com/lr/ <long random text string> =w1080-h1920
[24.12.2021 17:14.44.808] [LOG]   [GPHOTOS] refreshed:  1 , totalLength:  269 , Pntr:  16
[24.12.2021 17:14.44.830] [LOG]   [GPHOTOS] just sent  1  more pics
[24.12.2021 17:14.44.885] [LOG]   [GPHOTOS] Used last pic in list
[24.12.2021 17:14.44.889] [LOG]   [GPHOTOS] num to ref:  1 , DesChunk:  1 , totalLength:  269 , Pntr:  16
[24.12.2021 17:14.44.902] [LOG]   [GPHOTOS:AUTH] Token is alive.
[24.12.2021 17:14.44.916] [LOG]   [GPHOTOS:CORE] received:  1  to refresh
[24.12.2021 17:14.45.327] [LOG]   [GPHOTOS] Image loaded: https://lh3.googleusercontent.com/lr/ <long random text string> =w1080-h1920
[24.12.2021 17:14.45.741] [LOG]   [GPHOTOS] refreshed:  1 , totalLength:  269 , Pntr:  17
[24.12.2021 17:14.45.748] [LOG]   [GPHOTOS] just sent  1  more pics
[24.12.2021 17:14.45.774] [LOG]   [GPHOTOS] Used last pic in list
[24.12.2021 17:14.45.779] [LOG]   [GPHOTOS] num to ref:  1 , DesChunk:  1 , totalLength:  269 , Pntr:  17
[24.12.2021 17:14.45.787] [LOG]   [GPHOTOS:AUTH] Token is alive.
[24.12.2021 17:14.45.789] [LOG]   [GPHOTOS:CORE] received:  1  to refresh
[24.12.2021 17:14.46.105] [LOG]   [GPHOTOS] Image loaded: https://lh3.googleusercontent.com/lr/ <long random text string> =w1080-h1920
[24.12.2021 17:14.46.443] [LOG]   [GPHOTOS] refreshed:  1 , totalLength:  269 , Pntr:  18
[24.12.2021 17:14.46.472] [LOG]   [GPHOTOS] just sent  1  more pics
[24.12.2021 17:14.46.506] [LOG]   [GPHOTOS] Used last pic in list
[24.12.2021 17:14.46.522] [LOG]   [GPHOTOS] num to ref:  1 , DesChunk:  1 , totalLength:  269 , Pntr:  18
[24.12.2021 17:14.46.534] [LOG]   [GPHOTOS:AUTH] Token is alive.
[24.12.2021 17:14.46.560] [LOG]   [GPHOTOS:CORE] received:  1  to refresh
[24.12.2021 17:14.47.093] [LOG]   [GPHOTOS] Image loaded: https://lh3.googleusercontent.com/lr/ <long random text string> =w1080-h1920
[24.12.2021 17:14.47.508] [LOG]   [GPHOTOS] refreshed:  1 , totalLength:  269 , Pntr:  19
[24.12.2021 17:14.47.513] [LOG]   [GPHOTOS] just sent  1  more pics
[24.12.2021 17:14.47.558] [LOG]   [GPHOTOS] Used last pic in list
[24.12.2021 17:14.47.571] [LOG]   [GPHOTOS] num to ref:  1 , DesChunk:  1 , totalLength:  269 , Pntr:  19
[24.12.2021 17:14.47.579] [LOG]   [GPHOTOS:AUTH] Token is alive.
[24.12.2021 17:14.47.584] [LOG]   [GPHOTOS:CORE] received:  1  to refresh
[24.12.2021 17:14.48.049] [LOG]   [GPHOTOS] Image loaded: https://lh3.googleusercontent.com/lr/ <long random text string> =w1080-h1920
[24.12.2021 17:14.48.464] [LOG]   [GPHOTOS] refreshed:  1 , totalLength:  269 , Pntr:  20
[24.12.2021 17:14.48.470] [LOG]   [GPHOTOS] just sent  1  more pics
[24.12.2021 17:14.48.502] [LOG]   [GPHOTOS] Used last pic in list
[24.12.2021 17:14.48.506] [LOG]   [GPHOTOS] num to ref:  1 , DesChunk:  1 , totalLength:  269 , Pntr:  20
[24.12.2021 17:14.48.514] [LOG]   [GPHOTOS:AUTH] Token is alive.
[24.12.2021 17:14.48.519] [LOG]   [GPHOTOS:CORE] received:  1  to refresh
[24.12.2021 17:14.48.967] [LOG]   [GPHOTOS] Image loaded: https://lh3.googleusercontent.com/lr/ <long random text string> =w1080-h1920
[24.12.2021 17:14.49.331] [LOG]   [GPHOTOS] refreshed:  1 , totalLength:  269 , Pntr:  21
[24.12.2021 17:14.49.335] [LOG]   [GPHOTOS] just sent  1  more pics
[24.12.2021 17:14.49.355] [LOG]   [GPHOTOS] Used last pic in list
[24.12.2021 17:14.49.360] [LOG]   [GPHOTOS] num to ref:  1 , DesChunk:  1 , totalLength:  269 , Pntr:  21
[24.12.2021 17:14.49.367] [LOG]   [GPHOTOS:AUTH] Token is alive.
[24.12.2021 17:14.49.372] [LOG]   [GPHOTOS:CORE] received:  1  to refresh
[24.12.2021 17:14.49.899] [LOG]   [GPHOTOS] Image loaded: https://lh3.googleusercontent.com/lr/ <long random text string> =w1080-h1920
[24.12.2021 17:14.50.385] [LOG]   [GPHOTOS] refreshed:  1 , totalLength:  269 , Pntr:  22
[24.12.2021 17:14.50.389] [LOG]   [GPHOTOS] just sent  1  more pics
[24.12.2021 17:14.50.397] [LOG]   [GPHOTOS] Used last pic in list
[24.12.2021 17:14.50.413] [LOG]   [GPHOTOS] num to ref:  1 , DesChunk:  1 , totalLength:  269 , Pntr:  22
[24.12.2021 17:14.50.425] [LOG]   [GPHOTOS:AUTH] Token is alive.
[24.12.2021 17:14.50.429] [LOG]   [GPHOTOS:CORE] received:  1  to refresh
[24.12.2021 17:14.50.976] [LOG]   [GPHOTOS] Image loaded: https://lh3.googleusercontent.com/lr/ <long random text string> =w1080-h1920
[24.12.2021 17:14.51.364] [LOG]   [GPHOTOS] refreshed:  1 , totalLength:  269 , Pntr:  23
[24.12.2021 17:14.51.374] [LOG]   [GPHOTOS] just sent  1  more pics
[24.12.2021 17:14.51.393] [LOG]   [GPHOTOS] Used last pic in list
[24.12.2021 17:14.51.397] [LOG]   [GPHOTOS] num to ref:  1 , DesChunk:  1 , totalLength:  269 , Pntr:  23
[24.12.2021 17:14.51.404] [LOG]   [GPHOTOS:AUTH] Token is alive.
[24.12.2021 17:14.51.408] [LOG]   [GPHOTOS:CORE] received:  1  to refresh
[24.12.2021 17:14.51.736] [LOG]   [GPHOTOS] Image loaded: https://lh3.googleusercontent.com/lr/ <long random text string> =w1080-h1920
[24.12.2021 17:14.51.805] [LOG]   [GPHOTOS] refreshed:  1 , totalLength:  269 , Pntr:  24
[24.12.2021 17:14.51.811] [LOG]   [GPHOTOS] just sent  1  more pics
[24.12.2021 17:14.51.826] [LOG]   [GPHOTOS] Used last pic in list
[24.12.2021 17:14.51.831] [LOG]   [GPHOTOS] num to ref:  1 , DesChunk:  1 , totalLength:  269 , Pntr:  24
[24.12.2021 17:14.51.839] [LOG]   [GPHOTOS:AUTH] Token is alive.
[24.12.2021 17:14.51.844] [LOG]   [GPHOTOS:CORE] received:  1  to refresh
[24.12.2021 17:14.52.241] [LOG]   [GPHOTOS] Image loaded: https://lh3.googleusercontent.com/lr/ <long random text string> =w1080-h1920
[24.12.2021 17:14.52.343] [LOG]   [GPHOTOS] refreshed:  1 , totalLength:  269 , Pntr:  25
[24.12.2021 17:14.52.352] [LOG]   [GPHOTOS] just sent  1  more pics
[24.12.2021 17:14.52.416] [LOG]   [GPHOTOS] Used last pic in list
[24.12.2021 17:14.52.431] [LOG]   [GPHOTOS] num to ref:  1 , DesChunk:  1 , totalLength:  269 , Pntr:  25
[24.12.2021 17:14.52.437] [LOG]   [GPHOTOS:AUTH] Token is alive.
[24.12.2021 17:14.52.456] [LOG]   [GPHOTOS:CORE] received:  1  to refresh
[24.12.2021 17:14.52.719] [LOG]   [GPHOTOS] Image loaded: https://lh3.googleusercontent.com/lr/ <long random text string> =w1080-h1920
[24.12.2021 17:14.52.908] [LOG]   [GPHOTOS] refreshed:  1 , totalLength:  269 , Pntr:  26
[24.12.2021 17:14.52.934] [LOG]   [GPHOTOS] just sent  1  more pics
[24.12.2021 17:14.52.984] [LOG]   [GPHOTOS] Used last pic in list
[24.12.2021 17:14.52.987] [LOG]   [GPHOTOS] num to ref:  1 , DesChunk:  1 , totalLength:  269 , Pntr:  26
[24.12.2021 17:14.53.032] [LOG]   [GPHOTOS:AUTH] Token is alive.
[24.12.2021 17:14.53.034] [LOG]   [GPHOTOS:CORE] received:  1  to refresh
[24.12.2021 17:14.53.467] [LOG]   [GPHOTOS] Image loaded: https://lh3.googleusercontent.com/lr/ <long random text string> =w1080-h1920
[24.12.2021 17:14.53.806] [LOG]   [GPHOTOS] refreshed:  1 , totalLength:  269 , Pntr:  27
[24.12.2021 17:14.53.810] [LOG]   [GPHOTOS] just sent  1  more pics
[24.12.2021 17:14.53.847] [LOG]   [GPHOTOS] Used last pic in list
[24.12.2021 17:14.53.852] [LOG]   [GPHOTOS] num to ref:  1 , DesChunk:  1 , totalLength:  269 , Pntr:  27
[24.12.2021 17:14.53.865] [LOG]   [GPHOTOS:AUTH] Token is alive.
[24.12.2021 17:14.53.871] [LOG]   [GPHOTOS:CORE] received:  1  to refresh
[24.12.2021 17:14.53.921] [LOG]   Shutting down server...
[24.12.2021 17:14.53.925] [LOG]   Stopping module helper: MMM-3Day-Forecast
pi@Moms-Photo-Viewer:~/MagicMirror $
aneaville commented 2 years ago

Excellent. Scrubbing the long string was fine.

For documentation sake, a description of what's happening. The front end gets a list of pictures from the backend. Whenever it gets a new payload, it immediately displays the latest. When it displays the last picture in the list, it requests more pictures. Or if there is an error with a picture(like the 1 hour link expired), it also requests more pictures. The backend sends 20 minutes worth of pictures to each request.

In this case, when there is only 1 picture being sent at a time, it immediately displays, but its also the last(only) one in the list, so immediately requests more pictures and the cycle repeats.

This isn't an issue at the beginning, because if there is a cache saved, it sends 5 pictures at startup to make startup extra fast. When these 5 are 'used up' or after an hour when they start to expire, it gets into the described loop.

I don't plan to make changes to the code because I don't have a way to test it at the moment. Here is what I would recommend: make it so the minimum pictures sent is at least 2. this can be done by 2 ways:

  1. You can speed up the refresh rate. I believe anything faster than 19 minutes will work satisfactory with the default code. or with your changes you described, 58 min should work.
  2. Change the previously sited code to use the max of 2 or the calculated value. untested code: case 'NEED_MORE_PICS': this.log("Used last pic in list") this.prepAndSendChunk(Math.max(2,Math.ceil(60*60*1000/this.config.updateInterval))) // 20min * 60s * 1000ms / updateinterval in ms break
cweinhofer commented 2 years ago

Thanks for providing the two workarounds. I tried the code in (2.) and it seems to work fine. In case anyone else wants to use it, I've added in the line breaks that seem to have gotten removed:

      case 'NEED_MORE_PICS':
        this.log("Used last pic in list")
        this.prepAndSendChunk(Math.max(2,Math.ceil(60*60*1000/this.config.updateInterval)))// 60min * 60s * 1000ms / updateinterval in ms
        break

Just FYI, when I run now, my logs show a "Client network socket disconnected..." error followed by an "UnhandledPromiseRejectionWarning..." error (lines 57 to 66), but maybe that's not significant as things seem to be working fine otherwise.

pi@Moms-Photo-Viewer:~ $ cd ~/MagicMirror/ && npm run start

> magicmirror@2.17.1 start /home/pi/MagicMirror
> ./run-start.sh $1

[25.12.2021 07:34.44.705] [LOG]   Starting MagicMirror: v2.17.1
[25.12.2021 07:34.44.730] [LOG]   Loading config ...
[25.12.2021 07:34.44.752] [LOG]   Loading module helpers ...
[25.12.2021 07:34.44.759] [LOG]   No helper found for module: clock.
[25.12.2021 07:34.45.864] [LOG]   Initializing new module helper ...
[25.12.2021 07:34.45.869] [LOG]   Module helper loaded: MMM-GooglePhotos
[25.12.2021 07:34.47.083] [LOG]   Initializing new module helper ...
[25.12.2021 07:34.47.089] [LOG]   Module helper loaded: MMM-3Day-Forecast
[25.12.2021 07:34.47.092] [LOG]   All module helpers loaded.
[25.12.2021 07:34.47.423] [LOG]   Starting server on port 8080 ... 
[25.12.2021 07:34.47.488] [LOG]   Server started ...
[25.12.2021 07:34.47.495] [LOG]   Connecting socket for: MMM-GooglePhotos
[25.12.2021 07:34.47.511] [LOG]   Connecting socket for: MMM-3Day-Forecast
[25.12.2021 07:34.47.515] [LOG]   MMM-3Day-Forecast helper, started...
[25.12.2021 07:34.47.518] [LOG]   Sockets connected & modules started ...
[25.12.2021 07:34.48.423] [LOG]   Launching application.
[25.12.2021 07:34.54.070] [LOG]   [GPHOTOS] Starting Initialization
[25.12.2021 07:34.54.072] [LOG]   [GPHOTOS] Getting album list
[25.12.2021 07:34.54.093] [LOG]   [GPHOTOS:AUTH] Token is expired.
[25.12.2021 07:34.55.610] [LOG]   [GPHOTOS:AUTH] Token is refreshed.
[25.12.2021 07:34.55.615] [LOG]   [GPHOTOS:CORE] Getting Album info chunks.
[25.12.2021 07:34.56.544] [LOG]   [GPHOTOS:AUTH] Token is alive.
[25.12.2021 07:34.56.548] [LOG]   [GPHOTOS:CORE] Getting Album info chunks.
[25.12.2021 07:34.57.785] [LOG]   [GPHOTOS] Finish Album scanning. Properly scanned : 1
[25.12.2021 07:34.57.807] [LOG]   [GPHOTOS] Initialized
[25.12.2021 07:34.57.823] [LOG]   [GPHOTOS] Initialization complete!
[25.12.2021 07:34.57.825] [LOG]   [GPHOTOS] Start first scanning.
[25.12.2021 07:34.57.828] [LOG]   [GPHOTOS] Start Album scanning
[25.12.2021 07:34.57.834] [LOG]   [GPHOTOS] Prepping to get photo list from 'Moms Photo Viewer'
[25.12.2021 07:34.57.844] [LOG]   [GPHOTOS:AUTH] Token is alive.
[25.12.2021 07:34.57.849] [LOG]   [GPHOTOS:CORE] Indexing photos now. total:  0
[25.12.2021 07:34.57.942] [LOG]   [GPHOTOS] successfully loaded cache of  269  photos
[25.12.2021 07:34.57.948] [LOG]   [GPHOTOS] num to ref:  5 , DesChunk:  5 , totalLength:  269 , Pntr:  0
[25.12.2021 07:34.57.957] [LOG]   [GPHOTOS:AUTH] Token is alive.
[25.12.2021 07:34.57.964] [LOG]   [GPHOTOS:CORE] received:  5  to refresh
[25.12.2021 07:34.58.509] [LOG]   [GPHOTOS] refreshed:  5 , totalLength:  269 , Pntr:  5
[25.12.2021 07:34.58.513] [LOG]   [GPHOTOS] just sent  5  more pics
[25.12.2021 07:34.59.423] [LOG]   [GPHOTOS:CORE] Indexing photos now. total:  50
[25.12.2021 07:35.00.151] [LOG]   [GPHOTOS] Image loaded: https://lh3.googleusercontent.com/lr/ <long random text string> =w1080-h1920
[25.12.2021 07:35.01.539] [LOG]   [GPHOTOS:CORE] Indexing photos now. total:  100
[25.12.2021 07:35.03.058] [LOG]   [GPHOTOS:CORE] Indexing photos now. total:  150
[25.12.2021 07:35.06.099] [LOG]   [GPHOTOS:CORE] Indexing photos now. total:  200
[25.12.2021 07:35.13.985] [LOG]   [GPHOTOS:CORE] Indexing photos now. total:  250
[25.12.2021 07:35.14.647] [LOG]   [GPHOTOS] Got 269 photo(s) from 'Moms Photo Viewer'
[25.12.2021 07:35.14.651] [LOG]   [GPHOTOS] Total indexed photos: 269
[25.12.2021 07:35.14.719] [LOG]   [GPHOTOS] Photo list cache saved
[25.12.2021 08:29.57.831] [LOG]   [GPHOTOS] Start Album scanning
[25.12.2021 08:29.57.833] [LOG]   [GPHOTOS] Prepping to get photo list from 'Moms Photo Viewer'
[25.12.2021 08:29.57.838] [LOG]   [GPHOTOS:AUTH] Token is alive.
[25.12.2021 08:29.57.840] [LOG]   [GPHOTOS:CORE] Indexing photos now. total:  0
[25.12.2021 08:29.59.311] [LOG]   [GPHOTOS:CORE] Indexing photos now. total:  50
[25.12.2021 08:30.20.116] [LOG]   [GPHOTOS:CORE] Error: Client network socket disconnected before secure TLS connection was established
[25.12.2021 08:30.20.123] [ERROR] (node:16208) UnhandledPromiseRejectionWarning: Error: Client network socket disconnected before secure TLS connection was established
    at connResetException (internal/errors.js:607:14)
    at TLSSocket.onConnectEnd (_tls_wrap.js:1544:19)
    at TLSSocket.emit (events.js:327:22)
    at endReadableNT (internal/streams/readable.js:1327:12)
    at processTicksAndRejections (internal/process/task_queues.js:80:21)
(Use `electron --trace-warnings ...` to show where the warning was created)
[25.12.2021 08:30.20.126] [ERROR] (node:16208) 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: 2)
[25.12.2021 08:30.20.128] [ERROR] (node:16208) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code.
[25.12.2021 08:34.57.997] [LOG]   [GPHOTOS] Image loading fails. Check your network.: https://lh3.googleusercontent.com/lr/ <long random text string> =w1080-h1920
[25.12.2021 08:34.58.000] [LOG]   [GPHOTOS] num to ref:  1 , DesChunk:  1 , totalLength:  269 , Pntr:  5
[25.12.2021 08:34.58.005] [LOG]   [GPHOTOS:AUTH] Token is expired.
[25.12.2021 08:34.58.177] [LOG]   [GPHOTOS:AUTH] Token is refreshed.
[25.12.2021 08:34.58.181] [LOG]   [GPHOTOS:CORE] received:  1  to refresh
[25.12.2021 08:34.58.690] [LOG]   [GPHOTOS] refreshed:  1 , totalLength:  269 , Pntr:  6
[25.12.2021 08:34.58.693] [LOG]   [GPHOTOS] just sent  1  more pics
[25.12.2021 08:34.58.702] [LOG]   [GPHOTOS] Used last pic in list
[25.12.2021 08:34.58.704] [LOG]   [GPHOTOS] num to ref:  2 , DesChunk:  2 , totalLength:  269 , Pntr:  6
[25.12.2021 08:34.58.710] [LOG]   [GPHOTOS:AUTH] Token is alive.
[25.12.2021 08:34.58.713] [LOG]   [GPHOTOS:CORE] received:  2  to refresh
[25.12.2021 08:34.59.155] [LOG]   [GPHOTOS] Image loaded: https://lh3.googleusercontent.com/lr/ <long random text string> =w1080-h1920
[25.12.2021 08:34.59.505] [LOG]   [GPHOTOS] refreshed:  2 , totalLength:  269 , Pntr:  8
[25.12.2021 08:34.59.507] [LOG]   [GPHOTOS] just sent  2  more pics
[25.12.2021 08:34.59.881] [LOG]   [GPHOTOS] Image loaded: https://lh3.googleusercontent.com/lr/ <long random text string> =w1080-h1920
[25.12.2021 09:24.57.832] [LOG]   [GPHOTOS] Start Album scanning
[25.12.2021 09:24.57.834] [LOG]   [GPHOTOS] Prepping to get photo list from 'Moms Photo Viewer'
[25.12.2021 09:24.57.838] [LOG]   [GPHOTOS:AUTH] Token is alive.
[25.12.2021 09:24.57.840] [LOG]   [GPHOTOS:CORE] Indexing photos now. total:  0
[25.12.2021 09:24.59.498] [LOG]   [GPHOTOS:CORE] Indexing photos now. total:  50
[25.12.2021 09:25.21.497] [LOG]   [GPHOTOS:CORE] Error: Client network socket disconnected before secure TLS connection was established
[25.12.2021 09:25.21.499] [ERROR] (node:16208) UnhandledPromiseRejectionWarning: Error: Client network socket disconnected before secure TLS connection was established
    at connResetException (internal/errors.js:607:14)
    at TLSSocket.onConnectEnd (_tls_wrap.js:1544:19)
    at TLSSocket.emit (events.js:327:22)
    at endReadableNT (internal/streams/readable.js:1327:12)
    at processTicksAndRejections (internal/process/task_queues.js:80:21)
[25.12.2021 09:25.21.501] [ERROR] (node:16208) 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: 4)

Also, just for documentation sake, can either the workarounds you mention above be used to set an updateInterval that is longer than 60 min, or is this a hard limit because of the Google API?

Regardless, thanks again for the helpful module!