Pythonで日本語のログを出せるようにする

PaPeRo iでは現状pythonのloggingモジュールを使って日本語のログを出力しようとすると失敗します。
日本語をログ出力できるようにする方法を紹介します。

日本語のログが出せない確認

主題とは無関係なのですが、少し凝ってログローテーションでファイル出力するスクリプトで、まず日本語のログ出力が失敗することを確認してみます。
このスクリプトではログを英語、日本語、英語の順で出力しています。

from logging import (getLogger, Formatter,
                     DEBUG, INFO, WARN, ERROR, CRITICAL)
from logging.handlers import TimedRotatingFileHandler

logger = getLogger(__name__)


def test(eng):
    if eng:
        logger.debug('debug')
        logger.info('info')
        logger.warn('warn')
        logger.error('error')
    else:
        logger.debug('デバッグ')
        logger.info('情報')
        logger.warn('警告')
        logger.error('エラー')


def main():
    test(eng=True)
    test(eng=False)
    test(eng=True)


if __name__ == '__main__':
    loglevel = DEBUG
    #loglevel = INFO
    #loglevel = ERROR
    LOG_FMT = '%(asctime)s %(levelname)s %(thread)d.%(name)s.%(funcName)s %(message)s'

    toplogger = getLogger(__package__)  #top level
    toplogger.setLevel(loglevel)
    formatter = Formatter(LOG_FMT)
    logfn = 'test.log'
    fhandler = TimedRotatingFileHandler(logfn, when='D', interval=1, backupCount=3)
    fhandler.setLevel(loglevel)
    fhandler.setFormatter(formatter)
    toplogger.addHandler(fhandler)

    main()

このスクリプトをWindowsで動かすと、正常に動作します。

>python.exe filelog.py

>type test.log
2018-08-01 15:25:39,378 DEBUG 18376.__main__.test debug
2018-08-01 15:25:39,378 INFO 18376.__main__.test info
2018-08-01 15:25:39,378 WARNING 18376.__main__.test warn
2018-08-01 15:25:39,378 ERROR 18376.__main__.test error
2018-08-01 15:25:39,378 DEBUG 18376.__main__.test デバッグ
2018-08-01 15:25:39,379 INFO 18376.__main__.test 情報
2018-08-01 15:25:39,379 WARNING 18376.__main__.test 警告
2018-08-01 15:25:39,379 ERROR 18376.__main__.test エラー
2018-08-01 15:25:39,379 DEBUG 18376.__main__.test debug
2018-08-01 15:25:39,379 INFO 18376.__main__.test info
2018-08-01 15:25:39,379 WARNING 18376.__main__.test warn
2018-08-01 15:25:39,379 ERROR 18376.__main__.test error

PaPeRo iで確認します。ログファイルはカレントディレクトリになっているので、/tmpに転送してそのまま実行します。

root@aterm:/tmp# python3 filelog.py
--- Logging error ---
Traceback (most recent call last):
  File "/Extension/pkgroot/usr/lib/python3.4/logging/__init__.py", line 980, in emit
    stream.write(msg)
UnicodeEncodeError: 'ascii' codec can't encode characters in position 55-58: ordinal not in range(128)
Call stack:
  File "filelog.py", line 39, in <module>
    main()
  File "filelog.py", line 20, in main
    test(eng=False)
  File "filelog.py", line 13, in test
    logger.debug('\u30c7\u30d0\u30c3\u30b0')
Message: '\u30c7\u30d0\u30c3\u30b0'
Arguments: ()
--- Logging error ---
(略)

root@aterm:/tmp# cat test.log
2018-08-01 15:40:01,770 DEBUG 1074029136.__main__.test debug
2018-08-01 15:40:01,772 INFO 1074029136.__main__.test info
2018-08-01 15:40:01,773 WARNING 1074029136.__main__.test warn
2018-08-01 15:40:01,774 ERROR 1074029136.__main__.test error
2018-08-01 15:40:01,812 DEBUG 1074029136.__main__.test debug
2018-08-01 15:40:01,814 INFO 1074029136.__main__.test info
2018-08-01 15:40:01,815 WARNING 1074029136.__main__.test warn
2018-08-01 15:40:01,816 ERROR 1074029136.__main__.test error

日本語のログ出力で例外が発生し、ログファイルには出力されません。但し例外発生でもプログラムの実行は継続され、日本語が抜けた2回分の英語のログが残っています。

OpenWRTのchroot環境を構築する

日本語の出力が失敗するのはPaPeRo iでロケールが無効になっているためと思われます。
これを有効にするにはルートファイルシステムを書き換える必要がありますが、PaPeRo iのルートはリードオンリーのsquashfsです。
そこで、ルートを全てフラッシュにコピーし、chrootすることにします。
環境を/Extension/chroot/openwrtに作ることに決め、まず必要なファイルをコピーします。

# mkdir /Extension/chroot
# mkdir /Extension/chroot/openwrt
# cd /Extension/chroot/openwrt
# cp -a /bin /init /lib /media /nec_version.txt /overlay /rom /root /sbin /tiny2 /usr .
# mkdir dev sys tmp tiny java_cache Extension proc etc var opt

使用量はdu -s表示で47056(47MB強)でした。
chrootの準備のためのシェルスクリプトを/Extension/chroot/pre_openwrtとして作成します。

DRV=/Extension/chroot/openwrt
mount -o bind /dev $DRV/dev
mount -o bind /dev/pts $DRV/dev/pts
mount -o bind /sys $DRV/sys
mount -o bind /tmp $DRV/tmp
mount -o bind /tiny $DRV/tiny
mount -o bind /java_cache $DRV/java_cache
mount -o bind /Extension $DRV/Extension
mount -t proc none $DRV/proc
mount -o bind /etc $DRV/etc
mount -o bind /var $DRV/var
mount -o bind /opt $DRV/opt

このスクリプトを実行してからchrootします。

root@aterm:/# source /Extension/chroot/pre_openwrt
root@aterm:/# chroot /Extension/chroot/openwrt


BusyBox v1.18.5 (2016-07-08 14:47:37 JST) built-in shell (ash)
Enter 'help' for a list of built-in commands.

root@aterm:/#

ロケールを有効にする

ロケールを有効にするのに必要なファイルはOpenWRTのビルドオプションをロケール有効にしてビルドし直して生成する必要があります。
これをまとめましたのでこちらからダウンロードして/tmpに転送し、chrootしたシェルから以下の様に展開してください。

# cd /
# tar xvzf /tmp/localefiles.tar.gz

ja_JP.UTF-8ロケールをインストールします。

# ln -s /usr/share .
# mkdir -p /lib/locale/share/i18n
# localedef -i ja_JP -c -f UTF-8 -A /usr/share/locale/locale.alias ja_JP.UTF-8

ロケールをja_JP.UTF-8にセットするスクリプトを作成しておきます(/root/setja)。

export LANG=ja_JP.utf8
export LC_ALL=ja_JP.utf8
export TZ="Asia/Tokyo"

ロケールをセットしてから実行すると、pythonで日本語ログが出力されるようになります。

root@aterm:/tmp# source /root/setja
root@aterm:/tmp# python3 filelog.py
root@aterm:/tmp# cat test.log
2018-08-01 17:16:53,052 DEBUG 1074532944.__main__.test debug
2018-08-01 17:16:53,053 INFO 1074532944.__main__.test info
2018-08-01 17:16:53,057 WARNING 1074532944.__main__.test warn
2018-08-01 17:16:53,058 ERROR 1074532944.__main__.test error
2018-08-01 17:16:53,059 DEBUG 1074532944.__main__.test デバッグ
2018-08-01 17:16:53,060 INFO 1074532944.__main__.test 情報
2018-08-01 17:16:53,061 WARNING 1074532944.__main__.test 警告
2018-08-01 17:16:53,062 ERROR 1074532944.__main__.test エラー
2018-08-01 17:16:53,063 DEBUG 1074532944.__main__.test debug
2018-08-01 17:16:53,064 INFO 1074532944.__main__.test info
2018-08-01 17:16:53,065 WARNING 1074532944.__main__.test warn
2018-08-01 17:16:53,066 ERROR 1074532944.__main__.test error
root@aterm:/tmp/ppr#