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: /home/misc2010/bin/runsolver -s SIGUSR1 -M 1124 -C 290 -d 10 -w /home/misc2010/tmp/201012061533/p2cudf-paranoid-1.9/rand49d73b.cudf.difficult.log.runsolver ./p2cudf-paranoid-1.9 /home/misc2010/data/2010/difficult//rand49d73b.cudf /home/misc2010/tmp/201012061533/p2cudf-paranoid-1.9/rand49d73b.cudf.difficult.result 

Enforcing CPUTime limit (soft limit, will send signal-name then SIGKILL): 290 seconds
Enforcing CPUTime limit (hard limit, will send SIGXCPU): 320 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: 1.07 1.07 1.09 5/46 18010
/proc/meminfo: memFree=785976/1048576 swapFree=2078744/2097144
[pid=18009] ppid=18008 vsize=2572 CPUtime=0
/proc/18009/stat : 18009 (p2cudf-paranoid) S 18008 18009 2059 34821 2220 4202496 377 0 0 0 0 0 0 0 25 0 1 0 875819704 2633728 273 1283457024 134512640 135304128 4293507264 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18009/statm: 643 273 233 194 0 29 0
[pid=18010] ppid=18009 vsize=2572 CPUtime=0
/proc/18010/stat : 18010 (p2cudf) R 18009 18009 2059 34821 2220 4202496 348 0 0 0 0 0 0 0 25 0 1 0 875819705 2633728 274 1283457024 134512640 135304128 4293800208 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/18010/statm: 643 274 234 194 0 29 0
[pid=18011] ppid=18010 vsize=2572 CPUtime=0
/proc/18011/stat : 18011 (p2cudf) R 18010 18009 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 25 0 1 0 875819705 2633728 40 1283457024 134512640 135304128 4293800208 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/18011/statm: 643 40 0 194 0 29 0

[startup+0.113852 s]
/proc/loadavg: 1.07 1.07 1.09 5/46 18010
/proc/meminfo: memFree=785976/1048576 swapFree=2078744/2097144
[pid=18009] ppid=18008 vsize=2572 CPUtime=0
/proc/18009/stat : 18009 (p2cudf-paranoid) S 18008 18009 2059 34821 2220 4202496 377 0 0 0 0 0 0 0 25 0 1 0 875819704 2633728 273 1283457024 134512640 135304128 4293507264 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18009/statm: 643 273 233 194 0 29 0
[pid=18010] ppid=18009 vsize=2576 CPUtime=0.02
/proc/18010/stat : 18010 (p2cudf) S 18009 18009 2059 34821 2220 4202496 391 2987 0 1 0 0 1 1 25 0 1 0 875819705 2637824 282 1283457024 134512640 135304128 4293800208 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18010/statm: 644 282 241 194 0 30 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5148

[startup+0.203863 s]
/proc/loadavg: 1.07 1.07 1.09 5/46 18010
/proc/meminfo: memFree=785976/1048576 swapFree=2078744/2097144
[pid=18009] ppid=18008 vsize=2572 CPUtime=0
/proc/18009/stat : 18009 (p2cudf-paranoid) S 18008 18009 2059 34821 2220 4202496 377 0 0 0 0 0 0 0 25 0 1 0 875819704 2633728 273 1283457024 134512640 135304128 4293507264 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18009/statm: 643 273 233 194 0 29 0
[pid=18010] ppid=18009 vsize=2576 CPUtime=0.02
/proc/18010/stat : 18010 (p2cudf) S 18009 18009 2059 34821 2220 4202496 391 2987 0 1 0 0 1 1 25 0 1 0 875819705 2637824 282 1283457024 134512640 135304128 4293800208 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18010/statm: 644 282 241 194 0 30 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5148

[startup+0.313873 s]
/proc/loadavg: 1.07 1.07 1.09 5/46 18010
/proc/meminfo: memFree=785976/1048576 swapFree=2078744/2097144
[pid=18009] ppid=18008 vsize=2572 CPUtime=0
/proc/18009/stat : 18009 (p2cudf-paranoid) S 18008 18009 2059 34821 2220 4202496 377 0 0 0 0 0 0 0 25 0 1 0 875819704 2633728 273 1283457024 134512640 135304128 4293507264 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18009/statm: 643 273 233 194 0 29 0
[pid=18010] ppid=18009 vsize=2576 CPUtime=0.02
/proc/18010/stat : 18010 (p2cudf) S 18009 18009 2059 34821 2220 4202496 391 2987 0 1 0 0 1 1 25 0 1 0 875819705 2637824 282 1283457024 134512640 135304128 4293800208 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18010/statm: 644 282 241 194 0 30 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5148

[startup+0.707313 s]
/proc/loadavg: 1.07 1.07 1.09 5/46 18010
/proc/meminfo: memFree=785976/1048576 swapFree=2078744/2097144
[pid=18009] ppid=18008 vsize=2572 CPUtime=0
/proc/18009/stat : 18009 (p2cudf-paranoid) S 18008 18009 2059 34821 2220 4202496 377 0 0 0 0 0 0 0 25 0 1 0 875819704 2633728 273 1283457024 134512640 135304128 4293507264 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18009/statm: 643 273 233 194 0 29 0
[pid=18010] ppid=18009 vsize=2576 CPUtime=0.02
/proc/18010/stat : 18010 (p2cudf) S 18009 18009 2059 34821 2220 4202496 391 2987 0 1 0 0 1 1 25 0 1 0 875819705 2637824 282 1283457024 134512640 135304128 4293800208 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18010/statm: 644 282 241 194 0 30 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5148

[startup+1.50746 s]
/proc/loadavg: 1.30 1.12 1.10 3/57 18032
/proc/meminfo: memFree=748732/1048576 swapFree=2078744/2097144
[pid=18009] ppid=18008 vsize=2572 CPUtime=0
/proc/18009/stat : 18009 (p2cudf-paranoid) S 18008 18009 2059 34821 2220 4202496 377 0 0 0 0 0 0 0 25 0 1 0 875819704 2633728 273 1283457024 134512640 135304128 4293507264 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18009/statm: 643 273 233 194 0 29 0
[pid=18010] ppid=18009 vsize=2576 CPUtime=0.02
/proc/18010/stat : 18010 (p2cudf) S 18009 18009 2059 34821 2220 4202496 391 2987 0 1 0 0 1 1 25 0 1 0 875819705 2637824 282 1283457024 134512640 135304128 4293800208 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18010/statm: 644 282 241 194 0 30 0
[pid=18023] ppid=18010 vsize=877460 CPUtime=1.41
/proc/18023/stat : 18023 (java) S 18010 18009 2059 34821 2220 4202496 17729 0 1 0 134 7 0 0 25 0 10 0 875819709 898519040 15370 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/18023/statm: 219365 15370 1741 10 0 216455 0
[pid=18023/tid=18024] ppid=18010 vsize=877460 CPUtime=0.64
/proc/18023/task/18024/stat : 18024 (java) R 18010 18009 2059 34821 2220 4202560 9266 0 1 0 60 4 0 0 25 0 10 0 875819710 898519040 15370 1283457024 134512640 134550932 4288690896 18446744073709551615 4095638547 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=18023/tid=18025] ppid=18010 vsize=877460 CPUtime=0
/proc/18023/task/18025/stat : 18025 (java) S 18010 18009 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 17 0 10 0 875819712 898519040 15370 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 0 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18026] ppid=18010 vsize=877460 CPUtime=0
/proc/18023/task/18026/stat : 18026 (java) S 18010 18009 2059 34821 2220 4202560 9 0 0 0 0 0 0 0 25 0 10 0 875819712 898519040 15370 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18027] ppid=18010 vsize=877460 CPUtime=0
/proc/18023/task/18027/stat : 18027 (java) S 18010 18009 2059 34821 2220 4202560 4 0 0 0 0 0 0 0 25 0 10 0 875819712 898519040 15370 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18028] ppid=18010 vsize=877460 CPUtime=0
/proc/18023/task/18028/stat : 18028 (java) S 18010 18009 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875819715 898519040 15370 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18029] ppid=18010 vsize=877460 CPUtime=0.27
/proc/18023/task/18029/stat : 18029 (java) R 18010 18009 2059 34821 2220 4202560 3873 0 0 0 27 0 0 0 25 0 10 0 875819715 898519040 15370 1283457024 134512640 134550932 4288690896 18446744073709551615 4149357136 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=18023/tid=18030] ppid=18010 vsize=877460 CPUtime=0.49
/proc/18023/task/18030/stat : 18030 (java) R 18010 18009 2059 34821 2220 4202560 3477 0 0 0 47 2 0 0 21 0 10 0 875819715 898519040 15370 1283457024 134512640 134550932 4288690896 18446744073709551615 4152893268 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=18023/tid=18031] ppid=18010 vsize=877460 CPUtime=0
/proc/18023/task/18031/stat : 18031 (java) S 18010 18009 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875819715 898519040 15370 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18032] ppid=18010 vsize=877460 CPUtime=0
/proc/18023/task/18032/stat : 18032 (java) S 18010 18009 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 10 0 875819715 898519040 15370 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.43
Current children cumulated vsize (KiB) 882608

[startup+3.108 s]
/proc/loadavg: 1.30 1.12 1.10 4/57 18032
/proc/meminfo: memFree=691484/1048576 swapFree=2078744/2097144
[pid=18009] ppid=18008 vsize=2572 CPUtime=0
/proc/18009/stat : 18009 (p2cudf-paranoid) S 18008 18009 2059 34821 2220 4202496 377 0 0 0 0 0 0 0 25 0 1 0 875819704 2633728 273 1283457024 134512640 135304128 4293507264 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18009/statm: 643 273 233 194 0 29 0
[pid=18010] ppid=18009 vsize=2576 CPUtime=0.02
/proc/18010/stat : 18010 (p2cudf) S 18009 18009 2059 34821 2220 4202496 391 2987 0 1 0 0 1 1 25 0 1 0 875819705 2637824 282 1283457024 134512640 135304128 4293800208 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18010/statm: 644 282 241 194 0 30 0
[pid=18023] ppid=18010 vsize=883480 CPUtime=2.99
/proc/18023/stat : 18023 (java) S 18010 18009 2059 34821 2220 4202496 58671 0 1 0 282 17 0 0 25 0 10 0 875819709 904683520 53473 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/18023/statm: 220870 53473 1743 10 0 217960 0
[pid=18023/tid=18024] ppid=18010 vsize=883480 CPUtime=1.52
/proc/18023/task/18024/stat : 18024 (java) R 18010 18009 2059 34821 2220 4202560 45225 0 1 0 140 12 0 0 25 0 10 0 875819710 904683520 53473 1283457024 134512640 134550932 4288690896 18446744073709551615 4145934278 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=18023/tid=18025] ppid=18010 vsize=883480 CPUtime=0
/proc/18023/task/18025/stat : 18025 (java) S 18010 18009 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 15 0 10 0 875819712 904683520 53473 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 0 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18026] ppid=18010 vsize=883480 CPUtime=0
/proc/18023/task/18026/stat : 18026 (java) S 18010 18009 2059 34821 2220 4202560 9 0 0 0 0 0 0 0 25 0 10 0 875819712 904683520 53473 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18027] ppid=18010 vsize=883480 CPUtime=0
/proc/18023/task/18027/stat : 18027 (java) S 18010 18009 2059 34821 2220 4202560 4 0 0 0 0 0 0 0 25 0 10 0 875819712 904683520 53473 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18028] ppid=18010 vsize=883480 CPUtime=0
/proc/18023/task/18028/stat : 18028 (java) S 18010 18009 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875819715 904683520 53473 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18029] ppid=18010 vsize=883480 CPUtime=0.51
/proc/18023/task/18029/stat : 18029 (java) S 18010 18009 2059 34821 2220 4202560 7253 0 0 0 51 0 0 0 25 0 10 0 875819715 904683520 53473 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18030] ppid=18010 vsize=883480 CPUtime=0.93
/proc/18023/task/18030/stat : 18030 (java) S 18010 18009 2059 34821 2220 4202560 5080 0 0 0 90 3 0 0 16 0 10 0 875819715 904683520 53473 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18031] ppid=18010 vsize=883480 CPUtime=0
/proc/18023/task/18031/stat : 18031 (java) S 18010 18009 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875819715 904683520 53473 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18032] ppid=18010 vsize=883480 CPUtime=0
/proc/18023/task/18032/stat : 18032 (java) S 18010 18009 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 10 0 875819715 904683520 53473 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.01
Current children cumulated vsize (KiB) 888628

[startup+6.30877 s]
/proc/loadavg: 1.44 1.15 1.11 5/59 18039
/proc/meminfo: memFree=488828/1048576 swapFree=2078744/2097144
[pid=18009] ppid=18008 vsize=2572 CPUtime=0
/proc/18009/stat : 18009 (p2cudf-paranoid) S 18008 18009 2059 34821 2220 4202496 377 0 0 0 0 0 0 0 25 0 1 0 875819704 2633728 273 1283457024 134512640 135304128 4293507264 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18009/statm: 643 273 233 194 0 29 0
[pid=18010] ppid=18009 vsize=2576 CPUtime=0.02
/proc/18010/stat : 18010 (p2cudf) S 18009 18009 2059 34821 2220 4202496 391 2987 0 1 0 0 1 1 25 0 1 0 875819705 2637824 282 1283457024 134512640 135304128 4293800208 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18010/statm: 644 282 241 194 0 30 0
[pid=18023] ppid=18010 vsize=886404 CPUtime=6.19
/proc/18023/stat : 18023 (java) S 18010 18009 2059 34821 2220 4202496 79778 0 1 0 593 26 0 0 25 0 11 0 875819709 907677696 72629 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/18023/statm: 221601 72629 1792 10 0 218691 0
[pid=18023/tid=18024] ppid=18010 vsize=886404 CPUtime=2.92
/proc/18023/task/18024/stat : 18024 (java) R 18010 18009 2059 34821 2220 4202560 50451 0 1 0 279 13 0 0 25 0 11 0 875819710 907677696 72629 1283457024 134512640 134550932 4288690896 18446744073709551615 4096584901 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=18023/tid=18025] ppid=18010 vsize=886404 CPUtime=0.32
/proc/18023/task/18025/stat : 18025 (java) S 18010 18009 2059 34821 2220 4202560 13606 0 0 0 26 6 0 0 16 0 11 0 875819712 907677696 72629 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 0 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18026] ppid=18010 vsize=886404 CPUtime=0
/proc/18023/task/18026/stat : 18026 (java) S 18010 18009 2059 34821 2220 4202560 10 0 0 0 0 0 0 0 18 0 11 0 875819712 907677696 72629 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18027] ppid=18010 vsize=886404 CPUtime=0
/proc/18023/task/18027/stat : 18027 (java) S 18010 18009 2059 34821 2220 4202560 6 0 0 0 0 0 0 0 18 0 11 0 875819712 907677696 72629 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18028] ppid=18010 vsize=886404 CPUtime=0
/proc/18023/task/18028/stat : 18028 (java) S 18010 18009 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 11 0 875819715 907677696 72629 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18029] ppid=18010 vsize=886404 CPUtime=0.51
/proc/18023/task/18029/stat : 18029 (java) S 18010 18009 2059 34821 2220 4202560 7253 0 0 0 51 0 0 0 25 0 11 0 875819715 907677696 72629 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18030] ppid=18010 vsize=886404 CPUtime=2.4
/proc/18023/task/18030/stat : 18030 (java) S 18010 18009 2059 34821 2220 4202560 7329 0 0 0 236 4 0 0 15 0 11 0 875819715 907677696 72629 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18031] ppid=18010 vsize=886404 CPUtime=0
/proc/18023/task/18031/stat : 18031 (java) S 18010 18009 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 11 0 875819715 907677696 72629 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18032] ppid=18010 vsize=886404 CPUtime=0
/proc/18023/task/18032/stat : 18032 (java) S 18010 18009 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 11 0 875819715 907677696 72629 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.21
Current children cumulated vsize (KiB) 891552

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

[startup+9.50946 s]
/proc/loadavg: 1.44 1.15 1.11 2/58 18046
/proc/meminfo: memFree=461308/1048576 swapFree=2078744/2097144
[pid=18009] ppid=18008 vsize=2572 CPUtime=0
/proc/18009/stat : 18009 (p2cudf-paranoid) S 18008 18009 2059 34821 2220 4202496 377 0 0 0 0 0 0 0 25 0 1 0 875819704 2633728 273 1283457024 134512640 135304128 4293507264 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18009/statm: 643 273 233 194 0 29 0
[pid=18010] ppid=18009 vsize=2576 CPUtime=0.02
/proc/18010/stat : 18010 (p2cudf) S 18009 18009 2059 34821 2220 4202496 391 2987 0 1 0 0 1 1 25 0 1 0 875819705 2637824 282 1283457024 134512640 135304128 4293800208 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18010/statm: 644 282 241 194 0 30 0
[pid=18023] ppid=18010 vsize=885544 CPUtime=9.38
/proc/18023/stat : 18023 (java) S 18010 18009 2059 34821 2220 4202496 86819 0 1 0 910 28 0 0 25 0 11 0 875819709 906797056 79557 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/18023/statm: 221386 79557 1793 10 0 218476 0
[pid=18023/tid=18024] ppid=18010 vsize=885544 CPUtime=5.28
/proc/18023/task/18024/stat : 18024 (java) R 18010 18009 2059 34821 2220 4202560 50452 0 1 0 515 13 0 0 25 0 11 0 875819710 906797056 79557 1283457024 134512640 134550932 4288690896 18446744073709551615 4096624540 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=18023/tid=18025] ppid=18010 vsize=885544 CPUtime=1.04
/proc/18023/task/18025/stat : 18025 (java) S 18010 18009 2059 34821 2220 4202560 20645 0 0 0 96 8 0 0 16 0 11 0 875819712 906797056 79557 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 0 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18026] ppid=18010 vsize=885544 CPUtime=0
/proc/18023/task/18026/stat : 18026 (java) S 18010 18009 2059 34821 2220 4202560 10 0 0 0 0 0 0 0 18 0 11 0 875819712 906797056 79557 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18027] ppid=18010 vsize=885544 CPUtime=0
/proc/18023/task/18027/stat : 18027 (java) S 18010 18009 2059 34821 2220 4202560 6 0 0 0 0 0 0 0 18 0 11 0 875819712 906797056 79557 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18028] ppid=18010 vsize=885544 CPUtime=0
/proc/18023/task/18028/stat : 18028 (java) S 18010 18009 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 11 0 875819715 906797056 79557 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18029] ppid=18010 vsize=885544 CPUtime=0.51
/proc/18023/task/18029/stat : 18029 (java) S 18010 18009 2059 34821 2220 4202560 7253 0 0 0 51 0 0 0 25 0 11 0 875819715 906797056 79557 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18030] ppid=18010 vsize=885544 CPUtime=2.51
/proc/18023/task/18030/stat : 18030 (java) S 18010 18009 2059 34821 2220 4202560 7330 0 0 0 247 4 0 0 16 0 11 0 875819715 906797056 79557 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18031] ppid=18010 vsize=885544 CPUtime=0
/proc/18023/task/18031/stat : 18031 (java) S 18010 18009 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 11 0 875819715 906797056 79557 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18032] ppid=18010 vsize=885544 CPUtime=0
/proc/18023/task/18032/stat : 18032 (java) R 18010 18009 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 11 0 875819715 906797056 79557 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=18023/tid=18046] ppid=18010 vsize=885544 CPUtime=0
/proc/18023/task/18046/stat : 18046 (java) S 18010 18009 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 25 0 11 0 875820354 906797056 79557 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 9.4
Current children cumulated vsize (KiB) 890692

[startup+11.1099 s]
/proc/loadavg: 1.40 1.15 1.11 4/58 18046
/proc/meminfo: memFree=460812/1048576 swapFree=2078744/2097144
[pid=18009] ppid=18008 vsize=2572 CPUtime=0
/proc/18009/stat : 18009 (p2cudf-paranoid) S 18008 18009 2059 34821 2220 4202496 377 0 0 0 0 0 0 0 25 0 1 0 875819704 2633728 273 1283457024 134512640 135304128 4293507264 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18009/statm: 643 273 233 194 0 29 0
[pid=18010] ppid=18009 vsize=2576 CPUtime=0.02
/proc/18010/stat : 18010 (p2cudf) S 18009 18009 2059 34821 2220 4202496 391 2987 0 1 0 0 1 1 25 0 1 0 875819705 2637824 282 1283457024 134512640 135304128 4293800208 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18010/statm: 644 282 241 194 0 30 0
[pid=18023] ppid=18010 vsize=885544 CPUtime=10.98
/proc/18023/stat : 18023 (java) S 18010 18009 2059 34821 2220 4202496 86823 0 1 0 1070 28 0 0 25 0 11 0 875819709 906797056 79561 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/18023/statm: 221386 79561 1793 10 0 218476 0
[pid=18023/tid=18024] ppid=18010 vsize=885544 CPUtime=6.58
/proc/18023/task/18024/stat : 18024 (java) R 18010 18009 2059 34821 2220 4202560 50452 0 1 0 645 13 0 0 25 0 11 0 875819710 906797056 79561 1283457024 134512640 134550932 4288690896 18446744073709551615 4096745208 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=18023/tid=18025] ppid=18010 vsize=885544 CPUtime=1.3
/proc/18023/task/18025/stat : 18025 (java) S 18010 18009 2059 34821 2220 4202560 20645 0 0 0 122 8 0 0 16 0 11 0 875819712 906797056 79561 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 0 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18026] ppid=18010 vsize=885544 CPUtime=0
/proc/18023/task/18026/stat : 18026 (java) S 18010 18009 2059 34821 2220 4202560 10 0 0 0 0 0 0 0 18 0 11 0 875819712 906797056 79561 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18027] ppid=18010 vsize=885544 CPUtime=0
/proc/18023/task/18027/stat : 18027 (java) S 18010 18009 2059 34821 2220 4202560 6 0 0 0 0 0 0 0 18 0 11 0 875819712 906797056 79561 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18028] ppid=18010 vsize=885544 CPUtime=0
/proc/18023/task/18028/stat : 18028 (java) S 18010 18009 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 11 0 875819715 906797056 79561 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18029] ppid=18010 vsize=885544 CPUtime=0.51
/proc/18023/task/18029/stat : 18029 (java) S 18010 18009 2059 34821 2220 4202560 7253 0 0 0 51 0 0 0 25 0 11 0 875819715 906797056 79561 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18030] ppid=18010 vsize=885544 CPUtime=2.55
/proc/18023/task/18030/stat : 18030 (java) S 18010 18009 2059 34821 2220 4202560 7334 0 0 0 251 4 0 0 16 0 11 0 875819715 906797056 79561 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18031] ppid=18010 vsize=885544 CPUtime=0
/proc/18023/task/18031/stat : 18031 (java) S 18010 18009 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 11 0 875819715 906797056 79561 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18032] ppid=18010 vsize=885544 CPUtime=0
/proc/18023/task/18032/stat : 18032 (java) S 18010 18009 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 11 0 875819715 906797056 79561 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18046] ppid=18010 vsize=885544 CPUtime=0
/proc/18023/task/18046/stat : 18046 (java) S 18010 18009 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 25 0 11 0 875820354 906797056 79561 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 11
Current children cumulated vsize (KiB) 890692

[startup+11.5045 s]
/proc/loadavg: 1.40 1.15 1.11 4/58 18046
/proc/meminfo: memFree=460812/1048576 swapFree=2078744/2097144
[pid=18009] ppid=18008 vsize=2572 CPUtime=0
/proc/18009/stat : 18009 (p2cudf-paranoid) S 18008 18009 2059 34821 2220 4202496 377 0 0 0 0 0 0 0 25 0 1 0 875819704 2633728 273 1283457024 134512640 135304128 4293507264 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18009/statm: 643 273 233 194 0 29 0
[pid=18010] ppid=18009 vsize=2576 CPUtime=0.02
/proc/18010/stat : 18010 (p2cudf) S 18009 18009 2059 34821 2220 4202496 391 2987 0 1 0 0 1 1 25 0 1 0 875819705 2637824 282 1283457024 134512640 135304128 4293800208 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18010/statm: 644 282 241 194 0 30 0
[pid=18023] ppid=18010 vsize=885544 CPUtime=11.04
/proc/18023/stat : 18023 (java) S 18010 18009 2059 34821 2220 4202496 86828 0 1 0 1076 28 0 0 25 0 11 0 875819709 906797056 79566 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/18023/statm: 221386 79566 1793 10 0 218476 0
[pid=18023/tid=18024] ppid=18010 vsize=885544 CPUtime=6.63
/proc/18023/task/18024/stat : 18024 (java) S 18010 18009 2059 34821 2220 4202560 50457 0 1 0 650 13 0 0 25 0 11 0 875819710 906797056 79566 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18025] ppid=18010 vsize=885544 CPUtime=1.3
/proc/18023/task/18025/stat : 18025 (java) S 18010 18009 2059 34821 2220 4202560 20645 0 0 0 122 8 0 0 16 0 11 0 875819712 906797056 79566 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 0 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18026] ppid=18010 vsize=885544 CPUtime=0
/proc/18023/task/18026/stat : 18026 (java) S 18010 18009 2059 34821 2220 4202560 10 0 0 0 0 0 0 0 18 0 11 0 875819712 906797056 79566 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18027] ppid=18010 vsize=885544 CPUtime=0
/proc/18023/task/18027/stat : 18027 (java) S 18010 18009 2059 34821 2220 4202560 6 0 0 0 0 0 0 0 18 0 11 0 875819712 906797056 79566 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18028] ppid=18010 vsize=885544 CPUtime=0
/proc/18023/task/18028/stat : 18028 (java) S 18010 18009 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 11 0 875819715 906797056 79566 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18029] ppid=18010 vsize=885544 CPUtime=0.51
/proc/18023/task/18029/stat : 18029 (java) S 18010 18009 2059 34821 2220 4202560 7253 0 0 0 51 0 0 0 25 0 11 0 875819715 906797056 79566 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18030] ppid=18010 vsize=885544 CPUtime=2.56
/proc/18023/task/18030/stat : 18030 (java) S 18010 18009 2059 34821 2220 4202560 7334 0 0 0 252 4 0 0 15 0 11 0 875819715 906797056 79566 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18031] ppid=18010 vsize=885544 CPUtime=0
/proc/18023/task/18031/stat : 18031 (java) S 18010 18009 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 11 0 875819715 906797056 79566 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18032] ppid=18010 vsize=885544 CPUtime=0
/proc/18023/task/18032/stat : 18032 (java) S 18010 18009 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 11 0 875819715 906797056 79566 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 11.06
Current children cumulated vsize (KiB) 890692

[startup+11.7085 s]
/proc/loadavg: 1.40 1.15 1.11 4/58 18046
/proc/meminfo: memFree=460812/1048576 swapFree=2078744/2097144
[pid=18009] ppid=18008 vsize=2572 CPUtime=0
/proc/18009/stat : 18009 (p2cudf-paranoid) S 18008 18009 2059 34821 2220 4202496 377 0 0 0 0 0 0 0 25 0 1 0 875819704 2633728 273 1283457024 134512640 135304128 4293507264 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18009/statm: 643 273 233 194 0 29 0
[pid=18010] ppid=18009 vsize=2576 CPUtime=0.02
/proc/18010/stat : 18010 (p2cudf) S 18009 18009 2059 34821 2220 4202496 391 2987 0 1 0 0 1 1 25 0 1 0 875819705 2637824 282 1283457024 134512640 135304128 4293800208 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18010/statm: 644 282 241 194 0 30 0
[pid=18023] ppid=18010 vsize=885544 CPUtime=11.07
/proc/18023/stat : 18023 (java) S 18010 18009 2059 34821 2220 4202496 86829 0 1 0 1077 30 0 0 25 0 11 0 875819709 906797056 79567 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/18023/statm: 221386 79567 1793 10 0 218476 0
[pid=18023/tid=18024] ppid=18010 vsize=885544 CPUtime=6.63
/proc/18023/task/18024/stat : 18024 (java) S 18010 18009 2059 34821 2220 4202560 50457 0 1 0 650 13 0 0 25 0 11 0 875819710 906797056 79567 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18025] ppid=18010 vsize=885544 CPUtime=1.3
/proc/18023/task/18025/stat : 18025 (java) S 18010 18009 2059 34821 2220 4202560 20645 0 0 0 122 8 0 0 16 0 11 0 875819712 906797056 79567 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 0 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18026] ppid=18010 vsize=885544 CPUtime=0
/proc/18023/task/18026/stat : 18026 (java) S 18010 18009 2059 34821 2220 4202560 10 0 0 0 0 0 0 0 18 0 11 0 875819712 906797056 79567 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18027] ppid=18010 vsize=885544 CPUtime=0
/proc/18023/task/18027/stat : 18027 (java) S 18010 18009 2059 34821 2220 4202560 6 0 0 0 0 0 0 0 18 0 11 0 875819712 906797056 79567 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18028] ppid=18010 vsize=885544 CPUtime=0
/proc/18023/task/18028/stat : 18028 (java) S 18010 18009 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 11 0 875819715 906797056 79567 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18029] ppid=18010 vsize=885544 CPUtime=0.51
/proc/18023/task/18029/stat : 18029 (java) S 18010 18009 2059 34821 2220 4202560 7253 0 0 0 51 0 0 0 25 0 11 0 875819715 906797056 79567 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18030] ppid=18010 vsize=885544 CPUtime=2.56
/proc/18023/task/18030/stat : 18030 (java) S 18010 18009 2059 34821 2220 4202560 7334 0 0 0 252 4 0 0 15 0 11 0 875819715 906797056 79567 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18031] ppid=18010 vsize=885544 CPUtime=0
/proc/18023/task/18031/stat : 18031 (java) S 18010 18009 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 11 0 875819715 906797056 79567 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
[pid=18023/tid=18032] ppid=18010 vsize=885544 CPUtime=0
/proc/18023/task/18032/stat : 18032 (java) S 18010 18009 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 11 0 875819715 906797056 79567 1283457024 134512640 134550932 4288690896 18446744073709551615 4294960130 0 4 0 16800975 18446612132680193024 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 11.09
Current children cumulated vsize (KiB) 890692

Child status: 0
Real time (s): 11.7612
CPU time (s): 11.1487
CPU user time (s): 10.7967
CPU system time (s): 0.352022
CPU usage (%): 94.7922
Max. virtual memory (cumulated for all children) (KiB): 893832

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 10.7967
system time used= 0.352022
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 90609
page faults= 2
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 1198
involuntary context switches= 1249

runsolver used 0 second user time and 0.012 second system time

The end