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/201012070034/aspcud-trendy-1.3/rand550.sarge-etch-lenny.cudf.sarge-etch-lenny.log.runsolver ./aspcud-trendy-1.3 /home/misc2010/data/icse/sarge-etch-lenny/rand550.sarge-etch-lenny.cudf /home/misc2010/tmp/201012070034/aspcud-trendy-1.3/rand550.sarge-etch-lenny.cudf.sarge-etch-lenny.result 

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


[startup+0 s]
/proc/loadavg: 1.12 1.07 1.04 3/47 20335
/proc/meminfo: memFree=725200/1048576 swapFree=2077688/2097144
[pid=20334] ppid=20333 vsize=2588 CPUtime=0
/proc/20334/stat : 20334 (aspcud-trendy-1) R 20333 20334 4159 34819 4229 4202496 368 0 0 0 0 0 0 0 25 0 1 0 881655633 2650112 282 1283457024 134512640 135304128 4288181120 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/20334/statm: 647 282 237 194 0 33 0
[pid=20335] ppid=20334 vsize=2588 CPUtime=0
/proc/20335/stat : 20335 (aspcud-trendy-1) R 20334 20334 4159 34819 4229 4202560 0 0 0 0 0 0 0 0 25 0 1 0 881655633 2650112 45 1283457024 134512640 135304128 4288181120 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/20335/statm: 647 45 0 194 0 33 0

[startup+0.20625 s]
/proc/loadavg: 1.12 1.07 1.04 3/47 20335
/proc/meminfo: memFree=725200/1048576 swapFree=2077688/2097144
[pid=20334] ppid=20333 vsize=2596 CPUtime=0
/proc/20334/stat : 20334 (aspcud-trendy-1) S 20333 20334 4159 34819 4229 4202496 619 2215 0 0 0 0 0 0 25 0 1 0 881655633 2658304 300 1283457024 134512640 135304128 4288181120 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/20334/statm: 649 300 253 194 0 35 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2596

[startup+0.306268 s]
/proc/loadavg: 1.12 1.07 1.04 3/47 20335
/proc/meminfo: memFree=725200/1048576 swapFree=2077688/2097144
[pid=20334] ppid=20333 vsize=2596 CPUtime=0
/proc/20334/stat : 20334 (aspcud-trendy-1) S 20333 20334 4159 34819 4229 4202496 619 2215 0 0 0 0 0 0 25 0 1 0 881655633 2658304 300 1283457024 134512640 135304128 4288181120 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/20334/statm: 649 300 253 194 0 35 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2596

[startup+0.406309 s]
/proc/loadavg: 1.12 1.07 1.04 3/47 20335
/proc/meminfo: memFree=725200/1048576 swapFree=2077688/2097144
[pid=20334] ppid=20333 vsize=2596 CPUtime=0
/proc/20334/stat : 20334 (aspcud-trendy-1) S 20333 20334 4159 34819 4229 4202496 619 2215 0 0 0 0 0 0 25 0 1 0 881655633 2658304 300 1283457024 134512640 135304128 4288181120 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/20334/statm: 649 300 253 194 0 35 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2596

[startup+0.706396 s]
/proc/loadavg: 1.12 1.07 1.04 3/47 20335
/proc/meminfo: memFree=725200/1048576 swapFree=2077688/2097144
[pid=20334] ppid=20333 vsize=2596 CPUtime=0
/proc/20334/stat : 20334 (aspcud-trendy-1) S 20333 20334 4159 34819 4229 4202496 619 2215 0 0 0 0 0 0 25 0 1 0 881655633 2658304 300 1283457024 134512640 135304128 4288181120 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/20334/statm: 649 300 253 194 0 35 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2596

[startup+1.50663 s]
/proc/loadavg: 1.12 1.07 1.04 3/50 20348
/proc/meminfo: memFree=682784/1048576 swapFree=2077688/2097144
[pid=20334] ppid=20333 vsize=2596 CPUtime=0.87
/proc/20334/stat : 20334 (aspcud-trendy-1) S 20333 20334 4159 34819 4229 4202496 619 11333 0 1 0 0 81 6 18 0 1 0 881655633 2658304 300 1283457024 134512640 135304128 4288181120 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/20334/statm: 649 300 253 194 0 35 0
[pid=20346] ppid=20334 vsize=11828 CPUtime=0.05
/proc/20346/stat : 20346 (clasp) S 20334 20334 4159 34819 4229 4202496 3143 0 1 0 4 1 0 0 18 0 1 0 881655634 12111872 2626 1283457024 134512640 136223643 4292526640 18446744073709551615 135666734 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0
/proc/20346/statm: 2957 2626 174 418 0 2537 0
[pid=20347] ppid=20334 vsize=17960 CPUtime=0.55
/proc/20347/stat : 20347 (gringo) R 20334 20334 4159 34819 4229 4202496 5103 0 1 0 53 2 0 0 20 0 1 0 881655634 18391040 3491 1283457024 134512640 136959103 4293040672 18446744073709551615 134901445 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/20347/statm: 4490 3491 256 598 0 3889 0
Current children cumulated CPU time (s) 1.47
Current children cumulated vsize (KiB) 32384

[startup+3.10697 s]
/proc/loadavg: 1.12 1.07 1.04 2/49 20348
/proc/meminfo: memFree=670400/1048576 swapFree=2077688/2097144
[pid=20334] ppid=20333 vsize=2596 CPUtime=2.13
/proc/20334/stat : 20334 (aspcud-trendy-1) S 20333 20334 4159 34819 4229 4202496 619 24228 0 2 0 0 203 10 18 0 1 0 881655633 2658304 300 1283457024 134512640 135304128 4288181120 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/20334/statm: 649 300 253 194 0 35 0
[pid=20346] ppid=20334 vsize=37228 CPUtime=0.93
/proc/20346/stat : 20346 (clasp) R 20334 20334 4159 34819 4229 4202496 10477 0 1 0 89 4 0 0 18 0 1 0 881655634 38121472 8541 1283457024 134512640 136223643 4292526640 18446744073709551615 134928869 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/20346/statm: 9307 8541 222 418 0 8887 0
Current children cumulated CPU time (s) 3.06
Current children cumulated vsize (KiB) 39824

[startup+6.30794 s]
/proc/loadavg: 1.11 1.07 1.04 2/48 20348
/proc/meminfo: memFree=690752/1048576 swapFree=2077688/2097144
[pid=20334] ppid=20333 vsize=2596 CPUtime=2.13
/proc/20334/stat : 20334 (aspcud-trendy-1) S 20333 20334 4159 34819 4229 4202496 619 24228 0 2 0 0 203 10 18 0 1 0 881655633 2658304 300 1283457024 134512640 135304128 4288181120 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/20334/statm: 649 300 253 194 0 35 0
[pid=20346] ppid=20334 vsize=39876 CPUtime=4.14
/proc/20346/stat : 20346 (clasp) R 20334 20334 4159 34819 4229 4202496 11164 0 1 0 408 6 0 0 25 0 1 0 881655634 40833024 9228 1283457024 134512640 136223643 4292526640 18446744073709551615 134664705 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/20346/statm: 9969 9228 225 418 0 9549 0
Current children cumulated CPU time (s) 6.27
Current children cumulated vsize (KiB) 42472

[startup+12.7092 s]
/proc/loadavg: 1.10 1.07 1.04 2/48 20348
/proc/meminfo: memFree=674756/1048576 swapFree=2077688/2097144
[pid=20334] ppid=20333 vsize=2596 CPUtime=2.13
/proc/20334/stat : 20334 (aspcud-trendy-1) S 20333 20334 4159 34819 4229 4202496 619 24228 0 2 0 0 203 10 18 0 1 0 881655633 2658304 300 1283457024 134512640 135304128 4288181120 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/20334/statm: 649 300 253 194 0 35 0
[pid=20346] ppid=20334 vsize=54012 CPUtime=10.53
/proc/20346/stat : 20346 (clasp) R 20334 20334 4159 34819 4229 4202496 14694 0 1 0 1047 6 0 0 25 0 1 0 881655634 55308288 12758 1283457024 134512640 136223643 4292526640 18446744073709551615 134924244 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/20346/statm: 13503 12758 225 418 0 13083 0
Current children cumulated CPU time (s) 12.66
Current children cumulated vsize (KiB) 56608

[startup+25.5126 s]
/proc/loadavg: 1.08 1.06 1.04 2/48 20348
/proc/meminfo: memFree=651568/1048576 swapFree=2077688/2097144
[pid=20334] ppid=20333 vsize=2596 CPUtime=2.13
/proc/20334/stat : 20334 (aspcud-trendy-1) S 20333 20334 4159 34819 4229 4202496 619 24228 0 2 0 0 203 10 18 0 1 0 881655633 2658304 300 1283457024 134512640 135304128 4288181120 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/20334/statm: 649 300 253 194 0 35 0
[pid=20346] ppid=20334 vsize=76728 CPUtime=23.32
/proc/20346/stat : 20346 (clasp) R 20334 20334 4159 34819 4229 4202496 20364 0 1 0 2323 9 0 0 25 0 1 0 881655634 78569472 18428 1283457024 134512640 136223643 4292526640 18446744073709551615 134704907 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/20346/statm: 19182 18428 225 418 0 18762 0
Current children cumulated CPU time (s) 25.45
Current children cumulated vsize (KiB) 79324

[startup+51.1094 s]
/proc/loadavg: 1.05 1.06 1.03 2/48 20348
/proc/meminfo: memFree=615856/1048576 swapFree=2077688/2097144
[pid=20334] ppid=20333 vsize=2596 CPUtime=2.13
/proc/20334/stat : 20334 (aspcud-trendy-1) S 20333 20334 4159 34819 4229 4202496 619 24228 0 2 0 0 203 10 18 0 1 0 881655633 2658304 300 1283457024 134512640 135304128 4288181120 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/20334/statm: 649 300 253 194 0 35 0
[pid=20346] ppid=20334 vsize=113384 CPUtime=48.88
/proc/20346/stat : 20346 (clasp) R 20334 20334 4159 34819 4229 4202496 29525 0 1 0 4877 11 0 0 25 0 1 0 881655634 116105216 27589 1283457024 134512640 136223643 4292526640 18446744073709551615 134924385 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/20346/statm: 28346 27589 225 418 0 27926 0
Current children cumulated CPU time (s) 51.01
Current children cumulated vsize (KiB) 115980

[startup+102.312 s]
/proc/loadavg: 1.02 1.05 1.03 2/48 20348
/proc/meminfo: memFree=592544/1048576 swapFree=2077688/2097144
[pid=20334] ppid=20333 vsize=2596 CPUtime=2.13
/proc/20334/stat : 20334 (aspcud-trendy-1) S 20333 20334 4159 34819 4229 4202496 619 24228 0 2 0 0 203 10 18 0 1 0 881655633 2658304 300 1283457024 134512640 135304128 4288181120 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/20334/statm: 649 300 253 194 0 35 0
[pid=20346] ppid=20334 vsize=141136 CPUtime=100.04
/proc/20346/stat : 20346 (clasp) R 20334 20334 4159 34819 4229 4202496 36437 0 1 0 9990 14 0 0 25 0 1 0 881655634 144523264 34501 1283457024 134512640 136223643 4292526640 18446744073709551615 134924336 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/20346/statm: 35284 34501 225 418 0 34864 0
Current children cumulated CPU time (s) 102.17
Current children cumulated vsize (KiB) 143732

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

[startup+102.512 s]
/proc/loadavg: 1.02 1.05 1.03 2/48 20348
/proc/meminfo: memFree=586592/1048576 swapFree=2077688/2097144
[pid=20334] ppid=20333 vsize=2596 CPUtime=2.13
/proc/20334/stat : 20334 (aspcud-trendy-1) S 20333 20334 4159 34819 4229 4202496 619 24228 0 2 0 0 203 10 18 0 1 0 881655633 2658304 300 1283457024 134512640 135304128 4288181120 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/20334/statm: 649 300 253 194 0 35 0
[pid=20346] ppid=20334 vsize=142060 CPUtime=100.24
/proc/20346/stat : 20346 (clasp) R 20334 20334 4159 34819 4229 4202496 36674 0 1 0 10009 15 0 0 25 0 1 0 881655634 145469440 34738 1283457024 134512640 136223643 4292526640 18446744073709551615 134711984 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/20346/statm: 35515 34738 225 418 0 35095 0
Current children cumulated CPU time (s) 102.37
Current children cumulated vsize (KiB) 144656

[startup+128.109 s]
/proc/loadavg: 1.01 1.04 1.03 2/48 20348
/proc/meminfo: memFree=543564/1048576 swapFree=2077688/2097144
[pid=20334] ppid=20333 vsize=2596 CPUtime=2.13
/proc/20334/stat : 20334 (aspcud-trendy-1) S 20333 20334 4159 34819 4229 4202496 619 24228 0 2 0 0 203 10 18 0 1 0 881655633 2658304 300 1283457024 134512640 135304128 4288181120 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/20334/statm: 649 300 253 194 0 35 0
[pid=20346] ppid=20334 vsize=184680 CPUtime=125.8
/proc/20346/stat : 20346 (clasp) R 20334 20334 4159 34819 4229 4202496 47300 0 1 0 12558 22 0 0 25 0 1 0 881655634 189112320 45364 1283457024 134512640 136223643 4292526640 18446744073709551615 134924221 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/20346/statm: 46170 45364 225 418 0 45750 0
Current children cumulated CPU time (s) 127.93
Current children cumulated vsize (KiB) 187276

[startup+140.912 s]
/proc/loadavg: 1.01 1.04 1.03 2/48 20348
/proc/meminfo: memFree=543564/1048576 swapFree=2077688/2097144
[pid=20334] ppid=20333 vsize=2596 CPUtime=2.13
/proc/20334/stat : 20334 (aspcud-trendy-1) S 20333 20334 4159 34819 4229 4202496 619 24228 0 2 0 0 203 10 18 0 1 0 881655633 2658304 300 1283457024 134512640 135304128 4288181120 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/20334/statm: 649 300 253 194 0 35 0
[pid=20346] ppid=20334 vsize=184680 CPUtime=138.59
/proc/20346/stat : 20346 (clasp) R 20334 20334 4159 34819 4229 4202496 47300 0 1 0 13836 23 0 0 25 0 1 0 881655634 189112320 45364 1283457024 134512640 136223643 4292526640 18446744073709551615 134704900 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/20346/statm: 46170 45364 225 418 0 45750 0
Current children cumulated CPU time (s) 140.72
Current children cumulated vsize (KiB) 187276

[startup+144.113 s]
/proc/loadavg: 1.01 1.04 1.03 2/48 20348
/proc/meminfo: memFree=543564/1048576 swapFree=2077688/2097144
[pid=20334] ppid=20333 vsize=2596 CPUtime=2.13
/proc/20334/stat : 20334 (aspcud-trendy-1) S 20333 20334 4159 34819 4229 4202496 619 24228 0 2 0 0 203 10 18 0 1 0 881655633 2658304 300 1283457024 134512640 135304128 4288181120 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/20334/statm: 649 300 253 194 0 35 0
[pid=20346] ppid=20334 vsize=184680 CPUtime=141.79
/proc/20346/stat : 20346 (clasp) R 20334 20334 4159 34819 4229 4202496 47300 0 1 0 14156 23 0 0 25 0 1 0 881655634 189112320 45364 1283457024 134512640 136223643 4292526640 18446744073709551615 134931073 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/20346/statm: 46170 45364 225 418 0 45750 0
Current children cumulated CPU time (s) 143.92
Current children cumulated vsize (KiB) 187276

[startup+145.714 s]
/proc/loadavg: 1.01 1.04 1.02 2/48 20348
/proc/meminfo: memFree=543564/1048576 swapFree=2077688/2097144
[pid=20334] ppid=20333 vsize=2596 CPUtime=2.13
/proc/20334/stat : 20334 (aspcud-trendy-1) S 20333 20334 4159 34819 4229 4202496 619 24228 0 2 0 0 203 10 18 0 1 0 881655633 2658304 300 1283457024 134512640 135304128 4288181120 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/20334/statm: 649 300 253 194 0 35 0
[pid=20346] ppid=20334 vsize=184680 CPUtime=143.39
/proc/20346/stat : 20346 (clasp) R 20334 20334 4159 34819 4229 4202496 47300 0 1 0 14316 23 0 0 25 0 1 0 881655634 189112320 45364 1283457024 134512640 136223643 4292526640 18446744073709551615 134928869 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/20346/statm: 46170 45364 225 418 0 45750 0
Current children cumulated CPU time (s) 145.52
Current children cumulated vsize (KiB) 187276

[startup+146.504 s]
/proc/loadavg: 1.01 1.04 1.02 2/48 20348
/proc/meminfo: memFree=541332/1048576 swapFree=2077688/2097144
[pid=20334] ppid=20333 vsize=2596 CPUtime=2.13
/proc/20334/stat : 20334 (aspcud-trendy-1) S 20333 20334 4159 34819 4229 4202496 619 24228 0 2 0 0 203 10 18 0 1 0 881655633 2658304 300 1283457024 134512640 135304128 4288181120 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/20334/statm: 649 300 253 194 0 35 0
[pid=20346] ppid=20334 vsize=187452 CPUtime=144.17
/proc/20346/stat : 20346 (clasp) R 20334 20334 4159 34819 4229 4202496 48007 0 1 0 14394 23 0 0 25 0 1 0 881655634 191950848 46071 1283457024 134512640 136223643 4292526640 18446744073709551615 134931129 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/20346/statm: 46863 46071 225 418 0 46443 0
Current children cumulated CPU time (s) 146.3
Current children cumulated vsize (KiB) 190048

[startup+146.904 s]
/proc/loadavg: 1.01 1.04 1.02 2/48 20348
/proc/meminfo: memFree=541332/1048576 swapFree=2077688/2097144
[pid=20334] ppid=20333 vsize=2596 CPUtime=2.13
/proc/20334/stat : 20334 (aspcud-trendy-1) S 20333 20334 4159 34819 4229 4202496 619 24228 0 2 0 0 203 10 18 0 1 0 881655633 2658304 300 1283457024 134512640 135304128 4288181120 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/20334/statm: 649 300 253 194 0 35 0
[pid=20346] ppid=20334 vsize=189564 CPUtime=144.57
/proc/20346/stat : 20346 (clasp) R 20334 20334 4159 34819 4229 4202496 48535 0 1 0 14434 23 0 0 25 0 1 0 881655634 194113536 46599 1283457024 134512640 136223643 4292526640 18446744073709551615 134931099 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/20346/statm: 47391 46599 225 418 0 46971 0
Current children cumulated CPU time (s) 146.7
Current children cumulated vsize (KiB) 192160

[startup+147.104 s]
/proc/loadavg: 1.01 1.04 1.02 2/48 20348
/proc/meminfo: memFree=541332/1048576 swapFree=2077688/2097144
[pid=20334] ppid=20333 vsize=2596 CPUtime=2.13
/proc/20334/stat : 20334 (aspcud-trendy-1) S 20333 20334 4159 34819 4229 4202496 619 24228 0 2 0 0 203 10 18 0 1 0 881655633 2658304 300 1283457024 134512640 135304128 4288181120 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/20334/statm: 649 300 253 194 0 35 0
[pid=20346] ppid=20334 vsize=179228 CPUtime=144.75
/proc/20346/stat : 20346 (clasp) R 20334 20334 4159 34819 4229 4202496 48551 0 3 0 14452 23 0 0 25 0 1 0 881655634 183529472 44563 1283457024 134512640 136223643 4292526640 18446744073709551615 135599024 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/20346/statm: 44807 44563 231 418 0 44387 0
Current children cumulated CPU time (s) 146.88
Current children cumulated vsize (KiB) 181824

Child status: 0
Real time (s): 147.191
CPU time (s): 146.957
CPU user time (s): 146.577
CPU system time (s): 0.380023
CPU usage (%): 99.8413
Max. virtual memory (cumulated for all children) (KiB): 192308

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 146.577
system time used= 0.380023
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 77037
page faults= 9
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 2156
involuntary context switches= 3892

runsolver used 0 second user time and 0.004 second system time

The end