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