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/201108311143/p2cudf-user-1.13/301cbe92-a79c-11e0-9181-00163e1e087d.cudf.dudf-real.log.runsolver ./p2cudf-user-1.13 /home/misc2010/data/2011/dudf-real//301cbe92-a79c-11e0-9181-00163e1e087d.cudf /home/misc2010/tmp/201108311143/p2cudf-user-1.13/301cbe92-a79c-11e0-9181-00163e1e087d.cudf.dudf-real.result -sum(installedsize) 

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.16 1.09 1.03 3/37 24408
/proc/meminfo: memFree=584976/1048576 swapFree=0/0
[pid=24407] ppid=24406 vsize=2564 CPUtime=0
/proc/24407/stat : 24407 (p2cudf-user-1.1) R 24406 24407 19908 34817 19908 4202496 355 0 0 0 0 0 0 0 25 0 1 0 62939341 2625536 269 1283457024 134512640 135304128 4291358304 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/24407/statm: 641 269 230 194 0 28 0
[pid=24408] ppid=24407 vsize=2564 CPUtime=0
/proc/24408/stat : 24408 (p2cudf-user-1.1) R 24407 24407 19908 34817 19908 4202560 0 0 0 0 0 0 0 0 25 0 1 0 62939341 2625536 39 1283457024 134512640 135304128 4291358304 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/24408/statm: 641 39 0 194 0 28 0

[startup+0.155641 s]
/proc/loadavg: 1.16 1.09 1.03 3/37 24408
/proc/meminfo: memFree=584976/1048576 swapFree=0/0
[pid=24407] ppid=24406 vsize=2564 CPUtime=0
/proc/24407/stat : 24407 (p2cudf-user-1.1) S 24406 24407 19908 34817 19908 4202496 373 0 0 0 0 0 0 0 25 0 1 0 62939341 2625536 269 1283457024 134512640 135304128 4291358304 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24407/statm: 641 269 230 194 0 28 0
[pid=24408] ppid=24407 vsize=2580 CPUtime=0.02
/proc/24408/stat : 24408 (p2cudf) S 24407 24407 19908 34817 19908 4202496 394 3013 0 1 0 0 0 2 25 0 1 0 62939341 2641920 282 1283457024 134512640 135304128 4292482976 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24408/statm: 645 282 239 194 0 32 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5144

[startup+0.20564 s]
/proc/loadavg: 1.16 1.09 1.03 3/37 24408
/proc/meminfo: memFree=584976/1048576 swapFree=0/0
[pid=24407] ppid=24406 vsize=2564 CPUtime=0
/proc/24407/stat : 24407 (p2cudf-user-1.1) S 24406 24407 19908 34817 19908 4202496 373 0 0 0 0 0 0 0 25 0 1 0 62939341 2625536 269 1283457024 134512640 135304128 4291358304 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24407/statm: 641 269 230 194 0 28 0
[pid=24408] ppid=24407 vsize=2580 CPUtime=0.02
/proc/24408/stat : 24408 (p2cudf) S 24407 24407 19908 34817 19908 4202496 394 3013 0 1 0 0 0 2 25 0 1 0 62939341 2641920 282 1283457024 134512640 135304128 4292482976 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24408/statm: 645 282 239 194 0 32 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5144

[startup+0.305657 s]
/proc/loadavg: 1.16 1.09 1.03 3/37 24408
/proc/meminfo: memFree=584976/1048576 swapFree=0/0
[pid=24407] ppid=24406 vsize=2564 CPUtime=0
/proc/24407/stat : 24407 (p2cudf-user-1.1) S 24406 24407 19908 34817 19908 4202496 373 0 0 0 0 0 0 0 25 0 1 0 62939341 2625536 269 1283457024 134512640 135304128 4291358304 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24407/statm: 641 269 230 194 0 28 0
[pid=24408] ppid=24407 vsize=2580 CPUtime=0.02
/proc/24408/stat : 24408 (p2cudf) S 24407 24407 19908 34817 19908 4202496 394 3013 0 1 0 0 0 2 25 0 1 0 62939341 2641920 282 1283457024 134512640 135304128 4292482976 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24408/statm: 645 282 239 194 0 32 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5144

[startup+0.705738 s]
/proc/loadavg: 1.16 1.09 1.03 3/37 24408
/proc/meminfo: memFree=584976/1048576 swapFree=0/0
[pid=24407] ppid=24406 vsize=2564 CPUtime=0
/proc/24407/stat : 24407 (p2cudf-user-1.1) S 24406 24407 19908 34817 19908 4202496 373 0 0 0 0 0 0 0 25 0 1 0 62939341 2625536 269 1283457024 134512640 135304128 4291358304 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24407/statm: 641 269 230 194 0 28 0
[pid=24408] ppid=24407 vsize=2580 CPUtime=0.02
/proc/24408/stat : 24408 (p2cudf) S 24407 24407 19908 34817 19908 4202496 394 3013 0 1 0 0 0 2 25 0 1 0 62939341 2641920 282 1283457024 134512640 135304128 4292482976 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24408/statm: 645 282 239 194 0 32 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5144

[startup+1.50592 s]
/proc/loadavg: 1.39 1.14 1.04 5/48 24430
/proc/meminfo: memFree=539488/1048576 swapFree=0/0
[pid=24407] ppid=24406 vsize=2564 CPUtime=0
/proc/24407/stat : 24407 (p2cudf-user-1.1) S 24406 24407 19908 34817 19908 4202496 373 0 0 0 0 0 0 0 25 0 1 0 62939341 2625536 269 1283457024 134512640 135304128 4291358304 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24407/statm: 641 269 230 194 0 28 0
[pid=24408] ppid=24407 vsize=2580 CPUtime=0.02
/proc/24408/stat : 24408 (p2cudf) S 24407 24407 19908 34817 19908 4202496 394 3013 0 1 0 0 0 2 25 0 1 0 62939341 2641920 282 1283457024 134512640 135304128 4292482976 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24408/statm: 645 282 239 194 0 32 0
[pid=24421] ppid=24408 vsize=888928 CPUtime=1.47
/proc/24421/stat : 24421 (java) S 24408 24407 19908 34817 19908 4202496 21272 0 1 0 145 2 0 0 25 0 10 0 62939345 910262272 18269 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/24421/statm: 222232 18269 1721 10 0 219323 0
[pid=24421/tid=24422] ppid=24408 vsize=888928 CPUtime=0.79
/proc/24421/task/24422/stat : 24422 (java) R 24408 24407 19908 34817 19908 4202560 9239 0 1 0 79 0 0 0 25 0 10 0 62939345 910262272 18269 1283457024 134512640 134550932 4293039808 18446744073709551615 4095365996 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=24421/tid=24423] ppid=24408 vsize=888928 CPUtime=0
/proc/24421/task/24423/stat : 24423 (java) S 24408 24407 19908 34817 19908 4202560 7 0 0 0 0 0 0 0 16 0 10 0 62939347 910262272 18269 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 0 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24424] ppid=24408 vsize=888928 CPUtime=0
/proc/24421/task/24424/stat : 24424 (java) S 24408 24407 19908 34817 19908 4202560 8 0 0 0 0 0 0 0 25 0 10 0 62939347 910262272 18269 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24425] ppid=24408 vsize=888928 CPUtime=0
/proc/24421/task/24425/stat : 24425 (java) S 24408 24407 19908 34817 19908 4202560 4 0 0 0 0 0 0 0 25 0 10 0 62939347 910262272 18269 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24426] ppid=24408 vsize=888928 CPUtime=0
/proc/24421/task/24426/stat : 24426 (java) S 24408 24407 19908 34817 19908 4202560 1 0 0 0 0 0 0 0 25 0 10 0 62939350 910262272 18269 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24427] ppid=24408 vsize=888928 CPUtime=0.39
/proc/24421/task/24427/stat : 24427 (java) R 24408 24407 19908 34817 19908 4202560 8460 0 0 0 39 0 0 0 21 0 10 0 62939350 910262272 18269 1283457024 134512640 134550932 4293039808 18446744073709551615 4152340551 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=24421/tid=24428] ppid=24408 vsize=888928 CPUtime=0.27
/proc/24421/task/24428/stat : 24428 (java) R 24408 24407 19908 34817 19908 4202560 2494 0 0 0 26 1 0 0 25 0 10 0 62939350 910262272 18269 1283457024 134512640 134550932 4293039808 18446744073709551615 4152469136 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=24421/tid=24429] ppid=24408 vsize=888928 CPUtime=0
/proc/24421/task/24429/stat : 24429 (java) S 24408 24407 19908 34817 19908 4202560 1 0 0 0 0 0 0 0 25 0 10 0 62939350 910262272 18269 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24430] ppid=24408 vsize=888928 CPUtime=0
/proc/24421/task/24430/stat : 24430 (java) S 24408 24407 19908 34817 19908 4202560 1 0 0 0 0 0 0 0 15 0 10 0 62939350 910262272 18269 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.49
Current children cumulated vsize (KiB) 894072

[startup+3.10633 s]
/proc/loadavg: 1.39 1.14 1.04 2/48 24430
/proc/meminfo: memFree=421812/1048576 swapFree=0/0
[pid=24407] ppid=24406 vsize=2564 CPUtime=0
/proc/24407/stat : 24407 (p2cudf-user-1.1) S 24406 24407 19908 34817 19908 4202496 373 0 0 0 0 0 0 0 25 0 1 0 62939341 2625536 269 1283457024 134512640 135304128 4291358304 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24407/statm: 641 269 230 194 0 28 0
[pid=24408] ppid=24407 vsize=2580 CPUtime=0.02
/proc/24408/stat : 24408 (p2cudf) S 24407 24407 19908 34817 19908 4202496 394 3013 0 1 0 0 0 2 25 0 1 0 62939341 2641920 282 1283457024 134512640 135304128 4292482976 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24408/statm: 645 282 239 194 0 32 0
[pid=24421] ppid=24408 vsize=885496 CPUtime=3.06
/proc/24421/stat : 24421 (java) S 24408 24407 19908 34817 19908 4202496 74804 0 1 0 288 18 0 0 25 0 10 0 62939345 906747904 71351 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/24421/statm: 221374 71351 1753 10 0 218465 0
[pid=24421/tid=24422] ppid=24408 vsize=885496 CPUtime=1.8
/proc/24421/task/24422/stat : 24422 (java) R 24408 24407 19908 34817 19908 4202560 50090 0 1 0 164 16 0 0 25 0 10 0 62939345 906747904 71351 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=24421/tid=24423] ppid=24408 vsize=885496 CPUtime=0.26
/proc/24421/task/24423/stat : 24423 (java) S 24408 24407 19908 34817 19908 4202560 12575 0 0 0 25 1 0 0 16 0 10 0 62939347 906747904 71351 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 0 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24424] ppid=24408 vsize=885496 CPUtime=0
/proc/24421/task/24424/stat : 24424 (java) S 24408 24407 19908 34817 19908 4202560 9 0 0 0 0 0 0 0 18 0 10 0 62939347 906747904 71351 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24425] ppid=24408 vsize=885496 CPUtime=0
/proc/24421/task/24425/stat : 24425 (java) S 24408 24407 19908 34817 19908 4202560 5 0 0 0 0 0 0 0 18 0 10 0 62939347 906747904 71351 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24426] ppid=24408 vsize=885496 CPUtime=0
/proc/24421/task/24426/stat : 24426 (java) S 24408 24407 19908 34817 19908 4202560 1 0 0 0 0 0 0 0 25 0 10 0 62939350 906747904 71351 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24427] ppid=24408 vsize=885496 CPUtime=0.46
/proc/24421/task/24427/stat : 24427 (java) S 24408 24407 19908 34817 19908 4202560 8517 0 0 0 46 0 0 0 19 0 10 0 62939350 906747904 71351 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24428] ppid=24408 vsize=885496 CPUtime=0.53
/proc/24421/task/24428/stat : 24428 (java) R 24408 24407 19908 34817 19908 4202560 2548 0 0 0 52 1 0 0 16 0 10 0 62939350 906747904 71351 1283457024 134512640 134550932 4293039808 18446744073709551615 4148570805 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=24421/tid=24429] ppid=24408 vsize=885496 CPUtime=0
/proc/24421/task/24429/stat : 24429 (java) S 24408 24407 19908 34817 19908 4202560 1 0 0 0 0 0 0 0 25 0 10 0 62939350 906747904 71351 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24430] ppid=24408 vsize=885496 CPUtime=0
/proc/24421/task/24430/stat : 24430 (java) S 24408 24407 19908 34817 19908 4202560 1 0 0 0 0 0 0 0 15 0 10 0 62939350 906747904 71351 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.08
Current children cumulated vsize (KiB) 890640

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

[startup+3.21636 s]
/proc/loadavg: 1.39 1.14 1.04 2/48 24430
/proc/meminfo: memFree=421812/1048576 swapFree=0/0
[pid=24407] ppid=24406 vsize=2564 CPUtime=0
/proc/24407/stat : 24407 (p2cudf-user-1.1) S 24406 24407 19908 34817 19908 4202496 373 0 0 0 0 0 0 0 25 0 1 0 62939341 2625536 269 1283457024 134512640 135304128 4291358304 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24407/statm: 641 269 230 194 0 28 0
[pid=24408] ppid=24407 vsize=2580 CPUtime=0.02
/proc/24408/stat : 24408 (p2cudf) S 24407 24407 19908 34817 19908 4202496 394 3013 0 1 0 0 0 2 25 0 1 0 62939341 2641920 282 1283457024 134512640 135304128 4292482976 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24408/statm: 645 282 239 194 0 32 0
[pid=24421] ppid=24408 vsize=885496 CPUtime=3.16
/proc/24421/stat : 24421 (java) S 24408 24407 19908 34817 19908 4202496 74811 0 1 0 298 18 0 0 25 0 10 0 62939345 906747904 71358 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/24421/statm: 221374 71358 1753 10 0 218465 0
[pid=24421/tid=24422] ppid=24408 vsize=885496 CPUtime=1.82
/proc/24421/task/24422/stat : 24422 (java) R 24408 24407 19908 34817 19908 4202560 50090 0 1 0 166 16 0 0 25 0 10 0 62939345 906747904 71358 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=24421/tid=24423] ppid=24408 vsize=885496 CPUtime=0.26
/proc/24421/task/24423/stat : 24423 (java) S 24408 24407 19908 34817 19908 4202560 12575 0 0 0 25 1 0 0 16 0 10 0 62939347 906747904 71358 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 0 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24424] ppid=24408 vsize=885496 CPUtime=0
/proc/24421/task/24424/stat : 24424 (java) S 24408 24407 19908 34817 19908 4202560 9 0 0 0 0 0 0 0 18 0 10 0 62939347 906747904 71358 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24425] ppid=24408 vsize=885496 CPUtime=0
/proc/24421/task/24425/stat : 24425 (java) S 24408 24407 19908 34817 19908 4202560 5 0 0 0 0 0 0 0 18 0 10 0 62939347 906747904 71358 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24426] ppid=24408 vsize=885496 CPUtime=0
/proc/24421/task/24426/stat : 24426 (java) S 24408 24407 19908 34817 19908 4202560 1 0 0 0 0 0 0 0 25 0 10 0 62939350 906747904 71358 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24427] ppid=24408 vsize=885496 CPUtime=0.46
/proc/24421/task/24427/stat : 24427 (java) S 24408 24407 19908 34817 19908 4202560 8517 0 0 0 46 0 0 0 19 0 10 0 62939350 906747904 71358 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24428] ppid=24408 vsize=885496 CPUtime=0.61
/proc/24421/task/24428/stat : 24428 (java) R 24408 24407 19908 34817 19908 4202560 2555 0 0 0 60 1 0 0 15 0 10 0 62939350 906747904 71358 1283457024 134512640 134550932 4293039808 18446744073709551615 4151759082 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=24421/tid=24429] ppid=24408 vsize=885496 CPUtime=0
/proc/24421/task/24429/stat : 24429 (java) S 24408 24407 19908 34817 19908 4202560 1 0 0 0 0 0 0 0 25 0 10 0 62939350 906747904 71358 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24430] ppid=24408 vsize=885496 CPUtime=0
/proc/24421/task/24430/stat : 24430 (java) S 24408 24407 19908 34817 19908 4202560 1 0 0 0 0 0 0 0 15 0 10 0 62939350 906747904 71358 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.18
Current children cumulated vsize (KiB) 890640

[startup+4.00652 s]
/proc/loadavg: 1.39 1.14 1.04 2/48 24430
/proc/meminfo: memFree=305376/1048576 swapFree=0/0
[pid=24407] ppid=24406 vsize=2564 CPUtime=0
/proc/24407/stat : 24407 (p2cudf-user-1.1) S 24406 24407 19908 34817 19908 4202496 373 0 0 0 0 0 0 0 25 0 1 0 62939341 2625536 269 1283457024 134512640 135304128 4291358304 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24407/statm: 641 269 230 194 0 28 0
[pid=24408] ppid=24407 vsize=2580 CPUtime=0.02
/proc/24408/stat : 24408 (p2cudf) S 24407 24407 19908 34817 19908 4202496 394 3013 0 1 0 0 0 2 25 0 1 0 62939341 2641920 282 1283457024 134512640 135304128 4292482976 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24408/statm: 645 282 239 194 0 32 0
[pid=24421] ppid=24408 vsize=885004 CPUtime=3.96
/proc/24421/stat : 24421 (java) S 24408 24407 19908 34817 19908 4202496 76550 0 1 0 376 20 0 0 25 0 10 0 62939345 906244096 71451 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/24421/statm: 221251 71451 1756 10 0 218342 0
[pid=24421/tid=24422] ppid=24408 vsize=885004 CPUtime=2.04
/proc/24421/task/24422/stat : 24422 (java) R 24408 24407 19908 34817 19908 4202560 50226 0 1 0 187 17 0 0 25 0 10 0 62939345 906244096 71451 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=24421/tid=24423] ppid=24408 vsize=885004 CPUtime=0.26
/proc/24421/task/24423/stat : 24423 (java) S 24408 24407 19908 34817 19908 4202560 12575 0 0 0 25 1 0 0 15 0 10 0 62939347 906244096 71451 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 0 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24424] ppid=24408 vsize=885004 CPUtime=0
/proc/24421/task/24424/stat : 24424 (java) S 24408 24407 19908 34817 19908 4202560 9 0 0 0 0 0 0 0 18 0 10 0 62939347 906244096 71451 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24425] ppid=24408 vsize=885004 CPUtime=0
/proc/24421/task/24425/stat : 24425 (java) S 24408 24407 19908 34817 19908 4202560 5 0 0 0 0 0 0 0 18 0 10 0 62939347 906244096 71451 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24426] ppid=24408 vsize=885004 CPUtime=0
/proc/24421/task/24426/stat : 24426 (java) S 24408 24407 19908 34817 19908 4202560 1 0 0 0 0 0 0 0 25 0 10 0 62939350 906244096 71451 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24427] ppid=24408 vsize=885004 CPUtime=0.46
/proc/24421/task/24427/stat : 24427 (java) S 24408 24407 19908 34817 19908 4202560 8517 0 0 0 46 0 0 0 19 0 10 0 62939350 906244096 71451 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24428] ppid=24408 vsize=885004 CPUtime=1.17
/proc/24421/task/24428/stat : 24428 (java) R 24408 24407 19908 34817 19908 4202560 4158 0 0 0 116 1 0 0 16 0 10 0 62939350 906244096 71451 1283457024 134512640 134550932 4293039808 18446744073709551615 4151654225 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=24421/tid=24429] ppid=24408 vsize=885004 CPUtime=0
/proc/24421/task/24429/stat : 24429 (java) S 24408 24407 19908 34817 19908 4202560 1 0 0 0 0 0 0 0 25 0 10 0 62939350 906244096 71451 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24430] ppid=24408 vsize=885004 CPUtime=0
/proc/24421/task/24430/stat : 24430 (java) S 24408 24407 19908 34817 19908 4202560 1 0 0 0 0 0 0 0 15 0 10 0 62939350 906244096 71451 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.98
Current children cumulated vsize (KiB) 890148

[startup+4.80596 s]
/proc/loadavg: 1.39 1.14 1.04 2/48 24430
/proc/meminfo: memFree=304508/1048576 swapFree=0/0
[pid=24407] ppid=24406 vsize=2564 CPUtime=0
/proc/24407/stat : 24407 (p2cudf-user-1.1) S 24406 24407 19908 34817 19908 4202496 373 0 0 0 0 0 0 0 25 0 1 0 62939341 2625536 269 1283457024 134512640 135304128 4291358304 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24407/statm: 641 269 230 194 0 28 0
[pid=24408] ppid=24407 vsize=2580 CPUtime=0.02
/proc/24408/stat : 24408 (p2cudf) S 24407 24407 19908 34817 19908 4202496 394 3013 0 1 0 0 0 2 25 0 1 0 62939341 2641920 282 1283457024 134512640 135304128 4292482976 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24408/statm: 645 282 239 194 0 32 0
[pid=24421] ppid=24408 vsize=885328 CPUtime=4.57
/proc/24421/stat : 24421 (java) S 24408 24407 19908 34817 19908 4202496 76625 0 1 0 437 20 0 0 25 0 11 0 62939345 906575872 71526 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/24421/statm: 221332 71526 1772 10 0 218423 0
[pid=24421/tid=24422] ppid=24408 vsize=885328 CPUtime=2.42
/proc/24421/task/24422/stat : 24422 (java) S 24408 24407 19908 34817 19908 4202560 50255 0 1 0 224 18 0 0 25 0 11 0 62939345 906575872 71526 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24423] ppid=24408 vsize=885328 CPUtime=0.26
/proc/24421/task/24423/stat : 24423 (java) S 24408 24407 19908 34817 19908 4202560 12575 0 0 0 25 1 0 0 15 0 11 0 62939347 906575872 71526 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 0 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24424] ppid=24408 vsize=885328 CPUtime=0
/proc/24421/task/24424/stat : 24424 (java) S 24408 24407 19908 34817 19908 4202560 9 0 0 0 0 0 0 0 18 0 11 0 62939347 906575872 71526 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24425] ppid=24408 vsize=885328 CPUtime=0
/proc/24421/task/24425/stat : 24425 (java) S 24408 24407 19908 34817 19908 4202560 5 0 0 0 0 0 0 0 18 0 11 0 62939347 906575872 71526 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24426] ppid=24408 vsize=885328 CPUtime=0
/proc/24421/task/24426/stat : 24426 (java) S 24408 24407 19908 34817 19908 4202560 1 0 0 0 0 0 0 0 25 0 11 0 62939350 906575872 71526 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24427] ppid=24408 vsize=885328 CPUtime=0.46
/proc/24421/task/24427/stat : 24427 (java) S 24408 24407 19908 34817 19908 4202560 8517 0 0 0 46 0 0 0 19 0 11 0 62939350 906575872 71526 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24428] ppid=24408 vsize=885328 CPUtime=1.41
/proc/24421/task/24428/stat : 24428 (java) S 24408 24407 19908 34817 19908 4202560 4200 0 0 0 140 1 0 0 15 0 11 0 62939350 906575872 71526 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24429] ppid=24408 vsize=885328 CPUtime=0
/proc/24421/task/24429/stat : 24429 (java) S 24408 24407 19908 34817 19908 4202560 1 0 0 0 0 0 0 0 25 0 11 0 62939350 906575872 71526 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24430] ppid=24408 vsize=885328 CPUtime=0
/proc/24421/task/24430/stat : 24430 (java) S 24408 24407 19908 34817 19908 4202560 1 0 0 0 0 0 0 0 15 0 11 0 62939350 906575872 71526 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.59
Current children cumulated vsize (KiB) 890472

[startup+5.00603 s]
/proc/loadavg: 1.39 1.14 1.04 2/48 24430
/proc/meminfo: memFree=304508/1048576 swapFree=0/0
[pid=24407] ppid=24406 vsize=2564 CPUtime=0
/proc/24407/stat : 24407 (p2cudf-user-1.1) S 24406 24407 19908 34817 19908 4202496 373 0 0 0 0 0 0 0 25 0 1 0 62939341 2625536 269 1283457024 134512640 135304128 4291358304 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24407/statm: 641 269 230 194 0 28 0
[pid=24408] ppid=24407 vsize=2580 CPUtime=0.02
/proc/24408/stat : 24408 (p2cudf) S 24407 24407 19908 34817 19908 4202496 394 3013 0 1 0 0 0 2 25 0 1 0 62939341 2641920 282 1283457024 134512640 135304128 4292482976 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24408/statm: 645 282 239 194 0 32 0
[pid=24421] ppid=24408 vsize=885328 CPUtime=4.57
/proc/24421/stat : 24421 (java) S 24408 24407 19908 34817 19908 4202496 76625 0 1 0 437 20 0 0 25 0 11 0 62939345 906575872 71526 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/24421/statm: 221332 71526 1772 10 0 218423 0
[pid=24421/tid=24422] ppid=24408 vsize=885328 CPUtime=2.42
/proc/24421/task/24422/stat : 24422 (java) S 24408 24407 19908 34817 19908 4202560 50255 0 1 0 224 18 0 0 25 0 11 0 62939345 906575872 71526 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24423] ppid=24408 vsize=885328 CPUtime=0.26
/proc/24421/task/24423/stat : 24423 (java) S 24408 24407 19908 34817 19908 4202560 12575 0 0 0 25 1 0 0 15 0 11 0 62939347 906575872 71526 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 0 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24424] ppid=24408 vsize=885328 CPUtime=0
/proc/24421/task/24424/stat : 24424 (java) S 24408 24407 19908 34817 19908 4202560 9 0 0 0 0 0 0 0 18 0 11 0 62939347 906575872 71526 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24425] ppid=24408 vsize=885328 CPUtime=0
/proc/24421/task/24425/stat : 24425 (java) S 24408 24407 19908 34817 19908 4202560 5 0 0 0 0 0 0 0 18 0 11 0 62939347 906575872 71526 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24426] ppid=24408 vsize=885328 CPUtime=0
/proc/24421/task/24426/stat : 24426 (java) S 24408 24407 19908 34817 19908 4202560 1 0 0 0 0 0 0 0 25 0 11 0 62939350 906575872 71526 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24427] ppid=24408 vsize=885328 CPUtime=0.46
/proc/24421/task/24427/stat : 24427 (java) S 24408 24407 19908 34817 19908 4202560 8517 0 0 0 46 0 0 0 19 0 11 0 62939350 906575872 71526 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24428] ppid=24408 vsize=885328 CPUtime=1.41
/proc/24421/task/24428/stat : 24428 (java) S 24408 24407 19908 34817 19908 4202560 4200 0 0 0 140 1 0 0 15 0 11 0 62939350 906575872 71526 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24429] ppid=24408 vsize=885328 CPUtime=0
/proc/24421/task/24429/stat : 24429 (java) S 24408 24407 19908 34817 19908 4202560 1 0 0 0 0 0 0 0 25 0 11 0 62939350 906575872 71526 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24430] ppid=24408 vsize=885328 CPUtime=0
/proc/24421/task/24430/stat : 24430 (java) S 24408 24407 19908 34817 19908 4202560 1 0 0 0 0 0 0 0 15 0 11 0 62939350 906575872 71526 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.59
Current children cumulated vsize (KiB) 890472

[startup+5.10595 s]
/proc/loadavg: 1.39 1.14 1.04 2/48 24430
/proc/meminfo: memFree=304508/1048576 swapFree=0/0
[pid=24407] ppid=24406 vsize=2564 CPUtime=0
/proc/24407/stat : 24407 (p2cudf-user-1.1) S 24406 24407 19908 34817 19908 4202496 373 0 0 0 0 0 0 0 25 0 1 0 62939341 2625536 269 1283457024 134512640 135304128 4291358304 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24407/statm: 641 269 230 194 0 28 0
[pid=24408] ppid=24407 vsize=2580 CPUtime=0.02
/proc/24408/stat : 24408 (p2cudf) S 24407 24407 19908 34817 19908 4202496 394 3013 0 1 0 0 0 2 25 0 1 0 62939341 2641920 282 1283457024 134512640 135304128 4292482976 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24408/statm: 645 282 239 194 0 32 0
[pid=24421] ppid=24408 vsize=885328 CPUtime=4.57
/proc/24421/stat : 24421 (java) S 24408 24407 19908 34817 19908 4202496 76625 0 1 0 437 20 0 0 25 0 11 0 62939345 906575872 71526 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/24421/statm: 221332 71526 1772 10 0 218423 0
[pid=24421/tid=24422] ppid=24408 vsize=885328 CPUtime=2.42
/proc/24421/task/24422/stat : 24422 (java) S 24408 24407 19908 34817 19908 4202560 50255 0 1 0 224 18 0 0 25 0 11 0 62939345 906575872 71526 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24423] ppid=24408 vsize=885328 CPUtime=0.26
/proc/24421/task/24423/stat : 24423 (java) S 24408 24407 19908 34817 19908 4202560 12575 0 0 0 25 1 0 0 15 0 11 0 62939347 906575872 71526 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 0 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24424] ppid=24408 vsize=885328 CPUtime=0
/proc/24421/task/24424/stat : 24424 (java) S 24408 24407 19908 34817 19908 4202560 9 0 0 0 0 0 0 0 18 0 11 0 62939347 906575872 71526 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24425] ppid=24408 vsize=885328 CPUtime=0
/proc/24421/task/24425/stat : 24425 (java) S 24408 24407 19908 34817 19908 4202560 5 0 0 0 0 0 0 0 18 0 11 0 62939347 906575872 71526 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24426] ppid=24408 vsize=885328 CPUtime=0
/proc/24421/task/24426/stat : 24426 (java) S 24408 24407 19908 34817 19908 4202560 1 0 0 0 0 0 0 0 25 0 11 0 62939350 906575872 71526 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24427] ppid=24408 vsize=885328 CPUtime=0.46
/proc/24421/task/24427/stat : 24427 (java) S 24408 24407 19908 34817 19908 4202560 8517 0 0 0 46 0 0 0 19 0 11 0 62939350 906575872 71526 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24428] ppid=24408 vsize=885328 CPUtime=1.41
/proc/24421/task/24428/stat : 24428 (java) S 24408 24407 19908 34817 19908 4202560 4200 0 0 0 140 1 0 0 15 0 11 0 62939350 906575872 71526 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24429] ppid=24408 vsize=885328 CPUtime=0
/proc/24421/task/24429/stat : 24429 (java) S 24408 24407 19908 34817 19908 4202560 1 0 0 0 0 0 0 0 25 0 11 0 62939350 906575872 71526 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
[pid=24421/tid=24430] ppid=24408 vsize=885328 CPUtime=0
/proc/24421/task/24430/stat : 24430 (java) S 24408 24407 19908 34817 19908 4202560 1 0 0 0 0 0 0 0 15 0 11 0 62939350 906575872 71526 1283457024 134512640 134550932 4293039808 18446744073709551615 4294960130 0 4 0 16800975 18446612133002273856 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.59
Current children cumulated vsize (KiB) 890472

Child status: 0
Real time (s): 5.17196
CPU time (s): 4.63629
CPU user time (s): 4.38427
CPU system time (s): 0.252015
CPU usage (%): 89.6428
Max. virtual memory (cumulated for all children) (KiB): 894492

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 4.38427
system time used= 0.252015
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 80431
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= 493
involuntary context switches= 468

runsolver used 0 second user time and 0 second system time

The end