MagicMirror Failing on Raspberry Pi Zero W Rev 1.1

[davidgagne]

@sdetweil Here’s the entire mm.sh file:

#!/bin/bash
# This file is still here to keep PM2 working on older installations.
cd ~/MagicMirror
export external_browser=firefox
DISPLAY=:0 npm start

[sdetweil]

@davidgagne hm… no idea really
you can test the script with

cd ~/MagicMirror
installers/mm.sh

and

cd ~/MagicMirror
export external_browser=firefox
npm start 

never seen it fail tho.

[davidgagne]

@sdetweil If electron hasn’t been required for years, then why does a fresh install of everything generate tens of thousands of “can’t find electron” lines in MagicMirror-error.log?

[sdetweil]

@davidgagne the default install is to use electron.

We made it optional, so the install would not just fail.
and my script makes other browsers available as alternatives.

if you do the manual install, there is nothing to fix the package.json still trying to use electron. and it errors out.

now you can clear the pm2 logs

pm2 flush

and then see info from future runs

[davidgagne]

@sdetweil Okay. Next issue is that MagicMirror-out.log is always empty. I recall that I could find lots of information in there the last time I was setting up a MM, but this time it’s always just blank. (The MagicMirror-error.log file is, sadly, useless because it’s just filled with tens of thousands of lines of Error: Cannot find module 'electron'.)

Any idea why MagicMirror-out.log is always empty?

[sdetweil]

@davidgagne out is empty cause mm never started

Does
npm run server
Work

[davidgagne]

@sdetweil I’m sorry, but I don’t understand. What exactly is mm? (MagicMirror is running.)

What does npm run server do? (I can visit the IP address of the Pi on my phone or laptop on my home network.)

[davidgagne]

@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]

@davidgagne mm is my shorthand for MagicMirror

[sdetweil]

@davidgagne ok, another instance is already running

[davidgagne]

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

[sdetweil]

@davidgagne do
pm2 status

[davidgagne]

@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]

@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]

@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]

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

[davidgagne]

@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.

[sdetweil]

@davidgagne I really have no idea where you are.

Flash the legacy image
Boot , don’t update
Run my install script

[butchkemper]

@davidgagne The Pi Zero has 512KB memory, the default swapfile size setting is 100KB, and the swapfile is located on the SDcard which is not very fast.

I would suggest changing the swapfile size to 2048KB by editing /etc/dphys-swapfile and changing CONF_SWAPSIZE=100 to CONF_SWAPSIZE=2048.

You might consider moving from the SDcard to an SSD which will provide quicker data access and improved security against SDcard failure.

Lastly, you might consider changing from a Pi Zero to a Pi Zero 2 or something with more processing power. I use a Pi 3 Model A+ with a USB attached SSD and 2048GB swapfile size.

Butch

[sdetweil]

@butchkemper my install script increases the swap file size if its small (200meg or less).