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.cudf.sarge-etch.log.runsolver ./gj-paranoid-solver-0.1 /home/misc2010/data/icse/sarge-etch/rand180.sarge-etch.cudf /home/misc2010/tmp/201012061533/gj-paranoid-solver-0.1/rand180.sarge-etch.cudf.sarge-etch.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.29 1.10 1.08 5/47 9503
/proc/meminfo: memFree=790120/1048576 swapFree=2078740/2097144
[pid=9501] ppid=9500 vsize=2568 CPUtime=0
/proc/9501/stat : 9501 (gj-paranoid-sol) S 9500 9501 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 18 0 1 0 875112638 2629632 272 1283457024 134512640 135304128 4288166784 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9501/statm: 642 272 232 194 0 28 0
[pid=9502] ppid=9501 vsize=11244 CPUtime=0
/proc/9502/stat : 9502 (java) R 9501 9501 2059 34821 2220 4202496 908 0 0 0 0 0 0 0 25 0 2 0 875112638 11513856 642 1283457024 134512640 134550932 4287183344 18446744073709551615 4159832312 0 0 0 0 18446744073709551615 0 0 17 0 0 0 0
/proc/9502/statm: 2811 642 285 10 0 1185 0
[pid=9502/tid=9503] ppid=9501 vsize=11244 CPUtime=0
/proc/9502/task/9503/stat : 9503 (java) R 9501 9501 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 25 0 2 0 875112638 11513856 642 1283457024 134512640 134550932 4287183344 18446744073709551615 4159832312 0 0 0 0 0 0 0 -1 0 0 0 0

[startup+0.215057 s]
/proc/loadavg: 1.29 1.10 1.08 5/47 9503
/proc/meminfo: memFree=790120/1048576 swapFree=2078740/2097144
[pid=9501] ppid=9500 vsize=2568 CPUtime=0
/proc/9501/stat : 9501 (gj-paranoid-sol) S 9500 9501 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 18 0 1 0 875112638 2629632 272 1283457024 134512640 135304128 4288166784 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9501/statm: 642 272 232 194 0 28 0
[pid=9502] ppid=9501 vsize=409996 CPUtime=0.21
/proc/9502/stat : 9502 (java) S 9501 9501 2059 34821 2220 4202496 5170 0 1 0 19 2 0 0 25 0 9 0 875112638 419835904 4634 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9502/statm: 102499 4634 1883 10 0 96679 0
[pid=9502/tid=9503] ppid=9501 vsize=409996 CPUtime=0.17
/proc/9502/task/9503/stat : 9503 (java) R 9501 9501 2059 34821 2220 4202560 3376 0 1 0 15 2 0 0 25 0 9 0 875112638 419835904 4634 1283457024 134512640 134550932 4287183344 18446744073709551615 4115312766 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 0.21
Current children cumulated vsize (KiB) 412564

[startup+0.305075 s]
/proc/loadavg: 1.29 1.10 1.08 5/47 9503
/proc/meminfo: memFree=790120/1048576 swapFree=2078740/2097144
[pid=9501] ppid=9500 vsize=2568 CPUtime=0
/proc/9501/stat : 9501 (gj-paranoid-sol) S 9500 9501 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 18 0 1 0 875112638 2629632 272 1283457024 134512640 135304128 4288166784 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9501/statm: 642 272 232 194 0 28 0
[pid=9502] ppid=9501 vsize=409996 CPUtime=0.3
/proc/9502/stat : 9502 (java) S 9501 9501 2059 34821 2220 4202496 5171 0 1 0 28 2 0 0 25 0 9 0 875112638 419835904 4635 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9502/statm: 102499 4635 1883 10 0 96679 0
[pid=9502/tid=9503] ppid=9501 vsize=409996 CPUtime=0.26
/proc/9502/task/9503/stat : 9503 (java) R 9501 9501 2059 34821 2220 4202560 3377 0 1 0 24 2 0 0 25 0 9 0 875112638 419835904 4635 1283457024 134512640 134550932 4287183344 18446744073709551615 4115314028 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 0.3
Current children cumulated vsize (KiB) 412564

[startup+0.405106 s]
/proc/loadavg: 1.29 1.10 1.08 5/47 9503
/proc/meminfo: memFree=790120/1048576 swapFree=2078740/2097144
[pid=9501] ppid=9500 vsize=2568 CPUtime=0
/proc/9501/stat : 9501 (gj-paranoid-sol) S 9500 9501 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 18 0 1 0 875112638 2629632 272 1283457024 134512640 135304128 4288166784 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9501/statm: 642 272 232 194 0 28 0
[pid=9502] ppid=9501 vsize=410612 CPUtime=0.4
/proc/9502/stat : 9502 (java) S 9501 9501 2059 34821 2220 4202496 6150 0 1 0 38 2 0 0 25 0 9 0 875112638 420466688 5614 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9502/statm: 102653 5614 1890 10 0 96833 0
[pid=9502/tid=9503] ppid=9501 vsize=410612 CPUtime=0.33
/proc/9502/task/9503/stat : 9503 (java) R 9501 9501 2059 34821 2220 4202560 3379 0 1 0 31 2 0 0 25 0 9 0 875112638 420466688 5614 1283457024 134512640 134550932 4287183344 18446744073709551615 4115750800 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 0.4
Current children cumulated vsize (KiB) 413180

[startup+0.705226 s]
/proc/loadavg: 1.29 1.10 1.08 5/47 9503
/proc/meminfo: memFree=790120/1048576 swapFree=2078740/2097144
[pid=9501] ppid=9500 vsize=2568 CPUtime=0
/proc/9501/stat : 9501 (gj-paranoid-sol) S 9500 9501 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 18 0 1 0 875112638 2629632 272 1283457024 134512640 135304128 4288166784 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9501/statm: 642 272 232 194 0 28 0
[pid=9502] ppid=9501 vsize=410744 CPUtime=0.7
/proc/9502/stat : 9502 (java) S 9501 9501 2059 34821 2220 4202496 12832 0 1 0 66 4 0 0 25 0 9 0 875112638 420601856 12118 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9502/statm: 102686 12118 2878 10 0 96866 0
[pid=9502/tid=9503] ppid=9501 vsize=410744 CPUtime=0.43
/proc/9502/task/9503/stat : 9503 (java) R 9501 9501 2059 34821 2220 4202560 4067 0 1 0 41 2 0 0 25 0 9 0 875112638 420601856 12118 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 0.7
Current children cumulated vsize (KiB) 413312

[startup+1.50552 s]
/proc/loadavg: 1.34 1.12 1.09 3/55 9511
/proc/meminfo: memFree=717752/1048576 swapFree=2078740/2097144
[pid=9501] ppid=9500 vsize=2568 CPUtime=0
/proc/9501/stat : 9501 (gj-paranoid-sol) S 9500 9501 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 18 0 1 0 875112638 2629632 272 1283457024 134512640 135304128 4288166784 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9501/statm: 642 272 232 194 0 28 0
[pid=9502] ppid=9501 vsize=410744 CPUtime=1.5
/proc/9502/stat : 9502 (java) S 9501 9501 2059 34821 2220 4202496 28009 0 1 0 142 8 0 0 25 0 9 0 875112638 420601856 27295 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9502/statm: 102686 27295 2879 10 0 96866 0
[pid=9502/tid=9503] ppid=9501 vsize=410744 CPUtime=0.68
/proc/9502/task/9503/stat : 9503 (java) S 9501 9501 2059 34821 2220 4202560 6659 0 1 0 66 2 0 0 24 0 9 0 875112638 420601856 27295 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9502/tid=9505] ppid=9501 vsize=410744 CPUtime=0.77
/proc/9502/task/9505/stat : 9505 (java) R 9501 9501 2059 34821 2220 4202560 19960 0 0 0 71 6 0 0 20 0 9 0 875112639 420601856 27295 1283457024 134512640 134550932 4287183344 18446744073709551615 4151878130 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=9502/tid=9506] ppid=9501 vsize=410744 CPUtime=0
/proc/9502/task/9506/stat : 9506 (java) S 9501 9501 2059 34821 2220 4202560 18 0 0 0 0 0 0 0 20 0 9 0 875112640 420601856 27295 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9502/tid=9507] ppid=9501 vsize=410744 CPUtime=0
/proc/9502/task/9507/stat : 9507 (java) S 9501 9501 2059 34821 2220 4202560 6 0 0 0 0 0 0 0 24 0 9 0 875112640 420601856 27295 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9502/tid=9508] ppid=9501 vsize=410744 CPUtime=0
/proc/9502/task/9508/stat : 9508 (java) S 9501 9501 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 9 0 875112641 420601856 27295 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9502/tid=9509] ppid=9501 vsize=410744 CPUtime=0.04
/proc/9502/task/9509/stat : 9509 (java) S 9501 9501 2059 34821 2220 4202560 456 0 0 0 4 0 0 0 20 0 9 0 875112641 420601856 27295 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9502/tid=9510] ppid=9501 vsize=410744 CPUtime=0
/proc/9502/task/9510/stat : 9510 (java) S 9501 9501 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 9 0 875112641 420601856 27295 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9502/tid=9511] ppid=9501 vsize=410744 CPUtime=0
/proc/9502/task/9511/stat : 9511 (java) S 9501 9501 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 15 0 9 0 875112641 420601856 27295 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.5
Current children cumulated vsize (KiB) 413312

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

[startup+1.70559 s]
/proc/loadavg: 1.34 1.12 1.09 3/55 9511
/proc/meminfo: memFree=717752/1048576 swapFree=2078740/2097144
[pid=9501] ppid=9500 vsize=2568 CPUtime=0
/proc/9501/stat : 9501 (gj-paranoid-sol) S 9500 9501 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 18 0 1 0 875112638 2629632 272 1283457024 134512640 135304128 4288166784 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9501/statm: 642 272 232 194 0 28 0
[pid=9502] ppid=9501 vsize=410744 CPUtime=1.7
/proc/9502/stat : 9502 (java) S 9501 9501 2059 34821 2220 4202496 28055 0 1 0 162 8 0 0 25 0 9 0 875112638 420601856 27341 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9502/statm: 102686 27341 2880 10 0 96866 0
[pid=9502/tid=9503] ppid=9501 vsize=410744 CPUtime=0.7
/proc/9502/task/9503/stat : 9503 (java) R 9501 9501 2059 34821 2220 4202560 6661 0 1 0 68 2 0 0 22 0 9 0 875112638 420601856 27341 1283457024 134512640 134550932 4287183344 18446744073709551615 4151153678 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=9502/tid=9505] ppid=9501 vsize=410744 CPUtime=0.94
/proc/9502/task/9505/stat : 9505 (java) S 9501 9501 2059 34821 2220 4202560 20004 0 0 0 88 6 0 0 21 0 9 0 875112639 420601856 27341 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 0 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9502/tid=9506] ppid=9501 vsize=410744 CPUtime=0
/proc/9502/task/9506/stat : 9506 (java) S 9501 9501 2059 34821 2220 4202560 18 0 0 0 0 0 0 0 20 0 9 0 875112640 420601856 27341 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9502/tid=9507] ppid=9501 vsize=410744 CPUtime=0
/proc/9502/task/9507/stat : 9507 (java) S 9501 9501 2059 34821 2220 4202560 6 0 0 0 0 0 0 0 24 0 9 0 875112640 420601856 27341 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9502/tid=9508] ppid=9501 vsize=410744 CPUtime=0
/proc/9502/task/9508/stat : 9508 (java) S 9501 9501 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 9 0 875112641 420601856 27341 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9502/tid=9509] ppid=9501 vsize=410744 CPUtime=0.04
/proc/9502/task/9509/stat : 9509 (java) S 9501 9501 2059 34821 2220 4202560 456 0 0 0 4 0 0 0 20 0 9 0 875112641 420601856 27341 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9502/tid=9510] ppid=9501 vsize=410744 CPUtime=0
/proc/9502/task/9510/stat : 9510 (java) S 9501 9501 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 9 0 875112641 420601856 27341 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9502/tid=9511] ppid=9501 vsize=410744 CPUtime=0
/proc/9502/task/9511/stat : 9511 (java) S 9501 9501 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 15 0 9 0 875112641 420601856 27341 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.7
Current children cumulated vsize (KiB) 413312

[startup+2.10588 s]
/proc/loadavg: 1.34 1.12 1.09 3/55 9511
/proc/meminfo: memFree=717752/1048576 swapFree=2078740/2097144
[pid=9501] ppid=9500 vsize=2568 CPUtime=0
/proc/9501/stat : 9501 (gj-paranoid-sol) S 9500 9501 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 18 0 1 0 875112638 2629632 272 1283457024 134512640 135304128 4288166784 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9501/statm: 642 272 232 194 0 28 0
[pid=9502] ppid=9501 vsize=411068 CPUtime=2.09
/proc/9502/stat : 9502 (java) S 9501 9501 2059 34821 2220 4202496 34594 0 1 0 198 11 0 0 25 0 10 0 875112638 420933632 33864 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9502/statm: 102767 33864 2885 10 0 96947 0
[pid=9502/tid=9503] ppid=9501 vsize=411068 CPUtime=0.96
/proc/9502/task/9503/stat : 9503 (java) R 9501 9501 2059 34821 2220 4202560 9502 0 1 0 93 3 0 0 24 0 10 0 875112638 420933632 33864 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=9502/tid=9505] ppid=9501 vsize=411068 CPUtime=1.04
/proc/9502/task/9505/stat : 9505 (java) S 9501 9501 2059 34821 2220 4202560 23656 0 0 0 96 8 0 0 19 0 10 0 875112639 420933632 33864 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 0 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9502/tid=9506] ppid=9501 vsize=411068 CPUtime=0
/proc/9502/task/9506/stat : 9506 (java) S 9501 9501 2059 34821 2220 4202560 18 0 0 0 0 0 0 0 18 0 10 0 875112640 420933632 33864 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9502/tid=9507] ppid=9501 vsize=411068 CPUtime=0
/proc/9502/task/9507/stat : 9507 (java) S 9501 9501 2059 34821 2220 4202560 6 0 0 0 0 0 0 0 24 0 10 0 875112640 420933632 33864 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9502/tid=9508] ppid=9501 vsize=411068 CPUtime=0
/proc/9502/task/9508/stat : 9508 (java) S 9501 9501 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875112641 420933632 33864 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9502/tid=9509] ppid=9501 vsize=411068 CPUtime=0.08
/proc/9502/task/9509/stat : 9509 (java) S 9501 9501 2059 34821 2220 4202560 501 0 0 0 8 0 0 0 15 0 10 0 875112641 420933632 33864 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9502/tid=9510] ppid=9501 vsize=411068 CPUtime=0
/proc/9502/task/9510/stat : 9510 (java) S 9501 9501 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875112641 420933632 33864 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9502/tid=9511] ppid=9501 vsize=411068 CPUtime=0
/proc/9502/task/9511/stat : 9511 (java) S 9501 9501 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 15 0 10 0 875112641 420933632 33864 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 2.09
Current children cumulated vsize (KiB) 413636

[startup+2.20578 s]
/proc/loadavg: 1.34 1.12 1.09 3/55 9511
/proc/meminfo: memFree=717752/1048576 swapFree=2078740/2097144
[pid=9501] ppid=9500 vsize=2568 CPUtime=0
/proc/9501/stat : 9501 (gj-paranoid-sol) S 9500 9501 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 18 0 1 0 875112638 2629632 272 1283457024 134512640 135304128 4288166784 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9501/statm: 642 272 232 194 0 28 0
[pid=9502] ppid=9501 vsize=411068 CPUtime=2.19
/proc/9502/stat : 9502 (java) S 9501 9501 2059 34821 2220 4202496 34613 0 1 0 208 11 0 0 25 0 10 0 875112638 420933632 33883 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9502/statm: 102767 33883 2885 10 0 96947 0
[pid=9502/tid=9503] ppid=9501 vsize=411068 CPUtime=1.04
/proc/9502/task/9503/stat : 9503 (java) R 9501 9501 2059 34821 2220 4202560 9502 0 1 0 101 3 0 0 24 0 10 0 875112638 420933632 33883 1283457024 134512640 134550932 4287183344 18446744073709551615 4116124707 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=9502/tid=9505] ppid=9501 vsize=411068 CPUtime=1.04
/proc/9502/task/9505/stat : 9505 (java) S 9501 9501 2059 34821 2220 4202560 23656 0 0 0 96 8 0 0 19 0 10 0 875112639 420933632 33883 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 0 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9502/tid=9506] ppid=9501 vsize=411068 CPUtime=0
/proc/9502/task/9506/stat : 9506 (java) S 9501 9501 2059 34821 2220 4202560 18 0 0 0 0 0 0 0 18 0 10 0 875112640 420933632 33883 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9502/tid=9507] ppid=9501 vsize=411068 CPUtime=0
/proc/9502/task/9507/stat : 9507 (java) S 9501 9501 2059 34821 2220 4202560 6 0 0 0 0 0 0 0 24 0 10 0 875112640 420933632 33883 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9502/tid=9508] ppid=9501 vsize=411068 CPUtime=0
/proc/9502/task/9508/stat : 9508 (java) S 9501 9501 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875112641 420933632 33883 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9502/tid=9509] ppid=9501 vsize=411068 CPUtime=0.1
/proc/9502/task/9509/stat : 9509 (java) S 9501 9501 2059 34821 2220 4202560 516 0 0 0 10 0 0 0 15 0 10 0 875112641 420933632 33883 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9502/tid=9510] ppid=9501 vsize=411068 CPUtime=0
/proc/9502/task/9510/stat : 9510 (java) S 9501 9501 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875112641 420933632 33883 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9502/tid=9511] ppid=9501 vsize=411068 CPUtime=0
/proc/9502/task/9511/stat : 9511 (java) S 9501 9501 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 15 0 10 0 875112641 420933632 33883 1283457024 134512640 134550932 4287183344 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 2.19
Current children cumulated vsize (KiB) 413636

Child status: 0
Real time (s): 2.25994
CPU time (s): 2.24814
CPU user time (s): 2.12013
CPU system time (s): 0.128008
CPU usage (%): 99.478
Max. virtual memory (cumulated for all children) (KiB): 413636

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 2.12013
system time used= 0.128008
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 35013
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= 561
involuntary context switches= 563

runsolver used 0 second user time and 0 second system time

The end