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

        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)
{
        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	221549	vtc_log_set_cmd(struct vtclog vl, const struct cmds cmds)
52		{
53	221549	AN(cmds);
54	221549	vl->cmds = cmds;
55	221549	}
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	311522	vtc_logopen(const char *fmt, ...)
79		{
80		struct vtclog *vl;
81		va_list ap;
82		char buf[BUFSIZ];
83
84	311522	va_start(ap, fmt);
85	311522	vbprintf(buf, fmt, ap);
86	311522	va_end(ap);
87
88	311522	ALLOC_OBJ(vl, VTCLOG_MAGIC);
89	311510	AN(vl);
90	311510	REPLACE(vl->id, buf);
91	311510	vl->vsb = VSB_new_auto();
92	311510	PTOK(pthread_mutex_init(&vl->mtx, NULL));
93	311510	PTOK(pthread_setspecific(log_key, vl));
94	311510	return (vl);
95		}
96
97		void
98	271352	vtc_logclose(void *arg)
99		{
100		struct vtclog *vl;
101
102	271352	CAST_OBJ_NOTNULL(vl, arg, VTCLOG_MAGIC);
103	271352	if (pthread_getspecific(log_key) == vl)
104	155523	PTOK(pthread_setspecific(log_key, NULL));
105	271352	VSB_destroy(&vl->vsb);
106	271352	PTOK(pthread_mutex_destroy(&vl->mtx));
107	271352	REPLACE(vl->id, NULL);
108	271352	FREE_OBJ(vl);
109	271352	}
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		WRONG("unreachable"); /lint !e827 Help Coverity Scan see noreturn. /
122		}
123
124		static const char * const lead[] = {
125		"----",
126		"* ",
127		"** ",
128		"*** ",
129		"****"
130		};
131
132		#define NLEAD (sizeof(lead)/sizeof(lead[0]))
133
134		static void
135	17802668	vtc_leadinv(const struct vtclog vl, int lvl, const char fmt, va_list ap)
136		{
137
138	17802668	assert(lvl < (int)NLEAD);
139	17802668	assert(lvl >= 0);
140	35605336	VSB_printf(vl->vsb, "%s %-5s ",
141	17802668	lead[lvl < 0 ? 1: lvl], vl->id);
142	17802668	if (fmt != NULL)
143	17803390	(void)VSB_vprintf(vl->vsb, fmt, ap);
144	17804112	}
145
146		static void
147	26870	vtc_leadin(const struct vtclog vl, int lvl, const char fmt, ...)
148		{
149		va_list ap;
150
151	26870	va_start(ap, fmt);
152	26870	vtc_leadinv(vl, lvl, fmt, ap);
153	26870	va_end(ap);
154	26870	}
155
156		static void
157	22566567	vtc_log_emit(const struct vtclog *vl)
158		{
159		unsigned l;
160		int i;
161		int t_this;
162		static int t_last = -1;
163
164	22566567	l = VSB_len(vl->vsb);
165	22566567	if (l == 0)
166	344726	return;
167	22221841	t_this = (int)round((VTIM_mono() - t0) * 1000);
168	22221841	PTOK(pthread_mutex_lock(&vtclog_mtx));
169	22221841	if (t_last != t_this) {
170	1669521	assert(vtclog_left > 25);
171	3339042	i = snprintf(vtclog_buf, vtclog_left,
172	1669521	"**** dT %d.%03d\n", t_this / 1000, t_this % 1000);
173	1669521	t_last = t_this;
174	1669521	vtclog_buf += i;
175	1669521	vtclog_left -= i;
176	1669521	}
177	22221841	assert(vtclog_left > l);
178	22221841	memcpy(vtclog_buf, VSB_data(vl->vsb), l);
179	22221841	vtclog_buf += l;
180	22221841	*vtclog_buf = '\0';
181	22221841	vtclog_left -= l;
182	22221841	PTOK(pthread_mutex_unlock(&vtclog_mtx));
183	22566567	}
184
185		void
186	80	vtc_fatal(struct vtclog vl, const char fmt, ...)
187		{
188
189	80	GET_VL(vl);
190		va_list ap;
191	80	va_start(ap, fmt);
192	80	vtc_leadinv(vl, 0, fmt, ap);
193	80	VSB_putc(vl->vsb, '\n');
194	80	va_end(ap);
195	80	REL_VL(vl);
196
197	80	vtc_logfail();
198		}
199
200		void
201	17865837	vtc_log(struct vtclog vl, int lvl, const char fmt, ...)
202		{
203
204	17865837	GET_VL(vl);
205		va_list ap;
206	17865837	va_start(ap, fmt);
207	17865837	if (lvl >= 0) {
208	17776092	vtc_leadinv(vl, lvl, fmt, ap);
209	17776092	VSB_putc(vl->vsb, '\n');
210	17776092	}
211	17865837	va_end(ap);
212	17865837	REL_VL(vl);
213
214	17865837	if (lvl == 0)
215	0	vtc_logfail();
216	17865837	}
217
218		/**********************************************************************
219		* Dump a string
220		*/
221
222		#define MAX_DUMP 8192
223
224		void
225	4684000	vtc_dump(struct vtclog vl, int lvl, const char pfx, const char *str, int len)
226		{
227		char buf[64];
228	4684000	int quote = VSB_QUOTE_UNSAFE \| VSB_QUOTE_ESCHEX;
229
230	4684000	AN(pfx);
231	4684000	GET_VL(vl);
232	4684000	if (str == NULL)
233	40	vtc_leadin(vl, lvl, "%s(null)\n", pfx);
234		else {
235	4683960	bprintf(buf, "%s %-5s %s\|",
236		lead[lvl < 0 ? 1: lvl], vl->id, pfx);
237	4683960	if (len < 0)
238	3787545	len = strlen(str);
239	896415	else if (str[0] == 0x1f && (uint8_t)str[1] == 0x8b)
240	10160	quote = VSB_QUOTE_HEX; // Dump gzip data in HEX
241	9367920	VSB_quote_pfx(vl->vsb, buf, str,
242	4683960	len > MAX_DUMP ? MAX_DUMP : len, quote);
243	4683960	if (quote == VSB_QUOTE_HEX)
244	10160	VSB_putc(vl->vsb, '\n');
245	4683960	if (len > MAX_DUMP)
246	14860	VSB_printf(vl->vsb, "%s [...] (%d)\n",
247	7430	buf, len - MAX_DUMP);
248		}
249	4684000	REL_VL(vl);
250	4684000	if (lvl == 0)
251	0	vtc_logfail();
252	4684000	}
253
254		/**********************************************************************
255		* Hexdump
256		*/
257
258		void
259	15566	vtc_hexdump(struct vtclog vl, int lvl, const char pfx,
260		const void *ptr, unsigned len)
261		{
262	15566	int nl = 1;
263		unsigned l;
264	15566	const uint8_t *ss = ptr;
265
266	15566	AN(pfx);
267	15566	GET_VL(vl);
268	15566	if (ss == NULL)
269	0	vtc_leadin(vl, lvl, "%s(null)\n", pfx);
270		else {
271	278786	for (l = 0; l < len; l++, ss++) {
272	263270	if (l > 512) {
273	50	VSB_cat(vl->vsb, "...");
274	50	break;
275		}
276	263220	if (nl) {
277	26830	vtc_leadin(vl, lvl, "%s\| ", pfx);
278	26830	nl = 0;
279	26830	}
280	263220	VSB_printf(vl->vsb, " %02x", *ss);
281	263220	if ((l & 0xf) == 0xf) {
282	13273	VSB_cat(vl->vsb, "\n");
283	13273	nl = 1;
284	13273	}
285	263220	}
286		}
287	15566	if (!nl)
288	13557	VSB_cat(vl->vsb, "\n");
289	15566	REL_VL(vl);
290	15566	if (lvl == 0)
291	0	vtc_logfail();
292	15566	}
293
294		/**********************************************************************/
295
296		static void v_noreturn_
297	0	vtc_log_VAS_Fail(const char func, const char file, int line,
298		const char *cond, enum vas_e why)
299		{
300		struct vtclog *vl;
301	0	int e = errno;
302
303	0	(void)why;
304	0	vl = pthread_getspecific(log_key);
305	0	if (vl == NULL \|\| vl->act) {
306	0	fprintf(stderr,
307		"Assert error in %s(), %s line %d:\n"
308		" Condition(%s) not true. (errno=%d %s)\n",
309	0	func, file, line, cond, e, strerror(e));
310	0	} else
311	0	vtc_fatal(vl, "Assert error in %s(), %s line %d:"
312		" Condition(%s) not true."
313	0	" Errno=%d %s", func, file, line, cond, e, strerror(e));
314	0	abort();
315		}
316
317		/**********************************************************************/
318
319		void
320	40120	vtc_loginit(char *buf, unsigned buflen)
321		{
322
323	40120	VAS_Fail_Func = vtc_log_VAS_Fail;
324	40120	t0 = VTIM_mono();
325	40120	vtclog_buf = buf;
326	40120	vtclog_left = buflen;
327	40120	PTOK(pthread_mutex_init(&vtclog_mtx, NULL));
328	40120	PTOK(pthread_key_create(&log_key, NULL));
329	40120	}