linux-kernel - Re: Hang during boot, bisected to commit 96d60303fd

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Message-ID: <AANLkTinKqB95MvThlHShlT6snqf0fKHBuxgcPpNuslAb@mail.gmail.com>
Date:	Fri, 4 Jun 2010 21:45:50 -0400
From:	Marc Dionne <marc.c.dionne@...il.com>
To:	Robert Hancock <hancockrwd@...il.com>
Cc:	Matthew Garrett <mjg59@...f.ucam.org>,
	Linux Kernel Mailing List <linux-kernel@...r.kernel.org>,
	linux-ide@...r.kernel.org, garzik@...hat.com
Subject: Re: Hang during boot, bisected to commit 96d60303fd

On Fri, Jun 4, 2010 at 9:37 PM, Robert Hancock <hancockrwd@...il.com> wrote:
>  Fri, Jun 4, 2010 at 7:23 PM, Marc Dionne <marc.c.dionne@...il.com> wrote:
>> On Thu, Jun 3, 2010 at 11:42 PM, Robert Hancock <hancockrwd@...il.com> wrote:
>>> On 06/03/2010 07:21 PM, Marc Dionne wrote:
>>>>
>>>> On Wed, Jun 2, 2010 at 10:00 PM, Matthew Garrett<mjg59@...f.ucam.org>
>>>>  wrote:
>>>>>
>>>>> On Wed, Jun 02, 2010 at 09:49:27PM -0400, Marc Dionne wrote:
>>>>>>
>>>>>>    Since somewhere early in the 2.6.35 merge window I've been seeing a
>>>>>> hang
>>>>>>    during boot.  The hang last roughly 30 seconds and is followed by
>>>>>> this:
>>>>>>
>>>>>>    ata4.00: exception Emask 0x0 SAct 0x1 SErr 0x0 action 0x6 frozen
>>>>>>    ata4.00: failed command: READ FPDMA QUEUED
>>>>>>    ata4.00: cmd 60/08:00:00:00:00/00:00:00:00:00/40 tag 0 ncq 4096 in
>>>>>>             res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
>>>>>>    ata4.00: status: { DRDY }
>>>>>>    ata4: hard resetting link
>>>>>>    ahci_is_device_present: status is: 80
>>>>>>    ahci_is_device_present: status(2) is: 3
>>>>>>    ata4: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
>>>>>>    ata4.00: configured for UDMA/133
>>>>>>    ata4.00: device reported invalid CHS sector 0
>>>>>>    ata4: EH complete
>>>>>>
>>>>>>    The system works normally once booted.  I had some time to do a
>>>>>> bisect
>>>>>>    today and it cleanly ended up pointing to this commit:
>>>>>>        96d60303fd: ahci: Turn off DMA engines when there's no device
>>>>>> attached
>>>>>>
>>>>>>    Reverting the commit makes the system boot cleanly as before.  System
>>>>>> has
>>>>>>    an Intel ICH10 based board, in AHCI mode, disk is an Intel X25M SSD.
>>>>>
>>>>> Hm, interesting. Jeff, any immediate ideas? I don't see this behaviour
>>>>> on my ICH10. Is there actually a device on ata4?
>>>>>
>>>>> --
>>>>> Matthew Garrett | mjg59@...f.ucam.org
>>>>
>>>> If it's helpful, attached are the dmesg output following a normal boot
>>>> and one with the hang.
>>>>
>>>> The only difference in the kernel used for those two boots is that the
>>>> return statement in ahci_start_engine following the call to
>>>> ahci_is_device_present is commented out for the normal boot case.
>>>> When the return statement is active, the 30 second hang occurs.
>>>
>>> Can you try and put a printk in where it's returning out of the
>>> ahci_start_engine method? I wonder if that's getting triggered somewhere
>>> unexpected..
>>
>> Attached is a dmesg output with some printks added to show the status
>> when ahci_is_device_present causes ahci_start_engine to return early..
>>
>> It looks to me like there's two passes through ahci_start_engine for
>> all ports, and during the first pass the port with the disk is showing
>> a status of 127, causing the function to return early and skipping the
>> start DMA part.  This seems to cause the hang later on.
>>
>> I noticed that during this first pass all the print_id fields for the
>> ports are still set to -1, so as a test I made ahci_start_engine only
>> do the check for ahci_is_device_present if print_id != -1, and this
>> makes the system boot normally.
>
> Is that the right dmesg? I didn't see where the extra output was. It
> might be useful to put a WARN_ON(1); inside ahci_start_engine to see
> the two code paths where it's being called..

It's the right dmesg, look for lines containing
"ahci_is_device_present" or "ahci_start_engine" - sorry, I should have
pointed it out.

I'll try adding a WARN_ON to get the code paths.

Marc
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/