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: runsolver -s SIGUSR1 -M 1124 -C 300 -d 10 -w /tmp/misc2012/2012-09-02-22:42/full/aspcud-full-1.7/trendy-size/upgrade/easy/rand377.cudf.log.runsolver /home/competition/aspcud-full-1.7/aspcud-full /home/competition/data/upgrade/easy/rand377.cudf /tmp/misc2012/2012-09-02-22:42/full/aspcud-full-1.7/trendy-size/upgrade/easy/rand377.cudf.result -count(removed),-sum(solution,installedsize),-notuptodate(solution),-unsat_recommends(solution),-count(new) 

Enforcing CPUTime limit (soft limit, will send signal-name then SIGKILL): 300 seconds
Enforcing CPUTime limit (hard limit, will send SIGXCPU): 330 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.01 0.98 0.95 2/64 16822
/proc/meminfo: memFree=394060/1022884 swapFree=0/0
[pid=16822] ppid=16821 vsize=9196 CPUtime=0
/proc/16822/stat : 16822 (aspcud-full) R 16821 16822 1745 0 -1 4202496 412 0 0 0 0 0 0 0 20 0 1 0 119416655 9416704 320 18446744073709551615 4194304 5129932 140737212024560 140737212022856 4404760 0 0 16781316 65536 0 0 0 17 0 0 0 0 0 0
/proc/16822/statm: 2299 320 263 229 0 59 0

[startup+0.168405 s]
/proc/loadavg: 1.01 0.98 0.95 2/64 16822
/proc/meminfo: memFree=394060/1022884 swapFree=0/0
[pid=16822] ppid=16821 vsize=9212 CPUtime=0.04
/proc/16822/stat : 16822 (aspcud-full) S 16821 16822 1745 0 -1 4202496 740 3614 0 0 0 0 4 0 20 0 1 0 119416655 9433088 364 18446744073709551615 4194304 5129932 140737212024560 140737212023216 140042020717662 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/16822/statm: 2303 364 303 229 0 63 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 9212

[startup+0.200316 s]
/proc/loadavg: 1.01 0.98 0.95 2/64 16822
/proc/meminfo: memFree=394060/1022884 swapFree=0/0
[pid=16822] ppid=16821 vsize=9212 CPUtime=0.04
/proc/16822/stat : 16822 (aspcud-full) S 16821 16822 1745 0 -1 4202496 740 3614 0 0 0 0 4 0 20 0 1 0 119416655 9433088 364 18446744073709551615 4194304 5129932 140737212024560 140737212023216 140042020717662 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/16822/statm: 2303 364 303 229 0 63 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 9212

[startup+0.300299 s]
/proc/loadavg: 1.01 0.98 0.95 2/64 16822
/proc/meminfo: memFree=394060/1022884 swapFree=0/0
[pid=16822] ppid=16821 vsize=9212 CPUtime=0.04
/proc/16822/stat : 16822 (aspcud-full) S 16821 16822 1745 0 -1 4202496 740 3614 0 0 0 0 4 0 20 0 1 0 119416655 9433088 364 18446744073709551615 4194304 5129932 140737212024560 140737212023216 140042020717662 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/16822/statm: 2303 364 303 229 0 63 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 9212

[startup+0.700219 s]
/proc/loadavg: 1.01 0.98 0.95 2/64 16822
/proc/meminfo: memFree=394060/1022884 swapFree=0/0
[pid=16822] ppid=16821 vsize=9212 CPUtime=0.04
/proc/16822/stat : 16822 (aspcud-full) S 16821 16822 1745 0 -1 4202496 740 3614 0 0 0 0 4 0 20 0 1 0 119416655 9433088 364 18446744073709551615 4194304 5129932 140737212024560 140737212023216 140042020717662 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/16822/statm: 2303 364 303 229 0 63 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 9212

[startup+1.50031 s]
/proc/loadavg: 1.01 0.98 0.95 2/66 16838
/proc/meminfo: memFree=359688/1022884 swapFree=0/0
[pid=16822] ppid=16821 vsize=9212 CPUtime=0.04
/proc/16822/stat : 16822 (aspcud-full) S 16821 16822 1745 0 -1 4202496 740 3614 0 0 0 0 4 0 20 0 1 0 119416655 9433088 364 18446744073709551615 4194304 5129932 140737212024560 140737212023216 140042020717662 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/16822/statm: 2303 364 303 229 0 63 0
[pid=16838] ppid=16822 vsize=48864 CPUtime=1.4
/proc/16838/stat : 16838 (cudf2lp) R 16822 16822 1745 0 -1 4202496 13676 0 0 0 134 6 0 0 20 0 1 0 119416658 50036736 10277 18446744073709551615 4194304 5690517 140736850256720 140736850253304 4961154 0 0 16781316 0 0 0 0 17 0 0 0 4 0 0
/proc/16838/statm: 12216 10277 159 366 0 11847 0
Current children cumulated CPU time (s) 1.44
Current children cumulated vsize (KiB) 58076

[startup+3.10159 s]
/proc/loadavg: 1.01 0.98 0.95 2/66 16838
/proc/meminfo: memFree=329184/1022884 swapFree=0/0
[pid=16822] ppid=16821 vsize=9212 CPUtime=0.04
/proc/16822/stat : 16822 (aspcud-full) S 16821 16822 1745 0 -1 4202496 740 3614 0 0 0 0 4 0 20 0 1 0 119416655 9433088 364 18446744073709551615 4194304 5129932 140737212024560 140737212023216 140042020717662 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/16822/statm: 2303 364 303 229 0 63 0
[pid=16838] ppid=16822 vsize=72092 CPUtime=2.98
/proc/16838/stat : 16838 (cudf2lp) R 16822 16822 1745 0 -1 4202496 23823 0 0 0 282 16 0 0 20 0 1 0 119416658 73822208 15711 18446744073709551615 4194304 5690517 140736850256720 140736850254600 5219018 0 0 16781316 0 0 0 0 17 0 0 0 5 0 0
/proc/16838/statm: 18023 15711 174 366 0 17654 0
Current children cumulated CPU time (s) 3.02
Current children cumulated vsize (KiB) 81304

[startup+6.3003 s]
/proc/loadavg: 1.01 0.98 0.95 2/66 16839
/proc/meminfo: memFree=264456/1022884 swapFree=0/0
[pid=16822] ppid=16821 vsize=9212 CPUtime=3.09
/proc/16822/stat : 16822 (aspcud-full) S 16821 16822 1745 0 -1 4202496 766 27439 0 0 0 0 290 19 20 0 1 0 119416655 9433088 364 18446744073709551615 4194304 5129932 140737212024560 140737212023216 140042020717662 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/16822/statm: 2303 364 303 229 0 63 0
[pid=16839] ppid=16822 vsize=162064 CPUtime=3.1
/proc/16839/stat : 16839 (gringo) R 16822 16822 1745 0 -1 4202496 40795 0 0 0 291 19 0 0 20 0 1 0 119416970 165953536 36352 18446744073709551615 4194304 6531320 140733614632272 140733614628888 5520787 0 0 16781316 16386 0 0 0 17 0 0 0 0 0 0
/proc/16839/statm: 40516 36352 281 571 0 39937 0
Current children cumulated CPU time (s) 6.19
Current children cumulated vsize (KiB) 171276

[startup+12.7004 s]
/proc/loadavg: 1.01 0.98 0.95 2/67 16841
/proc/meminfo: memFree=268664/1022884 swapFree=0/0
[pid=16822] ppid=16821 vsize=9212 CPUtime=10.37
/proc/16822/stat : 16822 (aspcud-full) S 16821 16822 1745 0 -1 4202496 807 135175 0 0 0 0 958 79 20 0 1 0 119416655 9433088 364 18446744073709551615 4194304 5129932 140737212024560 140737212022624 140042020717662 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/16822/statm: 2303 364 303 229 0 63 0
[pid=16840] ppid=16822 vsize=138244 CPUtime=2.01
/proc/16840/stat : 16840 (clasp) R 16822 16822 1745 0 -1 4202496 40155 0 0 0 185 16 0 0 20 0 1 0 119417717 141561856 33995 18446744073709551615 4194304 6238623 140733537083984 140733537081008 4356146 0 0 16781316 18946 0 0 0 17 0 0 0 0 0 0
/proc/16840/statm: 34561 33995 263 500 0 34058 0
[pid=16841] ppid=16822 vsize=22040 CPUtime=0.02
/proc/16841/stat : 16841 (parse.py) S 16822 16822 1745 0 -1 4202496 1306 0 13 0 0 2 0 0 20 0 1 0 119417717 22568960 1128 18446744073709551615 4194304 6642060 140734923595440 140734923593800 140293693654816 0 0 16777220 20994 0 0 0 17 0 0 0 7 0 0
/proc/16841/statm: 5510 1128 508 598 0 596 0
Current children cumulated CPU time (s) 12.4
Current children cumulated vsize (KiB) 169496

[startup+25.5004 s]
/proc/loadavg: 1.00 0.98 0.95 2/67 16841
/proc/meminfo: memFree=267796/1022884 swapFree=0/0
[pid=16822] ppid=16821 vsize=9212 CPUtime=10.37
/proc/16822/stat : 16822 (aspcud-full) S 16821 16822 1745 0 -1 4202496 807 135175 0 0 0 0 958 79 20 0 1 0 119416655 9433088 364 18446744073709551615 4194304 5129932 140737212024560 140737212022624 140042020717662 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/16822/statm: 2303 364 303 229 0 63 0
[pid=16840] ppid=16822 vsize=138244 CPUtime=14.68
/proc/16840/stat : 16840 (clasp) R 16822 16822 1745 0 -1 4202496 40416 0 0 0 1452 16 0 0 20 0 1 0 119417717 141561856 34256 18446744073709551615 4194304 6238623 140733537083984 140733537081008 4687707 0 0 16781316 18946 0 0 0 17 0 0 0 0 0 0
/proc/16840/statm: 34561 34256 264 500 0 34058 0
[pid=16841] ppid=16822 vsize=22040 CPUtime=0.02
/proc/16841/stat : 16841 (parse.py) S 16822 16822 1745 0 -1 4202496 1306 0 13 0 0 2 0 0 20 0 1 0 119417717 22568960 1128 18446744073709551615 4194304 6642060 140734923595440 140734923593800 140293693654816 0 0 16777220 20994 0 0 0 17 0 0 0 7 0 0
/proc/16841/statm: 5510 1128 508 598 0 596 0
Current children cumulated CPU time (s) 25.07
Current children cumulated vsize (KiB) 169496

[startup+51.1003 s]
/proc/loadavg: 1.00 0.98 0.95 2/67 16841
/proc/meminfo: memFree=267796/1022884 swapFree=0/0
[pid=16822] ppid=16821 vsize=9212 CPUtime=10.37
/proc/16822/stat : 16822 (aspcud-full) S 16821 16822 1745 0 -1 4202496 807 135175 0 0 0 0 958 79 20 0 1 0 119416655 9433088 364 18446744073709551615 4194304 5129932 140737212024560 140737212022624 140042020717662 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/16822/statm: 2303 364 303 229 0 63 0
[pid=16840] ppid=16822 vsize=138244 CPUtime=40.04
/proc/16840/stat : 16840 (clasp) R 16822 16822 1745 0 -1 4202496 40416 0 0 0 3987 17 0 0 20 0 1 0 119417717 141561856 34256 18446744073709551615 4194304 6238623 140733537083984 140733537081008 4677160 0 0 16781316 18946 0 0 0 17 0 0 0 0 0 0
/proc/16840/statm: 34561 34256 264 500 0 34058 0
[pid=16841] ppid=16822 vsize=22040 CPUtime=0.02
/proc/16841/stat : 16841 (parse.py) S 16822 16822 1745 0 -1 4202496 1306 0 13 0 0 2 0 0 20 0 1 0 119417717 22568960 1128 18446744073709551615 4194304 6642060 140734923595440 140734923593800 140293693654816 0 0 16777220 20994 0 0 0 17 0 0 0 7 0 0
/proc/16841/statm: 5510 1128 508 598 0 596 0
Current children cumulated CPU time (s) 50.43
Current children cumulated vsize (KiB) 169496

[startup+102.3 s]
/proc/loadavg: 1.00 0.98 0.95 2/67 16849
/proc/meminfo: memFree=135240/1022884 swapFree=0/0
[pid=16822] ppid=16821 vsize=9212 CPUtime=10.37
/proc/16822/stat : 16822 (aspcud-full) S 16821 16822 1745 0 -1 4202496 807 135175 0 0 0 0 958 79 20 0 1 0 119416655 9433088 364 18446744073709551615 4194304 5129932 140737212024560 140737212022624 140042020717662 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/16822/statm: 2303 364 303 229 0 63 0
[pid=16840] ppid=16822 vsize=270444 CPUtime=90.7
/proc/16840/stat : 16840 (clasp) R 16822 16822 1745 0 -1 4202496 73408 0 0 0 9034 36 0 0 20 0 1 0 119417717 276934656 67248 18446744073709551615 4194304 6238623 140733537083984 140733537080536 4687675 0 0 16781316 18946 0 0 0 17 0 0 0 0 0 0
/proc/16840/statm: 67611 67248 264 500 0 67108 0
[pid=16841] ppid=16822 vsize=22040 CPUtime=0.02
/proc/16841/stat : 16841 (parse.py) S 16822 16822 1745 0 -1 4202496 1306 0 13 0 0 2 0 0 20 0 1 0 119417717 22568960 1128 18446744073709551615 4194304 6642060 140734923595440 140734923593800 140293693654816 0 0 16777220 20994 0 0 0 17 0 0 0 7 0 0
/proc/16841/statm: 5510 1128 508 598 0 596 0
Current children cumulated CPU time (s) 101.09
Current children cumulated vsize (KiB) 301696

[startup+162.3 s]
/proc/loadavg: 1.00 0.98 0.95 2/67 16849
/proc/meminfo: memFree=109572/1022884 swapFree=0/0
[pid=16822] ppid=16821 vsize=9212 CPUtime=10.37
/proc/16822/stat : 16822 (aspcud-full) S 16821 16822 1745 0 -1 4202496 807 135175 0 0 0 0 958 79 20 0 1 0 119416655 9433088 364 18446744073709551615 4194304 5129932 140737212024560 140737212022624 140042020717662 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/16822/statm: 2303 364 303 229 0 63 0
[pid=16840] ppid=16822 vsize=295772 CPUtime=150.09
/proc/16840/stat : 16840 (clasp) R 16822 16822 1745 0 -1 4202496 79772 0 0 0 14971 38 0 0 20 0 1 0 119417717 302870528 73612 18446744073709551615 4194304 6238623 140733537083984 140733537080536 4332843 0 0 16781316 18946 0 0 0 17 0 0 0 0 0 0
/proc/16840/statm: 73943 73612 264 500 0 73440 0
[pid=16841] ppid=16822 vsize=22040 CPUtime=0.02
/proc/16841/stat : 16841 (parse.py) S 16822 16822 1745 0 -1 4202496 1306 0 13 0 0 2 0 0 20 0 1 0 119417717 22568960 1128 18446744073709551615 4194304 6642060 140734923595440 140734923593800 140293693654816 0 0 16777220 20994 0 0 0 17 0 0 0 7 0 0
/proc/16841/statm: 5510 1128 508 598 0 596 0
Current children cumulated CPU time (s) 160.48
Current children cumulated vsize (KiB) 327024

[startup+222.303 s]
/proc/loadavg: 1.00 0.98 0.95 2/67 16849
/proc/meminfo: memFree=102876/1022884 swapFree=0/0
[pid=16822] ppid=16821 vsize=9212 CPUtime=10.37
/proc/16822/stat : 16822 (aspcud-full) S 16821 16822 1745 0 -1 4202496 807 135175 0 0 0 0 958 79 20 0 1 0 119416655 9433088 364 18446744073709551615 4194304 5129932 140737212024560 140737212022624 140042020717662 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/16822/statm: 2303 364 303 229 0 63 0
[pid=16840] ppid=16822 vsize=302600 CPUtime=209.5
/proc/16840/stat : 16840 (clasp) R 16822 16822 1745 0 -1 4202496 81457 0 0 0 20911 39 0 0 20 0 1 0 119417717 309862400 75297 18446744073709551615 4194304 6238623 140733537083984 140733537080536 4332646 0 0 16781316 18946 0 0 0 17 0 0 0 0 0 0
/proc/16840/statm: 75650 75297 264 500 0 75147 0
[pid=16841] ppid=16822 vsize=22040 CPUtime=0.02
/proc/16841/stat : 16841 (parse.py) S 16822 16822 1745 0 -1 4202496 1306 0 13 0 0 2 0 0 20 0 1 0 119417717 22568960 1128 18446744073709551615 4194304 6642060 140734923595440 140734923593800 140293693654816 0 0 16777220 20994 0 0 0 17 0 0 0 7 0 0
/proc/16841/statm: 5510 1128 508 598 0 596 0
Current children cumulated CPU time (s) 219.89
Current children cumulated vsize (KiB) 333852

[startup+282.3 s]
/proc/loadavg: 1.04 1.00 0.96 2/67 16849
/proc/meminfo: memFree=101636/1022884 swapFree=0/0
[pid=16822] ppid=16821 vsize=9212 CPUtime=10.37
/proc/16822/stat : 16822 (aspcud-full) S 16821 16822 1745 0 -1 4202496 807 135175 0 0 0 0 958 79 20 0 1 0 119416655 9433088 364 18446744073709551615 4194304 5129932 140737212024560 140737212022624 140042020717662 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/16822/statm: 2303 364 303 229 0 63 0
[pid=16840] ppid=16822 vsize=303676 CPUtime=268.92
/proc/16840/stat : 16840 (clasp) R 16822 16822 1745 0 -1 4202496 81739 0 0 0 26853 39 0 0 20 0 1 0 119417717 310964224 75579 18446744073709551615 4194304 6238623 140733537083984 140733537080536 4676718 0 0 16781316 18946 0 0 0 17 0 0 0 0 0 0
/proc/16840/statm: 75919 75579 264 500 0 75416 0
[pid=16841] ppid=16822 vsize=22040 CPUtime=0.02
/proc/16841/stat : 16841 (parse.py) S 16822 16822 1745 0 -1 4202496 1306 0 13 0 0 2 0 0 20 0 1 0 119417717 22568960 1128 18446744073709551615 4194304 6642060 140734923595440 140734923593800 140293693654816 0 0 16777220 20994 0 0 0 17 0 0 0 7 0 0
/proc/16841/statm: 5510 1128 508 598 0 596 0
Current children cumulated CPU time (s) 279.31
Current children cumulated vsize (KiB) 334928



Maximum CPU time exceeded: sending signal-name then SIGKILL

[startup+303.2 s]
/proc/loadavg: 1.02 1.00 0.96 2/67 16849
/proc/meminfo: memFree=101636/1022884 swapFree=0/0
[pid=16822] ppid=16821 vsize=9212 CPUtime=10.37
/proc/16822/stat : 16822 (aspcud-full) S 16821 16822 1745 0 -1 4202496 807 135175 0 0 0 0 958 79 20 0 1 0 119416655 9433088 364 18446744073709551615 4194304 5129932 140737212024560 140737212022624 140042020717662 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/16822/statm: 2303 364 303 229 0 63 0
[pid=16840] ppid=16822 vsize=303676 CPUtime=289.62
/proc/16840/stat : 16840 (clasp) R 16822 16822 1745 0 -1 4202496 81740 0 0 0 28923 39 0 0 20 0 1 0 119417717 310964224 75580 18446744073709551615 4194304 6238623 140733537083984 140733537080536 4687693 0 0 16781316 18946 0 0 0 17 0 0 0 0 0 0
/proc/16840/statm: 75919 75580 264 500 0 75416 0
[pid=16841] ppid=16822 vsize=22040 CPUtime=0.02
/proc/16841/stat : 16841 (parse.py) S 16822 16822 1745 0 -1 4202496 1306 0 13 0 0 2 0 0 20 0 1 0 119417717 22568960 1128 18446744073709551615 4194304 6642060 140734923595440 140734923593800 140293693654816 0 0 16777220 20994 0 0 0 17 0 0 0 7 0 0
/proc/16841/statm: 5510 1128 508 598 0 596 0
Current children cumulated CPU time (s) 300.01
Current children cumulated vsize (KiB) 334928

Sending User defined signal 1 to process tree (bottom up)
Sleeping 10 seconds

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

[startup+303.2 s]
/proc/loadavg: 1.02 1.00 0.96 2/67 16849
/proc/meminfo: memFree=101636/1022884 swapFree=0/0
[pid=16822] ppid=16821 vsize=9212 CPUtime=10.37
/proc/16822/stat : 16822 (aspcud-full) S 16821 16822 1745 0 -1 4202496 807 135175 0 0 0 0 958 79 20 0 1 0 119416655 9433088 364 18446744073709551615 4194304 5129932 140737212024560 140737212022624 140042020717662 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/16822/statm: 2303 364 303 229 0 63 0
[pid=16840] ppid=16822 vsize=303676 CPUtime=289.62
/proc/16840/stat : 16840 (clasp) R 16822 16822 1745 0 -1 4202496 81740 0 0 0 28923 39 0 0 20 0 1 0 119417717 310964224 75580 18446744073709551615 4194304 6238623 140733537083984 140733537080536 4687693 0 0 16781316 18946 0 0 0 17 0 0 0 0 0 0
/proc/16840/statm: 75919 75580 264 500 0 75416 0
[pid=16841] ppid=16822 vsize=22040 CPUtime=0.02
/proc/16841/stat : 16841 (parse.py) S 16822 16822 1745 0 -1 4202496 1306 0 13 0 0 2 0 0 20 0 1 0 119417717 22568960 1128 18446744073709551615 4194304 6642060 140734923595440 140734923593800 140293693654816 0 0 16777220 20994 0 0 0 17 0 0 0 7 0 0
/proc/16841/statm: 5510 1128 508 598 0 596 0
Current children cumulated CPU time (s) 300.01
Current children cumulated vsize (KiB) 334928

Child status: 0
Real time (s): 303.266
CPU time (s): 300.095
CPU user time (s): 298.831
CPU system time (s): 1.26408
CPU usage (%): 98.9543
Max. virtual memory (cumulated for all children) (KiB): 456724

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 298.831
system time used= 1.26408
maximum resident set size= 396768
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 219345
page faults= 13
swaps= 0
block input operations= 43744
block output operations= 46784
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 89
involuntary context switches= 34406

runsolver used 0.832052 second user time and 1.46409 second system time

The end