On Mon, Aug 03, 2026 at 11:14:40PM -0300, Tales A. Mendonça wrote:
> When a TLB invalidation fence times out we log the timeout, but if the
> ack for that seqno later shows up there is no record of it, making it
> impossible to tell from logs whether the ack was lost forever or merely
> (very) late.
>
> Track the most recent timed out seqno and log how late its ack arrives,
> relative to both the original request and the moment the fence was
> signaled with -ETIME.
>
> On ARL with GuC 70.53.0 this shows the acks are never lost: they
> consistently arrive ~2.3s after the request, tens of milliseconds after
> the TDR has already signaled the fence:
>
> TLB invalidation fence timeout, seqno=10992 recv=10991
> TLB invalidation late ack: seqno=10992 recv=10992, request-to-ack=2314ms,
> timeout-to-ack=45ms
>
> Link: https://gitlab.freedesktop.org/drm/xe/kernel/-/work_items/8678
> Signed-off-by: Tales A. Mendonça <[email protected]>
> ---
> drivers/gpu/drm/xe/xe_tlb_inval.c | 16 ++++++++++++++++
> drivers/gpu/drm/xe/xe_tlb_inval_types.h | 17 +++++++++++++++++
> 2 files changed, 33 insertions(+)
>
> diff --git a/drivers/gpu/drm/xe/xe_tlb_inval.c
> b/drivers/gpu/drm/xe/xe_tlb_inval.c
> index 833fb92cd3e..9dd04d5bc4c 100644
> --- a/drivers/gpu/drm/xe/xe_tlb_inval.c
> +++ b/drivers/gpu/drm/xe/xe_tlb_inval.c
> @@ -99,6 +99,9 @@ static void xe_tlb_inval_fence_timeout(struct work_struct
> *work)
> fence->seqno, tlb_inval->seqno_recv);
>
> timedout_seqno = fence->seqno;
Should this be:
if (!tlb_inval->timedout_seqno) {
tlb_inval->timedout_seqno = fence->seqno;
tlb_inval->timedout_inval_time = fence->inval_time;
tlb_inval->timedout_time = ktime_get();
}
To record the very first timeout seqno? I think this makes more sense.
> + tlb_inval->timedout_seqno = fence->seqno;
> + tlb_inval->timedout_inval_time = fence->inval_time;
> + tlb_inval->timedout_time = ktime_get();
>
> fence->base.error = -ETIME;
> xe_tlb_inval_fence_signal(fence);
> @@ -227,6 +230,7 @@ void xe_tlb_inval_reset(struct xe_tlb_inval *tlb_inval)
> else
> pending_seqno = tlb_inval->seqno - 1;
> WRITE_ONCE(tlb_inval->seqno_recv, pending_seqno);
> + tlb_inval->timedout_seqno = 0;
>
> list_for_each_entry_safe(fence, next,
> &tlb_inval->pending_fences, link)
> @@ -424,6 +428,18 @@ void xe_tlb_inval_done_handler(struct xe_tlb_inval
> *tlb_inval, int seqno)
>
> WRITE_ONCE(tlb_inval->seqno_recv, seqno);
>
> + if (tlb_inval->timedout_seqno &&
> + xe_tlb_inval_seqno_past(tlb_inval, tlb_inval->timedout_seqno)) {
> + ktime_t now = ktime_get();
> +
> + drm_warn(&xe->drm,
I think xe_warn is the preference here.
Matt
> + "TLB invalidation late ack: seqno=%d recv=%d,
> request-to-ack=%lldms, timeout-to-ack=%lldms",
> + tlb_inval->timedout_seqno, seqno,
> + ktime_ms_delta(now, tlb_inval->timedout_inval_time),
> + ktime_ms_delta(now, tlb_inval->timedout_time));
> + tlb_inval->timedout_seqno = 0;
> + }
> +
> list_for_each_entry_safe(fence, next,
> &tlb_inval->pending_fences, link) {
> trace_xe_tlb_inval_fence_recv(xe, fence);
> diff --git a/drivers/gpu/drm/xe/xe_tlb_inval_types.h
> b/drivers/gpu/drm/xe/xe_tlb_inval_types.h
> index 3d1797d186f..38288966254 100644
> --- a/drivers/gpu/drm/xe/xe_tlb_inval_types.h
> +++ b/drivers/gpu/drm/xe/xe_tlb_inval_types.h
> @@ -102,6 +102,23 @@ struct xe_tlb_inval {
> * @pending_lock: protects @pending_fences and updating @seqno_recv.
> */
> spinlock_t pending_lock;
> + /**
> + * @timedout_seqno: seqno of the most recent timed out TLB
> + * invalidation, 0 if none. Used to measure how late the ack for a
> + * timed out invalidation actually arrives. Protected by
> + * @pending_lock.
> + */
> + int timedout_seqno;
> + /**
> + * @timedout_inval_time: request time of @timedout_seqno. Protected by
> + * @pending_lock.
> + */
> + ktime_t timedout_inval_time;
> + /**
> + * @timedout_time: time @timedout_seqno was signaled with -ETIME.
> + * Protected by @pending_lock.
> + */
> + ktime_t timedout_time;
> /**
> * @fence_tdr: schedules a delayed call to xe_tlb_fence_timeout after
> * the timeout interval is over.
> --
> 2.55.0
>
