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/150.runsolver.aptitude aptitude -s -y --without-recommends remove grep portmap libncurses5-dev kopete kiconedit 

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.98 1.04 1.02 2/55 24625
/proc/meminfo: memFree=862760/1022884 swapFree=0/0
[pid=24625] ppid=24624 vsize=54860 CPUtime=0
/proc/24625/stat : 24625 (aptitude) R 24624 24625 17863 34816 17863 4202496 591 0 0 0 0 0 0 0 20 0 1 0 29240648 56176640 490 18446744073709551615 139790877601792 139790881909144 140734368223584 140734368222792 139790875410928 0 0 0 0 0 0 0 17 0 0 0 0 0 0
/proc/24625/statm: 13715 490 401 1052 0 73 0

[startup+0.169415 s]
/proc/loadavg: 0.98 1.04 1.02 2/55 24625
/proc/meminfo: memFree=862760/1022884 swapFree=0/0
[pid=24625] ppid=24624 vsize=100508 CPUtime=0.17
/proc/24625/stat : 24625 (aptitude) R 24624 24625 17863 34816 17863 4202496 10599 1709 0 0 14 2 1 0 20 0 1 0 29240648 102920192 10399 18446744073709551615 139790877601792 139790881909144 140734368223584 140734368214848 139790835754176 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0
/proc/24625/statm: 25127 10399 9225 1052 0 1122 0
Current children cumulated CPU time (s) 0.17
Current children cumulated vsize (KiB) 100508

[startup+0.200285 s]
/proc/loadavg: 0.98 1.04 1.02 2/55 24625
/proc/meminfo: memFree=862760/1022884 swapFree=0/0
[pid=24625] ppid=24624 vsize=100508 CPUtime=0.2
/proc/24625/stat : 24625 (aptitude) R 24624 24625 17863 34816 17863 4202496 10606 1709 0 0 17 2 1 0 20 0 1 0 29240648 102920192 10406 18446744073709551615 139790877601792 139790881909144 140734368223584 140734368214848 139790872442349 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0
/proc/24625/statm: 25127 10406 9232 1052 0 1122 0
Current children cumulated CPU time (s) 0.2
Current children cumulated vsize (KiB) 100508

[startup+0.300264 s]
/proc/loadavg: 0.98 1.04 1.02 2/55 24625
/proc/meminfo: memFree=862760/1022884 swapFree=0/0
[pid=24625] ppid=24624 vsize=111108 CPUtime=0.29
/proc/24625/stat : 24625 (aptitude) R 24624 24625 17863 34816 17863 4202496 12186 1709 0 0 26 2 1 0 20 0 1 0 29240648 113774592 11978 18446744073709551615 139790877601792 139790881909144 140734368223584 140734368215176 139790879733339 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0
/proc/24625/statm: 27777 11978 9302 1052 0 3772 0
Current children cumulated CPU time (s) 0.29
Current children cumulated vsize (KiB) 111108

[startup+0.700254 s]
/proc/loadavg: 0.98 1.04 1.02 2/55 24625
/proc/meminfo: memFree=862760/1022884 swapFree=0/0
[pid=24625] ppid=24624 vsize=123288 CPUtime=0.69
/proc/24625/stat : 24625 (aptitude) R 24624 24625 17863 34816 17863 4202496 17025 1709 0 0 62 6 1 0 20 0 2 0 29240648 126246912 14298 18446744073709551615 139790877601792 139790881909144 140734368223584 140734368217208 139790879727150 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/24625/statm: 30822 14298 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: 0.98 1.04 1.02 2/57 24630
/proc/meminfo: memFree=834852/1022884 swapFree=0/0
[pid=24625] ppid=24624 vsize=131940 CPUtime=1.49
/proc/24625/stat : 24625 (aptitude) R 24624 24625 17863 34816 17863 4202496 19298 1709 0 0 142 6 1 0 20 0 2 0 29240648 135106560 16567 18446744073709551615 139790877601792 139790881909144 140734368223584 140734368210456 139790846337457 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/24625/statm: 32985 16567 9569 1052 0 8980 0
[pid=24625/tid=24630] ppid=24624 vsize=131940 CPUtime=0.01
/proc/24625/task/24630/stat : 24630 (aptitude) S 24624 24625 17863 34816 17863 4202560 4 1709 0 0 0 0 1 0 20 0 2 0 29240713 135106560 16567 18446744073709551615 139790877601792 139790881909144 140734368223584 139790768429056 139790846345940 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) 131940

[startup+3.10024 s]
/proc/loadavg: 0.98 1.04 1.02 2/57 24630
/proc/meminfo: memFree=834108/1022884 swapFree=0/0
[pid=24625] ppid=24624 vsize=139504 CPUtime=3.08
/proc/24625/stat : 24625 (aptitude) S 24624 24625 17863 34816 17863 4202496 21284 1709 0 0 301 6 1 0 20 0 2 0 29240648 142852096 18552 18446744073709551615 139790877601792 139790881909144 140734368223584 140734368215344 139790846346827 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/24625/statm: 34876 18552 9662 1052 0 10871 0
[pid=24625/tid=24630] ppid=24624 vsize=139504 CPUtime=0.55
/proc/24625/task/24630/stat : 24630 (aptitude) R 24624 24625 17863 34816 17863 4202560 1845 1709 0 0 54 0 1 0 20 0 2 0 29240713 142852096 18552 18446744073709551615 139790877601792 139790881909144 140734368223584 139790768424552 139790879830590 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) 139504

Solver just ended. Dumping a history of the last processes samples

[startup+3.20031 s]
/proc/loadavg: 0.98 1.04 1.02 2/57 24630
/proc/meminfo: memFree=834108/1022884 swapFree=0/0
[pid=24625] ppid=24624 vsize=139504 CPUtime=3.18
/proc/24625/stat : 24625 (aptitude) S 24624 24625 17863 34816 17863 4202496 21286 1709 0 0 311 6 1 0 20 0 2 0 29240648 142852096 18554 18446744073709551615 139790877601792 139790881909144 140734368223584 140734368215344 139790846346827 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/24625/statm: 34876 18554 9662 1052 0 10871 0
[pid=24625/tid=24630] ppid=24624 vsize=139504 CPUtime=0.65
/proc/24625/task/24630/stat : 24630 (aptitude) R 24624 24625 17863 34816 17863 4202560 1847 1709 0 0 64 0 1 0 20 0 2 0 29240713 142852096 18554 18446744073709551615 139790877601792 139790881909144 140734368223584 139790768424552 139790835112032 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 3.18
Current children cumulated vsize (KiB) 139504

[startup+3.60024 s]
/proc/loadavg: 0.99 1.04 1.02 2/57 24630
/proc/meminfo: memFree=826792/1022884 swapFree=0/0
[pid=24625] ppid=24624 vsize=140324 CPUtime=3.57
/proc/24625/stat : 24625 (aptitude) R 24624 24625 17863 34816 17863 4202496 21528 1709 0 0 350 6 1 0 20 0 2 0 29240648 143691776 18794 18446744073709551615 139790877601792 139790881909144 140734368223584 140734368211448 139790879808989 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/24625/statm: 35081 18794 9711 1052 0 11069 0
[pid=24625/tid=24630] ppid=24624 vsize=140324 CPUtime=0.95
/proc/24625/task/24630/stat : 24630 (aptitude) S 24624 24625 17863 34816 17863 4202560 2033 1709 0 0 94 0 1 0 20 0 2 0 29240713 143691776 18794 18446744073709551615 139790877601792 139790881909144 140734368223584 139790768429056 139790846345940 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 3.57
Current children cumulated vsize (KiB) 140324

Child status: 255
Real time (s): 3.69628
CPU time (s): 3.68423
CPU user time (s): 3.60023
CPU system time (s): 0.084005
CPU usage (%): 99.6739
Max. virtual memory (cumulated for all children) (KiB): 140324

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 3.60023
system time used= 0.084005
maximum resident set size= 75244
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 23319
page faults= 0
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 55
involuntary context switches= 114

runsolver used 0.008 second user time and 0.016001 second system time

The end