From d3e35752e8d78a368940fc262b0013e1d50deed4 Mon Sep 17 00:00:00 2001 From: Arthur Hanson Rasmusson Date: Wed, 30 Sep 2026 12:54:11 -0400 Subject: sema-svc: gate per-push/per-doorbell/RPC tracing behind default-off sema_dbg A healthy run left dmesg dominated by per-operation lines (sema-push, sema-lda, sema-chan rel-apply, sema-grce, DOORBELL/BAR writes, GSPRM per-RPC lines, the teardown garbage-element stream). Introduce the module parameter sema_dbg (default 0) and route every high-frequency diagnostic through it; the finer-grained watch knobs (sema_ops_log, sema_copy_watch, sema_copy_pat, sema_copy_dst, sema_copy_dst2) only take effect while it is on. Boot stats, channel registrations, pin events and state changes stay unconditional. Also carries the per-side translation provenance (op_tr_src, printed as prov= in the destination-window watch) and the 16 KB destination window used to observe the guest's page-table writes. Verified: fresh boot + full cdt2 smoke test (64/64, ALL OK) leaves a 520-line dmesg with zero per-push/per-doorbell/per-RPC lines. --- kernel/gsp_rm_emulation.c | 75 +++++++++++++++++++++++++++-------------------- 1 file changed, 44 insertions(+), 31 deletions(-) (limited to 'kernel/gsp_rm_emulation.c') diff --git a/kernel/gsp_rm_emulation.c b/kernel/gsp_rm_emulation.c index a9b63b1..76d4eba 100644 --- a/kernel/gsp_rm_emulation.c +++ b/kernel/gsp_rm_emulation.c @@ -650,7 +650,8 @@ int gsp_rm_post_channel_event(struct nv_vgpu_device *vgpu, u32 h_src) if (posted) { rm->events_posted += posted; - if (rm->events_posted <= 32 || (rm->events_posted % 5000) == 0) + if (gsp_sema_dbg && + (rm->events_posted <= 32 || (rm->events_posted % 5000) == 0)) nv_vgpu_info(vgpu, "GSPRM: post_event hSrc=0x%x posted=%d total=%llu", h_src, posted, rm->events_posted); @@ -2283,14 +2284,16 @@ static void gsp_rm_handle_rm_alloc(struct gsp_emu_context *ctx, memcpy(¶ms_size, p + 20, 4); memcpy(&flags, p + 24, 4); - nv_vgpu_info(ctx->vgpu, - "GSPRM: GSP_RM_ALLOC class=0x%x paramsSize=%u flags=0x%x hClient=0x%x hParent=0x%x hObject=0x%x", - class_id, params_size, flags, hc, hp, ho); + if (gsp_sema_dbg) + nv_vgpu_info(ctx->vgpu, + "GSPRM: GSP_RM_ALLOC class=0x%x paramsSize=%u flags=0x%x hClient=0x%x hParent=0x%x hObject=0x%x", + class_id, params_size, flags, hc, hp, ho); /* Full param dump for memory/channel classes and any class we have not * classified yet (rate-limited). %phN is capped at 64 bytes per print, * so chunk it. */ - if (gsp_rm_alloc_interesting(class_id) && rm->alloc_param_dumps < 60) { + if (gsp_sema_dbg && gsp_rm_alloc_interesting(class_id) && + rm->alloc_param_dumps < 60) { u32 shown = min(params_size, (u32)384); u32 off; @@ -2356,10 +2359,11 @@ static void gsp_rm_handle_rm_alloc(struct gsp_emu_context *ctx, rm->events[rm->events_n].data = (u32)data64; rm->events[rm->events_n].valid = true; rm->events_n++; - nv_vgpu_info(ctx->vgpu, - "GSPRM: event registered hEvent=0x%x hSrc=0x%x notifyIndex=%u (off %d) params=%*phN", - ho, h_src, notify_index, hc_off, (int)min(params_size, (u32)24), - params); + if (gsp_sema_dbg) + nv_vgpu_info(ctx->vgpu, + "GSPRM: event registered hEvent=0x%x hSrc=0x%x notifyIndex=%u (off %d) params=%*phN", + ho, h_src, notify_index, hc_off, + (int)min(params_size, (u32)24), params); } /* Echo the fixed alloc header + as many param bytes as are contiguous @@ -2541,10 +2545,12 @@ gsp_rm_handle_promote_fault_method_buffers(struct gsp_emu_context *ctx, memcpy(&m->e[i].base, p + 32 * i, 8); memcpy(&m->e[i].size, p + 32 * i + 8, 8); memcpy(&m->e[i].address_space, p + 32 * i + 24, 4); - nv_vgpu_info(ctx->vgpu, - "GSPRM: FAULT_METHOD_BUFFER hObject=0x%x hClient=0x%x buf[%u] base=0x%llx size=%llu ap=%u", - req->hObject, req->hClient, i, m->e[i].base, - m->e[i].size, m->e[i].address_space); + if (gsp_sema_dbg) + nv_vgpu_info(ctx->vgpu, + "GSPRM: FAULT_METHOD_BUFFER hObject=0x%x hClient=0x%x buf[%u] base=0x%llx size=%llu ap=%u", + req->hObject, req->hClient, i, + m->e[i].base, m->e[i].size, + m->e[i].address_space); } } @@ -2563,9 +2569,10 @@ static void gsp_rm_handle_rm_control(struct gsp_emu_context *ctx, memcpy(&req, req_data, GSP_RM_CTRL_HDR_SIZE); - nv_vgpu_info(ctx->vgpu, "GSPRM: GSP_RM_CONTROL cmd=0x%x hClient=0x%x hObject=0x%x paramsSize=%u flags=0x%x", - req.cmd, req.hClient, req.hObject, req.paramsSize, - req.flags); + if (gsp_sema_dbg) + nv_vgpu_info(ctx->vgpu, "GSPRM: GSP_RM_CONTROL cmd=0x%x hClient=0x%x hObject=0x%x paramsSize=%u flags=0x%x", + req.cmd, req.hClient, req.hObject, req.paramsSize, + req.flags); /* Allocate reply: control header + max possible params */ reply_data_len = GSP_RM_CTRL_HDR_SIZE + max(req.paramsSize, (u32)4096); @@ -2740,11 +2747,12 @@ static void gsp_rm_handle_rm_control(struct gsp_emu_context *ctx, * Do NOT echo the request: pure queries pass uninitialized * stack structs as input (e.g. DISPLAY_GET_IP_VERSION), so an * echo hands the driver its own stack garbage as the answer. */ - nv_vgpu_info(ctx->vgpu, "GSPRM: RM_CONTROL unknown cmd=0x%x -> generic SUCCESS", - req.cmd); + if (gsp_sema_dbg) + nv_vgpu_info(ctx->vgpu, "GSPRM: RM_CONTROL unknown cmd=0x%x -> generic SUCCESS", + req.cmd); /* Dump small request params so mapping/alloc controls that * carry PAs can be identified (rate-limited). */ - if (req.paramsSize && req.paramsSize <= 96 && + if (gsp_sema_dbg && req.paramsSize && req.paramsSize <= 96 && rm->ctrl_param_dumps < 400) { rm->ctrl_param_dumps++; nv_vgpu_info(ctx->vgpu, @@ -2783,10 +2791,12 @@ static void gsp_rm_handle_rm_control(struct gsp_emu_context *ctx, { u64 dt_us = div_u64(ktime_get_ns() - t0, 1000); - nv_vgpu_info(ctx->vgpu, - "GSPRM: RM_CONTROL reply cmd=0x%x hClient=0x%x hObject=0x%x in=%u out=%u status=0x%x us=%llu", - req.cmd, req.hClient, req.hObject, req.paramsSize, - out_params_size, out_status, dt_us); + if (gsp_sema_dbg) + nv_vgpu_info(ctx->vgpu, + "GSPRM: RM_CONTROL reply cmd=0x%x hClient=0x%x hObject=0x%x in=%u out=%u status=0x%x us=%llu", + req.cmd, req.hClient, req.hObject, + req.paramsSize, out_params_size, + out_status, dt_us); } if (gsp_rm_send(ctx, GSPRM_RPC_FUNC_GSP_RM_CONTROL, sequence, 0, @@ -2852,8 +2862,9 @@ static void gsp_rm_handle_free(struct gsp_emu_context *ctx, const u8 *elem, "GSPRM: retired %u event record(s) on FREE hObjOld=0x%x hRoot=0x%x", removed, hObjOld, hRoot); - nv_vgpu_info(ctx->vgpu, "GSPRM: FREE hObjOld=0x%x seq=%u cmd_read=%u stat_write=%u", - hObjOld, sequence, rm->cmd_read, rm->stat_write); + if (gsp_sema_dbg) + nv_vgpu_info(ctx->vgpu, "GSPRM: FREE hObjOld=0x%x seq=%u cmd_read=%u stat_write=%u", + hObjOld, sequence, rm->cmd_read, rm->stat_write); /* Small delay before FREE/UNLOADING replies: mitigates an intermittent * driver-side reply-matching race in the cleanup path. */ @@ -3097,9 +3108,10 @@ static void gsp_rm_handle_element(struct gsp_emu_context *ctx, const u8 *elem) /* Synchronous RPC: echo function+sequence with success so the * driver's rpcRecvPoll completes. */ rm->unknown_rpcs++; - nv_vgpu_info(ctx->vgpu, "GSPRM: RPC %s(%u) seq=%u len=%u -> generic SUCCESS reply (unknown #%llu)", - gsp_rm_rpc_name(function), function, sequence, - hdr->length, rm->unknown_rpcs); + if (gsp_sema_dbg) + nv_vgpu_info(ctx->vgpu, "GSPRM: RPC %s(%u) seq=%u len=%u -> generic SUCCESS reply (unknown #%llu)", + gsp_rm_rpc_name(function), function, + sequence, hdr->length, rm->unknown_rpcs); if (gsp_rm_send(ctx, function, sequence, 0, NULL, 0)) nv_vgpu_err(ctx->vgpu, "GSPRM: reply send failed fn=%u", function); else @@ -3171,9 +3183,10 @@ static void gsp_rm_poll_commands(struct gsp_emu_context *ctx) * Booter-unload kick (SEC2 CPUCTL) trigger the reset * via gsp_emu_clear_boot_state. This allows the * driver's cleanup frees to complete. */ - nv_vgpu_info(ctx->vgpu, "GSPRM: garbage element idx=%u sig=0x%x elemCount=%u fn=%u, stopping poll (teardown?)", - rm->cmd_read, signature, elem_count, - hdr->function); + if (gsp_sema_dbg) + nv_vgpu_info(ctx->vgpu, "GSPRM: garbage element idx=%u sig=0x%x elemCount=%u fn=%u, stopping poll (teardown?)", + rm->cmd_read, signature, elem_count, + hdr->function); kfree(elem); return; } -- cgit v1.2.3