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	222908	vtc_log_set_cmd(struct vtclog vl, const struct cmds cmds)
52		{
53	222908	AN(cmds);
54	222908	vl->cmds = cmds;
55	222908	}
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	311816	vtc_logopen(const char *fmt, ...)
79		{
80		struct vtclog *vl;
81		va_list ap;
82		char buf[BUFSIZ];
83
84	311816	va_start(ap, fmt);
85	311816	vbprintf(buf, fmt, ap);
86	311816	va_end(ap);
87
88	311816	ALLOC_OBJ(vl, VTCLOG_MAGIC);
89	311804	AN(vl);
90	311804	REPLACE(vl->id, buf);
91	311804	vl->vsb = VSB_new_auto();
92	311804	PTOK(pthread_mutex_init(&vl->mtx, NULL));
93	311804	PTOK(pthread_setspecific(log_key, vl));
94	311804	return (vl);
95		}
96
97		void
98	271618	vtc_logclose(void *arg)
99		{
100		struct vtclog *vl;
101
102	271618	CAST_OBJ_NOTNULL(vl, arg, VTCLOG_MAGIC);
103	271618	if (pthread_getspecific(log_key) == vl)
104	155670	PTOK(pthread_setspecific(log_key, NULL));
105	271618	VSB_destroy(&vl->vsb);
106	271618	PTOK(pthread_mutex_destroy(&vl->mtx));
107	271618	REPLACE(vl->id, NULL);
108	271618	FREE_OBJ(vl);
109	271618	}
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	17878614	vtc_leadinv(const struct vtclog vl, int lvl, const char fmt, va_list ap)
136		{
137
138	17878614	assert(lvl < (int)NLEAD);
139	17878614	assert(lvl >= 0);
140	35757228	VSB_printf(vl->vsb, "%s %-5s ",
141	17878614	lead[lvl < 0 ? 1: lvl], vl->id);
142	17878614	if (fmt != NULL)
143	17879326	(void)VSB_vprintf(vl->vsb, fmt, ap);
144	17880038	}
145
146		static void
147	26878	vtc_leadin(const struct vtclog vl, int lvl, const char fmt, ...)
148		{
149		va_list ap;
150
151	26878	va_start(ap, fmt);
152	26878	vtc_leadinv(vl, lvl, fmt, ap);
153	26878	va_end(ap);
154	26878	}
155
156		static void
157	22662460	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	22662460	l = VSB_len(vl->vsb);
165	22662460	if (l == 0)
166	343020	return;
167	22319440	t_this = (int)round((VTIM_mono() - t0) * 1000);
168	22319440	PTOK(pthread_mutex_lock(&vtclog_mtx));
169	22319440	if (t_last != t_this) {
170	1676026	assert(vtclog_left > 25);
171	3352052	i = snprintf(vtclog_buf, vtclog_left,
172	1676026	"**** dT %d.%03d\n", t_this / 1000, t_this % 1000);
173	1676026	t_last = t_this;
174	1676026	vtclog_buf += i;
175	1676026	vtclog_left -= i;
176	1676026	}
177	22319440	assert(vtclog_left > l);
178	22319440	memcpy(vtclog_buf, VSB_data(vl->vsb), l);
179	22319440	vtclog_buf += l;
180	22319440	*vtclog_buf = '\0';
181	22319440	vtclog_left -= l;
182	22319440	PTOK(pthread_mutex_unlock(&vtclog_mtx));
183	22662460	}
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	17939807	vtc_log(struct vtclog vl, int lvl, const char fmt, ...)
202		{
203
204	17939807	GET_VL(vl);
205		va_list ap;
206	17939807	va_start(ap, fmt);
207	17939807	if (lvl >= 0) {
208	17852028	vtc_leadinv(vl, lvl, fmt, ap);
209	17852028	VSB_putc(vl->vsb, '\n');
210	17852028	}
211	17939807	va_end(ap);
212	17939807	REL_VL(vl);
213
214	17939807	if (lvl == 0)
215	0	vtc_logfail();
216	17939807	}
217
218		/**********************************************************************
219		* Dump a string
220		*/
221
222		#define MAX_DUMP 8192
223
224		void
225	4705884	vtc_dump(struct vtclog vl, int lvl, const char pfx, const char *str, int len)
226		{
227		char buf[64];
228	4705884	int quote = VSB_QUOTE_UNSAFE \| VSB_QUOTE_ESCHEX;
229
230	4705884	AN(pfx);
231	4705884	GET_VL(vl);
232	4705884	if (str == NULL)
233	40	vtc_leadin(vl, lvl, "%s(null)\n", pfx);
234		else {
235	4705844	bprintf(buf, "%s %-5s %s\|",
236		lead[lvl < 0 ? 1: lvl], vl->id, pfx);
237	4705844	if (len < 0)
238	3804784	len = strlen(str);
239	901060	else if (str[0] == 0x1f && (uint8_t)str[1] == 0x8b)
240	10160	quote = VSB_QUOTE_HEX; // Dump gzip data in HEX
241	9411688	VSB_quote_pfx(vl->vsb, buf, str,
242	4705844	len > MAX_DUMP ? MAX_DUMP : len, quote);
243	4705844	if (quote == VSB_QUOTE_HEX)
244	10160	VSB_putc(vl->vsb, '\n');
245	4705844	if (len > MAX_DUMP)
246	18756	VSB_printf(vl->vsb, "%s [...] (%d)\n",
247	9378	buf, len - MAX_DUMP);
248		}
249	4705884	REL_VL(vl);
250	4705884	if (lvl == 0)
251	0	vtc_logfail();
252	4705884	}
253
254		/**********************************************************************
255		* Hexdump
256		*/
257
258		void
259	15575	vtc_hexdump(struct vtclog vl, int lvl, const char pfx,
260		const void *ptr, unsigned len)
261		{
262	15575	int nl = 1;
263		unsigned l;
264	15575	const uint8_t *ss = ptr;
265
266	15575	AN(pfx);
267	15575	GET_VL(vl);
268	15575	if (ss == NULL)
269	0	vtc_leadin(vl, lvl, "%s(null)\n", pfx);
270		else {
271	278673	for (l = 0; l < len; l++, ss++) {
272	263149	if (l > 512) {
273	51	VSB_cat(vl->vsb, "...");
274	51	break;
275		}
276	263098	if (nl) {
277	26838	vtc_leadin(vl, lvl, "%s\| ", pfx);
278	26838	nl = 0;
279	26838	}
280	263098	VSB_printf(vl->vsb, " %02x", *ss);
281	263098	if ((l & 0xf) == 0xf) {
282	13264	VSB_cat(vl->vsb, "\n");
283	13264	nl = 1;
284	13264	}
285	263098	}
286		}
287	15575	if (!nl)
288	13575	VSB_cat(vl->vsb, "\n");
289	15575	REL_VL(vl);
290	15575	if (lvl == 0)
291	0	vtc_logfail();
292	15575	}
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	40160	vtc_loginit(char *buf, unsigned buflen)
321		{
322
323	40160	VAS_Fail_Func = vtc_log_VAS_Fail;
324	40160	t0 = VTIM_mono();
325	40160	vtclog_buf = buf;
326	40160	vtclog_left = buflen;
327	40160	PTOK(pthread_mutex_init(&vtclog_mtx, NULL));
328	40160	PTOK(pthread_key_create(&log_key, NULL));
329	40160	}