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/rand118.cudf.log.runsolver /home/competition/cudf_fumax_bu-0.1/cudf_fumax_bu-0.1 /home/competition/data/install/rand118.cudf /tmp/misc2012/2012-09-02-17:21/basic/cudf_fumax_bu-0.1/embedded/install/rand118.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
Current StackSize limit: 8192 KiB


[startup+0 s]
/proc/loadavg: 0.83 1.00 1.04 2/59 7084
/proc/meminfo: memFree=382580/1022884 swapFree=0/0
[pid=7084] ppid=7083 vsize=3152 CPUtime=0
/proc/7084/stat : 7084 (runsolver) R 7083 1750 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 1 0 116062582 3227648 33 18446744073709551615 134512640 134586868 4290774288 4290772336 4152140848 0 0 16781316 24578 0 0 0 17 0 0 0 0 0 0
/proc/7084/statm: 788 33 0 19 0 73 0

[startup+0.109567 s]
/proc/loadavg: 0.83 1.00 1.04 2/59 7084
/proc/meminfo: memFree=382580/1022884 swapFree=0/0
[pid=7084] ppid=7083 vsize=8380 CPUtime=0.08
/proc/7084/stat : 7084 (cudf_fumax_bu-0) R 7083 7084 1750 0 -1 4202496 1818 0 0 0 8 0 0 0 20 0 1 0 116062582 8581120 1740 18446744073709551615 4194304 5895655 140735093184800 140735093180712 4347334 0 0 16781316 16929 0 0 0 17 0 0 0 1 0 0
/proc/7084/statm: 2095 1740 149 416 0 1676 0
Current children cumulated CPU time (s) 0.08
Current children cumulated vsize (KiB) 8380

[startup+0.200269 s]
/proc/loadavg: 0.83 1.00 1.04 2/59 7084
/proc/meminfo: memFree=382580/1022884 swapFree=0/0
[pid=7084] ppid=7083 vsize=13676 CPUtime=0.17
/proc/7084/stat : 7084 (cudf_fumax_bu-0) R 7083 7084 1750 0 -1 4202496 3134 0 0 0 17 0 0 0 20 0 1 0 116062582 14004224 3056 18446744073709551615 4194304 5895655 140735093184800 140735093180728 4406714 0 0 16781316 16929 0 0 0 17 0 0 0 1 0 0
/proc/7084/statm: 3419 3056 149 416 0 3000 0
Current children cumulated CPU time (s) 0.17
Current children cumulated vsize (KiB) 13676

[startup+0.300251 s]
/proc/loadavg: 0.83 1.00 1.04 2/59 7084
/proc/meminfo: memFree=382580/1022884 swapFree=0/0
[pid=7084] ppid=7083 vsize=19080 CPUtime=0.27
/proc/7084/stat : 7084 (cudf_fumax_bu-0) R 7083 7084 1750 0 -1 4202496 4546 0 0 0 26 1 0 0 20 0 1 0 116062582 19537920 4419 18446744073709551615 4194304 5895655 140735093184800 140735093180712 4347453 0 0 16781316 16929 0 0 0 17 0 0 0 1 0 0
/proc/7084/statm: 4770 4419 149 416 0 4351 0
Current children cumulated CPU time (s) 0.27
Current children cumulated vsize (KiB) 19080

[startup+0.700185 s]
/proc/loadavg: 0.83 1.00 1.04 2/59 7084
/proc/meminfo: memFree=382580/1022884 swapFree=0/0
[pid=7084] ppid=7083 vsize=39104 CPUtime=0.67
/proc/7084/stat : 7084 (cudf_fumax_bu-0) R 7083 7084 1750 0 -1 4202496 9589 0 0 0 66 1 0 0 20 0 1 0 116062582 40042496 9413 18446744073709551615 4194304 5895655 140735093184800 140735093180712 4347118 0 0 16781316 16929 0 0 0 17 0 0 0 2 0 0
/proc/7084/statm: 9776 9413 149 416 0 9357 0
Current children cumulated CPU time (s) 0.67
Current children cumulated vsize (KiB) 39104

[startup+1.50018 s]
/proc/loadavg: 0.83 1.00 1.04 2/60 7085
/proc/meminfo: memFree=302708/1022884 swapFree=0/0
[pid=7084] ppid=7083 vsize=72224 CPUtime=1.44
/proc/7084/stat : 7084 (cudf_fumax_bu-0) R 7083 7084 1750 0 -1 4202496 17971 0 0 0 141 3 0 0 20 0 1 0 116062582 73957376 17698 18446744073709551615 4194304 5895655 140735093184800 140735093180712 4347111 0 0 16781316 16929 0 0 0 17 0 0 0 4 0 0
/proc/7084/statm: 18056 17698 149 416 0 17637 0
Current children cumulated CPU time (s) 1.44
Current children cumulated vsize (KiB) 72224

[startup+3.1002 s]
/proc/loadavg: 0.85 1.00 1.04 2/60 7085
/proc/meminfo: memFree=252612/1022884 swapFree=0/0
[pid=7084] ppid=7083 vsize=105356 CPUtime=3.04
/proc/7084/stat : 7084 (cudf_fumax_bu-0) R 7083 7084 1750 0 -1 4202496 26041 0 0 0 298 6 0 0 20 0 1 0 116062582 107884544 24139 18446744073709551615 4194304 5895655 140735093184800 140735093179656 4452112 0 0 16781316 16929 0 0 0 17 0 0 0 4 0 0
/proc/7084/statm: 26339 24139 195 416 0 25920 0
Current children cumulated CPU time (s) 3.04
Current children cumulated vsize (KiB) 105356

[startup+6.30022 s]
/proc/loadavg: 0.85 1.00 1.04 2/60 7085
/proc/meminfo: memFree=252116/1022884 swapFree=0/0
[pid=7084] ppid=7083 vsize=105624 CPUtime=6.19
/proc/7084/stat : 7084 (cudf_fumax_bu-0) R 7083 7084 1750 0 -1 4202496 26175 0 0 0 613 6 0 0 20 0 1 0 116062582 108158976 24269 18446744073709551615 4194304 5895655 140735093184800 140735093179656 5094021 0 0 16781316 16929 0 0 0 17 0 0 0 6 0 0
/proc/7084/statm: 26406 24269 195 416 0 25987 0
Current children cumulated CPU time (s) 6.19
Current children cumulated vsize (KiB) 105624

[startup+12.7002 s]
/proc/loadavg: 0.87 1.00 1.04 2/60 7085
/proc/meminfo: memFree=248272/1022884 swapFree=0/0
[pid=7084] ppid=7083 vsize=108564 CPUtime=12.53
/proc/7084/stat : 7084 (cudf_fumax_bu-0) R 7083 7084 1750 0 -1 4202496 27170 0 0 0 1245 8 0 0 20 0 1 0 116062582 111169536 25238 18446744073709551615 4194304 5895655 140735093184800 140735093179656 4456369 0 0 16781316 16929 0 0 0 17 0 0 0 6 0 0
/proc/7084/statm: 27141 25238 195 416 0 26722 0
Current children cumulated CPU time (s) 12.53
Current children cumulated vsize (KiB) 108564

[startup+25.5002 s]
/proc/loadavg: 0.89 1.00 1.04 2/60 7085
/proc/meminfo: memFree=239592/1022884 swapFree=0/0
[pid=7084] ppid=7083 vsize=115004 CPUtime=25.18
/proc/7084/stat : 7084 (cudf_fumax_bu-0) R 7083 7084 1750 0 -1 4202496 29329 0 0 0 2506 12 0 0 20 0 1 0 116062582 117764096 27337 18446744073709551615 4194304 5895655 140735093184800 140735093179656 4451032 0 0 16781316 16929 0 0 0 17 0 0 0 12 0 0
/proc/7084/statm: 28751 27337 195 416 0 28332 0
Current children cumulated CPU time (s) 25.18
Current children cumulated vsize (KiB) 115004

[startup+51.1003 s]
/proc/loadavg: 0.93 1.00 1.04 2/60 7085
/proc/meminfo: memFree=218512/1022884 swapFree=0/0
[pid=7084] ppid=7083 vsize=129508 CPUtime=50.54
/proc/7084/stat : 7084 (cudf_fumax_bu-0) R 7083 7084 1750 0 -1 4202496 141664 0 0 0 5000 54 0 0 20 0 1 0 116062582 132616192 30956 18446744073709551615 4194304 5895655 140735093184800 140735093178520 5085989 0 0 16781316 16929 0 0 0 17 0 0 0 19 0 0
/proc/7084/statm: 32377 30956 195 416 0 31958 0
Current children cumulated CPU time (s) 50.54
Current children cumulated vsize (KiB) 129508

[startup+102.3 s]
/proc/loadavg: 0.97 1.00 1.03 2/60 7085
/proc/meminfo: memFree=226324/1022884 swapFree=0/0
[pid=7084] ppid=7083 vsize=137664 CPUtime=101.12
/proc/7084/stat : 7084 (cudf_fumax_bu-0) R 7083 7084 1750 0 -1 4202496 1671256 0 0 0 9384 728 0 0 20 0 1 0 116062582 140967936 30685 18446744073709551615 4194304 5895655 140735093184800 140735093178600 4468964 0 0 16781316 16929 0 0 0 17 0 0 0 40 0 0
/proc/7084/statm: 34416 30685 195 416 0 33997 0
Current children cumulated CPU time (s) 101.12
Current children cumulated vsize (KiB) 137664



Maximum CPU time exceeded: sending signal-name then SIGKILL

[startup+151.7 s]
/proc/loadavg: 0.98 1.00 1.03 2/60 7085
/proc/meminfo: memFree=203508/1022884 swapFree=0/0
[pid=7084] ppid=7083 vsize=151268 CPUtime=150.04
/proc/7084/stat : 7084 (cudf_fumax_bu-0) R 7083 7084 1750 0 -1 4202496 3266035 0 0 0 13680 1324 0 0 20 0 1 0 116062582 154898432 36048 18446744073709551615 4194304 5895655 140735093184800 140735093179656 4474806 0 0 16781316 16929 0 0 0 17 0 0 0 54 0 0
/proc/7084/statm: 37817 36048 195 416 0 37398 0
Current children cumulated CPU time (s) 150.04
Current children cumulated vsize (KiB) 151268

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.75
CPU time (s): 150.093
CPU user time (s): 136.837
CPU system time (s): 13.2568
CPU usage (%): 98.9082
Max. virtual memory (cumulated for all children) (KiB): 178048

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 136.837
system time used= 13.2568
maximum resident set size= 167804
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 3266037
page faults= 0
swaps= 0
block input operations= 68424
block output operations= 224
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 77
involuntary context switches= 17112

runsolver used 0.264016 second user time and 0.48803 second system time

The end