MagicMirror Failing on Raspberry Pi Zero W Rev 1.1

davidgagne · Aug 5, 2024, 4:52 PM

@sdetweil Calling npm run server immediately after connecting via ssh yields:

npm error code ENOENT
npm error syscall open
npm error path /home/dvg/package.json
npm error errno -2
npm error enoent Could not read package.json: Error: ENOENT: no such file or directory, open '/home/dvg/package.json'
npm error enoent This is related to npm not being able to find a file.
npm error enoent
npm error A complete log of this run can be found in: /home/dvg/.npm/_logs/2024-08-05T16_42_00_562Z-debug-0.log

If I switch to the MagicMirror directory and call it, I get this:

> magicmirror@2.28.0 server
> node ./serveronly

[2024-08-05 12:43:48.489] [LOG]   Starting MagicMirror: v2.28.0 
[2024-08-05 12:43:48.956] [LOG]   Loading config ... 
[2024-08-05 12:43:49.021] [LOG]   config template file not exists, no envsubst 
[2024-08-05 12:43:56.659] [LOG]   Loading module helpers ... 
[2024-08-05 12:43:56.760] [LOG]   No helper found for module: alert. 
[2024-08-05 12:43:57.912] [LOG]   Initializing new module helper ... 
[2024-08-05 12:43:58.105] [LOG]   Module helper loaded: updatenotification 
[2024-08-05 12:43:58.210] [LOG]   No helper found for module: clock. 
[2024-08-05 12:43:58.475] [LOG]   Initializing new module helper ... 
[2024-08-05 12:43:58.608] [LOG]   Module helper loaded: mmm-systemtemperature 
[2024-08-05 12:43:58.784] [LOG]   No helper found for module: weather. 
[2024-08-05 12:43:58.837] [LOG]   No helper found for module: weather. 
[2024-08-05 12:44:06.841] [LOG]   Initializing new module helper ... 
[2024-08-05 12:44:06.956] [LOG]   Module helper loaded: MMM-ThemeParkWaitTimes 
[2024-08-05 12:44:08.953] [LOG]   Initializing new module helper ... 
[2024-08-05 12:44:09.018] [LOG]   Module helper loaded: MMM-birthdays 
[2024-08-05 12:44:09.067] [LOG]   No helper found for module: MMM-CloneWarsQuotes. 
[2024-08-05 12:44:09.136] [LOG]   Initializing new module helper ... 
[2024-08-05 12:44:09.228] [LOG]   Module helper loaded: MMM-ThemeParkWaitTimes 
[2024-08-05 12:44:09.603] [LOG]   Initializing new module helper ... 
[2024-08-05 12:44:09.673] [LOG]   Module helper loaded: MMM-ImagesPhotos 
[2024-08-05 12:44:09.721] [LOG]   All module helpers loaded. 
[2024-08-05 12:44:11.000] [LOG]   Starting server on port 8080 ...  
[2024-08-05 12:44:11.743] [WARN]  You're using a full whitelist configuration to allow for all IPs 
[2024-08-05 12:44:13.607] [ERROR] Whoops! There was an uncaught exception... 
[2024-08-05 12:44:14.335] [ERROR] Error: listen EADDRINUSE: address already in use 0.0.0.0:8080
    at Server.setupListenHandle [as _listen2] (node:net:1872:16)
    at listenInCluster (node:net:1920:12)
    at doListen (node:net:2069:7)
    at process.processTicksAndRejections (node:internal/process/task_queues:83:21) {
  code: 'EADDRINUSE',
  errno: -98,
  syscall: 'listen',
  address: '0.0.0.0',
  port: 8080
} 
[2024-08-05 12:44:14.400] [ERROR] MagicMirror² will not quit, but it might be a good idea to check why this happened. Maybe no internet connection? 
[2024-08-05 12:44:14.422] [ERROR] If you think this really is an issue, please open an issue on GitHub: https://github.com/MagicMirrorOrg/MagicMirror/issues 
[2024-08-05 12:47:35.279] [INFO]  System information:
### SYSTEM:   manufacturer: Raspberry Pi Foundation; model: Raspberry Pi Zero W Rev 1.1; raspberry: [object Object]; virtual: false
### OS:       platform: linux; distro: Raspbian GNU/Linux; release: 11; arch: arm; kernel: 6.1.21+
### VERSIONS: electron: undefined; used node: 20.9.0; installed node: 20.9.0; npm: 10.8.2; pm2: 5.4.2
### OTHER:    timeZone: America/New_York; ELECTRON_ENABLE_GPU: undefined

sdetweil · Aug 5, 2024, 6:08 PM

@davidgagne mm is my shorthand for MagicMirror

sdetweil · Aug 5, 2024, 6:09 PM

@davidgagne ok, another instance is already running

davidgagne · Aug 5, 2024, 6:13 PM

@sdetweil So then why is my MagicMirror-out.log always empty?

sdetweil · Aug 5, 2024, 6:55 PM

@davidgagne do
pm2 status

davidgagne · Aug 5, 2024, 6:59 PM

@sdetweil Executing pm2 status yields:

┌────┬────────┬─────────────┬─────────┬─────────┬──────────┬────────┬──────┬───────────┬──────────┬──────────┬──────────┬──────────┐
│ id │ name   │ namespace   │ version │ mode    │ pid      │ uptime │ ↺    │ status    │ cpu      │ mem      │ user     │ watching │
├────┼────────┼─────────────┼─────────┼─────────┼──────────┼────────┼──────┼───────────┼──────────┼──────────┼──────────┼──────────┤
│ 0  │ pm2    │ default     │ 2.28.0  │ fork    │ 1238     │ 17h    │ 0    │ online    │ 0%       │ 240.0kb  │ dvg      │ enabled  │
└────┴────────┴─────────────┴─────────┴─────────┴──────────┴────────┴──────┴───────────┴──────────┴──────────┴──────────┴──────────┘

sdetweil · Aug 5, 2024, 7:13 PM

@davidgagne that’s why the MagicMirror out log is empty, as the app name is pm2

How did you create that?

And the number under the curly circle next to status is the number of times it has restarted

davidgagne · Aug 5, 2024, 7:23 PM

@sdetweil I mean … I have no idea how I created that. I simply followed the same steps as last time and then executed a few of the commands you told me, e.g. pm2 delete 0, pm2 delete 1, and pm2 save -f. Then I called your fix’em up script:

bash -c "$(curl -sL https://raw.githubusercontent.com/sdetweil/MagicMirror_scripts/master/fixuppm2.sh)"
the log will be saved in /home/dvg/MagicMirror/installers/pm2_setup.log

and after that I called pm2 save followed by pm2 start MagicMirror and then installers/mm.sh & when I was asking you about my cluttered Terminal screen.

Then I called pm2 restart MagicMirror which told me:

Use --update-env to update environment variables
[PM2][ERROR] Process or Namespace MagicMirror not found

So then I called npm start & which gave me

[1] 12338

> magicmirror@2.28.0 start
> ./run-start.sh $1

./run-start.sh: line 79: 11841 Killed                  node serveronly

So I did a sudo reboot and everything seemed to be working fine. But my out log was empty so I called npm run server at your direction, and here we are.

sdetweil · Aug 5, 2024, 10:33 PM

@davidgagne the log is empty cause the pm2 app name is used for file names

davidgagne · Aug 5, 2024, 11:47 PM

@sdetweil Hm. I do have a file /.pm2/pm2.log that’s filled with thousands of these:

2024-08-04T00:35:12: PM2 log: App [MagicMirror:1] exited with code [1] via signal [SIGINT]
2024-08-04T00:35:13: PM2 log: App [MagicMirror:1] starting in -fork mode-
2024-08-04T00:35:13: PM2 log: App [MagicMirror:1] online
2024-08-04T00:35:19: PM2 log: App [MagicMirror:1] exited with code [1] via signal [SIGINT]
2024-08-04T00:35:19: PM2 log: App [MagicMirror:1] starting in -fork mode-
2024-08-04T00:35:19: PM2 log: App [MagicMirror:1] online
2024-08-04T00:35:25: PM2 log: App [MagicMirror:1] exited with code [1] via signal [SIGINT]
2024-08-04T00:35:25: PM2 log: App [MagicMirror:1] starting in -fork mode-
2024-08-04T00:35:25: PM2 log: App [MagicMirror:1] online

The last entry in that file is from 2024-08-04T21:22:04, which is around/about the last time I rebooted the Pi.

The tail of that log file looks like this:

2024-08-04T21:16:54: PM2 log: pid=3352 msg=failed to kill - retrying in 100ms
2024-08-04T21:16:54: PM2 log: Process with pid 3352 still alive after 1600ms, sending it SIGKILL now...
2024-08-04T21:16:55: PM2 log: App [pm2:0] exited with code [0] via signal [SIGKILL]
2024-08-04T21:16:55: PM2 log: pid=3352 msg=process killed
2024-08-04T21:16:56: PM2 log: PM2 successfully stopped
2024-08-04T21:22:02: PM2 log: ===============================================================================
2024-08-04T21:22:02: PM2 log: --- New PM2 Daemon started ----------------------------------------------------
2024-08-04T21:22:02: PM2 log: Time                 : Sun Aug 04 2024 21:22:02 GMT-0400 (Eastern Daylight Time)
2024-08-04T21:22:02: PM2 log: PM2 version          : 5.4.2
2024-08-04T21:22:02: PM2 log: Node.js version      : 20.9.0
2024-08-04T21:22:02: PM2 log: Current arch         : arm
2024-08-04T21:22:02: PM2 log: PM2 home             : /home/dvg/.pm2
2024-08-04T21:22:02: PM2 log: PM2 PID file         : /home/dvg/.pm2/pm2.pid
2024-08-04T21:22:02: PM2 log: RPC socket file      : /home/dvg/.pm2/rpc.sock
2024-08-04T21:22:02: PM2 log: BUS socket file      : /home/dvg/.pm2/pub.sock
2024-08-04T21:22:02: PM2 log: Application log path : /home/dvg/.pm2/logs
2024-08-04T21:22:02: PM2 log: Worker Interval      : 30000
2024-08-04T21:22:02: PM2 log: Process dump file    : /home/dvg/.pm2/dump.pm2
2024-08-04T21:22:02: PM2 log: Concurrent actions   : 2
2024-08-04T21:22:02: PM2 log: SIGTERM timeout      : 1600
2024-08-04T21:22:02: PM2 log: ===============================================================================
2024-08-04T21:22:04: PM2 log: [Watch] Start watching pm2
2024-08-04T21:22:04: PM2 log: App [pm2:0] starting in -fork mode-
2024-08-04T21:22:04: PM2 log: App [pm2:0] online

And in the /.pm2/logs/ directory I have MagicMirror-error.log, MagicMirror-out.log, pm2-error.log, and pm2-out.log.

That last one appears to contain what I would have expected to see in the MM-out.log.

I am not opposed to flashing the drive and starting from scratch if you think I should.