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/156.runsolver.aptitude aptitude -s -y --without-recommends remove cpio libasound2 ncurses-base libgpgme11 libgcrypt11-dev 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.02 2/55 24668 /proc/meminfo: memFree=869816/1022884 swapFree=0/0 [pid=24668] ppid=24667 vsize=3152 CPUtime=0 /proc/24668/stat : 24668 (runsolver) R 24667 17863 17863 34816 17863 4202560 0 0 0 0 0 0 0 0 20 0 1 0 29256456 3227648 32 18446744073709551615 134512640 134586868 4292764768 4292762816 4151534640 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/24668/statm: 788 32 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.206776 s] /proc/loadavg: 1.14 1.06 1.02 2/55 24668 /proc/meminfo: memFree=869816/1022884 swapFree=0/0 [pid=24668] ppid=24667 vsize=100508 CPUtime=0.2 /proc/24668/stat : 24668 (aptitude) R 24667 24668 17863 34816 17863 4202496 10607 1708 0 0 17 2 1 0 20 0 1 0 29256456 102920192 10407 18446744073709551615 140076708073472 140076712380824 140735809892224 140735809883488 140076703473536 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/24668/statm: 25127 10407 9232 1052 0 1122 0 Current children cumulated CPU time (s) 0.2 Current children cumulated vsize (KiB) 100508 [startup+0.300282 s] /proc/loadavg: 1.14 1.06 1.02 2/55 24668 /proc/meminfo: memFree=869816/1022884 swapFree=0/0 [pid=24668] ppid=24667 vsize=111108 CPUtime=0.29 /proc/24668/stat : 24668 (aptitude) R 24667 24668 17863 34816 17863 4202496 12497 1708 0 0 26 2 1 0 20 0 1 0 29256456 113774592 12289 18446744073709551615 140076708073472 140076712380824 140735809892224 140735809883816 140076710205019 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/24668/statm: 27777 12289 9302 1052 0 3772 0 Current children cumulated CPU time (s) 0.29 Current children cumulated vsize (KiB) 111108 [startup+0.400678 s] /proc/loadavg: 1.14 1.06 1.02 2/55 24668 /proc/meminfo: memFree=869816/1022884 swapFree=0/0 [pid=24668] ppid=24667 vsize=117476 CPUtime=0.4 /proc/24668/stat : 24668 (aptitude) R 24667 24668 17863 34816 17863 4202496 15712 1708 0 0 36 3 1 0 20 0 1 0 29256456 120295424 13989 18446744073709551615 140076708073472 140076712380824 140735809892224 140735809881736 140076665954583 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/24668/statm: 29369 13989 9312 1052 0 5364 0 Current children cumulated CPU time (s) 0.4 Current children cumulated vsize (KiB) 117476 [startup+0.700199 s] /proc/loadavg: 1.14 1.06 1.02 2/55 24668 /proc/meminfo: memFree=869816/1022884 swapFree=0/0 [pid=24668] ppid=24667 vsize=123288 CPUtime=0.69 /proc/24668/stat : 24668 (aptitude) R 24667 24668 17863 34816 17863 4202496 17026 1708 0 0 64 4 1 0 20 0 2 0 29256456 126246912 14299 18446744073709551615 140076708073472 140076712380824 140735809892224 140735809885848 140076710198821 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24668/statm: 30822 14299 9478 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.02 2/57 24673 /proc/meminfo: memFree=841784/1022884 swapFree=0/0 [pid=24668] ppid=24667 vsize=131940 CPUtime=1.48 /proc/24668/stat : 24668 (aptitude) R 24667 24668 17863 34816 17863 4202496 19298 1708 0 0 142 5 1 0 20 0 2 0 29256456 135106560 16567 18446744073709551615 140076708073472 140076712380824 140735809892224 140735809880344 140076711068270 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24668/statm: 32985 16567 9568 1052 0 8980 0 [pid=24668/tid=24673] ppid=24667 vsize=131940 CPUtime=0.01 /proc/24668/task/24673/stat : 24673 (aptitude) S 24667 24668 17863 34816 17863 4202560 4 1708 0 0 0 0 1 0 20 0 2 0 29256522 135106560 16567 18446744073709551615 140076708073472 140076712380824 140735809892224 140076598900736 140076676817620 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) 131940 [startup+3.10029 s] /proc/loadavg: 1.14 1.06 1.02 2/57 24673 /proc/meminfo: memFree=841164/1022884 swapFree=0/0 [pid=24668] ppid=24667 vsize=157192 CPUtime=3.08 /proc/24668/stat : 24668 (aptitude) S 24667 24668 17863 34816 17863 4202496 25710 1708 0 0 300 7 1 0 20 0 2 0 29256456 160964608 22978 18446744073709551615 140076708073472 140076712380824 140735809892224 140735809883984 140076676818507 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24668/statm: 39298 22978 9660 1052 0 15293 0 [pid=24668/tid=24673] ppid=24667 vsize=157192 CPUtime=0.55 /proc/24668/task/24673/stat : 24673 (aptitude) R 24667 24668 17863 34816 17863 4202560 6270 1708 0 0 53 1 1 0 20 0 2 0 29256522 160964608 22978 18446744073709551615 140076708073472 140076712380824 140735809892224 140076598894392 140076710658302 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) 157192 Solver just ended. Dumping a history of the last processes samples [startup+3.30029 s] /proc/loadavg: 1.14 1.06 1.02 2/57 24673 /proc/meminfo: memFree=841164/1022884 swapFree=0/0 [pid=24668] ppid=24667 vsize=165248 CPUtime=3.29 /proc/24668/stat : 24668 (aptitude) S 24667 24668 17863 34816 17863 4202496 27735 1708 0 0 320 8 1 0 20 0 2 0 29256456 169213952 25003 18446744073709551615 140076708073472 140076712380824 140735809892224 140735809883984 140076676818507 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24668/statm: 41312 25003 9660 1052 0 17307 0 [pid=24668/tid=24673] ppid=24667 vsize=165248 CPUtime=0.75 /proc/24668/task/24673/stat : 24673 (aptitude) R 24667 24668 17863 34816 17863 4202560 8295 1708 0 0 72 2 1 0 20 0 2 0 29256522 169213952 25003 18446744073709551615 140076708073472 140076712380824 140735809892224 140076598891352 140076710670512 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 3.29 Current children cumulated vsize (KiB) 165248 [startup+4.1003 s] /proc/loadavg: 1.14 1.06 1.02 2/57 24673 /proc/meminfo: memFree=803592/1022884 swapFree=0/0 [pid=24668] ppid=24667 vsize=182252 CPUtime=4.08 /proc/24668/stat : 24668 (aptitude) R 24667 24668 17863 34816 17863 4202496 32018 1708 0 0 397 10 1 0 20 0 2 0 29256456 186626048 29283 18446744073709551615 140076708073472 140076712380824 140735809892224 140735809882312 140076665564625 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24668/statm: 45563 29283 9711 1052 0 21551 0 [pid=24668/tid=24673] ppid=24667 vsize=182252 CPUtime=1.45 /proc/24668/task/24673/stat : 24673 (aptitude) S 24667 24668 17863 34816 17863 4202560 12415 1708 0 0 140 4 1 0 20 0 2 0 29256522 186626048 29283 18446744073709551615 140076708073472 140076712380824 140735809892224 140076598900736 140076676817620 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 4.08 Current children cumulated vsize (KiB) 182252 [startup+4.3003 s] /proc/loadavg: 1.14 1.06 1.02 2/57 24673 /proc/meminfo: memFree=803592/1022884 swapFree=0/0 [pid=24668] ppid=24667 vsize=182252 CPUtime=4.28 /proc/24668/stat : 24668 (aptitude) R 24667 24668 17863 34816 17863 4202496 32018 1708 0 0 417 10 1 0 20 0 2 0 29256456 186626048 29283 18446744073709551615 140076708073472 140076712380824 140735809892224 140735809880088 140076710279847 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24668/statm: 45563 29283 9711 1052 0 21551 0 [pid=24668/tid=24673] ppid=24667 vsize=182252 CPUtime=1.45 /proc/24668/task/24673/stat : 24673 (aptitude) S 24667 24668 17863 34816 17863 4202560 12415 1708 0 0 140 4 1 0 20 0 2 0 29256522 186626048 29283 18446744073709551615 140076708073472 140076712380824 140735809892224 140076598900736 140076676817620 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 4.28 Current children cumulated vsize (KiB) 182252 Child status: 255 Real time (s): 4.36696 CPU time (s): 4.35227 CPU user time (s): 4.22426 CPU system time (s): 0.128008 CPU usage (%): 99.6636 Max. virtual memory (cumulated for all children) (KiB): 182252 getrusage(RUSAGE_CHILDREN,...) data: user time used= 4.22426 system time used= 0.128008 maximum resident set size= 117228 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 33815 page faults= 0 swaps= 0 block input operations= 0 block output operations= 40 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 56 involuntary context switches= 114 runsolver used 0 second user time and 0.024001 second system time The end