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/201012091704/p2cudf-user-1.10/29180036-5408-11df-9f57-00163e7a6f5e.cudf.debian-dudf.log.runsolver ./p2cudf-user-1.10 /home/misc2010/data/2010/debian-dudf//29180036-5408-11df-9f57-00163e7a6f5e.cudf /home/misc2010/tmp/201012091704/p2cudf-user-1.10/29180036-5408-11df-9f57-00163e7a6f5e.cudf.debian-dudf.result -changed,-notuptodate,-removed,-new 

Enforcing CPUTime limit (soft limit, will send signal-name then SIGKILL): 290 seconds
Enforcing CPUTime limit (hard limit, will send SIGXCPU): 320 seconds
Enforcing VSIZE limit (soft limit, will send signal-name then SIGKILL): 1150976 KiB
Enforcing VSIZE limit (hard limit, stack expansion will fail with SIGSEGV, brk() and mmap() will return ENOMEM): 1202176 KiB
Current StackSize limit: 8192 KiB


[startup+0 s]
/proc/loadavg: 1.29 1.14 0.97 3/38 3600
/proc/meminfo: memFree=536920/1048576 swapFree=2095372/2097144
[pid=3599] ppid=3598 vsize=2568 CPUtime=0
/proc/3599/stat : 3599 (p2cudf-user-1.1) R 3598 3599 25521 34816 2180 4202496 359 0 0 0 0 0 0 0 25 0 1 0 900947656 2629632 272 1283457024 134512640 135304128 4291407456 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/3599/statm: 642 272 233 194 0 28 0
[pid=3600] ppid=3599 vsize=2568 CPUtime=0
/proc/3600/stat : 3600 (p2cudf-user-1.1) R 3599 3599 25521 34816 2180 4202560 0 0 0 0 0 0 0 0 25 0 1 0 900947656 2629632 39 1283457024 134512640 135304128 4291407456 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/3600/statm: 642 39 0 194 0 28 0

[startup+0.164152 s]
/proc/loadavg: 1.29 1.14 0.97 3/38 3600
/proc/meminfo: memFree=536920/1048576 swapFree=2095372/2097144
[pid=3599] ppid=3598 vsize=2568 CPUtime=0
/proc/3599/stat : 3599 (p2cudf-user-1.1) S 3598 3599 25521 34816 2180 4202496 377 0 0 0 0 0 0 0 25 0 1 0 900947656 2629632 272 1283457024 134512640 135304128 4291407456 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3599/statm: 642 272 233 194 0 28 0
[pid=3600] ppid=3599 vsize=2576 CPUtime=0.03
/proc/3600/stat : 3600 (p2cudf) S 3599 3599 25521 34816 2180 4202496 392 2997 0 1 0 0 2 1 25 0 1 0 900947656 2637824 282 1283457024 134512640 135304128 4292266768 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3600/statm: 644 282 241 194 0 30 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5144

[startup+0.204159 s]
/proc/loadavg: 1.29 1.14 0.97 3/38 3600
/proc/meminfo: memFree=536920/1048576 swapFree=2095372/2097144
[pid=3599] ppid=3598 vsize=2568 CPUtime=0
/proc/3599/stat : 3599 (p2cudf-user-1.1) S 3598 3599 25521 34816 2180 4202496 377 0 0 0 0 0 0 0 25 0 1 0 900947656 2629632 272 1283457024 134512640 135304128 4291407456 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3599/statm: 642 272 233 194 0 28 0
[pid=3600] ppid=3599 vsize=2576 CPUtime=0.03
/proc/3600/stat : 3600 (p2cudf) S 3599 3599 25521 34816 2180 4202496 392 2997 0 1 0 0 2 1 25 0 1 0 900947656 2637824 282 1283457024 134512640 135304128 4292266768 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3600/statm: 644 282 241 194 0 30 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5144

[startup+0.304178 s]
/proc/loadavg: 1.29 1.14 0.97 3/38 3600
/proc/meminfo: memFree=536920/1048576 swapFree=2095372/2097144
[pid=3599] ppid=3598 vsize=2568 CPUtime=0
/proc/3599/stat : 3599 (p2cudf-user-1.1) S 3598 3599 25521 34816 2180 4202496 377 0 0 0 0 0 0 0 25 0 1 0 900947656 2629632 272 1283457024 134512640 135304128 4291407456 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3599/statm: 642 272 233 194 0 28 0
[pid=3600] ppid=3599 vsize=2576 CPUtime=0.03
/proc/3600/stat : 3600 (p2cudf) S 3599 3599 25521 34816 2180 4202496 392 2997 0 1 0 0 2 1 25 0 1 0 900947656 2637824 282 1283457024 134512640 135304128 4292266768 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3600/statm: 644 282 241 194 0 30 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5144

[startup+0.704241 s]
/proc/loadavg: 1.29 1.14 0.97 3/38 3600
/proc/meminfo: memFree=536920/1048576 swapFree=2095372/2097144
[pid=3599] ppid=3598 vsize=2568 CPUtime=0
/proc/3599/stat : 3599 (p2cudf-user-1.1) S 3598 3599 25521 34816 2180 4202496 377 0 0 0 0 0 0 0 25 0 1 0 900947656 2629632 272 1283457024 134512640 135304128 4291407456 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3599/statm: 642 272 233 194 0 28 0
[pid=3600] ppid=3599 vsize=2576 CPUtime=0.03
/proc/3600/stat : 3600 (p2cudf) S 3599 3599 25521 34816 2180 4202496 392 2997 0 1 0 0 2 1 25 0 1 0 900947656 2637824 282 1283457024 134512640 135304128 4292266768 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3600/statm: 644 282 241 194 0 30 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5144

[startup+1.50436 s]
/proc/loadavg: 1.29 1.14 0.97 3/49 3622
/proc/meminfo: memFree=486200/1048576 swapFree=2095372/2097144
[pid=3599] ppid=3598 vsize=2568 CPUtime=0
/proc/3599/stat : 3599 (p2cudf-user-1.1) S 3598 3599 25521 34816 2180 4202496 377 0 0 0 0 0 0 0 25 0 1 0 900947656 2629632 272 1283457024 134512640 135304128 4291407456 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3599/statm: 642 272 233 194 0 28 0
[pid=3600] ppid=3599 vsize=2576 CPUtime=0.03
/proc/3600/stat : 3600 (p2cudf) S 3599 3599 25521 34816 2180 4202496 392 2997 0 1 0 0 2 1 25 0 1 0 900947656 2637824 282 1283457024 134512640 135304128 4292266768 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3600/statm: 644 282 241 194 0 30 0
[pid=3613] ppid=3600 vsize=873704 CPUtime=1.46
/proc/3613/stat : 3613 (java) S 3600 3599 25521 34816 2180 4202496 18561 0 1 0 140 6 0 0 25 0 10 0 900947659 894672896 16648 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/3613/statm: 218426 16648 1742 10 0 215516 0
[pid=3613/tid=3614] ppid=3600 vsize=873704 CPUtime=0.78
/proc/3613/task/3614/stat : 3614 (java) R 3600 3599 25521 34816 2180 4202560 11205 0 1 0 74 4 0 0 25 0 10 0 900947660 894672896 16648 1283457024 134512640 134550932 4291540288 18446744073709551615 4153044232 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=3613/tid=3615] ppid=3600 vsize=873704 CPUtime=0
/proc/3613/task/3615/stat : 3615 (java) S 3600 3599 25521 34816 2180 4202560 5 0 0 0 0 0 0 0 18 0 10 0 900947662 894672896 16648 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 0 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3616] ppid=3600 vsize=873704 CPUtime=0
/proc/3613/task/3616/stat : 3616 (java) S 3600 3599 25521 34816 2180 4202560 9 0 0 0 0 0 0 0 25 0 10 0 900947662 894672896 16648 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3617] ppid=3600 vsize=873704 CPUtime=0
/proc/3613/task/3617/stat : 3617 (java) S 3600 3599 25521 34816 2180 4202560 4 0 0 0 0 0 0 0 25 0 10 0 900947662 894672896 16648 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3618] ppid=3600 vsize=873704 CPUtime=0
/proc/3613/task/3618/stat : 3618 (java) S 3600 3599 25521 34816 2180 4202560 1 0 0 0 0 0 0 0 25 0 10 0 900947665 894672896 16648 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3619] ppid=3600 vsize=873704 CPUtime=0.36
/proc/3613/task/3619/stat : 3619 (java) R 3600 3599 25521 34816 2180 4202560 2993 0 0 0 36 0 0 0 25 0 10 0 900947665 894672896 16648 1283457024 134512640 134550932 4291540288 18446744073709551615 4148962934 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=3613/tid=3620] ppid=3600 vsize=873704 CPUtime=0.28
/proc/3613/task/3620/stat : 3620 (java) R 3600 3599 25521 34816 2180 4202560 3250 0 0 0 28 0 0 0 22 0 10 0 900947665 894672896 16648 1283457024 134512640 134550932 4291540288 18446744073709551615 4151814274 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=3613/tid=3621] ppid=3600 vsize=873704 CPUtime=0
/proc/3613/task/3621/stat : 3621 (java) S 3600 3599 25521 34816 2180 4202560 1 0 0 0 0 0 0 0 25 0 10 0 900947665 894672896 16648 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3622] ppid=3600 vsize=873704 CPUtime=0.01
/proc/3613/task/3622/stat : 3622 (java) S 3600 3599 25521 34816 2180 4202560 1 0 0 0 0 1 0 0 15 0 10 0 900947665 894672896 16648 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.49
Current children cumulated vsize (KiB) 878848

[startup+3.10534 s]
/proc/loadavg: 1.43 1.17 0.98 3/49 3622
/proc/meminfo: memFree=421324/1048576 swapFree=2095372/2097144
[pid=3599] ppid=3598 vsize=2568 CPUtime=0
/proc/3599/stat : 3599 (p2cudf-user-1.1) S 3598 3599 25521 34816 2180 4202496 377 0 0 0 0 0 0 0 25 0 1 0 900947656 2629632 272 1283457024 134512640 135304128 4291407456 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3599/statm: 642 272 233 194 0 28 0
[pid=3600] ppid=3599 vsize=2576 CPUtime=0.03
/proc/3600/stat : 3600 (p2cudf) S 3599 3599 25521 34816 2180 4202496 392 2997 0 1 0 0 2 1 25 0 1 0 900947656 2637824 282 1283457024 134512640 135304128 4292266768 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3600/statm: 644 282 241 194 0 30 0
[pid=3613] ppid=3600 vsize=882056 CPUtime=3.02
/proc/3613/stat : 3613 (java) S 3600 3599 25521 34816 2180 4202496 46130 0 1 0 288 14 0 0 25 0 10 0 900947659 903225344 42301 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/3613/statm: 220514 42301 1764 10 0 217604 0
[pid=3613/tid=3614] ppid=3600 vsize=882056 CPUtime=1.38
/proc/3613/task/3614/stat : 3614 (java) R 3600 3599 25521 34816 2180 4202560 34509 0 1 0 127 11 0 0 25 0 10 0 900947660 903225344 42301 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=3613/tid=3615] ppid=3600 vsize=882056 CPUtime=0
/proc/3613/task/3615/stat : 3615 (java) R 3600 3599 25521 34816 2180 4202560 5 0 0 0 0 0 0 0 18 0 10 0 900947662 903225344 42301 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=3613/tid=3616] ppid=3600 vsize=882056 CPUtime=0
/proc/3613/task/3616/stat : 3616 (java) S 3600 3599 25521 34816 2180 4202560 9 0 0 0 0 0 0 0 25 0 10 0 900947662 903225344 42301 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3617] ppid=3600 vsize=882056 CPUtime=0
/proc/3613/task/3617/stat : 3617 (java) S 3600 3599 25521 34816 2180 4202560 4 0 0 0 0 0 0 0 25 0 10 0 900947662 903225344 42301 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3618] ppid=3600 vsize=882056 CPUtime=0
/proc/3613/task/3618/stat : 3618 (java) S 3600 3599 25521 34816 2180 4202560 1 0 0 0 0 0 0 0 25 0 10 0 900947665 903225344 42301 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3619] ppid=3600 vsize=882056 CPUtime=0.6
/proc/3613/task/3619/stat : 3619 (java) R 3600 3599 25521 34816 2180 4202560 4636 0 0 0 60 0 0 0 16 0 10 0 900947665 903225344 42301 1283457024 134512640 134550932 4291540288 18446744073709551615 4150193788 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=3613/tid=3620] ppid=3600 vsize=882056 CPUtime=1
/proc/3613/task/3620/stat : 3620 (java) R 3600 3599 25521 34816 2180 4202560 5872 0 0 0 99 1 0 0 20 0 10 0 900947665 903225344 42301 1283457024 134512640 134550932 4291540288 18446744073709551615 4149092673 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=3613/tid=3621] ppid=3600 vsize=882056 CPUtime=0
/proc/3613/task/3621/stat : 3621 (java) S 3600 3599 25521 34816 2180 4202560 1 0 0 0 0 0 0 0 25 0 10 0 900947665 903225344 42301 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3622] ppid=3600 vsize=882056 CPUtime=0.01
/proc/3613/task/3622/stat : 3622 (java) S 3600 3599 25521 34816 2180 4202560 1 0 0 0 0 1 0 0 15 0 10 0 900947665 903225344 42301 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.05
Current children cumulated vsize (KiB) 887200

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

[startup+3.20536 s]
/proc/loadavg: 1.43 1.17 0.98 3/49 3622
/proc/meminfo: memFree=421324/1048576 swapFree=2095372/2097144
[pid=3599] ppid=3598 vsize=2568 CPUtime=0
/proc/3599/stat : 3599 (p2cudf-user-1.1) S 3598 3599 25521 34816 2180 4202496 377 0 0 0 0 0 0 0 25 0 1 0 900947656 2629632 272 1283457024 134512640 135304128 4291407456 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3599/statm: 642 272 233 194 0 28 0
[pid=3600] ppid=3599 vsize=2576 CPUtime=0.03
/proc/3600/stat : 3600 (p2cudf) S 3599 3599 25521 34816 2180 4202496 392 2997 0 1 0 0 2 1 25 0 1 0 900947656 2637824 282 1283457024 134512640 135304128 4292266768 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3600/statm: 644 282 241 194 0 30 0
[pid=3613] ppid=3600 vsize=882384 CPUtime=3.12
/proc/3613/stat : 3613 (java) S 3600 3599 25521 34816 2180 4202496 46598 0 1 0 298 14 0 0 25 0 10 0 900947659 903561216 42391 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/3613/statm: 220596 42391 1764 10 0 217686 0
[pid=3613/tid=3614] ppid=3600 vsize=882384 CPUtime=1.38
/proc/3613/task/3614/stat : 3614 (java) R 3600 3599 25521 34816 2180 4202560 34509 0 1 0 127 11 0 0 25 0 10 0 900947660 903561216 42391 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=3613/tid=3615] ppid=3600 vsize=882384 CPUtime=0
/proc/3613/task/3615/stat : 3615 (java) R 3600 3599 25521 34816 2180 4202560 5 0 0 0 0 0 0 0 18 0 10 0 900947662 903561216 42391 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=3613/tid=3616] ppid=3600 vsize=882384 CPUtime=0
/proc/3613/task/3616/stat : 3616 (java) S 3600 3599 25521 34816 2180 4202560 9 0 0 0 0 0 0 0 25 0 10 0 900947662 903561216 42391 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3617] ppid=3600 vsize=882384 CPUtime=0
/proc/3613/task/3617/stat : 3617 (java) S 3600 3599 25521 34816 2180 4202560 4 0 0 0 0 0 0 0 25 0 10 0 900947662 903561216 42391 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3618] ppid=3600 vsize=882384 CPUtime=0
/proc/3613/task/3618/stat : 3618 (java) S 3600 3599 25521 34816 2180 4202560 1 0 0 0 0 0 0 0 25 0 10 0 900947665 903561216 42391 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3619] ppid=3600 vsize=882384 CPUtime=0.7
/proc/3613/task/3619/stat : 3619 (java) R 3600 3599 25521 34816 2180 4202560 5104 0 0 0 70 0 0 0 16 0 10 0 900947665 903561216 42391 1283457024 134512640 134550932 4291540288 18446744073709551615 4149130596 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=3613/tid=3620] ppid=3600 vsize=882384 CPUtime=1
/proc/3613/task/3620/stat : 3620 (java) R 3600 3599 25521 34816 2180 4202560 5872 0 0 0 99 1 0 0 20 0 10 0 900947665 903561216 42391 1283457024 134512640 134550932 4291540288 18446744073709551615 4149092673 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=3613/tid=3621] ppid=3600 vsize=882384 CPUtime=0
/proc/3613/task/3621/stat : 3621 (java) S 3600 3599 25521 34816 2180 4202560 1 0 0 0 0 0 0 0 25 0 10 0 900947665 903561216 42391 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3622] ppid=3600 vsize=882384 CPUtime=0.01
/proc/3613/task/3622/stat : 3622 (java) S 3600 3599 25521 34816 2180 4202560 1 0 0 0 0 1 0 0 15 0 10 0 900947665 903561216 42391 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.15
Current children cumulated vsize (KiB) 887528

[startup+4.80584 s]
/proc/loadavg: 1.43 1.17 0.98 3/50 3623
/proc/meminfo: memFree=322252/1048576 swapFree=2095372/2097144
[pid=3599] ppid=3598 vsize=2568 CPUtime=0
/proc/3599/stat : 3599 (p2cudf-user-1.1) S 3598 3599 25521 34816 2180 4202496 377 0 0 0 0 0 0 0 25 0 1 0 900947656 2629632 272 1283457024 134512640 135304128 4291407456 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3599/statm: 642 272 233 194 0 28 0
[pid=3600] ppid=3599 vsize=2576 CPUtime=0.03
/proc/3600/stat : 3600 (p2cudf) S 3599 3599 25521 34816 2180 4202496 392 2997 0 1 0 0 2 1 25 0 1 0 900947656 2637824 282 1283457024 134512640 135304128 4292266768 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3600/statm: 644 282 241 194 0 30 0
[pid=3613] ppid=3600 vsize=879120 CPUtime=4.73
/proc/3613/stat : 3613 (java) S 3600 3599 25521 34816 2180 4202496 58659 0 1 0 455 18 0 0 25 0 11 0 900947659 900218880 53253 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/3613/statm: 219780 53253 1789 10 0 216870 0
[pid=3613/tid=3614] ppid=3600 vsize=879120 CPUtime=2.23
/proc/3613/task/3614/stat : 3614 (java) R 3600 3599 25521 34816 2180 4202560 45969 0 1 0 209 14 0 0 25 0 11 0 900947660 900218880 53253 1283457024 134512640 134550932 4291540288 18446744073709551615 4096398791 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=3613/tid=3615] ppid=3600 vsize=879120 CPUtime=0
/proc/3613/task/3615/stat : 3615 (java) S 3600 3599 25521 34816 2180 4202560 5 0 0 0 0 0 0 0 15 0 11 0 900947662 900218880 53253 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 0 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3616] ppid=3600 vsize=879120 CPUtime=0
/proc/3613/task/3616/stat : 3616 (java) S 3600 3599 25521 34816 2180 4202560 9 0 0 0 0 0 0 0 25 0 11 0 900947662 900218880 53253 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3617] ppid=3600 vsize=879120 CPUtime=0
/proc/3613/task/3617/stat : 3617 (java) S 3600 3599 25521 34816 2180 4202560 4 0 0 0 0 0 0 0 25 0 11 0 900947662 900218880 53253 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3618] ppid=3600 vsize=879120 CPUtime=0
/proc/3613/task/3618/stat : 3618 (java) S 3600 3599 25521 34816 2180 4202560 1 0 0 0 0 0 0 0 25 0 11 0 900947665 900218880 53253 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3619] ppid=3600 vsize=879120 CPUtime=0.8
/proc/3613/task/3619/stat : 3619 (java) S 3600 3599 25521 34816 2180 4202560 5607 0 0 0 80 0 0 0 15 0 11 0 900947665 900218880 53253 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3620] ppid=3600 vsize=879120 CPUtime=1.65
/proc/3613/task/3620/stat : 3620 (java) S 3600 3599 25521 34816 2180 4202560 5966 0 0 0 164 1 0 0 15 0 11 0 900947665 900218880 53253 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3621] ppid=3600 vsize=879120 CPUtime=0
/proc/3613/task/3621/stat : 3621 (java) S 3600 3599 25521 34816 2180 4202560 1 0 0 0 0 0 0 0 25 0 11 0 900947665 900218880 53253 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3622] ppid=3600 vsize=879120 CPUtime=0.01
/proc/3613/task/3622/stat : 3622 (java) S 3600 3599 25521 34816 2180 4202560 1 0 0 0 0 1 0 0 15 0 11 0 900947665 900218880 53253 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3623] ppid=3600 vsize=879120 CPUtime=0
/proc/3613/task/3623/stat : 3623 (java) S 3600 3599 25521 34816 2180 4202560 4 0 0 0 0 0 0 0 25 0 11 0 900948064 900218880 53253 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.76
Current children cumulated vsize (KiB) 884264

[startup+5.60445 s]
/proc/loadavg: 1.43 1.17 0.98 1/51 3624
/proc/meminfo: memFree=314060/1048576 swapFree=2095372/2097144
[pid=3599] ppid=3598 vsize=2568 CPUtime=0
/proc/3599/stat : 3599 (p2cudf-user-1.1) S 3598 3599 25521 34816 2180 4202496 377 0 0 0 0 0 0 0 25 0 1 0 900947656 2629632 272 1283457024 134512640 135304128 4291407456 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3599/statm: 642 272 233 194 0 28 0
[pid=3600] ppid=3599 vsize=2576 CPUtime=0.03
/proc/3600/stat : 3600 (p2cudf) S 3599 3599 25521 34816 2180 4202496 392 2997 0 1 0 0 2 1 25 0 1 0 900947656 2637824 282 1283457024 134512640 135304128 4292266768 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3600/statm: 644 282 241 194 0 30 0
[pid=3613] ppid=3600 vsize=879444 CPUtime=5.13
/proc/3613/stat : 3613 (java) S 3600 3599 25521 34816 2180 4202496 60191 0 1 0 495 18 0 0 25 0 12 0 900947659 900550656 54785 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/3613/statm: 219861 54785 1789 10 0 216951 0
[pid=3613/tid=3614] ppid=3600 vsize=879444 CPUtime=2.44
/proc/3613/task/3614/stat : 3614 (java) S 3600 3599 25521 34816 2180 4202560 47478 0 1 0 230 14 0 0 25 0 12 0 900947660 900550656 54785 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3615] ppid=3600 vsize=879444 CPUtime=0
/proc/3613/task/3615/stat : 3615 (java) S 3600 3599 25521 34816 2180 4202560 5 0 0 0 0 0 0 0 15 0 12 0 900947662 900550656 54785 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 0 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3616] ppid=3600 vsize=879444 CPUtime=0
/proc/3613/task/3616/stat : 3616 (java) S 3600 3599 25521 34816 2180 4202560 9 0 0 0 0 0 0 0 25 0 12 0 900947662 900550656 54785 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3617] ppid=3600 vsize=879444 CPUtime=0
/proc/3613/task/3617/stat : 3617 (java) S 3600 3599 25521 34816 2180 4202560 4 0 0 0 0 0 0 0 25 0 12 0 900947662 900550656 54785 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3618] ppid=3600 vsize=879444 CPUtime=0
/proc/3613/task/3618/stat : 3618 (java) S 3600 3599 25521 34816 2180 4202560 1 0 0 0 0 0 0 0 25 0 12 0 900947665 900550656 54785 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3619] ppid=3600 vsize=879444 CPUtime=0.8
/proc/3613/task/3619/stat : 3619 (java) S 3600 3599 25521 34816 2180 4202560 5607 0 0 0 80 0 0 0 15 0 12 0 900947665 900550656 54785 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3620] ppid=3600 vsize=879444 CPUtime=1.84
/proc/3613/task/3620/stat : 3620 (java) S 3600 3599 25521 34816 2180 4202560 5985 0 0 0 183 1 0 0 16 0 12 0 900947665 900550656 54785 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3621] ppid=3600 vsize=879444 CPUtime=0
/proc/3613/task/3621/stat : 3621 (java) S 3600 3599 25521 34816 2180 4202560 1 0 0 0 0 0 0 0 25 0 12 0 900947665 900550656 54785 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3622] ppid=3600 vsize=879444 CPUtime=0.01
/proc/3613/task/3622/stat : 3622 (java) S 3600 3599 25521 34816 2180 4202560 1 0 0 0 0 1 0 0 15 0 12 0 900947665 900550656 54785 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3623] ppid=3600 vsize=879444 CPUtime=0
/proc/3613/task/3623/stat : 3623 (java) S 3600 3599 25521 34816 2180 4202560 4 0 0 0 0 0 0 0 25 0 12 0 900948064 900550656 54785 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3624] ppid=3600 vsize=879444 CPUtime=0
/proc/3613/task/3624/stat : 3624 (java) S 3600 3599 25521 34816 2180 4202560 4 0 0 0 0 0 0 0 25 0 12 0 900948177 900550656 54785 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 5.16
Current children cumulated vsize (KiB) 884588

[startup+5.80649 s]
/proc/loadavg: 1.43 1.17 0.98 1/51 3624
/proc/meminfo: memFree=314060/1048576 swapFree=2095372/2097144
[pid=3599] ppid=3598 vsize=2568 CPUtime=0
/proc/3599/stat : 3599 (p2cudf-user-1.1) S 3598 3599 25521 34816 2180 4202496 377 0 0 0 0 0 0 0 25 0 1 0 900947656 2629632 272 1283457024 134512640 135304128 4291407456 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3599/statm: 642 272 233 194 0 28 0
[pid=3600] ppid=3599 vsize=2576 CPUtime=0.03
/proc/3600/stat : 3600 (p2cudf) S 3599 3599 25521 34816 2180 4202496 392 2997 0 1 0 0 2 1 25 0 1 0 900947656 2637824 282 1283457024 134512640 135304128 4292266768 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3600/statm: 644 282 241 194 0 30 0
[pid=3613] ppid=3600 vsize=879444 CPUtime=5.21
/proc/3613/stat : 3613 (java) S 3600 3599 25521 34816 2180 4202496 60404 0 1 0 499 22 0 0 25 0 12 0 900947659 900550656 54998 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/3613/statm: 219861 54998 1789 10 0 216951 0
[pid=3613/tid=3614] ppid=3600 vsize=879444 CPUtime=2.44
/proc/3613/task/3614/stat : 3614 (java) S 3600 3599 25521 34816 2180 4202560 47478 0 1 0 230 14 0 0 25 0 12 0 900947660 900550656 54998 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3615] ppid=3600 vsize=879444 CPUtime=0
/proc/3613/task/3615/stat : 3615 (java) S 3600 3599 25521 34816 2180 4202560 5 0 0 0 0 0 0 0 15 0 12 0 900947662 900550656 54998 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 0 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3616] ppid=3600 vsize=879444 CPUtime=0
/proc/3613/task/3616/stat : 3616 (java) S 3600 3599 25521 34816 2180 4202560 9 0 0 0 0 0 0 0 25 0 12 0 900947662 900550656 54998 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3617] ppid=3600 vsize=879444 CPUtime=0
/proc/3613/task/3617/stat : 3617 (java) S 3600 3599 25521 34816 2180 4202560 4 0 0 0 0 0 0 0 25 0 12 0 900947662 900550656 54998 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3618] ppid=3600 vsize=879444 CPUtime=0
/proc/3613/task/3618/stat : 3618 (java) S 3600 3599 25521 34816 2180 4202560 1 0 0 0 0 0 0 0 25 0 12 0 900947665 900550656 54998 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3619] ppid=3600 vsize=879444 CPUtime=0.8
/proc/3613/task/3619/stat : 3619 (java) S 3600 3599 25521 34816 2180 4202560 5607 0 0 0 80 0 0 0 15 0 12 0 900947665 900550656 54998 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3620] ppid=3600 vsize=879444 CPUtime=1.85
/proc/3613/task/3620/stat : 3620 (java) S 3600 3599 25521 34816 2180 4202560 5985 0 0 0 184 1 0 0 15 0 12 0 900947665 900550656 54998 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3621] ppid=3600 vsize=879444 CPUtime=0
/proc/3613/task/3621/stat : 3621 (java) S 3600 3599 25521 34816 2180 4202560 1 0 0 0 0 0 0 0 25 0 12 0 900947665 900550656 54998 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3622] ppid=3600 vsize=879444 CPUtime=0.01
/proc/3613/task/3622/stat : 3622 (java) S 3600 3599 25521 34816 2180 4202560 1 0 0 0 0 1 0 0 15 0 12 0 900947665 900550656 54998 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3623] ppid=3600 vsize=879444 CPUtime=0
/proc/3613/task/3623/stat : 3623 (java) S 3600 3599 25521 34816 2180 4202560 4 0 0 0 0 0 0 0 25 0 12 0 900948064 900550656 54998 1283457024 134512640 134550932 4291540288 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=3613/tid=3624] ppid=3600 vsize=879444 CPUtime=0.08
/proc/3613/task/3624/stat : 3624 (java) R 3600 3599 25521 34816 2180 4202560 217 0 0 0 4 4 0 0 20 0 12 0 900948177 900550656 54998 1283457024 134512640 134550932 4291540288 18446744073709551615 4095366385 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 5.24
Current children cumulated vsize (KiB) 884588

Child status: 0
Real time (s): 5.89216
CPU time (s): 5.32833
CPU user time (s): 5.06832
CPU system time (s): 0.260016
CPU usage (%): 90.4309
Max. virtual memory (cumulated for all children) (KiB): 887528

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 5.06832
system time used= 0.260016
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 64242
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= 770
involuntary context switches= 788

runsolver used 0 second user time and 0 second system time

The end