Menu

#26 DenyHosts exits without message

open
None
9
2008-11-12
2008-02-13
BlueH2O
No

My denyhosts daemon has been dying at seemingly random times. Last time it ran less than a minute, the time before that more than a day.

Feb 13 10:00:31 - AllowedHosts: DEBUG done initializing AllowedHosts
Feb 13 10:00:31 - filetracker : DEBUG __get_last_offset():
Feb 13 10:00:31 - filetracker : DEBUG first_line: Feb 10 04:10:02 arturo rsyslogd: [origin software="rsyslogd" swVersion="1.19.11" x-pid="1881"][x-configInfo udpReception="No" udpPort="514" tcpReception="No" tcpPort="0"] restart
Feb 13 10:00:31 - filetracker : DEBUG offset: 349631
Feb 13 10:00:31 - filetracker : DEBUG get_offset():
Feb 13 10:00:31 - filetracker : DEBUG offset: None
Feb 13 10:00:31 - denyhosts : INFO launching DenyHosts daemon (version 2.6)...
Feb 13 10:00:31 - denyhosts : INFO DenyHosts daemon is now running, pid: 31044
Feb 13 10:00:31 - denyhosts : INFO send daemon process a TERM signal to terminate cleanly
Feb 13 10:00:31 - denyhosts : INFO eg. kill -TERM 31044

As you can see there was no exit message or debug info as to why the process died.

Discussion

  • BlueH2O

    BlueH2O - 2008-02-13

    Logged In: YES
    user_id=1267347
    Originator: YES

    I have restarted denyhosts with debug and will report any new information I can gather.

     
  • Nobody/Anonymous

    Logged In: NO

    Today at 4 AM, denyhosts stopped:

    Mar 05 03:39:06 - denyhosts : DEBUG new hosts: []
    Mar 05 03:39:06 - denyhosts : DEBUG no new denied hosts
    Mar 05 03:39:06 - denyhosts : DEBUG no new suspicious logins
    Mar 05 04:10:02 - denyhosts : DEBUG Received SIGTERM
    Mar 05 04:10:02 - denyhosts : INFO DenyHosts daemon is shutting down

    And then started up again a second later:

    Mar 05 04:10:03 - denyhosts : INFO DenyHosts launched with the following args:
    Mar 05 04:10:03 - denyhosts : INFO /usr/bin/denyhosts.py --daemon --config=/etc/denyhosts.conf --debug
    <snip>
    Mar 05 04:10:03 - AllowedHosts: DEBUG done initializing AllowedHosts
    Mar 05 04:10:03 - filetracker : DEBUG __get_last_offset():
    Mar 05 04:10:03 - filetracker : DEBUG first_line: Mar 2 04:10:08 arturo rsyslogd: [origin software="rsyslogd" swVersion="2.0.2" x-pid="1849" x-info="http://www.rsyslog.com"][x-configInfo udpReception="No" udpPort="514" tcpReception="No" tcpPort="0"] restart
    Mar 05 04:10:03 - filetracker : DEBUG offset: 145221
    Mar 05 04:10:03 - filetracker : DEBUG get_offset():
    Mar 05 04:10:03 - filetracker : DEBUG offset: None
    Mar 05 04:10:03 - denyhosts : INFO launching DenyHosts daemon (version 2.6)...
    Mar 05 04:10:03 - denyhosts : INFO DenyHosts daemon is now running, pid: 6224
    Mar 05 04:10:03 - denyhosts : INFO send daemon process a TERM signal to terminate cleanly
    Mar 05 04:10:03 - denyhosts : INFO eg. kill -TERM 6224

    and then the process died..

    # service denyhosts status
    denyhosts.py is stopped

    Where did the sigterm come from in the first place?

     
  • BlueH2O

    BlueH2O - 2008-03-05

    Logged In: YES
    user_id=1267347
    Originator: YES

    Oops that was me, forgot to log in.

     
  • BlueH2O

    BlueH2O - 2008-04-16

    Logged In: YES
    user_id=1267347
    Originator: YES

    Today I noticed that although denyhosts claims to be running with PID 7953, it's not logging anything and not responding to attacks on my machine for the past week and a half.

     
  • BlueH2O

    BlueH2O - 2008-04-16

    Logged In: YES
    user_id=1267347
    Originator: YES

    I forgot to mention, it was running with --debug, but logged nothing. When I stopped it,
    it was apparently still running and responded to SIGTERM but for the past week and a half
    has been sitting idle doing nothing.

     
  • BlueH2O

    BlueH2O - 2008-04-16

    Logged In: YES
    user_id=1267347
    Originator: YES

    This is the tail for the denyhosts log showing it did not do ANYTHING from april 5th to today but yet was still running.

    Apr 05 12:02:14 - denyhosts : DEBUG /var/log/messages has additional data
    Apr 05 12:02:14 - denyhosts : DEBUG new hosts: []
    Apr 05 12:02:14 - denyhosts : DEBUG no new denied hosts
    Apr 05 12:02:14 - denyhosts : DEBUG no new suspicious logins
    Apr 05 12:06:14 - denyhosts : DEBUG /var/log/messages has additional data
    Apr 05 12:06:15 - denyhosts : DEBUG new hosts: []
    Apr 05 12:06:15 - denyhosts : DEBUG no new denied hosts
    Apr 05 12:06:15 - denyhosts : DEBUG no new suspicious logins
    Apr 05 12:09:15 - denyhosts : DEBUG /var/log/messages has additional data
    Apr 05 12:09:15 - denyhosts : DEBUG new hosts: []
    Apr 05 12:09:15 - denyhosts : DEBUG no new denied hosts
    Apr 05 12:09:15 - denyhosts : DEBUG no new suspicious logins
    Apr 05 12:20:15 - denyfileutil: DEBUG relative cutoff: 2419200 (seconds)
    Apr 05 12:20:15 - denyfileutil: DEBUG absolute cutoff: 1204993215 (epoch)
    Apr 05 12:20:15 - denyfileutil: INFO purging entries older than: Sat Mar 8 11:20:15 2008
    Apr 05 12:20:17 - loginattempt: INFO purging_hosts: ['200.114.6.122', '210.212.161.105', '202.69.140.58', '201.6.150.185', '65.254.55.10', '122.252.228.2', '82.210.107.242', '200.68.43.66', '141.201.50.213', '216.154.221.227', '202.105.179.9']
    Apr 05 12:20:20 - denyfileutil: INFO num entries purged: 11
    Apr 05 12:20:20 - denyhosts : DEBUG sync upload
    Apr 05 12:20:20 - sync : DEBUG send_new_hosts()
    Apr 05 12:20:20 - denyhosts : DEBUG sync download
    Apr 05 12:20:20 - sync : DEBUG receive_new_hosts()
    Apr 16 09:54:17 - denyhosts : DEBUG Received SIGTERM
    Apr 16 09:54:17 - denyhosts : INFO DenyHosts daemon is shutting down

    I'm setting a high priority on this bug. I'm not sure if anyone cares but I would call this behavior a critical problem.

     
  • BlueH2O

    BlueH2O - 2008-04-16
    • priority: 5 --> 9
     
  • BlueH2O

    BlueH2O - 2008-04-29

    denyhosts log

     
  • BlueH2O

    BlueH2O - 2008-04-29

    Logged In: YES
    user_id=1267347
    Originator: YES

    DenyHosts again exited without warning today after the daily cron jobs ran. The log shows it getting a TERM, exiting, restarting, and then dying without any warning.
    File Added: denyhosts

     
  • BlueH2O

    BlueH2O - 2008-04-29

    Logged In: YES
    user_id=1267347
    Originator: YES

    DenyHosts again exited without warning today after the daily cron jobs ran. The attached log shows it getting a TERM, exiting, restarting, and then dying without any warning.

     
  • BlueH2O

    BlueH2O - 2008-05-07

    Logged In: YES
    user_id=1267347
    Originator: YES

    Once again, denyhosts reports it's running (has PID) but has not logged anything for two days:

    May 04 17:10:51 - denyfileutil: DEBUG relative cutoff: 2419200 (seconds)
    May 04 17:10:51 - denyfileutil: DEBUG absolute cutoff: 1207516251 (epoch)
    May 04 17:10:51 - denyfileutil: INFO purging entries older than: Sun Apr 6 17:10:51 2008
    May 04 17:10:53 - denyfileutil: INFO num entries purged: 0
    May 04 17:10:53 - denyhosts : DEBUG sync upload
    May 04 17:10:53 - sync : DEBUG send_new_hosts()
    May 04 17:10:53 - denyhosts : DEBUG sync download
    May 04 17:10:53 - sync : DEBUG receive_new_hosts()

     
  • Robert Hardy

    Robert Hardy - 2008-05-07

    Logged In: YES
    user_id=527588
    Originator: NO

    I'm seeing something similar but the process is just stopping working during the download sync phase.

    The last thing in the logs is a recieved new hosts line, it hangs and stops checking the logs.

    I don't get any indication it's broken until thousands of attacks make it through and I notice them in the logs.

    I don't get a failure or trace until I try to stop the hung process.

    I have to rerun denyhosts.py --ignore to pickup the hosts which were attacking me during the failure.

    008-05-03 17:13:02,998 - denyhosts : INFO received new hosts: ['85.17.170.78', '81.30.190.193', '216.223.9.221', '58.53.196.135', '200.80.145.51', '81.25.50.40', '61.50.146.1', '24.227.171.188', '218.106.96
    2008-05-07 11:42:56,765 - denyhosts : INFO DenyHosts daemon is shutting down
    2008-05-07 11:42:56,775 - sync : ERROR 0
    Traceback (most recent call last):
    File "/usr/lib/python2.4/site-packages/DenyHosts/sync.py", line 117, in receive_new_hosts
    self.__prefs.get("SYNC_DOWNLOAD_RESILIENCY"))
    File "/usr/lib64/python2.4/xmlrpclib.py", line 1096, in __call__
    return self.__send(self.__name, args)
    File "/usr/lib64/python2.4/xmlrpclib.py", line 1383, in __request
    verbose=self.__verbose
    File "/usr/lib64/python2.4/xmlrpclib.py", line 1131, in request
    errcode, errmsg, headers = h.getreply()
    File "/usr/lib64/python2.4/httplib.py", line 1137, in getreply
    response = self._conn.getresponse()
    File "/usr/lib64/python2.4/httplib.py", line 866, in getresponse
    response.begin()
    File "/usr/lib64/python2.4/httplib.py", line 365, in begin
    self.msg = HTTPMessage(self.fp, 0)
    File "/usr/lib64/python2.4/mimetools.py", line 16, in __init__
    rfc822.Message.__init__(self, fp, seekable)
    File "/usr/lib64/python2.4/rfc822.py", line 106, in __init__
    self.readheaders()
    File "/usr/lib64/python2.4/httplib.py", line 221, in readheaders
    line = self.fp.readline()
    File "/usr/lib64/python2.4/socket.py", line 325, in readline
    data = recv(1)
    File "/usr/lib/python2.4/site-packages/DenyHosts/deny_hosts.py", line 114, in killDaemon
    sys.exit(0)
    SystemExit: 0

     
  • Robert Hardy

    Robert Hardy - 2008-06-03

    Logged In: YES
    user_id=527588
    Originator: NO

    It sounds like your bug is different than mine.

     
  • BlueH2O

    BlueH2O - 2008-10-23

    Rob I think you're seeing the same thing I am seeing. Today I noticed some attacks coming through on my new machine. Denyhosts hasn't logged anything since it received new hosts four days ago. The PID shows it's still running, but nothing logged for four days.

     
  • BlueH2O

    BlueH2O - 2008-10-23

    I ran denyhosts from the command line just now with --sync and got this interesting response:

    # denyhosts.py -c /etc/denyhosts.conf --sync
    Error synchronizing data
    name 'info' is not defined

    A clue?

     
  • BlueH2O

    BlueH2O - 2008-11-12

    I've captured packets from the server/client conversation when running this command, and everything looks fine in the data, nice clean XML; This leads me to wonder if this is not, in fact, a client-side error. Red Hat is now referring everything to upstream and since no one seems to want to do anything with this ticket, and the source for the server is not publicly available, I'm not sure what recourse there is.

     
  • BlueH2O

    BlueH2O - 2008-11-12
    • assigned_to: nobody --> phil_schwartz
     

Log in to post a comment.