MEDIUM: logs: add a new RFC5424 log-format for the structured-data
This patch adds a new RFC5424-specific log-format for the structured-data
that is automatically send by __send_log() when the sender is in RFC5424
mode.
A new statement "log-format-sd" should be used in order to set log-format
for the structured-data part in RFC5424 formatted syslog messages.
Example:
log-format-sd [exampleSDID@1234\ bytes=\"%B\"\ status=\"%ST\"]
diff --git a/src/cfgparse.c b/src/cfgparse.c
index af2d777..f3a7aee 100644
--- a/src/cfgparse.c
+++ b/src/cfgparse.c
@@ -1574,6 +1574,7 @@
logheader = realloc(logheader, global.max_syslog_len + 1);
logheader_rfc5424 = realloc(logheader_rfc5424, global.max_syslog_len + 1);
logline = realloc(logline, global.max_syslog_len + 1);
+ logline_rfc5424 = realloc(logline_rfc5424, global.max_syslog_len + 1);
}
/* after the length, a format may be specified */
@@ -2722,6 +2723,17 @@
curproxy->conf.lfs_file = strdup(defproxy.conf.lfs_file);
curproxy->conf.lfs_line = defproxy.conf.lfs_line;
}
+
+ /* get either a pointer to the logformat string for RFC5424 structured-data or a copy of it */
+ curproxy->conf.logformat_sd_string = defproxy.conf.logformat_sd_string;
+ if (curproxy->conf.logformat_sd_string &&
+ curproxy->conf.logformat_sd_string != default_rfc5424_sd_log_format)
+ curproxy->conf.logformat_sd_string = strdup(curproxy->conf.logformat_sd_string);
+
+ if (defproxy.conf.lfsd_file) {
+ curproxy->conf.lfsd_file = strdup(defproxy.conf.lfsd_file);
+ curproxy->conf.lfsd_line = defproxy.conf.lfsd_line;
+ }
}
if (curproxy->cap & PR_CAP_BE) {
@@ -2838,6 +2850,10 @@
free(defproxy.log_tag);
free_email_alert(&defproxy);
+ if (defproxy.conf.logformat_sd_string != default_rfc5424_sd_log_format)
+ free(defproxy.conf.logformat_sd_string);
+ free(defproxy.conf.lfsd_file);
+
for (rc = 0; rc < HTTP_ERR_SIZE; rc++)
chunk_destroy(&defproxy.errmsg[rc]);
@@ -5805,6 +5821,35 @@
err_code |= ERR_WARN;
}
}
+ else if (!strcmp(args[0], "log-format-sd")) {
+ if (!*(args[1])) {
+ Alert("parsing [%s:%d] : %s expects an argument.\n", file, linenum, args[0]);
+ err_code |= ERR_ALERT | ERR_FATAL;
+ goto out;
+ }
+ if (*(args[2])) {
+ Alert("parsing [%s:%d] : %s expects only one argument, don't forget to escape spaces!\n", file, linenum, args[0]);
+ err_code |= ERR_ALERT | ERR_FATAL;
+ goto out;
+ }
+
+ if (curproxy->conf.logformat_sd_string != default_rfc5424_sd_log_format)
+ free(curproxy->conf.logformat_sd_string);
+ curproxy->conf.logformat_sd_string = strdup(args[1]);
+
+ free(curproxy->conf.lfsd_file);
+ curproxy->conf.lfsd_file = strdup(curproxy->conf.args.file);
+ curproxy->conf.lfsd_line = curproxy->conf.args.line;
+
+ /* get a chance to improve log-format-sd error reporting by
+ * reporting the correct line-number when possible.
+ */
+ if (curproxy != &defproxy && !(curproxy->cap & PR_CAP_FE)) {
+ Warning("parsing [%s:%d] : backend '%s' : 'log-format-sd' directive is ignored in backends.\n",
+ file, linenum, curproxy->id);
+ err_code |= ERR_WARN;
+ }
+ }
else if (!strcmp(args[0], "log-tag")) { /* tag to report to syslog */
if (*(args[1]) == 0) {
Alert("parsing [%s:%d] : '%s' expects a tag for use in syslog.\n", file, linenum, args[0]);
@@ -5871,6 +5916,7 @@
logheader = realloc(logheader, global.max_syslog_len + 1);
logheader_rfc5424 = realloc(logheader_rfc5424, global.max_syslog_len + 1);
logline = realloc(logline, global.max_syslog_len + 1);
+ logline_rfc5424 = realloc(logline_rfc5424, global.max_syslog_len + 1);
}
/* after the length, a format may be specified */
@@ -7866,6 +7912,8 @@
hdr = logheader_rfc5424;
htp = &curproxy->log_htp_rfc5424;
htp_fmt = rfc5424_host_tag_pid_log_format;
+ if (!curproxy->conf.logformat_sd_string)
+ curproxy->conf.logformat_sd_string = default_rfc5424_sd_log_format;
break;
default:
@@ -7915,6 +7963,13 @@
free(curproxy->conf.lfs_file);
curproxy->conf.lfs_file = NULL;
curproxy->conf.lfs_line = 0;
+
+ if (curproxy->conf.logformat_sd_string != default_rfc5424_sd_log_format)
+ free(curproxy->conf.logformat_sd_string);
+ curproxy->conf.logformat_sd_string = NULL;
+ free(curproxy->conf.lfsd_file);
+ curproxy->conf.lfsd_file = NULL;
+ curproxy->conf.lfsd_line = 0;
}
if (curproxy->conf.logformat_string) {
@@ -7927,6 +7982,17 @@
curproxy->conf.args.line = 0;
}
+ if (curproxy->conf.logformat_sd_string) {
+ curproxy->conf.args.ctx = ARGC_LOGSD;
+ curproxy->conf.args.file = curproxy->conf.lfsd_file;
+ curproxy->conf.args.line = curproxy->conf.lfsd_line;
+ parse_logformat_string(curproxy->conf.logformat_sd_string, curproxy, &curproxy->logformat_sd, LOG_OPT_MANDATORY,
+ SMP_VAL_FE_LOG_END, curproxy->conf.lfsd_file, curproxy->conf.lfsd_line);
+ add_to_logformat_list(NULL, NULL, LF_SEPARATOR, &curproxy->logformat_sd);
+ curproxy->conf.args.file = NULL;
+ curproxy->conf.args.line = 0;
+ }
+
if (curproxy->conf.uniqueid_format_string) {
curproxy->conf.args.ctx = ARGC_UIF;
curproxy->conf.args.file = curproxy->conf.uif_file;
@@ -8287,7 +8353,8 @@
curproxy->to_log &= ~LW_BYTES;
if ((curproxy->mode == PR_MODE_TCP || curproxy->mode == PR_MODE_HTTP) &&
- (curproxy->cap & PR_CAP_FE) && !LIST_ISEMPTY(&curproxy->logformat) && LIST_ISEMPTY(&curproxy->logsrvs)) {
+ (curproxy->cap & PR_CAP_FE) && LIST_ISEMPTY(&curproxy->logsrvs) &&
+ (!LIST_ISEMPTY(&curproxy->logformat) || !LIST_ISEMPTY(&curproxy->logformat_sd))) {
Warning("config : log format ignored for %s '%s' since it has no log address.\n",
proxy_type_str(curproxy), curproxy->id);
err_code |= ERR_WARN;
diff --git a/src/haproxy.c b/src/haproxy.c
index 9539dfa..57db1db 100644
--- a/src/haproxy.c
+++ b/src/haproxy.c
@@ -1227,6 +1227,10 @@
free(p->conf.uif_file);
free(p->lbprm.map.srv);
+ if (p->conf.logformat_sd_string != default_rfc5424_sd_log_format)
+ free(p->conf.logformat_sd_string);
+ free(p->conf.lfsd_file);
+
for (i = 0; i < HTTP_ERR_SIZE; i++)
chunk_destroy(&p->errmsg[i]);
@@ -1336,6 +1340,11 @@
free(lf);
}
+ list_for_each_entry_safe(lf, lfb, &p->logformat_sd, list) {
+ LIST_DEL(&lf->list);
+ free(lf);
+ }
+
deinit_tcp_rules(&p->tcp_req.inspect_rules);
deinit_tcp_rules(&p->tcp_req.l4_rules);
diff --git a/src/log.c b/src/log.c
index 8fe2348..1829696 100644
--- a/src/log.c
+++ b/src/log.c
@@ -155,8 +155,16 @@
char default_tcp_log_format[] = "%ci:%cp [%t] %ft %b/%s %Tw/%Tc/%Tt %B %ts %ac/%fc/%bc/%sc/%rc %sq/%bq";
char *log_format = NULL;
+/* Common printf format strings for hostname, log_tag and pid used in all
+ * outgoing syslog messages.
+ */
char default_host_tag_pid_log_format[] = "%s%s[%d]: ";
-char rfc5424_host_tag_pid_log_format[] = "%s%s %d - - ";
+char rfc5424_host_tag_pid_log_format[] = "%s%s %d - ";
+
+/* Default string used for structured-data part in RFC5424 formatted
+ * syslog messages.
+ */
+char default_rfc5424_sd_log_format[] = "- ";
/* This is a global syslog header, common to all outgoing messages in
* RFC3164 format. It begins with time-based part and is updated by
@@ -174,6 +182,11 @@
*/
char *logline = NULL;
+/* A global syslog message buffer, common to all RFC5424 syslog messages.
+ * Currently, it is used for generating the structured-data part.
+ */
+char *logline_rfc5424 = NULL;
+
struct logformat_var_args {
char *name;
int mask;
@@ -201,6 +214,8 @@
return "track-sc";
case ARGC_LOG:
return "log-format";
+ case ARGC_LOGSD:
+ return "log-format-sd";
case ARGC_HRQ:
return "http-request";
case ARGC_HRS:
@@ -782,17 +797,17 @@
* the beginning of logheader once a second and return the pointer to the
* first character after it.
*/
-static char *update_log_hdr()
+static char *update_log_hdr(const time_t time)
{
static long tvsec;
static char *dataptr = NULL; /* backup of last end of header, NULL first time */
- if (unlikely(date.tv_sec != tvsec || dataptr == NULL)) {
+ if (unlikely(time != tvsec || dataptr == NULL)) {
/* this string is rebuild only once a second */
struct tm tm;
int hdr_len;
- tvsec = date.tv_sec;
+ tvsec = time;
get_localtime(tvsec, &tm);
hdr_len = snprintf(logheader, global.max_syslog_len,
@@ -818,17 +833,17 @@
* the beginning of logheader_rfc5424 once a second and return the pointer
* to the first character after it.
*/
-static char *update_log_hdr_rfc5424()
+static char *update_log_hdr_rfc5424(const time_t time)
{
static long tvsec;
static char *dataptr = NULL; /* backup of last end of header, NULL first time */
- if (unlikely(date.tv_sec != tvsec || dataptr == NULL)) {
+ if (unlikely(time != tvsec || dataptr == NULL)) {
/* this string is rebuild only once a second */
struct tm tm;
int hdr_len;
- tvsec = date.tv_sec;
+ tvsec = time;
get_localtime(tvsec, &tm);
hdr_len = snprintf(logheader_rfc5424, global.max_syslog_len,
@@ -869,15 +884,17 @@
data_len = global.max_syslog_len;
va_end(argp);
- __send_log(p, level, logline, data_len);
+ __send_log(p, level, logline, data_len, default_rfc5424_sd_log_format, 2);
}
/*
* This function sends a syslog message.
* It doesn't care about errors nor does it report them.
- * It overrides the last byte of the vector with an LF character.
+ * It overrides the last byte of the message vector with an LF character.
+ * The arguments <sd> and <sd_size> are used for the structured-data part
+ * in RFC5424 formatted syslog messages.
*/
-void __send_log(struct proxy *p, int level, char *message, size_t size)
+void __send_log(struct proxy *p, int level, char *message, size_t size, char *sd, size_t sd_size)
{
static struct iovec iovec[NB_MSG_IOVEC_ELEMENTS] = { };
static struct msghdr msghdr = {
@@ -895,6 +912,7 @@
char *hdr, *hdr_ptr;
size_t hdr_size;
struct chunk *htp;
+ time_t time = date.tv_sec;
dataptr = message;
@@ -921,6 +939,7 @@
int maxlen;
int hdr_max = 0;
int htp_max = 0;
+ int sd_max = 0;
int max = 1;
char backup;
@@ -948,14 +967,15 @@
switch (logsrv->format) {
case LOG_FORMAT_RFC3164:
hdr = logheader;
- hdr_ptr = update_log_hdr();
+ hdr_ptr = update_log_hdr(time);
htp = &p->log_htp;
break;
case LOG_FORMAT_RFC5424:
hdr = logheader_rfc5424;
- hdr_ptr = update_log_hdr_rfc5424();
+ hdr_ptr = update_log_hdr_rfc5424(time);
htp = &p->log_htp_rfc5424;
+ sd_max = sd_size; /* the SD part allowed only in RFC5424 */
break;
default:
@@ -986,21 +1006,28 @@
if (unlikely(hdr_size >= logsrv->maxlen)) {
hdr_max = MIN(hdr_max, logsrv->maxlen) - 1;
+ sd_max = 0;
goto send;
}
maxlen = logsrv->maxlen - hdr_max;
- htp_max = htp->len;
- if (unlikely(htp_max >= maxlen)) {
+ if (unlikely(htp->len >= maxlen)) {
htp_max = maxlen - 1;
+ sd_max = 0;
goto send;
}
- max = MIN(size, maxlen - htp_max);
+ htp_max = htp->len;
+ maxlen -= htp_max;
- log_ptr += max - 1;
+ if (sd_max >= maxlen) {
+ sd_max = maxlen - 1;
+ goto send;
+ }
+ max = MIN(size, maxlen - sd_max);
+ log_ptr += max - 1;
send:
/* insert a \n at the end of the message, but save what was
* there first because we could have different max lengths
@@ -1013,8 +1040,10 @@
iovec[0].iov_len = hdr_max;
iovec[1].iov_base = htp->str;
iovec[1].iov_len = htp_max;
- iovec[2].iov_base = dataptr;
- iovec[2].iov_len = max;
+ iovec[2].iov_base = sd;
+ iovec[2].iov_len = sd_max;
+ iovec[3].iov_base = dataptr;
+ iovec[3].iov_len = max;
msghdr.msg_name = (struct sockaddr *)&logsrv->addr;
msghdr.msg_namelen = get_addr_len(&logsrv->addr);
@@ -1942,6 +1971,7 @@
{
struct session *sess = s->sess;
int size, err, level;
+ int sd_size = 0;
/* if we don't want to log normal traffic, return now */
err = (s->flags & SF_REDISP) ||
@@ -1975,10 +2005,15 @@
build_logline(s, s->unique_id, UNIQUEID_LEN, &sess->fe->format_unique_id);
}
+ if (!LIST_ISEMPTY(&sess->fe->logformat_sd)) {
+ sd_size = build_logline(s, logline_rfc5424, global.max_syslog_len,
+ &sess->fe->logformat_sd);
+ }
+
size = build_logline(s, logline, global.max_syslog_len, &sess->fe->logformat);
if (size > 0) {
sess->fe->log_count++;
- __send_log(sess->fe, level, logline, size + 1);
+ __send_log(sess->fe, level, logline, size + 1, logline_rfc5424, sd_size);
s->logs.logwait = 0;
}
}
diff --git a/src/proxy.c b/src/proxy.c
index fb62b7c..52e4bbe 100644
--- a/src/proxy.c
+++ b/src/proxy.c
@@ -741,6 +741,7 @@
LIST_INIT(&p->listener_queue);
LIST_INIT(&p->logsrvs);
LIST_INIT(&p->logformat);
+ LIST_INIT(&p->logformat_sd);
LIST_INIT(&p->format_unique_id);
LIST_INIT(&p->conf.bind);
LIST_INIT(&p->conf.listeners);
diff --git a/src/sample.c b/src/sample.c
index c1d5bb5..5a79955 100644
--- a/src/sample.c
+++ b/src/sample.c
@@ -1103,16 +1103,17 @@
where = "in";
ctx = "sample fetch keyword";
switch (cur->ctx) {
- case ARGC_STK: where = "in stick rule in"; break;
- case ARGC_TRK: where = "in tracking rule in"; break;
- case ARGC_LOG: where = "in log-format string in"; break;
- case ARGC_HRQ: where = "in http-request header format string in"; break;
- case ARGC_HRS: where = "in http-response header format string in"; break;
- case ARGC_UIF: where = "in unique-id-format string in"; break;
- case ARGC_RDR: where = "in redirect format string in"; break;
- case ARGC_CAP: where = "in capture rule in"; break;
- case ARGC_ACL: ctx = "ACL keyword"; break;
- case ARGC_SRV: where = "in server directive in"; break;
+ case ARGC_STK: where = "in stick rule in"; break;
+ case ARGC_TRK: where = "in tracking rule in"; break;
+ case ARGC_LOG: where = "in log-format string in"; break;
+ case ARGC_LOGSD: where = "in log-format-sd string in"; break;
+ case ARGC_HRQ: where = "in http-request header format string in"; break;
+ case ARGC_HRS: where = "in http-response header format string in"; break;
+ case ARGC_UIF: where = "in unique-id-format string in"; break;
+ case ARGC_RDR: where = "in redirect format string in"; break;
+ case ARGC_CAP: where = "in capture rule in"; break;
+ case ARGC_ACL: ctx = "ACL keyword"; break;
+ case ARGC_SRV: where = "in server directive in"; break;
}
/* set a few default settings */