본문 바로가기

기술빙자사기

sendmail 로그분석 스팸 탐지 관련 삽질

################################################################3
### 쓴것 : Sendmail 로그분석 스팸 탐지 관련 삽질
### 쓴이 : 권성재(nonots@hanmail.net, http://www.badaweb.co.kr)
### 쓴때 : 2011-12-02
################################################################3

1. 개요

서버관리자들에게 있어서 스팸메일 보내는 인간들은 때려죽이고 싶은 충동을 
불러일으킵니다.
다른 해킹과 달리 스팸공격하는 건 로그분석해서 찾기도, 막기도 어렵습니다.
더구나, 많은 스팸이 한메일이나 네이버,구글 메일서버로 보내지다 보니,
한메일이나 네이버 메일서버 측에서 멀쩡한 메일서버 ip 를 차단해서
선량한 일반 메일 사용자들이 메일이 발송되지 않아 피해를 입습니다.
아래에,
리눅스 서버에서 sendmail 데몬 관련해서 삽질하면서 알게 된 정보를 공개합니다. 
허접합니다만, 나보다 더 허접한 관리자들에게 조금이나마 도움이 되었으면 합니다.


2. 서버환경
	- OS : CentOs 5.x (레드햇 계열)
	- Sendmail 버전 : 12.x, 13.x
	- POP3 데몬 : dovecot, qpopper 등
	- 메일 로그 파일 : /var/log/maillog


3. 웹소스 통한 스팸 발송 관련

	- 그누보드나 제로보드등 웹사이트 게시판의 첨부파일 업로드 기능의 헛점을
	이용해서 서버에 .php 같은 실행파일을 저장한 후 외부에서 이 파일을 통해서 
	스팸을 발송하는 방법입니다.
	문제는, 이렇게 웹경로에 업로드한 후 스팸메일을 보내면 해당 서버에 있는 sendmail 
	로그에 잘 기록이 안됩니다.	
	php 모듈이 웹서버권한을 이용해서 막바로 보내므로 특정 사용자 계정을
	알수가 없습니다. 또 한 외부 서버에 포트 접속해서 발송한다면 내부 메일서버에는
	기록이 남지 않게됩니다.
	이건 maillog 분석으로는 알기어렵고, 반드시 무단으로 업로드된 해킹 파일을
	찾아서 삭제해야 합니다.
	여기서는 간단한 방법만 소개합니다.
	
	만약 웹로트가 /home/mywebsite_home/public_html 인 곳에 그누보드가 설치됐고
	freeboard 라는 게시판아이디를 사용했다면
	/home/mywebsite_home/public_html/data/file/freeboard 이곳에 첨부파일이 
	저장되므로 보통 이런 곳에 해킹파일이 업로드 됩니다.

	# pwd 
	/home/mywebsite_home/public_html/data/file/freeboard 
	# ls *.php
	Iist.php corp.php meixia.php each.php dm.php yh.php lele.php  mem.php

	와 같이 게시판 저장경로에 이상한 php 파일이 저장되어 있으면 해킹당한겁니다.
	파일 이름과 확장자는 수시로 바뀌더군요.
	http://mywebsite.co.kr/data/file/freeboard/lele.php
	같이 웹접속 해서 불순한 짓을 쥐도새도 모르게 하게 됩니다.

	- 일단 http://www.krcert.or.kr/index.jsp 에 있는 whistl 같은 도구로
	웹루트 디렉토리의 전체 소스를 점검해서 해킹된 파일을 점검해 보는 것이
	좋습니다.  사용법은 위 사이트를 참조하시기 바랍니다.

	- 가장 강력한 해결책은 위 첨부파일이 저장되는 웹서버의 data 같은 디렉토리에서 
	php 같은 서버 사이드 스크립트가 실행이 안되게 해야 합니다.
	data 디렉토리 안에 .htaccess 파일을 아래와 비슷하게 시행안될 확장자를 지정해서
	생성합니다.
	
	# cat .htaccess 
	<FILES ~ "\.ph(p[2-6]?|tml)$|\.htm$|\.html$|\.inc$"> 
			Order allow,deny 
			Deny from all 
	</Files> 
	와 같이 넣어두면 위에 나열된 확장자 파일에 대한 접근이 거부되어 실행이 안됩니다.
	한가지 주의할 건
	아파치 웹서버 설정파일 httpd.conf 등에서 php 스크립트가 실행될 확장자에 맞게
	나열해야합니다.
	httpd.conf 파일에	

	AddType application/x-httpd-php .html .htm .php .php3 .php4 .php5 .phtml .cgi .inc
	이런 방식이나 혹은
	<FilesMatch "\.ph(p[2-6]?|tml)$|\.htm$|\.html$|\.inc$">
		SetHandler application/x-httpd-php
	</FilesMatch>
	와 같은 방식으로 php 실행 확장자를 넣는데, 이렇게 httpd.conf 에서 지정된 확장자를 
	모두 .htaccess 파일에서 지정을 해줘야 php 파일 실행을 막을 수 있습니다.
	이런 차이를 이용해서 좀 생소한 .phtml 이나 php2 등으로 확장자를 바꾸어서 저장하여
	공격하는 경우도 있습니다.
	자신의 웹서버 설정에 따라서 .htaccess 파일의 내용이 달라질겁니다.



4. POP 접속을 이용한 sendmail 공격

	1) 아이디 비번 해킹
	해커는 스팸을 보내기 위해 서버의 메일 계정 아이디 비번을 
	탈취하려고합니다.
	비밀번호를 1234 나 1111 혹은 아이디끝에 1234 등을 붙이는 등 단순하게 하면
	무차별 대입공격으로 쉽게 알아낼 수 있습니다.
	이런 공격은 ssh 나 ftp, telnet 등을 통해서도  자주 이루어 집니다.
	/var/log/message 나 ,/var/log/secure 파일등에서 가끔 무지막지한 기록을 볼 수 
	있을겁니다.
	여기서는 pop3 를 통해 시도한 공격흔적을  maillog 파일에서 찾아보겠습니다.

	- POP3 데몬으로 dovecot 을 사용할 경우

	# grep "Aborted login:" /var/log/maillog
	...
	9861 Nov 28 09:39:18 home7 dovecot: pop3-login: Aborted login: user=<chung>, method=PLAIN, rip=64.31.40.137, lip=222.122.server.ip
	9862 Nov 28 09:39:18 home7 dovecot: pop3-login: Aborted login: user=<hwan>, method=PLAIN, rip=64.31.40.137, lip=222.122.server.ip
	9863 Nov 28 09:39:18 home7 dovecot: pop3-login: Aborted login: user=<choi>, method=PLAIN, rip=64.31.40.137, lip=222.122.server.ip
	9864 Nov 28 09:39:19 home7 dovecot: pop3-login: Login: user=<chung>, method=PLAIN, rip=64.31.40.137, lip=222.122.server.ip
	9865 Nov 28 09:39:19 home7 dovecot: POP3(chung): Disconnected: Logged out top=0/0, retr=0/0, del=0/2, size=11095
	9866 Nov 28 09:39:20 home7 dovecot: pop3-login: Aborted login: user=<chen>, method=PLAIN, rip=64.31.40.137, lip=222.122.server.ip
	9867 Nov 28 09:39:20 home7 dovecot: pop3-login: Aborted login: user=<sung>, method=PLAIN, rip=64.31.40.137, lip=222.122.server.ip

	메일로그에서 "Aborted login:" 문구로 grep 했을때 동일한 rip= 값으로 수백
	수천 줄이 길게  나온다면 이건 비밀번호 해킹이 이루어 진겁니다.
	보통 자주 쓰는 아이디인 web, admin, root,webmaster 같은 계정이나 혹은
	한국에서 자주 쓰는 sung,yong,choi 같이 추측 가능한 아이디를 이용해서 
	비번이 1234 같이 간단한걸 무작위로 연속 대입해서 알아내는 겁니다.
	위 로그에서는 64.31.40.137 라는 듣보잡 ip 에서 공격한 예입니다.
	9864 라인에 chung 라는 계정이 결국 재수없게 뚫려서 정상 로그인 처리된 걸 확인할 
	수 있습니다.
	나중에 확인해 보니 이 사용자는 비밀번호로 chung1234 를 사용하고 있었다고 합니다.

	- POP3 데몬으로 qpopper 을 사용할 경우
	만약 pop3 로 qpopper 를 사용한다면 아래와 같이 "Password supplied" 라는 걸로
	grep 하면 비슷하게 확인 가능합니다.
	여기서는  222.179.203.46 에서 수천번의 비밀번호 넘겨짚으려는 시도가 있었습니다.

	# zgrep "Password supplied" ./maillog.1.gz  
	...
	Nov 21 14:21:33 home3 popper[20898]: web at 46.203.179.222.broad.cq.cq.dynamic.163data.com.cn (222.179.203.46): -ERR [AUTH] Password supplied for "web" is incorrect.
	Nov 21 14:21:33 home3 popper[20899]: user at 46.203.179.222.broad.cq.cq.dynamic.163data.com.cn (222.179.203.46): -ERR [AUTH] Password supplied for "user" is incorrect.
	Nov 21 14:21:35 home3 popper[20906]: admin at 46.203.179.222.broad.cq.cq.dynamic.163data.com.cn (222.179.203.46): -ERR [AUTH] Password supplied for "admin" is incorrect.
	Nov 21 14:21:37 home3 popper[20911]: webmaster at 46.203.179.222.broad.cq.cq.dynamic.163data.com.cn (222.179.203.46): -ERR [AUTH] Password supplied for "webmaster" is incorrect.


	2) pop3 클라이언트 사용시 로그 형태
	- 일반적으로 사용하는 아웃룩과 같은 메일 클라이언트로 접속해서 메일을 발송할 경우
	sendmail 로그에 어떻게 기록되는지 먼저 보겠습니다.

	## POP 아웃룩 연결
	..
	Dec  1 16:35:59 home5 sendmail[31579]: AUTH=server, relay=[112.187.xxx.xx], authid=nonots, mech=LOGIN, bits=0
	Dec  1 16:35:59 home5 sendmail[31579]: pB17ZvAS031579: from=<nonots@home5.myhome.co.kr>, size=1272, class=0, nrcpts=1, msgid=<777699E70A5C4270BEEF016962B9C39F@mycom>, proto=ESMTP, daemon=MTA, relay=[112.187.xxx.xx]
	Dec  1 16:35:59 home5 sendmail[31579]: pB17ZvAS031579: Milter add: header: X-Virus-Scanned: clamav-milter 0.97.2 at home5.myhome.co.kr
	Dec  1 16:35:59 home5 sendmail[31579]: pB17ZvAS031579: Milter add: header: X-Virus-Status: Clean 
	Dec  1 16:35:59 home5 sendmail[31583]: pB17ZvAS031579: to=<nonots@hanmail.net>, ctladdr=<nonots@home5.myhome.co.kr> (501/501), delay=00:00:00, xdelay=00:00:00, mailer=esmtp, pri=121272, relay=mx9.hanmail.net. [211.43.198.80], dsn=2.0.0, stat=Sent (fB1GZwhE5580598200 Message accepted for delivery)

	내가 사용하는 PC 아이피인  112.187.xxx.xx 에서 nonots 아이디로 home5.myhome.co.kr 
	서버에 접속해서, 한메일 nonots@hanmail.net 주소로 메일 보낸 기록입니다.
	한메일서버 mx9.hanamil.net 으로 메일을 보내서 stat=Sent 가 나와서
	정상적으로 발송됐음을 알 수 있습니다.
	첫 라인에 authid=nonots 라는 접속 기록이 보이고, 접속한 sendmail 프로세스
	번호가 [31579] 번입니다. 
	이 프로세스에 의해 식별자  pB17ZvAS031579 가 부여되는데, 이 식별자의 마지막 부분에 
	31579 라는 프로세스 아이디값을 사용한다는 점을 유의해야 합니다.
	이 식별자에 의해서 /var/spool/mqueue 에 메일 헤더파일인 hfpB17ZvAS031579 와 
	데이타파일인 dfpB17ZvAS031579 가 일시적으로 생기고, 발송 완료한 후에는 mqueue
	에서 일정기간 후 자동으로 삭제가 됩니다.
	이제 이 특징을 이용해서 메일서버 해킹 여부를 점검해 보겠습니다.


	3) maillog 점검
	- 보통 sendmail 로그는 /var/log에 저장되고 1 주일마다 서버 logrotate cron 에 의해 
	백업이 됩니다.
	maillog.1, maillog.2,maillog.3 와 같이 백업되는데, 어떤 서버에서는
	압축백업을 해서, maillog.1.gz, maillog.2.gz.. 와 같이 gz 압축되어
	저장되기도 합니다.
	로그 분석을 위해서는 지난 백업파일까지 전체를 검색하기 위해 /var/log/maillog* 와
	같이 옵션을 주는 것이 좋습니다.
	아래 grep 이 아니라 zgrep 을 사용한 이유는 gz 로 압축된건 자동으로 풀어서 
	검색하기 위해 zgrep 을 사용했습니다. 
	만약 백업파일이 업축되지 않았다면 그냥 grep 을 사용해도 됩니다.

	# zgrep "authid=" /var/log/maillog* | awk '{print $8}' | sort | uniq -c | grep authid | sort -r
	   2972 authid=chung,
		 20 authid=kmlee,
		 13 authid=aychoi,
		  8 authid=keom,
		  7 authid=hyseong,
		  6 authid=tsshyang,
	...
	이 명령어는 아웃룩 같은 메일클라이언트에서 정상적으로 계정에 로그인한 정보를 
	메일로그에서  추출하여서 각 아이디 별로 통계를 낸 겁니다.
	auth=?? 와 같이 로그인 성공한 라인에서 공백문자를 기준으로 cut 을 해서 8 번째
	필드를 뽑아낸 후 같은 아이디를 합산한 후 정렬한겁니다.
	위에서, 해킹당한 chung 라는 계정이 2972번으로 가장 많이 접속했음을 알 수 있습니다.
	그리고 메일을 발송한 ip 별로 보려면

	# zgrep "authid=" /var/log/maillog* |  awk '{print $7}' | sort | grep relay |  uniq -c | sort -r
	   2972 relay=[194.51.238.89],
		 23 relay=[121.166.xxx.xxx],
		 19 relay=[112.158.73.131],
		 12 relay=[183.98.111.130],
		  8 relay=[116.121.255.202],
	...
	와 같이 194.51.238.89 아이피에서 제일 많이 접속한걸 알수 있습니다.
	이 아이피가 chung 계정을 이용한 것으로 추측할 수 있습니다.
	실제로 maillog 파일을 에디터로 열어서 authid=chung 나 194.51.238.89 등을
	검색해서 보면
	..
	41628 Nov 28 20:07:23 home7 sendmail[15541]: AUTH=server, relay=[194.51.238.89], authid=chung, mech=LOGIN, bits=0 41629 Nov 28 20:07:23 home7 sendmail[15539]: AUTH=server, relay=[194.51.238.89], authid=chung, mech=LOGIN, bits=0
	41630 Nov 28 20:07:23 home7 sendmail[15540]: AUTH=server, relay=[194.51.238.89], authid=chung, mech=LOGIN, bits=0  41631 Nov 28 20:07:23 home7 sendmail[15554]: AUTH=server, relay=[194.51.238.89], authid=chung, mech=LOGIN, bits=0
	41632 Nov 28 20:07:23 home7 sendmail[15555]: AUTH=server, relay=[194.51.238.89], authid=chung, mech=LOGIN, bits=0
	41633 Nov 28 20:08:13 home7 sendmail[15540]: pASB7Bop015540: from=<co@e-lupeni.ro>, size=596, class=0, nrcpts=50, msgid=<201111281107.pASB7Bop01554       0@home7.myhome.co.kr>, proto=ESMTP, daemon=MTA, relay=[194.51.238.89] 
	41634 Nov 28 20:08:13 home7 sendmail[15540]: pASB7Bop015540: Milter add: header: X-Virus-Scanned: clamav-milter 0.97.2 at home7.myhome.co.kr
	41635 Nov 28 20:08:13 home7 sendmail[15540]: pASB7Bop015540: Milter add: header: X-Virus-Status: Clean
	41636 Nov 28 20:08:14 home7 sendmail[15542]: pASB7Bi0015542: from=<co@e-lupeni.ro>, size=596, class=0, nrcpts=50, msgid=<201111281107.pASB7Bi001554       2@home7.myhome.co.kr>, proto=ESMTP, daemon=MTA, relay=[194.51.238.89] 
	..
	와 같이 되어 있습니다.
	11월 28일 20시 7분에 접속해서 co@e-lupeni.ro 를 발송자로 해서 스팸메일을 
	발송한걸 알 수 있습니다. 
	아마 이런 발송이 수백 수천건이 보일겁니다. 빌어먹을..


	3) 실시간 스팸 발송 대응
	- 만약 현재 시각으로 서버에서 스팸이 열나게 발송되고 있을 경우
	우선 아래와 같이 ps 명령어로 보면 아래와 같은 sendmail 프로세스가 보입니다.

	# ps aux
	...
	root      6839  0.0  0.1  69232  2996 ?        S    15:14   0:00 sendmail: ./pB26E7mm006835 from queue
	...
	이 경우 식별자 pB26E7mm006835 에서 끝부분 숫자 6835 번 프로세스에 의해서 
	발송됐음을 알 수 있습니다.
	위에서 말했듯이 /var/spool/mqueue 에 dfpB26E7mm006835, hfpB26E7mm006835 파일이 있을 겁니다.
	로그파일에서 이 번호로 발송기록을 찾아보면

	# grep "\[6835\]" /var/log/maillog
	..
	Dec  2 15:14:10 home7 sendmail[6835]: AUTH=server, relay=[121.166.xxx.xxx], authid=jychoi, mech=LOGIN, bits=0
	Dec  2 15:14:10 home7 sendmail[6835]: pB26E7mm006835: from=<jychoi@aaabbb.com>, size=90127, class=0, nrcpts=1, msgid=<000001ccb0b9$9b14ed20$d13ec760$@com>, proto=ESMTP, daemon=MTA, relay=[121.166.xxx.xxx]
	Dec  2 15:14:10 home7 sendmail[6835]: pB26E7mm006835: Milter add: header: X-Virus-Scanned: clamav-milter 0.97.2 at home7.myhome.co.kr
	Dec  2 15:14:10 home7 sendmail[6835]: pB26E7mm006835: Milter add: header: X-Virus-Status: Clean
	..
	와 같이 검색이 될겁니다
	grep 검색에서 [, ] 문자를 사용하려면 위와 같이 역슬래시로 처리해 줘야 합니다.
	만약 너무 길어서 보기 힘들다면 authid= 부분만 검색해서 어느 계정으로
	발송 중인지 알 수 있습니다.

	# grep "\[6835\]" /var/log/maillog | grep authid
	Dec  2 15:14:10 home7 sendmail[6835]: AUTH=server, relay=[121.166.xxx.xxx], authid=jychoi, mech=LOGIN, bits=0
	..
	와 같이 jychoi 라는 계정으로 121.166.xxx.xxx 에서 접속해서 메일을
	발송 중입니다.
	만약 이 발송이 정상이 아니라 스팸 의심이 된다면 위에서 검색한
	# zgrep "authid=" /var/log/maillog* | awk '{print $8}' | sort | uniq -c | grep authid | sort -r
	의 결과를 보거나 기타 방법으로 스팸 여부를 판단하면 됩니다.
	실제 jychoi 사용자에게 전화해서 지금 메일 발송중인지 물어볼 수있다면 제일 정확하겠죠.
	그리고 보통 스팸은 늦은밤이나 새벽 시간대에 보내므로 발송 시간을 보고
	어느정도 추정할 수도 있습니다.


	5) 스팸발송일 경우 대처 방법
	- 장난이 아니라면 모든 메일로그를 압축해서 보관하고 "기관"에 신고하면 됩니다.
	  귀찮아서 그냥 자체 해결하려면,

		(0) sendmail 데몬을 중지합니다.

		(1) 우선 스팸 발송한 ID 계정을 폐쇄하거나, 혹은 실제 사용자에게 연락해서
		비밀번호를 수정하도록 강제합니다.

		(2) 해킹 의심되는 IP 를 차단합니다. 아래와 같이 iptables 로 해도 되고
		# iptables -I INPUT -s 194.51.238.89 -j DROP
		# iptables -I OUTPUT -s 194.51.238.89 -j DROP
		/etc/mail/access 파일이나, /etc/hosts.deny 등을 이용하거나
		하여튼, 방화벽에서 막을 수 있는 모든 수단을 동원해 막습니다.

		(3) /var/spool/mqueue 를 청소합니다.
		아이디나 아이피를 차단해도 sendmail 데몬의 큐에 저장된 건 일정시간 계속
		발송하려고 시도하게 됩니다.
		194.51.238.89 이 아이피로 생성된 큐의 임시파일을 
		아래와 같이 일괄 삭제 가능합니다.
		# grep -l 194.51.238.89 /var/spool/mqueue/* | xargs -i rm -f {}

		(4) sendmail 데몬을 재시작합니다.
		아마 재시작해도 일정시간 동안  큐에 있는 파일 때문에 일부 스팸 발송
		시도가 있을수 있습니다. 그건 수동으로 큐파일 이름을 확인해서 
		삭제해 주면 됩니다.



5. 마무리

	진인사대천명했는 데도 계속 스팸메일이 발송된다면
	그냥 즐.기.시.길. -_-;;