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/201108251442/gj-paranoid-solver-1.0/rand519.cudf.user-upgrades.log.runsolver ./gj-paranoid-solver-1.0 /home/misc2010/data/2011/user-upgrades/rand519.cudf /home/misc2010/tmp/201108251442/gj-paranoid-solver-1.0/rand519.cudf.user-upgrades.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.60 1.38 1.17 5/36 20259
/proc/meminfo: memFree=279812/1048576 swapFree=0/0
[pid=20258] ppid=20257 vsize=2576 CPUtime=0
/proc/20258/stat : 20258 (gj-paranoid-sol) R 20257 20258 4778 34817 4778 4202496 356 0 0 0 0 0 0 0 25 0 1 0 11121919 2637824 270 1283457024 134512640 135304128 4291757824 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/20258/statm: 644 270 228 194 0 31 0
[pid=20259] ppid=20258 vsize=2576 CPUtime=0
/proc/20259/stat : 20259 (gj-paranoid-sol) R 20258 20258 4778 34817 4778 4202560 0 0 0 0 0 0 0 0 25 0 1 0 11121919 2637824 42 1283457024 134512640 135304128 4291757824 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/20259/statm: 644 42 0 194 0 31 0

[startup+0.185449 s]
/proc/loadavg: 1.60 1.38 1.17 5/36 20259
/proc/meminfo: memFree=279812/1048576 swapFree=0/0
[pid=20258] ppid=20257 vsize=2576 CPUtime=0
/proc/20258/stat : 20258 (gj-paranoid-sol) S 20257 20258 4778 34817 4778 4202496 373 0 0 0 0 0 0 0 25 0 1 0 11121919 2637824 271 1283457024 134512640 135304128 4291757824 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/20258/statm: 644 271 229 194 0 31 0
[pid=20259] ppid=20258 vsize=409800 CPUtime=0.19
/proc/20259/stat : 20259 (java) S 20258 20258 4778 34817 4778 4202496 4033 0 1 0 15 4 0 0 25 0 9 0 11121919 419635200 3461 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/20259/statm: 102450 3461 1922 10 0 96598 0
Current children cumulated CPU time (s) 0.19
Current children cumulated vsize (KiB) 412376

[startup+0.205393 s]
/proc/loadavg: 1.60 1.38 1.17 5/36 20259
/proc/meminfo: memFree=279812/1048576 swapFree=0/0
[pid=20258] ppid=20257 vsize=2576 CPUtime=0
/proc/20258/stat : 20258 (gj-paranoid-sol) S 20257 20258 4778 34817 4778 4202496 373 0 0 0 0 0 0 0 25 0 1 0 11121919 2637824 271 1283457024 134512640 135304128 4291757824 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/20258/statm: 644 271 229 194 0 31 0
[pid=20259] ppid=20258 vsize=409800 CPUtime=0.21
/proc/20259/stat : 20259 (java) S 20258 20258 4778 34817 4778 4202496 4079 0 1 0 17 4 0 0 25 0 9 0 11121919 419635200 3507 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/20259/statm: 102450 3507 1922 10 0 96598 0
Current children cumulated CPU time (s) 0.21
Current children cumulated vsize (KiB) 412376

[startup+0.305422 s]
/proc/loadavg: 1.60 1.38 1.17 5/36 20259
/proc/meminfo: memFree=279812/1048576 swapFree=0/0
[pid=20258] ppid=20257 vsize=2576 CPUtime=0
/proc/20258/stat : 20258 (gj-paranoid-sol) S 20257 20258 4778 34817 4778 4202496 373 0 0 0 0 0 0 0 25 0 1 0 11121919 2637824 271 1283457024 134512640 135304128 4291757824 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/20258/statm: 644 271 229 194 0 31 0
[pid=20259] ppid=20258 vsize=410248 CPUtime=0.3
/proc/20259/stat : 20259 (java) S 20258 20258 4778 34817 4778 4202496 4420 0 1 0 26 4 0 0 25 0 9 0 11121919 420093952 3848 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/20259/statm: 102562 3848 1944 10 0 96710 0
Current children cumulated CPU time (s) 0.3
Current children cumulated vsize (KiB) 412824

[startup+0.705561 s]
/proc/loadavg: 1.60 1.38 1.17 5/36 20259
/proc/meminfo: memFree=279812/1048576 swapFree=0/0
[pid=20258] ppid=20257 vsize=2576 CPUtime=0
/proc/20258/stat : 20258 (gj-paranoid-sol) S 20257 20258 4778 34817 4778 4202496 373 0 0 0 0 0 0 0 25 0 1 0 11121919 2637824 271 1283457024 134512640 135304128 4291757824 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/20258/statm: 644 271 229 194 0 31 0
[pid=20259] ppid=20258 vsize=410688 CPUtime=0.7
/proc/20259/stat : 20259 (java) S 20258 20258 4778 34817 4778 4202496 11809 0 1 0 63 7 0 0 25 0 9 0 11121919 420544512 11050 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/20259/statm: 102672 11050 2901 10 0 96820 0
Current children cumulated CPU time (s) 0.7
Current children cumulated vsize (KiB) 413264

[startup+1.50579 s]
/proc/loadavg: 1.60 1.38 1.17 4/45 20268
/proc/meminfo: memFree=221448/1048576 swapFree=0/0
[pid=20258] ppid=20257 vsize=2576 CPUtime=0
/proc/20258/stat : 20258 (gj-paranoid-sol) S 20257 20258 4778 34817 4778 4202496 373 0 0 0 0 0 0 0 25 0 1 0 11121919 2637824 271 1283457024 134512640 135304128 4291757824 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/20258/statm: 644 271 229 194 0 31 0
[pid=20259] ppid=20258 vsize=410688 CPUtime=1.5
/proc/20259/stat : 20259 (java) S 20258 20258 4778 34817 4778 4202496 26956 0 1 0 137 13 0 0 25 0 9 0 11121919 420544512 26197 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/20259/statm: 102672 26197 2901 10 0 96820 0
[pid=20259/tid=20261] ppid=20258 vsize=410688 CPUtime=0.75
/proc/20259/task/20261/stat : 20261 (java) R 20258 20258 4778 34817 4778 4202560 6704 0 1 0 73 2 0 0 25 0 9 0 11121920 420544512 26197 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=20259/tid=20262] ppid=20258 vsize=410688 CPUtime=0.68
/proc/20259/task/20262/stat : 20262 (java) R 20258 20258 4778 34817 4778 4202560 18859 0 0 0 58 10 0 0 18 0 9 0 11121920 420544512 26197 1283457024 134512640 134550932 4286794128 18446744073709551615 4150952082 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=20259/tid=20263] ppid=20258 vsize=410688 CPUtime=0
/proc/20259/task/20263/stat : 20263 (java) S 20258 20258 4778 34817 4778 4202560 15 0 0 0 0 0 0 0 20 0 9 0 11121921 420544512 26197 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20264] ppid=20258 vsize=410688 CPUtime=0
/proc/20259/task/20264/stat : 20264 (java) S 20258 20258 4778 34817 4778 4202560 5 0 0 0 0 0 0 0 20 0 9 0 11121921 420544512 26197 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20265] ppid=20258 vsize=410688 CPUtime=0
/proc/20259/task/20265/stat : 20265 (java) S 20258 20258 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 9 0 11121922 420544512 26197 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20266] ppid=20258 vsize=410688 CPUtime=0.06
/proc/20259/task/20266/stat : 20266 (java) S 20258 20258 4778 34817 4778 4202560 452 0 0 0 6 0 0 0 20 0 9 0 11121922 420544512 26197 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20267] ppid=20258 vsize=410688 CPUtime=0
/proc/20259/task/20267/stat : 20267 (java) S 20258 20258 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 9 0 11121922 420544512 26197 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20268] ppid=20258 vsize=410688 CPUtime=0
/proc/20259/task/20268/stat : 20268 (java) S 20258 20258 4778 34817 4778 4202560 2 0 0 0 0 0 0 0 15 0 9 0 11121922 420544512 26197 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.5
Current children cumulated vsize (KiB) 413264

[startup+3.10624 s]
/proc/loadavg: 1.60 1.38 1.17 2/45 20268
/proc/meminfo: memFree=149660/1048576 swapFree=0/0
[pid=20258] ppid=20257 vsize=2576 CPUtime=0
/proc/20258/stat : 20258 (gj-paranoid-sol) S 20257 20258 4778 34817 4778 4202496 373 0 0 0 0 0 0 0 25 0 1 0 11121919 2637824 271 1283457024 134512640 135304128 4291757824 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/20258/statm: 644 271 229 194 0 31 0
[pid=20259] ppid=20258 vsize=410820 CPUtime=3.1
/proc/20259/stat : 20259 (java) S 20258 20258 4778 34817 4778 4202496 50497 0 1 0 287 23 0 0 25 0 9 0 11121919 420679680 49738 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/20259/statm: 102705 49738 2901 10 0 96853 0
[pid=20259/tid=20261] ppid=20258 vsize=410820 CPUtime=1.37
/proc/20259/task/20261/stat : 20261 (java) R 20258 20258 4778 34817 4778 4202560 13857 0 1 0 132 5 0 0 25 0 9 0 11121920 420679680 49738 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=20259/tid=20262] ppid=20258 vsize=410820 CPUtime=1.64
/proc/20259/task/20262/stat : 20262 (java) R 20258 20258 4778 34817 4778 4202560 35244 0 0 0 147 17 0 0 16 0 9 0 11121920 420679680 49738 1283457024 134512640 134550932 4286794128 18446744073709551615 4150572984 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=20259/tid=20263] ppid=20258 vsize=410820 CPUtime=0
/proc/20259/task/20263/stat : 20263 (java) S 20258 20258 4778 34817 4778 4202560 15 0 0 0 0 0 0 0 20 0 9 0 11121921 420679680 49738 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20264] ppid=20258 vsize=410820 CPUtime=0
/proc/20259/task/20264/stat : 20264 (java) S 20258 20258 4778 34817 4778 4202560 5 0 0 0 0 0 0 0 20 0 9 0 11121921 420679680 49738 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20265] ppid=20258 vsize=410820 CPUtime=0
/proc/20259/task/20265/stat : 20265 (java) S 20258 20258 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 9 0 11121922 420679680 49738 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20266] ppid=20258 vsize=410820 CPUtime=0.07
/proc/20259/task/20266/stat : 20266 (java) S 20258 20258 4778 34817 4778 4202560 455 0 0 0 7 0 0 0 15 0 9 0 11121922 420679680 49738 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20267] ppid=20258 vsize=410820 CPUtime=0
/proc/20259/task/20267/stat : 20267 (java) S 20258 20258 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 9 0 11121922 420679680 49738 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20268] ppid=20258 vsize=410820 CPUtime=0
/proc/20259/task/20268/stat : 20268 (java) S 20258 20258 4778 34817 4778 4202560 2 0 0 0 0 0 0 0 15 0 9 0 11121922 420679680 49738 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.1
Current children cumulated vsize (KiB) 413396

[startup+6.30712 s]
/proc/loadavg: 1.55 1.38 1.17 2/45 20268
/proc/meminfo: memFree=12764/1048576 swapFree=0/0
[pid=20258] ppid=20257 vsize=2576 CPUtime=0
/proc/20258/stat : 20258 (gj-paranoid-sol) S 20257 20258 4778 34817 4778 4202496 373 0 0 0 0 0 0 0 25 0 1 0 11121919 2637824 271 1283457024 134512640 135304128 4291757824 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/20258/statm: 644 271 229 194 0 31 0
[pid=20259] ppid=20258 vsize=439992 CPUtime=6.3
/proc/20259/stat : 20259 (java) S 20258 20258 4778 34817 4778 4202496 78233 0 1 0 598 32 0 0 25 0 9 0 11121919 450551808 77468 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/20259/statm: 109998 77468 2902 10 0 104146 0
[pid=20259/tid=20261] ppid=20258 vsize=439992 CPUtime=2.23
/proc/20259/task/20261/stat : 20261 (java) R 20258 20258 4778 34817 4778 4202560 13874 0 1 0 215 8 0 0 25 0 9 0 11121920 450551808 77468 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=20259/tid=20262] ppid=20258 vsize=439992 CPUtime=3.95
/proc/20259/task/20262/stat : 20262 (java) R 20258 20258 4778 34817 4778 4202560 62945 0 0 0 373 22 0 0 16 0 9 0 11121920 450551808 77468 1283457024 134512640 134550932 4286794128 18446744073709551615 4152064569 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=20259/tid=20263] ppid=20258 vsize=439992 CPUtime=0
/proc/20259/task/20263/stat : 20263 (java) S 20258 20258 4778 34817 4778 4202560 15 0 0 0 0 0 0 0 20 0 9 0 11121921 450551808 77468 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20264] ppid=20258 vsize=439992 CPUtime=0
/proc/20259/task/20264/stat : 20264 (java) S 20258 20258 4778 34817 4778 4202560 5 0 0 0 0 0 0 0 20 0 9 0 11121921 450551808 77468 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20265] ppid=20258 vsize=439992 CPUtime=0
/proc/20259/task/20265/stat : 20265 (java) S 20258 20258 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 9 0 11121922 450551808 77468 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20266] ppid=20258 vsize=439992 CPUtime=0.09
/proc/20259/task/20266/stat : 20266 (java) S 20258 20258 4778 34817 4778 4202560 473 0 0 0 9 0 0 0 15 0 9 0 11121922 450551808 77468 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20267] ppid=20258 vsize=439992 CPUtime=0
/proc/20259/task/20267/stat : 20267 (java) S 20258 20258 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 9 0 11121922 450551808 77468 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20268] ppid=20258 vsize=439992 CPUtime=0
/proc/20259/task/20268/stat : 20268 (java) S 20258 20258 4778 34817 4778 4202560 2 0 0 0 0 0 0 0 15 0 9 0 11121922 450551808 77468 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.3
Current children cumulated vsize (KiB) 442568

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

[startup+6.40716 s]
/proc/loadavg: 1.55 1.38 1.17 2/45 20268
/proc/meminfo: memFree=12764/1048576 swapFree=0/0
[pid=20258] ppid=20257 vsize=2576 CPUtime=0
/proc/20258/stat : 20258 (gj-paranoid-sol) S 20257 20258 4778 34817 4778 4202496 373 0 0 0 0 0 0 0 25 0 1 0 11121919 2637824 271 1283457024 134512640 135304128 4291757824 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/20258/statm: 644 271 229 194 0 31 0
[pid=20259] ppid=20258 vsize=439992 CPUtime=6.4
/proc/20259/stat : 20259 (java) S 20258 20258 4778 34817 4778 4202496 78233 0 1 0 608 32 0 0 25 0 9 0 11121919 450551808 77468 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/20259/statm: 109998 77468 2902 10 0 104146 0
[pid=20259/tid=20261] ppid=20258 vsize=439992 CPUtime=2.23
/proc/20259/task/20261/stat : 20261 (java) R 20258 20258 4778 34817 4778 4202560 13874 0 1 0 215 8 0 0 25 0 9 0 11121920 450551808 77468 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=20259/tid=20262] ppid=20258 vsize=439992 CPUtime=4.05
/proc/20259/task/20262/stat : 20262 (java) R 20258 20258 4778 34817 4778 4202560 62945 0 0 0 383 22 0 0 16 0 9 0 11121920 450551808 77468 1283457024 134512640 134550932 4286794128 18446744073709551615 4150964830 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=20259/tid=20263] ppid=20258 vsize=439992 CPUtime=0
/proc/20259/task/20263/stat : 20263 (java) S 20258 20258 4778 34817 4778 4202560 15 0 0 0 0 0 0 0 20 0 9 0 11121921 450551808 77468 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20264] ppid=20258 vsize=439992 CPUtime=0
/proc/20259/task/20264/stat : 20264 (java) S 20258 20258 4778 34817 4778 4202560 5 0 0 0 0 0 0 0 20 0 9 0 11121921 450551808 77468 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20265] ppid=20258 vsize=439992 CPUtime=0
/proc/20259/task/20265/stat : 20265 (java) S 20258 20258 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 9 0 11121922 450551808 77468 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20266] ppid=20258 vsize=439992 CPUtime=0.09
/proc/20259/task/20266/stat : 20266 (java) S 20258 20258 4778 34817 4778 4202560 473 0 0 0 9 0 0 0 15 0 9 0 11121922 450551808 77468 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20267] ppid=20258 vsize=439992 CPUtime=0
/proc/20259/task/20267/stat : 20267 (java) S 20258 20258 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 9 0 11121922 450551808 77468 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20268] ppid=20258 vsize=439992 CPUtime=0
/proc/20259/task/20268/stat : 20268 (java) S 20258 20258 4778 34817 4778 4202560 2 0 0 0 0 0 0 0 15 0 9 0 11121922 450551808 77468 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.4
Current children cumulated vsize (KiB) 442568

[startup+9.62809 s]
/proc/loadavg: 1.59 1.39 1.17 3/45 20269
/proc/meminfo: memFree=5236/1048576 swapFree=0/0
[pid=20258] ppid=20257 vsize=2576 CPUtime=0
/proc/20258/stat : 20258 (gj-paranoid-sol) S 20257 20258 4778 34817 4778 4202496 373 0 0 0 0 0 0 0 25 0 1 0 11121919 2637824 271 1283457024 134512640 135304128 4291757824 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/20258/statm: 644 271 229 194 0 31 0
[pid=20259] ppid=20258 vsize=411416 CPUtime=9.62
/proc/20259/stat : 20259 (java) S 20258 20258 4778 34817 4778 4202496 92730 0 1 0 923 39 0 0 25 0 9 0 11121919 421289984 70531 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/20259/statm: 102854 70531 2916 10 0 96999 0
[pid=20259/tid=20261] ppid=20258 vsize=411416 CPUtime=2.73
/proc/20259/task/20261/stat : 20261 (java) R 20258 20258 4778 34817 4778 4202560 14102 0 1 0 264 9 0 0 25 0 9 0 11121920 421289984 70531 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=20259/tid=20262] ppid=20258 vsize=411416 CPUtime=6.75
/proc/20259/task/20262/stat : 20262 (java) R 20258 20258 4778 34817 4778 4202560 77193 0 0 0 647 28 0 0 15 0 9 0 11121920 421289984 70531 1283457024 134512640 134550932 4286794128 18446744073709551615 4152063975 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=20259/tid=20263] ppid=20258 vsize=411416 CPUtime=0
/proc/20259/task/20263/stat : 20263 (java) S 20258 20258 4778 34817 4778 4202560 15 0 0 0 0 0 0 0 18 0 9 0 11121921 421289984 70531 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20264] ppid=20258 vsize=411416 CPUtime=0
/proc/20259/task/20264/stat : 20264 (java) S 20258 20258 4778 34817 4778 4202560 5 0 0 0 0 0 0 0 18 0 9 0 11121921 421289984 70531 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20265] ppid=20258 vsize=411416 CPUtime=0
/proc/20259/task/20265/stat : 20265 (java) S 20258 20258 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 9 0 11121922 421289984 70531 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20266] ppid=20258 vsize=411416 CPUtime=0.11
/proc/20259/task/20266/stat : 20266 (java) S 20258 20258 4778 34817 4778 4202560 494 0 0 0 11 0 0 0 15 0 9 0 11121922 421289984 70531 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20267] ppid=20258 vsize=411416 CPUtime=0
/proc/20259/task/20267/stat : 20267 (java) S 20258 20258 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 9 0 11121922 421289984 70531 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20268] ppid=20258 vsize=411416 CPUtime=0
/proc/20259/task/20268/stat : 20268 (java) S 20258 20258 4778 34817 4778 4202560 2 0 0 0 0 0 0 0 15 0 9 0 11121922 421289984 70531 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 9.62
Current children cumulated vsize (KiB) 413992

[startup+11.2085 s]
/proc/loadavg: 1.59 1.39 1.17 2/46 20270
/proc/meminfo: memFree=33004/1048576 swapFree=0/0
[pid=20258] ppid=20257 vsize=2576 CPUtime=0
/proc/20258/stat : 20258 (gj-paranoid-sol) S 20257 20258 4778 34817 4778 4202496 373 0 0 0 0 0 0 0 25 0 1 0 11121919 2637824 271 1283457024 134512640 135304128 4291757824 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/20258/statm: 644 271 229 194 0 31 0
[pid=20259] ppid=20258 vsize=411740 CPUtime=11.2
/proc/20259/stat : 20259 (java) S 20258 20258 4778 34817 4778 4202496 92797 0 1 0 1081 39 0 0 25 0 10 0 11121919 421621760 70594 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/20259/statm: 102935 70594 2917 10 0 97080 0
[pid=20259/tid=20261] ppid=20258 vsize=411740 CPUtime=4.03
/proc/20259/task/20261/stat : 20261 (java) R 20258 20258 4778 34817 4778 4202560 14126 0 1 0 394 9 0 0 25 0 10 0 11121920 421621760 70594 1283457024 134512640 134550932 4286794128 18446744073709551615 4115121316 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=20259/tid=20262] ppid=20258 vsize=411740 CPUtime=6.97
/proc/20259/task/20262/stat : 20262 (java) S 20258 20258 4778 34817 4778 4202560 77193 0 0 0 669 28 0 0 16 0 10 0 11121920 421621760 70594 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 0 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20263] ppid=20258 vsize=411740 CPUtime=0
/proc/20259/task/20263/stat : 20263 (java) S 20258 20258 4778 34817 4778 4202560 15 0 0 0 0 0 0 0 18 0 10 0 11121921 421621760 70594 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20264] ppid=20258 vsize=411740 CPUtime=0
/proc/20259/task/20264/stat : 20264 (java) S 20258 20258 4778 34817 4778 4202560 5 0 0 0 0 0 0 0 18 0 10 0 11121921 421621760 70594 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20265] ppid=20258 vsize=411740 CPUtime=0
/proc/20259/task/20265/stat : 20265 (java) S 20258 20258 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 10 0 11121922 421621760 70594 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20266] ppid=20258 vsize=411740 CPUtime=0.16
/proc/20259/task/20266/stat : 20266 (java) S 20258 20258 4778 34817 4778 4202560 533 0 0 0 16 0 0 0 15 0 10 0 11121922 421621760 70594 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20267] ppid=20258 vsize=411740 CPUtime=0
/proc/20259/task/20267/stat : 20267 (java) S 20258 20258 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 10 0 11121922 421621760 70594 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20268] ppid=20258 vsize=411740 CPUtime=0
/proc/20259/task/20268/stat : 20268 (java) S 20258 20258 4778 34817 4778 4202560 2 0 0 0 0 0 0 0 15 0 10 0 11121922 421621760 70594 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20270] ppid=20258 vsize=411740 CPUtime=0
/proc/20259/task/20270/stat : 20270 (java) S 20258 20258 4778 34817 4778 4202560 4 0 0 0 0 0 0 0 25 0 10 0 11122907 421621760 70594 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 11.2
Current children cumulated vsize (KiB) 414316

[startup+11.6085 s]
/proc/loadavg: 1.59 1.39 1.17 2/46 20270
/proc/meminfo: memFree=33004/1048576 swapFree=0/0
[pid=20258] ppid=20257 vsize=2576 CPUtime=0
/proc/20258/stat : 20258 (gj-paranoid-sol) S 20257 20258 4778 34817 4778 4202496 373 0 0 0 0 0 0 0 25 0 1 0 11121919 2637824 271 1283457024 134512640 135304128 4291757824 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/20258/statm: 644 271 229 194 0 31 0
[pid=20259] ppid=20258 vsize=411740 CPUtime=11.6
/proc/20259/stat : 20259 (java) S 20258 20258 4778 34817 4778 4202496 92799 0 1 0 1121 39 0 0 25 0 10 0 11121919 421621760 70596 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/20259/statm: 102935 70596 2917 10 0 97080 0
[pid=20259/tid=20261] ppid=20258 vsize=411740 CPUtime=4.43
/proc/20259/task/20261/stat : 20261 (java) R 20258 20258 4778 34817 4778 4202560 14127 0 1 0 434 9 0 0 25 0 10 0 11121920 421621760 70596 1283457024 134512640 134550932 4286794128 18446744073709551615 4115207009 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=20259/tid=20262] ppid=20258 vsize=411740 CPUtime=6.97
/proc/20259/task/20262/stat : 20262 (java) S 20258 20258 4778 34817 4778 4202560 77193 0 0 0 669 28 0 0 16 0 10 0 11121920 421621760 70596 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 0 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20263] ppid=20258 vsize=411740 CPUtime=0
/proc/20259/task/20263/stat : 20263 (java) S 20258 20258 4778 34817 4778 4202560 15 0 0 0 0 0 0 0 18 0 10 0 11121921 421621760 70596 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20264] ppid=20258 vsize=411740 CPUtime=0
/proc/20259/task/20264/stat : 20264 (java) S 20258 20258 4778 34817 4778 4202560 5 0 0 0 0 0 0 0 18 0 10 0 11121921 421621760 70596 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20265] ppid=20258 vsize=411740 CPUtime=0
/proc/20259/task/20265/stat : 20265 (java) S 20258 20258 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 10 0 11121922 421621760 70596 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20266] ppid=20258 vsize=411740 CPUtime=0.16
/proc/20259/task/20266/stat : 20266 (java) S 20258 20258 4778 34817 4778 4202560 534 0 0 0 16 0 0 0 15 0 10 0 11121922 421621760 70596 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20267] ppid=20258 vsize=411740 CPUtime=0
/proc/20259/task/20267/stat : 20267 (java) S 20258 20258 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 10 0 11121922 421621760 70596 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20268] ppid=20258 vsize=411740 CPUtime=0
/proc/20259/task/20268/stat : 20268 (java) S 20258 20258 4778 34817 4778 4202560 2 0 0 0 0 0 0 0 15 0 10 0 11121922 421621760 70596 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20270] ppid=20258 vsize=411740 CPUtime=0
/proc/20259/task/20270/stat : 20270 (java) S 20258 20258 4778 34817 4778 4202560 4 0 0 0 0 0 0 0 25 0 10 0 11122907 421621760 70596 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 11.6
Current children cumulated vsize (KiB) 414316

[startup+12.0086 s]
/proc/loadavg: 1.59 1.39 1.17 2/46 20270
/proc/meminfo: memFree=33004/1048576 swapFree=0/0
[pid=20258] ppid=20257 vsize=2576 CPUtime=0
/proc/20258/stat : 20258 (gj-paranoid-sol) S 20257 20258 4778 34817 4778 4202496 373 0 0 0 0 0 0 0 25 0 1 0 11121919 2637824 271 1283457024 134512640 135304128 4291757824 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/20258/statm: 644 271 229 194 0 31 0
[pid=20259] ppid=20258 vsize=411740 CPUtime=12
/proc/20259/stat : 20259 (java) S 20258 20258 4778 34817 4778 4202496 92799 0 1 0 1161 39 0 0 25 0 10 0 11121919 421621760 70596 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/20259/statm: 102935 70596 2917 10 0 97080 0
[pid=20259/tid=20261] ppid=20258 vsize=411740 CPUtime=4.83
/proc/20259/task/20261/stat : 20261 (java) R 20258 20258 4778 34817 4778 4202560 14127 0 1 0 474 9 0 0 25 0 10 0 11121920 421621760 70596 1283457024 134512640 134550932 4286794128 18446744073709551615 4115248386 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=20259/tid=20262] ppid=20258 vsize=411740 CPUtime=6.97
/proc/20259/task/20262/stat : 20262 (java) S 20258 20258 4778 34817 4778 4202560 77193 0 0 0 669 28 0 0 16 0 10 0 11121920 421621760 70596 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 0 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20263] ppid=20258 vsize=411740 CPUtime=0
/proc/20259/task/20263/stat : 20263 (java) S 20258 20258 4778 34817 4778 4202560 15 0 0 0 0 0 0 0 18 0 10 0 11121921 421621760 70596 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20264] ppid=20258 vsize=411740 CPUtime=0
/proc/20259/task/20264/stat : 20264 (java) S 20258 20258 4778 34817 4778 4202560 5 0 0 0 0 0 0 0 18 0 10 0 11121921 421621760 70596 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20265] ppid=20258 vsize=411740 CPUtime=0
/proc/20259/task/20265/stat : 20265 (java) S 20258 20258 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 10 0 11121922 421621760 70596 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20266] ppid=20258 vsize=411740 CPUtime=0.16
/proc/20259/task/20266/stat : 20266 (java) S 20258 20258 4778 34817 4778 4202560 534 0 0 0 16 0 0 0 15 0 10 0 11121922 421621760 70596 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20267] ppid=20258 vsize=411740 CPUtime=0
/proc/20259/task/20267/stat : 20267 (java) S 20258 20258 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 10 0 11121922 421621760 70596 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20268] ppid=20258 vsize=411740 CPUtime=0
/proc/20259/task/20268/stat : 20268 (java) S 20258 20258 4778 34817 4778 4202560 2 0 0 0 0 0 0 0 15 0 10 0 11121922 421621760 70596 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
[pid=20259/tid=20270] ppid=20258 vsize=411740 CPUtime=0
/proc/20259/task/20270/stat : 20270 (java) S 20258 20258 4778 34817 4778 4202560 4 0 0 0 0 0 0 0 25 0 10 0 11122907 421621760 70596 1283457024 134512640 134550932 4286794128 18446744073709551615 4294960130 0 4 0 16800975 18446612133395904512 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 12
Current children cumulated vsize (KiB) 414316

[startup+12.1022 s]
/proc/loadavg: 1.59 1.39 1.17 2/38 20271
/proc/meminfo: memFree=282376/1048576 swapFree=0/0
[pid=20258] ppid=20257 vsize=2576 CPUtime=0
/proc/20258/stat : 20258 (gj-paranoid-sol) S 20257 20258 4778 34817 4778 4202496 373 0 0 0 0 0 0 0 25 0 1 0 11121919 2637824 271 1283457024 134512640 135304128 4291757824 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/20258/statm: 644 271 229 194 0 31 0
[pid=20259] ppid=20258 vsize=0 CPUtime=12.06
/proc/20259/stat : 20259 (java) Z 20258 20258 4778 34817 4778 4202508 92807 0 1 0 1165 41 0 0 18 0 2 0 11121919 0 0 1283457024 0 0 0 0 0 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/20259/statm: 0 0 0 0 0 0 0
[pid=20259/tid=20267] ppid=20258 vsize=0 CPUtime=0.02
/proc/20259/task/20267/stat : 20267 (java) R 20258 20258 4778 34817 4778 4203588 1 0 0 0 0 2 0 0 18 0 2 0 11121922 0 0 1283457024 0 0 0 0 0 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 12.06
Current children cumulated vsize (KiB) 2576

Child status: 0
Real time (s): 12.1067
CPU time (s): 12.0688
CPU user time (s): 11.6527
CPU system time (s): 0.416026
CPU usage (%): 99.6868
Max. virtual memory (cumulated for all children) (KiB): 442568

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 11.6527
system time used= 0.416026
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 93192
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= 909
involuntary context switches= 1043

runsolver used 0 second user time and 0 second system time

The end