This kernel is very sick -- had a horrible death

vodoo · December 10, 2009, 2:14pm

I have a remote server (where ‘remote’ means a 3 hrs drive to get physical access, not counting the way back) which is running apache2, bind, sendmail + j-chkmail and has a Logitech Pro 9000 webcam attached. fswebcam is used to take a picture every minute.

openSUSE 11.1 32bit is installed. fswebcam was compiled from source. The machine is in runlevel 3. Recently I lost access via ssh but could still ping the IP number. There was no way to remote-reboot. So I hit the road to see what happened. Yesterday I found that the command line did no more react to the keyboard, but a friendly greeting with CTL+ALT+SysRq+B was happily accepted.

In the meantime I updated the kernel to version 2.6.27.39-0.2-pae (well, I actually knew that 2.6.27.7 was buggy, but I expected that I would not hit the bug, because it worked well for a couple of months). The question now is: can I reasonably expect that the problem is solved with the kernel update or do you suspect that the real problem is hidden elsewhere?

/var/log/messages showing this death is attached below. This is just the end of many similar events before.

Dec 3 03:48:13 paradiso kernel: Out of memory: kill process 30873 (j-chkmail) score 264
14 or a child
Dec 3 03:48:13 paradiso kernel: Killed process 30873 (j-chkmail)
Dec 3 03:48:13 paradiso kernel: fswebcam invoked oom-killer: gfp_mask=0xd0, order=0, oo
mkilladj=0
Dec 3 03:48:13 paradiso kernel: Pid: 30894, comm: fswebcam Tainted: G 2.6.27.7-9-pae #1
Dec 3 03:48:13 paradiso kernel: <c0106570>] dump_trace+0x6b/0x249
Dec 3 03:48:13 paradiso kernel: <c01070a5>] show_trace+0x20/0x39
Dec 3 03:48:13 paradiso kernel: <c035175f>] dump_stack+0x71/0x76
Dec 3 03:48:13 paradiso kernel: <c01702f0>] oom_kill_process+0x67/0x20f
Dec 3 03:48:13 paradiso kernel: <c01708bc>] out_of_memory+0x196/0x1c0
Dec 3 03:48:13 paradiso kernel: <c0173bf6>] __alloc_pages_internal+0x2e2/0x3e6
Dec 3 03:48:13 paradiso kernel: <c0190cff>] alloc_pages_current+0x95/0x9b
Dec 3 03:48:13 paradiso kernel: <c0188387>] __vmalloc_area_node+0xb0/0x124
Dec 3 03:48:13 paradiso kernel: <c0188531>] __vmalloc+0x28/0x2d
Dec 3 03:48:13 paradiso kernel: <c01885a6>] vmalloc_32+0x1c/0x1f
Dec 3 03:48:13 paradiso kernel: <f91ea840>] uvc_alloc_buffers+0x66/0x122 [uvcvideo]
Dec 3 03:48:13 paradiso kernel: <f91ebad7>] uvc_v4l2_do_ioctl+0xa8b/0xcdb [uvcvideo]
Dec 3 03:48:13 paradiso kernel: <f919075b>] video_usercopy+0x16b/0x1f4 [videodev]
Dec 3 03:48:13 paradiso kernel: <f91eac9b>] uvc_v4l2_ioctl+0x3b/0x41 [uvcvideo]
Dec 3 03:48:13 paradiso kernel: <c01a700c>] vfs_ioctl+0x4c/0x62
Dec 3 03:48:13 paradiso kernel: <c01a7280>] do_vfs_ioctl+0x174/0x186
Dec 3 03:48:13 paradiso kernel: <c01a72d7>] sys_ioctl+0x45/0x5e
Dec 3 03:48:13 paradiso kernel: <c0104c9b>] sysenter_do_call+0x12/0x2f
Dec 3 03:48:13 paradiso kernel: <ffffe430>] 0xffffe430
Dec 3 03:48:13 paradiso kernel: =======================
Dec 3 03:48:13 paradiso kernel: Mem-Info:
Dec 3 03:48:13 paradiso kernel: Node 0 DMA per-cpu:
Dec 3 03:48:13 paradiso kernel: CPU 0: hi: 0, btch: 1 usd: 0
Dec 3 03:48:13 paradiso kernel: CPU 1: hi: 0, btch: 1 usd: 0
Dec 3 03:48:13 paradiso kernel: Node 0 Normal per-cpu:
Dec 3 03:48:13 paradiso kernel: CPU 0: hi: 186, btch: 31 usd: 124
Dec 3 03:48:14 paradiso kernel: CPU 1: hi: 186, btch: 31 usd: 167
Dec 3 03:48:14 paradiso kernel: Node 0 HighMem per-cpu:
Dec 3 03:48:14 paradiso kernel: CPU 0: hi: 186, btch: 31 usd: 183
Dec 3 03:48:14 paradiso kernel: CPU 1: hi: 186, btch: 31 usd: 105
Dec 3 03:48:14 paradiso kernel: Active:8923 inactive:14635 dirty:0 writeback:3 unstable
:0
Dec 3 03:48:14 paradiso kernel: free:264474 slab:218151 mapped:2975 pagetables:671 bou
nce:0
Dec 3 03:48:14 paradiso kernel: Node 0 DMA free:3552kB min:64kB low:80kB high:96kB acti
ve:0kB inactive:0kB present:15788kB pages_scanned:0 all_unreclaimable? yes
Dec 3 03:48:14 paradiso kernel: lowmem_reserve]: 0 872 1986 1986
Dec 3 03:48:14 paradiso kernel: Node 0 Normal free:3668kB min:3744kB low:4680kB high:56
16kB active:176kB inactive:132kB present:893200kB pages_scanned:708 all_unreclaimable? yes
Dec 3 03:48:14 paradiso kernel: lowmem_reserve]: 0 0 8916 8916
Dec 3 03:48:15 paradiso kernel: Node 0 HighMem free:1050676kB min:512kB low:1708kB high
:2904kB active:35516kB inactive:58408kB present:1141332kB pages_scanned:0 all_unreclaima
ble? no
Dec 3 03:48:15 paradiso kernel: lowmem_reserve]: 0 0 0 0
Dec 3 03:48:15 paradiso kernel: Node 0 DMA: 284kB 228kB 1016kB 532kB 464kB 1128kB
2256kB 2512kB 11024kB 02048kB 04096kB = 3552kB
Dec 3 03:48:15 paradiso kernel: Node 0 Normal: 3104kB 438kB 716kB 532kB 264kB 112
8kB 2256kB 2512kB 01024kB 02048kB 04096kB = 3648kB
Dec 3 03:48:15 paradiso kernel: Node 0 HighMem: 12564kB 25208kB 382116kB 336732kB 2
49964kB 1591128kB 706256kB 222512kB 501024kB 102048kB 314096kB = 1050704kB
Dec 3 03:48:15 paradiso kernel: 19328 total pagecache pages
Dec 3 03:48:15 paradiso kernel: 6 pages in swap cache
Dec 3 03:48:15 paradiso kernel: Swap cache stats: add 9113, delete 9107, find 1766/2208
Dec 3 03:48:15 paradiso kernel: Free swap = 2409716kB
Dec 3 03:48:15 paradiso kernel: Total swap = 2409740kB
Dec 3 03:48:15 paradiso kernel: 521872 pages RAM
Dec 3 03:48:15 paradiso kernel: 292512 pages HighMem
Dec 3 03:48:15 paradiso kernel: 10884 pages reserved
Dec 3 03:48:15 paradiso kernel: 24993 pages shared
Dec 3 03:48:15 paradiso kernel: 230371 pages non-shared
Dec 3 03:48:15 paradiso kernel: Out of memory: kill process 30874 (sendmail) score 1821
or a child
Dec 3 03:48:15 paradiso kernel: Killed process 30874 (sendmail)
Dec 3 03:48:15 paradiso kernel: fswebcam invoked oom-killer: gfp_mask=0xd0, order=0, oo
mkilladj=0
Dec 3 03:48:15 paradiso kernel: Pid: 30894, comm: fswebcam Tainted: G 2.6.27.7
-9-pae #1
Dec 3 03:48:15 paradiso kernel: <c0106570>] dump_trace+0x6b/0x249
Dec 3 03:48:16 paradiso kernel: <c01070a5>] show_trace+0x20/0x39
Dec 3 03:48:16 paradiso kernel: <c035175f>] dump_stack+0x71/0x76
Dec 3 03:48:16 paradiso kernel: <c01702f0>] oom_kill_process+0x67/0x20f
Dec 3 03:48:16 paradiso kernel: <c01708bc>] out_of_memory+0x196/0x1c0
Dec 3 03:48:16 paradiso kernel: <c0173bf6>] __alloc_pages_internal+0x2e2/0x3e6
Dec 3 03:48:16 paradiso kernel: <c0190cff>] alloc_pages_current+0x95/0x9b
Dec 3 03:48:16 paradiso kernel: <c0188387>] __vmalloc_area_node+0xb0/0x124
Dec 3 03:48:16 paradiso kernel: <c0188531>] __vmalloc+0x28/0x2d
Dec 3 03:48:16 paradiso kernel: <c01885a6>] vmalloc_32+0x1c/0x1f
Dec 3 03:48:16 paradiso kernel: <f91ea840>] uvc_alloc_buffers+0x66/0x122 [uvcvideo]
Dec 3 03:48:16 paradiso kernel: <f91ebad7>] uvc_v4l2_do_ioctl+0xa8b/0xcdb [uvcvideo]
Dec 3 03:48:16 paradiso kernel: <f919075b>] video_usercopy+0x16b/0x1f4 [videodev]
Dec 3 03:48:16 paradiso kernel: <f91eac9b>] uvc_v4l2_ioctl+0x3b/0x41 [uvcvideo]
Dec 3 03:48:16 paradiso kernel: <c01a700c>] vfs_ioctl+0x4c/0x62
Dec 3 03:48:16 paradiso kernel: <c01a7280>] do_vfs_ioctl+0x174/0x186
Dec 3 03:48:16 paradiso kernel: <c01a72d7>] sys_ioctl+0x45/0x5e
Dec 3 03:48:16 paradiso kernel: <c0104c9b>] sysenter_do_call+0x12/0x2f
Dec 3 03:48:16 paradiso kernel: <ffffe430>] 0xffffe430
Dec 3 03:48:16 paradiso kernel: =======================
Dec 3 03:48:16 paradiso kernel: Mem-Info:
Dec 3 03:48:16 paradiso kernel: Node 0 DMA per-cpu:
Dec 3 03:48:16 paradiso kernel: CPU 0: hi: 0, btch: 1 usd: 0
Dec 3 03:48:16 paradiso kernel: CPU 1: hi: 0, btch: 1 usd: 0
Dec 3 03:48:16 paradiso kernel: Node 0 Normal per-cpu:
Dec 3 03:48:16 paradiso kernel: CPU 0: hi: 186, btch: 31 usd: 124
Dec 3 03:48:16 paradiso kernel: CPU 1: hi: 186, btch: 31 usd: 171
Dec 3 03:48:16 paradiso kernel: Node 0 HighMem per-cpu:
Dec 3 03:48:16 paradiso kernel: CPU 0: hi: 186, btch: 31 usd: 183
Dec 3 03:48:16 paradiso kernel: CPU 1: hi: 186, btch: 31 usd: 175
Dec 3 03:48:16 paradiso kernel: Active:8696 inactive:14678 dirty:0 writeback:0 unstable
:0
Dec 3 03:48:17 paradiso kernel: free:264625 slab:218150 mapped:2884 pagetables:652 bou
nce:0
Dec 3 03:48:17 paradiso kernel: Node 0 DMA free:3552kB min:64kB low:80kB high:96kB acti
ve:0kB inactive:0kB present:15788kB pages_scanned:0 all_unreclaimable? yes
Dec 3 03:48:17 paradiso kernel: lowmem_reserve]: 0 872 1986 1986
Dec 3 03:48:17 paradiso kernel: Node 0 Normal free:3656kB min:3744kB low:4680kB high:56
16kB active:96kB inactive:300kB present:893200kB pages_scanned:497 all_unreclaimable? no
Dec 3 03:48:17 paradiso kernel: lowmem_reserve]: 0 0 8916 8916
Dec 3 03:48:17 paradiso kernel: Node 0 HighMem free:1051292kB min:512kB low:1708kB high
:2904kB active:34688kB inactive:58412kB present:1141332kB pages_scanned:0 all_unreclaimable? no
Dec 3 03:48:17 paradiso kernel: lowmem_reserve]: 0 0 0 0
Dec 3 03:48:17 paradiso kernel: Node 0 DMA: 284kB 228kB 1016kB 532kB 464kB 1128kB
2256kB 2512kB 11024kB 02048kB 04096kB = 3552kB
Dec 3 03:48:17 paradiso kernel: Node 0 Normal: 3104kB 448kB 716kB 532kB 264kB 112
8kB 2256kB 2512kB 01024kB 02048kB 04096kB = 3656kB
Dec 3 03:48:17 paradiso kernel: Node 0 HighMem: 13174kB 25678kB 382116kB 336732kB 2
49964kB 1591128kB 706256kB 222512kB 501024kB 102048kB 314096kB = 1051324kB
Dec 3 03:48:17 paradiso kernel: 19325 total pagecache pages
Dec 3 03:48:17 paradiso kernel: 6 pages in swap cache
Dec 3 03:48:17 paradiso kernel: Swap cache stats: add 9113, delete 9107, find 1766/2208
Dec 3 03:48:17 paradiso kernel: Free swap = 2409716kB
Dec 3 03:48:17 paradiso kernel: Total swap = 2409740kB
Dec 3 03:48:17 paradiso kernel: 521872 pages RAM
Dec 3 03:48:17 paradiso kernel: 292512 pages HighMem
Dec 3 03:48:17 paradiso kernel: 10884 pages reserved
Dec 3 03:48:17 paradiso kernel: 24512 pages shared
Dec 3 03:48:17 paradiso kernel: 230247 pages non-shared
Dec 3 03:48:18 paradiso kernel: Out of memory: kill process 30861 (webimage) score 1540
or a child
Dec 3 03:48:18 paradiso kernel: Killed process 30894 (fswebcam)
Dec 3 03:49:02 paradiso /usr/sbin/cron[30897]: (usr) CMD (/home/usr/bin/webimage)
Dec 4 17:37:13 paradiso – MARK –
Dec 3 04:32:30 paradiso j-chkmail[3386]: *** Cleaning up spool dir : /var/spool/jchkmai
l
Dec 4 17:37:13 paradiso j-chkmail[3386]: *** 0 files deleted
Dec 3 03:49:03 paradiso kernel: fswebcam invoked oom-killer: gfp_mask=0xd0, order=0, oo
mkilladj=0
Dec 4 17:37:13 paradiso kernel: Pid: 30909, comm: fswebcam Tainted: G 2.6.27.7
-9-pae #1
Dec 4 17:37:13 paradiso kernel: <c0106570>] dump_trace+0x6b/0x249
Dec 4 17:37:13 paradiso kernel: <c01070a5>] show_trace+0x20/0x39
Dec 4 17:37:13 paradiso kernel: <c035175f>] dump_stack+0x71/0x76
Dec 4 17:37:13 paradiso kernel: <c01702f0>] oom_kill_process+0x67/0x20f
Dec 4 17:37:13 paradiso syslog-ng[2162]: Log statistics; dropped=‘pipe(/dev/xconsole)=1
07912’, dropped=‘pipe(/dev/tty10)=0’, processed=‘center(queued)=296861’, processed=‘cent
er(received)=89057’, processed=‘destination(newsnotice)=0’, processed=‘destination(acpid
)=0’, processed=‘destination(firewall)=2409’, processed=‘destination(null)=0’, processed
=‘destination(mail)=1192’, processed=‘destination(mailinfo)=997’, processed=‘destination
(console)=64116’, processed=‘destination(newserr)=0’, processed='destination(newscrit)=0
', processed=‘destination(messages)=85456’, processed=‘destination(mailwarn)=0’, process
ed=‘destination(localmessages)=12826’, processed=‘destination(netmgm)=0’, processed=‘des
tination(mailerr)=184’, processed=‘destination(xconsole)=64116’, processed=‘destination(
warn)=65565’, processed=‘source(src)=89057’

R.I.P.

microchip8 · December 10, 2009, 3:04pm

it seems fswebcam is eating all the memory up and thus the kernel forces the oom-killer to terminate it in order to allow the system to function properly. OOM is only invoked when system is running out of memory and it’s clear from the logs that fswebcam has triggered oom-killer. It may be buggy/leaking memory

vodoo · December 11, 2009, 11:04am

Thank you, microchip8

This meets my worst expectations. Well, the ‘easy’ way to solve the problem would be to reboot the baby every month or so. That is what certain sysadmins do for another well known OS. But it’s against my philosophy. I will try to debug it.

There are two candidates which could have memory leaks: fswebcam itself or libwebcam providing uvcdynctrl. Both are used in my script. My first step was to get the latest libwebcam from svn here: Revision 29: /Linux and recompile against my updated kernel.

Now I will try to find any memory leaks, but for this I’m definitely wrong in Install/Boot/Login.

vodoo · December 11, 2009, 1:28pm

Note: This story continues in the Programming/Scripting area with a new subject: fswebcam - debugging memory leaks - openSUSE Forums.