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"

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());
}

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)
{
        struct vtclog *vl;
        int e = errno;

        (void)why;
        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",
                    func, file, line, cond, e, strerror(e));
        } else
                vtc_fatal(vl, "Assert error in %s(), %s line %d:"
                    "  Condition(%s) not true."
                    "  Errno=%d %s", func, file, line, cond, e, strerror(e));
        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
43		static pthread_mutex_t vtclog_mtx;
44		static char *vtclog_buf;
45		static unsigned vtclog_left;
46
47		static pthread_key_t log_key;
48		static double t0;
49
50		void
51	217830	vtc_log_set_cmd(struct vtclog vl, const struct cmds cmds)
52		{
53	217830	AN(cmds);
54	217830	vl->cmds = cmds;
55	217830	}
56
57		/**********************************************************************/
58
59		#define GET_VL(vl) \
60		do { \
61		CHECK_OBJ_NOTNULL(vl, VTCLOG_MAGIC); \
62		PTOK(pthread_mutex_lock(&vl->mtx)); \
63		vl->act = 1; \
64		VSB_clear(vl->vsb); \
65		} while(0)
66
67		#define REL_VL(vl) \
68		do { \
69		AZ(VSB_finish(vl->vsb)); \
70		vtc_log_emit(vl); \
71		VSB_clear(vl->vsb); \
72		vl->act = 0; \
73		PTOK(pthread_mutex_unlock(&vl->mtx)); \
74		} while(0)
75
76
77		struct vtclog *
78	307724	vtc_logopen(const char *fmt, ...)
79		{
80		struct vtclog *vl;
81		va_list ap;
82		char buf[BUFSIZ];
83
84	307724	va_start(ap, fmt);
85	307724	vbprintf(buf, fmt, ap);
86	307724	va_end(ap);
87
88	307724	ALLOC_OBJ(vl, VTCLOG_MAGIC);
89	307706	AN(vl);
90	307706	REPLACE(vl->id, buf);
91	307706	vl->vsb = VSB_new_auto();
92	307706	PTOK(pthread_mutex_init(&vl->mtx, NULL));
93	307706	PTOK(pthread_setspecific(log_key, vl));
94	307706	return (vl);
95		}
96
97		void
98	268039	vtc_logclose(void *arg)
99		{
100		struct vtclog *vl;
101
102	268039	CAST_OBJ_NOTNULL(vl, arg, VTCLOG_MAGIC);
103	268039	if (pthread_getspecific(log_key) == vl)
104	153556	PTOK(pthread_setspecific(log_key, NULL));
105	268039	VSB_destroy(&vl->vsb);
106	268039	PTOK(pthread_mutex_destroy(&vl->mtx));
107	268039	REPLACE(vl->id, NULL);
108	268039	FREE_OBJ(vl);
109	268039	}
110
111		static void v_noreturn_
112	80	vtc_logfail(void)
113		{
114
115	80	vtc_error = 2;
116	80	if (!pthread_equal(pthread_self(), vtc_thread))
117	0	pthread_exit(NULL);
118		else
119	80	exit(fail_out());
120		}
121
122		static const char * const lead[] = {
123		"----",
124		"* ",
125		"** ",
126		"*** ",
127		"****"
128		};
129
130		#define NLEAD (sizeof(lead)/sizeof(lead[0]))
131
132		static void
133	17470419	vtc_leadinv(const struct vtclog vl, int lvl, const char fmt, va_list ap)
134		{
135
136	17470419	assert(lvl < (int)NLEAD);
137	17470419	assert(lvl >= 0);
138	34940838	VSB_printf(vl->vsb, "%s %-5s ",
139	17470419	lead[lvl < 0 ? 1: lvl], vl->id);
140	17470419	if (fmt != NULL)
141	17471311	(void)VSB_vprintf(vl->vsb, fmt, ap);
142	17472203	}
143
144		static void
145	26939	vtc_leadin(const struct vtclog vl, int lvl, const char fmt, ...)
146		{
147		va_list ap;
148
149	26939	va_start(ap, fmt);
150	26939	vtc_leadinv(vl, lvl, fmt, ap);
151	26939	va_end(ap);
152	26939	}
153
154		static void
155	22119094	vtc_log_emit(const struct vtclog *vl)
156		{
157		unsigned l;
158		int i;
159		int t_this;
160		static int t_last = -1;
161
162	22119094	l = VSB_len(vl->vsb);
163	22119094	if (l == 0)
164	337312	return;
165	21781782	t_this = (int)round((VTIM_mono() - t0) * 1000);
166	21781782	PTOK(pthread_mutex_lock(&vtclog_mtx));
167	21781782	if (t_last != t_this) {
168	1585014	assert(vtclog_left > 25);
169	3170028	i = snprintf(vtclog_buf, vtclog_left,
170	1585014	"**** dT %d.%03d\n", t_this / 1000, t_this % 1000);
171	1585014	t_last = t_this;
172	1585014	vtclog_buf += i;
173	1585014	vtclog_left -= i;
174	1585014	}
175	21781782	assert(vtclog_left > l);
176	21781782	memcpy(vtclog_buf, VSB_data(vl->vsb), l);
177	21781782	vtclog_buf += l;
178	21781782	*vtclog_buf = '\0';
179	21781782	vtclog_left -= l;
180	21781782	PTOK(pthread_mutex_unlock(&vtclog_mtx));
181	22119094	}
182
183		void
184	80	vtc_fatal(struct vtclog vl, const char fmt, ...)
185		{
186
187	80	GET_VL(vl);
188		va_list ap;
189	80	va_start(ap, fmt);
190	80	vtc_leadinv(vl, 0, fmt, ap);
191	80	VSB_putc(vl->vsb, '\n');
192	80	va_end(ap);
193	80	REL_VL(vl);
194
195	80	vtc_logfail();
196		}
197
198		void
199	17529284	vtc_log(struct vtclog vl, int lvl, const char fmt, ...)
200		{
201
202	17529284	GET_VL(vl);
203		va_list ap;
204	17529284	va_start(ap, fmt);
205	17529284	if (lvl >= 0) {
206	17443459	vtc_leadinv(vl, lvl, fmt, ap);
207	17443459	VSB_putc(vl->vsb, '\n');
208	17443459	}
209	17529284	va_end(ap);
210	17529284	REL_VL(vl);
211
212	17529284	if (lvl == 0)
213	0	vtc_logfail();
214	17529284	}
215
216		/**********************************************************************
217		* Dump a string
218		*/
219
220		#define MAX_DUMP 8192
221
222		void
223	4573255	vtc_dump(struct vtclog vl, int lvl, const char pfx, const char *str, int len)
224		{
225		char buf[64];
226	4573255	int quote = VSB_QUOTE_UNSAFE \| VSB_QUOTE_ESCHEX;
227
228	4573255	AN(pfx);
229	4573255	GET_VL(vl);
230	4573255	if (str == NULL)
231	40	vtc_leadin(vl, lvl, "%s(null)\n", pfx);
232		else {
233	4573215	bprintf(buf, "%s %-5s %s\|",
234		lead[lvl < 0 ? 1: lvl], vl->id, pfx);
235	4573215	if (len < 0)
236	3690478	len = strlen(str);
237	882737	else if (str[0] == 0x1f && (uint8_t)str[1] == 0x8b)
238	10160	quote = VSB_QUOTE_HEX; // Dump gzip data in HEX
239	9146430	VSB_quote_pfx(vl->vsb, buf, str,
240	4573215	len > MAX_DUMP ? MAX_DUMP : len, quote);
241	4573215	if (quote == VSB_QUOTE_HEX)
242	10160	VSB_putc(vl->vsb, '\n');
243	4573215	if (len > MAX_DUMP)
244	14844	VSB_printf(vl->vsb, "%s [...] (%d)\n",
245	7422	buf, len - MAX_DUMP);
246		}
247	4573255	REL_VL(vl);
248	4573255	if (lvl == 0)
249	0	vtc_logfail();
250	4573255	}
251
252		/**********************************************************************
253		* Hexdump
254		*/
255
256		void
257	15622	vtc_hexdump(struct vtclog vl, int lvl, const char pfx,
258		const void *ptr, unsigned len)
259		{
260	15622	int nl = 1;
261		unsigned l;
262	15622	const uint8_t *ss = ptr;
263
264	15622	AN(pfx);
265	15622	GET_VL(vl);
266	15622	if (ss == NULL)
267	0	vtc_leadin(vl, lvl, "%s(null)\n", pfx);
268		else {
269	279223	for (l = 0; l < len; l++, ss++) {
270	263644	if (l > 512) {
271	43	VSB_cat(vl->vsb, "...");
272	43	break;
273		}
274	263601	if (nl) {
275	26900	vtc_leadin(vl, lvl, "%s\| ", pfx);
276	26900	nl = 0;
277	26900	}
278	263601	VSB_printf(vl->vsb, " %02x", *ss);
279	263601	if ((l & 0xf) == 0xf) {
280	13288	VSB_cat(vl->vsb, "\n");
281	13288	nl = 1;
282	13288	}
283	263601	}
284		}
285	15622	if (!nl)
286	13612	VSB_cat(vl->vsb, "\n");
287	15622	REL_VL(vl);
288	15622	if (lvl == 0)
289	0	vtc_logfail();
290	15622	}
291
292		/**********************************************************************/
293
294		static void v_noreturn_
295	0	vtc_log_VAS_Fail(const char func, const char file, int line,
296		const char *cond, enum vas_e why)
297		{
298		struct vtclog *vl;
299	0	int e = errno;
300
301	0	(void)why;
302	0	vl = pthread_getspecific(log_key);
303	0	if (vl == NULL \|\| vl->act) {
304	0	fprintf(stderr,
305		"Assert error in %s(), %s line %d:\n"
306		" Condition(%s) not true. (errno=%d %s)\n",
307	0	func, file, line, cond, e, strerror(e));
308	0	} else
309	0	vtc_fatal(vl, "Assert error in %s(), %s line %d:"
310		" Condition(%s) not true."
311	0	" Errno=%d %s", func, file, line, cond, e, strerror(e));
312	0	abort();
313		}
314
315		/**********************************************************************/
316
317		void
318	39640	vtc_loginit(char *buf, unsigned buflen)
319		{
320
321	39640	VAS_Fail_Func = vtc_log_VAS_Fail;
322	39640	t0 = VTIM_mono();
323	39640	vtclog_buf = buf;
324	39640	vtclog_left = buflen;
325	39640	PTOK(pthread_mutex_init(&vtclog_mtx, NULL));
326	39640	PTOK(pthread_key_create(&log_key, NULL));
327	39640	}