SupportDude
Technical User
This call originates from the Polycom 6000 (3rd Party SIP) conference phone.
Telco prompts for LD Code input.
If calling from a 9650 set, you get about 5 seconds of silence, then a tone, then a recording instructing you to input your authorization code.
If calling from the Polycom, you hear about 4.5 rings, and then it goes to fast busy (reorder). The is never a prompt for the authorization code.
Anybody else ever run into this???
2017-06-19T06:50:36 836468390mS PRN: Monitor Status IP 500 V2 9.1.9.0 build 182
2017-06-19T06:50:36 836468390mS PRN: LAW=U PRI=1, BRI=0, ALOG=4, VCOMP=32, MDM=0, WAN=0, MODU=0 LANM=0 CkSRC=13 VMAIL=1(VER=3 TYP=1) 1-X=0 CALLS=0(TOT=1028)
2017-06-19T06:50:58 836490031mS SIP Rx: UDP 10.10.0.13:5060 -> 10.10.0.5:5060
INVITE sip:914086380968@10.10.0.5:5060;user=phone SIP/2.0
Via: SIP/2.0/UDP 10.10.0.13;branch=z9hG4bKb065e2652E6E34AC
From: "Polycom" <sip:259@10.10.0.5>;tag=8074248-E2D526CF
To: <sip:914086380968@10.10.0.5;user=phone>
CSeq: 1 INVITE
Call-ID: 1a7c433-eb6680fa-48725b01@10.10.0.13
Contact: <sip:259@10.10.0.13>
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
User-Agent: PolycomSoundStationIP-SPIP_6000-UA/3.0.4.0061
Supported: 100rel,replaces
Allow-Events: talk,hold,conference
Max-Forwards: 70
Content-Type: application/sdp
Content-Length: 445
v=0
o=- 1497807780 1497807780 IN IP4 10.10.0.13
s=Polycom IP Phone
c=IN IP4 10.10.0.13
t=0 0
m=audio 2226 RTP/AVP 115 99 9 102 0 8 18 101
a=sendrecv
a=rtpmap:115 G7221/32000
a=fmtp:115 annexb=no
a=rtpmap:99 SIREN14/16000
a=fmtp:99 annexb=no
a=rtpmap:9 G722/8000
a=rtpmap:102 G7221/16000
a=fmtp:102 annexb=no
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
2017-06-19T06:50:58 836490035mS CMCallEvt: 0000000000000000 0.5080.0 -1 BaseEP: NEW CMEndpoint f1708a50 TOTAL NOW=1 CALL_LIST=0
2017-06-19T06:50:58 836490035mS CMCallEvt: 0000000000000000 0.5080.0 -1 polycomUpstairs.-1: NEW CMExtnEndpoint f1708a50, Name=polycomUpstairs, Extn=259, Phys Extn=259
2017-06-19T06:50:58 836490036mS CMCallEvt: CREATE CALL:1029 (f172c2dc)
2017-06-19T06:50:58 836490036mS CMCallEvt: 0000000000000000 0.5081.0 -1 BaseEP: NEW CMEndpoint f172a984 TOTAL NOW=2 CALL_LIST=0
2017-06-19T06:50:58 836490038mS CMExtnEvt: polycomUpstairs: CMExtnHandler::SetCurrent( id: 0->5080 )
2017-06-19T06:50:58 836490038mS Sip: SIPDialog f4eda800 created, dialogs 1 txn_keys 1
2017-06-19T06:50:58 836490039mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) Cloned
2017-06-19T06:50:58 836490040mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) SendSIPResponse: INVITE code 100 SENT TO 10.10.0.13 5060
2017-06-19T06:50:58 836490040mS SIP Tx: UDP 10.10.0.5:5060 -> 10.10.0.13:5060
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 10.10.0.13;branch=z9hG4bKb065e2652E6E34AC
From: "Polycom" <sip:259@10.10.0.5>;tag=8074248-E2D526CF
Call-ID: 1a7c433-eb6680fa-48725b01@10.10.0.13
CSeq: 1 INVITE
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,REFER,NOTIFY,SUBSCRIBE,REGISTER,PUBLISH,UPDATE
Supported: timer,100rel
Server: IP Office 9.1.9.0 build 182
To: <sip:914086380968@10.10.0.5;user=phone>;tag=2e0eb0d83b0bd7e9
Content-Length: 0
2017-06-19T06:50:58 836490040mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) INVITE Received ep 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f1708a50), dialog f4eda800
2017-06-19T06:50:58 836490041mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) UpdateSIPCallState SIPDialog::INITIAL(0) -> SIPDialog::INVITE_RCVD(9)
2017-06-19T06:50:58 836490041mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) UpdateSDPState SIPDialog::IDLE(0) -> SIPDialog::OFFER_RCVD(2)
2017-06-19T06:50:58 836490041mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) SdpClone
2017-06-19T06:50:58 836490041mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) SIPDialog::BuildFastStartFromSDPOffer sdpmsg f190238c
2017-06-19T06:50:58 836490042mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) SIPDialog::FindConnectionParameters: found media proto <RTP/AVP>
2017-06-19T06:50:58 836490042mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) SetRfc2833TxPayload: use RFC2833 for dtmf
2017-06-19T06:50:58 836490042mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) SetRfc2833TxPayload: payload 101 set_rx 1
2017-06-19T06:50:58 836490042mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) SIPDialog::BuildFastStartFromAudioMediaSDPOffer reinvite 0 msg f1724250 fs in msg 1 mRTP_PType 255
2017-06-19T06:50:58 836490042mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) SetRemoteRTPAddress to 10.10.0.13:2226
2017-06-19T06:50:58 836490043mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) Process SIP request dialog f4eda800, method INVITE in state SIPDialog::INVITE_RCVD(9)
2017-06-19T06:50:58 836490044mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) UpdateClone mMesg f161b19c smsg f1618e24
2017-06-19T06:50:58 836490045mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) CMSetup forwarded to call model owner_ep 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f1708a50), dialog f4eda800 has sdp 1
2017-06-19T06:50:58 836490045mS CMExtnRx: v=259, p1=0
CMSetup
Line: type=SIPLine 260 Call: lid=251 id=5080 in=0
Called[914086380968] Type=Default (100) Reason=CMDRdirect SndComp Calling[259] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
IE CMIEFastStartInfoData (6) 6 item(s)
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=polycomUpstairs
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=259
2017-06-19T06:50:58 836490045mS CMCallEvt: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0: StateChange: END=A CMCSIdle->CMCSDialInitiated
2017-06-19T06:50:58 836490045mS CMExtnEvt: v=0 State, new=Dialling old=Idle,0,0,polycomUpstairs
2017-06-19T06:50:58 836490046mS CMTARGET: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=914086380968 sub= calling=259 calling_sub= dir=out complete=1 ses=0
2017-06-19T06:50:58 836490046mS CMTARGET: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0: ADD TARGET (N): number=914086380968 type=100 depth=1 nobar=1 setorig=1 ses=0
2017-06-19T06:50:58 836490046mS CMTARGET: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0: SYS SC: 914086380968 2 14086380968 sc=type=Dial3K1 code=9N, num=N callinfop->sending_complete=1 secondary_dialtone=
2017-06-19T06:50:58 836490046mS CMARS: FindActiveARSByGroupID GroupID=50 - Found
2017-06-19T06:50:58 836490047mS CMARS: MakeCallTarget - Called Number: 14086380968
2017-06-19T06:50:58 836490047mS CMCallEvt: 0000000000000000 0.5082.0 -1 BaseEP: NEW CMEndpoint f170e004 TOTAL NOW=3 CALL_LIST=1
2017-06-19T06:50:58 836490047mS CMTARGET: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0: INITIAL TARGETING SUCCEEDED
2017-06-19T06:50:58 836490047mS CMTARGET: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0: GetNoAnswerTimer:15
2017-06-19T06:50:58 836490048mS CMCallEvt: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0: StateChange: END=A CMCSDialInitiated->CMCSDialled
2017-06-19T06:50:58 836490048mS CMExtnEvt: v=0 State, new=Proceeding old=Dialling,0,0,polycomUpstairs
2017-06-19T06:50:58 836490049mS CMExtnTx: v=259, p1=0
CMProceeding
Line: type=SIPLine 260 Call: lid=251 id=5080 in=0
Timed: 19/06/17 06:50
2017-06-19T06:50:58 836490050mS CMCallEvt: 0000000000000000 0.5081.0 1029 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
2017-06-19T06:50:58 836490050mS CMCallEvt: 0000000000000000 0.5082.0 1029 ARS for Main: StateChange: END=T CMCSIdle->CMCSOffering
2017-06-19T06:50:58 836490051mS CMCallEvt: 0000000000000000 0.5081.0 1029 TargetingEP: RequestEnd 0000000000000000 0.5082.0 1029 ARS for Main
2017-06-19T06:50:58 836490051mS CMTARGET: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0: CancelTimer CMTCNoAnswerTimeout
2017-06-19T06:50:58 836490052mS CMCallEvt: 0000000000000000 0.5082.0 1029 ARS for Main: StateChange: END=B CMCSOffering->CMCSOverlapRecv
2017-06-19T06:50:58 836490052mS CMARS: FORM: Main - Received Number: 14086380968
2017-06-19T06:50:58 836490052mS CMARS: FOUND A SHORT CODE - short_code: N; - Tel: Nsi9075866806 - Called_Party: 14086380968 - Line Group Id: 1
2017-06-19T06:50:58 836490052mS CMARS: SetCurrentTarget: Short_Code: N; - Line_Group_ID: 1
2017-06-19T06:50:58 836490052mS CMARS: FindActiveARSByGroupID GroupID=1 - Not Found
2017-06-19T06:50:58 836490052mS CMLRQ: FindActiveLRQByGroupID GroupID=1 - Not Found
2017-06-19T06:50:58 836490053mS CMMap: a=6.1 b=0.0 Mapper::AllocateCodec allocated CMRTVocoder(f564e0b4) resource busy 1, total 32
2017-06-19T06:50:58 836490053mS CMCallEvt: 0000000000000000 0.5083.0 -1 BaseEP: NEW CMEndpoint f1611d5c TOTAL NOW=4 CALL_LIST=1
2017-06-19T06:50:58 836490053mS CMTARGET: ISDN BChannel 10: in-service check = 1
2017-06-19T06:50:58 836490054mS CMTARGET: ISDN BChannel 10: in-service check = 1
2017-06-19T06:50:58 836490054mS CMARS: ModifyCMARSTarget: Short_Code: N; - Line_Group_ID: 1 set line status to CMARS_TRYING
2017-06-19T06:50:58 836490055mS CMARS: FOUND LINE - Line Id: 13 - using line group id: 1 (code N;, line 1) - Called Number: 14086380968 - Calling Number: 9075866806
2017-06-19T06:50:58 836490055mS CMARS: SEND Setup TO LINE
2017-06-19T06:50:58 836490055mS CMCallEvt: 0a0a0005000013db 0.5083.0 1029 Q931 Trunk:13 CHAN=10: StateChange: END=child CMCSIdle->CMCSOffering
2017-06-19T06:50:58 836490055mS PRN: Setting configured voice gain for ch 10.
2017-06-19T06:50:58 836490055mS CMLineTx: v=13
CMSetup
Line: type=Q931Line 13 Call: lid=0 id=5083 in=0
Called[14086380968] Type=National (2) Reason=CMDRdirect Calling[9075866806] Type=National Plan=ISDN
BC: CMTC=3K1Audio CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
BChan: slot=0 chan=10
Locale: enu
2017-06-19T06:50:58 836490056mS CMCallEvt: 0000000000000000 0.5081.0 -1 TargetingEP: StateChange: END=X CMCSOffering->CMCSDelete
2017-06-19T06:50:58 836490056mS CMCallEvt: 0000000000000000 0.5081.0 -1 BaseEP: DELETE CMEndpoint f172a984 TOTAL NOW=3 CALL_LIST=1
2017-06-19T06:50:58 836490057mS ISDNL3Evt: v=13 stacknum=13 State, new=Initiated, old=NullState id=5083
2017-06-19T06:50:58 836490058mS ISDNL3Tx: v=13 peb=13
ISDN Layer3 Pcol=08(Q931) Reflen=2 ref=002F(Remote)
Message Type = Setup
InformationElement = BearerCapability
0000 04 03 90 90 a2 .....
InformationElement = CHI
0000 18 03 a9 83 8a .....
InformationElement = CallingPartyNumber
0000 6c 0c 21 80 39 30 37 35 38 36 36 38 30 36 l.!.9075866806
InformationElement = CalledPartyNumber
0000 70 0c a0 31 34 30 38 36 33 38 30 39 36 38 p..14086380968
2017-06-19T06:50:58 836490063mS CD: CALL: 251.5080.0 BState=Idle Cut=3 Music=0.0 Aend="polycomUpstairs(259)" (0.0) Bend="" [Line 13] (0.0) CalledNum=914086380968 () CallingNum=259 (polycomUpstairs) Internal=1 Time=27 AState=Dialled
2017-06-19T06:50:58 836490093mS RES: Mon 19/6/2017 06:50:58 FreeMem=54185012 Heap=52960576(0) Cache=1224436 MemObjs=14763(17658) CMMsg=7(8) ASN=0 Buff=5200 1371 990 7404 5 Links=58998(60700) BTree=1208(2302) CPU=07.65% CPUStats=09.63%/25/31/145/18505/227
98/00.04%/0/02.71% MCR=0 MCW=0
2017-06-19T06:50:58 836490093mS RES2: IP 500 V2 9.1.9.0 build 182 Tasks=50 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=142 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=0 TCP=100(TLS=7) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
2017-06-19T06:50:58 836490093mS RES4: XML MemObjs=63 PoolMem=4748404(2) FreePoolMem=4733100(0)
2017-06-19T06:50:58 836490094mS RES5: CLog MemObjs=1563 FreePoolMem(Objs)=1924(37) TotalMem=252600
2017-06-19T06:50:58 836490099mS ISDNL3Rx: v=13 peb=13
ISDN Layer3 Pcol=08(Q931) Reflen=2 ref=002F(Local)
Message Type = CallProceeding
InformationElement = CHI
0000 18 03 a9 83 8a .....
2017-06-19T06:50:58 836490100mS ISDNL3Evt: v=13 stacknum=13 State, new=Proceeding, old=Initiated id=5083
2017-06-19T06:50:58 836490100mS CMLineRx: v=13
CMProceeding
Line: type=Q931Line 13 Call: lid=0 id=5083 in=0
BChan: slot=0 chan=10
2017-06-19T06:50:58 836490100mS CMARS: LINE ep Received: CMProceeding - child->state = CMCSOffering - ARS Call State = CMCSOverlapRecv
2017-06-19T06:50:58 836490100mS CMARS: LINE IS NOW THE B END OF THE CALL - CMARSEndpoint::RequestEnd()
2017-06-19T06:50:58 836490101mS CMARS: CMARSEndpoint::CallLost(cause=124) - Address: 0a0a0005000013d8 0.5082.0 1029 ARS for Main - Call State: CMCSOverlapRecv
2017-06-19T06:50:58 836490101mS CMCallEvt: 0a0a0005000013d8 0.5082.0 -1 ARS for Main: StateChange: END=X CMCSOverlapRecv->CMCSDelete
2017-06-19T06:50:58 836490102mS CMCallEvt: 0a0a0005000013db 0.5083.0 1029 Q931 Trunk:13 CHAN=10: StateChange: END=B CMCSOffering->CMCSAccept
2017-06-19T06:50:58 836490102mS CMCallEvt: 0a0a0005000013d8 0.5082.0 -1 BaseEP: DELETE CMEndpoint f170e004 TOTAL NOW=2 CALL_LIST=1
2017-06-19T06:50:58 836490102mS CD: CALL: 251.5080.0 BState=Ringing Cut=3 Music=0.0 Aend="polycomUpstairs(259)" (0.0) Bend="Line 13" [Line 13] (7.11) CalledNum=14086380968 () CallingNum=259 (polycomUpstairs) Internal=0 Time=66 AState=Dialled
2017-06-19T06:50:58 836490470mS ISDNL3Rx: v=13 peb=13
ISDN Layer3 Pcol=08(Q931) Reflen=2 ref=002F(Local)
Message Type = Progress
InformationElement = PI
0000 1e 02 80 81 ....
2017-06-19T06:50:58 836490471mS CMLineRx: v=13
CMProgress
Line: type=Q931Line 13 Call: lid=0 id=5083 in=0
IE CMIEProgressIndicator (30) cs=CMCSITUT (0), loc=CMLUser (0), pd=CMPDNotISDN (1)
2017-06-19T06:50:58 836490472mS CMCallEvt: 0a0a0005000013db 0.5083.0 1029 Q931 Trunk:13 CHAN=10: StateChange: END=B CMCSAccept->CMCSRinging
2017-06-19T06:50:58 836490472mS CMCallEvt: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0: StateChange: END=A CMCSDialled->CMCSRingBack
2017-06-19T06:50:58 836490474mS CMMap: IP::SetCodec pcp[840]b0r0 0 -> f564e0b4
2017-06-19T06:50:58 836490474mS CMExtnTx: v=259, p1=0
CMFacility
Line: type=SIPLine 260 Call: lid=251 id=5080 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
IE CMIESecurityData (253) 2 item(s)
CMSecurityElement RX_ONLY {
CMSRTPCryptoCapability none
Codecs list (size 7)
}
CMSecurityElement TX_ONLY {
CMSRTPCryptoCapability none
Codecs list (size 7)
}
Timed: 19/06/17 06:50
2017-06-19T06:50:58 836490475mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) SIPDialog cannot reshuffle in SIPDialog::INVITE_RCVD, CMFacilityInterval 0, PendingUpdateResp 0, has_fs 1, has_video 0, hold_ch, 0 name_ch 0 media_ch 0 empt
y_reinvite 0 UnInt UnInt_None
2017-06-19T06:50:58 836490475mS CMExtnEvt: v=0 State, new=Alerting old=Proceeding,0,0,polycomUpstairs
2017-06-19T06:50:58 836490477mS CMExtnTx: v=259, p1=0
CMProgress
Line: type=SIPLine 260 Call: lid=251 id=5080 in=0
IE CMIEProgressIndicator (30) cs=CMCSITUT (0), loc=CMLUser (0), pd=CMPDNotISDN (1)
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=914086380968
IE CMIEDeviceDetail (231) 0a0a0005000013db LOCALE=enu HW=15 VER=9 class=CMDeviceISDNTrunk type=2 number=13 channel=10 features=0x0 rx_gain=32 tx_gain=32 ep_callid=5083 ipaddr=10.10.0.5 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=1
Timed: 19/06/17 06:50
2017-06-19T06:50:58 836490477mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) UpdateSIPCallState SIPDialog::INVITE_RCVD(9) -> SIPDialog::INV_PROV_RESP_SENT(11)
2017-06-19T06:50:58 836490477mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) SIPEndPoint: Received an CMProgress State Transition to SIPDialog::INV_PROV_RESP_SENT(11)
2017-06-19T06:50:58 836490478mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) InsertCallerIdHeader caller ID method <CallerIDPAID> added_pai <F>
2017-06-19T06:50:58 836490478mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) InsertPAID number <914086380968> and name <> and restricted <F>
2017-06-19T06:50:58 836490478mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) SendSIPResponse: INVITE code 180 SENT TO 10.10.0.13 5060
2017-06-19T06:50:58 836490479mS SIP Tx: UDP 10.10.0.5:5060 -> 10.10.0.13:5060
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 10.10.0.13;branch=z9hG4bKb065e2652E6E34AC
From: "Polycom" <sip:259@10.10.0.5>;tag=8074248-E2D526CF
Call-ID: 1a7c433-eb6680fa-48725b01@10.10.0.13
CSeq: 1 INVITE
Contact: <sip:914086380968@10.10.0.5:5060;transport=udp>
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,REFER,NOTIFY,SUBSCRIBE,REGISTER,PUBLISH,UPDATE
P-Asserted-Identity: <sip:914086380968@10.10.0.5:5060>
Supported: timer,100rel
Server: IP Office 9.1.9.0 build 182
To: <sip:914086380968@10.10.0.5;user=phone>;tag=2e0eb0d83b0bd7e9
Content-Length: 0
2017-06-19T06:50:58 836490480mS CD: CALL: 251.5080.0 BState=Ringing Cut=3 Music=0.0 Aend="polycomUpstairs(259)" (0.0) Bend="Line 13" [Line 13] (7.11) CalledNum=14086380968 () CallingNum=259 (polycomUpstairs) Internal=0 Time=443 AState=Ringing
2017-06-19T06:50:58 836490481mS CMMap: PCG::MapBChan pcp[840]b0r1 cp_b 0 other_cp_b 0 type CGTypeSimple
2017-06-19T06:50:58 836490481mS CMMap: PCGS CPReserveCodec for the other end (pcp[840]b0r1) true
2017-06-19T06:50:58 836490481mS CMMap: PCG::MapBChan pcp[103]b1r0 cp_b f55ab3e0 other_cp_b f55ffa70 type CGTypeSimple
2017-06-19T06:50:58 836490481mS CMMap: a=6.1 b=7.11 M12
2017-06-19T06:50:58 836490481mS CMMap: PlatformConnectionAudioSAP::Bind pcp[840]b0r1 to 6.1
2017-06-19T06:50:58 836490481mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[840]b0r1 Configure 6.1
2017-06-19T06:50:58 836490482mS CMMap: PlatformConnectionAudioSAP::ConnectVoice rtpRelay Open got rtpRelay ID: 1
2017-06-19T06:50:58 836490482mS CMMap: PlatformConnectionAudioSAP::ConnectVoice rtpRelay Configure success
2017-06-19T06:50:58 836490482mS CMMap: PlatformConnectionAudioSAP::ConnectVoice local IP addr 10.10.0.5:49152, Remote IP addr 10.10.0.13:2226
2017-06-19T06:50:58 836490482mS CMMap: PlatformConnectionAudioSAP::ConnectVoice DSP IP addr 1.1.1.3:32768, telogyHost IP addr 1.1.1.1:10
2017-06-19T06:50:58 836490482mS CMMap: PlatformConnectionAudioSAP::ConnectVoice rtpRelay Start success
2017-06-19T06:50:58 836490482mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[840]b0r1 ConnectIndication 6.1
2017-06-19T06:51:01 836493081mS SIP Rx: UDP 10.10.0.13:5060 -> 10.10.0.5:5060
REGISTER sip:10.10.0.5:5060 SIP/2.0
Via: SIP/2.0/UDP 10.10.0.13;branch=z9hG4bKc61fa79d9E4023E4
From: "Polycom" <sip:259@10.10.0.5>;tag=8E57AE4F-570C2016
To: <sip:259@10.10.0.5>
CSeq: 2069 REGISTER
Call-ID: f39c287a-5f89a281-323829c8@10.10.0.13
Contact: <sip:259@10.10.0.13>;methods="INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER"
User-Agent: PolycomSoundStationIP-SPIP_6000-UA/3.0.4.0061
Authorization: Digest username="polycomUpstairs", realm="ipoffice", nonce="d699125f8675a7870dc3", uri="sip:10.10.0.5:5060", response="40c70f9bcc9b983098e4758eff497c8c", algorithm=MD5
Max-Forwards: 70
Expires: 3600
Content-Length: 0
2017-06-19T06:51:01 836493084mS Sip: SIPDialog f17407bc created, dialogs 2 txn_keys 2
2017-06-19T06:51:01 836493085mS Sip: (f17407bc) SendSIPResponse: REGISTER code 200 SENT TO 10.10.0.13 5060
2017-06-19T06:51:01 836493086mS SIP Tx: UDP 10.10.0.5:5060 -> 10.10.0.13:5060
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.10.0.13;branch=z9hG4bKc61fa79d9E4023E4
From: "Polycom" <sip:259@10.10.0.5>;tag=8E57AE4F-570C2016
Call-ID: f39c287a-5f89a281-323829c8@10.10.0.13
CSeq: 2069 REGISTER
User-Agent: IP Office 9.1.9.0 build 182
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,REFER,NOTIFY,INFO,SUBSCRIBE,REGISTER,PUBLISH
Contact: <sip:259@10.10.0.13>
Date: Mon, 19 Jun 2017 14:51:01 GMT
Expires: 180
Supported: timer
Server: IP Office 9.1.9.0 build 182
To: <sip:259@10.10.0.5>;tag=1bc2b9f4e0caf00c
Content-Length: 0
2017-06-19T06:51:01 836493086mS Sip: SIP REG: Phone(259)(ip=10.10.0.13) is on PRIVATE network (has NO corporate NAT and phone NOT behind its own NAT. URI_type=SIPURI
2017-06-19T06:51:01 836493086mS Sip: SIPDialog f17407bc deleted, dialogs 1 txn_keys 2
2017-06-19T06:51:03 836495598mS RES: Mon 19/6/2017 06:51:03 FreeMem=54155916 Heap=52927364(1) Cache=1228552 MemObjs=14908(17658) CMMsg=6(8) ASN=0 Buff=5200 1372 990 7402 5 Links=59033(60700) BTree=1208(2302) CPU=07.61% CPUStats=06.91%/1/4/145/18535/22798
/00.20%/1/02.96% MCR=0 MCW=0
2017-06-19T06:51:03 836495598mS RES2: IP 500 V2 9.1.9.0 build 182 Tasks=50 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=136 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=0 TCP=100(TLS=7) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
2017-06-19T06:51:03 836495598mS RES4: XML MemObjs=63 PoolMem=4748404(2) FreePoolMem=4733100(0)
2017-06-19T06:51:03 836495598mS RES5: CLog MemObjs=1563 FreePoolMem(Objs)=1924(37) TotalMem=252600
2017-06-19T06:51:06 836498086mS Sip: sip_indicateTimeOut Timer 10
2017-06-19T06:51:06 836498086mS Sip: Timer 10 callback didn't find dialog, method REGISTER, callid f39c287a-5f89a281-323829c8@10.10.0.13
2017-06-19T06:51:06 836498086mS Sip: sip_indicateTimeOut txn_keys 1
2017-06-19T06:51:23 836516617mS ISDNL3Rx: v=13 peb=13
ISDN Layer3 Pcol=08(Q931) Reflen=2 ref=002F(Local)
Message Type = Release
InformationElement = CAUSE
0000 08 02 80 90 ....
2017-06-19T06:51:23 836516618mS ISDNL3Tx: v=13 peb=13
ISDN Layer3 Pcol=08(Q931) Reflen=2 ref=002F(Remote)
Message Type = ReleaseComplete
2017-06-19T06:51:23 836516618mS ISDNL3Evt: v=13 stacknum=13 State, new=NullState, old=Proceeding id=5083
2017-06-19T06:51:23 836516618mS CMLineRx: v=13
CMReleaseComp
Line: type=Q931Line 13 Call: lid=0 id=5083 in=0
BChan: slot=0 chan=10
Cause=16, Normal call clearing
2017-06-19T06:51:23 836516619mS CMCallEvt: 0a0a0005000013db 0.5083.0 1029 Q931 Trunk:13 CHAN=10: StateChange: END=B CMCSRinging->CMCSCompleted
2017-06-19T06:51:23 836516620mS CMLOGGING: CALL:2017/06/1906:50,00:00:00,000,259,O,14086380968,914086380968,polycomUpstairs,,,0,,"",0,n/a
2017-06-19T06:51:23 836516620mS CD: CALL: 251.5080.0 BState=Disconnecting Cut=1 Music=0.0 Aend="polycomUpstairs(259)" (0.0) Bend="Line 13" [Line 13] (7.11) CalledNum=14086380968 () CallingNum=259 (polycomUpstairs) Internal=0 Time=26584 AState=Ringing
2017-06-19T06:51:23 836516620mS CD: CALL: 251.5080.0 Deleted
2017-06-19T06:51:23 836516621mS CMExtnEvt: polycomUpstairs: CALL LOST (CMCauseNormal)
2017-06-19T06:51:23 836516621mS CMExtnEvt: polycomUpstairs: Extn(259) Calling Party Number(259) Type(CMNTypeInternal)
2017-06-19T06:51:23 836516621mS CMCallEvt: 0a0a0005000013d8 251.5080.0 -1 polycomUpstairs.0: StateChange: END=X CMCSRingBack->CMCSCompleted
2017-06-19T06:51:23 836516622mS CMExtnEvt: v=0 State, new=PortRecoverDelay old=Alerting,0,0,polycomUpstairs
2017-06-19T06:51:23 836516622mS CMExtnTx: v=259, p1=0
CMReleaseComp
Line: type=SIPLine 260 Call: lid=251 id=5080 in=0
Called[914086380968] Type=Default (100) Reason=CMDRdirect Calling[259] Type=Internal Plan=Default
Cause=16, Normal call clearing
Timed: 19/06/17 06:51
2017-06-19T06:51:23 836516622mS Sip: 0a0a0005000013d8 251.5080.0 -1 polycomUpstairs.0(f4eda800) Terminating dialog f4eda800, state SIPDialog::INV_PROV_RESP_SENT(11) for cause CMCauseNormal
2017-06-19T06:51:23 836516623mS Sip: 0a0a0005000013d8 251.5080.0 -1 polycomUpstairs.0(f4eda800) SendSIPResponse: INVITE code 404 SENT TO 10.10.0.13 5060
2017-06-19T06:51:23 836516623mS SIP Tx: UDP 10.10.0.5:5060 -> 10.10.0.13:5060
SIP/2.0 404 Not Found
Via: SIP/2.0/UDP 10.10.0.13;branch=z9hG4bKb065e2652E6E34AC
From: "Polycom" <sip:259@10.10.0.5>;tag=8074248-E2D526CF
Call-ID: 1a7c433-eb6680fa-48725b01@10.10.0.13
CSeq: 1 INVITE
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,REFER,NOTIFY,SUBSCRIBE,REGISTER,PUBLISH,UPDATE
Supported: timer,100rel
Server: IP Office 9.1.9.0 build 182
Reason: Q.850;cause=16;text="Normal call clearing"
To: <sip:914086380968@10.10.0.5;user=phone>;tag=2e0eb0d83b0bd7e9
Content-Length: 0
2017-06-19T06:51:23 836516624mS Sip: 0a0a0005000013d8 251.5080.0 -1 polycomUpstairs.0(f4eda800) UpdateSIPCallState SIPDialog::INV_PROV_RESP_SENT(11) -> SIPDialog::FINAL(28)
2017-06-19T06:51:23 836516624mS CMExtnEvt: polycomUpstairs: CMExtnHandler::SetCurrent( id: 5080->0 )
2017-06-19T06:51:23 836516624mS CMCallEvt: 0a0a0005000013d8 251.5080.0 -1 polycomUpstairs.-1: StateChange: END=X CMCSCompleted->CMCSDelete
2017-06-19T06:51:23 836516624mS Sip: (f4eda800) KeepDlgOnCmCallLost SIPDialog::FINAL
2017-06-19T06:51:23 836516625mS Sip: SIPDialog f4eda800 deleted, dialogs 0 txn_keys 1
2017-06-19T06:51:23 836516625mS CMTARGET: 0a0a0005000013d8 251.5080.0 -1 BaseEP: ~CMTargetHandler f17178b8 ep f1708a50
2017-06-19T06:51:23 836516625mS CMCallEvt: 0a0a0005000013d8 251.5080.0 -1 BaseEP: DELETE CMEndpoint f1708a50 TOTAL NOW=1 CALL_LIST=0
2017-06-19T06:51:23 836516626mS CMCallEvt: 0a0a0005000013db 0.5083.0 -1 Q931 Trunk:13 CHAN=10: StateChange: END=X CMCSCompleted->CMCSDelete
2017-06-19T06:51:23 836516626mS CMCallEvt: END CALL:1029 (f172c2dc)
2017-06-19T06:51:23 836516626mS CMTARGET: ISDN BChannel 10: in-service check = 1
2017-06-19T06:51:23 836516627mS CMTARGET: ISDN BChannel 10: in-service check = 1
2017-06-19T06:51:23 836516627mS CMCallEvt: 0a0a0005000013db 0.5083.0 -1 BaseEP: DELETE CMEndpoint f1611d5c TOTAL NOW=0 CALL_LIST=0
2017-06-19T06:51:23 836516628mS CMMap: PCG::UnmapBChan pcp[103]b1r0 cp_b f55ab3e0 other_cp_b f55ffa70
2017-06-19T06:51:23 836516628mS CMMap: a=6.1 b=7.11 M02
2017-06-19T06:51:23 836516628mS CMMap: PlatformConnectionAudioSAP:
isconnectRtpFilter rtpRelay ID: 1 Close success
2017-06-19T06:51:23 836516628mS CMMap: PCG::UnmapBChan pcp[840]b0r1 cp_b 0 other_cp_b 0
2017-06-19T06:51:23 836516629mS CMMap: a=6.1 b=0.0 Mapper::FreeCodec freed CMRTVocoder(f564e0b4) resource busy 1, total 32
2017-06-19T06:51:23 836516641mS SIP Rx: UDP 10.10.0.13:5060 -> 10.10.0.5:5060
ACK sip:914086380968@10.10.0.5:5060;transport=udp SIP/2.0
Via: SIP/2.0/UDP 10.10.0.13;branch=z9hG4bKb065e2652E6E34AC
From: "Polycom" <sip:259@10.10.0.5>;tag=8074248-E2D526CF
To: <sip:914086380968@10.10.0.5;user=phone>;tag=2e0eb0d83b0bd7e9
CSeq: 1 ACK
Call-ID: 1a7c433-eb6680fa-48725b01@10.10.0.13
Contact: <sip:259@10.10.0.13>
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
User-Agent: PolycomSoundStationIP-SPIP_6000-UA/3.0.4.0061
Max-Forwards: 70
Content-Length: 0
2017-06-19T06:51:24 836517031mS RES: Mon 19/6/2017 06:51:24 FreeMem=54250448 Heap=52960960(1) Cache=1289488 MemObjs=14329(17658) CMMsg=7(8) ASN=0 Buff=5200 1372 990 7404 5 Links=58931(60700) BTree=1206(2302) CPU=07.51% CPUStats=08.83%/10/16/145/18016/227
98/00.30%/1/02.90% MCR=0 MCW=0
2017-06-19T06:51:24 836517031mS RES2: IP 500 V2 9.1.9.0 build 182 Tasks=50 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=138 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=0 TCP=100(TLS=7) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
2017-06-19T06:51:24 836517032mS RES4: XML MemObjs=63 PoolMem=4748404(2) FreePoolMem=4733100(0)
2017-06-19T06:51:24 836517032mS RES5: CLog MemObjs=1563 FreePoolMem(Objs)=1924(37) TotalMem=252600
2017-06-19T06:51:24 836517124mS CMExtnEvt: polycomUpstairs: Recover Timer reason=CMTRWrapUp
2017-06-19T06:51:24 836517124mS CMExtnEvt: v=0 State, new=Idle old=PortRecoverDelay,0,0,polycomUpstairs
2017-06-19T06:51:24 836517124mS CM: CMReminder CheckReminder(user=259)
2017-06-19T06:51:28 836521643mS Sip: sip_indicateTimeOut Timer 9
2017-06-19T06:51:28 836521643mS Sip: Timer 9 callback didn't find dialog, method INVITE, callid 1a7c433-eb6680fa-48725b01@10.10.0.13
2017-06-19T06:51:28 836521643mS Sip: sip_indicateTimeOut txn_keys 0
2017-06-19T06:51:29 836522032mS RES: Mon 19/6/2017 06:51:29 FreeMem=54287808 Heap=52994548(1) Cache=1293260 MemObjs=14226(17658) CMMsg=7(8) ASN=0 Buff=5200 1372 990 7404 5 Links=58929(60700) BTree=1206(2302) CPU=07.35% CPUStats=06.67%/2/4/145/18634/22798
/00.03%/1/02.71% MCR=0 MCW=0
2017-06-19T06:51:29 836522033mS RES2: IP 500 V2 9.1.9.0 build 182 Tasks=50 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=134 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=0 TCP=100(TLS=7) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
2017-06-19T06:51:29 836522033mS RES4: XML MemObjs=63 PoolMem=4748404(2) FreePoolMem=4733100(0)
2017-06-19T06:51:29 836522033mS RES5: CLog MemObjs=1563 FreePoolMem(Objs)=1924(37) TotalMem=252600
-SD-
Telco prompts for LD Code input.
If calling from a 9650 set, you get about 5 seconds of silence, then a tone, then a recording instructing you to input your authorization code.
If calling from the Polycom, you hear about 4.5 rings, and then it goes to fast busy (reorder). The is never a prompt for the authorization code.
Anybody else ever run into this???
2017-06-19T06:50:36 836468390mS PRN: Monitor Status IP 500 V2 9.1.9.0 build 182
2017-06-19T06:50:36 836468390mS PRN: LAW=U PRI=1, BRI=0, ALOG=4, VCOMP=32, MDM=0, WAN=0, MODU=0 LANM=0 CkSRC=13 VMAIL=1(VER=3 TYP=1) 1-X=0 CALLS=0(TOT=1028)
2017-06-19T06:50:58 836490031mS SIP Rx: UDP 10.10.0.13:5060 -> 10.10.0.5:5060
INVITE sip:914086380968@10.10.0.5:5060;user=phone SIP/2.0
Via: SIP/2.0/UDP 10.10.0.13;branch=z9hG4bKb065e2652E6E34AC
From: "Polycom" <sip:259@10.10.0.5>;tag=8074248-E2D526CF
To: <sip:914086380968@10.10.0.5;user=phone>
CSeq: 1 INVITE
Call-ID: 1a7c433-eb6680fa-48725b01@10.10.0.13
Contact: <sip:259@10.10.0.13>
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
User-Agent: PolycomSoundStationIP-SPIP_6000-UA/3.0.4.0061
Supported: 100rel,replaces
Allow-Events: talk,hold,conference
Max-Forwards: 70
Content-Type: application/sdp
Content-Length: 445
v=0
o=- 1497807780 1497807780 IN IP4 10.10.0.13
s=Polycom IP Phone
c=IN IP4 10.10.0.13
t=0 0
m=audio 2226 RTP/AVP 115 99 9 102 0 8 18 101
a=sendrecv
a=rtpmap:115 G7221/32000
a=fmtp:115 annexb=no
a=rtpmap:99 SIREN14/16000
a=fmtp:99 annexb=no
a=rtpmap:9 G722/8000
a=rtpmap:102 G7221/16000
a=fmtp:102 annexb=no
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
2017-06-19T06:50:58 836490035mS CMCallEvt: 0000000000000000 0.5080.0 -1 BaseEP: NEW CMEndpoint f1708a50 TOTAL NOW=1 CALL_LIST=0
2017-06-19T06:50:58 836490035mS CMCallEvt: 0000000000000000 0.5080.0 -1 polycomUpstairs.-1: NEW CMExtnEndpoint f1708a50, Name=polycomUpstairs, Extn=259, Phys Extn=259
2017-06-19T06:50:58 836490036mS CMCallEvt: CREATE CALL:1029 (f172c2dc)
2017-06-19T06:50:58 836490036mS CMCallEvt: 0000000000000000 0.5081.0 -1 BaseEP: NEW CMEndpoint f172a984 TOTAL NOW=2 CALL_LIST=0
2017-06-19T06:50:58 836490038mS CMExtnEvt: polycomUpstairs: CMExtnHandler::SetCurrent( id: 0->5080 )
2017-06-19T06:50:58 836490038mS Sip: SIPDialog f4eda800 created, dialogs 1 txn_keys 1
2017-06-19T06:50:58 836490039mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) Cloned
2017-06-19T06:50:58 836490040mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) SendSIPResponse: INVITE code 100 SENT TO 10.10.0.13 5060
2017-06-19T06:50:58 836490040mS SIP Tx: UDP 10.10.0.5:5060 -> 10.10.0.13:5060
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 10.10.0.13;branch=z9hG4bKb065e2652E6E34AC
From: "Polycom" <sip:259@10.10.0.5>;tag=8074248-E2D526CF
Call-ID: 1a7c433-eb6680fa-48725b01@10.10.0.13
CSeq: 1 INVITE
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,REFER,NOTIFY,SUBSCRIBE,REGISTER,PUBLISH,UPDATE
Supported: timer,100rel
Server: IP Office 9.1.9.0 build 182
To: <sip:914086380968@10.10.0.5;user=phone>;tag=2e0eb0d83b0bd7e9
Content-Length: 0
2017-06-19T06:50:58 836490040mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) INVITE Received ep 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f1708a50), dialog f4eda800
2017-06-19T06:50:58 836490041mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) UpdateSIPCallState SIPDialog::INITIAL(0) -> SIPDialog::INVITE_RCVD(9)
2017-06-19T06:50:58 836490041mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) UpdateSDPState SIPDialog::IDLE(0) -> SIPDialog::OFFER_RCVD(2)
2017-06-19T06:50:58 836490041mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) SdpClone
2017-06-19T06:50:58 836490041mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) SIPDialog::BuildFastStartFromSDPOffer sdpmsg f190238c
2017-06-19T06:50:58 836490042mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) SIPDialog::FindConnectionParameters: found media proto <RTP/AVP>
2017-06-19T06:50:58 836490042mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) SetRfc2833TxPayload: use RFC2833 for dtmf
2017-06-19T06:50:58 836490042mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) SetRfc2833TxPayload: payload 101 set_rx 1
2017-06-19T06:50:58 836490042mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) SIPDialog::BuildFastStartFromAudioMediaSDPOffer reinvite 0 msg f1724250 fs in msg 1 mRTP_PType 255
2017-06-19T06:50:58 836490042mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) SetRemoteRTPAddress to 10.10.0.13:2226
2017-06-19T06:50:58 836490043mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) Process SIP request dialog f4eda800, method INVITE in state SIPDialog::INVITE_RCVD(9)
2017-06-19T06:50:58 836490044mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) UpdateClone mMesg f161b19c smsg f1618e24
2017-06-19T06:50:58 836490045mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) CMSetup forwarded to call model owner_ep 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f1708a50), dialog f4eda800 has sdp 1
2017-06-19T06:50:58 836490045mS CMExtnRx: v=259, p1=0
CMSetup
Line: type=SIPLine 260 Call: lid=251 id=5080 in=0
Called[914086380968] Type=Default (100) Reason=CMDRdirect SndComp Calling[259] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
IE CMIEFastStartInfoData (6) 6 item(s)
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=polycomUpstairs
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=259
2017-06-19T06:50:58 836490045mS CMCallEvt: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0: StateChange: END=A CMCSIdle->CMCSDialInitiated
2017-06-19T06:50:58 836490045mS CMExtnEvt: v=0 State, new=Dialling old=Idle,0,0,polycomUpstairs
2017-06-19T06:50:58 836490046mS CMTARGET: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=914086380968 sub= calling=259 calling_sub= dir=out complete=1 ses=0
2017-06-19T06:50:58 836490046mS CMTARGET: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0: ADD TARGET (N): number=914086380968 type=100 depth=1 nobar=1 setorig=1 ses=0
2017-06-19T06:50:58 836490046mS CMTARGET: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0: SYS SC: 914086380968 2 14086380968 sc=type=Dial3K1 code=9N, num=N callinfop->sending_complete=1 secondary_dialtone=
2017-06-19T06:50:58 836490046mS CMARS: FindActiveARSByGroupID GroupID=50 - Found
2017-06-19T06:50:58 836490047mS CMARS: MakeCallTarget - Called Number: 14086380968
2017-06-19T06:50:58 836490047mS CMCallEvt: 0000000000000000 0.5082.0 -1 BaseEP: NEW CMEndpoint f170e004 TOTAL NOW=3 CALL_LIST=1
2017-06-19T06:50:58 836490047mS CMTARGET: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0: INITIAL TARGETING SUCCEEDED
2017-06-19T06:50:58 836490047mS CMTARGET: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0: GetNoAnswerTimer:15
2017-06-19T06:50:58 836490048mS CMCallEvt: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0: StateChange: END=A CMCSDialInitiated->CMCSDialled
2017-06-19T06:50:58 836490048mS CMExtnEvt: v=0 State, new=Proceeding old=Dialling,0,0,polycomUpstairs
2017-06-19T06:50:58 836490049mS CMExtnTx: v=259, p1=0
CMProceeding
Line: type=SIPLine 260 Call: lid=251 id=5080 in=0
Timed: 19/06/17 06:50
2017-06-19T06:50:58 836490050mS CMCallEvt: 0000000000000000 0.5081.0 1029 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
2017-06-19T06:50:58 836490050mS CMCallEvt: 0000000000000000 0.5082.0 1029 ARS for Main: StateChange: END=T CMCSIdle->CMCSOffering
2017-06-19T06:50:58 836490051mS CMCallEvt: 0000000000000000 0.5081.0 1029 TargetingEP: RequestEnd 0000000000000000 0.5082.0 1029 ARS for Main
2017-06-19T06:50:58 836490051mS CMTARGET: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0: CancelTimer CMTCNoAnswerTimeout
2017-06-19T06:50:58 836490052mS CMCallEvt: 0000000000000000 0.5082.0 1029 ARS for Main: StateChange: END=B CMCSOffering->CMCSOverlapRecv
2017-06-19T06:50:58 836490052mS CMARS: FORM: Main - Received Number: 14086380968
2017-06-19T06:50:58 836490052mS CMARS: FOUND A SHORT CODE - short_code: N; - Tel: Nsi9075866806 - Called_Party: 14086380968 - Line Group Id: 1
2017-06-19T06:50:58 836490052mS CMARS: SetCurrentTarget: Short_Code: N; - Line_Group_ID: 1
2017-06-19T06:50:58 836490052mS CMARS: FindActiveARSByGroupID GroupID=1 - Not Found
2017-06-19T06:50:58 836490052mS CMLRQ: FindActiveLRQByGroupID GroupID=1 - Not Found
2017-06-19T06:50:58 836490053mS CMMap: a=6.1 b=0.0 Mapper::AllocateCodec allocated CMRTVocoder(f564e0b4) resource busy 1, total 32
2017-06-19T06:50:58 836490053mS CMCallEvt: 0000000000000000 0.5083.0 -1 BaseEP: NEW CMEndpoint f1611d5c TOTAL NOW=4 CALL_LIST=1
2017-06-19T06:50:58 836490053mS CMTARGET: ISDN BChannel 10: in-service check = 1
2017-06-19T06:50:58 836490054mS CMTARGET: ISDN BChannel 10: in-service check = 1
2017-06-19T06:50:58 836490054mS CMARS: ModifyCMARSTarget: Short_Code: N; - Line_Group_ID: 1 set line status to CMARS_TRYING
2017-06-19T06:50:58 836490055mS CMARS: FOUND LINE - Line Id: 13 - using line group id: 1 (code N;, line 1) - Called Number: 14086380968 - Calling Number: 9075866806
2017-06-19T06:50:58 836490055mS CMARS: SEND Setup TO LINE
2017-06-19T06:50:58 836490055mS CMCallEvt: 0a0a0005000013db 0.5083.0 1029 Q931 Trunk:13 CHAN=10: StateChange: END=child CMCSIdle->CMCSOffering
2017-06-19T06:50:58 836490055mS PRN: Setting configured voice gain for ch 10.
2017-06-19T06:50:58 836490055mS CMLineTx: v=13
CMSetup
Line: type=Q931Line 13 Call: lid=0 id=5083 in=0
Called[14086380968] Type=National (2) Reason=CMDRdirect Calling[9075866806] Type=National Plan=ISDN
BC: CMTC=3K1Audio CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
BChan: slot=0 chan=10
Locale: enu
2017-06-19T06:50:58 836490056mS CMCallEvt: 0000000000000000 0.5081.0 -1 TargetingEP: StateChange: END=X CMCSOffering->CMCSDelete
2017-06-19T06:50:58 836490056mS CMCallEvt: 0000000000000000 0.5081.0 -1 BaseEP: DELETE CMEndpoint f172a984 TOTAL NOW=3 CALL_LIST=1
2017-06-19T06:50:58 836490057mS ISDNL3Evt: v=13 stacknum=13 State, new=Initiated, old=NullState id=5083
2017-06-19T06:50:58 836490058mS ISDNL3Tx: v=13 peb=13
ISDN Layer3 Pcol=08(Q931) Reflen=2 ref=002F(Remote)
Message Type = Setup
InformationElement = BearerCapability
0000 04 03 90 90 a2 .....
InformationElement = CHI
0000 18 03 a9 83 8a .....
InformationElement = CallingPartyNumber
0000 6c 0c 21 80 39 30 37 35 38 36 36 38 30 36 l.!.9075866806
InformationElement = CalledPartyNumber
0000 70 0c a0 31 34 30 38 36 33 38 30 39 36 38 p..14086380968
2017-06-19T06:50:58 836490063mS CD: CALL: 251.5080.0 BState=Idle Cut=3 Music=0.0 Aend="polycomUpstairs(259)" (0.0) Bend="" [Line 13] (0.0) CalledNum=914086380968 () CallingNum=259 (polycomUpstairs) Internal=1 Time=27 AState=Dialled
2017-06-19T06:50:58 836490093mS RES: Mon 19/6/2017 06:50:58 FreeMem=54185012 Heap=52960576(0) Cache=1224436 MemObjs=14763(17658) CMMsg=7(8) ASN=0 Buff=5200 1371 990 7404 5 Links=58998(60700) BTree=1208(2302) CPU=07.65% CPUStats=09.63%/25/31/145/18505/227
98/00.04%/0/02.71% MCR=0 MCW=0
2017-06-19T06:50:58 836490093mS RES2: IP 500 V2 9.1.9.0 build 182 Tasks=50 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=142 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=0 TCP=100(TLS=7) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
2017-06-19T06:50:58 836490093mS RES4: XML MemObjs=63 PoolMem=4748404(2) FreePoolMem=4733100(0)
2017-06-19T06:50:58 836490094mS RES5: CLog MemObjs=1563 FreePoolMem(Objs)=1924(37) TotalMem=252600
2017-06-19T06:50:58 836490099mS ISDNL3Rx: v=13 peb=13
ISDN Layer3 Pcol=08(Q931) Reflen=2 ref=002F(Local)
Message Type = CallProceeding
InformationElement = CHI
0000 18 03 a9 83 8a .....
2017-06-19T06:50:58 836490100mS ISDNL3Evt: v=13 stacknum=13 State, new=Proceeding, old=Initiated id=5083
2017-06-19T06:50:58 836490100mS CMLineRx: v=13
CMProceeding
Line: type=Q931Line 13 Call: lid=0 id=5083 in=0
BChan: slot=0 chan=10
2017-06-19T06:50:58 836490100mS CMARS: LINE ep Received: CMProceeding - child->state = CMCSOffering - ARS Call State = CMCSOverlapRecv
2017-06-19T06:50:58 836490100mS CMARS: LINE IS NOW THE B END OF THE CALL - CMARSEndpoint::RequestEnd()
2017-06-19T06:50:58 836490101mS CMARS: CMARSEndpoint::CallLost(cause=124) - Address: 0a0a0005000013d8 0.5082.0 1029 ARS for Main - Call State: CMCSOverlapRecv
2017-06-19T06:50:58 836490101mS CMCallEvt: 0a0a0005000013d8 0.5082.0 -1 ARS for Main: StateChange: END=X CMCSOverlapRecv->CMCSDelete
2017-06-19T06:50:58 836490102mS CMCallEvt: 0a0a0005000013db 0.5083.0 1029 Q931 Trunk:13 CHAN=10: StateChange: END=B CMCSOffering->CMCSAccept
2017-06-19T06:50:58 836490102mS CMCallEvt: 0a0a0005000013d8 0.5082.0 -1 BaseEP: DELETE CMEndpoint f170e004 TOTAL NOW=2 CALL_LIST=1
2017-06-19T06:50:58 836490102mS CD: CALL: 251.5080.0 BState=Ringing Cut=3 Music=0.0 Aend="polycomUpstairs(259)" (0.0) Bend="Line 13" [Line 13] (7.11) CalledNum=14086380968 () CallingNum=259 (polycomUpstairs) Internal=0 Time=66 AState=Dialled
2017-06-19T06:50:58 836490470mS ISDNL3Rx: v=13 peb=13
ISDN Layer3 Pcol=08(Q931) Reflen=2 ref=002F(Local)
Message Type = Progress
InformationElement = PI
0000 1e 02 80 81 ....
2017-06-19T06:50:58 836490471mS CMLineRx: v=13
CMProgress
Line: type=Q931Line 13 Call: lid=0 id=5083 in=0
IE CMIEProgressIndicator (30) cs=CMCSITUT (0), loc=CMLUser (0), pd=CMPDNotISDN (1)
2017-06-19T06:50:58 836490472mS CMCallEvt: 0a0a0005000013db 0.5083.0 1029 Q931 Trunk:13 CHAN=10: StateChange: END=B CMCSAccept->CMCSRinging
2017-06-19T06:50:58 836490472mS CMCallEvt: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0: StateChange: END=A CMCSDialled->CMCSRingBack
2017-06-19T06:50:58 836490474mS CMMap: IP::SetCodec pcp[840]b0r0 0 -> f564e0b4
2017-06-19T06:50:58 836490474mS CMExtnTx: v=259, p1=0
CMFacility
Line: type=SIPLine 260 Call: lid=251 id=5080 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
IE CMIESecurityData (253) 2 item(s)
CMSecurityElement RX_ONLY {
CMSRTPCryptoCapability none
Codecs list (size 7)
}
CMSecurityElement TX_ONLY {
CMSRTPCryptoCapability none
Codecs list (size 7)
}
Timed: 19/06/17 06:50
2017-06-19T06:50:58 836490475mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) SIPDialog cannot reshuffle in SIPDialog::INVITE_RCVD, CMFacilityInterval 0, PendingUpdateResp 0, has_fs 1, has_video 0, hold_ch, 0 name_ch 0 media_ch 0 empt
y_reinvite 0 UnInt UnInt_None
2017-06-19T06:50:58 836490475mS CMExtnEvt: v=0 State, new=Alerting old=Proceeding,0,0,polycomUpstairs
2017-06-19T06:50:58 836490477mS CMExtnTx: v=259, p1=0
CMProgress
Line: type=SIPLine 260 Call: lid=251 id=5080 in=0
IE CMIEProgressIndicator (30) cs=CMCSITUT (0), loc=CMLUser (0), pd=CMPDNotISDN (1)
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=914086380968
IE CMIEDeviceDetail (231) 0a0a0005000013db LOCALE=enu HW=15 VER=9 class=CMDeviceISDNTrunk type=2 number=13 channel=10 features=0x0 rx_gain=32 tx_gain=32 ep_callid=5083 ipaddr=10.10.0.5 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=1
Timed: 19/06/17 06:50
2017-06-19T06:50:58 836490477mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) UpdateSIPCallState SIPDialog::INVITE_RCVD(9) -> SIPDialog::INV_PROV_RESP_SENT(11)
2017-06-19T06:50:58 836490477mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) SIPEndPoint: Received an CMProgress State Transition to SIPDialog::INV_PROV_RESP_SENT(11)
2017-06-19T06:50:58 836490478mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) InsertCallerIdHeader caller ID method <CallerIDPAID> added_pai <F>
2017-06-19T06:50:58 836490478mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) InsertPAID number <914086380968> and name <> and restricted <F>
2017-06-19T06:50:58 836490478mS Sip: 0a0a0005000013d8 251.5080.0 1029 polycomUpstairs.0(f4eda800) SendSIPResponse: INVITE code 180 SENT TO 10.10.0.13 5060
2017-06-19T06:50:58 836490479mS SIP Tx: UDP 10.10.0.5:5060 -> 10.10.0.13:5060
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 10.10.0.13;branch=z9hG4bKb065e2652E6E34AC
From: "Polycom" <sip:259@10.10.0.5>;tag=8074248-E2D526CF
Call-ID: 1a7c433-eb6680fa-48725b01@10.10.0.13
CSeq: 1 INVITE
Contact: <sip:914086380968@10.10.0.5:5060;transport=udp>
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,REFER,NOTIFY,SUBSCRIBE,REGISTER,PUBLISH,UPDATE
P-Asserted-Identity: <sip:914086380968@10.10.0.5:5060>
Supported: timer,100rel
Server: IP Office 9.1.9.0 build 182
To: <sip:914086380968@10.10.0.5;user=phone>;tag=2e0eb0d83b0bd7e9
Content-Length: 0
2017-06-19T06:50:58 836490480mS CD: CALL: 251.5080.0 BState=Ringing Cut=3 Music=0.0 Aend="polycomUpstairs(259)" (0.0) Bend="Line 13" [Line 13] (7.11) CalledNum=14086380968 () CallingNum=259 (polycomUpstairs) Internal=0 Time=443 AState=Ringing
2017-06-19T06:50:58 836490481mS CMMap: PCG::MapBChan pcp[840]b0r1 cp_b 0 other_cp_b 0 type CGTypeSimple
2017-06-19T06:50:58 836490481mS CMMap: PCGS CPReserveCodec for the other end (pcp[840]b0r1) true
2017-06-19T06:50:58 836490481mS CMMap: PCG::MapBChan pcp[103]b1r0 cp_b f55ab3e0 other_cp_b f55ffa70 type CGTypeSimple
2017-06-19T06:50:58 836490481mS CMMap: a=6.1 b=7.11 M12
2017-06-19T06:50:58 836490481mS CMMap: PlatformConnectionAudioSAP::Bind pcp[840]b0r1 to 6.1
2017-06-19T06:50:58 836490481mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[840]b0r1 Configure 6.1
2017-06-19T06:50:58 836490482mS CMMap: PlatformConnectionAudioSAP::ConnectVoice rtpRelay Open got rtpRelay ID: 1
2017-06-19T06:50:58 836490482mS CMMap: PlatformConnectionAudioSAP::ConnectVoice rtpRelay Configure success
2017-06-19T06:50:58 836490482mS CMMap: PlatformConnectionAudioSAP::ConnectVoice local IP addr 10.10.0.5:49152, Remote IP addr 10.10.0.13:2226
2017-06-19T06:50:58 836490482mS CMMap: PlatformConnectionAudioSAP::ConnectVoice DSP IP addr 1.1.1.3:32768, telogyHost IP addr 1.1.1.1:10
2017-06-19T06:50:58 836490482mS CMMap: PlatformConnectionAudioSAP::ConnectVoice rtpRelay Start success
2017-06-19T06:50:58 836490482mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[840]b0r1 ConnectIndication 6.1
2017-06-19T06:51:01 836493081mS SIP Rx: UDP 10.10.0.13:5060 -> 10.10.0.5:5060
REGISTER sip:10.10.0.5:5060 SIP/2.0
Via: SIP/2.0/UDP 10.10.0.13;branch=z9hG4bKc61fa79d9E4023E4
From: "Polycom" <sip:259@10.10.0.5>;tag=8E57AE4F-570C2016
To: <sip:259@10.10.0.5>
CSeq: 2069 REGISTER
Call-ID: f39c287a-5f89a281-323829c8@10.10.0.13
Contact: <sip:259@10.10.0.13>;methods="INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER"
User-Agent: PolycomSoundStationIP-SPIP_6000-UA/3.0.4.0061
Authorization: Digest username="polycomUpstairs", realm="ipoffice", nonce="d699125f8675a7870dc3", uri="sip:10.10.0.5:5060", response="40c70f9bcc9b983098e4758eff497c8c", algorithm=MD5
Max-Forwards: 70
Expires: 3600
Content-Length: 0
2017-06-19T06:51:01 836493084mS Sip: SIPDialog f17407bc created, dialogs 2 txn_keys 2
2017-06-19T06:51:01 836493085mS Sip: (f17407bc) SendSIPResponse: REGISTER code 200 SENT TO 10.10.0.13 5060
2017-06-19T06:51:01 836493086mS SIP Tx: UDP 10.10.0.5:5060 -> 10.10.0.13:5060
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.10.0.13;branch=z9hG4bKc61fa79d9E4023E4
From: "Polycom" <sip:259@10.10.0.5>;tag=8E57AE4F-570C2016
Call-ID: f39c287a-5f89a281-323829c8@10.10.0.13
CSeq: 2069 REGISTER
User-Agent: IP Office 9.1.9.0 build 182
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,REFER,NOTIFY,INFO,SUBSCRIBE,REGISTER,PUBLISH
Contact: <sip:259@10.10.0.13>
Date: Mon, 19 Jun 2017 14:51:01 GMT
Expires: 180
Supported: timer
Server: IP Office 9.1.9.0 build 182
To: <sip:259@10.10.0.5>;tag=1bc2b9f4e0caf00c
Content-Length: 0
2017-06-19T06:51:01 836493086mS Sip: SIP REG: Phone(259)(ip=10.10.0.13) is on PRIVATE network (has NO corporate NAT and phone NOT behind its own NAT. URI_type=SIPURI
2017-06-19T06:51:01 836493086mS Sip: SIPDialog f17407bc deleted, dialogs 1 txn_keys 2
2017-06-19T06:51:03 836495598mS RES: Mon 19/6/2017 06:51:03 FreeMem=54155916 Heap=52927364(1) Cache=1228552 MemObjs=14908(17658) CMMsg=6(8) ASN=0 Buff=5200 1372 990 7402 5 Links=59033(60700) BTree=1208(2302) CPU=07.61% CPUStats=06.91%/1/4/145/18535/22798
/00.20%/1/02.96% MCR=0 MCW=0
2017-06-19T06:51:03 836495598mS RES2: IP 500 V2 9.1.9.0 build 182 Tasks=50 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=136 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=0 TCP=100(TLS=7) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
2017-06-19T06:51:03 836495598mS RES4: XML MemObjs=63 PoolMem=4748404(2) FreePoolMem=4733100(0)
2017-06-19T06:51:03 836495598mS RES5: CLog MemObjs=1563 FreePoolMem(Objs)=1924(37) TotalMem=252600
2017-06-19T06:51:06 836498086mS Sip: sip_indicateTimeOut Timer 10
2017-06-19T06:51:06 836498086mS Sip: Timer 10 callback didn't find dialog, method REGISTER, callid f39c287a-5f89a281-323829c8@10.10.0.13
2017-06-19T06:51:06 836498086mS Sip: sip_indicateTimeOut txn_keys 1
2017-06-19T06:51:23 836516617mS ISDNL3Rx: v=13 peb=13
ISDN Layer3 Pcol=08(Q931) Reflen=2 ref=002F(Local)
Message Type = Release
InformationElement = CAUSE
0000 08 02 80 90 ....
2017-06-19T06:51:23 836516618mS ISDNL3Tx: v=13 peb=13
ISDN Layer3 Pcol=08(Q931) Reflen=2 ref=002F(Remote)
Message Type = ReleaseComplete
2017-06-19T06:51:23 836516618mS ISDNL3Evt: v=13 stacknum=13 State, new=NullState, old=Proceeding id=5083
2017-06-19T06:51:23 836516618mS CMLineRx: v=13
CMReleaseComp
Line: type=Q931Line 13 Call: lid=0 id=5083 in=0
BChan: slot=0 chan=10
Cause=16, Normal call clearing
2017-06-19T06:51:23 836516619mS CMCallEvt: 0a0a0005000013db 0.5083.0 1029 Q931 Trunk:13 CHAN=10: StateChange: END=B CMCSRinging->CMCSCompleted
2017-06-19T06:51:23 836516620mS CMLOGGING: CALL:2017/06/1906:50,00:00:00,000,259,O,14086380968,914086380968,polycomUpstairs,,,0,,"",0,n/a
2017-06-19T06:51:23 836516620mS CD: CALL: 251.5080.0 BState=Disconnecting Cut=1 Music=0.0 Aend="polycomUpstairs(259)" (0.0) Bend="Line 13" [Line 13] (7.11) CalledNum=14086380968 () CallingNum=259 (polycomUpstairs) Internal=0 Time=26584 AState=Ringing
2017-06-19T06:51:23 836516620mS CD: CALL: 251.5080.0 Deleted
2017-06-19T06:51:23 836516621mS CMExtnEvt: polycomUpstairs: CALL LOST (CMCauseNormal)
2017-06-19T06:51:23 836516621mS CMExtnEvt: polycomUpstairs: Extn(259) Calling Party Number(259) Type(CMNTypeInternal)
2017-06-19T06:51:23 836516621mS CMCallEvt: 0a0a0005000013d8 251.5080.0 -1 polycomUpstairs.0: StateChange: END=X CMCSRingBack->CMCSCompleted
2017-06-19T06:51:23 836516622mS CMExtnEvt: v=0 State, new=PortRecoverDelay old=Alerting,0,0,polycomUpstairs
2017-06-19T06:51:23 836516622mS CMExtnTx: v=259, p1=0
CMReleaseComp
Line: type=SIPLine 260 Call: lid=251 id=5080 in=0
Called[914086380968] Type=Default (100) Reason=CMDRdirect Calling[259] Type=Internal Plan=Default
Cause=16, Normal call clearing
Timed: 19/06/17 06:51
2017-06-19T06:51:23 836516622mS Sip: 0a0a0005000013d8 251.5080.0 -1 polycomUpstairs.0(f4eda800) Terminating dialog f4eda800, state SIPDialog::INV_PROV_RESP_SENT(11) for cause CMCauseNormal
2017-06-19T06:51:23 836516623mS Sip: 0a0a0005000013d8 251.5080.0 -1 polycomUpstairs.0(f4eda800) SendSIPResponse: INVITE code 404 SENT TO 10.10.0.13 5060
2017-06-19T06:51:23 836516623mS SIP Tx: UDP 10.10.0.5:5060 -> 10.10.0.13:5060
SIP/2.0 404 Not Found
Via: SIP/2.0/UDP 10.10.0.13;branch=z9hG4bKb065e2652E6E34AC
From: "Polycom" <sip:259@10.10.0.5>;tag=8074248-E2D526CF
Call-ID: 1a7c433-eb6680fa-48725b01@10.10.0.13
CSeq: 1 INVITE
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,REFER,NOTIFY,SUBSCRIBE,REGISTER,PUBLISH,UPDATE
Supported: timer,100rel
Server: IP Office 9.1.9.0 build 182
Reason: Q.850;cause=16;text="Normal call clearing"
To: <sip:914086380968@10.10.0.5;user=phone>;tag=2e0eb0d83b0bd7e9
Content-Length: 0
2017-06-19T06:51:23 836516624mS Sip: 0a0a0005000013d8 251.5080.0 -1 polycomUpstairs.0(f4eda800) UpdateSIPCallState SIPDialog::INV_PROV_RESP_SENT(11) -> SIPDialog::FINAL(28)
2017-06-19T06:51:23 836516624mS CMExtnEvt: polycomUpstairs: CMExtnHandler::SetCurrent( id: 5080->0 )
2017-06-19T06:51:23 836516624mS CMCallEvt: 0a0a0005000013d8 251.5080.0 -1 polycomUpstairs.-1: StateChange: END=X CMCSCompleted->CMCSDelete
2017-06-19T06:51:23 836516624mS Sip: (f4eda800) KeepDlgOnCmCallLost SIPDialog::FINAL
2017-06-19T06:51:23 836516625mS Sip: SIPDialog f4eda800 deleted, dialogs 0 txn_keys 1
2017-06-19T06:51:23 836516625mS CMTARGET: 0a0a0005000013d8 251.5080.0 -1 BaseEP: ~CMTargetHandler f17178b8 ep f1708a50
2017-06-19T06:51:23 836516625mS CMCallEvt: 0a0a0005000013d8 251.5080.0 -1 BaseEP: DELETE CMEndpoint f1708a50 TOTAL NOW=1 CALL_LIST=0
2017-06-19T06:51:23 836516626mS CMCallEvt: 0a0a0005000013db 0.5083.0 -1 Q931 Trunk:13 CHAN=10: StateChange: END=X CMCSCompleted->CMCSDelete
2017-06-19T06:51:23 836516626mS CMCallEvt: END CALL:1029 (f172c2dc)
2017-06-19T06:51:23 836516626mS CMTARGET: ISDN BChannel 10: in-service check = 1
2017-06-19T06:51:23 836516627mS CMTARGET: ISDN BChannel 10: in-service check = 1
2017-06-19T06:51:23 836516627mS CMCallEvt: 0a0a0005000013db 0.5083.0 -1 BaseEP: DELETE CMEndpoint f1611d5c TOTAL NOW=0 CALL_LIST=0
2017-06-19T06:51:23 836516628mS CMMap: PCG::UnmapBChan pcp[103]b1r0 cp_b f55ab3e0 other_cp_b f55ffa70
2017-06-19T06:51:23 836516628mS CMMap: a=6.1 b=7.11 M02
2017-06-19T06:51:23 836516628mS CMMap: PlatformConnectionAudioSAP:
isconnectRtpFilter rtpRelay ID: 1 Close success2017-06-19T06:51:23 836516628mS CMMap: PCG::UnmapBChan pcp[840]b0r1 cp_b 0 other_cp_b 0
2017-06-19T06:51:23 836516629mS CMMap: a=6.1 b=0.0 Mapper::FreeCodec freed CMRTVocoder(f564e0b4) resource busy 1, total 32
2017-06-19T06:51:23 836516641mS SIP Rx: UDP 10.10.0.13:5060 -> 10.10.0.5:5060
ACK sip:914086380968@10.10.0.5:5060;transport=udp SIP/2.0
Via: SIP/2.0/UDP 10.10.0.13;branch=z9hG4bKb065e2652E6E34AC
From: "Polycom" <sip:259@10.10.0.5>;tag=8074248-E2D526CF
To: <sip:914086380968@10.10.0.5;user=phone>;tag=2e0eb0d83b0bd7e9
CSeq: 1 ACK
Call-ID: 1a7c433-eb6680fa-48725b01@10.10.0.13
Contact: <sip:259@10.10.0.13>
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
User-Agent: PolycomSoundStationIP-SPIP_6000-UA/3.0.4.0061
Max-Forwards: 70
Content-Length: 0
2017-06-19T06:51:24 836517031mS RES: Mon 19/6/2017 06:51:24 FreeMem=54250448 Heap=52960960(1) Cache=1289488 MemObjs=14329(17658) CMMsg=7(8) ASN=0 Buff=5200 1372 990 7404 5 Links=58931(60700) BTree=1206(2302) CPU=07.51% CPUStats=08.83%/10/16/145/18016/227
98/00.30%/1/02.90% MCR=0 MCW=0
2017-06-19T06:51:24 836517031mS RES2: IP 500 V2 9.1.9.0 build 182 Tasks=50 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=138 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=0 TCP=100(TLS=7) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
2017-06-19T06:51:24 836517032mS RES4: XML MemObjs=63 PoolMem=4748404(2) FreePoolMem=4733100(0)
2017-06-19T06:51:24 836517032mS RES5: CLog MemObjs=1563 FreePoolMem(Objs)=1924(37) TotalMem=252600
2017-06-19T06:51:24 836517124mS CMExtnEvt: polycomUpstairs: Recover Timer reason=CMTRWrapUp
2017-06-19T06:51:24 836517124mS CMExtnEvt: v=0 State, new=Idle old=PortRecoverDelay,0,0,polycomUpstairs
2017-06-19T06:51:24 836517124mS CM: CMReminder CheckReminder(user=259)
2017-06-19T06:51:28 836521643mS Sip: sip_indicateTimeOut Timer 9
2017-06-19T06:51:28 836521643mS Sip: Timer 9 callback didn't find dialog, method INVITE, callid 1a7c433-eb6680fa-48725b01@10.10.0.13
2017-06-19T06:51:28 836521643mS Sip: sip_indicateTimeOut txn_keys 0
2017-06-19T06:51:29 836522032mS RES: Mon 19/6/2017 06:51:29 FreeMem=54287808 Heap=52994548(1) Cache=1293260 MemObjs=14226(17658) CMMsg=7(8) ASN=0 Buff=5200 1372 990 7404 5 Links=58929(60700) BTree=1206(2302) CPU=07.35% CPUStats=06.67%/2/4/145/18634/22798
/00.03%/1/02.71% MCR=0 MCW=0
2017-06-19T06:51:29 836522033mS RES2: IP 500 V2 9.1.9.0 build 182 Tasks=50 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=134 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=0 TCP=100(TLS=7) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
2017-06-19T06:51:29 836522033mS RES4: XML MemObjs=63 PoolMem=4748404(2) FreePoolMem=4733100(0)
2017-06-19T06:51:29 836522033mS RES5: CLog MemObjs=1563 FreePoolMem(Objs)=1924(37) TotalMem=252600
-SD-