【shell script】STARTとENDのみのログファイルから経過時間を計算して出力

# ログファイルから開始・終了時刻を抽出して表にまとめたい

テーブルのloadをするジョブごとに以下のようなログファイルが生成されるとします

```shell:TABLENAME1_load.log
# iroiro
2020-08-28 00:01:00 DATA LOAD START !!!
2020-08-28 00:03:00 DATA LOAD NORMAL END !!!
# iroiro
```

```shell:TABLETAME2_load.log
# iroiro
2020-08-28 00:01:00 DATA LOAD START !!!
2020-08-28 00:10:00 DATA LOAD NORMAL END !!!
# iroiro
```

これを以下の用にまとめて出力したいです

```shell:result
JOBNAME      START     END       TIME(s)  TIME(m)
TABLENAME1   00:01:00  00:03:00  120      2
TABLENAME2   00:01:00  00:10:00  540      9
...
```

# 方法

### 概要

すべてshellで完結させられるように頑張ります！

#### INPUT

- 日付(yyyymmdd)
- ロードジョブ一覧が書かれたファイル (jobs.txt)

```shell:jobs.txt
TABLENAME1
TABLENAME2
TABLENAME3
```

- ロードジョブごとのログファイル (TABLENAME_load.<timestamp>.log)

```shell:TABLENAME1_load.20200828000100.log
# iroiro
2020-08-28 00:01:00 DATA LOAD START !!!
2020-08-28 00:10:00 DATA LOAD NORMAL END !!!
# iroiro
```

```shell:TABLENAME2_load.20200828000100.log
# iroiro
2020-08-28 00:01:00 DATA LOAD START !!!
2020-08-28 00:13:00 DATA LOAD NORMAL END !!!
# iroiro
```

```shell:TABLENAME3_load.20200828000200.log
# iroiro
2020-08-28 00:01:00 DATA LOAD START !!!
2020-08-28 00:20:00 DATA LOAD NORMAL END !!!
# iroiro
```

#### OUTPUT
- JOBNAME, START, END, TIME(s), TIME(m)の表
- ボトルネックになっているjobが特定できるように、TIMEでsortする
 

### 処理の流れ

```shell
P0. 一時テキストファイル(JOBNAME, START, END, TIME(s), TIME(m)をheaderにもつ)を作成
P1. jobs.txtの1行ロードジョブごとに
    P1.1. ログファイルがあるかどうか確認
    P1.2. ログファイルからSTARTとENDの時刻が書かれた行を抽出
    P1.3. 時刻の部分を抽出して、START\tENDの形式で変数に代入
    P1.4. start, endを変数に格納
    P1.5. 経過時間(秒)を変数に格納
    P1.6. 経過時間(分)を変数に格納
    P1.7. 4,5,6をテキストファイルの1行に格納
P1.8. ロードジョブすべてが終了したら、経過時間の降順で表形式で出力する
P1.9. 一時テキストファイルを削除する
```

### 使うもの

- sample.sh : shellscript
- jobs.txt : 対象のジョブ名が書かれたファイル
- log : yymmddでフォルダが切られていて、そこに当日実行されたログが残るような想定

```bash:terminal
$ ls -l
sample.sh
jobs.txt
log/

$ cat jobs.txt
TABLENAME1
TABLENAME2
TABLENAME3

$ ls -l log/
20200828/
20200829/

$ ls -l log/20200828/
TABLENAME1_load.20200828000100.log
TABLENAME2_load.20200828000100.log
TABLENAME3_load.20200828000100.log
TABLENAME3_load.20200828000200.log

```

# コード全体


```shell:sample.sh
#!/bin/sh

# Get the jobname from txt file
jobs=($(cat $2))

# Create tmp file with table header
echo JOBNAME START END 'TIME(s)' 'TIME(m)'  >> tmp_result.txt

for x in ${jobs[@]};
do
	if [ "$(ls log/$1/${x}_load.*)" != '' ]; then
		# Extract START and END from log file
		result=$(ls log/$1/${x}_load.* | tail -n 1 | xargs cat | grep "DATA LOAD" | cut -d' ' -f2 | echo $(tr '\n' '\t'))
		start=$(cut -d' ' -f 1 <<< $result)
		end=$(cut -d' ' -f 2 <<< $result)
		# Calc processing time
		time_s=$(expr `date -d$end +%s` - `date -d$start +%s`)
		time_m=$((time_s/60))
		# Save into txt file
		echo $x $start $end $time_s $time_m >> tmp_result.txt
	else
		echo 'there is no log file'
	fi
done 2> /dev/null

# Display result
(head -n +1 tmp_result.txt && tail -n +2 tmp_result.txt | sort -n -r -k 5) | column -t

# Remove tmp file
rm tmp_result.txt
```

# 結果

- jobごとに経過時間が分かって、どのジョブを改善すればいいか把握できそう

```bash:terminal
$ sh sample.sh 20200828 jobs.txt
JOBNAME     START     END       TIME(s)  TIME(m)
TABLENAME3  00:01:00  00:20:00  1140     19
TABLENAME2  00:01:00  00:13:00  720      12
TABLENAME1  00:01:00  00:10:00  540      9
```


# 処理の詳細

##### jobs.txtを読み込んでfor文に利用する

```shell:sample.sh
#!/bin/sh
# get the jobname from txt file
jobs=($(cat $1))
for x in ${jobs[@]};
do
        echo $x
done
```

```bash:terminal
$ sh sample.sh jobs.txt
TABLENAME1
TABLENAME2
TABLENAME3
```


##### P0. 一時テキストファイル(JOBNAME, START, END, TIME(s), TIME(m)をheaderにもつ)を作成

```shell:sample.sh
echo JOBNAME START END 'TIME(s)' 'TIME(m)'  >> tmp_result.txt
```

##### P1.1 ログファイルがあるかどうか確認

- 第一引数をyymmddに、第二引数をjobs.txtに変更
- logファイルにtimestampが入るため、ワイルドカードで存在判定をしたい
    - -eなどで判定するとunexpected operatorのエラーが出てしまう
    - lsの結果を使って判定するようにする

```shell:sample.sh
#!/bin/sh
# --
for x in ${jobs[@]};
do
	if [ "$(ls log/$1/${x}_load.*)" != '' ]; then
		echo 'log file: ' $x
	else
		echo 'there is no log file'
	fi
done
```

```bash:terminal
$ sh sample.sh 20200828 jobs.txt
log file:  TABLENAME1
log file:  TABLENAME2
log file:  TABLENAME3
```

##### P1.2. ログファイルからSTARTとENDの時刻が書かれた行を抽出

- logファイルをlist
- logファイルが複数ある場合に最新のものをとる
    - ``tail -n 1``
- 内容をcatする
    - ``xargs cat``
- "DATA LOAD"の行のみ抽出
    - ``grep "DATA LOAD"``
- ' 'で区切った2列目を抽出
    - ``cut -d' ' -f2``

```shell:sample.sh
ls log/$1/${x}_load.* | tail -n 1 | xargs cat | grep "DATA LOAD" | cut -d' ' -f2 
```

```bash:terminal
$ sh sample.sh 20200828 jobs.txt
00:01:00 # TABLE1 START
00:10:00 # TABLE2 END
00:01:00 # TABLE2 START
00:13:00 # TABLE2 END
00:01:00 # TABLE3 START
00:20:00 # TABLE3 END
```

これで各ジョブごとにSTARTとENDの``HH:mm:dd``が取得できました


##### P1.3. 時刻の部分を抽出して、START\tENDの形式で変数に代入

- 改行をタブに変換
    - ``tr '\n' '\t'``
- pipeの結果を変数に代入
    - ``result=$(process | process | process)``

```shell:sample.sh
for x in ${jobs[@]};
do
	if [ "$(ls log/$1/${x}_load.*)" != '' ]; then
		result=$(ls log/$1/${x}_load.* | tail -n 1 | xargs cat | grep "DATA LOAD" | cut -d' ' -f2 | echo $(tr '\n' '\t'))
		echo $result
	else
		echo 'there is no log file'
	fi
done
```

```bash:terminal
$ sh sample.sh 20200828 jobs.txt
00:01:00 00:10:00 # TABLENAME1
00:01:00 00:13:00 # TABLENAME2
00:01:00 00:20:00 # TABLENAME3
```

##### P1.4. start, endを変数に格納

- resultを' 'で区切った一つ目をstartに、二つ目をendに代入
    - ``start=$(cut -d' ' -f 1 <<< $result)``
    - ``end=$(cut -d' ' -f 2 <<< $result)``

```shell:sample.sh
	if [ "$(ls log/$1/${x}_load.*)" != '' ]; then
		result=$(ls log/$1/${x}_load.* | tail -n 1 | xargs cat | grep "DATA LOAD" | cut -d' ' -f2 | echo $(tr '\n' '\t'))
		start=$(cut -d' ' -f 1 <<< $result)
		end=$(cut -d' ' -f 2 <<< $result)
	else
		echo 'there is no log file'
	fi
```

##### P1.5. 経過時間(秒)を変数に格納、P1.6. 経過時間(分)を変数に格納

- ``HH:mm:ss``同士の差を計算するため、UNIX時間に変換
    - date -d$start +%s
    - date -d$end +%s
- 式を評価
    - expr

※ ここが一番詰まった

```shell:sample.sh
time_s=$(expr `date -d$end +%s` - `date -d$start +%s`)
time_m=$((time_s/60))
```

```bash:terminal
$ expr `date -d'00:01:01' +%s` - `date -d'00:00:01' +%s`
60
```

##### P1.7. 4,5,6をテキストファイルの1行に格納
```shell:sample.sh
echo $x $start $end $time_s $time_m >> tmp_result.txt
```

##### P1.8. ロードジョブすべてが終了したら、経過時間の降順で表形式で出力する

- 1行目はheaderなのでsortの対象にしない
    - ``head -n +1 tmp_result.txt && ``
- 2行目以降、5列目``TIME(m)``をキーに降順でソートする
    - ``tail -n +2 tmp_result.txt | sort -n -r -k 5``
- テーブル形式で表示
    - ``column -t``

```shell:sample.sh
(head -n +1 tmp_result.txt && tail -n +2 tmp_result.txt | sort -n -r -k 5) | column -t
```


##### P1.9. 一時テキストファイルを削除する
```shell:sample.sh
rm tmp_result.txt 
```


## おわりに

shell scriptに入門したいと思っております、より良い書き方などご意見がございましたらご教示いただけると幸いです。

## 参考

- [シェルスクリプトのファイル存在判定でワイルドカードを使いたい](https://q.hatena.ne.jp/1431508258)
- [標準出力・標準エラー出力、/dev/nullについて。](https://qiita.com/i35_267/items/158cd20ed26f73a3d894)
- [シェルで文字列を比較したときに、: =: unary operator expected :というエラーがでる](https://karoten512.hatenablog.com/entry/2018/01/19/002558)
- [How do I center-align a column in UNIX?](https://unix.stackexchange.com/questions/199940/how-do-i-center-align-a-column-in-unix)
- [dateコマンドで日時(日付、時刻)計算をする方法](https://l-w-i.net/t/shell/date_001.txt)