xref: /freebsd/sys/contrib/openzfs/module/os/linux/zfs/zfs_debug.c (revision 5956d97f4b3204318ceb6aa9c77bd0bc6ea87a41)
1 /*
2  * CDDL HEADER START
3  *
4  * The contents of this file are subject to the terms of the
5  * Common Development and Distribution License (the "License").
6  * You may not use this file except in compliance with the License.
7  *
8  * You can obtain a copy of the license at usr/src/OPENSOLARIS.LICENSE
9  * or http://www.opensolaris.org/os/licensing.
10  * See the License for the specific language governing permissions
11  * and limitations under the License.
12  *
13  * When distributing Covered Code, include this CDDL HEADER in each
14  * file and include the License file at usr/src/OPENSOLARIS.LICENSE.
15  * If applicable, add the following below this CDDL HEADER, with the
16  * fields enclosed by brackets "[]" replaced with your own identifying
17  * information: Portions Copyright [yyyy] [name of copyright owner]
18  *
19  * CDDL HEADER END
20  */
21 /*
22  * Copyright (c) 2010, Oracle and/or its affiliates. All rights reserved.
23  * Copyright (c) 2012, 2014 by Delphix. All rights reserved.
24  */
25 
26 #include <sys/zfs_context.h>
27 #include <sys/trace_zfs.h>
28 
29 typedef struct zfs_dbgmsg {
30 	procfs_list_node_t	zdm_node;
31 	uint64_t		zdm_timestamp;
32 	int			zdm_size;
33 	char			zdm_msg[1]; /* variable length allocation */
34 } zfs_dbgmsg_t;
35 
36 static procfs_list_t zfs_dbgmsgs;
37 static int zfs_dbgmsg_size = 0;
38 int zfs_dbgmsg_maxsize = 4<<20; /* 4MB */
39 
40 /*
41  * Internal ZFS debug messages are enabled by default.
42  *
43  * # Print debug messages
44  * cat /proc/spl/kstat/zfs/dbgmsg
45  *
46  * # Disable the kernel debug message log.
47  * echo 0 > /sys/module/zfs/parameters/zfs_dbgmsg_enable
48  *
49  * # Clear the kernel debug message log.
50  * echo 0 >/proc/spl/kstat/zfs/dbgmsg
51  */
52 int zfs_dbgmsg_enable = B_TRUE;
53 
54 static int
55 zfs_dbgmsg_show_header(struct seq_file *f)
56 {
57 	seq_printf(f, "%-12s %-8s\n", "timestamp", "message");
58 	return (0);
59 }
60 
61 static int
62 zfs_dbgmsg_show(struct seq_file *f, void *p)
63 {
64 	zfs_dbgmsg_t *zdm = (zfs_dbgmsg_t *)p;
65 	seq_printf(f, "%-12llu %-s\n",
66 	    (u_longlong_t)zdm->zdm_timestamp, zdm->zdm_msg);
67 	return (0);
68 }
69 
70 static void
71 zfs_dbgmsg_purge(int max_size)
72 {
73 	while (zfs_dbgmsg_size > max_size) {
74 		zfs_dbgmsg_t *zdm = list_remove_head(&zfs_dbgmsgs.pl_list);
75 		if (zdm == NULL)
76 			return;
77 
78 		int size = zdm->zdm_size;
79 		kmem_free(zdm, size);
80 		zfs_dbgmsg_size -= size;
81 	}
82 }
83 
84 static int
85 zfs_dbgmsg_clear(procfs_list_t *procfs_list)
86 {
87 	(void) procfs_list;
88 	mutex_enter(&zfs_dbgmsgs.pl_lock);
89 	zfs_dbgmsg_purge(0);
90 	mutex_exit(&zfs_dbgmsgs.pl_lock);
91 	return (0);
92 }
93 
94 void
95 zfs_dbgmsg_init(void)
96 {
97 	procfs_list_install("zfs",
98 	    NULL,
99 	    "dbgmsg",
100 	    0600,
101 	    &zfs_dbgmsgs,
102 	    zfs_dbgmsg_show,
103 	    zfs_dbgmsg_show_header,
104 	    zfs_dbgmsg_clear,
105 	    offsetof(zfs_dbgmsg_t, zdm_node));
106 }
107 
108 void
109 zfs_dbgmsg_fini(void)
110 {
111 	procfs_list_uninstall(&zfs_dbgmsgs);
112 	zfs_dbgmsg_purge(0);
113 
114 	/*
115 	 * TODO - decide how to make this permanent
116 	 */
117 #ifdef _KERNEL
118 	procfs_list_destroy(&zfs_dbgmsgs);
119 #endif
120 }
121 
122 void
123 __set_error(const char *file, const char *func, int line, int err)
124 {
125 	/*
126 	 * To enable this:
127 	 *
128 	 * $ echo 512 >/sys/module/zfs/parameters/zfs_flags
129 	 */
130 	if (zfs_flags & ZFS_DEBUG_SET_ERROR)
131 		__dprintf(B_FALSE, file, func, line, "error %lu",
132 		    (ulong_t)err);
133 }
134 
135 void
136 __zfs_dbgmsg(char *buf)
137 {
138 	int size = sizeof (zfs_dbgmsg_t) + strlen(buf);
139 	zfs_dbgmsg_t *zdm = kmem_zalloc(size, KM_SLEEP);
140 	zdm->zdm_size = size;
141 	zdm->zdm_timestamp = gethrestime_sec();
142 	strcpy(zdm->zdm_msg, buf);
143 
144 	mutex_enter(&zfs_dbgmsgs.pl_lock);
145 	procfs_list_add(&zfs_dbgmsgs, zdm);
146 	zfs_dbgmsg_size += size;
147 	zfs_dbgmsg_purge(MAX(zfs_dbgmsg_maxsize, 0));
148 	mutex_exit(&zfs_dbgmsgs.pl_lock);
149 }
150 
151 #ifdef _KERNEL
152 
153 void
154 __dprintf(boolean_t dprint, const char *file, const char *func,
155     int line, const char *fmt, ...)
156 {
157 	const char *newfile;
158 	va_list adx;
159 	size_t size;
160 	char *buf;
161 	char *nl;
162 	int i;
163 	char *prefix = (dprint) ? "dprintf: " : "";
164 
165 	size = 1024;
166 	buf = kmem_alloc(size, KM_SLEEP);
167 
168 	/*
169 	 * Get rid of annoying prefix to filename.
170 	 */
171 	newfile = strrchr(file, '/');
172 	if (newfile != NULL) {
173 		newfile = newfile + 1; /* Get rid of leading / */
174 	} else {
175 		newfile = file;
176 	}
177 
178 	i = snprintf(buf, size, "%s%s:%d:%s(): ", prefix, newfile, line, func);
179 
180 	if (i < size) {
181 		va_start(adx, fmt);
182 		(void) vsnprintf(buf + i, size - i, fmt, adx);
183 		va_end(adx);
184 	}
185 
186 	/*
187 	 * Get rid of trailing newline for dprintf logs.
188 	 */
189 	if (dprint && buf[0] != '\0') {
190 		nl = &buf[strlen(buf) - 1];
191 		if (*nl == '\n')
192 			*nl = '\0';
193 	}
194 
195 	/*
196 	 * To get this data enable the zfs__dprintf trace point as shown:
197 	 *
198 	 * # Enable zfs__dprintf tracepoint, clear the tracepoint ring buffer
199 	 * $ echo 1 > /sys/kernel/debug/tracing/events/zfs/enable
200 	 * $ echo 0 > /sys/kernel/debug/tracing/trace
201 	 *
202 	 * # Dump the ring buffer.
203 	 * $ cat /sys/kernel/debug/tracing/trace
204 	 */
205 	DTRACE_PROBE1(zfs__dprintf, char *, buf);
206 
207 	/*
208 	 * To get this data:
209 	 *
210 	 * $ cat /proc/spl/kstat/zfs/dbgmsg
211 	 *
212 	 * To clear the buffer:
213 	 * $ echo 0 > /proc/spl/kstat/zfs/dbgmsg
214 	 */
215 	__zfs_dbgmsg(buf);
216 
217 	kmem_free(buf, size);
218 }
219 
220 #else
221 
222 void
223 zfs_dbgmsg_print(const char *tag)
224 {
225 	ssize_t ret __attribute__((unused));
226 
227 	/*
228 	 * We use write() in this function instead of printf()
229 	 * so it is safe to call from a signal handler.
230 	 */
231 	ret = write(STDOUT_FILENO, "ZFS_DBGMSG(", 11);
232 	ret = write(STDOUT_FILENO, tag, strlen(tag));
233 	ret = write(STDOUT_FILENO, ") START:\n", 9);
234 
235 	mutex_enter(&zfs_dbgmsgs.pl_lock);
236 	for (zfs_dbgmsg_t *zdm = list_head(&zfs_dbgmsgs.pl_list); zdm != NULL;
237 	    zdm = list_next(&zfs_dbgmsgs.pl_list, zdm)) {
238 		ret = write(STDOUT_FILENO, zdm->zdm_msg,
239 		    strlen(zdm->zdm_msg));
240 		ret = write(STDOUT_FILENO, "\n", 1);
241 	}
242 
243 	ret = write(STDOUT_FILENO, "ZFS_DBGMSG(", 11);
244 	ret = write(STDOUT_FILENO, tag, strlen(tag));
245 	ret = write(STDOUT_FILENO, ") END\n", 6);
246 
247 	mutex_exit(&zfs_dbgmsgs.pl_lock);
248 }
249 #endif /* _KERNEL */
250 
251 #ifdef _KERNEL
252 module_param(zfs_dbgmsg_enable, int, 0644);
253 MODULE_PARM_DESC(zfs_dbgmsg_enable, "Enable ZFS debug message log");
254 
255 module_param(zfs_dbgmsg_maxsize, int, 0644);
256 MODULE_PARM_DESC(zfs_dbgmsg_maxsize, "Maximum ZFS debug log size");
257 #endif
258