runsolver Copyright (C) 2010 Olivier ROUSSEL This is runsolver version 3.2.9a (svn: 651) This program is distributed in the hope that it will be useful, but WITHOUT ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License for more details. command line: runsolver -W 300 -M 1124 -w /home/cbse/results/sarge-etch/logs/66.runsolver.aptitude aptitude -s -y --without-recommends install libgnomedb0-common libeditex-dev lft libgcc1 pimppa Enforcing wall clock limit (soft limit, will send signal-name then SIGKILL): 300 seconds Enforcing VSIZE limit (soft limit, will send signal-name then SIGKILL): 1150976 KiB Enforcing VSIZE limit (hard limit, stack expansion will fail with SIGSEGV, brk() and mmap() will return ENOMEM): 1202176 KiB Current StackSize limit: 8192 KiB [startup+0 s] /proc/loadavg: 0.99 0.68 0.30 2/55 19809 /proc/meminfo: memFree=245364/1022884 swapFree=0/0 [pid=19809] ppid=19808 vsize=54860 CPUtime=0 /proc/19809/stat : 19809 (aptitude) R 19808 19809 17863 34816 17863 4202496 587 0 0 0 0 0 0 0 20 0 1 0 28196392 56176640 486 18446744073709551615 140503133913088 140503138220440 140733565033600 140733565032808 140503131716358 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/19809/statm: 13715 486 398 1052 0 73 0 [startup+0.179014 s] /proc/loadavg: 0.99 0.68 0.30 2/55 19809 /proc/meminfo: memFree=245364/1022884 swapFree=0/0 [pid=19809] ppid=19808 vsize=86100 CPUtime=0.16 /proc/19809/stat : 19809 (aptitude) R 19808 19809 17863 34816 17863 4202496 7114 1710 0 0 14 2 0 0 20 0 1 0 28196392 88166400 6904 18446744073709551615 140503133913088 140503138220440 140733565033600 140733565022744 140503128766802 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/19809/statm: 21525 6904 4716 1052 0 2116 0 Current children cumulated CPU time (s) 0.16 Current children cumulated vsize (KiB) 86100 [startup+0.200303 s] /proc/loadavg: 0.99 0.68 0.30 2/55 19809 /proc/meminfo: memFree=245364/1022884 swapFree=0/0 [pid=19809] ppid=19808 vsize=89348 CPUtime=0.19 /proc/19809/stat : 19809 (aptitude) R 19808 19809 17863 34816 17863 4202496 8317 1710 0 0 17 2 0 0 20 0 1 0 28196392 91492352 7362 18446744073709551615 140503133913088 140503138220440 140733565033600 140733565023112 140503136851943 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/19809/statm: 22337 7362 4721 1052 0 2928 0 Current children cumulated CPU time (s) 0.19 Current children cumulated vsize (KiB) 89348 [startup+0.300275 s] /proc/loadavg: 0.99 0.68 0.30 2/55 19809 /proc/meminfo: memFree=245364/1022884 swapFree=0/0 [pid=19809] ppid=19808 vsize=96684 CPUtime=0.28 /proc/19809/stat : 19809 (aptitude) R 19808 19809 17863 34816 17863 4202496 9021 1710 0 0 26 2 0 0 20 0 2 0 28196392 99004416 7654 18446744073709551615 140503133913088 140503138220440 140733565033600 140733565029384 140503128758630 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/19809/statm: 24171 7654 4888 1052 0 4762 0 Current children cumulated CPU time (s) 0.28 Current children cumulated vsize (KiB) 96684 [startup+0.700211 s] /proc/loadavg: 0.99 0.68 0.30 2/55 19809 /proc/meminfo: memFree=245364/1022884 swapFree=0/0 [pid=19809] ppid=19808 vsize=100668 CPUtime=0.68 /proc/19809/stat : 19809 (aptitude) R 19808 19809 17863 34816 17863 4202496 10139 1710 0 0 66 2 0 0 20 0 2 0 28196392 103084032 8767 18446744073709551615 140503133913088 140503138220440 140733565033600 140733565023592 140503136882244 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/19809/statm: 25167 8767 4994 1052 0 5758 0 Current children cumulated CPU time (s) 0.68 Current children cumulated vsize (KiB) 100668 [startup+1.50024 s] /proc/loadavg: 0.99 0.68 0.30 2/57 19815 /proc/meminfo: memFree=229492/1022884 swapFree=0/0 [pid=19809] ppid=19808 vsize=109516 CPUtime=1.49 /proc/19809/stat : 19809 (aptitude) S 19808 19809 17863 34816 17863 4202496 13398 2207 0 0 144 4 1 0 20 0 2 0 28196392 112144384 11085 18446744073709551615 140503133913088 140503138220440 140733565033600 140733565025360 140503102658123 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/19809/statm: 27379 11085 5106 1052 0 7970 0 [pid=19809/tid=19814] ppid=19808 vsize=109516 CPUtime=0.28 /proc/19809/task/19814/stat : 19814 (aptitude) R 19808 19809 17863 34816 17863 4202560 2674 2207 0 0 27 0 1 0 20 0 2 0 28196421 112144384 11085 18446744073709551615 140503133913088 140503138220440 140733565033600 140503050483576 140503136523616 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 1.49 Current children cumulated vsize (KiB) 109516 [startup+3.10025 s] /proc/loadavg: 0.99 0.68 0.30 2/57 19815 /proc/meminfo: memFree=208164/1022884 swapFree=0/0 [pid=19809] ppid=19808 vsize=194984 CPUtime=3.08 /proc/19809/stat : 19809 (aptitude) S 19808 19809 17863 34816 17863 4202496 18447 2207 0 0 301 6 1 0 20 0 2 0 28196392 199663616 16071 18446744073709551615 140503133913088 140503138220440 140733565033600 140733565025360 140503102658123 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/19809/statm: 48746 16071 5107 1052 0 29337 0 [pid=19809/tid=19814] ppid=19808 vsize=194984 CPUtime=1.88 /proc/19809/task/19814/stat : 19814 (aptitude) R 19808 19809 17863 34816 17863 4202560 7721 2207 0 0 184 3 1 0 20 0 2 0 28196421 199663616 16071 18446744073709551615 140503133913088 140503138220440 140733565033600 140503050485432 140503091423559 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 3.08 Current children cumulated vsize (KiB) 194984 [startup+6.30025 s] /proc/loadavg: 0.99 0.68 0.30 2/57 19815 /proc/meminfo: memFree=184232/1022884 swapFree=0/0 [pid=19809] ppid=19808 vsize=217868 CPUtime=6.26 /proc/19809/stat : 19809 (aptitude) S 19808 19809 17863 34816 17863 4202496 24178 2207 0 0 617 8 1 0 20 0 2 0 28196392 223096832 21794 18446744073709551615 140503133913088 140503138220440 140733565033600 140733565025360 140503102658123 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/19809/statm: 54467 21794 5107 1052 0 35058 0 [pid=19809/tid=19814] ppid=19808 vsize=217868 CPUtime=5.06 /proc/19809/task/19814/stat : 19814 (aptitude) R 19808 19809 17863 34816 17863 4202560 13452 2207 0 0 500 5 1 0 20 0 2 0 28196421 223096832 21794 18446744073709551615 140503133913088 140503138220440 140733565033600 140503050483224 140503136546215 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 6.26 Current children cumulated vsize (KiB) 217868 Solver just ended. Dumping a history of the last processes samples [startup+6.40032 s] /proc/loadavg: 0.99 0.68 0.30 2/57 19815 /proc/meminfo: memFree=184232/1022884 swapFree=0/0 [pid=19809] ppid=19808 vsize=218396 CPUtime=6.36 /proc/19809/stat : 19809 (aptitude) S 19808 19809 17863 34816 17863 4202496 24328 2207 0 0 626 9 1 0 20 0 2 0 28196392 223637504 21944 18446744073709551615 140503133913088 140503138220440 140733565033600 140733565025360 140503102658123 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/19809/statm: 54599 21944 5107 1052 0 35190 0 [pid=19809/tid=19814] ppid=19808 vsize=218396 CPUtime=5.17 /proc/19809/task/19814/stat : 19814 (aptitude) R 19808 19809 17863 34816 17863 4202560 13602 2207 0 0 510 6 1 0 20 0 2 0 28196421 223637504 21944 18446744073709551615 140503133913088 140503138220440 140733565033600 140503050485480 140503136588894 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 6.36 Current children cumulated vsize (KiB) 218396 [startup+9.60025 s] /proc/loadavg: 0.99 0.69 0.30 2/57 19815 /proc/meminfo: memFree=160300/1022884 swapFree=0/0 [pid=19809] ppid=19808 vsize=241716 CPUtime=9.55 /proc/19809/stat : 19809 (aptitude) S 19808 19809 17863 34816 17863 4202496 30131 2207 0 0 942 12 1 0 20 0 2 0 28196392 247517184 27739 18446744073709551615 140503133913088 140503138220440 140733565033600 140733565025360 140503102658123 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/19809/statm: 60429 27739 5108 1052 0 41020 0 [pid=19809/tid=19814] ppid=19808 vsize=241716 CPUtime=8.34 /proc/19809/task/19814/stat : 19814 (aptitude) R 19808 19809 17863 34816 17863 4202560 19405 2207 0 0 825 8 1 0 20 0 2 0 28196421 247517184 27739 18446744073709551615 140503133913088 140503138220440 140733565033600 140503050483224 140503136483768 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 9.55 Current children cumulated vsize (KiB) 241716 [startup+11.2002 s] /proc/loadavg: 0.99 0.69 0.30 2/57 19815 /proc/meminfo: memFree=146908/1022884 swapFree=0/0 [pid=19809] ppid=19808 vsize=249592 CPUtime=11.14 /proc/19809/stat : 19809 (aptitude) S 19808 19809 17863 34816 17863 4202496 32176 2207 0 0 1101 12 1 0 20 0 2 0 28196392 255582208 29713 18446744073709551615 140503133913088 140503138220440 140733565033600 140733565025360 140503102658123 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/19809/statm: 62398 29713 5109 1052 0 42989 0 [pid=19809/tid=19814] ppid=19808 vsize=249592 CPUtime=9.94 /proc/19809/task/19814/stat : 19814 (aptitude) R 19808 19809 17863 34816 17863 4202560 21450 2207 0 0 984 9 1 0 20 0 2 0 28196421 255582208 29713 18446744073709551615 140503133913088 140503138220440 140733565033600 140503050485384 140503100222496 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 11.14 Current children cumulated vsize (KiB) 249592 [startup+11.6002 s] /proc/loadavg: 0.99 0.69 0.30 2/57 19815 /proc/meminfo: memFree=146908/1022884 swapFree=0/0 [pid=19809] ppid=19808 vsize=253032 CPUtime=11.54 /proc/19809/stat : 19809 (aptitude) S 19808 19809 17863 34816 17863 4202496 33065 2207 0 0 1141 12 1 0 20 0 2 0 28196392 259104768 30600 18446744073709551615 140503133913088 140503138220440 140733565033600 140733565025360 140503102658123 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/19809/statm: 63258 30600 5110 1052 0 43849 0 [pid=19809/tid=19814] ppid=19808 vsize=253032 CPUtime=10.34 /proc/19809/task/19814/stat : 19814 (aptitude) R 19808 19809 17863 34816 17863 4202560 22339 2207 0 0 1024 9 1 0 20 0 2 0 28196421 259104768 30600 18446744073709551615 140503133913088 140503138220440 140733565033600 140503050481976 140503136657863 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 11.54 Current children cumulated vsize (KiB) 253032 [startup+12.0002 s] /proc/loadavg: 0.99 0.69 0.30 2/57 19815 /proc/meminfo: memFree=146908/1022884 swapFree=0/0 [pid=19809] ppid=19808 vsize=254656 CPUtime=11.93 /proc/19809/stat : 19809 (aptitude) R 19808 19809 17863 34816 17863 4202496 34140 2207 0 0 1179 13 1 0 20 0 2 0 28196392 260767744 31201 18446744073709551615 140503133913088 140503138220440 140733565033600 140733565023688 140503128758403 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/19809/statm: 63664 31201 5159 1052 0 44248 0 [pid=19809/tid=19814] ppid=19808 vsize=254656 CPUtime=10.48 /proc/19809/task/19814/stat : 19814 (aptitude) S 19808 19809 17863 34816 17863 4202560 22717 2207 0 0 1037 10 1 0 20 0 2 0 28196421 260767744 31201 18446744073709551615 140503133913088 140503138220440 140733565033600 140503050491904 140503102657236 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 11.93 Current children cumulated vsize (KiB) 254656 [startup+12.1002 s] /proc/loadavg: 0.99 0.69 0.31 2/57 19815 /proc/meminfo: memFree=140460/1022884 swapFree=0/0 [pid=19809] ppid=19808 vsize=254656 CPUtime=12.04 /proc/19809/stat : 19809 (aptitude) R 19808 19809 17863 34816 17863 4202496 35227 2207 0 0 1189 14 1 0 20 0 2 0 28196392 260767744 31150 18446744073709551615 140503133913088 140503138220440 140733565033600 140733565025800 140503136119463 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/19809/statm: 63664 31150 5159 1052 0 44248 0 [pid=19809/tid=19814] ppid=19808 vsize=254656 CPUtime=10.48 /proc/19809/task/19814/stat : 19814 (aptitude) S 19808 19809 17863 34816 17863 4202560 22717 2207 0 0 1037 10 1 0 20 0 2 0 28196421 260767744 31150 18446744073709551615 140503133913088 140503138220440 140733565033600 140503050491904 140503102657236 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 12.04 Current children cumulated vsize (KiB) 254656 Child status: 0 Real time (s): 12.1962 CPU time (s): 12.1448 CPU user time (s): 11.9487 CPU system time (s): 0.196012 CPU usage (%): 99.5786 Max. virtual memory (cumulated for all children) (KiB): 254656 getrusage(RUSAGE_CHILDREN,...) data: user time used= 11.9487 system time used= 0.196012 maximum resident set size= 125192 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 38664 page faults= 0 swaps= 0 block input operations= 0 block output operations= 112 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 84 involuntary context switches= 266 runsolver used 0.024001 second user time and 0.040002 second system time The end