[PATCH] Accept ms-wins settings provided by server

[PATCH] Accept ms-wins settings provided by server

[Marcus Better]

The PPP servers of some UMTS/HSPA modems, including the Huawei E220
and E620, will send WINS server settings and insist that the client
accepts these. If the client does not do so, the modem will sometimes
provide bogus DNS server addresses like 10.11.12.13 and 10.11.12.14.

If we receive ms-wins settings from the server, save and include them
in our ConfReqs.

See also discussions at

  http://thread.gmane.org/gmane.linux.ppp/2721
  http://bugs.debian.org/cgi-bin/bugreport.cgi?bugD5711

Signed-off-by: Marcus Better <marcus@better.se>
---
 pppd/ipcp.c |   52 ++++++++++++++++++++++++++++++++++++++++++++++++++--
 1 files changed, 50 insertions(+), 2 deletions(-)

diff --git a/pppd/ipcp.c b/pppd/ipcp.c
index b7da1f7..9d8df1c 100644
--- a/pppd/ipcp.c
+++ b/pppd/ipcp.c
@@ -723,7 +723,8 @@ ipcp_cilen(f)
 #define LENCIADDRS(neg)		(neg ? CILEN_ADDRS : 0)
 #define LENCIVJ(neg, old)	(neg ? (old? CILEN_COMPRESS : CILEN_VJ) : 0)
 #define LENCIADDR(neg)		(neg ? CILEN_ADDR : 0)
-#define LENCIDNS(neg)		(neg ? (CILEN_ADDR) : 0)
+#define LENCIDNS(neg)		LENCIADDR(neg)
+#define LENCIWINS(neg)		LENCIADDR(neg)
 
     /*
      * First see if we want to change our options to the old
@@ -745,7 +746,9 @@ ipcp_cilen(f)
 	    LENCIVJ(go->neg_vj, go->old_vj) +
 	    LENCIADDR(go->neg_addr) +
 	    LENCIDNS(go->req_dns1) +
-	    LENCIDNS(go->req_dns2)) ;
+	    LENCIDNS(go->req_dns2) +
+            LENCIWINS(go->winsaddr[0]) +
+            LENCIWINS(go->winsaddr[1])) ;
 }
 
 
@@ -819,6 +822,19 @@ ipcp_addci(f, ucp, lenp)
 	    neg = 0; \
     }
 
+#define ADDCIWINS(opt, addr)                  \
+    if (addr) { \
+	if (len >= CILEN_ADDR) { \
+	    u_int32_t l; \
+	    PUTCHAR(opt, ucp); \
+	    PUTCHAR(CILEN_ADDR, ucp); \
+	    l = ntohl(addr); \
+	    PUTLONG(l, ucp); \
+	    len -= CILEN_ADDR; \
+	} else \
+	    addr = 0; \
+    }
+
     ADDCIADDRS(CI_ADDRS, !go->neg_addr && go->old_addrs, go->ouraddr,
 	       go->hisaddr);
 
@@ -831,6 +847,10 @@ ipcp_addci(f, ucp, lenp)
 
     ADDCIDNS(CI_MS_DNS2, go->req_dns2, go->dnsaddr[1]);
 
+    ADDCIWINS(CI_MS_WINS1, go->winsaddr[0]);
+
+    ADDCIWINS(CI_MS_WINS2, go->winsaddr[1]);
+    
     *lenp -= len;
 }
 
@@ -1185,6 +1205,15 @@ ipcp_nakci(f, p, len, treat_as_reject)
 	    try.req_dns2 = 1;
 	    no.req_dns2 = 1;
 	    break;
+	case CI_MS_WINS1:
+	case CI_MS_WINS2:
+	    if (cilen != CILEN_ADDR)
+		goto bad;
+	    GETLONG(l, p);
+	    ciaddr1 = htonl(l);
+	    if (ciaddr1)
+		try.winsaddr[citype = CI_MS_WINS2] = ciaddr1;
+	    break;
 	}
 	p = next;
     }
@@ -1301,6 +1330,21 @@ ipcp_rejci(f, p, len)
 	try.neg = 0; \
     }
 
+#define REJCIWINS(opt, addr) \
+    if (addr && \
+	((cilen = p[1]) = CILEN_ADDR) && \
+	len >= cilen && \
+	p[0] = opt) { \
+	u_int32_t l; \
+	len -= cilen; \
+	INCPTR(2, p); \
+	GETLONG(l, p); \
+	cilong = htonl(l); \
+	/* Check rejected value. */ \
+	if (cilong != addr) \
+	    goto bad; \
+	try.winsaddr[opt = CI_MS_WINS2] = 0; \
+    }
 
     REJCIADDRS(CI_ADDRS, !go->neg_addr && go->old_addrs,
 	       go->ouraddr, go->hisaddr);
@@ -1314,6 +1358,10 @@ ipcp_rejci(f, p, len)
 
     REJCIDNS(CI_MS_DNS2, req_dns2, go->dnsaddr[1]);
 
+    REJCIWINS(CI_MS_WINS1, go->winsaddr[0]);
+
+    REJCIWINS(CI_MS_WINS2, go->winsaddr[1]);
+
     /*
      * If there are any remaining CIs, then this packet is bad.
      */
-- 
1.6.3.rc3

Re: [PATCH] Accept ms-wins settings provided by server

[Jiri Kosina]

On Wed, 6 May 2009, Marcus Better wrote:

> The PPP servers of some UMTS/HSPA modems, including the Huawei E220
> and E620, will send WINS server settings and insist that the client
> accepts these. If the client does not do so, the modem will sometimes
> provide bogus DNS server addresses like 10.11.12.13 and 10.11.12.14.
> 
> If we receive ms-wins settings from the server, save and include them
> in our ConfReqs.
> 
> See also discussions at
> 
>   http://thread.gmane.org/gmane.linux.ppp/2721
>   http://bugs.debian.org/cgi-bin/bugreport.cgi?bugD5711
> 
> Signed-off-by: Marcus Better <marcus@better.se>
Tested-by: Jiri Kosina <jkosina@suse.cz>

Thanks,

-- 
Jiri Kosina
SUSE Labs

Re: [PATCH] Accept ms-wins settings provided by server

[Paul Mackerras]

Marcus Better writes:

> The PPP servers of some UMTS/HSPA modems, including the Huawei E220
> and E620, will send WINS server settings and insist that the client
> accepts these. If the client does not do so, the modem will sometimes
> provide bogus DNS server addresses like 10.11.12.13 and 10.11.12.14.

Are you sure that not accepting WINS settings is the only reason for
getting those DNS server addresses?  As I understood it, the reason we
got those bogus addresses was that the phone/modem hadn't actually got
in touch with the gateway yet.  The symptom I've seen is that we get
those bogus addresses in IPCP configure-naks over and over again, even
if we request exactly the IP address that the modem asked us to
request, until the modem manages to get a connection, and then it naks
us with the correct values (for IP-addr as well as DNS addrs).

Also, have you tried the latest git version of pppd?  Since 2.4.4 I
have added code to add the MS-DNS option to our IPCP conf-reqs if the
modem insists.  At least at one stage that seemed to be the critical
thing, not the MS-WINS options.  So if you can replicate the problem
with the current git version of pppd, and this patch makes it go away,
let me know (or better still put it in the patch description) and I'll
put the patch in.

Paul.

Re: [PATCH] Accept ms-wins settings provided by server

[Jiri Kosina]

On Thu, 7 May 2009, Paul Mackerras wrote:

> Are you sure that not accepting WINS settings is the only reason for 
> getting those DNS server addresses?  

Well, that's the observation. As soon as pppd is patched to accept the 
WINS settings, the DNS settings always arrive.
If we don't accept WINS settings, sometimes (reproducibly) no DNS settings 
are received.

> Also, have you tried the latest git version of pppd?  Since 2.4.4 I have 
> added code to add the MS-DNS option to our IPCP conf-reqs if the modem 
> insists.  At least at one stage that seemed to be the critical thing, 
> not the MS-WINS options.  So if you can replicate the problem with the 
> current git version of pppd, and this patch makes it go away, let me 
> know (or better still put it in the patch description) and I'll put the 
> patch in.

I am able to reproduce the problem with 2.4.4. Are the changes 
you are talking about merged post-2.4.4? If so, I will try to reproduce 
with current git. 

Unfortunately, this problem seems to be location-specific to me, in some 
locations this reproduces easily, in other locations it takes time. I am 
currently mostly in the locations where things usually work, but I will 
try (maybe Marcus will be faster verifying this, as I guess he is able to 
reproduce it in his "primary" location).

I guess it's dependent on the speed of registration with network, or 
something like that.

Thanks,

-- 
Jiri Kosina
SUSE Labs

Re: [PATCH] Accept ms-wins settings provided by server

[Paul Mackerras]

Jiri Kosina writes:

> Well, that's the observation. As soon as pppd is patched to accept the 
> WINS settings, the DNS settings always arrive.
> If we don't accept WINS settings, sometimes (reproducibly) no DNS settings 
> are received.

Do you have logs of the negotiations with and without the patch?  I'd
be interested to see them.

> I am able to reproduce the problem with 2.4.4. Are the changes 
> you are talking about merged post-2.4.4? If so, I will try to reproduce 
> with current git. 

Yes, they have gone in since 2.4.4.

> Unfortunately, this problem seems to be location-specific to me, in some 
> locations this reproduces easily, in other locations it takes time. I am 
> currently mostly in the locations where things usually work, but I will 
> try (maybe Marcus will be faster verifying this, as I guess he is able to 
> reproduce it in his "primary" location).
> 
> I guess it's dependent on the speed of registration with network, or 
> something like that.

Most likely.

Paul.

Re: [PATCH] Accept ms-wins settings provided by server

[Jiri Kosina]

On Thu, 7 May 2009, Paul Mackerras wrote:

> > Well, that's the observation. As soon as pppd is patched to accept the 
> > WINS settings, the DNS settings always arrive. If we don't accept WINS 
> > settings, sometimes (reproducibly) no DNS settings are received.
> Do you have logs of the negotiations with and without the patch?  I'd
> be interested to see them.

For the one without the patch, I have one handy myself (from 2.4.4)

sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x281deae4> <accomp>]
rcvd [LCP ConfReq id=0x0 <asyncmap 0x0> <auth chap MD5> <magic 0xe1cd3a> <pcomp> <accomp>]
No auth is possible
sent [LCP ConfRej id=0x0 <auth chap MD5> <pcomp>]
rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0x281deae4> <accomp>]
rcvd [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xe1cd3a> <accomp>]
sent [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0xe1cd3a> <accomp>]
sent [LCP EchoReq id=0x0 magic=0x281deae4]
sent [CCP ConfReq id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns3 0.0.0.0>]
rcvd [LCP DiscReq id=0x2 magic=0xe1cd3a]
rcvd [LCP EchoRep id=0x0 magic=0xe1cd3a 28 1d ea e4]
rcvd [LCP ProtRej id=0x3 80 fd 01 01 00 0f 1a 04 78 00 18 04 78 00 15 03 2f]
Protocol-Reject for 'Compression Control Protocol' (0x80fd) received
rcvd [IPCP ConfNak id=0x1 <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
rcvd [IPCP ConfNak id=0x1 <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPCP ConfReq id=0x2 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14>]
rcvd [IPCP ConfNak id=0x2 <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPCP ConfReq id=0x3 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14>]
rcvd [IPCP ConfNak id=0x3 <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPCP ConfReq id=0x4 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14>]
rcvd [IPCP ConfNak id=0x4 <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPCP ConfReq id=0x5 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14>]
rcvd [IPCP ConfNak id=0x5 <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPCP ConfReq id=0x6 <addr 0.0.0.0>]
rcvd [IPCP ConfNak id=0x6 <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPCP ConfReq id=0x7 <addr 0.0.0.0>]
rcvd [IPCP ConfNak id=0x7 <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPCP ConfReq id=0x8 <addr 0.0.0.0>]
rcvd [IPCP ConfNak id=0x8 <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPCP ConfReq id=0x9 <addr 0.0.0.0>]
rcvd [IPCP ConfNak id=0x9 <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPCP ConfReq id=0xa <addr 0.0.0.0>]
rcvd [IPCP ConfNak id=0xa <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPCP ConfReq id=0xb <addr 0.0.0.0>]
rcvd [IPCP ConfReq id=0x0]
sent [IPCP ConfNak id=0x0 <addr 0.0.0.0>]
rcvd [IPCP ConfNak id=0xb <addr 10.169.204.193>]
sent [IPCP ConfReq id=0xc]
rcvd [IPCP ConfReq id=0x1]
sent [IPCP ConfAck id=0x1]
rcvd [IPCP ConfNak id=0xc <addr 10.169.204.193>]
sent [IPCP ConfReq id=0xd <addr 10.169.204.193>]
rcvd [IPCP ConfAck id=0xd <addr 10.169.204.193>]
Could not determine remote IP address: defaulting to 10.64.64.64
local  IP address 10.169.204.193
remote IP address 10.64.64.64
primary   DNS address 10.11.12.13
secondary DNS address 10.11.12.14


I don't currently have handy the log for the patched case myself where the 
bug triggered, but one can be found linked in the referenced bug -- it can 
be found on 
http://koti.kapsi.fi/~mcfrisk/gprs_debug/qualcomm_ppp/ppp_log_huawei_fixed_pppd.txt

[ copy/pasting in for the archive of the list to have in case it vanishes 
from the URL ]

sent [LCP ConfReq id=0x1 <asyncmap 0xa0000> <magic 0x4eb0abc8>]
rcvd [LCP ConfReq id=0x0 <asyncmap 0x0> <auth chap MD5> <magic 0x2006672d> <pcomp> <accomp>]
sent [LCP ConfRej id=0x0 <pcomp> <accomp>]
rcvd [LCP ConfAck id=0x1 <asyncmap 0xa0000> <magic 0x4eb0abc8>]
rcvd [LCP ConfReq id=0x1 <asyncmap 0x0> <auth chap MD5> <magic 0x2006672d>]
sent [LCP ConfAck id=0x1 <asyncmap 0x0> <auth chap MD5> <magic 0x2006672d>]
rcvd [LCP DiscReq id=0x2 magic=0x2006672d]
rcvd [CHAP Challenge id=0x1 <1a35cd97d28b59211899ea7d3c37e9b4>, name = "UMTS_CHAP_SRVR"]
sent [CHAP Response id=0x1 <def0f0c42bedbc7a2443568321a0f06a>, name = "foo"]
rcvd [CHAP Success id=0x1 ""]
CHAP authentication succeeded
CHAP authentication succeeded
sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns3 0.0.0.0>]
rcvd [IPCP ConfNak id=0x1 <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPCP ConfReq id=0x2 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14>]
rcvd [IPCP ConfNak id=0x2 <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPCP ConfReq id=0x3 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns3 10.11.12.14>]
rcvd [IPCP ConfReq id=0x0]
sent [IPCP ConfNak id=0x0 <addr 10.0.0.1>]
rcvd [IPCP ConfNak id=0x3 <addr 85.156.2.250> <ms-dns1 193.229.0.40> <ms-dns3 193.229.0.42>]
sent [IPCP ConfReq id=0x4 <addr 85.156.2.250> <ms-dns1 193.229.0.40> <ms-dns3 193.229.0.42>]
rcvd [IPCP ConfReq id=0x1]
sent [IPCP ConfAck id=0x1]
rcvd [IPCP ConfAck id=0x4 <addr 85.156.2.250> <ms-dns1 193.229.0.40> <ms-dns3 193.229.0.42>]
Cannot determine ethernet address for proxy ARP
local  IP address 85.156.2.250
remote IP address 10.0.0.1
primary   DNS address 193.229.0.40
secondary DNS address 193.229.0.42
Script /etc/ppp/ip-up started (pid 13168)
Script /etc/ppp/ip-up finished (pid 13168), status = 0x0

Thanks,

-- 
Jiri Kosina
SUSE Labs

Re: [PATCH] Accept ms-wins settings provided by server

[James Cameron]

On Thu, May 07, 2009 at 02:47:24PM +0200, Jiri Kosina wrote:
> For the one without the patch, I have one handy myself (from 2.4.4)

Include timings next time.  ;-)  I've reviewed this debug log, and it is
consistent with what I see from various HSDPA modem users where the
modem takes a touch longer to attach to the network.  I've seen times
between 3 and 30 seconds.

I'd like to see what you get with times, without the patch.

On the eee-bpw package that I maintain, the chatscript used contains
this:

#
# cease if modem is not attached to network yet
ABORT '+CGATT: 0'
'' AT+CGATT?

... and the connection is retried by the enclosing script until
attachment is reported.  I don't think I've seen 10.11.12.13 if the
attachment query succeeds.

Looking at the debug log with the patch ... three seconds elapse before
an address is given, and so the negotiation at 06:09:00 through to
09:09:02 appears more a delaying tactic by the modem because it hasn't
completed the negotiation with the provider's equipment.

Was the modem powered off and on before each test?

(I'd like to see you succeed ... if there's a way to encourage the modem
to complete connection sooner, I'm all for it.)

-- 
James Cameron                         http://quozl.netrek.org/
HP Open Source, Volunteer             http://opensource.hp.com/
PPTP Client Project, Release Engineer http://pptpclient.sourceforge.net/

Re: [PATCH] Accept ms-wins settings provided by server

[Marcus Better]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Paul Mackerras wrote:
> Also, have you tried the latest git version of pppd?  Since 2.4.4 I
> have added code to add the MS-DNS option to our IPCP conf-reqs if the
> modem insists.

I cannot reproduce the problem anymore. I have changed UMTS provider in between (from Tele2 to 3 in Sweden), and modem (from 
Huawei E620 to E220). This may explain the differences.

However I still have a very similar connection problem, but the patch makes no difference. I tried both pppd 2.4.4 and current 
git, patched and unpatched. In all cases it tends to fail at the first connection attempt after plugging in the modem. What 
helps however is setting ipcp-max-failure high enough, like 30.

I'm quite sure that the patch was needed with the old provider and hardware, and a few other people have confirmed this. I'll 
see if I can try another modem.

Hopefully someone else can reproduce it?

Here is the log with the current git (unpatched), failure case:

May 19 20:31:58 better kernel: PPP generic driver version 2.4.2
May 19 20:31:58 better pppd[10996]: pppd 2.4.5 started by root, uid 0
May 19 20:31:58 better pppd[10996]: Script /usr/sbin/chat -v -f /etc/ppp/3g.chat finished (pid 10999), status = 0x0
May 19 20:31:58 better pppd[10996]: Serial connection established.
May 19 20:31:59 better pppd[10996]: using channel 1
May 19 20:31:59 better pppd[10996]: Using interface ppp0
May 19 20:31:59 better pppd[10996]: Connect: ppp0 <--> /dev/3gmodem
May 19 20:32:00 better pppd[10996]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x803a1d6f> <pcomp> <accomp>]
May 19 20:32:00 better pppd[10996]: rcvd [LCP ConfReq id=0x0 <asyncmap 0x0> <auth chap MD5> <magic 0xca9094> <pcomp> <accomp>]
May 19 20:32:00 better pppd[10996]: sent [LCP ConfNak id=0x0 <auth pap>]
May 19 20:32:00 better pppd[10996]: rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0x803a1d6f> <pcomp> <accomp>]
May 19 20:32:00 better pppd[10996]: rcvd [LCP ConfReq id=0x1 <asyncmap 0x0> <auth pap> <magic 0xca9094> <pcomp> <accomp>]
May 19 20:32:00 better pppd[10996]: sent [LCP ConfAck id=0x1 <asyncmap 0x0> <auth pap> <magic 0xca9094> <pcomp> <accomp>]
May 19 20:32:00 better pppd[10996]: sent [LCP EchoReq id=0x0 magic=0x803a1d6f]
May 19 20:32:00 better pppd[10996]: sent [PAP AuthReq id=0x1 user="better" password=<hidden>]
May 19 20:32:00 better pppd[10996]: rcvd [LCP DiscReq id=0x2 magic=0xca9094]
May 19 20:32:00 better pppd[10996]: rcvd [LCP EchoRep id=0x0 magic=0xca9094 80 3a 1d 6f]
May 19 20:32:00 better pppd[10996]: rcvd [PAP AuthAck id=0x1 ""]
May 19 20:32:00 better pppd[10996]: PAP authentication succeeded
May 19 20:32:00 better pppd[10996]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
May 19 20:32:01 better pppd[10996]: rcvd [IPCP ConfNak id=0x1 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 
10.11.12.13> <ms-wins 10.11.12.14>]
May 19 20:32:01 better pppd[10996]: sent [IPCP ConfReq id=0x2 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
May 19 20:32:02 better pppd[10996]: rcvd [IPCP ConfNak id=0x2 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 
10.11.12.13> <ms-wins 10.11.12.14>]
May 19 20:32:02 better pppd[10996]: sent [IPCP ConfReq id=0x3 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
May 19 20:32:03 better pppd[10996]: rcvd [IPCP ConfNak id=0x3 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 
10.11.12.13> <ms-wins 10.11.12.14>]
May 19 20:32:03 better pppd[10996]: sent [IPCP ConfReq id=0x4 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
May 19 20:32:04 better pppd[10996]: rcvd [IPCP ConfNak id=0x4 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 
10.11.12.13> <ms-wins 10.11.12.14>]
May 19 20:32:04 better pppd[10996]: sent [IPCP ConfReq id=0x5 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
May 19 20:32:05 better pppd[10996]: rcvd [IPCP ConfNak id=0x5 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 
10.11.12.13> <ms-wins 10.11.12.14>]
May 19 20:32:05 better pppd[10996]: sent [IPCP ConfReq id=0x6 <addr 0.0.0.0>]
May 19 20:32:06 better pppd[10996]: rcvd [IPCP ConfNak id=0x6 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 
10.11.12.13> <ms-wins 10.11.12.14>]
May 19 20:32:06 better pppd[10996]: sent [IPCP ConfReq id=0x7 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
May 19 20:32:07 better pppd[10996]: rcvd [IPCP ConfNak id=0x7 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 
10.11.12.13> <ms-wins 10.11.12.14>]
May 19 20:32:07 better pppd[10996]: sent [IPCP ConfReq id=0x8 <addr 0.0.0.0>]
May 19 20:32:08 better pppd[10996]: rcvd [IPCP ConfNak id=0x8 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 
10.11.12.13> <ms-wins 10.11.12.14>]
May 19 20:32:08 better pppd[10996]: sent [IPCP ConfReq id=0x9 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
May 19 20:32:09 better pppd[10996]: rcvd [IPCP ConfNak id=0x9 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 
10.11.12.13> <ms-wins 10.11.12.14>]
May 19 20:32:09 better pppd[10996]: sent [IPCP ConfReq id=0xa <addr 0.0.0.0>]
May 19 20:32:10 better pppd[10996]: rcvd [IPCP ConfNak id=0xa <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 
10.11.12.13> <ms-wins 10.11.12.14>]
May 19 20:32:10 better pppd[10996]: sent [IPCP ConfReq id=0xb <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
May 19 20:32:11 better pppd[10996]: rcvd [IPCP ConfNak id=0xb <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 
10.11.12.13> <ms-wins 10.11.12.14>]
May 19 20:32:11 better pppd[10996]: sent [IPCP ConfReq id=0xc <addr 0.0.0.0>]
May 19 20:32:12 better pppd[10996]: rcvd [IPCP ConfNak id=0xc <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 
10.11.12.13> <ms-wins 10.11.12.14>]
May 19 20:32:12 better pppd[10996]: sent [IPCP ConfReq id=0xd <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
May 19 20:32:12 better pppd[10996]: rcvd [IPCP ConfReq id=0x0]
May 19 20:32:12 better pppd[10996]: sent [IPCP ConfNak id=0x0 <addr 0.0.0.0>]
May 19 20:32:12 better pppd[10996]: rcvd [IPCP ConfNak id=0xd <addr 95.209.165.82> <ms-dns1 80.251.192.244> <ms-dns2 
80.251.192.245>]
May 19 20:32:12 better pppd[10996]: sent [IPCP ConfReq id=0xe]
May 19 20:32:12 better pppd[10996]: rcvd [IPCP ConfReq id=0x1]
May 19 20:32:12 better pppd[10996]: sent [IPCP ConfAck id=0x1]
May 19 20:32:12 better pppd[10996]: rcvd [IPCP ConfNak id=0xe <addr 95.209.165.82>]
May 19 20:32:12 better pppd[10996]: sent [IPCP ConfReq id=0xf <addr 95.209.165.82>]
May 19 20:32:12 better pppd[10996]: rcvd [IPCP ConfAck id=0xf <addr 95.209.165.82>]
May 19 20:32:12 better pppd[10996]: Could not determine remote IP address: defaulting to 10.64.64.64
May 19 20:32:12 better pppd[10996]: not replacing existing default route via 192.168.1.1
May 19 20:32:12 better pppd[10996]: Cannot determine ethernet address for proxy ARP
May 19 20:32:12 better pppd[10996]: local  IP address 95.209.165.82
May 19 20:32:12 better pppd[10996]: remote IP address 10.64.64.64

Second attempt, successful connection (current git, unpatched):

May 19 20:35:57 better pppd[11280]: pppd 2.4.5 started by root, uid 0
May 19 20:36:00 better pppd[11280]: Script /usr/sbin/chat -v -f /etc/ppp/3g.chat finished (pid 11281), status = 0x0
May 19 20:36:00 better pppd[11280]: Serial connection established.
May 19 20:36:00 better pppd[11280]: using channel 2
May 19 20:36:00 better pppd[11280]: Using interface ppp0
May 19 20:36:00 better pppd[11280]: Connect: ppp0 <--> /dev/3gmodem
May 19 20:36:01 better pppd[11280]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xcc72d817> <pcomp> <accomp>]
May 19 20:36:01 better pppd[11280]: rcvd [LCP ConfReq id=0x3 <asyncmap 0x0> <auth chap MD5> <magic 0xce3f01> <pcomp> <accomp>]
May 19 20:36:01 better pppd[11280]: sent [LCP ConfNak id=0x3 <auth pap>]
May 19 20:36:01 better pppd[11280]: rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0xcc72d817> <pcomp> <accomp>]
May 19 20:36:01 better pppd[11280]: rcvd [LCP ConfReq id=0x4 <asyncmap 0x0> <auth pap> <magic 0xce3f01> <pcomp> <accomp>]
May 19 20:36:01 better pppd[11280]: sent [LCP ConfAck id=0x4 <asyncmap 0x0> <auth pap> <magic 0xce3f01> <pcomp> <accomp>]
May 19 20:36:01 better pppd[11280]: sent [LCP EchoReq id=0x0 magic=0xcc72d817]
May 19 20:36:01 better pppd[11280]: sent [PAP AuthReq id=0x1 user="better" password=<hidden>]
May 19 20:36:01 better pppd[11280]: rcvd [LCP DiscReq id=0x5 magic=0xce3f01]
May 19 20:36:01 better pppd[11280]: rcvd [LCP EchoRep id=0x0 magic=0xce3f01 cc 72 d8 17]
May 19 20:36:01 better pppd[11280]: rcvd [PAP AuthAck id=0x1 ""]
May 19 20:36:01 better pppd[11280]: PAP authentication succeeded
May 19 20:36:01 better pppd[11280]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
May 19 20:36:02 better hdapsd[4873]: un-parking
May 19 20:36:02 better pppd[11280]: rcvd [IPCP ConfNak id=0x1 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 
10.11.12.13> <ms-wins 10.11.12.14>]
May 19 20:36:02 better pppd[11280]: sent [IPCP ConfReq id=0x2 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
May 19 20:36:03 better pppd[11280]: rcvd [IPCP ConfNak id=0x2 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 
10.11.12.13> <ms-wins 10.11.12.14>]
May 19 20:36:03 better pppd[11280]: sent [IPCP ConfReq id=0x3 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
May 19 20:36:04 better pppd[11280]: rcvd [IPCP ConfReq id=0x2]
May 19 20:36:04 better pppd[11280]: sent [IPCP ConfNak id=0x2 <addr 0.0.0.0>]
May 19 20:36:04 better pppd[11280]: rcvd [IPCP ConfNak id=0x3 <addr 95.209.163.10> <ms-dns1 80.251.192.244> <ms-dns2 
80.251.192.245>]
May 19 20:36:04 better pppd[11280]: sent [IPCP ConfReq id=0x4 <addr 95.209.163.10> <ms-dns1 80.251.192.244> <ms-dns2 
80.251.192.245>]
May 19 20:36:04 better pppd[11280]: rcvd [IPCP ConfReq id=0x3]
May 19 20:36:04 better pppd[11280]: sent [IPCP ConfAck id=0x3]
May 19 20:36:04 better pppd[11280]: rcvd [IPCP ConfAck id=0x4 <addr 95.209.163.10> <ms-dns1 80.251.192.244> <ms-dns2 
80.251.192.245>]
May 19 20:36:04 better pppd[11280]: Could not determine remote IP address: defaulting to 10.64.64.64
May 19 20:36:04 better pppd[11280]: not replacing existing default route through eth0
May 19 20:36:04 better pppd[11280]: Cannot determine ethernet address for proxy ARP
May 19 20:36:04 better pppd[11280]: local  IP address 95.209.163.10
May 19 20:36:04 better pppd[11280]: remote IP address 10.64.64.64
May 19 20:36:04 better pppd[11280]: primary   DNS address 80.251.192.244
May 19 20:36:04 better pppd[11280]: secondary DNS address 80.251.192.245

After replugging the modem, current git with the patch applied:

May 19 20:49:10 better pppd[12763]: pppd 2.4.5 started by root, uid 0
May 19 20:49:10 better pppd[12763]: Script /usr/sbin/chat -v -f /etc/ppp/3g.chat finished (pid 12764), status = 0x0
May 19 20:49:10 better pppd[12763]: Serial connection established.
May 19 20:49:10 better pppd[12763]: using channel 4
May 19 20:49:10 better pppd[12763]: Using interface ppp0
May 19 20:49:10 better pppd[12763]: Connect: ppp0 <--> /dev/3gmodem
May 19 20:49:11 better pppd[12763]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xbad3a25f> <pcomp> <accomp>]
May 19 20:49:11 better pppd[12763]: rcvd [LCP ConfReq id=0x0 <asyncmap 0x0> <auth chap MD5> <magic 0xc8a08d> <pcomp> <accomp>]
May 19 20:49:11 better pppd[12763]: sent [LCP ConfNak id=0x0 <auth pap>]
May 19 20:49:11 better pppd[12763]: rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0xbad3a25f> <pcomp> <accomp>]
May 19 20:49:11 better pppd[12763]: rcvd [LCP ConfReq id=0x1 <asyncmap 0x0> <auth pap> <magic 0xc8a08d> <pcomp> <accomp>]
May 19 20:49:11 better pppd[12763]: sent [LCP ConfAck id=0x1 <asyncmap 0x0> <auth pap> <magic 0xc8a08d> <pcomp> <accomp>]
May 19 20:49:11 better pppd[12763]: sent [LCP EchoReq id=0x0 magic=0xbad3a25f]
May 19 20:49:11 better pppd[12763]: sent [PAP AuthReq id=0x1 user="better" password=<hidden>]
May 19 20:49:11 better pppd[12763]: rcvd [LCP DiscReq id=0x2 magic=0xc8a08d]
May 19 20:49:11 better pppd[12763]: rcvd [LCP EchoRep id=0x0 magic=0xc8a08d ba d3 a2 5f]
May 19 20:49:11 better pppd[12763]: rcvd [PAP AuthAck id=0x1 ""]
May 19 20:49:11 better pppd[12763]: PAP authentication succeeded
May 19 20:49:11 better pppd[12763]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
May 19 20:49:12 better pppd[12763]: rcvd [IPCP ConfNak id=0x1 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 
10.11.12.13> <ms-wins 10.11.12.14>]
May 19 20:49:12 better pppd[12763]: sent [IPCP ConfReq id=0x2 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-
wins 10.11.12.13> <ms-wins 10.11.12.14>]
May 19 20:49:13 better pppd[12763]: rcvd [IPCP ConfNak id=0x2 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 
10.11.12.13> <ms-wins 10.11.12.14>]
May 19 20:49:13 better pppd[12763]: sent [IPCP ConfReq id=0x3 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-
wins 10.11.12.13> <ms-wins 10.11.12.14>]
May 19 20:49:15 better pppd[12763]: rcvd [IPCP ConfNak id=0x3 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 
10.11.12.13> <ms-wins 10.11.12.14>]
May 19 20:49:15 better pppd[12763]: sent [IPCP ConfReq id=0x4 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-
wins 10.11.12.13> <ms-wins 10.11.12.14>]
May 19 20:49:16 better pppd[12763]: rcvd [IPCP ConfNak id=0x4 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 
10.11.12.13> <ms-wins 10.11.12.14>]
May 19 20:49:16 better pppd[12763]: sent [IPCP ConfReq id=0x5 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-
wins 10.11.12.13> <ms-wins 10.11.12.14>]
May 19 20:49:17 better pppd[12763]: rcvd [IPCP ConfNak id=0x5 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 
10.11.12.13> <ms-wins 10.11.12.14>]
May 19 20:49:17 better pppd[12763]: sent [IPCP ConfReq id=0x6 <addr 0.0.0.0> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
May 19 20:49:18 better pppd[12763]: rcvd [IPCP ConfNak id=0x6 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 
10.11.12.13> <ms-wins 10.11.12.14>]
May 19 20:49:18 better pppd[12763]: sent [IPCP ConfReq id=0x7 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-
wins 10.11.12.13> <ms-wins 10.11.12.14>]
May 19 20:49:19 better pppd[12763]: rcvd [IPCP ConfNak id=0x7 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 
10.11.12.13> <ms-wins 10.11.12.14>]
May 19 20:49:19 better pppd[12763]: sent [IPCP ConfReq id=0x8 <addr 0.0.0.0> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
May 19 20:49:20 better pppd[12763]: rcvd [IPCP ConfNak id=0x8 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 
10.11.12.13> <ms-wins 10.11.12.14>]
May 19 20:49:20 better pppd[12763]: sent [IPCP ConfReq id=0x9 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-
wins 10.11.12.13> <ms-wins 10.11.12.14>]
May 19 20:49:21 better pppd[12763]: rcvd [IPCP ConfNak id=0x9 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 
10.11.12.13> <ms-wins 10.11.12.14>]
May 19 20:49:21 better pppd[12763]: sent [IPCP ConfReq id=0xa <addr 0.0.0.0> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
May 19 20:49:22 better pppd[12763]: rcvd [IPCP ConfReq id=0x0]
May 19 20:49:22 better pppd[12763]: sent [IPCP ConfNak id=0x0 <addr 0.0.0.0>]
May 19 20:49:22 better pppd[12763]: rcvd [IPCP ConfRej id=0xa <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
May 19 20:49:22 better pppd[12763]: sent [IPCP ConfReq id=0xb <addr 0.0.0.0>]
May 19 20:49:22 better pppd[12763]: rcvd [IPCP ConfReq id=0x1]
May 19 20:49:22 better pppd[12763]: sent [IPCP ConfAck id=0x1]
May 19 20:49:22 better pppd[12763]: rcvd [IPCP ConfNak id=0xb <addr 95.209.175.89>]
May 19 20:49:22 better pppd[12763]: sent [IPCP ConfReq id=0xc <addr 95.209.175.89>]
May 19 20:49:22 better pppd[12763]: rcvd [IPCP ConfAck id=0xc <addr 95.209.175.89>]
May 19 20:49:22 better pppd[12763]: Could not determine remote IP address: defaulting to 10.64.64.64
May 19 20:49:22 better dnsmasq[5417]: no servers found in /var/run/dnsmasq/resolv.conf, will retry
May 19 20:49:22 better pppd[12763]: Cannot determine ethernet address for proxy ARP
May 19 20:49:22 better pppd[12763]: local  IP address 95.209.175.89
May 19 20:49:22 better pppd[12763]: remote IP address 10.64.64.64

Cheers,

Marcus

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.9 (GNU/Linux)

iEYEARECAAYFAkoTCE0ACgkQXjXn6TzcAQnbCwCfe7gc6iLuqzesc3BUCB5HoprE
XbYAoLSIxNnly7vbL/57CaJ8fGkPZ00j
=2RWX
-----END PGP SIGNATURE-----

Re: [PATCH] Accept ms-wins settings provided by server

[James Cameron]

On Tue, May 19, 2009 at 09:28:12PM +0200, Marcus Better wrote:
> I cannot reproduce the problem anymore. I have changed UMTS provider
> in between (from Tele2 to 3 in Sweden), and modem (from Huawei E620 to
> E220). This may explain the differences.

The change of provider means you are faced with changed attachment
delays.

Are you verifying in your chatscript that the modem is attached to the
network before attempting to dial?

#
# cease if modem is not attached to network yet
ABORT '+CGATT: 0'
'' AT+CGATT?


> However I still have a very similar connection problem, but the patch
> makes no difference. I tried both pppd 2.4.4 and current git, patched
> and unpatched. In all cases it tends to fail at the first connection
> attempt after plugging in the modem. What helps however is setting
> ipcp-max-failure high enough, like 30.
> 
> Here is the log [...]

All three logs you provided in this post showed successful connection.
What makes you think it failed?

-- 
James Cameron
http://ftp.hp.com.au/sigs/jc/

Re: [PATCH] Accept ms-wins settings provided by server

[Marco d'Itri]

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

On May 20, James Cameron <james.cameron@hp.com> wrote:

> # cease if modem is not attached to network yet
> ABORT '+CGATT: 0'
> '' AT+CGATT?
FYI, with my Nokia E51 I always get back 0.

-- 
ciao,
Marco

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

Re: [PATCH] Accept ms-wins settings provided by server

[Marcus Better]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

James Cameron wrote:
> Are you verifying in your chatscript that the modem is attached to the
> network before attempting to dial?
> 
> #
> # cease if modem is not attached to network yet
> ABORT '+CGATT: 0'
> '' AT+CGATT?

No. That would just fail if it is not attached, right? So it's not much 
better than the current situation.

> All three logs you provided in this post showed successful connection.
> What makes you think it failed?

You will notice that only the second one has these lines:

May 19 20:36:04 better pppd[11280]: primary   DNS address 80.251.192.244
May 19 20:36:04 better pppd[11280]: secondary DNS address 80.251.192.245

Cheers,

Marcus

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.9 (GNU/Linux)

iEYEARECAAYFAkoTxDkACgkQXjXn6TzcAQmhPQCeMYbso7qbkoaBzMr/eS/tLi5k
Zh0AoK0M0Mw9te2n8/5m9vVj3Sdf4nKT
=Ct5H
-----END PGP SIGNATURE-----

Re: [PATCH] Accept ms-wins settings provided by server

[James Cameron]

On Wed, May 20, 2009 at 10:50:01AM +0200, Marcus Better wrote:
> James Cameron wrote:
> > Are you verifying in your chatscript that the modem is attached to the
> > network before attempting to dial?
> > 
> > #
> > # cease if modem is not attached to network yet
> > ABORT '+CGATT: 0'
> > '' AT+CGATT?
> 
> No. That would just fail if it is not attached, right? So it's not much 
> better than the current situation.

Yes, but it helps you isolate the cause of the negotiation failure ...
if the modem is not attached to the radio network, then it won't be
successful in negotiating an IP address.  The attachment occurs before
negotiation with the provisioning servers.  The provisioning servers
cannot be reached until the radio network attachment completes.

Per Marco d'Itri this method may not be portable across all modems.

The modems I have used default to attempting to attach on power up, but
they have a configuration variable which can let them delay the attach
until a connection is requested.

To encourage a modem to try to attach, you can send "AT+CGATT=1".

> > All three logs you provided in this post showed successful connection.
> > What makes you think it failed?
> 
> You will notice that only the second one has these lines:
> 
> May 19 20:36:04 better pppd[11280]: primary   DNS address 80.251.192.244
> May 19 20:36:04 better pppd[11280]: secondary DNS address 80.251.192.245

ns.hi3gaccess.se.
ns2.hi3gaccess.se.

Looks quite reasonable.  What makes you think it failed?  Oh, right,
you're saying that these lines are *missing* from the first and third
logs.

Let's see, in your "log with the current git (unpatched), failure case",
the modem proposes addr, ms-dns1 and ms-dns2:

May 19 20:32:12 better pppd[10996]: rcvd [IPCP ConfNak id=0xd <addr 95.209.165.82> <ms-dns1 80.251.192.244> <ms-dns2 80.251.192.245>]

But what happens next appears to be an IPCP restart:

May 19 20:32:12 better pppd[10996]: sent [IPCP ConfReq id=0xe]
May 19 20:32:12 better pppd[10996]: rcvd [IPCP ConfReq id=0x1]
May 19 20:32:12 better pppd[10996]: sent [IPCP ConfAck id=0x1]
May 19 20:32:12 better pppd[10996]: rcvd [IPCP ConfNak id=0xe <addr 95.209.165.82>]
May 19 20:32:12 better pppd[10996]: sent [IPCP ConfReq id=0xf <addr 95.209.165.82>]
May 19 20:32:12 better pppd[10996]: rcvd [IPCP ConfAck id=0xf <addr 95.209.165.82>]

Which has only resulted in the local IP address being determined.

What is ipcp-max-configure set to?

What is ipcp-restart set to?

These two options will determine the persistence of pppd during this
negotiation.

--

In your log "successful connection (current git, unpatched)", the peer
and pppd negotiate addr, ms-dns1, and ms-dns2.

--

In your log "After replugging the modem, current git with the patch
applied", the same situation as the first log occurs, with IPCP
restarting and only the IP address negotiated.

--

I think the behaviour you observe has more to do with timing and IPCP
restart than anything else.

-- 
James Cameron
http://ftp.hp.com.au/sigs/jc/

Re: [PATCH] Accept ms-wins settings provided by server

[Marcus Better]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

James Cameron wrote:
> What is ipcp-max-configure set to?
> 
> What is ipcp-restart set to?

The default values.

Cheers,

Marcus

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.9 (GNU/Linux)

iEYEARECAAYFAkoVsuQACgkQXjXn6TzcAQnsKgCcDm8/tYkq72PA7EW45TaS/zJr
74sAoI1bzHTbePs8AMlHDYBZHhebbKtO
=hDtY
-----END PGP SIGNATURE-----

Re: [PATCH] Accept ms-wins settings provided by server

[James Cameron]

On Thu, May 21, 2009 at 10:00:36PM +0200, Marcus Better wrote:
> James Cameron wrote:
> > What is ipcp-max-configure set to?
> > 
> > What is ipcp-restart set to?
> 
> The default values.

Double them and see if the frequency of the connection failure is
changed.

-- 
James Cameron
http://ftp.hp.com.au/sigs/jc/

Re: [PATCH] Accept ms-wins settings provided by server

[Marco d'Itri]

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

On May 20, Marco d'Itri <md@Linux.IT> wrote:

> > # cease if modem is not attached to network yet
> > ABORT '+CGATT: 0'
> > '' AT+CGATT?
> FYI, with my Nokia E51 I always get back 0.
Because it was connected to a 3G network, this only works for GPRS.

-- 
ciao,
Marco

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

Re: [PATCH] Accept ms-wins settings provided by server

[Libor Pechacek]

Hi Marcus,

Marcus Better <marcus <at> better.se> writes:
> Paul Mackerras wrote:
> > Also, have you tried the latest git version of pppd?  Since 2.4.4 I
> > have added code to add the MS-DNS option to our IPCP conf-reqs if the
> > modem insists.
> 
> I cannot reproduce the problem anymore. I have changed UMTS provider in
> between (from Tele2 to 3 in Sweden), and modem (from Huawei E620 to E220).
> This may explain the differences.
> 
> However I still have a very similar connection problem, but the patch makes
> no difference. I tried both pppd 2.4.4 and current git, patched and
> unpatched. In all cases it tends to fail at the first connection attempt
> after plugging in the modem. What helps however is setting ipcp-max-failure
> high enough, like 30.

The DNS problem you observe is unrelated to the WINS one.  Increasing
ipcp-max-failure is IMO the right solution here.  The DNS negotiation trouble
is caused by the 'treat as reject' behavior introduced in GIT commit ec27e674.

> I'm quite sure that the patch was needed with the old provider and hardware,
> and a few other people have confirmed this. I'll see if I can try another
> modem.
> 
> Hopefully someone else can reproduce it?

I have information that people in Germany (hs2300 HSDPA modem, providers
T-Mobile and Vodafone) and Finland (no details provided) observed this failure
too.

> Here is the log with the current git (unpatched), failure case:
[...]
> May 19 20:32:00 better pppd[10996]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0>
<ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
> May 19 20:32:01 better pppd[10996]: rcvd [IPCP ConfNak id=0x1 <ms-dns1
10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]

This is the first configuration request - IP address and DNS servers are
requested, the remote end responds with NAK and provides some DNS and WINS
server addresses.  So far so good.

[...]
> May 19 20:32:08 better pppd[10996]: sent [IPCP ConfReq id=0x9 <addr 0.0.0.0>
<ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
> May 19 20:32:09 better pppd[10996]: rcvd [IPCP ConfNak id=0x9 <ms-dns1
10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]

The previous request was the last one where the local end requested the DNS
server addresses.  The next request does not contain the DNS options due to the
condition at line 556 in pppd/fsm.c (treat_as_reject = (f->rnakloops >f->maxnakloops)).

> May 19 20:32:09 better pppd[10996]: sent [IPCP ConfReq id=0xa <addr 0.0.0.0>]
> May 19 20:32:10 better pppd[10996]: rcvd [IPCP ConfNak id=0xa <ms-dns1
10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]

And despite the remote end offered valid DNS server addresses, they were
disregarded, and configuration request with id 0xe has surprisingly no options:

> May 19 20:32:12 better pppd[10996]: sent [IPCP ConfReq id=0xd <addr 0.0.0.0>
<ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
> May 19 20:32:12 better pppd[10996]: rcvd [IPCP ConfReq id=0x0]
> May 19 20:32:12 better pppd[10996]: sent [IPCP ConfNak id=0x0 <addr 0.0.0.0>]
> May 19 20:32:12 better pppd[10996]: rcvd [IPCP ConfNak id=0xd <addr
95.209.165.82> <ms-dns1 80.251.192.244> <ms-dns2 80.251.192.245>]
> May 19 20:32:12 better pppd[10996]: sent [IPCP ConfReq id=0xe]
> May 19 20:32:12 better pppd[10996]: rcvd [IPCP ConfReq id=0x1]
> May 19 20:32:12 better pppd[10996]: sent [IPCP ConfAck id=0x1]
> May 19 20:32:12 better pppd[10996]: rcvd [IPCP ConfNak id=0xe <addr
95.209.165.82>]
> May 19 20:32:12 better pppd[10996]: sent [IPCP ConfReq id=0xf <addr
95.209.165.82>]
> May 19 20:32:12 better pppd[10996]: rcvd [IPCP ConfAck id=0xf <addr
95.209.165.82>]
> May 19 20:32:12 better pppd[10996]: Could not determine remote IP address:
defaulting to 10.64.64.64
> May 19 20:32:12 better pppd[10996]: not replacing existing default route via
192.168.1.1
> May 19 20:32:12 better pppd[10996]: Cannot determine ethernet address for
proxy ARP
> May 19 20:32:12 better pppd[10996]: local  IP address 95.209.165.82
> May 19 20:32:12 better pppd[10996]: remote IP address 10.64.64.64

The remote end did not provide its IP address, the local end got 95.209.165.82,
but no DNS servers as DNS option negotiation was abandoned (ipcp-max-failure AKA
maxnakloops was exceeded).  The obvious solution is to fiddle about with 
the configuration parameters.

Yet it's hard to believe for me that the *modem* replies PPP packets, and
establishes PPP connection *before* the physical link is up.  Does it really
work this way?

--
Libor Pechacek
SUSE L3 Team

Re: [PATCH] Accept ms-wins settings provided by server

[James Cameron]

On Thu, Jul 09, 2009 at 12:38:36PM +0000, Libor Pechacek wrote:
> Yet it's hard to believe for me that the *modem* replies PPP packets,
> and establishes PPP connection *before* the physical link is up.  Does
> it really work this way?

Yes, it certainly does.  This can be demonstrated or reproduced quite
easily, with a modem inside an radiofrequency shield enclosure, or
without an antenna (non-radiating dummy load), or beyond reasonable
range.  PPP negotiation occurs between the host and the modem firmware,
yet there is no RF link.

-- 
James Cameron    mailto:quozl@us.netrek.org     http://quozl.netrek.org/