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