해당 이슈는 Classic 플랫폼에서만 발생하는 것으로 확인되었습니다.
C:\Windows\System32\xenagent_9_0_0_11.exe 시간 동기화 문제
안녕하세요. ManVSCloud 김수현입니다.
Windows Server를 운영하시다보면 시스템 시간이 실제 시간과 맞지 않는 경우를 겪어보셨을 것입니다.
이와 같이 시간이 맞지 않는 경우는 CMOS 배터리, RTC 모듈, NTP 서버 장애 등이 존재하는데 네이버 클라우드 플랫폼에서 Windows Server를 운영하다가 서버의 시간이 맞지 않았던 케이스 하나를 소개드리며 트러블 슈팅 방법과 함께 해결책을 공개해보겠습니다.
Case introduction
상황은 Windows Server를 운영 중에 이중화가 필요하여 이미지를 생성하고 동일한 서버를 하나 더 생성하여 기존 A 서버와 A서버의 이미지로 만들어진 B 서버가 운영되게 됩니다.
그리고 며칠 후 두 서버의 시간이 실제 시간보다 30초 가량 늦어진 것이 확인되었습니다.
- A 서버는 kr-1 존이고, B 서버는 kr-2 존입니다.
- A, B 서버만 시간이 다르고 나머지 서버들은 정상적인 시간으로 동작되고 있었습니다.
- 서버 내에서 윈도우 동기화를 수동으로 진행했을 때 정상적으로 동기화가 되었습니다.
- 하루에 20~30초씩 시간이 늦춰져있었습니다.
여기서 하드웨어의 장애가 아니라 A, B 두 서버 내에서 무언가 잘못 동작하고 있다는 걸 깨달았습니다.
Trouble shooting
먼저 Windows에서는 w32time 라는 서비스가 실행 중인 모든 컴퓨터의 날짜와 시간을 동기화하게 됩니다.
cmd에서 아래와 같이 명령어로 확인 시 RUNNING 상태를 확인할 수 있습니다.
C:\Users\Administrator>sc query w32time
SERVICE_NAME: w32time
종류 : 20 WIN32_SHARE_PROCESS
상태 : 4 RUNNING
(STOPPABLE, NOT_PAUSABLE, ACCEPTS_SHUTDOWN)
WIN32_EXIT_CODE : 0 (0x0)
SERVICE_EXIT_CODE : 0 (0x0)
검사점 : 0x0
WAIT_HINT : 0x0
이 시간 동기화 서비스는 레지스트리에서 값을 변경해주지 않으면 기본적으로 86400로 설정되어 있어 하루에 한번씩 시간 동기화를 하게 됩니다.
물론 위 레지스트리 값을 수정하여 동기화 시간을 단축시키면 해결할 수 있겠지만 이는 근본적인 해결 방법이 될 수 없습니다.
과연 시간을 동기화 하는 서비스가 계속해서 시간 동기화에 실패를 했던 것인가?
그것을 판단하기 위해 로그를 확인해보아야합니다.
C:\Users\Administrator>w32tm /query /status 윤초 조정: 0(경고 없음) 계층: 1(기본 참조 - 라디오 클록으로 동기화됨) 정밀도: -6(틱당 15.625ms) 루트 지연: 0.0000000s 루트 분산: 10.0000000s 참조 ID: 0x4C4F434C(원본 이름: "LOCL") 마지막으로 동기화한 시간: 2022-01-29 오후 11:21:08 원본: Local CMOS Clock 폴링 간격: 6(64s)
먼저 w32tm 서비스가 마지막으로 동기화한 시간을 확인해줍니다.
이어서 wevtutil 명령어를 이용하면 이벤트 로그 및 게시자에 대한 정보를 검색할 수 있는데 아래와 같이 옵션을 주어 시스템 시간이 변경된 이벤트 로그를 모두 가져옵니다.
wevtutil qe /rd Security /q:”*[System[(EventID=520) or (EventID=4616)]]” /e:Events /uni:false /f:text
C:\Users\Administrator>wevtutil qe /rd Security /q:"*[System[(EventID=520) or (EventID=4616)]]" /e:Events /uni:false /f:text
Event[0]:
Log Name: Security
Source: Microsoft-Windows-Security-Auditing
Date: 2022-01-30T01:51:10.601
Event ID: 4616
Task: 보안 상태 변경
Level: 정보
Opcode: 정보
Keyword: 감사 성공
User: N/A
User Name: N/A
Computer: manvscloud-win
Description:
시스템 시간이 변경되었습니다.
주체:
보안 ID: S-1-5-18
계정 이름: MANVSCLOUD-WIN$
계정 도메인: WORKGROUP
로그온 ID: 0x3E7
프로세스 정보:
프로세스 ID: 0x84c
이름: C:\Windows\System32\xenagent_9_0_0_11.exe
이전 시간: 2022-01-29T16:51:11.648519200Z
새 시간: 2022-01-29T16:51:10.601000000Z
이 이벤트는 시스템 시간이 변경되면 생성됩니다. 시스템 권한으로 실행되는 Windows 시간 서비스가 정기적으로 시스템 시간을 변경하는 것은 정상입니다. 다른 시스템 시간 변경은 컴퓨터를 임의로 변경하려는 시도를 나타낼 수 있습니다.
Event[1]:
Log Name: Security
Source: Microsoft-Windows-Security-Auditing
Date: 2022-01-30T01:21:11.645
Event ID: 4616
Task: 보안 상태 변경
Level: 정보
Opcode: 정보
Keyword: 감사 성공
User: N/A
User Name: N/A
Computer: manvscloud-win
Description:
시스템 시간이 변경되었습니다.
주체:
보안 ID: S-1-5-18
계정 이름: MANVSCLOUD-WIN$
계정 도메인: WORKGROUP
로그온 ID: 0x3E7
프로세스 정보:
프로세스 ID: 0x84c
이름: C:\Windows\System32\xenagent_9_0_0_11.exe
이전 시간: 2022-01-29T16:21:10.541507100Z
새 시간: 2022-01-29T16:21:11.646000000Z
이 이벤트는 시스템 시간이 변경되면 생성됩니다. 시스템 권한으로 실행되는 Windows 시간 서비스가 정기적으로 시스템 시간을 변경하는 것은 정상입니다. 다른 시스템 시간 변경은 컴퓨터를 임의로 변경하려는 시도를 나타낼 수 있습니다.
Event[2]:
Log Name: Security
Source: Microsoft-Windows-Security-Auditing
Date: 2022-01-30T00:51:10.538
Event ID: 4616
Task: 보안 상태 변경
Level: 정보
Opcode: 정보
Keyword: 감사 성공
User: N/A
User Name: N/A
Computer: manvscloud-win
Description:
시스템 시간이 변경되었습니다.
주체:
보안 ID: S-1-5-18
계정 이름: MANVSCLOUD-WIN$
계정 도메인: WORKGROUP
로그온 ID: 0x3E7
프로세스 정보:
프로세스 ID: 0x84c
이름: C:\Windows\System32\xenagent_9_0_0_11.exe
이전 시간: 2022-01-29T15:51:09.448407700Z
새 시간: 2022-01-29T15:51:10.539000000Z
이 이벤트는 시스템 시간이 변경되면 생성됩니다. 시스템 권한으로 실행되는 Windows 시간 서비스가 정기적으로 시스템 시간을 변경하는 것은 정상입니다. 다른 시스템 시간 변경은 컴퓨터를 임의로 변경하려는 시도를 나타낼 수 있습니다.
.
.
.
여기서 수상한 점을 발견하게 되었습니다.
w32time 서비스가 시간 동기화로 시스템 시간을 변경할 경우 주체의 계정 이름이 LOCAL SERVICE, 프로세스 ID가 C:\Windows\System32\svchost.exe로 나오는데 위 로그에서 xenagent_9_0_0_11.exe가 계속 시스템 시간을 변경하고 있는 것이었습니다.
그것도 30분 주기로 계속!
네이버 클라우드 플랫폼은 Xen 기반으로 구축되었는데 XenAgent(사용자가 생성한 서버)와 Host 간 agent를 통해 시간 동기화가 이루어지고 있는 상태!
C:\Users\Administrator>sc query xenagent
SERVICE_NAME: xenagent
종류 : 10 WIN32_OWN_PROCESS
상태 : 4 RUNNING
(STOPPABLE, NOT_PAUSABLE, ACCEPTS_SHUTDOWN)
WIN32_EXIT_CODE : 0 (0x0)
SERVICE_EXIT_CODE : 0 (0x0)
검사점 : 0x0
WAIT_HINT : 0x0
그렇다면 이 문제를 해결하기 위해서 xenagent 서비스를 중지해야하느냐?
아닙니다!! host와 agent 간의 시간 동기화는 일부 기능일뿐… xenagent를 중지하게 될 경우 네이버 클라우드 콘솔에서 서버를 컨트롤 할 수 없는 대참사가 일어납니다…
지금부터 해결 방법을 알려드리겠습니다.
The Solution
자! 우리는 Xen Tool을 업그레이드 할 것입니다.
참고로 이 작업을 하게되실 경우 두세번 정도의 재부팅 및 재부팅 시 정상 부팅까지 꽤 긴 시간을 요구하므로 운영 중인 서비스가 중요한 서비스일 경우 운영 시간을 잘 조율하여 작업하는 것을 권장드립니다.
또한 해당 작업은 레지스트리 수정 및 에이전트 업그레이드가 이루어지므로 이미지 백업을 진행 후 따라하시길 적극 권장드립니다.
레지스트리에서 TimeSyncMode 값을 설정해주면 되는데 아쉽게도 xeniface 9.0.0.11 driver는 해당 레지스트리 키가 없어 Xen Tool을 업그레이드하고 TimeSyncMode 값을 설정해줄겁니다.
위 링크에서 윈도우 서버의 Xentools 정보 확인 및 다운로드 할 수 있으며 Powershell에서 아래 명령어를 입력하여 최신 버전을 다운로드 할 수 있습니다.
Windows PowerShell Copyright (C) 2016 Microsoft Corporation. All rights reserved. PS C:\Users\Administrator> Start-BitsTransfer -Source "http://init.ncloud.com/xentools/windows/managementagentx64-latest .msi" -Destination "c:\managementagentx64-latest.msi"
설치가 완료되었다면 실행시켜줍시다.
PS C:\Users\Administrator> msiexec /i "c:\managementagentx64-latest.msi"
아래 이미지 화면이 나올 때까지 [Next]만 눌러주시면 됩니다.
Disallow automatic management agent updates 으로 변경해주고 Next를 눌러주었습니다.
(자동 관리 에이전트 업데이트 허용 안 함)
Finish를 누르시면 재부팅하자고 나올 것인데 앞으로 총 2번의 재부팅을 하게 됩니다.
첫번째 리부팅은 상당히 빠르게 됩니다.
두번째 리부팅이 꽤 시간이 소요될 수 있는데 살짝 랜덤인듯?합니다.
총 2번 시도 해봤는데 처음엔 30분 정도 소요됐고 두번째에서 10분내로 서버가 부팅되었습니다.
마지막으로 레지스트리에 다음과 같이 추가 작업을 해주겠습니다.
위 경로에서 [새로 만들기] – [DWORD(32비트) 값] 을 선택해줍니다.
이름은 TimeSyncMode로 입력해주고 값은 그대로 0 으로 둡니다.
설정이 완료되었으면 레지스트리를 적용시키기 위해 재부팅을 1회 추가로 진행해줍니다.
에이전트 업그레이드 전 미리 레지스트리 추가를 해둔다면 재부팅 횟수를 줄일 수 있습니다.
이후 cmd에서 wevtutil qe /rd Security /q:”*[System[(EventID=520) or (EventID=4616)]]” /e:Events /uni:false /f:text 명령어를 통해 다시 xenagent가 시스템 시간을 변경하는지 모니터링 해주시면 됩니다.
작업 전 xenagent가 30분마다 시스템 시간을 변경시킨다는 것을 알아두었습니다.
그러므로 작업 후 약 1시간 뒤에 확인해보시면 됩니다.
1시간 내로 시간 변동이 있었는지 체크 시 이제 더 이상 xenagent가 시스템 시간을 변경시키지 않는다는 것을 알 수 있습니다.
Personal Comments
DB 서버를 운영할 때에 DB의 시간이 로컬 시간으로 설정된 경우 시스템 시간에 변동이 있다면 큰 골칫거리가 될 것입니다.
주식 관련 프로그램을 운영하시는 분들은 시스템 시간 동기화 프로그램을 따로 사용하는 분들도 많더군요.
위 사례는 처음에는 시간 변동 증상이 없다가 갑자기 이중화를 하면서 해당 증상이 발견된 것처럼 보입니다. 정확한 원인을 파악 중이며 파악되는대로 네이버 클라우드 측에 공유해볼 예정입니다.
긴 글 읽어주셔서 감사합니다.
