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-lenny/logs/78.runsolver.aptitude aptitude -s -y --without-recommends install lg-issue59 libroxen-smbauth tipa dcl holotz-castle-data 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 [startup+0 s] /proc/loadavg: 1.01 1.03 0.99 2/55 21775 /proc/meminfo: memFree=907712/1022884 swapFree=0/0 [pid=21775] ppid=21774 vsize=3152 CPUtime=0 /proc/21775/stat : 21775 (runsolver) R 21774 17863 17863 34816 17863 4202560 0 0 0 0 0 0 0 0 20 0 1 0 28560534 3227648 33 18446744073709551615 134512640 134586868 4292255840 4292253888 4151223344 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/21775/statm: 788 33 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.190114 s] /proc/loadavg: 1.01 1.03 0.99 2/55 21775 /proc/meminfo: memFree=907712/1022884 swapFree=0/0 [pid=21775] ppid=21774 vsize=89152 CPUtime=0.18 /proc/21775/stat : 21775 (aptitude) R 21774 21775 17863 34816 17863 4202496 7775 1709 0 0 16 2 0 0 20 0 1 0 28560534 91291648 7575 18446744073709551615 139887332679680 139887336987032 140734098757472 140734098748736 139887327505364 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/21775/statm: 22288 7575 6665 1052 0 858 0 Current children cumulated CPU time (s) 0.18 Current children cumulated vsize (KiB) 89152 [startup+0.200282 s] /proc/loadavg: 1.01 1.03 0.99 2/55 21775 /proc/meminfo: memFree=907712/1022884 swapFree=0/0 [pid=21775] ppid=21774 vsize=89152 CPUtime=0.19 /proc/21775/stat : 21775 (aptitude) R 21774 21775 17863 34816 17863 4202496 7869 1709 0 0 17 2 0 0 20 0 1 0 28560534 91291648 7661 18446744073709551615 139887332679680 139887336987032 140734098757472 140734098747248 139887327533394 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/21775/statm: 22288 7661 6726 1052 0 858 0 Current children cumulated CPU time (s) 0.19 Current children cumulated vsize (KiB) 89152 [startup+0.300265 s] /proc/loadavg: 1.01 1.03 0.99 2/55 21775 /proc/meminfo: memFree=907712/1022884 swapFree=0/0 [pid=21775] ppid=21774 vsize=101864 CPUtime=0.28 /proc/21775/stat : 21775 (aptitude) R 21774 21775 17863 34816 17863 4202496 11708 1709 0 0 25 3 0 0 20 0 1 0 28560534 104308736 10755 18446744073709551615 139887332679680 139887336987032 140734098757472 140734098746904 139887327580304 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/21775/statm: 25466 10755 6746 1052 0 4036 0 Current children cumulated CPU time (s) 0.28 Current children cumulated vsize (KiB) 101864 [startup+0.700191 s] /proc/loadavg: 1.01 1.03 0.99 2/55 21775 /proc/meminfo: memFree=907712/1022884 swapFree=0/0 [pid=21775] ppid=21774 vsize=114152 CPUtime=0.68 /proc/21775/stat : 21775 (aptitude) R 21774 21775 17863 34816 17863 4202496 13713 1709 0 0 63 5 0 0 20 0 2 0 28560534 116891648 12086 18446744073709551615 139887332679680 139887336987032 140734098757472 140734098748744 139887327375088 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/21775/statm: 28538 12086 6977 1052 0 7108 0 Current children cumulated CPU time (s) 0.68 Current children cumulated vsize (KiB) 114152 [startup+1.50024 s] /proc/loadavg: 1.01 1.03 0.99 2/57 21780 /proc/meminfo: memFree=886996/1022884 swapFree=0/0 [pid=21775] ppid=21774 vsize=115548 CPUtime=1.48 /proc/21775/stat : 21775 (aptitude) R 21774 21775 17863 34816 17863 4202496 14546 2208 0 0 141 6 1 0 20 0 2 0 28560534 118321152 12317 18446744073709551615 139887332679680 139887336987032 140734098757472 140734098749496 139887334308017 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/21775/statm: 28887 12317 7066 1052 0 7457 0 [pid=21775/tid=21780] ppid=21774 vsize=115548 CPUtime=0.01 /proc/21775/task/21780/stat : 21780 (aptitude) S 21774 21775 17863 34816 17863 4202560 6 2208 0 0 0 0 1 0 20 0 2 0 28560578 118321152 12317 18446744073709551615 139887332679680 139887336987032 140734098757472 139887236085760 139887301423828 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 1.48 Current children cumulated vsize (KiB) 115548 [startup+3.10024 s] /proc/loadavg: 1.01 1.03 0.99 2/57 21781 /proc/meminfo: memFree=877200/1022884 swapFree=0/0 [pid=21775] ppid=21774 vsize=146576 CPUtime=3.08 /proc/21775/stat : 21775 (aptitude) S 21774 21775 17863 34816 17863 4202496 23645 2208 0 0 297 10 1 0 20 0 2 0 28560534 150093824 20366 18446744073709551615 139887332679680 139887336987032 140734098757472 140734098749232 139887301424715 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/21775/statm: 36644 20366 7122 1052 0 15214 0 [pid=21775/tid=21780] ppid=21774 vsize=146576 CPUtime=1.2 /proc/21775/task/21780/stat : 21780 (aptitude) R 21774 21775 17863 34816 17863 4202560 9053 2208 0 0 116 3 1 0 20 0 2 0 28560578 150093824 20366 18446744073709551615 139887332679680 139887336987032 140734098757472 139887236079336 139887335312934 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) 146576 [startup+6.30024 s] /proc/loadavg: 1.01 1.03 0.99 2/57 21781 /proc/meminfo: memFree=829088/1022884 swapFree=0/0 [pid=21775] ppid=21774 vsize=246384 CPUtime=6.27 /proc/21775/stat : 21775 (aptitude) S 21774 21775 17863 34816 17863 4202496 32244 2208 0 0 612 14 1 0 20 0 2 0 28560534 252297216 28929 18446744073709551615 139887332679680 139887336987032 140734098757472 140734098749232 139887301424715 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/21775/statm: 61596 28929 7123 1052 0 40166 0 [pid=21775/tid=21780] ppid=21774 vsize=246384 CPUtime=4.39 /proc/21775/task/21780/stat : 21780 (aptitude) R 21774 21775 17863 34816 17863 4202560 17651 2208 0 0 431 7 1 0 20 0 2 0 28560578 252297216 28929 18446744073709551615 139887332679680 139887336987032 140734098757472 139887236076632 139887290183224 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 6.27 Current children cumulated vsize (KiB) 246384 Solver just ended. Dumping a history of the last processes samples [startup+6.40031 s] /proc/loadavg: 1.01 1.03 0.99 2/57 21781 /proc/meminfo: memFree=829088/1022884 swapFree=0/0 [pid=21775] ppid=21774 vsize=248100 CPUtime=6.36 /proc/21775/stat : 21775 (aptitude) S 21774 21775 17863 34816 17863 4202496 32657 2208 0 0 621 14 1 0 20 0 2 0 28560534 254054400 29342 18446744073709551615 139887332679680 139887336987032 140734098757472 140734098749232 139887301424715 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/21775/statm: 62025 29342 7123 1052 0 40595 0 [pid=21775/tid=21780] ppid=21774 vsize=248100 CPUtime=4.49 /proc/21775/task/21780/stat : 21780 (aptitude) R 21774 21775 17863 34816 17863 4202560 18064 2208 0 0 440 8 1 0 20 0 2 0 28560578 254054400 29342 18446744073709551615 139887332679680 139887336987032 140734098757472 139887236077128 139887334029824 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) 248100 [startup+6.80023 s] /proc/loadavg: 1.01 1.03 0.99 2/57 21781 /proc/meminfo: memFree=816936/1022884 swapFree=0/0 [pid=21775] ppid=21774 vsize=249392 CPUtime=6.74 /proc/21775/stat : 21775 (aptitude) R 21774 21775 17863 34816 17863 4202496 34925 2208 1 0 655 18 1 0 20 0 2 0 28560534 255377408 29829 18446744073709551615 139887332679680 139887336987032 140734098757472 140734098747232 139887290382646 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 2 0 0 /proc/21775/statm: 62348 29829 7173 1052 0 40911 0 [pid=21775/tid=21780] ppid=21774 vsize=249392 CPUtime=4.57 /proc/21775/task/21780/stat : 21780 (aptitude) S 21774 21775 17863 34816 17863 4202560 18370 2208 0 0 448 8 1 0 20 0 2 0 28560578 255377408 29829 18446744073709551615 139887332679680 139887336987032 140734098757472 139887236085760 139887301423828 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 6.74 Current children cumulated vsize (KiB) 249392 [startup+6.90023 s] /proc/loadavg: 1.01 1.03 0.99 2/57 21781 /proc/meminfo: memFree=816936/1022884 swapFree=0/0 [pid=21775] ppid=21774 vsize=249392 CPUtime=6.83 /proc/21775/stat : 21775 (aptitude) R 21774 21775 17863 34816 17863 4202496 52415 2708 1 0 660 21 1 1 20 0 2 0 28560534 255377408 29771 18446744073709551615 139887332679680 139887336987032 140734098757472 140734098749448 139887290170823 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 2 0 0 /proc/21775/statm: 62348 29771 7173 1052 0 40911 0 [pid=21775/tid=21780] ppid=21774 vsize=249392 CPUtime=4.58 /proc/21775/task/21780/stat : 21780 (aptitude) S 21774 21775 17863 34816 17863 4202560 18370 2708 0 0 448 8 1 1 20 0 2 0 28560578 255377408 29771 18446744073709551615 139887332679680 139887336987032 140734098757472 139887236085760 139887301423828 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 6.83 Current children cumulated vsize (KiB) 249392 Child status: 0 Real time (s): 6.98228 CPU time (s): 6.93243 CPU user time (s): 6.68042 CPU system time (s): 0.252015 CPU usage (%): 99.2861 Max. virtual memory (cumulated for all children) (KiB): 249392 getrusage(RUSAGE_CHILDREN,...) data: user time used= 6.68042 system time used= 0.252015 maximum resident set size= 119396 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 55335 page faults= 1 swaps= 0 block input operations= 120 block output operations= 24 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 74 involuntary context switches= 173 runsolver used 0.036002 second user time and 0 second system time The end