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/201109011757/gj-user-solver-1.0/rand97.cudf.user-upgrades.log.runsolver ./gj-user-solver-1.0 /home/misc2010/data/2011/user-upgrades/rand97.cudf /home/misc2010/tmp/201109011757/gj-user-solver-1.0/rand97.cudf.user-upgrades.result -sum(pin-priority-1),-sum(pin-priority-500),-sum(pin-priority-700),-notuptodate,-removed,-changed 

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.31 1.09 1.02 4/36 31738
/proc/meminfo: memFree=571492/1048576 swapFree=0/0
[pid=31737] ppid=31736 vsize=2568 CPUtime=0
/proc/31737/stat : 31737 (gj-user-solver-) S 31736 31737 22717 34817 22717 4202496 371 0 0 0 0 0 0 0 18 0 1 0 73024128 2629632 269 1283457024 134512640 135304128 4294777216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31737/statm: 642 269 229 194 0 29 0
[pid=31738] ppid=31737 vsize=11040 CPUtime=0
/proc/31738/stat : 31738 (java) R 31737 31737 22717 34817 22717 4202496 671 0 0 0 0 0 0 0 25 0 1 0 73024128 11304960 408 1283457024 134512640 134550932 4291046736 18446744073709551615 4160476880 0 0 0 0 0 0 0 17 0 0 0 0
/proc/31738/statm: 2760 408 179 10 0 1102 0

[startup+0.165359 s]
/proc/loadavg: 1.31 1.09 1.02 4/36 31738
/proc/meminfo: memFree=571492/1048576 swapFree=0/0
[pid=31737] ppid=31736 vsize=2568 CPUtime=0
/proc/31737/stat : 31737 (gj-user-solver-) S 31736 31737 22717 34817 22717 4202496 371 0 0 0 0 0 0 0 18 0 1 0 73024128 2629632 269 1283457024 134512640 135304128 4294777216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31737/statm: 642 269 229 194 0 29 0
[pid=31738] ppid=31737 vsize=409920 CPUtime=0.16
/proc/31738/stat : 31738 (java) S 31737 31737 22717 34817 22717 4202496 3988 0 1 0 14 2 0 0 25 0 9 0 73024128 419758080 3416 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/31738/statm: 102480 3416 1918 10 0 96628 0
Current children cumulated CPU time (s) 0.16
Current children cumulated vsize (KiB) 412488

[startup+0.205371 s]
/proc/loadavg: 1.31 1.09 1.02 4/36 31738
/proc/meminfo: memFree=571492/1048576 swapFree=0/0
[pid=31737] ppid=31736 vsize=2568 CPUtime=0
/proc/31737/stat : 31737 (gj-user-solver-) S 31736 31737 22717 34817 22717 4202496 371 0 0 0 0 0 0 0 18 0 1 0 73024128 2629632 269 1283457024 134512640 135304128 4294777216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31737/statm: 642 269 229 194 0 29 0
[pid=31738] ppid=31737 vsize=409920 CPUtime=0.2
/proc/31738/stat : 31738 (java) S 31737 31737 22717 34817 22717 4202496 4071 0 1 0 18 2 0 0 25 0 9 0 73024128 419758080 3499 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/31738/statm: 102480 3499 1918 10 0 96628 0
Current children cumulated CPU time (s) 0.2
Current children cumulated vsize (KiB) 412488

[startup+0.305378 s]
/proc/loadavg: 1.31 1.09 1.02 4/36 31738
/proc/meminfo: memFree=571492/1048576 swapFree=0/0
[pid=31737] ppid=31736 vsize=2568 CPUtime=0
/proc/31737/stat : 31737 (gj-user-solver-) S 31736 31737 22717 34817 22717 4202496 371 0 0 0 0 0 0 0 18 0 1 0 73024128 2629632 269 1283457024 134512640 135304128 4294777216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31737/statm: 642 269 229 194 0 29 0
[pid=31738] ppid=31737 vsize=410476 CPUtime=0.3
/proc/31738/stat : 31738 (java) S 31737 31737 22717 34817 22717 4202496 4431 0 1 0 28 2 0 0 25 0 9 0 73024128 420327424 3859 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/31738/statm: 102619 3859 1945 10 0 96767 0
Current children cumulated CPU time (s) 0.3
Current children cumulated vsize (KiB) 413044

[startup+0.705542 s]
/proc/loadavg: 1.31 1.09 1.02 4/36 31738
/proc/meminfo: memFree=571492/1048576 swapFree=0/0
[pid=31737] ppid=31736 vsize=2568 CPUtime=0
/proc/31737/stat : 31737 (gj-user-solver-) S 31736 31737 22717 34817 22717 4202496 371 0 0 0 0 0 0 0 18 0 1 0 73024128 2629632 269 1283457024 134512640 135304128 4294777216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31737/statm: 642 269 229 194 0 29 0
[pid=31738] ppid=31737 vsize=410612 CPUtime=0.7
/proc/31738/stat : 31738 (java) S 31737 31737 22717 34817 22717 4202496 11669 0 1 0 65 5 0 0 25 0 9 0 73024128 420466688 10910 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/31738/statm: 102653 10910 2901 10 0 96801 0
Current children cumulated CPU time (s) 0.7
Current children cumulated vsize (KiB) 413180

[startup+1.50584 s]
/proc/loadavg: 1.31 1.09 1.02 2/45 31748
/proc/meminfo: memFree=513996/1048576 swapFree=0/0
[pid=31737] ppid=31736 vsize=2568 CPUtime=0
/proc/31737/stat : 31737 (gj-user-solver-) S 31736 31737 22717 34817 22717 4202496 371 0 0 0 0 0 0 0 18 0 1 0 73024128 2629632 269 1283457024 134512640 135304128 4294777216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31737/statm: 642 269 229 194 0 29 0
[pid=31738] ppid=31737 vsize=410744 CPUtime=1.5
/proc/31738/stat : 31738 (java) S 31737 31737 22717 34817 22717 4202496 26792 0 1 0 141 9 0 0 25 0 9 0 73024128 420601856 26033 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/31738/statm: 102686 26033 2901 10 0 96834 0
[pid=31738/tid=31740] ppid=31737 vsize=410744 CPUtime=0.79
/proc/31738/task/31740/stat : 31740 (java) R 31737 31737 22717 34817 22717 4202560 6712 0 1 0 76 3 0 0 25 0 9 0 73024129 420601856 26033 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=31738/tid=31741] ppid=31737 vsize=410744 CPUtime=0.64
/proc/31738/task/31741/stat : 31741 (java) R 31737 31737 22717 34817 22717 4202560 18694 0 0 0 59 5 0 0 18 0 9 0 73024129 420601856 26033 1283457024 134512640 134550932 4291046736 18446744073709551615 4151355320 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=31738/tid=31742] ppid=31737 vsize=410744 CPUtime=0
/proc/31738/task/31742/stat : 31742 (java) S 31737 31737 22717 34817 22717 4202560 15 0 0 0 0 0 0 0 20 0 9 0 73024130 420601856 26033 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31743] ppid=31737 vsize=410744 CPUtime=0
/proc/31738/task/31743/stat : 31743 (java) S 31737 31737 22717 34817 22717 4202560 5 0 0 0 0 0 0 0 20 0 9 0 73024130 420601856 26033 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31744] ppid=31737 vsize=410744 CPUtime=0
/proc/31738/task/31744/stat : 31744 (java) S 31737 31737 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 25 0 9 0 73024131 420601856 26033 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31745] ppid=31737 vsize=410744 CPUtime=0.05
/proc/31738/task/31745/stat : 31745 (java) S 31737 31737 22717 34817 22717 4202560 446 0 0 0 5 0 0 0 16 0 9 0 73024131 420601856 26033 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31746] ppid=31737 vsize=410744 CPUtime=0
/proc/31738/task/31746/stat : 31746 (java) S 31737 31737 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 25 0 9 0 73024131 420601856 26033 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31747] ppid=31737 vsize=410744 CPUtime=0
/proc/31738/task/31747/stat : 31747 (java) S 31737 31737 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 15 0 9 0 73024131 420601856 26033 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.5
Current children cumulated vsize (KiB) 413312

[startup+3.10637 s]
/proc/loadavg: 1.31 1.09 1.02 2/45 31748
/proc/meminfo: memFree=442200/1048576 swapFree=0/0
[pid=31737] ppid=31736 vsize=2568 CPUtime=0
/proc/31737/stat : 31737 (gj-user-solver-) S 31736 31737 22717 34817 22717 4202496 371 0 0 0 0 0 0 0 18 0 1 0 73024128 2629632 269 1283457024 134512640 135304128 4294777216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31737/statm: 642 269 229 194 0 29 0
[pid=31738] ppid=31737 vsize=410876 CPUtime=3.1
/proc/31738/stat : 31738 (java) S 31737 31737 22717 34817 22717 4202496 49859 0 1 0 293 17 0 0 25 0 9 0 73024128 420737024 49100 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/31738/statm: 102719 49100 2901 10 0 96867 0
[pid=31738/tid=31740] ppid=31737 vsize=410876 CPUtime=1.41
/proc/31738/task/31740/stat : 31740 (java) R 31737 31737 22717 34817 22717 4202560 13865 0 1 0 134 7 0 0 25 0 9 0 73024129 420737024 49100 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=31738/tid=31741] ppid=31737 vsize=410876 CPUtime=1.62
/proc/31738/task/31741/stat : 31741 (java) R 31737 31737 22717 34817 22717 4202560 34605 0 0 0 154 8 0 0 16 0 9 0 73024129 420737024 49100 1283457024 134512640 134550932 4291046736 18446744073709551615 4151352478 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=31738/tid=31742] ppid=31737 vsize=410876 CPUtime=0
/proc/31738/task/31742/stat : 31742 (java) S 31737 31737 22717 34817 22717 4202560 15 0 0 0 0 0 0 0 20 0 9 0 73024130 420737024 49100 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31743] ppid=31737 vsize=410876 CPUtime=0
/proc/31738/task/31743/stat : 31743 (java) S 31737 31737 22717 34817 22717 4202560 5 0 0 0 0 0 0 0 20 0 9 0 73024130 420737024 49100 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31744] ppid=31737 vsize=410876 CPUtime=0
/proc/31738/task/31744/stat : 31744 (java) S 31737 31737 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 25 0 9 0 73024131 420737024 49100 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31745] ppid=31737 vsize=410876 CPUtime=0.05
/proc/31738/task/31745/stat : 31745 (java) S 31737 31737 22717 34817 22717 4202560 449 0 0 0 5 0 0 0 15 0 9 0 73024131 420737024 49100 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31746] ppid=31737 vsize=410876 CPUtime=0
/proc/31738/task/31746/stat : 31746 (java) S 31737 31737 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 25 0 9 0 73024131 420737024 49100 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31747] ppid=31737 vsize=410876 CPUtime=0
/proc/31738/task/31747/stat : 31747 (java) R 31737 31737 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 15 0 9 0 73024131 420737024 49100 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.1
Current children cumulated vsize (KiB) 413444

[startup+6.30748 s]
/proc/loadavg: 1.45 1.12 1.03 3/45 31748
/proc/meminfo: memFree=305312/1048576 swapFree=0/0
[pid=31737] ppid=31736 vsize=2568 CPUtime=0
/proc/31737/stat : 31737 (gj-user-solver-) S 31736 31737 22717 34817 22717 4202496 371 0 0 0 0 0 0 0 18 0 1 0 73024128 2629632 269 1283457024 134512640 135304128 4294777216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31737/statm: 642 269 229 194 0 29 0
[pid=31738] ppid=31737 vsize=439916 CPUtime=6.3
/proc/31738/stat : 31738 (java) S 31737 31737 22717 34817 22717 4202496 78236 0 1 0 602 28 0 0 25 0 9 0 73024128 450473984 77471 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/31738/statm: 109979 77471 2902 10 0 104127 0
[pid=31738/tid=31740] ppid=31737 vsize=439916 CPUtime=2.25
/proc/31738/task/31740/stat : 31740 (java) R 31737 31737 22717 34817 22717 4202560 13882 0 1 0 218 7 0 0 25 0 9 0 73024129 450473984 77471 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=31738/tid=31741] ppid=31737 vsize=439916 CPUtime=3.95
/proc/31738/task/31741/stat : 31741 (java) R 31737 31737 22717 34817 22717 4202560 62947 0 0 0 375 20 0 0 16 0 9 0 73024129 450473984 77471 1283457024 134512640 134550932 4291046736 18446744073709551615 4153465377 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=31738/tid=31742] ppid=31737 vsize=439916 CPUtime=0
/proc/31738/task/31742/stat : 31742 (java) S 31737 31737 22717 34817 22717 4202560 15 0 0 0 0 0 0 0 20 0 9 0 73024130 450473984 77471 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31743] ppid=31737 vsize=439916 CPUtime=0
/proc/31738/task/31743/stat : 31743 (java) S 31737 31737 22717 34817 22717 4202560 5 0 0 0 0 0 0 0 20 0 9 0 73024130 450473984 77471 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31744] ppid=31737 vsize=439916 CPUtime=0
/proc/31738/task/31744/stat : 31744 (java) S 31737 31737 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 25 0 9 0 73024131 450473984 77471 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31745] ppid=31737 vsize=439916 CPUtime=0.08
/proc/31738/task/31745/stat : 31745 (java) S 31737 31737 22717 34817 22717 4202560 467 0 0 0 8 0 0 0 15 0 9 0 73024131 450473984 77471 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31746] ppid=31737 vsize=439916 CPUtime=0
/proc/31738/task/31746/stat : 31746 (java) S 31737 31737 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 25 0 9 0 73024131 450473984 77471 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31747] ppid=31737 vsize=439916 CPUtime=0
/proc/31738/task/31747/stat : 31747 (java) S 31737 31737 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 15 0 9 0 73024131 450473984 77471 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.3
Current children cumulated vsize (KiB) 442484

[startup+12.7095 s]
/proc/loadavg: 1.49 1.14 1.04 2/46 31750
/proc/meminfo: memFree=300220/1048576 swapFree=0/0
[pid=31737] ppid=31736 vsize=2568 CPUtime=0
/proc/31737/stat : 31737 (gj-user-solver-) S 31736 31737 22717 34817 22717 4202496 371 0 0 0 0 0 0 0 18 0 1 0 73024128 2629632 269 1283457024 134512640 135304128 4294777216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31737/statm: 642 269 229 194 0 29 0
[pid=31738] ppid=31737 vsize=411884 CPUtime=12.69
/proc/31738/stat : 31738 (java) S 31737 31737 22717 34817 22717 4202496 99933 0 1 0 1229 40 0 0 25 0 10 0 73024128 421769216 70656 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/31738/statm: 102971 70656 2919 10 0 97116 0
[pid=31738/tid=31740] ppid=31737 vsize=411884 CPUtime=4.26
/proc/31738/task/31740/stat : 31740 (java) R 31737 31737 22717 34817 22717 4202560 14134 0 1 0 418 8 0 0 25 0 10 0 73024129 421769216 70656 1283457024 134512640 134550932 4291046736 18446744073709551615 4115942372 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=31738/tid=31741] ppid=31737 vsize=411884 CPUtime=8.26
/proc/31738/task/31741/stat : 31741 (java) S 31737 31737 22717 34817 22717 4202560 84307 0 0 0 795 31 0 0 16 0 10 0 73024129 421769216 70656 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 0 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31742] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31742/stat : 31742 (java) S 31737 31737 22717 34817 22717 4202560 15 0 0 0 0 0 0 0 18 0 10 0 73024130 421769216 70656 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31743] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31743/stat : 31743 (java) S 31737 31737 22717 34817 22717 4202560 5 0 0 0 0 0 0 0 18 0 10 0 73024130 421769216 70656 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31744] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31744/stat : 31744 (java) S 31737 31737 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 25 0 10 0 73024131 421769216 70656 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31745] ppid=31737 vsize=411884 CPUtime=0.15
/proc/31738/task/31745/stat : 31745 (java) S 31737 31737 22717 34817 22717 4202560 547 0 0 0 15 0 0 0 16 0 10 0 73024131 421769216 70656 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31746] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31746/stat : 31746 (java) S 31737 31737 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 25 0 10 0 73024131 421769216 70656 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31747] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31747/stat : 31747 (java) S 31737 31737 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 15 0 10 0 73024131 421769216 70656 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31750] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31750/stat : 31750 (java) S 31737 31737 22717 34817 22717 4202560 5 0 0 0 0 0 0 0 25 0 10 0 73025266 421769216 70656 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 12.69
Current children cumulated vsize (KiB) 414452

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

[startup+12.8095 s]
/proc/loadavg: 1.49 1.14 1.04 2/46 31750
/proc/meminfo: memFree=300220/1048576 swapFree=0/0
[pid=31737] ppid=31736 vsize=2568 CPUtime=0
/proc/31737/stat : 31737 (gj-user-solver-) S 31736 31737 22717 34817 22717 4202496 371 0 0 0 0 0 0 0 18 0 1 0 73024128 2629632 269 1283457024 134512640 135304128 4294777216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31737/statm: 642 269 229 194 0 29 0
[pid=31738] ppid=31737 vsize=411884 CPUtime=12.79
/proc/31738/stat : 31738 (java) S 31737 31737 22717 34817 22717 4202496 99937 0 1 0 1239 40 0 0 25 0 10 0 73024128 421769216 70660 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/31738/statm: 102971 70660 2919 10 0 97116 0
[pid=31738/tid=31740] ppid=31737 vsize=411884 CPUtime=4.36
/proc/31738/task/31740/stat : 31740 (java) R 31737 31737 22717 34817 22717 4202560 14134 0 1 0 428 8 0 0 25 0 10 0 73024129 421769216 70660 1283457024 134512640 134550932 4291046736 18446744073709551615 4115893008 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=31738/tid=31741] ppid=31737 vsize=411884 CPUtime=8.26
/proc/31738/task/31741/stat : 31741 (java) S 31737 31737 22717 34817 22717 4202560 84307 0 0 0 795 31 0 0 16 0 10 0 73024129 421769216 70660 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 0 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31742] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31742/stat : 31742 (java) S 31737 31737 22717 34817 22717 4202560 15 0 0 0 0 0 0 0 18 0 10 0 73024130 421769216 70660 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31743] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31743/stat : 31743 (java) S 31737 31737 22717 34817 22717 4202560 5 0 0 0 0 0 0 0 18 0 10 0 73024130 421769216 70660 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31744] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31744/stat : 31744 (java) S 31737 31737 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 25 0 10 0 73024131 421769216 70660 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31745] ppid=31737 vsize=411884 CPUtime=0.15
/proc/31738/task/31745/stat : 31745 (java) S 31737 31737 22717 34817 22717 4202560 551 0 0 0 15 0 0 0 15 0 10 0 73024131 421769216 70660 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31746] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31746/stat : 31746 (java) S 31737 31737 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 25 0 10 0 73024131 421769216 70660 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31747] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31747/stat : 31747 (java) S 31737 31737 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 15 0 10 0 73024131 421769216 70660 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31750] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31750/stat : 31750 (java) S 31737 31737 22717 34817 22717 4202560 5 0 0 0 0 0 0 0 25 0 10 0 73025266 421769216 70660 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 12.79
Current children cumulated vsize (KiB) 414452

[startup+19.2112 s]
/proc/loadavg: 1.45 1.14 1.04 2/46 31750
/proc/meminfo: memFree=300220/1048576 swapFree=0/0
[pid=31737] ppid=31736 vsize=2568 CPUtime=0
/proc/31737/stat : 31737 (gj-user-solver-) S 31736 31737 22717 34817 22717 4202496 371 0 0 0 0 0 0 0 18 0 1 0 73024128 2629632 269 1283457024 134512640 135304128 4294777216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31737/statm: 642 269 229 194 0 29 0
[pid=31738] ppid=31737 vsize=411884 CPUtime=19.19
/proc/31738/stat : 31738 (java) S 31737 31737 22717 34817 22717 4202496 99945 0 1 0 1879 40 0 0 25 0 10 0 73024128 421769216 70668 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/31738/statm: 102971 70668 2921 10 0 97116 0
[pid=31738/tid=31740] ppid=31737 vsize=411884 CPUtime=10.63
/proc/31738/task/31740/stat : 31740 (java) R 31737 31737 22717 34817 22717 4202560 14134 0 1 0 1055 8 0 0 25 0 10 0 73024129 421769216 70668 1283457024 134512640 134550932 4291046736 18446744073709551615 4116091405 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=31738/tid=31741] ppid=31737 vsize=411884 CPUtime=8.36
/proc/31738/task/31741/stat : 31741 (java) S 31737 31737 22717 34817 22717 4202560 84309 0 0 0 805 31 0 0 15 0 10 0 73024129 421769216 70668 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 0 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31742] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31742/stat : 31742 (java) S 31737 31737 22717 34817 22717 4202560 15 0 0 0 0 0 0 0 18 0 10 0 73024130 421769216 70668 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31743] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31743/stat : 31743 (java) S 31737 31737 22717 34817 22717 4202560 5 0 0 0 0 0 0 0 18 0 10 0 73024130 421769216 70668 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31744] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31744/stat : 31744 (java) S 31737 31737 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 25 0 10 0 73024131 421769216 70668 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31745] ppid=31737 vsize=411884 CPUtime=0.18
/proc/31738/task/31745/stat : 31745 (java) S 31737 31737 22717 34817 22717 4202560 557 0 0 0 18 0 0 0 15 0 10 0 73024131 421769216 70668 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31746] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31746/stat : 31746 (java) S 31737 31737 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 25 0 10 0 73024131 421769216 70668 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31747] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31747/stat : 31747 (java) S 31737 31737 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 15 0 10 0 73024131 421769216 70668 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31750] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31750/stat : 31750 (java) S 31737 31737 22717 34817 22717 4202560 5 0 0 0 0 0 0 0 25 0 10 0 73025266 421769216 70668 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 19.19
Current children cumulated vsize (KiB) 414452

[startup+22.4121 s]
/proc/loadavg: 1.42 1.13 1.04 2/46 31751
/proc/meminfo: memFree=300220/1048576 swapFree=0/0
[pid=31737] ppid=31736 vsize=2568 CPUtime=0
/proc/31737/stat : 31737 (gj-user-solver-) S 31736 31737 22717 34817 22717 4202496 371 0 0 0 0 0 0 0 18 0 1 0 73024128 2629632 269 1283457024 134512640 135304128 4294777216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31737/statm: 642 269 229 194 0 29 0
[pid=31738] ppid=31737 vsize=411884 CPUtime=22.39
/proc/31738/stat : 31738 (java) S 31737 31737 22717 34817 22717 4202496 99946 0 1 0 2199 40 0 0 25 0 10 0 73024128 421769216 70669 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/31738/statm: 102971 70669 2921 10 0 97116 0
[pid=31738/tid=31740] ppid=31737 vsize=411884 CPUtime=13.83
/proc/31738/task/31740/stat : 31740 (java) R 31737 31737 22717 34817 22717 4202560 14134 0 1 0 1375 8 0 0 25 0 10 0 73024129 421769216 70669 1283457024 134512640 134550932 4291046736 18446744073709551615 4115935306 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=31738/tid=31741] ppid=31737 vsize=411884 CPUtime=8.36
/proc/31738/task/31741/stat : 31741 (java) S 31737 31737 22717 34817 22717 4202560 84309 0 0 0 805 31 0 0 15 0 10 0 73024129 421769216 70669 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 0 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31742] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31742/stat : 31742 (java) S 31737 31737 22717 34817 22717 4202560 15 0 0 0 0 0 0 0 18 0 10 0 73024130 421769216 70669 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31743] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31743/stat : 31743 (java) S 31737 31737 22717 34817 22717 4202560 5 0 0 0 0 0 0 0 18 0 10 0 73024130 421769216 70669 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31744] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31744/stat : 31744 (java) S 31737 31737 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 25 0 10 0 73024131 421769216 70669 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31745] ppid=31737 vsize=411884 CPUtime=0.18
/proc/31738/task/31745/stat : 31745 (java) S 31737 31737 22717 34817 22717 4202560 558 0 0 0 18 0 0 0 15 0 10 0 73024131 421769216 70669 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31746] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31746/stat : 31746 (java) S 31737 31737 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 25 0 10 0 73024131 421769216 70669 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31747] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31747/stat : 31747 (java) S 31737 31737 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 15 0 10 0 73024131 421769216 70669 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31750] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31750/stat : 31750 (java) S 31737 31737 22717 34817 22717 4202560 5 0 0 0 0 0 0 0 25 0 10 0 73025266 421769216 70669 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 22.39
Current children cumulated vsize (KiB) 414452

[startup+24.0125 s]
/proc/loadavg: 1.42 1.13 1.04 2/46 31751
/proc/meminfo: memFree=300220/1048576 swapFree=0/0
[pid=31737] ppid=31736 vsize=2568 CPUtime=0
/proc/31737/stat : 31737 (gj-user-solver-) S 31736 31737 22717 34817 22717 4202496 371 0 0 0 0 0 0 0 18 0 1 0 73024128 2629632 269 1283457024 134512640 135304128 4294777216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31737/statm: 642 269 229 194 0 29 0
[pid=31738] ppid=31737 vsize=411884 CPUtime=23.99
/proc/31738/stat : 31738 (java) S 31737 31737 22717 34817 22717 4202496 99947 0 1 0 2359 40 0 0 25 0 10 0 73024128 421769216 70670 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/31738/statm: 102971 70670 2921 10 0 97116 0
[pid=31738/tid=31740] ppid=31737 vsize=411884 CPUtime=15.4
/proc/31738/task/31740/stat : 31740 (java) R 31737 31737 22717 34817 22717 4202560 14134 0 1 0 1532 8 0 0 25 0 10 0 73024129 421769216 70670 1283457024 134512640 134550932 4291046736 18446744073709551615 4115942173 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=31738/tid=31741] ppid=31737 vsize=411884 CPUtime=8.39
/proc/31738/task/31741/stat : 31741 (java) S 31737 31737 22717 34817 22717 4202560 84309 0 0 0 808 31 0 0 16 0 10 0 73024129 421769216 70670 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 0 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31742] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31742/stat : 31742 (java) S 31737 31737 22717 34817 22717 4202560 15 0 0 0 0 0 0 0 18 0 10 0 73024130 421769216 70670 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31743] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31743/stat : 31743 (java) S 31737 31737 22717 34817 22717 4202560 5 0 0 0 0 0 0 0 18 0 10 0 73024130 421769216 70670 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31744] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31744/stat : 31744 (java) S 31737 31737 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 25 0 10 0 73024131 421769216 70670 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31745] ppid=31737 vsize=411884 CPUtime=0.18
/proc/31738/task/31745/stat : 31745 (java) S 31737 31737 22717 34817 22717 4202560 559 0 0 0 18 0 0 0 15 0 10 0 73024131 421769216 70670 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31746] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31746/stat : 31746 (java) S 31737 31737 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 25 0 10 0 73024131 421769216 70670 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31747] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31747/stat : 31747 (java) S 31737 31737 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 15 0 10 0 73024131 421769216 70670 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31750] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31750/stat : 31750 (java) S 31737 31737 22717 34817 22717 4202560 5 0 0 0 0 0 0 0 25 0 10 0 73025266 421769216 70670 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 23.99
Current children cumulated vsize (KiB) 414452

[startup+24.8126 s]
/proc/loadavg: 1.42 1.13 1.04 3/46 31751
/proc/meminfo: memFree=300220/1048576 swapFree=0/0
[pid=31737] ppid=31736 vsize=2568 CPUtime=0
/proc/31737/stat : 31737 (gj-user-solver-) S 31736 31737 22717 34817 22717 4202496 371 0 0 0 0 0 0 0 18 0 1 0 73024128 2629632 269 1283457024 134512640 135304128 4294777216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31737/statm: 642 269 229 194 0 29 0
[pid=31738] ppid=31737 vsize=411884 CPUtime=24.79
/proc/31738/stat : 31738 (java) S 31737 31737 22717 34817 22717 4202496 99948 0 1 0 2439 40 0 0 25 0 10 0 73024128 421769216 70671 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/31738/statm: 102971 70671 2921 10 0 97116 0
[pid=31738/tid=31740] ppid=31737 vsize=411884 CPUtime=16.17
/proc/31738/task/31740/stat : 31740 (java) R 31737 31737 22717 34817 22717 4202560 14134 0 1 0 1609 8 0 0 25 0 10 0 73024129 421769216 70671 1283457024 134512640 134550932 4291046736 18446744073709551615 4116091401 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=31738/tid=31741] ppid=31737 vsize=411884 CPUtime=8.41
/proc/31738/task/31741/stat : 31741 (java) S 31737 31737 22717 34817 22717 4202560 84309 0 0 0 810 31 0 0 16 0 10 0 73024129 421769216 70671 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 0 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31742] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31742/stat : 31742 (java) S 31737 31737 22717 34817 22717 4202560 15 0 0 0 0 0 0 0 18 0 10 0 73024130 421769216 70671 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31743] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31743/stat : 31743 (java) S 31737 31737 22717 34817 22717 4202560 5 0 0 0 0 0 0 0 18 0 10 0 73024130 421769216 70671 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31744] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31744/stat : 31744 (java) S 31737 31737 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 25 0 10 0 73024131 421769216 70671 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31745] ppid=31737 vsize=411884 CPUtime=0.19
/proc/31738/task/31745/stat : 31745 (java) S 31737 31737 22717 34817 22717 4202560 560 0 0 0 19 0 0 0 15 0 10 0 73024131 421769216 70671 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31746] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31746/stat : 31746 (java) S 31737 31737 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 25 0 10 0 73024131 421769216 70671 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31747] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31747/stat : 31747 (java) R 31737 31737 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 15 0 10 0 73024131 421769216 70671 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=31738/tid=31750] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31750/stat : 31750 (java) S 31737 31737 22717 34817 22717 4202560 5 0 0 0 0 0 0 0 25 0 10 0 73025266 421769216 70671 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 24.79
Current children cumulated vsize (KiB) 414452

[startup+25.2127 s]
/proc/loadavg: 1.42 1.13 1.04 3/46 31751
/proc/meminfo: memFree=300220/1048576 swapFree=0/0
[pid=31737] ppid=31736 vsize=2568 CPUtime=0
/proc/31737/stat : 31737 (gj-user-solver-) S 31736 31737 22717 34817 22717 4202496 371 0 0 0 0 0 0 0 18 0 1 0 73024128 2629632 269 1283457024 134512640 135304128 4294777216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31737/statm: 642 269 229 194 0 29 0
[pid=31738] ppid=31737 vsize=411884 CPUtime=25.19
/proc/31738/stat : 31738 (java) S 31737 31737 22717 34817 22717 4202496 99948 0 1 0 2479 40 0 0 25 0 10 0 73024128 421769216 70671 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/31738/statm: 102971 70671 2921 10 0 97116 0
[pid=31738/tid=31740] ppid=31737 vsize=411884 CPUtime=16.57
/proc/31738/task/31740/stat : 31740 (java) R 31737 31737 22717 34817 22717 4202560 14134 0 1 0 1649 8 0 0 25 0 10 0 73024129 421769216 70671 1283457024 134512640 134550932 4291046736 18446744073709551615 4115956283 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=31738/tid=31741] ppid=31737 vsize=411884 CPUtime=8.41
/proc/31738/task/31741/stat : 31741 (java) S 31737 31737 22717 34817 22717 4202560 84309 0 0 0 810 31 0 0 15 0 10 0 73024129 421769216 70671 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 0 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31742] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31742/stat : 31742 (java) S 31737 31737 22717 34817 22717 4202560 15 0 0 0 0 0 0 0 18 0 10 0 73024130 421769216 70671 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31743] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31743/stat : 31743 (java) S 31737 31737 22717 34817 22717 4202560 5 0 0 0 0 0 0 0 18 0 10 0 73024130 421769216 70671 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31744] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31744/stat : 31744 (java) S 31737 31737 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 25 0 10 0 73024131 421769216 70671 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31745] ppid=31737 vsize=411884 CPUtime=0.19
/proc/31738/task/31745/stat : 31745 (java) S 31737 31737 22717 34817 22717 4202560 560 0 0 0 19 0 0 0 15 0 10 0 73024131 421769216 70671 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31746] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31746/stat : 31746 (java) S 31737 31737 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 25 0 10 0 73024131 421769216 70671 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31747] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31747/stat : 31747 (java) S 31737 31737 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 15 0 10 0 73024131 421769216 70671 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31750] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31750/stat : 31750 (java) S 31737 31737 22717 34817 22717 4202560 5 0 0 0 0 0 0 0 25 0 10 0 73025266 421769216 70671 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 25.19
Current children cumulated vsize (KiB) 414452

[startup+25.3074 s]
/proc/loadavg: 1.38 1.13 1.04 1/45 31752
/proc/meminfo: memFree=300220/1048576 swapFree=0/0
[pid=31737] ppid=31736 vsize=2568 CPUtime=0
/proc/31737/stat : 31737 (gj-user-solver-) S 31736 31737 22717 34817 22717 4202496 371 0 0 0 0 0 0 0 18 0 1 0 73024128 2629632 269 1283457024 134512640 135304128 4294777216 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31737/statm: 642 269 229 194 0 29 0
[pid=31738] ppid=31737 vsize=411884 CPUtime=25.28
/proc/31738/stat : 31738 (java) S 31737 31737 22717 34817 22717 4202496 99950 0 1 0 2488 40 0 0 25 0 9 0 73024128 421769216 70673 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/31738/statm: 102971 70673 2922 10 0 97116 0
[pid=31738/tid=31740] ppid=31737 vsize=411884 CPUtime=16.63
/proc/31738/task/31740/stat : 31740 (java) S 31737 31737 22717 34817 22717 4202560 14134 0 1 0 1655 8 0 0 25 0 9 0 73024129 421769216 70673 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31741] ppid=31737 vsize=411884 CPUtime=8.43
/proc/31738/task/31741/stat : 31741 (java) S 31737 31737 22717 34817 22717 4202560 84309 0 0 0 812 31 0 0 16 0 9 0 73024129 421769216 70673 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 0 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31742] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31742/stat : 31742 (java) S 31737 31737 22717 34817 22717 4202560 15 0 0 0 0 0 0 0 18 0 9 0 73024130 421769216 70673 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31743] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31743/stat : 31743 (java) S 31737 31737 22717 34817 22717 4202560 5 0 0 0 0 0 0 0 18 0 9 0 73024130 421769216 70673 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31744] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31744/stat : 31744 (java) S 31737 31737 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 25 0 9 0 73024131 421769216 70673 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31745] ppid=31737 vsize=411884 CPUtime=0.19
/proc/31738/task/31745/stat : 31745 (java) S 31737 31737 22717 34817 22717 4202560 561 0 0 0 19 0 0 0 15 0 9 0 73024131 421769216 70673 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31746] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31746/stat : 31746 (java) S 31737 31737 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 25 0 9 0 73024131 421769216 70673 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
[pid=31738/tid=31747] ppid=31737 vsize=411884 CPUtime=0
/proc/31738/task/31747/stat : 31747 (java) S 31737 31737 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 15 0 9 0 73024131 421769216 70673 1283457024 134512640 134550932 4291046736 18446744073709551615 4294960130 0 4 0 16800975 18446612133392889664 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 25.28
Current children cumulated vsize (KiB) 414452

Child status: 0
Real time (s): 25.3761
CPU time (s): 25.3096
CPU user time (s): 24.8816
CPU system time (s): 0.428026
CPU usage (%): 99.738
Max. virtual memory (cumulated for all children) (KiB): 442508

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 24.8816
system time used= 0.428026
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 100337
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= 1334
involuntary context switches= 1744

runsolver used 0 second user time and 0 second system time

The end