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/201108241238/gj-trendy-solver-1.0/19890cfe-db9f-11df-9e6c-00163e3d3b7c.cudf.dudf-real.log.runsolver ./gj-trendy-solver-1.0 /home/misc2010/data/2011/dudf-real//19890cfe-db9f-11df-9e6c-00163e3d3b7c.cudf /home/misc2010/tmp/201108241238/gj-trendy-solver-1.0/19890cfe-db9f-11df-9e6c-00163e3d3b7c.cudf.dudf-real.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.18 1.11 1.03 4/34 5664
/proc/meminfo: memFree=492904/1048576 swapFree=0/0
[pid=5663] ppid=5662 vsize=2568 CPUtime=0
/proc/5663/stat : 5663 (gj-trendy-solve) S 5662 5663 1511 34817 1511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 1328258 2629632 270 1283457024 134512640 135304128 4292794320 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5663/statm: 642 270 229 194 0 29 0
[pid=5664] ppid=5663 vsize=1648 CPUtime=0.01
/proc/5664/stat : 5664 (java) R 5663 5663 1511 34817 1511 4194304 335 0 0 0 0 1 0 0 25 0 1 0 1328258 1687552 76 1283457024 134512640 134550932 4288762656 18446744073709551615 4159835665 0 0 0 0 0 0 0 17 0 0 0 0
/proc/5664/statm: 412 76 57 10 0 13 0

[startup+0.173886 s]
/proc/loadavg: 1.18 1.11 1.03 4/34 5664
/proc/meminfo: memFree=492904/1048576 swapFree=0/0
[pid=5663] ppid=5662 vsize=2568 CPUtime=0
/proc/5663/stat : 5663 (gj-trendy-solve) S 5662 5663 1511 34817 1511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 1328258 2629632 270 1283457024 134512640 135304128 4292794320 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5663/statm: 642 270 229 194 0 29 0
[pid=5664] ppid=5663 vsize=409800 CPUtime=0.17
/proc/5664/stat : 5664 (java) S 5663 5663 1511 34817 1511 4202496 3872 0 1 0 15 2 0 0 25 0 9 0 1328258 419635200 3299 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/5664/statm: 102450 3299 1803 10 0 96598 0
Current children cumulated CPU time (s) 0.17
Current children cumulated vsize (KiB) 412368

[startup+0.203882 s]
/proc/loadavg: 1.18 1.11 1.03 4/34 5664
/proc/meminfo: memFree=492904/1048576 swapFree=0/0
[pid=5663] ppid=5662 vsize=2568 CPUtime=0
/proc/5663/stat : 5663 (gj-trendy-solve) S 5662 5663 1511 34817 1511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 1328258 2629632 270 1283457024 134512640 135304128 4292794320 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5663/statm: 642 270 229 194 0 29 0
[pid=5664] ppid=5663 vsize=409800 CPUtime=0.2
/proc/5664/stat : 5664 (java) S 5663 5663 1511 34817 1511 4202496 3933 0 1 0 18 2 0 0 25 0 9 0 1328258 419635200 3360 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/5664/statm: 102450 3360 1803 10 0 96598 0
Current children cumulated CPU time (s) 0.2
Current children cumulated vsize (KiB) 412368

[startup+0.313919 s]
/proc/loadavg: 1.18 1.11 1.03 4/34 5664
/proc/meminfo: memFree=492904/1048576 swapFree=0/0
[pid=5663] ppid=5662 vsize=2568 CPUtime=0
/proc/5663/stat : 5663 (gj-trendy-solve) S 5662 5663 1511 34817 1511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 1328258 2629632 270 1283457024 134512640 135304128 4292794320 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5663/statm: 642 270 229 194 0 29 0
[pid=5664] ppid=5663 vsize=410384 CPUtime=0.31
/proc/5664/stat : 5664 (java) S 5663 5663 1511 34817 1511 4202496 4455 0 1 0 29 2 0 0 25 0 9 0 1328258 420233216 3882 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/5664/statm: 102596 3882 1950 10 0 96744 0
Current children cumulated CPU time (s) 0.31
Current children cumulated vsize (KiB) 412952

[startup+0.713999 s]
/proc/loadavg: 1.18 1.11 1.03 4/34 5664
/proc/meminfo: memFree=492904/1048576 swapFree=0/0
[pid=5663] ppid=5662 vsize=2568 CPUtime=0
/proc/5663/stat : 5663 (gj-trendy-solve) S 5662 5663 1511 34817 1511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 1328258 2629632 270 1283457024 134512640 135304128 4292794320 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5663/statm: 642 270 229 194 0 29 0
[pid=5664] ppid=5663 vsize=410652 CPUtime=0.72
/proc/5664/stat : 5664 (java) S 5663 5663 1511 34817 1511 4202496 12785 0 1 0 68 4 0 0 25 0 9 0 1328258 420507648 12025 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/5664/statm: 102663 12025 2901 10 0 96811 0
Current children cumulated CPU time (s) 0.72
Current children cumulated vsize (KiB) 413220

[startup+1.50415 s]
/proc/loadavg: 1.18 1.11 1.03 2/43 5673
/proc/meminfo: memFree=433424/1048576 swapFree=0/0
[pid=5663] ppid=5662 vsize=2568 CPUtime=0
/proc/5663/stat : 5663 (gj-trendy-solve) S 5662 5663 1511 34817 1511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 1328258 2629632 270 1283457024 134512640 135304128 4292794320 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5663/statm: 642 270 229 194 0 29 0
[pid=5664] ppid=5663 vsize=410784 CPUtime=1.5
/proc/5664/stat : 5664 (java) S 5663 5663 1511 34817 1511 4202496 26801 0 1 0 143 7 0 0 25 0 9 0 1328258 420642816 26041 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/5664/statm: 102696 26041 2901 10 0 96844 0
[pid=5664/tid=5666] ppid=5663 vsize=410784 CPUtime=0.84
/proc/5664/task/5666/stat : 5666 (java) R 5663 5663 1511 34817 1511 4202560 6842 0 1 0 82 2 0 0 25 0 9 0 1328259 420642816 26041 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=5664/tid=5667] ppid=5663 vsize=410784 CPUtime=0.62
/proc/5664/task/5667/stat : 5667 (java) R 5663 5663 1511 34817 1511 4202560 18577 0 0 0 58 4 0 0 18 0 9 0 1328260 420642816 26041 1283457024 134512640 134550932 4288762656 18446744073709551615 4150667192 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=5664/tid=5668] ppid=5663 vsize=410784 CPUtime=0
/proc/5664/task/5668/stat : 5668 (java) S 5663 5663 1511 34817 1511 4202560 15 0 0 0 0 0 0 0 20 0 9 0 1328260 420642816 26041 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5669] ppid=5663 vsize=410784 CPUtime=0
/proc/5664/task/5669/stat : 5669 (java) S 5663 5663 1511 34817 1511 4202560 5 0 0 0 0 0 0 0 20 0 9 0 1328260 420642816 26041 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5670] ppid=5663 vsize=410784 CPUtime=0
/proc/5664/task/5670/stat : 5670 (java) S 5663 5663 1511 34817 1511 4202560 1 0 0 0 0 0 0 0 25 0 9 0 1328261 420642816 26041 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5671] ppid=5663 vsize=410784 CPUtime=0.02
/proc/5664/task/5671/stat : 5671 (java) S 5663 5663 1511 34817 1511 4202560 439 0 0 0 2 0 0 0 18 0 9 0 1328261 420642816 26041 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5672] ppid=5663 vsize=410784 CPUtime=0
/proc/5664/task/5672/stat : 5672 (java) S 5663 5663 1511 34817 1511 4202560 1 0 0 0 0 0 0 0 25 0 9 0 1328261 420642816 26041 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5673] ppid=5663 vsize=410784 CPUtime=0
/proc/5664/task/5673/stat : 5673 (java) S 5663 5663 1511 34817 1511 4202560 2 0 0 0 0 0 0 0 15 0 9 0 1328261 420642816 26041 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.5
Current children cumulated vsize (KiB) 413352

[startup+3.10464 s]
/proc/loadavg: 1.18 1.11 1.03 2/43 5673
/proc/meminfo: memFree=358156/1048576 swapFree=0/0
[pid=5663] ppid=5662 vsize=2568 CPUtime=0
/proc/5663/stat : 5663 (gj-trendy-solve) S 5662 5663 1511 34817 1511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 1328258 2629632 270 1283457024 134512640 135304128 4292794320 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5663/statm: 642 270 229 194 0 29 0
[pid=5664] ppid=5663 vsize=410928 CPUtime=3.1
/proc/5664/stat : 5664 (java) S 5663 5663 1511 34817 1511 4202496 44280 0 1 0 298 12 0 0 25 0 9 0 1328258 420790272 43430 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/5664/statm: 102732 43430 2919 10 0 96877 0
[pid=5664/tid=5666] ppid=5663 vsize=410928 CPUtime=1.46
/proc/5664/task/5666/stat : 5666 (java) R 5663 5663 1511 34817 1511 4202560 9894 0 1 0 144 2 0 0 25 0 9 0 1328259 420790272 43430 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=5664/tid=5667] ppid=5663 vsize=410928 CPUtime=1.56
/proc/5664/task/5667/stat : 5667 (java) S 5663 5663 1511 34817 1511 4202560 32951 0 0 0 147 9 0 0 16 0 9 0 1328260 420790272 43430 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 0 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5668] ppid=5663 vsize=410928 CPUtime=0
/proc/5664/task/5668/stat : 5668 (java) S 5663 5663 1511 34817 1511 4202560 15 0 0 0 0 0 0 0 18 0 9 0 1328260 420790272 43430 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5669] ppid=5663 vsize=410928 CPUtime=0
/proc/5664/task/5669/stat : 5669 (java) S 5663 5663 1511 34817 1511 4202560 5 0 0 0 0 0 0 0 18 0 9 0 1328260 420790272 43430 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5670] ppid=5663 vsize=410928 CPUtime=0
/proc/5664/task/5670/stat : 5670 (java) S 5663 5663 1511 34817 1511 4202560 1 0 0 0 0 0 0 0 25 0 9 0 1328261 420790272 43430 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5671] ppid=5663 vsize=410928 CPUtime=0.05
/proc/5664/task/5671/stat : 5671 (java) S 5663 5663 1511 34817 1511 4202560 492 0 0 0 5 0 0 0 15 0 9 0 1328261 420790272 43430 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5672] ppid=5663 vsize=410928 CPUtime=0
/proc/5664/task/5672/stat : 5672 (java) S 5663 5663 1511 34817 1511 4202560 1 0 0 0 0 0 0 0 25 0 9 0 1328261 420790272 43430 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5673] ppid=5663 vsize=410928 CPUtime=0
/proc/5664/task/5673/stat : 5673 (java) S 5663 5663 1511 34817 1511 4202560 2 0 0 0 0 0 0 0 15 0 9 0 1328261 420790272 43430 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.1
Current children cumulated vsize (KiB) 413496

[startup+6.30564 s]
/proc/loadavg: 1.16 1.11 1.03 2/44 5674
/proc/meminfo: memFree=327768/1048576 swapFree=0/0
[pid=5663] ppid=5662 vsize=2568 CPUtime=0
/proc/5663/stat : 5663 (gj-trendy-solve) S 5662 5663 1511 34817 1511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 1328258 2629632 270 1283457024 134512640 135304128 4292794320 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5663/statm: 642 270 229 194 0 29 0
[pid=5664] ppid=5663 vsize=411252 CPUtime=6.3
/proc/5664/stat : 5664 (java) S 5663 5663 1511 34817 1511 4202496 45309 0 1 0 616 14 0 0 25 0 10 0 1328258 421122048 44455 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/5664/statm: 102813 44455 2920 10 0 96958 0
[pid=5664/tid=5666] ppid=5663 vsize=411252 CPUtime=4.62
/proc/5664/task/5666/stat : 5666 (java) R 5663 5663 1511 34817 1511 4202560 10890 0 1 0 459 3 0 0 25 0 10 0 1328259 421122048 44455 1283457024 134512640 134550932 4288762656 18446744073709551615 4115198490 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=5664/tid=5667] ppid=5663 vsize=411252 CPUtime=1.56
/proc/5664/task/5667/stat : 5667 (java) S 5663 5663 1511 34817 1511 4202560 32951 0 0 0 147 9 0 0 15 0 10 0 1328260 421122048 44455 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 0 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5668] ppid=5663 vsize=411252 CPUtime=0
/proc/5664/task/5668/stat : 5668 (java) S 5663 5663 1511 34817 1511 4202560 15 0 0 0 0 0 0 0 18 0 10 0 1328260 421122048 44455 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5669] ppid=5663 vsize=411252 CPUtime=0
/proc/5664/task/5669/stat : 5669 (java) S 5663 5663 1511 34817 1511 4202560 5 0 0 0 0 0 0 0 18 0 10 0 1328260 421122048 44455 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5670] ppid=5663 vsize=411252 CPUtime=0
/proc/5664/task/5670/stat : 5670 (java) S 5663 5663 1511 34817 1511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 1328261 421122048 44455 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5671] ppid=5663 vsize=411252 CPUtime=0.09
/proc/5664/task/5671/stat : 5671 (java) S 5663 5663 1511 34817 1511 4202560 521 0 0 0 9 0 0 0 15 0 10 0 1328261 421122048 44455 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5672] ppid=5663 vsize=411252 CPUtime=0
/proc/5664/task/5672/stat : 5672 (java) S 5663 5663 1511 34817 1511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 1328261 421122048 44455 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5673] ppid=5663 vsize=411252 CPUtime=0
/proc/5664/task/5673/stat : 5673 (java) S 5663 5663 1511 34817 1511 4202560 2 0 0 0 0 0 0 0 15 0 10 0 1328261 421122048 44455 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5674] ppid=5663 vsize=411252 CPUtime=0
/proc/5664/task/5674/stat : 5674 (java) S 5663 5663 1511 34817 1511 4202560 4 0 0 0 0 0 0 0 25 0 10 0 1328574 421122048 44455 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.3
Current children cumulated vsize (KiB) 413820

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

[startup+6.40567 s]
/proc/loadavg: 1.16 1.11 1.03 2/44 5674
/proc/meminfo: memFree=327768/1048576 swapFree=0/0
[pid=5663] ppid=5662 vsize=2568 CPUtime=0
/proc/5663/stat : 5663 (gj-trendy-solve) S 5662 5663 1511 34817 1511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 1328258 2629632 270 1283457024 134512640 135304128 4292794320 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5663/statm: 642 270 229 194 0 29 0
[pid=5664] ppid=5663 vsize=411252 CPUtime=6.4
/proc/5664/stat : 5664 (java) S 5663 5663 1511 34817 1511 4202496 45353 0 1 0 626 14 0 0 25 0 10 0 1328258 421122048 44499 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/5664/statm: 102813 44499 2920 10 0 96958 0
[pid=5664/tid=5666] ppid=5663 vsize=411252 CPUtime=4.72
/proc/5664/task/5666/stat : 5666 (java) R 5663 5663 1511 34817 1511 4202560 10934 0 1 0 469 3 0 0 25 0 10 0 1328259 421122048 44499 1283457024 134512640 134550932 4288762656 18446744073709551615 4115296996 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=5664/tid=5667] ppid=5663 vsize=411252 CPUtime=1.56
/proc/5664/task/5667/stat : 5667 (java) S 5663 5663 1511 34817 1511 4202560 32951 0 0 0 147 9 0 0 15 0 10 0 1328260 421122048 44499 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 0 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5668] ppid=5663 vsize=411252 CPUtime=0
/proc/5664/task/5668/stat : 5668 (java) S 5663 5663 1511 34817 1511 4202560 15 0 0 0 0 0 0 0 18 0 10 0 1328260 421122048 44499 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5669] ppid=5663 vsize=411252 CPUtime=0
/proc/5664/task/5669/stat : 5669 (java) S 5663 5663 1511 34817 1511 4202560 5 0 0 0 0 0 0 0 18 0 10 0 1328260 421122048 44499 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5670] ppid=5663 vsize=411252 CPUtime=0
/proc/5664/task/5670/stat : 5670 (java) S 5663 5663 1511 34817 1511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 1328261 421122048 44499 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5671] ppid=5663 vsize=411252 CPUtime=0.09
/proc/5664/task/5671/stat : 5671 (java) S 5663 5663 1511 34817 1511 4202560 521 0 0 0 9 0 0 0 15 0 10 0 1328261 421122048 44499 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5672] ppid=5663 vsize=411252 CPUtime=0
/proc/5664/task/5672/stat : 5672 (java) S 5663 5663 1511 34817 1511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 1328261 421122048 44499 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5673] ppid=5663 vsize=411252 CPUtime=0
/proc/5664/task/5673/stat : 5673 (java) S 5663 5663 1511 34817 1511 4202560 2 0 0 0 0 0 0 0 15 0 10 0 1328261 421122048 44499 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5674] ppid=5663 vsize=411252 CPUtime=0
/proc/5664/task/5674/stat : 5674 (java) S 5663 5663 1511 34817 1511 4202560 4 0 0 0 0 0 0 0 25 0 10 0 1328574 421122048 44499 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.4
Current children cumulated vsize (KiB) 413820

[startup+8.00611 s]
/proc/loadavg: 1.16 1.11 1.03 2/44 5674
/proc/meminfo: memFree=295660/1048576 swapFree=0/0
[pid=5663] ppid=5662 vsize=2568 CPUtime=0
/proc/5663/stat : 5663 (gj-trendy-solve) S 5662 5663 1511 34817 1511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 1328258 2629632 270 1283457024 134512640 135304128 4292794320 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5663/statm: 642 270 229 194 0 29 0
[pid=5664] ppid=5663 vsize=411252 CPUtime=7.98
/proc/5664/stat : 5664 (java) S 5663 5663 1511 34817 1511 4202496 56196 0 1 0 780 18 0 0 25 0 10 0 1328258 421122048 55342 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/5664/statm: 102813 55342 2920 10 0 96958 0
[pid=5664/tid=5666] ppid=5663 vsize=411252 CPUtime=6.07
/proc/5664/task/5666/stat : 5666 (java) R 5663 5663 1511 34817 1511 4202560 14234 0 1 0 602 5 0 0 25 0 10 0 1328259 421122048 55342 1283457024 134512640 134550932 4288762656 18446744073709551615 4115311364 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=5664/tid=5667] ppid=5663 vsize=411252 CPUtime=1.75
/proc/5664/task/5667/stat : 5667 (java) S 5663 5663 1511 34817 1511 4202560 40475 0 0 0 164 11 0 0 16 0 10 0 1328260 421122048 55342 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 0 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5668] ppid=5663 vsize=411252 CPUtime=0
/proc/5664/task/5668/stat : 5668 (java) S 5663 5663 1511 34817 1511 4202560 15 0 0 0 0 0 0 0 18 0 10 0 1328260 421122048 55342 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5669] ppid=5663 vsize=411252 CPUtime=0
/proc/5664/task/5669/stat : 5669 (java) S 5663 5663 1511 34817 1511 4202560 5 0 0 0 0 0 0 0 18 0 10 0 1328260 421122048 55342 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5670] ppid=5663 vsize=411252 CPUtime=0
/proc/5664/task/5670/stat : 5670 (java) S 5663 5663 1511 34817 1511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 1328261 421122048 55342 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5671] ppid=5663 vsize=411252 CPUtime=0.13
/proc/5664/task/5671/stat : 5671 (java) S 5663 5663 1511 34817 1511 4202560 540 0 0 0 13 0 0 0 15 0 10 0 1328261 421122048 55342 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5672] ppid=5663 vsize=411252 CPUtime=0
/proc/5664/task/5672/stat : 5672 (java) S 5663 5663 1511 34817 1511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 1328261 421122048 55342 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5673] ppid=5663 vsize=411252 CPUtime=0
/proc/5664/task/5673/stat : 5673 (java) S 5663 5663 1511 34817 1511 4202560 2 0 0 0 0 0 0 0 15 0 10 0 1328261 421122048 55342 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5674] ppid=5663 vsize=411252 CPUtime=0
/proc/5664/task/5674/stat : 5674 (java) S 5663 5663 1511 34817 1511 4202560 4 0 0 0 0 0 0 0 25 0 10 0 1328574 421122048 55342 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 7.98
Current children cumulated vsize (KiB) 413820

[startup+9.60643 s]
/proc/loadavg: 1.15 1.11 1.03 2/44 5674
/proc/meminfo: memFree=282516/1048576 swapFree=0/0
[pid=5663] ppid=5662 vsize=2568 CPUtime=0
/proc/5663/stat : 5663 (gj-trendy-solve) S 5662 5663 1511 34817 1511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 1328258 2629632 270 1283457024 134512640 135304128 4292794320 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5663/statm: 642 270 229 194 0 29 0
[pid=5664] ppid=5663 vsize=411252 CPUtime=9.58
/proc/5664/stat : 5664 (java) S 5663 5663 1511 34817 1511 4202496 56199 0 1 0 939 19 0 0 25 0 10 0 1328258 421122048 55345 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/5664/statm: 102813 55345 2920 10 0 96958 0
[pid=5664/tid=5666] ppid=5663 vsize=411252 CPUtime=7.67
/proc/5664/task/5666/stat : 5666 (java) R 5663 5663 1511 34817 1511 4202560 14234 0 1 0 761 6 0 0 25 0 10 0 1328259 421122048 55345 1283457024 134512640 134550932 4288762656 18446744073709551615 4115198499 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=5664/tid=5667] ppid=5663 vsize=411252 CPUtime=1.75
/proc/5664/task/5667/stat : 5667 (java) S 5663 5663 1511 34817 1511 4202560 40475 0 0 0 164 11 0 0 16 0 10 0 1328260 421122048 55345 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 0 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5668] ppid=5663 vsize=411252 CPUtime=0
/proc/5664/task/5668/stat : 5668 (java) S 5663 5663 1511 34817 1511 4202560 15 0 0 0 0 0 0 0 18 0 10 0 1328260 421122048 55345 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5669] ppid=5663 vsize=411252 CPUtime=0
/proc/5664/task/5669/stat : 5669 (java) S 5663 5663 1511 34817 1511 4202560 5 0 0 0 0 0 0 0 18 0 10 0 1328260 421122048 55345 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5670] ppid=5663 vsize=411252 CPUtime=0
/proc/5664/task/5670/stat : 5670 (java) S 5663 5663 1511 34817 1511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 1328261 421122048 55345 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5671] ppid=5663 vsize=411252 CPUtime=0.13
/proc/5664/task/5671/stat : 5671 (java) S 5663 5663 1511 34817 1511 4202560 543 0 0 0 13 0 0 0 16 0 10 0 1328261 421122048 55345 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5672] ppid=5663 vsize=411252 CPUtime=0
/proc/5664/task/5672/stat : 5672 (java) S 5663 5663 1511 34817 1511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 1328261 421122048 55345 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5673] ppid=5663 vsize=411252 CPUtime=0
/proc/5664/task/5673/stat : 5673 (java) S 5663 5663 1511 34817 1511 4202560 2 0 0 0 0 0 0 0 15 0 10 0 1328261 421122048 55345 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5674] ppid=5663 vsize=411252 CPUtime=0
/proc/5664/task/5674/stat : 5674 (java) S 5663 5663 1511 34817 1511 4202560 4 0 0 0 0 0 0 0 25 0 10 0 1328574 421122048 55345 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 9.58
Current children cumulated vsize (KiB) 413820

[startup+10.0065 s]
/proc/loadavg: 1.15 1.11 1.03 2/44 5674
/proc/meminfo: memFree=282516/1048576 swapFree=0/0
[pid=5663] ppid=5662 vsize=2568 CPUtime=0
/proc/5663/stat : 5663 (gj-trendy-solve) S 5662 5663 1511 34817 1511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 1328258 2629632 270 1283457024 134512640 135304128 4292794320 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5663/statm: 642 270 229 194 0 29 0
[pid=5664] ppid=5663 vsize=411252 CPUtime=9.98
/proc/5664/stat : 5664 (java) S 5663 5663 1511 34817 1511 4202496 56202 0 1 0 979 19 0 0 25 0 10 0 1328258 421122048 55348 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/5664/statm: 102813 55348 2920 10 0 96958 0
[pid=5664/tid=5666] ppid=5663 vsize=411252 CPUtime=8.01
/proc/5664/task/5666/stat : 5666 (java) R 5663 5663 1511 34817 1511 4202560 14234 0 1 0 795 6 0 0 25 0 10 0 1328259 421122048 55348 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=5664/tid=5667] ppid=5663 vsize=411252 CPUtime=1.81
/proc/5664/task/5667/stat : 5667 (java) R 5663 5663 1511 34817 1511 4202560 40475 0 0 0 170 11 0 0 16 0 10 0 1328260 421122048 55348 1283457024 134512640 134550932 4288762656 18446744073709551615 4150641429 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=5664/tid=5668] ppid=5663 vsize=411252 CPUtime=0
/proc/5664/task/5668/stat : 5668 (java) S 5663 5663 1511 34817 1511 4202560 15 0 0 0 0 0 0 0 18 0 10 0 1328260 421122048 55348 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5669] ppid=5663 vsize=411252 CPUtime=0
/proc/5664/task/5669/stat : 5669 (java) S 5663 5663 1511 34817 1511 4202560 5 0 0 0 0 0 0 0 18 0 10 0 1328260 421122048 55348 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5670] ppid=5663 vsize=411252 CPUtime=0
/proc/5664/task/5670/stat : 5670 (java) S 5663 5663 1511 34817 1511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 1328261 421122048 55348 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5671] ppid=5663 vsize=411252 CPUtime=0.13
/proc/5664/task/5671/stat : 5671 (java) S 5663 5663 1511 34817 1511 4202560 546 0 0 0 13 0 0 0 15 0 10 0 1328261 421122048 55348 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5672] ppid=5663 vsize=411252 CPUtime=0
/proc/5664/task/5672/stat : 5672 (java) S 5663 5663 1511 34817 1511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 1328261 421122048 55348 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5673] ppid=5663 vsize=411252 CPUtime=0
/proc/5664/task/5673/stat : 5673 (java) S 5663 5663 1511 34817 1511 4202560 2 0 0 0 0 0 0 0 15 0 10 0 1328261 421122048 55348 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
[pid=5664/tid=5674] ppid=5663 vsize=411252 CPUtime=0
/proc/5664/task/5674/stat : 5674 (java) S 5663 5663 1511 34817 1511 4202560 4 0 0 0 0 0 0 0 25 0 10 0 1328574 421122048 55348 1283457024 134512640 134550932 4288762656 18446744073709551615 4294960130 0 4 0 16800975 18446612133275974720 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 9.98
Current children cumulated vsize (KiB) 413820

[startup+10.4106 s]
/proc/loadavg: 1.15 1.11 1.03 2/44 5674
/proc/meminfo: memFree=282516/1048576 swapFree=0/0
[pid=5663] ppid=5662 vsize=2568 CPUtime=0
/proc/5663/stat : 5663 (gj-trendy-solve) S 5662 5663 1511 34817 1511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 1328258 2629632 270 1283457024 134512640 135304128 4292794320 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5663/statm: 642 270 229 194 0 29 0
[pid=5664] ppid=5663 vsize=0 CPUtime=10.34
/proc/5664/stat : 5664 (java) Z 5663 5663 1511 34817 1511 4202508 56215 0 1 0 1014 20 0 0 18 0 2 0 1328258 0 0 1283457024 0 0 0 0 0 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/5664/statm: 0 0 0 0 0 0 0
[pid=5664/tid=5672] ppid=5663 vsize=0 CPUtime=0
/proc/5664/task/5672/stat : 5672 (java) R 5663 5663 1511 34817 1511 4203588 1 0 0 0 0 0 0 0 18 0 2 0 1328261 0 0 1283457024 0 0 0 0 0 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 10.34
Current children cumulated vsize (KiB) 2568

Child status: 0
Real time (s): 10.4142
CPU time (s): 10.3486
CPU user time (s): 10.1486
CPU system time (s): 0.200012
CPU usage (%): 99.3709
Max. virtual memory (cumulated for all children) (KiB): 413820

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 10.1486
system time used= 0.200012
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 56599
page faults= 1
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 988
involuntary context switches= 1176

runsolver used 0 second user time and 0 second system time

The end