Writing big files to NFS target causes system lock up

Bug #561210 reported by Ancoron Luziferis
308
This bug affects 57 people
Affects Status Importance Assigned to Milestone
linux (Ubuntu)
Fix Released
Medium
Tim Gardner
Lucid
Fix Released
Undecided
Tim Gardner
Maverick
Fix Released
Undecided
Tim Gardner
Natty
Fix Released
Medium
Tim Gardner

Bug Description

I'm experiencing complete system lock ups occasionally when writing big files to an NFS target.

I can't remember that I had such issues with Jaunty, but at least Karmic and Lucid are affected in the exact same way.

In most cases just the "mv" or "cp" process hangs for a while, but sometimes the whole system freezes, including X.

Although some things keep running (e.g. the clock on my G15 Keyboard LCD display doesn't freeze, so the g15daemon keeps running as usual), I'm unable to get the system back to a normal state. Even waiting a whole night for the NFS task to finish doesn't succeed. In such a case the NFS server side is completely idle, not receiving any data from the client. I have to hard reset the client machine to get a working system again.

The server is a Busybox NAS system with the following exports options:
rw,no_wdelay,no_root_squash,insecure_locks,no_subtree_check

The clients are mounting with these options:
rw,rsize=32768,wsize=32768,hard,intr,noatime

All machines are connected through a LevelOne GSW-0803T 8-port GBit switch with Cat6e cables. No wireless here. No other issues with networking here. The client machines are both AMD64 AMD Quad-Cores, both have GigaByte mainboards using the internal GBit Ethernet connector for networking.

Some time ago I also used a Dell Inspiron (32-bit Pentium-M system) notebook with a 100MBit connection on this network without such issues.

The following gets logged during one of those lock-ups:

INFO: task mv:26028 blocked for more than 120 seconds.
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
mv D 00000000ffffffff 0 26028 2040 0x00000000
 ffff880100198f08 0000000000000086 0000000000015b80 0000000000015b80
 ffff880001dc83c0 ffff880100199fd8 0000000000015b80 ffff880001dc8000
 0000000000015b80 ffff880100199fd8 0000000000015b80 ffff880001dc83c0
Call Trace:
 [<ffffffffa0418280>] ? nfs_wait_bit_uninterruptible+0x0/0x20 [nfs]
 [<ffffffff8153e697>] io_schedule+0x47/0x70
 [<ffffffffa041828e>] nfs_wait_bit_uninterruptible+0xe/0x20 [nfs]
 [<ffffffff8153eeef>] __wait_on_bit+0x5f/0x90
 [<ffffffff81013cae>] ? apic_timer_interrupt+0xe/0x20
 [<ffffffffa0418280>] ? nfs_wait_bit_uninterruptible+0x0/0x20 [nfs]
 [<ffffffff8153ef98>] out_of_line_wait_on_bit+0x78/0x90
 [<ffffffff81085340>] ? wake_bit_function+0x0/0x40
 [<ffffffffa041826f>] nfs_wait_on_request+0x2f/0x40 [nfs]
 [<ffffffffa041c66f>] nfs_wait_on_requests_locked+0x7f/0xd0 [nfs]
 [<ffffffffa041daae>] nfs_sync_mapping_wait+0x9e/0x1a0 [nfs]
 [<ffffffffa041dc31>] nfs_wb_page+0x81/0xe0 [nfs]
 [<ffffffffa040cb17>] nfs_release_page+0x57/0x70 [nfs]
 [<ffffffff810f2a52>] try_to_release_page+0x32/0x50
 [<ffffffff811016a3>] shrink_page_list+0x453/0x5f0
 [<ffffffff81101b4d>] shrink_inactive_list+0x30d/0x7e0
 [<ffffffff810fbcda>] ? determine_dirtyable_memory+0x1a/0x30
 [<ffffffff810fbd87>] ? get_dirty_limits+0x27/0x2f0
 [<ffffffff811020b1>] shrink_list+0x91/0xf0
 [<ffffffff811022a7>] shrink_zone+0x197/0x240
 [<ffffffff811023c2>] shrink_zones+0x72/0x100
 [<ffffffff811024ce>] do_try_to_free_pages+0x7e/0x330
 [<ffffffff8110287f>] try_to_free_pages+0x6f/0x80
 [<ffffffff811003c0>] ? isolate_pages_global+0x0/0x50
 [<ffffffff810f992a>] __alloc_pages_slowpath+0x27a/0x580
 [<ffffffff810f9d8e>] __alloc_pages_nodemask+0x15e/0x1a0
 [<ffffffff8112cc07>] alloc_pages_current+0x87/0xd0
 [<ffffffff81132728>] new_slab+0x248/0x310
 [<ffffffff81134fb9>] __slab_alloc+0x169/0x2d0
 [<ffffffff810f5ab5>] ? mempool_alloc_slab+0x15/0x20
 [<ffffffff811354e4>] kmem_cache_alloc+0xe4/0x150
 [<ffffffff810f5ab5>] mempool_alloc_slab+0x15/0x20
 [<ffffffff810f5c53>] mempool_alloc+0x63/0x140
 [<ffffffff81085300>] ? autoremove_wake_function+0x0/0x40
 [<ffffffffa041ce70>] nfs_writedata_alloc+0x20/0xc0 [nfs]
 [<ffffffffa041cf32>] nfs_flush_one+0x22/0xf0 [nfs]
 [<ffffffffa0418097>] nfs_pageio_doio+0x37/0x80 [nfs]
 [<ffffffffa0418134>] nfs_pageio_add_request+0x54/0x100 [nfs]
 [<ffffffffa041c47d>] nfs_page_async_flush+0x9d/0xf0 [nfs]
 [<ffffffffa041c557>] nfs_do_writepage+0x87/0x90 [nfs]
 [<ffffffffa041cc9e>] nfs_writepages_callback+0x1e/0x40 [nfs]
 [<ffffffff810fcac7>] write_cache_pages+0x227/0x4d0
 [<ffffffffa041cc80>] ? nfs_writepages_callback+0x0/0x40 [nfs]
 [<ffffffffa041cc09>] nfs_writepages+0xb9/0x130 [nfs]
 [<ffffffffa041cf10>] ? nfs_flush_one+0x0/0xf0 [nfs]
 [<ffffffff810fcdc1>] do_writepages+0x21/0x40
 [<ffffffff810f40ab>] __filemap_fdatawrite_range+0x5b/0x60
 [<ffffffff810f43df>] filemap_fdatawrite+0x1f/0x30
 [<ffffffff810f4425>] filemap_write_and_wait+0x35/0x50
 [<ffffffffa041055b>] nfs_setattr+0x15b/0x180 [nfs]
 [<ffffffff810f4c26>] ? generic_file_aio_read+0xb6/0x1d0
 [<ffffffff81013b0e>] ? common_interrupt+0xe/0x13
 [<ffffffff810f36de>] ? find_get_page+0x1e/0xa0
 [<ffffffff810f50c9>] ? filemap_fault+0xb9/0x460
 [<ffffffff8106c4a7>] ? current_fs_time+0x27/0x30
 [<ffffffff8115b7db>] notify_change+0x16b/0x350
 [<ffffffff8116a16c>] utimes_common+0xdc/0x1b0
 [<ffffffff812b6eba>] ? __up_read+0x9a/0xc0
 [<ffffffff8116a2e1>] do_utimes+0xa1/0xf0
 [<ffffffff81543378>] ? do_page_fault+0x158/0x3b0
 [<ffffffff8116a442>] sys_utimensat+0x32/0x90
 [<ffffffff810131b2>] system_call_fastpath+0x16/0x1b

Other tasks raising such messages (the same session):

[103440.890116] INFO: task kswapd0:52 blocked for more than 120 seconds.
[103440.890576] INFO: task Xorg:1300 blocked for more than 120 seconds.
[103440.891199] INFO: task plasma-desktop:1987 blocked for more than 120 seconds.
[103440.892078] INFO: task mv:26028 blocked for more than 120 seconds.
[103560.890060] INFO: task kswapd0:52 blocked for more than 120 seconds.
[103560.890516] INFO: task Xorg:1300 blocked for more than 120 seconds.
[103560.891139] INFO: task plasma-desktop:1987 blocked for more than 120 seconds.
[103560.892002] INFO: task mv:26028 blocked for more than 120 seconds.
[103680.890072] INFO: task kswapd0:52 blocked for more than 120 seconds.
[103680.890535] INFO: task Xorg:1300 blocked for more than 120 seconds.

Revision history for this message
Ancoron Luziferis (ancoron) wrote :
Revision history for this message
Ancoron Luziferis (ancoron) wrote :
Revision history for this message
Ancoron Luziferis (ancoron) wrote :
Revision history for this message
Ancoron Luziferis (ancoron) wrote :
Revision history for this message
Ancoron Luziferis (ancoron) wrote :
Revision history for this message
barbz (p-barbz) wrote :

I have the same problem in lucid.

Mounting nfs in fstab via
192.168.1.128:/mnt/Array1 /media/Array1 nfs rsize=8192,wsize=8192,timeo=14,intr,noatime,nodiratime

Transfer of files larger than 1gb cause system to lock up when it transfers the first 1gb.

Base install of 10.04 beta 2 with nfs-common and portmap installed.

Paul

Revision history for this message
Andre Roth (lynx-deactivatedaccount) wrote :

Our NFS Boot environment is affected by the same problem, as we are trying to get the lucid lynx ready.

Apparently this has been fixed on kernel versions 2.6.33.2 and 2.6.32.11 according to:
http://bbs.archlinux.org/viewtopic.php?pid=739477

I really hope this will be patched in the ubuntu 2.6.32 kernels soon.

andré

Revision history for this message
Ancoron Luziferis (ancoron) wrote :

Yepp, the upstream commit seams to be this one:

http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commitdiff;h=bb6fbc4548b9ae7ebbd06ef72f00229df259d217

But in addition this one should also be considered for a backport:

http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commitdiff;h=d812e575822a2b7ab1a7cadae2571505ec6ec2bd

So, let's backport them and see if they really fix the issue...

Revision history for this message
Ancoron Luziferis (ancoron) wrote :

Well, just to see that 2.6.32.11 is already the current version for Lucid. So it should be fine.

If it is not then it is a problem elsewhere.

Revision history for this message
Ancoron Luziferis (ancoron) wrote :

Just made some tests with some ISO's (690 MiB - 3.7 GiB) and the issue seems to be fixed.

Now I got consistent read/write speed back again.

Revision history for this message
Andre Roth (lynx-deactivatedaccount) wrote : Re: [Bug 561210] Re: Writing big files to NFS target causes system lock up

On 22.04.2010 22:57, Ancoron Luziferis wrote:
> Well, just to see that 2.6.32.11 is already the current version for
> Lucid. So it should be fine.
>
> If it is not then it is a problem elsewhere.
>
>
Where did you find this information ?
I tried to build a vanilla kernel and patching it with the ubuntu
patches, but I was unable to find them anywhere...

Regards
 andré

tags: added: kj-triage
Revision history for this message
Christoph Lechleitner (lech) wrote :

I seem to suffer from the same problem in up-to-date lucid x86_64 with Ubuntu kernel 2.6.32-21-generic.
I assume the problem only occurs when the target server is considerable slower than the local machine, like an ultra slow NAS serving for a SSD boosted developer machine.

Revision history for this message
Jeremy Foshee (jeremyfoshee) wrote :

Hi Ancoron,

This bug was reported a while ago and there hasn't been any activity in it recently. We were wondering if this is still an issue? Can you try with the latest development release of Ubuntu? ISO CD images are available from http://cdimage.ubuntu.com/releases/ .

If it remains an issue, could you run the following command from a Terminal (Applications->Accessories->Terminal). It will automatically gather and attach updated debug information to this report.

apport-collect -p linux 561210

Also, if you could test the latest upstream kernel available that would be great. It will allow additional upstream developers to examine the issue. Refer to https://wiki.ubuntu.com/KernelMainlineBuilds . Once you've tested the upstream kernel, please remove the 'needs-upstream-testing' tag. This can be done by clicking on the yellow pencil icon next to the tag located at the bottom of the bug description and deleting the 'needs-upstream-testing' text. Please let us know your results.

Thanks in advance.

    [This is an automated message. Apologies if it has reached you inappropriately; please just reply to this message indicating so.]

tags: added: needs-kernel-logs
tags: added: needs-upstream-testing
Changed in linux (Ubuntu):
status: New → Incomplete
Revision history for this message
Ancoron Luziferis (ancoron) wrote :

@Christoph: If you still experience this bug please do that apport-collect thing.

For me it is fine here. Tested with two different amd64 machines accessing a single NAS (1 Gb network, software-RAID-5 on busybox NAS, write speed 20 - 30 MiB/s). Also simultaneous read/write access doesn't yield any problem here.

How I mount them:

rw,rsize=32768,wsize=32768,hard,intr,noatime

Revision history for this message
Christoph Lechleitner (lech) wrote :

I only had the problem with an extremely slow NAS as target, I have given the damn thing away a wee ago.
So I have no easy way of reproducing it now, sorry.

Revision history for this message
Ancoron Luziferis (ancoron) wrote :
Download full text (4.3 KiB)

Well, today on one of my machine here at home this issue is back:

[616201.460064] INFO: task kswapd0:52 blocked for more than 120 seconds.
[616201.460072] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[616201.460079] kswapd0 D 0000000000000000 0 52 2 0x00000000
[616201.460090] ffff880128d2f720 0000000000000046 0000000000015bc0 0000000000015bc0
[616201.460100] ffff88012af8df80 ffff880128d2ffd8 0000000000015bc0 ffff88012af8dbc0
[616201.460108] 0000000000015bc0 ffff880128d2ffd8 0000000000015bc0 ffff88012af8df80
[616201.460117] Call Trace:
[616201.460153] [<ffffffffa03a62b0>] ? nfs_wait_bit_uninterruptible+0x0/0x20 [nfs]
[616201.460166] [<ffffffff8153eb87>] io_schedule+0x47/0x70
[616201.460192] [<ffffffffa03a62be>] nfs_wait_bit_uninterruptible+0xe/0x20 [nfs]
[616201.460201] [<ffffffff8153f3df>] __wait_on_bit+0x5f/0x90
[616201.460211] [<ffffffff811346a6>] ? __slab_free+0x96/0x120
[616201.460235] [<ffffffffa03a62b0>] ? nfs_wait_bit_uninterruptible+0x0/0x20 [nfs]
[616201.460243] [<ffffffff8153f488>] out_of_line_wait_on_bit+0x78/0x90
[616201.460252] [<ffffffff81085360>] ? wake_bit_function+0x0/0x40
[616201.460277] [<ffffffffa03a629f>] nfs_wait_on_request+0x2f/0x40 [nfs]
[616201.460302] [<ffffffffa03aa6af>] nfs_wait_on_requests_locked+0x7f/0xd0 [nfs]
[616201.460329] [<ffffffffa03abaee>] nfs_sync_mapping_wait+0x9e/0x1a0 [nfs]
[616201.460354] [<ffffffffa03abc71>] nfs_wb_page+0x81/0xe0 [nfs]
[616201.460376] [<ffffffffa039ab2f>] nfs_release_page+0x5f/0x80 [nfs]
[616201.460384] [<ffffffff810f2bb2>] try_to_release_page+0x32/0x50
[616201.460392] [<ffffffff81101833>] shrink_page_list+0x453/0x5f0
[616201.460402] [<ffffffff8113b419>] ? mem_cgroup_del_lru+0x39/0x40
[616201.460409] [<ffffffff81100517>] ? isolate_lru_pages+0x227/0x260
[616201.460417] [<ffffffff81101cdd>] shrink_inactive_list+0x30d/0x7e0
[616201.460426] [<ffffffff810116c0>] ? __switch_to+0xd0/0x320
[616201.460434] [<ffffffff81076e2c>] ? lock_timer_base+0x3c/0x70
[616201.460441] [<ffffffff810778b5>] ? try_to_del_timer_sync+0x75/0xd0
[616201.460449] [<ffffffff81102241>] shrink_list+0x91/0xf0
[616201.460455] [<ffffffff81102437>] shrink_zone+0x197/0x240
[616201.460463] [<ffffffff811034c9>] balance_pgdat+0x659/0x6d0
[616201.460470] [<ffffffff81100550>] ? isolate_pages_global+0x0/0x50
[616201.460477] [<ffffffff8110363e>] kswapd+0xfe/0x150
[616201.460485] [<ffffffff81085320>] ? autoremove_wake_function+0x0/0x40
[616201.460492] [<ffffffff81103540>] ? kswapd+0x0/0x150
[616201.460498] [<ffffffff81084fa6>] kthread+0x96/0xa0
[616201.460506] [<ffffffff810141ea>] child_rip+0xa/0x20
[616201.460513] [<ffffffff81084f10>] ? kthread+0x0/0xa0
[616201.460520] [<ffffffff810141e0>] ? child_rip+0x0/0x20

This was an extract job for a rather small archive (just ~ 400 MiB) from the NAS, to the NAS (I know this is bad practice).

What also came up is that again KDE4 completely freezes, until the lock is released:

[616201.460551] INFO: task plasma-desktop:7429 blocked for more than 120 seconds.
[616201.460556] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[616201.460561] plasma-deskto D 0000000000000000 0 7429 ...

Read more...

Revision history for this message
Christoph Lechleitner (lech) wrote :

My Desktop also did freeze for those 120 seconds.
I use a Gnome but there are KDE based widgets running, namely klipper.

Ac. buffer size: Larger write buffers (backed by enough RAM) defer or eventually avoid the point at which the buffer runs full.
I think we agree that's when the freeze occurs.

Does the kernel allow some kind of temporary "overbooking" for wirite buffers, like it does for RAM?

Revision history for this message
Christoph Lechleitner (lech) wrote :

If my assumption of the freeze trigger is correct, it should be possible to provoke the problem even against fast NFS servers by setting the buffer size extremly low, i.e. to the minimum allowed by the NFS driver.
I 'll try this out, but due to a business trip I won't happen before the end of the upcoming week.

Revision history for this message
Christoph Lechleitner (lech) wrote :

Today I tried copying very large files to a NFS share mounted with rsize=64,wsize=64 and I could reproduce freezes of about 30 secs, but no 120-sec-freezes and nothing in dmesg' output.
I am on lucid's amd64 kernel 2.6.32-22.

Revision history for this message
jjbig (a-launchpad-net-jjbig-dittri-ch) wrote :

I have to confirm this bug as well. Same effekt, everything hangs for some time while transfering biger data to NFS I'm using Ubuntu 10.04 64 (2.6.32-22-generic #36-Ubuntu SMP Thu Jun 3 19:31:57 UTC 2010 x86_64 GNU/Linux). dmesg does't report anything.

Revision history for this message
Jeremy Foshee (jeremyfoshee) wrote :

Ancoron,
     Per the new kernel team policy, I'd like to close this issue out for you as fix released.

jjbig / Christoph,
    Also, per ubuntu kernel team policy, could I get the two of you to file new bugs for your issues? This will enable us to approach your bugs from an individual standpoint and rule out any hardware as affecting the core problem.

Thanks!

~JFo

Changed in linux (Ubuntu):
status: Incomplete → Fix Released
Revision history for this message
Ancoron Luziferis (ancoron) wrote :

Jeremy,

I disagree with the status change to "Fix Released" as it is not "fixed". The problem still occurs. It didn't occur for my main workstation here as I have raised the rsize/wsize to 32MB on the NFS mounts here and I am just issuing one to two NFS "transactions" at a time, so it didn't come up in the first place.

However, even if I raise the rsize/wsize I still can reproduce this issue by throwing a bit more work in parallel for the NFS mounts. On a "standard" NFS mount just a "cp" of a 400 MB file from the NFS mount to the same is sufficient to raise this issue again. This doesn't occur every time but around every second or third run at least.

I'll try to test the workload required for my 32MB mounts to get stuck too. After that I'll be able to build a small script as a test case for that.

Revision history for this message
JimWright (jim-jim-wright) wrote :
Download full text (9.7 KiB)

I believe we have also been affected by this issue. I've managed to recreate it using a single virtual machine running on VMWare server and only using the loopback interface.

First I created a 64-bit VM using VMWare Server with 2 CPUs, 512MB RAM and 8GB disk. Into that I performed a fresh install of 64-bit Ubuntu 10.04 LTS desktop edition (as it was all I had to hand), using the image file:

    ubuntu-10.04-desktop-amd64.iso

Once installed, I added the nfs-kernel-server package. At this stage I have not upgraded any packages from the versions that come on the CD.

In /etc/exports I added the line:

/srv *(rw,sync,no_subtree_check)

In /etc/fstab I added the line:

localhost:/srv /mnt/srv nfs rw 0 2

Then I executed the following commands:

# exportfs -a
# mkdir /mnt/srv
# mount /mnt/srv

In /srv I created a 512MB file (512MB was chosen to match the size of RAM on the virtual machine)

# dd if=/dev/urandom of=/srv/test bs=1M count=512

Then I executed a continual gzip loop accessing the file over NFS using the loopback interface, and writing its results back over NFS.

# while true
> do
> gzip -c /mnt/srv/test >/mnt/srv/test.gz
> done

I was running top in another virtual console and within seconds the load on the virtual machine rose rapidly (> 10), gzip was no longer consuming CPU, and the machine appeared to "lock up" permanently and never recover.

On rebooting the following messages were in /var/syslog:

Jun 21 23:22:12 lucid kernel: [ 1202.033262] INFO: task kswapd0:36 blocked for more than 120 seconds.
Jun 21 23:22:12 lucid kernel: [ 1202.150847] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Jun 21 23:22:12 lucid kernel: [ 1202.286349] kswapd0 D 0000000000000000 0 36 2 0x00000000
Jun 21 23:22:12 lucid kernel: [ 1202.286349] ffff880017881720 0000000000000046 0000000000015bc0 0000000000015bc0
Jun 21 23:22:12 lucid kernel: [ 1202.286349] ffff88001d79df80 ffff880017881fd8 0000000000015bc0 ffff88001d79dbc0
Jun 21 23:22:12 lucid kernel: [ 1202.286349] 0000000000015bc0 ffff880017881fd8 0000000000015bc0 ffff88001d79df80
Jun 21 23:22:12 lucid kernel: [ 1202.286349] Call Trace:
Jun 21 23:22:12 lucid kernel: [ 1202.288343] [<ffffffffa01d02b0>] ? nfs_wait_bit_uninterruptible+0x0/0x20 [nfs]
Jun 21 23:22:12 lucid kernel: [ 1202.288552] [<ffffffff8153eb57>] io_schedule+0x47/0x70
Jun 21 23:22:12 lucid kernel: [ 1202.288574] [<ffffffffa01d02be>] nfs_wait_bit_uninterruptible+0xe/0x20 [nfs]
Jun 21 23:22:12 lucid kernel: [ 1202.288580] [<ffffffff8153f3af>] __wait_on_bit+0x5f/0x90
Jun 21 23:22:12 lucid kernel: [ 1202.288593] [<ffffffffa01d02b0>] ? nfs_wait_bit_uninterruptible+0x0/0x20 [nfs]
Jun 21 23:22:12 lucid kernel: [ 1202.288599] [<ffffffff8153f458>] out_of_line_wait_on_bit+0x78/0x90
Jun 21 23:22:12 lucid kernel: [ 1202.288605] [<ffffffff81085360>] ? wake_bit_function+0x0/0x40
Jun 21 23:22:12 lucid kernel: [ 1202.288627] [<ffffffffa01d029f>] nfs_wait_on_request+0x2f/0x40 [nfs]
Jun 21 23:22:12 lucid kernel: [ 1202.288640] [<ffffffffa01d46af>] nfs_wait_on_requests_locked+0x7f/0xd0 [nfs]
Jun 21 23:22:12 lucid kernel: [ 1202.288658] [<ffffffffa01d...

Read more...

Changed in linux (Ubuntu):
status: Fix Released → Triaged
Revision history for this message
Ancoron Luziferis (ancoron) wrote :
Download full text (29.1 KiB)

@Jim: That looks to me like a test case :)

All this information leads me to the same conclusion that those blocking behavior occurs most commonly when the system runs out of free RAM and starts to swap heavily.

I'm currently running a vanilla kernel 2.6.35-rc3 and with that I wasn't able to reproduce some blocking here, but what I noticed was that when the system starts this heavy swapping even my hardware accelerated mouse cursor get stuck sometimes (reminds me on an old crappy windows box I used to have). And this plus the fact that the whole user interface (at least with KDE4) locks up sometimes points me to something that isn't necessarily related to NFS itself.

As every file operation in Linux also uses the system memory to speed up things it could be that the priority of what gets swapped out and what swapped in doesn't suite the individual needs. In the worst case if something like plasma-desktop is chosen to be swapped out then parts of it immediately are scheduled for swap-in as plasma-desktop updates periodically. That way the wrong swapping strategy could introduce this issue.

On the other hand I don't understand why the hell is some heavy swapping able to interfere a hardware accelerated mouse cursor? This lonely symptom leads me to another pointer: interrupt handling. But then I don't know enough about that thing to go any further.

I just issued a test on my 2.6.35-rc3 box:
- set up an NFS mount with rsize=128,wsize=128
- make the system memory (4GB) almost completely used by other processes (very few file cache/buffered)
- issue a "gunzip" of a 4.1 GiB file from the NFS mount to the NFS mount

And now guess what?

Yes, I got those hung tasks again even with a much newer kernel, so the problem isn't addressed upstream and can't be in lucid.

Although this time it is a bit different because I don't get NFS related backtraces here. Instead (and what I currently think is more of a reason to this problem) I always get some calls for memory allocation and/or paging requests. So the system is heavily swapping and the swapping needs time as we all know.

But instead just waiting for the scheduled operation to complete it "blocks" and therefore interferes user interaction at all.

To verify that problem I just made up some KVM's on my machine at work (a 6-core AMD64, 8GiB RAM) and even without having any NFS mounts or exports I got some very similar behavior. Although I didn't provoke a complete lockup yet (well, I need to do some work there), I also got temporarily freezing "hardware accelerated" mouse cursor and completely non-responsive desktop (at least for some seconds up to a minute).

Here it goes for my machine with kernel 2.6.35-rc3:

[240602.803784] INFO: task kwin:2102 blocked for more than 120 seconds.
[240602.803787] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[240602.803789] kwin D 00000000ffffffff 0 2102 2100 0x00000000
[240602.803793] ffff8801281d93d8 0000000000000086 ffff880073c09cc8 0000000000015840
[240602.803796] ffff8801281d9fd8 0000000000015840 ffff8801281d9fd8 ffff88012a2196d0
[240602.803798] 0000000000015840 0000000000015840 ffff8801281d9fd8 0000000000015840
[...

tags: added: kernel-fs kernel-needs-review
removed: needs-kernel-logs needs-upstream-testing
Revision history for this message
tom (thomas-gutzler) wrote :
Download full text (9.7 KiB)

I'm running
Linux io 2.6.32-23-server #37-Ubuntu SMP Fri Jun 11 09:11:11 UTC 2010 x86_64 GNU/Linux
with all upgrades installed and I got a freeze today. Since this is a multi-user file server I'm not sure what exactly was going on at the time. Unfortunately, I cannot try out different kernels either as the machine is always in use.

Jul 7 11:29:57 io kernel: [254640.440019] INFO: task jbd2/sdb-8:942 blocked for more than 120 seconds.
Jul 7 11:29:57 io kernel: [254640.440033] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Jul 7 11:29:57 io kernel: [254640.440042] jbd2/sdb-8 D 00000000ffffffff 0 942 2 0x00000000
Jul 7 11:29:57 io kernel: [254640.440047] ffff88007bd71d20 0000000000000046 0000000000015bc0 0000000000015bc0
Jul 7 11:29:57 io kernel: [254640.440052] ffff88007bff9ab0 ffff88007bd71fd8 0000000000015bc0 ffff88007bff96f0
Jul 7 11:29:57 io kernel: [254640.440056] 0000000000015bc0 ffff88007bd71fd8 0000000000015bc0 ffff88007bff9ab0
Jul 7 11:29:57 io kernel: [254640.440060] Call Trace:
Jul 7 11:29:57 io kernel: [254640.440069] [<ffffffff8121b9a1>] jbd2_journal_commit_transaction+0x1c1/0x1250
Jul 7 11:29:57 io kernel: [254640.440075] [<ffffffff81076c7c>] ? lock_timer_base+0x3c/0x70
Jul 7 11:29:57 io kernel: [254640.440080] [<ffffffff81085090>] ? autoremove_wake_function+0x0/0x40
Jul 7 11:29:57 io kernel: [254640.440084] [<ffffffff81222f6d>] kjournald2+0xbd/0x220
Jul 7 11:29:57 io kernel: [254640.440088] [<ffffffff81085090>] ? autoremove_wake_function+0x0/0x40
Jul 7 11:29:57 io kernel: [254640.440091] [<ffffffff81222eb0>] ? kjournald2+0x0/0x220
Jul 7 11:29:57 io kernel: [254640.440094] [<ffffffff81084d16>] kthread+0x96/0xa0
Jul 7 11:29:57 io kernel: [254640.440099] [<ffffffff810141ea>] child_rip+0xa/0x20
Jul 7 11:29:57 io kernel: [254640.440102] [<ffffffff81084c80>] ? kthread+0x0/0xa0
Jul 7 11:29:57 io kernel: [254640.440105] [<ffffffff810141e0>] ? child_rip+0x0/0x20
Jul 7 11:29:57 io kernel: [254640.440113] INFO: task nfsd:1753 blocked for more than 120 seconds.
Jul 7 11:29:57 io kernel: [254640.440119] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Jul 7 11:29:57 io kernel: [254640.440126] nfsd D 0000000000000000 0 1753 2 0x00000000
Jul 7 11:29:57 io kernel: [254640.440130] ffff88007b345b10 0000000000000046 0000000000015bc0 0000000000015bc0
Jul 7 11:29:57 io kernel: [254640.440135] ffff88007cbc4890 ffff88007b345fd8 0000000000015bc0 ffff88007cbc44d0
Jul 7 11:29:57 io kernel: [254640.440139] 0000000000015bc0 ffff88007b345fd8 0000000000015bc0 ffff88007cbc4890
Jul 7 11:29:57 io kernel: [254640.440143] Call Trace:
Jul 7 11:29:57 io kernel: [254640.440147] [<ffffffff81219ce1>] start_this_handle+0x251/0x4b0
Jul 7 11:29:57 io kernel: [254640.440150] [<ffffffff81085090>] ? autoremove_wake_function+0x0/0x40
Jul 7 11:29:57 io kernel: [254640.440154] [<ffffffff81559cde>] ? _spin_lock+0xe/0x20
Jul 7 11:29:57 io kernel: [254640.440158] [<ffffffff8121a115>] jbd2_journal_start+0xb5/0x100
Jul 7 11:29:57 io kernel: [254640.440162] [<ffffffff811f80b8>] ext4_journal_start_sb+0x58/0x90
Jul 7 11:29:57 io kernel: [254640.440167]...

Read more...

Revision history for this message
tom (thomas-gutzler) wrote :
Revision history for this message
Timo Harmonen (timo-harmonen) wrote :
Download full text (6.1 KiB)

I can repro this issue quite easily with my setup. I'm running two amd64 kvm guests on amd64 host system with 8GB of memory. Nfs server is running on the host, and guests heavily rely on it. All systems are up-to-date, kernel is 2.6.32-23.

So the guests hang when they heavily access nfs mounts, it seems that write operations are needed. First I used nfs3, then switched to nfs4, but it didn't really help.

host export:
/srv/mmedia 172.16.0.0/16(rw,nohide,insecure,no_subtree_check,async)

guest fstab mount:
172.16.1.1:/mmedia /mmedia nfs4 _netdev,auto 0 0

I have had this issue since upgrading to Lucid, and never had anything like this with Karmic, where I had exactly the same setup.

dmesg log attached, both from the host and a guest.

One way to repro this is to run a script on the guest that processes (copies) image files over nfs, this hangs after processing around 20-50 files. System load starts to increase after the script hangs, I have seen loads way over 200. After this happens, also all other processes accessing nfs mounts hang. Cannot reboot, have to hard reset the guest.

syslog from the gust:
--------------------------
Jul 12 13:42:14 scotty kernel: [ 360.190575] INFO: task perl:4360 blocked for more than 120 seconds.
Jul 12 13:42:14 scotty kernel: [ 360.190585] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Jul 12 13:42:14 scotty kernel: [ 360.190592] perl D 0000000000000000 0 4360 4358 0x00000000
Jul 12 13:42:14 scotty kernel: [ 360.190605] ffff8800b02ffc48 0000000000000082 0000000000015bc0 0000000000015bc0
Jul 12 13:42:14 scotty kernel: [ 360.190616] ffff8800ae73c890 ffff8800b02fffd8 0000000000015bc0 ffff8800ae73c4d0
Jul 12 13:42:14 scotty kernel: [ 360.190624] 0000000000015bc0 ffff8800b02fffd8 0000000000015bc0 ffff8800ae73c890
Jul 12 13:42:14 scotty kernel: [ 360.190633] Call Trace:
Jul 12 13:42:14 scotty kernel: [ 360.190729] [<ffffffffa014a3b0>] ? nfs_wait_bit_uninterruptible+0x0/0x20 [nfs]
Jul 12 13:42:14 scotty kernel: [ 360.190788] [<ffffffff81541357>] io_schedule+0x47/0x70
Jul 12 13:42:14 scotty kernel: [ 360.190816] [<ffffffffa014a3be>] nfs_wait_bit_uninterruptible+0xe/0x20 [nfs]
Jul 12 13:42:14 scotty kernel: [ 360.190824] [<ffffffff81541bbf>] __wait_on_bit+0x5f/0x90
Jul 12 13:42:14 scotty kernel: [ 360.190850] [<ffffffffa014a3b0>] ? nfs_wait_bit_uninterruptible+0x0/0x20 [nfs]
Jul 12 13:42:14 scotty kernel: [ 360.190860] [<ffffffff81541c68>] out_of_line_wait_on_bit+0x78/0x90
Jul 12 13:42:14 scotty kernel: [ 360.190905] [<ffffffff81085470>] ? wake_bit_function+0x0/0x40
Jul 12 13:42:14 scotty kernel: [ 360.190931] [<ffffffffa014a39f>] nfs_wait_on_request+0x2f/0x40 [nfs]
Jul 12 13:42:14 scotty kernel: [ 360.190964] [<ffffffffa014e7df>] nfs_wait_on_requests_locked+0x7f/0xd0 [nfs]
Jul 12 13:42:14 scotty kernel: [ 360.190992] [<ffffffffa014fc1e>] nfs_sync_mapping_wait+0x9e/0x1a0 [nfs]
Jul 12 13:42:14 scotty kernel: [ 360.191027] [<ffffffffa0150009>] nfs_write_mapping+0x79/0xb0 [nfs]
Jul 12 13:42:14 scotty kernel: [ 360.191060] [<ffffffff8115f7d0>] ? mntput_no_expire+0x30/0x110
Jul 12 13:42:14 scotty kernel: [ 360.191087] [<ffffffff...

Read more...

Andy Whitcroft (apw)
tags: added: kernel-candidate kernel-reviewed
removed: kernel-needs-review
tags: removed: kernel-candidate
Revision history for this message
no!chance (ralf-fehlau) wrote :

I have the same problem on my machine (10.04 LTS, linux-image-2.6.32-23-server 2.6.32-23.37, 64Bit). My system is up-to-date. During the last system freeze, I discovered that no data was written to the nfs share for at least 15 minutes.

I tried to login at the console and got a lot of messages like this:

INFO: task .... blocked for more than 120 seconds.
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

I couldn't log in and had to hard reset my machine. After boot up, I found nothing in the system logs.

Andy Whitcroft (apw)
Changed in linux (Ubuntu):
importance: Undecided → Medium
Revision history for this message
David McBride (david-mcbride) wrote :

Just ran into this bug, affecting me on a new Lucid 64-bit install. Memory exhaustion is unlikely, as the machine has 8GB of RAM and a fast network link.

This may be related to bug #585657.

Remote SSH still works, and the NFS transfer I started a couple of hours ago is still running, slowly, though a process-listing blocks and both X and the console is completely unusable.

(Which is a bit of a showstopper for rolling out a few hundred Lucid-based desktops..)

Revision history for this message
David McBride (david-mcbride) wrote :

(My test machine eventually unblocked when the 90GB NFS transfer finally finished. Still, that took a long time, and it was totally unusable until then.)

Checking the current kernel sources, the kernel patches referenced in bug #585657 are clearly already applied. Reviewing recent development history, it appears this bug entry (patch at end) might also be relevant:

  https://bugzilla.kernel.org/show_bug.cgi?id=16056

I'm going to try testing that patch locally to see if it fixes this particular problem.

Revision history for this message
David McBride (david-mcbride) wrote :

Applying the patch referenced in the previous comment, the situation with regards to NFS deadlocking is improved -- the local terminal no-longer locks up -- but there are continued issues with processes blocking in 'D' (disk-wait) when they should not.

(For example, automounted NFS volumes not involved in a transfer-in-progress which try to automatically unmount after a period of inactivity will have their 'umount' processes block in disk-wait until the transfer has completed.)

Revision history for this message
David McBride (david-mcbride) wrote :

And, indeed, if the umount process is stuck for long enough, the following kernel stack-trace is emitted:

Jul 26 21:38:49 illustrious kernel: [ 838.729063] INFO: task umount.nfs:2570 blocked for more than 120 seconds.
Jul 26 21:38:49 illustrious kernel: [ 838.729069] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Jul 26 21:38:49 illustrious kernel: [ 838.729073] umount.nfs D 0000000000000000 0 2570 1 0x00000000
Jul 26 21:38:49 illustrious kernel: [ 838.729080] ffff8801d5747d98 0000000000000086 0000000000015bc0 0000000000015bc0
Jul 26 21:38:49 illustrious kernel: [ 838.729087] ffff880210ec03c0 ffff8801d5747fd8 0000000000015bc0 ffff880210ec0000
Jul 26 21:38:49 illustrious kernel: [ 838.729092] 0000000000015bc0 ffff8801d5747fd8 0000000000015bc0 ffff880210ec03c0
Jul 26 21:38:49 illustrious kernel: [ 838.729098] Call Trace:
Jul 26 21:38:49 illustrious kernel: [ 838.729110] [<ffffffff811650d0>] ? bdi_sched_wait+0x0/0x20
Jul 26 21:38:49 illustrious kernel: [ 838.729115] [<ffffffff811650de>] bdi_sched_wait+0xe/0x20
Jul 26 21:38:49 illustrious kernel: [ 838.729123] [<ffffffff8153f3af>] __wait_on_bit+0x5f/0x90
Jul 26 21:38:49 illustrious kernel: [ 838.729127] [<ffffffff811650d0>] ? bdi_sched_wait+0x0/0x20
Jul 26 21:38:49 illustrious kernel: [ 838.729132] [<ffffffff8153f458>] out_of_line_wait_on_bit+0x78/0x90
Jul 26 21:38:49 illustrious kernel: [ 838.729140] [<ffffffff81085360>] ? wake_bit_function+0x0/0x40
Jul 26 21:38:49 illustrious kernel: [ 838.729144] [<ffffffff81165094>] ? bdi_queue_work+0xa4/0xe0
Jul 26 21:38:49 illustrious kernel: [ 838.729149] [<ffffffff8116640f>] bdi_sync_writeback+0x6f/0x80
Jul 26 21:38:49 illustrious kernel: [ 838.729154] [<ffffffff81166440>] sync_inodes_sb+0x20/0x30
Jul 26 21:38:49 illustrious kernel: [ 838.729160] [<ffffffff81169f12>] __sync_filesystem+0x82/0x90
Jul 26 21:38:49 illustrious kernel: [ 838.729164] [<ffffffff81169ff9>] sync_filesystems+0xd9/0x130
Jul 26 21:38:49 illustrious kernel: [ 838.729171] [<ffffffff8115ece1>] sys_umount+0xb1/0xd0
Jul 26 21:38:49 illustrious kernel: [ 838.729178] [<ffffffff810131b2>] system_call_fastpath+0x16/0x1b

I've also identified that my test NFS mount was using UDP, and performs several times *better* in terms of IO throughput when switched to TCP operation. This lack of performance (and responsiveness) may have been masking some other issues, so I'll use TCP for future testing.

Revision history for this message
David McBride (david-mcbride) wrote :

I've compiled up and retried my test transfers with Linus's current latest RC, 2.6.35-rc6, and found that this problem does not recur.

Revision history for this message
Alex (d-f0rce) wrote :

Will the fix from 2.6.35-rc6 be backported to Lucid?

Revision history for this message
Christoph Lechleitner (lech) wrote :

Is there a specific patch that addresses our problem?

Revision history for this message
David Ressman (davidressman) wrote :

If this is truly a duplicate of bug #585657, I can verify that I see this problem in 10.04 with both Ubuntu's 2.6.32-24.39 and with the stock kernel.org 2.6.32.18.

Revision history for this message
Tim Gardner (timg-tpi) wrote :

I'm not having any luck reproducing this problem on a 2.6.32-24.41 NFS server, using a simple mount from the client thusly: 'sudo mount 10.0.2.210:/export /mnt' and blasting a 90GB file onto the server: 'dd if=/dev/zero of=/mnt/users/rtg/bf.txt bs=512 count=188743680'. This is over a 100Mb switch.

Changed in linux (Ubuntu):
assignee: nobody → Tim Gardner (timg-tpi)
status: Triaged → In Progress
Revision history for this message
JimWright (jim-jim-wright) wrote :

Hi Tim,

After your post I retried my test case (see comment #23 above), except this time using KVM instead of VMWare Server. All details of the virtual machine, i.e. 2xCPU/512MB RAM/8GB HDD are the same - it's just using KVM instead of VMWare.

I can confirm that under KVM and a vanilla install of 10.04(.0) the problem occurs exactly as I described before, and within seconds. This is using a 64bit kernel version 2.6.32-21.32.

I then upgraded the virtual machine to the latest kernel 2.6.32-24.41 and ran the same test case again. This kernel seemed much more stable and did not exhibit problems. Multiple iterations of the gzip loop ran successfully. So I tried running a second loop of gzip processes. Thus there are now two gzip processes both accessing the NFS mount After a minute or so this caused the issue to occur together with the same messages appearing in syslog, the load skyrocketing and the system freezing. So whilst 2.6.32-24.41 appears to me to be better, I do not believe the fundamental problem has been solved. Repeating the test subsequent times, it sometimes took two simultaneous gzip processes to trigger the error, and other times three. I used the following script to run the gzip processes:

#!/bin/bash
while true
do
    gzip -c /mnt/srv/test >/mnt/srv/test$$.gz
done

If I could also make a couple of observations. Everyone I have seen having this issue (or issues that look in my opinion suspiciously close to this one) seems to be running a 64bit kernel - I have not tested a 32bit kernel. My test case uses the loopback interface, so switch speed and/or network card should be irrelevant. Also having an amount of load on the NFS client seems to be important, that is why my test case attempts to gzip a file of random data. I'm not sure your simple dd would generate enough of a real workload.

Jim

BTW In the original test case I missed out a "chmod 777 /srv", but that really isn't going to change anything.

Revision history for this message
Richard Huddleston (rhuddusa) wrote :

@Tim

i double the problem would exhibit itself on a 100mb switch unless your nfs server was writing to a storage media with a lower throughput . ... unless you are writing to a USB flash drive ... i'm pretty sure your storage can keep up with a 100mb switch

...

i only see this problem when my nfs writes are only server storage medium write bound ... i.e. ... i never max out the network / client throughput

Revision history for this message
Tim Gardner (timg-tpi) wrote :

JimWright - I was focused on the original reporter's setup, so I missed your comments in #23. It does appear that this seems to happen most when the NFS server is saturated, so it makes sense that a loopback mount would do it. I'll give your setup a try.

Revision history for this message
Tim Gardner (timg-tpi) wrote :

JimWright - I never did manage to reproduce your lockup using a VM, but I was able to do it on bare metal; a dual CPU 6 core machine (24 threads) with 16GB RAM. It took 48 instances of 'dd if=/dev/zero of=test.$i bs=1M count=512' over an NFS local mount to get it to lockup (after about 5 attempts). Nothing is leaping out at me in the dmesg. See attached.

Revision history for this message
kylea (kylea) wrote :

It may be related to LVM - I get the issue on my root disk. This is mounted via an LVM. If I run an update the update stalls with these errors

kernel: [ 2281.420086] dpkg D 0000000000000000 0 24196 24133 0x00000000
[ 2281.420090] ffff880168c87db8 0000000000000082 0000000000015bc0 0000000000015bc0
[ 2281.420094] ffff88021a7931a0 ffff880168c87fd8 0000000000015bc0 ffff88021a792de0
[ 2281.420097] 0000000000015bc0 ffff880168c87fd8 0000000000015bc0 ffff88021a7931a0
[ 2281.420100] Call Trace:
[ 2281.420109] [<ffffffff81166d80>] ? bdi_sched_wait+0x0/0x20
[ 2281.420112] [<ffffffff81166d8e>] bdi_sched_wait+0xe/0x20
[ 2281.420117] [<ffffffff815591df>] __wait_on_bit+0x5f/0x90
[ 2281.420119] [<ffffffff81166d80>] ? bdi_sched_wait+0x0/0x20
[ 2281.420122] [<ffffffff81559288>] out_of_line_wait_on_bit+0x78/0x90
[ 2281.420126] [<ffffffff810850d0>] ? wake_bit_function+0x0/0x40
[ 2281.420129] [<ffffffff81166d44>] ? bdi_queue_work+0xa4/0xe0
[ 2281.420131] [<ffffffff811680ef>] bdi_sync_writeback+0x6f/0x80
[ 2281.420134] [<ffffffff81168120>] sync_inodes_sb+0x20/0x30
[ 2281.420137] [<ffffffff8116bc92>] __sync_filesystem+0x82/0x90
[ 2281.420140] [<ffffffff8116bd79>] sync_filesystems+0xd9/0x130
[ 2281.420142] [<ffffffff8116be31>] sys_sync+0x21/0x40
[ 2281.420146] [<ffffffff810131b2>] system_call_fastpath+0x16/0x1b
[ 2401.422564] INFO: task dpkg:24196 blocked for more than 120 seconds.
[ 2401.422568] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 2401.422570] dpkg D 0000000000000000 0 24196 24133 0x00000000
[ 2401.422574] ffff880168c87db8 0000000000000082 0000000000015bc0 0000000000015bc0
[ 2401.422578] ffff88021a7931a0 ffff880168c87fd8 0000000000015bc0 ffff88021a792de0
[ 2401.422581] 0000000000015bc0 ffff880168c87fd8 0000000000015bc0 ffff88021a7931a0
[ 2401.422584] Call Trace:
[ 2401.422593] [<ffffffff81166d80>] ? bdi_sched_wait+0x0/0x20
[ 2401.422596] [<ffffffff81166d8e>] bdi_sched_wait+0xe/0x20
[ 2401.422601] [<ffffffff815591df>] __wait_on_bit+0x5f/0x90
[ 2401.422603] [<ffffffff81166d80>] ? bdi_sched_wait+0x0/0x20
[ 2401.422606] [<ffffffff81559288>] out_of_line_wait_on_bit+0x78/0x90
[ 2401.422610] [<ffffffff810850d0>] ? wake_bit_function+0x0/0x40
[ 2401.422613] [<ffffffff81166d44>] ? bdi_queue_work+0xa4/0xe0
[ 2401.422616] [<ffffffff811680ef>] bdi_sync_writeback+0x6f/0x80
[ 2401.422618] [<ffffffff81168120>] sync_inodes_sb+0x20/0x30
[ 2401.422621] [<ffffffff8116bc92>] __sync_filesystem+0x82/0x90
[ 2401.422624] [<ffffffff8116bd79>] sync_filesystems+0xd9/0x130
[ 2401.422626] [<ffffffff8116be31>] sys_sync+0x21/0x40
[ 2401.422631] [<ffffffff810131b2>] system_call_fastpath+0x16/0x1b

Revision history for this message
JimWright (jim-jim-wright) wrote :

TimGardner - From your dmesg output it appears your bare metal test was running kernel version 2.6.35, is that correct? Also the stack trace looks noticeable different. Is there an easy way I can test that kernel version on my 10.04 LTS setup (i.e. is there a package I can install on Lucid Lynx)?

We also experience this lockup on bare metal which is currently making us very nervous about using NFS for large files. I only produced the virtual machine test case to try and constrain the possible variables that may trigger the bug. What parameters did you use for your VM (CPUs/RAM/HDD and Ubuntu & Kernel versions)? BTW I was never able to reproduce the issue with a single CPU, I have always needed multiple CPUs.

I also noticed another difference between your dd test and my gzip test (in addition to the generating CPU load issue I mentioned before) - my gzip process both reads and writes from the NFS mount, whilst your dd only writes. I will see if I can reproduce the issue on my VM using your dd test.

Jim

Revision history for this message
Kim Botherway (dj-dvant) wrote :

Hi,

For me NFS locks up most often with large files when Gnome is running. eg, I have two machines, one with a 4 core CPU/4GB RAM running Gnome (machine A) and much smaller system single core/1GB RAM (machine B)

Same kernel version, copying the same file.

Machine A to B NFS pauses
Machine B to A NFS runs at max hard drive speed
Machine A to B (without Gnome running) NFS runs at max hard drive speed

Kim

Revision history for this message
Tim Gardner (timg-tpi) wrote :

JimWright: - After not being able to repro the problem using a 10.04 VM with -updates applied (8 CPUs, 512MB, 20GB) using VmWare Workstation as the hypervisor on a 10.04 host, I decided to try Maverick on bare metal. I'll have a better shot at enlisting upstream help if I can demo the problem on a more recent kernel.

I did try your 'gzip' method of reading and writing, but as mentioned, could never get it to fail even on bare metal. I'm next going to see if this issue still exists on 2.6.36-rc3.

Revision history for this message
JimWright (jim-jim-wright) wrote :

Tim:

I managed to get your dd testcase to trigger the issue on a VM running Ubuntu 10.04, Kernel 2.6.32-24.42, 8 CPUs, 512MB RAM, 8GB HDD. I've attached the dmesg output from that test.

I downloaded the latest daily snapshot of Maverick Ubuntu 10.10 (kernel 2.6.35-19.28) and installed it onto an identically configured VM. I was unable to trigger the issue I have seen using either my gzip testcase or your dd testcase after many hours of runtime.

So it would seem that the issue has been fixed in a more recent kernel, and that needs to be backported to the Ubuntu 10.04 kernel?

Jim

Revision history for this message
JimWright (jim-jim-wright) wrote :

FYI. Looking at David McBride's comments to this bug report, particularly #30, and checking the current kernel source package for Ubuntu 10.04 it appears that patch identified in https://bugzilla.kernel.org/show_bug.cgi?id=16056 (comments 17&18) has not been back ported to the 2.6.32 kernel. I have a high confidence that this would fix the issue I've been having as it always appears to be kswapd that is blocked first.

Jim

Revision history for this message
Tim Gardner (timg-tpi) wrote :

JimWright - That particular patch just arrived via stable updates. Please try Ubuntu-2.6.32-25.43 which was just uploaded to -proposed yesterday.

Revision history for this message
JimWright (jim-jim-wright) wrote :

Tim - thanks I have tried upgrading my virtual machine to the 2.6.32-25.43 kernel as you suggested. I now believe I experience the same failure that you observed on bare metal using the maverick 2.6.35 kernel - see the attached dmesg log from my latest test. So it is definitely an improvement of sorts.

Revision history for this message
Tim Gardner (timg-tpi) wrote :

JimWright - But you're still doing the loop mount test, right? Upstream has indicated that its not a supportable case, i.e., http://marc.info/?l=linux-kernel&m=128335681711984&w=2

Revision history for this message
JimWright (jim-jim-wright) wrote :

Tim - yes I was still doing it over the loopback interface. Thanks for that link, I guess that all kind of makes sense.

Part of my problem also stems from the change to autofs5 from autofs4. This has a separate bug (https://bugs.launchpad.net/ubuntu/+source/autofs5/+bug/517139) filed against it. Thus due to the default hosts file installed by Ubuntu you can end up with NFS mounts over the loopback interface. I can work around that issue myself though some additional manual configuration, as suggested in the bug report, but it might be worth pointing out to the autofs bug/people that it results in an unsupported configuration out of the box so to speak.

Many thanks for you help Tim. I think the latest proposed kernel and a bit of manual tweaking will fix the issue I've been having. I'll let everyone comment on if it fixes their issues.

Revision history for this message
Timo Harmonen (timo-harmonen) wrote :

So this fix is also in Maverick beta? Unfortunately then it does not seem to fix those problems I'm having.

I installed Maverick beta (2.6.35-19-server, amd64, clean installation) under kvm and was able to repro some of my earlier problems.

I see this most often when using torretflux to download multiple large (1GB) files simultaneously and save them on a nfs-mounted folder. This is the easiest method to repro this in Lucid, and seems to trigger the case also in Maverick. I have had this problem also when using emusic.com emusicj (java) mp3 downloader and when renaming multiple image files with renrot (these methods I have tried only in Lucid). These all process files over nfs, but don't utilize CPU that much.

I wrote some simple test scripts to try to repro this. First script uses dd to read and write several files simultaneously, but that hanged only once (syslog1 attached) even if I let it run for hours. Another script downloads simultaneously six 8MB files using wget, and that seemed to hang more easily. I run it twice, and both times it hanged (dmesg2, dmesg3).

Revision history for this message
Andy Whitcroft (apw) wrote :

We have had some success preventing this behaviour by adjusting a kernel tunable. If those who are able to reproduce this could try increasing the sysctl 'vm.min_free_kbytes' and see how that affects their tests. We have been running with this value approximatly 10x its default value for our testing though this is likely an excessive bump.

    # sysctl vm.min_free_kbytes
    vm.min_free_kbytes = 8080
    # sysctl vm.min_free_kbytes=80800
    #

Please report any testing back here on this bug. Thanks.

Revision history for this message
Alex (d-f0rce) wrote :

@Andy Whitcroft

Your sysctl setting on its own did not solve the problem for me. However while I was googling for vm.min_free_kbytes to check out what it actually does, I came across this site: http://russ.garrett.co.uk/2009/01/01/linux-kernel-tuning/

So I set these values on both, the server and the client:

## increase amount of kernel memory
vm.min_free_kbytes = 65536

## increase TCP max buffer size
net.core.rmem_max = 16777216
net.core.wmem_max = 16777216

## increase TCP autotuning buffer limits
net.ipv4.tcp_rmem = 4096 87380 16777216
net.ipv4.tcp_wmem = 4096 65536 16777216

With these settings my problem is gone using the current lucid kernel 2.6.32-24.42. The system still gets a bit laggy on very high NFS network load but it does not stall anymore.

Revision history for this message
Alex (d-f0rce) wrote :

Sorry for spaming but there is no edit function.

@Andy Whitcroft

I did not try "vm.min_free_kbytes = 65536" on its own.
So maybe your value of 8080 was not high enough for my system.

Revision history for this message
Timo Harmonen (timo-harmonen) wrote :

I tried adjusting vm.min_free_kbytes, and also those other settings suggested by Alex. They didn't seem to have any impact, still the test script hanged as earlier. I tried with 8080, 65536 and 80800, and also with the suggested TCP settings.

It seems that I can repro this case 100% with my wget test script. I have now run it total of 9 times, and at minimum it has taken 18 downloads in 77 seconds and at maximum 264 downloads in 1120 seconds before nfs gets stalled. I have attached the script in case that would help in trying to repro the problem (sorry for abusing ubuntu.com in testing :)). There shouldn't be anything special in my system setup, except that I run everything under kvm.

Revision history for this message
Alex (d-f0rce) wrote :

@Timo Harmonen

I tried your test case but my internet connection is by far too slow to trigger the problem with your script. However I modified your script by using cp instead of wget. So instead of fetching the file from a remote server I just copy it from the local harddisc to the NFS directory. I hope this modification does not destroy your test case.

The script is still running, but I do not even notice any lag:

------
File download count: 1026 Elapsed: 420 s
 20:50:19 up 6:24, 2 users, load average: 3.95, 3.22, 1.94
------

Can you give it a try with "cp" instead of "wget". Does it trigger the problem for you?

Revision history for this message
Timo Harmonen (timo-harmonen) wrote :

@Alex

You are quite right, just using cp is enough to trigger this. I ran it three times in Maverick beta, and it stalled every time.
-----
File copy count: 450 Elapsed: 150 s
File copy count: 252 Elapsed: 85 s
File copy count: 972 Elapsed: 325 s
-----

Revision history for this message
Alex (d-f0rce) wrote :

@Timo Harmonen

I reverted my sysctl settings and indeed it stalled again when using your cp-script. After reenabling the sysctl settings and copying about 40GB I still could not get it to stall. So it seems that the sysctl settings really fixed the problem for me. At least with Lucid kernel 2.6.32-24.42.

For comparison here are my NFS settings. All clients are connected via GB-LAN:

Server: rw,sync,no_subtree_check,no_root_squash
Client: hard,fg,rsize=16384,wsize=16384,acl

I hope you'll find a solution for your problem, too. Good Luck.

Revision history for this message
getnuked (getnuked) wrote :

A week ago I installed a fresh lucid 10.04 amd64 desktop onto a workstation (Athlon II 240, 4GB ECC RAM, 1TB SATAII disk). Within a day this machine locked up with no response to keyboard or mouse. I could ping it yet I couldn't ssh to it, luckily Magic sysrq + REISUB was able to sync the local disk, yet it wouldn't reboot. After looking at the logs I noticed the nfs and kswap errors that eventually brought me to this bug report (I have attached a portion of /var/log/messages showing the similar errors).

At first I couldn't reliably reproduce the lockup, it just happened on its own. However I was able to reproduce it in a few minutes by running a simple loop which copied a cd image to and from an nfs mount then diffing the contents. I later found that I could cause the lockup to occur in under 10 seconds by adding a second instance of the copy loop while also running memtester on half (2GB) of the RAM (which allocates and mlocks the RAM). If I do this test from a VT I can watch the kmesg/nfs dmesg logs you see at the top of this bug report being displayed on the VT in real time.

I am using autofs to mount nfs using the following parameters:

server: rw,sync,no_root_squash,no_subtree_check
client: rw,hard,intr,tcp,fg,nfsvers=3,rsize=32768,wsize=32768

After reading this bug report and the ones from the kernel development I got the impression that the problem was fixed in more recent kernels. Luckily the kernel-ppa team has ported the maverick 2.6.35 kernel for use in lucid. I used the following commands to try out the 2.6.35-21 maverick kernel on the lucid workstation. Unfortunately the lock up happened even with the maverick kernel.

sudo add-apt-repository ppa:kernel-ppa/ppa
sudo apt-get update
sudo apt-get install linux-headers-2.6.35-21-generic linux-image-generic-lts-backport-maverick
sudo apt-get reboot

Apparently this nfs bug is present in not only 2.6.32 yet all the way up to 2.6.35 (four different releases), which ultimately means anyone expecting to use lucid or maverick with nfs will either have to live with lock ups or hope that it eventually gets fixed.

Is there something unique to all of our systems that is masking this from being found during normal regression testing, or perhaps I should ask if NFS is even part of the regular testing?

Revision history for this message
Andy Whitcroft (apw) wrote :

@BlueBuntu -- is the NFS server going non-responsive in that dmesg output the location from which the mounts are made? If so the behaviour on the client is likely correct. I would look to see why the server is non-responsive in that case:

    Sep 18 02:03:01 stratos kernel: [21811.409952] nfs: server 192.168.14.4 not responding, still trying

Revision history for this message
getnuked (getnuked) wrote :

@Andy Whitcroft, yes the nfs server in my situation (192.168.14.4) is the location from which the mounts are made by the workstation that locked up, sorry I should have specified that.

Whenever the nfs client running the lucid/maverick kernel locked up I first checked all the other nfs client workstations we have to ensure their mounts were working fine in addition to the nfs server (in fact my first step was to check our gigabit switches since I have had network equipment failures in the past that resulted in nearly the same kind of symptoms with locked up nfs clients, of course in those situations there were no kernel errors as we have seen here other than the usual "nfs: server X not responding, still trying", and simply replacing the switch with a spare fixed the problem in those instances).

Another thing I forgot to mention previously is that we are using gigabit nics and switches along with jumbo frames on the lan (9k packet size). I am not sure if that has had some impact, yet I would be interested to find out if others have experienced this lockup with or without using jumbo frames on a gigabit lan.

Revision history for this message
Timo Harmonen (timo-harmonen) wrote :

This case is the sole reason I have had to skip upgrading to Lucid. And as the problem seems to be also in Maverick, it seems that I will be stuck with Karmic for even longer.

Please find below a recapture of my findings, hope it would help in investigating this.

I can reliable repro this case both with the latest Maverick beta (2.6.35-22) and Lucid (2.6.32-24). I have only tested with amd64.

Here are the minimal steps needed in my environment

1. Amd64 Maverick (or Lucid) host, install amd64 Maverick (or Lucid) kvm guest.

2. Export a nfs mount in host, mount that in guest. I use the following settings:
  server: rw,nohide,insecure,no_subtree_check,async
  client: timeo=14,rw,_netdev

3. Run the following script in guest, the script hangs every time, latest after creating a few thousand files.

cd <insert-your-nfspath-here>
while true
do
     for i in $(seq 6)
     do
         dd bs=1k count=8000 if=/dev/zero of="file_"$k" &
         k=$((k+1))
     done
     wait
done

Revision history for this message
getnuked (getnuked) wrote :

I just received an email titled "Ubuntu 9.04 reaches end-of-life on October 23, 2010" on the Ubuntu Security mailing list. 9.04 is the most recent version of Ubuntu that does not exhibit the NFS locking symptom as described in this bug (I have experienced this bug with both Lucid and Maverick kernels, I believe other people have reported Karmic kernels exhibiting the same behavior). As a result I respectfully request that the priority of this bug be raised since we now have one month (to the day) before people in our situation have to abandon using Ubuntu or keep using a distro (Jaunty) that will not be supported.

I have been a big admirer of the Ubuntu development team and have had nothing but the best to say about Ubuntu for the past two years. During that time I have been promoting the use of Ubuntu, to both friends and colleagues, having helped deploy it to many desktops and servers. However, I have to say I am really disappointed that this bug has been around since April (5 months now), and no progress has been made. NFS is a major feature and without it how can Ubuntu expect to be taken seriously for use in anything other than on a home PC or laptop?

On a side note, can anyone report any successes with other distros using recent (2.6.3x) kernels? I ask this primarily to help research how (and if) other distros are getting around this problem, in addition to looking for alternatives should the bug still exist when Ubuntu pulls the plug on Jaunty.

Revision history for this message
Bruce Edge (bruce-edge) wrote :

Medium priority !!!!

The flagship server edition hangs on NFS writes is a MEDUIM priority!!!!!!

This has been broken since 10.04 was released and 10.04.1 still has it and it's MEDIUM prio !???

Revision history for this message
Bruce Edge (bruce-edge) wrote :
Download full text (24.0 KiB)

0 %> uname -a

Linux topaz 2.6.32-24-server #43-Ubuntu SMP Thu Sep 16 16:05:42 UTC 2010 x86_64 GNU/Linux

New hardware, new Ubuntu = can't use NFS:

Sep 28 10:12:50 topaz kernel: [604724.768485] SGI XFS with ACLs, security attributes, realtime, large block/inode numbers, no debug enabled
Sep 28 10:12:50 topaz kernel: [604724.770961] SGI XFS Quota Management subsystem
Sep 28 10:12:50 topaz kernel: [604724.801090] JFS: nTxBlock = 8192, nTxLock = 65536
Sep 28 10:12:50 topaz kernel: [604724.853982] NTFS driver 2.1.29 [Flags: R/O MODULE].
Sep 28 10:12:50 topaz kernel: [604724.901501] QNX4 filesystem 0.2.3 registered.
Sep 28 10:12:50 topaz kernel: [604724.993765] Btrfs loaded
Sep 29 15:14:06 topaz kernel: [709201.511036] INFO: task tar:2926 blocked for more than 120 seconds.
Sep 29 15:14:06 topaz kernel: [709201.526445] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Sep 29 15:14:06 topaz kernel: [709201.542739] tar D 0000000000000002 0 2926 16813 0x00000004
Sep 29 15:14:06 topaz kernel: [709201.542751] ffff880211945c48 0000000000000082 0000000000015bc0 0000000000015bc0
Sep 29 15:14:06 topaz kernel: [709201.542761] ffff88015fa931a0 ffff880211945fd8 0000000000015bc0 ffff88015fa92de0
Sep 29 15:14:06 topaz kernel: [709201.542770] 0000000000015bc0 ffff880211945fd8 0000000000015bc0 ffff88015fa931a0
Sep 29 15:14:06 topaz kernel: [709201.542778] Call Trace:
Sep 29 15:14:06 topaz kernel: [709201.542814] [<ffffffffa01e4380>] ? nfs_wait_bit_uninterruptible+0x0/0x20 [nfs]
Sep 29 15:14:06 topaz kernel: [709201.542831] [<ffffffff81558b97>] io_schedule+0x47/0x70
Sep 29 15:14:06 topaz kernel: [709201.542856] [<ffffffffa01e438e>] nfs_wait_bit_uninterruptible+0xe/0x20 [nfs]
Sep 29 15:14:06 topaz kernel: [709201.542866] [<ffffffff815591bf>] __wait_on_bit+0x5f/0x90
Sep 29 15:14:06 topaz kernel: [709201.542885] [<ffffffffa01e4380>] ? nfs_wait_bit_uninterruptible+0x0/0x20 [nfs]
Sep 29 15:14:06 topaz kernel: [709201.542893] [<ffffffff81559268>] out_of_line_wait_on_bit+0x78/0x90
Sep 29 15:14:06 topaz kernel: [709201.542907] [<ffffffff810850f0>] ? wake_bit_function+0x0/0x40
Sep 29 15:14:06 topaz kernel: [709201.542925] [<ffffffffa01e436f>] nfs_wait_on_request+0x2f/0x40 [nfs]
Sep 29 15:14:06 topaz kernel: [709201.542945] [<ffffffffa01e879f>] nfs_wait_on_requests_locked+0x7f/0xd0 [nfs]
Sep 29 15:14:06 topaz kernel: [709201.542966] [<ffffffffa01e9bde>] nfs_sync_mapping_wait+0x9e/0x1a0 [nfs]
Sep 29 15:14:06 topaz kernel: [709201.542988] [<ffffffffa01e9fc9>] nfs_write_mapping+0x79/0xb0 [nfs]
Sep 29 15:14:06 topaz kernel: [709201.543010] [<ffffffffa01ea037>] nfs_wb_all+0x17/0x20 [nfs]
Sep 29 15:14:06 topaz kernel: [709201.543031] [<ffffffffa01d8f7a>] nfs_do_fsync+0x2a/0x60 [nfs]
Sep 29 15:14:06 topaz kernel: [709201.543047] [<ffffffffa01d91c5>] nfs_file_flush+0x75/0xa0 [nfs]
Sep 29 15:14:06 topaz kernel: [709201.543057] [<ffffffff8114225c>] filp_close+0x3c/0x90
Sep 29 15:14:06 topaz kernel: [709201.543064] [<ffffffff81142367>] sys_close+0xb7/0x120
Sep 29 15:14:06 topaz kernel: [709201.543073] [<ffffffff810131b2>] system_call_fastpath+0x16/0x1b
Sep 29 15:16:06 topaz kernel: [709321.540858] INFO: task tar:2926 blocked...

Revision history for this message
David McBride (david-mcbride) wrote :

Hi Thag,

I don't know if this helps you, but I'm currently running NFS servers and clients successfully on 10.04 after having replaced the kernel with Linus's upstream 2.6.35.6.

When testing with 2.6.35, enabling "Forced pre-emption" appeared to expose similar in-kernel deadlocking bugs which did not occur with just voluntary pre-emption enabled.

Note that some earlier point releases of 2.6.35 did not *serve* NFS properly from volumes backed by XFS, and would spuriously return "Stale NFS filehandle" for inodes which were valid; I'd recommend using stable release .6 or later if you're running in a similar configuration.

Finally, I'm sympathetic towards the Ubuntu chaps -- they're trying to roll full distribution releases every 6 months to a pre-determined schedule with (what appears to be) not enough manpower and not enough time to push patches back upstream. They're going to drop things..

Revision history for this message
ab (aaronb) wrote :

The large size file transfer mentioned in the original posting sounds like the problem I'm having, too, but I'm not using NFS, I'm using an mdadm RAID1 setup. When a large file is copied, only the dpkg/apt/synaptic packages run slowly. The rest of the system seems to function well, including text terminals, gdm, and file transfers within and between non-RAID drives.

I do not remember having this problem with any other Ubuntu flavors and versions. It started when I setup RAID. If I remove the RAID, or do not transfer large files when running the package programs, it does not seem to cause problems.

My machine:
- OS: Ubuntu Linux 10.10
- CPU: Intel Q8200 Core 2 Quad

Revision history for this message
manojav (manojav) wrote :
Revision history for this message
Hernan (hernan-123) wrote :
Download full text (5.0 KiB)

I'm having a similar problem but copying a file from Ubuntu to a Windows share using smb/CIFS (as a result of a backup triggered from a cron job).
The problem occurs erratically and after hours I have to reboot the machine (only a 'ping' from another machine reveals that the system is alive...).
I'm running Ubuntu 10.04 Lucid, file is on LVM volume on top of a raid1/mdadm, swap directly over raid1/mdam
uname : Linux 2.6.32-25-generic #45-Ubuntu SMP Sat Oct 16 19:52:42 UTC 2010 x86_64 GNU/Linux

First lines in kernel log:
Nov 17 04:00:05 hernan kernel: [381217.309261] EXT4-fs (dm-1): ext4_orphan_cleanup: deleting unreferenced inode 3679614
...
Nov 17 04:00:05 hernan kernel: [381217.427197] EXT4-fs (dm-1): ext4_orphan_cleanup: deleting unreferenced inode 3679431
Nov 17 04:00:05 hernan kernel: [381217.427217] EXT4-fs (dm-1): 13 orphan inodes deleted
Nov 17 04:00:05 hernan kernel: [381217.427221] EXT4-fs (dm-1): recovery complete
Nov 17 04:00:05 hernan kernel: [381217.661830] EXT4-fs (dm-1): mounted filesystem with ordered data mode
Nov 17 04:12:40 hernan kernel: [381972.960362] CIFS VFS: Error -4 sending data on socket to server
Nov 17 04:12:40 hernan kernel: [381972.964846] CIFS VFS: No response to cmd 47 mid 34736
Nov 17 04:12:40 hernan kernel: [381972.964850] CIFS VFS: No response to cmd 47 mid 34734
Nov 17 04:12:40 hernan kernel: [381972.964854] CIFS VFS: Write2 ret -11, wrote 0
Nov 17 04:12:40 hernan kernel: [381972.964868] CIFS VFS: No response to cmd 47 mid 34711
Nov 17 04:12:40 hernan kernel: [381972.964877] CIFS VFS: No response to cmd 47 mid 34735
Nov 17 04:16:28 hernan kernel: [382200.850064] INFO: task kswapd0:52 blocked for more than 120 seconds.
Nov 17 04:16:28 hernan kernel: [382200.850071] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 17 04:16:28 hernan kernel: [382200.850073] kswapd0 D ffffffffa004f3e0 0 52 2 0x00000000
Nov 17 04:16:28 hernan kernel: [382200.850078] ffff8801398e1590 0000000000000046 0000000000015bc0 0000000000015bc0
Nov 17 04:16:28 hernan kernel: [382200.850083] ffff88013a84df80 ffff8801398e1fd8 0000000000015bc0 ffff88013a84dbc0
Nov 17 04:16:28 hernan kernel: [382200.850087] 0000000000015bc0 ffff8801398e1fd8 0000000000015bc0 ffff88013a84df80
Nov 17 04:16:28 hernan kernel: [382200.850091] Call Trace:
Nov 17 04:16:28 hernan kernel: [382200.850102] [<ffffffff81541b6d>] schedule_timeout+0x22d/0x300
Nov 17 04:16:28 hernan kernel: [382200.850107] [<ffffffff81012b0e>] ? common_interrupt+0xe/0x13
Nov 17 04:16:28 hernan kernel: [382200.850111] [<ffffffff81542ace>] __down+0x7e/0xc0
Nov 17 04:16:28 hernan kernel: [382200.850116] [<ffffffff81089501>] down+0x41/0x50
Nov 17 04:16:28 hernan kernel: [382200.850123] [<ffffffffa0488719>] cifs_reconnect_tcon+0x1a9/0x2f0 [cifs]
Nov 17 04:16:28 hernan kernel: [382200.850130] [<ffffffffa048daf7>] small_smb_init+0x37/0x80 [cifs]
Nov 17 04:16:28 hernan kernel: [382200.850136] [<ffffffffa048eeba>] CIFSSMBWrite2+0x7a/0x290 [cifs]
Nov 17 04:16:28 hernan kernel: [382200.850143] [<ffffffffa049a8af>] cifs_write+0x1bf/0x480 [cifs]
Nov 17 04:16:28 hernan kernel: [382200.850150] [<ffffffffa049d6ee>] T.1064+0xee/0x190 [cifs]
Nov...

Read more...

Revision history for this message
Eric Pfeiffer (eric-pfeiffer) wrote :

I had the same issue with all of my linux clients here accessing a gigabit NAS. However after messing around the last weeks with this issue i finally found this hint:

http://publib.boulder.ibm.com/infocenter/pseries/v5r3/index.jsp?topic=/com.ibm.aix.prftungd/doc/prftungd/HT_prftungd_impr_nfs_client_writing_perf.htm

Mounting the NFS shares with option combehind in the clients solved the problem for me.

Revision history for this message
Eric Pfeiffer (eric-pfeiffer) wrote :

Ok sorry @ all - i fooled myself. After breaking the nfs mounts with this incompatible option i was writing to local storage...please forget about this. At all i'm now on the list and looking forward to a solution of this issue.

Revision history for this message
Eric Pfeiffer (eric-pfeiffer) wrote :

Just in case this can help someone (if not sorry for my frequent spam):

After long time of investigation, which clients really have that look-ups and which not i concluded that in my case the problem was caused by the simple fact, that those clients where solely NATed (most of them VMs, Ubuntu 9.04 .. 10.10). And correct I should have realized earlier that NFS over NAT is a 'not so good' idea (bidirectional port handling, file locks etc.). But the resulting errors are very similar to what is described in the report here.

So what can help, if getting a dedicated IP for all machines is not an option?

Do not mount the shares via fstab, instead take a look at autofs, a really great utility for doing on demand mounts and also handling not 100% reliable connections.

Sample config after apt-get install autofs5:

add to /etc/auto.master:
/mnt/myserver /etc/auto.guests --timeout=60 --ghost

create /etc/auto.guests and add (modify defaults to your demands):
/guests -defaults myserver:/your_export_path/guests

create a symbolic link where you really want to access the share:
ln -s /home/guests /mnt/myserver/guests

One thing that remains - now i can write huge files to the NFS server even from clients behind a NAT but the speed decreases the larger the file is (which remembers me on #71 - but i can't find a similar mount option in ubuntu). Anyone any idea?

Revision history for this message
Nrm (smith32-35) wrote :

Hi everyone,

I've got the same problem, and if I use my WIFI card, it's "solved".
My ethernet card is :

09:00.0 Ethernet controller: Atheros Communications Atheros AR8132 / L1c Gigabit Ethernet Adapter (rev c0)

Revision history for this message
StoatWblr (stoatwblr) wrote :

Your wifi card is likely a _lot_ slower than the ethernet. This only seems to manifest at high throughputs.

Revision history for this message
Nuno Sucena Almeida (slug-debian) wrote :

Still having this problem almost on a daily basis (lucid 10.04 amd64), tried all the workarounds (sysctl, newer 2.6.35-23-generic kernel, etc), none worked.

Revision history for this message
David Ressman (davidressman) wrote :

This is truly insane. We have a support contract, *and* we've provided Canonical with a patch that solves the problem, but we still can't get them to add it into the mainline kernel.

Revision history for this message
Tim Gardner (timg-tpi) wrote :

'NFS: kswapd must not block in nfs_release_page' was released as part of the 2.6.32 stable update series and was released in 2.6.32-25.44

Changed in linux (Ubuntu Lucid):
assignee: nobody → Tim Gardner (timg-tpi)
status: New → Fix Released
Revision history for this message
Tim Gardner (timg-tpi) wrote :

b608b283a962caaa280756bc8563016a71712acf was released as part of 2.6.35

Changed in linux (Ubuntu Maverick):
assignee: nobody → Tim Gardner (timg-tpi)
status: New → Fix Released
Changed in linux (Ubuntu Natty):
status: In Progress → Fix Released
Revision history for this message
David Ressman (davidressman) wrote :

I'm sorry my comment sounded snarky--this caught me on an (unrelated) bad day. I ran 2.6.32.27-generic, and the problem occurred almost immediately. This problem appears to be in nfs_do_fsync(), not nfs_release_page().

Revision history for this message
David Ressman (davidressman) wrote :

(i.e., please reopen this bug)

Revision history for this message
Tim Gardner (timg-tpi) wrote :

David - I think you should start a new bug. Though the symptoms are similar, it appears to be a different bug. Also, how about asking Trond Myklebust <email address hidden> if he agrees with your assessment re: nfs_do_fsync().

Revision history for this message
David Ressman (davidressman) wrote :

Actually, I think you might be correct, although it looks like bug 585657 could be the one.

Revision history for this message
David Ressman (davidressman) wrote :

(and the patch was actually a backport of a patch that Trond committed to 2.6.35.something)

Revision history for this message
Sean Clarke (sean-clarke) wrote :

Seeing this on Maverick - especially when booting KVM images over NFS, server is almost unusable and system never recovers until a reboot..

Linux enterprise 2.6.35-27-server #47-Ubuntu SMP Fri Feb 11 23:09:19 UTC 2011 x86_64 GNU/Linux

Revision history for this message
David McGiven (davidmcgivenn) wrote :

Dear All,

I'm having this issue as well but I don't understand what is the proposed solution. Where is that 2.6.35.something kernel that fixes the problem ?

Please help!

I can see the bug with those two kernels :
2.6.35-020635rc1
2.6.32-30.59

Thanks

Revision history for this message
David McGiven (davidmcgivenn) wrote :

This is fixed with 2.6.32-31

Revision history for this message
Ken Pratt (kenpratt) wrote :

Bug is back in 3.0.0-17-generic #30-Ubuntu SMP Thu Mar 8 20:45:39 UTC 2012 x86_64 x86_64 x86_64 GNU/Linux

When copying a large file over nfs4v, Nautilus reports 606.6MB in the first progress bar update to the GUI then hangs forever. The rest of my desktop remains responsive. Nautilus, however, is not. And, I can ssh to the machine that is exporting the NFS share to which I am copying - so networking is still fine. However, any attempt to access the NFS shares from the command line simply hang forever.

I am copying over GigE to a FitPCI2 (small atom based computer).

I am using a fully updated Ubuntu

LSB Version: core-2.0-amd64:core-2.0-noarch:core-3.0-amd64:core-3.0-noarch:core-3.1-amd64:core-3.1-noarch:core-3.2-amd64:core-3.2-noarch:core-4.0-amd64:core-4.0-noarch
Distributor ID: Ubuntu
Description: Ubuntu 11.10
Release: 11.10
Codename: oneiric

The only reported error shows up in syslog. It is the error indicating that the nautilus process is unresponsive.

The only way to clear the situation is to shutdown - which halts - I assume stuck on unmounting the NFS shares. So I have to power cycle.

I am using nfsv4 via autofs.

Revision history for this message
cpisbell (chrisisbell) wrote :
Download full text (3.3 KiB)

Having similar problem on:

Linux chris-laptop 3.0.0-19-generic #32-Ubuntu SMP Thu Apr 5 18:22:38 UTC 2012 x86_64 x86_64 x86_64 GNU/Linux.

The wired Ethernet interface seems to fail until the system is rebooted. (The slower wireless interface - which is running in parallel to the same switch - was not affected.)

The system log shows the following:

Apr 19 18:17:31 chris-laptop kernel: [ 2400.492131] INFO: task python:4151 blocked for more than 120 seconds.
Apr 19 18:17:31 chris-laptop kernel: [ 2400.492135] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Apr 19 18:17:31 chris-laptop kernel: [ 2400.492138] python D ffffffff81805120 0 4151 4150 0x00000000
Apr 19 18:17:31 chris-laptop kernel: [ 2400.492142] ffff880134cf1bb8 0000000000000046 ffff880134cf1b58 ffffffff81032a79
Apr 19 18:17:31 chris-laptop kernel: [ 2400.492147] ffff880134cf1fd8 ffff880134cf1fd8 ffff880134cf1fd8 0000000000012a40
Apr 19 18:17:31 chris-laptop kernel: [ 2400.492150] ffff880138f10000 ffff880136660000 ffff880134cf1b98 ffff88013fd132c0
Apr 19 18:21:31 chris-laptop kernel: [ 2640.492205] Call Trace:
Apr 19 18:21:31 chris-laptop kernel: [ 2640.492213] [<ffffffff81032a79>] ? default_spin_lock_flags+0x9/0x10
Apr 19 18:21:31 chris-laptop kernel: [ 2640.492218] [<ffffffff8110a320>] ? __lock_page+0x70/0x70
Apr 19 18:21:31 chris-laptop kernel: [ 2640.492222] [<ffffffff815f22df>] schedule+0x3f/0x60
Apr 19 18:21:31 chris-laptop kernel: [ 2640.492225] [<ffffffff815f238f>] io_schedule+0x8f/0xd0
Apr 19 18:21:31 chris-laptop kernel: [ 2640.492227] [<ffffffff8110a32e>] sleep_on_page+0xe/0x20
Apr 19 18:21:31 chris-laptop kernel: [ 2640.492230] [<ffffffff815f2baf>] __wait_on_bit+0x5f/0x90
Apr 19 18:21:31 chris-laptop kernel: [ 2640.492233] [<ffffffff8110a498>] wait_on_page_bit+0x78/0x80
Apr 19 18:21:31 chris-laptop kernel: [ 2640.492237] [<ffffffff81081de0>] ? autoremove_wake_function+0x40/0x40
Apr 19 18:21:31 chris-laptop kernel: [ 2640.492240] [<ffffffff8110a5ac>] filemap_fdatawait_range+0x10c/0x1a0
Apr 19 18:21:31 chris-laptop kernel: [ 2640.492243] [<ffffffff8110bfd8>] filemap_write_and_wait_range+0x68/0x80
Apr 19 18:21:31 chris-laptop kernel: [ 2640.492247] [<ffffffff81194ac2>] vfs_fsync_range+0x42/0xa0
Apr 19 18:21:31 chris-laptop kernel: [ 2640.492250] [<ffffffff81194b8c>] vfs_fsync+0x1c/0x20
Apr 19 18:21:31 chris-laptop kernel: [ 2640.492272] [<ffffffffa06632e3>] nfs_file_flush+0x53/0x80 [nfs]
Apr 19 18:21:31 chris-laptop kernel: [ 2640.492276] [<ffffffff811668df>] filp_close+0x3f/0x90
Apr 19 18:21:31 chris-laptop kernel: [ 2640.492280] [<ffffffff81060faa>] put_files_struct.part.14+0x7a/0xe0
Apr 19 18:21:31 chris-laptop kernel: [ 2640.492283] [<ffffffff81062aa8>] put_files_struct+0x18/0x20
Apr 19 18:21:31 chris-laptop kernel: [ 2640.492286] [<ffffffff81062b74>] exit_files+0x54/0x70
Apr 19 18:21:31 chris-laptop kernel: [ 2640.492289] [<ffffffff8106308d>] do_exit+0x19d/0x440
Apr 19 18:21:31 chris-laptop kernel: [ 2640.492291] [<ffffffff810634d4>] do_group_exit+0x44/0xa0
Apr 19 18:21:31 chris-laptop kernel: [ 2640.492294] [<ffffffff81063547>] sys_exit_group+0x17/0x20
Apr 19 18:21:31 chris-laptop kernel: [ 2640.492297]...

Read more...

Revision history for this message
Goktug YILDIRIM (goktug-yildirim) wrote :

Hi,

I have the same NFS problem with 12.04 and kernel 3.2.0-25. Symptoms are very same described above and easy to re-produce.
I'd like to know if there is a cure by now.

Thanks.

PS: In order to assist, I can deliver logs or make test progress if needed.

Revision history for this message
dth (destotelhorus) wrote :

Bug affects 12.04 aswell:

# uname -a
Linux vm-orion 3.2.0-23-generic #36-Ubuntu SMP Tue Apr 10 20:39:51 UTC 2012 x86_64 x86_64 x86_64 GNU/Linux

# lsb_release --all
No LSB modules are available.
Distributor ID: Ubuntu
Description: Ubuntu 12.04 LTS
Release: 12.04
Codename: precise

The machine in question is a VM run with KVM. It has 1 GiBi of RAM and no SWAP.

Please inform me if I can be of any further assistance.

Revision history for this message
icedfusion (icedfusion) wrote :

Also seeing this bug on 12.04.

When copying large files, the speed of the copy drops of dramatically until at some point it freezes completely and I loose nautilus and any networking activity/access to the server. I have to reboot the server to get it back on the network.

This issue makes NFS unusable.

Copying via SMB results in how I would expect NFS to be working. Fast and (almost)easy.

# uname -a
Linux iceserver 3.2.0-29-generic #46-Ubuntu SMP Fri Jul 27 17:03:23 UTC 2012 x86_64 x86_64 x86_64 GNU/Linux

I am wondering if it is a 64bit issue.

Cheers

Revision history for this message
Jason (jaseeverett) wrote :

This bug is also a problem in Ubuntu 12.10.

Linux zoop 3.5.0-18-generic #29-Ubuntu SMP Fri Oct 19 10:26:51 UTC 2012 x86_64 x86_64 x86_64 GNU/Linux

I am fully updated to today.

Revision history for this message
Timo (timo-de) wrote :

Having the same problems:

NFS (v4) share on freeBSD 8.03 up-to-date (Jan 2013)
Ubuntu 12.10 64bit up-to-date (Jan 2013)

I can copy (read) big files with consistant rates at about 70MB/s from the NFS share.
But when I write to the share it starts with 70MB/s for about 3 seconds, then transfer speed drops to 0 MB/s (really zero, see with nfsstat), and after 80 sec the transfer speed goes up to about 40MB/s for like 10sec, then it drops to 0 MB/s again, this repeats until the file is fully transferred.

Revision history for this message
Jan (jan-wiele) wrote :

I also have this problem. Even when writing to different shares: Saving a big download (8GB) to /pub/games results in a lockup of my desktop. Programs are unable to access /home (cannot launch any programs, kde plasma does not respond anymore, new page in chrome results in "Waiting for the cache").

Client: Ubuntu 12.10 (GNU/Linux 3.7.0-7-generic x86_64)
Server: Ubuntu 12.04.1 LTS (GNU/Linux 3.2.28-bcache+ x86_64)

Revision history for this message
Ceiling Cat (ceilingcat-r) wrote :

Having same problem on
Client: Ubuntu 12.04.2 LTS (GNU/Linux 3.2.0-69-generic-pae i686)
Server: Ubuntu 12.04.5 LTS (GNU/Linux 3.2.0-77-generic x86_64)

This is frighteningly bad.

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.