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/201012061533/gj-paranoid-solver-0.1/rand180.sarge-etch-lenny-squeeze-sid.cudf.sarge-etch-lenny-squeeze-sid.log.runsolver ./gj-paranoid-solver-0.1 /home/misc2010/data/icse/sarge-etch-lenny-squeeze-sid/rand180.sarge-etch-lenny-squeeze-sid.cudf /home/misc2010/tmp/201012061533/gj-paranoid-solver-0.1/rand180.sarge-etch-lenny-squeeze-sid.cudf.sarge-etch-lenny-squeeze-sid.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.27 1.19 1.12 1/45 8751
/proc/meminfo: memFree=956640/1048576 swapFree=2078740/2097144
[pid=8751] ppid=8750 vsize=3028 CPUtime=0
/proc/8751/stat : 8751 (runsolver) D 8750 8751 2059 34821 2220 4202560 73 0 0 0 0 0 0 0 22 0 1 0 875031346 3100672 94 1283457024 134512640 134586868 4290221120 18446744073709551615 4294960130 0 0 0 24578 18446744071564332000 0 0 17 0 0 0 0
/proc/8751/statm: 757 94 62 19 0 55 0

[startup+0.184214 s]
/proc/loadavg: 1.27 1.19 1.12 1/45 8751
/proc/meminfo: memFree=956640/1048576 swapFree=2078740/2097144
[pid=8751] ppid=8750 vsize=2568 CPUtime=0
/proc/8751/stat : 8751 (gj-paranoid-sol) S 8750 8751 2059 34821 2220 4202496 364 0 11 0 0 0 0 0 23 0 1 0 875031346 2629632 272 1283457024 134512640 135304128 4291861104 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/8751/statm: 642 272 232 194 0 28 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2568

[startup+0.204198 s]
/proc/loadavg: 1.27 1.19 1.12 1/45 8751
/proc/meminfo: memFree=956640/1048576 swapFree=2078740/2097144
[pid=8751] ppid=8750 vsize=2568 CPUtime=0
/proc/8751/stat : 8751 (gj-paranoid-sol) S 8750 8751 2059 34821 2220 4202496 364 0 11 0 0 0 0 0 23 0 1 0 875031346 2629632 272 1283457024 134512640 135304128 4291861104 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/8751/statm: 642 272 232 194 0 28 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2568

[startup+0.304203 s]
/proc/loadavg: 1.27 1.19 1.12 1/45 8751
/proc/meminfo: memFree=956640/1048576 swapFree=2078740/2097144
[pid=8751] ppid=8750 vsize=2568 CPUtime=0
/proc/8751/stat : 8751 (gj-paranoid-sol) S 8750 8751 2059 34821 2220 4202496 364 0 11 0 0 0 0 0 23 0 1 0 875031346 2629632 272 1283457024 134512640 135304128 4291861104 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/8751/statm: 642 272 232 194 0 28 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2568

[startup+0.704286 s]
/proc/loadavg: 1.27 1.19 1.12 1/45 8751
/proc/meminfo: memFree=956640/1048576 swapFree=2078740/2097144
[pid=8751] ppid=8750 vsize=2568 CPUtime=0
/proc/8751/stat : 8751 (gj-paranoid-sol) S 8750 8751 2059 34821 2220 4202496 364 0 11 0 0 0 0 0 23 0 1 0 875031346 2629632 272 1283457024 134512640 135304128 4291861104 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/8751/statm: 642 272 232 194 0 28 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2568

[startup+1.50428 s]
/proc/loadavg: 1.27 1.19 1.12 3/55 8761
/proc/meminfo: memFree=928220/1048576 swapFree=2078740/2097144
[pid=8751] ppid=8750 vsize=2568 CPUtime=0
/proc/8751/stat : 8751 (gj-paranoid-sol) S 8750 8751 2059 34821 2220 4202496 364 0 11 0 0 0 0 0 23 0 1 0 875031346 2629632 272 1283457024 134512640 135304128 4291861104 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/8751/statm: 642 272 232 194 0 28 0
[pid=8753] ppid=8751 vsize=410744 CPUtime=0.39
/proc/8753/stat : 8753 (java) S 8751 8751 2059 34821 2220 4202496 8244 0 225 0 39 0 0 0 23 0 9 0 875031354 420601856 7892 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/8753/statm: 102686 7892 2175 10 0 96866 0
[pid=8753/tid=8754] ppid=8751 vsize=410744 CPUtime=0.28
/proc/8753/task/8754/stat : 8754 (java) S 8751 8751 2059 34821 2220 4202560 3236 0 142 0 28 0 0 0 25 0 9 0 875031374 420601856 7892 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8755] ppid=8751 vsize=410744 CPUtime=0.09
/proc/8753/task/8755/stat : 8755 (java) D 8751 8751 2059 34821 2220 4202560 3687 0 20 0 9 0 0 0 16 0 9 0 875031393 420601856 7892 1283457024 134512640 134550932 4291206528 18446744073709551615 4152923341 0 0 0 16800975 18446744071564332000 0 0 -1 0 0 0 0
[pid=8753/tid=8756] ppid=8751 vsize=410744 CPUtime=0
/proc/8753/task/8756/stat : 8756 (java) S 8751 8751 2059 34821 2220 4202560 15 0 1 0 0 0 0 0 19 0 9 0 875031398 420601856 7892 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8757] ppid=8751 vsize=410744 CPUtime=0
/proc/8753/task/8757/stat : 8757 (java) S 8751 8751 2059 34821 2220 4202560 6 0 0 0 0 0 0 0 20 0 9 0 875031398 420601856 7892 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8758] ppid=8751 vsize=410744 CPUtime=0
/proc/8753/task/8758/stat : 8758 (java) S 8751 8751 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 24 0 9 0 875031417 420601856 7892 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8759] ppid=8751 vsize=410744 CPUtime=0.01
/proc/8753/task/8759/stat : 8759 (java) S 8751 8751 2059 34821 2220 4202560 444 0 6 0 1 0 0 0 21 0 9 0 875031417 420601856 7892 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8760] ppid=8751 vsize=410744 CPUtime=0
/proc/8753/task/8760/stat : 8760 (java) S 8751 8751 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 9 0 875031417 420601856 7892 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8761] ppid=8751 vsize=410744 CPUtime=0
/proc/8753/task/8761/stat : 8761 (java) S 8751 8751 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 18 0 9 0 875031417 420601856 7892 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 0.39
Current children cumulated vsize (KiB) 413312

[startup+3.1044 s]
/proc/loadavg: 1.27 1.19 1.12 2/55 8761
/proc/meminfo: memFree=865536/1048576 swapFree=2078740/2097144
[pid=8751] ppid=8750 vsize=2568 CPUtime=0
/proc/8751/stat : 8751 (gj-paranoid-sol) S 8750 8751 2059 34821 2220 4202496 364 0 11 0 0 0 0 0 23 0 1 0 875031346 2629632 272 1283457024 134512640 135304128 4291861104 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/8751/statm: 642 272 232 194 0 28 0
[pid=8753] ppid=8751 vsize=410744 CPUtime=1.88
/proc/8753/stat : 8753 (java) S 8751 8751 2059 34821 2220 4202496 37560 0 238 0 179 9 0 0 23 0 9 0 875031354 420601856 37082 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/8753/statm: 102686 37082 2879 10 0 96866 0
[pid=8753/tid=8754] ppid=8751 vsize=410744 CPUtime=0.74
/proc/8753/task/8754/stat : 8754 (java) R 8751 8751 2059 34821 2220 4202560 9508 0 142 0 71 3 0 0 25 0 9 0 875031374 420601856 37082 1283457024 134512640 134550932 4291206528 18446744073709551615 4115719535 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=8753/tid=8755] ppid=8751 vsize=410744 CPUtime=1.1
/proc/8753/task/8755/stat : 8755 (java) S 8751 8751 2059 34821 2220 4202560 26720 0 33 0 105 5 0 0 16 0 9 0 875031393 420601856 37082 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 0 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8756] ppid=8751 vsize=410744 CPUtime=0
/proc/8753/task/8756/stat : 8756 (java) S 8751 8751 2059 34821 2220 4202560 15 0 1 0 0 0 0 0 15 0 9 0 875031398 420601856 37082 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8757] ppid=8751 vsize=410744 CPUtime=0
/proc/8753/task/8757/stat : 8757 (java) S 8751 8751 2059 34821 2220 4202560 6 0 0 0 0 0 0 0 20 0 9 0 875031398 420601856 37082 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8758] ppid=8751 vsize=410744 CPUtime=0
/proc/8753/task/8758/stat : 8758 (java) S 8751 8751 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 24 0 9 0 875031417 420601856 37082 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8759] ppid=8751 vsize=410744 CPUtime=0.02
/proc/8753/task/8759/stat : 8759 (java) S 8751 8751 2059 34821 2220 4202560 455 0 6 0 2 0 0 0 15 0 9 0 875031417 420601856 37082 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8760] ppid=8751 vsize=410744 CPUtime=0
/proc/8753/task/8760/stat : 8760 (java) S 8751 8751 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 9 0 875031417 420601856 37082 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8761] ppid=8751 vsize=410744 CPUtime=0
/proc/8753/task/8761/stat : 8761 (java) S 8751 8751 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 9 0 875031417 420601856 37082 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.88
Current children cumulated vsize (KiB) 413312
heavy processes:

[startup+6.31097 s]
/proc/loadavg: 1.41 1.22 1.13 3/55 8761
/proc/meminfo: memFree=660532/1048576 swapFree=2078740/2097144
[pid=8751] ppid=8750 vsize=2568 CPUtime=0
/proc/8751/stat : 8751 (gj-paranoid-sol) S 8750 8751 2059 34821 2220 4202496 364 0 11 0 0 0 0 0 23 0 1 0 875031346 2629632 272 1283457024 134512640 135304128 4291861104 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/8751/statm: 642 272 232 194 0 28 0
[pid=8753] ppid=8751 vsize=430940 CPUtime=4.94
/proc/8753/stat : 8753 (java) S 8751 8751 2059 34821 2220 4202496 75436 0 240 0 474 20 0 0 23 0 9 0 875031354 441282560 74942 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/8753/statm: 107735 74942 2880 10 0 101915 0
[pid=8753/tid=8754] ppid=8751 vsize=430940 CPUtime=1.58
/proc/8753/task/8754/stat : 8754 (java) R 8751 8751 2059 34821 2220 4202560 13974 0 144 0 153 5 0 0 25 0 9 0 875031374 441282560 74942 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=8753/tid=8755] ppid=8751 vsize=430940 CPUtime=3.3
/proc/8753/task/8755/stat : 8755 (java) R 8751 8751 2059 34821 2220 4202560 60099 0 33 0 316 14 0 0 16 0 9 0 875031393 441282560 74942 1283457024 134512640 134550932 4291206528 18446744073709551615 4152923659 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=8753/tid=8756] ppid=8751 vsize=430940 CPUtime=0
/proc/8753/task/8756/stat : 8756 (java) S 8751 8751 2059 34821 2220 4202560 15 0 1 0 0 0 0 0 15 0 9 0 875031398 441282560 74942 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8757] ppid=8751 vsize=430940 CPUtime=0
/proc/8753/task/8757/stat : 8757 (java) S 8751 8751 2059 34821 2220 4202560 6 0 0 0 0 0 0 0 18 0 9 0 875031398 441282560 74942 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8758] ppid=8751 vsize=430940 CPUtime=0
/proc/8753/task/8758/stat : 8758 (java) S 8751 8751 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 24 0 9 0 875031417 441282560 74942 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8759] ppid=8751 vsize=430940 CPUtime=0.04
/proc/8753/task/8759/stat : 8759 (java) S 8751 8751 2059 34821 2220 4202560 486 0 6 0 4 0 0 0 15 0 9 0 875031417 441282560 74942 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8760] ppid=8751 vsize=430940 CPUtime=0
/proc/8753/task/8760/stat : 8760 (java) S 8751 8751 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 9 0 875031417 441282560 74942 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8761] ppid=8751 vsize=430940 CPUtime=0
/proc/8753/task/8761/stat : 8761 (java) S 8751 8751 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 9 0 875031417 441282560 74942 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.94
Current children cumulated vsize (KiB) 433508
heavy processes:

[startup+12.7081 s]
/proc/loadavg: 1.37 1.22 1.13 2/56 8762
/proc/meminfo: memFree=628040/1048576 swapFree=2078740/2097144
[pid=8751] ppid=8750 vsize=2568 CPUtime=0
/proc/8751/stat : 8751 (gj-paranoid-sol) S 8750 8751 2059 34821 2220 4202496 364 0 11 0 0 0 0 0 23 0 1 0 875031346 2629632 272 1283457024 134512640 135304128 4291861104 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/8751/statm: 642 272 232 194 0 28 0
[pid=8753] ppid=8751 vsize=430608 CPUtime=11.31
/proc/8753/stat : 8753 (java) S 8751 8751 2059 34821 2220 4202496 80593 0 241 0 1109 22 0 0 23 0 10 0 875031354 440942592 75137 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/8753/statm: 107652 75137 2883 10 0 101832 0
[pid=8753/tid=8754] ppid=8751 vsize=430608 CPUtime=6.54
/proc/8753/task/8754/stat : 8754 (java) R 8751 8751 2059 34821 2220 4202560 13996 0 145 0 649 5 0 0 25 0 10 0 875031374 440942592 75137 1283457024 134512640 134550932 4291206528 18446744073709551615 4116088664 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=8753/tid=8755] ppid=8751 vsize=430608 CPUtime=4.65
/proc/8753/task/8755/stat : 8755 (java) S 8751 8751 2059 34821 2220 4202560 65194 0 33 0 450 15 0 0 15 0 10 0 875031393 440942592 75137 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 0 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8756] ppid=8751 vsize=430608 CPUtime=0
/proc/8753/task/8756/stat : 8756 (java) S 8751 8751 2059 34821 2220 4202560 15 0 1 0 0 0 0 0 15 0 10 0 875031398 440942592 75137 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8757] ppid=8751 vsize=430608 CPUtime=0
/proc/8753/task/8757/stat : 8757 (java) S 8751 8751 2059 34821 2220 4202560 6 0 0 0 0 0 0 0 18 0 10 0 875031398 440942592 75137 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8758] ppid=8751 vsize=430608 CPUtime=0
/proc/8753/task/8758/stat : 8758 (java) S 8751 8751 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 24 0 10 0 875031417 440942592 75137 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8759] ppid=8751 vsize=430608 CPUtime=0.09
/proc/8753/task/8759/stat : 8759 (java) S 8751 8751 2059 34821 2220 4202560 521 0 6 0 8 1 0 0 16 0 10 0 875031417 440942592 75137 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8760] ppid=8751 vsize=430608 CPUtime=0
/proc/8753/task/8760/stat : 8760 (java) S 8751 8751 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875031417 440942592 75137 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8761] ppid=8751 vsize=430608 CPUtime=0
/proc/8753/task/8761/stat : 8761 (java) S 8751 8751 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 10 0 875031417 440942592 75137 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8762] ppid=8751 vsize=430608 CPUtime=0
/proc/8753/task/8762/stat : 8762 (java) S 8751 8751 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 25 0 10 0 875032025 440942592 75137 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 11.31
Current children cumulated vsize (KiB) 433176

[startup+25.5112 s]
/proc/loadavg: 1.36 1.22 1.13 2/56 8762
/proc/meminfo: memFree=628164/1048576 swapFree=2078740/2097144
[pid=8751] ppid=8750 vsize=2568 CPUtime=0
/proc/8751/stat : 8751 (gj-paranoid-sol) S 8750 8751 2059 34821 2220 4202496 364 0 11 0 0 0 0 0 23 0 1 0 875031346 2629632 272 1283457024 134512640 135304128 4291861104 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/8751/statm: 642 272 232 194 0 28 0
[pid=8753] ppid=8751 vsize=430524 CPUtime=24.1
/proc/8753/stat : 8753 (java) S 8751 8751 2059 34821 2220 4202496 90260 0 241 0 2386 24 0 0 23 0 10 0 875031354 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/8753/statm: 107631 75102 2883 10 0 101811 0
[pid=8753/tid=8754] ppid=8751 vsize=430524 CPUtime=17.57
/proc/8753/task/8754/stat : 8754 (java) R 8751 8751 2059 34821 2220 4202560 13996 0 145 0 1752 5 0 0 25 0 10 0 875031374 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4116035976 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=8753/tid=8755] ppid=8751 vsize=430524 CPUtime=6.41
/proc/8753/task/8755/stat : 8755 (java) S 8751 8751 2059 34821 2220 4202560 74860 0 33 0 624 17 0 0 15 0 10 0 875031393 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 0 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8756] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8756/stat : 8756 (java) S 8751 8751 2059 34821 2220 4202560 15 0 1 0 0 0 0 0 15 0 10 0 875031398 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8757] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8757/stat : 8757 (java) S 8751 8751 2059 34821 2220 4202560 6 0 0 0 0 0 0 0 18 0 10 0 875031398 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8758] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8758/stat : 8758 (java) S 8751 8751 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 24 0 10 0 875031417 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8759] ppid=8751 vsize=430524 CPUtime=0.1
/proc/8753/task/8759/stat : 8759 (java) S 8751 8751 2059 34821 2220 4202560 522 0 6 0 9 1 0 0 15 0 10 0 875031417 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8760] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8760/stat : 8760 (java) S 8751 8751 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875031417 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8761] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8761/stat : 8761 (java) S 8751 8751 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 10 0 875031417 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8762] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8762/stat : 8762 (java) S 8751 8751 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 25 0 10 0 875032025 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 24.1
Current children cumulated vsize (KiB) 433092

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

[startup+25.6112 s]
/proc/loadavg: 1.36 1.22 1.13 2/56 8762
/proc/meminfo: memFree=628164/1048576 swapFree=2078740/2097144
[pid=8751] ppid=8750 vsize=2568 CPUtime=0
/proc/8751/stat : 8751 (gj-paranoid-sol) S 8750 8751 2059 34821 2220 4202496 364 0 11 0 0 0 0 0 23 0 1 0 875031346 2629632 272 1283457024 134512640 135304128 4291861104 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/8751/statm: 642 272 232 194 0 28 0
[pid=8753] ppid=8751 vsize=430524 CPUtime=24.2
/proc/8753/stat : 8753 (java) S 8751 8751 2059 34821 2220 4202496 90260 0 241 0 2396 24 0 0 23 0 10 0 875031354 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/8753/statm: 107631 75102 2883 10 0 101811 0
[pid=8753/tid=8754] ppid=8751 vsize=430524 CPUtime=17.67
/proc/8753/task/8754/stat : 8754 (java) R 8751 8751 2059 34821 2220 4202560 13996 0 145 0 1762 5 0 0 25 0 10 0 875031374 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4115957579 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=8753/tid=8755] ppid=8751 vsize=430524 CPUtime=6.41
/proc/8753/task/8755/stat : 8755 (java) S 8751 8751 2059 34821 2220 4202560 74860 0 33 0 624 17 0 0 15 0 10 0 875031393 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 0 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8756] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8756/stat : 8756 (java) S 8751 8751 2059 34821 2220 4202560 15 0 1 0 0 0 0 0 15 0 10 0 875031398 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8757] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8757/stat : 8757 (java) S 8751 8751 2059 34821 2220 4202560 6 0 0 0 0 0 0 0 18 0 10 0 875031398 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8758] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8758/stat : 8758 (java) S 8751 8751 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 24 0 10 0 875031417 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8759] ppid=8751 vsize=430524 CPUtime=0.1
/proc/8753/task/8759/stat : 8759 (java) S 8751 8751 2059 34821 2220 4202560 522 0 6 0 9 1 0 0 15 0 10 0 875031417 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8760] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8760/stat : 8760 (java) S 8751 8751 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875031417 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8761] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8761/stat : 8761 (java) S 8751 8751 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 10 0 875031417 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8762] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8762/stat : 8762 (java) S 8751 8751 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 25 0 10 0 875032025 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 24.2
Current children cumulated vsize (KiB) 433092

[startup+32.0123 s]
/proc/loadavg: 1.49 1.25 1.14 2/56 8762
/proc/meminfo: memFree=628164/1048576 swapFree=2078740/2097144
[pid=8751] ppid=8750 vsize=2568 CPUtime=0
/proc/8751/stat : 8751 (gj-paranoid-sol) S 8750 8751 2059 34821 2220 4202496 364 0 11 0 0 0 0 0 23 0 1 0 875031346 2629632 272 1283457024 134512640 135304128 4291861104 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/8751/statm: 642 272 232 194 0 28 0
[pid=8753] ppid=8751 vsize=430524 CPUtime=30.61
/proc/8753/stat : 8753 (java) S 8751 8751 2059 34821 2220 4202496 95093 0 241 0 3031 30 0 0 23 0 10 0 875031354 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/8753/statm: 107631 75102 2883 10 0 101811 0
[pid=8753/tid=8754] ppid=8751 vsize=430524 CPUtime=23.19
/proc/8753/task/8754/stat : 8754 (java) R 8751 8751 2059 34821 2220 4202560 13996 0 145 0 2314 5 0 0 25 0 10 0 875031374 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4116028231 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=8753/tid=8755] ppid=8751 vsize=430524 CPUtime=7.29
/proc/8753/task/8755/stat : 8755 (java) S 8751 8751 2059 34821 2220 4202560 79693 0 33 0 707 22 0 0 15 0 10 0 875031393 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 0 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8756] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8756/stat : 8756 (java) S 8751 8751 2059 34821 2220 4202560 15 0 1 0 0 0 0 0 15 0 10 0 875031398 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8757] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8757/stat : 8757 (java) S 8751 8751 2059 34821 2220 4202560 6 0 0 0 0 0 0 0 18 0 10 0 875031398 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8758] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8758/stat : 8758 (java) S 8751 8751 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 24 0 10 0 875031417 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8759] ppid=8751 vsize=430524 CPUtime=0.1
/proc/8753/task/8759/stat : 8759 (java) S 8751 8751 2059 34821 2220 4202560 522 0 6 0 9 1 0 0 15 0 10 0 875031417 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8760] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8760/stat : 8760 (java) S 8751 8751 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875031417 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8761] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8761/stat : 8761 (java) S 8751 8751 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 10 0 875031417 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8762] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8762/stat : 8762 (java) S 8751 8751 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 25 0 10 0 875032025 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 30.61
Current children cumulated vsize (KiB) 433092

[startup+35.2031 s]
/proc/loadavg: 1.45 1.25 1.14 3/56 8762
/proc/meminfo: memFree=628288/1048576 swapFree=2078740/2097144
[pid=8751] ppid=8750 vsize=2568 CPUtime=0
/proc/8751/stat : 8751 (gj-paranoid-sol) S 8750 8751 2059 34821 2220 4202496 364 0 11 0 0 0 0 0 23 0 1 0 875031346 2629632 272 1283457024 134512640 135304128 4291861104 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/8751/statm: 642 272 232 194 0 28 0
[pid=8753] ppid=8751 vsize=430524 CPUtime=33.78
/proc/8753/stat : 8753 (java) S 8751 8751 2059 34821 2220 4202496 99926 0 241 0 3346 32 0 0 23 0 10 0 875031354 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/8753/statm: 107631 75102 2883 10 0 101811 0
[pid=8753/tid=8754] ppid=8751 vsize=430524 CPUtime=25.8
/proc/8753/task/8754/stat : 8754 (java) R 8751 8751 2059 34821 2220 4202560 13996 0 145 0 2575 5 0 0 25 0 10 0 875031374 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=8753/tid=8755] ppid=8751 vsize=430524 CPUtime=7.86
/proc/8753/task/8755/stat : 8755 (java) R 8751 8751 2059 34821 2220 4202560 84526 0 33 0 761 25 0 0 16 0 10 0 875031393 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4152923627 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=8753/tid=8756] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8756/stat : 8756 (java) S 8751 8751 2059 34821 2220 4202560 15 0 1 0 0 0 0 0 15 0 10 0 875031398 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8757] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8757/stat : 8757 (java) S 8751 8751 2059 34821 2220 4202560 6 0 0 0 0 0 0 0 18 0 10 0 875031398 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8758] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8758/stat : 8758 (java) S 8751 8751 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 24 0 10 0 875031417 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8759] ppid=8751 vsize=430524 CPUtime=0.1
/proc/8753/task/8759/stat : 8759 (java) S 8751 8751 2059 34821 2220 4202560 522 0 6 0 9 1 0 0 15 0 10 0 875031417 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8760] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8760/stat : 8760 (java) S 8751 8751 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875031417 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8761] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8761/stat : 8761 (java) S 8751 8751 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 10 0 875031417 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8762] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8762/stat : 8762 (java) S 8751 8751 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 25 0 10 0 875032025 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 33.78
Current children cumulated vsize (KiB) 433092

[startup+36.0032 s]
/proc/loadavg: 1.45 1.25 1.14 3/56 8762
/proc/meminfo: memFree=628288/1048576 swapFree=2078740/2097144
[pid=8751] ppid=8750 vsize=2568 CPUtime=0
/proc/8751/stat : 8751 (gj-paranoid-sol) S 8750 8751 2059 34821 2220 4202496 364 0 11 0 0 0 0 0 23 0 1 0 875031346 2629632 272 1283457024 134512640 135304128 4291861104 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/8751/statm: 642 272 232 194 0 28 0
[pid=8753] ppid=8751 vsize=430524 CPUtime=34.58
/proc/8753/stat : 8753 (java) S 8751 8751 2059 34821 2220 4202496 99926 0 241 0 3426 32 0 0 23 0 10 0 875031354 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/8753/statm: 107631 75102 2883 10 0 101811 0
[pid=8753/tid=8754] ppid=8751 vsize=430524 CPUtime=26.26
/proc/8753/task/8754/stat : 8754 (java) R 8751 8751 2059 34821 2220 4202560 13996 0 145 0 2621 5 0 0 25 0 10 0 875031374 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4116025840 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=8753/tid=8755] ppid=8751 vsize=430524 CPUtime=8.2
/proc/8753/task/8755/stat : 8755 (java) S 8751 8751 2059 34821 2220 4202560 84526 0 33 0 795 25 0 0 16 0 10 0 875031393 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 0 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8756] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8756/stat : 8756 (java) S 8751 8751 2059 34821 2220 4202560 15 0 1 0 0 0 0 0 15 0 10 0 875031398 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8757] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8757/stat : 8757 (java) S 8751 8751 2059 34821 2220 4202560 6 0 0 0 0 0 0 0 18 0 10 0 875031398 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8758] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8758/stat : 8758 (java) S 8751 8751 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 24 0 10 0 875031417 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8759] ppid=8751 vsize=430524 CPUtime=0.1
/proc/8753/task/8759/stat : 8759 (java) S 8751 8751 2059 34821 2220 4202560 522 0 6 0 9 1 0 0 15 0 10 0 875031417 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8760] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8760/stat : 8760 (java) S 8751 8751 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875031417 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8761] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8761/stat : 8761 (java) S 8751 8751 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 10 0 875031417 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8762] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8762/stat : 8762 (java) S 8751 8751 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 25 0 10 0 875032025 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 34.58
Current children cumulated vsize (KiB) 433092

[startup+36.4033 s]
/proc/loadavg: 1.45 1.25 1.14 2/56 8762
/proc/meminfo: memFree=628288/1048576 swapFree=2078740/2097144
[pid=8751] ppid=8750 vsize=2568 CPUtime=0
/proc/8751/stat : 8751 (gj-paranoid-sol) S 8750 8751 2059 34821 2220 4202496 364 0 11 0 0 0 0 0 23 0 1 0 875031346 2629632 272 1283457024 134512640 135304128 4291861104 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/8751/statm: 642 272 232 194 0 28 0
[pid=8753] ppid=8751 vsize=430524 CPUtime=34.98
/proc/8753/stat : 8753 (java) S 8751 8751 2059 34821 2220 4202496 99926 0 241 0 3466 32 0 0 23 0 10 0 875031354 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/8753/statm: 107631 75102 2883 10 0 101811 0
[pid=8753/tid=8754] ppid=8751 vsize=430524 CPUtime=26.66
/proc/8753/task/8754/stat : 8754 (java) R 8751 8751 2059 34821 2220 4202560 13996 0 145 0 2661 5 0 0 25 0 10 0 875031374 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4116005556 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=8753/tid=8755] ppid=8751 vsize=430524 CPUtime=8.2
/proc/8753/task/8755/stat : 8755 (java) S 8751 8751 2059 34821 2220 4202560 84526 0 33 0 795 25 0 0 16 0 10 0 875031393 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 0 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8756] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8756/stat : 8756 (java) S 8751 8751 2059 34821 2220 4202560 15 0 1 0 0 0 0 0 15 0 10 0 875031398 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8757] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8757/stat : 8757 (java) S 8751 8751 2059 34821 2220 4202560 6 0 0 0 0 0 0 0 18 0 10 0 875031398 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8758] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8758/stat : 8758 (java) S 8751 8751 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 24 0 10 0 875031417 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8759] ppid=8751 vsize=430524 CPUtime=0.1
/proc/8753/task/8759/stat : 8759 (java) S 8751 8751 2059 34821 2220 4202560 522 0 6 0 9 1 0 0 15 0 10 0 875031417 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8760] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8760/stat : 8760 (java) S 8751 8751 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875031417 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8761] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8761/stat : 8761 (java) S 8751 8751 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 10 0 875031417 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8762] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8762/stat : 8762 (java) S 8751 8751 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 25 0 10 0 875032025 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 34.98
Current children cumulated vsize (KiB) 433092

[startup+36.8035 s]
/proc/loadavg: 1.45 1.25 1.14 2/56 8762
/proc/meminfo: memFree=628288/1048576 swapFree=2078740/2097144
[pid=8751] ppid=8750 vsize=2568 CPUtime=0
/proc/8751/stat : 8751 (gj-paranoid-sol) S 8750 8751 2059 34821 2220 4202496 364 0 11 0 0 0 0 0 23 0 1 0 875031346 2629632 272 1283457024 134512640 135304128 4291861104 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/8751/statm: 642 272 232 194 0 28 0
[pid=8753] ppid=8751 vsize=430524 CPUtime=35.38
/proc/8753/stat : 8753 (java) S 8751 8751 2059 34821 2220 4202496 99926 0 241 0 3506 32 0 0 23 0 10 0 875031354 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/8753/statm: 107631 75102 2883 10 0 101811 0
[pid=8753/tid=8754] ppid=8751 vsize=430524 CPUtime=27.06
/proc/8753/task/8754/stat : 8754 (java) R 8751 8751 2059 34821 2220 4202560 13996 0 145 0 2701 5 0 0 25 0 10 0 875031374 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4116006616 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=8753/tid=8755] ppid=8751 vsize=430524 CPUtime=8.2
/proc/8753/task/8755/stat : 8755 (java) S 8751 8751 2059 34821 2220 4202560 84526 0 33 0 795 25 0 0 15 0 10 0 875031393 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 0 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8756] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8756/stat : 8756 (java) S 8751 8751 2059 34821 2220 4202560 15 0 1 0 0 0 0 0 15 0 10 0 875031398 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8757] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8757/stat : 8757 (java) S 8751 8751 2059 34821 2220 4202560 6 0 0 0 0 0 0 0 18 0 10 0 875031398 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8758] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8758/stat : 8758 (java) S 8751 8751 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 24 0 10 0 875031417 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8759] ppid=8751 vsize=430524 CPUtime=0.1
/proc/8753/task/8759/stat : 8759 (java) S 8751 8751 2059 34821 2220 4202560 522 0 6 0 9 1 0 0 15 0 10 0 875031417 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8760] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8760/stat : 8760 (java) S 8751 8751 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875031417 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8761] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8761/stat : 8761 (java) S 8751 8751 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 10 0 875031417 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=8753/tid=8762] ppid=8751 vsize=430524 CPUtime=0
/proc/8753/task/8762/stat : 8762 (java) S 8751 8751 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 25 0 10 0 875032025 440856576 75102 1283457024 134512640 134550932 4291206528 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 35.38
Current children cumulated vsize (KiB) 433092

Child status: 0
Real time (s): 36.8923
CPU time (s): 35.4462
CPU user time (s): 35.0982
CPU system time (s): 0.348021
CPU usage (%): 96.0801
Max. virtual memory (cumulated for all children) (KiB): 433508

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 35.0982
system time used= 0.348021
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 100312
page faults= 252
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 1705
involuntary context switches= 1701

runsolver used 0 second user time and 0 second system time

The end