sparc32 boot problem (SCSI?)

sparc32 boot problem (SCSI?)

[Robert Reif]

sparc32 v2.6.29 boots and runs fine.
sparc32 v2.6.30-rc6 fails at root filesystem detection.

Looks like a SCSI issue?

Here are the relevant boot log differences:

v2.6.29:
Begin: Loading essential drivers... ...
[42949381.570000] SCSI subsystem initialized
[42949381.710000] esp: esp0, regs[fd407000:fd406000] irq[36]
[42949381.720000] esp: esp0 is a FAS100A, 40 MHz (ccf=0), SCSI ID 7
[42949384.740000] scsi0 : esp
[42949384.760000] esp: esp1, regs[fd409000:fd408000] irq[53]
[42949384.770000] esp: esp1 is a FASHME, 40 MHz (ccf=0), SCSI ID 7
[42949387.790000] scsi1 : esp
[42949387.830000] scsi 1:0:0:0: Direct-Access     SEAGATE  
ST39102LCSUN9.0G 0822
[42949387.840000]  target1:0:0: Beginning Domain Validation
[42949387.870000]  target1:0:0: FAST-10 WIDE SCSI 20.0 MB/s ST (100 ns, 
offset )
[42949387.900000]  target1:0:0: Domain Validation skipping write tests
[42949387.910000]  target1:0:0: Ending Domain Validation
Done.
Begin: Running /scripts/init-premount ...
[42949392.670000] Driver 'sd' needs updating - please use bus_type methods
[42949392.710000] sd 1:0:0:0: [sda] 17689267 512-byte hardware sectors: 
(9.05 G)
[42949392.720000] sd 1:0:0:0: [sda] Write Protect is off
[42949392.740000] sd 1:0:0:0: [sda] Write cache: disabled, read cache: 
enabled,A
[42949392.750000] sd 1:0:0:0: [sda] 17689267 512-byte hardware sectors: 
(9.05 G)
[42949392.760000] sd 1:0:0:0: [sda] Write Protect is off
[42949392.770000] sd 1:0:0:0: [sda] Write cache: disabled, read cache: 
enabled,A
[42949392.780000]  sda: sda1 sda2 sda3 sda4
[42949392.830000] sd 1:0:0:0: [sda] Attached SCSI disk
Done.
Begin: Mounting root file system... ...
Begin: Running /scripts/local-top ...
Done.
Begin: Running /scripts/local-premount ...
Done.

v2.6.30-rc6:
Begin: Loading essential drivers... ...
[    5.350000] SCSI subsystem initialized
[    5.490000] esp: esp0, regs[fd407000:fd406000] irq[36]
[    5.500000] esp: esp0 is a FAS100A, 40 MHz (ccf=0), SCSI ID 7
[    8.520000] scsi0 : esp
[    8.530000] esp: esp1, regs[fd409000:fd408000] irq[53]
[    8.540000] esp: esp1 is a FASHME, 40 MHz (ccf=0), SCSI ID 7
[   11.560000] scsi1 : esp
[   11.580000] scsi 1:0:0:0: Direct-Access     SEAGATE  ST39102LCSUN9.0G 
0828 P2
[   11.590000]  target1:0:0: Beginning Domain Validation
[   11.610000]  target1:0:0: FAST-10 WIDE SCSI 20.0 MB/s ST (100 ns, 
offset 15)
[   11.630000]  target1:0:0: Domain Validation skipping write tests
[   11.640000]  target1:0:0: Ending Domain Validation
Done.
Begin: Running /scripts/init-premount ...
[   16.060000] Driver 'sd' needs updating - please use bus_type methods
[   16.090000] sd 1:0:0:0: [sda] 17689267 512-byte hardware sectors: 
(9.05 GB/8)
[   16.100000] sd 1:0:0:0: [sda] Write Protect is off
[   16.110000] sd 1:0:0:0: [sda] Write cache: disabled, read cache: 
enabled, suA
[   16.130000]  sda: sda1 sda2 sda3 sda4
[   16.190000] sd 1:0:0:0: [sda] Attached SCSI disk
Done.
Begin: Mounting root file system... ...
Begin: Running /scripts/local-top ...
Done.
Begin: Waiting for root file system... ...
Done.
Begin: Running /scripts/local-premount ...
Done.
mount: Mounting /dev/sda2 on /root failed: No such device
Begin: Running /scripts/local-bottom ...
Done.
Done.
Begin: Running /scripts/init-bottom ...
mount: Mounting /root/dev on /dev/.static/dev failed: No such file or 
directory
Done.
mount: Mounting /sys on /root/sys failed: No such file or directory
mount: Mounting /proc on /root/proc failed: No such file or directory
Target filesystem doesn't have /sbin/init

Re: sparc32 boot problem (SCSI?)

[Josip Rodin]

On Thu, May 21, 2009 at 10:07:31PM -0400, Robert Reif wrote:
> [42949392.780000]  sda: sda1 sda2 sda3 sda4
> [42949392.830000] sd 1:0:0:0: [sda] Attached SCSI disk
> Done.
> Begin: Mounting root file system... ...
> Begin: Running /scripts/local-top ...
> Done.
> Begin: Running /scripts/local-premount ...
> Done.

> [   16.130000]  sda: sda1 sda2 sda3 sda4
> [   16.190000] sd 1:0:0:0: [sda] Attached SCSI disk
> Done.
> Begin: Mounting root file system... ...
> Begin: Running /scripts/local-top ...
> Done.
> Begin: Waiting for root file system... ...
> Done.
> Begin: Running /scripts/local-premount ...
> Done.
> mount: Mounting /dev/sda2 on /root failed: No such device

You might want to do the generic initramfs debug steps like those
described at http://wiki.debian.org/InitramfsDebug

-- 
     2. That which causes joy or happiness.

Re: sparc32 boot problem (SCSI?)

[Robert Reif]

Josip Rodin wrote:
> You might want to do the generic initramfs debug steps like those
> described at http://wiki.debian.org/InitramfsDebug
>
>   
I tried the steps above and I don't see any issues.  All the
devices are in /dev, fstype returns the right info and
/proc/modules are the same.

The two significant differences in boot messages are the
timestamps and the premount output of the bad boot
has less output.

good:

Begin: Running /scripts/init-premount ...
[42949392.740000] Driver 'sd' needs updating - please use bus_type methods
[42949392.770000] sd 1:0:0:0: [sda] 17689267 512-byte hardware sectors: 
(9.05 GB/8.43 GiB)
[42949392.790000] sd 1:0:0:0: [sda] Write Protect is off
[42949392.800000] sd 1:0:0:0: [sda] Write cache: disabled, read cache: 
enabled, supports DPO and FUA
[42949392.820000] sd 1:0:0:0: [sda] 17689267 512-byte hardware sectors: 
(9.05 GB/8.43 GiB)
[42949392.830000] sd 1:0:0:0: [sda] Write Protect is off
[42949392.850000] sd 1:0:0:0: [sda] Write cache: disabled, read cache: 
enabled, supports DPO and FUA
[42949392.860000]  sda: sda1 sda2 sda3 sda4
[42949392.920000] sd 1:0:0:0: [sda] Attached SCSI disk
Done.

bad:

Begin: Running /scripts/init-premount ...
[   16.080000] Driver 'sd' needs updating - please use bus_type methods
[   16.110000] sd 1:0:0:0: [sda] 17689267 512-byte hardware sectors: 
(9.05 GB/8.43 GiB)
[   16.120000] sd 1:0:0:0: [sda] Write Protect is off
[   16.130000] sd 1:0:0:0: [sda] Write cache: disabled, read cache: 
enabled, supports DPO and FUA
[   16.150000]  sda: sda1 sda2 sda3 sda4
[   16.200000] sd 1:0:0:0: [sda] Attached SCSI disk
Done.

Re: sparc32 boot problem (SCSI?)

[Josip Rodin]

On Fri, May 22, 2009 at 09:21:54PM -0400, Robert Reif wrote:
> Josip Rodin wrote:
>> You might want to do the generic initramfs debug steps like those
>> described at http://wiki.debian.org/InitramfsDebug
>>   
> I tried the steps above and I don't see any issues.  All the
> devices are in /dev, fstype returns the right info and
> /proc/modules are the same.
>
> The two significant differences in boot messages are the
> timestamps and the premount output of the bad boot
> has less output.

The removed duplication looks like an improvement to me, and so does
the fixed timestamp (the old values can't be right, assuming the core of
the old kernel doesn't actually boot for 497 days before it comes to the
root filesystem :)).

One thing that came up with one of my recent upgrades was the md subsystem
interfering with /dev/root, and that kind of a problem isn't mentioned in
the generic instructions. Does /dev/root point to the right device (same
major:minor as /dev/sda2) in your case?

-- 
     2. That which causes joy or happiness.

Re: sparc32 boot problem (SCSI?)

[Robert Reif]

Josip Rodin wrote:
> One thing that came up with one of my recent upgrades was the md subsystem
> interfering with /dev/root, and that kind of a problem isn't mentioned in
> the generic instructions. Does /dev/root point to the right device (same
> major:minor as /dev/sda2) in your case?
>
>   
I don't have md selected.  There is no /dev/root in either
the working or broken version.  I'm running debian etch
if that matters.

Re: sparc32 boot problem (SCSI?)

[Robert Reif]

Robert Reif wrote:
> Josip Rodin wrote:
>> One thing that came up with one of my recent upgrades was the md 
>> subsystem
>> interfering with /dev/root, and that kind of a problem isn't 
>> mentioned in
>> the generic instructions. Does /dev/root point to the right device (same
>> major:minor as /dev/sda2) in your case?
>>
>>   
> I don't have md selected.  There is no /dev/root in either
> the working or broken version.  I'm running debian etch
> if that matters.
I'm trying to bisect this and have narrowed it down to
late in the merge window.  Unfortunately I can't easily narrow
it down further because module loading also broke during
the same time frame.

Re: sparc32 boot problem (SCSI?)

[Robert Reif]

Robert Reif wrote:
> I'm trying to bisect this and have narrowed it down to
> late in the merge window.  Unfortunately I can't easily narrow
> it down further because module loading also broke during
> the same time frame.
I bisected it down to this but it makes no sense.

f894e74dc1983062d30d4e1b79bdb90b8a847f52 is first bad commit
commit f894e74dc1983062d30d4e1b79bdb90b8a847f52
Author: Jaswinder Singh Rajput <jaswinder@kernel.org>
Date:   Fri Apr 3 01:42:50 2009 +0530

    [SCSI] qlogicpti: use request_firmware
   
    Firmware blob is little endian
   
    Thanks to Stephen Rothwell for fixing typos
   
    Signed-off-by: Jaswinder Singh Rajput <jaswinderrajput@gmail.com>
    Signed-off-by: James Bottomley <James.Bottomley@HansenPartnership.com>

It's an sbus module but not one I'm using.  I had to disable module
versioning and enable forced module loading to get around the
module loading bug fixed shortly after this series.

May 27 21:19:42 ss20-1 kernel: [42949376.370000] Freeing unused kernel 
memory: 132k freed
May 27 21:19:42 ss20-1 kernel: [42949377.210000] input: Sun Mouse as 
/class/input/input0
May 27 21:19:42 ss20-1 kernel: [42949378.400000] SCSI subsystem initialized
May 27 21:19:42 ss20-1 kernel: [42949378.540000] esp: esp0, 
regs[fd407000:fd406000] irq[36]
May 27 21:19:42 ss20-1 kernel: [42949378.550000] esp: esp0 is a FAS100A, 
40 MHz (ccf=0), SCSI ID 7
May 27 21:19:42 ss20-1 kernel: [42949381.570000] scsi0 : esp
May 27 21:19:42 ss20-1 kernel: [42949381.590000] esp: esp1, 
regs[fd409000:fd408000] irq[53]
May 27 21:19:42 ss20-1 kernel: [42949381.600000] esp: esp1 is a FASHME, 
40 MHz (ccf=0), SCSI ID 7
May 27 21:19:42 ss20-1 kernel: [42949384.620000] scsi1 : esp
May 27 21:19:42 ss20-1 kernel: [42949384.650000] scsi 1:0:0:0: 
Direct-Access     SEAGATE  ST39102LCSUN9.0G 0828 PQ: 0 ANSI: 2
May 27 21:19:42 ss20-1 kernel: [42949384.660000]  target1:0:0: Beginning 
Domain Validation
May 27 21:19:42 ss20-1 kernel: [42949384.680000]  target1:0:0: FAST-10 
WIDE SCSI 20.0 MB/s ST (100 ns, offset 15)
May 27 21:19:42 ss20-1 kernel: [42949384.690000]  target1:0:0: Domain 
Validation skipping write tests
May 27 21:19:42 ss20-1 kernel: [42949384.700000]  target1:0:0: Ending 
Domain Validation
May 27 21:19:42 ss20-1 kernel: [42949389.550000] Driver 'sd' needs 
updating - please use bus_type methods
May 27 21:19:42 ss20-1 kernel: [42949389.580000] sd 1:0:0:0: [sda] 
17689267 512-byte hardware sectors: (9.05 GB/8.43 GiB)
May 27 21:19:42 ss20-1 kernel: [42949389.590000] sd 1:0:0:0: [sda] Write 
Protect is off
May 27 21:19:42 ss20-1 kernel: [42949389.600000] sd 1:0:0:0: [sda] Mode 
Sense: cf 00 10 08
May 27 21:19:42 ss20-1 kernel: [42949389.600000] sd 1:0:0:0: [sda] Write 
cache: disabled, read cache: enabled, supports DPO and FUA
May 27 21:19:42 ss20-1 kernel: [42949389.620000]  sda: sda1 sda2 sda3 sda4
May 27 21:19:42 ss20-1 kernel: [42949389.680000] sd 1:0:0:0: [sda] 
Attached SCSI disk

Re: sparc32 boot problem (SCSI?)

[Robert Reif]

Robert Reif wrote:
> I bisected it down to this but it makes no sense.
>
> f894e74dc1983062d30d4e1b79bdb90b8a847f52 is first bad commit
> commit f894e74dc1983062d30d4e1b79bdb90b8a847f52
> Author: Jaswinder Singh Rajput <jaswinder@kernel.org>
> Date:   Fri Apr 3 01:42:50 2009 +0530
>
>    [SCSI] qlogicpti: use request_firmware
>      Firmware blob is little endian
>      Thanks to Stephen Rothwell for fixing typos
>      Signed-off-by: Jaswinder Singh Rajput <jaswinderrajput@gmail.com>
>    Signed-off-by: James Bottomley <James.Bottomley@HansenPartnership.com>
>
Compiling a kernel without this module produces a working system.

Re: sparc32 boot problem (SCSI?)

[David Miller]

From: Robert Reif <reif@earthlink.net>
Date: Thu, 28 May 2009 20:52:30 -0400

> Robert Reif wrote:
>> I bisected it down to this but it makes no sense.
>>
>> f894e74dc1983062d30d4e1b79bdb90b8a847f52 is first bad commit
>> commit f894e74dc1983062d30d4e1b79bdb90b8a847f52
>> Author: Jaswinder Singh Rajput <jaswinder@kernel.org>
>> Date:   Fri Apr 3 01:42:50 2009 +0530
>>
>>    [SCSI] qlogicpti: use request_firmware
>>      Firmware blob is little endian
>>      Thanks to Stephen Rothwell for fixing typos
>>      Signed-off-by: Jaswinder Singh Rajput <jaswinderrajput@gmail.com>
>>    Signed-off-by: James Bottomley <James.Bottomley@HansenPartnership.com>
>>
> Compiling a kernel without this module produces a working system.

Strange bug indeed.

Did you have this built statically into the kernel or modular?

If statically, the change may have taken your image over the limit for
bootable image size on sparc32.

If modular, that's very mysterious.  The probe code of this driver
should not even execute without an actual qlogicpti card in your
machine, and that's the only thing really modified here.