1

EC2上のUbuntu11.04上のtornado2.4で実行されているアプリのトラブルシューティングを試みています。定期的に100％CPUに到達しているようで、その要求で数秒間停止します。

これに関するどんな助けも大いに感謝されます。

症状：

  • topは、停止した時点で100％のCPUを示しています。通常、サーバーのCPU使用率は約30〜60％です。
  • 1回のリクエストで2〜5分ごとに停止します。これに影響を与えるcronジョブがないことを確認しました。
  • 約2〜9秒間停止します。竜巻を再開すると問題はなくなり、竜巻の稼働時間とともに悪化します。サーバーが稼働している時間が長いほど、サーバーは停止します。
  • 問題が発生しているHttpリクエストにはパターンがないようです。
  • 興味深いことに、ログ内の次のリクエストは、停止期間と一致する場合と一致しない場合があります。例：
00:00:00      GET /some/request ()
00:00:09      GET /next/request (9000ms)

00:00:00     GET /some/request ()
00:00:09     GET /next/request (1ms)
# 9 seconds gap in requests is certainly not possible as clients are constantly polling.
  • データベース（mongodb）は、高価なクエリや多数のクエリを表示しません。ページフォールトはありません。データベースは同じマシン（ローカルディスク）にあります。
  • vmstatは、過去数分間と比較して読み取り/書き込みサイズに変化がないことを示しています。

  • 竜巻はnginxの背後で実行されています。

  • 停止している可能性が最も高いときにSIGINTを送信すると、毎回異なるスタックトレースが得られます。それらのいくつかを以下に示します。

Traceback (most recent call last):
  File "chat/main.py", line 3396, in <module>
    main()
  File "chat/main.py", line 3392, in main
    tornado.ioloop.IOLoop.instance().start()
  File "/home/ubuntu/tornado/tornado/ioloop.py", line 515, in start
    self._run_callback(callback)
  File "/home/ubuntu/tornado/tornado/ioloop.py", line 370, in _run_callback
    callback()
  File "/home/ubuntu/tornado/tornado/stack_context.py", line 216, in wrapped
    callback(*args, **kwargs)
  File "/home/ubuntu/tornado/tornado/iostream.py", line 303, in wrapper
    callback(*args)
  File "/home/ubuntu/tornado/tornado/stack_context.py", line 216, in wrapped
    callback(*args, **kwargs)
  File "/home/ubuntu/tornado/tornado/httpserver.py", line 298, in _on_request_body
    self.request_callback(self._request)
  File "/home/ubuntu/tornado/tornado/web.py", line 1421, in __call__
    handler = spec.handler_class(self, request, **spec.kwargs)
  File "/home/ubuntu/tornado/tornado/web.py", line 126, in __init__
    application.ui_modules.iteritems())
  File "/home/ubuntu/tornado/tornado/web.py", line 125, in <genexpr>
    self.ui["_modules"] = ObjectDict((n, self._ui_module(n, m)) for n, m in
  File "/home/ubuntu/tornado/tornado/web.py", line 1114, in _ui_module
    def _ui_module(self, name, module):
KeyboardInterrupt

Traceback (most recent call last):
  File "chat/main.py", line 3398, in <module>
    main()
  File "chat/main.py", line 3394, in main
    tornado.ioloop.IOLoop.instance().start()
  File "/home/ubuntu/tornado/tornado/ioloop.py", line 515, in start
    self._run_callback(callback)
  File "/home/ubuntu/tornado/tornado/ioloop.py", line 370, in _run_callback
    callback()
  File "/home/ubuntu/tornado/tornado/stack_context.py", line 216, in wrapped
    callback(*args, **kwargs)
  File "/home/ubuntu/tornado/tornado/iostream.py", line 303, in wrapper
    callback(*args)
  File "/home/ubuntu/tornado/tornado/stack_context.py", line 216, in wrapped
    callback(*args, **kwargs)
  File "/home/ubuntu/tornado/tornado/httpserver.py", line 285, in _on_headers
    self.request_callback(self._request)
  File "/home/ubuntu/tornado/tornado/web.py", line 1408, in __call__
    transforms = [t(request) for t in self.transforms]
  File "/home/ubuntu/tornado/tornado/web.py", line 1811, in __init__
    def __init__(self, request):
KeyboardInterrupt

Traceback (most recent call last):
  File "chat/main.py", line 3351, in <module>
    main()
  File "chat/main.py", line 3347, in main
    tornado.ioloop.IOLoop.instance().start()
  File "/home/ubuntu/tornado/tornado/ioloop.py", line 571, in start
    self._handlers[fd](fd, events)
  File "/home/ubuntu/tornado/tornado/stack_context.py", line 216, in wrapped
    callback(*args, **kwargs)
  File "/home/ubuntu/tornado/tornado/netutil.py", line 342, in accept_handler
    callback(connection, address)
  File "/home/ubuntu/tornado/tornado/netutil.py", line 237, in _handle_connection
    self.handle_stream(stream, address)
  File "/home/ubuntu/tornado/tornado/httpserver.py", line 156, in handle_stream
    self.no_keep_alive, self.xheaders, self.protocol)
  File "/home/ubuntu/tornado/tornado/httpserver.py", line 183, in __init__
    self.stream.read_until(b("\r\n\r\n"), self._header_callback)
  File "/home/ubuntu/tornado/tornado/iostream.py", line 139, in read_until
    self._try_inline_read()
  File "/home/ubuntu/tornado/tornado/iostream.py", line 385, in _try_inline_read
    if self._read_to_buffer() == 0:
  File "/home/ubuntu/tornado/tornado/iostream.py", line 401, in _read_to_buffer
    chunk = self.read_from_fd()
  File "/home/ubuntu/tornado/tornado/iostream.py", line 632, in read_from_fd
    chunk = self.socket.recv(self.read_chunk_size)
KeyboardInterrupt

これをトラブルシューティングする方法に関するヒントは大歓迎です。

さらなる観察：

  • strace -pは、ハングしている間、空の出力を示します。

  • ハング時間中のltrace-pは、多数のfree（）呼び出しのみを示します。free（0x6fa70080）= free（0x1175f8060）= free（0x117a5c370）=

4

1 に答える 1

3

ガベージコレクション（GC）ストームに苦しんでいるようです。あなたが説明した振る舞いはその診断の典型であり、ltraceはさらに仮説をサポートします。

多くのオブジェクトが、使用によって実行されているメイン/イベントループで割り当てられ、破棄されています...そしてfree（）への呼び出しの定期的な急増はそれから生じます。

考えられるアプローチの1つは、コード（または依存しているライブラリ）のプロファイルを作成し、事前に割り当てられたプールのオブジェクトを使用（および再利用）するためにコードをリファクタリングできるかどうかを確認することです。

もう1つの考えられる緩和策は、ガベージコレクションをトリガーするために独自のより頻繁な呼び出しを行うことです---全体としてはより高価ですが、各呼び出しでより安価になる可能性があります。（これは、より予測可能なスループットとのトレードオフになります）。

Python：gcモジュールを使用して、問題をより深く調査するため（gc.set_debug（）を使用）と、単純な軽減の試み（たとえば、各トランザクションの後にgc.collect（）を呼び出す）の両方に使用できる場合があります。また、 gc.disable（）を使用してアプリケーションを妥当な時間実行して、Pythonガベージコレクターがさらに関係しているかどうかを確認することもできます。ガベージコレクターを長期間無効にすると、ほぼ確実にページング/スワッピングが発生することに注意してください...したがって、仮説の検証にのみ使用し、意味のある方法で問題を解決することを期待しないでください。システム全体がスラッシングし、再起動が必要になるまで、問題を延期する可能性があります。

Tornadoの別のSOスレッドでgc.collect（）を使用する例を次に示します。SO ：ドロップされた接続でのTornadoメモリリーク

于 2013-02-28T21:52:26.217 に答える