[Intel-gfx] ✗ Fi.CI.BAT: failure for drm/i915: ttm for stolen (rev5)
Hellstrom, Thomas
thomas.hellstrom at intel.com
Thu Jun 30 14:52:16 UTC 2022
Hi!
On Thu, 2022-06-30 at 15:20 +0100, Robert Beckett wrote:
>
>
> On 29/06/2022 13:51, Robert Beckett wrote:
> >
> >
> > On 28/06/2022 17:22, Robert Beckett wrote:
> > >
> > >
> > > On 28/06/2022 09:46, Tvrtko Ursulin wrote:
> > > >
> > > > On 27/06/2022 18:08, Robert Beckett wrote:
> > > > >
> > > > >
> > > > > On 22/06/2022 10:05, Tvrtko Ursulin wrote:
> > > > > >
> > > > > > On 21/06/2022 20:11, Robert Beckett wrote:
> > > > > > >
> > > > > > >
> > > > > > > On 21/06/2022 18:37, Patchwork wrote:
> > > > > > > > *Patch Details*
> > > > > > > > *Series:* drm/i915: ttm for stolen (rev5)
> > > > > > > > *URL:*
> > > > > > > > https://patchwork.freedesktop.org/series/101396/
> > > > > > > > <https://patchwork.freedesktop.org/series/101396/>
> > > > > > > > *State:* failure
> > > > > > > > *Details:*
> > > > > > > > https://intel-gfx-ci.01.org/tree/drm-tip/Patchwork_101396v5/index.html
> > > > > > > >
> > > > > > > > <
> > > > > > > > https://intel-gfx-ci.01.org/tree/drm-tip/Patchwork_101396v5/index.html
> > > > > > > > >
> > > > > > > >
> > > > > > > >
> > > > > > > >
> > > > > > > > CI Bug Log - changes from CI_DRM_11790 ->
> > > > > > > > Patchwork_101396v5
> > > > > > > >
> > > > > > > >
> > > > > > > > Summary
> > > > > > > >
> > > > > > > > *FAILURE*
> > > > > > > >
> > > > > > > > Serious unknown changes coming with Patchwork_101396v5
> > > > > > > > absolutely
> > > > > > > > need to be
> > > > > > > > verified manually.
> > > > > > > >
> > > > > > > > If you think the reported changes have nothing to do
> > > > > > > > with the
> > > > > > > > changes
> > > > > > > > introduced in Patchwork_101396v5, please notify your
> > > > > > > > bug team to
> > > > > > > > allow them
> > > > > > > > to document this new failure mode, which will reduce
> > > > > > > > false
> > > > > > > > positives in CI.
> > > > > > > >
> > > > > > > > External URL:
> > > > > > > > https://intel-gfx-ci.01.org/tree/drm-tip/Patchwork_101396v5/index.html
> > > > > > > >
> > > > > > > >
> > > > > > > >
> > > > > > > >
> > > > > > > > Participating hosts (40 -> 41)
> > > > > > > >
> > > > > > > > Additional (2): fi-icl-u2 bat-dg2-9
> > > > > > > > Missing (1): fi-bdw-samus
> > > > > > > >
> > > > > > > >
> > > > > > > > Possible new issues
> > > > > > > >
> > > > > > > > Here are the unknown changes that may have been
> > > > > > > > introduced in
> > > > > > > > Patchwork_101396v5:
> > > > > > > >
> > > > > > > >
> > > > > > > > IGT changes
> > > > > > > >
> > > > > > > >
> > > > > > > > Possible regressions
> > > > > > > >
> > > > > > > > * igt at i915_selftest@live at reset:
> > > > > > > > o bat-adlp-4: PASS
> > > > > > > > <
> > > > > > > > https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_11790/bat-adlp-4/igt@i915_selftest@live@reset.html
> > > > > > > > >
> > > > > > > >
> > > > > > > > -> DMESG-FAIL
> > > > > > > > <
> > > > > > > > https://intel-gfx-ci.01.org/tree/drm-tip/Patchwork_101396v5/bat-adlp-4/igt@i915_selftest@live@reset.html
> > > > > > > > >
> > > > > > > >
> > > > > > > >
> > > > > > >
> > > > > > > I keep hitting clobbered pages during engine resets on
> > > > > > > bat-adlp-4.
> > > > > > > It seems to happen most of the time on that machine and
> > > > > > > occasionally on bat-adlp-6.
> > > > > > >
> > > > > > > Should bat-adlp-4 be considered an unreliable machine
> > > > > > > like
> > > > > > > bat-adlp-6 is for now?
> > > > > > >
> > > > > > > Alternatively, seeing the history of this in
> > > > > > >
> > > > > > > commit 3da3c5c1c9825c24168f27b021339e90af37e969
> > > > > > > "drm/i915: Exclude
> > > > > > > low pages (128KiB) of stolen from use"
> > > > > > >
> > > > > > > could this be an indication that maybe the original issue
> > > > > > > is worse
> > > > > > > on adlp machines?
> > > > > > > I have only ever seen page page 135 or 136 clobbered
> > > > > > > across many
> > > > > > > runs via trybot, so it looks fairly consistent.
> > > > > > > Though excluding the use of over 540K of stolen might be
> > > > > > > too severe.
> > > > > >
> > > > > > Don't know but I see that on the latest version you even
> > > > > > hit pages
> > > > > > 165/166.
> > > > > >
> > > > > > Any history of hitting this in CI without your series? If
> > > > > > not, are
> > > > > > there some other changes which could explain it? Are you
> > > > > > touching
> > > > > > the selftest itself?
> > > > > >
> > > > > > Hexdump of the clobbered page looks quite complex.
> > > > > > Especially
> > > > > > POISON_FREE. Any idea how that ends up there?
> > > > >
> > > > >
> > > > > (see
> > > > > https://intel-gfx-ci.01.org/tree/drm-tip/Trybot_105517v4/fi-rkl-guc/igt@i915_selftest@live@reset.html#dmesg-warnings702
> > > > > )
> > > > >
> > > > >
> > > > > after lots of slow debug via CI, it looks like the issue is
> > > > > that a
> > > > > ring buffer was allocated and taking up that page during the
> > > > > initial
> > > > > crc capture in the test, but by the time it came to check for
> > > > > corruption, it had been freed from that page.
> > > > >
> > > > > The test has a number of weaknesses:
> > > > >
> > > > > 1. the busy check is done twice, without taking in to account
> > > > > any
> > > > > change in between. I assume previously this could be relied
> > > > > on never
> > > > > to occur, but now it can for some reason (more on that later)
> > > >
> > > > You mean the stolen page used/unused test? Probably the premise
> > > > is
> > > > that the test controls the driver completely ie. is the sole
> > > > user and
> > > > the two checks are run at the time where nothing else could
> > > > have
> > > > changed the state.
> > > >
> > > > With the nerfed request (as with GuC) this actually should
> > > > hold. In
> > > > the generic case I am less sure, my working knowledge faded a
> > > > bit,
> > > > but perhaps there was something guaranteeing the spinner
> > > > couldn't
> > > > have been retired yet at the time of the second check. Would
> > > > need
> > > > clarifying at least in comments.
> > > > >
> > > > > 2. the engine reset returns early with an error for guc
> > > > > submission
> > > > > engines, but it is silently ignored in the test. Perhaps it
> > > > > should
> > > > > ignore guc submission engines as it is a largely useless test
> > > > > for
> > > > > those situations.
> > > >
> > > > Yes looks dodgy indeed. You will need to summon the owners of
> > > > the GuC
> > > > backend to comment on this.
> > > >
> > > > However even if the test should be skipped with GuC it is
> > > > extremely
> > > > interesting that you are hitting this so I suspect there is a
> > > > more
> > > > serious issue at play.
> > >
> > > indeed. That's why I am keen to get to the root cause instead of
> > > just
> > > slapping in a fix.
> > >
> > > >
> > > > > A quick obvious fix is to have a busy bitmask that remembers
> > > > > each
> > > > > page's busy state initially and only check for corruption if
> > > > > it was
> > > > > busy during both checks.
> > > > >
> > > > > However, the main question is why this is occurring now with
> > > > > my
> > > > > changes.
> > > > > I have added more debug to check where the stolen memory is
> > > > > being
> > > > > freed, but the first run last night didn't hit the issue for
> > > > > once.
> > > > > I am running again now, will report back if I figure out
> > > > > where it is
> > > > > being freed.
> > > > >
> > > > > I am pretty sure the "corruption" (which isn't actually
> > > > > corruption)
> > > > > is from a ring buffer.
> > > > > The POISON_FREE is the only difference between the captured
> > > > > before
> > > > > and after dumps:
> > > > >
> > > > > [0040] 00000000 02800000 6b6b6b6b 6b6b6b6b 6b6b6b6b 6b6b6b6b
> > > > > 6b6b6b6b 6b6b6b6b
> > > > >
> > > > > with the 2nd dword being the MI_ARB_CHECK used for the
> > > > > spinner.
> > > > > I think this is the request poisoning from
> > > > > i915_request_retire()
> > > > >
> > > > > The bit I don't know yet is why a ring buffer was freed
> > > > > between the
> > > > > initial crc capture and the corruption check. The spinner
> > > > > should be
> > > > > active across the entire test, maintaining a ref on the
> > > > > context and
> > > > > it's ring.
> > > > >
> > > > > hopefully my latest debug will give more answers.
> > > >
> > > > Yeah if you can figure our whether the a) spinner is still
> > > > active
> > > > during the 2nd check (as I think it should be), and b) is the
> > > > corruption detected in the same pages which were used in the
> > > > 1st pass
> > > > that would be interesting.
> > >
> > > yep. The latest run is still stuck in the CI queue after 27
> > > hours.
> > > I think I have enough debug in there to catch it now.
> > > Hopefully I can get a root cause once it gets chance to run.
> > >
> >
> > https://intel-gfx-ci.01.org/tree/drm-tip/Trybot_105517v7/fi-adl-ddr5/igt@i915_selftest@live@reset.html#dmesg-warnings496
> >
> >
> >
> > well, the run finally happened.
> > And it shows that the freed resource happens from a workqueue. Not
> > helpful.
> >
> > I'll now add a saved stack traces to all objects that saves where
> > it is
> > allocated and freed/queued for free.
> >
>
> https://intel-gfx-ci.01.org/tree/drm-tip/Trybot_105517v8/fi-rkl-guc/igt@i915_selftest@live@reset.html#dmesg-warnings419
>
> I'm pretty sure I know what is going on now.
>
> igt_reset_engines_stolen() loops around each engine and calls
> __igt_reset_stolen() for that engine.
>
>
> __igt_reset_stolen() does
> intel_context_create()
>
> igt_spinner_create_request()->intel_context_create_request()-
> >__i915_request_create()->intel_context_get()
>
> intel_context_put()
>
> leaving the request as the remaining holder of the context.
>
> it then does the reset, which does nothing on GuC setups, does the
> comparisons, then ends the spinner via igt_spinner_fini()-
> >igt_spinner_end()
> which lets the spinner request finish.
>
> once the request is retired, intel_context_put() is eventually
> called,
> which starts the GuC teardown of the context as the request was the
> last
> holder of the context.
>
> This GuC teardown is asynchronous via ct transactions.
> By the time the ct_process_request() sees the
> INTEL_GUC_ACTION_DEREGISTER_CONTEXT_DONE message, the test has
> already
> looped to the next engine and has already checked the original status
> of
> the page that the destroying context used for its ring buffer, so the
> test sees it being freed from the previous loop while testing the
> next
> engine. It considers this a corruption of the stolen memory due to
> the
> previously highlighted double checking of busy state for each page.
>
> I think for now, we should simply not test GuC submission engines in
> line with the reset call returning an error.
> If at some point we want to enable this test for GuC setups, then
> flushing and waiting for context cleanup would need to be added to
> the test.
>
> Anyone know why per engine reset is not allowed for GuC submission
> setup?
> looking at commit "eb5e7da736f3 drm/i915/guc: Reset implementation
> for
> new GuC interface" doesn't really detail why per engine resets are
> not
> allowed.
> Maybe it just never got implemented? or are there reasons to not
> allow
> the host to request specific engine resets?
>
IIRC, the GuC by design decides for itself when it needs to do a per-
engine reset, hence the host can't trigger those.
/Thomas
More information about the Intel-gfx
mailing list