로그를 어디서부터 잘라야 하는지

장치가 하루에 몇 번 재부팅되는지 세려고 device.log 를 봤다. 최근 24시간으로 잘랐더니 숫자가 매번 달랐고 언제 보느냐에 따라 다르다.

Open Table of contents

자르는 지점이 임의였다
기준점을 찾았다
다른 자료에도 기준점이 있었다
시간대를 맞추는 문제
검증 — 경계와 집계 구간
정리

자르는 지점이 임의였다

$ awk -v d="$(date -d '24 hours ago' '+%Y-%m-%d %H:%M')" '$0 >= d' device.log | grep -c BOOT

지금부터 24시간 전이다. 오후 3시에 보면 어제 오후 3시부터고 오후 5시에 보면 어제 오후 5시부터다.

구간이 겹치거나 빠지므로 같은 사건이 두 번 세어지거나 안 세어진다. awk 로 범위를 거는 줄 하나가 매번 다른 구간을 세고 있었던 것이다.

기준점을 찾았다

장치가 매일 새벽 4시에 상태를 초기화하므로 그 시점이 하루의 시작이다. BOOT 를 세는 구간도 거기에 맞춰야 했다.

$ awk '$0 >= "2016-08-21 04:00" && $0 < "2016-08-22 04:00"' device.log | grep -c BOOT

awk 범위를 04:00 으로 고정하니 매번 같은 숫자가 나온다. 주기가 있는 자료는 그 주기의 시작점에서 자른다.

다른 자료에도 기준점이 있었다

같은 문제가 여러 곳에 있었다.

자료	기준점
외부 요청 한도	상대가 정한 초기화 시각
일일 통계	자정
근무 시간 통계	오전 9시
장치 상태	새벽 4시 (초기화)

각각 다르고 자정으로 통일하면 어떤 것은 한 주기가 두 구간에 걸친다. 그래서 Python 집계 코드에 기준을 명시했다.

# 장치는 매일 04:00 에 카운터를 초기화한다. 그 시각이 하루의 경계다.
DAY_START_HOUR = 4

def day_range(d):
    start = datetime(d.year, d.month, d.day, DAY_START_HOUR)
    return start, start + timedelta(days=1)

DAY_START_HOUR 라는 이름과 주석이 없으면 왜 4시인지 모른다.

시간대를 맞추는 문제

장치는 현지 시각으로 기록하고 서버는 협정 세계시로 기록했다.

장치 로그   2016-08-22 04:00:12 BOOT
서버 로그   2016-08-21T19:00:12Z  device_reconnect

같은 사건인데 시각이 9시간 다르다. UTC 쪽을 기준으로 하고 장치 로그를 읽을 때 astimezone 으로 변환했다.

from datetime import timezone, timedelta
KST = timezone(timedelta(hours=9))

ts = datetime.strptime(line[:19], '%Y-%m-%d %H:%M:%S').replace(tzinfo=KST)
ts_utc = ts.astimezone(timezone.utc)

두 기록을 대조하려면 시간대를 먼저 맞춘다.

장치 로그에 시간대가 없어서 헷갈렸으므로 기록 형식도 바꿨다.

2016-08-22T04:00:12+09:00 BOOT

date 의 %z 로 오프셋을 붙이면 나중에 읽을 때 의심이 없다. %Z 로 약어를 남기는 방법도 있지만 같은 약어를 여러 나라가 쓰는 경우가 있어 숫자 쪽이 안전했다.

이미 쌓인 로그는 못 바꾸니 언제부터 형식이 바뀌었는지 적어 뒀다.

검증 — 경계와 집계 구간

자르는 기준을 정하고 나서 경계 근처를 확인했다.

$ grep "2016-08-22 03:5\|2016-08-22 04:0" device.log

03:59와 04:00 사이에 사건이 몰려 있는지 봤다. 초기화 직전과 직후에 뭔가 일어나면 경계 처리가 중요해진다.

이 장치는 초기화 시점에 BOOT 를 남기고 있었고 그것을 어느 날에 세는지가 문제였다.

if entry.reason == 'SCHEDULED_RESET':
    continue

초기화로 인한 재부팅은 세지 않기로 정하고 조건을 넣었다.

숫자만 내면 어느 구간인지 모르므로 집계 결과에 구간도 적었다.

2016-08-21 04:00 ~ 2016-08-22 04:00 (KST)
  재부팅 3회 (정기 초기화 1회 제외)
  통신 오류 12회
  센서 읽기 실패 4회

구간과 제외 조건을 같이 적으니 다른 사람이 같은 숫자를 다시 뽑을 수 있다.

정리

주기가 있는 자료는 그 주기의 시작점에서 자른다
최근 몇 시간은 볼 때마다 구간이 달라진다
구간이 겹치거나 빠지면 같은 사건이 두 번 세어진다
자료마다 기준점이 다르므로 자정으로 통일하면 틀린다
기준을 코드에 적고 왜 그 시각인지 남긴다
두 기록을 대조하려면 시간대를 먼저 맞춘다
기록 형식에 %z 오프셋을 넣고 %Z 약어는 겹칠 수 있다
경계 근처에 사건이 몰리는지 확인하고 제외 조건을 정한다
집계 결과에 구간과 제외 조건을 같이 적는다