안녕하세요.

1.갑자기 cpu 사용률이 높아짐
2.실행하지 않은 프로세스가 구동되는것을 발견

3.그 프로그램은 채굴 프로그램이였음

4.설치한적이 없으니 서버가 해킹당한것으로 판단

5./tmp/javax 라는 디렉토리에서 sshd2 라는 프로그램이 실행됐고 이 프로그램이 채굴 프로그램임

strace는 이미 실행됐을 때 그 프로세스를 디버깅 하는거기 때문에 strace로는 분석이 불가능한것으로 판단

따라서 sysdig로 어떤 경로로 들어온건지 침해사고 분석을 해보자.

1./tmp/javax 디렉토리에 악성파일이 생성/실행 되는거니까 이 디렉토리를 기준으로 sysdig

ㄴ또는 /tmp/javax/sshd2 가 실행되는거니까 이 파일을 기준으로 하는것도 도움이 될듯하다. 하지만 sshd2가 실행되면 cpu 자원을 거의 다 잡아먹기 때문에 sshd2는 퍼미션 000으로 주고 수정도 안되게끔 immutable 해놓은 상태이다. 

[root@localhost ~]# sysdig fd.name contains /tmp/javax -w /root/sysdig.txt &
[1] 15994
[root@localhost ~]# 
[root@localhost ~]# 
[root@localhost ~]# ps -ef | grep 15994

root     15994 15215 15 14:10 pts/1    00:00:00 sysdig fd.name contains /tmp/javax -w /root/sysdig.txt

좀 있다 확인해보니 아래와 같은 로그들이 쌓여있다.

8526754 16:30:01.519760827 7  (24369) < open fd=5 name=javax(javax) flags=5185(O_DIRECTORY|O_NONBLOCK|O_RDONLY|O_CLOEXEC) mode=0 dev=802 
8526755 16:30:01.519764268 7  (24369) > fchdir fd=5 
8526756 16:30:01.519764853 7  (24369) < fchdir res=0 
8526757 16:30:01.519765611 7  (24369) > getdents fd=5 
8526758 16:30:01.519769890 7  (24369) < getdents res=160 
8526759 16:30:01.519771972 7  (24369) > getdents fd=5 
8526760 16:30:01.519772426 7  (24369) < getdents res=0 
8526761 16:30:01.519773239 7  (24369) > close fd=5 
8526762 16:30:01.519774769 7  (24369) < close res=0 
10671620 17:00:01.782017001 12 sshd (24528) < open fd=5(

pipe:[29129900]) name=javax(/javax) flags=5185(O_DIRECTORY|O_NONBLOCK|O_RDONLY|O_CLOEXEC) mode=0 dev=802 
10671621 17:00:01.782019569 12 sshd (24528) > fchdir fd=5(

pipe:[29129900]) 
10671622 17:00:01.782019965 12 sshd (24528) < fchdir res=0 
10671623 17:00:01.782020603 12 sshd (24528) > getdents fd=5(

pipe:[29129900]) 
10671624 17:00:01.782023743 12 sshd (24528) < getdents res=160 
10671625 17:00:01.782025437 12 sshd (24528) > getdents fd=5(

pipe:[29129900]) 
10671626 17:00:01.782025746 12 sshd (24528) < getdents res=0 
10671627 17:00:01.782026366 12 sshd (24528) > close fd=5(

pipe:[29129900]) 
10671628 17:00:01.782027341 12 sshd (24528) < close res=0 
12728508 17:30:01.294747116 2  (2681) < open fd=5 name=javax(javax) flags=5185(O_DIRECTORY|O_NONBLOCK|O_RDONLY|O_CLOEXEC) mode=0 dev=802 
12728509 17:30:01.294750623 2  (2681) > fchdir fd=5 
12728510 17:30:01.294751237 2  (2681) < fchdir res=0 
12728511 17:30:01.294751981 2  (2681) > getdents fd=5 
12728512 17:30:01.294756100 2  (2681) < getdents res=160 
12728513 17:30:01.294758160 2  (2681) > getdents fd=5 
12728514 17:30:01.294758765 2  (2681) < getdents res=0 
12728515 17:30:01.294759540 2  (2681) > close fd=5 
12728516 17:30:01.294760864 2  (2681) < close res=0 

Jun 101. 서버의 crontab이 삭제 돼있는것을 확인

2. 당시 등록해줬으나 또다시 삭제됨, 1분간격으로 삭제되는것을 확인

3.message 로그에는 
Jun 10 06:53:54 cobuy-0952 init: Re-executing /sbin/init 
Jun 10 06:54:55 cobuy-0952 init: Re-executing /sbin/init 
Jun 10 06:55:55 cobuy-0952 init: Re-executing /sbin/init 
Jun 10 06:56:56 cobuy-0952 init: Re-executing /sbin/init 
Jun 10 06:57:56 cobuy-0952 init: Re-executing /sbin/init 
Jun 10 06:58:57 cobuy-0952 init: Re-executing /sbin/init 
Jun 10 06:59:58 cobuy-0952 init: Re-executing /sbin/init
라는 메세지가 1분간격으로 쌓여있음, tail -f 로 확인해보면 위 메세지가 로깅될때마다 crontab에 삭제됨

##참고로 Re-executing /sbin/init  메세지는 init 6 해서 보면 서버 재부티될 때 올라오는 메세지

4.strace -s 65535 -f -t -o log.txt -p 1 으로 init(pid : 1) 프로세스를 확인해보면 1분간격으로 init restart가 확인됨

strace 내용
1     17:21:46 --- SIGTERM {si_signo=SIGTERM, si_code=SI_USER, si_pid=4316, si_uid=0} ---
1     17:21:46 write(4, "\0", 1)        = 1
1     17:21:46 rt_sigreturn()           = -1 EINTR (Interrupted system call)
1     17:21:46 read(3, "\0", 1)         = 1
1     17:21:46 read(3, 0x7fff9a1c07df, 1) = -1 EAGAIN (Resource temporarily unavailable)    ###7fff9a1c07df 이메모리주소를 찾을려고 했는데 못찾았다.
1     17:21:46 open("/etc/localtime", O_RDONLY) = 9   ####여기서부터 
1     17:21:46 fstat(9, {st_mode=S_IFREG|0644, st_size=517, ...}) = 0
1     17:21:46 fstat(9, {st_mode=S_IFREG|0644, st_size=517, ...}) = 0
1     17:21:46 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f95b8be1000
1     17:21:46 read(9, "TZif2\0\0\중략\0\0\0\0\0\0\0\0\0\0\0\0\nKST-9\n", 4096) = 517
1     17:21:46 lseek(9, -304, SEEK_CUR) = 213
1     17:21:46 read(9, "TZif2\0\중략\0\0\0\0\0\0\nKST-9\n", 4096) = 304
1     17:21:46 close(9)                 = 0       #####여기까지는 localtime 불러오는거니까 무시해도 될듯
1     17:21:46 munmap(0x7f95b8be1000, 4096) = 0
1     17:21:46 socket(PF_LOCAL, SOCK_DGRAM|SOCK_CLOEXEC, 0) = 9
1     17:21:46 connect(9, {sa_family=AF_LOCAL, sun_path="/dev/log"}, 110) = 0
1     17:21:46 sendto(9, "<28>May 31 17:21:46 init: Re-executing /sbin/init", 49, MSG_NOSIGNAL, NULL, 0) = 49  ###메세지 로그에 로깅되는 부분..
1     17:21:46 rt_sigprocmask(SIG_BLOCK, ~[RTMIN RT_1], [], 8) = 0
1     17:21:46 execve("/sbin/init", ["/sbin/init", "--restart"], [/* 3 vars */]) = 0     여기서 아마 crontab이 초기화되는것같다...
1     17:21:46 brk(0)                   = 0x560480f31000
등등... 약 360줄

strace를 토대로 어느 프로세스(혹은 데몬)때문에 crontab이 초기화 되는지 찾아보려했는데 결국은 실패
ㄴ/proc/*/map/ 에는 뒤에 몇자리 때봐도 안나
애초에 어느 프로세스로 인해 실행됐다 라는 기록이 안된다면 찾는건 거의 불가능하다고 판단
처음에는 시스템이 올라오면서 init 데몬이 뭔가 문제가 생겼나.. 싶어서 os 재부팅도 해보고 메모리에 Resource temporarily unavailable 에러가 나오니 메모리 불량인가... 싶어 메모리 교체도 해봤으나 하루정도 괜찮고 동일증상 발생
crontab도 안돌고 있는데 1분간격으로 위와같이 init 프로세스에서 뭔가 작동하는걸로보아 현재 실행돼있는 프로세스중 하나에 문제가 있다고 판단
수상한 프로세스를 찾아보니 서버가 해킹당해있었음
/tmp/javax 에 해킹 프로그램 실행돼있었음 많이 보던 해킹프로그램이였는데 이걸로 인해 crontab이 삭제(init 프로세스에 뭔가 작동)되는건 첨보는 경우였습니다.

TASK [Running Windows Update] **********************************************************************************************************
task path: /root/ansible/dhsa/winu.yml:5
win_updates: running win_updates module
Using module file /usr/lib/python2.7/site-packages/ansible/modules/windows/win_updates.ps1
<123.123.123.123> ESTABLISH WINRM CONNECTION FOR USER: test01 on PORT 5986 TO 123.123.123.123 
EXEC (via pipeline wrapper)
The full traceback is:
Exception calling "RunAsUser" with "7" argument(s): "Failed to start become pro
cess (The service cannot be started, either because it is disabled or because i
t has no enabled devices associated with it, Win32ErrorCode 1058)"
At line:907 char:9
+         $result = [AnsibleBecome.BecomeUtil]::RunAsUser($username, $password,
 $l ...
+ ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
~~~
    + CategoryInfo          : NotSpecified: (:) [], MethodInvocationException
    + FullyQualifiedErrorId : Win32Exception
 

fatal: [123.123.123.123  ]: FAILED! => {
    "changed": false, 
    "msg": "Failed to become user SYSTEM: Exception calling \"RunAsUser\" with \"7\" argument(s): \"Failed to start become process (The service cannot be started, either because it is disabled or because it has no enabled devices associated with it, Win32ErrorCode 1058)\""
}
        to retry, use: --limit @/root/ansible/dhsa/winu.retry

PLAY RECAP *****************************************************************************************************************************
123.123.123.123       : ok=0    changed=0    unreachable=0    failed=1    skipped=0  

윈도우 보안업데이트 하려고 하는데 위와같이 에러 발생

이럴경우에는 윈도우 서비스중 secondary logon  서비스가 사용안함으로 돼 있을경우 에러가 난다. 원래는 윈도우 보안업데이트 실행시 이게 종료돼있어도 자동으로 실행되야하는데 아에 사용안함으로 돼 있으니까 에러 난다.

secondary logon 이게 원래 디폴트는 사용안함이 아니다. 근데 보안상 취약한 서비스라 사용안함을 권고하고 있다. 

대부분 서비스 사용중이라 이런 에러 자체가 없어서 찾느라 드럽게 힘들었다.