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-0600 | Date Closed: | 2019-02-25 08:28:12.000-0600 |
Priority: | Minor | Regression? | |
Status: | Closed/Complete | Components: | 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. |