2.6.32-rc1-git2: Reported regressions 2.6.30 -> 2.6.31

Frans Pop · External Since: May 04, 2006 Posts: 460

On Monday 05 October 2009, Frans Pop wrote:
> With .32 it was obviously impossible to get that info due to the total
> freeze of the desktop. Not sure if the scheduler changes in .32
> contribute to this. Guess I could find out by doing the same test with
> .31.

I've tried with .31.1 too now and there does seem to be a scheduler
component too. With .31.1 I also get the SKB allocation errors, but the
desktop freeze seems to be less severe than with .32-rc3. I would suggest
looking into that _after_ the allocation issue has been traced/solved.

I did manage to really (partially) hang up the desktop with .31.1: music
did not come back and the task manager of the KDE desktop remained frozen,
but I could still use konsole [1].
I suspect this is because I also got an OOPS in between the SKB failures:

IP: [<ffffffffa0444ea2>] rpcauth_checkverf+0x4e/0x5a[sunrpc]
PGD 77b83067 PUD 0
Oops: 0000 [#1] SMP
last sysfs file: /sys/class/power_supply/C23D/charge_full
CPU 0
Modules linked in: i915 drm i2c_algo_bit i2c_core ppdev parport_pc lp parport cpufreq_conservative
cpufreq_userspace cpufreq_stats cpufreq_powersave ipv6 nfsd exportfs nfs lockd nfs_acl auth_rpcgss
sunrpc ext2 coretemp hp_wmi acpi_cpufreq loop snd_hda_codec_analog snd_hda_intel snd_hda_codec
arc4 snd_pcm_oss snd_mixer_oss ecb snd_pcm snd_seq_dummy snd_seq_oss iwlagn iwlcore snd_seq_midi
pcmcia mac80211 snd_rawmidi usblp snd_seq_midi_event snd_seq pcspkr cfg80211 yenta_socket
rsrc_nonstatic pcmcia_core psmouse snd_timer snd_seq_device rfkill serio_raw snd soundcore
snd_page_alloc hp_accel lis3lv02d video container output wmi intel_agp input_polldev battery ac
processor button joydev evdev ext3 jbd mbcache sha256_generic aes_x86_64 aes_generic cbc usbhid hid
dm_crypt dm_mirror dm_region_hash dm_log dm_snapshot dm_mod sg sr_mod sd_mod cdrom ide_pci_generic piix
ide_core pata_acpi uhci_hcd ata_piix ohci1394 sdhci_pci sdhci mmc_core led_class ieee1394 ricoh_mmc
ata_generic ehci_hcd libta e1000e scsi_mod thermal fan thermal_sys [last unloaded: scsi_wait_scan]
Pid: 3226, comm: rpciod/0 Not tainted 2.6.31.1 #20 HP Compaq 2510p Notebook PC
RIP: 0010:[<ffffffffa0444ea2>] [<ffffffffa0444ea2>]rpcauth_checkverf+0x4e/0x5a [sunrpc]
RSP: 0018:ffff88007aafbda0 EFLAGS: 00010246
RAX: 0000000400001000 RBX: ffff88003a718e40 RCX: 0000000000000001
RDX: ffff880038b821bc RSI: ffff880038b821c8 RDI: ffff8800618358c8
RBP: ffff88007aafbdc0 R08: 0000000000000000 R09: 0000000000000000
R10: ffff880001514d80 R11: ffff8800536401f0 R12: ffff8800618358c8
R13: ffff880038b821c8 R14: ffff880037bb4bd0 R15: ffffffffa04bf52b
FS: 0000000000000000(0000) GS:ffff880001504000(0000) knlGS:0000000000000000
CS: 0010 DS: 0018 ES: 0018 CR0: 000000008005003b
CR2: 0000000400001038 CR3: 0000000067ee5000 CR4: 00000000000006f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Process rpciod/0 (pid: 3226, threadinfo ffff88007aafa000, task ffff88007c431670)
Stack:
ffff88007aafbde0 ffff880037bb4bd0 ffff8800618358c8 ffff880061835958
<0> ffff88007aafbe00 ffffffffa043e24a ffff88007c4319e0 ffff8800618358c8
<0> ffff880061835970 ffff880061835958 0000000000000000 0000000000000001
Call Trace:
[<ffffffffa043e24a>] call_decode+0x374/0x68e [sunrpc]
[<ffffffffa044430e>] __rpc_execute+0x86/0x244 [sunrpc]
[<ffffffffa04444f8>] ? rpc_async_schedule+0x0/0x12 [sunrpc]
[<ffffffffa0444508>] rpc_async_schedule+0x10/0x12 [sunrpc]
[<ffffffff81048bd5>] worker_thread+0x132/0x1ca
[<ffffffff8104c657>] ? autoremove_wake_function+0x0/0x38
[<ffffffff81048aa3>] ? worker_thread+0x0/0x1ca
[<ffffffff8104c335>] kthread+0x8f/0x97
[<ffffffff8100ca7a>] child_rip+0xa/0x20
[<ffffffff8104c2a6>] ? kthread+0x0/0x97
[<ffffffff8100ca70>] ? child_rip+0x0/0x20
Code: 30 0f b7 b7 06 01 00 00 48 89 d9 48 c7 c7 30 42
45 a0 48 8b 40 10 48 8b 50 10 31 c0 e8 73 f8 e0 e0 48 8b 43 38 4c 89 ee 4c 89 e7 <ff> 50 38 41 59 5b 41 5c 41 5d c9 c3 55 48 89 e5 41 55 49 89 f5
RIP [<ffffffffa0444ea2>] rpcauth_checkverf+0x4e/0x5a [sunrpc]
RSP <ffff88007aafbda0>
CR2: 0000000400001038

Not sure whether it's worth following up on that as a separate issue.

Cheers,
FJP

[1] KDE's task manager freezing for short periods is normal for me while
amarok is blocked by NFS. This normally only happens when I start amarok
for the first time, but it does explain how the NFS oops can have the
same effect.
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo.RemoveThis@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/

Mel Gorman · External Since: May 19, 2006 Posts: 253

On Mon, Oct 05, 2009 at 08:50:58AM +0200, Frans Pop wrote:
> On Monday 05 October 2009, Frans Pop wrote:
> > I'll dig into this a bit more as it looks like this should be
> > reproducible, probably even without the kernel build. Next step is to
> > see how .30 behaves in the same situation.
>
> This looks conclusive. I tested .30 and .32-rc3 from clean reboots and
> only starting gitk. I only started music playing in the background
> (amarok) from an NFS share to ensure network activity.
>
> With .32-rc3 I got 4 SKB allocation errors while starting the *second* gitk
> instance. And the system was completely frozen with music stopped until gitk
> finished loading.
>
> With .30 I was able to start *three* gitk's (which meant 2 of them got
> (partially) swapped out) without any allocation errors. And with the system
> remaining relatively responsive. There was a short break in the music while
> I started the 2nd instance, but it just continued playing afterwards. There
> was also some mild latency in the mouse cursor, but nothing like the full
> desktop freeze I get with .32-rc3.
>
> With .30 I looked at /proc/buddyinfo while the 3rd gitk was being started,
> and that looked fairly healthy all the time:
> Node 0, zone DMA 5 9 22 20 21 11 0 0 0 0 1
> Node 0, zone DMA32 579 67 25 8 5 1 1 0 1 1 0
> Node 0, zone DMA 5 9 22 20 21 11 0 0 0 0 1
> Node 0, zone DMA32 276 54 13 15 8 10 3 1 1 1 0
> Node 0, zone DMA 4 9 22 20 21 11 0 0 0 0 1
> Node 0, zone DMA32 119 45 24 18 12 4 5 2 1 1 0
> Node 0, zone DMA 4 9 22 20 21 11 0 0 0 0 1
> Node 0, zone DMA32 527 13 9 5 5 3 2 1 1 1 0
> Node 0, zone DMA 5 9 22 20 21 11 0 0 0 0 1
> Node 0, zone DMA32 1375 24 7 7 8 5 1 1 0 1 0
> Node 0, zone DMA 5 9 22 20 21 11 0 0 0 0 1
> Node 0, zone DMA32 329 21 3 3 17 8 5 1 0 1 0
>
> With .32 it was obviously impossible to get that info due to the total
> freeze of the desktop. Not sure if the scheduler changes in .32 contribute
> to this. Guess I could find out by doing the same test with .31.
>
> One thing I should mention: my swap is an LVM volume that's in a VG that's
> on a LUKS encrypted partition.
>
> Does this give you enough info to go on, or should I try a bisection?
>

I'll be trying to reproduce it, but it's unlikely I'll manage to
reproduce it reliably as there may be a specific combination of hardware
necessary as well. What I'm going to try is writing a module that
allocates order-5 every second GFP_ATOMIC and see can I reproduce using
scenarios similar to yours but it'll take some time with no guarantee of
success. If you could bisect it, it would be fantastic.

Thanks

--
Mel Gorman
Part-time Phd Student Linux Technology Center
University of Limerick IBM Dublin Software Lab
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo.DeleteThis@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/

Rafael J. Wysocki · External Since: May 20, 2006 Posts: 1721

On Monday 05 October 2009, Justin Mattock wrote:
> On Thu, Oct 1, 2009 at 12:56 PM, Rafael J. Wysocki <rjw DeleteThis @sisk.pl> wrote:
> > This message has been generated automatically as a part of a report
> > of regressions introduced between 2.6.30 and 2.6.31.
> >
> > The following bug entry is on the current list of known regressions
> > introduced between 2.6.30 and 2.6.31. Please verify if it still should
> > be listed and let me know (either way).
> >
> >
> > Bug-Entry : http://bugzilla.kernel.org/show_bug.cgi?id=14267
> > Subject : Disassociating atheros wlan
> > Submitter : Kristoffer Ericson <kristoffer.ericson DeleteThis @gmail.com>
> > Date : 2009-09-24 10:16 (8 days old)
> > References : http://marc.info/?l=linux-kernel&m=125378723723384&w=4
> >
> >
> >
>
> Sorry for the delay
> (spent some time in bodie).
> yes it should be still open.

Thanks for the update.

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

Frans Pop · External Since: May 04, 2006 Posts: 460

On Monday 05 October 2009, Mel Gorman wrote:
> On Mon, Oct 05, 2009 at 08:50:58AM +0200, Frans Pop wrote:
> > On Monday 05 October 2009, Frans Pop wrote:
> > > I'll dig into this a bit more as it looks like this should be
> > > reproducible, probably even without the kernel build. Next step is
> > > to see how .30 behaves in the same situation.
> >
> > This looks conclusive. I tested .30 and .32-rc3 from clean reboots and
> > only starting gitk. I only started music playing in the background
> > (amarok) from an NFS share to ensure network activity.
> >
> > With .32-rc3 I got 4 SKB allocation errors while starting the *second*
> > gitk instance. And the system was completely frozen with music stopped
> > until gitk finished loading.
> >
> > With .30 I was able to start *three* gitk's (which meant 2 of them got
> > (partially) swapped out) without any allocation errors. And with the
> > system remaining relatively responsive. There was a short break in the
> > music while I started the 2nd instance, but it just continued playing
> > afterwards. There was also some mild latency in the mouse cursor, but
> > nothing like the full desktop freeze I get with .32-rc3.
> >
> > One thing I should mention: my swap is an LVM volume that's in a VG
> > that's on a LUKS encrypted partition.
> >
> > Does this give you enough info to go on, or should I try a bisection?
>
> I'll be trying to reproduce it, but it's unlikely I'll manage to
> reproduce it reliably as there may be a specific combination of hardware
> necessary as well. What I'm going to try is writing a module that
> allocates order-5 every second GFP_ATOMIC and see can I reproduce using
> scenarios similar to yours but it'll take some time with no guarantee of
> success. If you could bisect it, it would be fantastic.

And the winner is:
2ff05b2b4eac2e63d345fc731ea151a060247f53 is first bad commit
commit 2ff05b2b4eac2e63d345fc731ea151a060247f53
Author: David Rientjes <rientjes RemoveThis @google.com>
Date: Tue Jun 16 15:32:56 2009 -0700

oom: move oom_adj value from task_struct to mm_struct

I'm confident that the bisection is good. The test case was very reliable
while zooming in on the merge from akpm.

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

David Rientjes · External Since: Jan 29, 2007 Posts: 178

On Mon, 5 Oct 2009, Frans Pop wrote:

> And the winner is:
> 2ff05b2b4eac2e63d345fc731ea151a060247f53 is first bad commit
> commit 2ff05b2b4eac2e63d345fc731ea151a060247f53
> Author: David Rientjes <rientjes DeleteThis @google.com>
> Date: Tue Jun 16 15:32:56 2009 -0700
>
> oom: move oom_adj value from task_struct to mm_struct
>
> I'm confident that the bisection is good. The test case was very reliable
> while zooming in on the merge from akpm.
>

I doubt it for two reasons: (i) this commit was reverted in 0753ba0 since
2.6.31-rc7 and is no longer in the kernel, and (ii) these are GFP_ATOMIC
allocations which would be unaffected by oom killer scores.
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo DeleteThis @vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/

KOSAKI Motohiro · External Since: Jan 15, 2009 Posts: 112

> On Mon, 5 Oct 2009, Frans Pop wrote:
>
> > And the winner is:
> > 2ff05b2b4eac2e63d345fc731ea151a060247f53 is first bad commit
> > commit 2ff05b2b4eac2e63d345fc731ea151a060247f53
> > Author: David Rientjes <rientjes.DeleteThis@google.com>
> > Date: Tue Jun 16 15:32:56 2009 -0700
> >
> > oom: move oom_adj value from task_struct to mm_struct
> >
> > I'm confident that the bisection is good. The test case was very reliable
> > while zooming in on the merge from akpm.
> >
>
> I doubt it for two reasons: (i) this commit was reverted in 0753ba0 since
> 2.6.31-rc7 and is no longer in the kernel, and (ii) these are GFP_ATOMIC
> allocations which would be unaffected by oom killer scores.

I agree. this patch is pretty obvious correct. it was reverted by
one unfortunately regression.

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

Mel Gorman · External Since: May 19, 2006 Posts: 253

On Mon, Oct 05, 2009 at 05:04:55PM -0700, David Rientjes wrote:
> On Mon, 5 Oct 2009, Frans Pop wrote:
>
> > And the winner is:
> > 2ff05b2b4eac2e63d345fc731ea151a060247f53 is first bad commit
> > commit 2ff05b2b4eac2e63d345fc731ea151a060247f53
> > Author: David Rientjes <rientjes.RemoveThis@google.com>
> > Date: Tue Jun 16 15:32:56 2009 -0700
> >
> > oom: move oom_adj value from task_struct to mm_struct
> >
> > I'm confident that the bisection is good. The test case was very reliable
> > while zooming in on the merge from akpm.
> >
>
> I doubt it for two reasons: (i) this commit was reverted in 0753ba0 since
> 2.6.31-rc7 and is no longer in the kernel, and (ii) these are GFP_ATOMIC
> allocations which would be unaffected by oom killer scores.
>

However, the problem was reported to start showing up in 2.6.31-rc1 so
while it might not be *the* patch, it might be making the type of change
that caused more fragmentation. This patch adjusted the size of
mm_struct and maybe it was enough to change the "order" required for the
slab. Maybe there are other slabs that have changed size as well in that
timeframe.

Frans, what is the size of mm_struct before and after this patch was
applied? Find it with either

grep mm_struct /proc/slabinfo

and if the information is not available there, try

cat /sys/kernel/slab/mm_struct/slab_size and
/sys/kernel/slab/mm_struct/order

Thanks

--
Mel Gorman
Part-time Phd Student Linux Technology Center
University of Limerick IBM Dublin Software Lab
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo.RemoveThis@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/

David Rientjes · External Since: Jan 29, 2007 Posts: 178

On Tue, 6 Oct 2009, Mel Gorman wrote:

> > > And the winner is:
> > > 2ff05b2b4eac2e63d345fc731ea151a060247f53 is first bad commit
> > > commit 2ff05b2b4eac2e63d345fc731ea151a060247f53
> > > Author: David Rientjes <rientjes DeleteThis @google.com>
> > > Date: Tue Jun 16 15:32:56 2009 -0700
> > >
> > > oom: move oom_adj value from task_struct to mm_struct
> > >
> > > I'm confident that the bisection is good. The test case was very reliable
> > > while zooming in on the merge from akpm.
> > >
> >
> > I doubt it for two reasons: (i) this commit was reverted in 0753ba0 since
> > 2.6.31-rc7 and is no longer in the kernel, and (ii) these are GFP_ATOMIC
> > allocations which would be unaffected by oom killer scores.
> >
>
> However, the problem was reported to start showing up in 2.6.31-rc1 so
> while it might not be *the* patch, it might be making the type of change
> that caused more fragmentation. This patch adjusted the size of
> mm_struct and maybe it was enough to change the "order" required for the
> slab. Maybe there are other slabs that have changed size as well in that
> timeframe.
>
> Frans, what is the size of mm_struct before and after this patch was
> applied? Find it with either
>
> grep mm_struct /proc/slabinfo
>
> and if the information is not available there, try
>
> cat /sys/kernel/slab/mm_struct/slab_size and
> /sys/kernel/slab/mm_struct/order
>

If that's the case and the problem still persists in 2.6.31-rc7 as
reported, then you'd need to compare the current slab order for both
mm_struct and signal_struct to the previously known working kernel
since the latter is where oom_adj was moved. (You'd still have to check
the former to see if there were any mm_struct additions between rc1 and
rc7 between the commit and revert, though.)
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo DeleteThis @vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/

Mel Gorman · External Since: May 19, 2006 Posts: 253

On Tue, Oct 06, 2009 at 02:14:26AM -0700, David Rientjes wrote:
> On Tue, 6 Oct 2009, Mel Gorman wrote:
>
> > > > And the winner is:
> > > > 2ff05b2b4eac2e63d345fc731ea151a060247f53 is first bad commit
> > > > commit 2ff05b2b4eac2e63d345fc731ea151a060247f53
> > > > Author: David Rientjes <rientjes DeleteThis @google.com>
> > > > Date: Tue Jun 16 15:32:56 2009 -0700
> > > >
> > > > oom: move oom_adj value from task_struct to mm_struct
> > > >
> > > > I'm confident that the bisection is good. The test case was very reliable
> > > > while zooming in on the merge from akpm.
> > > >
> > >
> > > I doubt it for two reasons: (i) this commit was reverted in 0753ba0 since
> > > 2.6.31-rc7 and is no longer in the kernel, and (ii) these are GFP_ATOMIC
> > > allocations which would be unaffected by oom killer scores.
> > >
> >
> > However, the problem was reported to start showing up in 2.6.31-rc1 so
> > while it might not be *the* patch, it might be making the type of change
> > that caused more fragmentation. This patch adjusted the size of
> > mm_struct and maybe it was enough to change the "order" required for the
> > slab. Maybe there are other slabs that have changed size as well in that
> > timeframe.
> >
> > Frans, what is the size of mm_struct before and after this patch was
> > applied? Find it with either
> >
> > grep mm_struct /proc/slabinfo
> >
> > and if the information is not available there, try
> >
> > cat /sys/kernel/slab/mm_struct/slab_size and
> > /sys/kernel/slab/mm_struct/order
> >
>
> If that's the case and the problem still persists in 2.6.31-rc7 as
> reported, then you'd need to compare the current slab order for both
> mm_struct and signal_struct to the previously known working kernel
> since the latter is where oom_adj was moved. (You'd still have to check
> the former to see if there were any mm_struct additions between rc1 and
> rc7 between the commit and revert, though.)
>

Best to just grab all of slabinfo for a poke around. I know task_struct
has increases in size since 2.6.29 but not enough on the machines I've
changed to make a difference to the order of pages requested. It might
be different on the problem machines.

--
Mel Gorman
Part-time Phd Student Linux Technology Center
University of Limerick IBM Dublin Software Lab
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo DeleteThis @vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/

Frans Pop · External Since: May 04, 2006 Posts: 460

On Tuesday 06 October 2009, David Rientjes wrote:
> On Mon, 5 Oct 2009, Frans Pop wrote:
> > And the winner is:
> > 2ff05b2b4eac2e63d345fc731ea151a060247f53 is first bad commit
> > commit 2ff05b2b4eac2e63d345fc731ea151a060247f53
> > Author: David Rientjes <rientjes.TakeThisOut@google.com>
> > Date: Tue Jun 16 15:32:56 2009 -0700
> >
> > oom: move oom_adj value from task_struct to mm_struct
> >
> > I'm confident that the bisection is good. The test case was very
> > reliable while zooming in on the merge from akpm.
>
> I doubt it for two reasons: (i) this commit was reverted in 0753ba0
> since 2.6.31-rc7 and is no longer in the kernel, and (ii) these are
> GFP_ATOMIC allocations which would be unaffected by oom killer scores.

OK. Looks like I have been getting some false "good" results. I've been
redoing part of the bisect and am getting close to a new candidate. Will
explain further when I have that.

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

Tetsuo Handa · External Since: Feb 14, 2007 Posts: 20

Rafael J. Wysocki wrote:
> > > Bug-Entry : http://bugzilla.kernel.org/show_bug.cgi?id=14258
> > > Subject : Memory leak in SCSI initialization
> > > Submitter : Tetsuo Handa <penguin-kernel.TakeThisOut@i-love.sakura.ne.jp>
> > > Date : 2009-09-22 4:18 (10 days old)
> > > References : http://marc.info/?l=linux-kernel&m=125359311312243&w=4
> > > Handled-By : Michael Ellerman <michael.TakeThisOut@ellerman.id.au>
> > > Patch : http://patchwork.kernel.org/patch/49258/
>
> Thanks for the update.
http://patchwork.kernel.org/patch/49258/ would be replaced by
an updated patch at http://lkml.org/lkml/2009/10/2/335

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

Theodore Tso · External Since: Jun 05, 2006 Posts: 265

On Fri, Oct 02, 2009 at 03:13:07PM -0700, Jeff Kirsher wrote:
> >> > Patch : http://patchwork.kernel.org/patch/50277/
> >>
> > Most likely because it's not in the Linus' tree yet.
> >
> > [e1000e maintainers, we have a regression fix to merge, please.]
>
> Sorry, I forgot to send this patch out last night. I will send it now.

Do we have a status on this progress of this patch to mainline? Thanks,

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

Jeff Kirsher · External Since: Aug 21, 2009 Posts: 4

On Wed, Oct 7, 2009 at 11:34, Theodore Tso <tytso RemoveThis @mit.edu> wrote:
> On Fri, Oct 02, 2009 at 03:13:07PM -0700, Jeff Kirsher wrote:
>> >> > Patch : http://patchwork.kernel.org/patch/50277/
>> >>
>> > Most likely because it's not in the Linus' tree yet.
>> >
>> > [e1000e maintainers, we have a regression fix to merge, please.]
>>
>> Sorry, I forgot to send this patch out last night. I will send it now.
>
> Do we have a status on this progress of this patch to mainline? Thanks,
>
> - Ted

The patch has been submitted and accepted into David Miller's net-2.6
tree. I will submit the patch for 2.6.31 stable tree once it makes it
into Linus's tree later this week.

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

Rafael J. Wysocki · External Since: May 20, 2006 Posts: 1721

On Wednesday 07 October 2009, Tetsuo Handa wrote:
> Rafael J. Wysocki wrote:
> > > > Bug-Entry : http://bugzilla.kernel.org/show_bug.cgi?id=14258
> > > > Subject : Memory leak in SCSI initialization
> > > > Submitter : Tetsuo Handa <penguin-kernel.RemoveThis@i-love.sakura.ne.jp>
> > > > Date : 2009-09-22 4:18 (10 days old)
> > > > References : http://marc.info/?l=linux-kernel&m=125359311312243&w=4
> > > > Handled-By : Michael Ellerman <michael.RemoveThis@ellerman.id.au>
> > > > Patch : http://patchwork.kernel.org/patch/49258/
> >
> > Thanks for the update.
> http://patchwork.kernel.org/patch/49258/ would be replaced by
> an updated patch at http://lkml.org/lkml/2009/10/2/335

Thanks, updated.

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

Eric Dumazet · External Since: Jul 02, 2009 Posts: 27

Eric Dumazet a écrit :
> Eric Dumazet a écrit :
>> Eric Dumazet a écrit :
>>> Eric Dumazet a écrit :
>>>> Rafael J. Wysocki a écrit :
>>>>> This message has been generated automatically as a part of a report
>>>>> of regressions introduced between 2.6.30 and 2.6.31.
>>>>>
>>>>> The following bug entry is on the current list of known regressions
>>>>> introduced between 2.6.30 and 2.6.31. Please verify if it still should
>>>>> be listed and let me know (either way).
>>>>>
>>>>>
>>>>> Bug-Entry : http://bugzilla.kernel.org/show_bug.cgi?id=14301
>>>>> Subject : WARNING: at net/ipv4/af_inet.c:154
>>>>> Submitter : Ralf Hildebrandt <Ralf.Hildebrandt RemoveThis @charite.de>
>>>>> Date : 2009-09-30 12:24 (2 days old)
>>>>> References : http://marc.info/?l=linux-kernel&m=125431350218137&w=4
>>>>>
>> Investigation still needed...
>>
>
> OK, my last (buggy ???) feeling is about commit 95766fff6b9a78d1
>
> [UDP]: Add memory accounting.
>
> (Its a two years old patch, oh well...)
>
> Problem is the udp_poll() :
>
> We check the first frame to be dequeued from sk_receive_queue has a good checksum.
>
> If it doesnt, we drop the frame ( calling kfree_skb(skb); )
>
> Problem is now we perform memory accounting on UDP, this kfree_skb()
> should be done with socket locked, but are we allowed to
> call lock_sock() from this udp_poll() context ?
>

It seems we can lock_sock() from udp_poll() context, so here is a patch.

[PATCH] udp: Fix udp_poll()

udp_poll() can in some circumstances drop frames with incorrect checksums.

Problem is we now have to lock the socket while dropping frames, or risk
sk_forward corruption.

This bug is present since commit 95766fff6b9a78d1
([UDP]: Add memory accounting.)

While we are at it, we can correct ioctl(SIOCINQ) to also drop bad frames.

Signed-off-by: Eric Dumazet <eric.dumazet RemoveThis @gmail.com>
---
net/ipv4/udp.c | 73 +++++++++++++++++++++++++++--------------------
1 files changed, 43 insertions(+), 30 deletions(-)

diff --git a/net/ipv4/udp.c b/net/ipv4/udp.c
index 6ec6a8a..d0d436d 100644
--- a/net/ipv4/udp.c
+++ b/net/ipv4/udp.c
@@ -841,6 +841,42 @@ out:
return ret;
}

+
+/**
+ * first_packet_length - return length of first packet in receive queue
+ * @sk: socket
+ *
+ * Drops all bad checksum frames, until a valid one is found.
+ * Returns the length of found skb, or 0 if none is found.
+ */
+static unsigned int first_packet_length(struct sock *sk)
+{
+ struct sk_buff_head list_kill, *rcvq = &sk->sk_receive_queue;
+ struct sk_buff *skb;
+ unsigned int res;
+
+ __skb_queue_head_init(&list_kill);
+
+ spin_lock_bh(&rcvq->lock);
+ while ((skb = skb_peek(rcvq)) != NULL &&
+ udp_lib_checksum_complete(skb)) {
+ UDP_INC_STATS_BH(sock_net(sk), UDP_MIB_INERRORS,
+ IS_UDPLITE(sk));
+ __skb_unlink(skb, rcvq);
+ __skb_queue_tail(&list_kill, skb);
+ }
+ res = skb ? skb->len : 0;
+ spin_unlock_bh(&rcvq->lock);
+
+ if (!skb_queue_empty(&list_kill)) {
+ lock_sock(sk);
+ __skb_queue_purge(&list_kill);
+ sk_mem_reclaim_partial(sk);
+ release_sock(sk);
+ }
+ return res;
+}
+
/*
* IOCTL requests applicable to the UDP protocol
*/
@@ -857,21 +893,16 @@ int udp_ioctl(struct sock *sk, int cmd, unsigned long arg)

case SIOCINQ:
{
- struct sk_buff *skb;
- unsigned long amount;
+ unsigned int amount = first_packet_length(sk);

- amount = 0;
- spin_lock_bh(&sk->sk_receive_queue.lock);
- skb = skb_peek(&sk->sk_receive_queue);
- if (skb != NULL) {
+ if (amount)
/*
* We will only return the amount
* of this packet since that is all
* that will be read.
*/
- amount = skb->len - sizeof(struct udphdr);
- }
- spin_unlock_bh(&sk->sk_receive_queue.lock);
+ amount -= sizeof(struct udphdr);
+
return put_user(amount, (int __user *)arg);
}

@@ -1540,29 +1571,11 @@ unsigned int udp_poll(struct file *file, struct socket *sock, poll_table *wait)
{
unsigned int mask = datagram_poll(file, sock, wait);
struct sock *sk = sock->sk;
- int is_lite = IS_UDPLITE(sk);

/* Check for false positives due to checksum errors */
- if ((mask & POLLRDNORM) &&
- !(file->f_flags & O_NONBLOCK) &&
- !(sk->sk_shutdown & RCV_SHUTDOWN)) {
- struct sk_buff_head *rcvq = &sk->sk_receive_queue;
- struct sk_buff *skb;
-
- spin_lock_bh(&rcvq->lock);
- while ((skb = skb_peek(rcvq)) != NULL &&
- udp_lib_checksum_complete(skb)) {
- UDP_INC_STATS_BH(sock_net(sk),
- UDP_MIB_INERRORS, is_lite);
- __skb_unlink(skb, rcvq);
- kfree_skb(skb);
- }
- spin_unlock_bh(&rcvq->lock);
-
- /* nothing to see, move along */
- if (skb == NULL)
- mask &= ~(POLLIN | POLLRDNORM);
- }
+ if ((mask & POLLRDNORM) && !(file->f_flags & O_NONBLOCK) &&
+ !(sk->sk_shutdown & RCV_SHUTDOWN) && !first_packet_length(sk))
+ mask &= ~(POLLIN | POLLRDNORM);

return mask;

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

Mikael Pettersson · External Since: Jun 10, 2006 Posts: 79

Mikael Pettersson writes:
> Rafael J. Wysocki writes:
> > On Sunday 04 October 2009, Mikael Pettersson wrote:
> > > Rafael J. Wysocki wrote:
> > > > The following bug entry is on the current list of known regressions
> > > > introduced between 2.6.30 and 2.6.31. Please verify if it still should
> > > > be listed and let me know (either way).
> > > >
> > > >
> > > > Bug-Entry : http://bugzilla.kernel.org/show_bug.cgi?id=3D14256
> > > > Subject : kernel BUG at fs/ext3/super.c:435
> > > > Submitter : Mikael Pettersson <mikpe DeleteThis @it.uu.se>
> > > > Date : 2009-09-21 7:29 (11 days old)
> > > > References : http://marc.info/?l=3Dlinux-kernel&m=3D125351816109264&w=3D4
> > >
> > > The exact same bug (same cause, same symptom) just hit me again in 2.6.32-rc1.
> >
> > Thanks for the update.
> >
> > Could you check the current Linus' tree, please? There are some known
> > regression fixes in there.
>
> I tried simplified versions of the bug trigger on two machines
> running 2.6.32-rc1-git6, and neither triggered the kernel bug.
>
> The original recipe involved doing a glibc rebuild, run its test
> suite, install it, and reboot. Today however machine 1 was already
> doing a rebuild so after the rebuild it did a reboot into the new
> kernel before the install. The second machine booted the new kernel
> directly to install the binary packages from the first machine.
>
> I'll re-run the full bug trigger recipe on a third machine later next
> week (it must rebuild glibc itself anyway due to arch differences).

Not fixed in 2.6.32-rc3. A glibc rebuild + install triggered the
exact same bug on the third machine.

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

Rafael J. Wysocki · External Since: May 20, 2006 Posts: 1721

On Friday 09 October 2009, Mikael Pettersson wrote:
> Mikael Pettersson writes:
> > Rafael J. Wysocki writes:
> > > On Sunday 04 October 2009, Mikael Pettersson wrote:
> > > > Rafael J. Wysocki wrote:
> > > > > The following bug entry is on the current list of known regressions
> > > > > introduced between 2.6.30 and 2.6.31. Please verify if it still should
> > > > > be listed and let me know (either way).
> > > > >
> > > > >
> > > > > Bug-Entry : http://bugzilla.kernel.org/show_bug.cgi?id=3D14256
> > > > > Subject : kernel BUG at fs/ext3/super.c:435
> > > > > Submitter : Mikael Pettersson <mikpe.TakeThisOut@it.uu.se>
> > > > > Date : 2009-09-21 7:29 (11 days old)
> > > > > References : http://marc.info/?l=3Dlinux-kernel&m=3D125351816109264&w=3D4
> > > >
> > > > The exact same bug (same cause, same symptom) just hit me again in 2.6.32-rc1.
> > >
> > > Thanks for the update.
> > >
> > > Could you check the current Linus' tree, please? There are some known
> > > regression fixes in there.
> >
> > I tried simplified versions of the bug trigger on two machines
> > running 2.6.32-rc1-git6, and neither triggered the kernel bug.
> >
> > The original recipe involved doing a glibc rebuild, run its test
> > suite, install it, and reboot. Today however machine 1 was already
> > doing a rebuild so after the rebuild it did a reboot into the new
> > kernel before the install. The second machine booted the new kernel
> > directly to install the binary packages from the first machine.
> >
> > I'll re-run the full bug trigger recipe on a third machine later next
> > week (it must rebuild glibc itself anyway due to arch differences).
>
> Not fixed in 2.6.32-rc3. A glibc rebuild + install triggered the
> exact same bug on the third machine.

Thanks for the update.

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

Frans Pop · External Since: May 04, 2006 Posts: 460

Sorry for going quiet on this issue for a few days, but I have been
spending *a lot* of time on it. I've done what amounts to 5 bisection
rounds at ~20 minutes per iteration and in total over 80 boots.

The problem with my first bisection was that there are *at least two*
changes at the root of this issue, both committed between .30 and .30-rc1.
Because of this a normal bisection will not lead to a reliable result and
even with my last effort I can only narrow it down to two different areas,
and not 100% to specific commits.

The two identified areas are:
1) a wireless merge which causes the SKB errors to appear in the first
place, but not always;
2) an mm merge which makes the SKB errors occur *much* quicker; IMHO this
is the change that also causes the regressions reported by Pekka and
Karol.

So below my results. The issue is both complex and subtle. Now it's up to
you, domain experts for both mm *and* wireless/networking, to make sense of
it all and come up with suggestions on how to proceed.

I've improved my test and it's now a lot more reliable, but there are still
timing influences. Also, because this is all merge-window stuff, I'm
hitting quite a few minor and major regressions between commits that can
affect tests.

Please study the information below carefully. I know it's long, but I think
this issue justifies that.

On Monday 05 October 2009, Frans Pop wrote:
> This looks conclusive. I tested .30 and .32-rc3 from clean reboots and
> only starting gitk. I only started music playing in the background
> (amarok) from an NFS share to ensure network activity.
>
> With .32-rc3 I got 4 SKB allocation errors while starting the *second*
> gitk instance. And the system was completely frozen with music stopped
> until gitk finished loading.

With .32-rc3, .31.1 and vanilla .31 I will get multiple SKB allocation
errors the *first time* I run the test, *every* time.

> With .30 I was able to start *three* gitk's (which meant 2 of them got
> (partially) swapped out) without any allocation errors. And with the
> system remaining relatively responsive. There was a short break in the
> music while I started the 2nd instance, but it just continued playing
> afterwards. There was also some mild latency in the mouse cursor, but
> nothing like the full desktop freeze I get with .32-rc3.

With both .30.2 and vanilla .30 I have *never* been able to get any SKB
allocation errors. No matter how often I repeat the test.

So, the start and end position are 100% reproducible. Problem is that this
changes during the bisection. At some point the test will fail (no SKB
errors) the first time I run it, but it will fail on the second or third
attempt.
Apparently at some point memory must already be fragmented (or higher
orders already used up) to some extend for the errors to trigger.

TEST METHOD
-----------
As a normal bisection (I tried 3 times...) did not lead anywhere, I had to
think of an alternative approach. I decided to start by manually selecting
merges by Linus into mainline. The advantage is that that makes the
bisection linear and makes it a lot easier to see patterns.
After narrowing down to a specific merge, I bisected (again semi-manually)
inside that merge.

Because I suspected there were multiple changes involved, I deliberately
tried to find two points:
- where do I first start seeing SKB errors at all, even if it is only at
the second or third try;
- where do I start getting SKB errors reliably on the first try.

I worked from "good" to "bad", i.e. I started at .30. The merges were not
chosen completely randomly. From the first 3 bisections I strongly
suspected the first 'net-next' merge and the first 'akpm' merge, but I did
make sure to confirm that suspicion.

TEST DESCRIPTION
----------------
The test I've ended up using is:
1) clean boot
2) start music in amarok from NFS share; use very long song to avoid file
changes and thus ensure a fluent stream of network data during the test
3) start 'gitk v2.6.29..master &' - to use up some memory
4) start first 'gitk master &' - after this all normal memory is as good as
used up, with minor swap; this never resulted in SKB errors
5) start second 'gitk master &' - this causes heavy swapping (>700 MB) and
is the real test
6) if there were no SKB errors after 5), kill the gitk processes and repeat
steps 3) to 5). I've done this up to 4 times in some cases
7) if the results are not clear or when there is doubt later, repeat from
step 1) with same kernel

Memory after initial 'gitk v2.6.29..master &':
total used free shared buffers cached
Mem: 2030776 1153008 877768 0 41572 333968
-/+ buffers/cache: 777468 1253308
Swap: 2097144 0 2097144

Memory after first 'gitk master &':
total used free shared buffers cached
Mem: 2030776 1979040 51736 0 35684 238420
-/+ buffers/cache: 1704936 325840
Swap: 2097144 21876 2075268

Memory after second 'gitk master &' (with .30.2):
total used free shared buffers cached
Mem: 2030776 2011608 19168 0 21836 92336
-/+ buffers/cache: 1897436 133340
Swap: 2097144 776160 1320984

OVERVIEW OF RESULTS
-------------------
Below I list the most relevant merges and commits. Note that they are
listed in commit order; my kernel version shows the order of testing.

For the commits I tested the test results are listed on the next line.
The first number on that line consists of the test series + the iteration
(and also identifies the kernel I used).
A "+" means I got no SKB errors, a "-" that I did get them. A "|" means I
rebooted for a second series of tests.

v2.6.30-2330-gdb8e7f1 'x86-fixes-for-linus' of linux-2.6-tip
1.1 +++ iwlagn sw-error during first test
v2.6.30-4127-g0fa2133 'merge' of powerpc (last merge before net-next-2.6)
1.2 +++
v2.6.30-5398-g2ed0e21 net-next-2.6 (mega-merge!)
1.4 +- system reboot fails after testing
v2.6.30-5517-g609106b 'merge' of powerpc
1.3 +- system reboot fails after testing
v2.6.30-5927-gf83b1e6 'for-linus' of linux1394-2.6 (last merge before akpm)
2.2 ++-
v2.6.30-6111-g517d086 'akpm'
2.1 -|-

BISECTION OF net-next-2.6 MERGE
-------------------------------
Note that this merge was based not on .30 vanilla, but partly on
v2.6.30-rc1 and partly on v2.6.30-rc6.
I think this had an influence on the latencies I saw (i.e. because some
post-rc6 bug fixes were not present it changes the general behavior of the
system during the swapping). For example: with v2.6.30-4127-g0fa2133 the
system remained more responsive (smaller music skips) than with
v2.6.30-rc1-1219-g82d0481.

I started again by testing merges, this time those by David.

v2.6.30-rc1-1219-g82d0481 'master' of wireless-next-2.6
1.5 ++++ bad latencies
v2.6.30-rc6-660-gbb803cf 'master' of net-2.6
v2.6.30-rc6-808-g45ea4ea 'master' of wireless-next-2.6
v2.6.30-rc6-850-gc649c0e 'master' of net-2.6
v2.6.30-rc6-922-g3f1f39c 'linux-2.6.31.y' of wimax
v2.6.30-rc6-999-gb2f8f75 'master' of net-2.6
v2.6.30-rc6-1028-ga8c617e 'net-next' of lksctp-dev
1.7 ++++|++++|++++
I went back to this one twice because the bisection inside the
next merge (see below) did not give a clear result.
v2.6.30-rc6-1103-gb1bc81a 'master' of wireless-next-2.6
1.8 +-
v2.6.30-rc6-1224-g84503dd 'master' of wireless-next-2.6
1.6 +-

So the problem started in the v2.6.30-rc6-1103-gb1bc81a merge.
I was unable to narrow it down to an exact commit; AFAICT the remaining
ones (between v2.6.30-rc6-1028-g8fc0fee and v2.6.30-rc6-1032-g7ba10a8) are
uninteresting. But it *must* be in this area!

For a good overview of the area, use 'gitk 3f1f39c4..b1bc81a0'.

v2.6.30-rc6-1028-g8fc0fee cfg80211: use key size constants
1.11 ++++
v2.6.30-rc6-1031-g1bb5633 iwmc3200wifi: fix printk format
1.14 +++- not quite conclusive...
v2.6.30-rc6-1032-g7ba10a8 mac80211: fix transposed min/max CW values
1.13 -
This is a bugfix for aa837ee1d from an earlier merge! Could this maybe
influence the test results in between? There are various SKB related
changes there, for example: dfbf97f3..e5b9215e.
v2.6.30-rc6-1037-g2c5b9e5 wireless: libertas: fix unaligned accesses
1.12 +-
v2.6.30-rc6-1044-g729e9c7 cfg80211: fix for duplicate userspace replies
1.10 +-
v2.6.30-rc6-1075-gc587de0 iwlwifi: unify station management
1.9 ++-|+-
v2.6.30-rc6-1076-gd14d444 iwl3945: port allow skb allocation in tasklet
I thought this was a prime candidate, but as you can see several commits
before failed too. Still worth looking at I think!

BISECTION of akpm (mm) MERGE
----------------------------
So here I went looking for "where does the test start failing on the first
try". Again, I was unable to narrow it down to a single commit.

For a good overview of the area, use 'gitk f83b1e61..517d0869'.

v2.6.30-5466-ga1dd268 mm: use alloc_pages_exact in alloc_large_system_hash
2.3 +-
v2.6.30-5478-ge9bb35d mm: setup_per_zone_inactive_ratio - fix comment and..
2.5 +-
v2.6.30-5486-g35282a2 migration: only migrate_prep() once per move_pages()
2.6 -|+|- not quite conclusive...
v2.6.30-5492-gbce7394 page-allocator: reset wmark_min and inactive ratio..
2.4 -|-

WHERE NEXT?
===========
I think the results confirm there is definitely an issue here and that my
test is reliable and consistent enough to show it. And as it currently is
the only test we have...

I hope that the info above is enough for the mm and wireless domain
experts to identify likely candidates in the areas I've identified.

The next step could be trying specific reverts or debug patches, either on
top of current git, or 2.6.31, or inside the identified areas.
I'll run anything you care to throw at me and will try to provide any
additional info you need, but at this point it's up to you.

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

Frans Pop · External Since: May 04, 2006 Posts: 460

Another long mail, sorry.

On Wednesday 14 October 2009, Frans Pop wrote:
> > There still has not been a mm-change identified that makes
> > fragmentation significantly worse.
>
> My bisection shows a very clear point, even if not an individual commit,
> in the 'akpm' merge where SKB errors suddenly become *much* more
> frequent and easy to trigger.
> I'm sorry to say this, but the fact that nothing has been identified yet
> is IMO the result of a lack of effort, not because there is no such
> change.

I was wrong. It turns out that I was creating the variations in the test
results around the akpm merge myself by tiny changes in the way I ran the
tests. It took another round of about 30 compilations and tests purely in
this range to show that, but those same tests also made me aware of other
patterns I should look at.

Until a few days ago I was concentrating on "do I see SKB allocation errors
or not". Since then I've also been looking more consciously at when they
happen, at disk access patterns and at desktop freeze patterns.

I think I did mention before that this whole issue is rather subtle :-/
So, my apologies for finguering the wrong area for so long, but it looked
solid given the info available at the time.

On Thursday 15 October 2009, Mel Gorman wrote:
> Outside the range of commits suspected of causing problems was the
> following. It's extremely low probability
>
> Commit 8aa7e84 Fix congestion_wait() sync/async vs read/write confusion
> This patch alters the call to congestion_wait() in the page
> allocator. Frankly, I don't get the change but it might worth
> checking if replacing BLK_RW_ASYNC with WRITE on top of 2.6.31
> makes any difference

This is the real culprit. Mel: thanks very much for looking beyond the
area I identified. Your overview of mm changes was exactly what I needed
and really helped a lot during my later tests.

This commit definitely causes most of the problems; confirmed by reverting
it on top of 2.6.31 (also requires reverting 373c0a7e, which is a later
build fix).

The rest of this mail gives details on my tests and how I reached the above
conclusion.

TEST BASELINE (2.6.30)
======================
I mentioned in an earlier mail that I run three instances of gitk for my
tests. Loading gitk seems to consist of 3 phases:
1) general initial scan of the repository (branches?)
2) reading commits: commit counter increases
3) reading references (including bisection good/bad points) and
uncommitted changes

Below times and comments per stage when the test is run with 2.6.30. As my
test starts after a clean boot, buffers are mostly empty.

1st instance: 'gitk v2.6.29..master' (preparation)
1) ~20 seconds; user interface is mostly blank
2) ~5 seconds to read 35.000 commits; user interface is updated and counter
increases steadily as they are read
3) ~10 seconds; "branch"/"follows"/"precedes" info and tags are filled
in; fairly heavy disk activity

2st instance: 'gitk master' (preparation)
1) 0 seconds (because data is already buffered)
2) ~25 seconds to read 167500 commits; counter increases steadily
3) 1-2 seconds (because data is already buffered)

3st instance: 'gitk master' (the actual test)
1) 0 seconds because data is already buffered
2) ~55 seconds due to swapping overhead; minor music skip around commit
110.000; counter slower after 90.000, some short halts, but generally
increases steadily; moderate disk activity
3) ~55-60 seconds; because buffers have been emptied data must by read
again, with swapping; very heavy disk activity; fairly long music
skip (15-20 seconds), but no SKB allocation errors

So, the loading of the 3rd instance takes 1.5 minutes longer than the
second because of the swapping. And phase 3) is most affected by it.

AFTER WIRELESS CHANGE
=====================
After commit 4752c93c30 ("iwlcore: Allow skb allocation from tasklet") I
start getting the SKB errors. They can be triggered reliably if the whole
test is repeated 1 or 2 times, but generally not the first time the test
is run.

Or so I thought for a long time.
It turns out that I will get SKB errors during the first run if I'm
"sloppy" in the test execution. For example if I wait too long before
switching from the last gitk instance to konsole where I have
a 'tail -f /var/log/kern.log' running.
Another factor is the state of the repository: do I have master checked
out, or an older branch, or am I in the middle of a bisection. This
influences how data is read from the disk and thus the test results.
A last factor may be the size of the kernel I'm using: my test/bisect
kernel is significantly smaller than my regular kernel.

If the test is run completely cleanly, I will not get SKB errors during the
first run. Also, this change does not affect the timings of the test at
all: the total load time of the 3rd instance is still ~1:55 and music
skips happen in roughly the same places. The pattern of disk activity also
remains unchanged.

If I do *not* run the test cleanly, any SKB errors during the first test
run will always be during phase 3), never during phase 2). This is what I
saw during tests in the 'akpm' range, and explains the inconsistent
results there.

After discovering this I've made a copy of the git repo so that I always
test using the exact same state and tightened my test procedure.

AFTER congestion_wait CHANGE
============================
If I test commit 9f2d8be, which is just before the congestion_wait()
change, I still get the same pattern as described above. But when I test
with 8aa7e84 ("Fix congestion_wait() sync/async vs read/write confusion"),
things change dramatically when the 3rd gitk instance is started.

During the 2nd phase I see the first SKB allocation errors with a music
skip between reading commits 95.000 and 110.000.
About commit 115.000 there is a very long pause during which the counter
does not increase, music stops and the desktop freezes completely. The
first 30 seconds of that freeze there is only very low disk activity (which
seems strange); the next 25 seconds there suddenly is very high disk
activity during which things gradually unfreeze and more SKB errors are
displayed. After that the commit counter runs up fairly steadily again.

Phase 2) ends at ~1:45. Phase 3) (with more SKB errors) ends at ~2:05.

So this change almost doubles the time needed for phase 2) and causes SKB
allocation errors to occur during that phase. Also, before this commit the
desktop freezes are much shorter and less severe. With this change the
desktop is completely unusable for almost a minute during phase 2), with
even the mouse pointer frozen solid.
Note that phase 3) becomes shorter, but that the total time needed to load
the 3rd instance increases by about 10-15 seconds.

Note: -rc2 and -rc3 had broken NFS, so I had to cherry-pick 3 NFS commits
from -rc4 on top of the commits I wanted to test.

WITH congestion_wait CHANGE REVERTED
====================================
I've done quite a few tests of 2.6.31 with 373c0a7e and 8aa7e847 reverted
to confirm that's really the culprit. I've done this for .31-rc3, .31-rc4,
..31-rc5, .31 and .31.1.

In all cases the huge freeze in phase 2) is gone and the general behavior
and timings are again as it was after the wireless change. During most
tests I did not get any SKB allocation errors during phase 2) or phase 3).

However with .31-rc5, .31 and .31.1 I have had some tests where I would see
a few SKB allocation errors during phase 3) (which is somewhat likely),
but also during phase 2). At this point I'm unsure whether this is just
noise, or maybe a minor influence from some change merged after .31-rc4.
Looking through the commits there are several mm/page allocation changes.

For now I suggest ignoring this though as the impact (if any) is very minor
and it is not reproducible reliably enough.

Next I'll retest Mel's patches and also test Reinette's patches.

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

Pekka Enberg · External Since: Jun 15, 2006 Posts: 70

(Adding Jens to CC.)

On Wednesday 14 October 2009, Frans Pop wrote:
> > > There still has not been a mm-change identified that makes
> > > fragmentation significantly worse.

On Mon, 2009-10-19 at 01:33 +0200, Frans Pop wrote:
> > My bisection shows a very clear point, even if not an individual commit,
> > in the 'akpm' merge where SKB errors suddenly become *much* more
> > frequent and easy to trigger.
> > I'm sorry to say this, but the fact that nothing has been identified yet
> > is IMO the result of a lack of effort, not because there is no such
> > change.
>
> I was wrong. It turns out that I was creating the variations in the test
> results around the akpm merge myself by tiny changes in the way I ran the
> tests. It took another round of about 30 compilations and tests purely in
> this range to show that, but those same tests also made me aware of other
> patterns I should look at.
>
> Until a few days ago I was concentrating on "do I see SKB allocation errors
> or not". Since then I've also been looking more consciously at when they
> happen, at disk access patterns and at desktop freeze patterns.
>
> I think I did mention before that this whole issue is rather subtle :-/
> So, my apologies for finguering the wrong area for so long, but it looked
> solid given the info available at the time.
>
> On Thursday 15 October 2009, Mel Gorman wrote:
> > Outside the range of commits suspected of causing problems was the
> > following. It's extremely low probability
> >
> > Commit 8aa7e84 Fix congestion_wait() sync/async vs read/write confusion
> > This patch alters the call to congestion_wait() in the page
> > allocator. Frankly, I don't get the change but it might worth
> > checking if replacing BLK_RW_ASYNC with WRITE on top of 2.6.31
> > makes any difference
>
> This is the real culprit. Mel: thanks very much for looking beyond the
> area I identified. Your overview of mm changes was exactly what I needed
> and really helped a lot during my later tests.
>
> This commit definitely causes most of the problems; confirmed by reverting
> it on top of 2.6.31 (also requires reverting 373c0a7e, which is a later
> build fix).

Mel/Jens, any ideas why commit 8aa7e84 makes us run out of high order
pages? Should we be using BLK_RW_SYNC in mm/page_alloc.c instead of
BLK_RW_ASYNC?

Pekka

diff --git a/mm/page_alloc.c b/mm/page_alloc.c
index bf72055..fa8380a 100644
--- a/mm/page_alloc.c
+++ b/mm/page_alloc.c
@@ -1727,7 +1727,7 @@ __alloc_pages_high_priority(gfp_t gfp_mask, unsigned int order,
preferred_zone, migratetype);

if (!page && gfp_mask & __GFP_NOFAIL)
- congestion_wait(BLK_RW_ASYNC, HZ/50);
+ congestion_wait(BLK_RW_SYNC, HZ/50);
} while (!page && (gfp_mask & __GFP_NOFAIL));

return page;
@@ -1898,7 +1898,7 @@ rebalance:
pages_reclaimed += did_some_progress;
if (should_alloc_retry(gfp_mask, order, pages_reclaimed)) {
/* Wait for some write requests to complete then retry */
- congestion_wait(BLK_RW_ASYNC, HZ/50);
+ congestion_wait(BLK_RW_SYNC, HZ/50);
goto rebalance;
}

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