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/rand717.cudf.log.runsolver /home/competition/cudf_fumax_bu-0.1/cudf_fumax_bu-0.1 /home/competition/data/install/rand717.cudf /tmp/misc2012/2012-09-02-17:21/basic/cudf_fumax_bu-0.1/paranoid-size/install/rand717.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

[startup+0 s]
/proc/loadavg: 0.86 0.99 0.99 2/59 22438
/proc/meminfo: memFree=367072/1022884 swapFree=0/0
[pid=22438] ppid=22437 vsize=3152 CPUtime=0
/proc/22438/stat : 22438 (runsolver) R 22437 1733 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 1 0 115532930 3227648 33 18446744073709551615 134512640 134586868 4287611328 4287609376 4151215152 0 0 16781316 24578 0 0 0 17 0 0 0 0 0 0
/proc/22438/statm: 788 33 0 19 0 73 0
Current StackSize limit: 8192 KiB


[startup+0.135995 s]
/proc/loadavg: 0.86 0.99 0.99 2/59 22438
/proc/meminfo: memFree=367072/1022884 swapFree=0/0
[pid=22438] ppid=22437 vsize=7456 CPUtime=0.11
/proc/22438/stat : 22438 (cudf_fumax_bu-0) R 22437 22438 1733 0 -1 4202496 1579 0 0 0 11 0 0 0 20 0 1 0 115532930 7634944 1502 18446744073709551615 4194304 5895655 140733744514384 140733744510136 5107386 0 0 16781316 16929 0 0 0 17 0 0 0 1 0 0
/proc/22438/statm: 1864 1502 149 416 0 1445 0
Current children cumulated CPU time (s) 0.11
Current children cumulated vsize (KiB) 7456

[startup+0.200433 s]
/proc/loadavg: 0.86 0.99 0.99 2/59 22438
/proc/meminfo: memFree=367072/1022884 swapFree=0/0
[pid=22438] ppid=22437 vsize=9764 CPUtime=0.17
/proc/22438/stat : 22438 (cudf_fumax_bu-0) D 22437 22438 1733 0 -1 4202496 2186 0 0 0 17 0 0 0 20 0 1 0 115532930 9998336 2109 18446744073709551615 4194304 5895655 140733744514384 140733744510296 5193680 0 0 16781316 16929 0 0 0 17 0 0 0 1 0 0
/proc/22438/statm: 2441 2109 149 416 0 2022 0
Current children cumulated CPU time (s) 0.17
Current children cumulated vsize (KiB) 9764

[startup+0.300308 s]
/proc/loadavg: 0.86 0.99 0.99 2/59 22438
/proc/meminfo: memFree=367072/1022884 swapFree=0/0
[pid=22438] ppid=22437 vsize=13280 CPUtime=0.26
/proc/22438/stat : 22438 (cudf_fumax_bu-0) R 22437 22438 1733 0 -1 4202496 3050 0 0 0 25 1 0 0 20 0 1 0 115532930 13598720 2973 18446744073709551615 4194304 5895655 140733744514384 140733744510296 4346823 0 0 16781316 16929 0 0 0 17 0 0 0 2 0 0
/proc/22438/statm: 3320 2973 149 416 0 2901 0
Current children cumulated CPU time (s) 0.26
Current children cumulated vsize (KiB) 13280

[startup+0.700211 s]
/proc/loadavg: 0.86 0.99 0.99 2/59 22438
/proc/meminfo: memFree=367072/1022884 swapFree=0/0
[pid=22438] ppid=22437 vsize=27132 CPUtime=0.66
/proc/22438/stat : 22438 (cudf_fumax_bu-0) R 22437 22438 1733 0 -1 4202496 6547 0 0 0 62 4 0 0 20 0 1 0 115532930 27783168 6421 18446744073709551615 4194304 5895655 140733744514384 140733744510296 4346872 0 0 16781316 16929 0 0 0 17 0 0 0 3 0 0
/proc/22438/statm: 6783 6421 149 416 0 6364 0
Current children cumulated CPU time (s) 0.66
Current children cumulated vsize (KiB) 27132

[startup+1.50022 s]
/proc/loadavg: 0.86 0.99 0.99 2/60 22439
/proc/meminfo: memFree=313868/1022884 swapFree=0/0
[pid=22438] ppid=22437 vsize=51512 CPUtime=1.45
/proc/22438/stat : 22438 (cudf_fumax_bu-0) R 22437 22438 1733 0 -1 4202496 12717 0 0 0 139 6 0 0 20 0 1 0 115532930 52748288 12542 18446744073709551615 4194304 5895655 140733744514384 140733744510296 4346872 0 0 16781316 16929 0 0 0 17 0 0 0 3 0 0
/proc/22438/statm: 12878 12542 149 416 0 12459 0
Current children cumulated CPU time (s) 1.45
Current children cumulated vsize (KiB) 51512

[startup+3.1002 s]
/proc/loadavg: 0.86 0.99 0.99 2/60 22439
/proc/meminfo: memFree=253728/1022884 swapFree=0/0
[pid=22438] ppid=22437 vsize=104568 CPUtime=2.99
/proc/22438/stat : 22438 (cudf_fumax_bu-0) R 22437 22438 1733 0 -1 4202496 25909 0 0 0 288 11 0 0 20 0 1 0 115532930 107077632 23879 18446744073709551615 4194304 5895655 140733744514384 140733744509240 4436247 0 0 16781316 16929 0 0 0 17 0 0 0 8 0 0
/proc/22438/statm: 26142 23879 195 416 0 25723 0
Current children cumulated CPU time (s) 2.99
Current children cumulated vsize (KiB) 104568

[startup+6.30019 s]
/proc/loadavg: 0.87 0.99 0.99 2/60 22439
/proc/meminfo: memFree=234880/1022884 swapFree=0/0
[pid=22438] ppid=22437 vsize=107872 CPUtime=6.15
/proc/22438/stat : 22438 (cudf_fumax_bu-0) R 22437 22438 1733 0 -1 4202496 26960 0 0 0 604 11 0 0 20 0 1 0 115532930 110460928 24869 18446744073709551615 4194304 5895655 140733744514384 140733744509240 4452613 0 0 16781316 16929 0 0 0 17 0 0 0 9 0 0
/proc/22438/statm: 26968 24869 204 416 0 26549 0
Current children cumulated CPU time (s) 6.15
Current children cumulated vsize (KiB) 107872

[startup+12.7002 s]
/proc/loadavg: 0.88 0.99 0.99 2/60 22439
/proc/meminfo: memFree=233764/1022884 swapFree=0/0
[pid=22438] ppid=22437 vsize=107872 CPUtime=12.42
/proc/22438/stat : 22438 (cudf_fumax_bu-0) R 22437 22438 1733 0 -1 4202496 26993 0 0 0 1230 12 0 0 20 0 1 0 115532930 110460928 24899 18446744073709551615 4194304 5895655 140733744514384 140733744509240 4472928 0 0 16781316 16929 0 0 0 17 0 0 0 18 0 0
/proc/22438/statm: 26968 24899 204 416 0 26549 0
Current children cumulated CPU time (s) 12.42
Current children cumulated vsize (KiB) 107872

[startup+25.5003 s]
/proc/loadavg: 0.91 0.99 0.99 2/60 22439
/proc/meminfo: memFree=232276/1022884 swapFree=0/0
[pid=22438] ppid=22437 vsize=109152 CPUtime=25.05
/proc/22438/stat : 22438 (cudf_fumax_bu-0) R 22437 22438 1733 0 -1 4202496 27479 0 0 0 2491 14 0 0 20 0 1 0 115532930 111771648 25277 18446744073709551615 4194304 5895655 140733744514384 140733744509240 5093846 0 0 16781316 16929 0 0 0 17 0 0 0 26 0 0
/proc/22438/statm: 27288 25277 204 416 0 26869 0
Current children cumulated CPU time (s) 25.05
Current children cumulated vsize (KiB) 109152

[startup+51.1003 s]
/proc/loadavg: 0.94 0.99 0.99 2/60 22439
/proc/meminfo: memFree=231036/1022884 swapFree=0/0
[pid=22438] ppid=22437 vsize=110644 CPUtime=50.39
/proc/22438/stat : 22438 (cudf_fumax_bu-0) R 22437 22438 1733 0 -1 4202496 27867 0 0 0 5021 18 0 0 20 0 1 0 115532930 113299456 25592 18446744073709551615 4194304 5895655 140733744514384 140733744509240 4452779 0 0 16781316 16929 0 0 0 17 0 0 0 31 0 0
/proc/22438/statm: 27661 25592 204 416 0 27242 0
Current children cumulated CPU time (s) 50.39
Current children cumulated vsize (KiB) 110644

[startup+102.3 s]
/proc/loadavg: 0.97 0.99 0.99 2/60 22439
/proc/meminfo: memFree=221364/1022884 swapFree=0/0
[pid=22438] ppid=22437 vsize=117388 CPUtime=101.09
/proc/22438/stat : 22438 (cudf_fumax_bu-0) R 22437 22438 1733 0 -1 4202496 50016 0 0 0 10077 32 0 0 20 0 1 0 115532930 120205312 27948 18446744073709551615 4194304 5895655 140733744514384 140733744509240 5073263 0 0 16781316 16929 0 0 0 17 0 0 0 38 0 0
/proc/22438/statm: 29347 27948 204 416 0 28928 0
Current children cumulated CPU time (s) 101.09
Current children cumulated vsize (KiB) 117388



Maximum CPU time exceeded: sending signal-name then SIGKILL

[startup+151.7 s]
/proc/loadavg: 0.99 0.99 0.99 3/60 22439
/proc/meminfo: memFree=208468/1022884 swapFree=0/0
[pid=22438] ppid=22437 vsize=131460 CPUtime=150.01
/proc/22438/stat : 22438 (cudf_fumax_bu-0) R 22437 22438 1733 0 -1 4202496 53286 0 0 0 14964 37 0 0 20 0 1 0 115532930 134615040 31117 18446744073709551615 4194304 5895655 140733744514384 140733744509240 4452880 0 0 16781316 16929 0 0 0 17 0 0 0 45 0 0
/proc/22438/statm: 32865 31117 204 416 0 32446 0
Current children cumulated CPU time (s) 150.01
Current children cumulated vsize (KiB) 131460

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.79
CPU time (s): 150.101
CPU user time (s): 149.677
CPU system time (s): 0.424026
CPU usage (%): 98.8875
Max. virtual memory (cumulated for all children) (KiB): 131460

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 149.677
system time used= 0.424026
maximum resident set size= 124468
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 53288
page faults= 0
swaps= 0
block input operations= 68424
block output operations= 472
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 74
involuntary context switches= 17150

runsolver used 0.316019 second user time and 0.504031 second system time

The end