Request for 'mlp debug' dumps from Efficient 5861

Greetings:

This is a request to users of Efficient 5861 DMT routers who connect to a remote using ATM and PPP.

We need to debug PPP failures with an uncooperative ISP; as a baseline for comparison we are seeking a debug dump of a successful link startup and PAP authentication (please substitute your UID and PWD with placeholders). Most 5800 series firmware permits use of the 'mlp debug' commands. Please capture a console or telnet session with logging enabled and run these commands before restarting the connection to the remote:

'mlp debug lcp' 'mlp debug ncp' 'mlp debug ipcp' 'mlp debug auth' 'mlp debug ncpstates'

Posting the results to this newsgroup would be useful to those troubleshooting PPP problems by permitting comparisons to their own logs. We have no documentation on how the Efficient firmware responds to bad state changes and many other PPP errors.

Regards,

Michael Grigoni Cybertheque Museum

Reply to
msg
Loading thread data ...

We solved our PPP problem; the ISP is misconfigured for bi-directional authentication. For the record here is a good mlp debug trace:

# 01/19/2006-13:16:11:DOD: connecting to using 0*32 over ATM-VC/1 NCP: LCP: opening NCP connection: s/w control NCP: LCP: state 0, event 2, actions 10 LCP: Event 10 notification! LCP: TLS NCP: LCP: state 0, event 2, to state 1 NCP: LCP: state 1, event 0, actions 240 NCP: LCP: sending code 1, len=14, id=1 code 1: 06 0c code 5: dc 94 6c dc NCP: LCP: state 1, event 0, to state 6 LCP: LCP: RX len=14, reallen=14, code=1 id=3a, state=6 NCP: LCP: RX len=14, reallen=14, code=1 id=3a, state=6 ACK code 3 len 4... c0 23 ...ACK code 5 len 6... d7 ca d3 96 ...ACK ACK NCP: LCP: state 6, event 6, actions 400 NCP: LCP: sending code 2, len=14, id=3a code 3: c0 23 code 5: d7 ca d3 96 NCP: LCP: state 6, event 6, to state 8 LCP: LCP: RX len=14, reallen=14, code=2 id=1, state=8 NCP: LCP: RX len=14, reallen=14, code=2 id=1, state=8 code 1 len 4... 6 c ...processed code 5 len 6... dc 94 6c dc ...processed NCP: LCP: state 8, event 8, actions 42 LCP: Event 2 notification! LCP: TLU pppp = 0x33856c PPP: LCP: wewish 201 wemust 0 wegot 201 PPP: LCP: wecan 273 weacked 240 PPP: LCP: our magic dc946cdc their magic d7cad396 PPP: LCP: our mru 1548 their mru 1500 PPP: LCP: our mrru 1548 their mrru 0 LCP: start authen PAP: send id= pwd=, seq 1 NCP: LCP: state 8, event 8, to state 9

01/19/2006-13:16:11:PPP: remote will authenticate PAP: got pkt code 2, seq 1 AUTH: both auths now ok PPP: LCP: moving to network phase remote , ENC_TX_TYPE = 0, ENC_RX_TYPE = 0 IPNCP: setladdr=xxx.xxx.xxx.xxx defladdr=xxx.xxx.xxx.xxx state=IPNCP_OLDADDR NCP: IPNCP: opening NCP connection: LSAP BIND NCP: CCP: opening NCP connection: LSAP BIND NCP: IPNCP: state 0, event 2, actions 10 IPNCP: event 10 notified NCP: IPNCP: state 0, event 2, to state 1 NCP: CCP: state 0, event 2, actions 10 NCP: CCP: state 0, event 2, to state 1 NCP: IPNCP: state 1, event 0, actions 240 NCP: IPNCP: sending code 1, len=20, id=1 code 1: d8 fb b1 69 d1 f0 e2 80 code 2: 00 2d 0f 00 NCP: IPNCP: state 1, event 0, to state 6 NCP: CCP: state 1, event 0, actions 240 NCP: CCP: state 1, event 0, to state 6 NCP: IPNCP: RX len=10, reallen=10, code=1 id=9c, state=6 ACK code 3 len 6... d1 f0 e0 ef ...ACK ACK NCP: IPNCP: state 6, event 6, actions 400 NCP: IPNCP: sending code 2, len=10, id=9c code 3: d1 f0 e0 ef NCP: IPNCP: state 6, event 6, to state 8 01/19/2006-13:16:11:DOD: link to cpro_1 over ATM-VC/1 is now up NCP: IPNCP: RX len=10, reallen=10, code=4 id=1, state=8 code 2 len 6... 0 2d f 0 ...processed NCP: IPNCP: state 8, event 9, actions 240 NCP: IPNCP: sending code 1, len=14, id=2 code 1: d8 fb b1 69 d1 f0 e0 ef NCP: IPNCP: state 8, event 9, to state 8 NCP: IPNCP: RX len=14, reallen=14, code=3 id=2, state=8 code 1 len 10... d1 f0 f3 b1 d1 f0 e0 ef ...IPADDRESSES: cpro_1 Slave addr = yyy.yyy.yyy.yyy processed NCP: IPNCP: state 8, event 9, actions 240 NCP: IPNCP: sending code 1, len=14, id=3 code 1: d1 f0 f3 b1 d1 f0 e0 ef NCP: IPNCP: state 8, event 9, to state 8 NCP: IPNCP: RX len=14, reallen=14, code=2 id=3, state=8 code 1 len 10... d1 f0 f3 b1 d1 f0 e0 ef ...processed NCP: IPNCP: state 8, event 8, actions 42 IPNCP: event 2 notified IPNCP: wewish 2 wemust 0 wegot 4 IPNCP: wecan 173 weacked 0 LL_PPP: IPNCP: laddr=yyy.yyy.yyy.yyy setladdr=xxx.xxx.xxx.xxx defladdr=xxx.xxx.xxx.xxx

wewish , weoust , wecan

# .25LL_PPP: IPNCP: raddr=www.www.www.www setraddr=zzz.zzz.zzz.zzz configrmask =255.255.255.255 state=IPNCP_OLDADDR

0>, wecan

# .25LL_PPP: pridns=0.0.0.0, prinbns=0.0.0.0, secdns=0.0.0.0, secnbns=0.0.0.0

255.255.255.255 state=IPNCP_OLDADDR 0>, wecan

# .25LL_PPP: IP maxtu used=1500 bns=0.0.0.0, secdns=0.0.0.0, secnbns=0.0.0.0

255.255.255.255 state=IPNCP_OLDADDR 0>, wecan

# .25LL_PPP: IPNCP: VJ OFF

500 bns=0.0.0.0, secdns=0.0.0.0, secnbns=0.0.0.0 255.255.255.255 state=IPNCP_OLDADDR 0>, wecan

# .25NCP: IPNCP: state 8, event 8, to state 9 NCP: CCP: state 6, event 4, actions 200 NCP: CCP: sending code 1, len=9, id=1 code 17: 00 01 04 NCP: CCP: state 6, event 4, to state 6 LCP: LCP: RX len=15, reallen=15, code=8 id=3b, state=9 LCP: Rcv Proto Reject NCP: CCP: state 6, event 14, actions 20 NCP: CCP: state 6, event 14, to state 3

01/19/2006-13:16:12:PPP: Peer not negotiating `CCP' right now LCP: LCP: RX len=12, reallen=12, code=a id=2, state=9 LCP: LCP: RX len=12, reallen=12, code=a id=3, state=9 LCP: LCP: RX len=12, reallen=12, code=a id=4, state=9 LCP: LCP: RX len=12, reallen=12, code=a id=5, state=9 LCP: LCP: RX len=12, reallen=12, code=a id=6, state=9 LCP: LCP: RX len=12, reallen=12, code=a id=7, state=9 LCP: LCP: RX len=12, reallen=12, code=9 id=1, state=9 LCP: LCP: RX len=12, reallen=12, code=a id=8, state=9 LCP: LCP: RX len=12, reallen=12, code=a id=9, state=9 LCP: LCP: RX len=12, reallen=12, code=a id=a, state=9 LCP: LCP: RX len=12, reallen=12, code=a id=b, state=9 LCP: LCP: RX len=12, reallen=12, code=a id=c, state=9 LCP: LCP: RX len=12, reallen=12, code=a id=d, state=9

Regards,

Michael

Reply to
msg

My previous post was severely munged; I'll try again with no word-wrap. Here is a different mlp debug trace of a successful connect and authentication.

Regards,

Michael

IP: no route to 209.240.224.1

01/19/2006-17:59:31:DOD: connecting to using 0*32 over ATM-VC/1 NCP: LCP: opening NCP connection: s/w control NCP: LCP: state 0, event 2, actions 10 LCP: Event 10 notification! LCP: TLS NCP: LCP: state 0, event 2, to state 1 NCP: LCP: state 1, event 0, actions 240 NCP: LCP: sending code 1, len=14, id=1 code 1: 06 0c code 5: 73 34 d1 de NCP: LCP: state 1, event 0, to state 6 LCP: LCP: RX len=14, reallen=14, code=1 id=4d, state=6 NCP: LCP: RX len=14, reallen=14, code=1 id=4d, state=6 ACK code 3 len 4... c0 23 ...ACK code 5 len 6... d8 cf 71 a1 ...ACK ACK NCP: LCP: state 6, event 6, actions 400 NCP: LCP: sending code 2, len=14, id=4d code 3: c0 23 code 5: d8 cf 71 a1 NCP: LCP: state 6, event 6, to state 8 LCP: LCP: RX len=14, reallen=14, code=2 id=1, state=8 NCP: LCP: RX len=14, reallen=14, code=2 id=1, state=8 code 1 len 4... 6 c ...processed code 5 len 6... 73 34 d1 de ...processed NCP: LCP: state 8, event 8, actions 42 LCP: Event 2 notification! LCP: TLU pppp = 0x3384cc PPP: LCP: wewish 201 wemust 0 wegot 201 PPP: LCP: wecan 273 weacked 240 PPP: LCP: our magic 7334d1de their magic d8cf71a1 PPP: LCP: our mru 1548 their mru 1500 PPP: LCP: our mrru 1548 their mrru 0 LCP: start authen PAP: send id= pwd=, seq 1 NCP: LCP: state 8, event 8, to state 9 01/19/2006-17:59:31:PPP: remote will authenticate PAP: got pkt code 2, seq 1 AUTH: both auths now ok PPP: LCP: moving to network phase remote , ENC_TX_TYPE = 0, ENC_RX_TYPE = 0 IPNCP: setladdr=xxx.xxx.xxx.xxx defladdr=xxx.xxx.xxx.xxx state=IPNCP_OLDADDR NCP: IPNCP: opening NCP connection: LSAP BIND NCP: CCP: opening NCP connection: LSAP BIND NCP: IPNCP: state 0, event 2, actions 10 IPNCP: event 10 notified NCP: IPNCP: state 0, event 2, to state 1 NCP: CCP: state 0, event 2, actions 10 NCP: CCP: state 0, event 2, to state 1 NCP: IPNCP: state 1, event 0, actions 240 NCP: IPNCP: sending code 1, len=20, id=1 code 1: d8 fb b1 69 d1 f0 e2 80 code 2: 00 2d 0f 00 NCP: IPNCP: state 1, event 0, to state 6 NCP: CCP: state 1, event 0, actions 240 NCP: CCP: state 1, event 0, to state 6 NCP: IPNCP: RX len=10, reallen=10, code=1 id=9f, state=6 ACK code 3 len 6... d1 f0 e0 ef ...ACK ACK NCP: IPNCP: state 6, event 6, actions 400 NCP: IPNCP: sending code 2, len=10, id=9f code 3: d1 f0 e0 ef NCP: IPNCP: state 6, event 6, to state 8 01/19/2006-17:59:31:DOD: link to cpro_1 over ATM-VC/1 is now up NCP: IPNCP: RX len=10, reallen=10, code=4 id=1, state=8 code 2 len 6... 0 2d f 0 ...processed NCP: IPNCP: state 8, event 9, actions 240 NCP: IPNCP: sending code 1, len=14, id=2 code 1: d8 fb b1 69 d1 f0 e0 ef NCP: IPNCP: state 8, event 9, to state 8 NCP: IPNCP: RX len=14, reallen=14, code=3 id=2, state=8 code 1 len 10... d1 f0 e2 80 d1 f0 e0 ef ...IPADDRESSES: cpro_1 Slave addr = yyy.yyy.yyy.yyy processed NCP: IPNCP: state 8, event 9, actions 240 NCP: IPNCP: sending code 1, len=14, id=3 code 1: d1 f0 e2 80 d1 f0 e0 ef NCP: IPNCP: state 8, event 9, to state 8 NCP: IPNCP: RX len=14, reallen=14, code=2 id=3, state=8 code 1 len 10... d1 f0 e2 80 d1 f0 e0 ef ...processed NCP: IPNCP: state 8, event 8, actions 42 IPNCP: event 2 notified IPNCP: wewish 2 wemust 0 wegot 4 IPNCP: wecan 173 weacked 0 LL_PPP: IPNCP: laddr=yyy.yyy.yyy.yyy setladdr=xxx.xxx.xxx.xxx defladdr=xxx.xxx.xxx.xxx LL_PPP: IPNCP: raddr=zzz.zzz.zzz.zzz setraddr=yyy.yyy.yyy.yyy configrmask=255.255.255.255 state=IPNCP_OLDADDR

{{}@!LL_PPP: pridns=0.0.0.0, prinbns=0.0.0.0, secdns=0.0.0.0, secnbns=0.0.0.0

255.255.255.255 state=IPNCP_OLDADDR

{{}@!LL_PPP: IP maxtu used=1500 bns=0.0.0.0, secdns=0.0.0.0, secnbns=0.0.0.0

255.255.255.255 state=IPNCP_OLDADDR

{{}@!LL_PPP: IPNCP: VJ OFF 500 bns=0.0.0.0, secdns=0.0.0.0, secnbns=0.0.0.0

255.255.255.255 state=IPNCP_OLDADDR

{{}@!NCP: IPNCP: state 8, event 8, to state 9 NCP: CCP: state 6, event 4, actions 200 NCP: CCP: sending code 1, len=9, id=1 code 17: 00 01 04 NCP: CCP: state 6, event 4, to state 6 LCP: LCP: RX len=15, reallen=15, code=8 id=4e, state=9 LCP: Rcv Proto Reject NCP: CCP: state 6, event 14, actions 20 NCP: CCP: state 6, event 14, to state 3

01/19/2006-17:59:32:PPP: Peer not negotiating `CCP' right now LCP: LCP: RX len=12, reallen=12, code=a id=2, state=9 LCP: LCP: RX len=12, reallen=12, code=a id=3, state=9 LCP: LCP: RX len=12, reallen=12, code=a id=4, state=9 LCP: LCP: RX len=12, reallen=12, code=9 id=1, state=9 LCP: LCP: RX len=12, reallen=12, code=a id=5, state=9 LCP: LCP: RX len=12, reallen=12, code=a id=6, state=9 LCP: LCP: RX len=12, reallen=12, code=a id=7, state=9 LCP: LCP: RX len=12, reallen=12, code=9 id=2, state=9 LCP: LCP: RX len=12, reallen=12, code=a id=8, state=9 LCP: LCP: RX len=12, reallen=12, code=a id=9, state=9 LCP: LCP: RX len=12, reallen=12, code=a id=a, state=9

Keywords: Efficient 5861 PPP debug authentication troubleshooting states events actions rfc 1661 2364

Reply to
msg

Cabling-Design.com Forums website is not affiliated with any of the manufacturers or service providers discussed here. All logos and trade names are the property of their respective owners.