refal-5-lambda icon indicating copy to clipboard operation
refal-5-lambda copied to clipboard

Published 20 hours ago • verified publisher icon bmstu-iu9

Анализ и оптимизация производительности Рефала-5λ

Open Mazdaywik opened this issue 6 years ago • 7 comments

Эта задача — подзадача для #185.

Выяснилось, что компилятор Рефала-05, собранный Рефалом-5λ, в три раза медленнее компилятора, собранного самим собой, и компилятора, собранного refc. И это не смотря на максимально доступные оптимизации (-OdPRC).

То, что обгоняет refgo, можно объяснить более оптимальным форматом языка сборки. Команды сопоставления функциональны, они не изменяют значения уже присвоенных ячеек стека, а инициализируют новые. В то время как в Рефале-5λ при каждом сопоставлении изменяется содержимое ячейки-диапазона.

Но при этом Рефал-05 вообще не содержит никаких оптимизаций и его идеология языка сборки совпадает с идеологией в Рефале-5λ.

Можно предположить следующие причины:

  • В коде Рефала-5λ слишком много слоёв абстракций и используемый BCC 5.5 не может всё заинлайнить. Соответственно, нужно упрощать вручную. В частности, для функций и идентификаторов их указатель получается вызовом vm->ref(descr).

  • В Рефале-05 очень дешёвая функция Mu (в силу особенностей языка) и она активно используется. Например, в кодогенераторе инструкции формируются путём косвенного вызова их тегов в цикле. И, возможно, за счёт дешевизны Mu Рефал-05 обгоняет refc+refgo.

  • Встроенные функции реализованы на Рефале, при этом для каждой из них корректируется виртуальный счётчик шагов функциями <__Step-Start> и <__Step-End>

  • Используется неоптимальное построение результатных выражений, а именно, без учёта последовательного распределения строящихся элементов и с проверками успешности команд аллокации.

    В Рефале-5λ Mu не оптимизирована. Мало того, что она написана на Рефале с условиями и несколькими вспомогательными функциями, так ещё и сам поиск имени достаточно тяжеловесен.

Что нужно сделать:

  • [ ] Замерить время без использования функции Mu — конвертировать программу на Рефале-05 в Рефал-5λ, заменив все идентификаторы Func на указатели &Func и вызовы <Mu s.F …> на непосредственный вызов <s.F …>. Для этого можно написать препроцессор на Рефале-05, тем более что Рефал-05 декларируется как язык для написания таких инструментальных средств.

    В результате получится программа, семантически идентичная Рефалу-05, а значит, сравнение будет честнее.

  • [ ] Попробовать исключить лишние слои абстракций.

  • [ ] Посчитать количество, и, возможно, время выполнения вызовов каждой из функций программы для Рефала-05 и Рефала-5 и сделать выводы. Такие замеры уже делались (d6255fb10cf14418403ef9ff0a361bf9c8987111, 674963791fab8b6312b09186eeac03b2bc27ea23).

  • [ ] Оптимизировать построение результатных выражений (#196).

  • [ ] Пересмотреть и оптимизировать язык сборки, сделав команды сопоставления функциональными (#204).

Mazdaywik avatar Feb 27 '19 06:02 Mazdaywik

Замеры производительности

Запуск crefal (компиляция MRefal.r5.ref)

Начиная с версии 2.2.6 Рефал-5λ умеет декодировать и компилировать .rsl-файлы. А это значит, что можно сравнить производительность.

Замеры в консоли 
D:\Mazdaywik\Documents\Refal-5-lambda\build>refgo -a crefal MRefal.r5.ref
Copyright (C): RefalScope Project, 2004-2018
Refal-5 System. Version PZ Oct 29 2004
*** The View Field:
<STOP$ <Exit 0 >>

*** Number of Steps = 4640529
Elapsed system time: 13.486 seconds
*** Buried:

((Warnings '=' 0 )(Errors '=' 0 )(Mode '=' crefal )(Testing '=' False )
 (Output '=MRefal.r5.rsl'
 )(Input '=MRefal.r5.ref' )
)
Memory allocated =  10412032 Bytes

D:\Mazdaywik\Documents\Refal-5-lambda\build>srefc crefal.rsl
Srefc, a part of Refal-5-lambda compiler toolkit, version 2.2.6.1
Copyright (c) 2008-2016, Alexander Konovalov, 2016-2019, BMSTU IU9 Department
All rights reserved.

*Compiling crefal.rsl:
Decompiled "crefal.rsl" to "crefal-decompiled.ref"
** Compilation completed successfully **

D:\Mazdaywik\Documents\Refal-5-lambda\build>crefal.exe MRefal.r5.ref
Copyright (C): RefalScope Project, 2004-2018

Total program time: 44.953 seconds (100.0 %).
(Total refal time): 43.266 seconds (96.2 %).
t- and e-var copy time: 32.068 seconds (71.3 %).
Linear result time: 5.736 seconds (12.8 %).
Open e-loop time (clear): 2.950 seconds (6.6 %).
Linear pattern time: 2.123 seconds (4.7 %).
Native time: 1.142 seconds (2.5 %).
Runtime time overhead: 0.545 seconds (1.2 %).
Repeated t-var match time (inside e-loops): 0.389 seconds (0.9 %).
Step count 9159285
Memory used 650513 nodes, 650513 * 16 = 10408208 bytes

И без усреднения по N замерам очевидно, что Рефал-5λ работает в 3 раза медленнее.

Попробуем с оптимизациями.

Замеры в консоли 
D:\Mazdaywik\Documents\Refal-5-lambda\build>set CPPLINEE=bcc32 -w -e

D:\Mazdaywik\Documents\Refal-5-lambda\build>srmake --scratch -X-OdPRC crefal.rsl --runtime=refalrts-diagnostic-initializer
SRMake, a part of Refal-5-lambda compiler toolkit, version 2.2.6.1
Copyright (c) 2008-2016, Alexander Konovalov, 2016-2019, BMSTU IU9 Department
All rights reserved.

Srefc, a part of Refal-5-lambda compiler toolkit, version 2.2.6.1
Copyright (c) 2008-2016, Alexander Konovalov, 2016-2019, BMSTU IU9 Department
All rights reserved.

*Compiling crefal.rsl:
Decompiled "crefal.rsl" to "crefal-decompiled.ref"
   ... natives generated
+Linking (+ natives) C:\Users\Mazdaywik\AppData\Roaming\Refal-5-lambda\srlib\scratch/Library.rasl
+Linking (+ natives) C:\Users\Mazdaywik\AppData\Roaming\Refal-5-lambda\srlib\scratch/refalrts-main.rasl
+Linking (+ natives) C:\Users\Mazdaywik\AppData\Roaming\Refal-5-lambda\srlib\scratch/refalrts.rasl
+Linking (+ natives) C:\Users\Mazdaywik\AppData\Roaming\Refal-5-lambda\srlib\scratch/refalrts-allocator.rasl
+Linking (+ natives) C:\Users\Mazdaywik\AppData\Roaming\Refal-5-lambda\srlib\scratch/refalrts-functions.rasl
+Linking (+ natives) C:\Users\Mazdaywik\AppData\Roaming\Refal-5-lambda\srlib\scratch/refalrts-dynamic.rasl
+Linking (+ natives) C:\Users\Mazdaywik\AppData\Roaming\Refal-5-lambda\srlib\scratch\platform-Windows/refalrts-platform-specific.rasl
+Linking (+ natives) C:\Users\Mazdaywik\AppData\Roaming\Refal-5-lambda\srlib\scratch/refalrts-vm.rasl
+Linking (+ natives) C:\Users\Mazdaywik\AppData\Roaming\Refal-5-lambda\srlib\scratch/refalrts-profiler.rasl
+Linking (+ natives) C:\Users\Mazdaywik\AppData\Roaming\Refal-5-lambda\srlib\scratch/refalrts-diagnostic-initializer.rasl
+Linking (+ natives) C:\Users\Mazdaywik\AppData\Roaming\Refal-5-lambda\srlib\scratch/refalrts-debugger.rasl
Borland C++ 5.5.1 for Win32 Copyright (c) 1993, 2000 Borland
crefal.cpp:
c:\users\mazdaywik\appdata\roaming\refal-5-lambda\srlib\scratch/library.cpp:
c:\users\mazdaywik\appdata\roaming\refal-5-lambda\srlib\scratch/refalrts-main.cpp:
c:\users\mazdaywik\appdata\roaming\refal-5-lambda\srlib\scratch/refalrts.cpp:
c:\users\mazdaywik\appdata\roaming\refal-5-lambda\srlib\scratch/refalrts-allocator.cpp:
c:\users\mazdaywik\appdata\roaming\refal-5-lambda\srlib\scratch/refalrts-functions.cpp:
c:\users\mazdaywik\appdata\roaming\refal-5-lambda\srlib\scratch/refalrts-dynamic.cpp:
c:\users\mazdaywik\appdata\roaming\refal-5-lambda\srlib\scratch\platform-windows/refalrts-platform-specific.cpp:
c:\users\mazdaywik\appdata\roaming\refal-5-lambda\srlib\scratch/refalrts-vm.cpp:
c:\users\mazdaywik\appdata\roaming\refal-5-lambda\srlib\scratch/refalrts-profiler.cpp:
c:\users\mazdaywik\appdata\roaming\refal-5-lambda\srlib\scratch/refalrts-diagnostic-initializer.cpp:
c:\users\mazdaywik\appdata\roaming\refal-5-lambda\srlib\scratch/refalrts-debugger.cpp:
Turbo Incremental Link 5.00 Copyright (c) 1997, 2000 Borland
** Compilation completed successfully **

D:\Mazdaywik\Documents\Refal-5-lambda\build>crefal.exe MRefal.r5.ref
Copyright (C): RefalScope Project, 2004-2018

Total program time: 38.703 seconds (100.0 %).
(Total refal time): 37.008 seconds (95.6 %).
t- and e-var copy time: 30.571 seconds (79.0 %).
Linear result time: 2.634 seconds (6.8 %).
Open e-loop time (clear): 2.277 seconds (5.9 %).
Native time: 1.002 seconds (2.6 %).
Linear pattern time: 0.998 seconds (2.6 %).
Runtime time overhead: 0.693 seconds (1.8 %).
Repeated t-var match time (inside e-loops): 0.496 seconds (1.3 %).
Repeated e-var match time (inside e-loops): 0.032 seconds (0.1 %).
Step count 9159285
Memory used 650510 nodes, 650510 * 16 = 10408160 bytes

Разницы немного. В обоих случаях ≈30 секунд времени уходит на копирование переменных.

Рассмотрим другой тест.

Запуск crefal (компиляция себя)

Замеры в консоли 
D:\Mazdaywik\Documents\Refal-5-lambda\build>rsl-decompiler.exe crefal.rsl
Decompiled "crefal.rsl" to "crefal-decompiled.ref"

D:\Mazdaywik\Documents\Refal-5-lambda\build>refgo -a crefal crefal-decompiled.ref
Copyright (C): RefalScope Project, 2004-2018
Refal-5 System. Version PZ Oct 29 2004
*** The View Field:
<STOP$ <Exit 0 >>

*** Number of Steps = 1397550
Elapsed system time: 1.075 seconds
*** Buried:

((Warnings '=' 0 )(Errors '=' 0 )(Mode '=' crefal )(Testing '=' False )
 (Output '=crefal-decompiled.rsl'
 )(Input '=crefal-decompiled.ref' )
)
Memory allocated =   2686976 Bytes

D:\Mazdaywik\Documents\Refal-5-lambda\build>srefc crefal.rsl
Srefc, a part of Refal-5-lambda compiler toolkit, version 2.2.6.1
Copyright (c) 2008-2016, Alexander Konovalov, 2016-2019, BMSTU IU9 Department
All rights reserved.

*Compiling crefal.rsl:
Decompiled "crefal.rsl" to "crefal-decompiled.ref"
** Compilation completed successfully **

D:\Mazdaywik\Documents\Refal-5-lambda\build>rsl-decompiler.exe crefal.rsl
Decompiled "crefal.rsl" to "crefal-decompiled.ref"

D:\Mazdaywik\Documents\Refal-5-lambda\build>crefal.exe crefal-decompiled.ref
Copyright (C): RefalScope Project, 2004-2018

Total program time: 4.015 seconds (100.0 %).
(Total refal time): 3.450 seconds (85.9 %).
Linear result time: 1.346 seconds (33.5 %).
t- and e-var copy time: 1.173 seconds (29.2 %).
Linear pattern time: 0.572 seconds (14.2 %).
Open e-loop time (clear): 0.328 seconds (8.2 %).
Native time: 0.328 seconds (8.2 %).
Runtime time overhead: 0.237 seconds (5.9 %).
Repeated e-var match time (inside e-loops): 0.016 seconds (0.4 %).
Repeated t-var match time (inside e-loops): 0.015 seconds (0.4 %).
Step count 2894003
Memory used 167827 nodes, 167827 * 16 = 2685232 bytes

D:\Mazdaywik\Documents\Refal-5-lambda\build>srmake --scratch -X-OdPRC crefal.rsl --runtime=refalrts-diagnostic-initializer
SRMake, a part of Refal-5-lambda compiler toolkit, version 2.2.6.1
Copyright (c) 2008-2016, Alexander Konovalov, 2016-2019, BMSTU IU9 Department
All rights reserved.

Srefc, a part of Refal-5-lambda compiler toolkit, version 2.2.6.1
Copyright (c) 2008-2016, Alexander Konovalov, 2016-2019, BMSTU IU9 Department
All rights reserved.

*Compiling crefal.rsl:
Decompiled "crefal.rsl" to "crefal-decompiled.ref"
   ... natives generated
+Linking (+ natives) C:\Users\Mazdaywik\AppData\Roaming\Refal-5-lambda\srlib\scratch/Library.rasl
+Linking (+ natives) C:\Users\Mazdaywik\AppData\Roaming\Refal-5-lambda\srlib\scratch/refalrts-main.rasl
+Linking (+ natives) C:\Users\Mazdaywik\AppData\Roaming\Refal-5-lambda\srlib\scratch/refalrts.rasl
+Linking (+ natives) C:\Users\Mazdaywik\AppData\Roaming\Refal-5-lambda\srlib\scratch/refalrts-allocator.rasl
+Linking (+ natives) C:\Users\Mazdaywik\AppData\Roaming\Refal-5-lambda\srlib\scratch/refalrts-functions.rasl
+Linking (+ natives) C:\Users\Mazdaywik\AppData\Roaming\Refal-5-lambda\srlib\scratch/refalrts-dynamic.rasl
+Linking (+ natives) C:\Users\Mazdaywik\AppData\Roaming\Refal-5-lambda\srlib\scratch\platform-Windows/refalrts-platform-specific.rasl
+Linking (+ natives) C:\Users\Mazdaywik\AppData\Roaming\Refal-5-lambda\srlib\scratch/refalrts-vm.rasl
+Linking (+ natives) C:\Users\Mazdaywik\AppData\Roaming\Refal-5-lambda\srlib\scratch/refalrts-profiler.rasl
+Linking (+ natives) C:\Users\Mazdaywik\AppData\Roaming\Refal-5-lambda\srlib\scratch/refalrts-diagnostic-initializer.rasl
+Linking (+ natives) C:\Users\Mazdaywik\AppData\Roaming\Refal-5-lambda\srlib\scratch/refalrts-debugger.rasl
Borland C++ 5.5.1 for Win32 Copyright (c) 1993, 2000 Borland
crefal.cpp:
c:\users\mazdaywik\appdata\roaming\refal-5-lambda\srlib\scratch/library.cpp:
c:\users\mazdaywik\appdata\roaming\refal-5-lambda\srlib\scratch/refalrts-main.cpp:
c:\users\mazdaywik\appdata\roaming\refal-5-lambda\srlib\scratch/refalrts.cpp:
c:\users\mazdaywik\appdata\roaming\refal-5-lambda\srlib\scratch/refalrts-allocator.cpp:
c:\users\mazdaywik\appdata\roaming\refal-5-lambda\srlib\scratch/refalrts-functions.cpp:
c:\users\mazdaywik\appdata\roaming\refal-5-lambda\srlib\scratch/refalrts-dynamic.cpp:
c:\users\mazdaywik\appdata\roaming\refal-5-lambda\srlib\scratch\platform-windows/refalrts-platform-specific.cpp:
c:\users\mazdaywik\appdata\roaming\refal-5-lambda\srlib\scratch/refalrts-vm.cpp:
c:\users\mazdaywik\appdata\roaming\refal-5-lambda\srlib\scratch/refalrts-profiler.cpp:
c:\users\mazdaywik\appdata\roaming\refal-5-lambda\srlib\scratch/refalrts-diagnostic-initializer.cpp:
c:\users\mazdaywik\appdata\roaming\refal-5-lambda\srlib\scratch/refalrts-debugger.cpp:
Turbo Incremental Link 5.00 Copyright (c) 1997, 2000 Borland
** Compilation completed successfully **

D:\Mazdaywik\Documents\Refal-5-lambda\build>rsl-decompiler.exe crefal.rsl
Decompiled "crefal.rsl" to "crefal-decompiled.ref"

D:\Mazdaywik\Documents\Refal-5-lambda\build>crefal.exe crefal-decompiled.ref
Copyright (C): RefalScope Project, 2004-2018

Total program time: 2.828 seconds (100.0 %).
(Total refal time): 2.284 seconds (80.8 %).
t- and e-var copy time: 0.985 seconds (34.8 %).
Linear result time: 0.794 seconds (28.1 %).
Runtime time overhead: 0.279 seconds (9.9 %).
Native time: 0.265 seconds (9.4 %).
Linear pattern time: 0.253 seconds (8.9 %).
Open e-loop time (clear): 0.236 seconds (8.3 %).
Repeated t-var match time (inside e-loops): 0.016 seconds (0.6 %).
Step count 2894003
Memory used 167824 nodes, 167824 * 16 = 2685184 bytes

Другая программа, другой стиль её написания. Компиляция без оптимизаций выполняется в 4 раза медленнее, с оптимизациями — только в 3 раза.

Тест TimeElapsed.OK.ref

Тест скопирован из каталога тестов совместимости.

Замеры в консоли 
D:\Mazdaywik\Documents\Refal-5-lambda\build>refgo crefal TimeElapsed.OK.ref
Copyright (C): RefalScope Project, 2004-2018

D:\Mazdaywik\Documents\Refal-5-lambda\build>refgo -a TimeElapsed.OK.rsl && type REFAL7.DAT
Refal-5 System. Version PZ Oct 29 2004
*** The View Field:
<STOP$ >

*** Number of Steps = 128
Elapsed system time: 2.614 seconds
*** Buried:
()

Memory allocated =      8192 Bytes

Time elapsed 0.000
Time elapsed 0.552
Time elapsed 1.192
Time elapsed 0.672
Time elapsed 1.422

D:\Mazdaywik\Documents\Refal-5-lambda\build>srefc TimeElapsed.OK.ref
Srefc, a part of Refal-5-lambda compiler toolkit, version 2.2.6.1
Copyright (c) 2008-2016, Alexander Konovalov, 2016-2019, BMSTU IU9 Department
All rights reserved.

*Compiling TimeElapsed.OK.ref:
** Compilation completed successfully **

D:\Mazdaywik\Documents\Refal-5-lambda\build>TimeElapsed.OK.exe && type REFAL7.DAT

Total program time: 4.485 seconds (100.0 %).
Open e-loop time (clear): 4.469 seconds (99.6 %).
(Total refal time): 4.469 seconds (99.6 %).
Native time: 0.016 seconds (0.4 %).
Identifiers allocated: 88
Step count 203
Memory used 151 nodes, 151 * 16 = 2416 bytes
Time elapsed 0.000000
Time elapsed 1.125000
Time elapsed 2.219000
Time elapsed 1.140000
Time elapsed 2.250000

D:\Mazdaywik\Documents\Refal-5-lambda\build>srmake --scratch -X-OdPRC TimeElapsed.OK.ref --runtime=refalrts-diagnostic-initializer
SRMake, a part of Refal-5-lambda compiler toolkit, version 2.2.6.1
Copyright (c) 2008-2016, Alexander Konovalov, 2016-2019, BMSTU IU9 Department
All rights reserved.

Srefc, a part of Refal-5-lambda compiler toolkit, version 2.2.6.1
Copyright (c) 2008-2016, Alexander Konovalov, 2016-2019, BMSTU IU9 Department
All rights reserved.

*Compiling TimeElapsed.OK.ref:
   ... natives generated
+Linking (+ natives) C:\Users\Mazdaywik\AppData\Roaming\Refal-5-lambda\srlib\scratch/Library.rasl
+Linking (+ natives) C:\Users\Mazdaywik\AppData\Roaming\Refal-5-lambda\srlib\scratch/refalrts-main.rasl
+Linking (+ natives) C:\Users\Mazdaywik\AppData\Roaming\Refal-5-lambda\srlib\scratch/refalrts.rasl
+Linking (+ natives) C:\Users\Mazdaywik\AppData\Roaming\Refal-5-lambda\srlib\scratch/refalrts-allocator.rasl
+Linking (+ natives) C:\Users\Mazdaywik\AppData\Roaming\Refal-5-lambda\srlib\scratch/refalrts-functions.rasl
+Linking (+ natives) C:\Users\Mazdaywik\AppData\Roaming\Refal-5-lambda\srlib\scratch/refalrts-dynamic.rasl
+Linking (+ natives) C:\Users\Mazdaywik\AppData\Roaming\Refal-5-lambda\srlib\scratch\platform-Windows/refalrts-platform-specific.rasl
+Linking (+ natives) C:\Users\Mazdaywik\AppData\Roaming\Refal-5-lambda\srlib\scratch/refalrts-vm.rasl
+Linking (+ natives) C:\Users\Mazdaywik\AppData\Roaming\Refal-5-lambda\srlib\scratch/refalrts-profiler.rasl
+Linking (+ natives) C:\Users\Mazdaywik\AppData\Roaming\Refal-5-lambda\srlib\scratch/refalrts-diagnostic-initializer.rasl
+Linking (+ natives) C:\Users\Mazdaywik\AppData\Roaming\Refal-5-lambda\srlib\scratch/refalrts-debugger.rasl
Borland C++ 5.5.1 for Win32 Copyright (c) 1993, 2000 Borland
timeelapsed.ok.cpp:
c:\users\mazdaywik\appdata\roaming\refal-5-lambda\srlib\scratch/library.cpp:
c:\users\mazdaywik\appdata\roaming\refal-5-lambda\srlib\scratch/refalrts-main.cpp:
c:\users\mazdaywik\appdata\roaming\refal-5-lambda\srlib\scratch/refalrts.cpp:
c:\users\mazdaywik\appdata\roaming\refal-5-lambda\srlib\scratch/refalrts-allocator.cpp:
c:\users\mazdaywik\appdata\roaming\refal-5-lambda\srlib\scratch/refalrts-functions.cpp:
c:\users\mazdaywik\appdata\roaming\refal-5-lambda\srlib\scratch/refalrts-dynamic.cpp:
c:\users\mazdaywik\appdata\roaming\refal-5-lambda\srlib\scratch\platform-windows/refalrts-platform-specific.cpp:
c:\users\mazdaywik\appdata\roaming\refal-5-lambda\srlib\scratch/refalrts-vm.cpp:
c:\users\mazdaywik\appdata\roaming\refal-5-lambda\srlib\scratch/refalrts-profiler.cpp:
c:\users\mazdaywik\appdata\roaming\refal-5-lambda\srlib\scratch/refalrts-diagnostic-initializer.cpp:
c:\users\mazdaywik\appdata\roaming\refal-5-lambda\srlib\scratch/refalrts-debugger.cpp:
Turbo Incremental Link 5.00 Copyright (c) 1997, 2000 Borland
** Compilation completed successfully **

D:\Mazdaywik\Documents\Refal-5-lambda\build>TimeElapsed.OK.exe && type REFAL7.DAT
(Total refal time): 2.938 seconds (100.0 %).

Total program time: 2.938 seconds (100.0 %).
Open e-loop time (clear): 2.938 seconds (100.0 %).
Identifiers allocated: 88
Step count 203
Memory used 151 nodes, 151 * 16 = 2416 bytes
Time elapsed 0.000000
Time elapsed 0.719000
Time elapsed 1.469000
Time elapsed 0.719000
Time elapsed 1.469000

Без оптимизаций работает примерно в 2 раза медленнее, с оптимизациями — почти догнало.

Выводы

Вывод в том, что функция Mu не при чём. Особенно, в последнем тесте, где бо́льшую часть времени выполняется цикл по открытой переменной. В предыдущих двух тестах немалую часть затрат составляли копирования переменных.

Впрочем, измерения, предложенные выше, сделать всё равно было бы полезно.

Mazdaywik avatar Mar 20 '19 05:03 Mazdaywik

В заявке #264 приведён бенчмарк, также демонстрирующий проблемы с производительностью.

Mazdaywik avatar Oct 21 '19 10:10 Mazdaywik

Ещё один бенчмарк, показывающий проблемы с производительностью: https://groups.google.com/d/msg/refal/Bc429ngDJf4/ccUeOsbRBwAJ Профилировка показывает, что треть времени уходит на функцию DoFirst. Так что есть проблемы производительности из-за того, что библиотечные функции написаны на смеси Рефала и Си++.

Mazdaywik avatar Nov 12 '19 13:11 Mazdaywik

В коммите ca96a728969fcbb6b8b8b3772045ea0560bd620b сделаны интересные замеры производительности. В частности, замечено, что сопоставление с повторной переменной на 15 % медленнее, чем копирование той же переменной.

Mazdaywik avatar Apr 16 '20 07:04 Mazdaywik

Бенчмарк из комментария https://github.com/bmstu-iu9/refal-5-lambda/issues/194#issuecomment-552890284:

primes-swi2.ref 
$ENTRY Go {
  = <Br 'n=' <bi <Card>>> <erit () <i ('0') (<Cp 'n'>)>>;
}

bi {
  e.1 ' ' e.e = e.1;
  e.1 = e.1;
}

* забиваем массив единичками
i {
  t.1 t.1 = ;
  t.1 t.2 = '1' <i (<add t.1 '1'>) t.2>;
}

erit {
  () s.1 s.2 e.e = <f0 (s.1 s.2) e.e>;
  (e.0) e.1 '1' e.e = <f0 (e.0 e.1 '1') e.e>;
}

f0 {
  (e.1) e.e = <fc (<Lenw e.1>) (<Lenw <Cp 'n'>>) e.e>;
}

fc {
* часть проверки, что квадрат простого числа не больше размера массива
  (s.n e.1) e.e = <f1 (e.1 s.n) (<Lenw <mul (<Symb s.n>) <Symb s.n>>>) e.e>;
}

f1 {
  t.0 (s.1 e.2) (s.1 e.4) e.e = <f2 <cmp (e.2) e.4> t.0 e.e>;
  t.0 (s.1 e.2) (s.3 e.4) e.e = <f2 <cmp (s.1) s.3> t.0 e.e>;
}

f2 {
  '>' (e.0 s.n) e.e = <e ('1') e.0 e.e>;
  s.s (e.0 s.n) e.e = <fe <f s.n (e.0) <First s.n e.e>>>;
}

fe {
  e.e (e.0) (e.1) = <erit (e.0 e.1) e.e>;
}

*f (e0)(s1)s2ee='0'k/f/()(e0s1)ee.
*  (e0)(s1e2)ssee=ssk/f/(e0s1)(e2)ee.
*  (e0)(e1)=(e0)(e1)
f {
* заменяем дырку на нуль
  s.n t.0 (e.1 s.2) e.e = e.1 '0' <f s.n t.0 <First s.n e.e>>;
  s.n t.0 () e.e= e.e() t.0;
}

e {
  t.0 '0' e.e = <e (<add t.0 '1'>) e.e>;
  (e.0) '1' e.e = <Prout e.0> <e (<add (e.0) '1'>) e.e>;
* вывод полученного списка
  t.0 = ;
}

cmp {
  (e.L) e.R
    , <Compare <Numb e.L> <Numb e.R>>
    : {
        '+' = '>';
        '0' = '=';
        '-' = '<';
      }
}

mul { (e.L) e.R = <Symb <* <Numb e.L> <Numb e.R>>> }
add { (e.L) e.R = <Symb <+ <Numb e.L> <Numb e.R>>> }

Скачать: primes-swi2.ref.txt.

Такой странный стиль кодирования (в частности, mul и add связан с тем, что программа была конвертирована с Рефала/2 Стеллецкого. И благодаря этому, служит хорошим бенчмарком на встроенные функции арифметики.

Вот так выглядит начало бенчмарка функций:

_profile_time.txt 
Total time: 40.93800 s
Total steps: 58673181
Mean step time: 0.697729 us

DoFirst (8851) -> 15466.0 ms (37.78 %, += 37.78 %)                      rel step time 1.51
Sub-Digits (8851) -> 4337.0 ms (10.59 %, += 48.37 %)                    rel step time 0.44
Add-Nat (8851) -> 3780.0 ms (9.23 %, += 57.61 %)                        rel step time 1.20
DoNumb (8851) -> 2983.0 ms (7.29 %, += 64.89 %)                         rel step time 1.45
DoNumb-AddDigit (8851) -> 2144.0 ms (5.24 %, += 70.13 %)                rel step time 1.37
Add-Nat$1:1 (8851) -> 1817.0 ms (4.44 %, += 74.57 %)                    rel step time 1.16
Mul-Nat-Line (8851) -> 1518.0 ms (3.71 %, += 78.28 %)                   rel step time 0.97
Add-Digits (8851) -> 888.0 ms (2.17 %, += 80.45 %)                      rel step time 0.49
NormNumber (8851) -> 825.0 ms (2.02 %, += 82.46 %)                      rel step time 1.67
__Step-End (0000) -> 688.0 ms (1.68 %, += 84.14 %)                      rel step time 0.69
Numb (0000) -> 622.0 ms (1.52 %, += 85.66 %)                            rel step time 1.26
Mul-Digits (8851) -> 615.0 ms (1.50 %, += 87.16 %)                      rel step time 0.39
__Step-Start (0000) -> 593.0 ms (1.45 %, += 88.61 %)                    rel step time 0.60
f (3443) -> 515.0 ms (1.26 %, += 89.87 %)                               rel step time 2.02
. . .

Библиотека собрана с RLC_FLAGS=-OCDPRS.

Скачать: _profile_time.txt, _profile_count.txt.

Функция прикладной программы впервые появляется в 14-й строчке — остальное это реализация встроенных функций библиотеки. Причём 40 % времени занимает реализация функции First (функция DoFirst + Sub-Digits).

В самом компиляторе заметную долю времени занимает DoLenw — реализация Lenw, написанная на Рефале. Она вызывает Add-Digits, которая, однако, вызывается не только из DoLenw. Причина — для блоков, из которых формируется RASL, вычисляется их объём в байтах — для каждого байта вызывается в цикле DoLenw, которая вызывает Add-Digits.

Профиль выглядит так:

_profile_time.txt 
DoLenw (7641) -> 1582.0 ms (4.46 %, += 4.46 %)                         rel step time 1.02
NumberFromOpcode (0000) -> 1345.0 ms (3.80 %, += 8.26 %)               rel step time 5.52
IncCol (8693) -> 1124.0 ms (3.17 %, += 11.43 %)                        rel step time 0.97
GenCommand-RASL (4746) -> 938.0 ms (2.65 %, += 14.08 %)                rel step time 3.75
Map (9549) -> 890.0 ms (2.51 %, += 16.59 %)                            rel step time 2.77
Add-Digits (7641) -> 890.0 ms (2.51 %, += 19.10 %)                     rel step time 0.34
DoGenSubst (0177) -> 837.0 ms (2.36 %, += 21.46 %)                     rel step time 18.85
Add (0000) -> 796.0 ms (2.25 %, += 23.71 %)                            rel step time 0.73
DoMapAccum (8023) -> 690.0 ms (1.95 %, += 25.66 %)                     rel step time 1.26
DoMapAccum (9549) -> 659.0 ms (1.86 %, += 27.52 %)                     rel step time 1.94

Режимы:

set RLC_FLAGS=-OCDPRS
set RLMAKE_FLAGS=

Скачать: _profile_time.txt, _profile_count.txt.

Так что надо оптимизировать Lenw, First и Last, переписав их на C++. А в перспективе — вообще все функции арифметики. Но первые три выигрываю по соотношению затраты/результат в этих бенчмарках.

Mazdaywik avatar May 03 '20 15:05 Mazdaywik

Замеры времени для предшествующих коммитов:

Профиль для программы primes-swi2.ref теперь выглядит так:

_profile_time.txt 
Total time: 19.84400 s
Total steps: 28999547
Mean step time: 0.684287 us

Add-Nat (1508) -> 3616.0 ms (18.22 %, += 18.22 %)                        rel step time 1.18
DoNumb (1508) -> 2479.0 ms (12.49 %, += 30.71 %)                         rel step time 1.23
DoNumb-AddDigit (1508) -> 2410.0 ms (12.14 %, += 42.86 %)                rel step time 1.57
Mul-Nat-Line (1508) -> 1522.0 ms (7.67 %, += 50.53 %)                    rel step time 0.99
Add-Nat$1:1 (1508) -> 1518.0 ms (7.65 %, += 58.18 %)                     rel step time 0.99
Add-Digits (1508) -> 1065.0 ms (5.37 %, += 63.55 %)                      rel step time 0.60
NormNumber (1508) -> 810.0 ms (4.08 %, += 67.63 %)                       rel step time 1.68
__Step-End (0000) -> 670.0 ms (3.38 %, += 71.00 %)                       rel step time 0.92
Numb (0000) -> 640.0 ms (3.23 %, += 74.23 %)                             rel step time 1.32
Mul-Digits (1508) -> 635.0 ms (3.20 %, += 77.43 %)                       rel step time 0.41
f (3443) -> 391.0 ms (1.97 %, += 79.40 %)                                rel step time 1.57
__Step-Start (0000) -> 391.0 ms (1.97 %, += 81.37 %)                     rel step time 0.54
Numb-Aux (1508) -> 359.0 ms (1.81 %, += 83.18 %)                         rel step time 0.74
Symb=1 (1508) -> 312.0 ms (1.57 %, += 84.75 %)                           rel step time 1.29
NormNumber$9?1 (1508) -> 297.0 ms (1.50 %, += 86.25 %)                   rel step time 1.23
Add (0000) -> 295.0 ms (1.49 %, += 87.73 %)                              rel step time 1.22
Type (0000) -> 267.0 ms (1.35 %, += 89.08 %)                             rel step time 0.55
add (3443) -> 264.0 ms (1.33 %, += 90.41 %)                              rel step time 1.09
AllDigits-SwFirst (1508) -> 263.0 ms (1.33 %, += 91.74 %)                rel step time 1.09
Symb (0000) -> 218.0 ms (1.10 %, += 92.83 %)                             rel step time 0.90
AllDigits (1508) -> 217.0 ms (1.09 %, += 93.93 %)                        rel step time 0.90
i (3443) -> 216.0 ms (1.09 %, += 95.02 %)                                rel step time 1.79
__Step-Drop (0000) -> 206.0 ms (1.04 %, += 96.05 %)                      rel step time 0.82
Symb-Nat (1508) -> 186.0 ms (0.94 %, += 96.99 %)                         rel step time 0.77
e (3443) -> 172.0 ms (0.87 %, += 97.86 %)                                rel step time 1.42
NormNumber$7?1 (1508) -> 158.0 ms (0.80 %, += 98.65 %)                   rel step time 0.65
StrFromMacroDigit (1508) -> 143.0 ms (0.72 %, += 99.38 %)                rel step time 0.59
First (0000) -> 93.0 ms (0.47 %, += 99.84 %)                             rel step time 0.37
Putout-Aux (1508) -> 31.0 ms (0.16 %, += 100.00 %)                       rel step time 2.83


   1. D:\Mazdaywik\Documents\MEGA\primes\primes-swi2.exe
      SCOPES:
         1. #2820 - slim-prefix-exe.ref
         2. #1508 - Library.ref
         3. #9313 - Platform.ref
         4. #3443 - primes-swi2.ref

Скачать: _profile_time.txt, _profile_count.txt.

Функция First теперь последняя! Общее время работы программы уполовинилось. Но функции арифметики оптимизировать надо.

В случае самоприменимого компилятора «медленные» DoLenw, Add-Digits и IncCol теперь даже не в третьей десятке! (Замеры: _profile_time.txt, _profile_count.txt.)

Первые по списку функции уже оптимизировать не так интересно:

NumberFromOpcode (0000) -> 1420.0 ms (4.60 %, += 4.60 %)              rel step time 5.55
DoGenSubst (0177) -> 1001.0 ms (3.24 %, += 7.84 %)                    rel step time 21.46
Map (9549) -> 950.0 ms (3.08 %, += 10.92 %)                           rel step time 2.82
Map (4746) -> 759.0 ms (2.46 %, += 13.38 %)                           rel step time 1.41
DoMapAccum (8023) -> 640.0 ms (2.07 %, += 15.45 %)                    rel step time 1.12
GenCommand-RASL (4746) -> 610.0 ms (1.98 %, += 17.43 %)               rel step time 2.32
Apply (8023) -> 581.0 ms (1.88 %, += 19.31 %)                         rel step time 0.71
Apply (2191) -> 526.0 ms (1.70 %, += 21.01 %)                         rel step time 0.57
Close (0000) -> 516.0 ms (1.67 %, += 22.68 %)                         rel step time 1850.30
DoMapAccum (9549) -> 512.0 ms (1.66 %, += 24.34 %)                    rel step time 1.43
__Step-Drop (0000) -> 502.0 ms (1.63 %, += 25.97 %)                   rel step time 0.34

Функцию DoGenSubst нужно переписывать — делать команды сопоставления функциональными (#204), остальные функции оптимизируются при прогонке или специализации, а также имеют небольшой вклад.

Mazdaywik avatar May 03 '20 22:05 Mazdaywik

Замеры производительности к предыдущему коммиту (f2484e9):

Mazdaywik avatar May 05 '20 17:05 Mazdaywik