Bug 440284 - NM hangs trying to activate 3G connection
NM hangs trying to activate 3G connection
Status: CLOSED RAWHIDE
Product: Fedora
Classification: Fedora
Component: NetworkManager (Show other bugs)
rawhide
All Linux
low Severity low
: ---
: ---
Assigned To: Dan Williams
Fedora Extras Quality Assurance
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2008-04-02 12:20 EDT by Bastien Nocera
Modified: 2008-04-22 11:00 EDT (History)
2 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2008-04-22 11:00:36 EDT
Type: ---
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)
nm-3g-log.txt (2.53 KB, text/plain)
2008-04-10 13:57 EDT, Bastien Nocera
no flags Details

  None (edit)
Description Bastien Nocera 2008-04-02 12:20:50 EDT
NetworkManager-0.7.0-0.9.1.svn3521.fc9.i386

Seems to like eating my CPU:

Thread 2 (Thread 0xb809eb90 (LWP 10545)):
#0  0x00110416 in __kernel_vsyscall ()
#1  0x0050c11b in read () from /lib/libpthread.so.0
#2  0x00568e5d in child_watch_helper_thread (data=Could not find the frame base
for "child_watch_helper_thread".
) at /usr/include/bits/unistd.h:45
#3  0x0059212f in g_thread_create_proxy (data=<value optimized out>) at
gthread.c:635
#4  0x0050551f in start_thread (arg=<value optimized out>) at pthread_create.c:297
#5  0x0041ddbe in clone () from /lib/libc.so.6

Thread 1 (Thread 0xb809f710 (LWP 10159)):
#0  0x00110416 in __kernel_vsyscall ()
#1  0x0050c11b in read () from /lib/libpthread.so.0
#2  0x0059ea9a in g_io_unix_read (channel=<value optimized out>, buf=<value
optimized out>, count=<value optimized out>, bytes_read=<value optimized out>,
err=Could not find the frame base for "g_io_unix_read".
) at /usr/include/bits/unistd.h:45
#3  0x0055ce58 in g_io_channel_fill_buffer (channel=<value optimized out>,
err=<value optimized out>) at giochannel.c:1250
#4  0x0055e09f in IA__g_io_channel_read_chars (channel=<value optimized out>,
buf=<value optimized out>, count=<value optimized out>, bytes_read=<value
optimized out>, error=<value optimized out>)
    at giochannel.c:1798
#5  0x08071ca6 in wait_for_reply_got_data (source=0x8753660, condition=<value
optimized out>, data=0x874f4a0) at nm-serial-device.c:578
#6  0x0059e59d in g_io_unix_dispatch (source=<value optimized out>,
callback=<value optimized out>, user_data=Could not find the frame base for
"g_io_unix_dispatch".
) at giounix.c:162
#7  0x00567f48 in IA__g_main_context_dispatch (context=<value optimized out>) at
gmain.c:2009
#8  0x0056b4ab in g_main_context_iterate (context=<value optimized out>,
block=<value optimized out>, dispatch=<value optimized out>, self=Could not find
the frame base for "g_main_context_iterate".
) at gmain.c:2642
#9  0x0056b97a in IA__g_main_loop_run (loop=<value optimized out>) at gmain.c:2850
#10 0x0806887a in main (argc=141806216, argv=0xbfbb5c44) at NetworkManager.c:354
#0  0x00110416 in __kernel_vsyscall ()
Comment 1 Dan Williams 2008-04-10 12:26:16 EDT
Which 3G hardware/card?  Any chance you can reproduce and then in gdb break in
frame #5 here (wait_for_reply_got_data) and then do 'finish' and see how long it
takes to get back to wait_for_reply_got_data() ?  I'm wondering if it's hanging
inside the IO channel watch, or if it's the loop in wait_for_reply_got_data()
that's doing it.

ALso, can you include some log output from /var/log/messages showing a
connection attempt where it hangs?
Comment 2 Bastien Nocera 2008-04-10 12:44:18 EDT
Builtin HSDPA modem:
Bus 002 Device 009: ID 413c:8137 Dell Computer Corp. Wireless 5520 Voda L Mobile
Broadband (3G HSDPA) Minicard Status Port

It doesn't seem to ever exit from wait_for_reply_got_data() (I left it eat my
CPU for a couple of minutes already). This might be interesting:

(gdb) bt
#0  0x00110416 in __kernel_vsyscall ()
#1  0x0050c11b in read () from /lib/libpthread.so.0
#2  0x001d4aba in ?? () from /lib/libglib-2.0.so.0
#3  0x00192e68 in ?? () from /lib/libglib-2.0.so.0
#4  0x001940af in g_io_channel_read_chars () from /lib/libglib-2.0.so.0
#5  0x080723c6 in wait_for_reply_got_data (source=0x9529e20, condition=<value
optimized out>, data=0x9527ec8) at nm-serial-device.c:578
#6  0x001d45bd in ?? () from /lib/libglib-2.0.so.0
#7  0x0019df78 in g_main_context_dispatch () from /lib/libglib-2.0.so.0
#8  0x001a14db in ?? () from /lib/libglib-2.0.so.0
#9  0x001a19aa in g_main_loop_run () from /lib/libglib-2.0.so.0
#10 0x08068c5a in main (argc=156343376, argv=0xbf8b2674) at NetworkManager.c:362
(gdb) frame 4
#4  0x001940af in g_io_channel_read_chars () from /lib/libglib-2.0.so.0
(gdb) finish
Run till exit from #4  0x001940af in g_io_channel_read_chars () from
/lib/libglib-2.0.so.0
wait_for_reply_got_data (source=0x9529e20, condition=<value optimized out>,
data=0x9527ec8) at nm-serial-device.c:579
579			if (status == G_IO_STATUS_ERROR) {
(gdb) p status
$1 = G_IO_STATUS_AGAIN

And in /var/log/messages, the not so useful:
Apr 10 17:34:28 snoogens NetworkManager: <info>  Activation (ttyUSB0) starting
connection 'Auto GSM network connection'
Apr 10 17:34:28 snoogens NetworkManager: <info>  Activation (ttyUSB0) Stage 1 of
5 (Device Prepare) scheduled...
Apr 10 17:34:28 snoogens NetworkManager: <info>  Activation (ttyUSB0) Stage 1 of
5 (Device Prepare) started...
Apr 10 17:34:28 snoogens NetworkManager: <info>  Activation (ttyUSB0) Stage 1 of
5 (Device Prepare) complete.
Comment 3 Bastien Nocera 2008-04-10 12:45:20 EDT
BTW, I'm using NetworkManager-0.7.0-0.9.1.svn3547.fc9.i386 now
Comment 4 Bastien Nocera 2008-04-10 13:57:25 EDT
Created attachment 302033 [details]
nm-3g-log.txt
Comment 5 Dan Williams 2008-04-10 14:38:09 EDT
added a workaround upstream in r3556
Comment 6 Dan Williams 2008-04-22 11:00:36 EDT
fixed in rawhide

Note You need to log in before you can comment on or make changes to this bug.