Date: Fri, 29 Jan 2016 19:05:59 +1100 (EST) From: Ian Smith <smithi@nimnet.asn.au> To: Arthur Chance <freebsd@qeng-ho.org> Cc: Andrea Venturoli <ml@netfence.it>, freebsd-questions@freebsd.org Subject: Re: Log power button Message-ID: <20160129160926.V57844@sola.nimnet.asn.au> In-Reply-To: <mailman.125.1453982402.57471.freebsd-questions@freebsd.org> References: <mailman.125.1453982402.57471.freebsd-questions@freebsd.org>
next in thread | previous in thread | raw e-mail | index | archive | help
In freebsd-questions Digest, Vol 608, Issue 4, Message: 13
On Thu, 28 Jan 2016 08:24:35 +0000 Arthur Chance <freebsd@qeng-ho.org> wrote:
> On 27/01/2016 18:55, Andrea Venturoli wrote:
> > Hello.
> >
> > A server of mine (10.1) is "spontaneusly" rebooting.
> > This is not a power failure/panic/crash/whatever, since it properly
> > shuts down.
> >
> > I suspect someone is pushing the power button, but I have no physical
> > way to check. Problem is, this is not reported in the logs.
> >
> > I vaguely remember older FreeBSD versions did this once, but I might be
> > wrong; I cannot check on this box (100km away), but I tried on another
> > one and, to my surprise, the fact that I pressed the power button was
> > NOT logged.
I was going to suggest enabling verbose logging, ie boot_verbose="YES"
in /boot/loader.conf, as I was sure I remembered it too .. but just to
check I hit the power button on my 9.3-stable laptop that always logs
verbosely - due to be rebooted for another reason anyway - and indeed ..
nothing logged in messages at all, where the suspend button always is.
Jan 25 15:35:34 x200 acpi_cmbat: CMBAT notify = 0x80
Jan 25 15:55:37 x200 acpi_cmbat: CMBAT notify = 0x80
Jan 29 14:42:19 x200 kernel: acpi_lid0: Lid opened
[ power button pressed here, proper shutdown noted on console ]
Jan 29 14:46:22 x200 kernel: .
Jan 29 14:46:22 x200 syslogd: exiting on signal 15
Jan 29 14:48:25 x200 syslogd: kernel boot file is /boot/kernel/kernel
The 'syslogd: exiting' message - despite it being timestamped at the
restart, not when it happened at 14:42:??, at least indicates it wasn't
an 'instant power off', as Polytropon and Michael Powell mentioned.
If you have /var/log/console.log enabled in syslog.conf, you get some
clues there about the clean shutdown procedure (which would also have
had a preceding message if shutdown or reboot had been issued):
Jan 18 01:18:44 x200 kernel: Jan 18 01:18:44 x200 su: smithi to root on /dev/pts/0
Jan 18 02:01:09 x200 kernel: Jan 18 02:01:09 x200 su: smithi to root on /dev/pts/0
Jan 29 14:46:22 x200 kernel: Stopping cron.
Jan 29 14:46:22 x200 kernel: Waiting for PIDS: 843.
Jan 29 14:46:22 x200 kernel: Stopping sshd.
Jan 29 14:46:22 x200 kernel: Waiting for PIDS: 788
Jan 29 14:46:22 x200 kernel: Stopping powerd.
Jan 29 14:46:22 x200 kernel: Waiting for PIDS: 682.
Jan 29 14:46:22 x200 kernel: Stopping devd.
Jan 29 14:46:22 x200 kernel: Waiting for PIDS: 414.
Jan 29 14:46:22 x200 kernel: Writing entropy file:.
[ again, the above occurred around 14:42 or so, syslogd caches stuff
somewhere or other, somehow .. ]
Jan 29 14:48:25 x200 kernel: Setting hostuuid: 4b390c20-70a0-11dd-9e96-c95b512cb49e.
Jan 29 14:48:25 x200 kernel: Setting hostid: 0xeedb5311.
Jan 29 14:48:25 x200 kernel: Entropy harvesting: interrupts ethernet point_to_point kickstart.
Jan 29 14:48:25 x200 kernel: Starting file system checks:
Jan 29 14:48:25 x200 kernel: /dev/ada0s2a: FILE SYSTEM CLEAN; SKIPPING CHECKS
Jan 29 14:48:25 x200 kernel: /dev/ada0s2a: clean, 147856 free (1384 frags, 18309 blocks, 0.4% fragmentation)
[..]
> > Is there any way to enable this?
> > Maybe I'm dumb, but I looked for this and found nothing.
>
> It's not an area I'm that familiar with so double check this, but take a
> look towards the end of /etc/devd.conf, where there's a comment about
> ACPI notify handlers. There's a "Button" subsystem related to power and
> sleep buttons. You probably want a devd rule that looks something like
>
> notify 0 {
> match "system" "ACPI";
> match "subsystem" "Button";
> match "notify" "0";
> action "logger -p daemon.alert Power button pressed";
> }
>
> I can't guarantee that will work, I've never tried it, but it's a place
> to start.
Indeed, though I wouldn't be certain the notify will be "0" rather than
"0x00" as that's the form most other passed notifies use. Andrea might
leave out the 'match "notify"' line - also catching the suspend button,
if relevant - and use instead:
action "logger -p daemon.alert button $notify pressed";
Instead of logging directly, I used the other approach also in devd.conf
examples for CMBAT notifies, wanting to keep an eye on battery state to
find a way to suspend or clean shutdown on low battery - sadly missing
since the olden days of APM .. yet another unfinished project, so far.
devd.conf:
notify 10 {
match "system" "ACPI";
match "subsystem" "CMBAT";
action "/root/bin/acpi_cmbat $notify";
};
/root/bin/acpi_cmbat:
#!/bin/sh
#% acpi_cmbat 27/6/14 for CMBAT notifies. ex /etc/rc.d/power_profile
LOGGER="logger -t acpi_cmbat -p daemon.notice"
notify=$1
${LOGGER} "CMBAT notify = $1"
#% 17/9/14 seeing 'Sep 17 22:35:01 x200 acpi_cmbat: CMBAT notify = 0x80'
#% at 3%, 20% & 80%, dischg & chg, also at every change of AC|battery.
/root/bin/x200stat >> /root/acpi_cmbat_events.log
echo "CMBAT status: notify = $1" >> /root/acpi_cmbat_events.log
exit 0
Most likely overkill for what Andrea needs, but a working example.
cheers, Ian
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?20160129160926.V57844>