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.cudf.sarge-etch-lenny.log.runsolver ./gj-paranoid-solver-0.1 /home/misc2010/data/icse/sarge-etch-lenny/rand180.sarge-etch-lenny.cudf /home/misc2010/tmp/201012061533/gj-paranoid-solver-0.1/rand180.sarge-etch-lenny.cudf.sarge-etch-lenny.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: 0.85 1.01 1.06 6/47 9256
/proc/meminfo: memFree=737324/1048576 swapFree=2078740/2097144
[pid=9254] ppid=9253 vsize=2576 CPUtime=0
/proc/9254/stat : 9254 (gj-paranoid-sol) S 9253 9254 2059 34821 2220 4202496 376 0 0 0 0 0 0 0 18 0 1 0 875105678 2637824 273 1283457024 134512640 135304128 4288148336 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9254/statm: 644 273 232 194 0 30 0
[pid=9255] ppid=9254 vsize=11240 CPUtime=0.01
/proc/9255/stat : 9255 (java) R 9254 9254 2059 34821 2220 4202496 909 0 0 0 0 1 0 0 25 0 2 0 875105678 11509760 642 1283457024 134512640 134550932 4293056368 18446744073709551615 4159426808 0 0 0 0 18446744073709551615 0 0 17 0 0 0 0
/proc/9255/statm: 2810 642 285 10 0 1184 0
[pid=9255/tid=9256] ppid=9254 vsize=11240 CPUtime=0
/proc/9255/task/9256/stat : 9256 (java) R 9254 9254 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 25 0 2 0 875105678 11509760 642 1283457024 134512640 134550932 4293056368 18446744073709551615 4159426808 0 0 0 0 0 0 0 -1 0 0 0 0

[startup+0.152299 s]
/proc/loadavg: 0.85 1.01 1.06 6/47 9256
/proc/meminfo: memFree=737324/1048576 swapFree=2078740/2097144
[pid=9254] ppid=9253 vsize=2576 CPUtime=0
/proc/9254/stat : 9254 (gj-paranoid-sol) S 9253 9254 2059 34821 2220 4202496 376 0 0 0 0 0 0 0 18 0 1 0 875105678 2637824 273 1283457024 134512640 135304128 4288148336 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9254/statm: 644 273 232 194 0 30 0
[pid=9255] ppid=9254 vsize=409992 CPUtime=0.15
/proc/9255/stat : 9255 (java) S 9254 9254 2059 34821 2220 4202496 4350 0 1 0 14 1 0 0 25 0 9 0 875105678 419831808 3814 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9255/statm: 102498 3814 1875 10 0 96678 0
[pid=9255/tid=9256] ppid=9254 vsize=409992 CPUtime=0.14
/proc/9255/task/9256/stat : 9256 (java) R 9254 9254 2059 34821 2220 4202560 3175 0 1 0 14 0 0 0 25 0 9 0 875105678 419831808 3814 1283457024 134512640 134550932 4293056368 18446744073709551615 4115046032 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 0.15
Current children cumulated vsize (KiB) 412568

[startup+0.202313 s]
/proc/loadavg: 0.85 1.01 1.06 6/47 9256
/proc/meminfo: memFree=737324/1048576 swapFree=2078740/2097144
[pid=9254] ppid=9253 vsize=2576 CPUtime=0
/proc/9254/stat : 9254 (gj-paranoid-sol) S 9253 9254 2059 34821 2220 4202496 376 0 0 0 0 0 0 0 18 0 1 0 875105678 2637824 273 1283457024 134512640 135304128 4288148336 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9254/statm: 644 273 232 194 0 30 0
[pid=9255] ppid=9254 vsize=409992 CPUtime=0.21
/proc/9255/stat : 9255 (java) S 9254 9254 2059 34821 2220 4202496 5171 0 1 0 20 1 0 0 25 0 9 0 875105678 419831808 4634 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9255/statm: 102498 4634 1883 10 0 96678 0
[pid=9255/tid=9256] ppid=9254 vsize=409992 CPUtime=0.17
/proc/9255/task/9256/stat : 9256 (java) R 9254 9254 2059 34821 2220 4202560 3376 0 1 0 17 0 0 0 25 0 9 0 875105678 419831808 4634 1283457024 134512640 134550932 4293056368 18446744073709551615 4114908008 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) 412568

[startup+0.312345 s]
/proc/loadavg: 0.85 1.01 1.06 6/47 9256
/proc/meminfo: memFree=737324/1048576 swapFree=2078740/2097144
[pid=9254] ppid=9253 vsize=2576 CPUtime=0
/proc/9254/stat : 9254 (gj-paranoid-sol) S 9253 9254 2059 34821 2220 4202496 376 0 0 0 0 0 0 0 18 0 1 0 875105678 2637824 273 1283457024 134512640 135304128 4288148336 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9254/statm: 644 273 232 194 0 30 0
[pid=9255] ppid=9254 vsize=409992 CPUtime=0.31
/proc/9255/stat : 9255 (java) S 9254 9254 2059 34821 2220 4202496 5949 0 1 0 30 1 0 0 25 0 9 0 875105678 419831808 5412 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9255/statm: 102498 5412 1883 10 0 96678 0
[pid=9255/tid=9256] ppid=9254 vsize=409992 CPUtime=0.26
/proc/9255/task/9256/stat : 9256 (java) R 9254 9254 2059 34821 2220 4202560 3376 0 1 0 26 0 0 0 25 0 9 0 875105678 419831808 5412 1283457024 134512640 134550932 4293056368 18446744073709551615 4114889537 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) 412568

[startup+0.712471 s]
/proc/loadavg: 0.85 1.01 1.06 6/47 9256
/proc/meminfo: memFree=737324/1048576 swapFree=2078740/2097144
[pid=9254] ppid=9253 vsize=2576 CPUtime=0
/proc/9254/stat : 9254 (gj-paranoid-sol) S 9253 9254 2059 34821 2220 4202496 376 0 0 0 0 0 0 0 18 0 1 0 875105678 2637824 273 1283457024 134512640 135304128 4288148336 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9254/statm: 644 273 232 194 0 30 0
[pid=9255] ppid=9254 vsize=410740 CPUtime=0.71
/proc/9255/stat : 9255 (java) S 9254 9254 2059 34821 2220 4202496 12925 0 1 0 67 4 0 0 25 0 9 0 875105678 420597760 12210 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9255/statm: 102685 12210 2878 10 0 96865 0
[pid=9255/tid=9256] ppid=9254 vsize=410740 CPUtime=0.41
/proc/9255/task/9256/stat : 9256 (java) R 9254 9254 2059 34821 2220 4202560 4082 0 1 0 41 0 0 0 25 0 9 0 875105678 420597760 12210 1283457024 134512640 134550932 4293056368 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) 413316

[startup+1.51265 s]
/proc/loadavg: 0.94 1.03 1.06 2/55 9264
/proc/meminfo: memFree=678124/1048576 swapFree=2078740/2097144
[pid=9254] ppid=9253 vsize=2576 CPUtime=0
/proc/9254/stat : 9254 (gj-paranoid-sol) S 9253 9254 2059 34821 2220 4202496 376 0 0 0 0 0 0 0 18 0 1 0 875105678 2637824 273 1283457024 134512640 135304128 4288148336 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9254/statm: 644 273 232 194 0 30 0
[pid=9255] ppid=9254 vsize=410740 CPUtime=1.51
/proc/9255/stat : 9255 (java) S 9254 9254 2059 34821 2220 4202496 28372 0 1 0 142 9 0 0 25 0 9 0 875105678 420597760 27657 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9255/statm: 102685 27657 2879 10 0 96865 0
[pid=9255/tid=9256] ppid=9254 vsize=410740 CPUtime=0.69
/proc/9255/task/9256/stat : 9256 (java) R 9254 9254 2059 34821 2220 4202560 6754 0 1 0 69 0 0 0 25 0 9 0 875105678 420597760 27657 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=9255/tid=9258] ppid=9254 vsize=410740 CPUtime=0.78
/proc/9255/task/9258/stat : 9258 (java) R 9254 9254 2059 34821 2220 4202560 20228 0 0 0 70 8 0 0 20 0 9 0 875105679 420597760 27657 1283457024 134512640 134550932 4293056368 18446744073709551615 4152752512 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=9255/tid=9259] ppid=9254 vsize=410740 CPUtime=0
/proc/9255/task/9259/stat : 9259 (java) S 9254 9254 2059 34821 2220 4202560 18 0 0 0 0 0 0 0 20 0 9 0 875105679 420597760 27657 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9260] ppid=9254 vsize=410740 CPUtime=0
/proc/9255/task/9260/stat : 9260 (java) S 9254 9254 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 24 0 9 0 875105679 420597760 27657 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9261] ppid=9254 vsize=410740 CPUtime=0
/proc/9255/task/9261/stat : 9261 (java) S 9254 9254 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 9 0 875105681 420597760 27657 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9262] ppid=9254 vsize=410740 CPUtime=0.02
/proc/9255/task/9262/stat : 9262 (java) S 9254 9254 2059 34821 2220 4202560 456 0 0 0 2 0 0 0 17 0 9 0 875105681 420597760 27657 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9263] ppid=9254 vsize=410740 CPUtime=0
/proc/9255/task/9263/stat : 9263 (java) S 9254 9254 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 9 0 875105681 420597760 27657 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9264] ppid=9254 vsize=410740 CPUtime=0
/proc/9255/task/9264/stat : 9264 (java) S 9254 9254 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 15 0 9 0 875105681 420597760 27657 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.51
Current children cumulated vsize (KiB) 413316

[startup+3.11313 s]
/proc/loadavg: 0.94 1.03 1.06 3/55 9264
/proc/meminfo: memFree=598764/1048576 swapFree=2078740/2097144
[pid=9254] ppid=9253 vsize=2576 CPUtime=0
/proc/9254/stat : 9254 (gj-paranoid-sol) S 9253 9254 2059 34821 2220 4202496 376 0 0 0 0 0 0 0 18 0 1 0 875105678 2637824 273 1283457024 134512640 135304128 4288148336 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9254/statm: 644 273 232 194 0 30 0
[pid=9255] ppid=9254 vsize=410872 CPUtime=3.11
/proc/9255/stat : 9255 (java) S 9254 9254 2059 34821 2220 4202496 51214 0 1 0 297 14 0 0 25 0 9 0 875105678 420732928 50485 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9255/statm: 102718 50485 2881 10 0 96898 0
[pid=9255/tid=9256] ppid=9254 vsize=410872 CPUtime=1.32
/proc/9255/task/9256/stat : 9256 (java) R 9254 9254 2059 34821 2220 4202560 14114 0 1 0 130 2 0 0 25 0 9 0 875105678 420732928 50485 1283457024 134512640 134550932 4293056368 18446744073709551615 4115434319 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=9255/tid=9258] ppid=9254 vsize=410872 CPUtime=1.72
/proc/9255/task/9258/stat : 9258 (java) S 9254 9254 2059 34821 2220 4202560 35680 0 0 0 162 10 0 0 17 0 9 0 875105679 420732928 50485 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 0 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9259] ppid=9254 vsize=410872 CPUtime=0
/proc/9255/task/9259/stat : 9259 (java) S 9254 9254 2059 34821 2220 4202560 18 0 0 0 0 0 0 0 15 0 9 0 875105679 420732928 50485 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9260] ppid=9254 vsize=410872 CPUtime=0
/proc/9255/task/9260/stat : 9260 (java) S 9254 9254 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 18 0 9 0 875105679 420732928 50485 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9261] ppid=9254 vsize=410872 CPUtime=0
/proc/9255/task/9261/stat : 9261 (java) S 9254 9254 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 9 0 875105681 420732928 50485 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9262] ppid=9254 vsize=410872 CPUtime=0.04
/proc/9255/task/9262/stat : 9262 (java) S 9254 9254 2059 34821 2220 4202560 486 0 0 0 4 0 0 0 15 0 9 0 875105681 420732928 50485 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9263] ppid=9254 vsize=410872 CPUtime=0
/proc/9255/task/9263/stat : 9263 (java) S 9254 9254 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 9 0 875105681 420732928 50485 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9264] ppid=9254 vsize=410872 CPUtime=0
/proc/9255/task/9264/stat : 9264 (java) S 9254 9254 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 15 0 9 0 875105681 420732928 50485 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.11
Current children cumulated vsize (KiB) 413448

[startup+6.31377 s]
/proc/loadavg: 0.94 1.03 1.06 3/56 9265
/proc/meminfo: memFree=535888/1048576 swapFree=2078740/2097144
[pid=9254] ppid=9253 vsize=2576 CPUtime=0
/proc/9254/stat : 9254 (gj-paranoid-sol) S 9253 9254 2059 34821 2220 4202496 376 0 0 0 0 0 0 0 18 0 1 0 875105678 2637824 273 1283457024 134512640 135304128 4288148336 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9254/statm: 644 273 232 194 0 30 0
[pid=9255] ppid=9254 vsize=421624 CPUtime=6.31
/proc/9255/stat : 9255 (java) S 9254 9254 2059 34821 2220 4202496 58020 0 1 0 611 20 0 0 25 0 10 0 875105678 431742976 57283 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9255/statm: 105406 57283 2884 10 0 99586 0
[pid=9255/tid=9256] ppid=9254 vsize=421624 CPUtime=3.96
/proc/9255/task/9256/stat : 9256 (java) R 9254 9254 2059 34821 2220 4202560 14145 0 1 0 394 2 0 0 25 0 10 0 875105678 431742976 57283 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=9255/tid=9258] ppid=9254 vsize=421624 CPUtime=2.27
/proc/9255/task/9258/stat : 9258 (java) R 9254 9254 2059 34821 2220 4202560 42417 0 0 0 210 17 0 0 16 0 10 0 875105679 431742976 57283 1283457024 134512640 134550932 4293056368 18446744073709551615 4152583800 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=9255/tid=9259] ppid=9254 vsize=421624 CPUtime=0
/proc/9255/task/9259/stat : 9259 (java) S 9254 9254 2059 34821 2220 4202560 18 0 0 0 0 0 0 0 15 0 10 0 875105679 431742976 57283 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9260] ppid=9254 vsize=421624 CPUtime=0
/proc/9255/task/9260/stat : 9260 (java) S 9254 9254 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 18 0 10 0 875105679 431742976 57283 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9261] ppid=9254 vsize=421624 CPUtime=0
/proc/9255/task/9261/stat : 9261 (java) S 9254 9254 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875105681 431742976 57283 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9262] ppid=9254 vsize=421624 CPUtime=0.06
/proc/9255/task/9262/stat : 9262 (java) S 9254 9254 2059 34821 2220 4202560 519 0 0 0 6 0 0 0 16 0 10 0 875105681 431742976 57283 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9263] ppid=9254 vsize=421624 CPUtime=0
/proc/9255/task/9263/stat : 9263 (java) S 9254 9254 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875105681 431742976 57283 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9264] ppid=9254 vsize=421624 CPUtime=0
/proc/9255/task/9264/stat : 9264 (java) S 9254 9254 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 15 0 10 0 875105681 431742976 57283 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9265] ppid=9254 vsize=421624 CPUtime=0
/proc/9255/task/9265/stat : 9265 (java) S 9254 9254 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 25 0 10 0 875105993 431742976 57283 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.31
Current children cumulated vsize (KiB) 424200

[startup+12.7051 s]
/proc/loadavg: 0.95 1.03 1.06 2/56 9265
/proc/meminfo: memFree=519892/1048576 swapFree=2078740/2097144
[pid=9254] ppid=9253 vsize=2576 CPUtime=0
/proc/9254/stat : 9254 (gj-paranoid-sol) S 9253 9254 2059 34821 2220 4202496 376 0 0 0 0 0 0 0 18 0 1 0 875105678 2637824 273 1283457024 134512640 135304128 4288148336 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9254/statm: 644 273 232 194 0 30 0
[pid=9255] ppid=9254 vsize=420848 CPUtime=12.7
/proc/9255/stat : 9255 (java) S 9254 9254 2059 34821 2220 4202496 60587 0 1 0 1249 21 0 0 25 0 10 0 875105678 430948352 57308 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9255/statm: 105212 57308 2884 10 0 99392 0
[pid=9255/tid=9256] ppid=9254 vsize=420848 CPUtime=9.72
/proc/9255/task/9256/stat : 9256 (java) R 9254 9254 2059 34821 2220 4202560 14145 0 1 0 970 2 0 0 25 0 10 0 875105678 430948352 57308 1283457024 134512640 134550932 4293056368 18446744073709551615 4115694235 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=9255/tid=9258] ppid=9254 vsize=420848 CPUtime=2.9
/proc/9255/task/9258/stat : 9258 (java) S 9254 9254 2059 34821 2220 4202560 44982 0 0 0 272 18 0 0 15 0 10 0 875105679 430948352 57308 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 0 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9259] ppid=9254 vsize=420848 CPUtime=0
/proc/9255/task/9259/stat : 9259 (java) S 9254 9254 2059 34821 2220 4202560 18 0 0 0 0 0 0 0 15 0 10 0 875105679 430948352 57308 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9260] ppid=9254 vsize=420848 CPUtime=0
/proc/9255/task/9260/stat : 9260 (java) S 9254 9254 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 18 0 10 0 875105679 430948352 57308 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9261] ppid=9254 vsize=420848 CPUtime=0
/proc/9255/task/9261/stat : 9261 (java) S 9254 9254 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875105681 430948352 57308 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9262] ppid=9254 vsize=420848 CPUtime=0.06
/proc/9255/task/9262/stat : 9262 (java) S 9254 9254 2059 34821 2220 4202560 521 0 0 0 6 0 0 0 15 0 10 0 875105681 430948352 57308 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9263] ppid=9254 vsize=420848 CPUtime=0
/proc/9255/task/9263/stat : 9263 (java) S 9254 9254 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875105681 430948352 57308 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9264] ppid=9254 vsize=420848 CPUtime=0
/proc/9255/task/9264/stat : 9264 (java) S 9254 9254 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 15 0 10 0 875105681 430948352 57308 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9265] ppid=9254 vsize=420848 CPUtime=0
/proc/9255/task/9265/stat : 9265 (java) S 9254 9254 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 25 0 10 0 875105993 430948352 57308 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 12.7
Current children cumulated vsize (KiB) 423424

[startup+25.5078 s]
/proc/loadavg: 0.96 1.03 1.06 2/56 9265
/proc/meminfo: memFree=519148/1048576 swapFree=2078740/2097144
[pid=9254] ppid=9253 vsize=2576 CPUtime=0
/proc/9254/stat : 9254 (gj-paranoid-sol) S 9253 9254 2059 34821 2220 4202496 376 0 0 0 0 0 0 0 18 0 1 0 875105678 2637824 273 1283457024 134512640 135304128 4288148336 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9254/statm: 644 273 232 194 0 30 0
[pid=9255] ppid=9254 vsize=420788 CPUtime=25.51
/proc/9255/stat : 9255 (java) S 9254 9254 2059 34821 2220 4202496 68024 0 1 0 2526 25 0 0 25 0 10 0 875105678 430886912 57523 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9255/statm: 105197 57523 2884 10 0 99377 0
[pid=9255/tid=9256] ppid=9254 vsize=420788 CPUtime=20.74
/proc/9255/task/9256/stat : 9256 (java) R 9254 9254 2059 34821 2220 4202560 14145 0 1 0 2072 2 0 0 25 0 10 0 875105678 430886912 57523 1283457024 134512640 134550932 4293056368 18446744073709551615 4115735580 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=9255/tid=9258] ppid=9254 vsize=420788 CPUtime=4.68
/proc/9255/task/9258/stat : 9258 (java) S 9254 9254 2059 34821 2220 4202560 52419 0 0 0 447 21 0 0 15 0 10 0 875105679 430886912 57523 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 0 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9259] ppid=9254 vsize=420788 CPUtime=0
/proc/9255/task/9259/stat : 9259 (java) S 9254 9254 2059 34821 2220 4202560 18 0 0 0 0 0 0 0 15 0 10 0 875105679 430886912 57523 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9260] ppid=9254 vsize=420788 CPUtime=0
/proc/9255/task/9260/stat : 9260 (java) S 9254 9254 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 18 0 10 0 875105679 430886912 57523 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9261] ppid=9254 vsize=420788 CPUtime=0
/proc/9255/task/9261/stat : 9261 (java) S 9254 9254 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875105681 430886912 57523 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9262] ppid=9254 vsize=420788 CPUtime=0.06
/proc/9255/task/9262/stat : 9262 (java) S 9254 9254 2059 34821 2220 4202560 521 0 0 0 6 0 0 0 15 0 10 0 875105681 430886912 57523 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9263] ppid=9254 vsize=420788 CPUtime=0
/proc/9255/task/9263/stat : 9263 (java) S 9254 9254 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875105681 430886912 57523 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9264] ppid=9254 vsize=420788 CPUtime=0
/proc/9255/task/9264/stat : 9264 (java) S 9254 9254 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 15 0 10 0 875105681 430886912 57523 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9265] ppid=9254 vsize=420788 CPUtime=0
/proc/9255/task/9265/stat : 9265 (java) S 9254 9254 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 25 0 10 0 875105993 430886912 57523 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 25.51
Current children cumulated vsize (KiB) 423364

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

[startup+25.6078 s]
/proc/loadavg: 0.96 1.03 1.06 2/56 9265
/proc/meminfo: memFree=519148/1048576 swapFree=2078740/2097144
[pid=9254] ppid=9253 vsize=2576 CPUtime=0
/proc/9254/stat : 9254 (gj-paranoid-sol) S 9253 9254 2059 34821 2220 4202496 376 0 0 0 0 0 0 0 18 0 1 0 875105678 2637824 273 1283457024 134512640 135304128 4288148336 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9254/statm: 644 273 232 194 0 30 0
[pid=9255] ppid=9254 vsize=420788 CPUtime=25.61
/proc/9255/stat : 9255 (java) S 9254 9254 2059 34821 2220 4202496 68024 0 1 0 2536 25 0 0 25 0 10 0 875105678 430886912 57523 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9255/statm: 105197 57523 2884 10 0 99377 0
[pid=9255/tid=9256] ppid=9254 vsize=420788 CPUtime=20.84
/proc/9255/task/9256/stat : 9256 (java) R 9254 9254 2059 34821 2220 4202560 14145 0 1 0 2082 2 0 0 25 0 10 0 875105678 430886912 57523 1283457024 134512640 134550932 4293056368 18446744073709551615 4115745316 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=9255/tid=9258] ppid=9254 vsize=420788 CPUtime=4.68
/proc/9255/task/9258/stat : 9258 (java) S 9254 9254 2059 34821 2220 4202560 52419 0 0 0 447 21 0 0 15 0 10 0 875105679 430886912 57523 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 0 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9259] ppid=9254 vsize=420788 CPUtime=0
/proc/9255/task/9259/stat : 9259 (java) S 9254 9254 2059 34821 2220 4202560 18 0 0 0 0 0 0 0 15 0 10 0 875105679 430886912 57523 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9260] ppid=9254 vsize=420788 CPUtime=0
/proc/9255/task/9260/stat : 9260 (java) S 9254 9254 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 18 0 10 0 875105679 430886912 57523 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9261] ppid=9254 vsize=420788 CPUtime=0
/proc/9255/task/9261/stat : 9261 (java) S 9254 9254 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875105681 430886912 57523 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9262] ppid=9254 vsize=420788 CPUtime=0.06
/proc/9255/task/9262/stat : 9262 (java) S 9254 9254 2059 34821 2220 4202560 521 0 0 0 6 0 0 0 15 0 10 0 875105681 430886912 57523 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9263] ppid=9254 vsize=420788 CPUtime=0
/proc/9255/task/9263/stat : 9263 (java) S 9254 9254 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875105681 430886912 57523 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9264] ppid=9254 vsize=420788 CPUtime=0
/proc/9255/task/9264/stat : 9264 (java) S 9254 9254 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 15 0 10 0 875105681 430886912 57523 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9265] ppid=9254 vsize=420788 CPUtime=0
/proc/9255/task/9265/stat : 9265 (java) S 9254 9254 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 25 0 10 0 875105993 430886912 57523 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 25.61
Current children cumulated vsize (KiB) 423364

[startup+28.8285 s]
/proc/loadavg: 0.96 1.03 1.06 2/56 9265
/proc/meminfo: memFree=519024/1048576 swapFree=2078740/2097144
[pid=9254] ppid=9253 vsize=2576 CPUtime=0
/proc/9254/stat : 9254 (gj-paranoid-sol) S 9253 9254 2059 34821 2220 4202496 376 0 0 0 0 0 0 0 18 0 1 0 875105678 2637824 273 1283457024 134512640 135304128 4288148336 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9254/statm: 644 273 232 194 0 30 0
[pid=9255] ppid=9254 vsize=411152 CPUtime=28.8
/proc/9255/stat : 9255 (java) S 9254 9254 2059 34821 2220 4202496 68028 0 1 0 2855 25 0 0 25 0 10 0 875105678 421019648 55127 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9255/statm: 102788 55127 2884 10 0 96968 0
[pid=9255/tid=9256] ppid=9254 vsize=411152 CPUtime=23.93
/proc/9255/task/9256/stat : 9256 (java) R 9254 9254 2059 34821 2220 4202560 14145 0 1 0 2391 2 0 0 25 0 10 0 875105678 421019648 55127 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=9255/tid=9258] ppid=9254 vsize=411152 CPUtime=4.78
/proc/9255/task/9258/stat : 9258 (java) R 9254 9254 2059 34821 2220 4202560 52419 0 0 0 457 21 0 0 15 0 10 0 875105679 421019648 55127 1283457024 134512640 134550932 4293056368 18446744073709551615 4152583119 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=9255/tid=9259] ppid=9254 vsize=411152 CPUtime=0
/proc/9255/task/9259/stat : 9259 (java) S 9254 9254 2059 34821 2220 4202560 18 0 0 0 0 0 0 0 15 0 10 0 875105679 421019648 55127 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9260] ppid=9254 vsize=411152 CPUtime=0
/proc/9255/task/9260/stat : 9260 (java) S 9254 9254 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 18 0 10 0 875105679 421019648 55127 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9261] ppid=9254 vsize=411152 CPUtime=0
/proc/9255/task/9261/stat : 9261 (java) S 9254 9254 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875105681 421019648 55127 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9262] ppid=9254 vsize=411152 CPUtime=0.07
/proc/9255/task/9262/stat : 9262 (java) S 9254 9254 2059 34821 2220 4202560 525 0 0 0 7 0 0 0 15 0 10 0 875105681 421019648 55127 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9263] ppid=9254 vsize=411152 CPUtime=0
/proc/9255/task/9263/stat : 9263 (java) S 9254 9254 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875105681 421019648 55127 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9264] ppid=9254 vsize=411152 CPUtime=0
/proc/9255/task/9264/stat : 9264 (java) S 9254 9254 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 15 0 10 0 875105681 421019648 55127 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9265] ppid=9254 vsize=411152 CPUtime=0
/proc/9255/task/9265/stat : 9265 (java) S 9254 9254 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 25 0 10 0 875105993 421019648 55127 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 28.8
Current children cumulated vsize (KiB) 413728

[startup+30.4087 s]
/proc/loadavg: 0.96 1.03 1.06 2/56 9265
/proc/meminfo: memFree=517412/1048576 swapFree=2078740/2097144
[pid=9254] ppid=9253 vsize=2576 CPUtime=0
/proc/9254/stat : 9254 (gj-paranoid-sol) S 9253 9254 2059 34821 2220 4202496 376 0 0 0 0 0 0 0 18 0 1 0 875105678 2637824 273 1283457024 134512640 135304128 4288148336 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9254/statm: 644 273 232 194 0 30 0
[pid=9255] ppid=9254 vsize=420920 CPUtime=30.38
/proc/9255/stat : 9255 (java) S 9254 9254 2059 34821 2220 4202496 70838 0 1 0 3012 26 0 0 25 0 10 0 875105678 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9255/statm: 105230 57937 2884 10 0 99410 0
[pid=9255/tid=9256] ppid=9254 vsize=420920 CPUtime=25.06
/proc/9255/task/9256/stat : 9256 (java) R 9254 9254 2059 34821 2220 4202560 14145 0 1 0 2504 2 0 0 25 0 10 0 875105678 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4115735593 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=9255/tid=9258] ppid=9254 vsize=420920 CPUtime=5.23
/proc/9255/task/9258/stat : 9258 (java) S 9254 9254 2059 34821 2220 4202560 55229 0 0 0 501 22 0 0 15 0 10 0 875105679 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 0 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9259] ppid=9254 vsize=420920 CPUtime=0
/proc/9255/task/9259/stat : 9259 (java) S 9254 9254 2059 34821 2220 4202560 18 0 0 0 0 0 0 0 15 0 10 0 875105679 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9260] ppid=9254 vsize=420920 CPUtime=0
/proc/9255/task/9260/stat : 9260 (java) S 9254 9254 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 18 0 10 0 875105679 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9261] ppid=9254 vsize=420920 CPUtime=0
/proc/9255/task/9261/stat : 9261 (java) S 9254 9254 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875105681 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9262] ppid=9254 vsize=420920 CPUtime=0.07
/proc/9255/task/9262/stat : 9262 (java) S 9254 9254 2059 34821 2220 4202560 525 0 0 0 7 0 0 0 15 0 10 0 875105681 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9263] ppid=9254 vsize=420920 CPUtime=0
/proc/9255/task/9263/stat : 9263 (java) S 9254 9254 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875105681 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9264] ppid=9254 vsize=420920 CPUtime=0
/proc/9255/task/9264/stat : 9264 (java) S 9254 9254 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 15 0 10 0 875105681 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9265] ppid=9254 vsize=420920 CPUtime=0
/proc/9255/task/9265/stat : 9265 (java) S 9254 9254 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 25 0 10 0 875105993 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 30.38
Current children cumulated vsize (KiB) 423496

[startup+32.009 s]
/proc/loadavg: 0.96 1.03 1.06 2/56 9265
/proc/meminfo: memFree=517412/1048576 swapFree=2078740/2097144
[pid=9254] ppid=9253 vsize=2576 CPUtime=0
/proc/9254/stat : 9254 (gj-paranoid-sol) S 9253 9254 2059 34821 2220 4202496 376 0 0 0 0 0 0 0 18 0 1 0 875105678 2637824 273 1283457024 134512640 135304128 4288148336 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9254/statm: 644 273 232 194 0 30 0
[pid=9255] ppid=9254 vsize=420920 CPUtime=31.98
/proc/9255/stat : 9255 (java) S 9254 9254 2059 34821 2220 4202496 70838 0 1 0 3172 26 0 0 25 0 10 0 875105678 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9255/statm: 105230 57937 2884 10 0 99410 0
[pid=9255/tid=9256] ppid=9254 vsize=420920 CPUtime=26.66
/proc/9255/task/9256/stat : 9256 (java) R 9254 9254 2059 34821 2220 4202560 14145 0 1 0 2664 2 0 0 25 0 10 0 875105678 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4115664574 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=9255/tid=9258] ppid=9254 vsize=420920 CPUtime=5.23
/proc/9255/task/9258/stat : 9258 (java) S 9254 9254 2059 34821 2220 4202560 55229 0 0 0 501 22 0 0 15 0 10 0 875105679 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 0 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9259] ppid=9254 vsize=420920 CPUtime=0
/proc/9255/task/9259/stat : 9259 (java) S 9254 9254 2059 34821 2220 4202560 18 0 0 0 0 0 0 0 15 0 10 0 875105679 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9260] ppid=9254 vsize=420920 CPUtime=0
/proc/9255/task/9260/stat : 9260 (java) S 9254 9254 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 18 0 10 0 875105679 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9261] ppid=9254 vsize=420920 CPUtime=0
/proc/9255/task/9261/stat : 9261 (java) S 9254 9254 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875105681 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9262] ppid=9254 vsize=420920 CPUtime=0.07
/proc/9255/task/9262/stat : 9262 (java) S 9254 9254 2059 34821 2220 4202560 525 0 0 0 7 0 0 0 15 0 10 0 875105681 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9263] ppid=9254 vsize=420920 CPUtime=0
/proc/9255/task/9263/stat : 9263 (java) S 9254 9254 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875105681 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9264] ppid=9254 vsize=420920 CPUtime=0
/proc/9255/task/9264/stat : 9264 (java) S 9254 9254 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 15 0 10 0 875105681 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9265] ppid=9254 vsize=420920 CPUtime=0
/proc/9255/task/9265/stat : 9265 (java) S 9254 9254 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 25 0 10 0 875105993 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 31.98
Current children cumulated vsize (KiB) 423496

[startup+32.8092 s]
/proc/loadavg: 0.96 1.03 1.06 2/56 9265
/proc/meminfo: memFree=517412/1048576 swapFree=2078740/2097144
[pid=9254] ppid=9253 vsize=2576 CPUtime=0
/proc/9254/stat : 9254 (gj-paranoid-sol) S 9253 9254 2059 34821 2220 4202496 376 0 0 0 0 0 0 0 18 0 1 0 875105678 2637824 273 1283457024 134512640 135304128 4288148336 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9254/statm: 644 273 232 194 0 30 0
[pid=9255] ppid=9254 vsize=420920 CPUtime=32.79
/proc/9255/stat : 9255 (java) S 9254 9254 2059 34821 2220 4202496 70838 0 1 0 3253 26 0 0 25 0 10 0 875105678 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9255/statm: 105230 57937 2884 10 0 99410 0
[pid=9255/tid=9256] ppid=9254 vsize=420920 CPUtime=27.46
/proc/9255/task/9256/stat : 9256 (java) R 9254 9254 2059 34821 2220 4202560 14145 0 1 0 2744 2 0 0 25 0 10 0 875105678 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4115694137 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=9255/tid=9258] ppid=9254 vsize=420920 CPUtime=5.23
/proc/9255/task/9258/stat : 9258 (java) S 9254 9254 2059 34821 2220 4202560 55229 0 0 0 501 22 0 0 15 0 10 0 875105679 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 0 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9259] ppid=9254 vsize=420920 CPUtime=0
/proc/9255/task/9259/stat : 9259 (java) S 9254 9254 2059 34821 2220 4202560 18 0 0 0 0 0 0 0 15 0 10 0 875105679 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9260] ppid=9254 vsize=420920 CPUtime=0
/proc/9255/task/9260/stat : 9260 (java) S 9254 9254 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 18 0 10 0 875105679 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9261] ppid=9254 vsize=420920 CPUtime=0
/proc/9255/task/9261/stat : 9261 (java) S 9254 9254 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875105681 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9262] ppid=9254 vsize=420920 CPUtime=0.07
/proc/9255/task/9262/stat : 9262 (java) S 9254 9254 2059 34821 2220 4202560 525 0 0 0 7 0 0 0 15 0 10 0 875105681 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9263] ppid=9254 vsize=420920 CPUtime=0
/proc/9255/task/9263/stat : 9263 (java) S 9254 9254 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875105681 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9264] ppid=9254 vsize=420920 CPUtime=0
/proc/9255/task/9264/stat : 9264 (java) S 9254 9254 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 15 0 10 0 875105681 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9265] ppid=9254 vsize=420920 CPUtime=0
/proc/9255/task/9265/stat : 9265 (java) S 9254 9254 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 25 0 10 0 875105993 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 32.79
Current children cumulated vsize (KiB) 423496

[startup+33.2093 s]
/proc/loadavg: 0.96 1.03 1.06 2/56 9265
/proc/meminfo: memFree=517412/1048576 swapFree=2078740/2097144
[pid=9254] ppid=9253 vsize=2576 CPUtime=0
/proc/9254/stat : 9254 (gj-paranoid-sol) S 9253 9254 2059 34821 2220 4202496 376 0 0 0 0 0 0 0 18 0 1 0 875105678 2637824 273 1283457024 134512640 135304128 4288148336 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9254/statm: 644 273 232 194 0 30 0
[pid=9255] ppid=9254 vsize=420920 CPUtime=33.19
/proc/9255/stat : 9255 (java) S 9254 9254 2059 34821 2220 4202496 70838 0 1 0 3293 26 0 0 25 0 10 0 875105678 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9255/statm: 105230 57937 2884 10 0 99410 0
[pid=9255/tid=9256] ppid=9254 vsize=420920 CPUtime=27.86
/proc/9255/task/9256/stat : 9256 (java) R 9254 9254 2059 34821 2220 4202560 14145 0 1 0 2784 2 0 0 25 0 10 0 875105678 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4115745296 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=9255/tid=9258] ppid=9254 vsize=420920 CPUtime=5.23
/proc/9255/task/9258/stat : 9258 (java) S 9254 9254 2059 34821 2220 4202560 55229 0 0 0 501 22 0 0 15 0 10 0 875105679 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 0 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9259] ppid=9254 vsize=420920 CPUtime=0
/proc/9255/task/9259/stat : 9259 (java) S 9254 9254 2059 34821 2220 4202560 18 0 0 0 0 0 0 0 15 0 10 0 875105679 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9260] ppid=9254 vsize=420920 CPUtime=0
/proc/9255/task/9260/stat : 9260 (java) S 9254 9254 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 18 0 10 0 875105679 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9261] ppid=9254 vsize=420920 CPUtime=0
/proc/9255/task/9261/stat : 9261 (java) S 9254 9254 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875105681 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9262] ppid=9254 vsize=420920 CPUtime=0.07
/proc/9255/task/9262/stat : 9262 (java) S 9254 9254 2059 34821 2220 4202560 525 0 0 0 7 0 0 0 15 0 10 0 875105681 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9263] ppid=9254 vsize=420920 CPUtime=0
/proc/9255/task/9263/stat : 9263 (java) S 9254 9254 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875105681 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9264] ppid=9254 vsize=420920 CPUtime=0
/proc/9255/task/9264/stat : 9264 (java) S 9254 9254 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 15 0 10 0 875105681 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9265] ppid=9254 vsize=420920 CPUtime=0
/proc/9255/task/9265/stat : 9265 (java) S 9254 9254 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 25 0 10 0 875105993 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 33.19
Current children cumulated vsize (KiB) 423496

[startup+33.3093 s]
/proc/loadavg: 0.96 1.03 1.06 2/56 9265
/proc/meminfo: memFree=517412/1048576 swapFree=2078740/2097144
[pid=9254] ppid=9253 vsize=2576 CPUtime=0
/proc/9254/stat : 9254 (gj-paranoid-sol) S 9253 9254 2059 34821 2220 4202496 376 0 0 0 0 0 0 0 18 0 1 0 875105678 2637824 273 1283457024 134512640 135304128 4288148336 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9254/statm: 644 273 232 194 0 30 0
[pid=9255] ppid=9254 vsize=420920 CPUtime=33.29
/proc/9255/stat : 9255 (java) S 9254 9254 2059 34821 2220 4202496 70838 0 1 0 3303 26 0 0 25 0 10 0 875105678 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9255/statm: 105230 57937 2884 10 0 99410 0
[pid=9255/tid=9256] ppid=9254 vsize=420920 CPUtime=27.96
/proc/9255/task/9256/stat : 9256 (java) R 9254 9254 2059 34821 2220 4202560 14145 0 1 0 2794 2 0 0 25 0 10 0 875105678 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4115747118 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=9255/tid=9258] ppid=9254 vsize=420920 CPUtime=5.23
/proc/9255/task/9258/stat : 9258 (java) S 9254 9254 2059 34821 2220 4202560 55229 0 0 0 501 22 0 0 15 0 10 0 875105679 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 0 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9259] ppid=9254 vsize=420920 CPUtime=0
/proc/9255/task/9259/stat : 9259 (java) S 9254 9254 2059 34821 2220 4202560 18 0 0 0 0 0 0 0 15 0 10 0 875105679 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9260] ppid=9254 vsize=420920 CPUtime=0
/proc/9255/task/9260/stat : 9260 (java) S 9254 9254 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 18 0 10 0 875105679 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9261] ppid=9254 vsize=420920 CPUtime=0
/proc/9255/task/9261/stat : 9261 (java) S 9254 9254 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875105681 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9262] ppid=9254 vsize=420920 CPUtime=0.07
/proc/9255/task/9262/stat : 9262 (java) S 9254 9254 2059 34821 2220 4202560 525 0 0 0 7 0 0 0 15 0 10 0 875105681 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9263] ppid=9254 vsize=420920 CPUtime=0
/proc/9255/task/9263/stat : 9263 (java) S 9254 9254 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875105681 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9264] ppid=9254 vsize=420920 CPUtime=0
/proc/9255/task/9264/stat : 9264 (java) S 9254 9254 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 15 0 10 0 875105681 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
[pid=9255/tid=9265] ppid=9254 vsize=420920 CPUtime=0
/proc/9255/task/9265/stat : 9265 (java) S 9254 9254 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 25 0 10 0 875105993 431022080 57937 1283457024 134512640 134550932 4293056368 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920896 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 33.29
Current children cumulated vsize (KiB) 423496

Child status: 0
Real time (s): 33.3905
CPU time (s): 33.3461
CPU user time (s): 33.0821
CPU system time (s): 0.264016
CPU usage (%): 99.8669
Max. virtual memory (cumulated for all children) (KiB): 424200

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 33.0821
system time used= 0.264016
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 71236
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= 1264
involuntary context switches= 1599

runsolver used 0 second user time and 0 second system time

The end