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/201108291842/gj-user-solver-1.0/rand740.cudf.user-upgrades.log.runsolver ./gj-user-solver-1.0 /home/misc2010/data/2011/user-upgrades/rand740.cudf /home/misc2010/tmp/201108291842/gj-user-solver-1.0/rand740.cudf.user-upgrades.result -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.44 1.28 1.20 6/36 24680
/proc/meminfo: memFree=253832/1048576 swapFree=0/0
[pid=24679] ppid=24678 vsize=2576 CPUtime=0
/proc/24679/stat : 24679 (gj-user-solver-) R 24678 24679 17511 34816 17511 4202496 356 0 0 0 0 0 0 0 25 0 1 0 46314275 2637824 270 1283457024 134512640 135304128 4288230272 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/24679/statm: 644 270 228 194 0 31 0
[pid=24680] ppid=24679 vsize=2576 CPUtime=0
/proc/24680/stat : 24680 (gj-user-solver-) R 24679 24679 17511 34816 17511 4202560 0 0 0 0 0 0 0 0 25 0 1 0 46314276 2637824 42 1283457024 134512640 135304128 4288230272 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/24680/statm: 644 42 0 194 0 31 0

[startup+0.106933 s]
/proc/loadavg: 1.44 1.28 1.20 6/36 24680
/proc/meminfo: memFree=253832/1048576 swapFree=0/0
[pid=24679] ppid=24678 vsize=2576 CPUtime=0
/proc/24679/stat : 24679 (gj-user-solver-) S 24678 24679 17511 34816 17511 4202496 374 0 0 0 0 0 0 0 25 0 1 0 46314275 2637824 271 1283457024 134512640 135304128 4288230272 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24679/statm: 644 271 229 194 0 31 0
[pid=24680] ppid=24679 vsize=410100 CPUtime=0.11
/proc/24680/stat : 24680 (java) S 24679 24679 17511 34816 17511 4202496 3941 0 1 0 7 4 0 0 25 0 9 0 46314276 419942400 3367 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/24680/statm: 102525 3367 1934 10 0 96673 0
Current children cumulated CPU time (s) 0.11
Current children cumulated vsize (KiB) 412676

[startup+0.206947 s]
/proc/loadavg: 1.44 1.28 1.20 6/36 24680
/proc/meminfo: memFree=253832/1048576 swapFree=0/0
[pid=24679] ppid=24678 vsize=2576 CPUtime=0
/proc/24679/stat : 24679 (gj-user-solver-) S 24678 24679 17511 34816 17511 4202496 374 0 0 0 0 0 0 0 25 0 1 0 46314275 2637824 271 1283457024 134512640 135304128 4288230272 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24679/statm: 644 271 229 194 0 31 0
[pid=24680] ppid=24679 vsize=410100 CPUtime=0.21
/proc/24680/stat : 24680 (java) S 24679 24679 17511 34816 17511 4202496 4177 0 1 0 17 4 0 0 25 0 9 0 46314276 419942400 3603 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/24680/statm: 102525 3603 1934 10 0 96673 0
Current children cumulated CPU time (s) 0.21
Current children cumulated vsize (KiB) 412676

[startup+0.306965 s]
/proc/loadavg: 1.44 1.28 1.20 6/36 24680
/proc/meminfo: memFree=253832/1048576 swapFree=0/0
[pid=24679] ppid=24678 vsize=2576 CPUtime=0
/proc/24679/stat : 24679 (gj-user-solver-) S 24678 24679 17511 34816 17511 4202496 374 0 0 0 0 0 0 0 25 0 1 0 46314275 2637824 271 1283457024 134512640 135304128 4288230272 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24679/statm: 644 271 229 194 0 31 0
[pid=24680] ppid=24679 vsize=410384 CPUtime=0.31
/proc/24680/stat : 24680 (java) S 24679 24679 17511 34816 17511 4202496 4485 0 1 0 27 4 0 0 25 0 9 0 46314276 420233216 3911 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/24680/statm: 102596 3911 1946 10 0 96744 0
Current children cumulated CPU time (s) 0.31
Current children cumulated vsize (KiB) 412960

[startup+0.707059 s]
/proc/loadavg: 1.44 1.28 1.20 6/36 24680
/proc/meminfo: memFree=253832/1048576 swapFree=0/0
[pid=24679] ppid=24678 vsize=2576 CPUtime=0
/proc/24679/stat : 24679 (gj-user-solver-) S 24678 24679 17511 34816 17511 4202496 374 0 0 0 0 0 0 0 25 0 1 0 46314275 2637824 271 1283457024 134512640 135304128 4288230272 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24679/statm: 644 271 229 194 0 31 0
[pid=24680] ppid=24679 vsize=410652 CPUtime=0.71
/proc/24680/stat : 24680 (java) S 24679 24679 17511 34816 17511 4202496 12475 0 1 0 61 10 0 0 25 0 9 0 46314276 420507648 11714 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/24680/statm: 102663 11714 2901 10 0 96811 0
Current children cumulated CPU time (s) 0.71
Current children cumulated vsize (KiB) 413228

[startup+1.50938 s]
/proc/loadavg: 1.44 1.28 1.20 2/45 24689
/proc/meminfo: memFree=195392/1048576 swapFree=0/0
[pid=24679] ppid=24678 vsize=2576 CPUtime=0
/proc/24679/stat : 24679 (gj-user-solver-) S 24678 24679 17511 34816 17511 4202496 374 0 0 0 0 0 0 0 25 0 1 0 46314275 2637824 271 1283457024 134512640 135304128 4288230272 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24679/statm: 644 271 229 194 0 31 0
[pid=24680] ppid=24679 vsize=410784 CPUtime=1.49
/proc/24680/stat : 24680 (java) S 24679 24679 17511 34816 17511 4202496 27174 0 1 0 139 10 0 0 25 0 9 0 46314276 420642816 26413 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/24680/statm: 102696 26413 2901 10 0 96844 0
[pid=24680/tid=24682] ppid=24679 vsize=410784 CPUtime=0.78
/proc/24680/task/24682/stat : 24682 (java) R 24679 24679 17511 34816 17511 4202560 6710 0 1 0 76 2 0 0 25 0 9 0 46314276 420642816 26413 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=24680/tid=24683] ppid=24679 vsize=410784 CPUtime=0.65
/proc/24680/task/24683/stat : 24683 (java) R 24679 24679 17511 34816 17511 4202560 19075 0 0 0 59 6 0 0 18 0 9 0 46314277 420642816 26413 1283457024 134512640 134550932 4288258800 18446744073709551615 4151105464 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=24680/tid=24684] ppid=24679 vsize=410784 CPUtime=0
/proc/24680/task/24684/stat : 24684 (java) S 24679 24679 17511 34816 17511 4202560 15 0 0 0 0 0 0 0 20 0 9 0 46314277 420642816 26413 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24685] ppid=24679 vsize=410784 CPUtime=0
/proc/24680/task/24685/stat : 24685 (java) S 24679 24679 17511 34816 17511 4202560 5 0 0 0 0 0 0 0 20 0 9 0 46314277 420642816 26413 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24686] ppid=24679 vsize=410784 CPUtime=0
/proc/24680/task/24686/stat : 24686 (java) S 24679 24679 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 9 0 46314278 420642816 26413 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24687] ppid=24679 vsize=410784 CPUtime=0.03
/proc/24680/task/24687/stat : 24687 (java) S 24679 24679 17511 34816 17511 4202560 446 0 0 0 3 0 0 0 16 0 9 0 46314278 420642816 26413 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24688] ppid=24679 vsize=410784 CPUtime=0
/proc/24680/task/24688/stat : 24688 (java) S 24679 24679 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 9 0 46314278 420642816 26413 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24689] ppid=24679 vsize=410784 CPUtime=0
/proc/24680/task/24689/stat : 24689 (java) R 24679 24679 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 15 0 9 0 46314278 420642816 26413 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.49
Current children cumulated vsize (KiB) 413360

[startup+3.10972 s]
/proc/loadavg: 1.41 1.27 1.20 2/45 24689
/proc/meminfo: memFree=123596/1048576 swapFree=0/0
[pid=24679] ppid=24678 vsize=2576 CPUtime=0
/proc/24679/stat : 24679 (gj-user-solver-) S 24678 24679 17511 34816 17511 4202496 374 0 0 0 0 0 0 0 25 0 1 0 46314275 2637824 271 1283457024 134512640 135304128 4288230272 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24679/statm: 644 271 229 194 0 31 0
[pid=24680] ppid=24679 vsize=410784 CPUtime=3.09
/proc/24680/stat : 24680 (java) S 24679 24679 17511 34816 17511 4202496 50911 0 1 0 296 13 0 0 25 0 9 0 46314276 420642816 50150 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/24680/statm: 102696 50150 2901 10 0 96844 0
[pid=24680/tid=24682] ppid=24679 vsize=410784 CPUtime=1.4
/proc/24680/task/24682/stat : 24682 (java) R 24679 24679 17511 34816 17511 4202560 13862 0 1 0 136 4 0 0 25 0 9 0 46314276 420642816 50150 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=24680/tid=24683] ppid=24679 vsize=410784 CPUtime=1.62
/proc/24680/task/24683/stat : 24683 (java) R 24679 24679 17511 34816 17511 4202560 35656 0 0 0 156 6 0 0 16 0 9 0 46314277 420642816 50150 1283457024 134512640 134550932 4288258800 18446744073709551615 4151105464 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=24680/tid=24684] ppid=24679 vsize=410784 CPUtime=0
/proc/24680/task/24684/stat : 24684 (java) S 24679 24679 17511 34816 17511 4202560 15 0 0 0 0 0 0 0 20 0 9 0 46314277 420642816 50150 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24685] ppid=24679 vsize=410784 CPUtime=0
/proc/24680/task/24685/stat : 24685 (java) S 24679 24679 17511 34816 17511 4202560 5 0 0 0 0 0 0 0 20 0 9 0 46314277 420642816 50150 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24686] ppid=24679 vsize=410784 CPUtime=0
/proc/24680/task/24686/stat : 24686 (java) S 24679 24679 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 9 0 46314278 420642816 50150 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24687] ppid=24679 vsize=410784 CPUtime=0.03
/proc/24680/task/24687/stat : 24687 (java) S 24679 24679 17511 34816 17511 4202560 450 0 0 0 3 0 0 0 15 0 9 0 46314278 420642816 50150 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24688] ppid=24679 vsize=410784 CPUtime=0
/proc/24680/task/24688/stat : 24688 (java) S 24679 24679 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 9 0 46314278 420642816 50150 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24689] ppid=24679 vsize=410784 CPUtime=0
/proc/24680/task/24689/stat : 24689 (java) S 24679 24679 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 15 0 9 0 46314278 420642816 50150 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.09
Current children cumulated vsize (KiB) 413360

[startup+6.3104 s]
/proc/loadavg: 1.41 1.27 1.20 2/45 24689
/proc/meminfo: memFree=5728/1048576 swapFree=0/0
[pid=24679] ppid=24678 vsize=2576 CPUtime=0
/proc/24679/stat : 24679 (gj-user-solver-) S 24678 24679 17511 34816 17511 4202496 374 0 0 0 0 0 0 0 25 0 1 0 46314275 2637824 271 1283457024 134512640 135304128 4288230272 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24679/statm: 644 271 229 194 0 31 0
[pid=24680] ppid=24679 vsize=439956 CPUtime=6.27
/proc/24680/stat : 24680 (java) S 24679 24679 17511 34816 17511 4202496 78237 0 1 0 599 28 0 0 25 0 9 0 46314276 450514944 77470 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/24680/statm: 109989 77470 2902 10 0 104137 0
[pid=24680/tid=24682] ppid=24679 vsize=439956 CPUtime=2.26
/proc/24680/task/24682/stat : 24682 (java) R 24679 24679 17511 34816 17511 4202560 13878 0 1 0 221 5 0 0 25 0 9 0 46314276 450514944 77470 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=24680/tid=24683] ppid=24679 vsize=439956 CPUtime=3.92
/proc/24680/task/24683/stat : 24683 (java) R 24679 24679 17511 34816 17511 4202560 62948 0 0 0 372 20 0 0 16 0 9 0 46314277 450514944 77470 1283457024 134512640 134550932 4288258800 18446744073709551615 4152597019 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=24680/tid=24684] ppid=24679 vsize=439956 CPUtime=0
/proc/24680/task/24684/stat : 24684 (java) S 24679 24679 17511 34816 17511 4202560 15 0 0 0 0 0 0 0 20 0 9 0 46314277 450514944 77470 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24685] ppid=24679 vsize=439956 CPUtime=0
/proc/24680/task/24685/stat : 24685 (java) S 24679 24679 17511 34816 17511 4202560 5 0 0 0 0 0 0 0 20 0 9 0 46314277 450514944 77470 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24686] ppid=24679 vsize=439956 CPUtime=0
/proc/24680/task/24686/stat : 24686 (java) S 24679 24679 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 9 0 46314278 450514944 77470 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24687] ppid=24679 vsize=439956 CPUtime=0.05
/proc/24680/task/24687/stat : 24687 (java) S 24679 24679 17511 34816 17511 4202560 468 0 0 0 5 0 0 0 15 0 9 0 46314278 450514944 77470 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24688] ppid=24679 vsize=439956 CPUtime=0
/proc/24680/task/24688/stat : 24688 (java) S 24679 24679 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 9 0 46314278 450514944 77470 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24689] ppid=24679 vsize=439956 CPUtime=0
/proc/24680/task/24689/stat : 24689 (java) S 24679 24679 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 15 0 9 0 46314278 450514944 77470 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.27
Current children cumulated vsize (KiB) 442532

[startup+12.7122 s]
/proc/loadavg: 1.42 1.28 1.20 2/45 24690
/proc/meminfo: memFree=33540/1048576 swapFree=0/0
[pid=24679] ppid=24678 vsize=2576 CPUtime=0
/proc/24679/stat : 24679 (gj-user-solver-) S 24678 24679 17511 34816 17511 4202496 374 0 0 0 0 0 0 0 25 0 1 0 46314275 2637824 271 1283457024 134512640 135304128 4288230272 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24679/statm: 644 271 229 194 0 31 0
[pid=24680] ppid=24679 vsize=411892 CPUtime=12.66
/proc/24680/stat : 24680 (java) S 24679 24679 17511 34816 17511 4202496 100046 0 1 0 1229 37 0 0 25 0 10 0 46314276 421777408 70653 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/24680/statm: 102973 70653 2918 10 0 97118 0
[pid=24680/tid=24682] ppid=24679 vsize=411892 CPUtime=4.47
/proc/24680/task/24682/stat : 24682 (java) R 24679 24679 17511 34816 17511 4202560 14133 0 1 0 441 6 0 0 25 0 10 0 46314276 421777408 70653 1283457024 134512640 134550932 4288258800 18446744073709551615 4115669568 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=24680/tid=24683] ppid=24679 vsize=411892 CPUtime=8.05
/proc/24680/task/24683/stat : 24683 (java) S 24679 24679 17511 34816 17511 4202560 84422 0 0 0 776 29 0 0 16 0 10 0 46314277 421777408 70653 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 0 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24684] ppid=24679 vsize=411892 CPUtime=0
/proc/24680/task/24684/stat : 24684 (java) S 24679 24679 17511 34816 17511 4202560 15 0 0 0 0 0 0 0 15 0 10 0 46314277 421777408 70653 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24685] ppid=24679 vsize=411892 CPUtime=0
/proc/24680/task/24685/stat : 24685 (java) S 24679 24679 17511 34816 17511 4202560 5 0 0 0 0 0 0 0 18 0 10 0 46314277 421777408 70653 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24686] ppid=24679 vsize=411892 CPUtime=0
/proc/24680/task/24686/stat : 24686 (java) S 24679 24679 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46314278 421777408 70653 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24687] ppid=24679 vsize=411892 CPUtime=0.11
/proc/24680/task/24687/stat : 24687 (java) S 24679 24679 17511 34816 17511 4202560 543 0 0 0 11 0 0 0 15 0 10 0 46314278 421777408 70653 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24688] ppid=24679 vsize=411892 CPUtime=0
/proc/24680/task/24688/stat : 24688 (java) S 24679 24679 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46314278 421777408 70653 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24689] ppid=24679 vsize=411892 CPUtime=0
/proc/24680/task/24689/stat : 24689 (java) S 24679 24679 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 15 0 10 0 46314278 421777408 70653 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24690] ppid=24679 vsize=411892 CPUtime=0
/proc/24680/task/24690/stat : 24690 (java) S 24679 24679 17511 34816 17511 4202560 5 0 0 0 0 0 0 0 22 0 10 0 46315359 421777408 70653 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 12.66
Current children cumulated vsize (KiB) 414468

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

[startup+12.8122 s]
/proc/loadavg: 1.42 1.28 1.20 2/45 24690
/proc/meminfo: memFree=33540/1048576 swapFree=0/0
[pid=24679] ppid=24678 vsize=2576 CPUtime=0
/proc/24679/stat : 24679 (gj-user-solver-) S 24678 24679 17511 34816 17511 4202496 374 0 0 0 0 0 0 0 25 0 1 0 46314275 2637824 271 1283457024 134512640 135304128 4288230272 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24679/statm: 644 271 229 194 0 31 0
[pid=24680] ppid=24679 vsize=411892 CPUtime=12.76
/proc/24680/stat : 24680 (java) S 24679 24679 17511 34816 17511 4202496 100048 0 1 0 1239 37 0 0 25 0 10 0 46314276 421777408 70655 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/24680/statm: 102973 70655 2918 10 0 97118 0
[pid=24680/tid=24682] ppid=24679 vsize=411892 CPUtime=4.56
/proc/24680/task/24682/stat : 24682 (java) R 24679 24679 17511 34816 17511 4202560 14133 0 1 0 450 6 0 0 25 0 10 0 46314276 421777408 70655 1283457024 134512640 134550932 4288258800 18446744073709551615 4150521339 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=24680/tid=24683] ppid=24679 vsize=411892 CPUtime=8.05
/proc/24680/task/24683/stat : 24683 (java) S 24679 24679 17511 34816 17511 4202560 84422 0 0 0 776 29 0 0 16 0 10 0 46314277 421777408 70655 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 0 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24684] ppid=24679 vsize=411892 CPUtime=0
/proc/24680/task/24684/stat : 24684 (java) S 24679 24679 17511 34816 17511 4202560 15 0 0 0 0 0 0 0 15 0 10 0 46314277 421777408 70655 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24685] ppid=24679 vsize=411892 CPUtime=0
/proc/24680/task/24685/stat : 24685 (java) S 24679 24679 17511 34816 17511 4202560 5 0 0 0 0 0 0 0 18 0 10 0 46314277 421777408 70655 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24686] ppid=24679 vsize=411892 CPUtime=0
/proc/24680/task/24686/stat : 24686 (java) S 24679 24679 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46314278 421777408 70655 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24687] ppid=24679 vsize=411892 CPUtime=0.12
/proc/24680/task/24687/stat : 24687 (java) S 24679 24679 17511 34816 17511 4202560 545 0 0 0 12 0 0 0 15 0 10 0 46314278 421777408 70655 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24688] ppid=24679 vsize=411892 CPUtime=0
/proc/24680/task/24688/stat : 24688 (java) S 24679 24679 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46314278 421777408 70655 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24689] ppid=24679 vsize=411892 CPUtime=0
/proc/24680/task/24689/stat : 24689 (java) S 24679 24679 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 15 0 10 0 46314278 421777408 70655 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24690] ppid=24679 vsize=411892 CPUtime=0
/proc/24680/task/24690/stat : 24690 (java) S 24679 24679 17511 34816 17511 4202560 5 0 0 0 0 0 0 0 22 0 10 0 46315359 421777408 70655 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 12.76
Current children cumulated vsize (KiB) 414468

[startup+14.4126 s]
/proc/loadavg: 1.42 1.28 1.20 2/45 24690
/proc/meminfo: memFree=33540/1048576 swapFree=0/0
[pid=24679] ppid=24678 vsize=2576 CPUtime=0
/proc/24679/stat : 24679 (gj-user-solver-) S 24678 24679 17511 34816 17511 4202496 374 0 0 0 0 0 0 0 25 0 1 0 46314275 2637824 271 1283457024 134512640 135304128 4288230272 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24679/statm: 644 271 229 194 0 31 0
[pid=24680] ppid=24679 vsize=411892 CPUtime=14.36
/proc/24680/stat : 24680 (java) S 24679 24679 17511 34816 17511 4202496 100052 0 1 0 1399 37 0 0 25 0 10 0 46314276 421777408 70659 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/24680/statm: 102973 70659 2918 10 0 97118 0
[pid=24680/tid=24682] ppid=24679 vsize=411892 CPUtime=6.14
/proc/24680/task/24682/stat : 24682 (java) R 24679 24679 17511 34816 17511 4202560 14133 0 1 0 608 6 0 0 25 0 10 0 46314276 421777408 70659 1283457024 134512640 134550932 4288258800 18446744073709551615 4115813308 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=24680/tid=24683] ppid=24679 vsize=411892 CPUtime=8.05
/proc/24680/task/24683/stat : 24683 (java) S 24679 24679 17511 34816 17511 4202560 84422 0 0 0 776 29 0 0 16 0 10 0 46314277 421777408 70659 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 0 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24684] ppid=24679 vsize=411892 CPUtime=0
/proc/24680/task/24684/stat : 24684 (java) S 24679 24679 17511 34816 17511 4202560 15 0 0 0 0 0 0 0 15 0 10 0 46314277 421777408 70659 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24685] ppid=24679 vsize=411892 CPUtime=0
/proc/24680/task/24685/stat : 24685 (java) S 24679 24679 17511 34816 17511 4202560 5 0 0 0 0 0 0 0 18 0 10 0 46314277 421777408 70659 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24686] ppid=24679 vsize=411892 CPUtime=0
/proc/24680/task/24686/stat : 24686 (java) S 24679 24679 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46314278 421777408 70659 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24687] ppid=24679 vsize=411892 CPUtime=0.15
/proc/24680/task/24687/stat : 24687 (java) S 24679 24679 17511 34816 17511 4202560 549 0 0 0 15 0 0 0 15 0 10 0 46314278 421777408 70659 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24688] ppid=24679 vsize=411892 CPUtime=0
/proc/24680/task/24688/stat : 24688 (java) S 24679 24679 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46314278 421777408 70659 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24689] ppid=24679 vsize=411892 CPUtime=0
/proc/24680/task/24689/stat : 24689 (java) S 24679 24679 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 15 0 10 0 46314278 421777408 70659 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24690] ppid=24679 vsize=411892 CPUtime=0
/proc/24680/task/24690/stat : 24690 (java) S 24679 24679 17511 34816 17511 4202560 5 0 0 0 0 0 0 0 22 0 10 0 46315359 421777408 70659 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 14.36
Current children cumulated vsize (KiB) 414468

[startup+15.2128 s]
/proc/loadavg: 1.42 1.28 1.20 2/45 24690
/proc/meminfo: memFree=33540/1048576 swapFree=0/0
[pid=24679] ppid=24678 vsize=2576 CPUtime=0
/proc/24679/stat : 24679 (gj-user-solver-) S 24678 24679 17511 34816 17511 4202496 374 0 0 0 0 0 0 0 25 0 1 0 46314275 2637824 271 1283457024 134512640 135304128 4288230272 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24679/statm: 644 271 229 194 0 31 0
[pid=24680] ppid=24679 vsize=411892 CPUtime=15.16
/proc/24680/stat : 24680 (java) S 24679 24679 17511 34816 17511 4202496 100052 0 1 0 1479 37 0 0 25 0 10 0 46314276 421777408 70659 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/24680/statm: 102973 70659 2918 10 0 97118 0
[pid=24680/tid=24682] ppid=24679 vsize=411892 CPUtime=6.94
/proc/24680/task/24682/stat : 24682 (java) R 24679 24679 17511 34816 17511 4202560 14133 0 1 0 688 6 0 0 25 0 10 0 46314276 421777408 70659 1283457024 134512640 134550932 4288258800 18446744073709551615 4115813308 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=24680/tid=24683] ppid=24679 vsize=411892 CPUtime=8.05
/proc/24680/task/24683/stat : 24683 (java) S 24679 24679 17511 34816 17511 4202560 84422 0 0 0 776 29 0 0 15 0 10 0 46314277 421777408 70659 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 0 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24684] ppid=24679 vsize=411892 CPUtime=0
/proc/24680/task/24684/stat : 24684 (java) S 24679 24679 17511 34816 17511 4202560 15 0 0 0 0 0 0 0 15 0 10 0 46314277 421777408 70659 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24685] ppid=24679 vsize=411892 CPUtime=0
/proc/24680/task/24685/stat : 24685 (java) S 24679 24679 17511 34816 17511 4202560 5 0 0 0 0 0 0 0 18 0 10 0 46314277 421777408 70659 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24686] ppid=24679 vsize=411892 CPUtime=0
/proc/24680/task/24686/stat : 24686 (java) S 24679 24679 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46314278 421777408 70659 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24687] ppid=24679 vsize=411892 CPUtime=0.15
/proc/24680/task/24687/stat : 24687 (java) S 24679 24679 17511 34816 17511 4202560 549 0 0 0 15 0 0 0 15 0 10 0 46314278 421777408 70659 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24688] ppid=24679 vsize=411892 CPUtime=0
/proc/24680/task/24688/stat : 24688 (java) S 24679 24679 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46314278 421777408 70659 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24689] ppid=24679 vsize=411892 CPUtime=0
/proc/24680/task/24689/stat : 24689 (java) S 24679 24679 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 15 0 10 0 46314278 421777408 70659 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24690] ppid=24679 vsize=411892 CPUtime=0
/proc/24680/task/24690/stat : 24690 (java) S 24679 24679 17511 34816 17511 4202560 5 0 0 0 0 0 0 0 22 0 10 0 46315359 421777408 70659 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 15.16
Current children cumulated vsize (KiB) 414468

[startup+15.6123 s]
/proc/loadavg: 1.42 1.28 1.20 2/45 24690
/proc/meminfo: memFree=33540/1048576 swapFree=0/0
[pid=24679] ppid=24678 vsize=2576 CPUtime=0
/proc/24679/stat : 24679 (gj-user-solver-) S 24678 24679 17511 34816 17511 4202496 374 0 0 0 0 0 0 0 25 0 1 0 46314275 2637824 271 1283457024 134512640 135304128 4288230272 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24679/statm: 644 271 229 194 0 31 0
[pid=24680] ppid=24679 vsize=411892 CPUtime=15.55
/proc/24680/stat : 24680 (java) S 24679 24679 17511 34816 17511 4202496 100055 0 1 0 1518 37 0 0 25 0 9 0 46314276 421777408 70662 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/24680/statm: 102973 70662 2921 10 0 97118 0
[pid=24680/tid=24682] ppid=24679 vsize=411892 CPUtime=7.32
/proc/24680/task/24682/stat : 24682 (java) S 24679 24679 17511 34816 17511 4202560 14133 0 1 0 726 6 0 0 25 0 9 0 46314276 421777408 70662 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24683] ppid=24679 vsize=411892 CPUtime=8.06
/proc/24680/task/24683/stat : 24683 (java) S 24679 24679 17511 34816 17511 4202560 84424 0 0 0 777 29 0 0 16 0 9 0 46314277 421777408 70662 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 0 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24684] ppid=24679 vsize=411892 CPUtime=0
/proc/24680/task/24684/stat : 24684 (java) S 24679 24679 17511 34816 17511 4202560 15 0 0 0 0 0 0 0 15 0 9 0 46314277 421777408 70662 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24685] ppid=24679 vsize=411892 CPUtime=0
/proc/24680/task/24685/stat : 24685 (java) S 24679 24679 17511 34816 17511 4202560 5 0 0 0 0 0 0 0 18 0 9 0 46314277 421777408 70662 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24686] ppid=24679 vsize=411892 CPUtime=0
/proc/24680/task/24686/stat : 24686 (java) S 24679 24679 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 9 0 46314278 421777408 70662 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24687] ppid=24679 vsize=411892 CPUtime=0.15
/proc/24680/task/24687/stat : 24687 (java) S 24679 24679 17511 34816 17511 4202560 549 0 0 0 15 0 0 0 15 0 9 0 46314278 421777408 70662 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24688] ppid=24679 vsize=411892 CPUtime=0
/proc/24680/task/24688/stat : 24688 (java) S 24679 24679 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 9 0 46314278 421777408 70662 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=24680/tid=24689] ppid=24679 vsize=411892 CPUtime=0
/proc/24680/task/24689/stat : 24689 (java) S 24679 24679 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 15 0 9 0 46314278 421777408 70662 1283457024 134512640 134550932 4288258800 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 15.55
Current children cumulated vsize (KiB) 414468

Child status: 0
Real time (s): 15.6801
CPU time (s): 15.581
CPU user time (s): 15.1849
CPU system time (s): 0.396024
CPU usage (%): 99.3677
Max. virtual memory (cumulated for all children) (KiB): 442532

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 15.1849
system time used= 0.396024
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 100444
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= 1072
involuntary context switches= 1259

runsolver used 0 second user time and 0 second system time

The end