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/130.runsolver.aptitude aptitude -s -y --without-recommends remove apt diff xutils kdemultimedia kbugbuster 

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.07 1.08 1.04 2/55 24482
/proc/meminfo: memFree=865388/1022884 swapFree=0/0
[pid=24482] ppid=24481 vsize=3152 CPUtime=0
/proc/24482/stat : 24482 (runsolver) R 24481 17863 17863 34816 17863 4202560 0 0 0 0 0 0 0 0 20 0 1 0 29229628 3227648 32 18446744073709551615 134512640 134586868 4293641024 4293639072 4151854128 0 0 0 24578 0 0 0 17 0 0 0 0 0 0
/proc/24482/statm: 788 32 0 19 0 73 0
Current StackSize limit: 8192 KiB


[startup+0.207342 s]
/proc/loadavg: 1.07 1.08 1.04 2/55 24482
/proc/meminfo: memFree=865388/1022884 swapFree=0/0
[pid=24482] ppid=24481 vsize=100508 CPUtime=0.19
/proc/24482/stat : 24482 (aptitude) R 24481 24482 17863 34816 17863 4202496 10606 1708 0 0 15 4 0 0 20 0 1 0 29229628 102920192 10407 18446744073709551615 139773068656640 139773072963992 140734306646864 140734306638128 139773063500241 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0
/proc/24482/statm: 25127 10407 9232 1052 0 1122 0
Current children cumulated CPU time (s) 0.19
Current children cumulated vsize (KiB) 100508

[startup+0.300293 s]
/proc/loadavg: 1.07 1.08 1.04 2/55 24482
/proc/meminfo: memFree=865388/1022884 swapFree=0/0
[pid=24482] ppid=24481 vsize=111108 CPUtime=0.28
/proc/24482/stat : 24482 (aptitude) R 24481 24482 17863 34816 17863 4202496 12824 1708 0 0 24 4 0 0 20 0 1 0 29229628 113774592 12617 18446744073709551615 139773068656640 139773072963992 140734306646864 140734306638456 139773026873964 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0
/proc/24482/statm: 27777 12617 9302 1052 0 3772 0
Current children cumulated CPU time (s) 0.28
Current children cumulated vsize (KiB) 111108

[startup+0.400273 s]
/proc/loadavg: 1.07 1.08 1.04 2/55 24482
/proc/meminfo: memFree=865388/1022884 swapFree=0/0
[pid=24482] ppid=24481 vsize=117476 CPUtime=0.39
/proc/24482/stat : 24482 (aptitude) R 24481 24482 17863 34816 17863 4202496 15814 1708 0 0 33 6 0 0 20 0 1 0 29229628 120295424 14092 18446744073709551615 139773068656640 139773072963992 140734306646864 140734306636376 139773069712532 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0
/proc/24482/statm: 29369 14092 9312 1052 0 5364 0
Current children cumulated CPU time (s) 0.39
Current children cumulated vsize (KiB) 117476

[startup+0.70021 s]
/proc/loadavg: 1.07 1.08 1.04 2/55 24482
/proc/meminfo: memFree=865388/1022884 swapFree=0/0
[pid=24482] ppid=24481 vsize=123288 CPUtime=0.68
/proc/24482/stat : 24482 (aptitude) R 24481 24482 17863 34816 17863 4202496 17026 1708 0 0 60 8 0 0 20 0 2 0 29229628 126246912 14300 18446744073709551615 139773068656640 139773072963992 140734306646864 140734306640488 139773070832216 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/24482/statm: 30822 14300 9478 1052 0 6817 0
Current children cumulated CPU time (s) 0.68
Current children cumulated vsize (KiB) 123288

[startup+1.50024 s]
/proc/loadavg: 1.07 1.08 1.04 2/57 24487
/proc/meminfo: memFree=837356/1022884 swapFree=0/0
[pid=24482] ppid=24481 vsize=131940 CPUtime=1.48
/proc/24482/stat : 24482 (aptitude) R 24481 24482 17863 34816 17863 4202496 19302 1708 0 0 140 8 0 0 20 0 2 0 29229628 135106560 16572 18446744073709551615 139773068656640 139773072963992 140734306646864 140734306634984 139773026166920 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/24482/statm: 32985 16572 9569 1052 0 8980 0
[pid=24482/tid=24487] ppid=24481 vsize=131940 CPUtime=0
/proc/24482/task/24487/stat : 24487 (aptitude) S 24481 24482 17863 34816 17863 4202560 4 1708 0 0 0 0 0 0 20 0 2 0 29229693 135106560 16572 18446744073709551615 139773068656640 139773072963992 140734306646864 139772959483904 139773037400788 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.10025 s]
/proc/loadavg: 1.07 1.08 1.04 2/57 24487
/proc/meminfo: memFree=836736/1022884 swapFree=0/0
[pid=24482] ppid=24481 vsize=137816 CPUtime=3.07
/proc/24482/stat : 24482 (aptitude) R 24481 24482 17863 34816 17863 4202496 20907 1708 0 0 298 9 0 0 20 0 2 0 29229628 141123584 18173 18446744073709551615 139773068656640 139773072963992 140734306646864 140734306634728 139773070781597 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/24482/statm: 34454 18173 9710 1052 0 10442 0
[pid=24482/tid=24487] ppid=24481 vsize=137816 CPUtime=0.49
/proc/24482/task/24487/stat : 24487 (aptitude) S 24481 24482 17863 34816 17863 4202560 1411 1708 0 0 48 1 0 0 20 0 2 0 29229693 141123584 18173 18446744073709551615 139773068656640 139773072963992 140734306646864 139772959483904 139773037400788 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 3.07
Current children cumulated vsize (KiB) 137816

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

[startup+3.20033 s]
/proc/loadavg: 1.07 1.08 1.04 2/57 24487
/proc/meminfo: memFree=836736/1022884 swapFree=0/0
[pid=24482] ppid=24481 vsize=137816 CPUtime=3.17
/proc/24482/stat : 24482 (aptitude) R 24481 24482 17863 34816 17863 4202496 20907 1708 0 0 308 9 0 0 20 0 2 0 29229628 141123584 18173 18446744073709551615 139773068656640 139773072963992 140734306646864 140734306634728 139773070863015 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/24482/statm: 34454 18173 9710 1052 0 10442 0
[pid=24482/tid=24487] ppid=24481 vsize=137816 CPUtime=0.49
/proc/24482/task/24487/stat : 24487 (aptitude) S 24481 24482 17863 34816 17863 4202560 1411 1708 0 0 48 1 0 0 20 0 2 0 29229693 141123584 18173 18446744073709551615 139773068656640 139773072963992 140734306646864 139772959483904 139773037400788 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 3.17
Current children cumulated vsize (KiB) 137816

Child status: 255
Real time (s): 3.23835
CPU time (s): 3.2282
CPU user time (s): 3.10419
CPU system time (s): 0.124007
CPU usage (%): 99.6867
Max. virtual memory (cumulated for all children) (KiB): 137816

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 3.10419
system time used= 0.124007
maximum resident set size= 72760
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 22696
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= 54
involuntary context switches= 104

runsolver used 0.004 second user time and 0.016001 second system time

The end