[Bluez-devel] sdpd in polling loop on disconnect

[Bluez-devel] sdpd in polling loop on disconnect

[Frank de Lange]

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
Bluez-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/bluez-devel

Re: [Bluez-devel] sdpd in polling loop on disconnect

[Marcel Holtmann]

Hi Frank,

> 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...

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
Bluez-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/bluez-devel

Re: [Bluez-devel] sdpd in polling loop on disconnect

[Frank de Lange]

[-- Attachment #1: Type: text/plain, Size: 3310 bytes --]

Marcel Holtmann wrote:
> 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/gtk-devel-list@gnome.org/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
-- 
    WWWWW      ________________________
   ## o o\    /     Frank de Lange     \
   }#   \|   /                          \
    \ `--| _/     <Hacker for Hire>      \
     `---'  \       +46-734352015        /
             \    frank@unternet.org    /
              `------------------------'
   [ "Omnis enim res, quae dando non deficit, dum habetur
      et non datur, nondum habetur, quomodo habenda est."  ]



[-- Attachment #2: bluez-utils.g_io_add_watch-g_io_hup.patch --]
[-- Type: text/x-patch, Size: 1160 bytes --]

diff -pruN bluez-utils-3.9/sdpd/server.c bluez-utils-3.9.patched/sdpd/server.c
--- bluez-utils-3.9/sdpd/server.c	2007-01-21 19:57:15.000000000 +0100
+++ bluez-utils-3.9.patched/sdpd/server.c	2007-02-19 20:32:35.000000000 +0100
@@ -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;

[-- Attachment #3: Type: text/plain, Size: 345 bytes --]

-------------------------------------------------------------------------
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

[-- Attachment #4: Type: text/plain, Size: 164 bytes --]

_______________________________________________
Bluez-devel mailing list
Bluez-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/bluez-devel

Re: [Bluez-devel] sdpd in polling loop on disconnect

[Marcel Holtmann]

Hi Frank,

> > 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/gtk-devel-list@gnome.org/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)

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
Bluez-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/bluez-devel

Re: [Bluez-devel] sdpd in polling loop on disconnect

[Frank de Lange]

Marcel Holtmann wrote:
>> 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

-- 
    WWWWW      ________________________
   ## o o\    /     Frank de Lange     \
   }#   \|   /                          \
    \ `--| _/     <Hacker for Hire>      \
     `---'  \       +46-734352015        /
             \    frank@unternet.org    /
              `------------------------'
   [ "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
Bluez-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/bluez-devel

Re: [Bluez-devel] sdpd in polling loop on disconnect

[Johan Hedberg]

Hi Frank,

On Mon, Feb 19, 2007, Frank de Lange wrote:
> Marcel Holtmann wrote:
> >> 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
Bluez-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/bluez-devel

Re: [Bluez-devel] sdpd in polling loop on disconnect

[Marcel Holtmann]

Hi Frank,

> >> 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
Bluez-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/bluez-devel

Re: [Bluez-devel] sdpd in polling loop on disconnect

[Frank de Lange]

Frank de Lange wrote:
> Marcel Holtmann wrote:
>>> 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
Bluez-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/bluez-devel