Re: [systemd-devel] shutdown delayed by failure to start a service
Lennart Poettering composed on 2016-05-30 17:37 (UTC+0200): > Felix Miata wrote: >> Lennart Poettering composed on 2016-05-29 18:40 (UTC+0200): >> >Felix Miata wrote: >> >>The message I see is equivalent in form as during boot, e.g. when a >> >>filesystem not noauto in fstab is to be mounted but cannot be found, so a >> >>delay of typically 90sec, but sometimes much longer, occurs. Mount >> >>specification mistyped or a subsequently changed volume label, or similarly >> >>a change of filesystem UUID should be an easy enough way to observe what >> >>I've not infrequently seen, though the cause(s) of the more irritating >> >>shutdown delays isn't coming to mind ATM. If this was something I had a >> >>reliable recreate scenario for I'd have filed a bug somewhere by now, >> >>likely >> >>at least a year ago. >> >Well, we put a timeout of 90s on *everything* systemd starts or >> >stops. Hence, saying that you see some 90s timeout just means >> >*something* isn't finishing as quickly as it should, with exactly zero >> >information about what that something might be... >> Now that I know this isn't something familiar to you, I'll be on the watch >> to collect specifics to report next time I encounter it. Will there be a >> specific journalctl option to use at that time, or will -b do it? > "journalctl -b" shows you everything that happened during your current > boot. If you are trying to find log data generated during shutdown > this probably won't give you what you want, as you probably want the > data from the previous boot, not the current one, i.e. "journalctl > -b-1" is what you want... Caught one by journal. I had forgotten to edit fstab after some partition shuffling. Old/unchanged fstab (excerpt): LABEL=2st17f24 /disks/f24 ext4noatime,nofail 1 2 # blkid /dev/sda17 /dev/sda21 /dev/sda17: LABEL="2st17f25" UUID="bcb777c0-2283-41f8-a345-30356d7f253e" TYPE="ext4" PTTYPE="dos" PARTUUID="0051ea28-11" /dev/sda21: LABEL="2st21f24" UUID="98b1d584-6a0f-4b02-8dd4-e47f11ab994a" TYPE="ext4" PTTYPE="dos" PARTUUID="0051ea28-15" Subsequently repaired fstab (excerpt): LABEL=2st17f25 /disks/f25 ext4noatime,nofail 0 0 LABEL=2st21f24 /disks/f24 ext4noatime,nofail 0 0 # uname -a Linux g5eas 3.16.7-35-desktop #1 SMP PREEMPT Sun Feb 7 17:32:21 UTC 2016 (832c776) x86_64 x86_64 x86_64 GNU/Linux # zypper se -si | egrep 'systemd|udev' i | libgudev-1_0-0 | package | 210.1463730809.e37fc98-25.40.2 | x86_64 | Update i | libudev1 | package | 210.1463730809.e37fc98-25.40.2 | x86_64 | Update i | python-pyudev| package | 0.16.1-9.1.5 | noarch | OSS i | systemd | package | 210.1463730809.e37fc98-25.40.2 | x86_64 | Update i | systemd-bash-completion | package | 210.1463730809.e37fc98-25.40.2 | noarch | Update i | systemd-logger | package | 210.1463730809.e37fc98-25.40.2 | x86_64 | Update i | systemd-presets-branding-openSUSE| package | 0.3.0-12.7.1 | noarch | Update i | systemd-sysvinit | package | 210.1463730809.e37fc98-25.40.2 | x86_64 | Update i | udev | package | 210.1463730809.e37fc98-25.40.2 | x86_64 | Update i | util-linux-systemd | package | 2.25.1-20.1 | x86_64 | Update # journalctl -b -1 | tail -n55 Jun 14 22:14:21 g5eas systemd[1]: Stopping Apply Kernel Variables... Jun 14 22:14:21 g5eas systemd[1]: Stopped Apply Kernel Variables. Jun 14 22:14:21 g5eas systemd[1]: Stopping Setup Virtual Console... Jun 14 22:14:21 g5eas systemd[1]: Stopping Load Kernel Modules... Jun 14 22:14:21 g5eas systemd[1]: Stopped Load Kernel Modules. Jun 14 22:14:21 g5eas systemd[1]: Stopping Encrypted Volumes. Jun 14 22:14:21 g5eas systemd[1]: Stopped target Encrypted Volumes. Jun 14 22:14:21 g5eas systemd[1]: Stopping Swap. Jun 14 22:14:21 g5eas systemd[1]: Deactivating swap /dev/sda7... Jun 14 22:14:21 g5eas systemd[1]: Deactivating swap /dev/sda7... Jun 14 22:14:21 g5eas systemd[1]: Deactivating swap /dev/sda7... Jun 14 22:14:21 g5eas systemd[1]: Deactivating swap /dev/sda7... Jun 14 22:14:21 g5eas systemd[1]: Deactivating swap /dev/sda7... Jun 14 22:14:21 g5eas systemd[1]: Stopping Update UTMP about System Reboot/Shutdown... Jun 14 22:14:21 g5eas systemd[1]: Stopped Entropy Daemon based on the HAVEGE algorithm. Jun 14 22:14:21 g5eas systemd[1]: Stopped LSB: Set default boot entry if called. Jun 14 22:14:21 g5eas systemd[1]: Stopping Load/Save Random Seed... Jun 14 22:14:21 g5eas haveged[483]: haveged: Stopping due to signal 15 Jun 14 22:14:21 g5eas haveged[483]: haveged starting up Jun 14 22:14:21 g5eas systemd[1]: Deactivated swap
Re: [systemd-devel] shutdown delayed by failure to start a service
Lennart Poettering composed on 2016-05-30 17:37 (UTC+0200): > Felix Miata wrote: >> Lennart Poettering composed on 2016-05-29 18:40 (UTC+0200): >> >Felix Miata wrote: >> >>The message I see is equivalent in form as during boot, e.g. when a >> >>filesystem not noauto in fstab is to be mounted but cannot be found, so a >> >>delay of typically 90sec, but sometimes much longer, occurs. Mount >> >>specification mistyped or a subsequently changed volume label, or similarly >> >>a change of filesystem UUID should be an easy enough way to observe what >> >>I've not infrequently seen, though the cause(s) of the more irritating >> >>shutdown delays isn't coming to mind ATM. If this was something I had a >> >>reliable recreate scenario for I'd have filed a bug somewhere by now, >> >>likely >> >>at least a year ago. >> >Well, we put a timeout of 90s on *everything* systemd starts or >> >stops. Hence, saying that you see some 90s timeout just means >> >*something* isn't finishing as quickly as it should, with exactly zero >> >information about what that something might be... >> Now that I know this isn't something familiar to you, I'll be on the watch >> to collect specifics to report next time I encounter it. Will there be a >> specific journalctl option to use at that time, or will -b do it? > "journalctl -b" shows you everything that happened during your current > boot. If you are trying to find log data generated during shutdown > this probably won't give you what you want, as you probably want the > data from the previous boot, not the current one, i.e. "journalctl > -b-1" is what you want... Caught by journal: # blkid /dev/sda17 /dev/sda17: LABEL="2st17f25" UUID="bcb777c0-2283-41f8-a345-30356d7f253e" TYPE="ext4" PTTYPE="dos" PARTUUID="0051ea28-11" # uname -a Linux g5eas 3.16.7-35-desktop #1 SMP PREEMPT Sun Feb 7 17:32:21 UTC 2016 (832c776) x86_64 x86_64 x86_64 GNU/Linux # zypper se -si | egrep 'systemd|udev' i | libgudev-1_0-0 | package | 210.1463730809.e37fc98-25.40.2 | x86_64 | Update i | libudev1 | package | 210.1463730809.e37fc98-25.40.2 | x86_64 | Update i | python-pyudev| package | 0.16.1-9.1.5 | noarch | OSS i | systemd | package | 210.1463730809.e37fc98-25.40.2 | x86_64 | Update i | systemd-bash-completion | package | 210.1463730809.e37fc98-25.40.2 | noarch | Update i | systemd-logger | package | 210.1463730809.e37fc98-25.40.2 | x86_64 | Update i | systemd-presets-branding-openSUSE| package | 0.3.0-12.7.1 | noarch | Update i | systemd-sysvinit | package | 210.1463730809.e37fc98-25.40.2 | x86_64 | Update i | udev | package | 210.1463730809.e37fc98-25.40.2 | x86_64 | Update i | util-linux-systemd | package | 2.25.1-20.1 | x86_64 | Update # journalctl -b -1 | tail -n55 Jun 14 22:14:21 g5eas systemd[1]: Stopping Apply Kernel Variables... Jun 14 22:14:21 g5eas systemd[1]: Stopped Apply Kernel Variables. Jun 14 22:14:21 g5eas systemd[1]: Stopping Setup Virtual Console... Jun 14 22:14:21 g5eas systemd[1]: Stopping Load Kernel Modules... Jun 14 22:14:21 g5eas systemd[1]: Stopped Load Kernel Modules. Jun 14 22:14:21 g5eas systemd[1]: Stopping Encrypted Volumes. Jun 14 22:14:21 g5eas systemd[1]: Stopped target Encrypted Volumes. Jun 14 22:14:21 g5eas systemd[1]: Stopping Swap. Jun 14 22:14:21 g5eas systemd[1]: Deactivating swap /dev/sda7... Jun 14 22:14:21 g5eas systemd[1]: Deactivating swap /dev/sda7... Jun 14 22:14:21 g5eas systemd[1]: Deactivating swap /dev/sda7... Jun 14 22:14:21 g5eas systemd[1]: Deactivating swap /dev/sda7... Jun 14 22:14:21 g5eas systemd[1]: Deactivating swap /dev/sda7... Jun 14 22:14:21 g5eas systemd[1]: Stopping Update UTMP about System Reboot/Shutdown... Jun 14 22:14:21 g5eas systemd[1]: Stopped Entropy Daemon based on the HAVEGE algorithm. Jun 14 22:14:21 g5eas systemd[1]: Stopped LSB: Set default boot entry if called. Jun 14 22:14:21 g5eas systemd[1]: Stopping Load/Save Random Seed... Jun 14 22:14:21 g5eas haveged[483]: haveged: Stopping due to signal 15 Jun 14 22:14:21 g5eas haveged[483]: haveged starting up Jun 14 22:14:21 g5eas systemd[1]: Deactivated swap /dev/disk/by-path/pci-:00:1f.2-scsi-0:0:0:0-part7. Jun 14 22:14:21 g5eas systemd[1]: Deactivated swap /dev/disk/by-path/pci-:00:1f.2-ata-1.0-part7. Jun 14 22:14:21 g5eas systemd[1]: Deactivated swap /dev/disk/by-id/scsi-SATA_ST3200822AS_3LJ22WE0-part7. Jun 14 22:14:21 g5eas systemd[1]: Deactivated swap /dev/disk/by-id/scsi-1ATA_ST3200822AS_3LJ22WE0-part7. Jun 14 22:14:21 g5eas systemd[1]: Deactivated swap /dev/disk/by-id/scsi-0ATA_ST3200822AS_3LJ22WE0-part7. Jun 14 22:1
Re: [systemd-devel] shutdown delayed by failure to start a service
On Sun, 29.05.16 13:28, Felix Miata (mrma...@earthlink.net) wrote: > Lennart Poettering composed on 2016-05-29 18:40 (UTC+0200): > > >Felix Miata wrote: > > >>The message I see is equivalent in form as during boot, e.g. when a > >>filesystem not noauto in fstab is to be mounted but cannot be found, so a > >>delay of typically 90sec, but sometimes much longer, occurs. Mount > >>specification mistyped or a subsequently changed volume label, or similarly > >>a change of filesystem UUID should be an easy enough way to observe what > >>I've not infrequently seen, though the cause(s) of the more irritating > >>shutdown delays isn't coming to mind ATM. If this was something I had a > >>reliable recreate scenario for I'd have filed a bug somewhere by now, likely > >>at least a year ago. > > >Well, we put a timeout of 90s on *everything* systemd starts or > >stops. Hence, saying that you see some 90s timeout just means > >*something* isn't finishing as quickly as it should, with exactly zero > >information about what that something might be... > > Now that I know this isn't something familiar to you, I'll be on the watch > to collect specifics to report next time I encounter it. Will there be a > specific journalctl option to use at that time, or will -b do it? "journalctl -b" shows you everything that happened during your current boot. If you are trying to find log data generated during shutdown this probably won't give you what you want, as you probably want the data from the previous boot, not the current one, i.e. "journalctl -b-1" is what you want... That said, the journal itself is also terminated at shutdown. It's terminated quite late, but it might happen that something that also runs pretty late isn't covered anymore. This is harder to debug, and documented here: https://freedesktop.org/wiki/Software/systemd/Debugging/#index2h1 Lennart -- Lennart Poettering, Red Hat ___ systemd-devel mailing list systemd-devel@lists.freedesktop.org https://lists.freedesktop.org/mailman/listinfo/systemd-devel
Re: [systemd-devel] shutdown delayed by failure to start a service
29.05.2016 20:28, Felix Miata пишет: > Lennart Poettering composed on 2016-05-29 18:40 (UTC+0200): > >> Felix Miata wrote: > >>> The message I see is equivalent in form as during boot, e.g. when a >>> filesystem not noauto in fstab is to be mounted but cannot be found, >>> so a >>> delay of typically 90sec, but sometimes much longer, occurs. Mount >>> specification mistyped or a subsequently changed volume label, or >>> similarly >>> a change of filesystem UUID should be an easy enough way to observe what >>> I've not infrequently seen, though the cause(s) of the more irritating >>> shutdown delays isn't coming to mind ATM. If this was something I had a >>> reliable recreate scenario for I'd have filed a bug somewhere by now, >>> likely >>> at least a year ago. > >> Well, we put a timeout of 90s on *everything* systemd starts or >> stops. Hence, saying that you see some 90s timeout just means >> *something* isn't finishing as quickly as it should, with exactly zero >> information about what that something might be... > > Now that I know this isn't something familiar to you, I'll be on the > watch to collect specifics to report next time I encounter it. Will > there be a specific journalctl option to use at that time, or will -b do > it? Delay may also happen after journal is already shut down. The best way to collect shutdown log would be console logging. Either serial or net console. ___ systemd-devel mailing list systemd-devel@lists.freedesktop.org https://lists.freedesktop.org/mailman/listinfo/systemd-devel
Re: [systemd-devel] shutdown delayed by failure to start a service
Lennart Poettering composed on 2016-05-29 18:40 (UTC+0200): Felix Miata wrote: The message I see is equivalent in form as during boot, e.g. when a filesystem not noauto in fstab is to be mounted but cannot be found, so a delay of typically 90sec, but sometimes much longer, occurs. Mount specification mistyped or a subsequently changed volume label, or similarly a change of filesystem UUID should be an easy enough way to observe what I've not infrequently seen, though the cause(s) of the more irritating shutdown delays isn't coming to mind ATM. If this was something I had a reliable recreate scenario for I'd have filed a bug somewhere by now, likely at least a year ago. Well, we put a timeout of 90s on *everything* systemd starts or stops. Hence, saying that you see some 90s timeout just means *something* isn't finishing as quickly as it should, with exactly zero information about what that something might be... Now that I know this isn't something familiar to you, I'll be on the watch to collect specifics to report next time I encounter it. Will there be a specific journalctl option to use at that time, or will -b do it? -- "The wise are known for their understanding, and pleasant words are persuasive." Proverbs 16:21 (New Living Translation) Team OS/2 ** Reg. Linux User #211409 ** a11y rocks! Felix Miata *** http://fm.no-ip.com/ ___ systemd-devel mailing list systemd-devel@lists.freedesktop.org https://lists.freedesktop.org/mailman/listinfo/systemd-devel
Re: [systemd-devel] shutdown delayed by failure to start a service
On Sat, 28.05.16 04:42, Felix Miata (mrma...@earthlink.net) wrote: > Mantas Mikulėnas composed on 2016-05-27 20:05 (UTC+0300): > > >Lennart Poettering wrote: > > >>Felix Miata wrote: > > >>>Did this ever get fixed? IOW, sometimes a service will fail to start when a > >>>system is started, or later, after a session of updating, a previously > >>>operating service fails to restart, or a newly installed service fails to > >>>start, or a service is removed. Then at shutdown/reboot time, systemd > >>>pauses > >>>90 seconds with a message about trying to *start* a service. I think I most > >>>often notice this when I try to hold down CAD after a normal > >>>shutdown/reboot > >>>order gets stuck or seemingly ignored. At such times I typically see an > >>>"endless" string of failing to save sound card state messages. > > >>I have never heard of something like this. And what you describe is > >>not really how systemd works. At shutdown, we actually only shut down > >>services, we don't start any. > > The message I see is equivalent in form as during boot, e.g. when a > filesystem not noauto in fstab is to be mounted but cannot be found, so a > delay of typically 90sec, but sometimes much longer, occurs. Mount > specification mistyped or a subsequently changed volume label, or similarly > a change of filesystem UUID should be an easy enough way to observe what > I've not infrequently seen, though the cause(s) of the more irritating > shutdown delays isn't coming to mind ATM. If this was something I had a > reliable recreate scenario for I'd have filed a bug somewhere by now, likely > at least a year ago. Well, we put a timeout of 90s on *everything* systemd starts or stops. Hence, saying that you see some 90s timeout just means *something* isn't finishing as quickly as it should, with exactly zero information about what that something might be... Lennart -- Lennart Poettering, Red Hat ___ systemd-devel mailing list systemd-devel@lists.freedesktop.org https://lists.freedesktop.org/mailman/listinfo/systemd-devel
Re: [systemd-devel] shutdown delayed by failure to start a service
Mantas Mikulėnas composed on 2016-05-27 20:05 (UTC+0300): Lennart Poettering wrote: Felix Miata wrote: Did this ever get fixed? IOW, sometimes a service will fail to start when a system is started, or later, after a session of updating, a previously operating service fails to restart, or a newly installed service fails to start, or a service is removed. Then at shutdown/reboot time, systemd pauses 90 seconds with a message about trying to *start* a service. I think I most often notice this when I try to hold down CAD after a normal shutdown/reboot order gets stuck or seemingly ignored. At such times I typically see an "endless" string of failing to save sound card state messages. I have never heard of something like this. And what you describe is not really how systemd works. At shutdown, we actually only shut down services, we don't start any. The message I see is equivalent in form as during boot, e.g. when a filesystem not noauto in fstab is to be mounted but cannot be found, so a delay of typically 90sec, but sometimes much longer, occurs. Mount specification mistyped or a subsequently changed volume label, or similarly a change of filesystem UUID should be an easy enough way to observe what I've not infrequently seen, though the cause(s) of the more irritating shutdown delays isn't coming to mind ATM. If this was something I had a reliable recreate scenario for I'd have filed a bug somewhere by now, likely at least a year ago. Not when a distro installs some junk with DefaultDependencies=no & WantedBy=shutdown.target... So, you're saying this is something you're familiar with? -- "The wise are known for their understanding, and pleasant words are persuasive." Proverbs 16:21 (New Living Translation) Team OS/2 ** Reg. Linux User #211409 ** a11y rocks! Felix Miata *** http://fm.no-ip.com/ ___ systemd-devel mailing list systemd-devel@lists.freedesktop.org https://lists.freedesktop.org/mailman/listinfo/systemd-devel
Re: [systemd-devel] shutdown delayed by failure to start a service
On Fri, May 27, 2016 at 7:47 PM, Lennart Poettering wrote: > On Thu, 26.05.16 11:29, Felix Miata (mrma...@earthlink.net) wrote: > > > Did this ever get fixed? IOW, sometimes a service will fail to start > when a > > system is started, or later, after a session of updating, a previously > > operating service fails to restart, or a newly installed service fails to > > start, or a service is removed. Then at shutdown/reboot time, systemd > pauses > > 90 seconds with a message about trying to *start* a service. I think I > most > > often notice this when I try to hold down CAD after a normal > shutdown/reboot > > order gets stuck or seemingly ignored. At such times I typically see an > > "endless" string of failing to save sound card state messages. > > I have never heard of something like this. And what you describe is > not really how systemd works. At shutdown, we actually only shut down > services, we don't start any. > Not when a distro installs some junk with DefaultDependencies=no & WantedBy=shutdown.target... -- Mantas Mikulėnas ___ systemd-devel mailing list systemd-devel@lists.freedesktop.org https://lists.freedesktop.org/mailman/listinfo/systemd-devel
Re: [systemd-devel] shutdown delayed by failure to start a service
On Thu, 26.05.16 11:29, Felix Miata (mrma...@earthlink.net) wrote: > Did this ever get fixed? IOW, sometimes a service will fail to start when a > system is started, or later, after a session of updating, a previously > operating service fails to restart, or a newly installed service fails to > start, or a service is removed. Then at shutdown/reboot time, systemd pauses > 90 seconds with a message about trying to *start* a service. I think I most > often notice this when I try to hold down CAD after a normal shutdown/reboot > order gets stuck or seemingly ignored. At such times I typically see an > "endless" string of failing to save sound card state messages. I have never heard of something like this. And what you describe is not really how systemd works. At shutdown, we actually only shut down services, we don't start any. Lennart -- Lennart Poettering, Red Hat ___ systemd-devel mailing list systemd-devel@lists.freedesktop.org https://lists.freedesktop.org/mailman/listinfo/systemd-devel
[systemd-devel] shutdown delayed by failure to start a service
Did this ever get fixed? IOW, sometimes a service will fail to start when a system is started, or later, after a session of updating, a previously operating service fails to restart, or a newly installed service fails to start, or a service is removed. Then at shutdown/reboot time, systemd pauses 90 seconds with a message about trying to *start* a service. I think I most often notice this when I try to hold down CAD after a normal shutdown/reboot order gets stuck or seemingly ignored. At such times I typically see an "endless" string of failing to save sound card state messages. -- "The wise are known for their understanding, and pleasant words are persuasive." Proverbs 16:21 (New Living Translation) Team OS/2 ** Reg. Linux User #211409 ** a11y rocks! Felix Miata *** http://fm.no-ip.com/ ___ systemd-devel mailing list systemd-devel@lists.freedesktop.org https://lists.freedesktop.org/mailman/listinfo/systemd-devel
