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/26f3d4cc-d470-11df-9e6c-00163e3d3b7c.cudf.dudf-real.log.runsolver ./gj-trendy-solver-1.0 /home/misc2010/data/2011/dudf-real//26f3d4cc-d470-11df-9e6c-00163e3d3b7c.cudf /home/misc2010/tmp/201108241238/gj-trendy-solver-1.0/26f3d4cc-d470-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.25 1.17 1.06 5/35 9398
/proc/meminfo: memFree=443128/1048576 swapFree=0/0
[pid=9396] ppid=9395 vsize=2572 CPUtime=0
/proc/9396/stat : 9396 (gj-trendy-solve) S 9395 9396 1511 34817 1511 4202496 373 0 0 0 0 0 0 0 18 0 1 0 2149721 2633728 270 1283457024 134512640 135304128 4290586048 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9396/statm: 643 270 229 194 0 30 0
[pid=9397] ppid=9396 vsize=11360 CPUtime=0
/proc/9397/stat : 9397 (java) R 9396 9396 1511 34817 1511 4202496 918 0 0 0 0 0 0 0 25 0 2 0 2149721 11632640 651 1283457024 134512640 134550932 4290489552 18446744073709551615 4158967400 0 0 0 0 18446744073709551615 0 0 17 0 0 0 0
/proc/9397/statm: 2840 651 285 10 0 1186 0
[pid=9397/tid=9398] ppid=9396 vsize=11360 CPUtime=0
/proc/9397/task/9398/stat : 9398 (java) R 9396 9396 1511 34817 1511 4202560 0 0 0 0 0 0 0 0 25 0 2 0 2149721 11632640 651 1283457024 134512640 134550932 4290489552 18446744073709551615 4158967400 0 0 0 0 0 0 0 -1 0 0 0 0

[startup+0.199773 s]
/proc/loadavg: 1.25 1.17 1.06 5/35 9398
/proc/meminfo: memFree=443128/1048576 swapFree=0/0
[pid=9396] ppid=9395 vsize=2572 CPUtime=0
/proc/9396/stat : 9396 (gj-trendy-solve) S 9395 9396 1511 34817 1511 4202496 373 0 0 0 0 0 0 0 18 0 1 0 2149721 2633728 270 1283457024 134512640 135304128 4290586048 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9396/statm: 643 270 229 194 0 30 0
[pid=9397] ppid=9396 vsize=410232 CPUtime=0.19
/proc/9397/stat : 9397 (java) S 9396 9396 1511 34817 1511 4202496 4428 0 1 0 17 2 0 0 25 0 9 0 2149721 420077568 3855 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9397/statm: 102558 3855 1944 10 0 96706 0
[pid=9397/tid=9398] ppid=9396 vsize=410232 CPUtime=0.18
/proc/9397/task/9398/stat : 9398 (java) R 9396 9396 1511 34817 1511 4202560 3194 0 1 0 16 2 0 0 25 0 9 0 2149721 420077568 3855 1283457024 134512640 134550932 4290489552 18446744073709551615 4114326887 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 0.19
Current children cumulated vsize (KiB) 412804

[startup+0.209768 s]
/proc/loadavg: 1.25 1.17 1.06 5/35 9398
/proc/meminfo: memFree=443128/1048576 swapFree=0/0
[pid=9396] ppid=9395 vsize=2572 CPUtime=0
/proc/9396/stat : 9396 (gj-trendy-solve) S 9395 9396 1511 34817 1511 4202496 373 0 0 0 0 0 0 0 18 0 1 0 2149721 2633728 270 1283457024 134512640 135304128 4290586048 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9396/statm: 643 270 229 194 0 30 0
[pid=9397] ppid=9396 vsize=410232 CPUtime=0.2
/proc/9397/stat : 9397 (java) S 9396 9396 1511 34817 1511 4202496 4469 0 1 0 18 2 0 0 25 0 9 0 2149721 420077568 3896 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9397/statm: 102558 3896 1944 10 0 96706 0
[pid=9397/tid=9398] ppid=9396 vsize=410232 CPUtime=0.19
/proc/9397/task/9398/stat : 9398 (java) R 9396 9396 1511 34817 1511 4202560 3235 0 1 0 17 2 0 0 25 0 9 0 2149721 420077568 3896 1283457024 134512640 134550932 4290489552 18446744073709551615 4114325508 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 0.2
Current children cumulated vsize (KiB) 412804

[startup+0.309809 s]
/proc/loadavg: 1.25 1.17 1.06 5/35 9398
/proc/meminfo: memFree=443128/1048576 swapFree=0/0
[pid=9396] ppid=9395 vsize=2572 CPUtime=0
/proc/9396/stat : 9396 (gj-trendy-solve) S 9395 9396 1511 34817 1511 4202496 373 0 0 0 0 0 0 0 18 0 1 0 2149721 2633728 270 1283457024 134512640 135304128 4290586048 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9396/statm: 643 270 229 194 0 30 0
[pid=9397] ppid=9396 vsize=410388 CPUtime=0.3
/proc/9397/stat : 9397 (java) S 9396 9396 1511 34817 1511 4202496 5394 0 1 0 28 2 0 0 25 0 9 0 2149721 420237312 4821 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9397/statm: 102597 4821 1952 10 0 96745 0
[pid=9397/tid=9398] ppid=9396 vsize=410388 CPUtime=0.26
/proc/9397/task/9398/stat : 9398 (java) R 9396 9396 1511 34817 1511 4202560 3530 0 1 0 24 2 0 0 25 0 9 0 2149721 420237312 4821 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 0.3
Current children cumulated vsize (KiB) 412960

[startup+0.709955 s]
/proc/loadavg: 1.25 1.17 1.06 5/35 9398
/proc/meminfo: memFree=443128/1048576 swapFree=0/0
[pid=9396] ppid=9395 vsize=2572 CPUtime=0
/proc/9396/stat : 9396 (gj-trendy-solve) S 9395 9396 1511 34817 1511 4202496 373 0 0 0 0 0 0 0 18 0 1 0 2149721 2633728 270 1283457024 134512640 135304128 4290586048 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9396/statm: 643 270 229 194 0 30 0
[pid=9397] ppid=9396 vsize=410688 CPUtime=0.7
/proc/9397/stat : 9397 (java) S 9396 9396 1511 34817 1511 4202496 12897 0 1 0 68 2 0 0 25 0 9 0 2149721 420544512 12137 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9397/statm: 102672 12137 2901 10 0 96820 0
[pid=9397/tid=9398] ppid=9396 vsize=410688 CPUtime=0.46
/proc/9397/task/9398/stat : 9398 (java) R 9396 9396 1511 34817 1511 4202560 4220 0 1 0 44 2 0 0 25 0 9 0 2149721 420544512 12137 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 0.7
Current children cumulated vsize (KiB) 413260

[startup+1.51022 s]
/proc/loadavg: 1.25 1.17 1.06 2/43 9406
/proc/meminfo: memFree=384836/1048576 swapFree=0/0
[pid=9396] ppid=9395 vsize=2572 CPUtime=0
/proc/9396/stat : 9396 (gj-trendy-solve) S 9395 9396 1511 34817 1511 4202496 373 0 0 0 0 0 0 0 18 0 1 0 2149721 2633728 270 1283457024 134512640 135304128 4290586048 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9396/statm: 643 270 229 194 0 30 0
[pid=9397] ppid=9396 vsize=410688 CPUtime=1.5
/proc/9397/stat : 9397 (java) S 9396 9396 1511 34817 1511 4202496 28029 0 1 0 143 7 0 0 25 0 9 0 2149721 420544512 27269 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9397/statm: 102672 27269 2901 10 0 96820 0
[pid=9397/tid=9398] ppid=9396 vsize=410688 CPUtime=0.79
/proc/9397/task/9398/stat : 9398 (java) S 9396 9396 1511 34817 1511 4202560 6828 0 1 0 77 2 0 0 24 0 9 0 2149721 420544512 27269 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9400] ppid=9396 vsize=410688 CPUtime=0.66
/proc/9397/task/9400/stat : 9400 (java) R 9396 9396 1511 34817 1511 4202560 19821 0 0 0 61 5 0 0 19 0 9 0 2149722 420544512 27269 1283457024 134512640 134550932 4290489552 18446744073709551615 4150951336 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=9397/tid=9401] ppid=9396 vsize=410688 CPUtime=0
/proc/9397/task/9401/stat : 9401 (java) S 9396 9396 1511 34817 1511 4202560 15 0 0 0 0 0 0 0 20 0 9 0 2149722 420544512 27269 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9402] ppid=9396 vsize=410688 CPUtime=0
/proc/9397/task/9402/stat : 9402 (java) S 9396 9396 1511 34817 1511 4202560 5 0 0 0 0 0 0 0 20 0 9 0 2149722 420544512 27269 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9403] ppid=9396 vsize=410688 CPUtime=0
/proc/9397/task/9403/stat : 9403 (java) S 9396 9396 1511 34817 1511 4202560 1 0 0 0 0 0 0 0 25 0 9 0 2149724 420544512 27269 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9404] ppid=9396 vsize=410688 CPUtime=0.04
/proc/9397/task/9404/stat : 9404 (java) S 9396 9396 1511 34817 1511 4202560 439 0 0 0 4 0 0 0 17 0 9 0 2149724 420544512 27269 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9405] ppid=9396 vsize=410688 CPUtime=0
/proc/9397/task/9405/stat : 9405 (java) S 9396 9396 1511 34817 1511 4202560 0 0 0 0 0 0 0 0 25 0 9 0 2149724 420544512 27269 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9406] ppid=9396 vsize=410688 CPUtime=0
/proc/9397/task/9406/stat : 9406 (java) R 9396 9396 1511 34817 1511 4202560 2 0 0 0 0 0 0 0 15 0 9 0 2149724 420544512 27269 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.5
Current children cumulated vsize (KiB) 413260

[startup+3.13074 s]
/proc/loadavg: 1.25 1.17 1.06 3/43 9406
/proc/meminfo: memFree=310188/1048576 swapFree=0/0
[pid=9396] ppid=9395 vsize=2572 CPUtime=0
/proc/9396/stat : 9396 (gj-trendy-solve) S 9395 9396 1511 34817 1511 4202496 373 0 0 0 0 0 0 0 18 0 1 0 2149721 2633728 270 1283457024 134512640 135304128 4290586048 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9396/statm: 643 270 229 194 0 30 0
[pid=9397] ppid=9396 vsize=410820 CPUtime=3.12
/proc/9397/stat : 9397 (java) S 9396 9396 1511 34817 1511 4202496 49251 0 1 0 299 13 0 0 25 0 9 0 2149721 420679680 48485 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9397/statm: 102705 48485 2903 10 0 96853 0
[pid=9397/tid=9398] ppid=9396 vsize=410820 CPUtime=1.47
/proc/9397/task/9398/stat : 9398 (java) R 9396 9396 1511 34817 1511 4202560 14302 0 1 0 141 6 0 0 25 0 9 0 2149721 420679680 48485 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=9397/tid=9400] ppid=9396 vsize=410820 CPUtime=1.58
/proc/9397/task/9400/stat : 9400 (java) R 9396 9396 1511 34817 1511 4202560 33546 0 0 0 152 6 0 0 15 0 9 0 2149722 420679680 48485 1283457024 134512640 134550932 4290489552 18446744073709551615 4150952269 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=9397/tid=9401] ppid=9396 vsize=410820 CPUtime=0
/proc/9397/task/9401/stat : 9401 (java) S 9396 9396 1511 34817 1511 4202560 15 0 0 0 0 0 0 0 20 0 9 0 2149722 420679680 48485 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9402] ppid=9396 vsize=410820 CPUtime=0
/proc/9397/task/9402/stat : 9402 (java) S 9396 9396 1511 34817 1511 4202560 5 0 0 0 0 0 0 0 20 0 9 0 2149722 420679680 48485 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9403] ppid=9396 vsize=410820 CPUtime=0
/proc/9397/task/9403/stat : 9403 (java) S 9396 9396 1511 34817 1511 4202560 1 0 0 0 0 0 0 0 25 0 9 0 2149724 420679680 48485 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9404] ppid=9396 vsize=410820 CPUtime=0.05
/proc/9397/task/9404/stat : 9404 (java) S 9396 9396 1511 34817 1511 4202560 462 0 0 0 5 0 0 0 15 0 9 0 2149724 420679680 48485 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9405] ppid=9396 vsize=410820 CPUtime=0
/proc/9397/task/9405/stat : 9405 (java) S 9396 9396 1511 34817 1511 4202560 0 0 0 0 0 0 0 0 25 0 9 0 2149724 420679680 48485 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9406] ppid=9396 vsize=410820 CPUtime=0
/proc/9397/task/9406/stat : 9406 (java) R 9396 9396 1511 34817 1511 4202560 2 0 0 0 0 0 0 0 15 0 9 0 2149724 420679680 48485 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.12
Current children cumulated vsize (KiB) 413392

[startup+6.30203 s]
/proc/loadavg: 1.23 1.17 1.06 2/44 9407
/proc/meminfo: memFree=197960/1048576 swapFree=0/0
[pid=9396] ppid=9395 vsize=2572 CPUtime=0
/proc/9396/stat : 9396 (gj-trendy-solve) S 9395 9396 1511 34817 1511 4202496 373 0 0 0 0 0 0 0 18 0 1 0 2149721 2633728 270 1283457024 134512640 135304128 4290586048 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9396/statm: 643 270 229 194 0 30 0
[pid=9397] ppid=9396 vsize=411420 CPUtime=6.29
/proc/9397/stat : 9397 (java) S 9396 9396 1511 34817 1511 4202496 66495 0 1 0 609 20 0 0 25 0 10 0 2149721 421294080 65641 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9397/statm: 102855 65641 2920 10 0 97000 0
[pid=9397/tid=9398] ppid=9396 vsize=411420 CPUtime=3.83
/proc/9397/task/9398/stat : 9398 (java) R 9396 9396 1511 34817 1511 4202560 14556 0 1 0 376 7 0 0 25 0 10 0 2149721 421294080 65641 1283457024 134512640 134550932 4290489552 18446744073709551615 4115131504 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=9397/tid=9400] ppid=9396 vsize=411420 CPUtime=2.37
/proc/9397/task/9400/stat : 9400 (java) S 9396 9396 1511 34817 1511 4202560 50449 0 0 0 225 12 0 0 16 0 10 0 2149722 421294080 65641 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 0 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9401] ppid=9396 vsize=411420 CPUtime=0
/proc/9397/task/9401/stat : 9401 (java) S 9396 9396 1511 34817 1511 4202560 15 0 0 0 0 0 0 0 18 0 10 0 2149722 421294080 65641 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9402] ppid=9396 vsize=411420 CPUtime=0
/proc/9397/task/9402/stat : 9402 (java) S 9396 9396 1511 34817 1511 4202560 5 0 0 0 0 0 0 0 18 0 10 0 2149722 421294080 65641 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9403] ppid=9396 vsize=411420 CPUtime=0
/proc/9397/task/9403/stat : 9403 (java) S 9396 9396 1511 34817 1511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 2149724 421294080 65641 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9404] ppid=9396 vsize=411420 CPUtime=0.07
/proc/9397/task/9404/stat : 9404 (java) S 9396 9396 1511 34817 1511 4202560 545 0 0 0 7 0 0 0 15 0 10 0 2149724 421294080 65641 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9405] ppid=9396 vsize=411420 CPUtime=0
/proc/9397/task/9405/stat : 9405 (java) S 9396 9396 1511 34817 1511 4202560 0 0 0 0 0 0 0 0 25 0 10 0 2149724 421294080 65641 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9406] ppid=9396 vsize=411420 CPUtime=0
/proc/9397/task/9406/stat : 9406 (java) S 9396 9396 1511 34817 1511 4202560 2 0 0 0 0 0 0 0 15 0 10 0 2149724 421294080 65641 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9407] ppid=9396 vsize=411420 CPUtime=0
/proc/9397/task/9407/stat : 9407 (java) S 9396 9396 1511 34817 1511 4202560 4 0 0 0 0 0 0 0 25 0 10 0 2150142 421294080 65641 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.29
Current children cumulated vsize (KiB) 413992

[startup+12.7144 s]
/proc/loadavg: 1.21 1.16 1.06 2/44 9407
/proc/meminfo: memFree=192636/1048576 swapFree=0/0
[pid=9396] ppid=9395 vsize=2572 CPUtime=0
/proc/9396/stat : 9396 (gj-trendy-solve) S 9395 9396 1511 34817 1511 4202496 373 0 0 0 0 0 0 0 18 0 1 0 2149721 2633728 270 1283457024 134512640 135304128 4290586048 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9396/statm: 643 270 229 194 0 30 0
[pid=9397] ppid=9396 vsize=411420 CPUtime=12.69
/proc/9397/stat : 9397 (java) S 9396 9396 1511 34817 1511 4202496 66505 0 1 0 1249 20 0 0 25 0 10 0 2149721 421294080 65651 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9397/statm: 102855 65651 2920 10 0 97000 0
[pid=9397/tid=9398] ppid=9396 vsize=411420 CPUtime=10.15
/proc/9397/task/9398/stat : 9398 (java) R 9396 9396 1511 34817 1511 4202560 14557 0 1 0 1008 7 0 0 25 0 10 0 2149721 421294080 65651 1283457024 134512640 134550932 4290489552 18446744073709551615 4115164180 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=9397/tid=9400] ppid=9396 vsize=411420 CPUtime=2.44
/proc/9397/task/9400/stat : 9400 (java) S 9396 9396 1511 34817 1511 4202560 50449 0 0 0 232 12 0 0 15 0 10 0 2149722 421294080 65651 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 0 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9401] ppid=9396 vsize=411420 CPUtime=0
/proc/9397/task/9401/stat : 9401 (java) S 9396 9396 1511 34817 1511 4202560 15 0 0 0 0 0 0 0 18 0 10 0 2149722 421294080 65651 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9402] ppid=9396 vsize=411420 CPUtime=0
/proc/9397/task/9402/stat : 9402 (java) S 9396 9396 1511 34817 1511 4202560 5 0 0 0 0 0 0 0 18 0 10 0 2149722 421294080 65651 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9403] ppid=9396 vsize=411420 CPUtime=0
/proc/9397/task/9403/stat : 9403 (java) S 9396 9396 1511 34817 1511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 2149724 421294080 65651 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9404] ppid=9396 vsize=411420 CPUtime=0.09
/proc/9397/task/9404/stat : 9404 (java) S 9396 9396 1511 34817 1511 4202560 554 0 0 0 9 0 0 0 15 0 10 0 2149724 421294080 65651 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9405] ppid=9396 vsize=411420 CPUtime=0
/proc/9397/task/9405/stat : 9405 (java) S 9396 9396 1511 34817 1511 4202560 0 0 0 0 0 0 0 0 25 0 10 0 2149724 421294080 65651 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9406] ppid=9396 vsize=411420 CPUtime=0
/proc/9397/task/9406/stat : 9406 (java) R 9396 9396 1511 34817 1511 4202560 2 0 0 0 0 0 0 0 15 0 10 0 2149724 421294080 65651 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=9397/tid=9407] ppid=9396 vsize=411420 CPUtime=0
/proc/9397/task/9407/stat : 9407 (java) S 9396 9396 1511 34817 1511 4202560 4 0 0 0 0 0 0 0 25 0 10 0 2150142 421294080 65651 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 12.69
Current children cumulated vsize (KiB) 413992

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

[startup+13.5046 s]
/proc/loadavg: 1.21 1.16 1.06 2/44 9407
/proc/meminfo: memFree=192636/1048576 swapFree=0/0
[pid=9396] ppid=9395 vsize=2572 CPUtime=0
/proc/9396/stat : 9396 (gj-trendy-solve) S 9395 9396 1511 34817 1511 4202496 373 0 0 0 0 0 0 0 18 0 1 0 2149721 2633728 270 1283457024 134512640 135304128 4290586048 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9396/statm: 643 270 229 194 0 30 0
[pid=9397] ppid=9396 vsize=411420 CPUtime=13.48
/proc/9397/stat : 9397 (java) S 9396 9396 1511 34817 1511 4202496 66505 0 1 0 1328 20 0 0 25 0 10 0 2149721 421294080 65651 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9397/statm: 102855 65651 2920 10 0 97000 0
[pid=9397/tid=9398] ppid=9396 vsize=411420 CPUtime=10.93
/proc/9397/task/9398/stat : 9398 (java) R 9396 9396 1511 34817 1511 4202560 14557 0 1 0 1086 7 0 0 25 0 10 0 2149721 421294080 65651 1283457024 134512640 134550932 4290489552 18446744073709551615 4115179040 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=9397/tid=9400] ppid=9396 vsize=411420 CPUtime=2.44
/proc/9397/task/9400/stat : 9400 (java) S 9396 9396 1511 34817 1511 4202560 50449 0 0 0 232 12 0 0 16 0 10 0 2149722 421294080 65651 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 0 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9401] ppid=9396 vsize=411420 CPUtime=0
/proc/9397/task/9401/stat : 9401 (java) S 9396 9396 1511 34817 1511 4202560 15 0 0 0 0 0 0 0 18 0 10 0 2149722 421294080 65651 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9402] ppid=9396 vsize=411420 CPUtime=0
/proc/9397/task/9402/stat : 9402 (java) S 9396 9396 1511 34817 1511 4202560 5 0 0 0 0 0 0 0 18 0 10 0 2149722 421294080 65651 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9403] ppid=9396 vsize=411420 CPUtime=0
/proc/9397/task/9403/stat : 9403 (java) S 9396 9396 1511 34817 1511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 2149724 421294080 65651 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9404] ppid=9396 vsize=411420 CPUtime=0.09
/proc/9397/task/9404/stat : 9404 (java) S 9396 9396 1511 34817 1511 4202560 554 0 0 0 9 0 0 0 15 0 10 0 2149724 421294080 65651 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9405] ppid=9396 vsize=411420 CPUtime=0
/proc/9397/task/9405/stat : 9405 (java) S 9396 9396 1511 34817 1511 4202560 0 0 0 0 0 0 0 0 25 0 10 0 2149724 421294080 65651 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9406] ppid=9396 vsize=411420 CPUtime=0
/proc/9397/task/9406/stat : 9406 (java) S 9396 9396 1511 34817 1511 4202560 2 0 0 0 0 0 0 0 15 0 10 0 2149724 421294080 65651 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9407] ppid=9396 vsize=411420 CPUtime=0
/proc/9397/task/9407/stat : 9407 (java) S 9396 9396 1511 34817 1511 4202560 4 0 0 0 0 0 0 0 25 0 10 0 2150142 421294080 65651 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 13.48
Current children cumulated vsize (KiB) 413992

[startup+13.9047 s]
/proc/loadavg: 1.21 1.16 1.06 2/44 9407
/proc/meminfo: memFree=192636/1048576 swapFree=0/0
[pid=9396] ppid=9395 vsize=2572 CPUtime=0
/proc/9396/stat : 9396 (gj-trendy-solve) S 9395 9396 1511 34817 1511 4202496 373 0 0 0 0 0 0 0 18 0 1 0 2149721 2633728 270 1283457024 134512640 135304128 4290586048 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9396/statm: 643 270 229 194 0 30 0
[pid=9397] ppid=9396 vsize=411420 CPUtime=13.88
/proc/9397/stat : 9397 (java) S 9396 9396 1511 34817 1511 4202496 66505 0 1 0 1368 20 0 0 25 0 10 0 2149721 421294080 65651 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9397/statm: 102855 65651 2920 10 0 97000 0
[pid=9397/tid=9398] ppid=9396 vsize=411420 CPUtime=11.33
/proc/9397/task/9398/stat : 9398 (java) R 9396 9396 1511 34817 1511 4202560 14557 0 1 0 1126 7 0 0 25 0 10 0 2149721 421294080 65651 1283457024 134512640 134550932 4290489552 18446744073709551615 4115312457 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=9397/tid=9400] ppid=9396 vsize=411420 CPUtime=2.44
/proc/9397/task/9400/stat : 9400 (java) S 9396 9396 1511 34817 1511 4202560 50449 0 0 0 232 12 0 0 16 0 10 0 2149722 421294080 65651 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 0 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9401] ppid=9396 vsize=411420 CPUtime=0
/proc/9397/task/9401/stat : 9401 (java) S 9396 9396 1511 34817 1511 4202560 15 0 0 0 0 0 0 0 18 0 10 0 2149722 421294080 65651 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9402] ppid=9396 vsize=411420 CPUtime=0
/proc/9397/task/9402/stat : 9402 (java) S 9396 9396 1511 34817 1511 4202560 5 0 0 0 0 0 0 0 18 0 10 0 2149722 421294080 65651 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9403] ppid=9396 vsize=411420 CPUtime=0
/proc/9397/task/9403/stat : 9403 (java) S 9396 9396 1511 34817 1511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 2149724 421294080 65651 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9404] ppid=9396 vsize=411420 CPUtime=0.09
/proc/9397/task/9404/stat : 9404 (java) S 9396 9396 1511 34817 1511 4202560 554 0 0 0 9 0 0 0 15 0 10 0 2149724 421294080 65651 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9405] ppid=9396 vsize=411420 CPUtime=0
/proc/9397/task/9405/stat : 9405 (java) S 9396 9396 1511 34817 1511 4202560 0 0 0 0 0 0 0 0 25 0 10 0 2149724 421294080 65651 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9406] ppid=9396 vsize=411420 CPUtime=0
/proc/9397/task/9406/stat : 9406 (java) S 9396 9396 1511 34817 1511 4202560 2 0 0 0 0 0 0 0 15 0 10 0 2149724 421294080 65651 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9407] ppid=9396 vsize=411420 CPUtime=0
/proc/9397/task/9407/stat : 9407 (java) S 9396 9396 1511 34817 1511 4202560 4 0 0 0 0 0 0 0 25 0 10 0 2150142 421294080 65651 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 13.88
Current children cumulated vsize (KiB) 413992

[startup+14.3046 s]
/proc/loadavg: 1.20 1.16 1.06 2/44 9407
/proc/meminfo: memFree=192636/1048576 swapFree=0/0
[pid=9396] ppid=9395 vsize=2572 CPUtime=0
/proc/9396/stat : 9396 (gj-trendy-solve) S 9395 9396 1511 34817 1511 4202496 373 0 0 0 0 0 0 0 18 0 1 0 2149721 2633728 270 1283457024 134512640 135304128 4290586048 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9396/statm: 643 270 229 194 0 30 0
[pid=9397] ppid=9396 vsize=411420 CPUtime=14.27
/proc/9397/stat : 9397 (java) S 9396 9396 1511 34817 1511 4202496 66514 0 1 0 1407 20 0 0 25 0 9 0 2149721 421294080 65660 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9397/statm: 102855 65660 2921 10 0 97000 0
[pid=9397/tid=9398] ppid=9396 vsize=411420 CPUtime=11.69
/proc/9397/task/9398/stat : 9398 (java) S 9396 9396 1511 34817 1511 4202560 14557 0 1 0 1162 7 0 0 25 0 9 0 2149721 421294080 65660 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9400] ppid=9396 vsize=411420 CPUtime=2.47
/proc/9397/task/9400/stat : 9400 (java) S 9396 9396 1511 34817 1511 4202560 50449 0 0 0 235 12 0 0 16 0 9 0 2149722 421294080 65660 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 0 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9401] ppid=9396 vsize=411420 CPUtime=0
/proc/9397/task/9401/stat : 9401 (java) S 9396 9396 1511 34817 1511 4202560 15 0 0 0 0 0 0 0 18 0 9 0 2149722 421294080 65660 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9402] ppid=9396 vsize=411420 CPUtime=0
/proc/9397/task/9402/stat : 9402 (java) S 9396 9396 1511 34817 1511 4202560 5 0 0 0 0 0 0 0 18 0 9 0 2149722 421294080 65660 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9403] ppid=9396 vsize=411420 CPUtime=0
/proc/9397/task/9403/stat : 9403 (java) S 9396 9396 1511 34817 1511 4202560 1 0 0 0 0 0 0 0 25 0 9 0 2149724 421294080 65660 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9404] ppid=9396 vsize=411420 CPUtime=0.1
/proc/9397/task/9404/stat : 9404 (java) S 9396 9396 1511 34817 1511 4202560 562 0 0 0 10 0 0 0 16 0 9 0 2149724 421294080 65660 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9405] ppid=9396 vsize=411420 CPUtime=0
/proc/9397/task/9405/stat : 9405 (java) S 9396 9396 1511 34817 1511 4202560 0 0 0 0 0 0 0 0 25 0 9 0 2149724 421294080 65660 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
[pid=9397/tid=9406] ppid=9396 vsize=411420 CPUtime=0
/proc/9397/task/9406/stat : 9406 (java) S 9396 9396 1511 34817 1511 4202560 2 0 0 0 0 0 0 0 15 0 9 0 2149724 421294080 65660 1283457024 134512640 134550932 4290489552 18446744073709551615 4294960130 0 4 0 16800975 18446612133173261632 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 14.27
Current children cumulated vsize (KiB) 413992

Child status: 0
Real time (s): 14.3567
CPU time (s): 14.2849
CPU user time (s): 14.0769
CPU system time (s): 0.208013
CPU usage (%): 99.4999
Max. virtual memory (cumulated for all children) (KiB): 413992

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 14.0769
system time used= 0.208013
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 66902
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= 1048
involuntary context switches= 1271

runsolver used 0.008 second user time and 0.008 second system time

The end