summaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
-rw-r--r--kernel/gsp_rm_emulation.c75
-rw-r--r--kernel/gsp_sema_service.c181
-rw-r--r--kernel/gsp_sema_service.h10
-rw-r--r--kernel/main.c33
4 files changed, 213 insertions, 86 deletions
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(&params_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;
}
diff --git a/kernel/gsp_sema_service.c b/kernel/gsp_sema_service.c
index 17b2ae4..75c5697 100644
--- a/kernel/gsp_sema_service.c
+++ b/kernel/gsp_sema_service.c
@@ -361,6 +361,7 @@ struct sema_svc {
u64 copy_watch_log; /* sema_copy_watch log budget */
u64 copy_pat_log; /* sema_copy_pat log budget */
u64 copy_dst_log; /* sema_copy_dst log budget */
+ u32 op_tr_src; /* provenance of last svc_op_translate */
u64 push_pat_log; /* push-content pattern budget */
u64 dma_skip_log; /* unrecognized-DMA budget */
u64 grce_log; /* GRCE inline-write budget */
@@ -1852,7 +1853,7 @@ static void svc_rebuild(struct nv_vgpu_device *vgpu)
svc.vidmem_writes, svc_ring_n, svc_pb_n, svc_pb_passes,
svc.pin_n, svc.pin_drop, svc.ipin_n, svc.ipin_drop);
/* show a few entries so mappings can be verified from dmesg */
- {
+ if (gsp_sema_dbg) {
u32 shown;
for (shown = 0; shown < svc.map_n && shown < 8; shown++)
@@ -1971,15 +1972,19 @@ static int svc_op_translate(struct nv_vgpu_device *vgpu, u64 va, u64 *addr,
u64 pa = 0;
int ap = SVC_APERTURE_SYS;
+ svc.op_tr_src = 0;
+
if (!svc_pin_lookup_any(va, &pa, &ap)) {
*addr = pa;
*aperture = (ap == SVC_APERTURE_FB) ? CE_APERTURE_VID :
CE_APERTURE_SYS;
+ svc.op_tr_src = 1;
return 0;
}
if (!svc_map_lookup(va, &pa)) {
*addr = pa;
*aperture = CE_APERTURE_SYS;
+ svc.op_tr_src = 2;
return 0;
}
/*
@@ -1992,12 +1997,14 @@ static int svc_op_translate(struct nv_vgpu_device *vgpu, u64 va, u64 *addr,
*addr = pa + (va & 0xfff);
*aperture = (ap == SVC_APERTURE_FB) ? CE_APERTURE_VID :
CE_APERTURE_SYS;
+ svc.op_tr_src = 3;
return 0;
}
if (!svc_walk_discovered(vgpu, va & ~0xfffULL, &pa, &ap)) {
*addr = pa + (va & 0xfff);
*aperture = (ap == SVC_APERTURE_FB) ? CE_APERTURE_VID :
CE_APERTURE_SYS;
+ svc.op_tr_src = 4;
return 0;
}
/*
@@ -2018,6 +2025,7 @@ static int svc_op_translate(struct nv_vgpu_device *vgpu, u64 va, u64 *addr,
pr_info("sema-op-tr: va=0x%llx -> pa=0x%llx\n",
va, *addr);
}
+ svc.op_tr_src = 5;
return 0;
}
/*
@@ -2032,6 +2040,25 @@ static int svc_op_translate(struct nv_vgpu_device *vgpu, u64 va, u64 *addr,
}
/*
+ * Does a destination address fall inside either 16 KB watch window
+ * (sema_copy_dst / sema_copy_dst2)? The window is what makes the page-table
+ * write chain observable: root PD, child tables and PTE pages all sit in
+ * distinct pages a whole run apart.
+ */
+static bool svc_dst_watched(u64 dst)
+{
+ if (gsp_sema_copy_dst &&
+ dst >= (gsp_sema_copy_dst & ~0x3fffULL) &&
+ dst < (gsp_sema_copy_dst & ~0x3fffULL) + 0x4000)
+ return true;
+ if (gsp_sema_copy_dst2 &&
+ dst >= (gsp_sema_copy_dst2 & ~0x3fffULL) &&
+ dst < (gsp_sema_copy_dst2 & ~0x3fffULL) + 0x4000)
+ return true;
+ return false;
+}
+
+/*
* Write `count` elements of `value` (element size `elem`) starting at
* `addr`, in vidmem or guest RAM depending on the aperture DST_TYPE
* selected. Returns 0 on success.
@@ -2064,6 +2091,17 @@ static int svc_fill(struct nv_vgpu_device *vgpu, u64 addr, u64 value, u32 elem,
aperture = aper;
}
+ if (gsp_sema_dbg && svc_dst_watched(addr) && svc.copy_dst_log < 192) {
+ u8 pb[8];
+
+ memset(pb, 0, sizeof(pb));
+ memcpy(pb, pat, sizeof(pb));
+ svc.copy_dst_log++;
+ pr_info("sema-copy-dst: FILL dst=0x%llx off=0x%llx total=%zu elem=%u count=%u value=0x%llx prov=%u pat=%*phN h=0x%x\n",
+ addr, addr & 0xfffULL, total, elem, count, value,
+ svc.op_tr_src, elem, pb, svc.cur_ch);
+ }
+
if (aperture == CE_APERTURE_VID) {
u8 *base = vgpu->bars[1].vaddr;
size_t size = vgpu->bars[1].size;
@@ -2110,7 +2148,7 @@ static int svc_copy(struct nv_vgpu_device *vgpu, u64 dst, u64 src, size_t total,
u32 aper;
if (svc_op_translate(vgpu, dst, &pa, &aper)) {
- if (svc.op_tr_log < 64) {
+ if (gsp_sema_dbg && svc.op_tr_log < 64) {
svc.op_tr_log++;
pr_info("sema-tr-miss: DST va=0x%llx h=0x%x\n",
dst, svc.cur_ch);
@@ -2125,7 +2163,7 @@ static int svc_copy(struct nv_vgpu_device *vgpu, u64 dst, u64 src, size_t total,
u32 aper;
if (svc_op_translate(vgpu, src, &pa, &aper)) {
- if (svc.op_tr_log < 64) {
+ if (gsp_sema_dbg && svc.op_tr_log < 64) {
svc.op_tr_log++;
pr_info("sema-tr-miss: SRC va=0x%llx h=0x%x\n",
src, svc.cur_ch);
@@ -2144,8 +2182,9 @@ static int svc_copy(struct nv_vgpu_device *vgpu, u64 dst, u64 src, size_t total,
* source or destination starts with that 8-byte value is logged too,
* whatever its size - this finds the push carrying a known payload.
*/
- if ((gsp_sema_copy_watch && total == gsp_sema_copy_watch) ||
- gsp_sema_copy_pat) {
+ if (gsp_sema_dbg &&
+ ((gsp_sema_copy_watch && total == gsp_sema_copy_watch) ||
+ gsp_sema_copy_pat)) {
u8 sb[8] = {0}, db[8] = {0};
if (src_aperture == CE_APERTURE_VID) {
@@ -2164,7 +2203,8 @@ static int svc_copy(struct nv_vgpu_device *vgpu, u64 dst, u64 src, size_t total,
} else {
svc_read(vgpu, dst, db, 8);
}
- if (gsp_sema_copy_watch && total == gsp_sema_copy_watch &&
+ if (gsp_sema_dbg && gsp_sema_copy_watch &&
+ total == gsp_sema_copy_watch &&
svc.copy_watch_log < 64) {
svc.copy_watch_log++;
pr_info("sema-copy-watch: total=%zu dst=0x%llx dap=%u src=0x%llx sap=%u src8=%02x %02x %02x %02x %02x %02x %02x %02x dst8_before=%02x %02x %02x %02x %02x %02x %02x %02x\n",
@@ -2173,7 +2213,8 @@ static int svc_copy(struct nv_vgpu_device *vgpu, u64 dst, u64 src, size_t total,
sb[6], sb[7], db[0], db[1], db[2], db[3],
db[4], db[5], db[6], db[7]);
}
- if (gsp_sema_copy_pat && svc.copy_pat_log < 64) {
+ if (gsp_sema_dbg && gsp_sema_copy_pat &&
+ svc.copy_pat_log < 64) {
u64 sv = 0, dv = 0;
memcpy(&sv, sb, 8);
@@ -2194,12 +2235,13 @@ static int svc_copy(struct nv_vgpu_device *vgpu, u64 dst, u64 src, size_t total,
/*
* Destination-keyed watch: dump the source bytes of every copy whose
- * destination lies in gsp_sema_copy_dst's page. This reads the
- * page-table entries the guest writes into vidmem directly.
+ * destination lies in the 16 KB window at gsp_sema_copy_dst. This
+ * reads the page-table entries the guest writes into vidmem directly,
+ * whatever the mechanism; `prov` names which translation layer
+ * answered for the source (1 pin, 2 map, 3 vaspaces, 4 discovered,
+ * 5 targeted RAM resolve).
*/
- if (gsp_sema_copy_dst &&
- (dst & ~0xfffULL) == (gsp_sema_copy_dst & ~0xfffULL) &&
- svc.copy_dst_log < 32) {
+ if (gsp_sema_dbg && svc_dst_watched(dst) && svc.copy_dst_log < 192) {
u8 peek[32];
u32 n = total < sizeof(peek) ? (u32)total : sizeof(peek);
@@ -2213,9 +2255,9 @@ static int svc_copy(struct nv_vgpu_device *vgpu, u64 dst, u64 src, size_t total,
svc_read(vgpu, src, peek, n);
}
svc.copy_dst_log++;
- pr_info("sema-copy-dst: dst=0x%llx off=0x%llx total=%zu src=0x%llx sap=%u data=%*phN h=0x%x\n",
+ pr_info("sema-copy-dst: dst=0x%llx off=0x%llx total=%zu src=0x%llx sap=%u prov=%u data=%*phN h=0x%x\n",
dst, dst & 0xfffULL, total, src, src_aperture,
- n, peek, svc.cur_ch);
+ svc.op_tr_src, n, peek, svc.cur_ch);
}
for (o = 0; o < total; ) {
@@ -2252,7 +2294,8 @@ static int svc_copy(struct nv_vgpu_device *vgpu, u64 dst, u64 src, size_t total,
o += chunk;
}
- if (gsp_sema_copy_watch && total == gsp_sema_copy_watch &&
+ if (gsp_sema_dbg && gsp_sema_copy_watch &&
+ total == gsp_sema_copy_watch &&
svc.copy_watch_log <= 64) {
u8 da[8] = {0};
@@ -2268,6 +2311,21 @@ static int svc_copy(struct nv_vgpu_device *vgpu, u64 dst, u64 src, size_t total,
da[0], da[1], da[2], da[3], da[4], da[5], da[6],
da[7], dst);
}
+ if (gsp_sema_dbg && svc_dst_watched(dst) && svc.copy_dst_log <= 192) {
+ u8 da[16] = {0};
+ u32 n = total < sizeof(da) ? (u32)total : sizeof(da);
+
+ if (dst_aperture == CE_APERTURE_VID) {
+ u8 *base = vgpu->bars[1].vaddr;
+
+ if (base && dst + n <= vgpu->bars[1].size)
+ memcpy(da, base + dst, n);
+ } else {
+ svc_read(vgpu, dst, da, n);
+ }
+ pr_info("sema-copy-dst: after dst=0x%llx dst16=%*phN\n",
+ dst, n, da);
+ }
return 0;
}
@@ -2286,7 +2344,7 @@ static int svc_grce_inline_write(struct nv_vgpu_device *vgpu, u64 dst_va,
if (!bytes || bytes > (1u << 20))
return -EINVAL;
if (svc_lookup_trusted(vgpu, dst_va & ~0xfffULL, &pa, &ap)) {
- if (svc.grce_log < 16) {
+ if (gsp_sema_dbg && svc.grce_log < 16) {
svc.grce_log++;
pr_info("sema-grce: inline write dst=0x%llx bytes=%u UNRESOLVED h=0x%x\n",
dst_va, bytes, ch_h);
@@ -2295,7 +2353,8 @@ static int svc_grce_inline_write(struct nv_vgpu_device *vgpu, u64 dst_va,
}
svc_pin_store(dst_va & ~0xfffULL, pa, ap);
pa += dst_va & 0xfff;
- if (svc.grce_log < (gsp_sema_ops_log > 64 ? gsp_sema_ops_log : 64)) {
+ if (gsp_sema_dbg &&
+ svc.grce_log < (gsp_sema_ops_log > 64 ? gsp_sema_ops_log : 64)) {
u32 n = bytes >= 8 ? 8 : bytes;
svc.grce_log++;
@@ -2348,15 +2407,16 @@ static void svc_run_ops(struct nv_vgpu_device *vgpu, struct svc_memset_op *ops,
svc.memsets_nomap++;
else
svc.memsets_fail++;
- if (m->bytes == 256 && svc.sem256_log < 64) {
+ if (gsp_sema_dbg && m->bytes == 256 && svc.sem256_log < 64) {
svc.sem256_log++;
pr_info("sema-256: type=%u dst=0x%llx src=0x%llx bytes=%llu rc=%d h=0x%x done=%llu nomap=%llu fail=%llu\n",
m->type, m->dst, m->src, m->bytes, rc, ch_h,
svc.memsets_done, svc.memsets_nomap,
svc.memsets_fail);
}
- if ((rc == 0 && svc.memsets_done <= gsp_sema_ops_log) ||
- (rc != 0 && svc.memsets_fail + svc.memsets_nomap <= 64))
+ if (gsp_sema_dbg &&
+ ((rc == 0 && svc.memsets_done <= gsp_sema_ops_log) ||
+ (rc != 0 && svc.memsets_fail + svc.memsets_nomap <= 64)))
pr_info("sema-svc: %s dst=0x%llx value=0x%llx elem=%u count=%u bytes=%llu phys=%u ap=%u src=0x%llx srcphys=%u srcap=%u rc=%d h=0x%x\n",
m->type == 1 ? "memcopy" : "memset",
m->dst, m->value, m->elem, m->count,
@@ -2484,12 +2544,12 @@ static void svc_counter_release_apply(struct nv_vgpu_device *vgpu, u32 h,
}
}
spin_unlock_irqrestore(&svc.chan_lock, flags);
- if (svc.counter_rel_dbg < 96) {
+ if (gsp_sema_dbg && svc.counter_rel_dbg < 96) {
svc.counter_rel_dbg++;
pr_info("sema-chan: rel-apply h=0x%x va=0x%llx pay=%u -> slot pending\n",
h, sem_va, payload);
}
- } else if (svc.counter_rel_dbg < 96) {
+ } else if (gsp_sema_dbg && svc.counter_rel_dbg < 96) {
svc.counter_rel_dbg++;
pr_info("sema-chan: rel-apply h=0x%x va=0x%llx pay=%u -> no slot registered\n",
h, sem_va, payload);
@@ -2498,7 +2558,7 @@ static void svc_counter_release_apply(struct nv_vgpu_device *vgpu, u32 h,
}
if (svc_read_ap(vgpu, pa, SVC_APERTURE_SYS, &cur, sizeof(cur))) {
- if (svc.counter_rel_dbg < 32) {
+ if (gsp_sema_dbg && svc.counter_rel_dbg < 32) {
svc.counter_rel_dbg++;
pr_info("sema-chan: rel-apply h=0x%x pa=0x%llx pay=%u -> read failed\n",
h, pa, payload);
@@ -2506,7 +2566,7 @@ static void svc_counter_release_apply(struct nv_vgpu_device *vgpu, u32 h,
return;
}
if (payload <= cur || payload - cur > 0x100000) {
- if (svc.counter_rel_dbg < 32) {
+ if (gsp_sema_dbg && svc.counter_rel_dbg < 32) {
svc.counter_rel_dbg++;
pr_info("sema-chan: rel-apply h=0x%x pa=0x%llx pay=%u cur=%u -> skip\n",
h, pa, payload, cur);
@@ -2520,7 +2580,7 @@ static void svc_counter_release_apply(struct nv_vgpu_device *vgpu, u32 h,
svc.counter_rel_applied++;
svc.gr_rel_applied++;
svc.post_hint_until = jiffies + 10 * HZ;
- if (svc.counter_rel_dbg < 32) {
+ if (gsp_sema_dbg && svc.counter_rel_dbg < 32) {
svc.counter_rel_dbg++;
pr_info("sema-chan: rel-apply h=0x%x pa=0x%llx pay=%u cur=%u -> written\n",
h, pa, payload, cur);
@@ -2561,7 +2621,7 @@ static void svc_counter_flush_pending(struct nv_vgpu_device *vgpu,
svc.counter_rel_applied++;
svc.gr_rel_applied++;
svc.post_hint_until = jiffies + 10 * HZ;
- if (svc.counter_rel_dbg < 96) {
+ if (gsp_sema_dbg && svc.counter_rel_dbg < 96) {
svc.counter_rel_dbg++;
pr_info("sema-chan: rel-flush h=0x%x pa=0x%llx pay=%u cur=%u -> written\n",
ch->h_object, ch->counter_pa, payload, cur);
@@ -2680,7 +2740,7 @@ static void svc_decode_stream(struct nv_vgpu_device *vgpu, const u8 *buf,
memset(&st, 0, sizeof(st));
svc.pages_decoded++;
- if (ch->engine_type && svc_dbg_streams < 24) {
+ if (gsp_sema_dbg && ch->engine_type && svc_dbg_streams < 24) {
svc_dbg_streams++;
pr_info("sema-dbg: stream h=0x%x eng=%u va=0x%llx len=%u allow=%d w=%08x %08x %08x %08x %08x %08x %08x %08x\n",
ch->h_object, ch->engine_type, push_va, len, allow_ops,
@@ -2700,7 +2760,7 @@ static void svc_decode_stream(struct nv_vgpu_device *vgpu, const u8 *buf,
* in the push). This finds the submission carrying a known payload
* even when its method encoding is not (yet) decoded into an op.
*/
- if (gsp_sema_copy_pat && svc.push_pat_log < 32) {
+ if (gsp_sema_dbg && gsp_sema_copy_pat && svc.push_pat_log < 32) {
u32 o;
for (o = 0; o + 8 <= len; o += 4) {
@@ -2745,7 +2805,7 @@ static void svc_decode_stream(struct nv_vgpu_device *vgpu, const u8 *buf,
svc_grce_inline_write(vgpu, st.offset_out,
buf + off + 4, bytes,
ch->h_object);
- } else if (svc.grce_log < 16) {
+ } else if (gsp_sema_dbg && svc.grce_log < 16) {
svc.grce_log++;
pr_info("sema-grce: inline data not run (trusted=%d allow=%d have_out=%d line=%u) h=0x%x\n",
trusted, allow_ops, st.have_out,
@@ -3070,8 +3130,8 @@ static void svc_decode_stream(struct nv_vgpu_device *vgpu, const u8 *buf,
u32 dma = v0;
u32 transfer = DMA_DATA_TRANSFER_TYPE(dma);
- if (ch->h_object && svc.lda_log <
- (gsp_sema_ops_log > 48 ? gsp_sema_ops_log : 48)) {
+ if (gsp_sema_dbg && ch->h_object &&
+ svc.lda_log < (gsp_sema_ops_log > 48 ? gsp_sema_ops_log : 48)) {
svc.lda_log++;
pr_info("sema-lda: h=0x%x eng=%u push=0x%llx inj=%u allow=%u dma=0x%08x xfer=%u remap=%u dpitch=%u dstphys=%u srcphys=%u sem=%u out=0x%llx in=0x%llx line=%u have_out=%u have_in=%u have_remap=%u have_sem=%u ops=%u\n",
ch->h_object, ch->engine_type, push_va,
@@ -3123,7 +3183,7 @@ static void svc_decode_stream(struct nv_vgpu_device *vgpu, const u8 *buf,
m->src_aperture = st.have_src_mode ?
st.src_phys_mode : CE_APERTURE_VID;
n_ops++;
- } else if (svc.dma_skip_log < 32) {
+ } else if (gsp_sema_dbg && svc.dma_skip_log < 32) {
/*
* A launch that looks like a transfer but
* carries no branch we execute: no source
@@ -3133,12 +3193,18 @@ static void svc_decode_stream(struct nv_vgpu_device *vgpu, const u8 *buf,
* missing OFFSET_IN run, or a phys-mode
* value that never arrived).
*/
+ u32 dl = len < 192 ? len : 192;
+
svc.dma_skip_log++;
- pr_info("sema-dma-skip: h=0x%x dma=0x%08x line=%u in=0x%llx out=0x%llx have_in=%u have_out=%u have_remap=%u have_sem=%u\n",
- ch->h_object, dma, st.line_length,
+ pr_info("sema-dma-skip: h=0x%x push=0x%llx off=0x%x dma=0x%08x line=%u in=0x%llx out=0x%llx have_in=%u have_out=%u have_remap=%u have_sem=%u\n",
+ ch->h_object, push_va, off, dma,
+ st.line_length,
st.offset_in, st.offset_out,
st.have_in, st.have_out,
st.have_remap, st.have_sem);
+ if (svc.dma_skip_log <= 8)
+ pr_info("sema-dma-skip: raw len=%u %*phN\n",
+ len, dl, buf);
}
}
@@ -3214,7 +3280,7 @@ static void svc_decode_stream(struct nv_vgpu_device *vgpu, const u8 *buf,
* only the copy itself.
*/
if (allow_ops && n_ops && !gsp_sema_skip_ops) {
- if (ch->engine_type == 0 &&
+ if (gsp_sema_dbg && ch->engine_type == 0 &&
svc.sem256_log < 64) {
svc.sem256_log++;
pr_info("sema-sem0: h=0x%x va=0x%llx allow=%u n_ops=%u skip=%u\n",
@@ -3285,7 +3351,7 @@ static void svc_decode_stream(struct nv_vgpu_device *vgpu, const u8 *buf,
off += 4 + count * 4;
}
- if (ch->h_object && svc.entry_log < 512) {
+ if (gsp_sema_dbg && ch->h_object && svc.entry_log < 512) {
svc.entry_log++;
{
u8 tail[24];
@@ -3371,8 +3437,9 @@ static void svc_apply_pending(struct nv_vgpu_device *vgpu)
p->op ? cur + p->payload : p->payload)) {
svc.releases_applied++;
svc.post_hint_until = jiffies + 10 * HZ;
- pr_info("sema-svc: deferred release va=0x%llx payload=%u (was cur=%u)\n",
- p->va, p->payload, cur);
+ if (gsp_sema_dbg)
+ pr_info("sema-svc: deferred release va=0x%llx payload=%u (was cur=%u)\n",
+ p->va, p->payload, cur);
svc_pending[i] = svc_pending[--svc_pending_n];
continue;
}
@@ -3517,8 +3584,9 @@ static u32 __maybe_unused __svc_apply_page_data_disabled(struct nv_vgpu_device *
svc.releases_jumped++;
pr_info("sema-svc: applied va=0x%llx pa=0x%llx payload=%u (gap: cur=%u)\n",
va, pa, payload, cur32);
- } else if (svc.releases_applied <= 64 ||
- (svc.releases_applied % 100) == 0) {
+ } else if (gsp_sema_dbg &&
+ (svc.releases_applied <= 64 ||
+ (svc.releases_applied % 100) == 0)) {
pr_info("sema-svc: applied va=0x%llx pa=0x%llx payload=%u\n",
va, pa, payload);
}
@@ -3985,7 +4053,8 @@ static void svc_notify_complete(struct nv_vgpu_device *vgpu,
*/
if (!svc_write_ap(vgpu, base, ch->notifier_as, zero, sizeof(zero))) {
ch->notified++;
- if (ch->notified <= 4 || (ch->notified % 10000) == 0)
+ if (gsp_sema_dbg &&
+ (ch->notified <= 4 || (ch->notified % 10000) == 0))
pr_info("sema-chan: notifier cleared h=0x%x info32=0x%x status=0x%x (n=%llu)\n",
ch->h_object, info32, status, ch->notified);
@@ -4078,6 +4147,15 @@ unsigned gsp_sema_gr_grace_ms = 8000;
bool gsp_sema_fake_rel;
/*
+ * Master diagnostic switch for the per-push/per-doorbell/per-op tracing.
+ * Off by default: a healthy boot must leave dmesg quiet (boot stats and
+ * state changes only). Enable per run through the module parameter when
+ * instrumenting; the finer-grained watch knobs (ops_log, copy_watch,
+ * copy_pat, copy_dst) only take effect while this is on.
+ */
+bool gsp_sema_dbg;
+
+/*
* Skip executing a push's collected work (CE memsets/copies into the vidmem
* shadow) while still applying its semaphore release. The client only ever
* observes the release; the shadow writes exist so the emulation can walk
@@ -4108,6 +4186,7 @@ u64 gsp_sema_copy_pat;
* guest writes to vidmem (32-byte PD updates) and learn their encoding.
*/
u64 gsp_sema_copy_dst;
+u64 gsp_sema_copy_dst2;
/*
* Grace window (ms) an untranslatable CE entry stays pending before the
@@ -4559,7 +4638,7 @@ static void svc_init_expected_payload(struct nv_vgpu_device *vgpu,
if (cur < 0x100000) {
ch->expected_sem_payload = cur + 1;
- if (ch->logged_expected != cur) {
+ if (gsp_sema_dbg && ch->logged_expected != cur) {
ch->logged_expected = cur;
pr_info("sema-svc: ch=0x%x rank=%u pool sem @0x%llx cur=%u -> expected=%u\n",
ch->h_object, ch->ce_index, pool_va, cur,
@@ -4607,7 +4686,7 @@ static void svc_counter_publish(struct nv_vgpu_device *vgpu,
&val, sizeof(val)))
return;
ch->counter_last = val;
- if (svc.counter_pub_dbg < 48) {
+ if (gsp_sema_dbg && svc.counter_pub_dbg < 48) {
svc.counter_pub_dbg++;
pr_info("sema-chan: counter publish h=0x%x pa=0x%llx val=%u (was %u)\n",
ch->h_object, ch->counter_pa, val, cur);
@@ -4775,7 +4854,7 @@ static void svc_pump_channels(struct nv_vgpu_device *vgpu)
/* GP_ENTRY1.LENGTH[30:10], in dwords */
len = ((e1 >> 10) & 0x1fffff) << 2;
- if (svc.gpfifo_entry_log < 32) {
+ if (gsp_sema_dbg && svc.gpfifo_entry_log < 32) {
pr_info("sema-chan: entry[%llu] raw=%08x%08x va=0x%llx len=%u\n",
idx, e1, e0, va, len);
svc.gpfifo_entry_log++;
@@ -5445,9 +5524,10 @@ static void svc_handle_map_add(void)
svc_lat_store(req.va + off, req.pa + off, ap);
}
rewound = true;
- pr_info_ratelimited("sema-svc: injected mapping va=0x%llx -> pa=0x%llx len=0x%llx (%s)\n",
- req.va, req.pa, req.len,
- ap == SVC_APERTURE_FB ? "vidmem" : "sysmem");
+ if (gsp_sema_dbg)
+ pr_info_ratelimited("sema-svc: injected mapping va=0x%llx -> pa=0x%llx len=0x%llx (%s)\n",
+ req.va, req.pa, req.len,
+ ap == SVC_APERTURE_FB ? "vidmem" : "sysmem");
}
/*
@@ -5749,8 +5829,9 @@ static int svc_thread(void *arg)
svc.last_hint = jiffies;
rc = gsp_rm_post_all_events(vgpu);
- pr_info_ratelimited("sema-svc: completion hint rc=%d\n",
- rc);
+ if (gsp_sema_dbg)
+ pr_info_ratelimited("sema-svc: completion hint rc=%d\n",
+ rc);
}
/*
@@ -5801,7 +5882,7 @@ void gsp_sema_service_doorbell(u32 token)
if (svc.task)
wake_up_process(svc.task);
- if (svc.doorbell_log < 64) {
+ if (gsp_sema_dbg && svc.doorbell_log < 64) {
pr_info("sema-svc: doorbell token=0x%x runlist=%u vector=%u (count=%llu)\n",
token, (token >> 16) & 0x7f, token & 0xfff,
svc.doorbell_count);
diff --git a/kernel/gsp_sema_service.h b/kernel/gsp_sema_service.h
index 51397b9..baed3cf 100644
--- a/kernel/gsp_sema_service.h
+++ b/kernel/gsp_sema_service.h
@@ -80,6 +80,13 @@ extern bool gsp_sema_gr_rings;
extern bool gsp_sema_fake_rel;
/*
+ * Master diagnostic switch for the per-push/per-doorbell/per-op tracing
+ * (module parameter sema_dbg). Off by default so a healthy boot leaves the
+ * kernel log quiet; the watch knobs below only take effect while it is on.
+ */
+extern bool gsp_sema_dbg;
+
+/*
* Skip executing a push's collected work (CE memsets/copies) while still
* applying its release; see the definition for the trade-off.
*/
@@ -103,6 +110,9 @@ extern u64 gsp_sema_copy_pat;
/* Data-path watch: dump copies landing in this page (source bytes). */
extern u64 gsp_sema_copy_dst;
+/* Second destination window for the same watch (0 = off). */
+extern u64 gsp_sema_copy_dst2;
+
/* CE pending-entry grace window in ms before the release fallback fires. */
extern unsigned gsp_sema_ce_grace_ms;
diff --git a/kernel/main.c b/kernel/main.c
index d6e6c9d..dd38402 100644
--- a/kernel/main.c
+++ b/kernel/main.c
@@ -717,7 +717,9 @@ static ssize_t nv_vgpu_vfio_dev_read(struct vfio_device *vdev, char __user *buf,
struct nv_vgpu_device *vgpu = container_of(vdev, struct nv_vgpu_device, vfio_dev);
loff_t pos = *ppos;
- pr_info("gsp-resman-vfio: VFIO device read count=%zu pos=%lld (0x%llx)\n", count, pos, pos);
+ if (gsp_sema_dbg)
+ pr_info("gsp-resman-vfio: VFIO device read count=%zu pos=%lld (0x%llx)\n",
+ count, pos, pos);
/* Config space region: VFIO_PCI_INDEX_TO_OFFSET(VFIO_PCI_CONFIG_REGION_INDEX) = 0x70000000000 */
if (pos >= 0x70000000000ULL && pos < 0x70000000000ULL + 4096) {
@@ -772,7 +774,9 @@ static ssize_t nv_vgpu_vfio_dev_write(struct vfio_device *vdev, const char __use
struct nv_vgpu_device *vgpu = container_of(vdev, struct nv_vgpu_device, vfio_dev);
loff_t pos = *ppos;
- pr_info_ratelimited("gsp-resman-vfio: VFIO device write count=%zu pos=%lld (0x%llx)\n", count, pos, pos);
+ if (gsp_sema_dbg)
+ pr_info_ratelimited("gsp-resman-vfio: VFIO device write count=%zu pos=%lld (0x%llx)\n",
+ count, pos, pos);
/* Config space region - route through the per-register filter so the
* guest can only modify writable registers (not vendor/device IDs,
@@ -802,14 +806,14 @@ static ssize_t nv_vgpu_vfio_dev_write(struct vfio_device *vdev, const char __use
if (copy_from_user(tmp, buf, count))
return -EFAULT;
- if (bar0_log < 64 || (u64)pos == 0x88704) {
+ if ((u64)pos == 0x88704 || (gsp_sema_dbg && bar0_log < 64)) {
static u32 db_log;
u64 v = 0;
memcpy(&v, tmp, count);
if ((u64)pos == 0x88704) {
- if (db_log < 512) {
+ if (gsp_sema_dbg && db_log < 512) {
pr_info("gsp-resman-vfio: DOORBELL write pos=0x%llx size=%zu val=0x%llx\n",
(u64)pos, count, v);
db_log++;
@@ -837,7 +841,7 @@ static ssize_t nv_vgpu_vfio_dev_write(struct vfio_device *vdev, const char __use
u64 bar1_off = (u64)pos - (1ULL << 40);
static u32 bar1_log;
- if (bar1_log < 64) {
+ if (gsp_sema_dbg && bar1_log < 64) {
u64 v = 0;
memcpy(&v, buf, count);
@@ -2450,6 +2454,17 @@ module_param_named(sema_skip_ops, gsp_sema_skip_ops, bool, 0644);
MODULE_PARM_DESC(sema_skip_ops, "Apply releases without executing pushed memsets (default 0)");
/*
+ * Master diagnostic switch for the per-push/per-doorbell/per-op tracing
+ * (sema-push, sema-lda, sema-chan rel-apply, sema-grce, DOORBELL, the
+ * GSPRM per-RPC lines, ...). Off by default so a healthy boot leaves the
+ * kernel log quiet; turn it on when instrumenting a cycle. The watch knobs
+ * below (ops_log, copy_watch, copy_pat, copy_dst) only take effect while
+ * this is on.
+ */
+module_param_named(sema_dbg, gsp_sema_dbg, bool, 0644);
+MODULE_PARM_DESC(sema_dbg, "Verbose per-push/per-RPC emulation tracing (default 0)");
+
+/*
* Executed-op log cap: how many CE fills/copies are logged with full
* operands. Raise it (e.g. 4096) to audit a data path; the default keeps a
* run quiet.
@@ -2484,6 +2499,14 @@ module_param_named(sema_copy_dst, gsp_sema_copy_dst, ullong, 0644);
MODULE_PARM_DESC(sema_copy_dst, "Dump source bytes of copies landing in this page (default 0)");
/*
+ * Same watch, second 16 KB-aligned window (0 = off). Two windows let one
+ * run cover both the page-directory table and the page-table page it points
+ * into, e.g. 0x208000 and 0x230000.
+ */
+module_param_named(sema_copy_dst2, gsp_sema_copy_dst2, ullong, 0644);
+MODULE_PARM_DESC(sema_copy_dst2, "Second destination window for sema_copy_dst (default 0)");
+
+/*
* Grace window (ms) an untranslatable CE entry stays pending before the
* fallback acknowledges its release and consumes it. Its work must run before
* the release the client synchronizes on; the translation usually lands within