Bug 599509

Summary: Reconfiguring while service active spews to /var/log/messages
Product: Red Hat Enterprise Linux 6 Reporter: Jan Zeleny <jzeleny>
Component: xinetdAssignee: Jan Zeleny <jzeleny>
Status: CLOSED CURRENTRELEASE QA Contact: Martin Cermak <mcermak>
Severity: medium Docs Contact:
Priority: low    
Version: 6.0CC: azelinka, jifl-bugzilla, jzeleny, mcermak, ovasik
Target Milestone: rc   
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: xinetd-2.3.14-29.el6 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: 593904
: 754444 (view as bug list) Environment:
Last Closed: 2010-11-10 21:55:23 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On: 593904    
Bug Blocks: 754444    

Description Jan Zeleny 2010-06-03 11:59:13 UTC
+++ This bug was initially created as a clone of Bug #593904 +++

Description of problem:

I disabled the amanda backup client service with "chkconfig amanda off" while the amanda client was running. The outcome was that xinetd got itself confused and spewed this message endlessly to /var/log/messages:

May 20 02:39:03 localhost xinetd[17737]: 1 descriptors still set

By the time I noticed the log file was over 2 gig.

Here is the output in /var/log/messages when the chkconfig was run:

May 20 02:00:03 localhost xinetd[17737]: START: amanda pid=10697 from=::ffff:192.168.7.11
May 20 02:39:02 localhost xinetd[17737]: Starting reconfiguration
May 20 02:39:02 localhost xinetd[17737]: Swapping defaults
May 20 02:39:02 localhost xinetd[17737]: readjusting service tftp
May 20 02:39:02 localhost xinetd[17737]: Sending signal 9 to amanda server 10697
May 20 02:39:03 localhost xinetd[17737]: EXIT: amanda status=0 pid=10697 duration=2340(sec)
May 20 02:39:03 localhost xinetd[17737]: service amanda deactivated
May 20 02:39:03 localhost xinetd[17737]: amanda: svc_release with 0 count
May 20 02:39:03 localhost xinetd[17737]: Reconfigured: new=0 old=1 dropped=1 (services)
May 20 02:39:03 localhost xinetd[17737]: unknown child process 10697 died
May 20 02:39:03 localhost xinetd[17737]: 1 descriptors still set
[repeat forever]

I have a suspicion the problem may be because xinetd is expecting the socket to get freed up when it kills the process. However amanda forks off child processes, each of which I suspect get dups of the socket fds which they don't close (very probably for a good reason). The amanda client is of course entitled to do this, so it is xinetd which is making false assumptions.

And it should definitely not be the case that it should syslog a message repeatedly forever. This could have DoS'd my machine.

Version-Release number of selected component (if applicable):

xinetd-2.3.14-30.fc12.x86_64

Steps to reproduce:

1. Have amanda backup in progress
2. While client is running, run: chkconfig amanda off.

If my suspicions are correct, you could instead substitute any xinetd client which forks a child.

--- Additional comment from jzeleny on 2010-05-20 08:40:48 CEST ---

Are you sure with the xinetd version? Revision 30 should fix this issue.

--- Additional comment from jifl-bugzilla on 2010-05-20 10:26:05 CEST ---

Yes I'm sure, and rpm -V xinetd confirms. And to check it isn't jsut the running executable not matching the RPM, I double-checked and it was installed on my machine on April 20th, and it had restarted at least on May 13th.

I've now found bug 573764 which you are evidently referring to. If I try and reproduce the problem reported in that bug report, then it does not reproduce. Similarly I can enable and disable the amanda service normally. I believe the problem is specific to when a client like the amanda client is running at the time it is disabled.

Here's a clearer way to reproduce using amanda:

1) chkconfig amanda on
2) In another shell do:
nc -u localhost 10080
3) press return so that a packet is sent and xinetd kicks off amandad
4) Back in the root shell, run: chkconfig amanda off
5) tail /var/log/messages

--- Additional comment from jzeleny on 2010-05-20 10:37:41 CEST ---

Thanks for verbose information. I'll look to it ASAP.

--- Additional comment from jzeleny on 2010-05-27 13:47:39 CEST ---

I didn't manage to reproduce the issue, so I might need some help here. This is my tail /var/log/messages:

May 27 13:41:17 localhost xinetd[6481]: Reconfigured: new=0 old=1 dropped=0 (services)
May 27 13:41:21 localhost xinetd[6481]: START: amanda pid=6489 from=::ffff:127.0.0.1
May 27 13:41:51 localhost xinetd[6481]: EXIT: amanda status=0 pid=6489 duration=30(sec)
May 27 13:41:59 localhost xinetd[6481]: Starting reconfiguration
May 27 13:41:59 localhost xinetd[6481]: Swapping defaults
May 27 13:41:59 localhost xinetd[6481]: service amanda deactivated
May 27 13:41:59 localhost xinetd[6481]: amanda: svc_release with 0 count
May 27 13:41:59 localhost xinetd[6481]: Reconfigured: new=0 old=0 dropped=1 (services)

Please run xinetd in debug mode (-d), try to reproduce the issue and send me the log output. Hopefully from it I will be able to find out what's wrong.

--- Additional comment from jifl-bugzilla on 2010-05-27 18:32:35 CEST ---

Created an attachment (id=417301)
GNU screen log

It reproduces so easily for me I'm surprised you have a difference. But sure, here's the debug output. I had to use GNU screen to log it (xinetd seems to send debug output straight to the tty, rather than stdout/err).

--- Additional comment from jzeleny on 2010-06-01 14:26:30 CEST ---

I finally figured out what's going on. I've created a scratch build and briefly tested it. It seems to fix the issue. Can you please confirm it?

http://koji.fedoraproject.org/koji/taskinfo?taskID=2221987

--- Additional comment from jifl-bugzilla on 2010-06-01 16:03:23 CEST ---

Thanks for looking at this. I can't see the problem any more (although I've only been able to try it manually connecting with nc rather than with a proper amanda run) so it looks ok to me.

Thanks!

--- Additional comment from updates on 2010-06-02 09:31:23 CEST ---

xinetd-2.3.14-31.fc12 has been submitted as an update for Fedora 12.
http://admin.fedoraproject.org/updates/xinetd-2.3.14-31.fc12

--- Additional comment from updates on 2010-06-02 10:08:21 CEST ---

xinetd-2.3.14-32.fc13 has been submitted as an update for Fedora 13.
http://admin.fedoraproject.org/updates/xinetd-2.3.14-32.fc13

--- Additional comment from updates on 2010-06-02 20:03:36 CEST ---

xinetd-2.3.14-32.fc13 has been pushed to the Fedora 13 testing repository.  If problems still persist, please make note of it in this bug report.
 If you want to test the update, you can install it with 
 su -c 'yum --enablerepo=updates-testing update xinetd'.  You can provide feedback for this update here: http://admin.fedoraproject.org/updates/xinetd-2.3.14-32.fc13

--- Additional comment from updates on 2010-06-02 20:03:45 CEST ---

xinetd-2.3.14-31.fc12 has been pushed to the Fedora 12 testing repository.  If problems still persist, please make note of it in this bug report.
 If you want to test the update, you can install it with 
 su -c 'yum --enablerepo=updates-testing update xinetd'.  You can provide feedback for this update here: http://admin.fedoraproject.org/updates/xinetd-2.3.14-31.fc12

Comment 1 RHEL Program Management 2010-06-03 12:03:15 UTC
This request was evaluated by Red Hat Product Management for inclusion in a Red
Hat Enterprise Linux major release.  Product Management has requested further
review of this request by Red Hat Engineering, for potential inclusion in a Red
Hat Enterprise Linux Major release.  This request is not yet committed for
inclusion.

Comment 5 Martin Cermak 2010-09-17 06:15:37 UTC
=> VERIFIED

Comment 6 releng-rhel@redhat.com 2010-11-10 21:55:23 UTC
Red Hat Enterprise Linux 6.0 is now available and should resolve
the problem described in this bug report. This report is therefore being closed
with a resolution of CURRENTRELEASE. You may reopen this bug report if the
solution does not work for you.