1. 개요
syslog 데이터를 주요 항목인 severity를 기준으로 요약하였고,
기존의 syslog에서 이벤트를 추출해 내는 25가지 룰을 기반으로 event를 정의하였다.
서버 운영자가 추출하는 event와 실제 룰을 기반으로 syslog row data에서 추출한 이벤트는 숫자가 매우 상이하다.
중복 제거나 일부 필터링 조건이 추가적으로 존재하는 것으로 판단 된다.
syslog의 serverity는 모든 log 데이터가 가지고 있는 값이나 event는 룰에 맞는 경우에만 해당 event 유형 값이
들어있다.
syslog는 단순 현상으로 결과와의 상관을 분석하기 위해 fault 데이터를 사용하였다.
사용 데이터
syslog
- 2015년 11월 data
- 3,971GB(약 4TB), 240억건
- hadoop(10대 규모)에 저장
- hive를 통해 통계데이터 생성
fault
- 2015년 11월 data
- 919KB, 1,952건
- csv 파일
주요 제약 사항
- syslog data는 2015년 11월 데이터를 사용
- syslog severity 항목중 중요도에 따라 emerg, alert, crit 유형의 데이터만 사용
주요 분석 결과
- syslog severity 값이 emerg인 값은 전체의 0.0002%로 매우 작은 비중을 차지하고 있음
- 그중 약 99.9%는 사전에 정의된 event 추출 룰에 걸리지 않았으며, 추출된 0.02%의 데이터는 모두 disk_error 유형임
- syslog severity 값이 alert인 값은 전체의 0.16% 이며, event 룰에 추출된 49%의 데이터가 모두 disk_error 유형임
- emerg의 99.9%, alert의 51%, crit의 98.9% 데이터는 기존의 event 추출룰에 매칭 되지 않음
- fault와의 단순 상관 관계를 보았을때 많은 syslog event가 많은 fault와 매칭되지 않는다.(날짜 + ip 기준으로 2%미만)
2. 분석 결과
2.1 severity
전체 syslog 데이터를 severity 기준으로 분류하여 비중을 알아보면 다음과 같다.
severity 중요도 순위는 emerg, alert, crit 이고, 전체 데이터에서 3가지 유형은 합은 0.2 % 이다.
주로 분석은 해당 3가지 유형에 집중하려 한다.
## Source: local data frame [7 x 3]
##
## severity total prop
## (fctr) (dbl) (dbl)
## 1 emerg 39380 0.000002
## 2 crit 12883235 0.000536
## 3 alert 39630043 0.001648
## 4 warning 623511091 0.025931
## 5 err 3752663597 0.156069
## 6 info 3791553949 0.157687
## 7 notice 15824596164 0.658128
severity 에서 3가지 유형만 추출해서 볼 경우 비중은 아래와 같다.
참고삼아 보면 역시 emerg는 매우 비중이 작다.
하지만 가장 중요한 내용(emerg -> System is unusable)으로 알려져 있다.
## Source: local data frame [3 x 3]
##
## severity count group_prop
## (fctr) (int) (dbl)
## 1 alert 40537082 0.7519
## 2 crit 13336093 0.2474
## 3 emerg 40709 0.0008
2.2 event
전체 syslog 데이터를 event 룰을 기반으로 추출한 값이다.
전체 비중을 살펴보면, disk_error가 96%를 차지하고 있어 대부분의 룰이 하나의 유형에 집중되어 있다.
각 event type의 업무적인 중요성 기준은 별도로 업무담당자의 코멘트가 필요하다.
## Source: local data frame [8 x 3]
##
## event_type total prop
## (fctr) (dbl) (dbl)
## 1 disk_error 75518599 0.966671
## 2 memory_error 2332185 0.029853
## 3 nic_down 108410 0.001388
## 4 nic_bandwidth 84060 0.001076
## 5 temperature_issue 49384 0.000632
## 6 oom 23750 0.000304
## 7 passwd_security 5850 0.000075
## 8 dhcp_error 90 0.000001
severity를 emerg, alert, crit 3개의 유형만 추출한 경우 그중에 확인되는 event 는 다음과 같다.
disk_error 이외의 대부분의 event는 포함되지 않는 것을 알 수 있다.
## Source: local data frame [3 x 3]
##
## event count group_prop
## (fctr) (int) (dbl)
## 1 33906701 0.63
## 2 disk_error 19987203 0.37
## 3 temperature_issue 19980 0.00
2.3 event by severity
severity별로 어떤 event로 구성되어 있는지 살펴보자
참고로 빈칸으로 표시된 부분은 기존의 syslog event 룰에 잡히지 않은 데이터들이다.
앞에서 언급한 것과 같이
syslog severity 값이 emerg인 값은 전체의 0.0002%로 매우 작은 비중을 차지하고 있음
그중 약 99.9%는 사전에 정의된 event 추출 룰에 걸리지 않았으며, 추출된 0.02%의 데이터는 모두 disk_error 유형임
syslog severity 값이 alert인 값은 전체의 0.16% 이며, event 룰에 추출된 49%의 데이터가 모두 disk_error 유형임
emerg의 99.9%, alert의 51%, crit의 98.9% 데이터는 기존의 event 추출룰에 매칭 되지 않음
## Source: local data frame [7 x 5]
## Groups: severity [3]
##
## severity event count total group_prop
## (fctr) (fctr) (int) (int) (dbl)
## 1 alert 20673431 40537082 0.5100
## 2 alert disk_error 19863651 40537082 0.4900
## 3 crit 13192569 13336093 0.9892
## 4 crit disk_error 123544 13336093 0.0093
## 5 crit temperature_issue 19980 13336093 0.0015
## 6 emerg 40701 40709 0.9998
## 7 emerg disk_error 8 40709 0.0002
2.4 severity by event
이번에는 event 별로 어떤 severity에 속한 데이터가 많은지 확인해보자
event 중에 temperature_issue 가 포함된 부분이 눈에 띈다.
## Source: local data frame [7 x 5]
## Groups: event [3]
##
## event severity count total group_prop
## (fctr) (fctr) (int) (int) (dbl)
## 1 alert 20673431 33906701 0.6097152
## 2 crit 13192569 33906701 0.3890844
## 3 emerg 40701 33906701 0.0012004
## 4 disk_error alert 19863651 19987203 0.9938184
## 5 disk_error crit 123544 19987203 0.0061812
## 6 disk_error emerg 8 19987203 0.0000004
## 7 temperature_issue crit 19980 19980 1.0000000
2.5 fault vs syslog
fault 데이터와 syslog 데이터를 함께 보면서 서로간에 어떤 상관 관계가 있는지
어떤 유형의 syslog가 fault와 관련이 높은지를 찾아보자
일별로 fault 카운트를 보면 아래와 같다. 2015년 11월 기준으로 하루 평균 53개의 fault가 발생한다.
## Source: local data frame [30 x 4]
##
## day fault_count mean deviation
## (time) (int) (dbl) (dbl)
## 1 2015-11-01 12 53 -41
## 2 2015-11-02 226 53 173
## 3 2015-11-03 50 53 -3
## 4 2015-11-04 39 53 -14
## 5 2015-11-05 95 53 42
## 6 2015-11-06 21 53 -32
## 7 2015-11-07 5 53 -48
## 8 2015-11-08 23 53 -30
## 9 2015-11-09 86 53 33
## 10 2015-11-10 47 53 -6
## .. ... ... ... ...
시간 기준으로 fault 발생 현황을 보면 오전 업무 시작시간에 발생하는 경우가 많다.
시간당 fault 발생 평균은 5.5건 이므로 30건이 넘는 시간대는 대부분 업무를 통해 등록되는 시간대일 것이다.
## function (x, ...)
## UseMethod("print")
## <bytecode: 0x0000000009b915f0>
## <environment: namespace:base>시간별 fault 건수 기준으로 히스토그램을 그려보면 역시 1~5건 내외가 가장 많은 비중을 차지한다.
날짜별로 event count와 fault count 간의 상관관계를 확인해본다.
상관관계가 높다면, syslog event의 활용이 잘 되고 있는 것으로 볼 수 있으나,
날짜별 관계에 비해 시간기준의 관계에서 매우 낮은 상관관계를 보이는 것으로 보아 전반적으로 상관관계는
무시할 만한 수준인 것으로 판단된다.
시간대 별로 한시간 안에 event_count와 fault_count 간의 상관관계를 확인해보았으나
fault가 대부분 1의 값을 가져 특별히 유의미한 결과를 보여주지는 못한다.
결국 event도 fault도 서버 단위에서 일어나는 일이므로, ip와 발생일자가 매칭되는 데이터를 찾아보았다.
빈칸으로 표시된 부분은 해당 서버에서 로그는 발생하였으나 event 룰에 걸리지는 않은 수를 의미한다.
11월 한달동안 23건의 ip, 날짜 매칭 데이터가 존재한다.
(전체 fault 1592건 대비 1.4% 매칭)
매칭 범위를 시간으로 한정할 경우 조금 숫자가 줄어 18건 정도가 된다.
## ip day event event_count fault_count
## 1 10.20.136.137 2015-11-04 1 1
## 2 10.20.137.172 2015-11-04 1 1
## 3 10.25.235.195 2015-11-10 1 2
## 4 10.97.0.70 2015-11-12 20 1
## 5 10.97.53.215 2015-11-26 1 1
## 6 10.97.66.227 2015-11-11 85 1
## 7 10.97.66.227 2015-11-11 disk_error 34 1
## 8 10.97.68.111 2015-11-26 12 1
## 9 10.97.68.111 2015-11-26 disk_error 14 1
## 10 10.97.70.41 2015-11-01 1 1
## 11 10.97.70.41 2015-11-02 1 1
## 12 10.97.70.76 2015-11-18 2 1
## 13 10.99.106.28 2015-11-18 12 1
## 14 10.99.116.60 2015-11-26 1 1
## 15 10.99.116.62 2015-11-26 1 1
## 16 10.99.116.64 2015-11-26 102 1
## 17 10.99.116.89 2015-11-16 4 1
## 18 10.99.117.33 2015-11-26 11 1
## 19 10.99.125.77 2015-11-01 3 1
## 20 10.99.80.57 2015-11-08 1 1
## 21 10.99.80.58 2015-11-08 1 1
## 22 10.99.80.59 2015-11-08 1 1
## 23 10.99.86.149 2015-11-06 1 1ip 기준으로 일간 fault는 최대 2건 이고 주로 1건 이므로 의미있는 상관관계 도표를 그리기는 어렵다.
다만, 위쪽 테이블에서 23건중에 event가 추출되고 fault도 있는 것이 단 2건 뿐이라는 점은 눈여겨 봐야한다.
그러면 os레벨에서 syslog를 분류해주는 severity 항목은 어떤 차이점을 보이는지 살펴보자
앞에서 언급한 것 처럼 중요도 순으로 emerg, alert, crit 3개의 타입만 대상으로 한다.
ip 단위로 fault가 있었던 건의 severity 레벨을 함께 보자
## ip day severity severity_count fault_count
## 1 10.20.136.137 2015-11-04 crit 1 1
## 2 10.20.137.172 2015-11-04 crit 1 1
## 3 10.25.235.195 2015-11-10 crit 1 2
## 4 10.97.0.70 2015-11-12 crit 20 1
## 5 10.97.53.215 2015-11-26 crit 1 1
## 6 10.97.66.227 2015-11-11 alert 41 1
## 7 10.97.66.227 2015-11-11 crit 75 1
## 8 10.97.66.227 2015-11-11 emerg 3 1
## 9 10.97.68.111 2015-11-26 alert 25 1
## 10 10.97.68.111 2015-11-26 crit 1 1
## 11 10.97.70.41 2015-11-01 crit 1 1
## 12 10.97.70.41 2015-11-02 crit 1 1
## 13 10.97.70.76 2015-11-18 crit 2 1
## 14 10.99.106.28 2015-11-18 crit 12 1
## 15 10.99.116.60 2015-11-26 crit 1 1
## 16 10.99.116.62 2015-11-26 crit 1 1
## 17 10.99.116.64 2015-11-26 crit 102 1
## 18 10.99.116.89 2015-11-16 alert 3 1
## 19 10.99.116.89 2015-11-16 crit 1 1
## 20 10.99.117.33 2015-11-26 alert 9 1
## 21 10.99.117.33 2015-11-26 crit 2 1
## 22 10.99.125.77 2015-11-01 crit 3 1
## 23 10.99.80.57 2015-11-08 crit 1 1
## 24 10.99.80.58 2015-11-08 crit 1 1
## 25 10.99.80.59 2015-11-08 crit 1 1
## 26 10.99.86.149 2015-11-06 crit 1 1
## fault_type
## 1 [서버] Ping Fail
## 2 [서버] Ping Fail
## 3 [서버] Ping Fail
## 4 [서버] Kernel Panic
## 5 [서버] Power Supply Error
## 6 [서버] Ping Fail
## 7 [서버] Ping Fail
## 8 [서버] Ping Fail
## 9 [서버] Kernel Panic
## 10 [서버] Kernel Panic
## 11 [서버] Kernel Panic
## 12 [서버] Ping Fail
## 13 [서버] Hang
## 14 [서버] Ping Fail
## 15 [서버] Ping Fail
## 16 [서버] Ping Fail
## 17 [서버] Ping Fail
## 18 [서버] 자동 Rebooting
## 19 [서버] 자동 Rebooting
## 20 [서버] Ping Fail
## 21 [서버] Ping Fail
## 22 [서버] Kernel Panic
## 23 [서버] Hang
## 24 [서버] Hang
## 25 [서버] Hang
## 26 [서버] Ping Fail
fault 중에 일부 건에 대해 disk_error이 매칭 되는 것을 볼 수 있다.
## ip date_hour event event_count fault_count
## 1 10.20.137.172 2015-11-04 17:00:00 1 1
## 2 10.97.0.70 2015-11-12 13:00:00 20 1
## 3 10.97.66.227 2015-11-11 09:00:00 85 1
## 4 10.97.66.227 2015-11-11 09:00:00 disk_error 34 1
## 5 10.97.68.111 2015-11-26 00:00:00 disk_error 1 1
## 6 10.97.70.41 2015-11-01 11:00:00 1 1
## 7 10.97.70.41 2015-11-02 19:00:00 1 1
## 8 10.97.70.76 2015-11-18 11:00:00 1 1
## 9 10.99.106.28 2015-11-18 14:00:00 1 1
## 10 10.99.116.60 2015-11-26 15:00:00 1 1
## 11 10.99.116.62 2015-11-26 15:00:00 1 1
## 12 10.99.116.64 2015-11-26 15:00:00 102 1
## 13 10.99.117.33 2015-11-26 18:00:00 1 1
## 14 10.99.125.77 2015-11-01 16:00:00 3 1
## 15 10.99.80.57 2015-11-08 15:00:00 1 1
## 16 10.99.80.58 2015-11-08 15:00:00 1 1
## 17 10.99.80.59 2015-11-08 15:00:00 1 1
## 18 10.99.86.149 2015-11-06 05:00:00 1 1
## fault_type
## 1 [서버] Ping Fail
## 2 [서버] Kernel Panic
## 3 [서버] Ping Fail
## 4 [서버] Ping Fail
## 5 [서버] Kernel Panic
## 6 [서버] Kernel Panic
## 7 [서버] Ping Fail
## 8 [서버] Hang
## 9 [서버] Ping Fail
## 10 [서버] Ping Fail
## 11 [서버] Ping Fail
## 12 [서버] Ping Fail
## 13 [서버] Ping Fail
## 14 [서버] Kernel Panic
## 15 [서버] Hang
## 16 [서버] Hang
## 17 [서버] Hang
## 18 [서버] Ping Fail
3. 결론
syslog는 서버의 주요 활동을 기록하고 있는 매우 소중한 데이터이다.
이러한 데이터를 통해 알수 있는 정보는 매우 많을 것이다.
몇가지 분석 데이터를 통해, syslog event로 정의된 내용이 일부 현상에 집중 되어 있고,
실제 시스템적인 결과값인 fault 데이터와 관련 되어 의미 있는 상관 관계를 찾기에
부족함이 있음을 알 수 있다.
하루에 수만대의 서버에서 syslog가 수백GB 만큼 쌓이고 있는 현 시점에서 활용도를 높이고, 운영을 위해 효율적으로 활용 할수 있는 방안을 찾을 수 있다면 매우 좋을 것이다.
event 추출 룰을 좀더 정교화 하고, fault 등록/관리를 자동화 하는 노력을 진행한다면,
유의미하게 syslog를 활용하는데 도움이 될 것이라 기대된다.