Re: [Intel-gfx] [PATCH] drm/i915: Don't wait forever in drop_caches

Tvrtko Ursulin
2022-11-08T09:09:00Z

On 07/11/2022 19:45, John Harrison wrote:
> On 11/7/2022 06:09, Tvrtko Ursulin wrote:
>> On 04/11/2022 17:45, John Harrison wrote:
>>> On 11/4/2022 03:01, Tvrtko Ursulin wrote:
>>>> On 03/11/2022 19:16, John Harrison wrote:
>>>>> On 11/3/2022 02:38, Tvrtko Ursulin wrote:
>>>>>> On 03/11/2022 09:18, Tvrtko Ursulin wrote:
>>>>>>> On 03/11/2022 01:33, John Harrison wrote:
>>>>>>>> On 11/2/2022 07:20, Tvrtko Ursulin wrote:
>>>>>>>>> On 02/11/2022 12:12, Jani Nikula wrote:
>>>>>>>>>> On Tue, 01 Nov 2022, John.C.Harrison@Intel.com wrote:
>>>>>>>>>>> From: John Harrison <John.C.Harrison@Intel.com>
>>>>>>>>>>>
>>>>>>>>>>> At the end of each test, IGT does a drop caches call via
>>>>>>>>>>> sysfs with
>>>>>>>>>>
>>>>>>>>>> sysfs?
>>>>>>>> Sorry, that was meant to say debugfs. I've also been working on
>>>>>>>> some sysfs IGT issues and evidently got my wires crossed!
>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>> special flags set. One of the possible paths waits for idle
>>>>>>>>>>> with an
>>>>>>>>>>> infinite timeout. That causes problems for debugging issues
>>>>>>>>>>> when CI
>>>>>>>>>>> catches a "can't go idle" test failure. Best case, the CI
>>>>>>>>>>> system times
>>>>>>>>>>> out (after 90s), attempts a bunch of state dump actions and then
>>>>>>>>>>> reboots the system to recover it. Worst case, the CI system
>>>>>>>>>>> can't do
>>>>>>>>>>> anything at all and then times out (after 1000s) and simply
>>>>>>>>>>> reboots.
>>>>>>>>>>> Sometimes a serial port log of dmesg might be available,
>>>>>>>>>>> sometimes not.
>>>>>>>>>>>
>>>>>>>>>>> So rather than making life hard for ourselves, change the
>>>>>>>>>>> timeout to
>>>>>>>>>>> be 10s rather than infinite. Also, trigger the standard
>>>>>>>>>>> wedge/reset/recover sequence so that testing can continue with a
>>>>>>>>>>> working system (if possible).
>>>>>>>>>>>
>>>>>>>>>>> Signed-off-by: John Harrison <John.C.Harrison@Intel.com>
>>>>>>>>>>> ---
>>>>>>>>>>>   drivers/gpu/drm/i915/i915_debugfs.c | 7 ++++++-
>>>>>>>>>>>   1 file changed, 6 insertions(+), 1 deletion(-)
>>>>>>>>>>>
>>>>>>>>>>> diff --git a/drivers/gpu/drm/i915/i915_debugfs.c
>>>>>>>>>>> b/drivers/gpu/drm/i915/i915_debugfs.c
>>>>>>>>>>> index ae987e92251dd..9d916fbbfc27c 100644
>>>>>>>>>>> --- a/drivers/gpu/drm/i915/i915_debugfs.c
>>>>>>>>>>> +++ b/drivers/gpu/drm/i915/i915_debugfs.c
>>>>>>>>>>> @@ -641,6 +641,9 @@
>>>>>>>>>>> DEFINE_SIMPLE_ATTRIBUTE(i915_perf_noa_delay_fops,
>>>>>>>>>>>             DROP_RESET_ACTIVE | \
>>>>>>>>>>>             DROP_RESET_SEQNO | \
>>>>>>>>>>>             DROP_RCU)
>>>>>>>>>>> +
>>>>>>>>>>> +#define DROP_IDLE_TIMEOUT    (HZ * 10)
>>>>>>>>>>
>>>>>>>>>> I915_IDLE_ENGINES_TIMEOUT is defined in i915_drv.h. It's also
>>>>>>>>>> only used
>>>>>>>>>> here.
>>>>>>>>>
>>>>>>>>> So move here, dropping i915 prefix, next to the newly proposed
>>>>>>>>> one?
>>>>>>>> Sure, can do that.
>>>>>>>>
>>>>>>>>>
>>>>>>>>>> I915_GEM_IDLE_TIMEOUT is defined in i915_gem.h. It's only used in
>>>>>>>>>> gt/intel_gt.c.
>>>>>>>>>
>>>>>>>>> Move there and rename to GT_IDLE_TIMEOUT?
>>>>>>>>>
>>>>>>>>>> I915_GT_SUSPEND_IDLE_TIMEOUT is defined and used only in
>>>>>>>>>> intel_gt_pm.c.
>>>>>>>>>
>>>>>>>>> No action needed, maybe drop i915 prefix if wanted.
>>>>>>>>>
>>>>>>>> These two are totally unrelated and in code not being touched by
>>>>>>>> this change. I would rather not conflate changing random other
>>>>>>>> things with fixing this specific issue.
>>>>>>>>
>>>>>>>>>> I915_IDLE_ENGINES_TIMEOUT is in ms, the rest are in jiffies.
>>>>>>>>>
>>>>>>>>> Add _MS suffix if wanted.
>>>>>>>>>
>>>>>>>>>> My head spins.
>>>>>>>>>
>>>>>>>>> I follow and raise that the newly proposed DROP_IDLE_TIMEOUT
>>>>>>>>> applies to DROP_ACTIVE and not only DROP_IDLE.
>>>>>>>> My original intention for the name was that is the 'drop caches
>>>>>>>> timeout for intel_gt_wait_for_idle'. Which is quite the mouthful
>>>>>>>> and hence abbreviated to DROP_IDLE_TIMEOUT. But yes, I realised
>>>>>>>> later that name can be conflated with the DROP_IDLE flag. Will
>>>>>>>> rename.
>>>>>>>>
>>>>>>>>
>>>>>>>>>
>>>>>>>>> Things get refactored, code moves around, bits get left behind,
>>>>>>>>> who knows. No reason to get too worked up. :) As long as people
>>>>>>>>> are taking a wider view when touching the code base, and are
>>>>>>>>> not afraid to send cleanups, things should be good.
>>>>>>>> On the other hand, if every patch gets blocked in code review
>>>>>>>> because someone points out some completely unrelated piece of
>>>>>>>> code could be a bit better then nothing ever gets fixed. If you
>>>>>>>> spot something that you think should be improved, isn't the
>>>>>>>> general idea that you should post a patch yourself to improve it?
>>>>>>>
>>>>>>> There's two maintainers per branch and an order of magnitude or
>>>>>>> two more developers so it'd be nice if cleanups would just be
>>>>>>> incoming on self-initiative basis. ;)
>>>>>>>
>>>>>>>>> For the actual functional change at hand - it would be nice if
>>>>>>>>> code paths in question could handle SIGINT and then we could
>>>>>>>>> punt the decision on how long someone wants to wait purely to
>>>>>>>>> userspace. But it's probably hard and it's only debugfs so
>>>>>>>>> whatever.
>>>>>>>>>
>>>>>>>> The code paths in question will already abort on a signal won't
>>>>>>>> they? Both intel_gt_wait_for_idle() and
>>>>>>>> intel_guc_wait_for_pending_msg(), which is where the
>>>>>>>> uc_wait_for_idle eventually ends up, have an 'if(signal_pending)
>>>>>>>> return -EINTR;' check. Beyond that, it sounds like what you are
>>>>>>>> asking for is a change in the IGT libraries and/or CI framework
>>>>>>>> to start sending signals after some specific timeout. That seems
>>>>>>>> like a significantly more complex change (in terms of the number
>>>>>>>> of entities affected and number of groups involved) and
>>>>>>>> unnecessary.
>>>>>>>
>>>>>>> If you say so, I haven't looked at them all. But if the code path
>>>>>>> in question already aborts on signals then I am not sure what is
>>>>>>> the patch fixing? I assumed you are trying to avoid the write
>>>>>>> stuck in D forever, which then prevents driver unload and
>>>>>>> everything, requiring the test runner to eventually reboot. If
>>>>>>> you say SIGINT works then you can already recover from userspace,
>>>>>>> no?
>>>>>>>
>>>>>>>>> Whether or not 10s is enough CI will hopefully tell us. I'd
>>>>>>>>> probably err on the side of safety and make it longer, but at
>>>>>>>>> most half from the test runner timeout.
>>>>>>>> This is supposed to be test clean up. This is not about how long
>>>>>>>> a particular test takes to complete but about how long it takes
>>>>>>>> to declare the system broken after the test has already
>>>>>>>> finished. I would argue that even 10s is massively longer than
>>>>>>>> required.
>>>>>>>>
>>>>>>>>>
>>>>>>>>> I am not convinced that wedging is correct though. Conceptually
>>>>>>>>> could be just that the timeout is too short. What does wedging
>>>>>>>>> really give us, on top of limiting the wait, when latter AFAIU
>>>>>>>>> is the key factor which would prevent the need to reboot the
>>>>>>>>> machine?
>>>>>>>>>
>>>>>>>> It gives us a system that knows what state it is in. If we can't
>>>>>>>> idle the GT then something is very badly wrong. Wedging
>>>>>>>> indicates that. It also ensure that a full GT reset will be
>>>>>>>> attempted before the next test is run. Helping to prevent a
>>>>>>>> failure on test X from propagating into failures of unrelated
>>>>>>>> tests X+1, X+2, ... And if the GT reset does not work because
>>>>>>>> the system is really that badly broken then future tests will
>>>>>>>> not run rather than report erroneous failures.
>>>>>>>>
>>>>>>>> This is not about getting a more stable system for end users by
>>>>>>>> sweeping issues under the carpet and pretending all is well. End
>>>>>>>> users don't run IGTs or explicitly call dodgy debugfs entry
>>>>>>>> points. The sole motivation here is to get more accurate results
>>>>>>>> from CI. That is, correctly identifying which test has hit a
>>>>>>>> problem, getting valid debug analysis for that test (logs and
>>>>>>>> such) and allowing further testing to complete correctly in the
>>>>>>>> case where the system can be recovered.
>>>>>>>
>>>>>>> I don't really oppose shortening of the timeout in principle,
>>>>>>> just want a clear statement if this is something IGT / test
>>>>>>> runner could already do or not. It can apply a timeout, it can
>>>>>>> also send SIGINT, and it could even trigger a reset from outside.
>>>>>>> Sure it is debugfs hacks so general "kernel should not implement
>>>>>>> policy" need not be strictly followed, but lets have it clear
>>>>>>> what are the options.
>>>>>>
>>>>>> One conceptual problem with applying this policy is that the code is:
>>>>>>
>>>>>>     if (val & (DROP_IDLE | DROP_ACTIVE)) {
>>>>>>         ret = intel_gt_wait_for_idle(gt, MAX_SCHEDULE_TIMEOUT);
>>>>>>         if (ret)
>>>>>>             return ret;
>>>>>>     }
>>>>>>
>>>>>>     if (val & DROP_IDLE) {
>>>>>>         ret = intel_gt_pm_wait_for_idle(gt);
>>>>>>         if (ret)
>>>>>>             return ret;
>>>>>>     }
>>>>>>
>>>>>> So if someone passes in DROP_IDLE and then why would only the
>>>>>> first branch have a short timeout and wedge. Yeah some bug happens
>>>>>> to be there at the moment, but put a bug in a different place and
>>>>>> you hang on the second branch and then need another patch. Versus
>>>>>> perhaps making it all respect SIGINT and handle from outside.
>>>>>>
>>>>> The pm_wait_for_idle is can only called after gt_wait_for_idle has
>>>>> completed successfully. There is no route to skip the GT idle or to
>>>>> do the PM idle even if the GT idle fails. So the chances of the PM
>>>>> idle failing are greatly reduced. There would have to be something
>>>>> outside of a GT keeping the GPU awake and there isn't a whole lot
>>>>> of hardware left at that point!
>>>>
>>>> Well "greatly reduced" is beside my point. Point is today bug is
>>>> here and we add a timeout, tomorrow bug is there and then the same
>>>> dance. It can be just a sw bug which forgets to release the pm ref
>>>> in some circumstances, doesn't really matter.
>>>>
>>> Huh?
>>>
>>> Greatly reduced is the whole point. Today there is a bug and it
>>> causes a kernel hang which requires the CI framework to reboot the
>>> system in an extremely unfriendly way which makes it very hard to
>>> work out what happened. Logs are likely not available. We don't even
>>> necessarily know which test was being run at the time. Etc. So we
>>> replace the infinite timeout with a meaningful timeout. CI now
>>> correctly marks the single test as failing, captures all the correct
>>> logs, creates a useful bug report and continues on testing more stuff.
>>
>> So what is preventing CI to collect logs if IGT is forever stuck in
>> interruptible wait? Surely it can collect the logs at that point if
>> the kernel is healthy enough. If it isn't then I don't see how wedging
>> the GPU will make the kernel any healthier.
>>
>> Is i915 preventing better log collection or could test runner be
>> improved?
>>
>>> Sure, there is still the chance of hitting an infinite timeout. But
>>> that one is significantly more complicated to remove. And the chances
>>> of hitting that one are significantly smaller than the chances of
>>> hitting the first one.
>>
>> This statement relies on intimate knowledge implementation details and
>> a bit too much white box testing approach but that's okay, lets move
>> past this one.
>>
>>> So you are arguing that because I can't fix the last 0.1% of possible
>>> failures, I am not allowed to fix the first 99.9% of the failures?
>>
>> I am clearly not arguing for that. But we are also not talking about
>> "fixing failures" here. Just how to make CI cope better with a class
>> of i915 bugs.
>>
>>>>> Regarding signals, the PM idle code ends up at
>>>>> wait_var_event_killable(). I assume that is interruptible via at
>>>>> least a KILL signal if not any signal. Although it's not entirely
>>>>> clear trying to follow through the implementation of this code.
>>>>> Also, I have no idea if there is a safe way to add a timeout to
>>>>> that code (or why it wasn't already written with a timeout
>>>>> included). Someone more familiar with the wakeref internals would
>>>>> need to comment.
>>>>>
>>>>> However, I strongly disagree that we should not fix the driver just
>>>>> because it is possible to workaround the issue by re-writing the CI
>>>>> framework. Feel free to bring a redesign plan to the IGT WG and
>>>>> whatever equivalent CI meetings in parallel. But we absolutely
>>>>> should not have infinite waits in the kernel if there is a trivial
>>>>> way to not have infinite waits.
>>>>
>>>> I thought I was clear that I am not really opposed to the timeout.
>>>>
>>>> The rest of the paragraph I don't really care - point is moot
>>>> because it's debugfs so we can do whatever, as long as it is not
>>>> burdensome to i915, which this isn't. If either wasn't the case then
>>>> we certainly wouldn't be adding any workarounds in the kernel if it
>>>> can be achieved in IGT.
>>>>
>>>>> Also, sending a signal does not result in the wedge happening. I
>>>>> specifically did not want to change that code path because I was
>>>>> assuming there was a valid reason for it. If you have been
>>>>> interrupted then you are in the territory of maybe it would have
>>>>> succeeded if you just left it for a moment longer. Whereas, hitting
>>>>> the timeout says that someone very deliberately said this is too
>>>>> long to wait and therefore the system must be broken.
>>>>
>>>> I wanted to know specifically about wedging - why can't you
>>>> wedge/reset from IGT if DROP_IDLE times out in quiescent or
>>>> wherever, if that's what you say is the right thing?
>>> Huh?
>>>
>>> DROP_IDLE has two waits. One that I am trying to change from infinite
>>> to finite + wedge. One that would take considerable effort to change
>>> and would be quite invasive to a lot more of the driver and which can
>>> only be hit if the first timeout actually completed successfully and
>>> is therefore of less importance anyway. Both of those time outs
>>> appear to respect signal interrupts.
>>>
>>>> That's a policy decision so why would i915 wedge if an arbitrary
>>>> timeout expired? I915 is not controlling how much work there is
>>>> outstanding at the point the IGT decides to call DROP_IDLE.
>>>
>>> Because this is a debug test interface that is used solely by IGT
>>> after it has finished its testing. This is not about wedging the
>>> device at some random arbitrary point because an AI compute workload
>>> takes three hours to complete. This is about a very specific test
>>> framework cleaning up after testing is completed and making sure the
>>> test did not fry the system.
>>>
>>> And even if an IGT test was calling DROP_IDLE in the middle of a test
>>> for some reason, it should not be deliberately pushing 10+ seconds of
>>> work through and then calling a debug only interface to flush it out.
>>> If a test wants to verify that the system can cope with submitting a
>>> minutes worth of rendering and then waiting for it to complete then
>>> the test should be using official channels for that wait.
>>>
>>>>
>>>>> Plus, infinite wait is not a valid code path in the first place so
>>>>> any change in behaviour is not really a change in behaviour. Code
>>>>> can't be relying on a kernel call to never return for its correct
>>>>> operation!
>>>>
>>>> Why infinite wait wouldn't be valid? Then you better change the
>>>> other one as well. ;P
>>> In what universe is it ever valid to wait forever for a test to
>>> complete?
>>
>> Well above you claimed both paths respect SIGINT. If that is so then
>> the wait is as infinite as the IGT wanted it to be.
>>
>>> See above, the PM code would require much more invasive changes. This
>>> was low hanging fruit. It was supposed to be a two minute change to a
>>> very self contained section of code that would provide significant
>>> benefit to debugging a small class of very hard to debug problems.
>>
>> Sure, but I'd still like to know why can't you do what you want from
>> the IGT framework.
>>
>> Have the timeout reduction in i915, again that's fine assuming 10
>> seconds it enough to not break something by accident.
> CI showed no regressions. And if someone does find a valid reason why a
> post test drop caches call should legitimately take a stupidly long time
> then it is easy to track back where the ETIME error came from and bump
> the timeout.
>
>>
>> With that change you already have broken the "infinite wait". It makes
>> the debugfs write return -ETIME in time much shorter than the test
>> runner timeout(s). What is the thing that you cannot do from IGT at
>> that point is my question? You want to wedge then? Send
>> DROP_RESET_ACTIVE to do it for you? If that doesn't work add a new
>> flag which will wedge explicitly.
>>
>> We are again degrading into a huge philosophical discussion and all I
>> wanted to start with is to hear how exactly things go bad.
>>
> I have no idea what you are wanting. I am trying to have a technical
> discussion about improving the stability of the driver during CI
> testing. I have no idea if you are arguing that this change is good,
> bad, broken, wrong direction or what.
>
> Things go bad as explained in the commit message. The CI framework does
> not use signals. The IGT framework does not use signals. There is no
> watchdog that sends a TERM or KILL signal after a specified timeout. All
> that happens is the IGT sits there forever waiting for the drop caches
> IOCTL to return. The CI framework eventually gives up waiting for the
> test to complete and tries to recover. There are many different CI
> frameworks in use across Intel. Some timeout quickly, some timeout
> slowly. But basically, they all eventually give up and don't bother
> trying any kind of remedial action but just hit the reset button
> (sometimes by literally power cycling the DUT). As result, background
> processes that are saving dmesg, stdout, etc do not necessarily
> terminate cleanly. That results in logs that are at best truncated, at
> worst missing entirely. It also results in some frameworks aborting
> testing at that point. So no results are generated for all the other
> tests that have yet to be run. Some frameworks also run tests in
> batches. All they log is that something, somewhere in the batch died. So
> you don't even know which specific test actually hit the problem.
>
> Can the CI frameworks be improved? Undoubtedly. In very many ways. Is
> that something we have the ability to do with a simple patch? No. Would
> re-writing the IGT framework to add watchdog mechanisms improve things?
> Yes. Can it be done with a simple patch? No. Would a simple patch to
> i915 significantly improve the situation? Yes. Will it solve every
> possible CI hang? No. Will it fix any actual end user visible bugs? No.
> Will it introduce any new bugs? No. Will it help us to debug at least
> some CI failures? Yes.

To unblock, I suggest you go with the patch which caps the wait only,
and propose a wedging as an IGT patch to gem_quiescent_gpu(). That
should involve the CI/IGT folks into discussion on what logs will be, or
will not be collected once gem_quiescent_gpu() fails due -ETIME. In fact
probably you should copy CI/IGT folks on the v2 of the i915 patch as
well since I now think their acks would be good to have - from the point
of view of the current test runner behaviour with hanging tests.

Regards,

Tvrtko