python で Too many open files2015/05/26 23:34

Raspberry Pi上で、pythonにより、センサーのデータをシリアル経由で取得してログファイルに書き出すテストプログラムを作ったが、起動して1時間程度で、プロセスが停止してしまう。
Too many open files のメッセージを出して止まる。以下試行錯誤して対処したメモ。

■実施環境
  python 2.7
  OS : Raspbian
  基盤 : Raspberry Pi model B+


エラー個所はログ出力&画面表示機能を関数化した以下を呼び出す部分で発生した。
事例についてwebを探してみると、「closeしてないよ」という指摘が多いがcloseはしている。

# -------------------------------------
# ログ出力
# -------------------------------------
def logoutput(text):
  try:
    f = open("IoTGtwlog.txt","a")
    f.write(str(text) + "\n")
    print str(text)
  except Exception as e:
    print str(e)
  finally:
    f.close()

   
次に指摘されるケースはディスクリプタの上限数がなんちゃらという指摘。
Linuxでプロセスが開けるファイルの上限は決まっている。以下の方法で確認できる。
ulimit -n
1024
この上限を増やす設定を施す事で回避する方法が各地で紹介されている。
(ファイルディスクリプタの上限数を上げる対処方法)

しかし、今回openしているファイルは1つで、try命令の中のfinallyで
openしたファイルのcloseは指定していた。にもかかわらず
Too many open files のエラーが出た。
書き方が古いようなので、withを使った書き方に変更するが同じように開始20分でToo many open files のエラーが出た。close指定したけどcloseできてない?という事で、closeできるまで待つロジックを入れてみたが、同じ結果になる。

# -------------------------------------
# ログ出力
# -------------------------------------
def logoutput(text):
  with open("IoTGtwlog.txt","a") as f:
    f.write(str(text) + "\n")
    while (f.closed != True):
      f.close()
      time.sleep(0.1)
  print str(text)


お作法に習った記述をしたにもかかわらず、Too many open files のエラーが回避できない。
よくわからないので、ファイルに自力でログを記録するのではなく、pythonが持っているロギングツールを使う。以下に使い方かわかりやすく説明されたサイトがある。こちらを元に変更する。
http://symfoware.blog68.fc2.com/blog-entry-883.html

# -------------------------------------
# ログ出力
# -------------------------------------
import logging

def logoutput(text):
  logging.basicConfig(
    level=logging.DEBUG,      #デバッグモード
    filename='IoTGtwlog.txt', #ファイル名指定
    filemode='a',             #追記モード
    format="%(asctime)s %(levelname)s %(message)s"  #フォーマット指定
    )
  logging.debug(str(text))
  print str(text)


稼働テストをした結果、ログ出力ではエラーが出なくなった。
が、今度はシリアルポートが開けないためにToo many open files のエラーが発生した。

serial.serialutil.SerialException: could not open port /dev/ttyAMA0: [Errno 24] Too many open files: '/dev/ttyAMA0'

Raspberry Piでシリアル通信する時の処理は、ファイル操作のopen closeと同じで、論理パスに対してopen/closeするので、同じ問題が起きると推測される。シリアルは通信の都度、openしてread、writeしていたが、デバッグしてみると、どうやらclose命令出してもcloseしないので、最初にopenしたままcloseしないことにした。起動してからほぼ1日放置してみたが、Too many open files のメッセージは出なくなったので、この問題はとりあえず解決とした。