Most recent kernel where this bug did not occur: 2.6.12 Distribution: Gentoo Linux AMD64 Hardware Environment: Athlon64, asus k8v deluxe, pcmcia/pci bridge, Novatel Merlin u530 Software Environment: gcc 3.4.4-r1, binutils 2.16.1, pcmcia-cs 3.2.8-r2 Problem Description: Novatel Merlin u530 is a gprs/umts(3g) pcmcia card. When i insert the card, its mapped as ttyS2. Then i pon gprs(a script which works for my isp) and it DOES establish a connection, BUT it will start working at 1Kbps and in a matter of few seconds, decrease until reaching 0Bs. The connection isnt hung up, but it wont work anymore. My guess is that this bug might be related somehow with http://bugzilla.kernel.org/show_bug.cgi?id=5569 and http://bugzilla.kernel.org/show_bug.cgi?id=5678 . But just my guess. This is a cut from /var/log/messages on 2.6.14.5 sources from kernel.org (NON_WORKING): Jan 7 15:44:41 localhost Yenta: CardBus bridge found at 0000:00:0d.0 [414e:454c] Jan 7 15:44:41 localhost Yenta: Enabling burst memory read transactions Jan 7 15:44:41 localhost Yenta: Using CSCINT to route CSC interrupts to PCI Jan 7 15:44:41 localhost Yenta: Routing CardBus interrupts to PCI Jan 7 15:44:41 localhost Yenta TI: socket 0000:00:0d.0, mfunc 0x00c00d02, devctl 0x42 Jan 7 15:44:41 localhost Yenta: ISA IRQ mask 0x0000, PCI irq 169 Jan 7 15:44:41 localhost Socket status: 30000006 Jan 7 15:44:41 localhost ACPI: PCI Interrupt 0000:00:0d.1[A] -> GSI 18 (level, low) -> IRQ 169 Jan 7 15:44:41 localhost Yenta: CardBus bridge found at 0000:00:0d.1 [414e:454c] Jan 7 15:44:41 localhost Yenta: Using CSCINT to route CSC interrupts to PCI Jan 7 15:44:41 localhost Yenta: Routing CardBus interrupts to PCI Jan 7 15:44:41 localhost Yenta TI: socket 0000:00:0d.1, mfunc 0x00c00d02, devctl 0x42 Jan 7 15:44:42 localhost Yenta: ISA IRQ mask 0x0000, PCI irq 169 Jan 7 15:44:42 localhost Socket status: 30000006 Jan 7 15:44:42 localhost ds: ds_open(socket 0) Jan 7 15:44:42 localhost pcmcia: Detected deprecated PCMCIA ioctl usage. Jan 7 15:44:42 localhost pcmcia: This interface will soon be removed from the kernel; please expect breakage unless you upgrade to new tools. Jan 7 15:44:42 localhost pcmcia: see http://www.kernel.org/pub/linux/utils/kernel/pcmcia/pcmcia.html for details. Jan 7 15:44:42 localhost ds: ds_open(socket 1) Jan 7 15:44:42 localhost ds: ds_open(socket 2) Jan 7 15:44:42 localhost ds: ds_open(socket 2) Jan 7 15:44:42 localhost cardmgr[7041]: watching 2 sockets Jan 7 15:45:14 localhost cardmgr[7042]: socket 1: Serial or Modem Jan 7 15:45:14 localhost ttyS2 at I/O 0x3e8 (irq = 169) is a 16550A Jan 7 15:45:32 localhost pppd[7386]: pppd 2.4.2 started by root, uid 0 Jan 7 15:45:33 localhost chat[7387]: timeout set to 5 seconds Jan 7 15:45:33 localhost chat[7387]: abort on (\nBUSY\r) Jan 7 15:45:33 localhost chat[7387]: abort on (\nERROR\r) Jan 7 15:45:33 localhost chat[7387]: abort on (\nNO ANSWER\r) Jan 7 15:45:33 localhost chat[7387]: abort on (\nNO CARRIER\r) Jan 7 15:45:33 localhost chat[7387]: abort on (\nNO DIALTONE\r) Jan 7 15:45:33 localhost chat[7387]: abort on (\nRINGING\r\n\r\nRINGING\r) Jan 7 15:45:33 localhost chat[7387]: send (^MAT^M) Jan 7 15:45:33 localhost chat[7387]: timeout set to 5 seconds Jan 7 15:45:33 localhost chat[7387]: expect (OK) Jan 7 15:45:33 localhost chat[7387]: AT^M^M Jan 7 15:45:33 localhost chat[7387]: OK Jan 7 15:45:33 localhost chat[7387]: -- got it Jan 7 15:45:33 localhost chat[7387]: send (ATE1^M) Jan 7 15:45:33 localhost chat[7387]: expect (OK) Jan 7 15:45:33 localhost chat[7387]: ^M Jan 7 15:45:33 localhost chat[7387]: ATE1^M^M Jan 7 15:45:33 localhost chat[7387]: OK Jan 7 15:45:33 localhost chat[7387]: -- got it Jan 7 15:45:33 localhost chat[7387]: send (AT+cgdcont=1,"IP","movistar.es"^M) Jan 7 15:45:34 localhost chat[7387]: expect (OK) Jan 7 15:45:34 localhost chat[7387]: ^M Jan 7 15:45:34 localhost chat[7387]: AT+cgdcont=1,"IP","movistar.es"^M^M Jan 7 15:45:34 localhost chat[7387]: OK Jan 7 15:45:34 localhost chat[7387]: -- got it Jan 7 15:45:34 localhost chat[7387]: send (ATD*99***1#^M) Jan 7 15:45:34 localhost chat[7387]: expect (CONNECT) Jan 7 15:45:34 localhost chat[7387]: ^M Jan 7 15:45:34 localhost chat[7387]: ATD*99***1#^M^M Jan 7 15:45:34 localhost chat[7387]: CONNECT Jan 7 15:45:34 localhost chat[7387]: -- got it Jan 7 15:45:34 localhost chat[7387]: send (^M) Jan 7 15:45:34 localhost pppd[7386]: Serial connection established. Jan 7 15:45:34 localhost pppd[7386]: using channel 1 Jan 7 15:45:34 localhost pppd[7386]: Using interface ppp0 Jan 7 15:45:34 localhost pppd[7386]: Connect: ppp0 <--> /dev/ttyS2 Jan 7 15:45:35 localhost pppd[7386]: sent [LCP ConfReq id=0x1 <asyncmap 0xa0000> <magic 0x69009317> <pcomp> <accomp>] Jan 7 15:45:35 localhost pppd[7386]: rcvd [LCP ConfReq id=0x0 <asyncmap 0x0> <auth chap MD5> <magic 0x4013ac6> <pcomp> <accomp>] Jan 7 15:45:35 localhost pppd[7386]: sent [LCP ConfAck id=0x0 <asyncmap 0x0> <auth chap MD5> <magic 0x4013ac6> <pcomp> <accomp>] Jan 7 15:45:35 localhost pppd[7386]: rcvd [LCP ConfAck id=0x1 <asyncmap 0xa0000> <magic 0x69009317> <pcomp> <accomp>] Jan 7 15:45:35 localhost pppd[7386]: rcvd [LCP DiscReq id=0x1 magic=0x4013ac6] Jan 7 15:45:35 localhost pppd[7386]: rcvd [CHAP Challenge id=0x1 <fe8845370af824b6f2b51835183e51e9>, name = "UMTS_CHAP_SRVR"] Jan 7 15:45:35 localhost pppd[7386]: sent [CHAP Response id=0x1 <ca4916ec88fcd9f57c4cdcd71a2f1320>, name = "MOVISTAR"] Jan 7 15:45:35 localhost pppd[7386]: rcvd [CHAP Success id=0x1 ""] Jan 7 15:45:35 localhost pppd[7386]: CHAP authentication succeeded Jan 7 15:45:35 localhost pppd[7386]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns3 0.0.0.0>] Jan 7 15:45:35 localhost pppd[7386]: rcvd [IPCP ConfNak id=0x1 <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14>] Jan 7 15:45:35 localhost pppd[7386]: sent [IPCP ConfReq id=0x2 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14>] Jan 7 15:45:36 localhost pppd[7386]: rcvd [IPCP ConfNak id=0x2 <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14>] Jan 7 15:45:36 localhost pppd[7386]: sent [IPCP ConfReq id=0x3 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14>] Jan 7 15:45:37 localhost pppd[7386]: rcvd [IPCP ConfNak id=0x3 <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14>] Jan 7 15:45:37 localhost pppd[7386]: sent [IPCP ConfReq id=0x4 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14>] Jan 7 15:45:38 localhost pppd[7386]: rcvd [IPCP ConfReq id=0x2] Jan 7 15:45:38 localhost pppd[7386]: sent [IPCP ConfNak id=0x2 <addr 0.0.0.0>] Jan 7 15:45:38 localhost pppd[7386]: rcvd [IPCP ConfNak id=0x4 <addr 213.4.177.99> <ms-dns1 194.179.1.100> <ms-dns3 194.179.1.101>] Jan 7 15:45:38 localhost pppd[7386]: sent [IPCP ConfReq id=0x5 <addr 213.4.177.99> <ms-dns1 194.179.1.100> <ms-dns3 194.179.1.101>] Jan 7 15:45:38 localhost pppd[7386]: rcvd [IPCP ConfAck id=0x5 <addr 213.4.177.99> <ms-dns1 194.179.1.100> <ms-dns3 194.179.1.101>] Jan 7 15:45:39 localhost pppd[7386]: rcvd [IPCP ConfReq id=0x3] Jan 7 15:45:39 localhost pppd[7386]: sent [IPCP ConfAck id=0x3] Jan 7 15:45:39 localhost pppd[7386]: Could not determine remote IP address: defaulting to 10.64.64.64 Jan 7 15:45:39 localhost pppd[7386]: local IP address 213.4.177.99 Jan 7 15:45:39 localhost pppd[7386]: remote IP address 10.64.64.64 Jan 7 15:45:39 localhost pppd[7386]: primary DNS address 194.179.1.100 Jan 7 15:45:39 localhost pppd[7386]: secondary DNS address 194.179.1.101 Jan 7 15:45:39 localhost pppd[7386]: Script /etc/ppp/ip-up started (pid 7400) Jan 7 15:45:39 localhost pppd[7386]: Script /etc/ppp/ip-up finished (pid 7400), status = 0x1 This is a cut from /var/log/messages on 2.6.12-r10 sources from gentoo (WORKING): Jan 7 15:52:39 localhost Yenta: CardBus bridge found at 0000:00:0d.0 [414e:454c] Jan 7 15:52:39 localhost Yenta: Enabling burst memory read transactions Jan 7 15:52:39 localhost Yenta: Using CSCINT to route CSC interrupts to PCI Jan 7 15:52:39 localhost Yenta: Routing CardBus interrupts to PCI Jan 7 15:52:39 localhost Yenta TI: socket 0000:00:0d.0, mfunc 0x00c00d02, devctl 0x42 Jan 7 15:52:40 localhost Yenta: ISA IRQ mask 0x0000, PCI irq 217 Jan 7 15:52:40 localhost Socket status: 30000006 Jan 7 15:52:40 localhost PCI: Enabling device 0000:00:0d.1 (0000 -> 0002) Jan 7 15:52:40 localhost ACPI: PCI Interrupt 0000:00:0d.1[A] -> GSI 18 (level, low) -> IRQ 217 Jan 7 15:52:40 localhost Yenta: CardBus bridge found at 0000:00:0d.1 [414e:454c] Jan 7 15:52:40 localhost Yenta: Using CSCINT to route CSC interrupts to PCI Jan 7 15:52:40 localhost Yenta: Routing CardBus interrupts to PCI Jan 7 15:52:40 localhost Yenta TI: socket 0000:00:0d.1, mfunc 0x00c00d02, devctl 0x42 Jan 7 15:52:40 localhost Yenta: ISA IRQ mask 0x0000, PCI irq 217 Jan 7 15:52:40 localhost Socket status: 30000006 Jan 7 15:52:40 localhost cardmgr[7598]: watching 2 sockets Jan 7 15:53:43 localhost cs: memory probe 0x0c0000-0x0fffff: excluding 0xc0000-0xdbfff 0xe0000-0xfffff Jan 7 15:53:43 localhost cardmgr[7599]: socket 1: Serial or Modem Jan 7 15:53:44 localhost ttyS2 at I/O 0x3e8 (irq = 217) is a 16550A Jan 7 15:53:58 localhost pppd[8128]: pppd 2.4.2 started by root, uid 0 Jan 7 15:53:59 localhost chat[8129]: timeout set to 5 seconds Jan 7 15:53:59 localhost chat[8129]: abort on (\nBUSY\r) Jan 7 15:53:59 localhost chat[8129]: abort on (\nERROR\r) Jan 7 15:53:59 localhost chat[8129]: abort on (\nNO ANSWER\r) Jan 7 15:53:59 localhost chat[8129]: abort on (\nNO CARRIER\r) Jan 7 15:53:59 localhost chat[8129]: abort on (\nNO DIALTONE\r) Jan 7 15:53:59 localhost chat[8129]: abort on (\nRINGING\r\n\r\nRINGING\r) Jan 7 15:53:59 localhost chat[8129]: send (^MAT^M) Jan 7 15:53:59 localhost chat[8129]: timeout set to 5 seconds Jan 7 15:53:59 localhost chat[8129]: expect (OK) Jan 7 15:53:59 localhost chat[8129]: AT^M^M Jan 7 15:53:59 localhost chat[8129]: OK Jan 7 15:53:59 localhost chat[8129]: -- got it Jan 7 15:53:59 localhost chat[8129]: send (ATE1^M) Jan 7 15:53:59 localhost chat[8129]: expect (OK) Jan 7 15:53:59 localhost chat[8129]: ^M Jan 7 15:53:59 localhost chat[8129]: ATE1^M^M Jan 7 15:53:59 localhost chat[8129]: OK Jan 7 15:53:59 localhost chat[8129]: -- got it Jan 7 15:53:59 localhost chat[8129]: send (AT+cgdcont=1,"IP","movistar.es"^M) Jan 7 15:54:00 localhost chat[8129]: expect (OK) Jan 7 15:54:00 localhost chat[8129]: ^M Jan 7 15:54:00 localhost chat[8129]: AT+cgdcont=1,"IP","movistar.es"^M^M Jan 7 15:54:00 localhost chat[8129]: OK Jan 7 15:54:00 localhost chat[8129]: -- got it Jan 7 15:54:00 localhost chat[8129]: send (ATD*99***1#^M) Jan 7 15:54:00 localhost chat[8129]: expect (CONNECT) Jan 7 15:54:00 localhost chat[8129]: ^M Jan 7 15:54:00 localhost chat[8129]: ATD*99***1#^M^M Jan 7 15:54:00 localhost chat[8129]: CONNECT Jan 7 15:54:00 localhost chat[8129]: -- got it Jan 7 15:54:00 localhost chat[8129]: send (^M) Jan 7 15:54:00 localhost pppd[8128]: Serial connection established. Jan 7 15:54:00 localhost pppd[8128]: using channel 1 Jan 7 15:54:00 localhost pppd[8128]: Using interface ppp0 Jan 7 15:54:00 localhost pppd[8128]: Connect: ppp0 <--> /dev/ttyS2 Jan 7 15:54:01 localhost pppd[8128]: sent [LCP ConfReq id=0x1 <asyncmap 0xa0000> <magic 0xae4bc118> <pcomp> <accomp>] Jan 7 15:54:01 localhost pppd[8128]: rcvd [LCP ConfReq id=0x0 <asyncmap 0x0> <auth chap MD5> <magic 0x4013193> <pcomp> <accomp>] Jan 7 15:54:01 localhost pppd[8128]: sent [LCP ConfAck id=0x0 <asyncmap 0x0> <auth chap MD5> <magic 0x4013193> <pcomp> <accomp>] Jan 7 15:54:01 localhost pppd[8128]: rcvd [LCP ConfAck id=0x1 <asyncmap 0xa0000> <magic 0xae4bc118> <pcomp> <accomp>] Jan 7 15:54:01 localhost pppd[8128]: rcvd [LCP DiscReq id=0x1 magic=0x4013193] Jan 7 15:54:01 localhost pppd[8128]: rcvd [CHAP Challenge id=0x1 <14c92ce61ab64586d4a9b64a9ec3471e>, name = "UMTS_CHAP_SRVR"] Jan 7 15:54:01 localhost pppd[8128]: sent [CHAP Response id=0x1 <821c4d047d706ebbfba912f54706e1df>, name = "MOVISTAR"] Jan 7 15:54:01 localhost pppd[8128]: rcvd [CHAP Success id=0x1 ""] Jan 7 15:54:01 localhost pppd[8128]: CHAP authentication succeeded Jan 7 15:54:01 localhost pppd[8128]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns3 0.0.0.0>] Jan 7 15:54:02 localhost pppd[8128]: rcvd [IPCP ConfNak id=0x1 <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14>] Jan 7 15:54:02 localhost pppd[8128]: sent [IPCP ConfReq id=0x2 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14>] Jan 7 15:54:03 localhost pppd[8128]: rcvd [IPCP ConfNak id=0x2 <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14>] Jan 7 15:54:03 localhost pppd[8128]: sent [IPCP ConfReq id=0x3 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14>] Jan 7 15:54:04 localhost pppd[8128]: rcvd [IPCP ConfNak id=0x3 <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14>] Jan 7 15:54:04 localhost pppd[8128]: sent [IPCP ConfReq id=0x4 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14>] Jan 7 15:54:05 localhost pppd[8128]: rcvd [IPCP ConfReq id=0x2] Jan 7 15:54:05 localhost pppd[8128]: sent [IPCP ConfNak id=0x2 <addr 0.0.0.0>] Jan 7 15:54:05 localhost pppd[8128]: rcvd [IPCP ConfNak id=0x4 <addr 213.4.187.73> <ms-dns1 194.179.1.100> <ms-dns3 194.179.1.101>] Jan 7 15:54:05 localhost pppd[8128]: sent [IPCP ConfReq id=0x5 <addr 213.4.187.73> <ms-dns1 194.179.1.100> <ms-dns3 194.179.1.101>] Jan 7 15:54:05 localhost pppd[8128]: rcvd [IPCP ConfAck id=0x5 <addr 213.4.187.73> <ms-dns1 194.179.1.100> <ms-dns3 194.179.1.101>] Jan 7 15:54:06 localhost pppd[8128]: rcvd [IPCP ConfReq id=0x3] Jan 7 15:54:06 localhost pppd[8128]: sent [IPCP ConfAck id=0x3] Jan 7 15:54:06 localhost pppd[8128]: Could not determine remote IP address: defaulting to 10.64.64.64 Jan 7 15:54:06 localhost pppd[8128]: local IP address 213.4.187.73 Jan 7 15:54:06 localhost pppd[8128]: remote IP address 10.64.64.64 Jan 7 15:54:06 localhost pppd[8128]: primary DNS address 194.179.1.100 Jan 7 15:54:06 localhost pppd[8128]: secondary DNS address 194.179.1.101 Jan 7 15:54:06 localhost pppd[8128]: Script /etc/ppp/ip-up started (pid 8144) Jan 7 15:54:06 localhost pppd[8128]: Script /etc/ppp/ip-up finished (pid 8144), status = 0x1 Steps to reproduce:
The card seems to be sending and receiving OK. I'm wondering if this is a ppp problem? Begin forwarded message: Date: Sat, 7 Jan 2006 08:29:54 -0800 From: bugme-daemon@bugzilla.kernel.org To: bugme-new@lists.osdl.org Subject: [Bugme-new] [Bug 5848] New: pcmcia novatel merlin u530 not working properly on 2.6.13 and up http://bugzilla.kernel.org/show_bug.cgi?id=5848 Summary: pcmcia novatel merlin u530 not working properly on 2.6.13 and up Kernel Version: 2.6.13, 2.6.14(, 2.6.15?) Status: NEW Severity: normal Owner: linux-pcmcia@lists.infradead.org Submitter: oxiroxt@123mail.org Most recent kernel where this bug did not occur: 2.6.12 Distribution: Gentoo Linux AMD64 Hardware Environment: Athlon64, asus k8v deluxe, pcmcia/pci bridge, Novatel Merlin u530 Software Environment: gcc 3.4.4-r1, binutils 2.16.1, pcmcia-cs 3.2.8-r2 Problem Description: Novatel Merlin u530 is a gprs/umts(3g) pcmcia card. When i insert the card, its mapped as ttyS2. Then i pon gprs(a script which works for my isp) and it DOES establish a connection, BUT it will start working at 1Kbps and in a matter of few seconds, decrease until reaching 0Bs. The connection isnt hung up, but it wont work anymore. My guess is that this bug might be related somehow with http://bugzilla.kernel.org/show_bug.cgi?id=5569 and http://bugzilla.kernel.org/show_bug.cgi?id=5678 . But just my guess. This is a cut from /var/log/messages on 2.6.14.5 sources from kernel.org (NON_WORKING): Jan 7 15:44:41 localhost Yenta: CardBus bridge found at 0000:00:0d.0 [414e:454c] Jan 7 15:44:41 localhost Yenta: Enabling burst memory read transactions Jan 7 15:44:41 localhost Yenta: Using CSCINT to route CSC interrupts to PCI Jan 7 15:44:41 localhost Yenta: Routing CardBus interrupts to PCI Jan 7 15:44:41 localhost Yenta TI: socket 0000:00:0d.0, mfunc 0x00c00d02, devctl 0x42 Jan 7 15:44:41 localhost Yenta: ISA IRQ mask 0x0000, PCI irq 169 Jan 7 15:44:41 localhost Socket status: 30000006 Jan 7 15:44:41 localhost ACPI: PCI Interrupt 0000:00:0d.1[A] -> GSI 18 (level, low) -> IRQ 169 Jan 7 15:44:41 localhost Yenta: CardBus bridge found at 0000:00:0d.1 [414e:454c] Jan 7 15:44:41 localhost Yenta: Using CSCINT to route CSC interrupts to PCI Jan 7 15:44:41 localhost Yenta: Routing CardBus interrupts to PCI Jan 7 15:44:41 localhost Yenta TI: socket 0000:00:0d.1, mfunc 0x00c00d02, devctl 0x42 Jan 7 15:44:42 localhost Yenta: ISA IRQ mask 0x0000, PCI irq 169 Jan 7 15:44:42 localhost Socket status: 30000006 Jan 7 15:44:42 localhost ds: ds_open(socket 0) Jan 7 15:44:42 localhost pcmcia: Detected deprecated PCMCIA ioctl usage. Jan 7 15:44:42 localhost pcmcia: This interface will soon be removed from the kernel; please expect breakage unless you upgrade to new tools. Jan 7 15:44:42 localhost pcmcia: see http://www.kernel.org/pub/linux/utils/kernel/pcmcia/pcmcia.html for details. Jan 7 15:44:42 localhost ds: ds_open(socket 1) Jan 7 15:44:42 localhost ds: ds_open(socket 2) Jan 7 15:44:42 localhost ds: ds_open(socket 2) Jan 7 15:44:42 localhost cardmgr[7041]: watching 2 sockets Jan 7 15:45:14 localhost cardmgr[7042]: socket 1: Serial or Modem Jan 7 15:45:14 localhost ttyS2 at I/O 0x3e8 (irq = 169) is a 16550A Jan 7 15:45:32 localhost pppd[7386]: pppd 2.4.2 started by root, uid 0 Jan 7 15:45:33 localhost chat[7387]: timeout set to 5 seconds Jan 7 15:45:33 localhost chat[7387]: abort on (\nBUSY\r) Jan 7 15:45:33 localhost chat[7387]: abort on (\nERROR\r) Jan 7 15:45:33 localhost chat[7387]: abort on (\nNO ANSWER\r) Jan 7 15:45:33 localhost chat[7387]: abort on (\nNO CARRIER\r) Jan 7 15:45:33 localhost chat[7387]: abort on (\nNO DIALTONE\r) Jan 7 15:45:33 localhost chat[7387]: abort on (\nRINGING\r\n\r\nRINGING\r) Jan 7 15:45:33 localhost chat[7387]: send (^MAT^M) Jan 7 15:45:33 localhost chat[7387]: timeout set to 5 seconds Jan 7 15:45:33 localhost chat[7387]: expect (OK) Jan 7 15:45:33 localhost chat[7387]: AT^M^M Jan 7 15:45:33 localhost chat[7387]: OK Jan 7 15:45:33 localhost chat[7387]: -- got it Jan 7 15:45:33 localhost chat[7387]: send (ATE1^M) Jan 7 15:45:33 localhost chat[7387]: expect (OK) Jan 7 15:45:33 localhost chat[7387]: ^M Jan 7 15:45:33 localhost chat[7387]: ATE1^M^M Jan 7 15:45:33 localhost chat[7387]: OK Jan 7 15:45:33 localhost chat[7387]: -- got it Jan 7 15:45:33 localhost chat[7387]: send (AT+cgdcont=1,"IP","movistar.es"^M) Jan 7 15:45:34 localhost chat[7387]: expect (OK) Jan 7 15:45:34 localhost chat[7387]: ^M Jan 7 15:45:34 localhost chat[7387]: AT+cgdcont=1,"IP","movistar.es"^M^M Jan 7 15:45:34 localhost chat[7387]: OK Jan 7 15:45:34 localhost chat[7387]: -- got it Jan 7 15:45:34 localhost chat[7387]: send (ATD*99***1#^M) Jan 7 15:45:34 localhost chat[7387]: expect (CONNECT) Jan 7 15:45:34 localhost chat[7387]: ^M Jan 7 15:45:34 localhost chat[7387]: ATD*99***1#^M^M Jan 7 15:45:34 localhost chat[7387]: CONNECT Jan 7 15:45:34 localhost chat[7387]: -- got it Jan 7 15:45:34 localhost chat[7387]: send (^M) Jan 7 15:45:34 localhost pppd[7386]: Serial connection established. Jan 7 15:45:34 localhost pppd[7386]: using channel 1 Jan 7 15:45:34 localhost pppd[7386]: Using interface ppp0 Jan 7 15:45:34 localhost pppd[7386]: Connect: ppp0 <--> /dev/ttyS2 Jan 7 15:45:35 localhost pppd[7386]: sent [LCP ConfReq id=0x1 <asyncmap 0xa0000> <magic 0x69009317> <pcomp> <accomp>] Jan 7 15:45:35 localhost pppd[7386]: rcvd [LCP ConfReq id=0x0 <asyncmap 0x0> <auth chap MD5> <magic 0x4013ac6> <pcomp> <accomp>] Jan 7 15:45:35 localhost pppd[7386]: sent [LCP ConfAck id=0x0 <asyncmap 0x0> <auth chap MD5> <magic 0x4013ac6> <pcomp> <accomp>] Jan 7 15:45:35 localhost pppd[7386]: rcvd [LCP ConfAck id=0x1 <asyncmap 0xa0000> <magic 0x69009317> <pcomp> <accomp>] Jan 7 15:45:35 localhost pppd[7386]: rcvd [LCP DiscReq id=0x1 magic=0x4013ac6] Jan 7 15:45:35 localhost pppd[7386]: rcvd [CHAP Challenge id=0x1 <fe8845370af824b6f2b51835183e51e9>, name = "UMTS_CHAP_SRVR"] Jan 7 15:45:35 localhost pppd[7386]: sent [CHAP Response id=0x1 <ca4916ec88fcd9f57c4cdcd71a2f1320>, name = "MOVISTAR"] Jan 7 15:45:35 localhost pppd[7386]: rcvd [CHAP Success id=0x1 ""] Jan 7 15:45:35 localhost pppd[7386]: CHAP authentication succeeded Jan 7 15:45:35 localhost pppd[7386]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns3 0.0.0.0>] Jan 7 15:45:35 localhost pppd[7386]: rcvd [IPCP ConfNak id=0x1 <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14>] Jan 7 15:45:35 localhost pppd[7386]: sent [IPCP ConfReq id=0x2 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14>] Jan 7 15:45:36 localhost pppd[7386]: rcvd [IPCP ConfNak id=0x2 <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14>] Jan 7 15:45:36 localhost pppd[7386]: sent [IPCP ConfReq id=0x3 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14>] Jan 7 15:45:37 localhost pppd[7386]: rcvd [IPCP ConfNak id=0x3 <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14>] Jan 7 15:45:37 localhost pppd[7386]: sent [IPCP ConfReq id=0x4 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14>] Jan 7 15:45:38 localhost pppd[7386]: rcvd [IPCP ConfReq id=0x2] Jan 7 15:45:38 localhost pppd[7386]: sent [IPCP ConfNak id=0x2 <addr 0.0.0.0>] Jan 7 15:45:38 localhost pppd[7386]: rcvd [IPCP ConfNak id=0x4 <addr 213.4.177.99> <ms-dns1 194.179.1.100> <ms-dns3 194.179.1.101>] Jan 7 15:45:38 localhost pppd[7386]: sent [IPCP ConfReq id=0x5 <addr 213.4.177.99> <ms-dns1 194.179.1.100> <ms-dns3 194.179.1.101>] Jan 7 15:45:38 localhost pppd[7386]: rcvd [IPCP ConfAck id=0x5 <addr 213.4.177.99> <ms-dns1 194.179.1.100> <ms-dns3 194.179.1.101>] Jan 7 15:45:39 localhost pppd[7386]: rcvd [IPCP ConfReq id=0x3] Jan 7 15:45:39 localhost pppd[7386]: sent [IPCP ConfAck id=0x3] Jan 7 15:45:39 localhost pppd[7386]: Could not determine remote IP address: defaulting to 10.64.64.64 Jan 7 15:45:39 localhost pppd[7386]: local IP address 213.4.177.99 Jan 7 15:45:39 localhost pppd[7386]: remote IP address 10.64.64.64 Jan 7 15:45:39 localhost pppd[7386]: primary DNS address 194.179.1.100 Jan 7 15:45:39 localhost pppd[7386]: secondary DNS address 194.179.1.101 Jan 7 15:45:39 localhost pppd[7386]: Script /etc/ppp/ip-up started (pid 7400) Jan 7 15:45:39 localhost pppd[7386]: Script /etc/ppp/ip-up finished (pid 7400), status = 0x1 This is a cut from /var/log/messages on 2.6.12-r10 sources from gentoo (WORKING): Jan 7 15:52:39 localhost Yenta: CardBus bridge found at 0000:00:0d.0 [414e:454c] Jan 7 15:52:39 localhost Yenta: Enabling burst memory read transactions Jan 7 15:52:39 localhost Yenta: Using CSCINT to route CSC interrupts to PCI Jan 7 15:52:39 localhost Yenta: Routing CardBus interrupts to PCI Jan 7 15:52:39 localhost Yenta TI: socket 0000:00:0d.0, mfunc 0x00c00d02, devctl 0x42 Jan 7 15:52:40 localhost Yenta: ISA IRQ mask 0x0000, PCI irq 217 Jan 7 15:52:40 localhost Socket status: 30000006 Jan 7 15:52:40 localhost PCI: Enabling device 0000:00:0d.1 (0000 -> 0002) Jan 7 15:52:40 localhost ACPI: PCI Interrupt 0000:00:0d.1[A] -> GSI 18 (level, low) -> IRQ 217 Jan 7 15:52:40 localhost Yenta: CardBus bridge found at 0000:00:0d.1 [414e:454c] Jan 7 15:52:40 localhost Yenta: Using CSCINT to route CSC interrupts to PCI Jan 7 15:52:40 localhost Yenta: Routing CardBus interrupts to PCI Jan 7 15:52:40 localhost Yenta TI: socket 0000:00:0d.1, mfunc 0x00c00d02, devctl 0x42 Jan 7 15:52:40 localhost Yenta: ISA IRQ mask 0x0000, PCI irq 217 Jan 7 15:52:40 localhost Socket status: 30000006 Jan 7 15:52:40 localhost cardmgr[7598]: watching 2 sockets Jan 7 15:53:43 localhost cs: memory probe 0x0c0000-0x0fffff: excluding 0xc0000-0xdbfff 0xe0000-0xfffff Jan 7 15:53:43 localhost cardmgr[7599]: socket 1: Serial or Modem Jan 7 15:53:44 localhost ttyS2 at I/O 0x3e8 (irq = 217) is a 16550A Jan 7 15:53:58 localhost pppd[8128]: pppd 2.4.2 started by root, uid 0 Jan 7 15:53:59 localhost chat[8129]: timeout set to 5 seconds Jan 7 15:53:59 localhost chat[8129]: abort on (\nBUSY\r) Jan 7 15:53:59 localhost chat[8129]: abort on (\nERROR\r) Jan 7 15:53:59 localhost chat[8129]: abort on (\nNO ANSWER\r) Jan 7 15:53:59 localhost chat[8129]: abort on (\nNO CARRIER\r) Jan 7 15:53:59 localhost chat[8129]: abort on (\nNO DIALTONE\r) Jan 7 15:53:59 localhost chat[8129]: abort on (\nRINGING\r\n\r\nRINGING\r) Jan 7 15:53:59 localhost chat[8129]: send (^MAT^M) Jan 7 15:53:59 localhost chat[8129]: timeout set to 5 seconds Jan 7 15:53:59 localhost chat[8129]: expect (OK) Jan 7 15:53:59 localhost chat[8129]: AT^M^M Jan 7 15:53:59 localhost chat[8129]: OK Jan 7 15:53:59 localhost chat[8129]: -- got it Jan 7 15:53:59 localhost chat[8129]: send (ATE1^M) Jan 7 15:53:59 localhost chat[8129]: expect (OK) Jan 7 15:53:59 localhost chat[8129]: ^M Jan 7 15:53:59 localhost chat[8129]: ATE1^M^M Jan 7 15:53:59 localhost chat[8129]: OK Jan 7 15:53:59 localhost chat[8129]: -- got it Jan 7 15:53:59 localhost chat[8129]: send (AT+cgdcont=1,"IP","movistar.es"^M) Jan 7 15:54:00 localhost chat[8129]: expect (OK) Jan 7 15:54:00 localhost chat[8129]: ^M Jan 7 15:54:00 localhost chat[8129]: AT+cgdcont=1,"IP","movistar.es"^M^M Jan 7 15:54:00 localhost chat[8129]: OK Jan 7 15:54:00 localhost chat[8129]: -- got it Jan 7 15:54:00 localhost chat[8129]: send (ATD*99***1#^M) Jan 7 15:54:00 localhost chat[8129]: expect (CONNECT) Jan 7 15:54:00 localhost chat[8129]: ^M Jan 7 15:54:00 localhost chat[8129]: ATD*99***1#^M^M Jan 7 15:54:00 localhost chat[8129]: CONNECT Jan 7 15:54:00 localhost chat[8129]: -- got it Jan 7 15:54:00 localhost chat[8129]: send (^M) Jan 7 15:54:00 localhost pppd[8128]: Serial connection established. Jan 7 15:54:00 localhost pppd[8128]: using channel 1 Jan 7 15:54:00 localhost pppd[8128]: Using interface ppp0 Jan 7 15:54:00 localhost pppd[8128]: Connect: ppp0 <--> /dev/ttyS2 Jan 7 15:54:01 localhost pppd[8128]: sent [LCP ConfReq id=0x1 <asyncmap 0xa0000> <magic 0xae4bc118> <pcomp> <accomp>] Jan 7 15:54:01 localhost pppd[8128]: rcvd [LCP ConfReq id=0x0 <asyncmap 0x0> <auth chap MD5> <magic 0x4013193> <pcomp> <accomp>] Jan 7 15:54:01 localhost pppd[8128]: sent [LCP ConfAck id=0x0 <asyncmap 0x0> <auth chap MD5> <magic 0x4013193> <pcomp> <accomp>] Jan 7 15:54:01 localhost pppd[8128]: rcvd [LCP ConfAck id=0x1 <asyncmap 0xa0000> <magic 0xae4bc118> <pcomp> <accomp>] Jan 7 15:54:01 localhost pppd[8128]: rcvd [LCP DiscReq id=0x1 magic=0x4013193] Jan 7 15:54:01 localhost pppd[8128]: rcvd [CHAP Challenge id=0x1 <14c92ce61ab64586d4a9b64a9ec3471e>, name = "UMTS_CHAP_SRVR"] Jan 7 15:54:01 localhost pppd[8128]: sent [CHAP Response id=0x1 <821c4d047d706ebbfba912f54706e1df>, name = "MOVISTAR"] Jan 7 15:54:01 localhost pppd[8128]: rcvd [CHAP Success id=0x1 ""] Jan 7 15:54:01 localhost pppd[8128]: CHAP authentication succeeded Jan 7 15:54:01 localhost pppd[8128]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns3 0.0.0.0>] Jan 7 15:54:02 localhost pppd[8128]: rcvd [IPCP ConfNak id=0x1 <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14>] Jan 7 15:54:02 localhost pppd[8128]: sent [IPCP ConfReq id=0x2 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14>] Jan 7 15:54:03 localhost pppd[8128]: rcvd [IPCP ConfNak id=0x2 <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14>] Jan 7 15:54:03 localhost pppd[8128]: sent [IPCP ConfReq id=0x3 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14>] Jan 7 15:54:04 localhost pppd[8128]: rcvd [IPCP ConfNak id=0x3 <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14>] Jan 7 15:54:04 localhost pppd[8128]: sent [IPCP ConfReq id=0x4 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14>] Jan 7 15:54:05 localhost pppd[8128]: rcvd [IPCP ConfReq id=0x2] Jan 7 15:54:05 localhost pppd[8128]: sent [IPCP ConfNak id=0x2 <addr 0.0.0.0>] Jan 7 15:54:05 localhost pppd[8128]: rcvd [IPCP ConfNak id=0x4 <addr 213.4.187.73> <ms-dns1 194.179.1.100> <ms-dns3 194.179.1.101>] Jan 7 15:54:05 localhost pppd[8128]: sent [IPCP ConfReq id=0x5 <addr 213.4.187.73> <ms-dns1 194.179.1.100> <ms-dns3 194.179.1.101>] Jan 7 15:54:05 localhost pppd[8128]: rcvd [IPCP ConfAck id=0x5 <addr 213.4.187.73> <ms-dns1 194.179.1.100> <ms-dns3 194.179.1.101>] Jan 7 15:54:06 localhost pppd[8128]: rcvd [IPCP ConfReq id=0x3] Jan 7 15:54:06 localhost pppd[8128]: sent [IPCP ConfAck id=0x3] Jan 7 15:54:06 localhost pppd[8128]: Could not determine remote IP address: defaulting to 10.64.64.64 Jan 7 15:54:06 localhost pppd[8128]: local IP address 213.4.187.73 Jan 7 15:54:06 localhost pppd[8128]: remote IP address 10.64.64.64 Jan 7 15:54:06 localhost pppd[8128]: primary DNS address 194.179.1.100 Jan 7 15:54:06 localhost pppd[8128]: secondary DNS address 194.179.1.101 Jan 7 15:54:06 localhost pppd[8128]: Script /etc/ppp/ip-up started (pid 8144) Jan 7 15:54:06 localhost pppd[8128]: Script /etc/ppp/ip-up finished (pid 8144), status = 0x1 Steps to reproduce: ------- You are receiving this mail because: ------- You are on the CC list for the bug, or are watching someone who is.
Probably. What info do you need to check this out please? Sorry if the problem didnt fit here :/
Now i think about it... I got to use a gprs connection over bluetooth on 2.6.14. It was sustaining around 3-5kbps and worked ok all the time. But this isnt a solution, gprs sucks and my phone isnt 3g :( Then i guess its not ppp related.
OK, the IRQ routing seems to have changed... could you try booting with "noapic", please?
Behaves exactly the same.
Can you create attachments with the output of cat /proc/iomem /proc/ioports /proc/interrupts for the working and the non-working case, please?
Created attachment 7011 [details] Winterrupts.txt
Created attachment 7012 [details] Wiomem.txt
Created attachment 7013 [details] Wioports.txt
Created attachment 7014 [details] NWinterrupts.txt
Created attachment 7015 [details] NWiomem.txt
Created attachment 7016 [details] NWioports.txt
There we go I cat'ed them after a connection was made. Dunno if that matters. W prefix stands for Working and NW for Non-Working.
the resources _except IRQs_ seem to be set up just well... strange. The serial port on the card even gets the same resource, even some things "outside" do change. So, I'd like to make sure that the IRQ assignements aren't the cause for this trouble. x86-64 experts: _how_ can we force the IRQ setting to behave like it did for 2.6.12?
Might this be a serial port configuration issue? Back at my last workplace we tested a couple of those (and similar 8250_pci) cards and the general results were rather disappointing. Those cards come with a 16550A that Linux usually configures for 115200, but most of them can (and do) handle much more than that. I seem to recall that the problem looked like a buffer overrun -- we would get the cards to run at ~ 20 kB/s UMTS download for a couple of seconds, then stall, and sometimes get back to a fluctuating 5-15 kB/s, and sometimes not. When only GPRS was used, the card was much more stable (sustained 4-5 kB/s), though occasional hiccups occured. We initially suspected hardware, but we got to run the cards on the same machine with Windows XP, and voila, 33-36 kB/s sustained download rate. It might be that we simply couldn't configure the cards properly (if there really is _the right way_ to configure serial ports faster than 115200 it *really* needs proper docs), but my experience with similar hardware (8250_pci GPRS/UMTS modems, serial_cs 3Com Bluetooth PC Card that advertises a 16C950) seems to suggest that Linux's support for fast serial ports is just lousy and you will run into problems if you can't limit the rate properly (read: GPRS). Okay, enough ranting, oxiroxt, is the problem less visible if you just use GPRS and no UMTS? Checking with recent 2.6.16-rc kernels might be worth trying, as some patches were merged that might be relevant to this issue.
Reply-To: Kiran_Thota@pmc-sierra.com I am on vacation till March 15th. Please contact my manager Vineet Dujari email: vineet_dujari@pmc-sierra.com.
The same problem was here on gentoo linux pentium IV (kernel 2.6.13 2.6.14 and 2.6.15, both gentoo-patched and vanilla, pcmcia-cs or pcmciautils and pcmcia-cs-cis). Howewer i'm happy to announce that with kernel 2.6.16-rc4 the problem was fixed and the linux driver performs better then xxxdows and flyes over 40 Kbytes/s without stalling. I'm just curious to know the new patches in order to apply them to older versions couse some other external kernel modules does not compile yet now..
I meant this specifically: http://kernel.org/git/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commit;h=33f0f88f1c51ae5c2d593d26960c760ea154c2e2 Yet since I don't have the card at hand, I can't confirm if it's really the patch that fixes it (especially that my Bluetooth card still doesn't seem to work faster than 115200 on 2.6.16-rc2, but that might be another problem). For reference, could you paste your serial port configuration? Anything that sets the port's speed would be relevant, including statements in /etc/ppp/*
I have no special serial configuration. Simply i have the following ppp options: /dev/ttyS1 460800 connect "/usr/sbin/chat -f '/etc/ppp/tim.chat'" name tim remotename umts linkname tim defaultroute noipdefault novj usepeerdns asyncmap 0 lock modem lcp-echo-interval 30 lcp-echo-failure 4 idle 300 the following (i think unuseful) is tim.chat "" ATZ OK\r\n AT+CGDCONT=1,"IP","ibox.tim.it" OK\r\n ATDT*99***1# CONNECT "" \r\n
And "/dev/ttyS1 460800" is all you do to get that speed? There's no setserial magic involved?
Yes! i have no setserial package emerged. I retested some minutes ago, with http over a tgz file, (last test was on a rsync transfer of plain text data) and my download rate was 45.5 Kbytes/sec. Due this rate is near my ppp speed settings i tryed it at 921600, the average was always about 45Kbytes/sec but and sometimes i reached 55Kbytes/sec, i think i reached my umts bandwidth. (off topic: With this speed i can spend about 9 euro/minute :(((( )
I can confirm that bug does exist in kernels 2.6.12, 2.6.13 and 2.6.15 (specifically binary 2.6.15-1-686 from Debian testing) and that was not present in kernel 2.6.8 (binary from Debian stable). I've no problem with GPRS/UMTS connection establishing, but resulting bandwith is very limited due to RX packets errors as you can see: # ifconfig ppp0 ppp0 Link encap:Point-to-Point Protocol inet addr:10.114.0.26 P-t-P:62.13.164.101 Mask:255.255.255.255 UP POINTOPOINT RUNNING NOARP MULTICAST MTU:1500 Metric:1 RX packets:2518 errors:757 dropped:0 overruns:0 frame:0 TX packets:2544 errors:0 dropped:0 overruns:0 carrier:0 collisions:0 txqueuelen:3 RX bytes:2349574 (2.2 MiB) TX bytes:249919 (244.0 KiB)
So, do I understand it correctly that using "setserial" properly solves this bug? If so, can we close it?
You also need a recent kernel, I guess (but I no longer have the card to verify this).
As suggested from Nicola Ranaldo, I'm now running a 2.6.16-rc4 and this bug is solved. setserial was not useful with bugged kernels.