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/upgrade/difficult/rand491.cudf.log.runsolver /home/competition/aspcud-full-1.7/aspcud-full /home/competition/data/upgrade/difficult/rand491.cudf /tmp/misc2012/2012-09-02-22:42/full/aspcud-full-1.7/slowlink/upgrade/difficult/rand491.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

[startup+0 s]
/proc/loadavg: 0.87 0.94 0.96 2/59 20930
/proc/meminfo: memFree=443120/1022884 swapFree=0/0
[pid=20930] ppid=20929 vsize=3152 CPUtime=0
/proc/20930/stat : 20930 (runsolver) R 20929 1750 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 1 0 120456411 3227648 32 18446744073709551615 134512640 134586868 4288712560 4288710608 4151759920 0 0 16781316 24578 0 0 0 17 0 0 0 0 0 0
/proc/20930/statm: 788 32 0 19 0 73 0
Current StackSize limit: 8192 KiB


[startup+0.184658 s]
/proc/loadavg: 0.87 0.94 0.96 2/59 20930
/proc/meminfo: memFree=443120/1022884 swapFree=0/0
[pid=20930] ppid=20929 vsize=9212 CPUtime=0.02
/proc/20930/stat : 20930 (aspcud-full) S 20929 20930 1750 0 -1 4202496 733 3620 0 0 0 0 2 0 20 0 1 0 120456411 9433088 365 18446744073709551615 4194304 5129932 140736166428480 140736166427136 140067488330846 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/20930/statm: 2303 365 303 229 0 63 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 9212

[startup+0.200262 s]
/proc/loadavg: 0.87 0.94 0.96 2/59 20930
/proc/meminfo: memFree=443120/1022884 swapFree=0/0
[pid=20930] ppid=20929 vsize=9212 CPUtime=0.02
/proc/20930/stat : 20930 (aspcud-full) S 20929 20930 1750 0 -1 4202496 733 3620 0 0 0 0 2 0 20 0 1 0 120456411 9433088 365 18446744073709551615 4194304 5129932 140736166428480 140736166427136 140067488330846 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/20930/statm: 2303 365 303 229 0 63 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 9212

[startup+0.300241 s]
/proc/loadavg: 0.87 0.94 0.96 2/59 20930
/proc/meminfo: memFree=443120/1022884 swapFree=0/0
[pid=20930] ppid=20929 vsize=9212 CPUtime=0.02
/proc/20930/stat : 20930 (aspcud-full) S 20929 20930 1750 0 -1 4202496 733 3620 0 0 0 0 2 0 20 0 1 0 120456411 9433088 365 18446744073709551615 4194304 5129932 140736166428480 140736166427136 140067488330846 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/20930/statm: 2303 365 303 229 0 63 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 9212

[startup+0.700189 s]
/proc/loadavg: 0.87 0.94 0.96 2/59 20930
/proc/meminfo: memFree=443120/1022884 swapFree=0/0
[pid=20930] ppid=20929 vsize=9212 CPUtime=0.02
/proc/20930/stat : 20930 (aspcud-full) S 20929 20930 1750 0 -1 4202496 733 3620 0 0 0 0 2 0 20 0 1 0 120456411 9433088 365 18446744073709551615 4194304 5129932 140736166428480 140736166427136 140067488330846 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/20930/statm: 2303 365 303 229 0 63 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 9212

[startup+1.50024 s]
/proc/loadavg: 0.87 0.94 0.96 2/61 20946
/proc/meminfo: memFree=385188/1022884 swapFree=0/0
[pid=20930] ppid=20929 vsize=9212 CPUtime=0.02
/proc/20930/stat : 20930 (aspcud-full) S 20929 20930 1750 0 -1 4202496 733 3620 0 0 0 0 2 0 20 0 1 0 120456411 9433088 365 18446744073709551615 4194304 5129932 140736166428480 140736166427136 140067488330846 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/20930/statm: 2303 365 303 229 0 63 0
[pid=20946] ppid=20930 vsize=50676 CPUtime=1.43
/proc/20946/stat : 20946 (cudf2lp) R 20930 20930 1750 0 -1 4202496 15089 0 0 0 137 6 0 0 20 0 1 0 120456413 51892224 11691 18446744073709551615 4194304 5690517 140735593741056 140735593738696 4329480 0 0 16781316 0 0 0 0 17 0 0 0 2 0 0
/proc/20946/statm: 12669 11691 160 366 0 12300 0
Current children cumulated CPU time (s) 1.45
Current children cumulated vsize (KiB) 59888

[startup+3.10025 s]
/proc/loadavg: 0.87 0.94 0.96 2/61 20946
/proc/meminfo: memFree=332488/1022884 swapFree=0/0
[pid=20930] ppid=20929 vsize=9212 CPUtime=0.02
/proc/20930/stat : 20930 (aspcud-full) S 20929 20930 1750 0 -1 4202496 733 3620 0 0 0 0 2 0 20 0 1 0 120456411 9433088 365 18446744073709551615 4194304 5129932 140736166428480 140736166427136 140067488330846 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/20930/statm: 2303 365 303 229 0 63 0
[pid=20946] ppid=20930 vsize=114764 CPUtime=3.03
/proc/20946/stat : 20946 (cudf2lp) R 20930 20930 1750 0 -1 4202496 39320 0 0 0 287 16 0 0 20 0 1 0 120456413 117518336 28364 18446744073709551615 4194304 5690517 140735593741056 140735593738408 4999222 0 0 16781316 0 0 0 0 17 0 0 0 2 0 0
/proc/20946/statm: 28691 28364 174 366 0 28322 0
Current children cumulated CPU time (s) 3.05
Current children cumulated vsize (KiB) 123976

[startup+6.30027 s]
/proc/loadavg: 0.88 0.94 0.96 2/61 20947
/proc/meminfo: memFree=240604/1022884 swapFree=0/0
[pid=20930] ppid=20929 vsize=9212 CPUtime=3.28
/proc/20930/stat : 20930 (aspcud-full) S 20929 20930 1750 0 -1 4202496 757 42942 0 0 0 0 308 20 20 0 1 0 120456411 9433088 365 18446744073709551615 4194304 5129932 140736166428480 140736166427136 140067488330846 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/20930/statm: 2303 365 303 229 0 63 0
[pid=20947] ppid=20930 vsize=272224 CPUtime=2.95
/proc/20947/stat : 20947 (gringo) R 20930 20930 1750 0 -1 4202496 66619 0 0 0 275 20 0 0 20 0 1 0 120456743 278757376 57340 18446744073709551615 4194304 6531320 140735631356832 140735631353256 4596844 0 0 16781316 16386 0 0 0 17 0 0 0 0 0 0
/proc/20947/statm: 68056 57340 283 571 0 67477 0
Current children cumulated CPU time (s) 6.23
Current children cumulated vsize (KiB) 281436

[startup+12.7003 s]
/proc/loadavg: 0.89 0.94 0.96 2/62 20949
/proc/meminfo: memFree=275688/1022884 swapFree=0/0
[pid=20930] ppid=20929 vsize=9212 CPUtime=8.3
/proc/20930/stat : 20930 (aspcud-full) S 20929 20930 1750 0 -1 4202496 794 154473 0 0 0 0 770 60 20 0 1 0 120456411 9433088 365 18446744073709551615 4194304 5129932 140736166428480 140736166426544 140067488330846 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/20930/statm: 2303 365 303 229 0 63 0
[pid=20948] ppid=20930 vsize=143432 CPUtime=4.2
/proc/20948/stat : 20948 (clasp) R 20930 20930 1750 0 -1 4202496 41535 0 1 0 408 12 0 0 20 0 1 0 120457254 146874368 35351 18446744073709551615 4194304 6238623 140733334877792 140733334874816 4421838 0 0 16781316 18946 0 0 0 17 0 0 0 1 0 0
/proc/20948/statm: 35858 35351 263 500 0 35355 0
[pid=20949] ppid=20930 vsize=22040 CPUtime=0
/proc/20949/stat : 20949 (parse.py) S 20930 20930 1750 0 -1 4202496 1318 0 0 0 0 0 0 0 20 0 1 0 120457254 22568960 1128 18446744073709551615 4194304 6642060 140734490297968 140734490296328 140651949922080 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/20949/statm: 5510 1128 508 598 0 596 0
Current children cumulated CPU time (s) 12.5
Current children cumulated vsize (KiB) 174684

[startup+25.5003 s]
/proc/loadavg: 0.91 0.94 0.96 2/62 20949
/proc/meminfo: memFree=275688/1022884 swapFree=0/0
[pid=20930] ppid=20929 vsize=9212 CPUtime=8.3
/proc/20930/stat : 20930 (aspcud-full) S 20929 20930 1750 0 -1 4202496 794 154473 0 0 0 0 770 60 20 0 1 0 120456411 9433088 365 18446744073709551615 4194304 5129932 140736166428480 140736166426544 140067488330846 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/20930/statm: 2303 365 303 229 0 63 0
[pid=20948] ppid=20930 vsize=143432 CPUtime=16.91
/proc/20948/stat : 20948 (clasp) R 20930 20930 1750 0 -1 4202496 41535 0 1 0 1679 12 0 0 20 0 1 0 120457254 146874368 35351 18446744073709551615 4194304 6238623 140733334877792 140733334874816 4409898 0 0 16781316 18946 0 0 0 17 0 0 0 1 0 0
/proc/20948/statm: 35858 35351 263 500 0 35355 0
[pid=20949] ppid=20930 vsize=22040 CPUtime=0
/proc/20949/stat : 20949 (parse.py) S 20930 20930 1750 0 -1 4202496 1318 0 0 0 0 0 0 0 20 0 1 0 120457254 22568960 1128 18446744073709551615 4194304 6642060 140734490297968 140734490296328 140651949922080 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/20949/statm: 5510 1128 508 598 0 596 0
Current children cumulated CPU time (s) 25.21
Current children cumulated vsize (KiB) 174684

[startup+51.1003 s]
/proc/loadavg: 0.94 0.95 0.96 2/62 20949
/proc/meminfo: memFree=275688/1022884 swapFree=0/0
[pid=20930] ppid=20929 vsize=9212 CPUtime=8.3
/proc/20930/stat : 20930 (aspcud-full) S 20929 20930 1750 0 -1 4202496 794 154473 0 0 0 0 770 60 20 0 1 0 120456411 9433088 365 18446744073709551615 4194304 5129932 140736166428480 140736166426544 140067488330846 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/20930/statm: 2303 365 303 229 0 63 0
[pid=20948] ppid=20930 vsize=143432 CPUtime=42.31
/proc/20948/stat : 20948 (clasp) R 20930 20930 1750 0 -1 4202496 41535 0 1 0 4219 12 0 0 20 0 1 0 120457254 146874368 35351 18446744073709551615 4194304 6238623 140733334877792 140733334874816 4407044 0 0 16781316 18946 0 0 0 17 0 0 0 1 0 0
/proc/20948/statm: 35858 35351 263 500 0 35355 0
[pid=20949] ppid=20930 vsize=22040 CPUtime=0
/proc/20949/stat : 20949 (parse.py) S 20930 20930 1750 0 -1 4202496 1318 0 0 0 0 0 0 0 20 0 1 0 120457254 22568960 1128 18446744073709551615 4194304 6642060 140734490297968 140734490296328 140651949922080 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/20949/statm: 5510 1128 508 598 0 596 0
Current children cumulated CPU time (s) 50.61
Current children cumulated vsize (KiB) 174684

[startup+102.3 s]
/proc/loadavg: 1.01 0.97 0.97 2/62 20949
/proc/meminfo: memFree=275192/1022884 swapFree=0/0
[pid=20930] ppid=20929 vsize=9212 CPUtime=8.3
/proc/20930/stat : 20930 (aspcud-full) S 20929 20930 1750 0 -1 4202496 794 154473 0 0 0 0 770 60 20 0 1 0 120456411 9433088 365 18446744073709551615 4194304 5129932 140736166428480 140736166426544 140067488330846 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/20930/statm: 2303 365 303 229 0 63 0
[pid=20948] ppid=20930 vsize=143432 CPUtime=93.14
/proc/20948/stat : 20948 (clasp) R 20930 20930 1750 0 -1 4202496 41628 0 1 0 9300 14 0 0 20 0 1 0 120457254 146874368 35444 18446744073709551615 4194304 6238623 140733334877792 140733334874816 4421792 0 0 16781316 18946 0 0 0 17 0 0 0 1 0 0
/proc/20948/statm: 35858 35444 263 500 0 35355 0
[pid=20949] ppid=20930 vsize=22040 CPUtime=0
/proc/20949/stat : 20949 (parse.py) S 20930 20930 1750 0 -1 4202496 1318 0 0 0 0 0 0 0 20 0 1 0 120457254 22568960 1128 18446744073709551615 4194304 6642060 140734490297968 140734490296328 140651949922080 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/20949/statm: 5510 1128 508 598 0 596 0
Current children cumulated CPU time (s) 101.44
Current children cumulated vsize (KiB) 174684

[startup+162.3 s]
/proc/loadavg: 1.00 0.97 0.97 2/62 20949
/proc/meminfo: memFree=212200/1022884 swapFree=0/0
[pid=20930] ppid=20929 vsize=9212 CPUtime=8.3
/proc/20930/stat : 20930 (aspcud-full) S 20929 20930 1750 0 -1 4202496 794 154473 0 0 0 0 770 60 20 0 1 0 120456411 9433088 365 18446744073709551615 4194304 5129932 140736166428480 140736166426544 140067488330846 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/20930/statm: 2303 365 303 229 0 63 0
[pid=20948] ppid=20930 vsize=206148 CPUtime=152.69
/proc/20948/stat : 20948 (clasp) R 20930 20930 1750 0 -1 4202496 57360 0 1 0 15246 23 0 0 20 0 1 0 120457254 211095552 51176 18446744073709551615 4194304 6238623 140733334877792 140733334874816 4687972 0 0 16781316 18946 0 0 0 17 0 0 0 1 0 0
/proc/20948/statm: 51537 51176 263 500 0 51034 0
[pid=20949] ppid=20930 vsize=22040 CPUtime=0
/proc/20949/stat : 20949 (parse.py) S 20930 20930 1750 0 -1 4202496 1318 0 0 0 0 0 0 0 20 0 1 0 120457254 22568960 1128 18446744073709551615 4194304 6642060 140734490297968 140734490296328 140651949922080 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/20949/statm: 5510 1128 508 598 0 596 0
Current children cumulated CPU time (s) 160.99
Current children cumulated vsize (KiB) 237400

[startup+222.303 s]
/proc/loadavg: 1.00 0.97 0.97 2/62 20949
/proc/meminfo: memFree=212200/1022884 swapFree=0/0
[pid=20930] ppid=20929 vsize=9212 CPUtime=8.3
/proc/20930/stat : 20930 (aspcud-full) S 20929 20930 1750 0 -1 4202496 794 154473 0 0 0 0 770 60 20 0 1 0 120456411 9433088 365 18446744073709551615 4194304 5129932 140736166428480 140736166426544 140067488330846 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/20930/statm: 2303 365 303 229 0 63 0
[pid=20948] ppid=20930 vsize=206148 CPUtime=212.24
/proc/20948/stat : 20948 (clasp) R 20930 20930 1750 0 -1 4202496 57362 0 1 0 21201 23 0 0 20 0 1 0 120457254 211095552 51178 18446744073709551615 4194304 6238623 140733334877792 140733334874816 4676718 0 0 16781316 18946 0 0 0 17 0 0 0 1 0 0
/proc/20948/statm: 51537 51178 263 500 0 51034 0
[pid=20949] ppid=20930 vsize=22040 CPUtime=0
/proc/20949/stat : 20949 (parse.py) S 20930 20930 1750 0 -1 4202496 1318 0 0 0 0 0 0 0 20 0 1 0 120457254 22568960 1128 18446744073709551615 4194304 6642060 140734490297968 140734490296328 140651949922080 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/20949/statm: 5510 1128 508 598 0 596 0
Current children cumulated CPU time (s) 220.54
Current children cumulated vsize (KiB) 237400

[startup+282.3 s]
/proc/loadavg: 1.00 0.97 0.97 2/62 20949
/proc/meminfo: memFree=194220/1022884 swapFree=0/0
[pid=20930] ppid=20929 vsize=9212 CPUtime=8.3
/proc/20930/stat : 20930 (aspcud-full) S 20929 20930 1750 0 -1 4202496 794 154473 0 0 0 0 770 60 20 0 1 0 120456411 9433088 365 18446744073709551615 4194304 5129932 140736166428480 140736166426544 140067488330846 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/20930/statm: 2303 365 303 229 0 63 0
[pid=20948] ppid=20930 vsize=224112 CPUtime=271.78
/proc/20948/stat : 20948 (clasp) R 20930 20930 1750 0 -1 4202496 61873 0 1 0 27154 24 0 0 20 0 1 0 120457254 229490688 55689 18446744073709551615 4194304 6238623 140733334877792 140733334874816 4663111 0 0 16781316 18946 0 0 0 17 0 0 0 1 0 0
/proc/20948/statm: 56028 55689 263 500 0 55525 0
[pid=20949] ppid=20930 vsize=22040 CPUtime=0
/proc/20949/stat : 20949 (parse.py) S 20930 20930 1750 0 -1 4202496 1318 0 0 0 0 0 0 0 20 0 1 0 120457254 22568960 1128 18446744073709551615 4194304 6642060 140734490297968 140734490296328 140651949922080 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/20949/statm: 5510 1128 508 598 0 596 0
Current children cumulated CPU time (s) 280.08
Current children cumulated vsize (KiB) 255364



Maximum CPU time exceeded: sending signal-name then SIGKILL

[startup+302.4 s]
/proc/loadavg: 1.00 0.97 0.97 2/62 20949
/proc/meminfo: memFree=194220/1022884 swapFree=0/0
[pid=20930] ppid=20929 vsize=9212 CPUtime=8.3
/proc/20930/stat : 20930 (aspcud-full) S 20929 20930 1750 0 -1 4202496 794 154473 0 0 0 0 770 60 20 0 1 0 120456411 9433088 365 18446744073709551615 4194304 5129932 140736166428480 140736166426544 140067488330846 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/20930/statm: 2303 365 303 229 0 63 0
[pid=20948] ppid=20930 vsize=224112 CPUtime=291.74
/proc/20948/stat : 20948 (clasp) R 20930 20930 1750 0 -1 4202496 61873 0 1 0 29150 24 0 0 20 0 1 0 120457254 229490688 55689 18446744073709551615 4194304 6238623 140733334877792 140733334874816 4321256 0 0 16781316 18946 0 0 0 17 0 0 0 1 0 0
/proc/20948/statm: 56028 55689 263 500 0 55525 0
[pid=20949] ppid=20930 vsize=22040 CPUtime=0
/proc/20949/stat : 20949 (parse.py) S 20930 20930 1750 0 -1 4202496 1318 0 0 0 0 0 0 0 20 0 1 0 120457254 22568960 1128 18446744073709551615 4194304 6642060 140734490297968 140734490296328 140651949922080 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/20949/statm: 5510 1128 508 598 0 596 0
Current children cumulated CPU time (s) 300.04
Current children cumulated vsize (KiB) 255364

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.4 s]
/proc/loadavg: 1.00 0.97 0.97 2/62 20949
/proc/meminfo: memFree=194220/1022884 swapFree=0/0
[pid=20930] ppid=20929 vsize=9212 CPUtime=8.3
/proc/20930/stat : 20930 (aspcud-full) S 20929 20930 1750 0 -1 4202496 794 154473 0 0 0 0 770 60 20 0 1 0 120456411 9433088 365 18446744073709551615 4194304 5129932 140736166428480 140736166426544 140067488330846 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/20930/statm: 2303 365 303 229 0 63 0
[pid=20948] ppid=20930 vsize=224112 CPUtime=291.74
/proc/20948/stat : 20948 (clasp) R 20930 20930 1750 0 -1 4202496 61873 0 1 0 29150 24 0 0 20 0 1 0 120457254 229490688 55689 18446744073709551615 4194304 6238623 140733334877792 140733334874816 4321256 0 0 16781316 18946 0 0 0 17 0 0 0 1 0 0
/proc/20948/statm: 56028 55689 263 500 0 55525 0
[pid=20949] ppid=20930 vsize=22040 CPUtime=0
/proc/20949/stat : 20949 (parse.py) S 20930 20930 1750 0 -1 4202496 1318 0 0 0 0 0 0 0 20 0 1 0 120457254 22568960 1128 18446744073709551615 4194304 6642060 140734490297968 140734490296328 140651949922080 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/20949/statm: 5510 1128 508 598 0 596 0
Current children cumulated CPU time (s) 300.04
Current children cumulated vsize (KiB) 255364

Child status: 0
Real time (s): 302.439
CPU time (s): 300.119
CPU user time (s): 299.235
CPU system time (s): 0.884055
CPU usage (%): 99.2329
Max. virtual memory (cumulated for all children) (KiB): 478164

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 299.235
system time used= 0.884055
maximum resident set size= 408992
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 218772
page faults= 1
swaps= 0
block input operations= 68544
block output operations= 51480
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 77
involuntary context switches= 34266

runsolver used 0.472029 second user time and 1.13207 second system time

The end