blob: 093accb28735e9b40389ab66559a24990b85db2b [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 Tarreau2dd0d472006-06-29 17:53:05 +020026#include <common/standard.h>
Willy Tarreaufb278672006-10-15 15:38:50 +020027#include <common/time.h>
Willy Tarreaubaaee002006-06-26 02:48:02 +020028
Willy Tarreaubaaee002006-06-26 02:48:02 +020029#include <types/global.h>
Willy Tarreauec6c5df2008-07-15 00:22:45 +020030
31#include <proto/log.h>
Willy Tarreaubaaee002006-06-26 02:48:02 +020032
Robert Tsai81ae1952007-12-05 10:47:29 +010033#ifndef MSG_NOSIGNAL
34#define MSG_NOSIGNAL (0)
35#endif /* !MSG_NOSIGNAL */
Willy Tarreaubaaee002006-06-26 02:48:02 +020036
37const char *log_facilities[NB_LOG_FACILITIES] = {
38 "kern", "user", "mail", "daemon",
39 "auth", "syslog", "lpr", "news",
40 "uucp", "cron", "auth2", "ftp",
41 "ntp", "audit", "alert", "cron2",
42 "local0", "local1", "local2", "local3",
43 "local4", "local5", "local6", "local7"
44};
45
46
47const char *log_levels[NB_LOG_LEVELS] = {
48 "emerg", "alert", "crit", "err",
49 "warning", "notice", "info", "debug"
50};
51
52const char *monthname[12] = {
53 "Jan", "Feb", "Mar", "Apr", "May", "Jun",
54 "Jul", "Aug", "Sep", "Oct", "Nov", "Dec"
55};
56
57const char sess_term_cond[8] = "-cCsSPRI"; /* normal, CliTo, CliErr, SrvTo, SrvErr, PxErr, Resource, Internal */
Willy Tarreaub8750a82006-09-03 09:56:00 +020058const char sess_fin_state[8] = "-RCHDLQT"; /* cliRequest, srvConnect, srvHeader, Data, Last, Queue, Tarpit */
Willy Tarreaubaaee002006-06-26 02:48:02 +020059
60/*
61 * Displays the message on stderr with the date and pid. Overrides the quiet
62 * mode during startup.
63 */
Willy Tarreaub17916e2006-10-15 15:17:57 +020064void Alert(const char *fmt, ...)
Willy Tarreaubaaee002006-06-26 02:48:02 +020065{
66 va_list argp;
Willy Tarreaufe944602007-10-25 10:34:16 +020067 struct tm tm;
Willy Tarreaubaaee002006-06-26 02:48:02 +020068
69 if (!(global.mode & MODE_QUIET) || (global.mode & (MODE_VERBOSE | MODE_STARTING))) {
70 va_start(argp, fmt);
71
Willy Tarreaub7f694f2008-06-22 17:18:02 +020072 get_localtime(date.tv_sec, &tm);
Willy Tarreaubaaee002006-06-26 02:48:02 +020073 fprintf(stderr, "[ALERT] %03d/%02d%02d%02d (%d) : ",
Willy Tarreaufe944602007-10-25 10:34:16 +020074 tm.tm_yday, tm.tm_hour, tm.tm_min, tm.tm_sec, (int)getpid());
Willy Tarreaubaaee002006-06-26 02:48:02 +020075 vfprintf(stderr, fmt, argp);
76 fflush(stderr);
77 va_end(argp);
78 }
79}
80
81
82/*
83 * Displays the message on stderr with the date and pid.
84 */
Willy Tarreaub17916e2006-10-15 15:17:57 +020085void Warning(const char *fmt, ...)
Willy Tarreaubaaee002006-06-26 02:48:02 +020086{
87 va_list argp;
Willy Tarreaufe944602007-10-25 10:34:16 +020088 struct tm tm;
Willy Tarreaubaaee002006-06-26 02:48:02 +020089
90 if (!(global.mode & MODE_QUIET) || (global.mode & MODE_VERBOSE)) {
91 va_start(argp, fmt);
92
Willy Tarreaub7f694f2008-06-22 17:18:02 +020093 get_localtime(date.tv_sec, &tm);
Willy Tarreaubaaee002006-06-26 02:48:02 +020094 fprintf(stderr, "[WARNING] %03d/%02d%02d%02d (%d) : ",
Willy Tarreaufe944602007-10-25 10:34:16 +020095 tm.tm_yday, tm.tm_hour, tm.tm_min, tm.tm_sec, (int)getpid());
Willy Tarreaubaaee002006-06-26 02:48:02 +020096 vfprintf(stderr, fmt, argp);
97 fflush(stderr);
98 va_end(argp);
99 }
100}
101
102/*
103 * Displays the message on <out> only if quiet mode is not set.
104 */
Willy Tarreaub17916e2006-10-15 15:17:57 +0200105void qfprintf(FILE *out, const char *fmt, ...)
Willy Tarreaubaaee002006-06-26 02:48:02 +0200106{
107 va_list argp;
108
109 if (!(global.mode & MODE_QUIET) || (global.mode & MODE_VERBOSE)) {
110 va_start(argp, fmt);
111 vfprintf(out, fmt, argp);
112 fflush(out);
113 va_end(argp);
114 }
115}
116
117/*
118 * returns log level for <lev> or -1 if not found.
119 */
120int get_log_level(const char *lev)
121{
122 int level;
123
124 level = NB_LOG_LEVELS - 1;
125 while (level >= 0 && strcmp(log_levels[level], lev))
126 level--;
127
128 return level;
129}
130
131
132/*
133 * returns log facility for <fac> or -1 if not found.
134 */
135int get_log_facility(const char *fac)
136{
137 int facility;
138
139 facility = NB_LOG_FACILITIES - 1;
140 while (facility >= 0 && strcmp(log_facilities[facility], fac))
141 facility--;
142
143 return facility;
144}
145
Robert Tsai81ae1952007-12-05 10:47:29 +0100146/*
147 * Return the length of the address endpoint, suitable for use with sendto().
148 */
Willy Tarreau019767b2007-12-05 11:11:55 +0100149static inline int logsrv_addrlen(const struct logsrv *logsrv)
Robert Tsai81ae1952007-12-05 10:47:29 +0100150{
Robert Tsai81ae1952007-12-05 10:47:29 +0100151 switch (logsrv->u.addr.sa_family) {
152 case AF_UNIX:
153 return sizeof(logsrv->u.un);
154 case AF_INET:
155 return sizeof(logsrv->u.in);
156 default:
157 break;
158 }
Robert Tsai81ae1952007-12-05 10:47:29 +0100159 return -1;
160}
Willy Tarreaubaaee002006-06-26 02:48:02 +0200161
Willy Tarreaubaaee002006-06-26 02:48:02 +0200162/*
163 * This function sends a syslog message to both log servers of a proxy,
164 * or to global log servers if the proxy is NULL.
165 * It also tries not to waste too much time computing the message header.
166 * It doesn't care about errors nor does it report them.
167 */
Willy Tarreaub17916e2006-10-15 15:17:57 +0200168void send_log(struct proxy *p, int level, const char *message, ...)
Willy Tarreaubaaee002006-06-26 02:48:02 +0200169{
Robert Tsai81ae1952007-12-05 10:47:29 +0100170 static int logfdunix = -1; /* syslog to AF_UNIX socket */
171 static int logfdinet = -1; /* syslog to AF_INET socket */
Willy Tarreaubaaee002006-06-26 02:48:02 +0200172 static long tvsec = -1; /* to force the string to be initialized */
Willy Tarreaubaaee002006-06-26 02:48:02 +0200173 va_list argp;
174 static char logmsg[MAX_SYSLOG_LEN];
175 static char *dataptr = NULL;
176 int fac_level;
177 int hdr_len, data_len;
Robert Tsai81ae1952007-12-05 10:47:29 +0100178 struct logsrv *logsrvs[2];
Willy Tarreauf7edefa2009-05-10 17:20:05 +0200179 int facilities[2], loglevel[2], minlvl[2];
Robert Tsai81ae1952007-12-05 10:47:29 +0100180 int nblogger;
Willy Tarreaubaaee002006-06-26 02:48:02 +0200181 int nbloggers = 0;
182 char *log_ptr;
183
Willy Tarreaubaaee002006-06-26 02:48:02 +0200184 if (level < 0 || progname == NULL || message == NULL)
185 return;
186
Willy Tarreaub7f694f2008-06-22 17:18:02 +0200187 if (unlikely(date.tv_sec != tvsec || dataptr == NULL)) {
Willy Tarreaubaaee002006-06-26 02:48:02 +0200188 /* this string is rebuild only once a second */
Willy Tarreaufe944602007-10-25 10:34:16 +0200189 struct tm tm;
190
Willy Tarreaub7f694f2008-06-22 17:18:02 +0200191 tvsec = date.tv_sec;
Willy Tarreaufe944602007-10-25 10:34:16 +0200192 get_localtime(tvsec, &tm);
Willy Tarreaubaaee002006-06-26 02:48:02 +0200193
194 hdr_len = snprintf(logmsg, sizeof(logmsg),
195 "<<<<>%s %2d %02d:%02d:%02d %s[%d]: ",
Willy Tarreaufe944602007-10-25 10:34:16 +0200196 monthname[tm.tm_mon],
197 tm.tm_mday, tm.tm_hour, tm.tm_min, tm.tm_sec,
Willy Tarreaubaaee002006-06-26 02:48:02 +0200198 progname, pid);
199 /* WARNING: depending upon implementations, snprintf may return
200 * either -1 or the number of bytes that would be needed to store
201 * the total message. In both cases, we must adjust it.
202 */
203 if (hdr_len < 0 || hdr_len > sizeof(logmsg))
204 hdr_len = sizeof(logmsg);
205
206 dataptr = logmsg + hdr_len;
207 }
208
209 va_start(argp, message);
Willy Tarreau8d5d7f22007-01-21 19:16:41 +0100210 /*
211 * FIXME: we take a huge performance hit here. We might have to replace
212 * vsnprintf() for a hard-coded log writer.
213 */
Willy Tarreaubaaee002006-06-26 02:48:02 +0200214 data_len = vsnprintf(dataptr, logmsg + sizeof(logmsg) - dataptr, message, argp);
215 if (data_len < 0 || data_len > (logmsg + sizeof(logmsg) - dataptr))
216 data_len = logmsg + sizeof(logmsg) - dataptr;
217 va_end(argp);
218 dataptr[data_len - 1] = '\n'; /* force a break on ultra-long lines */
219
220 if (p == NULL) {
221 if (global.logfac1 >= 0) {
Robert Tsai81ae1952007-12-05 10:47:29 +0100222 logsrvs[nbloggers] = &global.logsrv1;
Willy Tarreaubaaee002006-06-26 02:48:02 +0200223 facilities[nbloggers] = global.logfac1;
224 loglevel[nbloggers] = global.loglev1;
Willy Tarreauf7edefa2009-05-10 17:20:05 +0200225 minlvl[nbloggers] = global.minlvl1;
Willy Tarreaubaaee002006-06-26 02:48:02 +0200226 nbloggers++;
227 }
228 if (global.logfac2 >= 0) {
Robert Tsai81ae1952007-12-05 10:47:29 +0100229 logsrvs[nbloggers] = &global.logsrv2;
Willy Tarreaubaaee002006-06-26 02:48:02 +0200230 facilities[nbloggers] = global.logfac2;
231 loglevel[nbloggers] = global.loglev2;
Willy Tarreauf7edefa2009-05-10 17:20:05 +0200232 minlvl[nbloggers] = global.minlvl2;
Willy Tarreaubaaee002006-06-26 02:48:02 +0200233 nbloggers++;
234 }
235 } else {
236 if (p->logfac1 >= 0) {
Robert Tsai81ae1952007-12-05 10:47:29 +0100237 logsrvs[nbloggers] = &p->logsrv1;
Willy Tarreaubaaee002006-06-26 02:48:02 +0200238 facilities[nbloggers] = p->logfac1;
239 loglevel[nbloggers] = p->loglev1;
Willy Tarreauf7edefa2009-05-10 17:20:05 +0200240 minlvl[nbloggers] = p->minlvl1;
Willy Tarreaubaaee002006-06-26 02:48:02 +0200241 nbloggers++;
242 }
243 if (p->logfac2 >= 0) {
Robert Tsai81ae1952007-12-05 10:47:29 +0100244 logsrvs[nbloggers] = &p->logsrv2;
Willy Tarreaubaaee002006-06-26 02:48:02 +0200245 facilities[nbloggers] = p->logfac2;
246 loglevel[nbloggers] = p->loglev2;
Willy Tarreauf7edefa2009-05-10 17:20:05 +0200247 minlvl[nbloggers] = p->minlvl2;
Willy Tarreaubaaee002006-06-26 02:48:02 +0200248 nbloggers++;
249 }
Robert Tsai81ae1952007-12-05 10:47:29 +0100250 }
251
252 /* Lazily set up syslog sockets for protocol families of configured
253 * syslog servers. */
254 for (nblogger = 0; nblogger < nbloggers; nblogger++) {
255 const struct logsrv *logsrv = logsrvs[nblogger];
256 int proto, *plogfd;
257 if (logsrv->u.addr.sa_family == AF_UNIX) {
258 proto = 0;
259 plogfd = &logfdunix;
260 } else {
261 /* sa_family == AF_INET */
262 proto = IPPROTO_UDP;
263 plogfd = &logfdinet;
264 }
265 if (*plogfd >= 0) {
266 /* socket already created. */
267 continue;
268 }
269 if ((*plogfd = socket(logsrv->u.addr.sa_family, SOCK_DGRAM,
270 proto)) < 0) {
271 Alert("socket for logger #%d failed: %s (errno=%d)\n",
272 nblogger + 1, strerror(errno), errno);
273 return;
274 }
275 /* we don't want to receive anything on this socket */
276 setsockopt(*plogfd, SOL_SOCKET, SO_RCVBUF, &zero, sizeof(zero));
277 /* does nothing under Linux, maybe needed for others */
278 shutdown(*plogfd, SHUT_RD);
Willy Tarreaubaaee002006-06-26 02:48:02 +0200279 }
280
Robert Tsai81ae1952007-12-05 10:47:29 +0100281 /* Send log messages to syslog server. */
282 for (nblogger = 0; nblogger < nbloggers; nblogger++) {
283 const struct logsrv *logsrv = logsrvs[nblogger];
284 int *plogfd = logsrv->u.addr.sa_family == AF_UNIX ?
285 &logfdunix : &logfdinet;
286 int sent;
287
Willy Tarreaubaaee002006-06-26 02:48:02 +0200288 /* we can filter the level of the messages that are sent to each logger */
Robert Tsai81ae1952007-12-05 10:47:29 +0100289 if (level > loglevel[nblogger])
Willy Tarreaubaaee002006-06-26 02:48:02 +0200290 continue;
291
292 /* For each target, we may have a different facility.
293 * We can also have a different log level for each message.
294 * This induces variations in the message header length.
295 * Since we don't want to recompute it each time, nor copy it every
296 * time, we only change the facility in the pre-computed header,
297 * and we change the pointer to the header accordingly.
298 */
Willy Tarreauf7edefa2009-05-10 17:20:05 +0200299 fac_level = (facilities[nblogger] << 3) + MAX(level, minlvl[nblogger]);
Willy Tarreaubaaee002006-06-26 02:48:02 +0200300 log_ptr = logmsg + 3; /* last digit of the log level */
301 do {
302 *log_ptr = '0' + fac_level % 10;
303 fac_level /= 10;
304 log_ptr--;
305 } while (fac_level && log_ptr > logmsg);
306 *log_ptr = '<';
307
308 /* the total syslog message now starts at logptr, for dataptr+data_len-logptr */
Robert Tsai81ae1952007-12-05 10:47:29 +0100309 sent = sendto(*plogfd, log_ptr, dataptr + data_len - log_ptr,
310 MSG_DONTWAIT | MSG_NOSIGNAL, &logsrv->u.addr, logsrv_addrlen(logsrv));
311 if (sent < 0) {
312 Alert("sendto logger #%d failed: %s (errno=%d)\n",
313 nblogger, strerror(errno), errno);
314 }
Willy Tarreaubaaee002006-06-26 02:48:02 +0200315 }
316}
317
318
319/*
320 * send a log for the session when we have enough info about it
321 */
Willy Tarreau42250582007-04-01 01:30:43 +0200322void tcp_sess_log(struct session *s)
Willy Tarreaubaaee002006-06-26 02:48:02 +0200323{
324 char pn[INET6_ADDRSTRLEN + strlen(":65535")];
Willy Tarreau73de9892006-11-30 11:40:23 +0100325 struct proxy *fe = s->fe;
Willy Tarreauddb358d2006-12-17 22:55:52 +0100326 struct proxy *be = s->be;
327 struct proxy *prx_log;
Willy Tarreauc9bd0cc2009-05-10 11:57:02 +0200328 int tolog, level, err;
Willy Tarreau42250582007-04-01 01:30:43 +0200329 char *svid;
Willy Tarreaufe944602007-10-25 10:34:16 +0200330 struct tm tm;
Willy Tarreaubaaee002006-06-26 02:48:02 +0200331
Willy Tarreauc9bd0cc2009-05-10 11:57:02 +0200332 /* if we don't want to log normal traffic, return now */
333 err = (s->flags & (SN_ERR_MASK | SN_REDISP)) || (s->conn_retries != be->conn_retries);
334 if (!err && (fe->options2 & PR_O2_NOLOGNORM))
335 return;
336
Willy Tarreaubaaee002006-06-26 02:48:02 +0200337 if (s->cli_addr.ss_family == AF_INET)
338 inet_ntop(AF_INET,
339 (const void *)&((struct sockaddr_in *)&s->cli_addr)->sin_addr,
340 pn, sizeof(pn));
341 else
342 inet_ntop(AF_INET6,
343 (const void *)&((struct sockaddr_in6 *)(&s->cli_addr))->sin6_addr,
344 pn, sizeof(pn));
345
Willy Tarreaufe944602007-10-25 10:34:16 +0200346 get_localtime(s->logs.tv_accept.tv_sec, &tm);
Willy Tarreauddb358d2006-12-17 22:55:52 +0100347
348 if (fe->logfac1 >= 0)
349 prx_log = fe;
Willy Tarreau97de6242006-12-27 17:18:38 +0100350 /*
351 * FIXME: should we fall back to the backend if the frontend did not
352 * define any log ? It seems like we should not permit such complex
353 * setups because they would induce a debugging nightmare for the
354 * admin.
355 */
356 // else if (be->logfac1 >= 0)
357 // prx_log = be;
Willy Tarreauddb358d2006-12-17 22:55:52 +0100358 else
359 prx_log = NULL; /* global */
360
Willy Tarreau42250582007-04-01 01:30:43 +0200361 /* FIXME: let's limit ourselves to frontend logging for now. */
362 tolog = fe->to_log;
363 svid = (tolog & LW_SVID) ? (s->srv != NULL) ? s->srv->id : "<NOSRV>" : "-";
Willy Tarreaubaaee002006-06-26 02:48:02 +0200364
Willy Tarreauc9bd0cc2009-05-10 11:57:02 +0200365 level = LOG_INFO;
366 if (err && (fe->options2 & PR_O2_LOGERRORS))
367 level = LOG_ERR;
368
369 send_log(prx_log, level, "%s:%d [%02d/%s/%04d:%02d:%02d:%02d.%03d]"
Willy Tarreau1772ece2009-04-03 14:49:12 +0200370 " %s %s/%s %ld/%ld/%s%ld %s%lld"
371 " %c%c %d/%d/%d/%d/%s%u %ld/%ld\n",
Willy Tarreau42250582007-04-01 01:30:43 +0200372 pn,
373 (s->cli_addr.ss_family == AF_INET) ?
374 ntohs(((struct sockaddr_in *)&s->cli_addr)->sin_port) :
375 ntohs(((struct sockaddr_in6 *)&s->cli_addr)->sin6_port),
Willy Tarreaufe944602007-10-25 10:34:16 +0200376 tm.tm_mday, monthname[tm.tm_mon], tm.tm_year+1900,
Willy Tarreau1772ece2009-04-03 14:49:12 +0200377 tm.tm_hour, tm.tm_min, tm.tm_sec, (int)s->logs.tv_accept.tv_usec/1000,
Willy Tarreau42250582007-04-01 01:30:43 +0200378 fe->id, be->id, svid,
379 (s->logs.t_queue >= 0) ? s->logs.t_queue : -1,
380 (s->logs.t_connect >= 0) ? s->logs.t_connect - s->logs.t_queue : -1,
381 (tolog & LW_BYTES) ? "" : "+", s->logs.t_close,
Willy Tarreau8b3977f2008-01-18 11:16:32 +0100382 (tolog & LW_BYTES) ? "" : "+", s->logs.bytes_out,
Willy Tarreau42250582007-04-01 01:30:43 +0200383 sess_term_cond[(s->flags & SN_ERR_MASK) >> SN_ERR_SHIFT],
384 sess_fin_state[(s->flags & SN_FINST_MASK) >> SN_FINST_SHIFT],
385 actconn, fe->feconn, be->beconn, s->srv ? s->srv->cur_sess : 0,
Krzysztof Piotr Oledzki25b501a2008-01-06 16:36:16 +0100386 (s->flags & SN_REDISP)?"+":"",
387 (s->conn_retries>0)?(be->conn_retries - s->conn_retries):be->conn_retries,
Willy Tarreau42250582007-04-01 01:30:43 +0200388 s->logs.srv_queue_size, s->logs.prx_queue_size);
Willy Tarreaubaaee002006-06-26 02:48:02 +0200389
390 s->logs.logwait = 0;
391}
392
Willy Tarreaubaaee002006-06-26 02:48:02 +0200393
394/*
395 * Local variables:
396 * c-indent-level: 8
397 * c-basic-offset: 8
398 * End:
399 */