From 18 Jan, 2021 0:00 UTC: All services will be temporary unavailable for maintenance

Ticket #26414

TracLightningのチューニング方法について

Open Date: 2011-09-28 02:38 Last Update: 2012-03-18 23:07

Reporter:
Owner:
(None)
Type:
Status:
Closed
MileStone:
(None)
Priority:
5 - Medium
Severity:
5 - Medium
Resolution:
None
File:
4

Details

TracLightning3.1.2を使用させていただいています。2~3ヶ月ほど前にTracの使用頻度が高いこともあり、Trac専用のサーバーを購入・移行するのと同時にTracLightning2.4系からバージョンアップしました。

このところ、チケットやwikiを表示するのに時間がかかる(4秒以上)との相談が続いているため、何とか改善を行いたいのですがの良いチューニング方法はありますでしょうか?よろしくお願いいたします。



ひとまず、OS(Windows Server 2008)での対応として、httpdのプロセスの優先度を通常から高に変更してみました。若干、レスポンスがよくなったように思いますが、状況はあまり変わっていません。また、CPU利用率も1つのコアだけに偏ってしまっており、5分平均で40~70%の使用率のコア以外は数%しか使用していませんでした。

Ticket History (3/18 Histories)

2011-09-28 02:38 Updated by: ponmiki
  • New Ticket "TracLightningのチューニング方法について" created
2011-09-28 03:08 Updated by: jun66j5
Comment

そんなに遅いのは何かおかしい気がしますね…。ざっと確認したいのが…、

  1. 作ったばかりのプロジェクトでも同様に遅いでしょうか?
  2. 有効になっているプラグインや設定を確認したいので trac.ini と httpd.conf を添付してもらえないでしょうか? (見せたくないところは適当に伏せ文字にしてもらえれば)
  3. レスポンスが遅い時がある…ではなくて常に遅いでしょうか?
  4. Google Chrome のデベロッパーツールにあるネットワークタブ (または Firefox + Firebug の同様の機能) を使ってどの URL に時間を費やしているかを特定できないでしょうか。計測結果を添付してもらってもかまいません。http://code.google.com/intl/ja/chrome/devtools/docs/network.html
  5. 管理ページも同じように遅いでしょうか? 管理ページはプラグインの影響が小さいところなのでこのページが遅いようだと根本的な要因が存在するのだと思います。

こんなところでしょうか。

2011-09-28 08:38 Updated by: okamototk
Comment

jun66j5が既にコメントしてますが、思い当たるところを書いておきます(まずはjun66j5さんのコメントを試してもらうのがいいと思います)。

  • decoratorプラグインを利用している場合、無効にする。decoratorプラグインを利用すると遅くなります。最近のTracLightningでは外していますが、、
  • avatarプラグインを無効にしてみる。タイムラインやチケットにavatarプラグインはアイコンを埋め込みますが、javascriptで遅延書き込みしているので、遅くなったような気がします(実際はUIはロックしていないので操作はできるのですが)。
  • VMなどを利用している場合
  • VM用のディスク/ネットワークドライバが入っていない(特にKVM/Xenでは明示的に入れる必要があるので遅くなるのを経験しています)
  • RAMの割り当てが足りない。最低1Gくらい欲しいです
  • submitpolicyプラグインを利用している場合外す: チケットが遅い場合ですが、submitpolicyを利用するとちょっと重くなります。

あと、秒間のアクセス頻度はどのくらいでしょうか?CPU使用率が40~70%だと、かなりアクセスがあるのではないかと思います。

2011-09-28 22:54 Updated by: ponmiki
Comment

早速の情報ありがとうございました。確認できたところからご返答させていただきます。

なお、TracLightningはVM環境ではありません。物理HWにインストールしています。
CPU Xeon 2.4GHz
RAM 3GiB
Windows Server 2008 STD SP2(32bit)

すいません。いろいろ調べているうちに思い出したのですが、以下のようなエラーが1時間あたり多いと10件くらい記録されていました。 しかし、影響がなさそうに見えたため、すっかり問題なしと思い込んでいました。

日時 : 2011/09/20 8:56:10
イベントの種類 : エラー
コンピュータ : 
ユーザー : N/A
ソース : d:\traclight\projects\trac\●●●●
カテゴリー : 0 (0)
イベントID : 1

Trac[main] ERROR: Internal Server Error: 
Traceback (most recent call last):
  File "build\bdist.win32\egg\trac\web\main.py", line 511, in _dispatch_request
    dispatcher.dispatch(req)
  File "build\bdist.win32\egg\trac\web\main.py", line 202, in dispatch
    chosen_handler)
  File "build\bdist.win32\egg\trac\web\main.py", line 344, in _pre_process_request
    chosen_handler = filter_.pre_process_request(req, chosen_handler)
  File "build\bdist.win32\egg\acct_mgr\web_ui.py", line 827, in pre_process_request
    if not req.session.authenticated:
  File "build\bdist.win32\egg\trac\web\api.py", line 216, in __getattr__
    value = self.callbacks[name](self)
  File "build\bdist.win32\egg\trac\web\main.py", line 300, in _get_session
    return Session(self.env, req)
  File "build\bdist.win32\egg\trac\web\session.py", line 192, in __init__
    if req.authname == 'anonymous':
  File "build\bdist.win32\egg\trac\web\api.py", line 216, in __getattr__
    value = self.callbacks[name](self)
  File "build\bdist.win32\egg\trac\web\main.py", line 159, in authenticate
    authname = authenticator.authenticate(req)
  File "build\bdist.win32\egg\trac\web\auth.py", line 83, in authenticate
    authname = self._get_name_for_cookie(req, req.incookie['trac_auth'])
  File "build\bdist.win32\egg\trac\web\auth.py", line 209, in _get_name_for_cookie
    db = self.env.get_db_cnx()
  File "build\bdist.win32\egg\trac\env.py", line 328, in get_db_cnx
    return get_read_db(self)
  File "build\bdist.win32\egg\trac\db\api.py", line 90, in get_read_db
    return _transaction_local.db or DatabaseManager(env).get_connection()
  File "build\bdist.win32\egg\trac\db\api.py", line 152, in get_connection
    return self._cnx_pool.get_cnx(self.timeout or None)
  File "build\bdist.win32\egg\trac\db\pool.py", line 226, in get_cnx
    return _backend.get_cnx(self._connector, self._kwargs, timeout)
  File "build\bdist.win32\egg\trac\db\pool.py", line 146, in get_cnx
    raise TimeoutError(errmsg)
TimeoutError: 0秒内にデータベースに接続できませんでした。
日時 : 2011/09/20 8:53:46
イベントの種類 : エラー
コンピュータ : 
ユーザー : N/A
ソース : d:\traclight\projects\trac\●●●●
カテゴリー : 0 (0)
イベントID : 1

Trac[main] ERROR: Internal Server Error: 
Traceback (most recent call last):
  File "build\bdist.win32\egg\trac\web\main.py", line 511, in _dispatch_request
    dispatcher.dispatch(req)
  File "build\bdist.win32\egg\trac\web\main.py", line 261, in dispatch
    req.send(output, content_type or 'text/html')
  File "build\bdist.win32\egg\trac\web\api.py", line 416, in send
    self.write(content)
  File "build\bdist.win32\egg\trac\web\api.py", line 536, in write
    self._write(data)
IOError: failed to write data
日時 : 2011/09/17 17:00:02
イベントの種類 : エラー
コンピュータ : 
ユーザー : N/A
ソース : d:\traclight\projects\trac\●●●●
カテゴリー : 0 (0)
イベントID : 1

Trac[main] ERROR: Internal Server Error: 
Traceback (most recent call last):
  File "build\bdist.win32\egg\trac\web\main.py", line 511, in _dispatch_request
    dispatcher.dispatch(req)
  File "build\bdist.win32\egg\trac\web\main.py", line 237, in dispatch
    resp = chosen_handler.process_request(req)
  File "build\bdist.win32\egg\trac\versioncontrol\web_ui\browser.py", line 393, in process_request
    file_data = self._render_file(req, context, repos, node, rev)
  File "build\bdist.win32\egg\trac\versioncontrol\web_ui\browser.py", line 652, in _render_file
    req.write(chunk)
  File "build\bdist.win32\egg\trac\web\api.py", line 536, in write
    self._write(data)
IOError: failed to write data

2011-09-28 23:07 Updated by: okamototk
Comment

最初のエラーメッセージを見て思い出したのですが、アクセスが多すぎてDBのアクセスが 追いつかなく処理が重くなることはありますね。

pool.pyの

_pool_size = int(os.environ.get('TRAC_DB_POOL_SIZE', 10))

の部分で、コネクションのプールサイズを設定しているので、ここを大きく(100とかに) すると改善されるかも知れません。

2011-09-28 23:08 Updated by: ponmiki
Comment

上記の記録されているエラーに問題ありでしたら、そもそもチューニングの話ではなかったかもしれませんね……。

>2.有効になっているプラグインや設定を確認したいので trac.ini と httpd.conf を添付してもらえないでしょうか?

上記、添付いたしました。

>3.レスポンスが遅い時がある…ではなくて常に遅いでしょうか?

今日はあまり問題なかったとのことで、常に遅いわけではないようです。



よろしくお願いします。

2011-09-29 20:33 Updated by: jun66j5
Comment

trac.ini や httpd.conf は特に問題ないと思います。

それで Windows 環境の Apache + mod_wsgi は1プロセス・マルチスレッドで実行されます。同時に実行されるスレッドは GIL により1つなので CPU が1コア分以下しか使えていないのはそういうものです。ちなみに Apache Bench で concurrent 4 にして /wiki/WikiStart にアクセスさせたら concurrent 1 のときの4倍近い時間がかかってました。

この環境下で残されたチューニングは、個々のプラグインが持っている静的ファイルを Trac に処理させないで Apache で返すようにすれば、その分 Python に処理が流れないので少し早くなると思います (F5 でリロードしたがる人には有効)。

これを施してもデータベースに接続できないエラーが出るようでしたら、環境変数 TRAC_DB_POOL_SIZE を使ってサイズを大きくしてみてください。


手順:

  1. すべての egg ファイルを展開された状態にします
    1. egg\install-eggs.cmd を編集してすべての easy_install.exe-Z オプションを付け足します。
      python\Scripts\easy_install.exe -Z egg\Babel-0.9.5-py2.6.egg
      ....
      
    2. スタートメニューから「Trac」>「コマンドプロンプト」を開きます
    3. C:\TracLight に移動して egg\install-eggs.cmd を実行します
  2. 添付ファイル chrome-paths.py を次のように実行して httpd.conf に付け足す設定を生成させます
    python\python.exe chrome-paths.py > CollabNetSVN\httpd\conf\chrome-paths.conf
    
  3. CollabNetSVN\httpd\conf\httpd.conf の WSGIScriptAlias /trac ... の真上に ↓ を足します
    Include conf/chrome-paths.conf
    
  4. traclightning サービスを再起動

別案としては IIS7, fastcgi で複数プロセスでサービスさせるとか、VirtualBox などで Linux を入れて Kanon でサービスするとかのほうがマシな気がしなくもないです。

2011-09-29 23:18 Updated by: ponmiki
Comment

>jun66j5さん
>okamototkさん

情報ありがとうございました!

TRAC_DB_POOL_SIZEですが、SQLiteのデットロックがでてサービスを再起動しないとTracにアクセスできない現象が2.4系の頃に多発していたため、100に変更済みでした。3.1.2にバージョンアップしたときも念のために100に設定していましたが、まだ足りないとの可能性があるようなので500まであげてみました。

IIS7への変更など、あまり変更してしまうとTracLightningのバージョンアップに追随できなくなりそうなので、悩ましいところですね。いただいた情報を検討してみます。できれば、別の環境でテストしてみます。

次回はkanonを検討するか、少なくともCPUはクロック数の高いものを選定するようにします。マルチコアはいきないんですね、勉強になりました。

2011-10-02 18:00 Updated by: ponmiki
Comment

>jun66j5さん

テストのためWin2003 + Trac Lightning 3.1.2で適用してみたのですが、うまくいきませんでした。

プロジェクトの一覧画面までは表示されるのですが、プロジェクト名をクリックすると、下記のようなエラーが表示されてしまいました。

Traceback (most recent call last):
  File "build\bdist.win32\egg\trac\web\api.py", line 440, in send_error
    data, 'text/html')
  File "build\bdist.win32\egg\trac\web\chrome.py", line 833, in render_template
    data = self.populate_data(req, data)
  File "build\bdist.win32\egg\trac\web\chrome.py", line 756, in populate_data
    'locale': req and req.locale,
  File "build\bdist.win32\egg\trac\web\api.py", line 216, in __getattr__
    value = self.callbacks[name](self)
  File "build\bdist.win32\egg\trac\web\main.py", line 311, in _get_locale
    req.languages)
  File "build\bdist.win32\egg\trac\util\translation.py", line 347, in get_negotiated_locale
    normalize(get_available_locales()), sep='-')
  File "build\bdist.win32\egg\babel\core.py", line 185, in negotiate
    return Locale.parse(identifier, sep=sep)
  File "build\bdist.win32\egg\babel\core.py", line 212, in parse
    return cls(*parse_locale(identifier, sep=sep))
  File "build\bdist.win32\egg\babel\core.py", line 137, in __init__
    raise UnknownLocaleError(identifier)
UnknownLocaleError: unknown locale 'ja'

もう一度やりなおしたのですがダメで、ダメもとで次の変更を行いました。easy_installの展開先がDocument and Settings\Administrator\Application Data\Pyhon-Eggs\以下に書き出されていました。
フォルダをTracLightning用フォルダ以下にフォルダを作って移動。chrome-paths.confのファイルパスを上記にあわせ修正したくらいです。

お忙しいところすみませんが、アドバイスいただけると幸いです。

2011-10-03 13:15 Updated by: jun66j5
Comment

生成した chrome-paths.conf の中に %USERPROFILE%\Application Data\Python-Eggs があるということは python\lib\site-packages にある egg ファイルを展開した状態になっていないのではないでしょうか (setuptools-0.6c11-py2.6.egg は除く)。なんとなく -Z オプションを最初の1行にだけ付けた、もしくは traclightning サービスが起動していて書き換えに失敗したのかどちらかのような気がします。実行前に traclightning サービスは停止させてみてください。

あと、念のため 3.1.2 から抜き出した egg\install-eggs.cmd に -Z を書きたしたファイルを添付しておきました。

これを実行したあとに python\lib\site-packages\ 配下に setuptools-0.6c11-py2.6.egg 以外の *.egg ファイルがすべてディレクトリになっていない場合は何かに失敗しています。

どうしてもうまく行かないようでしたら egg\install-eggs.cmd >install-eggs.log 2>&1 で実行結果をいただけますか?

2011-10-04 21:59 Updated by: ponmiki
Comment

>jun66j5さん

アドバイスありがとうございました。うまく動作するようになりました。本当にありがとうございました!
install-eggs.cmdですが、オプションをzとしていました。Zに修正したところ、正しく動作するようになりました。

ちなみに、今後TracLightningをバージョンアップした場合、基本的にはバージョンアップ作業後に上記の egg ファイルを展開、chrome-paths.confの更新、サービスの再起動をすれば動作するはずですよね?
万一、ダメならhttpd.confを元に戻す、と。

参考までにApache Benchの結果です。別セグメントのWin 2003 R2(他に稼働しているサービスあり)+TracLightning3.1.2に対して、リクエスト 100 同時接続 10でSample ProjectのTOP(wiki)にアクセスしました。それぞれ3回テストし、効果を確認できました。

・標準の状態
Requests per second: 2.57~2.72 [#/sec]

・TRAC_DB_POOL_SIZE=500
Requests per second: 2.83~2.86 [#/sec]

・POOL_SIZE=500 + eggファイルを展開
Requests per second: 3.11~3.14 [#/sec]

2011-10-05 10:46 Updated by: jun66j5
Comment

ちなみに、今後TracLightningをバージョンアップした場合、基本的にはバージョンアップ作業後に上記の egg ファイルを展開、chrome-paths.confの更新、サービスの再起動をすれば動作するはずですよね?
万一、ダメならhttpd.confを元に戻す、と。

はい。それで問題ないです。

ちなみに 3.1.3 以降は egg ファイルは展開した状態でインストールするようにしています (最近変更しました)。 なので 3.1.3 以降の場合は chrome-paths.conf 生成以降の手順を行なってもらえればよいです。

それと、別のプラグインを導入するときは -Z オプション付きで easy_install を実行し、chrome-paths.conf を再生成するとよいです。

参考までにApache Benchの結果です。別セグメントのWin 2003 R2(他に稼働しているサービスあり)+TracLightning3.1.2に対して、リクエスト 100 同時接続 10でSample ProjectのTOP(wiki)にアクセスしました。それぞれ3回テストし、効果を確認できました。
...

少し早くなっていますね。これは egg ファイルを展開した効果だと思います。

chrome-paths.conf の効果は、ブラウザを使ってアクセスしたときに *.{css,js} などの静的ファイルを早く返却することで、その分早くなったように感じることを期待しています。

2011-10-06 19:29 Updated by: ponmiki
  • Ticket Close date is changed to 2011-10-06 19:29
  • Status Update from Open to Closed
Comment

>jun66j5さん
>okamototkさん

ご返答ありがとうございました。非常に助かりました。プラグインなどOFFにできそうなものがあれば、OFFにしてみます。
今後ともよろしくお願いします。

2012-03-18 23:07 Updated by: ponmiki
Comment

今更ですが、もう少し改善しましたのでご報告だけさせて下さい。

Windows 2003 R2でPOOL_SIZE=1000にし、eggファイルを展開してベンチをとりました。

・POOL_SIZE=1000 + eggファイルを展開

Requests per second: 約5 #/sec (/newticket に対して実施)

というところまで改善しました。ただ、OSがWindows 2008では変わらず3でした。 また、POOL_SIZEを3000まであげてみましたが、5以上にはなりませんでした。 ※POOL_SIZEをこんなに大きくしていいのかという疑問もありますが。

ご指摘の通り、KanonをPCにインストールしてベンチとったら15以上でました。

Attachment File List

  • trac-ini.txt(3KB)
    • trac.iniのコピペです。よろしくお願いします。
  • httpd-conf.txt(21KB)
    • httpd.confです。こちらは、デフォルトから変更していないはずです。
  • chrome-paths.py(1KB)
  • install-eggs.cmd(3KB)
    • 変更後の egg\\install-eggs.cmd ファイル (3.1.2 ベース)

Edit

Please login to add comment to this ticket » Login