[mayaa-user:1037] Re: 頻繁にレンダリングを行っていると、ページのビルドが遅くなります

Susumu ISHIGAMI [E-MAIL ADDRESS DELETED]
2014年 5月 6日 (火) 22:25:44 JST


石上です

表題の件につきまして私の方で調べたことを報告いたします。
結論としては、私の予想と異なる結果でした。
それに対する解決策も私の方では思いつかず、現状、お手上げ状態です。

## 当初の予想との相違点

当初renderとbuildが互いにengineをsynchronizedして、干渉し合うことによる処理遅延と認識しておりました。
実際にJMeterで高負荷を与えるとそのように思われる挙動もありましたが、それによる影響は限定的で、
通常の負荷による処理遅延とみなせる範囲でした。

どうやら、TemplateBuilderによるビルド処理が遅いのではなく、
ビルド後初回のレンダリング処理で、スクリプトエンジンの処理が遅くなっているようです。

また、そのスクリプトエンジンの処理速度は、ヒープの状態に依存するように思います。
前回XPathの対応を行った時、GCを行った直後としばらく経過後では処理時間が異なると報告をしましたが、
それこそが今回の件の本質であったと思われます。

## CPUサンプリング結果

改めてVisualVMのサンプラーでスナップショットを解析した結果の一部を添付致します。
キャプチャではIfProcessor(の独自カスタマイズクラス)が表示されていますが、
org.seasar.mayaa.impl.cycle.script.rhino.TextCompiledScriptImpl.normalExecute()
 + org.mozilla.javascript.Context.compileString()
 + org.mozilla.javascript.gen.c****.exec()
       :
       :
のセットは兄弟に複数存在しています。
CharacterProcessor、AbstractAttributeProcessor、ExecProcessorがそのようになっており、
この例ではこれらの合計で17秒に達していました。

さらにサンプラーの設定を変更して、奥の方のクラスまで見えるよういおくまで解析してみますと、
java.lang.Class.getDeclaredConstructors0[native]()
のセルフタイムが若干多めで、800ms程度
org.mozilla.javascript.gen.c****._c**()でCPU時間を消費していました。
***のところには数字が入ります。

org.mozilla.javascript.gen.c****は動的に生成されたクラスなので、その先のボトルネックはわかりません。

## 対策の代替案と、本体コードのカスタマイズ性に対する要望

処理に時間がかかるなら、せめて処理が終わるまでの間は待つのではなくキャッシュを継続的に参照させたいのですが、
遅いのがビルドであればそれはできたのですが、renderとなると、SpecificationCacheは既に上書きされてしまっていますので
同一画面をレンダリングしようとするすべてのスレッドが、テンプレートの初回レンダリングを待ってしまいます。

これを何とかする方法はありませんでしょうか?

初回レンダリングが済んでからSpecificationCacheに格納するようなことは可能でしょうか?
SpecificationCache内のReferSpecificationがprivateであるため、
ここのカスタマイズが困難でした。

また、EngineImplの_specCache_surviveLimitがprivateであることも、
カスタマイズしづらく、これらがprotectedであれば、いろいろいじれると思います。
そもそもあまりいじるべきではないのかもしれませんが。。。。

## ビルド中はキャッシュを参照するカスタマイズの実装方法

前述のとおりこちらは作ることが出来ました。
以前メールでやりとりした方法は、ReferSpecificationがprivateである問題があるため上手くできませんでしたが、
PageImplのgetTemplateFromFixedSuffixをOverrideすることでできました。

標準ではengineをsynchronizeしていますが、
修正版では、同じsynchronizeブロックを使用するものの、内部でビルドが働く瞬間に
自分のスレッドとは別にスレッドを作成し、waitをコールして、ビルドが終わるのを待つようにします。
このようにすれば、別のテンプレートのレンダリングをすることもでき、
また、同じテンプレートもキャッシュを使用してすぐにレスポンスさせることもできます。
TemplateImplのisDeprecatedを常にfalseを返す(ビルド用のスレッドの時だけオリジナルの処理をする)
ようにもしています。

もしこの効果が劇的であれば、共有したかったのですが、前述のとおりあまり効果がなかったため、
デッドロックなどの心配もありますので、お蔵入りにしようと思います。
(どうしても自社独自のライブラリに依存するコードを書かならない箇所があったため、そのまま共有することができません)

たしかに、ビルドはsynchronizedブロックの中で行われるので、ボトルネックがbuildにあれば、
全スレッドがここで待ってしまい大変都合が悪い状態になっていました。
実際はbuildは比較的すぐに終わり、render内部のスクリプトエンジンの処理で遅延しているため、
該当のテンプレートの初回アクセスのみが遅くなったのだと思います。


以上、長々と大変失礼いたしました。
もしRhinoと現在のヒープの状態について考えられることがあれば、ご教示いただきたく思いますが、
この問題を劇的に改善する方法があるとしたら、JavaScriptコード生成時のパイプラインを大幅に変更するか、
スクリプトエンジン自体を別実装に変えてしまうしかないのではないかと思います。




2014年4月23日 8:27 suga <ko.suga @ gmail.com>:
> suga です。
>
> 概ね問題ないように見えます。
>
> isDeprecated をビルド用スレッドでのみtrueにするのは、ThreadLocal にフラグを持って、
> というところですかね。
>
> --
> suga ( ko.suga @ gmail.com )
>
>
> 2014-04-21 18:02 GMT+09:00 Susumu ISHIGAMI <susumu.ishigami @ gmail.com>:
>> 石上です。
>>
>> 以前sugaさんに下記のアドバイスを頂いた件について、実際に対応を行おうとしています。
>> もし、とても良い成果が得られれば、高負荷環境下でのMayaaの事例として、
>> 可能な限りソースなどをフィードバック致します。
>>
>>> - 更新を検出したらビルドを別スレッドで開始
>>> - ビルドが終わったのと同じ扱いで(タイムスタンプ更新)更新前のリソースで描画
>>> - 別スレッドでのビルドが終わったら差し替える
>>
>> 具体的には以下のように考えました。
>> ざっくりとした感じで申し訳ありませんが、下記1から3の対応方針に
>> おかしな点があればご指摘いただけますと幸いです。
>>
>> 1.isDeprecatedをOverride
>>   org.seasar.mayaa.impl.engine.specification.SpecificationImpl.isDeprecated()
>>   org.seasar.mayaa.impl.engine.TemplateImpl.isDeprecated()
>>   (もしかするとTemplateImplだけでも良いでしょうか。mayaaファイルの実行時更新は行いません)
>>   をOverrideしてTimestampで比較してtrueを返している条件の箇所を常にfalseを返すように変更すればよいかと思っています。
>>
>> 2.ファイル更新をフックしてEngineImpl.createSpecificationInstanceを呼び出す
>>   1.の時に更新を検知して裏でビルドを動かすような方式だと、
>>   > 更新後最初のアクセスでは必ず更新前で描画される
>>   となると思いますが、そうではなくファイルの更新をフックして、
>>   createSpecificationInstanceを呼び出せば比較的リアルタイムに引き継げるのではないかと思います。
>>
>>   問題はこの中でもspec.isDeprecatedを何度も呼んでいるので、
>>   ビルド用の別スレッドでは、isDeprecatedがfalseを返さないように調整しなければならないと思っています。
>>
>> 3.ビルド用スレッドはSingleThreadExecutorでキューイングする
>>   createSpecificationInstance以下のメソッドがsynchronizedなしに実行されますが、
>>   本来このロジックはsynchronizedされて実行されることを想定されて作られていますので、
>>   並列実行を行うと、何か問題が起きるかもしれません。
>>   別オブジェクトでsynchronizedしても良いですが、スレッドがむやみに増えてしまわないように、
>>   シングルスレッドでキューイングしようと考えてます。
>>
>> 2014年3月16日 16:21 suga <ko.suga @ gmail.com>:
>>> suga です。
>>>
>>> 高負荷サイトでは再ビルドしない設定にすることを想定した造りのため、
>>> それに対応するにはTemplateBuilderやSpecificationBuilderに手を入れる
>>> (あるいは自作する)必要があるでしょう。
>>>
>>> アプローチとしてはこの方向が良いと思います。
>>>
>>>> ・レンダリング処理時は、ビルド処理と競合するリソースについては直接参照せず
>>>>  キャッシュを参照することにして、ビルドとレンダリングを干渉させないようにする
>>>
>>> - 更新を検出したらビルドを別スレッドで開始
>>> - ビルドが終わったのと同じ扱いで(タイムスタンプ更新)更新前のリソースで描画
>>> - 別スレッドでのビルドが終わったら差し替える
>>>
>>> 当然ですが更新後最初のアクセスでは必ず更新前で描画されるなど
>>> 不便な点があるでしょう。
>>>
>>> あとsynchronizedを外せるような造りにするとより良いでしょう。
>>>
>>> --
>>> suga ( ko.suga @ gmail.com )
>>>
>>>
>>> 2014-03-15 20:41 GMT+09:00 Susumu ISHIGAMI <susumu.ishigami @ gmail.com>:
>>>> 石上です
>>>>
>>>> 連投で申し訳ありません。
>>>>
>>>> 一つのmayaaエンジンで、多数のWebページを提供しているWebサイトにて、
>>>> ローカル環境では数秒で終わっていたテンプレートのビルドに、数十秒
>>>> かかる現象を観測しています。
>>>>
>>>> おそらく、このような構成のサイトでは、ページが多い分、
>>>> 全体的にレンダリング処理が頻繁に行われていると思われます。
>>>> JMeterを使用して、ビルド済みのテンプレートをレンダリングする
>>>> 処理を頻繁に行うと、ローカル環境でも、当該テンプレートのビルド時間が
>>>> 遅くなることを確認いたしました。
>>>>
>>>> 私の推測では、Engineオブジェクトが事実上シングルトンとして実装されているため、
>>>> ビルド処理やレンダリング処理などあらゆる処理でEngineオブジェクトをsynchronizeしてしまっていて、
>>>> Engineオブジェクトのロック待ちが処理のボトルネックとなっているのではないかと思っています。
>>>>
>>>> この件について、もし何か対処法があればご教示いただけると有難いです。
>>>>
>>>> 私が思いついたアプローチとしては、
>>>>
>>>> ・レンダリング処理時は、ビルド処理と競合するリソースについては直接参照せず
>>>>  キャッシュを参照することにして、ビルドとレンダリングを干渉させないようにする
>>>>
>>>> ・ロックの範囲をテンプレートエンジン全体ではなく、フォルダ等一定のセグメントごとにロックする
>>>>
>>>> このとき、ランタイムで変更できるファイルを限定しても構いません
>>>> (例えばdefault.mayaaファイルの変更は検知しない)
>>>>
>>>> 曖昧で申し訳ありません。
>>>>
>>>> 更に情報が必要でしたら、提供致します。
>>>> 再現ソースが必要でしたら少し時間をいただければ作成致します。
>>>> _______________________________________________
>>>> mayaa-user mailing list
>>>> mayaa-user @ ml.seasar.org
>>>> https://ml.seasar.org/mailman/listinfo/mayaa-user
>>> _______________________________________________
>>> mayaa-user mailing list
>>> mayaa-user @ ml.seasar.org
>>> https://ml.seasar.org/mailman/listinfo/mayaa-user
>>
>>
>>
>> --
>> Susumu ISHIGAMI
>> susumu.ishigami @ gmail.com
>> _______________________________________________
>> mayaa-user mailing list
>> mayaa-user @ ml.seasar.org
>> https://ml.seasar.org/mailman/listinfo/mayaa-user
> _______________________________________________
> mayaa-user mailing list
> mayaa-user @ ml.seasar.org
> https://ml.seasar.org/mailman/listinfo/mayaa-user



-- 
Susumu ISHIGAMI
susumu.ishigami @ gmail.com
-------------- next part --------------
$B%F%-%9%H7A<00J30$NE:IU%U%!%$%k$rJ]4I$7$^$7$?(B...
$B%U%!%$%kL>(B: snapshot.png
$B7?(B:         image/png
$B%5%$%:(B:     57842 $B%P%$%H(B
$B @ bL@(B:       $BL5$7(B
URL:        <http://ml.seasar.org/archives/mayaa-user/attachments/20140506/43741fd3/attachment.png>


mayaa-user メーリングリストの案内