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/103.cudf.caixa.log.runsolver ./p2cudf-paranoid-1.12 /home/misc2010/data/misc4/caixa//103.cudf /home/misc2010/tmp/201103031013/p2cudf-paranoid-1.12/103.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: 1.29 1.14 0.94 5/39 11592
/proc/meminfo: memFree=675896/1048576 swapFree=0/0
[pid=11589] ppid=11588 vsize=2564 CPUtime=0
/proc/11589/stat : 11589 (p2cudf-paranoid) S 11588 11589 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 18 0 1 0 74797869 2625536 270 1283457024 134512640 135304128 4292884528 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11589/statm: 641 270 230 194 0 28 0
[pid=11590] ppid=11589 vsize=2572 CPUtime=0
/proc/11590/stat : 11590 (p2cudf) S 11589 11589 29493 34817 29493 4202496 354 0 0 0 0 0 0 0 18 0 1 0 74797869 2633728 272 1283457024 134512640 135304128 4291778352 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0
/proc/11590/statm: 643 272 231 194 0 30 0
[pid=11591] ppid=11590 vsize=2572 CPUtime=0
/proc/11591/stat : 11591 (p2cudf) R 11590 11589 29493 34817 29493 4202560 94 0 0 0 0 0 0 0 25 0 1 0 74797869 2633728 119 1283457024 134512640 135304128 4291778352 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/11591/statm: 643 119 77 194 0 30 0
[pid=11592] ppid=11591 vsize=2572 CPUtime=0
/proc/11592/stat : 11592 (p2cudf) R 11591 11589 29493 34817 29493 4202560 0 0 0 0 0 0 0 0 25 0 1 0 74797869 2633728 42 1283457024 134512640 135304128 4291778352 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/11592/statm: 643 42 0 194 0 30 0

[startup+0.197622 s]
/proc/loadavg: 1.29 1.14 0.94 5/39 11592
/proc/meminfo: memFree=675896/1048576 swapFree=0/0
[pid=11589] ppid=11588 vsize=2564 CPUtime=0
/proc/11589/stat : 11589 (p2cudf-paranoid) S 11588 11589 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 18 0 1 0 74797869 2625536 270 1283457024 134512640 135304128 4292884528 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11589/statm: 641 270 230 194 0 28 0
[pid=11590] ppid=11589 vsize=2580 CPUtime=0.02
/proc/11590/stat : 11590 (p2cudf) S 11589 11589 29493 34817 29493 4202496 394 3012 0 1 0 0 1 1 25 0 1 0 74797869 2641920 282 1283457024 134512640 135304128 4291778352 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11590/statm: 645 282 239 194 0 32 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5144

[startup+0.207617 s]
/proc/loadavg: 1.29 1.14 0.94 5/39 11592
/proc/meminfo: memFree=675896/1048576 swapFree=0/0
[pid=11589] ppid=11588 vsize=2564 CPUtime=0
/proc/11589/stat : 11589 (p2cudf-paranoid) S 11588 11589 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 18 0 1 0 74797869 2625536 270 1283457024 134512640 135304128 4292884528 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11589/statm: 641 270 230 194 0 28 0
[pid=11590] ppid=11589 vsize=2580 CPUtime=0.02
/proc/11590/stat : 11590 (p2cudf) S 11589 11589 29493 34817 29493 4202496 394 3012 0 1 0 0 1 1 25 0 1 0 74797869 2641920 282 1283457024 134512640 135304128 4291778352 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11590/statm: 645 282 239 194 0 32 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5144

[startup+0.307631 s]
/proc/loadavg: 1.29 1.14 0.94 5/39 11592
/proc/meminfo: memFree=675896/1048576 swapFree=0/0
[pid=11589] ppid=11588 vsize=2564 CPUtime=0
/proc/11589/stat : 11589 (p2cudf-paranoid) S 11588 11589 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 18 0 1 0 74797869 2625536 270 1283457024 134512640 135304128 4292884528 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11589/statm: 641 270 230 194 0 28 0
[pid=11590] ppid=11589 vsize=2580 CPUtime=0.02
/proc/11590/stat : 11590 (p2cudf) S 11589 11589 29493 34817 29493 4202496 394 3012 0 1 0 0 1 1 25 0 1 0 74797869 2641920 282 1283457024 134512640 135304128 4291778352 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11590/statm: 645 282 239 194 0 32 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5144

[startup+0.707698 s]
/proc/loadavg: 1.29 1.14 0.94 5/39 11592
/proc/meminfo: memFree=675896/1048576 swapFree=0/0
[pid=11589] ppid=11588 vsize=2564 CPUtime=0
/proc/11589/stat : 11589 (p2cudf-paranoid) S 11588 11589 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 18 0 1 0 74797869 2625536 270 1283457024 134512640 135304128 4292884528 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11589/statm: 641 270 230 194 0 28 0
[pid=11590] ppid=11589 vsize=2580 CPUtime=0.02
/proc/11590/stat : 11590 (p2cudf) S 11589 11589 29493 34817 29493 4202496 394 3012 0 1 0 0 1 1 25 0 1 0 74797869 2641920 282 1283457024 134512640 135304128 4291778352 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11590/statm: 645 282 239 194 0 32 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5144

[startup+1.50797 s]
/proc/loadavg: 1.29 1.14 0.94 5/48 11612
/proc/meminfo: memFree=635336/1048576 swapFree=0/0
[pid=11589] ppid=11588 vsize=2564 CPUtime=0
/proc/11589/stat : 11589 (p2cudf-paranoid) S 11588 11589 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 18 0 1 0 74797869 2625536 270 1283457024 134512640 135304128 4292884528 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11589/statm: 641 270 230 194 0 28 0
[pid=11590] ppid=11589 vsize=2580 CPUtime=0.02
/proc/11590/stat : 11590 (p2cudf) S 11589 11589 29493 34817 29493 4202496 394 3012 0 1 0 0 1 1 25 0 1 0 74797869 2641920 282 1283457024 134512640 135304128 4291778352 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11590/statm: 645 282 239 194 0 32 0
[pid=11603] ppid=11590 vsize=881808 CPUtime=1.48
/proc/11603/stat : 11603 (java) S 11590 11589 29493 34817 29493 4202496 18073 0 1 0 140 8 0 0 25 0 10 0 74797872 902971392 13641 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/11603/statm: 220452 13641 1725 10 0 217543 0
[pid=11603/tid=11604] ppid=11590 vsize=881808 CPUtime=0.64
/proc/11603/task/11604/stat : 11604 (java) R 11590 11589 29493 34817 29493 4202560 5867 0 1 0 59 5 0 0 25 0 10 0 74797873 902971392 13641 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=11603/tid=11605] ppid=11590 vsize=881808 CPUtime=0
/proc/11603/task/11605/stat : 11605 (java) S 11590 11589 29493 34817 29493 4202560 7 0 0 0 0 0 0 0 15 0 10 0 74797875 902971392 13641 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 0 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11606] ppid=11590 vsize=881808 CPUtime=0
/proc/11603/task/11606/stat : 11606 (java) S 11590 11589 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 25 0 10 0 74797875 902971392 13641 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11607] ppid=11590 vsize=881808 CPUtime=0
/proc/11603/task/11607/stat : 11607 (java) S 11590 11589 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 25 0 10 0 74797875 902971392 13641 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11608] ppid=11590 vsize=881808 CPUtime=0
/proc/11603/task/11608/stat : 11608 (java) S 11590 11589 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 74797878 902971392 13641 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11609] ppid=11590 vsize=881808 CPUtime=0.55
/proc/11603/task/11609/stat : 11609 (java) R 11590 11589 29493 34817 29493 4202560 8798 0 0 0 54 1 0 0 22 0 10 0 74797878 902971392 13641 1283457024 134512640 134550932 4292820688 18446744073709551615 4152060676 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=11603/tid=11610] ppid=11590 vsize=881808 CPUtime=0.26
/proc/11603/task/11610/stat : 11610 (java) R 11590 11589 29493 34817 29493 4202560 2327 0 0 0 26 0 0 0 24 0 10 0 74797878 902971392 13641 1283457024 134512640 134550932 4292820688 18446744073709551615 4152527955 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=11603/tid=11611] ppid=11590 vsize=881808 CPUtime=0
/proc/11603/task/11611/stat : 11611 (java) S 11590 11589 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 74797878 902971392 13641 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11612] ppid=11590 vsize=881808 CPUtime=0
/proc/11603/task/11612/stat : 11612 (java) S 11590 11589 29493 34817 29493 4202560 2 0 0 0 0 0 0 0 15 0 10 0 74797878 902971392 13641 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.5
Current children cumulated vsize (KiB) 886952

[startup+3.10831 s]
/proc/loadavg: 1.29 1.14 0.94 4/48 11612
/proc/meminfo: memFree=594912/1048576 swapFree=0/0
[pid=11589] ppid=11588 vsize=2564 CPUtime=0
/proc/11589/stat : 11589 (p2cudf-paranoid) S 11588 11589 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 18 0 1 0 74797869 2625536 270 1283457024 134512640 135304128 4292884528 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11589/statm: 641 270 230 194 0 28 0
[pid=11590] ppid=11589 vsize=2580 CPUtime=0.02
/proc/11590/stat : 11590 (p2cudf) S 11589 11589 29493 34817 29493 4202496 394 3012 0 1 0 0 1 1 25 0 1 0 74797869 2641920 282 1283457024 134512640 135304128 4291778352 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11590/statm: 645 282 239 194 0 32 0
[pid=11603] ppid=11590 vsize=881440 CPUtime=3.07
/proc/11603/stat : 11603 (java) S 11590 11589 29493 34817 29493 4202496 55271 0 1 0 283 24 0 0 25 0 10 0 74797872 902594560 47435 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/11603/statm: 220360 47435 1742 10 0 217451 0
[pid=11603/tid=11604] ppid=11590 vsize=881440 CPUtime=1.53
/proc/11603/task/11604/stat : 11604 (java) R 11590 11589 29493 34817 29493 4202560 39604 0 1 0 133 20 0 0 25 0 10 0 74797873 902594560 47435 1283457024 134512640 134550932 4292820688 18446744073709551615 4095383805 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=11603/tid=11605] ppid=11590 vsize=881440 CPUtime=0
/proc/11603/task/11605/stat : 11605 (java) S 11590 11589 29493 34817 29493 4202560 7 0 0 0 0 0 0 0 15 0 10 0 74797875 902594560 47435 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 0 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11606] ppid=11590 vsize=881440 CPUtime=0
/proc/11603/task/11606/stat : 11606 (java) S 11590 11589 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 25 0 10 0 74797875 902594560 47435 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11607] ppid=11590 vsize=881440 CPUtime=0
/proc/11603/task/11607/stat : 11607 (java) S 11590 11589 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 25 0 10 0 74797875 902594560 47435 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11608] ppid=11590 vsize=881440 CPUtime=0
/proc/11603/task/11608/stat : 11608 (java) S 11590 11589 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 74797878 902594560 47435 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11609] ppid=11590 vsize=881440 CPUtime=0.86
/proc/11603/task/11609/stat : 11609 (java) R 11590 11589 29493 34817 29493 4202560 9030 0 0 0 85 1 0 0 17 0 10 0 74797878 902594560 47435 1283457024 134512640 134550932 4292820688 18446744073709551615 4152067817 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=11603/tid=11610] ppid=11590 vsize=881440 CPUtime=0.64
/proc/11603/task/11610/stat : 11610 (java) R 11590 11589 29493 34817 29493 4202560 5556 0 0 0 64 0 0 0 24 0 10 0 74797878 902594560 47435 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=11603/tid=11611] ppid=11590 vsize=881440 CPUtime=0
/proc/11603/task/11611/stat : 11611 (java) S 11590 11589 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 74797878 902594560 47435 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11612] ppid=11590 vsize=881440 CPUtime=0
/proc/11603/task/11612/stat : 11612 (java) S 11590 11589 29493 34817 29493 4202560 2 0 0 0 0 0 0 0 15 0 10 0 74797878 902594560 47435 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.09
Current children cumulated vsize (KiB) 886584

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

[startup+3.20835 s]
/proc/loadavg: 1.29 1.14 0.94 4/48 11612
/proc/meminfo: memFree=594912/1048576 swapFree=0/0
[pid=11589] ppid=11588 vsize=2564 CPUtime=0
/proc/11589/stat : 11589 (p2cudf-paranoid) S 11588 11589 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 18 0 1 0 74797869 2625536 270 1283457024 134512640 135304128 4292884528 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11589/statm: 641 270 230 194 0 28 0
[pid=11590] ppid=11589 vsize=2580 CPUtime=0.02
/proc/11590/stat : 11590 (p2cudf) S 11589 11589 29493 34817 29493 4202496 394 3012 0 1 0 0 1 1 25 0 1 0 74797869 2641920 282 1283457024 134512640 135304128 4291778352 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11590/statm: 645 282 239 194 0 32 0
[pid=11603] ppid=11590 vsize=881440 CPUtime=3.17
/proc/11603/stat : 11603 (java) S 11590 11589 29493 34817 29493 4202496 57829 0 1 0 293 24 0 0 25 0 10 0 74797872 902594560 49993 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/11603/statm: 220360 49993 1742 10 0 217451 0
[pid=11603/tid=11604] ppid=11590 vsize=881440 CPUtime=1.59
/proc/11603/task/11604/stat : 11604 (java) R 11590 11589 29493 34817 29493 4202560 42160 0 1 0 139 20 0 0 25 0 10 0 74797873 902594560 49993 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=11603/tid=11605] ppid=11590 vsize=881440 CPUtime=0
/proc/11603/task/11605/stat : 11605 (java) S 11590 11589 29493 34817 29493 4202560 7 0 0 0 0 0 0 0 15 0 10 0 74797875 902594560 49993 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 0 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11606] ppid=11590 vsize=881440 CPUtime=0
/proc/11603/task/11606/stat : 11606 (java) S 11590 11589 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 25 0 10 0 74797875 902594560 49993 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11607] ppid=11590 vsize=881440 CPUtime=0
/proc/11603/task/11607/stat : 11607 (java) S 11590 11589 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 25 0 10 0 74797875 902594560 49993 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11608] ppid=11590 vsize=881440 CPUtime=0
/proc/11603/task/11608/stat : 11608 (java) S 11590 11589 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 74797878 902594560 49993 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11609] ppid=11590 vsize=881440 CPUtime=0.89
/proc/11603/task/11609/stat : 11609 (java) S 11590 11589 29493 34817 29493 4202560 9032 0 0 0 88 1 0 0 17 0 10 0 74797878 902594560 49993 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11610] ppid=11590 vsize=881440 CPUtime=0.65
/proc/11603/task/11610/stat : 11610 (java) R 11590 11589 29493 34817 29493 4202560 5556 0 0 0 65 0 0 0 23 0 10 0 74797878 902594560 49993 1283457024 134512640 134550932 4292820688 18446744073709551615 4151800593 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=11603/tid=11611] ppid=11590 vsize=881440 CPUtime=0
/proc/11603/task/11611/stat : 11611 (java) S 11590 11589 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 74797878 902594560 49993 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11612] ppid=11590 vsize=881440 CPUtime=0
/proc/11603/task/11612/stat : 11612 (java) R 11590 11589 29493 34817 29493 4202560 2 0 0 0 0 0 0 0 15 0 10 0 74797878 902594560 49993 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.19
Current children cumulated vsize (KiB) 886584

[startup+4.00856 s]
/proc/loadavg: 1.34 1.16 0.94 3/48 11612
/proc/meminfo: memFree=479592/1048576 swapFree=0/0
[pid=11589] ppid=11588 vsize=2564 CPUtime=0
/proc/11589/stat : 11589 (p2cudf-paranoid) S 11588 11589 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 18 0 1 0 74797869 2625536 270 1283457024 134512640 135304128 4292884528 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11589/statm: 641 270 230 194 0 28 0
[pid=11590] ppid=11589 vsize=2580 CPUtime=0.02
/proc/11590/stat : 11590 (p2cudf) S 11589 11589 29493 34817 29493 4202496 394 3012 0 1 0 0 1 1 25 0 1 0 74797869 2641920 282 1283457024 134512640 135304128 4291778352 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11590/statm: 645 282 239 194 0 32 0
[pid=11603] ppid=11590 vsize=881440 CPUtime=3.97
/proc/11603/stat : 11603 (java) S 11590 11589 29493 34817 29493 4202496 81438 0 1 0 364 33 0 0 25 0 10 0 74797872 902594560 73602 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/11603/statm: 220360 73602 1747 10 0 217451 0
[pid=11603/tid=11604] ppid=11590 vsize=881440 CPUtime=1.78
/proc/11603/task/11604/stat : 11604 (java) R 11590 11589 29493 34817 29493 4202560 50151 0 1 0 155 23 0 0 25 0 10 0 74797873 902594560 73602 1283457024 134512640 134550932 4292820688 18446744073709551615 4145710484 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=11603/tid=11605] ppid=11590 vsize=881440 CPUtime=0.33
/proc/11603/task/11605/stat : 11605 (java) S 11590 11589 29493 34817 29493 4202560 15598 0 0 0 27 6 0 0 16 0 10 0 74797875 902594560 73602 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 0 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11606] ppid=11590 vsize=881440 CPUtime=0
/proc/11603/task/11606/stat : 11606 (java) S 11590 11589 29493 34817 29493 4202560 9 0 0 0 0 0 0 0 18 0 10 0 74797875 902594560 73602 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11607] ppid=11590 vsize=881440 CPUtime=0
/proc/11603/task/11607/stat : 11607 (java) S 11590 11589 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 10 0 74797875 902594560 73602 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11608] ppid=11590 vsize=881440 CPUtime=0
/proc/11603/task/11608/stat : 11608 (java) S 11590 11589 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 74797878 902594560 73602 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11609] ppid=11590 vsize=881440 CPUtime=1.04
/proc/11603/task/11609/stat : 11609 (java) S 11590 11589 29493 34817 29493 4202560 9046 0 0 0 103 1 0 0 15 0 10 0 74797878 902594560 73602 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11610] ppid=11590 vsize=881440 CPUtime=0.77
/proc/11603/task/11610/stat : 11610 (java) R 11590 11589 29493 34817 29493 4202560 5566 0 0 0 77 0 0 0 23 0 10 0 74797878 902594560 73602 1283457024 134512640 134550932 4292820688 18446744073709551615 4150257456 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=11603/tid=11611] ppid=11590 vsize=881440 CPUtime=0
/proc/11603/task/11611/stat : 11611 (java) S 11590 11589 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 74797878 902594560 73602 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11612] ppid=11590 vsize=881440 CPUtime=0
/proc/11603/task/11612/stat : 11612 (java) R 11590 11589 29493 34817 29493 4202560 2 0 0 0 0 0 0 0 15 0 10 0 74797878 902594560 73602 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.99
Current children cumulated vsize (KiB) 886584

[startup+4.80607 s]
/proc/loadavg: 1.34 1.16 0.94 4/48 11612
/proc/meminfo: memFree=385972/1048576 swapFree=0/0
[pid=11589] ppid=11588 vsize=2564 CPUtime=0
/proc/11589/stat : 11589 (p2cudf-paranoid) S 11588 11589 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 18 0 1 0 74797869 2625536 270 1283457024 134512640 135304128 4292884528 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11589/statm: 641 270 230 194 0 28 0
[pid=11590] ppid=11589 vsize=2580 CPUtime=0.02
/proc/11590/stat : 11590 (p2cudf) S 11589 11589 29493 34817 29493 4202496 394 3012 0 1 0 0 1 1 25 0 1 0 74797869 2641920 282 1283457024 134512640 135304128 4291778352 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11590/statm: 645 282 239 194 0 32 0
[pid=11603] ppid=11590 vsize=881764 CPUtime=4.76
/proc/11603/stat : 11603 (java) S 11590 11589 29493 34817 29493 4202496 83815 0 1 0 438 38 0 0 25 0 11 0 74797872 902926336 73692 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/11603/statm: 220441 73692 1754 10 0 217532 0
[pid=11603/tid=11604] ppid=11590 vsize=881764 CPUtime=2.02
/proc/11603/task/11604/stat : 11604 (java) S 11590 11589 29493 34817 29493 4202560 50182 0 1 0 179 23 0 0 25 0 11 0 74797873 902926336 73692 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11605] ppid=11590 vsize=881764 CPUtime=0.33
/proc/11603/task/11605/stat : 11605 (java) S 11590 11589 29493 34817 29493 4202560 15598 0 0 0 27 6 0 0 16 0 11 0 74797875 902926336 73692 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 0 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11606] ppid=11590 vsize=881764 CPUtime=0
/proc/11603/task/11606/stat : 11606 (java) S 11590 11589 29493 34817 29493 4202560 9 0 0 0 0 0 0 0 18 0 11 0 74797875 902926336 73692 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11607] ppid=11590 vsize=881764 CPUtime=0
/proc/11603/task/11607/stat : 11607 (java) S 11590 11589 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 11 0 74797875 902926336 73692 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11608] ppid=11590 vsize=881764 CPUtime=0
/proc/11603/task/11608/stat : 11608 (java) S 11590 11589 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 11 0 74797878 902926336 73692 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11609] ppid=11590 vsize=881764 CPUtime=1.26
/proc/11603/task/11609/stat : 11609 (java) S 11590 11589 29493 34817 29493 4202560 9074 0 0 0 125 1 0 0 15 0 11 0 74797878 902926336 73692 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11610] ppid=11590 vsize=881764 CPUtime=1.11
/proc/11603/task/11610/stat : 11610 (java) S 11590 11589 29493 34817 29493 4202560 7879 0 0 0 106 5 0 0 25 0 11 0 74797878 902926336 73692 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11611] ppid=11590 vsize=881764 CPUtime=0
/proc/11603/task/11611/stat : 11611 (java) S 11590 11589 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 11 0 74797878 902926336 73692 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11612] ppid=11590 vsize=881764 CPUtime=0
/proc/11603/task/11612/stat : 11612 (java) S 11590 11589 29493 34817 29493 4202560 2 0 0 0 0 0 0 0 15 0 11 0 74797878 902926336 73692 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.78
Current children cumulated vsize (KiB) 886908

[startup+5.20593 s]
/proc/loadavg: 1.34 1.16 0.94 4/48 11612
/proc/meminfo: memFree=385972/1048576 swapFree=0/0
[pid=11589] ppid=11588 vsize=2564 CPUtime=0
/proc/11589/stat : 11589 (p2cudf-paranoid) S 11588 11589 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 18 0 1 0 74797869 2625536 270 1283457024 134512640 135304128 4292884528 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11589/statm: 641 270 230 194 0 28 0
[pid=11590] ppid=11589 vsize=2580 CPUtime=0.02
/proc/11590/stat : 11590 (p2cudf) S 11589 11589 29493 34817 29493 4202496 394 3012 0 1 0 0 1 1 25 0 1 0 74797869 2641920 282 1283457024 134512640 135304128 4291778352 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11590/statm: 645 282 239 194 0 32 0
[pid=11603] ppid=11590 vsize=881764 CPUtime=4.76
/proc/11603/stat : 11603 (java) S 11590 11589 29493 34817 29493 4202496 83815 0 1 0 438 38 0 0 25 0 11 0 74797872 902926336 73692 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/11603/statm: 220441 73692 1754 10 0 217532 0
[pid=11603/tid=11604] ppid=11590 vsize=881764 CPUtime=2.02
/proc/11603/task/11604/stat : 11604 (java) S 11590 11589 29493 34817 29493 4202560 50182 0 1 0 179 23 0 0 25 0 11 0 74797873 902926336 73692 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11605] ppid=11590 vsize=881764 CPUtime=0.33
/proc/11603/task/11605/stat : 11605 (java) S 11590 11589 29493 34817 29493 4202560 15598 0 0 0 27 6 0 0 15 0 11 0 74797875 902926336 73692 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 0 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11606] ppid=11590 vsize=881764 CPUtime=0
/proc/11603/task/11606/stat : 11606 (java) S 11590 11589 29493 34817 29493 4202560 9 0 0 0 0 0 0 0 18 0 11 0 74797875 902926336 73692 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11607] ppid=11590 vsize=881764 CPUtime=0
/proc/11603/task/11607/stat : 11607 (java) S 11590 11589 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 11 0 74797875 902926336 73692 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11608] ppid=11590 vsize=881764 CPUtime=0
/proc/11603/task/11608/stat : 11608 (java) S 11590 11589 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 11 0 74797878 902926336 73692 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11609] ppid=11590 vsize=881764 CPUtime=1.26
/proc/11603/task/11609/stat : 11609 (java) S 11590 11589 29493 34817 29493 4202560 9074 0 0 0 125 1 0 0 15 0 11 0 74797878 902926336 73692 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11610] ppid=11590 vsize=881764 CPUtime=1.11
/proc/11603/task/11610/stat : 11610 (java) S 11590 11589 29493 34817 29493 4202560 7879 0 0 0 106 5 0 0 25 0 11 0 74797878 902926336 73692 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11611] ppid=11590 vsize=881764 CPUtime=0
/proc/11603/task/11611/stat : 11611 (java) S 11590 11589 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 11 0 74797878 902926336 73692 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11612] ppid=11590 vsize=881764 CPUtime=0
/proc/11603/task/11612/stat : 11612 (java) S 11590 11589 29493 34817 29493 4202560 2 0 0 0 0 0 0 0 15 0 11 0 74797878 902926336 73692 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.78
Current children cumulated vsize (KiB) 886908

[startup+5.30593 s]
/proc/loadavg: 1.34 1.16 0.94 4/48 11612
/proc/meminfo: memFree=385972/1048576 swapFree=0/0
[pid=11589] ppid=11588 vsize=2564 CPUtime=0
/proc/11589/stat : 11589 (p2cudf-paranoid) S 11588 11589 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 18 0 1 0 74797869 2625536 270 1283457024 134512640 135304128 4292884528 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11589/statm: 641 270 230 194 0 28 0
[pid=11590] ppid=11589 vsize=2580 CPUtime=0.02
/proc/11590/stat : 11590 (p2cudf) S 11589 11589 29493 34817 29493 4202496 394 3012 0 1 0 0 1 1 25 0 1 0 74797869 2641920 282 1283457024 134512640 135304128 4291778352 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11590/statm: 645 282 239 194 0 32 0
[pid=11603] ppid=11590 vsize=881764 CPUtime=4.76
/proc/11603/stat : 11603 (java) S 11590 11589 29493 34817 29493 4202496 83815 0 1 0 438 38 0 0 25 0 11 0 74797872 902926336 73692 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/11603/statm: 220441 73692 1754 10 0 217532 0
[pid=11603/tid=11604] ppid=11590 vsize=881764 CPUtime=2.02
/proc/11603/task/11604/stat : 11604 (java) S 11590 11589 29493 34817 29493 4202560 50182 0 1 0 179 23 0 0 25 0 11 0 74797873 902926336 73692 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11605] ppid=11590 vsize=881764 CPUtime=0.33
/proc/11603/task/11605/stat : 11605 (java) S 11590 11589 29493 34817 29493 4202560 15598 0 0 0 27 6 0 0 15 0 11 0 74797875 902926336 73692 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 0 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11606] ppid=11590 vsize=881764 CPUtime=0
/proc/11603/task/11606/stat : 11606 (java) S 11590 11589 29493 34817 29493 4202560 9 0 0 0 0 0 0 0 18 0 11 0 74797875 902926336 73692 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11607] ppid=11590 vsize=881764 CPUtime=0
/proc/11603/task/11607/stat : 11607 (java) S 11590 11589 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 11 0 74797875 902926336 73692 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11608] ppid=11590 vsize=881764 CPUtime=0
/proc/11603/task/11608/stat : 11608 (java) S 11590 11589 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 11 0 74797878 902926336 73692 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11609] ppid=11590 vsize=881764 CPUtime=1.26
/proc/11603/task/11609/stat : 11609 (java) S 11590 11589 29493 34817 29493 4202560 9074 0 0 0 125 1 0 0 15 0 11 0 74797878 902926336 73692 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11610] ppid=11590 vsize=881764 CPUtime=1.11
/proc/11603/task/11610/stat : 11610 (java) S 11590 11589 29493 34817 29493 4202560 7879 0 0 0 106 5 0 0 25 0 11 0 74797878 902926336 73692 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11611] ppid=11590 vsize=881764 CPUtime=0
/proc/11603/task/11611/stat : 11611 (java) S 11590 11589 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 11 0 74797878 902926336 73692 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
[pid=11603/tid=11612] ppid=11590 vsize=881764 CPUtime=0
/proc/11603/task/11612/stat : 11612 (java) S 11590 11589 29493 34817 29493 4202560 2 0 0 0 0 0 0 0 15 0 11 0 74797878 902926336 73692 1283457024 134512640 134550932 4292820688 18446744073709551615 4294960130 0 4 0 16800975 18446612133061566656 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.78
Current children cumulated vsize (KiB) 886908

Child status: 0
Real time (s): 5.39399
CPU time (s): 4.8243
CPU user time (s): 4.39227
CPU system time (s): 0.432027
CPU usage (%): 89.4385
Max. virtual memory (cumulated for all children) (KiB): 891840

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 4.39227
system time used= 0.432027
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 87622
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= 391
involuntary context switches= 377

runsolver used 0 second user time and 0 second system time

The end