| 1 | // SPDX-License-Identifier: MIT |
| 2 | /* |
| 3 | * Copyright © 2014-2019 Intel Corporation |
| 4 | */ |
| 5 | |
| 6 | #include <linux/debugfs.h> |
| 7 | #include <linux/string_helpers.h> |
| 8 | |
| 9 | #include <drm/drm_managed.h> |
| 10 | |
| 11 | #include "gt/intel_gt.h" |
| 12 | #include "i915_drv.h" |
| 13 | #include "i915_irq.h" |
| 14 | #include "i915_memcpy.h" |
| 15 | #include "intel_guc_capture.h" |
| 16 | #include "intel_guc_log.h" |
| 17 | #include "intel_guc_print.h" |
| 18 | |
| 19 | #if IS_ENABLED(CONFIG_DRM_I915_DEBUG_GUC) |
| 20 | #define GUC_LOG_DEFAULT_CRASH_BUFFER_SIZE SZ_2M |
| 21 | #define GUC_LOG_DEFAULT_DEBUG_BUFFER_SIZE SZ_16M |
| 22 | #define GUC_LOG_DEFAULT_CAPTURE_BUFFER_SIZE SZ_1M |
| 23 | #elif IS_ENABLED(CONFIG_DRM_I915_DEBUG_GEM) |
| 24 | #define GUC_LOG_DEFAULT_CRASH_BUFFER_SIZE SZ_1M |
| 25 | #define GUC_LOG_DEFAULT_DEBUG_BUFFER_SIZE SZ_2M |
| 26 | #define GUC_LOG_DEFAULT_CAPTURE_BUFFER_SIZE SZ_1M |
| 27 | #else |
| 28 | #define GUC_LOG_DEFAULT_CRASH_BUFFER_SIZE SZ_8K |
| 29 | #define GUC_LOG_DEFAULT_DEBUG_BUFFER_SIZE SZ_64K |
| 30 | #define GUC_LOG_DEFAULT_CAPTURE_BUFFER_SIZE SZ_1M |
| 31 | #endif |
| 32 | |
| 33 | static void guc_log_copy_debuglogs_for_relay(struct intel_guc_log *log); |
| 34 | |
| 35 | struct guc_log_section { |
| 36 | u32 max; |
| 37 | u32 flag; |
| 38 | u32 default_val; |
| 39 | const char *name; |
| 40 | }; |
| 41 | |
| 42 | static void _guc_log_init_sizes(struct intel_guc_log *log) |
| 43 | { |
| 44 | struct intel_guc *guc = log_to_guc(log); |
| 45 | static const struct guc_log_section sections[GUC_LOG_SECTIONS_LIMIT] = { |
| 46 | { |
| 47 | GUC_LOG_CRASH_MASK >> GUC_LOG_CRASH_SHIFT, |
| 48 | GUC_LOG_LOG_ALLOC_UNITS, |
| 49 | GUC_LOG_DEFAULT_CRASH_BUFFER_SIZE, |
| 50 | "crash dump" |
| 51 | }, |
| 52 | { |
| 53 | GUC_LOG_DEBUG_MASK >> GUC_LOG_DEBUG_SHIFT, |
| 54 | GUC_LOG_LOG_ALLOC_UNITS, |
| 55 | GUC_LOG_DEFAULT_DEBUG_BUFFER_SIZE, |
| 56 | "debug" , |
| 57 | }, |
| 58 | { |
| 59 | GUC_LOG_CAPTURE_MASK >> GUC_LOG_CAPTURE_SHIFT, |
| 60 | GUC_LOG_CAPTURE_ALLOC_UNITS, |
| 61 | GUC_LOG_DEFAULT_CAPTURE_BUFFER_SIZE, |
| 62 | "capture" , |
| 63 | } |
| 64 | }; |
| 65 | int i; |
| 66 | |
| 67 | for (i = 0; i < GUC_LOG_SECTIONS_LIMIT; i++) |
| 68 | log->sizes[i].bytes = sections[i].default_val; |
| 69 | |
| 70 | /* If debug size > 1MB then bump default crash size to keep the same units */ |
| 71 | if (log->sizes[GUC_LOG_SECTIONS_DEBUG].bytes >= SZ_1M && |
| 72 | GUC_LOG_DEFAULT_CRASH_BUFFER_SIZE < SZ_1M) |
| 73 | log->sizes[GUC_LOG_SECTIONS_CRASH].bytes = SZ_1M; |
| 74 | |
| 75 | /* Prepare the GuC API structure fields: */ |
| 76 | for (i = 0; i < GUC_LOG_SECTIONS_LIMIT; i++) { |
| 77 | /* Convert to correct units */ |
| 78 | if ((log->sizes[i].bytes % SZ_1M) == 0) { |
| 79 | log->sizes[i].units = SZ_1M; |
| 80 | log->sizes[i].flag = sections[i].flag; |
| 81 | } else { |
| 82 | log->sizes[i].units = SZ_4K; |
| 83 | log->sizes[i].flag = 0; |
| 84 | } |
| 85 | |
| 86 | if (!IS_ALIGNED(log->sizes[i].bytes, log->sizes[i].units)) |
| 87 | guc_err(guc, "Mis-aligned log %s size: 0x%X vs 0x%X!\n" , |
| 88 | sections[i].name, log->sizes[i].bytes, log->sizes[i].units); |
| 89 | log->sizes[i].count = log->sizes[i].bytes / log->sizes[i].units; |
| 90 | |
| 91 | if (!log->sizes[i].count) { |
| 92 | guc_err(guc, "Zero log %s size!\n" , sections[i].name); |
| 93 | } else { |
| 94 | /* Size is +1 unit */ |
| 95 | log->sizes[i].count--; |
| 96 | } |
| 97 | |
| 98 | /* Clip to field size */ |
| 99 | if (log->sizes[i].count > sections[i].max) { |
| 100 | guc_err(guc, "log %s size too large: %d vs %d!\n" , |
| 101 | sections[i].name, log->sizes[i].count + 1, sections[i].max + 1); |
| 102 | log->sizes[i].count = sections[i].max; |
| 103 | } |
| 104 | } |
| 105 | |
| 106 | if (log->sizes[GUC_LOG_SECTIONS_CRASH].units != log->sizes[GUC_LOG_SECTIONS_DEBUG].units) { |
| 107 | guc_err(guc, "Unit mismatch for crash and debug sections: %d vs %d!\n" , |
| 108 | log->sizes[GUC_LOG_SECTIONS_CRASH].units, |
| 109 | log->sizes[GUC_LOG_SECTIONS_DEBUG].units); |
| 110 | log->sizes[GUC_LOG_SECTIONS_CRASH].units = log->sizes[GUC_LOG_SECTIONS_DEBUG].units; |
| 111 | log->sizes[GUC_LOG_SECTIONS_CRASH].count = 0; |
| 112 | } |
| 113 | |
| 114 | log->sizes_initialised = true; |
| 115 | } |
| 116 | |
| 117 | static void guc_log_init_sizes(struct intel_guc_log *log) |
| 118 | { |
| 119 | if (log->sizes_initialised) |
| 120 | return; |
| 121 | |
| 122 | _guc_log_init_sizes(log); |
| 123 | } |
| 124 | |
| 125 | static u32 intel_guc_log_section_size_crash(struct intel_guc_log *log) |
| 126 | { |
| 127 | guc_log_init_sizes(log); |
| 128 | |
| 129 | return log->sizes[GUC_LOG_SECTIONS_CRASH].bytes; |
| 130 | } |
| 131 | |
| 132 | static u32 intel_guc_log_section_size_debug(struct intel_guc_log *log) |
| 133 | { |
| 134 | guc_log_init_sizes(log); |
| 135 | |
| 136 | return log->sizes[GUC_LOG_SECTIONS_DEBUG].bytes; |
| 137 | } |
| 138 | |
| 139 | u32 intel_guc_log_section_size_capture(struct intel_guc_log *log) |
| 140 | { |
| 141 | guc_log_init_sizes(log); |
| 142 | |
| 143 | return log->sizes[GUC_LOG_SECTIONS_CAPTURE].bytes; |
| 144 | } |
| 145 | |
| 146 | static u32 intel_guc_log_size(struct intel_guc_log *log) |
| 147 | { |
| 148 | /* |
| 149 | * GuC Log buffer Layout: |
| 150 | * |
| 151 | * NB: Ordering must follow "enum guc_log_buffer_type". |
| 152 | * |
| 153 | * +===============================+ 00B |
| 154 | * | Debug state header | |
| 155 | * +-------------------------------+ 32B |
| 156 | * | Crash dump state header | |
| 157 | * +-------------------------------+ 64B |
| 158 | * | Capture state header | |
| 159 | * +-------------------------------+ 96B |
| 160 | * | | |
| 161 | * +===============================+ PAGE_SIZE (4KB) |
| 162 | * | Debug logs | |
| 163 | * +===============================+ + DEBUG_SIZE |
| 164 | * | Crash Dump logs | |
| 165 | * +===============================+ + CRASH_SIZE |
| 166 | * | Capture logs | |
| 167 | * +===============================+ + CAPTURE_SIZE |
| 168 | */ |
| 169 | return PAGE_SIZE + |
| 170 | intel_guc_log_section_size_crash(log) + |
| 171 | intel_guc_log_section_size_debug(log) + |
| 172 | intel_guc_log_section_size_capture(log); |
| 173 | } |
| 174 | |
| 175 | /** |
| 176 | * DOC: GuC firmware log |
| 177 | * |
| 178 | * Firmware log is enabled by setting i915.guc_log_level to the positive level. |
| 179 | * Log data is printed out via reading debugfs i915_guc_log_dump. Reading from |
| 180 | * i915_guc_load_status will print out firmware loading status and scratch |
| 181 | * registers value. |
| 182 | */ |
| 183 | |
| 184 | static int guc_action_flush_log_complete(struct intel_guc *guc) |
| 185 | { |
| 186 | u32 action[] = { |
| 187 | INTEL_GUC_ACTION_LOG_BUFFER_FILE_FLUSH_COMPLETE, |
| 188 | GUC_DEBUG_LOG_BUFFER |
| 189 | }; |
| 190 | |
| 191 | return intel_guc_send_nb(guc, action, ARRAY_SIZE(action), g2h_len_dw: 0); |
| 192 | } |
| 193 | |
| 194 | static int guc_action_flush_log(struct intel_guc *guc) |
| 195 | { |
| 196 | u32 action[] = { |
| 197 | INTEL_GUC_ACTION_FORCE_LOG_BUFFER_FLUSH, |
| 198 | 0 |
| 199 | }; |
| 200 | |
| 201 | return intel_guc_send(guc, action, ARRAY_SIZE(action)); |
| 202 | } |
| 203 | |
| 204 | static int guc_action_control_log(struct intel_guc *guc, bool enable, |
| 205 | bool default_logging, u32 verbosity) |
| 206 | { |
| 207 | u32 action[] = { |
| 208 | INTEL_GUC_ACTION_UK_LOG_ENABLE_LOGGING, |
| 209 | (enable ? GUC_LOG_CONTROL_LOGGING_ENABLED : 0) | |
| 210 | (verbosity << GUC_LOG_CONTROL_VERBOSITY_SHIFT) | |
| 211 | (default_logging ? GUC_LOG_CONTROL_DEFAULT_LOGGING : 0) |
| 212 | }; |
| 213 | |
| 214 | GEM_BUG_ON(verbosity > GUC_LOG_VERBOSITY_MAX); |
| 215 | |
| 216 | return intel_guc_send(guc, action, ARRAY_SIZE(action)); |
| 217 | } |
| 218 | |
| 219 | /* |
| 220 | * Sub buffer switch callback. Called whenever relay has to switch to a new |
| 221 | * sub buffer, relay stays on the same sub buffer if 0 is returned. |
| 222 | */ |
| 223 | static int subbuf_start_callback(struct rchan_buf *buf, |
| 224 | void *subbuf, |
| 225 | void *prev_subbuf) |
| 226 | { |
| 227 | /* |
| 228 | * Use no-overwrite mode by default, where relay will stop accepting |
| 229 | * new data if there are no empty sub buffers left. |
| 230 | * There is no strict synchronization enforced by relay between Consumer |
| 231 | * and Producer. In overwrite mode, there is a possibility of getting |
| 232 | * inconsistent/garbled data, the producer could be writing on to the |
| 233 | * same sub buffer from which Consumer is reading. This can't be avoided |
| 234 | * unless Consumer is fast enough and can always run in tandem with |
| 235 | * Producer. |
| 236 | */ |
| 237 | if (relay_buf_full(buf)) |
| 238 | return 0; |
| 239 | |
| 240 | return 1; |
| 241 | } |
| 242 | |
| 243 | /* |
| 244 | * file_create() callback. Creates relay file in debugfs. |
| 245 | */ |
| 246 | static struct dentry *create_buf_file_callback(const char *filename, |
| 247 | struct dentry *parent, |
| 248 | umode_t mode, |
| 249 | struct rchan_buf *buf, |
| 250 | int *is_global) |
| 251 | { |
| 252 | struct dentry *buf_file; |
| 253 | |
| 254 | /* |
| 255 | * This to enable the use of a single buffer for the relay channel and |
| 256 | * correspondingly have a single file exposed to User, through which |
| 257 | * it can collect the logs in order without any post-processing. |
| 258 | * Need to set 'is_global' even if parent is NULL for early logging. |
| 259 | */ |
| 260 | *is_global = 1; |
| 261 | |
| 262 | if (!parent) |
| 263 | return NULL; |
| 264 | |
| 265 | buf_file = debugfs_create_file(filename, mode, |
| 266 | parent, buf, &relay_file_operations); |
| 267 | if (IS_ERR(ptr: buf_file)) |
| 268 | return NULL; |
| 269 | |
| 270 | return buf_file; |
| 271 | } |
| 272 | |
| 273 | /* |
| 274 | * file_remove() default callback. Removes relay file in debugfs. |
| 275 | */ |
| 276 | static int remove_buf_file_callback(struct dentry *dentry) |
| 277 | { |
| 278 | debugfs_remove(dentry); |
| 279 | return 0; |
| 280 | } |
| 281 | |
| 282 | /* relay channel callbacks */ |
| 283 | static const struct rchan_callbacks relay_callbacks = { |
| 284 | .subbuf_start = subbuf_start_callback, |
| 285 | .create_buf_file = create_buf_file_callback, |
| 286 | .remove_buf_file = remove_buf_file_callback, |
| 287 | }; |
| 288 | |
| 289 | static void guc_move_to_next_buf(struct intel_guc_log *log) |
| 290 | { |
| 291 | /* |
| 292 | * Make sure the updates made in the sub buffer are visible when |
| 293 | * Consumer sees the following update to offset inside the sub buffer. |
| 294 | */ |
| 295 | smp_wmb(); |
| 296 | |
| 297 | /* All data has been written, so now move the offset of sub buffer. */ |
| 298 | relay_reserve(chan: log->relay.channel, length: log->vma->obj->base.size - |
| 299 | intel_guc_log_section_size_capture(log)); |
| 300 | |
| 301 | /* Switch to the next sub buffer */ |
| 302 | relay_flush(chan: log->relay.channel); |
| 303 | } |
| 304 | |
| 305 | static void *guc_get_write_buffer(struct intel_guc_log *log) |
| 306 | { |
| 307 | /* |
| 308 | * Just get the base address of a new sub buffer and copy data into it |
| 309 | * ourselves. NULL will be returned in no-overwrite mode, if all sub |
| 310 | * buffers are full. Could have used the relay_write() to indirectly |
| 311 | * copy the data, but that would have been bit convoluted, as we need to |
| 312 | * write to only certain locations inside a sub buffer which cannot be |
| 313 | * done without using relay_reserve() along with relay_write(). So its |
| 314 | * better to use relay_reserve() alone. |
| 315 | */ |
| 316 | return relay_reserve(chan: log->relay.channel, length: 0); |
| 317 | } |
| 318 | |
| 319 | bool intel_guc_check_log_buf_overflow(struct intel_guc_log *log, |
| 320 | enum guc_log_buffer_type type, |
| 321 | unsigned int full_cnt) |
| 322 | { |
| 323 | unsigned int prev_full_cnt = log->stats[type].sampled_overflow; |
| 324 | bool overflow = false; |
| 325 | |
| 326 | if (full_cnt != prev_full_cnt) { |
| 327 | overflow = true; |
| 328 | |
| 329 | log->stats[type].overflow = full_cnt; |
| 330 | log->stats[type].sampled_overflow += full_cnt - prev_full_cnt; |
| 331 | |
| 332 | if (full_cnt < prev_full_cnt) { |
| 333 | /* buffer_full_cnt is a 4 bit counter */ |
| 334 | log->stats[type].sampled_overflow += 16; |
| 335 | } |
| 336 | |
| 337 | guc_notice_ratelimited(log_to_guc(log), "log buffer overflow\n" ); |
| 338 | } |
| 339 | |
| 340 | return overflow; |
| 341 | } |
| 342 | |
| 343 | unsigned int intel_guc_get_log_buffer_size(struct intel_guc_log *log, |
| 344 | enum guc_log_buffer_type type) |
| 345 | { |
| 346 | switch (type) { |
| 347 | case GUC_DEBUG_LOG_BUFFER: |
| 348 | return intel_guc_log_section_size_debug(log); |
| 349 | case GUC_CRASH_DUMP_LOG_BUFFER: |
| 350 | return intel_guc_log_section_size_crash(log); |
| 351 | case GUC_CAPTURE_LOG_BUFFER: |
| 352 | return intel_guc_log_section_size_capture(log); |
| 353 | default: |
| 354 | MISSING_CASE(type); |
| 355 | } |
| 356 | |
| 357 | return 0; |
| 358 | } |
| 359 | |
| 360 | size_t intel_guc_get_log_buffer_offset(struct intel_guc_log *log, |
| 361 | enum guc_log_buffer_type type) |
| 362 | { |
| 363 | enum guc_log_buffer_type i; |
| 364 | size_t offset = PAGE_SIZE;/* for the log_buffer_states */ |
| 365 | |
| 366 | for (i = GUC_DEBUG_LOG_BUFFER; i < GUC_MAX_LOG_BUFFER; ++i) { |
| 367 | if (i == type) |
| 368 | break; |
| 369 | offset += intel_guc_get_log_buffer_size(log, type: i); |
| 370 | } |
| 371 | |
| 372 | return offset; |
| 373 | } |
| 374 | |
| 375 | static void _guc_log_copy_debuglogs_for_relay(struct intel_guc_log *log) |
| 376 | { |
| 377 | struct intel_guc *guc = log_to_guc(log); |
| 378 | unsigned int buffer_size, read_offset, write_offset, bytes_to_copy, full_cnt; |
| 379 | struct guc_log_buffer_state *log_buf_state, *log_buf_snapshot_state; |
| 380 | struct guc_log_buffer_state log_buf_state_local; |
| 381 | enum guc_log_buffer_type type; |
| 382 | void *src_data, *dst_data; |
| 383 | bool new_overflow; |
| 384 | |
| 385 | mutex_lock(lock: &log->relay.lock); |
| 386 | |
| 387 | if (guc_WARN_ON(guc, !intel_guc_log_relay_created(log))) |
| 388 | goto out_unlock; |
| 389 | |
| 390 | /* Get the pointer to shared GuC log buffer */ |
| 391 | src_data = log->buf_addr; |
| 392 | log_buf_state = src_data; |
| 393 | |
| 394 | /* Get the pointer to local buffer to store the logs */ |
| 395 | log_buf_snapshot_state = dst_data = guc_get_write_buffer(log); |
| 396 | |
| 397 | if (unlikely(!log_buf_snapshot_state)) { |
| 398 | /* |
| 399 | * Used rate limited to avoid deluge of messages, logs might be |
| 400 | * getting consumed by User at a slow rate. |
| 401 | */ |
| 402 | guc_err_ratelimited(guc, "no sub-buffer to copy general logs\n" ); |
| 403 | log->relay.full_count++; |
| 404 | |
| 405 | goto out_unlock; |
| 406 | } |
| 407 | |
| 408 | /* Actual logs are present from the 2nd page */ |
| 409 | src_data += PAGE_SIZE; |
| 410 | dst_data += PAGE_SIZE; |
| 411 | |
| 412 | /* For relay logging, we exclude error state capture */ |
| 413 | for (type = GUC_DEBUG_LOG_BUFFER; type <= GUC_CRASH_DUMP_LOG_BUFFER; type++) { |
| 414 | /* |
| 415 | * Make a copy of the state structure, inside GuC log buffer |
| 416 | * (which is uncached mapped), on the stack to avoid reading |
| 417 | * from it multiple times. |
| 418 | */ |
| 419 | memcpy(to: &log_buf_state_local, from: log_buf_state, |
| 420 | len: sizeof(struct guc_log_buffer_state)); |
| 421 | buffer_size = intel_guc_get_log_buffer_size(log, type); |
| 422 | read_offset = log_buf_state_local.read_ptr; |
| 423 | write_offset = log_buf_state_local.sampled_write_ptr; |
| 424 | full_cnt = log_buf_state_local.buffer_full_cnt; |
| 425 | |
| 426 | /* Bookkeeping stuff */ |
| 427 | log->stats[type].flush += log_buf_state_local.flush_to_file; |
| 428 | new_overflow = intel_guc_check_log_buf_overflow(log, type, full_cnt); |
| 429 | |
| 430 | /* Update the state of shared log buffer */ |
| 431 | log_buf_state->read_ptr = write_offset; |
| 432 | log_buf_state->flush_to_file = 0; |
| 433 | log_buf_state++; |
| 434 | |
| 435 | /* First copy the state structure in snapshot buffer */ |
| 436 | memcpy(to: log_buf_snapshot_state, from: &log_buf_state_local, |
| 437 | len: sizeof(struct guc_log_buffer_state)); |
| 438 | |
| 439 | /* |
| 440 | * The write pointer could have been updated by GuC firmware, |
| 441 | * after sending the flush interrupt to Host, for consistency |
| 442 | * set write pointer value to same value of sampled_write_ptr |
| 443 | * in the snapshot buffer. |
| 444 | */ |
| 445 | log_buf_snapshot_state->write_ptr = write_offset; |
| 446 | log_buf_snapshot_state++; |
| 447 | |
| 448 | /* Now copy the actual logs. */ |
| 449 | if (unlikely(new_overflow)) { |
| 450 | /* copy the whole buffer in case of overflow */ |
| 451 | read_offset = 0; |
| 452 | write_offset = buffer_size; |
| 453 | } else if (unlikely((read_offset > buffer_size) || |
| 454 | (write_offset > buffer_size))) { |
| 455 | guc_err(guc, "invalid log buffer state\n" ); |
| 456 | /* copy whole buffer as offsets are unreliable */ |
| 457 | read_offset = 0; |
| 458 | write_offset = buffer_size; |
| 459 | } |
| 460 | |
| 461 | /* Just copy the newly written data */ |
| 462 | if (read_offset > write_offset) { |
| 463 | i915_memcpy_from_wc(dst: dst_data, src: src_data, len: write_offset); |
| 464 | bytes_to_copy = buffer_size - read_offset; |
| 465 | } else { |
| 466 | bytes_to_copy = write_offset - read_offset; |
| 467 | } |
| 468 | i915_memcpy_from_wc(dst: dst_data + read_offset, |
| 469 | src: src_data + read_offset, len: bytes_to_copy); |
| 470 | |
| 471 | src_data += buffer_size; |
| 472 | dst_data += buffer_size; |
| 473 | } |
| 474 | |
| 475 | guc_move_to_next_buf(log); |
| 476 | |
| 477 | out_unlock: |
| 478 | mutex_unlock(lock: &log->relay.lock); |
| 479 | } |
| 480 | |
| 481 | static void copy_debug_logs_work(struct work_struct *work) |
| 482 | { |
| 483 | struct intel_guc_log *log = |
| 484 | container_of(work, struct intel_guc_log, relay.flush_work); |
| 485 | |
| 486 | guc_log_copy_debuglogs_for_relay(log); |
| 487 | } |
| 488 | |
| 489 | static int guc_log_relay_map(struct intel_guc_log *log) |
| 490 | { |
| 491 | lockdep_assert_held(&log->relay.lock); |
| 492 | |
| 493 | if (!log->vma || !log->buf_addr) |
| 494 | return -ENODEV; |
| 495 | |
| 496 | /* |
| 497 | * WC vmalloc mapping of log buffer pages was done at |
| 498 | * GuC Log Init time, but lets keep a ref for book-keeping |
| 499 | */ |
| 500 | i915_gem_object_get(obj: log->vma->obj); |
| 501 | log->relay.buf_in_use = true; |
| 502 | |
| 503 | return 0; |
| 504 | } |
| 505 | |
| 506 | static void guc_log_relay_unmap(struct intel_guc_log *log) |
| 507 | { |
| 508 | lockdep_assert_held(&log->relay.lock); |
| 509 | |
| 510 | i915_gem_object_put(obj: log->vma->obj); |
| 511 | log->relay.buf_in_use = false; |
| 512 | } |
| 513 | |
| 514 | void intel_guc_log_init_early(struct intel_guc_log *log) |
| 515 | { |
| 516 | struct intel_guc *guc = log_to_guc(log); |
| 517 | struct drm_i915_private *i915 = guc_to_i915(guc); |
| 518 | |
| 519 | drmm_mutex_init(&i915->drm, &log->relay.lock); |
| 520 | drmm_mutex_init(&i915->drm, &log->guc_lock); |
| 521 | INIT_WORK(&log->relay.flush_work, copy_debug_logs_work); |
| 522 | log->relay.started = false; |
| 523 | } |
| 524 | |
| 525 | static int guc_log_relay_create(struct intel_guc_log *log) |
| 526 | { |
| 527 | struct intel_guc *guc = log_to_guc(log); |
| 528 | struct drm_i915_private *i915 = guc_to_i915(guc); |
| 529 | struct rchan *guc_log_relay_chan; |
| 530 | size_t n_subbufs, subbuf_size; |
| 531 | int ret; |
| 532 | |
| 533 | lockdep_assert_held(&log->relay.lock); |
| 534 | GEM_BUG_ON(!log->vma); |
| 535 | |
| 536 | /* |
| 537 | * Keep the size of sub buffers same as shared log buffer |
| 538 | * but GuC log-events excludes the error-state-capture logs |
| 539 | */ |
| 540 | subbuf_size = log->vma->size - intel_guc_log_section_size_capture(log); |
| 541 | |
| 542 | /* |
| 543 | * Store up to 8 snapshots, which is large enough to buffer sufficient |
| 544 | * boot time logs and provides enough leeway to User, in terms of |
| 545 | * latency, for consuming the logs from relay. Also doesn't take |
| 546 | * up too much memory. |
| 547 | */ |
| 548 | n_subbufs = 8; |
| 549 | |
| 550 | if (!guc->dbgfs_node) |
| 551 | return -ENOENT; |
| 552 | |
| 553 | guc_log_relay_chan = relay_open(base_filename: "guc_log" , |
| 554 | parent: guc->dbgfs_node, |
| 555 | subbuf_size, n_subbufs, |
| 556 | cb: &relay_callbacks, private_data: i915); |
| 557 | if (!guc_log_relay_chan) { |
| 558 | guc_err(guc, "Couldn't create relay channel for logging\n" ); |
| 559 | |
| 560 | ret = -ENOMEM; |
| 561 | return ret; |
| 562 | } |
| 563 | |
| 564 | GEM_BUG_ON(guc_log_relay_chan->subbuf_size < subbuf_size); |
| 565 | log->relay.channel = guc_log_relay_chan; |
| 566 | |
| 567 | return 0; |
| 568 | } |
| 569 | |
| 570 | static void guc_log_relay_destroy(struct intel_guc_log *log) |
| 571 | { |
| 572 | lockdep_assert_held(&log->relay.lock); |
| 573 | |
| 574 | relay_close(chan: log->relay.channel); |
| 575 | log->relay.channel = NULL; |
| 576 | } |
| 577 | |
| 578 | static void guc_log_copy_debuglogs_for_relay(struct intel_guc_log *log) |
| 579 | { |
| 580 | struct intel_guc *guc = log_to_guc(log); |
| 581 | struct drm_i915_private *i915 = guc_to_i915(guc); |
| 582 | intel_wakeref_t wakeref; |
| 583 | |
| 584 | _guc_log_copy_debuglogs_for_relay(log); |
| 585 | |
| 586 | /* |
| 587 | * Generally device is expected to be active only at this |
| 588 | * time, so get/put should be really quick. |
| 589 | */ |
| 590 | with_intel_runtime_pm(&i915->runtime_pm, wakeref) |
| 591 | guc_action_flush_log_complete(guc); |
| 592 | } |
| 593 | |
| 594 | static u32 __get_default_log_level(struct intel_guc_log *log) |
| 595 | { |
| 596 | struct intel_guc *guc = log_to_guc(log); |
| 597 | struct drm_i915_private *i915 = guc_to_i915(guc); |
| 598 | |
| 599 | /* A negative value means "use platform/config default" */ |
| 600 | if (i915->params.guc_log_level < 0) { |
| 601 | return (IS_ENABLED(CONFIG_DRM_I915_DEBUG) || |
| 602 | IS_ENABLED(CONFIG_DRM_I915_DEBUG_GEM)) ? |
| 603 | GUC_LOG_LEVEL_MAX : GUC_LOG_LEVEL_NON_VERBOSE; |
| 604 | } |
| 605 | |
| 606 | if (i915->params.guc_log_level > GUC_LOG_LEVEL_MAX) { |
| 607 | guc_warn(guc, "Log verbosity param out of range: %d > %d!\n" , |
| 608 | i915->params.guc_log_level, GUC_LOG_LEVEL_MAX); |
| 609 | return (IS_ENABLED(CONFIG_DRM_I915_DEBUG) || |
| 610 | IS_ENABLED(CONFIG_DRM_I915_DEBUG_GEM)) ? |
| 611 | GUC_LOG_LEVEL_MAX : GUC_LOG_LEVEL_DISABLED; |
| 612 | } |
| 613 | |
| 614 | GEM_BUG_ON(i915->params.guc_log_level < GUC_LOG_LEVEL_DISABLED); |
| 615 | GEM_BUG_ON(i915->params.guc_log_level > GUC_LOG_LEVEL_MAX); |
| 616 | return i915->params.guc_log_level; |
| 617 | } |
| 618 | |
| 619 | int intel_guc_log_create(struct intel_guc_log *log) |
| 620 | { |
| 621 | struct intel_guc *guc = log_to_guc(log); |
| 622 | struct i915_vma *vma; |
| 623 | void *vaddr; |
| 624 | u32 guc_log_size; |
| 625 | int ret; |
| 626 | |
| 627 | GEM_BUG_ON(log->vma); |
| 628 | |
| 629 | guc_log_size = intel_guc_log_size(log); |
| 630 | |
| 631 | vma = intel_guc_allocate_vma(guc, size: guc_log_size); |
| 632 | if (IS_ERR(ptr: vma)) { |
| 633 | ret = PTR_ERR(ptr: vma); |
| 634 | goto err; |
| 635 | } |
| 636 | |
| 637 | log->vma = vma; |
| 638 | /* |
| 639 | * Create a WC (Uncached for read) vmalloc mapping up front immediate access to |
| 640 | * data from memory during critical events such as error capture |
| 641 | */ |
| 642 | vaddr = i915_gem_object_pin_map_unlocked(obj: log->vma->obj, type: I915_MAP_WC); |
| 643 | if (IS_ERR(ptr: vaddr)) { |
| 644 | ret = PTR_ERR(ptr: vaddr); |
| 645 | i915_vma_unpin_and_release(p_vma: &log->vma, flags: 0); |
| 646 | goto err; |
| 647 | } |
| 648 | log->buf_addr = vaddr; |
| 649 | |
| 650 | log->level = __get_default_log_level(log); |
| 651 | guc_dbg(guc, "guc_log_level=%d (%s, verbose:%s, verbosity:%d)\n" , |
| 652 | log->level, str_enabled_disabled(log->level), |
| 653 | str_yes_no(GUC_LOG_LEVEL_IS_VERBOSE(log->level)), |
| 654 | GUC_LOG_LEVEL_TO_VERBOSITY(log->level)); |
| 655 | |
| 656 | return 0; |
| 657 | |
| 658 | err: |
| 659 | guc_err(guc, "Failed to allocate or map log buffer %pe\n" , ERR_PTR(ret)); |
| 660 | return ret; |
| 661 | } |
| 662 | |
| 663 | void intel_guc_log_destroy(struct intel_guc_log *log) |
| 664 | { |
| 665 | log->buf_addr = NULL; |
| 666 | i915_vma_unpin_and_release(p_vma: &log->vma, I915_VMA_RELEASE_MAP); |
| 667 | } |
| 668 | |
| 669 | int intel_guc_log_set_level(struct intel_guc_log *log, u32 level) |
| 670 | { |
| 671 | struct intel_guc *guc = log_to_guc(log); |
| 672 | struct drm_i915_private *i915 = guc_to_i915(guc); |
| 673 | intel_wakeref_t wakeref; |
| 674 | int ret = 0; |
| 675 | |
| 676 | BUILD_BUG_ON(GUC_LOG_VERBOSITY_MIN != 0); |
| 677 | GEM_BUG_ON(!log->vma); |
| 678 | |
| 679 | /* |
| 680 | * GuC is recognizing log levels starting from 0 to max, we're using 0 |
| 681 | * as indication that logging should be disabled. |
| 682 | */ |
| 683 | if (level < GUC_LOG_LEVEL_DISABLED || level > GUC_LOG_LEVEL_MAX) |
| 684 | return -EINVAL; |
| 685 | |
| 686 | mutex_lock(lock: &log->guc_lock); |
| 687 | |
| 688 | if (log->level == level) |
| 689 | goto out_unlock; |
| 690 | |
| 691 | with_intel_runtime_pm(&i915->runtime_pm, wakeref) |
| 692 | ret = guc_action_control_log(guc, |
| 693 | GUC_LOG_LEVEL_IS_VERBOSE(level), |
| 694 | GUC_LOG_LEVEL_IS_ENABLED(level), |
| 695 | GUC_LOG_LEVEL_TO_VERBOSITY(level)); |
| 696 | if (ret) { |
| 697 | guc_dbg(guc, "guc_log_control action failed %pe\n" , ERR_PTR(ret)); |
| 698 | goto out_unlock; |
| 699 | } |
| 700 | |
| 701 | log->level = level; |
| 702 | |
| 703 | out_unlock: |
| 704 | mutex_unlock(lock: &log->guc_lock); |
| 705 | |
| 706 | return ret; |
| 707 | } |
| 708 | |
| 709 | bool intel_guc_log_relay_created(const struct intel_guc_log *log) |
| 710 | { |
| 711 | return log->buf_addr; |
| 712 | } |
| 713 | |
| 714 | int intel_guc_log_relay_open(struct intel_guc_log *log) |
| 715 | { |
| 716 | int ret; |
| 717 | |
| 718 | if (!log->vma) |
| 719 | return -ENODEV; |
| 720 | |
| 721 | mutex_lock(lock: &log->relay.lock); |
| 722 | |
| 723 | if (intel_guc_log_relay_created(log)) { |
| 724 | ret = -EEXIST; |
| 725 | goto out_unlock; |
| 726 | } |
| 727 | |
| 728 | /* |
| 729 | * We require SSE 4.1 for fast reads from the GuC log buffer and |
| 730 | * it should be present on the chipsets supporting GuC based |
| 731 | * submissions. |
| 732 | */ |
| 733 | if (!i915_has_memcpy_from_wc()) { |
| 734 | ret = -ENXIO; |
| 735 | goto out_unlock; |
| 736 | } |
| 737 | |
| 738 | ret = guc_log_relay_create(log); |
| 739 | if (ret) |
| 740 | goto out_unlock; |
| 741 | |
| 742 | ret = guc_log_relay_map(log); |
| 743 | if (ret) |
| 744 | goto out_relay; |
| 745 | |
| 746 | mutex_unlock(lock: &log->relay.lock); |
| 747 | |
| 748 | return 0; |
| 749 | |
| 750 | out_relay: |
| 751 | guc_log_relay_destroy(log); |
| 752 | out_unlock: |
| 753 | mutex_unlock(lock: &log->relay.lock); |
| 754 | |
| 755 | return ret; |
| 756 | } |
| 757 | |
| 758 | int intel_guc_log_relay_start(struct intel_guc_log *log) |
| 759 | { |
| 760 | if (log->relay.started) |
| 761 | return -EEXIST; |
| 762 | |
| 763 | /* |
| 764 | * When GuC is logging without us relaying to userspace, we're ignoring |
| 765 | * the flush notification. This means that we need to unconditionally |
| 766 | * flush on relay enabling, since GuC only notifies us once. |
| 767 | */ |
| 768 | queue_work(wq: system_highpri_wq, work: &log->relay.flush_work); |
| 769 | |
| 770 | log->relay.started = true; |
| 771 | |
| 772 | return 0; |
| 773 | } |
| 774 | |
| 775 | void intel_guc_log_relay_flush(struct intel_guc_log *log) |
| 776 | { |
| 777 | struct intel_guc *guc = log_to_guc(log); |
| 778 | intel_wakeref_t wakeref; |
| 779 | |
| 780 | if (!log->relay.started) |
| 781 | return; |
| 782 | |
| 783 | /* |
| 784 | * Before initiating the forceful flush, wait for any pending/ongoing |
| 785 | * flush to complete otherwise forceful flush may not actually happen. |
| 786 | */ |
| 787 | flush_work(work: &log->relay.flush_work); |
| 788 | |
| 789 | with_intel_runtime_pm(guc_to_gt(guc)->uncore->rpm, wakeref) |
| 790 | guc_action_flush_log(guc); |
| 791 | |
| 792 | /* GuC would have updated log buffer by now, so copy it */ |
| 793 | guc_log_copy_debuglogs_for_relay(log); |
| 794 | } |
| 795 | |
| 796 | /* |
| 797 | * Stops the relay log. Called from intel_guc_log_relay_close(), so no |
| 798 | * possibility of race with start/flush since relay_write cannot race |
| 799 | * relay_close. |
| 800 | */ |
| 801 | static void guc_log_relay_stop(struct intel_guc_log *log) |
| 802 | { |
| 803 | struct intel_guc *guc = log_to_guc(log); |
| 804 | struct drm_i915_private *i915 = guc_to_i915(guc); |
| 805 | |
| 806 | if (!log->relay.started) |
| 807 | return; |
| 808 | |
| 809 | intel_synchronize_irq(i915); |
| 810 | |
| 811 | flush_work(work: &log->relay.flush_work); |
| 812 | |
| 813 | log->relay.started = false; |
| 814 | } |
| 815 | |
| 816 | void intel_guc_log_relay_close(struct intel_guc_log *log) |
| 817 | { |
| 818 | guc_log_relay_stop(log); |
| 819 | |
| 820 | mutex_lock(lock: &log->relay.lock); |
| 821 | GEM_BUG_ON(!intel_guc_log_relay_created(log)); |
| 822 | guc_log_relay_unmap(log); |
| 823 | guc_log_relay_destroy(log); |
| 824 | mutex_unlock(lock: &log->relay.lock); |
| 825 | } |
| 826 | |
| 827 | void intel_guc_log_handle_flush_event(struct intel_guc_log *log) |
| 828 | { |
| 829 | if (log->relay.started) |
| 830 | queue_work(wq: system_highpri_wq, work: &log->relay.flush_work); |
| 831 | } |
| 832 | |
| 833 | static const char * |
| 834 | stringify_guc_log_type(enum guc_log_buffer_type type) |
| 835 | { |
| 836 | switch (type) { |
| 837 | case GUC_DEBUG_LOG_BUFFER: |
| 838 | return "DEBUG" ; |
| 839 | case GUC_CRASH_DUMP_LOG_BUFFER: |
| 840 | return "CRASH" ; |
| 841 | case GUC_CAPTURE_LOG_BUFFER: |
| 842 | return "CAPTURE" ; |
| 843 | default: |
| 844 | MISSING_CASE(type); |
| 845 | } |
| 846 | |
| 847 | return "" ; |
| 848 | } |
| 849 | |
| 850 | /** |
| 851 | * intel_guc_log_info - dump information about GuC log relay |
| 852 | * @log: the GuC log |
| 853 | * @p: the &drm_printer |
| 854 | * |
| 855 | * Pretty printer for GuC log info |
| 856 | */ |
| 857 | void intel_guc_log_info(struct intel_guc_log *log, struct drm_printer *p) |
| 858 | { |
| 859 | enum guc_log_buffer_type type; |
| 860 | |
| 861 | if (!intel_guc_log_relay_created(log)) { |
| 862 | drm_puts(p, str: "GuC log relay not created\n" ); |
| 863 | return; |
| 864 | } |
| 865 | |
| 866 | drm_puts(p, str: "GuC logging stats:\n" ); |
| 867 | |
| 868 | drm_printf(p, f: "\tRelay full count: %u\n" , log->relay.full_count); |
| 869 | |
| 870 | for (type = GUC_DEBUG_LOG_BUFFER; type < GUC_MAX_LOG_BUFFER; type++) { |
| 871 | drm_printf(p, f: "\t%s:\tflush count %10u, overflow count %10u\n" , |
| 872 | stringify_guc_log_type(type), |
| 873 | log->stats[type].flush, |
| 874 | log->stats[type].sampled_overflow); |
| 875 | } |
| 876 | } |
| 877 | |
| 878 | /** |
| 879 | * intel_guc_log_dump - dump the contents of the GuC log |
| 880 | * @log: the GuC log |
| 881 | * @p: the &drm_printer |
| 882 | * @dump_load_err: dump the log saved on GuC load error |
| 883 | * |
| 884 | * Pretty printer for the GuC log |
| 885 | */ |
| 886 | int intel_guc_log_dump(struct intel_guc_log *log, struct drm_printer *p, |
| 887 | bool dump_load_err) |
| 888 | { |
| 889 | struct intel_guc *guc = log_to_guc(log); |
| 890 | struct intel_uc *uc = container_of(guc, struct intel_uc, guc); |
| 891 | struct drm_i915_gem_object *obj = NULL; |
| 892 | void *map; |
| 893 | u32 *page; |
| 894 | int i, j; |
| 895 | |
| 896 | if (!intel_guc_is_supported(guc)) |
| 897 | return -ENODEV; |
| 898 | |
| 899 | if (dump_load_err) |
| 900 | obj = uc->load_err_log; |
| 901 | else if (guc->log.vma) |
| 902 | obj = guc->log.vma->obj; |
| 903 | |
| 904 | if (!obj) |
| 905 | return 0; |
| 906 | |
| 907 | page = (u32 *)__get_free_page(GFP_KERNEL); |
| 908 | if (!page) |
| 909 | return -ENOMEM; |
| 910 | |
| 911 | intel_guc_dump_time_info(guc, p); |
| 912 | |
| 913 | map = i915_gem_object_pin_map_unlocked(obj, type: I915_MAP_WC); |
| 914 | if (IS_ERR(ptr: map)) { |
| 915 | guc_dbg(guc, "Failed to pin log object: %pe\n" , map); |
| 916 | drm_puts(p, str: "(log data unaccessible)\n" ); |
| 917 | free_page((unsigned long)page); |
| 918 | return PTR_ERR(ptr: map); |
| 919 | } |
| 920 | |
| 921 | for (i = 0; i < obj->base.size; i += PAGE_SIZE) { |
| 922 | if (!i915_memcpy_from_wc(dst: page, src: map + i, PAGE_SIZE)) |
| 923 | memcpy(to: page, from: map + i, PAGE_SIZE); |
| 924 | |
| 925 | for (j = 0; j < PAGE_SIZE / sizeof(u32); j += 4) |
| 926 | drm_printf(p, f: "0x%08x 0x%08x 0x%08x 0x%08x\n" , |
| 927 | *(page + j + 0), *(page + j + 1), |
| 928 | *(page + j + 2), *(page + j + 3)); |
| 929 | } |
| 930 | |
| 931 | drm_puts(p, str: "\n" ); |
| 932 | |
| 933 | i915_gem_object_unpin_map(obj); |
| 934 | free_page((unsigned long)page); |
| 935 | |
| 936 | return 0; |
| 937 | } |
| 938 | |