Univention Bugzilla – Bug 25518
univention-repository-update: wget OOM und massiv paralleler Aufruf von apt-ftparchive
Last modified: 2014-02-05 12:20:19 CET
Für die QA von Bug #25273 wurde eine Master mit einem lokalen Repository eingerichtet, das mit 2.4-0 beginnt und beide Architekturen amd64 und i386 enthält. Durch den anschließenden Aufruf von "univention-updater net ..." wurde "univention-repository-update net" ausgeführt, was nach dem Download von 8 GiB UCS-3.0-Paketen _parallel_ für alle bis dahin existierenden Depots "apt-ftparchive" aufgerufen hat. Dadurch stieg die IO-Last erheblich an und die VM war längere Zeit unbenutzbar. 1. Die Anzahl der gleichzeitig laufenden Prozesse sollte begrenzt werden. Da atp-ftparchive eher sehr IO-lastig ist, sollten dass nicht mehr als eine Hand voll Instanzen sein. 2. apt-get sollte in Zeile 538 neben dem Perl-exec auch ein Shell-"exec" machen, um die Anzahl der Prozess-forks zu halbieren. 15499 ttyS0 Ss 0:00 /bin/login -- 15544 ttyS0 S 0:04 \_ -bash 6224 ttyS0 S+ 0:00 \_ /usr/bin/python2.4 /usr/sbin/univention-updater net --updateto 3.0-0 --ignoressh 6230 ttyS0 S+ 0:00 \_ /usr/bin/python2.4 /usr/sbin/univention-repository-update net --updateto 3.0-0 6240 ttyS0 S+ 0:00 \_ /usr/bin/perl -w /usr/bin/apt-mirror 6713 ttyS0 S+ 0:00 \_ sh -c apt-ftparchive packages 3.0-0/i386/ > 3.0-0/i386//Packages? 6734 ttyS0 R+ 0:03 | \_ apt-ftparchive packages 3.0-0/i386/ 6718 ttyS0 S+ 0:00 \_ sh -c apt-ftparchive packages 2.4-2/all/ > 2.4-2/all//Packages? 6732 ttyS0 R+ 0:07 | \_ apt-ftparchive packages 2.4-2/all/ 6722 ttyS0 S+ 0:00 \_ sh -c apt-ftparchive packages 2.4-3/i386/ > 2.4-3/i386//Packages? 6740 ttyS0 R+ 0:06 | \_ apt-ftparchive packages 2.4-3/i386/ 6723 ttyS0 S+ 0:00 \_ sh -c apt-ftparchive packages sec2/i386/ > sec2/i386//Packages? 6738 ttyS0 D+ 0:08 | \_ apt-ftparchive packages sec2/i386/ 6724 ttyS0 S+ 0:00 \_ sh -c apt-ftparchive packages 2.4-1/i386/ > 2.4-1/i386//Packages? 6739 ttyS0 R+ 0:05 | \_ apt-ftparchive packages 2.4-1/i386/ 6725 ttyS0 S+ 0:00 \_ sh -c apt-ftparchive packages sec1/i386/ > sec1/i386//Packages? 6743 ttyS0 R+ 0:06 | \_ apt-ftparchive packages sec1/i386/ 6727 ttyS0 S+ 0:00 \_ sh -c apt-ftparchive packages 3.0-0/all/ > 3.0-0/all//Packages? 6754 ttyS0 R+ 0:04 | \_ apt-ftparchive packages 3.0-0/all/ 6728 ttyS0 S+ 0:00 \_ sh -c apt-ftparchive packages 2.4-2/i386/ > 2.4-2/i386//Packages? 6755 ttyS0 R+ 0:05 | \_ apt-ftparchive packages 2.4-2/i386/ 6748 ttyS0 S+ 0:00 \_ sh -c apt-ftparchive packages 2.4-0/i386/ > 2.4-0/i386//Packages? 6759 ttyS0 S+ 0:03 | \_ apt-ftparchive packages 2.4-0/i386/ 8232 ttyS0 R+ 0:00 | \_ apt-ftparchive packages 2.4-0/i386/ 6749 ttyS0 S+ 0:00 \_ sh -c apt-ftparchive packages 2.4-0/extern/ > 2.4-0/extern//Packages? 6760 ttyS0 R+ 0:07 | \_ apt-ftparchive packages 2.4-0/extern/ 6752 ttyS0 S+ 0:00 \_ sh -c apt-ftparchive packages sec4/i386/ > sec4/i386//Packages? 6761 ttyS0 R+ 0:09 | \_ apt-ftparchive packages sec4/i386/ 6753 ttyS0 S+ 0:00 \_ sh -c apt-ftparchive packages 2.4-0/all/ > 2.4-0/all//Packages? 6762 ttyS0 S+ 0:06 \_ apt-ftparchive packages 2.4-0/all/ 8233 ttyS0 R+ 0:00 \_ apt-ftparchive packages 2.4-0/all/ Zudem starb während dem Download der UCS-3.0-Pakete ein wget-Prozess den OOM-Tod: Dec 15 15:42:05 master82 kernel: [21519.637803] wget: page allocation failure. order:0, mode:0x20 Dec 15 15:42:05 master82 kernel: [21519.639216] Pid: 6310, comm: wget Not tainted 2.6.32-ucs21-686-bigmem #1 Dec 15 15:42:05 master82 kernel: [21519.640332] Call Trace: Dec 15 15:42:05 master82 kernel: [21519.640849] [<c109262c>] ? __alloc_pages_nodemask+0x484/0x4d9 Dec 15 15:42:05 master82 kernel: [21519.641967] [<e0f57cc7>] ? try_fill_recv+0x72/0x117 [virtio_net] Dec 15 15:42:05 master82 kernel: [21519.643073] [<e0f58556>] ? virtnet_poll+0x45c/0x4d2 [virtio_net] Dec 15 15:42:05 master82 kernel: [21519.644087] [<c11fd225>] ? net_rx_action+0x96/0x194 Dec 15 15:42:05 master82 kernel: [21519.644900] [<c103b53c>] ? __do_softirq+0xaa/0x151 Dec 15 15:42:05 master82 kernel: [21519.645674] [<c103b614>] ? do_softirq+0x31/0x3c Dec 15 15:42:05 master82 kernel: [21519.646415] [<c103b77f>] ? _local_bh_enable_ip+0x63/0x6e Dec 15 15:42:05 master82 kernel: [21519.647585] [<c1291dc2>] ? __cond_resched_softirq+0x28/0x57 Dec 15 15:42:05 master82 kernel: [21519.648516] [<c11f2d10>] ? release_sock+0x3d/0x89 Dec 15 15:42:05 master82 kernel: [21519.649281] [<c1225485>] ? tcp_recvmsg+0x7dd/0x8df Dec 15 15:42:05 master82 kernel: [21519.650108] [<c11f23eb>] ? sock_common_recvmsg+0x2f/0x45 Dec 15 15:42:05 master82 kernel: [21519.650964] [<c11f07b0>] ? __sock_recvmsg+0x50/0x58 Dec 15 15:42:05 master82 kernel: [21519.651674] [<c11f0855>] ? sock_aio_read+0x9d/0xab Dec 15 15:42:05 master82 kernel: [21519.652319] [<c10ba75d>] ? do_sync_read+0xc0/0x107 Dec 15 15:42:05 master82 kernel: [21519.652957] [<c104a192>] ? autoremove_wake_function+0x0/0x2d Dec 15 15:42:05 master82 kernel: [21519.653703] [<c114c103>] ? copy_to_user+0x29/0xf8 Dec 15 15:42:05 master82 kernel: [21519.654320] [<c10c5b96>] ? poll_select_copy_remaining+0xbd/0xd9 Dec 15 15:42:05 master82 kernel: [21519.655087] [<c11129b0>] ? security_file_permission+0xc/0xd Dec 15 15:42:05 master82 kernel: [21519.655933] [<c10bb125>] ? vfs_read+0x8c/0xd3 Dec 15 15:42:05 master82 kernel: [21519.656529] [<c10bb204>] ? sys_read+0x3c/0x63 Dec 15 15:42:05 master82 kernel: [21519.657105] [<c100825c>] ? syscall_call+0x7/0xb Dec 15 15:42:05 master82 kernel: [21519.657698] Mem-Info: Dec 15 15:42:05 master82 kernel: [21519.658003] DMA per-cpu: Dec 15 15:42:05 master82 kernel: [21519.658336] CPU 0: hi: 0, btch: 1 usd: 0 Dec 15 15:42:05 master82 kernel: [21519.658950] Normal per-cpu: Dec 15 15:42:05 master82 kernel: [21519.659325] CPU 0: hi: 186, btch: 31 usd: 99 Dec 15 15:42:05 master82 kernel: [21519.659935] active_anon:13770 inactive_anon:20789 isolated_anon:0 Dec 15 15:42:05 master82 kernel: [21519.659937] active_file:24386 inactive_file:59407 isolated_file:32 Dec 15 15:42:05 master82 kernel: [21519.659938] unevictable:0 dirty:11754 writeback:0 unstable:0 Dec 15 15:42:05 master82 kernel: [21519.659939] free:746 slab_reclaimable:3099 slab_unreclaimable:2164 Dec 15 15:42:05 master82 kernel: [21519.659941] mapped:3457 shmem:2026 pagetables:995 bounce:0 Dec 15 15:42:05 master82 kernel: [21519.762385] DMA free:2004kB min:84kB low:104kB high:124kB active_anon:2276kB inactive_anon:2676kB active_file:3016kB inactive_file:5008kB unevic Dec 15 15:42:05 master82 kernel: [21519.979587] lowmem_reserve[]: 0 492 492 492 Dec 15 15:42:05 master82 kernel: [21520.033045] Normal free:980kB min:2792kB low:3488kB high:4188kB active_anon:52804kB inactive_anon:80480kB active_file:94528kB inactive_file:2326 Dec 15 15:42:05 master82 kernel: [21520.263347] lowmem_reserve[]: 0 0 0 0 Dec 15 15:42:05 master82 kernel: [21520.322894] DMA: 15*4kB 1*8kB 1*16kB 0*32kB 0*64kB 1*128kB 1*256kB 1*512kB 1*1024kB 0*2048kB 0*4096kB = 2004kB Dec 15 15:42:05 master82 kernel: [21520.384419] Normal: 245*4kB 0*8kB 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 980kB Dec 15 15:42:05 master82 kernel: [21520.447000] 95980 total pagecache pages Dec 15 15:42:05 master82 kernel: [21520.506634] 10137 pages in swap cache Dec 15 15:42:05 master82 kernel: [21520.564840] Swap cache stats: add 265359, delete 255222, find 207710/223361 Dec 15 15:42:05 master82 kernel: [21520.623681] Free swap = 766268kB Dec 15 15:42:05 master82 kernel: [21520.681856] Total swap = 1028152kB Dec 15 15:42:05 master82 kernel: [21520.742405] 131069 pages RAM Dec 15 15:42:05 master82 kernel: [21520.799420] 0 pages HighMem Dec 15 15:42:05 master82 kernel: [21520.856552] 2478 pages reserved Dec 15 15:42:05 master82 kernel: [21520.913194] 102967 pages shared Dec 15 15:42:05 master82 kernel: [21520.969400] 38945 pages non-shared Standard-UCS-2.4-1-Master mit 512 MiB
Created attachment 4027 [details] Limit child forks TODO: $nthreads is still way to high for apt-ftparchive; find a better value.
Der OOM rührt vermutlich daher, das unsere 2.4-VM standardmäßig nur 512 KiB hat. Bei 10 parallel laufenden wget-Prozessen geht dem Kernel dann irgendwann der Speicherplatz aus, um die per VirtIO schnell eintreffenden Pakete noch geordnet zu bearbeiten. Mit 1 GiB trat das Problem zumindest nicht mehr auf.
Patch wurde eingespielt. svn10727, apt-mirror_0.4.8-3.22.201208072030 ChangeLog: svn14238 \item \ucsCommand{apt-mirror} has been patched to honor the limit of forked \ucsCommand{apt-ftparchive} and \ucsCommand{gzip} processes as configured by \ucsUCRV{repository/mirror/threads} (\ucsBug{25518}).
Patch ist eingespielt und wird berücksichtigt. Die Anzahl der Threads/Prozesse kann über die UCR-Variable repository/mirror/threads geändert werden. Default ist weiterhin 10. → OK Changelogeintrag → OK
UCS 3.1-0 has been released: http://forum.univention.de/viewtopic.php?f=54&t=2125 If this error occurs again, please use "Clone This Bug".
*** Bug 14562 has been marked as a duplicate of this bug. ***