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/rand3dec28.cudf.impossible.log.runsolver ./gj-paranoid-solver-0.1 /home/misc2010/data/2010/impossible//rand3dec28.cudf /home/misc2010/tmp/201012061533/gj-paranoid-solver-0.1/rand3dec28.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.19 1.16 1.10 1/45 8500
/proc/meminfo: memFree=948108/1048576 swapFree=2078740/2097144
[pid=8500] ppid=8499 vsize=3020 CPUtime=0
/proc/8500/stat : 8500 (runsolver) D 8499 8500 2059 34821 2220 4202560 72 0 0 0 0 0 0 0 22 0 1 0 874992497 3092480 93 1283457024 134512640 134586868 4294406336 18446744073709551615 4294960130 0 0 0 24578 18446744071564332000 0 0 17 0 0 0 0
/proc/8500/statm: 755 93 62 19 0 53 0

[startup+0.113431 s]
/proc/loadavg: 1.19 1.16 1.10 1/45 8500
/proc/meminfo: memFree=948108/1048576 swapFree=2078740/2097144
[pid=8500] ppid=8499 vsize=2564 CPUtime=0
/proc/8500/stat : 8500 (gj-paranoid-sol) D 8499 8500 2059 34821 2220 4202496 345 0 11 0 0 0 0 0 22 0 1 0 874992497 2625536 270 1283457024 134512640 135304128 4286649152 18446744073709551615 4294960130 0 0 4 65536 18446744071564252162 0 0 17 0 0 0 0
/proc/8500/statm: 641 270 231 194 0 27 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2564

[startup+0.205461 s]
/proc/loadavg: 1.19 1.16 1.10 1/45 8500
/proc/meminfo: memFree=948108/1048576 swapFree=2078740/2097144
[pid=8500] ppid=8499 vsize=2572 CPUtime=0
/proc/8500/stat : 8500 (gj-paranoid-sol) S 8499 8500 2059 34821 2220 4202496 365 0 11 0 0 0 0 0 22 0 1 0 874992497 2633728 273 1283457024 134512640 135304128 4286649152 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/8500/statm: 643 273 232 194 0 29 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2572

[startup+0.305501 s]
/proc/loadavg: 1.19 1.16 1.10 1/45 8500
/proc/meminfo: memFree=948108/1048576 swapFree=2078740/2097144
[pid=8500] ppid=8499 vsize=2572 CPUtime=0
/proc/8500/stat : 8500 (gj-paranoid-sol) S 8499 8500 2059 34821 2220 4202496 365 0 11 0 0 0 0 0 22 0 1 0 874992497 2633728 273 1283457024 134512640 135304128 4286649152 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/8500/statm: 643 273 232 194 0 29 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2572

[startup+0.705471 s]
/proc/loadavg: 1.19 1.16 1.10 1/45 8500
/proc/meminfo: memFree=948108/1048576 swapFree=2078740/2097144
[pid=8500] ppid=8499 vsize=2572 CPUtime=0
/proc/8500/stat : 8500 (gj-paranoid-sol) S 8499 8500 2059 34821 2220 4202496 365 0 11 0 0 0 0 0 22 0 1 0 874992497 2633728 273 1283457024 134512640 135304128 4286649152 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/8500/statm: 643 273 232 194 0 29 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2572

[startup+1.50604 s]
/proc/loadavg: 1.19 1.16 1.10 2/55 8510
/proc/meminfo: memFree=919508/1048576 swapFree=2078740/2097144
[pid=8500] ppid=8499 vsize=2572 CPUtime=0
/proc/8500/stat : 8500 (gj-paranoid-sol) S 8499 8500 2059 34821 2220 4202496 365 0 11 0 0 0 0 0 22 0 1 0 874992497 2633728 273 1283457024 134512640 135304128 4286649152 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/8500/statm: 643 273 232 194 0 29 0
[pid=8502] ppid=8500 vsize=410728 CPUtime=0.32
/proc/8502/stat : 8502 (java) S 8500 8500 2059 34821 2220 4202496 11146 0 231 0 26 6 0 0 21 0 9 0 874992508 420585472 10661 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/8502/statm: 102682 10661 2878 10 0 96862 0
[pid=8502/tid=8503] ppid=8500 vsize=410728 CPUtime=0.14
/proc/8502/task/8503/stat : 8503 (java) R 8500 8500 2059 34821 2220 4202560 3932 0 131 0 14 0 0 0 18 0 9 0 874992530 420585472 10661 1283457024 134512640 134550932 4293480448 18446744073709551615 4115400920 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=8502/tid=8504] ppid=8500 vsize=410728 CPUtime=0.15
/proc/8502/task/8504/stat : 8504 (java) S 8500 8500 2059 34821 2220 4202560 5899 0 33 0 11 4 0 0 16 0 9 0 874992548 420585472 10661 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 0 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=8502/tid=8505] ppid=8500 vsize=410728 CPUtime=0
/proc/8502/task/8505/stat : 8505 (java) S 8500 8500 2059 34821 2220 4202560 16 0 1 0 0 0 0 0 15 0 9 0 874992551 420585472 10661 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=8502/tid=8506] ppid=8500 vsize=410728 CPUtime=0
/proc/8502/task/8506/stat : 8506 (java) S 8500 8500 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 17 0 9 0 874992551 420585472 10661 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=8502/tid=8507] ppid=8500 vsize=410728 CPUtime=0
/proc/8502/task/8507/stat : 8507 (java) S 8500 8500 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 21 0 9 0 874992570 420585472 10661 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=8502/tid=8508] ppid=8500 vsize=410728 CPUtime=0
/proc/8502/task/8508/stat : 8508 (java) S 8500 8500 2059 34821 2220 4202560 443 0 6 0 0 0 0 0 16 0 9 0 874992570 420585472 10661 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=8502/tid=8509] ppid=8500 vsize=410728 CPUtime=0
/proc/8502/task/8509/stat : 8509 (java) S 8500 8500 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 22 0 9 0 874992570 420585472 10661 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=8502/tid=8510] ppid=8500 vsize=410728 CPUtime=0
/proc/8502/task/8510/stat : 8510 (java) R 8500 8500 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 16 0 9 0 874992570 420585472 10661 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 0.32
Current children cumulated vsize (KiB) 413300

[startup+3.11168 s]
/proc/loadavg: 1.25 1.17 1.10 2/55 8510
/proc/meminfo: memFree=841948/1048576 swapFree=2078740/2097144
[pid=8500] ppid=8499 vsize=2572 CPUtime=0
/proc/8500/stat : 8500 (gj-paranoid-sol) S 8499 8500 2059 34821 2220 4202496 365 0 11 0 0 0 0 0 22 0 1 0 874992497 2633728 273 1283457024 134512640 135304128 4286649152 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/8500/statm: 643 273 232 194 0 29 0
[pid=8502] ppid=8500 vsize=410728 CPUtime=1.69
/proc/8502/stat : 8502 (java) S 8500 8500 2059 34821 2220 4202496 36897 0 231 0 154 15 0 0 21 0 9 0 874992508 420585472 36412 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/8502/statm: 102682 36412 2879 10 0 96862 0
[pid=8502/tid=8503] ppid=8500 vsize=410728 CPUtime=0.54
/proc/8502/task/8503/stat : 8503 (java) R 8500 8500 2059 34821 2220 4202560 9308 0 131 0 50 4 0 0 18 0 9 0 874992530 420585472 36412 1283457024 134512640 134550932 4293480448 18446744073709551615 4115401203 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=8502/tid=8504] ppid=8500 vsize=410728 CPUtime=1.11
/proc/8502/task/8504/stat : 8504 (java) S 8500 8500 2059 34821 2220 4202560 26265 0 33 0 102 9 0 0 16 0 9 0 874992548 420585472 36412 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 0 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=8502/tid=8505] ppid=8500 vsize=410728 CPUtime=0
/proc/8502/task/8505/stat : 8505 (java) S 8500 8500 2059 34821 2220 4202560 16 0 1 0 0 0 0 0 15 0 9 0 874992551 420585472 36412 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=8502/tid=8506] ppid=8500 vsize=410728 CPUtime=0
/proc/8502/task/8506/stat : 8506 (java) S 8500 8500 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 17 0 9 0 874992551 420585472 36412 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=8502/tid=8507] ppid=8500 vsize=410728 CPUtime=0
/proc/8502/task/8507/stat : 8507 (java) S 8500 8500 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 21 0 9 0 874992570 420585472 36412 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=8502/tid=8508] ppid=8500 vsize=410728 CPUtime=0.02
/proc/8502/task/8508/stat : 8508 (java) S 8500 8500 2059 34821 2220 4202560 452 0 6 0 2 0 0 0 15 0 9 0 874992570 420585472 36412 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=8502/tid=8509] ppid=8500 vsize=410728 CPUtime=0
/proc/8502/task/8509/stat : 8509 (java) S 8500 8500 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 22 0 9 0 874992570 420585472 36412 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=8502/tid=8510] ppid=8500 vsize=410728 CPUtime=0
/proc/8502/task/8510/stat : 8510 (java) S 8500 8500 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 15 0 9 0 874992570 420585472 36412 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.69
Current children cumulated vsize (KiB) 413300
heavy processes:

[startup+6.30337 s]
/proc/loadavg: 1.25 1.17 1.10 2/55 8510
/proc/meminfo: memFree=636184/1048576 swapFree=2078740/2097144
[pid=8500] ppid=8499 vsize=2572 CPUtime=0
/proc/8500/stat : 8500 (gj-paranoid-sol) S 8499 8500 2059 34821 2220 4202496 365 0 11 0 0 0 0 0 22 0 1 0 874992497 2633728 273 1283457024 134512640 135304128 4286649152 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/8500/statm: 643 273 232 194 0 29 0
[pid=8502] ppid=8500 vsize=447292 CPUtime=4.79
/proc/8502/stat : 8502 (java) S 8500 8500 2059 34821 2220 4202496 79704 0 231 0 454 25 0 0 21 0 9 0 874992508 458027008 79219 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/8502/statm: 111823 79219 2879 10 0 106003 0
[pid=8502/tid=8503] ppid=8500 vsize=447292 CPUtime=1.34
/proc/8502/task/8503/stat : 8503 (java) R 8500 8500 2059 34821 2220 4202560 13933 0 131 0 128 6 0 0 19 0 9 0 874992530 458027008 79219 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=8502/tid=8504] ppid=8500 vsize=447292 CPUtime=3.4
/proc/8502/task/8504/stat : 8504 (java) R 8500 8500 2059 34821 2220 4202560 64445 0 33 0 323 17 0 0 16 0 9 0 874992548 458027008 79219 1283457024 134512640 134550932 4293480448 18446744073709551615 4153214938 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=8502/tid=8505] ppid=8500 vsize=447292 CPUtime=0
/proc/8502/task/8505/stat : 8505 (java) S 8500 8500 2059 34821 2220 4202560 16 0 1 0 0 0 0 0 15 0 9 0 874992551 458027008 79219 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=8502/tid=8506] ppid=8500 vsize=447292 CPUtime=0
/proc/8502/task/8506/stat : 8506 (java) S 8500 8500 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 17 0 9 0 874992551 458027008 79219 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=8502/tid=8507] ppid=8500 vsize=447292 CPUtime=0
/proc/8502/task/8507/stat : 8507 (java) S 8500 8500 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 21 0 9 0 874992570 458027008 79219 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=8502/tid=8508] ppid=8500 vsize=447292 CPUtime=0.02
/proc/8502/task/8508/stat : 8508 (java) S 8500 8500 2059 34821 2220 4202560 454 0 6 0 2 0 0 0 15 0 9 0 874992570 458027008 79219 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=8502/tid=8509] ppid=8500 vsize=447292 CPUtime=0
/proc/8502/task/8509/stat : 8509 (java) S 8500 8500 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 22 0 9 0 874992570 458027008 79219 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=8502/tid=8510] ppid=8500 vsize=447292 CPUtime=0
/proc/8502/task/8510/stat : 8510 (java) S 8500 8500 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 15 0 9 0 874992570 458027008 79219 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.79
Current children cumulated vsize (KiB) 449864
heavy processes:

[startup+12.7094 s]
/proc/loadavg: 1.52 1.23 1.12 4/55 8510
/proc/meminfo: memFree=596064/1048576 swapFree=2078740/2097144
[pid=8500] ppid=8499 vsize=2572 CPUtime=0
/proc/8500/stat : 8500 (gj-paranoid-sol) S 8499 8500 2059 34821 2220 4202496 365 0 11 0 0 0 0 0 22 0 1 0 874992497 2633728 273 1283457024 134512640 135304128 4286649152 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/8500/statm: 643 273 232 194 0 29 0
[pid=8502] ppid=8500 vsize=437856 CPUtime=11.14
/proc/8502/stat : 8502 (java) S 8500 8500 2059 34821 2220 4202496 112476 0 233 0 1074 40 0 0 21 0 9 0 874992508 448364544 76969 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/8502/statm: 109464 76969 2880 10 0 103644 0
[pid=8502/tid=8503] ppid=8500 vsize=437856 CPUtime=2.02
/proc/8502/task/8503/stat : 8503 (java) R 8500 8500 2059 34821 2220 4202560 14016 0 133 0 196 6 0 0 20 0 9 0 874992530 448364544 76969 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=8502/tid=8504] ppid=8500 vsize=437856 CPUtime=9.04
/proc/8502/task/8504/stat : 8504 (java) R 8500 8500 2059 34821 2220 4202560 97105 0 33 0 873 31 0 0 16 0 9 0 874992548 448364544 76969 1283457024 134512640 134550932 4293480448 18446744073709551615 4151521872 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=8502/tid=8505] ppid=8500 vsize=437856 CPUtime=0
/proc/8502/task/8505/stat : 8505 (java) S 8500 8500 2059 34821 2220 4202560 16 0 1 0 0 0 0 0 15 0 9 0 874992551 448364544 76969 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=8502/tid=8506] ppid=8500 vsize=437856 CPUtime=0
/proc/8502/task/8506/stat : 8506 (java) S 8500 8500 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 15 0 9 0 874992551 448364544 76969 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=8502/tid=8507] ppid=8500 vsize=437856 CPUtime=0
/proc/8502/task/8507/stat : 8507 (java) S 8500 8500 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 21 0 9 0 874992570 448364544 76969 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=8502/tid=8508] ppid=8500 vsize=437856 CPUtime=0.05
/proc/8502/task/8508/stat : 8508 (java) S 8500 8500 2059 34821 2220 4202560 483 0 6 0 4 1 0 0 15 0 9 0 874992570 448364544 76969 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=8502/tid=8509] ppid=8500 vsize=437856 CPUtime=0
/proc/8502/task/8509/stat : 8509 (java) S 8500 8500 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 22 0 9 0 874992570 448364544 76969 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=8502/tid=8510] ppid=8500 vsize=437856 CPUtime=0
/proc/8502/task/8510/stat : 8510 (java) S 8500 8500 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 15 0 9 0 874992570 448364544 76969 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 11.14
Current children cumulated vsize (KiB) 440428

[startup+25.5095 s]
/proc/loadavg: 1.59 1.26 1.13 3/56 8511
/proc/meminfo: memFree=595688/1048576 swapFree=2078740/2097144
[pid=8500] ppid=8499 vsize=2572 CPUtime=0
/proc/8500/stat : 8500 (gj-paranoid-sol) S 8499 8500 2059 34821 2220 4202496 365 0 11 0 0 0 0 0 22 0 1 0 874992497 2633728 273 1283457024 134512640 135304128 4286649152 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/8500/statm: 643 273 232 194 0 29 0
[pid=8502] ppid=8500 vsize=447116 CPUtime=23.9
/proc/8502/stat : 8502 (java) S 8500 8500 2059 34821 2220 4202496 155262 0 234 0 2334 56 0 0 21 0 10 0 874992508 457846784 79258 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/8502/statm: 111779 79258 2883 10 0 105959 0
[pid=8502/tid=8503] ppid=8500 vsize=447116 CPUtime=7.02
/proc/8502/task/8503/stat : 8503 (java) R 8500 8500 2059 34821 2220 4202560 14039 0 134 0 695 7 0 0 25 0 10 0 874992530 457846784 79258 1283457024 134512640 134550932 4293480448 18446744073709551615 4115720228 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=8502/tid=8504] ppid=8500 vsize=447116 CPUtime=16.76
/proc/8502/task/8504/stat : 8504 (java) S 8500 8500 2059 34821 2220 4202560 139826 0 33 0 1630 46 0 0 18 0 10 0 874992548 457846784 79258 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 0 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=8502/tid=8505] ppid=8500 vsize=447116 CPUtime=0
/proc/8502/task/8505/stat : 8505 (java) S 8500 8500 2059 34821 2220 4202560 16 0 1 0 0 0 0 0 15 0 10 0 874992551 457846784 79258 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=8502/tid=8506] ppid=8500 vsize=447116 CPUtime=0
/proc/8502/task/8506/stat : 8506 (java) S 8500 8500 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 15 0 10 0 874992551 457846784 79258 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=8502/tid=8507] ppid=8500 vsize=447116 CPUtime=0
/proc/8502/task/8507/stat : 8507 (java) S 8500 8500 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 21 0 10 0 874992570 457846784 79258 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=8502/tid=8508] ppid=8500 vsize=447116 CPUtime=0.08
/proc/8502/task/8508/stat : 8508 (java) S 8500 8500 2059 34821 2220 4202560 520 0 6 0 7 1 0 0 16 0 10 0 874992570 457846784 79258 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=8502/tid=8509] ppid=8500 vsize=447116 CPUtime=0
/proc/8502/task/8509/stat : 8509 (java) S 8500 8500 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 22 0 10 0 874992570 457846784 79258 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=8502/tid=8510] ppid=8500 vsize=447116 CPUtime=0
/proc/8502/task/8510/stat : 8510 (java) S 8500 8500 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 15 0 10 0 874992570 457846784 79258 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=8502/tid=8511] ppid=8500 vsize=447116 CPUtime=0
/proc/8502/task/8511/stat : 8511 (java) S 8500 8500 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 22 0 10 0 874994489 457846784 79258 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 23.9
Current children cumulated vsize (KiB) 449688

[startup+51.1056 s]
/proc/loadavg: 1.46 1.25 1.13 3/55 8511
/proc/meminfo: memFree=595820/1048576 swapFree=2078740/2097144
[pid=8500] ppid=8499 vsize=2572 CPUtime=0
/proc/8500/stat : 8500 (gj-paranoid-sol) S 8499 8500 2059 34821 2220 4202496 365 0 11 0 0 0 0 0 22 0 1 0 874992497 2633728 273 1283457024 134512640 135304128 4286649152 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/8500/statm: 643 273 232 194 0 29 0
[pid=8502] ppid=8500 vsize=446984 CPUtime=49.48
/proc/8502/stat : 8502 (java) S 8500 8500 2059 34821 2220 4202496 189013 0 234 0 4879 69 0 0 21 0 9 0 874992508 457711616 79223 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/8502/statm: 111746 79223 2883 10 0 105926 0
[pid=8502/tid=8503] ppid=8500 vsize=446984 CPUtime=26.76
/proc/8502/task/8503/stat : 8503 (java) R 8500 8500 2059 34821 2220 4202560 14039 0 134 0 2669 7 0 0 25 0 9 0 874992530 457711616 79223 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=8502/tid=8504] ppid=8500 vsize=446984 CPUtime=22.61
/proc/8502/task/8504/stat : 8504 (java) R 8500 8500 2059 34821 2220 4202560 173576 0 33 0 2202 59 0 0 17 0 9 0 874992548 457711616 79223 1283457024 134512640 134550932 4293480448 18446744073709551615 4152632981 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=8502/tid=8505] ppid=8500 vsize=446984 CPUtime=0
/proc/8502/task/8505/stat : 8505 (java) S 8500 8500 2059 34821 2220 4202560 16 0 1 0 0 0 0 0 15 0 9 0 874992551 457711616 79223 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=8502/tid=8506] ppid=8500 vsize=446984 CPUtime=0
/proc/8502/task/8506/stat : 8506 (java) S 8500 8500 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 15 0 9 0 874992551 457711616 79223 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=8502/tid=8507] ppid=8500 vsize=446984 CPUtime=0
/proc/8502/task/8507/stat : 8507 (java) S 8500 8500 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 21 0 9 0 874992570 457711616 79223 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=8502/tid=8508] ppid=8500 vsize=446984 CPUtime=0.08
/proc/8502/task/8508/stat : 8508 (java) S 8500 8500 2059 34821 2220 4202560 521 0 6 0 7 1 0 0 15 0 9 0 874992570 457711616 79223 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=8502/tid=8509] ppid=8500 vsize=446984 CPUtime=0
/proc/8502/task/8509/stat : 8509 (java) S 8500 8500 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 22 0 9 0 874992570 457711616 79223 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=8502/tid=8510] ppid=8500 vsize=446984 CPUtime=0
/proc/8502/task/8510/stat : 8510 (java) S 8500 8500 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 15 0 9 0 874992570 457711616 79223 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 49.48
Current children cumulated vsize (KiB) 449556

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

[startup+51.2069 s]
/proc/loadavg: 1.46 1.25 1.13 3/55 8511
/proc/meminfo: memFree=595820/1048576 swapFree=2078740/2097144
[pid=8500] ppid=8499 vsize=2572 CPUtime=0
/proc/8500/stat : 8500 (gj-paranoid-sol) S 8499 8500 2059 34821 2220 4202496 365 0 11 0 0 0 0 0 22 0 1 0 874992497 2633728 273 1283457024 134512640 135304128 4286649152 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/8500/statm: 643 273 232 194 0 29 0
[pid=8502] ppid=8500 vsize=446984 CPUtime=49.52
/proc/8502/stat : 8502 (java) R 8500 8500 2059 34821 2220 4202496 189020 0 234 0 4883 69 0 0 18 0 5 0 874992508 457711616 73080 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/8502/statm: 111746 73080 2883 10 0 105926 0
[pid=8502/tid=8505] ppid=8500 vsize=446984 CPUtime=0
/proc/8502/task/8505/stat : 8505 (java) S 8500 8500 2059 34821 2220 4202560 16 0 1 0 0 0 0 0 15 0 5 0 874992551 457711616 73080 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=8502/tid=8506] ppid=8500 vsize=446984 CPUtime=0
/proc/8502/task/8506/stat : 8506 (java) S 8500 8500 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 15 0 5 0 874992551 457711616 73080 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=8502/tid=8508] ppid=8500 vsize=446984 CPUtime=0.08
/proc/8502/task/8508/stat : 8508 (java) S 8500 8500 2059 34821 2220 4202560 523 0 6 0 7 1 0 0 15 0 5 0 874992570 457711616 73080 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=8502/tid=8509] ppid=8500 vsize=446984 CPUtime=0
/proc/8502/task/8509/stat : 8509 (java) S 8500 8500 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 22 0 5 0 874992570 457711616 73080 1283457024 134512640 134550932 4293480448 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 49.52
Current children cumulated vsize (KiB) 449556

Child status: 0
Real time (s): 51.2302
CPU time (s): 49.5551
CPU user time (s): 48.8391
CPU system time (s): 0.716044
CPU usage (%): 96.7302
Max. virtual memory (cumulated for all children) (KiB): 449864

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 48.8391
system time used= 0.716044
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 189396
page faults= 245
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 2136
involuntary context switches= 2333

runsolver used 0 second user time and 0.004 second system time

The end