SRX Services Gateway
Highlighted
SRX Services Gateway

PPPoE Session Disconnection

‎03-26-2019 03:53 PM

Hello,
I'm new to the Juniper forums so please forgive me if I have posted in the incorrect place or anything!
I’m experiencing issues with a PPPoE connection from an vSRX running as a gateway.

It’s more a learning experience than a real issue. I seem to have get all the basics working.
The issue I’m having is the PPPoE connection will drop randomly during the day/ night seemingly regardless of load.

My PPP config:
set interfaces pp0 unit 0 apply-macro ISP-Connection
set interfaces pp0 unit 0 ppp-options chap default-chap-secret "insert password here"
set interfaces pp0 unit 0 ppp-options chap local-name "insert username here"
set interfaces pp0 unit 0 ppp-options chap no-rfc2486
set interfaces pp0 unit 0 ppp-options chap passive
set interfaces pp0 unit 0 pppoe-options underlying-interface ge-0/0/0.0
set interfaces pp0 unit 0 pppoe-options auto-reconnect 2
set interfaces pp0 unit 0 family inet mtu 1420
set interfaces pp0 unit 0 family inet negotiate-address

I've set traceoptions on pppoe and am getting the following logs when the connection drops and then restarts:
Mar 25 03:58:48 In Parse TLV: opts 0x0 0x2 ge-0/0/0.0 (null) (null)
Mar 25 03:58:48 pppoed_change_ifl_options: ifname pp0.0
Mar 25 03:58:48 pppoed_change_ifl_options: pp0.0 session mode client
Mar 25 03:58:48 pppoed_change_ifl_options: pp0.0 session up, kernsync false
Mar 25 03:58:48 pppoed_change_ifl_options: pp0.0 session id=2422 (current 2422)
Mar 25 03:58:48 pppoed_change_ifl_options: pp0.0 credit scale 0 max 65535 ppp max payload 1492
Mar 25 03:58:48 pppoed_change_ifl_options: pp0.0 credits disabled, interval 0, scale 0
Mar 25 03:58:48 pppoed_change_ifl_options: pp0.0 credit interval set to 0
Mar 25 03:58:48 pppoed_change_ifl_options: pp0.0 session id=2422
Mar 25 03:58:48 pppoed_change_ifl: ifname pp0.0
Mar 25 03:58:48 Bringing session down for pp0.0
Mar 25 03:58:48 Sent PADT on pp0.0
Mar 25 03:58:48 pppoe_ifl_params_change: ifl pp0.0, ifl sid 2422, param sid 2422
Mar 25 03:58:48 pppoed_ifl_msg_handler pp0.0 ifl 74 op 2 flag 0xc018
Mar 25 03:58:48 In Parse TLV: opts 0x0 0x2 ge-0/0/0.0 (null) (null)
Mar 25 03:58:48 pppoed_change_ifl_options: ifname pp0.0
Mar 25 03:58:48 pppoed_change_ifl_options: pp0.0 session mode client
Mar 25 03:58:48 pppoed_change_ifl_options: pp0.0 session down, kernsync false
Mar 25 03:58:48 pppoed_change_ifl_options: pp0.0 session id=0 (current 0)
Mar 25 03:58:48 pppoed_change_ifl_options: pp0.0 credit scale 0 max 65535 ppp max payload 1492
Mar 25 03:58:48 pppoed_change_ifl_options: pp0.0 credits disabled, interval 0, scale 0
Mar 25 03:58:48 pppoed_change_ifl_options: pp0.0 credit interval set to 0
Mar 25 03:58:48 pppoed_change_ifl_options: pp0.0 session id=0
Mar 25 03:58:48 pppoed_change_ifl: ifname pp0.0
Mar 25 03:58:49 pppoed_ifl_msg_handler pp0.0 ifl 74 op 2 flag 0xc011
Mar 25 03:58:49 In Parse TLV: opts 0x0 0x2 ge-0/0/0.0 (null) (null)
Mar 25 03:58:49 pppoed_change_ifl_options: ifname pp0.0
Mar 25 03:58:49 pppoed_change_ifl_options: pp0.0 session mode client
Mar 25 03:58:49 pppoed_change_ifl_options: pp0.0 session down, kernsync false
Mar 25 03:58:49 pppoed_change_ifl_options: pp0.0 session id=0 (current 0)
Mar 25 03:58:49 pppoed_change_ifl_options: pp0.0 credit scale 0 max 65535 ppp max payload 1492
Mar 25 03:58:49 pppoed_change_ifl_options: pp0.0 credits disabled, interval 0, scale 0
Mar 25 03:58:49 pppoed_change_ifl_options: pp0.0 credit interval set to 0
Mar 25 03:58:49 pppoed_change_ifl_options: pp0.0 session id=0
Mar 25 03:58:49 pppoed_change_ifl: ifname pp0.0
Mar 25 03:58:49 pppoed_ifl_msg_handler pp0.0 ifl 74 op 2 flag 0xc011
Mar 25 03:58:49 In Parse TLV: opts 0x0 0x2 ge-0/0/0.0 (null) (null)
Mar 25 03:58:49 pppoed_change_ifl_options: ifname pp0.0
Mar 25 03:58:49 pppoed_change_ifl_options: pp0.0 session mode client
Mar 25 03:58:49 pppoed_change_ifl_options: pp0.0 session down, kernsync false
Mar 25 03:58:49 pppoed_change_ifl_options: pp0.0 session id=0 (current 0)
Mar 25 03:58:49 pppoed_change_ifl_options: pp0.0 credit scale 0 max 65535 ppp max payload 1492
Mar 25 03:58:49 pppoed_change_ifl_options: pp0.0 credits disabled, interval 0, scale 0
Mar 25 03:58:49 pppoed_change_ifl_options: pp0.0 credit interval set to 0
Mar 25 03:58:49 pppoed_change_ifl_options: pp0.0 session id=0
Mar 25 03:58:49 pppoed_change_ifl: ifname pp0.0
Mar 25 03:58:55 ***Discovery Init: pp0.0
Mar 25 03:58:55 allocated 1510 bytes at 0x4eb000
Mar 25 03:58:55 *totlen=0x6 tp->len=0x2 ntohs(tplen)=0x2 tot=0x6 MAX_L=0x1502
Mar 25 03:58:55 *totlen=0xa tp->len=0x0 ntohs(tplen)=0x0 tot=0xa MAX_L=0x1502
Mar 25 03:58:55 *totlen=0xe tp->len=0x0 ntohs(tplen)=0x0 tot=0xe MAX_L=0x1502
Mar 25 03:58:55 IO send ... PADI for pp0.0
Mar 25 03:58:58 IO send ... Packet resend for pp0.0
Mar 25 03:59:03 IO send ... Packet resend for pp0.0
Mar 25 03:59:12 IO send ... Packet resend for pp0.0
Mar 25 03:59:29 IO send ... Packet resend for pp0.0
Mar 25 04:00:03 IO send ... Packet resend for pp0.0
Mar 25 04:01:09 Discovery phase timedout for intf pp0.0
Mar 25 04:01:12 ***Discovery Init: pp0.0
Mar 25 04:01:12 allocated 1510 bytes at 0x4eb000
Mar 25 04:01:12 *totlen=0x6 tp->len=0x2 ntohs(tplen)=0x2 tot=0x6 MAX_L=0x1502
Mar 25 04:01:12 *totlen=0xa tp->len=0x0 ntohs(tplen)=0x0 tot=0xa MAX_L=0x1502
Mar 25 04:01:12 *totlen=0xe tp->len=0x0 ntohs(tplen)=0x0 tot=0xe MAX_L=0x1502
Mar 25 04:01:12 IO send ... PADI for pp0.0
Mar 25 04:01:15 IO send ... Packet resend for pp0.0
Mar 25 04:01:20 IO send ... Packet resend for pp0.0
Mar 25 04:01:29 IO send ... Packet resend for pp0.0
Mar 25 04:01:46 IO send ... Packet resend for pp0.0
Mar 25 04:02:19 IO send ... Packet resend for pp0.0
Mar 25 04:03:25 Discovery phase timedout for intf pp0.0
Mar 25 04:03:28 ***Discovery Init: pp0.0
Mar 25 04:03:28 allocated 1510 bytes at 0x4eb000
Mar 25 04:03:28 *totlen=0x6 tp->len=0x2 ntohs(tplen)=0x2 tot=0x6 MAX_L=0x1502
Mar 25 04:03:28 *totlen=0xa tp->len=0x0 ntohs(tplen)=0x0 tot=0xa MAX_L=0x1502
Mar 25 04:03:28 *totlen=0xe tp->len=0x0 ntohs(tplen)=0x0 tot=0xe MAX_L=0x1502
Mar 25 04:03:28 IO send ... PADI for pp0.0
Mar 25 04:03:28 Discovery Input: PADO packet received on uifl (idx 73)
Mar 25 04:03:28 Received AC name acc-aln1.wh\x01\x03 configured AC name on uifl (idx 73)
Mar 25 04:03:28 code: 7 outlen=0x1e pt->len: 0xb
Mar 25 04:03:28 *totlen=0x2d tp->len=0xb ntohs(tplen)=0xb tot=0x2d MAX_L=0x1502
Mar 25 04:03:28 code: 7 outlen=0x2d pt->len: 0x10
Mar 25 04:03:28 *totlen=0x41 tp->len=0x10 ntohs(tplen)=0x10 tot=0x41 MAX_L=0x1502
Mar 25 04:03:28 *totlen=0x45 tp->len=0x0 ntohs(tplen)=0x0 tot=0x45 MAX_L=0x1502
Mar 25 04:03:28 IO send ... PADR for pp0.0
Mar 25 04:03:28 Discovery Input: PADS packet received on uifl (idx 73)
Mar 25 04:03:28 pppoed_client_discovery_input: params.remote_mac="remotemac" params.confirmed_mtu=0
Mar 25 04:03:28 pppoe_ifl_params_change: ifl pp0.0, ifl sid 2975, param sid 2975
Mar 25 04:03:28 pppoed_ifl_msg_handler pp0.0 ifl 74 op 2 flag 0xc011
Mar 25 04:03:28 pppoed_change_ifl: ifname pp0.0
Mar 25 04:03:28 pppoed_ifl_msg_handler pp0.0 ifl 74 op 2 flag 0xc011
Mar 25 04:03:28 In Parse TLV: opts 0x0 0x2 ge-0/0/0.0 (null) (null)
Mar 25 04:03:28 pppoed_change_ifl_options: ifname pp0.0
Mar 25 04:03:28 pppoed_change_ifl_options: pp0.0 session mode client
Mar 25 04:03:28 pppoed_change_ifl_options: pp0.0 session up, kernsync false
Mar 25 04:03:28 pppoed_change_ifl_options: pp0.0 session id=2975 (current 2975)
Mar 25 04:03:28 pppoed_change_ifl_options: pp0.0 credit scale 0 max 65535 ppp max payload 1492
Mar 25 04:03:28 pppoed_change_ifl_options: pp0.0 credits disabled, interval 0, scale 0
Mar 25 04:03:28 pppoed_change_ifl_options: pp0.0 credit interval set to 0
Mar 25 04:03:28 pppoed_change_ifl_options: pp0.0 session id=2975
Mar 25 04:03:28 pppoed_change_ifl: ifname pp0.0
Mar 25 04:03:28 pppoed_ifl_msg_handler pp0.0 ifl 74 op 2 flag 0xc011
Mar 25 04:03:28 In Parse TLV: opts 0x0 0x2 ge-0/0/0.0 (null) (null)
Mar 25 04:03:28 pppoed_change_ifl_options: ifname pp0.0
Mar 25 04:03:28 pppoed_change_ifl_options: pp0.0 session mode client
Mar 25 04:03:28 pppoed_change_ifl_options: pp0.0 session up, kernsync false
Mar 25 04:03:28 pppoed_change_ifl_options: pp0.0 session id=2975 (current 2975)
Mar 25 04:03:28 pppoed_change_ifl_options: pp0.0 credit scale 0 max 65535 ppp max payload 1492
Mar 25 04:03:28 pppoed_change_ifl_options: pp0.0 credits disabled, interval 0, scale 0
Mar 25 04:03:28 pppoed_change_ifl_options: pp0.0 credit interval set to 0
Mar 25 04:03:28 pppoed_change_ifl_options: pp0.0 session id=2975
Mar 25 04:03:28 pppoed_change_ifl: ifname pp0.0
Mar 25 04:03:28 pppoed_ifl_msg_handler pp0.0 ifl 74 op 2 flag 0xc011
Mar 25 04:03:28 In Parse TLV: opts 0x0 0x2 ge-0/0/0.0 (null) (null)
Mar 25 04:03:28 pppoed_change_ifl_options: ifname pp0.0
Mar 25 04:03:28 pppoed_change_ifl_options: pp0.0 session mode client
Mar 25 04:03:28 pppoed_change_ifl_options: pp0.0 session up, kernsync false
Mar 25 04:03:28 pppoed_change_ifl_options: pp0.0 session id=2975 (current 2975)
Mar 25 04:03:28 pppoed_change_ifl_options: pp0.0 credit scale 0 max 65535 ppp max payload 1492
Mar 25 04:03:28 pppoed_change_ifl_options: pp0.0 credits disabled, interval 0, scale 0
Mar 25 04:03:28 pppoed_change_ifl_options: pp0.0 credit interval set to 0
Mar 25 04:03:28 pppoed_change_ifl_options: pp0.0 session id=2975
Mar 25 04:03:28 pppoed_change_ifl: ifname pp0.0
Mar 25 04:03:28 pppoed_ifl_msg_handler pp0.0 ifl 74 op 2 flag 0xc011
Mar 25 04:03:28 In Parse TLV: opts 0x0 0x2 ge-0/0/0.0 (null) (null)
Mar 25 04:03:28 pppoed_change_ifl_options: ifname pp0.0
Mar 25 04:03:28 pppoed_change_ifl_options: pp0.0 session mode client
Mar 25 04:03:28 pppoed_change_ifl_options: pp0.0 session up, kernsync false
Mar 25 04:03:28 pppoed_change_ifl_options: pp0.0 session id=2975 (current 2975)
Mar 25 04:03:28 pppoed_change_ifl_options: pp0.0 credit scale 0 max 65535 ppp max payload 1492
Mar 25 04:03:28 pppoed_change_ifl_options: pp0.0 credits disabled, interval 0, scale 0
Mar 25 04:03:28 pppoed_change_ifl_options: pp0.0 credit interval set to 0
Mar 25 04:03:28 pppoed_change_ifl_options: pp0.0 session id=2975
Mar 25 04:03:28 pppoed_change_ifl: ifname pp0.0
Mar 25 04:03:28 pppoed_ifl_msg_handler pp0.0 ifl 74 op 2 flag 0xc010
Mar 25 04:03:28 In Parse TLV: opts 0x0 0x2 ge-0/0/0.0 (null) (null)
Mar 25 04:03:28 pppoed_change_ifl_options: ifname pp0.0
Mar 25 04:03:28 pppoed_change_ifl_options: pp0.0 session mode client
Mar 25 04:03:28 pppoed_change_ifl_options: pp0.0 session up, kernsync false
Mar 25 04:03:28 pppoed_change_ifl_options: pp0.0 session id=2975 (current 2975)
Mar 25 04:03:28 pppoed_change_ifl_options: pp0.0 credit scale 0 max 65535 ppp max payload 1492
Mar 25 04:03:28 pppoed_change_ifl_options: pp0.0 credits disabled, interval 0, scale 0
Mar 25 04:03:28 pppoed_change_ifl_options: pp0.0 credit interval set to 0
Mar 25 04:03:28 pppoed_change_ifl_options: pp0.0 session id=2975
Mar 25 04:03:28 pppoed_change_ifl: ifname pp0.0

So really, I’m a bit stumped about what this is actually telling me but it’s pretty much the same every time it disconnects.

I can see that I am sending PADT's, does this mean that I am terminating the connection? or is this in response to the connection being terminated?

Is my config right? did I miss something?
I will say that this disconnect issue was also an issue I had on a different firewall on the same connection, as well as the provided router that the isp gave me. So, I’m only partly sure it’s not my fault, but if someone can break that down and explain what its telling me then I will be able to "hopefully" go about fixing the issue.

Any help would be amazing!

Ryan

5 REPLIES 5
Highlighted
SRX Services Gateway

Re: PPPoE Session Disconnection

‎03-26-2019 10:14 PM

Hi Ryan,

 

It will be worth to enable PPP logs as well. This will be confirm if PADT is send because of LCP term-req or LCP keepalive failure.

 

Regards,
Rahul

Highlighted
SRX Services Gateway

Re: PPPoE Session Disconnection

[ Edited ]
‎03-27-2019 01:07 PM

Hello Rahul,

 

Thank you for the advice, i have now enabled and i shall see what it logs when the connection drops again!

 

Many thanks,

 

Ryan

Highlighted
SRX Services Gateway

Re: PPPoE Session Disconnection

‎03-27-2019 02:29 PM

Hello Ryan,

 

I see that you are getting IP via dhcp.

 

set interfaces pp0 unit 0 family inet negotiate-address

 

I would recommend you to check if the disconnections coincide with the lease time of the dynamic IP. 

 

Thanks!

Highlighted
SRX Services Gateway

Re: PPPoE Session Disconnection

‎03-27-2019 03:21 PM

So here is the dump from the PPP trace options regarding the dropping and then re connecting of the PPPoE connection! 

Any thoughts? Is it my end dropping this, i cant see anything stating that im dropping the connection?

 

Any help is amazing,

 

Mar 27 21:43:13 op change ifl pp0.0 idx 74 devindex 129 flags c018
Mar 27 21:43:13 op change ifl pp0.0 idx 74 devindex 129
Mar 27 21:43:13 IFL State TLV:
Mar 27 21:43:13 State - Opened
Mar 27 21:43:13 Auth Chap flags - 0e
Mar 27 21:43:13 Auth Pap flags - 00
Mar 27 21:43:13 Options:
Mar 27 21:43:13 MRU: 1492
Mar 27 21:43:13 Auth proto: CHAP, algo: MD5
Mar 27 21:43:13 Magic Num: magic number
Mar 27 21:43:13 IFL Config TLV:
Mar 27 21:43:13 Media flags - 0000
Mar 27 21:43:13 Auth protocol CHAP - 0xc223
Mar 27 21:43:13 PPP flags - 09
Mar 27 21:43:13 MRU - 1492
Mar 27 21:43:13 pppd_iflm_handle_change: ifl->ifl_flags 0xc010 iflm->iflm_flags 0xc018
Mar 27 21:43:13 pp0.0: Session LCP max configuration request count 254 is set(254 default count)
Mar 27 21:43:13 pp0.0: pppd_ncp_close_proto
Mar 27 21:43:13 DNS Server primary (DNS1)
Mar 27 21:43:13 DNS Server secondary (DNS2)
Mar 27 21:43:14 pp0.0: IPCP - State changed to: Closed
Mar 27 21:43:14 IPCP: Set IFFF_HARDDOWN pp0.0
Mar 27 21:43:14 pp0.0: IFF af inet - Building TLV (changed 0xb)
Mar 27 21:43:14 pp0.0: IFF af inet - Building flags (0x80000000), cflags (0x1000804)
Mar 27 21:43:14 pp0.0: IFF af inet - Building NCP, proto 0x8021, len 16
Mar 27 21:43:14 pp0.0: IFF af inet - Building IFA delete
Mar 27 21:43:14 Upd iff pp0.0 af inet iflidx 74 devidx 129: done
Mar 27 21:43:14 pp0.0: CHAP - Stopping answer wait timer
Mar 27 21:43:14 pp0.0: IFL - Building TLV (changed 0x5)
Mar 27 21:43:14 pp0.0: IFL - Building flags (0xc019), cflags (0x1)
Mar 27 21:43:14 pp0.0: IFL - Building AUTH, len 3
Mar 27 21:43:14 Upd ifl pp0.0 iflidx 74 devidx 129: done
Mar 27 21:43:14 pp0.0: LCP - State changed to: Closed
Mar 27 21:43:14 pp0.0: IFL - Building TLV (changed 0x3)
Mar 27 21:43:14 pp0.0: IFL - Building flags (0xc019), cflags (0x1)
Mar 27 21:43:14 pp0.0: IFL - Building LCP, len 20
Mar 27 21:43:14 Upd ifl pp0.0 iflidx 74 devidx 129: done
Mar 27 21:43:14 pp0.0: LCP - Renegotiation to happen after kernel close
Mar 27 21:43:14 pp0.0: Session phase changed Network -> Establish
Mar 27 21:43:14 op delete ifa pp0.0 af inet iflidx 74 devindex 129
Mar 27 21:43:14 Deleting ifa pp0.0 iflidx 74 af inet
Mar 27 21:43:14 op change ifl pp0.0 idx 74 devindex 129 flags c011
Mar 27 21:43:14 op change ifl pp0.0 idx 74 devindex 129
Mar 27 21:43:14 IFL State TLV:
Mar 27 21:43:14 State - Closed
Mar 27 21:43:14 Auth Chap flags - 0a
Mar 27 21:43:14 Auth Pap flags - 00
Mar 27 21:43:14 Options:
Mar 27 21:43:14 MRU: 1492
Mar 27 21:43:14 Magic Num: magic
Mar 27 21:43:14 IFL Config TLV:
Mar 27 21:43:14 Media flags - 0000
Mar 27 21:43:14 Auth protocol CHAP - 0xc223
Mar 27 21:43:14 PPP flags - 00
Mar 27 21:43:14 MRU - 1492
Mar 27 21:43:14 pppd_iflm_handle_change: ifl->ifl_flags 0xc019 iflm->iflm_flags 0xc011
Mar 27 21:43:14 pp0.0: Session LCP max configuration request count 254 is set(254 default count)
Mar 27 21:43:14 pp0.0: LCP - Starting protocol timer (3 sec, 0 nsec)
Mar 27 21:43:14 pp0.0: Sent 18 byte (10 data bytes) PPP packet: 0x21 0xc0 0x0f 0x01
Mar 27 21:43:14 pp0.0: LCP - State changed to: Creq-sent
Mar 27 21:43:14 pp0.0: LCP - Stopping protocol timer
Mar 27 21:43:14 pp0.0: LCP - State changed to: Closed
Mar 27 21:43:14 pp0.0: Session phase changed Establish -> Disabled
Mar 27 21:43:14 op change iff pp0.0 af inet iflidx 74 devindex 129
Mar 27 21:43:14 IFF State TLV:
Mar 27 21:43:14 State - Closed
Mar 27 21:43:14 Options:
Mar 27 21:43:14 Address: local "my ip", remote "remote ip"
Mar 27 21:43:14 Primary DNS: DNS1
Mar 27 21:43:14 Secondary DNS: DNS2
Mar 27 21:45:37 op change ifl pp0.0 idx 74 devindex 129 flags c011
Mar 27 21:45:37 op change ifl pp0.0 idx 74 devindex 129
Mar 27 21:45:37 pppd_iflm_handle_change: ifl->ifl_flags 0xc011 iflm->iflm_flags 0xc011
Mar 27 21:45:37 op change ifl pp0.0 idx 74 devindex 129 flags c011
Mar 27 21:45:37 op change ifl pp0.0 idx 74 devindex 129
Mar 27 21:45:37 IFL State TLV:
Mar 27 21:45:37 State - Closed
Mar 27 21:45:37 Auth Chap flags - 0a
Mar 27 21:45:37 Auth Pap flags - 00
Mar 27 21:45:37 Options:
Mar 27 21:45:37 MRU: 1492
Mar 27 21:45:37 Magic Num: magic
Mar 27 21:45:37 IFL Config TLV:
Mar 27 21:45:37 Media flags - 0000
Mar 27 21:45:37 Auth protocol CHAP - 0xc223
Mar 27 21:45:37 PPP flags - 01
Mar 27 21:45:37 MRU - 1492
Mar 27 21:45:37 pppd_iflm_handle_change: ifl->ifl_flags 0xc011 iflm->iflm_flags 0xc011
Mar 27 21:45:37 pp0.0: Session LCP max configuration request count 254 is set(254 default count)
Mar 27 21:45:37 pp0.0: LCP - Starting protocol timer (3 sec, 0 nsec)
Mar 27 21:45:37 pp0.0: Sent 18 byte (10 data bytes) PPP packet: 0x21 0xc0 0x10 0x01
Mar 27 21:45:37 pp0.0: LCP - State changed to: Creq-sent
Mar 27 21:45:37 pp0.0: Session phase changed Disabled -> Establish
Mar 27 21:45:37 pp0.0: Received 40 byte PPP packet: 0xc0 0x21 0x02
Mar 27 21:45:37 pp0.0: LCP - Stopping protocol timer
Mar 27 21:45:37 pp0.0: LCP - State changed to: Ack-rcvd
Mar 27 21:45:37 pp0.0: LCP - Starting protocol timer (3 sec, 0 nsec)
Mar 27 21:45:37 pppd_msg_input: recvmsg: Resource temporarily unavailable
Mar 27 21:45:40 pp0.0: LCP - Timer expired
Mar 27 21:45:40 pp0.0: LCP - Starting protocol timer (3 sec, 0 nsec)
Mar 27 21:45:40 pp0.0: Sent 18 byte (10 data bytes) PPP packet: 0x21 0xc0 0x11 0x01
Mar 27 21:45:40 pp0.0: LCP - State changed to: Creq-sent
Mar 27 21:45:40 pp0.0: Received 40 byte PPP packet: 0xc0 0x21 0x02
Mar 27 21:45:40 pp0.0: LCP - Stopping protocol timer
Mar 27 21:45:40 pp0.0: LCP - State changed to: Ack-rcvd
Mar 27 21:45:40 pp0.0: LCP - Starting protocol timer (3 sec, 0 nsec)
Mar 27 21:45:40 pppd_msg_input: recvmsg: Resource temporarily unavailable
Mar 27 21:45:40 pp0.0: Received 40 byte PPP packet: 0xc0 0x21 0x01
Mar 27 21:45:40 pp0.0: Sent 23 byte (15 data bytes) PPP packet: 0x21 0xc0 0x8e 0x02
Mar 27 21:45:40 pp0.0: LCP - Stopping protocol timer
Mar 27 21:45:40 pp0.0: LCP - State changed to: Opened
Mar 27 21:45:40 pp0.0: IFL - Building TLV (changed 0xa)
Mar 27 21:45:40 pp0.0: IFL - Building magic magic, len 8
Mar 27 21:45:40 pp0.0: IFL - Building LCP, len 20
Mar 27 21:45:40 Upd ifl pp0.0 iflidx 74 devidx 129: done
Mar 27 21:45:40 pppd_msg_input: recvmsg: Resource temporarily unavailable
Mar 27 21:45:40 op change ifl pp0.0 idx 74 devindex 129 flags c011
Mar 27 21:45:40 op change ifl pp0.0 idx 74 devindex 129
Mar 27 21:45:40 IFL State TLV:
Mar 27 21:45:40 State - Opened
Mar 27 21:45:40 Auth Chap flags - 0e
Mar 27 21:45:40 Auth Pap flags - 00
Mar 27 21:45:40 Options:
Mar 27 21:45:40 MRU: 1492
Mar 27 21:45:40 Auth proto: CHAP, algo: MD5
Mar 27 21:45:40 Magic Num: magic
Mar 27 21:45:40 IFL Config TLV:
Mar 27 21:45:40 Media flags - 0000
Mar 27 21:45:40 Auth protocol CHAP - 0xc223
Mar 27 21:45:40 PPP flags - 01
Mar 27 21:45:40 MRU - 1492
Mar 27 21:45:40 pppd_iflm_handle_change: ifl->ifl_flags 0xc011 iflm->iflm_flags 0xc011
Mar 27 21:45:40 pp0.0: Session LCP max configuration request count 254 is set(254 default count)
Mar 27 21:45:40 pp0.0: CHAP - Stopping answer wait timer
Mar 27 21:45:40 pp0.0: CHAP - Starting answer wait timer 30 sec, 0 nsec
Mar 27 21:45:40 pp0.0: Session phase changed Establish -> Authenticate
Mar 27 21:45:40 pp0.0: Received 67 byte PPP packet: 0xc2 0x23 0x01
Mar 27 21:45:40 pp0.0: CHAP - recieve new chap challenge, restart answer timer
Mar 27 21:45:40 pp0.0: Sent 47 byte (39 data bytes) PPP packet: 0x23 0xc2 0x01 0x02
Mar 27 21:45:40 pppd_msg_input: recvmsg: Resource temporarily unavailable
Mar 27 21:45:40 pp0.0: Received 40 byte PPP packet: 0xc0 0x21 0x01
Mar 27 21:45:40 pp0.0: CHAP - Stopping answer wait timer
Mar 27 21:45:40 pp0.0: LCP - State changed to: Closed
Mar 27 21:45:40 pp0.0: IFL - Building TLV (changed 0x3)
Mar 27 21:45:40 pp0.0: IFL - Building flags (0xc011), cflags (0x1)
Mar 27 21:45:40 pp0.0: IFL - Building LCP, len 20
Mar 27 21:45:40 Upd ifl pp0.0 iflidx 74 devidx 129: done
Mar 27 21:45:40 pp0.0: LCP - Renegotiation to happen after kernel close
Mar 27 21:45:40 pp0.0: Session phase changed Authenticate -> Establish
Mar 27 21:45:40 pp0.0: LCP - keep LCP conf_req before reneg!
Mar 27 21:45:40 pp0.0: LCP - Renegotiation to happen after kernel close
Mar 27 21:45:40 pppd_msg_input: recvmsg: Resource temporarily unavailable
Mar 27 21:45:40 op change ifl pp0.0 idx 74 devindex 129 flags c011
Mar 27 21:45:40 op change ifl pp0.0 idx 74 devindex 129
Mar 27 21:45:40 IFL State TLV:
Mar 27 21:45:40 State - Closed
Mar 27 21:45:40 Auth Chap flags - 0a
Mar 27 21:45:40 Auth Pap flags - 00
Mar 27 21:45:40 Options:
Mar 27 21:45:40 MRU: 1492
Mar 27 21:45:40 Magic Num: 3106908791
Mar 27 21:45:40 IFL Config TLV:
Mar 27 21:45:40 Media flags - 0000
Mar 27 21:45:40 Auth protocol CHAP - 0xc223
Mar 27 21:45:40 PPP flags - 01
Mar 27 21:45:40 MRU - 1492
Mar 27 21:45:40 pppd_iflm_handle_change: ifl->ifl_flags 0xc011 iflm->iflm_flags 0xc011
Mar 27 21:45:40 pp0.0: Session LCP max configuration request count 254 is set(254 default count)
Mar 27 21:45:40 pp0.0: LCP - Starting protocol timer (3 sec, 0 nsec)
Mar 27 21:45:40 pp0.0: Sent 18 byte (10 data bytes) PPP packet: 0x21 0xc0 0x12 0x01
Mar 27 21:45:40 pp0.0: LCP - Send pending lcp conf-ack
Mar 27 21:45:40 pp0.0: Sent 19 byte (11 data bytes) PPP packet: 0x21 0xc0 0xad 0x02
Mar 27 21:45:40 pp0.0: LCP - State changed to: Ack-sent
Mar 27 21:45:40 pp0.0: Received 40 byte PPP packet: 0xc2 0x23 0x01
Mar 27 21:45:40 pp0.0: Received 40 byte PPP packet: 0xc0 0x21 0x02
Mar 27 21:45:40 pp0.0: LCP - Stopping protocol timer
Mar 27 21:45:40 pp0.0: LCP - State changed to: Opened
Mar 27 21:45:40 pp0.0: IFL - Building TLV (changed 0xa)
Mar 27 21:45:40 pp0.0: IFL - Building magic 3106915364, len 8
Mar 27 21:45:40 pp0.0: IFL - Building LCP, len 20
Mar 27 21:45:40 Upd ifl pp0.0 iflidx 74 devidx 129: done
Mar 27 21:45:40 pppd_msg_input: recvmsg: Resource temporarily unavailable
Mar 27 21:45:40 op change ifl pp0.0 idx 74 devindex 129 flags c011
Mar 27 21:45:40 op change ifl pp0.0 idx 74 devindex 129
Mar 27 21:45:40 IFL State TLV:
Mar 27 21:45:40 State - Opened
Mar 27 21:45:40 Auth Chap flags - 0e
Mar 27 21:45:40 Auth Pap flags - 00
Mar 27 21:45:40 Options:
Mar 27 21:45:40 MRU: 1492
Mar 27 21:45:40 Auth proto: CHAP, algo: MD5
Mar 27 21:45:40 Magic Num: 3106915364
Mar 27 21:45:40 IFL Config TLV:
Mar 27 21:45:40 Media flags - 0000
Mar 27 21:45:40 Auth protocol CHAP - 0xc223
Mar 27 21:45:40 PPP flags - 01
Mar 27 21:45:40 MRU - 1492
Mar 27 21:45:40 pppd_iflm_handle_change: ifl->ifl_flags 0xc011 iflm->iflm_flags 0xc011
Mar 27 21:45:40 pp0.0: Session LCP max configuration request count 254 is set(254 default count)
Mar 27 21:45:40 pp0.0: CHAP - Stopping answer wait timer
Mar 27 21:45:40 pp0.0: CHAP - Starting answer wait timer 30 sec, 0 nsec
Mar 27 21:45:40 pp0.0: Session phase changed Establish -> Authenticate
Mar 27 21:45:44 pp0.0: Received 40 byte PPP packet: 0xc2 0x23 0x01
Mar 27 21:45:44 pp0.0: CHAP - recieve new chap challenge, restart answer timer
Mar 27 21:45:44 pp0.0: Sent 47 byte (39 data bytes) PPP packet: 0x23 0xc2 0xc6 0x02
Mar 27 21:45:44 pppd_msg_input: recvmsg: Resource temporarily unavailable
Mar 27 21:45:44 pp0.0: Received 40 byte PPP packet: 0xc2 0x23 0x03
Mar 27 21:45:44 pp0.0: CHAP - CHAP Authentication is succesful, interface pp0.0
Mar 27 21:45:44 pp0.0: CHAP - Stopping answer wait timer
Mar 27 21:45:44 pp0.0: IFL - Building TLV (changed 0x5)
Mar 27 21:45:44 pp0.0: IFL - Building flags (0xc010), cflags (0x1)
Mar 27 21:45:44 pp0.0: IFL - Building AUTH, len 3
Mar 27 21:45:44 Upd ifl pp0.0 iflidx 74 devidx 129: done
Mar 27 21:45:44 pppd_msg_input: recvmsg: Resource temporarily unavailable
Mar 27 21:45:44 op change ifl pp0.0 idx 74 devindex 129 flags c010
Mar 27 21:45:44 op change ifl pp0.0 idx 74 devindex 129
Mar 27 21:45:44 IFL State TLV:
Mar 27 21:45:44 State - Opened
Mar 27 21:45:44 Auth Chap flags - 0e
Mar 27 21:45:44 Auth Pap flags - 00
Mar 27 21:45:44 Options:
Mar 27 21:45:44 MRU: 1492
Mar 27 21:45:44 Auth proto: CHAP, algo: MD5
Mar 27 21:45:44 Magic Num: 3106915364
Mar 27 21:45:44 IFL Config TLV:
Mar 27 21:45:44 Media flags - 0000
Mar 27 21:45:44 Auth protocol CHAP - 0xc223
Mar 27 21:45:44 PPP flags - 01
Mar 27 21:45:44 MRU - 1492
Mar 27 21:45:44 pppd_iflm_handle_change: ifl->ifl_flags 0xc010 iflm->iflm_flags 0xc010
Mar 27 21:45:44 pp0.0: Session LCP max configuration request count 254 is set(254 default count)
Mar 27 21:45:44 pp0.0: IPCP - ADDRESS using local address: 0.0.0.0
Mar 27 21:45:44 pp0.0: IPCP - Config-Request, Built 6 bytes of PRIMARY DNS at 0x5bfed816
Mar 27 21:45:44 pp0.0: IPCP - Starting protocol timer (3 sec, 0 nsec)
Mar 27 21:45:44 pp0.0: Sent 26 byte (18 data bytes) PPP packet: 0x21 0x80 0x13 0x01
Mar 27 21:45:44 pp0.0: IPCP - State changed to: Creq-sent
Mar 27 21:45:44 pp0.0: Session phase changed Authenticate -> Network
Mar 27 21:45:44 pp0.0: Received 40 byte PPP packet: 0x80 0x21 0x03
Mar 27 21:45:44 pp0.0: pppd_ncp_process_nak_rej
Mar 27 21:45:44 pp0.0: IPCP - Handling Conf-Nak
Mar 27 21:45:44 pp0.0: IPCP - Negotiated address
Mar 27 21:45:44 pp0.0: IPCP - Stopping protocol timer
Mar 27 21:45:44 pp0.0: IPCP - Starting protocol timer (3 sec, 0 nsec)
Mar 27 21:45:44 pppd_msg_input: recvmsg: Resource temporarily unavailable
Mar 27 21:45:47 pp0.0: IPCP - Timer expired
Mar 27 21:45:47 pp0.0: IPCP - Proto timeout
Mar 27 21:45:47 pp0.0: IPCP - ADDRESS using local address: my ip
Mar 27 21:45:47 pp0.0: IPCP - Starting protocol timer (3 sec, 0 nsec)
Mar 27 21:45:47 pp0.0: Sent 14 byte (6 data bytes) PPP packet: 0x21 0x80 0x14 0x01
Mar 27 21:45:47 pp0.0: IPCP - State changed to: Creq-sent
Mar 27 21:45:47 pp0.0: Received 40 byte PPP packet: 0x80 0x21 0x01
Mar 27 21:45:47 pp0.0: pppd_ncp_process_conf_req
Mar 27 21:45:47 pp0.0: IPCP - Remote peer requesting address "remote ip"
Mar 27 21:45:47 pp0.0: IPCP - Need to negotiate address
Mar 27 21:45:47 pp0.0: IPCP - Current state Creq-sent
Mar 27 21:45:47 pp0.0: Sent 14 byte (6 data bytes) PPP packet: 0x21 0x80 0x6f 0x02
Mar 27 21:45:47 pp0.0: IPCP - State changed to: Ack-sent
Mar 27 21:45:47 pppd_msg_input: recvmsg: Resource temporarily unavailable
Mar 27 21:45:47 pp0.0: Received 40 byte PPP packet: 0x80 0x21 0x02
Mar 27 21:45:47 pp0.0: pppd_ncp_process_conf_ack
Mar 27 21:45:47 pp0.0: IPCP - Stopping protocol timer
Mar 27 21:45:47 pp0.0: IPCP - Current state Ack-sent
Mar 27 21:45:47 pp0.0: IPCP - State changed to: Opened
Mar 27 21:45:47 DNS Server primary (DNS1)
Mar 27 21:45:47 DNS Server secondary (DNS2)
Mar 27 21:45:49 pp0.0: IFF af inet - Building TLV (changed 0x7)
Mar 27 21:45:49 pp0.0: IFF af inet - Building flags (0x80000000), cflags (0x1000800)
Mar 27 21:45:49 pp0.0: IFF af inet - Building NCP, proto 0x8021, len 16
Mar 27 21:45:49 pp0.0: IFF af inet - Building IFA add
Mar 27 21:45:49 Upd iff pp0.0 af inet iflidx 74 devidx 129: done
Mar 27 21:45:49 pppd_msg_input: recvmsg: Resource temporarily unavailable
Mar 27 21:45:49 op change iff pp0.0 af inet iflidx 74 devindex 129
Mar 27 21:45:49 IFF State TLV:
Mar 27 21:45:49 State - Opened
Mar 27 21:45:49 Options:
Mar 27 21:45:49 Address: local my ip, remote "remote ip"
Mar 27 21:45:49 Primary DNS: DNS1
Mar 27 21:45:49 Secondary DNS: DNS2
Mar 27 21:45:49 op add ifa pp0.0 af inet iflidx 74 devindex 129
Mar 27 21:45:49 pp0: Local IP address set to my ip/32
Mar 27 21:45:49 pp0: Remote IP address set to "remote ip"32
Mar 27 21:45:49 Added ifa pp0.0 iflidx 74 af inet (primary address)

Highlighted
SRX Services Gateway

Re: PPPoE Session Disconnection

‎03-27-2019 03:24 PM

Hello TheDisciple,

 

The disconnects are sometime a few seconds apart and sometimes a day or two apart. They seem completely random. 

 

Really annoying Smiley Sad

 

Thank you though! Out of interest how would I see how long the lease has left?

 

Many thanks,