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/218091ce-4bcc-11df-bc4e-00163e7a6f5e.cudf.debian.log.runsolver ./p2cudf-paranoid-1.12 /home/misc2010/data/misc4/debian//218091ce-4bcc-11df-bc4e-00163e7a6f5e.cudf /home/misc2010/tmp/201103031013/p2cudf-paranoid-1.12/218091ce-4bcc-11df-bc4e-00163e7a6f5e.cudf.debian.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.00 1.06 0.80 4/38 7651
/proc/meminfo: memFree=645296/1048576 swapFree=0/0
[pid=7649] ppid=7648 vsize=2564 CPUtime=0
/proc/7649/stat : 7649 (p2cudf-paranoid) S 7648 7649 29493 34817 29493 4202496 372 0 0 0 0 0 0 0 25 0 1 0 74754034 2625536 269 1283457024 134512640 135304128 4293423216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7649/statm: 641 269 230 194 0 28 0
[pid=7650] ppid=7649 vsize=2564 CPUtime=0
/proc/7650/stat : 7650 (p2cudf) R 7649 7649 29493 34817 29493 4202496 345 0 0 0 0 0 0 0 25 0 1 0 74754034 2625536 271 1283457024 134512640 135304128 4294642096 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/7650/statm: 641 271 231 194 0 28 0
[pid=7651] ppid=7650 vsize=2564 CPUtime=0
/proc/7651/stat : 7651 (p2cudf) R 7650 7649 29493 34817 29493 4202560 0 0 0 0 0 0 0 0 25 0 1 0 74754034 2625536 40 1283457024 134512640 135304128 4294642096 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/7651/statm: 641 40 0 194 0 28 0

[startup+0.139819 s]
/proc/loadavg: 1.00 1.06 0.80 4/38 7651
/proc/meminfo: memFree=645296/1048576 swapFree=0/0
[pid=7649] ppid=7648 vsize=2564 CPUtime=0
/proc/7649/stat : 7649 (p2cudf-paranoid) S 7648 7649 29493 34817 29493 4202496 372 0 0 0 0 0 0 0 25 0 1 0 74754034 2625536 269 1283457024 134512640 135304128 4293423216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7649/statm: 641 269 230 194 0 28 0
[pid=7650] ppid=7649 vsize=2572 CPUtime=0.02
/proc/7650/stat : 7650 (p2cudf) S 7649 7649 29493 34817 29493 4202496 393 3017 0 1 0 0 1 1 25 0 1 0 74754034 2633728 281 1283457024 134512640 135304128 4294642096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7650/statm: 643 281 239 194 0 30 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5136

[startup+0.209835 s]
/proc/loadavg: 1.00 1.06 0.80 4/38 7651
/proc/meminfo: memFree=645296/1048576 swapFree=0/0
[pid=7649] ppid=7648 vsize=2564 CPUtime=0
/proc/7649/stat : 7649 (p2cudf-paranoid) S 7648 7649 29493 34817 29493 4202496 372 0 0 0 0 0 0 0 25 0 1 0 74754034 2625536 269 1283457024 134512640 135304128 4293423216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7649/statm: 641 269 230 194 0 28 0
[pid=7650] ppid=7649 vsize=2572 CPUtime=0.02
/proc/7650/stat : 7650 (p2cudf) S 7649 7649 29493 34817 29493 4202496 393 3017 0 1 0 0 1 1 25 0 1 0 74754034 2633728 281 1283457024 134512640 135304128 4294642096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7650/statm: 643 281 239 194 0 30 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5136

[startup+0.309844 s]
/proc/loadavg: 1.00 1.06 0.80 4/38 7651
/proc/meminfo: memFree=645296/1048576 swapFree=0/0
[pid=7649] ppid=7648 vsize=2564 CPUtime=0
/proc/7649/stat : 7649 (p2cudf-paranoid) S 7648 7649 29493 34817 29493 4202496 372 0 0 0 0 0 0 0 25 0 1 0 74754034 2625536 269 1283457024 134512640 135304128 4293423216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7649/statm: 641 269 230 194 0 28 0
[pid=7650] ppid=7649 vsize=2572 CPUtime=0.02
/proc/7650/stat : 7650 (p2cudf) S 7649 7649 29493 34817 29493 4202496 393 3017 0 1 0 0 1 1 25 0 1 0 74754034 2633728 281 1283457024 134512640 135304128 4294642096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7650/statm: 643 281 239 194 0 30 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5136

[startup+0.71018 s]
/proc/loadavg: 1.00 1.06 0.80 4/38 7651
/proc/meminfo: memFree=645296/1048576 swapFree=0/0
[pid=7649] ppid=7648 vsize=2564 CPUtime=0
/proc/7649/stat : 7649 (p2cudf-paranoid) S 7648 7649 29493 34817 29493 4202496 372 0 0 0 0 0 0 0 25 0 1 0 74754034 2625536 269 1283457024 134512640 135304128 4293423216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7649/statm: 641 269 230 194 0 28 0
[pid=7650] ppid=7649 vsize=2572 CPUtime=0.02
/proc/7650/stat : 7650 (p2cudf) S 7649 7649 29493 34817 29493 4202496 393 3017 0 1 0 0 1 1 25 0 1 0 74754034 2633728 281 1283457024 134512640 135304128 4294642096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7650/statm: 643 281 239 194 0 30 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5136

[startup+1.51012 s]
/proc/loadavg: 1.00 1.06 0.80 4/48 7672
/proc/meminfo: memFree=599228/1048576 swapFree=0/0
[pid=7649] ppid=7648 vsize=2564 CPUtime=0
/proc/7649/stat : 7649 (p2cudf-paranoid) S 7648 7649 29493 34817 29493 4202496 372 0 0 0 0 0 0 0 25 0 1 0 74754034 2625536 269 1283457024 134512640 135304128 4293423216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7649/statm: 641 269 230 194 0 28 0
[pid=7650] ppid=7649 vsize=2572 CPUtime=0.02
/proc/7650/stat : 7650 (p2cudf) S 7649 7649 29493 34817 29493 4202496 393 3017 0 1 0 0 1 1 25 0 1 0 74754034 2633728 281 1283457024 134512640 135304128 4294642096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7650/statm: 643 281 239 194 0 30 0
[pid=7663] ppid=7650 vsize=881632 CPUtime=1.47
/proc/7663/stat : 7663 (java) S 7650 7649 29493 34817 29493 4202496 24242 0 1 0 137 10 0 0 25 0 10 0 74754038 902791168 21105 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/7663/statm: 220408 21105 1730 10 0 217499 0
[pid=7663/tid=7664] ppid=7650 vsize=881632 CPUtime=0.74
/proc/7663/task/7664/stat : 7664 (java) R 7650 7649 29493 34817 29493 4202560 13399 0 1 0 68 6 0 0 25 0 10 0 74754038 902791168 21105 1283457024 134512640 134550932 4288262704 18446744073709551615 4094991626 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=7663/tid=7665] ppid=7650 vsize=881632 CPUtime=0
/proc/7663/task/7665/stat : 7665 (java) S 7650 7649 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 17 0 10 0 74754040 902791168 21105 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 0 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7666] ppid=7650 vsize=881632 CPUtime=0
/proc/7663/task/7666/stat : 7666 (java) S 7650 7649 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 25 0 10 0 74754040 902791168 21105 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7667] ppid=7650 vsize=881632 CPUtime=0
/proc/7663/task/7667/stat : 7667 (java) S 7650 7649 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 25 0 10 0 74754040 902791168 21105 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7668] ppid=7650 vsize=881632 CPUtime=0
/proc/7663/task/7668/stat : 7668 (java) S 7650 7649 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 74754043 902791168 21105 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7669] ppid=7650 vsize=881632 CPUtime=0.29
/proc/7663/task/7669/stat : 7669 (java) S 7650 7649 29493 34817 29493 4202560 2112 0 0 0 29 0 0 0 23 0 10 0 74754043 902791168 21105 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7670] ppid=7650 vsize=881632 CPUtime=0.41
/proc/7663/task/7670/stat : 7670 (java) R 7650 7649 29493 34817 29493 4202560 7652 0 0 0 38 3 0 0 25 0 10 0 74754043 902791168 21105 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=7663/tid=7671] ppid=7650 vsize=881632 CPUtime=0
/proc/7663/task/7671/stat : 7671 (java) S 7650 7649 29493 34817 29493 4202560 0 0 0 0 0 0 0 0 25 0 10 0 74754043 902791168 21105 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7672] ppid=7650 vsize=881632 CPUtime=0
/proc/7663/task/7672/stat : 7672 (java) S 7650 7649 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 10 0 74754043 902791168 21105 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.49
Current children cumulated vsize (KiB) 886768

[startup+3.11048 s]
/proc/loadavg: 1.08 1.08 0.81 2/48 7672
/proc/meminfo: memFree=445096/1048576 swapFree=0/0
[pid=7649] ppid=7648 vsize=2564 CPUtime=0
/proc/7649/stat : 7649 (p2cudf-paranoid) S 7648 7649 29493 34817 29493 4202496 372 0 0 0 0 0 0 0 25 0 1 0 74754034 2625536 269 1283457024 134512640 135304128 4293423216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7649/statm: 641 269 230 194 0 28 0
[pid=7650] ppid=7649 vsize=2572 CPUtime=0.02
/proc/7650/stat : 7650 (p2cudf) S 7649 7649 29493 34817 29493 4202496 393 3017 0 1 0 0 1 1 25 0 1 0 74754034 2633728 281 1283457024 134512640 135304128 4294642096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7650/statm: 643 281 239 194 0 30 0
[pid=7663] ppid=7650 vsize=881632 CPUtime=3.07
/proc/7663/stat : 7663 (java) S 7650 7649 29493 34817 29493 4202496 73768 0 1 0 274 33 0 0 25 0 10 0 74754038 902791168 70631 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/7663/statm: 220408 70631 1743 10 0 217499 0
[pid=7663/tid=7664] ppid=7650 vsize=881632 CPUtime=1.8
/proc/7663/task/7664/stat : 7664 (java) R 7650 7649 29493 34817 29493 4202560 50069 0 1 0 154 26 0 0 25 0 10 0 74754038 902791168 70631 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=7663/tid=7665] ppid=7650 vsize=881632 CPUtime=0.28
/proc/7663/task/7665/stat : 7665 (java) S 7650 7649 29493 34817 29493 4202560 12835 0 0 0 24 4 0 0 16 0 10 0 74754040 902791168 70631 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 0 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7666] ppid=7650 vsize=881632 CPUtime=0
/proc/7663/task/7666/stat : 7666 (java) S 7650 7649 29493 34817 29493 4202560 9 0 0 0 0 0 0 0 18 0 10 0 74754040 902791168 70631 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7667] ppid=7650 vsize=881632 CPUtime=0
/proc/7663/task/7667/stat : 7667 (java) S 7650 7649 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 10 0 74754040 902791168 70631 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7668] ppid=7650 vsize=881632 CPUtime=0
/proc/7663/task/7668/stat : 7668 (java) S 7650 7649 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 74754043 902791168 70631 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7669] ppid=7650 vsize=881632 CPUtime=0.29
/proc/7663/task/7669/stat : 7669 (java) S 7650 7649 29493 34817 29493 4202560 2112 0 0 0 29 0 0 0 18 0 10 0 74754043 902791168 70631 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7670] ppid=7650 vsize=881632 CPUtime=0.67
/proc/7663/task/7670/stat : 7670 (java) R 7650 7649 29493 34817 29493 4202560 7676 0 0 0 64 3 0 0 16 0 10 0 74754043 902791168 70631 1283457024 134512640 134550932 4288262704 18446744073709551615 4152737196 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=7663/tid=7671] ppid=7650 vsize=881632 CPUtime=0
/proc/7663/task/7671/stat : 7671 (java) S 7650 7649 29493 34817 29493 4202560 0 0 0 0 0 0 0 0 25 0 10 0 74754043 902791168 70631 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7672] ppid=7650 vsize=881632 CPUtime=0
/proc/7663/task/7672/stat : 7672 (java) S 7650 7649 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 10 0 74754043 902791168 70631 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.09
Current children cumulated vsize (KiB) 886768

[startup+6.31138 s]
/proc/loadavg: 1.08 1.08 0.81 4/48 7672
/proc/meminfo: memFree=314896/1048576 swapFree=0/0
[pid=7649] ppid=7648 vsize=2564 CPUtime=0
/proc/7649/stat : 7649 (p2cudf-paranoid) S 7648 7649 29493 34817 29493 4202496 372 0 0 0 0 0 0 0 25 0 1 0 74754034 2625536 269 1283457024 134512640 135304128 4293423216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7649/statm: 641 269 230 194 0 28 0
[pid=7650] ppid=7649 vsize=2572 CPUtime=0.02
/proc/7650/stat : 7650 (p2cudf) S 7649 7649 29493 34817 29493 4202496 393 3017 0 1 0 0 1 1 25 0 1 0 74754034 2633728 281 1283457024 134512640 135304128 4294642096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7650/statm: 643 281 239 194 0 30 0
[pid=7663] ppid=7650 vsize=882400 CPUtime=6.24
/proc/7663/stat : 7663 (java) S 7650 7649 29493 34817 29493 4202496 88686 0 1 0 584 40 0 0 25 0 11 0 74754038 903577600 84167 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/7663/statm: 220600 84167 1778 10 0 217691 0
[pid=7663/tid=7664] ppid=7650 vsize=882400 CPUtime=3.2
/proc/7663/task/7664/stat : 7664 (java) R 7650 7649 29493 34817 29493 4202560 50260 0 1 0 292 28 0 0 25 0 11 0 74754038 903577600 84167 1283457024 134512640 134550932 4288262704 18446744073709551615 4095602410 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=7663/tid=7665] ppid=7650 vsize=882400 CPUtime=0.59
/proc/7663/task/7665/stat : 7665 (java) S 7650 7649 29493 34817 29493 4202560 25890 0 0 0 52 7 0 0 16 0 11 0 74754040 903577600 84167 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 0 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7666] ppid=7650 vsize=882400 CPUtime=0
/proc/7663/task/7666/stat : 7666 (java) S 7650 7649 29493 34817 29493 4202560 9 0 0 0 0 0 0 0 18 0 11 0 74754040 903577600 84167 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7667] ppid=7650 vsize=882400 CPUtime=0
/proc/7663/task/7667/stat : 7667 (java) S 7650 7649 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 11 0 74754040 903577600 84167 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7668] ppid=7650 vsize=882400 CPUtime=0
/proc/7663/task/7668/stat : 7668 (java) S 7650 7649 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 11 0 74754043 903577600 84167 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7669] ppid=7650 vsize=882400 CPUtime=0.29
/proc/7663/task/7669/stat : 7669 (java) S 7650 7649 29493 34817 29493 4202560 2112 0 0 0 29 0 0 0 18 0 11 0 74754043 903577600 84167 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7670] ppid=7650 vsize=882400 CPUtime=2.12
/proc/7663/task/7670/stat : 7670 (java) S 7650 7649 29493 34817 29493 4202560 9344 0 0 0 208 4 0 0 15 0 11 0 74754043 903577600 84167 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7671] ppid=7650 vsize=882400 CPUtime=0
/proc/7663/task/7671/stat : 7671 (java) S 7650 7649 29493 34817 29493 4202560 0 0 0 0 0 0 0 0 25 0 11 0 74754043 903577600 84167 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7672] ppid=7650 vsize=882400 CPUtime=0
/proc/7663/task/7672/stat : 7672 (java) S 7650 7649 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 11 0 74754043 903577600 84167 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.26
Current children cumulated vsize (KiB) 887536

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

[startup+6.41141 s]
/proc/loadavg: 1.08 1.08 0.81 4/48 7672
/proc/meminfo: memFree=314896/1048576 swapFree=0/0
[pid=7649] ppid=7648 vsize=2564 CPUtime=0
/proc/7649/stat : 7649 (p2cudf-paranoid) S 7648 7649 29493 34817 29493 4202496 372 0 0 0 0 0 0 0 25 0 1 0 74754034 2625536 269 1283457024 134512640 135304128 4293423216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7649/statm: 641 269 230 194 0 28 0
[pid=7650] ppid=7649 vsize=2572 CPUtime=0.02
/proc/7650/stat : 7650 (p2cudf) S 7649 7649 29493 34817 29493 4202496 393 3017 0 1 0 0 1 1 25 0 1 0 74754034 2633728 281 1283457024 134512640 135304128 4294642096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7650/statm: 643 281 239 194 0 30 0
[pid=7663] ppid=7650 vsize=882400 CPUtime=6.34
/proc/7663/stat : 7663 (java) S 7650 7649 29493 34817 29493 4202496 88686 0 1 0 594 40 0 0 25 0 11 0 74754038 903577600 84167 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/7663/statm: 220600 84167 1778 10 0 217691 0
[pid=7663/tid=7664] ppid=7650 vsize=882400 CPUtime=3.3
/proc/7663/task/7664/stat : 7664 (java) R 7650 7649 29493 34817 29493 4202560 50260 0 1 0 302 28 0 0 25 0 11 0 74754038 903577600 84167 1283457024 134512640 134550932 4288262704 18446744073709551615 4095647066 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=7663/tid=7665] ppid=7650 vsize=882400 CPUtime=0.59
/proc/7663/task/7665/stat : 7665 (java) S 7650 7649 29493 34817 29493 4202560 25890 0 0 0 52 7 0 0 16 0 11 0 74754040 903577600 84167 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 0 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7666] ppid=7650 vsize=882400 CPUtime=0
/proc/7663/task/7666/stat : 7666 (java) S 7650 7649 29493 34817 29493 4202560 9 0 0 0 0 0 0 0 18 0 11 0 74754040 903577600 84167 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7667] ppid=7650 vsize=882400 CPUtime=0
/proc/7663/task/7667/stat : 7667 (java) S 7650 7649 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 11 0 74754040 903577600 84167 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7668] ppid=7650 vsize=882400 CPUtime=0
/proc/7663/task/7668/stat : 7668 (java) S 7650 7649 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 11 0 74754043 903577600 84167 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7669] ppid=7650 vsize=882400 CPUtime=0.29
/proc/7663/task/7669/stat : 7669 (java) S 7650 7649 29493 34817 29493 4202560 2112 0 0 0 29 0 0 0 18 0 11 0 74754043 903577600 84167 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7670] ppid=7650 vsize=882400 CPUtime=2.12
/proc/7663/task/7670/stat : 7670 (java) S 7650 7649 29493 34817 29493 4202560 9344 0 0 0 208 4 0 0 15 0 11 0 74754043 903577600 84167 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7671] ppid=7650 vsize=882400 CPUtime=0
/proc/7663/task/7671/stat : 7671 (java) S 7650 7649 29493 34817 29493 4202560 0 0 0 0 0 0 0 0 25 0 11 0 74754043 903577600 84167 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7672] ppid=7650 vsize=882400 CPUtime=0
/proc/7663/task/7672/stat : 7672 (java) S 7650 7649 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 11 0 74754043 903577600 84167 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.36
Current children cumulated vsize (KiB) 887536

[startup+7.10419 s]
/proc/loadavg: 1.08 1.08 0.81 2/49 7673
/proc/meminfo: memFree=314640/1048576 swapFree=0/0
[pid=7649] ppid=7648 vsize=2564 CPUtime=0
/proc/7649/stat : 7649 (p2cudf-paranoid) S 7648 7649 29493 34817 29493 4202496 372 0 0 0 0 0 0 0 25 0 1 0 74754034 2625536 269 1283457024 134512640 135304128 4293423216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7649/statm: 641 269 230 194 0 28 0
[pid=7650] ppid=7649 vsize=2572 CPUtime=0.02
/proc/7650/stat : 7650 (p2cudf) S 7649 7649 29493 34817 29493 4202496 393 3017 0 1 0 0 1 1 25 0 1 0 74754034 2633728 281 1283457024 134512640 135304128 4294642096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7650/statm: 643 281 239 194 0 30 0
[pid=7663] ppid=7650 vsize=882724 CPUtime=6.92
/proc/7663/stat : 7663 (java) S 7650 7649 29493 34817 29493 4202496 88713 0 1 0 652 40 0 0 25 0 12 0 74754038 903909376 84194 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/7663/statm: 220681 84194 1779 10 0 217772 0
[pid=7663/tid=7664] ppid=7650 vsize=882724 CPUtime=3.73
/proc/7663/task/7664/stat : 7664 (java) S 7650 7649 29493 34817 29493 4202560 50268 0 1 0 345 28 0 0 25 0 12 0 74754038 903909376 84194 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7665] ppid=7650 vsize=882724 CPUtime=0.59
/proc/7663/task/7665/stat : 7665 (java) S 7650 7649 29493 34817 29493 4202560 25890 0 0 0 52 7 0 0 16 0 12 0 74754040 903909376 84194 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 0 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7666] ppid=7650 vsize=882724 CPUtime=0
/proc/7663/task/7666/stat : 7666 (java) S 7650 7649 29493 34817 29493 4202560 9 0 0 0 0 0 0 0 18 0 12 0 74754040 903909376 84194 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7667] ppid=7650 vsize=882724 CPUtime=0
/proc/7663/task/7667/stat : 7667 (java) S 7650 7649 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 12 0 74754040 903909376 84194 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7668] ppid=7650 vsize=882724 CPUtime=0
/proc/7663/task/7668/stat : 7668 (java) S 7650 7649 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 12 0 74754043 903909376 84194 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7669] ppid=7650 vsize=882724 CPUtime=0.29
/proc/7663/task/7669/stat : 7669 (java) S 7650 7649 29493 34817 29493 4202560 2112 0 0 0 29 0 0 0 18 0 12 0 74754043 903909376 84194 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7670] ppid=7650 vsize=882724 CPUtime=2.27
/proc/7663/task/7670/stat : 7670 (java) S 7650 7649 29493 34817 29493 4202560 9358 0 0 0 223 4 0 0 15 0 12 0 74754043 903909376 84194 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7671] ppid=7650 vsize=882724 CPUtime=0
/proc/7663/task/7671/stat : 7671 (java) S 7650 7649 29493 34817 29493 4202560 0 0 0 0 0 0 0 0 25 0 12 0 74754043 903909376 84194 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7672] ppid=7650 vsize=882724 CPUtime=0
/proc/7663/task/7672/stat : 7672 (java) S 7650 7649 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 12 0 74754043 903909376 84194 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7673] ppid=7650 vsize=882724 CPUtime=0
/proc/7663/task/7673/stat : 7673 (java) S 7650 7649 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 25 0 12 0 74754591 903909376 84194 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.94
Current children cumulated vsize (KiB) 887860

[startup+7.50425 s]
/proc/loadavg: 1.08 1.08 0.81 2/49 7673
/proc/meminfo: memFree=314640/1048576 swapFree=0/0
[pid=7649] ppid=7648 vsize=2564 CPUtime=0
/proc/7649/stat : 7649 (p2cudf-paranoid) S 7648 7649 29493 34817 29493 4202496 372 0 0 0 0 0 0 0 25 0 1 0 74754034 2625536 269 1283457024 134512640 135304128 4293423216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7649/statm: 641 269 230 194 0 28 0
[pid=7650] ppid=7649 vsize=2572 CPUtime=0.02
/proc/7650/stat : 7650 (p2cudf) S 7649 7649 29493 34817 29493 4202496 393 3017 0 1 0 0 1 1 25 0 1 0 74754034 2633728 281 1283457024 134512640 135304128 4294642096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7650/statm: 643 281 239 194 0 30 0
[pid=7663] ppid=7650 vsize=882724 CPUtime=6.92
/proc/7663/stat : 7663 (java) S 7650 7649 29493 34817 29493 4202496 88713 0 1 0 652 40 0 0 25 0 12 0 74754038 903909376 84194 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/7663/statm: 220681 84194 1779 10 0 217772 0
[pid=7663/tid=7664] ppid=7650 vsize=882724 CPUtime=3.73
/proc/7663/task/7664/stat : 7664 (java) S 7650 7649 29493 34817 29493 4202560 50268 0 1 0 345 28 0 0 25 0 12 0 74754038 903909376 84194 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7665] ppid=7650 vsize=882724 CPUtime=0.59
/proc/7663/task/7665/stat : 7665 (java) S 7650 7649 29493 34817 29493 4202560 25890 0 0 0 52 7 0 0 16 0 12 0 74754040 903909376 84194 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 0 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7666] ppid=7650 vsize=882724 CPUtime=0
/proc/7663/task/7666/stat : 7666 (java) S 7650 7649 29493 34817 29493 4202560 9 0 0 0 0 0 0 0 18 0 12 0 74754040 903909376 84194 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7667] ppid=7650 vsize=882724 CPUtime=0
/proc/7663/task/7667/stat : 7667 (java) S 7650 7649 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 12 0 74754040 903909376 84194 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7668] ppid=7650 vsize=882724 CPUtime=0
/proc/7663/task/7668/stat : 7668 (java) S 7650 7649 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 12 0 74754043 903909376 84194 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7669] ppid=7650 vsize=882724 CPUtime=0.29
/proc/7663/task/7669/stat : 7669 (java) S 7650 7649 29493 34817 29493 4202560 2112 0 0 0 29 0 0 0 18 0 12 0 74754043 903909376 84194 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7670] ppid=7650 vsize=882724 CPUtime=2.27
/proc/7663/task/7670/stat : 7670 (java) S 7650 7649 29493 34817 29493 4202560 9358 0 0 0 223 4 0 0 15 0 12 0 74754043 903909376 84194 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7671] ppid=7650 vsize=882724 CPUtime=0
/proc/7663/task/7671/stat : 7671 (java) S 7650 7649 29493 34817 29493 4202560 0 0 0 0 0 0 0 0 25 0 12 0 74754043 903909376 84194 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7672] ppid=7650 vsize=882724 CPUtime=0
/proc/7663/task/7672/stat : 7672 (java) S 7650 7649 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 12 0 74754043 903909376 84194 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7673] ppid=7650 vsize=882724 CPUtime=0
/proc/7663/task/7673/stat : 7673 (java) S 7650 7649 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 25 0 12 0 74754591 903909376 84194 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.94
Current children cumulated vsize (KiB) 887860

[startup+7.70431 s]
/proc/loadavg: 1.08 1.08 0.81 2/50 7674
/proc/meminfo: memFree=314508/1048576 swapFree=0/0
[pid=7649] ppid=7648 vsize=2564 CPUtime=0
/proc/7649/stat : 7649 (p2cudf-paranoid) S 7648 7649 29493 34817 29493 4202496 372 0 0 0 0 0 0 0 25 0 1 0 74754034 2625536 269 1283457024 134512640 135304128 4293423216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7649/statm: 641 269 230 194 0 28 0
[pid=7650] ppid=7649 vsize=2572 CPUtime=0.02
/proc/7650/stat : 7650 (p2cudf) S 7649 7649 29493 34817 29493 4202496 393 3017 0 1 0 0 1 1 25 0 1 0 74754034 2633728 281 1283457024 134512640 135304128 4294642096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7650/statm: 643 281 239 194 0 30 0
[pid=7663] ppid=7650 vsize=882724 CPUtime=7.11
/proc/7663/stat : 7663 (java) S 7650 7649 29493 34817 29493 4202496 88724 0 1 0 667 44 0 0 25 0 12 0 74754038 903909376 84205 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/7663/statm: 220681 84205 1779 10 0 217772 0
[pid=7663/tid=7664] ppid=7650 vsize=882724 CPUtime=3.73
/proc/7663/task/7664/stat : 7664 (java) S 7650 7649 29493 34817 29493 4202560 50268 0 1 0 345 28 0 0 25 0 12 0 74754038 903909376 84205 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7665] ppid=7650 vsize=882724 CPUtime=0.59
/proc/7663/task/7665/stat : 7665 (java) S 7650 7649 29493 34817 29493 4202560 25890 0 0 0 52 7 0 0 16 0 12 0 74754040 903909376 84205 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 0 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7666] ppid=7650 vsize=882724 CPUtime=0
/proc/7663/task/7666/stat : 7666 (java) S 7650 7649 29493 34817 29493 4202560 9 0 0 0 0 0 0 0 18 0 12 0 74754040 903909376 84205 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7667] ppid=7650 vsize=882724 CPUtime=0
/proc/7663/task/7667/stat : 7667 (java) S 7650 7649 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 12 0 74754040 903909376 84205 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7668] ppid=7650 vsize=882724 CPUtime=0
/proc/7663/task/7668/stat : 7668 (java) S 7650 7649 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 12 0 74754043 903909376 84205 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7669] ppid=7650 vsize=882724 CPUtime=0.29
/proc/7663/task/7669/stat : 7669 (java) S 7650 7649 29493 34817 29493 4202560 2112 0 0 0 29 0 0 0 18 0 12 0 74754043 903909376 84205 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7670] ppid=7650 vsize=882724 CPUtime=2.34
/proc/7663/task/7670/stat : 7670 (java) S 7650 7649 29493 34817 29493 4202560 9367 0 0 0 230 4 0 0 15 0 12 0 74754043 903909376 84205 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7671] ppid=7650 vsize=882724 CPUtime=0
/proc/7663/task/7671/stat : 7671 (java) S 7650 7649 29493 34817 29493 4202560 0 0 0 0 0 0 0 0 25 0 12 0 74754043 903909376 84205 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7672] ppid=7650 vsize=882724 CPUtime=0
/proc/7663/task/7672/stat : 7672 (java) S 7650 7649 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 12 0 74754043 903909376 84205 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7673] ppid=7650 vsize=882724 CPUtime=0
/proc/7663/task/7673/stat : 7673 (java) S 7650 7649 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 25 0 12 0 74754591 903909376 84205 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 18446612133396264064 0 0 -1 0 0 0 0
[pid=7663/tid=7674] ppid=7650 vsize=882724 CPUtime=0.12
/proc/7663/task/7674/stat : 7674 (java) R 7650 7649 29493 34817 29493 4202560 7 0 0 0 8 4 0 0 21 0 12 0 74754734 903909376 84205 1283457024 134512640 134550932 4288262704 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 7.13
Current children cumulated vsize (KiB) 887860

Child status: 0
Real time (s): 7.80364
CPU time (s): 7.18045
CPU user time (s): 6.68442
CPU system time (s): 0.496031
CPU usage (%): 92.0141
Max. virtual memory (cumulated for all children) (KiB): 890200

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 6.68442
system time used= 0.496031
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 92529
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= 906
involuntary context switches= 890

runsolver used 0.012 second user time and 0.012 second system time

The end