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 5345
vtc_logopen(const char *id)
80
{
81
        struct vtclog *vl;
82
83 5345
        ALLOC_OBJ(vl, VTCLOG_MAGIC);
84 5345
        AN(vl);
85 5345
        vl->id = id;
86 5345
        vl->vsb = VSB_new_auto();
87 5345
        AZ(pthread_mutex_init(&vl->mtx, NULL));
88 5345
        AZ(pthread_setspecific(log_key, vl));
89 5345
        return (vl);
90
}
91
92
void
93 4581
vtc_logclose(void *arg)
94
{
95 4581
        struct vtclog *vl = arg;
96
97 4581
        CHECK_OBJ_NOTNULL(vl, VTCLOG_MAGIC);
98 4581
        if (pthread_getspecific(log_key) == vl)
99 2884
                AZ(pthread_setspecific(log_key, NULL));
100 4581
        VSB_destroy(&vl->vsb);
101 4581
        AZ(pthread_mutex_destroy(&vl->mtx));
102 4581
        FREE_OBJ(vl);
103 4581
}
104
105
static void v_noreturn_
106 2
vtc_logfail(void)
107
{
108
109 2
        vtc_error = 2;
110 2
        if (pthread_self() != vtc_thread)
111 0
                pthread_exit(NULL);
112
        else
113 2
                exit(fail_out());
114
}
115
116
static const char * const lead[] = {
117
        "----",
118
        "*   ",
119
        "**  ",
120
        "*** ",
121
        "****"
122
};
123
124
#define NLEAD (sizeof(lead)/sizeof(lead[0]))
125
126
static void
127 293851
vtc_leadinv(const struct vtclog *vl, int lvl, const char *fmt, va_list ap)
128
{
129
130 293851
        assert(lvl < (int)NLEAD);
131 293851
        assert(lvl >= 0);
132 587702
        VSB_printf(vl->vsb, "%s %-4s %4.1f ",
133 293851
            lead[lvl < 0 ? 1: lvl], vl->id, vl->tx);
134 293859
        if (fmt != NULL)
135 293859
                (void)VSB_vprintf(vl->vsb, fmt, ap);
136 293853
}
137
138
static void
139 542
vtc_leadin(const struct vtclog *vl, int lvl, const char *fmt, ...)
140
{
141
        va_list ap;
142
143 542
        va_start(ap, fmt);
144 542
        vtc_leadinv(vl, lvl, fmt, ap);
145 542
        va_end(ap);
146 542
}
147
148
static void
149 371957
vtc_log_emit(const struct vtclog *vl)
150
{
151
        int l;
152
153 371957
        l = VSB_len(vl->vsb);
154 371963
        if (l == 0)
155 3533
                return;
156 368430
        AZ(pthread_mutex_lock(&vtclog_mtx));
157 368478
        assert(vtclog_left > l);
158 368478
        memcpy(vtclog_buf,VSB_data(vl->vsb), l);
159 368478
        vtclog_buf += l;
160 368478
        *vtclog_buf = '\0';
161 368478
        vtclog_left -= l;
162 368478
        AZ(pthread_mutex_unlock(&vtclog_mtx));
163
}
164
165
void
166 2
vtc_fatal(struct vtclog *vl, const char *fmt, ...)
167
{
168
169 2
        GET_VL(vl);
170
        va_list ap;
171 2
        va_start(ap, fmt);
172 2
        vtc_leadinv(vl, 0, fmt, ap);
173 2
        VSB_putc(vl->vsb, '\n');
174 2
        va_end(ap);
175 2
        REL_VL(vl);
176
177 2
        vtc_logfail();
178
}
179
180
void
181 293302
vtc_log(struct vtclog *vl, int lvl, const char *fmt, ...)
182
{
183
184 293302
        GET_VL(vl);
185
        va_list ap;
186 293311
        va_start(ap, fmt);
187 293311
        if (lvl >= 0) {
188 293304
                vtc_leadinv(vl, lvl, fmt, ap);
189 293307
                VSB_putc(vl->vsb, '\n');
190
        }
191 293310
        va_end(ap);
192 293310
        REL_VL(vl);
193
194 293323
        if (lvl == 0)
195 0
                vtc_logfail();
196 293323
}
197
198
/**********************************************************************
199
 * Dump a string
200
 */
201
202
#define MAX_DUMP 8192
203
204
void
205 78353
vtc_dump(struct vtclog *vl, int lvl, const char *pfx, const char *str, int len)
206
{
207
        char buf[64];
208
209 78353
        AN(pfx);
210 78353
        GET_VL(vl);
211 78350
        if (str == NULL)
212 1
                vtc_leadin(vl, lvl, "%s(null)\n", pfx);
213
        else {
214 78349
                bprintf(buf, "%s %-4s %4.1f %s|",
215
                    lead[lvl < 0 ? 1: lvl], vl->id, vl->tx, pfx);
216 78357
                if (len < 0)
217 68119
                        len = strlen(str);
218 78357
                VSB_quote_pfx(vl->vsb, buf, str,
219
                    len > MAX_DUMP ? MAX_DUMP : len, VSB_QUOTE_UNSAFE);
220 78355
                if (len > MAX_DUMP)
221 96
                        VSB_printf(vl->vsb, "%s [...] (%d)\n",
222
                            buf, len - MAX_DUMP);
223
        }
224 78356
        REL_VL(vl);
225 78358
        if (lvl == 0)
226 0
                vtc_logfail();
227 78358
}
228
229
/**********************************************************************
230
 * Hexdump
231
 */
232
233
void
234 328
vtc_hexdump(struct vtclog *vl, int lvl, const char *pfx,
235
    const void *ptr, int len)
236
{
237 328
        int nl = 1;
238
        unsigned l;
239 328
        const uint8_t *ss = ptr;
240
241 328
        AN(pfx);
242 328
        GET_VL(vl);
243 328
        if (ss == NULL)
244 0
                vtc_leadin(vl, lvl, "%s(null)\n", pfx);
245
        else {
246 5466
                for (l = 0; l < len; l++, ss++) {
247 5141
                        if (l > 512) {
248 3
                                VSB_printf(vl->vsb, "...");
249 3
                                break;
250
                        }
251 5138
                        if (nl) {
252 541
                                vtc_leadin(vl, lvl, "%s| ", pfx);
253 541
                                nl = 0;
254
                        }
255 5138
                        VSB_printf(vl->vsb, " %02x", *ss);
256 5138
                        if ((l & 0xf) == 0xf) {
257 255
                                VSB_printf(vl->vsb, "\n");
258 255
                                nl = 1;
259
                        }
260
                }
261
        }
262 328
        if (!nl)
263 286
                VSB_printf(vl->vsb, "\n");
264 328
        REL_VL(vl);
265 328
        if (lvl == 0)
266 0
                vtc_logfail();
267 328
}
268
269
/**********************************************************************/
270
271
static void v_noreturn_
272 0
vtc_log_VAS_Fail(const char *func, const char *file, int line,
273
    const char *cond, enum vas_e why)
274
{
275
        struct vtclog *vl;
276
277
        (void)why;
278 0
        vl = pthread_getspecific(log_key);
279 0
        if (vl == NULL || vl->act) {
280 0
                fprintf(stderr,
281
                    "Assert error in %s(), %s line %d:\n"
282
                    "  Condition(%s) not true.\n",
283
                    func, file, line, cond);
284
        } else
285 0
                vtc_fatal(vl, "Assert error in %s(), %s line %d:"
286
                    "  Condition(%s) not true.\n", func, file, line, cond);
287 0
        abort();
288
}
289
290
/**********************************************************************/
291
292
void
293 763
vtc_loginit(char *buf, unsigned buflen)
294
{
295
296 763
        VAS_Fail_Func = vtc_log_VAS_Fail;
297 763
        t0 = VTIM_mono();
298 763
        vtclog_buf = buf;
299 763
        vtclog_left = buflen;
300 763
        AZ(pthread_mutex_init(&vtclog_mtx, NULL));
301 763
        AZ(pthread_key_create(&log_key, NULL));
302 763
}
303