Bug 13024
Summary: | nozomi: pppd fails on kernel 2.6.29 | ||
---|---|---|---|
Product: | Drivers | Reporter: | Mark Karpeles (mark) |
Component: | Serial | Assignee: | Alan (alan) |
Status: | CLOSED CODE_FIX | ||
Severity: | high | CC: | alan, and, clebersantz, florian, markus.stasch, miko, public, radoslaww, rjw, xeryi.lpz |
Priority: | P1 | ||
Hardware: | All | ||
OS: | Linux | ||
Kernel Version: | 2.6.29 | Subsystem: | |
Regression: | Yes | Bisected commit-id: | |
Bug Depends on: | |||
Bug Blocks: | 12398 | ||
Attachments: |
strace -f of pppd running and working
strace -f of pppd not working (kernel 2.6.30-rc3) Kerneloops in pppd dmesg for modprobe nozomi debug=255, kernel 2.6.29 and failed pppd/chat strace.pppd-2.4.4-2.6.30.failed.txt strace.pppd-2.4.4-2.6.30.ok.txt Test Patch #1 |
Description
Mark Karpeles
2009-04-06 19:12:29 UTC
There's not been any followup, closing. Tested with kernel 2.6.30-rc3 and reproduced: minicom and other applications have no problem communicating with /dev/noz0, however pppd with a chat script asking to send "ATZ^M" and gets no reply. I didn't have much time to diff the two versions of nozomi.c and check where the problem comes from because of personnal issues (moving to another country, etc), however I'll be able to test that next friday. Debug output from chat: timeout set to 5 seconds abort on (BUSY) abort on (NO CARRIER) abort on (ERROR) abort on (+COPS: 0^M) send (ATZ^M) Checking if we have network... expect (OK) alarm send (AT^M) expect (OK) alarm Failed Connect script failed minicom: AT S7=45 S0=0 L1 V1 X4 &c1 E1 Q0 OK ATZ OK ATI Manufacturer: Option N.V. Model: GlobeTrotter 3G+ Revision: 3.19.0Hd (Date: May 31 2006, Time: 15:49:25) OK uname: Linux Kaze 2.6.30-rc3-tux #1 SMP PREEMPT Mon Apr 27 10:08:55 CEST 2009 x86_64 Intel(R) Core(TM)2 CPU U7500 @ 1.06GHz GenuineIntel GNU/Linux dmesg: [ 90.921160] pcmcia_socket pcmcia_socket0: pccard: CardBus card inserted into slot 0 [ 90.921222] pci 0000:05:00.0: reg 10 32bit mmio: [0x000000-0x0007ff] [ 90.930420] Initializing Nozomi driver 2.1d (build date: Apr 27 2009 10:12:21) [ 90.930605] nozomi 0000:05:00.0: Init, new card found [ 90.930621] nozomi 0000:05:00.0: enabling device (0000 -> 0002) [ 90.930638] nozomi 0000:05:00.0: PCI INT A -> GSI 22 (level, low) -> IRQ 22 [ 90.930649] nozomi 0000:05:00.0: Card type is: 2048 [ 91.221149] nozomi 0000:05:00.0: Version of card: 3 [ 91.221538] nozomi 0000:05:00.0: Initialization OK! [ 91.843368] nozomi 0000:05:00.0: Device READY! [ 138.253439] PPP generic driver version 2.4.2 If more feedback is needed, please let me know what you want. If the other apps work that strongly points to either a bug in your chat setup or just as likely chat is doing something the others are not. What does an strace of the failing chat script look like ? Created attachment 21136 [details]
strace -f of pppd running and working
pppd/chat running against nozomi.c from kernel 2.6.28, with kernel 2.6.29 (my current working configuration)
Created attachment 21137 [details]
strace -f of pppd not working (kernel 2.6.30-rc3)
strace -f on pppd/chat running on kernel 2.6.30-rc3 with original nozomi.c
Here are two full strace (pppd, chat, etc) under two versions of nozomi.c The first one is running on kernel 2.6.29 using nozomi.c from kernel 2.6.28. This configuration works. The second one is running on kernel 2.6.30-rc3 with its original nozomi.c. Result is the same as the one I got with 2.6.29 and its nozomi.c (I hope I made this clear enough). Very strange, no obvious differences so it looks to be kernel side somewhere Yep, also copying nozomi.c from 2.6.28 fixes the issue, so it must be a diff specifically in this file. I also have this problem. Debian sid system, Option GTmax card Manufacturer's Revision: 3.19.0Hd (Date: May 31 2006, Time: 15:49:2 Hardware Revision: 2.1 Kernel from Debian package: linux-image-2.6.29-1-686 (2.6.29-3) Exactly the same ppp configuration works on kernel 2.6.18. ppp from Debian package ppp 2.4.4rel-10 I can confirm this problem also. Using archlinux, kernel 2.6.29, ppp 2.4.4. Using older kernels, all worked OK (I did not change my scripts/configuration for months). Created attachment 21491 [details]
Kerneloops in pppd
I have the same problem using Ubuntu and 3G modem ZTE MF636 (19d2:0031) Kernel 2.6.29.3 and above PPP 2.4.2 Driver Option 0.7.2 Cleber: your system is not even using the nozomi driver - that is a different bug (and one that should be fixed as of 2.6.30-rcsomething) I can confirm this problem too. # cat /proc/version Linux version 2.6.30 (root@box) (gcc version 4.3.2 (Gentoo 4.3.2-r3 p1.6, pie-10.1.5) ) #3 SMP Thu Jun 17 20:20:20 UTC 2009 # dmesg | grep noz nozomi 0000:04:00.2: Init, new card found nozomi 0000:04:00.2: enabling device (0000 -> 0002) nozomi 0000:04:00.2: PCI INT A -> GSI 19 (level, low) -> IRQ 19 nozomi 0000:04:00.2: Card type is: 2048 nozomi 0000:04:00.2: Version of card: 3 nozomi 0000:04:00.2: Initialization OK! nozomi 0000:04:00.2: Device READY! using ppp version 2.4.4 (gentoo ppp-2.4.4-r22) minicom working but not program chat from ppp package # /usr/sbin/pppd /dev/noz0 nodetach connect '/usr/sbin/chat -s -v TIMEOUT 1 "" AT OK' timeout set to 1 seconds send (AT^M) expect (OK) alarm Failed Connect script failed using Mark Karpeles workaround (take nozomi.c from 2.6.28) program chat work again # /usr/sbin/pppd /dev/noz0 nodetach connect '/usr/sbin/chat -s -v TIMEOUT 1 "" AT OK' timeout set to 1 seconds send (AT^M) expect (OK) AT^M^M OK -- got it ... Not obvious what is going on here even reviewig the changes. Can you repeat the experiment for the failing case (ie a current kernel) but load nozomi with the option nozomi.debug=255 (ie before using it: rmmod nozomi # in case the distro autoloaded it modprobe nozomi debug=255 ) That should put lots of useful diagnostics into "dmesg" which you can then attach to the bug and may help work out what is up Created attachment 21980 [details]
dmesg for modprobe nozomi debug=255, kernel 2.6.29 and failed pppd/chat
Here is my dmesg log for kernel 2.6.29 , ppp 2.4.4, current archlinux distro. The connection is failing (but would work for 2.6.28)
Full strace dumps attached. Before execve(call) there is maybe one interesting different between working and non-working ppp/chat. # sed 's/2476/pppd/g;s/2477/chat/g;s/0x[0-9a-f]*/<addr>/g' strace.pppd-2.4.4-2.6.30.ok.txt > strace.pppd.ok.strip.txt # sed 's/2099/pppd/g;s/2100/chat/g;s/0x[0-9a-f]*/<addr>/g' strace.pppd-2.4.4-2.6.30.failed.txt > strace.pppd.failed.strip.txt # diff -uN strace.pppd.failed.strip.txt strace.pppd.ok.strip.txt ... -pppd ioctl(9, SNDCTL_TMR_TIMEBASE or TCGETS, {B115200 opost isig icanon -echo ...}) = 0 +pppd ioctl(9, SNDCTL_TMR_TIMEBASE or TCGETS, {B115200 opost isig icanon echo ...}) = 0 ... Created attachment 22027 [details]
strace.pppd-2.4.4-2.6.30.failed.txt
Created attachment 22028 [details]
strace.pppd-2.4.4-2.6.30.ok.txt
"Jun 18 13:34:16 linux kernel: [834] receive_data(): tty not open for port: 0?" Ok that looks relevant and I'll dig a bit more on that later. The TCGETS one doesn' t look a relevant difference (its just reading the state of the port when it starts) but it is odd that is different. mhh no news with 2.6.31.6 debug-failed.txt 2.6.31.6 nozomi.c debug=255 debug-sucess.txt 2.6.28 nozomi.c file using with 2.6.31.6 --- debug-success.txt 2009-11-25 21:41:28.000000000 +0100 +++ debug-failed.txt 2009-11-25 21:39:41.000000000 +0100 @@ -8,7 +8,7 @@ kernel: nozomi 0000:04:00.2: enabling device (0000 -> 0002) kernel: nozomi 0000:04:00.2: PCI INT A -> GSI 19 (level, low) -> IRQ 19 kernel: nozomi 0000:04:00.2: Card type is: 2048 -kernel: nozomi_card_init(): base_addr: ffffc90005e6c000 +kernel: nozomi_card_init(): base_addr: ffffc90005e3c000 kernel: interrupt_handler(): RESET irq:0x8000, prev:0x8000 kernel: nozomi_read_config_table(): First phase: pushing upload buffers, clearing download kernel: nozomi 0000:04:00.2: Version of card: 3 @@ -70,6 +70,8 @@ kernel: set_dtr(): SETTING DTR index: 0, dtr: 1 kernel: ntty_ioctl(): ******** IOCTL, cmd: 21505 kernel: ntty_ioctl(): ERR: 0x00005401, 21505 +kernel: interrupt_handler(): CTRL_UL irq:0x1000, prev:0x9805 +kernel: interrupt_handler(): CTRL_UL kernel: ntty_ioctl(): ******** IOCTL, cmd: 21508 kernel: ntty_ioctl(): ERR: 0x00005404, 21508 kernel: set_dtr(): SETTING DTR index: 0, dtr: 0 @@ -96,21 +98,31 @@ kernel: interrupt_handler(): MDM_UL1 MDM_UL2 irq:0x000A, prev:0x880F kernel: send_data(): No more data to send, disable link: kernel: interrupt_handler(): MDM_DL1 irq:0x0001, prev:0x8805 +kernel: receive_data(): tty not open for port: 0? kernel: ntty_write(): Enable interrupt kernel: interrupt_handler(): MDM_UL1 MDM_UL2 irq:0x000A, prev:0x880F kernel: send_data(): No more data to send, disable link: kernel: interrupt_handler(): MDM_DL2 irq:0x0004, prev:0x8805 +kernel: receive_data(): tty not open for port: 0? kernel: ntty_write(): Enable interrupt kernel: interrupt_handler(): MDM_UL1 MDM_UL2 irq:0x000A, prev:0x880F kernel: send_data(): No more data to send, disable link: kernel: interrupt_handler(): MDM_DL1 irq:0x0001, prev:0x8805 +kernel: receive_data(): tty not open for port: 0? kernel: ntty_write(): Enable interrupt kernel: interrupt_handler(): MDM_UL1 MDM_UL2 irq:0x000A, prev:0x880F kernel: send_data(): No more data to send, disable link: chat: expect (OK) kernel: interrupt_handler(): MDM_DL2 irq:0x0004, prev:0x8805 -kernel: interrupt_handler(): CTRL_DL irq:0x0800, prev:0x8805 +kernel: receive_data(): tty not open for port: 0? +kernel: interrupt_handler(): MDM_DL1 CTRL_DL irq:0x0801, prev:0x8805 kernel: receive_flow_control(): 0x0109->0x0109 kernel: receive_flow_control(): No change in mctrl -kernel: interrupt_handler(): MDM_DL1 irq:0x0001, prev:0x8805 -chat: ATZ^M^M +kernel: receive_data(): tty not open for port: 0? +kernel: ntty_ioctl(): ******** IOCTL, cmd: 21506 +kernel: ntty_ioctl(): ERR: 0x00005402, 21506 +kernel: set_dtr(): SETTING DTR index: 0, dtr: 0 +kernel: interrupt_handler(): CTRL_UL irq:0x1000, prev:0x9805 +kernel: interrupt_handler(): CTRL_UL +pppd: Connect script failed +chat: alarm I _poke_ a bit to find the tty pointer problem. dc = ffff88007ce20000 dc->port[0] = ffff88007ce20078 port[0]->tty = ffff88007fa6f000 > ok, tty is null, port is not open actually kernel: [1184] interrupt_handler(): ffff88007ce20000 ffff88007ce20078 (null) kernel: [1202] interrupt_handler(): CTRL_DL irq:0x0800, prev:0x8800 kernel: [1184] interrupt_handler(): ffff88007ce20000 ffff88007ce20078 (null) kernel: [1202] interrupt_handler(): CTRL_DL irq:0x0800, prev:0x8800 kernel: [1606] ntty_open(): open: 5 > good, tty pointer exist after ntty_open() kernel: [1613] ntty_open(): open ffff88007ce20000 ffff88007ce20078 ffff88007fa6f000 kernel: [1184] interrupt_handler(): ffff88007ce20000 ffff88007ce20078 ffff88007fa6f000 kernel: [1202] interrupt_handler(): CTRL_UL irq:0x1000, prev:0x9805 kernel: [1217] interrupt_handler(): CTRL_UL kernel: [1184] interrupt_handler(): ffff88007ce20000 ffff88007ce20078 ffff88007fa6f000 kernel: [1202] interrupt_handler(): CTRL_UL irq:0x1000, prev:0x9805 kernel: [1217] interrupt_handler(): CTRL_UL kernel: [1184] interrupt_handler(): ffff88007ce20000 ffff88007ce20078 ffff88007fa6f000 kernel: [1202] interrupt_handler(): CTRL_UL irq:0x1000, prev:0x9805 kernel: [1217] interrupt_handler(): CTRL_UL chat[2297]: send (ATZ^M) kernel: [1667] ntty_write(): ffff88007ce20000 ffff88007ce20078 ffff88007fa6f000 kernel: [1701] ntty_write(): Enable interrupt kernel: [1713] ntty_write(): ffff88007ce20000 ffff88007ce20078 ffff88007fa6f000 > hey, now interrupt_handler() deals without tty pointer, why? kernel: [1184] interrupt_handler(): ffff88007ce20000 ffff88007ce20078 (null) kernel: [1202] interrupt_handler(): MDM_UL1 MDM_UL2 irq:0x000A, prev:0x880F kernel: [799] send_data(): ffff88007ce20000 ffff88007ce20078 (null) kernel: [799] send_data(): ffff88007ce20000 ffff88007ce20078 (null) kernel: [806] send_data(): No more data to send, disable link: kernel: [1184] interrupt_handler(): ffff88007ce20000 ffff88007ce20078 (null) kernel: [1202] interrupt_handler(): MDM_DL1 irq:0x0001, prev:0x8805 kernel: [836] receive_data(): tty not open for port: 0? ffff88007ce20000 ffff88007ce20078 (null) kernel: [1667] ntty_write(): ffff88007ce20000 ffff88007ce20078 ffff88007fa6f000 kernel: [1701] ntty_write(): Enable interrupt kernel: [1713] ntty_write(): ffff88007ce20000 ffff88007ce20078 ffff88007fa6f000 kernel: [1184] interrupt_handler(): ffff88007ce20000 ffff88007ce20078 (null) kernel: [1202] interrupt_handler(): MDM_UL1 MDM_UL2 irq:0x000A, prev:0x880F kernel: [799] send_data(): ffff88007ce20000 ffff88007ce20078 (null) kernel: [799] send_data(): ffff88007ce20000 ffff88007ce20078 (null) > hey, now interrupt_handler() deals without tty pointer, why?
kernel: [836] receive_data(): tty not open for port: 0? ffff88007ce20000
ffff88007ce20078 (null)
That would be why
The nozomi driver open and close handling is on inspection completely and utter bogus. That driver should never have been merged in the state it is in and the maintainer seems to have vanished.
You seem to be happy poking through debug data, do you fancy acting as tester while I try and beat this pile of crap into shape and get it working ? and if so can you turn around results from test patches in 2 or 3 days ?
Thanks Alan for responding. Yes, I have free time. Ok a first patch - cleans up the open/close and adds a couple of bits of diagnostics to try and see what is going on better Created attachment 23977 [details]
Test Patch #1
# cd /usr/src/linux-2.6.31.6 # sha1sum drivers/char/nozomi.c 98e8586435fa2356748884bcff85b5bba12318fc drivers/char/nozomi.c # patch -p1 < /usr/src/nozomi-debug/23977.patch patching file drivers/char/nozomi.c Hunk #1 succeeded at 370 (offset -1 lines). Hunk #2 succeeded at 415 (offset -1 lines). Hunk #3 succeeded at 1467 (offset -1 lines). Hunk #4 succeeded at 1584 (offset -1 lines). Hunk #5 succeeded at 1897 (offset -1 lines). Hunk #6 succeeded at 1914 (offset -1 lines). # sha1sum drivers/char/nozomi.c bddacdce86fedd5ba87288f59bb050e6be31a168 drivers/char/nozomi.c # gcc -v Using built-in specs. Target: x86_64-pc-linux-gnu Configured with: /var/tmp/portage/sys-devel/gcc-4.3.4/work/gcc-4.3.4/configure --prefix=/usr --bindir=/usr/x86_64-pc-linux-gnu/gcc-bin/4.3.4 --includedir=/usr/lib/gcc/x86_64-pc-linux-gnu/4.3.4/include --datadir=/usr/share/gcc-data/x86_64-pc-linux-gnu/4.3.4 --mandir=/usr/share/gcc-data/x86_64-pc-linux-gnu/4.3.4/man --infodir=/usr/share/gcc-data/x86_64-pc-linux-gnu/4.3.4/info --with-gxx-include-dir=/usr/lib/gcc/x86_64-pc-linux-gnu/4.3.4/include/g++-v4 --host=x86_64-pc-linux-gnu --build=x86_64-pc-linux-gnu --disable-altivec --disable-fixed-point --disable-nls --with-system-zlib --disable-checking --disable-werror --enable-secureplt --enable-multilib --disable-libmudflap --disable-libssp --enable-libgomp --disable-libgcj --enable-languages=c,c++,treelang --enable-shared --enable-threads=posix --enable-__cxa_atexit --enable-clocale=gnu --with-bugurl=http://bugs.gentoo.org/ --with-pkgversion='Gentoo 4.3.4 p1.0, pie-10.1.5' Thread model: posix gcc version 4.3.4 (Gentoo 4.3.4 p1.0, pie-10.1.5) # make CHK include/linux/version.h CHK include/linux/utsrelease.h SYMLINK include/asm -> include/asm-x86 CALL scripts/checksyscalls.sh CHK include/linux/compile.h CC [M] drivers/char/nozomi.o drivers/char/nozomi.c: In function 'ntty_open': drivers/char/nozomi.c:1626: error: implicit declaration of function 'tty_port_open' drivers/char/nozomi.c: At top level: drivers/char/nozomi.c:1901: error: unknown field 'activate' specified in initializer drivers/char/nozomi.c:1901: warning: initialization from incompatible pointer type drivers/char/nozomi.c:1918: error: unknown field 'cleanup' specified in initializer drivers/char/nozomi.c:1918: warning: initialization from incompatible pointer type make[2]: *** [drivers/char/nozomi.o] Error 1 make[1]: *** [drivers/char] Error 2 make: *** [drivers] Error 2 # Needs building against a current kernel - the infrastructure it wants to make the whole process simple isn't in 2.6.29 in the form needed. 2.6.31 should do fine for this. Sorry should have said. No problemo, but I use already 2.6.31.6 # head -4 Makefile VERSION = 2 PATCHLEVEL = 6 SUBLEVEL = 31 EXTRAVERSION = .6 Also tested with 2.6.32-rc8 drivers/char/nozomi.c: In function 'ntty_open': drivers/char/nozomi.c:1627: error: implicit declaration of function 'tty_port_open' drivers/char/nozomi.c: At top level: drivers/char/nozomi.c:1902: error: unknown field 'activate' specified in initializer drivers/char/nozomi.c:1902: warning: initialization from incompatible pointer type make[2]: *** [drivers/char/nozomi.o] Error 1 make[1]: *** [drivers/char] Error 2 make: *** [drivers] Error 2 Should I use some GIT sources? I'm working against the -next tree but I hadn't realised how far back the base tree was (I guess because 2.6.32rc has been going on for ages and ages now) Same problem here. Since kernel version 2.6.29, when the driver was changed to use tty_port_tty_get/tty_kref_put, nozomi support seems to be broken. I think the problem (at least, the most immediate one) is in "ntty_close": static void ntty_close(struct tty_struct *tty, struct file *file) { struct nozomi *dc = get_dc_by_tty(tty); struct port *nport = tty->driver_data; struct tty_port *port = &nport->port; unsigned long flags; if (!dc || !nport) return; /* Users cannot interrupt a close */ mutex_lock(&nport->tty_sem); WARN_ON(!port->count); dc->open_ttys--; port->count--; tty_port_tty_set(port, NULL); if (port->count == 0) { DBG1("close: %d", nport->token_dl); spin_lock_irqsave(&dc->spin_mutex, flags); dc->last_ier &= ~(nport->token_dl); writew(dc->last_ier, dc->reg_ier); spin_unlock_irqrestore(&dc->spin_mutex, flags); } mutex_unlock(&nport->tty_sem); } Here, "tty" object is cleared for "tty_port" each time "ntty_close" is called, not only when the reference count gets to zero. Simply moving the "tty_port_tty_set" statement into the "if" clause makes the driver work for me again. So,patch compiling with 2.6.33-rc1 works now. Maybe the warnings help you, to give me a new test patch. nozomi debug=255 output: Dec 19 18:35:44 d kernel: pcmcia_socket pcmcia_socket0: pccard: CardBus card inserted into slot 0 Dec 19 18:35:44 d kernel: pci 0000:04:00.0: reg 10: [mem 0xd0000000-0xd000ffff] Dec 19 18:35:44 d kernel: pci 0000:04:00.0: reg 14: [mem 0xc0000000-0xc000ffff] Dec 19 18:35:44 d kernel: pci 0000:04:00.1: reg 10: [mem 0xd0000000-0xd000ffff] Dec 19 18:35:44 d kernel: pci 0000:04:00.1: reg 14: [mem 0xc0000000-0xc000ffff] Dec 19 18:35:44 d kernel: pci 0000:04:00.2: reg 10: [mem 0x00000000-0x000007ff] Dec 19 18:35:44 d kernel: pci 0000:04:00.0: BAR 0: assigned [mem 0x88000000-0x8800ffff] Dec 19 18:35:44 d kernel: pci 0000:04:00.0: BAR 0: set to [mem 0x88000000-0x8800ffff] (PCI address [0x88000000-0x8800ffff] Dec 19 18:35:44 d kernel: pci 0000:04:00.0: BAR 1: assigned [mem 0x88010000-0x8801ffff] Dec 19 18:35:44 d kernel: pci 0000:04:00.0: BAR 1: set to [mem 0x88010000-0x8801ffff] (PCI address [0x88010000-0x8801ffff] Dec 19 18:35:44 d kernel: pci 0000:04:00.1: BAR 0: assigned [mem 0x88020000-0x8802ffff] Dec 19 18:35:44 d kernel: pci 0000:04:00.1: BAR 0: set to [mem 0x88020000-0x8802ffff] (PCI address [0x88020000-0x8802ffff] Dec 19 18:35:44 d kernel: pci 0000:04:00.1: BAR 1: assigned [mem 0x88030000-0x8803ffff] Dec 19 18:35:44 d kernel: pci 0000:04:00.1: BAR 1: set to [mem 0x88030000-0x8803ffff] (PCI address [0x88030000-0x8803ffff] Dec 19 18:35:44 d kernel: pci 0000:04:00.2: BAR 0: assigned [mem 0x88040000-0x880407ff] Dec 19 18:35:44 d kernel: pci 0000:04:00.2: BAR 0: set to [mem 0x88040000-0x880407ff] (PCI address [0x88040000-0x880407ff] Dec 19 18:35:44 d kernel: pci 0000:04:00.2: cache line size of 64 is not supported Dec 19 18:35:44 d kernel: Initializing Nozomi driver 2.1d (build date: Dec 19 2009 18:08:22) Dec 19 18:35:44 d kernel: nozomi 0000:04:00.2: Init, new card found Dec 19 18:35:44 d kernel: nozomi 0000:04:00.2: enabling device (0000 -> 0002) Dec 19 18:35:44 d kernel: nozomi 0000:04:00.2: PCI INT A -> GSI 19 (level, low) -> IRQ 19 Dec 19 18:35:44 d kernel: nozomi 0000:04:00.2: Card type is: 2048 Dec 19 18:35:44 d kernel: [1455] nozomi_card_init(): base_addr: ffffc900040fe000 Dec 19 18:35:45 d kernel: [1201] interrupt_handler(): RESET irq:0x8000, prev:0x8000 Dec 19 18:35:45 d kernel: [710] nozomi_read_config_table(): First phase: pushing upload buffers, clearing download Dec 19 18:35:45 d kernel: nozomi 0000:04:00.2: Version of card: 3 Dec 19 18:35:45 d kernel: [731] nozomi_read_config_table(): First phase done Dec 19 18:35:45 d kernel: [1201] interrupt_handler(): RESET irq:0x8000, prev:0x8000 Dec 19 18:35:45 d kernel: [678] nozomi_read_config_table(): Second phase, configuring card Dec 19 18:35:45 d kernel: [687] nozomi_read_config_table(): toggle ports: MDM UL:0 MDM DL:0, DIAG DL:0 Dec 19 18:35:45 d kernel: [617] dump_table(): signature: 0xEFEFFEFE Dec 19 18:35:45 d kernel: [618] dump_table(): version: 0x0003 Dec 19 18:35:45 d kernel: [620] dump_table(): product_information: 0x0000 Dec 19 18:35:45 d kernel: [621] dump_table(): toggle enabled: 0 Dec 19 18:35:45 d kernel: [622] dump_table(): toggle up_mdm: 0 Dec 19 18:35:45 d kernel: [623] dump_table(): toggle dl_mdm: 0 Dec 19 18:35:45 d kernel: [624] dump_table(): toggle dl_dbg: 0 Dec 19 18:35:45 d kernel: [626] dump_table(): dl_start: 0x0000 Dec 19 18:35:45 d kernel: [628] dump_table(): dl_mdm_len0: 0x00AC, 172 Dec 19 18:35:45 d kernel: [630] dump_table(): dl_mdm_len1: 0x00AC, 172 Dec 19 18:35:45 d kernel: [632] dump_table(): dl_diag_len0: 0x0044, 68 Dec 19 18:35:45 d kernel: [634] dump_table(): dl_diag_len1: 0x0044, 68 Dec 19 18:35:45 d kernel: [636] dump_table(): dl_app1_len: 0x000C, 12 Dec 19 18:35:45 d kernel: [638] dump_table(): dl_app2_len: 0x000C, 12 Dec 19 18:35:45 d kernel: [640] dump_table(): dl_ctrl_len: 0x0004, 4 Dec 19 18:35:45 d kernel: [642] dump_table(): ul_start: 0x0200, 512 Dec 19 18:35:45 d kernel: [644] dump_table(): ul_mdm_len[0]: 0x0048, 72 Dec 19 18:35:45 d kernel: [646] dump_table(): ul_mdm_len[1]: 0x0048, 72 Dec 19 18:35:45 d kernel: [648] dump_table(): ul_diag_len: 0x0044, 68 Dec 19 18:35:45 d kernel: [650] dump_table(): ul_app1_len: 0x0014, 20 Dec 19 18:35:45 d kernel: [652] dump_table(): ul_app2_len: 0x0014, 20 Dec 19 18:35:45 d kernel: [654] dump_table(): ul_ctrl_len: 0x0004, 4 Dec 19 18:35:45 d kernel: nozomi 0000:04:00.2: Initialization OK! Dec 19 18:35:45 d kernel: [1201] interrupt_handler(): CTRL_DL irq:0x0800, prev:0x8800 Dec 19 18:35:45 d kernel: [983] receive_flow_control(): 0x0000->0x0209 Dec 19 18:35:45 d kernel: [1002] receive_flow_control(): No data in buffer... Dec 19 18:35:45 d kernel: [1025] receive_flow_control(): port: 1 DCD(0), CTS(1), RI(0), DSR(1) Dec 19 18:35:45 d kernel: [1201] interrupt_handler(): CTRL_DL irq:0x0800, prev:0x8800 Dec 19 18:35:45 d kernel: [983] receive_flow_control(): 0x0000->0x0109 Dec 19 18:35:45 d kernel: [1002] receive_flow_control(): No data in buffer... Dec 19 18:35:45 d kernel: [1025] receive_flow_control(): port: 0 DCD(0), CTS(1), RI(0), DSR(1) Dec 19 18:35:45 d kernel: [1201] interrupt_handler(): CTRL_DL irq:0x0800, prev:0x8800 Dec 19 18:35:45 d kernel: [983] receive_flow_control(): 0x0109->0x0109 Dec 19 18:35:45 d kernel: [1007] receive_flow_control(): No change in mctrl Dec 19 18:35:45 d kernel: [1201] interrupt_handler(): CTRL_DL irq:0x0800, prev:0x8800 Dec 19 18:35:45 d kernel: [983] receive_flow_control(): 0x0109->0x0109 Dec 19 18:35:45 d kernel: [1007] receive_flow_control(): No change in mctrl Dec 19 18:35:45 d kernel: [1201] interrupt_handler(): CTRL_DL irq:0x0800, prev:0x8800 Dec 19 18:35:45 d kernel: [983] receive_flow_control(): 0x0109->0x0109 Dec 19 18:35:45 d kernel: [1007] receive_flow_control(): No change in mctrl Dec 19 18:35:45 d kernel: [1201] interrupt_handler(): CTRL_DL irq:0x0800, prev:0x8800 Dec 19 18:35:45 d kernel: [983] receive_flow_control(): 0x0000->0x0309 Dec 19 18:35:45 d kernel: [1002] receive_flow_control(): No data in buffer... Dec 19 18:35:45 d kernel: [1025] receive_flow_control(): port: 2 DCD(0), CTS(1), RI(0), DSR(1) Dec 19 18:35:45 d kernel: [1201] interrupt_handler(): CTRL_DL irq:0x0800, prev:0x8800 Dec 19 18:35:45 d kernel: nozomi 0000:04:00.2: Device READY! Dec 19 18:35:45 d kernel: [983] receive_flow_control(): 0x0000->0x0409 Dec 19 18:35:45 d kernel: [1002] receive_flow_control(): No data in buffer... Dec 19 18:35:45 d kernel: [1025] receive_flow_control(): port: 3 DCD(0), CTS(1), RI(0), DSR(1) Dec 19 18:37:07 d pppd[3478]: pppd 2.4.4 started by root, uid 0 Dec 19 18:37:07 d kernel: Warning: dev (noz0) tty->count(0) != #fd's(1) in tty_open Dec 19 18:37:07 d kernel: [1614] ntty_activate(): open: 5 Dec 19 18:37:07 d kernel: noz: activated 0: ffff88007596e078 Dec 19 18:37:07 d kernel: [1575] set_dtr(): SETTING DTR index: 0, dtr: 1 Dec 19 18:37:07 d kernel: [1827] ntty_ioctl(): ******** IOCTL, cmd: 21505 Dec 19 18:37:07 d kernel: [1201] interrupt_handler(): CTRL_UL irq:0x1000, prev:0x9805 Dec 19 18:37:07 d kernel: [1216] interrupt_handler(): CTRL_UL Dec 19 18:37:07 d kernel: [1840] ntty_ioctl(): ERR: 0x00005401, 21505 Dec 19 18:37:07 d kernel: [1827] ntty_ioctl(): ******** IOCTL, cmd: 21508 Dec 19 18:37:07 d kernel: [1840] ntty_ioctl(): ERR: 0x00005404, 21508 Dec 19 18:37:07 d kernel: [1575] set_dtr(): SETTING DTR index: 0, dtr: 0 Dec 19 18:37:07 d kernel: [1201] interrupt_handler(): CTRL_UL irq:0x1000, prev:0x9805 Dec 19 18:37:07 d kernel: [1216] interrupt_handler(): CTRL_UL Dec 19 18:37:07 d /etc/init.d/net.ppp0[3402]: WARNING: net.ppp0 has started, but is inactive Dec 19 18:37:08 d kernel: [1575] set_dtr(): SETTING DTR index: 0, dtr: 1 Dec 19 18:37:08 d kernel: [1201] interrupt_handler(): CTRL_UL irq:0x1000, prev:0x9805 Dec 19 18:37:08 d kernel: [1216] interrupt_handler(): CTRL_UL Dec 19 18:37:08 d kernel: Warning: dev (noz0) tty->count(1) != #fd's(2) in tty_open Dec 19 18:37:08 d kernel: Warning: dev (noz0) tty->count(1) != #fd's(2) in tty_release_dev Dec 19 18:37:08 d kernel: [1827] ntty_ioctl(): ******** IOCTL, cmd: 21505 Dec 19 18:37:08 d kernel: [1840] ntty_ioctl(): ERR: 0x00005401, 21505 In the meantime, I use Sergio Lopez hint. Diff against 2.6.32.2: --- nozomi.c 2009-12-19 19:16:11.244374317 +0100 +++ nozomi.new 2009-12-19 19:16:26.251249134 +0100 @@ -1629,10 +1629,10 @@ dc->open_ttys--; port->count--; - tty_port_tty_set(port, NULL); if (port->count == 0) { DBG1("close: %d", nport->token_dl); + tty_port_tty_set(port, NULL); spin_lock_irqsave(&dc->spin_mutex, flags); dc->last_ier &= ~(nport->token_dl); writew(dc->last_ier, dc->reg_ier); Problems with Internet connection using the nozomi driver were reported in two Ubuntu bug reports: https://bugs.launchpad.net/ubuntu/+source/modemmanager/+bug/425312 https://bugs.launchpad.net/ubuntu/+bug/505330 The first one is about other issue but you can find some debugging output of connection attempts there. Maybe information provided within that reports will be helpful while working on this bug. I am encountering the same problem on sidux with kernel 2.6.32.5. After reviewing the changelog of the driver, I would suggest, that there is a timing problem. The high Baud rates (my wvdial config is using Baud = 921600) seems to cause the problem. After adding low_latency to the port, as it was done in 2.6.28, everything is working for me now. (Option GTmax aka Telekom Web'n'Walk compact card). Jan 24 17:10:45 denkbrett kernel: pcmcia_socket pcmcia_socket0: pccard: CardBus card inserted into slot 0 Jan 24 17:10:45 denkbrett kernel: nozomi 0000:03:00.0: enabling device (0000 -> 0002) Jan 24 17:10:45 denkbrett kernel: nozomi 0000:03:00.0: PCI INT A -> Link[LNKA] -> GSI 11 (level, low) -> IRQ 11 Jan 24 17:10:45 denkbrett kernel: nozomi 0000:03:00.0: Card type is: 2048 Jan 24 17:10:46 denkbrett kernel: nozomi 0000:03:00.0: Version of card: 3 Jan 24 17:10:46 denkbrett kernel: nozomi 0000:03:00.0: Initialization OK! Jan 24 17:10:47 denkbrett kernel: nozomi 0000:03:00.0: Device READY! -- snip static int ntty_open(struct tty_struct *tty, struct file *file) { ... /* Enable interrupt downlink for channel */ if (port->port.count == 1) { tty->low_latency = 1; // <-- This line was (re)added tty->driver_data = port; tty_port_tty_set(&port->port, tty); DBG1("open: %d", port->token_dl); spin_lock_irqsave(&dc->spin_mutex, flags); dc->last_ier = dc->last_ier | port->token_dl; writew(dc->last_ier, dc->reg_ier); spin_unlock_irqrestore(&dc->spin_mutex, flags); } mutex_unlock(&port->tty_sem); return 0; } -- snap After doing these modifications, wvdial -> ppp works like a breeze. Maybe it could give someone a hint. (In reply to comment #35) I think, I was a bit too enthuastic. After doing several tests yesterday, and today, the functionality with pppd is broken. (LCP: timeout sending Config-Requests). Only the nozomi.c from 2.6.28.10 seems to work... Alan, there was an intention to polish up the nozomi driver. If no, let us close this bug. I'm happy with the working bugfix/workaround that was also pushed to mainstream kernel by you. Alright. As far as I understood a fix for this issue has been merged? I'm closing this then, please reopen if necessery. What is missing for me is when and how the bug was fixed. Some investigation shows, that above fix was right (Comment #32 From Sergio Lopez 2009-12-05 21:39:25). The same fix was commited to 2.6.33 kernel version as: 2010-01-20 Alan Cox nozomi: quick fix for the close/close bug You can find description of this commit here: http://git.kernel.org/?p=linux/kernel/git/stable/linux-2.6.36.y.git;a=commitdiff;h=eeec32a731631a9bad9abb21c626b9f2840bee0d Thanks. |