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/201108251442/p2cudf-paranoid-1.13/80e3fda2-9501-11e0-8001-00163e1e087d.cudf.dudf-real.log.runsolver ./p2cudf-paranoid-1.13 /home/misc2010/data/2011/dudf-real//80e3fda2-9501-11e0-8001-00163e1e087d.cudf /home/misc2010/tmp/201108251442/p2cudf-paranoid-1.13/80e3fda2-9501-11e0-8001-00163e1e087d.cudf.dudf-real.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.44 1.40 1.29 5/38 25584
/proc/meminfo: memFree=259216/1048576 swapFree=0/0
[pid=25581] ppid=25580 vsize=2572 CPUtime=0
/proc/25581/stat : 25581 (p2cudf-paranoid) S 25580 25581 4778 34817 4778 4202496 375 0 0 0 0 0 0 0 18 0 1 0 11202604 2633728 271 1283457024 134512640 135304128 4291548832 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25581/statm: 643 271 230 194 0 30 0
[pid=25582] ppid=25581 vsize=2564 CPUtime=0
/proc/25582/stat : 25582 (p2cudf) S 25581 25581 4778 34817 4778 4202496 352 0 0 0 0 0 0 0 18 0 1 0 11202605 2625536 270 1283457024 134512640 135304128 4292788192 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0
/proc/25582/statm: 641 270 231 194 0 28 0
[pid=25583] ppid=25582 vsize=2564 CPUtime=0
/proc/25583/stat : 25583 (p2cudf) R 25582 25581 4778 34817 4778 4202560 94 0 0 0 0 0 0 0 25 0 1 0 11202605 2625536 118 1283457024 134512640 135304128 4292788192 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/25583/statm: 641 118 77 194 0 28 0
[pid=25584] ppid=25583 vsize=2564 CPUtime=0
/proc/25584/stat : 25584 (p2cudf) R 25583 25581 4778 34817 4778 4202560 0 0 0 0 0 0 0 0 25 0 1 0 11202605 2625536 41 1283457024 134512640 135304128 4292788192 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/25584/statm: 641 41 0 194 0 28 0

[startup+0.164433 s]
/proc/loadavg: 1.44 1.40 1.29 5/38 25584
/proc/meminfo: memFree=259216/1048576 swapFree=0/0
[pid=25581] ppid=25580 vsize=2572 CPUtime=0
/proc/25581/stat : 25581 (p2cudf-paranoid) S 25580 25581 4778 34817 4778 4202496 375 0 0 0 0 0 0 0 18 0 1 0 11202604 2633728 271 1283457024 134512640 135304128 4291548832 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25581/statm: 643 271 230 194 0 30 0
[pid=25582] ppid=25581 vsize=2568 CPUtime=0.02
/proc/25582/stat : 25582 (p2cudf) S 25581 25581 4778 34817 4778 4202496 388 3013 0 1 0 0 0 2 25 0 1 0 11202605 2629632 279 1283457024 134512640 135304128 4292788192 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25582/statm: 642 279 239 194 0 29 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5140

[startup+0.204432 s]
/proc/loadavg: 1.44 1.40 1.29 5/38 25584
/proc/meminfo: memFree=259216/1048576 swapFree=0/0
[pid=25581] ppid=25580 vsize=2572 CPUtime=0
/proc/25581/stat : 25581 (p2cudf-paranoid) S 25580 25581 4778 34817 4778 4202496 375 0 0 0 0 0 0 0 18 0 1 0 11202604 2633728 271 1283457024 134512640 135304128 4291548832 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25581/statm: 643 271 230 194 0 30 0
[pid=25582] ppid=25581 vsize=2568 CPUtime=0.02
/proc/25582/stat : 25582 (p2cudf) S 25581 25581 4778 34817 4778 4202496 388 3013 0 1 0 0 0 2 25 0 1 0 11202605 2629632 279 1283457024 134512640 135304128 4292788192 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25582/statm: 642 279 239 194 0 29 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5140

[startup+0.304456 s]
/proc/loadavg: 1.44 1.40 1.29 5/38 25584
/proc/meminfo: memFree=259216/1048576 swapFree=0/0
[pid=25581] ppid=25580 vsize=2572 CPUtime=0
/proc/25581/stat : 25581 (p2cudf-paranoid) S 25580 25581 4778 34817 4778 4202496 375 0 0 0 0 0 0 0 18 0 1 0 11202604 2633728 271 1283457024 134512640 135304128 4291548832 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25581/statm: 643 271 230 194 0 30 0
[pid=25582] ppid=25581 vsize=2568 CPUtime=0.02
/proc/25582/stat : 25582 (p2cudf) S 25581 25581 4778 34817 4778 4202496 388 3013 0 1 0 0 0 2 25 0 1 0 11202605 2629632 279 1283457024 134512640 135304128 4292788192 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25582/statm: 642 279 239 194 0 29 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5140

[startup+0.704549 s]
/proc/loadavg: 1.44 1.40 1.29 5/38 25584
/proc/meminfo: memFree=259216/1048576 swapFree=0/0
[pid=25581] ppid=25580 vsize=2572 CPUtime=0
/proc/25581/stat : 25581 (p2cudf-paranoid) S 25580 25581 4778 34817 4778 4202496 375 0 0 0 0 0 0 0 18 0 1 0 11202604 2633728 271 1283457024 134512640 135304128 4291548832 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25581/statm: 643 271 230 194 0 30 0
[pid=25582] ppid=25581 vsize=2568 CPUtime=0.02
/proc/25582/stat : 25582 (p2cudf) S 25581 25581 4778 34817 4778 4202496 388 3013 0 1 0 0 0 2 25 0 1 0 11202605 2629632 279 1283457024 134512640 135304128 4292788192 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25582/statm: 642 279 239 194 0 29 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5140

[startup+1.50475 s]
/proc/loadavg: 1.56 1.43 1.30 3/47 25604
/proc/meminfo: memFree=206876/1048576 swapFree=0/0
[pid=25581] ppid=25580 vsize=2572 CPUtime=0
/proc/25581/stat : 25581 (p2cudf-paranoid) S 25580 25581 4778 34817 4778 4202496 375 0 0 0 0 0 0 0 18 0 1 0 11202604 2633728 271 1283457024 134512640 135304128 4291548832 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25581/statm: 643 271 230 194 0 30 0
[pid=25582] ppid=25581 vsize=2568 CPUtime=0.02
/proc/25582/stat : 25582 (p2cudf) S 25581 25581 4778 34817 4778 4202496 388 3013 0 1 0 0 0 2 25 0 1 0 11202605 2629632 279 1283457024 134512640 135304128 4292788192 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25582/statm: 642 279 239 194 0 29 0
[pid=25595] ppid=25582 vsize=885168 CPUtime=1.47
/proc/25595/stat : 25595 (java) S 25582 25581 4778 34817 4778 4202496 22196 0 1 0 139 8 0 0 25 0 10 0 11202608 906412032 18690 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/25595/statm: 221292 18690 1721 10 0 218383 0
[pid=25595/tid=25596] ppid=25582 vsize=885168 CPUtime=0.79
/proc/25595/task/25596/stat : 25596 (java) R 25582 25581 4778 34817 4778 4202560 10568 0 1 0 73 6 0 0 25 0 10 0 11202609 906412032 18690 1283457024 134512640 134550932 4292140512 18446744073709551615 4095594276 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=25595/tid=25597] ppid=25582 vsize=885168 CPUtime=0
/proc/25595/task/25597/stat : 25597 (java) S 25582 25581 4778 34817 4778 4202560 6 0 0 0 0 0 0 0 18 0 10 0 11202610 906412032 18690 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 0 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25598] ppid=25582 vsize=885168 CPUtime=0
/proc/25595/task/25598/stat : 25598 (java) S 25582 25581 4778 34817 4778 4202560 9 0 0 0 0 0 0 0 25 0 10 0 11202611 906412032 18690 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25599] ppid=25582 vsize=885168 CPUtime=0
/proc/25595/task/25599/stat : 25599 (java) S 25582 25581 4778 34817 4778 4202560 4 0 0 0 0 0 0 0 25 0 10 0 11202611 906412032 18690 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25600] ppid=25582 vsize=885168 CPUtime=0
/proc/25595/task/25600/stat : 25600 (java) S 25582 25581 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 10 0 11202613 906412032 18690 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25601] ppid=25582 vsize=885168 CPUtime=0.45
/proc/25595/task/25601/stat : 25601 (java) R 25582 25581 4778 34817 4778 4202560 8424 0 0 0 44 1 0 0 25 0 10 0 11202613 906412032 18690 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=25595/tid=25602] ppid=25582 vsize=885168 CPUtime=0.22
/proc/25595/task/25602/stat : 25602 (java) R 25582 25581 4778 34817 4778 4202560 2124 0 0 0 22 0 0 0 18 0 10 0 11202613 906412032 18690 1283457024 134512640 134550932 4292140512 18446744073709551615 4152512679 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=25595/tid=25603] ppid=25582 vsize=885168 CPUtime=0
/proc/25595/task/25603/stat : 25603 (java) S 25582 25581 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 10 0 11202613 906412032 18690 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25604] ppid=25582 vsize=885168 CPUtime=0
/proc/25595/task/25604/stat : 25604 (java) S 25582 25581 4778 34817 4778 4202560 2 0 0 0 0 0 0 0 15 0 10 0 11202613 906412032 18690 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.49
Current children cumulated vsize (KiB) 890308

[startup+3.1081 s]
/proc/loadavg: 1.56 1.43 1.30 2/47 25604
/proc/meminfo: memFree=117720/1048576 swapFree=0/0
[pid=25581] ppid=25580 vsize=2572 CPUtime=0
/proc/25581/stat : 25581 (p2cudf-paranoid) S 25580 25581 4778 34817 4778 4202496 375 0 0 0 0 0 0 0 18 0 1 0 11202604 2633728 271 1283457024 134512640 135304128 4291548832 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25581/statm: 643 271 230 194 0 30 0
[pid=25582] ppid=25581 vsize=2568 CPUtime=0.02
/proc/25582/stat : 25582 (p2cudf) S 25581 25581 4778 34817 4778 4202496 388 3013 0 1 0 0 0 2 25 0 1 0 11202605 2629632 279 1283457024 134512640 135304128 4292788192 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25582/statm: 642 279 239 194 0 29 0
[pid=25595] ppid=25582 vsize=881848 CPUtime=3.06
/proc/25595/stat : 25595 (java) S 25582 25581 4778 34817 4778 4202496 75470 0 1 0 280 26 0 0 25 0 10 0 11202608 903012352 71359 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/25595/statm: 220462 71359 1743 10 0 217553 0
[pid=25595/tid=25596] ppid=25582 vsize=881848 CPUtime=1.67
/proc/25595/task/25596/stat : 25596 (java) R 25582 25581 4778 34817 4778 4202560 50087 0 1 0 147 20 0 0 25 0 10 0 11202609 903012352 71359 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=25595/tid=25597] ppid=25582 vsize=881848 CPUtime=0.3
/proc/25595/task/25597/stat : 25597 (java) S 25582 25581 4778 34817 4778 4202560 13487 0 0 0 26 4 0 0 16 0 10 0 11202610 903012352 71359 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 0 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25598] ppid=25582 vsize=881848 CPUtime=0
/proc/25595/task/25598/stat : 25598 (java) S 25582 25581 4778 34817 4778 4202560 10 0 0 0 0 0 0 0 18 0 10 0 11202611 903012352 71359 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25599] ppid=25582 vsize=881848 CPUtime=0
/proc/25595/task/25599/stat : 25599 (java) S 25582 25581 4778 34817 4778 4202560 6 0 0 0 0 0 0 0 18 0 10 0 11202611 903012352 71359 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25600] ppid=25582 vsize=881848 CPUtime=0
/proc/25595/task/25600/stat : 25600 (java) S 25582 25581 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 10 0 11202613 903012352 71359 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25601] ppid=25582 vsize=881848 CPUtime=0.55
/proc/25595/task/25601/stat : 25601 (java) R 25582 25581 4778 34817 4778 4202560 8474 0 0 0 54 1 0 0 20 0 10 0 11202613 903012352 71359 1283457024 134512640 134550932 4292140512 18446744073709551615 4149984212 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=25595/tid=25602] ppid=25582 vsize=881848 CPUtime=0.51
/proc/25595/task/25602/stat : 25602 (java) S 25582 25581 4778 34817 4778 4202560 2345 0 0 0 51 0 0 0 15 0 10 0 11202613 903012352 71359 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25603] ppid=25582 vsize=881848 CPUtime=0
/proc/25595/task/25603/stat : 25603 (java) S 25582 25581 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 10 0 11202613 903012352 71359 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25604] ppid=25582 vsize=881848 CPUtime=0
/proc/25595/task/25604/stat : 25604 (java) S 25582 25581 4778 34817 4778 4202560 2 0 0 0 0 0 0 0 15 0 10 0 11202613 903012352 71359 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.08
Current children cumulated vsize (KiB) 886988

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

[startup+3.20966 s]
/proc/loadavg: 1.56 1.43 1.30 2/47 25604
/proc/meminfo: memFree=117720/1048576 swapFree=0/0
[pid=25581] ppid=25580 vsize=2572 CPUtime=0
/proc/25581/stat : 25581 (p2cudf-paranoid) S 25580 25581 4778 34817 4778 4202496 375 0 0 0 0 0 0 0 18 0 1 0 11202604 2633728 271 1283457024 134512640 135304128 4291548832 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25581/statm: 643 271 230 194 0 30 0
[pid=25582] ppid=25581 vsize=2568 CPUtime=0.02
/proc/25582/stat : 25582 (p2cudf) S 25581 25581 4778 34817 4778 4202496 388 3013 0 1 0 0 0 2 25 0 1 0 11202605 2629632 279 1283457024 134512640 135304128 4292788192 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25582/statm: 642 279 239 194 0 29 0
[pid=25595] ppid=25582 vsize=881848 CPUtime=3.16
/proc/25595/stat : 25595 (java) S 25582 25581 4778 34817 4778 4202496 75477 0 1 0 290 26 0 0 25 0 10 0 11202608 903012352 71366 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/25595/statm: 220462 71366 1743 10 0 217553 0
[pid=25595/tid=25596] ppid=25582 vsize=881848 CPUtime=1.68
/proc/25595/task/25596/stat : 25596 (java) R 25582 25581 4778 34817 4778 4202560 50087 0 1 0 148 20 0 0 25 0 10 0 11202609 903012352 71366 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=25595/tid=25597] ppid=25582 vsize=881848 CPUtime=0.3
/proc/25595/task/25597/stat : 25597 (java) S 25582 25581 4778 34817 4778 4202560 13487 0 0 0 26 4 0 0 16 0 10 0 11202610 903012352 71366 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 0 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25598] ppid=25582 vsize=881848 CPUtime=0
/proc/25595/task/25598/stat : 25598 (java) S 25582 25581 4778 34817 4778 4202560 10 0 0 0 0 0 0 0 18 0 10 0 11202611 903012352 71366 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25599] ppid=25582 vsize=881848 CPUtime=0
/proc/25595/task/25599/stat : 25599 (java) S 25582 25581 4778 34817 4778 4202560 6 0 0 0 0 0 0 0 18 0 10 0 11202611 903012352 71366 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25600] ppid=25582 vsize=881848 CPUtime=0
/proc/25595/task/25600/stat : 25600 (java) S 25582 25581 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 10 0 11202613 903012352 71366 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25601] ppid=25582 vsize=881848 CPUtime=0.55
/proc/25595/task/25601/stat : 25601 (java) R 25582 25581 4778 34817 4778 4202560 8474 0 0 0 54 1 0 0 20 0 10 0 11202613 903012352 71366 1283457024 134512640 134550932 4292140512 18446744073709551615 4149984212 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=25595/tid=25602] ppid=25582 vsize=881848 CPUtime=0.6
/proc/25595/task/25602/stat : 25602 (java) S 25582 25581 4778 34817 4778 4202560 2352 0 0 0 60 0 0 0 15 0 10 0 11202613 903012352 71366 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25603] ppid=25582 vsize=881848 CPUtime=0
/proc/25595/task/25603/stat : 25603 (java) S 25582 25581 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 10 0 11202613 903012352 71366 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25604] ppid=25582 vsize=881848 CPUtime=0
/proc/25595/task/25604/stat : 25604 (java) S 25582 25581 4778 34817 4778 4202560 2 0 0 0 0 0 0 0 15 0 10 0 11202613 903012352 71366 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.18
Current children cumulated vsize (KiB) 886988

[startup+4.00543 s]
/proc/loadavg: 1.56 1.43 1.30 3/47 25605
/proc/meminfo: memFree=5380/1048576 swapFree=0/0
[pid=25581] ppid=25580 vsize=2572 CPUtime=0
/proc/25581/stat : 25581 (p2cudf-paranoid) S 25580 25581 4778 34817 4778 4202496 375 0 0 0 0 0 0 0 18 0 1 0 11202604 2633728 271 1283457024 134512640 135304128 4291548832 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25581/statm: 643 271 230 194 0 30 0
[pid=25582] ppid=25581 vsize=2568 CPUtime=0.02
/proc/25582/stat : 25582 (p2cudf) S 25581 25581 4778 34817 4778 4202496 388 3013 0 1 0 0 0 2 25 0 1 0 11202605 2629632 279 1283457024 134512640 135304128 4292788192 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25582/statm: 642 279 239 194 0 29 0
[pid=25595] ppid=25582 vsize=881740 CPUtime=3.96
/proc/25595/stat : 25595 (java) S 25582 25581 4778 34817 4778 4202496 77336 0 1 0 368 28 0 0 25 0 10 0 11202608 902901760 71613 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/25595/statm: 220435 71613 1752 10 0 217526 0
[pid=25595/tid=25596] ppid=25582 vsize=881740 CPUtime=1.93
/proc/25595/task/25596/stat : 25596 (java) R 25582 25581 4778 34817 4778 4202560 50224 0 1 0 171 22 0 0 25 0 10 0 11202609 902901760 71613 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=25595/tid=25597] ppid=25582 vsize=881740 CPUtime=0.3
/proc/25595/task/25597/stat : 25597 (java) S 25582 25581 4778 34817 4778 4202560 13487 0 0 0 26 4 0 0 16 0 10 0 11202610 902901760 71613 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 0 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25598] ppid=25582 vsize=881740 CPUtime=0
/proc/25595/task/25598/stat : 25598 (java) S 25582 25581 4778 34817 4778 4202560 10 0 0 0 0 0 0 0 18 0 10 0 11202611 902901760 71613 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25599] ppid=25582 vsize=881740 CPUtime=0
/proc/25595/task/25599/stat : 25599 (java) S 25582 25581 4778 34817 4778 4202560 6 0 0 0 0 0 0 0 18 0 10 0 11202611 902901760 71613 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25600] ppid=25582 vsize=881740 CPUtime=0
/proc/25595/task/25600/stat : 25600 (java) S 25582 25581 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 10 0 11202613 902901760 71613 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25601] ppid=25582 vsize=881740 CPUtime=0.69
/proc/25595/task/25601/stat : 25601 (java) R 25582 25581 4778 34817 4778 4202560 8494 0 0 0 68 1 0 0 19 0 10 0 11202613 902901760 71613 1283457024 134512640 134550932 4292140512 18446744073709551615 4149823440 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=25595/tid=25602] ppid=25582 vsize=881740 CPUtime=1.01
/proc/25595/task/25602/stat : 25602 (java) S 25582 25581 4778 34817 4778 4202560 4054 0 0 0 101 0 0 0 16 0 10 0 11202613 902901760 71613 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25603] ppid=25582 vsize=881740 CPUtime=0
/proc/25595/task/25603/stat : 25603 (java) S 25582 25581 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 10 0 11202613 902901760 71613 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25604] ppid=25582 vsize=881740 CPUtime=0
/proc/25595/task/25604/stat : 25604 (java) S 25582 25581 4778 34817 4778 4202560 2 0 0 0 0 0 0 0 15 0 10 0 11202613 902901760 71613 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.98
Current children cumulated vsize (KiB) 886880

[startup+4.80445 s]
/proc/loadavg: 1.56 1.43 1.30 4/48 25606
/proc/meminfo: memFree=6536/1048576 swapFree=0/0
[pid=25581] ppid=25580 vsize=2572 CPUtime=0
/proc/25581/stat : 25581 (p2cudf-paranoid) S 25580 25581 4778 34817 4778 4202496 375 0 0 0 0 0 0 0 18 0 1 0 11202604 2633728 271 1283457024 134512640 135304128 4291548832 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25581/statm: 643 271 230 194 0 30 0
[pid=25582] ppid=25581 vsize=2568 CPUtime=0.02
/proc/25582/stat : 25582 (p2cudf) S 25581 25581 4778 34817 4778 4202496 388 3013 0 1 0 0 0 2 25 0 1 0 11202605 2629632 279 1283457024 134512640 135304128 4292788192 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25582/statm: 642 279 239 194 0 29 0
[pid=25595] ppid=25582 vsize=882388 CPUtime=4.58
/proc/25595/stat : 25595 (java) S 25582 25581 4778 34817 4778 4202496 77448 0 1 0 428 30 0 0 25 0 11 0 11202608 903565312 71725 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/25595/statm: 220597 71725 1763 10 0 217688 0
[pid=25595/tid=25596] ppid=25582 vsize=882388 CPUtime=2.2
/proc/25595/task/25596/stat : 25596 (java) S 25582 25581 4778 34817 4778 4202560 50281 0 1 0 196 24 0 0 25 0 11 0 11202609 903565312 71725 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25597] ppid=25582 vsize=882388 CPUtime=0.3
/proc/25595/task/25597/stat : 25597 (java) S 25582 25581 4778 34817 4778 4202560 13487 0 0 0 26 4 0 0 16 0 11 0 11202610 903565312 71725 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 0 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25598] ppid=25582 vsize=882388 CPUtime=0
/proc/25595/task/25598/stat : 25598 (java) S 25582 25581 4778 34817 4778 4202560 10 0 0 0 0 0 0 0 18 0 11 0 11202611 903565312 71725 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25599] ppid=25582 vsize=882388 CPUtime=0
/proc/25595/task/25599/stat : 25599 (java) S 25582 25581 4778 34817 4778 4202560 6 0 0 0 0 0 0 0 18 0 11 0 11202611 903565312 71725 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25600] ppid=25582 vsize=882388 CPUtime=0
/proc/25595/task/25600/stat : 25600 (java) S 25582 25581 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 11 0 11202613 903565312 71725 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25601] ppid=25582 vsize=882388 CPUtime=1.05
/proc/25595/task/25601/stat : 25601 (java) S 25582 25581 4778 34817 4778 4202560 8540 0 0 0 104 1 0 0 17 0 11 0 11202613 903565312 71725 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25602] ppid=25582 vsize=882388 CPUtime=1.01
/proc/25595/task/25602/stat : 25602 (java) S 25582 25581 4778 34817 4778 4202560 4054 0 0 0 101 0 0 0 16 0 11 0 11202613 903565312 71725 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25603] ppid=25582 vsize=882388 CPUtime=0
/proc/25595/task/25603/stat : 25603 (java) S 25582 25581 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 11 0 11202613 903565312 71725 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25604] ppid=25582 vsize=882388 CPUtime=0
/proc/25595/task/25604/stat : 25604 (java) S 25582 25581 4778 34817 4778 4202560 2 0 0 0 0 0 0 0 15 0 11 0 11202613 903565312 71725 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.6
Current children cumulated vsize (KiB) 887528

[startup+5.2123 s]
/proc/loadavg: 1.56 1.43 1.30 4/48 25606
/proc/meminfo: memFree=6536/1048576 swapFree=0/0
[pid=25581] ppid=25580 vsize=2572 CPUtime=0
/proc/25581/stat : 25581 (p2cudf-paranoid) S 25580 25581 4778 34817 4778 4202496 375 0 0 0 0 0 0 0 18 0 1 0 11202604 2633728 271 1283457024 134512640 135304128 4291548832 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25581/statm: 643 271 230 194 0 30 0
[pid=25582] ppid=25581 vsize=2568 CPUtime=0.02
/proc/25582/stat : 25582 (p2cudf) S 25581 25581 4778 34817 4778 4202496 388 3013 0 1 0 0 0 2 25 0 1 0 11202605 2629632 279 1283457024 134512640 135304128 4292788192 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25582/statm: 642 279 239 194 0 29 0
[pid=25595] ppid=25582 vsize=882388 CPUtime=4.66
/proc/25595/stat : 25595 (java) S 25582 25581 4778 34817 4778 4202496 77455 0 1 0 435 31 0 0 25 0 11 0 11202608 903565312 71732 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/25595/statm: 220597 71732 1764 10 0 217688 0
[pid=25595/tid=25596] ppid=25582 vsize=882388 CPUtime=2.2
/proc/25595/task/25596/stat : 25596 (java) S 25582 25581 4778 34817 4778 4202560 50281 0 1 0 196 24 0 0 25 0 11 0 11202609 903565312 71732 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25597] ppid=25582 vsize=882388 CPUtime=0.3
/proc/25595/task/25597/stat : 25597 (java) S 25582 25581 4778 34817 4778 4202560 13487 0 0 0 26 4 0 0 16 0 11 0 11202610 903565312 71732 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 0 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25598] ppid=25582 vsize=882388 CPUtime=0
/proc/25595/task/25598/stat : 25598 (java) S 25582 25581 4778 34817 4778 4202560 10 0 0 0 0 0 0 0 18 0 11 0 11202611 903565312 71732 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25599] ppid=25582 vsize=882388 CPUtime=0
/proc/25595/task/25599/stat : 25599 (java) S 25582 25581 4778 34817 4778 4202560 6 0 0 0 0 0 0 0 18 0 11 0 11202611 903565312 71732 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25600] ppid=25582 vsize=882388 CPUtime=0
/proc/25595/task/25600/stat : 25600 (java) S 25582 25581 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 11 0 11202613 903565312 71732 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25601] ppid=25582 vsize=882388 CPUtime=1.08
/proc/25595/task/25601/stat : 25601 (java) S 25582 25581 4778 34817 4778 4202560 8545 0 0 0 107 1 0 0 15 0 11 0 11202613 903565312 71732 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25602] ppid=25582 vsize=882388 CPUtime=1.01
/proc/25595/task/25602/stat : 25602 (java) S 25582 25581 4778 34817 4778 4202560 4054 0 0 0 101 0 0 0 16 0 11 0 11202613 903565312 71732 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25603] ppid=25582 vsize=882388 CPUtime=0
/proc/25595/task/25603/stat : 25603 (java) S 25582 25581 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 11 0 11202613 903565312 71732 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25595/tid=25604] ppid=25582 vsize=882388 CPUtime=0
/proc/25595/task/25604/stat : 25604 (java) S 25582 25581 4778 34817 4778 4202560 2 0 0 0 0 0 0 0 15 0 11 0 11202613 903565312 71732 1283457024 134512640 134550932 4292140512 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.68
Current children cumulated vsize (KiB) 887528

Child status: 0
Real time (s): 5.29575
CPU time (s): 4.73629
CPU user time (s): 4.37627
CPU system time (s): 0.360022
CPU usage (%): 89.4357
Max. virtual memory (cumulated for all children) (KiB): 891164

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 4.37627
system time used= 0.360022
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 81258
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= 634
involuntary context switches= 659

runsolver used 0 second user time and 0.012 second system time

The end