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/688250e8-4bb4-11df-a561-00163e7a6f5e.cudf.debian.log.runsolver ./p2cudf-paranoid-1.12 /home/misc2010/data/misc4/debian//688250e8-4bb4-11df-a561-00163e7a6f5e.cudf /home/misc2010/tmp/201103031013/p2cudf-paranoid-1.12/688250e8-4bb4-11df-a561-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.02 1.05 1.04 2/35 5925
/proc/meminfo: memFree=647640/1048576 swapFree=0/0
[pid=5925] ppid=5924 vsize=3016 CPUtime=0
/proc/5925/stat : 5925 (runsolver) D 5924 5925 29493 34817 29493 4202560 72 0 0 0 0 0 0 0 24 0 1 0 75244469 3088384 93 1283457024 134512640 134586868 4286912944 18446744073709551615 4294960130 0 0 0 24578 18446744071564332000 0 0 17 0 0 0 0
/proc/5925/statm: 754 93 62 19 0 53 0

[startup+0.186784 s]
/proc/loadavg: 1.02 1.05 1.04 2/35 5925
/proc/meminfo: memFree=647640/1048576 swapFree=0/0
[pid=5925] ppid=5924 vsize=2572 CPUtime=0
/proc/5925/stat : 5925 (p2cudf-paranoid) S 5924 5925 29493 34817 29493 4202496 375 0 0 0 0 0 0 0 25 0 1 0 75244469 2633728 271 1283457024 134512640 135304128 4290139472 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5925/statm: 643 271 230 194 0 30 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2572

[startup+0.206738 s]
/proc/loadavg: 1.02 1.05 1.04 2/35 5925
/proc/meminfo: memFree=647640/1048576 swapFree=0/0
[pid=5925] ppid=5924 vsize=2572 CPUtime=0
/proc/5925/stat : 5925 (p2cudf-paranoid) S 5924 5925 29493 34817 29493 4202496 375 0 0 0 0 0 0 0 25 0 1 0 75244469 2633728 271 1283457024 134512640 135304128 4290139472 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5925/statm: 643 271 230 194 0 30 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2572

[startup+0.306769 s]
/proc/loadavg: 1.02 1.05 1.04 2/35 5925
/proc/meminfo: memFree=647640/1048576 swapFree=0/0
[pid=5925] ppid=5924 vsize=2572 CPUtime=0
/proc/5925/stat : 5925 (p2cudf-paranoid) S 5924 5925 29493 34817 29493 4202496 375 0 0 0 0 0 0 0 25 0 1 0 75244469 2633728 271 1283457024 134512640 135304128 4290139472 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5925/statm: 643 271 230 194 0 30 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2572

[startup+0.706795 s]
/proc/loadavg: 1.02 1.05 1.04 2/35 5925
/proc/meminfo: memFree=647640/1048576 swapFree=0/0
[pid=5925] ppid=5924 vsize=2572 CPUtime=0
/proc/5925/stat : 5925 (p2cudf-paranoid) S 5924 5925 29493 34817 29493 4202496 375 0 0 0 0 0 0 0 25 0 1 0 75244469 2633728 271 1283457024 134512640 135304128 4290139472 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5925/statm: 643 271 230 194 0 30 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2572

[startup+1.5069 s]
/proc/loadavg: 1.02 1.05 1.04 2/39 5940
/proc/meminfo: memFree=624072/1048576 swapFree=0/0
[pid=5925] ppid=5924 vsize=2572 CPUtime=0
/proc/5925/stat : 5925 (p2cudf-paranoid) S 5924 5925 29493 34817 29493 4202496 375 0 0 0 0 0 0 0 25 0 1 0 75244469 2633728 271 1283457024 134512640 135304128 4290139472 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5925/statm: 643 271 230 194 0 30 0
[pid=5927] ppid=5925 vsize=2572 CPUtime=0
/proc/5927/stat : 5927 (p2cudf) S 5925 5925 29493 34817 29493 4202496 392 2791 0 142 0 0 0 0 18 0 1 0 75244470 2633728 280 1283457024 134512640 135304128 4292763616 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5927/statm: 643 280 239 194 0 30 0
[pid=5939] ppid=5927 vsize=855372 CPUtime=0.02
/proc/5939/stat : 5939 (java) S 5927 5925 29493 34817 29493 4202496 3115 0 138 0 2 0 0 0 18 0 10 0 75244542 875900928 2980 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/5939/statm: 213843 2980 1350 10 0 210934 0
[pid=5939/tid=5940] ppid=5927 vsize=855372 CPUtime=0.02
/proc/5939/task/5940/stat : 5940 (java) D 5927 5925 29493 34817 29493 4202560 2098 0 56 0 2 0 0 0 20 0 10 0 75244569 875900928 2980 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446744071564332000 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 860516

[startup+3.11582 s]
/proc/loadavg: 1.02 1.05 1.04 3/47 5948
/proc/meminfo: memFree=611676/1048576 swapFree=0/0
[pid=5925] ppid=5924 vsize=2572 CPUtime=0
/proc/5925/stat : 5925 (p2cudf-paranoid) S 5924 5925 29493 34817 29493 4202496 375 0 0 0 0 0 0 0 25 0 1 0 75244469 2633728 271 1283457024 134512640 135304128 4290139472 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5925/statm: 643 271 230 194 0 30 0
[pid=5927] ppid=5925 vsize=2572 CPUtime=0
/proc/5927/stat : 5927 (p2cudf) S 5925 5925 29493 34817 29493 4202496 392 2791 0 142 0 0 0 0 18 0 1 0 75244470 2633728 280 1283457024 134512640 135304128 4292763616 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5927/statm: 643 280 239 194 0 30 0
[pid=5939] ppid=5927 vsize=880048 CPUtime=1.19
/proc/5939/stat : 5939 (java) S 5927 5925 29493 34817 29493 4202496 29288 0 146 0 102 17 0 0 18 0 10 0 75244542 901169152 26270 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/5939/statm: 220012 26270 1733 10 0 217103 0
[pid=5939/tid=5940] ppid=5927 vsize=880048 CPUtime=0.52
/proc/5939/task/5940/stat : 5940 (java) R 5927 5925 29493 34817 29493 4202560 18890 0 56 0 41 11 0 0 18 0 10 0 75244569 901169152 26270 1283457024 134512640 134550932 4287529344 18446744073709551615 4095273929 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=5939/tid=5941] ppid=5927 vsize=880048 CPUtime=0
/proc/5939/task/5941/stat : 5941 (java) S 5927 5925 29493 34817 29493 4202560 9 0 0 0 0 0 0 0 16 0 10 0 75244582 901169152 26270 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 0 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5942] ppid=5927 vsize=880048 CPUtime=0
/proc/5939/task/5942/stat : 5942 (java) S 5927 5925 29493 34817 29493 4202560 7 0 1 0 0 0 0 0 19 0 10 0 75244583 901169152 26270 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5943] ppid=5927 vsize=880048 CPUtime=0
/proc/5939/task/5943/stat : 5943 (java) S 5927 5925 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 19 0 10 0 75244584 901169152 26270 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5944] ppid=5927 vsize=880048 CPUtime=0
/proc/5939/task/5944/stat : 5944 (java) S 5927 5925 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 19 0 10 0 75244593 901169152 26270 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5945] ppid=5927 vsize=880048 CPUtime=0.01
/proc/5939/task/5945/stat : 5945 (java) S 5927 5925 29493 34817 29493 4202560 24 0 0 0 1 0 0 0 16 0 10 0 75244593 901169152 26270 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5946] ppid=5927 vsize=880048 CPUtime=0.65
/proc/5939/task/5946/stat : 5946 (java) S 5927 5925 29493 34817 29493 4202560 9373 0 8 0 59 6 0 0 15 0 10 0 75244593 901169152 26270 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5947] ppid=5927 vsize=880048 CPUtime=0
/proc/5939/task/5947/stat : 5947 (java) S 5927 5925 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 20 0 10 0 75244593 901169152 26270 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5948] ppid=5927 vsize=880048 CPUtime=0
/proc/5939/task/5948/stat : 5948 (java) S 5927 5925 29493 34817 29493 4202560 2 0 0 0 0 0 0 0 15 0 10 0 75244593 901169152 26270 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.19
Current children cumulated vsize (KiB) 885192
heavy processes:

[startup+6.30728 s]
/proc/loadavg: 1.18 1.09 1.05 3/47 5948
/proc/meminfo: memFree=348452/1048576 swapFree=0/0
[pid=5925] ppid=5924 vsize=2572 CPUtime=0
/proc/5925/stat : 5925 (p2cudf-paranoid) S 5924 5925 29493 34817 29493 4202496 375 0 0 0 0 0 0 0 25 0 1 0 75244469 2633728 271 1283457024 134512640 135304128 4290139472 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5925/statm: 643 271 230 194 0 30 0
[pid=5927] ppid=5925 vsize=2572 CPUtime=0
/proc/5927/stat : 5927 (p2cudf) S 5925 5925 29493 34817 29493 4202496 392 2791 0 142 0 0 0 0 18 0 1 0 75244470 2633728 280 1283457024 134512640 135304128 4292763616 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5927/statm: 643 280 239 194 0 30 0
[pid=5939] ppid=5927 vsize=880048 CPUtime=4.25
/proc/5939/stat : 5939 (java) S 5927 5925 29493 34817 29493 4202496 87900 0 147 0 387 38 0 0 18 0 10 0 75244542 901169152 82590 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/5939/statm: 220012 82590 1763 10 0 217103 0
[pid=5939/tid=5940] ppid=5927 vsize=880048 CPUtime=1.91
/proc/5939/task/5940/stat : 5940 (java) R 5927 5925 29493 34817 29493 4202560 50149 0 56 0 168 23 0 0 20 0 10 0 75244569 901169152 82590 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=5939/tid=5941] ppid=5927 vsize=880048 CPUtime=0.56
/proc/5939/task/5941/stat : 5941 (java) R 5927 5925 29493 34817 29493 4202560 24948 0 0 0 51 5 0 0 16 0 10 0 75244582 901169152 82590 1283457024 134512640 134550932 4287529344 18446744073709551615 4149832976 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=5939/tid=5942] ppid=5927 vsize=880048 CPUtime=0
/proc/5939/task/5942/stat : 5942 (java) S 5927 5925 29493 34817 29493 4202560 8 0 1 0 0 0 0 0 18 0 10 0 75244583 901169152 82590 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5943] ppid=5927 vsize=880048 CPUtime=0
/proc/5939/task/5943/stat : 5943 (java) S 5927 5925 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 10 0 75244584 901169152 82590 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5944] ppid=5927 vsize=880048 CPUtime=0
/proc/5939/task/5944/stat : 5944 (java) S 5927 5925 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 19 0 10 0 75244593 901169152 82590 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5945] ppid=5927 vsize=880048 CPUtime=1.1
/proc/5939/task/5945/stat : 5945 (java) S 5927 5925 29493 34817 29493 4202560 2435 0 1 0 108 2 0 0 15 0 10 0 75244593 901169152 82590 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5946] ppid=5927 vsize=880048 CPUtime=0.65
/proc/5939/task/5946/stat : 5946 (java) S 5927 5925 29493 34817 29493 4202560 9373 0 8 0 59 6 0 0 15 0 10 0 75244593 901169152 82590 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5947] ppid=5927 vsize=880048 CPUtime=0
/proc/5939/task/5947/stat : 5947 (java) S 5927 5925 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 20 0 10 0 75244593 901169152 82590 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5948] ppid=5927 vsize=880048 CPUtime=0
/proc/5939/task/5948/stat : 5948 (java) S 5927 5925 29493 34817 29493 4202560 2 0 0 0 0 0 0 0 15 0 10 0 75244593 901169152 82590 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.25
Current children cumulated vsize (KiB) 885192
heavy processes:

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

[startup+6.40731 s]
/proc/loadavg: 1.18 1.09 1.05 3/47 5948
/proc/meminfo: memFree=301148/1048576 swapFree=0/0
[pid=5925] ppid=5924 vsize=2572 CPUtime=0
/proc/5925/stat : 5925 (p2cudf-paranoid) S 5924 5925 29493 34817 29493 4202496 375 0 0 0 0 0 0 0 25 0 1 0 75244469 2633728 271 1283457024 134512640 135304128 4290139472 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5925/statm: 643 271 230 194 0 30 0
[pid=5927] ppid=5925 vsize=2572 CPUtime=0
/proc/5927/stat : 5927 (p2cudf) S 5925 5925 29493 34817 29493 4202496 392 2791 0 142 0 0 0 0 18 0 1 0 75244470 2633728 280 1283457024 134512640 135304128 4292763616 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5927/statm: 643 280 239 194 0 30 0
[pid=5939] ppid=5927 vsize=880048 CPUtime=4.35
/proc/5939/stat : 5939 (java) S 5927 5925 29493 34817 29493 4202496 88850 0 147 0 397 38 0 0 18 0 10 0 75244542 901169152 83540 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/5939/statm: 220012 83540 1763 10 0 217103 0
[pid=5939/tid=5940] ppid=5927 vsize=880048 CPUtime=1.98
/proc/5939/task/5940/stat : 5940 (java) R 5927 5925 29493 34817 29493 4202560 50150 0 56 0 175 23 0 0 20 0 10 0 75244569 901169152 83540 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=5939/tid=5941] ppid=5927 vsize=880048 CPUtime=0.58
/proc/5939/task/5941/stat : 5941 (java) S 5927 5925 29493 34817 29493 4202560 25895 0 0 0 53 5 0 0 16 0 10 0 75244582 901169152 83540 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 0 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5942] ppid=5927 vsize=880048 CPUtime=0
/proc/5939/task/5942/stat : 5942 (java) S 5927 5925 29493 34817 29493 4202560 8 0 1 0 0 0 0 0 18 0 10 0 75244583 901169152 83540 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5943] ppid=5927 vsize=880048 CPUtime=0
/proc/5939/task/5943/stat : 5943 (java) S 5927 5925 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 10 0 75244584 901169152 83540 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5944] ppid=5927 vsize=880048 CPUtime=0
/proc/5939/task/5944/stat : 5944 (java) S 5927 5925 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 19 0 10 0 75244593 901169152 83540 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5945] ppid=5927 vsize=880048 CPUtime=1.12
/proc/5939/task/5945/stat : 5945 (java) R 5927 5925 29493 34817 29493 4202560 2437 0 1 0 110 2 0 0 16 0 10 0 75244593 901169152 83540 1283457024 134512640 134550932 4287529344 18446744073709551615 4153179032 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=5939/tid=5946] ppid=5927 vsize=880048 CPUtime=0.65
/proc/5939/task/5946/stat : 5946 (java) S 5927 5925 29493 34817 29493 4202560 9373 0 8 0 59 6 0 0 15 0 10 0 75244593 901169152 83540 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5947] ppid=5927 vsize=880048 CPUtime=0
/proc/5939/task/5947/stat : 5947 (java) S 5927 5925 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 20 0 10 0 75244593 901169152 83540 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5948] ppid=5927 vsize=880048 CPUtime=0
/proc/5939/task/5948/stat : 5948 (java) S 5927 5925 29493 34817 29493 4202560 2 0 0 0 0 0 0 0 15 0 10 0 75244593 901169152 83540 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.35
Current children cumulated vsize (KiB) 885192

[startup+7.21327 s]
/proc/loadavg: 1.18 1.09 1.05 2/47 5948
/proc/meminfo: memFree=297304/1048576 swapFree=0/0
[pid=5925] ppid=5924 vsize=2572 CPUtime=0
/proc/5925/stat : 5925 (p2cudf-paranoid) S 5924 5925 29493 34817 29493 4202496 375 0 0 0 0 0 0 0 25 0 1 0 75244469 2633728 271 1283457024 134512640 135304128 4290139472 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5925/statm: 643 271 230 194 0 30 0
[pid=5927] ppid=5925 vsize=2572 CPUtime=0
/proc/5927/stat : 5927 (p2cudf) S 5925 5925 29493 34817 29493 4202496 392 2791 0 142 0 0 0 0 18 0 1 0 75244470 2633728 280 1283457024 134512640 135304128 4292763616 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5927/statm: 643 280 239 194 0 30 0
[pid=5939] ppid=5927 vsize=880048 CPUtime=5.09
/proc/5939/stat : 5939 (java) S 5927 5925 29493 34817 29493 4202496 88942 0 147 0 471 38 0 0 18 0 10 0 75244542 901169152 83632 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/5939/statm: 220012 83632 1770 10 0 217103 0
[pid=5939/tid=5940] ppid=5927 vsize=880048 CPUtime=2.41
/proc/5939/task/5940/stat : 5940 (java) R 5927 5925 29493 34817 29493 4202560 50201 0 56 0 218 23 0 0 20 0 10 0 75244569 901169152 83632 1283457024 134512640 134550932 4287529344 18446744073709551615 4095102020 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=5939/tid=5941] ppid=5927 vsize=880048 CPUtime=0.58
/proc/5939/task/5941/stat : 5941 (java) S 5927 5925 29493 34817 29493 4202560 25895 0 0 0 53 5 0 0 16 0 10 0 75244582 901169152 83632 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 0 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5942] ppid=5927 vsize=880048 CPUtime=0
/proc/5939/task/5942/stat : 5942 (java) S 5927 5925 29493 34817 29493 4202560 8 0 1 0 0 0 0 0 18 0 10 0 75244583 901169152 83632 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5943] ppid=5927 vsize=880048 CPUtime=0
/proc/5939/task/5943/stat : 5943 (java) S 5927 5925 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 10 0 75244584 901169152 83632 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5944] ppid=5927 vsize=880048 CPUtime=0
/proc/5939/task/5944/stat : 5944 (java) S 5927 5925 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 19 0 10 0 75244593 901169152 83632 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5945] ppid=5927 vsize=880048 CPUtime=1.42
/proc/5939/task/5945/stat : 5945 (java) S 5927 5925 29493 34817 29493 4202560 2478 0 1 0 140 2 0 0 16 0 10 0 75244593 901169152 83632 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5946] ppid=5927 vsize=880048 CPUtime=0.65
/proc/5939/task/5946/stat : 5946 (java) S 5927 5925 29493 34817 29493 4202560 9373 0 8 0 59 6 0 0 15 0 10 0 75244593 901169152 83632 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5947] ppid=5927 vsize=880048 CPUtime=0
/proc/5939/task/5947/stat : 5947 (java) S 5927 5925 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 20 0 10 0 75244593 901169152 83632 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5948] ppid=5927 vsize=880048 CPUtime=0
/proc/5939/task/5948/stat : 5948 (java) S 5927 5925 29493 34817 29493 4202560 2 0 0 0 0 0 0 0 15 0 10 0 75244593 901169152 83632 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 5.09
Current children cumulated vsize (KiB) 885192

[startup+8.00725 s]
/proc/loadavg: 1.24 1.10 1.06 2/48 5949
/proc/meminfo: memFree=296560/1048576 swapFree=0/0
[pid=5925] ppid=5924 vsize=2572 CPUtime=0
/proc/5925/stat : 5925 (p2cudf-paranoid) S 5924 5925 29493 34817 29493 4202496 375 0 0 0 0 0 0 0 25 0 1 0 75244469 2633728 271 1283457024 134512640 135304128 4290139472 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5925/statm: 643 271 230 194 0 30 0
[pid=5927] ppid=5925 vsize=2572 CPUtime=0
/proc/5927/stat : 5927 (p2cudf) S 5925 5925 29493 34817 29493 4202496 392 2791 0 142 0 0 0 0 18 0 1 0 75244470 2633728 280 1283457024 134512640 135304128 4292763616 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5927/statm: 643 280 239 194 0 30 0
[pid=5939] ppid=5927 vsize=880696 CPUtime=5.62
/proc/5939/stat : 5939 (java) S 5927 5925 29493 34817 29493 4202496 89019 0 147 0 524 38 0 0 18 0 12 0 75244542 901832704 83709 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/5939/statm: 220174 83709 1778 10 0 217265 0
[pid=5939/tid=5940] ppid=5927 vsize=880696 CPUtime=2.57
/proc/5939/task/5940/stat : 5940 (java) S 5927 5925 29493 34817 29493 4202560 50219 0 56 0 234 23 0 0 22 0 12 0 75244569 901832704 83709 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5941] ppid=5927 vsize=880696 CPUtime=0.58
/proc/5939/task/5941/stat : 5941 (java) S 5927 5925 29493 34817 29493 4202560 25895 0 0 0 53 5 0 0 16 0 12 0 75244582 901832704 83709 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 0 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5942] ppid=5927 vsize=880696 CPUtime=0
/proc/5939/task/5942/stat : 5942 (java) S 5927 5925 29493 34817 29493 4202560 8 0 1 0 0 0 0 0 18 0 12 0 75244583 901832704 83709 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5943] ppid=5927 vsize=880696 CPUtime=0
/proc/5939/task/5943/stat : 5943 (java) S 5927 5925 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 12 0 75244584 901832704 83709 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5944] ppid=5927 vsize=880696 CPUtime=0
/proc/5939/task/5944/stat : 5944 (java) S 5927 5925 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 19 0 12 0 75244593 901832704 83709 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5945] ppid=5927 vsize=880696 CPUtime=1.79
/proc/5939/task/5945/stat : 5945 (java) S 5927 5925 29493 34817 29493 4202560 2529 0 1 0 177 2 0 0 15 0 12 0 75244593 901832704 83709 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5946] ppid=5927 vsize=880696 CPUtime=0.65
/proc/5939/task/5946/stat : 5946 (java) S 5927 5925 29493 34817 29493 4202560 9373 0 8 0 59 6 0 0 15 0 12 0 75244593 901832704 83709 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5947] ppid=5927 vsize=880696 CPUtime=0
/proc/5939/task/5947/stat : 5947 (java) S 5927 5925 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 20 0 12 0 75244593 901832704 83709 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5948] ppid=5927 vsize=880696 CPUtime=0
/proc/5939/task/5948/stat : 5948 (java) S 5927 5925 29493 34817 29493 4202560 2 0 0 0 0 0 0 0 15 0 12 0 75244593 901832704 83709 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5949] ppid=5927 vsize=880696 CPUtime=0
/proc/5939/task/5949/stat : 5949 (java) S 5927 5925 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 21 0 12 0 75245192 901832704 83709 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 5.62
Current children cumulated vsize (KiB) 885840

[startup+8.4033 s]
/proc/loadavg: 1.24 1.10 1.06 2/48 5949
/proc/meminfo: memFree=296560/1048576 swapFree=0/0
[pid=5925] ppid=5924 vsize=2572 CPUtime=0
/proc/5925/stat : 5925 (p2cudf-paranoid) S 5924 5925 29493 34817 29493 4202496 375 0 0 0 0 0 0 0 25 0 1 0 75244469 2633728 271 1283457024 134512640 135304128 4290139472 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5925/statm: 643 271 230 194 0 30 0
[pid=5927] ppid=5925 vsize=2572 CPUtime=0
/proc/5927/stat : 5927 (p2cudf) S 5925 5925 29493 34817 29493 4202496 392 2791 0 142 0 0 0 0 18 0 1 0 75244470 2633728 280 1283457024 134512640 135304128 4292763616 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5927/statm: 643 280 239 194 0 30 0
[pid=5939] ppid=5927 vsize=880696 CPUtime=5.76
/proc/5939/stat : 5939 (java) S 5927 5925 29493 34817 29493 4202496 89028 0 147 0 536 40 0 0 18 0 12 0 75244542 901832704 83718 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/5939/statm: 220174 83718 1778 10 0 217265 0
[pid=5939/tid=5940] ppid=5927 vsize=880696 CPUtime=2.57
/proc/5939/task/5940/stat : 5940 (java) S 5927 5925 29493 34817 29493 4202560 50219 0 56 0 234 23 0 0 22 0 12 0 75244569 901832704 83718 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5941] ppid=5927 vsize=880696 CPUtime=0.58
/proc/5939/task/5941/stat : 5941 (java) S 5927 5925 29493 34817 29493 4202560 25895 0 0 0 53 5 0 0 16 0 12 0 75244582 901832704 83718 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 0 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5942] ppid=5927 vsize=880696 CPUtime=0
/proc/5939/task/5942/stat : 5942 (java) S 5927 5925 29493 34817 29493 4202560 8 0 1 0 0 0 0 0 18 0 12 0 75244583 901832704 83718 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5943] ppid=5927 vsize=880696 CPUtime=0
/proc/5939/task/5943/stat : 5943 (java) S 5927 5925 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 12 0 75244584 901832704 83718 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5944] ppid=5927 vsize=880696 CPUtime=0
/proc/5939/task/5944/stat : 5944 (java) S 5927 5925 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 19 0 12 0 75244593 901832704 83718 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5945] ppid=5927 vsize=880696 CPUtime=1.86
/proc/5939/task/5945/stat : 5945 (java) R 5927 5925 29493 34817 29493 4202560 2536 0 1 0 184 2 0 0 16 0 12 0 75244593 901832704 83718 1283457024 134512640 134550932 4287529344 18446744073709551615 4152500287 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=5939/tid=5946] ppid=5927 vsize=880696 CPUtime=0.65
/proc/5939/task/5946/stat : 5946 (java) S 5927 5925 29493 34817 29493 4202560 9373 0 8 0 59 6 0 0 15 0 12 0 75244593 901832704 83718 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5947] ppid=5927 vsize=880696 CPUtime=0
/proc/5939/task/5947/stat : 5947 (java) S 5927 5925 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 20 0 12 0 75244593 901832704 83718 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5948] ppid=5927 vsize=880696 CPUtime=0
/proc/5939/task/5948/stat : 5948 (java) S 5927 5925 29493 34817 29493 4202560 2 0 0 0 0 0 0 0 15 0 12 0 75244593 901832704 83718 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
[pid=5939/tid=5949] ppid=5927 vsize=880696 CPUtime=0
/proc/5939/task/5949/stat : 5949 (java) S 5927 5925 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 21 0 12 0 75245192 901832704 83718 1283457024 134512640 134550932 4287529344 18446744073709551615 4294960130 0 4 0 16800975 18446612133392887872 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 5.76
Current children cumulated vsize (KiB) 885840

[startup+8.50957 s]
/proc/loadavg: 1.24 1.10 1.06 2/48 5949
/proc/meminfo: memFree=296560/1048576 swapFree=0/0
[pid=5925] ppid=5924 vsize=2572 CPUtime=0
/proc/5925/stat : 5925 (p2cudf-paranoid) S 5924 5925 29493 34817 29493 4202496 375 0 0 0 0 0 0 0 25 0 1 0 75244469 2633728 271 1283457024 134512640 135304128 4290139472 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5925/statm: 643 271 230 194 0 30 0
[pid=5927] ppid=5925 vsize=2572 CPUtime=0
/proc/5927/stat : 5927 (p2cudf) S 5925 5925 29493 34817 29493 4202496 392 2791 0 142 0 0 0 0 18 0 1 0 75244470 2633728 280 1283457024 134512640 135304128 4292763616 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5927/statm: 643 280 239 194 0 30 0
[pid=5939] ppid=5927 vsize=0 CPUtime=5.83
/proc/5939/stat : 5939 (java) R 5927 5925 29493 34817 29493 4203524 89034 0 147 0 538 45 0 0 18 0 1 0 75244542 0 0 1283457024 0 0 0 0 0 0 0 0 16800975 0 0 0 17 0 0 0 0
/proc/5939/statm: 0 0 0 0 0 0 0
Current children cumulated CPU time (s) 5.83
Current children cumulated vsize (KiB) 5144

Child status: 0
Real time (s): 8.52758
CPU time (s): 5.86837
CPU user time (s): 5.39634
CPU system time (s): 0.472029
CPU usage (%): 68.8163
Max. virtual memory (cumulated for all children) (KiB): 887276

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 5.39634
system time used= 0.472029
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 92611
page faults= 289
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 1699
involuntary context switches= 965

runsolver used 0 second user time and 0.016001 second system time

The end