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/ec32fc68-7254-11e0-8436-00163e1e087d.cudf.dudf-real.log.runsolver ./p2cudf-user-1.13 /home/misc2010/data/2011/dudf-real//ec32fc68-7254-11e0-8436-00163e1e087d.cudf /home/misc2010/tmp/201108291842/p2cudf-user-1.13/ec32fc68-7254-11e0-8436-00163e1e087d.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.08 1.14 1.12 5/37 31458
/proc/meminfo: memFree=590608/1048576 swapFree=0/0
[pid=31456] ppid=31455 vsize=2568 CPUtime=0
/proc/31456/stat : 31456 (p2cudf-user-1.1) S 31455 31456 17511 34816 17511 4202496 375 0 0 0 0 0 0 0 18 0 1 0 46671397 2629632 270 1283457024 134512640 135304128 4288478096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31456/statm: 642 270 230 194 0 29 0
[pid=31457] ppid=31456 vsize=2568 CPUtime=0
/proc/31457/stat : 31457 (p2cudf) R 31456 31456 17511 34816 17511 4202496 346 0 0 0 0 0 0 0 25 0 1 0 46671397 2629632 272 1283457024 134512640 135304128 4288357280 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/31457/statm: 642 272 231 194 0 29 0
[pid=31458] ppid=31457 vsize=2568 CPUtime=0
/proc/31458/stat : 31458 (p2cudf) R 31457 31456 17511 34816 17511 4202560 0 0 0 0 0 0 0 0 25 0 1 0 46671398 2629632 41 1283457024 134512640 135304128 4288357280 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/31458/statm: 642 41 0 194 0 29 0

[startup+0.135766 s]
/proc/loadavg: 1.08 1.14 1.12 5/37 31458
/proc/meminfo: memFree=590608/1048576 swapFree=0/0
[pid=31456] ppid=31455 vsize=2568 CPUtime=0
/proc/31456/stat : 31456 (p2cudf-user-1.1) S 31455 31456 17511 34816 17511 4202496 375 0 0 0 0 0 0 0 18 0 1 0 46671397 2629632 270 1283457024 134512640 135304128 4288478096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31456/statm: 642 270 230 194 0 29 0
[pid=31457] ppid=31456 vsize=2572 CPUtime=0.02
/proc/31457/stat : 31457 (p2cudf) S 31456 31456 17511 34816 17511 4202496 392 3010 0 1 0 0 0 2 25 0 1 0 46671397 2633728 281 1283457024 134512640 135304128 4288357280 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31457/statm: 643 281 239 194 0 30 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5140

[startup+0.205765 s]
/proc/loadavg: 1.08 1.14 1.12 5/37 31458
/proc/meminfo: memFree=590608/1048576 swapFree=0/0
[pid=31456] ppid=31455 vsize=2568 CPUtime=0
/proc/31456/stat : 31456 (p2cudf-user-1.1) S 31455 31456 17511 34816 17511 4202496 375 0 0 0 0 0 0 0 18 0 1 0 46671397 2629632 270 1283457024 134512640 135304128 4288478096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31456/statm: 642 270 230 194 0 29 0
[pid=31457] ppid=31456 vsize=2572 CPUtime=0.02
/proc/31457/stat : 31457 (p2cudf) S 31456 31456 17511 34816 17511 4202496 392 3010 0 1 0 0 0 2 25 0 1 0 46671397 2633728 281 1283457024 134512640 135304128 4288357280 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31457/statm: 643 281 239 194 0 30 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5140

[startup+0.305778 s]
/proc/loadavg: 1.08 1.14 1.12 5/37 31458
/proc/meminfo: memFree=590608/1048576 swapFree=0/0
[pid=31456] ppid=31455 vsize=2568 CPUtime=0
/proc/31456/stat : 31456 (p2cudf-user-1.1) S 31455 31456 17511 34816 17511 4202496 375 0 0 0 0 0 0 0 18 0 1 0 46671397 2629632 270 1283457024 134512640 135304128 4288478096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31456/statm: 642 270 230 194 0 29 0
[pid=31457] ppid=31456 vsize=2572 CPUtime=0.02
/proc/31457/stat : 31457 (p2cudf) S 31456 31456 17511 34816 17511 4202496 392 3010 0 1 0 0 0 2 25 0 1 0 46671397 2633728 281 1283457024 134512640 135304128 4288357280 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31457/statm: 643 281 239 194 0 30 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5140

[startup+0.705854 s]
/proc/loadavg: 1.08 1.14 1.12 5/37 31458
/proc/meminfo: memFree=590608/1048576 swapFree=0/0
[pid=31456] ppid=31455 vsize=2568 CPUtime=0
/proc/31456/stat : 31456 (p2cudf-user-1.1) S 31455 31456 17511 34816 17511 4202496 375 0 0 0 0 0 0 0 18 0 1 0 46671397 2629632 270 1283457024 134512640 135304128 4288478096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31456/statm: 642 270 230 194 0 29 0
[pid=31457] ppid=31456 vsize=2572 CPUtime=0.02
/proc/31457/stat : 31457 (p2cudf) S 31456 31456 17511 34816 17511 4202496 392 3010 0 1 0 0 0 2 25 0 1 0 46671397 2633728 281 1283457024 134512640 135304128 4288357280 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31457/statm: 643 281 239 194 0 30 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5140

[startup+1.50607 s]
/proc/loadavg: 1.23 1.17 1.13 3/47 31479
/proc/meminfo: memFree=537880/1048576 swapFree=0/0
[pid=31456] ppid=31455 vsize=2568 CPUtime=0
/proc/31456/stat : 31456 (p2cudf-user-1.1) S 31455 31456 17511 34816 17511 4202496 375 0 0 0 0 0 0 0 18 0 1 0 46671397 2629632 270 1283457024 134512640 135304128 4288478096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31456/statm: 642 270 230 194 0 29 0
[pid=31457] ppid=31456 vsize=2572 CPUtime=0.02
/proc/31457/stat : 31457 (p2cudf) S 31456 31456 17511 34816 17511 4202496 392 3010 0 1 0 0 0 2 25 0 1 0 46671397 2633728 281 1283457024 134512640 135304128 4288357280 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31457/statm: 643 281 239 194 0 30 0
[pid=31470] ppid=31457 vsize=884424 CPUtime=1.47
/proc/31470/stat : 31470 (java) S 31457 31456 17511 34816 17511 4202496 22011 0 1 0 140 7 0 0 25 0 10 0 46671401 905650176 18589 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/31470/statm: 221106 18589 1721 10 0 218197 0
[pid=31470/tid=31471] ppid=31457 vsize=884424 CPUtime=0.8
/proc/31470/task/31471/stat : 31471 (java) R 31457 31456 17511 34816 17511 4202560 10628 0 1 0 76 4 0 0 25 0 10 0 46671401 905650176 18589 1283457024 134512640 134550932 4291779968 18446744073709551615 4095482996 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=31470/tid=31472] ppid=31457 vsize=884424 CPUtime=0
/proc/31470/task/31472/stat : 31472 (java) S 31457 31456 17511 34816 17511 4202560 7 0 0 0 0 0 0 0 18 0 10 0 46671403 905650176 18589 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 0 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31473] ppid=31457 vsize=884424 CPUtime=0
/proc/31470/task/31473/stat : 31473 (java) S 31457 31456 17511 34816 17511 4202560 8 0 0 0 0 0 0 0 25 0 10 0 46671403 905650176 18589 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31474] ppid=31457 vsize=884424 CPUtime=0
/proc/31470/task/31474/stat : 31474 (java) S 31457 31456 17511 34816 17511 4202560 4 0 0 0 0 0 0 0 25 0 10 0 46671403 905650176 18589 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31475] ppid=31457 vsize=884424 CPUtime=0
/proc/31470/task/31475/stat : 31475 (java) S 31457 31456 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46671406 905650176 18589 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31476] ppid=31457 vsize=884424 CPUtime=0.43
/proc/31470/task/31476/stat : 31476 (java) R 31457 31456 17511 34816 17511 4202560 8476 0 0 0 42 1 0 0 25 0 10 0 46671406 905650176 18589 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=31470/tid=31477] ppid=31457 vsize=884424 CPUtime=0.21
/proc/31470/task/31477/stat : 31477 (java) R 31457 31456 17511 34816 17511 4202560 1828 0 0 0 20 1 0 0 18 0 10 0 46671406 905650176 18589 1283457024 134512640 134550932 4291779968 18446744073709551615 4151710784 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=31470/tid=31478] ppid=31457 vsize=884424 CPUtime=0
/proc/31470/task/31478/stat : 31478 (java) S 31457 31456 17511 34816 17511 4202560 0 0 0 0 0 0 0 0 25 0 10 0 46671406 905650176 18589 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31479] ppid=31457 vsize=884424 CPUtime=0
/proc/31470/task/31479/stat : 31479 (java) S 31457 31456 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 15 0 10 0 46671406 905650176 18589 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.49
Current children cumulated vsize (KiB) 889564

[startup+3.10746 s]
/proc/loadavg: 1.23 1.17 1.13 2/47 31479
/proc/meminfo: memFree=446492/1048576 swapFree=0/0
[pid=31456] ppid=31455 vsize=2568 CPUtime=0
/proc/31456/stat : 31456 (p2cudf-user-1.1) S 31455 31456 17511 34816 17511 4202496 375 0 0 0 0 0 0 0 18 0 1 0 46671397 2629632 270 1283457024 134512640 135304128 4288478096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31456/statm: 642 270 230 194 0 29 0
[pid=31457] ppid=31456 vsize=2572 CPUtime=0.02
/proc/31457/stat : 31457 (p2cudf) S 31456 31456 17511 34816 17511 4202496 392 3010 0 1 0 0 0 2 25 0 1 0 46671397 2633728 281 1283457024 134512640 135304128 4288357280 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31457/statm: 643 281 239 194 0 30 0
[pid=31470] ppid=31457 vsize=884532 CPUtime=3.07
/proc/31470/stat : 31470 (java) S 31457 31456 17511 34816 17511 4202496 58742 0 1 0 288 19 0 0 25 0 10 0 46671401 905760768 53716 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/31470/statm: 221133 53716 1744 10 0 218224 0
[pid=31470/tid=31471] ppid=31457 vsize=884532 CPUtime=1.59
/proc/31470/task/31471/stat : 31471 (java) R 31457 31456 17511 34816 17511 4202560 45379 0 1 0 143 16 0 0 25 0 10 0 46671401 905760768 53716 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=31470/tid=31472] ppid=31457 vsize=884532 CPUtime=0
/proc/31470/task/31472/stat : 31472 (java) S 31457 31456 17511 34816 17511 4202560 7 0 0 0 0 0 0 0 18 0 10 0 46671403 905760768 53716 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 0 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31473] ppid=31457 vsize=884532 CPUtime=0
/proc/31470/task/31473/stat : 31473 (java) S 31457 31456 17511 34816 17511 4202560 8 0 0 0 0 0 0 0 25 0 10 0 46671403 905760768 53716 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31474] ppid=31457 vsize=884532 CPUtime=0
/proc/31470/task/31474/stat : 31474 (java) S 31457 31456 17511 34816 17511 4202560 4 0 0 0 0 0 0 0 25 0 10 0 46671403 905760768 53716 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31475] ppid=31457 vsize=884532 CPUtime=0
/proc/31470/task/31475/stat : 31475 (java) S 31457 31456 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46671406 905760768 53716 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31476] ppid=31457 vsize=884532 CPUtime=0.78
/proc/31470/task/31476/stat : 31476 (java) R 31457 31456 17511 34816 17511 4202560 9985 0 0 0 77 1 0 0 22 0 10 0 46671406 905760768 53716 1283457024 134512640 134550932 4291779968 18446744073709551615 4150106980 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=31470/tid=31477] ppid=31457 vsize=884532 CPUtime=0.67
/proc/31470/task/31477/stat : 31477 (java) S 31457 31456 17511 34816 17511 4202560 2299 0 0 0 66 1 0 0 15 0 10 0 46671406 905760768 53716 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31478] ppid=31457 vsize=884532 CPUtime=0
/proc/31470/task/31478/stat : 31478 (java) S 31457 31456 17511 34816 17511 4202560 0 0 0 0 0 0 0 0 25 0 10 0 46671406 905760768 53716 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31479] ppid=31457 vsize=884532 CPUtime=0
/proc/31470/task/31479/stat : 31479 (java) S 31457 31456 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 15 0 10 0 46671406 905760768 53716 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.09
Current children cumulated vsize (KiB) 889672

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

[startup+3.20746 s]
/proc/loadavg: 1.23 1.17 1.13 2/47 31479
/proc/meminfo: memFree=446492/1048576 swapFree=0/0
[pid=31456] ppid=31455 vsize=2568 CPUtime=0
/proc/31456/stat : 31456 (p2cudf-user-1.1) S 31455 31456 17511 34816 17511 4202496 375 0 0 0 0 0 0 0 18 0 1 0 46671397 2629632 270 1283457024 134512640 135304128 4288478096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31456/statm: 642 270 230 194 0 29 0
[pid=31457] ppid=31456 vsize=2572 CPUtime=0.02
/proc/31457/stat : 31457 (p2cudf) S 31456 31456 17511 34816 17511 4202496 392 3010 0 1 0 0 0 2 25 0 1 0 46671397 2633728 281 1283457024 134512640 135304128 4288357280 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31457/statm: 643 281 239 194 0 30 0
[pid=31470] ppid=31457 vsize=884532 CPUtime=3.16
/proc/31470/stat : 31470 (java) S 31457 31456 17511 34816 17511 4202496 59519 0 1 0 296 20 0 0 25 0 10 0 46671401 905760768 54493 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/31470/statm: 221133 54493 1744 10 0 218224 0
[pid=31470/tid=31471] ppid=31457 vsize=884532 CPUtime=1.65
/proc/31470/task/31471/stat : 31471 (java) R 31457 31456 17511 34816 17511 4202560 46145 0 1 0 148 17 0 0 25 0 10 0 46671401 905760768 54493 1283457024 134512640 134550932 4291779968 18446744073709551615 4095233822 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=31470/tid=31472] ppid=31457 vsize=884532 CPUtime=0
/proc/31470/task/31472/stat : 31472 (java) S 31457 31456 17511 34816 17511 4202560 7 0 0 0 0 0 0 0 15 0 10 0 46671403 905760768 54493 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 0 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31473] ppid=31457 vsize=884532 CPUtime=0
/proc/31470/task/31473/stat : 31473 (java) S 31457 31456 17511 34816 17511 4202560 8 0 0 0 0 0 0 0 25 0 10 0 46671403 905760768 54493 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31474] ppid=31457 vsize=884532 CPUtime=0
/proc/31470/task/31474/stat : 31474 (java) S 31457 31456 17511 34816 17511 4202560 4 0 0 0 0 0 0 0 25 0 10 0 46671403 905760768 54493 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31475] ppid=31457 vsize=884532 CPUtime=0
/proc/31470/task/31475/stat : 31475 (java) S 31457 31456 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46671406 905760768 54493 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31476] ppid=31457 vsize=884532 CPUtime=0.79
/proc/31470/task/31476/stat : 31476 (java) R 31457 31456 17511 34816 17511 4202560 9985 0 0 0 78 1 0 0 22 0 10 0 46671406 905760768 54493 1283457024 134512640 134550932 4291779968 18446744073709551615 4150110001 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=31470/tid=31477] ppid=31457 vsize=884532 CPUtime=0.7
/proc/31470/task/31477/stat : 31477 (java) S 31457 31456 17511 34816 17511 4202560 2310 0 0 0 69 1 0 0 15 0 10 0 46671406 905760768 54493 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31478] ppid=31457 vsize=884532 CPUtime=0
/proc/31470/task/31478/stat : 31478 (java) S 31457 31456 17511 34816 17511 4202560 0 0 0 0 0 0 0 0 25 0 10 0 46671406 905760768 54493 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31479] ppid=31457 vsize=884532 CPUtime=0
/proc/31470/task/31479/stat : 31479 (java) S 31457 31456 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 15 0 10 0 46671406 905760768 54493 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.18
Current children cumulated vsize (KiB) 889672

[startup+4.70776 s]
/proc/loadavg: 1.23 1.17 1.13 3/47 31479
/proc/meminfo: memFree=318276/1048576 swapFree=0/0
[pid=31456] ppid=31455 vsize=2568 CPUtime=0
/proc/31456/stat : 31456 (p2cudf-user-1.1) S 31455 31456 17511 34816 17511 4202496 375 0 0 0 0 0 0 0 18 0 1 0 46671397 2629632 270 1283457024 134512640 135304128 4288478096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31456/statm: 642 270 230 194 0 29 0
[pid=31457] ppid=31456 vsize=2572 CPUtime=0.02
/proc/31457/stat : 31457 (p2cudf) S 31456 31456 17511 34816 17511 4202496 392 3010 0 1 0 0 0 2 25 0 1 0 46671397 2633728 281 1283457024 134512640 135304128 4288357280 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31457/statm: 643 281 239 194 0 30 0
[pid=31470] ppid=31457 vsize=882256 CPUtime=4.67
/proc/31470/stat : 31470 (java) S 31457 31456 17511 34816 17511 4202496 75181 0 1 0 440 27 0 0 25 0 11 0 46671401 903430144 69564 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/31470/statm: 220564 69564 1774 10 0 217655 0
[pid=31470/tid=31471] ppid=31457 vsize=882256 CPUtime=2.19
/proc/31470/task/31471/stat : 31471 (java) R 31457 31456 17511 34816 17511 4202560 50273 0 1 0 202 17 0 0 25 0 11 0 46671401 903430144 69564 1283457024 134512640 134550932 4291779968 18446744073709551615 4096106169 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=31470/tid=31472] ppid=31457 vsize=882256 CPUtime=0.25
/proc/31470/task/31472/stat : 31472 (java) S 31457 31456 17511 34816 17511 4202560 11239 0 0 0 19 6 0 0 16 0 11 0 46671403 903430144 69564 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 0 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31473] ppid=31457 vsize=882256 CPUtime=0
/proc/31470/task/31473/stat : 31473 (java) S 31457 31456 17511 34816 17511 4202560 8 0 0 0 0 0 0 0 18 0 11 0 46671403 903430144 69564 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31474] ppid=31457 vsize=882256 CPUtime=0.01
/proc/31470/task/31474/stat : 31474 (java) S 31457 31456 17511 34816 17511 4202560 6 0 0 0 1 0 0 0 18 0 11 0 46671403 903430144 69564 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31475] ppid=31457 vsize=882256 CPUtime=0
/proc/31470/task/31475/stat : 31475 (java) S 31457 31456 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 11 0 46671406 903430144 69564 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31476] ppid=31457 vsize=882256 CPUtime=1.2
/proc/31470/task/31476/stat : 31476 (java) S 31457 31456 17511 34816 17511 4202560 10242 0 0 0 119 1 0 0 20 0 11 0 46671406 903430144 69564 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31477] ppid=31457 vsize=882256 CPUtime=0.98
/proc/31470/task/31477/stat : 31477 (java) S 31457 31456 17511 34816 17511 4202560 2349 0 0 0 97 1 0 0 15 0 11 0 46671406 903430144 69564 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31478] ppid=31457 vsize=882256 CPUtime=0
/proc/31470/task/31478/stat : 31478 (java) S 31457 31456 17511 34816 17511 4202560 0 0 0 0 0 0 0 0 25 0 11 0 46671406 903430144 69564 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31479] ppid=31457 vsize=882256 CPUtime=0
/proc/31470/task/31479/stat : 31479 (java) S 31457 31456 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 15 0 11 0 46671406 903430144 69564 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.69
Current children cumulated vsize (KiB) 887396

[startup+5.50611 s]
/proc/loadavg: 1.29 1.18 1.14 3/48 31480
/proc/meminfo: memFree=318268/1048576 swapFree=0/0
[pid=31456] ppid=31455 vsize=2568 CPUtime=0
/proc/31456/stat : 31456 (p2cudf-user-1.1) S 31455 31456 17511 34816 17511 4202496 375 0 0 0 0 0 0 0 18 0 1 0 46671397 2629632 270 1283457024 134512640 135304128 4288478096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31456/statm: 642 270 230 194 0 29 0
[pid=31457] ppid=31456 vsize=2572 CPUtime=0.02
/proc/31457/stat : 31457 (p2cudf) S 31456 31456 17511 34816 17511 4202496 392 3010 0 1 0 0 0 2 25 0 1 0 46671397 2633728 281 1283457024 134512640 135304128 4288357280 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31457/statm: 643 281 239 194 0 30 0
[pid=31470] ppid=31457 vsize=882580 CPUtime=5.39
/proc/31470/stat : 31470 (java) S 31457 31456 17511 34816 17511 4202496 75247 0 1 0 512 27 0 0 25 0 11 0 46671401 903761920 69630 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/31470/statm: 220645 69630 1783 10 0 217736 0
[pid=31470/tid=31471] ppid=31457 vsize=882580 CPUtime=2.53
/proc/31470/task/31471/stat : 31471 (java) S 31457 31456 17511 34816 17511 4202560 50286 0 1 0 236 17 0 0 25 0 11 0 46671401 903761920 69630 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31472] ppid=31457 vsize=882580 CPUtime=0.25
/proc/31470/task/31472/stat : 31472 (java) S 31457 31456 17511 34816 17511 4202560 11239 0 0 0 19 6 0 0 16 0 11 0 46671403 903761920 69630 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 0 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31473] ppid=31457 vsize=882580 CPUtime=0
/proc/31470/task/31473/stat : 31473 (java) S 31457 31456 17511 34816 17511 4202560 8 0 0 0 0 0 0 0 18 0 11 0 46671403 903761920 69630 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31474] ppid=31457 vsize=882580 CPUtime=0.01
/proc/31470/task/31474/stat : 31474 (java) S 31457 31456 17511 34816 17511 4202560 6 0 0 0 1 0 0 0 18 0 11 0 46671403 903761920 69630 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31475] ppid=31457 vsize=882580 CPUtime=0
/proc/31470/task/31475/stat : 31475 (java) S 31457 31456 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 11 0 46671406 903761920 69630 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31476] ppid=31457 vsize=882580 CPUtime=1.57
/proc/31470/task/31476/stat : 31476 (java) S 31457 31456 17511 34816 17511 4202560 10289 0 0 0 156 1 0 0 18 0 11 0 46671406 903761920 69630 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31477] ppid=31457 vsize=882580 CPUtime=0.99
/proc/31470/task/31477/stat : 31477 (java) S 31457 31456 17511 34816 17511 4202560 2350 0 0 0 98 1 0 0 15 0 11 0 46671406 903761920 69630 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31478] ppid=31457 vsize=882580 CPUtime=0
/proc/31470/task/31478/stat : 31478 (java) S 31457 31456 17511 34816 17511 4202560 0 0 0 0 0 0 0 0 25 0 11 0 46671406 903761920 69630 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31479] ppid=31457 vsize=882580 CPUtime=0
/proc/31470/task/31479/stat : 31479 (java) S 31457 31456 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 15 0 11 0 46671406 903761920 69630 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 5.41
Current children cumulated vsize (KiB) 887720

[startup+5.9061 s]
/proc/loadavg: 1.29 1.18 1.14 3/48 31480
/proc/meminfo: memFree=318268/1048576 swapFree=0/0
[pid=31456] ppid=31455 vsize=2568 CPUtime=0
/proc/31456/stat : 31456 (p2cudf-user-1.1) S 31455 31456 17511 34816 17511 4202496 375 0 0 0 0 0 0 0 18 0 1 0 46671397 2629632 270 1283457024 134512640 135304128 4288478096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31456/statm: 642 270 230 194 0 29 0
[pid=31457] ppid=31456 vsize=2572 CPUtime=0.02
/proc/31457/stat : 31457 (p2cudf) S 31456 31456 17511 34816 17511 4202496 392 3010 0 1 0 0 0 2 25 0 1 0 46671397 2633728 281 1283457024 134512640 135304128 4288357280 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31457/statm: 643 281 239 194 0 30 0
[pid=31470] ppid=31457 vsize=882580 CPUtime=5.39
/proc/31470/stat : 31470 (java) S 31457 31456 17511 34816 17511 4202496 75247 0 1 0 512 27 0 0 25 0 11 0 46671401 903761920 69630 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/31470/statm: 220645 69630 1783 10 0 217736 0
[pid=31470/tid=31471] ppid=31457 vsize=882580 CPUtime=2.53
/proc/31470/task/31471/stat : 31471 (java) S 31457 31456 17511 34816 17511 4202560 50286 0 1 0 236 17 0 0 25 0 11 0 46671401 903761920 69630 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31472] ppid=31457 vsize=882580 CPUtime=0.25
/proc/31470/task/31472/stat : 31472 (java) S 31457 31456 17511 34816 17511 4202560 11239 0 0 0 19 6 0 0 16 0 11 0 46671403 903761920 69630 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 0 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31473] ppid=31457 vsize=882580 CPUtime=0
/proc/31470/task/31473/stat : 31473 (java) S 31457 31456 17511 34816 17511 4202560 8 0 0 0 0 0 0 0 18 0 11 0 46671403 903761920 69630 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31474] ppid=31457 vsize=882580 CPUtime=0.01
/proc/31470/task/31474/stat : 31474 (java) S 31457 31456 17511 34816 17511 4202560 6 0 0 0 1 0 0 0 18 0 11 0 46671403 903761920 69630 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31475] ppid=31457 vsize=882580 CPUtime=0
/proc/31470/task/31475/stat : 31475 (java) S 31457 31456 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 11 0 46671406 903761920 69630 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31476] ppid=31457 vsize=882580 CPUtime=1.57
/proc/31470/task/31476/stat : 31476 (java) S 31457 31456 17511 34816 17511 4202560 10289 0 0 0 156 1 0 0 18 0 11 0 46671406 903761920 69630 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31477] ppid=31457 vsize=882580 CPUtime=0.99
/proc/31470/task/31477/stat : 31477 (java) S 31457 31456 17511 34816 17511 4202560 2350 0 0 0 98 1 0 0 15 0 11 0 46671406 903761920 69630 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31478] ppid=31457 vsize=882580 CPUtime=0
/proc/31470/task/31478/stat : 31478 (java) S 31457 31456 17511 34816 17511 4202560 0 0 0 0 0 0 0 0 25 0 11 0 46671406 903761920 69630 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31479] ppid=31457 vsize=882580 CPUtime=0
/proc/31470/task/31479/stat : 31479 (java) S 31457 31456 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 15 0 11 0 46671406 903761920 69630 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 5.41
Current children cumulated vsize (KiB) 887720

[startup+6.1061 s]
/proc/loadavg: 1.29 1.18 1.14 3/48 31480
/proc/meminfo: memFree=318268/1048576 swapFree=0/0
[pid=31456] ppid=31455 vsize=2568 CPUtime=0
/proc/31456/stat : 31456 (p2cudf-user-1.1) S 31455 31456 17511 34816 17511 4202496 375 0 0 0 0 0 0 0 18 0 1 0 46671397 2629632 270 1283457024 134512640 135304128 4288478096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31456/statm: 642 270 230 194 0 29 0
[pid=31457] ppid=31456 vsize=2572 CPUtime=0.02
/proc/31457/stat : 31457 (p2cudf) S 31456 31456 17511 34816 17511 4202496 392 3010 0 1 0 0 0 2 25 0 1 0 46671397 2633728 281 1283457024 134512640 135304128 4288357280 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31457/statm: 643 281 239 194 0 30 0
[pid=31470] ppid=31457 vsize=882580 CPUtime=5.53
/proc/31470/stat : 31470 (java) S 31457 31456 17511 34816 17511 4202496 75255 0 1 0 523 30 0 0 25 0 10 0 46671401 903761920 69638 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/31470/statm: 220645 69638 1783 10 0 217736 0
[pid=31470/tid=31471] ppid=31457 vsize=882580 CPUtime=2.53
/proc/31470/task/31471/stat : 31471 (java) S 31457 31456 17511 34816 17511 4202560 50286 0 1 0 236 17 0 0 19 0 10 0 46671401 903761920 69638 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31472] ppid=31457 vsize=882580 CPUtime=0.25
/proc/31470/task/31472/stat : 31472 (java) S 31457 31456 17511 34816 17511 4202560 11239 0 0 0 19 6 0 0 16 0 10 0 46671403 903761920 69638 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 0 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31473] ppid=31457 vsize=882580 CPUtime=0
/proc/31470/task/31473/stat : 31473 (java) S 31457 31456 17511 34816 17511 4202560 8 0 0 0 0 0 0 0 18 0 10 0 46671403 903761920 69638 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31474] ppid=31457 vsize=882580 CPUtime=0.01
/proc/31470/task/31474/stat : 31474 (java) S 31457 31456 17511 34816 17511 4202560 6 0 0 0 1 0 0 0 18 0 10 0 46671403 903761920 69638 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31475] ppid=31457 vsize=882580 CPUtime=0
/proc/31470/task/31475/stat : 31475 (java) S 31457 31456 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46671406 903761920 69638 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31476] ppid=31457 vsize=882580 CPUtime=1.61
/proc/31470/task/31476/stat : 31476 (java) S 31457 31456 17511 34816 17511 4202560 10295 0 0 0 160 1 0 0 15 0 10 0 46671406 903761920 69638 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31477] ppid=31457 vsize=882580 CPUtime=0.99
/proc/31470/task/31477/stat : 31477 (java) S 31457 31456 17511 34816 17511 4202560 2350 0 0 0 98 1 0 0 15 0 10 0 46671406 903761920 69638 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31478] ppid=31457 vsize=882580 CPUtime=0
/proc/31470/task/31478/stat : 31478 (java) S 31457 31456 17511 34816 17511 4202560 0 0 0 0 0 0 0 0 25 0 10 0 46671406 903761920 69638 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=31470/tid=31479] ppid=31457 vsize=882580 CPUtime=0
/proc/31470/task/31479/stat : 31479 (java) S 31457 31456 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 15 0 10 0 46671406 903761920 69638 1283457024 134512640 134550932 4291779968 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 5.55
Current children cumulated vsize (KiB) 887720

Child status: 0
Real time (s): 6.14304
CPU time (s): 5.58835
CPU user time (s): 5.24433
CPU system time (s): 0.344021
CPU usage (%): 90.9705
Max. virtual memory (cumulated for all children) (KiB): 891172

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 5.24433
system time used= 0.344021
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 79057
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= 829
involuntary context switches= 823

runsolver used 0 second user time and 0 second system time

The end