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/812.cudf.caixa.log.runsolver ./p2cudf-paranoid-1.12 /home/misc2010/data/misc4/caixa//812.cudf /home/misc2010/tmp/201103031013/p2cudf-paranoid-1.12/812.cudf.caixa.result 

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


[startup+0 s]
/proc/loadavg: 1.61 1.75 1.72 5/35 31369
/proc/meminfo: memFree=297816/1048576 swapFree=0/0
[pid=31367] ppid=31366 vsize=2564 CPUtime=0
/proc/31367/stat : 31367 (p2cudf-paranoid) S 31366 31367 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 18 0 1 0 76360614 2625536 269 1283457024 134512640 135304128 4292821024 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31367/statm: 641 269 230 194 0 28 0
[pid=31368] ppid=31367 vsize=2564 CPUtime=0
/proc/31368/stat : 31368 (p2cudf) R 31367 31367 29493 34817 29493 4202496 345 0 0 0 0 0 0 0 25 0 1 0 76360614 2625536 271 1283457024 134512640 135304128 4287773536 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/31368/statm: 641 271 231 194 0 28 0
[pid=31369] ppid=31368 vsize=2564 CPUtime=0
/proc/31369/stat : 31369 (p2cudf) R 31368 31367 29493 34817 29493 4202560 0 0 0 0 0 0 0 0 25 0 1 0 76360614 2625536 40 1283457024 134512640 135304128 4287773536 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/31369/statm: 641 40 0 194 0 28 0

[startup+0.145549 s]
/proc/loadavg: 1.61 1.75 1.72 5/35 31369
/proc/meminfo: memFree=297816/1048576 swapFree=0/0
[pid=31367] ppid=31366 vsize=2564 CPUtime=0
/proc/31367/stat : 31367 (p2cudf-paranoid) S 31366 31367 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 18 0 1 0 76360614 2625536 269 1283457024 134512640 135304128 4292821024 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31367/statm: 641 269 230 194 0 28 0
[pid=31368] ppid=31367 vsize=2572 CPUtime=0.04
/proc/31368/stat : 31368 (p2cudf) S 31367 31367 29493 34817 29493 4202496 393 3018 0 1 0 0 2 2 25 0 1 0 76360614 2633728 281 1283457024 134512640 135304128 4287773536 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31368/statm: 643 281 239 194 0 30 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 5136

[startup+0.205546 s]
/proc/loadavg: 1.61 1.75 1.72 5/35 31369
/proc/meminfo: memFree=297816/1048576 swapFree=0/0
[pid=31367] ppid=31366 vsize=2564 CPUtime=0
/proc/31367/stat : 31367 (p2cudf-paranoid) S 31366 31367 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 18 0 1 0 76360614 2625536 269 1283457024 134512640 135304128 4292821024 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31367/statm: 641 269 230 194 0 28 0
[pid=31368] ppid=31367 vsize=2572 CPUtime=0.04
/proc/31368/stat : 31368 (p2cudf) S 31367 31367 29493 34817 29493 4202496 393 3018 0 1 0 0 2 2 25 0 1 0 76360614 2633728 281 1283457024 134512640 135304128 4287773536 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31368/statm: 643 281 239 194 0 30 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 5136

[startup+0.305563 s]
/proc/loadavg: 1.61 1.75 1.72 5/35 31369
/proc/meminfo: memFree=297816/1048576 swapFree=0/0
[pid=31367] ppid=31366 vsize=2564 CPUtime=0
/proc/31367/stat : 31367 (p2cudf-paranoid) S 31366 31367 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 18 0 1 0 76360614 2625536 269 1283457024 134512640 135304128 4292821024 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31367/statm: 641 269 230 194 0 28 0
[pid=31368] ppid=31367 vsize=2572 CPUtime=0.04
/proc/31368/stat : 31368 (p2cudf) S 31367 31367 29493 34817 29493 4202496 393 3018 0 1 0 0 2 2 25 0 1 0 76360614 2633728 281 1283457024 134512640 135304128 4287773536 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31368/statm: 643 281 239 194 0 30 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 5136

[startup+0.705649 s]
/proc/loadavg: 1.61 1.75 1.72 5/35 31369
/proc/meminfo: memFree=297816/1048576 swapFree=0/0
[pid=31367] ppid=31366 vsize=2564 CPUtime=0
/proc/31367/stat : 31367 (p2cudf-paranoid) S 31366 31367 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 18 0 1 0 76360614 2625536 269 1283457024 134512640 135304128 4292821024 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31367/statm: 641 269 230 194 0 28 0
[pid=31368] ppid=31367 vsize=2572 CPUtime=0.04
/proc/31368/stat : 31368 (p2cudf) S 31367 31367 29493 34817 29493 4202496 393 3018 0 1 0 0 2 2 25 0 1 0 76360614 2633728 281 1283457024 134512640 135304128 4287773536 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31368/statm: 643 281 239 194 0 30 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 5136

[startup+1.50584 s]
/proc/loadavg: 1.61 1.75 1.72 3/45 31390
/proc/meminfo: memFree=249180/1048576 swapFree=0/0
[pid=31367] ppid=31366 vsize=2564 CPUtime=0
/proc/31367/stat : 31367 (p2cudf-paranoid) S 31366 31367 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 18 0 1 0 76360614 2625536 269 1283457024 134512640 135304128 4292821024 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31367/statm: 641 269 230 194 0 28 0
[pid=31368] ppid=31367 vsize=2572 CPUtime=0.04
/proc/31368/stat : 31368 (p2cudf) S 31367 31367 29493 34817 29493 4202496 393 3018 0 1 0 0 2 2 25 0 1 0 76360614 2633728 281 1283457024 134512640 135304128 4287773536 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31368/statm: 643 281 239 194 0 30 0
[pid=31381] ppid=31368 vsize=881772 CPUtime=1.46
/proc/31381/stat : 31381 (java) S 31368 31367 29493 34817 29493 4202496 23372 0 1 0 141 5 0 0 25 0 10 0 76360618 902934528 19965 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/31381/statm: 220443 19965 1730 10 0 217534 0
[pid=31381/tid=31382] ppid=31368 vsize=881772 CPUtime=0.79
/proc/31381/task/31382/stat : 31382 (java) R 31368 31367 29493 34817 29493 4202560 12637 0 1 0 76 3 0 0 25 0 10 0 76360618 902934528 19965 1283457024 134512640 134550932 4289448864 18446744073709551615 4094741251 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=31381/tid=31383] ppid=31368 vsize=881772 CPUtime=0
/proc/31381/task/31383/stat : 31383 (java) S 31368 31367 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 16 0 10 0 76360620 902934528 19965 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 0 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31384] ppid=31368 vsize=881772 CPUtime=0
/proc/31381/task/31384/stat : 31384 (java) S 31368 31367 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 25 0 10 0 76360620 902934528 19965 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31385] ppid=31368 vsize=881772 CPUtime=0
/proc/31381/task/31385/stat : 31385 (java) S 31368 31367 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 25 0 10 0 76360620 902934528 19965 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31386] ppid=31368 vsize=881772 CPUtime=0
/proc/31381/task/31386/stat : 31386 (java) S 31368 31367 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76360623 902934528 19965 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31387] ppid=31368 vsize=881772 CPUtime=0.43
/proc/31381/task/31387/stat : 31387 (java) R 31368 31367 29493 34817 29493 4202560 7341 0 0 0 41 2 0 0 25 0 10 0 76360623 902934528 19965 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=31381/tid=31388] ppid=31368 vsize=881772 CPUtime=0.23
/proc/31381/task/31388/stat : 31388 (java) R 31368 31367 29493 34817 29493 4202560 2316 0 0 0 23 0 0 0 19 0 10 0 76360623 902934528 19965 1283457024 134512640 134550932 4289448864 18446744073709551615 4149507972 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=31381/tid=31389] ppid=31368 vsize=881772 CPUtime=0
/proc/31381/task/31389/stat : 31389 (java) S 31368 31367 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76360623 902934528 19965 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31390] ppid=31368 vsize=881772 CPUtime=0
/proc/31381/task/31390/stat : 31390 (java) S 31368 31367 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 10 0 76360623 902934528 19965 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.5
Current children cumulated vsize (KiB) 886908

[startup+3.12628 s]
/proc/loadavg: 1.72 1.77 1.72 4/45 31390
/proc/meminfo: memFree=165480/1048576 swapFree=0/0
[pid=31367] ppid=31366 vsize=2564 CPUtime=0
/proc/31367/stat : 31367 (p2cudf-paranoid) S 31366 31367 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 18 0 1 0 76360614 2625536 269 1283457024 134512640 135304128 4292821024 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31367/statm: 641 269 230 194 0 28 0
[pid=31368] ppid=31367 vsize=2572 CPUtime=0.04
/proc/31368/stat : 31368 (p2cudf) S 31367 31367 29493 34817 29493 4202496 393 3018 0 1 0 0 2 2 25 0 1 0 76360614 2633728 281 1283457024 134512640 135304128 4287773536 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31368/statm: 643 281 239 194 0 30 0
[pid=31381] ppid=31368 vsize=879508 CPUtime=3.07
/proc/31381/stat : 31381 (java) S 31368 31367 29493 34817 29493 4202496 64533 0 1 0 288 19 0 0 25 0 10 0 76360618 900616192 59654 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/31381/statm: 219877 59654 1742 10 0 216968 0
[pid=31381/tid=31382] ppid=31368 vsize=879508 CPUtime=1.52
/proc/31381/task/31382/stat : 31382 (java) R 31368 31367 29493 34817 29493 4202560 50060 0 1 0 137 15 0 0 25 0 10 0 76360618 900616192 59654 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=31381/tid=31383] ppid=31368 vsize=879508 CPUtime=0.04
/proc/31381/task/31383/stat : 31383 (java) R 31368 31367 29493 34817 29493 4202560 2318 0 0 0 2 2 0 0 15 0 10 0 76360620 900616192 59654 1283457024 134512640 134550932 4289448864 18446744073709551615 4148756856 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=31381/tid=31384] ppid=31368 vsize=879508 CPUtime=0
/proc/31381/task/31384/stat : 31384 (java) S 31368 31367 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 25 0 10 0 76360620 900616192 59654 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31385] ppid=31368 vsize=879508 CPUtime=0
/proc/31381/task/31385/stat : 31385 (java) S 31368 31367 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 25 0 10 0 76360620 900616192 59654 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31386] ppid=31368 vsize=879508 CPUtime=0
/proc/31381/task/31386/stat : 31386 (java) S 31368 31367 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76360623 900616192 59654 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31387] ppid=31368 vsize=879508 CPUtime=0.62
/proc/31381/task/31387/stat : 31387 (java) S 31368 31367 29493 34817 29493 4202560 7402 0 0 0 60 2 0 0 25 0 10 0 76360623 900616192 59654 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31388] ppid=31368 vsize=879508 CPUtime=0.88
/proc/31381/task/31388/stat : 31388 (java) S 31368 31367 29493 34817 29493 4202560 3681 0 0 0 88 0 0 0 15 0 10 0 76360623 900616192 59654 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31389] ppid=31368 vsize=879508 CPUtime=0
/proc/31381/task/31389/stat : 31389 (java) S 31368 31367 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76360623 900616192 59654 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31390] ppid=31368 vsize=879508 CPUtime=0
/proc/31381/task/31390/stat : 31390 (java) S 31368 31367 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 10 0 76360623 900616192 59654 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.11
Current children cumulated vsize (KiB) 884644

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

[startup+3.22633 s]
/proc/loadavg: 1.72 1.77 1.72 4/45 31390
/proc/meminfo: memFree=165480/1048576 swapFree=0/0
[pid=31367] ppid=31366 vsize=2564 CPUtime=0
/proc/31367/stat : 31367 (p2cudf-paranoid) S 31366 31367 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 18 0 1 0 76360614 2625536 269 1283457024 134512640 135304128 4292821024 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31367/statm: 641 269 230 194 0 28 0
[pid=31368] ppid=31367 vsize=2572 CPUtime=0.04
/proc/31368/stat : 31368 (p2cudf) S 31367 31367 29493 34817 29493 4202496 393 3018 0 1 0 0 2 2 25 0 1 0 76360614 2633728 281 1283457024 134512640 135304128 4287773536 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31368/statm: 643 281 239 194 0 30 0
[pid=31381] ppid=31368 vsize=879508 CPUtime=3.18
/proc/31381/stat : 31381 (java) S 31368 31367 29493 34817 29493 4202496 70794 0 1 0 298 20 0 0 25 0 10 0 76360618 900616192 65915 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/31381/statm: 219877 65915 1742 10 0 216968 0
[pid=31381/tid=31382] ppid=31368 vsize=879508 CPUtime=1.52
/proc/31381/task/31382/stat : 31382 (java) R 31368 31367 29493 34817 29493 4202560 50060 0 1 0 137 15 0 0 25 0 10 0 76360618 900616192 65915 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=31381/tid=31383] ppid=31368 vsize=879508 CPUtime=0.14
/proc/31381/task/31383/stat : 31383 (java) R 31368 31367 29493 34817 29493 4202560 8579 0 0 0 12 2 0 0 15 0 10 0 76360620 900616192 65915 1283457024 134512640 134550932 4289448864 18446744073709551615 4148756856 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=31381/tid=31384] ppid=31368 vsize=879508 CPUtime=0
/proc/31381/task/31384/stat : 31384 (java) S 31368 31367 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 25 0 10 0 76360620 900616192 65915 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31385] ppid=31368 vsize=879508 CPUtime=0
/proc/31381/task/31385/stat : 31385 (java) S 31368 31367 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 25 0 10 0 76360620 900616192 65915 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31386] ppid=31368 vsize=879508 CPUtime=0
/proc/31381/task/31386/stat : 31386 (java) S 31368 31367 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76360623 900616192 65915 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31387] ppid=31368 vsize=879508 CPUtime=0.62
/proc/31381/task/31387/stat : 31387 (java) S 31368 31367 29493 34817 29493 4202560 7402 0 0 0 60 2 0 0 25 0 10 0 76360623 900616192 65915 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31388] ppid=31368 vsize=879508 CPUtime=0.88
/proc/31381/task/31388/stat : 31388 (java) S 31368 31367 29493 34817 29493 4202560 3681 0 0 0 88 0 0 0 15 0 10 0 76360623 900616192 65915 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31389] ppid=31368 vsize=879508 CPUtime=0
/proc/31381/task/31389/stat : 31389 (java) S 31368 31367 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76360623 900616192 65915 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31390] ppid=31368 vsize=879508 CPUtime=0
/proc/31381/task/31390/stat : 31390 (java) S 31368 31367 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 10 0 76360623 900616192 65915 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.22
Current children cumulated vsize (KiB) 884644

[startup+4.00652 s]
/proc/loadavg: 1.72 1.77 1.72 3/45 31390
/proc/meminfo: memFree=25484/1048576 swapFree=0/0
[pid=31367] ppid=31366 vsize=2564 CPUtime=0
/proc/31367/stat : 31367 (p2cudf-paranoid) S 31366 31367 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 18 0 1 0 76360614 2625536 269 1283457024 134512640 135304128 4292821024 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31367/statm: 641 269 230 194 0 28 0
[pid=31368] ppid=31367 vsize=2572 CPUtime=0.04
/proc/31368/stat : 31368 (p2cudf) S 31367 31367 29493 34817 29493 4202496 393 3018 0 1 0 0 2 2 25 0 1 0 76360614 2633728 281 1283457024 134512640 135304128 4287773536 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31368/statm: 643 281 239 194 0 30 0
[pid=31381] ppid=31368 vsize=880288 CPUtime=3.96
/proc/31381/stat : 31381 (java) S 31368 31367 29493 34817 29493 4202496 80476 0 1 0 371 25 0 0 25 0 10 0 76360618 901414912 74231 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/31381/statm: 220072 74231 1746 10 0 217163 0
[pid=31381/tid=31382] ppid=31368 vsize=880288 CPUtime=1.67
/proc/31381/task/31382/stat : 31382 (java) R 31368 31367 29493 34817 29493 4202560 50185 0 1 0 150 17 0 0 25 0 10 0 76360618 901414912 74231 1283457024 134512640 134550932 4289448864 18446744073709551615 4149122474 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=31381/tid=31383] ppid=31368 vsize=880288 CPUtime=0.36
/proc/31381/task/31383/stat : 31383 (java) S 31368 31367 29493 34817 29493 4202560 16579 0 0 0 32 4 0 0 16 0 10 0 76360620 901414912 74231 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 0 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31384] ppid=31368 vsize=880288 CPUtime=0
/proc/31381/task/31384/stat : 31384 (java) S 31368 31367 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 18 0 10 0 76360620 901414912 74231 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31385] ppid=31368 vsize=880288 CPUtime=0
/proc/31381/task/31385/stat : 31385 (java) S 31368 31367 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 10 0 76360620 901414912 74231 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31386] ppid=31368 vsize=880288 CPUtime=0
/proc/31381/task/31386/stat : 31386 (java) S 31368 31367 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76360623 901414912 74231 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31387] ppid=31368 vsize=880288 CPUtime=0.62
/proc/31381/task/31387/stat : 31387 (java) S 31368 31367 29493 34817 29493 4202560 7402 0 0 0 60 2 0 0 25 0 10 0 76360623 901414912 74231 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31388] ppid=31368 vsize=880288 CPUtime=1.28
/proc/31381/task/31388/stat : 31388 (java) S 31368 31367 29493 34817 29493 4202560 5236 0 0 0 128 0 0 0 16 0 10 0 76360623 901414912 74231 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31389] ppid=31368 vsize=880288 CPUtime=0
/proc/31381/task/31389/stat : 31389 (java) S 31368 31367 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76360623 901414912 74231 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31390] ppid=31368 vsize=880288 CPUtime=0
/proc/31381/task/31390/stat : 31390 (java) S 31368 31367 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 10 0 76360623 901414912 74231 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4
Current children cumulated vsize (KiB) 885424

[startup+4.4058 s]
/proc/loadavg: 1.72 1.77 1.72 1/46 31391
/proc/meminfo: memFree=6380/1048576 swapFree=0/0
[pid=31367] ppid=31366 vsize=2564 CPUtime=0
/proc/31367/stat : 31367 (p2cudf-paranoid) S 31366 31367 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 18 0 1 0 76360614 2625536 269 1283457024 134512640 135304128 4292821024 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31367/statm: 641 269 230 194 0 28 0
[pid=31368] ppid=31367 vsize=2572 CPUtime=0.04
/proc/31368/stat : 31368 (p2cudf) S 31367 31367 29493 34817 29493 4202496 393 3018 0 1 0 0 2 2 25 0 1 0 76360614 2633728 281 1283457024 134512640 135304128 4287773536 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31368/statm: 643 281 239 194 0 30 0
[pid=31381] ppid=31368 vsize=880612 CPUtime=4.23
/proc/31381/stat : 31381 (java) S 31368 31367 29493 34817 29493 4202496 80512 0 1 0 398 25 0 0 25 0 11 0 76360618 901746688 74267 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/31381/statm: 220153 74267 1752 10 0 217244 0
[pid=31381/tid=31382] ppid=31368 vsize=880612 CPUtime=1.78
/proc/31381/task/31382/stat : 31382 (java) S 31368 31367 29493 34817 29493 4202560 50194 0 1 0 161 17 0 0 25 0 11 0 76360618 901746688 74267 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31383] ppid=31368 vsize=880612 CPUtime=0.36
/proc/31381/task/31383/stat : 31383 (java) S 31368 31367 29493 34817 29493 4202560 16579 0 0 0 32 4 0 0 16 0 11 0 76360620 901746688 74267 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 0 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31384] ppid=31368 vsize=880612 CPUtime=0
/proc/31381/task/31384/stat : 31384 (java) S 31368 31367 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 18 0 11 0 76360620 901746688 74267 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31385] ppid=31368 vsize=880612 CPUtime=0
/proc/31381/task/31385/stat : 31385 (java) S 31368 31367 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 11 0 76360620 901746688 74267 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31386] ppid=31368 vsize=880612 CPUtime=0
/proc/31381/task/31386/stat : 31386 (java) S 31368 31367 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 11 0 76360623 901746688 74267 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31387] ppid=31368 vsize=880612 CPUtime=0.62
/proc/31381/task/31387/stat : 31387 (java) S 31368 31367 29493 34817 29493 4202560 7402 0 0 0 60 2 0 0 25 0 11 0 76360623 901746688 74267 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31388] ppid=31368 vsize=880612 CPUtime=1.44
/proc/31381/task/31388/stat : 31388 (java) S 31368 31367 29493 34817 29493 4202560 5258 0 0 0 144 0 0 0 15 0 11 0 76360623 901746688 74267 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31389] ppid=31368 vsize=880612 CPUtime=0
/proc/31381/task/31389/stat : 31389 (java) S 31368 31367 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 11 0 76360623 901746688 74267 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31390] ppid=31368 vsize=880612 CPUtime=0
/proc/31381/task/31390/stat : 31390 (java) S 31368 31367 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 11 0 76360623 901746688 74267 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31391] ppid=31368 vsize=880612 CPUtime=0
/proc/31381/task/31391/stat : 31391 (java) S 31368 31367 29493 34817 29493 4202560 5 0 0 0 0 0 0 0 25 0 11 0 76361042 901746688 74267 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.27
Current children cumulated vsize (KiB) 885748

[startup+4.80588 s]
/proc/loadavg: 1.72 1.77 1.72 1/46 31391
/proc/meminfo: memFree=6380/1048576 swapFree=0/0
[pid=31367] ppid=31366 vsize=2564 CPUtime=0
/proc/31367/stat : 31367 (p2cudf-paranoid) S 31366 31367 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 18 0 1 0 76360614 2625536 269 1283457024 134512640 135304128 4292821024 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31367/statm: 641 269 230 194 0 28 0
[pid=31368] ppid=31367 vsize=2572 CPUtime=0.04
/proc/31368/stat : 31368 (p2cudf) S 31367 31367 29493 34817 29493 4202496 393 3018 0 1 0 0 2 2 25 0 1 0 76360614 2633728 281 1283457024 134512640 135304128 4287773536 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31368/statm: 643 281 239 194 0 30 0
[pid=31381] ppid=31368 vsize=880612 CPUtime=4.23
/proc/31381/stat : 31381 (java) S 31368 31367 29493 34817 29493 4202496 80514 0 1 0 398 25 0 0 25 0 10 0 76360618 901746688 74269 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/31381/statm: 220153 74269 1754 10 0 217244 0
[pid=31381/tid=31382] ppid=31368 vsize=880612 CPUtime=1.78
/proc/31381/task/31382/stat : 31382 (java) S 31368 31367 29493 34817 29493 4202560 50194 0 1 0 161 17 0 0 20 0 10 0 76360618 901746688 74269 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31383] ppid=31368 vsize=880612 CPUtime=0.36
/proc/31381/task/31383/stat : 31383 (java) S 31368 31367 29493 34817 29493 4202560 16580 0 0 0 32 4 0 0 16 0 10 0 76360620 901746688 74269 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 0 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31384] ppid=31368 vsize=880612 CPUtime=0
/proc/31381/task/31384/stat : 31384 (java) S 31368 31367 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 18 0 10 0 76360620 901746688 74269 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31385] ppid=31368 vsize=880612 CPUtime=0
/proc/31381/task/31385/stat : 31385 (java) S 31368 31367 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 10 0 76360620 901746688 74269 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31386] ppid=31368 vsize=880612 CPUtime=0
/proc/31381/task/31386/stat : 31386 (java) S 31368 31367 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76360623 901746688 74269 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31387] ppid=31368 vsize=880612 CPUtime=0.62
/proc/31381/task/31387/stat : 31387 (java) S 31368 31367 29493 34817 29493 4202560 7402 0 0 0 60 2 0 0 25 0 10 0 76360623 901746688 74269 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31388] ppid=31368 vsize=880612 CPUtime=1.44
/proc/31381/task/31388/stat : 31388 (java) S 31368 31367 29493 34817 29493 4202560 5258 0 0 0 144 0 0 0 15 0 10 0 76360623 901746688 74269 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31389] ppid=31368 vsize=880612 CPUtime=0
/proc/31381/task/31389/stat : 31389 (java) S 31368 31367 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76360623 901746688 74269 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=31381/tid=31390] ppid=31368 vsize=880612 CPUtime=0
/proc/31381/task/31390/stat : 31390 (java) S 31368 31367 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 10 0 76360623 901746688 74269 1283457024 134512640 134550932 4289448864 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.27
Current children cumulated vsize (KiB) 885748

Child status: 0
Real time (s): 4.85835
CPU time (s): 4.30427
CPU user time (s): 4.00025
CPU system time (s): 0.304019
CPU usage (%): 88.5953
Max. virtual memory (cumulated for all children) (KiB): 888204

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 4.00025
system time used= 0.304019
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 84323
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= 402
involuntary context switches= 394

runsolver used 0 second user time and 0 second system time

The end