A New Chapter for MagicMirror: The Community Takes the Lead
Read the statement by Michael Teeuw here.
Read the statement by Michael Teeuw here.
Autostarts but doesn't run, will run on restart
-
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.
-
@ember1205 yes… I see that too…
-
It almost seems like the X desktop isn’t fully initialized when the pgrep command executes and it isn’t collecting info on the process as a result. The restart NEVER happens until X is fully initialized which means that it -can- collect info on the process from a restart or stop/start.
-
@ember1205 yes. I am looking for a resolution…
-
I just edited the run-start.sh script and inserted a ten second sleep before the pgrep command. It’s a bit “extreme”, but should hopefully demonstrate if that’s the issue.
WIthout the sleep, not detecting X simply moves on to a different test instead of trying again at least once before moving on.
-
@ember1205 yes, adding a sleep would ‘fix’ it
if only we knew how LONG to sleep… working on it…
if X is not running then we just launch serveronly and don’t look at its output
