[bug]: Cannot transfer call in TLS setup with SRTP, SDES - call terminated when pressing transfer key on phone

[ComputerSnail]

Severity

Major

Versions

20.6.0

Components/Modules

Asterisk, PJSIP

Operating Environment

root@asterisk ~/asterisk # uname -a
Linux asterisk 6.1.0-17-amd64 #1 SMP PREEMPT_DYNAMIC Debian 6.1.69-1 (2023-12-30) x86_64 GNU/Linux
root@asterisk ~/asterisk # cat /etc/os-release
PRETTY_NAME="Debian GNU/Linux 12 (bookworm)"
NAME="Debian GNU/Linux"
VERSION_ID="12"
VERSION="12 (bookworm)"
VERSION_CODENAME=bookworm
ID=debian
HOME_URL="https://www.debian.org/"
SUPPORT_URL="https://www.debian.org/support"
BUG_REPORT_URL="https://bugs.debian.org/"

Frequency of Occurrence

Constant

Issue Description

I have a newly built small Asterisk setup that uses SIP only (PJSIP), no legacy protocols. It is connected to the outside world using a SIP trunk. For the SIP trunk and the internal phones, TLS transport is in place. The Asterisk server listens on port 5061 has a certificate that is signed by a CA that is trusted by the desk and soft phones.

[transport-tls]
type=transport
protocol=tls
bind=0.0.0.0:5061
method=tlsv1_2
ca_list_file=/etc/ssl/certs/ca-certificates.crt
local_net = 10.24.0.0/15
external_media_address = 81.xx.xx.xx
external_signaling_address = 81.xx.xx.xx
cert_file=/etc/asterisk/ssl/asterisk.crt
priv_key_file=/etc/asterisk/ssl/asterisk.key

[mytrunk]
type=registration
transport=transport-tls
outbound_auth=mytrunk_auth
server_uri=sip:secure.sip.mytrunk.example.org
client_uri=sip:0049123456789@secure.sip.mytrunk.example.org
contact_user=491234567890
retry_interval=60
forbidden_retry_interval=600
expiration=1800
line=yes
endpoint=mytrunk

All endpoints use transport-tls, direct_media=no, media_encryption=sdes, allow_transfer=yes and media_encryption_optimistic=no.

Most things work without problems! ☺️

Users can call each other, I can call from outside using the phone number provided by the trunk and I can do outbound calls to the PSTN over the trunk.

But one thing constantly doesn't work: If I press the transfer / hold key on a desk phone, the call is terminated immediately. The Asterisk -vvv... output with pjsip log on shows that it starts music on hold but after some milliseconds both parties leave the simple_bridge and the call is killed.

[2024-02-05 00:24:50.358]     -- Started music on hold, class 'default', on channel 'PJSIP/mytrunk-00000002'
[2024-02-05 00:24:50.393] <--- Received SIP request (449 bytes) from TLS:10.25.12.14:52057 --->
[2024-02-05 00:24:50.393] BYE sip:01234567890@10.24.12.58:5061;transport=TLS SIP/2.0
[2024-02-05 00:24:50.394] Via: SIP/2.0/TLS 10.25.12.14:52057;rport;branch=z9hG4bKPj98d61745-61c7-4bfe-a62a-375b7b9ed121;alias
[2024-02-05 00:24:50.394] Max-Forwards: 70
[2024-02-05 00:24:50.394] From: <sips:234@10.25.12.14>;tag=1eeefad2-d4c3-4453-9687-823549430280
[2024-02-05 00:24:50.394] To: <sip:0555555555@10.24.12.58>;tag=c39995b5-df11-42bd-9f04-e84e0dbc0fd4
[2024-02-05 00:24:50.394] Call-ID: 331bfab4-44b5-4625-a33b-33b5d72cb5da
[2024-02-05 00:24:50.395] CSeq: 32612 BYE
[2024-02-05 00:24:50.395] Warning: 381 max3b "SIPS Required"
[2024-02-05 00:24:50.395] Content-Length:  0

It seems the desk phone (10.25.12.14) says BYE to Asterisk (10.24.12.58) because it didn't accept whatever Asterisk did in response to pressing the hold key. Maybe it is related to the line: Warning: 381 max3b "SIPS Required"

The problem occurs with the Bintec Elmeg IP 630 (see phone manual about consulation calls, page 19 in print, 20 in PDF ) and the SNOM D385, both with the latest firmware.

There is a community forum discussion about the problem: https://community.asterisk.org/t/hold-error-when-trying-to-transfer-incoming-call-transfer-of-outgoing-call-works/100840

Here is a more complete SIP trace: https://pastebin.com/p0Fb4qu9

A very helpful forum colleague had the idea, the issue might be related to the construction of the Contact header.

I guess the problem is somehow related to the encryption of SIP and voice.

Relevant log output

[2024-02-05 00:24:50.353] <--- Received SIP request (1200 bytes) from TLS:10.25.12.14:52057 --->
[2024-02-05 00:24:50.353] INVITE sips:0100000000@10.24.12.58:5061;transport=TLS SIP/2.0
[2024-02-05 00:24:50.353] Via: SIP/2.0/TLS 10.25.12.14:52057;rport;branch=z9hG4bKPjf247e4b4-c462-47c1-929f-9448423951c5;alias
[2024-02-05 00:24:50.353] Max-Forwards: 70
[2024-02-05 00:24:50.353] From: <sips:234@10.25.12.14>;tag=1eeefad2-d4c3-4453-9687-823549430280
[2024-02-05 00:24:50.353] To: <sip:012345678901@10.24.12.58>;tag=c39995b5-df11-42bd-9f04-e84e0dbc0fd4
[2024-02-05 00:24:50.353] Contact: <sips:234@10.25.12.14:5061;transport=tls>
[2024-02-05 00:24:50.353] Call-ID: 331bfab4-44b5-4625-a33b-33b5d72cb5da
[2024-02-05 00:24:50.353] CSeq: 32611 INVITE
[2024-02-05 00:24:50.353] Allow: SUBSCRIBE, NOTIFY, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, OPTIONS, PRACK, REFER, MESSAGE
[2024-02-05 00:24:50.353] Supported: 100rel, replaces, timer, eventlist
[2024-02-05 00:24:50.353] Session-Expires: 1800;refresher=uas
[2024-02-05 00:24:50.353] Min-SE: 90
[2024-02-05 00:24:50.353] User-Agent: elmeg IP630/82.3.19.1-release;589EC66BDF2D
[2024-02-05 00:24:50.353] Allow-Events: hold,talk
[2024-02-05 00:24:50.353] Content-Type: application/sdp
[2024-02-05 00:24:50.353] Content-Length:   419
[2024-02-05 00:24:50.353]
[2024-02-05 00:24:50.353] v=0
[2024-02-05 00:24:50.353] o=- 3916077851 3916077853 IN IP4 10.25.12.14
[2024-02-05 00:24:50.353] s=elmeg IP630/82.3.19.1-release;589EC66BDF2D
[2024-02-05 00:24:50.353] t=0 0
[2024-02-05 00:24:50.353] m=audio 8046 RTP/SAVP 9 8 0 101
[2024-02-05 00:24:50.354] c=IN IP4 10.25.12.14
[2024-02-05 00:24:50.354] b=TIAS:64000
[2024-02-05 00:24:50.354] a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:3jAXcQNdabSJSWB/kRGbATfPEa/jHIAD9fPJQihH
[2024-02-05 00:24:50.354] a=rtcp:8047 IN IP4 10.25.12.14
[2024-02-05 00:24:50.354] a=rtpmap:9 G722/8000
[2024-02-05 00:24:50.354] a=rtpmap:8 PCMA/8000
[2024-02-05 00:24:50.354] a=rtpmap:0 PCMU/8000
[2024-02-05 00:24:50.354] a=rtpmap:101 telephone-event/8000
[2024-02-05 00:24:50.354] a=fmtp:101 0-16
[2024-02-05 00:24:50.354] a=sendonly
[2024-02-05 00:24:50.354]
[2024-02-05 00:24:50.355] <--- Transmitting SIP response (1064 bytes) to TLS:10.25.12.14:52057 --->
[2024-02-05 00:24:50.355] SIP/2.0 200 OK
[2024-02-05 00:24:50.355] Via: SIP/2.0/TLS 10.25.12.14:52057;rport=52057;received=10.25.12.14;branch=z9hG4bKPjf247e4b4-c462-47c1-929f-9448423951c5;alias
[2024-02-05 00:24:50.355] Call-ID: 331bfab4-44b5-4625-a33b-33b5d72cb5da
[2024-02-05 00:24:50.355] From: <sips:234@10.25.12.14>;tag=1eeefad2-d4c3-4453-9687-823549430280
[2024-02-05 00:24:50.355] To: <sip:012345678901@10.24.12.58>;tag=c39995b5-df11-42bd-9f04-e84e0dbc0fd4
[2024-02-05 00:24:50.355] CSeq: 32611 INVITE
[2024-02-05 00:24:50.355] Session-Expires: 1800;refresher=uas
[2024-02-05 00:24:50.356] Contact: <sip:0100000000@10.24.12.58:5061;transport=TLS>
[2024-02-05 00:24:50.356] Allow: OPTIONS, REGISTER, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, MESSAGE, INFO, REFER
[2024-02-05 00:24:50.356] Supported: 100rel, timer, replaces, norefersub
[2024-02-05 00:24:50.356] Server: Asterisk PBX
[2024-02-05 00:24:50.356] Content-Type: application/sdp
[2024-02-05 00:24:50.356] Content-Length:   366
[2024-02-05 00:24:50.356]
[2024-02-05 00:24:50.356] v=0
[2024-02-05 00:24:50.356] o=- 511053411 511053412 IN IP4 10.24.12.58
[2024-02-05 00:24:50.356] s=Asterisk
[2024-02-05 00:24:50.356] c=IN IP4 10.24.12.58
[2024-02-05 00:24:50.357] t=0 0
[2024-02-05 00:24:50.357] m=audio 15248 RTP/SAVP 9 8 0 101
[2024-02-05 00:24:50.357] a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:YTvDRwsfUxy9tljBWO2EHacLr+23NowN1G+gzMK2
[2024-02-05 00:24:50.357] a=rtpmap:9 G722/8000
[2024-02-05 00:24:50.357] a=rtpmap:8 PCMA/8000
[2024-02-05 00:24:50.357] a=rtpmap:0 PCMU/8000
[2024-02-05 00:24:50.357] a=rtpmap:101 telephone-event/8000
[2024-02-05 00:24:50.357] a=fmtp:101 0-16
[2024-02-05 00:24:50.357] a=ptime:20
[2024-02-05 00:24:50.357] a=maxptime:140
[2024-02-05 00:24:50.357] a=recvonly
[2024-02-05 00:24:50.358]
[2024-02-05 00:24:50.358]     -- Started music on hold, class 'default', on channel 'PJSIP/mytrunk-00000002'
[2024-02-05 00:24:50.393] <--- Received SIP request (449 bytes) from TLS:10.25.12.14:52057 --->
[2024-02-05 00:24:50.393] BYE sip:0100000000@10.24.12.58:5061;transport=TLS SIP/2.0
[2024-02-05 00:24:50.394] Via: SIP/2.0/TLS 10.25.12.14:52057;rport;branch=z9hG4bKPj98d61745-61c7-4bfe-a62a-375b7b9ed121;alias
[2024-02-05 00:24:50.394] Max-Forwards: 70
[2024-02-05 00:24:50.394] From: <sips:234@10.25.12.14>;tag=1eeefad2-d4c3-4453-9687-823549430280
[2024-02-05 00:24:50.394] To: <sip:012345678901@10.24.12.58>;tag=c39995b5-df11-42bd-9f04-e84e0dbc0fd4
[2024-02-05 00:24:50.394] Call-ID: 331bfab4-44b5-4625-a33b-33b5d72cb5da
[2024-02-05 00:24:50.395] CSeq: 32612 BYE
[2024-02-05 00:24:50.395] Warning: 381 max3b "SIPS Required"
[2024-02-05 00:24:50.395] Content-Length:  0
[2024-02-05 00:24:50.395]
[2024-02-05 00:24:50.395]
[2024-02-05 00:24:50.395] <--- Transmitting SIP response (400 bytes) to TLS:10.25.12.14:52057 --->
[2024-02-05 00:24:50.396] SIP/2.0 200 OK
[2024-02-05 00:24:50.396] Via: SIP/2.0/TLS 10.25.12.14:52057;rport=52057;received=10.25.12.14;branch=z9hG4bKPj98d61745-61c7-4bfe-a62a-375b7b9ed121;alias
[2024-02-05 00:24:50.396] Call-ID: 331bfab4-44b5-4625-a33b-33b5d72cb5da
[2024-02-05 00:24:50.396] From: <sips:234@10.25.12.14>;tag=1eeefad2-d4c3-4453-9687-823549430280
[2024-02-05 00:24:50.396] To: <sip:012345678901@10.24.12.58>;tag=c39995b5-df11-42bd-9f04-e84e0dbc0fd4
[2024-02-05 00:24:50.396] CSeq: 32612 BYE
[2024-02-05 00:24:50.396] Server: Asterisk PBX
[2024-02-05 00:24:50.396] Content-Length:  0
[2024-02-05 00:24:50.397]
[2024-02-05 00:24:50.397]
[2024-02-05 00:24:50.397]     -- Channel PJSIP/234-00000003 left 'simple_bridge' basic-bridge <17df271c-5bcc-4b89-8a65-802e7bad0661>
[2024-02-05 00:24:50.397]     -- Channel PJSIP/mytrunk-00000002 left 'simple_bridge' basic-bridge <17df271c-5bcc-4b89-8a65-802e7bad0661>
[2024-02-05 00:24:50.398]     -- Stopped music on hold on PJSIP/mytrunk-00000002
[2024-02-05 00:24:50.398]   == Spawn extension (mytrunk, 4910000000234, 1) exited non-zero on 'PJSIP/mytrunk-00000002'

Asterisk Issue Guidelines

• Yes, I have read the Asterisk Issue Guidelines

[jcolp]

Please provide the COMPLETE PJSIP configuration, including endpoint configuration. We also need a debug level log: https://docs.asterisk.org/Operation/Logging/Collecting-Debug-Information/?h=collecting

It's also important to attach these things, and not link to outside resources as they can go away so when someone wants to work on problems they can't.

[ComputerSnail]

First of all, please see attached configuration for PJSIP.
pjsip_conf_2024-02-07.txt

[ComputerSnail]

I've attached the redacted debug output (changed phone numbers etc. using "replace all") here:
debug_log_github20240207_mod.txt

The phone seems to say "BYE" in line 10022 in response to Asterisk's reaction to pressing the "consultation call" / "transfer" / "hold" key (even before having a chance to type in the number on the keypad of the phone).

@jcolp I hope the files attached can help!