blob: dd1b63f13caa1bc977dbb05004fc130f67d2c967 [file] [log] [blame]
Willy Tarreaubaaee002006-06-26 02:48:02 +02001/*
2 * General logging functions.
3 *
Willy Tarreaub7f694f2008-06-22 17:18:02 +02004 * Copyright 2000-2008 Willy Tarreau <w@1wt.eu>
Willy Tarreaubaaee002006-06-26 02:48:02 +02005 *
6 * This program is free software; you can redistribute it and/or
7 * modify it under the terms of the GNU General Public License
8 * as published by the Free Software Foundation; either version
9 * 2 of the License, or (at your option) any later version.
10 *
11 */
12
Willy Tarreauc8f24f82007-11-30 18:38:35 +010013#include <fcntl.h>
Willy Tarreaubaaee002006-06-26 02:48:02 +020014#include <stdarg.h>
15#include <stdio.h>
16#include <stdlib.h>
17#include <string.h>
18#include <syslog.h>
19#include <time.h>
20#include <unistd.h>
Robert Tsai81ae1952007-12-05 10:47:29 +010021#include <errno.h>
Willy Tarreaubaaee002006-06-26 02:48:02 +020022
23#include <sys/time.h>
24
Willy Tarreaue3ba5f02006-06-29 18:54:54 +020025#include <common/config.h>
Willy Tarreaud6d06902009-08-19 11:22:33 +020026#include <common/compat.h>
Willy Tarreau2dd0d472006-06-29 17:53:05 +020027#include <common/standard.h>
Willy Tarreaufb278672006-10-15 15:38:50 +020028#include <common/time.h>
Willy Tarreaubaaee002006-06-26 02:48:02 +020029
Willy Tarreaubaaee002006-06-26 02:48:02 +020030#include <types/global.h>
Willy Tarreauec6c5df2008-07-15 00:22:45 +020031
32#include <proto/log.h>
Willy Tarreau827aee92011-03-10 16:55:02 +010033#include <proto/stream_interface.h>
Willy Tarreaubaaee002006-06-26 02:48:02 +020034
Willy Tarreaubaaee002006-06-26 02:48:02 +020035const char *log_facilities[NB_LOG_FACILITIES] = {
36 "kern", "user", "mail", "daemon",
37 "auth", "syslog", "lpr", "news",
38 "uucp", "cron", "auth2", "ftp",
39 "ntp", "audit", "alert", "cron2",
40 "local0", "local1", "local2", "local3",
41 "local4", "local5", "local6", "local7"
42};
43
44
45const char *log_levels[NB_LOG_LEVELS] = {
46 "emerg", "alert", "crit", "err",
47 "warning", "notice", "info", "debug"
48};
49
50const char *monthname[12] = {
51 "Jan", "Feb", "Mar", "Apr", "May", "Jun",
52 "Jul", "Aug", "Sep", "Oct", "Nov", "Dec"
53};
54
Willy Tarreaua2a64e92011-09-07 23:01:56 +020055const char sess_term_cond[10] = "-cCsSPRIDK"; /* normal, CliTo, CliErr, SrvTo, SrvErr, PxErr, Resource, Internal, Down, Killed */
Willy Tarreaub8750a82006-09-03 09:56:00 +020056const char sess_fin_state[8] = "-RCHDLQT"; /* cliRequest, srvConnect, srvHeader, Data, Last, Queue, Tarpit */
Willy Tarreaubaaee002006-06-26 02:48:02 +020057
58/*
59 * Displays the message on stderr with the date and pid. Overrides the quiet
60 * mode during startup.
61 */
Willy Tarreaub17916e2006-10-15 15:17:57 +020062void Alert(const char *fmt, ...)
Willy Tarreaubaaee002006-06-26 02:48:02 +020063{
64 va_list argp;
Willy Tarreaufe944602007-10-25 10:34:16 +020065 struct tm tm;
Willy Tarreaubaaee002006-06-26 02:48:02 +020066
67 if (!(global.mode & MODE_QUIET) || (global.mode & (MODE_VERBOSE | MODE_STARTING))) {
68 va_start(argp, fmt);
69
Willy Tarreaub7f694f2008-06-22 17:18:02 +020070 get_localtime(date.tv_sec, &tm);
Willy Tarreaubaaee002006-06-26 02:48:02 +020071 fprintf(stderr, "[ALERT] %03d/%02d%02d%02d (%d) : ",
Willy Tarreaufe944602007-10-25 10:34:16 +020072 tm.tm_yday, tm.tm_hour, tm.tm_min, tm.tm_sec, (int)getpid());
Willy Tarreaubaaee002006-06-26 02:48:02 +020073 vfprintf(stderr, fmt, argp);
74 fflush(stderr);
75 va_end(argp);
76 }
77}
78
79
80/*
81 * Displays the message on stderr with the date and pid.
82 */
Willy Tarreaub17916e2006-10-15 15:17:57 +020083void Warning(const char *fmt, ...)
Willy Tarreaubaaee002006-06-26 02:48:02 +020084{
85 va_list argp;
Willy Tarreaufe944602007-10-25 10:34:16 +020086 struct tm tm;
Willy Tarreaubaaee002006-06-26 02:48:02 +020087
88 if (!(global.mode & MODE_QUIET) || (global.mode & MODE_VERBOSE)) {
89 va_start(argp, fmt);
90
Willy Tarreaub7f694f2008-06-22 17:18:02 +020091 get_localtime(date.tv_sec, &tm);
Willy Tarreaubaaee002006-06-26 02:48:02 +020092 fprintf(stderr, "[WARNING] %03d/%02d%02d%02d (%d) : ",
Willy Tarreaufe944602007-10-25 10:34:16 +020093 tm.tm_yday, tm.tm_hour, tm.tm_min, tm.tm_sec, (int)getpid());
Willy Tarreaubaaee002006-06-26 02:48:02 +020094 vfprintf(stderr, fmt, argp);
95 fflush(stderr);
96 va_end(argp);
97 }
98}
99
100/*
101 * Displays the message on <out> only if quiet mode is not set.
102 */
Willy Tarreaub17916e2006-10-15 15:17:57 +0200103void qfprintf(FILE *out, const char *fmt, ...)
Willy Tarreaubaaee002006-06-26 02:48:02 +0200104{
105 va_list argp;
106
107 if (!(global.mode & MODE_QUIET) || (global.mode & MODE_VERBOSE)) {
108 va_start(argp, fmt);
109 vfprintf(out, fmt, argp);
110 fflush(out);
111 va_end(argp);
112 }
113}
114
115/*
116 * returns log level for <lev> or -1 if not found.
117 */
118int get_log_level(const char *lev)
119{
120 int level;
121
122 level = NB_LOG_LEVELS - 1;
123 while (level >= 0 && strcmp(log_levels[level], lev))
124 level--;
125
126 return level;
127}
128
129
130/*
131 * returns log facility for <fac> or -1 if not found.
132 */
133int get_log_facility(const char *fac)
134{
135 int facility;
136
137 facility = NB_LOG_FACILITIES - 1;
138 while (facility >= 0 && strcmp(log_facilities[facility], fac))
139 facility--;
140
141 return facility;
142}
143
Robert Tsai81ae1952007-12-05 10:47:29 +0100144/*
Willy Tarreaubaaee002006-06-26 02:48:02 +0200145 * This function sends a syslog message to both log servers of a proxy,
146 * or to global log servers if the proxy is NULL.
147 * It also tries not to waste too much time computing the message header.
148 * It doesn't care about errors nor does it report them.
149 */
Willy Tarreaub17916e2006-10-15 15:17:57 +0200150void send_log(struct proxy *p, int level, const char *message, ...)
Willy Tarreaubaaee002006-06-26 02:48:02 +0200151{
Robert Tsai81ae1952007-12-05 10:47:29 +0100152 static int logfdunix = -1; /* syslog to AF_UNIX socket */
153 static int logfdinet = -1; /* syslog to AF_INET socket */
Willy Tarreaubaaee002006-06-26 02:48:02 +0200154 static long tvsec = -1; /* to force the string to be initialized */
Willy Tarreaubaaee002006-06-26 02:48:02 +0200155 va_list argp;
156 static char logmsg[MAX_SYSLOG_LEN];
157 static char *dataptr = NULL;
158 int fac_level;
159 int hdr_len, data_len;
William Lallemand0f99e342011-10-12 17:50:54 +0200160 struct list *logsrvs = NULL;
161 struct logsrv *tmp = NULL;
Robert Tsai81ae1952007-12-05 10:47:29 +0100162 int nblogger;
Willy Tarreaubaaee002006-06-26 02:48:02 +0200163 char *log_ptr;
164
Kevinm48936af2010-12-22 16:08:21 +0000165 if (level < 0 || message == NULL)
Willy Tarreaubaaee002006-06-26 02:48:02 +0200166 return;
167
Willy Tarreaub7f694f2008-06-22 17:18:02 +0200168 if (unlikely(date.tv_sec != tvsec || dataptr == NULL)) {
Willy Tarreaubaaee002006-06-26 02:48:02 +0200169 /* this string is rebuild only once a second */
Willy Tarreaufe944602007-10-25 10:34:16 +0200170 struct tm tm;
171
Willy Tarreaub7f694f2008-06-22 17:18:02 +0200172 tvsec = date.tv_sec;
Willy Tarreaufe944602007-10-25 10:34:16 +0200173 get_localtime(tvsec, &tm);
Willy Tarreaubaaee002006-06-26 02:48:02 +0200174
175 hdr_len = snprintf(logmsg, sizeof(logmsg),
Joe Williamsdf5b38f2010-12-29 17:05:48 +0100176 "<<<<>%s %2d %02d:%02d:%02d %s%s[%d]: ",
Willy Tarreaufe944602007-10-25 10:34:16 +0200177 monthname[tm.tm_mon],
178 tm.tm_mday, tm.tm_hour, tm.tm_min, tm.tm_sec,
Joe Williamsdf5b38f2010-12-29 17:05:48 +0100179 global.log_send_hostname ? global.log_send_hostname : "",
Kevinm48936af2010-12-22 16:08:21 +0000180 global.log_tag, pid);
Willy Tarreaubaaee002006-06-26 02:48:02 +0200181 /* WARNING: depending upon implementations, snprintf may return
182 * either -1 or the number of bytes that would be needed to store
183 * the total message. In both cases, we must adjust it.
184 */
185 if (hdr_len < 0 || hdr_len > sizeof(logmsg))
186 hdr_len = sizeof(logmsg);
187
188 dataptr = logmsg + hdr_len;
189 }
190
191 va_start(argp, message);
Willy Tarreau8d5d7f22007-01-21 19:16:41 +0100192 /*
193 * FIXME: we take a huge performance hit here. We might have to replace
194 * vsnprintf() for a hard-coded log writer.
195 */
Willy Tarreaubaaee002006-06-26 02:48:02 +0200196 data_len = vsnprintf(dataptr, logmsg + sizeof(logmsg) - dataptr, message, argp);
197 if (data_len < 0 || data_len > (logmsg + sizeof(logmsg) - dataptr))
198 data_len = logmsg + sizeof(logmsg) - dataptr;
199 va_end(argp);
200 dataptr[data_len - 1] = '\n'; /* force a break on ultra-long lines */
201
202 if (p == NULL) {
William Lallemand0f99e342011-10-12 17:50:54 +0200203 if (!LIST_ISEMPTY(&global.logsrvs)) {
204 logsrvs = &global.logsrvs;
Willy Tarreaubaaee002006-06-26 02:48:02 +0200205 }
206 } else {
William Lallemand0f99e342011-10-12 17:50:54 +0200207 if (!LIST_ISEMPTY(&p->logsrvs)) {
208 logsrvs = &p->logsrvs;
Willy Tarreaubaaee002006-06-26 02:48:02 +0200209 }
Robert Tsai81ae1952007-12-05 10:47:29 +0100210 }
211
William Lallemand0f99e342011-10-12 17:50:54 +0200212 if (!logsrvs)
213 return;
214
Robert Tsai81ae1952007-12-05 10:47:29 +0100215 /* Lazily set up syslog sockets for protocol families of configured
216 * syslog servers. */
William Lallemand0f99e342011-10-12 17:50:54 +0200217 nblogger = 0;
218 list_for_each_entry(tmp, logsrvs, list) {
219 const struct logsrv *logsrv = tmp;
Robert Tsai81ae1952007-12-05 10:47:29 +0100220 int proto, *plogfd;
William Lallemand0f99e342011-10-12 17:50:54 +0200221
David du Colombier11bcb6c2011-03-24 12:23:00 +0100222 if (logsrv->addr.ss_family == AF_UNIX) {
Robert Tsai81ae1952007-12-05 10:47:29 +0100223 proto = 0;
224 plogfd = &logfdunix;
225 } else {
Robert Tsai81ae1952007-12-05 10:47:29 +0100226 proto = IPPROTO_UDP;
227 plogfd = &logfdinet;
228 }
229 if (*plogfd >= 0) {
230 /* socket already created. */
231 continue;
232 }
David du Colombier11bcb6c2011-03-24 12:23:00 +0100233 if ((*plogfd = socket(logsrv->addr.ss_family, SOCK_DGRAM,
Robert Tsai81ae1952007-12-05 10:47:29 +0100234 proto)) < 0) {
235 Alert("socket for logger #%d failed: %s (errno=%d)\n",
236 nblogger + 1, strerror(errno), errno);
237 return;
238 }
239 /* we don't want to receive anything on this socket */
240 setsockopt(*plogfd, SOL_SOCKET, SO_RCVBUF, &zero, sizeof(zero));
241 /* does nothing under Linux, maybe needed for others */
242 shutdown(*plogfd, SHUT_RD);
William Lallemand0f99e342011-10-12 17:50:54 +0200243 nblogger++;
Willy Tarreaubaaee002006-06-26 02:48:02 +0200244 }
245
Robert Tsai81ae1952007-12-05 10:47:29 +0100246 /* Send log messages to syslog server. */
William Lallemand0f99e342011-10-12 17:50:54 +0200247 nblogger = 0;
248 list_for_each_entry(tmp, logsrvs, list) {
249 const struct logsrv *logsrv = tmp;
David du Colombier11bcb6c2011-03-24 12:23:00 +0100250 int *plogfd = logsrv->addr.ss_family == AF_UNIX ?
Robert Tsai81ae1952007-12-05 10:47:29 +0100251 &logfdunix : &logfdinet;
252 int sent;
253
Willy Tarreaubaaee002006-06-26 02:48:02 +0200254 /* we can filter the level of the messages that are sent to each logger */
William Lallemand0f99e342011-10-12 17:50:54 +0200255 if (level > logsrv->level)
Willy Tarreaubaaee002006-06-26 02:48:02 +0200256 continue;
257
258 /* For each target, we may have a different facility.
259 * We can also have a different log level for each message.
260 * This induces variations in the message header length.
261 * Since we don't want to recompute it each time, nor copy it every
262 * time, we only change the facility in the pre-computed header,
263 * and we change the pointer to the header accordingly.
264 */
William Lallemand0f99e342011-10-12 17:50:54 +0200265 fac_level = (logsrv->facility << 3) + MAX(level, logsrv->minlvl);
Willy Tarreaubaaee002006-06-26 02:48:02 +0200266 log_ptr = logmsg + 3; /* last digit of the log level */
267 do {
268 *log_ptr = '0' + fac_level % 10;
269 fac_level /= 10;
270 log_ptr--;
271 } while (fac_level && log_ptr > logmsg);
272 *log_ptr = '<';
273
274 /* the total syslog message now starts at logptr, for dataptr+data_len-logptr */
Robert Tsai81ae1952007-12-05 10:47:29 +0100275 sent = sendto(*plogfd, log_ptr, dataptr + data_len - log_ptr,
Willy Tarreau1b4b7ce2011-04-05 16:56:50 +0200276 MSG_DONTWAIT | MSG_NOSIGNAL,
277 (struct sockaddr *)&logsrv->addr, get_addr_len(&logsrv->addr));
Robert Tsai81ae1952007-12-05 10:47:29 +0100278 if (sent < 0) {
279 Alert("sendto logger #%d failed: %s (errno=%d)\n",
280 nblogger, strerror(errno), errno);
281 }
William Lallemand0f99e342011-10-12 17:50:54 +0200282 nblogger++;
Willy Tarreaubaaee002006-06-26 02:48:02 +0200283 }
284}
285
286
287/*
288 * send a log for the session when we have enough info about it
289 */
Willy Tarreau42250582007-04-01 01:30:43 +0200290void tcp_sess_log(struct session *s)
Willy Tarreaubaaee002006-06-26 02:48:02 +0200291{
Cyril Bontéacd7d632010-11-01 19:26:02 +0100292 char pn[INET6_ADDRSTRLEN];
Willy Tarreau73de9892006-11-30 11:40:23 +0100293 struct proxy *fe = s->fe;
Willy Tarreauddb358d2006-12-17 22:55:52 +0100294 struct proxy *be = s->be;
295 struct proxy *prx_log;
Willy Tarreauc9bd0cc2009-05-10 11:57:02 +0200296 int tolog, level, err;
Willy Tarreau42250582007-04-01 01:30:43 +0200297 char *svid;
Willy Tarreaufe944602007-10-25 10:34:16 +0200298 struct tm tm;
Willy Tarreaubaaee002006-06-26 02:48:02 +0200299
Willy Tarreauc9bd0cc2009-05-10 11:57:02 +0200300 /* if we don't want to log normal traffic, return now */
Willy Tarreauee28de02010-06-01 09:51:00 +0200301 err = (s->flags & (SN_ERR_MASK | SN_REDISP)) || (s->req->cons->conn_retries != be->conn_retries);
Willy Tarreauc9bd0cc2009-05-10 11:57:02 +0200302 if (!err && (fe->options2 & PR_O2_NOLOGNORM))
303 return;
304
Willy Tarreau6471afb2011-09-23 10:54:59 +0200305 addr_to_str(&s->si[0].addr.from, pn, sizeof(pn));
Willy Tarreaufe944602007-10-25 10:34:16 +0200306 get_localtime(s->logs.tv_accept.tv_sec, &tm);
Willy Tarreauddb358d2006-12-17 22:55:52 +0100307
William Lallemand0f99e342011-10-12 17:50:54 +0200308 if(LIST_ISEMPTY(&fe->logsrvs))
Willy Tarreaue7ded1f2009-08-09 10:11:45 +0200309 return;
Willy Tarreauddb358d2006-12-17 22:55:52 +0100310
Willy Tarreaue7ded1f2009-08-09 10:11:45 +0200311 prx_log = fe;
Willy Tarreau42250582007-04-01 01:30:43 +0200312 tolog = fe->to_log;
Willy Tarreau71904a42011-02-13 14:30:26 +0100313
314 if (!(tolog & LW_SVID))
315 svid = "-";
Willy Tarreau7b7a8e92011-03-27 19:53:06 +0200316 else switch (s->target.type) {
Willy Tarreau71904a42011-02-13 14:30:26 +0100317 case TARG_TYPE_SERVER:
Willy Tarreau7b7a8e92011-03-27 19:53:06 +0200318 svid = s->target.ptr.s->id;
Willy Tarreau71904a42011-02-13 14:30:26 +0100319 break;
320 case TARG_TYPE_APPLET:
Willy Tarreau7b7a8e92011-03-27 19:53:06 +0200321 svid = s->target.ptr.a->name;
Willy Tarreau71904a42011-02-13 14:30:26 +0100322 break;
323 default:
324 svid = "<NOSRV>";
325 break;
326 }
Willy Tarreaubaaee002006-06-26 02:48:02 +0200327
Willy Tarreauc9bd0cc2009-05-10 11:57:02 +0200328 level = LOG_INFO;
329 if (err && (fe->options2 & PR_O2_LOGERRORS))
330 level = LOG_ERR;
331
332 send_log(prx_log, level, "%s:%d [%02d/%s/%04d:%02d:%02d:%02d.%03d]"
Willy Tarreau1772ece2009-04-03 14:49:12 +0200333 " %s %s/%s %ld/%ld/%s%ld %s%lld"
334 " %c%c %d/%d/%d/%d/%s%u %ld/%ld\n",
Willy Tarreau6471afb2011-09-23 10:54:59 +0200335 s->si[0].addr.from.ss_family == AF_UNIX ? "unix" : pn,
336 s->si[0].addr.from.ss_family == AF_UNIX ? s->listener->luid : get_host_port(&s->si[0].addr.from),
Willy Tarreaufe944602007-10-25 10:34:16 +0200337 tm.tm_mday, monthname[tm.tm_mon], tm.tm_year+1900,
Willy Tarreau1772ece2009-04-03 14:49:12 +0200338 tm.tm_hour, tm.tm_min, tm.tm_sec, (int)s->logs.tv_accept.tv_usec/1000,
Willy Tarreau42250582007-04-01 01:30:43 +0200339 fe->id, be->id, svid,
340 (s->logs.t_queue >= 0) ? s->logs.t_queue : -1,
341 (s->logs.t_connect >= 0) ? s->logs.t_connect - s->logs.t_queue : -1,
342 (tolog & LW_BYTES) ? "" : "+", s->logs.t_close,
Willy Tarreau8b3977f2008-01-18 11:16:32 +0100343 (tolog & LW_BYTES) ? "" : "+", s->logs.bytes_out,
Willy Tarreau42250582007-04-01 01:30:43 +0200344 sess_term_cond[(s->flags & SN_ERR_MASK) >> SN_ERR_SHIFT],
345 sess_fin_state[(s->flags & SN_FINST_MASK) >> SN_FINST_SHIFT],
Willy Tarreau827aee92011-03-10 16:55:02 +0100346 actconn, fe->feconn, be->beconn, target_srv(&s->target) ? target_srv(&s->target)->cur_sess : 0,
Krzysztof Piotr Oledzki25b501a2008-01-06 16:36:16 +0100347 (s->flags & SN_REDISP)?"+":"",
Willy Tarreauee28de02010-06-01 09:51:00 +0200348 (s->req->cons->conn_retries>0)?(be->conn_retries - s->req->cons->conn_retries):be->conn_retries,
Willy Tarreau42250582007-04-01 01:30:43 +0200349 s->logs.srv_queue_size, s->logs.prx_queue_size);
Willy Tarreaubaaee002006-06-26 02:48:02 +0200350
351 s->logs.logwait = 0;
352}
353
Willy Tarreaubaaee002006-06-26 02:48:02 +0200354
355/*
356 * Local variables:
357 * c-indent-level: 8
358 * c-basic-offset: 8
359 * End:
360 */