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 -s SIGUSR1 -M 1124 -C 150 -d 10 -w /tmp/misc2012/2012-09-02-17:21/basic/cudf_fumax_bu-0.1/embedded/install/rand30.cudf.log.runsolver /home/competition/cudf_fumax_bu-0.1/cudf_fumax_bu-0.1 /home/competition/data/install/rand30.cudf /tmp/misc2012/2012-09-02-17:21/basic/cudf_fumax_bu-0.1/embedded/install/rand30.cudf.result -sum(solution,installedsize),-count(removed) 

Enforcing CPUTime limit (soft limit, will send signal-name then SIGKILL): 150 seconds
Enforcing CPUTime limit (hard limit, will send SIGXCPU): 180 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: 0.84 0.98 1.00 2/64 7134
/proc/meminfo: memFree=336644/1022884 swapFree=0/0
[pid=7134] ppid=7133 vsize=3152 CPUtime=0
/proc/7134/stat : 7134 (runsolver) R 7133 1745 1745 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 1 0 116061501 3227648 32 18446744073709551615 134512640 134586868 4293225328 4293223376 4151395376 0 0 16781316 24578 0 0 0 17 0 0 0 0 0 0
/proc/7134/statm: 788 32 0 19 0 73 0
Current StackSize limit: 8192 KiB


[startup+0.137427 s]
/proc/loadavg: 0.84 0.98 1.00 2/64 7134
/proc/meminfo: memFree=336644/1022884 swapFree=0/0
[pid=7134] ppid=7133 vsize=2148 CPUtime=0
/proc/7134/stat : 7134 (cudf_fumax_bu-0) D 7133 7134 1745 0 -1 4202496 274 0 0 0 0 0 0 0 20 0 1 0 116061501 2199552 197 18446744073709551615 4194304 5895655 140736069336304 140736069332216 5193680 0 0 16781316 16929 0 0 0 17 0 0 0 0 0 0
/proc/7134/statm: 537 197 146 416 0 118 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2148

[startup+0.200283 s]
/proc/loadavg: 0.84 0.98 1.00 2/64 7134
/proc/meminfo: memFree=336644/1022884 swapFree=0/0
[pid=7134] ppid=7133 vsize=2940 CPUtime=0.01
/proc/7134/stat : 7134 (cudf_fumax_bu-0) R 7133 7134 1745 0 -1 4202496 478 0 0 0 1 0 0 0 20 0 1 0 116061501 3010560 401 18446744073709551615 4194304 5895655 140736069336304 140736069332216 4410837 0 0 16781316 16929 0 0 0 17 0 0 0 18 0 0
/proc/7134/statm: 735 401 146 416 0 316 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 2940

[startup+0.30025 s]
/proc/loadavg: 0.84 0.98 1.00 2/64 7134
/proc/meminfo: memFree=336644/1022884 swapFree=0/0
[pid=7134] ppid=7133 vsize=9500 CPUtime=0.11
/proc/7134/stat : 7134 (cudf_fumax_bu-0) R 7133 7134 1745 0 -1 4202496 2099 0 0 0 10 1 0 0 20 0 1 0 116061501 9728000 2022 18446744073709551615 4194304 5895655 140736069336304 140736069332216 4347073 0 0 16781316 16929 0 0 0 17 0 0 0 18 0 0
/proc/7134/statm: 2375 2022 149 416 0 1956 0
Current children cumulated CPU time (s) 0.11
Current children cumulated vsize (KiB) 9500

[startup+0.700217 s]
/proc/loadavg: 0.84 0.98 1.00 2/64 7134
/proc/meminfo: memFree=336644/1022884 swapFree=0/0
[pid=7134] ppid=7133 vsize=29904 CPUtime=0.5
/proc/7134/stat : 7134 (cudf_fumax_bu-0) R 7133 7134 1745 0 -1 4202496 7270 0 0 0 46 4 0 0 20 0 1 0 116061501 30621696 7144 18446744073709551615 4194304 5895655 140736069336304 140736069332216 5059895 0 0 16781316 16929 0 0 0 17 0 0 0 18 0 0
/proc/7134/statm: 7476 7144 149 416 0 7057 0
Current children cumulated CPU time (s) 0.5
Current children cumulated vsize (KiB) 29904

[startup+1.5002 s]
/proc/loadavg: 0.84 0.98 1.00 2/65 7135
/proc/meminfo: memFree=271280/1022884 swapFree=0/0
[pid=7134] ppid=7133 vsize=62852 CPUtime=1.28
/proc/7134/stat : 7134 (cudf_fumax_bu-0) R 7133 7134 1745 0 -1 4202496 15639 0 0 0 122 6 0 0 20 0 1 0 116061501 64360448 15367 18446744073709551615 4194304 5895655 140736069336304 140736069332216 4406499 0 0 16781316 16929 0 0 0 17 0 0 0 19 0 0
/proc/7134/statm: 15713 15367 149 416 0 15294 0
Current children cumulated CPU time (s) 1.28
Current children cumulated vsize (KiB) 62852

[startup+3.10023 s]
/proc/loadavg: 0.84 0.98 1.00 2/65 7135
/proc/meminfo: memFree=206304/1022884 swapFree=0/0
[pid=7134] ppid=7133 vsize=105792 CPUtime=2.66
/proc/7134/stat : 7134 (cudf_fumax_bu-0) R 7133 7134 1745 0 -1 4202496 26177 0 0 0 257 9 0 0 20 0 1 0 116061501 108331008 24204 18446744073709551615 4194304 5895655 140736069336304 140736069331160 4436208 0 0 16781316 16929 0 0 0 17 0 0 0 40 0 0
/proc/7134/statm: 26448 24204 195 416 0 26029 0
Current children cumulated CPU time (s) 2.66
Current children cumulated vsize (KiB) 105792

[startup+6.30024 s]
/proc/loadavg: 0.85 0.98 1.00 2/65 7135
/proc/meminfo: memFree=205808/1022884 swapFree=0/0
[pid=7134] ppid=7133 vsize=105924 CPUtime=5.83
/proc/7134/stat : 7134 (cudf_fumax_bu-0) R 7133 7134 1745 0 -1 4202496 26297 0 0 0 574 9 0 0 20 0 1 0 116061501 108466176 24305 18446744073709551615 4194304 5895655 140736069336304 140736069331160 5094686 0 0 16781316 16929 0 0 0 17 0 0 0 41 0 0
/proc/7134/statm: 26481 24305 195 416 0 26062 0
Current children cumulated CPU time (s) 5.83
Current children cumulated vsize (KiB) 105924

[startup+12.7002 s]
/proc/loadavg: 0.86 0.98 1.00 2/65 7135
/proc/meminfo: memFree=205312/1022884 swapFree=0/0
[pid=7134] ppid=7133 vsize=106188 CPUtime=12.15
/proc/7134/stat : 7134 (cudf_fumax_bu-0) R 7133 7134 1745 0 -1 4202496 26422 0 0 0 1205 10 0 0 20 0 1 0 116061501 108736512 24411 18446744073709551615 4194304 5895655 140736069336304 140736069331160 4436099 0 0 16781316 16929 0 0 0 17 0 0 0 44 0 0
/proc/7134/statm: 26547 24411 195 416 0 26128 0
Current children cumulated CPU time (s) 12.15
Current children cumulated vsize (KiB) 106188

[startup+25.5003 s]
/proc/loadavg: 0.96 1.00 1.00 2/65 7135
/proc/meminfo: memFree=200104/1022884 swapFree=0/0
[pid=7134] ppid=7133 vsize=110032 CPUtime=24.82
/proc/7134/stat : 7134 (cudf_fumax_bu-0) R 7133 7134 1745 0 -1 4202496 28012 0 0 0 2469 13 0 0 20 0 1 0 116061501 112672768 25679 18446744073709551615 4194304 5895655 140736069336304 140736069331160 5081787 0 0 16781316 16929 0 0 0 17 0 0 0 47 0 0
/proc/7134/statm: 27508 25679 195 416 0 27089 0
Current children cumulated CPU time (s) 24.82
Current children cumulated vsize (KiB) 110032

[startup+51.1003 s]
/proc/loadavg: 0.97 1.00 1.00 2/65 7135
/proc/meminfo: memFree=197500/1022884 swapFree=0/0
[pid=7134] ppid=7133 vsize=111704 CPUtime=50.14
/proc/7134/stat : 7134 (cudf_fumax_bu-0) R 7133 7134 1745 0 -1 4202496 153541 0 0 0 4953 61 0 0 20 0 1 0 116061501 114384896 25819 18446744073709551615 4194304 5895655 140736069336304 140736069330312 5130443 0 0 16781316 16929 0 0 0 17 0 0 0 53 0 0
/proc/7134/statm: 27926 25819 195 416 0 27507 0
Current children cumulated CPU time (s) 50.14
Current children cumulated vsize (KiB) 111704

[startup+102.3 s]
/proc/loadavg: 0.99 1.00 1.00 2/65 7135
/proc/meminfo: memFree=176172/1022884 swapFree=0/0
[pid=7134] ppid=7133 vsize=132332 CPUtime=100.9
/proc/7134/stat : 7134 (cudf_fumax_bu-0) R 7133 7134 1745 0 -1 4202496 456210 0 0 0 9913 177 0 0 20 0 1 0 116061501 135507968 31590 18446744073709551615 4194304 5895655 140736069336304 140736069331160 4452613 0 0 16781316 16929 0 0 0 17 0 0 0 60 0 0
/proc/7134/statm: 33083 31590 195 416 0 32664 0
Current children cumulated CPU time (s) 100.9
Current children cumulated vsize (KiB) 132332



Maximum CPU time exceeded: sending signal-name then SIGKILL

[startup+151.904 s]
/proc/loadavg: 0.99 1.00 1.00 2/65 7135
/proc/meminfo: memFree=160796/1022884 swapFree=0/0
[pid=7134] ppid=7133 vsize=154640 CPUtime=150.04
/proc/7134/stat : 7134 (cudf_fumax_bu-0) R 7133 7134 1745 0 -1 4202496 1267187 0 0 0 14536 468 0 0 20 0 1 0 116061501 158351360 35364 18446744073709551615 4194304 5895655 140736069336304 140736069331160 4469047 0 0 16781316 16929 0 0 0 17 0 0 0 69 0 0
/proc/7134/statm: 38660 35364 195 416 0 38241 0
Current children cumulated CPU time (s) 150.04
Current children cumulated vsize (KiB) 154640

Sending User defined signal 1 to process tree (bottom up)
Sleeping 10 seconds

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

Child status: 0
Real time (s): 151.952
CPU time (s): 150.101
CPU user time (s): 145.397
CPU system time (s): 4.70429
CPU usage (%): 98.782
Max. virtual memory (cumulated for all children) (KiB): 154640

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 145.397
system time used= 4.70429
maximum resident set size= 141456
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 1267189
page faults= 0
swaps= 0
block input operations= 68424
block output operations= 272
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 82
involuntary context switches= 17091

runsolver used 0.224014 second user time and 0.568035 second system time

The end