Processed: Re: Bug#568385: gracie: daemonizes too late, ends up with socket closed
Processing commands for cont...@bugs.debian.org: > package gracie Limiting to bugs with field 'package' containing at least one of 'gracie' Limit currently set to 'package':'gracie' > tags 568385 + pending Bug #568385 [gracie] gracie: network socket file descriptor must remain open when becoming daemon Added tag(s) pending. > thanks Stopping processing here. Please contact me if you need assistance. Debian bug tracking system administrator (administrator, Debian Bugs database) -- To UNSUBSCRIBE, email to debian-bugs-rc-requ...@lists.debian.org with a subject of "unsubscribe". Trouble? Contact listmas...@lists.debian.org
Bug#568385: gracie: daemonizes too late, ends up with socket closed
package gracie tags 568385 + pending thanks On 12-Feb-2010, Ben Finney wrote: > I am testing a fix for this in the upstream code. I haven't seen a response from you on this matter, so I will assume you are busy. Thank you very much for the work and communication you did so far on this bug report. There is a new upstream version that hopefully fixes this bug, and I will seek a different sponsor to get it into Debian quickly. -- \ “Oh, I realize it's a penny here and a penny there, but look at | `\ me: I've worked myself up from nothing to a state of extreme | _o__) poverty.” —Groucho Marx | Ben Finney signature.asc Description: Digital signature
Bug#568385: gracie: daemonizes too late, ends up with socket closed
I am testing a fix for this in the upstream code. The daemon context
now receives the HTTP server socket file descriptor, and is told not
to close that file descriptor. (This uses the ‘files_exclude’ option of
the DaemonContext instance.)
The command I'm using to test this in the upstream codebase is:
PYTHONPATH=. strace -f -s 1024 bin/gracied --pidfile /tmp/gracied.pid
--data-dir /tmp/gracie --host 127.0.0.1 --port 8123 2> /tmp/gracied.$(date
+'%Y%m%d').strace
The result of the change is that the tail end of the trace now looks
like:
=
[…]
close(6)= -1 EBADF (Bad file descriptor)
close(5)= -1 EBADF (Bad file descriptor)
close(4)= -1 EBADF (Bad file descriptor)
close(1)= 0
close(0)= 0
open("/dev/null", O_RDWR|O_LARGEFILE) = 0
dup2(0, 0) = 0
open("/dev/null", O_RDWR|O_LARGEFILE) = 1
dup2(1, 1) = 1
open("/dev/null", O_RDWR|O_LARGEFILE) = 4
dup2(4, 2) = 2
open("/tmp/fuschia.MainThread-17293", O_WRONLY|O_CREAT|O_TRUNC|O_LARGEFILE,
0666) = 5
fstat64(0x5, 0xffa07b88)= 0
close(5)= 0
link("/tmp/fuschia.MainThread-17293", "/tmp/gracied.pid.lock") = 0
open("/tmp/gracied.pid", O_WRONLY|O_CREAT|O_EXCL|O_LARGEFILE, 0644) = 5
fcntl64(5, F_GETFL) = 0x10001 (flags O_WRONLY|O_LARGEFILE)
fstat64(0x5, 0xffa07b88)= 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
0xf7ce5000
_llseek(5, 0, [0], SEEK_CUR)= 0
fstat64(0x5, 0xffa07c68)= 0
write(5, "17296\n", 6) = 6
close(5)= 0
munmap(0xf7ce5000, 4096)= 0
accept(3, 0xffa07c84, [16]) = ? ERESTARTSYS (To be restarted)
=
The server is now accepting connections on the socket.
I don't understand the “ERESTARTSYS (To be restarted)” result from the
‘accept’ call. The ‘accept(2)’ manpage says:
=
ERRORS
[…]
In addition, network errors for the new socket and as
defined for the protocol may be returned. Various Linux
kernels can return other errors such as ENOSR,
ESOCKTNOSUPPORT, EPROTONOSUPPORT, ETIMEDOUT. The value
ERESTARTSYS may be seen during a trace.
=
There's no explanation of what the ‘ERESTARTSYS’ error condition
means, though. Do you have any idea what is causing this?
--
\“Somebody told me how frightening it was how much topsoil we |
`\ are losing each year, but I told that story around the campfire |
_o__) and nobody got scared.” —Jack Handey |
Ben Finney
signature.asc
Description: Digital signature
Processed: Re: Bug#568385: gracie: daemonizes too late, ends up with socket closed
Processing commands for cont...@bugs.debian.org: > package gracie Limiting to bugs with field 'package' containing at least one of 'gracie' Limit currently set to 'package':'gracie' > tags 568385 + confirmed upstream Bug #568385 [gracie] gracie: daemonizes too late, ends up with socket closed Added tag(s) upstream and confirmed. > retitle 568385 gracie: network socket file descriptor must remain open when > becoming daemon Bug #568385 [gracie] gracie: daemonizes too late, ends up with socket closed Changed Bug title to 'gracie: network socket file descriptor must remain open when becoming daemon' from 'gracie: daemonizes too late, ends up with socket closed' > thanks Stopping processing here. Please contact me if you need assistance. Debian bug tracking system administrator (administrator, Debian Bugs database) -- To UNSUBSCRIBE, email to debian-bugs-rc-requ...@lists.debian.org with a subject of "unsubscribe". Trouble? Contact listmas...@lists.debian.org
Bug#568385: gracie: daemonizes too late, ends up with socket closed
On Wed, 2010-02-10 at 23:27 +1100, Ben Finney wrote: > Thank you for taking the trouble to track down this problem to this > level of detail, and for reporting it here. No problem at all, I had to restore my openid service anyway =) > Can you please provide a command-line that I can run to reproduce > similar output for a run of Gracie? This was what I used to investigate: strace -f -s 1024 /usr/bin/python /usr/bin/gracied --pidfile /var/run/gracied.pid --data-dir /var/lib/gracie --host 127.0.0.1 --port 8123 --root-url http://openid.kov.eti.br/ 2>| tee /tmp/log I fixed it locally by changing the code, and temporarily moving the daemonization to before opening the port (that is fine in my case given the high port number), but a real fix would be to make the daemonization process less trigger happy (making it not close the listening socket). See you, -- Gustavo Noronha Silva Debian signature.asc Description: This is a digitally signed message part
Bug#568385: gracie: daemonizes too late, ends up with socket closed
On 04-Feb-2010, Gustavo Noronha Silva wrote: > Gracie does not work for me after upgrading (it doesn't open the > port). After investigating a while, it looks like the problem is it > daemonizes after having the port bound, and listened to, but the > daemonization process closes the socket: Thank you for taking the trouble to track down this problem to this level of detail, and for reporting it here. Can you please provide a command-line that I can run to reproduce similar output for a run of Gracie? -- \ “I'm not a bad guy! I work hard, and I love my kids. So why | `\ should I spend half my Sunday hearing about how I'm going to | _o__)Hell?” —Homer Simpson | Ben Finney signature.asc Description: Digital signature
Bug#568385: gracie: daemonizes too late, ends up with socket closed
Package: gracie
Version: 0.2.10-3
Severity: grave
Justification: renders package unusable
Gracie does not work for me after upgrading (it doesn't open the
port). After investigating a while, it looks like the problem is it
daemonizes after having the port bound, and listened to, but the
daemonization process closes the socket:
socket(PF_INET, SOCK_STREAM, IPPROTO_IP) = 3
setsockopt(3, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0
bind(3, {sa_family=AF_INET, sin_port=htons(8123), sin_addr=inet_addr("127.0.0.1"
)}, 16) = 0
getsockname(3, {sa_family=AF_INET, sin_port=htons(8123), sin_addr=inet_addr("127
.0.0.1")}, [16]) = 0
getsockname(3, {sa_family=AF_INET, sin_port=htons(8123), sin_addr=inet_addr("127
.0.0.1")}, [16]) = 0
[...]
umask(0)= 022
chdir("/") = 0
setgid32(0) = 0
setuid32(0) = 0
clone(Process 22607 attached (waiting for parent)
Process 22607 resumed (parent 22606 ready)
child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD,
child_tidptr=0xb7ed8728) = 22607
[pid 22607] setsid()= 22607
[...]
[pid 22608] close(9)= -1 EBADF (Bad file descriptor)
[pid 22608] close(8)= -1 EBADF (Bad file descriptor)
[pid 22608] close(7)= -1 EBADF (Bad file descriptor)
[pid 22608] close(6)= -1 EBADF (Bad file descriptor)
[pid 22608] close(5)= -1 EBADF (Bad file descriptor)
[pid 22608] close(4)= -1 EBADF (Bad file descriptor)
[pid 22608] close(3)= 0
[pid 22608] close(1)= 0
[pid 22608] close(0)= 0
[pid 22608] open("/dev/null", O_RDWR|O_LARGEFILE) = 0
[pid 22608] dup2(0, 0) = 0
[pid 22608] open("/dev/null", O_RDWR|O_LARGEFILE) = 1
[pid 22608] dup2(1, 1) = 1
[pid 22608] open("/dev/null", O_RDWR|O_LARGEFILE) = 3
[...]
[pid 22608] accept(3, 0xbfe92244, [16]) = -1 ENOTSOCK (Socket operation on
non-socket)
[pid 22608] accept(3, 0xbfe92244, [16]) = -1 ENOTSOCK (Socket operation on
non-socket)
...
And it stays there forever, eating CPU cycles, trying to accept on
/dev/null =D.
Thanks,
-- System Information:
Debian Release: squeeze/sid
APT prefers unstable
APT policy: (500, 'unstable'), (500, 'testing'), (1, 'experimental')
Architecture: amd64 (x86_64)
Kernel: Linux 2.6.30-2-amd64 (SMP w/2 CPU cores)
Locale: LANG=en_GB.UTF-8, LC_CTYPE=en_GB.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/bash
--
To UNSUBSCRIBE, email to debian-bugs-rc-requ...@lists.debian.org
with a subject of "unsubscribe". Trouble? Contact listmas...@lists.debian.org
