Bug 13024 - nozomi: pppd fails on kernel 2.6.29
Summary: nozomi: pppd fails on kernel 2.6.29
Status: CLOSED CODE_FIX
Alias: None
Product: Drivers
Classification: Unclassified
Component: Serial (show other bugs)
Hardware: All Linux
: P1 high
Assignee: Alan
URL:
Keywords:
Depends on:
Blocks: 12398
  Show dependency tree
 
Reported: 2009-04-06 19:12 UTC by Mark Karpeles
Modified: 2010-11-15 22:10 UTC (History)
10 users (show)

See Also:
Kernel Version: 2.6.29
Subsystem:
Regression: Yes
Bisected commit-id:


Attachments
strace -f of pppd running and working (184.80 KB, text/plain)
2009-04-27 13:36 UTC, Mark Karpeles
Details
strace -f of pppd not working (kernel 2.6.30-rc3) (42.03 KB, text/plain)
2009-04-27 13:37 UTC, Mark Karpeles
Details
Kerneloops in pppd (21.65 KB, text/plain)
2009-05-22 13:06 UTC, Cleber Santz
Details
dmesg for modprobe nozomi debug=255, kernel 2.6.29 and failed pppd/chat (55.11 KB, text/plain)
2009-06-18 11:47 UTC, miko
Details
strace.pppd-2.4.4-2.6.30.failed.txt (45.40 KB, text/plain)
2009-06-20 15:34 UTC, and
Details
strace.pppd-2.4.4-2.6.30.ok.txt (57.34 KB, text/plain)
2009-06-20 15:35 UTC, and
Details
Test Patch #1 (5.90 KB, patch)
2009-11-30 13:15 UTC, Alan
Details | Diff

Description Mark Karpeles 2009-04-06 19:12:29 UTC
Opening /dev/noz0 with minicom or open() syscall allows communication with Option NV 3G+ PCMCIA card.
When running pppd however, no reply is seen from the card (chat timeouts).

Downgrading nozomi.c from kernel 2.6.28 fixes this problem.

Not sure about exactly which informations are needed. I'm going to diff the two nozomi.c files and try to locate what's wrong (and maybe fix it), however if anyone did some major changes between the two versions, maybe he will know and will be able to fix this problem before I get enough time to look into it.

The kernel "tree" used is genpatches for both kernels (http://dev.gentoo.org/~dsd/genpatches/) however it seems that nozomi.c is left untouched.

I might be able to run tests on a vanilla kernel if need arise (I prefer only compiling nozomi.c as it's much faster).
Comment 1 Rafael J. Wysocki 2009-04-26 11:42:14 UTC
There's not been any followup, closing.
Comment 2 Mark Karpeles 2009-04-27 09:14:09 UTC
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.
Comment 3 Mark Karpeles 2009-04-27 09:19:51 UTC
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.
Comment 4 Alan 2009-04-27 12:12:05 UTC
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 ?
Comment 5 Mark Karpeles 2009-04-27 13:36:07 UTC
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)
Comment 6 Mark Karpeles 2009-04-27 13:37:11 UTC
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
Comment 7 Mark Karpeles 2009-04-27 13:38:56 UTC
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).
Comment 8 Alan 2009-04-27 15:25:50 UTC
Very strange, no obvious differences so it looks to be kernel side somewhere
Comment 9 Mark Karpeles 2009-04-27 15:35:33 UTC
Yep, also copying nozomi.c from 2.6.28 fixes the issue, so it must be a diff specifically in this file.
Comment 10 Miernik 2009-04-27 17:07:01 UTC
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
Comment 11 miko 2009-05-04 16:00:22 UTC
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).
Comment 12 Cleber Santz 2009-05-22 13:06:55 UTC
Created attachment 21491 [details]
Kerneloops in pppd
Comment 13 Cleber Santz 2009-05-22 13:11:32 UTC
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
Comment 14 Alan 2009-05-22 13:40:24 UTC
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)
Comment 15 and 2009-06-17 22:36:49 UTC
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
...
Comment 16 Alan 2009-06-18 10:37:46 UTC
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
Comment 17 miko 2009-06-18 11:47:30 UTC
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)
Comment 18 and 2009-06-20 15:32:20 UTC
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
...
Comment 19 and 2009-06-20 15:34:48 UTC
Created attachment 22027 [details]
strace.pppd-2.4.4-2.6.30.failed.txt
Comment 20 and 2009-06-20 15:35:24 UTC
Created attachment 22028 [details]
strace.pppd-2.4.4-2.6.30.ok.txt
Comment 21 Alan 2009-06-22 09:43:19 UTC
"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.
Comment 22 and 2009-11-25 21:11:24 UTC
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
Comment 23 and 2009-11-28 18:08:10 UTC
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)
Comment 24 Alan 2009-11-28 19:25:16 UTC
> 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 ?
Comment 25 and 2009-11-29 21:35:33 UTC
Thanks Alan for responding.
Yes, I have free time.
Comment 26 Alan 2009-11-30 13:13:50 UTC
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
Comment 27 Alan 2009-11-30 13:15:01 UTC
Created attachment 23977 [details]
Test Patch #1
Comment 28 and 2009-11-30 18:22:12 UTC
# 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
#
Comment 29 Alan 2009-11-30 18:46:38 UTC
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.
Comment 30 and 2009-11-30 19:52:16 UTC
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?
Comment 31 Alan 2009-12-02 14:05:55 UTC
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)
Comment 32 Sergio Lopez 2009-12-05 21:39:25 UTC
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.
Comment 33 and 2009-12-19 18:21:23 UTC
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);
Comment 34 Radoslaw Warowny 2010-01-15 23:55:22 UTC
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.
Comment 35 markus.stasch 2010-01-24 16:19:06 UTC
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.
Comment 36 markus.stasch 2010-01-25 13:24:36 UTC
(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...
Comment 37 and 2010-03-13 14:01:00 UTC
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.
Comment 38 Florian Mickler 2010-11-11 19:46:20 UTC
Alright. As far as I understood a fix for this issue has been merged?

I'm closing this then, please reopen if necessery.
Comment 39 Radoslaw Warowny 2010-11-15 22:10:33 UTC
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.

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