Page MenuHomePhabricator

Misleading message on "reboot at" command
Open, Requires assessmentPublicBUG

Description

vyos@vyos:~$ reboot at 04:00
Shutdown Ischeduled for Wed 2019-11-27 04:00:00 CET

It indicates that system would shutdown and not reboot. It actually reboots but the message is missleading.

Details

Difficulty level
Unknown (require assessment)
Version
1.2.3
Why the issue appeared?
Will be filled on close
Is it a breaking change?
Perfectly compatible

Event Timeline

c-po created this task.Tue, Nov 26, 9:56 PM
Dmitry added a subscriber: Dmitry.Tue, Nov 26, 10:01 PM

If we cancel reboot, it also write about shutdown.

vyos@vyos# run reboot cancel 
Broadcast message from root@vyos (Tue 2019-11-26 21:59:38 UTC):
The system shutdown has been cancelled at Tue 2019-11-26 22:00:38 UTC!
pasik added a subscriber: pasik.Wed, Nov 27, 6:20 PM

If we replace string 108 in file /usr/libexec/vyos/op_mode/powerctrl.py

- print(cmd.decode().split(",",1)[0])
+ check_shutdown()

We'll get.

vyos@1.2-roll-ns:~$ reboot at 04:00
Shutting down at Tue 2019-12-03 04:00:00 UTC (reboot)...

Is this output suitable for the first part of the problem?

c-po added a comment.EditedMon, Dec 2, 7:53 PM

That is definately much better then before. But it doe not fix the second problem.

vyos@vyosI:~$ reboot cancel

Broadcast message from root@LR2.wueIII (Mon 2019-12-02 20:54:59 CET):

The system shutdown has been cancelled at Mon 2019-12-02 20:55:59 CET!
cat /opt/vyatta/share/vyatta-op/templates/reboot/node.def
help: Reboot the system
run: sudo ${vyos_op_scripts_dir}/powerctrl.py --reboot

# cat /opt/vyatta/share/vyatta-op/templates/show/reboot/node.def
help: Show scheduled reboot
run: sudo /opt/vyatta/bin/sudo-users/vyatta-reboot.pl --action show_reboot

ref https://phabricator.vyos.net/T870

Viacheslav added a comment.EditedWed, Dec 4, 9:31 AM

PR https://github.com/vyos/vyos-1x/pull/173

$ reboot at 04:00
Shutting down at Thu 2019-12-05 04:00:00 UTC (reboot)...

$ reboot cancel
                                                                               
Broadcast message from vyos@1.2-roll-ns (pts/0) (Wed Dec  4 09:55:56 2019):    
                                                                               
Reboot scheduled has been cancelled 2019-12-04 09:55:56
                     

It work for 1.2 version (used systemd-shutdownd.service).
For 1.3 some bug with:

#sudo systemctl status systemd-shutdownd.service
Unit systemd-shutdownd.service could not be found.

Ref https://phabricator.vyos.net/T1842

Viacheslav added a comment.EditedThu, Dec 5, 10:50 AM

Bug in latest rolling

vyos@roll-1.2-ns:~$ sh version 
Version:          VyOS 1.2-rolling-201912050217

vyos@roll-1.2-ns:~$ reboot at 04:00
Traceback (most recent call last):
  File "/usr/libexec/vyos/op_mode/powerctrl.py", line 166, in <module>
    main()
  File "/usr/libexec/vyos/op_mode/powerctrl.py", line 154, in main
    execute_shutdown(args.reboot, reboot=True, ask=args.yes)
  File "/usr/libexec/vyos/op_mode/powerctrl.py", line 112, in execute_shutdown
    check_shutdown()
  File "/usr/libexec/vyos/op_mode/powerctrl.py", line 55, in check_shutdown
    r = re.findall(r'Status: \"(.*)\"\n', cmd.decode())[0]
IndexError: list index out of range
vyos@roll-1.2-ns:~$
vyos@roll-1.2-ns:~$ sudo systemctl status systemd-shutdownd.service
● systemd-shutdownd.service - Delayed Shutdown Service
   Loaded: loaded (/lib/systemd/system/systemd-shutdownd.service; static)
   Active: active (running) since Thu 2019-12-05 10:46:18 UTC; 5min ago
     Docs: man:systemd-shutdownd.service(8)
 Main PID: 2336 (systemd-shutdow)
   Status: "Shutting down at Fri 2019-12-06 04:00:00 UTC (reboot)..."
   CGroup: /system.slice/systemd-shutdownd.service
           └─2336 /lib/systemd/systemd-shutdownd

Dec 05 10:46:18 roll-1.2-ns systemd[1]: Starting Delayed Shutdown Service...
Dec 05 10:46:18 roll-1.2-ns systemd[1]: Started Delayed Shutdown Service.
Dec 05 10:46:18 roll-1.2-ns systemd-shutdownd[2336]: Shutting down at Fri 2019-12-06 04:00:00 UTC (reboot)...`

https://github.com/vyos/vyos-1x/pull/173/files#diff-cca0174eed4e987206a4ec872069a5ddL108

Wrong logic.
Need to return line 108 code

print (cmd.decode (). split (",", 1) [0])

And delete 112

check_shutdown()

/usr/libexec/vyos/op_mode/powerctrl.py

#check_shutdown()
print(cmd.decode().split(",",1)[0])

The problem described in the first message will not be resolved.

vyos@1.2-roll-ns:~$ reboot at 04:00
Shutdown scheduled for Fri 2019-12-06 04:00:00 UTC
vyos@1.2-roll-ns:~$ 
vyos@1.2-roll-ns:~$ reboot cancel
                                                                               
Broadcast message from vyos@1.2-roll-ns (pts/0) (Thu Dec  5 11:25:40 2019):    
                                                                               
Reboot scheduled has been cancelled 2019-12-05 11:25:40
                                                                               
vyos@1.2-roll-ns:~$
dmbaturin renamed this task from Missleading message on "reboot at" command to Misleading message on "reboot at" command.Thu, Dec 5, 10:43 PM

The runtime errors are fixed by the above commit.

As of the cancel message, looks like there's no way to get the event type (reboot or shutdown) information reliably. Immediately after systemd service startup, it's unavailable as runtime errors found by @Viacheslav show. Moreover, sometimes the "Status" line is available but the content is "Processing requests".
We could try to parse the output with a regex and issue a generic or specific message, but no one promises the format of that message is stable.

I think a generic message is best we can do.