Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 23.128.96.18 as permitted sender) client-ip=23.128.96.18;
From:   Stephen Berman <stephen.berman@gmx.net>
To:     Sebastian Andrzej Siewior <bigeasy@linutronix.de>
Cc:     Thomas Gleixner <tglx@linutronix.de>,
        Peter Zijlstra <peterz@infradead.org>,
        linux-kernel@vger.kernel.org, linux-acpi@vger.kernel.org
Subject: Re: power-off delay/hang due to commit 6d25be57 (mainline)
References: <87imfyh6yx.fsf@gmx.net> <87wo4dligz.fsf@gmx.net>
        <20200612110122.jossn5zrktcvpbpm@linutronix.de>
        <87tuzdrgm5.fsf@gmx.net>
        <20200614171005.3zy673p6bpwoqnmq@linutronix.de>
        <874krcsquv.fsf@gmx.net>
        <20200615145130.bcdidqkp6w23xb6c@linutronix.de>
        <87tuzbh482.fsf@gmx.net>
        <20200616073827.vysntufld3ves666@linutronix.de>
        <87o8pjh1i0.fsf@gmx.net>
        <20200616155501.psduxnisltitodme@linutronix.de>
Date:   Tue, 16 Jun 2020 22:28:43 +0200
In-Reply-To: <20200616155501.psduxnisltitodme@linutronix.de> (Sebastian
        Andrzej Siewior's message of "Tue, 16 Jun 2020 17:55:01 +0200")
Message-ID: <871rmesqkk.fsf@gmx.net>
User-Agent: Gnus/5.13 (Gnus v5.13) Emacs/28.0.50 (gnu/linux)
MIME-Version: 1.0
Content-Type: text/plain; charset=utf-8
Content-Transfer-Encoding: quoted-printable
Sender: linux-kernel-owner@vger.kernel.org
Precedence: bulk

On Tue, 16 Jun 2020 17:55:01 +0200 Sebastian Andrzej Siewior <bigeasy@linut=
ronix.de> wrote:

> On 2020-06-16 10:13:27 [+0200], Stephen Berman wrote:
>> Yes, thanks, that did it.  Trace attached.
>
> So TZ10 is a temperature sensor of some kind on your motherboard. In
> your v5.6 dmesg there is:
> | thermal LNXTHERM:00: registered as thermal_zone0
> | ACPI: Thermal Zone [TZ10] (17 C)
>
> So. In /sys/class/thermal/thermal_zone0/device/path you should also see
> TZ10. And /sys/class/thermal/thermal_zone0/temp should show the actual
> value.
> This comes from the "thermal" module.

Yes, TZ10 was in the thermal_zone0/device/path and the value in
thermal_zone0/temp was 16800.

> Looking at the trace, might query the temperature every second which
> somehow results in "Dispatching Notify on". I don't understand how it
> gets from reading of the temperature to the notify part, maybe it is
> part of the ACPI=E2=80=A6
>
> However. Could you please make sure that the thermal module is not
> loaded at system startup? Adding
>     thermal.off=3D1
>
> to the kernel commandline should do the trick. And you should see
>    thermal control disabled
>
> in dmesg.=20

Confirmed.  And the value in thermal_zone0/temp was now 33000.

>           That means your thermal_zone0 with TZ10 does not show up in
> /sys and nothing should schedule the work-items. This in turn should
> allow you to shutdown your system without the delay.

It did!

> If this works, could you please try to load the module with tzp=3D300?
> If you add this
>  	thermal.tzp=3D300
>=20=20=20
> to the kernel commandline then it should do the trick. You can verify it
> by
>    cat /sys/module/thermal/parameters/tzp=20
>
> This should change the polling interval from what ACPI says to 30secs.
> This should ensure that you don't have so many worker waiting. So you
> should also be able to shutdown the system.

Your assessment and predictions are right on the mark!

I'm fine with the thermal.tzp=3D300 workaround, but it would be good to
find out why this problem started with commit 6d25be57, if my git
bisection was correct, or if it wasn't, then at least somewhere between
5.1.0 and 5.2.0.  Or can you already deduce why?  If not, I'd be more
than happy to continue applying any patches or trying any suggestions
you have, if you want to continue debugging this issue.  In any case,
thanks for pursuing it to this point.

Steve Berman