kern/119200: [acpi] Lid close switch suspends CPU for 1 second on HP nx6125

[Bruce Evans]

On Sun, 4 Mar 2012 jh at freebsd.org wrote:

> Synopsis: [acpi] Lid close switch suspends CPU for 1 second on HP nx6125

HP nx6325 had the same bug.  I happened to test this yesterday and was
surprised to find that it was fixed.  All other sleep modes are still
unusable, but this might be because I don't have anything except default
acpi to support powe management in the kernel (no acpi_hp) and my
userland is from 2004.

Further investigation shows that the main problem described in the PR
is still there -- the system still seems to stop for 1 second.  But now
the time according to the ACPI timecounter isn't corrupted by 1 second
after this system comes back.  The fix might have been in timer code
and have little to do with acpi.  But last time I checked more details,
all timers and interrupts seemed to stop for 1 second.  The behaviour
is still hard to explain, with some most parts of the system apparently
stopping, but not all.  According to ping -i 0.1:

% PING etaplex.bde.org (192.168.2.7): 56 data bytes
% ...
% 64 bytes from 192.168.2.7: icmp_seq=13 ttl=64 time=0.082 ms
% 64 bytes from 192.168.2.7: icmp_seq=14 ttl=64 time=0.080 ms
% 64 bytes from 192.168.2.7: icmp_seq=15 ttl=64 time=986.046 ms
% 64 bytes from 192.168.2.7: icmp_seq=16 ttl=64 time=886.075 ms
% 64 bytes from 192.168.2.7: icmp_seq=17 ttl=64 time=786.079 ms
% 64 bytes from 192.168.2.7: icmp_seq=18 ttl=64 time=686.076 ms
% 64 bytes from 192.168.2.7: icmp_seq=19 ttl=64 time=586.072 ms
% 64 bytes from 192.168.2.7: icmp_seq=20 ttl=64 time=486.073 ms
% 64 bytes from 192.168.2.7: icmp_seq=21 ttl=64 time=386.088 ms
% 64 bytes from 192.168.2.7: icmp_seq=22 ttl=64 time=286.086 ms
% 64 bytes from 192.168.2.7: icmp_seq=23 ttl=64 time=186.083 ms
% 64 bytes from 192.168.2.7: icmp_seq=24 ttl=64 time=86.082 ms
% 64 bytes from 192.168.2.7: icmp_seq=25 ttl=64 time=0.075 ms
% 64 bytes from 192.168.2.7: icmp_seq=26 ttl=64 time=0.074 ms

According to this, the NIC didn't lose any packets while the system
stopped.

% Script started on Mon Mar  5 09:52:01 2012
% ttyp0:bde at etaplex:/d/tmp/r> time countll
%        10.04 real        10.01 user         0.00 sys
% ttyp0:bde at etaplex:/d/tmp/r> time sleep 10
%        10.00 real         0.00 user         0.00 sys

Normal operation.  countll counts to 10 billion, taking 2 cycles per
iteration, so with a CPU frequency of 1.995 GHz it takes almost
exactly 10 seconds.

% ttyp0:bde at etaplex:/d/tmp/r> time countll
%        11.18 real        11.16 user         0.00 sys
% ttyp0:bde at etaplex:/d/tmp/r> time sleep 10
%        10.00 real         0.00 user         0.00 sys
% Script done on Mon Mar  5 09:53:59 2012

With the screen turned off in the middle of each (doesn't matter if it
is turned back on).  The counting process still presumably takes only
20 billion CPU cycles, but now it takes 1.18 seconds longer.  The
accuracy of the sleep is even more interesting.  The sleep is for a
certain number of timer ticks, but last time I checked, there were
no timer ticks during the 1-second pause.  This has probably been
fixed by the new timer code.  It has to compensate for not interrupting
for every tick in normal operation, and this apparently handles lost
ticks perfectly too.

Bruce