varnish-cache/bin/varnishtest/vtc_syslog.c
1
/*-
2
 * Copyright (c) 2008-2010 Varnish Software AS
3
 * All rights reserved.
4
 *
5
 * Author: Frédéric Lécaille <flecaille@haproxy.com>
6
 *
7
 * Redistribution and use in source and binary forms, with or without
8
 * modification, are permitted provided that the following conditions
9
 * are met:
10
 * 1. Redistributions of source code must retain the above copyright
11
 *    notice, this list of conditions and the following disclaimer.
12
 * 2. Redistributions in binary form must reproduce the above copyright
13
 *    notice, this list of conditions and the following disclaimer in the
14
 *    documentation and/or other materials provided with the distribution.
15
 *
16
 * THIS SOFTWARE IS PROVIDED BY THE AUTHOR AND CONTRIBUTORS ``AS IS'' AND
17
 * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
18
 * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE
19
 * ARE DISCLAIMED.  IN NO EVENT SHALL AUTHOR OR CONTRIBUTORS BE LIABLE
20
 * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL
21
 * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS
22
 * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION)
23
 * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT
24
 * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY
25
 * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF
26
 * SUCH DAMAGE.
27
 */
28
29
#include "config.h"
30
31
#include <sys/types.h>
32
#include <sys/socket.h>
33
34
#include <stdio.h>
35
#include <stdlib.h>
36
#include <string.h>
37
#include <unistd.h>
38
39
#include "vtc.h"
40
41
#include "vsa.h"
42
#include "vss.h"
43
#include "vtcp.h"
44
#include "vre.h"
45
46
struct syslog_srv {
47
        unsigned                        magic;
48
#define SYSLOG_SRV_MAGIC                0xbf28a692
49
        char                            *name;
50
        struct vtclog                   *vl;
51
        VTAILQ_ENTRY(syslog_srv)        list;
52
        char                            run;
53
54
        int                             repeat;
55
        char                            *spec;
56
57
        int                             sock;
58
        char                            bind[256];
59
        int                             lvl;
60
61
        pthread_t                       tp;
62
        ssize_t                         rxbuf_left;
63
        size_t                          rxbuf_sz;
64
        char                            *rxbuf;
65
        vtim_dur                        timeout;
66
};
67
68
static pthread_mutex_t                  syslog_mtx;
69
70
static VTAILQ_HEAD(, syslog_srv)        syslogs =
71
    VTAILQ_HEAD_INITIALIZER(syslogs);
72
73
static const char * const syslog_levels[] = {
74
        "emerg",
75
        "alert",
76
        "crit",
77
        "err",
78
        "warning",
79
        "notice",
80
        "info",
81
        "debug",
82
        NULL,
83
};
84
85
static int
86 48
get_syslog_level(struct vtclog *vl, const char *lvl)
87
{
88
        int i;
89
90 312
        for (i = 0; syslog_levels[i]; i++)
91 312
                if (!strcmp(lvl, syslog_levels[i]))
92 48
                        return (i);
93 0
        vtc_fatal(vl, "wrong syslog level '%s'\n", lvl);
94
}
95
96
/*--------------------------------------------------------------------
97
 * Check if a UDP syscall return value is fatal
98
 * XXX: Largely copied from VTCP, not sure if really applicable
99
 */
100
101
static int
102 24
VUDP_Check(int a)
103
{
104 24
        if (a == 0)
105 24
                return (1);
106 0
        if (errno == ECONNRESET)
107 0
                return (1);
108
#if (defined (__SVR4) && defined (__sun)) || defined (__NetBSD__)
109
        /*
110
         * Solaris returns EINVAL if the other end unexpectedly reset the
111
         * connection.
112
         * This is a bug in Solaris and documented behaviour on NetBSD.
113
         */
114
        if (errno == EINVAL || errno == ETIMEDOUT || errno == EPIPE)
115
                return (1);
116
#elif defined (__APPLE__)
117
        /*
118
         * MacOS returns EINVAL if the other end unexpectedly reset
119
         * the connection.
120
         */
121
        if (errno == EINVAL)
122
                return (1);
123
#endif
124 0
        return (0);
125 24
}
126
127
/*--------------------------------------------------------------------
128
 * When closing a UDP connection, a couple of errno's are legit, we
129
 * can't be held responsible for the other end wanting to talk to us.
130
 */
131
132
static void
133 24
VUDP_close(int *s)
134
{
135
        int i;
136
137 24
        i = close(*s);
138
139 24
        assert(VUDP_Check(i));
140 24
        *s = -1;
141 24
}
142
143
/*--------------------------------------------------------------------
144
 * Given a struct suckaddr, open a socket of the appropriate type, and bind
145
 * it to the requested address.
146
 *
147
 * If the address is an IPv6 address, the IPV6_V6ONLY option is set to
148
 * avoid conflicts between INADDR_ANY and IN6ADDR_ANY.
149
 */
150
151
static int
152 24
VUDP_bind(const struct suckaddr *sa, const char **errp)
153
{
154
#ifdef IPV6_V6ONLY
155
        int val;
156
#endif
157
        int sd, e;
158
        socklen_t sl;
159
        const struct sockaddr *so;
160
        int proto;
161
162 24
        if (errp != NULL)
163 24
                *errp = NULL;
164
165 24
        proto = VSA_Get_Proto(sa);
166 24
        sd = socket(proto, SOCK_DGRAM, 0);
167 24
        if (sd < 0) {
168 0
                if (errp != NULL)
169 0
                        *errp = "socket(2)";
170 0
                return (-1);
171
        }
172
173
#ifdef IPV6_V6ONLY
174
        /* forcibly use separate sockets for IPv4 and IPv6 */
175
        val = 1;
176
        if (proto == AF_INET6 &&
177
            setsockopt(sd, IPPROTO_IPV6, IPV6_V6ONLY, &val, sizeof val) != 0) {
178
                if (errp != NULL)
179
                        *errp = "setsockopt(IPV6_V6ONLY, 1)";
180
                e = errno;
181
                closefd(&sd);
182
                errno = e;
183
                return (-1);
184
        }
185
#endif
186 24
        so = VSA_Get_Sockaddr(sa, &sl);
187 24
        if (bind(sd, so, sl) != 0) {
188 0
                if (errp != NULL)
189 0
                        *errp = "bind(2)";
190 0
                e = errno;
191 0
                closefd(&sd);
192 0
                errno = e;
193 0
                return (-1);
194
        }
195 24
        return (sd);
196 24
}
197
198
/*--------------------------------------------------------------------*/
199
200
struct udp_helper {
201
        const char      **errp;
202
};
203
204
static int v_matchproto_(vss_resolved_f)
205 24
vudp_lo_cb(void *priv, const struct suckaddr *sa)
206
{
207
        int sock;
208 24
        struct udp_helper *hp = priv;
209
210 24
        sock = VUDP_bind(sa, hp->errp);
211 24
        if (sock > 0) {
212 24
                *hp->errp = NULL;
213 24
                return (sock);
214
        }
215 0
        AN(*hp->errp);
216 0
        return (0);
217 24
}
218
219
static int
220 24
VUDP_bind_on(const char *addr, const char *def_port, const char **errp)
221
{
222
        struct udp_helper h;
223
        int sock;
224
225 24
        h.errp = errp;
226
227 24
        sock = VSS_resolver_socktype(
228 24
            addr, def_port, vudp_lo_cb, &h, errp, SOCK_DGRAM);
229 24
        if (*errp != NULL)
230 0
                return (-1);
231 24
        return (sock);
232 24
}
233
234
/**********************************************************************
235
 * Allocate and initialize a syslog
236
 */
237
238
static struct syslog_srv *
239 24
syslog_new(const char *name, struct vtclog *vl)
240
{
241
        struct syslog_srv *s;
242
243 24
        VTC_CHECK_NAME(vl, name, "Syslog", 'S');
244 24
        ALLOC_OBJ(s, SYSLOG_SRV_MAGIC);
245 24
        AN(s);
246 24
        REPLACE(s->name, name);
247 24
        s->vl = vtc_logopen(s->name);
248 24
        AN(s->vl);
249
250 24
        bprintf(s->bind, "%s", "127.0.0.1 0");
251 24
        s->repeat = 1;
252 24
        s->sock = -1;
253 24
        s->lvl = -1;
254 24
        s->timeout = vtc_maxdur * .5;           // XXX
255
256 24
        vl = vtc_logopen(s->name);
257 24
        AN(vl);
258
259 24
        s->rxbuf_sz = s->rxbuf_left = 2048*1024;
260 24
        s->rxbuf = malloc(s->rxbuf_sz);         /* XXX */
261 24
        AN(s->rxbuf);
262
263 24
        AZ(pthread_mutex_lock(&syslog_mtx));
264 24
        VTAILQ_INSERT_TAIL(&syslogs, s, list);
265 24
        AZ(pthread_mutex_unlock(&syslog_mtx));
266 24
        return (s);
267
}
268
269
/**********************************************************************
270
 * Clean up a syslog
271
 */
272
273
static void
274 24
syslog_delete(struct syslog_srv *s)
275
{
276
277 24
        CHECK_OBJ_NOTNULL(s, SYSLOG_SRV_MAGIC);
278 24
        macro_undef(s->vl, s->name, "addr");
279 24
        macro_undef(s->vl, s->name, "port");
280 24
        macro_undef(s->vl, s->name, "sock");
281 24
        vtc_logclose(s->vl);
282 24
        free(s->name);
283 24
        free(s->rxbuf);
284
        /* XXX: MEMLEAK (?) (VSS ??) */
285 24
        FREE_OBJ(s);
286 24
}
287
288
static void
289 72
syslog_rx(const struct syslog_srv *s, int lvl)
290
{
291
        ssize_t ret;
292
293 72
        while (!vtc_error) {
294
                /* Pointers to syslog priority value (see <PRIVAL>, rfc5424). */
295
                char *prib, *prie, *end;
296
                unsigned int prival;
297
298 72
                VTCP_set_read_timeout(s->sock, s->timeout);
299
300 72
                ret = recv(s->sock, s->rxbuf, s->rxbuf_sz - 1, 0);
301 72
                if (ret < 0) {
302 0
                        if (errno == EINTR || errno == EAGAIN)
303 0
                                continue;
304
305 0
                        vtc_fatal(s->vl,
306
                            "%s: recv failed (fd: %d read: %s", __func__,
307 0
                            s->sock, strerror(errno));
308
                }
309 72
                if (ret == 0)
310 0
                        vtc_fatal(s->vl,
311
                            "syslog rx timeout (fd: %d %.3fs ret: %zd)",
312 0
                            s->sock, s->timeout, ret);
313
314 72
                s->rxbuf[ret] = '\0';
315 72
                vtc_dump(s->vl, 4, "syslog", s->rxbuf, ret);
316
317 72
                prib = s->rxbuf;
318 72
                if (*prib++ != '<')
319 0
                        vtc_fatal(s->vl, "syslog PRI, no '<'");
320 72
                prie = strchr(prib, '>');
321 72
                if (prie == NULL)
322 0
                        vtc_fatal(s->vl, "syslog PRI, no '>'");
323
324 72
                prival = strtoul(prib, &end, 10);
325 72
                if (end != prie)
326 0
                        vtc_fatal(s->vl, "syslog PRI, bad number");
327
328 72
                if (lvl >= 0 && lvl == (prival & 0x7))
329 72
                        return;
330
        }
331 72
}
332
333
/**********************************************************************
334
 * Syslog server bind
335
 */
336
337
static void
338 24
syslog_bind(struct syslog_srv *s)
339
{
340
        const char *err;
341
        char aaddr[VTCP_ADDRBUFSIZE];
342
        char aport[VTCP_PORTBUFSIZE];
343
344 24
        CHECK_OBJ_NOTNULL(s, SYSLOG_SRV_MAGIC);
345
346 24
        if (s->sock >= 0)
347 0
                VUDP_close(&s->sock);
348 24
        s->sock = VUDP_bind_on(s->bind, "0", &err);
349 24
        if (err != NULL)
350 0
                vtc_fatal(s->vl,
351
                    "Syslog server bind address (%s) cannot be resolved: %s",
352 0
                    s->bind, err);
353 24
        assert(s->sock > 0);
354 24
        VTCP_myname(s->sock, aaddr, sizeof aaddr, aport, sizeof aport);
355 24
        macro_def(s->vl, s->name, "addr", "%s", aaddr);
356 24
        macro_def(s->vl, s->name, "port", "%s", aport);
357 24
        macro_def(s->vl, s->name, "sock", "%s %s", aaddr, aport);
358
        /* Record the actual port, and reuse it on subsequent starts */
359 24
        bprintf(s->bind, "%s %s", aaddr, aport);
360 24
}
361
362
static void v_matchproto_(cmd_f)
363 24
cmd_syslog_expect(CMD_ARGS)
364
{
365
        struct syslog_srv *s;
366
        vre_t *vre;
367
        const char *error;
368
        int erroroffset, i, ret;
369
        char *cmp, *spec;
370
371 24
        (void)vl;
372 24
        (void)cmd;
373 24
        CAST_OBJ_NOTNULL(s, priv, SYSLOG_SRV_MAGIC);
374 24
        AZ(strcmp(av[0], "expect"));
375 24
        av++;
376
377 24
        cmp = av[0];
378 24
        spec = av[1];
379 24
        AN(cmp);
380 24
        AN(spec);
381 24
        AZ(av[2]);
382
383 24
        assert(!strcmp(cmp, "~") || !strcmp(cmp, "!~"));
384
385 24
        vre = VRE_compile(spec, 0, &error, &erroroffset);
386 24
        if (!vre)
387 0
                vtc_fatal(s->vl, "REGEXP error: '%s' (@%d) (%s)",
388 0
                    error, erroroffset, spec);
389
390 24
        i = VRE_exec(vre, s->rxbuf, strlen(s->rxbuf), 0, 0, NULL, 0, 0);
391
392 24
        VRE_free(&vre);
393
394 24
        ret = (i >= 0 && *cmp == '~') || (i < 0 && *cmp == '!');
395 24
        if (!ret)
396 0
                vtc_fatal(s->vl, "EXPECT FAILED %s \"%s\"", cmp, spec);
397
        else
398 24
                vtc_log(s->vl, 4, "EXPECT MATCH %s \"%s\"", cmp, spec);
399 24
}
400
401
static void v_matchproto_(cmd_f)
402 72
cmd_syslog_recv(CMD_ARGS)
403
{
404
        int lvl;
405
        struct syslog_srv *s;
406
407 72
        CAST_OBJ_NOTNULL(s, priv, SYSLOG_SRV_MAGIC);
408 72
        (void)cmd;
409 72
        (void)vl;
410 72
        AZ(strcmp(av[0], "recv"));
411 72
        av++;
412 72
        if (av[0] == NULL)
413 48
                lvl = s->lvl;
414
        else
415 24
                lvl = get_syslog_level(vl, av[0]);
416
417 72
        syslog_rx(s, lvl);
418 72
}
419
420
static const struct cmds syslog_cmds[] = {
421
#define CMD_SYSLOG(n) { #n, cmd_syslog_##n },
422
        /* session */
423
        CMD_SYSLOG(expect)
424
        CMD_SYSLOG(recv)
425
#undef CMD_SYSLOG
426
        { NULL, NULL }
427
};
428
429
/**********************************************************************
430
 * Syslog server thread
431
 */
432
433
static void *
434 24
syslog_thread(void *priv)
435
{
436
        struct syslog_srv *s;
437
        int i;
438
439 24
        CAST_OBJ_NOTNULL(s, priv, SYSLOG_SRV_MAGIC);
440 24
        assert(s->sock >= 0);
441
442 24
        vtc_log(s->vl, 2, "Started on %s (level: %d)", s->bind, s->lvl);
443 48
        for (i = 0; i < s->repeat; i++) {
444 24
                if (s->repeat > 1)
445 0
                        vtc_log(s->vl, 3, "Iteration %d", i);
446 24
                parse_string(s->spec, syslog_cmds, s, s->vl);
447 24
                vtc_log(s->vl, 3, "shutting fd %d", s->sock);
448 24
        }
449 24
        VUDP_close(&s->sock);
450 24
        vtc_log(s->vl, 2, "Ending");
451 24
        return (NULL);
452
}
453
454
/**********************************************************************
455
 * Start the syslog thread
456
 */
457
458
static void
459 24
syslog_start(struct syslog_srv *s)
460
{
461 24
        CHECK_OBJ_NOTNULL(s, SYSLOG_SRV_MAGIC);
462 24
        vtc_log(s->vl, 2, "Starting syslog server");
463 24
        if (s->sock == -1)
464 0
                syslog_bind(s);
465 24
        vtc_log(s->vl, 1, "Bound on %s", s->bind);
466 24
        s->run = 1;
467 24
        AZ(pthread_create(&s->tp, NULL, syslog_thread, s));
468 24
}
469
470
/**********************************************************************
471
 * Force stop the syslog thread
472
 */
473
474
static void
475 0
syslog_stop(struct syslog_srv *s)
476
{
477
        void *res;
478
479 0
        CHECK_OBJ_NOTNULL(s, SYSLOG_SRV_MAGIC);
480 0
        vtc_log(s->vl, 2, "Stopping for syslog server");
481 0
        (void)pthread_cancel(s->tp);
482 0
        AZ(pthread_join(s->tp, &res));
483 0
        s->tp = 0;
484 0
        s->run = 0;
485 0
}
486
487
/**********************************************************************
488
 * Wait for syslog thread to stop
489
 */
490
491
static void
492 24
syslog_wait(struct syslog_srv *s)
493
{
494
        void *res;
495
496 24
        CHECK_OBJ_NOTNULL(s, SYSLOG_SRV_MAGIC);
497 24
        vtc_log(s->vl, 2, "Waiting for syslog server (%d)", s->sock);
498 24
        AZ(pthread_join(s->tp, &res));
499 24
        if (res != NULL && !vtc_stop)
500 0
                vtc_fatal(s->vl, "Syslog server returned \"%p\"",
501 0
                    (char *)res);
502 24
        s->tp = 0;
503 24
        s->run = 0;
504 24
}
505
506
/* SECTION: syslog syslog
507
 *
508
 * Define and interact with syslog instances (for use with haproxy)
509
 *
510
 * To define a syslog server, you'll use this syntax::
511
 *
512
 *     syslog SNAME
513
 *
514
 * Arguments:
515
 *
516
 * SNAME
517
 *     Identify the syslog server with a string which must start with 'S'.
518
 *
519
 * \-level STRING
520
 *         Set the default syslog priority level used by any subsequent "recv"
521
 *         command.
522
 *         Any syslog dgram with a different level will be skipped by
523
 *         "recv" command. This default level value may be superseded
524
 *         by "recv" command if supplied as first argument: "recv <level>".
525
 *
526
 * \-start
527
 *         Start the syslog server thread in the background.
528
 *
529
 * \-repeat
530
 *         Instead of processing the specification only once, do it
531
 *         NUMBER times.
532
 *
533
 * \-bind
534
 *         Bind the syslog socket to a local address.
535
 *
536
 * \-wait
537
 *         Wait for that thread to terminate.
538
 *
539
 * \-stop
540
 *         Stop the syslog server thread.
541
 */
542
543
void v_matchproto_(cmd_f)
544 19248
cmd_syslog(CMD_ARGS)
545
{
546
        struct syslog_srv *s;
547
548 19248
        (void)priv;
549 19248
        (void)cmd;
550
551 19248
        if (av == NULL) {
552
                /* Reset and free */
553 19200
                do {
554 19224
                        AZ(pthread_mutex_lock(&syslog_mtx));
555 19224
                        s = VTAILQ_FIRST(&syslogs);
556 19224
                        CHECK_OBJ_ORNULL(s, SYSLOG_SRV_MAGIC);
557 19224
                        if (s != NULL)
558 24
                                VTAILQ_REMOVE(&syslogs, s, list);
559 19224
                        AZ(pthread_mutex_unlock(&syslog_mtx));
560 19224
                        if (s != NULL) {
561 24
                                if (s->run) {
562 0
                                        (void)pthread_cancel(s->tp);
563 0
                                        syslog_wait(s);
564 0
                                }
565 24
                                if (s->sock >= 0)
566 0
                                        VUDP_close(&s->sock);
567 24
                                syslog_delete(s);
568 24
                        }
569 19224
                } while (s != NULL);
570 19200
                return;
571
        }
572
573 48
        AZ(strcmp(av[0], "syslog"));
574 48
        av++;
575
576 48
        AZ(pthread_mutex_lock(&syslog_mtx));
577 48
        VTAILQ_FOREACH(s, &syslogs, list)
578 24
                if (!strcmp(s->name, av[0]))
579 24
                        break;
580 48
        AZ(pthread_mutex_unlock(&syslog_mtx));
581 48
        if (s == NULL)
582 24
                s = syslog_new(av[0], vl);
583 48
        CHECK_OBJ_NOTNULL(s, SYSLOG_SRV_MAGIC);
584 48
        av++;
585
586 168
        for (; *av != NULL; av++) {
587 120
                if (vtc_error)
588 0
                        break;
589 120
                if (!strcmp(*av, "-wait")) {
590 24
                        if (!s->run)
591 0
                                vtc_fatal(s->vl, "Syslog server not -started");
592 24
                        syslog_wait(s);
593 24
                        continue;
594
                }
595
596 96
                if (!strcmp(*av, "-stop")) {
597 0
                        syslog_stop(s);
598 0
                        continue;
599
                }
600
601
                /*
602
                 * We do an implict -wait if people muck about with a
603
                 * running syslog.
604
                 * This only works if the previous ->spec has completed
605
                 */
606 96
                if (s->run)
607 0
                        syslog_wait(s);
608
609 96
                AZ(s->run);
610 96
                if (!strcmp(*av, "-repeat")) {
611 0
                        AN(av[1]);
612 0
                        s->repeat = atoi(av[1]);
613 0
                        av++;
614 0
                        continue;
615
                }
616 96
                if (!strcmp(*av, "-bind")) {
617 24
                        AN(av[1]);
618 24
                        bprintf(s->bind, "%s", av[1]);
619 24
                        av++;
620 24
                        syslog_bind(s);
621 24
                        continue;
622
                }
623 72
                if (!strcmp(*av, "-level")) {
624 24
                        AN(av[1]);
625 24
                        s->lvl = get_syslog_level(vl, av[1]);
626 24
                        av++;
627 24
                        continue;
628
                }
629 48
                if (!strcmp(*av, "-start")) {
630 24
                        syslog_start(s);
631 24
                        continue;
632
                }
633 24
                if (**av == '-')
634 0
                        vtc_fatal(s->vl, "Unknown syslog argument: %s", *av);
635 24
                s->spec = *av;
636 24
        }
637 19248
}
638
639
void
640 19200
init_syslog(void)
641
{
642 19200
        AZ(pthread_mutex_init(&syslog_mtx, NULL));
643 19200
}