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/167.cudf.caixa.log.runsolver ./p2cudf-paranoid-1.12 /home/misc2010/data/misc4/caixa//167.cudf /home/misc2010/tmp/201103031013/p2cudf-paranoid-1.12/167.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.73 1.72 1.48 5/36 26516
/proc/meminfo: memFree=299300/1048576 swapFree=0/0
[pid=26513] ppid=26512 vsize=2568 CPUtime=0
/proc/26513/stat : 26513 (p2cudf-paranoid) S 26512 26513 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 18 0 1 0 75861215 2629632 269 1283457024 134512640 135304128 4291477216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/26513/statm: 642 269 230 194 0 29 0
[pid=26514] ppid=26513 vsize=2568 CPUtime=0
/proc/26514/stat : 26514 (p2cudf) S 26513 26513 29493 34817 29493 4202496 353 0 0 0 0 0 0 0 18 0 1 0 75861215 2629632 272 1283457024 134512640 135304128 4288963712 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0
/proc/26514/statm: 642 272 231 194 0 29 0
[pid=26515] ppid=26514 vsize=2568 CPUtime=0
/proc/26515/stat : 26515 (p2cudf) R 26514 26513 29493 34817 29493 4202560 93 0 0 0 0 0 0 0 25 0 1 0 75861215 2629632 119 1283457024 134512640 135304128 4288963712 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/26515/statm: 642 119 77 194 0 29 0
[pid=26516] ppid=26515 vsize=2568 CPUtime=0
/proc/26516/stat : 26516 (p2cudf) R 26515 26513 29493 34817 29493 4202560 0 0 0 0 0 0 0 0 25 0 1 0 75861215 2629632 42 1283457024 134512640 135304128 4288963712 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/26516/statm: 642 42 0 194 0 29 0

[startup+0.155816 s]
/proc/loadavg: 1.73 1.72 1.48 5/36 26516
/proc/meminfo: memFree=299300/1048576 swapFree=0/0
[pid=26513] ppid=26512 vsize=2568 CPUtime=0
/proc/26513/stat : 26513 (p2cudf-paranoid) S 26512 26513 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 18 0 1 0 75861215 2629632 269 1283457024 134512640 135304128 4291477216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/26513/statm: 642 269 230 194 0 29 0
[pid=26514] ppid=26513 vsize=2576 CPUtime=0.03
/proc/26514/stat : 26514 (p2cudf) S 26513 26513 29493 34817 29493 4202496 395 3012 0 1 0 0 2 1 25 0 1 0 75861215 2637824 282 1283457024 134512640 135304128 4288963712 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/26514/statm: 644 282 239 194 0 31 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5144

[startup+0.205813 s]
/proc/loadavg: 1.73 1.72 1.48 5/36 26516
/proc/meminfo: memFree=299300/1048576 swapFree=0/0
[pid=26513] ppid=26512 vsize=2568 CPUtime=0
/proc/26513/stat : 26513 (p2cudf-paranoid) S 26512 26513 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 18 0 1 0 75861215 2629632 269 1283457024 134512640 135304128 4291477216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/26513/statm: 642 269 230 194 0 29 0
[pid=26514] ppid=26513 vsize=2576 CPUtime=0.03
/proc/26514/stat : 26514 (p2cudf) S 26513 26513 29493 34817 29493 4202496 395 3012 0 1 0 0 2 1 25 0 1 0 75861215 2637824 282 1283457024 134512640 135304128 4288963712 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/26514/statm: 644 282 239 194 0 31 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5144

[startup+0.305829 s]
/proc/loadavg: 1.73 1.72 1.48 5/36 26516
/proc/meminfo: memFree=299300/1048576 swapFree=0/0
[pid=26513] ppid=26512 vsize=2568 CPUtime=0
/proc/26513/stat : 26513 (p2cudf-paranoid) S 26512 26513 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 18 0 1 0 75861215 2629632 269 1283457024 134512640 135304128 4291477216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/26513/statm: 642 269 230 194 0 29 0
[pid=26514] ppid=26513 vsize=2576 CPUtime=0.03
/proc/26514/stat : 26514 (p2cudf) S 26513 26513 29493 34817 29493 4202496 395 3012 0 1 0 0 2 1 25 0 1 0 75861215 2637824 282 1283457024 134512640 135304128 4288963712 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/26514/statm: 644 282 239 194 0 31 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5144

[startup+0.70594 s]
/proc/loadavg: 1.73 1.72 1.48 5/36 26516
/proc/meminfo: memFree=299300/1048576 swapFree=0/0
[pid=26513] ppid=26512 vsize=2568 CPUtime=0
/proc/26513/stat : 26513 (p2cudf-paranoid) S 26512 26513 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 18 0 1 0 75861215 2629632 269 1283457024 134512640 135304128 4291477216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/26513/statm: 642 269 230 194 0 29 0
[pid=26514] ppid=26513 vsize=2576 CPUtime=0.03
/proc/26514/stat : 26514 (p2cudf) S 26513 26513 29493 34817 29493 4202496 395 3012 0 1 0 0 2 1 25 0 1 0 75861215 2637824 282 1283457024 134512640 135304128 4288963712 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/26514/statm: 644 282 239 194 0 31 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5144

[startup+1.5061 s]
/proc/loadavg: 1.83 1.75 1.48 4/45 26536
/proc/meminfo: memFree=247828/1048576 swapFree=0/0
[pid=26513] ppid=26512 vsize=2568 CPUtime=0
/proc/26513/stat : 26513 (p2cudf-paranoid) S 26512 26513 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 18 0 1 0 75861215 2629632 269 1283457024 134512640 135304128 4291477216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/26513/statm: 642 269 230 194 0 29 0
[pid=26514] ppid=26513 vsize=2576 CPUtime=0.03
/proc/26514/stat : 26514 (p2cudf) S 26513 26513 29493 34817 29493 4202496 395 3012 0 1 0 0 2 1 25 0 1 0 75861215 2637824 282 1283457024 134512640 135304128 4288963712 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/26514/statm: 644 282 239 194 0 31 0
[pid=26527] ppid=26514 vsize=881772 CPUtime=1.46
/proc/26527/stat : 26527 (java) S 26514 26513 29493 34817 29493 4202496 24225 0 1 0 133 13 0 0 25 0 10 0 75861218 902934528 20816 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/26527/statm: 220443 20816 1724 10 0 217534 0
[pid=26527/tid=26528] ppid=26514 vsize=881772 CPUtime=0.79
/proc/26527/task/26528/stat : 26528 (java) R 26514 26513 29493 34817 29493 4202560 13486 0 1 0 71 8 0 0 25 0 10 0 75861219 902934528 20816 1283457024 134512640 134550932 4293762992 18446744073709551615 4095054180 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=26527/tid=26529] ppid=26514 vsize=881772 CPUtime=0
/proc/26527/task/26529/stat : 26529 (java) S 26514 26513 29493 34817 29493 4202560 7 0 0 0 0 0 0 0 17 0 10 0 75861221 902934528 20816 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 0 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26530] ppid=26514 vsize=881772 CPUtime=0
/proc/26527/task/26530/stat : 26530 (java) S 26514 26513 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 25 0 10 0 75861221 902934528 20816 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26531] ppid=26514 vsize=881772 CPUtime=0
/proc/26527/task/26531/stat : 26531 (java) S 26514 26513 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 25 0 10 0 75861221 902934528 20816 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26532] ppid=26514 vsize=881772 CPUtime=0
/proc/26527/task/26532/stat : 26532 (java) S 26514 26513 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 75861223 902934528 20816 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26533] ppid=26514 vsize=881772 CPUtime=0.43
/proc/26527/task/26533/stat : 26533 (java) R 26514 26513 29493 34817 29493 4202560 7343 0 0 0 39 4 0 0 25 0 10 0 75861224 902934528 20816 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=26527/tid=26534] ppid=26514 vsize=881772 CPUtime=0.22
/proc/26527/task/26534/stat : 26534 (java) R 26514 26513 29493 34817 29493 4202560 2315 0 0 0 22 0 0 0 19 0 10 0 75861224 902934528 20816 1283457024 134512640 134550932 4293762992 18446744073709551615 4152448663 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=26527/tid=26535] ppid=26514 vsize=881772 CPUtime=0
/proc/26527/task/26535/stat : 26535 (java) S 26514 26513 29493 34817 29493 4202560 0 0 0 0 0 0 0 0 25 0 10 0 75861224 902934528 20816 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26536] ppid=26514 vsize=881772 CPUtime=0
/proc/26527/task/26536/stat : 26536 (java) S 26514 26513 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 10 0 75861224 902934528 20816 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.49
Current children cumulated vsize (KiB) 886916

[startup+3.11084 s]
/proc/loadavg: 1.83 1.75 1.48 4/45 26536
/proc/meminfo: memFree=158300/1048576 swapFree=0/0
[pid=26513] ppid=26512 vsize=2568 CPUtime=0
/proc/26513/stat : 26513 (p2cudf-paranoid) S 26512 26513 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 18 0 1 0 75861215 2629632 269 1283457024 134512640 135304128 4291477216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/26513/statm: 642 269 230 194 0 29 0
[pid=26514] ppid=26513 vsize=2576 CPUtime=0.03
/proc/26514/stat : 26514 (p2cudf) S 26513 26513 29493 34817 29493 4202496 395 3012 0 1 0 0 2 1 25 0 1 0 75861215 2637824 282 1283457024 134512640 135304128 4288963712 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/26514/statm: 644 282 239 194 0 31 0
[pid=26527] ppid=26514 vsize=886996 CPUtime=3.06
/proc/26527/stat : 26527 (java) S 26514 26513 29493 34817 29493 4202496 62974 0 1 0 286 20 0 0 25 0 10 0 75861218 908283904 57217 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/26527/statm: 221749 57217 1741 10 0 218840 0
[pid=26527/tid=26528] ppid=26514 vsize=886996 CPUtime=1.53
/proc/26527/task/26528/stat : 26528 (java) R 26514 26513 29493 34817 29493 4202560 48244 0 1 0 138 15 0 0 25 0 10 0 75861219 908283904 57217 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=26527/tid=26529] ppid=26514 vsize=886996 CPUtime=0
/proc/26527/task/26529/stat : 26529 (java) S 26514 26513 29493 34817 29493 4202560 7 0 0 0 0 0 0 0 15 0 10 0 75861221 908283904 57217 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 0 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26530] ppid=26514 vsize=886996 CPUtime=0
/proc/26527/task/26530/stat : 26530 (java) S 26514 26513 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 25 0 10 0 75861221 908283904 57217 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26531] ppid=26514 vsize=886996 CPUtime=0
/proc/26527/task/26531/stat : 26531 (java) S 26514 26513 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 25 0 10 0 75861221 908283904 57217 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26532] ppid=26514 vsize=886996 CPUtime=0
/proc/26527/task/26532/stat : 26532 (java) S 26514 26513 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 75861223 908283904 57217 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26533] ppid=26514 vsize=886996 CPUtime=0.8
/proc/26527/task/26533/stat : 26533 (java) R 26514 26513 29493 34817 29493 4202560 9951 0 0 0 76 4 0 0 23 0 10 0 75861224 908283904 57217 1283457024 134512640 134550932 4293762992 18446744073709551615 4151573469 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=26527/tid=26534] ppid=26514 vsize=886996 CPUtime=0.71
/proc/26527/task/26534/stat : 26534 (java) S 26514 26513 29493 34817 29493 4202560 3698 0 0 0 71 0 0 0 15 0 10 0 75861224 908283904 57217 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26535] ppid=26514 vsize=886996 CPUtime=0
/proc/26527/task/26535/stat : 26535 (java) S 26514 26513 29493 34817 29493 4202560 0 0 0 0 0 0 0 0 25 0 10 0 75861224 908283904 57217 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26536] ppid=26514 vsize=886996 CPUtime=0
/proc/26527/task/26536/stat : 26536 (java) S 26514 26513 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 10 0 75861224 908283904 57217 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.09
Current children cumulated vsize (KiB) 892140

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

[startup+3.22642 s]
/proc/loadavg: 1.83 1.75 1.48 4/45 26536
/proc/meminfo: memFree=158300/1048576 swapFree=0/0
[pid=26513] ppid=26512 vsize=2568 CPUtime=0
/proc/26513/stat : 26513 (p2cudf-paranoid) S 26512 26513 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 18 0 1 0 75861215 2629632 269 1283457024 134512640 135304128 4291477216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/26513/statm: 642 269 230 194 0 29 0
[pid=26514] ppid=26513 vsize=2576 CPUtime=0.03
/proc/26514/stat : 26514 (p2cudf) S 26513 26513 29493 34817 29493 4202496 395 3012 0 1 0 0 2 1 25 0 1 0 75861215 2637824 282 1283457024 134512640 135304128 4288963712 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/26514/statm: 644 282 239 194 0 31 0
[pid=26527] ppid=26514 vsize=886996 CPUtime=3.18
/proc/26527/stat : 26527 (java) S 26514 26513 29493 34817 29493 4202496 67081 0 1 0 297 21 0 0 25 0 10 0 75861218 908283904 61324 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/26527/statm: 221749 61324 1742 10 0 218840 0
[pid=26527/tid=26528] ppid=26514 vsize=886996 CPUtime=1.55
/proc/26527/task/26528/stat : 26528 (java) R 26514 26513 29493 34817 29493 4202560 50047 0 1 0 140 15 0 0 25 0 10 0 75861219 908283904 61324 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=26527/tid=26529] ppid=26514 vsize=886996 CPUtime=0.04
/proc/26527/task/26529/stat : 26529 (java) R 26514 26513 29493 34817 29493 4202560 2305 0 0 0 4 0 0 0 15 0 10 0 75861221 908283904 61324 1283457024 134512640 134550932 4293762992 18446744073709551615 4149207416 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=26527/tid=26530] ppid=26514 vsize=886996 CPUtime=0
/proc/26527/task/26530/stat : 26530 (java) S 26514 26513 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 25 0 10 0 75861221 908283904 61324 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26531] ppid=26514 vsize=886996 CPUtime=0
/proc/26527/task/26531/stat : 26531 (java) S 26514 26513 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 25 0 10 0 75861221 908283904 61324 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26532] ppid=26514 vsize=886996 CPUtime=0
/proc/26527/task/26532/stat : 26532 (java) S 26514 26513 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 75861223 908283904 61324 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26533] ppid=26514 vsize=886996 CPUtime=0.84
/proc/26527/task/26533/stat : 26533 (java) S 26514 26513 29493 34817 29493 4202560 9957 0 0 0 80 4 0 0 23 0 10 0 75861224 908283904 61324 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26534] ppid=26514 vsize=886996 CPUtime=0.72
/proc/26527/task/26534/stat : 26534 (java) S 26514 26513 29493 34817 29493 4202560 3698 0 0 0 72 0 0 0 16 0 10 0 75861224 908283904 61324 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26535] ppid=26514 vsize=886996 CPUtime=0
/proc/26527/task/26535/stat : 26535 (java) S 26514 26513 29493 34817 29493 4202560 0 0 0 0 0 0 0 0 25 0 10 0 75861224 908283904 61324 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26536] ppid=26514 vsize=886996 CPUtime=0
/proc/26527/task/26536/stat : 26536 (java) S 26514 26513 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 10 0 75861224 908283904 61324 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.21
Current children cumulated vsize (KiB) 892140

[startup+4.00653 s]
/proc/loadavg: 1.83 1.75 1.48 3/45 26536
/proc/meminfo: memFree=34796/1048576 swapFree=0/0
[pid=26513] ppid=26512 vsize=2568 CPUtime=0
/proc/26513/stat : 26513 (p2cudf-paranoid) S 26512 26513 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 18 0 1 0 75861215 2629632 269 1283457024 134512640 135304128 4291477216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/26513/statm: 642 269 230 194 0 29 0
[pid=26514] ppid=26513 vsize=2576 CPUtime=0.03
/proc/26514/stat : 26514 (p2cudf) S 26513 26513 29493 34817 29493 4202496 395 3012 0 1 0 0 2 1 25 0 1 0 75861215 2637824 282 1283457024 134512640 135304128 4288963712 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/26514/statm: 644 282 239 194 0 31 0
[pid=26527] ppid=26514 vsize=888480 CPUtime=3.96
/proc/26527/stat : 26527 (java) S 26514 26513 29493 34817 29493 4202496 81799 0 1 0 369 27 0 0 25 0 10 0 75861218 909803520 76042 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/26527/statm: 222120 76042 1746 10 0 219211 0
[pid=26527/tid=26528] ppid=26514 vsize=888480 CPUtime=1.72
/proc/26527/task/26528/stat : 26528 (java) R 26514 26513 29493 34817 29493 4202560 50172 0 1 0 157 15 0 0 25 0 10 0 75861219 909803520 76042 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=26527/tid=26529] ppid=26514 vsize=888480 CPUtime=0.36
/proc/26527/task/26529/stat : 26529 (java) S 26514 26513 29493 34817 29493 4202560 16499 0 0 0 29 7 0 0 16 0 10 0 75861221 909803520 76042 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 0 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26530] ppid=26514 vsize=888480 CPUtime=0
/proc/26527/task/26530/stat : 26530 (java) S 26514 26513 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 18 0 10 0 75861221 909803520 76042 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26531] ppid=26514 vsize=888480 CPUtime=0
/proc/26527/task/26531/stat : 26531 (java) S 26514 26513 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 10 0 75861221 909803520 76042 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26532] ppid=26514 vsize=888480 CPUtime=0
/proc/26527/task/26532/stat : 26532 (java) S 26514 26513 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 75861223 909803520 76042 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26533] ppid=26514 vsize=888480 CPUtime=1.06
/proc/26527/task/26533/stat : 26533 (java) R 26514 26513 29493 34817 29493 4202560 10341 0 0 0 102 4 0 0 19 0 10 0 75861224 909803520 76042 1283457024 134512640 134550932 4293762992 18446744073709551615 4149932784 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=26527/tid=26534] ppid=26514 vsize=888480 CPUtime=0.8
/proc/26527/task/26534/stat : 26534 (java) R 26514 26513 29493 34817 29493 4202560 3711 0 0 0 80 0 0 0 16 0 10 0 75861224 909803520 76042 1283457024 134512640 134550932 4293762992 18446744073709551615 4152459617 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=26527/tid=26535] ppid=26514 vsize=888480 CPUtime=0
/proc/26527/task/26535/stat : 26535 (java) S 26514 26513 29493 34817 29493 4202560 0 0 0 0 0 0 0 0 25 0 10 0 75861224 909803520 76042 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26536] ppid=26514 vsize=888480 CPUtime=0
/proc/26527/task/26536/stat : 26536 (java) S 26514 26513 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 10 0 75861224 909803520 76042 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.99
Current children cumulated vsize (KiB) 893624

[startup+4.40603 s]
/proc/loadavg: 1.83 1.75 1.48 1/46 26537
/proc/meminfo: memFree=6728/1048576 swapFree=0/0
[pid=26513] ppid=26512 vsize=2568 CPUtime=0
/proc/26513/stat : 26513 (p2cudf-paranoid) S 26512 26513 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 18 0 1 0 75861215 2629632 269 1283457024 134512640 135304128 4291477216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/26513/statm: 642 269 230 194 0 29 0
[pid=26514] ppid=26513 vsize=2576 CPUtime=0.03
/proc/26514/stat : 26514 (p2cudf) S 26513 26513 29493 34817 29493 4202496 395 3012 0 1 0 0 2 1 25 0 1 0 75861215 2637824 282 1283457024 134512640 135304128 4288963712 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/26514/statm: 644 282 239 194 0 31 0
[pid=26527] ppid=26514 vsize=887320 CPUtime=4.34
/proc/26527/stat : 26527 (java) S 26514 26513 29493 34817 29493 4202496 82690 0 1 0 407 27 0 0 25 0 11 0 75861218 908615680 75793 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/26527/statm: 221830 75793 1747 10 0 218921 0
[pid=26527/tid=26528] ppid=26514 vsize=887320 CPUtime=1.84
/proc/26527/task/26528/stat : 26528 (java) S 26514 26513 29493 34817 29493 4202560 50192 0 1 0 169 15 0 0 25 0 11 0 75861219 908615680 75793 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26529] ppid=26514 vsize=887320 CPUtime=0.36
/proc/26527/task/26529/stat : 26529 (java) S 26514 26513 29493 34817 29493 4202560 16499 0 0 0 29 7 0 0 16 0 11 0 75861221 908615680 75793 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 0 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26530] ppid=26514 vsize=887320 CPUtime=0
/proc/26527/task/26530/stat : 26530 (java) S 26514 26513 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 18 0 11 0 75861221 908615680 75793 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26531] ppid=26514 vsize=887320 CPUtime=0
/proc/26527/task/26531/stat : 26531 (java) S 26514 26513 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 11 0 75861221 908615680 75793 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26532] ppid=26514 vsize=887320 CPUtime=0
/proc/26527/task/26532/stat : 26532 (java) S 26514 26513 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 11 0 75861223 908615680 75793 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26533] ppid=26514 vsize=887320 CPUtime=1.2
/proc/26527/task/26533/stat : 26533 (java) S 26514 26513 29493 34817 29493 4202560 11137 0 0 0 116 4 0 0 19 0 11 0 75861224 908615680 75793 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26534] ppid=26514 vsize=887320 CPUtime=0.91
/proc/26527/task/26534/stat : 26534 (java) S 26514 26513 29493 34817 29493 4202560 3782 0 0 0 91 0 0 0 15 0 11 0 75861224 908615680 75793 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26535] ppid=26514 vsize=887320 CPUtime=0
/proc/26527/task/26535/stat : 26535 (java) S 26514 26513 29493 34817 29493 4202560 0 0 0 0 0 0 0 0 25 0 11 0 75861224 908615680 75793 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26536] ppid=26514 vsize=887320 CPUtime=0
/proc/26527/task/26536/stat : 26536 (java) S 26514 26513 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 11 0 75861224 908615680 75793 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26537] ppid=26514 vsize=887320 CPUtime=0
/proc/26527/task/26537/stat : 26537 (java) S 26514 26513 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 25 0 11 0 75861653 908615680 75793 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.37
Current children cumulated vsize (KiB) 892464

[startup+4.80601 s]
/proc/loadavg: 1.83 1.75 1.48 1/46 26537
/proc/meminfo: memFree=6728/1048576 swapFree=0/0
[pid=26513] ppid=26512 vsize=2568 CPUtime=0
/proc/26513/stat : 26513 (p2cudf-paranoid) S 26512 26513 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 18 0 1 0 75861215 2629632 269 1283457024 134512640 135304128 4291477216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/26513/statm: 642 269 230 194 0 29 0
[pid=26514] ppid=26513 vsize=2576 CPUtime=0.03
/proc/26514/stat : 26514 (p2cudf) S 26513 26513 29493 34817 29493 4202496 395 3012 0 1 0 0 2 1 25 0 1 0 75861215 2637824 282 1283457024 134512640 135304128 4288963712 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/26514/statm: 644 282 239 194 0 31 0
[pid=26527] ppid=26514 vsize=887320 CPUtime=4.34
/proc/26527/stat : 26527 (java) S 26514 26513 29493 34817 29493 4202496 82690 0 1 0 407 27 0 0 25 0 11 0 75861218 908615680 75793 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/26527/statm: 221830 75793 1747 10 0 218921 0
[pid=26527/tid=26528] ppid=26514 vsize=887320 CPUtime=1.84
/proc/26527/task/26528/stat : 26528 (java) S 26514 26513 29493 34817 29493 4202560 50192 0 1 0 169 15 0 0 25 0 11 0 75861219 908615680 75793 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26529] ppid=26514 vsize=887320 CPUtime=0.36
/proc/26527/task/26529/stat : 26529 (java) S 26514 26513 29493 34817 29493 4202560 16499 0 0 0 29 7 0 0 15 0 11 0 75861221 908615680 75793 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 0 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26530] ppid=26514 vsize=887320 CPUtime=0
/proc/26527/task/26530/stat : 26530 (java) S 26514 26513 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 18 0 11 0 75861221 908615680 75793 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26531] ppid=26514 vsize=887320 CPUtime=0
/proc/26527/task/26531/stat : 26531 (java) S 26514 26513 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 11 0 75861221 908615680 75793 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26532] ppid=26514 vsize=887320 CPUtime=0
/proc/26527/task/26532/stat : 26532 (java) S 26514 26513 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 11 0 75861223 908615680 75793 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26533] ppid=26514 vsize=887320 CPUtime=1.2
/proc/26527/task/26533/stat : 26533 (java) S 26514 26513 29493 34817 29493 4202560 11137 0 0 0 116 4 0 0 19 0 11 0 75861224 908615680 75793 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26534] ppid=26514 vsize=887320 CPUtime=0.91
/proc/26527/task/26534/stat : 26534 (java) S 26514 26513 29493 34817 29493 4202560 3782 0 0 0 91 0 0 0 15 0 11 0 75861224 908615680 75793 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26535] ppid=26514 vsize=887320 CPUtime=0
/proc/26527/task/26535/stat : 26535 (java) S 26514 26513 29493 34817 29493 4202560 0 0 0 0 0 0 0 0 25 0 11 0 75861224 908615680 75793 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26536] ppid=26514 vsize=887320 CPUtime=0
/proc/26527/task/26536/stat : 26536 (java) S 26514 26513 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 11 0 75861224 908615680 75793 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26537] ppid=26514 vsize=887320 CPUtime=0
/proc/26527/task/26537/stat : 26537 (java) S 26514 26513 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 25 0 11 0 75861653 908615680 75793 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.37
Current children cumulated vsize (KiB) 892464

[startup+4.906 s]
/proc/loadavg: 1.83 1.75 1.48 1/46 26537
/proc/meminfo: memFree=6728/1048576 swapFree=0/0
[pid=26513] ppid=26512 vsize=2568 CPUtime=0
/proc/26513/stat : 26513 (p2cudf-paranoid) S 26512 26513 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 18 0 1 0 75861215 2629632 269 1283457024 134512640 135304128 4291477216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/26513/statm: 642 269 230 194 0 29 0
[pid=26514] ppid=26513 vsize=2576 CPUtime=0.03
/proc/26514/stat : 26514 (p2cudf) S 26513 26513 29493 34817 29493 4202496 395 3012 0 1 0 0 2 1 25 0 1 0 75861215 2637824 282 1283457024 134512640 135304128 4288963712 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/26514/statm: 644 282 239 194 0 31 0
[pid=26527] ppid=26514 vsize=887320 CPUtime=4.34
/proc/26527/stat : 26527 (java) S 26514 26513 29493 34817 29493 4202496 82692 0 1 0 407 27 0 0 25 0 10 0 75861218 908615680 75795 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/26527/statm: 221830 75795 1749 10 0 218921 0
[pid=26527/tid=26528] ppid=26514 vsize=887320 CPUtime=1.84
/proc/26527/task/26528/stat : 26528 (java) S 26514 26513 29493 34817 29493 4202560 50192 0 1 0 169 15 0 0 20 0 10 0 75861219 908615680 75795 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26529] ppid=26514 vsize=887320 CPUtime=0.36
/proc/26527/task/26529/stat : 26529 (java) S 26514 26513 29493 34817 29493 4202560 16500 0 0 0 29 7 0 0 16 0 10 0 75861221 908615680 75795 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 0 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26530] ppid=26514 vsize=887320 CPUtime=0
/proc/26527/task/26530/stat : 26530 (java) S 26514 26513 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 18 0 10 0 75861221 908615680 75795 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26531] ppid=26514 vsize=887320 CPUtime=0
/proc/26527/task/26531/stat : 26531 (java) S 26514 26513 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 10 0 75861221 908615680 75795 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26532] ppid=26514 vsize=887320 CPUtime=0
/proc/26527/task/26532/stat : 26532 (java) S 26514 26513 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 75861223 908615680 75795 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26533] ppid=26514 vsize=887320 CPUtime=1.2
/proc/26527/task/26533/stat : 26533 (java) S 26514 26513 29493 34817 29493 4202560 11137 0 0 0 116 4 0 0 19 0 10 0 75861224 908615680 75795 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26534] ppid=26514 vsize=887320 CPUtime=0.91
/proc/26527/task/26534/stat : 26534 (java) S 26514 26513 29493 34817 29493 4202560 3782 0 0 0 91 0 0 0 15 0 10 0 75861224 908615680 75795 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26535] ppid=26514 vsize=887320 CPUtime=0
/proc/26527/task/26535/stat : 26535 (java) S 26514 26513 29493 34817 29493 4202560 0 0 0 0 0 0 0 0 25 0 10 0 75861224 908615680 75795 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
[pid=26527/tid=26536] ppid=26514 vsize=887320 CPUtime=0
/proc/26527/task/26536/stat : 26536 (java) S 26514 26513 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 10 0 75861224 908615680 75795 1283457024 134512640 134550932 4293762992 18446744073709551615 4294960130 0 4 0 16800975 18446612132467744832 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.37
Current children cumulated vsize (KiB) 892464

Child status: 0
Real time (s): 4.94514
CPU time (s): 4.42027
CPU user time (s): 4.09225
CPU system time (s): 0.32802
CPU usage (%): 89.3863
Max. virtual memory (cumulated for all children) (KiB): 893680

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 4.09225
system time used= 0.32802
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 86496
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= 409
involuntary context switches= 399

runsolver used 0 second user time and 0 second system time

The end