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/vtest2/src/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	231607	vtc_log_set_cmd(struct vtclog vl, const struct cmds cmds)
53		{
54	231607	AN(cmds);
55	231607	vl->cmds = cmds;
56	231607	}
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	322810	vtc_logopen(const char *fmt, ...)
80		{
81		struct vtclog *vl;
82		va_list ap;
83		char buf[BUFSIZ];
84
85	322810	va_start(ap, fmt);
86	322810	vbprintf(buf, fmt, ap);
87	322810	va_end(ap);
88
89	322810	ALLOC_OBJ(vl, VTCLOG_MAGIC);
90	322796	AN(vl);
91	322796	REPLACE(vl->id, buf);
92	322796	vl->vsb = VSB_new_auto();
93	322796	PTOK(pthread_mutex_init(&vl->mtx, NULL));
94	322796	PTOK(pthread_setspecific(log_key, vl));
95	322796	return (vl);
96		}
97
98		void
99	281670	vtc_logclose(void *arg)
100		{
101		struct vtclog *vl;
102
103	281670	CAST_OBJ_NOTNULL(vl, arg, VTCLOG_MAGIC);
104	281670	if (pthread_getspecific(log_key) == vl)
105	160794	PTOK(pthread_setspecific(log_key, NULL));
106	281670	VSB_destroy(&vl->vsb);
107	281670	PTOK(pthread_mutex_destroy(&vl->mtx));
108	281670	REPLACE(vl->id, NULL);
109	281670	FREE_OBJ(vl);
110	281670	}
111
112		static void v_noreturn_
113	40	vtc_logfail(void)
114		{
115
116	40	vtc_error = 2;
117	40	if (!pthread_equal(pthread_self(), vtc_thread))
118	0	pthread_exit(NULL);
119		else
120	40	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	18711569	vtc_leadinv(const struct vtclog vl, int lvl, const char fmt, va_list ap)
137		{
138
139	18711569	assert(lvl < (int)NLEAD);
140	18711569	assert(lvl >= 0);
141	37423138	VSB_printf(vl->vsb, "%s %-5s ",
142	18711569	lead[lvl < 0 ? 1: lvl], vl->id);
143	18711569	if (fmt != NULL)
144	18712521	(void)VSB_vprintf(vl->vsb, fmt, ap);
145	18713473	}
146
147		static void
148	21444	vtc_leadin(const struct vtclog vl, int lvl, const char fmt, ...)
149		{
150		va_list ap;
151
152	21444	va_start(ap, fmt);
153	21444	vtc_leadinv(vl, lvl, fmt, ap);
154	21444	va_end(ap);
155	21444	}
156
157		static void
158	23623655	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	23623655	l = VSB_len(vl->vsb);
166	23623655	if (l == 0)
167	351679	return;
168	23271976	t_this = (int)round((VTIM_mono() - t0) * 1000);
169	23271976	PTOK(pthread_mutex_lock(&vtclog_mtx));
170	23271976	if (t_last != t_this) {
171	1733131	assert(vtclog_left > 25);
172	3466262	i = snprintf(vtclog_buf, vtclog_left,
173	1733131	"**** dT %d.%03d\n", t_this / 1000, t_this % 1000);
174	1733131	t_last = t_this;
175	1733131	vtclog_buf += i;
176	1733131	vtclog_left -= i;
177	1733131	}
178	23271976	assert(vtclog_left > l);
179	23271976	memcpy(vtclog_buf, VSB_data(vl->vsb), l);
180	23271976	vtclog_buf += l;
181	23271976	*vtclog_buf = '\0';
182	23271976	vtclog_left -= l;
183	23271976	PTOK(pthread_mutex_unlock(&vtclog_mtx));
184	23623655	}
185
186		void
187	40	vtc_fatal(struct vtclog vl, const char fmt, ...)
188		{
189
190	40	GET_VL(vl);
191		va_list ap;
192	40	va_start(ap, fmt);
193	40	vtc_leadinv(vl, 0, fmt, ap);
194	40	VSB_putc(vl->vsb, '\n');
195	40	va_end(ap);
196	40	REL_VL(vl);
197
198	40	vtc_logfail();
199		}
200
201		void
202	18778489	vtc_log(struct vtclog vl, int lvl, const char fmt, ...)
203		{
204
205	18778489	GET_VL(vl);
206		va_list ap;
207	18778489	va_start(ap, fmt);
208	18778489	if (lvl >= 0) {
209	18690135	vtc_leadinv(vl, lvl, fmt, ap);
210	18690135	VSB_putc(vl->vsb, '\n');
211	18690135	}
212	18778489	va_end(ap);
213	18778489	REL_VL(vl);
214
215	18778489	if (lvl == 0)
216	0	vtc_logfail();
217	18778489	}
218
219		/**********************************************************************
220		* Dump a string
221		*/
222
223		#define MAX_DUMP 8192
224
225		void
226	4831215	vtc_dump(struct vtclog vl, int lvl, const char pfx, const char *str, int len)
227		{
228		char buf[64];
229	4831215	int quote = VSB_QUOTE_UNSAFE \| VSB_QUOTE_ESCHEX;
230
231	4831215	AN(pfx);
232	4831215	GET_VL(vl);
233	4831215	if (str == NULL)
234	40	vtc_leadin(vl, lvl, "%s(null)\n", pfx);
235		else {
236	4831175	bprintf(buf, "%s %-5s %s\|",
237		lead[lvl < 0 ? 1: lvl], vl->id, pfx);
238	4831175	if (len < 0)
239	3957144	len = strlen(str);
240	874031	else if (str[0] == 0x1f && (uint8_t)str[1] == 0x8b)
241	10200	quote = VSB_QUOTE_HEX; // Dump gzip data in HEX
242	9662350	VSB_quote_pfx(vl->vsb, buf, str,
243	4831175	len > MAX_DUMP ? MAX_DUMP : len, quote);
244	4831175	if (quote == VSB_QUOTE_HEX)
245	10200	VSB_putc(vl->vsb, '\n');
246	4831175	if (len > MAX_DUMP)
247	23436	VSB_printf(vl->vsb, "%s [...] (%d)\n",
248	11718	buf, len - MAX_DUMP);
249		}
250	4831215	REL_VL(vl);
251	4831215	if (lvl == 0)
252	0	vtc_logfail();
253	4831215	}
254
255		/**********************************************************************
256		* Hexdump
257		*/
258
259		void
260	12989	vtc_hexdump(struct vtclog vl, int lvl, const char pfx,
261		const void *ptr, unsigned len)
262		{
263	12989	int nl = 1;
264		unsigned l;
265	12989	const uint8_t *ss = ptr;
266
267	12989	AN(pfx);
268	12989	GET_VL(vl);
269	12989	if (ss == NULL)
270	0	vtc_leadin(vl, lvl, "%s(null)\n", pfx);
271		else {
272	224779	for (l = 0; l < len; l++, ss++) {
273	211840	if (l > 512) {
274	50	VSB_cat(vl->vsb, "...");
275	50	break;
276		}
277	211790	if (nl) {
278	21404	vtc_leadin(vl, lvl, "%s\| ", pfx);
279	21404	nl = 0;
280	21404	}
281	211790	VSB_printf(vl->vsb, " %02x", *ss);
282	211790	if ((l & 0xf) == 0xf) {
283	10438	VSB_cat(vl->vsb, "\n");
284	10438	nl = 1;
285	10438	}
286	211790	}
287		}
288	12989	if (!nl)
289	10966	VSB_cat(vl->vsb, "\n");
290	12989	REL_VL(vl);
291	12989	if (lvl == 0)
292	0	vtc_logfail();
293	12989	}
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	41080	vtc_loginit(char *buf, unsigned buflen)
333		{
334
335	41080	VAS_Fail_Func = vtc_log_VAS_Fail;
336	41080	t0 = VTIM_mono();
337	41080	vtclog_buf = buf;
338	41080	vtclog_left = buflen;
339	41080	PTOK(pthread_mutex_init(&vtclog_mtx, NULL));
340	41080	PTOK(pthread_key_create(&log_key, NULL));
341	41080	}