Bug #1920
Out of memory while recording
0%
Description
Hello,
I installed tvheadend on a RaspberryPi with 2013-12-20-wheezy-raspbian. gpu_mem is set to 16 in config.txt.
I'm using a Terratec Cinergy HTC USB XS with DVB-C.
Problem:
After 6-7 minutes of recording, tvheadend crashes. I think it is a bug like https://tvheadend.org/issues/1593
Thanks
[ 1914.123943] ifplugd invoked oom-killer: gfp_mask=0x201da, order=0, oom_score_adj=-1000 [ 1914.124014] CPU: 0 PID: 1744 Comm: ifplugd Not tainted 3.10.25+ #622 [ 1914.124115] [<c0013a18>] (unwind_backtrace+0x0/0xf0) from [<c0010d7c>] (show_stack+0x10/0x14) [ 1914.124169] [<c0010d7c>] (show_stack+0x10/0x14) from [<c03fd070>] (dump_header.isra.13+0x74/0x1b0) [ 1914.124241] [<c03fd070>] (dump_header.isra.13+0x74/0x1b0) from [<c0099c64>] (oom_kill_process+0x298/0x41c) [ 1914.124276] [<c0099c64>] (oom_kill_process+0x298/0x41c) from [<c009a26c>] (out_of_memory+0x26c/0x2b8) [ 1914.124344] [<c009a26c>] (out_of_memory+0x26c/0x2b8) from [<c009df90>] (__alloc_pages_nodemask+0x808/0x83c) [ 1914.124377] [<c009df90>] (__alloc_pages_nodemask+0x808/0x83c) from [<c0098c84>] (filemap_fault+0x1f0/0x47c) [ 1914.124425] [<c0098c84>] (filemap_fault+0x1f0/0x47c) from [<c00b22d0>] (__do_fault+0x6c/0x4d4) [ 1914.124493] [<c00b22d0>] (__do_fault+0x6c/0x4d4) from [<c00b5698>] (handle_pte_fault+0x70/0x7e0) [ 1914.124531] [<c00b5698>] (handle_pte_fault+0x70/0x7e0) from [<c00b5eb4>] (handle_mm_fault+0xac/0xe8) [ 1914.124598] [<c00b5eb4>] (handle_mm_fault+0xac/0xe8) from [<c0403dfc>] (do_page_fault+0x224/0x3c4) [ 1914.124632] [<c0403dfc>] (do_page_fault+0x224/0x3c4) from [<c000834c>] (do_DataAbort+0x34/0x98) [ 1914.124679] [<c000834c>] (do_DataAbort+0x34/0x98) from [<c040285c>] (__dabt_usr+0x3c/0x40) [ 1914.124725] Exception stack(0xddb53fb0 to 0xddb53ff8) [ 1914.124747] 3fa0: ffffffff 0000d35c 0000cfd0 00000001 [ 1914.124769] 3fc0: 009f4018 00000001 0000cfd0 0000d35c 000156c8 00000000 00000007 bee16794 [ 1914.124819] 3fe0: b6f7f218 bee16760 b6eb1e04 b6ebdf44 60000010 ffffffff [ 1914.124834] Mem-info: [ 1914.124847] Normal per-cpu: [ 1914.124862] CPU 0: hi: 186, btch: 31 usd: 41 [ 1914.124889] active_anon:58668 inactive_anon:58720 isolated_anon:0 [ 1914.124889] active_file:74 inactive_file:153 isolated_file:0 [ 1914.124889] unevictable:0 dirty:0 writeback:0 unstable:0 [ 1914.124889] free:2047 slab_reclaimable:312 slab_unreclaimable:878 [ 1914.124889] mapped:70 shmem:2 pagetables:434 bounce:0 [ 1914.124889] free_cma:0 [ 1914.124988] Normal free:8188kB min:8192kB low:10240kB high:12288kB active_anon:234672kB inactive_anon:234880kB active_file:296kB inactive_file:612kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:507904kB managed:480420kB mlocked:0kB dirty:0kB writeback:0kB mapped:280kB shmem:8kB slab_reclaimable:1248kB slab_unreclaimable:3512kB kernel_stack:664kB pagetables:1736kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:28144 all_unreclaimable? yes [ 1914.125833] lowmem_reserve[]: 0 0 [ 1914.125867] Normal: 9*4kB (U) 1*8kB (R) 1*16kB (R) 0*32kB 1*64kB (R) 1*128kB (R) 1*256kB (R) 1*512kB (R) 1*1024kB (R) 1*2048kB (R) 1*4096kB (R) = 8188kB [ 1914.125974] 273 total pagecache pages [ 1914.125993] 44 pages in swap cache [ 1914.126005] Swap cache stats: add 41606, delete 41562, find 8639/9573 [ 1914.126014] Free swap = 0kB [ 1914.126025] Total swap = 102396kB [ 1914.189848] 126976 pages of RAM [ 1914.189873] 2317 free pages [ 1914.189884] 2739 reserved pages [ 1914.189894] 838 slab pages [ 1914.189902] 261973 pages shared [ 1914.189914] 57 pages swap cached [ 1914.189957] [ pid ] uid tgid total_vm rss nr_ptes swapents oom_score_adj name [ 1914.190005] [ 156] 0 156 721 0 5 133 -1000 udevd [ 1914.190048] [ 1714] 0 1714 437 5 4 16 -1000 ifplugd [ 1914.190099] [ 1728] 0 1728 437 5 5 16 -1000 ifplugd [ 1914.190123] [ 1744] 0 1744 437 10 4 11 -1000 ifplugd [ 1914.190144] [ 1786] 0 1786 1409 9 6 81 -1000 wpa_supplicant [ 1914.190166] [ 1998] 0 1998 6993 44 7 74 0 rsyslogd [ 1914.190214] [ 2059] 0 2059 1086 18 6 23 0 cron [ 1914.190252] [ 2109] 104 2109 794 0 5 56 0 dbus-daemon [ 1914.190273] [ 2146] 102 2146 1378 26 6 82 0 ntpd [ 1914.190297] [ 2206] 65534 2206 504 5 4 23 0 thd [ 1914.190344] [ 2217] 107 2217 177337 117155 303 24088 0 tvheadend [ 1914.190366] [ 2246] 0 2246 1073 0 6 32 0 getty [ 1914.190386] [ 2247] 0 2247 1073 0 6 32 0 getty [ 1914.190405] [ 2248] 0 2248 1073 0 6 32 0 getty [ 1914.190429] [ 2249] 0 2249 1073 0 6 32 0 getty [ 1914.190474] [ 2250] 0 2250 1073 0 6 32 0 getty [ 1914.190509] [ 2251] 0 2251 1073 0 6 32 0 getty [ 1914.190530] [ 2252] 0 2252 516 0 5 31 0 getty [ 1914.190583] [ 2272] 0 2272 1224 0 6 429 -1000 dhclient [ 1914.190605] [ 2297] 0 2297 720 0 5 132 -1000 udevd [ 1914.190627] [ 2298] 0 2298 720 0 5 134 -1000 udevd [ 1914.190647] [ 2299] 0 2299 12615 48 12 124 -1000 curlftpfs [ 1914.190670] [ 2366] 0 2366 1553 17 6 89 -1000 sshd [ 1914.190728] Out of memory: Kill process 2217 (tvheadend) score 944 or sacrifice child [ 1914.190755] Killed process 2217 (tvheadend) total-vm:709348kB, anon-rss:468604kB, file-rss:16kB [ 1915.405923] ifplugd invoked oom-killer: gfp_mask=0x201da, order=0, oom_score_adj=-1000 [ 1915.405966] CPU: 0 PID: 1714 Comm: ifplugd Not tainted 3.10.25+ #622 [ 1915.406066] [<c0013a18>] (unwind_backtrace+0x0/0xf0) from [<c0010d7c>] (show_stack+0x10/0x14) [ 1915.406170] [<c0010d7c>] (show_stack+0x10/0x14) from [<c03fd070>] (dump_header.isra.13+0x74/0x1b0) [ 1915.406216] [<c03fd070>] (dump_header.isra.13+0x74/0x1b0) from [<c0099c64>] (oom_kill_process+0x298/0x41c) [ 1915.406279] [<c0099c64>] (oom_kill_process+0x298/0x41c) from [<c009a26c>] (out_of_memory+0x26c/0x2b8) [ 1915.406316] [<c009a26c>] (out_of_memory+0x26c/0x2b8) from [<c009df90>] (__alloc_pages_nodemask+0x808/0x83c) [ 1915.406351] [<c009df90>] (__alloc_pages_nodemask+0x808/0x83c) from [<c0098c84>] (filemap_fault+0x1f0/0x47c) [ 1915.406421] [<c0098c84>] (filemap_fault+0x1f0/0x47c) from [<c00b22d0>] (__do_fault+0x6c/0x4d4) [ 1915.406464] [<c00b22d0>] (__do_fault+0x6c/0x4d4) from [<c00b5698>] (handle_pte_fault+0x70/0x7e0) [ 1915.406540] [<c00b5698>] (handle_pte_fault+0x70/0x7e0) from [<c00b5eb4>] (handle_mm_fault+0xac/0xe8) [ 1915.406581] [<c00b5eb4>] (handle_mm_fault+0xac/0xe8) from [<c0403dfc>] (do_page_fault+0x224/0x3c4) [ 1915.406644] [<c0403dfc>] (do_page_fault+0x224/0x3c4) from [<c00083e4>] (do_PrefetchAbort+0x34/0x98) [ 1915.406690] [<c00083e4>] (do_PrefetchAbort+0x34/0x98) from [<c0402a54>] (ret_from_exception+0x0/0x10) [ 1915.406752] Exception stack(0xdc59dfb0 to 0xdc59dff8) [ 1915.406775] dfa0: 00000007 00826008 000178dc 0000b5e0 [ 1915.406797] dfc0: 000178dc 000178dc 00826008 00000007 000156ac 00000000 00000007 00000000 [ 1915.406816] dfe0: 00000000 bea0db60 00009778 0000b5e0 20000010 ffffffff [ 1915.406830] Mem-info: [ 1915.406871] Normal per-cpu: [ 1915.406887] CPU 0: hi: 186, btch: 31 usd: 44 [ 1915.406915] active_anon:58725 inactive_anon:58726 isolated_anon:0 [ 1915.406915] active_file:26 inactive_file:184 isolated_file:0 [ 1915.406915] unevictable:0 dirty:0 writeback:1 unstable:0 [ 1915.406915] free:2019 slab_reclaimable:312 slab_unreclaimable:877 [ 1915.406915] mapped:42 shmem:2 pagetables:434 bounce:0 [ 1915.406915] free_cma:0 [ 1915.407023] Normal free:8076kB min:8192kB low:10240kB high:12288kB active_anon:234900kB inactive_anon:234904kB active_file:104kB inactive_file:736kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:507904kB managed:480420kB mlocked:0kB dirty:0kB writeback:4kB mapped:168kB shmem:8kB slab_reclaimable:1248kB slab_unreclaimable:3508kB kernel_stack:584kB pagetables:1736kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:12312 all_unreclaimable? yes [ 1915.407043] lowmem_reserve[]: 0 0 [ 1915.407060] Normal: 3*4kB (UE) 0*8kB 0*16kB 0*32kB 0*64kB 1*128kB (R) 1*256kB (R) 1*512kB (R) 1*1024kB (R) 1*2048kB (R) 1*4096kB (R) = 8076kB [ 1915.407170] 318 total pagecache pages [ 1915.407187] 106 pages in swap cache [ 1915.407201] Swap cache stats: add 41682, delete 41576, find 8653/9594 [ 1915.407238] Free swap = 0kB [ 1915.407249] Total swap = 102396kB [ 1915.463293] 126976 pages of RAM [ 1915.463320] 2372 free pages [ 1915.463332] 2739 reserved pages [ 1915.463385] 837 slab pages [ 1915.463396] 261876 pages shared [ 1915.463406] 106 pages swap cached [ 1915.463418] [ pid ] uid tgid total_vm rss nr_ptes swapents oom_score_adj name [ 1915.463466] [ 156] 0 156 721 0 5 133 -1000 udevd [ 1915.463523] [ 1714] 0 1714 437 5 4 16 -1000 ifplugd [ 1915.463546] [ 1728] 0 1728 437 5 5 16 -1000 ifplugd [ 1915.463566] [ 1744] 0 1744 437 10 4 11 -1000 ifplugd [ 1915.463592] [ 1786] 0 1786 1409 9 6 81 -1000 wpa_supplicant [ 1915.463649] [ 1998] 0 1998 6993 46 7 71 0 rsyslogd [ 1915.463672] [ 2059] 0 2059 1086 18 6 23 0 cron [ 1915.463694] [ 2109] 104 2109 794 0 5 56 0 dbus-daemon [ 1915.463718] [ 2146] 102 2146 1378 26 6 82 0 ntpd [ 1915.463764] [ 2206] 65534 2206 504 5 4 23 0 thd [ 1915.463787] [ 2475] 107 2217 177337 117148 303 24091 0 tvheadend [ 1915.463807] [ 2246] 0 2246 1073 0 6 32 0 getty [ 1915.463827] [ 2247] 0 2247 1073 0 6 32 0 getty [ 1915.463852] [ 2248] 0 2248 1073 0 6 32 0 getty [ 1915.463896] [ 2249] 0 2249 1073 0 6 32 0 getty [ 1915.463917] [ 2250] 0 2250 1073 0 6 32 0 getty [ 1915.463937] [ 2251] 0 2251 1073 0 6 32 0 getty [ 1915.463960] [ 2252] 0 2252 516 0 5 31 0 getty [ 1915.464007] [ 2272] 0 2272 1224 0 6 429 -1000 dhclient [ 1915.464029] [ 2297] 0 2297 720 0 5 132 -1000 udevd [ 1915.464049] [ 2298] 0 2298 720 0 5 134 -1000 udevd [ 1915.464069] [ 2299] 0 2299 12615 47 12 124 -1000 curlftpfs [ 1915.464094] [ 2366] 0 2366 1553 17 6 89 -1000 sshd [ 1915.464138] Out of memory: Kill process 2475 (tvheadend) score 944 or sacrifice child [ 1915.464158] Killed process 2475 (tvheadend) total-vm:709348kB, anon-rss:468592kB, file-rss:0kB
History
Updated by timo nein almost 11 years ago
Updated by version is version 3.4~wheezy
mkv or ts doesn't make a difference
Updated by Adam Sutton almost 11 years ago
Updated by - Category set to non-x86
- Status changed from New to Need feedback
Tvheadend has almost ZERO protection for memory over allocation in the recording chain. It's implicitly assumed (you can argue that's bad design) that the available IO bandwidth is enough to achieve the recording, else you're going to be losing data anyway and its just doomed to fail one way or the other.
The PI can have awful IO bandwidth, especially if you're also streaming in large data streams from a DVB source (or even IPTV, since pretty much everything is hanging off the same bus). So it's quite possible that it can't keep up, however I'm a little surprised as I know people are doing this sort of thing. Though it really depends on the exact arrangement of hardware and what else you might be trying to do.
There was some suggestion made, I think there might be a PR, that add some improvement to the throughput on the pi. Can't say I've looked at it in much detail.
Adam
Updated by timo nein almost 11 years ago
Hello Adam,
Thanks for your response and for Tvheadend. I'm impressed by the nice functionality (epg, recording), and the possiblility to connect it (api) to mobile apps.
I'm not sure, what you mean by your last paragraph ("some suggestion"), but I can report, that with 3.5.139~g767f824 it became better. I also disabled recording to an external ftp and use now an usb stick, which perhaps released some memory (curlftpfs). The device seems to be at it's limit (web interface is loaded, but without content during record; cpu wa load is at 70%), but I managed to record about 20minutes and now trying a longer record.
As a hobby developer myself (obj-c), I'm asking myself if it is necessary to have a growing amout of RAM memory while recording, when the recorded information is also written to disk. Could you free memory by recording to separate files?
Best regards
Timo
Updated by Adam Sutton almost 11 years ago
There isn't an arbitrary buffer of data sitting there unused etc.. The memory I'm talking about, that grows unbounded, is exactly that which you're trying to record (but not yet saved to disk).
On a normal PC, that will be very short/small and leaving it unbounded is a very low risk affair. The IO rate out (to disk) is (or should) always significantly greater (~1Gbps if straight to SATA) than the IO in (~20Mbps max for some HD channels). So it's unlikely things will stall and cause TVH to buffer stuff waiting for IO (disk) bandwidth. Even when recording multiple streams.
However in the pi, which has much more limited bandwidth. Remember that the USB and Ethernet are both hanging off the same bus (which isn't that quick). So if you're using USB DVB tuner (which most people tend to) that happens to not filter the data HW side, this could be pumping as much as 50Mbps across that shared bus. Then you need to record out, plus you might not just be IO limited, since the pi doesn't have oodles of spare CPU if you're using it for more than just TVH or doing decryption (no idea if you are or not). So it doesn't take much to tip it over the edge and cause the input bandwidth to exceed the output, if this happens for long enough, the buffer will grow (unbounded) until it runs out of memory (something else the pi doesn't have much of).
You're not the first to have this sort of problem on the pi, and in general (and don't take this the wrong way) I'm not that interested in such issues. The pi isn't the ideal platform for TVH (though in theory it seems like it should be half decent).
But, and this is the reason I've not closed this immediately, I cannot at this stage rule out a more general problem. And its certainly not impossible that some minor tweak could improve the performance on the pi and make these issues go away. See this PR, https://github.com/tvheadend/tvheadend/pull/314.
Adam
Updated by timo nein almost 11 years ago
Problem solved (tvheadend: version 3.5.139~g767f824~wheezy): cpu wa load is now at 0%, memory down from 60%->2,3%.
=> The usb flash drive mustn't be mounted with option "sync" under a RaspberryPi.
Without this option, everything works fluently. I had to remove option "sync" from usbmount.conf or mount the drive manually, for example with:
sudo mount -t vfat /dev/sda1 /video0 -o uid=107,gid=110,fmask=0002,dmask=0002,allow_utime=0020
This is also noted here: http://raspberrypi.stackexchange.com/questions/9457/slow-file-transfer-to-usb-thumbdrive
Updated by Adam Sutton almost 11 years ago
- Status changed from Need feedback to Rejected
So I was correct 
Good to know you've solved the issue 