Victor Hsu | e0cd0e7 | 2021-06-08 11:05:03 +0800 | [diff] [blame] | 1 | /* |
| 2 | * DHD debugability support |
| 3 | * |
| 4 | * Copyright (C) 2021, 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 | |
| 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 | |
| 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 |
| 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 |
| 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 |
| 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 |
| 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 |
| 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 |
| 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 |
| 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 |
| 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 |
| 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 | |
| 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 |
| 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 |
| 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 */ |