Prev: [PATCH 4/5] drivers/staging/otus: drop redundant memset
Next: [PATCH 2/5] drivers/net: drop redundant memset
From: Markus Rechberger on 9 Mar 2010 16:20
Hi,

I just stumbled around following issue:

[275835.163502] Pid: 14298, comm: mediasrv Not tainted 2.6.33 #7
[275835.163505] Call Trace:
[275835.163514] [<ffffffff810df7a6>] __alloc_pages_nodemask+0x5b6/0x700
[275835.163520] [<ffffffff8110c667>] alloc_pages_current+0x87/0xd0
[275835.163525] [<ffffffff810dcf79>] __get_free_pages+0x9/0x50
[275835.163529] [<ffffffff81114f2b>] __kmalloc+0x13b/0x1f0
[275835.163535] [<ffffffff813a18ef>] proc_do_submiturb+0x2ff/0x9d0
[275835.163539] [<ffffffff813a26b9>] usbdev_do_ioctl+0x6f9/0x14a0
[275835.163544] [<ffffffff8111a78f>] ? try_get_mem_cgroup_from_mm+0x1f/0x70
[275835.163549] [<ffffffff81047dbb>] ? finish_task_switch+0x4b/0xe0
[275835.163554] [<ffffffff8111bb30>] ? __mem_cgroup_try_charge+0x50/0x210
[275835.163558] [<ffffffff8111af5f>] ? __mem_cgroup_commit_charge+0x3f/0x90
[275835.163562] [<ffffffff8111bec6>] ? mem_cgroup_charge_common+0x76/0x90
[275835.163566] [<ffffffff810e3394>] ? lru_cache_add_lru+0x14/0x30
[275835.163570] [<ffffffff813a3523>] usbdev_ioctl+0x43/0x80
[275835.163576] [<ffffffff8112da75>] vfs_ioctl+0x35/0xc0
[275835.163580] [<ffffffff8102e429>] ? default_spin_lock_flags+0x9/0x10
[275835.163584] [<ffffffff8112dfe1>] do_vfs_ioctl+0x81/0x560
[275835.163589] [<ffffffff8126f006>] ? __up_read+0x46/0xc0
[275835.163594] [<ffffffff81078329>] ? up_read+0x9/0x10
[275835.163598] [<ffffffff8112e542>] sys_ioctl+0x82/0xa0
[275835.163604] [<ffffffff81009e42>] system_call_fastpath+0x16/0x1b
[275835.163606] Mem-Info:
[275835.163608] Node 0 DMA per-cpu:
[275835.163612] CPU 0: hi: 0, btch: 1 usd: 0
[275835.163614] CPU 1: hi: 0, btch: 1 usd: 0
[275835.163616] Node 0 DMA32 per-cpu:
[275835.163619] CPU 0: hi: 186, btch: 31 usd: 0
[275835.163621] CPU 1: hi: 186, btch: 31 usd: 147
[275835.163623] Node 0 Normal per-cpu:
[275835.163626] CPU 0: hi: 186, btch: 31 usd: 0
[275835.163629] CPU 1: hi: 186, btch: 31 usd: 0
[275835.163634] active_anon:105063 inactive_anon:70615 isolated_anon:0
[275835.163635] active_file:194534 inactive_file:181212 isolated_file:0
[275835.163636] unevictable:0 dirty:42 writeback:0 unstable:0
[275835.163637] free:89728 slab_reclaimable:315969 slab_unreclaimable:15720
[275835.163639] mapped:24777 shmem:40448 pagetables:6350 bounce:0
[275835.163641] Node 0 DMA free:15832kB min:28kB low:32kB high:40kB
active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB
unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15224kB
mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB
slab_reclaimable:0kB slab_unreclaimable:8kB kernel_stack:0kB
pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB
pages_scanned:0 all_unreclaimable? no
[275835.163652] lowmem_reserve[]: 0 2965 3975 3975
[275835.163657] Node 0 DMA32 free:294784kB min:6004kB low:7504kB
high:9004kB active_anon:274660kB inactive_anon:100000kB
active_file:559472kB inactive_file:547164kB unevictable:0kB
isolated(anon):0kB isolated(file):0kB present:3036832kB mlocked:0kB
dirty:76kB writeback:0kB mapped:53624kB shmem:106460kB
slab_reclaimable:1139344kB slab_unreclaimable:33336kB
kernel_stack:448kB pagetables:6408kB unstable:0kB bounce:0kB
writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[275835.163669] lowmem_reserve[]: 0 0 1010 1010
[275835.163673] Node 0 Normal free:48296kB min:2044kB low:2552kB
high:3064kB active_anon:145592kB inactive_anon:182460kB
active_file:218664kB inactive_file:177684kB unevictable:0kB
isolated(anon):0kB isolated(file):0kB present:1034240kB mlocked:0kB
dirty:92kB writeback:0kB mapped:45484kB shmem:55332kB
slab_reclaimable:124532kB slab_unreclaimable:29536kB
kernel_stack:2224kB pagetables:18992kB unstable:0kB bounce:0kB
writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[275835.163685] lowmem_reserve[]: 0 0 0 0
[275835.163689] Node 0 DMA: 2*4kB 0*8kB 1*16kB 0*32kB 1*64kB 1*128kB
1*256kB 0*512kB 1*1024kB 1*2048kB 3*4096kB = 15832kB
[275835.163701] Node 0 DMA32: 16122*4kB 21655*8kB 2766*16kB 272*32kB
52*64kB 4*128kB 1*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 294784kB
[275835.163712] Node 0 Normal: 3266*4kB 644*8kB 1721*16kB 47*32kB
7*64kB 3*128kB 1*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 48344kB
[275835.163724] 416200 total pagecache pages
[275835.163726] 0 pages in swap cache
[275835.163728] Swap cache stats: add 0, delete 0, find 0/0
[275835.163730] Free swap = 0kB
[275835.163731] Total swap = 0kB
[275835.186808] 1048560 pages RAM
[275835.186811] 42285 pages reserved
[275835.186813] 387040 pages shared
[275835.186814] 588137 pages non-shared
[275835.491094] mediasrv: page allocation failure. order:6, mode:0x40d0
[275835.491100] Pid: 14298, comm: mediasrv Not tainted 2.6.33 #7
[275835.491102] Call Trace:
[275835.491112] [<ffffffff810df7a6>] __alloc_pages_nodemask+0x5b6/0x700
[275835.491118] [<ffffffff8110c667>] alloc_pages_current+0x87/0xd0
[275835.491122] [<ffffffff810dcf79>] __get_free_pages+0x9/0x50
[275835.491127] [<ffffffff81114f2b>] __kmalloc+0x13b/0x1f0
[275835.491132] [<ffffffff813a18ef>] proc_do_submiturb+0x2ff/0x9d0
[275835.491137] [<ffffffff813a26b9>] usbdev_do_ioctl+0x6f9/0x14a0
[275835.491142] [<ffffffff8111a78f>] ? try_get_mem_cgroup_from_mm+0x1f/0x70
[275835.491147] [<ffffffff81047dbb>] ? finish_task_switch+0x4b/0xe0
[275835.491151] [<ffffffff8111bb30>] ? __mem_cgroup_try_charge+0x50/0x210
[275835.491155] [<ffffffff8111af5f>] ? __mem_cgroup_commit_charge+0x3f/0x90
[275835.491159] [<ffffffff8111bec6>] ? mem_cgroup_charge_common+0x76/0x90
[275835.491164] [<ffffffff810e3394>] ? lru_cache_add_lru+0x14/0x30
[275835.491168] [<ffffffff813a3523>] usbdev_ioctl+0x43/0x80
[275835.491173] [<ffffffff8112da75>] vfs_ioctl+0x35/0xc0
[275835.491177] [<ffffffff8102e429>] ? default_spin_lock_flags+0x9/0x10
[275835.491181] [<ffffffff8112dfe1>] do_vfs_ioctl+0x81/0x560
[275835.491187] [<ffffffff8126f006>] ? __up_read+0x46/0xc0
[275835.491192] [<ffffffff81078329>] ? up_read+0x9/0x10
[275835.491196] [<ffffffff8112e542>] sys_ioctl+0x82/0xa0
[275835.491201] [<ffffffff81009e42>] system_call_fastpath+0x16/0x1b
[275835.491204] Mem-Info:
[275835.491205] Node 0 DMA per-cpu:
[275835.491209] CPU 0: hi: 0, btch: 1 usd: 0
[275835.491211] CPU 1: hi: 0, btch: 1 usd: 0
[275835.491213] Node 0 DMA32 per-cpu:
[275835.491216] CPU 0: hi: 186, btch: 31 usd: 0
[275835.491218] CPU 1: hi: 186, btch: 31 usd: 0
[275835.491220] Node 0 Normal per-cpu:
[275835.491223] CPU 0: hi: 186, btch: 31 usd: 0
[275835.491226] CPU 1: hi: 186, btch: 31 usd: 0
[275835.491231] active_anon:104889 inactive_anon:70863 isolated_anon:0
[275835.491232] active_file:174421 inactive_file:174601 isolated_file:0
[275835.491234] unevictable:0 dirty:42 writeback:0 unstable:0
[275835.491235] free:158292 slab_reclaimable:274318 slab_unreclaimable:15652
[275835.491236] mapped:23188 shmem:40448 pagetables:6350 bounce:0
[275835.491238] Node 0 DMA free:15832kB min:28kB low:32kB high:40kB
active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB
unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15224kB
mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB
slab_reclaimable:0kB slab_unreclaimable:8kB kernel_stack:0kB
pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB
pages_scanned:0 all_unreclaimable? no
[275835.491249] lowmem_reserve[]: 0 2965 3975 3975
[275835.491254] Node 0 DMA32 free:476700kB min:6004kB low:7504kB
high:9004kB active_anon:274156kB inactive_anon:100592kB
active_file:517364kB inactive_file:517540kB unevictable:0kB
isolated(anon):0kB isolated(file):0kB present:3036832kB mlocked:0kB
dirty:76kB writeback:0kB mapped:50368kB shmem:106460kB
slab_reclaimable:1029688kB slab_unreclaimable:33336kB
kernel_stack:448kB pagetables:6408kB unstable:0kB bounce:0kB
writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[275835.491266] lowmem_reserve[]: 0 0 1010 1010
[275835.491271] Node 0 Normal free:140636kB min:2044kB low:2552kB
high:3064kB active_anon:145400kB inactive_anon:182860kB
active_file:180320kB inactive_file:180864kB unevictable:0kB
isolated(anon):0kB isolated(file):0kB present:1034240kB mlocked:0kB
dirty:92kB writeback:0kB mapped:42384kB shmem:55332kB
slab_reclaimable:67472kB slab_unreclaimable:29264kB
kernel_stack:2224kB pagetables:18992kB unstable:0kB bounce:0kB
writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[275835.491283] lowmem_reserve[]: 0 0 0 0
[275835.491287] Node 0 DMA: 2*4kB 0*8kB 1*16kB 0*32kB 1*64kB 1*128kB
1*256kB 0*512kB 1*1024kB 1*2048kB 3*4096kB = 15832kB
[275835.491299] Node 0 DMA32: 20143*4kB 23426*8kB 10321*16kB 912*32kB
197*64kB 13*128kB 1*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB =
476828kB
[275835.491310] Node 0 Normal: 6697*4kB 4644*8kB 2789*16kB 781*32kB
99*64kB 4*128kB 1*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 140660kB
[275835.491321] 389455 total pagecache pages
[275835.491323] 0 pages in swap cache
[275835.491325] Swap cache stats: add 0, delete 0, find 0/0
[275835.491327] Free swap = 0kB
[275835.491329] Total swap = 0kB
[275835.514050] 1048560 pages RAM
[275835.514053] 42285 pages reserved
[275835.514055] 361109 pages shared
[275835.514056] 541768 pages non-shared


Markus
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo(a)vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
From: Alan Stern on 9 Mar 2010 17:40
On Tue, 9 Mar 2010, Markus Rechberger wrote:

> Hi,
>
> I just stumbled around following issue:
>
> [275835.163502] Pid: 14298, comm: mediasrv Not tainted 2.6.33 #7
> [275835.163505] Call Trace:
> [275835.163514] [<ffffffff810df7a6>] __alloc_pages_nodemask+0x5b6/0x700
> [275835.163520] [<ffffffff8110c667>] alloc_pages_current+0x87/0xd0
> [275835.163525] [<ffffffff810dcf79>] __get_free_pages+0x9/0x50
> [275835.163529] [<ffffffff81114f2b>] __kmalloc+0x13b/0x1f0
> [275835.163535] [<ffffffff813a18ef>] proc_do_submiturb+0x2ff/0x9d0
> [275835.163539] [<ffffffff813a26b9>] usbdev_do_ioctl+0x6f9/0x14a0

The mediasrv program tried to allocate more memory than was available.
It's unfortunate but it's not a bug.

Alan Stern

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo(a)vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
From: Markus Rechberger on 9 Mar 2010 18:40
On Tue, Mar 9, 2010 at 11:31 PM, Alan Stern <stern(a)rowland.harvard.edu> wrote:
> On Tue, 9 Mar 2010, Markus Rechberger wrote:
>
>> Hi,
>>
>> I just stumbled around following issue:
>>
>> [275835.163502] Pid: 14298, comm: mediasrv Not tainted 2.6.33 #7
>> [275835.163505] Call Trace:
>> [275835.163514] �[<ffffffff810df7a6>] __alloc_pages_nodemask+0x5b6/0x700
>> [275835.163520] �[<ffffffff8110c667>] alloc_pages_current+0x87/0xd0
>> [275835.163525] �[<ffffffff810dcf79>] __get_free_pages+0x9/0x50
>> [275835.163529] �[<ffffffff81114f2b>] __kmalloc+0x13b/0x1f0
>> [275835.163535] �[<ffffffff813a18ef>] proc_do_submiturb+0x2ff/0x9d0
>> [275835.163539] �[<ffffffff813a26b9>] usbdev_do_ioctl+0x6f9/0x14a0
>
> The mediasrv program tried to allocate more memory than was available.
> It's unfortunate but it's not a bug.
>

Yes, 'unfortunate' is what bothers me about this, it can only be
around 198kbyte what the app can try to request (everything else will
fail internally).
The system has 4 gig ram, around 1 gig was not allocated (according to
free). not sure but I guess the pool where kmalloc tried to get the
memory from was out of memory, at least the OOM manager was not active
at all either and the rest of the system was more or less running
smoothly at this time.

Markus
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo(a)vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
From: Alan Stern on 9 Mar 2010 22:20
On Wed, 10 Mar 2010, Markus Rechberger wrote:

> On Tue, Mar 9, 2010 at 11:31 PM, Alan Stern <stern(a)rowland.harvard.edu> wrote:
> > On Tue, 9 Mar 2010, Markus Rechberger wrote:
> >
> >> Hi,
> >>
> >> I just stumbled around following issue:
> >>
> >> [275835.163502] Pid: 14298, comm: mediasrv Not tainted 2.6.33 #7
> >> [275835.163505] Call Trace:
> >> [275835.163514] �[<ffffffff810df7a6>] __alloc_pages_nodemask+0x5b6/0x700
> >> [275835.163520] �[<ffffffff8110c667>] alloc_pages_current+0x87/0xd0
> >> [275835.163525] �[<ffffffff810dcf79>] __get_free_pages+0x9/0x50
> >> [275835.163529] �[<ffffffff81114f2b>] __kmalloc+0x13b/0x1f0
> >> [275835.163535] �[<ffffffff813a18ef>] proc_do_submiturb+0x2ff/0x9d0
> >> [275835.163539] �[<ffffffff813a26b9>] usbdev_do_ioctl+0x6f9/0x14a0
> >
> > The mediasrv program tried to allocate more memory than was available.
> > It's unfortunate but it's not a bug.
> >
>
> Yes, 'unfortunate' is what bothers me about this, it can only be
> around 198kbyte what the app can try to request (everything else will
> fail internally).
> The system has 4 gig ram, around 1 gig was not allocated (according to
> free). not sure but I guess the pool where kmalloc tried to get the
> memory from was out of memory, at least the OOM manager was not active
> at all either and the rest of the system was more or less running
> smoothly at this time.

I suppose it's barely possible that even though 1 GB of memory was
free, there was too much fragmentation to allocate a contiguous 198 KB
buffer. But that seems rather unlikely (unless your machine had been
up for a very long time).

At any rate, clearly the bug, if there is one, lies in the memory
management subsystem and not in usbfs.

Alan Stern

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo(a)vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
From: Markus Rechberger on 10 Mar 2010 04:40
On Wed, Mar 10, 2010 at 4:13 AM, Alan Stern <stern(a)rowland.harvard.edu> wrote:
> On Wed, 10 Mar 2010, Markus Rechberger wrote:
>
>> On Tue, Mar 9, 2010 at 11:31 PM, Alan Stern <stern(a)rowland.harvard.edu> wrote:
>> > On Tue, 9 Mar 2010, Markus Rechberger wrote:
>> >
>> >> Hi,
>> >>
>> >> I just stumbled around following issue:
>> >>
>> >> [275835.163502] Pid: 14298, comm: mediasrv Not tainted 2.6.33 #7
>> >> [275835.163505] Call Trace:
>> >> [275835.163514] �[<ffffffff810df7a6>] __alloc_pages_nodemask+0x5b6/0x700
>> >> [275835.163520] �[<ffffffff8110c667>] alloc_pages_current+0x87/0xd0
>> >> [275835.163525] �[<ffffffff810dcf79>] __get_free_pages+0x9/0x50
>> >> [275835.163529] �[<ffffffff81114f2b>] __kmalloc+0x13b/0x1f0
>> >> [275835.163535] �[<ffffffff813a18ef>] proc_do_submiturb+0x2ff/0x9d0
>> >> [275835.163539] �[<ffffffff813a26b9>] usbdev_do_ioctl+0x6f9/0x14a0
>> >
>> > The mediasrv program tried to allocate more memory than was available.
>> > It's unfortunate but it's not a bug.
>> >
>>
>> Yes, 'unfortunate' is what bothers me about this, it can only be
>> around 198kbyte what the app can try to request (everything else will
>> fail internally).
>> The system has 4 gig ram, around 1 gig was not allocated (according to
>> free). not sure but I guess the pool where kmalloc tried to get the
>> memory from was out of memory, at least the OOM manager was not active
>> at all either and the rest of the system was more or less running
>> smoothly at this time.
>
> I suppose it's barely possible that even though 1 GB of memory was
> free, there was too much fragmentation to allocate a contiguous 198 KB
> buffer. �But that seems rather unlikely (unless your machine had been
> up for a very long time).
>
> At any rate, clearly the bug, if there is one, lies in the memory
> management subsystem and not in usbfs.
>

seems like yes, but the final result of this is that mediasrv was not
killable anymore.
Shouldn't the syscall just fail if this happens?

Markus

> Alan Stern
>
>
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo(a)vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
 |  Next  |  Last
Pages: 1 2 3
Prev: [PATCH 4/5] drivers/staging/otus: drop redundant memset
Next: [PATCH 2/5] drivers/net: drop redundant memset