xref: /spdk/lib/trace/trace.c (revision 510f4c134a21b45ff3a5add9ebc6c6cf7e49aeab)
1 /*   SPDX-License-Identifier: BSD-3-Clause
2  *   Copyright (c) Intel Corporation.
3  *   All rights reserved.
4  */
5 
6 #include "spdk/stdinc.h"
7 
8 #include "spdk/env.h"
9 #include "spdk/string.h"
10 #include "spdk/trace.h"
11 #include "spdk/util.h"
12 #include "spdk/barrier.h"
13 #include "spdk/log.h"
14 
15 static int g_trace_fd = -1;
16 static char g_shm_name[64];
17 
18 struct spdk_trace_histories *g_trace_histories;
19 
20 static inline struct spdk_trace_entry *
21 get_trace_entry(struct spdk_trace_history *history, uint64_t offset)
22 {
23 	return &history->entries[offset & (history->num_entries - 1)];
24 }
25 
26 void
27 _spdk_trace_record(uint64_t tsc, uint16_t tpoint_id, uint16_t poller_id, uint32_t size,
28 		   uint64_t object_id, int num_args, ...)
29 {
30 	struct spdk_trace_history *lcore_history;
31 	struct spdk_trace_entry *next_entry;
32 	struct spdk_trace_entry_buffer *buffer;
33 	struct spdk_trace_tpoint *tpoint;
34 	struct spdk_trace_argument *argument;
35 	unsigned lcore, i, offset, num_entries, arglen, argoff, curlen;
36 	uint64_t intval;
37 	void *argval;
38 	va_list vl;
39 
40 	lcore = spdk_env_get_current_core();
41 	if (lcore >= SPDK_TRACE_MAX_LCORE) {
42 		return;
43 	}
44 
45 	lcore_history = spdk_get_per_lcore_history(g_trace_histories, lcore);
46 	if (tsc == 0) {
47 		tsc = spdk_get_ticks();
48 	}
49 
50 	lcore_history->tpoint_count[tpoint_id]++;
51 
52 	tpoint = &g_trace_flags->tpoint[tpoint_id];
53 	/* Make sure that the number of arguments passed matches tracepoint definition */
54 	if (tpoint->num_args != num_args) {
55 		assert(0 && "Unexpected number of tracepoint arguments");
56 		return;
57 	}
58 
59 	/* Get next entry index in the circular buffer */
60 	next_entry = get_trace_entry(lcore_history, lcore_history->next_entry);
61 	next_entry->tsc = tsc;
62 	next_entry->tpoint_id = tpoint_id;
63 	next_entry->poller_id = poller_id;
64 	next_entry->size = size;
65 	next_entry->object_id = object_id;
66 
67 	num_entries = 1;
68 	buffer = (struct spdk_trace_entry_buffer *)next_entry;
69 	/* The initial offset needs to be adjusted by the fields present in the first entry
70 	 * (poller_id, size, etc.).
71 	 */
72 	offset = offsetof(struct spdk_trace_entry, args) -
73 		 offsetof(struct spdk_trace_entry_buffer, data);
74 
75 	va_start(vl, num_args);
76 	for (i = 0; i < tpoint->num_args; ++i) {
77 		argument = &tpoint->args[i];
78 		switch (argument->type) {
79 		case SPDK_TRACE_ARG_TYPE_STR:
80 			argval = va_arg(vl, void *);
81 			arglen = strnlen((const char *)argval, argument->size - 1) + 1;
82 			break;
83 		case SPDK_TRACE_ARG_TYPE_INT:
84 		case SPDK_TRACE_ARG_TYPE_PTR:
85 			if (argument->size == 8) {
86 				intval = va_arg(vl, uint64_t);
87 			} else {
88 				intval = va_arg(vl, uint32_t);
89 			}
90 			argval = &intval;
91 			arglen = argument->size;
92 			break;
93 		default:
94 			assert(0 && "Invalid trace argument type");
95 			return;
96 		}
97 
98 		/* Copy argument's data. For some argument types (strings) user is allowed to pass a
99 		 * value that is either larger or smaller than what's defined in the tracepoint's
100 		 * description. If the value is larger, we'll truncate it, while if it's smaller,
101 		 * we'll only fill portion of the buffer, without touching the rest. For instance,
102 		 * if the definition marks an argument as 40B and user passes 12B string, we'll only
103 		 * copy 13B (accounting for the NULL terminator).
104 		 */
105 		argoff = 0;
106 		while (argoff < argument->size) {
107 			/* Current buffer is full, we need to acquire another one */
108 			if (offset == sizeof(buffer->data)) {
109 				buffer = (struct spdk_trace_entry_buffer *) get_trace_entry(
110 						 lcore_history,
111 						 lcore_history->next_entry + num_entries);
112 				buffer->tpoint_id = SPDK_TRACE_MAX_TPOINT_ID;
113 				buffer->tsc = tsc;
114 				num_entries++;
115 				offset = 0;
116 			}
117 
118 			curlen = spdk_min(sizeof(buffer->data) - offset, argument->size - argoff);
119 			if (argoff < arglen) {
120 				assert(argval != NULL);
121 				memcpy(&buffer->data[offset], (uint8_t *)argval + argoff,
122 				       spdk_min(curlen, arglen - argoff));
123 			}
124 
125 			offset += curlen;
126 			argoff += curlen;
127 		}
128 
129 		/* Make sure that truncated strings are NULL-terminated */
130 		if (argument->type == SPDK_TRACE_ARG_TYPE_STR) {
131 			assert(offset > 0);
132 			buffer->data[offset - 1] = '\0';
133 		}
134 	}
135 	va_end(vl);
136 
137 	/* Ensure all elements of the trace entry are visible to outside trace tools */
138 	spdk_smp_wmb();
139 	lcore_history->next_entry += num_entries;
140 }
141 
142 int
143 spdk_trace_init(const char *shm_name, uint64_t num_entries)
144 {
145 	int i = 0;
146 	int histories_size;
147 	uint64_t lcore_offsets[SPDK_TRACE_MAX_LCORE + 1];
148 
149 	/* 0 entries requested - skip trace initialization */
150 	if (num_entries == 0) {
151 		return 0;
152 	}
153 
154 	lcore_offsets[0] = sizeof(struct spdk_trace_flags);
155 	for (i = 1; i < (int)SPDK_COUNTOF(lcore_offsets); i++) {
156 		lcore_offsets[i] = spdk_get_trace_history_size(num_entries) + lcore_offsets[i - 1];
157 	}
158 	histories_size = lcore_offsets[SPDK_TRACE_MAX_LCORE];
159 
160 	snprintf(g_shm_name, sizeof(g_shm_name), "%s", shm_name);
161 
162 	g_trace_fd = shm_open(shm_name, O_RDWR | O_CREAT, 0600);
163 	if (g_trace_fd == -1) {
164 		SPDK_ERRLOG("could not shm_open spdk_trace\n");
165 		SPDK_ERRLOG("errno=%d %s\n", errno, spdk_strerror(errno));
166 		return 1;
167 	}
168 
169 	if (ftruncate(g_trace_fd, histories_size) != 0) {
170 		SPDK_ERRLOG("could not truncate shm\n");
171 		goto trace_init_err;
172 	}
173 
174 	g_trace_histories = mmap(NULL, histories_size, PROT_READ | PROT_WRITE,
175 				 MAP_SHARED, g_trace_fd, 0);
176 	if (g_trace_histories == MAP_FAILED) {
177 		SPDK_ERRLOG("could not mmap shm\n");
178 		goto trace_init_err;
179 	}
180 
181 	/* TODO: On FreeBSD, mlock on shm_open'd memory doesn't seem to work.  Docs say that kern.ipc.shm_use_phys=1
182 	 * should allow it, but forcing that doesn't seem to work either.  So for now just skip mlock on FreeBSD
183 	 * altogether.
184 	 */
185 #if defined(__linux__)
186 	if (mlock(g_trace_histories, histories_size) != 0) {
187 		SPDK_ERRLOG("Could not mlock shm for tracing - %s.\n", spdk_strerror(errno));
188 		if (errno == ENOMEM) {
189 			SPDK_ERRLOG("Check /dev/shm for old tracing files that can be deleted.\n");
190 		}
191 		goto trace_init_err;
192 	}
193 #endif
194 
195 	memset(g_trace_histories, 0, histories_size);
196 
197 	g_trace_flags = &g_trace_histories->flags;
198 
199 	g_trace_flags->tsc_rate = spdk_get_ticks_hz();
200 
201 	for (i = 0; i < SPDK_TRACE_MAX_LCORE; i++) {
202 		struct spdk_trace_history *lcore_history;
203 
204 		g_trace_flags->lcore_history_offsets[i] = lcore_offsets[i];
205 		lcore_history = spdk_get_per_lcore_history(g_trace_histories, i);
206 		lcore_history->lcore = i;
207 		lcore_history->num_entries = num_entries;
208 	}
209 	g_trace_flags->lcore_history_offsets[SPDK_TRACE_MAX_LCORE] = lcore_offsets[SPDK_TRACE_MAX_LCORE];
210 
211 	spdk_trace_flags_init();
212 
213 	return 0;
214 
215 trace_init_err:
216 	if (g_trace_histories != MAP_FAILED) {
217 		munmap(g_trace_histories, histories_size);
218 	}
219 	close(g_trace_fd);
220 	g_trace_fd = -1;
221 	shm_unlink(shm_name);
222 	g_trace_histories = NULL;
223 
224 	return 1;
225 
226 }
227 
228 void
229 spdk_trace_cleanup(void)
230 {
231 	bool unlink;
232 	int i;
233 	struct spdk_trace_history *lcore_history;
234 
235 	if (g_trace_histories == NULL) {
236 		return;
237 	}
238 
239 	/*
240 	 * Only unlink the shm if there were no trace_entry recorded. This ensures the file
241 	 * can be used after this process exits/crashes for debugging.
242 	 * Note that we have to calculate this value before g_trace_histories gets unmapped.
243 	 */
244 	for (i = 0; i < SPDK_TRACE_MAX_LCORE; i++) {
245 		lcore_history = spdk_get_per_lcore_history(g_trace_histories, i);
246 		unlink = lcore_history->entries[0].tsc == 0;
247 		if (!unlink) {
248 			break;
249 		}
250 	}
251 
252 	munmap(g_trace_histories, sizeof(struct spdk_trace_histories));
253 	g_trace_histories = NULL;
254 	close(g_trace_fd);
255 
256 	if (unlink) {
257 		shm_unlink(g_shm_name);
258 	}
259 }
260