Ускорение работы оптимизатора прогонки #239

Mazdaywik · 2019-07-04T09:20:39Z

Оптимизатор-прогонщик работает очень медленно, особенно медленно совместно с режимом специализации, с которым и должен совместно работать. Вот таблица:

Режим	Время, сек
`-OT`	36,1
`-OD`	440,8
`-OS`	38,2
`-ODS`	725,0

Замеры неточные, но порядок величины отражают достоверно. Кроме того, лютую долю времени при прогонке занимают копирования t- и e-переменных и контекста, например, в последнем замере они требуют, соответственно, 79,0 % и 15,8 %.

Понятно, что в случае -ODS фронт деятельности прогонщика расширяется: появляется возможность оптимизировать вызовы Apply в функциях Map@n, а затем и прогнать там замыкания.

Поэтому предлагаются следующие пути для оптимизации:

Отложенное создание функций Func*n (Удалять и не порождать неиспользуемые функции #228). Оно приводит к наполнению дерева ненужными функциями вида Func*n, которые никогда не вызываются. Из-за этого каждая следующая итерация выполняется дольше, временна́я сложность возрастает на лишний порядок. Это хорошо заметно на файле Generator-RASL.ref, в котором прогоняется функция NumberFromOpcode, содержащая 119 предложений.
За одну итерацию прогонять/встраивать сразу несколько предложений. Текущая реализация пытается прогнать первое предложение. Если результат прогонки с сужениями или неудачный (Failure), то вызов функции Func заменяется на Func*1, вызов Func*n на Func*(n+1). Следующий такой вызов будет анализироваться на следующей итерации. Предлагается за одну итерацию анализировать сразу несколько предложений. В этом случае бо́льшая глубина оптимизации будет достигаться за меньшее число итераций.
Поискать копирования переменных и оптимизировать их. (Копирований много, нужно искать наиболее затратные.) Чтобы искать наиболее затратные копирования, можно написать простой профилировщик.

The text was updated successfully, but these errors were encountered:

Mazdaywik · 2019-07-25T18:48:57Z

Результаты профилирования

Выполнил замер при помощи профилировщика #246. Самоприменение неоптимизированной версии без оптимизации, первые 14 функций по времени (50 % времени выполнения программы, время в мс):

makeself.bat без оптимизации

Map -> 3290.0 (8.57 %, += 8.57 %)
Apply -> 2793.0 (7.28 %, += 15.85 %)
DoMapAccum -> 1951.0 (5.08 %, += 20.94 %)
NumberFromOpcode -> 1658.0 (4.32 %, += 25.26 %)
DoLenw -> 1423.0 (3.71 %, += 28.96 %)
DoMapAccum-Aux -> 1315.0 (3.43 %, += 32.39 %)
IncCol -> 1234.0 (3.22 %, += 35.61 %)
GenCommand-RASL -> 1079.0 (2.81 %, += 38.42 %)
Add -> 1000.0 (2.61 %, += 41.02 %)
Divmod -> 813.0 (2.12 %, += 43.14 %)
__Step-Start -> 812.0 (2.12 %, += 45.26 %)
DoGenSubst -> 809.0 (2.11 %, += 47.37 %)
__Step-End -> 718.0 (1.87 %, += 49.24 %)
Add-Digits -> 609.0 (1.59 %, += 50.82 %)

Видно, что только две функции требуют более 5 % времени (Map, Apply и DoMapAccum), функции DoMapAccum и DoMapAccum-Aux потребляют сравнимое время (5,08 % и 3,43 %).

А вот замер для запуска неоптимизированной версии с ключами

set SRMAKE_FLAGS=-X-ODS -X--opt-tree-cycles=10

(запускаем неоптимизированную версию, поскольку в оптимизированной будут всякие Map@1):

DoMapAccum -> 499315.0 (57.22 %, += 57.22 %)
<unwrap closure>: OptimizeF$1=1\1 -> 72631.0 (8.32 %, += 65.54 %)
DriveSentence -> 69230.0 (7.93 %, += 73.47 %)
DriveSentence$1?2 -> 68893.0 (7.89 %, += 81.37 %)
<unwrap closure>: DriveInlineOptimizerTick=2\1 -> 46506.0 (5.33 %, += 86.70 %)
Map -> 13734.0 (1.57 %, += 88.27 %)
OptSentence -> 7967.0 (0.91 %, += 89.18 %)
FindOptimizedCall-Term$3?1 -> 7336.0 (0.84 %, += 90.03 %)
Apply -> 7135.0 (0.82 %, += 90.84 %)

При этом общий профиль программы такой:

Total program time: 872.68700 seconds (100.0 %).
(Total refal time): 727.72100 seconds (83.4 %).
t- and e-var copy time: 682.63800 seconds (78.2 %).
Context copy time: 125.83900 seconds (14.4 %).
Linear result time: 20.19800 seconds (2.3 %).
Linear pattern time: 20.10600 seconds (2.3 %).
Runtime time overhead: 14.36100 seconds (1.6 %).
Native time: 4.76600 seconds (0.5 %).
Open e-loop time (clear): 3.75300 seconds (0.4 %).
Repeated e-var match time (inside e-loops): 0.76100 seconds (0.1 %).
Repeated e-var match time (outside e-loops): 0.18600 seconds (0.0 %).
Repeated t-var match time (inside e-loops): 0.06300 seconds (0.0 %).
Repeated t-var match time (outside e-loops): 0.01600 seconds (0.0 %).
Step count 42996655
Identifiers allocated: 991
Memory used 593000 nodes, 593000 * 16 = 9488000 bytes

На первой строчке находится DoMapAccum и t- and e-var copy time, что согласуется между собой, ведь функция DoMapAccum на каждой итерации копирует функциональный объект:

refal-5-lambda/src/srlib/common/LibraryEx.refi

Lines 73 to 80 in f4e56e6

    
           DoMapAccum { 
        
             t.Fn t.Acc (e.Scanned) t.Next e.Tail 
        
               = <DoMapAccum-Aux 
        
                   t.Fn (e.Scanned) (<Apply t.Fn t.Acc t.Next>) e.Tail 
        
                 >; 
        
             t.Fn t.Acc (e.Scanned) = t.Acc e.Scanned; 
        
           }

Без оптимизации DoMapAccum потребляет довольно мало времени, значит, проблема в оптимизации. И вот она:

refal-5-lambda/src/compiler/OptTree-Drive.ref

Lines 534 to 539 in f4e56e6

    
           FindOptimizedCall { 
        
             (t.DriveInfo s.Filter) e.Expr 
        
               = <MapAccum (&FindOptimizedCall-Term (t.DriveInfo s.Filter)) None e.Expr>; 
        
             t.DriveInfo t.Found e.Expr = t.Found e.Expr; 
        
           }

Здесь на каждой итерации копируется t.DriveInfo.

Если проанализировать остальные медленные функции, то тоже выяснится, что на каждой итерации там происходит копирование t.DriveInfo.

Вторая строчка, <unwrap closure>: OptimizeF$1=1\1 соответствует копированию контекста для вызова соответствующей функции, в контексте у неё e.OptNames и e.OptFunctions.
Третья и четвёртая строчки (DriveSentence и DriveSentence$1?2) — функция DriveSentence копирует t.DriveInfo, четвёртая строка соответствует части функции после неуспешного условия в первом предложении.
Пятая строчка — копирование контекста для DriveInlineOptimizerTick=2\1, тоже копируются e.OptNames и e.OptFunctions.

Последующие строчки (Map, OptSentence и т.д.) уже занимают существенно меньше времени и потому не интересны.

Что делать?

Очевидное (и кошерное) решение состоит в том, чтобы переписать перечисленные выше функции так, чтобы они не копировали t.DriveInfo. Для этого нужно найти те функции, которые получают t.DriveInfo и на выходе не возвращают его же, и переписать так, чтобы они его возвращали. Таким образом удастся избежать копирования.

Но это достаточно сложный и долгий рефакторинг. Рефакторинг делать надо, но не сейчас.

Есть другое предложение: снизить стоимость копирования. Наиболее тяжёлое в t.DriveInfo — это тела функций. Но многие функции, потребляющие t.DriveInfo, эти самые тела не используют, например, FindOptimizedCall интересуется лишь именами.

Предлагается тела функций в t.DriveInfo передавать не по значению, а по ссылке — ссылка будет копироваться за малое константное время. А когда тело понядобится (например, во время прогонки в DriveSentence-Aux), ссылку разыменовывать.

В Рефале-5λ есть такой вид ссылок — это безымянные функции, замыкающие контекст. Функция вида { = e.X } замыкает значение e.X, и если её вызвать, она это значение вернёт (переместив или скопировав из контекста).

Поэтому предлагается хранить тела функций в t.DriveInfo как замыкания. По идее, это должно существенно снизить стоимость копирования t.DriveInfo по всему модулю OptTree-Drive.ref. Решение не очень красивое, напоминает хак, но на первое время его будет достаточно. Почему хак? Потому что это использование вложенных функций не по прямому назначению и нигде больше в исходниках Рефала-5λ этот приём не используется.

Mazdaywik · 2019-07-25T20:01:12Z

Завернул тела функций в замыкания. Результат обрадовал (условия запуска те же):

DoMapAccum -> 125097.0 (45.10 %, += 45.10 %)
<unwrap closure>: OptimizeF$1=1\1 -> 15758.0 (5.68 %, += 50.78 %)
Map -> 13860.0 (5.00 %, += 55.78 %)
DriveSentence$1?2 -> 13720.0 (4.95 %, += 60.72 %)
DriveSentence -> 13312.0 (4.80 %, += 65.52 %)
OptSentence -> 9355.0 (3.37 %, += 68.89 %)
<unwrap closure>: DriveInlineOptimizerTick=2\1 -> 8574.0 (3.09 %, += 71.98 %)
<unwrap closure>: OptTree-Simple\1 -> 6374.0 (2.30 %, += 74.28 %)
Apply -> 6178.0 (2.23 %, += 76.51 %)

Total program time: 277.42200 seconds (100.0 %).
(Total refal time): 225.86900 seconds (81.4 %).
t- and e-var copy time: 181.59600 seconds (65.5 %).
Context copy time: 32.22600 seconds (11.6 %).
Linear result time: 20.14500 seconds (7.3 %).
Linear pattern time: 19.04600 seconds (6.9 %).
Runtime time overhead: 13.90100 seconds (5.0 %).
Native time: 5.42600 seconds (2.0 %).
Open e-loop time (clear): 4.14000 seconds (1.5 %).
Repeated e-var match time (inside e-loops): 0.64300 seconds (0.2 %).
Repeated e-var match time (outside e-loops): 0.23600 seconds (0.1 %).
Repeated t-var match time (inside e-loops): 0.06300 seconds (0.0 %).
Step count 43033765
Identifiers allocated: 993
Memory used 593000 nodes, 593000 * 16 = 9488000 bytes

Ускорение составило 872,687/277,422 = 3,1457 раз! При этом уменьшились метрики t- and e-var copy time и Context copy time, а остальные практически не поменяли свои значения.

Однако, по-прежнему лидируют DoMapAccum (а конкретнее, его вызов с &FindOptimizedCall-Term) и копирование контекста для OptimizeF$1=1\1, на них приходится половина времени выполнения программы. На третьем месте функция Map, при этом совершенно непонятно, какие её вызовы так медленно выполняются. Но это не так важно: начиная с Map последующие функции требуют не более 5 % времени. Также время выполнения функции Map почти совпадает со временем в предыдущем тесте.

Так что надо оптимизировать первые две функции, передавая данные оптимизаций через аккумулятор.

Таблица t.DriveInfo теперь не копируется, а передаётся через аккумулятор

Mazdaywik · 2019-07-25T21:38:59Z

С оптимизацией FindOptimizedCall получилось так:

DoMapAccum -> 36567.0 (21.47 %, += 21.47 %)
Map -> 13323.0 (7.82 %, += 29.29 %)
<unwrap closure>: OptimizeF$1=1\1 -> 11374.0 (6.68 %, += 35.97 %)
DriveSentence -> 10825.0 (6.36 %, += 42.33 %)
DriveSentence$1?2 -> 10500.0 (6.17 %, += 48.49 %)
OptSentence -> 8515.0 (5.00 %, += 53.49 %)
<unwrap closure>: DriveInlineOptimizerTick=2\1 -> 7786.0 (4.57 %, += 58.06 %)
<unwrap closure>: OptTree-Simple\1 -> 5287.0 (3.10 %, += 61.17 %)
Apply -> 5001.0 (2.94 %, += 64.10 %)
SpecSentence -> 4362.0 (2.56 %, += 66.67 %)
DoMapAccum-Aux -> 3411.0 (2.00 %, += 68.67 %)

Total program time: 170.34300 seconds (100.0 %).
(Total refal time): 125.90000 seconds (73.9 %).
t- and e-var copy time: 85.64200 seconds (50.3 %).
Context copy time: 26.02300 seconds (15.3 %).
Linear result time: 18.83100 seconds (11.1 %).
Linear pattern time: 17.25700 seconds (10.1 %).
Runtime time overhead: 13.14100 seconds (7.7 %).
Native time: 5.27900 seconds (3.1 %).
Open e-loop time (clear): 3.35000 seconds (2.0 %).
Repeated e-var match time (inside e-loops): 0.64900 seconds (0.4 %).
Repeated e-var match time (outside e-loops): 0.12300 seconds (0.1 %).
Repeated t-var match time (inside e-loops): 0.04800 seconds (0.0 %).
Step count 43124873
Identifiers allocated: 994
Memory used 593000 nodes, 593000 * 16 = 9488000 bytes

Не смотря на отсутствие копирования t.DriveInfo в FindOptimizedCall, на DoMapAccum уходит пятая часть времени выполнения программы (для сравнения, DoMapAccum-Aux только 2 %). Это странно, ведь копируется теперь только (&FindOptimizedCall-Term s.Filter), что не должно требовать столько времени. Других вызовов MapAccum/MapReduce, копирующих много контекста, я в исходниках не нашёл.

Но, тем не менее, имеем ускорение 277,422/170,343 = 1,6286. По сравнению с исходным: 872,687/170,343 = 5,1231.

И это только тактическая оптимизация. Стратегическая оптимизация будет заключаться в рефакторинге и переработке подхода. Возможный рефакторинг: в функцию FindOptimizedCall можно передавать не всё t.DriveInfo, а только список имён функций. А переработка подхода — прогонка сразу нескольких предложений за раз.

Отдельно оптимизировать OptimizeF$1=1\1 нет смысла, поскольку оно даст экономию не более 10 секунд. К ней можно будет вернуться только после (или во время) стратегической оптимизации.

Mazdaywik · 2019-07-26T14:28:11Z

Ускорение в 5 раз, конечно, внушительно. Но всё равно это медленно. На выполнение самоприменения с ключами

set SRMAKE_FLAGS=-X-ODPRS

требуется около получаса времени (причём это повторный прогон оптимизированной версии):

Total program time: 1510.85900 seconds (100.0 %).
(Total refal time): 1293.36400 seconds (85.6 %).
t- and e-var copy time: 1141.16700 seconds (75.5 %).
Context copy time: 198.09100 seconds (13.1 %).
Linear pattern time: 75.80200 seconds (5.0 %).
Linear result time: 53.74800 seconds (3.6 %).
Open e-loop time (clear): 17.63400 seconds (1.2 %).
Runtime time overhead: 14.49700 seconds (1.0 %).
Native time: 4.90700 seconds (0.3 %).
Repeated e-var match time (inside e-loops): 3.31600 seconds (0.2 %).
Repeated e-var match time (outside e-loops): 1.61800 seconds (0.1 %).
Repeated t-var match time (inside e-loops): 0.04700 seconds (0.0 %).
Repeated t-var match time (outside e-loops): 0.03200 seconds (0.0 %).
Step count 185236685
Identifiers allocated: 994
Memory used 4331000 nodes, 4331000 * 16 = 69296000 bytes

Так что нужно реализовывать стратегическую оптимизацию.

Mazdaywik · 2019-08-01T11:07:38Z

Запуск makeself.bat на текущей вершине ветки refal-5-lambda (f66b2d6) с предыдущими ключами:

set SRMAKE_FLAGS=-X-ODS -X--opt-tree-cycles=10

print-statistics = true
enable-profiler = true

Результаты:

Total program time: 142.03100 seconds (100.0 %).
(Total refal time): 105.24800 seconds (74.1 %).
t- and e-var copy time: 71.14400 seconds (50.1 %).
Context copy time: 22.30800 seconds (15.7 %).
Linear result time: 15.73500 seconds (11.1 %).
Linear pattern time: 14.82300 seconds (10.4 %).
Runtime time overhead: 10.15100 seconds (7.1 %).
Native time: 4.32400 seconds (3.0 %).
Open e-loop time (clear): 2.84400 seconds (2.0 %).
Repeated e-var match time (inside e-loops): 0.48400 seconds (0.3 %).
Repeated e-var match time (outside e-loops): 0.21800 seconds (0.2 %).
Step count 42852458
Identifiers allocated: 1031
Memory used 593000 nodes, 593000 * 16 = 9488000 bytes

DoMapAccum -> 31218.0 (21.98 %, += 21.98 %)
Map -> 10151.0 (7.15 %, += 29.13 %)
<unwrap closure>: OptimizeF$1=1\1 -> 10046.0 (7.07 %, += 36.21 %)
DriveSentence -> 9119.0 (6.42 %, += 42.63 %)
DriveSentence$1?2 -> 8970.0 (6.32 %, += 48.95 %)
OptSentence -> 6780.0 (4.77 %, += 53.72 %)
<unwrap closure>: DriveInlineOptimizerTick=2\1 -> 6746.0 (4.75 %, += 58.47 %)
Apply -> 4432.0 (3.12 %, += 61.59 %)
<unwrap closure>: OptTree-Simple\1 -> 4223.0 (2.97 %, += 64.57 %)
SpecSentence -> 3415.0 (2.40 %, += 66.97 %)
DoMapAccum-Aux -> 2448.0 (1.72 %, += 68.70 %)

Последующий запуск с ключами

set SRMAKE_FLAGS=-X-ODPRS

print-statistics = true
enable-profiler = false

Результат:

Total program time: 1386.64100 seconds (100.0 %).
(Total refal time): 1182.96700 seconds (85.3 %).
t- and e-var copy time: 1005.04000 seconds (72.5 %).
Context copy time: 186.91400 seconds (13.5 %).
Linear pattern time: 85.52700 seconds (6.2 %).
Linear result time: 75.03500 seconds (5.4 %).
Open e-loop time (clear): 14.35900 seconds (1.0 %).
Runtime time overhead: 12.29100 seconds (0.9 %).
Native time: 4.46900 seconds (0.3 %).
Repeated e-var match time (inside e-loops): 2.39300 seconds (0.2 %).
Repeated e-var match time (outside e-loops): 0.53500 seconds (0.0 %).
Repeated t-var match time (inside e-loops): 0.06300 seconds (0.0 %).
Repeated t-var match time (outside e-loops): 0.01500 seconds (0.0 %).
Step count 185042998
Identifiers allocated: 1031
Memory used 4331000 nodes, 4331000 * 16 = 69296000 bytes

(т.е. 23 минуты 6 секунд)

И ещё один запуск оптимизированной версии:

Total program time: 1228.37500 seconds (100.0 %).
(Total refal time): 1049.68400 seconds (85.5 %).
t- and e-var copy time: 925.94000 seconds (75.4 %).
Context copy time: 162.98600 seconds (13.3 %).
Linear pattern time: 61.51600 seconds (5.0 %).
Linear result time: 44.02200 seconds (3.6 %).
Open e-loop time (clear): 14.23400 seconds (1.2 %).
Runtime time overhead: 11.45600 seconds (0.9 %).
Native time: 4.24900 seconds (0.3 %).
Repeated e-var match time (inside e-loops): 2.52000 seconds (0.2 %).
Repeated e-var match time (outside e-loops): 1.31100 seconds (0.1 %).
Repeated t-var match time (outside e-loops): 0.07900 seconds (0.0 %).
Repeated t-var match time (inside e-loops): 0.06200 seconds (0.0 %).
Step count 184385762
Identifiers allocated: 1031
Memory used 4331000 nodes, 4331000 * 16 = 69296000 bytes

(20 минут 28 секунд)

Применим несколько коммитов с побочными багфиксами, рефакторингами и тактическими оптимизациями.

Отчасти этот коммит является и оптимизацией, поэтому ссылка на #239

Теперь при подстановке сужений проверяется содержимое замороженных скобок: если оно изменилось, скобка оттаивает, иначе остаётся как есть. Ранее подогрев включался в зависимости от контекста подстановки, и включался неправильно, из-за чего достигалась недостаточная глубина оптимизации.

Прогонка для функций <F*n …> работала, а встраивание — нет, из-за чего в сгенерированном коде оставались вызовы <Apply*1 (&F e.B) e.A>.

Часть кода ответственного за прогонку и встраивание, была очень похожа с точностью до копипаста. Данный код был рефакторизован в исходном смысле слова «факторизация» — написана одна функция, параметризуемая ключом «прогонка/встраивание». Ну и мелкие попутные правки.

…122) Этот коммит отчасти является оптимизацией, поскольку на следующих итерациях данные вызовы анализироваться не будут. Поэтому ссылка на #239.

Ранее в режиме -OI встраивались только $INLINE-функции, а $DRIVE вообще не трогались. А должны были, поскольку в режиме -OI метка $DRIVE должна была рассматриваться как метка $INLINE, это входило в постановку задачи.

Очевидные упрощения кода

Упрощение и оптимизация функции FindOptimizedCall: в ней используется только список имён оптимизируемых функций, их тела не передаются.

Ещё один набор достаточно очевидных упрощений

Mazdaywik · 2019-08-01T12:45:16Z

Коммиты выше исключительно тактические. Повторим замеры из предыдущего комментария.

set SRMAKE_FLAGS=-X-ODS -X--opt-tree-cycles=10

print-statistics = true
enable-profiler = true

Total program time: 108.39100 seconds (100.0 %).
(Total refal time): 89.31000 seconds (82.4 %).
t- and e-var copy time: 51.93300 seconds (47.9 %).
Linear result time: 15.23600 seconds (14.1 %).
Linear pattern time: 15.01000 seconds (13.8 %).
Runtime time overhead: 9.35300 seconds (8.6 %).
Context copy time: 5.82000 seconds (5.4 %).
Native time: 3.90800 seconds (3.6 %).
Repeated t-var match time (outside e-loops): 3.28500 seconds (3.0 %).
Open e-loop time (clear): 3.17400 seconds (2.9 %).
Repeated e-var match time (inside e-loops): 0.42300 seconds (0.4 %).
Repeated e-var match time (outside e-loops): 0.23300 seconds (0.2 %).
Repeated t-var match time (inside e-loops): 0.01600 seconds (0.0 %).
Step count 40911617
Identifiers allocated: 1024
Memory used 593000 nodes, 593000 * 16 = 9488000 bytes

Ускорение в 142/108 = 1,3 раза.

DoMapAccum -> 29270.0 (27.01 %, += 27.01 %)
Map -> 10391.0 (9.59 %, += 36.60 %)
OptSentence -> 7364.0 (6.79 %, += 43.39 %)
<unwrap closure>: OptTree-Simple\1 -> 4754.0 (4.39 %, += 47.78 %)
Apply -> 4233.0 (3.91 %, += 51.68 %)
SpecSentence -> 4181.0 (3.86 %, += 55.54 %)
OptimizeF=1 -> 3317.0 (3.06 %, += 58.60 %)
OptimizeF -> 2997.0 (2.77 %, += 61.37 %)
DoMapAccum-Aux -> 2412.0 (2.23 %, += 63.59 %)
OptResultTerm -> 2075.0 (1.91 %, += 65.51 %)
NumberFromOpcode -> 1875.0 (1.73 %, += 67.24 %)
DoLenw -> 1482.0 (1.37 %, += 68.61 %)
GenCommand-RASL -> 1218.0 (1.12 %, += 69.73 %)

set SRMAKE_FLAGS=-X-ODPRS

print-statistics = true
enable-profiler = false

Total program time: 805.32800 seconds (100.0 %).
(Total refal time): 790.75300 seconds (98.2 %).
t- and e-var copy time: 615.08200 seconds (76.4 %).
Linear pattern time: 83.47200 seconds (10.4 %).
Linear result time: 68.31200 seconds (8.5 %).
Open e-loop time (clear): 12.05900 seconds (1.5 %).
Runtime time overhead: 9.00800 seconds (1.1 %).
Repeated t-var match time (outside e-loops): 8.88200 seconds (1.1 %).
Native time: 4.47100 seconds (0.6 %).
Repeated e-var match time (inside e-loops): 1.98300 seconds (0.2 %).
Context copy time: 1.09600 seconds (0.1 %).
Repeated e-var match time (outside e-loops): 0.90100 seconds (0.1 %).
Repeated t-var match time (inside e-loops): 0.06200 seconds (0.0 %).
Step count 163786297
Identifiers allocated: 1024
Memory used 4401000 nodes, 4401000 * 16 = 70416000 bytes

(13 минут 25 секунд, ускорение 1386/805 = 1,7 раз)

Total program time: 706.43800 seconds (100.0 %).
(Total refal time): 692.19700 seconds (98.0 %).
t- and e-var copy time: 570.43100 seconds (80.7 %).
Linear pattern time: 56.98300 seconds (8.1 %).
Linear result time: 39.51100 seconds (5.6 %).
Open e-loop time (clear): 12.48200 seconds (1.8 %).
Runtime time overhead: 9.28800 seconds (1.3 %).
Repeated t-var match time (outside e-loops): 8.87600 seconds (1.3 %).
Native time: 4.12500 seconds (0.6 %).
Repeated e-var match time (inside e-loops): 2.05800 seconds (0.3 %).
Repeated e-var match time (outside e-loops): 1.80900 seconds (0.3 %).
Context copy time: 0.82800 seconds (0.1 %).
Repeated t-var match time (inside e-loops): 0.04700 seconds (0.0 %).
Step count 159006156
Identifiers allocated: 1024
Memory used 4401000 nodes, 4401000 * 16 = 70416000 bytes

(11 минут 46 секунд, ускорение 1228/706 = 1,7 раз)

И это только тактические оптимизации. Пришёл черёд стратегической.

Теперь, во-первых, создаётся меньше функций Func*n, поэтому коммит частично решает задачу #228, во-вторых, компилятор работает, в частности, самоприменяется быстрее, поэтому ссылка на #239.

Mazdaywik · 2019-08-01T17:22:43Z

Стратегическая оптимизация сделана! Замеры:

set SRMAKE_FLAGS=-X-ODS -X--opt-tree-cycles=10

print-statistics = true
enable-profiler = true

Total program time: 79.95300 seconds (100.0 %).
(Total refal time): 62.83800 seconds (78.6 %).
t- and e-var copy time: 32.88000 seconds (41.1 %).
Linear pattern time: 12.62300 seconds (15.8 %).
Linear result time: 12.42700 seconds (15.5 %).
Runtime time overhead: 8.49700 seconds (10.6 %).
Context copy time: 4.82900 seconds (6.0 %).
Native time: 3.78900 seconds (4.7 %).
Repeated t-var match time (outside e-loops): 2.15500 seconds (2.7 %).
Open e-loop time (clear): 2.06600 seconds (2.6 %).
Repeated e-var match time (inside e-loops): 0.42400 seconds (0.5 %).
Repeated e-var match time (outside e-loops): 0.24800 seconds (0.3 %).
Repeated t-var match time (inside e-loops): 0.01500 seconds (0.0 %).
Step count 35861859
Identifiers allocated: 1025
Memory used 569000 nodes, 569000 * 16 = 9104000 bytes

Ускорение в 108/79,9 = 1,3 раза.

DoMapAccum -> 19509.0 (24.41 %, += 24.41 %)
Map -> 7236.0 (9.05 %, += 33.46 %)
OptSentence -> 4038.0 (5.05 %, += 38.51 %)
<unwrap closure>: OptTree-Simple\1 -> 3466.0 (4.34 %, += 42.84 %)
Apply -> 3289.0 (4.11 %, += 46.96 %)
SpecSentence -> 2526.0 (3.16 %, += 50.12 %)
OptimizeF -> 2204.0 (2.76 %, += 52.88 %)
OptimizeF=1 -> 2187.0 (2.74 %, += 55.61 %)
DoMapAccum-Aux -> 1681.0 (2.10 %, += 57.72 %)
NumberFromOpcode -> 1572.0 (1.97 %, += 59.68 %)
DoLenw -> 1323.0 (1.66 %, += 61.34 %)
GenCommand-RASL -> 1143.0 (1.43 %, += 62.77 %)
Add -> 1105.0 (1.38 %, += 64.15 %)
IncCol -> 1042.0 (1.30 %, += 65.45 %)

set SRMAKE_FLAGS=-X-ODPRS

print-statistics = true
enable-profiler = false

Total program time: 174.92200 seconds (100.0 %).
(Total refal time): 166.01600 seconds (94.9 %).
Linear pattern time: 59.12100 seconds (33.8 %).
t- and e-var copy time: 55.04900 seconds (31.5 %).
Linear result time: 44.54200 seconds (25.5 %).
Runtime time overhead: 5.18800 seconds (3.0 %).
Open e-loop time (clear): 3.94200 seconds (2.3 %).
Native time: 3.29800 seconds (1.9 %).
Repeated t-var match time (outside e-loops): 2.70600 seconds (1.5 %).
Context copy time: 0.42000 seconds (0.2 %).
Repeated e-var match time (inside e-loops): 0.35900 seconds (0.2 %).
Repeated e-var match time (outside e-loops): 0.25100 seconds (0.1 %).
Repeated t-var match time (inside e-loops): 0.04600 seconds (0.0 %).
Step count 109434259
Identifiers allocated: 1025
Memory used 845000 nodes, 845000 * 16 = 13520000 bytes

(2 минуты 55 секунд, ускорение в 805/174,9 = 4,6 раз)

Total program time: 133.17200 seconds (100.0 %).
(Total refal time): 123.03700 seconds (92.4 %).
t- and e-var copy time: 53.44100 seconds (40.1 %).
Linear pattern time: 38.80300 seconds (29.1 %).
Linear result time: 23.67900 seconds (17.8 %).
Runtime time overhead: 5.92100 seconds (4.4 %).
Open e-loop time (clear): 3.91000 seconds (2.9 %).
Native time: 3.66500 seconds (2.8 %).
Repeated t-var match time (outside e-loops): 2.53300 seconds (1.9 %).
Context copy time: 0.54900 seconds (0.4 %).
Repeated e-var match time (outside e-loops): 0.32800 seconds (0.2 %).
Repeated e-var match time (inside e-loops): 0.29600 seconds (0.2 %).
Repeated t-var match time (inside e-loops): 0.04700 seconds (0.0 %).
Step count 109434259
Identifiers allocated: 1025
Memory used 845000 nodes, 845000 * 16 = 13520000 bytes

(2 минуты 13 секунд, ускорение в 706/133 = 5,3 раз)

Mazdaywik · 2019-08-01T17:23:52Z

Вывод

Результаты показывают приемлемую скорость компилятора. Т.е. компилятор можно самоприменять с ключами максимальной оптимизации -OdDPRS за приемлемое время.

Mazdaywik added the task label Jul 4, 2019

Mazdaywik self-assigned this Jul 4, 2019

Mazdaywik mentioned this issue Jul 4, 2019

Удалять и не порождать неиспользуемые функции #228

Open

Mazdaywik added a commit that referenced this issue Jul 25, 2019

Отложенное копирование тел функций в OptTree-Drive (#239)

1f47f3a

Mazdaywik added a commit that referenced this issue Jul 25, 2019

Оптимизация FindOptimizedCall (#239)

5d583da

Таблица t.DriveInfo теперь не копируется, а передаётся через аккумулятор

Mazdaywik added a commit that referenced this issue Aug 1, 2019

Рефакторинг функции IsLexpr (#229, #239)

e2b50a9

Mazdaywik added a commit that referenced this issue Aug 1, 2019

Рефакторинг OptSentence-Aux (1) (#229, #239)

71e45b5

Mazdaywik added a commit that referenced this issue Aug 1, 2019

Рефакторинг OptSentence-Aux (2) (#229, #239)

c977638

Mazdaywik added a commit that referenced this issue Aug 1, 2019

FIXED: Функции Func*n не могут быть $ENTRY (#122, #239)

fa46cad

Mazdaywik added a commit that referenced this issue Aug 1, 2019

Рефакторинг после предыдущего коммита (1) (#122, #229, #239)

48afb25

Очевидные упрощения кода

Mazdaywik added a commit that referenced this issue Aug 1, 2019

Рефакторинг после предыдущего коммита (3) (#122, #229, #239)

c01deb1

Ещё один набор достаточно очевидных упрощений

Mazdaywik added a commit that referenced this issue Aug 1, 2019

Оптимизация: минимизация копирований в OptSentence (#122, #229, #239)

a19ae2b

Mazdaywik closed this as completed Aug 1, 2019

Mazdaywik mentioned this issue Aug 1, 2019

Интегрировать специализацию и прогонку #229

Closed

6 tasks

Mazdaywik added a commit that referenced this issue Aug 2, 2019

FIXED: оптимизация не падает на нативных функциях (#122, #239)

badcd75

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Ускорение работы оптимизатора прогонки #239

Ускорение работы оптимизатора прогонки #239

Mazdaywik commented Jul 4, 2019 •

edited

Loading

Mazdaywik commented Jul 25, 2019

Mazdaywik commented Jul 25, 2019 •

edited

Loading

Mazdaywik commented Jul 25, 2019

Mazdaywik commented Jul 26, 2019

Mazdaywik commented Aug 1, 2019

Mazdaywik commented Aug 1, 2019 •

edited

Loading

Mazdaywik commented Aug 1, 2019

Mazdaywik commented Aug 1, 2019

Ускорение работы оптимизатора прогонки #239

Ускорение работы оптимизатора прогонки #239

Comments

Mazdaywik commented Jul 4, 2019 • edited Loading

Mazdaywik commented Jul 25, 2019

Результаты профилирования

Что делать?

Mazdaywik commented Jul 25, 2019 • edited Loading

Mazdaywik commented Jul 25, 2019

Mazdaywik commented Jul 26, 2019

Mazdaywik commented Aug 1, 2019

Mazdaywik commented Aug 1, 2019 • edited Loading

Mazdaywik commented Aug 1, 2019

Mazdaywik commented Aug 1, 2019

Вывод

Mazdaywik commented Jul 4, 2019 •

edited

Loading

Mazdaywik commented Jul 25, 2019 •

edited

Loading

Mazdaywik commented Aug 1, 2019 •

edited

Loading