From 0b85ecee53b517fbc16c505c7e1ab4b802f9054a Mon Sep 17 00:00:00 2001 From: Dragan Dosen Date: Fri, 25 Sep 2015 19:17:44 +0200 Subject: [PATCH] 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\"] --- include/proto/log.h | 5 ++- include/types/arg.h | 1 + include/types/log.h | 2 +- include/types/proxy.h | 4 +++ src/cfgparse.c | 69 +++++++++++++++++++++++++++++++++++++++- src/haproxy.c | 9 ++++++ src/log.c | 73 ++++++++++++++++++++++++++++++++----------- src/proxy.c | 1 + src/sample.c | 21 +++++++------ 9 files changed, 153 insertions(+), 32 deletions(-) diff --git a/include/proto/log.h b/include/proto/log.h index fca7fdd2fd..62b39eab83 100644 --- a/include/proto/log.h +++ b/include/proto/log.h @@ -43,9 +43,12 @@ extern char clf_http_log_format[]; extern char default_host_tag_pid_log_format[]; extern char rfc5424_host_tag_pid_log_format[]; +extern char default_rfc5424_sd_log_format[]; + extern char *logheader; extern char *logheader_rfc5424; extern char *logline; +extern char *logline_rfc5424; int build_logline(struct stream *s, char *dst, size_t maxsize, struct list *list_format); @@ -111,7 +114,7 @@ void send_log(struct proxy *p, int level, const char *format, ...) * It doesn't care about errors nor does it report them. */ -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); /* * returns log format for or -1 if not found. diff --git a/include/types/arg.h b/include/types/arg.h index fd35354acb..5430de733f 100644 --- a/include/types/arg.h +++ b/include/types/arg.h @@ -69,6 +69,7 @@ enum { ARGC_STK, /* sticking rule */ ARGC_TRK, /* tracking rule */ ARGC_LOG, /* log-format */ + ARGC_LOGSD, /* log-format-sd */ ARGC_HRQ, /* http-request */ ARGC_HRS, /* http-response */ ARGC_UIF, /* unique-id-format */ diff --git a/include/types/log.h b/include/types/log.h index 2cfd31a8bc..6a68b5dbeb 100644 --- a/include/types/log.h +++ b/include/types/log.h @@ -30,7 +30,7 @@ #define NB_LOG_FACILITIES 24 #define NB_LOG_LEVELS 8 -#define NB_MSG_IOVEC_ELEMENTS 3 +#define NB_MSG_IOVEC_ELEMENTS 4 #define SYSLOG_PORT 514 #define UNIQUEID_LEN 128 diff --git a/include/types/proxy.h b/include/types/proxy.h index 9793a29f5d..49debc628d 100644 --- a/include/types/proxy.h +++ b/include/types/proxy.h @@ -345,6 +345,7 @@ struct proxy { unsigned int log_count; /* number of logs produced by the frontend */ struct list logsrvs; struct list logformat; /* log_format linked list */ + struct list logformat_sd; /* log_format linked list for the RFC5424 structured-data part */ char *log_tag; /* override default syslog tag */ struct chunk log_htp; /* a syslog header part that contains hostname, log_tag and pid (RFC3164 format) */ struct chunk log_htp_rfc5424; /* a syslog header part that contains hostname, log_tag and pid (RFC5424 format) */ @@ -404,6 +405,9 @@ struct proxy { int uif_line; /* file name where the unique-id-format string appears */ char *uif_file; /* file name where the unique-id-format string appears (strdup) */ char *uniqueid_format_string; /* unique-id format string */ + char *logformat_sd_string; /* log format string for the RFC5424 structured-data part */ + char *lfsd_file; /* file name where the structured-data logformat string for RFC5424 appears (strdup) */ + int lfsd_line; /* file name where the structured-data logformat string for RFC5424 appears */ } conf; /* config information */ void *parent; /* parent of the proxy when applicable */ struct comp *comp; /* http compression */ diff --git a/src/cfgparse.c b/src/cfgparse.c index af2d7771fa..f3a7aee3a8 100644 --- a/src/cfgparse.c +++ b/src/cfgparse.c @@ -1574,6 +1574,7 @@ int cfg_parse_global(const char *file, int linenum, char **args, int kwm) 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 @@ int cfg_parse_listen(const char *file, int linenum, char **args, int kwm) 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 @@ int cfg_parse_listen(const char *file, int linenum, char **args, int kwm) 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 @@ int cfg_parse_listen(const char *file, int linenum, char **args, int kwm) 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 @@ int cfg_parse_listen(const char *file, int linenum, char **args, int kwm) 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 @@ int check_config_validity() 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 @@ int check_config_validity() 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 @@ int check_config_validity() 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 @@ int check_config_validity() 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 9539dfa309..57db1db31e 100644 --- a/src/haproxy.c +++ b/src/haproxy.c @@ -1227,6 +1227,10 @@ void deinit(void) 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 @@ void deinit(void) 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 8fe2348569..18296967a1 100644 --- a/src/log.c +++ b/src/log.c @@ -155,8 +155,16 @@ char clf_http_log_format[] = "%{+Q}o %{-Q}ci - - [%T] %r %ST %B \"\" \"\" %cp %m 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 *logheader_rfc5424 = NULL; */ 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 @@ static inline const char *fmt_directive(const struct proxy *curproxy) 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 @@ char *lf_host_tag_pid(char *dst, const char *format, const char *hostname, const * 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 @@ static char *update_log_hdr() * 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 @@ void send_log(struct proxy *p, int level, const char *format, ...) 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 and 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 @@ void __send_log(struct proxy *p, int level, char *message, size_t size) char *hdr, *hdr_ptr; size_t hdr_size; struct chunk *htp; + time_t time = date.tv_sec; dataptr = message; @@ -921,6 +939,7 @@ void __send_log(struct proxy *p, int level, char *message, size_t size) int maxlen; int hdr_max = 0; int htp_max = 0; + int sd_max = 0; int max = 1; char backup; @@ -948,14 +967,15 @@ void __send_log(struct proxy *p, int level, char *message, size_t size) 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 @@ void __send_log(struct proxy *p, int level, char *message, size_t size) 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; + 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 @@ void __send_log(struct proxy *p, int level, char *message, size_t size) 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 @@ void strm_log(struct stream *s) { 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 @@ void strm_log(struct stream *s) 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 fb62b7c044..52e4bbe52b 100644 --- a/src/proxy.c +++ b/src/proxy.c @@ -741,6 +741,7 @@ void init_new_proxy(struct proxy *p) 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 c1d5bb5d45..5a79955bcb 100644 --- a/src/sample.c +++ b/src/sample.c @@ -1103,16 +1103,17 @@ int smp_resolve_args(struct proxy *p) 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 */