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/157.runsolver.aptitude aptitude -s -y --without-recommends remove gtk2-engines-redmond95 kapptemplate libhtml-parser-perl kdemultimedia-kfile-plugins wget 

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.13 1.06 1.02 2/55 24675
/proc/meminfo: memFree=869816/1022884 swapFree=0/0
[pid=24675] ppid=24674 vsize=3152 CPUtime=0
/proc/24675/stat : 24675 (runsolver) R 24674 17863 17863 34816 17863 4202560 0 0 0 0 0 0 0 0 20 0 1 0 29256897 3227648 32 18446744073709551615 134512640 134586868 4290154784 4290152832 4151292976 0 0 0 24578 0 0 0 17 0 0 0 0 0 0
/proc/24675/statm: 788 32 0 19 0 73 0
Current StackSize limit: 8192 KiB


[startup+0.152434 s]
/proc/loadavg: 1.13 1.06 1.02 2/55 24675
/proc/meminfo: memFree=869816/1022884 swapFree=0/0
[pid=24675] ppid=24674 vsize=100508 CPUtime=0.14
/proc/24675/stat : 24675 (aptitude) R 24674 24675 17863 34816 17863 4202496 10588 1706 0 0 10 3 1 0 20 0 1 0 29256897 102920192 10389 18446744073709551615 140271366795264 140271371102616 140737289238320 140737289229584 140271361636099 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0
/proc/24675/statm: 25127 10389 9214 1052 0 1122 0
Current children cumulated CPU time (s) 0.14
Current children cumulated vsize (KiB) 100508

[startup+0.20035 s]
/proc/loadavg: 1.13 1.06 1.02 2/55 24675
/proc/meminfo: memFree=869816/1022884 swapFree=0/0
[pid=24675] ppid=24674 vsize=100508 CPUtime=0.19
/proc/24675/stat : 24675 (aptitude) R 24674 24675 17863 34816 17863 4202496 10606 1706 0 0 15 3 1 0 20 0 1 0 29256897 102920192 10407 18446744073709551615 140271366795264 140271371102616 140737289238320 140737289229584 140271361636182 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0
/proc/24675/statm: 25127 10407 9232 1052 0 1122 0
Current children cumulated CPU time (s) 0.19
Current children cumulated vsize (KiB) 100508

[startup+0.300324 s]
/proc/loadavg: 1.13 1.06 1.02 2/55 24675
/proc/meminfo: memFree=869816/1022884 swapFree=0/0
[pid=24675] ppid=24674 vsize=104484 CPUtime=0.29
/proc/24675/stat : 24675 (aptitude) R 24674 24675 17863 34816 17863 4202496 11233 1706 0 0 24 4 1 0 20 0 1 0 29256897 106991616 11026 18446744073709551615 140271366795264 140271371102616 140737289238320 140737289229976 140271368943701 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0
/proc/24675/statm: 26121 11026 9300 1052 0 2116 0
Current children cumulated CPU time (s) 0.29
Current children cumulated vsize (KiB) 104484

[startup+0.700197 s]
/proc/loadavg: 1.13 1.06 1.02 2/55 24675
/proc/meminfo: memFree=869816/1022884 swapFree=0/0
[pid=24675] ppid=24674 vsize=123288 CPUtime=0.69
/proc/24675/stat : 24675 (aptitude) R 24674 24675 17863 34816 17863 4202496 17024 1706 0 0 61 7 1 0 20 0 2 0 29256897 126246912 14299 18446744073709551615 140271366795264 140271371102616 140737289238320 140737289231944 140271368920221 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/24675/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.13 1.06 1.02 2/57 24680
/proc/meminfo: memFree=841784/1022884 swapFree=0/0
[pid=24675] ppid=24674 vsize=131940 CPUtime=1.49
/proc/24675/stat : 24675 (aptitude) R 24674 24675 17863 34816 17863 4202496 19296 1706 0 0 140 8 1 0 20 0 2 0 29256897 135106560 16567 18446744073709551615 140271366795264 140271371102616 140737289238320 140737289226440 140271324305785 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/24675/statm: 32985 16567 9568 1052 0 8980 0
[pid=24675/tid=24680] ppid=24674 vsize=131940 CPUtime=0.01
/proc/24675/task/24680/stat : 24680 (aptitude) S 24674 24675 17863 34816 17863 4202560 4 1706 0 0 0 0 1 0 20 0 2 0 29256962 135106560 16567 18446744073709551615 140271366795264 140271371102616 140737289238320 140271257622528 140271335539412 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.10025 s]
/proc/loadavg: 1.13 1.06 1.02 2/57 24680
/proc/meminfo: memFree=841164/1022884 swapFree=0/0
[pid=24675] ppid=24674 vsize=139532 CPUtime=3.08
/proc/24675/stat : 24675 (aptitude) R 24674 24675 17863 34816 17863 4202496 21324 1706 0 0 298 9 1 0 20 0 2 0 29256897 142880768 18592 18446744073709551615 140271366795264 140271371102616 140737289238320 140737289226184 140271367624240 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/24675/statm: 34883 18592 9709 1052 0 10871 0
[pid=24675/tid=24680] ppid=24674 vsize=139532 CPUtime=0.38
/proc/24675/task/24680/stat : 24680 (aptitude) S 24674 24675 17863 34816 17863 4202560 1830 1706 0 0 36 1 1 0 20 0 2 0 29256962 142880768 18592 18446744073709551615 140271366795264 140271371102616 140737289238320 140271257622528 140271335539412 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) 139532

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

[startup+3.10025 s]
/proc/loadavg: 1.13 1.06 1.02 2/57 24680
/proc/meminfo: memFree=841164/1022884 swapFree=0/0
[pid=24675] ppid=24674 vsize=139532 CPUtime=3.08
/proc/24675/stat : 24675 (aptitude) R 24674 24675 17863 34816 17863 4202496 21324 1706 0 0 298 9 1 0 20 0 2 0 29256897 142880768 18592 18446744073709551615 140271366795264 140271371102616 140737289238320 140737289226184 140271367624240 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/24675/statm: 34883 18592 9709 1052 0 10871 0
[pid=24675/tid=24680] ppid=24674 vsize=139532 CPUtime=0.38
/proc/24675/task/24680/stat : 24680 (aptitude) S 24674 24675 17863 34816 17863 4202560 1830 1706 0 0 36 1 1 0 20 0 2 0 29256962 142880768 18592 18446744073709551615 140271366795264 140271371102616 140737289238320 140271257622528 140271335539412 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) 139532

Child status: 0
Real time (s): 3.13337
CPU time (s): 3.1202
CPU user time (s): 3.00819
CPU system time (s): 0.112007
CPU usage (%): 99.5796
Max. virtual memory (cumulated for all children) (KiB): 139532

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 3.00819
system time used= 0.112007
maximum resident set size= 74384
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 23099
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= 57
involuntary context switches= 98

runsolver used 0.020001 second user time and 0 second system time

The end