hcq/MaxScale
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

log manager now spreads log writings 'down' so that LOGFILE_ERROR logs are duplicated in LOGFILE_MESSAGE, and in LOGFILE_TRACE, and LOGFILE_MESSAGE logs are duplicated in LOGFILE_TRACE.

Browse Source
This commit is contained in:
vraatikka
2013-08-20 10:43:54 +03:00
parent 2ad0b12d79
commit 76de8f3758
3 changed files with 169 additions and 91 deletions
Download Patch File Download Diff File Expand all files Collapse all files

100
log_manager/log_manager.cc
View File

@ -194,7 +194,7 @@ static char* blockbuf_get_writepos(
static void blockbuf_register(blockbuf_t* bb); static void blockbuf_register(blockbuf_t* bb);
static void blockbuf_unregister(blockbuf_t* bb); static void blockbuf_unregister(blockbuf_t* bb);
static bool log_set_enabled(logfile_id_t id, bool val); static bool logfile_set_enabled(logfile_id_t id, bool val);
const char* get_suffix_default(void) const char* get_suffix_default(void)
@ -517,7 +517,9 @@ static int logmanager_write_log(
char* wp; char* wp;
int err = 0; int err = 0;
blockbuf_t* bb; blockbuf_t* bb;
blockbuf_t* bb_c;
int timestamp_len; int timestamp_len;
int i;
CHK_LOGMANAGER(lm); CHK_LOGMANAGER(lm);
@ -554,31 +556,13 @@ static int logmanager_write_log(
ss_dassert(flush); ss_dassert(flush);
logfile_flush(lf); /**< here we wake up file writer */ logfile_flush(lf); /**< here we wake up file writer */
} else { } else {
int i;
timestamp_len = get_timestamp_len(); timestamp_len = get_timestamp_len();
/**
* Write to target log. If spread_down == TRUE, then write also
* to all logs with greater logfile id.
* LOGFILE_ERROR = 1,
* LOGFILE_MESSAGE = 2,
* LOGFILE_TRACE = 4
*
* So everything written to error log will appear in message and
* trace log. Messages will be written in trace log.
*/
for (i=id; i<=LOGFILE_LAST; i<<=1) {
/**< Check if particular log is enabled */
if (!(lm->lm_enabled_logfiles & i)) {
continue;
}
/** /**
* Seek write position and register to block buffer. * Seek write position and register to block buffer.
* Then print formatted string to write position. * Then print formatted string to write position.
*/ */
wp = blockbuf_get_writepos(&bb, wp = blockbuf_get_writepos(&bb,
(logfile_id_t)i, id,
timestamp_len-1+str_len, timestamp_len-1+str_len,
flush); flush);
/** /**
@ -601,13 +585,52 @@ static int logmanager_write_log(
} }
wp[timestamp_len-1+str_len-1]='\n'; wp[timestamp_len-1+str_len-1]='\n';
/** lock-free unregistration, includes flush if bb_isfull */ if (spread_down) {
blockbuf_unregister(bb); /**
* Write to target log. If spread_down == TRUE, then write
* also to all logs with greater logfile id.
* LOGFILE_ERROR = 1,
* LOGFILE_MESSAGE = 2,
* LOGFILE_TRACE = 4
*
* So everything written to error log will appear in
* message and trace log. Messages will be written in
* trace log.
*/
for (i=(id<<1); i<=LOGFILE_LAST; i<<=1) {
/** pointer to write buffer of larger-id log */
char* wp_c;
if (!spread_down) { /**< Check if particular log is enabled */
break; if (!(lm->lm_enabled_logfiles & i)) {
continue;
} }
/**
* Seek write position and register to block buffer.
* Then print formatted string to write position.
*/
wp_c = blockbuf_get_writepos(&bb_c,
(logfile_id_t)i,
timestamp_len-1+str_len,
flush);
/**
* Copy original string from block buffer to other
* logs' block buffers.
*/
snprintf(wp_c, timestamp_len+str_len, wp);
/** remove double line feed */
if (wp_c[timestamp_len-1+str_len-2] == '\n') {
wp_c[timestamp_len-1+str_len-2]=' ';
} }
wp_c[timestamp_len-1+str_len-1]='\n';
/** lock-free unregistration, includes flush if
* bb_isfull */
blockbuf_unregister(bb_c);
}
} /* if (spread_down) */
blockbuf_unregister(bb);
} }
return_err: return_err:
@ -886,7 +909,7 @@ int skygw_log_enable(
} }
CHK_LOGMANAGER(lm); CHK_LOGMANAGER(lm);
if (log_set_enabled(id, TRUE)) { if (logfile_set_enabled(id, TRUE)) {
lm->lm_enabled_logfiles |= id; lm->lm_enabled_logfiles |= id;
} }
@ -908,7 +931,7 @@ int skygw_log_disable(
} }
CHK_LOGMANAGER(lm); CHK_LOGMANAGER(lm);
if (log_set_enabled(id, FALSE)) { if (logfile_set_enabled(id, FALSE)) {
lm->lm_enabled_logfiles &= ~id; lm->lm_enabled_logfiles &= ~id;
} }
@ -918,7 +941,7 @@ return_err:
} }
static bool log_set_enabled( static bool logfile_set_enabled(
logfile_id_t id, logfile_id_t id,
bool val) bool val)
{ {
@ -973,7 +996,7 @@ static bool log_set_enabled(
if (err != 0) { if (err != 0) {
lf->lf_enabled = oldval; lf->lf_enabled = oldval;
fprintf(stderr, fprintf(stderr,
"log_set_enabled failed. Writing notification to logfile %s " "logfile_set_enabled failed. Writing notification to logfile %s "
"failed.\n ", "failed.\n ",
STRLOGID(id)); STRLOGID(id));
goto return_succp; goto return_succp;
@ -1021,7 +1044,7 @@ int skygw_log_write_flush(
* Write log string to buffer and add to file write list. * Write log string to buffer and add to file write list.
*/ */
va_start(valist, str); va_start(valist, str);
err = logmanager_write_log(id, TRUE, TRUE, FALSE, len, str, valist); err = logmanager_write_log(id, TRUE, TRUE, TRUE, len, str, valist);
va_end(valist); va_end(valist);
if (err != 0) { if (err != 0) {
@ -1074,7 +1097,7 @@ int skygw_log_write(
* Write log string to buffer and add to file write list. * Write log string to buffer and add to file write list.
*/ */
va_start(valist, str); va_start(valist, str);
err = logmanager_write_log(id, FALSE, TRUE, FALSE, len, str, valist); err = logmanager_write_log(id, FALSE, TRUE, TRUE, len, str, valist);
va_end(valist); va_end(valist);
if (err != 0) { if (err != 0) {
@ -1107,11 +1130,7 @@ int skygw_log_flush(
fprintf(stderr, "skygw_log_flush failed.\n"); fprintf(stderr, "skygw_log_flush failed.\n");
goto return_unregister; goto return_unregister;
} }
#if 0
ss_dfprintf(stderr,
"skygw_log_flush : flushed %s successfully.\n",
STRLOGID(id));
#endif
return_unregister: return_unregister:
logmanager_unregister(); logmanager_unregister();
return_err: return_err:
@ -1691,6 +1710,7 @@ static void* thr_filewriter_fun(
/** Process all logfiles which have buffered writes. */ /** Process all logfiles which have buffered writes. */
for (i=LOGFILE_FIRST; i<=LOGFILE_LAST; i <<= 1) { for (i=LOGFILE_FIRST; i<=LOGFILE_LAST; i <<= 1) {
retry_flush_on_exit:
/** /**
* Get file pointer of current logfile. * Get file pointer of current logfile.
*/ */
@ -1760,6 +1780,16 @@ static void* thr_filewriter_fun(
} while (vn1 != vn2); } while (vn1 != vn2);
} /* while (node != NULL) */ } /* while (node != NULL) */
/**
* Writer's exit flag was set after checking it.
* Loop is restarted to ensure that all logfiles are flushed.
*/
if (!flushall_logfiles && skygw_thread_must_exit(thr)) {
flushall_logfiles = TRUE;
i = LOGFILE_FIRST;
goto retry_flush_on_exit;
}
} /* for */ } /* for */
} /* while (!skygw_thread_must_exit) */ } /* while (!skygw_thread_must_exit) */

2
log_manager/test/makefile
View File

@ -24,7 +24,7 @@ testcomp:
-L$(LOG_MANAGER_PATH) \ -L$(LOG_MANAGER_PATH) \
-Wl,-rpath,$(DEST)/lib \ -Wl,-rpath,$(DEST)/lib \
-Wl,-rpath,$(LOG_MANAGER_PATH)/ \ -Wl,-rpath,$(LOG_MANAGER_PATH)/ \
-o testlog -DSS_DEBUG \ -o testlog \
-I$(MARIADB_SRC_PATH)/include \ -I$(MARIADB_SRC_PATH)/include \
-I$(LOG_MANAGER_PATH) -I$(ROOT_PATH)/utils testlog.c \ -I$(LOG_MANAGER_PATH) -I$(ROOT_PATH)/utils testlog.c \
-llog_manager $(LDLIBS) \ -llog_manager $(LDLIBS) \

94
log_manager/test/testlog.c
View File

@ -98,22 +98,35 @@ int main(int argc, char* argv[])
err = skygw_log_flush(LOGFILE_ERROR); err = skygw_log_flush(LOGFILE_ERROR);
logstr = "My name is %s %d years and %d months."; logstr = "My name is %s %d years and %d months.";
#if !defined(SS_DEBUG)
skygw_log_enable(LOGFILE_TRACE);
#endif
err = skygw_log_write(LOGFILE_TRACE, logstr, "TraceyTracey", 3, 7); err = skygw_log_write(LOGFILE_TRACE, logstr, "TraceyTracey", 3, 7);
skygw_log_flush(LOGFILE_TRACE); skygw_log_flush(LOGFILE_TRACE);
#if !defined(SS_DEBUG)
skygw_log_enable(LOGFILE_TRACE);
#endif
logstr = "My name is Tracey Tracey 47 years and 7 months."; logstr = "My name is Tracey Tracey 47 years and 7 months.";
err = skygw_log_write(LOGFILE_TRACE, logstr); err = skygw_log_write(LOGFILE_TRACE, logstr);
#if !defined(SS_DEBUG)
skygw_log_enable(LOGFILE_TRACE);
#endif
logstr = "My name is Stacey %s"; logstr = "My name is Stacey %s";
err = skygw_log_write_flush(LOGFILE_TRACE, logstr, " "); err = skygw_log_write_flush(LOGFILE_TRACE, logstr, " ");
skygw_logmanager_done(); skygw_logmanager_done();
#if !defined(SS_DEBUG)
skygw_log_enable(LOGFILE_TRACE);
#endif
logstr = "My name is Philip"; logstr = "My name is Philip";
err = skygw_log_write(LOGFILE_TRACE, logstr); err = skygw_log_write(LOGFILE_TRACE, logstr);
#if !defined(SS_DEBUG)
skygw_log_enable(LOGFILE_TRACE);
#endif
logstr = "Philip."; logstr = "Philip.";
err = skygw_log_write(LOGFILE_TRACE, logstr); err = skygw_log_write(LOGFILE_TRACE, logstr);
#if !defined(SS_DEBUG)
skygw_log_enable(LOGFILE_TRACE);
#endif
logstr = "Ph%dlip."; logstr = "Ph%dlip.";
err = skygw_log_write(LOGFILE_TRACE, logstr, 1); err = skygw_log_write(LOGFILE_TRACE, logstr, 1);
@ -242,12 +255,19 @@ int main(int argc, char* argv[])
/** /**
* Test enable/disable log. * Test enable/disable log.
*/ */
#if !defined(SS_DEBUG)
skygw_log_enable(LOGFILE_TRACE);
#endif
logstr = ("\tTEST 3 - test enabling and disabling logs.");
err = skygw_log_write(LOGFILE_ERROR, logstr);
ss_dassert(err == 0);
r = skygw_logmanager_init(argc, argv); r = skygw_logmanager_init(argc, argv);
ss_dassert(r); ss_dassert(r);
skygw_log_disable(LOGFILE_TRACE); skygw_log_disable(LOGFILE_TRACE);
logstr = ("1.\tWrite to ERROR and MESSAGE logs."); logstr = ("1.\tWrite once to ERROR and twice to MESSAGE log.");
err = skygw_log_write(LOGFILE_MESSAGE, logstr); err = skygw_log_write(LOGFILE_MESSAGE, logstr);
ss_dassert(err == 0); ss_dassert(err == 0);
err = skygw_log_write(LOGFILE_TRACE, logstr); err = skygw_log_write(LOGFILE_TRACE, logstr);
@ -257,7 +277,8 @@ int main(int argc, char* argv[])
skygw_log_enable(LOGFILE_TRACE); skygw_log_enable(LOGFILE_TRACE);
logstr = ("2.\tWrite to ERROR and MESSAGE and TRACE logs."); logstr = ("2.\tWrite to once to ERROR, twice to MESSAGE and "
"three times to TRACE log.");
err = skygw_log_write(LOGFILE_MESSAGE, logstr); err = skygw_log_write(LOGFILE_MESSAGE, logstr);
ss_dassert(err == 0); ss_dassert(err == 0);
err = skygw_log_write(LOGFILE_TRACE, logstr); err = skygw_log_write(LOGFILE_TRACE, logstr);
@ -267,7 +288,7 @@ int main(int argc, char* argv[])
skygw_log_disable(LOGFILE_ERROR); skygw_log_disable(LOGFILE_ERROR);
logstr = ("3.\tWrite to MESSAGE and TRACE logs."); logstr = ("3.\tWrite to once to MESSAGE and twice to TRACE log.");
err = skygw_log_write(LOGFILE_MESSAGE, logstr); err = skygw_log_write(LOGFILE_MESSAGE, logstr);
ss_dassert(err == 0); ss_dassert(err == 0);
err = skygw_log_write(LOGFILE_TRACE, logstr); err = skygw_log_write(LOGFILE_TRACE, logstr);
@ -289,7 +310,7 @@ int main(int argc, char* argv[])
skygw_log_enable(LOGFILE_ERROR); skygw_log_enable(LOGFILE_ERROR);
skygw_log_enable(LOGFILE_MESSAGE); skygw_log_enable(LOGFILE_MESSAGE);
logstr = ("4.\tWrite to ERROR and MESSAGE logs."); logstr = ("4.\tWrite once to ERROR and twice to MESSAGE log.");
err = skygw_log_write(LOGFILE_MESSAGE, logstr); err = skygw_log_write(LOGFILE_MESSAGE, logstr);
ss_dassert(err == 0); ss_dassert(err == 0);
err = skygw_log_write(LOGFILE_TRACE, logstr); err = skygw_log_write(LOGFILE_TRACE, logstr);
@ -302,29 +323,36 @@ int main(int argc, char* argv[])
#endif /* TEST 3 */ #endif /* TEST 3 */
#if defined(TEST4) #if defined(TEST4)
r = skygw_logmanager_init(argc, argv); r = skygw_logmanager_init(argc, argv);
ss_dassert(r); ss_dassert(r);
#if !defined(SS_DEBUG)
skygw_log_enable(LOGFILE_TRACE);
#endif
logstr = ("\tTEST 4 - test spreading logs down to other logs.");
err = skygw_log_write(LOGFILE_ERROR, logstr);
ss_dassert(err == 0);
logstr = ("1.\tWrite to ERROR and thus also to MESSAGE and TRACE logs."); logstr = ("1.\tWrite to ERROR and thus also to MESSAGE and TRACE logs.");
err = skygw_log_write(LOGFILE_ERROR, logstr); err = skygw_log_write(LOGFILE_ERROR, logstr);
ss_dassert(err == 0); ss_dassert(err == 0);
logstr = ("1.\tWrite to MESSAGE and thus to TRACE logs."); logstr = ("2.\tWrite to MESSAGE and thus to TRACE logs.");
err = skygw_log_write(LOGFILE_MESSAGE, logstr); err = skygw_log_write(LOGFILE_MESSAGE, logstr);
ss_dassert(err == 0); ss_dassert(err == 0);
logstr = ("1.\tWrite to TRACE log only."); logstr = ("3.\tWrite to TRACE log only.");
err = skygw_log_write(LOGFILE_TRACE, logstr); err = skygw_log_write(LOGFILE_TRACE, logstr);
ss_dassert(err == 0); ss_dassert(err == 0);
skygw_log_disable(LOGFILE_MESSAGE); skygw_log_disable(LOGFILE_MESSAGE);
logstr = ("1.\tWrite to ERROR and thus also to TRACE log. MESSAGE is disabled"); logstr = ("4.\tWrite to ERROR and thus also to TRACE log. "
"MESSAGE is disabled.");
err = skygw_log_write(LOGFILE_ERROR, logstr); err = skygw_log_write(LOGFILE_ERROR, logstr);
ss_dassert(err == 0); ss_dassert(err == 0);
logstr = ("1.\tThis should not appear anywhere since MESSAGE is disabled."); logstr = ("5.\tThis should not appear anywhere since MESSAGE "
"is disabled.");
err = skygw_log_write(LOGFILE_MESSAGE, logstr); err = skygw_log_write(LOGFILE_MESSAGE, logstr);
ss_dassert(err != 0); ss_dassert(err != 0);
@ -332,42 +360,51 @@ int main(int argc, char* argv[])
r = skygw_logmanager_init(argc, argv); r = skygw_logmanager_init(argc, argv);
ss_dassert(r); ss_dassert(r);
#if !defined(SS_DEBUG)
logstr = ("1.\tWrite to ERROR and thus also to MESSAGE and TRACE logs."); skygw_log_enable(LOGFILE_TRACE);
#endif
logstr = ("6.\tWrite to ERROR and thus also to MESSAGE and TRACE logs.");
err = skygw_log_write_flush(LOGFILE_ERROR, logstr); err = skygw_log_write_flush(LOGFILE_ERROR, logstr);
ss_dassert(err == 0); ss_dassert(err == 0);
logstr = ("1.\tWrite to MESSAGE and thus to TRACE logs."); logstr = ("7.\tWrite to MESSAGE and thus to TRACE logs.");
err = skygw_log_write_flush(LOGFILE_MESSAGE, logstr); err = skygw_log_write_flush(LOGFILE_MESSAGE, logstr);
ss_dassert(err == 0); ss_dassert(err == 0);
logstr = ("1.\tWrite to TRACE log only."); logstr = ("8.\tWrite to TRACE log only.");
skygw_log_enable(LOGFILE_TRACE);
err = skygw_log_write_flush(LOGFILE_TRACE, logstr); err = skygw_log_write_flush(LOGFILE_TRACE, logstr);
ss_dassert(err == 0); ss_dassert(err == 0);
skygw_log_disable(LOGFILE_MESSAGE); skygw_log_disable(LOGFILE_MESSAGE);
logstr = ("1.\tWrite to ERROR and thus also to TRACE log. MESSAGE is disabled"); logstr = ("9.\tWrite to ERROR and thus also to TRACE log. "
"MESSAGE is disabled");
err = skygw_log_write_flush(LOGFILE_ERROR, logstr); err = skygw_log_write_flush(LOGFILE_ERROR, logstr);
ss_dassert(err == 0); ss_dassert(err == 0);
logstr = ("1.\tThis should not appear anywhere since MESSAGE is disabled."); logstr = ("10.\tThis should not appear anywhere since MESSAGE is "
"disabled.");
err = skygw_log_write_flush(LOGFILE_MESSAGE, logstr); err = skygw_log_write_flush(LOGFILE_MESSAGE, logstr);
ss_dassert(err != 0); ss_dassert(err != 0);
skygw_log_enable(LOGFILE_MESSAGE);
err = skygw_log_write(LOGFILE_ERROR, err = skygw_log_write(LOGFILE_ERROR,
"Write to all logs some formattings : %d %s %d", "11.\tWrite to all logs some formattings : "
"%d %s %d",
(int)3, (int)3,
"foo", "foo",
(int)3); (int)3);
err = skygw_log_write(LOGFILE_MESSAGE, err = skygw_log_write(LOGFILE_MESSAGE,
"Write to MESSAGE and TRACE log some formattings " "12.\tWrite to MESSAGE and TRACE log some "
"formattings "
": %d %s %d", ": %d %s %d",
(int)3, (int)3,
"foo", "foo",
(int)3); (int)3);
err = skygw_log_write(LOGFILE_TRACE, err = skygw_log_write(LOGFILE_TRACE,
"Write to TRACE log some formattings " "13.\tWrite to TRACE log some formattings "
": %d %s %d", ": %d %s %d",
(int)3, (int)3,
"foo", "foo",
@ -412,6 +449,8 @@ static void* thr_run(
skygw_logmanager_init( 0, NULL); skygw_logmanager_init( 0, NULL);
skygw_log_flush(LOGFILE_ERROR); skygw_log_flush(LOGFILE_ERROR);
logstr = ("For automatic and register variables, it is done each time the function or block is entered."); logstr = ("For automatic and register variables, it is done each time the function or block is entered.");
skygw_log_enable(LOGFILE_TRACE);
err = skygw_log_write(LOGFILE_TRACE, logstr); err = skygw_log_write(LOGFILE_TRACE, logstr);
ss_dassert(err == 0); ss_dassert(err == 0);
skygw_logmanager_done(); skygw_logmanager_done();
@ -430,6 +469,9 @@ static void* thr_run(
skygw_logmanager_init( 0, NULL); skygw_logmanager_init( 0, NULL);
skygw_logmanager_init( 0, NULL); skygw_logmanager_init( 0, NULL);
logstr = ("For automatic and register variables, it is done each time the function or block is entered."); logstr = ("For automatic and register variables, it is done each time the function or block is entered.");
#if !defined(SS_DEBUG)
skygw_log_enable(LOGFILE_TRACE);
#endif
err = skygw_log_write(LOGFILE_TRACE, logstr); err = skygw_log_write(LOGFILE_TRACE, logstr);
ss_dassert(err == 0); ss_dassert(err == 0);
skygw_logmanager_init( 0, NULL); skygw_logmanager_init( 0, NULL);
@ -441,8 +483,14 @@ static void* thr_run(
err = skygw_log_write(LOGFILE_MESSAGE, logstr); err = skygw_log_write(LOGFILE_MESSAGE, logstr);
ss_dassert(err == 0); ss_dassert(err == 0);
skygw_logmanager_done(); skygw_logmanager_done();
#if !defined(SS_DEBUG)
skygw_log_enable(LOGFILE_TRACE);
#endif
skygw_log_flush(LOGFILE_TRACE); skygw_log_flush(LOGFILE_TRACE);
logstr = ("For automatic and register variables, it is done each time the function or block is entered."); logstr = ("For automatic and register variables, it is done each time the function or block is entered.");
#if !defined(SS_DEBUG)
skygw_log_enable(LOGFILE_TRACE);
#endif
err = skygw_log_write(LOGFILE_TRACE, logstr); err = skygw_log_write(LOGFILE_TRACE, logstr);
ss_dassert(err == 0); ss_dassert(err == 0);
skygw_logmanager_done(); skygw_logmanager_done();