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/201103031013/p2cudf-paranoid-1.12/597.cudf.caixa.log.runsolver ./p2cudf-paranoid-1.12 /home/misc2010/data/misc4/caixa//597.cudf /home/misc2010/tmp/201103031013/p2cudf-paranoid-1.12/597.cudf.caixa.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: 2.20 1.85 1.71 5/36 23466
/proc/meminfo: memFree=299440/1048576 swapFree=0/0
[pid=23463] ppid=23462 vsize=2568 CPUtime=0
/proc/23463/stat : 23463 (p2cudf-paranoid) S 23462 23463 29493 34817 29493 4202496 376 0 0 0 0 0 0 0 18 0 1 0 76310440 2629632 271 1283457024 134512640 135304128 4289783104 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23463/statm: 642 271 230 194 0 29 0
[pid=23464] ppid=23463 vsize=2572 CPUtime=0
/proc/23464/stat : 23464 (p2cudf) S 23463 23463 29493 34817 29493 4202496 354 0 0 0 0 0 0 0 18 0 1 0 76310441 2633728 272 1283457024 134512640 135304128 4288222160 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0
/proc/23464/statm: 643 272 231 194 0 30 0
[pid=23465] ppid=23464 vsize=2572 CPUtime=0
/proc/23465/stat : 23465 (p2cudf) R 23464 23463 29493 34817 29493 4202560 93 0 0 0 0 0 0 0 25 0 1 0 76310441 2633728 119 1283457024 134512640 135304128 4288222160 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/23465/statm: 643 119 77 194 0 30 0
[pid=23466] ppid=23465 vsize=2572 CPUtime=0
/proc/23466/stat : 23466 (p2cudf) R 23465 23463 29493 34817 29493 4202560 0 0 0 0 0 0 0 0 25 0 1 0 76310441 2633728 42 1283457024 134512640 135304128 4288222160 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/23466/statm: 643 42 0 194 0 30 0

[startup+0.125772 s]
/proc/loadavg: 2.20 1.85 1.71 5/36 23466
/proc/meminfo: memFree=299440/1048576 swapFree=0/0
[pid=23463] ppid=23462 vsize=2568 CPUtime=0
/proc/23463/stat : 23463 (p2cudf-paranoid) S 23462 23463 29493 34817 29493 4202496 376 0 0 0 0 0 0 0 18 0 1 0 76310440 2629632 271 1283457024 134512640 135304128 4289783104 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23463/statm: 642 271 230 194 0 29 0
[pid=23464] ppid=23463 vsize=2580 CPUtime=0.03
/proc/23464/stat : 23464 (p2cudf) S 23463 23463 29493 34817 29493 4202496 396 3013 0 1 0 0 2 1 25 0 1 0 76310441 2641920 282 1283457024 134512640 135304128 4288222160 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23464/statm: 645 282 239 194 0 32 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5148

[startup+0.205778 s]
/proc/loadavg: 2.20 1.85 1.71 5/36 23466
/proc/meminfo: memFree=299440/1048576 swapFree=0/0
[pid=23463] ppid=23462 vsize=2568 CPUtime=0
/proc/23463/stat : 23463 (p2cudf-paranoid) S 23462 23463 29493 34817 29493 4202496 376 0 0 0 0 0 0 0 18 0 1 0 76310440 2629632 271 1283457024 134512640 135304128 4289783104 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23463/statm: 642 271 230 194 0 29 0
[pid=23464] ppid=23463 vsize=2580 CPUtime=0.03
/proc/23464/stat : 23464 (p2cudf) S 23463 23463 29493 34817 29493 4202496 396 3013 0 1 0 0 2 1 25 0 1 0 76310441 2641920 282 1283457024 134512640 135304128 4288222160 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23464/statm: 645 282 239 194 0 32 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5148

[startup+0.305799 s]
/proc/loadavg: 2.20 1.85 1.71 5/36 23466
/proc/meminfo: memFree=299440/1048576 swapFree=0/0
[pid=23463] ppid=23462 vsize=2568 CPUtime=0
/proc/23463/stat : 23463 (p2cudf-paranoid) S 23462 23463 29493 34817 29493 4202496 376 0 0 0 0 0 0 0 18 0 1 0 76310440 2629632 271 1283457024 134512640 135304128 4289783104 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23463/statm: 642 271 230 194 0 29 0
[pid=23464] ppid=23463 vsize=2580 CPUtime=0.03
/proc/23464/stat : 23464 (p2cudf) S 23463 23463 29493 34817 29493 4202496 396 3013 0 1 0 0 2 1 25 0 1 0 76310441 2641920 282 1283457024 134512640 135304128 4288222160 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23464/statm: 645 282 239 194 0 32 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5148

[startup+0.705894 s]
/proc/loadavg: 2.20 1.85 1.71 5/36 23466
/proc/meminfo: memFree=299440/1048576 swapFree=0/0
[pid=23463] ppid=23462 vsize=2568 CPUtime=0
/proc/23463/stat : 23463 (p2cudf-paranoid) S 23462 23463 29493 34817 29493 4202496 376 0 0 0 0 0 0 0 18 0 1 0 76310440 2629632 271 1283457024 134512640 135304128 4289783104 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23463/statm: 642 271 230 194 0 29 0
[pid=23464] ppid=23463 vsize=2580 CPUtime=0.03
/proc/23464/stat : 23464 (p2cudf) S 23463 23463 29493 34817 29493 4202496 396 3013 0 1 0 0 2 1 25 0 1 0 76310441 2641920 282 1283457024 134512640 135304128 4288222160 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23464/statm: 645 282 239 194 0 32 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5148

[startup+1.50609 s]
/proc/loadavg: 2.20 1.85 1.71 5/45 23486
/proc/meminfo: memFree=255284/1048576 swapFree=0/0
[pid=23463] ppid=23462 vsize=2568 CPUtime=0
/proc/23463/stat : 23463 (p2cudf-paranoid) S 23462 23463 29493 34817 29493 4202496 376 0 0 0 0 0 0 0 18 0 1 0 76310440 2629632 271 1283457024 134512640 135304128 4289783104 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23463/statm: 642 271 230 194 0 29 0
[pid=23464] ppid=23463 vsize=2580 CPUtime=0.03
/proc/23464/stat : 23464 (p2cudf) S 23463 23463 29493 34817 29493 4202496 396 3013 0 1 0 0 2 1 25 0 1 0 76310441 2641920 282 1283457024 134512640 135304128 4288222160 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23464/statm: 645 282 239 194 0 32 0
[pid=23477] ppid=23464 vsize=887328 CPUtime=1.46
/proc/23477/stat : 23477 (java) S 23464 23463 29493 34817 29493 4202496 18989 0 1 0 137 9 0 0 25 0 10 0 76310444 908623872 14721 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/23477/statm: 221832 14721 1725 10 0 218923 0
[pid=23477/tid=23478] ppid=23464 vsize=887328 CPUtime=0.62
/proc/23477/task/23478/stat : 23478 (java) R 23464 23463 29493 34817 29493 4202560 5902 0 1 0 58 4 0 0 25 0 10 0 76310445 908623872 14721 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=23477/tid=23479] ppid=23464 vsize=887328 CPUtime=0
/proc/23477/task/23479/stat : 23479 (java) S 23464 23463 29493 34817 29493 4202560 7 0 0 0 0 0 0 0 16 0 10 0 76310446 908623872 14721 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 0 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23480] ppid=23464 vsize=887328 CPUtime=0
/proc/23477/task/23480/stat : 23480 (java) S 23464 23463 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 25 0 10 0 76310447 908623872 14721 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23481] ppid=23464 vsize=887328 CPUtime=0
/proc/23477/task/23481/stat : 23481 (java) S 23464 23463 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 25 0 10 0 76310447 908623872 14721 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23482] ppid=23464 vsize=887328 CPUtime=0
/proc/23477/task/23482/stat : 23482 (java) S 23464 23463 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76310449 908623872 14721 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23483] ppid=23464 vsize=887328 CPUtime=0.55
/proc/23477/task/23483/stat : 23483 (java) R 23464 23463 29493 34817 29493 4202560 9040 0 0 0 52 3 0 0 21 0 10 0 76310449 908623872 14721 1283457024 134512640 134550932 4287740416 18446744073709551615 4150335092 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=23477/tid=23484] ppid=23464 vsize=887328 CPUtime=0.28
/proc/23477/task/23484/stat : 23484 (java) R 23464 23463 29493 34817 29493 4202560 2967 0 0 0 26 2 0 0 25 0 10 0 76310449 908623872 14721 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=23477/tid=23485] ppid=23464 vsize=887328 CPUtime=0
/proc/23477/task/23485/stat : 23485 (java) S 23464 23463 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76310449 908623872 14721 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23486] ppid=23464 vsize=887328 CPUtime=0
/proc/23477/task/23486/stat : 23486 (java) S 23464 23463 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 10 0 76310449 908623872 14721 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.49
Current children cumulated vsize (KiB) 892476

[startup+3.10649 s]
/proc/loadavg: 2.20 1.85 1.71 3/45 23486
/proc/meminfo: memFree=165880/1048576 swapFree=0/0
[pid=23463] ppid=23462 vsize=2568 CPUtime=0
/proc/23463/stat : 23463 (p2cudf-paranoid) S 23462 23463 29493 34817 29493 4202496 376 0 0 0 0 0 0 0 18 0 1 0 76310440 2629632 271 1283457024 134512640 135304128 4289783104 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23463/statm: 642 271 230 194 0 29 0
[pid=23464] ppid=23463 vsize=2580 CPUtime=0.03
/proc/23464/stat : 23464 (p2cudf) S 23463 23463 29493 34817 29493 4202496 396 3013 0 1 0 0 2 1 25 0 1 0 76310441 2641920 282 1283457024 134512640 135304128 4288222160 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23464/statm: 645 282 239 194 0 32 0
[pid=23477] ppid=23464 vsize=887640 CPUtime=3.06
/proc/23477/stat : 23477 (java) S 23464 23463 29493 34817 29493 4202496 63843 0 1 0 288 18 0 0 25 0 10 0 76310444 908943360 58752 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/23477/statm: 221910 58752 1743 10 0 219001 0
[pid=23477/tid=23478] ppid=23464 vsize=887640 CPUtime=1.59
/proc/23477/task/23478/stat : 23478 (java) R 23464 23463 29493 34817 29493 4202560 49571 0 1 0 147 12 0 0 25 0 10 0 76310445 908943360 58752 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=23477/tid=23479] ppid=23464 vsize=887640 CPUtime=0
/proc/23477/task/23479/stat : 23479 (java) S 23464 23463 29493 34817 29493 4202560 7 0 0 0 0 0 0 0 16 0 10 0 76310446 908943360 58752 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 0 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23480] ppid=23464 vsize=887640 CPUtime=0
/proc/23477/task/23480/stat : 23480 (java) S 23464 23463 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 25 0 10 0 76310447 908943360 58752 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23481] ppid=23464 vsize=887640 CPUtime=0
/proc/23477/task/23481/stat : 23481 (java) S 23464 23463 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 25 0 10 0 76310447 908943360 58752 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23482] ppid=23464 vsize=887640 CPUtime=0
/proc/23477/task/23482/stat : 23482 (java) S 23464 23463 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76310449 908943360 58752 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23483] ppid=23464 vsize=887640 CPUtime=0.62
/proc/23477/task/23483/stat : 23483 (java) S 23464 23463 29493 34817 29493 4202560 9047 0 0 0 59 3 0 0 16 0 10 0 76310449 908943360 58752 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23484] ppid=23464 vsize=887640 CPUtime=0.83
/proc/23477/task/23484/stat : 23484 (java) R 23464 23463 29493 34817 29493 4202560 4145 0 0 0 81 2 0 0 24 0 10 0 76310449 908943360 58752 1283457024 134512640 134550932 4287740416 18446744073709551615 4150099618 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=23477/tid=23485] ppid=23464 vsize=887640 CPUtime=0
/proc/23477/task/23485/stat : 23485 (java) S 23464 23463 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76310449 908943360 58752 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23486] ppid=23464 vsize=887640 CPUtime=0
/proc/23477/task/23486/stat : 23486 (java) S 23464 23463 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 10 0 76310449 908943360 58752 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.09
Current children cumulated vsize (KiB) 892788

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

[startup+3.2265 s]
/proc/loadavg: 2.20 1.85 1.71 3/45 23486
/proc/meminfo: memFree=165880/1048576 swapFree=0/0
[pid=23463] ppid=23462 vsize=2568 CPUtime=0
/proc/23463/stat : 23463 (p2cudf-paranoid) S 23462 23463 29493 34817 29493 4202496 376 0 0 0 0 0 0 0 18 0 1 0 76310440 2629632 271 1283457024 134512640 135304128 4289783104 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23463/statm: 642 271 230 194 0 29 0
[pid=23464] ppid=23463 vsize=2580 CPUtime=0.03
/proc/23464/stat : 23464 (p2cudf) S 23463 23463 29493 34817 29493 4202496 396 3013 0 1 0 0 2 1 25 0 1 0 76310441 2641920 282 1283457024 134512640 135304128 4288222160 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23464/statm: 645 282 239 194 0 32 0
[pid=23477] ppid=23464 vsize=887640 CPUtime=3.18
/proc/23477/stat : 23477 (java) S 23464 23463 29493 34817 29493 4202496 67801 0 1 0 299 19 0 0 25 0 10 0 76310444 908943360 62710 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/23477/statm: 221910 62710 1746 10 0 219001 0
[pid=23477/tid=23478] ppid=23464 vsize=887640 CPUtime=1.62
/proc/23477/task/23478/stat : 23478 (java) R 23464 23463 29493 34817 29493 4202560 50160 0 1 0 150 12 0 0 25 0 10 0 76310445 908943360 62710 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=23477/tid=23479] ppid=23464 vsize=887640 CPUtime=0.06
/proc/23477/task/23479/stat : 23479 (java) R 23464 23463 29493 34817 29493 4202560 3375 0 0 0 5 1 0 0 15 0 10 0 76310446 908943360 62710 1283457024 134512640 134550932 4287740416 18446744073709551615 4149584248 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=23477/tid=23480] ppid=23464 vsize=887640 CPUtime=0
/proc/23477/task/23480/stat : 23480 (java) S 23464 23463 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 25 0 10 0 76310447 908943360 62710 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23481] ppid=23464 vsize=887640 CPUtime=0
/proc/23477/task/23481/stat : 23481 (java) S 23464 23463 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 25 0 10 0 76310447 908943360 62710 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23482] ppid=23464 vsize=887640 CPUtime=0
/proc/23477/task/23482/stat : 23482 (java) S 23464 23463 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76310449 908943360 62710 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23483] ppid=23464 vsize=887640 CPUtime=0.62
/proc/23477/task/23483/stat : 23483 (java) S 23464 23463 29493 34817 29493 4202560 9047 0 0 0 59 3 0 0 16 0 10 0 76310449 908943360 62710 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23484] ppid=23464 vsize=887640 CPUtime=0.86
/proc/23477/task/23484/stat : 23484 (java) S 23464 23463 29493 34817 29493 4202560 4146 0 0 0 84 2 0 0 24 0 10 0 76310449 908943360 62710 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23485] ppid=23464 vsize=887640 CPUtime=0
/proc/23477/task/23485/stat : 23485 (java) S 23464 23463 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76310449 908943360 62710 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23486] ppid=23464 vsize=887640 CPUtime=0
/proc/23477/task/23486/stat : 23486 (java) S 23464 23463 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 10 0 76310449 908943360 62710 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.21
Current children cumulated vsize (KiB) 892788

[startup+4.01524 s]
/proc/loadavg: 2.18 1.85 1.71 3/45 23486
/proc/meminfo: memFree=34812/1048576 swapFree=0/0
[pid=23463] ppid=23462 vsize=2568 CPUtime=0
/proc/23463/stat : 23463 (p2cudf-paranoid) S 23462 23463 29493 34817 29493 4202496 376 0 0 0 0 0 0 0 18 0 1 0 76310440 2629632 271 1283457024 134512640 135304128 4289783104 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23463/statm: 642 271 230 194 0 29 0
[pid=23464] ppid=23463 vsize=2580 CPUtime=0.03
/proc/23464/stat : 23464 (p2cudf) S 23463 23463 29493 34817 29493 4202496 396 3013 0 1 0 0 2 1 25 0 1 0 76310441 2641920 282 1283457024 134512640 135304128 4288222160 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23464/statm: 645 282 239 194 0 32 0
[pid=23477] ppid=23464 vsize=888592 CPUtime=3.96
/proc/23477/stat : 23477 (java) S 23464 23463 29493 34817 29493 4202496 80757 0 1 0 370 26 0 0 25 0 10 0 76310444 909918208 75494 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/23477/statm: 222148 75494 1748 10 0 219239 0
[pid=23477/tid=23478] ppid=23464 vsize=888592 CPUtime=1.77
/proc/23477/task/23478/stat : 23478 (java) R 23464 23463 29493 34817 29493 4202560 50176 0 1 0 165 12 0 0 25 0 10 0 76310445 909918208 75494 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=23477/tid=23479] ppid=23464 vsize=888592 CPUtime=0.34
/proc/23477/task/23479/stat : 23479 (java) S 23464 23463 29493 34817 29493 4202560 15863 0 0 0 26 8 0 0 16 0 10 0 76310446 909918208 75494 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 0 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23480] ppid=23464 vsize=888592 CPUtime=0
/proc/23477/task/23480/stat : 23480 (java) S 23464 23463 29493 34817 29493 4202560 9 0 0 0 0 0 0 0 18 0 10 0 76310447 909918208 75494 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23481] ppid=23464 vsize=888592 CPUtime=0
/proc/23477/task/23481/stat : 23481 (java) S 23464 23463 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 10 0 76310447 909918208 75494 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23482] ppid=23464 vsize=888592 CPUtime=0
/proc/23477/task/23482/stat : 23482 (java) S 23464 23463 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76310449 909918208 75494 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23483] ppid=23464 vsize=888592 CPUtime=0.81
/proc/23477/task/23483/stat : 23483 (java) S 23464 23463 29493 34817 29493 4202560 9070 0 0 0 78 3 0 0 15 0 10 0 76310449 909918208 75494 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23484] ppid=23464 vsize=888592 CPUtime=1.02
/proc/23477/task/23484/stat : 23484 (java) R 23464 23463 29493 34817 29493 4202560 4572 0 0 0 100 2 0 0 21 0 10 0 76310449 909918208 75494 1283457024 134512640 134550932 4287740416 18446744073709551615 4152825494 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=23477/tid=23485] ppid=23464 vsize=888592 CPUtime=0
/proc/23477/task/23485/stat : 23485 (java) S 23464 23463 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76310449 909918208 75494 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23486] ppid=23464 vsize=888592 CPUtime=0
/proc/23477/task/23486/stat : 23486 (java) S 23464 23463 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 10 0 76310449 909918208 75494 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.99
Current children cumulated vsize (KiB) 893740

[startup+4.4061 s]
/proc/loadavg: 2.18 1.85 1.71 1/46 23487
/proc/meminfo: memFree=6696/1048576 swapFree=0/0
[pid=23463] ppid=23462 vsize=2568 CPUtime=0
/proc/23463/stat : 23463 (p2cudf-paranoid) S 23462 23463 29493 34817 29493 4202496 376 0 0 0 0 0 0 0 18 0 1 0 76310440 2629632 271 1283457024 134512640 135304128 4289783104 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23463/statm: 642 271 230 194 0 29 0
[pid=23464] ppid=23463 vsize=2580 CPUtime=0.03
/proc/23464/stat : 23464 (p2cudf) S 23463 23463 29493 34817 29493 4202496 396 3013 0 1 0 0 2 1 25 0 1 0 76310441 2641920 282 1283457024 134512640 135304128 4288222160 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23464/statm: 645 282 239 194 0 32 0
[pid=23477] ppid=23464 vsize=887732 CPUtime=4.25
/proc/23477/stat : 23477 (java) S 23464 23463 29493 34817 29493 4202496 81935 0 1 0 398 27 0 0 25 0 11 0 76310444 909037568 75236 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/23477/statm: 221933 75236 1749 10 0 219024 0
[pid=23477/tid=23478] ppid=23464 vsize=887732 CPUtime=1.85
/proc/23477/task/23478/stat : 23478 (java) S 23464 23463 29493 34817 29493 4202560 50184 0 1 0 173 12 0 0 25 0 11 0 76310445 909037568 75236 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23479] ppid=23464 vsize=887732 CPUtime=0.34
/proc/23477/task/23479/stat : 23479 (java) S 23464 23463 29493 34817 29493 4202560 15863 0 0 0 26 8 0 0 16 0 11 0 76310446 909037568 75236 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 0 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23480] ppid=23464 vsize=887732 CPUtime=0
/proc/23477/task/23480/stat : 23480 (java) S 23464 23463 29493 34817 29493 4202560 9 0 0 0 0 0 0 0 18 0 11 0 76310447 909037568 75236 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23481] ppid=23464 vsize=887732 CPUtime=0
/proc/23477/task/23481/stat : 23481 (java) S 23464 23463 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 11 0 76310447 909037568 75236 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23482] ppid=23464 vsize=887732 CPUtime=0
/proc/23477/task/23482/stat : 23482 (java) S 23464 23463 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 11 0 76310449 909037568 75236 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23483] ppid=23464 vsize=887732 CPUtime=0.84
/proc/23477/task/23483/stat : 23483 (java) S 23464 23463 29493 34817 29493 4202560 9073 0 0 0 81 3 0 0 15 0 11 0 76310449 909037568 75236 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23484] ppid=23464 vsize=887732 CPUtime=1.2
/proc/23477/task/23484/stat : 23484 (java) S 23464 23463 29493 34817 29493 4202560 5735 0 0 0 117 3 0 0 21 0 11 0 76310449 909037568 75236 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23485] ppid=23464 vsize=887732 CPUtime=0
/proc/23477/task/23485/stat : 23485 (java) S 23464 23463 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 11 0 76310449 909037568 75236 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23486] ppid=23464 vsize=887732 CPUtime=0
/proc/23477/task/23486/stat : 23486 (java) S 23464 23463 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 11 0 76310449 909037568 75236 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23487] ppid=23464 vsize=887732 CPUtime=0
/proc/23477/task/23487/stat : 23487 (java) S 23464 23463 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 25 0 11 0 76310871 909037568 75236 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.28
Current children cumulated vsize (KiB) 892880

[startup+4.806 s]
/proc/loadavg: 2.18 1.85 1.71 1/46 23487
/proc/meminfo: memFree=6696/1048576 swapFree=0/0
[pid=23463] ppid=23462 vsize=2568 CPUtime=0
/proc/23463/stat : 23463 (p2cudf-paranoid) S 23462 23463 29493 34817 29493 4202496 376 0 0 0 0 0 0 0 18 0 1 0 76310440 2629632 271 1283457024 134512640 135304128 4289783104 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23463/statm: 642 271 230 194 0 29 0
[pid=23464] ppid=23463 vsize=2580 CPUtime=0.03
/proc/23464/stat : 23464 (p2cudf) S 23463 23463 29493 34817 29493 4202496 396 3013 0 1 0 0 2 1 25 0 1 0 76310441 2641920 282 1283457024 134512640 135304128 4288222160 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23464/statm: 645 282 239 194 0 32 0
[pid=23477] ppid=23464 vsize=887732 CPUtime=4.25
/proc/23477/stat : 23477 (java) S 23464 23463 29493 34817 29493 4202496 81935 0 1 0 398 27 0 0 25 0 11 0 76310444 909037568 75236 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/23477/statm: 221933 75236 1749 10 0 219024 0
[pid=23477/tid=23478] ppid=23464 vsize=887732 CPUtime=1.85
/proc/23477/task/23478/stat : 23478 (java) S 23464 23463 29493 34817 29493 4202560 50184 0 1 0 173 12 0 0 25 0 11 0 76310445 909037568 75236 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23479] ppid=23464 vsize=887732 CPUtime=0.34
/proc/23477/task/23479/stat : 23479 (java) S 23464 23463 29493 34817 29493 4202560 15863 0 0 0 26 8 0 0 15 0 11 0 76310446 909037568 75236 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 0 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23480] ppid=23464 vsize=887732 CPUtime=0
/proc/23477/task/23480/stat : 23480 (java) S 23464 23463 29493 34817 29493 4202560 9 0 0 0 0 0 0 0 18 0 11 0 76310447 909037568 75236 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23481] ppid=23464 vsize=887732 CPUtime=0
/proc/23477/task/23481/stat : 23481 (java) S 23464 23463 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 11 0 76310447 909037568 75236 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23482] ppid=23464 vsize=887732 CPUtime=0
/proc/23477/task/23482/stat : 23482 (java) S 23464 23463 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 11 0 76310449 909037568 75236 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23483] ppid=23464 vsize=887732 CPUtime=0.84
/proc/23477/task/23483/stat : 23483 (java) S 23464 23463 29493 34817 29493 4202560 9073 0 0 0 81 3 0 0 15 0 11 0 76310449 909037568 75236 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23484] ppid=23464 vsize=887732 CPUtime=1.2
/proc/23477/task/23484/stat : 23484 (java) S 23464 23463 29493 34817 29493 4202560 5735 0 0 0 117 3 0 0 21 0 11 0 76310449 909037568 75236 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23485] ppid=23464 vsize=887732 CPUtime=0
/proc/23477/task/23485/stat : 23485 (java) S 23464 23463 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 11 0 76310449 909037568 75236 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=23477/tid=23486] ppid=23464 vsize=887732 CPUtime=0
/proc/23477/task/23486/stat : 23486 (java) R 23464 23463 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 11 0 76310449 909037568 75236 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=23477/tid=23487] ppid=23464 vsize=887732 CPUtime=0
/proc/23477/task/23487/stat : 23487 (java) S 23464 23463 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 21 0 11 0 76310871 909037568 75236 1283457024 134512640 134550932 4287740416 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.28
Current children cumulated vsize (KiB) 892880

Child status: 0
Real time (s): 4.89406
CPU time (s): 4.33227
CPU user time (s): 4.01625
CPU system time (s): 0.316019
CPU usage (%): 88.5209
Max. virtual memory (cumulated for all children) (KiB): 894276

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 4.01625
system time used= 0.316019
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 85746
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= 459
involuntary context switches= 438

runsolver used 0 second user time and 0 second system time

The end