1/*-
2 * Copyright (c) 2017 Colin Percival
3 * All rights reserved.
4 *
5 * Redistribution and use in source and binary forms, with or without
6 * modification, are permitted provided that the following conditions
7 * are met:
8 * 1. Redistributions of source code must retain the above copyright
9 *    notice, this list of conditions and the following disclaimer.
10 * 2. Redistributions in binary form must reproduce the above copyright
11 *    notice, this list of conditions and the following disclaimer in the
12 *    documentation and/or other materials provided with the distribution.
13 *
14 * THIS SOFTWARE IS PROVIDED BY THE AUTHOR AND CONTRIBUTORS ``AS IS'' AND
15 * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
16 * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE
17 * ARE DISCLAIMED.  IN NO EVENT SHALL THE AUTHOR OR CONTRIBUTORS BE LIABLE
18 * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL
19 * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS
20 * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION)
21 * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT
22 * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY
23 * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF
24 * SUCH DAMAGE.
25 */
26
27#include <sys/param.h>
28#include <sys/kernel.h>
29#include <sys/linker.h>
30#include <sys/malloc.h>
31#include <sys/proc.h>
32#include <sys/sbuf.h>
33#include <sys/sysctl.h>
34#include <sys/systm.h>
35#include <sys/tslog.h>
36
37#include <machine/atomic.h>
38#include <machine/cpu.h>
39
40#ifndef TSLOGSIZE
41#define TSLOGSIZE 262144
42#endif
43
44static volatile long nrecs = 0;
45static struct timestamp {
46	void * td;
47	int type;
48	const char * f;
49	const char * s;
50	uint64_t tsc;
51} timestamps[TSLOGSIZE];
52
53void
54tslog(void * td, int type, const char * f, const char * s)
55{
56	uint64_t tsc = get_cyclecount();
57	long pos;
58
59	/* A NULL thread is thread0 before curthread is set. */
60	if (td == NULL)
61		td = &thread0;
62
63	/* Grab a slot. */
64	pos = atomic_fetchadd_long(&nrecs, 1);
65
66	/* Store record. */
67	if (pos < nitems(timestamps)) {
68		timestamps[pos].td = td;
69		timestamps[pos].type = type;
70		timestamps[pos].f = f;
71		timestamps[pos].s = s;
72		timestamps[pos].tsc = tsc;
73	}
74}
75
76static int
77sysctl_debug_tslog(SYSCTL_HANDLER_ARGS)
78{
79	int error;
80	struct sbuf *sb;
81	size_t i, limit;
82	caddr_t loader_tslog;
83	void * loader_tslog_buf;
84	size_t loader_tslog_len;
85
86	/*
87	 * This code can race against the code in tslog() which stores
88	 * records: Theoretically we could end up reading a record after
89	 * its slots have been reserved but before it has been written.
90	 * Since this code takes orders of magnitude longer to run than
91	 * tslog() takes to write a record, it is highly unlikely that
92	 * anyone will ever experience this race.
93	 */
94	sb = sbuf_new_for_sysctl(NULL, NULL, 1024, req);
95
96	/* Get data from the boot loader, if it provided any. */
97	loader_tslog = preload_search_by_type("TSLOG data");
98	if (loader_tslog != NULL) {
99		loader_tslog_buf = preload_fetch_addr(loader_tslog);
100		loader_tslog_len = preload_fetch_size(loader_tslog);
101		sbuf_bcat(sb, loader_tslog_buf, loader_tslog_len);
102	}
103
104	/* Add data logged within the kernel. */
105	limit = MIN(nrecs, nitems(timestamps));
106	for (i = 0; i < limit; i++) {
107		sbuf_printf(sb, "%p", timestamps[i].td);
108		sbuf_printf(sb, " %llu",
109		    (unsigned long long)timestamps[i].tsc);
110		switch (timestamps[i].type) {
111		case TS_ENTER:
112			sbuf_cat(sb, " ENTER");
113			break;
114		case TS_EXIT:
115			sbuf_cat(sb, " EXIT");
116			break;
117		case TS_THREAD:
118			sbuf_cat(sb, " THREAD");
119			break;
120		case TS_EVENT:
121			sbuf_cat(sb, " EVENT");
122			break;
123		}
124		sbuf_printf(sb, " %s", timestamps[i].f ? timestamps[i].f : "(null)");
125		if (timestamps[i].s)
126			sbuf_printf(sb, " %s\n", timestamps[i].s);
127		else
128			sbuf_putc(sb, '\n');
129	}
130	error = sbuf_finish(sb);
131	sbuf_delete(sb);
132	return (error);
133}
134
135SYSCTL_PROC(_debug, OID_AUTO, tslog,
136    CTLTYPE_STRING|CTLFLAG_RD|CTLFLAG_MPSAFE|CTLFLAG_SKIP,
137    0, 0, sysctl_debug_tslog, "", "Dump recorded event timestamps");
138
139MALLOC_DEFINE(M_TSLOGUSER, "tsloguser", "Strings used by userland tslog");
140static struct procdata {
141	pid_t ppid;
142	uint64_t tsc_forked;
143	uint64_t tsc_exited;
144	char * execname;
145	char * namei;
146	int reused;
147} procs[PID_MAX + 1];
148
149void
150tslog_user(pid_t pid, pid_t ppid, const char * execname, const char * namei)
151{
152	uint64_t tsc = get_cyclecount();
153
154	/* If we wrapped, do nothing. */
155	if (procs[pid].reused)
156		return;
157
158	/* If we have a ppid, we're recording a fork. */
159	if (ppid != (pid_t)(-1)) {
160		/* If we have a ppid already, we wrapped. */
161		if (procs[pid].ppid) {
162			procs[pid].reused = 1;
163			return;
164		}
165
166		/* Fill in some fields. */
167		procs[pid].ppid = ppid;
168		procs[pid].tsc_forked = tsc;
169		return;
170	}
171
172	/* If we have an execname, record it. */
173	if (execname != NULL) {
174		if (procs[pid].execname != NULL)
175			free(procs[pid].execname, M_TSLOGUSER);
176		procs[pid].execname = strdup(execname, M_TSLOGUSER);
177		return;
178	}
179
180	/* Record the first namei for the process. */
181	if (namei != NULL) {
182		if (procs[pid].namei == NULL)
183			procs[pid].namei = strdup(namei, M_TSLOGUSER);
184		return;
185	}
186
187	/* Otherwise we're recording an exit. */
188	procs[pid].tsc_exited = tsc;
189}
190
191static int
192sysctl_debug_tslog_user(SYSCTL_HANDLER_ARGS)
193{
194	int error;
195	struct sbuf *sb;
196	pid_t pid;
197
198	sb = sbuf_new_for_sysctl(NULL, NULL, 1024, req);
199
200	/* Export the data we logged. */
201	for (pid = 0; pid <= PID_MAX; pid++) {
202		sbuf_printf(sb, "%zu", (size_t)pid);
203		sbuf_printf(sb, " %zu", (size_t)procs[pid].ppid);
204		sbuf_printf(sb, " %llu",
205		    (unsigned long long)procs[pid].tsc_forked);
206		sbuf_printf(sb, " %llu",
207		    (unsigned long long)procs[pid].tsc_exited);
208		sbuf_printf(sb, " \"%s\"", procs[pid].execname ?
209		    procs[pid].execname : "");
210		sbuf_printf(sb, " \"%s\"", procs[pid].namei ?
211		    procs[pid].namei : "");
212		sbuf_putc(sb, '\n');
213	}
214	error = sbuf_finish(sb);
215	sbuf_delete(sb);
216	return (error);
217}
218
219SYSCTL_PROC(_debug, OID_AUTO, tslog_user,
220    CTLTYPE_STRING|CTLFLAG_RD|CTLFLAG_MPSAFE|CTLFLAG_SKIP,
221    0, 0, sysctl_debug_tslog_user,
222    "", "Dump recorded userland event timestamps");
223