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/slowlink/install/rand208.cudf.log.runsolver /home/competition/aspcud-full-1.7/aspcud-full /home/competition/data/install/rand208.cudf /tmp/misc2012/2012-09-02-22:42/full/aspcud-full-1.7/slowlink/install/rand208.cudf.result -sum(changed,installedsize),-count(removed),-notuptodate(solution),-count(changed) 

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: 0.85 0.95 0.99 2/64 19196
/proc/meminfo: memFree=439808/1022884 swapFree=0/0
[pid=19196] ppid=19195 vsize=9204 CPUtime=0
/proc/19196/stat : 19196 (aspcud-full) S 19195 19196 1745 0 -1 4202496 430 0 0 0 0 0 0 0 20 0 1 0 120045338 9424896 331 18446744073709551615 4194304 5129932 140736388315120 140736388312584 139671822886688 0 0 16781316 65536 0 0 0 17 0 0 0 0 0 0
/proc/19196/statm: 2301 331 272 229 0 61 0

[startup+0.177436 s]
/proc/loadavg: 0.85 0.95 0.99 2/64 19196
/proc/meminfo: memFree=439808/1022884 swapFree=0/0
[pid=19196] ppid=19195 vsize=9212 CPUtime=0.03
/proc/19196/stat : 19196 (aspcud-full) S 19195 19196 1745 0 -1 4202496 738 3613 0 0 0 0 3 0 20 0 1 0 120045338 9433088 364 18446744073709551615 4194304 5129932 140736388315120 140736388313776 139671822742622 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/19196/statm: 2303 364 303 229 0 63 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 9212

[startup+0.200307 s]
/proc/loadavg: 0.85 0.95 0.99 2/64 19196
/proc/meminfo: memFree=439808/1022884 swapFree=0/0
[pid=19196] ppid=19195 vsize=9212 CPUtime=0.03
/proc/19196/stat : 19196 (aspcud-full) S 19195 19196 1745 0 -1 4202496 738 3613 0 0 0 0 3 0 20 0 1 0 120045338 9433088 364 18446744073709551615 4194304 5129932 140736388315120 140736388313776 139671822742622 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/19196/statm: 2303 364 303 229 0 63 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 9212

[startup+0.300326 s]
/proc/loadavg: 0.85 0.95 0.99 2/64 19196
/proc/meminfo: memFree=439808/1022884 swapFree=0/0
[pid=19196] ppid=19195 vsize=9212 CPUtime=0.03
/proc/19196/stat : 19196 (aspcud-full) S 19195 19196 1745 0 -1 4202496 738 3613 0 0 0 0 3 0 20 0 1 0 120045338 9433088 364 18446744073709551615 4194304 5129932 140736388315120 140736388313776 139671822742622 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/19196/statm: 2303 364 303 229 0 63 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 9212

[startup+0.700215 s]
/proc/loadavg: 0.85 0.95 0.99 2/64 19196
/proc/meminfo: memFree=439808/1022884 swapFree=0/0
[pid=19196] ppid=19195 vsize=9212 CPUtime=0.03
/proc/19196/stat : 19196 (aspcud-full) S 19195 19196 1745 0 -1 4202496 738 3613 0 0 0 0 3 0 20 0 1 0 120045338 9433088 364 18446744073709551615 4194304 5129932 140736388315120 140736388313776 139671822742622 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/19196/statm: 2303 364 303 229 0 63 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 9212

[startup+1.50027 s]
/proc/loadavg: 0.85 0.95 0.99 2/66 19212
/proc/meminfo: memFree=401344/1022884 swapFree=0/0
[pid=19196] ppid=19195 vsize=9212 CPUtime=0.03
/proc/19196/stat : 19196 (aspcud-full) S 19195 19196 1745 0 -1 4202496 738 3613 0 0 0 0 3 0 20 0 1 0 120045338 9433088 364 18446744073709551615 4194304 5129932 140736388315120 140736388313776 139671822742622 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/19196/statm: 2303 364 303 229 0 63 0
[pid=19212] ppid=19196 vsize=50676 CPUtime=1.4
/proc/19212/stat : 19212 (cudf2lp) R 19196 19196 1745 0 -1 4202496 14580 0 0 0 134 6 0 0 20 0 1 0 120045340 51892224 11181 18446744073709551615 4194304 5690517 140735375210112 140735375207752 4293600 0 0 16781316 0 0 0 0 17 0 0 0 5 0 0
/proc/19212/statm: 12669 11181 160 366 0 12300 0
Current children cumulated CPU time (s) 1.43
Current children cumulated vsize (KiB) 59888

[startup+3.10026 s]
/proc/loadavg: 0.87 0.95 0.99 2/66 19212
/proc/meminfo: memFree=333640/1022884 swapFree=0/0
[pid=19196] ppid=19195 vsize=9212 CPUtime=0.03
/proc/19196/stat : 19196 (aspcud-full) S 19195 19196 1745 0 -1 4202496 738 3613 0 0 0 0 3 0 20 0 1 0 120045338 9433088 364 18446744073709551615 4194304 5129932 140736388315120 140736388313776 139671822742622 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/19196/statm: 2303 364 303 229 0 63 0
[pid=19212] ppid=19196 vsize=114760 CPUtime=2.98
/proc/19212/stat : 19212 (cudf2lp) R 19196 19196 1745 0 -1 4202496 39313 0 0 0 282 16 0 0 20 0 1 0 120045340 117514240 28356 18446744073709551615 4194304 5690517 140735375210112 140735375207992 4277018 0 0 16781316 0 0 0 0 17 0 0 0 6 0 0
/proc/19212/statm: 28690 28356 169 366 0 28321 0
Current children cumulated CPU time (s) 3.01
Current children cumulated vsize (KiB) 123972

[startup+6.30026 s]
/proc/loadavg: 0.87 0.95 0.99 2/66 19213
/proc/meminfo: memFree=262340/1022884 swapFree=0/0
[pid=19196] ppid=19195 vsize=9212 CPUtime=3.46
/proc/19196/stat : 19196 (aspcud-full) S 19195 19196 1745 0 -1 4202496 764 42934 0 0 0 0 324 22 20 0 1 0 120045338 9433088 364 18446744073709551615 4194304 5129932 140736388315120 140736388313776 139671822742622 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/19196/statm: 2303 364 303 229 0 63 0
[pid=19213] ppid=19196 vsize=230264 CPUtime=2.72
/proc/19213/stat : 19213 (gringo) R 19196 19196 1745 0 -1 4202496 57085 0 0 0 255 17 0 0 20 0 1 0 120045693 235790336 47805 18446744073709551615 4194304 6531320 140733295220832 140733295217112 4596840 0 0 16781316 16386 0 0 0 17 0 0 0 0 0 0
/proc/19213/statm: 57566 47805 283 571 0 56987 0
Current children cumulated CPU time (s) 6.18
Current children cumulated vsize (KiB) 239476

[startup+12.7004 s]
/proc/loadavg: 0.89 0.95 0.99 2/67 19215
/proc/meminfo: memFree=271508/1022884 swapFree=0/0
[pid=19196] ppid=19195 vsize=9212 CPUtime=8.53
/proc/19196/stat : 19196 (aspcud-full) S 19195 19196 1745 0 -1 4202496 806 153503 0 0 0 0 789 64 20 0 1 0 120045338 9433088 364 18446744073709551615 4194304 5129932 140736388315120 140736388313184 139671822742622 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/19196/statm: 2303 364 303 229 0 63 0
[pid=19214] ppid=19196 vsize=142768 CPUtime=3.92
/proc/19214/stat : 19214 (clasp) R 19196 19196 1745 0 -1 4202496 41658 0 1 0 379 13 0 0 20 0 1 0 120046208 146194432 35179 18446744073709551615 4194304 6238623 140734403485360 140734403482384 4669522 0 0 16781316 18946 0 0 0 17 0 0 0 1 0 0
/proc/19214/statm: 35692 35179 263 500 0 35189 0
[pid=19215] ppid=19196 vsize=22040 CPUtime=0.01
/proc/19215/stat : 19215 (parse.py) S 19196 19196 1745 0 -1 4202496 1319 0 0 0 1 0 0 0 20 0 1 0 120046208 22568960 1128 18446744073709551615 4194304 6642060 140733677625424 140733677623784 140114625586976 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/19215/statm: 5510 1128 508 598 0 596 0
Current children cumulated CPU time (s) 12.46
Current children cumulated vsize (KiB) 174020

[startup+25.5004 s]
/proc/loadavg: 0.90 0.95 0.99 2/67 19215
/proc/meminfo: memFree=270764/1022884 swapFree=0/0
[pid=19196] ppid=19195 vsize=9212 CPUtime=8.53
/proc/19196/stat : 19196 (aspcud-full) S 19195 19196 1745 0 -1 4202496 806 153503 0 0 0 0 789 64 20 0 1 0 120045338 9433088 364 18446744073709551615 4194304 5129932 140736388315120 140736388313184 139671822742622 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/19196/statm: 2303 364 303 229 0 63 0
[pid=19214] ppid=19196 vsize=142768 CPUtime=16.59
/proc/19214/stat : 19214 (clasp) R 19196 19196 1745 0 -1 4202496 41834 0 1 0 1646 13 0 0 20 0 1 0 120046208 146194432 35355 18446744073709551615 4194304 6238623 140734403485360 140734403482384 4421745 0 0 16781316 18946 0 0 0 17 0 0 0 1 0 0
/proc/19214/statm: 35692 35355 263 500 0 35189 0
[pid=19215] ppid=19196 vsize=22040 CPUtime=0.01
/proc/19215/stat : 19215 (parse.py) S 19196 19196 1745 0 -1 4202496 1319 0 0 0 1 0 0 0 20 0 1 0 120046208 22568960 1128 18446744073709551615 4194304 6642060 140733677625424 140733677623784 140114625586976 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/19215/statm: 5510 1128 508 598 0 596 0
Current children cumulated CPU time (s) 25.13
Current children cumulated vsize (KiB) 174020

[startup+51.1004 s]
/proc/loadavg: 0.93 0.95 0.99 2/67 19215
/proc/meminfo: memFree=270764/1022884 swapFree=0/0
[pid=19196] ppid=19195 vsize=9212 CPUtime=8.53
/proc/19196/stat : 19196 (aspcud-full) S 19195 19196 1745 0 -1 4202496 806 153503 0 0 0 0 789 64 20 0 1 0 120045338 9433088 364 18446744073709551615 4194304 5129932 140736388315120 140736388313184 139671822742622 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/19196/statm: 2303 364 303 229 0 63 0
[pid=19214] ppid=19196 vsize=142768 CPUtime=41.92
/proc/19214/stat : 19214 (clasp) R 19196 19196 1745 0 -1 4202496 41834 0 1 0 4179 13 0 0 20 0 1 0 120046208 146194432 35355 18446744073709551615 4194304 6238623 140734403485360 140734403482384 4687690 0 0 16781316 18946 0 0 0 17 0 0 0 1 0 0
/proc/19214/statm: 35692 35355 263 500 0 35189 0
[pid=19215] ppid=19196 vsize=22040 CPUtime=0.01
/proc/19215/stat : 19215 (parse.py) S 19196 19196 1745 0 -1 4202496 1319 0 0 0 1 0 0 0 20 0 1 0 120046208 22568960 1128 18446744073709551615 4194304 6642060 140733677625424 140733677623784 140114625586976 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/19215/statm: 5510 1128 508 598 0 596 0
Current children cumulated CPU time (s) 50.46
Current children cumulated vsize (KiB) 174020

[startup+102.3 s]
/proc/loadavg: 0.97 0.96 0.99 2/67 19215
/proc/meminfo: memFree=256132/1022884 swapFree=0/0
[pid=19196] ppid=19195 vsize=9212 CPUtime=8.53
/proc/19196/stat : 19196 (aspcud-full) S 19195 19196 1745 0 -1 4202496 806 153503 0 0 0 0 789 64 20 0 1 0 120045338 9433088 364 18446744073709551615 4194304 5129932 140736388315120 140736388313184 139671822742622 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/19196/statm: 2303 364 303 229 0 63 0
[pid=19214] ppid=19196 vsize=157164 CPUtime=92.6
/proc/19214/stat : 19214 (clasp) R 19196 19196 1745 0 -1 4202496 45456 0 1 0 9245 15 0 0 20 0 1 0 120046208 160935936 38977 18446744073709551615 4194304 6238623 140734403485360 140734403481912 4635539 0 0 16781316 18946 0 0 0 17 0 0 0 1 0 0
/proc/19214/statm: 39291 38977 263 500 0 38788 0
[pid=19215] ppid=19196 vsize=22040 CPUtime=0.01
/proc/19215/stat : 19215 (parse.py) S 19196 19196 1745 0 -1 4202496 1319 0 0 0 1 0 0 0 20 0 1 0 120046208 22568960 1128 18446744073709551615 4194304 6642060 140733677625424 140733677623784 140114625586976 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/19215/statm: 5510 1128 508 598 0 596 0
Current children cumulated CPU time (s) 101.14
Current children cumulated vsize (KiB) 188416

[startup+162.3 s]
/proc/loadavg: 0.99 0.96 0.99 2/67 19215
/proc/meminfo: memFree=245096/1022884 swapFree=0/0
[pid=19196] ppid=19195 vsize=9212 CPUtime=8.53
/proc/19196/stat : 19196 (aspcud-full) S 19195 19196 1745 0 -1 4202496 806 153503 0 0 0 0 789 64 20 0 1 0 120045338 9433088 364 18446744073709551615 4194304 5129932 140736388315120 140736388313184 139671822742622 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/19196/statm: 2303 364 303 229 0 63 0
[pid=19214] ppid=19196 vsize=168220 CPUtime=152.08
/proc/19214/stat : 19214 (clasp) R 19196 19196 1745 0 -1 4202496 48227 0 1 0 15192 16 0 0 20 0 1 0 120046208 172257280 41748 18446744073709551615 4194304 6238623 140734403485360 140734403482384 4425916 0 0 16781316 18946 0 0 0 17 0 0 0 1 0 0
/proc/19214/statm: 42055 41748 263 500 0 41552 0
[pid=19215] ppid=19196 vsize=22040 CPUtime=0.01
/proc/19215/stat : 19215 (parse.py) S 19196 19196 1745 0 -1 4202496 1319 0 0 0 1 0 0 0 20 0 1 0 120046208 22568960 1128 18446744073709551615 4194304 6642060 140733677625424 140733677623784 140114625586976 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/19215/statm: 5510 1128 508 598 0 596 0
Current children cumulated CPU time (s) 160.62
Current children cumulated vsize (KiB) 199472

[startup+222.304 s]
/proc/loadavg: 0.99 0.97 0.99 2/67 19215
/proc/meminfo: memFree=113656/1022884 swapFree=0/0
[pid=19196] ppid=19195 vsize=9212 CPUtime=8.53
/proc/19196/stat : 19196 (aspcud-full) S 19195 19196 1745 0 -1 4202496 806 153503 0 0 0 0 789 64 20 0 1 0 120045338 9433088 364 18446744073709551615 4194304 5129932 140736388315120 140736388313184 139671822742622 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/19196/statm: 2303 364 303 229 0 63 0
[pid=19214] ppid=19196 vsize=300796 CPUtime=211.63
/proc/19214/stat : 19214 (clasp) R 19196 19196 1745 0 -1 4202496 81065 0 1 0 21123 40 0 0 20 0 1 0 120046208 308015104 74586 18446744073709551615 4194304 6238623 140734403485360 140734403481912 4684948 0 0 16781316 18946 0 0 0 17 0 0 0 1 0 0
/proc/19214/statm: 75199 74586 263 500 0 74696 0
[pid=19215] ppid=19196 vsize=22040 CPUtime=0.01
/proc/19215/stat : 19215 (parse.py) S 19196 19196 1745 0 -1 4202496 1319 0 0 0 1 0 0 0 20 0 1 0 120046208 22568960 1128 18446744073709551615 4194304 6642060 140733677625424 140733677623784 140114625586976 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/19215/statm: 5510 1128 508 598 0 596 0
Current children cumulated CPU time (s) 220.17
Current children cumulated vsize (KiB) 332048

[startup+282.3 s]
/proc/loadavg: 0.99 0.97 0.99 2/67 19215
/proc/meminfo: memFree=96792/1022884 swapFree=0/0
[pid=19196] ppid=19195 vsize=9212 CPUtime=8.53
/proc/19196/stat : 19196 (aspcud-full) S 19195 19196 1745 0 -1 4202496 806 153503 0 0 0 0 789 64 20 0 1 0 120045338 9433088 364 18446744073709551615 4194304 5129932 140736388315120 140736388313184 139671822742622 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/19196/statm: 2303 364 303 229 0 63 0
[pid=19214] ppid=19196 vsize=318032 CPUtime=271.18
/proc/19214/stat : 19214 (clasp) R 19196 19196 1745 0 -1 4202496 85295 0 1 0 27076 42 0 0 20 0 1 0 120046208 325664768 78816 18446744073709551615 4194304 6238623 140734403485360 140734403482384 4407054 0 0 16781316 18946 0 0 0 17 0 0 0 1 0 0
/proc/19214/statm: 79508 78816 263 500 0 79005 0
[pid=19215] ppid=19196 vsize=22040 CPUtime=0.01
/proc/19215/stat : 19215 (parse.py) S 19196 19196 1745 0 -1 4202496 1319 0 0 0 1 0 0 0 20 0 1 0 120046208 22568960 1128 18446744073709551615 4194304 6642060 140733677625424 140733677623784 140114625586976 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/19215/statm: 5510 1128 508 598 0 596 0
Current children cumulated CPU time (s) 279.72
Current children cumulated vsize (KiB) 349284



Maximum CPU time exceeded: sending signal-name then SIGKILL

[startup+302.8 s]
/proc/loadavg: 0.99 0.97 0.99 2/67 19215
/proc/meminfo: memFree=96668/1022884 swapFree=0/0
[pid=19196] ppid=19195 vsize=9212 CPUtime=8.53
/proc/19196/stat : 19196 (aspcud-full) S 19195 19196 1745 0 -1 4202496 806 153503 0 0 0 0 789 64 20 0 1 0 120045338 9433088 364 18446744073709551615 4194304 5129932 140736388315120 140736388313184 139671822742622 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/19196/statm: 2303 364 303 229 0 63 0
[pid=19214] ppid=19196 vsize=318032 CPUtime=291.52
/proc/19214/stat : 19214 (clasp) R 19196 19196 1745 0 -1 4202496 85306 0 1 0 29110 42 0 0 20 0 1 0 120046208 325664768 78827 18446744073709551615 4194304 6238623 140734403485360 140734403482384 4677160 0 0 16781316 18946 0 0 0 17 0 0 0 1 0 0
/proc/19214/statm: 79508 78827 263 500 0 79005 0
[pid=19215] ppid=19196 vsize=22040 CPUtime=0.01
/proc/19215/stat : 19215 (parse.py) S 19196 19196 1745 0 -1 4202496 1319 0 0 0 1 0 0 0 20 0 1 0 120046208 22568960 1128 18446744073709551615 4194304 6642060 140733677625424 140733677623784 140114625586976 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/19215/statm: 5510 1128 508 598 0 596 0
Current children cumulated CPU time (s) 300.06
Current children cumulated vsize (KiB) 349284

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+302.8 s]
/proc/loadavg: 0.99 0.97 0.99 2/67 19215
/proc/meminfo: memFree=96668/1022884 swapFree=0/0
[pid=19196] ppid=19195 vsize=9212 CPUtime=8.53
/proc/19196/stat : 19196 (aspcud-full) S 19195 19196 1745 0 -1 4202496 806 153503 0 0 0 0 789 64 20 0 1 0 120045338 9433088 364 18446744073709551615 4194304 5129932 140736388315120 140736388313184 139671822742622 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/19196/statm: 2303 364 303 229 0 63 0
[pid=19214] ppid=19196 vsize=318032 CPUtime=291.52
/proc/19214/stat : 19214 (clasp) R 19196 19196 1745 0 -1 4202496 85306 0 1 0 29110 42 0 0 20 0 1 0 120046208 325664768 78827 18446744073709551615 4194304 6238623 140734403485360 140734403482384 4677160 0 0 16781316 18946 0 0 0 17 0 0 0 1 0 0
/proc/19214/statm: 79508 78827 263 500 0 79005 0
[pid=19215] ppid=19196 vsize=22040 CPUtime=0.01
/proc/19215/stat : 19215 (parse.py) S 19196 19196 1745 0 -1 4202496 1319 0 0 0 1 0 0 0 20 0 1 0 120046208 22568960 1128 18446744073709551615 4194304 6642060 140733677625424 140733677623784 140114625586976 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/19215/statm: 5510 1128 508 598 0 596 0
Current children cumulated CPU time (s) 300.06
Current children cumulated vsize (KiB) 349284

Child status: 0
Real time (s): 302.848
CPU time (s): 300.143
CPU user time (s): 299.027
CPU system time (s): 1.11607
CPU usage (%): 99.1067
Max. virtual memory (cumulated for all children) (KiB): 475248

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 299.027
system time used= 1.11607
maximum resident set size= 405140
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 241250
page faults= 1
swaps= 0
block input operations= 68536
block output operations= 51272
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 82
involuntary context switches= 34307

runsolver used 0.604037 second user time and 1.32808 second system time

The end