xref: /illumos-gate/usr/src/uts/common/io/ib/clients/rdsv3/rdsv3_debug.c (revision cadbfdc3bdb156e92d7a88978bc98ea87f6e037f)
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  */
24 #include <sys/types.h>
25 #include <sys/varargs.h>
26 #include <sys/cmn_err.h>
27 #include <sys/ddi.h>
28 #include <sys/sunddi.h>
29 #include <sys/time.h>
30 #include <sys/ib/clients/rdsv3/rdsv3_debug.h>
31 
32 /*
33  * This file contains the debug defines and routines.
34  * Debugging information is collected in a circular kernel buffer. Debug
35  * messages with level lower than rdsv3dbglvl are ignored. The size of the
36  * of the debug buffer can be changed by setting 'rdsv3_debug_buf_size' in
37  * bytes in /etc/system.
38  *
39  * The debug buffer can be cleared by setting 'rdsv3_clear_debug_buf_flag = 1'
40  * on a running system.
41  */
42 
43 #define	RDSV3_DEBUG_SIZE_EXTRA_ALLOC	8
44 #define	RDSV3_MIN_DEBUG_BUF_SIZE		0x1000
45 #define	RDSV3_FUNCNAME_LEN		40
46 #define	RDSV3_PRINTBUF_LEN		4096
47 #ifdef	DEBUG
48 #define	RDSV3_DEBUG_BUF_SIZE		0x200000	/* 2M size */
49 #else
50 #define	RDSV3_DEBUG_BUF_SIZE		0x2000
51 #endif	/* DEBUG */
52 
53 /* Max length of a debug statement */
54 #define	RDSV3_PRINT_BUF_LEN	4096
55 
56 static int rdsv3_suppress_dprintf;	/* Suppress debug printing */
57 static int rdsv3_buffer_dprintf = 1;	/* Use debug buffer (0 == console) */
58 static int rdsv3_debug_buf_size = RDSV3_DEBUG_BUF_SIZE; /* Sz of Debug buf */
59 static int rdsv3_allow_intr_msgs = 0;	/* log "intr" messages */
60 char *rdsv3_debug_buf = NULL;	/* The Debug Buf */
61 char *rdsv3_buf_sptr, *rdsv3_buf_eptr;	/* debug buffer temp pointer */
62 int rdsv3_clear_debug_buf_flag = 0;	/* Clear debug buffer */
63 uint_t	rdsv3dbglvl = RDSV3_LOG_L4;
64 
65 /*
66  * Print Buffer protected by mutex for debug stuff. The mutex also
67  * ensures serializing debug messages.
68  */
69 static kmutex_t	rdsv3_debug_mutex;
70 static char	rdsv3_print_buf[RDSV3_PRINT_BUF_LEN];
71 
72 /* Function Prototypes */
73 static void	rdsv3_clear_print_buf();
74 
75 /* RDS logging init */
76 void
rdsv3_logging_initialization()77 rdsv3_logging_initialization()
78 {
79 	boolean_t flag = B_FALSE;
80 
81 	mutex_init(&rdsv3_debug_mutex, NULL, MUTEX_DRIVER, NULL);
82 	mutex_enter(&rdsv3_debug_mutex);
83 
84 	if (rdsv3_debug_buf_size <= RDSV3_DEBUG_SIZE_EXTRA_ALLOC) {
85 		rdsv3_debug_buf_size = RDSV3_MIN_DEBUG_BUF_SIZE;
86 		flag = B_TRUE;
87 	}
88 
89 	/* if it is less that RDSV3_MIN_DEBUG_BUF_SIZE, adjust it */
90 	rdsv3_debug_buf_size = max(RDSV3_MIN_DEBUG_BUF_SIZE,
91 	    rdsv3_debug_buf_size);
92 
93 	rdsv3_debug_buf = (char *)kmem_alloc(rdsv3_debug_buf_size, KM_SLEEP);
94 	rdsv3_clear_print_buf();
95 	mutex_exit(&rdsv3_debug_mutex);
96 
97 	if (flag == B_TRUE) {
98 		RDSV3_DPRINTF2("RDS", "rdsv3_debug_buf_size was too small, "
99 		    "adjusted to %x", rdsv3_debug_buf_size);
100 	}
101 }
102 
103 
104 /* RDS logging destroy */
105 void
rdsv3_logging_destroy()106 rdsv3_logging_destroy()
107 {
108 	mutex_enter(&rdsv3_debug_mutex);
109 	if (rdsv3_debug_buf) {
110 		kmem_free(rdsv3_debug_buf, rdsv3_debug_buf_size);
111 		rdsv3_debug_buf = NULL;
112 	}
113 	mutex_exit(&rdsv3_debug_mutex);
114 	mutex_destroy(&rdsv3_debug_mutex);
115 }
116 
117 
118 /*
119  * debug, log, and console message handling
120  */
121 
122 /*
123  * clear the RDS debug buffer
124  */
125 static void
rdsv3_clear_print_buf()126 rdsv3_clear_print_buf()
127 {
128 	ASSERT(MUTEX_HELD(&rdsv3_debug_mutex));
129 	if (rdsv3_debug_buf) {
130 		rdsv3_buf_sptr = rdsv3_debug_buf;
131 		rdsv3_buf_eptr = rdsv3_debug_buf + rdsv3_debug_buf_size -
132 		    RDSV3_DEBUG_SIZE_EXTRA_ALLOC;
133 
134 		bzero(rdsv3_debug_buf, rdsv3_debug_buf_size);
135 	}
136 }
137 
138 
139 static void
rdsv3_vlog(char * name,uint_t level,char * fmt,va_list ap)140 rdsv3_vlog(char *name, uint_t level, char *fmt, va_list ap)
141 {
142 	char	*label = (name == NULL) ? "rds" : name;
143 	char	*msg_ptr;
144 	size_t	len;
145 
146 	mutex_enter(&rdsv3_debug_mutex);
147 
148 	/* if not using logging scheme; quit */
149 	if (rdsv3_suppress_dprintf || (rdsv3_debug_buf == NULL)) {
150 		mutex_exit(&rdsv3_debug_mutex);
151 		return;
152 	}
153 
154 	/* If user requests to clear debug buffer, go ahead */
155 	if (rdsv3_clear_debug_buf_flag != 0) {
156 		rdsv3_clear_print_buf();
157 		rdsv3_clear_debug_buf_flag = 0;
158 	}
159 
160 	/*
161 	 * put "label" into the buffer
162 	 */
163 	len = snprintf(rdsv3_print_buf, RDSV3_FUNCNAME_LEN, "%s:\t", label);
164 
165 	msg_ptr = rdsv3_print_buf + len;
166 	len += vsnprintf(msg_ptr, RDSV3_PRINT_BUF_LEN - len - 2, fmt, ap);
167 
168 	len = min(len, RDSV3_PRINT_BUF_LEN - 2);
169 	ASSERT(len == strlen(rdsv3_print_buf));
170 	rdsv3_print_buf[len++] = '\n';
171 	rdsv3_print_buf[len] = '\0';
172 
173 	/*
174 	 * stuff the message in the debug buf
175 	 */
176 	if (rdsv3_buffer_dprintf) {
177 
178 		/*
179 		 * overwrite >>>> that might be over the end of the
180 		 * the buffer
181 		 */
182 		*rdsv3_buf_sptr = '\0';
183 
184 		if (rdsv3_buf_sptr + len > rdsv3_buf_eptr) {
185 			size_t left = (uintptr_t)rdsv3_buf_eptr -
186 			    (uintptr_t)rdsv3_buf_sptr;
187 
188 			bcopy((caddr_t)rdsv3_print_buf,
189 			    (caddr_t)rdsv3_buf_sptr, left);
190 			bcopy((caddr_t)rdsv3_print_buf + left,
191 			    (caddr_t)rdsv3_debug_buf, len - left);
192 			rdsv3_buf_sptr = rdsv3_debug_buf + len - left;
193 		} else {
194 			bcopy((caddr_t)rdsv3_print_buf, rdsv3_buf_sptr, len);
195 			rdsv3_buf_sptr += len;
196 		}
197 
198 		/* add marker */
199 		(void) sprintf(rdsv3_buf_sptr, ">>>>");
200 	}
201 
202 	/*
203 	 * LINTR, L5-L2 message may go to the rdsv3_debug_buf
204 	 * L1 messages will go to the /var/adm/messages (debug & non-debug).
205 	 * L0 messages will go to console (debug & non-debug).
206 	 */
207 	switch (level) {
208 	case RDSV3_LOG_LINTR:
209 	case RDSV3_LOG_L5:
210 	case RDSV3_LOG_L4:
211 	case RDSV3_LOG_L3:
212 	case RDSV3_LOG_L2:
213 		if (!rdsv3_buffer_dprintf) {
214 			cmn_err(CE_CONT, "^%s", rdsv3_print_buf);
215 		}
216 		break;
217 	case RDSV3_LOG_L1:
218 		if (!rdsv3_buffer_dprintf) {
219 			cmn_err(CE_CONT, "^%s", rdsv3_print_buf);
220 		} else {
221 			/* go to messages file */
222 			cmn_err(CE_CONT, "!%s", rdsv3_print_buf);
223 		}
224 		break;
225 	case RDSV3_LOG_L0:
226 		/* Strip the "\n" added earlier */
227 		if (rdsv3_print_buf[len - 1] == '\n') {
228 			rdsv3_print_buf[len - 1] = '\0';
229 		}
230 		if (msg_ptr[len - 1] == '\n') {
231 			msg_ptr[len - 1] = '\0';
232 		}
233 		/* go to console */
234 		cmn_err(CE_CONT, "^%s", rdsv3_print_buf);
235 		break;
236 	}
237 
238 	mutex_exit(&rdsv3_debug_mutex);
239 }
240 
241 void
rdsv3_dprintf_intr(char * name,char * fmt,...)242 rdsv3_dprintf_intr(char *name, char *fmt, ...)
243 {
244 	va_list ap;
245 
246 	va_start(ap, fmt);
247 	rdsv3_vlog(name, RDSV3_LOG_LINTR, fmt, ap);
248 	va_end(ap);
249 }
250 
251 /*
252  * Check individual subsystem err levels
253  */
254 #define	RDSV3_CHECK_ERR_LEVEL(level)		\
255 	if (rdsv3dbglvl < level)		\
256 		return;				\
257 
258 void
rdsv3_dprintf5(char * name,char * fmt,...)259 rdsv3_dprintf5(char *name, char *fmt, ...)
260 {
261 	va_list ap;
262 
263 	RDSV3_CHECK_ERR_LEVEL(RDSV3_LOG_L5);
264 
265 	va_start(ap, fmt);
266 	rdsv3_vlog(name, RDSV3_LOG_L5, fmt, ap);
267 	va_end(ap);
268 }
269 
270 void
rdsv3_dprintf4(char * name,char * fmt,...)271 rdsv3_dprintf4(char *name, char *fmt, ...)
272 {
273 	va_list ap;
274 
275 	RDSV3_CHECK_ERR_LEVEL(RDSV3_LOG_L4);
276 
277 	va_start(ap, fmt);
278 	rdsv3_vlog(name, RDSV3_LOG_L4, fmt, ap);
279 	va_end(ap);
280 }
281 
282 void
rdsv3_dprintf3(char * name,char * fmt,...)283 rdsv3_dprintf3(char *name, char *fmt, ...)
284 {
285 	va_list ap;
286 
287 	RDSV3_CHECK_ERR_LEVEL(RDSV3_LOG_L3);
288 
289 	va_start(ap, fmt);
290 	rdsv3_vlog(name, RDSV3_LOG_L3, fmt, ap);
291 	va_end(ap);
292 }
293 
294 void
rdsv3_dprintf2(char * name,char * fmt,...)295 rdsv3_dprintf2(char *name, char *fmt, ...)
296 {
297 	va_list ap;
298 
299 	RDSV3_CHECK_ERR_LEVEL(RDSV3_LOG_L2);
300 
301 	va_start(ap, fmt);
302 	rdsv3_vlog(name, RDSV3_LOG_L2, fmt, ap);
303 	va_end(ap);
304 }
305 
306 void
rdsv3_dprintf1(char * name,char * fmt,...)307 rdsv3_dprintf1(char *name, char *fmt, ...)
308 {
309 	va_list ap;
310 
311 	va_start(ap, fmt);
312 	rdsv3_vlog(name, RDSV3_LOG_L1, fmt, ap);
313 	va_end(ap);
314 }
315 
316 
317 /*
318  * Function:
319  *      rdsv3_dprintf0
320  * Input:
321  *      name	- Name of the function generating the debug message
322  *  	fmt	- The message to be displayed.
323  * Output:
324  *      none
325  * Returns:
326  *      none
327  * Description:
328  *  	A generic log function to display RDS debug messages.
329  */
330 void
rdsv3_dprintf0(char * name,char * fmt,...)331 rdsv3_dprintf0(char *name, char *fmt, ...)
332 {
333 	va_list ap;
334 
335 	va_start(ap, fmt);
336 	rdsv3_vlog(name, RDSV3_LOG_L0, fmt, ap);
337 	va_end(ap);
338 }
339 
340 /* For ofed rdstrace */
341 void
rdsv3_trace(char * name,uint8_t lvl,char * fmt,...)342 rdsv3_trace(char *name, uint8_t lvl, char *fmt, ...)
343 {
344 	va_list ap;
345 
346 	va_start(ap, fmt);
347 	rdsv3_vlog(name, lvl, fmt, ap);
348 	va_end(ap);
349 }
350 
351 #define	DEFAULT_RATELIMIT_INTERVAL	5
352 #define	DEFAULT_RATELIMIT_BURST	10
353 
354 struct ratelimit_state {
355 	clock_t interval;
356 	int burst;
357 	int printed;
358 	int missed;
359 	hrtime_t begin;
360 	kmutex_t lock;
361 };
362 
363 #define	DEFINE_RATELIMIT_STATE(name, interval, burst)		\
364 	static struct ratelimit_state name = {interval, burst, }
365 
366 DEFINE_RATELIMIT_STATE(rdsv3_printk_ratelimit_state,
367     DEFAULT_RATELIMIT_INTERVAL,
368     DEFAULT_RATELIMIT_BURST);
369 
370 int
rdsv3_printk_ratelimit(void)371 rdsv3_printk_ratelimit(void)
372 {
373 	struct ratelimit_state *rs = &rdsv3_printk_ratelimit_state;
374 	hrtime_t current = gethrtime();
375 	int rtn = 0;
376 
377 	if (rs->interval) {
378 		return (1);
379 	}
380 	mutex_enter(&rs->lock);
381 	if (!rs->begin) {
382 		rs->begin = current;
383 	}
384 	if (current < rs->begin + TICK_TO_NSEC(rs->interval)) {
385 		if (rs->missed) {
386 			RDSV3_DPRINTF0("rdsv3_printk_ratelimit: ",
387 			    "%d callbacks suppressed\n", rs->missed);
388 			rs->begin = 0;
389 			rs->printed = 0;
390 			rs->missed = 0;
391 		}
392 	}
393 	if (rs->burst && rs->burst > rs->printed) {
394 		rs->printed++;
395 		rtn = 1;
396 	} else {
397 		rs->missed++;
398 	}
399 	mutex_exit(&rs->lock);
400 	return (rtn);
401 }
402