log: print trace flag names in SPDK_TRACELOG()

Change-Id: I962ee098818f48563e67f9b4214bc3519eee48b4
Signed-off-by: Daniel Verkamp <daniel.verkamp@intel.com>
This commit is contained in:
Daniel Verkamp 2016-11-23 11:48:14 -07:00
parent 5f3761cf7e
commit c454900960
6 changed files with 74 additions and 87 deletions

View File

@ -63,20 +63,16 @@ void spdk_noticelog(const char *file, const int line, const char *func,
const char *format, ...) __attribute__((__format__(__printf__, 4, 5))); const char *format, ...) __attribute__((__format__(__printf__, 4, 5)));
void spdk_warnlog(const char *file, const int line, const char *func, void spdk_warnlog(const char *file, const int line, const char *func,
const char *format, ...) __attribute__((__format__(__printf__, 4, 5))); const char *format, ...) __attribute__((__format__(__printf__, 4, 5)));
void spdk_tracelog(const char *file, const int line, void spdk_tracelog(const char *flag, const char *file, const int line,
const char *func, const char *format, ...) __attribute__((__format__(__printf__, 4, 5))); const char *func, const char *format, ...) __attribute__((__format__(__printf__, 5, 6)));
void spdk_errlog(const char *file, const int line, const char *func, void spdk_errlog(const char *file, const int line, const char *func,
const char *format, ...) __attribute__((__format__(__printf__, 4, 5))); const char *format, ...) __attribute__((__format__(__printf__, 4, 5)));
void spdk_trace_dump(const char *label, const uint8_t *buf, size_t len); void spdk_trace_dump(const char *label, const uint8_t *buf, size_t len);
void spdk_log_register_trace_flag(const char *name, bool *enabled);
bool spdk_log_get_trace_flag(const char *flag); bool spdk_log_get_trace_flag(const char *flag);
int spdk_log_set_trace_flag(const char *flag); int spdk_log_set_trace_flag(const char *flag);
int spdk_log_clear_trace_flag(const char *flag); int spdk_log_clear_trace_flag(const char *flag);
size_t spdk_log_get_num_trace_flags(void);
const char *spdk_log_get_trace_flag_name(size_t idx);
void spdk_open_log(void); void spdk_open_log(void);
void spdk_close_log(void); void spdk_close_log(void);

View File

@ -40,10 +40,25 @@
#define SPDK_INTERNAL_LOG_H #define SPDK_INTERNAL_LOG_H
#include "spdk/log.h" #include "spdk/log.h"
#include "spdk/queue.h"
struct spdk_trace_flag {
TAILQ_ENTRY(spdk_trace_flag) tailq;
const char *name;
bool enabled;
};
void spdk_log_register_trace_flag(const char *name, struct spdk_trace_flag *flag);
struct spdk_trace_flag *spdk_log_get_first_trace_flag(void);
struct spdk_trace_flag *spdk_log_get_next_trace_flag(struct spdk_trace_flag *flag);
#ifdef DEBUG #ifdef DEBUG
#define SPDK_LOG_REGISTER_TRACE_FLAG(str, flag) \ #define SPDK_LOG_REGISTER_TRACE_FLAG(str, flag) \
bool flag = false; \ struct spdk_trace_flag flag = { \
.enabled = false, \
.name = str, \
}; \
__attribute__((constructor)) static void register_trace_flag_##flag(void) \ __attribute__((constructor)) static void register_trace_flag_##flag(void) \
{ \ { \
spdk_log_register_trace_flag(str, &flag); \ spdk_log_register_trace_flag(str, &flag); \
@ -51,16 +66,16 @@ __attribute__((constructor)) static void register_trace_flag_##flag(void) \
#define SPDK_TRACELOG(FLAG, ...) \ #define SPDK_TRACELOG(FLAG, ...) \
do { \ do { \
extern bool FLAG; \ extern struct spdk_trace_flag FLAG; \
if (FLAG) { \ if (FLAG.enabled) { \
spdk_tracelog(__FILE__, __LINE__, __func__, __VA_ARGS__); \ spdk_tracelog(FLAG.name, __FILE__, __LINE__, __func__, __VA_ARGS__); \
} \ } \
} while (0) } while (0)
#define SPDK_TRACEDUMP(FLAG, LABEL, BUF, LEN) \ #define SPDK_TRACEDUMP(FLAG, LABEL, BUF, LEN) \
do { \ do { \
extern bool FLAG; \ extern struct spdk_trace_flag FLAG; \
if ((FLAG) && (LEN)) { \ if ((FLAG.enabled) && (LEN)) { \
spdk_trace_dump((LABEL), (BUF), (LEN)); \ spdk_trace_dump((LABEL), (BUF), (LEN)); \
} \ } \
} while (0) } while (0)

View File

@ -42,13 +42,7 @@
#include <ctype.h> #include <ctype.h>
#include <errno.h> #include <errno.h>
struct spdk_trace_flag { static TAILQ_HEAD(, spdk_trace_flag) g_trace_flags = TAILQ_HEAD_INITIALIZER(g_trace_flags);
const char *name;
bool *enabled;
};
static size_t g_num_trace_flags = 0;
static struct spdk_trace_flag *g_trace_flags = NULL;
unsigned int spdk_g_notice_stderr_flag = 1; unsigned int spdk_g_notice_stderr_flag = 1;
unsigned int spdk_g_log_facility = LOG_DAEMON; unsigned int spdk_g_log_facility = LOG_DAEMON;
@ -171,7 +165,7 @@ spdk_warnlog(const char *file, const int line, const char *func,
} }
void void
spdk_tracelog(const char *file, const int line, const char *func, spdk_tracelog(const char *flag, const char *file, const int line, const char *func,
const char *format, ...) const char *format, ...)
{ {
char buf[MAX_TMPBUF]; char buf[MAX_TMPBUF];
@ -180,11 +174,11 @@ spdk_tracelog(const char *file, const int line, const char *func,
va_start(ap, format); va_start(ap, format);
vsnprintf(buf, sizeof buf, format, ap); vsnprintf(buf, sizeof buf, format, ap);
if (func != NULL) { if (func != NULL) {
fprintf(stderr, "%s:%4d:%s: %s", file, line, func, buf); fprintf(stderr, "[%s] %s:%4d:%s: %s", flag, file, line, func, buf);
//syslog(LOG_INFO, "%s:%4d:%s: %s", file, line, func, buf); //syslog(LOG_INFO, "[%s] %s:%4d:%s: %s", flag, file, line, func, buf);
} else { } else {
fprintf(stderr, "%s:%4d: %s", file, line, buf); fprintf(stderr, "[%s] %s:%4d: %s", flag, file, line, buf);
//syslog(LOG_INFO, "%s:%4d: %s", file, line, buf); //syslog(LOG_INFO, "[%s] %s:%4d: %s", flag, file, line, buf);
} }
va_end(ap); va_end(ap);
} }
@ -254,26 +248,26 @@ spdk_trace_dump(const char *label, const uint8_t *buf, size_t len)
fdump(stderr, label, buf, len); fdump(stderr, label, buf, len);
} }
static int compare_trace_flags(const void *key, const void *p)
{
const struct spdk_trace_flag *flag = p;
return strcasecmp(key, flag->name);
}
static struct spdk_trace_flag * static struct spdk_trace_flag *
get_trace_flag(const char *name) get_trace_flag(const char *name)
{ {
return bsearch(name, g_trace_flags, g_num_trace_flags, sizeof(struct spdk_trace_flag), struct spdk_trace_flag *flag;
compare_trace_flags);
TAILQ_FOREACH(flag, &g_trace_flags, tailq) {
if (strcasecmp(name, flag->name) == 0) {
return flag;
}
}
return NULL;
} }
void void
spdk_log_register_trace_flag(const char *name, bool *enabled) spdk_log_register_trace_flag(const char *name, struct spdk_trace_flag *flag)
{ {
struct spdk_trace_flag *flag, *new_flags; struct spdk_trace_flag *iter;
if (name == NULL || enabled == NULL) { if (name == NULL || flag == NULL) {
fprintf(stderr, "missing spdk_trace_flag parameters\n"); fprintf(stderr, "missing spdk_trace_flag parameters\n");
abort(); abort();
} }
@ -283,27 +277,14 @@ spdk_log_register_trace_flag(const char *name, bool *enabled)
abort(); abort();
} }
new_flags = realloc(g_trace_flags, (g_num_trace_flags + 1) * sizeof(struct spdk_trace_flag)); TAILQ_FOREACH(iter, &g_trace_flags, tailq) {
if (new_flags == NULL) { if (strcasecmp(iter->name, flag->name) > 0) {
fprintf(stderr, "spdk_trace_flag allocation error\n"); TAILQ_INSERT_BEFORE(iter, flag, tailq);
abort(); return;
}
g_trace_flags = new_flags;
/* Find slot so that new flag is inserted in sorted order */
for (flag = g_trace_flags; flag != g_trace_flags + g_num_trace_flags; flag++) {
if (strcasecmp(name, flag->name) < 0) {
size_t to_move = g_num_trace_flags - (flag - g_trace_flags);
memmove(flag + 1, flag, to_move * sizeof(struct spdk_trace_flag));
break;
} }
} }
flag->name = name; TAILQ_INSERT_TAIL(&g_trace_flags, flag, tailq);
flag->enabled = enabled;
g_num_trace_flags++;
} }
bool bool
@ -311,7 +292,7 @@ spdk_log_get_trace_flag(const char *name)
{ {
struct spdk_trace_flag *flag = get_trace_flag(name); struct spdk_trace_flag *flag = get_trace_flag(name);
if (flag && *flag->enabled) { if (flag && flag->enabled) {
return true; return true;
} }
@ -322,11 +303,10 @@ static int
set_trace_flag(const char *name, bool value) set_trace_flag(const char *name, bool value)
{ {
struct spdk_trace_flag *flag; struct spdk_trace_flag *flag;
size_t i;
if (strcasecmp(name, "all") == 0) { if (strcasecmp(name, "all") == 0) {
for (i = 0; i < g_num_trace_flags; i++) { TAILQ_FOREACH(flag, &g_trace_flags, tailq) {
*g_trace_flags[i].enabled = value; flag->enabled = value;
} }
return 0; return 0;
} }
@ -336,7 +316,7 @@ set_trace_flag(const char *name, bool value)
return -1; return -1;
} }
*flag->enabled = value; flag->enabled = value;
return 0; return 0;
} }
@ -353,19 +333,16 @@ spdk_log_clear_trace_flag(const char *name)
return set_trace_flag(name, false); return set_trace_flag(name, false);
} }
struct spdk_trace_flag *
size_t spdk_log_get_num_trace_flags(void) spdk_log_get_first_trace_flag(void)
{ {
return g_num_trace_flags; return TAILQ_FIRST(&g_trace_flags);
} }
const char *spdk_log_get_trace_flag_name(size_t idx) struct spdk_trace_flag *
spdk_log_get_next_trace_flag(struct spdk_trace_flag *flag)
{ {
if (idx >= g_num_trace_flags) { return TAILQ_NEXT(flag, tailq);
return NULL;
}
return g_trace_flags[idx].name;
} }
void void
@ -388,12 +365,12 @@ void
spdk_tracelog_usage(FILE *f, const char *trace_arg) spdk_tracelog_usage(FILE *f, const char *trace_arg)
{ {
#ifdef DEBUG #ifdef DEBUG
size_t i; struct spdk_trace_flag *flag;
fprintf(f, " %s flag enable trace flag (all", trace_arg); fprintf(f, " %s flag enable trace flag (all", trace_arg);
for (i = 0; i < g_num_trace_flags; i++) { TAILQ_FOREACH(flag, &g_trace_flags, tailq) {
fprintf(f, ", %s", g_trace_flags[i].name); fprintf(f, ", %s", flag->name);
} }
fprintf(f, ")\n"); fprintf(f, ")\n");

View File

@ -129,7 +129,7 @@ spdk_rpc_get_trace_flags(struct spdk_jsonrpc_server_conn *conn,
const struct spdk_json_val *id) const struct spdk_json_val *id)
{ {
struct spdk_json_write_ctx *w; struct spdk_json_write_ctx *w;
size_t i, count; struct spdk_trace_flag *flag;
if (params != NULL) { if (params != NULL) {
spdk_jsonrpc_send_error_response(conn, id, SPDK_JSONRPC_ERROR_INVALID_PARAMS, spdk_jsonrpc_send_error_response(conn, id, SPDK_JSONRPC_ERROR_INVALID_PARAMS,
@ -141,14 +141,13 @@ spdk_rpc_get_trace_flags(struct spdk_jsonrpc_server_conn *conn,
return; return;
} }
count = spdk_log_get_num_trace_flags(); flag = spdk_log_get_first_trace_flag();
w = spdk_jsonrpc_begin_result(conn, id); w = spdk_jsonrpc_begin_result(conn, id);
spdk_json_write_object_begin(w); spdk_json_write_object_begin(w);
for (i = 0; i < count; i++) { while (flag) {
const char *name = spdk_log_get_trace_flag_name(i); spdk_json_write_name(w, flag->name);
spdk_json_write_bool(w, flag->enabled);
spdk_json_write_name(w, name); flag = spdk_log_get_next_trace_flag(flag);
spdk_json_write_bool(w, spdk_log_get_trace_flag(name));
} }
spdk_json_write_object_end(w); spdk_json_write_object_end(w);
spdk_jsonrpc_end_result(conn, w); spdk_jsonrpc_end_result(conn, w);

View File

@ -56,10 +56,6 @@ log_test(void)
CU_ASSERT(rc == 0); CU_ASSERT(rc == 0);
#ifdef DEBUG #ifdef DEBUG
rc = spdk_log_get_num_trace_flags();
CU_ASSERT(rc == 1);
CU_ASSERT(strcasecmp(spdk_log_get_trace_flag_name(0), "debug") == 0);
CU_ASSERT(spdk_log_get_trace_flag("debug") == false); CU_ASSERT(spdk_log_get_trace_flag("debug") == false);
spdk_log_set_trace_flag("debug"); spdk_log_set_trace_flag("debug");

View File

@ -33,12 +33,16 @@
#include "spdk_cunit.h" #include "spdk_cunit.h"
#include "spdk_internal/log.h"
#include <stdbool.h> #include <stdbool.h>
#include "lib/nvme/unit/test_env.c" #include "lib/nvme/unit/test_env.c"
bool trace_flag = false; struct spdk_trace_flag SPDK_TRACE_NVME = {
#define SPDK_TRACE_NVME trace_flag .name = "nvme",
.enabled = false,
};
#include "nvme/nvme_ctrlr.c" #include "nvme/nvme_ctrlr.c"