Junos OS

 View Only
last person joined: 3 days ago 

Ask questions and share experiences about Junos OS.

  • 1.  Juniper MX204 - LNS functionality - L2TP suscribers

    Posted 27 days ago

    We have used Juniper as an LNS service to terminate DSL sessions and the likes for a long time with no issue.
    We have one issue with a tunnel where by we see a L2TP tunnel come up, we also see a session establish and then drop off and the cycle repeat.

    My log files do not appear to assist with my investigations. Is there any other logs I can apply to help my progress. 

    Feb 17 12:15:06.694464 load: AVP Header: type = message, length = 8, flags = M ~H
    Feb 17 12:15:06.694481 load: AVP Header: type = connectSpeed, length = 10, flags = M ~H
    Feb 17 12:15:06.694495 load: AVP Header: type = framingType, length = 10, flags = M ~H
    Feb 17 12:15:06.694509 load: AVP Header: type = proxyAuthenId, length = 8, flags = ~M ~H
    Feb 17 12:15:06.694522 load: AVP Header: type = lastSentLcpConfReq, length = 21, flags = ~M ~H
    Feb 17 12:15:06.694536 load: AVP Header: type = lastReceivedLcpConfReq, length = 16, flags = ~M ~H
    Feb 17 12:15:06.694550 load: AVP Header: type = proxyAuthenType, length = 8, flags = ~M ~H
    Feb 17 12:15:06.694563 load: AVP Header: type = proxyAuthenName, length = 34, flags = ~M ~H
    Feb 17 12:15:06.694576 load: AVP Header: type = proxyAuthenChallenge, length = 22, flags = ~M ~H
    Feb 17 12:15:06.694591 load: AVP Header: type = vendor (0x0009) type (0x006b), length = 7, flags = ~M ~H
    Feb 17 12:15:06.694606 load: AVP Header: type = proxyAuthenResponse, length = 22, flags = ~M ~H
    Feb 17 12:15:06.694620 load: AVP Header: type = rxConnectSpeed, length = 10, flags = ~M ~H
    Feb 17 12:15:06.694635 run: lnsIncomingSession: state = waitConnected, event = iccn, next state = established
    Feb 17 12:15:06.694651 run: SM lnsIncomingSession, L2tpSession 0xb3c, enter State waitConnected, exit State established, current event iccn
    Feb 17 12:15:06.694665 setIfOperStatus: Changing ifOperStatus from Down to Up

    It does not however appear to hit our radius server and pass on the details to our suppliers LAC server and therefore the session just drops and trys again.

    The radius logs do not seem to be suggesting it is doing any thing

    Feb 17 12:21:47.628031 Received Flex license event for unknown feature 0
    Feb 17 12:21:47.628043 Received Flex license event for unknown feature 0
    Feb 17 12:21:47.628055 Received Flex license event for unknown feature 0
    Feb 17 12:21:47.628066 Received Flex license event for unknown feature 0
    Feb 17 12:21:47.628078 Received Flex license event for unknown feature 0
    Feb 17 12:21:47.628089 Received Flex license event for unknown feature 0
    Feb 17 12:21:47.628101 Received Flex license event for unknown feature 0
    Feb 17 12:22:47.629557 Received Flex license event for unknown feature 0
    Feb 17 12:22:47.629709 Received Flex license event for unknown feature 0
    Feb 17 12:22:47.629739 Received Flex license event for unknown feature 0
    Feb 17 12:22:47.629752 Received Flex license event for unknown feature 0
    Feb 17 12:22:47.629764 Received Flex license event for unknown feature 0
    Feb 17 12:22:47.629776 Received Flex license event for unknown feature 0
    Feb 17 12:22:47.629787 Received Flex license event for unknown feature 0
    Feb 17 12:22:47.629799 Received Flex license event for unknown feature 0
    Feb 17 12:22:47.629810 Received Flex license event for unknown feature 0
    Feb 17 12:22:47.629822 Received Flex license event for unknown feature 0
    Feb 17 12:23:00.722899 findSession AST-Table couldn't find the session-id:2893
    Feb 17 12:23:10.917201 findSession AST-Table couldn't find the session-id:2894

    And the PPP service log has nothing interesting to say either

    Feb 17 12:24:01.953862 si-0/0/0.3221228370|LinkSubscriberMgr::lowerLayerTransitionedToDown: sdbId 2899
    Feb 17 12:24:01.953888 si-0/0/0.3221228370|LinkInterface::disassociateFromSubscriberMgrAndClientSession: sdbId 2899, subscriberMgr 0x4c59c08
    Feb 17 12:24:02.016589 dyn_prof_ipc_response_msg: opcode = ACK, request_id = 0x568bd38
    Feb 17 12:24:02.016607 ACK received for profile request with id=568bd38
    Feb 17 12:24:02.016638 sdbId 2899|dynProfileResponseHandler: Profile ACK for sdbId 2899 serviceTypes 0x1, action code 2, result code 0
    Feb 17 12:24:02.016663 sdbId 2899|SEQ: sdbId 2899, profile deactivate response(ACK), services(dyn ), func profileDeactivateResponse
    Feb 17 12:24:02.016681 sdbId 2899|dynamicProfileDeactivateResponse: serviceTypes 1, response 1
    Feb 17 12:24:02.016701 sdbId 2899|LinkSubscriberMgr::profileDeactivateResponse: sdbId 2899, serviceTypes 1, response 1, appliedConfigBits 0x00000000 0x00000001
    Feb 17 12:24:02.016716 sdbId 2899|LinkSubscriberMgr::profileDeactivateResponse: sdbId 2899, CommonLinkSubscriberMgr not found, generic processing
    Feb 17 12:24:02.016733 sdbId 2899|DynamicSubscriberMgr::setAppliedConfigBits: sdbId 2899, clear, new 0x00000000 0x00000001 , old bits 0x00000000 0x00000001
    Feb 17 12:24:02.016749 sdbId 2899|setAppliedConfigBits: sdbId 2899, applied 0x00000000 0x00000000 , action clear
    Feb 17 12:24:02.016765 sdbId 2899|LinkSubscriberMgr::profileDeactivateResponse: sdbId 2899, appliedServiceTypes 0x0, pendingCount: 0
    Feb 17 12:24:02.016779 sdbId 2899|LinkSubscriberMgr::profileDeactivated: sdbId 2899
    Feb 17 12:24:02.016793 sdbId 2899|LinkSubscriberMgr::initiateSubscriberTermination: sdbId 2899
    Feb 17 12:24:02.016809 sdbId 2899|LinkSubscriberMgr::displaySequencerFlags: sdbId 2899, SequencerState: idle
    Feb 17 12:24:02.016830 sdbId 2899|... : RD2A:0 APND:0 LGIN:0 PREQ:1 PRFI:0 CFGD:0 PACK:1
    Feb 17 12:24:02.016853 sdbId 2899|... : LOPN:0 LOUT:1 TTED:0 TING:1 LL2D:1 TREQ:0 TPND:0 PDRQ:0 PDIP:0
    Feb 17 12:24:02.016873 sdbId 2899|sessionDbSetStateTerminated: entered
    Feb 17 12:24:02.016922 state:0 to index:2
    Feb 17 12:24:02.016932 sdb_summary_counter_decrement: sdb counter for index:2 changed from:2
    Feb 17 12:24:02.016941 sdb_summary_counter_decrement: sdb counter for index:9 changed from:2
    Feb 17 12:24:02.016966 sdb_update_summary_counters: 3789: decremented counter for state:0
    Feb 17 12:24:02.016976 state:4 to index:6
    Feb 17 12:24:02.016984 sdb_summary_counter_increment: sdb counter for index:6 changed to:1
    Feb 17 12:24:02.017019 sdb_summary_counter_increment: sdb counter for index:9 changed to:2
    Feb 17 12:24:02.017030 sdb_update_summary_counters: 3810: incremented counter for state:4
    Feb 17 12:24:02.017038 sdb_update_client_session_internal_sts: updated acct type summary counter: first 0, last 0
    Feb 17 12:24:02.017047 sdb_update_client_session_internal_sts 4559: updated counter first state:0 last state:4 for session id 2899
    Feb 17 12:24:02.017056 sdb_update_client_session_internal_sts:lstifl Add precheck sid 2899 fstifl si-0/0/0.3221228370 fstiflset 1 lastifl si-0/0/0.3221228370 lstiflset 1 fstuiflset 0 fstuifl
    Feb 17 12:24:02.017071 state:0 to index:2
    Feb 17 12:24:02.017079 state:0 to index:2
    Feb 17 12:24:02.017087 state:4 to index:6
    Feb 17 12:24:02.017095 state:4 to index:6



    ------------------------------
    Lee Byatt
    ------------------------------


  • 2.  RE: Juniper MX204 - LNS functionality - L2TP suscribers

    Posted 26 days ago

    Hello Lee,

    Provided snippet from PPP service traceoptions seems to cover only part when the session has been actually destroyed. It would be helpful to see what happened earlier.

    As a general rule, the most useful are the following traceoptions:

    • system processes general-authentication-service traceoptions
    • system processes smg-service traceoptions
    • protocols ppp-service traceoptions
    • services l2tp traceoptions

    and output of

    • show shmlog entries logname all

    where you can search for events related to the same session/SDB ID since the timestamp when the session was created.

    Regards,

    Wojciech


    Original Message


  • 3.  RE: Juniper MX204 - LNS functionality - L2TP suscribers

    Posted 26 days ago

    Thank  you for taking the time to reply.

    Here is an extract of the full attempt in the PPP Log

    displaySmdPluginMsg: SMD IPC Message
    ==============================
     
    Len        : 95
    Type       : 2
     
    Feb 18 16:18:09.466381 |
     
    displaySmdPluginMsg: SMD Plugin Message
    =================================
     
    msgId : 8 (New LNS session message)
    msgLength : 95
    pluginId BBE_PLUGIN_ID_PPP
    iflId : 0x20002468
    sdbId : 9301
     
     
    Feb 18 16:18:09.466436 |processL2tpSessionUp: l2tp session PppInterface 0x20002468, sdbId 9301
    Feb 18 16:18:09.466451 |retrieveL2tpAttributes: entered sdbId 9301
    Feb 18 16:18:09.466477 |retrieveL2tpAttributes: tunnelRttId is 0
    Feb 18 16:18:09.466499 |processL2tpSessionUp: l2tpPppSessionTable not used for L2TP flow IFL session l2tp address local IP address LOCAL local tunnel id = 7419 local session id = 53397 retVal = 1 for pppInterface PppInterface 0x20002468
    Feb 18 16:18:09.466516 |processL2tpSessionUp: l2tp session up for localL2tpSessionEndPoint = IP Address = LOCAL tunnel Id = 7419 session Id = 53397
    Feb 18 16:18:09.466533 | remoteL2tpSessionEndPoint = IP Address = REMOTE tunnel Id = 64365 session Id = 28141 keepaliveTimer = 15 secs
    Feb 18 16:18:09.466553 |handleSmdPppPluginMsg: No ppp-options at ifl level. Using groupProfile values. pppAuthOptions.papEnabled=true pppAuthOptions.chapEnabled=trueGP mtu: 1300GP mtu: 0groupProfPeerIpAddressOptional=false groupProfIpcpSuggestDnsOption=false ignoreMagicNumberMismatch=disable
    Feb 18 16:18:09.466576 |setCharacteristics: num classes flag 0 num of classes set to 0 mru 1 mrru 1 reassemblyEnabled 0 on PppInterface 0x20002468
    Feb 18 16:18:09.466598 |checkOpenEnabled: Lcp, PppInterface 0x20002468, old LcpOpenEnabled 1, new LcpOpenEnabled 1, termId 0
    Feb 18 16:18:09.466616 |handleSmdPppPluginMsg configuredMtu 1300 configuredMru : 0 pppLocalMtu : 1300 retMru 1300
    Feb 18 16:18:09.466632 |lowerStateChangeEvent: PppInterface 0x20002468 lower state changed from 1 to 1
    Feb 18 16:18:09.466655 |processProxyLcpAuthDataResp : For ifl Index 536880232 sdbId 9301, Lcp no size 0, Auth no size 0, tunnelRttId = 0, remoteL2tpUdpPort = 1701, l2tpCookie 938
    Feb 18 16:18:09.466672 |processProxyLcpAuthDataResp : si-0/0/0.3221234772 start negotiations for ifl Index 536880232 sdbid 9301
    Feb 18 16:18:09.466685 |enableNegotiation : Lcp: for si-0/0/0.3221234772
    Feb 18 16:18:09.466709 si-0/0/0.3221234772 Lcp ReqSent|run: SM Lcp: pppInterface = PppInterface 0x20002468: enter State = Stopped: exit State = ReqSent: current event = StartLocal
    Feb 18 16:18:09.466726 si-0/0/0.3221234772 Lcp ReqSent|thisLayerNotPassive: Lcp, PppInterface 0x20002468
    Feb 18 16:18:09.466743 si-0/0/0.3221234772 Lcp ReqSent|Lcp::configure: isConfigureLocalEnabled true, isConfigurePeerEnabled true
    Feb 18 16:18:09.466767 si-0/0/0.3221234772 Lcp ReqSent|configureLocalOptions: Lcp: PppInterface 0x20002468, isBundled false, isReassemblyEnabled false
    Feb 18 16:18:09.466785 si-0/0/0.3221234772 Lcp ReqSent|Lcp::configureLocalOptions: localMrruEnabled false, localMrruRequired false, localMrru 1500
    Feb 18 16:18:09.466799 si-0/0/0.3221234772 Lcp ReqSent|configurePeerOptions: Lcp: peerMrruHint false, peerEndpointDiscriminatorHint false
    Feb 18 16:18:09.466826 si-0/0/0.3221234772 Lcp ReqSent|sendPacket: Send packet with protocol Lcp, code challenge, on interface PppInterface 0x20002468, id 227, len 18
    Feb 18 16:18:09.466867 si-0/0/0.3221234772 Lcp ReqSent|actionScr timer 30 count 9 uid PppInterface 0x20002468
    Feb 18 16:18:09.466883 |SubscriberMgr::Ref::~Ref

    I cannot see any thing which suggests issue with the setup. But nothing is hitting the radius logs from either my radius OR the MX



    ------------------------------
    L B
    ------------------------------

    Original Message


  • 4.  RE: Juniper MX204 - LNS functionality - L2TP suscribers

    Posted 26 days ago

    In addition to the previous reply, you can check that all the parameters assigned to this user are conigured, like filters, pools, routing-instance etc. I anything is missing in the config, the user is  disconnected. The reason of such disconnect can be found in shmlog, but it's not an easy task.


    Original Message