고수들이 절대 가르쳐 주지 않는 C/C++ 프로그래밍 팁 #4 - C/C++ 로깅 Facility
고절가주팁 네 번째입니다. 지난 글 마지막에 밝혔던 바와 같이 이번 글부터는 거의 모든 프로그램에서 필요로 하는 로깅(logging) 라이브러리를 구현해 보도록 하겠습니다.
회사에서나 개인적으로 S/W를 전문적으로 개발해 본 경험이 있는 분이라면 로깅 라이브러리는 거의 모든 프로젝트에 공통적으로 필요한 모듈이라는 걸 인정하실 것입니다.
로깅 라이브러리는 개발하는 중간에는 S/W 가 잘못 수행되는 부분은 없는지 디버깅하는 데 유용할 뿐만 아니라 개발이 완료되고 나서 시스템 운영자나 관리자가 해당 S/W를 운영하는 데 필수적인 정보를 제공하는 데 유용합니다. 여러분이 웬만한 규모 이상의 S/W를 개발한다면 항상 맞닥뜨려야 하는 문제라는 것이죠. 이렇게 거의 모든 S/W에서 필요한 라이브러리임에도 불구하고, 잘 설계된 로깅 라이브러리를 만든다는 건 쉽지 않은 일입니다.
이런 로깅 라이브러리를 설계/구현하는 긴 여정을 이번 글을 시작으로 해서 떠나 보도록 하겠습니다.
아~! 근데 본격적으로 여정을 떠나기 전에 한 가지 준비를 하고 떠나야 되겠습니다. 로깅을 위해 C/C++ 언어에서 제공하는 기본 메커니즘들을 확인하고 가는 것이죠. 이걸 확인하는 방법은 다양하겠지만, 저는 assert()를 통해 설명드리도록 하겠습니다.
assert() 란 함수의 본래 로직을 수행하기 전/후에 해당 로직이 가정하고 있는 특정 조건이 만족하는지를 체크해 보고 만족하지 않으면 실행을 중단해 버리는 특수한 함수로 개발 도중 디버깅 용도로 많이 쓰이는 방법입니다.
예를 들어, 여러분이 C 라이브러리 구현자라고 상상해 보시겠습니다. 그리고, memcpy() 와 같은 함수를 구현하는 책임이 있다고 상상해 보겠습니다. memcpy()는 다음과 같이 구현할 수 있을 것입니다.
/*
* memcpy()는 pvSource 로부터 pvSink 로 sz 만큼을 복사함.
* memcpy()는 pvSource 와 pvSink 가 NULL 이 아니라는 걸 가정하고 있음
*/
void*
memcpy(void* pvSink, void* pvSource, size_t sz)
{
char* pSrc = (char*)pvSource;
char* pSnk = (char*)pvSink;
while (sz-- > 0)
*pSnk++ = *pSrc++;
return pvSink;
}
기본적인 아이디어는 위와 같이 구현할 수 있지만, memcpy 가 가정하고 있는 pvSource와 pvSink 가 NULL 이 아니라는 건 체크하지 않고 있기 때문에 어떤 개발자가 실수로 pvSink 나 pvSource에 NULL을 주게 되면 실행시에 심각한 문제가 발생할 수도 있습니다. 이런 문제를 피하기 위해 당연히 본래의 로직을 실행하기 전에 pvSource 와 pvSink의 NULL 여부를 체크하는 로직을 넣어야 할 것입니다.
/*
* pvSource, pvSink가 NULL인지를 체크함
*/
void*
memcpy(void* pvSink, void* pvSource, size_t sz)
{
char* pSrc = (char*)pvSource;
char* pSnk = (char*)pvSink;
/* pvSource 나 pvSink가 NULL 프로그램 수행을 중단 */
if (pvSource == NULL || pvSink == NULL) {
fprintf(stderr, "memcpy(): Bad args: pvSource or pvSink is NULL\n");
abort();
}
while (sz-- > 0)
*pSnk++ = *pSrc++;
return pvSink;
}
어떤 분은 NULL 인지 체크한 후 에러 메시지만 출력하고 바로 리턴하는 게 아니라 abort()를 호출하는 걸 이상하게 생각하실 분도 있을 것 같습니다. 그건 pvSource 나 pvSink의 값으로 NULL이 넘어 왔다면 프로그램에 뭔가 심각한 버그가 있다는 걸 뜻하기 때문입니다. 뭔가 심각한 버그가 있는 채로 실행되는 것 보다는 그 상황이 알려지면 빨리 종료해 버리는 것이 문제를 해결하는 데 훨씬 유리하기 때문입니다. 그렇다 하더라도 이미 S/W가 출시된 상황에서 그런 일이 벌어진다면 고객으로부터 Claim이 올 것은 자명한 일입니다. 따라서 pvSource 나 pvSink 가 NULL 인지 체크하는 코드는 Production 시스템에 사용되는 것이 아니라 개발시에 사용되어야 그 의미가 살아날 수 있습니다. 즉, 다음과 같이 작성해야 할 것입니다.
/*
* pvSource, pvSink가 NULL인지를 체크함
*/
void*
memcpy(void* pvSink, void* pvSource, size_t sz)
{
char* pSrc = (char*)pvSource;
char* pSnk = (char*)pvSink;
#ifdef DEBUG
/* pvSource 나 pvSink가 NULL 프로그램 수행을 중단 */
if (pvSource == NULL || pvSink == NULL) {
fprintf(stderr, "memcpy(): Bad args: pvSource or pvSink is NULL\n");
abort();
}
#endif
while (sz-- > 0)
*pSnk++ = *pSrc++;
return pvSink;
}
위와 같이 작성하고 개발시에는 DEBUG 를 정의해서 컴파일하고, 정식 릴리즈시에는 DEBUG를 정의하지 않고 컴파일하면 개발시에만 abort()가 적용되어 디버깅하는 데 도움을 얻을 수 있게 됩니다.
이렇게 뭔가 만족되어야 하는 조건을 검사하고, 그 조건이 만족하지 않을 경우 실행을 중단해버리는 함수가 바로 assert() 입니다. 다음은 assert() 를 적용해서 위 코드를 수정해 본 것입니다.
/*
* pvSource, pvSink가 NULL인지를 체크함
*/
void*
my_memcpy(void* pvSink, void* pvSource, size_t sz)
{
char* pSrc = (char*)pvSource;
char* pSnk = (char*)pvSink;
assert(pvSource != NULL && pvSink != NULL);
while (sz-- > 0)
*pSnk++ = *pSrc++;
return pvSink;
}
char* pSource = "source memory content";
char pSink[32];
/* main() 함수 */
int
main(void)
{
printf("Calling my_memcpy(%08x,%08x, %d)\n",
pSink, pSource, strlen(pSource));
my_memcpy(pSink, pSource, strlen(pSource));
/* assert()가 실패하는 케이스 */
printf("Calling my_memcpy(NULL,%08x, %d)\n", pSource,
strlen(pSource));
my_memcpy(NULL, pSource, strlen(pSource));
}
다음은 GCC(3.4.4)로 컴파일하고 실행해 본 결과입니다.
$ ./debug
Calling my_memcpy(00404020,0040302b, 21)
Calling my_memcpy(NULL,0040302b, 21)
debug: debug.c:15: main: Assertion `pvSource != NULL && pvSink != NULL' failed.
Aborted
위 결과에서 보시다시피 두 번째 my_memcpy() 실행 중에 assert()가 실패해서 실행이 취소되는 걸 확인할 수 있습니다.
assert()가 실패했을 때, 출력해주는 메시지를 살펴 보시기 바랍니다. 프로그래머가 특별히 입력인자로 주지도 않았는데 다음과 같은 부가적인 정보를 출력해서 디버깅이 용이하도록 해줍니다.
1. debug.c 라는 파일명을 출력해 주네요
2. 정확한 라인번호도 출력해 줍니다.
3. pvSource != NULL && pvSink != NULL 이라는 수식을 문자열로 출력해 줍니다.
너무 신기하지 않나요 ? 도대체 assert() 란 녀석이 어떤 마술을 부리길래 프로그래머가 주지도 않은 정보를 알아내서 저런 정보를 출력해 줄 수 있을까요 ? 전 처음에 이 assert() 란 녀석을 써보고서는 어찌나 신기했던지 어떻게 구현된지를 알아낼려고 한참을 헤멨습니다. 여러분도 궁금하시죠 ? 그럼 지금부터 하나 하나 그 비밀을 파헤쳐 보도록 하겠습니다.
assert() 란 녀석이 어떻게 구현되어 있는지를 알아내면 그 비밀을 알아낼 수 있을 것 같습니다. 우선 assert() 가 선언되어 있는 헤더 파일부터 뒤져보기로 하죠.
제가 지금 이 글을 쓰면서 쓰고 있는 컴파일러는 GCC 인데요, 그곳에서는 다음과 같이 assert()가 정의되어 있습니다.
/* 이해를 돕기 위해 간략하게 표현했습니다 */
extern void __assert_fail (__const char *__assertion,
__const char *__file,
unsigned int __line,
__const char *__function)
#define assert(expr) \
((void) ((expr) ? 0 : (__assert_fail (#expr, __FILE__, \
__LINE__, __func__), 0)))
일단 이걸 보면 assert() 가 그냥 함수가 아니라 매크로 함수인 것을 알 수 있습니다. 그리고 내부적으로는 __assert_fail() 이라는 또 다른 함수를 #expr, __FILE__, __LINE__, __func__ 라는 인자를 가지고 호출하는 걸 확인할 수 있습니다. 도대체 이런 듣도 보도 못한 애들은 어느 별에서 온 걸까요 ? 참 신기하긴 합니다만 신기해 하는 것으로 그쳐서는 안되고 진정한 골수 엔지니어라면 얘네들이 어떤 별에서 왔는지 무슨 일이 있어도 알아내야 되겠지요.
우선 #expr 부터 살펴 보겠습니다. 다음 코드를 한 번 컴파일하고 실행시켜 보시겠어요 ?
#include <stdio.h>
#define STRINGIFY(x) #x
int
return10(void)
{
return 10;
}
int
main(void)
{
printf("%s = %d\n", STRINGIFY(10 + 100), 10 + 100);
printf("%s = %d\n", STRINGIFY(strlen("printf")), strlen("printf"));
printf("%s returned %d\n", STRINGIFY(return10()), return10());
}
컴파일한 후 실행시켜 보았더니 이런 결과가 나오네요.
$ gcc -o stringify stringify.c
$ ./stringify
10 + 100 = 110
strlen("printf") = 6
return10() returned 10
어~! STRINGIFY()를 호출하면 STRINGIFY로 넘겨준 인자가 그냥 그대로 문자열 리터럴이 되어 버리네요. 아~! 그렇구나. 매크로 함수로 넘겨준 인자에 '#'를 붙이면 전처리기가 그걸 문자열 리터럴로 바꿔주나 봅니다. 그것 참 쓸모 있을 것 같습니다.
다음은 __FILE__, __LINE__, __func__ 를 알아보도록 하겠습니다.
__FILE__ 매크로는 컴파일시에 파일명을 나타내는 문자열 리터럴로 치환되고 __LINE__ 은 소스 코드 라인번호로 치환됩니다. 그리고, __func_ 는 매크로가 아니라 컴파일러에 의해 자동으로 선언되는 변수로서 함수명을 나타내는 문자열을 가리키게 됩니다. __FILE__ 은 문자열 리터럴이고, __LINE__ 은 정수 리터럴이고, __func__ 는 자동으로 정의되는 변수라는 점에 주의해야 합니다. __func__ 와 비슷한 역할을 하는 녀석이 __FUNCTION__ 이라는 녀석입니다. 다음 코드를 컴파일해서 실행해 볼까요 ?
/* debug2.c */
#include <stdio.h>
#include <assert.h>
int
main(void)
{
printf("%s() at %s::%05d\n", __FUNCTION__, __FILE__, __LINE__);
printf("%s() at %s::%05d\n", __func__, __FILE__, __LINE__);
assert(1 == 0);
return 0;
}
Windows XP 에서 cygwin GCC(3.4.4)로 컴파일해서 실행해 봤더니 다음과 같은 결과가 나오는 군요.
$ ./debug2
main() at debug2.c::00009
main() at debug2.c::00010
assertion "1 == 0" failed: file "debug2.c", line 11
38 [sig] debug2 5940 C:\cygwin\home\김윤수\work\debug2.exe: *** fatal error - called with threadlist_ix -1
Hangup
주의할 점은 __FUNCTION__ 은 비표준으로 컴파일러 벤더들이 자체적으로 제공하는 확장 매크로로 preprocessing 중에 문자열 리터럴로 치환되는 반면 __func__ 는 C99 표준에 포함된 것으로 컴파일러에 의해 자동적으로 정의되는 const char * 형의 변수라는 점입니다.
일단 GCC는 __FUNCTION__ 과 __func__ 둘 다를 지원하는 반면 Microsoft Visual C++ 2005의 cl은 __FUNCTION__ 만 지원하는 군요. 또 신기한 점은 GCC, G++은 __FUNCTION__ 을 __func__ 와 동일하게 처리한다는 점입니다. 위에서 컴파일해 본 debug2.c 에 대해 preprocessing 한 결과를 살펴 보면 매크로가 아니라 변수로 취급하는 걸 알 수 있습니다.
$ gcc -E debug2.c > debug2.pre.c
$ cat debug2.pre.c
......
int
main(void)
{
printf("%s() at %s::%05d\n", __FUNCTION__, "debug2.c", 10);
printf("%s() at %s::%05d\n", __func__, "debug2.c", 11);
((1 == 0) ? (void)0 : __assert("debug2.c", 12, "1 == 0"));
return 0;
}
위에서 첫번째 명령에서 gcc 의 -E option은 preprocessing 한 결과를 표준출력으로 내보내라라는 옵션입니다. 위 명령들은 그걸 리다이렉션해서 debug2.pre.c 라는 파일로 저장해서 그 내용을 살펴본 것입니다. (각 컴파일러에서 preprocessing 만 하게 하는 옵션을 알아두면, 매크로 치환하면서 문제가 발생하는 경우 쉽게 디버깅할 수 있습니다. 꼭 알아 두시기를 권유합니다.)
__FUNCTION__, __func__ 이 매크로였다면 preprocessing 후에는 둘 다 __FILE__ 처럼 문자열 리터럴로 치환되어야 함에도 원래 이름대로 그대로 남아 있는 것은 전처리기가 처리하지 않는다는 뜻이 될 것입니다.
위에서 assert() 가 어떻게 정의되어 있는지 보여드렸을 때는 간략하게 하기 위해 복잡한 조건 컴파일을 보여드리지 않았는데요, 실제로는 다음과 같이 NDEBUG(No debugging 의 약자라고 보시면 됩니다)가 정의되어 있느냐에 따라 조건 컴파일이 되도록 정의되어 있습니다.
#ifdef NDEBUG /* required by ANSI standard */
#define assert(expr) ((void)0)
#else
/* 아까 나온 부분. 이해를 돕기 위해 간략하게 표현했습니다 */
......
#define assert(expr) \
((void) ((expr) ? 0 : (__assert_fail (#expr, __FILE__, \
__LINE__, __func__), 0)))
#endif
즉, NDEBUG 가 정의되어 있으면(다르게 표현하면 디버깅 버전이 아니라는 뜻이겠지요), assert() 가 아무런 영향을 미치지 않고, 아무것도 정의되어 있지 않으면 assert()가 영향을 미치는 것이겠지요. NDEBUG는 ANSI 표준에 의해 정의된 매크로이기 때문에 대부분의 컴파일러가 지원할 것으로 보입니다. 앞에서 작성했던 debug2.c 를 다음과 같이 NDEBUG를 정의한 채로 컴파일한 후 실행하면 assert()가 아무런 영향을 미치지 않는 것을 확인할 수 있습니다.
$ gcc -o debug2 -DNDEBUG debug2.c
$ ./debug2
main() at debug2.c::00010
main() at debug2.c::00011
이렇게 디버깅 버전과 Production 버전에 따라 여러 가지 코드가 포함되고 포함되지 않게 하는 것은 실제 프로젝트에서 일상적으로 활용되는 방법입니다. 개발하는 동안에는 디버깅 버전으로 원래의 실행 로직외에 다양한 코드 또는 정보들이 실행 파일에 포함되게 함으로써 문제가 발생했을 때 신속하게 찾을 수 있게 도와주고, Production 버전에서는 성능을 개선하고 실행파일의 크기를 줄이기 위해 그런 부가적인 정보 또는 코드를 없애버리는 것이지요
마지막으로 한 가지 더 주의할 점을 알려 드리겠습니다. __FUNCTION__ 은 컴파일러 벤더들이 나름대로 정의한 확장 매크로이기 때문에 portability 가 떨어지고, __func__ 는 최신 C99 규격에 포함된 것이라 portability 가 약간 떨어진다는 것입니다. 물론 장기적으로는 __func__ 를 쓰는 것이 유리하겠지만(표준이니까 __func__ 를 지원하는 컴파일러가 많이 생길 것으로 기대할 수 있으므로), Microsoft Visual C++ 2005 버전도 지원하지 않는 걸 보니 __func__도 본격적으로 쓰일 수 있으려면 아직 갈 길이 먼 것 같습니다. 정리하자면 portability 가 중요하다면 __FUNCTION__ 이나 __func__ 를 전혀 쓰지 않거나 아니면 쓰더라도 컴파일러에서 __FUNCTION__ 이나 __func__이 지원되는 여부에 따라서 다르게 처리되도록 해야할 것입니다. 더 상세한 정보를 얻기 원하시면 다음 링크를 참고하시기 바랍니다.
- __LINE__, __FUNCTION__, and __FILE__ macros
- C, C++ 언어에서 디버깅시에 유용하게 쓸 수 있는 predefined macro 에 대한 설명
- Pre-defined C/C++ Compiler Macros
- 다양한 C/C++ 컴파일러에서 정의된 표준 및 비표준 predefined macro 목록을 잘 정의해 둔 곳
이번 글에서는 다음과 같은 사항을 기억하시면 될 것입니다.
- 매크로 함수 정의에서 인자 x 에 대해 #x 라고 쓰면 x 가 문자열 리터럴로 바뀝니다.
- __FUNCTION__ 또는 __func__ 는 현재 함수명을 출력하는 데 사용할 수 있습니다. 단, __FUNCTION__, __func__ 모두 portability 측면에서 약간 문제가 있으므로 주의해서 사용해야 합니다.
- __FILE__ 은 현재 파일명을 출력하는 데 사용할 수 있습니다.
- __LINE__ 은 현재 라인번호를 출력하는 데 사용할 수 있습니다.
- 조건부 컴파일을 이용해서 디비깅용 빌드와 Production 빌드를 구분하는 방법을 사용할 수 있어야 합니다.
- 컴파일러 옵션 중 preprocessing 만 하는 옵션을 알아두면 매크로 함수를 디비겅하는데 유용하게 사용될 수 있습니다.
자~ 그럼 이상으로 해서 로깅 라이브러리를 설계/구현하기 위한 여정에 필수적인 도구들을 다 챙긴 것 같습니다. 다음 글부터는 본격적으로 로깅 라이브러리를 설계/구현해 보도록 하겠습니다.
고절가주팁이 쭉~ 갈 수 있도록 많은 관심 부탁드리고, 혹시 잘못된 부분이나 보완할 부분이 있으면 언제라도 알려주세요. 여러분이 알고 있는 팁을 트랙백이나 댓글로 좀 알려 주시면 정말 감사하겠습니다.
블로그를 구독하는 방법을 잘 모르시는 분은 2. RSS 활용을 클릭하세요.
RSS에 대해 잘 모르시는 분은 1. RSS란 무엇인가를 클릭하세요.
이상계는 이쪽에 속해있지 않고 저쪽에 속해 있다. 이쪽에 사는 우리는 이쪽에 머무르지 않고 저쪽을 꿈꾸며 살아야 한다. 여기 오는 모든이들이 저쪽의 충만함을 이쪽에서의 매일의 삶에 경험할 수 있기를...
E-mail: (yesarang) at (yahoo.co.kr)
