Notes; Lenovo T400
Ian Smith
smithi at nimnet.asn.au
Sun Feb 10 15:06:39 UTC 2013
On Fri, 8 Feb 2013 22:52:13 -0800, Kevin Oberman wrote:
> On Sun, Feb 3, 2013 at 7:10 AM, Ian Smith <smithi at nimnet.asn.au> wrote:
> > On Sat, 2 Feb 2013 22:46:26 -0800, Kevin Oberman wrote:
> > > On Fri, Feb 1, 2013 at 5:36 PM, Adrian Chadd <adrian at freebsd.org> wrote:
> > > > Yeah I commented it out to make it work.
> > > >
> > > > Try booting to single user mode and then try a suspend/resume pass.
> > > >
> > > >
> > > >
> > > > Adrian
> > > >
> > > >
> > > > On 1 February 2013 17:34, Kevin Oberman <kob6558 at gmail.com> wrote:
> > > >> Adrian,
> > > >>
> > > >> Can I assume that you did NOT have the '#' in the sysctl.conf? (Still
> > > >> hoping to et my T520 to resume some day.)
> > > >>
> > > >> On Wed, Jan 30, 2013 at 9:35 PM, Adrian Chadd <adrian at freebsd.org> wrote:
> > > >>> Hi,
> > > >>>
> > > >>> It turns out my Lenovo T400 issue? It was because in /etc/sysctl.conf
> > > >>> I had this:
> > > >>>
> > > >>> # hw.acpi.reset_video=1
> > > >>>
> > > >>> .. don't do that.
> > > >>>
> > > >>>
> > > >>>
> > > >>> Adrian
> > >
> > > Almost worked. I saw several acpi power state errors as the system
> > > suspended. On resume, the system came back up, but the display
> > > remained off (no backlight). I was able to type 'shutdown -r now' and
> > > do a clean reboot. Of course, the number of differences between single
> > > and multi-user are substantial, but this eliminates a LOT of things.
> > >
> > > I then tried coming up to multi-user, but not starting X (Gnome).
> > > Again, it suspended and resumed with no display. My network came up
> > > and I sshed into the system from my phone. Then I got an interrupt
> > > from my greyhounds. Time to brush their teeth. I was away from the
> > > laptop for about 10 minutes. When I came back, it was dead. My ssh
> > > session was hung and I could no longer ping it. :-(
> > >
> > > Weird. It's getting really close, but not quite. I suspect that the
> > > video ties into it in some way. I also mount a couple of FUSE NTFS
> > > partitions when I start X (Gnome auto-mounts them). When I suspend in
> > > Gnome, the network never comes back up and the power LED pulses just
> > > like it does while suspended, so it really does not finish the resume.
Sounds more like it doesn't or scarcely begins the resume in the latter
case; powering up from S3 sleep sufficiently to run resume code is
pretty low level BIOS stuff I'd have thought, power LED and such?
I clearly know nothing about video issues these days, but 'blank screen
on resume' seems to come up pretty often. Maybe more on acpi@?
> > > I think I can now eliminate the wireless (iwn), at least.
> > >
> > > Thanks for the suggestions!
> >
> > Kevin, have you tried doing suspend/resume after booting with verbose
> > messages? If you can get in eg ssh as above, you can dmesg > file and
> > even if you can't, it should all be there in /var/log/messages .. I've
> > found it handy to see all the blow-by-blow disabling of devices then
> > reenabling after resume for working out what happened (or didn't :)
> >
> > You can also increase ACPI verbosity, but I've rarely needed to.
>
> Finally gave it a try, but nothing looks very odd to me. It stays
> responsive for about a couple of minutes and then stops responding to
> either the ssh session or the keyboard.
>
> Here are the contents of messages for the suspend and the resume. I
> don't really see anything very bad. Looks like firewire has a problem.
Just a few likely unhelpful observations ..
First thing I noticed was the lack of my very old friend, the 'wakeup
from sleeping state (slept hh:mm:ss)' line, which marks wakeup, busses
ablaze, before device reconfig. Is this on -current?
> Feb 8 22:26:17 rogue console-kit-daemon[1509]: WARNING: kvm_getenvv failed:
> Feb 8 22:26:17 rogue kernel: blanktime screensaver
> Feb 8 22:26:17 rogue kernel: splash: image decoder found: logo_saver
I guess you've tried disabling screensavers? Recalling older issues ..
> Feb 8 22:26:21 rogue ntpd[1351]: time reset -1.063975 s
> Feb 8 22:26:24 rogue login: ROOT LOGIN (root) ON ttyv0
> Feb 8 22:26:45 rogue acpi: suspend at 20130208 22:26:45
> Feb 8 22:26:48 rogue kernel: acpi_timer0: switching timecounter,
> TSC-low -> ACPI-fast
Switching timecounters is news; I must read more commit messages! :)
> Feb 8 22:26:48 rogue kernel: (ada0:ahcich0:0:0:0): spin-down
> Feb 8 22:26:49 rogue kernel: (ada1:ahcich1:0:0:0): spin-down
> Feb 8 22:27:03 rogue kernel: acpi_lid0: wake_prep enabled for \_SB_.LID_ (S3)
> Feb 8 22:27:03 rogue kernel: acpi_button0: wake_prep enabled for
> \_SB_.SLPB (S3)
> Feb 8 22:27:03 rogue kernel: uhub0: at usbus0, port 1, addr 1 (disconnected)
> Feb 8 22:27:03 rogue kernel: ugen0.2: <vendor 0x8087> at usbus0 (disconnected)
> Feb 8 22:27:03 rogue kernel: uhub2: at uhub0, port 1, addr 2 (disconnected)
> Feb 8 22:27:03 rogue kernel: ugen0.3: <Chicony Electronics Co., Ltd.>
> at usbus0 (disconnected)
> Feb 8 22:27:03 rogue kernel: pci0:0:28:0: Transition from D0 to D3
> Feb 8 22:27:03 rogue kernel: wlan0: link state changed to DOWN
> Feb 8 22:27:03 rogue kernel: pci0:3:0:0: Transition from D0 to D3
> Feb 8 22:27:03 rogue kernel: pci0:0:28:1: Transition from D0 to D3
> Feb 8 22:27:03 rogue kernel: pci0:0:28:3: Transition from D0 to D3
> Feb 8 22:27:03 rogue kernel: fwohci0: fwohci_pci_suspend
> Feb 8 22:27:03 rogue kernel: pci0:13:0:0: Transition from D0 to D3
> Feb 8 22:27:03 rogue kernel: pci0:13:0:3: Transition from D0 to D3
> Feb 8 22:27:03 rogue kernel: pci0:0:28:4: Transition from D0 to D3
> Feb 8 22:27:03 rogue kernel: uhub1: at usbus1, port 1, addr 1 (disconnected)
> Feb 8 22:27:03 rogue kernel: ugen1.2: <vendor 0x8087> at usbus1 (disconnected)
> Feb 8 22:27:03 rogue kernel: uhub3: at uhub1, port 1, addr 2 (disconnected)
No surprises, without knowing your device mapping ..
> Feb 8 22:27:03 rogue kernel: vga0: saving 6724 bytes of video state
> Feb 8 22:27:03 rogue kernel: vga0: saving color palette
Less than twice the size of state saved by my lil' S3 Savage card :)
> Feb 8 22:27:03 rogue kernel: pci0: failed to set ACPI power state D2
> on \_SB_.PCI0.EXP1: AE_BAD_PARAMETER
> Feb 8 22:27:03 rogue kernel: pci0: failed to set ACPI power state D2
> on \_SB_.PCI0.EXP2: AE_BAD_PARAMETER
> Feb 8 22:27:03 rogue kernel: pci0: failed to set ACPI power state D2
> on \_SB_.PCI0.EXP4: AE_BAD_PARAMETER
> Feb 8 22:27:03 rogue kernel: pci0: failed to set ACPI power state D2
> on \_SB_.PCI0.EXP5: AE_BAD_PARAMETER
Card reader I guess? I get the same messages on 9.1 for both cardbus
bridges. All below are on the resume path after the wakeup.
> Feb 8 22:27:03 rogue kernel: acpi_lid0: run_prep cleaned up for \_SB_.LID_
> Feb 8 22:27:03 rogue kernel: acpi_button0: run_prep cleaned up for \_SB_.SLPB
> Feb 8 22:27:03 rogue kernel: pci0: set ACPI power state D0 on \_SB_.PCI0.VID_
I wish I knew something about how X resumes graphic video state, or what
triggers it to .. I guess it has its own resume method? Is that suspect?
> Feb 8 22:27:03 rogue kernel: pci0: set ACPI power state D0 on \_SB_.PCI0.IGBE
> Feb 8 22:27:03 rogue kernel: pci0: set ACPI power state D0 on \_SB_.PCI0.EHC2
> Feb 8 22:27:03 rogue kernel: pci0: set ACPI power state D0 on \_SB_.PCI0.HDEF
> Feb 8 22:27:03 rogue kernel: pci0: set ACPI power state D0 on \_SB_.PCI0.EXP1
> Feb 8 22:27:03 rogue kernel: pci0: set ACPI power state D0 on \_SB_.PCI0.EXP2
> Feb 8 22:27:03 rogue kernel: pci0: set ACPI power state D0 on \_SB_.PCI0.EXP4
> Feb 8 22:27:03 rogue kernel: pci0: set ACPI power state D0 on \_SB_.PCI0.EXP5
I see the above four repeated below, plus .EXP5.SLOT. I don't get that.
> Feb 8 22:27:03 rogue kernel: pci0: set ACPI power state D0 on \_SB_.PCI0.EHC1
> Feb 8 22:27:03 rogue kernel: pci0: set ACPI power state D0 on \_SB_.PCI0.LPC_
> Feb 8 22:27:03 rogue kernel: pci0: set ACPI power state D0 on \_SB_.PCI0.SAT1
> Feb 8 22:27:03 rogue kernel: pci0:0:22:0: Transition from D0 to D3
Hmm, what is pci0:0:22:0 and why is it going back to sleep? firewire?
> Feb 8 22:27:03 rogue kernel: pci0: set ACPI power state D0 on \_SB_.PCI0.EXP1
> Feb 8 22:27:03 rogue kernel: pci0: set ACPI power state D0 on \_SB_.PCI0.EXP2
> Feb 8 22:27:03 rogue kernel: pci0: set ACPI power state D0 on \_SB_.PCI0.EXP4
> Feb 8 22:27:03 rogue kernel: pci0: set ACPI power state D0 on \_SB_.PCI0.EXP5
> Feb 8 22:27:03 rogue kernel: pci13: set ACPI power state D0 on
> \_SB_.PCI0.EXP5.SLOT
A card in one of the slots?
> Feb 8 22:27:03 rogue kernel: fwohci0: Phy 1394a available S400, 1 ports.
> Feb 8 22:27:03 rogue kernel: fwohci0: Link S400, max_rec 2048 bytes.
> Feb 8 22:27:03 rogue kernel: fwohci0: Initiate bus reset
> Feb 8 22:27:03 rogue kernel: vga0: calling BIOS POST
> Feb 8 22:27:03 rogue kernel: fwohci0: fwohci_intr_core: BUS reset
> Feb 8 22:27:03 rogue kernel: fwohci0: fwohci_intr_core:
> node_id=0x00000000, SelfID Count=1, CYCLEMASTER mode
> Feb 8 22:27:03 rogue kernel: firewire0: 1 nodes, maxhop <= 0 cable
> IRM irm(0) (me)
> Feb 8 22:27:03 rogue kernel: firewire0: bus manager 0
> Feb 8 22:27:03 rogue kernel: fwohci0: unrecoverable error
Yes it looks unhappy. BIOS POST amidst that is probably coincidence.
> Feb 8 22:27:03 rogue kernel: hdaa0: Headphones redirection for
> association 0 nid=25 using unsolicited responses.
> Feb 8 22:27:03 rogue kernel: ahcich0: AHCI reset...
> Feb 8 22:27:03 rogue kernel: ahcich0: SATA connect time=1000us status=00000123
> Feb 8 22:27:03 rogue kernel: ahcich0: AHCI reset: device found
> Feb 8 22:27:03 rogue kernel: ahcich1: AHCI reset...
> Feb 8 22:27:03 rogue kernel: ahcich1: SATA connect time=1000us status=00000123
> Feb 8 22:27:03 rogue kernel: ahcich1: AHCI reset: device found
> Feb 8 22:27:03 rogue kernel: ahcich3: AHCI reset...
> Feb 8 22:27:03 rogue kernel: ahcich3: SATA connect timeout
> time=10000us status=00000000
> Feb 8 22:27:03 rogue kernel: ahcich3: AHCI reset: device not found
> Feb 8 22:27:03 rogue kernel: ahcich4: AHCI reset...
> Feb 8 22:27:03 rogue kernel: ahcich4: SATA connect timeout
> time=10000us status=00000000
> Feb 8 22:27:03 rogue kernel: ahcich4: AHCI reset: device not found
> Feb 8 22:27:03 rogue kernel: atkbd: the current kbd controller
> command byte 0047
> Feb 8 22:27:03 rogue kernel: atkbd: keyboard ID 0x54ab (2)
> Feb 8 22:27:03 rogue kernel: kbdc: RESET_KBD return code:00fa
> Feb 8 22:27:03 rogue kernel: kbdc: RESET_KBD status:00aa
> Feb 8 22:27:03 rogue kernel: kbdc: TEST_AUX_PORT status:0000
> Feb 8 22:27:03 rogue kernel: kbdc: RESET_AUX return code:00fa
> Feb 8 22:27:03 rogue kernel: kbdc: RESET_AUX status:00aa
> Feb 8 22:27:03 rogue kernel: kbdc: RESET_AUX ID:0000
All that looks 'normal' from here, given AHCI/SATA rather than ATA/PATA.
> Feb 8 22:27:03 rogue kernel: firmware: 'iwn6000g2afw' version 0:
> 444128 bytes loaded at 0xffffffff8183c0b0
> Feb 8 22:27:03 rogue kernel: battery0: battery initialization start
> Feb 8 22:27:03 rogue kernel: uhub0: <Intel EHCI root HUB, class 9/0,
> rev 2.00/1.00, addr 1> on usbus1
> Feb 8 22:27:03 rogue kernel: uhub1: <Intel EHCI root HUB, class 9/0,
> rev 2.00/1.00, addr 1> on usbus0
> Feb 8 22:27:03 rogue kernel: ahcich0: AHCI reset: device ready after 800ms
> Feb 8 22:27:03 rogue kernel: ahcich1: AHCI reset: device ready after 1200ms
> Feb 8 22:27:03 rogue kernel: uhub0: 3 ports with 3 removable, self powered
> Feb 8 22:27:03 rogue kernel: uhub1: 3 ports with 3 removable, self powered
> Feb 8 22:27:03 rogue kernel: ugen1.2: <vendor 0x8087> at usbus1
> Feb 8 22:27:03 rogue kernel: uhub2: <vendor 0x8087 product 0x0024,
> class 9/0, rev 2.00/0.00, addr 2> on usbus1
> Feb 8 22:27:03 rogue kernel: ugen0.2: <vendor 0x8087> at usbus0
> Feb 8 22:27:03 rogue kernel: uhub3: <vendor 0x8087 product 0x0024,
> class 9/0, rev 2.00/0.00, addr 2> on usbus0
> Feb 8 22:27:03 rogue kernel: uhub3: 6 ports with 6 removable, self powered
> Feb 8 22:27:03 rogue kernel: battery0: battery initialization done,
> tried 1 times
> Feb 8 22:27:03 rogue kernel: wlan0: link state changed to UP
> Feb 8 22:27:03 rogue kernel: uhub2: 8 ports with 8 removable, self powered
> Feb 8 22:27:03 rogue kernel: (ada0:ahcich0:0:0:0): resume
> Feb 8 22:27:03 rogue kernel: (ada1:ahcich1:0:0:0): resume
Seems uneventful.
> Feb 8 22:27:03 rogue kernel: acpi_timer0: restoring timecounter,
> ACPI-fast -> TSC-low
I'm curious about this. Note the next log timestamp is at least 13
seconds earlier, but maybe that's why we're using TSC-low instead?
Yes, looks like wireless is working below ..
The fact that it resumed, sans backlight - is there anything that could
poke that from /etc/rc.resume? DPMS? - but then died inside 10 minutes
seems a bit spooky. I remember from DOS days - the screensaver dun it!
cheers, Ian
> Feb 8 22:26:50 rogue wpa_supplicant[538]: CTRL-EVENT-DISCONNECTED
> bssid=00:26:b8:67:c3:2d reason=0
> Feb 8 22:26:50 rogue wpa_supplicant[538]: Failed to initiate AP scan.
> Feb 8 22:26:53 rogue last message repeated 3 times
> Feb 8 22:26:57 rogue wpa_supplicant[538]: Trying to associate with
> 00:26:b8:67:c3:2d (SSID='babcom' freq=2437 MHz)
> Feb 8 22:26:57 rogue wpa_supplicant[538]: Associated with 00:26:b8:67:c3:2d
> Feb 8 22:26:57 rogue wpa_supplicant[538]: WPA: Key negotiation
> completed with 00:26:b8:67:c3:2d [PTK=CCMP GTK=CCMP]
> Feb 8 22:26:57 rogue wpa_supplicant[538]: CTRL-EVENT-CONNECTED -
> Connection to 00:26:b8:67:c3:2d completed (reauth) [id=1 id_str=]
> Feb 8 22:27:03 rogue acpi: resumed at 20130208 22:27:03
> Feb 8 22:27:03 rogue dhclient: New IP Address (wlan0): 192.168.1.5
> Feb 8 22:27:03 rogue dhclient: New Subnet Mask (wlan0): 255.255.255.0
> Feb 8 22:27:03 rogue dhclient: New Broadcast Address (wlan0): 192.168.1.255
> Feb 8 22:27:03 rogue dhclient: New Routers (wlan0): 192.168.1.1
> Feb 8 22:27:03 rogue root: Unknown USB device: vendor 0x04f2 product
> 0xb217 bus uhub3
> Feb 8 22:27:03 rogue kernel: ugen0.3: <Chicony Electronics Co., Ltd.> at usbus0
> Feb 8 22:27:03 rogue root: Unknown USB device: vendor 0x04f2 product
> 0xb217 bus uhub3
> Feb 8 22:27:41 rogue sudo: oberman : TTY=pts/0 ;
> PWD=/usr/home/oberman ; USER=root ; COMMAND=/bin/csh
> Feb 8 22:27:52 rogue wpa_supplicant[538]: WPA: Group rekeying
> completed with 00:26:b8:67:c3:2d [GTK=CCMP]
> --
> R. Kevin Oberman, Network Engineer
> E-mail: kob6558 at gmail.com
More information about the freebsd-mobile
mailing list