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/rand984.cudf.log.runsolver /home/competition/cudf_fumax_bu-0.1/cudf_fumax_bu-0.1 /home/competition/data/install/rand984.cudf /tmp/misc2012/2012-09-02-17:21/basic/cudf_fumax_bu-0.1/paranoid-size/install/rand984.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.85 0.96 0.98 2/59 22445
/proc/meminfo: memFree=332360/1022884 swapFree=0/0
[pid=22445] ppid=22444 vsize=3152 CPUtime=0
/proc/22445/stat : 22445 (runsolver) R 22444 1733 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 1 0 115549787 3227648 33 18446744073709551615 134512640 134586868 4287205536 4287203584 4151272496 0 0 16781316 24578 0 0 0 17 0 0 0 0 0 0
/proc/22445/statm: 788 33 0 19 0 73 0
Current StackSize limit: 8192 KiB


[startup+0.146615 s]
/proc/loadavg: 0.85 0.96 0.98 2/59 22445
/proc/meminfo: memFree=332360/1022884 swapFree=0/0
[pid=22445] ppid=22444 vsize=10772 CPUtime=0.12
/proc/22445/stat : 22445 (cudf_fumax_bu-0) R 22444 22445 1733 0 -1 4202496 2411 0 0 0 12 0 0 0 20 0 1 0 115549787 11030528 2334 18446744073709551615 4194304 5895655 140736084560912 140736084556664 4346971 0 0 16781316 16929 0 0 0 17 0 0 0 1 0 0
/proc/22445/statm: 2693 2334 149 416 0 2274 0
Current children cumulated CPU time (s) 0.12
Current children cumulated vsize (KiB) 10772

[startup+0.200256 s]
/proc/loadavg: 0.85 0.96 0.98 2/59 22445
/proc/meminfo: memFree=332360/1022884 swapFree=0/0
[pid=22445] ppid=22444 vsize=13676 CPUtime=0.17
/proc/22445/stat : 22445 (cudf_fumax_bu-0) R 22444 22445 1733 0 -1 4202496 3156 0 0 0 16 1 0 0 20 0 1 0 115549787 14004224 3079 18446744073709551615 4194304 5895655 140736084560912 140736084556824 4347073 0 0 16781316 16929 0 0 0 17 0 0 0 1 0 0
/proc/22445/statm: 3419 3079 149 416 0 3000 0
Current children cumulated CPU time (s) 0.17
Current children cumulated vsize (KiB) 13676

[startup+0.300271 s]
/proc/loadavg: 0.85 0.96 0.98 2/59 22445
/proc/meminfo: memFree=332360/1022884 swapFree=0/0
[pid=22445] ppid=22444 vsize=19212 CPUtime=0.27
/proc/22445/stat : 22445 (cudf_fumax_bu-0) R 22444 22445 1733 0 -1 4202496 4570 0 0 0 26 1 0 0 20 0 1 0 115549787 19673088 4444 18446744073709551615 4194304 5895655 140736084560912 140736084556824 5087514 0 0 16781316 16929 0 0 0 17 0 0 0 1 0 0
/proc/22445/statm: 4803 4444 149 416 0 4384 0
Current children cumulated CPU time (s) 0.27
Current children cumulated vsize (KiB) 19212

[startup+0.700183 s]
/proc/loadavg: 0.85 0.96 0.98 2/59 22445
/proc/meminfo: memFree=332360/1022884 swapFree=0/0
[pid=22445] ppid=22444 vsize=39236 CPUtime=0.67
/proc/22445/stat : 22445 (cudf_fumax_bu-0) R 22444 22445 1733 0 -1 4202496 9632 0 0 0 64 3 0 0 20 0 1 0 115549787 40177664 9457 18446744073709551615 4194304 5895655 140736084560912 140736084556824 5107386 0 0 16781316 16929 0 0 0 17 0 0 0 1 0 0
/proc/22445/statm: 9809 9457 149 416 0 9390 0
Current children cumulated CPU time (s) 0.67
Current children cumulated vsize (KiB) 39236

[startup+1.50018 s]
/proc/loadavg: 0.86 0.96 0.98 2/60 22446
/proc/meminfo: memFree=252488/1022884 swapFree=0/0
[pid=22445] ppid=22444 vsize=72884 CPUtime=1.45
/proc/22445/stat : 22445 (cudf_fumax_bu-0) R 22444 22445 1733 0 -1 4202496 18147 0 0 0 136 9 0 0 20 0 1 0 115549787 74633216 17875 18446744073709551615 4194304 5895655 140736084560912 140736084556824 4347053 0 0 16781316 16929 0 0 0 17 0 0 0 2 0 0
/proc/22445/statm: 18221 17875 149 416 0 17802 0
Current children cumulated CPU time (s) 1.45
Current children cumulated vsize (KiB) 72884

[startup+3.10022 s]
/proc/loadavg: 0.86 0.96 0.98 2/60 22446
/proc/meminfo: memFree=203128/1022884 swapFree=0/0
[pid=22445] ppid=22444 vsize=104804 CPUtime=3.05
/proc/22445/stat : 22445 (cudf_fumax_bu-0) R 22444 22445 1733 0 -1 4202496 26079 0 0 0 294 11 0 0 20 0 1 0 115549787 107319296 24063 18446744073709551615 4194304 5895655 140736084560912 140736084555768 5073402 0 0 16781316 16929 0 0 0 17 0 0 0 2 0 0
/proc/22445/statm: 26201 24063 195 416 0 25782 0
Current children cumulated CPU time (s) 3.05
Current children cumulated vsize (KiB) 104804

[startup+6.3002 s]
/proc/loadavg: 0.86 0.96 0.98 2/60 22446
/proc/meminfo: memFree=202508/1022884 swapFree=0/0
[pid=22445] ppid=22444 vsize=104804 CPUtime=6.2
/proc/22445/stat : 22445 (cudf_fumax_bu-0) R 22444 22445 1733 0 -1 4202496 26092 0 0 0 608 12 0 0 20 0 1 0 115549787 107319296 24072 18446744073709551615 4194304 5895655 140736084560912 140736084555768 4473017 0 0 16781316 16929 0 0 0 17 0 0 0 5 0 0
/proc/22445/statm: 26201 24072 195 416 0 25782 0
Current children cumulated CPU time (s) 6.2
Current children cumulated vsize (KiB) 104804

[startup+12.7002 s]
/proc/loadavg: 0.88 0.96 0.98 2/60 22446
/proc/meminfo: memFree=198788/1022884 swapFree=0/0
[pid=22445] ppid=22444 vsize=108108 CPUtime=12.46
/proc/22445/stat : 22445 (cudf_fumax_bu-0) R 22444 22445 1733 0 -1 4202496 27068 0 0 0 1234 12 0 0 20 0 1 0 115549787 110702592 24980 18446744073709551615 4194304 5895655 140736084560912 140736084555768 4447231 0 0 16781316 16929 0 0 0 17 0 0 0 15 0 0
/proc/22445/statm: 27027 24980 204 416 0 26608 0
Current children cumulated CPU time (s) 12.46
Current children cumulated vsize (KiB) 108108

[startup+25.5003 s]
/proc/loadavg: 0.90 0.96 0.98 2/60 22446
/proc/meminfo: memFree=197920/1022884 swapFree=0/0
[pid=22445] ppid=22444 vsize=108588 CPUtime=25.14
/proc/22445/stat : 22445 (cudf_fumax_bu-0) R 22444 22445 1733 0 -1 4202496 27327 0 0 0 2501 13 0 0 20 0 1 0 115549787 111194112 25183 18446744073709551615 4194304 5895655 140736084560912 140736084555768 5093533 0 0 16781316 16929 0 0 0 17 0 0 0 18 0 0
/proc/22445/statm: 27147 25183 204 416 0 26728 0
Current children cumulated CPU time (s) 25.14
Current children cumulated vsize (KiB) 108588

[startup+51.1003 s]
/proc/loadavg: 0.93 0.96 0.98 2/60 22446
/proc/meminfo: memFree=195192/1022884 swapFree=0/0
[pid=22445] ppid=22444 vsize=111180 CPUtime=50.5
/proc/22445/stat : 22445 (cudf_fumax_bu-0) R 22444 22445 1733 0 -1 4202496 28131 0 0 0 5034 16 0 0 20 0 1 0 115549787 113848320 25826 18446744073709551615 4194304 5895655 140736084560912 140736084555768 4452059 0 0 16781316 16929 0 0 0 17 0 0 0 23 0 0
/proc/22445/statm: 27795 25826 204 416 0 27376 0
Current children cumulated CPU time (s) 50.5
Current children cumulated vsize (KiB) 111180

[startup+102.3 s]
/proc/loadavg: 0.97 0.97 0.98 2/60 22446
/proc/meminfo: memFree=182172/1022884 swapFree=0/0
[pid=22445] ppid=22444 vsize=126108 CPUtime=101.22
/proc/22445/stat : 22445 (cudf_fumax_bu-0) R 22444 22445 1733 0 -1 4202496 60592 0 0 0 10088 34 0 0 20 0 1 0 115549787 129134592 29065 18446744073709551615 4194304 5895655 140736084560912 140736084555768 4447285 0 0 16781316 16929 0 0 0 17 0 0 0 31 0 0
/proc/22445/statm: 31527 29065 205 416 0 31108 0
Current children cumulated CPU time (s) 101.22
Current children cumulated vsize (KiB) 126108



Maximum CPU time exceeded: sending signal-name then SIGKILL

[startup+151.5 s]
/proc/loadavg: 0.99 0.97 0.98 2/60 22446
/proc/meminfo: memFree=162820/1022884 swapFree=0/0
[pid=22445] ppid=22444 vsize=143084 CPUtime=150.06
/proc/22445/stat : 22445 (cudf_fumax_bu-0) R 22444 22445 1733 0 -1 4202496 529945 0 0 0 14806 200 0 0 20 0 1 0 115549787 146518016 33853 18446744073709551615 4194304 5895655 140736084560912 140736084555768 4452295 0 0 16781316 16929 0 0 0 17 0 0 0 33 0 0
/proc/22445/statm: 35771 33853 205 416 0 35352 0
Current children cumulated CPU time (s) 150.06
Current children cumulated vsize (KiB) 143084

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.593
CPU time (s): 150.157
CPU user time (s): 148.117
CPU system time (s): 2.04013
CPU usage (%): 99.0532
Max. virtual memory (cumulated for all children) (KiB): 143084

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 148.117
system time used= 2.04013
maximum resident set size= 135412
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 529947
page faults= 0
swaps= 0
block input operations= 68424
block output operations= 480
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 79
involuntary context switches= 17103

runsolver used 0.220013 second user time and 0.500031 second system time

The end