INTELLIGENT WORK FORUMS
FOR COMPUTER PROFESSIONALS

Log In

Come Join Us!

Are you a
Computer / IT professional?
Join Tek-Tips Forums!
  • Talk With Other Members
  • Be Notified Of Responses
    To Your Posts
  • Keyword Search
  • One-Click Access To Your
    Favorite Forums
  • Automated Signatures
    On Your Posts
  • Best Of All, It's Free!

*Tek-Tips's functionality depends on members receiving e-mail. By joining you are opting in to receive e-mail.

Posting Guidelines

Promoting, selling, recruiting, coursework and thesis posting is forbidden.

Jobs

Issues with PRI Line

Issues with PRI Line

(OP)
We have an IP office release 9.1 . The PRI trunk is idle but we can not make or receive calls via this trunk . I have configured both incoming and outgoing ID with short code pointing to calls to the ID on the trunk but i am still getting an error that Group ID not found .

Below is a trace.

Timed: 13/07/17 15:58
15:58:56 2946173mS CMExtnTx: v=7012, p1=8011
CMFacility
Line: type=IPLine 250 Call: lid=262 id=23 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
15:58:56 2946173mS CMExtnEvt: Rashida Saleh: CMExtnHandler::SetCurrent( id: 1096->0 )
15:58:56 2946174mS CMCallEvt: 0a85020100000448 262.1096.0 -1 Rashida Saleh.-1: StateChange: END=X CMCSCompleted->CMCSDelete
15:58:56 2946176mS CMCallEvt: 0a85020100000448 262.1096.0 -1 BaseEP: DELETE CMEndpoint f17d6c54 TOTAL NOW=3 CALL_LIST=1
15:58:56 2946177mS CMCallEvt: 0a82440300003827 0.1098.0 -1 H323TrunkEP: StateChange: END=X CMCSCompleted->CMCSDelete
15:58:56 2946177mS CMCallEvt: END CALL:33 (f17d6060)
15:58:56 2946178mS CMCallEvt: 0a82440300003827 0.1098.0 -1 BaseEP: DELETE CMEndpoint f17c0ef8 TOTAL NOW=2 CALL_LIST=1
15:58:56 2946180mS CMMap: PCG::UnmapBChan pcp[222]b0r1 cp_b 0 other_cp_b 0
15:58:56 2946180mS H323Evt: SESS 28 SetOperational local 10.133.2.1:49158 remote 10.133.2.111:50218 to 0
15:58:56 2946180mS H323Evt: SESS 27 SetOperational local 10.133.2.1:49156 remote 10.130.68.3:49152 to 0
15:58:56 2946180mS CMMap: PCG::UMMapBChan rtpRelay ID: 2 Close success
15:58:56 2946180mS CMMap: PCG::UnmapBChan pcp[223]b0r1 cp_b 0 other_cp_b 0
15:58:56 2946181mS H323Evt: SESS 28: RTP(END): 10.133.2.1/49158 10.133.2.111/50218 CODEC=Alaw64K(4) PKTSZ=160 RFC2833=off AGE=300861 SENT=14958 RECV=15040 RTdelay=0 jitter=0 loss=0 remotejitter=0 remoteloss=0
15:58:56 2946181mS H323Evt: SESS 27: RTP(END): 10.133.2.1/49156 10.130.68.3/49152 CODEC=Alaw64K(4) PKTSZ=160 RFC2833=off AGE=300861 SENT=15037 RECV=14961 RTdelay=0 jitter=0 loss=0 remotejitter=0 remoteloss=0
15:58:56 2946632mS RES: Thu 13/7/2017 15:58:55 FreeMem=50864256 Heap=50569912(2) Cache=294344 MemObjs=13878(14345) CMMsg=5(7) ASN=0 Buff=5200 1360 1000 7403 5 Links=57024(57245) BTree=1252(3213) CPU=03.77% CPUStats=03.69%/1/4/2924/14125/14810/00.66%/0
/03.56% MCR=0 MCW=0
15:58:56 2946632mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=59 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=131 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=1 Monitor=1 SSA=1 TCP=86(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
15:58:56 2946632mS RES4: XML MemObjs=63 PoolMem=4748404(2) FreePoolMem=4733100(0)
15:58:56 2946632mS RES5: CLog MemObjs=501 FreePoolMem(Objs)=5148(99) TotalMem=165250
15:58:56 2946848mS R2DSP: PRIU DSP 3: is alive
15:58:58 2948174mS CMExtnEvt: Rashida Saleh: Recover Timer reason=CMTRWrapUp
15:58:58 2948174mS CMExtnEvt: v=23 State, new=Idle old=PortRecoverDelay,0,0,Rashida Saleh
15:58:58 2948175mS CMExtnTx: v=7012, p1=0
CMVoiceMailStatus
Line: type=IPLine 250 Call: lid=0 id=-1 in=0
Called[Rashida Saleh Msgs=25 Old=0 Sav=0] Type=Default (100) Reason=CMDRdirect Calling[00000025] Type=Default Plan=Default
Display [Rashida Saleh Msgs=25]
Timed: 13/07/17 15:58
15:58:58 2949765mS PRN: Optimizing BTree Lists Completed...Started:2949764 Duration:1 Size:118 Attempted:118
15:59:01 2952864mS H323Evt: Recv: RegistrationRequest 10.133.2.129; Extn(7024), time since last RRQ-KA 55010, Endpoints registered: 31; Endpoints in registration: 0
15:59:02 2953922mS H323Evt: Recv: RegistrationRequest 10.133.2.122; Extn(7017), time since last RRQ-KA 55010, Endpoints registered: 31; Endpoints in registration: 0
15:59:04 2955651mS H323Evt: Recv: RegistrationRequest 10.133.2.103; Extn(7006), time since last RRQ-KA 55013, Endpoints registered: 31; Endpoints in registration: 0
15:59:04 2955950mS H323Evt: Recv: RegistrationRequest 10.133.2.106; Extn(7031), time since last RRQ-KA 55011, Endpoints registered: 31; Endpoints in registration: 0
15:59:05 2956650mS H323Evt: Recv: RegistrationRequest 10.133.2.120; Extn(7008), time since last RRQ-KA 55013, Endpoints registered: 31; Endpoints in registration: 0
15:59:06 2957884mS H323Evt: Recv: RegistrationRequest 10.133.2.128; Extn(7025), time since last RRQ-KA 55012, Endpoints registered: 31; Endpoints in registration: 0
15:59:09 2959660mS H323Evt: Recv: RegistrationRequest 10.133.2.124; Extn(7027), time since last RRQ-KA 55011, Endpoints registered: 31; Endpoints in registration: 0
15:59:11 2961561mS H323Evt: Recv: RegistrationRequest 10.133.2.109; Extn(7013), time since last RRQ-KA 55012, Endpoints registered: 31; Endpoints in registration: 0
15:59:12 2962083mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 0
15:59:12 2962085mS CMCallEvt: 0000000000000000 0.1101.0 -1 BaseEP: NEW CMEndpoint f17d6c54 TOTAL NOW=3 CALL_LIST=1
15:59:12 2962085mS CMCallEvt: 0000000000000000 0.1101.0 -1 Test User.-1: NEW CMExtnEndpoint f17d6c54, Name=Test User, Extn=7040, Phys Extn=7040
15:59:12 2962086mS CMCallEvt: CREATE CALL:35 (f17d6060)
15:59:12 2962086mS CMCallEvt: 0000000000000000 0.1102.0 -1 BaseEP: NEW CMEndpoint f17d4754 TOTAL NOW=4 CALL_LIST=1
15:59:12 2962088mS CMExtnEvt: Test User: CMExtnHandler::SetCurrent( id: 0->1101 )
15:59:12 2962089mS CMExtnRx: v=7040, p1=0
CMSetup
Line: type=IPLine 250 Call: lid=287 id=1101 in=0
Called[] Type=Default (100) Reason=CMDRdirect Calling[7040] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
IE CMIEFastStartInfoData (6) 12 item(s)
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=Test User
IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=Test User
15:59:12 2962089mS CMCallEvt: 0a8502010000044d 287.1101.0 35 Test User.0: StateChange: END=A CMCSIdle->CMCSDialInitiated
15:59:12 2962089mS CMExtnEvt: v=32 State, new=Dialling old=Idle,0,0,Test User
15:59:12 2962089mS CMTARGET: 0a8502010000044d 287.1101.0 35 Test User.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party= sub= calling=7040 calling_sub= dir=out complete=0 ses=0
15:59:12 2962090mS CMTARGET: 0a8502010000044d 287.1101.0 35 Test User.0: ADD TARGET (N): number= type=100 depth=1 nobar=1 setorig=1 ses=0
15:59:12 2962090mS CMCallEvt: 0a8502010000044d 287.1101.0 35 Test User.0: StateChange: END=A CMCSDialInitiated->CMCSDialling
15:59:12 2962093mS CMExtnTx: v=7040, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=287 id=1101 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
IE CMIESecurityData (253) 2 item(s)
CMSecurityElement RX_ONLY {
CMSRTPCryptoCapability none
Codecs list (size 4)
}
CMSecurityElement TX_ONLY {
CMSRTPCryptoCapability none
Codecs list (size 4)
}
Timed: 13/07/17 15:59
15:59:12 2962093mS H323Evt: PortmAvayaH323Phone::PortmAvayaH323PhoneDelay: 7040 - delay disabled
15:59:12 2962093mS CMExtnTx: v=7040, p1=8036
CMFacility
Line: type=IPLine 250 Call: lid=287 id=32 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
15:59:12 2962094mS CMExtnTx: v=7040, p1=0
CMSetupAck
Line: type=IPLine 250 Call: lid=287 id=1101 in=0
Timed: 13/07/17 15:59
15:59:12 2962094mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1101 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
15:59:12 2962097mS CD: CALL: 287.1101.0 BState=Idle Cut=0 Music=0.0 Aend="Test User(7040)" (0.0) Bend="" [] (0.0) CalledNum=0 () CallingNum=7040 (Test User) Internal=1 Time=11 AState=Dialling
15:59:12 2962099mS H323Evt: SESS 2a SetOperational local 10.133.2.1:0 remote 0.0.0.0:0 to 0
15:59:12 2962099mS H323Evt: SESS 2a SetRemUDP 0 -> 51694, remote IP 0.0.0.0 -> 10.130.64.184
15:59:12 2962139mS RES: Thu 13/7/2017 15:59:11 FreeMem=50829420 Heap=50569912(2) Cache=259508 MemObjs=14020(14345) CMMsg=5(7) ASN=0 Buff=5200 1361 1000 7402 5 Links=57085(57245) BTree=1253(3213) CPU=04.03% CPUStats=05.94%/14/25/2924/13931/14810/00.39%
/0/03.19% MCR=0 MCW=0
15:59:12 2962139mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=59 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=135 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=1 TCP=86(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
15:59:12 2962139mS RES4: XML MemObjs=63 PoolMem=4748404(2) FreePoolMem=4733100(0)
15:59:12 2962139mS RES5: CLog MemObjs=501 FreePoolMem(Objs)=5148(99) TotalMem=165250
15:59:12 2962177mS H323Evt: Recv: RegistrationRequest 10.133.2.127; Extn(7001), time since last RRQ-KA 55013, Endpoints registered: 31; Endpoints in registration: 0
15:59:12 2962398mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 8
15:59:12 2962399mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1101 in=0
Called[8] Type=Default (100) Reason=CMDRdirect Keypad[8]
15:59:12 2962645mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 0
15:59:12 2962646mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1101 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
15:59:12 2962994mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 3
15:59:12 2962995mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1101 in=0
Called[3] Type=Default (100) Reason=CMDRdirect Keypad[3]
15:59:13 2963191mS H323Evt: Recv: RegistrationRequest 10.133.2.125; Extn(7004), time since last RRQ-KA 55014, Endpoints registered: 31; Endpoints in registration: 0
15:59:13 2963266mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 6
15:59:13 2963266mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1101 in=0
Called[6] Type=Default (100) Reason=CMDRdirect Keypad[6]
15:59:13 2963570mS H323Evt: Recv: RegistrationRequest 10.133.2.102; Extn(7033), time since last RRQ-KA 55010, Endpoints registered: 31; Endpoints in registration: 0
15:59:13 2963586mS H323Evt: Recv: RegistrationRequest 10.133.2.126; Extn(7023), time since last RRQ-KA 55011, Endpoints registered: 31; Endpoints in registration: 0
15:59:13 2963636mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 7
15:59:13 2963636mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1101 in=0
Called[7] Type=Default (100) Reason=CMDRdirect Keypad[7]
15:59:13 2963915mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 8
15:59:13 2963916mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1101 in=0
Called[8] Type=Default (100) Reason=CMDRdirect Keypad[8]
15:59:14 2964216mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 6
15:59:14 2964216mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1101 in=0
Called[6] Type=Default (100) Reason=CMDRdirect Keypad[6]
15:59:14 2964221mS H323Evt: Recv: RegistrationRequest 10.133.3.193; Extn(7010), time since last RRQ-KA 55014, Endpoints registered: 31; Endpoints in registration: 0
15:59:14 2964520mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 2
15:59:14 2964520mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1101 in=0
Called[2] Type=Default (100) Reason=CMDRdirect Keypad[2]
15:59:14 2964800mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 6
15:59:14 2964801mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1101 in=0
Called[6] Type=Default (100) Reason=CMDRdirect Keypad[6]
15:59:15 2965099mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 8
15:59:15 2965099mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1101 in=0
Called[8] Type=Default (100) Reason=CMDRdirect Keypad[8]
15:59:15 2965099mS CMTARGET: 0a8502010000044d 287.1101.0 35 Test User.0: CancelTimer CMTCDelayedProcessing
15:59:15 2965100mS CMTARGET: 0a8502010000044d 287.1101.0 35 Test User.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=08036786268 sub= calling=7040 calling_sub= dir=out complete=0 ses=0
15:59:15 2965100mS CMTARGET: 0a8502010000044d 287.1101.0 35 Test User.0: ADD TARGET (N): number=08036786268 type=100 depth=1 nobar=1 setorig=1 ses=0
15:59:15 2965101mS CMTARGET: 0a8502010000044d 287.1101.0 35 Test User.0: DEF SC: 08036786268 0 sc=type=Dial code=?, num=.
15:59:15 2965101mS CMARS: FindActiveARSByGroupID GroupID=51 - Not Found
15:59:15 2965101mS CMLRQ: FindActiveLRQByGroupID GroupID=51 - Not Found
15:59:15 2965101mS CMMap: a=4.1 b=0.0 Mapper::AllocateCodec allocated CMRTVocoder(f5380e5c) resource busy 1, total 52
15:59:15 2965102mS CMCallEvt: 0000000000000000 0.1103.0 -1 BaseEP: NEW CMEndpoint f17c4edc TOTAL NOW=5 CALL_LIST=2
15:59:15 2965103mS CMTARGET: DIAL LINE: 35 GROUP = 51 SUCCESS = f17c4edc
15:59:15 2965103mS CMTARGET: 0a8502010000044d 287.1101.0 35 Test User.0: CancelTimer CMTCDialToneTimeout
15:59:15 2965103mS CMTARGET: 0a8502010000044d 287.1101.0 35 Test User.0: INITIAL TARGETING SUCCEEDED
15:59:15 2965103mS CMTARGET: 0a8502010000044d 287.1101.0 35 Test User.0: GetNoAnswerTimer:15
15:59:15 2965103mS CMCallEvt: 0000000000000000 0.1102.0 35 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
15:59:15 2965104mS CMCallEvt: 0a8502010000044f 0.1103.0 35 Q931 Trunk:9 CHAN=-1: StateChange: END=T CMCSIdle->CMCSOffering
15:59:15 2965105mS CMLineTx: v=9
CMSetup
Line: type=Q931Line 9 Call: lid=0 id=1103 in=0
Called[08036786268] Type=Unknown (0) Reason=CMDRdirect Calling[] Type=Unknown Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
Timed: 13/07/17 15:59
Locale: eng
15:59:15 2965105mS CD: CALL: 287.1101.0 BState=Idle Cut=0 Music=0.0 Aend="Test User(7040)" (0.0) Bend="Line 9" [Line 9] (0.0) CalledNum=08036786268 () CallingNum=7040 (Test User) Internal=0 Time=3019 AState=Dialling
15:59:15 2965107mS ISDNL3Evt: v=9 stacknum=9 State, new=Initiated, old=NullState id=1103
15:59:15 2965831mS H323Evt: Recv: RegistrationRequest 10.133.3.125; Extn(9002), time since last RRQ-KA 55014, Endpoints registered: 31; Endpoints in registration: 0
15:59:18 2968584mS H323Evt: Recv: RegistrationRequest 10.133.2.104; Extn(7019), time since last RRQ-KA 55011, Endpoints registered: 31; Endpoints in registration: 0
15:59:18 2968593mS H323Evt: Recv: RegistrationRequest 10.133.2.111; Extn(7012), time since last RRQ-KA 55011, Endpoints registered: 31; Endpoints in registration: 0
15:59:19 2969707mS ISDNL3Evt: v=9 p1=9,p2=1001,p3=5,p4=0,s1=
15:59:19 2969707mS ISDNL3Evt: v=9 stacknum=9 State, new=NullState, old=Initiated id=1103
15:59:19 2969708mS CMLineRx: v=9
CMReleaseComp
Line: type=Q931Line 9 Call: lid=0 id=1103 in=0
Cause=38, Network out of order
15:59:19 2969708mS CMCallEvt: 0000000000000000 0.1102.0 35 TargetingEP: RequestEnd 0a8502010000044f 0.1103.0 35 Q931 Trunk:9 CHAN=-1
15:59:19 2969708mS CMTARGET: 0a8502010000044d 287.1101.0 35 Test User.0: CancelTimer CMTCNoAnswerTimeout
15:59:19 2969708mS CMCallEvt: 0000000000000000 0.1102.0 -1 BaseEP: DELETE CMEndpoint f17d4754 TOTAL NOW=4 CALL_LIST=2
15:59:19 2969709mS CMCallEvt: 0a8502010000044f 0.1103.0 35 Q931 Trunk:9 CHAN=-1: StateChange: END=B CMCSOffering->CMCSCompleted
15:59:19 2969710mS CMExtnTx: v=7040, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=287 id=1101 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
Timed: 13/07/17 15:59
15:59:19 2969710mS CMExtnTx: v=7040, p1=8036
CMFacility
Line: type=IPLine 250 Call: lid=287 id=32 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
15:59:19 2969711mS CMLOGGING: CALL:2017/07/1315:59,00:00:00,000,7040,O,08036786268,08036786268,TestUser,,,0,,"",0,n/a
15:59:19 2969711mS CD: CALL: 287.1101.0 BState=Disconnecting Cut=0 Music=0.0 Aend="Test User(7040)" (0.0) Bend="Line 9" [Line 9] (0.0) CalledNum=08036786268 () CallingNum=7040 (Test User) Internal=0 Time=7625 AState=Dialling
15:59:19 2969711mS CD: CALL: 287.1101.0 Deleted
15:59:19 2969712mS CMExtnEvt: Test User: CALL LOST (CMCauseNetworkOOO)
15:59:19 2969712mS CMExtnEvt: Test User: Extn(7040) Calling Party Number(7040) Type(CMNTypeInternal)
15:59:19 2969712mS CMCallEvt: 0a8502010000044d 287.1101.0 -1 Test User.0: StateChange: END=X CMCSDialling->CMCSCompletedTone
15:59:19 2969714mS CMMap: IP::SetCodec pcp[226]b0r1 0 -> f5380e5c
15:59:19 2969714mS CMExtnTx: v=7040, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=287 id=1101 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
Timed: 13/07/17 15:59
15:59:19 2969715mS H323Evt: PortmAvayaH323Phone::PortmAvayaH323PhoneDelay: 7040 - delay disabled
15:59:19 2969715mS CMExtnTx: v=7040, p1=8036
CMFacility
Line: type=IPLine 250 Call: lid=287 id=32 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
15:59:19 2969715mS CMExtnEvt: v=32 State, new=CMESCompleted old=Dialling,0,0,Test User
15:59:19 2969716mS CMCallEvt: 0a8502010000044f 0.1103.0 -1 Q931 Trunk:9 CHAN=-1: StateChange: END=X CMCSCompleted->CMCSDelete
15:59:19 2969716mS CMCallEvt: END CALL:35 (f17d6060)
15:59:19 2969716mS CMCallEvt: 0a8502010000044f 0.1103.0 -1 BaseEP: DELETE CMEndpoint f17c4edc TOTAL NOW=3 CALL_LIST=1
15:59:19 2969720mS CMMap: PCG::AddToneGenerator g B1[4] for cp[226]b0r1 append pcp[227]b0r1 (total 1)
15:59:19 2969721mS CMMap: PlatformConnectionAudioSAP::Bind pcp[227]b0r1 to 0.0
15:59:19 2969721mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[227]b0r1 Configure 0.0
15:59:19 2969721mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[227]b0r1 ConnectIndication 0.0
15:59:19 2969721mS CMMap: a=0.0 b=0.0 pcp[226]b0r1 RTPB2
15:59:19 2969721mS H323Evt: SESS 2a SetOperational local 10.133.2.1:49156 remote 10.130.64.184:51694 to 1
15:59:20 2970148mS RES: Thu 13/7/2017 15:59:19 FreeMem=50837296 Heap=50568856(2) Cache=268440 MemObjs=14012(14345) CMMsg=5(7) ASN=0 Buff=5200 1360 1000 7402 5 Links=57101(57245) BTree=1252(3213) CPU=04.25% CPUStats=05.06%/10/19/2924/13884/14810/00.57%
/0/03.32% MCR=0 MCW=0
15:59:20 2970149mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=59 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=134 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=1 TCP=86(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
15:59:20 2970149mS RES4: XML MemObjs=63 PoolMem=4748404(2) FreePoolMem=4733100(0)
15:59:20 2970149mS RES5: CLog MemObjs=501 FreePoolMem(Objs)=5148(99) TotalMem=165250
15:59:20 2970231mS H323Evt: Recv: RegistrationRequest 10.130.64.184; Extn(7040), time since last RRQ-KA 55031, Endpoints registered: 31; Endpoints in registration: 0
15:59:20 2970891mS H323Evt: SESS 2a: RTP(50r): 10.133.2.1/49156 10.130.64.184/51694 CODEC=Alaw64K(4) PKTSZ=160 RFC2833=off AGE=8792 SENT=58 (avg size=164) RECV=50 (avg size=160)
15:59:21 2971310mS H323Evt: Recv: RegistrationRequest 10.133.3.102; Extn(6150), time since last RRQ-KA 55013, Endpoints registered: 31; Endpoints in registration: 0
15:59:23 2973709mS H323Evt: Recv: RegistrationRequest 10.133.2.119; Extn(7007), time since last RRQ-KA 55011, Endpoints registered: 31; Endpoints in registration: 0
15:59:24 2974307mS ISDNL3Evt: v=9 p1=9,p2=1001,p3=5,p4=0,s1=
15:59:24 2974697mS H323Evt: Recv: RegistrationRequest 10.133.2.110; Extn(7009), time since last RRQ-KA 55010, Endpoints registered: 31; Endpoints in registration: 0
15:59:24 2974820mS ISDNL3Evt: v=9 p1=9,p2=1000,p3=0,p4=0,s1=
15:59:25 2975021mS CMExtnTx: v=7040, p1=8036
CMFacility
Line: type=IPLine 250 Call: lid=287 id=32 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
15:59:25 2975021mS CMExtnRx: v=7040, p1=0
CMReleaseComp
Line: type=IPLine 250 Call: lid=287 id=1101 in=0
15:59:25 2975021mS CMCallEvt: 0a8502010000044d 287.1101.0 -1 Test User.0: StateChange: END=X CMCSCompletedTone->CMCSCompleted
15:59:25 2975022mS CMExtnTx: v=7040, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=287 id=1101 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
Timed: 13/07/17 15:59
15:59:25 2975022mS CMExtnEvt: v=32 State, new=PortRecoverDelay old=CMESCompleted,0,0,Test User
15:59:25 2975023mS CMExtnEvt: Test User: CALL LOST (CMCauseForceClear)
15:59:25 2975023mS CMExtnEvt: Test User: Extn(7040) Calling Party Number(7040) Type(CMNTypeInternal)
15:59:25 2975023mS CMExtnEvt: Test User: CMExtnHandler::SetCurrent( id: 1101->0 )
15:59:25 2975024mS CMCallEvt: 0a8502010000044d 287.1101.0 -1 Test User.-1: StateChange: END=X CMCSCompleted->CMCSDelete
15:59:25 2975024mS CMTARGET: 0a8502010000044d 287.1101.0 -1 BaseEP: ~CMTargetHandler f17ce1ec ep f17d6c54
15:59:25 2975025mS CMCallEvt: 0a8502010000044d 287.1101.0 -1 BaseEP: DELETE CMEndpoint f17d6c54 TOTAL NOW=2 CALL_LIST=1
15:59:25 2975027mS CMMap: a=0.0 b=0.0 pcp[226]b0r1 RTPB0
15:59:25 2975027mS H323Evt: SESS 2a SetOperational local 10.133.2.1:49156 remote 10.130.64.184:51694 to 0
15:59:25 2975028mS H323Evt: SESS 2a: RTP(END): 10.133.2.1/49156 10.130.64.184/51694 CODEC=Alaw64K(4) PKTSZ=160 RFC2833=off AGE=12929 SENT=265 RECV=255 RTdelay=0 jitter=0 loss=0 remotejitter=0 remoteloss=0
15:59:25 2975028mS CMMap: a=4.1 b=0.0 Mapper::FreeCodec freed CMRTVocoder(f5380e5c) resource busy 0, total 52
15:59:25 2975149mS RES: Thu 13/7/2017 15:59:24 FreeMem=50864120 Heap=50568856(2) Cache=295264 MemObjs=13880(14345) CMMsg=5(7) ASN=0 Buff=5200 1359 1000 7401 5 Links=57025(57245) BTree=1252(3213) CPU=04.11% CPUStats=05.22%/5/14/2924/13813/14810/00.66%/
0/03.35% MCR=0 MCW=0
15:59:25 2975149mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=59 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=136 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=1 TCP=86(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
15:59:25 2975149mS RES4: XML MemObjs=63 PoolMem=4748404(2) FreePoolMem=4733100(0)
15:59:25 2975149mS RES5: CLog MemObjs=501 FreePoolMem(Objs)=5148(99) TotalMem=165250
15:59:25 2975765mS H323Evt: Recv: RegistrationRequest 10.133.2.113; Extn(7020), time since last RRQ-KA 55010, Endpoints registered: 31; Endpoints in registration: 0
15:59:26 2976963mS H323Evt: Recv: RegistrationRequest 10.133.2.121; Extn(7021), time since last RRQ-KA 55012, Endpoints registered: 31; Endpoints in registration: 0
15:59:27 2977024mS CMExtnEvt: Test User: Recover Timer reason=CMTRWrapUp
15:59:27 2977024mS CMExtnEvt: v=32 State, new=Idle old=PortRecoverDelay,0,0,Test User
15:59:27 2977025mS CMExtnTx: v=7040, p1=0
CMVoiceMailStatus
Line: type=IPLine 250 Call: lid=0 id=-1 in=0
Called[Test User Msgs=0 Old=0 Sav=0] Type=Default (100) Reason=CMDRdirect Calling[00000000] Type=Default Plan=Default
Display [Test User Msgs=0]
Timed: 13/07/17 15:59
15:59:29 2979138mS H323Evt: Recv: RegistrationRequest 10.133.2.100; Extn(7014), time since last RRQ-KA 55010, Endpoints registered: 31; Endpoints in registration: 0
15:59:31 2981517mS H323Evt: Recv: RegistrationRequest 10.133.2.101; Extn(7029), time since last RRQ-KA 55010, Endpoints registered: 31; Endpoints in registration: 0
15:59:31 2981551mS H323Evt: Recv: RegistrationRequest 10.133.2.115; Extn(7018), time since last RRQ-KA 55012, Endpoints registered: 31; Endpoints in registration: 0
15:59:36 2987902mS H323Evt: Recv: RegistrationRequest 10.133.2.107; Extn(7015), time since last RRQ-KA 55010, Endpoints registered: 31; Endpoints in registration: 0
15:59:42 2992514mS H323Evt: Recv: RegistrationRequest 10.133.2.116; Extn(7016), time since last RRQ-KA 55010, Endpoints registered: 31; Endpoints in registration: 0
15:59:42 2992799mS H323Evt: Recv: RegistrationRequest 10.133.2.105; Extn(7005), time since last RRQ-KA 55012, Endpoints registered: 31; Endpoints in registration: 0
15:59:43 2993754mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 3
15:59:43 2993756mS CMCallEvt: 0000000000000000 0.1104.0 -1 BaseEP: NEW CMEndpoint f17d6c54 TOTAL NOW=3 CALL_LIST=1
15:59:43 2993756mS CMCallEvt: 0000000000000000 0.1104.0 -1 Test User.-1: NEW CMExtnEndpoint f17d6c54, Name=Test User, Extn=7040, Phys Extn=7040
15:59:43 2993757mS CMCallEvt: CREATE CALL:36 (f17d6060)
15:59:43 2993757mS CMCallEvt: 0000000000000000 0.1105.0 -1 BaseEP: NEW CMEndpoint f17d4754 TOTAL NOW=4 CALL_LIST=1
15:59:43 2993759mS CMExtnEvt: Test User: CMExtnHandler::SetCurrent( id: 0->1104 )
15:59:43 2993760mS CMExtnRx: v=7040, p1=0
CMSetup
Line: type=IPLine 250 Call: lid=287 id=1104 in=0
Called[] Type=Default (100) Reason=CMDRdirect Calling[7040] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
IE CMIEFastStartInfoData (6) 12 item(s)
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=Test User
IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=Test User
15:59:43 2993760mS CMCallEvt: 0a85020100000450 287.1104.0 36 Test User.0: StateChange: END=A CMCSIdle->CMCSDialInitiated
15:59:43 2993760mS CMExtnEvt: v=32 State, new=Dialling old=Idle,0,0,Test User
15:59:43 2993760mS CMTARGET: 0a85020100000450 287.1104.0 36 Test User.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party= sub= calling=7040 calling_sub= dir=out complete=0 ses=0
15:59:43 2993761mS CMTARGET: 0a85020100000450 287.1104.0 36 Test User.0: ADD TARGET (N): number= type=100 depth=1 nobar=1 setorig=1 ses=0
15:59:43 2993761mS CMCallEvt: 0a85020100000450 287.1104.0 36 Test User.0: StateChange: END=A CMCSDialInitiated->CMCSDialling
15:59:43 2993764mS CMExtnTx: v=7040, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=287 id=1104 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
IE CMIESecurityData (253) 2 item(s)
CMSecurityElement RX_ONLY {
CMSRTPCryptoCapability none
Codecs list (size 4)
}
CMSecurityElement TX_ONLY {
CMSRTPCryptoCapability none
Codecs list (size 4)
}
Timed: 13/07/17 15:59
15:59:43 2993764mS H323Evt: PortmAvayaH323Phone::PortmAvayaH323PhoneDelay: 7040 - delay disabled
15:59:43 2993764mS CMExtnTx: v=7040, p1=8036
CMFacility
Line: type=IPLine 250 Call: lid=287 id=32 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
15:59:43 2993765mS CMExtnTx: v=7040, p1=0
CMSetupAck
Line: type=IPLine 250 Call: lid=287 id=1104 in=0
Timed: 13/07/17 15:59
15:59:43 2993765mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1104 in=0
Called[3] Type=Default (100) Reason=CMDRdirect Keypad[3]
15:59:43 2993768mS CD: CALL: 287.1104.0 BState=Idle Cut=0 Music=0.0 Aend="Test User(7040)" (0.0) Bend="" [] (0.0) CalledNum=3 () CallingNum=7040 (Test User) Internal=1 Time=11 AState=Dialling
15:59:43 2993770mS H323Evt: SESS 2b SetOperational local 10.133.2.1:0 remote 0.0.0.0:0 to 0
15:59:43 2993770mS H323Evt: SESS 2b SetRemUDP 0 -> 51694, remote IP 0.0.0.0 -> 10.130.64.184
15:59:44 2994172mS RES: Thu 13/7/2017 15:59:43 FreeMem=50829328 Heap=50569912(2) Cache=259416 MemObjs=14021(14345) CMMsg=5(7) ASN=0 Buff=5200 1361 1000 7402 5 Links=57085(57245) BTree=1255(3213) CPU=03.67% CPUStats=05.78%/14/23/2924/14108/14810/00.42%
/0/03.20% MCR=0 MCW=0
15:59:44 2994172mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=59 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=134 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=1 TCP=86(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
15:59:44 2994172mS RES4: XML MemObjs=63 PoolMem=4748404(2) FreePoolMem=4733100(0)
15:59:44 2994172mS RES5: CLog MemObjs=501 FreePoolMem(Objs)=5148(99) TotalMem=165250
15:59:44 2994203mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 0
15:59:44 2994204mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1104 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
15:59:44 2994437mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 8
15:59:44 2994437mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1104 in=0
Called[8] Type=Default (100) Reason=CMDRdirect Keypad[8]
15:59:44 2994673mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 0
15:59:44 2994674mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1104 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
15:59:43 2994977mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 3
15:59:43 2994977mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1104 in=0
Called[3] Type=Default (100) Reason=CMDRdirect Keypad[3]
15:59:44 2995265mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 6
15:59:44 2995266mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1104 in=0
Called[6] Type=Default (100) Reason=CMDRdirect Keypad[6]
15:59:44 2995557mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 7
15:59:44 2995557mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1104 in=0
Called[7] Type=Default (100) Reason=CMDRdirect Keypad[7]
15:59:44 2995868mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 8
15:59:44 2995869mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1104 in=0
Called[8] Type=Default (100) Reason=CMDRdirect Keypad[8]
15:59:45 2996013mS H323Evt: Recv: RegistrationRequest 10.133.2.108; Extn(7002), time since last RRQ-KA 55014, Endpoints registered: 31; Endpoints in registration: 0
15:59:45 2996188mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 6
15:59:45 2996188mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1104 in=0
Called[6] Type=Default (100) Reason=CMDRdirect Keypad[6]

********** SysMonitor v9.1.7.0 build 163 [connected to 10.133.2.1 (Oriental Abuja)] **********
15:59:45 2996449mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 2
15:59:45 2996450mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1104 in=0
Called[2] Type=Default (100) Reason=CMDRdirect Keypad[2]
15:59:45 2996469mS PRN: Monitor Status IP 500 V2 9.1.6.0 build 153
15:59:45 2996469mS PRN: LAW=A PRI=1, BRI=0, ALOG=8, VCOMP=52, MDM=0, WAN=0, MODU=0 LANM=0 CkSRC=9 VMAIL=1(VER=3 TYP=2) 1-X=0 CALLS=2(TOT=36)
15:59:45 2996781mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 6
15:59:45 2996781mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1104 in=0
Called[6] Type=Default (100) Reason=CMDRdirect Keypad[6]
15:59:45 2996781mS CMTARGET: 0a85020100000450 287.1104.0 36 Test User.0: CancelTimer CMTCDelayedProcessing
15:59:45 2996782mS CMTARGET: 0a85020100000450 287.1104.0 36 Test User.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=30803678626 sub= calling=7040 calling_sub= dir=out complete=0 ses=0
15:59:45 2996782mS CMTARGET: 0a85020100000450 287.1104.0 36 Test User.0: ADD TARGET (N): number=30803678626 type=100 depth=1 nobar=1 setorig=1 ses=0
15:59:45 2996783mS CMTARGET: 0a85020100000450 287.1104.0 36 Test User.0: DEF SC: 30803678626 0 sc=type=Dial code=?, num=.
15:59:45 2996783mS CMARS: FindActiveARSByGroupID GroupID=51 - Not Found
15:59:45 2996783mS CMLRQ: FindActiveLRQByGroupID GroupID=51 - Not Found
15:59:45 2996783mS CMMap: a=4.1 b=0.0 Mapper::AllocateCodec allocated CMRTVocoder(f5380e5c) resource busy 1, total 52
15:59:45 2996784mS CMCallEvt: 0000000000000000 0.1106.0 -1 BaseEP: NEW CMEndpoint f17c4edc TOTAL NOW=5 CALL_LIST=2
15:59:45 2996785mS CMTARGET: DIAL LINE: 36 GROUP = 51 SUCCESS = f17c4edc
15:59:45 2996785mS CMTARGET: 0a85020100000450 287.1104.0 36 Test User.0: CancelTimer CMTCDialToneTimeout
15:59:45 2996785mS CMTARGET: 0a85020100000450 287.1104.0 36 Test User.0: INITIAL TARGETING SUCCEEDED
15:59:45 2996785mS CMTARGET: 0a85020100000450 287.1104.0 36 Test User.0: GetNoAnswerTimer:15
15:59:45 2996785mS CMCallEvt: 0000000000000000 0.1105.0 36 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
15:59:45 2996786mS CMCallEvt: 0a85020100000452 0.1106.0 36 Q931 Trunk:9 CHAN=-1: StateChange: END=T CMCSIdle->CMCSOffering
15:59:45 2996787mS CMLineTx: v=9
CMSetup
Line: type=Q931Line 9 Call: lid=0 id=1106 in=0
Called[30803678626] Type=Unknown (0) Reason=CMDRdirect Calling[] Type=Unknown Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
Timed: 13/07/17 15:59
Locale: eng
15:59:45 2996787mS CD: CALL: 287.1104.0 BState=Idle Cut=0 Music=0.0 Aend="Test User(7040)" (0.0) Bend="Line 9" [Line 9] (0.0) CalledNum=30803678626 () CallingNum=7040 (Test User) Internal=0 Time=3030 AState=Dialling
15:59:45 2996789mS ISDNL3Evt: v=9 stacknum=9 State, new=Initiated, old=NullState id=1106
15:59:46 2997043mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 8
15:59:46 2997044mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1104 in=0
Called[8] Type=Default (100) Reason=CMDRdirect Keypad[8]
15:59:46 2997706mS H323Evt: Recv: RegistrationRequest 10.133.2.130; Extn(7028), time since last RRQ-KA 55011, Endpoints registered: 31; Endpoints in registration: 0
15:59:46 2997835mS H323Evt: Recv: RegistrationRequest 10.133.2.112; Extn(7011), time since last RRQ-KA 55010, Endpoints registered: 31; Endpoints in registration: 0
15:59:56 3006441mS CMExtnEvt: Rashida Saleh: No user activity
15:59:56 3006848mS R2DSP: PRIU DSP 3: is alive
15:59:57 3007875mS H323Evt: Recv: RegistrationRequest 10.133.2.129; Extn(7024), time since last RRQ-KA 55011, Endpoints registered: 31; Endpoints in registration: 0
15:59:58 3008932mS H323Evt: Recv: RegistrationRequest 10.133.2.122; Extn(7017), time since last RRQ-KA 55010, Endpoints registered: 31; Endpoints in registration: 0
15:59:58 3009768mS PRN: Optimizing BTree Lists Completed...Started:3009767 Duration:0 Size:120 Attempted:120
15:59:59 3010664mS H323Evt: Recv: RegistrationRequest 10.133.2.103; Extn(7006), time since last RRQ-KA 55013, Endpoints registered: 31; Endpoints in registration: 0
15:59:59 3010961mS H323Evt: Recv: RegistrationRequest 10.133.2.106; Extn(7031), time since last RRQ-KA 55011, Endpoints registered: 31; Endpoints in registration: 0
16:00:00 3011663mS H323Evt: Recv: RegistrationRequest 10.133.2.120; Extn(7008), time since last RRQ-KA 55013, Endpoints registered: 31; Endpoints in registration: 0
16:00:00 3011785mS CMTARGET: 0a85020100000450 287.1104.0 36 Test User.0: TimerExpired cause=CMTCNoAnswerTimeout
16:00:00 3011786mS CMTARGET: 0a85020100000450 287.1104.0 36 Test User.0: Retarget NOANSWER EXCEPTED=00000000 INCLUDED=00000000 ValidTargets=0
16:00:00 3011786mS CMTARGET: 0a85020100000450 287.1104.0 36 Test User.0: Retarget NOANSWER delete call cause CMCauseCallRejected aend state CMCSDialling
16:00:00 3011786mS CMLOGGING: CALL:2017/07/1315:59,00:00:00,000,7040,O,308036786268,308036786268,TestUser,,,0,,"",0,n/a
16:00:00 3011786mS CD: CALL: 287.1104.0 BState=Idle Cut=0 Music=0.0 Aend="Test User(7040)" (0.0) Bend="Line 9" [Line 9] (0.0) CalledNum=308036786268 () CallingNum=7040 (Test User) Internal=0 Time=18029 AState=Dialling
16:00:00 3011786mS CD: CALL: 287.1104.0 Deleted
16:00:00 3011787mS CMExtnEvt: Test User: CALL LOST (CMCauseCallRejected)
16:00:00 3011787mS CMExtnEvt: Test User: Extn(7040) Calling Party Number(7040) Type(CMNTypeInternal)
16:00:00 3011787mS CMCallEvt: 0a85020100000450 287.1104.0 -1 Test User.0: StateChange: END=X CMCSDialling->CMCSCompletedTone
16:00:00 3011788mS CMMap: IP::SetCodec pcp[228]b0r1 0 -> f5380e5c
16:00:00 3011788mS CMExtnEvt: v=32 State, new=CMESCompleted old=Dialling,0,0,Test User
16:00:00 3011788mS CMCallEvt: 0000000000000000 0.1105.0 -1 BaseEP: DELETE CMEndpoint f17d4754 TOTAL NOW=4 CALL_LIST=1
16:00:00 3011789mS CMLineTx: v=9
CMDisconnect
Line: type=Q931Line 9 Call: lid=0 id=1106 in=0
Cause=21, Call rejected
16:00:00 3011789mS CMCallEvt: 0a85020100000452 0.1106.0 -1 Q931 Trunk:9 CHAN=-1: StateChange: END=X CMCSOffering->CMCSCompleted
16:00:00 3011789mS CMCallEvt: END CALL:36 (f17d6060)
16:00:00 3011791mS CMMap: PCG::AddToneGenerator g E1[7] for cp[228]b0r1 append pcp[229]b0r1 (total 1)
16:00:00 3011792mS CMMap: PlatformConnectionAudioSAP::Bind pcp[229]b0r1 to 0.0
16:00:00 3011792mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[229]b0r1 Configure 0.0
16:00:00 3011792mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[229]b0r1 ConnectIndication 0.0
16:00:00 3011792mS CMMap: a=0.0 b=0.0 pcp[228]b0r1 RTPE1
16:00:00 3011792mS H323Evt: SESS 2b SetOperational local 10.133.2.1:49156 remote 10.130.64.184:51694 to 1
16:00:00 3011793mS ISDNL3Evt: v=9 stacknum=9 State, new=DiscReq, old=Initiated id=1106
16:00:01 3012184mS RES: Thu 13/7/2017 16:00:01 FreeMem=50832828 Heap=50569912(2) Cache=262916 MemObjs=14007(14345) CMMsg=5(7) ASN=0 Buff=5200 1360 1000 7403 5 Links=57095(57245) BTree=1252(3213) CPU=03.96% CPUStats=05.14%/5/13/2924/13939/14810/00.58%/
0/03.32% MCR=0 MCW=0
16:00:01 3012184mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=59 RTEngine=1 CMRTEngine=0 ExRTEngine=0 Timer=134 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=1 TCP=86(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
16:00:01 3012185mS RES4: XML MemObjs=63 PoolMem=4748404(2) FreePoolMem=4733100(0)
16:00:01 3012185mS RES5: CLog MemObjs=501 FreePoolMem(Objs)=5148(99) TotalMem=165250
16:00:01 3012825mS H323Evt: SESS 2b: RTP(50r): 10.133.2.1/49156 10.130.64.184/51694 CODEC=Alaw64K(4) PKTSZ=160 RFC2833=off AGE=19054 SENT=51 (avg size=164) RECV=50 (avg size=160)
16:00:01 3012895mS H323Evt: Recv: RegistrationRequest 10.133.2.128; Extn(7025), time since last RRQ-KA 55011, Endpoints registered: 31; Endpoints in registration: 0
16:00:03 3014672mS H323Evt: Recv: RegistrationRequest 10.133.2.124; Extn(7027), time since last RRQ-KA 55012, Endpoints registered: 31; Endpoints in registration: 0
16:00:04 3015325mS CMExtnTx: v=7040, p1=8036
CMFacility
Line: type=IPLine 250 Call: lid=287 id=32 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
16:00:04 3015326mS CMExtnRx: v=7040, p1=0
CMReleaseComp
Line: type=IPLine 250 Call: lid=287 id=1104 in=0
16:00:04 3015326mS CMCallEvt: 0a85020100000450 287.1104.0 -1 Test User.0: StateChange: END=X CMCSCompletedTone->CMCSCompleted
16:00:04 3015327mS CMExtnTx: v=7040, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=287 id=1104 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
Timed: 13/07/17 16:00
16:00:04 3015327mS CMExtnEvt: v=32 State, new=PortRecoverDelay old=CMESCompleted,0,0,Test User
16:00:04 3015328mS CMExtnEvt: Test User: CALL LOST (CMCauseForceClear)
16:00:04 3015328mS CMExtnEvt: Test User: Extn(7040) Calling Party Number(7040) Type(CMNTypeInternal)
16:00:04 3015328mS CMExtnEvt: Test User: CMExtnHandler::SetCurrent( id: 1104->0 )
16:00:04 3015329mS CMCallEvt: 0a85020100000450 287.1104.0 -1 Test User.-1: StateChange: END=X CMCSCompleted->CMCSDelete
16:00:04 3015329mS CMTARGET: 0a85020100000450 287.1104.0 -1 BaseEP: ~CMTargetHandler f17ce1ec ep f17d6c54
16:00:04 3015330mS CMCallEvt: 0a85020100000450 287.1104.0 -1 BaseEP: DELETE CMEndpoint f17d6c54 TOTAL NOW=3 CALL_LIST=1
16:00:04 3015332mS CMMap: a=0.0 b=0.0 pcp[228]b0r1 RTPE0
16:00:04 3015332mS H323Evt: SESS 2b SetOperational local 10.133.2.1:49156 remote 10.130.64.184:51694 to 0
16:00:04 3015333mS H323Evt: SESS 2b: RTP(END): 10.133.2.1/49156 10.130.64.184/51694 CODEC=Alaw64K(4) PKTSZ=160 RFC2833=off AGE=21563 SENT=177 RECV=175 RTdelay=0 jitter=0 loss=0 remotejitter=0 remoteloss=0
16:00:04 3015333mS CMMap: a=4.1 b=0.0 Mapper::FreeCodec freed CMRTVocoder(f5380e5c) resource busy 0, total 52
16:00:05 3016573mS H323Evt: Recv: RegistrationRequest 10.133.2.109; Extn(7013), time since last RRQ-KA 55012, Endpoints registered: 31; Endpoints in registration: 0
16:00:06 3017190mS H323Evt: Recv: RegistrationRequest 10.133.2.127; Extn(7001), time since last RRQ-KA 55013, Endpoints registered: 31; Endpoints in registration: 0
16:00:06 3017329mS CMExtnEvt: Test User: Recover Timer reason=CMTRWrapUp
16:00:06 3017329mS CMExtnEvt: v=32 State, new=Idle old=PortRecoverDelay,0,0,Test User
16:00:06 3017330mS CMExtnTx: v=7040, p1=0
CMVoiceMailStatus
Line: type=IPLine 250 Call: lid=0 id=-1 in=0
Called[Test User Msgs=0 Old=0 Sav=0] Type=Default (100) Reason=CMDRdirect Calling[00000000] Type=Default Plan=Default
Display [Test User Msgs=0]
Timed: 13/07/17 16:00
16:00:07 3018205mS H323Evt: Recv: RegistrationRequest 10.133.2.125; Extn(7004), time since last RRQ-KA 55014, Endpoints registered: 31; Endpoints in registration: 0
16:00:07 3018581mS H323Evt: Recv: RegistrationRequest 10.133.2.102; Extn(7033), time since last RRQ-KA 55011, Endpoints registered: 31; Endpoints in registration: 0
16:00:07 3018597mS H323Evt: Recv: RegistrationRequest 10.133.2.126; Extn(7023), time since last RRQ-KA 55011, Endpoints registered: 31; Endpoints in registration: 0
16:00:08 3019234mS H323Evt: Recv: RegistrationRequest 10.133.3.193; Extn(7010), time since last RRQ-KA 55013, Endpoints registered: 31; Endpoints in registration: 0

RE: Issues with PRI Line

(OP)
Here is another trace on my test extension 7040. Please advise .

Called[8] Type=Default (100) Reason=CMDRdirect Keypad[8]
15:59:45 2996013mS H323Evt: Recv: RegistrationRequest 10.133.2.108; Extn(7002), time since last RRQ-KA 55014, Endpoints registered: 31; Endpoints in registration: 0
15:59:45 2996188mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 6
15:59:45 2996188mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1104 in=0
Called[6] Type=Default (100) Reason=CMDRdirect Keypad[6]

********** SysMonitor v9.1.7.0 build 163 [connected to 10.133.2.1 (Oriental Abuja)] **********
15:59:45 2996449mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 2
15:59:45 2996450mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1104 in=0
Called[2] Type=Default (100) Reason=CMDRdirect Keypad[2]
15:59:45 2996469mS PRN: Monitor Status IP 500 V2 9.1.6.0 build 153
15:59:45 2996469mS PRN: LAW=A PRI=1, BRI=0, ALOG=8, VCOMP=52, MDM=0, WAN=0, MODU=0 LANM=0 CkSRC=9 VMAIL=1(VER=3 TYP=2) 1-X=0 CALLS=2(TOT=36)
15:59:45 2996781mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 6
15:59:45 2996781mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1104 in=0
Called[6] Type=Default (100) Reason=CMDRdirect Keypad[6]
15:59:45 2996781mS CMTARGET: 0a85020100000450 287.1104.0 36 Test User.0: CancelTimer CMTCDelayedProcessing
15:59:45 2996782mS CMTARGET: 0a85020100000450 287.1104.0 36 Test User.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=30803678626 sub= calling=7040 calling_sub= dir=out complete=0 ses=0
15:59:45 2996782mS CMTARGET: 0a85020100000450 287.1104.0 36 Test User.0: ADD TARGET (N): number=30803678626 type=100 depth=1 nobar=1 setorig=1 ses=0
15:59:45 2996783mS CMTARGET: 0a85020100000450 287.1104.0 36 Test User.0: DEF SC: 30803678626 0 sc=type=Dial code=?, num=.
15:59:45 2996783mS CMARS: FindActiveARSByGroupID GroupID=51 - Not Found
15:59:45 2996783mS CMLRQ: FindActiveLRQByGroupID GroupID=51 - Not Found
15:59:45 2996783mS CMMap: a=4.1 b=0.0 Mapper::AllocateCodec allocated CMRTVocoder(f5380e5c) resource busy 1, total 52
15:59:45 2996784mS CMCallEvt: 0000000000000000 0.1106.0 -1 BaseEP: NEW CMEndpoint f17c4edc TOTAL NOW=5 CALL_LIST=2
15:59:45 2996785mS CMTARGET: DIAL LINE: 36 GROUP = 51 SUCCESS = f17c4edc
15:59:45 2996785mS CMTARGET: 0a85020100000450 287.1104.0 36 Test User.0: CancelTimer CMTCDialToneTimeout
15:59:45 2996785mS CMTARGET: 0a85020100000450 287.1104.0 36 Test User.0: INITIAL TARGETING SUCCEEDED
15:59:45 2996785mS CMTARGET: 0a85020100000450 287.1104.0 36 Test User.0: GetNoAnswerTimer:15
15:59:45 2996785mS CMCallEvt: 0000000000000000 0.1105.0 36 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
15:59:45 2996786mS CMCallEvt: 0a85020100000452 0.1106.0 36 Q931 Trunk:9 CHAN=-1: StateChange: END=T CMCSIdle->CMCSOffering
15:59:45 2996787mS CMLineTx: v=9
CMSetup
Line: type=Q931Line 9 Call: lid=0 id=1106 in=0
Called[30803678626] Type=Unknown (0) Reason=CMDRdirect Calling[] Type=Unknown Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
Timed: 13/07/17 15:59
Locale: eng
15:59:45 2996787mS CD: CALL: 287.1104.0 BState=Idle Cut=0 Music=0.0 Aend="Test User(7040)" (0.0) Bend="Line 9" [Line 9] (0.0) CalledNum=30803678626 () CallingNum=7040 (Test User) Internal=0 Time=3030 AState=Dialling
15:59:45 2996789mS ISDNL3Evt: v=9 stacknum=9 State, new=Initiated, old=NullState id=1106
15:59:46 2997043mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 8
15:59:46 2997044mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1104 in=0
Called[8] Type=Default (100) Reason=CMDRdirect Keypad[8]
15:59:46 2997706mS H323Evt: Recv: RegistrationRequest 10.133.2.130; Extn(7028), time since last RRQ-KA 55011, Endpoints registered: 31; Endpoints in registration: 0
15:59:46 2997835mS H323Evt: Recv: RegistrationRequest 10.133.2.112; Extn(7011), time since last RRQ-KA 55010, Endpoints registered: 31; Endpoints in registration: 0
15:59:56 3006441mS CMExtnEvt: Rashida Saleh: No user activity
15:59:56 3006848mS R2DSP: PRIU DSP 3: is alive
15:59:57 3007875mS H323Evt: Recv: RegistrationRequest 10.133.2.129; Extn(7024), time since last RRQ-KA 55011, Endpoints registered: 31; Endpoints in registration: 0
15:59:58 3008932mS H323Evt: Recv: RegistrationRequest 10.133.2.122; Extn(7017), time since last RRQ-KA 55010, Endpoints registered: 31; Endpoints in registration: 0
15:59:58 3009768mS PRN: Optimizing BTree Lists Completed...Started:3009767 Duration:0 Size:120 Attempted:120
15:59:59 3010664mS H323Evt: Recv: RegistrationRequest 10.133.2.103; Extn(7006), time since last RRQ-KA 55013, Endpoints registered: 31; Endpoints in registration: 0
15:59:59 3010961mS H323Evt: Recv: RegistrationRequest 10.133.2.106; Extn(7031), time since last RRQ-KA 55011, Endpoints registered: 31; Endpoints in registration: 0
16:00:00 3011663mS H323Evt: Recv: RegistrationRequest 10.133.2.120; Extn(7008), time since last RRQ-KA 55013, Endpoints registered: 31; Endpoints in registration: 0
16:00:00 3011785mS CMTARGET: 0a85020100000450 287.1104.0 36 Test User.0: TimerExpired cause=CMTCNoAnswerTimeout
16:00:00 3011786mS CMTARGET: 0a85020100000450 287.1104.0 36 Test User.0: Retarget NOANSWER EXCEPTED=00000000 INCLUDED=00000000 ValidTargets=0
16:00:00 3011786mS CMTARGET: 0a85020100000450 287.1104.0 36 Test User.0: Retarget NOANSWER delete call cause CMCauseCallRejected aend state CMCSDialling
16:00:00 3011786mS CMLOGGING: CALL:2017/07/1315:59,00:00:00,000,7040,O,308036786268,308036786268,TestUser,,,0,,"",0,n/a
16:00:00 3011786mS CD: CALL: 287.1104.0 BState=Idle Cut=0 Music=0.0 Aend="Test User(7040)" (0.0) Bend="Line 9" [Line 9] (0.0) CalledNum=308036786268 () CallingNum=7040 (Test User) Internal=0 Time=18029 AState=Dialling
16:00:00 3011786mS CD: CALL: 287.1104.0 Deleted
16:00:00 3011787mS CMExtnEvt: Test User: CALL LOST (CMCauseCallRejected)
16:00:00 3011787mS CMExtnEvt: Test User: Extn(7040) Calling Party Number(7040) Type(CMNTypeInternal)
16:00:00 3011787mS CMCallEvt: 0a85020100000450 287.1104.0 -1 Test User.0: StateChange: END=X CMCSDialling->CMCSCompletedTone
16:00:00 3011788mS CMMap: IP::SetCodec pcp[228]b0r1 0 -> f5380e5c
16:00:00 3011788mS CMExtnEvt: v=32 State, new=CMESCompleted old=Dialling,0,0,Test User
16:00:00 3011788mS CMCallEvt: 0000000000000000 0.1105.0 -1 BaseEP: DELETE CMEndpoint f17d4754 TOTAL NOW=4 CALL_LIST=1
16:00:00 3011789mS CMLineTx: v=9
CMDisconnect
Line: type=Q931Line 9 Call: lid=0 id=1106 in=0
Cause=21, Call rejected
16:00:00 3011789mS CMCallEvt: 0a85020100000452 0.1106.0 -1 Q931 Trunk:9 CHAN=-1: StateChange: END=X CMCSOffering->CMCSCompleted
16:00:00 3011789mS CMCallEvt: END CALL:36 (f17d6060)
16:00:00 3011791mS CMMap: PCG::AddToneGenerator g E1[7] for cp[228]b0r1 append pcp[229]b0r1 (total 1)
16:00:00 3011792mS CMMap: PlatformConnectionAudioSAP::Bind pcp[229]b0r1 to 0.0
16:00:00 3011792mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[229]b0r1 Configure 0.0
16:00:00 3011792mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[229]b0r1 ConnectIndication 0.0
16:00:00 3011792mS CMMap: a=0.0 b=0.0 pcp[228]b0r1 RTPE1
16:00:00 3011792mS H323Evt: SESS 2b SetOperational local 10.133.2.1:49156 remote 10.130.64.184:51694 to 1
16:00:00 3011793mS ISDNL3Evt: v=9 stacknum=9 State, new=DiscReq, old=Initiated id=1106
16:00:01 3012184mS RES: Thu 13/7/2017 16:00:01 FreeMem=50832828 Heap=50569912(2) Cache=262916 MemObjs=14007(14345) CMMsg=5(7) ASN=0 Buff=5200 1360 1000 7403 5 Links=57095(57245) BTree=1252(3213) CPU=03.96% CPUStats=05.14%/5/13/2924/13939/14810/00.58%/
0/03.32% MCR=0 MCW=0
16:00:01 3012184mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=59 RTEngine=1 CMRTEngine=0 ExRTEngine=0 Timer=134 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=1 TCP=86(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
16:00:01 3012185mS RES4: XML MemObjs=63 PoolMem=4748404(2) FreePoolMem=4733100(0)
16:00:01 3012185mS RES5: CLog MemObjs=501 FreePoolMem(Objs)=5148(99) TotalMem=165250
16:00:01 3012825mS H323Evt: SESS 2b: RTP(50r): 10.133.2.1/49156 10.130.64.184/51694 CODEC=Alaw64K(4) PKTSZ=160 RFC2833=off AGE=19054 SENT=51 (avg size=164) RECV=50 (avg size=160)
16:00:01 3012895mS H323Evt: Recv: RegistrationRequest 10.133.2.128; Extn(7025), time since last RRQ-KA 55011, Endpoints registered: 31; Endpoints in registration: 0
16:00:03 3014672mS H323Evt: Recv: RegistrationRequest 10.133.2.124; Extn(7027), time since last RRQ-KA 55012, Endpoints registered: 31; Endpoints in registration: 0
16:00:04 3015325mS CMExtnTx: v=7040, p1=8036
CMFacility
Line: type=IPLine 250 Call: lid=287 id=32 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
16:00:04 3015326mS CMExtnRx: v=7040, p1=0
CMReleaseComp
Line: type=IPLine 250 Call: lid=287 id=1104 in=0
16:00:04 3015326mS CMCallEvt: 0a85020100000450 287.1104.0 -1 Test User.0: StateChange: END=X CMCSCompletedTone->CMCSCompleted
16:00:04 3015327mS CMExtnTx: v=7040, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=287 id=1104 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
Timed: 13/07/17 16:00
16:00:04 3015327mS CMExtnEvt: v=32 State, new=PortRecoverDelay old=CMESCompleted,0,0,Test User
16:00:04 3015328mS CMExtnEvt: Test User: CALL LOST (CMCauseForceClear)
16:00:04 3015328mS CMExtnEvt: Test User: Extn(7040) Calling Party Number(7040) Type(CMNTypeInternal)
16:00:04 3015328mS CMExtnEvt: Test User: CMExtnHandler::SetCurrent( id: 1104->0 )
16:00:04 3015329mS CMCallEvt: 0a85020100000450 287.1104.0 -1 Test User.-1: StateChange: END=X CMCSCompleted->CMCSDelete
16:00:04 3015329mS CMTARGET: 0a85020100000450 287.1104.0 -1 BaseEP: ~CMTargetHandler f17ce1ec ep f17d6c54
16:00:04 3015330mS CMCallEvt: 0a85020100000450 287.1104.0 -1 BaseEP: DELETE CMEndpoint f17d6c54 TOTAL NOW=3 CALL_LIST=1
16:00:04 3015332mS CMMap: a=0.0 b=0.0 pcp[228]b0r1 RTPE0
16:00:04 3015332mS H323Evt: SESS 2b SetOperational local 10.133.2.1:49156 remote 10.130.64.184:51694 to 0
16:00:04 3015333mS H323Evt: SESS 2b: RTP(END): 10.133.2.1/49156 10.130.64.184/51694 CODEC=Alaw64K(4) PKTSZ=160 RFC2833=off AGE=21563 SENT=177 RECV=175 RTdelay=0 jitter=0 loss=0 remotejitter=0 remoteloss=0
16:00:04 3015333mS CMMap: a=4.1 b=0.0 Mapper::FreeCodec freed CMRTVocoder(f5380e5c) resource busy 0, total 52
16:00:05 3016573mS H323Evt: Recv: RegistrationRequest 10.133.2.109; Extn(7013), time since last RRQ-KA 55012, Endpoints registered: 31; Endpoints in registration: 0
16:00:06 3017190mS H323Evt: Recv: RegistrationRequest 10.133.2.127; Extn(7001), time since last RRQ-KA 55013, Endpoints registered: 31; Endpoints in registration: 0
16:00:06 3017329mS CMExtnEvt: Test User: Recover Timer reason=CMTRWrapUp
16:00:06 3017329mS CMExtnEvt: v=32 State, new=Idle old=PortRecoverDelay,0,0,Test User
16:00:06 3017330mS CMExtnTx: v=7040, p1=0
CMVoiceMailStatus
Line: type=IPLine 250 Call: lid=0 id=-1 in=0
Called[Test User Msgs=0 Old=0 Sav=0] Type=Default (100) Reason=CMDRdirect Calling[00000000] Type=Default Plan=Default
Display [Test User Msgs=0]
Timed: 13/07/17 16:00
16:00:07 3018205mS H323Evt: Recv: RegistrationRequest 10.133.2.125; Extn(7004), time since last RRQ-KA 55014, Endpoints registered: 31; Endpoints in registration: 0
16:00:07 3018581mS H323Evt: Recv: RegistrationRequest 10.133.2.102; Extn(7033), time since last RRQ-KA 55011, Endpoints registered: 31; Endpoints in registration: 0
16:00:07 3018597mS H323Evt: Recv: RegistrationRequest 10.133.2.126; Extn(7023), time since last RRQ-KA 55011, Endpoints registered: 31; Endpoints in registration: 0
16:00:08 3019234mS H323Evt: Recv: RegistrationRequest 10.133.3.193; Extn(7010), time since last RRQ-KA 55013, Endpoints registered: 31; Endpoints in registration: 0

********** Warning: Logging to Screen Stopped **********

********** Warning: Logging to Screen Started **********
16:18:53 4143928mS ISDNL1Rx: v=9 peb=9
0000 02 01 7f ...
16:18:53 4143928mS ISDNL2Rx: v=9 peb=9
0000 02 01 7f ...
16:18:53 4143928mS ISDNL2Tx: v=9 peb=9
0000 02 01 73 ..s
16:18:53 4143929mS ISDNL1Tx: v=9 peb=9
0000 02 01 73 ..s
16:18:54 4144928mS ISDNL1Rx: v=9 peb=9
0000 02 01 7f ...
16:18:54 4144928mS ISDNL2Rx: v=9 peb=9
0000 02 01 7f ...
16:18:54 4144928mS ISDNL2Tx: v=9 peb=9
0000 02 01 73 ..s
16:18:54 4144929mS ISDNL1Tx: v=9 peb=9
0000 02 01 73 ..s
16:18:55 4145382mS PRN: SCNTFTP::SendPacket (3) seq=99 len=39 retries=2 dest 10.130.68.3
16:18:55 4145928mS ISDNL1Rx: v=9 peb=9
0000 02 01 7f ...
16:18:55 4145928mS ISDNL2Rx: v=9 peb=9
0000 02 01 7f ...
16:18:55 4145928mS ISDNL2Tx: v=9 peb=9
0000 02 01 73 ..s
16:18:55 4145929mS ISDNL1Tx: v=9 peb=9
0000 02 01 73 ..s
16:18:56 4146049mS PRN: SCNTFTP::SendPacket (2) seq=29 len=714 retries=3 dest 10.130.68.3
16:18:56 4146848mS R2DSP: PRIU DSP 3: is alive
16:18:56 4146928mS ISDNL1Rx: v=9 peb=9
0000 02 01 7f ...
16:18:56 4146928mS ISDNL2Rx: v=9 peb=9
0000 02 01 7f ...
16:18:56 4146928mS ISDNL2Tx: v=9 peb=9
0000 02 01 73 ..s
16:18:56 4146929mS ISDNL1Tx: v=9 peb=9
0000 02 01 73 ..s
16:18:57 4147735mS H323Evt: Recv: RegistrationRequest 10.133.2.116; Extn(7016), time since last RRQ-KA 55011, Endpoints registered: 31; Endpoints in registration: 0
16:18:58 4148078mS H323Evt: Recv: RegistrationRequest 10.133.2.105; Extn(7005), time since last RRQ-KA 55013, Endpoints registered: 31; Endpoints in registration: 0
16:18:58 4148253mS PRN: Config Write Wake Up
16:18:58 4148753mS PRN: Updates IO list size 0 updated list size 1
16:18:58 4148753mS PRN: Config Write Completed
16:18:59 4149824mS PRN: Optimizing BTree Lists Completed...Started:4149821 Duration:3 Size:117 Attempted:117
16:19:01 4151299mS H323Evt: Recv: RegistrationRequest 10.133.2.108; Extn(7002), time since last RRQ-KA 55013, Endpoints registered: 31; Endpoints in registration: 0

********** SysMonitor v9.1.7.0 build 163 [connected to 10.133.2.1 (Oriental Abuja)] **********
16:19:02 4152763mS PRN: Monitor Status IP 500 V2 9.1.6.0 build 153
16:19:02 4152763mS PRN: LAW=A PRI=1, BRI=0, ALOG=8, VCOMP=52, MDM=0, WAN=0, MODU=0 LANM=0 CkSRC=9 VMAIL=1(VER=3 TYP=2) 1-X=0 CALLS=0(TOT=43)
16:19:02 4152933mS H323Evt: Recv: RegistrationRequest 10.133.2.130; Extn(7028), time since last RRQ-KA 55011, Endpoints registered: 31; Endpoints in registration: 0
16:19:03 4153051mS H323Evt: Recv: RegistrationRequest 10.133.2.112; Extn(7011), time since last RRQ-KA 55010, Endpoints registered: 31; Endpoints in registration: 0
16:19:04 4155689mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 0
16:19:04 4155691mS CMCallEvt: 0000000000000000 0.1132.0 -1 BaseEP: NEW CMEndpoint f17d6c54 TOTAL NOW=1 CALL_LIST=0
16:19:04 4155691mS CMCallEvt: 0000000000000000 0.1132.0 -1 Test User.-1: NEW CMExtnEndpoint f17d6c54, Name=Test User, Extn=7040, Phys Extn=7040
16:19:04 4155692mS CMCallEvt: CREATE CALL:44 (f179c058)
16:19:04 4155692mS CMCallEvt: 0000000000000000 0.1133.0 -1 BaseEP: NEW CMEndpoint f17d4754 TOTAL NOW=2 CALL_LIST=0
16:19:04 4155694mS CMExtnEvt: Test User: CMExtnHandler::SetCurrent( id: 0->1132 )
16:19:04 4155694mS CMExtnRx: v=7040, p1=0
CMSetup
Line: type=IPLine 250 Call: lid=287 id=1132 in=0
Called[] Type=Default (100) Reason=CMDRdirect Calling[7040] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
IE CMIEFastStartInfoData (6) 12 item(s)
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=Test User
IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=Test User
16:19:04 4155695mS CMCallEvt: 0a8502010000046c 287.1132.0 44 Test User.0: StateChange: END=A CMCSIdle->CMCSDialInitiated
16:19:04 4155695mS CMExtnEvt: v=33 State, new=Dialling old=Idle,0,0,Test User
16:19:04 4155695mS CMTARGET: 0a8502010000046c 287.1132.0 44 Test User.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party= sub= calling=7040 calling_sub= dir=out complete=0 ses=0
16:19:04 4155695mS CMTARGET: 0a8502010000046c 287.1132.0 44 Test User.0: ADD TARGET (N): number= type=100 depth=1 nobar=1 setorig=1 ses=0
16:19:04 4155696mS CMCallEvt: 0a8502010000046c 287.1132.0 44 Test User.0: StateChange: END=A CMCSDialInitiated->CMCSDialling
16:19:04 4155699mS CMExtnTx: v=7040, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=287 id=1132 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
IE CMIESecurityData (253) 2 item(s)
CMSecurityElement RX_ONLY {
CMSRTPCryptoCapability none
Codecs list (size 4)
}
CMSecurityElement TX_ONLY {
CMSRTPCryptoCapability none
Codecs list (size 4)
}
Timed: 13/07/17 16:19
16:19:04 4155699mS H323Evt: PortmAvayaH323Phone::PortmAvayaH323PhoneDelay: 7040 - delay disabled
16:19:04 4155699mS CMExtnTx: v=7040, p1=8036
CMFacility
Line: type=IPLine 250 Call: lid=287 id=33 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
16:19:04 4155699mS CMExtnTx: v=7040, p1=0
CMSetupAck
Line: type=IPLine 250 Call: lid=287 id=1132 in=0
Timed: 13/07/17 16:19
16:19:04 4155700mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1132 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
16:19:04 4155703mS CD: CALL: 287.1132.0 BState=Idle Cut=0 Music=0.0 Aend="Test User(7040)" (0.0) Bend="" [] (0.0) CalledNum=0 () CallingNum=7040 (Test User) Internal=1 Time=11 AState=Dialling
16:19:04 4155705mS H323Evt: SESS 39 SetOperational local 10.133.2.1:0 remote 0.0.0.0:0 to 0
16:19:04 4155705mS H323Evt: SESS 39 SetRemUDP 0 -> 51694, remote IP 0.0.0.0 -> 10.130.64.184
16:19:05 4156039mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 8
16:19:05 4156039mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1132 in=0
Called[8] Type=Default (100) Reason=CMDRdirect Keypad[8]
16:19:05 4156131mS RES: Thu 13/7/2017 16:19:05 FreeMem=50866100 Heap=50527992(0) Cache=338108 MemObjs=13792(14631) CMMsg=5(7) ASN=0 Buff=5200 1356 1000 7404 5 Links=56967(57400) BTree=1268(3213) CPU=02.56% CPUStats=04.57%/14/24/2924/14113/14830/00.10%
/1/02.77% MCR=0 MCW=0
16:19:05 4156131mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=59 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=130 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=0 TCP=85(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
16:19:05 4156131mS RES4: XML MemObjs=63 PoolMem=4748404(2) FreePoolMem=4733100(0)
16:19:05 4156131mS RES5: CLog MemObjs=513 FreePoolMem(Objs)=4524(87) TotalMem=165250
16:19:05 4156352mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 0
16:19:05 4156352mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1132 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
16:19:05 4156853mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 3
16:19:05 4156854mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1132 in=0
Called[3] Type=Default (100) Reason=CMDRdirect Keypad[3]
16:19:05 4156929mS ISDNL1Rx: v=9 peb=9
0000 02 01 7f ...
16:19:05 4156929mS ISDNL2Rx: v=9 peb=9
0000 02 01 7f ...
16:19:05 4156929mS ISDNL2Tx: v=9 peb=9
0000 02 01 73 ..s
16:19:05 4156930mS ISDNL1Tx: v=9 peb=9
0000 02 01 73 ..s
16:19:06 4157175mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 6
16:19:06 4157175mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1132 in=0
Called[6] Type=Default (100) Reason=CMDRdirect Keypad[6]
16:19:06 4157630mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 7
16:19:06 4157631mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1132 in=0
Called[7] Type=Default (100) Reason=CMDRdirect Keypad[7]
16:19:06 4157666mS PRN: Config Write Wake Up
16:19:06 4157929mS ISDNL1Rx: v=9 peb=9
0000 02 01 7f ...
16:19:06 4157929mS ISDNL2Rx: v=9 peb=9
0000 02 01 7f ...
16:19:06 4157929mS ISDNL2Tx: v=9 peb=9
0000 02 01 73 ..s
16:19:06 4157930mS ISDNL1Tx: v=9 peb=9
0000 02 01 73 ..s
16:19:06 4157966mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 8
16:19:06 4157966mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1132 in=0
Called[8] Type=Default (100) Reason=CMDRdirect Keypad[8]
16:19:07 4158166mS PRN: Updates IO list size 0 updated list size 1
16:19:07 4158166mS PRN: Config Write Completed
16:19:07 4158344mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 6
16:19:07 4158344mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1132 in=0
Called[6] Type=Default (100) Reason=CMDRdirect Keypad[6]
16:19:07 4158720mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 2
16:19:07 4158720mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1132 in=0
Called[2] Type=Default (100) Reason=CMDRdirect Keypad[2]
16:19:07 4158929mS ISDNL1Rx: v=9 peb=9
0000 02 01 7f ...
16:19:07 4158929mS ISDNL2Rx: v=9 peb=9
0000 02 01 7f ...
16:19:07 4158929mS ISDNL2Tx: v=9 peb=9
0000 02 01 73 ..s
16:19:07 4158930mS ISDNL1Tx: v=9 peb=9
0000 02 01 73 ..s
16:19:08 4159099mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 6
16:19:08 4159099mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1132 in=0
Called[6] Type=Default (100) Reason=CMDRdirect Keypad[6]
16:19:08 4159492mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,7040: Digit Key Pressed 8
16:19:08 4159492mS CMExtnRx: v=7040, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=287 id=1132 in=0
Called[8] Type=Default (100) Reason=CMDRdirect Keypad[8]
16:19:08 4159492mS CMTARGET: 0a8502010000046c 287.1132.0 44 Test User.0: CancelTimer CMTCDelayedProcessing
16:19:08 4159493mS CMTARGET: 0a8502010000046c 287.1132.0 44 Test User.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=08036786268 sub= calling=7040 calling_sub= dir=out complete=0 ses=0
16:19:08 4159493mS CMTARGET: 0a8502010000046c 287.1132.0 44 Test User.0: ADD TARGET (N): number=08036786268 type=100 depth=1 nobar=1 setorig=1 ses=0
16:19:08 4159493mS CMTARGET: 0a8502010000046c 287.1132.0 44 Test User.0: DEF SC: 08036786268 0 sc=type=Dial code=?, num=.
16:19:08 4159494mS CMARS: FindActiveARSByGroupID GroupID=51 - Not Found
16:19:08 4159494mS CMLRQ: FindActiveLRQByGroupID GroupID=51 - Not Found
16:19:08 4159494mS CMMap: a=4.1 b=0.0 Mapper::AllocateCodec allocated CMRTVocoder(f5380e5c) resource busy 1, total 52
16:19:08 4159494mS CMCallEvt: 0000000000000000 0.1134.0 -1 BaseEP: NEW CMEndpoint f17c4edc TOTAL NOW=3 CALL_LIST=1
16:19:08 4159495mS CMTARGET: DIAL LINE: 44 GROUP = 51 SUCCESS = f17c4edc
16:19:08 4159495mS CMTARGET: 0a8502010000046c 287.1132.0 44 Test User.0: CancelTimer CMTCDialToneTimeout
16:19:08 4159496mS CMTARGET: 0a8502010000046c 287.1132.0 44 Test User.0: INITIAL TARGETING SUCCEEDED
16:19:08 4159496mS CMTARGET: 0a8502010000046c 287.1132.0 44 Test User.0: GetNoAnswerTimer:15
16:19:08 4159496mS CMCallEvt: 0000000000000000 0.1133.0 44 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
16:19:08 4159497mS CMCallEvt: 0a8502010000046e 0.1134.0 44 Q931 Trunk:9 CHAN=-1: StateChange: END=T CMCSIdle->CMCSOffering
16:19:08 4159497mS CMLineTx: v=9
CMSetup
Line: type=Q931Line 9 Call: lid=0 id=1134 in=0
Called[08036786268] Type=Unknown (0) Reason=CMDRdirect Calling[] Type=Unknown Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
Timed: 13/07/17 16:19
Locale: eng
16:19:08 4159498mS CD: CALL: 287.1132.0 BState=Idle Cut=0 Music=0.0 Aend="Test User(7040)" (0.0) Bend="Line 9" [Line 9] (0.0) CalledNum=08036786268 () CallingNum=7040 (Test User) Internal=0 Time=3806 AState=Dialling
16:19:08 4159499mS ISDNL3Evt: v=9 stacknum=9 State, new=Initiated, old=NullState id=1134
16:19:08 4159500mS ISDNL3Tx: v=9 peb=9
ISDN Layer3 Pcol=08(Q931) Reflen=2 ref=0012(Remote)
Message Type = Setup
InformationElement = BearerCapability
0000 04 03 80 90 a3 .....
InformationElement = CalledPartyNumber
0000 70 0c 80 30 38 30 33 36 37 38 36 32 36 38 p..08036786268
16:19:08 4159500mS ISDNL2Tx: v=9 peb=9
0000 00 01 00 00 08 02 00 12 05 04 03 80 90 a3 70 0c ..............p.
0010 80 30 38 30 33 36 37 38 36 32 36 38 .08036786268
16:19:08 4159500mS ISDNL1Tx: v=9 peb=9
0000 00 01 00 00 08 02 00 12 05 04 03 80 90 a3 70 0c ..............p.
0010 80 30 38 30 33 36 37 38 36 32 36 38 .08036786268
16:19:08 4159929mS ISDNL1Rx: v=9 peb=9
0000 02 01 7f ...
16:19:08 4159929mS ISDNL2Rx: v=9 peb=9
0000 02 01 7f ...
16:19:08 4159930mS ISDNL2Tx: v=9 peb=9
0000 02 01 73 ..s
16:19:08 4159930mS ISDNL1Tx: v=9 peb=9
0000 02 01 73 ..s
16:19:12 4163104mS H323Evt: Recv: RegistrationRequest 10.133.2.129; Extn(7024), time since last RRQ-KA 55011, Endpoints registered: 31; Endpoints in registration: 0
16:19:13 4164156mS H323Evt: Recv: RegistrationRequest 10.133.2.122; Extn(7017), time since last RRQ-KA 55009, Endpoints registered: 31; Endpoints in registration: 0
16:19:14 4165940mS H323Evt: Recv: RegistrationRequest 10.133.2.103; Extn(7006), time since last RRQ-KA 55013, Endpoints registered: 31; Endpoints in registration: 0
16:19:15 4166194mS H323Evt: Recv: RegistrationRequest 10.133.2.106; Extn(7031), time since last RRQ-KA 55012, Endpoints registered: 31; Endpoints in registration: 0
16:19:15 4166945mS H323Evt: Recv: RegistrationRequest 10.133.2.120; Extn(7008), time since last RRQ-KA 55013, Endpoints registered: 31; Endpoints in registration: 0
16:19:17 4168125mS H323Evt: Recv: RegistrationRequest 10.133.2.128; Extn(7025), time since last RRQ-KA 55011, Endpoints registered: 31; Endpoints in registration: 0
16:19:18 4169902mS H323Evt: Recv: RegistrationRequest 10.133.2.124; Extn(7027), time since last RRQ-KA 55011, Endpoints registered: 31; Endpoints in registration: 0
16:19:18 4169930mS ISDNL1Rx: v=9 peb=9
0000 02 01 7f ...
16:19:18 4169930mS ISDNL2Rx: v=9 peb=9
0000 02 01 7f ...
16:19:18 4169930mS ISDNL2Tx: v=9 peb=9
0000 02 01 73 ..s
16:19:18 4169931mS ISDNL1Tx: v=9 peb=9
0000 02 01 73 ..s
16:19:19 4170845mS H323Evt: v=0 stacknum=18 State, new=NullState, old=NullState id=-1
16:19:19 4170845mS H323Evt: v=0 stacknum=18 State, new=Present, old=NullState id=27
16:19:19 4170848mS CMLineRx: v=18
CMSetup
Line: type=IPLine 18 Call: lid=18 id=27 in=1
Called[7015] Type=Default (100) Reason=CMDRdirect SndComp Calling[7018] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
IE CMIESupplementaryService (3)
Network Facility Extension
sourceEntity: 0
destinationEntity: 0
Interpretation APDU
discardAnyUnrecognisedInvokePdu
CallingName.Invoke.CodePageBmpString
invokeId 15761
user 'Mamman Gur' presentation Allowed
IE CMIEFastStartInfoData (6) 4 item(s)
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=Mamman Gur
IE CMIEFarEndCMCallIdData (182) Far End CM Call: lid=0 (0000) id=14615 (3917) in=0 (0000)
IE CMIEDtmf (209) CMIEDtmf oob 1, txp 101, rxp 101, fmtp = <null>, misc 21 (misc oob 0 misc rfc2833 1 prio oob 1 prio rfc2833 0)
IE CMIECalledPartyName (224)(Type=CMNameDefault) name=Mustafa Sam
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=Mamman Gur
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=7018
IE CMIEDeviceDetail (231) 0a82440300003913 LOCALE=eng HW=15 VER=9 class=CMDeviceH323Phone type=53 number=8267 channel=0 features=0x10000420 rx_gain=32 tx_gain=32 ep_callid=14611 ipaddr=10.130.68.3 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=
0
IE CMIEMohSourceId (247) MOH Source = 255
IE CMIESecurityData (253) 2 item(s)
CMSecurityElement RX_ONLY {
CMSRTPCryptoCapability none
Codecs list (size 2)
}
CMSecurityElement TX_ONLY {
CMSRTPCryptoCapability none
Codecs list (size 2)
}
16:19:19 4170848mS CMCallEvt: 0000000000000000 0.1135.0 -1 BaseEP: NEW CMEndpoint f178dae8 TOTAL NOW=4 CALL_LIST=1
16:19:19 4170849mS CMCallEvt: CREATE CALL:45 (f17abd58)
16:19:19 4170849mS CMCallEvt: 0000000000000000 0.1136.0 -1 BaseEP: NEW CMEndpoint f17aa44c TOTAL NOW=5 CALL_LIST=1
16:19:19 4170851mS CD: CALL: 18.27.1 BState=Idle Cut=1 Music=0.0 Aend="Line 18" (268.1) Bend="" [] (0.0) CalledNum=7015 (Mustafa Sam) CallingNum=7018 (Mamman Gur) Internal=0 Time=2 AState=Idle
16:19:19 4170851mS CMCallEvt: 0a82440300003913 18.27.1 45 H323TrunkEP: StateChange: END=A CMCSIdle->CMCSDialInitiated
16:19:19 4170852mS CMTARGET: 0a82440300003913 18.27.1 45 H323TrunkEP: LOOKUP CALL ROUTE: GID=0 type=100 called_party=7015 sub= calling=7018 calling_sub= dir=out complete=1 ses=0
16:19:19 4170852mS CMTARGET: 0a82440300003913 18.27.1 45 H323TrunkEP: ADD TARGET (N): number=7015 type=100 depth=1 nobar=1 setorig=1 ses=0
16:19:19 4170852mS CMTARGET: 0a82440300003913 18.27.1 45 H323TrunkEP: SET USER: Mustafa Sam orig=1
16:19:19 4170852mS CMTARGET: 0a82440300003913 18.27.1 45 H323TrunkEP: ADD USER: Mustafa Sam depth=1 disallow_cw=0 dnd=0 real_call=1 group_call=0 type(CMNTypeDefault) incl(0x0) excpt(0x0), allow_redir(1) remote=00000000 simult 0 (0)
16:19:19 4170852mS CMCallEvt: 0000000000000000 0.1137.0 -1 BaseEP: NEW CMEndpoint f17a6084 TOTAL NOW=6 CALL_LIST=2
16:19:19 4170853mS CMCallEvt: 0000000000000000 0.1137.0 -1 Mustafa Sam.-1: NEW CMExtnEndpoint f17a6084, Name=Mustafa Sam, Extn=7015, Phys Extn=7015
16:19:19 4170854mS CMTARGET: 0a85020100000471 265.1137.0 45 Mustafa Sam.0: ADD PRIMARY
16:19:19 4170854mS CMTARGET: 0a82440300003913 18.27.1 45 H323TrunkEP: INITIAL TARGETING SUCCEEDED
16:19:19 4170854mS CMTARGET: 0a82440300003913 18.27.1 45 H323TrunkEP: GetNoAnswerTimer:15
16:19:19 4170855mS CMCallEvt: 0a82440300003913 18.27.1 45 H323TrunkEP: StateChange: END=A CMCSDialInitiated->CMCSDialled
16:19:19 4170856mS CMLineTx: v=18
CMProceeding
Line: type=IPLine 18 Call: lid=18 id=27 in=1
IE CMIEDtmf (209) CMIEDtmf oob 1, txp 101, rxp 101, fmtp = <null>, misc 21 (misc oob 0 misc rfc2833 1 prio oob 1 prio rfc2833 0)
16:19:19 4170856mS CMCallEvt: 0000000000000000 0.1136.0 45 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
16:19:19 4170857mS CMCallEvt: 0a85020100000471 265.1137.0 45 Mustafa Sam.0: StateChange: END=T CMCSIdle->CMCSOffering
16:19:19 4170859mS CMExtnEvt: Mustafa Sam: CMExtnHandler::SetCurrent( id: 0->1137 )
16:19:19 4170859mS CMExtnTx: v=7015, p1=0
CMSetup
Line: type=IPLine 250 Call: lid=265 id=1137 in=0
Called[7015] Type=Default (100) Reason=CMDRdirect SndComp Calling[7018] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
IE CMIESupplementaryService (3)
Network Facility Extension
sourceEntity: 0
destinationEntity: 0
Interpretation APDU
discardAnyUnrecognisedInvokePdu
CallingName.Invoke.CodePageBmpString
invokeId 15761
user 'Mamman Gur' presentation Allowed
IE CMIEFastStartInfoData (6) 4 item(s)
IE CMIECallSignalChannelData (8) unknown
IE CMIEMediaWaitForConnect (16) CMIEMediaWaitForConnect
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=Mamman Gur
IE CMIEFarEndCMCallIdData (182) Far End CM Call: lid=0 (0000) id=14615 (3917) in=0 (0000)
IE CMIECalledPartyName (224)(Type=CMNameDefault) name=Mustafa Sam
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=Mamman Gur
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=7018
IE CMIEDeviceDetail (231) 0a82440300003913 LOCALE=eng HW=15 VER=9 class=CMDeviceH323Phone type=53 number=8267 channel=0 features=0x10000420 rx_gain=32 tx_gain=32 ep_callid=14611 ipaddr=10.130.68.3 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=
0
IE CMIEMohSourceId (247) MOH Source = 255
IE CMIESecurityData (253) 2 item(s)
CMSecurityElement TX_ONLY {
CMSRTPCryptoCapability none
Codecs list (size 2)
}
CMSecurityElement RX_ONLY {
CMSRTPCryptoCapability none
Codecs list (size 2)
}
Display [Mamman Gur>Mustafa Sam]
Timed: 13/07/17 16:19
Locale: eng
16:19:19 4170859mS CMExtnRx: v=7015, p1=0
CMAlerting
Line: type=IPLine 250 Call: lid=265 id=1137 in=0
16:19:19 4170859mS CMCallEvt: 0a85020100000471 265.1137.0 45 Mustafa Sam.0: StateChange: END=T CMCSOffering->CMCSRinging
16:19:19 4170859mS CMExtnEvt: v=14 State, new=Ringing old=Idle,0,0,Mustafa Sam
16:19:19 4170860mS CMCallEvt: 0000000000000000 0.1136.0 45 TargetingEP: StateChange: END=B CMCSOffering->CMCSRinging
16:19:19 4170860mS CMCallEvt: 0a82440300003913 18.27.1 45 H323TrunkEP: StateChange: END=A CMCSDialled->CMCSRingBack
16:19:19 4170863mS CMLineTx: v=18
CMAlerting
Line: type=IPLine 18 Call: lid=18 id=27 in=1
IE CMIESupplementaryService (3)
Network Facility Extension
sourceEntity: 0
destinationEntity: 0
Interpretation APDU
discardAnyUnrecognisedInvokePdu
AlertingName.Invoke.CodePageUtf8String
invokeId 14672
user 'Mustafa Sam' presentation Allowed
IE CMIEFastStartInfoData (6) 2 item(s)
IE CMIEDtmf (209) CMIEDtmf oob 1, txp 101, rxp 101, fmtp = <null>, misc 21 (misc oob 0 misc rfc2833 1 prio oob 1 prio rfc2833 0)
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=Mustafa Sam
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=7015
IE CMIEDeviceDetail (231) 0a85020100000471 LOCALE=eng HW=15 VER=9 class=CMDeviceH323Phone type=110 number=8014 channel=0 features=0x10000400 rx_gain=32 tx_gain=32 ep_callid=1137 ipaddr=10.133.2.1 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=0
IE CMIESecurityData (253) 2 item(s)
CMSecurityElement RX_ONLY {
CMSRTPCryptoCapability none
Codecs list (size 3)
}
CMSecurityElement TX_ONLY {
CMSRTPCryptoCapability none
Codecs list (size 3)
}
16:19:19 4170865mS CD: CALL: 18.27.1 BState=Ringing Cut=1 Music=2.0 Aend="Line 18" (268.1) Bend="Mustafa Sam(7015)" [Mustafa Sam(7015)] (0.0) CalledNum=7015 (Mustafa Sam) CallingNum=7018 (Mamman Gur) Internal=0 Time=16 AState=Ringing
16:19:19 4170867mS H323Evt: SESS 3a SetOperational local 10.133.2.1:0 remote 0.0.0.0:0 to 0
16:19:19 4170867mS H323Evt: SESS 3a SetRemUDP 0 -> 49154, remote IP 0.0.0.0 -> 10.130.68.3
16:19:19 4170867mS CMMap: PCG::AddToneGenerator g R1[3] for cp[254]b0r1 append pcp[256]b0r1 (total 1)
16:19:19 4170868mS CMMap: PlatformConnectionAudioSAP::Bind pcp[256]b0r1 to 0.0
16:19:19 4170868mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[256]b0r1 Configure 0.0
16:19:19 4170868mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[256]b0r1 ConnectIndication 0.0
16:19:19 4170868mS CMMap: a=0.0 b=0.0 pcp[254]b0r1 RTPR1
16:19:19 4170868mS H323Evt: SESS 3a SetOperational local 10.133.2.1:49156 remote 10.130.68.3:49154 to 1
16:19:19 4170869mS H323Evt: v=0 stacknum=18 State, new=ICProceeding, old=Present id=27
16:19:19 4170870mS H323Evt: v=0 stacknum=18 State, new=Received, old=ICProceeding id=27
16:19:19 4170930mS ISDNL1Rx: v=9 peb=9
0000 02 01 7f ...
16:19:19 4170930mS ISDNL2Rx: v=9 peb=9
0000 02 01 7f ...
16:19:19 4170931mS ISDNL2Tx: v=9 peb=9
0000 02 01 73 ..s
16:19:19 4170931mS ISDNL1Tx: v=9 peb=9
0000 02 01 73 ..s
16:19:20 4171135mS RES: Thu 13/7/2017 16:19:20 FreeMem=50807540 Heap=50527992(0) Cache=279548 MemObjs=14016(14631) CMMsg=5(7) ASN=0 Buff=5200 1355 1000 7404 5 Links=57072(57400) BTree=1282(3213) CPU=03.07% CPUStats=05.86%/18/32/2924/13864/14830/00.27%
/0/02.90% MCR=0 MCW=0
16:19:20 4171136mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=59 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=131 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=0 TCP=85(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
16:19:20 4171136mS RES4: XML MemObjs=63 PoolMem=4748404(2) FreePoolMem=4733100(0)
16:19:20 4171136mS RES5: CLog MemObjs=514 FreePoolMem(Objs)=4472(86) TotalMem=165250
16:19:20 4171837mS H323Evt: Recv: RegistrationRequest 10.133.2.109; Extn(7013), time since last RRQ-KA 55012, Endpoints registered: 31; Endpoints in registration: 0
16:19:20 4171857mS H323Evt: SESS 3a: RTP(50t): 10.133.2.1/49156 10.130.68.3/49154 CODEC=G729A8K(6) PKTSZ=20 RFC2833=off AGE=990 SENT=50 (avg size=24) RECV=36 (avg size=20)
16:19:20 4171930mS ISDNL1Rx: v=9 peb=9
0000 02 01 7f ...
16:19:20 4171930mS ISDNL2Rx: v=9 peb=9
0000 02 01 7f ...
16:19:20 4171931mS ISDNL2Tx: v=9 peb=9
0000 02 01 73 ..s
16:19:20 4171931mS ISDNL1Tx: v=9 peb=9
0000 02 01 73 ..s
16:19:21 4172464mS H323Evt: Recv: RegistrationRequest 10.133.2.127; Extn(7001), time since last RRQ-KA 55012, Endpoints registered: 31; Endpoints in registration: 0
16:19:21 4172930mS ISDNL1Rx: v=9 peb=9
0000 02 01 7f ...
16:19:21 4172930mS ISDNL2Rx: v=9 peb=9
0000 02 01 7f ...
16:19:21 4172931mS ISDNL2Tx: v=9 peb=9
0000 02 01 73 ..s
16:19:21 4172931mS ISDNL1Tx: v=9 peb=9
0000 02 01 73 ..s
16:19:22 4173486mS H323Evt: Recv: RegistrationRequest 10.133.2.125; Extn(7004), time since last RRQ-KA 55013, Endpoints registered: 31; Endpoints in registration: 0
16:19:22 4173801mS H323Evt: Recv: RegistrationRequest 10.133.2.102; Extn(7033), time since last RRQ-KA 55011, Endpoints registered: 31; Endpoints in registration: 0
16:19:22 4173826mS H323Evt: Recv: RegistrationRequest 10.133.2.126; Extn(7023), time since last RRQ-KA 55011, Endpoints registered: 31; Endpoints in registration: 0
16:19:23 4174496mS CMTARGET: 0a8502010000046c 287.1132.0 44 Test User.0: TimerExpired cause=CMTCNoAnswerTimeout
16:19:23 4174496mS CMTARGET: 0a8502010000046c 287.1132.0 44 Test User.0: Retarget NOANSWER EXCEPTED=00000000 INCLUDED=00000000 ValidTargets=0
16:19:23 4174496mS CMTARGET: 0a8502010000046c 287.1132.0 44 Test User.0: Retarget NOANSWER delete call cause CMCauseCallRejected aend state CMCSDialling
16:19:23 4174497mS CMLOGGING: CALL:2017/07/1316:19,00:00:00,000,7040,O,08036786268,08036786268,TestUser,,,0,,"",0,n/a
16:19:23 4174497mS CD: CALL: 287.1132.0 BState=Idle Cut=0 Music=0.0 Aend="Test User(7040)" (0.0) Bend="Line 9" [Line 9] (0.0) CalledNum=08036786268 () CallingNum=7040 (Test User) Internal=0 Time=18805 AState=Dialling
16:19:23 4174497mS CD: CALL: 287.1132.0 Deleted
16:19:23 4174497mS CMExtnEvt: Test User: CALL LOST (CMCauseCallRejected)
16:19:23 4174497mS CMExtnEvt: Test User: Extn(7040) Calling Party Number(7040) Type(CMNTypeInternal)
16:19:23 4174498mS CMCallEvt: 0a8502010000046c 287.1132.0 -1 Test User.0: StateChange: END=X CMCSDialling->CMCSCompletedTone
16:19:23 4174498mS CMMap: IP::SetCodec pcp[253]b0r1 0 -> f5380e5c
16:19:23 4174498mS CMExtnEvt: v=33 State, new=CMESCompleted old=Dialling,0,0,Test User
16:19:23 4174499mS CMCallEvt: 0000000000000000 0.1133.0 -1 BaseEP: DELETE CMEndpoint f17d4754 TOTAL NOW=5 CALL_LIST=1
16:19:23 4174500mS CMLineTx: v=9
CMDisconnect
Line: type=Q931Line 9 Call: lid=0 id=1134 in=0
Cause=21, Call rejected
16:19:23 4174500mS CMCallEvt: 0a8502010000046e 0.1134.0 -1 Q931 Trunk:9 CHAN=-1: StateChange: END=X CMCSOffering->CMCSCompleted
16:19:23 4174500mS CMCallEvt: END CALL:44 (f179c058)
16:19:23 4174501mS ISDNL3Evt: v=9 stacknum=9 State, new=DiscReq, old=Initiated id=1134
16:19:23 4174501mS ISDNL3Tx: v=9 peb=9
ISDN Layer3 Pcol=08(Q931) Reflen=2 ref=0012(Remote)
Message Type = Disconnect
InformationElement = CAUSE
0000 08 02 80 95 ....
16:19:23 4174501mS ISDNL2Tx: v=9 peb=9
0000 00 01 00 00 08 02 00 12 45 08 02 80 95 ........E....
16:19:23 4174502mS ISDNL1Tx: v=9 peb=9
0000 00 01 00 00 08 02 00 12 45 08 02 80 95 ........E....
16:19:23 4174503mS CMMap: PCG::AddToneGenerator g E1[7] for cp[253]b0r1 append pcp[257]b0r1 (total 1)
16:19:23 4174503mS CMMap: PlatformConnectionAudioSAP::Bind pcp[257]b0r1 to 0.0
16:19:23 4174503mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[257]b0r1 Configure 0.0
16:19:23 4174503mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[257]b0r1 ConnectIndication 0.0
16:19:23 4174503mS CMMap: a=0.0 b=0.0 pcp[253]b0r1 RTPE1
16:19:23 4174503mS H323Evt: SESS 39 SetOperational local 10.133.2.1:49152 remote 10.130.64.184:51694 to 1
16:19:23 4174523mS H323Evt: Recv: RegistrationRequest 10.133.3.193; Extn(7010), time since last RRQ-KA 55014, Endpoints registered: 31; Endpoints in registration: 0
16:19:24 4175547mS H323Evt: SESS 39: RTP(50r): 10.133.2.1/49152 10.130.64.184/51694 CODEC=Alaw64K(4) PKTSZ=160 RFC2833=off AGE=19842 SENT=52 (avg size=164) RECV=50 (avg size=160)
16:19:24 4175651mS ISDNL2Tx: v=9 peb=9
0000 00 01 01 01 ....
16:19:24 4175652mS ISDNL1Tx: v=9 peb=9
0000 00 01 01 01 ....
16:19:25 4176117mS H323Evt: Recv: RegistrationRequest 10.133.3.125; Extn(9002), time since last RRQ-KA 55014, Endpoints registered: 31; Endpoints in registration: 0
16:19:25 4176801mS ISDNL2Tx: v=9 peb=9
0000 00 01 01 01 ....
16:19:25 4176801mS ISDNL1Tx: v=9 peb=9
0000 00 01 01 01 ....
16:19:26 4177951mS ISDNL2Tx: v=9 peb=9
0000 00 01 01 01 ....
16:19:26 4177951mS ISDNL1Tx: v=9 peb=9
0000 00 01 01 01 ....
16:19:27 4178637mS RES: Thu 13/7/2017 16:19:27 FreeMem=50819920 Heap=50527992(0) Cache=291928 MemObjs=13991(14631) CMMsg=5(7) ASN=0 Buff=5200 1355 1000 7404 5 Links=57078(57400) BTree=1280(3213) CPU=03.57% CPUStats=04.09%/1/4/2924/14055/14830/00.61%/0
/02.99% MCR=0 MCW=0
16:19:27 4178637mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=59 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=130 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=0 TCP=85(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
16:19:27 4178637mS RES4: XML MemObjs=63 PoolMem=4748404(2) FreePoolMem=4733100(0)
16:19:27 4178637mS RES5: CLog MemObjs=514 FreePoolMem(Objs)=4472(86) TotalMem=165250
16:19:27 4178822mS H323Evt: Recv: RegistrationRequest 10.133.2.104; Extn(7019), time since last RRQ-KA 55010, Endpoints registered: 31; Endpoints in registration: 0
16:19:27 4178834mS H323Evt: Recv: RegistrationRequest 10.133.2.111; Extn(7012), time since last RRQ-KA 55011, Endpoints registered: 31; Endpoints in registration: 0
16:19:28 4179101mS ISDNL2Tx: v=9 peb=9
0000 00 01 7f ...
16:19:28 4179101mS ISDNL3Evt: v=9 p1=9,p2=1001,p3=5,p4=0,s1=
16:19:28 4179101mS ISDNL3Evt: v=9 stacknum=9 State, new=NullState, old=DiscReq id=1134
16:19:28 4179102mS ISDNL1Tx: v=9 peb=9
0000 00 01 7f ...
16:19:28 4179102mS CMLineRx: v=9
CMReleaseComp
Line: type=Q931Line 9 Call: lid=0 id=1134 in=0
Cause=38, Network out of order
16:19:28 4179103mS CMCallEvt: 0a8502010000046e 0.1134.0 -1 Q931 Trunk:9 CHAN=-1: StateChange: END=X CMCSCompleted->CMCSDelete
16:19:28 4179103mS CMCallEvt: 0a8502010000046e 0.1134.0 -1 BaseEP: DELETE CMEndpoint f17c4edc TOTAL NOW=4 CALL_LIST=1

RE: Issues with PRI Line

Do you have a problem with VoIP?

RE: Issues with PRI Line

Cause No. 38 - network out of order.
This cause indicates that the network is not functioning correctly and that the condition is likely to last a relatively long period of time e.g., immediately re-attempting the call is not likely to be successful.

RE: Issues with PRI Line

(OP)
Yes this issue is happening on the PRI trunk . We have voip trunk which is working fine .

RE: Issues with PRI Line

Then next time you post a trace enable only the parts which are involved, now the H.323 stuff makes it almost unreadable.
I have noticed the casue 38 errors and was hoping you would discover that yourself as it is a easy thing to find and then use google to determine what a cause 38 error means.
That is what a good engineer would do (at least that is what I expect from a good engineer).

RE: Issues with PRI Line

Is it just me who struggles to read monitor traces in anything but monitor or notepad :)

| ACSS SME |

RE: Issues with PRI Line

If someone posts a multiple page monitor trace I usually won't bother reading it, there is a attachment feature for a reason.

"Trying is the first step to failure..." - Homer

RE: Issues with PRI Line

Hate to say but I also ignore stuff that is longer than the page can handle because I get confused
Smartedge
Not to be not helpful but it is really hard to get any useful information or of a trace posted like this.

If you get network not available as error I bet you have a PRI that runs via VoIP in the background and the provider has issues.

Joe W.

FHandw, ACSS (SME)


"This is the end of the world, make sure to buy your T-shirt before it is too late"
Original expression of my daughter

RE: Issues with PRI Line

I have to agree
if the monitor trace is this long then it is obvious the OP has either not bothered or been unable to trim it to the relevant details.
this invariably means the OP has not correctly set the filters & probably has not captured anything useful anyway.

I would also agree with westi, the issue is almost certainly with the line provider not the IP Office




Do things on the cheap & it will cost you dear

Red Flag This Post

Please let us know here why this post is inappropriate. Reasons such as off-topic, duplicates, flames, illegal, vulgar, or students posting their homework.

Red Flag Submitted

Thank you for helping keep Tek-Tips Forums free from inappropriate posts.
The Tek-Tips staff will check this out and take appropriate action.

Reply To This Thread

Posting in the Tek-Tips forums is a member-only feature.

Click Here to join Tek-Tips and talk with other members!

Resources

Close Box

Join Tek-Tips® Today!

Join your peers on the Internet's largest technical computer professional community.
It's easy to join and it's free.

Here's Why Members Love Tek-Tips Forums:

Register now while it's still free!

Already a member? Close this window and log in.

Join Us             Close