How to find out from the logs what caused system shutdown?

Question

E.g. I'm seeing this in /var/log/messages:

Mar 01 23:12:34 hostname shutdown: shutting down for system halt

Is there a way to find out what caused the shutdown? E.g. was it run from console, or someone hit power button, etc.?

Solution 1

Only root privileged programs can gracefully shutdown a system. So when a system shuts down in a normal way, it is either a user with root privileges or an acpi script. In both cases you can find out by checking the logs. An acpi shutdown can be caused by power button press, overheating or low battery (laptop). I forgot the third reason, UPS software when power supply fails, which will send an alert anyway.

Recently I had a system that started repeatedly to power off ungracefully, turned out that it was overheating and the mobo was configured to just power off early. The system didn't have a chance to save logs, but fortunately monitoring the system's temperature showed it was starting to increase just before powering off.

So if it is a normal shutdown it will be logged, if it is an intrusion... good luck, and if it is a cold shutdown your best chance to know is to control and monitor its environment.

Solution 2

Try the following commands:

Display list of last reboot entries: last reboot | less

Display list of last shutdown entries: last -x | less

or more precisely: last -x | grep shutdown | less

You won't know who did it however. If you want to know who did it, you will need to add a bit of code which means you'll know next time.

I've found this resource online. It might be useful to you:

How to find out who or what halted my system

Solution 3

TLDR

last -x | head | tac

grep -iv ': starting\|kernel: .*: Power Button\|watching system buttons\|Stopped Cleaning Up\|Started Crash recovery kernel' \
  /var/log/messages /var/log/syslog /var/log/apcupsd* \
  | grep -iw 'recover[a-z]*\|power[a-z]*\|shut[a-z ]*down\|rsyslogd\|ups'

1) Regarding the output of last -x command

Run this command* and compare the output to the examples below:

last -x | head | tac

Normal shutdown examples

A normal shutdown and power-up looks like this (note that you have a shutdown event and then a system boot event):

runlevel (to lvl 0)   2.6.32- Sat Mar 17 08:48 - 08:51  (00:02) 
shutdown system down  ... <-- first the system shuts down   
reboot   system boot  ... <-- afterwards the system boots
runlevel (to lvl 3)       

In some cases you may see this (note that there is no line about the shutdown but the system was at runlevel 0 which is the "halt state"):

runlevel (to lvl 0)   ... <-- first the system shuts down (init level 0)
reboot   system boot  ... <-- afterwards the system boots
runlevel (to lvl 2)   2.6.24-... Fri Aug 10 15:58 - 15:32 (2+23:34)   

Unexpected shutdown examples

An unexpected shutdown from power loss looks like this (note that you have a system boot event without a prior system shutdown event):

runlevel (to lvl 3)   ... <-- the system was running since this momemnt
reboot   system boot  ... <-- then we've a boot WITHOUT a prior shutdown
runlevel (to lvl 3)   3.10.0-693.21.1. Sun Jun 17 15:40 - 09:51  (18:11)    

2) Regarding the logs in /var/log/

A bash command to filter the most interesting log messages is this:

grep -iv ': starting\|kernel: .*: Power Button\|watching system buttons\|Stopped Cleaning Up\|Started Crash recovery kernel' \
  /var/log/messages /var/log/syslog /var/log/apcupsd* \
  | grep -iw 'recover[a-z]*\|power[a-z]*\|shut[a-z ]*down\|rsyslogd\|ups'

When an unexpected power off or hardware failure occurs the filesystems will not be properly unmounted so in the next boot you may get logs like this:

EXT4-fs ... INFO: recovery required ... 
Starting XFS recovery filesystem ...
systemd-fsck: ... recovering journal
systemd-journald: File /var/log/journal/.../system.journal corrupted or uncleanly shut down, renaming and replacing.

When the system powers off because user pressed the power button you get logs like this:

systemd-logind: Power key pressed.
systemd-logind: Powering Off...
systemd-logind: System is powering down.

Only when the system shuts down orderly you get logs like this:

rsyslogd: ... exiting on signal 15

When the system shuts down due to overheating you get logs like this:

critical temperature reached...,shutting down

If you have a UPS and running a daemon to monitor power and shutdown you should obviously check its logs (NUT logs on /var/log/messages but apcupsd logs on /var/log/apcupsd*)

---

Notes

*: Here's the description of last from its man page:

last [...] prints information about connect times of users. 
Records are printed from most recent to least recent.  
[...]
The special users reboot and shutdown log in when the system reboots
or (surprise) shuts down. 

We use head to keep the latest 10 events and we use tac to invert the ordering so that we don't get confused by the fact that last prints from most recent to least recent event.

Solution 4

Some possible log files to explore: (found a Ubuntu system, but I would hope that they're present on most Linux/Unix systems)

/var/log/debug
/var/log/syslog (will be pretty full and may be harder to browse)
/var/log/user.log
/var/log/kern.log
/var/log/boot

Again, these log files are present on a Ubuntu system, so filenames may be different. The tail command is your friend.

Solution 5

Not fully satisfying

I had a similar need on a Debian 7.8 and observe that basically there's no clear and explicit message in log, which is a little surprising.

Grep through /var/log would tell the time the machine was shut down, show proper daemons shutdown, etc, but not the initial reason.

shutdown[25861]: shutting down for system halt

The other solutions mentioned (last -x) did not help much.

Looking how it works

Reading /etc/acpi/powerbtn-acpi-support.sh which includes:

if [ -x /etc/acpi/powerbtn.sh ] ; then
    # Compatibility with old config script from acpid package
    /etc/acpi/powerbtn.sh
elif [ -x /etc/acpi/powerbtn.sh.dpkg-bak ] ; then
        # Compatibility with old config script from acpid package
    # which is still around because it was changed by the admin
        /etc/acpi/powerbtn.sh.dpkg-bak
else
    # Normal handling.
    /sbin/shutdown -h -P now "Power button pressed"
fi

Notice that an explicit text is given as parameter of the shutdown command. I would expect that string to be logged automatically by the shutdown program.

Adjusting for better logs

Anyway, to get an explicit message I put the text below (as root) in a newly created /etc/acpi/powerbtn.sh made executable with chmod a+x /etc/acpi/powerbtn.sh

#!/bin/sh
logger in /etc/acpi/powerbtn.sh, presumably "Power button pressed"
    /sbin/shutdown -h -P now "Power button pressed"

Doing it this way will probably make a longer lasting change than modifying /etc/acpi/powerbtn-acpi-support.sh. The latter option would probably lose its effect on next upgrade of package acpi-support-base.

Notice than Ubuntu 14.04 does it differently (/etc/acpi/powerbtn.sh already exists with different content from acpid package). Also, Debian 8 probably does it differently. Feel free to offer variants.

Profit!

And now when the power button is pressed, a line like below appears in /var/log/messages, /var/log/syslog and /var/log/user.log:

logger: in /etc/acpi/powerbtn.sh, presumably Power button pressed

Now that's an explicit message in the log.

View more solutions

Comments

[alex]

So this time a had some luck with /var/log/acpid: turned out the power button was hit. Any other ideas, where to look if acpid doesn't give a clue?

[forcefsck]

The shutdown script does this already (last -x)

[alex]

Well, this doesn't tell me what caused the shutdown, only when it was done. Which I already know, see my question.

[Rahul Patil]

more precisely last -x shutdown

[Wolfgang]

The link is specifically to "How do I find out who or what halted my system (Old Sco Unix)?"

[Stéphane Gourichon]

Thanks to @Bielecki for suggesting to consider installing acpi-support-base and acpid packages. I haven't tested myself. Can you elaborate on which distribution and version it yields benefits?

[Atifm]

Nice solution. What would be required to get a patch out there to get the fix into the distribution?

[nominalize]

Running last reboot showed me that I had a new kernel version every time after the sudden reboot. This led me to look at Unattended-Upgrade in /etc/apt/apt.conf.d/50unattended-upgrades and /etc/apt/apt.conf.d/99custom-unattended-upgrades. See my answer here for more details: askubuntu.com/a/1261057/119592

[moo]

Thanks! I needed a slight modification for an Ubuntu system: grep -iv ': starting\|kernel: .*: Power Button\|watching system buttons\|Stopped Cleaning Up\|Started Crash recovery kernel' /var/log/auth.log /var/log/syslog | grep -iw 'recover[a-z]*\|power[a-z]*\|shut[a-z ]*down\|rsyslogd\|ups'

[Bikash Gyawali]

In both cases you can find out by checking the logs. .... which log files should I check?

[vishnu m c]

exit on signal 15 is not available in the buster OS's syslog. How to find the same in buster?

[Maxxx]

journalctl, /var/log/syslog, /var/log/messages