[Bluez-devel] sdpd in polling loop on disconnect

Frank de Lange

author

2007-02-16 00:31 UTC #0 lore raw

Is there anyone else here who has seen sdpd run away in a tight poll() loop when a connected device drops the connection? I can more or less reliably get sdpd go mad poll()ing and hogging the CPU by walking out of range, turning off Bluetooth on the (ngage) phone, sending crap to the serial port service on the phone, etc.

An almost surefire way to get this behaviour to occur goes as follows:

(assumption: paired phone, serial port bound to /dev/rfcomm3)

cat /dev/rfcomm3 (phone wakes up and wants OK)
echo blah > /dev/rfcomm3 (ditto)
usually sdpd will now start eating the CPU. Attaching gdb does not show much more than that it is looping in g_main_loop_run:

Program received signal SIGUSR2, User defined signal 2. 0x00e1a402 in __kernel_vsyscall ()
(gdb) bt

#0  0x00e1a402 in __kernel_vsyscall ()
#1  0x008c2cfb in poll () from /lib/libc.so.6
#2  0x0046b453 in ?? () from /lib/libglib-2.0.so.0
#3  0x0046b7c9 in g_main_loop_run () from /lib/libglib-2.0.so.0
#4  0x80001800 in main (argc=1, argv=Cannot access memory at address 0x7

) at main.c:147

It loops in g_main_context_check(), repeatedly calling g_io_channel_get_buffer_condition() as if it still believes there is some data left to be read. I will look further into this but I'd like to hear whether I'm the only one with these problems...

I'm using fedora core development by the way...

Cheers//Frank

-------------------------------------------------------------------------
Take Surveys. Earn Cash. Influence the Future of IT
Join SourceForge.net's Techsay panel and you'll get the chance to share your opinions on IT & business topics through brief surveys-and earn cash
http://www.techsay.com/default.php?page=join.php&p=sourceforge&CID=DEVDEV
_______________________________________________
Bluez-devel mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/bluez-devel

Marcel Holtmann

maintainer

2007-02-16 02:00 UTC #1 lore raw

Hi Frank,

Quoted 23 lines

Is there anyone else here who has seen sdpd run away in a tight poll() loop when a connected device drops the connection? I can more or less reliably get sdpd go mad poll()ing and hogging the CPU by walking out of range, turning off Bluetooth on the (ngage) phone, sending crap to the serial port service on the phone, etc.
An almost surefire way to get this behaviour to occur goes as follows:
(assumption: paired phone, serial port bound to /dev/rfcomm3)
cat /dev/rfcomm3 (phone wakes up and wants OK)
echo blah > /dev/rfcomm3 (ditto)
usually sdpd will now start eating the CPU. Attaching gdb does not show much more than that it is looping in g_main_loop_run:
Program received signal SIGUSR2, User defined signal 2. 0x00e1a402 in __kernel_vsyscall ()
(gdb) bt
#0  0x00e1a402 in __kernel_vsyscall ()
#1  0x008c2cfb in poll () from /lib/libc.so.6
#2  0x0046b453 in ?? () from /lib/libglib-2.0.so.0
#3  0x0046b7c9 in g_main_loop_run () from /lib/libglib-2.0.so.0
#4  0x80001800 in main (argc=1, argv=Cannot access memory at address 0x7

Quoted 6 lines

) at main.c:147
It loops in g_main_context_check(), repeatedly calling g_io_channel_get_buffer_condition() as if it still believes there is some data left to be read. I will look further into this but I'd like to hear whether I'm the only one with these problems...

if this is bluez-utils-3.9 you might wanna try to compile it with --enable-glib to use the system Glib. It might be possible that our eglib has some kind of bad. In case of using the Glib system library, I think you discovered a real bug in sdpd. Do you see the same issue if you don't start sdpd and use hcid -s instead.

Regards

Marcel

-------------------------------------------------------------------------
Take Surveys. Earn Cash. Influence the Future of IT
Join SourceForge.net's Techsay panel and you'll get the chance to share your opinions on IT & business topics through brief surveys-and earn cash
http://www.techsay.com/default.php?page=join.php&p=sourceforge&CID=DEVDEV
_______________________________________________
Bluez-devel mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/bluez-devel

Frank de Lange

2007-02-19 20:00 UTC #2 lore raw

Quoted 5 lines · Marcel Holtmann

if this is bluez-utils-3.9 you might wanna try to compile it with --enable-glib to use the system Glib. It might be possible that our eglib has some kind of bad. In case of using the Glib system library, I think you discovered a real bug in sdpd. Do you see the same issue if you don't start sdpd and use hcid -s instead.

Fedora's bluez-utils is already compiled with --enable-glib:

%configure --with-bluez-libs=%{_libdir} --enable-pie --enable-debug \
       --enable-all --disable-bcm203x --enable-alsa --enable-bccmd \
       --enable-bccmd --enable-avctrl --enable-glib

Trying with hcid -s instead of a separate sdpd leads to the same
behaviour: hcid loops on poll.

Looking at the code it strikes me that there are many calls to
g_io_add_watch which only trigger on G_IO_IN or G_IO_OUT. These channels
are configured with g_io_channel_set_close_on_unref(<channel>, TRUE) but
that does not seem to be enough to set POLLHUP (or POLLRDHUP) on the
listening socket. What seems to happen is that the socket is kept open after the remote connection dropped and polled continuously, most likely returning POLLRDHUP. The semantics of glib are a bit unclear in this respect but I have found the following quote from Owen Taylor:

(http://www.mail-archive.com/[email protected]/msg01577.html)

"In general, on systems new enough to have poll(), a socket will indicate HUP rather than IN when it has been closed on the other end. poll() and select() are about *state* rather than *events* so once a socket returns HUP, it will continue to return HUP.

On the other hand, if a system is emulating poll() with select() - which was the standard state 5 years ago and I think is still the case on OS X, then you'll just get IN, and have to notice the zero length read.

In general, if you are writing code that you want to be portable, what you should do is add a watch on G_IO_IN | G_IO_HUP, and in that callback just always do a read. If the read is zero length, then the socket has been closed, so cleanup, close the socket, and return FALSE to remove the watch."

I have patched sdpd to add G_IO_HUP|G_IO_ERR to the watched conditions on the g_io_channel. This cures the polling loop behaviour. There are several other places in the code where channels are being watched for G_IO_IN only. Someone with good knowledge of the context in which these g_io_channels are being used should check whether there is a need for adding G_IO_HUP to the watched conditions. The callbacks should also be changed to watch for this condition as failing to do the latter seems to lead to kernel panics. This is a bug in its own right - a userspace program should not be able to bring down the kernel... I have not found the culprit for those panics yet.

Attached: patch for sdpd (adds G_IO_HUP|G_IO_ERR to watched conditions on g_io_channels)

Cheers//Frank

Signature · 9 lines

   WWWWW      ________________________
  ## o o\    /     Frank de Lange     \
  }#   \|   /                          \
   \ `--| _/     <Hacker for Hire>      \
    `---'  \       +46-734352015        /
            \    [email protected]    /
             `------------------------'
  [ "Omnis enim res, quae dando non deficit, dum habetur
     et non datur, nondum habetur, quomodo habenda est."  ]

sdpd/server.c +3 -3

diff -pruN bluez-utils-3.9/sdpd/server.c bluez-utils-3.9.patched/sdpd/server.c
@@ -207,7 +207,7 @@ static gboolean io_accept_event(GIOChann
 	io = g_io_channel_unix_new(nsk);
 	g_io_channel_set_close_on_unref(io, TRUE);
 
-	g_io_add_watch(io, G_IO_IN, io_session_event, data);
+	g_io_add_watch(io, G_IO_IN|G_IO_HUP|G_IO_ERR, io_session_event, data);
 
 	g_io_channel_unref(io);

@@ -230,13 +230,13 @@ int start_sdp_server(uint16_t mtu, uint3
 	l2cap_io = g_io_channel_unix_new(l2cap_sock);
 	g_io_channel_set_close_on_unref(l2cap_io, TRUE);
 
-	g_io_add_watch(l2cap_io, G_IO_IN, io_accept_event, &l2cap_sock);
+	g_io_add_watch(l2cap_io, G_IO_IN|G_IO_HUP|G_IO_ERR, io_accept_event, &l2cap_sock);
 
 	if (compat && unix_sock > fileno(stderr)) {
 		unix_io = g_io_channel_unix_new(unix_sock);
 		g_io_channel_set_close_on_unref(unix_io, TRUE);
 
-		g_io_add_watch(unix_io, G_IO_IN, io_accept_event, &unix_sock);
+		g_io_add_watch(unix_io, G_IO_IN|G_IO_HUP|G_IO_ERR, io_accept_event, &unix_sock);
 	}
 
 	return 0;

-------------------------------------------------------------------------
Take Surveys. Earn Cash. Influence the Future of IT
Join SourceForge.net's Techsay panel and you'll get the chance to share your opinions on IT & business topics through brief surveys-and earn cash
http://www.techsay.com/default.php?page=join.php&p=sourceforge&CID=DEVDEV

_______________________________________________
Bluez-devel mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/bluez-devel

Marcel Holtmann

maintainer

2007-02-19 20:33 UTC #3 lore raw

Hi Frank,

Quoted 53 lines

Quoted 5 lines
if this is bluez-utils-3.9 you might wanna try to compile it with --enable-glib to use the system Glib. It might be possible that our eglib has some kind of bad. In case of using the Glib system library, I think you discovered a real bug in sdpd. Do you see the same issue if you don't start sdpd and use hcid -s instead.
Fedora's bluez-utils is already compiled with --enable-glib:
%configure --with-bluez-libs=%{_libdir} --enable-pie --enable-debug \
        --enable-all --disable-bcm203x --enable-alsa --enable-bccmd \
        --enable-bccmd --enable-avctrl --enable-glib
Trying with hcid -s instead of a separate sdpd leads to the same
behaviour: hcid loops on poll.
Looking at the code it strikes me that there are many calls to g_io_add_watch which only trigger on G_IO_IN or G_IO_OUT. These channels are configured with g_io_channel_set_close_on_unref(<channel>, TRUE) but that does not seem to be enough to set POLLHUP (or POLLRDHUP) on the listening socket. What seems to happen is that the socket is kept open after the remote connection dropped and polled continuously, most likely returning POLLRDHUP. The semantics of glib are a bit unclear in this respect but I have found the following quote from Owen Taylor:
(http://www.mail-archive.com/[email protected]/msg01577.html)
"In general, on systems new enough to have poll(), a socket will indicate HUP rather than IN when it has been closed on the other end. poll() and select() are about *state* rather than *events* so once a socket returns HUP, it will continue to return HUP.
On the other hand, if a system is emulating poll() with select() - which was the standard state 5 years ago and I think is still the case on OS X, then you'll just get IN, and have to notice the zero length read.
In general, if you are writing code that you want to be portable, what you should do is add a watch on G_IO_IN | G_IO_HUP, and in that callback just always do a read. If the read is zero length, then the socket has been closed, so cleanup, close the socket, and return FALSE to remove the watch."
I have patched sdpd to add G_IO_HUP|G_IO_ERR to the watched conditions on the g_io_channel. This cures the polling loop behaviour. There are several other places in the code where channels are being watched for G_IO_IN only. Someone with good knowledge of the context in which these g_io_channels are being used should check whether there is a need for adding G_IO_HUP to the watched conditions. The callbacks should also be changed to watch for this condition as failing to do the latter seems to lead to kernel panics. This is a bug in its own right - a userspace program should not be able to bring down the kernel... I have not found the culprit for those panics yet.

Quoted 2 lines

Attached: patch for sdpd (adds G_IO_HUP|G_IO_ERR to watched conditions on g_io_channels)

thanks for the patch, but that should be already fixed in the CVS. Johan found this during the UPF testing last week.

Regards

Marcel

-------------------------------------------------------------------------
Take Surveys. Earn Cash. Influence the Future of IT
Join SourceForge.net's Techsay panel and you'll get the chance to share your opinions on IT & business topics through brief surveys-and earn cash
http://www.techsay.com/default.php?page=join.php&p=sourceforge&CID=DEVDEV
_______________________________________________
Bluez-devel mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/bluez-devel

Frank de Lange

2007-02-19 21:19 UTC #4 lore raw

Quoted 5 lines · Marcel Holtmann

Quoted 2 lines
Attached: patch for sdpd (adds G_IO_HUP|G_IO_ERR to watched conditions on g_io_channels)
thanks for the patch, but that should be already fixed in the CVS. Johan found this during the UPF testing last week.

Even better. Did he also check the other watchers for similar problems? As said there are several of them which only look for G_IO_IN events.

Cheers//Frank

Signature · 19 lines

    WWWWW      ________________________
   ## o o\    /     Frank de Lange     \
   }#   \|   /                          \
    \ `--| _/     <Hacker for Hire>      \
     `---'  \       +46-734352015        /
             \    [email protected]    /
              `------------------------'
   [ "Omnis enim res, quae dando non deficit, dum habetur
      et non datur, nondum habetur, quomodo habenda est."  ]

-------------------------------------------------------------------------
Take Surveys. Earn Cash. Influence the Future of IT
Join SourceForge.net's Techsay panel and you'll get the chance to share your
opinions on IT & business topics through brief surveys-and earn cash
http://www.techsay.com/default.php?page=join.php&p=sourceforge&CID=DEVDEV
_______________________________________________
Bluez-devel mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/bluez-devel

Johan Hedberg

2007-02-19 21:28 UTC #5 lore raw

Hi Frank,

Quoted 9 lines · Frank de Lange

Quoted 5 lines · Marcel Holtmann
Quoted 2 lines
Attached: patch for sdpd (adds G_IO_HUP|G_IO_ERR to watched conditions on g_io_channels)
thanks for the patch, but that should be already fixed in the CVS. Johan found this during the UPF testing last week.
Even better. Did he also check the other watchers for similar problems? As said there are several of them which only look for G_IO_IN events.

I tried to check all places that used g_io_add_watch so hopefully there shouldn't be any issues left. Feel free to check the CVS though as it's not impossible that I've missed some place.

Johan

-------------------------------------------------------------------------
Take Surveys. Earn Cash. Influence the Future of IT
Join SourceForge.net's Techsay panel and you'll get the chance to share your opinions on IT & business topics through brief surveys-and earn cash
http://www.techsay.com/default.php?page=join.php&p=sourceforge&CID=DEVDEV
_______________________________________________
Bluez-devel mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/bluez-devel

Marcel Holtmann

maintainer

2007-02-19 21:31 UTC #6 lore raw

In reply to Frank de Lange

Hi Frank,

Quoted 8 lines

Quoted 5 lines
Quoted 2 lines
Attached: patch for sdpd (adds G_IO_HUP|G_IO_ERR to watched conditions on g_io_channels)
thanks for the patch, but that should be already fixed in the CVS. Johan found this during the UPF testing last week.
Even better. Did he also check the other watchers for similar problems? As said there are several of them which only look for G_IO_IN events.

feel free to double-check the CVS. However they should all be fixed now.

Regards

Marcel

-------------------------------------------------------------------------
Take Surveys. Earn Cash. Influence the Future of IT
Join SourceForge.net's Techsay panel and you'll get the chance to share your opinions on IT & business topics through brief surveys-and earn cash
http://www.techsay.com/default.php?page=join.php&p=sourceforge&CID=DEVDEV
_______________________________________________
Bluez-devel mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/bluez-devel

Frank de Lange

author

2007-02-19 21:36 UTC #7 lore raw

In reply to Frank de Lange

Quoted 11 lines · Frank de Lange

Quoted 4 lines · Marcel Holtmann
Quoted 2 lines
Attached: patch for sdpd (adds G_IO_HUP|G_IO_ERR to watched conditions on g_io_channels)
thanks for the patch, but that should be already fixed in the CVS. Johan found this during the UPF testing last week.
Even better. Did he also check the other watchers for similar problems? As said there are several of them which only look for G_IO_IN events.
Cheers//Frank

Replying to my own message here... I checked current CVS for the above and found a few remaining occurrences of listening watchers which don't care for HUP:

utils/daemon/echo.c:176
utils/hcid/main.c:782
utils/input/server.c:233
utils/test/hciemu.c:1331
utils/transfer/server.c:108

Are these accounted for as being 'safe'?

Cheers//Frank

-------------------------------------------------------------------------
Take Surveys. Earn Cash. Influence the Future of IT
Join SourceForge.net's Techsay panel and you'll get the chance to share your opinions on IT & business topics through brief surveys-and earn cash
http://www.techsay.com/default.php?page=join.php&p=sourceforge&CID=DEVDEV
_______________________________________________
Bluez-devel mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/bluez-devel