mythwelcome - does not shut down

For discussion of topics specific to MythTV on linux
Post Reply
Caudron100
Newcomer
Posts: 1
Joined: Fri Jan 03, 2020 3:04 am
Australia

mythwelcome - does not shut down

Post by Caudron100 »

I have installed a clean install of ubuntu 20.04 with mythtv 31 installed from Mythtv PPA. All working well including MythWeb. I have worked my way through getting Mythwelcome working as well, but only to a point.
I need help with setting up the prerequisites. My BIOS uses UTC and does not require a reboot after setting the time.
When I run Mythwelcome it appears to work correctly to the point of waiting to shutdown the Backend. Times for future recordings are displayed correctly.

Is there check list, somewhere that I have not found yet, to test the Shutdown setup completely?

Thanks in advance for any help.
Caudron
blm-ubunet
Senior
Posts: 265
Joined: Sun Jun 15, 2014 1:08 am
Cambodia

Re: mythwelcome - does not shut down

Post by blm-ubunet »

You could check the systemd logs to see if mythshutdown is being run.
journalctl -xe

or run the backend from terminal & watch the stdout..
User avatar
bill6502
Developer
Posts: 2307
Joined: Fri Feb 07, 2014 5:28 pm
United States of America

Re: mythwelcome - does not shut down

Post by bill6502 »

mythbackend --setverbose idle,system may help. That command is used to
increase logging on a running backend.
PhilB
Senior
Posts: 403
Joined: Sun May 11, 2014 6:23 pm
Great Britain

Re: mythwelcome - does not shut down

Post by PhilB »

I have the same problem.

Setup: AMD/Nvidia frontend/backend, stable with Ubuntu 14.04 and 0.27.
New SSD disk: Ubuntu 20.04, Myth 31 set up with MCC.
UK channel scanning, EIT, recording, playback are all ok but mythwelcome does not close down.

Logging added to Setwakup shows it is called every 30 secs but the system will not turn off.

If I replace the /usr/sbin/poweroff command in mythwelcome setup with a simple echo:
echo "poweroff" >> /home/phil/log it is not executed.
The poweroff works from a terminal session.

Mythwelcome seems VERY sluggish, despite the switch to SSD.

Log as suggested by Bill follows.
I am suspicious of the entry at 14:35:44. Those spurious characters are not present on the backend setup page, However, if I replace the mythshutdown --shutdown with a simple 'echo' it still appears (with the junk characters) in the log but it works.
I'd appreciate any views.
Phil

Code: Select all

Apr 12 14:34:12 myth mythbackend: mythbackend[8409]: I ProcessRequest mainserver.cpp:1768 (HandleAnnounce) MainServer: MainServer::ANN Monitor
Apr 12 14:34:12 myth mythbackend: mythbackend[8409]: I ProcessRequest mainserver.cpp:1770 (HandleAnnounce) MainServer: adding: myth(55d287a38b2
0) as a client (events: 1)
Apr 12 14:34:12 myth mythbackend: mythbackend[8409]: I MythSocketThread(58) mainserver.cpp:7858 (connectionClosed) Monitor sock(55d287a9c390) '
myth' disconnected
Apr 12 14:34:12 myth mythbackend: mythbackend[8409]: I MythSocketThread(129) mainserver.cpp:7858 (connectionClosed) Monitor sock(55d287a38b20) 
'myth' disconnected
Apr 12 14:34:12 myth mythbackend: mythbackend[8409]: I SystemManager mythsystemunix.cpp:335 (run) Managed child (PID: 8928) has exited! command
=mythshutdown --check, status=256, result=1
Apr 12 14:34:12 myth mythbackend: mythbackend[8409]: N Scheduler scheduler.cpp:3284 (CheckShutdownServer) CheckShutdownServer returned - Not OK
 to shutdown
Apr 12 14:34:14 myth mythbackend: mythbackend[8409]: I ProcessRequest mainserver.cpp:1768 (HandleAnnounce) MainServer: MainServer::ANN Playback
Apr 12 14:34:14 myth mythbackend: mythbackend[8409]: I ProcessRequest mainserver.cpp:1770 (HandleAnnounce) MainServer: adding: myth(55d2879f151
0) as a client (events: 0)
Apr 12 14:34:14 myth mythbackend: mythbackend[8409]: I ProcessRequest mainserver.cpp:1768 (HandleAnnounce) MainServer: MainServer::ANN Monitor
Apr 12 14:34:14 myth mythbackend: mythbackend[8409]: I ProcessRequest mainserver.cpp:1770 (HandleAnnounce) MainServer: adding: myth(55d287a817d
0) as a client (events: 1)
Apr 12 14:34:14 myth mythbackend: mythbackend[8409]: I MythSocketThread(58) mainserver.cpp:7858 (connectionClosed) Playback sock(55d2879f1510) 
'myth' disconnected
Apr 12 14:34:14 myth mythbackend: mythbackend[8409]: I MythSocketThread(129) mainserver.cpp:7858 (connectionClosed) Monitor sock(55d287a817d0) 
'myth' disconnected
Apr 12 14:34:27 myth mythbackend: mythbackend[8409]: I Scheduler mythsystemunix.cpp:934 (Fork) Managed child (PID: 8994) has started! * command
=mythshutdown --check, timeout=0
Apr 12 14:34:28 myth mythbackend: mythbackend[8409]: I ProcessRequest mainserver.cpp:1768 (HandleAnnounce) MainServer: MainServer::ANN Monitor
Apr 12 14:34:28 myth mythbackend: mythbackend[8409]: I ProcessRequest mainserver.cpp:1770 (HandleAnnounce) MainServer: adding: myth(55d287a817d
0) as a client (events: 0)
Apr 12 14:34:28 myth mythbackend: mythbackend[8409]: I ProcessRequest mainserver.cpp:1768 (HandleAnnounce) MainServer: MainServer::ANN Monitor
Apr 12 14:34:28 myth mythbackend: mythbackend[8409]: I ProcessRequest mainserver.cpp:1770 (HandleAnnounce) MainServer: adding: myth(55d287a38ba
0) as a client (events: 1)
Apr 12 14:34:29 myth mythbackend: mythbackend[8409]: I MythSocketThread(58) mainserver.cpp:7858 (connectionClosed) Monitor sock(55d287a817d0) '
myth' disconnected
Apr 12 14:34:29 myth mythbackend: mythbackend[8409]: I MythSocketThread(129) mainserver.cpp:7858 (connectionClosed) Monitor sock(55d287a38ba0) 
'myth' disconnected
Apr 12 14:34:29 myth mythbackend: mythbackend[8409]: I SystemManager mythsystemunix.cpp:335 (run) Managed child (PID: 8994) has exited! command
=mythshutdown --check, status=0, result=0
Apr 12 14:34:29 myth mythbackend: mythbackend[8409]: I Scheduler scheduler.cpp:3279 (CheckShutdownServer) CheckShutdownServer returned - OK to 
shutdown
Apr 12 14:34:29 myth mythbackend: mythbackend[8409]: N Scheduler scheduler.cpp:3219 (HandleIdleShutdown) I'm idle now... shutdown will occur in
 30 seconds.
Apr 12 14:34:34 myth mythbackend: mythbackend[8409]: N Scheduler scheduler.cpp:3228 (HandleIdleShutdown) 24 secs left to system shutdown!
Apr 12 14:34:39 myth mythbackend: mythbackend[8409]: N Scheduler scheduler.cpp:3228 (HandleIdleShutdown) 19 secs left to system shutdown!
Apr 12 14:34:44 myth mythbackend: mythbackend[8409]: N Scheduler scheduler.cpp:3228 (HandleIdleShutdown) 14 secs left to system shutdown!
Apr 12 14:34:49 myth mythbackend: mythbackend[8409]: N Scheduler scheduler.cpp:3228 (HandleIdleShutdown) 9 secs left to system shutdown!
Apr 12 14:34:50 myth mythbackend: mythbackend[8409]: N Scheduler scheduler.cpp:3228 (HandleIdleShutdown) 8 secs left to system shutdown!
Apr 12 14:34:51 myth mythbackend: mythbackend[8409]: N Scheduler scheduler.cpp:3228 (HandleIdleShutdown) 7 secs left to system shutdown!
Apr 12 14:34:52 myth mythbackend: mythbackend[8409]: N Scheduler scheduler.cpp:3228 (HandleIdleShutdown) 6 secs left to system shutdown!
Apr 12 14:34:53 myth mythbackend: mythbackend[8409]: N Scheduler scheduler.cpp:3228 (HandleIdleShutdown) 5 secs left to system shutdown!
Apr 12 14:34:54 myth mythbackend: mythbackend[8409]: N Scheduler scheduler.cpp:3228 (HandleIdleShutdown) 4 secs left to system shutdown!
Apr 12 14:34:55 myth mythbackend: mythbackend[8409]: N Scheduler scheduler.cpp:3228 (HandleIdleShutdown) 3 secs left to system shutdown!
Apr 12 14:34:56 myth mythbackend: mythbackend[8409]: N Scheduler scheduler.cpp:3228 (HandleIdleShutdown) 2 secs left to system shutdown!
Apr 12 14:34:57 myth mythbackend: mythbackend[8409]: N Scheduler scheduler.cpp:3228 (HandleIdleShutdown) 1 secs left to system shutdown!
Apr 12 14:34:58 myth mythbackend: mythbackend[8409]: I Scheduler mythsystemunix.cpp:934 (Fork) Managed child (PID: 9209) has started! * command
=mythshutdown --check, timeout=0
Apr 12 14:34:59 myth mythbackend: mythbackend[8409]: I ProcessRequest mainserver.cpp:1768 (HandleAnnounce) MainServer: MainServer::ANN Monitor
Apr 12 14:34:59 myth mythbackend: mythbackend[8409]: I ProcessRequest mainserver.cpp:1770 (HandleAnnounce) MainServer: adding: myth(55d287a38b2
0) as a client (events: 0)
Apr 12 14:34:59 myth mythbackend: mythbackend[8409]: I ProcessRequest mainserver.cpp:1768 (HandleAnnounce) MainServer: MainServer::ANN Monitor
Apr 12 14:34:59 myth mythbackend: mythbackend[8409]: I ProcessRequest mainserver.cpp:1770 (HandleAnnounce) MainServer: adding: myth(55d2879f10c
0) as a client (events: 1)
Apr 12 14:34:59 myth mythbackend: mythbackend[8409]: I MythSocketThread(58) mainserver.cpp:7858 (connectionClosed) Monitor sock(55d287a38b20) '
myth' disconnected
Apr 12 14:34:59 myth mythbackend: mythbackend[8409]: I MythSocketThread(129) mainserver.cpp:7858 (connectionClosed) Monitor sock(55d2879f10c0) 
'myth' disconnected
Apr 12 14:34:59 myth mythbackend: mythbackend[8409]: I SystemManager mythsystemunix.cpp:335 (run) Managed child (PID: 9209) has exited! command
=mythshutdown --check, status=0, result=0
Apr 12 14:34:59 myth mythbackend: mythbackend[8409]: I Scheduler scheduler.cpp:3279 (CheckShutdownServer) CheckShutdownServer returned - OK to 
shutdown
Apr 12 14:34:59 myth mythbackend: mythbackend[8409]: N Scheduler scheduler.cpp:3390 (ShutdownServer) Running the command to set the next schedu
led wakeup time :-#012#011#011#011#011mythshutdown --setwakeup 2021-04-12T20:07
Apr 12 14:34:59 myth mythbackend: mythbackend[8409]: I Scheduler mythsystemunix.cpp:934 (Fork) Managed child (PID: 9249) has started! * command
=mythshutdown --setwakeup 2021-04-12T20:07, timeout=0
Apr 12 14:35:01 myth mythbackend: mythbackend[8409]: I SystemManager mythsystemunix.cpp:335 (run) Managed child (PID: 9249) has exited! command
=mythshutdown --setwakeup 2021-04-12T20:07, status=0, result=0
Apr 12 14:35:01 myth mythbackend: mythbackend[8409]: N Scheduler scheduler.cpp:3421 (ShutdownServer) Running the command to shutdown this compu
ter :-#012#011#011#011#011mythshutdown --shutdown  
Apr 12 14:35:01 myth mythbackend: mythbackend[8409]: I Scheduler mythsystemunix.cpp:934 (Fork) Managed child (PID: 9273) has started! * command
=mythshutdown --shutdown, timeout=0
Apr 12 14:35:02 myth mythbackend: mythbackend[8409]: I SystemManager mythsystemunix.cpp:335 (run) Managed child (PID: 9273) has exited! command
=mythshutdown --shutdown, status=256, result=1
Apr 12 14:35:02 myth mythbackend: mythbackend[8409]: E Scheduler scheduler.cpp:3430 (ShutdownServer) ServerHaltCommand failed, shutdown aborted
Apr 12 14:35:10 myth mythbackend: mythbackend[8409]: I Scheduler mythsystemunix.cpp:934 (Fork) Managed child (PID: 9366) has started! * command
=mythshutdown --check, timeout=0
Apr 12 14:35:11 myth mythbackend: mythbackend[8409]: I ProcessRequest mainserver.cpp:1768 (HandleAnnounce) MainServer: MainServer::ANN Monitor
Apr 12 14:35:11 myth mythbackend: mythbackend[8409]: I ProcessRequest mainserver.cpp:1770 (HandleAnnounce) MainServer: adding: myth(55d287a9396
0) as a client (events: 0)
Apr 12 14:35:11 myth mythbackend: mythbackend[8409]: I ProcessRequest mainserver.cpp:1768 (HandleAnnounce) MainServer: MainServer::ANN Monitor
Apr 12 14:35:12 myth mythbackend: mythbackend[8409]: I ProcessRequest mainserver.cpp:1770 (HandleAnnounce) MainServer: adding: myth(55d287a22cf
0) as a client (events: 1)
Apr 12 14:35:12 myth mythbackend: mythbackend[8409]: I MythSocketThread(58) mainserver.cpp:7858 (connectionClosed) Monitor sock(55d287a93960) '
myth' disconnected
Apr 12 14:35:12 myth mythbackend: mythbackend[8409]: I MythSocketThread(129) mainserver.cpp:7858 (connectionClosed) Monitor sock(55d287a22cf0) 
'myth' disconnected
Apr 12 14:35:12 myth mythbackend: mythbackend[8409]: I SystemManager mythsystemunix.cpp:335 (run) Managed child (PID: 9366) has exited! command
=mythshutdown --check, status=0, result=0
Apr 12 14:35:12 myth mythbackend: mythbackend[8409]: I Scheduler scheduler.cpp:3279 (CheckShutdownServer) CheckShutdownServer returned - OK to 
shutdown
Apr 12 14:35:12 myth mythbackend: mythbackend[8409]: N Scheduler scheduler.cpp:3219 (HandleIdleShutdown) I'm idle now... shutdown will occur in
 30 seconds.
Apr 12 14:35:12 myth mythbackend: mythbackend[8409]: N Scheduler scheduler.cpp:3219 (HandleIdleShutdown) I'm idle now... shutdown will occur in
 30 seconds.
Apr 12 14:35:17 myth mythbackend: mythbackend[8409]: N Scheduler scheduler.cpp:3228 (HandleIdleShutdown) 24 secs left to system shutdown!
Apr 12 14:35:22 myth mythbackend: mythbackend[8409]: N Scheduler scheduler.cpp:3228 (HandleIdleShutdown) 19 secs left to system shutdown!
Apr 12 14:35:27 myth mythbackend: mythbackend[8409]: N Scheduler scheduler.cpp:3228 (HandleIdleShutdown) 14 secs left to system shutdown!
Apr 12 14:35:32 myth mythbackend: mythbackend[8409]: N Scheduler scheduler.cpp:3228 (HandleIdleShutdown) 9 secs left to system shutdown!
Apr 12 14:35:33 myth mythbackend: mythbackend[8409]: N Scheduler scheduler.cpp:3228 (HandleIdleShutdown) 8 secs left to system shutdown!
Apr 12 14:35:34 myth mythbackend: mythbackend[8409]: N Scheduler scheduler.cpp:3228 (HandleIdleShutdown) 7 secs left to system shutdown!
Apr 12 14:35:35 myth mythbackend: mythbackend[8409]: N Scheduler scheduler.cpp:3228 (HandleIdleShutdown) 6 secs left to system shutdown!
Apr 12 14:35:36 myth mythbackend: mythbackend[8409]: N Scheduler scheduler.cpp:3228 (HandleIdleShutdown) 5 secs left to system shutdown!
Apr 12 14:35:37 myth mythbackend: mythbackend[8409]: N Scheduler scheduler.cpp:3228 (HandleIdleShutdown) 4 secs left to system shutdown!
Apr 12 14:35:38 myth mythbackend: mythbackend[8409]: N Scheduler scheduler.cpp:3228 (HandleIdleShutdown) 3 secs left to system shutdown!
Apr 12 14:35:39 myth mythbackend: mythbackend[8409]: N Scheduler scheduler.cpp:3228 (HandleIdleShutdown) 2 secs left to system shutdown!
Apr 12 14:35:40 myth mythbackend: mythbackend[8409]: N Scheduler scheduler.cpp:3228 (HandleIdleShutdown) 1 secs left to system shutdown!
Apr 12 14:35:41 myth mythbackend: mythbackend[8409]: I Scheduler mythsystemunix.cpp:934 (Fork) Managed child (PID: 9577) has started! * command
=mythshutdown --check, timeout=0
Apr 12 14:35:42 myth mythbackend: mythbackend[8409]: I ProcessRequest mainserver.cpp:1768 (HandleAnnounce) MainServer: MainServer::ANN Monitor
Apr 12 14:35:42 myth mythbackend: mythbackend[8409]: I ProcessRequest mainserver.cpp:1770 (HandleAnnounce) MainServer: adding: myth(55d2879f10c
0) as a client (events: 0)
Apr 12 14:35:42 myth mythbackend: mythbackend[8409]: I ProcessRequest mainserver.cpp:1768 (HandleAnnounce) MainServer: MainServer::ANN Monitor
Apr 12 14:35:42 myth mythbackend: mythbackend[8409]: I ProcessRequest mainserver.cpp:1770 (HandleAnnounce) MainServer: adding: myth(55d287a38ba
0) as a client (events: 1)
Apr 12 14:35:42 myth mythbackend: mythbackend[8409]: I MythSocketThread(58) mainserver.cpp:7858 (connectionClosed) Monitor sock(55d2879f10c0) '
myth' disconnected
Apr 12 14:35:42 myth mythbackend: mythbackend[8409]: I MythSocketThread(129) mainserver.cpp:7858 (connectionClosed) Monitor sock(55d287a38ba0) 
'myth' disconnected
Apr 12 14:35:42 myth mythbackend: mythbackend[8409]: I SystemManager mythsystemunix.cpp:335 (run) Managed child (PID: 9577) has exited! command
=mythshutdown --check, status=0, result=0
Apr 12 14:35:42 myth mythbackend: mythbackend[8409]: I Scheduler scheduler.cpp:3279 (CheckShutdownServer) CheckShutdownServer returned - OK to 
shutdown
Apr 12 14:35:42 myth mythbackend: mythbackend[8409]: N Scheduler scheduler.cpp:3390 (ShutdownServer) Running the command to set the next schedu
led wakeup time :-#012#011#011#011#011mythshutdown --setwakeup 2021-04-12T20:07
Apr 12 14:35:42 myth mythbackend: mythbackend[8409]: I Scheduler mythsystemunix.cpp:934 (Fork) Managed child (PID: 9617) has started! * command
=mythshutdown --setwakeup 2021-04-12T20:07, timeout=0
Apr 12 14:35:44 myth mythbackend: mythbackend[8409]: I SystemManager mythsystemunix.cpp:335 (run) Managed child (PID: 9617) has exited! command
=mythshutdown --setwakeup 2021-04-12T20:07, status=0, result=0
Apr 12 14:35:44 myth mythbackend: mythbackend[8409]: N Scheduler scheduler.cpp:3421 (ShutdownServer) Running the command to shutdown this compu
ter :-#012#011#011#011#011mythshutdown --shutdown  
Apr 12 14:35:44 myth mythbackend: mythbackend[8409]: I Scheduler mythsystemunix.cpp:934 (Fork) Managed child (PID: 9641) has started! * command
=mythshutdown --shutdown, timeout=0
Apr 12 14:35:45 myth mythbackend: mythbackend[8409]: I SystemManager mythsystemunix.cpp:335 (run) Managed child (PID: 9641) has exited! command
=mythshutdown --shutdown, status=256, result=1
Apr 12 14:35:45 myth mythbackend: mythbackend[8409]: E Scheduler scheduler.cpp:3430 (ShutdownServer) ServerHaltCommand failed, shutdown aborted
Apr 12 14:36:00 myth mythbackend: mythbackend[8409]: I Scheduler mythsystemunix.cpp:934 (Fork) Managed child (PID: 9731) has started! * command
=mythshutdown --check, timeout=0
Apr 12 14:36:02 myth mythbackend: mythbackend[8409]: I ProcessRequest mainserver.cpp:1768 (HandleAnnounce) MainServer: MainServer::ANN Monitor
Apr 12 14:36:02 myth mythbackend: mythbackend[8409]: I ProcessRequest mainserver.cpp:1770 (HandleAnnounce) MainServer: adding: myth(55d287a22cf
0) as a client (events: 0)
Apr 12 14:36:02 myth mythbackend: mythbackend[8409]: I ProcessRequest mainserver.cpp:1768 (HandleAnnounce) MainServer: MainServer::ANN Monitor
Apr 12 14:36:02 myth mythbackend: mythbackend[8409]: I ProcessRequest mainserver.cpp:1770 (HandleAnnounce) MainServer: adding: myth(55d287a4b90
0) as a client (events: 1)
Apr 12 14:36:02 myth mythbackend: mythbackend[8409]: I MythSocketThread(58) mainserver.cpp:7858 (connectionClosed) Monitor sock(55d287a22cf0) '
myth' disconnected
Apr 12 14:36:02 myth mythbackend: mythbackend[8409]: I MythSocketThread(129) mainserver.cpp:7858 (connectionClosed) Monitor sock(55d287a4b900) 
'myth' disconnected
Apr 12 14:36:02 myth mythbackend: mythbackend[8409]: I SystemManager mythsystemunix.cpp:335 (run) Managed child (PID: 9731) has exited! command
=mythshutdown --check, status=0, result=0
Apr 12 14:36:02 myth mythbackend: mythbackend[8409]: I Scheduler scheduler.cpp:3279 (CheckShutdownServer) CheckShutdownServer returned - OK to 
shutdown
Apr 12 14:36:02 myth mythbackend: mythbackend[8409]: N Scheduler scheduler.cpp:3219 (HandleIdleShutdown) I'm idle now... shutdown will occur in
 30 seconds.
Apr 12 14:36:07 myth mythbackend: mythbackend[8409]: N Scheduler scheduler.cpp:3228 (HandleIdleShutdown) 24 secs left to system shutdown!
User avatar
bill6502
Developer
Posts: 2307
Joined: Fri Feb 07, 2014 5:28 pm
United States of America

Re: mythwelcome - does not shut down

Post by bill6502 »

Hey Phil, with the same backend logging, can you see anything in mythshutdown.log?

Of interest (to me) is from mythshutdown/main.cpp: the setting MythShutdownNvramCmd" defaults to: "/usr/bin/nvram-wakeup --settime $time"
but I don't use mythshutdown, rather my ServerHaltCommand in settings is set to /bin/systemctl poweroff --message="MythTV Backend Idle Shutdown"

/usr/bin/nvram-wakeup doesn't exist on my *buntu 18.04 and 20.04 hosts.

The #012#011#011#011#011 characters (if that's what you're referring to) are just line feed
and 4 tabs, converted by rsyslog to the #control-character format.
PhilB
Senior
Posts: 403
Joined: Sun May 11, 2014 6:23 pm
Great Britain

Re: mythwelcome - does not shut down

Post by PhilB »

Thanks for the very prompt reply - puts me to shame.
I put a --logpath on the mythshutdown --shutdown setting.
That told me two things:
a) --shutdown calls --setwakeup. I did not know that!
b) I did not have permissions on rtc. fixed and setwakeup.sh is now returning zero. That allowed further progress:

The mythshutdown log now shows more optimism:
2021-04-12 18:09:41.242123 E [23022/23022] CoreContext main.cpp:546 (shutdown) - Error: no daily wakeup times are set

2021-04-12 18:09:41.244839 E [23022/23022] CoreContext main.cpp:565 (shutdown) - Recording scheduled at: 20:07

2021-04-12 18:09:41.245346 E [23022/23022] CoreContext main.cpp:606 (shutdown) - Will wake up at next scheduled program

2021-04-12 18:09:41.252221 E [23022/23022] CoreContext main.cpp:688 (shutdown) - Sending command to set time in BIOS /usr/bin/setwakeup.sh 1618254420

2021-04-12 18:09:41.306119 E [23022/23022] CoreContext main.cpp:695 (shutdown) - Program /usr/bin/setwakeup.sh 1618254420 exited with code 0

2021-04-12 18:09:41.307004 E [23022/23022] CoreContext main.cpp:745 (shutdown) - Everything looks fine, but reboot is needed

2021-04-12 18:09:41.307783 E [23022/23022] CoreContext main.cpp:748 (shutdown) - Sending command to bootloader ...

2021-04-12 18:09:41.308101 E [23022/23022] CoreContext main.cpp:751 (shutdown) - #
2021-04-12 18:09:41.356388 E [23022/23022] CoreContext main.cpp:755 (shutdown) - ..
.
rebooting ...
I'll try to assimilate your reply and do more checking - I'll tie up one of these shutdown logs (there are hundreds) with the mythwelcome log once I can get access again.

A few questions meanwhile:
1. I have an ACP system, not an NVRAM one. Am I right in thinking that I leave all the nvram settings blank?
2. I note what I think is a documentation error in mythshutdown --status. I think it should say 256 (not 255) = setup is running.
Do you concur with that?

Regards and thanks again.
Phil
User avatar
bill6502
Developer
Posts: 2307
Joined: Fri Feb 07, 2014 5:28 pm
United States of America

Re: mythwelcome - does not shut down

Post by bill6502 »

Don't know about #1. For #2, 255 is what I get. But, the bits are additive,
256 implies setup + transcoding, although that seems to be a big coincidence.
See if mythshutdown --help status helps.
PhilB
Senior
Posts: 403
Joined: Sun May 11, 2014 6:23 pm
Great Britain

Re: mythwelcome - does not shut down

Post by PhilB »

mythshutdown --help also shows 255 not 256.
Phil
User avatar
bill6502
Developer
Posts: 2307
Joined: Fri Feb 07, 2014 5:28 pm
United States of America

Re: mythwelcome - does not shut down

Post by bill6502 »

Hi,

I'm missing the 'documentation error in mythshutdown --status' question, this is what I see

Code: Select all

$ mythshutdown --help status
...
              returns 0 - Idle
...
                    255 - Setup is running
$ mythshutdown --status ; echo $? # and mythtv-setup is running on this host
Setup is running...
255
Where is the 256 documentation that's in error?
mtvf2894
Junior
Posts: 81
Joined: Sat Apr 10, 2021 2:33 pm
Great Britain

Re: mythwelcome - does not shut down

Post by mtvf2894 »

Caudron100 wrote:
Wed Nov 18, 2020 3:03 am
Is there check list, somewhere that I have not found yet, to test the Shutdown setup completely?
Can you provide any details on if you have prefixed the commands in setup with sudo, have you added anything to your sudoers file, whether you are running a pre shutdown check script and whether the immediate shutdown option in the Mythwelcome menu works?

Everything seems to work as expected for me apart from:

Welcome "nvram-wakeup Restart Command" option make sure this is blank as it keeps getting set to an unwanted command whenever you go back into the screen

Backend "Block shutdown before client connected" option is ignored so if I manually switch on I need to remember to lock otherwise it automatically shuts off again after the idle countdown.

I suspect it is a permissions problem or a typo somewhere. That was what was causing me problems.
Current: v32 now v33.1 / Lubuntu 22.04 / AMD APU
Previous: v31 / Lubuntu 20.10 / AMD APU
Historic: Mythbuntu / NVIDIA GFX
PhilB
Senior
Posts: 403
Joined: Sun May 11, 2014 6:23 pm
Great Britain

Re: mythwelcome - does not shut down

Post by PhilB »

Sorry - I am wrong about the mythshutdown -s - it does return 255 if setup is running!

If I use the mythwelcome shutdown now option everything freezes - needs a power off at the main switch and power on again.
The /usr/sbin/poweroff works from a terminal- no sudo needed, and that is set in the shutdown field on welcome/F11 page.

That logging 'mythbackend --setverbose idle,system' shows this as it is starting up. Don't know if it is relevant:
2021-04-14 14:38:49.845839 N Reading locale defaults from /usr/share/mythtv//locales/en_gb.xml
2021-04-14 14:38:49.894110 I PowerDBus: Failed to delay sleep,shutdown: Permission denied
2021-04-14 14:38:49.998280 I Power: On AC power
If I invoke extra logging by replacing the shutdown string with:
mythshutdown --shutdown --logpath /home/phil/logging
then I learn that the setwakeup.sh script fails:
2021-04-14 12:48:01.222569 E [2102/2102] CoreContext main.cpp:546 (shutdown) - Error: no daily wakeup times are set
2021-04-14 12:48:01.225316 E [2102/2102] CoreContext main.cpp:565 (shutdown) - Recording scheduled at: 11:28
2021-04-14 12:48:01.225695 E [2102/2102] CoreContext main.cpp:606 (shutdown) - Will wake up at next scheduled program
2021-04-14 12:48:01.231939 E [2102/2102] CoreContext main.cpp:688 (shutdown) - Sending command to set time in BIOS /usr/bin/setwakeup.sh 1618482480
2021-04-14 12:48:01.283144 E [2102/2102] CoreContext main.cpp:695 (shutdown) - Program /usr/bin/setwakeup.sh 1618482480 exited with code 2
2021-04-14 12:48:01.283862 E [2102/2102] CoreContext main.cpp:701 (shutdown) - Error: nvram-wakeup failed to set time in BIOS
Extra tracing in setwakeup.sh pointed to lack of permissions for /sys/class/rtc/rtc0/wakealarm.

If I sudo it then the shutdown log is not produced but the backend log shows:
Apr 14 12:39:14 myth mythbackend: mythbackend[1505]: I SystemManager mythsystemunix.cpp:335 (run) Managed child (PID: 8741) has exited! command
=mythshutdown --check, status=0, result=0
Apr 14 12:39:14 myth mythbackend: mythbackend[1505]: I Scheduler scheduler.cpp:3279 (CheckShutdownServer) CheckShutdownServer returned - OK to
shutdown
Apr 14 12:39:14 myth mythbackend: mythbackend[1505]: N Scheduler scheduler.cpp:3390 (ShutdownServer) Running the command to set the next schedu
led wakeup time :-#012#011#011#011#011sudo mythshutdown --setwakeup 2021-04-15T11:28
Apr 14 12:39:14 myth mythbackend: mythbackend[1505]: I Scheduler mythsystemunix.cpp:934 (Fork) Managed child (PID: 8781) has started! * command
=sudo mythshutdown --setwakeup 2021-04-15T11:28, timeout=0
Apr 14 12:39:14 myth mythbackend: mythbackend[1505]: I SystemManager mythsystemunix.cpp:335 (run) Managed child (PID: 8781) has exited! command
=sudo mythshutdown --setwakeup 2021-04-15T11:28, status=256, result=1
Apr 14 12:39:14 myth mythbackend: mythbackend[1505]: E Scheduler scheduler.cpp:3397 (ShutdownServer) SetWakeuptimeCommand failed, shutdown abor
ted
If instead I chmod 666 /sys/class/rtc/rtc0/wakealarm then it gives a shutdown log and gets further:
2021-04-14 12:48:51.466168 E [2175/2175] CoreContext main.cpp:546 (shutdown) - Error: no daily wakeup times are set
2021-04-14 12:48:51.469094 E [2175/2175] CoreContext main.cpp:565 (shutdown) - Recording scheduled at: 11:28
2021-04-14 12:48:51.469497 E [2175/2175] CoreContext main.cpp:606 (shutdown) - Will wake up at next scheduled program
2021-04-14 12:48:51.476522 E [2175/2175] CoreContext main.cpp:688 (shutdown) - Sending command to set time in BIOS /usr/bin/setwakeup.sh 1618482480
2021-04-14 12:48:51.529920 E [2175/2175] CoreContext main.cpp:695 (shutdown) - Program /usr/bin/setwakeup.sh 1618482480 exited with code 0
2021-04-14 12:48:51.530669 E [2175/2175] CoreContext main.cpp:745 (shutdown) - Everything looks fine, but reboot is needed
2021-04-14 12:48:51.530883 E [2175/2175] CoreContext main.cpp:748 (shutdown) - Sending command to bootloader ...
2021-04-14 12:48:51.531019 E [2175/2175] CoreContext main.cpp:751 (shutdown) - #nvramrestart
2021-04-14 12:48:51.580128 E [2175/2175] CoreContext main.cps:755 (shutdown) - ..
.
rebooting ...
Unfortunately, those permissions reset to 644 on next boot up.

That #nvramrestart is not the expected shutdown command; it's the content of the 'nvram -wakeup restart command' in F11 of Mythwelcome.
I don't know why it is trying to reboot rather than doing an ACP powering off (and I don't understand why both are there) but if I change it to /usr/sbin/poweroff
then it still won't shut off. The shutdown log shows:
2021-04-14 14:46:21.692016 E [3324/3324] CoreContext main.cpp:546 (shutdown) - Error: no daily wakeup times are set
2021-04-14 14:46:21.695078 E [3324/3324] CoreContext main.cpp:565 (shutdown) - Recording scheduled at: 11:28
2021-04-14 14:46:21.695329 E [3324/3324] CoreContext main.cpp:606 (shutdown) - Will wake up at next scheduled program
2021-04-14 14:46:21.702097 E [3324/3324] CoreContext main.cpp:688 (shutdown) - Sending command to set time in BIOS /usr/bin/setwakeup.sh 1618482480
2021-04-14 14:46:21.753462 E [3324/3324] CoreContext main.cpp:695 (shutdown) - Program /usr/bin/setwakeup.sh 1618482480 exited with code 0
2021-04-14 14:46:21.753924 E [3324/3324] CoreContext main.cpp:745 (shutdown) - Everything looks fine, but reboot is needed
2021-04-14 14:46:21.754155 E [3324/3324] CoreContext main.cpp:748 (shutdown) - Sending command to bootloader ...
2021-04-14 14:46:21.754712 E [3324/3324] CoreContext main.cpp:751 (shutdown) - /usr/sbin/poweroff
2021-04-14 14:46:21.853602 E [3324/3324] CoreContext main.cpp:755 (shutdown) - ..
.
rebooting ...
The backend log shows this:
Apr 14 14:46:19 myth mythbackend: mythbackend[1504]: I Scheduler scheduler.cpp:3279 (CheckShutdownServer) CheckShutdownServer returned - OK to shutdown
Apr 14 14:46:19 myth mythbackend: mythbackend[1504]: N Scheduler scheduler.cpp:3390 (ShutdownServer) Running the command to set the next scheduled wakeup time :-#012#011#011#011#011mythshutdown --setwakeup 2021-04-15T11:28
Apr 14 14:46:19 myth mythbackend: mythbackend[1504]: I Scheduler mythsystemunix.cpp:934 (Fork) Managed child (PID: 3299) has started! * command=mythshutdown --setwakeup 2021-04-15T11:28, timeout=0
Apr 14 14:46:20 myth mythbackend: mythbackend[1504]: I SystemManager mythsystemunix.cpp:335 (run) Managed child (PID: 3299) has exited! command=mythshutdown --setwakeup 2021-04-15T11:28, status=0, result=0
Apr 14 14:46:20 myth mythbackend: mythbackend[1504]: N Scheduler scheduler.cpp:3421 (ShutdownServer) Running the command to shutdown this computer :-#012#011#011#011#011mythshutdown --shutdown --logpath /home/phil/logging
Apr 14 14:46:20 myth mythbackend: mythbackend[1504]: I Scheduler mythsystemunix.cpp:934 (Fork) Managed child (PID: 3323) has started! * command=mythshutdown --shutdown --logpath /home/phil/logging, timeout=0
Apr 14 14:46:22 myth mythbackend: mythbackend[1504]: I SystemManager mythsystemunix.cpp:335 (run) Managed child (PID: 3323) has exited! command=mythshutdown --shutdown --logpath /home/phil/logging, status=0, result=0
Apr 14 14:46:37 myth mythbackend: mythbackend[1504]: I Scheduler mythsystemunix.cpp:934 (Fork) Managed child (PID: 3389) has started! * command=mythshutdown --check, timeout=0
Apr 14 14:46:38 myth mythbackend: mythbackend[1504]: I ProcessRequest mainserver.cpp:1768 (HandleAnnounce) MainServer: MainServer::ANN Monitor
Apr 14 14:46:38 myth mythbackend: mythbackend[1504]: I ProcessRequest mainserver.cpp:1770 (HandleAnnounce) MainServer: adding: myth(5588e6eae590) as a client (events: 0)
Apr 14 14:46:38 myth mythbackend: mythbackend[1504]: I ProcessRequest mainserver.cpp:1768 (HandleAnnounce) MainServer: MainServer::ANN Monitor
Apr 14 14:46:38 myth mythbackend: mythbackend[1504]: I ProcessRequest mainserver.cpp:1770 (HandleAnnounce) MainServer: adding: myth(5588e6e1dfe0) as a client (events: 1)
So, I think I have two problems:
1. Fix permissions on wakealarm.
2. Understanding why it is trying to reboot/restart rather than shutdown and why that does not work anyway.

I also seem to have lost my mouse cursor once welcome starts - I recall ticking an option somewhere to hide it during playback but I can't remember where!

Phil
gedakc
Junior
Posts: 96
Joined: Fri Jul 18, 2014 1:28 am
Canada

Re: mythwelcome - does not shut down

Post by gedakc »

One thing to check is that the nvram-wakeup Restart command is blank / empty. I ran into problems with autostart/shutdown when an space character somehow appeared in that field. With the space character being invisible it was very difficult to track down.

EDIT: Note that years ago I wrote some documentation if it helps with ideas to try.
Configuring MythTV Automatic Wakeup and Shutdown (with Mythbuntu 14.04 and MythTV 0.27)
PhilB
Senior
Posts: 403
Joined: Sun May 11, 2014 6:23 pm
Great Britain

Re: mythwelcome - does not shut down

Post by PhilB »

Many thanks - fixed now. Very useful notes.
That nvram-wakeup Restart command was one issue - I had it set to a comment, never imagining that it would then be invoked in preference to the backend closedown command!
sudos and permissions also needed fixing - but not without a little drama - creating a file /etc/sudoers.d/mythtv froze sudo completely - had to USB connect the drive to my laptop to remove it!

On to the next steps!

Thanks again.
Phil
mtvf2894
Junior
Posts: 81
Joined: Sat Apr 10, 2021 2:33 pm
Great Britain

Re: mythwelcome - does not shut down

Post by mtvf2894 »

PhilB wrote:
Fri Apr 16, 2021 1:35 pm
Many thanks - fixed now. Very useful notes. That nvram-wakeup Restart command was one issue - I had it set to a comment, never imagining that it would then be invoked in preference to the backend closedown command! sudos and permissions also needed fixing - but not without a little drama - creating a file /etc/sudoers.d/mythtv froze sudo completely - had to USB connect the drive to my laptop to remove it!
Glad you got it working.

As noted above I do think there is something not quite working as expected with the nvram-wakeup restart command until you realise this you can go around in circles for hours - I certainly did.
Current: v32 now v33.1 / Lubuntu 22.04 / AMD APU
Previous: v31 / Lubuntu 20.10 / AMD APU
Historic: Mythbuntu / NVIDIA GFX
Post Reply