varnish-cache/bin/varnishtest/vtc_log.c
1
/*-
2
 * Copyright (c) 2008-2011 Varnish Software AS
3
 * All rights reserved.
4
 *
5
 * Author: Poul-Henning Kamp <phk@phk.freebsd.dk>
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 <stdarg.h>
32
#include <stdio.h>
33
#include <stdlib.h>
34
#include <string.h>
35
36
#include "vtc.h"
37
38
#include "vtim.h"
39
40
static pthread_mutex_t  vtclog_mtx;
41
static char             *vtclog_buf;
42
static unsigned         vtclog_left;
43
44
struct vtclog {
45
        unsigned        magic;
46
#define VTCLOG_MAGIC    0x82731202
47
        const char      *id;
48
        struct vsb      *vsb;
49
        pthread_mutex_t mtx;
50
        int             act;
51
        double          tx;
52
};
53
54
static pthread_key_t log_key;
55
static double t0;
56
57
/**********************************************************************/
58
59
#define GET_VL(vl)                                      \
60
        do {                                            \
61
                CHECK_OBJ_NOTNULL(vl, VTCLOG_MAGIC);    \
62
                vl->tx = VTIM_mono() - t0;              \
63
                AZ(pthread_mutex_lock(&vl->mtx));       \
64
                vl->act = 1;                            \
65
                VSB_clear(vl->vsb);                     \
66
        } while(0)
67
68
#define REL_VL(vl)                                      \
69
        do {                                            \
70
                AZ(VSB_finish(vl->vsb));                \
71
                vtc_log_emit(vl);                       \
72
                VSB_clear(vl->vsb);                     \
73
                vl->act = 0;                            \
74
                AZ(pthread_mutex_unlock(&vl->mtx));     \
75
        } while(0)
76
77
78
struct vtclog *
79 4586
vtc_logopen(const char *id)
80
{
81
        struct vtclog *vl;
82
83 4586
        ALLOC_OBJ(vl, VTCLOG_MAGIC);
84 4586
        AN(vl);
85 4586
        vl->id = id;
86 4586
        vl->vsb = VSB_new_auto();
87 4586
        AZ(pthread_mutex_init(&vl->mtx, NULL));
88 4586
        AZ(pthread_setspecific(log_key, vl));
89 4586
        return (vl);
90
}
91
92
void
93 1990
vtc_logclose(struct vtclog *vl)
94
{
95
96 1990
        CHECK_OBJ_NOTNULL(vl, VTCLOG_MAGIC);
97 1990
        if (pthread_getspecific(log_key) == vl)
98 637
                AZ(pthread_setspecific(log_key, NULL));
99 1990
        VSB_destroy(&vl->vsb);
100 1990
        AZ(pthread_mutex_destroy(&vl->mtx));
101 1990
        FREE_OBJ(vl);
102 1990
}
103
104
static void v_noreturn_
105 2
vtc_logfail(void)
106
{
107
108 2
        vtc_error = 2;
109 2
        if (pthread_self() != vtc_thread)
110 0
                pthread_exit(NULL);
111
        else
112 2
                exit(fail_out());
113
}
114
115
static const char * const lead[] = {
116
        "----",
117
        "*   ",
118
        "**  ",
119
        "*** ",
120
        "****"
121
};
122
123
#define NLEAD (sizeof(lead)/sizeof(lead[0]))
124
125
static void
126 249784
vtc_leadinv(const struct vtclog *vl, int lvl, const char *fmt, va_list ap)
127
{
128
129 249784
        assert(lvl < (int)NLEAD);
130 249784
        assert(lvl >= 0);
131 499568
        VSB_printf(vl->vsb, "%s %-4s %4.1f ",
132 249784
            lead[lvl < 0 ? 1: lvl], vl->id, vl->tx);
133 249799
        if (fmt != NULL)
134 249799
                (void)VSB_vprintf(vl->vsb, fmt, ap);
135 249794
}
136
137
static void
138 203
vtc_leadin(const struct vtclog *vl, int lvl, const char *fmt, ...)
139
{
140
        va_list ap;
141
142 203
        va_start(ap, fmt);
143 203
        vtc_leadinv(vl, lvl, fmt, ap);
144 203
        va_end(ap);
145 203
}
146
147
static void
148 311223
vtc_log_emit(const struct vtclog *vl)
149
{
150
        int l;
151
152 311223
        l = VSB_len(vl->vsb);
153 311224
        if (l == 0)
154 314251
                return;
155 308230
        AZ(pthread_mutex_lock(&vtclog_mtx));
156 308263
        assert(vtclog_left > l);
157 308263
        memcpy(vtclog_buf,VSB_data(vl->vsb), l);
158 308263
        vtclog_buf += l;
159 308263
        *vtclog_buf = '\0';
160 308263
        vtclog_left -= l;
161 308263
        AZ(pthread_mutex_unlock(&vtclog_mtx));
162
}
163
164
void
165 2
vtc_fatal(struct vtclog *vl, const char *fmt, ...)
166
{
167
168 2
        GET_VL(vl);
169
        va_list ap;
170 2
        va_start(ap, fmt);
171 2
        vtc_leadinv(vl, 0, fmt, ap);
172 2
        VSB_putc(vl->vsb, '\n');
173 2
        va_end(ap);
174 2
        REL_VL(vl);
175
176 2
        vtc_logfail();
177
}
178
179
void
180 249589
vtc_log(struct vtclog *vl, int lvl, const char *fmt, ...)
181
{
182
183 249589
        GET_VL(vl);
184
        va_list ap;
185 249586
        va_start(ap, fmt);
186 249586
        if (lvl >= 0) {
187 249582
                vtc_leadinv(vl, lvl, fmt, ap);
188 249587
                VSB_putc(vl->vsb, '\n');
189
        }
190 249589
        va_end(ap);
191 249589
        REL_VL(vl);
192
193 249602
        if (lvl == 0)
194 0
                vtc_logfail();
195 249602
}
196
197
/**********************************************************************
198
 * Dump a string
199
 */
200
201
#define MAX_DUMP 8192
202
203
void
204 61485
vtc_dump(struct vtclog *vl, int lvl, const char *pfx, const char *str, int len)
205
{
206
        char buf[64];
207
208 61485
        AN(pfx);
209 61485
        GET_VL(vl);
210 61482
        if (str == NULL)
211 0
                vtc_leadin(vl, lvl, "%s(null)\n", pfx);
212
        else {
213 61482
                bprintf(buf, "%s %-4s %4.1f %s|",
214
                    lead[lvl < 0 ? 1: lvl], vl->id, vl->tx, pfx);
215 61488
                if (len < 0)
216 55642
                        len = strlen(str);
217 61488
                VSB_quote_pfx(vl->vsb, buf, str,
218
                    len > MAX_DUMP ? MAX_DUMP : len, VSB_QUOTE_UNSAFE);
219 61483
                if (len > MAX_DUMP)
220 89
                        VSB_printf(vl->vsb, "%s [...] (%d)\n",
221
                            buf, len - MAX_DUMP);
222
        }
223 61483
        REL_VL(vl);
224 61488
        if (lvl == 0)
225 0
                vtc_logfail();
226 61488
}
227
228
/**********************************************************************
229
 * Hexdump
230
 */
231
232
void
233 165
vtc_hexdump(struct vtclog *vl, int lvl, const char *pfx,
234
    const void *ptr, int len)
235
{
236 165
        int nl = 1;
237
        unsigned l;
238 165
        const uint8_t *ss = ptr;
239
240 165
        AN(pfx);
241 165
        GET_VL(vl);
242 165
        if (ss == NULL)
243 0
                vtc_leadin(vl, lvl, "%s(null)\n", pfx);
244
        else {
245 1932
                for (l = 0; l < len; l++, ss++) {
246 1768
                        if (l > 512) {
247 1
                                VSB_printf(vl->vsb, "...");
248 1
                                break;
249
                        }
250 1767
                        if (nl) {
251 203
                                vtc_leadin(vl, lvl, "%s| ", pfx);
252 203
                                nl = 0;
253
                        }
254 1767
                        VSB_printf(vl->vsb, " %02x", *ss);
255 1767
                        if ((l & 0xf) == 0xf) {
256 79
                                VSB_printf(vl->vsb, "\n");
257 79
                                nl = 1;
258
                        }
259
                }
260
        }
261 165
        if (!nl)
262 124
                VSB_printf(vl->vsb, "\n");
263 165
        REL_VL(vl);
264 165
        if (lvl == 0)
265 0
                vtc_logfail();
266 165
}
267
268
/**********************************************************************/
269
270
static void v_noreturn_
271 0
vtc_log_VAS_Fail(const char *func, const char *file, int line,
272
    const char *cond, enum vas_e why)
273
{
274
        struct vtclog *vl;
275
276
        (void)why;
277 0
        vl = pthread_getspecific(log_key);
278 0
        if (vl == NULL || vl->act) {
279 0
                fprintf(stderr,
280
                    "Assert error in %s(), %s line %d:\n"
281
                    "  Condition(%s) not true.\n",
282
                    func, file, line, cond);
283
        } else
284 0
                vtc_fatal(vl, "Assert error in %s(), %s line %d:"
285
                    "  Condition(%s) not true.\n", func, file, line, cond);
286 0
        abort();
287
}
288
289
/**********************************************************************/
290
291
void
292 678
vtc_loginit(char *buf, unsigned buflen)
293
{
294
295 678
        VAS_Fail_Func = vtc_log_VAS_Fail;
296 678
        t0 = VTIM_mono();
297 678
        vtclog_buf = buf;
298 678
        vtclog_left = buflen;
299 678
        AZ(pthread_mutex_init(&vtclog_mtx, NULL));
300 678
        AZ(pthread_key_create(&log_key, NULL));
301 678
}
302