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/rand144.cudf.s.log.runsolver ./p2cudf-paranoid-1.13 /home/misc2010/data/2011/incremental/s/rand144.cudf /home/misc2010/tmp/201108251442/p2cudf-paranoid-1.13/rand144.cudf.s.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.24 1.06 0.94 5/38 7386
/proc/meminfo: memFree=451856/1048576 swapFree=0/0
[pid=7383] ppid=7382 vsize=2568 CPUtime=0
/proc/7383/stat : 7383 (p2cudf-paranoid) S 7382 7383 4778 34817 4778 4202496 374 0 0 0 0 0 0 0 18 0 1 0 10196420 2629632 270 1283457024 134512640 135304128 4286831200 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7383/statm: 642 270 230 194 0 29 0
[pid=7384] ppid=7383 vsize=2568 CPUtime=0
/proc/7384/stat : 7384 (p2cudf) S 7383 7383 4778 34817 4778 4202496 351 0 0 0 0 0 0 0 18 0 1 0 10196420 2629632 270 1283457024 134512640 135304128 4289555728 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0
/proc/7384/statm: 642 270 231 194 0 29 0
[pid=7385] ppid=7384 vsize=2568 CPUtime=0
/proc/7385/stat : 7385 (p2cudf) R 7384 7383 4778 34817 4778 4202560 94 0 0 0 0 0 0 0 25 0 1 0 10196420 2629632 118 1283457024 134512640 135304128 4289555728 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/7385/statm: 642 118 77 194 0 29 0
[pid=7386] ppid=7385 vsize=2568 CPUtime=0
/proc/7386/stat : 7386 (p2cudf) R 7385 7383 4778 34817 4778 4202560 0 0 0 0 0 0 0 0 25 0 1 0 10196420 2629632 41 1283457024 134512640 135304128 4289555728 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/7386/statm: 642 41 0 194 0 29 0

[startup+0.105763 s]
/proc/loadavg: 1.24 1.06 0.94 5/38 7386
/proc/meminfo: memFree=451856/1048576 swapFree=0/0
[pid=7383] ppid=7382 vsize=2568 CPUtime=0
/proc/7383/stat : 7383 (p2cudf-paranoid) S 7382 7383 4778 34817 4778 4202496 374 0 0 0 0 0 0 0 18 0 1 0 10196420 2629632 270 1283457024 134512640 135304128 4286831200 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7383/statm: 642 270 230 194 0 29 0
[pid=7384] ppid=7383 vsize=2572 CPUtime=0.04
/proc/7384/stat : 7384 (p2cudf) S 7383 7383 4778 34817 4778 4202496 389 3015 0 1 0 0 2 2 25 0 1 0 10196420 2633728 280 1283457024 134512640 135304128 4289555728 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7384/statm: 643 280 239 194 0 30 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 5140

[startup+0.205768 s]
/proc/loadavg: 1.24 1.06 0.94 5/38 7386
/proc/meminfo: memFree=451856/1048576 swapFree=0/0
[pid=7383] ppid=7382 vsize=2568 CPUtime=0
/proc/7383/stat : 7383 (p2cudf-paranoid) S 7382 7383 4778 34817 4778 4202496 374 0 0 0 0 0 0 0 18 0 1 0 10196420 2629632 270 1283457024 134512640 135304128 4286831200 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7383/statm: 642 270 230 194 0 29 0
[pid=7384] ppid=7383 vsize=2572 CPUtime=0.04
/proc/7384/stat : 7384 (p2cudf) S 7383 7383 4778 34817 4778 4202496 389 3015 0 1 0 0 2 2 25 0 1 0 10196420 2633728 280 1283457024 134512640 135304128 4289555728 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7384/statm: 643 280 239 194 0 30 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 5140

[startup+0.305778 s]
/proc/loadavg: 1.24 1.06 0.94 5/38 7386
/proc/meminfo: memFree=451856/1048576 swapFree=0/0
[pid=7383] ppid=7382 vsize=2568 CPUtime=0
/proc/7383/stat : 7383 (p2cudf-paranoid) S 7382 7383 4778 34817 4778 4202496 374 0 0 0 0 0 0 0 18 0 1 0 10196420 2629632 270 1283457024 134512640 135304128 4286831200 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7383/statm: 642 270 230 194 0 29 0
[pid=7384] ppid=7383 vsize=2572 CPUtime=0.04
/proc/7384/stat : 7384 (p2cudf) S 7383 7383 4778 34817 4778 4202496 389 3015 0 1 0 0 2 2 25 0 1 0 10196420 2633728 280 1283457024 134512640 135304128 4289555728 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7384/statm: 643 280 239 194 0 30 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 5140

[startup+0.705896 s]
/proc/loadavg: 1.24 1.06 0.94 5/38 7386
/proc/meminfo: memFree=451856/1048576 swapFree=0/0
[pid=7383] ppid=7382 vsize=2568 CPUtime=0
/proc/7383/stat : 7383 (p2cudf-paranoid) S 7382 7383 4778 34817 4778 4202496 374 0 0 0 0 0 0 0 18 0 1 0 10196420 2629632 270 1283457024 134512640 135304128 4286831200 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7383/statm: 642 270 230 194 0 29 0
[pid=7384] ppid=7383 vsize=2572 CPUtime=0.04
/proc/7384/stat : 7384 (p2cudf) S 7383 7383 4778 34817 4778 4202496 389 3015 0 1 0 0 2 2 25 0 1 0 10196420 2633728 280 1283457024 134512640 135304128 4289555728 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7384/statm: 643 280 239 194 0 30 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 5140

[startup+1.50607 s]
/proc/loadavg: 1.24 1.06 0.94 4/47 7406
/proc/meminfo: memFree=406832/1048576 swapFree=0/0
[pid=7383] ppid=7382 vsize=2568 CPUtime=0
/proc/7383/stat : 7383 (p2cudf-paranoid) S 7382 7383 4778 34817 4778 4202496 374 0 0 0 0 0 0 0 18 0 1 0 10196420 2629632 270 1283457024 134512640 135304128 4286831200 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7383/statm: 642 270 230 194 0 29 0
[pid=7384] ppid=7383 vsize=2572 CPUtime=0.04
/proc/7384/stat : 7384 (p2cudf) S 7383 7383 4778 34817 4778 4202496 389 3015 0 1 0 0 2 2 25 0 1 0 10196420 2633728 280 1283457024 134512640 135304128 4289555728 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7384/statm: 643 280 239 194 0 30 0
[pid=7397] ppid=7384 vsize=883804 CPUtime=1.47
/proc/7397/stat : 7397 (java) S 7384 7383 4778 34817 4778 4202496 20715 0 1 0 141 6 0 0 25 0 10 0 10196423 905015296 17633 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/7397/statm: 220951 17633 1724 10 0 218042 0
[pid=7397/tid=7398] ppid=7384 vsize=883804 CPUtime=0.79
/proc/7397/task/7398/stat : 7398 (java) R 7384 7383 4778 34817 4778 4202560 9888 0 1 0 75 4 0 0 25 0 10 0 10196424 905015296 17633 1283457024 134512640 134550932 4293689248 18446744073709551615 4095374216 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=7397/tid=7399] ppid=7384 vsize=883804 CPUtime=0
/proc/7397/task/7399/stat : 7399 (java) S 7384 7383 4778 34817 4778 4202560 7 0 0 0 0 0 0 0 17 0 10 0 10196426 905015296 17633 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 0 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7400] ppid=7384 vsize=883804 CPUtime=0
/proc/7397/task/7400/stat : 7400 (java) S 7384 7383 4778 34817 4778 4202560 8 0 0 0 0 0 0 0 25 0 10 0 10196426 905015296 17633 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7401] ppid=7384 vsize=883804 CPUtime=0
/proc/7397/task/7401/stat : 7401 (java) S 7384 7383 4778 34817 4778 4202560 4 0 0 0 0 0 0 0 25 0 10 0 10196426 905015296 17633 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7402] ppid=7384 vsize=883804 CPUtime=0
/proc/7397/task/7402/stat : 7402 (java) S 7384 7383 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 10 0 10196429 905015296 17633 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7403] ppid=7384 vsize=883804 CPUtime=0.45
/proc/7397/task/7403/stat : 7403 (java) R 7384 7383 4778 34817 4778 4202560 8023 0 0 0 44 1 0 0 25 0 10 0 10196429 905015296 17633 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=7397/tid=7404] ppid=7384 vsize=883804 CPUtime=0.21
/proc/7397/task/7404/stat : 7404 (java) S 7384 7383 4778 34817 4778 4202560 1725 0 0 0 21 0 0 0 22 0 10 0 10196429 905015296 17633 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7405] ppid=7384 vsize=883804 CPUtime=0
/proc/7397/task/7405/stat : 7405 (java) S 7384 7383 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 10 0 10196429 905015296 17633 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7406] ppid=7384 vsize=883804 CPUtime=0
/proc/7397/task/7406/stat : 7406 (java) S 7384 7383 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 15 0 10 0 10196429 905015296 17633 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.51
Current children cumulated vsize (KiB) 888944

[startup+3.11913 s]
/proc/loadavg: 1.22 1.06 0.94 2/47 7406
/proc/meminfo: memFree=352024/1048576 swapFree=0/0
[pid=7383] ppid=7382 vsize=2568 CPUtime=0
/proc/7383/stat : 7383 (p2cudf-paranoid) S 7382 7383 4778 34817 4778 4202496 374 0 0 0 0 0 0 0 18 0 1 0 10196420 2629632 270 1283457024 134512640 135304128 4286831200 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7383/statm: 642 270 230 194 0 29 0
[pid=7384] ppid=7383 vsize=2572 CPUtime=0.04
/proc/7384/stat : 7384 (p2cudf) S 7383 7383 4778 34817 4778 4202496 389 3015 0 1 0 0 2 2 25 0 1 0 10196420 2633728 280 1283457024 134512640 135304128 4289555728 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7384/statm: 643 280 239 194 0 30 0
[pid=7397] ppid=7384 vsize=881996 CPUtime=3.07
/proc/7397/stat : 7397 (java) S 7384 7383 4778 34817 4778 4202496 38518 0 1 0 297 10 0 0 25 0 11 0 10196423 903163904 32241 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/7397/statm: 220499 32241 1755 10 0 217590 0
[pid=7397/tid=7398] ppid=7384 vsize=881996 CPUtime=1.32
/proc/7397/task/7398/stat : 7398 (java) R 7384 7383 4778 34817 4778 4202560 24417 0 1 0 127 5 0 0 25 0 11 0 10196424 903163904 32241 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=7397/tid=7399] ppid=7384 vsize=881996 CPUtime=0
/proc/7397/task/7399/stat : 7399 (java) S 7384 7383 4778 34817 4778 4202560 7 0 0 0 0 0 0 0 16 0 11 0 10196426 903163904 32241 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 0 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7400] ppid=7384 vsize=881996 CPUtime=0
/proc/7397/task/7400/stat : 7400 (java) S 7384 7383 4778 34817 4778 4202560 8 0 0 0 0 0 0 0 25 0 11 0 10196426 903163904 32241 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7401] ppid=7384 vsize=881996 CPUtime=0
/proc/7397/task/7401/stat : 7401 (java) S 7384 7383 4778 34817 4778 4202560 4 0 0 0 0 0 0 0 25 0 11 0 10196426 903163904 32241 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7402] ppid=7384 vsize=881996 CPUtime=0
/proc/7397/task/7402/stat : 7402 (java) S 7384 7383 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 11 0 10196429 903163904 32241 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7403] ppid=7384 vsize=881996 CPUtime=0.51
/proc/7397/task/7403/stat : 7403 (java) S 7384 7383 4778 34817 4778 4202560 8069 0 0 0 50 1 0 0 25 0 11 0 10196429 903163904 32241 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7404] ppid=7384 vsize=881996 CPUtime=1.23
/proc/7397/task/7404/stat : 7404 (java) S 7384 7383 4778 34817 4778 4202560 4949 0 0 0 119 4 0 0 15 0 11 0 10196429 903163904 32241 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7405] ppid=7384 vsize=881996 CPUtime=0
/proc/7397/task/7405/stat : 7405 (java) S 7384 7383 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 11 0 10196429 903163904 32241 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7406] ppid=7384 vsize=881996 CPUtime=0
/proc/7397/task/7406/stat : 7406 (java) S 7384 7383 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 15 0 11 0 10196429 903163904 32241 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.11
Current children cumulated vsize (KiB) 887136

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

[startup+3.20982 s]
/proc/loadavg: 1.22 1.06 0.94 2/47 7406
/proc/meminfo: memFree=352024/1048576 swapFree=0/0
[pid=7383] ppid=7382 vsize=2568 CPUtime=0
/proc/7383/stat : 7383 (p2cudf-paranoid) S 7382 7383 4778 34817 4778 4202496 374 0 0 0 0 0 0 0 18 0 1 0 10196420 2629632 270 1283457024 134512640 135304128 4286831200 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7383/statm: 642 270 230 194 0 29 0
[pid=7384] ppid=7383 vsize=2572 CPUtime=0.04
/proc/7384/stat : 7384 (p2cudf) S 7383 7383 4778 34817 4778 4202496 389 3015 0 1 0 0 2 2 25 0 1 0 10196420 2633728 280 1283457024 134512640 135304128 4289555728 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7384/statm: 643 280 239 194 0 30 0
[pid=7397] ppid=7384 vsize=881996 CPUtime=3.16
/proc/7397/stat : 7397 (java) S 7384 7383 4778 34817 4778 4202496 38686 0 1 0 306 10 0 0 25 0 11 0 10196423 903163904 32409 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/7397/statm: 220499 32409 1757 10 0 217590 0
[pid=7397/tid=7398] ppid=7384 vsize=881996 CPUtime=1.32
/proc/7397/task/7398/stat : 7398 (java) R 7384 7383 4778 34817 4778 4202560 24575 0 1 0 127 5 0 0 25 0 11 0 10196424 903163904 32409 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=7397/tid=7399] ppid=7384 vsize=881996 CPUtime=0
/proc/7397/task/7399/stat : 7399 (java) S 7384 7383 4778 34817 4778 4202560 7 0 0 0 0 0 0 0 16 0 11 0 10196426 903163904 32409 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 0 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7400] ppid=7384 vsize=881996 CPUtime=0
/proc/7397/task/7400/stat : 7400 (java) S 7384 7383 4778 34817 4778 4202560 8 0 0 0 0 0 0 0 25 0 11 0 10196426 903163904 32409 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7401] ppid=7384 vsize=881996 CPUtime=0
/proc/7397/task/7401/stat : 7401 (java) S 7384 7383 4778 34817 4778 4202560 4 0 0 0 0 0 0 0 25 0 11 0 10196426 903163904 32409 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7402] ppid=7384 vsize=881996 CPUtime=0
/proc/7397/task/7402/stat : 7402 (java) S 7384 7383 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 11 0 10196429 903163904 32409 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7403] ppid=7384 vsize=881996 CPUtime=0.51
/proc/7397/task/7403/stat : 7403 (java) S 7384 7383 4778 34817 4778 4202560 8069 0 0 0 50 1 0 0 25 0 11 0 10196429 903163904 32409 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7404] ppid=7384 vsize=881996 CPUtime=1.32
/proc/7397/task/7404/stat : 7404 (java) S 7384 7383 4778 34817 4778 4202560 4959 0 0 0 128 4 0 0 15 0 11 0 10196429 903163904 32409 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7405] ppid=7384 vsize=881996 CPUtime=0
/proc/7397/task/7405/stat : 7405 (java) S 7384 7383 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 11 0 10196429 903163904 32409 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7406] ppid=7384 vsize=881996 CPUtime=0
/proc/7397/task/7406/stat : 7406 (java) S 7384 7383 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 15 0 11 0 10196429 903163904 32409 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.2
Current children cumulated vsize (KiB) 887136

[startup+3.60594 s]
/proc/loadavg: 1.22 1.06 0.94 1/48 7409
/proc/meminfo: memFree=328448/1048576 swapFree=0/0
[pid=7383] ppid=7382 vsize=2568 CPUtime=0
/proc/7383/stat : 7383 (p2cudf-paranoid) S 7382 7383 4778 34817 4778 4202496 374 0 0 0 0 0 0 0 18 0 1 0 10196420 2629632 270 1283457024 134512640 135304128 4286831200 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7383/statm: 642 270 230 194 0 29 0
[pid=7384] ppid=7383 vsize=2572 CPUtime=0.04
/proc/7384/stat : 7384 (p2cudf) S 7383 7383 4778 34817 4778 4202496 389 3015 0 1 0 0 2 2 25 0 1 0 10196420 2633728 280 1283457024 134512640 135304128 4289555728 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7384/statm: 643 280 239 194 0 30 0
[pid=7397] ppid=7384 vsize=882320 CPUtime=3.25
/proc/7397/stat : 7397 (java) S 7384 7383 4778 34817 4778 4202496 38739 0 1 0 315 10 0 0 25 0 11 0 10196423 903495680 32462 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/7397/statm: 220580 32462 1761 10 0 217671 0
[pid=7397/tid=7398] ppid=7384 vsize=882320 CPUtime=1.35
/proc/7397/task/7398/stat : 7398 (java) S 7384 7383 4778 34817 4778 4202560 24613 0 1 0 130 5 0 0 25 0 11 0 10196424 903495680 32462 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7399] ppid=7384 vsize=882320 CPUtime=0
/proc/7397/task/7399/stat : 7399 (java) S 7384 7383 4778 34817 4778 4202560 7 0 0 0 0 0 0 0 15 0 11 0 10196426 903495680 32462 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 0 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7400] ppid=7384 vsize=882320 CPUtime=0
/proc/7397/task/7400/stat : 7400 (java) S 7384 7383 4778 34817 4778 4202560 8 0 0 0 0 0 0 0 25 0 11 0 10196426 903495680 32462 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7401] ppid=7384 vsize=882320 CPUtime=0
/proc/7397/task/7401/stat : 7401 (java) S 7384 7383 4778 34817 4778 4202560 4 0 0 0 0 0 0 0 25 0 11 0 10196426 903495680 32462 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7402] ppid=7384 vsize=882320 CPUtime=0
/proc/7397/task/7402/stat : 7402 (java) S 7384 7383 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 11 0 10196429 903495680 32462 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7403] ppid=7384 vsize=882320 CPUtime=0.51
/proc/7397/task/7403/stat : 7403 (java) S 7384 7383 4778 34817 4778 4202560 8069 0 0 0 50 1 0 0 25 0 11 0 10196429 903495680 32462 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7404] ppid=7384 vsize=882320 CPUtime=1.38
/proc/7397/task/7404/stat : 7404 (java) S 7384 7383 4778 34817 4778 4202560 4969 0 0 0 134 4 0 0 15 0 11 0 10196429 903495680 32462 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7405] ppid=7384 vsize=882320 CPUtime=0
/proc/7397/task/7405/stat : 7405 (java) S 7384 7383 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 11 0 10196429 903495680 32462 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7406] ppid=7384 vsize=882320 CPUtime=0
/proc/7397/task/7406/stat : 7406 (java) S 7384 7383 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 15 0 11 0 10196429 903495680 32462 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7409] ppid=7384 vsize=882320 CPUtime=0
/proc/7397/task/7409/stat : 7409 (java) S 7384 7383 4778 34817 4778 4202560 4 0 0 0 0 0 0 0 25 0 11 0 10196750 903495680 32462 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.29
Current children cumulated vsize (KiB) 887460

[startup+3.80596 s]
/proc/loadavg: 1.22 1.06 0.94 1/48 7409
/proc/meminfo: memFree=328448/1048576 swapFree=0/0
[pid=7383] ppid=7382 vsize=2568 CPUtime=0
/proc/7383/stat : 7383 (p2cudf-paranoid) S 7382 7383 4778 34817 4778 4202496 374 0 0 0 0 0 0 0 18 0 1 0 10196420 2629632 270 1283457024 134512640 135304128 4286831200 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7383/statm: 642 270 230 194 0 29 0
[pid=7384] ppid=7383 vsize=2572 CPUtime=0.04
/proc/7384/stat : 7384 (p2cudf) S 7383 7383 4778 34817 4778 4202496 389 3015 0 1 0 0 2 2 25 0 1 0 10196420 2633728 280 1283457024 134512640 135304128 4289555728 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7384/statm: 643 280 239 194 0 30 0
[pid=7397] ppid=7384 vsize=882320 CPUtime=3.25
/proc/7397/stat : 7397 (java) S 7384 7383 4778 34817 4778 4202496 38739 0 1 0 315 10 0 0 25 0 11 0 10196423 903495680 32462 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/7397/statm: 220580 32462 1761 10 0 217671 0
[pid=7397/tid=7398] ppid=7384 vsize=882320 CPUtime=1.35
/proc/7397/task/7398/stat : 7398 (java) S 7384 7383 4778 34817 4778 4202560 24613 0 1 0 130 5 0 0 25 0 11 0 10196424 903495680 32462 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7399] ppid=7384 vsize=882320 CPUtime=0
/proc/7397/task/7399/stat : 7399 (java) S 7384 7383 4778 34817 4778 4202560 7 0 0 0 0 0 0 0 15 0 11 0 10196426 903495680 32462 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 0 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7400] ppid=7384 vsize=882320 CPUtime=0
/proc/7397/task/7400/stat : 7400 (java) S 7384 7383 4778 34817 4778 4202560 8 0 0 0 0 0 0 0 25 0 11 0 10196426 903495680 32462 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7401] ppid=7384 vsize=882320 CPUtime=0
/proc/7397/task/7401/stat : 7401 (java) S 7384 7383 4778 34817 4778 4202560 4 0 0 0 0 0 0 0 25 0 11 0 10196426 903495680 32462 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7402] ppid=7384 vsize=882320 CPUtime=0
/proc/7397/task/7402/stat : 7402 (java) S 7384 7383 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 11 0 10196429 903495680 32462 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7403] ppid=7384 vsize=882320 CPUtime=0.51
/proc/7397/task/7403/stat : 7403 (java) S 7384 7383 4778 34817 4778 4202560 8069 0 0 0 50 1 0 0 25 0 11 0 10196429 903495680 32462 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7404] ppid=7384 vsize=882320 CPUtime=1.38
/proc/7397/task/7404/stat : 7404 (java) S 7384 7383 4778 34817 4778 4202560 4969 0 0 0 134 4 0 0 15 0 11 0 10196429 903495680 32462 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7405] ppid=7384 vsize=882320 CPUtime=0
/proc/7397/task/7405/stat : 7405 (java) S 7384 7383 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 11 0 10196429 903495680 32462 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7406] ppid=7384 vsize=882320 CPUtime=0
/proc/7397/task/7406/stat : 7406 (java) S 7384 7383 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 15 0 11 0 10196429 903495680 32462 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 18446612133155120448 0 0 -1 0 0 0 0
[pid=7397/tid=7409] ppid=7384 vsize=882320 CPUtime=0
/proc/7397/task/7409/stat : 7409 (java) R 7384 7383 4778 34817 4778 4202560 4 0 0 0 0 0 0 0 20 0 11 0 10196750 903495680 32462 1283457024 134512640 134550932 4293689248 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.29
Current children cumulated vsize (KiB) 887460

[startup+3.90722 s]
/proc/loadavg: 1.22 1.06 0.94 1/48 7409
/proc/meminfo: memFree=328448/1048576 swapFree=0/0
[pid=7383] ppid=7382 vsize=2568 CPUtime=0
/proc/7383/stat : 7383 (p2cudf-paranoid) S 7382 7383 4778 34817 4778 4202496 374 0 0 0 0 0 0 0 18 0 1 0 10196420 2629632 270 1283457024 134512640 135304128 4286831200 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7383/statm: 642 270 230 194 0 29 0
[pid=7384] ppid=7383 vsize=2572 CPUtime=0.04
/proc/7384/stat : 7384 (p2cudf) S 7383 7383 4778 34817 4778 4202496 389 3015 0 1 0 0 2 2 25 0 1 0 10196420 2633728 280 1283457024 134512640 135304128 4289555728 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7384/statm: 643 280 239 194 0 30 0
[pid=7397] ppid=7384 vsize=0 CPUtime=3.35
/proc/7397/stat : 7397 (java) Z 7384 7383 4778 34817 4778 4203532 38900 0 1 0 324 11 0 0 18 0 2 0 10196423 0 0 1283457024 0 0 0 0 0 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/7397/statm: 0 0 0 0 0 0 0
[pid=7397/tid=7398] ppid=7384 vsize=0 CPUtime=1.36
/proc/7397/task/7398/stat : 7398 (java) R 7384 7383 4778 34817 4778 4203588 24613 0 1 0 130 6 0 0 19 0 2 0 10196424 0 0 1283457024 0 0 0 0 0 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.39
Current children cumulated vsize (KiB) 5140

Child status: 0
Real time (s): 3.91908
CPU time (s): 3.40821
CPU user time (s): 3.2642
CPU system time (s): 0.144009
CPU usage (%): 86.9647
Max. virtual memory (cumulated for all children) (KiB): 889004

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 3.2642
system time used= 0.144009
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 42698
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= 517
involuntary context switches= 491

runsolver used 0 second user time and 0 second system time

The end