Weird modem behaviour in 2.5.73-mm1

Weird modem behaviour in 2.5.73-mm1

[ismail (cartman) donmez]

Hi All,

First I did not tried 2.5.73 vanilla so this can be a bug in 2.5.73 itself . 
When I use my 56k modem to connect to internet it always hang up 5-6 minutes 
( sometimes like 1-2 minutes ) later. I checked with 2.5.72-mm1 and I got not 
hang-up whatsoever. I checked system logs and it just says :

[pppd] Modem Hang Up

Anyone noticed this behaviour?


Regards,
/ismail

Re: Weird modem behaviour in 2.5.73-mm1

[Valdis.Kletnieks]

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

On Tue, 24 Jun 2003 21:02:49 +0300, "ismail (cartman) donmez" <kde@myrealbox.com>  said:
> Hi All,
> 
> First I did not tried 2.5.73 vanilla so this can be a bug in 2.5.73 itself . 
> When I use my 56k modem to connect to internet it always hang up 5-6 minutes 
> ( sometimes like 1-2 minutes ) later. I checked with 2.5.72-mm1 and I got not
 
> hang-up whatsoever. I checked system logs and it just says :
> 
> [pppd] Modem Hang Up

2.5.72-mm3 is fine for modem usage for me.

2.5.73-mm1 threw this all 3 times I tried starting PPPD:

Jun 24 22:37:48 turing-police pppd[1144]: Using interface ppp0
Jun 24 22:37:48 turing-police pppd[1144]: Connect: ppp0 <--> /dev/ttyS14
Jun 24 22:37:49 turing-police pppd[1144]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x9ed88e38> <pcomp> <accomp>]
Jun 24 22:37:49 turing-police pppd[1144]: Modem hangup
Jun 24 22:37:49 turing-police pppd[1144]: Connection terminated.

i.e. it died a quick and horrid death.  I've not checked a plain 2.5.73 yet,
but I suspect this is the most likely culprit:

#	           ChangeSet	1.1348.1.42 -> 1.1348.1.43
#	 drivers/net/pppoe.c	1.31    -> 1.32   
#	drivers/net/ppp_generic.c	1.33    -> 1.34   
#
# The following is the BitKeeper ChangeSet Log
# --------------------------------------------
# 03/06/23	shemminger@osdl.org	1.1348.1.43
# [NET]: Convert PPPoE to new style protocol.
# --------------------------------------------

(if only because it's the only changeset that hits ppp_generic.c between
the known good and known bad versions).  If a clean 2.5.73 works, then
reverting this cset is probably the best place to start looking...


[-- Attachment #2: Type: application/pgp-signature, Size: 226 bytes --]

Re: Weird modem behaviour in 2.5.73-mm1

[Valdis.Kletnieks]

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

On Tue, 24 Jun 2003 23:27:57 EDT, Valdis.Kletnieks@vt.edu said:

Reverting this one cset makes the modem work for me under 2.5.73-mm1.
With it in place, pppd hung up before even finishing the option
negotiations.  With it reverted, it's staying up.  There's apparently
something subtly wrong with the part that hits ppp_generic.c, although
I admit not understanding enough to see exactly what.

> #	           ChangeSet	1.1348.1.42 -> 1.1348.1.43
> #	 drivers/net/pppoe.c	1.31    -> 1.32   
> #	drivers/net/ppp_generic.c	1.33    -> 1.34   
> #
> # The following is the BitKeeper ChangeSet Log
> # --------------------------------------------
> # 03/06/23	shemminger@osdl.org	1.1348.1.43
> # [NET]: Convert PPPoE to new style protocol.
> # --------------------------------------------


[-- Attachment #2: Type: application/pgp-signature, Size: 226 bytes --]

Re: Weird modem behaviour in 2.5.73-mm1

[Stephen Hemminger]

On Wed, 25 Jun 2003 00:18:31 -0400
Valdis.Kletnieks@vt.edu wrote:

> On Tue, 24 Jun 2003 23:27:57 EDT, Valdis.Kletnieks@vt.edu said:
> 
> Reverting this one cset makes the modem work for me under 2.5.73-mm1.
> With it in place, pppd hung up before even finishing the option
> negotiations.  With it reverted, it's staying up.  There's apparently
> something subtly wrong with the part that hits ppp_generic.c, although
> I admit not understanding enough to see exactly what.

How far along did pppd get before it hung up?  Was the ppp0 netdevice still
around (ifconfig -a)?  I'll try a dedicated serial line and see if I can reproduce
it.

Re: Weird modem behaviour in 2.5.73-mm1

[ismail (cartman) donmez]

On Wednesday 25 June 2003 19:10, Stephen Hemminger wrote:
> On Wed, 25 Jun 2003 00:18:31 -0400
>
> Valdis.Kletnieks@vt.edu wrote:
> > On Tue, 24 Jun 2003 23:27:57 EDT, Valdis.Kletnieks@vt.edu said:
> >
> > Reverting this one cset makes the modem work for me under 2.5.73-mm1.
> > With it in place, pppd hung up before even finishing the option
> > negotiations.  With it reverted, it's staying up.  There's apparently
> > something subtly wrong with the part that hits ppp_generic.c, although
> > I admit not understanding enough to see exactly what.
>
> How far along did pppd get before it hung up?

For me its random between 1-5 minutes.

Regards,
/ismail

Re: Weird modem behaviour in 2.5.73-mm1

[Valdis.Kletnieks]

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

On Wed, 25 Jun 2003 09:10:13 PDT, Stephen Hemminger said:

> How far along did pppd get before it hung up?  Was the ppp0 netdevice still
> around (ifconfig -a)?  I'll try a dedicated serial line and see if I can reproduce

For me, it didn't even finish negotiating the connection:

Jun 24 22:37:48 turing-police pppd[1144]: Using interface ppp0
Jun 24 22:37:48 turing-police pppd[1144]: Connect: ppp0 <--> /dev/ttyS14
Jun 24 22:37:49 turing-police pppd[1144]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x9ed88e38> <pcomp> <accomp>]
Jun 24 22:37:49 turing-police pppd[1144]: Modem hangup
Jun 24 22:37:49 turing-police pppd[1144]: Connection terminated.

I'm assuming the netdevice was there when it said 'Using interface'.  It was
certainly gone by the time I was able to do ifconfig or 'ip link show' or
anything like that.  ismail reports "several  minutes" - I'm wondering it the
bug is in pskb_may_pull()  being handed an oodd packet-of-death that I receive
during startup but ismail gets later on.  There's comments in the patch about
making sure the decompressor is linear, but in my case the LCP stuff isn't even
negotiating compression.  Uninitialized variable?


[-- Attachment #2: Type: application/pgp-signature, Size: 226 bytes --]

Re: Weird modem behaviour in 2.5.73-mm1

[Wade]

Valdis.Kletnieks@vt.edu wrote:

>On Wed, 25 Jun 2003 09:10:13 PDT, Stephen Hemminger said:
>
>  
>
>>How far along did pppd get before it hung up?  Was the ppp0 netdevice still
>>around (ifconfig -a)?  I'll try a dedicated serial line and see if I can reproduce
>>    
>>
>
>For me, it didn't even finish negotiating the connection:
>  
>
Same here.

>Jun 24 22:37:48 turing-police pppd[1144]: Using interface ppp0
>Jun 24 22:37:48 turing-police pppd[1144]: Connect: ppp0 <--> /dev/ttyS14
>Jun 24 22:37:49 turing-police pppd[1144]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x9ed88e38> <pcomp> <accomp>]
>Jun 24 22:37:49 turing-police pppd[1144]: Modem hangup
>Jun 24 22:37:49 turing-police pppd[1144]: Connection terminated.
>

Same message too.  I tried connecting several times with the same 
results (thought it might
have been the provider).

>I'm assuming the netdevice was there when it said 'Using interface'.  It was
>certainly gone by the time I was able to do ifconfig or 'ip link show' or
>anything like that.  ismail reports "several  minutes" - I'm wondering it the
>bug is in pskb_may_pull()  being handed an oodd packet-of-death that I receive
>during startup but ismail gets later on.  There's comments in the patch about
>making sure the decompressor is linear, but in my case the LCP stuff isn't even
>negotiating compression.  Uninitialized variable?
>
>  
>

Re: Weird modem behaviour in 2.5.73-mm1

[Stephen Hemminger]

Try this patch, it is more paranoid in some of the code paths.
I did get PPP over a null modem cable working between 2.4.18 and 2.5.73 with the PPP patches.

diff -Nru a/drivers/net/ppp_generic.c b/drivers/net/ppp_generic.c
--- a/drivers/net/ppp_generic.c	Wed Jun 25 17:32:29 2003
+++ b/drivers/net/ppp_generic.c	Wed Jun 25 17:32:29 2003
@@ -1448,7 +1448,7 @@
 		if (ppp->vj == 0 || (ppp->flags & SC_REJ_COMP_TCP))
 			goto err;
 
-		if (skb_tailroom(skb) < 124 || skb_is_nonlinear(skb) ) {
+		if (skb_tailroom(skb) < 124) {
 			/* copy to a new sk_buff with more tailroom */
 			ns = dev_alloc_skb(skb->len + 128);
 			if (ns == 0) {
@@ -1459,7 +1459,9 @@
 			memcpy(skb_put(ns, skb->len), skb->data, skb->len);
 			kfree_skb(skb);
 			skb = ns;
-		}
+		} else if (!pskb_may_pull(skb, skb->len)) 
+			goto err;
+
 		len = slhc_uncompress(ppp->vj, skb->data + 2, skb->len - 2);
 		if (len <= 0) {
 			printk(KERN_DEBUG "PPP: VJ decompression error\n");
@@ -2033,11 +2035,15 @@
 static void
 ppp_ccp_peek(struct ppp *ppp, struct sk_buff *skb, int inbound)
 {
-	unsigned char *dp = skb->data + 2;
+	unsigned char *dp;
 	int len;
 
-	if (!pskb_may_pull(skb, CCP_HDRLEN + 2)
-	    || skb->len < (len = CCP_LENGTH(dp)) + 2)
+	if (!pskb_may_pull(skb, CCP_HDRLEN + 2))
+		return;
+
+	dp = skb->data + 2;
+	len = CCP_LENGTH(dp);
+	if (skb->len < len +2)
 		return;		/* too short */
 
 	switch (CCP_CODE(dp)) {

Re: Weird modem behaviour in 2.5.73-mm1

[Valdis.Kletnieks]

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

On Wed, 25 Jun 2003 17:35:49 PDT, Stephen Hemminger said:
> Try this patch, it is more paranoid in some of the code paths.
> I did get PPP over a null modem cable working between 2.4.18 and 2.5.73 with 
the PPP patches.

I wasn't able to get this patch to apply cleanly to either the replacement .c you sent or
to any of the .c's I already had - which version was this based from?

Also, the entire-replacement .c showed the same symptoms of a quick death as
the problem cset from bitkeeper.  Here's some more info:  In the *working* version,
the first few lines logged by 'pppd -d' are:

Jun 27 10:02:28 turing-police pppd[999]: Using interface ppp0
Jun 27 10:02:28 turing-police pppd[999]: Connect: ppp0 <--> /dev/ttyS14
Jun 27 10:02:28 turing-police /etc/hotplug/net.agent: NET add event not supported
Jun 27 10:02:29 turing-police pppd[999]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x7e941686> <pcomp> <accomp>]
Jun 27 10:02:32 turing-police pppd[999]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x7e941686> <pcomp> <accomp>]
(broken version dies here)
Jun 27 10:02:32 turing-police pppd[999]: rcvd [LCP ConfReq id=0xa3 <asyncmap 0xa0000> <auth pap> <magic 0xa55eea11> <pcomp> <accomp>]
Jun 27 10:02:32 turing-police pppd[999]: sent [LCP ConfAck id=0xa3 <asyncmap 0xa0000> <auth pap> <magic 0xa55eea11> <pcomp> <accomp>]
Jun 27 10:02:32 turing-police pppd[999]: rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0x7e941686> <pcomp> <accomp>]

so I'm thinking there's some breakage decoding that next rcvd packet...

My next step is to go through each separate change in the cset that's causing the
problem and apply it, and see which one breaks it.  

[-- Attachment #2: Type: application/pgp-signature, Size: 226 bytes --]

Re: Weird modem behaviour in 2.5.73-mm1

[ismail (cartman) donmez]

On Wednesday 25 June 2003 06:27, you wrote:
> 2.5.73-mm1 threw this all 3 times I tried starting PPPD:
>
> Jun 24 22:37:48 turing-police pppd[1144]: Using interface ppp0
> Jun 24 22:37:48 turing-police pppd[1144]: Connect: ppp0 <--> /dev/ttyS14
> Jun 24 22:37:49 turing-police pppd[1144]: sent [LCP ConfReq id=0x1
> <asyncmap 0x0> <magic 0x9ed88e38> <pcomp> <accomp>] Jun 24 22:37:49
> turing-police pppd[1144]: Modem hangup
> Jun 24 22:37:49 turing-police pppd[1144]: Connection terminated.
>

Yes same messages.

> i.e. it died a quick and horrid death.  I've not checked a plain 2.5.73
> yet, but I suspect this is the most likely culprit:
>
> #	           ChangeSet	1.1348.1.42 -> 1.1348.1.43
> #	 drivers/net/pppoe.c	1.31    -> 1.32
> #	drivers/net/ppp_generic.c	1.33    -> 1.34
> #
> # The following is the BitKeeper ChangeSet Log
> # --------------------------------------------
> # 03/06/23	shemminger@osdl.org	1.1348.1.43
> # [NET]: Convert PPPoE to new style protocol.
> # --------------------------------------------
>

Nice hope its fixed in -mm2

Regards,
/ismail

Re: Weird modem behaviour in 2.5.73-mm1

[Wade]

Valdis.Kletnieks@vt.edu wrote:

>On Tue, 24 Jun 2003 21:02:49 +0300, "ismail (cartman) donmez" <kde@myrealbox.com>  said:
>  
>
>>Hi All,
>>
>>First I did not tried 2.5.73 vanilla so this can be a bug in 2.5.73 itself . 
>>When I use my 56k modem to connect to internet it always hang up 5-6 minutes 
>>( sometimes like 1-2 minutes ) later. I checked with 2.5.72-mm1 and I got not
>>    
>>
> 
>  
>
>>hang-up whatsoever. I checked system logs and it just says :
>>
>>[pppd] Modem Hang Up
>>    
>>
>
>2.5.72-mm3 is fine for modem usage for me.
>
>2.5.73-mm1 threw this all 3 times I tried starting PPPD:
>
>Jun 24 22:37:48 turing-police pppd[1144]: Using interface ppp0
>Jun 24 22:37:48 turing-police pppd[1144]: Connect: ppp0 <--> /dev/ttyS14
>Jun 24 22:37:49 turing-police pppd[1144]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x9ed88e38> <pcomp> <accomp>]
>Jun 24 22:37:49 turing-police pppd[1144]: Modem hangup
>Jun 24 22:37:49 turing-police pppd[1144]: Connection terminated.
>
>i.e. it died a quick and horrid death.  I've not checked a plain 2.5.73 yet
>
I get the same issue in mm1, haven't tried vanilla either.