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