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-sid/logs/90.runsolver.aptitude aptitude -s -y --without-recommends install wmtemp php3-cgi-mysql xbindkeys openoffice.org-l10n-zh-tw itcl3.1 

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.08 1.06 2/55 26254
/proc/meminfo: memFree=958716/1022884 swapFree=0/0
[pid=26254] ppid=26253 vsize=3152 CPUtime=0
/proc/26254/stat : 26254 (runsolver) R 26253 17863 17863 34816 17863 4202560 0 0 0 0 0 0 0 0 20 0 1 0 29821477 3227648 33 18446744073709551615 134512640 134586868 4293015312 4293013360 4151764016 0 0 0 24578 0 0 0 17 0 0 0 0 0 0
/proc/26254/statm: 788 33 0 19 0 73 0
Current StackSize limit: 8192 KiB


[startup+0.184636 s]
/proc/loadavg: 1.13 1.08 1.06 2/55 26254
/proc/meminfo: memFree=958716/1022884 swapFree=0/0
[pid=26254] ppid=26253 vsize=33024 CPUtime=0
/proc/26254/stat : 26254 (aptitude) D 26253 26254 17863 34816 17863 4202496 162 0 13 0 0 0 0 0 20 0 1 0 29821477 33816576 85 18446744073709551615 140243979288576 140243983595928 140734762697072 140734762693496 140243977147939 0 0 0 0 0 0 0 17 0 0 0 17 0 0
/proc/26254/statm: 8256 85 55 1052 0 34 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 33024

[startup+0.200421 s]
/proc/loadavg: 1.13 1.08 1.06 2/55 26254
/proc/meminfo: memFree=958716/1022884 swapFree=0/0
[pid=26254] ppid=26253 vsize=36128 CPUtime=0
/proc/26254/stat : 26254 (aptitude) D 26253 26254 17863 34816 17863 4202496 168 0 14 0 0 0 0 0 20 0 1 0 29821477 36995072 91 18446744073709551615 140243979288576 140243983595928 140734762697072 140734762693496 140243977147782 0 0 0 0 0 0 0 17 0 0 0 19 0 0
/proc/26254/statm: 9032 91 58 1052 0 39 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 36128

[startup+0.300398 s]
/proc/loadavg: 1.13 1.08 1.06 2/55 26254
/proc/meminfo: memFree=958716/1022884 swapFree=0/0
[pid=26254] ppid=26253 vsize=54968 CPUtime=0.01
/proc/26254/stat : 26254 (aptitude) R 26253 26254 17863 34816 17863 4202496 1029 0 25 0 1 0 0 0 20 0 1 0 29821477 56287232 944 18446744073709551615 140243979288576 140243983595928 140734762697072 140734762692232 140243948044656 0 134217728 4096 0 0 0 0 17 0 0 0 27 0 0
/proc/26254/statm: 13742 944 789 1052 0 106 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 54968

[startup+0.700339 s]
/proc/loadavg: 1.13 1.08 1.06 2/55 26254
/proc/meminfo: memFree=958716/1022884 swapFree=0/0
[pid=26254] ppid=26253 vsize=103288 CPUtime=0.01
/proc/26254/stat : 26254 (aptitude) D 26253 26254 17863 34816 17863 4202496 2887 1704 67 4 1 0 0 0 20 0 1 0 29821477 105766912 2754 18446744073709551615 140243979288576 140243983595928 140734762697072 140734762688544 140243974338458 0 134217728 4096 0 0 0 0 17 0 0 0 64 0 0
/proc/26254/statm: 25822 2754 1543 1052 0 1159 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 103288

[startup+1.50027 s]
/proc/loadavg: 1.13 1.08 1.06 1/56 26258
/proc/meminfo: memFree=950516/1022884 swapFree=0/0
[pid=26254] ppid=26253 vsize=103288 CPUtime=0.07
/proc/26254/stat : 26254 (aptitude) D 26253 26254 17863 34816 17863 4202496 8338 1704 200 4 6 1 0 0 20 0 1 0 29821477 105766912 8338 18446744073709551615 140243979288576 140243983595928 140734762697072 140734762688336 140243974133649 0 134217728 4096 0 0 0 0 17 0 0 0 139 0 0
/proc/26254/statm: 25822 8338 7127 1052 0 1159 0
Current children cumulated CPU time (s) 0.07
Current children cumulated vsize (KiB) 103288

[startup+3.1003 s]
/proc/loadavg: 1.13 1.08 1.06 1/56 26258
/proc/meminfo: memFree=915424/1022884 swapFree=0/0
[pid=26254] ppid=26253 vsize=123068 CPUtime=0.8
/proc/26254/stat : 26254 (aptitude) D 26253 26254 17863 34816 17863 4202496 17464 1704 224 4 68 12 0 0 20 0 1 0 29821477 126021632 15964 18446744073709551615 140243979288576 140243983595928 140734762697072 140734762686504 140243948044656 0 134217728 4096 0 0 0 0 17 0 0 0 227 0 0
/proc/26254/statm: 30767 15964 9976 1052 0 6104 0
Current children cumulated CPU time (s) 0.8
Current children cumulated vsize (KiB) 123068
heavy processes:

[startup+6.30121 s]
/proc/loadavg: 1.12 1.08 1.06 2/57 26260
/proc/meminfo: memFree=801088/1022884 swapFree=0/0
[pid=26254] ppid=26253 vsize=96476 CPUtime=3.86
/proc/26254/stat : 26254 (aptitude) R 26253 26254 17863 34816 17863 4202496 28189 2700 224 6 367 18 1 0 20 0 1 0 29821477 98791424 6891 18446744073709551615 140243979288576 140243983595928 140734762697072 140734762696632 140243937154538 0 134217728 4096 0 0 0 0 17 0 0 0 236 0 0
/proc/26254/statm: 24119 6891 1501 1052 0 8375 0
Current children cumulated CPU time (s) 3.86
Current children cumulated vsize (KiB) 96476
heavy processes:

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

[startup+6.30121 s]
/proc/loadavg: 1.12 1.08 1.06 2/56 26261
/proc/meminfo: memFree=813248/1022884 swapFree=0/0
[pid=26254] ppid=26253 vsize=96476 CPUtime=3.86
/proc/26254/stat : 26254 (aptitude) R 26253 26254 17863 34816 17863 4202496 28189 2700 224 6 367 18 1 0 20 0 1 0 29821477 98791424 6891 18446744073709551615 140243979288576 140243983595928 140734762697072 140734762696632 140243937154538 0 134217728 4096 0 0 0 0 17 0 0 0 236 0 0
/proc/26254/statm: 24119 6891 1501 1052 0 8375 0
Current children cumulated CPU time (s) 3.86
Current children cumulated vsize (KiB) 96476

Child status: 0
Real time (s): 6.31019
CPU time (s): 3.88824
CPU user time (s): 3.69223
CPU system time (s): 0.196012
CPU usage (%): 61.6185
Max. virtual memory (cumulated for all children) (KiB): 147096

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 3.69223
system time used= 0.196012
maximum resident set size= 82192
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 30956
page faults= 230
swaps= 0
block input operations= 246328
block output operations= 8
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 2431
involuntary context switches= 109

runsolver used 0.016001 second user time and 0.024001 second system time

The end