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/rand316.sarge-etch.cudf.sarge-etch.log.runsolver ./gj-paranoid-solver-0.1 /home/misc2010/data/icse/sarge-etch/rand316.sarge-etch.cudf /home/misc2010/tmp/201012061533/gj-paranoid-solver-0.1/rand316.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.27 1.15 1.10 5/46 12031
/proc/meminfo: memFree=732368/1048576 swapFree=2078820/2097144
[pid=12029] ppid=12028 vsize=2576 CPUtime=0
/proc/12029/stat : 12029 (gj-paranoid-sol) S 12028 12029 2059 34821 2220 4202496 377 0 0 0 0 0 0 0 18 0 1 0 875327079 2637824 273 1283457024 134512640 135304128 4290672112 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/12029/statm: 644 273 232 194 0 30 0
[pid=12030] ppid=12029 vsize=11248 CPUtime=0.01
/proc/12030/stat : 12030 (java) R 12029 12029 2059 34821 2220 4202496 911 0 0 0 1 0 0 0 25 0 2 0 875327079 11517952 643 1283457024 134512640 134550932 4286579040 18446744073709551615 4159774968 0 0 0 0 18446744073709551615 0 0 17 0 0 0 0
/proc/12030/statm: 2812 643 285 10 0 1186 0
[pid=12030/tid=12031] ppid=12029 vsize=11248 CPUtime=0
/proc/12030/task/12031/stat : 12031 (java) R 12029 12029 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 25 0 2 0 875327079 11517952 643 1283457024 134512640 134550932 4286579040 18446744073709551615 4159774968 0 0 0 0 0 0 0 -1 0 0 0 0

[startup+0.205284 s]
/proc/loadavg: 1.27 1.15 1.10 5/46 12031
/proc/meminfo: memFree=732368/1048576 swapFree=2078820/2097144
[pid=12029] ppid=12028 vsize=2576 CPUtime=0
/proc/12029/stat : 12029 (gj-paranoid-sol) S 12028 12029 2059 34821 2220 4202496 377 0 0 0 0 0 0 0 18 0 1 0 875327079 2637824 273 1283457024 134512640 135304128 4290672112 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/12029/statm: 644 273 232 194 0 30 0
[pid=12030] ppid=12029 vsize=410000 CPUtime=0.21
/proc/12030/stat : 12030 (java) S 12029 12029 2059 34821 2220 4202496 5173 0 1 0 19 2 0 0 25 0 9 0 875327079 419840000 4635 1283457024 134512640 134550932 4286579040 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/12030/statm: 102500 4635 1883 10 0 96680 0
[pid=12030/tid=12031] ppid=12029 vsize=410000 CPUtime=0.17
/proc/12030/task/12031/stat : 12031 (java) R 12029 12029 2059 34821 2220 4202560 3376 0 1 0 15 2 0 0 25 0 9 0 875327079 419840000 4635 1283457024 134512640 134550932 4286579040 18446744073709551615 4115254644 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) 412576

[startup+0.305326 s]
/proc/loadavg: 1.27 1.15 1.10 5/46 12031
/proc/meminfo: memFree=732368/1048576 swapFree=2078820/2097144
[pid=12029] ppid=12028 vsize=2576 CPUtime=0
/proc/12029/stat : 12029 (gj-paranoid-sol) S 12028 12029 2059 34821 2220 4202496 377 0 0 0 0 0 0 0 18 0 1 0 875327079 2637824 273 1283457024 134512640 135304128 4290672112 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/12029/statm: 644 273 232 194 0 30 0
[pid=12030] ppid=12029 vsize=410000 CPUtime=0.31
/proc/12030/stat : 12030 (java) S 12029 12029 2059 34821 2220 4202496 5174 0 1 0 29 2 0 0 25 0 9 0 875327079 419840000 4636 1283457024 134512640 134550932 4286579040 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/12030/statm: 102500 4636 1883 10 0 96680 0
[pid=12030/tid=12031] ppid=12029 vsize=410000 CPUtime=0.27
/proc/12030/task/12031/stat : 12031 (java) R 12029 12029 2059 34821 2220 4202560 3377 0 1 0 25 2 0 0 25 0 9 0 875327079 419840000 4636 1283457024 134512640 134550932 4286579040 18446744073709551615 4115256703 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 0.31
Current children cumulated vsize (KiB) 412576

[startup+0.405349 s]
/proc/loadavg: 1.27 1.15 1.10 5/46 12031
/proc/meminfo: memFree=732368/1048576 swapFree=2078820/2097144
[pid=12029] ppid=12028 vsize=2576 CPUtime=0
/proc/12029/stat : 12029 (gj-paranoid-sol) S 12028 12029 2059 34821 2220 4202496 377 0 0 0 0 0 0 0 18 0 1 0 875327079 2637824 273 1283457024 134512640 135304128 4290672112 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/12029/statm: 644 273 232 194 0 30 0
[pid=12030] ppid=12029 vsize=410616 CPUtime=0.41
/proc/12030/stat : 12030 (java) S 12029 12029 2059 34821 2220 4202496 6153 0 1 0 39 2 0 0 25 0 9 0 875327079 420470784 5615 1283457024 134512640 134550932 4286579040 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/12030/statm: 102654 5615 1890 10 0 96834 0
[pid=12030/tid=12031] ppid=12029 vsize=410616 CPUtime=0.34
/proc/12030/task/12031/stat : 12031 (java) R 12029 12029 2059 34821 2220 4202560 3379 0 1 0 32 2 0 0 25 0 9 0 875327079 420470784 5615 1283457024 134512640 134550932 4286579040 18446744073709551615 4151245104 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 0.41
Current children cumulated vsize (KiB) 413192

[startup+0.705442 s]
/proc/loadavg: 1.27 1.15 1.10 5/46 12031
/proc/meminfo: memFree=732368/1048576 swapFree=2078820/2097144
[pid=12029] ppid=12028 vsize=2576 CPUtime=0
/proc/12029/stat : 12029 (gj-paranoid-sol) S 12028 12029 2059 34821 2220 4202496 377 0 0 0 0 0 0 0 18 0 1 0 875327079 2637824 273 1283457024 134512640 135304128 4290672112 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/12029/statm: 644 273 232 194 0 30 0
[pid=12030] ppid=12029 vsize=410748 CPUtime=0.71
/proc/12030/stat : 12030 (java) S 12029 12029 2059 34821 2220 4202496 12835 0 1 0 67 4 0 0 25 0 9 0 875327079 420605952 12119 1283457024 134512640 134550932 4286579040 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/12030/statm: 102687 12119 2878 10 0 96867 0
[pid=12030/tid=12031] ppid=12029 vsize=410748 CPUtime=0.42
/proc/12030/task/12031/stat : 12031 (java) R 12029 12029 2059 34821 2220 4202560 4067 0 1 0 40 2 0 0 25 0 9 0 875327079 420605952 12119 1283457024 134512640 134550932 4286579040 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 0.71
Current children cumulated vsize (KiB) 413324

[startup+1.50569 s]
/proc/loadavg: 1.27 1.15 1.10 3/54 12039
/proc/meminfo: memFree=660248/1048576 swapFree=2078820/2097144
[pid=12029] ppid=12028 vsize=2576 CPUtime=0
/proc/12029/stat : 12029 (gj-paranoid-sol) S 12028 12029 2059 34821 2220 4202496 377 0 0 0 0 0 0 0 18 0 1 0 875327079 2637824 273 1283457024 134512640 135304128 4290672112 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/12029/statm: 644 273 232 194 0 30 0
[pid=12030] ppid=12029 vsize=410748 CPUtime=1.5
/proc/12030/stat : 12030 (java) S 12029 12029 2059 34821 2220 4202496 28012 0 1 0 142 8 0 0 25 0 9 0 875327079 420605952 27296 1283457024 134512640 134550932 4286579040 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/12030/statm: 102687 27296 2879 10 0 96867 0
[pid=12030/tid=12031] ppid=12029 vsize=410748 CPUtime=0.67
/proc/12030/task/12031/stat : 12031 (java) S 12029 12029 2059 34821 2220 4202560 6659 0 1 0 63 4 0 0 25 0 9 0 875327079 420605952 27296 1283457024 134512640 134550932 4286579040 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=12030/tid=12033] ppid=12029 vsize=410748 CPUtime=0.76
/proc/12030/task/12033/stat : 12033 (java) R 12029 12029 2059 34821 2220 4202560 19960 0 0 0 72 4 0 0 20 0 9 0 875327080 420605952 27296 1283457024 134512640 134550932 4286579040 18446744073709551615 4151820786 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=12030/tid=12034] ppid=12029 vsize=410748 CPUtime=0
/proc/12030/task/12034/stat : 12034 (java) S 12029 12029 2059 34821 2220 4202560 18 0 0 0 0 0 0 0 20 0 9 0 875327080 420605952 27296 1283457024 134512640 134550932 4286579040 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=12030/tid=12035] ppid=12029 vsize=410748 CPUtime=0
/proc/12030/task/12035/stat : 12035 (java) S 12029 12029 2059 34821 2220 4202560 6 0 0 0 0 0 0 0 24 0 9 0 875327080 420605952 27296 1283457024 134512640 134550932 4286579040 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=12030/tid=12036] ppid=12029 vsize=410748 CPUtime=0
/proc/12030/task/12036/stat : 12036 (java) S 12029 12029 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 9 0 875327082 420605952 27296 1283457024 134512640 134550932 4286579040 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=12030/tid=12037] ppid=12029 vsize=410748 CPUtime=0.04
/proc/12030/task/12037/stat : 12037 (java) S 12029 12029 2059 34821 2220 4202560 456 0 0 0 4 0 0 0 20 0 9 0 875327082 420605952 27296 1283457024 134512640 134550932 4286579040 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=12030/tid=12038] ppid=12029 vsize=410748 CPUtime=0
/proc/12030/task/12038/stat : 12038 (java) S 12029 12029 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 9 0 875327082 420605952 27296 1283457024 134512640 134550932 4286579040 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=12030/tid=12039] ppid=12029 vsize=410748 CPUtime=0
/proc/12030/task/12039/stat : 12039 (java) S 12029 12029 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 15 0 9 0 875327082 420605952 27296 1283457024 134512640 134550932 4286579040 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.5
Current children cumulated vsize (KiB) 413324

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

[startup+1.70574 s]
/proc/loadavg: 1.27 1.15 1.10 3/54 12039
/proc/meminfo: memFree=660248/1048576 swapFree=2078820/2097144
[pid=12029] ppid=12028 vsize=2576 CPUtime=0
/proc/12029/stat : 12029 (gj-paranoid-sol) S 12028 12029 2059 34821 2220 4202496 377 0 0 0 0 0 0 0 18 0 1 0 875327079 2637824 273 1283457024 134512640 135304128 4290672112 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/12029/statm: 644 273 232 194 0 30 0
[pid=12030] ppid=12029 vsize=410748 CPUtime=1.7
/proc/12030/stat : 12030 (java) S 12029 12029 2059 34821 2220 4202496 28070 0 1 0 162 8 0 0 25 0 9 0 875327079 420605952 27349 1283457024 134512640 134550932 4286579040 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/12030/statm: 102687 27349 2880 10 0 96867 0
[pid=12030/tid=12031] ppid=12029 vsize=410748 CPUtime=0.7
/proc/12030/task/12031/stat : 12031 (java) R 12029 12029 2059 34821 2220 4202560 6671 0 1 0 66 4 0 0 23 0 9 0 875327079 420605952 27349 1283457024 134512640 134550932 4286579040 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=12030/tid=12033] ppid=12029 vsize=410748 CPUtime=0.92
/proc/12030/task/12033/stat : 12033 (java) S 12029 12029 2059 34821 2220 4202560 20004 0 0 0 88 4 0 0 21 0 9 0 875327080 420605952 27349 1283457024 134512640 134550932 4286579040 18446744073709551615 4294960130 0 0 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=12030/tid=12034] ppid=12029 vsize=410748 CPUtime=0
/proc/12030/task/12034/stat : 12034 (java) S 12029 12029 2059 34821 2220 4202560 18 0 0 0 0 0 0 0 20 0 9 0 875327080 420605952 27349 1283457024 134512640 134550932 4286579040 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=12030/tid=12035] ppid=12029 vsize=410748 CPUtime=0
/proc/12030/task/12035/stat : 12035 (java) S 12029 12029 2059 34821 2220 4202560 6 0 0 0 0 0 0 0 24 0 9 0 875327080 420605952 27349 1283457024 134512640 134550932 4286579040 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=12030/tid=12036] ppid=12029 vsize=410748 CPUtime=0
/proc/12030/task/12036/stat : 12036 (java) S 12029 12029 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 9 0 875327082 420605952 27349 1283457024 134512640 134550932 4286579040 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=12030/tid=12037] ppid=12029 vsize=410748 CPUtime=0.05
/proc/12030/task/12037/stat : 12037 (java) R 12029 12029 2059 34821 2220 4202560 458 0 0 0 5 0 0 0 16 0 9 0 875327082 420605952 27349 1283457024 134512640 134550932 4286579040 18446744073709551615 4150818272 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=12030/tid=12038] ppid=12029 vsize=410748 CPUtime=0
/proc/12030/task/12038/stat : 12038 (java) S 12029 12029 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 9 0 875327082 420605952 27349 1283457024 134512640 134550932 4286579040 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=12030/tid=12039] ppid=12029 vsize=410748 CPUtime=0
/proc/12030/task/12039/stat : 12039 (java) S 12029 12029 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 15 0 9 0 875327082 420605952 27349 1283457024 134512640 134550932 4286579040 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.7
Current children cumulated vsize (KiB) 413324

[startup+2.10588 s]
/proc/loadavg: 1.27 1.15 1.10 3/54 12039
/proc/meminfo: memFree=660248/1048576 swapFree=2078820/2097144
[pid=12029] ppid=12028 vsize=2576 CPUtime=0
/proc/12029/stat : 12029 (gj-paranoid-sol) S 12028 12029 2059 34821 2220 4202496 377 0 0 0 0 0 0 0 18 0 1 0 875327079 2637824 273 1283457024 134512640 135304128 4290672112 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/12029/statm: 644 273 232 194 0 30 0
[pid=12030] ppid=12029 vsize=411072 CPUtime=2.1
/proc/12030/stat : 12030 (java) S 12029 12029 2059 34821 2220 4202496 34604 0 1 0 200 10 0 0 25 0 10 0 875327079 420937728 33872 1283457024 134512640 134550932 4286579040 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/12030/statm: 102768 33872 2885 10 0 96948 0
[pid=12030/tid=12031] ppid=12029 vsize=411072 CPUtime=0.96
/proc/12030/task/12031/stat : 12031 (java) R 12029 12029 2059 34821 2220 4202560 9496 0 1 0 92 4 0 0 25 0 10 0 875327079 420937728 33872 1283457024 134512640 134550932 4286579040 18446744073709551615 4116032207 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=12030/tid=12033] ppid=12029 vsize=411072 CPUtime=1.03
/proc/12030/task/12033/stat : 12033 (java) S 12029 12029 2059 34821 2220 4202560 23672 0 0 0 98 5 0 0 19 0 10 0 875327080 420937728 33872 1283457024 134512640 134550932 4286579040 18446744073709551615 4294960130 0 0 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=12030/tid=12034] ppid=12029 vsize=411072 CPUtime=0
/proc/12030/task/12034/stat : 12034 (java) S 12029 12029 2059 34821 2220 4202560 18 0 0 0 0 0 0 0 18 0 10 0 875327080 420937728 33872 1283457024 134512640 134550932 4286579040 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=12030/tid=12035] ppid=12029 vsize=411072 CPUtime=0
/proc/12030/task/12035/stat : 12035 (java) S 12029 12029 2059 34821 2220 4202560 6 0 0 0 0 0 0 0 24 0 10 0 875327080 420937728 33872 1283457024 134512640 134550932 4286579040 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=12030/tid=12036] ppid=12029 vsize=411072 CPUtime=0
/proc/12030/task/12036/stat : 12036 (java) S 12029 12029 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875327082 420937728 33872 1283457024 134512640 134550932 4286579040 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=12030/tid=12037] ppid=12029 vsize=411072 CPUtime=0.08
/proc/12030/task/12037/stat : 12037 (java) S 12029 12029 2059 34821 2220 4202560 498 0 0 0 8 0 0 0 15 0 10 0 875327082 420937728 33872 1283457024 134512640 134550932 4286579040 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=12030/tid=12038] ppid=12029 vsize=411072 CPUtime=0
/proc/12030/task/12038/stat : 12038 (java) S 12029 12029 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875327082 420937728 33872 1283457024 134512640 134550932 4286579040 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=12030/tid=12039] ppid=12029 vsize=411072 CPUtime=0
/proc/12030/task/12039/stat : 12039 (java) S 12029 12029 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 15 0 10 0 875327082 420937728 33872 1283457024 134512640 134550932 4286579040 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 2.1
Current children cumulated vsize (KiB) 413648

[startup+2.30595 s]
/proc/loadavg: 1.33 1.16 1.10 2/54 12040
/proc/meminfo: memFree=609152/1048576 swapFree=2078820/2097144
[pid=12029] ppid=12028 vsize=2576 CPUtime=0
/proc/12029/stat : 12029 (gj-paranoid-sol) S 12028 12029 2059 34821 2220 4202496 377 0 0 0 0 0 0 0 18 0 1 0 875327079 2637824 273 1283457024 134512640 135304128 4290672112 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/12029/statm: 644 273 232 194 0 30 0
[pid=12030] ppid=12029 vsize=411072 CPUtime=2.3
/proc/12030/stat : 12030 (java) S 12029 12029 2059 34821 2220 4202496 34633 0 1 0 220 10 0 0 25 0 9 0 875327079 420937728 33901 1283457024 134512640 134550932 4286579040 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/12030/statm: 102768 33901 2885 10 0 96948 0
[pid=12030/tid=12031] ppid=12029 vsize=411072 CPUtime=1.16
/proc/12030/task/12031/stat : 12031 (java) R 12029 12029 2059 34821 2220 4202560 9505 0 1 0 112 4 0 0 25 0 9 0 875327079 420937728 33901 1283457024 134512640 134550932 4286579040 18446744073709551615 4115862879 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=12030/tid=12033] ppid=12029 vsize=411072 CPUtime=1.03
/proc/12030/task/12033/stat : 12033 (java) S 12029 12029 2059 34821 2220 4202560 23672 0 0 0 98 5 0 0 19 0 9 0 875327080 420937728 33901 1283457024 134512640 134550932 4286579040 18446744073709551615 4294960130 0 0 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=12030/tid=12034] ppid=12029 vsize=411072 CPUtime=0
/proc/12030/task/12034/stat : 12034 (java) S 12029 12029 2059 34821 2220 4202560 18 0 0 0 0 0 0 0 18 0 9 0 875327080 420937728 33901 1283457024 134512640 134550932 4286579040 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=12030/tid=12035] ppid=12029 vsize=411072 CPUtime=0
/proc/12030/task/12035/stat : 12035 (java) S 12029 12029 2059 34821 2220 4202560 6 0 0 0 0 0 0 0 24 0 9 0 875327080 420937728 33901 1283457024 134512640 134550932 4286579040 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=12030/tid=12036] ppid=12029 vsize=411072 CPUtime=0
/proc/12030/task/12036/stat : 12036 (java) S 12029 12029 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 9 0 875327082 420937728 33901 1283457024 134512640 134550932 4286579040 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=12030/tid=12037] ppid=12029 vsize=411072 CPUtime=0.08
/proc/12030/task/12037/stat : 12037 (java) S 12029 12029 2059 34821 2220 4202560 514 0 0 0 8 0 0 0 15 0 9 0 875327082 420937728 33901 1283457024 134512640 134550932 4286579040 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=12030/tid=12038] ppid=12029 vsize=411072 CPUtime=0
/proc/12030/task/12038/stat : 12038 (java) S 12029 12029 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 9 0 875327082 420937728 33901 1283457024 134512640 134550932 4286579040 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=12030/tid=12039] ppid=12029 vsize=411072 CPUtime=0
/proc/12030/task/12039/stat : 12039 (java) S 12029 12029 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 15 0 9 0 875327082 420937728 33901 1283457024 134512640 134550932 4286579040 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 2.3
Current children cumulated vsize (KiB) 413648

Child status: 0
Real time (s): 2.38098
CPU time (s): 2.32414
CPU user time (s): 2.21614
CPU system time (s): 0.108006
CPU usage (%): 97.6128
Max. virtual memory (cumulated for all children) (KiB): 413648

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 2.21614
system time used= 0.108006
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 35030
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= 549
involuntary context switches= 547

runsolver used 0 second user time and 0 second system time

The end