xref: /freebsd/tests/sys/pmc/pmc_log_test.c (revision 8f0789bee7abb2fdb2ff6d625f254533a138e6e8)
1 /*-
2  * SPDX-License-Identifier: BSD-2-Clause
3  *
4  * Copyright (c) 2026 Alexander Leidinger <netchild@FreeBSD.org>
5  *
6  * Redistribution and use in source and binary forms, with or without
7  * modification, are permitted provided that the following conditions
8  * are met:
9  * 1. Redistributions of source code must retain the above copyright
10  *    notice, this list of conditions and the following disclaimer.
11  * 2. Redistributions in binary form must reproduce the above copyright
12  *    notice, this list of conditions and the following disclaimer in the
13  *    documentation and/or other advertising materials provided with the
14  *    distribution.
15  *
16  * THIS SOFTWARE IS PROVIDED BY THE AUTHOR AND CONTRIBUTORS ``AS IS'' AND
17  * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
18  * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE
19  * ARE DISCLAIMED.  IN NO EVENT SHALL THE AUTHOR OR CONTRIBUTORS BE LIABLE
20  * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL
21  * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS
22  * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION)
23  * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT
24  * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY
25  * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF
26  * SUCH DAMAGE.
27  */
28 
29 /**
30  * @file
31  * Tests for the log file a sampling PMC writes through: which descriptors
32  * PMC_OP_CONFIGURELOG accepts, when a log is required at all, and what the
33  * descriptor-less log operations do without one.
34  *
35  * Two properties are asserted because they are easy to get backwards.  A
36  * sampling PMC does not as such need a log: PMC_F_NEEDS_LOGFILE covers
37  * only one attached to a process other than its owner, and system-mode
38  * PMCs, so a PMC that samples its owner starts with none.  And the
39  * descriptor need not be a regular file - a socket is accepted, and has to
40  * be: that is the shape pmcstat(8) uses for a pipe or a network peer.
41  *
42  * Log ownership is per process and sticky, a second PMC_OP_CONFIGURELOG
43  * being refused with EBUSY, so no case may configure a log the next one
44  * depends on; ATF's per-case process supplies that isolation, and the case
45  * needing a second fresh owner forks for it.
46  *
47  * The sampling cases skip where there is no hardware PMC, so the skip
48  * count is part of the result.
49  */
50 
51 #include <sys/param.h>
52 #include <sys/socket.h>
53 #include <sys/wait.h>
54 
55 #include <errno.h>
56 #include <fcntl.h>
57 #include <pmc.h>
58 #include <signal.h>
59 #include <stdint.h>
60 #include <stdlib.h>
61 #include <string.h>
62 #include <unistd.h>
63 
64 #include <atf-c.h>
65 
66 /**
67  * @internal
68  * Sampling needs a real counter, and which one it is does not matter, so try
69  * the usual spellings across vendors until one is accepted.
70  */
71 static const char *const hw_events[] = {
72 	"instructions", "inst_retired.any", "unhalted-core-cycles",
73 	"cycles", "cpu_clk_unhalted.thread", NULL
74 };
75 
76 #define	SAMPLE_RATE	10000
77 
78 static void
require_hwpmc(void)79 require_hwpmc(void)
80 {
81 
82 	if (pmc_init() != 0)
83 		atf_tc_skip("hwpmc(4) is not available");
84 }
85 
86 static int
alloc_sampling(pmc_id_t * idp,uint32_t flags)87 alloc_sampling(pmc_id_t *idp, uint32_t flags)
88 {
89 	int k;
90 
91 	for (k = 0; hw_events[k] != NULL; k++) {
92 		if (pmc_allocate(hw_events[k], PMC_MODE_TS, flags, PMC_CPU_ANY,
93 		    idp, SAMPLE_RATE) == 0)
94 			return (0);
95 	}
96 	return (-1);
97 }
98 
99 static pmc_id_t
require_sampling_pmc(uint32_t flags)100 require_sampling_pmc(uint32_t flags)
101 {
102 	pmc_id_t id;
103 
104 	if (alloc_sampling(&id, flags) != 0)
105 		atf_tc_skip("no hardware sampling PMC is allocatable: %s",
106 		    strerror(errno));
107 	return (id);
108 }
109 
110 /** @internal A writable regular file in the case's own work directory. */
111 static int
work_file(const char * name)112 work_file(const char *name)
113 {
114 	int fd;
115 
116 	fd = open(name, O_RDWR | O_CREAT | O_TRUNC, 0600);
117 	ATF_REQUIRE_MSG(fd >= 0, "open %s: %s", name, strerror(errno));
118 	return (fd);
119 }
120 
121 /**
122  * @internal
123  * A sampling PMC whose only target is its owner needs no log: pmc_start()
124  * attaches the owner implicitly when the target list is empty, and that is
125  * not the case PMC_F_NEEDS_LOGFILE covers.
126  */
127 ATF_TC_WITHOUT_HEAD(sampling_owner_needs_no_log);
ATF_TC_BODY(sampling_owner_needs_no_log,tc)128 ATF_TC_BODY(sampling_owner_needs_no_log, tc)
129 {
130 	pmc_id_t id;
131 
132 	require_hwpmc();
133 	id = require_sampling_pmc(0);
134 
135 	ATF_CHECK_MSG(pmc_start(id) == 0,
136 	    "a sampling PMC targeting its owner was refused a start without "
137 	    "a log: %s", strerror(errno));
138 	ATF_CHECK_MSG(pmc_stop(id) == 0, "pmc_stop: %s", strerror(errno));
139 	ATF_CHECK_MSG(pmc_release(id) == 0, "pmc_release: %s", strerror(errno));
140 }
141 
142 /**
143  * @internal
144  * The other half of the same rule: once the target is a different process,
145  * the samples have nowhere to go without a log and PMCSTART refuses.
146  */
147 ATF_TC_WITHOUT_HEAD(sampling_foreign_target_needs_a_log);
ATF_TC_BODY(sampling_foreign_target_needs_a_log,tc)148 ATF_TC_BODY(sampling_foreign_target_needs_a_log, tc)
149 {
150 	pmc_id_t id;
151 	pid_t child;
152 	int status, rc;
153 
154 	require_hwpmc();
155 	id = require_sampling_pmc(0);
156 
157 	ATF_REQUIRE((child = fork()) >= 0);
158 	if (child == 0) {
159 		/* Stay alive long enough to be a target. */
160 		(void)sleep(5);
161 		_exit(0);
162 	}
163 
164 	rc = pmc_attach(id, child);
165 	if (rc != 0) {
166 		(void)kill(child, SIGKILL);
167 		(void)waitpid(child, &status, 0);
168 		(void)pmc_release(id);
169 		atf_tc_skip("pmc_attach to a child failed: %s",
170 		    strerror(errno));
171 	}
172 
173 	errno = 0;
174 	ATF_CHECK_MSG(pmc_start(id) != 0,
175 	    "a sampling PMC attached to another process started with no log "
176 	    "configured");
177 	ATF_CHECK_MSG(errno == EDOOFUS, "pmc_start: expected EDOOFUS, got %s",
178 	    strerror(errno));
179 
180 	ATF_CHECK_MSG(pmc_detach(id, child) == 0, "pmc_detach: %s",
181 	    strerror(errno));
182 	(void)kill(child, SIGKILL);
183 	(void)waitpid(child, &status, 0);
184 	ATF_CHECK_MSG(pmc_release(id) == 0, "pmc_release: %s", strerror(errno));
185 }
186 
187 /**
188  * @internal
189  * Descriptors the kernel must refuse.  All three fail, so none of them
190  * leaves a log configured and one process can carry the whole case.
191  */
192 ATF_TC_WITHOUT_HEAD(configurelog_refuses_unwritable_fd);
ATF_TC_BODY(configurelog_refuses_unwritable_fd,tc)193 ATF_TC_BODY(configurelog_refuses_unwritable_fd, tc)
194 {
195 	int fd;
196 
197 	require_hwpmc();
198 
199 	/* Closed before the call. */
200 	fd = work_file("closed.pmclog");
201 	ATF_REQUIRE(close(fd) == 0);
202 	errno = 0;
203 	ATF_CHECK_MSG(pmc_configure_logfile(fd) != 0,
204 	    "a closed descriptor was accepted as a log");
205 	ATF_CHECK_MSG(errno == EBADF, "closed fd: expected EBADF, got %s",
206 	    strerror(errno));
207 
208 	/* Open, but not for writing: fget_write() has to refuse it. */
209 	fd = work_file("ro.pmclog");
210 	ATF_REQUIRE(close(fd) == 0);
211 	fd = open("ro.pmclog", O_RDONLY);
212 	ATF_REQUIRE_MSG(fd >= 0, "reopen read-only: %s", strerror(errno));
213 	errno = 0;
214 	ATF_CHECK_MSG(pmc_configure_logfile(fd) != 0,
215 	    "a read-only descriptor was accepted as a log");
216 	ATF_CHECK_MSG(errno == EBADF, "read-only fd: expected EBADF, got %s",
217 	    strerror(errno));
218 	(void)close(fd);
219 
220 	/* A directory, which can only ever be open read-only. */
221 	fd = open(".", O_RDONLY);
222 	ATF_REQUIRE_MSG(fd >= 0, "open .: %s", strerror(errno));
223 	errno = 0;
224 	ATF_CHECK_MSG(pmc_configure_logfile(fd) != 0,
225 	    "a directory was accepted as a log");
226 	ATF_CHECK_MSG(errno == EBADF, "directory fd: expected EBADF, got %s",
227 	    strerror(errno));
228 	(void)close(fd);
229 
230 	/*
231 	 * A negative descriptor means "deconfigure".  With nothing
232 	 * configured there is nothing to deconfigure, and the op refuses.
233 	 */
234 	errno = 0;
235 	ATF_CHECK_MSG(pmc_configure_logfile(-1) != 0,
236 	    "deconfiguring succeeded with no log configured");
237 	ATF_CHECK_MSG(errno == EINVAL, "fd -1: expected EINVAL, got %s",
238 	    strerror(errno));
239 }
240 
241 /**
242  * @internal
243  * A socket is a legitimate log destination - pmcstat(8) logs to one when
244  * told to pipe - so the fd check must not be narrowed to regular files.
245  */
246 ATF_TC_WITHOUT_HEAD(configurelog_accepts_a_socket);
ATF_TC_BODY(configurelog_accepts_a_socket,tc)247 ATF_TC_BODY(configurelog_accepts_a_socket, tc)
248 {
249 	int sv[2];
250 
251 	require_hwpmc();
252 
253 	if (socketpair(AF_UNIX, SOCK_STREAM, 0, sv) != 0)
254 		atf_tc_skip("socketpair: %s", strerror(errno));
255 
256 	ATF_CHECK_MSG(pmc_configure_logfile(sv[0]) == 0,
257 	    "a socket was refused as a log destination: %s", strerror(errno));
258 
259 	(void)pmc_close_logfile();
260 	(void)close(sv[0]);
261 	(void)close(sv[1]);
262 }
263 
264 /**
265  * @internal
266  * One log per owner: the second configure is refused while the first holds.
267  */
268 ATF_TC_WITHOUT_HEAD(configurelog_twice_is_refused);
ATF_TC_BODY(configurelog_twice_is_refused,tc)269 ATF_TC_BODY(configurelog_twice_is_refused, tc)
270 {
271 	int fd1, fd2;
272 
273 	require_hwpmc();
274 	fd1 = work_file("first.pmclog");
275 	fd2 = work_file("second.pmclog");
276 
277 	ATF_REQUIRE_MSG(pmc_configure_logfile(fd1) == 0,
278 	    "pmc_configure_logfile: %s", strerror(errno));
279 
280 	errno = 0;
281 	ATF_CHECK_MSG(pmc_configure_logfile(fd2) != 0,
282 	    "a second log was configured over a live one");
283 	ATF_CHECK_MSG(errno == EBUSY, "second configure: expected EBUSY, "
284 	    "got %s", strerror(errno));
285 
286 	(void)pmc_close_logfile();
287 	(void)close(fd1);
288 	(void)close(fd2);
289 }
290 
291 /**
292  * @internal
293  * The log operations take no descriptor and have to find the caller's owner
294  * record themselves.  A process that has never allocated a PMC has none.
295  */
296 ATF_TC_WITHOUT_HEAD(log_ops_without_an_owner);
ATF_TC_BODY(log_ops_without_an_owner,tc)297 ATF_TC_BODY(log_ops_without_an_owner, tc)
298 {
299 
300 	require_hwpmc();
301 
302 	errno = 0;
303 	ATF_CHECK_MSG(pmc_flush_logfile() != 0,
304 	    "pmc_flush_logfile succeeded with no owner record");
305 	ATF_CHECK_MSG(errno == EINVAL, "flush: expected EINVAL, got %s",
306 	    strerror(errno));
307 
308 	errno = 0;
309 	ATF_CHECK_MSG(pmc_close_logfile() != 0,
310 	    "pmc_close_logfile succeeded with no owner record");
311 	ATF_CHECK_MSG(errno == EINVAL, "close: expected EINVAL, got %s",
312 	    strerror(errno));
313 
314 	errno = 0;
315 	ATF_CHECK_MSG(pmc_writelog(0x5a5a5a5a) != 0,
316 	    "pmc_writelog succeeded with no owner record");
317 	ATF_CHECK_MSG(errno == EINVAL, "writelog: expected EINVAL, got %s",
318 	    strerror(errno));
319 }
320 
321 /**
322  * @internal
323  * The kernel takes its own reference on the log file, so userland closing
324  * its descriptor must not break logging or fault anything.
325  */
326 ATF_TC_WITHOUT_HEAD(log_survives_userland_closing_the_fd);
ATF_TC_BODY(log_survives_userland_closing_the_fd,tc)327 ATF_TC_BODY(log_survives_userland_closing_the_fd, tc)
328 {
329 	int fd;
330 
331 	require_hwpmc();
332 	fd = work_file("behind.pmclog");
333 
334 	ATF_REQUIRE_MSG(pmc_configure_logfile(fd) == 0,
335 	    "pmc_configure_logfile: %s", strerror(errno));
336 	ATF_REQUIRE_MSG(close(fd) == 0, "close: %s", strerror(errno));
337 
338 	ATF_CHECK_MSG(pmc_writelog(0xdeadbeef) == 0,
339 	    "writelog after the fd was closed in userland: %s",
340 	    strerror(errno));
341 	ATF_CHECK_MSG(pmc_flush_logfile() == 0,
342 	    "flush after the fd was closed in userland: %s", strerror(errno));
343 	ATF_CHECK_MSG(pmc_close_logfile() == 0,
344 	    "close after the fd was closed in userland: %s", strerror(errno));
345 }
346 
347 /**
348  * @internal
349  * A write error on the log has to reach userland rather than be swallowed.
350  * /dev/full accepts the configure and fails every write with ENOSPC, which
351  * the flush - which waits for the buffers to be written - reports.
352  */
353 ATF_TC_WITHOUT_HEAD(log_write_error_is_reported);
ATF_TC_BODY(log_write_error_is_reported,tc)354 ATF_TC_BODY(log_write_error_is_reported, tc)
355 {
356 	int fd;
357 
358 	require_hwpmc();
359 
360 	if ((fd = open("/dev/full", O_WRONLY)) < 0)
361 		atf_tc_skip("/dev/full: %s", strerror(errno));
362 
363 	ATF_REQUIRE_MSG(pmc_configure_logfile(fd) == 0,
364 	    "/dev/full was refused as a log: %s", strerror(errno));
365 
366 	ATF_REQUIRE_MSG(pmc_writelog(0x1234) == 0, "pmc_writelog: %s",
367 	    strerror(errno));
368 
369 	errno = 0;
370 	ATF_CHECK_MSG(pmc_flush_logfile() != 0,
371 	    "flushing a log on a full device reported success");
372 	ATF_CHECK_MSG(errno == ENOSPC, "flush: expected ENOSPC, got %s",
373 	    strerror(errno));
374 
375 	(void)close(fd);
376 }
377 
378 /**
379  * @internal
380  * Process exit is a teardown path of its own: the owner leaves with the PMC
381  * running and the log still configured, and the kernel has to unwind both.
382  * The child does no cleanup on purpose.  A wedge or a fault here shows up as
383  * a signal or a timeout rather than a failed assertion, so the case also
384  * confirms hwpmc is still usable afterwards.
385  */
386 ATF_TC_WITHOUT_HEAD(owner_exit_with_log_and_running_pmc);
ATF_TC_BODY(owner_exit_with_log_and_running_pmc,tc)387 ATF_TC_BODY(owner_exit_with_log_and_running_pmc, tc)
388 {
389 	pmc_id_t id;
390 	pid_t child;
391 	int status;
392 
393 	require_hwpmc();
394 
395 	/* Establish up front that this machine can sample at all. */
396 	id = require_sampling_pmc(PMC_F_CALLCHAIN);
397 	ATF_REQUIRE(pmc_release(id) == 0);
398 
399 	ATF_REQUIRE((child = fork()) >= 0);
400 	if (child == 0) {
401 		volatile unsigned long sink = 0;
402 		unsigned long i;
403 		pmc_id_t cid;
404 		int fd;
405 
406 		if (pmc_init() != 0)
407 			_exit(10);
408 		if ((fd = open("owner-exit.pmclog",
409 		    O_RDWR | O_CREAT | O_TRUNC, 0600)) < 0)
410 			_exit(11);
411 		if (pmc_configure_logfile(fd) != 0)
412 			_exit(12);
413 		if (alloc_sampling(&cid, PMC_F_CALLCHAIN) != 0)
414 			_exit(13);
415 		if (pmc_start(cid) != 0)
416 			_exit(14);
417 		for (i = 0; i < 20000000; i++)
418 			sink += i;
419 		/* No stop, no release, no close: exit is the teardown. */
420 		_exit(0);
421 	}
422 
423 	ATF_REQUIRE(waitpid(child, &status, 0) == child);
424 	ATF_REQUIRE_MSG(!WIFSIGNALED(status),
425 	    "the owner died on signal %d while exiting with a live PMC and a "
426 	    "configured log", WIFSIGNALED(status) ? WTERMSIG(status) : 0);
427 	ATF_REQUIRE_MSG(WIFEXITED(status) && WEXITSTATUS(status) == 0,
428 	    "the child could not set up the case (exit %d)",
429 	    WIFEXITED(status) ? WEXITSTATUS(status) : -1);
430 
431 	/* The owner's teardown must not have left the driver unusable. */
432 	ATF_CHECK_MSG(alloc_sampling(&id, 0) == 0,
433 	    "no sampling PMC could be allocated after an owner exited with "
434 	    "one running: %s", strerror(errno));
435 	if (id != PMC_ID_INVALID)
436 		ATF_CHECK(pmc_release(id) == 0);
437 }
438 
ATF_TP_ADD_TCS(tp)439 ATF_TP_ADD_TCS(tp)
440 {
441 
442 	ATF_TP_ADD_TC(tp, sampling_owner_needs_no_log);
443 	ATF_TP_ADD_TC(tp, sampling_foreign_target_needs_a_log);
444 	ATF_TP_ADD_TC(tp, configurelog_refuses_unwritable_fd);
445 	ATF_TP_ADD_TC(tp, configurelog_accepts_a_socket);
446 	ATF_TP_ADD_TC(tp, configurelog_twice_is_refused);
447 	ATF_TP_ADD_TC(tp, log_ops_without_an_owner);
448 	ATF_TP_ADD_TC(tp, log_survives_userland_closing_the_fd);
449 	ATF_TP_ADD_TC(tp, log_write_error_is_reported);
450 	ATF_TP_ADD_TC(tp, owner_exit_with_log_and_running_pmc);
451 
452 	return (atf_no_error());
453 }
454