サーバが夜間に Internal Server Error になり、アラートが上がってきていたので、サーバログを確認したところ、以下のエラーが発生していました。

mod_wsgi (pid=31341): Target WSGI script 'xxx/wsgi.py' cannot be loaded as Python module.   
ValueError: Unable to configure handler u'app_log_file': [Errno 13] Permission denied: u'/xxx/mezzanine_app.log'

エラーの意味は、ログの書き込み権限がないという意味になります。
夜間に何故、ログの書き込み権限がなくなった理由を記載します。夜間権限が突然なくなるのは、以下の要因で発生していました。

  1. アプリケーションのログは、ロガーでログディレクトリに書き出している。ログローテーションをしている。ログの所有者は HTTPサーバのユーザ。

  2. 一部スケジュール起動している django command がある。 起動ユーザーは root ユーザ。

アプリケーションのログの書き込みでのファイルローテーションが発生する場合は、問題ありませんでしたが、スケジュール起動している django command でローテーションが発生すると、ログファイルの所有者が root ユーザーになり、アプリケーションからの書き込みができなくなり、エラーとなりました。


解決方法

Stack Overflow で、以下記事があります。
Django の Logger 側の設定で、ローテーション前のファイルの権限を引き継ぐなどはできなそうです。1

解決方法としては以下の2つが考えられます。

  • ジョブ実行ユーザーと、アプリケーション実行ユーザーのロールを揃える。
    同じグループのユーザーであれば、ログファイルのパーミッション次第でログを書き込めるので、ジョブ実行を HTTP サーバのユーザと同じグループに所属させれば、ローテーションされても問題はなさそうです。

  • ジョブと、アプリケーションで別のログファイルに書き込むようにする。
    現状、区別なく書き込みを行っているので、ジョブとアプリケーションが書き込むログファイルを別にします。


とりあえず暫定対処

ジョブの実行ユーザは root なので、HTTP サーバ のユーザが書き込む必要のあるログのパーミッションを、スケジューラから書き換えるようにしました。

*/1 * * * * /bin/sh $SCRIPT_HOME/change_permission.sh &>> $LOG_DIR/change_permission.log # change permission
根本的な解決策ではないですが、とりあえずこれで様子を見ようかと思います。

アプリケーションユーザは作成しておいて、そのユーザで JOB 実行を行うのが理想です。
後日、ロガーの設定変更、ジョブ実行ユーザの変更は実施しようと思います。

以上です。


  1. Django というか Python というか OS 側のファイル書き込み時の動作に引きづられる動作かと思います。 

コメント