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.
Logged In: YES
user_id=1267347
Originator: YES
I have restarted denyhosts with debug and will report any new information I can gather.
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?
Logged In: YES
user_id=1267347
Originator: YES
Oops that was me, forgot to log in.
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.
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.
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.
denyhosts log
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
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.
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()
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
Logged In: YES
user_id=527588
Originator: NO
It sounds like your bug is different than mine.
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.
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?
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.
https://bugzilla.redhat.com/show_bug.cgi?id=458963