Read the statement by Michael Teeuw here.
Autostarts but doesn't run, will run on restart
-
@ember1205 pm2 logs --lines=100
to dump out the logs
may want to pm2 flush to empty, and then reboot to get current info
-
Thanks - I had dug into them and found nothing of any use. Still, I went ahead and purged the logs and tried again.
I’m getting VERY weird behavior with zero consistency. I booted the mirror yesterday a half dozen different times and I was getting a split between not launching the browser and launching the browser but landing on “Web Store” and “Magic Mirror” icons in the center with no content.
First boot attempt today resulted in the browser not only launching but correctly bring up my configured mirror and content. Today’s logs show no indication of a PM2 daemon being started, but this WAS being shown in the logs yesterday (very strange).
Executed a powerdown of the Pi, powered it off, waited about ten minutes, powered it back on. Made it all the way to bringing up the desktop and then … nothing. No entry in the log that it was starting Chromium. Executing “pm2 restart mm” brought the browser up but it landed again on the “Magic Mirror” and “Web Store”.
This is frustrating.
-
@ember1205 yes, that chromium desktop thing is a problem…
I posted an issue on MM github back in january.
stop MM…
then
cd ~ rm -rf .config/chromium rm -rf .config/electronnote the dot in front of config…
(one of those commands might fail with not found)then restart mm
another user also cannot get rid of that. he went to midori.
I added midori support for the run-start.sh script…i haven’t seen this except on armv6l devices… (pi0w/pi1)
-
What’s the goal?
I have .config/chromium and .config/Electron with the latter being two years old and the former having a current date (I switched to Chromium because Electron was a ton of trouble).
This is all on Bullseye which I upgraded to (yeah, yeah, I know… don’t upgrade, fresh install, not supported, etc.). Up to that point, it was on Buster and ran fine.
Incidentally… I have an automated routine to bring the RPi down gracefully based on a virtual switch setting on a home automation controller. Here’s the gist:
- Set the virtual switch to “on”
- Every five minutes, the RPi queries the status of the switch
- If the switch is set to “1” (on), it launches a script with sudo
The script does the following:
- Using cec-client, it puts the Soundbar into Standby (off)
- Using cec-client, it puts the TV into standby (off)
- Sets the status of the virtual switch to “1” (on) to ensure that any other items that trigger of the state change of that switch will run as well
- Sets the status of the virtual switch to “0” (off)
- Sends an IFTTT message using WebHooks / curl
- Does a “shutdown now”
If I comment out the cec commands, it starts up incorrectly. If I manually just do a “shutdown now” and boot it back up, it starts up incorrectly.
-
@ember1205 what pi?
if armv6l, use the legacy buster image… do NOT upgrade to bullseye
uname -a will show u
the deletes were to wipe out any saved config data for the browser so it would come up clean…
(not desktop.) supposedly -
armv71
I’ve modified my shutdown control to stop MM, wipe the .config/chromium directory, and then power off. This allows chromium to load the correct information when it does finally launch.
There still remains an issue, however, with the run-start.sh script actually launching the chromium browser on boot. The log file basically ends with “0|mm | Ready to go! Please point your browser to: http://0.0.0.0:8080” on boot up. “pm2 restart mm” correctly brings everything up every time.
Here’s what the log looks like when it boots:
0|mm | > magicmirror@2.13.0 start 0|mm | > ./run-start.sh 0|mm | 0|mm | [2022-05-10 14:30:59.191] [LOG] Starting MagicMirror: v2.13.0 0|mm | [2022-05-10 14:30:59.207] [LOG] Loading config ... 0|mm | [2022-05-10 14:30:59.222] [LOG] Loading module helpers ... 0|mm | [2022-05-10 14:31:00.614] [LOG] Initializing new module helper ... 0|mm | [2022-05-10 14:31:00.617] [LOG] Module helper loaded: MMM-ImagesPhotos 0|mm | [2022-05-10 14:31:00.625] [LOG] No helper found for module: alert. 0|mm | [2022-05-10 14:31:00.733] [LOG] Initializing new module helper ... 0|mm | [2022-05-10 14:31:00.735] [LOG] Module helper loaded: updatenotification 0|mm | [2022-05-10 14:31:00.741] [LOG] No helper found for module: clock. 0|mm | [2022-05-10 14:31:01.058] [LOG] Initializing new module helper ... 0|mm | [2022-05-10 14:31:01.060] [LOG] Module helper loaded: calendar 0|mm | [2022-05-10 14:31:01.068] [LOG] No helper found for module: currentweather. 0|mm | [2022-05-10 14:31:01.072] [LOG] No helper found for module: weatherforecast. 0|mm | [2022-05-10 14:31:01.074] [LOG] All module helpers loaded. 0|mm | [2022-05-10 14:31:02.616] [LOG] Starting server on port 8080 ... 0|mm | [2022-05-10 14:31:02.665] [LOG] Server started ... 0|mm | [2022-05-10 14:31:02.680] [LOG] Connecting socket for: MMM-ImagesPhotos 0|mm | [2022-05-10 14:31:02.683] [LOG] Starting node helper for: MMM-ImagesPhotos 0|mm | [2022-05-10 14:31:02.685] [LOG] Connecting socket for: updatenotification 0|mm | [2022-05-10 14:31:02.693] [LOG] Connecting socket for: calendar 0|mm | [2022-05-10 14:31:02.700] [LOG] Starting node helper for: calendar 0|mm | [2022-05-10 14:31:02.702] [LOG] Sockets connected & modules started ... 0|mm | [2022-05-10 14:31:02.704] [LOG] 0|mm | Ready to go! Please point your browser to: http://0.0.0.0:8080 -
@ember1205 ok,
lets edit run-start.sh t- enable some more debugging
in the 1st line add -x to the change the 1st line to
#!/bin/bash -xthen pm2 flush
then do the reboot which causes mm not to come up.then pm2 logs --lines=100
the debug output will come out in the error listing of the two listings displayed
-
Full logs…
[TAILING] Tailing last 100 lines for [all] processes (change the value with --lines option) /home/pi/.pm2/pm2.log last 100 lines: PM2 | 2022-05-10T15:00:25: PM2 log: PM2 successfully stopped PM2 | 2022-05-10T15:00:44: PM2 log: =============================================================================== PM2 | 2022-05-10T15:00:44: PM2 log: --- New PM2 Daemon started ---------------------------------------------------- PM2 | 2022-05-10T15:00:44: PM2 log: Time : Tue May 10 2022 15:00:44 GMT-0400 (Eastern Daylight Time) PM2 | 2022-05-10T15:00:44: PM2 log: PM2 version : 4.4.1 PM2 | 2022-05-10T15:00:44: PM2 log: Node.js version : 16.15.0 PM2 | 2022-05-10T15:00:44: PM2 log: Current arch : arm PM2 | 2022-05-10T15:00:44: PM2 log: PM2 home : /home/pi/.pm2 PM2 | 2022-05-10T15:00:44: PM2 log: PM2 PID file : /home/pi/.pm2/pm2.pid PM2 | 2022-05-10T15:00:44: PM2 log: RPC socket file : /home/pi/.pm2/rpc.sock PM2 | 2022-05-10T15:00:44: PM2 log: BUS socket file : /home/pi/.pm2/pub.sock PM2 | 2022-05-10T15:00:44: PM2 log: Application log path : /home/pi/.pm2/logs PM2 | 2022-05-10T15:00:44: PM2 log: Worker Interval : 30000 PM2 | 2022-05-10T15:00:44: PM2 log: Process dump file : /home/pi/.pm2/dump.pm2 PM2 | 2022-05-10T15:00:44: PM2 log: Concurrent actions : 2 PM2 | 2022-05-10T15:00:44: PM2 log: SIGTERM timeout : 1600 PM2 | 2022-05-10T15:00:44: PM2 log: =============================================================================== PM2 | 2022-05-10T15:00:45: PM2 log: App [mm:0] starting in -fork mode- PM2 | 2022-05-10T15:00:45: PM2 log: App [mm:0] online /home/pi/.pm2/logs/mm-error.log last 100 lines: 0|mm | + '[' -f ./untrack-css.sh ']' 0|mm | + grep docker /proc/1/cgroup -qa 0|mm | + '[' -z :0 ']' 0|mm | ++ uname -m 0|mm | + arch=armv7l 0|mm | + false=false 0|mm | ++ grep -v '^[[:blank:]]*//' config/config.js 0|mm | ++ grep -i serveronly: 0|mm | ++ awk -F: '{print tolower($2)}' 0|mm | ++ sed -e 's/^[[:space:]]*//' 0|mm | ++ tr -d ',"'\''\r' 0|mm | + serveronly=local 0|mm | + serveronly=local 0|mm | ++ pgrep Xorg 0|mm | + xorg= 0|mm | + '[' . == . ']' 0|mm | ++ pgrep X 0|mm | + xorg= 0|mm | ++ uname 0|mm | + mac=Linux 0|mm | + '[' local. '!=' false. -o armv7l == armv6l ']' 0|mm | + '[' local. == true. ']' 0|mm | + '[' . == . -a Linux '!=' Darwin ']' 0|mm | + node serveronly /home/pi/.pm2/logs/mm-out.log last 100 lines: 0|mm | 0|mm | > magicmirror@2.13.0 start 0|mm | > ./run-start.sh 0|mm | 0|mm | [2022-05-10 15:00:55.768] [LOG] Starting MagicMirror: v2.13.0 0|mm | [2022-05-10 15:00:55.790] [LOG] Loading config ... 0|mm | [2022-05-10 15:00:55.804] [LOG] Loading module helpers ... 0|mm | [2022-05-10 15:00:57.248] [LOG] Initializing new module helper ... 0|mm | [2022-05-10 15:00:57.252] [LOG] Module helper loaded: MMM-ImagesPhotos 0|mm | [2022-05-10 15:00:57.264] [LOG] No helper found for module: alert. 0|mm | [2022-05-10 15:00:57.385] [LOG] Initializing new module helper ... 0|mm | [2022-05-10 15:00:57.387] [LOG] Module helper loaded: updatenotification 0|mm | [2022-05-10 15:00:57.391] [LOG] No helper found for module: clock. 0|mm | [2022-05-10 15:00:57.686] [LOG] Initializing new module helper ... 0|mm | [2022-05-10 15:00:57.689] [LOG] Module helper loaded: calendar 0|mm | [2022-05-10 15:00:57.692] [LOG] No helper found for module: currentweather. 0|mm | [2022-05-10 15:00:57.696] [LOG] No helper found for module: weatherforecast. 0|mm | [2022-05-10 15:00:57.698] [LOG] All module helpers loaded. 0|mm | [2022-05-10 15:01:00.465] [LOG] Starting server on port 8080 ... 0|mm | [2022-05-10 15:01:00.504] [LOG] Server started ... 0|mm | [2022-05-10 15:01:00.507] [LOG] Connecting socket for: MMM-ImagesPhotos 0|mm | [2022-05-10 15:01:00.509] [LOG] Starting node helper for: MMM-ImagesPhotos 0|mm | [2022-05-10 15:01:00.511] [LOG] Connecting socket for: updatenotification 0|mm | [2022-05-10 15:01:00.514] [LOG] Connecting socket for: calendar 0|mm | [2022-05-10 15:01:00.516] [LOG] Starting node helper for: calendar 0|mm | [2022-05-10 15:01:00.517] [LOG] Sockets connected & modules started ... 0|mm | [2022-05-10 15:01:00.519] [LOG] 0|mm | Ready to go! Please point your browser to: http://0.0.0.0:8080 -
Here’s a portion of the log when doing a stop and a start (without reboot):
0|mm | + false=false 0|mm | ++ grep -v '^[[:blank:]]*//' config/config.js 0|mm | ++ grep -i serveronly: 0|mm | ++ awk -F: '{print tolower($2)}' 0|mm | ++ sed -e 's/^[[:space:]]*//' 0|mm | ++ tr -d ',"'\''\r' 0|mm | + serveronly=local 0|mm | + serveronly=local 0|mm | ++ pgrep Xorg 0|mm | + xorg=755 0|mm | + '[' 755. == . ']' 0|mm | ++ uname 0|mm | + mac=Linux 0|mm | + '[' local. '!=' false. -o armv7l == armv6l ']' 0|mm | + '[' local. == true. ']' 0|mm | + '[' 755. == . -a Linux '!=' Darwin ']' 0|mm | + exec 0|mm | + read line 0|mm | ++ node serveronly 0|mm | + case "$line" in 0|mm | + echo '[2022-05-10' '15:14:59.203]' '[LOG]' Starting MagicMirror: v2.13.0 0|mm | + read line 0|mm | + case "$line" in 0|mm | + echo '[2022-05-10' '15:14:59.220]' '[LOG]' Loading config ... 0|mm | + read line 0|mm | + case "$line" in 0|mm | + echo '[2022-05-10' '15:14:59.231]' '[LOG]' Loading module helpers ... 0|mm | + read line 0|mm | + case "$line" in 0|mm | + echo '[2022-05-10' '15:14:59.936]' '[LOG]' Initializing new module helper ... 0|mm | + read line 0|mm | + case "$line" in 0|mm | + echo '[2022-05-10' '15:14:59.938]' '[LOG]' Module helper loaded: MMM-ImagesPhotos 0|mm | + read line 0|mm | + case "$line" in 0|mm | + echo '[2022-05-10' '15:14:59.943]' '[LOG]' No helper found for module: alert. 0|mm | + read line 0|mm | + case "$line" in 0|mm | + echo '[2022-05-10' '15:15:00.042]' '[LOG]' Initializing new module helper ... 0|mm | + read line 0|mm | + case "$line" in 0|mm | + echo '[2022-05-10' '15:15:00.050]' '[LOG]' Module helper loaded: updatenotification 0|mm | + read line 0|mm | + case "$line" in 0|mm | + echo '[2022-05-10' '15:15:00.059]' '[LOG]' No helper found for module: clock. 0|mm | + read line 0|mm | + case "$line" in 0|mm | + echo '[2022-05-10' '15:15:00.274]' '[LOG]' Initializing new module helper ... 0|mm | + read line 0|mm | + case "$line" in 0|mm | + echo '[2022-05-10' '15:15:00.278]' '[LOG]' Module helper loaded: calendar 0|mm | + read line 0|mm | + case "$line" in 0|mm | + echo '[2022-05-10' '15:15:00.280]' '[LOG]' No helper found for module: currentweather. 0|mm | + read line 0|mm | + case "$line" in 0|mm | + echo '[2022-05-10' '15:15:00.282]' '[LOG]' No helper found for module: weatherforecast. 0|mm | + read line 0|mm | + case "$line" in 0|mm | + echo '[2022-05-10' '15:15:00.284]' '[LOG]' All module helpers loaded. 0|mm | + read line 0|mm | + case "$line" in 0|mm | + echo '[2022-05-10' '15:15:00.471]' '[LOG]' Starting server on port 8080 ... 0|mm | + read line 0|mm | + case "$line" in 0|mm | + echo '[2022-05-10' '15:15:00.496]' '[LOG]' Server started ... 0|mm | + read line 0|mm | + case "$line" in 0|mm | + echo '[2022-05-10' '15:15:00.498]' '[LOG]' Connecting socket for: MMM-ImagesPhotos 0|mm | + read line 0|mm | + case "$line" in 0|mm | + echo '[2022-05-10' '15:15:00.500]' '[LOG]' Starting node helper for: MMM-ImagesPhotos 0|mm | + read line 0|mm | + case "$line" in 0|mm | + echo '[2022-05-10' '15:15:00.502]' '[LOG]' Connecting socket for: updatenotification 0|mm | + read line 0|mm | + case "$line" in 0|mm | + echo '[2022-05-10' '15:15:00.504]' '[LOG]' Connecting socket for: calendar 0|mm | + read line 0|mm | + case "$line" in 0|mm | + echo '[2022-05-10' '15:15:00.505]' '[LOG]' Starting node helper for: calendar 0|mm | + read line 0|mm | + case "$line" in 0|mm | + echo '[2022-05-10' '15:15:00.506]' '[LOG]' Sockets connected '&' modules started ... 0|mm | + read line 0|mm | + case "$line" in 0|mm | + echo '[2022-05-10' '15:15:00.507]' '[LOG]' 0|mm | + read line 0|mm | + case "$line" in 0|mm | + echo Ready to 'go!' Please point your browser to: http://0.0.0.0:8080 0|mm | + break 0|mm | ++ echo Ready to 'go!' Please point your browser to: http://0.0.0.0:8080 0|mm | ++ awk -F: '{print $4}' 0|mm | + port=8080 0|mm | + echo 'Starting chromium browser now, have patience, it takes a minute' 0|mm | + '[' Linux '!=' Darwin ']' 0|mm | + tee 0|mm | ++ which chromium-browser 0|mm | + '[' /usr/bin/chromium-browser '!=' '' ']' 0|mm | + chromium-browser -noerrdialogs -kiosk -start_maximized --disable-infobars --app=http://localhost:8080 --ignore-certificate-errors-spki-list --ignore-ssl-errors --ignore-certificate-errors -
I’m seeing a discrepancy where on boot it’s collecting xorg= blank versus xorg=755 on a stop/start after boot.
