Unix Programming - read on socket shows EOF... but only when app is running in background

Author

read on socket shows EOF... but only when app is running in background

Ruud Schramp

2004-08-19, 3:57 am

Hello All,

Does anybody know other reasons a TCP Socket will read eof besides being
closed localy or receiving a FIN packet?

My multi threaded server application doesn't work when run in the
background. The application is intended to run as a daemon so I want to
create a commandline option that puts it in the background. It does work
when run in the foreground, even when started with a "&" option, but not
when an internal fork is used.

I did this (in lots of other programs as well) by putting a fork() function
almost at startup in which the parent exits and the child continues running.

This forking itself works, so the application runs in the background, but
now when I connect to it with TCP (the app has a server socket) the client
socket is immediately "closed" again (saying it will unblock for read,
reading the EOF (read returns 0)). The client connecting has not terminated
the TCP connection, also tcpdump doesn't show a FIN packet being sent to the
server. After verification with strace I see that no signals generated
within the timeframe of these events. Also no unexpeced closes are created
by the server application.

comparison of the strace logging of the application run in the foreground
with the strace logging when forked show no difference upto the reception of
the EOF.

Unfortunately the application is too big to show in the mailing list. I am
afraid that I will not be able to reproduce the problem on a micro scale
because, well I can't isolate the event. To my best knowledge it should
work....

Anyone seen this type of events before?

regards,

Ruud Schramp

Ruud Schramp

2004-08-19, 9:15 pm

What effect would you expect from setsid?

What tests would you suggest on the socket descriptor? It is just an
integer...

Also what is worying me is that strace doesn't show any syscalls on socket
that would close it...

below an strace of the faulty app:
Functionality explanation:
a single select is monitoring a TCP server socket (FD=3) and is handeling a
list of timers.
at 16:16:42.705216 the server socket becomes unblocked and a new TCP session
is accepted.
The new TCP session is set ti NONBLOCK (the O_READONLY is not in the code).
TCP_NODELAY is turned on.
Some logging to syslog to monitor the thing.. (2 times)
At 16:16:42.708948 the read returns EOF (No FIN has been received!). After
that the local stuff is cleaned up hence the shutdown and close.

Best regards,

Ruud Schramp

16:16:42.704856 select(4, [3], [], [], {0, 0}) = 0 (Timeout)
16:16:42.705006 rt_sigprocmask(SIG_SETMASK, [RTMIN], NULL, 8) = 0
16:16:42.705095 gettimeofday({1092838602, 705118}, NULL) = 0
16:16:42.705152 rt_sigprocmask(SIG_SETMASK, NULL, [RTMIN], 8) = 0
16:16:42.705216 select(4, [3], [], [], {0, 8000}) = 1 (in [3], left {0,
9765})
16:16:42.706166 rt_sigprocmask(SIG_SETMASK, [RTMIN], NULL, 8) = 0
16:16:42.706293 accept(3, 0, NULL) = 8
16:16:42.706434 brk(0x832b000) = 0x832b000
16:16:42.706508 brk(0x832c000) = 0x832c000
16:16:42.706588 fcntl64(8, F_SETFL, O_RDONLY|O_NONBLOCK) = 0
16:16:42.706654 setsockopt(8, SOL_TCP, TCP_NODELAY, [1], 4) = 0
16:16:42.706714 brk(0x832d000) = 0x832d000
16:16:42.706818 brk(0x832e000) = 0x832e000
16:16:42.706902 brk(0x8330000) = 0x8330000
16:16:42.706984 time([1092838602]) = 1092838602
16:16:42.707090 rt_sigaction(SIGPIPE, {0x420d6aa0, [], SA_RESTORER,
0x42028c48}, {0x
825693e, [PIPE], SA_RESTORER|SA_RESTART, 0x42028c48}, 8) = 0
16:16:42.707186 socket(PF_UNIX, SOCK_DGRAM, 0) = 9
16:16:42.707254 fcntl64(9, F_SETFD, FD_CLOEXEC) = 0
16:16:42.707311 connect(9, {sin_family=AF_UNIX, path="/dev/log"}, 16) = 0
16:16:42.707393 send(9, "<14>Aug 18 16:16:42 "..., 90, 0) = 90
16:16:42.707614 rt_sigaction(SIGPIPE, {0x825693e, [PIPE],
SA_RESTORER|SA_RESTART, 0x
42028c48}, NULL, 8) = 0
16:16:42.707860 gettimeofday({1092838602, 707887}, NULL) = 0
16:16:42.708019 time([1092838602]) = 1092838602
16:16:42.708109 rt_sigaction(SIGPIPE, {0x420d6aa0, [], SA_RESTORER,
0x42028c48}, {0x
825693e, [PIPE], SA_RESTORER|SA_RESTART, 0x42028c48}, 8) = 0
16:16:42.708200 send(9, "<14>Aug 18 16:16:42 "..., 76, 0) = 76
16:16:42.708332 rt_sigaction(SIGPIPE, {0x825693e, [PIPE],
SA_RESTORER|SA_RESTART, 0x
42028c48}, NULL, 8) = 0
16:16:42.708429 gettimeofday({1092838602, 708561}, NULL) = 0
16:16:42.708599 rt_sigprocmask(SIG_SETMASK, NULL, [RTMIN], 8) = 0
16:16:42.708667 select(9, [3 8], [], [], {0, 4000}) = 1 (in [8], left {0,
5859})
16:16:42.708867 rt_sigprocmask(SIG_SETMASK, [RTMIN], NULL, 8) = 0
16:16:42.708948 read(8, "", 4) = 0
16:16:42.709029 shutdown(8, 2 /* send and receive */) = 0
16:16:42.709125 close(8) = 0
16:16:42.709201 time([1092838602]) = 1092838602
16:16:42.709281 rt_sigaction(SIGPIPE, {0x420d6aa0, [], SA_RESTORER,
0x42028c48}, {0x
825693e, [PIPE], SA_RESTORER|SA_RESTART, 0x42028c48}, 8) = 0
16:16:42.709373 send(9, "<14>Aug 18 16:16:42 "..., 78, 0) = 78
16:16:42.709442 rt_sigaction(SIGPIPE, {0x825693e, [PIPE],
SA_RESTORER|SA_RESTART, 0x
42028c48}, NULL, 8) = 0
16:16:42.709516 gettimeofday({1092838602, 709539}, NULL) = 0
16:16:42.709601 gettimeofday({1092838602, 709624}, NULL) = 0
16:16:42.709659 rt_sigprocmask(SIG_SETMASK, NULL, [RTMIN], 8) = 0
16:16:42.709724 select(4, [3], [], [], {0, 3000}) = 0 (Timeout)
16:16:42.712293 rt_sigprocmask(SIG_SETMASK, [RTMIN], NULL, 8) = 0
16:16:42.712395 gettimeofday({1092838602, 712417}, NULL) = 0
16:16:42.712456 rt_sigprocmask(SIG_SETMASK, NULL, [RTMIN], 8) = 0
16:16:42.712519 select(4, [3], [], [], {0, 1000}) = 0 (Timeout)
16:16:42.714357 rt_sigprocmask(SIG_SETMASK, [RTMIN], NULL, 8) = 0
16:16:42.714432 gettimeofday({1092838602, 714453}, NULL) = 0
16:16:42.714560 rt_sigprocmask(SIG_SETMASK, NULL, [RTMIN], 8) = 0
16:16:42.714624 select(4, [3], [], [], {0, 0}) = 0 (Timeout)

Sponsored Links