1 /*
2 * DHD debugability support
3 *
4 * <<Broadcom-WL-IPTag/Open:>>
5 *
6 * Copyright (C) 1999-2019, Broadcom.
7 *
8 * Unless you and Broadcom execute a separate written software license
9 * agreement governing use of this software, this software is licensed to you
10 * under the terms of the GNU General Public License version 2 (the "GPL"),
11 * available at http://www.broadcom.com/licenses/GPLv2.php, with the
12 * following added to such license:
13 *
14 * As a special exception, the copyright holders of this software give you
15 * permission to link this software with independent modules, and to copy and
16 * distribute the resulting executable under terms of your choice, provided that
17 * you also meet, for each linked independent module, the terms and conditions
18 * of the license of that module. An independent module is a module which is
19 * not derived from this software. The special exception does not apply to any
20 * modifications of the software.
21 *
22 * Notwithstanding the above, under no circumstances may you combine this
23 * software in any way with any other Broadcom software provided under a license
24 * other than the GPL, without Broadcom's express prior written consent.
25 *
26 * $Id: dhd_mschdbg.c 639872 2016-05-25 05:39:30Z $
27 */
28 #ifdef SHOW_LOGTRACE
29 #include <typedefs.h>
30 #include <osl.h>
31 #include <bcmutils.h>
32 #include <bcmendian.h>
33 #include <dngl_stats.h>
34 #include <dhd.h>
35 #include <dhd_dbg.h>
36 #include <dhd_debug.h>
37 #include <dhd_mschdbg.h>
38
39 #include <event_log.h>
40 #include <event_trace.h>
41 #include <msgtrace.h>
42
43 static const char *head_log = "";
44 #define MSCH_EVENT_HEAD(space) \
45 do { \
46 MSCH_EVENT(("%s_E: ", head_log)); \
47 if (space > 0) { \
48 int ii; \
49 for (ii = 0; ii < space; ii += 4) \
50 MSCH_EVENT((" ")); \
51 } \
52 } while (0)
53 #define MSCH_EVENT(args) \
54 do { \
55 if (dhd_msg_level & DHD_EVENT_VAL) \
56 printf args; \
57 } while (0)
58
59 static uint64 solt_start_time[4], req_start_time[4], profiler_start_time[4];
60 static uint32 solt_chanspec[4] = {
61 0,
62 },
63 req_start[4] = {
64 0,
65 };
66 static bool lastMessages = FALSE;
67
68 #define US_PRE_SEC 1000000
69 #define DATA_UNIT_FOR_LOG_CNT 4
70
dhd_mschdbg_us_to_sec(uint32 time_h,uint32 time_l,uint32 * sec,uint32 * remain)71 static void dhd_mschdbg_us_to_sec(uint32 time_h, uint32 time_l, uint32 *sec,
72 uint32 *remain)
73 {
74 uint64 cur_time = ((uint64)(ntoh32(time_h)) << 32) | ntoh32(time_l);
75 uint64 r, u = 0;
76
77 r = cur_time;
78 while (time_h != 0) {
79 u += (uint64)((0xffffffff / US_PRE_SEC)) * time_h;
80 r = cur_time - u * US_PRE_SEC;
81 time_h = (uint32)(r >> 0x20);
82 }
83
84 *sec = (uint32)(u + ((uint32)(r) / US_PRE_SEC));
85 *remain = (uint32)(r) % US_PRE_SEC;
86 }
87
dhd_mschdbg_display_time(uint32 time_h,uint32 time_l)88 static char *dhd_mschdbg_display_time(uint32 time_h, uint32 time_l)
89 {
90 static char display_time[32];
91 uint32 s, ss;
92
93 if (time_h == 0xffffffff && time_l == 0xffffffff) {
94 snprintf(display_time, 0x1F, "-1");
95 } else {
96 dhd_mschdbg_us_to_sec(time_h, time_l, &s, &ss);
97 snprintf(display_time, 0x1F, "%d.%06d", s, ss);
98 }
99 return display_time;
100 }
101
dhd_mschdbg_chanspec_list(int sp,char * data,uint16 ptr,uint16 chanspec_cnt)102 static void dhd_mschdbg_chanspec_list(int sp, char *data, uint16 ptr,
103 uint16 chanspec_cnt)
104 {
105 int i, cnt = (int)ntoh16(chanspec_cnt);
106 uint16 *chanspec_list = (uint16 *)(data + ntoh16(ptr));
107 char buf[CHANSPEC_STR_LEN];
108 chanspec_t c;
109
110 MSCH_EVENT_HEAD(sp);
111 MSCH_EVENT(("<chanspec_list>:"));
112 for (i = 0; i < cnt; i++) {
113 c = (chanspec_t)ntoh16(chanspec_list[i]);
114 MSCH_EVENT((" %s", wf_chspec_ntoa(c, buf)));
115 }
116 MSCH_EVENT(("\n"));
117 }
118
dhd_mschdbg_elem_list(int sp,char * title,char * data,uint16 ptr,uint16 list_cnt)119 static void dhd_mschdbg_elem_list(int sp, char *title, char *data, uint16 ptr,
120 uint16 list_cnt)
121 {
122 int i, cnt = (int)ntoh16(list_cnt);
123 uint32 *list = (uint32 *)(data + ntoh16(ptr));
124
125 MSCH_EVENT_HEAD(sp);
126 MSCH_EVENT(("%s_list: ", title));
127 for (i = 0; i < cnt; i++) {
128 MSCH_EVENT(("0x%08x->", ntoh32(list[i])));
129 }
130 MSCH_EVENT(("null\n"));
131 }
132
dhd_mschdbg_req_param_profiler_event_data(int sp,int ver,char * data,uint16 ptr)133 static void dhd_mschdbg_req_param_profiler_event_data(int sp, int ver,
134 char *data, uint16 ptr)
135 {
136 int sn = sp + 4;
137 msch_req_param_profiler_event_data_t *p =
138 (msch_req_param_profiler_event_data_t *)(data + ntoh16(ptr));
139 uint32 type, flags;
140
141 MSCH_EVENT_HEAD(sp);
142 MSCH_EVENT(("<request parameters>\n"));
143 MSCH_EVENT_HEAD(sn);
144 MSCH_EVENT(("req_type: "));
145
146 type = p->req_type;
147 if (type < 0x4) {
148 char *req_type[] = {"fixed", "start-flexible", "duration-flexible",
149 "both-flexible"};
150 MSCH_EVENT(("%s", req_type[type]));
151 } else {
152 MSCH_EVENT(("unknown(%d)", type));
153 }
154
155 flags = ntoh16(p->flags);
156 if (flags & WL_MSCH_REQ_FLAGS_CHAN_CONTIGUOUS) {
157 MSCH_EVENT((", CHAN_CONTIGUOUS"));
158 }
159 if (flags & WL_MSCH_REQ_FLAGS_MERGE_CONT_SLOTS) {
160 MSCH_EVENT((", MERGE_CONT_SLOTS"));
161 }
162 if (flags & WL_MSCH_REQ_FLAGS_PREMTABLE) {
163 MSCH_EVENT((", PREMTABLE"));
164 }
165 if (flags & WL_MSCH_REQ_FLAGS_PREMT_CURTS) {
166 MSCH_EVENT((", PREMT_CURTS"));
167 }
168 if (flags & WL_MSCH_REQ_FLAGS_PREMT_IMMEDIATE) {
169 MSCH_EVENT((", PREMT_IMMEDIATE"));
170 }
171 MSCH_EVENT((", priority: %d\n", p->priority));
172
173 MSCH_EVENT_HEAD(sn);
174 MSCH_EVENT(("start-time: %s, duration: %d(us), interval: %d(us)\n",
175 dhd_mschdbg_display_time(p->start_time_h, p->start_time_l),
176 ntoh32(p->duration), ntoh32(p->interval)));
177
178 if (type == WL_MSCH_RT_DUR_FLEX) {
179 MSCH_EVENT_HEAD(sn);
180 MSCH_EVENT(("dur_flex: %d(us)\n", ntoh32(p->flex.dur_flex)));
181 } else if (type == WL_MSCH_RT_BOTH_FLEX) {
182 MSCH_EVENT_HEAD(sn);
183 MSCH_EVENT(("min_dur: %d(us), max_away_dur: %d(us)\n",
184 ntoh32(p->flex.bf.min_dur),
185 ntoh32(p->flex.bf.max_away_dur)));
186
187 MSCH_EVENT_HEAD(sn);
188 MSCH_EVENT(("hi_prio_time: %s, hi_prio_interval: %d(us)\n",
189 dhd_mschdbg_display_time(p->flex.bf.hi_prio_time_h,
190 p->flex.bf.hi_prio_time_l),
191 ntoh32(p->flex.bf.hi_prio_interval)));
192 }
193 }
194
dhd_mschdbg_timeslot_profiler_event_data(int sp,int ver,char * title,char * data,uint16 ptr,bool empty)195 static void dhd_mschdbg_timeslot_profiler_event_data(int sp, int ver,
196 char *title, char *data,
197 uint16 ptr, bool empty)
198 {
199 int s, sn = sp + 4;
200 msch_timeslot_profiler_event_data_t *p =
201 (msch_timeslot_profiler_event_data_t *)(data + ntoh16(ptr));
202 char *state[] = {"NONE", "CHN_SW", "ONCHAN_FIRE",
203 "OFF_CHN_PREP", "OFF_CHN_DONE", "TS_COMPLETE"};
204
205 MSCH_EVENT_HEAD(sp);
206 MSCH_EVENT(("<%s timeslot>: ", title));
207 if (empty) {
208 MSCH_EVENT((" null\n"));
209 return;
210 } else {
211 MSCH_EVENT(("0x%08x\n", ntoh32(p->p_timeslot)));
212 }
213
214 s = (int)(ntoh32(p->state));
215 if (s > 0x5) {
216 s = 0;
217 }
218
219 MSCH_EVENT_HEAD(sn);
220 MSCH_EVENT(("id: %d, state[%d]: %s, chan_ctxt: [0x%08x]\n",
221 ntoh32(p->timeslot_id), ntoh32(p->state), state[s],
222 ntoh32(p->p_chan_ctxt)));
223
224 MSCH_EVENT_HEAD(sn);
225 MSCH_EVENT(("fire_time: %s",
226 dhd_mschdbg_display_time(p->fire_time_h, p->fire_time_l)));
227
228 MSCH_EVENT(
229 (", pre_start_time: %s",
230 dhd_mschdbg_display_time(p->pre_start_time_h, p->pre_start_time_l)));
231
232 MSCH_EVENT((", end_time: %s",
233 dhd_mschdbg_display_time(p->end_time_h, p->end_time_l)));
234
235 MSCH_EVENT((", sch_dur: %s\n",
236 dhd_mschdbg_display_time(p->sch_dur_h, p->sch_dur_l)));
237 }
238
dhd_mschdbg_req_timing_profiler_event_data(int sp,int ver,char * title,char * data,uint16 ptr,bool empty)239 static void dhd_mschdbg_req_timing_profiler_event_data(int sp, int ver,
240 char *title, char *data,
241 uint16 ptr, bool empty)
242 {
243 int sn = sp + 4;
244 msch_req_timing_profiler_event_data_t *p =
245 (msch_req_timing_profiler_event_data_t *)(data + ntoh16(ptr));
246 uint32 type;
247
248 MSCH_EVENT_HEAD(sp);
249 MSCH_EVENT(("<%s req_timing>: ", title));
250 if (empty) {
251 MSCH_EVENT((" null\n"));
252 return;
253 } else {
254 MSCH_EVENT(("0x%08x (prev 0x%08x, next 0x%08x)\n",
255 ntoh32(p->p_req_timing), ntoh32(p->p_prev),
256 ntoh32(p->p_next)));
257 }
258
259 MSCH_EVENT_HEAD(sn);
260 MSCH_EVENT(("flags:"));
261 type = ntoh16(p->flags);
262 if ((type & 0x7f) == 0) {
263 MSCH_EVENT((" NONE"));
264 } else {
265 if (type & WL_MSCH_RC_FLAGS_ONCHAN_FIRE) {
266 MSCH_EVENT((" ONCHAN_FIRE"));
267 }
268 if (type & WL_MSCH_RC_FLAGS_START_FIRE_DONE) {
269 MSCH_EVENT((" START_FIRE"));
270 }
271 if (type & WL_MSCH_RC_FLAGS_END_FIRE_DONE) {
272 MSCH_EVENT((" END_FIRE"));
273 }
274 if (type & WL_MSCH_RC_FLAGS_ONFIRE_DONE) {
275 MSCH_EVENT((" ONFIRE_DONE"));
276 }
277 if (type & WL_MSCH_RC_FLAGS_SPLIT_SLOT_START) {
278 MSCH_EVENT((" SPLIT_SLOT_START"));
279 }
280 if (type & WL_MSCH_RC_FLAGS_SPLIT_SLOT_END) {
281 MSCH_EVENT((" SPLIT_SLOT_END"));
282 }
283 if (type & WL_MSCH_RC_FLAGS_PRE_ONFIRE_DONE) {
284 MSCH_EVENT((" PRE_ONFIRE_DONE"));
285 }
286 }
287 MSCH_EVENT(("\n"));
288
289 MSCH_EVENT_HEAD(sn);
290 MSCH_EVENT(
291 ("pre_start_time: %s",
292 dhd_mschdbg_display_time(p->pre_start_time_h, p->pre_start_time_l)));
293
294 MSCH_EVENT((", start_time: %s",
295 dhd_mschdbg_display_time(p->start_time_h, p->start_time_l)));
296
297 MSCH_EVENT((", end_time: %s\n",
298 dhd_mschdbg_display_time(p->end_time_h, p->end_time_l)));
299
300 if (p->p_timeslot && (p->timeslot_ptr == 0)) {
301 MSCH_EVENT_HEAD(sn);
302 MSCH_EVENT(("<%s timeslot>: 0x%08x\n", title, ntoh32(p->p_timeslot)));
303 } else {
304 dhd_mschdbg_timeslot_profiler_event_data(
305 sn, ver, title, data, p->timeslot_ptr, (p->timeslot_ptr == 0));
306 }
307 }
308
dhd_mschdbg_chan_ctxt_profiler_event_data(int sp,int ver,char * data,uint16 ptr,bool empty)309 static void dhd_mschdbg_chan_ctxt_profiler_event_data(int sp, int ver,
310 char *data, uint16 ptr,
311 bool empty)
312 {
313 int sn = sp + 4;
314 msch_chan_ctxt_profiler_event_data_t *p =
315 (msch_chan_ctxt_profiler_event_data_t *)(data + ntoh16(ptr));
316 chanspec_t c;
317 char buf[CHANSPEC_STR_LEN];
318
319 MSCH_EVENT_HEAD(sp);
320 MSCH_EVENT(("<chan_ctxt>: "));
321 if (empty) {
322 MSCH_EVENT((" null\n"));
323 return;
324 } else {
325 MSCH_EVENT(("0x%08x (prev 0x%08x, next 0x%08x)\n",
326 ntoh32(p->p_chan_ctxt), ntoh32(p->p_prev),
327 ntoh32(p->p_next)));
328 }
329
330 c = (chanspec_t)ntoh16(p->chanspec);
331
332 MSCH_EVENT_HEAD(sn);
333 MSCH_EVENT(("channel: %s, bf_sch_pending: %s, bf_skipped: %d\n",
334 wf_chspec_ntoa(c, buf), p->bf_sch_pending ? "TRUE" : "FALSE",
335 ntoh32(p->bf_skipped_count)));
336
337 MSCH_EVENT_HEAD(sn);
338 MSCH_EVENT(("bf_link: prev 0x%08x, next 0x%08x\n", ntoh32(p->bf_link_prev),
339 ntoh32(p->bf_link_next)));
340
341 MSCH_EVENT_HEAD(sn);
342 MSCH_EVENT(("onchan_time: %s",
343 dhd_mschdbg_display_time(p->onchan_time_h, p->onchan_time_l)));
344 MSCH_EVENT((", actual_onchan_dur: %s",
345 dhd_mschdbg_display_time(p->actual_onchan_dur_h,
346 p->actual_onchan_dur_l)));
347 MSCH_EVENT(
348 (", pend_onchan_dur: %s\n",
349 dhd_mschdbg_display_time(p->pend_onchan_dur_h, p->pend_onchan_dur_l)));
350
351 dhd_mschdbg_elem_list(sn, "req_entity", data, p->req_entity_list_ptr,
352 p->req_entity_list_cnt);
353 dhd_mschdbg_elem_list(sn, "bf_entity", data, p->bf_entity_list_ptr,
354 p->bf_entity_list_cnt);
355 }
356
dhd_mschdbg_req_entity_profiler_event_data(int sp,int ver,char * data,uint16 ptr,bool empty)357 static void dhd_mschdbg_req_entity_profiler_event_data(int sp, int ver,
358 char *data, uint16 ptr,
359 bool empty)
360 {
361 int sn = sp + 4;
362 msch_req_entity_profiler_event_data_t *p =
363 (msch_req_entity_profiler_event_data_t *)(data + ntoh16(ptr));
364 char buf[CHANSPEC_STR_LEN];
365 chanspec_t c;
366 uint32 flags;
367
368 MSCH_EVENT_HEAD(sp);
369 MSCH_EVENT(("<req_entity>: "));
370 if (empty) {
371 MSCH_EVENT((" null\n"));
372 return;
373 } else {
374 MSCH_EVENT(("0x%08x (prev 0x%08x, next 0x%08x)\n",
375 ntoh32(p->p_req_entity), ntoh32(p->req_hdl_link_prev),
376 ntoh32(p->req_hdl_link_next)));
377 }
378
379 MSCH_EVENT_HEAD(sn);
380 MSCH_EVENT(("req_hdl: [0x%08x]\n", ntoh32(p->p_req_hdl)));
381
382 MSCH_EVENT_HEAD(sn);
383 MSCH_EVENT(("chan_ctxt_link: prev 0x%08x, next 0x%08x\n",
384 ntoh32(p->chan_ctxt_link_prev),
385 ntoh32(p->chan_ctxt_link_next)));
386 MSCH_EVENT_HEAD(sn);
387 MSCH_EVENT(("rt_specific_link: prev 0x%08x, next 0x%08x\n",
388 ntoh32(p->rt_specific_link_prev),
389 ntoh32(p->rt_specific_link_next)));
390 MSCH_EVENT_HEAD(sn);
391 MSCH_EVENT(("start_fixed_link: prev 0x%08x, next 0x%08x\n",
392 ntoh32(p->start_fixed_link_prev),
393 ntoh32(p->start_fixed_link_next)));
394 MSCH_EVENT_HEAD(sn);
395 MSCH_EVENT(("both_flex_list: prev 0x%08x, next 0x%08x\n",
396 ntoh32(p->both_flex_list_prev),
397 ntoh32(p->both_flex_list_next)));
398
399 c = (chanspec_t)ntoh16(p->chanspec);
400 MSCH_EVENT_HEAD(sn);
401 if (ver >= 0x2) {
402 MSCH_EVENT(
403 ("channel: %s, onchan Id %d, current chan Id %d, priority %d",
404 wf_chspec_ntoa(c, buf), ntoh16(p->onchan_chn_idx),
405 ntoh16(p->cur_chn_idx), ntoh16(p->priority)));
406 flags = ntoh32(p->flags);
407 if (flags & WL_MSCH_ENTITY_FLAG_MULTI_INSTANCE) {
408 MSCH_EVENT((" : MULTI_INSTANCE\n"));
409 } else {
410 MSCH_EVENT(("\n"));
411 }
412 MSCH_EVENT_HEAD(sn);
413 MSCH_EVENT(("actual_start_time: %s, ",
414 dhd_mschdbg_display_time(p->actual_start_time_h,
415 p->actual_start_time_l)));
416 MSCH_EVENT(("curts_fire_time: %s, ",
417 dhd_mschdbg_display_time(p->curts_fire_time_h,
418 p->curts_fire_time_l)));
419 } else {
420 MSCH_EVENT(("channel: %s, priority %d, ", wf_chspec_ntoa(c, buf),
421 ntoh16(p->priority)));
422 }
423 MSCH_EVENT(("bf_last_serv_time: %s\n",
424 dhd_mschdbg_display_time(p->bf_last_serv_time_h,
425 p->bf_last_serv_time_l)));
426
427 dhd_mschdbg_req_timing_profiler_event_data(
428 sn, ver, "current", data, p->cur_slot_ptr, (p->cur_slot_ptr == 0));
429 dhd_mschdbg_req_timing_profiler_event_data(
430 sn, ver, "pending", data, p->pend_slot_ptr, (p->pend_slot_ptr == 0));
431
432 if (p->p_chan_ctxt && (p->chan_ctxt_ptr == 0)) {
433 MSCH_EVENT_HEAD(sn);
434 MSCH_EVENT(("<chan_ctxt>: 0x%08x\n", ntoh32(p->p_chan_ctxt)));
435 } else {
436 dhd_mschdbg_chan_ctxt_profiler_event_data(
437 sn, ver, data, p->chan_ctxt_ptr, (p->chan_ctxt_ptr == 0));
438 }
439 }
440
dhd_mschdbg_req_handle_profiler_event_data(int sp,int ver,char * data,uint16 ptr,bool empty)441 static void dhd_mschdbg_req_handle_profiler_event_data(int sp, int ver,
442 char *data, uint16 ptr,
443 bool empty)
444 {
445 int sn = sp + 4;
446 msch_req_handle_profiler_event_data_t *p =
447 (msch_req_handle_profiler_event_data_t *)(data + ntoh16(ptr));
448 uint32 flags;
449
450 MSCH_EVENT_HEAD(sp);
451 MSCH_EVENT(("<req_handle>: "));
452 if (empty) {
453 MSCH_EVENT((" null\n"));
454 return;
455 } else {
456 MSCH_EVENT(("0x%08x (prev 0x%08x, next 0x%08x)\n",
457 ntoh32(p->p_req_handle), ntoh32(p->p_prev),
458 ntoh32(p->p_next)));
459 }
460
461 dhd_mschdbg_elem_list(sn, "req_entity", data, p->req_entity_list_ptr,
462 p->req_entity_list_cnt);
463 MSCH_EVENT_HEAD(sn);
464 MSCH_EVENT(("cb_func: [0x%08x], cb_func: [0x%08x]", ntoh32(p->cb_func),
465 ntoh32(p->cb_ctxt)));
466 if (ver < 0x2) {
467 MSCH_EVENT((", chan_cnt: %d", ntoh16(p->chan_cnt)));
468 }
469 flags = ntoh32(p->flags);
470 if (flags & WL_MSCH_REQ_HDL_FLAGS_NEW_REQ) {
471 MSCH_EVENT((", NEW_REQ"));
472 }
473 MSCH_EVENT(("\n"));
474
475 dhd_mschdbg_req_param_profiler_event_data(sn, ver, data, p->req_param_ptr);
476
477 if (ver >= 0x2) {
478 MSCH_EVENT_HEAD(sn);
479 MSCH_EVENT(("req_time: %s\n",
480 dhd_mschdbg_display_time(p->req_time_h, p->req_time_l)));
481 MSCH_EVENT_HEAD(sn);
482 MSCH_EVENT(("chan_cnt: %d, chan idx %d, last chan idx %d\n",
483 ntoh16(p->chan_cnt), ntoh16(p->chan_idx),
484 ntoh16(p->last_chan_idx)));
485 if (p->chanspec_list && p->chanspec_cnt) {
486 dhd_mschdbg_chanspec_list(sn, data, p->chanspec_list,
487 p->chanspec_cnt);
488 }
489 }
490 }
491
dhd_mschdbg_profiler_profiler_event_data(int sp,int ver,char * data,uint16 ptr)492 static void dhd_mschdbg_profiler_profiler_event_data(int sp, int ver,
493 char *data, uint16 ptr)
494 {
495 msch_profiler_profiler_event_data_t *p =
496 (msch_profiler_profiler_event_data_t *)(data + ntoh16(ptr));
497 uint32 flags;
498
499 MSCH_EVENT_HEAD(sp);
500 MSCH_EVENT(("free list: req_hdl 0x%08x, req_entity 0x%08x,"
501 " chan_ctxt 0x%08x, chanspec 0x%08x\n",
502 ntoh32(p->free_req_hdl_list), ntoh32(p->free_req_entity_list),
503 ntoh32(p->free_chan_ctxt_list), ntoh32(p->free_chanspec_list)));
504
505 MSCH_EVENT_HEAD(sp);
506 MSCH_EVENT(("alloc count: chanspec %d, req_entity %d, req_hdl %d, "
507 "chan_ctxt %d, timeslot %d\n",
508 ntoh16(p->msch_chanspec_alloc_cnt),
509 ntoh16(p->msch_req_entity_alloc_cnt),
510 ntoh16(p->msch_req_hdl_alloc_cnt),
511 ntoh16(p->msch_chan_ctxt_alloc_cnt),
512 ntoh16(p->msch_timeslot_alloc_cnt)));
513
514 dhd_mschdbg_elem_list(sp, "req_hdl", data, p->msch_req_hdl_list_ptr,
515 p->msch_req_hdl_list_cnt);
516 dhd_mschdbg_elem_list(sp, "chan_ctxt", data, p->msch_chan_ctxt_list_ptr,
517 p->msch_chan_ctxt_list_cnt);
518 dhd_mschdbg_elem_list(sp, "req_timing", data, p->msch_req_timing_list_ptr,
519 p->msch_req_timing_list_cnt);
520 dhd_mschdbg_elem_list(sp, "start_fixed", data, p->msch_start_fixed_list_ptr,
521 p->msch_start_fixed_list_cnt);
522 dhd_mschdbg_elem_list(sp, "both_flex_req_entity", data,
523 p->msch_both_flex_req_entity_list_ptr,
524 p->msch_both_flex_req_entity_list_cnt);
525 dhd_mschdbg_elem_list(sp, "start_flex", data, p->msch_start_flex_list_ptr,
526 p->msch_start_flex_list_cnt);
527 dhd_mschdbg_elem_list(sp, "both_flex", data, p->msch_both_flex_list_ptr,
528 p->msch_both_flex_list_cnt);
529
530 if (p->p_cur_msch_timeslot && (p->cur_msch_timeslot_ptr == 0)) {
531 MSCH_EVENT_HEAD(sp);
532 MSCH_EVENT(
533 ("<cur_msch timeslot>: 0x%08x\n", ntoh32(p->p_cur_msch_timeslot)));
534 } else {
535 dhd_mschdbg_timeslot_profiler_event_data(
536 sp, ver, "cur_msch", data, p->cur_msch_timeslot_ptr,
537 (p->cur_msch_timeslot_ptr == 0));
538 }
539
540 if (p->p_next_timeslot && (p->next_timeslot_ptr == 0)) {
541 MSCH_EVENT_HEAD(sp);
542 MSCH_EVENT(("<next timeslot>: 0x%08x\n", ntoh32(p->p_next_timeslot)));
543 } else {
544 dhd_mschdbg_timeslot_profiler_event_data(sp, ver, "next", data,
545 p->next_timeslot_ptr,
546 (p->next_timeslot_ptr == 0));
547 }
548
549 MSCH_EVENT_HEAD(sp);
550 MSCH_EVENT(("ts_id: %d, ", ntoh32(p->ts_id)));
551 flags = ntoh32(p->flags);
552 if (flags & WL_MSCH_STATE_IN_TIEMR_CTXT) {
553 MSCH_EVENT(("IN_TIEMR_CTXT, "));
554 }
555 if (flags & WL_MSCH_STATE_SCHD_PENDING) {
556 MSCH_EVENT(("SCHD_PENDING, "));
557 }
558 MSCH_EVENT(("slotskip_flags: %d, cur_armed_timeslot: 0x%08x\n",
559 (ver >= 2) ? ntoh32(p->slotskip_flag) : 0,
560 ntoh32(p->cur_armed_timeslot)));
561 MSCH_EVENT_HEAD(sp);
562 MSCH_EVENT(("flex_list_cnt: %d, service_interval: %d, "
563 "max_lo_prio_interval: %d\n",
564 ntoh16(p->flex_list_cnt), ntoh32(p->service_interval),
565 ntoh32(p->max_lo_prio_interval)));
566 }
567
dhd_mschdbg_dump_data(dhd_pub_t * dhdp,void * raw_event_ptr,int type,char * data,int len)568 static void dhd_mschdbg_dump_data(dhd_pub_t *dhdp, void *raw_event_ptr,
569 int type, char *data, int len)
570 {
571 uint64 t = 0, tt = 0;
572 uint32 s = 0, ss = 0;
573 int wlc_index, ver;
574
575 ver = (type & WL_MSCH_PROFILER_VER_MASK) >> WL_MSCH_PROFILER_VER_SHIFT;
576 wlc_index = (type & WL_MSCH_PROFILER_WLINDEX_MASK) >>
577 WL_MSCH_PROFILER_WLINDEX_SHIFT;
578 if (wlc_index >= 0x4) {
579 return;
580 }
581
582 type &= WL_MSCH_PROFILER_TYPE_MASK;
583 if (type <= WL_MSCH_PROFILER_PROFILE_END) {
584 msch_profiler_event_data_t *pevent = (msch_profiler_event_data_t *)data;
585 tt =
586 ((uint64)(ntoh32(pevent->time_hi)) << 0x20) | ntoh32(pevent->time_lo);
587 dhd_mschdbg_us_to_sec(pevent->time_hi, pevent->time_lo, &s, &ss);
588 }
589
590 if (lastMessages && (type != WL_MSCH_PROFILER_MESSAGE) &&
591 (type != WL_MSCH_PROFILER_EVENT_LOG)) {
592 MSCH_EVENT_HEAD(0);
593 MSCH_EVENT(("\n"));
594 lastMessages = FALSE;
595 }
596
597 switch (type) {
598 case WL_MSCH_PROFILER_START:
599 MSCH_EVENT_HEAD(0);
600 MSCH_EVENT(("%06d.%06d START\n", s, ss));
601 break;
602
603 case WL_MSCH_PROFILER_EXIT:
604 MSCH_EVENT_HEAD(0);
605 MSCH_EVENT(("%06d.%06d EXIT\n", s, ss));
606 break;
607
608 case WL_MSCH_PROFILER_REQ: {
609 msch_req_profiler_event_data_t *p =
610 (msch_req_profiler_event_data_t *)data;
611 MSCH_EVENT_HEAD(0);
612 MSCH_EVENT(("\n"));
613 MSCH_EVENT_HEAD(0);
614 MSCH_EVENT(("===============================\n"));
615 MSCH_EVENT_HEAD(0);
616 MSCH_EVENT(("%06d.%06d [wl%d] REGISTER:\n", s, ss, wlc_index));
617 dhd_mschdbg_req_param_profiler_event_data(0x4, ver, data,
618 p->req_param_ptr);
619 dhd_mschdbg_chanspec_list(0x4, data, p->chanspec_ptr,
620 p->chanspec_cnt);
621 MSCH_EVENT_HEAD(0);
622 MSCH_EVENT(("===============================\n"));
623 MSCH_EVENT_HEAD(0);
624 MSCH_EVENT(("\n"));
625 break;
626 }
627
628 case WL_MSCH_PROFILER_CALLBACK: {
629 msch_callback_profiler_event_data_t *p =
630 (msch_callback_profiler_event_data_t *)data;
631 char buf[CHANSPEC_STR_LEN];
632 chanspec_t chanspec;
633 uint16 cbtype;
634
635 MSCH_EVENT_HEAD(0);
636 MSCH_EVENT(("%06d.%06d [wl%d] CALLBACK: ", s, ss, wlc_index));
637 chanspec = (chanspec_t)ntoh16(p->chanspec);
638 MSCH_EVENT(("req_hdl[0x%08x], channel %s --", ntoh32(p->p_req_hdl),
639 wf_chspec_ntoa(chanspec, buf)));
640
641 cbtype = ntoh16(p->type);
642 if (cbtype & WL_MSCH_CT_ON_CHAN) {
643 MSCH_EVENT((" ON_CHAN"));
644 }
645 if (cbtype & WL_MSCH_CT_OFF_CHAN) {
646 MSCH_EVENT((" OFF_CHAN"));
647 }
648 if (cbtype & WL_MSCH_CT_REQ_START) {
649 MSCH_EVENT((" REQ_START"));
650 }
651 if (cbtype & WL_MSCH_CT_REQ_END) {
652 MSCH_EVENT((" REQ_END"));
653 }
654 if (cbtype & WL_MSCH_CT_SLOT_START) {
655 MSCH_EVENT((" SLOT_START"));
656 }
657 if (cbtype & WL_MSCH_CT_SLOT_SKIP) {
658 MSCH_EVENT((" SLOT_SKIP"));
659 }
660 if (cbtype & WL_MSCH_CT_SLOT_END) {
661 MSCH_EVENT((" SLOT_END"));
662 }
663 if (cbtype & WL_MSCH_CT_OFF_CHAN_DONE) {
664 MSCH_EVENT((" OFF_CHAN_DONE"));
665 }
666 if (cbtype & WL_MSCH_CT_PARTIAL) {
667 MSCH_EVENT((" PARTIAL"));
668 }
669 if (cbtype & WL_MSCH_CT_PRE_ONCHAN) {
670 MSCH_EVENT((" PRE_ONCHAN"));
671 }
672 if (cbtype & WL_MSCH_CT_PRE_REQ_START) {
673 MSCH_EVENT((" PRE_REQ_START"));
674 }
675
676 if (cbtype & WL_MSCH_CT_REQ_START) {
677 req_start[wlc_index] = 1;
678 req_start_time[wlc_index] = tt;
679 } else if (cbtype & WL_MSCH_CT_REQ_END) {
680 if (req_start[wlc_index]) {
681 MSCH_EVENT((" : REQ duration %d",
682 (uint32)(tt - req_start_time[wlc_index])));
683 req_start[wlc_index] = 0;
684 }
685 }
686
687 if (cbtype & WL_MSCH_CT_SLOT_START) {
688 solt_chanspec[wlc_index] = p->chanspec;
689 solt_start_time[wlc_index] = tt;
690 } else if (cbtype & WL_MSCH_CT_SLOT_END) {
691 if (p->chanspec == solt_chanspec[wlc_index]) {
692 MSCH_EVENT((" : SLOT duration %d",
693 (uint32)(tt - solt_start_time[wlc_index])));
694 solt_chanspec[wlc_index] = 0;
695 }
696 }
697 MSCH_EVENT(("\n"));
698
699 if (cbtype & (WL_MSCH_CT_ON_CHAN | WL_MSCH_CT_SLOT_SKIP)) {
700 MSCH_EVENT_HEAD(4);
701 if (cbtype & WL_MSCH_CT_ON_CHAN) {
702 MSCH_EVENT(("ID %d onchan idx %d cur_chan_seq_start %s ",
703 ntoh32(p->timeslot_id), ntoh32(p->onchan_idx),
704 dhd_mschdbg_display_time(
705 p->cur_chan_seq_start_time_h,
706 p->cur_chan_seq_start_time_l)));
707 }
708 t = ((uint64)(ntoh32(p->start_time_h)) << 0x20) |
709 ntoh32(p->start_time_l);
710 MSCH_EVENT(
711 ("start %s ", dhd_mschdbg_display_time(p->start_time_h,
712 p->start_time_l)));
713 tt = ((uint64)(ntoh32(p->end_time_h)) << 0x20) |
714 ntoh32(p->end_time_l);
715 MSCH_EVENT((
716 "end %s duration %d\n",
717 dhd_mschdbg_display_time(p->end_time_h, p->end_time_l),
718 (p->end_time_h == 0xffffffff && p->end_time_l == 0xffffffff)
719 ? -1 : (int)(tt - t)));
720 }
721 break;
722 }
723
724 case WL_MSCH_PROFILER_EVENT_LOG: {
725 while (len >= (int)WL_MSCH_EVENT_LOG_HEAD_SIZE) {
726 msch_event_log_profiler_event_data_t *p =
727 (msch_event_log_profiler_event_data_t *)data;
728 /* How to parse MSCH if extended event tag is present ???
729 */
730 prcd_event_log_hdr_t hdr;
731 int size =
732 WL_MSCH_EVENT_LOG_HEAD_SIZE + p->hdr.count * sizeof(uint32);
733 if (len < size ||
734 size > sizeof(msch_event_log_profiler_event_data_t)) {
735 break;
736 }
737 data += size;
738 len -= size;
739 dhd_mschdbg_us_to_sec(p->time_hi, p->time_lo, &s, &ss);
740 MSCH_EVENT_HEAD(0);
741 MSCH_EVENT(("%06d.%06d [wl%d]: ", s, ss, p->hdr.tag));
742 bzero(&hdr, sizeof(hdr));
743 hdr.tag = EVENT_LOG_TAG_MSCHPROFILE;
744 hdr.count = p->hdr.count + 1;
745 /* exclude LSB 2 bits which indicate binary/non-binary data */
746 hdr.fmt_num = ntoh16(p->hdr.fmt_num) >> 2;
747 hdr.fmt_num_raw = ntoh16(p->hdr.fmt_num);
748 if (ntoh16(p->hdr.fmt_num) == DHD_OW_BI_RAW_EVENT_LOG_FMT) {
749 hdr.binary_payload = TRUE;
750 }
751 dhd_dbg_verboselog_printf(dhdp, &hdr, raw_event_ptr, p->data, 0,
752 0);
753 }
754 lastMessages = TRUE;
755 break;
756 }
757
758 case WL_MSCH_PROFILER_MESSAGE: {
759 msch_message_profiler_event_data_t *p =
760 (msch_message_profiler_event_data_t *)data;
761 MSCH_EVENT_HEAD(0);
762 MSCH_EVENT(("%06d.%06d [wl%d]: %s", s, ss, wlc_index, p->message));
763 lastMessages = TRUE;
764 break;
765 }
766
767 case WL_MSCH_PROFILER_PROFILE_START:
768 profiler_start_time[wlc_index] = tt;
769 MSCH_EVENT_HEAD(0);
770 MSCH_EVENT(("-------------------------------\n"));
771 MSCH_EVENT_HEAD(0);
772 MSCH_EVENT(("%06d.%06d [wl%d] PROFILE DATA:\n", s, ss, wlc_index));
773 dhd_mschdbg_profiler_profiler_event_data(0x4, ver, data, 0);
774 break;
775
776 case WL_MSCH_PROFILER_PROFILE_END:
777 MSCH_EVENT_HEAD(0);
778 MSCH_EVENT(("%06d.%06d [wl%d] PROFILE END: take time %d\n", s, ss,
779 wlc_index,
780 (uint32)(tt - profiler_start_time[wlc_index])));
781 MSCH_EVENT_HEAD(0);
782 MSCH_EVENT(("-------------------------------\n"));
783 MSCH_EVENT_HEAD(0);
784 MSCH_EVENT(("\n"));
785 break;
786
787 case WL_MSCH_PROFILER_REQ_HANDLE:
788 dhd_mschdbg_req_handle_profiler_event_data(0x4, ver, data, 0, FALSE);
789 break;
790
791 case WL_MSCH_PROFILER_REQ_ENTITY:
792 dhd_mschdbg_req_entity_profiler_event_data(0x4, ver, data, 0, FALSE);
793 break;
794
795 case WL_MSCH_PROFILER_CHAN_CTXT:
796 dhd_mschdbg_chan_ctxt_profiler_event_data(0x4, ver, data, 0, FALSE);
797 break;
798
799 case WL_MSCH_PROFILER_REQ_TIMING:
800 dhd_mschdbg_req_timing_profiler_event_data(0x4, ver, "msch", data, 0,
801 FALSE);
802 break;
803
804 default:
805 MSCH_EVENT_HEAD(0);
806 MSCH_EVENT(("[wl%d] ERROR: unsupported EVENT reason code:%d; ",
807 wlc_index, type));
808 break;
809 }
810 }
811
wl_mschdbg_event_handler(dhd_pub_t * dhdp,void * raw_event_ptr,int type,void * data,int len)812 void wl_mschdbg_event_handler(dhd_pub_t *dhdp, void *raw_event_ptr, int type,
813 void *data, int len)
814 {
815 head_log = "MSCH";
816 dhd_mschdbg_dump_data(dhdp, raw_event_ptr, type, (char *)data, len);
817 }
818
wl_mschdbg_verboselog_handler(dhd_pub_t * dhdp,void * raw_event_ptr,prcd_event_log_hdr_t * plog_hdr,uint32 * log_ptr)819 void wl_mschdbg_verboselog_handler(dhd_pub_t *dhdp, void *raw_event_ptr,
820 prcd_event_log_hdr_t *plog_hdr,
821 uint32 *log_ptr)
822 {
823 uint32 log_pyld_len;
824 head_log = "CONSOLE";
825
826 if (plog_hdr->count == 0) {
827 return;
828 }
829 log_pyld_len = (plog_hdr->count - 1) * DATA_UNIT_FOR_LOG_CNT;
830
831 if (plog_hdr->tag == EVENT_LOG_TAG_MSCHPROFILE) {
832 msch_event_log_profiler_event_data_t *p =
833 (msch_event_log_profiler_event_data_t *)log_ptr;
834 /* How to parse MSCH if extended event tag is present ??? */
835 prcd_event_log_hdr_t hdr;
836 uint32 s, ss;
837
838 if (log_pyld_len <
839 OFFSETOF(msch_event_log_profiler_event_data_t, data) ||
840 log_pyld_len > sizeof(msch_event_log_profiler_event_data_t)) {
841 return;
842 }
843
844 dhd_mschdbg_us_to_sec(p->time_hi, p->time_lo, &s, &ss);
845 MSCH_EVENT_HEAD(0);
846 MSCH_EVENT(("%06d.%06d [wl%d]: ", s, ss, p->hdr.tag));
847 bzero(&hdr, sizeof(hdr));
848 hdr.tag = EVENT_LOG_TAG_MSCHPROFILE;
849 hdr.count = p->hdr.count + 1;
850 /* exclude LSB 2 bits which indicate binary/non-binary data */
851 hdr.fmt_num = ntoh16(p->hdr.fmt_num) >> 2;
852 hdr.fmt_num_raw = ntoh16(p->hdr.fmt_num);
853 if (ntoh16(p->hdr.fmt_num) == DHD_OW_BI_RAW_EVENT_LOG_FMT) {
854 hdr.binary_payload = TRUE;
855 }
856 dhd_dbg_verboselog_printf(dhdp, &hdr, raw_event_ptr, p->data, 0, 0);
857 } else {
858 msch_collect_tlv_t *p = (msch_collect_tlv_t *)log_ptr;
859 int type = ntoh16(p->type);
860 int len = ntoh16(p->size);
861 if (log_pyld_len < OFFSETOF(msch_collect_tlv_t, value) + len) {
862 return;
863 }
864
865 dhd_mschdbg_dump_data(dhdp, raw_event_ptr, type, p->value, len);
866 }
867 }
868 #endif /* SHOW_LOGTRACE */
869