On Tue, 14 Dec 2021 15:03:00 +0100 Sebastian Andrzej Siewior bigeasy@linutronix.de wrote:
Luca Abeni reported this: | BUG: scheduling while atomic: kworker/u8:2/15203/0x00000003 | CPU: 1 PID: 15203 Comm: kworker/u8:2 Not tainted 4.19.1-rt3 #10 | Call Trace: | rt_spin_lock+0x3f/0x50 | gen6_read32+0x45/0x1d0 [i915] | g4x_get_vblank_counter+0x36/0x40 [i915] | trace_event_raw_event_i915_pipe_update_start+0x7d/0xf0 [i915]
The tracing events use trace_i915_pipe_update_start() among other events use functions acquire spinlock_t locks which are transformed into sleeping locks on PREEMPT_RT. A few trace points use intel_get_crtc_scanline(), others use ->get_vblank_counter() wich also might acquire a sleeping locks on PREEMPT_RT. At the time the arguments are evaluated within trace point, preemption is disabled and so the locks must not be acquired on PREEMPT_RT.
Based on this I don't see any other way than disable trace points on PREMPT_RT.
Another way around this that I can see is if the data for the tracepoints can fit on the stack and add wrappers around the tracepoints. For example, looking at the first tracepoint in i915_trace.h:
TRACE_EVENT(intel_pipe_enable, TP_PROTO(struct intel_crtc *crtc), TP_ARGS(crtc),
TP_STRUCT__entry( __array(u32, frame, 3) __array(u32, scanline, 3) __field(enum pipe, pipe) ), TP_fast_assign( struct drm_i915_private *dev_priv = to_i915(crtc->base.dev); struct intel_crtc *it__; for_each_intel_crtc(&dev_priv->drm, it__) { __entry->frame[it__->pipe] = intel_crtc_get_vblank_counter(it__); __entry->scanline[it__->pipe] = intel_get_crtc_scanline(it__); } __entry->pipe = crtc->pipe; ),
TP_printk("pipe %c enable, pipe A: frame=%u, scanline=%u, pipe B: frame=%u, scanline=%u, pipe C: frame=%u, scanline=%u", pipe_name(__entry->pipe), __entry->frame[PIPE_A], __entry->scanline[PIPE_A], __entry->frame[PIPE_B], __entry->scanline[PIPE_B], __entry->frame[PIPE_C], __entry->scanline[PIPE_C]) );
We could modify this to be:
TRACE_EVENT(intel_pipe_enable, TP_PROTO(u32 *frame, u32 *scanline, enum pipe), TP_ARGS(frame, scanline, pipe),
TP_STRUCT__entry( __array(u32, frame, 3) __array(u32, scanline, 3) __field(enum pipe, pipe) ), TP_fast_assign( int i; for (i = 0; i < 3; i++) { __entry->frame[i] = frame[i]; __entry->scanline[i] = scanline[i]; } __entry->pipe = pipe; ),
TP_printk("pipe %c enable, pipe A: frame=%u, scanline=%u, pipe B: frame=%u, scanline=%u, pipe C: frame=%u, scanline=%u", pipe_name(__entry->pipe), __entry->frame[PIPE_A], __entry->scanline[PIPE_A], __entry->frame[PIPE_B], __entry->scanline[PIPE_B], __entry->frame[PIPE_C], __entry->scanline[PIPE_C]) );
static inline void do_trace_intel_pipe(struct intel_crtc *crtc) { u32 frame[3]; u32 scanline[3]; enum pipe pipe;
if (!trace_intel_pipe_enable_enabled()) return;
struct drm_i915_private *dev_priv = to_i915(crtc->base.dev); struct intel_crtc *it__; for_each_intel_crtc(&dev_priv->drm, it__) { frame[it__->pipe] = intel_crtc_get_vblank_counter(it__); scanline[it__->pipe] = intel_get_crtc_scanline(it__); }
trace_intel_pipe(frame, scanline, crtc->pipe); }
The trace_intel_pipe_enable_enabled() is a static_branch that will act the same as the nop of a trace event, so this will still not add overhead when not enabled.
All the processing will be done outside the trace event allowing it to be preempted, and then when the trace event is executed, it will run quickly without taking any locks.
Then have the code call do_trace_intel_pipe() instead of trace_intel_pipe() and this should fix the issue with preempt rt.
-- Steve