runsolver Copyright (C) 2010 Olivier ROUSSEL

This is runsolver version 3.2.9a (svn: 651)

This program is distributed in the hope that it will be useful,
but WITHOUT ANY WARRANTY; without even the implied warranty of
MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
GNU General Public License for more details.

command line: /home/misc2010/bin/runsolver -s SIGUSR1 -M 1124 -C 290 -d 10 -w /home/misc2010/tmp/201103031013/p2cudf-paranoid-1.12/1262.cudf.caixa.log.runsolver ./p2cudf-paranoid-1.12 /home/misc2010/data/misc4/caixa//1262.cudf /home/misc2010/tmp/201103031013/p2cudf-paranoid-1.12/1262.cudf.caixa.result 

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


[startup+0 s]
/proc/loadavg: 1.93 1.56 1.27 5/38 18376
/proc/meminfo: memFree=461400/1048576 swapFree=0/0
[pid=18373] ppid=18372 vsize=2572 CPUtime=0
/proc/18373/stat : 18373 (p2cudf-paranoid) S 18372 18373 29493 34817 29493 4202496 374 0 0 0 0 0 0 0 18 0 1 0 75806156 2633728 271 1283457024 134512640 135304128 4292310944 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18373/statm: 643 271 230 194 0 30 0
[pid=18374] ppid=18373 vsize=2568 CPUtime=0
/proc/18374/stat : 18374 (p2cudf) S 18373 18373 29493 34817 29493 4202496 351 0 0 0 0 0 0 0 18 0 1 0 75806156 2629632 270 1283457024 134512640 135304128 4290309584 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0
/proc/18374/statm: 642 270 231 194 0 29 0
[pid=18375] ppid=18374 vsize=2568 CPUtime=0
/proc/18375/stat : 18375 (p2cudf) R 18374 18373 29493 34817 29493 4202560 94 0 0 0 0 0 0 0 25 0 1 0 75806156 2629632 118 1283457024 134512640 135304128 4290309584 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/18375/statm: 642 118 77 194 0 29 0
[pid=18376] ppid=18375 vsize=2568 CPUtime=0
/proc/18376/stat : 18376 (p2cudf) R 18375 18373 29493 34817 29493 4202560 0 0 0 0 0 0 0 0 25 0 1 0 75806156 2629632 41 1283457024 134512640 135304128 4290309584 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/18376/statm: 642 41 0 194 0 29 0

[startup+0.165339 s]
/proc/loadavg: 1.93 1.56 1.27 5/38 18376
/proc/meminfo: memFree=461400/1048576 swapFree=0/0
[pid=18373] ppid=18372 vsize=2572 CPUtime=0
/proc/18373/stat : 18373 (p2cudf-paranoid) S 18372 18373 29493 34817 29493 4202496 374 0 0 0 0 0 0 0 18 0 1 0 75806156 2633728 271 1283457024 134512640 135304128 4292310944 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18373/statm: 643 271 230 194 0 30 0
[pid=18374] ppid=18373 vsize=2576 CPUtime=0.02
/proc/18374/stat : 18374 (p2cudf) S 18373 18373 29493 34817 29493 4202496 391 3011 0 1 0 0 2 0 25 0 1 0 75806156 2637824 280 1283457024 134512640 135304128 4290309584 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18374/statm: 644 280 239 194 0 31 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5148

[startup+0.205337 s]
/proc/loadavg: 1.93 1.56 1.27 5/38 18376
/proc/meminfo: memFree=461400/1048576 swapFree=0/0
[pid=18373] ppid=18372 vsize=2572 CPUtime=0
/proc/18373/stat : 18373 (p2cudf-paranoid) S 18372 18373 29493 34817 29493 4202496 374 0 0 0 0 0 0 0 18 0 1 0 75806156 2633728 271 1283457024 134512640 135304128 4292310944 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18373/statm: 643 271 230 194 0 30 0
[pid=18374] ppid=18373 vsize=2576 CPUtime=0.02
/proc/18374/stat : 18374 (p2cudf) S 18373 18373 29493 34817 29493 4202496 391 3011 0 1 0 0 2 0 25 0 1 0 75806156 2637824 280 1283457024 134512640 135304128 4290309584 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18374/statm: 644 280 239 194 0 31 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5148

[startup+0.305353 s]
/proc/loadavg: 1.93 1.56 1.27 5/38 18376
/proc/meminfo: memFree=461400/1048576 swapFree=0/0
[pid=18373] ppid=18372 vsize=2572 CPUtime=0
/proc/18373/stat : 18373 (p2cudf-paranoid) S 18372 18373 29493 34817 29493 4202496 374 0 0 0 0 0 0 0 18 0 1 0 75806156 2633728 271 1283457024 134512640 135304128 4292310944 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18373/statm: 643 271 230 194 0 30 0
[pid=18374] ppid=18373 vsize=2576 CPUtime=0.02
/proc/18374/stat : 18374 (p2cudf) S 18373 18373 29493 34817 29493 4202496 391 3011 0 1 0 0 2 0 25 0 1 0 75806156 2637824 280 1283457024 134512640 135304128 4290309584 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18374/statm: 644 280 239 194 0 31 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5148

[startup+0.705455 s]
/proc/loadavg: 1.93 1.56 1.27 5/38 18376
/proc/meminfo: memFree=461400/1048576 swapFree=0/0
[pid=18373] ppid=18372 vsize=2572 CPUtime=0
/proc/18373/stat : 18373 (p2cudf-paranoid) S 18372 18373 29493 34817 29493 4202496 374 0 0 0 0 0 0 0 18 0 1 0 75806156 2633728 271 1283457024 134512640 135304128 4292310944 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18373/statm: 643 271 230 194 0 30 0
[pid=18374] ppid=18373 vsize=2576 CPUtime=0.02
/proc/18374/stat : 18374 (p2cudf) S 18373 18373 29493 34817 29493 4202496 391 3011 0 1 0 0 2 0 25 0 1 0 75806156 2637824 280 1283457024 134512640 135304128 4290309584 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18374/statm: 644 280 239 194 0 31 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5148

[startup+1.50562 s]
/proc/loadavg: 2.09 1.60 1.29 5/47 18396
/proc/meminfo: memFree=419600/1048576 swapFree=0/0
[pid=18373] ppid=18372 vsize=2572 CPUtime=0
/proc/18373/stat : 18373 (p2cudf-paranoid) S 18372 18373 29493 34817 29493 4202496 374 0 0 0 0 0 0 0 18 0 1 0 75806156 2633728 271 1283457024 134512640 135304128 4292310944 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18373/statm: 643 271 230 194 0 30 0
[pid=18374] ppid=18373 vsize=2576 CPUtime=0.02
/proc/18374/stat : 18374 (p2cudf) S 18373 18373 29493 34817 29493 4202496 391 3011 0 1 0 0 2 0 25 0 1 0 75806156 2637824 280 1283457024 134512640 135304128 4290309584 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18374/statm: 644 280 239 194 0 31 0
[pid=18387] ppid=18374 vsize=882680 CPUtime=1.46
/proc/18387/stat : 18387 (java) S 18374 18373 29493 34817 29493 4202496 18291 0 1 0 137 9 0 0 25 0 10 0 75806160 903864320 13743 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/18387/statm: 220670 13743 1727 10 0 217761 0
[pid=18387/tid=18388] ppid=18374 vsize=882680 CPUtime=0.65
/proc/18387/task/18388/stat : 18388 (java) R 18374 18373 29493 34817 29493 4202560 5896 0 1 0 60 5 0 0 25 0 10 0 75806160 903864320 13743 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=18387/tid=18389] ppid=18374 vsize=882680 CPUtime=0
/proc/18387/task/18389/stat : 18389 (java) S 18374 18373 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 15 0 10 0 75806162 903864320 13743 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 0 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18390] ppid=18374 vsize=882680 CPUtime=0
/proc/18387/task/18390/stat : 18390 (java) S 18374 18373 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 25 0 10 0 75806162 903864320 13743 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18391] ppid=18374 vsize=882680 CPUtime=0
/proc/18387/task/18391/stat : 18391 (java) S 18374 18373 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 25 0 10 0 75806162 903864320 13743 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18392] ppid=18374 vsize=882680 CPUtime=0
/proc/18387/task/18392/stat : 18392 (java) S 18374 18373 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 75806165 903864320 13743 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18393] ppid=18374 vsize=882680 CPUtime=0.55
/proc/18387/task/18393/stat : 18393 (java) R 18374 18373 29493 34817 29493 4202560 8846 0 0 0 52 3 0 0 22 0 10 0 75806165 903864320 13743 1283457024 134512640 134550932 4293785536 18446744073709551615 4148397393 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=18387/tid=18394] ppid=18374 vsize=882680 CPUtime=0.25
/proc/18387/task/18394/stat : 18394 (java) R 18374 18373 29493 34817 29493 4202560 2470 0 0 0 24 1 0 0 24 0 10 0 75806165 903864320 13743 1283457024 134512640 134550932 4293785536 18446744073709551615 4148156216 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=18387/tid=18395] ppid=18374 vsize=882680 CPUtime=0
/proc/18387/task/18395/stat : 18395 (java) S 18374 18373 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 75806165 903864320 13743 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18396] ppid=18374 vsize=882680 CPUtime=0
/proc/18387/task/18396/stat : 18396 (java) S 18374 18373 29493 34817 29493 4202560 2 0 0 0 0 0 0 0 15 0 10 0 75806165 903864320 13743 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.48
Current children cumulated vsize (KiB) 887828

[startup+3.10594 s]
/proc/loadavg: 2.09 1.60 1.29 3/47 18396
/proc/meminfo: memFree=378184/1048576 swapFree=0/0
[pid=18373] ppid=18372 vsize=2572 CPUtime=0
/proc/18373/stat : 18373 (p2cudf-paranoid) S 18372 18373 29493 34817 29493 4202496 374 0 0 0 0 0 0 0 18 0 1 0 75806156 2633728 271 1283457024 134512640 135304128 4292310944 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18373/statm: 643 271 230 194 0 30 0
[pid=18374] ppid=18373 vsize=2576 CPUtime=0.02
/proc/18374/stat : 18374 (p2cudf) S 18373 18373 29493 34817 29493 4202496 391 3011 0 1 0 0 2 0 25 0 1 0 75806156 2637824 280 1283457024 134512640 135304128 4290309584 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18374/statm: 644 280 239 194 0 31 0
[pid=18387] ppid=18374 vsize=882220 CPUtime=3.07
/proc/18387/stat : 18387 (java) S 18374 18373 29493 34817 29493 4202496 58117 0 1 0 284 23 0 0 25 0 10 0 75806160 903393280 50011 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/18387/statm: 220555 50011 1743 10 0 217646 0
[pid=18387/tid=18388] ppid=18374 vsize=882220 CPUtime=1.49
/proc/18387/task/18388/stat : 18388 (java) R 18374 18373 29493 34817 29493 4202560 41986 0 1 0 133 16 0 0 25 0 10 0 75806160 903393280 50011 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=18387/tid=18389] ppid=18374 vsize=882220 CPUtime=0
/proc/18387/task/18389/stat : 18389 (java) S 18374 18373 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 15 0 10 0 75806162 903393280 50011 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 0 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18390] ppid=18374 vsize=882220 CPUtime=0
/proc/18387/task/18390/stat : 18390 (java) S 18374 18373 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 25 0 10 0 75806162 903393280 50011 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18391] ppid=18374 vsize=882220 CPUtime=0
/proc/18387/task/18391/stat : 18391 (java) S 18374 18373 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 25 0 10 0 75806162 903393280 50011 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18392] ppid=18374 vsize=882220 CPUtime=0
/proc/18387/task/18392/stat : 18392 (java) S 18374 18373 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 75806165 903393280 50011 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18393] ppid=18374 vsize=882220 CPUtime=0.82
/proc/18387/task/18393/stat : 18393 (java) S 18374 18373 29493 34817 29493 4202560 9153 0 0 0 79 3 0 0 15 0 10 0 75806165 903393280 50011 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18394] ppid=18374 vsize=882220 CPUtime=0.75
/proc/18387/task/18394/stat : 18394 (java) R 18374 18373 29493 34817 29493 4202560 5899 0 0 0 71 4 0 0 24 0 10 0 75806165 903393280 50011 1283457024 134512640 134550932 4293785536 18446744073709551615 4148444531 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=18387/tid=18395] ppid=18374 vsize=882220 CPUtime=0
/proc/18387/task/18395/stat : 18395 (java) S 18374 18373 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 75806165 903393280 50011 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18396] ppid=18374 vsize=882220 CPUtime=0
/proc/18387/task/18396/stat : 18396 (java) S 18374 18373 29493 34817 29493 4202560 2 0 0 0 0 0 0 0 15 0 10 0 75806165 903393280 50011 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.09
Current children cumulated vsize (KiB) 887368

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

[startup+3.21599 s]
/proc/loadavg: 2.09 1.60 1.29 3/47 18396
/proc/meminfo: memFree=378184/1048576 swapFree=0/0
[pid=18373] ppid=18372 vsize=2572 CPUtime=0
/proc/18373/stat : 18373 (p2cudf-paranoid) S 18372 18373 29493 34817 29493 4202496 374 0 0 0 0 0 0 0 18 0 1 0 75806156 2633728 271 1283457024 134512640 135304128 4292310944 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18373/statm: 643 271 230 194 0 30 0
[pid=18374] ppid=18373 vsize=2576 CPUtime=0.02
/proc/18374/stat : 18374 (p2cudf) S 18373 18373 29493 34817 29493 4202496 391 3011 0 1 0 0 2 0 25 0 1 0 75806156 2637824 280 1283457024 134512640 135304128 4290309584 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18374/statm: 644 280 239 194 0 31 0
[pid=18387] ppid=18374 vsize=882220 CPUtime=3.17
/proc/18387/stat : 18387 (java) S 18374 18373 29493 34817 29493 4202496 59196 0 1 0 294 23 0 0 25 0 10 0 75806160 903393280 51090 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/18387/statm: 220555 51090 1744 10 0 217646 0
[pid=18387/tid=18388] ppid=18374 vsize=882220 CPUtime=1.54
/proc/18387/task/18388/stat : 18388 (java) R 18374 18373 29493 34817 29493 4202560 43062 0 1 0 138 16 0 0 25 0 10 0 75806160 903393280 51090 1283457024 134512640 134550932 4293785536 18446744073709551615 4147235051 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=18387/tid=18389] ppid=18374 vsize=882220 CPUtime=0
/proc/18387/task/18389/stat : 18389 (java) S 18374 18373 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 15 0 10 0 75806162 903393280 51090 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 0 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18390] ppid=18374 vsize=882220 CPUtime=0
/proc/18387/task/18390/stat : 18390 (java) S 18374 18373 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 25 0 10 0 75806162 903393280 51090 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18391] ppid=18374 vsize=882220 CPUtime=0
/proc/18387/task/18391/stat : 18391 (java) S 18374 18373 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 25 0 10 0 75806162 903393280 51090 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18392] ppid=18374 vsize=882220 CPUtime=0
/proc/18387/task/18392/stat : 18392 (java) S 18374 18373 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 75806165 903393280 51090 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18393] ppid=18374 vsize=882220 CPUtime=0.84
/proc/18387/task/18393/stat : 18393 (java) R 18374 18373 29493 34817 29493 4202560 9155 0 0 0 81 3 0 0 15 0 10 0 75806165 903393280 51090 1283457024 134512640 134550932 4293785536 18446744073709551615 4149114224 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=18387/tid=18394] ppid=18374 vsize=882220 CPUtime=0.78
/proc/18387/task/18394/stat : 18394 (java) R 18374 18373 29493 34817 29493 4202560 5900 0 0 0 74 4 0 0 24 0 10 0 75806165 903393280 51090 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=18387/tid=18395] ppid=18374 vsize=882220 CPUtime=0
/proc/18387/task/18395/stat : 18395 (java) S 18374 18373 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 75806165 903393280 51090 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18396] ppid=18374 vsize=882220 CPUtime=0
/proc/18387/task/18396/stat : 18396 (java) S 18374 18373 29493 34817 29493 4202560 2 0 0 0 0 0 0 0 15 0 10 0 75806165 903393280 51090 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.19
Current children cumulated vsize (KiB) 887368

[startup+4.00618 s]
/proc/loadavg: 2.09 1.60 1.29 3/47 18396
/proc/meminfo: memFree=263360/1048576 swapFree=0/0
[pid=18373] ppid=18372 vsize=2572 CPUtime=0
/proc/18373/stat : 18373 (p2cudf-paranoid) S 18372 18373 29493 34817 29493 4202496 374 0 0 0 0 0 0 0 18 0 1 0 75806156 2633728 271 1283457024 134512640 135304128 4292310944 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18373/statm: 643 271 230 194 0 30 0
[pid=18374] ppid=18373 vsize=2576 CPUtime=0.02
/proc/18374/stat : 18374 (p2cudf) S 18373 18373 29493 34817 29493 4202496 391 3011 0 1 0 0 2 0 25 0 1 0 75806156 2637824 280 1283457024 134512640 135304128 4290309584 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18374/statm: 644 280 239 194 0 31 0
[pid=18387] ppid=18374 vsize=883952 CPUtime=3.97
/proc/18387/stat : 18387 (java) S 18374 18373 29493 34817 29493 4202496 82738 0 1 0 368 29 0 0 25 0 10 0 75806160 905166848 73783 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/18387/statm: 220988 73783 1749 10 0 218079 0
[pid=18387/tid=18388] ppid=18374 vsize=883952 CPUtime=1.66
/proc/18387/task/18388/stat : 18388 (java) R 18374 18373 29493 34817 29493 4202560 50170 0 1 0 150 16 0 0 25 0 10 0 75806160 905166848 73783 1283457024 134512640 134550932 4293785536 18446744073709551615 4152445749 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=18387/tid=18389] ppid=18374 vsize=883952 CPUtime=0.33
/proc/18387/task/18389/stat : 18389 (java) S 18374 18373 29493 34817 29493 4202560 15272 0 0 0 29 4 0 0 16 0 10 0 75806162 905166848 73783 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 0 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18390] ppid=18374 vsize=883952 CPUtime=0
/proc/18387/task/18390/stat : 18390 (java) S 18374 18373 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 18 0 10 0 75806162 905166848 73783 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18391] ppid=18374 vsize=883952 CPUtime=0
/proc/18387/task/18391/stat : 18391 (java) S 18374 18373 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 10 0 75806162 905166848 73783 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18392] ppid=18374 vsize=883952 CPUtime=0
/proc/18387/task/18392/stat : 18392 (java) S 18374 18373 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 75806165 905166848 73783 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18393] ppid=18374 vsize=883952 CPUtime=0.92
/proc/18387/task/18393/stat : 18393 (java) S 18374 18373 29493 34817 29493 4202560 9163 0 0 0 89 3 0 0 15 0 10 0 75806165 905166848 73783 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18394] ppid=18374 vsize=883952 CPUtime=1.02
/proc/18387/task/18394/stat : 18394 (java) R 18374 18373 29493 34817 29493 4202560 7058 0 0 0 98 4 0 0 25 0 10 0 75806165 905166848 73783 1283457024 134512640 134550932 4293785536 18446744073709551615 4146848033 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=18387/tid=18395] ppid=18374 vsize=883952 CPUtime=0
/proc/18387/task/18395/stat : 18395 (java) S 18374 18373 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 75806165 905166848 73783 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18396] ppid=18374 vsize=883952 CPUtime=0
/proc/18387/task/18396/stat : 18396 (java) S 18374 18373 29493 34817 29493 4202560 2 0 0 0 0 0 0 0 15 0 10 0 75806165 905166848 73783 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.99
Current children cumulated vsize (KiB) 889100

[startup+4.80158 s]
/proc/loadavg: 2.09 1.60 1.29 3/47 18396
/proc/meminfo: memFree=171972/1048576 swapFree=0/0
[pid=18373] ppid=18372 vsize=2572 CPUtime=0
/proc/18373/stat : 18373 (p2cudf-paranoid) S 18372 18373 29493 34817 29493 4202496 374 0 0 0 0 0 0 0 18 0 1 0 75806156 2633728 271 1283457024 134512640 135304128 4292310944 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18373/statm: 643 271 230 194 0 30 0
[pid=18374] ppid=18373 vsize=2576 CPUtime=0.02
/proc/18374/stat : 18374 (p2cudf) S 18373 18373 29493 34817 29493 4202496 391 3011 0 1 0 0 2 0 25 0 1 0 75806156 2637824 280 1283457024 134512640 135304128 4290309584 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18374/statm: 644 280 239 194 0 31 0
[pid=18387] ppid=18374 vsize=882544 CPUtime=4.73
/proc/18387/stat : 18387 (java) S 18374 18373 29493 34817 29493 4202496 83966 0 1 0 444 29 0 0 25 0 11 0 75806160 903725056 73573 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/18387/statm: 220636 73573 1764 10 0 217727 0
[pid=18387/tid=18388] ppid=18374 vsize=882544 CPUtime=2.01
/proc/18387/task/18388/stat : 18388 (java) S 18374 18373 29493 34817 29493 4202560 50198 0 1 0 185 16 0 0 24 0 11 0 75806160 903725056 73573 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18389] ppid=18374 vsize=882544 CPUtime=0.33
/proc/18387/task/18389/stat : 18389 (java) S 18374 18373 29493 34817 29493 4202560 15272 0 0 0 29 4 0 0 16 0 11 0 75806162 903725056 73573 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 0 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18390] ppid=18374 vsize=882544 CPUtime=0
/proc/18387/task/18390/stat : 18390 (java) S 18374 18373 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 18 0 11 0 75806162 903725056 73573 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18391] ppid=18374 vsize=882544 CPUtime=0
/proc/18387/task/18391/stat : 18391 (java) S 18374 18373 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 11 0 75806162 903725056 73573 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18392] ppid=18374 vsize=882544 CPUtime=0
/proc/18387/task/18392/stat : 18392 (java) S 18374 18373 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 11 0 75806165 903725056 73573 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18393] ppid=18374 vsize=882544 CPUtime=1.17
/proc/18387/task/18393/stat : 18393 (java) S 18374 18373 29493 34817 29493 4202560 9198 0 0 0 114 3 0 0 15 0 11 0 75806165 903725056 73573 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18394] ppid=18374 vsize=882544 CPUtime=1.18
/proc/18387/task/18394/stat : 18394 (java) S 18374 18373 29493 34817 29493 4202560 8219 0 0 0 114 4 0 0 25 0 11 0 75806165 903725056 73573 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18395] ppid=18374 vsize=882544 CPUtime=0
/proc/18387/task/18395/stat : 18395 (java) S 18374 18373 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 11 0 75806165 903725056 73573 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18396] ppid=18374 vsize=882544 CPUtime=0
/proc/18387/task/18396/stat : 18396 (java) S 18374 18373 29493 34817 29493 4202560 2 0 0 0 0 0 0 0 15 0 11 0 75806165 903725056 73573 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.75
Current children cumulated vsize (KiB) 887692

[startup+5.2056 s]
/proc/loadavg: 2.09 1.60 1.29 3/47 18396
/proc/meminfo: memFree=171972/1048576 swapFree=0/0
[pid=18373] ppid=18372 vsize=2572 CPUtime=0
/proc/18373/stat : 18373 (p2cudf-paranoid) S 18372 18373 29493 34817 29493 4202496 374 0 0 0 0 0 0 0 18 0 1 0 75806156 2633728 271 1283457024 134512640 135304128 4292310944 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18373/statm: 643 271 230 194 0 30 0
[pid=18374] ppid=18373 vsize=2576 CPUtime=0.02
/proc/18374/stat : 18374 (p2cudf) S 18373 18373 29493 34817 29493 4202496 391 3011 0 1 0 0 2 0 25 0 1 0 75806156 2637824 280 1283457024 134512640 135304128 4290309584 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18374/statm: 644 280 239 194 0 31 0
[pid=18387] ppid=18374 vsize=882544 CPUtime=4.73
/proc/18387/stat : 18387 (java) S 18374 18373 29493 34817 29493 4202496 83966 0 1 0 444 29 0 0 25 0 11 0 75806160 903725056 73573 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/18387/statm: 220636 73573 1764 10 0 217727 0
[pid=18387/tid=18388] ppid=18374 vsize=882544 CPUtime=2.01
/proc/18387/task/18388/stat : 18388 (java) S 18374 18373 29493 34817 29493 4202560 50198 0 1 0 185 16 0 0 24 0 11 0 75806160 903725056 73573 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18389] ppid=18374 vsize=882544 CPUtime=0.33
/proc/18387/task/18389/stat : 18389 (java) S 18374 18373 29493 34817 29493 4202560 15272 0 0 0 29 4 0 0 15 0 11 0 75806162 903725056 73573 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 0 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18390] ppid=18374 vsize=882544 CPUtime=0
/proc/18387/task/18390/stat : 18390 (java) S 18374 18373 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 18 0 11 0 75806162 903725056 73573 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18391] ppid=18374 vsize=882544 CPUtime=0
/proc/18387/task/18391/stat : 18391 (java) S 18374 18373 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 11 0 75806162 903725056 73573 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18392] ppid=18374 vsize=882544 CPUtime=0
/proc/18387/task/18392/stat : 18392 (java) S 18374 18373 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 11 0 75806165 903725056 73573 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18393] ppid=18374 vsize=882544 CPUtime=1.17
/proc/18387/task/18393/stat : 18393 (java) S 18374 18373 29493 34817 29493 4202560 9198 0 0 0 114 3 0 0 15 0 11 0 75806165 903725056 73573 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18394] ppid=18374 vsize=882544 CPUtime=1.18
/proc/18387/task/18394/stat : 18394 (java) S 18374 18373 29493 34817 29493 4202560 8219 0 0 0 114 4 0 0 25 0 11 0 75806165 903725056 73573 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18395] ppid=18374 vsize=882544 CPUtime=0
/proc/18387/task/18395/stat : 18395 (java) S 18374 18373 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 11 0 75806165 903725056 73573 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18396] ppid=18374 vsize=882544 CPUtime=0
/proc/18387/task/18396/stat : 18396 (java) S 18374 18373 29493 34817 29493 4202560 2 0 0 0 0 0 0 0 15 0 11 0 75806165 903725056 73573 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.75
Current children cumulated vsize (KiB) 887692

[startup+5.30559 s]
/proc/loadavg: 2.09 1.60 1.29 3/47 18396
/proc/meminfo: memFree=171972/1048576 swapFree=0/0
[pid=18373] ppid=18372 vsize=2572 CPUtime=0
/proc/18373/stat : 18373 (p2cudf-paranoid) S 18372 18373 29493 34817 29493 4202496 374 0 0 0 0 0 0 0 18 0 1 0 75806156 2633728 271 1283457024 134512640 135304128 4292310944 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18373/statm: 643 271 230 194 0 30 0
[pid=18374] ppid=18373 vsize=2576 CPUtime=0.02
/proc/18374/stat : 18374 (p2cudf) S 18373 18373 29493 34817 29493 4202496 391 3011 0 1 0 0 2 0 25 0 1 0 75806156 2637824 280 1283457024 134512640 135304128 4290309584 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18374/statm: 644 280 239 194 0 31 0
[pid=18387] ppid=18374 vsize=882544 CPUtime=4.73
/proc/18387/stat : 18387 (java) S 18374 18373 29493 34817 29493 4202496 83968 0 1 0 444 29 0 0 25 0 10 0 75806160 903725056 73575 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/18387/statm: 220636 73575 1766 10 0 217727 0
[pid=18387/tid=18388] ppid=18374 vsize=882544 CPUtime=2.01
/proc/18387/task/18388/stat : 18388 (java) S 18374 18373 29493 34817 29493 4202560 50198 0 1 0 185 16 0 0 19 0 10 0 75806160 903725056 73575 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18389] ppid=18374 vsize=882544 CPUtime=0.33
/proc/18387/task/18389/stat : 18389 (java) S 18374 18373 29493 34817 29493 4202560 15273 0 0 0 29 4 0 0 16 0 10 0 75806162 903725056 73575 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 0 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18390] ppid=18374 vsize=882544 CPUtime=0
/proc/18387/task/18390/stat : 18390 (java) S 18374 18373 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 18 0 10 0 75806162 903725056 73575 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18391] ppid=18374 vsize=882544 CPUtime=0
/proc/18387/task/18391/stat : 18391 (java) S 18374 18373 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 10 0 75806162 903725056 73575 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18392] ppid=18374 vsize=882544 CPUtime=0
/proc/18387/task/18392/stat : 18392 (java) S 18374 18373 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 75806165 903725056 73575 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18393] ppid=18374 vsize=882544 CPUtime=1.17
/proc/18387/task/18393/stat : 18393 (java) S 18374 18373 29493 34817 29493 4202560 9198 0 0 0 114 3 0 0 15 0 10 0 75806165 903725056 73575 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18394] ppid=18374 vsize=882544 CPUtime=1.18
/proc/18387/task/18394/stat : 18394 (java) S 18374 18373 29493 34817 29493 4202560 8219 0 0 0 114 4 0 0 25 0 10 0 75806165 903725056 73575 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18395] ppid=18374 vsize=882544 CPUtime=0
/proc/18387/task/18395/stat : 18395 (java) S 18374 18373 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 75806165 903725056 73575 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
[pid=18387/tid=18396] ppid=18374 vsize=882544 CPUtime=0
/proc/18387/task/18396/stat : 18396 (java) S 18374 18373 29493 34817 29493 4202560 2 0 0 0 0 0 0 0 15 0 10 0 75806165 903725056 73575 1283457024 134512640 134550932 4293785536 18446744073709551615 4294960130 0 4 0 16800975 18446612133396263168 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.75
Current children cumulated vsize (KiB) 887692

Child status: 0
Real time (s): 5.36296
CPU time (s): 4.7883
CPU user time (s): 4.46828
CPU system time (s): 0.32002
CPU usage (%): 89.2846
Max. virtual memory (cumulated for all children) (KiB): 892320

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 4.46828
system time used= 0.32002
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 87769
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= 354
involuntary context switches= 347

runsolver used 0 second user time and 0.012 second system time

The end