Re: Shutdown -r under -current hangs on RPi3

On Oct 1, 2023, at 19:25, bob prohaska <fbsd@www.zefox.net> wrote:

> On Sun, Oct 01, 2023 at 10:09:59AM -0700, Mark Millard wrote:
>> On Oct 1, 2023, at 09:25, bob prohaska <fbsd@www.zefox.net> wrote:
>> 
>>> On Sun, Sep 24, 2023 at 08:17:54AM -0700, bob prohaska wrote:
>>>> 
>>>> It appears that setting 
>>>> debug.bootverbose=1 
>>>> suppresses the otherwise-persistent
>>>> Khelp module "ertt" can't unload until its refcount drops from 1 to 0.
>>>> message during shutdown. No new output either, apart from the swap
>>>> removal notice.
>>>> 
>>>> So far, the few shutdown -r experiments tried have not gotten stuck,
>>>> even after an OS build/install cycle.
>>> 
>>> Another shutdown hang has been observed with -current on a Pi3.
>>> This time bootverbose was on, as was ucom debug. This machine
>>> has an FTDI usb-serial adaper. 
>>> 
>>> The serial console reported:
>>> 
>>> *** FINAL System shutdown message from bob@pelorus.zefox.org ***             
>>> 
>>> System going down IMMEDIATELY                                                  
>>> 
>>> 
>>> Oct  1 08:21:26 pelorus shutdown[78571]: reboot by bob: 
>>> Stopping sshd.
>>> Waiting for PIDS: 1063.
>>> Stopping cron.
>>> Waiting for PIDS: 1073.
>>> Stopping powerd.
>>> Waiting for PIDS: 1002.
>>> Stopping devd.
>>> Waiting for PIDS: 752.
>>> Writing entropy file: .
>>> Writing early boot entropy file: .
>>> .
>>> Terminated
>>> ucom_inwakeup: tp=0xffffa00021cc1c00
>>> ucom_ioctl: cmd = 0x2000740e
>>> ucom_inwakeup: tp=0xffffa00021cc1c00
>>> ucom_inwakeup: tp=0xffffa00021cc1c00
>>> ucom_close: tp=0xffffa00021cc1c00
>>> ucom_shutdown: 
>>> ucom_dtr: onoff = 0
>>> ucom_line_state: on=0x00, off=0x01
>>> ucom_rts: onoff = 1
>>> ucom_line_state: on=0x02, off=0x00
>>> Oct  1 08:21:32 pelorus ucom_cfg_close: 
>>> syslogd: exiting on signal 15
>>> Waiting (max 60 seconds) for system process `vnlru' to stop... done
>>> Waiting (max 60 seconds) for system process `syncer' to stop... 
>>> Syncing disks, vnodes remaining... 0 0 0 done
>>> All buffers synced.
>>> Swap device da0s2b removed.
>>> Uptime: 3d0h14m47s
>>> Resetting system ... 
>>> 
>>> Both Ethernet LEDs turned off, if that's significant.
>>> After about half an hour, I pulled the plug. The machine
>>> came up hands-off.
>>> 
>> 
>> Was this a debug world/kernel? non-debug? May be
>> output I was expecting only is generated by the
>> debug variants?
>> 
> The kernel was GENERIC, no private modifications
> 
>> Was there any lights sometimes on anywhere during that
>> about half hour?
> 
> Wasn't watching. On a repeat performance all of the on-board
> LEDs remain off, while the disk light seems stuck on.

My understanding is that the RPi3B's SOC can be powered off without
cutting the external power, leaving much of the board also powered
off despite external power. (Simplified wording.) In other words,
"shutdown -p  now" has a chance of being made to largely work, if I
understand right.

If the USB disk is bus powered, that stuck-on may indicate that the
SOC/board is still powered. (Not just in the external supply
sense, but operationally using that external power still.)

> On a
> successful boot the disk light comes on at power on, goes
> off until the disk is probed and then remains on while running.

Is that also descriptive of a successful reboot's disk
light behavior?

> If the probe fails, the disk LED turns off, apparently
> signifying some sort of sleep or power-save state.

Or the SOC(/most-of-board) is no longer using the external
power: internally ignoring the power that is available,
not routing power to the drive.

It might take a power or current monitor to have solid
evidence of how much power is being used, especially in the
"no lights" type of case.

>> Might it have powered off instead of
>> rebooting?
>> 
> 
> No reason to think so. This machine and all its companions are
> on a UPS.

I was thinking of if it was operationally using the external
power still, rather than if the external power had been cut
such that it never reaches the RPi*'s power connector.

>> Is there anything about the above message sequence
>> (before "Resetting system ...") that is different
>> from when the reboot works, also with "bootverbose was
>> on, as was ucom debug"?
>> 
> 
> Not that I can recognize. 
> 
> Setting debug for ucom on Pi3 (current)  generates quite a 
> lot of extra console output, but none of it looks like an 
> error message. I tried to turn on debugging for ucom on the
> Pi2 running stable/14, but the effort failed:
> 
> root@generic:~ # sysctl hw.usb.ucom.debug=1
> sysctl: unknown oid 'hw.usb.ucom.debug'
> Apparently the feature isn't enabled on stable/14.
> Odd, because it's in the man page.
> 
>> It is an example with no "ertt" message.
> 
> Yes, and in retrospect I'm slightly surprised.
> Apparently I set bootverbose interactively.
> Now it's set in /etc/sysctl.conf.

===
Mark Millard
marklmi at yahoo.com