Crashing after "Starting Server"

BEGreen87 · Nov 20, 2023, 8:26 PM

Hey Gang,

I run MagicMirror in a Docker Container and started running into an issue yesterday where it seems to crash after reaching " —Starting Server—". Just prior to this I had rebooted the Container and the page worked for 1-2hrs until it froze.

Updates on the container are disabled after a past learning event since things were stable, although I did update during troubleshooting efforts.

The following log is on constant loop:

> magicmirror@2.25.0 server
> node ./serveronly

[20.11.2023 11:27.12.528] [LOG]   Starting MagicMirror: v2.25.0
[20.11.2023 11:27.12.530] [LOG]   Loading config ...
[20.11.2023 11:27.12.532] [DEBUG] config template file not exists, no envsubst
[20.11.2023 11:27.12.535] [LOG]   Loading module helpers ...
[20.11.2023 11:27.12.536] [LOG]   No helper found for module: alert.
[20.11.2023 11:27.12.544] [LOG]   Initializing new module helper ...
[20.11.2023 11:27.12.545] [LOG]   Module helper loaded: updatenotification
[20.11.2023 11:27.12.546] [LOG]   No helper found for module: clock.
[20.11.2023 11:27.12.670] [ERROR] Whoops! There was an uncaught exception...
[20.11.2023 11:27.12.672] [ERROR] Error: Cannot find module 'fetch'
Require stack:
- /magicmirror2/modules/default/calendar/calendarfetcher.js
- /magicmirror2/modules/default/calendar/node_helper.js
- /magicmirror2/js/app.js
- /magicmirror2/serveronly/index.js
    at Module._resolveFilename (node:internal/modules/cjs/loader:1077:15)
    at Module._resolveFilename (/magicmirror2/node_modules/module-alias/index.js:49:29)
    at Module._load (node:internal/modules/cjs/loader:922:27)
    at Module.require (node:internal/modules/cjs/loader:1143:19)
    at require (node:internal/modules/cjs/helpers:121:18)
    at Object.<anonymous> (/magicmirror2/modules/default/calendar/calendarfetcher.js:11:15)
    at Module._compile (node:internal/modules/cjs/loader:1256:14)
    at Module._extensions..js (node:internal/modules/cjs/loader:1310:10)
    at Module.load (node:internal/modules/cjs/loader:1119:32)
    at Module._load (node:internal/modules/cjs/loader:960:12)
    at Module.require (node:internal/modules/cjs/loader:1143:19)
    at require (node:internal/modules/cjs/helpers:121:18)
    at Object.<anonymous> (/magicmirror2/modules/default/calendar/node_helper.js:8:25)
    at Module._compile (node:internal/modules/cjs/loader:1256:14)
    at Module._extensions..js (node:internal/modules/cjs/loader:1310:10)
    at Module.load (node:internal/modules/cjs/loader:1119:32) {
  code: 'MODULE_NOT_FOUND',
  requireStack: [
    '/magicmirror2/modules/default/calendar/calendarfetcher.js',
    '/magicmirror2/modules/default/calendar/node_helper.js',
    '/magicmirror2/js/app.js',
    '/magicmirror2/serveronly/index.js'
  ]
}
[20.11.2023 11:27.12.673] [ERROR] MagicMirror² will not quit, but it might be a good idea to check why this happened. Maybe no internet connection?
[20.11.2023 11:27.12.673] [ERROR] If you think this really is an issue, please open an issue on GitHub: https://github.com/MichMich/MagicMirror/issues
---Ensuring UID: 99 matches user---
usermod: no changes
---Ensuring GID: 100 matches user---
usermod: no changes
---Setting umask to 000---
---Checking for optional scripts---
---No optional script found, continuing---
---Taking ownership of data...---
---Starting...---
---MagicMirror² up-to-date---
---Looking for new modules to install---
Module 'MMM-GoogleCalendar' found!
Module 'MMM-GooglePhotos' found!
Module 'MMM-WeatherGraph' found!
Module 'MMM-MyCommute' found!
Module 'MMM-MonthlyCalendar' found!
Module 'MMM-WebHookAlerts' found!
Module 'MMM-WeasleyClock' found!
Module 'MMM-NotificationReceived' found!
Module 'MMM-TracCar' found!
Module 'MMM-WiFiPassword' found!
Module 'MMM-GoogleDocs-Notes' found!
---Preparing Server---
---Configuration file found!---
---Please wait, permissions are set, this can take some time...---
---Starting Server---

I’m not sure if this is related to “Error: Cannot find module ‘fetch’”, but went ahead and tried the suggestions over here (this was for “node-fetch” while it looks like mine is just “fetch”).

Thanks in advance for the help.

sdetweil · Nov 20, 2023, 8:29 PM

@BEGreen87 sounds like the npm install was not done after the code update

BEGreen87 · Nov 21, 2023, 1:45 AM

@sdetweil Thanks for the reply. Tried again:

Here’s result from “npm install node-fetch@2”:

up to date, audited 153 packages in 1s

12 packages are looking for funding
  run `npm fund` for details

11 vulnerabilities (5 moderate, 6 high)

To address issues that do not require attention, run:
  npm audit fix

Some issues need review, and may require choosing
a different dependency.

Run `npm audit` for details.

and “npm install”:

up to date, audited 153 packages in 879ms

12 packages are looking for funding
  run `npm fund` for details

11 vulnerabilities (5 moderate, 6 high)

To address issues that do not require attention, run:
  npm audit fix

Some issues need review, and may require choosing
a different dependency.

Run `npm audit` for details.

Started to look at the vulnerabilities with ‘npm audit’:

npm audit report

connect  <=2.30.2
Severity: high
methodOverride Middleware Reflected Cross-Site Scripting in connect - https://github.com/advisories/GHSA-3fw8-66wf-pr7m
Cross-Site Scripting in connect - https://github.com/advisories/GHSA-rch9-xh7r-mqgw
Node Connect Reflected Cross-Site Scripting in Sencha Labs Connect middleware - https://github.com/advisories/GHSA-6w62-83g6-rfhj
Depends on vulnerable versions of cookie-signature
Depends on vulnerable versions of fresh
Depends on vulnerable versions of qs
Depends on vulnerable versions of send
fix available via `npm audit fix`
node_modules/connect
  express  <=4.15.4 || 5.0.0-alpha.1 - 5.0.0-alpha.5
  Depends on vulnerable versions of connect
  Depends on vulnerable versions of cookie-signature
  Depends on vulnerable versions of fresh
  Depends on vulnerable versions of send
  node_modules/hooks-node/node_modules/express
    hooks-node  *
    Depends on vulnerable versions of express
    Depends on vulnerable versions of request
    node_modules/hooks-node

cookie-signature  <1.0.4
Severity: moderate
cookie-signature Timing Attack - https://github.com/advisories/GHSA-92vm-wfm5-mxvv
fix available via `npm audit fix`
node_modules/connect/node_modules/cookie-signature
node_modules/hooks-node/node_modules/cookie-signature


fresh  <0.5.2
Severity: high
Regular Expression Denial of Service in fresh - https://github.com/advisories/GHSA-9qj9-36jm-prpv
fix available via `npm audit fix`
node_modules/connect/node_modules/fresh
node_modules/hooks-node/node_modules/fresh
  send  <=0.15.6
  Depends on vulnerable versions of fresh
  Depends on vulnerable versions of mime
  node_modules/connect/node_modules/send
  node_modules/hooks-node/node_modules/send

mime  <1.4.1
Severity: high
mime Regular Expression Denial of Service when MIME lookup performed on untrusted user input - https://github.com/advisories/GHSA-wrvr-8mpx-r7pp
fix available via `npm audit fix`
node_modules/connect/node_modules/mime
node_modules/hooks-node/node_modules/mime

qs  <=6.2.3
Severity: high
Prototype Pollution Protection Bypass in qs - https://github.com/advisories/GHSA-gqgv-6jq5-jjj9
Denial-of-Service Extended Event Loop Blocking in qs - https://github.com/advisories/GHSA-f9cm-p3w6-xvr3
Denial-of-Service Memory Exhaustion in qs - https://github.com/advisories/GHSA-jjv7-qpx3-h62q
qs vulnerable to Prototype Pollution - https://github.com/advisories/GHSA-hrpp-h998-j3pp
fix available via `npm audit fix`
node_modules/connect/node_modules/qs

request  *
Severity: moderate
Server-Side Request Forgery in Request - https://github.com/advisories/GHSA-p8p7-x288-28g6
Depends on vulnerable versions of tough-cookie
No fix available
node_modules/request
  fetch-node  *
  Depends on vulnerable versions of hooks-node
  Depends on vulnerable versions of request
  node_modules/fetch-node


tough-cookie  <4.1.3
Severity: moderate
tough-cookie Prototype Pollution vulnerability - https://github.com/advisories/GHSA-72xf-g2v4-qvf3
No fix available
node_modules/tough-cookie

11 vulnerabilities (5 moderate, 6 high)

To address issues that do not require attention, run:
  npm audit fix

Some issues need review, and may require choosing
a different dependency.

No dice with “npm audit fix” or “npm audit fix --force”. Ended up deleting package-lock.json and the node_modules directory to reset everything.

Result of “npm install”:

> magicmirror@2.25.0 postinstall
> npm run install-vendor && npm run install-fonts && echo "MagicMirror² installation finished successfully! 
> "


> magicmirror@2.25.0 install-vendor
> echo "Installing vendor files ...
> " && cd vendor && npm install --loglevel=error --no-audit --no-fund --no-update-notifier

Installing vendor files ...


up to date in 346ms

> magicmirror@2.25.0 install-fonts
> echo "Installing fonts ...
> " && cd fonts && npm install --loglevel=error --no-audit --no-fund --no-update-notifier

Installing fonts ...


up to date in 285ms
MagicMirror² installation finished successfully! 


> magicmirror@2.25.0 prepare
> [ -f node_modules/.bin/husky ] && husky install || echo no husky installed.

fatal: not a git repository (or any parent up to mount point /)
Stopping at filesystem boundary (GIT_DISCOVERY_ACROSS_FILESYSTEM not set).
husky - git command not found, skipping install

added 862 packages, and audited 863 packages in 39s

199 packages are looking for funding
  run `npm fund` for details

found 0 vulnerabilities

No dice yet… Also tried to get things to run between these steps.

MMRIZE · Nov 20, 2023, 11:08 PM

@BEGreen87
“fetch” is introduced since node 18. Your log seems fetch is not provided natively and it means your node version might be somehow older than nodev18.

BEGreen87 · Nov 21, 2023, 1:41 AM

@MMRIZE Thanks for the help. Is there a configuration that needs to be set around node?

Here’s what “node -v” returns:

v18.17.1

Noticed it wasn’t the latest so went through the following:

npm install -g n
n lts
n prune

Now “node -v” returns:

v20.9.0

Still having the same issue, log after update below:

> magicmirror@2.25.0 server
> node ./serveronly

[20.11.2023 15:43.16.311] [LOG]   Starting MagicMirror: v2.25.0
[20.11.2023 15:43.16.313] [LOG]   Loading config ...
[20.11.2023 15:43.16.315] [DEBUG] config template file not exists, no envsubst
[20.11.2023 15:43.16.319] [LOG]   Loading module helpers ...
[20.11.2023 15:43.16.320] [LOG]   No helper found for module: alert.
[20.11.2023 15:43.16.331] [LOG]   Initializing new module helper ...
[20.11.2023 15:43.16.331] [LOG]   Module helper loaded: updatenotification
[20.11.2023 15:43.16.332] [LOG]   No helper found for module: clock.
[20.11.2023 15:43.16.449] [ERROR] Whoops! There was an uncaught exception...
[20.11.2023 15:43.16.453] [ERROR] Error: Cannot find module 'fetch'
Require stack:
- /magicmirror2/modules/default/calendar/calendarfetcher.js
- /magicmirror2/modules/default/calendar/node_helper.js
- /magicmirror2/js/app.js
- /magicmirror2/serveronly/index.js
    at Module._resolveFilename (node:internal/modules/cjs/loader:1048:15)
    at Module._resolveFilename (/magicmirror2/node_modules/module-alias/index.js:49:29)
    at Module._load (node:internal/modules/cjs/loader:901:27)
    at Module.require (node:internal/modules/cjs/loader:1115:19)
    at require (node:internal/modules/helpers:130:18)
    at Object.<anonymous> (/magicmirror2/modules/default/calendar/calendarfetcher.js:11:15)
    at Module._compile (node:internal/modules/cjs/loader:1241:14)
    at Module._extensions..js (node:internal/modules/cjs/loader:1295:10)
    at Module.load (node:internal/modules/cjs/loader:1091:32)
    at Module._load (node:internal/modules/cjs/loader:938:12)
    at Module.require (node:internal/modules/cjs/loader:1115:19)
    at require (node:internal/modules/helpers:130:18)
    at Object.<anonymous> (/magicmirror2/modules/default/calendar/node_helper.js:8:25)
    at Module._compile (node:internal/modules/cjs/loader:1241:14)
    at Module._extensions..js (node:internal/modules/cjs/loader:1295:10)
    at Module.load (node:internal/modules/cjs/loader:1091:32) {
  code: 'MODULE_NOT_FOUND',
  requireStack: [
    '/magicmirror2/modules/default/calendar/calendarfetcher.js',
    '/magicmirror2/modules/default/calendar/node_helper.js',
    '/magicmirror2/js/app.js',
    '/magicmirror2/serveronly/index.js'
  ]
}
[20.11.2023 15:43.16.453] [ERROR] MagicMirror² will not quit, but it might be a good idea to check why this happened. Maybe no internet connection?
[20.11.2023 15:43.16.453] [ERROR] If you think this really is an issue, please open an issue on GitHub: https://github.com/MichMich/MagicMirror/issues
---Ensuring UID: 99 matches user---
usermod: no changes
---Ensuring GID: 100 matches user---
usermod: no changes
---Setting umask to 000---
---Checking for optional scripts---
---No optional script found, continuing---
---Taking ownership of data...---
---Starting...---
---MagicMirror² up-to-date---
---Looking for new modules to install---
Module 'MMM-GoogleCalendar' found!
Module 'MMM-GooglePhotos' found!
Module 'MMM-WeatherGraph' found!
Module 'MMM-MyCommute' found!
Module 'MMM-MonthlyCalendar' found!
Module 'MMM-WebHookAlerts' found!
Module 'MMM-WeasleyClock' found!
Module 'MMM-NotificationReceived' found!
Module 'MMM-TracCar' found!
Module 'MMM-WiFiPassword' found!
Module 'MMM-GoogleDocs-Notes' found!
---Preparing Server---
---Configuration file found!---
---Please wait, permissions are set, this can take some time...---
---Starting Server---

sdetweil · Nov 21, 2023, 1:41 AM

@BEGreen87 what is all that junk at the end?

sdetweil · Nov 21, 2023, 1:45 AM

@BEGreen87 move the mm folder out of the way

and run my install script
https://github.com/sdetweil/MagicMirror_scripts

you may want to backup your mirror setup and restore after

https://github.com/sdetweil/MagicMirror-backup-restore

MMRIZE · Nov 21, 2023, 2:24 AM

@BEGreen87

[20.11.2023 15:43.16.453] [ERROR] Error: Cannot find module 'fetch'
Require stack:
- /magicmirror2/modules/default/calendar/calendarfetcher.js

This is very weird log, because calendarfetcer.js doesn’t call require("fetch") in the source, so there is no reason of that error. Is the source modified? Can you check the source is the same with original?

BEGreen87 · Nov 21, 2023, 2:47 AM

@MMRIZE Looks like I match the 2.23.0 Release.

BEGreen87 · Nov 21, 2023, 3:33 AM

@MMRIZE @sdetweil

Thanks for all the help, was able to resolve the issue by replacing all the files in /modules/default/calendar with the ones for the latest release.

Not sure why this didn’t occur during the update, but looks like I’m back in business!