2016년 3월 10일 목요일

LogParser 활용(Web Log 이상징후 분석 - 3rd)

오늘은 500 응답코드의 급증 원인을 확인해보자. 일단 500 응답코드를 발생시킨 출발지 IP와 해당 IP가 접근을 시도한 웹 문서(URL) 현황은 다음과 같다.

접근 IP 내역

접근 웹 문서 내역

'192.168.57.110(가장 많은 404 응답코드를 발생시킨 IP)', '192.168.175.190' 2개의 출발지에서 4개의 웹 문서, 그중 대부분이 'view.asp'에 접근하는 과정에서 500 응답코드가 발생했다. 어떤 요청을 했길래 웹서버가 '처리 실패' 메시지를 토해냈을까?

'cs-uri-stem'은 사용자가 최종 접근한 웹 문서, 즉 URL 정보를 저장하고, 'cs-uri-query'는 해당 웹 문서에 대한 사용자의 여러가지 요구사항이 반영된 '변수=값' 정보를 저장한다.

웹서버는 '변수=값' 정보의 처리 결과를 웹 문서에 반영해서 사용자에게 제공하기 때문에, 웹서버의 '처리 실패' 원인을 찾으려면 사용자의 세부 요구사항 정보, 즉 'cs-uri-query' 영역에 담긴 정보를 보면 된다.


참고로 Windows 웹서버는 500 에러 발생 시 웹로그의 'cs-uri-query' 영역에 '변수=값'과 '웹 애플리케이션 에러 메시지'를 '|'로 구분해서 같이 기록한다. 당연히 분리해서 보는 게 편하다.
id=784%20and%201=1|514|80040e14|키워드_'and'_근처의_구문이_잘못되었습니다.

① select extract_token(cs-uri-query,0,'|'), extract_token(cs-uri-query,3,'|'), count(*)
② from d:\ex.log
③ where sc-status = 500
    and extract_filename(cs-uri-stem) = 'view.asp'
    and to_string(time, 'hh:mm') >= '15:30'
    and to_string(time, 'hh:mm') <= '17:00'
④ group by extract_token(cs-uri-query,0,'|'), extract_token(cs-uri-query,3,'|')
⑤ order by count(*) desc


일단 에러 메시지만 있는 로그는 '변수=값' 정보 전송 시 URI를 이용하지 않는 POST 메소드 사용 때문으로 추정되며, 나머지 로그는 변수 영역에 사용된 'drop%20table' 등의 문자열로 봤을 때 Sql Injection 공격 시도가 의심된다. 500 응답코드가 급증하기 전 시간대와 비교를 해보자.



15:30분 전까지 접근 시도가 있었던 URL, 즉 웹 문서는 'download.asp'와 'view.asp' 단 2개이며, 그중 90%가 'download.asp'. 에러 메시지 역시 'download.asp'에서 발생한 '파일을 열 수 없다'는 에러 메시지가 대부분이다.

파일 다운로드 과정의 오류로 인한 500 응답코드 발생을 추정해볼 수 있으며, 15:30분 이후와는 확연히 대비되는 발생 양상임을 알 수 있다.

Sql Injection 공격 시도가 의심된다고 했는데 어떤 식의 공격 시도가 있었는지 확인해보자. 그러기 위해서는 변수 영역에 사용된 공격 문자열만을 분리해야 한다.

Sql Injection 공격은 일반적으로 쿼리문에 사용되는 '마지막 변수의 값'을 조작한다는 것이 힌트. '마지막 변수의 값'만을 추출해보자.

① 'extract_token' 함수를 이용해서 'cs-uri-query' 영역 데이터 중 '변수=값&변수=값'만을 추출한 후, (웹 애플리케이션 에러 메시지 제외)

② 'extract_suffix' 함수를 이용해서 '&'를 기준으로 마지막 데이터만을 다시 추출하면 된다. ('&'가 없으면 'extract_suffix' 함수는 전체 데이터를 반환함)


① select extract_suffix(extract_token(cs-uri-query,0,'|'),0,'&'), count(*)
② from d:\ex.log
③ where sc-status = 500
    and extract_filename(cs-uri-stem) = 'view.asp'
    and to_string(time, 'hh:mm') >= '15:30'
    and to_string(time, 'hh:mm') <= '17:00'
④ group by extract_suffix(extract_token(cs-uri-query,0,'|'),0,'&')
⑤ order by count(*) desc

사용된 변수의 정확한 현황을 파악해보자. 'extract_token' 함수를 이용해서 이전 쿼리문 결과 중 '='을 기준으로 첫 번째 데이터만 추출하면 된다.


① select extract_token(extract_suffix(extract_token(cs-uri-query,0,'|'),0,'&'),0,'='), count(*)
② from d:\ex.log
③ where sc-status = 500
    and extract_filename(cs-uri-stem) = 'view.asp'
    and to_string(time, 'hh:mm') >= '15:30'
    and to_string(time, 'hh:mm') <= '17:00'
④ group by extract_token(extract_suffix(extract_token(cs-uri-query,0,'|'),0,'&'),0,'=')
⑤ order by count(*) desc

'vod_id'와 'cate_id', 2개의 변수를 대상으로 쿼리문 조작 시도가 있었음을 알 수 있다. 해당 변수의 값과 Sql Injection 공격 문자열을 정확히 분리하려면 정상적으로 변수에 사용된 값의 형식을 알아야 한다. (문자형인지, 숫자형인지 등)

200 응답코드가 발생했을 때, 즉 정상적인 상황에서 해당 변수에 사용된 값을 확인해보자.



해당 변수는 모두 숫자형의 값을 사용한다. 이제 '변수=숫자값' 영역만 구분해주면 Sql Injection 공격 문자열만을 정확하게 분리할 수 있다.

VIM 정규표현식 '\v^(vod_id|cate_id)\=(\d+|\d{-})'는 'vod_id=' 또는 'cate_id=' 이후 숫자가 이어지거나 또는 아예 값이 없는 패턴만을 검색 및 구분해준다.



엑셀의 '텍스트 나누기' 기능을 이용하여 '변수=숫자값' 영역과 Sql Injection 공격 문자열을 구분한 결과는 다음과 같다.


그런데 공격 문자열 해독(?)이 좀 어렵다. URI 영역은 HTML 태그 등과의 혼동을 막기 위해 몇몇 기호들을 인코딩 처리하기 때문.

이 때 '%20(공백)' 등 자주 쓰이는 인코딩 문자를 디코딩해주면 읽기가 좀 수월해진다. 엑셀의 '찾기 및 바꾸기' 기능을 이용하면 되며, 자주 사용되는 인코딩 문자와 디코딩 결과는 다음과 같다.



확인 결과 'view.asp'에서 발생한 500 응답코드는 전부 Sql Injection 공격 시도에 의해 발생한 것으로 밝혀졌다. 뻔한 공격 패턴을 이용해서 데이터베이스 구조 파악이나 계정 정보 추출, 조작 등을 시도하는 소위 Blind Sql Injection 공격.

웹 로그에 이 정도 흔적이 남았다면 IDS나 IPS, 웹방화벽 등의 보안장비에는 훨씬 더 많은 로그가 남았을 것이고, 아마 차단도 꽤 많이 했을 것이다.

하지만 해당 로그를 남긴 웹서버는 관리자 계정이 노출되고, 웹쉘이 업로드 되는 등 만신창이가 돼버렸다. 뭐가 문제였을까?

관련 글

댓글 없음:

댓글 쓰기

크리에이티브 커먼즈 라이선스