problem in F25 shutdown process

[Joerg Lechner]

Hi
is use external disks (USB) to collect TV films and TV shows. Yesterday I forgot to eject
the external disk before shutting down F25. Result ratarata...... of the external disk
during the shut down process. Currently I have no access to this disk (sata, 1TB) via F25,
F24 and Windows I did not try so far. 
The shut down process of F25 takes a lot more time, then the shut down process of F24/F23.
Shutting down F25 a lot of code is displayed. I didn't make any modification, the
system is as originally installed, with the last updates. This very long lasting shut down
process seems to have been the same since Alpha. With F24/F23 I could shutting down the PC
without destroying an external disk. My system Acer Laptop E5-571G-50K9, F25 Desktop
Version 64bit, the external disk is connected with an USB adapter, it's a used
internal disk. I don't know whether the disk has had an error previously or not, but I
could save on it about 100GB films before shutting down without of the "ticking"
of a moribund disk.
Kind regards

[stan]

On Thu, 19 Jan 2017 01:04:39 -0500
Joerg Lechner <julechner(a)aol.com&gt; wrote:

>  Hi
>  is use external disks (USB) to collect TV films and TV shows.
>  Yesterday I forgot to eject the external disk before shutting down
>  F25. Result ratarata...... of the external disk during the shut down
>  process. Currently I have no access to this disk (sata, 1TB) via F25,
>  F24 and Windows I did not try so far. The shut down process of F25
>  takes a lot more time, then the shut down process of F24/F23.
>  Shutting down F25 a lot of code is displayed. I didn't make any
>  modification, the system is as originally installed, with the last
>  updates. This very long lasting shut down process seems to have been
>  the same since Alpha. With F24/F23 I could shutting down the PC
>  without destroying an external disk. My system Acer Laptop
>  E5-571G-50K9, F25 Desktop Version 64bit, the external disk is
>  connected with an USB adapter, it's a used internal disk. I don't
>  know whether the disk has had an error previously or not, but I could
>  save on it about 100GB films before shutting down without of the
>  "ticking" of a moribund disk. Kind regards 
I don't have a usb disk, so I'm not familiar with this.  But, are you
saying that shutting down F25 with a usb disk attached destroyed the
usb disk?  I think that at shutdown, all buffers are flushed to disk,
so that the disk is left in the correct state.  I can't see how that
would trash a disk.  If it did, that's a major bug, and you should open
a bugzilla documenting your experience as above.  I'm not sure which
component does that, unfortunately.  Probably the kernel, but systemd
is in charge of shutdown, so you could choose either kernel or systemd.

https://bugzilla.redhat.com/

[Joerg Lechner]

Hi Stan,
I have already filed Bug 1414809 -       problem in F25 shutdown process to Kernel. In my
eyes its a major bug. I have just done the same on F24 with another disk - no problem.
Also if You don't have a USB-disk, if You compare shutting down in F24 and F25, You
should see the -only viewing shut down in F25 desktop version, no logging -  lines of code
displayed and the the time needed for shutting down, and You can compare this this with
the shut down procedure in F24.
Kind regards

 

 

 

-----Ursprüngliche Mitteilung----- 
Von: stan <stanl-fedorauser(a)vfemail.net&gt;
An: test <test(a)lists.fedoraproject.org&gt;
Verschickt: Do, 19 Jan 2017 5:52 pm
Betreff: Re: problem in F25 shutdown process

On Thu, 19 Jan 2017 01:04:39 -0500Joerg Lechner <julechner(a)aol.com&gt; wrote:>
Hi> is use external disks (USB) to collect TV films and TV shows.> Yesterday I
forgot to eject the external disk before shutting down> F25. Result ratarata...... of
the external disk during the shut down> process. Currently I have no access to this
disk (sata, 1TB) via F25,> F24 and Windows I did not try so far. The shut down process
of F25> takes a lot more time, then the shut down process of F24/F23.> Shutting down
F25 a lot of code is displayed. I didn't make any> modification, the system is as
originally installed, with the last> updates. This very long lasting shut down process
seems to have been> the same since Alpha. With F24/F23 I could shutting down the PC>
without destroying an external disk. My system Acer Laptop> E5-571G-50K9, F25 Desktop
Version 64bit, the external disk is> connected with an USB adapter, it's a used
internal disk. I don't> know whether the disk has had an error previously or not,
but I could> save on it about 100GB films before shutting down without of the>
"ticking" of a moribund disk. Kind regardsI don't have a usb disk, so
I'm not familiar with this.  But, are yousaying that shutting down F25 with a usb disk
attached destroyed theusb disk?  I think that at shutdown, all buffers are flushed to
disk,so that the disk is left in the correct state.  I can't see how thatwould trash a
disk.  If it did, that's a major bug, and you should opena bugzilla documenting your
experience as above.  I'm not sure whichcomponent does that, unfortunately.  Probably
the kernel, but systemdis in charge of shutdown, so you could choose either kernel or
systemd.https://bugzilla.redhat.com/_____________________________________...
mailing list -- test(a)lists.fedoraproject.orgTo unsubscribe send an email to
test-leave(a)lists.fedoraproject.org

[Joerg Lechner]

 Hi,
i would like to compare the shutdown logs F24 and F25. Assume I can find it in /var/logs.
Which log is to view, to see the possible error in the F25 shutdown in comparison to F24?
Kind regards

 

 

-----Ursprüngliche Mitteilung----- 
Von: Joerg Lechner <julechner(a)aol.com&gt;
An: test <test(a)lists.fedoraproject.org&gt;
Verschickt: Do, 19. Jan 2017 19:00
Betreff: Re: problem in F25 shutdown process


Hi Stan,
I have already filed Bug 1414809 -       problem in F25 shutdown process to Kernel. In my
eyes its a major bug. I have just done the same on F24 with another disk - no problem.
Also if You don't have a USB-disk, if You compare shutting down in F24 and F25, You
should see the -only viewing shut down in F25 desktop version, no logging -  lines of code
displayed and the the time needed for shutting down, and You can compare this this with
the shut down procedure in F24.
Kind regards

 

 

 

-----Ursprüngliche Mitteilung----- 
Von: stan <stanl-fedorauser(a)vfemail.net&gt;
An: test <test(a)lists.fedoraproject.org&gt;
Verschickt: Do, 19 Jan 2017 5:52 pm
Betreff: Re: problem in F25 shutdown process

On Thu, 19 Jan 2017 01:04:39 -0500Joerg Lechner <julechner(a)aol.com&gt; wrote:>
Hi> is use external disks (USB) to collect TV films and TV shows.> Yesterday I
forgot to eject the external disk before shutting down> F25. Result ratarata...... of
the external disk during the shut down> process. Currently I have no access to this
disk (sata, 1TB) via F25,> F24 and Windows I did not try so far. The shut down process
of F25> takes a lot more time, then the shut down process of F24/F23.> Shutting down
F25 a lot of code is displayed. I didn't make any> modification, the system is as
originally installed, with the last> updates. This very long lasting shut down process
seems to have been> the same since Alpha. With F24/F23 I could shutting down the PC>
without destroying an external disk. My system Acer Laptop> E5-571G-50K9, F25 Desktop
Version 64bit, the external disk is> connected with an USB adapter, it's a used
internal disk. I don't> know whether the disk has had an error previously or not,
but I could> save on it about 100GB films before shutting down without of the>
"ticking" of a moribund disk. Kind regardsI don't have a usb disk, so
I'm not familiar with this.  But, are yousaying that shutting down F25 with a usb disk
attached destroyed theusb disk?  I think that at shutdown, all buffers are flushed to
disk,so that the disk is left in the correct state.  I can't see how thatwould trash a
disk.  If it did, that's a major bug, and you should opena bugzilla documenting your
experience as above.  I'm not sure whichcomponent does that, unfortunately.  Probably
the kernel, but systemdis in charge of shutdown, so you could choose either kernel or
systemd.https://bugzilla.redhat.com/_____________________________________...
mailing list -- test(a)lists.fedoraproject.orgTo unsubscribe send an email to
test-leave(a)lists.fedoraproject.org

[stan]

On Sun, 22 Jan 2017 04:00:50 -0500
Joerg Lechner <julechner(a)aol.com&gt; wrote:

>   Hi,
>  i would like to compare the shutdown logs F24 and F25. Assume I can
>  find it in /var/logs. Which log is to view, to see the possible error
>  in the F25 shutdown in comparison to F24? Kind regards 
If your shutdown delay is similar to mine, I don't think this will
work because journald, which is the main log process is stopped
(SIGTERM) at shutdown, and obeys.  Then systemd waits for the reluctant
processes to time out, and the shutdown happens.  But those reluctant
shutdown events are never logged because the logging has been stopped
before they happen.

I think maybe systemd needs to be modified so that logging is always
the very last thing to be terminated during shutdown.  Then, when the
problem occurs, it is just a simple matter of looking in journalctl to
see what the problem is.

I think the above applies even if you have rsyslog enabled as your
logging solution.  It is also sent a SIGTERM, and obeys, before these
problem processes are terminated.

You can try comparing /var/log/messages or var/log/syslog (if it
exists).

For journalctl, just run it and find the last shutdown you did to see
the messages it logs.

[Chris Murphy]

It is possible to get a log of events following journald shutdown. See
the section under Shutdown Completes Eventually


https://freedesktop.org/wiki/Software/systemd/Debugging/#index2h1

[stan]

On Sun, 22 Jan 2017 20:59:04 -0700
Chris Murphy <lists(a)colorremedies.com&gt; wrote:

>  It is possible to get a log of events following journald shutdown.
> See
>  the section under Shutdown Completes Eventually
>  
>  
>  https://freedesktop.org/wiki/Software/systemd/Debugging/#index2h1 
Thank you very much for this.  It took a few reboots, but I think I now
know what the problem is.  

[  134.831290] systemd-shutdown[1]: Sending SIGKILL to remaining
processes... [  
134.839939] systemd-shutdown[1]: Process 1708
(plymouthd) has been marked to be excluded from killing. It is running
from the root file system, and thus likely to block re-mounting of the
root file system to read-only. Please consider moving it into an initrd
file system instead.

I'm not sure this is the problem, because the system didn't stall at
shutdown once I modified the kernel line with the added options,
systemd.log_level=debug systemd.log_target=kmsg log_buf_len=1M
enforcing=0
I might just leave them, since systemd is more chatty with
them enabled, mentioning every problem it encounters.  The only thing
is I'll have to remember to setenforce 1 at start, and setenforce 0
before shutdown. Or just remove the enforcing=0, and remember
setenforce 0 before shutdown.

Is there anything I can do as a user to remedy this issue with
plymouthd?

[stan]

On Mon, 23 Jan 2017 11:15:15 -0700
stan <stanl-fedorauser(a)vfemail.net&gt; wrote:

>  Is there anything I can do as a user to remedy this issue with
>  plymouthd? 
A little investigation showed that I don't use plymouth, so I purged it
root and branch.  A subsequent reboot without the systemd debug options
showed no delay.  I'm taking this as confirmation that the problem was
the plymouthd daemon.

[stan]

On Mon, 23 Jan 2017 14:29:02 -0700
stan <stanl-fedorauser(a)vfemail.net&gt; wrote:

>  A little investigation showed that I don't use plymouth, so I
> purged
>  it root and branch.  A subsequent reboot without the systemd debug
>  options showed no delay.  I'm taking this as confirmation that the
>  problem was the plymouthd daemon. 
Subsequent experience (it's still happening) indicates that this was
not the problem.  The only fix that seems to work is to use the kernel
debug line for systemd.  I removed the enforcing=0, and type
setenforce 0 just before I shutdown.  Then, the shutdown occurs
quickly, so the actual errors causing the delayed shutdown aren't in
the log.

Quick glimpses as the actual messages of what is causing the delay
flash by on the screen shows most of the messages are from systemd and
I think I saw an auditk message, but it is so fast it is hard to read.
There are only about a dozen lines in the delayed messages, but with
the delay, the screen is blank by the time I could react, even to take
a photo.

[Chris Murphy]

On Wed, Jan 25, 2017 at 10:45 AM, stan <stanl-fedorauser(a)vfemail.net&gt; wrote:
>  On Mon, 23 Jan 2017 14:29:02 -0700
>  stan <stanl-fedorauser(a)vfemail.net&gt; wrote:
>
> > A little investigation showed that I don't use plymouth, so I purged
> > it root and branch.  A subsequent reboot without the systemd debug
> > options showed no delay.  I'm taking this as confirmation that the
> > problem was the plymouthd daemon.
>
>  Subsequent experience (it's still happening) indicates that this was
>  not the problem.  The only fix that seems to work is to use the kernel
>  debug line for systemd.  I removed the enforcing=0, and type
>  setenforce 0 just before I shutdown.  Then, the shutdown occurs
>  quickly, so the actual errors causing the delayed shutdown aren't in
>  the log.
>
>  Quick glimpses as the actual messages of what is causing the delay
>  flash by on the screen shows most of the messages are from systemd and
>  I think I saw an auditk message, but it is so fast it is hard to read.
>  There are only about a dozen lines in the delayed messages, but with
>  the delay, the screen is blank by the time I could react, even to take
>  a photo. 
Could be a labeling problem. Might be worth 'sudo restorecon -rv /'
and then a sync and then reboot -f and see if it works with
enforcing=0 (or even without, let it enforce).

Stock Fedora 25 I have had a stop job for user 1000, that takes 90
seconds to time out. Your problem seems different. But to isolate if
this is a user environment problem, or a system problem, you could try
modifying /etc/systemd/logind.conf such that KillUserProcesses=yes
(and remove the # so it's uncommented). The gotcha with this is that
user processes are unceremoniously killed at logout time (including
restart and shutown). So if you use screen or tmux, and logout, the
tmux/screen processes get killed by virtue of tmux/screen getting
killed. There's a work around for that also which I can't articulate -
something to do with linger or gettting it to run in a separate logind
session? Anyway... just change this option temporarily for
troubleshooting purposes.


Chris Murphy

-- 
Chris Murphy

[stan]

On Wed, 25 Jan 2017 15:24:52 -0700
Chris Murphy <lists(a)colorremedies.com&gt; wrote:

Thanks for the response.

>  Could be a labeling problem. Might be worth 'sudo restorecon -rv
> /'
>  and then a sync and then reboot -f and see if it works with
>  enforcing=0 (or even without, let it enforce). 
This made lots of changes, but didn't seem to affect the shutdown delay
problem.  After the restorecon, the system delayed without setenforce 0
and with it, a few times.  Some kind of race?

>  Stock Fedora 25 I have had a stop job for user 1000, that takes 90
>  seconds to time out. Your problem seems different. But to isolate if
>  this is a user environment problem, or a system problem, you could try
>  modifying /etc/systemd/logind.conf such that KillUserProcesses=yes 
This was already in place.

>  (and remove the # so it's uncommented). The gotcha with this is
> that
>  user processes are unceremoniously killed at logout time (including
>  restart and shutown). So if you use screen or tmux, and logout, the
>  tmux/screen processes get killed by virtue of tmux/screen getting
>  killed. There's a work around for that also which I can't articulate -
>  something to do with linger or gettting it to run in a separate logind
>  session? Anyway... just change this option temporarily for
>  troubleshooting purposes. 
I changed some timeout options in the systemd .conf files
in /ets/systemd. It doesn't seem consistent.  One time if I use
setenforce 0 there is no delay, and the next time there is. And there
aren't useful messages in the /shutdown-log.txt file that systemd is
creating.  I changed journald to allow all output by setting burst to
0.  The burst set to 0 didn't affect that there are lots of messages
elided by shutdown because of rate limiting.  I'll keep playing with
that, maybe I can see what the problem is if I can see those.

After more than a half dozen reboots, time for a respite.