catalog

Log system of DPDK

The dynamic type log system is introduced in the newer version of DPDK. In addition, in addition to the global log output originally supported, log output for a single module is also supported. In this paper, 18.05 version is described.

RTE_LOG macro

DPDK is packaged with RTE_LOG macro is used for developing App, as follows:

// x86_64-native-linuxapp-gcc/include/rte_log.h

/**
 * Generates a log message.
 *
 * The RTE_LOG() is a helper that prefixes the string with the log level
 * and type, and call rte_log().
 *
 * @param l
 *   Log level. A value between EMERG (1) and DEBUG (8). The short name is
 *   expanded by the macro, so it cannot be an integer value.
 * @param t
 *   The log type, for example, EAL. The short name is expanded by the
 *   macro, so it cannot be an integer value.
 * @param ...
 *   The fmt string, as in printf(3), followed by the variable arguments
 *   required by the format.
 * @return
 *   - 0: Success.
 *   - Negative on error.
 */
#define RTE_LOG(l, t, ...)                    \
     rte_log(RTE_LOG_ ## l,                    \
         RTE_LOGTYPE_ ## t, # t ": " __VA_ARGS__)

Visible, RTE_ The log macro contains variable length parameters, including two key required parameters:

1. Log level
2. Log type

The log level is defined as follows:

/* Can't use 0, as it gives compiler warnings */
#define RTE_LOG_EMERG    1U  /**< System is unusable.               */
#define RTE_LOG_ALERT    2U  /**< Action must be taken immediately. */
#define RTE_LOG_CRIT     3U  /**< Critical conditions.              */
#define RTE_LOG_ERR      4U  /**< Error conditions.                 */
#define RTE_LOG_WARNING  5U  /**< Warning conditions.               */
#define RTE_LOG_NOTICE   6U  /**< Normal but significant condition. */
#define RTE_LOG_INFO     7U  /**< Informational.                    */
#define RTE_LOG_DEBUG    8U  /**< Debug-level messages.             */

The log type is defined as follows:

/* SDK log type */                                                         
#define RTE_LOGTYPE_EAL        0 /**< Log related to eal. */               
#define RTE_LOGTYPE_MALLOC     1 /**< Log related to malloc. */            
#define RTE_LOGTYPE_RING       2 /**< Log related to ring. */              
#define RTE_LOGTYPE_MEMPOOL    3 /**< Log related to mempool. */           
#define RTE_LOGTYPE_TIMER      4 /**< Log related to timers. */            
#define RTE_LOGTYPE_PMD        5 /**< Log related to poll mode driver. */  
#define RTE_LOGTYPE_HASH       6 /**< Log related to hash table. */        
#define RTE_LOGTYPE_LPM        7 /**< Log related to LPM. */               
#define RTE_LOGTYPE_KNI        8 /**< Log related to KNI. */               
#define RTE_LOGTYPE_ACL        9 /**< Log related to ACL. */               
#define RTE_LOGTYPE_POWER     10 /**< Log related to power. */             
#define RTE_LOGTYPE_METER     11 /**< Log related to QoS meter. */         
#define RTE_LOGTYPE_SCHED     12 /**< Log related to QoS port scheduler. */
#define RTE_LOGTYPE_PORT      13 /**< Log related to port. */              
#define RTE_LOGTYPE_TABLE     14 /**< Log related to table. */             
#define RTE_LOGTYPE_PIPELINE  15 /**< Log related to pipeline. */          
#define RTE_LOGTYPE_MBUF      16 /**< Log related to mbuf. */              
#define RTE_LOGTYPE_CRYPTODEV 17 /**< Log related to cryptodev. */         
#define RTE_LOGTYPE_EFD       18 /**< Log related to EFD. */               
#define RTE_LOGTYPE_EVENTDEV  19 /**< Log related to eventdev. */          
#define RTE_LOGTYPE_GSO       20 /**< Log related to GSO. */ 

/* these log types can be used in an application */
#define RTE_LOGTYPE_USER1     24 /**< User-defined log type 1. */
#define RTE_LOGTYPE_USER2     25 /**< User-defined log type 2. */
#define RTE_LOGTYPE_USER3     26 /**< User-defined log type 3. */
#define RTE_LOGTYPE_USER4     27 /**< User-defined log type 4. */
#define RTE_LOGTYPE_USER5     28 /**< User-defined log type 5. */
#define RTE_LOGTYPE_USER6     29 /**< User-defined log type 6. */
#define RTE_LOGTYPE_USER7     30 /**< User-defined log type 7. */
#define RTE_LOGTYPE_USER8     31 /**< User-defined log type 8. */

/** First identifier for extended logs */
#define RTE_LOGTYPE_FIRST_EXT_ID 32 

DPDK App uses RTE_ A simple example of log is as follows:

RTE_LOG(INFO, EAL, "Just a test.\n");

But it's usually RTE_LOG in the package layer:

#define DPDK_APP_LOG(level,...) RTE_LOG(level, DPDK_APP, "["#level"] "__VA_ARGS__)

rte_log and rte_vlog function

int rte_log(uint32_t level, uint32_t logtype, const char *format, ...)
{
    va_list ap;
    int ret;    
    va_start(ap, format);
    ret = rte_vlog(level, logtype, format, ap);
    va_end(ap);
    return ret;
}       

rte_ The log function is very simple, which is the implementation of a variable length function. It directly calls rte_vlog function.

int rte_vlog(uint32_t level, uint32_t logtype, const char *format, va_list ap)
{ 
    int ret;
    FILE *f = rte_logs.file;  /* Log output to the terminal or file pointed to by the global variable */

	/* Print to default terminal if global variable is not set */
    if (f == NULL) {
		/* default_log_stream The setting of is in eal_ log_ set_ The default function is set when the log is initialized */
        f = default_log_stream; 
        /* If the default output location is not set, output directly to stderr */
        if (f == NULL) { 
            f = stderr; 
        } 
    }
	/* If the current printing level exceeds the set global level, exit directly */
    if (level > rte_logs.level) 
        return 0; 

	/* If the current log type is out of range, exit directly and return - 1, indicating there is a problem */
    if (logtype >= rte_logs.dynamic_types_len)
        return -1;
        
	/* If the current log level exceeds the level set by the current module, exit directly */
    if (level > rte_logs.dynamic_types[logtype].loglevel) 
        return 0; 

    /* save loglevel and logtype in a global per-lcore variable */        
    /* Record the current printing level, which is currently used when calling syslog function */
    RTE_PER_LCORE(log_cur_msg).loglevel = level; 
    RTE_PER_LCORE(log_cur_msg).logtype = logtype;

    ret = vfprintf(f, format, ap); 
    fflush(f); 
    return ret;
} 

Log module initialization

The initialization of DPDK log module is divided into two parts:

1. The first stage (pre initialization of log module): it is the initialization performed when the DPDK module is loaded, which enables the log module to be used in the initialization of other modules of DPDK.
2. The second stage (log module post initialization): in DPDK environment abstraction layer initialization (rte_eal_init) to set the output of the log module.

First stage initialization

rte_logs structure type:

struct rte_logs {
    uint32_t type;  /**< Bit fields for enabled logs */
    uint32_t level; /**< log level */
    FILE *file;     /**< By RTE_ openlog_ The output file specified by stream, or NULL */
    size_t dynamic_types_len; /**< Number of dynamic log types */
    struct rte_log_dynamic_type *dynamic_types;  /**< Store the name and level of each dynamic type */
};  

• type: indicates the bitmask of the enabled logs module. In version 18.05, this variable is not used.
• Level: indicates the global log level. Only logs no larger than this level are output.
• File: indicates where the log is output. It can be a terminal or a specified file.
• dynamic_types_len: indicates the number of dynamic log types. For each type added, the variable is increased by 1.
• dynamic_types: refers to the structure representing the dynamic log type. The level of setting the name of the saved log type is defined as follows:

struct rte_log_dynamic_type {
    const char *name;		/* Name of the log type */
    uint32_t loglevel;		/* For the log level of this log type, the log module only outputs logs no larger than this level and no larger than the global log level */
};      

Define rte_logs global log variable:

/* global log structure */
struct rte_logs rte_logs = {
    .type = ~0, 			/* Enable all log types by default */
    .level = RTE_LOG_DEBUG, /* The default level is DEBUG, i.e. output all logs */
    .file = NULL,
};

Initialization of the first stage:

RTE_INIT_PRIO(rte_log_init, LOG);

static void rte_log_init(void)
{
    uint32_t i;

	/* Set up rte_logs.level */
    rte_log_set_global_level(RTE_LOG_DEBUG);

	 /* Allocate memory for all log types, default total RTE_LOGTYPE_FIRST_EXT_ID (32) types */
    rte_logs.dynamic_types = calloc(RTE_LOGTYPE_FIRST_EXT_ID,
        sizeof(struct rte_log_dynamic_type));
        
    if (rte_logs.dynamic_types == NULL)
        return;
    /* register legacy log types */
    for (i = 0; i < RTE_DIM(logtype_strings); i++)
    	/* Register logtype_ All log types defined in strings [] */
        __rte_log_register(logtype_strings[i].logtype,
                logtype_strings[i].log_id);    
    rte_logs.dynamic_types_len = RTE_LOGTYPE_FIRST_EXT_ID;
}   

logtype_ The strings [] array is defined as follows:

struct logtype {        
    uint32_t log_id;    
    const char *logtype;
}; 

static const struct logtype logtype_strings[] = {
    {RTE_LOGTYPE_EAL,        "lib.eal"},
    {RTE_LOGTYPE_MALLOC,     "lib.malloc"}, 
    {RTE_LOGTYPE_RING,       "lib.ring"}, 
    {RTE_LOGTYPE_MEMPOOL,    "lib.mempool"},
......
    {RTE_LOGTYPE_EVENTDEV,   "lib.eventdev"},
    {RTE_LOGTYPE_GSO,        "lib.gso"},     
    {RTE_LOGTYPE_USER1,      "user1"},       
    {RTE_LOGTYPE_USER2,      "user2"},       
    {RTE_LOGTYPE_USER3,      "user3"},       
    {RTE_LOGTYPE_USER4,      "user4"},       
    {RTE_LOGTYPE_USER5,      "user5"},       
    {RTE_LOGTYPE_USER6,      "user6"},       
    {RTE_LOGTYPE_USER7,      "user7"},       
    {RTE_LOGTYPE_USER8,      "user8"}        
}; 

Wei rte_ log_ The register function registers the log type and saves the id and type name representing the log type to rte_logs.dynamic_types, return the type in RTE_ logs.dynamic_ The index in types, so these log types, such as RTE_LOGTYPE_EAL, etc., also became the type in RTE_ logs.dynamic_ Index in types:

static int __rte_log_register(const char *name, int id)           
{   
    char *dup_name = strdup(name);
    if (dup_name == NULL)                              
        return -ENOMEM;
    rte_logs.dynamic_types[id].name = dup_name;
    rte_logs.dynamic_types[id].loglevel = RTE_LOG_INFO;
    return id;
}

Finally, set the number of log types:

rte_logs.dynamic_types_len = RTE_LOGTYPE_FIRST_EXT_ID;

It can be seen that the first stage of log module initialization is to complete the log configuration of DPDK itself and provide log support for subsequent loading of other DPDK modules.

Second stage initialization

The post initialization of the log module is done through RTE_ eal_ Calling rte_ in init function eal_ log_ The init function is defined as follows:

int rte_eal_log_init(const char *id, int facility) 
{
    FILE *log_stream; 
    log_stream = fopencookie(NULL, "w+", console_log_func);
    if (log_stream == NULL) 
        return -1;
    openlog(id, LOG_NDELAY | LOG_PID, facility);  
    eal_log_set_default(log_stream); 
    return 0;
}

First, a standard I / O stream is created using the fopencook function:

extern FILE *fopencookie (void *__restrict __magic_cookie,
              const char *__restrict __modes,
              _IO_cookie_io_functions_t __io_funcs) __THROW __wur;

• Wei magic_cookie: a custom data structure for__ io_funcs can be NULL.
• Wei modes: the same as fopen, including r, w, a, r +, w +, a +, etc.
• Wei io_funcs: a function set consisting of four function pointers (read, write, seek, close), which need to be implemented by the user.

console_log_func functions are defined as follows:

static cookie_io_functions_t console_log_func = {
    .write = console_log_write,
};

Since the log module only needs to output strings, the variable only implements the write function console_ log_ The write function is defined as follows:

static ssize_t
console_log_write(__attribute__((unused)) void *c, const char *buf, size_t size)
{ 
    char copybuf[BUFSIZ + 1]; 
    ssize_t ret;
    uint32_t loglevel;
    /* Output log content to stdout standard output */
    ret = fwrite(buf, 1, size, stdout);
    fflush(stdout);

    /* truncate message if too big (should not happen) */
	/* syslog Log output, BUFSIZ characters at most */
    if (size > BUFSIZ)
        size = BUFSIZ;

    /* Syslog error levels are from 0 to 7, so subtract 1 to convert */
	/* Calculates the syslog log output level. Since the level definition starts from 1, you need to subtract 1 */
    loglevel = rte_log_cur_msg_loglevel() - 1;
    memcpy(copybuf, buf, size);
    copybuf[size] = '\0';

    /* Write syslog log */
    syslog(loglevel, "%s", copybuf);

    return ret;
} 

syslog log initialization:

openlog(id, LOG_NDELAY | LOG_PID, facility);

Set the output object of DPDK log module:

eal_log_set_default(log_stream);

The log just created and initialized_ Stream, assign to default_log_stream. According to the previous RTE_ The vlog function is used when outputting logs. That is to say, by default, DPDK's standard log module will output log information to stdout and syslog.

It can be seen that the initialization of DPDK log module in the second stage mainly focuses on the use and printing mode of logs. In fact, these are mainly set by DPDK App.

Register a new log type

In addition to the default log type of DPDK, the log system of DPDK also supports the registration of new log types for DPDK App, that is, the so-called dynamic calorific value type system.

1. Add a new log type via rte_log_register function to add a new log type to the system. This function is defined as follows:

/* register an extended log type */                            
int rte_log_register(const char *name)
{
    struct rte_log_dynamic_type *new_dynamic_types;            
    int id, ret; 

	/* At RTE_ logs.dynamic_ In types, query whether the log type with the same name has been registered. If it has been registered, the index of the type will be returned directly */
    id = rte_log_lookup(name); 
    if (id >= 0) 
        return id; 

	/* Reallocate memory for new types, for rte_logs.dynamic_types increase the space of a type and point it to a new type */
    new_dynamic_types = realloc(rte_logs.dynamic_types,        
        sizeof(struct rte_log_dynamic_type) * (rte_logs.dynamic_types_len + 1));                     
    if (new_dynamic_types == NULL)
        return -ENOMEM; 
    rte_logs.dynamic_types = new_dynamic_types; 
    
	/* Register the new type to RTE_ logs.dynamic_ In types, the index is RTE_ logs.dynamic_ The newly allocated position in types space */
    ret = __rte_log_register(name, rte_logs.dynamic_types_len);
    if (ret < 0) 
        return ret; 
        
	/* Increase in total types */
    rte_logs.dynamic_types_len++; 
    return ret; 
} 

1. Set / get the print level of the log, including the global log print level acquisition and setting functions, as well as the specified module log print level acquisition and setting functions. It is defined as follows:

/* Set global log level */   
/* Set global log print level */                     
void rte_log_set_global_level(uint32_t level) 
{
    rte_logs.level = (uint32_t)level;             
} 

/* Get global log level */  
/* Get global log print level */                      
uint32_t rte_log_get_global_level(void)                    
{  
    return rte_logs.level;                        
}  

/* Gets the print level of the specified log type */
int rte_log_get_level(uint32_t type)                  
{ 
    if (type >= rte_logs.dynamic_types_len)       
        return -1;                                
    return rte_logs.dynamic_types[type].loglevel; 
} 

/* Set the print level for the specified log type */                                               
int rte_log_set_level(uint32_t type, uint32_t level)  
{  
    if (type >= rte_logs.dynamic_types_len)       
        return -1;                                
    if (level > RTE_LOG_DEBUG)                    
        return -1;                                
    rte_logs.dynamic_types[type].loglevel = level;
    return 0; 
}

1. For example, take testpmd as an example. In the main function, a new log type is registered:

testpmd_logtype = rte_log_register("testpmd");

Return value testpmd_logtype also indicates that the type is in RTE_ logs.dynamic_ Index in types. Then set the printing level of this type to DEBUG, and print all logs of this type:

rte_log_set_level(testpmd_logtype, RTE_LOG_DEBUG);

At the same time, in the header file of testpmd example, the log function is encapsulated accordingly:

#define TESTPMD_LOG(level, fmt, args...) \
    rte_log(RTE_LOG_ ## level, testpmd_logtype, "testpmd: " fmt, ## args)

After that, you can use testpmd in the testpmd program_ The log macro prints the log.

Reuse existing log types

In addition to adding new log types, you can also reuse existing log types to exception_path is an example program. At IP_ In the fragmentation / main. C file, there are the following definitions:

#define RTE_LOGTYPE_IP_FRAG RTE_LOGTYPE_USER1

Among them, RTE_LOGTYPE_USER1 to RTE_ LOGTYPE_ The 8 types of user8 are prepared for user customization, so they can be used directly. When in use, call RTE_ Use IP directly when log macro_ Frag can:

RTE_LOG(INFO, IP_FRAG, "XXXXXX");

Reference documents

https://www.sunxidong.com/36.html