1 /* 2 * Copyright © 2014-2017 Intel Corporation 3 * 4 * Permission is hereby granted, free of charge, to any person obtaining a 5 * copy of this software and associated documentation files (the "Software"), 6 * to deal in the Software without restriction, including without limitation 7 * the rights to use, copy, modify, merge, publish, distribute, sublicense, 8 * and/or sell copies of the Software, and to permit persons to whom the 9 * Software is furnished to do so, subject to the following conditions: 10 * 11 * The above copyright notice and this permission notice (including the next 12 * paragraph) shall be included in all copies or substantial portions of the 13 * Software. 14 * 15 * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR 16 * IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, 17 * FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL 18 * THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER 19 * LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING 20 * FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS 21 * IN THE SOFTWARE. 22 * 23 */ 24 #include <linux/debugfs.h> 25 #include <linux/relay.h> 26 #include "i915_drv.h" 27 28 #if 0 29 static void guc_log_capture_logs(struct intel_guc *guc); 30 31 /** 32 * DOC: GuC firmware log 33 * 34 * Firmware log is enabled by setting i915.guc_log_level to non-negative level. 35 * Log data is printed out via reading debugfs i915_guc_log_dump. Reading from 36 * i915_guc_load_status will print out firmware loading status and scratch 37 * registers value. 38 * 39 */ 40 41 static int guc_log_flush_complete(struct intel_guc *guc) 42 { 43 u32 action[] = { 44 INTEL_GUC_ACTION_LOG_BUFFER_FILE_FLUSH_COMPLETE 45 }; 46 47 return intel_guc_send(guc, action, ARRAY_SIZE(action)); 48 } 49 50 static int guc_log_flush(struct intel_guc *guc) 51 { 52 u32 action[] = { 53 INTEL_GUC_ACTION_FORCE_LOG_BUFFER_FLUSH, 54 0 55 }; 56 57 return intel_guc_send(guc, action, ARRAY_SIZE(action)); 58 } 59 60 static int guc_log_control(struct intel_guc *guc, u32 control_val) 61 { 62 u32 action[] = { 63 INTEL_GUC_ACTION_UK_LOG_ENABLE_LOGGING, 64 control_val 65 }; 66 67 return intel_guc_send(guc, action, ARRAY_SIZE(action)); 68 } 69 70 /* 71 * Sub buffer switch callback. Called whenever relay has to switch to a new 72 * sub buffer, relay stays on the same sub buffer if 0 is returned. 73 */ 74 static int subbuf_start_callback(struct rchan_buf *buf, 75 void *subbuf, 76 void *prev_subbuf, 77 size_t prev_padding) 78 { 79 /* Use no-overwrite mode by default, where relay will stop accepting 80 * new data if there are no empty sub buffers left. 81 * There is no strict synchronization enforced by relay between Consumer 82 * and Producer. In overwrite mode, there is a possibility of getting 83 * inconsistent/garbled data, the producer could be writing on to the 84 * same sub buffer from which Consumer is reading. This can't be avoided 85 * unless Consumer is fast enough and can always run in tandem with 86 * Producer. 87 */ 88 if (relay_buf_full(buf)) 89 return 0; 90 91 return 1; 92 } 93 94 /* 95 * file_create() callback. Creates relay file in debugfs. 96 */ 97 static struct dentry *create_buf_file_callback(const char *filename, 98 struct dentry *parent, 99 umode_t mode, 100 struct rchan_buf *buf, 101 int *is_global) 102 { 103 struct dentry *buf_file; 104 105 /* This to enable the use of a single buffer for the relay channel and 106 * correspondingly have a single file exposed to User, through which 107 * it can collect the logs in order without any post-processing. 108 * Need to set 'is_global' even if parent is NULL for early logging. 109 */ 110 *is_global = 1; 111 112 if (!parent) 113 return NULL; 114 115 /* Not using the channel filename passed as an argument, since for each 116 * channel relay appends the corresponding CPU number to the filename 117 * passed in relay_open(). This should be fine as relay just needs a 118 * dentry of the file associated with the channel buffer and that file's 119 * name need not be same as the filename passed as an argument. 120 */ 121 buf_file = debugfs_create_file("guc_log", mode, 122 parent, buf, &relay_file_operations); 123 return buf_file; 124 } 125 126 /* 127 * file_remove() default callback. Removes relay file in debugfs. 128 */ 129 static int remove_buf_file_callback(struct dentry *dentry) 130 { 131 debugfs_remove(dentry); 132 return 0; 133 } 134 135 /* relay channel callbacks */ 136 static struct rchan_callbacks relay_callbacks = { 137 .subbuf_start = subbuf_start_callback, 138 .create_buf_file = create_buf_file_callback, 139 .remove_buf_file = remove_buf_file_callback, 140 }; 141 142 static int guc_log_relay_file_create(struct intel_guc *guc) 143 { 144 struct drm_i915_private *dev_priv = guc_to_i915(guc); 145 struct dentry *log_dir; 146 int ret; 147 148 if (i915.guc_log_level < 0) 149 return 0; 150 151 /* For now create the log file in /sys/kernel/debug/dri/0 dir */ 152 log_dir = dev_priv->drm.primary->debugfs_root; 153 154 /* If /sys/kernel/debug/dri/0 location do not exist, then debugfs is 155 * not mounted and so can't create the relay file. 156 * The relay API seems to fit well with debugfs only, for availing relay 157 * there are 3 requirements which can be met for debugfs file only in a 158 * straightforward/clean manner :- 159 * i) Need the associated dentry pointer of the file, while opening the 160 * relay channel. 161 * ii) Should be able to use 'relay_file_operations' fops for the file. 162 * iii) Set the 'i_private' field of file's inode to the pointer of 163 * relay channel buffer. 164 */ 165 if (!log_dir) { 166 DRM_ERROR("Debugfs dir not available yet for GuC log file\n"); 167 return -ENODEV; 168 } 169 170 ret = relay_late_setup_files(guc->log.runtime.relay_chan, "guc_log", log_dir); 171 if (ret < 0 && ret != -EEXIST) { 172 DRM_ERROR("Couldn't associate relay chan with file %d\n", ret); 173 return ret; 174 } 175 176 return 0; 177 } 178 179 static void guc_move_to_next_buf(struct intel_guc *guc) 180 { 181 /* Make sure the updates made in the sub buffer are visible when 182 * Consumer sees the following update to offset inside the sub buffer. 183 */ 184 smp_wmb(); 185 186 /* All data has been written, so now move the offset of sub buffer. */ 187 relay_reserve(guc->log.runtime.relay_chan, guc->log.vma->obj->base.size); 188 189 /* Switch to the next sub buffer */ 190 relay_flush(guc->log.runtime.relay_chan); 191 } 192 193 static void *guc_get_write_buffer(struct intel_guc *guc) 194 { 195 if (!guc->log.runtime.relay_chan) 196 return NULL; 197 198 /* Just get the base address of a new sub buffer and copy data into it 199 * ourselves. NULL will be returned in no-overwrite mode, if all sub 200 * buffers are full. Could have used the relay_write() to indirectly 201 * copy the data, but that would have been bit convoluted, as we need to 202 * write to only certain locations inside a sub buffer which cannot be 203 * done without using relay_reserve() along with relay_write(). So its 204 * better to use relay_reserve() alone. 205 */ 206 return relay_reserve(guc->log.runtime.relay_chan, 0); 207 } 208 209 static bool guc_check_log_buf_overflow(struct intel_guc *guc, 210 enum guc_log_buffer_type type, 211 unsigned int full_cnt) 212 { 213 unsigned int prev_full_cnt = guc->log.prev_overflow_count[type]; 214 bool overflow = false; 215 216 if (full_cnt != prev_full_cnt) { 217 overflow = true; 218 219 guc->log.prev_overflow_count[type] = full_cnt; 220 guc->log.total_overflow_count[type] += full_cnt - prev_full_cnt; 221 222 if (full_cnt < prev_full_cnt) { 223 /* buffer_full_cnt is a 4 bit counter */ 224 guc->log.total_overflow_count[type] += 16; 225 } 226 DRM_ERROR_RATELIMITED("GuC log buffer overflow\n"); 227 } 228 229 return overflow; 230 } 231 232 static unsigned int guc_get_log_buffer_size(enum guc_log_buffer_type type) 233 { 234 switch (type) { 235 case GUC_ISR_LOG_BUFFER: 236 return (GUC_LOG_ISR_PAGES + 1) * PAGE_SIZE; 237 case GUC_DPC_LOG_BUFFER: 238 return (GUC_LOG_DPC_PAGES + 1) * PAGE_SIZE; 239 case GUC_CRASH_DUMP_LOG_BUFFER: 240 return (GUC_LOG_CRASH_PAGES + 1) * PAGE_SIZE; 241 default: 242 MISSING_CASE(type); 243 } 244 245 return 0; 246 } 247 248 static void guc_read_update_log_buffer(struct intel_guc *guc) 249 { 250 unsigned int buffer_size, read_offset, write_offset, bytes_to_copy, full_cnt; 251 struct guc_log_buffer_state *log_buf_state, *log_buf_snapshot_state; 252 struct guc_log_buffer_state log_buf_state_local; 253 enum guc_log_buffer_type type; 254 void *src_data, *dst_data; 255 bool new_overflow; 256 257 if (WARN_ON(!guc->log.runtime.buf_addr)) 258 return; 259 260 /* Get the pointer to shared GuC log buffer */ 261 log_buf_state = src_data = guc->log.runtime.buf_addr; 262 263 /* Get the pointer to local buffer to store the logs */ 264 log_buf_snapshot_state = dst_data = guc_get_write_buffer(guc); 265 266 /* Actual logs are present from the 2nd page */ 267 src_data += PAGE_SIZE; 268 dst_data += PAGE_SIZE; 269 270 for (type = GUC_ISR_LOG_BUFFER; type < GUC_MAX_LOG_BUFFER; type++) { 271 /* Make a copy of the state structure, inside GuC log buffer 272 * (which is uncached mapped), on the stack to avoid reading 273 * from it multiple times. 274 */ 275 memcpy(&log_buf_state_local, log_buf_state, 276 sizeof(struct guc_log_buffer_state)); 277 buffer_size = guc_get_log_buffer_size(type); 278 read_offset = log_buf_state_local.read_ptr; 279 write_offset = log_buf_state_local.sampled_write_ptr; 280 full_cnt = log_buf_state_local.buffer_full_cnt; 281 282 /* Bookkeeping stuff */ 283 guc->log.flush_count[type] += log_buf_state_local.flush_to_file; 284 new_overflow = guc_check_log_buf_overflow(guc, type, full_cnt); 285 286 /* Update the state of shared log buffer */ 287 log_buf_state->read_ptr = write_offset; 288 log_buf_state->flush_to_file = 0; 289 log_buf_state++; 290 291 if (unlikely(!log_buf_snapshot_state)) 292 continue; 293 294 /* First copy the state structure in snapshot buffer */ 295 memcpy(log_buf_snapshot_state, &log_buf_state_local, 296 sizeof(struct guc_log_buffer_state)); 297 298 /* The write pointer could have been updated by GuC firmware, 299 * after sending the flush interrupt to Host, for consistency 300 * set write pointer value to same value of sampled_write_ptr 301 * in the snapshot buffer. 302 */ 303 log_buf_snapshot_state->write_ptr = write_offset; 304 log_buf_snapshot_state++; 305 306 /* Now copy the actual logs. */ 307 if (unlikely(new_overflow)) { 308 /* copy the whole buffer in case of overflow */ 309 read_offset = 0; 310 write_offset = buffer_size; 311 } else if (unlikely((read_offset > buffer_size) || 312 (write_offset > buffer_size))) { 313 DRM_ERROR("invalid log buffer state\n"); 314 /* copy whole buffer as offsets are unreliable */ 315 read_offset = 0; 316 write_offset = buffer_size; 317 } 318 319 /* Just copy the newly written data */ 320 if (read_offset > write_offset) { 321 i915_memcpy_from_wc(dst_data, src_data, write_offset); 322 bytes_to_copy = buffer_size - read_offset; 323 } else { 324 bytes_to_copy = write_offset - read_offset; 325 } 326 i915_memcpy_from_wc(dst_data + read_offset, 327 src_data + read_offset, bytes_to_copy); 328 329 src_data += buffer_size; 330 dst_data += buffer_size; 331 } 332 333 if (log_buf_snapshot_state) 334 guc_move_to_next_buf(guc); 335 else { 336 /* Used rate limited to avoid deluge of messages, logs might be 337 * getting consumed by User at a slow rate. 338 */ 339 DRM_ERROR_RATELIMITED("no sub-buffer to capture logs\n"); 340 guc->log.capture_miss_count++; 341 } 342 } 343 344 static void capture_logs_work(struct work_struct *work) 345 { 346 struct intel_guc *guc = 347 container_of(work, struct intel_guc, log.runtime.flush_work); 348 349 guc_log_capture_logs(guc); 350 } 351 352 static bool guc_log_has_runtime(struct intel_guc *guc) 353 { 354 return guc->log.runtime.buf_addr != NULL; 355 } 356 357 static int guc_log_runtime_create(struct intel_guc *guc) 358 { 359 struct drm_i915_private *dev_priv = guc_to_i915(guc); 360 void *vaddr; 361 struct rchan *guc_log_relay_chan; 362 size_t n_subbufs, subbuf_size; 363 int ret = 0; 364 365 lockdep_assert_held(&dev_priv->drm.struct_mutex); 366 367 GEM_BUG_ON(guc_log_has_runtime(guc)); 368 369 /* Create a WC (Uncached for read) vmalloc mapping of log 370 * buffer pages, so that we can directly get the data 371 * (up-to-date) from memory. 372 */ 373 vaddr = i915_gem_object_pin_map(guc->log.vma->obj, I915_MAP_WC); 374 if (IS_ERR(vaddr)) { 375 DRM_ERROR("Couldn't map log buffer pages %d\n", ret); 376 return PTR_ERR(vaddr); 377 } 378 379 guc->log.runtime.buf_addr = vaddr; 380 381 /* Keep the size of sub buffers same as shared log buffer */ 382 subbuf_size = guc->log.vma->obj->base.size; 383 384 /* Store up to 8 snapshots, which is large enough to buffer sufficient 385 * boot time logs and provides enough leeway to User, in terms of 386 * latency, for consuming the logs from relay. Also doesn't take 387 * up too much memory. 388 */ 389 n_subbufs = 8; 390 391 /* Create a relay channel, so that we have buffers for storing 392 * the GuC firmware logs, the channel will be linked with a file 393 * later on when debugfs is registered. 394 */ 395 guc_log_relay_chan = relay_open(NULL, NULL, subbuf_size, 396 n_subbufs, &relay_callbacks, dev_priv); 397 if (!guc_log_relay_chan) { 398 DRM_ERROR("Couldn't create relay chan for GuC logging\n"); 399 400 ret = -ENOMEM; 401 goto err_vaddr; 402 } 403 404 GEM_BUG_ON(guc_log_relay_chan->subbuf_size < subbuf_size); 405 guc->log.runtime.relay_chan = guc_log_relay_chan; 406 407 INIT_WORK(&guc->log.runtime.flush_work, capture_logs_work); 408 409 /* 410 * GuC log buffer flush work item has to do register access to 411 * send the ack to GuC and this work item, if not synced before 412 * suspend, can potentially get executed after the GFX device is 413 * suspended. 414 * By marking the WQ as freezable, we don't have to bother about 415 * flushing of this work item from the suspend hooks, the pending 416 * work item if any will be either executed before the suspend 417 * or scheduled later on resume. This way the handling of work 418 * item can be kept same between system suspend & rpm suspend. 419 */ 420 guc->log.runtime.flush_wq = alloc_ordered_workqueue("i915-guc_log", 421 WQ_HIGHPRI | WQ_FREEZABLE); 422 if (!guc->log.runtime.flush_wq) { 423 DRM_ERROR("Couldn't allocate the wq for GuC logging\n"); 424 ret = -ENOMEM; 425 goto err_relaychan; 426 } 427 428 return 0; 429 430 err_relaychan: 431 relay_close(guc->log.runtime.relay_chan); 432 err_vaddr: 433 i915_gem_object_unpin_map(guc->log.vma->obj); 434 guc->log.runtime.buf_addr = NULL; 435 return ret; 436 } 437 438 static void guc_log_runtime_destroy(struct intel_guc *guc) 439 { 440 /* 441 * It's possible that the runtime stuff was never allocated because 442 * guc_log_level was < 0 at the time 443 **/ 444 if (!guc_log_has_runtime(guc)) 445 return; 446 447 destroy_workqueue(guc->log.runtime.flush_wq); 448 relay_close(guc->log.runtime.relay_chan); 449 i915_gem_object_unpin_map(guc->log.vma->obj); 450 guc->log.runtime.buf_addr = NULL; 451 } 452 453 static int guc_log_late_setup(struct intel_guc *guc) 454 { 455 struct drm_i915_private *dev_priv = guc_to_i915(guc); 456 int ret; 457 458 lockdep_assert_held(&dev_priv->drm.struct_mutex); 459 460 if (!guc_log_has_runtime(guc)) { 461 /* If log_level was set as -1 at boot time, then setup needed to 462 * handle log buffer flush interrupts would not have been done yet, 463 * so do that now. 464 */ 465 ret = guc_log_runtime_create(guc); 466 if (ret) 467 goto err; 468 } 469 470 ret = guc_log_relay_file_create(guc); 471 if (ret) 472 goto err_runtime; 473 474 return 0; 475 476 err_runtime: 477 guc_log_runtime_destroy(guc); 478 err: 479 /* logging will remain off */ 480 i915.guc_log_level = -1; 481 return ret; 482 } 483 484 static void guc_log_capture_logs(struct intel_guc *guc) 485 { 486 struct drm_i915_private *dev_priv = guc_to_i915(guc); 487 488 guc_read_update_log_buffer(guc); 489 490 /* Generally device is expected to be active only at this 491 * time, so get/put should be really quick. 492 */ 493 intel_runtime_pm_get(dev_priv); 494 guc_log_flush_complete(guc); 495 intel_runtime_pm_put(dev_priv); 496 } 497 498 static void guc_flush_logs(struct intel_guc *guc) 499 { 500 struct drm_i915_private *dev_priv = guc_to_i915(guc); 501 502 if (!i915.enable_guc_submission || (i915.guc_log_level < 0)) 503 return; 504 505 /* First disable the interrupts, will be renabled afterwards */ 506 gen9_disable_guc_interrupts(dev_priv); 507 508 /* Before initiating the forceful flush, wait for any pending/ongoing 509 * flush to complete otherwise forceful flush may not actually happen. 510 */ 511 flush_work(&guc->log.runtime.flush_work); 512 513 /* Ask GuC to update the log buffer state */ 514 guc_log_flush(guc); 515 516 /* GuC would have updated log buffer by now, so capture it */ 517 guc_log_capture_logs(guc); 518 } 519 #endif 520 521 int intel_guc_log_create(struct intel_guc *guc) 522 { 523 struct i915_vma *vma; 524 unsigned long offset; 525 uint32_t size, flags; 526 int ret; 527 528 GEM_BUG_ON(guc->log.vma); 529 530 if (i915.guc_log_level > GUC_LOG_VERBOSITY_MAX) 531 i915.guc_log_level = GUC_LOG_VERBOSITY_MAX; 532 533 /* The first page is to save log buffer state. Allocate one 534 * extra page for others in case for overlap */ 535 size = (1 + GUC_LOG_DPC_PAGES + 1 + 536 GUC_LOG_ISR_PAGES + 1 + 537 GUC_LOG_CRASH_PAGES + 1) << PAGE_SHIFT; 538 539 /* We require SSE 4.1 for fast reads from the GuC log buffer and 540 * it should be present on the chipsets supporting GuC based 541 * submisssions. 542 */ 543 if (WARN_ON(!i915_has_memcpy_from_wc())) { 544 ret = -EINVAL; 545 goto err; 546 } 547 548 vma = intel_guc_allocate_vma(guc, size); 549 if (IS_ERR(vma)) { 550 ret = PTR_ERR(vma); 551 goto err; 552 } 553 554 guc->log.vma = vma; 555 556 #if 0 557 if (i915.guc_log_level >= 0) { 558 ret = guc_log_runtime_create(guc); 559 if (ret < 0) 560 goto err_vma; 561 } 562 #endif 563 564 /* each allocated unit is a page */ 565 flags = GUC_LOG_VALID | GUC_LOG_NOTIFY_ON_HALF_FULL | 566 (GUC_LOG_DPC_PAGES << GUC_LOG_DPC_SHIFT) | 567 (GUC_LOG_ISR_PAGES << GUC_LOG_ISR_SHIFT) | 568 (GUC_LOG_CRASH_PAGES << GUC_LOG_CRASH_SHIFT); 569 570 offset = guc_ggtt_offset(vma) >> PAGE_SHIFT; /* in pages */ 571 guc->log.flags = (offset << GUC_LOG_BUF_ADDR_SHIFT) | flags; 572 573 return 0; 574 575 #if 0 576 err_vma: 577 i915_vma_unpin_and_release(&guc->log.vma); 578 #endif 579 err: 580 /* logging will be off */ 581 i915.guc_log_level = -1; 582 return ret; 583 } 584 585 void intel_guc_log_destroy(struct intel_guc *guc) 586 { 587 #if 0 588 guc_log_runtime_destroy(guc); 589 #endif 590 i915_vma_unpin_and_release(&guc->log.vma); 591 } 592 593 #if 0 594 int i915_guc_log_control(struct drm_i915_private *dev_priv, u64 control_val) 595 { 596 struct intel_guc *guc = &dev_priv->guc; 597 598 union guc_log_control log_param; 599 int ret; 600 601 log_param.value = control_val; 602 603 if (log_param.verbosity < GUC_LOG_VERBOSITY_MIN || 604 log_param.verbosity > GUC_LOG_VERBOSITY_MAX) 605 return -EINVAL; 606 607 /* This combination doesn't make sense & won't have any effect */ 608 if (!log_param.logging_enabled && (i915.guc_log_level < 0)) 609 return 0; 610 611 ret = guc_log_control(guc, log_param.value); 612 if (ret < 0) { 613 DRM_DEBUG_DRIVER("guc_logging_control action failed %d\n", ret); 614 return ret; 615 } 616 617 if (log_param.logging_enabled) { 618 i915.guc_log_level = log_param.verbosity; 619 620 /* If log_level was set as -1 at boot time, then the relay channel file 621 * wouldn't have been created by now and interrupts also would not have 622 * been enabled. Try again now, just in case. 623 */ 624 ret = guc_log_late_setup(guc); 625 if (ret < 0) { 626 DRM_DEBUG_DRIVER("GuC log late setup failed %d\n", ret); 627 return ret; 628 } 629 630 /* GuC logging is currently the only user of Guc2Host interrupts */ 631 gen9_enable_guc_interrupts(dev_priv); 632 } else { 633 /* Once logging is disabled, GuC won't generate logs & send an 634 * interrupt. But there could be some data in the log buffer 635 * which is yet to be captured. So request GuC to update the log 636 * buffer state and then collect the left over logs. 637 */ 638 guc_flush_logs(guc); 639 640 /* As logging is disabled, update log level to reflect that */ 641 i915.guc_log_level = -1; 642 } 643 644 return ret; 645 } 646 #endif 647 648 void i915_guc_log_register(struct drm_i915_private *dev_priv) 649 { 650 if (!i915.enable_guc_submission || i915.guc_log_level < 0) 651 return; 652 653 mutex_lock(&dev_priv->drm.struct_mutex); 654 #if 0 655 guc_log_late_setup(&dev_priv->guc); 656 #endif 657 mutex_unlock(&dev_priv->drm.struct_mutex); 658 } 659 660 void i915_guc_log_unregister(struct drm_i915_private *dev_priv) 661 { 662 if (!i915.enable_guc_submission) 663 return; 664 665 mutex_lock(&dev_priv->drm.struct_mutex); 666 /* GuC logging is currently the only user of Guc2Host interrupts */ 667 gen9_disable_guc_interrupts(dev_priv); 668 #if 0 669 guc_log_runtime_destroy(&dev_priv->guc); 670 #endif 671 mutex_unlock(&dev_priv->drm.struct_mutex); 672 } 673