2018年7月31日

福岡拠点の宮里です。
先日、アパッチのアクセスログをアーカイブして一定期間保存する作業を行っていたのですが、

apache-loggenでダミーアクセスログの生成

ログを確認していると、何か違和感が…

|02/May/2018:09:24:59 +0000|

私「あれ？もう出社して9時間は経ってて、もう今日も終わっちまうのかなぁって気がしていたけど」

心の中の金子賢「バカヤロー、まだ始まってもいねーよ」

サーバー時刻をUTCからJSTへ変更

あれあれあれと心を鎮めながら、サーバーに設定されているタイムゾーンを確認してみると、

strings /etc/localtime

#出力結果
TZif2
TZif2
UTC0 #←これ

strings /etc/localtime

#出力結果

TZif2

UTC0 #←これ

このサーバーのタイムゾーンはUTC。
このままだとなにかと不都合です。
心臓にもわるいので、JST時間帯へ変更したいと思います。

sysconfigディレクトリの設定ファイル(clock)からタイムゾーンを修正します。
ひとまずバックアップ取って、

cp /etc/sysconfig/clock{,.orig}

#/etc/sysconfig/clockの修正
vi /etc/sysconfig/clock

#下記に追記修正
ZONE="Asia/Tokyo"
UTC=false

cp /etc/sysconfig/clock{,.orig}

#/etc/sysconfig/clockの修正

vi /etc/sysconfig/clock

#下記に追記修正

ZONE="Asia/Tokyo"

UTC=false

シンボリックリンクの向き先Asia/Tokyoへ変更します。

ln -sf /usr/share/zoneinfo/Asia/Tokyo /etc/localtime

#確認
ls -l /etc/localtime
/etc/localtime -> /usr/share/zoneinfo/Asia/Tokyo

#設定変更した時刻を確認
strings /etc/localtime

#出力結果
TZif2
TZif2
JST-9 #←これ

ln -sf /usr/share/zoneinfo/Asia/Tokyo /etc/localtime

#確認

ls -l /etc/localtime

/etc/localtime -> /usr/share/zoneinfo/Asia/Tokyo

#設定変更した時刻を確認

strings /etc/localtime

#出力結果

TZif2

JST-9 #←これ

サーバーのタイムゾーンがUTCからJSTに変わりました。

これでひと安心かと思いきや、
この作業を行う前にすでに記録されているログの時刻をJSTに修正しないと何かと収まりがわるいです。
なので、USTで記録されているログをJSTへと変換するスクリプトを作りたいと思います。

既に出力されているログの時刻をJSTへ修正

スクリプトは、サーバーに標準でインストールされているpythonで作成してライブラリをひとつだけ追加します。

pytzの取得

cd /適当なディレクトリ/

wget https://files.pythonhosted.org/packages/10/76/52efda4ef98e7544321fd8d5d512e11739c1df18b0649551aeccfb1c8376/pytz-2018.4.tar.gz

tar zxvf pytz-2018.4.tar.gz
cd pytz-2018.4
# 解凍したディレクトリから本体をコピー
cp pytz-2018.4/pytz /作業ディレクトリ/

cd /適当なディレクトリ/

wget https://files.pythonhosted.org/packages/10/76/52efda4ef98e7544321fd8d5d512e11739c1df18b0649551aeccfb1c8376/pytz-2018.4.tar.gz

tar zxvf pytz-2018.4.tar.gz

cd pytz-2018.4

# 解凍したディレクトリから本体をコピー

cp pytz-2018.4/pytz /作業ディレクトリ/

JSTへ変換するスクリプト
changeJst.py

# /usr/bin/python
# coding: utf-8
import sys
import os
import shutil
import re
import datetime
import pytz

#ディレクトリへのパス
logDirPath = '/ログのディレクトリパス/'

#正規表現
#パスにマッチ
fileNamePtn = '(access|error)_log\.[0-9]{8}$'

#ファイル名にマッチ
fileName_ptn = '.*fileName.*(access|error)_log\.[0-9]{8}$'

#access_logにマッチさせる
accsNamePtn = 'access_log\.[0-9]{8}$'
#error_logにマッチさせる
errNamePtn = 'error_log\.[0-9]{8}$'

#アクセスログ内のUTC時刻マッチ
#例:[22/May/2018:08:21:01 +0000]
accs_ptn = '[0-9]{2}/\D{3}/[0-9]{4}:[0-9]{2}:[0-9]{2}:[0-9]{2}\s\+[0-9]{4}'

#実はJST⁇の行のチェック
accs_ptn_jst = '[0-9]{2}/\D{3}/[0-9]{4}:[0-9]{2}:[0-9]{2}:[0-9]{2}\s\+0900'

#エラーログの時刻にマッチ
#例:[Tue Jun 07 15:34:25.126709 2670]
error_ptn = '\D{3}\s\D{3}\s[0-9]{2}\s[0-9]{2}:[0-9]{2}:[0-9]{2}\.[0-9]{6}\s2[0-9]{3}'

def changeJST(string):
    result = ""
    jst_time = ""
    #もしJST時刻ならスルー
    if re.search(accs_ptn_jst, string):
      return None
    #アクセスログにマッチ
    elif re.search(accs_ptn, string):
      ff = re.search(accs_ptn, string)
      utc = []
      #月
      ffDec = re.search('/\D{3}', ff.group(0))
      utc.append(ffDec.group(0)[1:])
      #日
      ffDec = re.search('[0-9]{2}', ff.group(0))
      utc.append(ffDec.group(0))
      #時間
      ffDec = re.search(':[0-9]{2}:[0-9]{2}:[0-9]{2}', ff.group(0))
      utc.append(ffDec.group(0)[1:])
      #時差
      ffDec = re.search('\+[0-9]{4}', ff.group(0))
      utc.append(ffDec.group(0))
      #年
      ffDec = re.search('2[0-9]{3}', ff.group(0))
      utc.append(ffDec.group(0))
      #並べ替え
      #形式:Nov 29 06:08:08 +0000 2006
      result = "%s %s %s %s %s" % (utc[0], utc[1], utc[2], utc[3], utc[4])
      utcDate = datetime.datetime.strptime(result, '%b %d %H:%M:%S +0000 %Y')
      jstTimezone = pytz.timezone('Asia/Tokyo')
      #Asia/Tokyoへ変換後、元のログフォーマットへ戻す
      jst_time = jstTimezone.fromutc(utcDate)
      #形式[07/Jun/2018:01:47:12 +0900]
      jst_time = jst_time.strftime('%d/%b/%Y:%X %z')
      return jst_time
    #エラーログにマッチ
    elif re.search(error_ptn, string):
      ff = re.search(error_ptn, string)
      utc = []
      #曜日
      ffDec = re.search('^\D{3}\s', ff.group(0))
      utc.append(ffDec.group(0)[:-1])
      #月
      ffDec = re.search('\s\D{3}\s', ff.group(0))
      utc.append(ffDec.group(0)[1:][:-1])
      #日
      ffDec = re.search('\s[0-9]{2}\s', ff.group(0))
      utc.append(ffDec.group(0)[1:][:-1])
      #時間
      ffDec = re.search('\s[0-9]{2}:[0-9]{2}:[0-9]{2}', ff.group(0))
      utc.append(ffDec.group(0)[1:])
      #id
      ffDec = re.search('\.[0-9]{6}', ff.group(0))
      utc.append(ffDec.group(0))
      #年
      ffDec = re.search('\s2[0-9]{3}', ff.group(0))
      utc.append(ffDec.group(0)[1:])
      
      #エラーログにマッチ
      #配列の中身の例:['Thu', 'Jun', '07', '06:35:13', '.378829', '2018']
      #並べ替え
      #形式:Nov 29 06:08:08 +0000 2006
      result = "%s %s %s +0000 %s" % (utc[1], utc[2], utc[3], utc[5])
      utcDate = datetime.datetime.strptime(result, '%b %d %H:%M:%S +0000 %Y')
      jstTimezone = pytz.timezone('Asia/Tokyo')
      #Asia/Tokyoへ変換後、元のログフォーマットへ戻す
      jst_error = jstTimezone.fromutc(utcDate)
      #形式:[Tue Jun 05 07:44:15.465239 2018]
      #Thu Jun 07 15:35:13 2018
      jst_time = jst_error.strftime('%a %b %d ')
      jst_time += jst_error.strftime('%X')
      jst_time += utc[4]
      jst_time += jst_error.strftime(' %Y')
      return jst_time
    else:
        return None

#標準入力から読込
for line in sys.stdin:    
    #オリジナルログの保存ディレクトリの作成
    #保存ディレクトリの存在チェック後、存在しなければmkdir
    if os.path.isdir("%sfileName" % logDirPath) is not True:
     os.makedirs("%sfileName" % logDirPath)
    #行末の改行を削除
    line = line.rstrip()
    #Readでオープン
    file = open(line, "r")
    newFileName = ""
    #念のためファイルの存在チェック後、
    #読み込んだファイルを保存ディレクトリへ移動
    if os.path.exists(line):
      fileName = re.search(fileNamePtn, line)
      fName = fileName.group(0)
      if re.search(fileName_ptn, line):
        fPath = "%sfileName/%s" % (logDirPath, fName)
        shutil.move(line, fPath)

      #読み込んだファイルを1行ずつ処理
      for row in file:
        #UTCからJSTへ変換する関数。JSTに変換された日付の文字列が返ってくる
        toJst = changeJST(row)
        utcToJst = ""
        if toJst is not None:
          if re.search(accsNamePtn, line):
            utcToJst = re.sub(accs_ptn, toJst, row)
          elif re.search(errNamePtn, line):
            utcToJst = re.sub(error_ptn, toJst, row)
          #新規ファイルへの書き込み。無限ループ回避の名前変更
          newFileName = line + ".log"
          newfile = open(newFileName, "a")
          newfile.write(utcToJst)
          newfile.close()
    file.close()
    #元のファイル名へ戻す
    if os.path.isfile(newFileName):      
      os.rename(newFileName, line)
    else:
      #ファイル全体で修正が無かったときに保存ディレクトリにmvしたファイルを戻す
      if re.search(fileName_ptn, line):
        fPath = "%sfileName/%s" % (logDirPath, fName)
        shutil.copy2(fPath, line)

100

101

102

103

104

105

106

107

108

109

110

111

112

113

114

115

116

117

118

119

120

121

122

123

124

125

126

127

128

129

130

131

132

133

134

135

136

137

138

139

140

141

142

143

144

145

146

147

148

149

150

151

152

153

154

155

156

# /usr/bin/python

# coding: utf-8

import sys

import os

import shutil

import re

import datetime

import pytz

#ディレクトリへのパス

logDirPath = '/ログのディレクトリパス/'

#正規表現

#パスにマッチ

fileNamePtn = '(access|error)_log\.[0-9]{8}$'

#ファイル名にマッチ

fileName_ptn = '.*fileName.*(access|error)_log\.[0-9]{8}$'

#access_logにマッチさせる

accsNamePtn = 'access_log\.[0-9]{8}$'

#error_logにマッチさせる

errNamePtn = 'error_log\.[0-9]{8}$'

#アクセスログ内のUTC時刻マッチ

#例:[22/May/2018:08:21:01 +0000]

accs_ptn = '[0-9]{2}/\D{3}/[0-9]{4}:[0-9]{2}:[0-9]{2}:[0-9]{2}\s\+[0-9]{4}'

#実はJST⁇の行のチェック

accs_ptn_jst = '[0-9]{2}/\D{3}/[0-9]{4}:[0-9]{2}:[0-9]{2}:[0-9]{2}\s\+0900'

#エラーログの時刻にマッチ

#例:[Tue Jun 07 15:34:25.126709 2670]

error_ptn = '\D{3}\s\D{3}\s[0-9]{2}\s[0-9]{2}:[0-9]{2}:[0-9]{2}\.[0-9]{6}\s2[0-9]{3}'

def changeJST(string):

result = ""

jst_time = ""

#もしJST時刻ならスルー

if re.search(accs_ptn_jst, string):

return None

#アクセスログにマッチ

elif re.search(accs_ptn, string):

ff = re.search(accs_ptn, string)

utc = []

#月

ffDec = re.search('/\D{3}', ff.group(0))

utc.append(ffDec.group(0)[1:])

#日

ffDec = re.search('[0-9]{2}', ff.group(0))

utc.append(ffDec.group(0))

#時間

ffDec = re.search(':[0-9]{2}:[0-9]{2}:[0-9]{2}', ff.group(0))

utc.append(ffDec.group(0)[1:])

#時差

ffDec = re.search('\+[0-9]{4}', ff.group(0))

utc.append(ffDec.group(0))

#年

ffDec = re.search('2[0-9]{3}', ff.group(0))

utc.append(ffDec.group(0))

#並べ替え

#形式:Nov 29 06:08:08 +0000 2006

result = "%s %s %s %s %s" % (utc[0], utc[1], utc[2], utc[3], utc[4])

utcDate = datetime.datetime.strptime(result, '%b %d %H:%M:%S +0000 %Y')

jstTimezone = pytz.timezone('Asia/Tokyo')

#Asia/Tokyoへ変換後、元のログフォーマットへ戻す

jst_time = jstTimezone.fromutc(utcDate)

#形式[07/Jun/2018:01:47:12 +0900]

jst_time = jst_time.strftime('%d/%b/%Y:%X %z')

return jst_time

#エラーログにマッチ

elif re.search(error_ptn, string):

ff = re.search(error_ptn, string)

utc = []

#曜日

ffDec = re.search('^\D{3}\s', ff.group(0))

utc.append(ffDec.group(0)[:-1])

#月

ffDec = re.search('\s\D{3}\s', ff.group(0))

utc.append(ffDec.group(0)[1:][:-1])

#日

ffDec = re.search('\s[0-9]{2}\s', ff.group(0))

utc.append(ffDec.group(0)[1:][:-1])

#時間

ffDec = re.search('\s[0-9]{2}:[0-9]{2}:[0-9]{2}', ff.group(0))

utc.append(ffDec.group(0)[1:])

#id

ffDec = re.search('\.[0-9]{6}', ff.group(0))

utc.append(ffDec.group(0))

#年

ffDec = re.search('\s2[0-9]{3}', ff.group(0))

utc.append(ffDec.group(0)[1:])

#エラーログにマッチ

#配列の中身の例:['Thu', 'Jun', '07', '06:35:13', '.378829', '2018']

#並べ替え

#形式:Nov 29 06:08:08 +0000 2006

result = "%s %s %s +0000 %s" % (utc[1], utc[2], utc[3], utc[5])

utcDate = datetime.datetime.strptime(result, '%b %d %H:%M:%S +0000 %Y')

jstTimezone = pytz.timezone('Asia/Tokyo')

#Asia/Tokyoへ変換後、元のログフォーマットへ戻す

jst_error = jstTimezone.fromutc(utcDate)

#形式:[Tue Jun 05 07:44:15.465239 2018]

#Thu Jun 07 15:35:13 2018

jst_time = jst_error.strftime('%a %b %d ')

jst_time += jst_error.strftime('%X')

jst_time += utc[4]

jst_time += jst_error.strftime(' %Y')

return jst_time

else:

return None

#標準入力から読込

for line in sys.stdin:

#オリジナルログの保存ディレクトリの作成

#保存ディレクトリの存在チェック後、存在しなければmkdir

if os.path.isdir("%sfileName" % logDirPath) is not True:

os.makedirs("%sfileName" % logDirPath)

#行末の改行を削除

line = line.rstrip()

#Readでオープン

file = open(line, "r")

newFileName = ""

#念のためファイルの存在チェック後、

#読み込んだファイルを保存ディレクトリへ移動

if os.path.exists(line):

fileName = re.search(fileNamePtn, line)

fName = fileName.group(0)

if re.search(fileName_ptn, line):

fPath = "%sfileName/%s" % (logDirPath, fName)

shutil.move(line, fPath)

#読み込んだファイルを1行ずつ処理

for row in file:

#UTCからJSTへ変換する関数。JSTに変換された日付の文字列が返ってくる

toJst = changeJST(row)

utcToJst = ""

if toJst is not None:

if re.search(accsNamePtn, line):

utcToJst = re.sub(accs_ptn, toJst, row)

elif re.search(errNamePtn, line):

utcToJst = re.sub(error_ptn, toJst, row)

#新規ファイルへの書き込み。無限ループ回避の名前変更

newFileName = line + ".log"

newfile = open(newFileName, "a")

newfile.write(utcToJst)

newfile.close()

file.close()

#元のファイル名へ戻す

if os.path.isfile(newFileName):

os.rename(newFileName, line)

else:

#ファイル全体で修正が無かったときに保存ディレクトリにmvしたファイルを戻す

if re.search(fileName_ptn, line):

fPath = "%sfileName/%s" % (logDirPath, fName)

shutil.copy2(fPath, line)

粗いスクリプトですが、ひとまず期待通りに動くことが確認できましたので、作業するサーバーのhttpdを停止してスクリプトを実行しました。ちなみにAWSのELBがunhealthyを認識して振り分けを開始するまで約1分~2分ほどかかるようです。認識する前にhttpdを止めると502で振り分けもされなくなるので注意が必要です。

処理するディレクトリのバックアップを取って実行。

#処理するファイル数の確認
find /ディレクトリ/ -type f | grep -E '.*(access|error)_log\.[0-9]{8}$' -c

#スクリプト実行
find /ディレクトリ/ -type f | grep -E '.*(access|error)_log\.[0-9]{8}$' | python /スクリプトのディレクトリ/changeJst.py > log.txt

#エラーチェックスクリプト実行
find /ディレクトリ/ -type f | grep -E '.*(access|error)_log\.[0-9]{8}$' | python /ディレクトリ/errCheck.py > errCheck0308.txt

#処理後のファイル数の確認
find /ディレクトリ/ -type f | grep -E '.*(access|error)_log\.[0-9]{8}$' -c

#差分チェック
diff -s -q -r /ディレクトリ/ /バックアップディレクトリ/ > diff.txt

diff -y /ディレクトリ/access_log.20180304 /バックアップディレクトリ/access_log.20180304.log > diff-fileName_log.txt

#処理するファイル数の確認

find /ディレクトリ/ -type f | grep -E '.*(access|error)_log\.[0-9]{8}$' -c

#スクリプト実行

find /ディレクトリ/ -type f | grep -E '.*(access|error)_log\.[0-9]{8}$' | python /スクリプトのディレクトリ/changeJst.py > log.txt

#エラーチェックスクリプト実行

find /ディレクトリ/ -type f | grep -E '.*(access|error)_log\.[0-9]{8}$' | python /ディレクトリ/errCheck.py > errCheck0308.txt

#処理後のファイル数の確認

find /ディレクトリ/ -type f | grep -E '.*(access|error)_log\.[0-9]{8}$' -c

#差分チェック

diff -s -q -r /ディレクトリ/ /バックアップディレクトリ/ > diff.txt

diff -y /ディレクトリ/access_log.20180304 /バックアップディレクトリ/access_log.20180304.log > diff-fileName_log.txt

なんとか完了です。
サーバー時刻もUTCからJSTへ変更します。
その後、httpdを再起動。
無事に現在時刻が18時に修正されました。
やっと終わっちまえます。

あれ、cronの実行がおかしい

それから様子をみること数日。
dateコマンドやログに出力される時刻はしっかりUTCからJSTに変更がされているけど、cronに設定したタスクの実行時間がおかしい！どうにも9時間遅れて実行されている！と気づきました。
調べてみるとサーバーのタイムゾーンを変更しただけではcronの実行時刻への反映がされないようです。crondを再起動してJSTタイムゾーンの反映が必要でした。。。

crontabの設定ファイルへtimezoneを記述して、crondの再起動。

vi /etc/crontab
------
#下記の行を追記
CRON_TZ=Asia/Tokyo

------

#crondの再起動
service crond restart

vi /etc/crontab

------

#下記の行を追記

CRON_TZ=Asia/Tokyo

------

#crondの再起動

service crond restart

これでcronの実行時間にもJSTが反映されました。

日: 2018年7月31日

AWSのタイムゾーン設定でハマった件

サーバー時刻をUTCからJSTへ変更

既に出力されているログの時刻をJSTへ修正

あれ、cronの実行がおかしい

[Laravel]プロジェクトの作成

2018年7月
月	火	水	木	金	土	日
						1
2	3	4	5	6	7	8
9	10	11	12	13	14	15
16	17	18	19	20	21	22
23	24	25	26	27	28	29
30	31