Author vinay.sajip
Recipients Julien.Palard, joshpurvis, vinay.sajip
Date 2013-05-16.17:14:57
SpamBayes Score -1.0
Marked as misclassified Yes
Message-id <1368724497.64.0.5140872838.issue17981@psf.upfronthosting.co.za>
In-reply-to
Content
We'll try this with a simple script which doesn't use logging at all:

import os
import socket

MSG1 = '<14>Hi, \x00'
MSG2 = '<14>there!\x00'

sock = socket.socket(socket.AF_UNIX, socket.SOCK_DGRAM)
sock.connect('/dev/log')
sock.send(MSG1)
os.close(sock.fileno()) # what daemonizing does
try:
    sock.send(MSG2)
except socket.error as e:
    print(e)
    print('Trying to reconnect:')
    sock = socket.socket(socket.AF_UNIX, socket.SOCK_DGRAM)
    try:
        sock.connect('/dev/log')
    except socket.error as e:
        print('Oh look, reconnecting failed: %s' % e)

When we run this, we get:

[Errno 9] Bad file descriptor
Trying to reconnect:
Oh look, reconnecting failed: [Errno 9] Bad file descriptor

And the strace output looks like this:

socket(PF_FILE, SOCK_DGRAM, 0)          = 3
connect(3, {sa_family=AF_FILE, path="/dev/log"}, 10) = 0
sendto(3, "<14>Hi, \0", 9, 0, NULL, 0)  = 9

===================================================
The next close() is the os.close(sock.fileno())
===================================================
close(3)                                = 0
sendto(3, "<14>there!\0", 11, 0, NULL, 0) = -1 EBADF (Bad file descriptor)
fstat(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 0), ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fc4a90e5000
write(1, "[Errno 9] Bad file descriptor\n", 30) = 30
write(1, "Trying to reconnect:\n", 21)  = 21
socket(PF_FILE, SOCK_DGRAM, 0)          = 3
===================================================
Created the socket via a call to socket.socket().
===================================================
close(3)                                = 0
===================================================
No idea where this close() comes from, but it's
the same as in the logging case.
===================================================
connect(3, {sa_family=AF_FILE, path="/dev/log"}, 10) = -1 EBADF (Bad file descriptor)
===================================================
connect() fails, just as in the logging case.
===================================================
write(1, "Oh look, reconnecting failed: [E"..., 60) = 60

So, while it seems to be a bug, it's not a logging bug. It seems to be
connected to the fact that os.close() closes the socket fd out from under the socket object, which somehow then causes a close() to be called...
History
Date User Action Args
2013-05-16 17:14:57vinay.sajipsetrecipients: + vinay.sajip, Julien.Palard, joshpurvis
2013-05-16 17:14:57vinay.sajipsetmessageid: <1368724497.64.0.5140872838.issue17981@psf.upfronthosting.co.za>
2013-05-16 17:14:57vinay.sajiplinkissue17981 messages
2013-05-16 17:14:57vinay.sajipcreate