Author vinay.sajip
Recipients Julien.Palard, joshpurvis, vinay.sajip
Date 2013-05-16.16:56:22
SpamBayes Score -1.0
Marked as misclassified Yes
Message-id <1368723382.33.0.362296905233.issue17981@psf.upfronthosting.co.za>
In-reply-to
Content
I see what you're saying now, but there's no explicit close in logging, so it's coming from somewhere lower down. Let's examine what happens when we try to emit the record:

-> def emit(self, record):
(Pdb) 
> /usr/lib/python2.7/logging/handlers.py(791)emit()
-> msg = self.format(record) + '\000'
(Pdb) n
> /usr/lib/python2.7/logging/handlers.py(796)emit()
-> prio = '<%d>' % self.encodePriority(self.facility,
(Pdb) n
> /usr/lib/python2.7/logging/handlers.py(797)emit()
-> self.mapPriority(record.levelname))
(Pdb) n
> /usr/lib/python2.7/logging/handlers.py(799)emit()
-> if type(msg) is unicode:
(Pdb) n
> /usr/lib/python2.7/logging/handlers.py(803)emit()
-> msg = prio + msg
(Pdb) n
> /usr/lib/python2.7/logging/handlers.py(804)emit()
-> try:
(Pdb) p msg
'<14>world!\x00'
(Pdb) n
> /usr/lib/python2.7/logging/handlers.py(805)emit()
-> if self.unixsocket:
(Pdb) n
> /usr/lib/python2.7/logging/handlers.py(806)emit()
-> try:
(Pdb) n
> /usr/lib/python2.7/logging/handlers.py(807)emit()

==============================================================
Here is where we try to send the message
==============================================================
-> self.socket.send(msg)
(Pdb) n
error: (9, 'Bad file descriptor')
> /usr/lib/python2.7/logging/handlers.py(807)emit()
-> self.socket.send(msg)
(Pdb) s
> /usr/lib/python2.7/logging/handlers.py(808)emit()
==============================================================
It failed, as expected, so we go to the exception handler.
==============================================================
-> except socket.error:
(Pdb) 
> /usr/lib/python2.7/logging/handlers.py(809)emit()
==============================================================
We are going to try and connect again.
==============================================================
-> self._connect_unixsocket(self.address)
(Pdb) s
--Call--
> /usr/lib/python2.7/logging/handlers.py(737)_connect_unixsocket()
-> def _connect_unixsocket(self, address):
(Pdb) 
> /usr/lib/python2.7/logging/handlers.py(738)_connect_unixsocket()
-> self.socket = socket.socket(socket.AF_UNIX, socket.SOCK_DGRAM)
==============================================================
Created the socket at line 738. Line 739 is a comment.
==============================================================
(Pdb) n
> /usr/lib/python2.7/logging/handlers.py(740)_connect_unixsocket()
-> try:
(Pdb) n
> /usr/lib/python2.7/logging/handlers.py(741)_connect_unixsocket()
-> self.socket.connect(address)
(Pdb) n
error: (9, 'Bad file descriptor')
==============================================================
Line 740 is a try: statement.
At line 741, called connect, got an EBADF, and there's no
intervening call to close().
==============================================================
> /usr/lib/python2.7/logging/handlers.py(741)_connect_unixsocket()
-> self.socket.connect(address)
(Pdb) n
> /usr/lib/python2.7/logging/handlers.py(742)_connect_unixsocket()
-> except socket.error:
(Pdb) n
> /usr/lib/python2.7/logging/handlers.py(743)_connect_unixsocket()
-> self.socket.close()
==============================================================
This close is just trying to tidy up in the exception handler.
==============================================================
(Pdb) n
> /usr/lib/python2.7/logging/handlers.py(744)_connect_unixsocket()
-> self.socket = socket.socket(socket.AF_UNIX, socket.SOCK_STREAM)
==============================================================
We'll try to open using TCP, which will fail.
==============================================================

To summarise:

line 738 is a call to socket.socket(AF_UNIX, SOCK_DGRAM)
line 739 is a comment "# syslog may require either ..."
line 740 is a try:
line 741 is a call to socket.connect(address)

There is no close() called by logging between socket.socket() and socket.connect(), so the close seems to be coming from inside one of those two calls to the socket module.
History
Date User Action Args
2013-05-16 16:56:22vinay.sajipsetrecipients: + vinay.sajip, Julien.Palard, joshpurvis
2013-05-16 16:56:22vinay.sajipsetmessageid: <1368723382.33.0.362296905233.issue17981@psf.upfronthosting.co.za>
2013-05-16 16:56:22vinay.sajiplinkissue17981 messages
2013-05-16 16:56:22vinay.sajipcreate