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/paranoid-size/install/rand179.cudf.log.runsolver /home/competition/cudf_fumax_bu-0.1/cudf_fumax_bu-0.1 /home/competition/data/install/rand179.cudf /tmp/misc2012/2012-09-02-17:21/basic/cudf_fumax_bu-0.1/paranoid-size/install/rand179.cudf.result -count(removed),-sum(solution,installedsize),-count(changed) 

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
Current StackSize limit: 8192 KiB


[startup+0 s]
/proc/loadavg: 0.86 0.99 0.99 2/59 4809
/proc/meminfo: memFree=396308/1022884 swapFree=0/0
[pid=4809] ppid=4808 vsize=3152 CPUtime=0
/proc/4809/stat : 4809 (runsolver) R 4808 1750 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 1 0 115533387 3227648 33 18446744073709551615 134512640 134586868 4294415664 4294413712 4151239728 0 0 16781316 24578 0 0 0 17 0 0 0 0 0 0
/proc/4809/statm: 788 33 0 19 0 73 0

[startup+0.163209 s]
/proc/loadavg: 0.86 0.99 0.99 2/59 4809
/proc/meminfo: memFree=396308/1022884 swapFree=0/0
[pid=4809] ppid=4808 vsize=8380 CPUtime=0.14
/proc/4809/stat : 4809 (cudf_fumax_bu-0) R 4808 4809 1750 0 -1 4202496 1828 0 0 0 12 2 0 0 20 0 1 0 115533387 8581120 1750 18446744073709551615 4194304 5895655 140733718238688 140733718234600 5086016 0 0 16781316 16929 0 0 0 17 0 0 0 1 0 0
/proc/4809/statm: 2095 1750 149 416 0 1676 0
Current children cumulated CPU time (s) 0.14
Current children cumulated vsize (KiB) 8380

[startup+0.200326 s]
/proc/loadavg: 0.86 0.99 0.99 2/59 4809
/proc/meminfo: memFree=396308/1022884 swapFree=0/0
[pid=4809] ppid=4808 vsize=9764 CPUtime=0.18
/proc/4809/stat : 4809 (cudf_fumax_bu-0) R 4808 4809 1750 0 -1 4202496 2174 0 0 0 16 2 0 0 20 0 1 0 115533387 9998336 2096 18446744073709551615 4194304 5895655 140733718238688 140733718234600 4406660 0 0 16781316 16929 0 0 0 17 0 0 0 1 0 0
/proc/4809/statm: 2441 2096 149 416 0 2022 0
Current children cumulated CPU time (s) 0.18
Current children cumulated vsize (KiB) 9764

[startup+0.300352 s]
/proc/loadavg: 0.86 0.99 0.99 2/59 4809
/proc/meminfo: memFree=396308/1022884 swapFree=0/0
[pid=4809] ppid=4808 vsize=13412 CPUtime=0.28
/proc/4809/stat : 4809 (cudf_fumax_bu-0) R 4808 4809 1750 0 -1 4202496 3072 0 0 0 26 2 0 0 20 0 1 0 115533387 13733888 2994 18446744073709551615 4194304 5895655 140733718238688 140733718234600 4346913 0 0 16781316 16929 0 0 0 17 0 0 0 1 0 0
/proc/4809/statm: 3353 2994 149 416 0 2934 0
Current children cumulated CPU time (s) 0.28
Current children cumulated vsize (KiB) 13412

[startup+0.700253 s]
/proc/loadavg: 0.86 0.99 0.99 2/59 4809
/proc/meminfo: memFree=396308/1022884 swapFree=0/0
[pid=4809] ppid=4808 vsize=27528 CPUtime=0.63
/proc/4809/stat : 4809 (cudf_fumax_bu-0) R 4808 4809 1750 0 -1 4202496 6673 0 0 0 59 4 0 0 20 0 1 0 115533387 28188672 6546 18446744073709551615 4194304 5895655 140733718238688 140733718234600 4346952 0 0 16781316 16929 0 0 0 17 0 0 0 5 0 0
/proc/4809/statm: 6882 6546 149 416 0 6463 0
Current children cumulated CPU time (s) 0.63
Current children cumulated vsize (KiB) 27528

[startup+1.50027 s]
/proc/loadavg: 0.86 0.99 0.99 2/60 4810
/proc/meminfo: memFree=340616/1022884 swapFree=0/0
[pid=4809] ppid=4808 vsize=51908 CPUtime=1.41
/proc/4809/stat : 4809 (cudf_fumax_bu-0) R 4808 4809 1750 0 -1 4202496 12798 0 0 0 133 8 0 0 20 0 1 0 115533387 53153792 12622 18446744073709551615 4194304 5895655 140733718238688 140733718234600 4300428 0 0 16781316 16929 0 0 0 17 0 0 0 6 0 0
/proc/4809/statm: 12977 12622 149 416 0 12558 0
Current children cumulated CPU time (s) 1.41
Current children cumulated vsize (KiB) 51908

[startup+3.10028 s]
/proc/loadavg: 0.86 0.99 0.99 2/60 4810
/proc/meminfo: memFree=295232/1022884 swapFree=0/0
[pid=4809] ppid=4808 vsize=103704 CPUtime=3
/proc/4809/stat : 4809 (cudf_fumax_bu-0) R 4808 4809 1750 0 -1 4202496 25587 0 0 0 284 16 0 0 20 0 1 0 115533387 106192896 23628 18446744073709551615 4194304 5895655 140733718238688 140733718233544 5086004 0 0 16781316 16929 0 0 0 17 0 0 0 6 0 0
/proc/4809/statm: 25926 23628 195 416 0 25507 0
Current children cumulated CPU time (s) 3
Current children cumulated vsize (KiB) 103704

[startup+6.30024 s]
/proc/loadavg: 0.87 0.99 0.99 2/60 4810
/proc/meminfo: memFree=263240/1022884 swapFree=0/0
[pid=4809] ppid=4808 vsize=110492 CPUtime=6.16
/proc/4809/stat : 4809 (cudf_fumax_bu-0) R 4808 4809 1750 0 -1 4202496 26923 0 0 0 600 16 0 0 20 0 1 0 115533387 113143808 24867 18446744073709551615 4194304 5895655 140733718238688 140733718233544 4452657 0 0 16781316 16929 0 0 0 17 0 0 0 7 0 0
/proc/4809/statm: 27623 24867 203 416 0 27204 0
Current children cumulated CPU time (s) 6.16
Current children cumulated vsize (KiB) 110492

[startup+12.7003 s]
/proc/loadavg: 0.88 0.99 0.99 2/60 4810
/proc/meminfo: memFree=262992/1022884 swapFree=0/0
[pid=4809] ppid=4808 vsize=110492 CPUtime=12.52
/proc/4809/stat : 4809 (cudf_fumax_bu-0) R 4808 4809 1750 0 -1 4202496 26955 0 0 0 1234 18 0 0 20 0 1 0 115533387 113143808 24896 18446744073709551615 4194304 5895655 140733718238688 140733718233544 4436099 0 0 16781316 16929 0 0 0 17 0 0 0 8 0 0
/proc/4809/statm: 27623 24896 203 416 0 27204 0
Current children cumulated CPU time (s) 12.52
Current children cumulated vsize (KiB) 110492

[startup+25.5002 s]
/proc/loadavg: 0.91 0.99 0.99 2/60 4810
/proc/meminfo: memFree=262744/1022884 swapFree=0/0
[pid=4809] ppid=4808 vsize=110492 CPUtime=25.19
/proc/4809/stat : 4809 (cudf_fumax_bu-0) R 4808 4809 1750 0 -1 4202496 27020 0 0 0 2499 20 0 0 20 0 1 0 115533387 113143808 24953 18446744073709551615 4194304 5895655 140733718238688 140733718233544 4448187 0 0 16781316 16929 0 0 0 17 0 0 0 11 0 0
/proc/4809/statm: 27623 24953 203 416 0 27204 0
Current children cumulated CPU time (s) 25.19
Current children cumulated vsize (KiB) 110492

[startup+51.1003 s]
/proc/loadavg: 0.94 0.99 0.99 2/60 4810
/proc/meminfo: memFree=259396/1022884 swapFree=0/0
[pid=4809] ppid=4808 vsize=112140 CPUtime=50.56
/proc/4809/stat : 4809 (cudf_fumax_bu-0) R 4808 4809 1750 0 -1 4202496 28037 0 0 0 5030 26 0 0 20 0 1 0 115533387 114831360 25774 18446744073709551615 4194304 5895655 140733718238688 140733718233544 4473007 0 0 16781316 16929 0 0 0 17 0 0 0 15 0 0
/proc/4809/statm: 28035 25774 203 416 0 27616 0
Current children cumulated CPU time (s) 50.56
Current children cumulated vsize (KiB) 112140

[startup+102.3 s]
/proc/loadavg: 1.01 1.00 0.99 2/60 4810
/proc/meminfo: memFree=242284/1022884 swapFree=0/0
[pid=4809] ppid=4808 vsize=127544 CPUtime=101.33
/proc/4809/stat : 4809 (cudf_fumax_bu-0) R 4808 4809 1750 0 -1 4202496 32370 0 0 0 10095 38 0 0 20 0 1 0 115533387 130605056 30024 18446744073709551615 4194304 5895655 140733718238688 140733718233544 4455699 0 0 16781316 16929 0 0 0 17 0 0 0 23 0 0
/proc/4809/statm: 31886 30024 203 416 0 31467 0
Current children cumulated CPU time (s) 101.33
Current children cumulated vsize (KiB) 127544



Maximum CPU time exceeded: sending signal-name then SIGKILL

[startup+151.5 s]
/proc/loadavg: 1.00 1.00 0.99 2/60 4810
/proc/meminfo: memFree=226908/1022884 swapFree=0/0
[pid=4809] ppid=4808 vsize=145792 CPUtime=150.02
/proc/4809/stat : 4809 (cudf_fumax_bu-0) R 4808 4809 1750 0 -1 4202496 433423 0 0 0 14818 184 0 0 20 0 1 0 115533387 149291008 33790 18446744073709551615 4194304 5895655 140733718238688 140733718232440 5131056 0 0 16781316 16929 0 0 0 17 0 0 0 37 0 0
/proc/4809/statm: 36448 33790 203 416 0 36029 0
Current children cumulated CPU time (s) 150.02
Current children cumulated vsize (KiB) 145792

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.589
CPU time (s): 150.121
CPU user time (s): 148.237
CPU system time (s): 1.88412
CPU usage (%): 99.0321
Max. virtual memory (cumulated for all children) (KiB): 145792

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 148.237
system time used= 1.88412
maximum resident set size= 138620
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 434092
page faults= 0
swaps= 0
block input operations= 68424
block output operations= 512
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 79
involuntary context switches= 17188

runsolver used 0.288018 second user time and 0.436027 second system time

The end