xref: /spdk/lib/trace/trace.c (revision 7506a7aa53d239f533af3bc768f0d2af55e735fe)
1 /*-
2  *   BSD LICENSE
3  *
4  *   Copyright (c) Intel Corporation.
5  *   All rights reserved.
6  *
7  *   Redistribution and use in source and binary forms, with or without
8  *   modification, are permitted provided that the following conditions
9  *   are met:
10  *
11  *     * Redistributions of source code must retain the above copyright
12  *       notice, this list of conditions and the following disclaimer.
13  *     * Redistributions in binary form must reproduce the above copyright
14  *       notice, this list of conditions and the following disclaimer in
15  *       the documentation and/or other materials provided with the
16  *       distribution.
17  *     * Neither the name of Intel Corporation nor the names of its
18  *       contributors may be used to endorse or promote products derived
19  *       from this software without specific prior written permission.
20  *
21  *   THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
22  *   "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
23  *   LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
24  *   A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
25  *   OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
26  *   SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
27  *   LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
28  *   DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
29  *   THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
30  *   (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
31  *   OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
32  */
33 
34 #include "spdk/stdinc.h"
35 
36 #include "spdk/env.h"
37 #include "spdk/string.h"
38 #include "spdk/trace.h"
39 #include "spdk/util.h"
40 #include "spdk/barrier.h"
41 #include "spdk/log.h"
42 
43 static int g_trace_fd = -1;
44 static char g_shm_name[64];
45 
46 struct spdk_trace_histories *g_trace_histories;
47 
48 static inline struct spdk_trace_entry *
49 get_trace_entry(struct spdk_trace_history *history, uint64_t offset)
50 {
51 	return &history->entries[offset & (history->num_entries - 1)];
52 }
53 
54 void
55 _spdk_trace_record(uint64_t tsc, uint16_t tpoint_id, uint16_t poller_id, uint32_t size,
56 		   uint64_t object_id, int num_args, ...)
57 {
58 	struct spdk_trace_history *lcore_history;
59 	struct spdk_trace_entry *next_entry;
60 	struct spdk_trace_entry_buffer *buffer;
61 	struct spdk_trace_tpoint *tpoint;
62 	struct spdk_trace_argument *argument;
63 	unsigned lcore, i, offset, num_entries, arglen, argoff, curlen;
64 	uint64_t intval;
65 	void *argval;
66 	va_list vl;
67 
68 	lcore = spdk_env_get_current_core();
69 	if (lcore >= SPDK_TRACE_MAX_LCORE) {
70 		return;
71 	}
72 
73 	lcore_history = spdk_get_per_lcore_history(g_trace_histories, lcore);
74 	if (tsc == 0) {
75 		tsc = spdk_get_ticks();
76 	}
77 
78 	lcore_history->tpoint_count[tpoint_id]++;
79 
80 	tpoint = &g_trace_flags->tpoint[tpoint_id];
81 	/* Make sure that the number of arguments passed matches tracepoint definition */
82 	if (tpoint->num_args != num_args) {
83 		assert(0 && "Unexpected number of tracepoint arguments");
84 		return;
85 	}
86 
87 	/* Get next entry index in the circular buffer */
88 	next_entry = get_trace_entry(lcore_history, lcore_history->next_entry);
89 	next_entry->tsc = tsc;
90 	next_entry->tpoint_id = tpoint_id;
91 	next_entry->poller_id = poller_id;
92 	next_entry->size = size;
93 	next_entry->object_id = object_id;
94 
95 	num_entries = 1;
96 	buffer = (struct spdk_trace_entry_buffer *)next_entry;
97 	/* The initial offset needs to be adjusted by the fields present in the first entry
98 	 * (poller_id, size, etc.).
99 	 */
100 	offset = offsetof(struct spdk_trace_entry, args) -
101 		 offsetof(struct spdk_trace_entry_buffer, data);
102 
103 	va_start(vl, num_args);
104 	for (i = 0; i < tpoint->num_args; ++i) {
105 		argument = &tpoint->args[i];
106 		switch (argument->type) {
107 		case SPDK_TRACE_ARG_TYPE_STR:
108 			argval = va_arg(vl, void *);
109 			arglen = strnlen((const char *)argval, argument->size - 1) + 1;
110 			break;
111 		case SPDK_TRACE_ARG_TYPE_INT:
112 		case SPDK_TRACE_ARG_TYPE_PTR:
113 			intval = va_arg(vl, uint64_t);
114 			argval = &intval;
115 			arglen = sizeof(uint64_t);
116 			break;
117 		default:
118 			assert(0 && "Invalid trace argument type");
119 			return;
120 		}
121 
122 		/* Copy argument's data. For some argument types (strings) user is allowed to pass a
123 		 * value that is either larger or smaller than what's defined in the tracepoint's
124 		 * description. If the value is larger, we'll truncate it, while if it's smaller,
125 		 * we'll only fill portion of the buffer, without touching the rest. For instance,
126 		 * if the definition marks an argument as 40B and user passes 12B string, we'll only
127 		 * copy 13B (accounting for the NULL terminator).
128 		 */
129 		argoff = 0;
130 		while (argoff < argument->size) {
131 			/* Current buffer is full, we need to acquire another one */
132 			if (offset == sizeof(buffer->data)) {
133 				buffer = (struct spdk_trace_entry_buffer *) get_trace_entry(
134 						 lcore_history,
135 						 lcore_history->next_entry + num_entries);
136 				buffer->tpoint_id = SPDK_TRACE_MAX_TPOINT_ID;
137 				buffer->tsc = tsc;
138 				num_entries++;
139 				offset = 0;
140 			}
141 
142 			curlen = spdk_min(sizeof(buffer->data) - offset, argument->size - argoff);
143 			if (argoff < arglen) {
144 				assert(argval != NULL);
145 				memcpy(&buffer->data[offset], (uint8_t *)argval + argoff,
146 				       spdk_min(curlen, arglen - argoff));
147 			}
148 
149 			offset += curlen;
150 			argoff += curlen;
151 		}
152 
153 		/* Make sure that truncated strings are NULL-terminated */
154 		if (argument->type == SPDK_TRACE_ARG_TYPE_STR) {
155 			assert(offset > 0);
156 			buffer->data[offset - 1] = '\0';
157 		}
158 	}
159 	va_end(vl);
160 
161 	/* Ensure all elements of the trace entry are visible to outside trace tools */
162 	spdk_smp_wmb();
163 	lcore_history->next_entry += num_entries;
164 }
165 
166 int
167 spdk_trace_init(const char *shm_name, uint64_t num_entries)
168 {
169 	int i = 0;
170 	int histories_size;
171 	uint64_t lcore_offsets[SPDK_TRACE_MAX_LCORE + 1];
172 
173 	/* 0 entries requested - skip trace initialization */
174 	if (num_entries == 0) {
175 		return 0;
176 	}
177 
178 	lcore_offsets[0] = sizeof(struct spdk_trace_flags);
179 	for (i = 1; i < (int)SPDK_COUNTOF(lcore_offsets); i++) {
180 		lcore_offsets[i] = spdk_get_trace_history_size(num_entries) + lcore_offsets[i - 1];
181 	}
182 	histories_size = lcore_offsets[SPDK_TRACE_MAX_LCORE];
183 
184 	snprintf(g_shm_name, sizeof(g_shm_name), "%s", shm_name);
185 
186 	g_trace_fd = shm_open(shm_name, O_RDWR | O_CREAT, 0600);
187 	if (g_trace_fd == -1) {
188 		SPDK_ERRLOG("could not shm_open spdk_trace\n");
189 		SPDK_ERRLOG("errno=%d %s\n", errno, spdk_strerror(errno));
190 		return 1;
191 	}
192 
193 	if (ftruncate(g_trace_fd, histories_size) != 0) {
194 		SPDK_ERRLOG("could not truncate shm\n");
195 		goto trace_init_err;
196 	}
197 
198 	g_trace_histories = mmap(NULL, histories_size, PROT_READ | PROT_WRITE,
199 				 MAP_SHARED, g_trace_fd, 0);
200 	if (g_trace_histories == MAP_FAILED) {
201 		SPDK_ERRLOG("could not mmap shm\n");
202 		goto trace_init_err;
203 	}
204 
205 	/* TODO: On FreeBSD, mlock on shm_open'd memory doesn't seem to work.  Docs say that kern.ipc.shm_use_phys=1
206 	 * should allow it, but forcing that doesn't seem to work either.  So for now just skip mlock on FreeBSD
207 	 * altogether.
208 	 */
209 #if defined(__linux__)
210 	if (mlock(g_trace_histories, histories_size) != 0) {
211 		SPDK_ERRLOG("Could not mlock shm for tracing - %s.\n", spdk_strerror(errno));
212 		if (errno == ENOMEM) {
213 			SPDK_ERRLOG("Check /dev/shm for old tracing files that can be deleted.\n");
214 		}
215 		goto trace_init_err;
216 	}
217 #endif
218 
219 	memset(g_trace_histories, 0, histories_size);
220 
221 	g_trace_flags = &g_trace_histories->flags;
222 
223 	g_trace_flags->tsc_rate = spdk_get_ticks_hz();
224 
225 	for (i = 0; i < SPDK_TRACE_MAX_LCORE; i++) {
226 		struct spdk_trace_history *lcore_history;
227 
228 		g_trace_flags->lcore_history_offsets[i] = lcore_offsets[i];
229 		lcore_history = spdk_get_per_lcore_history(g_trace_histories, i);
230 		lcore_history->lcore = i;
231 		lcore_history->num_entries = num_entries;
232 	}
233 	g_trace_flags->lcore_history_offsets[SPDK_TRACE_MAX_LCORE] = lcore_offsets[SPDK_TRACE_MAX_LCORE];
234 
235 	spdk_trace_flags_init();
236 
237 	return 0;
238 
239 trace_init_err:
240 	if (g_trace_histories != MAP_FAILED) {
241 		munmap(g_trace_histories, histories_size);
242 	}
243 	close(g_trace_fd);
244 	g_trace_fd = -1;
245 	shm_unlink(shm_name);
246 	g_trace_histories = NULL;
247 
248 	return 1;
249 
250 }
251 
252 void
253 spdk_trace_cleanup(void)
254 {
255 	bool unlink;
256 	int i;
257 	struct spdk_trace_history *lcore_history;
258 
259 	if (g_trace_histories == NULL) {
260 		return;
261 	}
262 
263 	/*
264 	 * Only unlink the shm if there were no trace_entry recorded. This ensures the file
265 	 * can be used after this process exits/crashes for debugging.
266 	 * Note that we have to calculate this value before g_trace_histories gets unmapped.
267 	 */
268 	for (i = 0; i < SPDK_TRACE_MAX_LCORE; i++) {
269 		lcore_history = spdk_get_per_lcore_history(g_trace_histories, i);
270 		unlink = lcore_history->entries[0].tsc == 0;
271 		if (!unlink) {
272 			break;
273 		}
274 	}
275 
276 	munmap(g_trace_histories, sizeof(struct spdk_trace_histories));
277 	g_trace_histories = NULL;
278 	close(g_trace_fd);
279 
280 	if (unlink) {
281 		shm_unlink(g_shm_name);
282 	}
283 }
284