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/56ae4afa-0b33-11df-8a2b-00163e1d94dc.cudf.dudf-real.log.runsolver ./gj-trendy-solver-1.0 /home/misc2010/data/2011/dudf-real//56ae4afa-0b33-11df-8a2b-00163e1d94dc.cudf /home/misc2010/tmp/201108241238/gj-trendy-solver-1.0/56ae4afa-0b33-11df-8a2b-00163e1d94dc.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.25 1.20 1.12 5/36 25231
/proc/meminfo: memFree=357412/1048576 swapFree=0/0
[pid=25229] ppid=25228 vsize=2568 CPUtime=0
/proc/25229/stat : 25229 (gj-trendy-solve) S 25228 25229 1511 34817 1511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 4749095 2629632 269 1283457024 134512640 135304128 4286859824 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25229/statm: 642 269 229 194 0 29 0
[pid=25230] ppid=25229 vsize=11360 CPUtime=0.01
/proc/25230/stat : 25230 (java) R 25229 25229 1511 34817 1511 4202496 919 0 0 0 0 1 0 0 25 0 2 0 4749095 11632640 652 1283457024 134512640 134550932 4293898256 18446744073709551615 4159229544 0 0 0 0 18446744073709551615 0 0 17 0 0 0 0
/proc/25230/statm: 2840 652 285 10 0 1186 0
[pid=25230/tid=25231] ppid=25229 vsize=11360 CPUtime=0
/proc/25230/task/25231/stat : 25231 (java) R 25229 25229 1511 34817 1511 4202560 0 0 0 0 0 0 0 0 25 0 2 0 4749096 11632640 652 1283457024 134512640 134550932 4293898256 18446744073709551615 4159229544 0 0 0 0 0 0 0 -1 0 0 0 0

[startup+0.165414 s]
/proc/loadavg: 1.25 1.20 1.12 5/36 25231
/proc/meminfo: memFree=357412/1048576 swapFree=0/0
[pid=25229] ppid=25228 vsize=2568 CPUtime=0
/proc/25229/stat : 25229 (gj-trendy-solve) S 25228 25229 1511 34817 1511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 4749095 2629632 269 1283457024 134512640 135304128 4286859824 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25229/statm: 642 269 229 194 0 29 0
[pid=25230] ppid=25229 vsize=410104 CPUtime=0.17
/proc/25230/stat : 25230 (java) S 25229 25229 1511 34817 1511 4202496 4086 0 1 0 16 1 0 0 25 0 9 0 4749095 419946496 3514 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/25230/statm: 102526 3514 1933 10 0 96674 0
[pid=25230/tid=25231] ppid=25229 vsize=410104 CPUtime=0.15
/proc/25230/task/25231/stat : 25231 (java) R 25229 25229 1511 34817 1511 4202560 2891 0 1 0 15 0 0 0 25 0 9 0 4749096 419946496 3514 1283457024 134512640 134550932 4293898256 18446744073709551615 4114568340 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 0.17
Current children cumulated vsize (KiB) 412672

[startup+0.205416 s]
/proc/loadavg: 1.25 1.20 1.12 5/36 25231
/proc/meminfo: memFree=357412/1048576 swapFree=0/0
[pid=25229] ppid=25228 vsize=2568 CPUtime=0
/proc/25229/stat : 25229 (gj-trendy-solve) S 25228 25229 1511 34817 1511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 4749095 2629632 269 1283457024 134512640 135304128 4286859824 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25229/statm: 642 269 229 194 0 29 0
[pid=25230] ppid=25229 vsize=410104 CPUtime=0.21
/proc/25230/stat : 25230 (java) S 25229 25229 1511 34817 1511 4202496 4348 0 1 0 20 1 0 0 25 0 9 0 4749095 419946496 3776 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/25230/statm: 102526 3776 1934 10 0 96674 0
[pid=25230/tid=25231] ppid=25229 vsize=410104 CPUtime=0.19
/proc/25230/task/25231/stat : 25231 (java) R 25229 25229 1511 34817 1511 4202560 3153 0 1 0 19 0 0 0 25 0 9 0 4749096 419946496 3776 1283457024 134512640 134550932 4293898256 18446744073709551615 4114586915 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 0.21
Current children cumulated vsize (KiB) 412672

[startup+0.305435 s]
/proc/loadavg: 1.25 1.20 1.12 5/36 25231
/proc/meminfo: memFree=357412/1048576 swapFree=0/0
[pid=25229] ppid=25228 vsize=2568 CPUtime=0
/proc/25229/stat : 25229 (gj-trendy-solve) S 25228 25229 1511 34817 1511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 4749095 2629632 269 1283457024 134512640 135304128 4286859824 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25229/statm: 642 269 229 194 0 29 0
[pid=25230] ppid=25229 vsize=410384 CPUtime=0.31
/proc/25230/stat : 25230 (java) S 25229 25229 1511 34817 1511 4202496 5387 0 1 0 30 1 0 0 25 0 9 0 4749095 420233216 4814 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/25230/statm: 102596 4814 1945 10 0 96744 0
[pid=25230/tid=25231] ppid=25229 vsize=410384 CPUtime=0.26
/proc/25230/task/25231/stat : 25231 (java) R 25229 25229 1511 34817 1511 4202560 3514 0 1 0 26 0 0 0 25 0 9 0 4749096 420233216 4814 1283457024 134512640 134550932 4293898256 18446744073709551615 4114991096 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 0.31
Current children cumulated vsize (KiB) 412952

[startup+0.705504 s]
/proc/loadavg: 1.25 1.20 1.12 5/36 25231
/proc/meminfo: memFree=357412/1048576 swapFree=0/0
[pid=25229] ppid=25228 vsize=2568 CPUtime=0
/proc/25229/stat : 25229 (gj-trendy-solve) S 25228 25229 1511 34817 1511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 4749095 2629632 269 1283457024 134512640 135304128 4286859824 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25229/statm: 642 269 229 194 0 29 0
[pid=25230] ppid=25229 vsize=410784 CPUtime=0.71
/proc/25230/stat : 25230 (java) S 25229 25229 1511 34817 1511 4202496 12777 0 1 0 70 1 0 0 25 0 9 0 4749095 420642816 12020 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/25230/statm: 102696 12020 2896 10 0 96844 0
[pid=25230/tid=25231] ppid=25229 vsize=410784 CPUtime=0.44
/proc/25230/task/25231/stat : 25231 (java) R 25229 25229 1511 34817 1511 4202560 4170 0 1 0 44 0 0 0 25 0 9 0 4749096 420642816 12020 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 0.71
Current children cumulated vsize (KiB) 413352

[startup+1.50568 s]
/proc/loadavg: 1.25 1.20 1.12 2/44 25239
/proc/meminfo: memFree=299800/1048576 swapFree=0/0
[pid=25229] ppid=25228 vsize=2568 CPUtime=0
/proc/25229/stat : 25229 (gj-trendy-solve) S 25228 25229 1511 34817 1511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 4749095 2629632 269 1283457024 134512640 135304128 4286859824 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25229/statm: 642 269 229 194 0 29 0
[pid=25230] ppid=25229 vsize=410784 CPUtime=1.51
/proc/25230/stat : 25230 (java) S 25229 25229 1511 34817 1511 4202496 27631 0 1 0 148 3 0 0 25 0 9 0 4749095 420642816 26874 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/25230/statm: 102696 26874 2896 10 0 96844 0
[pid=25230/tid=25231] ppid=25229 vsize=410784 CPUtime=0.77
/proc/25230/task/25231/stat : 25231 (java) R 25229 25229 1511 34817 1511 4202560 6746 0 1 0 76 1 0 0 25 0 9 0 4749096 420642816 26874 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=25230/tid=25233] ppid=25229 vsize=410784 CPUtime=0.68
/proc/25230/task/25233/stat : 25233 (java) R 25229 25229 1511 34817 1511 4202560 19506 0 0 0 68 0 0 0 19 0 9 0 4749096 420642816 26874 1283457024 134512640 134550932 4293898256 18446744073709551615 4153446488 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=25230/tid=25234] ppid=25229 vsize=410784 CPUtime=0
/proc/25230/task/25234/stat : 25234 (java) S 25229 25229 1511 34817 1511 4202560 15 0 0 0 0 0 0 0 21 0 9 0 4749097 420642816 26874 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25235] ppid=25229 vsize=410784 CPUtime=0
/proc/25230/task/25235/stat : 25235 (java) S 25229 25229 1511 34817 1511 4202560 5 0 0 0 0 0 0 0 21 0 9 0 4749097 420642816 26874 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25236] ppid=25229 vsize=410784 CPUtime=0
/proc/25230/task/25236/stat : 25236 (java) S 25229 25229 1511 34817 1511 4202560 1 0 0 0 0 0 0 0 25 0 9 0 4749098 420642816 26874 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25237] ppid=25229 vsize=410784 CPUtime=0.04
/proc/25230/task/25237/stat : 25237 (java) S 25229 25229 1511 34817 1511 4202560 438 0 0 0 4 0 0 0 17 0 9 0 4749098 420642816 26874 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25238] ppid=25229 vsize=410784 CPUtime=0
/proc/25230/task/25238/stat : 25238 (java) S 25229 25229 1511 34817 1511 4202560 1 0 0 0 0 0 0 0 25 0 9 0 4749098 420642816 26874 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25239] ppid=25229 vsize=410784 CPUtime=0
/proc/25230/task/25239/stat : 25239 (java) S 25229 25229 1511 34817 1511 4202560 0 0 0 0 0 0 0 0 15 0 9 0 4749098 420642816 26874 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.51
Current children cumulated vsize (KiB) 413352

[startup+3.11611 s]
/proc/loadavg: 1.31 1.22 1.13 2/44 25239
/proc/meminfo: memFree=227384/1048576 swapFree=0/0
[pid=25229] ppid=25228 vsize=2568 CPUtime=0
/proc/25229/stat : 25229 (gj-trendy-solve) S 25228 25229 1511 34817 1511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 4749095 2629632 269 1283457024 134512640 135304128 4286859824 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25229/statm: 642 269 229 194 0 29 0
[pid=25230] ppid=25229 vsize=410916 CPUtime=3.12
/proc/25230/stat : 25230 (java) S 25229 25229 1511 34817 1511 4202496 48217 0 1 0 296 16 0 0 25 0 9 0 4749095 420777984 47460 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/25230/statm: 102729 47460 2896 10 0 96877 0
[pid=25230/tid=25231] ppid=25229 vsize=410916 CPUtime=1.39
/proc/25230/task/25231/stat : 25231 (java) R 25229 25229 1511 34817 1511 4202560 13930 0 1 0 131 8 0 0 25 0 9 0 4749096 420777984 47460 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=25230/tid=25233] ppid=25229 vsize=410916 CPUtime=1.66
/proc/25230/task/25233/stat : 25233 (java) R 25229 25229 1511 34817 1511 4202560 32905 0 0 0 160 6 0 0 15 0 9 0 4749096 420777984 47460 1283457024 134512640 134550932 4293898256 18446744073709551615 4150835128 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=25230/tid=25234] ppid=25229 vsize=410916 CPUtime=0
/proc/25230/task/25234/stat : 25234 (java) S 25229 25229 1511 34817 1511 4202560 15 0 0 0 0 0 0 0 21 0 9 0 4749097 420777984 47460 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25235] ppid=25229 vsize=410916 CPUtime=0
/proc/25230/task/25235/stat : 25235 (java) S 25229 25229 1511 34817 1511 4202560 5 0 0 0 0 0 0 0 21 0 9 0 4749097 420777984 47460 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25236] ppid=25229 vsize=410916 CPUtime=0
/proc/25230/task/25236/stat : 25236 (java) S 25229 25229 1511 34817 1511 4202560 1 0 0 0 0 0 0 0 25 0 9 0 4749098 420777984 47460 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25237] ppid=25229 vsize=410916 CPUtime=0.04
/proc/25230/task/25237/stat : 25237 (java) S 25229 25229 1511 34817 1511 4202560 441 0 0 0 4 0 0 0 16 0 9 0 4749098 420777984 47460 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25238] ppid=25229 vsize=410916 CPUtime=0
/proc/25230/task/25238/stat : 25238 (java) S 25229 25229 1511 34817 1511 4202560 1 0 0 0 0 0 0 0 25 0 9 0 4749098 420777984 47460 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25239] ppid=25229 vsize=410916 CPUtime=0
/proc/25230/task/25239/stat : 25239 (java) S 25229 25229 1511 34817 1511 4202560 0 0 0 0 0 0 0 0 15 0 9 0 4749098 420777984 47460 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.12
Current children cumulated vsize (KiB) 413484

[startup+6.31 s]
/proc/loadavg: 1.31 1.22 1.13 2/44 25239
/proc/meminfo: memFree=90124/1048576 swapFree=0/0
[pid=25229] ppid=25228 vsize=2568 CPUtime=0
/proc/25229/stat : 25229 (gj-trendy-solve) S 25228 25229 1511 34817 1511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 4749095 2629632 269 1283457024 134512640 135304128 4286859824 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25229/statm: 642 269 229 194 0 29 0
[pid=25230] ppid=25229 vsize=411252 CPUtime=6.27
/proc/25230/stat : 25230 (java) S 25229 25229 1511 34817 1511 4202496 70792 0 1 0 605 22 0 0 25 0 10 0 4749095 421122048 69944 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/25230/statm: 102813 69944 2913 10 0 96958 0
[pid=25230/tid=25231] ppid=25229 vsize=411252 CPUtime=3.04
/proc/25230/task/25231/stat : 25231 (java) R 25229 25229 1511 34817 1511 4202560 15300 0 1 0 296 8 0 0 25 0 10 0 4749096 421122048 69944 1283457024 134512640 134550932 4293898256 18446744073709551615 4115053106 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=25230/tid=25233] ppid=25229 vsize=411252 CPUtime=3.09
/proc/25230/task/25233/stat : 25233 (java) S 25229 25229 1511 34817 1511 4202560 54011 0 0 0 296 13 0 0 16 0 10 0 4749096 421122048 69944 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 0 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25234] ppid=25229 vsize=411252 CPUtime=0
/proc/25230/task/25234/stat : 25234 (java) S 25229 25229 1511 34817 1511 4202560 15 0 0 0 0 0 0 0 15 0 10 0 4749097 421122048 69944 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25235] ppid=25229 vsize=411252 CPUtime=0
/proc/25230/task/25235/stat : 25235 (java) S 25229 25229 1511 34817 1511 4202560 5 0 0 0 0 0 0 0 18 0 10 0 4749097 421122048 69944 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25236] ppid=25229 vsize=411252 CPUtime=0
/proc/25230/task/25236/stat : 25236 (java) S 25229 25229 1511 34817 1511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 4749098 421122048 69944 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25237] ppid=25229 vsize=411252 CPUtime=0.12
/proc/25230/task/25237/stat : 25237 (java) S 25229 25229 1511 34817 1511 4202560 535 0 0 0 12 0 0 0 15 0 10 0 4749098 421122048 69944 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25238] ppid=25229 vsize=411252 CPUtime=0
/proc/25230/task/25238/stat : 25238 (java) S 25229 25229 1511 34817 1511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 4749098 421122048 69944 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25239] ppid=25229 vsize=411252 CPUtime=0
/proc/25230/task/25239/stat : 25239 (java) S 25229 25229 1511 34817 1511 4202560 0 0 0 0 0 0 0 0 15 0 10 0 4749098 421122048 69944 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.27
Current children cumulated vsize (KiB) 413820

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

[startup+6.41003 s]
/proc/loadavg: 1.31 1.22 1.13 2/44 25239
/proc/meminfo: memFree=90124/1048576 swapFree=0/0
[pid=25229] ppid=25228 vsize=2568 CPUtime=0
/proc/25229/stat : 25229 (gj-trendy-solve) S 25228 25229 1511 34817 1511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 4749095 2629632 269 1283457024 134512640 135304128 4286859824 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25229/statm: 642 269 229 194 0 29 0
[pid=25230] ppid=25229 vsize=411252 CPUtime=6.37
/proc/25230/stat : 25230 (java) S 25229 25229 1511 34817 1511 4202496 70794 0 1 0 615 22 0 0 25 0 10 0 4749095 421122048 69946 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/25230/statm: 102813 69946 2913 10 0 96958 0
[pid=25230/tid=25231] ppid=25229 vsize=411252 CPUtime=3.14
/proc/25230/task/25231/stat : 25231 (java) R 25229 25229 1511 34817 1511 4202560 15300 0 1 0 306 8 0 0 25 0 10 0 4749096 421122048 69946 1283457024 134512640 134550932 4293898256 18446744073709551615 4115457648 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=25230/tid=25233] ppid=25229 vsize=411252 CPUtime=3.09
/proc/25230/task/25233/stat : 25233 (java) S 25229 25229 1511 34817 1511 4202560 54011 0 0 0 296 13 0 0 16 0 10 0 4749096 421122048 69946 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 0 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25234] ppid=25229 vsize=411252 CPUtime=0
/proc/25230/task/25234/stat : 25234 (java) S 25229 25229 1511 34817 1511 4202560 15 0 0 0 0 0 0 0 15 0 10 0 4749097 421122048 69946 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25235] ppid=25229 vsize=411252 CPUtime=0
/proc/25230/task/25235/stat : 25235 (java) S 25229 25229 1511 34817 1511 4202560 5 0 0 0 0 0 0 0 18 0 10 0 4749097 421122048 69946 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25236] ppid=25229 vsize=411252 CPUtime=0
/proc/25230/task/25236/stat : 25236 (java) S 25229 25229 1511 34817 1511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 4749098 421122048 69946 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25237] ppid=25229 vsize=411252 CPUtime=0.12
/proc/25230/task/25237/stat : 25237 (java) S 25229 25229 1511 34817 1511 4202560 537 0 0 0 12 0 0 0 15 0 10 0 4749098 421122048 69946 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25238] ppid=25229 vsize=411252 CPUtime=0
/proc/25230/task/25238/stat : 25238 (java) S 25229 25229 1511 34817 1511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 4749098 421122048 69946 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25239] ppid=25229 vsize=411252 CPUtime=0
/proc/25230/task/25239/stat : 25239 (java) S 25229 25229 1511 34817 1511 4202560 0 0 0 0 0 0 0 0 15 0 10 0 4749098 421122048 69946 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.37
Current children cumulated vsize (KiB) 413820

[startup+8.01024 s]
/proc/loadavg: 1.28 1.21 1.13 3/45 25240
/proc/meminfo: memFree=89752/1048576 swapFree=0/0
[pid=25229] ppid=25228 vsize=2568 CPUtime=0
/proc/25229/stat : 25229 (gj-trendy-solve) S 25228 25229 1511 34817 1511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 4749095 2629632 269 1283457024 134512640 135304128 4286859824 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25229/statm: 642 269 229 194 0 29 0
[pid=25230] ppid=25229 vsize=411252 CPUtime=7.97
/proc/25230/stat : 25230 (java) S 25229 25229 1511 34817 1511 4202496 70802 0 1 0 775 22 0 0 25 0 10 0 4749095 421122048 69954 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/25230/statm: 102813 69954 2913 10 0 96958 0
[pid=25230/tid=25231] ppid=25229 vsize=411252 CPUtime=4.72
/proc/25230/task/25231/stat : 25231 (java) R 25229 25229 1511 34817 1511 4202560 15300 0 1 0 464 8 0 0 25 0 10 0 4749096 421122048 69954 1283457024 134512640 134550932 4293898256 18446744073709551615 4115429306 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=25230/tid=25233] ppid=25229 vsize=411252 CPUtime=3.09
/proc/25230/task/25233/stat : 25233 (java) S 25229 25229 1511 34817 1511 4202560 54011 0 0 0 296 13 0 0 16 0 10 0 4749096 421122048 69954 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 0 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25234] ppid=25229 vsize=411252 CPUtime=0
/proc/25230/task/25234/stat : 25234 (java) S 25229 25229 1511 34817 1511 4202560 15 0 0 0 0 0 0 0 15 0 10 0 4749097 421122048 69954 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25235] ppid=25229 vsize=411252 CPUtime=0
/proc/25230/task/25235/stat : 25235 (java) S 25229 25229 1511 34817 1511 4202560 5 0 0 0 0 0 0 0 18 0 10 0 4749097 421122048 69954 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25236] ppid=25229 vsize=411252 CPUtime=0
/proc/25230/task/25236/stat : 25236 (java) S 25229 25229 1511 34817 1511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 4749098 421122048 69954 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25237] ppid=25229 vsize=411252 CPUtime=0.14
/proc/25230/task/25237/stat : 25237 (java) S 25229 25229 1511 34817 1511 4202560 545 0 0 0 14 0 0 0 15 0 10 0 4749098 421122048 69954 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25238] ppid=25229 vsize=411252 CPUtime=0
/proc/25230/task/25238/stat : 25238 (java) S 25229 25229 1511 34817 1511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 4749098 421122048 69954 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25239] ppid=25229 vsize=411252 CPUtime=0
/proc/25230/task/25239/stat : 25239 (java) R 25229 25229 1511 34817 1511 4202560 0 0 0 0 0 0 0 0 15 0 10 0 4749098 421122048 69954 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=25230/tid=25240] ppid=25229 vsize=411252 CPUtime=0
/proc/25230/task/25240/stat : 25240 (java) S 25229 25229 1511 34817 1511 4202560 5 0 0 0 0 0 0 0 25 0 10 0 4749652 421122048 69954 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 7.97
Current children cumulated vsize (KiB) 413820

[startup+8.81063 s]
/proc/loadavg: 1.28 1.21 1.13 2/45 25240
/proc/meminfo: memFree=87644/1048576 swapFree=0/0
[pid=25229] ppid=25228 vsize=2568 CPUtime=0
/proc/25229/stat : 25229 (gj-trendy-solve) S 25228 25229 1511 34817 1511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 4749095 2629632 269 1283457024 134512640 135304128 4286859824 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25229/statm: 642 269 229 194 0 29 0
[pid=25230] ppid=25229 vsize=411252 CPUtime=8.77
/proc/25230/stat : 25230 (java) S 25229 25229 1511 34817 1511 4202496 71334 0 1 0 855 22 0 0 25 0 10 0 4749095 421122048 70486 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/25230/statm: 102813 70486 2916 10 0 96958 0
[pid=25230/tid=25231] ppid=25229 vsize=411252 CPUtime=5.47
/proc/25230/task/25231/stat : 25231 (java) R 25229 25229 1511 34817 1511 4202560 15301 0 1 0 539 8 0 0 25 0 10 0 4749096 421122048 70486 1283457024 134512640 134550932 4293898256 18446744073709551615 4115112364 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=25230/tid=25233] ppid=25229 vsize=411252 CPUtime=3.15
/proc/25230/task/25233/stat : 25233 (java) S 25229 25229 1511 34817 1511 4202560 54541 0 0 0 302 13 0 0 16 0 10 0 4749096 421122048 70486 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 0 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25234] ppid=25229 vsize=411252 CPUtime=0
/proc/25230/task/25234/stat : 25234 (java) S 25229 25229 1511 34817 1511 4202560 15 0 0 0 0 0 0 0 15 0 10 0 4749097 421122048 70486 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25235] ppid=25229 vsize=411252 CPUtime=0
/proc/25230/task/25235/stat : 25235 (java) S 25229 25229 1511 34817 1511 4202560 5 0 0 0 0 0 0 0 18 0 10 0 4749097 421122048 70486 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25236] ppid=25229 vsize=411252 CPUtime=0
/proc/25230/task/25236/stat : 25236 (java) S 25229 25229 1511 34817 1511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 4749098 421122048 70486 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25237] ppid=25229 vsize=411252 CPUtime=0.14
/proc/25230/task/25237/stat : 25237 (java) S 25229 25229 1511 34817 1511 4202560 546 0 0 0 14 0 0 0 15 0 10 0 4749098 421122048 70486 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25238] ppid=25229 vsize=411252 CPUtime=0
/proc/25230/task/25238/stat : 25238 (java) S 25229 25229 1511 34817 1511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 4749098 421122048 70486 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25239] ppid=25229 vsize=411252 CPUtime=0
/proc/25230/task/25239/stat : 25239 (java) S 25229 25229 1511 34817 1511 4202560 0 0 0 0 0 0 0 0 15 0 10 0 4749098 421122048 70486 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25240] ppid=25229 vsize=411252 CPUtime=0
/proc/25230/task/25240/stat : 25240 (java) S 25229 25229 1511 34817 1511 4202560 5 0 0 0 0 0 0 0 25 0 10 0 4749652 421122048 70486 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 8.77
Current children cumulated vsize (KiB) 413820

[startup+9.21076 s]
/proc/loadavg: 1.28 1.21 1.13 2/45 25240
/proc/meminfo: memFree=87644/1048576 swapFree=0/0
[pid=25229] ppid=25228 vsize=2568 CPUtime=0
/proc/25229/stat : 25229 (gj-trendy-solve) S 25228 25229 1511 34817 1511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 4749095 2629632 269 1283457024 134512640 135304128 4286859824 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25229/statm: 642 269 229 194 0 29 0
[pid=25230] ppid=25229 vsize=411252 CPUtime=9.17
/proc/25230/stat : 25230 (java) S 25229 25229 1511 34817 1511 4202496 71335 0 1 0 895 22 0 0 25 0 10 0 4749095 421122048 70487 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/25230/statm: 102813 70487 2916 10 0 96958 0
[pid=25230/tid=25231] ppid=25229 vsize=411252 CPUtime=5.87
/proc/25230/task/25231/stat : 25231 (java) R 25229 25229 1511 34817 1511 4202560 15301 0 1 0 579 8 0 0 25 0 10 0 4749096 421122048 70487 1283457024 134512640 134550932 4293898256 18446744073709551615 4115551365 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=25230/tid=25233] ppid=25229 vsize=411252 CPUtime=3.15
/proc/25230/task/25233/stat : 25233 (java) S 25229 25229 1511 34817 1511 4202560 54541 0 0 0 302 13 0 0 16 0 10 0 4749096 421122048 70487 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 0 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25234] ppid=25229 vsize=411252 CPUtime=0
/proc/25230/task/25234/stat : 25234 (java) S 25229 25229 1511 34817 1511 4202560 15 0 0 0 0 0 0 0 15 0 10 0 4749097 421122048 70487 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25235] ppid=25229 vsize=411252 CPUtime=0
/proc/25230/task/25235/stat : 25235 (java) S 25229 25229 1511 34817 1511 4202560 5 0 0 0 0 0 0 0 18 0 10 0 4749097 421122048 70487 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25236] ppid=25229 vsize=411252 CPUtime=0
/proc/25230/task/25236/stat : 25236 (java) S 25229 25229 1511 34817 1511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 4749098 421122048 70487 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25237] ppid=25229 vsize=411252 CPUtime=0.14
/proc/25230/task/25237/stat : 25237 (java) S 25229 25229 1511 34817 1511 4202560 547 0 0 0 14 0 0 0 15 0 10 0 4749098 421122048 70487 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25238] ppid=25229 vsize=411252 CPUtime=0
/proc/25230/task/25238/stat : 25238 (java) S 25229 25229 1511 34817 1511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 4749098 421122048 70487 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25239] ppid=25229 vsize=411252 CPUtime=0
/proc/25230/task/25239/stat : 25239 (java) R 25229 25229 1511 34817 1511 4202560 0 0 0 0 0 0 0 0 15 0 10 0 4749098 421122048 70487 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=25230/tid=25240] ppid=25229 vsize=411252 CPUtime=0
/proc/25230/task/25240/stat : 25240 (java) S 25229 25229 1511 34817 1511 4202560 5 0 0 0 0 0 0 0 25 0 10 0 4749652 421122048 70487 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 9.17
Current children cumulated vsize (KiB) 413820

[startup+9.41087 s]
/proc/loadavg: 1.28 1.21 1.13 2/45 25240
/proc/meminfo: memFree=87644/1048576 swapFree=0/0
[pid=25229] ppid=25228 vsize=2568 CPUtime=0
/proc/25229/stat : 25229 (gj-trendy-solve) S 25228 25229 1511 34817 1511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 4749095 2629632 269 1283457024 134512640 135304128 4286859824 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25229/statm: 642 269 229 194 0 29 0
[pid=25230] ppid=25229 vsize=411252 CPUtime=9.37
/proc/25230/stat : 25230 (java) S 25229 25229 1511 34817 1511 4202496 71335 0 1 0 915 22 0 0 25 0 10 0 4749095 421122048 70487 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/25230/statm: 102813 70487 2916 10 0 96958 0
[pid=25230/tid=25231] ppid=25229 vsize=411252 CPUtime=6.07
/proc/25230/task/25231/stat : 25231 (java) R 25229 25229 1511 34817 1511 4202560 15301 0 1 0 599 8 0 0 25 0 10 0 4749096 421122048 70487 1283457024 134512640 134550932 4293898256 18446744073709551615 4115435997 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=25230/tid=25233] ppid=25229 vsize=411252 CPUtime=3.15
/proc/25230/task/25233/stat : 25233 (java) S 25229 25229 1511 34817 1511 4202560 54541 0 0 0 302 13 0 0 16 0 10 0 4749096 421122048 70487 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 0 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25234] ppid=25229 vsize=411252 CPUtime=0
/proc/25230/task/25234/stat : 25234 (java) S 25229 25229 1511 34817 1511 4202560 15 0 0 0 0 0 0 0 15 0 10 0 4749097 421122048 70487 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25235] ppid=25229 vsize=411252 CPUtime=0
/proc/25230/task/25235/stat : 25235 (java) S 25229 25229 1511 34817 1511 4202560 5 0 0 0 0 0 0 0 18 0 10 0 4749097 421122048 70487 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25236] ppid=25229 vsize=411252 CPUtime=0
/proc/25230/task/25236/stat : 25236 (java) S 25229 25229 1511 34817 1511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 4749098 421122048 70487 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25237] ppid=25229 vsize=411252 CPUtime=0.14
/proc/25230/task/25237/stat : 25237 (java) S 25229 25229 1511 34817 1511 4202560 547 0 0 0 14 0 0 0 15 0 10 0 4749098 421122048 70487 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25238] ppid=25229 vsize=411252 CPUtime=0
/proc/25230/task/25238/stat : 25238 (java) S 25229 25229 1511 34817 1511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 4749098 421122048 70487 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25239] ppid=25229 vsize=411252 CPUtime=0
/proc/25230/task/25239/stat : 25239 (java) S 25229 25229 1511 34817 1511 4202560 0 0 0 0 0 0 0 0 15 0 10 0 4749098 421122048 70487 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
[pid=25230/tid=25240] ppid=25229 vsize=411252 CPUtime=0
/proc/25230/task/25240/stat : 25240 (java) S 25229 25229 1511 34817 1511 4202560 5 0 0 0 0 0 0 0 25 0 10 0 4749652 421122048 70487 1283457024 134512640 134550932 4293898256 18446744073709551615 4294960130 0 4 0 16800975 18446612132974981184 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 9.37
Current children cumulated vsize (KiB) 413820

Child status: 0
Real time (s): 9.46754
CPU time (s): 9.42059
CPU user time (s): 9.17657
CPU system time (s): 0.244015
CPU usage (%): 99.5041
Max. virtual memory (cumulated for all children) (KiB): 413820

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 9.17657
system time used= 0.244015
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 71724
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= 914
involuntary context switches= 1036

runsolver used 0 second user time and 0 second system time

The end