GCOV - Varnish Cache


/*-
 * Copyright (c) 2008-2011 Varnish Software AS
 * All rights reserved.
 *
 * Author: Poul-Henning Kamp <phk@phk.freebsd.dk>
 *
 * SPDX-License-Identifier: BSD-2-Clause
 *
 * Redistribution and use in source and binary forms, with or without
 * modification, are permitted provided that the following conditions
 * are met:
 * 1. Redistributions of source code must retain the above copyright
 *    notice, this list of conditions and the following disclaimer.
 * 2. Redistributions in binary form must reproduce the above copyright
 *    notice, this list of conditions and the following disclaimer in the
 *    documentation and/or other materials provided with the distribution.
 *
 * THIS SOFTWARE IS PROVIDED BY THE AUTHOR AND CONTRIBUTORS ``AS IS'' AND
 * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
 * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE
 * ARE DISCLAIMED.  IN NO EVENT SHALL AUTHOR OR CONTRIBUTORS BE LIABLE
 * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL
 * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS
 * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION)
 * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT
 * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY
 * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF
 * SUCH DAMAGE.
 */

#include "config.h"

#include <math.h>
#include <stdarg.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>

#include "vtc.h"
#include "vtc_log.h"

#include "vtim.h"
#include "vbt.h"

static pthread_mutex_t  vtclog_mtx;
static char             *vtclog_buf;
static unsigned         vtclog_left;

static pthread_key_t log_key;
static double t0;

void
vtc_log_set_cmd(struct vtclog *vl, const struct cmds *cmds)
{
        AN(cmds);
        vl->cmds = cmds;
}

/**********************************************************************/

#define GET_VL(vl)                                      \
        do {                                            \
                CHECK_OBJ_NOTNULL(vl, VTCLOG_MAGIC);    \
                PTOK(pthread_mutex_lock(&vl->mtx));     \
                vl->act = 1;                            \
                VSB_clear(vl->vsb);                     \
        } while(0)

#define REL_VL(vl)                                      \
        do {                                            \
                AZ(VSB_finish(vl->vsb));                \
                vtc_log_emit(vl);                       \
                VSB_clear(vl->vsb);                     \
                vl->act = 0;                            \
                PTOK(pthread_mutex_unlock(&vl->mtx));   \
        } while(0)


struct vtclog *
vtc_logopen(const char *fmt, ...)
{
        struct vtclog *vl;
        va_list ap;
        char buf[BUFSIZ];

        va_start(ap, fmt);
        vbprintf(buf, fmt, ap);
        va_end(ap);

        ALLOC_OBJ(vl, VTCLOG_MAGIC);
        AN(vl);
        REPLACE(vl->id, buf);
        vl->vsb = VSB_new_auto();
        PTOK(pthread_mutex_init(&vl->mtx, NULL));
        PTOK(pthread_setspecific(log_key, vl));
        return (vl);
}

void
vtc_logclose(void *arg)
{
        struct vtclog *vl;

        CAST_OBJ_NOTNULL(vl, arg, VTCLOG_MAGIC);
        if (pthread_getspecific(log_key) == vl)
                PTOK(pthread_setspecific(log_key, NULL));
        VSB_destroy(&vl->vsb);
        PTOK(pthread_mutex_destroy(&vl->mtx));
        REPLACE(vl->id, NULL);
        FREE_OBJ(vl);
}

static void v_noreturn_
vtc_logfail(void)
{

        vtc_error = 2;
        if (!pthread_equal(pthread_self(), vtc_thread))
                pthread_exit(NULL);
        else
                exit(fail_out());

        WRONG("unreachable"); /*lint !e827 Help Coverity Scan see noreturn. */
}

static const char * const lead[] = {
        "----",
        "*   ",
        "**  ",
        "*** ",
        "****"
};

#define NLEAD (sizeof(lead)/sizeof(lead[0]))

static void
vtc_leadinv(const struct vtclog *vl, int lvl, const char *fmt, va_list ap)
{

        assert(lvl < (int)NLEAD);
        assert(lvl >= 0);
        VSB_printf(vl->vsb, "%s %-5s ",
            lead[lvl < 0 ? 1: lvl], vl->id);
        if (fmt != NULL)
                (void)VSB_vprintf(vl->vsb, fmt, ap);
}

static void
vtc_leadin(const struct vtclog *vl, int lvl, const char *fmt, ...)
{
        va_list ap;

        va_start(ap, fmt);
        vtc_leadinv(vl, lvl, fmt, ap);
        va_end(ap);
}

static void
vtc_log_emit(const struct vtclog *vl)
{
        unsigned l;
        int i;
        int t_this;
        static int t_last = -1;

        l = VSB_len(vl->vsb);
        if (l == 0)
                return;
        t_this = (int)round((VTIM_mono() - t0) * 1000);
        PTOK(pthread_mutex_lock(&vtclog_mtx));
        if (t_last != t_this) {
                assert(vtclog_left > 25);
                i = snprintf(vtclog_buf, vtclog_left,
                    "**** dT    %d.%03d\n", t_this / 1000, t_this % 1000);
                t_last = t_this;
                vtclog_buf += i;
                vtclog_left -= i;
        }
        assert(vtclog_left > l);
        memcpy(vtclog_buf, VSB_data(vl->vsb), l);
        vtclog_buf += l;
        *vtclog_buf = '\0';
        vtclog_left -= l;
        PTOK(pthread_mutex_unlock(&vtclog_mtx));
}

void
vtc_fatal(struct vtclog *vl, const char *fmt, ...)
{

        GET_VL(vl);
        va_list ap;
        va_start(ap, fmt);
        vtc_leadinv(vl, 0, fmt, ap);
        VSB_putc(vl->vsb, '\n');
        va_end(ap);
        REL_VL(vl);

        vtc_logfail();
}

void
vtc_log(struct vtclog *vl, int lvl, const char *fmt, ...)
{

        GET_VL(vl);
        va_list ap;
        va_start(ap, fmt);
        if (lvl >= 0) {
                vtc_leadinv(vl, lvl, fmt, ap);
                VSB_putc(vl->vsb, '\n');
        }
        va_end(ap);
        REL_VL(vl);

        if (lvl == 0)
                vtc_logfail();
}

/**********************************************************************
 * Dump a string
 */

#define MAX_DUMP 8192

void
vtc_dump(struct vtclog *vl, int lvl, const char *pfx, const char *str, int len)
{
        char buf[64];
        int quote = VSB_QUOTE_UNSAFE | VSB_QUOTE_ESCHEX;

        AN(pfx);
        GET_VL(vl);
        if (str == NULL)
                vtc_leadin(vl, lvl, "%s(null)\n", pfx);
        else {
                bprintf(buf, "%s %-5s %s|",
                    lead[lvl < 0 ? 1: lvl], vl->id, pfx);
                if (len < 0)
                        len = strlen(str);
                else if (str[0] == 0x1f && (uint8_t)str[1] == 0x8b)
                        quote = VSB_QUOTE_HEX; // Dump gzip data in HEX
                VSB_quote_pfx(vl->vsb, buf, str,
                    len > MAX_DUMP ? MAX_DUMP : len, quote);
                if (quote == VSB_QUOTE_HEX)
                        VSB_putc(vl->vsb, '\n');
                if (len > MAX_DUMP)
                        VSB_printf(vl->vsb, "%s [...] (%d)\n",
                            buf, len - MAX_DUMP);
        }
        REL_VL(vl);
        if (lvl == 0)
                vtc_logfail();
}

/**********************************************************************
 * Hexdump
 */

void
vtc_hexdump(struct vtclog *vl, int lvl, const char *pfx,
    const void *ptr, unsigned len)
{
        int nl = 1;
        unsigned l;
        const uint8_t *ss = ptr;

        AN(pfx);
        GET_VL(vl);
        if (ss == NULL)
                vtc_leadin(vl, lvl, "%s(null)\n", pfx);
        else {
                for (l = 0; l < len; l++, ss++) {
                        if (l > 512) {
                                VSB_cat(vl->vsb, "...");
                                break;
                        }
                        if (nl) {
                                vtc_leadin(vl, lvl, "%s| ", pfx);
                                nl = 0;
                        }
                        VSB_printf(vl->vsb, " %02x", *ss);
                        if ((l & 0xf) == 0xf) {
                                VSB_cat(vl->vsb, "\n");
                                nl = 1;
                        }
                }
        }
        if (!nl)
                VSB_cat(vl->vsb, "\n");
        REL_VL(vl);
        if (lvl == 0)
                vtc_logfail();
}

/**********************************************************************/

static void v_noreturn_
vtc_log_VAS_Fail(const char *func, const char *file, int line,
    const char *cond, enum vas_e why)
{
        char buf[4096] = "";
        struct vtclog *vl;
        int e = errno;

        (void)why;

        if (VBT_dump(sizeof buf, buf) < 0) {
                bprintf(buf, "Failed to print backtrace: %d (%s)\n",
                    errno, strerror(errno));
        }

        vl = pthread_getspecific(log_key);
        if (vl == NULL || vl->act) {
                fprintf(stderr,
                    "Assert error in %s(), %s line %d:\n"
                    "  Condition(%s) not true. (errno=%d %s)\n"
                    "%s\n",
                    func, file, line, cond, e, strerror(e), buf);
        } else {
                vtc_fatal(vl, "Assert error in %s(), %s line %d:"
                    "  Condition(%s) not true."
                    "  Errno=%d %s\n"
                    "%s\n",
                    func, file, line, cond, e, strerror(e), buf);
        }
        abort();
}

/**********************************************************************/

void
vtc_loginit(char *buf, unsigned buflen)
{

        VAS_Fail_Func = vtc_log_VAS_Fail;
        t0 = VTIM_mono();
        vtclog_buf = buf;
        vtclog_left = buflen;
        PTOK(pthread_mutex_init(&vtclog_mtx, NULL));
        PTOK(pthread_key_create(&log_key, NULL));
}

		varnish-cache/bin/varnishtest/vtc_log.c
0		/*-
1		* Copyright (c) 2008-2011 Varnish Software AS
2		* All rights reserved.
3		*
4		* Author: Poul-Henning Kamp <phk@phk.freebsd.dk>
5		*
6		* SPDX-License-Identifier: BSD-2-Clause
7		*
8		* Redistribution and use in source and binary forms, with or without
9		* modification, are permitted provided that the following conditions
10		* are met:
11		* 1. Redistributions of source code must retain the above copyright
12		* notice, this list of conditions and the following disclaimer.
13		* 2. Redistributions in binary form must reproduce the above copyright
14		* notice, this list of conditions and the following disclaimer in the
15		* documentation and/or other materials provided with the distribution.
16		*
17		* THIS SOFTWARE IS PROVIDED BY THE AUTHOR AND CONTRIBUTORS ``AS IS'' AND
18		* ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
19		* IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE
20		* ARE DISCLAIMED. IN NO EVENT SHALL AUTHOR OR CONTRIBUTORS BE LIABLE
21		* FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL
22		* DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS
23		* OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION)
24		* HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT
25		* LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY
26		* OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF
27		* SUCH DAMAGE.
28		*/
29
30		#include "config.h"
31
32		#include <math.h>
33		#include <stdarg.h>
34		#include <stdio.h>
35		#include <stdlib.h>
36		#include <string.h>
37
38		#include "vtc.h"
39		#include "vtc_log.h"
40
41		#include "vtim.h"
42		#include "vbt.h"
43
44		static pthread_mutex_t vtclog_mtx;
45		static char *vtclog_buf;
46		static unsigned vtclog_left;
47
48		static pthread_key_t log_key;
49		static double t0;
50
51		void
52	5714	vtc_log_set_cmd(struct vtclog vl, const struct cmds cmds)
53		{
54	5714	AN(cmds);
55	5714	vl->cmds = cmds;
56	5714	}
57
58		/**********************************************************************/
59
60		#define GET_VL(vl) \
61		do { \
62		CHECK_OBJ_NOTNULL(vl, VTCLOG_MAGIC); \
63		PTOK(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		PTOK(pthread_mutex_unlock(&vl->mtx)); \
75		} while(0)
76
77
78		struct vtclog *
79	7992	vtc_logopen(const char *fmt, ...)
80		{
81		struct vtclog *vl;
82		va_list ap;
83		char buf[BUFSIZ];
84
85	7992	va_start(ap, fmt);
86	7992	vbprintf(buf, fmt, ap);
87	7992	va_end(ap);
88
89	7992	ALLOC_OBJ(vl, VTCLOG_MAGIC);
90	7992	AN(vl);
91	7992	REPLACE(vl->id, buf);
92	7992	vl->vsb = VSB_new_auto();
93	7992	PTOK(pthread_mutex_init(&vl->mtx, NULL));
94	7992	PTOK(pthread_setspecific(log_key, vl));
95	7992	return (vl);
96		}
97
98		void
99	6968	vtc_logclose(void *arg)
100		{
101		struct vtclog *vl;
102
103	6968	CAST_OBJ_NOTNULL(vl, arg, VTCLOG_MAGIC);
104	6968	if (pthread_getspecific(log_key) == vl)
105	3976	PTOK(pthread_setspecific(log_key, NULL));
106	6968	VSB_destroy(&vl->vsb);
107	6968	PTOK(pthread_mutex_destroy(&vl->mtx));
108	6968	REPLACE(vl->id, NULL);
109	6968	FREE_OBJ(vl);
110	6968	}
111
112		static void v_noreturn_
113	2	vtc_logfail(void)
114		{
115
116	2	vtc_error = 2;
117	2	if (!pthread_equal(pthread_self(), vtc_thread))
118	0	pthread_exit(NULL);
119		else
120	2	exit(fail_out());
121
122		WRONG("unreachable"); /lint !e827 Help Coverity Scan see noreturn. /
123		}
124
125		static const char * const lead[] = {
126		"----",
127		"* ",
128		"** ",
129		"*** ",
130		"****"
131		};
132
133		#define NLEAD (sizeof(lead)/sizeof(lead[0]))
134
135		static void
136	459432	vtc_leadinv(const struct vtclog vl, int lvl, const char fmt, va_list ap)
137		{
138
139	459432	assert(lvl < (int)NLEAD);
140	459432	assert(lvl >= 0);
141	918864	VSB_printf(vl->vsb, "%s %-5s ",
142	459432	lead[lvl < 0 ? 1: lvl], vl->id);
143	459432	if (fmt != NULL)
144	459451	(void)VSB_vprintf(vl->vsb, fmt, ap);
145	459470	}
146
147		static void
148	695	vtc_leadin(const struct vtclog vl, int lvl, const char fmt, ...)
149		{
150		va_list ap;
151
152	695	va_start(ap, fmt);
153	695	vtc_leadinv(vl, lvl, fmt, ap);
154	695	va_end(ap);
155	695	}
156
157		static void
158	581207	vtc_log_emit(const struct vtclog *vl)
159		{
160		unsigned l;
161		int i;
162		int t_this;
163		static int t_last = -1;
164
165	581207	l = VSB_len(vl->vsb);
166	581207	if (l == 0)
167	8618	return;
168	572589	t_this = (int)round((VTIM_mono() - t0) * 1000);
169	572589	PTOK(pthread_mutex_lock(&vtclog_mtx));
170	572589	if (t_last != t_this) {
171	42523	assert(vtclog_left > 25);
172	85046	i = snprintf(vtclog_buf, vtclog_left,
173	42523	"**** dT %d.%03d\n", t_this / 1000, t_this % 1000);
174	42523	t_last = t_this;
175	42523	vtclog_buf += i;
176	42523	vtclog_left -= i;
177	42523	}
178	572589	assert(vtclog_left > l);
179	572589	memcpy(vtclog_buf, VSB_data(vl->vsb), l);
180	572589	vtclog_buf += l;
181	572589	*vtclog_buf = '\0';
182	572589	vtclog_left -= l;
183	572589	PTOK(pthread_mutex_unlock(&vtclog_mtx));
184	581207	}
185
186		void
187	2	vtc_fatal(struct vtclog vl, const char fmt, ...)
188		{
189
190	2	GET_VL(vl);
191		va_list ap;
192	2	va_start(ap, fmt);
193	2	vtc_leadinv(vl, 0, fmt, ap);
194	2	VSB_putc(vl->vsb, '\n');
195	2	va_end(ap);
196	2	REL_VL(vl);
197
198	2	vtc_logfail();
199		}
200
201		void
202	460826	vtc_log(struct vtclog vl, int lvl, const char fmt, ...)
203		{
204
205	460826	GET_VL(vl);
206		va_list ap;
207	460826	va_start(ap, fmt);
208	460826	if (lvl >= 0) {
209	458741	vtc_leadinv(vl, lvl, fmt, ap);
210	458741	VSB_putc(vl->vsb, '\n');
211	458741	}
212	460826	va_end(ap);
213	460826	REL_VL(vl);
214
215	460826	if (lvl == 0)
216	0	vtc_logfail();
217	460826	}
218
219		/**********************************************************************
220		* Dump a string
221		*/
222
223		#define MAX_DUMP 8192
224
225		void
226	119943	vtc_dump(struct vtclog vl, int lvl, const char pfx, const char *str, int len)
227		{
228		char buf[64];
229	119943	int quote = VSB_QUOTE_UNSAFE \| VSB_QUOTE_ESCHEX;
230
231	119943	AN(pfx);
232	119943	GET_VL(vl);
233	119943	if (str == NULL)
234	1	vtc_leadin(vl, lvl, "%s(null)\n", pfx);
235		else {
236	119942	bprintf(buf, "%s %-5s %s\|",
237		lead[lvl < 0 ? 1: lvl], vl->id, pfx);
238	119942	if (len < 0)
239	96970	len = strlen(str);
240	22972	else if (str[0] == 0x1f && (uint8_t)str[1] == 0x8b)
241	254	quote = VSB_QUOTE_HEX; // Dump gzip data in HEX
242	239884	VSB_quote_pfx(vl->vsb, buf, str,
243	119942	len > MAX_DUMP ? MAX_DUMP : len, quote);
244	119942	if (quote == VSB_QUOTE_HEX)
245	254	VSB_putc(vl->vsb, '\n');
246	119942	if (len > MAX_DUMP)
247	468	VSB_printf(vl->vsb, "%s [...] (%d)\n",
248	234	buf, len - MAX_DUMP);
249		}
250	119943	REL_VL(vl);
251	119943	if (lvl == 0)
252	0	vtc_logfail();
253	119943	}
254
255		/**********************************************************************
256		* Hexdump
257		*/
258
259		void
260	411	vtc_hexdump(struct vtclog vl, int lvl, const char pfx,
261		const void *ptr, unsigned len)
262		{
263	411	int nl = 1;
264		unsigned l;
265	411	const uint8_t *ss = ptr;
266
267	411	AN(pfx);
268	411	GET_VL(vl);
269	411	if (ss == NULL)
270	0	vtc_leadin(vl, lvl, "%s(null)\n", pfx);
271		else {
272	7207	for (l = 0; l < len; l++, ss++) {
273	6797	if (l > 512) {
274	1	VSB_cat(vl->vsb, "...");
275	1	break;
276		}
277	6796	if (nl) {
278	694	vtc_leadin(vl, lvl, "%s\| ", pfx);
279	694	nl = 0;
280	694	}
281	6796	VSB_printf(vl->vsb, " %02x", *ss);
282	6796	if ((l & 0xf) == 0xf) {
283	336	VSB_cat(vl->vsb, "\n");
284	336	nl = 1;
285	336	}
286	6796	}
287		}
288	411	if (!nl)
289	358	VSB_cat(vl->vsb, "\n");
290	411	REL_VL(vl);
291	411	if (lvl == 0)
292	0	vtc_logfail();
293	411	}
294
295		/**********************************************************************/
296
297		static void v_noreturn_
298	0	vtc_log_VAS_Fail(const char func, const char file, int line,
299		const char *cond, enum vas_e why)
300		{
301	0	char buf[4096] = "";
302		struct vtclog *vl;
303	0	int e = errno;
304
305	0	(void)why;
306
307	0	if (VBT_dump(sizeof buf, buf) < 0) {
308	0	bprintf(buf, "Failed to print backtrace: %d (%s)\n",
309		errno, strerror(errno));
310	0	}
311
312	0	vl = pthread_getspecific(log_key);
313	0	if (vl == NULL \|\| vl->act) {
314	0	fprintf(stderr,
315		"Assert error in %s(), %s line %d:\n"
316		" Condition(%s) not true. (errno=%d %s)\n"
317		"%s\n",
318	0	func, file, line, cond, e, strerror(e), buf);
319	0	} else {
320	0	vtc_fatal(vl, "Assert error in %s(), %s line %d:"
321		" Condition(%s) not true."
322		" Errno=%d %s\n"
323		"%s\n",
324	0	func, file, line, cond, e, strerror(e), buf);
325		}
326	0	abort();
327		}
328
329		/**********************************************************************/
330
331		void
332	1023	vtc_loginit(char *buf, unsigned buflen)
333		{
334
335	1023	VAS_Fail_Func = vtc_log_VAS_Fail;
336	1023	t0 = VTIM_mono();
337	1023	vtclog_buf = buf;
338	1023	vtclog_left = buflen;
339	1023	PTOK(pthread_mutex_init(&vtclog_mtx, NULL));
340	1023	PTOK(pthread_key_create(&log_key, NULL));
341	1023	}