Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > linux.debian.bugs.dist > #772480 > unrolled thread

Bug#840056: shibboleth-sp2-utils: upgrade attempt of shibboleth-sp2-utils gets hung at restart of shibd service

Back to article view | Back to linux.debian.bugs.dist

Contents

  Bug#840056: shibboleth-sp2-utils: upgrade attempt of shibboleth-sp2-utils gets hung at restart of shibd service banerian <banerian@uw.edu> - 2016-10-07 22:10 +0200
    Bug#840056: shibboleth-sp2-utils: upgrade attempt of shibboleth-sp2-utils gets hung at restart of shibd service wferi@niif.hu (Ferenc Wágner) - 2016-10-10 02:40 +0200
      Bug#840056: shibboleth-sp2-utils: upgrade attempt of shibboleth-sp2-utils gets hung at restart of shibd service "S. Banerian" <banerian@u.washington.edu> - 2016-10-10 23:20 +0200
        Bug#840056: shibboleth-sp2-utils: upgrade attempt of shibboleth-sp2-utils gets hung at restart of shibd service "S. Banerian" <banerian@u.washington.edu> - 2016-10-11 01:30 +0200
        Bug#840056: shibboleth-sp2-utils: upgrade attempt of shibboleth-sp2-utils gets hung at restart of shibd service wferi@niif.hu (Ferenc Wágner) - 2016-10-11 12:30 +0200
          Bug#840056: shibboleth-sp2-utils: upgrade attempt of shibboleth-sp2-utils gets hung at restart of shibd service "S. Banerian" <banerian@u.washington.edu> - 2016-10-11 20:20 +0200
            Bug#840056: shibboleth-sp2-utils: upgrade attempt of shibboleth-sp2-utils gets hung at restart of shibd service "S. Banerian" <banerian@u.washington.edu> - 2016-10-11 20:40 +0200
              Bug#840056: shibboleth-sp2-utils: upgrade attempt of shibboleth-sp2-utils gets hung at restart of shibd service wferi@niif.hu (Ferenc Wágner) - 2016-10-13 12:30 +0200

#772480 — Bug#840056: shibboleth-sp2-utils: upgrade attempt of shibboleth-sp2-utils gets hung at restart of shibd service

Package: shibboleth-sp2-utils
Version: 2.6.0+dfsg1-3+b1
Severity: important

Dear Maintainer,

In attempting to upgrade this package to the latest version, i see
repeated failures. shibd.log does not report unusual errors.
No /run/shibboleth/shibd.sock  is created.
During the attempt to upgrade, shibd process starts, but seems to get
hung (ps axjf):

apt-get -f install
  \_ /usr/bin/dpkg --status-fd 17 --configure --pending
    \_ /bin/sh 
      \_ /bin/sh /var/lib/dpkg/info/shibboleth-sp2-utils.postinst conf
        \_ systemctl start shibd.service 
          \_ /bin/systemd-tty-ask-password-agent --watch


journalctl -xe  shows:

-- Defined-By: systemd
-- Support: https://www.debian.org/support
-- 
-- Unit shibd.service has begun starting up.
Oct 07 12:24:25 epics systemd[1]: shibd.service: Start operation timed
out. Terminating.
Oct 07 12:24:31 epics systemd[1]: shibd.service: State
'stop-final-sigterm' timed out. Killing.
Oct 07 12:24:31 epics systemd[1]: shibd.service: Killing process 3910
(shibd) with signal SIGKILL.
Oct 07 12:24:31 epics systemd[1]: shibd.service: Main process exited,
code=killed, status=9/KILL
Oct 07 12:24:31 epics systemd[1]: Failed to start Shibboleth Service
Provider Daemon.
-- Subject: Unit shibd.service has failed
-- Defined-By: systemd
-- Support: https://www.debian.org/support
-- 
-- Unit shibd.service has failed.
-- 
-- The result is failed.
Oct 07 12:24:31 epics systemd[1]: shibd.service: Unit entered failed
state.
Oct 07 12:24:31 epics systemd[1]: shibd.service: Failed with result
'signal'.
Oct 07 12:25:01 epics systemd[1]: shibd.service: Service hold-off time
over, scheduling restart.
Oct 07 12:25:01 epics systemd[1]: Stopped Shibboleth Service Provider
Daemon.
-- Subject: Unit shibd.service has finished shutting down
-- Defined-By: systemd
-- Support: https://www.debian.org/support
-- 
-- Unit shibd.service has finished shutting down.
Oct 07 12:25:01 epics systemd[1]: Starting Shibboleth Service Provider
Daemon...
-- Subject: Unit shibd.service has begun start-up
-- Defined-By: systemd
-- Support: https://www.debian.org/support
-- 
-- Unit shibd.service has begun starting up.


Based on other bug reports, commands such as

systemctl stop systemd-ask-password-wall.service
and 
systemctl daemon-reexec

were tried, and typically led to dpkg failing.

Manually trying to start /usr/sbin/shibd -f -F  never produces the
/run/shibboleth/shibd.sock     nor any other files in that dir.



-- System Information:
Debian Release: stretch/sid
  APT prefers testing
  APT policy: (500, 'testing')
Architecture: amd64 (x86_64)

Kernel: Linux 4.6.0-1-amd64 (SMP w/2 CPU cores)
Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash
Init: systemd (via /run/systemd/system)

Versions of packages shibboleth-sp2-utils depends on:
ii  adduser            3.115
ii  libc6              2.24-3
ii  libfcgi0ldbl       2.4.0-8.4
ii  libgcc1            1:6.1.1-11
ii  liblog4shib1v5     1.0.9-3
ii  libsaml9           2.6.0-4
ii  libshibsp-plugins  2.6.0+dfsg1-3+b1
ii  libshibsp7         2.6.0+dfsg1-3+b1
ii  libstdc++6         6.1.1-11
ii  libsystemd0        231-9
ii  libxerces-c3.1     3.1.3+debian-2.1+b1
ii  libxmltooling7     1.6.0-3

Versions of packages shibboleth-sp2-utils recommends:
ii  openssl  1.0.2j-1

shibboleth-sp2-utils suggests no packages.

-- no debconf information

[toc] | [next] | [standalone]

#772923

"S. Banerian" <banerian@u.washington.edu> writes:

> On 10/07/2016 02:04 PM, Ferenc Wágner wrote:
> 
>>> Manually trying to start /usr/sbin/shibd -f -F never produces the
>>> /run/shibboleth/shibd.sock nor any other files in that dir.
>> 
>> This is really disturbing.  You don't except the above command to give
>> back your prompt, right?  
>
> correct.
>
>> Could you please make sure shibd isn't running
>> then show me the output of
>> 
>> # sudo -u _shibd strace shibd -f -F
>
> the output is rather long...
> I shall attach.

Thanks.  Does it hang there indefinitely, with no further output for
minutes?  Does shibd still consume significant CPU according to top?
What are its memory figures?  Isn't your computer swapping heavily?  Can
you provide a full GDB backtrace (after installing
shibboleth-sp2-utils-dbgsym; please yell if you need precise
instructions).

> Note: prior to the upgrade, shibboleth was working.

Which version of shibboleth was working for you?
Can you share your shibboleth2.xml?

> We did note that sometimes shibd was more well-behaved when starting
> from shell than via systemctl.

Could you please make this more precise?  How did it misbehave when
started by systemctl?
-- 
Thanks,
Feri

[toc] | [prev] | [next] | [standalone]

#773186

On 10/09/2016 05:25 PM, Ferenc Wágner wrote:
> "S. Banerian" <banerian@u.washington.edu> writes:
> 
>> On 10/07/2016 02:04 PM, Ferenc Wágner wrote:
>>
>>>> Manually trying to start /usr/sbin/shibd -f -F never produces the
>>>> /run/shibboleth/shibd.sock nor any other files in that dir.
>>>
>>> This is really disturbing.  You don't except the above command to give
>>> back your prompt, right?  
>>
>> correct.
>>
>>> Could you please make sure shibd isn't running
>>> then show me the output of
>>>
>>> # sudo -u _shibd strace shibd -f -F
>>
>> the output is rather long...
>> I shall attach.
> 
> Thanks.  Does it hang there indefinitely, with no further output for
> minutes?  

after some 12 hours of trying to start, failing, it finally started,
created shibd.sock, and under a test, worked.

Its dpkg status is still iF


Does shibd still consume significant CPU according to top?

at this moment, no.
> What are its memory figures?

nothing big.

> Isn't your computer swapping heavily?

no

> Can
> you provide a full GDB backtrace (after installing
> shibboleth-sp2-utils-dbgsym; please yell if you need precise
> instructions).

does not appear to be in stretch. so i need the instructions.


>> Note: prior to the upgrade, shibboleth was working.
> 
> Which version of shibboleth was working for you?

the version just prior to this one 2.6.0+dfsg1-3+b1 on stretch.

> Can you share your shibboleth2.xml?

I'm a bit reluctant to provide some of the information in the
RequestMapper sections.



>> We did note that sometimes shibd was more well-behaved when starting
>> from shell than via systemctl.
> 
> Could you please make this more precise?  How did it misbehave when
> started by systemctl?

this is where it hangs for minutes, says it might start, may or may not
create /run/shibboleth/shibd.sock  and the apache application only
returns with shibboleth errors.

Now, however, as it has sat over the weekend, and finally started, dpkg
has let the upgrade complete, with no errors.

When I force a restart, systemctl restart shibd.service I get the issue
as before, where

\_ /bin/systemd-tty-ask-password-agent --watch

stays there for a looong time, and is not returning, systemctl says it
is started, but journalctl -xe gives:

Oct 10 14:00:35 epics systemd[1]: shibd.service: Killing process 30980
(shibd) with signal SIGKILL.
Oct 10 14:00:35 epics systemd[1]: shibd.service: Main process exited,
code=killed, status=9/KILL
Oct 10 14:00:35 epics systemd[1]: Failed to start Shibboleth Service
Provider Daemon.
-- Subject: Unit shibd.service has failed

there is a shibd -f -F process running, but no shibd.sock file

I'm not convinced that systemd is behaving well.


-- 
Stefani Banerian
UW Clinical Cyclotron www.uwmcf.org
UW School of Medicine
UW Box 356043
206-598-0302
gpg key 6642E7EE
fingerprint = BD13 875D 2D03 5E1D 1E3B  8BF7 F4B8 63AD 6642 E7EE

[toc] | [prev] | [next] | [standalone]

#773213

On 10/10/2016 02:03 PM, S. Banerian wrote:
> On 10/09/2016 05:25 PM, Ferenc Wágner wrote:
> Does shibd still consume significant CPU according to top?
> 
> at this moment, no.
>> What are its memory figures?
> 
> nothing big.
> 
>> Isn't your computer swapping heavily?
> 
> no

with the attempt to perform
systemctl restart shibd.service
I'm now seeing the CPU at 100% and memory (but not yet swap) near 100% also.
and no  shibd.sock.

web app error message:

shibsp::ListenerException

The system encountered an error at Mon Oct 10 14:06:15 2016
To report this problem, please contact the site administrator at ...

Please include the following message in any email:

shibsp::ListenerException at ...

Cannot connect to shibd process, a site administrator should be notified
that this web server has malfunctioned.


rebooting machine gave same result.  I'll let it sit overnight to see
what happens.


-- 
Stefani Banerian
UW Clinical Cyclotron www.uwmcf.org
UW School of Medicine
UW Box 356043
206-598-0302
gpg key 6642E7EE
fingerprint = BD13 875D 2D03 5E1D 1E3B  8BF7 F4B8 63AD 6642 E7EE

[toc] | [prev] | [next] | [standalone]

#773309

"S. Banerian" <banerian@u.washington.edu> writes:

> On 10/09/2016 05:25 PM, Ferenc Wágner wrote:
>
>> "S. Banerian" <banerian@u.washington.edu> writes:
>> 
>>> On 10/07/2016 02:04 PM, Ferenc Wágner wrote:
>>>
>>>> Could you please make sure shibd isn't running
>>>> then show me the output of
>>>>
>>>> # sudo -u _shibd strace shibd -f -F
> [...]
> after some 12 hours of trying to start, failing, it finally started,
> created shibd.sock, and under a test, worked.

Was this the doing of a single invocation of the above, or do you refer
to systemd continuously trying to restart it and succeeding eventually?

>> Can you provide a full GDB backtrace (after installing
>> shibboleth-sp2-utils-dbgsym; please yell if you need precise
>> instructions).
>
> does not appear to be in stretch. so i need the instructions.

It is in a separate archive, see
https://wiki.debian.org/AutomaticDebugPackages.  But let's exclude the
simple timeout problem beforehand.

>>> Note: prior to the upgrade, shibboleth was working.
>> 
>> Which version of shibboleth was working for you?
>
> the version just prior to this one 2.6.0+dfsg1-3+b1 on stretch.

Do you mean 2.5.6+dfsg1-2?  Your dpkg or apt logs should reveal the
upgraded version.

>> Can you share your shibboleth2.xml?
>
> I'm a bit reluctant to provide some of the information in the
> RequestMapper sections.

If configuring a longer timeout (below) does not help, please check if
you can reproduce the issue without the sensitive parts.

> When I force a restart, systemctl restart shibd.service I get the issue
> as before, where
>
> \_ /bin/systemd-tty-ask-password-agent --watch
>
> stays there for a looong time, and is not returning, systemctl says it
> is started, but journalctl -xe gives:
>
> Oct 10 14:00:35 epics systemd[1]: shibd.service: Killing process 30980
> (shibd) with signal SIGKILL.
> Oct 10 14:00:35 epics systemd[1]: shibd.service: Main process exited,
> code=killed, status=9/KILL
> Oct 10 14:00:35 epics systemd[1]: Failed to start Shibboleth Service
> Provider Daemon.
> -- Subject: Unit shibd.service has failed

This really does not make much sense together...  And I can't see any
systemd-tty-ask-password-agent processes at all for some reason.

> there is a shibd -f -F process running, but no shibd.sock file

Are you sure that process isn't from some manual start attempt?  Also,
if you start an instance manually while systemd's still trying to
occasionally restart shibd in the background, the socket may get lost.

So, first of all, tell systemd to stop shibd and wait for it:

# systemctl stop shibd

Then you should see something like:

# systemctl status shibd
[...]
   Active: inactive (dead) [...]
[...]
 Main PID: 360 (code=exited, status=0/SUCCESS)
[...]
Oct 11 11:34:39 elm systemd[1]: Stopped Shibboleth Service Provider Daemon.

Then start it manually:

# date; sudo -u _shibd /usr/sbin/shibd -f -F

Meanwhile check /var/log/shibboleth/shibd.log for progress; the
timestamps should tell you where time was spent.

> I'm not convinced that systemd is behaving well.

Maybe it is, just the default start timeut (90s) is too short for your
metadata setup.  Try setting it longer like:

# mkdir /etc/systemd/system/shibd.service.d
# printf '[Service]\nTimeoutStartSec=5min\n' >/etc/systemd/system/shibd.service.d/timeout.conf
# systemctl daemon-reload
# systemctl cat shibd
[you should see the result at then end of output]

Make sure to Ctrl-C your manually started shibd process if it's still
running before starting the systemd shibd service.

> with the attempt to perform
> systemctl restart shibd.service
> I'm now seeing the CPU at 100% and memory (but not yet swap) near 100% also.
> and no shibd.sock.

Yes, the startup phase of shibd can consume lots of resources (Dynamic
MetadataProvider can help with this).  And the default timeout changed
from 5min to 1.5min in this upgrade, which might cause your problems.
-- 
Feri

[toc] | [prev] | [next] | [standalone]

#773422

On 10/11/2016 03:22 AM, Ferenc Wágner wrote:
> "S. Banerian" <banerian@u.washington.edu> writes:
> 
>> On 10/09/2016 05:25 PM, Ferenc Wágner wrote:
>>
>>> "S. Banerian" <banerian@u.washington.edu> writes:
>>>
>>>> On 10/07/2016 02:04 PM, Ferenc Wágner wrote:
>>>>
>>>>> Could you please make sure shibd isn't running
>>>>> then show me the output of
>>>>>
>>>>> # sudo -u _shibd strace shibd -f -F
>> [...]
>> after some 12 hours of trying to start, failing, it finally started,
>> created shibd.sock, and under a test, worked.
> 
> Was this the doing of a single invocation of the above, or do you refer
> to systemd continuously trying to restart it and succeeding eventually?

this was systemd continually trying. i ensured no spurious shibd procs
were running.



>>> Can you provide a full GDB backtrace (after installing
>>> shibboleth-sp2-utils-dbgsym; please yell if you need precise
>>> instructions).
>>
>> does not appear to be in stretch. so i need the instructions.
> 
> It is in a separate archive, see
> https://wiki.debian.org/AutomaticDebugPackages.  But let's exclude the
> simple timeout problem beforehand.
> 
>>>> Note: prior to the upgrade, shibboleth was working.
>>>
>>> Which version of shibboleth was working for you?
>>
>> the version just prior to this one 2.6.0+dfsg1-3+b1 on stretch.
> 
> Do you mean 2.5.6+dfsg1-2?  Your dpkg or apt logs should reveal the
> upgraded version.

yes.


>>> Can you share your shibboleth2.xml?
>>
>> I'm a bit reluctant to provide some of the information in the
>> RequestMapper sections.
> 
> If configuring a longer timeout (below) does not help, please check if
> you can reproduce the issue without the sensitive parts.
> 
>> When I force a restart, systemctl restart shibd.service I get the issue
>> as before, where
>>
>> \_ /bin/systemd-tty-ask-password-agent --watch
>>
>> stays there for a looong time, and is not returning, systemctl says it
>> is started, but journalctl -xe gives:
>>
>> Oct 10 14:00:35 epics systemd[1]: shibd.service: Killing process 30980
>> (shibd) with signal SIGKILL.
>> Oct 10 14:00:35 epics systemd[1]: shibd.service: Main process exited,
>> code=killed, status=9/KILL
>> Oct 10 14:00:35 epics systemd[1]: Failed to start Shibboleth Service
>> Provider Daemon.
>> -- Subject: Unit shibd.service has failed
> 
> This really does not make much sense together...  And I can't see any
> systemd-tty-ask-password-agent processes at all for some reason.

we agree. no reason to be seeing this.



>> there is a shibd -f -F process running, but no shibd.sock file
> 
> Are you sure that process isn't from some manual start attempt?  Also,
> if you start an instance manually while systemd's still trying to
> occasionally restart shibd in the background, the socket may get lost.
> 
> So, first of all, tell systemd to stop shibd and wait for it:
> 
> # systemctl stop shibd
> 
> Then you should see something like:
> 
> # systemctl status shibd
> [...]
>    Active: inactive (dead) [...]
> [...]
>  Main PID: 360 (code=exited, status=0/SUCCESS)
> [...]
> Oct 11 11:34:39 elm systemd[1]: Stopped Shibboleth Service Provider Daemon.

actually, after doing that, I got:

systemctl  status shibd.service
● shibd.service - Shibboleth Service Provider Daemon
   Loaded: loaded (/lib/systemd/system/shibd.service; disabled; vendor
preset: enabled)
   Active: inactive (dead)
     Docs: man:shibd(8)

https://wiki.shibboleth.net/confluence/display/SHIB2/NativeSPshibd

Oct 11 10:35:18 epics systemd[1]: Stopped Shibboleth Service Provider
Daemon.
Oct 11 10:35:18 epics systemd[1]: Starting Shibboleth Service Provider
Daemon...
Oct 11 10:36:48 epics systemd[1]: shibd.service: Start operation timed
out. Terminating.
Oct 11 10:36:54 epics systemd[1]: shibd.service: State
'stop-final-sigterm' timed out. Killing.
Oct 11 10:36:54 epics systemd[1]: shibd.service: Killing process 5523
(shibd) with signal SIGKILL.
Oct 11 10:36:54 epics systemd[1]: shibd.service: Main process exited,
code=killed, status=9/KILL
Oct 11 10:36:54 epics systemd[1]: Failed to start Shibboleth Service
Provider Daemon.
Oct 11 10:36:54 epics systemd[1]: shibd.service: Unit entered failed state.
Oct 11 10:36:54 epics systemd[1]: shibd.service: Failed with result
'signal'.
Oct 11 10:36:58 epics systemd[1]: Stopped Shibboleth Service Provider
Daemon.



> Then start it manually:
> 
> # date; sudo -u _shibd /usr/sbin/shibd -f -F
> 
> Meanwhile check /var/log/shibboleth/shibd.log for progress; the
> timestamps should tell you where time was spent.

Did this, and after a while, it started.


>> I'm not convinced that systemd is behaving well.
> 
> Maybe it is, just the default start timeut (90s) is too short for your
> metadata setup.  Try setting it longer like:
> 
> # mkdir /etc/systemd/system/shibd.service.d
> # printf '[Service]\nTimeoutStartSec=5min\n' >/etc/systemd/system/shibd.service.d/timeout.conf
> # systemctl daemon-reload
> # systemctl cat shibd
> [you should see the result at then end of output]
> 
> Make sure to Ctrl-C your manually started shibd process if it's still
> running before starting the systemd shibd service.
> 
>> with the attempt to perform
>> systemctl restart shibd.service
>> I'm now seeing the CPU at 100% and memory (but not yet swap) near 100% also.
>> and no shibd.sock.
> 
> Yes, the startup phase of shibd can consume lots of resources (Dynamic
> MetadataProvider can help with this).  And the default timeout changed
> from 5min to 1.5min in this upgrade, which might cause your problems.

adding the timeout.conf file, systemctl daemon-reload and then
systemctl start shibd

after approximately two minutes, the shibd process started.
I was able to use apache2 normally. I was able to
systemctl stop shibd   and start it again normally, and after two
minutes or so, it was running.

I have been able to reproduce this now. Two minutes seems to be the
requirement.

thank you.


-- 
Stefani Banerian
UW Clinical Cyclotron www.uwmcf.org
UW School of Medicine
UW Box 356043
206-598-0302
gpg key 6642E7EE
fingerprint = BD13 875D 2D03 5E1D 1E3B  8BF7 F4B8 63AD 6642 E7EE

[toc] | [prev] | [next] | [standalone]

#773432

On 10/11/2016 11:18 AM, Cantor, Scott wrote:
>> I have been able to reproduce this now. Two minutes seems to be the
>> requirement.
> 
> That would imply a fairly slow machine + a fairly large metadata source. In any event, the only real fix is moving to on-demand metadata, so whatever your metadata source is, you need to be thinking in terms of making sure they know they have to stop relying on aggregates.
> 
> -- Scott

I will pass on this suggestion to InCommon and my local IdP, the u of
Washington, who are the sources.

sb



-- 
Stefani Banerian
UW Clinical Cyclotron www.uwmcf.org
UW School of Medicine
UW Box 356043
206-598-0302
gpg key 6642E7EE
fingerprint = BD13 875D 2D03 5E1D 1E3B  8BF7 F4B8 63AD 6642 E7EE

[toc] | [prev] | [next] | [standalone]

#773794

Control: severity -1 wishlist

I transform this into a request to enlarge the default shibd start
timeout.  Scott, can you think of any reasonable maximum?
-- 
Thanks,
Feri

[toc] | [prev] | [standalone]

Back to top | Article view | linux.debian.bugs.dist

csiph-web