[Home]

Summary:ASTERISK-28299: 481 Call/Transaction Does Not Exist on receiving MESSAGE event
Reporter:Brian J. Murrell (brian_j_murrell)Labels:
Date Opened:2019-02-20 07:22:18.000-0600Date Closed:2019-02-25 08:28:12.000-0600
Priority:MinorRegression?
Status:Closed/CompleteComponents:Resources/res_pjsip_messaging
Versions:13.25.0 Frequency of
Occurrence		Constant
Related
Issues:
Environment:Attachments:
Description:When my ITSP tries to send a (SIP SIMPLE) MESSAGE event to my Asterisk machine, Asterisk responds with {{SIP/2.0 481 Call/Transaction Does Not Exist}} which doesn't really make any sense to me for a single/one-off event like a MESSAGE event.  MESSAGE events don't seem to involve "transactions" which must exist.

My ITSP configuration:

{noformat}
[trunk]
type=registration
transport=transport-udp
outbound_auth=trunk-auth
server_uri=sip:itsp.example.com
client_uri=sip:userid@itsp.example.com

[trunk-auth]
type=auth
auth_type=userpass
password=********
username=userid

[trunk-endpoint](!)
type=endpoint
transport=transport-udp
context=from-trunk
message_context=messages
disallow=all
allow=ulaw
from_user=userid
outbound_auth=trunk-auth
auth=trunk-auth
send_pai=yes

[trunk-aor](!)
type=aor
qualify_frequency=15

[trunk-foo](trunk-endpoint)
aors=trunk-foo
[trunk-foo](trunk-aor)
contact=sip:userid@itsp.example.com:5060

[trunk-foo]
type=identify
endpoint=trunk-foo
match=itsp.example.com
{noformat}

The SIP conversation when the ITSP is trying to send the MESSAGE:

{noformat}
<--- Received SIP request (456 bytes) from UDP:10.0.0.1:5060 --->
MESSAGE sip:s@10.75.22.8:5060 SIP/2.0
Via: SIP/2.0/UDP 10.0.0.1:5060;branch=z9hG4bK51d6d4da;rport
Max-Forwards: 70
From: "5555551212" <sip:5555551212@itsp.example.com>;tag=as6c34cb69
To: <sip:s@10.75.22.8:5060>
Contact: <sip:5555551212@10.0.0.1:5060>
Call-ID: 3e9735b4313e58f90b4b61c82f392c2e@10.0.0.1:5060
CSeq: 102 MESSAGE
User-Agent: itsp.example.com
X-SMS-To: 5551234567
Content-Type: text/plain;charset=UTF-8
Content-Length: 1

test message
<--- Transmitting SIP response (515 bytes) to UDP:10.0.0.1:5060 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 10.0.0.1:5060;rport=5060;received=10.0.0.1;branch=z9hG4bK51d6d4da
Call-ID: 3e9735b4313e58f90b4b61c82f392c2e@10.0.0.1:5060
From: "5555551212" <sip:5555551212@itsp.example.com>;tag=as6c34cb69
To: <sip:s@10.75.22.8>;tag=z9hG4bK51d6d4da
CSeq: 102 MESSAGE
WWW-Authenticate: Digest realm="asterisk",nonce="1550441754/[redacted]",opaque="2c504a1035f74a1d",algorithm=md5,qop="auth"
Server: Asterisk PBX 13.25.0
Content-Length:  0


<--- Received SIP request (707 bytes) from UDP:10.0.0.1:5060 --->
MESSAGE sip:s@10.75.22.8:5060 SIP/2.0
Via: SIP/2.0/UDP 10.0.0.1:5060;branch=z9hG4bK516e2ba7;rport
Max-Forwards: 70
From: "5555551212" <sip:5555551212@itsp.example.com>;tag=as6c34cb69
To: <sip:s@10.75.22.8:5060>;tag=z9hG4bK51d6d4da
Call-ID: 3e9735b4313e58f90b4b61c82f392c2e@10.0.0.1:5060
CSeq: 103 MESSAGE
User-Agent: itsp.example.com
Proxy-Authorization: Digest username="userid", realm="asterisk", algorithm=MD5, uri="sip:s@172.1.2.3:5060", nonce="1550441754/[redacted]", response="[redacted]", opaque="2c504a1035f74a1d", qop=auth, cnonce="544772bb", nc=00000002
X-SMS-To: 5551234567
Content-Type: text/plain;charset=UTF-8
Content-Length: 1

c
<--- Transmitting SIP response (388 bytes) to UDP:10.0.0.1:5060 --->
SIP/2.0 481 Call/Transaction Does Not Exist
Via: SIP/2.0/UDP 10.0.0.1:5060;rport=5060;received=10.0.0.1;branch=z9hG4bK516e2ba7
Call-ID: 3e9735b4313e58f90b4b61c82f392c2e@10.0.0.1:5060
From: "5555551212" <sip:5555551212@itsp.example.com>;tag=as6c34cb69
To: <sip:s@10.75.22.8>;tag=z9hG4bK51d6d4da
CSeq: 103 MESSAGE
Server: Asterisk PBX 13.25.0
Content-Length:  0
{noformat}
Comments:By: Asterisk Team (asteriskteam) 2019-02-20 07:22:19.137-0600

Thanks for creating a report! The issue has entered the triage process. That means the issue will wait in this status until a Bug Marshal has an opportunity to review the issue. Once the issue has been reviewed you will receive comments regarding the next steps towards resolution.

A good first step is for you to review the [Asterisk Issue Guidelines|https://wiki.asterisk.org/wiki/display/AST/Asterisk+Issue+Guidelines] if you haven't already. The guidelines detail what is expected from an Asterisk issue report.

Then, if you are submitting a patch, please review the [Patch Contribution Process|https://wiki.asterisk.org/wiki/display/AST/Patch+Contribution+Process].

Please note that once your issue enters an open state it has been accepted. As Asterisk is an open source project there is no guarantee or timeframe on when your issue will be looked into. If you need expedient resolution you will need to find and pay a suitable developer. Asking for an update on your issue will not yield any progress on it and will not result in a response. All updates are posted to the issue when they occur.
By: Joshua C. Colp (jcolp) 2019-02-25 08:27:57.805-0600

I believe this is a bug in the remote side. A SIP transaction consists of a request, and then responses. The following is a transaction:

{noformat}
<--- Received SIP request (456 bytes) from UDP:10.0.0.1:5060 --->
MESSAGE sip:s@10.75.22.8:5060 SIP/2.0
Via: SIP/2.0/UDP 10.0.0.1:5060;branch=z9hG4bK51d6d4da;rport
Max-Forwards: 70
From: "5555551212" <sip:5555551212@itsp.example.com>;tag=as6c34cb69
To: <sip:s@10.75.22.8:5060>
Contact: <sip:5555551212@10.0.0.1:5060>
Call-ID: 3e9735b4313e58f90b4b61c82f392c2e@10.0.0.1:5060
CSeq: 102 MESSAGE
User-Agent: itsp.example.com
X-SMS-To: 5551234567
Content-Type: text/plain;charset=UTF-8
Content-Length: 1

test message
<--- Transmitting SIP response (515 bytes) to UDP:10.0.0.1:5060 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 10.0.0.1:5060;rport=5060;received=10.0.0.1;branch=z9hG4bK51d6d4da
Call-ID: 3e9735b4313e58f90b4b61c82f392c2e@10.0.0.1:5060
From: "5555551212" <sip:5555551212@itsp.example.com>;tag=as6c34cb69
To: <sip:s@10.75.22.8>;tag=z9hG4bK51d6d4da
CSeq: 102 MESSAGE
WWW-Authenticate: Digest realm="asterisk",nonce="1550441754/[redacted]",opaque="2c504a1035f74a1d",algorithm=md5,qop="auth"
Server: Asterisk PBX 13.25.0
Content-Length:  0
{noformat}

Since a 401 was sent, the transaction was completed.

The remote side then attempts to resend the MESSAGE with the same call id and within the same transaction. The code then bounces it back as there is no dialog and the transaction is over - you can't send another request using it. What should happen is that the MESSAGE with authentication details should not have a To tag. This would start a new transaction.
By: Brian J. Murrell (brian_j_murrell) 2019-02-25 09:43:53.364-0600

Thank-you for this thorough and detailed analysis.  I have relayed your findings to my ITSP/VoIP provider.
By: Asterisk Team (asteriskteam) 2019-02-25 09:43:53.511-0600

This issue has been reopened as a result of your commenting on it as the reporter. It will be triaged once again as applicable.
By: Brian J. Murrell (brian_j_murrell) 2019-03-07 06:08:15.930-0600

If a 401 completes a transaction, and the life of a {{Call-ID:}} value, why does that not apply to an {{INVITE}}?

When my ITSP sends me an unauthenticated {{INVITE}}, Asterisk sends a 401, to which they respond with the same {{INVITE}} again, using the same {{Call-ID:}} but with the added {{Authentication:}} header and Asterisk accepts that.

Is {{INVITE}} being treated differently than {{MESSAGE}} in this regard?
By: Asterisk Team (asteriskteam) 2019-03-07 06:08:16.405-0600

This issue has been reopened as a result of your commenting on it as the reporter. It will be triaged once again as applicable.
By: Joshua C. Colp (jcolp) 2019-03-07 06:33:06.877-0600

It's not the life of a Call-ID, that refers to a dialog/call. It's the Tag information in the From and To header that identifies the transaction. You can reuse the Call-ID, but the transaction has to be different.
By: Brian J. Murrell (brian_j_murrell) 2019-03-07 06:50:06.399-0600

Ahhh.  The plot thickens with Tag information.

But I still have an {{INVITE}} replied to with a 401 followed by an invite with an {{Authentication:}} header that is accepted where all 4 of those packets have the same {{Call-ID:}} and {{tag=}} on the {{From:}} header, just like my example {{MESSAGE}} packets above in the description.

So I am still not quite following why it works for {{INVITE}} and not {{MESSAGE}}.

One other thing of difference that I do notice though is that with {{INVITE}} my ITSP is sending an {{Authorization:}} header but with {{MESSAGE}} they are using a {{Proxy-Authorization:}} header.
By: Asterisk Team (asteriskteam) 2019-03-07 06:50:06.583-0600

This issue has been reopened as a result of your commenting on it as the reporter. It will be triaged once again as applicable.
By: Joshua C. Colp (jcolp) 2019-03-07 08:50:27.055-0600

Attach the INVITE information and it can be looked into and analyzed.
By: Brian J. Murrell (brian_j_murrell) 2019-03-07 11:44:05.179-0600

{noformat}
<--- Received SIP request (1003 bytes) from UDP:192.168.5.6:5060 --->
INVITE sip:5555551212@10.75.22.8:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.5.6:5060;branch=z9hG4bK7539c954;rport
Max-Forwards: 70
From: "Fred Flintsone" <sip:5555551212@192.168.5.6>;tag=as6fe86629
To: <sip:5555551212@10.75.22.8:5060>
Contact: <sip:5555551212@192.168.5.6:5060>
Call-ID: 644970b50c7200aa1f7cc40d5f925346@192.168.5.6:5060
CSeq: 102 INVITE
User-Agent: itsp.example.com
Date: Wed, 06 Mar 2019 20:24:45 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Remote-Party-ID: "Fred Flintsone" <sip:5555551212@192.168.5.6>;party=calling;privacy=off;screen=no
Content-Type: application/sdp
Content-Length: 297

v=0
o=root 1784943158 1784943158 IN IP4 192.168.5.6
s=itsp.example.com  
c=IN IP4 192.168.5.6
t=0 0
m=audio 11350 RTP/AVP 0 18 3 101
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20  
a=sendrecv  

<--- Transmitting SIP response (526 bytes) to UDP:192.168.5.6:5060 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 192.168.5.6:5060;rport=5060;received=192.168.5.6;branch=z9hG4bK7539c954
Call-ID: 644970b50c7200aa1f7cc40d5f925346@192.168.5.6:5060
From: "Fred Flintsone" <sip:5555551212@192.168.5.6>;tag=as6fe86629
To: <sip:5555551212@10.75.22.8>;tag=z9hG4bK7539c954
CSeq: 102 INVITE
WWW-Authenticate: Digest realm="asterisk",nonce="1551903885/259e10745dba6fcf8820b48fdcbd27c0",opaque="4e82c5c17a353b76",algorithm=md5,qop="auth"
Server: Asterisk PBX 13.25.0
Content-Length:  0


<--- Received SIP request (426 bytes) from UDP:192.168.5.6:5060 --->
ACK sip:5555551212@10.75.22.8:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.5.6:5060;branch=z9hG4bK7539c954;rport
Max-Forwards: 70
From: "Fred Flintsone" <sip:5555551212@192.168.5.6>;tag=as6fe86629
To: <sip:5555551212@10.75.22.8:5060>;tag=z9hG4bK7539c954
Contact: <sip:5555551212@192.168.5.6:5060>
Call-ID: 644970b50c7200aa1f7cc40d5f925346@192.168.5.6:5060
CSeq: 102 ACK
User-Agent: itsp.example.com
Content-Length: 0


<--- Received SIP request (1286 bytes) from UDP:192.168.5.6:5060 --->
INVITE sip:5555551212@10.75.22.8:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.5.6:5060;branch=z9hG4bK579e73f7;rport
Max-Forwards: 70
From: "Fred Flintsone" <sip:5555551212@192.168.5.6>;tag=as6fe86629
To: <sip:5555551212@10.75.22.8:5060>
Contact: <sip:5555551212@192.168.5.6:5060>
Call-ID: 644970b50c7200aa1f7cc40d5f925346@192.168.5.6:5060
CSeq: 103 INVITE
User-Agent: itsp.example.com
Authorization: Digest username="[redacted]", realm="asterisk", algorithm=MD5, uri="sip:5555551212@172.0.0.1:5060", nonce="1551903885/259e10745dba6fcf8820b48fdcbd27c0", response="9623d76a01682c22ba375aabf5d746c0", opaque="4e82c5c17a353b76", qop=auth, cnonce="6a43566c", nc=00000001
Date: Wed, 06 Mar 2019 20:24:45 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Remote-Party-ID: "Fred Flintsone" <sip:5555551212@192.168.5.6>;party=calling;privacy=off;screen=no
Content-Type: application/sdp
Content-Length: 297

v=0
o=root 1784943158 1784943159 IN IP4 192.168.5.6
s=itsp.example.com
c=IN IP4 192.168.5.6
t=0 0
m=audio 11350 RTP/AVP 0 18 3 101
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

<--- Transmitting SIP response (354 bytes) to UDP:192.168.5.6:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.5.6:5060;rport=5060;received=192.168.5.6;branch=z9hG4bK579e73f7
Call-ID: 644970b50c7200aa1f7cc40d5f925346@192.168.5.6:5060
From: "Fred Flintsone" <sip:5555551212@192.168.5.6>;tag=as6fe86629
To: <sip:5555551212@10.75.22.8>
CSeq: 103 INVITE
Server: Asterisk PBX 13.25.0
Content-Length:  0
{noformat}
By: Joshua C. Colp (jcolp) 2019-03-07 11:59:37.957-0600

As you can see in the INVITE with credentials:

{noformat}
From: "Fred Flintsone" <sip:5555551212@192.168.5.6>;tag=as6fe86629
To: <sip:5555551212@10.75.22.8:5060>
{noformat}

The To header doesn't have a tag, and thus this creates a new transaction. If a tag is present then it is referring to an existing one on the Asterisk side, and thus the code would try to find (and fail) to find it.
By: Joshua C. Colp (jcolp) 2019-03-07 12:15:31.436-0600

Argh I got things swapped. I always do that with the branch identifier and the tags. The Call-ID, From Tag, and To Tag uniquely identify a dialog. MESSAGE doesn't create a dialog[1][2] though, so when the MESSAGE comes in with a To Tag the code tries to find an existing one and can't - because it can't exist.

[1] https://tools.ietf.org/html/rfc3428
[2] MESSAGE requests do not themselves initiate a SIP dialog; under normal usage each Instant Message stands alone, much like pager messages.