gpu: nvgpu: Reduce linux debug log spew

Currently when nvgpu prints debug information for something like an MMU
fault the result includes a lot of usless boiler plate logging spew. In
some cases this can be helpful in identifying where the log message came
from in the nvgpu code base. However, for debug spews from faults, the
viewer of that info does not care which function printed the log (for
example).

Instead having a fast and readable debug dump is more valuable. So to
that end, add a special debug dump printing function that does not use
the normal log format. Instead, it prints only a breif prefix to use as
a grep search query. The new print out is listed below.

Since often the kernel logs are impressively long and obtuse, having a
clear debug search string can be helpful. With this log format, one can
simply do:

  $ grep __$CHIP__ kernel.log

And find any debug logs for the desired chip.

New log format - collected on a gv11b under L4T running
`nvgpu_submit_mmu_fault':

[   32.005793] nvgpu: 17000000.gv11b      gv11b_fb_mmu_fault_info_dump:311  [ERR]  [MMU FAULT] mmu engine id:  32, ch id:  511, fault addr: 0x1000, fault addr aperture: 0, fault type: invalid pde, access type: virt read,
[   32.006137] nvgpu: 17000000.gv11b      gv11b_fb_mmu_fault_info_dump:320  [ERR]  [MMU FAULT] protected mode: 0, client type: hub, client id:  host, gpc id if client type is gpc: 0,
[   32.006417] nvgpu: 17000000.gv11b                nvgpu_rc_mmu_fault:296  [ERR]  mmu fault id=0 id_type=1 act_eng_bitmask=00000000
[   32.007125] __gv11b__ Channel Status - chip gv11b
[   32.007128] __gv11b__ ---------------------------
[   32.007241] __gv11b__ 511-gv11b, TSG: 0, pid 955, refs: 2, deterministic:
[   32.007364] __gv11b__ channel status:  in use pending busy
[   32.007509] __gv11b__ RAMFC : TOP: 8000000000001000 PUT: 0000000000001030 GET: 0000000000001000 FETCH: 0000600000001000HEADER: 60400000 COUNT: 00000000SEMAPHORE: addr 0000000000000000payload 0000000000000000 execute 00000000
[   32.007601] __gv11b__
[   32.008696] __gv11b__
[   32.008700] __gv11b__ PBDMA Status - chip gv11b
[   32.008894] __gv11b__ -------------------------
[   32.013477] __gv11b__ pbdma 0:
[   32.017840] __gv11b__   id: -1 - [channel] next_id: - -1 [channel] | status: invalid
[   32.020992] __gv11b__   PBDMA_PUT 0000000000001030 PBDMA_GET 0000000000001000
[   32.029037] __gv11b__   GP_PUT    00000001  GP_GET  00000001  FETCH   00000001 HEADER 60400000
[   32.036386] __gv11b__   HDR       00000000  SHADOW0 00001000  SHADOW1 80003000
[   32.044787] __gv11b__ pbdma 1:
[   32.051964] __gv11b__   id: -1 - [channel] next_id: - -1 [channel] | status: invalid
[   32.055099] __gv11b__   PBDMA_PUT 0000000042003200 PBDMA_GET 00000050728bc914
[   32.062997] __gv11b__   GP_PUT    00000000  GP_GET  2080a000  FETCH   00000000 HEADER e1850010
[   32.070424] __gv11b__   HDR       00110000  SHADOW0 02000000  SHADOW1 10000004
[   32.078652] __gv11b__ pbdma 2:
[   32.085913] __gv11b__   id: -1 - [channel] next_id: - -1 [channel] | status: invalid
[   32.088973] __gv11b__   PBDMA_PUT 00000021040c0004 PBDMA_GET 0000000140020000
[   32.096502] __gv11b__   GP_PUT    00000000  GP_GET  8080a440  FETCH   00000000 HEADER 61400040
[   32.103679] __gv11b__   HDR       14000010  SHADOW0 00000000  SHADOW1 00000400
[   32.112336] __gv11b__
[   32.119860] __gv11b__ gv11b eng 0:
[   32.122119] __gv11b__ id: -1 (channel), next_id: -1 (channel), ctx status: invalid
[   32.125807] __gv11b__
[   32.135954] __gv11b__ gv11b eng 1:
[   32.135958] __gv11b__ id: -1 (channel), next_id: -1 (channel), ctx status: invalid
[   32.139457] __gv11b__
[   32.149945] __gv11b__ gv11b eng 2:
[   32.149950] __gv11b__ id: -1 (channel), next_id: -1 (channel), ctx status: invalid
[   32.153543] __gv11b__
[   32.163598] __gv11b__ gv11b eng 3:
[   32.163601] __gv11b__ id: -1 (channel), next_id: -1 (channel), ctx status: invalid
[   32.167278] __gv11b__
[   32.177076] __gv11b__
[   32.186145] nvgpu: 17000000.gv11b       nvgpu_tsg_set_ctx_mmu_error:492  [ERR]  TSG 0 generated a mmu fault
[   32.189443] nvgpu: 17000000.gv11b     nvgpu_set_err_notifier_locked:140  [ERR]  error notifier set to 31 for ch 511

JIRA NVGPU-5541

Change-Id: Iad60adfab5198ee11dd2ec595f2422ea541b7a2a
Signed-off-by: Alex Waterman <alexw@nvidia.com>
Reviewed-on: https://git-master.nvidia.com/r/c/linux-nvgpu/+/2349166
Tested-by: mobile promotions <svcmobile_promotions@nvidia.com>
Reviewed-by: mobile promotions <svcmobile_promotions@nvidia.com>
This commit is contained in:
Alex Waterman
2020-05-22 13:20:20 -05:00
parent 5d06a59bc5
commit 6b1302f23c
4 changed files with 29 additions and 3 deletions

View File

@@ -2595,7 +2595,6 @@ void nvgpu_channel_debug_dump_all(struct gk20a *g,
nvgpu_kfree(g, info); nvgpu_kfree(g, info);
} }
} }
gk20a_debug_output(o, " ");
nvgpu_kfree(g, infos); nvgpu_kfree(g, infos);
} }

View File

@@ -56,6 +56,28 @@ void nvgpu_log_dbg_impl(struct gk20a *g, u64 log_mask,
#define nvgpu_info_impl(g, fmt, arg...) \ #define nvgpu_info_impl(g, fmt, arg...) \
nvgpu_log_msg_impl(g, __func__, __LINE__, NVGPU_INFO, fmt, ##arg) nvgpu_log_msg_impl(g, __func__, __LINE__, NVGPU_INFO, fmt, ##arg)
/**
* nvgpu_dbg_dump_impl - Print part of a debug dump.
*
* @g - The GPU.
* @str - A debug message.
*
* Print a component of a debug message. Typically the err, warning, and
* info prints have a bunch of information about the location of the call.
* For example on Linux:
*
* nvgpu: 17000000.gv11b nvgpu_rc_mmu_fault:296 [ERR]
*
* But, for debug dumps this information is completely useless and
* redundant. This also slows down the UART terminal significantly.
* Note that this function does not take a format and subsequent args. In
* our current model the formatting happens a layer above this function
* call.
*
* This variant prints only a small prefix (to aid in grepping logs).
*/
void nvgpu_dbg_dump_impl(struct gk20a *g, const char *str);
/* /*
* Deprecated API. Do not use!! * Deprecated API. Do not use!!
*/ */
@@ -68,4 +90,4 @@ void nvgpu_log_dbg_impl(struct gk20a *g, u64 log_mask,
} \ } \
} while (false) } while (false)
#endif #endif

View File

@@ -43,7 +43,7 @@ static inline void gk20a_debug_write_printk(void *ctx, const char *str)
{ {
struct gk20a *g = ctx; struct gk20a *g = ctx;
nvgpu_err(g, str); nvgpu_dbg_dump_impl(g, str);
} }
static inline void gk20a_debug_write_to_seqfile(void *ctx, const char *str) static inline void gk20a_debug_write_to_seqfile(void *ctx, const char *str)

View File

@@ -127,3 +127,8 @@ void nvgpu_log_dbg_impl(struct gk20a *g, u64 log_mask,
__nvgpu_really_print_log(g->log_trace, nvgpu_log_name(g), __nvgpu_really_print_log(g->log_trace, nvgpu_log_name(g),
func_name, line, NVGPU_DEBUG, log); func_name, line, NVGPU_DEBUG, log);
} }
void nvgpu_dbg_dump_impl(struct gk20a *g, const char *str)
{
pr_err("__%s__ %s", g->name, str);
}