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/201108291842/p2cudf-user-1.13/deb285a6-db9e-11df-8f4f-00163e3d3b7c.cudf.dudf-real.log.runsolver ./p2cudf-user-1.13 /home/misc2010/data/2011/dudf-real//deb285a6-db9e-11df-8f4f-00163e3d3b7c.cudf /home/misc2010/tmp/201108291842/p2cudf-user-1.13/deb285a6-db9e-11df-8f4f-00163e3d3b7c.cudf.dudf-real.result -notuptodate,-removed,-changed 

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.18 1.16 1.12 5/37 30584
/proc/meminfo: memFree=670856/1048576 swapFree=0/0
[pid=30582] ppid=30581 vsize=2564 CPUtime=0
/proc/30582/stat : 30582 (p2cudf-user-1.1) S 30581 30582 17511 34816 17511 4202496 374 0 0 0 0 0 0 0 18 0 1 0 46634914 2625536 269 1283457024 134512640 135304128 4294459728 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30582/statm: 641 269 230 194 0 28 0
[pid=30583] ppid=30582 vsize=2572 CPUtime=0
/proc/30583/stat : 30583 (p2cudf) R 30582 30582 17511 34816 17511 4202496 346 0 0 0 0 0 0 0 25 0 1 0 46634914 2633728 272 1283457024 134512640 135304128 4290282880 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/30583/statm: 643 272 231 194 0 30 0
[pid=30584] ppid=30583 vsize=2572 CPUtime=0
/proc/30584/stat : 30584 (p2cudf) R 30583 30582 17511 34816 17511 4202560 0 0 0 0 0 0 0 0 25 0 1 0 46634915 2633728 41 1283457024 134512640 135304128 4290282880 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/30584/statm: 643 41 0 194 0 30 0

[startup+0.175615 s]
/proc/loadavg: 1.18 1.16 1.12 5/37 30584
/proc/meminfo: memFree=670856/1048576 swapFree=0/0
[pid=30582] ppid=30581 vsize=2564 CPUtime=0
/proc/30582/stat : 30582 (p2cudf-user-1.1) S 30581 30582 17511 34816 17511 4202496 374 0 0 0 0 0 0 0 18 0 1 0 46634914 2625536 269 1283457024 134512640 135304128 4294459728 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30582/statm: 641 269 230 194 0 28 0
[pid=30583] ppid=30582 vsize=2576 CPUtime=0.02
/proc/30583/stat : 30583 (p2cudf) S 30582 30582 17511 34816 17511 4202496 392 3013 0 1 0 0 2 0 25 0 1 0 46634914 2637824 281 1283457024 134512640 135304128 4290282880 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30583/statm: 644 281 239 194 0 31 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5140

[startup+0.205611 s]
/proc/loadavg: 1.18 1.16 1.12 5/37 30584
/proc/meminfo: memFree=670856/1048576 swapFree=0/0
[pid=30582] ppid=30581 vsize=2564 CPUtime=0
/proc/30582/stat : 30582 (p2cudf-user-1.1) S 30581 30582 17511 34816 17511 4202496 374 0 0 0 0 0 0 0 18 0 1 0 46634914 2625536 269 1283457024 134512640 135304128 4294459728 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30582/statm: 641 269 230 194 0 28 0
[pid=30583] ppid=30582 vsize=2576 CPUtime=0.02
/proc/30583/stat : 30583 (p2cudf) S 30582 30582 17511 34816 17511 4202496 392 3013 0 1 0 0 2 0 25 0 1 0 46634914 2637824 281 1283457024 134512640 135304128 4290282880 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30583/statm: 644 281 239 194 0 31 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5140

[startup+0.305621 s]
/proc/loadavg: 1.18 1.16 1.12 5/37 30584
/proc/meminfo: memFree=670856/1048576 swapFree=0/0
[pid=30582] ppid=30581 vsize=2564 CPUtime=0
/proc/30582/stat : 30582 (p2cudf-user-1.1) S 30581 30582 17511 34816 17511 4202496 374 0 0 0 0 0 0 0 18 0 1 0 46634914 2625536 269 1283457024 134512640 135304128 4294459728 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30582/statm: 641 269 230 194 0 28 0
[pid=30583] ppid=30582 vsize=2576 CPUtime=0.02
/proc/30583/stat : 30583 (p2cudf) S 30582 30582 17511 34816 17511 4202496 392 3013 0 1 0 0 2 0 25 0 1 0 46634914 2637824 281 1283457024 134512640 135304128 4290282880 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30583/statm: 644 281 239 194 0 31 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5140

[startup+0.705676 s]
/proc/loadavg: 1.18 1.16 1.12 5/37 30584
/proc/meminfo: memFree=670856/1048576 swapFree=0/0
[pid=30582] ppid=30581 vsize=2564 CPUtime=0
/proc/30582/stat : 30582 (p2cudf-user-1.1) S 30581 30582 17511 34816 17511 4202496 374 0 0 0 0 0 0 0 18 0 1 0 46634914 2625536 269 1283457024 134512640 135304128 4294459728 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30582/statm: 641 269 230 194 0 28 0
[pid=30583] ppid=30582 vsize=2576 CPUtime=0.02
/proc/30583/stat : 30583 (p2cudf) S 30582 30582 17511 34816 17511 4202496 392 3013 0 1 0 0 2 0 25 0 1 0 46634914 2637824 281 1283457024 134512640 135304128 4290282880 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30583/statm: 644 281 239 194 0 31 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5140

[startup+1.50578 s]
/proc/loadavg: 1.24 1.18 1.12 4/47 30605
/proc/meminfo: memFree=634620/1048576 swapFree=0/0
[pid=30582] ppid=30581 vsize=2564 CPUtime=0
/proc/30582/stat : 30582 (p2cudf-user-1.1) S 30581 30582 17511 34816 17511 4202496 374 0 0 0 0 0 0 0 18 0 1 0 46634914 2625536 269 1283457024 134512640 135304128 4294459728 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30582/statm: 641 269 230 194 0 28 0
[pid=30583] ppid=30582 vsize=2576 CPUtime=0.02
/proc/30583/stat : 30583 (p2cudf) S 30582 30582 17511 34816 17511 4202496 392 3013 0 1 0 0 2 0 25 0 1 0 46634914 2637824 281 1283457024 134512640 135304128 4290282880 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30583/statm: 644 281 239 194 0 31 0
[pid=30596] ppid=30583 vsize=884972 CPUtime=1.47
/proc/30596/stat : 30596 (java) S 30583 30582 17511 34816 17511 4202496 22204 0 1 0 139 8 0 0 25 0 10 0 46634918 906211328 18901 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/30596/statm: 221243 18901 1723 10 0 218334 0
[pid=30596/tid=30597] ppid=30583 vsize=884972 CPUtime=0.74
/proc/30596/task/30597/stat : 30597 (java) R 30583 30582 17511 34816 17511 4202560 10371 0 1 0 68 6 0 0 25 0 10 0 46634918 906211328 18901 1283457024 134512640 134550932 4289663872 18446744073709551615 4095089472 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=30596/tid=30598] ppid=30583 vsize=884972 CPUtime=0
/proc/30596/task/30598/stat : 30598 (java) S 30583 30582 17511 34816 17511 4202560 6 0 0 0 0 0 0 0 17 0 10 0 46634920 906211328 18901 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 0 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30599] ppid=30583 vsize=884972 CPUtime=0
/proc/30596/task/30599/stat : 30599 (java) S 30583 30582 17511 34816 17511 4202560 8 0 0 0 0 0 0 0 25 0 10 0 46634920 906211328 18901 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30600] ppid=30583 vsize=884972 CPUtime=0
/proc/30596/task/30600/stat : 30600 (java) S 30583 30582 17511 34816 17511 4202560 4 0 0 0 0 0 0 0 25 0 10 0 46634920 906211328 18901 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30601] ppid=30583 vsize=884972 CPUtime=0
/proc/30596/task/30601/stat : 30601 (java) S 30583 30582 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46634923 906211328 18901 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30602] ppid=30583 vsize=884972 CPUtime=0.55
/proc/30596/task/30602/stat : 30602 (java) R 30583 30582 17511 34816 17511 4202560 8802 0 0 0 54 1 0 0 22 0 10 0 46634923 906211328 18901 1283457024 134512640 134550932 4289663872 18446744073709551615 4152211100 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=30596/tid=30603] ppid=30583 vsize=884972 CPUtime=0.16
/proc/30596/task/30603/stat : 30603 (java) S 30583 30582 17511 34816 17511 4202560 1949 0 0 0 16 0 0 0 22 0 10 0 46634923 906211328 18901 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30604] ppid=30583 vsize=884972 CPUtime=0
/proc/30596/task/30604/stat : 30604 (java) S 30583 30582 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46634923 906211328 18901 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30605] ppid=30583 vsize=884972 CPUtime=0
/proc/30596/task/30605/stat : 30605 (java) S 30583 30582 17511 34816 17511 4202560 2 0 0 0 0 0 0 0 15 0 10 0 46634923 906211328 18901 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.49
Current children cumulated vsize (KiB) 890112

[startup+3.10612 s]
/proc/loadavg: 1.24 1.18 1.12 3/47 30605
/proc/meminfo: memFree=508760/1048576 swapFree=0/0
[pid=30582] ppid=30581 vsize=2564 CPUtime=0
/proc/30582/stat : 30582 (p2cudf-user-1.1) S 30581 30582 17511 34816 17511 4202496 374 0 0 0 0 0 0 0 18 0 1 0 46634914 2625536 269 1283457024 134512640 135304128 4294459728 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30582/statm: 641 269 230 194 0 28 0
[pid=30583] ppid=30582 vsize=2576 CPUtime=0.02
/proc/30583/stat : 30583 (p2cudf) S 30582 30582 17511 34816 17511 4202496 392 3013 0 1 0 0 2 0 25 0 1 0 46634914 2637824 281 1283457024 134512640 135304128 4290282880 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30583/statm: 644 281 239 194 0 31 0
[pid=30596] ppid=30583 vsize=884972 CPUtime=3.08
/proc/30596/stat : 30596 (java) S 30583 30582 17511 34816 17511 4202496 55361 0 1 0 286 22 0 0 25 0 10 0 46634918 906211328 52058 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/30596/statm: 221243 52058 1744 10 0 218334 0
[pid=30596/tid=30597] ppid=30583 vsize=884972 CPUtime=1.42
/proc/30596/task/30597/stat : 30597 (java) R 30583 30582 17511 34816 17511 4202560 43398 0 1 0 123 19 0 0 25 0 10 0 46634918 906211328 52058 1283457024 134512640 134550932 4289663872 18446744073709551615 4145145910 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=30596/tid=30598] ppid=30583 vsize=884972 CPUtime=0
/proc/30596/task/30598/stat : 30598 (java) S 30583 30582 17511 34816 17511 4202560 6 0 0 0 0 0 0 0 15 0 10 0 46634920 906211328 52058 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 0 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30599] ppid=30583 vsize=884972 CPUtime=0
/proc/30596/task/30599/stat : 30599 (java) S 30583 30582 17511 34816 17511 4202560 8 0 0 0 0 0 0 0 25 0 10 0 46634920 906211328 52058 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30600] ppid=30583 vsize=884972 CPUtime=0
/proc/30596/task/30600/stat : 30600 (java) S 30583 30582 17511 34816 17511 4202560 4 0 0 0 0 0 0 0 25 0 10 0 46634920 906211328 52058 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30601] ppid=30583 vsize=884972 CPUtime=0
/proc/30596/task/30601/stat : 30601 (java) S 30583 30582 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46634923 906211328 52058 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30602] ppid=30583 vsize=884972 CPUtime=1.44
/proc/30596/task/30602/stat : 30602 (java) S 30583 30582 17511 34816 17511 4202560 8932 0 0 0 143 1 0 0 17 0 10 0 46634923 906211328 52058 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30603] ppid=30583 vsize=884972 CPUtime=0.19
/proc/30596/task/30603/stat : 30603 (java) S 30583 30582 17511 34816 17511 4202560 1949 0 0 0 19 0 0 0 21 0 10 0 46634923 906211328 52058 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30604] ppid=30583 vsize=884972 CPUtime=0
/proc/30596/task/30604/stat : 30604 (java) S 30583 30582 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46634923 906211328 52058 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30605] ppid=30583 vsize=884972 CPUtime=0
/proc/30596/task/30605/stat : 30605 (java) S 30583 30582 17511 34816 17511 4202560 2 0 0 0 0 0 0 0 15 0 10 0 46634923 906211328 52058 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.1
Current children cumulated vsize (KiB) 890112

[startup+6.30596 s]
/proc/loadavg: 1.22 1.17 1.12 3/48 30606
/proc/meminfo: memFree=399756/1048576 swapFree=0/0
[pid=30582] ppid=30581 vsize=2564 CPUtime=0
/proc/30582/stat : 30582 (p2cudf-user-1.1) S 30581 30582 17511 34816 17511 4202496 374 0 0 0 0 0 0 0 18 0 1 0 46634914 2625536 269 1283457024 134512640 135304128 4294459728 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30582/statm: 641 269 230 194 0 28 0
[pid=30583] ppid=30582 vsize=2576 CPUtime=0.02
/proc/30583/stat : 30583 (p2cudf) S 30582 30582 17511 34816 17511 4202496 392 3013 0 1 0 0 2 0 25 0 1 0 46634914 2637824 281 1283457024 134512640 135304128 4290282880 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30583/statm: 644 281 239 194 0 31 0
[pid=30596] ppid=30583 vsize=885620 CPUtime=6.01
/proc/30596/stat : 30596 (java) S 30583 30582 17511 34816 17511 4202496 72673 0 1 0 573 28 0 0 25 0 11 0 46634918 906874880 69370 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/30596/statm: 221405 69370 1785 10 0 218496 0
[pid=30596/tid=30597] ppid=30583 vsize=885620 CPUtime=3
/proc/30596/task/30597/stat : 30597 (java) S 30583 30582 17511 34816 17511 4202560 50290 0 1 0 279 21 0 0 25 0 11 0 46634918 906874880 69370 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30598] ppid=30583 vsize=885620 CPUtime=0.26
/proc/30596/task/30598/stat : 30598 (java) S 30583 30582 17511 34816 17511 4202560 10271 0 0 0 23 3 0 0 16 0 11 0 46634920 906874880 69370 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 0 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30599] ppid=30583 vsize=885620 CPUtime=0
/proc/30596/task/30599/stat : 30599 (java) S 30583 30582 17511 34816 17511 4202560 8 0 0 0 0 0 0 0 18 0 11 0 46634920 906874880 69370 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30600] ppid=30583 vsize=885620 CPUtime=0
/proc/30596/task/30600/stat : 30600 (java) S 30583 30582 17511 34816 17511 4202560 6 0 0 0 0 0 0 0 18 0 11 0 46634920 906874880 69370 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30601] ppid=30583 vsize=885620 CPUtime=0
/proc/30596/task/30601/stat : 30601 (java) S 30583 30582 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 11 0 46634923 906874880 69370 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30602] ppid=30583 vsize=885620 CPUtime=2.52
/proc/30596/task/30602/stat : 30602 (java) S 30583 30582 17511 34816 17511 4202560 9075 0 0 0 250 2 0 0 16 0 11 0 46634923 906874880 69370 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30603] ppid=30583 vsize=885620 CPUtime=0.19
/proc/30596/task/30603/stat : 30603 (java) S 30583 30582 17511 34816 17511 4202560 1949 0 0 0 19 0 0 0 21 0 11 0 46634923 906874880 69370 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30604] ppid=30583 vsize=885620 CPUtime=0
/proc/30596/task/30604/stat : 30604 (java) S 30583 30582 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 11 0 46634923 906874880 69370 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30605] ppid=30583 vsize=885620 CPUtime=0
/proc/30596/task/30605/stat : 30605 (java) S 30583 30582 17511 34816 17511 4202560 2 0 0 0 0 0 0 0 15 0 11 0 46634923 906874880 69370 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.03
Current children cumulated vsize (KiB) 890760

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

[startup+6.40603 s]
/proc/loadavg: 1.22 1.17 1.12 3/48 30606
/proc/meminfo: memFree=399756/1048576 swapFree=0/0
[pid=30582] ppid=30581 vsize=2564 CPUtime=0
/proc/30582/stat : 30582 (p2cudf-user-1.1) S 30581 30582 17511 34816 17511 4202496 374 0 0 0 0 0 0 0 18 0 1 0 46634914 2625536 269 1283457024 134512640 135304128 4294459728 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30582/statm: 641 269 230 194 0 28 0
[pid=30583] ppid=30582 vsize=2576 CPUtime=0.02
/proc/30583/stat : 30583 (p2cudf) S 30582 30582 17511 34816 17511 4202496 392 3013 0 1 0 0 2 0 25 0 1 0 46634914 2637824 281 1283457024 134512640 135304128 4290282880 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30583/statm: 644 281 239 194 0 31 0
[pid=30596] ppid=30583 vsize=885620 CPUtime=6.01
/proc/30596/stat : 30596 (java) S 30583 30582 17511 34816 17511 4202496 72673 0 1 0 573 28 0 0 25 0 11 0 46634918 906874880 69370 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/30596/statm: 221405 69370 1785 10 0 218496 0
[pid=30596/tid=30597] ppid=30583 vsize=885620 CPUtime=3
/proc/30596/task/30597/stat : 30597 (java) S 30583 30582 17511 34816 17511 4202560 50290 0 1 0 279 21 0 0 25 0 11 0 46634918 906874880 69370 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30598] ppid=30583 vsize=885620 CPUtime=0.26
/proc/30596/task/30598/stat : 30598 (java) S 30583 30582 17511 34816 17511 4202560 10271 0 0 0 23 3 0 0 16 0 11 0 46634920 906874880 69370 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 0 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30599] ppid=30583 vsize=885620 CPUtime=0
/proc/30596/task/30599/stat : 30599 (java) S 30583 30582 17511 34816 17511 4202560 8 0 0 0 0 0 0 0 18 0 11 0 46634920 906874880 69370 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30600] ppid=30583 vsize=885620 CPUtime=0
/proc/30596/task/30600/stat : 30600 (java) S 30583 30582 17511 34816 17511 4202560 6 0 0 0 0 0 0 0 18 0 11 0 46634920 906874880 69370 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30601] ppid=30583 vsize=885620 CPUtime=0
/proc/30596/task/30601/stat : 30601 (java) S 30583 30582 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 11 0 46634923 906874880 69370 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30602] ppid=30583 vsize=885620 CPUtime=2.52
/proc/30596/task/30602/stat : 30602 (java) S 30583 30582 17511 34816 17511 4202560 9075 0 0 0 250 2 0 0 16 0 11 0 46634923 906874880 69370 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30603] ppid=30583 vsize=885620 CPUtime=0.19
/proc/30596/task/30603/stat : 30603 (java) S 30583 30582 17511 34816 17511 4202560 1949 0 0 0 19 0 0 0 21 0 11 0 46634923 906874880 69370 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30604] ppid=30583 vsize=885620 CPUtime=0
/proc/30596/task/30604/stat : 30604 (java) S 30583 30582 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 11 0 46634923 906874880 69370 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30605] ppid=30583 vsize=885620 CPUtime=0
/proc/30596/task/30605/stat : 30605 (java) S 30583 30582 17511 34816 17511 4202560 2 0 0 0 0 0 0 0 15 0 11 0 46634923 906874880 69370 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.03
Current children cumulated vsize (KiB) 890760

[startup+6.61 s]
/proc/loadavg: 1.22 1.17 1.12 2/48 30607
/proc/meminfo: memFree=401128/1048576 swapFree=0/0
[pid=30582] ppid=30581 vsize=2564 CPUtime=0
/proc/30582/stat : 30582 (p2cudf-user-1.1) S 30581 30582 17511 34816 17511 4202496 374 0 0 0 0 0 0 0 18 0 1 0 46634914 2625536 269 1283457024 134512640 135304128 4294459728 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30582/statm: 641 269 230 194 0 28 0
[pid=30583] ppid=30582 vsize=2576 CPUtime=0.02
/proc/30583/stat : 30583 (p2cudf) S 30582 30582 17511 34816 17511 4202496 392 3013 0 1 0 0 2 0 25 0 1 0 46634914 2637824 281 1283457024 134512640 135304128 4290282880 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30583/statm: 644 281 239 194 0 31 0
[pid=30596] ppid=30583 vsize=883256 CPUtime=6.07
/proc/30596/stat : 30596 (java) S 30583 30582 17511 34816 17511 4202496 72675 0 1 0 578 29 0 0 25 0 11 0 46634918 904454144 68810 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/30596/statm: 220814 68810 1785 10 0 217905 0
[pid=30596/tid=30597] ppid=30583 vsize=883256 CPUtime=3
/proc/30596/task/30597/stat : 30597 (java) S 30583 30582 17511 34816 17511 4202560 50290 0 1 0 279 21 0 0 25 0 11 0 46634918 904454144 68810 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30598] ppid=30583 vsize=883256 CPUtime=0.26
/proc/30596/task/30598/stat : 30598 (java) S 30583 30582 17511 34816 17511 4202560 10271 0 0 0 23 3 0 0 15 0 11 0 46634920 904454144 68810 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 0 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30599] ppid=30583 vsize=883256 CPUtime=0
/proc/30596/task/30599/stat : 30599 (java) S 30583 30582 17511 34816 17511 4202560 8 0 0 0 0 0 0 0 18 0 11 0 46634920 904454144 68810 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30600] ppid=30583 vsize=883256 CPUtime=0
/proc/30596/task/30600/stat : 30600 (java) S 30583 30582 17511 34816 17511 4202560 6 0 0 0 0 0 0 0 18 0 11 0 46634920 904454144 68810 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30601] ppid=30583 vsize=883256 CPUtime=0
/proc/30596/task/30601/stat : 30601 (java) S 30583 30582 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 11 0 46634923 904454144 68810 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30602] ppid=30583 vsize=883256 CPUtime=2.54
/proc/30596/task/30602/stat : 30602 (java) S 30583 30582 17511 34816 17511 4202560 9076 0 0 0 252 2 0 0 16 0 11 0 46634923 904454144 68810 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30603] ppid=30583 vsize=883256 CPUtime=0.19
/proc/30596/task/30603/stat : 30603 (java) S 30583 30582 17511 34816 17511 4202560 1949 0 0 0 19 0 0 0 21 0 11 0 46634923 904454144 68810 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30604] ppid=30583 vsize=883256 CPUtime=0
/proc/30596/task/30604/stat : 30604 (java) S 30583 30582 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 11 0 46634923 904454144 68810 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30605] ppid=30583 vsize=883256 CPUtime=0
/proc/30596/task/30605/stat : 30605 (java) S 30583 30582 17511 34816 17511 4202560 2 0 0 0 0 0 0 0 15 0 11 0 46634923 904454144 68810 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30607] ppid=30583 vsize=883256 CPUtime=0.04
/proc/30596/task/30607/stat : 30607 (java) R 30583 30582 17511 34816 17511 4202560 6 0 0 0 4 0 0 0 20 0 11 0 46635519 904454144 68810 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.09
Current children cumulated vsize (KiB) 888396

[startup+6.70606 s]
/proc/loadavg: 1.22 1.17 1.12 2/48 30607
/proc/meminfo: memFree=401128/1048576 swapFree=0/0
[pid=30582] ppid=30581 vsize=2564 CPUtime=0
/proc/30582/stat : 30582 (p2cudf-user-1.1) S 30581 30582 17511 34816 17511 4202496 374 0 0 0 0 0 0 0 18 0 1 0 46634914 2625536 269 1283457024 134512640 135304128 4294459728 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30582/statm: 641 269 230 194 0 28 0
[pid=30583] ppid=30582 vsize=2576 CPUtime=0.02
/proc/30583/stat : 30583 (p2cudf) S 30582 30582 17511 34816 17511 4202496 392 3013 0 1 0 0 2 0 25 0 1 0 46634914 2637824 281 1283457024 134512640 135304128 4290282880 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30583/statm: 644 281 239 194 0 31 0
[pid=30596] ppid=30583 vsize=883256 CPUtime=6.17
/proc/30596/stat : 30596 (java) S 30583 30582 17511 34816 17511 4202496 72683 0 1 0 586 31 0 0 25 0 10 0 46634918 904454144 68818 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/30596/statm: 220814 68818 1785 10 0 217905 0
[pid=30596/tid=30597] ppid=30583 vsize=883256 CPUtime=3
/proc/30596/task/30597/stat : 30597 (java) S 30583 30582 17511 34816 17511 4202560 50290 0 1 0 279 21 0 0 19 0 10 0 46634918 904454144 68818 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30598] ppid=30583 vsize=883256 CPUtime=0.26
/proc/30596/task/30598/stat : 30598 (java) S 30583 30582 17511 34816 17511 4202560 10271 0 0 0 23 3 0 0 15 0 10 0 46634920 904454144 68818 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 0 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30599] ppid=30583 vsize=883256 CPUtime=0
/proc/30596/task/30599/stat : 30599 (java) S 30583 30582 17511 34816 17511 4202560 8 0 0 0 0 0 0 0 18 0 10 0 46634920 904454144 68818 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30600] ppid=30583 vsize=883256 CPUtime=0
/proc/30596/task/30600/stat : 30600 (java) S 30583 30582 17511 34816 17511 4202560 6 0 0 0 0 0 0 0 18 0 10 0 46634920 904454144 68818 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30601] ppid=30583 vsize=883256 CPUtime=0
/proc/30596/task/30601/stat : 30601 (java) S 30583 30582 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46634923 904454144 68818 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30602] ppid=30583 vsize=883256 CPUtime=2.57
/proc/30596/task/30602/stat : 30602 (java) S 30583 30582 17511 34816 17511 4202560 9083 0 0 0 255 2 0 0 16 0 10 0 46634923 904454144 68818 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30603] ppid=30583 vsize=883256 CPUtime=0.19
/proc/30596/task/30603/stat : 30603 (java) S 30583 30582 17511 34816 17511 4202560 1949 0 0 0 19 0 0 0 21 0 10 0 46634923 904454144 68818 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30604] ppid=30583 vsize=883256 CPUtime=0
/proc/30596/task/30604/stat : 30604 (java) S 30583 30582 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46634923 904454144 68818 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 18446612133395359680 0 0 -1 0 0 0 0
[pid=30596/tid=30605] ppid=30583 vsize=883256 CPUtime=0
/proc/30596/task/30605/stat : 30605 (java) R 30583 30582 17511 34816 17511 4202560 2 0 0 0 0 0 0 0 15 0 10 0 46634923 904454144 68818 1283457024 134512640 134550932 4289663872 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.19
Current children cumulated vsize (KiB) 888396

Child status: 0
Real time (s): 6.72304
CPU time (s): 6.21639
CPU user time (s): 5.88037
CPU system time (s): 0.336021
CPU usage (%): 92.4639
Max. virtual memory (cumulated for all children) (KiB): 890760

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 5.88037
system time used= 0.336021
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 76487
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= 860
involuntary context switches= 844

runsolver used 0 second user time and 0 second system time

The end