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/rand290.cudf.log.runsolver /home/competition/cudf_fumax_bu-0.1/cudf_fumax_bu-0.1 /home/competition/data/install/rand290.cudf /tmp/misc2012/2012-09-02-17:21/basic/cudf_fumax_bu-0.1/embedded/install/rand290.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: 1.46 1.37 1.09 2/64 7110
/proc/meminfo: memFree=430252/1022884 swapFree=0/0
[pid=7110] ppid=7109 vsize=3152 CPUtime=0
/proc/7110/stat : 7110 (runsolver) R 7109 1745 1745 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 1 0 115996725 3227648 33 18446744073709551615 134512640 134586868 4290877504 4290875552 4151354416 0 0 16781316 24578 0 0 0 17 0 0 0 0 0 0
/proc/7110/statm: 788 33 0 19 0 73 0
Current StackSize limit: 8192 KiB


[startup+0.116288 s]
/proc/loadavg: 1.46 1.37 1.09 2/64 7110
/proc/meminfo: memFree=430252/1022884 swapFree=0/0
[pid=7110] ppid=7109 vsize=3468 CPUtime=0.02
/proc/7110/stat : 7110 (cudf_fumax_bu-0) R 7109 7110 1745 0 -1 4202496 578 0 15 0 2 0 0 0 20 0 1 0 115996725 3551232 515 18446744073709551615 4194304 5895655 140736076459776 140736076455688 4346926 0 0 16781316 16929 0 0 0 17 0 0 0 7 0 0
/proc/7110/statm: 867 515 146 416 0 448 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 3468

[startup+0.20046 s]
/proc/loadavg: 1.46 1.37 1.09 2/64 7110
/proc/meminfo: memFree=430252/1022884 swapFree=0/0
[pid=7110] ppid=7109 vsize=7060 CPUtime=0.1
/proc/7110/stat : 7110 (cudf_fumax_bu-0) D 7109 7110 1745 0 -1 4202496 1468 0 15 0 10 0 0 0 20 0 1 0 115996725 7229440 1405 18446744073709551615 4194304 5895655 140736076459776 140736076455688 5193680 0 0 16781316 16929 0 0 0 17 0 0 0 7 0 0
/proc/7110/statm: 1765 1405 149 416 0 1346 0
Current children cumulated CPU time (s) 0.1
Current children cumulated vsize (KiB) 7060

[startup+0.300281 s]
/proc/loadavg: 1.46 1.37 1.09 2/64 7110
/proc/meminfo: memFree=430252/1022884 swapFree=0/0
[pid=7110] ppid=7109 vsize=9896 CPUtime=0.17
/proc/7110/stat : 7110 (cudf_fumax_bu-0) R 7109 7110 1745 0 -1 4202496 2181 0 15 0 16 1 0 0 20 0 1 0 115996725 10133504 2118 18446744073709551615 4194304 5895655 140736076459776 140736076455688 5082023 0 0 16781316 16929 0 0 0 17 0 0 0 11 0 0
/proc/7110/statm: 2474 2118 149 416 0 2055 0
Current children cumulated CPU time (s) 0.17
Current children cumulated vsize (KiB) 9896

[startup+0.700237 s]
/proc/loadavg: 1.46 1.37 1.09 2/64 7110
/proc/meminfo: memFree=430252/1022884 swapFree=0/0
[pid=7110] ppid=7109 vsize=22776 CPUtime=0.56
/proc/7110/stat : 7110 (cudf_fumax_bu-0) R 7109 7110 1745 0 -1 4202496 5463 0 15 0 52 4 0 0 20 0 1 0 115996725 23322624 5351 18446744073709551615 4194304 5895655 140736076459776 140736076455688 5061093 0 0 16781316 16929 0 0 0 17 0 0 0 12 0 0
/proc/7110/statm: 5694 5351 149 416 0 5275 0
Current children cumulated CPU time (s) 0.56
Current children cumulated vsize (KiB) 22776

[startup+1.50024 s]
/proc/loadavg: 1.42 1.36 1.09 2/65 7111
/proc/meminfo: memFree=382372/1022884 swapFree=0/0
[pid=7110] ppid=7109 vsize=45968 CPUtime=1.35
/proc/7110/stat : 7110 (cudf_fumax_bu-0) R 7109 7110 1745 0 -1 4202496 11320 0 15 0 126 9 0 0 20 0 1 0 115996725 47071232 11159 18446744073709551615 4194304 5895655 140736076459776 140736076455688 4211490 0 0 16781316 16929 0 0 0 17 0 0 0 12 0 0
/proc/7110/statm: 11492 11159 149 416 0 11073 0
Current children cumulated CPU time (s) 1.35
Current children cumulated vsize (KiB) 45968

[startup+3.10027 s]
/proc/loadavg: 1.42 1.36 1.09 2/65 7111
/proc/meminfo: memFree=336740/1022884 swapFree=0/0
[pid=7110] ppid=7109 vsize=107104 CPUtime=2.91
/proc/7110/stat : 7110 (cudf_fumax_bu-0) R 7109 7110 1745 0 -1 4202496 27454 0 16 0 275 16 0 0 20 0 1 0 115996725 109674496 25077 18446744073709551615 4194304 5895655 140736076459776 140736076454632 5093533 0 0 16781316 16929 0 0 0 17 0 0 0 15 0 0
/proc/7110/statm: 26776 25077 195 416 0 26357 0
Current children cumulated CPU time (s) 2.91
Current children cumulated vsize (KiB) 107104

[startup+6.30027 s]
/proc/loadavg: 1.47 1.37 1.10 2/65 7111
/proc/meminfo: memFree=294704/1022884 swapFree=0/0
[pid=7110] ppid=7109 vsize=108268 CPUtime=6.08
/proc/7110/stat : 7110 (cudf_fumax_bu-0) R 7109 7110 1745 0 -1 4202496 27928 0 16 0 590 18 0 0 20 0 1 0 115996725 110866432 25472 18446744073709551615 4194304 5895655 140736076459776 140736076454632 4448201 0 0 16781316 16929 0 0 0 17 0 0 0 16 0 0
/proc/7110/statm: 27067 25472 195 416 0 26648 0
Current children cumulated CPU time (s) 6.08
Current children cumulated vsize (KiB) 108268

[startup+12.7003 s]
/proc/loadavg: 1.51 1.38 1.10 2/65 7111
/proc/meminfo: memFree=292596/1022884 swapFree=0/0
[pid=7110] ppid=7109 vsize=108268 CPUtime=12.41
/proc/7110/stat : 7110 (cudf_fumax_bu-0) R 7109 7110 1745 0 -1 4202496 28057 0 16 0 1222 19 0 0 20 0 1 0 115996725 110866432 25598 18446744073709551615 4194304 5895655 140736076459776 140736076454632 5090113 0 0 16781316 16929 0 0 0 17 0 0 0 16 0 0
/proc/7110/statm: 27067 25598 195 416 0 26648 0
Current children cumulated CPU time (s) 12.41
Current children cumulated vsize (KiB) 108268

[startup+25.5003 s]
/proc/loadavg: 1.40 1.36 1.10 2/65 7111
/proc/meminfo: memFree=291108/1022884 swapFree=0/0
[pid=7110] ppid=7109 vsize=109548 CPUtime=25.07
/proc/7110/stat : 7110 (cudf_fumax_bu-0) R 7109 7110 1745 0 -1 4202496 28430 0 16 0 2486 21 0 0 20 0 1 0 115996725 112177152 25971 18446744073709551615 4194304 5895655 140736076459776 140736076454632 4474720 0 0 16781316 16929 0 0 0 17 0 0 0 18 0 0
/proc/7110/statm: 27387 25971 195 416 0 26968 0
Current children cumulated CPU time (s) 25.07
Current children cumulated vsize (KiB) 109548

[startup+51.1003 s]
/proc/loadavg: 1.26 1.33 1.09 2/65 7111
/proc/meminfo: memFree=278212/1022884 swapFree=0/0
[pid=7110] ppid=7109 vsize=124020 CPUtime=50.42
/proc/7110/stat : 7110 (cudf_fumax_bu-0) R 7109 7110 1745 0 -1 4202496 31635 0 16 0 5018 24 0 0 20 0 1 0 115996725 126996480 29173 18446744073709551615 4194304 5895655 140736076459776 140736076454632 4428323 0 0 16781316 16929 0 0 0 17 0 0 0 22 0 0
/proc/7110/statm: 31005 29173 195 416 0 30586 0
Current children cumulated CPU time (s) 50.42
Current children cumulated vsize (KiB) 124020

[startup+102.3 s]
/proc/loadavg: 1.11 1.28 1.09 2/65 7111
/proc/meminfo: memFree=256636/1022884 swapFree=0/0
[pid=7110] ppid=7109 vsize=144336 CPUtime=100.79
/proc/7110/stat : 7110 (cudf_fumax_bu-0) R 7109 7110 1745 0 -1 4202496 38150 0 16 0 10049 30 0 0 20 0 1 0 115996725 147800064 34520 18446744073709551615 4194304 5895655 140736076459776 140736076454632 4456376 0 0 16781316 16929 0 0 0 17 0 0 0 66 0 0
/proc/7110/statm: 36084 34520 195 416 0 35665 0
Current children cumulated CPU time (s) 100.79
Current children cumulated vsize (KiB) 144336



Maximum CPU time exceeded: sending signal-name then SIGKILL

[startup+152.1 s]
/proc/loadavg: 1.05 1.23 1.08 2/65 7111
/proc/meminfo: memFree=245972/1022884 swapFree=0/0
[pid=7110] ppid=7109 vsize=158796 CPUtime=150
/proc/7110/stat : 7110 (cudf_fumax_bu-0) R 7109 7110 1745 0 -1 4202496 161722 0 17 0 14928 72 0 0 20 0 1 0 115996725 162607104 37126 18446744073709551615 4194304 5895655 140736076459776 140736076453528 5081845 0 0 16781316 16929 0 0 0 17 0 0 0 82 0 0
/proc/7110/statm: 39699 37126 208 416 0 39280 0
Current children cumulated CPU time (s) 150
Current children cumulated vsize (KiB) 158796

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): 152.179
CPU time (s): 150.089
CPU user time (s): 149.337
CPU system time (s): 0.752047
CPU usage (%): 98.6268
Max. virtual memory (cumulated for all children) (KiB): 170808

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 149.337
system time used= 0.752047
maximum resident set size= 158196
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 163967
page faults= 17
swaps= 0
block input operations= 71560
block output operations= 232
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 103
involuntary context switches= 17173

runsolver used 0.276017 second user time and 0.588036 second system time

The end