2011-03-22 07:52:15

by Belisko Marek

[permalink] [raw]
Subject: [bisect] kernel 2.6.38 regression with root nfs mounting

CC: also lkml

After update from 2.6.38-rc8 to 2.6.38 is mounting rootfs over nfs not possible.
Log:
VFS: Mounted root (nfs filesystem) on device 0:14.
Freeing init memory: 132K
nfs: server 10.146.1.21 not responding, still trying
nfs: server 10.146.1.21 not responding, still trying

This is never ending. I make short bisect (not too much commits
between versions)
and bad commit was reported: 53d4737580535e073963b91ce87d4216e434fab5

NFS: NFSROOT should default to "proto=udp"

I've tested on mini2440 board (DM9000, static IP).
Is there some missing option or something else to be checked?

Regards,

marek

--
as simple and primitive as possible
-------------------------------------------------
Marek Belisko - OPEN-NANDRA
Freelance Developer

Ruska Nova Ves 219 | Presov, 08005 Slovak Republic
Tel: +421 915 052 184
skype: marekwhite
icq: 290551086
web: http://open-nandra.com


2011-03-22 13:34:15

by Steven Rostedt

[permalink] [raw]
Subject: Re: [bisect] kernel 2.6.38 regression with root nfs mounting

On Tue, Mar 22, 2011 at 08:52:12AM +0100, Belisko Marek wrote:
> CC: also lkml

And please Cc those that are on that commit.


>
> After update from 2.6.38-rc8 to 2.6.38 is mounting rootfs over nfs not possible.
> Log:
> VFS: Mounted root (nfs filesystem) on device 0:14.
> Freeing init memory: 132K
> nfs: server 10.146.1.21 not responding, still trying
> nfs: server 10.146.1.21 not responding, still trying
>
> This is never ending. I make short bisect (not too much commits
> between versions)
> and bad commit was reported: 53d4737580535e073963b91ce87d4216e434fab5
>
> NFS: NFSROOT should default to "proto=udp"
>
> I've tested on mini2440 board (DM9000, static IP).
> Is there some missing option or something else to be checked?

Sometimes git bisect messes up. Did you verify that commit broke the
kernel? It's easy to do:

git checkout 53d4737580535e073963b91ce87d4216e434fab5~1

then build and boot the kernel and test if it works.

git checkout 53d4737580535e073963b91ce87d4216e434fab5

then build and boot again and test if it fails.

If the first checkout works and the second fails, then you have verified
that is the guilty commit.

Thanks,

-- Steve

>
> Regards,
>
> marek
>
> --
> as simple and primitive as possible
> -------------------------------------------------
> Marek Belisko - OPEN-NANDRA
> Freelance Developer
>
> Ruska Nova Ves 219 | Presov, 08005 Slovak Republic
> Tel: +421 915 052 184
> skype: marekwhite
> icq: 290551086
> web: http://open-nandra.com

2011-03-23 06:06:03

by Belisko Marek

[permalink] [raw]
Subject: Re: [bisect] kernel 2.6.38 regression with root nfs mounting

On Tue, Mar 22, 2011 at 2:34 PM, Steven Rostedt <[email protected]> wrote:
> On Tue, Mar 22, 2011 at 08:52:12AM +0100, Belisko Marek wrote:
>> CC: also lkml
>
> And please Cc those that are on that commit.
>
>
>>
>> After update from 2.6.38-rc8 to 2.6.38 is mounting rootfs over nfs not possible.
>> Log:
>> VFS: Mounted root (nfs filesystem) on device 0:14.
>> Freeing init memory: 132K
>> nfs: server 10.146.1.21 not responding, still trying
>> nfs: server 10.146.1.21 not responding, still trying
>>
>> This is never ending. I make short bisect (not too much commits
>> between versions)
>> and bad commit was reported: 53d4737580535e073963b91ce87d4216e434fab5
>>
>> NFS: NFSROOT should default to "proto=udp"
>>
>> I've tested on mini2440 board (DM9000, static IP).
>> Is there some missing option or something else to be checked?
>
> Sometimes git bisect messes up. Did you verify that commit broke the
> kernel? It's easy to do:
Sure I did same thing to check if bisect is correct. I try to check also patch
but after short look it doesn't seems to be something strange or guilty there.
>
> git checkout 53d4737580535e073963b91ce87d4216e434fab5~1
>
> then build and boot the kernel and test if it works.
>
> git checkout 53d4737580535e073963b91ce87d4216e434fab5
>
> then build and boot again and test if it fails.
>
> If the first checkout works and the second fails, then you have verified
> that is the guilty commit.
>
> Thanks,
>
> -- Steve
>
>>
>> Regards,
>>
>> marek
>>
>> --
>> as simple and primitive as possible
>> -------------------------------------------------
>> Marek Belisko - OPEN-NANDRA
>> Freelance Developer
>>
>> Ruska Nova Ves 219 | Presov, 08005 Slovak Republic
>> Tel: +421 915 052 184
>> skype: marekwhite
>> icq: 290551086
>> web: http://open-nandra.com
>

regards,

marek

--
as simple and primitive as possible
-------------------------------------------------
Marek Belisko - OPEN-NANDRA
Freelance Developer

Ruska Nova Ves 219 | Presov, 08005 Slovak Republic
Tel: +421 915 052 184
skype: marekwhite
icq: 290551086
web: http://open-nandra.com

2011-03-23 06:30:57

by Belisko Marek

[permalink] [raw]
Subject: Re: [bisect] kernel 2.6.38 regression with root nfs mounting

Added linux-nfs to CC (to keep history) add added log with nfsdebugroot enabled.

On Tue, Mar 22, 2011 at 1:34 PM, Chuck Lever <[email protected]> wrote:
>
> On Mar 22, 2011, at 3:51 AM, Belisko Marek wrote:
>
>> After update from 2.6.38-rc8 to 2.6.38 is mounting rootfs over nfs not possible.
>> Log:
>> VFS: Mounted root (nfs filesystem) on device 0:14.
>> Freeing init memory: 132K
>> nfs: server 10.146.1.21 not responding, still trying
>> nfs: server 10.146.1.21 not responding, still trying
>>
>> This is never ending. I make short bisect (not too much commits
>> between versions)
>> and bad commit was reported: 53d4737580535e073963b91ce87d4216e434fab5
>>
>> NFS: NFSROOT should default to "proto=udp"
>>
>> I've tested on mini2440 board (DM9000, static IP).
>> Is there some missing option or something else to be checked?
>
> NFSROOT is supposed to work as it did before 2.6.37.
>
> Enable NFSROOT debugging (see the description of nfsrootdebug in Documentation/filesystems/nfs/nfsroot.txt), try your boot, and then post the contents of your system log to [email protected].
>
> --
> Chuck Lever
> chuck[dot]lever[at]oracle[dot]com
>
>
>
>
>

Linux version 2.6.38-rc7+ (open-nandra@host) (gcc version 4.5.1
(Sourcery G++ Lite 2010.09-50) ) #1 Wed Mar 23 07:23:36 CET 2011
CPU: ARM920T [41129200] revision 0 (ARMv4T), cr=c0007177
CPU: VIVT data cache, VIVT instruction cache
Machine: MINI2440
Memory policy: ECC disabled, Data cache writeback
CPU S3C2440A (id 0x32440001)
S3C24XX Clocks, Copyright 2004 Simtec Electronics
S3C244X: core 405.000 MHz, memory 101.250 MHz, peripheral 50.625 MHz
CLOCK: Slow mode (1.500 MHz), fast, MPLL on, UPLL on
Built 1 zonelists in Zone order, mobility grouping on. Total pages: 16256
Kernel command line: console=ttySAC0,115200 noinitrd init=/sbin/init
mini2440=1b nfsrootdebug root=/dev/nfs rw
nfsroot=10.146.1.21:/home/open-nandra/rootfs
ip=10.146.1.199:10.146.1.21::255.20
PID hash table entries: 256 (order: -2, 1024 bytes)
Dentry cache hash table entries: 8192 (order: 3, 32768 bytes)
Inode-cache hash table entries: 4096 (order: 2, 16384 bytes)
Memory: 64MB = 64MB total
Memory: 60536k/60536k available, 5000k reserved, 0K highmem
Virtual kernel memory layout:
vector : 0xffff0000 - 0xffff1000 ( 4 kB)
fixmap : 0xfff00000 - 0xfffe0000 ( 896 kB)
DMA : 0xffc00000 - 0xffe00000 ( 2 MB)
vmalloc : 0xc4800000 - 0xf6000000 ( 792 MB)
lowmem : 0xc0000000 - 0xc4000000 ( 64 MB)
modules : 0xbf000000 - 0xc0000000 ( 16 MB)
.init : 0xc0008000 - 0xc0029000 ( 132 kB)
.text : 0xc0029000 - 0xc03e9bb4 (3843 kB)
.data : 0xc03ea000 - 0xc040e220 ( 145 kB)
SLUB: Genslabs=13, HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
NR_IRQS:85
irq: clearing pending status 02000000
irq: clearing subpending status 00000002
Console: colour dummy device 80x30
console [ttySAC0] enabled
Calibrating delay loop... 201.93 BogoMIPS (lpj=504832)
pid_max: default: 32768 minimum: 301
Mount-cache hash table entries: 512
CPU: Testing write buffer coherency: ok
gpiochip_add: gpios 288..303 (GPIOK) failed to register
gpiochip_add: gpios 320..334 (GPIOL) failed to register
gpiochip_add: gpios 352..353 (GPIOM) failed to register
NET: Registered protocol family 16
MINI2440: Option string mini2440=1b
MINI2440: LCD 0:240x320 [1:800x480] 2:1024x768
S3C2440: Initialising architecture
S3C2440: IRQ Support
S3C244X: Clock Support, DVS off
bio: create slab <bio-0> at 0
usbcore: registered new interface driver usbfs
usbcore: registered new interface driver hub
usbcore: registered new device driver usb
s3c-i2c s3c2440-i2c: slave address 0x10
s3c-i2c s3c2440-i2c: bus frequency set to 98 KHz
s3c-i2c s3c2440-i2c: i2c-0: S3C I2C adapter
Advanced Linux Sound Architecture Driver Version 1.0.23.
NET: Registered protocol family 2
IP route cache hash table entries: 1024 (order: 0, 4096 bytes)
TCP established hash table entries: 2048 (order: 2, 16384 bytes)
TCP bind hash table entries: 2048 (order: 1, 8192 bytes)
TCP: Hash tables configured (established 2048 bind 2048)
TCP reno registered
UDP hash table entries: 256 (order: 0, 4096 bytes)
UDP-Lite hash table entries: 256 (order: 0, 4096 bytes)
NET: Registered protocol family 1
RPC: Registered udp transport module.
RPC: Registered tcp transport module.
RPC: Registered tcp NFSv4.1 backchannel transport module.
JFFS2 version 2.2. (NAND) �© 2001-2006 Red Hat, Inc.
ROMFS MTD (C) 2007 Red Hat, Inc.
msgmni has been set to 118
io scheduler noop registered
io scheduler deadline registered
io scheduler cfq registered (default)
Console: switching to colour frame buffer device 200x80
fb0: s3c2410fb frame buffer device
s3c2440-uart.0: ttySAC0 at MMIO 0x50000000 (irq = 70) is a S3C2440
s3c2440-uart.1: ttySAC1 at MMIO 0x50004000 (irq = 73) is a S3C2440
s3c2440-uart.2: ttySAC2 at MMIO 0x50008000 (irq = 76) is a S3C2440
brd: module loaded
at24 0-0050: 1024 byte 24c08 EEPROM, writable, 16 bytes/write
S3C24XX NAND Driver, (c) 2004 Simtec Electronics
s3c24xx-nand s3c2440-nand: Tacls=1, 9ns Twrph0=3 29ns, Twrph1=2 19ns
s3c24xx-nand s3c2440-nand: NAND soft ECC
NAND device: Manufacturer ID: 0xec, Chip ID: 0xda (Samsung NAND 256MiB
3,3V 8-bit)
Creating 4 MTD partitions on "nand":
0x000000000000-0x000000040000 : "u-boot"
ftl_cs: FTL header not found.
0x000000040000-0x000000060000 : "u-boot-env"
ftl_cs: FTL header not found.
0x000000060000-0x000000560000 : "kernel"
ftl_cs: FTL header not found.
0x000000560000-0x000010000000 : "root"
ftl_cs: FTL header not found.
dm9000 Ethernet Driver, V1.31
eth0: dm9000e at c486a300,c486e304 IRQ 51 MAC: 08:08:11:18:12:27 (chip)
ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
s3c2410-ohci s3c2410-ohci: S3C24XX OHCI
s3c2410-ohci s3c2410-ohci: new USB bus registered, assigned bus number 1
s3c2410-ohci s3c2410-ohci: irq 42, io mem 0x49000000
hub 1-0:1.0: USB hub found
hub 1-0:1.0: 2 ports detected
usbcore: registered new interface driver libusual
s3c2440-usbgadget s3c2440-usbgadget: S3C2440: increasing FIFO to 128 bytes
mousedev: PS/2 mouse device common for all mice
input: gpio-keys as /devices/platform/gpio-keys/input/input0
S3C24XX RTC, (c) 2004,2006 Simtec Electronics
s3c-rtc s3c2410-rtc: rtc disabled, re-enabling
s3c-rtc s3c2410-rtc: rtc core: registered s3c as rtc0
i2c /dev entries driver
S3C2410 Watchdog Timer, (c) 2004 Simtec Electronics
s3c2410-wdt s3c2410-wdt: watchdog inactive, reset disabled, irq enabled
cpuidle: using governor ladder
sdhci: Secure Digital Host Controller Interface driver
sdhci: Copyright(c) Pierre Ossman
s3c-sdi s3c2440-sdi: powered down.
s3c-sdi s3c2440-sdi: mmc0 - using pio, sw SDIO IRQ
s3c-sdi s3c2440-sdi: running at 0kHz (requested: 0kHz).
s3c-sdi s3c2440-sdi: running at 398kHz (requested: 400kHz).
s3c-sdi s3c2440-sdi: running at 398kHz (requested: 400kHz).
s3c-sdi s3c2440-sdi: running at 398kHz (requested: 400kHz).
s3c-sdi s3c2440-sdi: running at 398kHz (requested: 400kHz).
s3c-sdi s3c2440-sdi: running at 398kHz (requested: 400kHz).
s3c-sdi s3c2440-sdi: running at 398kHz (requested: 400kHz).
usbcore: registered new interface driver usbhid
usbhid: USB HID core driver
ALSA device list:
No soundcards found.
TCP cubic registered
NET: Registered protocol family 17
Registering the dns_resolver key type
s3c-rtc s3c2410-rtc: setting system clock to 2011-03-23 06:01:06 UTC
(1300860066)
s3c-sdi s3c2440-sdi: running at 398kHz (requested: 400kHz).
s3c-sdi s3c2440-sdi: running at 16875kHz (requested: 25000kHz).
s3c-sdi s3c2440-sdi: running at 16875kHz (requested: 25000kHz).
mmc0: new SD card at address b368
mmcblk0: mmc0:b368 SD 970 MiB
mmcblk0: p1 p2 p3
eth0: link down
IP-Config: Complete:
device=eth0, addr=10.146.1.199, mask=255.255.255.0, gw=255.255.255.255,
host=mini2440, domain=, nis-domain=(none),
bootserver=10.146.1.21, rootserver=10.146.1.21, rootpath=
Root-NFS: nfsroot=/home/open-nandra/rootfs
NFS: nfs mount opts='udp,nolock,addr=10.146.1.21'
NFS: parsing nfs mount option 'udp'
NFS: parsing nfs mount option 'nolock'
NFS: parsing nfs mount option 'addr=10.146.1.21'
NFS: MNTPATH: '/home/open-nandra/rootfs'
NFS: sending MNT request for 10.146.1.21:/home/open-nandra/rootfs
eth0: link up, 100Mbps, full-duplex, lpa 0x45E1
NFS: received 1 auth flavors
NFS: auth flavor[0]: 1
NFS: MNT request succeeded
NFS: using auth flavor 1
VFS: Mounted root (nfs filesystem) on device 0:14.
Freeing init memory: 132K
nfs: server 10.146.1.21 not responding, still trying
nfs: server 10.146.1.21 not responding, still trying

This is behavior for commit 53d4737580535e073963b91ce87d4216e434fab5
For commit before it works properly.


regards,

marek

--
as simple and primitive as possible
-------------------------------------------------
Marek Belisko - OPEN-NANDRA
Freelance Developer

Ruska Nova Ves 219 | Presov, 08005 Slovak Republic
Tel: +421 915 052 184
skype: marekwhite
icq: 290551086
web: http://open-nandra.com

2011-03-23 13:44:23

by Chuck Lever

[permalink] [raw]
Subject: Re: [bisect] kernel 2.6.38 regression with root nfs mounting


On Mar 23, 2011, at 2:30 AM, Belisko Marek wrote:

> Added linux-nfs to CC (to keep history) add added log with nfsdebugroot enabled.
>
> On Tue, Mar 22, 2011 at 1:34 PM, Chuck Lever <[email protected]> wrote:
>>
>> On Mar 22, 2011, at 3:51 AM, Belisko Marek wrote:
>>
>>> After update from 2.6.38-rc8 to 2.6.38 is mounting rootfs over nfs not possible.
>>> Log:
>>> VFS: Mounted root (nfs filesystem) on device 0:14.
>>> Freeing init memory: 132K
>>> nfs: server 10.146.1.21 not responding, still trying
>>> nfs: server 10.146.1.21 not responding, still trying
>>>
>>> This is never ending. I make short bisect (not too much commits
>>> between versions)
>>> and bad commit was reported: 53d4737580535e073963b91ce87d4216e434fab5
>>>
>>> NFS: NFSROOT should default to "proto=udp"
>>>
>>> I've tested on mini2440 board (DM9000, static IP).
>>> Is there some missing option or something else to be checked?
>>
>> NFSROOT is supposed to work as it did before 2.6.37.
>>
>> Enable NFSROOT debugging (see the description of nfsrootdebug in Documentation/filesystems/nfs/nfsroot.txt), try your boot, and then post the contents of your system log to [email protected].
>>
>> --
>> Chuck Lever
>> chuck[dot]lever[at]oracle[dot]com
>>
>>
>>
>>
>>
>
> Linux version 2.6.38-rc7+ (open-nandra@host) (gcc version 4.5.1
> (Sourcery G++ Lite 2010.09-50) ) #1 Wed Mar 23 07:23:36 CET 2011
> CPU: ARM920T [41129200] revision 0 (ARMv4T), cr=c0007177
> CPU: VIVT data cache, VIVT instruction cache
> Machine: MINI2440
> Memory policy: ECC disabled, Data cache writeback
> CPU S3C2440A (id 0x32440001)
> S3C24XX Clocks, Copyright 2004 Simtec Electronics
> S3C244X: core 405.000 MHz, memory 101.250 MHz, peripheral 50.625 MHz
> CLOCK: Slow mode (1.500 MHz), fast, MPLL on, UPLL on
> Built 1 zonelists in Zone order, mobility grouping on. Total pages: 16256
> Kernel command line: console=ttySAC0,115200 noinitrd init=/sbin/init
> mini2440=1b nfsrootdebug root=/dev/nfs rw
> nfsroot=10.146.1.21:/home/open-nandra/rootfs
> ip=10.146.1.199:10.146.1.21::255.20
> PID hash table entries: 256 (order: -2, 1024 bytes)
> Dentry cache hash table entries: 8192 (order: 3, 32768 bytes)
> Inode-cache hash table entries: 4096 (order: 2, 16384 bytes)
> Memory: 64MB = 64MB total
> Memory: 60536k/60536k available, 5000k reserved, 0K highmem
> Virtual kernel memory layout:
> vector : 0xffff0000 - 0xffff1000 ( 4 kB)
> fixmap : 0xfff00000 - 0xfffe0000 ( 896 kB)
> DMA : 0xffc00000 - 0xffe00000 ( 2 MB)
> vmalloc : 0xc4800000 - 0xf6000000 ( 792 MB)
> lowmem : 0xc0000000 - 0xc4000000 ( 64 MB)
> modules : 0xbf000000 - 0xc0000000 ( 16 MB)
> .init : 0xc0008000 - 0xc0029000 ( 132 kB)
> .text : 0xc0029000 - 0xc03e9bb4 (3843 kB)
> .data : 0xc03ea000 - 0xc040e220 ( 145 kB)
> SLUB: Genslabs=13, HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
> NR_IRQS:85
> irq: clearing pending status 02000000
> irq: clearing subpending status 00000002
> Console: colour dummy device 80x30
> console [ttySAC0] enabled
> Calibrating delay loop... 201.93 BogoMIPS (lpj=504832)
> pid_max: default: 32768 minimum: 301
> Mount-cache hash table entries: 512
> CPU: Testing write buffer coherency: ok
> gpiochip_add: gpios 288..303 (GPIOK) failed to register
> gpiochip_add: gpios 320..334 (GPIOL) failed to register
> gpiochip_add: gpios 352..353 (GPIOM) failed to register
> NET: Registered protocol family 16
> MINI2440: Option string mini2440=1b
> MINI2440: LCD 0:240x320 [1:800x480] 2:1024x768
> S3C2440: Initialising architecture
> S3C2440: IRQ Support
> S3C244X: Clock Support, DVS off
> bio: create slab <bio-0> at 0
> usbcore: registered new interface driver usbfs
> usbcore: registered new interface driver hub
> usbcore: registered new device driver usb
> s3c-i2c s3c2440-i2c: slave address 0x10
> s3c-i2c s3c2440-i2c: bus frequency set to 98 KHz
> s3c-i2c s3c2440-i2c: i2c-0: S3C I2C adapter
> Advanced Linux Sound Architecture Driver Version 1.0.23.
> NET: Registered protocol family 2
> IP route cache hash table entries: 1024 (order: 0, 4096 bytes)
> TCP established hash table entries: 2048 (order: 2, 16384 bytes)
> TCP bind hash table entries: 2048 (order: 1, 8192 bytes)
> TCP: Hash tables configured (established 2048 bind 2048)
> TCP reno registered
> UDP hash table entries: 256 (order: 0, 4096 bytes)
> UDP-Lite hash table entries: 256 (order: 0, 4096 bytes)
> NET: Registered protocol family 1
> RPC: Registered udp transport module.
> RPC: Registered tcp transport module.
> RPC: Registered tcp NFSv4.1 backchannel transport module.
> JFFS2 version 2.2. (NAND) �© 2001-2006 Red Hat, Inc.
> ROMFS MTD (C) 2007 Red Hat, Inc.
> msgmni has been set to 118
> io scheduler noop registered
> io scheduler deadline registered
> io scheduler cfq registered (default)
> Console: switching to colour frame buffer device 200x80
> fb0: s3c2410fb frame buffer device
> s3c2440-uart.0: ttySAC0 at MMIO 0x50000000 (irq = 70) is a S3C2440
> s3c2440-uart.1: ttySAC1 at MMIO 0x50004000 (irq = 73) is a S3C2440
> s3c2440-uart.2: ttySAC2 at MMIO 0x50008000 (irq = 76) is a S3C2440
> brd: module loaded
> at24 0-0050: 1024 byte 24c08 EEPROM, writable, 16 bytes/write
> S3C24XX NAND Driver, (c) 2004 Simtec Electronics
> s3c24xx-nand s3c2440-nand: Tacls=1, 9ns Twrph0=3 29ns, Twrph1=2 19ns
> s3c24xx-nand s3c2440-nand: NAND soft ECC
> NAND device: Manufacturer ID: 0xec, Chip ID: 0xda (Samsung NAND 256MiB
> 3,3V 8-bit)
> Creating 4 MTD partitions on "nand":
> 0x000000000000-0x000000040000 : "u-boot"
> ftl_cs: FTL header not found.
> 0x000000040000-0x000000060000 : "u-boot-env"
> ftl_cs: FTL header not found.
> 0x000000060000-0x000000560000 : "kernel"
> ftl_cs: FTL header not found.
> 0x000000560000-0x000010000000 : "root"
> ftl_cs: FTL header not found.
> dm9000 Ethernet Driver, V1.31
> eth0: dm9000e at c486a300,c486e304 IRQ 51 MAC: 08:08:11:18:12:27 (chip)
> ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
> s3c2410-ohci s3c2410-ohci: S3C24XX OHCI
> s3c2410-ohci s3c2410-ohci: new USB bus registered, assigned bus number 1
> s3c2410-ohci s3c2410-ohci: irq 42, io mem 0x49000000
> hub 1-0:1.0: USB hub found
> hub 1-0:1.0: 2 ports detected
> usbcore: registered new interface driver libusual
> s3c2440-usbgadget s3c2440-usbgadget: S3C2440: increasing FIFO to 128 bytes
> mousedev: PS/2 mouse device common for all mice
> input: gpio-keys as /devices/platform/gpio-keys/input/input0
> S3C24XX RTC, (c) 2004,2006 Simtec Electronics
> s3c-rtc s3c2410-rtc: rtc disabled, re-enabling
> s3c-rtc s3c2410-rtc: rtc core: registered s3c as rtc0
> i2c /dev entries driver
> S3C2410 Watchdog Timer, (c) 2004 Simtec Electronics
> s3c2410-wdt s3c2410-wdt: watchdog inactive, reset disabled, irq enabled
> cpuidle: using governor ladder
> sdhci: Secure Digital Host Controller Interface driver
> sdhci: Copyright(c) Pierre Ossman
> s3c-sdi s3c2440-sdi: powered down.
> s3c-sdi s3c2440-sdi: mmc0 - using pio, sw SDIO IRQ
> s3c-sdi s3c2440-sdi: running at 0kHz (requested: 0kHz).
> s3c-sdi s3c2440-sdi: running at 398kHz (requested: 400kHz).
> s3c-sdi s3c2440-sdi: running at 398kHz (requested: 400kHz).
> s3c-sdi s3c2440-sdi: running at 398kHz (requested: 400kHz).
> s3c-sdi s3c2440-sdi: running at 398kHz (requested: 400kHz).
> s3c-sdi s3c2440-sdi: running at 398kHz (requested: 400kHz).
> s3c-sdi s3c2440-sdi: running at 398kHz (requested: 400kHz).
> usbcore: registered new interface driver usbhid
> usbhid: USB HID core driver
> ALSA device list:
> No soundcards found.
> TCP cubic registered
> NET: Registered protocol family 17
> Registering the dns_resolver key type
> s3c-rtc s3c2410-rtc: setting system clock to 2011-03-23 06:01:06 UTC
> (1300860066)
> s3c-sdi s3c2440-sdi: running at 398kHz (requested: 400kHz).
> s3c-sdi s3c2440-sdi: running at 16875kHz (requested: 25000kHz).
> s3c-sdi s3c2440-sdi: running at 16875kHz (requested: 25000kHz).
> mmc0: new SD card at address b368
> mmcblk0: mmc0:b368 SD 970 MiB
> mmcblk0: p1 p2 p3
> eth0: link down
> IP-Config: Complete:
> device=eth0, addr=10.146.1.199, mask=255.255.255.0, gw=255.255.255.255,
> host=mini2440, domain=, nis-domain=(none),
> bootserver=10.146.1.21, rootserver=10.146.1.21, rootpath=
> Root-NFS: nfsroot=/home/open-nandra/rootfs
> NFS: nfs mount opts='udp,nolock,addr=10.146.1.21'
> NFS: parsing nfs mount option 'udp'
> NFS: parsing nfs mount option 'nolock'
> NFS: parsing nfs mount option 'addr=10.146.1.21'
> NFS: MNTPATH: '/home/open-nandra/rootfs'
> NFS: sending MNT request for 10.146.1.21:/home/open-nandra/rootfs
> eth0: link up, 100Mbps, full-duplex, lpa 0x45E1
> NFS: received 1 auth flavors
> NFS: auth flavor[0]: 1
> NFS: MNT request succeeded
> NFS: using auth flavor 1
> VFS: Mounted root (nfs filesystem) on device 0:14.
> Freeing init memory: 132K
> nfs: server 10.146.1.21 not responding, still trying
> nfs: server 10.146.1.21 not responding, still trying
>
> This is behavior for commit 53d4737580535e073963b91ce87d4216e434fab5
> For commit before it works properly.

What does "rpcinfo -p 10.146.1.21" output look like? Is NFS over UDP enabled on your server?

--
Chuck Lever
chuck[dot]lever[at]oracle[dot]com



2011-03-23 13:46:31

by Belisko Marek

[permalink] [raw]
Subject: Re: [bisect] kernel 2.6.38 regression with root nfs mounting

On Wed, Mar 23, 2011 at 2:44 PM, Chuck Lever <[email protected]> wrote:
>
> On Mar 23, 2011, at 2:30 AM, Belisko Marek wrote:
>
>> Added linux-nfs to CC (to keep history) add added log with nfsdebugroot enabled.
>>
>> On Tue, Mar 22, 2011 at 1:34 PM, Chuck Lever <[email protected]> wrote:
>>>
>>> On Mar 22, 2011, at 3:51 AM, Belisko Marek wrote:
>>>
>>>> After update from 2.6.38-rc8 to 2.6.38 is mounting rootfs over nfs not possible.
>>>> Log:
>>>> VFS: Mounted root (nfs filesystem) on device 0:14.
>>>> Freeing init memory: 132K
>>>> nfs: server 10.146.1.21 not responding, still trying
>>>> nfs: server 10.146.1.21 not responding, still trying
>>>>
>>>> This is never ending. I make short bisect (not too much commits
>>>> between versions)
>>>> and bad commit was reported: 53d4737580535e073963b91ce87d4216e434fab5
>>>>
>>>> NFS: NFSROOT should default to "proto=udp"
>>>>
>>>> I've tested on mini2440 board (DM9000, static IP).
>>>> Is there some missing option or something else to be checked?
>>>
>>> NFSROOT is supposed to work as it did before 2.6.37.
>>>
>>> Enable NFSROOT debugging (see the description of nfsrootdebug in Documentation/filesystems/nfs/nfsroot.txt), try your boot, and then post the contents of your system log to [email protected].
>>>
>>> --
>>> Chuck Lever
>>> chuck[dot]lever[at]oracle[dot]com
>>>
>>>
>>>
>>>
>>>
>>
>> Linux version 2.6.38-rc7+ (open-nandra@host) (gcc version 4.5.1
>> (Sourcery G++ Lite 2010.09-50) ) #1 Wed Mar 23 07:23:36 CET 2011
>> CPU: ARM920T [41129200] revision 0 (ARMv4T), cr=c0007177
>> CPU: VIVT data cache, VIVT instruction cache
>> Machine: MINI2440
>> Memory policy: ECC disabled, Data cache writeback
>> CPU S3C2440A (id 0x32440001)
>> S3C24XX Clocks, Copyright 2004 Simtec Electronics
>> S3C244X: core 405.000 MHz, memory 101.250 MHz, peripheral 50.625 MHz
>> CLOCK: Slow mode (1.500 MHz), fast, MPLL on, UPLL on
>> Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 16256
>> Kernel command line: console=ttySAC0,115200 noinitrd init=/sbin/init
>> mini2440=1b nfsrootdebug root=/dev/nfs rw
>> nfsroot=10.146.1.21:/home/open-nandra/rootfs
>> ip=10.146.1.199:10.146.1.21::255.20
>> PID hash table entries: 256 (order: -2, 1024 bytes)
>> Dentry cache hash table entries: 8192 (order: 3, 32768 bytes)
>> Inode-cache hash table entries: 4096 (order: 2, 16384 bytes)
>> Memory: 64MB = 64MB total
>> Memory: 60536k/60536k available, 5000k reserved, 0K highmem
>> Virtual kernel memory layout:
>>    vector  : 0xffff0000 - 0xffff1000   (   4 kB)
>>    fixmap  : 0xfff00000 - 0xfffe0000   ( 896 kB)
>>    DMA     : 0xffc00000 - 0xffe00000   (   2 MB)
>>    vmalloc : 0xc4800000 - 0xf6000000   ( 792 MB)
>>    lowmem  : 0xc0000000 - 0xc4000000   (  64 MB)
>>    modules : 0xbf000000 - 0xc0000000   (  16 MB)
>>      .init : 0xc0008000 - 0xc0029000   ( 132 kB)
>>      .text : 0xc0029000 - 0xc03e9bb4   (3843 kB)
>>      .data : 0xc03ea000 - 0xc040e220   ( 145 kB)
>> SLUB: Genslabs=13, HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
>> NR_IRQS:85
>> irq: clearing pending status 02000000
>> irq: clearing subpending status 00000002
>> Console: colour dummy device 80x30
>> console [ttySAC0] enabled
>> Calibrating delay loop... 201.93 BogoMIPS (lpj=504832)
>> pid_max: default: 32768 minimum: 301
>> Mount-cache hash table entries: 512
>> CPU: Testing write buffer coherency: ok
>> gpiochip_add: gpios 288..303 (GPIOK) failed to register
>> gpiochip_add: gpios 320..334 (GPIOL) failed to register
>> gpiochip_add: gpios 352..353 (GPIOM) failed to register
>> NET: Registered protocol family 16
>> MINI2440: Option string mini2440=1b
>> MINI2440: LCD 0:240x320 [1:800x480] 2:1024x768
>> S3C2440: Initialising architecture
>> S3C2440: IRQ Support
>> S3C244X: Clock Support, DVS off
>> bio: create slab <bio-0> at 0
>> usbcore: registered new interface driver usbfs
>> usbcore: registered new interface driver hub
>> usbcore: registered new device driver usb
>> s3c-i2c s3c2440-i2c: slave address 0x10
>> s3c-i2c s3c2440-i2c: bus frequency set to 98 KHz
>> s3c-i2c s3c2440-i2c: i2c-0: S3C I2C adapter
>> Advanced Linux Sound Architecture Driver Version 1.0.23.
>> NET: Registered protocol family 2
>> IP route cache hash table entries: 1024 (order: 0, 4096 bytes)
>> TCP established hash table entries: 2048 (order: 2, 16384 bytes)
>> TCP bind hash table entries: 2048 (order: 1, 8192 bytes)
>> TCP: Hash tables configured (established 2048 bind 2048)
>> TCP reno registered
>> UDP hash table entries: 256 (order: 0, 4096 bytes)
>> UDP-Lite hash table entries: 256 (order: 0, 4096 bytes)
>> NET: Registered protocol family 1
>> RPC: Registered udp transport module.
>> RPC: Registered tcp transport module.
>> RPC: Registered tcp NFSv4.1 backchannel transport module.
>> JFFS2 version 2.2. (NAND) �© 2001-2006 Red Hat, Inc.
>> ROMFS MTD (C) 2007 Red Hat, Inc.
>> msgmni has been set to 118
>> io scheduler noop registered
>> io scheduler deadline registered
>> io scheduler cfq registered (default)
>> Console: switching to colour frame buffer device 200x80
>> fb0: s3c2410fb frame buffer device
>> s3c2440-uart.0: ttySAC0 at MMIO 0x50000000 (irq = 70) is a S3C2440
>> s3c2440-uart.1: ttySAC1 at MMIO 0x50004000 (irq = 73) is a S3C2440
>> s3c2440-uart.2: ttySAC2 at MMIO 0x50008000 (irq = 76) is a S3C2440
>> brd: module loaded
>> at24 0-0050: 1024 byte 24c08 EEPROM, writable, 16 bytes/write
>> S3C24XX NAND Driver, (c) 2004 Simtec Electronics
>> s3c24xx-nand s3c2440-nand: Tacls=1, 9ns Twrph0=3 29ns, Twrph1=2 19ns
>> s3c24xx-nand s3c2440-nand: NAND soft ECC
>> NAND device: Manufacturer ID: 0xec, Chip ID: 0xda (Samsung NAND 256MiB
>> 3,3V 8-bit)
>> Creating 4 MTD partitions on "nand":
>> 0x000000000000-0x000000040000 : "u-boot"
>> ftl_cs: FTL header not found.
>> 0x000000040000-0x000000060000 : "u-boot-env"
>> ftl_cs: FTL header not found.
>> 0x000000060000-0x000000560000 : "kernel"
>> ftl_cs: FTL header not found.
>> 0x000000560000-0x000010000000 : "root"
>> ftl_cs: FTL header not found.
>> dm9000 Ethernet Driver, V1.31
>> eth0: dm9000e at c486a300,c486e304 IRQ 51 MAC: 08:08:11:18:12:27 (chip)
>> ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
>> s3c2410-ohci s3c2410-ohci: S3C24XX OHCI
>> s3c2410-ohci s3c2410-ohci: new USB bus registered, assigned bus number 1
>> s3c2410-ohci s3c2410-ohci: irq 42, io mem 0x49000000
>> hub 1-0:1.0: USB hub found
>> hub 1-0:1.0: 2 ports detected
>> usbcore: registered new interface driver libusual
>> s3c2440-usbgadget s3c2440-usbgadget: S3C2440: increasing FIFO to 128 bytes
>> mousedev: PS/2 mouse device common for all mice
>> input: gpio-keys as /devices/platform/gpio-keys/input/input0
>> S3C24XX RTC, (c) 2004,2006 Simtec Electronics
>> s3c-rtc s3c2410-rtc: rtc disabled, re-enabling
>> s3c-rtc s3c2410-rtc: rtc core: registered s3c as rtc0
>> i2c /dev entries driver
>> S3C2410 Watchdog Timer, (c) 2004 Simtec Electronics
>> s3c2410-wdt s3c2410-wdt: watchdog inactive, reset disabled, irq enabled
>> cpuidle: using governor ladder
>> sdhci: Secure Digital Host Controller Interface driver
>> sdhci: Copyright(c) Pierre Ossman
>> s3c-sdi s3c2440-sdi: powered down.
>> s3c-sdi s3c2440-sdi: mmc0 - using pio, sw SDIO IRQ
>> s3c-sdi s3c2440-sdi: running at 0kHz (requested: 0kHz).
>> s3c-sdi s3c2440-sdi: running at 398kHz (requested: 400kHz).
>> s3c-sdi s3c2440-sdi: running at 398kHz (requested: 400kHz).
>> s3c-sdi s3c2440-sdi: running at 398kHz (requested: 400kHz).
>> s3c-sdi s3c2440-sdi: running at 398kHz (requested: 400kHz).
>> s3c-sdi s3c2440-sdi: running at 398kHz (requested: 400kHz).
>> s3c-sdi s3c2440-sdi: running at 398kHz (requested: 400kHz).
>> usbcore: registered new interface driver usbhid
>> usbhid: USB HID core driver
>> ALSA device list:
>>  No soundcards found.
>> TCP cubic registered
>> NET: Registered protocol family 17
>> Registering the dns_resolver key type
>> s3c-rtc s3c2410-rtc: setting system clock to 2011-03-23 06:01:06 UTC
>> (1300860066)
>> s3c-sdi s3c2440-sdi: running at 398kHz (requested: 400kHz).
>> s3c-sdi s3c2440-sdi: running at 16875kHz (requested: 25000kHz).
>> s3c-sdi s3c2440-sdi: running at 16875kHz (requested: 25000kHz).
>> mmc0: new SD card at address b368
>> mmcblk0: mmc0:b368 SD    970 MiB
>> mmcblk0: p1 p2 p3
>> eth0: link down
>> IP-Config: Complete:
>>     device=eth0, addr=10.146.1.199, mask=255.255.255.0, gw=255.255.255.255,
>>     host=mini2440, domain=, nis-domain=(none),
>>     bootserver=10.146.1.21, rootserver=10.146.1.21, rootpath=
>> Root-NFS: nfsroot=/home/open-nandra/rootfs
>> NFS: nfs mount opts='udp,nolock,addr=10.146.1.21'
>> NFS:   parsing nfs mount option 'udp'
>> NFS:   parsing nfs mount option 'nolock'
>> NFS:   parsing nfs mount option 'addr=10.146.1.21'
>> NFS: MNTPATH: '/home/open-nandra/rootfs'
>> NFS: sending MNT request for 10.146.1.21:/home/open-nandra/rootfs
>> eth0: link up, 100Mbps, full-duplex, lpa 0x45E1
>> NFS: received 1 auth flavors
>> NFS:   auth flavor[0]: 1
>> NFS: MNT request succeeded
>> NFS: using auth flavor 1
>> VFS: Mounted root (nfs filesystem) on device 0:14.
>> Freeing init memory: 132K
>> nfs: server 10.146.1.21 not responding, still trying
>> nfs: server 10.146.1.21 not responding, still trying
>>
>> This is behavior for commit 53d4737580535e073963b91ce87d4216e434fab5
>> For commit before it works properly.
>
> What does "rpcinfo -p 10.146.1.21" output look like?  Is NFS over UDP enabled on your server?
program vers proto port
100000 2 tcp 111 portmapper
100000 2 udp 111 portmapper
100024 1 udp 40517 status
100024 1 tcp 51397 status
100021 1 udp 44516 nlockmgr
100021 3 udp 44516 nlockmgr
100021 4 udp 44516 nlockmgr
100021 1 tcp 55152 nlockmgr
100021 3 tcp 55152 nlockmgr
100021 4 tcp 55152 nlockmgr
100003 2 tcp 2049 nfs
100003 3 tcp 2049 nfs
100003 4 tcp 2049 nfs
100227 2 tcp 2049
100227 3 tcp 2049
100003 2 udp 2049 nfs
100003 3 udp 2049 nfs
100003 4 udp 2049 nfs
100227 2 udp 2049
100227 3 udp 2049
100005 1 udp 58278 mountd
100005 1 tcp 37178 mountd
100005 2 udp 58278 mountd
100005 2 tcp 37178 mountd
100005 3 udp 58278 mountd
100005 3 tcp 37178 mountd

>
> --
> Chuck Lever
> chuck[dot]lever[at]oracle[dot]com
>
>
>
>
>

regards,

marek

--
as simple and primitive as possible
-------------------------------------------------
Marek Belisko - OPEN-NANDRA
Freelance Developer

Ruska Nova Ves 219 | Presov, 08005 Slovak Republic
Tel: +421 915 052 184
skype: marekwhite
icq: 290551086
web: http://open-nandra.com

2011-03-23 14:06:38

by Chuck Lever

[permalink] [raw]
Subject: Re: [bisect] kernel 2.6.38 regression with root nfs mounting


On Mar 23, 2011, at 9:46 AM, Belisko Marek wrote:

> On Wed, Mar 23, 2011 at 2:44 PM, Chuck Lever <[email protected]> wrote:
>>
>> On Mar 23, 2011, at 2:30 AM, Belisko Marek wrote:
>>
>>> Added linux-nfs to CC (to keep history) add added log with nfsdebugroot enabled.
>>>
>>> On Tue, Mar 22, 2011 at 1:34 PM, Chuck Lever <[email protected]> wrote:
>>>>
>>>> On Mar 22, 2011, at 3:51 AM, Belisko Marek wrote:
>>>>
>>>>> After update from 2.6.38-rc8 to 2.6.38 is mounting rootfs over nfs not possible.
>>>>> Log:
>>>>> VFS: Mounted root (nfs filesystem) on device 0:14.
>>>>> Freeing init memory: 132K
>>>>> nfs: server 10.146.1.21 not responding, still trying
>>>>> nfs: server 10.146.1.21 not responding, still trying
>>>>>
>>>>> This is never ending. I make short bisect (not too much commits
>>>>> between versions)
>>>>> and bad commit was reported: 53d4737580535e073963b91ce87d4216e434fab5
>>>>>
>>>>> NFS: NFSROOT should default to "proto=udp"
>>>>>
>>>>> I've tested on mini2440 board (DM9000, static IP).
>>>>> Is there some missing option or something else to be checked?
>>>>
>>>> NFSROOT is supposed to work as it did before 2.6.37.
>>>>
>>>> Enable NFSROOT debugging (see the description of nfsrootdebug in Documentation/filesystems/nfs/nfsroot.txt), try your boot, and then post the contents of your system log to [email protected].
>>>>
>>>> --
>>>> Chuck Lever
>>>> chuck[dot]lever[at]oracle[dot]com
>>>>
>>>>
>>>>
>>>>
>>>>
>>>
>>> Linux version 2.6.38-rc7+ (open-nandra@host) (gcc version 4.5.1
>>> (Sourcery G++ Lite 2010.09-50) ) #1 Wed Mar 23 07:23:36 CET 2011
>>> CPU: ARM920T [41129200] revision 0 (ARMv4T), cr=c0007177
>>> CPU: VIVT data cache, VIVT instruction cache
>>> Machine: MINI2440
>>> Memory policy: ECC disabled, Data cache writeback
>>> CPU S3C2440A (id 0x32440001)
>>> S3C24XX Clocks, Copyright 2004 Simtec Electronics
>>> S3C244X: core 405.000 MHz, memory 101.250 MHz, peripheral 50.625 MHz
>>> CLOCK: Slow mode (1.500 MHz), fast, MPLL on, UPLL on
>>> Built 1 zonelists in Zone order, mobility grouping on. Total pages: 16256
>>> Kernel command line: console=ttySAC0,115200 noinitrd init=/sbin/init
>>> mini2440=1b nfsrootdebug root=/dev/nfs rw
>>> nfsroot=10.146.1.21:/home/open-nandra/rootfs
>>> ip=10.146.1.199:10.146.1.21::255.20
>>> PID hash table entries: 256 (order: -2, 1024 bytes)
>>> Dentry cache hash table entries: 8192 (order: 3, 32768 bytes)
>>> Inode-cache hash table entries: 4096 (order: 2, 16384 bytes)
>>> Memory: 64MB = 64MB total
>>> Memory: 60536k/60536k available, 5000k reserved, 0K highmem
>>> Virtual kernel memory layout:
>>> vector : 0xffff0000 - 0xffff1000 ( 4 kB)
>>> fixmap : 0xfff00000 - 0xfffe0000 ( 896 kB)
>>> DMA : 0xffc00000 - 0xffe00000 ( 2 MB)
>>> vmalloc : 0xc4800000 - 0xf6000000 ( 792 MB)
>>> lowmem : 0xc0000000 - 0xc4000000 ( 64 MB)
>>> modules : 0xbf000000 - 0xc0000000 ( 16 MB)
>>> .init : 0xc0008000 - 0xc0029000 ( 132 kB)
>>> .text : 0xc0029000 - 0xc03e9bb4 (3843 kB)
>>> .data : 0xc03ea000 - 0xc040e220 ( 145 kB)
>>> SLUB: Genslabs=13, HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
>>> NR_IRQS:85
>>> irq: clearing pending status 02000000
>>> irq: clearing subpending status 00000002
>>> Console: colour dummy device 80x30
>>> console [ttySAC0] enabled
>>> Calibrating delay loop... 201.93 BogoMIPS (lpj=504832)
>>> pid_max: default: 32768 minimum: 301
>>> Mount-cache hash table entries: 512
>>> CPU: Testing write buffer coherency: ok
>>> gpiochip_add: gpios 288..303 (GPIOK) failed to register
>>> gpiochip_add: gpios 320..334 (GPIOL) failed to register
>>> gpiochip_add: gpios 352..353 (GPIOM) failed to register
>>> NET: Registered protocol family 16
>>> MINI2440: Option string mini2440=1b
>>> MINI2440: LCD 0:240x320 [1:800x480] 2:1024x768
>>> S3C2440: Initialising architecture
>>> S3C2440: IRQ Support
>>> S3C244X: Clock Support, DVS off
>>> bio: create slab <bio-0> at 0
>>> usbcore: registered new interface driver usbfs
>>> usbcore: registered new interface driver hub
>>> usbcore: registered new device driver usb
>>> s3c-i2c s3c2440-i2c: slave address 0x10
>>> s3c-i2c s3c2440-i2c: bus frequency set to 98 KHz
>>> s3c-i2c s3c2440-i2c: i2c-0: S3C I2C adapter
>>> Advanced Linux Sound Architecture Driver Version 1.0.23.
>>> NET: Registered protocol family 2
>>> IP route cache hash table entries: 1024 (order: 0, 4096 bytes)
>>> TCP established hash table entries: 2048 (order: 2, 16384 bytes)
>>> TCP bind hash table entries: 2048 (order: 1, 8192 bytes)
>>> TCP: Hash tables configured (established 2048 bind 2048)
>>> TCP reno registered
>>> UDP hash table entries: 256 (order: 0, 4096 bytes)
>>> UDP-Lite hash table entries: 256 (order: 0, 4096 bytes)
>>> NET: Registered protocol family 1
>>> RPC: Registered udp transport module.
>>> RPC: Registered tcp transport module.
>>> RPC: Registered tcp NFSv4.1 backchannel transport module.
>>> JFFS2 version 2.2. (NAND) �© 2001-2006 Red Hat, Inc.
>>> ROMFS MTD (C) 2007 Red Hat, Inc.
>>> msgmni has been set to 118
>>> io scheduler noop registered
>>> io scheduler deadline registered
>>> io scheduler cfq registered (default)
>>> Console: switching to colour frame buffer device 200x80
>>> fb0: s3c2410fb frame buffer device
>>> s3c2440-uart.0: ttySAC0 at MMIO 0x50000000 (irq = 70) is a S3C2440
>>> s3c2440-uart.1: ttySAC1 at MMIO 0x50004000 (irq = 73) is a S3C2440
>>> s3c2440-uart.2: ttySAC2 at MMIO 0x50008000 (irq = 76) is a S3C2440
>>> brd: module loaded
>>> at24 0-0050: 1024 byte 24c08 EEPROM, writable, 16 bytes/write
>>> S3C24XX NAND Driver, (c) 2004 Simtec Electronics
>>> s3c24xx-nand s3c2440-nand: Tacls=1, 9ns Twrph0=3 29ns, Twrph1=2 19ns
>>> s3c24xx-nand s3c2440-nand: NAND soft ECC
>>> NAND device: Manufacturer ID: 0xec, Chip ID: 0xda (Samsung NAND 256MiB
>>> 3,3V 8-bit)
>>> Creating 4 MTD partitions on "nand":
>>> 0x000000000000-0x000000040000 : "u-boot"
>>> ftl_cs: FTL header not found.
>>> 0x000000040000-0x000000060000 : "u-boot-env"
>>> ftl_cs: FTL header not found.
>>> 0x000000060000-0x000000560000 : "kernel"
>>> ftl_cs: FTL header not found.
>>> 0x000000560000-0x000010000000 : "root"
>>> ftl_cs: FTL header not found.
>>> dm9000 Ethernet Driver, V1.31
>>> eth0: dm9000e at c486a300,c486e304 IRQ 51 MAC: 08:08:11:18:12:27 (chip)
>>> ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
>>> s3c2410-ohci s3c2410-ohci: S3C24XX OHCI
>>> s3c2410-ohci s3c2410-ohci: new USB bus registered, assigned bus number 1
>>> s3c2410-ohci s3c2410-ohci: irq 42, io mem 0x49000000
>>> hub 1-0:1.0: USB hub found
>>> hub 1-0:1.0: 2 ports detected
>>> usbcore: registered new interface driver libusual
>>> s3c2440-usbgadget s3c2440-usbgadget: S3C2440: increasing FIFO to 128 bytes
>>> mousedev: PS/2 mouse device common for all mice
>>> input: gpio-keys as /devices/platform/gpio-keys/input/input0
>>> S3C24XX RTC, (c) 2004,2006 Simtec Electronics
>>> s3c-rtc s3c2410-rtc: rtc disabled, re-enabling
>>> s3c-rtc s3c2410-rtc: rtc core: registered s3c as rtc0
>>> i2c /dev entries driver
>>> S3C2410 Watchdog Timer, (c) 2004 Simtec Electronics
>>> s3c2410-wdt s3c2410-wdt: watchdog inactive, reset disabled, irq enabled
>>> cpuidle: using governor ladder
>>> sdhci: Secure Digital Host Controller Interface driver
>>> sdhci: Copyright(c) Pierre Ossman
>>> s3c-sdi s3c2440-sdi: powered down.
>>> s3c-sdi s3c2440-sdi: mmc0 - using pio, sw SDIO IRQ
>>> s3c-sdi s3c2440-sdi: running at 0kHz (requested: 0kHz).
>>> s3c-sdi s3c2440-sdi: running at 398kHz (requested: 400kHz).
>>> s3c-sdi s3c2440-sdi: running at 398kHz (requested: 400kHz).
>>> s3c-sdi s3c2440-sdi: running at 398kHz (requested: 400kHz).
>>> s3c-sdi s3c2440-sdi: running at 398kHz (requested: 400kHz).
>>> s3c-sdi s3c2440-sdi: running at 398kHz (requested: 400kHz).
>>> s3c-sdi s3c2440-sdi: running at 398kHz (requested: 400kHz).
>>> usbcore: registered new interface driver usbhid
>>> usbhid: USB HID core driver
>>> ALSA device list:
>>> No soundcards found.
>>> TCP cubic registered
>>> NET: Registered protocol family 17
>>> Registering the dns_resolver key type
>>> s3c-rtc s3c2410-rtc: setting system clock to 2011-03-23 06:01:06 UTC
>>> (1300860066)
>>> s3c-sdi s3c2440-sdi: running at 398kHz (requested: 400kHz).
>>> s3c-sdi s3c2440-sdi: running at 16875kHz (requested: 25000kHz).
>>> s3c-sdi s3c2440-sdi: running at 16875kHz (requested: 25000kHz).
>>> mmc0: new SD card at address b368
>>> mmcblk0: mmc0:b368 SD 970 MiB
>>> mmcblk0: p1 p2 p3
>>> eth0: link down
>>> IP-Config: Complete:
>>> device=eth0, addr=10.146.1.199, mask=255.255.255.0, gw=255.255.255.255,
>>> host=mini2440, domain=, nis-domain=(none),
>>> bootserver=10.146.1.21, rootserver=10.146.1.21, rootpath=
>>> Root-NFS: nfsroot=/home/open-nandra/rootfs
>>> NFS: nfs mount opts='udp,nolock,addr=10.146.1.21'
>>> NFS: parsing nfs mount option 'udp'
>>> NFS: parsing nfs mount option 'nolock'
>>> NFS: parsing nfs mount option 'addr=10.146.1.21'
>>> NFS: MNTPATH: '/home/open-nandra/rootfs'
>>> NFS: sending MNT request for 10.146.1.21:/home/open-nandra/rootfs
>>> eth0: link up, 100Mbps, full-duplex, lpa 0x45E1
>>> NFS: received 1 auth flavors
>>> NFS: auth flavor[0]: 1
>>> NFS: MNT request succeeded
>>> NFS: using auth flavor 1
>>> VFS: Mounted root (nfs filesystem) on device 0:14.
>>> Freeing init memory: 132K
>>> nfs: server 10.146.1.21 not responding, still trying
>>> nfs: server 10.146.1.21 not responding, still trying
>>>
>>> This is behavior for commit 53d4737580535e073963b91ce87d4216e434fab5
>>> For commit before it works properly.
>>
>> What does "rpcinfo -p 10.146.1.21" output look like? Is NFS over UDP enabled on your server?
> program vers proto port
> 100000 2 tcp 111 portmapper
> 100000 2 udp 111 portmapper
> 100024 1 udp 40517 status
> 100024 1 tcp 51397 status
> 100021 1 udp 44516 nlockmgr
> 100021 3 udp 44516 nlockmgr
> 100021 4 udp 44516 nlockmgr
> 100021 1 tcp 55152 nlockmgr
> 100021 3 tcp 55152 nlockmgr
> 100021 4 tcp 55152 nlockmgr
> 100003 2 tcp 2049 nfs
> 100003 3 tcp 2049 nfs
> 100003 4 tcp 2049 nfs
> 100227 2 tcp 2049
> 100227 3 tcp 2049
> 100003 2 udp 2049 nfs
> 100003 3 udp 2049 nfs
> 100003 4 udp 2049 nfs
> 100227 2 udp 2049
> 100227 3 udp 2049
> 100005 1 udp 58278 mountd
> 100005 1 tcp 37178 mountd
> 100005 2 udp 58278 mountd
> 100005 2 tcp 37178 mountd
> 100005 3 udp 58278 mountd
> 100005 3 tcp 37178 mountd

Can you boot if you specify either the "tcp" or "proto=tcp" NFSROOT mount options?

Perhaps a network trace would be probative. Capture on the server with "tcpdump -s0 -w /tmp/foo ip 10.146.1.199" (untested, but I think you get the idea) while the client is attempting to boot, and post.

--
Chuck Lever
chuck[dot]lever[at]oracle[dot]com



2011-03-23 14:54:51

by Chuck Lever

[permalink] [raw]
Subject: Re: [bisect] kernel 2.6.38 regression with root nfs mounting


On Mar 23, 2011, at 10:30 AM, Belisko Marek wrote:

> On Wed, Mar 23, 2011 at 3:06 PM, Chuck Lever <[email protected]> wrote:
>>
>> On Mar 23, 2011, at 9:46 AM, Belisko Marek wrote:
>>
>>> On Wed, Mar 23, 2011 at 2:44 PM, Chuck Lever <[email protected]> wrote:
>>>>
>>>> What does "rpcinfo -p 10.146.1.21" output look like? Is NFS over UDP enabled on your server?
>>> program vers proto port
>>> 100000 2 tcp 111 portmapper
>>> 100000 2 udp 111 portmapper
>>> 100024 1 udp 40517 status
>>> 100024 1 tcp 51397 status
>>> 100021 1 udp 44516 nlockmgr
>>> 100021 3 udp 44516 nlockmgr
>>> 100021 4 udp 44516 nlockmgr
>>> 100021 1 tcp 55152 nlockmgr
>>> 100021 3 tcp 55152 nlockmgr
>>> 100021 4 tcp 55152 nlockmgr
>>> 100003 2 tcp 2049 nfs
>>> 100003 3 tcp 2049 nfs
>>> 100003 4 tcp 2049 nfs
>>> 100227 2 tcp 2049
>>> 100227 3 tcp 2049
>>> 100003 2 udp 2049 nfs
>>> 100003 3 udp 2049 nfs
>>> 100003 4 udp 2049 nfs

The server is advertising NFS over UDP. Why can't a client access your server via UDP? What happens if you perform a normal post-boot mount of this file system via UDP?

>>> 100227 2 udp 2049
>>> 100227 3 udp 2049
>>> 100005 1 udp 58278 mountd
>>> 100005 1 tcp 37178 mountd
>>> 100005 2 udp 58278 mountd
>>> 100005 2 tcp 37178 mountd
>>> 100005 3 udp 58278 mountd
>>> 100005 3 tcp 37178 mountd
>>
>> Can you boot if you specify either the "tcp" or "proto=tcp" NFSROOT mount options?
> When add proto=tcp to bootargs it boot fine
> (....nfsroot=10.146.1.21:/home/open-nandra/rootfs,proto=tcp....).
>> Perhaps a network trace would be probative. Capture on the server with "tcpdump -s0 -w /tmp/foo ip 10.146.1.199" (untested, but I think you get the idea) while the client is attempting to boot, and post.
> Log is attached in attachment (too big 4.8M). Correct form is: tcpdump
> -s0 -w /tmp/foo host 10.146.1.199

Received. I should have been clear: Please capture a non-working client boot attempt. To reduce the size of the attachment, strip the TFTP packets before sending, and please gzip the file.

--
Chuck Lever
chuck[dot]lever[at]oracle[dot]com



2011-03-25 07:25:08

by Belisko Marek

[permalink] [raw]
Subject: Re: [bisect] kernel 2.6.38 regression with root nfs mounting

On Wed, Mar 23, 2011 at 3:54 PM, Chuck Lever <[email protected]> wrote:
>
> On Mar 23, 2011, at 10:30 AM, Belisko Marek wrote:
>
>> On Wed, Mar 23, 2011 at 3:06 PM, Chuck Lever <[email protected]> wrote:
>>>
>>> On Mar 23, 2011, at 9:46 AM, Belisko Marek wrote:
>>>
>>>> On Wed, Mar 23, 2011 at 2:44 PM, Chuck Lever <[email protected]> wrote:
>>>>>
>>>>> What does "rpcinfo -p 10.146.1.21" output look like?  Is NFS over UDP enabled on your server?
>>>> program vers proto   port
>>>>    100000    2   tcp    111  portmapper
>>>>    100000    2   udp    111  portmapper
>>>>    100024    1   udp  40517  status
>>>>    100024    1   tcp  51397  status
>>>>    100021    1   udp  44516  nlockmgr
>>>>    100021    3   udp  44516  nlockmgr
>>>>    100021    4   udp  44516  nlockmgr
>>>>    100021    1   tcp  55152  nlockmgr
>>>>    100021    3   tcp  55152  nlockmgr
>>>>    100021    4   tcp  55152  nlockmgr
>>>>    100003    2   tcp   2049  nfs
>>>>    100003    3   tcp   2049  nfs
>>>>    100003    4   tcp   2049  nfs
>>>>    100227    2   tcp   2049
>>>>    100227    3   tcp   2049
>>>>    100003    2   udp   2049  nfs
>>>>    100003    3   udp   2049  nfs
>>>>    100003    4   udp   2049  nfs
>
> The server is advertising NFS over UDP.  Why can't a client access your server via UDP?  What happens if you perform a normal post-boot mount of this file system via UDP?
Strange (rootfs mounted from SD card and try to mount nfs always fail)

mount -t nfs -o udp 10.146.1.21:/home/open-nandra/rootfs /mnt
svc: failed to register lockdv1 RPC service (errno 111).
lockd_up: makesock failed, error=-111
mount: mounting 10.146.1.21:/home/open-nandra/rootfs on /mnt failed:
Connection refused
# mount -t nfs -o tcp 10.146.1.21:/home/open-nandra/rootfs /mnt
svc: failed to register lockdv1 RPC service (errno 111).
mount: mounting 10.146.1.21:/home/open-nandra/rootfs on /mnt failed:
Connection refused

>
>>>>    100227    2   udp   2049
>>>>    100227    3   udp   2049
>>>>    100005    1   udp  58278  mountd
>>>>    100005    1   tcp  37178  mountd
>>>>    100005    2   udp  58278  mountd
>>>>    100005    2   tcp  37178  mountd
>>>>    100005    3   udp  58278  mountd
>>>>    100005    3   tcp  37178  mountd
>>>
>>> Can you boot if you specify either the "tcp" or "proto=tcp" NFSROOT mount options?
>> When add proto=tcp to bootargs it boot fine
>> (....nfsroot=10.146.1.21:/home/open-nandra/rootfs,proto=tcp....).
>>> Perhaps a network trace would be probative.  Capture on the server with "tcpdump -s0 -w /tmp/foo ip 10.146.1.199" (untested, but I think you get the idea) while the client is attempting to boot, and post.
>> Log is attached in attachment (too big 4.8M). Correct form is: tcpdump
>> -s0 -w /tmp/foo host 10.146.1.199
>
> Received.  I should have been clear: Please capture a non-working client boot attempt.  To reduce the size of the attachment, strip the TFTP packets before sending, and please gzip the file.
tcpdump log from wrong attemp in attachment.
>
> --
> Chuck Lever
> chuck[dot]lever[at]oracle[dot]com
>
>
>
>
>

regards,

marek


--
as simple and primitive as possible
-------------------------------------------------
Marek Belisko - OPEN-NANDRA
Freelance Developer

Ruska Nova Ves 219 | Presov, 08005 Slovak Republic
Tel: +421 915 052 184
skype: marekwhite
icq: 290551086
web: http://open-nandra.com


Attachments:
nfs_server_tcpdump.gz (191.58 kB)

2011-03-25 13:26:30

by Chuck Lever

[permalink] [raw]
Subject: Re: [bisect] kernel 2.6.38 regression with root nfs mounting


On Mar 25, 2011, at 3:24 AM, Belisko Marek wrote:

> On Wed, Mar 23, 2011 at 3:54 PM, Chuck Lever <[email protected]> wrote:
>>
>> On Mar 23, 2011, at 10:30 AM, Belisko Marek wrote:
>>
>> The server is advertising NFS over UDP. Why can't a client access your server via UDP? What happens if you perform a normal post-boot mount of this file system via UDP?
> Strange (rootfs mounted from SD card and try to mount nfs always fail)
>
> mount -t nfs -o udp 10.146.1.21:/home/open-nandra/rootfs /mnt
> svc: failed to register lockdv1 RPC service (errno 111).
> lockd_up: makesock failed, error=-111
> mount: mounting 10.146.1.21:/home/open-nandra/rootfs on /mnt failed:
> Connection refused
> # mount -t nfs -o tcp 10.146.1.21:/home/open-nandra/rootfs /mnt
> svc: failed to register lockdv1 RPC service (errno 111).
> mount: mounting 10.146.1.21:/home/open-nandra/rootfs on /mnt failed:
> Connection refused

The client system isn't running a portmapper that its NFS client (specifically lockd) can talk to. That "connection refused" is due to an incorrect client configuration. A simple workaround might be to specify the "nolock" mount option for this test.

>
>>
>>>>> 100227 2 udp 2049
>>>>> 100227 3 udp 2049
>>>>> 100005 1 udp 58278 mountd
>>>>> 100005 1 tcp 37178 mountd
>>>>> 100005 2 udp 58278 mountd
>>>>> 100005 2 tcp 37178 mountd
>>>>> 100005 3 udp 58278 mountd
>>>>> 100005 3 tcp 37178 mountd
>>>>
>>>> Can you boot if you specify either the "tcp" or "proto=tcp" NFSROOT mount options?
>>> When add proto=tcp to bootargs it boot fine
>>> (....nfsroot=10.146.1.21:/home/open-nandra/rootfs,proto=tcp....).
>>>> Perhaps a network trace would be probative. Capture on the server with "tcpdump -s0 -w /tmp/foo ip 10.146.1.199" (untested, but I think you get the idea) while the client is attempting to boot, and post.
>>> Log is attached in attachment (too big 4.8M). Correct form is: tcpdump
>>> -s0 -w /tmp/foo host 10.146.1.199
>>
>> Received. I should have been clear: Please capture a non-working client boot attempt. To reduce the size of the attachment, strip the TFTP packets before sending, and please gzip the file.
> tcpdump log from wrong attemp in attachment.

According to the trace, the mount succeeds, and NFS requests are working. However, the server's replies to READ requests are not being seen by the client. Something on the client host or in the network is dropping them. I see successful 16KB reads, but 32KB reads do not work. Check your client for packet filtering (either intentional filtering, or accidental filtering due to configuration issues).

I'll revisit the mount option defaults for NFSROOT again.

--
Chuck Lever
chuck[dot]lever[at]oracle[dot]com



2011-03-29 20:48:30

by Will Simoneau

[permalink] [raw]
Subject: Re: [bisect] kernel 2.6.38 regression with root nfs mounting

On 09:26 Fri 25 Mar , Chuck Lever wrote:
>
> According to the trace, the mount succeeds, and NFS requests are working. However, the server's replies to READ requests are not being seen by the client. Something on the client host or in the network is dropping them. I see successful 16KB reads, but 32KB reads do not work. Check your client for packet filtering (either intentional filtering, or accidental filtering due to configuration issues).
>
> I'll revisit the mount option defaults for NFSROOT again.

I have encountered the same problem as Belisko, using an FPGA board I am
working on (CPU is a mipsel r4k clone). 2.6.38-rc8 nfsroot works fine,
2.6.38 hangs while starting init. I can see read replies going out from
the NFS server but the client does not seem to receive them.

Interestingly, we are both using DM9000 network chips. I wonder if there
is a UDP-related problem on the DM9000. I will play with my
configuration a little more (in particular testing proto=tcp and revert
of 53d4737580535e073963b91ce87d4216e434fab5) but my guess is the DM9000
driver/chip is to blame. The DM9000A on my board has 16K of on-chip SRAM
used for its RX/TX buffers which may be playing a part in the problem.


Attachments:
(No filename) (1.19 kB)
(No filename) (198.00 B)
Download all attachments

2011-03-29 21:22:04

by Mark Brown

[permalink] [raw]
Subject: Re: [bisect] kernel 2.6.38 regression with root nfs mounting

On Tue, Mar 29, 2011 at 04:24:08PM -0400, Will Simoneau wrote:

> Interestingly, we are both using DM9000 network chips. I wonder if there
> is a UDP-related problem on the DM9000. I will play with my
> configuration a little more (in particular testing proto=tcp and revert
> of 53d4737580535e073963b91ce87d4216e434fab5) but my guess is the DM9000
> driver/chip is to blame. The DM9000A on my board has 16K of on-chip SRAM
> used for its RX/TX buffers which may be playing a part in the problem.

It's more likely that the DM9000 is just slow and fragile. One thing to
note with a lot of the lower end network chips is that you end up
needing to specify rsize and wsize so that you don't get fragmentation -
about 1k tends to work well IME. Otherwise performance often degrades
to the point of unusability.