ha-plugins
ha-plugins copied to clipboard
arnonym
Unable to initiate a call
I have HA running on a Raspberry Pi 4. I've installed ha-sip via HACS, and configured as follows:
global:
port: 5060
log_level: 5
name_server: ""
cache_dir: /config/audio_cache
sip1:
enabled: true
registrar_uri: sip:10.10.60.20:5060;transport=tcp
id_uri: sip:[email protected]
realm: grandstream
user_name: assistant
password: somepassword
answer_mode: listen
settle_time: 1
incoming_call_file: ""
10.10.60.20 is the IP address of an on-prem Grandstream UCM 6300.
Registration works fine:
Python 3.11.3
| 20:30:57.556819 [ ] Error: Cache directory not found.
| 20:30:57.557216 [1] No file name for incoming call config specified.
| 20:30:57.557340 [2] No file name for incoming call config specified.
| 20:30:57.557456 [3] No file name for incoming call config specified.
20:30:57.559 os_core_unix.c !pjlib 2.14.1 for POSIX initialized
20:30:57.563 sip_endpoint.c .Creating endpoint instance...
20:30:57.564 pjlib .select() I/O Queue created (0x7f7e3851d8)
20:30:57.564 sip_endpoint.c .Module "mod-msg-print" registered
20:30:57.564 sip_transport.c .Transport manager created.
20:30:57.564 pjsua_core.c .PJSUA state changed: NULL --> CREATED
20:30:57.564 sip_endpoint.c .Module "mod-pjsua-log" registered
20:30:57.564 sip_endpoint.c .Module "mod-tsx-layer" registered
20:30:57.564 sip_endpoint.c .Module "mod-stateful-util" registered
20:30:57.564 sip_endpoint.c .Module "mod-ua" registered
20:30:57.564 sip_endpoint.c .Module "mod-100rel" registered
20:30:57.564 sip_endpoint.c .Module "mod-pjsua" registered
20:30:57.564 sip_endpoint.c .Module "mod-invite" registered
20:30:57.583 alsa_dev.c ..ALSA driver found 0 devices
20:30:57.583 alsa_dev.c ..ALSA initialized
20:30:57.583 pjlib ..select() I/O Queue created (0x7f80a71a88)
20:30:57.593 sip_endpoint.c .Module "mod-evsub" registered
20:30:57.593 sip_endpoint.c .Module "mod-presence" registered
20:30:57.593 sip_endpoint.c .Module "mod-mwi" registered
20:30:57.593 sip_endpoint.c .Module "mod-refer" registered
20:30:57.593 sip_endpoint.c .Module "mod-pjsua-pres" registered
20:30:57.593 sip_endpoint.c .Module "mod-pjsua-im" registered
20:30:57.593 sip_endpoint.c .Module "mod-pjsua-options" registered
20:30:57.593 pjsua_core.c .No SIP worker threads created
20:30:57.593 pjsua_core.c .pjsua version 2.14.1 for Linux-6.6.62/aarch64 initialized
20:30:57.593 pjsua_core.c .PJSUA state changed: CREATED --> INIT
| 20:30:57.594494 [ ] Supported audio codecs: speex/16000/1, speex/8000/1, speex/32000/1, iLBC/8000/1, GSM/8000/1, PCMU/8000/1, PCMA/8000/1, G722/16000/1, opus/48000/2, L16/44100/2, L16/44100/1
20:30:57.595 pjsua_aud.c Setting null sound device..
20:30:57.595 pjsua_aud.c .Opening null sound device..
20:30:57.598 pjsua_core.c SIP UDP socket reachable at 10.10.20.171:5060
20:30:57.598 udp0x7f7e3bbda0 SIP UDP transport started, published address is 10.10.20.171:5060
20:30:57.598 pjsua_core.c PJSUA state changed: INIT --> STARTING
20:30:57.599 sip_endpoint.c .Module "mod-unsolicited-mwi" registered
20:30:57.599 pjsua_core.c .PJSUA state changed: STARTING --> RUNNING
20:30:57.599 pjsua_acc.c Adding account: id=sip:[email protected]
20:30:57.600 pjsua_acc.c .Account sip:[email protected] added with id 0
20:30:57.600 pjsua_acc.c .Acc 0: setting registration..
20:30:57.600 pjsua_acc.c ..Contact for acc 0 updated: <sip:[email protected]:5060;ob>;+sip.ice
20:30:57.600 pjsua_core.c ...TX 504 bytes Request msg REGISTER/cseq=12285 (tdta0x7f7e29a3a8) to UDP 10.10.60.20:5060:
20:30:57.600 pjsua_acc.c ..Acc 0: Registration sent
20:30:57.606 pjsua_core.c .RX 562 bytes Response msg 401/REGISTER/cseq=12285 (rdata0x7f7e295078) from UDP 10.10.60.20:5060:
<some sdp>
20:30:57.606 sip_auth_client.c ...Digest algorithm is "md5"
20:30:57.606 pjsua_core.c ....TX 817 bytes Request msg REGISTER/cseq=12286 (tdta0x7f7e29a3a8) to UDP 10.10.60.20:5060:
<some sdp>
20:30:57.633 pjsua_core.c .RX 584 bytes Response msg 200/REGISTER/cseq=12286 (rdata0x7f7e295088) from UDP 10.10.60.20:5060:
<some sdp>
20:30:57.633 pjsua_acc.c ....SIP outbound status for acc 0 is not active
20:30:57.633 pjsua_acc.c ....sip:[email protected]: registration success, status=200 (OK), will re-register in 299 seconds
20:30:57.633 pjsua_acc.c ....Keep-alive timer started for acc 0, destination:10.10.60.20:5060, interval:13s
| 20:30:57.633943 [1] OnRegState: 200 OK
First issue (well, not sure if it's an issue) is this line after the REGISTER is 200'd:
pjsua_acc.c ....SIP outbound status for acc 0 is not active
Regardless, the registration happens, and I can see on the Grandstream's Web interface that the extension (900) is registered, and idle.
When I try and place a call to another extension on the PBX, this happens:
20:30:58.599 pjsua_aud.c .Closing null sound device..
| 20:31:31.155324 [ ] Got "dial" command for sip:[email protected]:5060
| &id001
| id: null
| message: null
| audio_file: null
| language: en
| action: null
| choices_are_pin: false
| choices: {}
| default_choice:
| id: null
| message: Unknown option
| audio_file: null
| language: en
| action: null
| choices_are_pin: false
| choices: null
| default_choice: null
| timeout_choice: null
| post_action:
| action: return
| level: 1
| timeout: 300.0
| parent_menu: *id001
| cache_audio: false
| wait_for_audio_to_finish: false
| timeout_choice:
| id: null
| message: null
| audio_file: null
| language: en
| action: null
| choices_are_pin: false
| choices: null
| default_choice: null
| timeout_choice: null
| post_action:
| action: hangup
| timeout: 300.0
| parent_menu: *id001
| cache_audio: false
| wait_for_audio_to_finish: false
| post_action:
| action: noop
| timeout: 300.0
| parent_menu: null
| cache_audio: false
| wait_for_audio_to_finish: false
|
| 20:31:31.168959 [1] Registering call with id sip:[email protected]:5060
| 20:31:31.169148 [ ] Add to state: sip:[email protected]:5060
20:31:31.169 pjsua_call.c Making call with acc #0 to sip:[email protected]:5060
20:31:31.174 pjsua_aud.c .Set sound device: capture=-99, playback=-99, mode=0, use_default_settings=0
20:31:31.174 pjsua_aud.c ..Null sound device, mode setting is ignored
20:31:31.174 pjsua_aud.c ..Setting null sound device..
20:31:31.174 pjsua_aud.c ...Opening null sound device..
20:31:31.174 pjsua_media.c .Call 0: initializing media..
20:31:31.175 icetp00 ..Creating ICE stream transport with 2 component(s)
20:31:31.178 icetp00 ...Comp 1/0: host candidate 10.10.20.171:4020 (tpid=64) added
20:31:31.178 icetp00 ...Comp 1/1: host candidate 172.30.232.1:4020 (tpid=64) added
20:31:31.178 icetp00 ...Comp 1/2: host candidate 172.30.32.1:4020 (tpid=64) added
20:31:31.182 icetp00 ...Comp 2/0: host candidate 10.10.20.171:4034 (tpid=64) added
20:31:31.182 icetp00 ...Comp 2/1: host candidate 172.30.232.1:4034 (tpid=64) added
20:31:31.182 icetp00 ...Comp 2/2: host candidate 172.30.32.1:4034 (tpid=64) added
20:31:31.182 icetp00 ...ICE stream transport 0x7f7e29a2a8 created
20:31:31.182 pjsua_media.c ..Media index 0 selected for audio call 0
20:31:31.185 srtp0x7f7e2c8870 SRTP transport created
20:31:31.185 icetp00 ICE session created, comp_cnt=2, role is Controlling agent
20:31:31.185 icetp00 ICE nomination type set to aggressive
20:31:31.185 icetp00 Candidate 0 added: comp_id=1, type=host, foundation=Ha0a14ab, addr=10.10.20.171:4020, base=10.10.20.171:4020, prio=0x7effffff (2130706431)
20:31:31.185 icetp00 Candidate 1 added: comp_id=1, type=host, foundation=Hac1ee801, addr=172.30.232.1:4020, base=172.30.232.1:4020, prio=0x7efffeff (2130706175)
20:31:31.185 icetp00 Candidate 2 added: comp_id=1, type=host, foundation=Hac1e2001, addr=172.30.32.1:4020, base=172.30.32.1:4020, prio=0x7efffdff (2130705919)
20:31:31.185 icetp00 Candidate 3 added: comp_id=2, type=host, foundation=Ha0a14ab, addr=10.10.20.171:4034, base=10.10.20.171:4034, prio=0x7efffffe (2130706430)
20:31:31.185 icetp00 Candidate 4 added: comp_id=2, type=host, foundation=Hac1ee801, addr=172.30.232.1:4034, base=172.30.232.1:4034, prio=0x7efffefe (2130706174)
20:31:31.185 icetp00 Candidate 5 added: comp_id=2, type=host, foundation=Hac1e2001, addr=172.30.32.1:4034, base=172.30.32.1:4034, prio=0x7efffdfe (2130705918)
20:31:31.186 tsx0x7f7e530358 ...Temporary failure in sending Request msg INVITE/cseq=6990 (tdta0x7f7e29c898), will try next server: Unsupported transport (PJSIP_EUNSUPTRANSPORT)
20:31:31.186 pjsua_core.c ...TX 1789 bytes Request msg INVITE/cseq=6990 (tdta0x7f7e29c898) to UDP 10.10.60.20:5060:
INVITE sip:[email protected]:5060 SIP/2.0
Via: SIP/2.0/UDP 10.10.20.171:5060;rport;branch=z9hG4bKPjd35KgBDISk5AO1X-D60f1daLEh1DphQn
Max-Forwards: 70
From: sip:[email protected];tag=q-E0RQiqoKx6akWmPjMXF37b.NBbGsSO
To: sip:[email protected]
Contact: <sip:[email protected]:5060;ob>;+sip.ice
Call-ID: XQzqv3HdAEVFmCOI0BsG8XQZI-NWg-ss
CSeq: 6990 INVITE
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, timer, norefersub
Session-Expires: 1800
Min-SE: 90
Content-Type: application/sdp
Content-Length: 1201
v=0
o=- 3946390291 3946390291 IN IP4 10.10.20.171
s=pjmedia
b=AS:117
t=0 0
a=X-nat:0
m=audio 4020 RTP/AVP 96 97 98 99 3 0 8 9 100 120 121 122 123
c=IN IP4 10.10.20.171
b=TIAS:96000
a=rtcp:4034 IN IP4 10.10.20.171
a=sendrecv
a=rtpmap:96 speex/16000
a=rtpmap:97 speex/8000
a=rtpmap:98 speex/32000
a=rtpmap:99 iLBC/8000
a=fmtp:99 mode=30
a=rtpmap:3 GSM/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:9 G722/8000
a=rtpmap:100 opus/48000/2
a=fmtp:100 useinbandfec=1
a=rtpmap:120 telephone-event/16000
a=fmtp:120 0-16
a=rtpmap:121 telephone-event/8000
a=fmtp:121 0-16
a=rtpmap:122 telephone-event/32000
a=fmtp:122 0-16
a=rtpmap:123 telephone-event/48000
a=fmtp:123 0-16
a=ssrc:1079637296 cname:2d0042027f907e94
a=ice-ufrag:462ddb0c
a=ice-pwd:3e95b5206a4c03ac7a7ac4ad
a=candidate:Ha0a14ab 1 UDP 2130706431 10.10.20.171 4020 typ host
a=candidate:Hac1ee801 1 UDP 2130706175 172.30.232.1 4020 typ host
a=candidate:Hac1e2001 1 UDP 2130705919 172.30.32.1 4020 typ host
a=candidate:Ha0a14ab 2 UDP 2130706430 10.10.20.171 4034 typ host
a=candidate:Hac1ee801 2 UDP 2130706174 172.30.232.1 4034 typ host
a=candidate:Hac1e2001 2 UDP 2130705918 172.30.32.1 4034 typ host
--end msg--
| 20:31:31.188561 [1] Calling
20:31:31.687 pjsua_core.c .TX 1789 bytes Request msg INVITE/cseq=6990 (tdta0x7f7e29c898) to UDP 10.10.60.20:5060:
<sdp invite occurs 4 more times>
Obviously the standout message here is:
20:31:31.186 tsx0x7f7e530358 ...Temporary failure in sending Request msg INVITE/cseq=6990 (tdta0x7f7e29c898), will try next server: Unsupported transport (PJSIP_EUNSUPTRANSPORT)
I've tried any number of combinations of SIP URIs (with transport=udp, transport=tcp, transport=tls), SRTP settings on the Grandstream's extension (Disabled, Optional, Enabled and enforced), tried turning of NAT in the Grandstream PBX, Enabled/Disabled Direct Media.
Not knowing much about SIP, I'm falling around in the dark. Do those error messages mean anything to anyone?
