Cannot locate LRG/GVP

ankush87 · December 28, 2016, 2:34pm

Hello experts,

I am facing a issue where in when i dial the Trunk group , I get the fast busy tone.
I checked the SIP logs in and SIP logs I get Event Destination busy. and in Resource Manager logs I see
Cannot locate logical resource matching Physical AOR sip:192.168.1.3:5060

However I have already created the LRG i am not sure why LRG is not seen.

SIP log:

08:02:57.4290 [0] 8.1.102.53 distribute_event: message EventDialing
AttributeEventSequenceNumber 000000000000004c
AttributeTimeinuSecs 429000
AttributeTimeinSecs 1482912177 (08:02:57)
AttributeExtensions [23] 00 01 01 00..
‘BusinessCall’ 0
AttributeOtherDNRole 2
AttributeOtherDN ‘2200’
AttributePartyUUID ‘OSMESV2Q9P5V140BRJURTD6AEG000004’
AttributeThisDNRole 1
AttributeThisDN ‘9001’
AttributeANI ‘9001’
AttributeDNIS ‘2200’
AttributeCallUUID ‘OTNRESGK2H1HT7GQ1GEICJ025G000001’
AttributeConnID 00750295d10b1001
AttributeCallID 16777217
AttributePropagatedCallType 1
AttributeCallType 1
AttributeCallState 0
08:02:57.430 Int 04544 Interaction message “EventDialing” generated
08:02:57.430 Trc 04542 EventDialing sent to [640] (00000005 ORS_1 192.168.1.2:49524)
08:02:57.430 Trc 04542 EventDialing sent to [500] (00000003 StatServer_1 192.168.1.2:49517)

+++ Post-event +++
Type EventOriginated
Devices: <9001/9001> <2200/2200> <-/->
Calls: 16777217/00750295d10b1001/16777217.3148e70/c:1/r:0 0/00750295d10b1001/16777217.3148e70/c:1/r:0
Parties: D9001/9001.3149430-3148e70:1/l:1/r:0/Dialing,Active,Origination
D2200/2200.314a1d0-3148e70:1/l:2/r:0/Null,Destination
none
Call type: Internal/1
Flags: divert=0 hook=0 postCall=0 active=1 moveAll=1 callType=1 hideOtherPi=0 InternalOther=1
— Post-event —
08:02:57.430 — CIFace::Event —
08:02:57.430: SIPTR(3): complete
08:02:57.430: SIPTR(0): Step 2 - SipTransactionChangePartyState(3) complete
08:02:57.430: SIPTR(0): Begin step 3 - SipTransactionGetOffer(4)
08:02:57.432: SIPTR(4): complete
08:02:57.432: SIPTR(0): Step 3 - SipTransactionGetOffer(4) complete
08:02:57.432: SIPTR(0): Begin step 4 - SipTransactionConnectNewParty(5)
Session value of the SDP is [3957275403]
Version values of the SDP is [1]
08:02:57.434 SIPCONN(2200): re-invite-null
08:02:57.434: SipDialog: set monitor 0000000003149a58
08:02:57.434 SIPCONN(2200): main dialog 0 created, flags 0x21f
08:02:57.463 SIPCONN(2200): Local contact: ‘sip:9001@192.168.1.3:5060’
08:02:57.471: add party info ‘2200’ state 0.
08:02:57.472: SIPDLG[7]: register TRN[7]
08:02:57.472: SIPDLG[7]: TRN[7] flags set to 0x6
08:02:57.472: Sending [0,UDP] 1018 bytes to 192.168.1.3:5090 >>>>>
INVITE sip:2200@192.168.1.3:5090 SIP/2.0
From: sip:9001@192.168.1.3:5060;tag=84F6DEC0-281E-4D6E-A949-F898B252DD59-5
To: sip:2200@192.168.1.3:5060
Call-ID: 2D4D7F5F-0615-4B50-8241-59CD1D53834C-1@192.168.1.3
CSeq: 1 INVITE
Content-Length: 327
Content-Type: application/sdp
Via: SIP/2.0/UDP 192.168.1.3:5060;branch=z9hG4bK1ED03076-1788-45F1-8FAD-4D0C45FA92E9-1
Contact: sip:9001@192.168.1.3:5060
Allow: ACK, BYE, CANCEL, INFO, INVITE, MESSAGE, NOTIFY, OPTIONS, PRACK, REFER, UPDATE
User-Agent: X-Lite release 4.9.6 stamp 82158
Max-Forwards: 69
X-Genesys-CallUUID: OTNRESGK2H1HT7GQ1GEICJ025G000001
Session-Expires: 1800;refresher=uac
Min-SE: 90
Supported: uui,100rel,timer

v=0
o=- 1482912187 1 IN IP4 192.168.1.52
s=X-Lite release 4.9.6 stamp 82158
c=IN IP4 192.168.1.52
t=0 0
m=audio 55540 RTP/AVP 9 8 120 0 84 101
a=sendrecv
a=rtpmap:120 opus/48000/2
a=fmtp:120 useinbandfec=1; usedtx=1; maxaveragebitrate=64000
a=rtpmap:84 speex/16000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

08:02:57.472: SipDialog: event SEND_INVITE, t=7, s=2, r=7, m=0000000003149a58
08:02:57.472: CID:CUUID>2D4D7F5F-0615-4B50-8241-59CD1D53834C-1@192.168.1.3:OTNRESGK2H1HT7GQ1GEICJ025G000001:
08:02:57.472 SIPCONN(2200): HandleSipDialogEvent(SEND_INVITE) - filtered
08:02:57.472 SIPCONN(2200): sdp state SDP_STATE_NULL, event SDP_EVENT_OFFER_SENT
08:02:57.472 SIPCONN(2200): new sdp state SDP_STATE_OFFER_SENT, event SDP_EVENT_OFFER_SENT
08:02:57.472: $-NET:SIP::0:264377

08:02:57.483: Sending [0,UDP] 305 bytes to 192.168.1.52:54158 >>>>>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.1.52:54158;branch=z9hG4bK-524287-1—4bd140261561f901;rport;received=192.168.1.52
To: sip:2200@192.168.1.3:5060
From: sip:9001@192.168.1.3:5060;tag=20e6c156
Call-ID: 82158MGUxODRiYjc4ODI2M2NkZjAwNjE2MTRkZWJhNmRjOWE
CSeq: 1 INVITE
Content-Length: 0

08:02:57.563: $+NET:SIP::0:0
08:02:57.563: SIPTR: Received [0,UDP] 315 bytes from 192.168.1.3:5090 <<<<<
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.1.3:5060;branch=z9hG4bK1ED03076-1788-45F1-8FAD-4D0C45FA92E9-1
From: sip:9001@192.168.1.3:5060;tag=84F6DEC0-281E-4D6E-A949-F898B252DD59-5
To: sip:2200@192.168.1.3:5060
CSeq: 1 INVITE
Call-ID: 2D4D7F5F-0615-4B50-8241-59CD1D53834C-1@192.168.1.3
Content-Length: 0

08:02:57.563: SipDialog: event CALLING_RESPROV, t=7, s=2, r=5, m=0000000003149a58
08:02:57.563: CID:CUUID>2D4D7F5F-0615-4B50-8241-59CD1D53834C-1@192.168.1.3:OTNRESGK2H1HT7GQ1GEICJ025G000001:
08:02:57.563 SIPCONN(2200): HandleSipDialogEvent(CALLING_RESPROV)
08:02:57.563 SIPCONN(2200): Capabilities 61013f
08:02:57.563 SIPCONN(2200): reliable=0
08:02:57.564 SIPCONN(2200): store remote content
08:02:57.564 SIPCONN(2200): store remote content - trying ignored
08:02:57.564 SIPCONN(2200): Trying Timer for 32000 mlsec started…
08:02:57.564: $-NET:SIP::0:894

08:02:57.624: Assocaited transport for the device [13] changed from [:0:0] to [192.168.1.52:54158:1]
08:02:57.639: $+NET:SIP::0:0
08:02:57.639: SIPTR: Received [0,UDP] 880 bytes from 192.168.1.52:54158 <<<<<
INVITE sip:2200@192.168.1.3:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.52:54158;branch=z9hG4bK-524287-1—4bd140261561f901;rport
Max-Forwards: 70
Contact: sip:9001@192.168.1.52:54158
To: sip:2200@192.168.1.3:5060
From: sip:9001@192.168.1.3:5060;tag=20e6c156
Call-ID: 82158MGUxODRiYjc4ODI2M2NkZjAwNjE2MTRkZWJhNmRjOWE
CSeq: 1 INVITE
Allow: SUBSCRIBE, NOTIFY, INVITE, ACK, CANCEL, BYE, REFER, INFO, OPTIONS, MESSAGE
Content-Type: application/sdp
Supported: replaces
User-Agent: X-Lite release 4.9.6 stamp 82158
Content-Length: 334

v=0
o=- 13127385779580515 1 IN IP4 192.168.1.52
s=X-Lite release 4.9.6 stamp 82158
c=IN IP4 192.168.1.52
t=0 0
m=audio 55540 RTP/AVP 9 8 120 0 84 101
a=rtpmap:120 opus/48000/2
a=fmtp:120 useinbandfec=1; usedtx=1; maxaveragebitrate=64000
a=rtpmap:84 speex/16000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv

08:02:57.639: Sending [0,UDP] 305 bytes to 192.168.1.52:54158 >>>>>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.1.52:54158;branch=z9hG4bK-524287-1—4bd140261561f901;rport;received=192.168.1.52
To: sip:2200@192.168.1.3:5060
From: sip:9001@192.168.1.3:5060;tag=20e6c156
Call-ID: 82158MGUxODRiYjc4ODI2M2NkZjAwNjE2MTRkZWJhNmRjOWE
CSeq: 1 INVITE
Content-Length: 0

08:02:57.639: $-NET:SIP::0:122

08:02:57.798: $+NET:SIP::0:0
08:02:57.798: SIPTR: Received [0,UDP] 811 bytes from 192.168.1.3:5090 <<<<<
SIP/2.0 500 Server Internal Error
Via: SIP/2.0/UDP 192.168.1.3:5060;branch=z9hG4bK1ED03076-1788-45F1-8FAD-4D0C45FA92E9-1
From: sip:9001@192.168.1.3:5060;tag=84F6DEC0-281E-4D6E-A949-F898B252DD59-5
To: sip:2200@192.168.1.3:5060;tag=AF97B611-38BF-43CD-DE87-D56D11588C8D
CSeq: 1 INVITE
Call-ID: 2D4D7F5F-0615-4B50-8241-59CD1D53834C-1@192.168.1.3
Contact: sip:Genesys@192.168.1.3:5070
Content-Length: 0
Record-Route: sip:0000000015B36FF0@192.168.1.3:5090;lr;gvp.rm.datanodes=1;idtag=00000001
User-Agent: X-Lite release 4.9.6 stamp 82158
Min-SE: 90
X-Genesys-GVP-Session-Data: callsession=1BA3C618-84FF-4101-3AA0-27BCC1B95198;1;0;;;;Environment;TestIVRProfile;;0;default_IVRProfile
X-Genesys-GVP-Session-ID: 1BA3C618-84FF-4101-3AA0-27BCC1B95198;gvp.rm.datanodes=1;gvp.rm.tenant-id=1_TestIVRProfile

08:02:57.798: Sending [0,UDP] 436 bytes to 192.168.1.3:5090 >>>>>
ACK sip:2200@192.168.1.3:5090 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.3:5060;branch=z9hG4bK1ED03076-1788-45F1-8FAD-4D0C45FA92E9-1
From: sip:9001@192.168.1.3:5060;tag=84F6DEC0-281E-4D6E-A949-F898B252DD59-5
To: sip:2200@192.168.1.3:5060;tag=AF97B611-38BF-43CD-DE87-D56D11588C8D
Call-ID: 2D4D7F5F-0615-4B50-8241-59CD1D53834C-1@192.168.1.3
CSeq: 1 ACK
Max-Forwards: 69
User-Agent: X-Lite release 4.9.6 stamp 82158
Content-Length: 0

08:02:57.800: SipDialog: event CALLING_RESREJECT, t=7, s=9, r=5, m=0000000003149a58
08:02:57.800: CID:CUUID>2D4D7F5F-0615-4B50-8241-59CD1D53834C-1@192.168.1.3:OTNRESGK2H1HT7GQ1GEICJ025G000001:
08:02:57.800 SIPCONN(2200): HandleSipDialogEvent(CALLING_RESREJECT)
08:02:57.800 SIPCONN(2200): Trying Timer deleted…
08:02:57.800 SIPCONN(2200): ConvertResponse: 500
08:02:57.800 SIPCONN(2200): ConvertResponse: no conversion configured for 500
08:02:57.800 SIPCONN(2200): state e:4,p:0,s:6,c:8,rc:500,m:1
08:02:57.800 SIPCONN(9001): CheckUpdateTransferStatus: no original dialog
08:02:57.832 SIPPARTY(2200): 16777218 verify update of party-connection state N-F
08:02:57.832 SIPPARTY(2200): 16777218 update party-connection state N-F
08:02:57.845 +++ CIFace::Event +++
+++ Pre-event +++
Type EventDestinationBusy
Devices: <9001/9001> <2200/2200> <-/->
Calls: 16777217/00750295d10b1001/16777217.3148e70/c:1/r:0 0/none
Parties: D9001/9001.3149430-3148e70:1/l:1/r:0/Dialing,Active,Origination
D2200/2200.314a1d0-3148e70:1/l:2/r:0/Null,Destination
none
Cause: Blocked/35, Info: 0
Flags: divert=0 hook=0 postCall=0 active=1 moveAll=1 callType=1 hideOtherPi=0 InternalOther=1
— Pre-event —
+++ DestBusy +++
SetFailed: party 9001.3149430-3148e70:1, cause Blocked
@08:02:57.8460 [0] 8.1.102.53 distribute_event: message EventDestinationBusy
AttributeEventSequenceNumber 000000000000004d
AttributeTimeinuSecs 846000
AttributeTimeinSecs 1482912177 (08:02:57)
AttributeExtensions [23] 00 01 01 00..
‘BusinessCall’ 0
AttributeOtherDNRole 2
AttributeOtherDN ‘2200’
AttributePartyUUID ‘OSMESV2Q9P5V140BRJURTD6AEG000004’
AttributeThisDNRole 1
AttributeThisDN ‘9001’
AttributeANI ‘9001’
AttributeDNIS ‘2200’
AttributeCallUUID ‘OTNRESGK2H1HT7GQ1GEICJ025G000001’
AttributeConnID 00750295d10b1001
AttributeCallID 16777217
AttributePropagatedCallType 1
AttributeCallType 1
AttributeCallState 5
08:02:57.846 Int 04544 Interaction message “EventDestinationBusy” generated
08:02:57.847 Trc 04542 EventDestinationBusy sent to [640] (00000005 ORS_1 192.168.1.2:49524)
08:02:57.848 Trc 04542 EventDestinationBusy sent to [500] (00000003 StatServer_1 192.168.1.2:49517)
— DestBusy —
+++ Post-event +++
Type EventDestinationBusy
Devices: <9001/9001> <2200/2200> <-/->
Calls: 16777217/00750295d10b1001/16777217.3148e70/c:1/r:0 0/none
Parties: D9001/9001.3149430-3148e70:1/l:1/r:0/Failed,Active,Origination
D2200/2200.314a1d0-3148e70:1/l:2/r:0/Blocked,Destination
none
Cause: Blocked/35, Info: 0
Flags: divert=0 hook=0 postCall=0 active=1 moveAll=1 callType=1 hideOtherPi=0 InternalOther=1
— Post-event —
08:02:57.849 — CIFace::Event —
08:02:57.929: check call postponed until end of operation
08:02:57.932 SIPCONN(2200): terminate dialog
08:02:57.932: SipDialog: set monitor 0000000000000000
08:02:57.932: SipDialog::Terminate(state=9,reason=0)
08:02:57.932 SIPCONN(2200): state e:4,p:6,s:6,c:8,rc:500,m:1
08:02:57.932 SIPCONN(9001): CheckUpdateTransferStatus: no original dialog
08:02:57.932 SIPPARTY(2200): 16777218 verify update of party-connection state F-F
08:02:57.933: SIPTR(5): failed
08:02:57.933: SIPTR(0): Step 4 - SipTransactionConnectNewParty(5) failed
08:02:57.933: SIPTR(0): failed
08:02:57.933: SIPCM: transaction SipScenario failed
08:02:57.933: PI: 00 S[IN]D[9001]C[*D[9001]]P[2200]
08:02:57.933: PI: 01 S[FN]D[2200]P[9001], busy scheduled
08:02:57.933: party cannot be recovered
08:02:57.934: CALLSTATE(a:2,d:0,i:0,e:0,r:0,o:0)
08:02:57.934: apply fast busy tone for device ‘2200’
08:02:57.943: Selected for Dn (geo-loc:partitionId[SipServerDefaultPartition]:cpdCapability): Service VOIP_DN (geo-loc, priority[0], capacity 0 (0% of 0))
08:02:57.962: previous scenario is not cleaned up
08:02:57.962: SIPTR(0): Begin step 0 - SipTransactionConnectMediaService(6)
08:02:57.962 SIPCONN(VOIP_DN): set monitor 0000000003162390, 00000000019d9dc0
08:02:57.962 SIPCONN(2200): DetachMediaPeer
08:02:57.962 SIPCONN(9001): re-invite-called-initiated
08:02:57.962 SIPCONN(VOIP_DN): re-invite-null
08:02:57.962 SIPCONN(9001): GetOffer
08:02:57.962 SIPCONN(9001): GetOffer::ReturnOffer
08:02:57.962 SIPCONN(9001): NotifyOnOffer
08:02:57.962 SIPCONN(VOIP_DN): SendOffer
08:02:57.962 SIPCONN(VOIP_DN): re-invite-null
08:02:57.962 SIPCONN(VOIP_DN): SendOffer::Invite
08:02:57.962: SipDialog: set monitor 0000000003162448
08:02:57.962 SIPCONN(VOIP_DN): main dialog 0 created, flags 0x21f
Session value of the SDP is [3957275403]
Version values of the SDP is [1]
08:02:57.963 SIPCONN(VOIP_DN): Local contact: ‘sip:9001@192.168.1.3:5060’
08:02:57.963: SIPDLG[8]: register TRN[8]
08:02:57.963: SIPDLG[8]: TRN[8] flags set to 0x6
08:02:57.963: Sending [0,UDP] 1002 bytes to 192.168.1.3:5090 >>>>>
INVITE sip:msml@192.168.1.3:5090;tenant-dbid=1;media-service=media SIP/2.0
From: sip:9001@192.168.1.3:5060;tag=84F6DEC0-281E-4D6E-A949-F898B252DD59-6
To: sip:VOIP_DN@192.168.1.3:5060
Call-ID: 2D4D7F5F-0615-4B50-8241-59CD1D53834C-2@192.168.1.3
CSeq: 1 INVITE
Content-Length: 327
Content-Type: application/sdp
Via: SIP/2.0/UDP 192.168.1.3:5060;branch=z9hG4bK1ED03076-1788-45F1-8FAD-4D0C45FA92E9-2
Contact: sip:9001@192.168.1.3:5060
Allow: ACK, BYE, CANCEL, INFO, INVITE, MESSAGE, NOTIFY, OPTIONS, PRACK, REFER, UPDATE
Max-Forwards: 69
X-Genesys-CallUUID: OTNRESGK2H1HT7GQ1GEICJ025G000001
Session-Expires: 1800;refresher=uac
Min-SE: 90
Supported: uui,timer

v=0
o=- 1482912192 1 IN IP4 192.168.1.52
s=X-Lite release 4.9.6 stamp 82158
c=IN IP4 192.168.1.52
t=0 0
m=audio 55540 RTP/AVP 9 8 120 0 84 101
a=sendrecv
a=rtpmap:120 opus/48000/2
a=fmtp:120 useinbandfec=1; usedtx=1; maxaveragebitrate=64000
a=rtpmap:84 speex/16000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

08:02:57.963: SipDialog: event SEND_INVITE, t=8, s=2, r=6, m=0000000003162448
08:02:57.963: CID:CUUID>2D4D7F5F-0615-4B50-8241-59CD1D53834C-2@192.168.1.3:OTNRESGK2H1HT7GQ1GEICJ025G000001:
08:02:57.963 SIPCONN(VOIP_DN): HandleSipDialogEvent(SEND_INVITE) - filtered
08:02:57.963 SIPCONN(VOIP_DN): sdp state SDP_STATE_NULL, event SDP_EVENT_OFFER_SENT
08:02:57.963 SIPCONN(VOIP_DN): new sdp state SDP_STATE_OFFER_SENT, event SDP_EVENT_OFFER_SENT
08:02:57.963: SipDialog: event DESTROY, t=0, s=10, r=4, m=0000000000000000
08:02:57.963: CID:CUUID>2D4D7F5F-0615-4B50-8241-59CD1D53834C-1@192.168.1.3:OTNRESGK2H1HT7GQ1GEICJ025G000001:
08:02:57.963: DIALOG_TRANSPORT_ASSOCIATION[7] NOT FOUND
08:02:57.963: SipDialog[7]:<< Abort ALL <<
08:02:57.963: $-NET:SIP::0:165723

08:02:57.965: $+NET:SIP::0:0
08:02:57.965: SIPTR: Received [0,UDP] 318 bytes from 192.168.1.3:5090 <<<<<
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.1.3:5060;branch=z9hG4bK1ED03076-1788-45F1-8FAD-4D0C45FA92E9-2
From: sip:9001@192.168.1.3:5060;tag=84F6DEC0-281E-4D6E-A949-F898B252DD59-6
To: sip:VOIP_DN@192.168.1.3:5060
CSeq: 1 INVITE
Call-ID: 2D4D7F5F-0615-4B50-8241-59CD1D53834C-2@192.168.1.3
Content-Length: 0

08:02:57.965: SipDialog: event CALLING_RESPROV, t=8, s=2, r=5, m=0000000003162448
08:02:57.965: CID:CUUID>2D4D7F5F-0615-4B50-8241-59CD1D53834C-2@192.168.1.3:OTNRESGK2H1HT7GQ1GEICJ025G000001:
08:02:57.965 SIPCONN(VOIP_DN): HandleSipDialogEvent(CALLING_RESPROV)
08:02:57.965 SIPCONN(VOIP_DN): Capabilities 60013f
08:02:57.965 SIPCONN(VOIP_DN): reliable=0
08:02:57.965 SIPCONN(VOIP_DN): store remote content
08:02:57.965 SIPCONN(VOIP_DN): store remote content - trying ignored
08:02:57.965 SIPCONN(VOIP_DN): Trying Timer for 32000 mlsec started…
08:02:57.966 SIPCONN(VOIP_DN): Connect(2,1)
08:02:57.966: $-NET:SIP::0:514

08:02:58.210: $+NET:SIP::0:0
08:02:58.210: SIPTR: Received [0,UDP] 1090 bytes from 192.168.1.3:5090 <<<<<
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.3:5060;branch=z9hG4bK1ED03076-1788-45F1-8FAD-4D0C45FA92E9-2
From: sip:9001@192.168.1.3:5060;tag=84F6DEC0-281E-4D6E-A949-F898B252DD59-6
To: sip:VOIP_DN@192.168.1.3:5060;tag=6675E895-D1AB-494B-BDAB-D74D0D3FFA82
CSeq: 1 INVITE
Call-ID: 2D4D7F5F-0615-4B50-8241-59CD1D53834C-2@192.168.1.3
Contact: sip:Genesys@192.168.1.3:5070
Content-Length: 247
Content-Type: application/sdp
Record-Route: sip:0000000015B36FF0@192.168.1.3:5090;lr;gvp.rm.datanodes=1;idtag=00000002
Min-SE: 90
X-Genesys-GVP-Session-Data: callsession=547CEA1C-97FA-40AF-6B9B-FF1EB82D9F7F;1;0;;;;Environment;default_IVRProfile;;0;default_IVRProfile
X-Genesys-GVP-Session-ID: 547CEA1C-97FA-40AF-6B9B-FF1EB82D9F7F;gvp.rm.datanodes=1;gvp.rm.tenant-id=1_default_IVRProfile
Session-Expires: 1800;refresher=uac
Require: timer

v=0
o=- 268532156 1 IN IP4 192.168.1.3
s=phone-call
c=IN IP4 192.168.1.3
t=0 0
m=audio 20002 RTP/AVP 9 8 0 101
a=rtpmap:9 g722/8000
a=rtpmap:8 pcma/8000
a=rtpmap:0 pcmu/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv

08:02:58.210: SipDialog: event CALLING_RESOK, t=8, s=7, r=5, m=0000000003162448
08:02:58.210: CID:CUUID>2D4D7F5F-0615-4B50-8241-59CD1D53834C-2@192.168.1.3:OTNRESGK2H1HT7GQ1GEICJ025G000001:
08:02:58.210 SIPCONN(VOIP_DN): HandleSipDialogEvent(CALLING_RESOK)
08:02:58.210 SIPCONN(VOIP_DN): Trying Timer deleted…
08:02:58.210 SIPCONN(VOIP_DN): store remote content
08:02:58.210 SIPCONN(VOIP_DN): sdp state SDP_STATE_OFFER_SENT, event SDP_EVENT_SDP
08:02:58.210 SIPCONN(VOIP_DN): new sdp state SDP_STATE_NULL, event SDP_EVENT_SDP
08:02:58.210 SIPCONN(VOIP_DN): Connect(2,4)
08:02:58.210 SIPCONN(VOIP_DN): NotifyResponseOnAnswer
08:02:58.210 SIPCONN(9001): SendAnswer
Session value of the SDP is [268532156]
Version values of the SDP is [1]
08:02:58.210 SIPCONN(9001): SendAnswer::Response
08:02:58.210 SIPCONN(9001): SendResponse(200,6)
08:02:58.210: add party info ‘9001’ state 1.
08:02:58.210: Sending [0,UDP] 1109 bytes to 192.168.1.52:54158 >>>>>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.52:54158;branch=z9hG4bK-524287-1—4bd140261561f901;rport;received=192.168.1.52
To: sip:2200@192.168.1.3:5060;tag=84F6DEC0-281E-4D6E-A949-F898B252DD59-4
From: sip:9001@192.168.1.3:5060;tag=20e6c156
Call-ID: 82158MGUxODRiYjc4ODI2M2NkZjAwNjE2MTRkZWJhNmRjOWE
CSeq: 1 INVITE
Contact: sip:192.168.1.3:5060
X-Genesys-CallUUID: OTNRESGK2H1HT7GQ1GEICJ025G000001
Allow: INVITE, ACK, PRACK, CANCEL, BYE, REFER, INFO, MESSAGE, NOTIFY, OPTIONS
X-Genesys-GVP-Session-Data: callsession=547CEA1C-97FA-40AF-6B9B-FF1EB82D9F7F;1;0;;;;Environment;default_IVRProfile;;0;default_IVRProfile
X-Genesys-GVP-Session-ID: 547CEA1C-97FA-40AF-6B9B-FF1EB82D9F7F;gvp.rm.datanodes=1;gvp.rm.tenant-id=1_default_IVRProfile
Session-Expires: 1800;refresher=uas
Supported: uui,timer
Content-Type: application/sdp
Content-Length: 248

v=0
o=- 1482912179 1 IN IP4 192.168.1.3
s=phone-call
c=IN IP4 192.168.1.3
t=0 0
m=audio 20002 RTP/AVP 9 8 0 101
a=sendrecv
a=rtpmap:9 g722/8000
a=rtpmap:8 pcma/8000
a=rtpmap:0 pcmu/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

08:02:58.210: SipDialog: event CALLED_RESOK, t=6, s=7, r=5, m=000000000313e188
08:02:58.210 SIPCONN(9001): HandleSipDialogEvent(CALLED_RESOK) - filtered
08:02:58.210 SIPCONN(9001): TRCLR(6)
08:02:58.210 SIPCONN(9001): sdp state SDP_STATE_OFFER_RECEIVED, event SDP_EVENT_ANSWER_SENT
08:02:58.210 SIPCONN(9001): new sdp state SDP_STATE_NULL, event SDP_EVENT_ANSWER_SENT
08:02:58.210 SIPCONN(VOIP_DN): state e:3,p:0,s:3,c:0,rc:0,m:1
08:02:58.210 SIPCONN(9001): CheckUpdateTransferStatus: no original dialog
08:02:58.210 SIPCONN(VOIP_DN): NotifyOnComplete
08:02:58.210: $-NET:SIP::0:651

08:02:58.647: $+NET:SIP::0:0
08:02:58.647: SIPTR: Received [0,UDP] 441 bytes from 192.168.1.52:54158 <<<<<
ACK sip:192.168.1.3:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.52:54158;branch=z9hG4bK-524287-1—dfaa7e00737d0952;rport
Max-Forwards: 70
Contact: sip:9001@192.168.1.52:54158
To: sip:2200@192.168.1.3:5060;tag=84F6DEC0-281E-4D6E-A949-F898B252DD59-4
From: sip:9001@192.168.1.3:5060;tag=20e6c156
Call-ID: 82158MGUxODRiYjc4ODI2M2NkZjAwNjE2MTRkZWJhNmRjOWE
CSeq: 1 ACK
User-Agent: X-Lite release 4.9.6 stamp 82158
Content-Length: 0

08:02:58.648: SipDialog: event CONNECTED_ACK, t=6, s=7, r=5, m=000000000313e188
08:02:58.648 SIPCONN(9001): HandleSipDialogEvent(CONNECTED_ACK)
08:02:58.648 SIPCONN(9001): new transaction
08:02:58.648 SIPCONN(9001): store remote content
08:02:58.648 SIPCONN(9001): skip SDP pocessing [0/SDP_STATE_NULL]
08:02:58.648 SIPCONN(9001): Connect(4,26)
08:02:58.648 SIPCONN(9001): TRCLR(0)
08:02:58.648 SIPCONN(9001): NotifyOnComplete
08:02:58.648 SIPCONN(9001): Connect complete, other device ‘VOIP_DN’,(000000000313e0d0,0000000003162390)
08:02:58.648 SIPCONN(VOIP_DN): Connect complete, other device ‘9001’,(0000000003162390,000000000313e0d0)
08:02:58.648 SIPCONN(VOIP_DN): SendAck(8)
08:02:58.648: Sending [0,UDP] 606 bytes to 192.168.1.3:5090 >>>>>
ACK sip:Genesys@192.168.1.3:5070 SIP/2.0
From: sip:9001@192.168.1.3:5060;tag=84F6DEC0-281E-4D6E-A949-F898B252DD59-6
To: sip:VOIP_DN@192.168.1.3:5060;tag=6675E895-D1AB-494B-BDAB-D74D0D3FFA82
Call-ID: 2D4D7F5F-0615-4B50-8241-59CD1D53834C-2@192.168.1.3
CSeq: 1 ACK
Content-Length: 0
Via: SIP/2.0/UDP 192.168.1.3:5060;branch=z9hG4bK1ED03076-1788-45F1-8FAD-4D0C45FA92E9-3
Route: sip:0000000015B36FF0@192.168.1.3:5090;lr;gvp.rm.datanodes=1;idtag=00000002
Allow: INVITE, ACK, PRACK, CANCEL, BYE, REFER, INFO, MESSAGE, NOTIFY, OPTIONS
Max-Forwards: 69
User-Agent: X-Lite release 4.9.6 stamp 82158

08:02:58.648: SipDialog: event CONNECTED_SEND_ACK, t=8, s=7, r=5, m=0000000003162448
08:02:58.648: CID:CUUID>2D4D7F5F-0615-4B50-8241-59CD1D53834C-2@192.168.1.3:OTNRESGK2H1HT7GQ1GEICJ025G000001:
08:02:58.648 SIPCONN(VOIP_DN): HandleSipDialogEvent(CONNECTED_SEND_ACK) - filtered
08:02:58.649: SIPTR(6): complete
08:02:58.649: SIPTR(0): Step 0 - SipTransactionConnectMediaService(6) complete
08:02:58.649: SIPTR(0): Begin step 1 - SipTransactionProcessMsml(7)
08:02:58.651 SIPCONN(VOIP_DN): CtiRequest(3)
08:02:58.651: SIPDLG[8]: register TRN[9]
08:02:58.651: Sending [0,UDP] 865 bytes to 192.168.1.3:5090 >>>>>
INFO sip:Genesys@192.168.1.3:5070 SIP/2.0
From: sip:9001@192.168.1.3:5060;tag=84F6DEC0-281E-4D6E-A949-F898B252DD59-6
To: sip:VOIP_DN@192.168.1.3:5060;tag=6675E895-D1AB-494B-BDAB-D74D0D3FFA82
Call-ID: 2D4D7F5F-0615-4B50-8241-59CD1D53834C-2@192.168.1.3
CSeq: 2 INFO
Content-Length: 294
Content-Type: application/vnd.radisys.msml+xml
Via: SIP/2.0/UDP 192.168.1.3:5060;branch=z9hG4bK1ED03076-1788-45F1-8FAD-4D0C45FA92E9-4
Contact: sip:9001@192.168.1.3:5060
Max-Forwards: 69
Route: sip:0000000015B36FF0@192.168.1.3:5090;lr;gvp.rm.datanodes=1;idtag=00000002

<?xml version="1.0" encoding="UTF-8"?>

Kubig · December 28, 2016, 3:24pm

Check or post MCP logs to find out what is wrong. From the logs it seems like IVR proflie is not configured properly and MCP has nothing to play.

ankush87 · December 28, 2016, 6:00pm

Hi Kubig,

Thanks for the reply, please find the MCP logs attached

ankush87 · December 29, 2016, 5:30am

Ptr<00000000180A4C10> CAddr<192.168.1.3:49283>
2016-12-28T17:29:27.378 Trc 33009 INFO 00000000-00000000 2436 02800FA1 Request received: INVITE sip:dialog@192.168.1.3:5070;gvp-tenant-id=[Environment].newone;gvp.appmodule=VXML-NG;record-ivr-profile=[Environment].VP_defaultApp;trunkport=2200;voicexml=http://192.168.1.3:8088/GVP_1/src-gen/Main.vxml SIP/2.0
Via: SIP/2.0/TCP 192.168.1.3:5090;branch=z9hG4bK0000000003F6F8F063f677abcdef09
Via: SIP/2.0/UDP 192.168.1.3:5060;branch=z9hG4bKA5C455CC-7BF6-465C-B829-C963B9792B44-16
From: sip:9001@192.168.1.3:5060;tag=387C08A9-E401-49D1-BBB0-321120F1EF4B-13
To: sip:2200@192.168.1.3:5060
Max-Forwards: 68
CSeq: 1 INVITE
Call-ID: 46F61B0A-6ECC-4135-AA1A-1E5C91051E4B-6@192.168.1.3
Contact: sip:9001@192.168.1.3:5060
Content-Length: 327
Content-Type: application/sdp
Record-Route: sip:000000000A742460@192.168.1.3:5090;transport=TCP;lr;gvp.rm.datanodes=1;idtag=00000006
Allow: ACK, BYE, CANCEL, INFO, INVITE, MESSAGE, NOTIFY, OPTIONS, PRACK, REFER, UPDATE
User-Agent: X-Lite release 4.9.6 stamp 82158
X-Genesys-CallUUID: 4M5C4RPIFT7I702UNTI5DMAO7K000004
Session-Expires: 1800;refresher=uac
Min-SE: 90
Supported: uui,100rel,timer
X-Genesys-GVP-Session-ID: 8A908C9C-4C6A-40CE-CDB7-8BB0A371C97C;gvp.rm.datanodes=1;gvp.rm.tenant-id=1_newone
X-Genesys-RM-Application-dbid: 106
X-Genesys-GVP-Session-Data: callsession=8A908C9C-4C6A-40CE-CDB7-8BB0A371C97C;1;0;;;;Environment;newone;;0;VP_defaultApp

v=0
o=- 1482944147 1 IN IP4 192.168.1.54
s=X-Lite release 4.9.6 stamp 82158
c=IN IP4 192.168.1.54
t=0 0
m=audio 60224 RTP/AVP 9 8 120 0 84 101
a=sendrecv
a=rtpmap:120 opus/48000/2
a=fmtp:120 useinbandfec=1; usedtx=1; maxaveragebitrate=64000
a=rtpmap:84 speex/16000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

2016-12-28 17:29:27.379 DBUG 00000000-00000000 2436 08500000 VGSIPTransportMgr.cxx:3637 VGSIPTransportMgr::ResolveDNS for 192.168.1.3:5090
2016-12-28 17:29:27.379 DBUG 00000000-00000000 2436 08500000 VGSIPTransportMgr.cxx:3752 VGSIPTransportMgr::ResolveDNS nResult 2; CallID46F61B0A-6ECC-4135-AA1A-1E5C91051E4B-6@192.168.1.3
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 02800000 LMCallSIPHandler.C:153 LMCallSIP::HandleDerivedEvent - nEventType=0, m_nState=0, m_nIntfState=0
2016-12-28T17:29:27.379 Trc 33009 INFO 00000000-00000000 2436 02800FA1 Response sent: SIP/2.0 100 Trying
Via: SIP/2.0/TCP 192.168.1.3:5090;branch=z9hG4bK0000000003F6F8F063f677abcdef09
Via: SIP/2.0/UDP 192.168.1.3:5060;branch=z9hG4bKA5C455CC-7BF6-465C-B829-C963B9792B44-16
From: sip:9001@192.168.1.3:5060;tag=387C08A9-E401-49D1-BBB0-321120F1EF4B-13
To: sip:2200@192.168.1.3:5060
CSeq: 1 INVITE
Call-ID: 46F61B0A-6ECC-4135-AA1A-1E5C91051E4B-6@192.168.1.3
Content-Length: 0
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 02800000 LMCallSIPHandler.C:1008 LMCallSIP::HandleSipInvite - pszName=[gvp-tenant-id], pszValue=[[Environment].newone]
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 02800000 LMCallSIPHandler.C:1008 LMCallSIP::HandleSipInvite - pszName=[gvp.appmodule], pszValue=[VXML-NG]
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 02800000 LMCallSIPHandler.C:1008 LMCallSIP::HandleSipInvite - pszName=[record-ivr-profile], pszValue=[[Environment].VP_defaultApp]
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 02800000 LMCallSIPHandler.C:1008 LMCallSIP::HandleSipInvite - pszName=[trunkport], pszValue=[2200]
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 02800000 LMCallSIPHandler.C:1008 LMCallSIP::HandleSipInvite - pszName=[voicexml], pszValue=[http://192.168.1.3:8088/GVP_1/src-gen/Main.vxml]
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[sip.warningheaders]; Value=; [Local]
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 02800000 LMSIPSessionConfig.C:154 LMSIPSessionConfig - Local: Param=sip.warningheaders; Value=; Found=No
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[sip.sdpwarningheaders]; Value=; [Local]
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 02800000 LMSIPSessionConfig.C:154 LMSIPSessionConfig - Local: Param=sip.sdpwarningheaders; Value=; Found=No
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[sip.passertedidentity]; Value=; [Local]
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 02800000 LMSIPSessionConfig.C:154 LMSIPSessionConfig - Local: Param=sip.passertedidentity; Value=; Found=No
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[sip.pcalledpartyid]; Value=; [Local]
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 02800000 LMSIPSessionConfig.C:154 LMSIPSessionConfig - Local: Param=sip.pcalledpartyid; Value=; Found=No
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[sip.p-alcatel-csbu]; Value=; [Local]
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 02800000 LMSIPSessionConfig.C:154 LMSIPSessionConfig - Local: Param=sip.p-alcatel-csbu; Value=; Found=No
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[sip.sendalert]; Value=; [Local]
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 02800000 LMSIPSessionConfig.C:154 LMSIPSessionConfig - Local: Param=sip.sendalert; Value=; Found=No
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[sip.sdpansinprov]; Value=; [Local]
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 02800000 LMSIPSessionConfig.C:154 LMSIPSessionConfig - Local: Param=sip.sdpansinprov; Value=; Found=No
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[sip.enablesendrecvevents]; Value=; [Local]
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 02800000 LMSIPSessionConfig.C:154 LMSIPSessionConfig - Local: Param=sip.enablesendrecvevents; Value=; Found=No
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[cpa.outbound.method]; Value=; [Local]
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 02800000 LMSIPSessionConfig.C:154 LMSIPSessionConfig - Local: Param=cpa.outbound.method; Value=; Found=No
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[cpa.gateway.events]; Value=; [Local]
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 02800000 LMSIPSessionConfig.C:154 LMSIPSessionConfig - Local: Param=cpa.gateway.events; Value=; Found=No
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[cpa.outbound.native.initialstate]; Value=; [Local]
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 02800000 LMSIPSessionConfig.C:154 LMSIPSessionConfig - Local: Param=cpa.outbound.native.initialstate; Value=; Found=No
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[cpa.outbound.native.ignoreconnectevent]; Value=; [Local]
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 02800000 LMSIPSessionConfig.C:154 LMSIPSessionConfig - Local: Param=cpa.outbound.native.ignoreconnectevent; Value=; Found=No
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[sessmgr.mrt.sendsdpininvite]; Value=; [Local]
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 02800000 LMSIPSessionConfig.C:154 LMSIPSessionConfig - Local: Param=sessmgr.mrt.sendsdpininvite; Value=; Found=No
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[asr.reserve]; Value=; [Local]
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 02800000 LMSIPSessionConfig.C:154 LMSIPSessionConfig - Local: Param=asr.reserve; Value=; Found=No
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[tts.reserve]; Value=; [Local]
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 02800000 LMSIPSessionConfig.C:154 LMSIPSessionConfig - Local: Param=tts.reserve; Value=; Found=No
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[asr.load_once_per_call]; Value=; [Local]
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 02800000 LMSIPSessionConfig.C:154 LMSIPSessionConfig - Local: Param=asr.load_once_per_call; Value=; Found=No
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[asr.log_metrics_to_asr]; Value=; [Local]
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 02800000 LMSIPSessionConfig.C:154 LMSIPSessionConfig - Local: Param=asr.log_metrics_to_asr; Value=; Found=No
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[asr.defaultengine]; Value=; [Local]
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 02800000 LMSIPSessionConfig.C:154 LMSIPSessionConfig - Local: Param=asr.defaultengine; Value=; Found=No
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[tts.defaultengine]; Value=; [Local]
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 02800000 LMSIPSessionConfig.C:154 LMSIPSessionConfig - Local: Param=tts.defaultengine; Value=; Found=No
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[sip.userouteonrecording]; Value=; [Local]
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 02800000 LMSIPSessionConfig.C:154 LMSIPSessionConfig - Local: Param=sip.userouteonrecording; Value=; Found=No
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[sip.handlesessionrefreshsdp]; Value=; [Local]
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 02800000 LMSIPSessionConfig.C:154 LMSIPSessionConfig - Local: Param=sip.handlesessionrefreshsdp; Value=; Found=No
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 02800000 LMCallSIPHandler.C:3426 LMCallSIP::AddCallToLogging - CallInit called - szComponentId=00760186-100032C9, strSessionId=8A908C9C-4C6A-40CE-CDB7-8BB0A371C97C, strTenantId=1 callCreateTime=16-12-28 17:29:27.379 strAppId=106
2016-12-28 17:29:27.380 DBUG 00760186-100032C9 688 02800000 LMCallSIPUtil.C:794 PushBackUnknownHeaders: Prefix=[Sip.Invite.]
2016-12-28 17:29:27.380 DBUG 00760186-100032C9 688 02800000 LMCallSIPUtil.C:811 LMCallSIP::PushBackUnknownHeaders - Pushing Back Header - Name=Allow, Value=ACK, BYE, CANCEL, INFO, INVITE, MESSAGE, NOTIFY, OPTIONS, PRACK, REFER, UPDATE
2016-12-28 17:29:27.380 DBUG 00760186-100032C9 688 02800000 LMCallSIPUtil.C:822 LMCallSIP::PushBackUnknownHeaders - Unknown Header Not Found
2016-12-28 17:29:27.380 DBUG 00760186-100032C9 688 02800000 LMCallSIPUtil.C:811 LMCallSIP::PushBackUnknownHeaders - Pushing Back Header - Name=User-Agent, Value=X-Lite release 4.9.6 stamp 82158
2016-12-28 17:29:27.380 DBUG 00760186-100032C9 688 02800000 LMCallSIPUtil.C:822 LMCallSIP::PushBackUnknownHeaders - Unknown Header Not Found
2016-12-28 17:29:27.380 DBUG 00760186-100032C9 688 02800000 LMCallSIPUtil.C:811 LMCallSIP::PushBackUnknownHeaders - Pushing Back Header - Name=X-Genesys-CallUUID, Value=4M5C4RPIFT7I702UNTI5DMAO7K000004
2016-12-28 17:29:27.380 DBUG 00760186-100032C9 688 02800000 LMCallSIPUtil.C:811 LMCallSIP::PushBackUnknownHeaders - Pushing Back Header - Name=X-Genesys-GVP-Session-ID, Value=8A908C9C-4C6A-40CE-CDB7-8BB0A371C97C;gvp.rm.datanodes=1;gvp.rm.tenant-id=1_newone
2016-12-28 17:29:27.380 DBUG 00760186-100032C9 688 02800000 LMCallSIPUtil.C:822 LMCallSIP::PushBackUnknownHeaders - Unknown Header Not Found
2016-12-28 17:29:27.380 DBUG 00760186-100032C9 688 02800000 LMCallSIPUtil.C:811 LMCallSIP::PushBackUnknownHeaders - Pushing Back Header - Name=X-Genesys-RM-Application-dbid, Value=106
2016-12-28 17:29:27.380 DBUG 00760186-100032C9 688 02800000 LMCallSIPUtil.C:822 LMCallSIP::PushBackUnknownHeaders - Unknown Header Not Found
2016-12-28 17:29:27.380 DBUG 00760186-100032C9 688 02800000 LMCallSIPUtil.C:811 LMCallSIP::PushBackUnknownHeaders - Pushing Back Header - Name=X-Genesys-GVP-Session-Data, Value=callsession=8A908C9C-4C6A-40CE-CDB7-8BB0A371C97C;1;0;;;;Environment;newone;;0;VP_defaultApp
2016-12-28 17:29:27.380 DBUG 00760186-100032C9 688 02800000 LMCallSIPUtil.C:822 LMCallSIP::PushBackUnknownHeaders - Unknown Header Not Found
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 02F00000 MPCWrapper.cxx:568 Creating Media RTP Session
2016-12-28 17:29:27.381 DBUG 00000000-00000000 688 0B100000 MPCConnection.cxx:96 MPCConnection::MPCConnection nLogID=00760186-100032C9 nConnID=1000002F this=000000001D828CD0
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[mpc.codec]; Value=; [Local]
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 MPCSessionConfig.cxx:375 MPCSessionConfig - Local: Param=mpc.codec; Value=; Found=No
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[mpc.codecpref]; Value=; [Local]
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 MPCSessionConfig.cxx:375 MPCSessionConfig - Local: Param=mpc.codecpref; Value=; Found=No
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[mpc.fcr.defaultdtmfhandling]; Value=; [Local]
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 MPCSessionConfig.cxx:375 MPCSessionConfig - Local: Param=mpc.fcr.defaultdtmfhandling; Value=; Found=No
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[mpc.transmitmultiplecodec]; Value=; [Local]
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 MPCSessionConfig.cxx:375 MPCSessionConfig - Local: Param=mpc.transmitmultiplecodec; Value=; Found=No
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[mpc.appendrejcodec]; Value=; [Local]
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 MPCSessionConfig.cxx:375 MPCSessionConfig - Local: Param=mpc.appendrejcodec; Value=; Found=No
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[mpc.rtp.dtmf.receive]; Value=; [Local]
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 MPCSessionConfig.cxx:375 MPCSessionConfig - Local: Param=mpc.rtp.dtmf.receive; Value=; Found=No
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[mpc.rtp.dtmf.send]; Value=; [Local]
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 MPCSessionConfig.cxx:375 MPCSessionConfig - Local: Param=mpc.rtp.dtmf.send; Value=; Found=No
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[mpc.record.defaultdtmfhandling]; Value=; [Local]
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 MPCSessionConfig.cxx:375 MPCSessionConfig - Local: Param=mpc.record.defaultdtmfhandling; Value=; Found=No
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[mpc.disabledcodecs]; Value=; [Local]
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 MPCSessionConfig.cxx:375 MPCSessionConfig - Local: Param=mpc.disabledcodecs; Value=; Found=No
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[mpc.disabledtranscoders]; Value=; [Local]
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 MPCSessionConfig.cxx:375 MPCSessionConfig - Local: Param=mpc.disabledtranscoders; Value=; Found=No
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[mpc.rtp.tos]; Value=; [Local]
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 MPCSessionConfig.cxx:375 MPCSessionConfig - Local: Param=mpc.rtp.tos; Value=; Found=No
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[mpc.rtp.tos.video]; Value=; [Local]
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 MPCSessionConfig.cxx:375 MPCSessionConfig - Local: Param=mpc.rtp.tos.video; Value=; Found=No
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[mpc.rtcp.tos]; Value=; [Local]
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 MPCSessionConfig.cxx:375 MPCSessionConfig - Local: Param=mpc.rtcp.tos; Value=; Found=No
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[mpc.rtcp.tos.video]; Value=; [Local]
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 MPCSessionConfig.cxx:375 MPCSessionConfig - Local: Param=mpc.rtcp.tos.video; Value=; Found=No
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[mpc.maxrecordfilesize]; Value=; [Local]
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 MPCSessionConfig.cxx:375 MPCSessionConfig - Local: Param=mpc.maxrecordfilesize; Value=; Found=No
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[mpc.rtp.request_iframe]; Value=; [Local]
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 MPCSessionConfig.cxx:375 MPCSessionConfig - Local: Param=mpc.rtp.request_iframe; Value=; Found=No
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[mpc.conference.allowloudestvideoecho]; Value=; [Local]
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 MPCSessionConfig.cxx:375 MPCSessionConfig - Local: Param=mpc.conference.allowloudestvideoecho; Value=; Found=No
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[mpc.videotranscoder.checkframerate]; Value=; [Local]
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 MPCSessionConfig.cxx:375 MPCSessionConfig - Local: Param=mpc.videotranscoder.checkframerate; Value=; Found=No
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[mpc.videotranscoder.checkbitrate]; Value=; [Local]
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 MPCSessionConfig.cxx:375 MPCSessionConfig - Local: Param=mpc.videotranscoder.checkbitrate; Value=; Found=No
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[mpc.videotranscoder.maxbitrate]; Value=; [Local]
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 MPCSessionConfig.cxx:375 MPCSessionConfig - Local: Param=mpc.videotranscoder.maxbitrate; Value=; Found=No
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[mpc.rtp.source_buffer_video_size]; Value=; [Local]
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 MPCSessionConfig.cxx:375 MPCSessionConfig - Local: Param=mpc.rtp.source_buffer_video_size; Value=; Found=No
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[mpc.rtp.source_buffer_video_data_size]; Value=; [Local]
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 MPCSessionConfig.cxx:375 MPCSessionConfig - Local: Param=mpc.rtp.source_buffer_video_data_size; Value=; Found=No
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[mpc.dsp.g726littleendian]; Value=; [Local]
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 MPCSessionConfig.cxx:375 MPCSessionConfig - Local: Param=mpc.dsp.g726littleendian; Value=; Found=No
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[conference.novideoimage]; Value=; [Local]
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 MPCSessionConfig.cxx:375 MPCSessionConfig - Local: Param=conference.novideoimage; Value=; Found=No
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[mpc.playcache.enable]; Value=; [Local]
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 MPCSessionConfig.cxx:375 MPCSessionConfig - Local: Param=mpc.playcache.enable; Value=; Found=No
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[mpc.playcache.checkversiontime]; Value=; [Local]
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 MPCSessionConfig.cxx:375 MPCSessionConfig - Local: Param=mpc.playcache.checkversiontime; Value=; Found=No
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[mpc.ice.level]; Value=; [Local]
2016-12-28 17:29:27.381 DBUG 00760186-100032C9 688 08500000 MPCSessionConfig.cxx:375 MPCSessionConfig - Local: Param=mpc.ice.level; Value=; Found=No

2016-12-28 17:29:27.382 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:86 SessConfig::GetValue - Param=[mpc.cpa.cm_match_percent]; Value=; [Local]
2016-12-28 17:29:27.382 DBUG 00760186-100032C9 688 0B400000 DSPCPACarrierMsgConfig.cxx:105 DSPCPACarrierMsgConfig - Local: Param=mpc.cpa.cm_match_percent; Value=; Found=No
2016-12-28 17:29:27.382 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:112 SessConfig::GetValue - Param=[mpc.codec]; Value=[pcmu pcma g722 g726 g729 gsm amr amr-wb h263 h263-1998 h264 vp8 telephone-event]; [Global]
2016-12-28 17:29:27.382 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:112 SessConfig::GetValue - Param=[mpc.srtp.mode]; Value=[none]; [Global]
2016-12-28 17:29:27.382 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:112 SessConfig::GetValue - Param=[mpc.srtp.cryptomethods]; Value=[AES_CM_128_HMAC_SHA1_80]; [Global]
2016-12-28 17:29:27.382 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:112 SessConfig::GetValue - Param=[mpc.srtp.sessionparamsoffer]; Value=[none]; [Global]
2016-12-28 17:29:27.382 DBUG 00760186-100032C9 688 08500000 SessionConfiguration.C:112 SessConfig::GetValue - Param=[mpc.srtp.sessionparams]; Value=[UNENCRYPTED_SRTP UNENCRYPTED_SRTCP UNAUTHENTICATED_SRTP]; [Global]
2016-12-28 17:29:27.383 DBUG 00000000-00000000 688 08500000 VGRTPTypes.cxx:585 RTPMediaDescriptor::VGSdpToRTPMediaDescList - pSDP->m_bIsReceived=[true], pSDP->GetRawMessage()=[v=0
o=- 1482944147 1 IN IP4 192.168.1.54
s=X-Lite release 4.9.6 stamp 82158
c=IN IP4 192.168.1.54
t=0 0
m=audio 60224 RTP/AVP 9 8 120 0 84 101
a=sendrecv
a=rtpmap:120 opus/48000/2
a=fmtp:120 useinbandfec=1; usedtx=1; maxaveragebitrate=64000
a=rtpmap:84 speex/16000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
2016-12-28 17:29:27.386 DBUG 00000000-00000000 688 08500000 VGRTPTypes.cxx:1474 ParseSDPConnectionString - pszConnection=[IN IP4 192.168.1.3]
2016-12-28 17:29:27.386 DBUG 00000000-00000000 688 08500000 VGRTPTypes.cxx:914 Clock rate found for m-line #0
2016-12-28 17:29:27.386 DBUG 00000000-00000000 688 08500000 VGRTPTypes.cxx:914 Clock rate found for m-line #0
2016-12-28 17:29:27.386 DBUG 00000000-00000000 688 08500000 VGRTPTypes.cxx:914 Clock rate found for m-line #0
2016-12-28 17:29:27.386 DBUG 00000000-00000000 688 08500000 VGRTPTypes.cxx:914 Clock rate found for m-line #0
2016-12-28 17:29:27.386 DBUG 00000000-00000000 688 08500000 VGRTPTypes.cxx:1460 Adding m-line #0 to media desc list: RTPMEDIADESC =
m_nMediaType=[audio]
m_nDirection=[sendrecv]
m_saLocalRTP=[192.168.1.3:20000]
m_listSaRemoteRTPs=
m_strMLineValue=[audio 20000 RTP/AVP 9 8 0 101]
m_bActivated=[false]
m_bIsPLIFBMessage=[false]
m_listFormat[m_nFormat=[4], m_MediaInfo=, m_nClockRate=[8000], m_nTXRate=[0], m_cTxPayload=[127], m_cRxPayload=[9], m_strVideoProperties=
m_nFormat=[3], m_MediaInfo=, m_nClockRate=[8000], m_nTXRate=[0], m_cTxPayload=[127], m_cRxPayload=[8], m_strVideoProperties=
m_nFormat=[2], m_MediaInfo=, m_nClockRate=[8000], m_nTXRate=[0], m_cTxPayload=[127], m_cRxPayload=[0], m_strVideoProperties=
m_nFormat=[30], m_MediaInfo=, m_nClockRate=[8000], m_nTXRate=[0], m_cTxPayload=[127], m_cRxPayload=[101], m_strVideoProperties=
016-12-28 17:29:27.387 DBUG 00760186-100032C9 688 02F00000 MPCWrapper.cxx:681 Registering the Session 268435503
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 688 02800000 LMCallSIP.C:2719 LMCallSIP::CreateRTPSession finished successfully
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 688 02800000 LMCallSIP.C:3280 LMCallSIP::OpenMRCPResources - bASRReserve=false, bTTSReserve=false, bASRLoadOnce=true, bASRLogMetrics=false, strASRDefault=default, strTTSDefault=default
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 688 02800000 LMCallSIPHandler.C:2186 Received INVITE; ID=46F61B0A-6ECC-4135-AA1A-1E5C91051E4B-6@192.168.1.3/ANI=sip:9001@192.168.1.3:5060/DNIS=sip:2200@192.168.1.3:5060
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 688 02800000 LMCallSIP.C:2043 Media session registered, m_nState=0
2016-12-28 17:29:27.387 DBUG 00000000-00000000 3668 01C00000 CMMsgBase.h:186 cmapi.msg: CM_MSG_LMCC_CALLINOFFERED - 00760186-100032C9; CallRef=46F61B0A-6ECC-4135-AA1A-1E5C91051E4B-6@192.168.1.3; CallAddress=sip:2200@192.168.1.3:5060; ANI=sip:9001@192.168.1.3:5060; DNIS=sip:2200@192.168.1.3:5060; CPAType=voice
2016-12-28 17:29:27.387 DBUG 00000000-00000000 3668 01C00000 CMCallManager.C:262 license usage:
2016-12-28 17:29:27.387 DBUG 00000000-00000000 3668 02400000 GVPLicenseLogger.C:89 Acquire GVP License:Product=vggateway; Features=in; Current Use=1; Peak Use=1
2016-12-28 17:29:27.387 DBUG 00000000-00000000 3668 01C00000 CMCallManager.C:269 Acquired license 1D7D8070 type 0
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=RURIUSER, m_Value=dialog
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=LOGCALLDIR, m_Value=INBOUND
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=SIPLOCALTAG, m_Value=A7DE953D-F35C-47F2-4899-2B9721EC0BA7
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=initial-url, m_Value=http://192.168.1.3:8088/GVP_1/src-gen/Main.vxml
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=gvp.appmodule, m_Value=VXML-NG
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=REDIRECT, m_Value=sip:2200@192.168.1.3:5060|N/A|N/A|unknown
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=CALLIDREF, m_Value=46F61B0A-6ECC-4135-AA1A-1E5C91051E4B-6@192.168.1.3
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=PROTOCOLNAME, m_Value=sip
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=PROTOCOLVERSION, m_Value=2.0
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=INITINFO, m_Value=0:0
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=XGENESYSCALLUUID, m_Value=4M5C4RPIFT7I702UNTI5DMAO7K000004
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=XGENESYSGVPSESSIONID, m_Value=8A908C9C-4C6A-40CE-CDB7-8BB0A371C97C
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=XGENESYSTENANTID, m_Value=1_newone
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=XGENESYSAPPDBID, m_Value=106
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.RequestURI, m_Value=sip:dialog@192.168.1.3:5070;gvp-tenant-id=[Environment].newone;gvp.appmodule=VXML-NG;record-ivr-profile=[Environment].VP_defaultApp;trunkport=2200;voicexml=http://192.168.1.3:8088/GVP_1/src-gen/Main.vxml
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.allow, m_Value=ACK, BYE, CANCEL, INFO, INVITE, MESSAGE, NOTIFY, OPTIONS, PRACK, REFER, UPDATE
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.min-se, m_Value=90
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.session-expires, m_Value=1800;refresher=uac
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.supported, m_Value=uui,100rel,timer
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.user-agent, m_Value=X-Lite release 4.9.6 stamp 82158
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.x-genesys-calluuid, m_Value=4M5C4RPIFT7I702UNTI5DMAO7K000004
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.x-genesys-gvp-session-data, m_Value=callsession=8A908C9C-4C6A-40CE-CDB7-8BB0A371C97C;1;0;;;;Environment;newone;;0;VP_defaultApp
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.x-genesys-gvp-session-id, m_Value=8A908C9C-4C6A-40CE-CDB7-8BB0A371C97C;gvp.rm.datanodes=1;gvp.rm.tenant-id=1_newone
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.x-genesys-rm-application-dbid, m_Value=106
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.originalcase.Allow, m_Value=ACK, BYE, CANCEL, INFO, INVITE, MESSAGE, NOTIFY, OPTIONS, PRACK, REFER, UPDATE
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.originalcase.Min-SE, m_Value=90
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.originalcase.Session-Expires, m_Value=1800;refresher=uac
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.originalcase.Supported, m_Value=uui,100rel,timer
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.originalcase.User-Agent, m_Value=X-Lite release 4.9.6 stamp 82158
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.originalcase.X-Genesys-CallUUID, m_Value=4M5C4RPIFT7I702UNTI5DMAO7K000004
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.originalcase.X-Genesys-GVP-Session-Data, m_Value=callsession=8A908C9C-4C6A-40CE-CDB7-8BB0A371C97C;1;0;;;;Environment;newone;;0;VP_defaultApp
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.originalcase.X-Genesys-GVP-Session-ID, m_Value=8A908C9C-4C6A-40CE-CDB7-8BB0A371C97C;gvp.rm.datanodes=1;gvp.rm.tenant-id=1_newone
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.originalcase.X-Genesys-RM-Application-dbid, m_Value=106
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.via, m_Value=SIP/2.0/TCP 192.168.1.3:5090;branch=z9hG4bK0000000003F6F8F063f677abcdef09,SIP/2.0/UDP 192.168.1.3:5060;branch=z9hG4bKA5C455CC-7BF6-465C-B829-C963B9792B44-16
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.from, m_Value=sip:9001@192.168.1.3:5060;tag=387C08A9-E401-49D1-BBB0-321120F1EF4B-13
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.to, m_Value=sip:2200@192.168.1.3:5060
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.max-forwards, m_Value=68
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.cseq, m_Value=1 INVITE
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.call-id, m_Value=46F61B0A-6ECC-4135-AA1A-1E5C91051E4B-6@192.168.1.3
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.contact, m_Value=sip:9001@192.168.1.3:5060
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.content-length, m_Value=327
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.content-type, m_Value=application/sdp
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.record-route, m_Value=sip:000000000A742460@192.168.1.3:5090;transport=TCP;lr;gvp.rm.datanodes=1;idtag=00000006
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.RequestURI.gvp-tenant-id, m_Value=[Environment].newone
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.RequestURI.gvp.appmodule, m_Value=VXML-NG
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.RequestURI.record-ivr-profile, m_Value=[Environment].VP_defaultApp
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.RequestURI.trunkport, m_Value=2200
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.RequestURI.voicexml, m_Value=http://192.168.1.3:8088/GVP_1/src-gen/Main.vxml
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Body, m_Value=v=0
o=- 1482944147 1 IN IP4 192.168.1.54
s=X-Lite release 4.9.6 stamp 82158
c=IN IP4 192.168.1.54
t=0 0
m=audio 60224 RTP/AVP 9 8 120 0 84 101
a=sendrecv
a=rtpmap:120 opus/48000/2
a=fmtp:120 useinbandfec=1; usedtx=1; maxaveragebitrate=64000
a=rtpmap:84 speex/16000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

ankush87 · December 29, 2016, 5:34am

2016-12-28 17:29:27.331 DBUG 00000000-00000000 2436 08500000 VGSocketMgr.C:240 Calling VGSocketMgr::SocketAcceptNew on socket
2016-12-28 17:29:27.331 DBUG 00000000-00000000 2436 08500000 VGSIPTransportTCP.cxx:62 VGSIPTransportTCP::TCPConnection::Initialize SIPTransportTCP_Port<5070> TPtr<00000000157388F0> CPtr<00000000180A4C10> CAddr<192.168.1.3:49283>
2016-12-28T17:29:27.378 Trc 33009 INFO 00000000-00000000 2436 02800FA1 Request received: INVITE sip:dialog@192.168.1.3:5070;gvp-tenant-id=[Environment].newone;gvp.appmodule=VXML-NG;record-ivr-profile=[Environment].VP_defaultApp;trunkport=2200;voicexml=http://192.168.1.3:8088/GVP_1/src-gen/Main.vxml SIP/2.0
Via: SIP/2.0/TCP 192.168.1.3:5090;branch=z9hG4bK0000000003F6F8F063f677abcdef09
Via: SIP/2.0/UDP 192.168.1.3:5060;branch=z9hG4bKA5C455CC-7BF6-465C-B829-C963B9792B44-16
From: sip:9001@192.168.1.3:5060;tag=387C08A9-E401-49D1-BBB0-321120F1EF4B-13
To: sip:2200@192.168.1.3:5060
Max-Forwards: 68
CSeq: 1 INVITE
Call-ID: 46F61B0A-6ECC-4135-AA1A-1E5C91051E4B-6@192.168.1.3
Contact: sip:9001@192.168.1.3:5060
Content-Length: 327
Content-Type: application/sdp
Record-Route: sip:000000000A742460@192.168.1.3:5090;transport=TCP;lr;gvp.rm.datanodes=1;idtag=00000006
Allow: ACK, BYE, CANCEL, INFO, INVITE, MESSAGE, NOTIFY, OPTIONS, PRACK, REFER, UPDATE
User-Agent: X-Lite release 4.9.6 stamp 82158
X-Genesys-CallUUID: 4M5C4RPIFT7I702UNTI5DMAO7K000004
Session-Expires: 1800;refresher=uac
Min-SE: 90
Supported: uui,100rel,timer
X-Genesys-GVP-Session-ID: 8A908C9C-4C6A-40CE-CDB7-8BB0A371C97C;gvp.rm.datanodes=1;gvp.rm.tenant-id=1_newone
X-Genesys-RM-Application-dbid: 106
X-Genesys-GVP-Session-Data: callsession=8A908C9C-4C6A-40CE-CDB7-8BB0A371C97C;1;0;;;;Environment;newone;;0;VP_defaultApp

v=0
o=- 1482944147 1 IN IP4 192.168.1.54
s=X-Lite release 4.9.6 stamp 82158
c=IN IP4 192.168.1.54
t=0 0
m=audio 60224 RTP/AVP 9 8 120 0 84 101
a=sendrecv
a=rtpmap:120 opus/48000/2
a=fmtp:120 useinbandfec=1; usedtx=1; maxaveragebitrate=64000
a=rtpmap:84 speex/16000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

2016-12-28 17:29:27.379 DBUG 00000000-00000000 2436 08500000 VGSIPTransportMgr.cxx:3637 VGSIPTransportMgr::ResolveDNS for 192.168.1.3:5090
2016-12-28 17:29:27.379 DBUG 00000000-00000000 2436 08500000 VGSIPTransportMgr.cxx:3752 VGSIPTransportMgr::ResolveDNS nResult 2; CallID46F61B0A-6ECC-4135-AA1A-1E5C91051E4B-6@192.168.1.3
2016-12-28 17:29:27.379 DBUG 00760186-100032C9 688 02800000 LMCallSIPHandler.C:153 LMCallSIP::HandleDerivedEvent - nEventType=0, m_nState=0, m_nIntfState=0
2016-12-28T17:29:27.379 Trc 33009 INFO 00000000-00000000 2436 02800FA1 Response sent: SIP/2.0 100 Trying
Via: SIP/2.0/TCP 192.168.1.3:5090;branch=z9hG4bK0000000003F6F8F063f677abcdef09
Via: SIP/2.0/UDP 192.168.1.3:5060;branch=z9hG4bKA5C455CC-7BF6-465C-B829-C963B9792B44-16
From: sip:9001@192.168.1.3:5060;tag=387C08A9-E401-49D1-BBB0-321120F1EF4B-13
To: sip:2200@192.168.1.3:5060
CSeq: 1 INVITE
Call-ID: 46F61B0A-6ECC-4135-AA1A-1E5C91051E4B-6@192.168.1.3
Content-Length: 0

2016-12-28 17:29:27.387 DBUG 00760186-100032C9 688 02800000 LMCallSIPHandler.C:2186 Received INVITE; ID=46F61B0A-6ECC-4135-AA1A-1E5C91051E4B-6@192.168.1.3/ANI=sip:9001@192.168.1.3:5060/DNIS=sip:2200@192.168.1.3:5060
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 688 02800000 LMCallSIP.C:2043 Media session registered, m_nState=0
2016-12-28 17:29:27.387 DBUG 00000000-00000000 3668 01C00000 CMMsgBase.h:186 cmapi.msg: CM_MSG_LMCC_CALLINOFFERED - 00760186-100032C9; CallRef=46F61B0A-6ECC-4135-AA1A-1E5C91051E4B-6@192.168.1.3; CallAddress=sip:2200@192.168.1.3:5060; ANI=sip:9001@192.168.1.3:5060; DNIS=sip:2200@192.168.1.3:5060; CPAType=voice
2016-12-28 17:29:27.387 DBUG 00000000-00000000 3668 01C00000 CMCallManager.C:262 license usage:
2016-12-28 17:29:27.387 DBUG 00000000-00000000 3668 02400000 GVPLicenseLogger.C:89 Acquire GVP License:Product=vggateway; Features=in; Current Use=1; Peak Use=1
2016-12-28 17:29:27.387 DBUG 00000000-00000000 3668 01C00000 CMCallManager.C:269 Acquired license 1D7D8070 type 0
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=RURIUSER, m_Value=dialog
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=LOGCALLDIR, m_Value=INBOUND
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=SIPLOCALTAG, m_Value=A7DE953D-F35C-47F2-4899-2B9721EC0BA7
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=initial-url, m_Value=http://192.168.1.3:8088/GVP_1/src-gen/Main.vxml
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=gvp.appmodule, m_Value=VXML-NG
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=REDIRECT, m_Value=sip:2200@192.168.1.3:5060|N/A|N/A|unknown
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=CALLIDREF, m_Value=46F61B0A-6ECC-4135-AA1A-1E5C91051E4B-6@192.168.1.3
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=PROTOCOLNAME, m_Value=sip
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=PROTOCOLVERSION, m_Value=2.0
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=INITINFO, m_Value=0:0
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=XGENESYSCALLUUID, m_Value=4M5C4RPIFT7I702UNTI5DMAO7K000004
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=XGENESYSGVPSESSIONID, m_Value=8A908C9C-4C6A-40CE-CDB7-8BB0A371C97C
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=XGENESYSTENANTID, m_Value=1_newone
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=XGENESYSAPPDBID, m_Value=106
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.RequestURI, m_Value=sip:dialog@192.168.1.3:5070;gvp-tenant-id=[Environment].newone;gvp.appmodule=VXML-NG;record-ivr-profile=[Environment].VP_defaultApp;trunkport=2200;voicexml=http://192.168.1.3:8088/GVP_1/src-gen/Main.vxml
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.allow, m_Value=ACK, BYE, CANCEL, INFO, INVITE, MESSAGE, NOTIFY, OPTIONS, PRACK, REFER, UPDATE
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.min-se, m_Value=90
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.session-expires, m_Value=1800;refresher=uac
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.supported, m_Value=uui,100rel,timer
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.user-agent, m_Value=X-Lite release 4.9.6 stamp 82158
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.x-genesys-calluuid, m_Value=4M5C4RPIFT7I702UNTI5DMAO7K000004
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.x-genesys-gvp-session-data, m_Value=callsession=8A908C9C-4C6A-40CE-CDB7-8BB0A371C97C;1;0;;;;Environment;newone;;0;VP_defaultApp

ID=46F61B0A-6ECC-4135-AA1A-1E5C91051E4B-6@192.168.1.3/ANI=sip:9001@192.168.1.3:5060/DNIS=sip:2200@192.168.1.3:5060
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 688 02800000 LMCallSIP.C:2043 Media session registered, m_nState=0
2016-12-28 17:29:27.387 DBUG 00000000-00000000 3668 01C00000 CMMsgBase.h:186 cmapi.msg: CM_MSG_LMCC_CALLINOFFERED - 00760186-100032C9; CallRef=46F61B0A-6ECC-4135-AA1A-1E5C91051E4B-6@192.168.1.3; CallAddress=sip:2200@192.168.1.3:5060; ANI=sip:9001@192.168.1.3:5060; DNIS=sip:2200@192.168.1.3:5060; CPAType=voice

016-12-28 17:29:27.387 DBUG 00000000-00000000 3668 01C00000 CMCallManager.C:262 license usage:
2016-12-28 17:29:27.387 DBUG 00000000-00000000 3668 02400000 GVPLicenseLogger.C:89 Acquire GVP License:Product=vggateway; Features=in; Current Use=1; Peak Use=1
2016-12-28 17:29:27.387 DBUG 00000000-00000000 3668 01C00000 CMCallManager.C:269 Acquired license 1D7D8070 type 0
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=RURIUSER, m_Value=dialog
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=LOGCALLDIR, m_Value=INBOUND
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=SIPLOCALTAG, m_Value=A7DE953D-F35C-47F2-4899-2B9721EC0BA7
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=initial-url, m_Value=http://192.168.1.3:8088/GVP_1/src-gen/Main.vxml
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=gvp.appmodule, m_Value=VXML-NG
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=REDIRECT, m_Value=sip:2200@192.168.1.3:5060|N/A|N/A|unknown
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=CALLIDREF, m_Value=46F61B0A-6ECC-4135-AA1A-1E5C91051E4B-6@192.168.1.3
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=PROTOCOLNAME, m_Value=sip
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=PROTOCOLVERSION, m_Value=2.0
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=INITINFO, m_Value=0:0
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=XGENESYSCALLUUID, m_Value=4M5C4RPIFT7I702UNTI5DMAO7K000004
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=XGENESYSGVPSESSIONID, m_Value=8A908C9C-4C6A-40CE-CDB7-8BB0A371C97C
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=XGENESYSTENANTID, m_Value=1_newone
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=XGENESYSAPPDBID, m_Value=106
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.RequestURI, m_Value=sip:dialog@192.168.1.3:5070;gvp-tenant-id=[Environment].newone;gvp.appmodule=VXML-NG;record-ivr-profile=[Environment].VP_defaultApp;trunkport=2200;voicexml=http://192.168.1.3:8088/GVP_1/src-gen/Main.vxml
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.allow, m_Value=ACK, BYE, CANCEL, INFO, INVITE, MESSAGE, NOTIFY, OPTIONS, PRACK, REFER, UPDATE
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.min-se, m_Value=90
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.session-expires, m_Value=1800;refresher=uac
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.supported, m_Value=uui,100rel,timer
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.user-agent, m_Value=X-Lite release 4.9.6 stamp 82158
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.x-genesys-calluuid, m_Value=4M5C4RPIFT7I702UNTI5DMAO7K000004
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.x-genesys-gvp-session-data, m_Value=callsession=8A908C9C-4C6A-40CE-CDB7-8BB0A371C97C;1;0;;;;Environment;newone;;0;VP_defaultApp
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.x-genesys-gvp-session-id, m_Value=8A908C9C-4C6A-40CE-CDB7-8BB0A371C97C;gvp.rm.datanodes=1;gvp.rm.tenant-id=1_newone
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.x-genesys-rm-application-dbid, m_Value=106
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.originalcase.Allow, m_Value=ACK, BYE, CANCEL, INFO, INVITE, MESSAGE, NOTIFY, OPTIONS, PRACK, REFER, UPDATE
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.originalcase.Min-SE, m_Value=90
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.originalcase.Session-Expires, m_Value=1800;refresher=uac
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.originalcase.Supported, m_Value=uui,100rel,timer
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.originalcase.User-Agent, m_Value=X-Lite release 4.9.6 stamp 82158
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.originalcase.X-Genesys-CallUUID, m_Value=4M5C4RPIFT7I702UNTI5DMAO7K000004
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.originalcase.X-Genesys-GVP-Session-Data, m_Value=callsession=8A908C9C-4C6A-40CE-CDB7-8BB0A371C97C;1;0;;;;Environment;newone;;0;VP_defaultApp
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.originalcase.X-Genesys-GVP-Session-ID, m_Value=8A908C9C-4C6A-40CE-CDB7-8BB0A371C97C;gvp.rm.datanodes=1;gvp.rm.tenant-id=1_newone
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.originalcase.X-Genesys-RM-Application-dbid, m_Value=106
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.via, m_Value=SIP/2.0/TCP 192.168.1.3:5090;branch=z9hG4bK0000000003F6F8F063f677abcdef09,SIP/2.0/UDP 192.168.1.3:5060;branch=z9hG4bKA5C455CC-7BF6-465C-B829-C963B9792B44-16
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.from, m_Value=sip:9001@192.168.1.3:5060;tag=387C08A9-E401-49D1-BBB0-321120F1EF4B-13
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.to, m_Value=sip:2200@192.168.1.3:5060
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.max-forwards, m_Value=68
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.cseq, m_Value=1 INVITE
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.call-id, m_Value=46F61B0A-6ECC-4135-AA1A-1E5C91051E4B-6@192.168.1.3
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.contact, m_Value=sip:9001@192.168.1.3:5060
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.content-length, m_Value=327
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.content-type, m_Value=application/sdp
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.record-route, m_Value=sip:000000000A742460@192.168.1.3:5090;transport=TCP;lr;gvp.rm.datanodes=1;idtag=00000006
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.RequestURI.gvp-tenant-id, m_Value=[Environment].newone
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.RequestURI.gvp.appmodule, m_Value=VXML-NG
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.RequestURI.record-ivr-profile, m_Value=[Environment].VP_defaultApp
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.RequestURI.trunkport, m_Value=2200
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.RequestURI.voicexml, m_Value=http://192.168.1.3:8088/GVP_1/src-gen/Main.vxml
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Body, m_Value=v=0
o=- 1482944147 1 IN IP4 192.168.1.54
s=X-Lite release 4.9.6 stamp 82158
c=IN IP4 192.168.1.54
t=0 0
m=audio 60224 RTP/AVP 9 8 120 0 84 101
a=sendrecv
a=rtpmap:120 opus/48000/2
a=fmtp:120 useinbandfec=1; usedtx=1; maxaveragebitrate=64000
a=rtpmap:84 speex/16000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.from, m_Value=sip:9001@192.168.1.3:5060;tag=387C08A9-E401-49D1-BBB0-321120F1EF4B-13
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.to, m_Value=sip:2200@192.168.1.3:5060
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.max-forwards, m_Value=68
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.cseq, m_Value=1 INVITE
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.call-id, m_Value=46F61B0A-6ECC-4135-AA1A-1E5C91051E4B-6@192.168.1.3
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.contact, m_Value=sip:9001@192.168.1.3:5060
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.content-length, m_Value=327
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.content-type, m_Value=application/sdp
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.record-route, m_Value=sip:000000000A742460@192.168.1.3:5090;transport=TCP;lr;gvp.rm.datanodes=1;idtag=00000006
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.RequestURI.gvp-tenant-id, m_Value=[Environment].newone
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.RequestURI.gvp.appmodule, m_Value=VXML-NG
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.RequestURI.record-ivr-profile, m_Value=[Environment].VP_defaultApp
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.RequestURI.trunkport, m_Value=2200
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.RequestURI.voicexml, m_Value=http://192.168.1.3:8088/GVP_1/src-gen/Main.vxml
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Body, m_Value=v=0
o=- 1482944147 1 IN IP4 192.168.1.54
s=X-Lite release 4.9.6 stamp 82158
c=IN IP4 192.168.1.54
t=0 0
m=audio 60224 RTP/AVP 9 8 120 0 84 101
a=sendrecv
a=rtpmap:120 opus/48000/2
a=fmtp:120 useinbandfec=1; usedtx=1; maxaveragebitrate=64000
a=rtpmap:84 speex/16000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.to, m_Value=sip:2200@192.168.1.3:5060
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.max-forwards, m_Value=68
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.cseq, m_Value=1 INVITE
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.call-id, m_Value=46F61B0A-6ECC-4135-AA1A-1E5C91051E4B-6@192.168.1.3
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.contact, m_Value=sip:9001@192.168.1.3:5060
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.content-length, m_Value=327
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.content-type, m_Value=application/sdp
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.record-route, m_Value=sip:000000000A742460@192.168.1.3:5090;transport=TCP;lr;gvp.rm.datanodes=1;idtag=00000006
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.RequestURI.gvp-tenant-id, m_Value=[Environment].newone
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.RequestURI.gvp.appmodule, m_Value=VXML-NG
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.RequestURI.record-ivr-profile, m_Value=[Environment].VP_defaultApp
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.RequestURI.trunkport, m_Value=2200
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.RequestURI.voicexml, m_Value=http://192.168.1.3:8088/GVP_1/src-gen/Main.vxml
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Body, m_Value=v=0
o=- 1482944147 1 IN IP4 192.168.1.54
s=X-Lite release 4.9.6 stamp 82158
c=IN IP4 192.168.1.54
t=0 0
m=audio 60224 RTP/AVP 9 8 120 0 84 101
a=sendrecv
a=rtpmap:120 opus/48000/2
a=fmtp:120 useinbandfec=1; usedtx=1; maxaveragebitrate=64000
a=rtpmap:84 speex/16000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
2016-12-28 17:29:27.388 DBUG 00000000-00000000 688 08500000 VGSIPTransportMgr.cxx:3752 VGSIPTransportMgr::ResolveDNS nResult 2; CallID46F61B0A-6ECC-4135-AA1A-1E5C91051E4B-6@192.168.1.3
2016-12-28T17:29:27.388 Trc 33009 INFO 00000000-00000000 688 02800FA1 Response sent: SIP/2.0 503 Service Unavailable
Via: SIP/2.0/TCP 192.168.1.3:5090;branch=z9hG4bK0000000003F6F8F063f677abcdef09
Via: SIP/2.0/UDP 192.168.1.3:5060;branch=z9hG4bKA5C455CC-7BF6-465C-B829-C963B9792B44-16
From: sip:9001@192.168.1.3:5060;tag=387C08A9-E401-49D1-BBB0-321120F1EF4B-13
To: sip:2200@192.168.1.3:5060;tag=A7DE953D-F35C-47F2-4899-2B9721EC0BA7
CSeq: 1 INVITE
Call-ID: 46F61B0A-6ECC-4135-AA1A-1E5C91051E4B-6@192.168.1.3
Contact: sip:Genesys@192.168.1.3:5070
Content-Length: 0
Record-Route: sip:000000000A742460@192.168.1.3:5090;transport=TCP;lr;gvp.rm.datanodes=1;idtag=00000006
User-Agent: X-Lite release 4.9.6 stamp 82158
Min-SE: 90
X-Genesys-GVP-Session-Data: callsession=8A908C9C-4C6A-40CE-CDB7-8BB0A371C97C;1;0;;;;Environment;newone;;0;VP_defaultApp
X-Genesys-GVP-Session-ID: 8A908C9C-4C6A-40CE-CDB7-8BB0A371C97C;gvp.rm.datanodes=1;gvp.rm.tenant-id=1_newone

2016-12-28 17:29:27.388 DBUG 00760186-100032C9 688 02800000 LMCallSIP.C:3488 LMCallSIP::CloseMRCPResources - ASRState=0, TTSState=0, bForceClose=false
2016-12-28 17:29:27.388 DBUG 00760186-100032C9 688 02F00000 MPCWrapper.cxx:998 Processing Media Destroy on Session 1000002F
2016-12-28 17:29:27.388 DBUG 00000000-00000000 688 0B100000 MPCConnection.cxx:1897 MPCConnection::Destroy nLogID=00760186-100032C9 nConnID=1000002F
2016-12-28 17:29:27.388 DBUG 00000000-00000000 688 0B100000 MPCControlObject.cxx:368 MPCControlObject::UnregisterSinkHelper LogID=00760186-100032C9 ObjectID=1000002F SourceID=00017520 SinkID=00010000 pRoute=00000000
2016-12-28 17:29:27.389 DBUG 00000000-00000000 688 0B300000 VGRTPSocketObjects.cxx:590 closing RTP port 20000, m_nRTP 000000001D7C05D0, SocketThread 000000000EE71AB0
2016-12-28T17:29:27.398 Trc 33009 INFO 00000000-00000000 2436 02800FA1 Request received: ACK sip:dialog@192.168.1.3:5070;gvp-tenant-id=[Environment].newone;gvp.appmodule=VXML-NG;record-ivr-profile=[Environment].VP_defaultApp;trunkport=2200;voicexml=http://192.168.1.3:8088/GVP_1/src-gen/Main.vxml SIP/2.0
Via: SIP/2.0/TCP 192.168.1.3:5090;branch=z9hG4bK0000000003F6F8F063f677abcdef09
From: sip:9001@192.168.1.3:5060;tag=387C08A9-E401-49D1-BBB0-321120F1EF4B-13
To: sip:2200@192.168.1.3:5060;tag=A7DE953D-F35C-47F2-4899-2B9721EC0BA7
Max-Forwards: 70
CSeq: 1 ACK
Call-ID: 46F61B0A-6ECC-4135-AA1A-1E5C91051E4B-6@192.168.1.3
Content-Length: 0

2016-12-28 17:29:27.387 DBUG 00760186-100032C9 688 02F00000 MPCWrapper.cxx:681 Registering the Session 268435503
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 688 02800000 LMCallSIP.C:2719 LMCallSIP::CreateRTPSession finished successfully
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 688 02800000 LMCallSIP.C:3280 LMCallSIP::OpenMRCPResources - bASRReserve=false, bTTSReserve=false, bASRLoadOnce=true, bASRLogMetrics=false, strASRDefault=default, strTTSDefault=default
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 688 02800000 LMCallSIPHandler.C:2186 Received INVITE; ID=46F61B0A-6ECC-4135-AA1A-1E5C91051E4B-6@192.168.1.3/ANI=sip:9001@192.168.1.3:5060/DNIS=sip:2200@192.168.1.3:5060
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 688 02800000 LMCallSIP.C:2043 Media session registered, m_nState=0
2016-12-28 17:29:27.387 DBUG 00000000-00000000 3668 01C00000 CMMsgBase.h:186 cmapi.msg: CM_MSG_LMCC_CALLINOFFERED - 00760186-100032C9; CallRef=46F61B0A-6ECC-4135-AA1A-1E5C91051E4B-6@192.168.1.3; CallAddress=sip:2200@192.168.1.3:5060; ANI=sip:9001@192.168.1.3:5060; DNIS=sip:2200@192.168.1.3:5060; CPAType=voice
2016-12-28 17:29:27.387 DBUG 00000000-00000000 3668 01C00000 CMCallManager.C:262 license usage:
2016-12-28 17:29:27.387 DBUG 00000000-00000000 3668 02400000 GVPLicenseLogger.C:89 Acquire GVP License:Product=vggateway; Features=in; Current Use=1; Peak Use=1
2016-12-28 17:29:27.387 DBUG 00000000-00000000 3668 01C00000 CMCallManager.C:269 Acquired license 1D7D8070 type 0
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=RURIUSER, m_Value=dialog
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=LOGCALLDIR, m_Value=INBOUND
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=SIPLOCALTAG, m_Value=A7DE953D-F35C-47F2-4899-2B9721EC0BA7
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=initial-url, m_Value=http://192.168.1.3:8088/GVP_1/src-gen/Main.vxml
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=gvp.appmodule, m_Value=VXML-NG
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=REDIRECT, m_Value=sip:2200@192.168.1.3:5060|N/A|N/A|unknown
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=CALLIDREF, m_Value=46F61B0A-6ECC-4135-AA1A-1E5C91051E4B-6@192.168.1.3
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=PROTOCOLNAME, m_Value=sip
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=PROTOCOLVERSION, m_Value=2.0
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=INITINFO, m_Value=0:0
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=XGENESYSCALLUUID, m_Value=4M5C4RPIFT7I702UNTI5DMAO7K000004
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=XGENESYSGVPSESSIONID, m_Value=8A908C9C-4C6A-40CE-CDB7-8BB0A371C97C
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=XGENESYSTENANTID, m_Value=1_newone
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=XGENESYSAPPDBID, m_Value=106
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.RequestURI, m_Value=sip:dialog@192.168.1.3:5070;gvp-tenant-id=[Environment].newone;gvp.appmodule=VXML-NG;record-ivr-profile=[Environment].VP_defaultApp;trunkport=2200;voicexml=http://192.168.1.3:8088/GVP_1/src-gen/Main.vxml
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.allow, m_Value=ACK, BYE, CANCEL, INFO, INVITE, MESSAGE, NOTIFY, OPTIONS, PRACK, REFER, UPDATE
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.min-se, m_Value=90
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.session-expires, m_Value=1800;refresher=uac
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.supported, m_Value=uui,100rel,timer
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.user-agent, m_Value=X-Lite release 4.9.6 stamp 82158
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.x-genesys-calluuid, m_Value=4M5C4RPIFT7I702UNTI5DMAO7K000004
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.x-genesys-gvp-session-data, m_Value=callsession=8A908C9C-4C6A-40CE-CDB7-8BB0A371C97C;1;0;;;;Environment;newone;;0;VP_defaultApp
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.x-genesys-gvp-session-id, m_Value=8A908C9C-4C6A-40CE-CDB7-8BB0A371C97C;gvp.rm.datanodes=1;gvp.rm.tenant-id=1_newone
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.x-genesys-rm-application-dbid, m_Value=106
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.originalcase.Allow, m_Value=ACK, BYE, CANCEL, INFO, INVITE, MESSAGE, NOTIFY, OPTIONS, PRACK, REFER, UPDATE
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.originalcase.Min-SE, m_Value=90
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.originalcase.Session-Expires, m_Value=1800;refresher=uac
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.originalcase.Supported, m_Value=uui,100rel,timer
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.originalcase.User-Agent, m_Value=X-Lite release 4.9.6 stamp 82158
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.originalcase.X-Genesys-CallUUID, m_Value=4M5C4RPIFT7I702UNTI5DMAO7K000004
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.originalcase.X-Genesys-GVP-Session-Data, m_Value=callsession=8A908C9C-4C6A-40CE-CDB7-8BB0A371C97C;1;0;;;;Environment;newone;;0;VP_defaultApp
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.originalcase.X-Genesys-GVP-Session-ID, m_Value=8A908C9C-4C6A-40CE-CDB7-8BB0A371C97C;gvp.rm.datanodes=1;gvp.rm.tenant-id=1_newone
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.originalcase.X-Genesys-RM-Application-dbid, m_Value=106
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.via, m_Value=SIP/2.0/TCP 192.168.1.3:5090;branch=z9hG4bK0000000003F6F8F063f677abcdef09,SIP/2.0/UDP 192.168.1.3:5060;branch=z9hG4bKA5C455CC-7BF6-465C-B829-C963B9792B44-16
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.from, m_Value=sip:9001@192.168.1.3:5060;tag=387C08A9-E401-49D1-BBB0-321120F1EF4B-13
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.to, m_Value=sip:2200@192.168.1.3:5060
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.max-forwards, m_Value=68
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.cseq, m_Value=1 INVITE
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.call-id, m_Value=46F61B0A-6ECC-4135-AA1A-1E5C91051E4B-6@192.168.1.3
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.contact, m_Value=sip:9001@192.168.1.3:5060
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.content-length, m_Value=327
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.content-type, m_Value=application/sdp
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.record-route, m_Value=sip:000000000A742460@192.168.1.3:5090;transport=TCP;lr;gvp.rm.datanodes=1;idtag=00000006
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.RequestURI.gvp-tenant-id, m_Value=[Environment].newone
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.RequestURI.gvp.appmodule, m_Value=VXML-NG
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.RequestURI.record-ivr-profile, m_Value=[Environment].VP_defaultApp
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.RequestURI.trunkport, m_Value=2200
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Invite.RequestURI.voicexml, m_Value=http://192.168.1.3:8088/GVP_1/src-gen/Main.vxml
2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Sip.Body, m_Value=v=0
o=- 1482944147 1 IN IP4 192.168.1.54
s=X-Lite release 4.9.6 stamp 82158
c=IN IP4 192.168.1.54
t=0 0
m=audio 60224 RTP/AVP 9 8 120 0 84 101
a=sendrecv
a=rtpmap:120 opus/48000/2
a=fmtp:120 useinbandfec=1; usedtx=1; maxaveragebitrate=64000
a=rtpmap:84 speex/16000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

2016-12-28 17:29:27.387 DBUG 00760186-100032C9 3668 01C00000 CMCallManager.C:1232 DnisToUrlLookup - m_Attr=Record.Status, m_Value=stopped
2016-12-28T17:29:27.387 Std 30027 WARN 00760186-100032C9 3668 01C00BBE The desired AppModule (VXML-NG) was not found
2016-12-28 17:29:27.387 DBUG 00000000-00000000 3668 01C00000 CMCallManager.h:246 Releasing license 1D7D8070
2016-12-28 17:29:27.387 DBUG 00000000-00000000 3668 02400000 GVPLicenseLogger.C:112 Release GVP License:Product=vggateway; Features=in; Current Use=0; Peak Use=1
2016-12-28 17:29:27.388 DBUG 00000000-00000000 3668 01C00000 CMCallManager.h:252 license usage: Product=vggateway; Features=in; Current Use=0; Peak Use=1

2016-12-28 17:29:27.388 DBUG 00760186-100032C9 3668 02100000 BillingMetricsLogger.C:500 Logging Billing RE
2016-12-28T17:29:27.388 Int 50056 00760186-100032C9 3668 call_reference 46F61B0A-6ECC-4135-AA1A-1E5C91051E4B-6@192.168.1.3|8A908C9C-4C6A-40CE-CDB7-8BB0A371C97C|Environment|newone
2016-12-28 17:29:27.388 DBUG 00760186-100032C9 3668 02100000 BillingMetricsLogger.C:239 Logging Billing II
2016-12-28T17:29:27.388 Int 50052 00760186-100032C9 3668 incall_initiated 0:0
2016-12-28 17:29:27.388 DBUG 00760186-100032C9 3668 02100000 BillingMetricsLogger.C:283 Logging Billing IR
2016-12-28 17:29:27.388 DBUG 00760186-100032C9 688 02800000 LMCallSIP.C:1600 In CallDisconnect
2016-12-28T17:29:27.388 Int 50002 00760186-100032C9 3668 incall_reject sip:2200@192.168.1.3:5060|sip:9001@192.168.1.3:5060|20161228946167000|N/A|N/A|N/A|noresource
2016-12-28 17:29:27.388 DBUG 00760186-100032C9 688 02800000 LMCallSIP.C:1642 LMCallSIP::CallDisconnect - strContentType=, strContent=
2016-12-28 17:29:27.388 DBUG 00760186-100032C9 688 02800000 LMCallSIPStack.C:203 LMCallSIP::SendResponse for ID Headers
2016-12-28 17:29:27.388 DBUG 00760186-100032C9 688 02800000 LMCallSIPStack.C:225 LMCallSIP::SendResponse - X-Genesys-GVP-Session-ID: 8A908C9C-4C6A-40CE-CDB7-8BB0A371C97C;gvp.rm.datanodes=1;gvp.rm.tenant-id=1_newone
2016-12-28 17:29:27.388 DBUG 00000000-00000000 688 08500000 VGSIPTransportMgr.cxx:3637 VGSIPTransportMgr::ResolveDNS for 192.168.1.3:5090
2016-12-28 17:29:27.388 DBUG 00000000-00000000 688 08500000 VGSIPTransportMgr.cxx:3752 VGSIPTransportMgr::ResolveDNS nResult 2; CallID46F61B0A-6ECC-4135-AA1A-1E5C91051E4B-6@192.168.1.3
2016-12-28T17:29:27.388 Trc 33009 INFO 00000000-00000000 688 02800FA1 Response sent: SIP/2.0 503 Service Unavailable
Via: SIP/2.0/TCP 192.168.1.3:5090;branch=z9hG4bK0000000003F6F8F063f677abcdef09
Via: SIP/2.0/UDP 192.168.1.3:5060;branch=z9hG4bKA5C455CC-7BF6-465C-B829-C963B9792B44-16
From: sip:9001@192.168.1.3:5060;tag=387C08A9-E401-49D1-BBB0-321120F1EF4B-13
To: sip:2200@192.168.1.3:5060;tag=A7DE953D-F35C-47F2-4899-2B9721EC0BA7
CSeq: 1 INVITE
Call-ID: 46F61B0A-6ECC-4135-AA1A-1E5C91051E4B-6@192.168.1.3
Contact: sip:Genesys@192.168.1.3:5070
Content-Length: 0
Record-Route: sip:000000000A742460@192.168.1.3:5090;transport=TCP;lr;gvp.rm.datanodes=1;idtag=00000006
User-Agent: X-Lite release 4.9.6 stamp 82158
Min-SE: 90
X-Genesys-GVP-Session-Data: callsession=8A908C9C-4C6A-40CE-CDB7-8BB0A371C97C;1;0;;;;Environment;newone;;0;VP_defaultApp
X-Genesys-GVP-Session-ID: 8A908C9C-4C6A-40CE-CDB7-8BB0A371C97C;gvp.rm.datanodes=1;gvp.rm.tenant-id=1_newone

2016-12-28 17:29:27.388 DBUG 00760186-100032C9 688 02800000 LMCallSIP.C:3488 LMCallSIP::CloseMRCPResources - ASRState=0, TTSState=0, bForceClose=false
2016-12-28 17:29:27.388 DBUG 00760186-100032C9 688 02F00000 MPCWrapper.cxx:998 Processing Media Destroy on Session 1000002F
2016-12-28 17:29:27.388 DBUG 00000000-00000000 688 0B100000 MPCConnection.cxx:1897 MPCConnection::Destroy nLogID=00760186-100032C9 nConnID=1000002F
2016-12-28 17:29:27.388 DBUG 00000000-00000000 688 0B100000 MPCControlObject.cxx:368 MPCControlObject::UnregisterSinkHelper LogID=00760186-100032C9 ObjectID=1000002F SourceID=00017520 SinkID=00010000 pRoute=00000000
2016-12-28 17:29:27.389 DBUG 00000000-00000000 688 0B300000 VGRTPSocketObjects.cxx:590 closing RTP port 20000, m_nRTP 000000001D7C05D0, SocketThread 000000000EE71AB0
2016-12-28T17:29:27.398 Trc 33009 INFO 00000000-00000000 2436 02800FA1 Request received: ACK sip:dialog@192.168.1.3:5070;gvp-tenant-id=[Environment].newone;gvp.appmodule=VXML-NG;record-ivr-profile=[Environment].VP_defaultApp;trunkport=2200;voicexml=http://192.168.1.3:8088/GVP_1/src-gen/Main.vxml SIP/2.0
Via: SIP/2.0/TCP 192.168.1.3:5090;branch=z9hG4bK0000000003F6F8F063f677abcdef09
From: sip:9001@192.168.1.3:5060;tag=387C08A9-E401-49D1-BBB0-321120F1EF4B-13
To: sip:2200@192.168.1.3:5060;tag=A7DE953D-F35C-47F2-4899-2B9721EC0BA7
Max-Forwards: 70
CSeq: 1 ACK
Call-ID: 46F61B0A-6ECC-4135-AA1A-1E5C91051E4B-6@192.168.1.3
Content-Length: 0

2016-12-28 17:29:27.389 DBUG 00000000-00000000 688 0B300000 VGRTPSocketObjects.cxx:590 closing RTP port 20000, m_nRTP 000000001D7C05D0, SocketThread 000000000EE71AB0
2016-12-28T17:29:27.398 Trc 33009 INFO 00000000-00000000 2436 02800FA1 Request received: ACK sip:dialog@192.168.1.3:5070;gvp-tenant-id=[Environment].newone;gvp.appmodule=VXML-NG;record-ivr-profile=[Environment].VP_defaultApp;trunkport=2200;voicexml=http://192.168.1.3:8088/GVP_1/src-gen/Main.vxml SIP/2.0
Via: SIP/2.0/TCP 192.168.1.3:5090;branch=z9hG4bK0000000003F6F8F063f677abcdef09
From: sip:9001@192.168.1.3:5060;tag=387C08A9-E401-49D1-BBB0-321120F1EF4B-13
To: sip:2200@192.168.1.3:5060;tag=A7DE953D-F35C-47F2-4899-2B9721EC0BA7
Max-Forwards: 70
CSeq: 1 ACK
Call-ID: 46F61B0A-6ECC-4135-AA1A-1E5C91051E4B-6@192.168.1.3
Content-Length: 0

Kubig · December 29, 2016, 11:13am

The desired AppModule (VXML-NG) was not found

This is the reason. You try to interpret the VXML using NG mode, which is not available on MCP. This can be caused by using incorrect version or incorrect MCP configuration, so the GVP deployment has not been followed properly.

ankush87 · December 29, 2016, 6:07pm

Thanks a lot Kubig, I re-installed the MCP as per your suggestion and selected the correct interpreter. and it works now