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/real/103c9978-5408-11df-9bc1-00163e7a6f5e.cudf.log.runsolver /home/competition/cudf_fumax_bu-0.1/cudf_fumax_bu-0.1 /home/competition/data/real/103c9978-5408-11df-9bc1-00163e7a6f5e.cudf /tmp/misc2012/2012-09-02-17:21/basic/cudf_fumax_bu-0.1/embedded/real/103c9978-5408-11df-9bc1-00163e7a6f5e.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.90 0.96 0.99 2/60 11374
/proc/meminfo: memFree=238604/1022884 swapFree=0/0
[pid=11374] ppid=11373 vsize=2280 CPUtime=0
/proc/11374/stat : 11374 (cudf_fumax_bu-0) R 11373 11374 32685 0 -1 4202496 295 0 0 0 0 0 0 0 20 0 1 0 37855692 2334720 217 18446744073709551615 4194304 5895655 140735486085840 140735486081752 4347111 0 0 16781316 16929 0 0 0 17 0 0 0 0 0 0
/proc/11374/statm: 570 217 146 416 0 151 0

[startup+0.13827 s]
/proc/loadavg: 0.90 0.96 0.99 2/60 11374
/proc/meminfo: memFree=238604/1022884 swapFree=0/0
[pid=11374] ppid=11373 vsize=8292 CPUtime=0.13
/proc/11374/stat : 11374 (cudf_fumax_bu-0) R 11373 11374 32685 0 -1 4202496 1792 0 0 0 12 1 0 0 20 0 1 0 37855692 8491008 1714 18446744073709551615 4194304 5895655 140735486085840 140735486081752 4406462 0 0 16781316 16929 0 0 0 17 0 0 0 0 0 0
/proc/11374/statm: 2073 1714 149 416 0 1654 0
Current children cumulated CPU time (s) 0.13
Current children cumulated vsize (KiB) 8292

[startup+0.200315 s]
/proc/loadavg: 0.90 0.96 0.99 2/60 11374
/proc/meminfo: memFree=238604/1022884 swapFree=0/0
[pid=11374] ppid=11373 vsize=10748 CPUtime=0.19
/proc/11374/stat : 11374 (cudf_fumax_bu-0) R 11373 11374 32685 0 -1 4202496 2424 0 0 0 18 1 0 0 20 0 1 0 37855692 11005952 2346 18446744073709551615 4194304 5895655 140735486085840 140735486081752 4346913 0 0 16781316 16929 0 0 0 17 0 0 0 0 0 0
/proc/11374/statm: 2687 2346 149 416 0 2268 0
Current children cumulated CPU time (s) 0.19
Current children cumulated vsize (KiB) 10748

[startup+0.300308 s]
/proc/loadavg: 0.90 0.96 0.99 2/60 11374
/proc/meminfo: memFree=238604/1022884 swapFree=0/0
[pid=11374] ppid=11373 vsize=14708 CPUtime=0.29
/proc/11374/stat : 11374 (cudf_fumax_bu-0) R 11373 11374 32685 0 -1 4202496 3398 0 0 0 27 2 0 0 20 0 1 0 37855692 15060992 3320 18446744073709551615 4194304 5895655 140735486085840 140735486081752 4347031 0 0 16781316 16929 0 0 0 17 0 0 0 0 0 0
/proc/11374/statm: 3677 3320 149 416 0 3258 0
Current children cumulated CPU time (s) 0.29
Current children cumulated vsize (KiB) 14708

[startup+0.700231 s]
/proc/loadavg: 0.90 0.96 0.99 2/60 11374
/proc/meminfo: memFree=238604/1022884 swapFree=0/0
[pid=11374] ppid=11373 vsize=29584 CPUtime=0.69
/proc/11374/stat : 11374 (cudf_fumax_bu-0) R 11373 11374 32685 0 -1 4202496 7236 0 0 0 65 4 0 0 20 0 1 0 37855692 30294016 7060 18446744073709551615 4194304 5895655 140735486085840 140735486081752 4346872 0 0 16781316 16929 0 0 0 17 0 0 0 0 0 0
/proc/11374/statm: 7396 7060 149 416 0 6977 0
Current children cumulated CPU time (s) 0.69
Current children cumulated vsize (KiB) 29584

[startup+1.50024 s]
/proc/loadavg: 0.91 0.96 0.99 2/61 11375
/proc/meminfo: memFree=199404/1022884 swapFree=0/0
[pid=11374] ppid=11373 vsize=45848 CPUtime=1.48
/proc/11374/stat : 11374 (cudf_fumax_bu-0) R 11373 11374 32685 0 -1 4202496 10635 0 0 0 143 5 0 0 20 0 1 0 37855692 46948352 10053 18446744073709551615 4194304 5895655 140735486085840 140735486080696 4474658 0 0 16781316 16929 0 0 0 17 0 0 0 0 0 0
/proc/11374/statm: 11462 10053 195 416 0 11043 0
Current children cumulated CPU time (s) 1.48
Current children cumulated vsize (KiB) 45848

[startup+3.10024 s]
/proc/loadavg: 0.91 0.96 0.99 2/61 11375
/proc/meminfo: memFree=199032/1022884 swapFree=0/0
[pid=11374] ppid=11373 vsize=45980 CPUtime=3.08
/proc/11374/stat : 11374 (cudf_fumax_bu-0) R 11373 11374 32685 0 -1 4202496 10643 0 0 0 302 6 0 0 20 0 1 0 37855692 47083520 10061 18446744073709551615 4194304 5895655 140735486085840 140735486080696 4436159 0 0 16781316 16929 0 0 0 17 0 0 0 0 0 0
/proc/11374/statm: 11495 10061 195 416 0 11076 0
Current children cumulated CPU time (s) 3.08
Current children cumulated vsize (KiB) 45980

[startup+6.30024 s]
/proc/loadavg: 0.91 0.96 0.99 2/61 11375
/proc/meminfo: memFree=198536/1022884 swapFree=0/0
[pid=11374] ppid=11373 vsize=46624 CPUtime=6.25
/proc/11374/stat : 11374 (cudf_fumax_bu-0) R 11373 11374 32685 0 -1 4202496 10804 0 0 0 616 9 0 0 20 0 1 0 37855692 47742976 10190 18446744073709551615 4194304 5895655 140735486085840 140735486080696 4452438 0 0 16781316 16929 0 0 0 17 0 0 0 0 0 0
/proc/11374/statm: 11656 10190 195 416 0 11237 0
Current children cumulated CPU time (s) 6.25
Current children cumulated vsize (KiB) 46624

[startup+12.7002 s]
/proc/loadavg: 0.93 0.96 0.99 2/61 11375
/proc/meminfo: memFree=198040/1022884 swapFree=0/0
[pid=11374] ppid=11373 vsize=46820 CPUtime=12.6
/proc/11374/stat : 11374 (cudf_fumax_bu-0) R 11373 11374 32685 0 -1 4202496 10882 0 0 0 1249 11 0 0 20 0 1 0 37855692 47943680 10249 18446744073709551615 4194304 5895655 140735486085840 140735486080696 5093846 0 0 16781316 16929 0 0 0 17 0 0 0 0 0 0
/proc/11374/statm: 11705 10249 195 416 0 11286 0
Current children cumulated CPU time (s) 12.6
Current children cumulated vsize (KiB) 46820

Solver just ended. Dumping a history of the last processes samples

[startup+12.8003 s]
/proc/loadavg: 0.93 0.96 0.99 2/61 11375
/proc/meminfo: memFree=198040/1022884 swapFree=0/0
[pid=11374] ppid=11373 vsize=46820 CPUtime=12.7
/proc/11374/stat : 11374 (cudf_fumax_bu-0) R 11373 11374 32685 0 -1 4202496 10882 0 0 0 1259 11 0 0 20 0 1 0 37855692 47943680 10249 18446744073709551615 4194304 5895655 140735486085840 140735486080696 5085752 0 0 16781316 16929 0 0 0 17 0 0 0 0 0 0
/proc/11374/statm: 11705 10249 195 416 0 11286 0
Current children cumulated CPU time (s) 12.7
Current children cumulated vsize (KiB) 46820

[startup+16.0002 s]
/proc/loadavg: 0.93 0.96 0.99 2/61 11375
/proc/meminfo: memFree=197792/1022884 swapFree=0/0
[pid=11374] ppid=11373 vsize=46976 CPUtime=15.89
/proc/11374/stat : 11374 (cudf_fumax_bu-0) R 11373 11374 32685 0 -1 4202496 10955 0 0 0 1576 13 0 0 20 0 1 0 37855692 48103424 10308 18446744073709551615 4194304 5895655 140735486085840 140735486080696 4428323 0 0 16781316 16929 0 0 0 17 0 0 0 1 0 0
/proc/11374/statm: 11744 10308 195 416 0 11325 0
Current children cumulated CPU time (s) 15.89
Current children cumulated vsize (KiB) 46976

[startup+17.6003 s]
/proc/loadavg: 0.93 0.96 0.99 2/61 11375
/proc/meminfo: memFree=197668/1022884 swapFree=0/0
[pid=11374] ppid=11373 vsize=46976 CPUtime=17.48
/proc/11374/stat : 11374 (cudf_fumax_bu-0) R 11373 11374 32685 0 -1 4202496 10987 0 0 0 1735 13 0 0 20 0 1 0 37855692 48103424 10333 18446744073709551615 4194304 5895655 140735486085840 140735486080696 5086074 0 0 16781316 16929 0 0 0 17 0 0 0 1 0 0
/proc/11374/statm: 11744 10333 195 416 0 11325 0
Current children cumulated CPU time (s) 17.48
Current children cumulated vsize (KiB) 46976

[startup+18.4002 s]
/proc/loadavg: 0.93 0.96 0.99 2/61 11375
/proc/meminfo: memFree=197668/1022884 swapFree=0/0
[pid=11374] ppid=11373 vsize=47640 CPUtime=18.27
/proc/11374/stat : 11374 (cudf_fumax_bu-0) R 11373 11374 32685 0 -1 4202496 11147 0 0 0 1814 13 0 0 20 0 1 0 37855692 48783360 10457 18446744073709551615 4194304 5895655 140735486085840 140735486080696 4446901 0 0 16781316 16929 0 0 0 17 0 0 0 1 0 0
/proc/11374/statm: 11910 10457 195 416 0 11491 0
Current children cumulated CPU time (s) 18.27
Current children cumulated vsize (KiB) 47640

[startup+18.8086 s]
/proc/loadavg: 0.93 0.96 0.99 2/61 11375
/proc/meminfo: memFree=197172/1022884 swapFree=0/0
[pid=11374] ppid=11373 vsize=47640 CPUtime=18.68
/proc/11374/stat : 11374 (cudf_fumax_bu-0) R 11373 11374 32685 0 -1 4202496 11168 0 0 0 1853 15 0 0 20 0 1 0 37855692 48783360 10472 18446744073709551615 4194304 5895655 140735486085840 140735486080696 5084769 0 0 16781316 16929 0 0 0 17 0 0 0 1 0 0
/proc/11374/statm: 11910 10472 195 416 0 11491 0
Current children cumulated CPU time (s) 18.68
Current children cumulated vsize (KiB) 47640

[startup+19.0002 s]
/proc/loadavg: 0.93 0.96 0.99 2/61 11375
/proc/meminfo: memFree=197172/1022884 swapFree=0/0
[pid=11374] ppid=11373 vsize=47640 CPUtime=18.87
/proc/11374/stat : 11374 (cudf_fumax_bu-0) R 11373 11374 32685 0 -1 4202496 11170 0 0 0 1872 15 0 0 20 0 1 0 37855692 48783360 10473 18446744073709551615 4194304 5895655 140735486085840 140735486080696 4452862 0 0 16781316 16929 0 0 0 17 0 0 0 1 0 0
/proc/11374/statm: 11910 10473 195 416 0 11491 0
Current children cumulated CPU time (s) 18.87
Current children cumulated vsize (KiB) 47640

[startup+19.1036 s]
/proc/loadavg: 0.93 0.96 0.99 2/61 11375
/proc/meminfo: memFree=197172/1022884 swapFree=0/0
[pid=11374] ppid=11373 vsize=0 CPUtime=18.97
/proc/11374/stat : 11374 (cudf_fumax_bu-0) R 11373 11374 32685 0 -1 4202500 11313 0 0 0 1881 16 0 0 20 0 1 0 37855692 0 0 18446744073709551615 0 0 0 0 0 0 0 16781316 16929 18446744073709551615 0 0 17 0 0 0 1 0 0
/proc/11374/statm: 0 0 0 0 0 0 0
Current children cumulated CPU time (s) 18.97
Current children cumulated vsize (KiB) 0

Child status: 0
Real time (s): 19.1039
CPU time (s): 18.9772
CPU user time (s): 18.8132
CPU system time (s): 0.16401
CPU usage (%): 99.337
Max. virtual memory (cumulated for all children) (KiB): 47640

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 18.8132
system time used= 0.16401
maximum resident set size= 42320
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 11313
page faults= 0
swaps= 0
block input operations= 0
block output operations= 320
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 7
involuntary context switches= 288

runsolver used 0.052003 second user time and 0.072004 second system time

The end