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-squeeze/logs/39.runsolver.aptitude aptitude -s -y --without-recommends install libselinux1 rcs guile-gnome0-gnome-ui nettle-bin libopenssl-ruby1.6 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.14 1.06 1.01 2/55 23255 /proc/meminfo: memFree=869792/1022884 swapFree=0/0 [pid=23255] ppid=23254 vsize=3152 CPUtime=0 /proc/23255/stat : 23255 (runsolver) R 23254 17863 17863 34816 17863 4202560 0 0 0 0 0 0 0 0 20 0 1 0 28882908 3227648 33 18446744073709551615 134512640 134586868 4293693904 4293691952 4152108080 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/23255/statm: 788 33 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.153415 s] /proc/loadavg: 1.14 1.06 1.01 2/55 23255 /proc/meminfo: memFree=869792/1022884 swapFree=0/0 [pid=23255] ppid=23254 vsize=100508 CPUtime=0.15 /proc/23255/stat : 23255 (aptitude) R 23254 23255 17863 34816 17863 4202496 10591 1708 0 0 9 5 1 0 20 0 1 0 28882908 102920192 10393 18446744073709551615 140265708044288 140265712351640 140734508174880 140734508166144 140265702734016 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/23255/statm: 25127 10393 9218 1052 0 1122 0 Current children cumulated CPU time (s) 0.15 Current children cumulated vsize (KiB) 100508 [startup+0.200275 s] /proc/loadavg: 1.14 1.06 1.01 2/55 23255 /proc/meminfo: memFree=869792/1022884 swapFree=0/0 [pid=23255] ppid=23254 vsize=100508 CPUtime=0.2 /proc/23255/stat : 23255 (aptitude) R 23254 23255 17863 34816 17863 4202496 10605 1708 0 0 14 5 1 0 20 0 1 0 28882908 102920192 10407 18446744073709551615 140265708044288 140265712351640 140734508174880 140734508166144 140265702884936 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/23255/statm: 25127 10407 9232 1052 0 1122 0 Current children cumulated CPU time (s) 0.2 Current children cumulated vsize (KiB) 100508 [startup+0.300269 s] /proc/loadavg: 1.14 1.06 1.01 2/55 23255 /proc/meminfo: memFree=869792/1022884 swapFree=0/0 [pid=23255] ppid=23254 vsize=104484 CPUtime=0.3 /proc/23255/stat : 23255 (aptitude) R 23254 23255 17863 34816 17863 4202496 11163 1708 0 0 24 5 1 0 20 0 1 0 28882908 106991616 10957 18446744073709551615 140265708044288 140265712351640 140734508174880 140734508166536 140265710192741 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/23255/statm: 26121 10957 9300 1052 0 2116 0 Current children cumulated CPU time (s) 0.3 Current children cumulated vsize (KiB) 104484 [startup+0.700224 s] /proc/loadavg: 1.14 1.06 1.01 2/55 23255 /proc/meminfo: memFree=869792/1022884 swapFree=0/0 [pid=23255] ppid=23254 vsize=123288 CPUtime=0.69 /proc/23255/stat : 23255 (aptitude) R 23254 23255 17863 34816 17863 4202496 17028 1708 0 0 59 9 1 0 20 0 2 0 28882908 126246912 14303 18446744073709551615 140265708044288 140265712351640 140734508174880 140734508170664 140265703444017 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23255/statm: 30822 14303 9482 1052 0 6817 0 Current children cumulated CPU time (s) 0.69 Current children cumulated vsize (KiB) 123288 [startup+1.50024 s] /proc/loadavg: 1.14 1.06 1.01 2/57 23260 /proc/meminfo: memFree=841512/1022884 swapFree=0/0 [pid=23255] ppid=23254 vsize=132384 CPUtime=1.49 /proc/23255/stat : 23255 (aptitude) R 23254 23255 17863 34816 17863 4202496 19433 1708 0 0 138 10 1 0 20 0 2 0 28882908 135561216 16703 18446744073709551615 140265708044288 140265712351640 140734508174880 140734508165232 140265665554528 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23255/statm: 33096 16703 9585 1052 0 9091 0 [pid=23255/tid=23260] ppid=23254 vsize=132384 CPUtime=0.01 /proc/23255/task/23260/stat : 23260 (aptitude) S 23254 23255 17863 34816 17863 4202560 4 1708 0 0 0 0 1 0 20 0 2 0 28882974 135561216 16703 18446744073709551615 140265708044288 140265712351640 140734508174880 140265598871552 140265676788436 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) 132384 [startup+3.10025 s] /proc/loadavg: 1.13 1.06 1.01 2/57 23261 /proc/meminfo: memFree=840264/1022884 swapFree=0/0 [pid=23255] ppid=23254 vsize=133888 CPUtime=3.08 /proc/23255/stat : 23255 (aptitude) R 23254 23255 17863 34816 17863 4202496 20610 2209 0 0 292 15 1 0 20 0 2 0 28882908 137101312 16941 18446744073709551615 140265708044288 140265712351640 140734508174880 140734508161696 140265710620453 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23255/statm: 33472 16941 9644 1052 0 9467 0 [pid=23255/tid=23260] ppid=23254 vsize=133888 CPUtime=0.01 /proc/23255/task/23260/stat : 23260 (aptitude) S 23254 23255 17863 34816 17863 4202560 6 2209 0 0 0 0 1 0 20 0 2 0 28882974 137101312 16941 18446744073709551615 140265708044288 140265712351640 140734508174880 140265598871552 140265676788436 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) 133888 [startup+6.30024 s] /proc/loadavg: 1.13 1.06 1.01 2/57 23261 /proc/meminfo: memFree=797368/1022884 swapFree=0/0 [pid=23255] ppid=23254 vsize=245048 CPUtime=6.26 /proc/23255/stat : 23255 (aptitude) S 23254 23255 17863 34816 17863 4202496 33019 2209 0 0 605 20 1 0 20 0 2 0 28882908 250929152 28583 18446744073709551615 140265708044288 140265712351640 140734508174880 140734508166640 140265676789323 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23255/statm: 61262 28583 9700 1052 0 37257 0 [pid=23255/tid=23260] ppid=23254 vsize=245048 CPUtime=3.16 /proc/23255/task/23260/stat : 23260 (aptitude) R 23254 23255 17863 34816 17863 4202560 12408 2209 0 0 310 5 1 0 20 0 2 0 28882974 250929152 28583 18446744073709551615 140265708044288 140265712351640 140734508174880 140265598865080 140265710873155 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) 245048 Solver just ended. Dumping a history of the last processes samples [startup+6.40031 s] /proc/loadavg: 1.13 1.06 1.01 2/57 23261 /proc/meminfo: memFree=797368/1022884 swapFree=0/0 [pid=23255] ppid=23254 vsize=245708 CPUtime=6.36 /proc/23255/stat : 23255 (aptitude) S 23254 23255 17863 34816 17863 4202496 33209 2209 0 0 615 20 1 0 20 0 2 0 28882908 251604992 28773 18446744073709551615 140265708044288 140265712351640 140734508174880 140734508166640 140265676789323 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23255/statm: 61427 28773 9700 1052 0 37422 0 [pid=23255/tid=23260] ppid=23254 vsize=245708 CPUtime=3.26 /proc/23255/task/23260/stat : 23260 (aptitude) R 23254 23255 17863 34816 17863 4202560 12598 2209 0 0 320 5 1 0 20 0 2 0 28882974 251604992 28773 18446744073709551615 140265708044288 140265712351640 140734508174880 140265598862872 140265710759203 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) 245708 [startup+9.60024 s] /proc/loadavg: 1.12 1.06 1.01 2/57 23261 /proc/meminfo: memFree=781124/1022884 swapFree=0/0 [pid=23255] ppid=23254 vsize=265904 CPUtime=9.54 /proc/23255/stat : 23255 (aptitude) S 23254 23255 17863 34816 17863 4202496 38380 2209 0 0 931 22 1 0 20 0 2 0 28882908 272285696 33818 18446744073709551615 140265708044288 140265712351640 140734508174880 140734508166640 140265676789323 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23255/statm: 66476 33818 9700 1052 0 42471 0 [pid=23255/tid=23260] ppid=23254 vsize=265904 CPUtime=6.44 /proc/23255/task/23260/stat : 23260 (aptitude) R 23254 23255 17863 34816 17863 4202560 17769 2209 0 0 636 7 1 0 20 0 2 0 28882974 272285696 33818 18446744073709551615 140265708044288 140265712351640 140734508174880 140265598862872 140265665554759 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 9.54 Current children cumulated vsize (KiB) 265904 [startup+10.4002 s] /proc/loadavg: 1.12 1.06 1.01 2/57 23261 /proc/meminfo: memFree=770088/1022884 swapFree=0/0 [pid=23255] ppid=23254 vsize=272636 CPUtime=10.34 /proc/23255/stat : 23255 (aptitude) S 23254 23255 17863 34816 17863 4202496 40083 2209 0 0 1010 23 1 0 20 0 2 0 28882908 279179264 35483 18446744073709551615 140265708044288 140265712351640 140734508174880 140734508166640 140265676789323 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23255/statm: 68159 35483 9700 1052 0 44154 0 [pid=23255/tid=23260] ppid=23254 vsize=272636 CPUtime=7.24 /proc/23255/task/23260/stat : 23260 (aptitude) R 23254 23255 17863 34816 17863 4202560 19472 2209 0 0 715 8 1 0 20 0 2 0 28882974 279179264 35483 18446744073709551615 140265708044288 140265712351640 140734508174880 140265598862872 140265710740602 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 10.34 Current children cumulated vsize (KiB) 272636 [startup+11.2002 s] /proc/loadavg: 1.12 1.06 1.01 2/57 23261 /proc/meminfo: memFree=761160/1022884 swapFree=0/0 [pid=23255] ppid=23254 vsize=276784 CPUtime=11.13 /proc/23255/stat : 23255 (aptitude) R 23254 23255 17863 34816 17863 4202496 42041 2209 0 0 1088 24 1 0 20 0 2 0 28882908 283426816 36705 18446744073709551615 140265708044288 140265712351640 140734508174880 140734508164968 140265702777382 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23255/statm: 69196 36705 9749 1052 0 45184 0 [pid=23255/tid=23260] ppid=23254 vsize=276784 CPUtime=7.78 /proc/23255/task/23260/stat : 23260 (aptitude) S 23254 23255 17863 34816 17863 4202560 20516 2209 0 0 769 8 1 0 20 0 2 0 28882974 283426816 36705 18446744073709551615 140265708044288 140265712351640 140734508174880 140265598871552 140265676788436 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 11.13 Current children cumulated vsize (KiB) 276784 [startup+11.6002 s] /proc/loadavg: 1.12 1.06 1.01 2/57 23261 /proc/meminfo: memFree=761160/1022884 swapFree=0/0 [pid=23255] ppid=23254 vsize=276784 CPUtime=11.53 /proc/23255/stat : 23255 (aptitude) R 23254 23255 17863 34816 17863 4202496 44206 2708 0 0 1121 31 1 0 20 0 2 0 28882908 283426816 36891 18446744073709551615 140265708044288 140265712351640 140734508174880 140734508166856 140265702767045 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23255/statm: 69196 36891 9749 1052 0 45184 0 [pid=23255/tid=23260] ppid=23254 vsize=276784 CPUtime=7.78 /proc/23255/task/23260/stat : 23260 (aptitude) S 23254 23255 17863 34816 17863 4202560 20516 2708 0 0 769 8 1 0 20 0 2 0 28882974 283426816 36891 18446744073709551615 140265708044288 140265712351640 140734508174880 140265598871552 140265676788436 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 11.53 Current children cumulated vsize (KiB) 276784 Child status: 0 Real time (s): 11.6787 CPU time (s): 11.6327 CPU user time (s): 11.2647 CPU system time (s): 0.368023 CPU usage (%): 99.6064 Max. virtual memory (cumulated for all children) (KiB): 276784 getrusage(RUSAGE_CHILDREN,...) data: user time used= 11.2647 system time used= 0.368023 maximum resident set size= 147564 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 47416 page faults= 0 swaps= 0 block input operations= 0 block output operations= 136 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 78 involuntary context switches= 248 runsolver used 0.020001 second user time and 0.036002 second system time The end