ACE_日志的使用

ACE_DEBUG介绍及日志输出

ACE_DEBUG  常规的一些输出消息   
ACE_ERROR  会提供程序出错的一些低级消息

2个宏的用法上是一致的
  ACE_DEBUG(错误级别,"格式串",变量1...变量N）
  
  其中部分错误级别系统定义如下：
   LM_SHUTDOWN = 01,系统死机级别
    LM_TRACE = 02,跟踪级别
    LM_DEBUG = 04,DEBUG级别
    LM_INFO = 010,常规信息级别
    LM_NOTICE = 020,注意级别
    LM_WARNING = 040,警告级别
    LM_STARTUP = 0100,启动级别
    LM_ERROR = 0200,错误级别
    LM_CRITICAL = 0400,危急级别
    LM_ALERT = 01000,可修复的警告级别
    LM_EMERGENCY = 02000,全局警告级别
  部分格式串使用如下：
   跟c 中printf使用类似
   %n-表当前程序名称
   %t-表当前线程号
   %p-表指针
   %s-字符串
 
ACE通过全局单体实例 ACE_LOG_MSG 管理和控制输出，我们可以利用这个实例把输出重定向

到文件，也可以重定向到标志输出
其中还可以控制什么级别的消息可被输出，简单使用如下：

  ACE_LOG_MSG->set_flags (ACE_Log_Msg::STDERR); 
  设置输出到标准错误输出
  ACE_LOG_MSG->clr_flags (ACE_Log_Msg::STDERR);
  关闭输出到标志错误输出
  ACE_LOG_MSG->set_flags (ACE_Log_Msg::OSTREAM);
  ofstream myostream (filename, ios::out | ios::trunc);
  ACE_LOG_MSG->msg_ostream (&myostream);
  设置输出到文件
  u_long priority_mask =ACE_LOG_MSG->priority_mask (ACE_Log_Msg::PROCESS);
  ACE_SET_BITS (priority_mask,LM_DEBUG |LM_INFO);
  设置只记录LM_DEBUG 或者LM_INFO级别的消息
  ACE_CLR_BITS (priority_mask,LM_DEBUG | LM_INFO);                    
  清除设置条件
ACE_LOG_MSG还有一个非常有意思的功能，能以16进制方式输出内存中的块 ,简单使用如下: 
      ACE_LOG_MSG->log_hexdump (LM_DEBUG,
                                (char *) array,
                                sizeof array);

下面附上一个使用例子，例子来源于ACE包中的例子程序
#include "ace/OS_main.h"
#include "ace/streams.h"
#include "ace/Log_Msg.h"
int
ACE_TMAIN (int, ACE_TCHAR *[])
{
  // 这个消息将输出到STDERR
  ACE_DEBUG ((LM_DEBUG,
              "first message\n"));
  ACE_LOG_MSG->clr_flags (ACE_Log_Msg::STDERR);
  // 这个消息将不被输出，因为标志位清除了
  ACE_DEBUG ((LM_DEBUG,
              "second message\n"));
  ACE_LOG_MSG->set_flags (ACE_Log_Msg::OSTREAM);
  //这个消息将不被输出，因为流的实体尚未定义
  ACE_DEBUG ((LM_DEBUG,
              "third message\n"));
  //建立一个流实体，指向d:\output.log文件
  const char *filename = "d:\\output.log";
  ofstream myostream (filename, ios::out | ios::trunc);
  if (myostream.bad ())
    return 1;
  // 设置输出到流
  ACE_LOG_MSG->msg_ostream (&myostream);
  //这个消息将输出到文件中
  ACE_DEBUG ((LM_DEBUG,
              "fourth message\n"));
  ACE_LOG_MSG->set_flags (ACE_Log_Msg::STDERR);
  // 这个消息将同时输出到文件和STDERR
  ACE_DEBUG ((LM_DEBUG,
              "fifth message\n"));
  return 0;
}

//更详细的讲解：

绍了ACE中日志系统(Logging Facility）的基本使用

一、简介
以前曾介绍过一个开源日志系统log4cplus，ACE也有自己的Logging Facility，与log4cplus相似，ACE日志系统
也具有线程安全、灵活、分级显示等特点，可以面向程序调试、运行、测试、和维护等全生命周期，可以选择将
信息输出到屏幕、文件、系统日志（如Windows下的Event log）、甚至是远程服务器。除此之外，ACE日志系统
支持回调函数以及运行时刻动态配置（Runtime Configuration ），本文主要参考了《ACE Programmer's Guide,
The: Practical Design Patterns for Network and Systems Programming》。

二、ACE日志系统的基本使用

首先通过一个引例介绍如何调用ACE Log Macro：

#include < ace/Log_Msg.h >

int ACE_TMAIN (int, ACE_TCHAR *[])
{
  ACE_DEBUG ((LM_INFO, ACE_TEXT ("Hi ACE Logging Facility!\n")));
  return 0;
}

程序需要包含头文件：Log_Msg.h，该文件定义了各种有用的日志输出宏，宏ACE_TMAIN 是ACE定义的
wide-character-enabled entry point ，ACE日志系统缺省输出到stderr，所以对于Console类型的应用程序，
会直接输出到屏幕。运行该程序时屏幕上会显示：
 Hi ACE Logging Facility!

可以看出ACE日志系统的宏调用非常简单：
 ACE_XXX((severity, formatting-args));

其中，ACE_XXX表示日志输出宏（ACE Logging Macros），包括：
ACE_ERROR((level, string, ...))
ACE_DEBUG((level, string, ...))
ACE_TRACE(string)
ACE_ASSERT(test)
ACE_HEX_DUMP((level, buffer, size [,text]))
ACE_RETURN(value)
ACE_ERROR_RETURN((level, string, ...), value)
ACE_ERROR_INIT( value, flags )
ACE_ERROR_BREAK((level, string, ...))

severity即输出的严重等级（Severity Level），包括：
LM_TRACE  Messages indicating function-calling sequence
LM_DEBUG  Debugging information
LM_INFO   Messages that contain information normally of use only when debugging a program
LM_NOTICE  Conditions that are not error conditions but that may require special handling
LM_WARNING  Warning messages
LM_ERROR  Error messages
LM_CRITICAL  Critical conditions, such as hard device errors
LM_ALERT  A condition that should be corrected immediately, such as a corrupted database
LM_EMERGENCY     A panic condition, normally broadcast to all usersLM_TRACE Messages indicating
                 function-calling sequence

formatting-args是要输出的内容，格式类似于printf函数的输出格式：

Code        Argument Type   Displays

A           ACE_timer_t     浮点数
a           —              导致程序终止（Abort）
c           char            单个字符
C           char*           字符串（narrow characters）
i,d         int             10进制整数
I           —              缩进
e,E,f,F,g,G double          双精度浮点数
l           —              行号
M           —              severity level的名称
m           —              错误号（errorno）
N           —              文件名
n           —              ACE_Log_Msg::open()指定的程序名
o           int             八进制整数
P           —              当前进程ID
p           ACE_TCHAR*      字符串，后接错误号，同perror
Q           ACE_UINT64      64位无符号十进制整数
r           void (*)()      函数调用
R           int             十进制整数
S           int             数字对应的信号名称
s           ACE_TCHAR*      ACE_TCHAR类型的字符串
T           —              当前时间（hour:minute:sec.usec）
D           —              时戳（month/day/year/hour:minute:sec.usec）
t           —              当前线程ID
u           int             无符号十进制整数
w           wchar_t         Single wide character
W           wchar_t*        Wide-character string
x,X         int             十六进制数
@           void*           指针（十六进制）
%           N/A             %

我们可以通过一些例子来进一步了解如何使用这些宏、Severity Level和格式，在开始之前，首先澄清一个概念：
一些日志系统（如log4cplus）是靠宏名来区分日志信息类型的，比如：
    LOG4CPLUS_DEBUG(Logger::getRoot(),"some text")   /* DEDUG 类型 */
    LOG4CPLUS_ERROR(Logger::getRoot(),"some text")   /* ERROR 类型 */
    
ACE的日志系统不是靠宏名本身，而是靠宏的第一个参数，即Severity Level来区分日志信息类型：

    ACE_DEBUG((LM_DEBUG, ACE_TEXT ("some text\n"))); /* DEDUG 类型 */
    ACE_ERROR((LM_DEBUG, ACE_TEXT ("some text\n"))); /* DEDUG 类型 */
    ACE_DEBUG((LM_ERROR, ACE_TEXT ("some text\n"))); /* ERROR 类型 */
    ACE_ERROR((LM_ERROR, ACE_TEXT ("some text\n"))); /* ERROR 类型 */

从这个角度考虑，宏ACE_DEBUG和ACE_ERROR没有什么区别，几乎可以混用，这两个宏的区别主要体现在两方面：

a) 语义上的差别
b) 语句执行完后，op_status不同，比如：

    ACE_Log_Msg *lm = ACE_LOG_MSG;
    ACE_DEBUG ((LM_ERROR, ACE_TEXT ("some text\n")));
    ACE_ASSERT( 0 == lm->op_status() );  /* ACE_DEBUG执行完后，op_status 是0 */
    ACE_ERROR ((LM_ERROR, ACE_TEXT ("some text\n")));
    ACE_ASSERT( -1 == lm->op_status() ); /* ACE_ERROR执行完后，op_status 是-1 */
    
下面举一些典型用例：

【use-case1】 如何在编译时刻Enabling 或Disabling Logging Macros

在#include < ace/Log_Msg.h >之前定义一些宏，可以在编译时刻Enable/Disable logging Macros

/* disable ACE_DEBUG and ACE_ERROR */
#define ACE_NLOGGING

/* enable ACE_DEBUG and ACE_ERROR（缺省） */
#undef ACE_NLOGGING

/* enable ACE_ASSERT（缺省） */
#undef ACE_NDEBUG

/* disable ACE_ASSERT */
#define ACE_NDEBUG

/* enable ACE_TRACE */
#define ACE_NTRACE 0

/* disable ACE_TRACE（缺省） */
#define ACE_NTRACE 1

【use-case2】格式使用

a) 打印完结果后终止（Abort）

    ACE_DEBUG ((LM_DEBUG, ACE_TEXT ("begin %a end \n")));

输出以下信息后提示Abort信息：
begin Aborting... end

b) 缩进

int ACE_TMAIN (int, ACE_TCHAR *[])
{
    ACE_TRACE("main");
    ACE_DEBUG ((LM_DEBUG, ACE_TEXT ("%Itext\n")));
    return 0;
}

输出：
(700) calling main in file `D:\aceprj\testlog\main.cpp' on line 24
    text
(700) leaving main

（其中，700是ACE_TRACE控制输出的当前线程ID）

c) HEX Dump（调试时候比较有用）
    char szBuf[128] = "hello world!";
    ACE_HEX_DUMP((LM_DEBUG, szBuf, 128,"szBuf: "));

输出：

szBuf:  - HEXDUMP 128 bytes
68 65 6c 6c 6f 20 77 6f  72 6c 64 21 00 00 00 00   hello world!....
00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00   ................
00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00   ................
00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00   ................
00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00   ................
00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00   ................
00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00   ................
00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00   ................

d)函数调用

void foo(void)
{
    ACE_DEBUG ((LM_DEBUG, ACE_TEXT ("in func foo\n")));
}

int ACE_TMAIN (int, ACE_TCHAR *[])
{
    ACE_DEBUG ((LM_DEBUG, ACE_TEXT ("call function %r\n"),foo));
    return 0;
}

输出：
in func foo
call function

e) 进制转换
    ACE_UINT64 uint64A = 210113198510308319;
    int hexA = 0xBEEE3F;
    int octA = 9;
    ACE_timer_t tmInterval = 0.000001;
    
    ACE_DEBUG ((LM_DEBUG, ACE_TEXT ("UINT64: %Q\n"),uint64A));
    ACE_DEBUG ((LM_DEBUG, ACE_TEXT ("HEX: %X, hex: %x\n"),hexA,hexA));
    ACE_DEBUG ((LM_DEBUG, ACE_TEXT ("Ptr in hex:%@\n"),&hexA));
    ACE_DEBUG ((LM_DEBUG, ACE_TEXT ("Octal number of 9:%o\n"),octA));
    ACE_DEBUG ((LM_DEBUG, ACE_TEXT ("timer's Interval: %A\n"),tmInterval));

输出：
UINT64: 210113198510308319
HEX: BEEE3F, hex: beee3f
Ptr in hex:0012FE30
Octal number of 9:11
timer's Interval: 0.000001

f)综合使用
    ACE_DEBUG ((LM_DEBUG, ACE_TEXT ("%D, %M, [%t], Line:%l\n")));
    ACE_DEBUG ((LM_ERROR, ACE_TEXT ("%D, %M, [%t], Line:%l\n")));
    
输出：
    Mon Mar 20 2005 20:02:16.912000, LM_DEBUG, [3296], Line:24
    Mon Mar 20 2006 20:02:16.912000, LM_ERROR, [3296], Line:25
    
    
【use-case3】宏使用

a) ACE_RETURN

int foo(void)
{
    ACE_RETURN(3);
}

int ACE_TMAIN (int, ACE_TCHAR *[])
{
    foo();
    ACE_ASSERT( 3 == ACE_LOG_MSG->op_status() );
    return 0;
}

输出：（无任何输出）

b) ACE_ERROR_RETURN

int foo(void)
{
    ACE_ERROR_RETURN((LM_DEBUG,"Return error\n"), 3);
}

int ACE_TMAIN (int, ACE_TCHAR *[])
{
    foo();
    ACE_ASSERT( 3 == ACE_LOG_MSG->op_status() );
    return 0;
}

输出：
Return error

c) ACE_ERROR_BREAK

    int i = 0;

    while(1)
    {
        if( i > 10 )
        {
            ACE_ERROR_BREAK((LM_DEBUG,"break from while\n"));
        }

        i++;
    }

    ACE_DEBUG((LM_DEBUG, "i = %d\n", i));

输出：
break from while
i = 11

【use-case4】 如何在运行时刻Enabling 或Disabling Logging Severities

由于缺省情况下在进程范围内所有logging severities都会被输出，因此需要通过priority_mask、
ACE_Log_Msg::enable_debug_messages、ACE_Log_Msg::disable_debug_messages来过滤输出。

其中priority_mask的用法如下：

    /* Get the current ACE_Log_Priority mask. */
    u_long priority_mask (MASK_TYPE = THREAD);

    /* Set the ACE_Log_Priority mask, returns original mask. */
    u_long priority_mask (u_long, MASK_TYPE = THREAD);

这里MASK_TYPE可选择：ACE_Log_Msg::PROCESS（作用范围是进程）或ACE_Log_Msg::THREAD（作用范围是线程）

enable_debug_messages/disable_debug_messages的用法如下：

    static void disable_debug_messages
    (ACE_Log_Priority priority = LM_DEBUG);

    static void enable_debug_messages
    (ACE_Log_Priority priority = LM_DEBUG);

这里输入参数可选择任意需要打开或屏蔽的logging severity，不像函数名称暗示的那样只能控制LM_DEBUG
类型，另外由于是静态函数，enable_debug_messages/disable_debug_messages的设置对整个进程有效。

注意一下priority_mask与enable_debug_messages/disable_debug_messages的区别：
priority_mask将进程（或线程）的logging severitys用其第一个参数所代替，清除之前的设置。
enable_debug_messages将进程的logging severitys用其参数去累加，不清除之前的设置。
disable_debug_messages将进程的logging severitys用其参数去屏蔽，不清除之前的设置。

a) 整个进程仅允许输出LM_ERROR和LM_WARNING
    ACE_DEBUG((LM_DEBUG, "Debug Text1\n"));
    ACE_DEBUG((LM_ERROR, "Error Text1\n"));
    
    ACE_LOG_MSG->priority_mask (LM_ERROR | LM_WARNING, ACE_Log_Msg::PROCESS);
    
    ACE_DEBUG((LM_DEBUG, "Debug Text2\n"));
    ACE_DEBUG((LM_ERROR, "Error Text2\n"));
    
或者：
    ACE_DEBUG((LM_DEBUG, "Debug Text1\n"));
    ACE_DEBUG((LM_ERROR, "Error Text1\n"));

    /* 禁用了进程所有的logging severitys */
    ACE_LOG_MSG->priority_mask (0, ACE_Log_Msg::PROCESS);
    ACE_Log_Msg::enable_debug_messages (LM_ERROR);
    ACE_Log_Msg::enable_debug_messages (LM_WARNING);

    ACE_DEBUG((LM_DEBUG, "Debug Text2\n"));
    ACE_DEBUG((LM_ERROR, "Error Text2\n"));
    
    
输出：
Debug Text1
Error Text1
Error Text2

b) 每个线程控制各自的logging severity
#include < ace/Task.h >    /* for ACE_Thread_Manager */
#include < ace/Log_Msg.h >
void service(void)
{
 ACE_LOG_MSG->priority_mask (LM_INFO, ACE_Log_Msg::THREAD);
 ACE_DEBUG((LM_DEBUG, "in service, MsgType:%M,  ThreadID: %t\n"));
 ACE_DEBUG((LM_INFO,  "in service, MsgType:%M,  ThreadID: %t\n"));
}
void worker(void)
{
 ACE_LOG_MSG->priority_mask (LM_DEBUG, ACE_Log_Msg::THREAD);
 ACE_DEBUG((LM_DEBUG, "in worker,  MsgType:%M, ThreadID: %t\n"));
 ACE_DEBUG((LM_INFO,  "in worker,  MsgType:%M, ThreadID: %t\n"));
}
int ACE_TMAIN (int, ACE_TCHAR *[])
{
  ACE_LOG_MSG->priority_mask (0, ACE_Log_Msg::PROCESS);
 ACE_Thread_Manager::instance ()->spawn ((ACE_THR_FUNC)service);
 ACE_Thread_Manager::instance ()->spawn_n (3, (ACE_THR_FUNC)worker);
 ACE_Thread_Manager::instance ()->wait();
 return 0;
}
输出：
in service, MsgType:LM_INFO,  ThreadID: 3428
in worker,  MsgType:LM_DEBUG, ThreadID: 2064
in worker,  MsgType:LM_DEBUG, ThreadID: 1240
in worker,  MsgType:LM_DEBUG, ThreadID: 1800