djangoをdockerコンテナで利用(10) – データベースにログ出力

ログって業務ではよく見るけど、個人的にはあまり見ない。
何かエラーが出た時とか、操作履歴を調べたいときとか。

テキストファイルに吐き出すとgrepできるから便利ってのもあるけど、自分はデータベースに書き出してる。

勝手に圧縮してくれるし、古いログを消したいなら書き込み日付で削除のsql発行すれば一発で終わるし。

できるだけ楽をしたいなぁって思う。

あと、テーブルを使う理由は新しい順に表示させてほしいから。
テキスト表示だと、新しい書き込みは下に追加されていく。

sortかcatの逆のtacでできるけど・・・。

linuxのlogrotate設定は、bashのスクリプト使って日次バックアップの結果ログとかで使ってはいるけど、ローテート設定面倒なのであまり好かない。
世代とかサイズとか指定してく必要がある。

アプリケーションとしては、dockerコンテナで、しかもsslをnginxを通じてdjangoのコンテナを使うとログ出力がどうなるのかやってみた。

mariadbのテーブル定義

ログは、いつ、誰が、何をした、みたいなことが残ればいい。
必要なら発行したsqlとかも入れればいいけど、そこまで必要なのは業務利用の場合かなぁ。

7年ほどphpで使ってきた仕組みをdjangoで書き換えて踏襲するので、データベースのログ保管の定義は変えない。

CREATE TABLE `GVIS_log` (
  `id` int(11) NOT NULL AUTO_INCREMENT COMMENT 'id',
  `logPeriod` datetime DEFAULT NULL COMMENT 'ログ年月日時分秒',
  `logShubetsu` char(10) DEFAULT NULL COMMENT 'ログ種別',
  `clientIP` char(15) DEFAULT '' COMMENT 'クライアントIP',
  `userID` char(32) DEFAULT '' COMMENT 'ユーザID',
  `Sousa` varchar(100) DEFAULT '' COMMENT '操作',
  `Message` varchar(10000) DEFAULT NULL COMMENT 'ログメッセージ',
  `browser` varchar(100) DEFAULT '' COMMENT '操作',
  `ins_date` datetime DEFAULT NULL COMMENT 'データ作成日',
  `ins_user` varchar(100) DEFAULT NULL COMMENT 'データ作成ユーザ',
  PRIMARY KEY (`id`),
  KEY `GVIS_log_idx` (`logPeriod`,`userID`,`Sousa`,`Message`(255),`browser`) USING BTREE
) ENGINE=InnoDB AUTO_INCREMENT=66928 DEFAULT CHARSET=utf8

django用って言うと、djangoのためにid列を追加したっけ。
テーブル定義にはオートナンバのidがつかないとdjangoは処理出来ないっていうし。

実際のログ出力

sqlで新しい順にログ表示させてみる。
そのうちdjangoで検索画面とか作らなあかんなぁ。

select * from GVIS_log order by id Desc ;

djangoのことを調べながら作った。

ログイン・ログアウト・ログイン失敗とかは後のほうにdjangoに処理追記したから上のほうに出てきてる。

実際の格納はこんな感じ。

ログ出力のための関数定義

アプリケーションのベースディレクトリにcommonってフォルダを作ってて、ログ出力のための関数をcommon.pyに書き足した。

内容はデータベースに書き出してるだけ。
内容変更したらテキストログにも書き出せると思う。

：（中略）
from ..models import GvisLog                ## DBへのログ保管のため

from ipware import get_client_ip           ## クライアント側ipアドレス取得のため

## GVHD ------------------------------------------------------------------------
## GVHD 　処理名：ログ出力処理
## GVHD ------------------------------------------------------------------------
## GVHD   処　理：gv_logwrite
## GVHD 　概　要：引数に基づいてログDBへ出力する
## GVHD 　作成日：2022/01/18
## GVHD 　更新日：
## GVHD 　引数１：種別                      (arg1 as string 例:info)
## GVHD 　引数２：httpリクエスト            (arg2 as self.request)
## GVHD 　引数３：djangoの操作              (arg3 as string)
## GVHD 　引数４：log内容                   (arg4 as string)
## GVHD 
## GVHD 　ログ内容について
## GVHD 　フィールド１：APLサーバ内yyyymmdd-hhmmss  (例: 2011-05-25 11:22:33)
## GVHD 　フィールド２：端末IDとIPアドレス          (例: 192.168.1.1)
## GVHD 　フィールド３：操作画面                    (例: 資産更新)
## GVHD 　フィールド４：ログ内容                    (任意)
## GVHD 　フィールド５：ブラウザ                    (例: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:96.0) Gecko/20100101 Firefox/96.0)
## GVHD 　返り値：なし
## GVHD 
## GVHD 　参考URL
## GVHD     https://qiita.com/3244/items/0b47d3ad91968fe15eb9
## GVHD 

def gv_logwrite(arg1,arg2,arg3,arg4):

    ## ホスト名は取れず。ルータ経由してるとクライアントIPしか入ってこないみたい
    client_addr, _ = get_client_ip(arg2,request_header_order=['HTTP_X_FORWARDED_FOR', 'HTTP_X_REAL_IP'])

    '''
    forwarded_addresses = arg2.META.get('HTTP_X_FORWARDED_FOR')
    if forwarded_addresses:
        # 'HTTP_X_FORWARDED_FOR'ヘッダがある場合: 転送経路の先頭要素を取得する。
        client_addr = forwarded_addresses.split(',')[0]
    else:
        # 'HTTP_X_FORWARDED_FOR'ヘッダがない場合: 直接接続なので'REMOTE_ADDR'ヘッダを参照する。
        client_addr = arg2.META.get('HTTP_ORIGIN')
    '''

    reqBrowser = arg2.META.get('HTTP_USER_AGENT')
    reqBrowser = 'browser' if reqBrowser is None else reqBrowser

    GvisLog.GvisLog.objects.create(
        logshubetsu=arg1[0:9],
        clientip= str(client_addr)[0:14],
        userid=str(arg2.user)[0:31],
        sousa= str(arg3)[0:99],
        message= str(arg4)[0:9999],
        browser=reqBrowser[0:99],
        ins_user=str(arg2.user)[0:31],
    )

    return True

：（中略）

httpリクエストに入っているIPアドレスの取り方がわからなかったので、ググって参考にさせていただいた。

作者さんありがとう。

DjangoでクライアントのIPアドレスを取得する - Qiita

直接アクセスのみクライアントが Django に直接アクセスすると決まっている場合は、HTTP ヘッダの'REMOTE_ADDR'を参照するだけで IP アドレスを取得することができます。fro…

qiita.com

get_client_ipを使うとIPアドレスが取れる。
使わないときの記述も試したけど、楽に書けるほうを残してコメント化した。

わざとdjangoで記述エラーを発生させてhttpリクエストの内容を確認してみた。

dockerコンテナでssl介してるから、IPアドレスはコンテナのIPアドレスか、ルータのIPアドレスしか取れんかった。

実ノードのローカルIPアドレスはhttpリクエストには入ってこず。
ホスト名もサーバ側のホスト名しか無理やった。

いつかローカルのホスト名取れるようにしたいなぁ。

アプリケーションのフォルダ階層

いっぱい入ってるので端折る。

/docker/nariDockerDat/sv_django-uwsgi-nginx/app/gvisWebApp
：（中略）
|--common
：（中略）
|  |--common.py ★ログ出力関数を追記
|--forms
|--migrations
|--models
|  |--GvisLog.py ★ログ出力テーブルを追記
|  |--GvisMaster.py
|  |--GvisZaiko.py
：（中略）
|--templates
：（中略）
|--views
：（中略）
|  |--gvis_base_views.py  ★認証したときログ出力する処理を追記
|  |--gvis_zaiko_views.py ★検索・新規登録・入力エラー・更新・削除でログ出力する処理を追記
：（中略）

ログ出力のためのmodels

inspect dbさせて自動出力されたものにdefaultとかdef __str__とか追記した。

default=timezone.nowってすると勝手に日時が入ってくれる。

from django.db import models
from django.utils import timezone
from pymysql import NULL

from datetime import datetime,timedelta     ## テーブルの日付フィールドを扱うため
from django.utils import timezone

class GvisLog(models.Model):

    logperiod = models.DateTimeField(verbose_name='ログ年月日時分秒',db_column='logPeriod', blank=True, null=True,
        default=timezone.now
    )  # Field name made lowercase.
    def __str__(self):
        return self.logperiod.strftime('%c')

    logshubetsu = models.CharField(db_column='logShubetsu', max_length=10, blank=True, null=True)  # Field name made lowercase.
    def __str__(self):
        return self.logshubetsu

    clientip = models.CharField(db_column='clientIP', max_length=15, blank=True, null=True)  # Field name made lowercase.
    def __str__(self):
        return self.clientip

    userid = models.CharField(db_column='userID', max_length=32, blank=True, null=True)  # Field name made lowercase.
    def __str__(self):
        return self.userid

    sousa = models.CharField(db_column='Sousa', max_length=100, blank=True, null=True)  # Field name made lowercase.
    def __str__(self):
        return self.sousa

    message = models.CharField(db_column='Message', max_length=10000, blank=True, null=True)  # Field name made lowercase.
    def __str__(self):
        return self.message

    browser = models.CharField(max_length=100, blank=True, null=True)
    def __str__(self):
        return self.browser

    ins_date = models.DateTimeField(verbose_name='データ作成日',db_column='ins_date', blank=True, null=True, 
        default=timezone.now
    )  # Field name made lowercase.
    def __str__(self):
        return self.ins_date.strftime('%c')

    ins_user = models.CharField(max_length=100, blank=True, null=True)

    class Meta:
        managed = False
        db_table = 'GVIS_log'

viewsに関数インポートしておく

使いたい関数は、定義をインポートしておく必要がある。

viewsのあるフォルダから見て１つ上の階層になるから、..commonって書いておき、common.pyを参照するから..common.commonって書くと、vscodeでエラーのハイライトにならず参照できた。

「何て書けばいいのかなぁ」ってときvscodeが教えてくれる。

importするのは使いたい関数を書いておく。

from ..common.common import (               ## 共通関数
    gv_logwrite,
)

関数はまだ４つほどしかないけど、これから増えてくやろなぁ。

更新・新規登録・検索画面でのログ出力

どこからでもよかったけど、viewsの最後のほうに作った更新画面から関数つめこんでいった。

まずはデータ検索したとき、正しく画面入力されて保存したとき。

def form_valid(self, form):
：（中略）

    ## ログ出力
    key = GvisZaiko.serialshubetsu + str(GvisZaiko.serialseq1) + "-" + "%06d" % (GvisZaiko.serialseq2)
    gv_logwrite('info',self.request,'dj-資産更新','(' + key + ')')

keyって箇所は例えば「GVH2014-000017」みたいなゼロ埋め編集をしてる。
C言語のprintfの書式指定は直観的にわかるので、自分にはやりやすい。
ちょっと昭和なやり方なのかもなぁ。

self.requestはhttpヘッダが入ってる。
関数の中でユーザ名とかIPアドレスとか取り出す。

「dj-資産更新」は、新規登録のとき「dj-資産新規登録」って書いてる。
djってつけているのはdjangoからの処理を明示するため。

自分だけの機能やけど、他のアプリケーションからデータベース操作させるときにも似たような区別をさせる。

次はデータ入力でエラーがあったとき。

def form_invalid(self, form, **kwargs):
：（中略）
  ## ログ出力
  context = super().get_context_data(**kwargs)
  ob_name = super().get_context_object_name(self)
  #key = GvisZaiko.serialshubetsu + str(GvisZaiko.serialseq1) + "-" + "%06d" % (GvisZaiko.serialseq2)
  key = context[ob_name].serialshubetsu + str(context[ob_name].serialseq1) + "-" + "%06d" % (context[ob_name].serialseq2) 
  gv_logwrite('error',self.request,'dj-資産更新-入力誤り','(' + key + ')')

最初は更新対象のGvisZaikoが参照できず悩んだ。

form_invalidの引数には最初**kwargsを書いてなかった。
試しに書き足したらコンテキストからkeyに入れたい値が取れるようになった。

これでいいのか？
まぁ値が取れるようになったしええか。

添付を開いた画面・削除でのログ出力

操作対象のレコードはblob列を持ってる。
その中にbase64でpdfやらjpeg画像が入っていて、ブラウザで開けるようにしてる。

それを開いた操作した時のログ出力。

def get_context_data(self, **kwargs):

    ## ログ出力
    context = super().get_context_data(**kwargs)
    ob_name = super().get_context_object_name(self)
    #key = GvisZaiko.serialshubetsu + str(GvisZaiko.serialseq1) + "-" + "%06d" % (GvisZaiko.serialseq2)
    key = context[ob_name].serialshubetsu + str(context[ob_name].serialseq1) + "-" + "%06d" % (context[ob_name].serialseq2) 
    gv_logwrite('info',self.request,'dj-資産添付' + self.request.GET['tenpu'],'(' + key + ')')

    return context

最初はこのdef記述まったく何もなくて、何をdefしたらいいのかわからなかった。
ページを開いたときに呼び出されるオーバーライド関数を調べて、get_context_dataでいいってことがわかった。

ここもモデルの名前では直接参照できなかったので、context/ob_nameを使って参照させたらログ出力できるようになった。

ログイン・ログアウトのログ出力

ログインしたときにログ出力。
最初はviewsのどこに書けばいいのかわからず。

ヒントを探したら、書いておられる方がおられた。
作者さんありがとう。

Narito Blog

Python/Djangoを中心に、プログラミングのメモや備忘録、チュートリアルを書いています。

blog.narito.ninja

from ..common.common import (               ## 共通関数
    gv_logwrite,
)

@receiver(user_logged_in)
def user_logged_in_callback(sender, request, user, **kwargs):
    ## ログ出力
    gv_logwrite('info',request,'dj-ログイン','成功')

@receiver(user_logged_out)
def user_logged_out_callback(sender, request, user, **kwargs):
    ## ログ出力
    gv_logwrite('info',request,'dj-ログアウト','')

djangoのドキュメントを見ると、シグナルっていうのがあるそうな。

Django

The web framework for perfectionists with deadlines.

docs.djangoproject.com

ログイン失敗したときのログ出力

ログイン・ログアウトだけじゃなくログイン失敗したときの記述もできるらしいのでやってみた。

：（中略）
@receiver(user_login_failed)
def user_login_failed_callback(sender, request, credentials, **kwargs):
    ## ログ出力
    gv_logwrite('info',request,'dj-ログイン失敗',credentials.get('username',None))

credentialsの中にログインしようとしたユーザ名が入ってくるみたい。
やってみたらログにちゃんと入ってた。