runsolver Copyright (C) 2010 Olivier ROUSSEL

This is runsolver version 3.2.9a (svn: 651)

This program is distributed in the hope that it will be useful,
but WITHOUT ANY WARRANTY; without even the implied warranty of
MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
GNU General Public License for more details.

command line: /home/misc2010/bin/runsolver -s SIGUSR1 -M 1124 -C 290 -d 10 -w /home/misc2010/tmp/201108251442/gj-paranoid-solver-1.0/rand283.cudf.user-upgrades.log.runsolver ./gj-paranoid-solver-1.0 /home/misc2010/data/2011/user-upgrades/rand283.cudf /home/misc2010/tmp/201108251442/gj-paranoid-solver-1.0/rand283.cudf.user-upgrades.result 

Enforcing CPUTime limit (soft limit, will send signal-name then SIGKILL): 290 seconds
Enforcing CPUTime limit (hard limit, will send SIGXCPU): 320 seconds
Enforcing VSIZE limit (soft limit, will send signal-name then SIGKILL): 1150976 KiB
Enforcing VSIZE limit (hard limit, stack expansion will fail with SIGSEGV, brk() and mmap() will return ENOMEM): 1202176 KiB
Current StackSize limit: 8192 KiB


[startup+0 s]
/proc/loadavg: 1.86 1.41 1.16 5/34 13365
/proc/meminfo: memFree=297928/1048576 swapFree=0/0
[pid=13364] ppid=13363 vsize=2568 CPUtime=0
/proc/13364/stat : 13364 (gj-paranoid-sol) R 13363 13364 4778 34817 4778 4202496 354 0 0 0 0 0 0 0 25 0 1 0 10593932 2629632 268 1283457024 134512640 135304128 4290325920 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/13364/statm: 642 268 228 194 0 29 0
[pid=13365] ppid=13364 vsize=2568 CPUtime=0
/proc/13365/stat : 13365 (gj-paranoid-sol) R 13364 13364 4778 34817 4778 4202560 0 0 0 0 0 0 0 0 25 0 1 0 10593932 2629632 40 1283457024 134512640 135304128 4290325920 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/13365/statm: 642 40 0 194 0 29 0

[startup+0.185386 s]
/proc/loadavg: 1.86 1.41 1.16 5/34 13365
/proc/meminfo: memFree=297928/1048576 swapFree=0/0
[pid=13364] ppid=13363 vsize=2568 CPUtime=0
/proc/13364/stat : 13364 (gj-paranoid-sol) S 13363 13364 4778 34817 4778 4202496 371 0 0 0 0 0 0 0 25 0 1 0 10593932 2629632 269 1283457024 134512640 135304128 4290325920 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/13364/statm: 642 269 229 194 0 29 0
[pid=13365] ppid=13364 vsize=409796 CPUtime=0.18
/proc/13365/stat : 13365 (java) S 13364 13364 4778 34817 4778 4202496 4037 0 1 0 16 2 0 0 25 0 9 0 10593932 419631104 3465 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/13365/statm: 102449 3465 1922 10 0 96597 0
Current children cumulated CPU time (s) 0.18
Current children cumulated vsize (KiB) 412364

[startup+0.205381 s]
/proc/loadavg: 1.86 1.41 1.16 5/34 13365
/proc/meminfo: memFree=297928/1048576 swapFree=0/0
[pid=13364] ppid=13363 vsize=2568 CPUtime=0
/proc/13364/stat : 13364 (gj-paranoid-sol) S 13363 13364 4778 34817 4778 4202496 371 0 0 0 0 0 0 0 25 0 1 0 10593932 2629632 269 1283457024 134512640 135304128 4290325920 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/13364/statm: 642 269 229 194 0 29 0
[pid=13365] ppid=13364 vsize=409796 CPUtime=0.2
/proc/13365/stat : 13365 (java) S 13364 13364 4778 34817 4778 4202496 4082 0 1 0 18 2 0 0 25 0 9 0 10593932 419631104 3510 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/13365/statm: 102449 3510 1922 10 0 96597 0
Current children cumulated CPU time (s) 0.2
Current children cumulated vsize (KiB) 412364

[startup+0.305403 s]
/proc/loadavg: 1.86 1.41 1.16 5/34 13365
/proc/meminfo: memFree=297928/1048576 swapFree=0/0
[pid=13364] ppid=13363 vsize=2568 CPUtime=0
/proc/13364/stat : 13364 (gj-paranoid-sol) S 13363 13364 4778 34817 4778 4202496 371 0 0 0 0 0 0 0 25 0 1 0 10593932 2629632 269 1283457024 134512640 135304128 4290325920 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/13364/statm: 642 269 229 194 0 29 0
[pid=13365] ppid=13364 vsize=410380 CPUtime=0.3
/proc/13365/stat : 13365 (java) S 13364 13364 4778 34817 4778 4202496 4433 0 1 0 27 3 0 0 25 0 9 0 10593932 420229120 3861 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/13365/statm: 102595 3861 1944 10 0 96743 0
Current children cumulated CPU time (s) 0.3
Current children cumulated vsize (KiB) 412948

[startup+0.705553 s]
/proc/loadavg: 1.86 1.41 1.16 5/34 13365
/proc/meminfo: memFree=297928/1048576 swapFree=0/0
[pid=13364] ppid=13363 vsize=2568 CPUtime=0
/proc/13364/stat : 13364 (gj-paranoid-sol) S 13363 13364 4778 34817 4778 4202496 371 0 0 0 0 0 0 0 25 0 1 0 10593932 2629632 269 1283457024 134512640 135304128 4290325920 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/13364/statm: 642 269 229 194 0 29 0
[pid=13365] ppid=13364 vsize=410648 CPUtime=0.7
/proc/13365/stat : 13365 (java) S 13364 13364 4778 34817 4778 4202496 11435 0 1 0 65 5 0 0 25 0 9 0 10593932 420503552 10676 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/13365/statm: 102662 10676 2901 10 0 96810 0
Current children cumulated CPU time (s) 0.7
Current children cumulated vsize (KiB) 413216

[startup+1.50583 s]
/proc/loadavg: 1.86 1.41 1.16 3/43 13374
/proc/meminfo: memFree=239564/1048576 swapFree=0/0
[pid=13364] ppid=13363 vsize=2568 CPUtime=0
/proc/13364/stat : 13364 (gj-paranoid-sol) S 13363 13364 4778 34817 4778 4202496 371 0 0 0 0 0 0 0 25 0 1 0 10593932 2629632 269 1283457024 134512640 135304128 4290325920 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/13364/statm: 642 269 229 194 0 29 0
[pid=13365] ppid=13364 vsize=410780 CPUtime=1.5
/proc/13365/stat : 13365 (java) S 13364 13364 4778 34817 4778 4202496 26394 0 1 0 141 9 0 0 25 0 9 0 10593932 420638720 25635 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/13365/statm: 102695 25635 2901 10 0 96843 0
[pid=13365/tid=13367] ppid=13364 vsize=410780 CPUtime=0.78
/proc/13365/task/13367/stat : 13367 (java) R 13364 13364 4778 34817 4778 4202560 6704 0 1 0 75 3 0 0 25 0 9 0 10593933 420638720 25635 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=13365/tid=13368] ppid=13364 vsize=410780 CPUtime=0.66
/proc/13365/task/13368/stat : 13368 (java) R 13364 13364 4778 34817 4778 4202560 18301 0 0 0 61 5 0 0 18 0 9 0 10593933 420638720 25635 1283457024 134512640 134550932 4290391296 18446744073709551615 4150601656 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=13365/tid=13369] ppid=13364 vsize=410780 CPUtime=0
/proc/13365/task/13369/stat : 13369 (java) S 13364 13364 4778 34817 4778 4202560 15 0 0 0 0 0 0 0 20 0 9 0 10593934 420638720 25635 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13370] ppid=13364 vsize=410780 CPUtime=0
/proc/13365/task/13370/stat : 13370 (java) S 13364 13364 4778 34817 4778 4202560 5 0 0 0 0 0 0 0 20 0 9 0 10593934 420638720 25635 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13371] ppid=13364 vsize=410780 CPUtime=0
/proc/13365/task/13371/stat : 13371 (java) S 13364 13364 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 9 0 10593935 420638720 25635 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13372] ppid=13364 vsize=410780 CPUtime=0.04
/proc/13365/task/13372/stat : 13372 (java) S 13364 13364 4778 34817 4778 4202560 449 0 0 0 4 0 0 0 16 0 9 0 10593935 420638720 25635 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13373] ppid=13364 vsize=410780 CPUtime=0
/proc/13365/task/13373/stat : 13373 (java) S 13364 13364 4778 34817 4778 4202560 0 0 0 0 0 0 0 0 25 0 9 0 10593935 420638720 25635 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13374] ppid=13364 vsize=410780 CPUtime=0
/proc/13365/task/13374/stat : 13374 (java) S 13364 13364 4778 34817 4778 4202560 2 0 0 0 0 0 0 0 15 0 9 0 10593935 420638720 25635 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.5
Current children cumulated vsize (KiB) 413348

[startup+3.12622 s]
/proc/loadavg: 1.86 1.41 1.16 2/43 13374
/proc/meminfo: memFree=167768/1048576 swapFree=0/0
[pid=13364] ppid=13363 vsize=2568 CPUtime=0
/proc/13364/stat : 13364 (gj-paranoid-sol) S 13363 13364 4778 34817 4778 4202496 371 0 0 0 0 0 0 0 25 0 1 0 10593932 2629632 269 1283457024 134512640 135304128 4290325920 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/13364/statm: 642 269 229 194 0 29 0
[pid=13365] ppid=13364 vsize=410780 CPUtime=3.12
/proc/13365/stat : 13365 (java) S 13364 13364 4778 34817 4778 4202496 50536 0 1 0 293 19 0 0 25 0 9 0 10593932 420638720 49777 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/13365/statm: 102695 49777 2901 10 0 96843 0
[pid=13365/tid=13367] ppid=13364 vsize=410780 CPUtime=1.38
/proc/13365/task/13367/stat : 13367 (java) R 13364 13364 4778 34817 4778 4202560 13857 0 1 0 129 9 0 0 25 0 9 0 10593933 420638720 49777 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=13365/tid=13368] ppid=13364 vsize=410780 CPUtime=1.67
/proc/13365/task/13368/stat : 13368 (java) R 13364 13364 4778 34817 4778 4202560 35287 0 0 0 158 9 0 0 15 0 9 0 10593933 420638720 49777 1283457024 134512640 134550932 4290391296 18446744073709551615 4150598809 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=13365/tid=13369] ppid=13364 vsize=410780 CPUtime=0
/proc/13365/task/13369/stat : 13369 (java) S 13364 13364 4778 34817 4778 4202560 15 0 0 0 0 0 0 0 20 0 9 0 10593934 420638720 49777 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13370] ppid=13364 vsize=410780 CPUtime=0
/proc/13365/task/13370/stat : 13370 (java) S 13364 13364 4778 34817 4778 4202560 5 0 0 0 0 0 0 0 20 0 9 0 10593934 420638720 49777 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13371] ppid=13364 vsize=410780 CPUtime=0
/proc/13365/task/13371/stat : 13371 (java) S 13364 13364 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 9 0 10593935 420638720 49777 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13372] ppid=13364 vsize=410780 CPUtime=0.05
/proc/13365/task/13372/stat : 13372 (java) S 13364 13364 4778 34817 4778 4202560 452 0 0 0 5 0 0 0 15 0 9 0 10593935 420638720 49777 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13373] ppid=13364 vsize=410780 CPUtime=0
/proc/13365/task/13373/stat : 13373 (java) S 13364 13364 4778 34817 4778 4202560 0 0 0 0 0 0 0 0 25 0 9 0 10593935 420638720 49777 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13374] ppid=13364 vsize=410780 CPUtime=0
/proc/13365/task/13374/stat : 13374 (java) S 13364 13364 4778 34817 4778 4202560 2 0 0 0 0 0 0 0 15 0 9 0 10593935 420638720 49777 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.12
Current children cumulated vsize (KiB) 413348

[startup+6.30719 s]
/proc/loadavg: 1.87 1.42 1.16 3/43 13374
/proc/meminfo: memFree=30872/1048576 swapFree=0/0
[pid=13364] ppid=13363 vsize=2568 CPUtime=0
/proc/13364/stat : 13364 (gj-paranoid-sol) S 13363 13364 4778 34817 4778 4202496 371 0 0 0 0 0 0 0 25 0 1 0 10593932 2629632 269 1283457024 134512640 135304128 4290325920 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/13364/statm: 642 269 229 194 0 29 0
[pid=13365] ppid=13364 vsize=439952 CPUtime=6.3
/proc/13365/stat : 13365 (java) S 13364 13364 4778 34817 4778 4202496 78232 0 1 0 601 29 0 0 25 0 9 0 10593932 450510848 77467 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/13365/statm: 109988 77467 2902 10 0 104136 0
[pid=13365/tid=13367] ppid=13364 vsize=439952 CPUtime=2.22
/proc/13365/task/13367/stat : 13367 (java) R 13364 13364 4778 34817 4778 4202560 13874 0 1 0 210 12 0 0 25 0 9 0 10593933 450510848 77467 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=13365/tid=13368] ppid=13364 vsize=439952 CPUtime=3.99
/proc/13365/task/13368/stat : 13368 (java) R 13364 13364 4778 34817 4778 4202560 62948 0 0 0 383 16 0 0 16 0 9 0 10593933 450510848 77467 1283457024 134512640 134550932 4290391296 18446744073709551615 4152093109 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=13365/tid=13369] ppid=13364 vsize=439952 CPUtime=0
/proc/13365/task/13369/stat : 13369 (java) S 13364 13364 4778 34817 4778 4202560 15 0 0 0 0 0 0 0 20 0 9 0 10593934 450510848 77467 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13370] ppid=13364 vsize=439952 CPUtime=0
/proc/13365/task/13370/stat : 13370 (java) S 13364 13364 4778 34817 4778 4202560 5 0 0 0 0 0 0 0 20 0 9 0 10593934 450510848 77467 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13371] ppid=13364 vsize=439952 CPUtime=0
/proc/13365/task/13371/stat : 13371 (java) S 13364 13364 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 9 0 10593935 450510848 77467 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13372] ppid=13364 vsize=439952 CPUtime=0.07
/proc/13365/task/13372/stat : 13372 (java) S 13364 13364 4778 34817 4778 4202560 470 0 0 0 7 0 0 0 15 0 9 0 10593935 450510848 77467 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13373] ppid=13364 vsize=439952 CPUtime=0
/proc/13365/task/13373/stat : 13373 (java) S 13364 13364 4778 34817 4778 4202560 0 0 0 0 0 0 0 0 25 0 9 0 10593935 450510848 77467 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13374] ppid=13364 vsize=439952 CPUtime=0
/proc/13365/task/13374/stat : 13374 (java) S 13364 13364 4778 34817 4778 4202560 2 0 0 0 0 0 0 0 15 0 9 0 10593935 450510848 77467 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.3
Current children cumulated vsize (KiB) 442520

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

[startup+6.40726 s]
/proc/loadavg: 1.87 1.42 1.16 3/43 13374
/proc/meminfo: memFree=30872/1048576 swapFree=0/0
[pid=13364] ppid=13363 vsize=2568 CPUtime=0
/proc/13364/stat : 13364 (gj-paranoid-sol) S 13363 13364 4778 34817 4778 4202496 371 0 0 0 0 0 0 0 25 0 1 0 10593932 2629632 269 1283457024 134512640 135304128 4290325920 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/13364/statm: 642 269 229 194 0 29 0
[pid=13365] ppid=13364 vsize=439952 CPUtime=6.4
/proc/13365/stat : 13365 (java) S 13364 13364 4778 34817 4778 4202496 78232 0 1 0 611 29 0 0 25 0 9 0 10593932 450510848 77467 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/13365/statm: 109988 77467 2902 10 0 104136 0
[pid=13365/tid=13367] ppid=13364 vsize=439952 CPUtime=2.22
/proc/13365/task/13367/stat : 13367 (java) R 13364 13364 4778 34817 4778 4202560 13874 0 1 0 210 12 0 0 25 0 9 0 10593933 450510848 77467 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=13365/tid=13368] ppid=13364 vsize=439952 CPUtime=4.09
/proc/13365/task/13368/stat : 13368 (java) R 13364 13364 4778 34817 4778 4202560 62948 0 0 0 393 16 0 0 16 0 9 0 10593933 450510848 77467 1283457024 134512640 134550932 4290391296 18446744073709551615 4150993502 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=13365/tid=13369] ppid=13364 vsize=439952 CPUtime=0
/proc/13365/task/13369/stat : 13369 (java) S 13364 13364 4778 34817 4778 4202560 15 0 0 0 0 0 0 0 20 0 9 0 10593934 450510848 77467 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13370] ppid=13364 vsize=439952 CPUtime=0
/proc/13365/task/13370/stat : 13370 (java) S 13364 13364 4778 34817 4778 4202560 5 0 0 0 0 0 0 0 20 0 9 0 10593934 450510848 77467 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13371] ppid=13364 vsize=439952 CPUtime=0
/proc/13365/task/13371/stat : 13371 (java) S 13364 13364 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 9 0 10593935 450510848 77467 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13372] ppid=13364 vsize=439952 CPUtime=0.07
/proc/13365/task/13372/stat : 13372 (java) S 13364 13364 4778 34817 4778 4202560 470 0 0 0 7 0 0 0 15 0 9 0 10593935 450510848 77467 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13373] ppid=13364 vsize=439952 CPUtime=0
/proc/13365/task/13373/stat : 13373 (java) S 13364 13364 4778 34817 4778 4202560 0 0 0 0 0 0 0 0 25 0 9 0 10593935 450510848 77467 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13374] ppid=13364 vsize=439952 CPUtime=0
/proc/13365/task/13374/stat : 13374 (java) S 13364 13364 4778 34817 4778 4202560 2 0 0 0 0 0 0 0 15 0 9 0 10593935 450510848 77467 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.4
Current children cumulated vsize (KiB) 442520

[startup+9.6282 s]
/proc/loadavg: 1.88 1.43 1.17 4/43 13374
/proc/meminfo: memFree=5892/1048576 swapFree=0/0
[pid=13364] ppid=13363 vsize=2568 CPUtime=0
/proc/13364/stat : 13364 (gj-paranoid-sol) S 13363 13364 4778 34817 4778 4202496 371 0 0 0 0 0 0 0 25 0 1 0 10593932 2629632 269 1283457024 134512640 135304128 4290325920 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/13364/statm: 642 269 229 194 0 29 0
[pid=13365] ppid=13364 vsize=411424 CPUtime=9.62
/proc/13365/stat : 13365 (java) S 13364 13364 4778 34817 4778 4202496 92731 0 1 0 924 38 0 0 25 0 9 0 10593932 421298176 70534 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/13365/statm: 102856 70534 2916 10 0 97001 0
[pid=13365/tid=13367] ppid=13364 vsize=411424 CPUtime=2.75
/proc/13365/task/13367/stat : 13367 (java) R 13364 13364 4778 34817 4778 4202560 14102 0 1 0 263 12 0 0 25 0 9 0 10593933 421298176 70534 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=13365/tid=13368] ppid=13364 vsize=411424 CPUtime=6.78
/proc/13365/task/13368/stat : 13368 (java) R 13364 13364 4778 34817 4778 4202560 77198 0 0 0 653 25 0 0 15 0 9 0 10593933 421298176 70534 1283457024 134512640 134550932 4290391296 18446744073709551615 4152295072 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=13365/tid=13369] ppid=13364 vsize=411424 CPUtime=0
/proc/13365/task/13369/stat : 13369 (java) S 13364 13364 4778 34817 4778 4202560 15 0 0 0 0 0 0 0 18 0 9 0 10593934 421298176 70534 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13370] ppid=13364 vsize=411424 CPUtime=0
/proc/13365/task/13370/stat : 13370 (java) S 13364 13364 4778 34817 4778 4202560 5 0 0 0 0 0 0 0 18 0 9 0 10593934 421298176 70534 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13371] ppid=13364 vsize=411424 CPUtime=0
/proc/13365/task/13371/stat : 13371 (java) S 13364 13364 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 9 0 10593935 421298176 70534 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13372] ppid=13364 vsize=411424 CPUtime=0.07
/proc/13365/task/13372/stat : 13372 (java) S 13364 13364 4778 34817 4778 4202560 491 0 0 0 7 0 0 0 15 0 9 0 10593935 421298176 70534 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13373] ppid=13364 vsize=411424 CPUtime=0
/proc/13365/task/13373/stat : 13373 (java) S 13364 13364 4778 34817 4778 4202560 0 0 0 0 0 0 0 0 25 0 9 0 10593935 421298176 70534 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13374] ppid=13364 vsize=411424 CPUtime=0
/proc/13365/task/13374/stat : 13374 (java) S 13364 13364 4778 34817 4778 4202560 2 0 0 0 0 0 0 0 15 0 9 0 10593935 421298176 70534 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 9.62
Current children cumulated vsize (KiB) 413992

[startup+11.2085 s]
/proc/loadavg: 1.88 1.43 1.17 2/44 13375
/proc/meminfo: memFree=33660/1048576 swapFree=0/0
[pid=13364] ppid=13363 vsize=2568 CPUtime=0
/proc/13364/stat : 13364 (gj-paranoid-sol) S 13363 13364 4778 34817 4778 4202496 371 0 0 0 0 0 0 0 25 0 1 0 10593932 2629632 269 1283457024 134512640 135304128 4290325920 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/13364/statm: 642 269 229 194 0 29 0
[pid=13365] ppid=13364 vsize=411748 CPUtime=11.2
/proc/13365/stat : 13365 (java) S 13364 13364 4778 34817 4778 4202496 92798 0 1 0 1082 38 0 0 25 0 10 0 10593932 421629952 70597 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/13365/statm: 102937 70597 2917 10 0 97082 0
[pid=13365/tid=13367] ppid=13364 vsize=411748 CPUtime=4.04
/proc/13365/task/13367/stat : 13367 (java) R 13364 13364 4778 34817 4778 4202560 14126 0 1 0 392 12 0 0 25 0 10 0 10593933 421629952 70597 1283457024 134512640 134550932 4290391296 18446744073709551615 4115156224 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=13365/tid=13368] ppid=13364 vsize=411748 CPUtime=7.03
/proc/13365/task/13368/stat : 13368 (java) S 13364 13364 4778 34817 4778 4202560 77198 0 0 0 678 25 0 0 16 0 10 0 10593933 421629952 70597 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 0 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13369] ppid=13364 vsize=411748 CPUtime=0
/proc/13365/task/13369/stat : 13369 (java) S 13364 13364 4778 34817 4778 4202560 15 0 0 0 0 0 0 0 18 0 10 0 10593934 421629952 70597 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13370] ppid=13364 vsize=411748 CPUtime=0
/proc/13365/task/13370/stat : 13370 (java) S 13364 13364 4778 34817 4778 4202560 5 0 0 0 0 0 0 0 18 0 10 0 10593934 421629952 70597 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13371] ppid=13364 vsize=411748 CPUtime=0
/proc/13365/task/13371/stat : 13371 (java) S 13364 13364 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 10 0 10593935 421629952 70597 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13372] ppid=13364 vsize=411748 CPUtime=0.11
/proc/13365/task/13372/stat : 13372 (java) S 13364 13364 4778 34817 4778 4202560 530 0 0 0 11 0 0 0 15 0 10 0 10593935 421629952 70597 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13373] ppid=13364 vsize=411748 CPUtime=0
/proc/13365/task/13373/stat : 13373 (java) S 13364 13364 4778 34817 4778 4202560 0 0 0 0 0 0 0 0 25 0 10 0 10593935 421629952 70597 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13374] ppid=13364 vsize=411748 CPUtime=0
/proc/13365/task/13374/stat : 13374 (java) S 13364 13364 4778 34817 4778 4202560 2 0 0 0 0 0 0 0 15 0 10 0 10593935 421629952 70597 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13375] ppid=13364 vsize=411748 CPUtime=0
/proc/13365/task/13375/stat : 13375 (java) S 13364 13364 4778 34817 4778 4202560 4 0 0 0 0 0 0 0 25 0 10 0 10594924 421629952 70597 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 11.2
Current children cumulated vsize (KiB) 414316

[startup+11.6086 s]
/proc/loadavg: 1.88 1.43 1.17 2/44 13375
/proc/meminfo: memFree=33660/1048576 swapFree=0/0
[pid=13364] ppid=13363 vsize=2568 CPUtime=0
/proc/13364/stat : 13364 (gj-paranoid-sol) S 13363 13364 4778 34817 4778 4202496 371 0 0 0 0 0 0 0 25 0 1 0 10593932 2629632 269 1283457024 134512640 135304128 4290325920 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/13364/statm: 642 269 229 194 0 29 0
[pid=13365] ppid=13364 vsize=411748 CPUtime=11.59
/proc/13365/stat : 13365 (java) S 13364 13364 4778 34817 4778 4202496 92800 0 1 0 1121 38 0 0 25 0 10 0 10593932 421629952 70599 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/13365/statm: 102937 70599 2917 10 0 97082 0
[pid=13365/tid=13367] ppid=13364 vsize=411748 CPUtime=4.44
/proc/13365/task/13367/stat : 13367 (java) R 13364 13364 4778 34817 4778 4202560 14127 0 1 0 432 12 0 0 25 0 10 0 10593933 421629952 70599 1283457024 134512640 134550932 4290391296 18446744073709551615 4115166636 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=13365/tid=13368] ppid=13364 vsize=411748 CPUtime=7.03
/proc/13365/task/13368/stat : 13368 (java) S 13364 13364 4778 34817 4778 4202560 77198 0 0 0 678 25 0 0 16 0 10 0 10593933 421629952 70599 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 0 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13369] ppid=13364 vsize=411748 CPUtime=0
/proc/13365/task/13369/stat : 13369 (java) S 13364 13364 4778 34817 4778 4202560 15 0 0 0 0 0 0 0 18 0 10 0 10593934 421629952 70599 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13370] ppid=13364 vsize=411748 CPUtime=0
/proc/13365/task/13370/stat : 13370 (java) S 13364 13364 4778 34817 4778 4202560 5 0 0 0 0 0 0 0 18 0 10 0 10593934 421629952 70599 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13371] ppid=13364 vsize=411748 CPUtime=0
/proc/13365/task/13371/stat : 13371 (java) S 13364 13364 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 10 0 10593935 421629952 70599 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13372] ppid=13364 vsize=411748 CPUtime=0.11
/proc/13365/task/13372/stat : 13372 (java) S 13364 13364 4778 34817 4778 4202560 531 0 0 0 11 0 0 0 15 0 10 0 10593935 421629952 70599 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13373] ppid=13364 vsize=411748 CPUtime=0
/proc/13365/task/13373/stat : 13373 (java) S 13364 13364 4778 34817 4778 4202560 0 0 0 0 0 0 0 0 25 0 10 0 10593935 421629952 70599 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13374] ppid=13364 vsize=411748 CPUtime=0
/proc/13365/task/13374/stat : 13374 (java) S 13364 13364 4778 34817 4778 4202560 2 0 0 0 0 0 0 0 15 0 10 0 10593935 421629952 70599 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13375] ppid=13364 vsize=411748 CPUtime=0
/proc/13365/task/13375/stat : 13375 (java) S 13364 13364 4778 34817 4778 4202560 4 0 0 0 0 0 0 0 25 0 10 0 10594924 421629952 70599 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 11.59
Current children cumulated vsize (KiB) 414316

[startup+12.0088 s]
/proc/loadavg: 1.88 1.43 1.17 2/44 13375
/proc/meminfo: memFree=33660/1048576 swapFree=0/0
[pid=13364] ppid=13363 vsize=2568 CPUtime=0
/proc/13364/stat : 13364 (gj-paranoid-sol) S 13363 13364 4778 34817 4778 4202496 371 0 0 0 0 0 0 0 25 0 1 0 10593932 2629632 269 1283457024 134512640 135304128 4290325920 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/13364/statm: 642 269 229 194 0 29 0
[pid=13365] ppid=13364 vsize=411748 CPUtime=11.99
/proc/13365/stat : 13365 (java) S 13364 13364 4778 34817 4778 4202496 92804 0 1 0 1160 39 0 0 25 0 9 0 10593932 421629952 70603 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/13365/statm: 102937 70603 2920 10 0 97082 0
[pid=13365/tid=13367] ppid=13364 vsize=411748 CPUtime=4.82
/proc/13365/task/13367/stat : 13367 (java) R 13364 13364 4778 34817 4778 4202560 14127 0 1 0 469 13 0 0 25 0 9 0 10593933 421629952 70603 1283457024 134512640 134550932 4290391296 18446744073709551615 4114355030 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=13365/tid=13368] ppid=13364 vsize=411748 CPUtime=7.05
/proc/13365/task/13368/stat : 13368 (java) S 13364 13364 4778 34817 4778 4202560 77200 0 0 0 680 25 0 0 16 0 9 0 10593933 421629952 70603 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 0 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13369] ppid=13364 vsize=411748 CPUtime=0
/proc/13365/task/13369/stat : 13369 (java) S 13364 13364 4778 34817 4778 4202560 15 0 0 0 0 0 0 0 18 0 9 0 10593934 421629952 70603 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13370] ppid=13364 vsize=411748 CPUtime=0
/proc/13365/task/13370/stat : 13370 (java) S 13364 13364 4778 34817 4778 4202560 5 0 0 0 0 0 0 0 18 0 9 0 10593934 421629952 70603 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13371] ppid=13364 vsize=411748 CPUtime=0
/proc/13365/task/13371/stat : 13371 (java) S 13364 13364 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 9 0 10593935 421629952 70603 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13372] ppid=13364 vsize=411748 CPUtime=0.11
/proc/13365/task/13372/stat : 13372 (java) S 13364 13364 4778 34817 4778 4202560 532 0 0 0 11 0 0 0 15 0 9 0 10593935 421629952 70603 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13373] ppid=13364 vsize=411748 CPUtime=0
/proc/13365/task/13373/stat : 13373 (java) S 13364 13364 4778 34817 4778 4202560 0 0 0 0 0 0 0 0 25 0 9 0 10593935 421629952 70603 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=13365/tid=13374] ppid=13364 vsize=411748 CPUtime=0
/proc/13365/task/13374/stat : 13374 (java) S 13364 13364 4778 34817 4778 4202560 2 0 0 0 0 0 0 0 15 0 9 0 10593935 421629952 70603 1283457024 134512640 134550932 4290391296 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 11.99
Current children cumulated vsize (KiB) 414316

Child status: 0
Real time (s): 12.1036
CPU time (s): 12.0408
CPU user time (s): 11.6287
CPU system time (s): 0.412025
CPU usage (%): 99.4806
Max. virtual memory (cumulated for all children) (KiB): 442520

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 11.6287
system time used= 0.412025
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 93191
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= 943
involuntary context switches= 1061

runsolver used 0 second user time and 0 second system time

The end