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/rand0695fb.cudf.impossible.log.runsolver ./gj-paranoid-solver-0.1 /home/misc2010/data/2010/impossible//rand0695fb.cudf /home/misc2010/tmp/201012061533/gj-paranoid-solver-0.1/rand0695fb.cudf.impossible.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.39 1.22 0.80 3/51 3395
/proc/meminfo: memFree=168988/1048576 swapFree=2095580/2097144
[pid=3394] ppid=3393 vsize=2572 CPUtime=0
/proc/3394/stat : 3394 (gj-paranoid-sol) R 3393 3394 2059 34821 2220 4202496 358 0 0 0 0 0 0 0 25 0 1 0 874359765 2633728 271 1283457024 134512640 135304128 4294791648 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/3394/statm: 643 271 231 194 0 29 0
[pid=3395] ppid=3394 vsize=2572 CPUtime=0
/proc/3395/stat : 3395 (gj-paranoid-sol) R 3394 3394 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 25 0 1 0 874359765 2633728 40 1283457024 134512640 135304128 4294791648 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/3395/statm: 643 40 0 194 0 29 0

[startup+0.137068 s]
/proc/loadavg: 1.39 1.22 0.80 3/51 3395
/proc/meminfo: memFree=168988/1048576 swapFree=2095580/2097144
[pid=3394] ppid=3393 vsize=2572 CPUtime=0
/proc/3394/stat : 3394 (gj-paranoid-sol) S 3393 3394 2059 34821 2220 4202496 376 0 0 0 0 0 0 0 25 0 1 0 874359765 2633728 272 1283457024 134512640 135304128 4294791648 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3394/statm: 643 272 232 194 0 29 0
[pid=3395] ppid=3394 vsize=409944 CPUtime=0.13
/proc/3395/stat : 3395 (java) S 3394 3394 2059 34821 2220 4202496 3844 0 1 0 13 0 0 0 25 0 9 0 874359765 419782656 3309 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/3395/statm: 102486 3309 1868 10 0 96666 0
Current children cumulated CPU time (s) 0.13
Current children cumulated vsize (KiB) 412516

[startup+0.207073 s]
/proc/loadavg: 1.39 1.22 0.80 3/51 3395
/proc/meminfo: memFree=168988/1048576 swapFree=2095580/2097144
[pid=3394] ppid=3393 vsize=2572 CPUtime=0
/proc/3394/stat : 3394 (gj-paranoid-sol) S 3393 3394 2059 34821 2220 4202496 376 0 0 0 0 0 0 0 25 0 1 0 874359765 2633728 272 1283457024 134512640 135304128 4294791648 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3394/statm: 643 272 232 194 0 29 0
[pid=3395] ppid=3394 vsize=409944 CPUtime=0.2
/proc/3395/stat : 3395 (java) S 3394 3394 2059 34821 2220 4202496 4062 0 1 0 20 0 0 0 25 0 9 0 874359765 419782656 3527 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/3395/statm: 102486 3527 1868 10 0 96666 0
Current children cumulated CPU time (s) 0.2
Current children cumulated vsize (KiB) 412516

[startup+0.307098 s]
/proc/loadavg: 1.39 1.22 0.80 3/51 3395
/proc/meminfo: memFree=168988/1048576 swapFree=2095580/2097144
[pid=3394] ppid=3393 vsize=2572 CPUtime=0
/proc/3394/stat : 3394 (gj-paranoid-sol) S 3393 3394 2059 34821 2220 4202496 376 0 0 0 0 0 0 0 25 0 1 0 874359765 2633728 272 1283457024 134512640 135304128 4294791648 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3394/statm: 643 272 232 194 0 29 0
[pid=3395] ppid=3394 vsize=410104 CPUtime=0.3
/proc/3395/stat : 3395 (java) S 3394 3394 2059 34821 2220 4202496 4476 0 1 0 29 1 0 0 25 0 9 0 874359765 419946496 3941 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/3395/statm: 102526 3941 1882 10 0 96706 0
Current children cumulated CPU time (s) 0.3
Current children cumulated vsize (KiB) 412676

[startup+0.707182 s]
/proc/loadavg: 1.39 1.22 0.80 3/51 3395
/proc/meminfo: memFree=168988/1048576 swapFree=2095580/2097144
[pid=3394] ppid=3393 vsize=2572 CPUtime=0
/proc/3394/stat : 3394 (gj-paranoid-sol) S 3393 3394 2059 34821 2220 4202496 376 0 0 0 0 0 0 0 25 0 1 0 874359765 2633728 272 1283457024 134512640 135304128 4294791648 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3394/statm: 643 272 232 194 0 29 0
[pid=3395] ppid=3394 vsize=410708 CPUtime=0.7
/proc/3395/stat : 3395 (java) S 3394 3394 2059 34821 2220 4202496 12837 0 1 0 68 2 0 0 25 0 9 0 874359765 420564992 12123 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/3395/statm: 102677 12123 2878 10 0 96857 0
Current children cumulated CPU time (s) 0.7
Current children cumulated vsize (KiB) 413280

[startup+1.50732 s]
/proc/loadavg: 1.39 1.22 0.80 2/60 3404
/proc/meminfo: memFree=109136/1048576 swapFree=2095580/2097144
[pid=3394] ppid=3393 vsize=2572 CPUtime=0
/proc/3394/stat : 3394 (gj-paranoid-sol) S 3393 3394 2059 34821 2220 4202496 376 0 0 0 0 0 0 0 25 0 1 0 874359765 2633728 272 1283457024 134512640 135304128 4294791648 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3394/statm: 643 272 232 194 0 29 0
[pid=3395] ppid=3394 vsize=410840 CPUtime=1.5
/proc/3395/stat : 3395 (java) S 3394 3394 2059 34821 2220 4202496 28067 0 1 0 142 8 0 0 25 0 9 0 874359765 420700160 27353 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/3395/statm: 102710 27353 2878 10 0 96890 0
[pid=3395/tid=3397] ppid=3394 vsize=410840 CPUtime=0.71
/proc/3395/task/3397/stat : 3397 (java) R 3394 3394 2059 34821 2220 4202560 6663 0 1 0 68 3 0 0 24 0 9 0 874359766 420700160 27353 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=3395/tid=3398] ppid=3394 vsize=410840 CPUtime=0.75
/proc/3395/task/3398/stat : 3398 (java) R 3394 3394 2059 34821 2220 4202560 20008 0 0 0 71 4 0 0 20 0 9 0 874359766 420700160 27353 1283457024 134512640 134550932 4290403600 18446744073709551615 4153084410 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=3395/tid=3399] ppid=3394 vsize=410840 CPUtime=0
/proc/3395/task/3399/stat : 3399 (java) S 3394 3394 2059 34821 2220 4202560 18 0 0 0 0 0 0 0 20 0 9 0 874359766 420700160 27353 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3400] ppid=3394 vsize=410840 CPUtime=0
/proc/3395/task/3400/stat : 3400 (java) S 3394 3394 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 23 0 9 0 874359766 420700160 27353 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3401] ppid=3394 vsize=410840 CPUtime=0
/proc/3395/task/3401/stat : 3401 (java) S 3394 3394 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 9 0 874359768 420700160 27353 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3402] ppid=3394 vsize=410840 CPUtime=0.02
/proc/3395/task/3402/stat : 3402 (java) S 3394 3394 2059 34821 2220 4202560 462 0 0 0 2 0 0 0 17 0 9 0 874359768 420700160 27353 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3403] ppid=3394 vsize=410840 CPUtime=0
/proc/3395/task/3403/stat : 3403 (java) S 3394 3394 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 9 0 874359768 420700160 27353 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3404] ppid=3394 vsize=410840 CPUtime=0
/proc/3395/task/3404/stat : 3404 (java) S 3394 3394 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 9 0 874359768 420700160 27353 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.5
Current children cumulated vsize (KiB) 413412

[startup+3.10761 s]
/proc/loadavg: 1.39 1.22 0.80 3/60 3404
/proc/meminfo: memFree=18492/1048576 swapFree=2095580/2097144
[pid=3394] ppid=3393 vsize=2572 CPUtime=0
/proc/3394/stat : 3394 (gj-paranoid-sol) S 3393 3394 2059 34821 2220 4202496 376 0 0 0 0 0 0 0 25 0 1 0 874359765 2633728 272 1283457024 134512640 135304128 4294791648 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3394/statm: 643 272 232 194 0 29 0
[pid=3395] ppid=3394 vsize=410840 CPUtime=3.08
/proc/3395/stat : 3395 (java) S 3394 3394 2059 34821 2220 4202496 55537 0 1 0 288 20 0 0 25 0 9 0 874359765 420700160 54823 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/3395/statm: 102710 54823 2879 10 0 96890 0
[pid=3395/tid=3397] ppid=3394 vsize=410840 CPUtime=1.24
/proc/3395/task/3397/stat : 3397 (java) R 3394 3394 2059 34821 2220 4202560 14056 0 1 0 115 9 0 0 25 0 9 0 874359766 420700160 54823 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=3395/tid=3398] ppid=3394 vsize=410840 CPUtime=1.8
/proc/3395/task/3398/stat : 3398 (java) R 3394 3394 2059 34821 2220 4202560 40081 0 0 0 170 10 0 0 16 0 9 0 874359766 420700160 54823 1283457024 134512640 134550932 4290403600 18446744073709551615 4151725392 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=3395/tid=3399] ppid=3394 vsize=410840 CPUtime=0
/proc/3395/task/3399/stat : 3399 (java) S 3394 3394 2059 34821 2220 4202560 18 0 0 0 0 0 0 0 20 0 9 0 874359766 420700160 54823 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3400] ppid=3394 vsize=410840 CPUtime=0
/proc/3395/task/3400/stat : 3400 (java) S 3394 3394 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 23 0 9 0 874359766 420700160 54823 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3401] ppid=3394 vsize=410840 CPUtime=0
/proc/3395/task/3401/stat : 3401 (java) S 3394 3394 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 9 0 874359768 420700160 54823 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3402] ppid=3394 vsize=410840 CPUtime=0.02
/proc/3395/task/3402/stat : 3402 (java) S 3394 3394 2059 34821 2220 4202560 466 0 0 0 2 0 0 0 15 0 9 0 874359768 420700160 54823 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3403] ppid=3394 vsize=410840 CPUtime=0
/proc/3395/task/3403/stat : 3403 (java) S 3394 3394 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 9 0 874359768 420700160 54823 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3404] ppid=3394 vsize=410840 CPUtime=0
/proc/3395/task/3404/stat : 3404 (java) S 3394 3394 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 9 0 874359768 420700160 54823 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.08
Current children cumulated vsize (KiB) 413412

[startup+6.30854 s]
/proc/loadavg: 1.52 1.25 0.81 3/60 3404
/proc/meminfo: memFree=5644/1048576 swapFree=2095580/2097144
[pid=3394] ppid=3393 vsize=2572 CPUtime=0
/proc/3394/stat : 3394 (gj-paranoid-sol) S 3393 3394 2059 34821 2220 4202496 376 0 0 0 0 0 0 0 25 0 1 0 874359765 2633728 272 1283457024 134512640 135304128 4294791648 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3394/statm: 643 272 232 194 0 29 0
[pid=3395] ppid=3394 vsize=447932 CPUtime=6.25
/proc/3395/stat : 3395 (java) S 3394 3394 2059 34821 2220 4202496 80123 0 1 0 599 26 0 0 25 0 9 0 874359765 458682368 79404 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/3395/statm: 111983 79404 2880 10 0 106163 0
[pid=3395/tid=3397] ppid=3394 vsize=447932 CPUtime=1.98
/proc/3395/task/3397/stat : 3397 (java) R 3394 3394 2059 34821 2220 4202560 14068 0 1 0 189 9 0 0 25 0 9 0 874359766 458682368 79404 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=3395/tid=3398] ppid=3394 vsize=447932 CPUtime=4.24
/proc/3395/task/3398/stat : 3398 (java) R 3394 3394 2059 34821 2220 4202560 64637 0 0 0 408 16 0 0 16 0 9 0 874359766 458682368 79404 1283457024 134512640 134550932 4290403600 18446744073709551615 4153497372 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=3395/tid=3399] ppid=3394 vsize=447932 CPUtime=0
/proc/3395/task/3399/stat : 3399 (java) S 3394 3394 2059 34821 2220 4202560 18 0 0 0 0 0 0 0 20 0 9 0 874359766 458682368 79404 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3400] ppid=3394 vsize=447932 CPUtime=0
/proc/3395/task/3400/stat : 3400 (java) S 3394 3394 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 23 0 9 0 874359766 458682368 79404 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3401] ppid=3394 vsize=447932 CPUtime=0
/proc/3395/task/3401/stat : 3401 (java) S 3394 3394 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 9 0 874359768 458682368 79404 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3402] ppid=3394 vsize=447932 CPUtime=0.02
/proc/3395/task/3402/stat : 3402 (java) S 3394 3394 2059 34821 2220 4202560 484 0 0 0 2 0 0 0 15 0 9 0 874359768 458682368 79404 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3403] ppid=3394 vsize=447932 CPUtime=0
/proc/3395/task/3403/stat : 3403 (java) S 3394 3394 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 9 0 874359768 458682368 79404 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3404] ppid=3394 vsize=447932 CPUtime=0
/proc/3395/task/3404/stat : 3404 (java) S 3394 3394 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 9 0 874359768 458682368 79404 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.25
Current children cumulated vsize (KiB) 450504

[startup+12.7106 s]
/proc/loadavg: 1.64 1.28 0.82 4/60 3404
/proc/meminfo: memFree=5476/1048576 swapFree=2095580/2097144
[pid=3394] ppid=3393 vsize=2572 CPUtime=0
/proc/3394/stat : 3394 (gj-paranoid-sol) S 3393 3394 2059 34821 2220 4202496 376 0 0 0 0 0 0 0 25 0 1 0 874359765 2633728 272 1283457024 134512640 135304128 4294791648 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3394/statm: 643 272 232 194 0 29 0
[pid=3395] ppid=3394 vsize=434372 CPUtime=12.66
/proc/3395/stat : 3395 (java) S 3394 3394 2059 34821 2220 4202496 112278 0 1 0 1221 45 0 0 25 0 9 0 874359765 444796928 76096 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/3395/statm: 108593 76096 2880 10 0 102773 0
[pid=3395/tid=3397] ppid=3394 vsize=434372 CPUtime=2.64
/proc/3395/task/3397/stat : 3397 (java) R 3394 3394 2059 34821 2220 4202560 14142 0 1 0 254 10 0 0 25 0 9 0 874359766 444796928 76096 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=3395/tid=3398] ppid=3394 vsize=434372 CPUtime=9.96
/proc/3395/task/3398/stat : 3398 (java) R 3394 3394 2059 34821 2220 4202560 96706 0 0 0 963 33 0 0 16 0 9 0 874359766 444796928 76096 1283457024 134512640 134550932 4290403600 18446744073709551615 4151804408 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=3395/tid=3399] ppid=3394 vsize=434372 CPUtime=0
/proc/3395/task/3399/stat : 3399 (java) S 3394 3394 2059 34821 2220 4202560 18 0 0 0 0 0 0 0 18 0 9 0 874359766 444796928 76096 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3400] ppid=3394 vsize=434372 CPUtime=0
/proc/3395/task/3400/stat : 3400 (java) S 3394 3394 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 18 0 9 0 874359766 444796928 76096 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3401] ppid=3394 vsize=434372 CPUtime=0
/proc/3395/task/3401/stat : 3401 (java) S 3394 3394 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 9 0 874359768 444796928 76096 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3402] ppid=3394 vsize=434372 CPUtime=0.04
/proc/3395/task/3402/stat : 3402 (java) S 3394 3394 2059 34821 2220 4202560 496 0 0 0 4 0 0 0 15 0 9 0 874359768 444796928 76096 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3403] ppid=3394 vsize=434372 CPUtime=0
/proc/3395/task/3403/stat : 3403 (java) S 3394 3394 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 9 0 874359768 444796928 76096 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3404] ppid=3394 vsize=434372 CPUtime=0
/proc/3395/task/3404/stat : 3404 (java) S 3394 3394 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 9 0 874359768 444796928 76096 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 12.66
Current children cumulated vsize (KiB) 436944

[startup+25.5043 s]
/proc/loadavg: 1.79 1.33 0.84 2/61 3405
/proc/meminfo: memFree=5344/1048576 swapFree=2095580/2097144
[pid=3394] ppid=3393 vsize=2572 CPUtime=0
/proc/3394/stat : 3394 (gj-paranoid-sol) S 3393 3394 2059 34821 2220 4202496 376 0 0 0 0 0 0 0 25 0 1 0 874359765 2633728 272 1283457024 134512640 135304128 4294791648 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3394/statm: 643 272 232 194 0 29 0
[pid=3395] ppid=3394 vsize=447680 CPUtime=25.44
/proc/3395/stat : 3395 (java) S 3394 3394 2059 34821 2220 4202496 150238 0 1 0 2488 56 0 0 25 0 10 0 874359765 458424320 79407 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/3395/statm: 111920 79407 2883 10 0 106100 0
[pid=3395/tid=3397] ppid=3394 vsize=447680 CPUtime=8.83
/proc/3395/task/3397/stat : 3397 (java) R 3394 3394 2059 34821 2220 4202560 14163 0 1 0 873 10 0 0 25 0 10 0 874359766 458424320 79407 1283457024 134512640 134550932 4290403600 18446744073709551615 4115947621 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=3395/tid=3398] ppid=3394 vsize=447680 CPUtime=16.52
/proc/3395/task/3398/stat : 3398 (java) S 3394 3394 2059 34821 2220 4202560 134605 0 0 0 1608 44 0 0 19 0 10 0 874359766 458424320 79407 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 0 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3399] ppid=3394 vsize=447680 CPUtime=0
/proc/3395/task/3399/stat : 3399 (java) S 3394 3394 2059 34821 2220 4202560 18 0 0 0 0 0 0 0 18 0 10 0 874359766 458424320 79407 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3400] ppid=3394 vsize=447680 CPUtime=0
/proc/3395/task/3400/stat : 3400 (java) S 3394 3394 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 18 0 10 0 874359766 458424320 79407 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3401] ppid=3394 vsize=447680 CPUtime=0
/proc/3395/task/3401/stat : 3401 (java) S 3394 3394 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 874359768 458424320 79407 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3402] ppid=3394 vsize=447680 CPUtime=0.06
/proc/3395/task/3402/stat : 3402 (java) S 3394 3394 2059 34821 2220 4202560 531 0 0 0 6 0 0 0 16 0 10 0 874359768 458424320 79407 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3403] ppid=3394 vsize=447680 CPUtime=0
/proc/3395/task/3403/stat : 3403 (java) S 3394 3394 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 874359768 458424320 79407 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3404] ppid=3394 vsize=447680 CPUtime=0
/proc/3395/task/3404/stat : 3404 (java) S 3394 3394 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 10 0 874359768 458424320 79407 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3405] ppid=3394 vsize=447680 CPUtime=0
/proc/3395/task/3405/stat : 3405 (java) S 3394 3394 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 24 0 10 0 874361627 458424320 79407 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 25.44
Current children cumulated vsize (KiB) 450252

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

[startup+25.6043 s]
/proc/loadavg: 1.79 1.33 0.84 2/61 3405
/proc/meminfo: memFree=5344/1048576 swapFree=2095580/2097144
[pid=3394] ppid=3393 vsize=2572 CPUtime=0
/proc/3394/stat : 3394 (gj-paranoid-sol) S 3393 3394 2059 34821 2220 4202496 376 0 0 0 0 0 0 0 25 0 1 0 874359765 2633728 272 1283457024 134512640 135304128 4294791648 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3394/statm: 643 272 232 194 0 29 0
[pid=3395] ppid=3394 vsize=447680 CPUtime=25.54
/proc/3395/stat : 3395 (java) S 3394 3394 2059 34821 2220 4202496 150238 0 1 0 2498 56 0 0 25 0 10 0 874359765 458424320 79407 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/3395/statm: 111920 79407 2883 10 0 106100 0
[pid=3395/tid=3397] ppid=3394 vsize=447680 CPUtime=8.93
/proc/3395/task/3397/stat : 3397 (java) R 3394 3394 2059 34821 2220 4202560 14163 0 1 0 883 10 0 0 25 0 10 0 874359766 458424320 79407 1283457024 134512640 134550932 4290403600 18446744073709551615 4116005117 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=3395/tid=3398] ppid=3394 vsize=447680 CPUtime=16.52
/proc/3395/task/3398/stat : 3398 (java) S 3394 3394 2059 34821 2220 4202560 134605 0 0 0 1608 44 0 0 19 0 10 0 874359766 458424320 79407 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 0 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3399] ppid=3394 vsize=447680 CPUtime=0
/proc/3395/task/3399/stat : 3399 (java) S 3394 3394 2059 34821 2220 4202560 18 0 0 0 0 0 0 0 18 0 10 0 874359766 458424320 79407 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3400] ppid=3394 vsize=447680 CPUtime=0
/proc/3395/task/3400/stat : 3400 (java) S 3394 3394 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 18 0 10 0 874359766 458424320 79407 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3401] ppid=3394 vsize=447680 CPUtime=0
/proc/3395/task/3401/stat : 3401 (java) S 3394 3394 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 874359768 458424320 79407 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3402] ppid=3394 vsize=447680 CPUtime=0.06
/proc/3395/task/3402/stat : 3402 (java) S 3394 3394 2059 34821 2220 4202560 531 0 0 0 6 0 0 0 16 0 10 0 874359768 458424320 79407 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3403] ppid=3394 vsize=447680 CPUtime=0
/proc/3395/task/3403/stat : 3403 (java) S 3394 3394 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 874359768 458424320 79407 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3404] ppid=3394 vsize=447680 CPUtime=0
/proc/3395/task/3404/stat : 3404 (java) S 3394 3394 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 10 0 874359768 458424320 79407 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3405] ppid=3394 vsize=447680 CPUtime=0
/proc/3395/task/3405/stat : 3405 (java) S 3394 3394 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 24 0 10 0 874361627 458424320 79407 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 25.54
Current children cumulated vsize (KiB) 450252

[startup+38.4074 s]
/proc/loadavg: 1.74 1.33 0.85 2/61 3405
/proc/meminfo: memFree=6112/1048576 swapFree=2095580/2097144
[pid=3394] ppid=3393 vsize=2572 CPUtime=0
/proc/3394/stat : 3394 (gj-paranoid-sol) S 3393 3394 2059 34821 2220 4202496 376 0 0 0 0 0 0 0 25 0 1 0 874359765 2633728 272 1283457024 134512640 135304128 4294791648 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3394/statm: 643 272 232 194 0 29 0
[pid=3395] ppid=3394 vsize=447548 CPUtime=38.33
/proc/3395/stat : 3395 (java) S 3394 3394 2059 34821 2220 4202496 157196 0 1 0 3775 58 0 0 25 0 10 0 874359765 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/3395/statm: 111887 79371 2883 10 0 106067 0
[pid=3395/tid=3397] ppid=3394 vsize=447548 CPUtime=20.55
/proc/3395/task/3397/stat : 3397 (java) R 3394 3394 2059 34821 2220 4202560 14163 0 1 0 2045 10 0 0 25 0 10 0 874359766 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4115995844 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=3395/tid=3398] ppid=3394 vsize=447548 CPUtime=17.7
/proc/3395/task/3398/stat : 3398 (java) S 3394 3394 2059 34821 2220 4202560 141562 0 0 0 1723 47 0 0 18 0 10 0 874359766 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 0 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3399] ppid=3394 vsize=447548 CPUtime=0
/proc/3395/task/3399/stat : 3399 (java) S 3394 3394 2059 34821 2220 4202560 18 0 0 0 0 0 0 0 18 0 10 0 874359766 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3400] ppid=3394 vsize=447548 CPUtime=0
/proc/3395/task/3400/stat : 3400 (java) S 3394 3394 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 18 0 10 0 874359766 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3401] ppid=3394 vsize=447548 CPUtime=0
/proc/3395/task/3401/stat : 3401 (java) S 3394 3394 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 874359768 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3402] ppid=3394 vsize=447548 CPUtime=0.06
/proc/3395/task/3402/stat : 3402 (java) S 3394 3394 2059 34821 2220 4202560 532 0 0 0 6 0 0 0 15 0 10 0 874359768 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3403] ppid=3394 vsize=447548 CPUtime=0
/proc/3395/task/3403/stat : 3403 (java) S 3394 3394 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 874359768 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3404] ppid=3394 vsize=447548 CPUtime=0
/proc/3395/task/3404/stat : 3404 (java) S 3394 3394 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 10 0 874359768 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3405] ppid=3394 vsize=447548 CPUtime=0
/proc/3395/task/3405/stat : 3405 (java) S 3394 3394 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 24 0 10 0 874361627 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 38.33
Current children cumulated vsize (KiB) 450120

[startup+44.8087 s]
/proc/loadavg: 1.77 1.35 0.86 2/61 3405
/proc/meminfo: memFree=6484/1048576 swapFree=2095580/2097144
[pid=3394] ppid=3393 vsize=2572 CPUtime=0
/proc/3394/stat : 3394 (gj-paranoid-sol) S 3393 3394 2059 34821 2220 4202496 376 0 0 0 0 0 0 0 25 0 1 0 874359765 2633728 272 1283457024 134512640 135304128 4294791648 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3394/statm: 643 272 232 194 0 29 0
[pid=3395] ppid=3394 vsize=447548 CPUtime=44.74
/proc/3395/stat : 3395 (java) S 3394 3394 2059 34821 2220 4202496 164153 0 1 0 4415 59 0 0 25 0 10 0 874359765 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/3395/statm: 111887 79371 2883 10 0 106067 0
[pid=3395/tid=3397] ppid=3394 vsize=447548 CPUtime=25.65
/proc/3395/task/3397/stat : 3397 (java) R 3394 3394 2059 34821 2220 4202560 14163 0 1 0 2555 10 0 0 25 0 10 0 874359766 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4115997944 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=3395/tid=3398] ppid=3394 vsize=447548 CPUtime=19
/proc/3395/task/3398/stat : 3398 (java) S 3394 3394 2059 34821 2220 4202560 148519 0 0 0 1852 48 0 0 15 0 10 0 874359766 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 0 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3399] ppid=3394 vsize=447548 CPUtime=0
/proc/3395/task/3399/stat : 3399 (java) S 3394 3394 2059 34821 2220 4202560 18 0 0 0 0 0 0 0 18 0 10 0 874359766 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3400] ppid=3394 vsize=447548 CPUtime=0
/proc/3395/task/3400/stat : 3400 (java) S 3394 3394 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 18 0 10 0 874359766 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3401] ppid=3394 vsize=447548 CPUtime=0
/proc/3395/task/3401/stat : 3401 (java) S 3394 3394 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 874359768 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3402] ppid=3394 vsize=447548 CPUtime=0.06
/proc/3395/task/3402/stat : 3402 (java) S 3394 3394 2059 34821 2220 4202560 532 0 0 0 6 0 0 0 15 0 10 0 874359768 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3403] ppid=3394 vsize=447548 CPUtime=0
/proc/3395/task/3403/stat : 3403 (java) S 3394 3394 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 874359768 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3404] ppid=3394 vsize=447548 CPUtime=0
/proc/3395/task/3404/stat : 3404 (java) R 3394 3394 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 10 0 874359768 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=3395/tid=3405] ppid=3394 vsize=447548 CPUtime=0
/proc/3395/task/3405/stat : 3405 (java) S 3394 3394 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 24 0 10 0 874361627 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 44.74
Current children cumulated vsize (KiB) 450120

[startup+46.409 s]
/proc/loadavg: 1.77 1.35 0.86 2/61 3405
/proc/meminfo: memFree=6484/1048576 swapFree=2095580/2097144
[pid=3394] ppid=3393 vsize=2572 CPUtime=0
/proc/3394/stat : 3394 (gj-paranoid-sol) S 3393 3394 2059 34821 2220 4202496 376 0 0 0 0 0 0 0 25 0 1 0 874359765 2633728 272 1283457024 134512640 135304128 4294791648 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3394/statm: 643 272 232 194 0 29 0
[pid=3395] ppid=3394 vsize=447548 CPUtime=46.34
/proc/3395/stat : 3395 (java) S 3394 3394 2059 34821 2220 4202496 164153 0 1 0 4575 59 0 0 25 0 10 0 874359765 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/3395/statm: 111887 79371 2883 10 0 106067 0
[pid=3395/tid=3397] ppid=3394 vsize=447548 CPUtime=27.25
/proc/3395/task/3397/stat : 3397 (java) R 3394 3394 2059 34821 2220 4202560 14163 0 1 0 2715 10 0 0 25 0 10 0 874359766 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4116084112 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=3395/tid=3398] ppid=3394 vsize=447548 CPUtime=19
/proc/3395/task/3398/stat : 3398 (java) S 3394 3394 2059 34821 2220 4202560 148519 0 0 0 1852 48 0 0 15 0 10 0 874359766 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 0 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3399] ppid=3394 vsize=447548 CPUtime=0
/proc/3395/task/3399/stat : 3399 (java) S 3394 3394 2059 34821 2220 4202560 18 0 0 0 0 0 0 0 18 0 10 0 874359766 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3400] ppid=3394 vsize=447548 CPUtime=0
/proc/3395/task/3400/stat : 3400 (java) S 3394 3394 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 18 0 10 0 874359766 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3401] ppid=3394 vsize=447548 CPUtime=0
/proc/3395/task/3401/stat : 3401 (java) S 3394 3394 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 874359768 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3402] ppid=3394 vsize=447548 CPUtime=0.06
/proc/3395/task/3402/stat : 3402 (java) S 3394 3394 2059 34821 2220 4202560 532 0 0 0 6 0 0 0 15 0 10 0 874359768 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3403] ppid=3394 vsize=447548 CPUtime=0
/proc/3395/task/3403/stat : 3403 (java) S 3394 3394 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 874359768 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3404] ppid=3394 vsize=447548 CPUtime=0
/proc/3395/task/3404/stat : 3404 (java) S 3394 3394 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 10 0 874359768 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3405] ppid=3394 vsize=447548 CPUtime=0
/proc/3395/task/3405/stat : 3405 (java) S 3394 3394 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 24 0 10 0 874361627 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 46.34
Current children cumulated vsize (KiB) 450120

[startup+48.0093 s]
/proc/loadavg: 1.77 1.35 0.86 2/61 3405
/proc/meminfo: memFree=6484/1048576 swapFree=2095580/2097144
[pid=3394] ppid=3393 vsize=2572 CPUtime=0
/proc/3394/stat : 3394 (gj-paranoid-sol) S 3393 3394 2059 34821 2220 4202496 376 0 0 0 0 0 0 0 25 0 1 0 874359765 2633728 272 1283457024 134512640 135304128 4294791648 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3394/statm: 643 272 232 194 0 29 0
[pid=3395] ppid=3394 vsize=443456 CPUtime=47.94
/proc/3395/stat : 3395 (java) S 3394 3394 2059 34821 2220 4202496 170092 0 1 0 4732 62 0 0 25 0 10 0 874359765 454098944 78353 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/3395/statm: 110864 78353 2883 10 0 105044 0
[pid=3395/tid=3397] ppid=3394 vsize=443456 CPUtime=28.37
/proc/3395/task/3397/stat : 3397 (java) R 3394 3394 2059 34821 2220 4202560 14163 0 1 0 2827 10 0 0 25 0 10 0 874359766 454098944 78353 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=3395/tid=3398] ppid=3394 vsize=443456 CPUtime=19.48
/proc/3395/task/3398/stat : 3398 (java) R 3394 3394 2059 34821 2220 4202560 154458 0 0 0 1898 50 0 0 16 0 10 0 874359766 454098944 78353 1283457024 134512640 134550932 4290403600 18446744073709551615 4150114281 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=3395/tid=3399] ppid=3394 vsize=443456 CPUtime=0
/proc/3395/task/3399/stat : 3399 (java) S 3394 3394 2059 34821 2220 4202560 18 0 0 0 0 0 0 0 18 0 10 0 874359766 454098944 78353 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3400] ppid=3394 vsize=443456 CPUtime=0
/proc/3395/task/3400/stat : 3400 (java) S 3394 3394 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 18 0 10 0 874359766 454098944 78353 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3401] ppid=3394 vsize=443456 CPUtime=0
/proc/3395/task/3401/stat : 3401 (java) S 3394 3394 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 874359768 454098944 78353 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3402] ppid=3394 vsize=443456 CPUtime=0.06
/proc/3395/task/3402/stat : 3402 (java) S 3394 3394 2059 34821 2220 4202560 532 0 0 0 6 0 0 0 15 0 10 0 874359768 454098944 78353 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3403] ppid=3394 vsize=443456 CPUtime=0
/proc/3395/task/3403/stat : 3403 (java) S 3394 3394 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 874359768 454098944 78353 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3404] ppid=3394 vsize=443456 CPUtime=0
/proc/3395/task/3404/stat : 3404 (java) S 3394 3394 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 10 0 874359768 454098944 78353 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3405] ppid=3394 vsize=443456 CPUtime=0
/proc/3395/task/3405/stat : 3405 (java) S 3394 3394 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 24 0 10 0 874361627 454098944 78353 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 47.94
Current children cumulated vsize (KiB) 446028

[startup+48.4094 s]
/proc/loadavg: 1.77 1.35 0.86 3/61 3405
/proc/meminfo: memFree=6112/1048576 swapFree=2095580/2097144
[pid=3394] ppid=3393 vsize=2572 CPUtime=0
/proc/3394/stat : 3394 (gj-paranoid-sol) S 3393 3394 2059 34821 2220 4202496 376 0 0 0 0 0 0 0 25 0 1 0 874359765 2633728 272 1283457024 134512640 135304128 4294791648 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3394/statm: 643 272 232 194 0 29 0
[pid=3395] ppid=3394 vsize=447548 CPUtime=48.34
/proc/3395/stat : 3395 (java) S 3394 3394 2059 34821 2220 4202496 171110 0 1 0 4772 62 0 0 25 0 10 0 874359765 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/3395/statm: 111887 79371 2883 10 0 106067 0
[pid=3395/tid=3397] ppid=3394 vsize=447548 CPUtime=28.37
/proc/3395/task/3397/stat : 3397 (java) R 3394 3394 2059 34821 2220 4202560 14163 0 1 0 2827 10 0 0 25 0 10 0 874359766 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=3395/tid=3398] ppid=3394 vsize=447548 CPUtime=19.88
/proc/3395/task/3398/stat : 3398 (java) R 3394 3394 2059 34821 2220 4202560 155476 0 0 0 1938 50 0 0 16 0 10 0 874359766 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4151233351 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=3395/tid=3399] ppid=3394 vsize=447548 CPUtime=0
/proc/3395/task/3399/stat : 3399 (java) S 3394 3394 2059 34821 2220 4202560 18 0 0 0 0 0 0 0 18 0 10 0 874359766 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3400] ppid=3394 vsize=447548 CPUtime=0
/proc/3395/task/3400/stat : 3400 (java) S 3394 3394 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 18 0 10 0 874359766 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3401] ppid=3394 vsize=447548 CPUtime=0
/proc/3395/task/3401/stat : 3401 (java) S 3394 3394 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 874359768 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3402] ppid=3394 vsize=447548 CPUtime=0.06
/proc/3395/task/3402/stat : 3402 (java) S 3394 3394 2059 34821 2220 4202560 532 0 0 0 6 0 0 0 15 0 10 0 874359768 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3403] ppid=3394 vsize=447548 CPUtime=0
/proc/3395/task/3403/stat : 3403 (java) S 3394 3394 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 874359768 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3404] ppid=3394 vsize=447548 CPUtime=0
/proc/3395/task/3404/stat : 3404 (java) S 3394 3394 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 10 0 874359768 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
[pid=3395/tid=3405] ppid=3394 vsize=447548 CPUtime=0
/proc/3395/task/3405/stat : 3405 (java) S 3394 3394 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 24 0 10 0 874361627 458289152 79371 1283457024 134512640 134550932 4290403600 18446744073709551615 4294960130 0 4 0 16800975 18446612132680192128 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 48.34
Current children cumulated vsize (KiB) 450120

[startup+48.8091 s]
/proc/loadavg: 1.77 1.35 0.86 3/61 3405
/proc/meminfo: memFree=6112/1048576 swapFree=2095580/2097144
[pid=3394] ppid=3393 vsize=2572 CPUtime=0
/proc/3394/stat : 3394 (gj-paranoid-sol) S 3393 3394 2059 34821 2220 4202496 376 0 0 0 0 0 0 0 25 0 1 0 874359765 2633728 272 1283457024 134512640 135304128 4294791648 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3394/statm: 643 272 232 194 0 29 0
[pid=3395] ppid=3394 vsize=0 CPUtime=48.71
/proc/3395/stat : 3395 (java) Z 3394 3394 2059 34821 2220 4202508 171117 0 1 0 4806 65 0 0 18 0 2 0 874359765 0 0 1283457024 0 0 0 0 0 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/3395/statm: 0 0 0 0 0 0 0
[pid=3395/tid=3403] ppid=3394 vsize=0 CPUtime=0.03
/proc/3395/task/3403/stat : 3403 (java) R 3394 3394 2059 34821 2220 4203588 1 0 0 0 0 3 0 0 18 0 2 0 874359768 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) 48.71
Current children cumulated vsize (KiB) 2572

Child status: 0
Real time (s): 48.8107
CPU time (s): 48.719
CPU user time (s): 48.067
CPU system time (s): 0.65204
CPU usage (%): 99.8123
Max. virtual memory (cumulated for all children) (KiB): 450504

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 48.067
system time used= 0.65204
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 171504
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= 1565
involuntary context switches= 2159

runsolver used 0 second user time and 0 second system time

The end