1. 문제 현상

지상국 운용 중 서버 프로그램이 디버깅 창과 함께 비정상 종료되는 문제가 간헐적으로 발생하였습니다.

2. 원인 분석

2-1. 팝업된 오류 메시지 분석

• Debug Assertion Failed

  → 프로그램이 정상적으로 구동되기 위한 환경 조건을 체크한 후 비정상인 경우 프로그램을 종료하며 출력해주는 메시지

• (_osfile(fth) & FOPEN)

  → 정상 확인을 위한 환경 조건 체크 구문, 해당 구문에 의한 체크가 실패한 것으로 확인됨

• write.c

  → 파일연산(File Open/Write/Read 등)과 관련된 Framework (Visual Studio 2005) 내부 소스코드인 것으로 확인

2-2. 오류 메시지가 발생할 수 있는 가설 수립

(1) 닫힌 파일에 대해 쓰기를 시도하는 경우

• 오류 메시지를 근거로 Framework (Visual Studio 2005)의 write.c 파일의 관련 코드 분석(C:\Program Files (x86)\Microsoft Visual Studio 8\VC\crt\src\write.c)
• 분석 결과 다른 쓰레드에 의해 이미 닫힌 파일에 대해 쓰기를 시도하는 경우 발생할 수 있는 오류임을 확인

int __cdecl _write(int fh, const void* buf, unsigned cnt) {    	
    
    ... 
     // 68번 라인, 디버그 모드에서 Asssertion 구문 
    _VALIDATE_CLEAR_OSSERR_RETURN((_osfile(fh) & FOPEN), EBADF, -1);
    ...
    // 릴리즈 모드에서 위와 동일한 역할 수행  
    if (_osfile(fh) & FOPEN) {
    	...
        
    } else {
        ...
        // 릴리즈 모드에서 출력 될 오류 메시지
        _ASSERTE(("Invalid file descriptor. File possibly closed by a different thread", 0)); 
    }

    return r;
}

(2) 동시에 512개 이상의 파일을 열고 쓰기를 시도하는 경우

• 서버 프로그램에서 사용하는 운영체제 자원 핸들이 실행 중 누적하여 증가하는 것을 확인(아래 이미지는 프로그램을 시작한 후, 수일 동안 누적된 핸들 값을 모니터링한 결과)

• 오류 메시지가 파일과 관련된 것임으로 파일 자원을 할당하고 해제하지 않음으로 문제가 발생할 수 있을 것으로 추측하고 이론적 배경 탐색
• 동시에 512개 이상의 파일을 열고 쓰기를 시도하는 경우 오류가 발생할 수 있음을 마이크로소프트 관련 사이트에서 확인

C run-time I/O now supports up to 8,192 files open simultaneously at the low I/O level. This level includes files opened and accessed using the _open, _read, and _write family of I/O functions. By default, up to 512 files can be open simultaneously at the stream I/O level. This level includes files opened and accessed using the fopen, fgetc, and fputc family of functions.

• 위 오류 상황을 모의하여 우리 시스템과 유사한 오류 창이 뜨는 것을 확인

for (int i = 0; i < 512; i++) {	
    
    str.Format("D:\\%d.txt", i);

    errno_t e = fopen_s(&fp, str, "w");
    
    int ret = fwrite("test", sizeof(char), strlen("test"), fp);
}

2-3. 파일 연산 로그 수집

• Process Monitor 유틸리티를 활용하여 서버 프로그램 실행 중 파일 관련 API (CreateFile, WriteFile, CloseFile) 호출 로그 수집
  Process Monitor 사용법
• 프로그램 시작부터 위성 교신 수행 완료까지의 약 7만 라인의 로그 수집

![https://velog.velcdn.com/images%2Fjoosing%2Fpost%2Fd22b2bf2-8a70-4b1b-b811-a62498be5131%2Fimage.png%5D(https%3A%2F%2Fimages.velog.io%2Fimages%2Fjoosing%2Fpost%2Fd22b2bf2-8a70-4b1b-b811-a62498be5131%2Fimage.png)

2-4. 로그 분석

• 7만 라인의 로그 분석을 위한 자동화된 유틸리티 프로그램 개발
• 유틸리티 프로그램에서 다음 2가지 오류 상황이 발생했는지 확인
  • 멀티쓰레드 환경에서 닫힌 파일에 대한 쓰기 시도가 있는 경우
  • 512개 이상의 파일을 동시에 열고 쓰기를 시도하는 경우
• 로그 분석 결과 오류 로그 발견하지 못함
  • 멀티쓰레드 환경에서 닫힌 파일에 대한 쓰기 시도를 하는 파일 없음
  • 여러 쓰레드에서 동시에 열기를 수행하는 파일은 있지만 읽기만 수행하여 영향이 없음
  • 동시에 512개 이상의 파일을 열고 쓰기를 시도하는 경우 없음
  • 동시에 최대 7개의 파일을 열는 것으로 확인

2-5. 실행 파일(EXE)과 라이브러리 파일(DLL) 종속성 분석

• 구글링을 통해 우리와 유사한 오류를 만나고 해결한 상황을 Stack Overflow 사이트에서 확인
• 실행 파일(EXE)과 라이브러리 파일(DLL)의 Runtime-Library 설정이 상이하여 문제가 발생하였고 해당 설정을 동일하게 맞추어 주어 문제를 해결한 상황

• 서버 프로그램 실행 파일과 사용하는 모든 라이브러리 파일 설정 확인 결과 동일한 설정이 문제 없이 적용됨 확인

• 일부 사용중인 DLL 파일은 소스코드가 없어 Dependancy Walker 툴을 활용하여 상태 확인 ( MFC80D.DLL, MSVCR80D.DLL 종속성을 가진 경우 Multi-threaded DLL 설정임을 확인 )

2-7. 오류 재현 시, ProcDump 프로그램 로그 분석

• 프로그램 비정상 종료 시, 종료 시점의 프로그램 컨텍스트 (소스파일, 함수, 소스라인, 콜스택 등 확이) 확인을 위해 Proc Dump 프로그램 사용

  ProcDump 프로그램 사용 예

• 덤프 파일 확인을 통해 비정상 종료 시점의 코드 확인하였고, 특정 소스코드에서 fopen 이후 fwrite 호출 중 비정상 종료 확인

• 해당 코드는 1초에 한번씩 약 13,000 바이트 크기의 로그를 파일에 기록하고 있는데, 실제로 사용하지 않는 쓰레기 로그로 확인되어 관련 코드를 제거하기로 운영팀과 함께 결정

• fwrite() 호출 시 프로그램이 죽는 원인은 파악하지 못함

3. 처리 결과

• 문제 코드 제거 후, 현재까지 동일한 문제 발생하지 않음