"no matching session" in ng_pppoe.c 1.74.2.4? (RELENG_6)

[cpghost]

On Thu, 06 Dec 2007 13:57:16 +0200
Alexander Motin <mav at FreeBSD.org> wrote:

> cpghost wrote:
> > The problem is that the last mile carrier of the PPP provider
> > that this router is attached to disconnects the ppp session
> > forcibly once every 24h. Before the update, ppp would detect
> > this and reconnect immediately. After the update, ppp doesn't
> > recover gracefully from this anymore, but spits out on the
> > console:
> > 
> > ng_pppoe[5]: no matching session
> > 
> > for hours, and tries to connect again every two minutes without 
> > success, until I manually stop and restart the userland ppp daemon
> > (and then the connection is immediately restored with a new
> > session). I've tried this for a few days now, and it is always the
> > same: it's definitely not a problem on the provider's side: As soon
> > as ppp restarts, it gets a new session without any problems and
> > connects again.
> > 
> > Since the last working sources were from 2007/09/25, and
> > ng_pppoe.c was at rev. 1.74.2.3; and the new revision of
> > ng_pppoe.c is now at 1.74.2.4; I'm suspecting that whatever
> > was changed there could be the cause (because this "no matching
> > session" is being logged from there).
> 
> I have tested and unable to reproduce that myself with ppp -> mpd or
> mpd
> - -> mpd PPPoE connections. Actually I am not sure about any
> difference between reconnect and ppp restart. From the ng_pppoe node
> point of view it should be the same.
> 
> Could you provide tcpdump output for connection tries from your
> Ethernet interface? Use "-pes 0" options please.

Hi again,

no luck this time: I just went through the 24h disconnect with tcpdump
watching, but this time, ppp did reconnect flawlessly:

[... packets belonging to ses 0x1d06 ..., then:]

16:03:28.367734 00:90:1a:a0:15:b7 > 00:00:24:c2:45:74, ethertype PPPoE
  D (0x8863), length 64: PPPoE PADT [ses 0x1d06] 16:03:28.368035

00:00:24:c2:45:74 > 00:90:1a:a0:15:b7, ethertype PPPoE D (0x8863),
  length 38: PPPoE PADT [ses 0x1d06] [Generic-Error "session closed"]

16:06:22.211545 00:00:24:c2:45:74 > ff:ff:ff:ff:ff:ff, ethertype PPPoE
  D (0x8863), length 32: PPPoE PADI [Host-Uniq 0x405B1AC1]
  [Service-Name]

16:06:22.383675 00:90:1a:a0:15:b7 > 00:00:24:c2:45:74, ethertype PPPoE
  D (0x8863), length 66: PPPoE PADO [AC-Name "DSSX43-erx"] [Host-Uniq
  0x405B1AC1] [Service-Name] [AC-Cookie "..7\t.K.,.!y.y.E"]

16:06:22.383871 00:00:24:c2:45:74 > 00:90:1a:a0:15:b7, ethertype PPPoE
  D (0x8863), length 66: PPPoE PADR [Host-Uniq 0x405B1AC1] [AC-Cookie
  "..7\t.K.,.!y.y.E"] [AC-Name "DSSX43-erx"] [Service-Name]

16:06:22.503154 00:90:1a:a0:15:b7 > 00:00:24:c2:45:74, ethertype PPPoE
  D (0x8863), length 66: PPPoE PADS [ses 0xb6b] [Service-Name]
  [Host-Uniq 0x405B1AC1] [AC-Name "DSSX43-erx"] [AC-Cookie
  "..7\t.K.,.!y.y.E"]

16:06:24.243677 00:00:24:c2:45:74 > 00:90:1a:a0:15:b7, ethertype PPPoE
  S (0x8864), length 36: PPPoE  [ses 0xb6b] LCP (0xc021), length 16:
  LCP, Conf-Request (0x01), id 4, length 16

[... more LCP packets belonging to ses 0xb6b ...]

So the PADT/PADI/PADO/PADR/PADS sequence is correct. Maybe the PADT got
lost on its way to this box the last times? Would ng_pppoe.c handle this
case gracefully?

Anyway, I will monitor this a few more days with tcpdump and report back
should a "no matching session" come up again.

Thanks,
-cpghost.

-- 
Cordula's Web. http://www.cordula.ws/