IEC error UPDATE/PRACK unacceptable when call forward no answer triggers

Tom Ribbens · ‎12-10-2014

Hi,

A customer complained about errors in the logging of a voice gateway:

002481: Dec 10 10:28:07.965: %VOICE_IEC-3-GW: SIP: Internal Error (UPDATE/PRACK, unacceptable): IEC=1.1.180.7.113.4 on callID 4284 GUID=0535334D7F8E11E4852E2893FE22E6A0

So I did some digging: it happens when a call is forwarded to voicemail after the no answer timeout expires.

First we see the call coming in on the voice gateway, nothing special here:

002475: Dec 10 11:27:47.757: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent: 
INVITE sip:+3227181100@10.255.255.21:5060 SIP/2.0
Via: SIP/2.0/UDP  10.255.255.24:5060;branch=z9hG4bK7AFDE6
From: <sip:+3235404951@10.255.255.24>;tag=876A204C-A29
To: <sip:+3227181100@10.255.255.21>
Date: Wed, 10 Dec 2014 10:27:47 GMT
Call-ID: 53707C5-7F8E11E4-BA4395E2-E788F63D@10.255.255.24
Supported: 100rel,timer,replaces
Min-SE:  1800
Cisco-Guid: 87372621-2140017124-2234394771-4263700128
User-Agent: Cisco-SIPGateway/IOS-12.x
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO, UPDATE, REGISTER
CSeq: 101 INVITE
Max-Forwards: 70
Remote-Party-ID: <sip:+3235404951@10.255.255.24>;party=calling;screen=yes;privacy=off
Timestamp: 1418207267
Contact: <sip:+3235404951@10.255.255.24:5060>
Expires: 180
Allow-Events: telephone-event
Content-Type: application/sdp
Content-Length: 383

v=0
o=CiscoSystemsSIP-GW-UserAgent 4732 7265 IN IP4 10.255.255.24
s=SIP Call
c=IN IP4 10.255.255.24
t=0 0
m=audio 18224 RTP/AVP 8 18 0 100 101 19
c=IN IP4 10.255.255.24
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000          
a=fmtp:18 annexb=yes
a=rtpmap:0 PCMU/8000
a=rtpmap:100 X-NSE/8000
a=fmtp:100 192-194
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:19 CN/8000

002476: Dec 10 11:27:47.813: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received: 
SIP/2.0 100 Trying
Via: SIP/2.0/UDP  10.255.255.24:5060;branch=z9hG4bK7AFDE6
From: <sip:+3235404951@10.255.255.24>;tag=876A204C-A29
To: <sip:+3227181100@10.255.255.21>
Date: Wed, 10 Dec 2014 10:27:47 GMT
Call-ID: 53707C5-7F8E11E4-BA4395E2-E788F63D@10.255.255.24
CSeq: 101 INVITE
Allow-Events: presence
Content-Length: 0


002477: Dec 10 11:27:47.877: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received: 
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP  10.255.255.24:5060;branch=z9hG4bK7AFDE6
From: <sip:+3235404951@10.255.255.24>;tag=876A204C-A29
To: <sip:+3227181100@10.255.255.21>;tag=29779701~f12b72fc-4392-4a84-ae30-ce69cc6b291c-23194721
Date: Wed, 10 Dec 2014 10:27:47 GMT
Call-ID: 53707C5-7F8E11E4-BA4395E2-E788F63D@10.255.255.24
CSeq: 101 INVITE
Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY
Allow-Events: presence
Supported: X-cisco-srtp-fallback
Supported: Geolocation
P-Asserted-Identity: "Tom Ribbens" <sip:+3227181100@10.255.255.21>
Remote-Party-ID: "Tom Ribbens" <sip:+3227181100@10.255.255.21>;party=called;screen=yes;privacy=off
Contact: <sip:+3227181100@10.255.255.21:5060>
Content-Length: 0

But then we get an UPDATE that is peculiar, to which the gateway complains:

002480: Dec 10 11:28:07.965: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received: 
UPDATE sip:+3235404951@10.255.255.24:5060 SIP/2.0
Via: SIP/2.0/UDP 10.255.255.21:5060;branch=z9hG4bK2f4a271db88d51
From: <sip:+3227181100@10.255.255.21>;tag=29779701~f12b72fc-4392-4a84-ae30-ce69cc6b291c-23194721
To: <sip:+3235404951@10.255.255.24>;tag=876A204C-A29
Date: Wed, 10 Dec 2014 10:27:47 GMT
Call-ID: 53707C5-7F8E11E4-BA4395E2-E788F63D@10.255.255.24
User-Agent: Cisco-CUCM8.6
Max-Forwards: 70
Supported: timer,resource-priority,replaces
Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY
CSeq: 101 UPDATE
Supported: X-cisco-srtp-fallback
Supported: Geolocation
P-Asserted-Identity: <sip:5000@10.255.255.21>
Remote-Party-ID: <sip:5000@10.255.255.21>;party=calling;screen=yes;privacy=off
Contact: <sip:+3235404951@10.255.255.21:5060>
Content-Length: 0

002481: Dec 10 10:28:07.965: %VOICE_IEC-3-GW: SIP: Internal Error (UPDATE/PRACK, unacceptable): IEC=1.1.180.7.113.4 on callID 4284 GUID=0535334D7F8E11E4852E2893FE22E6A0

First of all we notice that it clearly is forwarding to voicemail, since the voicemail number 5000 is included in the message. Other than that, there are some questions I have:

Is it legal for an UPDATE message to be sent, even though a media path is not yet established?
Why are the From: and To: addresses switched from the rest of the SIP conversation?

Even though the voice gateway doesn't like the UPDATE, it still replies with an OK:

002482: Dec 10 11:28:07.969: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent: 
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.255.255.21:5060;branch=z9hG4bK2f4a271db88d51
From: <sip:+3227181100@10.255.255.21>;tag=29779701~f12b72fc-4392-4a84-ae30-ce69cc6b291c-23194721
To: <sip:+3235404951@10.255.255.24>;tag=876A204C-A29
Date: Wed, 10 Dec 2014 10:28:07 GMT
Call-ID: 53707C5-7F8E11E4-BA4395E2-E788F63D@10.255.255.24
Server: Cisco-SIPGateway/IOS-12.x
CSeq: 101 UPDATE
Content-Length: 0
Contact: <sip:+3235404951@10.255.255.24:5060>

Again, the To: and From: lines are swapped, as in the UPDATE.

After that, the call is answered by voicemail, and the call progresses as normal. To: and From: headers are back to the original:

002483: Dec 10 11:28:08.065: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received: 
SIP/2.0 200 OK
Via: SIP/2.0/UDP  10.255.255.24:5060;branch=z9hG4bK7AFDE6
From: <sip:+3235404951@10.255.255.24>;tag=876A204C-A29
To: <sip:+3227181100@10.255.255.21>;tag=29779701~f12b72fc-4392-4a84-ae30-ce69cc6b291c-23194721
Date: Wed, 10 Dec 2014 10:27:47 GMT
Call-ID: 53707C5-7F8E11E4-BA4395E2-E788F63D@10.255.255.24
CSeq: 101 INVITE
Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY
Allow-Events: presence
Supported: replaces
Supported: X-cisco-srtp-fallback
Supported: Geolocation
Session-Expires:  7200;refresher=uas
Require:  timer
P-Asserted-Identity: <sip:5000@10.255.255.21>
Remote-Party-ID: <sip:5000@10.255.255.21>;party=called;screen=yes;privacy=off
Contact: <sip:+3227181100@10.255.255.21:5060>
Content-Type: application/sdp
Content-Length: 220

v=0
o=CiscoSystemsCCM-SIP 29779701 1 IN IP4 10.255.255.21
s=SIP Call
c=IN IP4 10.255.255.22
t=0 0
m=audio 20902 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=ptime:20
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

002484: Dec 10 11:28:08.069: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent: 
ACK sip:+3227181100@10.255.255.21:5060 SIP/2.0
Via: SIP/2.0/UDP  10.255.255.24:5060;branch=z9hG4bK7B054A
From: <sip:+3235404951@10.255.255.24>;tag=876A204C-A29
To: <sip:+3227181100@10.255.255.21>;tag=29779701~f12b72fc-4392-4a84-ae30-ce69cc6b291c-23194721
Date: Wed, 10 Dec 2014 10:28:07 GMT
Call-ID: 53707C5-7F8E11E4-BA4395E2-E788F63D@10.255.255.24
Max-Forwards: 70
CSeq: 101 ACK
Content-Length: 0


002489: Dec 10 11:28:16.069: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent: 
BYE sip:+3227181100@10.255.255.21:5060 SIP/2.0
Via: SIP/2.0/UDP  10.255.255.24:5060;branch=z9hG4bK7B11F25
From: <sip:+3235404951@10.255.255.24>;tag=876A204C-A29
To: <sip:+3227181100@10.255.255.21>;tag=29779701~f12b72fc-4392-4a84-ae30-ce69cc6b291c-23194721
Date: Wed, 10 Dec 2014 10:28:07 GMT
Call-ID: 53707C5-7F8E11E4-BA4395E2-E788F63D@10.255.255.24
User-Agent: Cisco-SIPGateway/IOS-12.x
Max-Forwards: 70
Timestamp: 1418207296
CSeq: 102 BYE
Content-Length: 0


002490: Dec 10 11:28:16.077: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received: 
SIP/2.0 200 OK
Via: SIP/2.0/UDP  10.255.255.24:5060;branch=z9hG4bK7B11F25
From: <sip:+3235404951@10.255.255.24>;tag=876A204C-A29
To: <sip:+3227181100@10.255.255.21>;tag=29779701~f12b72fc-4392-4a84-ae30-ce69cc6b291c-23194721
Date: Wed, 10 Dec 2014 10:28:16 GMT
Call-ID: 53707C5-7F8E11E4-BA4395E2-E788F63D@10.255.255.24
CSeq: 102 BYE
Content-Length: 0

From the user perspective, everything is going as it should be, it's only the error that pops up in the voice gateway. Is this simply something we should accept, or can we fix this?

Ayodeji Okanlawon · ‎12-10-2014

Tom,

I will attempt to answer your queries to the best of my abilities, so help me God :)

Is it legal for an UPDATE message to be sent, even though a media path is not yet established?

Yes. It is. According to the UPDATE method RFC 3311.

Once a dialog is established, either early or confirmed, the caller can generate an UPDATE method that contains an SDP offer [3] for the purposes of updating the session. The response to the UPDATE method contains the answer. Similarly, once a dialog is established, the callee can send an UPDATE with an offer, and the caller places its answer in the 2xx to the UPDATE. The Allow header field is used to indicate support for the UPDATE method

So an UPDATE can be sent once a dialog is established ie (INVITE sent, trying received.) before the dialog is confirmed (200OK, ACK) etc

Why are the From: and To: addresses switched from the rest of the SIP conversation?

The To and From headers in the UPDATE method gets switched around because they indicate who is sending the UPDATE. Here we can see the direction that the update is coming from. The UPDATE is generally used to update the dialog. Here we see that the call has been sent to voicemail and the remote-party-id has changed from

Remote-Party-ID: <sip:+3235404951@10.255.255.24>;party=calling;screen=yes;privacy=off

to

Remote-Party-ID: <sip:5000@10.255.255.21>;party=called;screen=yes;privacy=off

Question two:

From the user perspective, everything is going as it should be, it's only the error that pops up in the voice gateway. Is this simply something we should accept, or can we fix this?

I am not sure I know what the fix is but I know a work around. We can disable the UPDATE totally, I am however reluctant to do that as UPDATE can be important sometimes. This may be a bug on the IOS and as such you may need to open a TAC case with cisco to know why this is happening. As far as I can tell this has no operational impact. It can be ignored..

Please rate all useful posts