Re: [UniMRCP] UCCX/UniMRCP - 406 Not Acceptable

228 views

Skip to first unread message

Arsen Chaloyan

unread,

Apr 13, 2021, 9:39:28 PM4/13/21

to UniMRCP

The first two SIP INVITES are responded with SIP OK. However, since UCCX seems to discard the responses and keeps sending new SIP INVITE messages, the remaining ones are responded with SIP 486. Anyway, the latter is simply a side effect, let's observe the first SIP session to understand what causes UCCX to continue sending new SIP INVITE messages.

A SIP INVITE message is received from UCCX.

2021-04-07 12:50:09.272467 recv 947 bytes from tcp/[10.89.219.175]:41529
INVITE sip:a...@10.89.232.46:8060;transport=tcp SIP/2.0
Via: SIP/2.0/TCP 10.89.219.175:5065;branch=z9hG4bKbMZ2FT5p1R98kO66NgNPIQ~~116563
Max-Forwards: 70
To: <sip:a...@10.89.232.46>
From: <sip:voiceB...@10.89.219.175>;tag=ds16d77633
Call-ID: AD77C743-0178-1000-400D-001125AE2A68
CSeq: 100 INVITE
Content-Length: 336
Contact: <sip:voiceB...@10.89.219.175:5065;transport=tcp>
Content-Type: application/sdp
Call-Info: <sip:10.89.219.175:5065>;method="NOTIFY;Event=telephone-event;Duration=2000"
Allow-Events: telephone-event
Allow: INVITE, INFO, BYE, CANCEL, ACK, UPDATE
User-Agent: Cisco-UCCX

v=0
o=- 123 456 IN IP4 10.89.219.175
s=Unified Contact Center Express 12.5.1.11001-348
c=IN IP4 10.89.219.175
t=0 0
m=audio 24962 RTP/AVP 0 96
a=rtpmap:0 pcmu/8000
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-15
a=sendonly
a=mid:1
m=application 9 TCP/MRCPv2
a=setup:active
a=connection:new
a=fmtp:96 0-15
a=resource:speechrecog
a=cmid:1

The server responds with SIP 100 Trying and then SIP 200 OK.

2021-04-07 12:50:09.272906 sent 319 bytes to tcp/[10.89.219.175]:41529

SIP/2.0 100 Trying
Via: SIP/2.0/TCP 10.89.219.175:5065;branch=z9hG4bKbMZ2FT5p1R98kO66NgNPIQ~~116563;rport=41529
From: <sip:voiceB...@10.89.219.175>;tag=ds16d77633
To: <sip:a...@10.89.232.46>
Call-ID: AD77C743-0178-1000-400D-001125AE2A68
CSeq: 100 INVITE
User-Agent: UniMRCP SofiaSIP 1.7.0
Content-Length: 0

2021-04-07 12:50:09.284069 sent 978 bytes to tcp/[10.89.219.175]:41529
SIP/2.0 200 OK
Via: SIP/2.0/TCP 10.89.219.175:5065;branch=z9hG4bKbMZ2FT5p1R98kO66NgNPIQ~~116563;rport=41529
From: <sip:voiceB...@10.89.219.175>;tag=ds16d77633
To: <sip:a...@10.89.232.46>;tag=UKteUvrgyS0Zj
Call-ID: AD77C743-0178-1000-400D-001125AE2A68
CSeq: 100 INVITE
Contact: <sip:10.89.232.46:8060>
User-Agent: UniMRCP SofiaSIP 1.7.0
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE
Supported: timer, 100rel
Session-Expires: 600;refresher=uas
Min-SE: 120
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 356

v=0
o=UniMRCPServer 4287477140538436308 1144379081323679349 IN IP4 10.89.232.46
s=-
c=IN IP4 10.89.232.46
t=0 0
m=audio 24576 RTP/AVP 0 96
a=rtpmap:0 PCMU/8000
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-15
a=recvonly
a=mid:1
m=application 1544 TCP/MRCPv2 1
a=setup:passive
a=connection:new
a=channel:350c6a8385c14489@speechrecog
a=cmid:1

I am pretty sure UCCX either discards or does not receive the SIP OK, as no SIP ACK is sent back. As a result, SIP OK is retransmitted numerous times and the session eventually times out.

2021-04-07 14:17:58:572023 [INFO] Receive SIP Event [nua_i_error] Status 408 ACK Timeout [SIP-Agent-1]
2021-04-07 14:17:58:572794 [INFO] Receive SIP Event [nua_i_state] Status 0 ACK Timeout [SIP-Agent-1]
2021-04-07 14:17:58:572806 [NOTICE] SIP Call State 0x7f13cc001c38 [terminating]

The only reason for UCCX to discard the SIP OK would be the transport field is not explicitly set to TCP. I'd suggest to leave tcp only in unimrcpserver.xml as follows

<sip-uas id="SIP-Agent-1" type="SofiaSIP">
<sip-transport>tcp</sip-transport>

On Wed, Apr 7, 2021 at 1:17 PM Nathan Cartwright <cartwr...@gmail.com> wrote:

I'm having an issue with UCCX and the latest version of UniMRCP. Using the GDF/GSS plugins.

For ASR and TTS both UCCX sends an invite to UniMRCP. Uni responds with a 100 Trying and then immediately sends a 406 Not Acceptable.

I verified on the UCCX system and it shows the exact same thing.

12886542: Apr 07 14:54:09.132 CST %MIVR-SS_MRCP_ASR-7-UNK: [MIVR_ENG_TASKS-31-8-TASK:0x5d21dbaaa_vxml_sample.aef] com.cisco.wf.mrcp.asr.channel.impl.MRCPSpeechChannelImpl MRCPSpeechChannel(Channel id:2, Contact id:167, Task id:25000000170): Entering activateBuiltInGrammar() - grammar ID: fie...@field.grammar
12886543: Apr 07 14:54:09.132 CST %MIVR-SS_MRCP_ASR-7-UNK: [MIVR_ENG_TASKS-31-8-TASK:0x5d21dbaaa_vxml_sample.aef] com.cisco.wf.mrcp.asr.channel.impl.MRCPSpeechChannelImpl MRCPSpeechChannel(Channel id:2, Contact id:167, Task id:25000000170): activateBuiltInGrammar() - params: DialogParameters[base.uri=(java.lang.String)crtp:/Documents/VXML/nlu_sample.vxml,fetch.timeout=(java.lang.Integer)300000,grammar.max.stale=(java.lang.Integer)0,grammar.max.age=(java.lang.Integer)300]
12886544: Apr 07 14:54:09.132 CST %MIVR-SS_MRCP_ASR-7-UNK: [MIVR_ENG_TASKS-31-8-TASK:0x5d21dbaaa_vxml_sample.aef] com.cisco.wf.mrcp.asr.channel.impl.MRCPSpeechChannelImpl MRCPSpeechChannel(Channel id:2, Contact id:167, Task id:25000000170): activateBuiltInGrammar() - type: transcribe, modal: false, mode: speech
12886545: Apr 07 14:54:09.132 CST %MIVR-SS_MRCP_ASR-7-UNK: [MIVR_ENG_TASKS-31-8-TASK:0x5d21dbaaa_vxml_sample.aef] com.cisco.wf.mrcp.asr.channel.impl.MRCPSpeechChannelImpl MRCPSpeechChannel(Channel id:2, Contact id:167, Task id:25000000170): createSession:createSession Creating Mrcp Session start
12886546: Apr 07 14:54:09.132 CST %MIVR-SS_MRCP_ASR-7-UNK: [MIVR_ENG_TASKS-31-8-TASK:0x5d21dbaaa_vxml_sample.aef] com.cisco.util.MRCPClientLog UNIQUE_ID ================>>
12886547: Apr 07 14:54:09.134 CST %MIVR-SS_MRCP_TTS-7-UNK: [MIVR_PROMPT_MGR_ASYNC-5-69-RESOLVE_167] com.cisco.util.MRCPClientLog Task:25000000170 MrcpV2ClientImpl.createSession() : Nuance host and Port= 10.89.232.46:8060
sessionxmlMsg: null
12886548: Apr 07 14:54:09.134 CST %MIVR-SS_MRCP_ASR-7-UNK: [MIVR_ENG_TASKS-31-8-TASK:0x5d21dbaaa_vxml_sample.aef] com.cisco.util.MRCPClientLog MrcpV2ClientImpl.createSession() : Nuance host and Port= 10.89.232.46:8060
sessionxmlMsg: null
12886549: Apr 07 14:54:09.134 CST %MIVR-SS_MRCP_TTS-7-UNK: [MIVR_PROMPT_MGR_ASYNC-5-69-RESOLVE_167] com.cisco.util.MRCPClientLog Task:25000000170 MrcpV2ClientImpl.createSession() : callbackHandler id = 161 : Waiting for SETUP complete event
12886550: Apr 07 14:54:09.135 CST %MIVR-SS_MRCP_TTS-7-UNK: [MRCPv2_EXE-21898] com.cisco.util.MRCPClientLog Task:25000000170 MrcpV2ClientImpl.sendSetupMsg() : Enter
12886551: Apr 07 14:54:09.135 CST %MIVR-SS_MRCP_ASR-7-UNK: [MRCPv2_EXE-21899] com.cisco.util.MRCPClientLog MrcpV2ClientImpl.sendSetupMsg() : Enter
12886552: Apr 07 14:54:09.135 CST %MIVR-SS_MRCP_TTS-7-UNK: [MRCPv2_EXE-21898] com.cisco.util.MRCPClientLog Task:25000000170 from = SIP-LocalLine-voiceBrowser; to = SIP-LocalLine-tts
12886553: Apr 07 14:54:09.135 CST %MIVR-SS_MRCP_ASR-7-UNK: [MRCPv2_EXE-21899] com.cisco.util.MRCPClientLog from = SIP-LocalLine-voiceBrowser; to = SIP-LocalLine-asr
12886554: Apr 07 14:54:09.135 CST %MIVR-SS_MRCP_TTS-7-UNK: [MRCPv2_EXE-21898] com.cisco.util.MRCPClientLog Task:25000000170 SIP clientRtpPort = 51352
12886555: Apr 07 14:54:09.135 CST %MIVR-SS_MRCP_ASR-7-UNK: [MRCPv2_EXE-21899] com.cisco.util.MRCPClientLog SIP clientRtpPort = 25012
12886556: Apr 07 14:54:09.135 CST %MIVR-SS_MRCP_TTS-7-UNK: [MRCPv2_EXE-21898] com.cisco.util.MRCPClientLog Task:25000000170 SIPMrcpV2ClientImpl SipInterfaceImpl Unique id is Task:25000000170 -TTS-161
12886557: Apr 07 14:54:09.135 CST %MIVR-SS_MRCP_ASR-7-UNK: [MRCPv2_EXE-21899] com.cisco.util.MRCPClientLog SIPMrcpV2ClientImpl SipInterfaceImpl Unique id is -ASR-2
12886558: Apr 07 14:54:09.135 CST %MIVR-SS_MRCP_TTS-7-UNK: [MRCPv2_EXE-21898] com.cisco.util.MRCPClientLog Task:25000000170 MrcpV2CallListener: onCallConnectionOriginated()
12886559: Apr 07 14:54:09.135 CST %MIVR-SS_MRCP_ASR-7-UNK: [MRCPv2_EXE-21899] com.cisco.util.MRCPClientLog MrcpV2CallListener: onCallConnectionOriginated()
12886560: Apr 07 14:54:09.136 CST %MIVR-LIB_TPL-7-UNK: [I/O-Thread.14] org.apache.log4j.AppenderSkeleton source=com.dynamicsoft.DsLibs.DsUALibs.DsSipLlApi.Wire, level=DEBUG, message=Sending message on TCP local[[ port = 57120 (10.89.219.175)]] remote[[ port = 8060 (10.89.232.46) ]], Connection ID = null, network = DEFAULT, TSIP = false
INVITE sip:t...@10.89.232.46:8060;transport=tcp SIP/2.0
Via: SIP/2.0/TCP 10.89.219.175:5065;branch=z9hG4bKbMZ2FT5p1R98kO66NgNPIQ~~119893
Max-Forwards: 70
To: <sip:t...@10.89.232.46>
From: <sip:voiceB...@10.89.219.175>;tag=dsf383e6cd
Call-ID: ADE6376F-0178-1000-4010-001125AE2A68
CSeq: 100 INVITE
Content-Length: 336
Contact: <sip:voiceB...@10.89.219.175:5065;transport=tcp>
Content-Type: application/sdp
Call-Info: <sip:10.89.219.175:5065>;method="NOTIFY;Event=telephone-event;Duration=2000"
Allow-Events: telephone-event
Allow: INVITE, INFO, BYE, CANCEL, ACK, UPDATE
User-Agent: Cisco-UCCX

v=0
o=- 123 456 IN IP4 10.89.219.175
s=Unified Contact Center Express 12.5.1.11001-348
c=IN IP4 10.89.219.175
t=0 0
m=audio 51352 RTP/AVP 0 96
a=rtpmap:0 pcmu/8000
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-15
a=recvonly
a=mid:1
m=application 9 TCP/MRCPv2
a=setup:active
a=connection:new
a=fmtp:96 0-15
a=resource:speechsynth
a=cmid:1
12886561: Apr 07 14:54:09.136 CST %MIVR-LIB_TPL-7-UNK: [I/O-Thread.14] org.apache.log4j.AppenderSkeleton source=com.dynamicsoft.DsLibs.DsUALibs.DsSipLlApi.Wire, level=DEBUG, message=Sending message on TCP local[[ port = 57120 (10.89.219.175)]] remote[[ port = 8060 (10.89.232.46) ]], Connection ID = null, network = DEFAULT, TSIP = false
INVITE sip:a...@10.89.232.46:8060;transport=tcp SIP/2.0
Via: SIP/2.0/TCP 10.89.219.175:5065;branch=z9hG4bKbMZ2FT5p1R98kO66NgNPIQ~~119894
Max-Forwards: 70
To: <sip:a...@10.89.232.46>
From: <sip:voiceB...@10.89.219.175>;tag=ds9fd1e6cd
Call-ID: ADE6376F-0178-1000-4011-001125AE2A68
CSeq: 100 INVITE
Content-Length: 336
Contact: <sip:voiceB...@10.89.219.175:5065;transport=tcp>
Content-Type: application/sdp
Call-Info: <sip:10.89.219.175:5065>;method="NOTIFY;Event=telephone-event;Duration=2000"
Allow-Events: telephone-event
Allow: INVITE, INFO, BYE, CANCEL, ACK, UPDATE
User-Agent: Cisco-UCCX

v=0
o=- 123 456 IN IP4 10.89.219.175
s=Unified Contact Center Express 12.5.1.11001-348
c=IN IP4 10.89.219.175
t=0 0
m=audio 25012 RTP/AVP 0 96
a=rtpmap:0 pcmu/8000
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-15
a=sendonly
a=mid:1
m=application 9 TCP/MRCPv2
a=setup:active
a=connection:new
a=fmtp:96 0-15
a=resource:speechrecog
a=cmid:1
12886562: Apr 07 14:54:09.137 CST %MIVR-LIB_TPL-7-UNK: [DsMessageReader-104] org.apache.log4j.AppenderSkeleton source=com.dynamicsoft.DsLibs.DsUALibs.DsSipLlApi.Wire, level=DEBUG, message=Received message on TCP local[[ port = 57120 (10.89.219.175)]] remote[[ port = 8060 (10.89.232.46) ]], Connection ID = null, network = DEFAULT, TSIP = false
SIP/2.0 100 Trying
Via: SIP/2.0/TCP 10.89.219.175:5065;branch=z9hG4bKbMZ2FT5p1R98kO66NgNPIQ~~119893;rport=57120
From: <sip:voiceB...@10.89.219.175>;tag=dsf383e6cd
To: <sip:t...@10.89.232.46>
Call-ID: ADE6376F-0178-1000-4010-001125AE2A68
CSeq: 100 INVITE
User-Agent: UniMRCP SofiaSIP 1.7.0
Content-Length: 0

12886563: Apr 07 14:54:09.137 CST %MIVR-LIB_TPL-7-UNK: [DsMessageReader-104] org.apache.log4j.AppenderSkeleton source=com.dynamicsoft.DsLibs.DsUALibs.DsSipLlApi.Wire, level=DEBUG, message=Received message on TCP local[[ port = 57120 (10.89.219.175)]] remote[[ port = 8060 (10.89.232.46) ]], Connection ID = null, network = DEFAULT, TSIP = false
SIP/2.0 100 Trying
Via: SIP/2.0/TCP 10.89.219.175:5065;branch=z9hG4bKbMZ2FT5p1R98kO66NgNPIQ~~119894;rport=57120
From: <sip:voiceB...@10.89.219.175>;tag=ds9fd1e6cd
To: <sip:a...@10.89.232.46>
Call-ID: ADE6376F-0178-1000-4011-001125AE2A68
CSeq: 100 INVITE
User-Agent: UniMRCP SofiaSIP 1.7.0
Content-Length: 0

12886564: Apr 07 14:54:09.139 CST %MIVR-LIB_TPL-7-UNK: [DsMessageReader-104] org.apache.log4j.AppenderSkeleton source=com.dynamicsoft.DsLibs.DsUALibs.DsSipLlApi.Wire, level=DEBUG, message=Received message on TCP local[[ port = 57120 (10.89.219.175)]] remote[[ port = 8060 (10.89.232.46) ]], Connection ID = null, network = DEFAULT, TSIP = false
SIP/2.0 406 Not Acceptable
Via: SIP/2.0/TCP 10.89.219.175:5065;branch=z9hG4bKbMZ2FT5p1R98kO66NgNPIQ~~119893;rport=57120
From: <sip:voiceB...@10.89.219.175>;tag=dsf383e6cd
To: <sip:t...@10.89.232.46>;tag=y6N54X0B6BH4D
Call-ID: ADE6376F-0178-1000-4010-001125AE2A68
CSeq: 100 INVITE
User-Agent: UniMRCP SofiaSIP 1.7.0
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE
Supported: timer, 100rel
Content-Length: 0

12886565: Apr 07 14:54:09.139 CST %MIVR-SS_MRCP_TTS-7-UNK: [DIALOG_CALLBACK.5] com.cisco.util.MRCPClientLog Task:25000000170 MrcpV2CallListener: onCallConnectionFailed(). Enter
12886566: Apr 07 14:54:09.139 CST %MIVR-SS_MRCP_TTS-7-UNK: [DIALOG_CALLBACK.5] com.cisco.util.MRCPClientLog Task:25000000170 MrcpV2CallListener: onCallConnectionFailed(). Call rejected:311
12886567: Apr 07 14:54:09.140 CST %MIVR-SS_MRCP_TTS-7-UNK: [DIALOG_CALLBACK.5] com.cisco.util.MRCPClientLog Task:25000000170 MRCPV2ClientImpl.processSetupFailed: callbackHandler id = 161 : Setup failure received; cause = 6; reason = Rejected

--
You received this message because you are subscribed to the Google Groups "UniMRCP" group.
To unsubscribe from this group and stop receiving emails from it, send an email to unimrcp+u...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/unimrcp/42772b7c-2b60-4025-9439-fb2a002ba9c0n%40googlegroups.com.

Arsen Chaloyan
Author of UniMRCP
http://www.unimrcp.org

Nathan Cartwright

unread,

Apr 14, 2021, 9:45:23 AM4/14/21

to UniMRCP

I figured out the issue to that...it was a misconfiguration. However, now that I'm passed that I get 408 request timed out. I don't think it's the network as I have a LumenVox server on the same network as UniMRCP and we have no issues.

Nathan Cartwright

unread,

Apr 14, 2021, 9:57:09 AM4/14/21

to UniMRCP

Here is Cisco's response on the 408 I'm getting now.

"As per MRCP 2.0 RFC (https://tools.ietf.org/html/rfc6787#section-5.4) Status Code 408 -- > Unrecognized or unsupported message entity. Issue might not be timeout related, as per the status code CCX is not supporting the format sent from UniMRCP."

Arsen Chaloyan

unread,

Apr 16, 2021, 7:01:56 PM4/16/21

to UniMRCP

Can you provide the server logs to see what is actually causing 408 responses?

To view this discussion on the web visit https://groups.google.com/d/msgid/unimrcp/01004880-0734-4b57-b859-e67459d2e4c9n%40googlegroups.com.

Reply all

Reply to author

Forward

0 new messages