UNSOLVED MMM-GooglePhotos - Reaching quota but don't know why
-
I had this configuration for more than a year and recently re-installed Magic Mirror and all the modules.
This is my GooglePhotos config:{ 226 module: "MMM-GooglePhotos", 227 position: "fullscreen_below", 228 config: { 229 albums: ["FamilyPhotos"], // Set your album name. like ["My wedding", "family share", "Travle to Paris"] 230 updateInterval: 1000 * 60 *2, // minimum 10 seconds. 231 scanInterval:1000*60*10 232 sort: "random", // "old", "random" 233 uploadAlbum: null, // Only album created by `create_uploadable_album.js`. 234 condition: { 235 fromDate: null, // Or "2018-03", RFC ... format available 236 toDate: null, // Or "2019-12-25", 237 minWidth: null, // Or 400 238 maxWidth: null, // Or 8000 239 minHeight: null, // Or 400 240 maxHeight: null, // Or 8000 241 minWHRatio: null, 242 maxWHRatio: null, 243 // WHRatio = Width/Height ratio ( ==1 : Squared Photo, < 1 : Portraited Photo, > 1 : Landscaped Photo) 244 }, 245 showWidth: 1080, // These values will be used for quality of downloaded photos to show. real size to show in your MagicMirror region is recommended. 246 showHeight: 1920, 247 timeFormat: "DD MMM YYYY HH:mm", // Or `relative` can be used. 248 debug: true, 249 } 250 },When I go to the MagicMirror-out.log I get:
267546 [19.12.2021 10:58.04.127] [LOG] [GPHOTOS] Getting album list 267547 [19.12.2021 10:58.04.137] [LOG] [GPHOTOS:AUTH] Token is alive. 267548 [19.12.2021 10:58.04.143] [LOG] [GPHOTOS:CORE] Getting Album info chunks. 267549 [19.12.2021 10:58.04.807] [LOG] [GPHOTOS:CORE] Error: Request failed with status code 429 267550 [19.12.2021 10:59.04.127] [LOG] [GPHOTOS] Starting Initialization 267551 [19.12.2021 10:59.04.134] [LOG] [GPHOTOS] Getting album list 267552 [19.12.2021 10:59.04.143] [LOG] [GPHOTOS:AUTH] Token is alive. 267553 [19.12.2021 10:59.04.146] [LOG] [GPHOTOS:CORE] Getting Album info chunks. 267554 [19.12.2021 10:59.05.781] [LOG] [GPHOTOS:CORE] Error: Request failed with status code 429When I go to MagicMirror-error.log I get:
212039 [19.12.2021 10:59.05.786] [ERROR] (node:25894) 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: 6) 212040 [19.12.2021 11:00.05.787] [ERROR] (node:25894) UnhandledPromiseRejectionWarning: Error: Request failed with status code 429 212041 at createError (/home/pi/MagicMirror/modules/MMM-GooglePhotos/node_modules/axios/lib/core/createError.js:16:15) 212042 at settle (/home/pi/MagicMirror/modules/MMM-GooglePhotos/node_modules/axios/lib/core/settle.js:17:12) 212043 at IncomingMessage.handleStreamEnd (/home/pi/MagicMirror/modules/MMM-GooglePhotos/node_modules/axios/lib/adapters/http.js:236:11) 212044 at IncomingMessage.emit (events.js:327:22) 212045 at endReadableNT (internal/streams/readable.js:1327:12) 212046 at processTicksAndRejections (internal/process/task_queues.js:80:21)What I found about this error was this page from the forum: https://forum.magicmirror.builders/topic/14871/mmm-googlephotos-unhandled-promise-rejection/8 but I can’t seem to figure out how am I getting too may requests as I should be below that number with a request every 5 minutes.
In the evenings though the Google Photos module seems to start working. Last night it worked from about 8PM to about 2AM:
263628 [19.12.2021 02:01.29.956] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 4230 263629 [19.12.2021 02:01.31.057] [LOG] en 263630 [19.12.2021 02:01.31.937] [LOG] NOAA3 weather updated.. next update in 1 hour 263631 [19.12.2021 02:01.33.091] [LOG] en 263632 [19.12.2021 02:01.33.590] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 4270 263633 [19.12.2021 02:01.34.612] [LOG] NOAA3 weather updated.. next update in 1 hour 263634 [19.12.2021 02:01.35.775] [LOG] en 263635 [19.12.2021 02:01.36.816] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 4319 263636 [19.12.2021 02:01.37.552] [LOG] NOAA3 weather updated.. next update in 1 hour 263637 [19.12.2021 02:01.38.690] [LOG] en 263638 [19.12.2021 02:01.40.010] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 4369 263639 [19.12.2021 02:01.40.261] [LOG] NOAA3 weather updated.. next update in 1 hour 263640 [19.12.2021 02:01.41.418] [LOG] en 263641 [19.12.2021 02:01.42.818] [LOG] NOAA3 weather updated.. next update in 1 hour 263642 [19.12.2021 02:01.43.235] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 4419 263643 [19.12.2021 02:01.44.146] [LOG] en 263644 [19.12.2021 02:01.45.877] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 4468 263645 [19.12.2021 02:01.45.912] [LOG] NOAA3 weather updated.. next update in 1 hour 263646 [19.12.2021 02:01.47.045] [LOG] en 263647 [19.12.2021 02:01.48.018] [LOG] Notification: GET_SOLAR Payload: [object Object] 263648 [19.12.2021 02:01.48.421] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 4518 263649 [19.12.2021 02:01.48.595] [LOG] NOAA3 weather updated.. next update in 1 hour 263650 [19.12.2021 02:01.50.022] [LOG] en 263651 [19.12.2021 02:01.50.694] [LOG] starting network connection testing 263652 [19.12.2021 02:01.51.086] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 4568 263653 [19.12.2021 02:01.52.585] [LOG] [GPHOTOS] Start Album scanning 263654 [19.12.2021 02:01.52.596] [LOG] [GPHOTOS] Prepping to get photo list from 'FamilyPhotos' 263655 [19.12.2021 02:01.52.602] [LOG] [GPHOTOS:AUTH] Token is alive. 263656 [19.12.2021 02:01.52.605] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 0 263657 [19.12.2021 02:01.54.347] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 4615 263658 [19.12.2021 02:01.54.845] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 45 263659 [19.12.2021 02:01.56.918] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 4659 263660 [19.12.2021 02:01.58.438] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 91 263661 [19.12.2021 02:01.59.317] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 4702 263662 [19.12.2021 02:02.01.182] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 140 263663 [19.12.2021 02:02.01.943] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 4749 263664 [19.12.2021 02:02.03.825] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 187 263665 [19.12.2021 02:02.05.659] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 4798 263666 [19.12.2021 02:02.06.479] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 234 263667 [19.12.2021 02:02.09.398] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 4847 263668 [19.12.2021 02:02.09.927] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 276 263669 [19.12.2021 02:02.11.982] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 4897 263670 [19.12.2021 02:02.13.361] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 325 263671 [19.12.2021 02:02.15.614] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 4946 263672 [19.12.2021 02:02.17.021] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 375 263673 [19.12.2021 02:02.19.028] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 4995 263674 [19.12.2021 02:02.20.643] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 420 263675 [19.12.2021 02:02.21.314] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 5044 263676 [19.12.2021 02:02.22.998] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 468 263677 [19.12.2021 02:02.23.433] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 5094 263678 [19.12.2021 02:02.26.387] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 515 263679 [19.12.2021 02:02.26.760] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 5143 263680 [19.12.2021 02:02.32.390] [INFO] Calendar-Fetcher: Broadcasting 15 events. 263681 [19.12.2021 02:02.32.949] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 5191 263682 [19.12.2021 02:02.32.978] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 559 263683 [19.12.2021 02:02.36.310] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 607 263684 [19.12.2021 02:02.36.335] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 5240 263685 [19.12.2021 02:02.39.673] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 5289 263686 [19.12.2021 02:02.39.770] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 651 263687 [19.12.2021 02:02.41.940] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 5338 263688 [19.12.2021 02:02.42.876] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 696 263689 [19.12.2021 02:02.45.429] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 5388 263690 [19.12.2021 02:02.46.248] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 734 263691 [19.12.2021 02:02.48.599] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 778 263692 [19.12.2021 02:02.49.679] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 5438 263693 [19.12.2021 02:02.50.705] [LOG] [GPHOTOS:CORE] Error: Request failed with status code 429 263694 [19.12.2021 02:02.52.221] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 5488 263695 [19.12.2021 02:02.53.756] [LOG] [GPHOTOS:CORE] Error: Request failed with status code 429 263696 [19.12.2021 02:04.05.930] [LOG] [GPHOTOS] Image loading fails. Check your network.: https://lh3.googleusercontent.com/lr/AFBm1_b84YissZJVOjwjMwQ-ztj7i-L_kjglXaMKSLMzhSWx5pqfSI_BDFFNToYwrOzJAQqcUPworEBaXfJVagYWNppK9g-0giQ_3iHKwGWnaT9CDBLUfAQP9gBRnTYouHAP- gI053J7hFAuWRv1y072K_dEL9K7Kipr5Inm5OoTnR4gPG6_Nq1y6hBoCFrAjJTOnsrdYlLJixbIm4bKgzdrGzQSxzt3zUolBG-1VBbhzurYmrY9AIt7o_NqPn8bdQZTpXVF7-D9MWT91yq7sH0yzkFmxqOz3qeaMr_VYnfs4eSaQOuDQQw80ZggI4KZlkxeCr8fTSVoCQ5oZaZwsirn6cFsAlFNkX1B8-mCm7TYnWYlJbEzeKkfMxqKVlBdERpmc- jXAl3Ip8FgrNGrgebzUnfzglYUkyWvWjZAnwVqCDzKCEVVHjAy1zxd94TiqV37uXmP8C3Sp-f4_lvCVkDSuk-X8NzosEKcStZRMJl0mxP75UnVfHHhlCql8AXncwmVstX5y2ftlqRuj499_LFKx6b_2Kkz-xC4OOJoUvy- jSPVp1UiH0hMMLhhTwwi1X89jwCInvK9HwHHF3jE7lUs9NgmTcC0ffheLS0fYNcZ7OxLlV15SIPH60XdNYNM2OfWBajJtbFeDuMQmTx6WUx1QADfpa81DoAffv8jj7PRJ6U2Fv_scoNcN08IgbKt_DJjgVk67b69BtHJciymhmkSx8EWzeUFBMFwe3D0k6vcbnOssDMw96XTVZU5SGQKewYNIh7zOm_TD8EvI-PuWKwVDgOiESMuVynxNIRvlgggwSdu5HlSnq9- HTQgwQOHx_v-N0ca99ULapd6=w1080-h1920 263697 [19.12.2021 02:04.05.931] [LOG] [GPHOTOS] num to ref: 8 , DesChunk: 8 , totalLength: 6228 , Pntr: 343 263698 [19.12.2021 02:04.05.933] [LOG] [GPHOTOS:AUTH] Token is alive.Looking at the logs what I found curious was that it seems that there are multiple streams of indexing happeing in paralel:
263684 [19.12.2021 02:02.36.335] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 5240 263685 [19.12.2021 02:02.39.673] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 5289 263686 [19.12.2021 02:02.39.770] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 651 263687 [19.12.2021 02:02.41.940] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 5338 263688 [19.12.2021 02:02.42.876] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 696 263689 [19.12.2021 02:02.45.429] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 5388 263690 [19.12.2021 02:02.46.248] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 734 263691 [19.12.2021 02:02.48.599] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 778 263692 [19.12.2021 02:02.49.679] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 5438
I also went in my google api account and clicked around and found that I was going over my quota every day and probably my quota was reset at in the evening and fill it up by morning.
Can anyone give me an idea why I’m going over my quota and how can I troubleshoot this? -
@bhaules do you have multiple mirrors running, or multiple browsers connected to mm?
-
@sdetweil That was my thought as well.
I initially tried re-installing MagicMirror using the official manual steps, configured PM2 and I couldn’t get it to work. I then used your script and that worked wonders
Thank you for that.pi@MagicMirror2:~ $ pm2 start all [PM2] Applying action restartProcessId on app [all](ids: [ 0 ]) [PM2] [MagicMirror](0) ✓ [PM2] Process successfully started ┌─────┬────────────────┬─────────────┬─────────┬─────────┬──────────┬────────┬──────┬───────────┬──────────┬──────────┬──────────┬──────────┐ │ id │ name │ namespace │ version │ mode │ pid │ uptime │ ↺ │ status │ cpu │ mem │ user │ watching │ ├─────┼────────────────┼─────────────┼─────────┼─────────┼──────────┼────────┼──────┼───────────┼──────────┼──────────┼──────────┼──────────┤ │ 0 │ MagicMirror │ default │ 2.17.1 │ fork │ 2440 │ 0s │ 1 │ online │ 0% │ 2.6mb │ pi │ disabled │I don’t have anything in crontab
Where else can I check to see if there’s another instance running? -
@bhaules I meant from another machine, windows PC looking at the mm web page
-
@sdetweil Not as far as I’m aware.
My current setup is a rpi connected to a tv and that’s it.
Is there a way to check to see if there are other external connections? -
@bhaules not that I am aware of
what is the address: setting in config.js?
if ,“localhost” then only apps inside the same machine can connect
-
@sdetweil I really appreciate you giving your time to help me:
I have whitelisted in the past my local network ips to be able to connect to the MM instance (for troubleshooting). Not using it any more in any other browsers.
10 let config = { 11 address: "localhost", // Address to listen on, can be: 12 // - "localhost", "127.0.0.1", "::1" to listen on loopback interface 13 // - another specific IPv4/6 to listen on a specific interface 14 // - "0.0.0.0", "::" to listen on any interface 15 // Default, when address config is left out or empty, is "localhost" 16 port: 8080, 17 basePath: "/", // The URL path where MagicMirror is hosted. If you are using a Reverse proxy 18 // you must set the sub path here. basePath must end with a / 19 ipWhitelist: ["::ff:0.0.0.0/1", "::fff:128.0.0.0/2", "::fff:192.0.0.0/3", "::fff:224.0.0.0/4", "127.0.0.1", "::ffff:127.0.0.1", "::1","10.1.1.142","::ffff:10.1.1.1/112","10.1.1.89", "10.1.1.215"], 20 //ipWhitelist: ["127.0.0.1", "::ffff:127.0.0.1", "::1"], // Set [] to allow all IP addresses 21 // or add a specific IPv4 of 192.168.1.5 : 22 // ["127.0.0.1", "::ffff:127.0.0.1", "::1", "::ffff:192.168.1.5"], 23 // or IPv4 range of 192.168.3.0 --> 192.168.3.15 use CIDR format : 24 // ["127.0.0.1", "::ffff:127.0.0.1", "::1", "::ffff:192.168.3.0/28"], 25 26 useHttps: false, // Support HTTPS or not, default "false" will use HTTP 27 httpsPrivateKey: "", // HTTPS private key path, only require when useHttps is true 28 httpsCertificate: "", // HTTPS Certificate path, only require when useHttps is true 29 30 language: "en", 31 locale: "en-US", 32 logLevel: ["INFO", "LOG", "WARN", "ERROR"], // Add "DEBUG" for even more logging 33 timeFormat: 24, 34 units: "metric", 35 // serverOnly: true/false/"local" , 36 // local for armv6l processors, default 37 // starts serveronly and then starts chrome browser 38 // false, default for all NON-armv6l devices 39 // true, force serveronly mode, because you want to.. no UI on this deviceWhat I find curious is that it almost looks like there are 2 streams of indexing running in the same time:
263684 [19.12.2021 02:02.36.335] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 5240 263685 [19.12.2021 02:02.39.673] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 5289 263686 [19.12.2021 02:02.39.770] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 651 263687 [19.12.2021 02:02.41.940] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 5338 263688 [19.12.2021 02:02.42.876] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 696 263689 [19.12.2021 02:02.45.429] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 5388 263690 [19.12.2021 02:02.46.248] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 734 263691 [19.12.2021 02:02.48.599] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 778 263692 [19.12.2021 02:02.49.679] [LOG] [GPHOTOS:CORE] Indexing photos now. total: 5438other than looking at the PM2 not sure where else to look at to see if there is another instance running.
Although I haven’t changed the configuration, I have recently re-installed everything so I’m thinking it’s related to the re-install rather than the config:
-
Just memo;
It seems Indexing 50 photos took around 3~4 seconds. (It is too slower than I expect) 5000 photos will take 3000~4000 sec, = around 50 ~ 60minutes.
But your scanInterval is 10 minutes. It might be the reason? Before finishing the previous scanning cycle, a new cycle might begin.As I mentioned earlier on github, scanning 5thousands photos every 10 minutes to show random 5 pictures in that 10 minutes, seems not so much efficient.
