1. 현상

아래와 같이 last reboot 명령어로 시스템  부팅 시간을 확인 하자 파란색 두줄이 이상하게 출력된걸 볼 수 있다.
[root@mhkim ~]# last reboot
reboot   system boot  2.6.32-220.el6.x Wed Apr 16 10:33 - 11:16  (00:43)
reboot   system boot  2.6.32-220.el6.x Wed Apr 16 10:24 - 11:16  (00:52)
reboot   system boot  2.6.32-220.el6.x Wed Apr 16 10:21 - 10:21  (00:00)
reboot   system boot  2.6.32-220.el6.x Wed Apr 16 10:20 - 10:20  (00:00)
reboot   system boot  2.6.32-220.el6.x Wed Apr 16 09:10 - 10:16  (01:06)
reboot   system boot  2.6.32-220.el6.x Tue Apr 15 22:00 - 10:16  (12:15)

.
.


2. 분석

아래 글은 위 현상의 원인을 분석한 내용이다.

2.1. wtmp와 utmp 파일 설명
wtmp - 처음부터 접속했던 모든 사용자의 로그인정보와 로그아웃정보를 가지고 있다. - last 명령어는 이 값을 보여주는 것이다.
utmp - 현재시스템에 접속해 있는 사용자의 정보를 가지고 있다.
두 파일은 서로 관련이 있으며 아래의 내용을 통해 OS shutdown과 부팅시 메커니즘을 이해할 수 있다.

2.2. 리눅스 shutdown과 wtmp
리눅스의 shutdown(또는 reboot), init 0 명령어로 OS를 셧다운 하게되면 아래의 init 0 Level에 정의된 killall과 halt 스크립트가 구동된다.[root@mhkim ~]# ls -la /etc/rc.d/rc0.d
.
.
lrwxrwxrwx.  1 root root   17 2014-04-01 21:16 S00killall -> ../init.d/killall
lrwxrwxrwx.  1 root root   14 2014-04-01 21:16 S01halt -> ../init.d/halt

1) killall을 통해 lock 파일이 생성된 데몬 프로세스를 중단한다.
2) halt를 통해 프로세스 종료, swap off, /var/log/wtmp에 down 마킹, 파일시스템 umount, 전원 off 순을 밟아 시스템이 off 된다.
이때 halt 스크립트의 95번째 라인(CentOS 6.2 기준)에 있는 /sbin/halt -w 을 실행하면서 /var/log/wtmp 파일의 가장 마지막라인(last로 보면 최상위)에 아래와 같이 종료시각값에 down을 마킹한다.
root     pts/0        192.168.0.77     Tue Apr 15 21:39 - down   (00:10)

그렇게 시스템이 꺼지고 다시 부팅을 하게되면 시작 스크립트인 /etc/rc.sysinit에 의해 /var/run/utmp 파일이 초기화(utmp 파일이 없으면 생성)된다.
--> 해당 부분은 /etc/rc.sysinit 스크립트의 584 ~ 602 라인에 있다. (CentOS 6.2 기준)

그런데 시스템이 비정상적인 종료(전원강제종료, 정전, 커널패닉 등)에 의해 halt 스크립트가 구동이 안되면 /var/log/wtmp 파일에 down을 마킹하지 못 한다.
다시 OS 부팅이되고 /var/log/wtmp의 가장 마지막 라인의 종료시각 값에 down이 없으면 crash를 마킹하고 crash가 되기 직전의 system boot 종료시각값 표기를 현재 시각에 맞춰 표기를 한다.
왜냐하면 wtmp 메커니즘으로는 그 전 종료 시각을 알 수 없기 때문에 그렇게 표기를 하는 것이다.


3. 상황 재현

이것을 간단하게 테스트 해볼수 있는 방법이 몇 가지가 있는데 2가지 방법을 소개한다.
3.1. utmp 파일의 이름을 바꾼후 정상적으로 shutdown을 한다.
   그러면 halt -w 명령을 통해 utmp파일을 읽을 수 없어서 wtmp 파일에 종료시각값에 down을 표기하지 못 한다.
   1) $ mv /var/run/utmp /var/run/utmp_test
   2) $ shutdown -h 0
   부팅 후 last 명령을 통해 보면 정상적으로 시스템을 껐다 켰는데도 crash가 확인되고 그전 system boot 타임의 종료시각값 부분이 현재시각으로 표기되어 있다.
   그리고 /var/run/utmp_test 사라지고 /var/run/utmp 파일이 새로 생성되어 있다.

3.2. wtmp파일에 down을 마킹하고 시스템을 강제종료시킨다.
   1) $ /sbin/halt -w
   2) 그리고 시스템 전원을 강제 종료시킨다.
   부팅 후 last 명령을 통해 보면 비정상적으로 시스템을 껐다 켰는데도 crash가 마킹되지 않고 그전 system boot 타임의 종료시각값 부분이 down으로 마킹이 되어 정상적인것처럼 wtmp 값이 보인다.

last 명령과 wtmp 로깅 동작 원리

답글 남기기

이메일 주소는 공개되지 않습니다. 필수 필드는 *로 표시됩니다