perfectly agree that there are so many queries to this end and almost all pointers are towards codec negotiation failures. i still have this issue after i see that codec negotiation goes through.
i have set up 2 Js-SIP clients. webrtc.
however when i place a call from one client (extension 1000) to another (extension 1001), i receive a "488 Not Acceptable Here" message and the call ends with "Bad Media Description" error and i never get the call on receiver side
i am completely at the surface still and have given it a try with all solutions posted to this end
attaching the entire log in a file here. please help
INVITE sip
INVITE
sip:1001@11.22.33.44 SIP/2.0
Via: SIP/2.0/WSS 11.22.33.44;branch=z9hG4bK7948245
Max-Forwards: 69
To: <
sip:1001@11.22.33.44>
From: <
sip:1000@11.22.33.44>;tag=jimkkm04qn
Call-ID: aoc0tkcjs47mrj5n1jl4
CSeq: 3752 INVITE
X-Test: tester-tested
Contact: <
sip:1000@11.22.33.44;ob>
Content-Type: application/sdp
Allow: INVITE,ACK,CANCEL,BYE,UPDATE,MESSAGE,OPTIONS,REFER,INFO,NOTIFY
Supported: ice,replaces,outbound
User-Agent: JsSIP 3.9.1
Content-Length: 1950
v=0
o=- 8689874841498562319 2 IN IP4 127.0.0.1
s=-
t=0 0
a=group:BUNDLE 0
a=extmap-allow-mixed
a=msid-semantic: WMS qikHHSycCzJUUpbTJgCfWpaVC44ukpKp5iAX
m=audio 59566 UDP/TLS/RTP/SAVPF 111 63 103 104 9 0 8 106 105 13 110 112 113 126
c=IN IP4 192.168.1.64
a=rtcp:9 IN IP4 0.0.0.0
a=candidate:3460887983 1 udp 2122260223 192.168.1.64 59566 typ host generation 0 network-id 1 network-cost 10
a=candidate:2403671225 1 udp 2122194687 172.27.239.86 55376 typ host generation 0 network-id 2 network-cost 50
a=candidate:2160789855 1 tcp 1518280447 192.168.1.64 9 typ host tcptype active generation 0 network-id 1 network-cost 10
a=candidate:3251036233 1 tcp 1518214911 172.27.239.86 9 typ host tcptype active generation 0 network-id 2 network-cost 50
a=ice-ufrag:KQsy
a=ice-pwd:oTFySc5ArZ1oxVZ+qb+errt5
a=ice-options:trickle
a=fingerprint:sha-256 C9:60:D5:F6:7C:26:A5:2B:A5:1C:C5:23:0A:36:4B:E2:CE:D5:C8:15:8A:AD:35:DB:2C:E3:7D:C4:E8:7C:D3:E2
a=setup:actpass
a=mid:0
a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level
a=extmap:2
http://www.webrtc.org/experiments/rtp-hdrext/abs-send-timea=extmap:3
http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01a=extmap:4 urn:ietf:params:rtp-hdrext:sdes:mid
a=sendrecv
a=msid:qikHHSycCzJUUpbTJgCfWpaVC44ukpKp5iAX 871ec968-71eb-4810-a9ff-dcd4c80705b2
a=rtcp-mux
a=rtpmap:111 opus/48000/2
a=rtcp-fb:111 transport-cc
a=fmtp:111 minptime=10;useinbandfec=1
a=rtpmap:63 red/48000/2
a=fmtp:63 111/111
a=rtpmap:103 ISAC/16000
a=rtpmap:104 ISAC/32000
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:106 CN/32000
a=rtpmap:105 CN/16000
a=rtpmap:13 CN/8000
a=rtpmap:110 telephone-event/48000
a=rtpmap:112 telephone-event/32000
a=rtpmap:113 telephone-event/16000
a=rtpmap:126 telephone-event/8000
a=ssrc:3961239200 cname:Bb33wRyqhUohexBZ
a=ssrc:3961239200 msid:qikHHSycCzJUUpbTJgCfWpaVC44ukpKp5iAX 871ec968-71eb-4810-a9ff-dcd4c80705b2
=================
Remote SDP:
2022-10-06 10:18:15.078122 99.83% [NOTICE] switch_channel.c:1123 New Channel sofia/external/
1000@11.22.33.44 []
2022-10-06 10:18:15.078122 99.83% [DEBUG] switch_core_state_machine.c:581 (sofia/external/
1000@11.22.33.44) Running State Change CS_NEW (Cur 1 Tot 11)
2022-10-06 10:18:15.078122 99.83% [INFO] sofia.c:10465 sofia/external/
1000@11.22.33.44 receiving invite from
3.7.130.46:54985 version: 1.10.8-dev git 98d2e62 2022-09-09 13:32:35Z 64bit call-id: aoc0tkcjs47mrj5n1jl4
2022-10-06 10:18:15.078122 99.83% [DEBUG] sofia.c:11674 Setting NAT mode based on websockets
2022-10-06 10:18:15.078122 99.83% [DEBUG] sofia.c:7499 Channel sofia/external/
1000@11.22.33.44 entering state [received][100]
2022-10-06 10:18:15.078122 99.83% [DEBUG] sofia.c:7509 Remote SDP:
v=0
o=- 8689874841498562319 2 IN IP4 127.0.0.1
s=-
t=0 0
a=group:BUNDLE 0
a=extmap-allow-mixed
a=msid-semantic: WMS qikHHSycCzJUUpbTJgCfWpaVC44ukpKp5iAX
m=audio 59566 UDP/TLS/RTP/SAVPF 111 63 103 104 9 0 8 106 105 13 110 112 113 126
c=IN IP4 192.168.1.64
a=rtpmap:111 opus/48000/2
a=fmtp:111 minptime=10;useinbandfec=1
a=rtpmap:63 red/48000/2
a=fmtp:63 111/111
a=rtpmap:103 ISAC/16000
a=rtpmap:104 ISAC/32000
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:106 CN/32000
a=rtpmap:105 CN/16000
a=rtpmap:13 CN/8000
a=rtpmap:110 telephone-event/48000
a=rtpmap:112 telephone-event/32000
a=rtpmap:113 telephone-event/16000
a=rtpmap:126 telephone-event/8000
a=rtcp:9 IN IP4 0.0.0.0
a=candidate:3460887983 1 udp 2122260223 192.168.1.64 59566 typ host generation 0 network-id 1 network-cost 10
a=candidate:2403671225 1 udp 2122194687 172.27.239.86 55376 typ host generation 0 network-id 2 network-cost 50
a=candidate:2160789855 1 tcp 1518280447 192.168.1.64 9 typ host tcptype active generation 0 network-id 1 network-cost 10
a=candidate:3251036233 1 tcp 1518214911 172.27.239.86 9 typ host tcptype active generation 0 network-id 2 network-cost 50
a=ice-ufrag:KQsy
a=ice-pwd:oTFySc5ArZ1oxVZ+qb+errt5
a=ice-options:trickle
a=fingerprint:sha-256 C9:60:D5:F6:7C:26:A5:2B:A5:1C:C5:23:0A:36:4B:E2:CE:D5:C8:15:8A:AD:35:DB:2C:E3:7D:C4:E8:7C:D3:E2
a=setup:actpass
a=mid:0
a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level
a=extmap:2
http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time a=extmap:3
http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01 a=extmap:4 urn:ietf:params:rtp-hdrext:sdes:mid
a=msid:qikHHSycCzJUUpbTJgCfWpaVC44ukpKp5iAX 871ec968-71eb-4810-a9ff-dcd4c80705b2
a=rtcp-mux
a=rtcp-fb:111 transport-cc
a=ssrc:3961239200 cname:Bb33wRyqhUohexBZ
a=ssrc:3961239200 msid:qikHHSycCzJUUpbTJgCfWpaVC44ukpKp5iAX 871ec968-71eb-4810-a9ff-dcd4c80705b2
=============================================
codec negotiation. i have removed OPUS as it was giving me bitrate mismatch
G722, PCMU, PCMA are exact match
2022-10-06 10:18:25.018122 99.80% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [opus:111:48000:20:0:1]/[G722:9:8000:20:64000:1]
2022-10-06 10:18:25.018122 99.80% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [opus:111:48000:20:0:1]/[PCMU:0:8000:20:64000:1]
2022-10-06 10:18:25.018122 99.80% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [opus:111:48000:20:0:1]/[PCMA:8:8000:20:64000:1]
2022-10-06 10:18:25.018122 99.80% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [red:63:48000:20:0:2]/[G722:9:8000:20:64000:1]
2022-10-06 10:18:25.018122 99.80% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [red:63:48000:20:0:2]/[PCMU:0:8000:20:64000:1]
2022-10-06 10:18:25.018122 99.80% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [red:63:48000:20:0:2]/[PCMA:8:8000:20:64000:1]
2022-10-06 10:18:25.018122 99.80% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [ISAC:103:16000:30:32000:1]/[G722:9:8000:20:64000:1]
2022-10-06 10:18:25.018122 99.80% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [ISAC:103:16000:30:32000:1]/[PCMU:0:8000:20:64000:1]
2022-10-06 10:18:25.018122 99.80% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [ISAC:103:16000:30:32000:1]/[PCMA:8:8000:20:64000:1]
2022-10-06 10:18:25.018122 99.80% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [ISAC:104:32000:30:32000:1]/[G722:9:8000:20:64000:1]
2022-10-06 10:18:25.018122 99.80% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [ISAC:104:32000:30:32000:1]/[PCMU:0:8000:20:64000:1]
2022-10-06 10:18:25.018122 99.80% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [ISAC:104:32000:30:32000:1]/[PCMA:8:8000:20:64000:1]
2022-10-06 10:18:25.018122 99.80% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2022-10-06 10:18:25.018122 99.80% [DEBUG] switch_core_media.c:5718 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
2022-10-06 10:18:25.018122 99.80% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2022-10-06 10:18:25.018122 99.80% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2022-10-06 10:18:25.018122 99.80% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2022-10-06 10:18:25.018122 99.80% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2022-10-06 10:18:25.018122 99.80% [DEBUG] switch_core_media.c:5718 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2022-10-06 10:18:25.018122 99.80% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2022-10-06 10:18:25.018122 99.80% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2022-10-06 10:18:25.018122 99.80% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2022-10-06 10:18:25.018122 99.80% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2022-10-06 10:18:25.018122 99.80% [DEBUG] switch_core_media.c:5718 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2022-10-06 10:18:25.018122 99.80% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [CN:105:16000:20:0:1]/[G722:9:8000:20:64000:1]
2022-10-06 10:18:25.018122 99.80% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [CN:105:16000:20:0:1]/[PCMU:0:8000:20:64000:1]
2022-10-06 10:18:25.018122 99.80% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [CN:105:16000:20:0:1]/[PCMA:8:8000:20:64000:1]
2022-10-06 10:18:25.018122 99.80% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [CN:13:8000:20:0:1]/[G722:9:8000:20:64000:1]
2022-10-06 10:18:25.018122 99.80% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [CN:13:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
2022-10-06 10:18:25.018122 99.80% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [CN:13:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
=======================================================
SIP to receiver
2022-10-06 10:18:25.018122 99.80% [DEBUG] mod_sofia.c:913 Local SDP sofia/external/
1000@11.22.33.44:
v=0
o=FreeSWITCH 1665021629 1665021630 IN IP4 11.22.33.44
s=FreeSWITCH
c=IN IP4 11.22.33.44
t=0 0
a=msid-semantic: WMS VUSFGZ4CEjXvMLYzijtMWkwcRx3I8zET
m=audio 29876 UDP/AVPF 9 126
a=rtpmap:9 G722/8000
a=rtpmap:126 telephone-event/8000
a=ptime:20
a=sendrecv
a=rtcp:29877 IN IP4 11.22.33.44
a=ice-ufrag:0OsMZPPHcIga8KUi
a=ice-pwd:XaZYj9vC6oyD4TjUxCxnhcUk
a=candidate:0153546995 1 udp 2130706431 11.22.33.44 29876 typ host generation 0
a=candidate:0153546995 2 udp 2130706430 11.22.33.44 29877 typ host generation 0
a=end-of-candidates
a=ssrc:3007569695 cname:kmpRbjjGt625HQuP
a=ssrc:3007569695 msid:VUSFGZ4CEjXvMLYzijtMWkwcRx3I8zET a0
a=ssrc:3007569695 mslabel:VUSFGZ4CEjXvMLYzijtMWkwcRx3I8zET
a=ssrc:3007569695 label:VUSFGZ4CEjXvMLYzijtMWkwcRx3I8zETa0
2022-10-06 10:18:25.018122 99.80% [NOTICE] mod_dptools.c:1408 Channel [sofia/external/
1000@11.22.33.44] has been answered
send 985 bytes to wss/[3.7.130.46]:54985 at 10:18:25.032155:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/WSS 11.22.33.44;branch=z9hG4bK7948245;received=3.7.130.46;rport=54985
From: <
sip:1000@11.22.33.44>;tag=jimkkm04qn
To: <
sip:1001@11.22.33.44>;tag=0jtBBc4ryZ8Zg
Call-ID: aoc0tkcjs47mrj5n1jl4
CSeq: 3752 INVITE
Contact: <sip:1001@11.22.33.44:5080;transport=udp>
User-Agent: FreeSWITCH-mod_sofia/1.10.8-dev+git~20220909T133235Z~98d2e6212c~64bit
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, refer
Session-Expires: 120;refresher=uas
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 196
Remote-Party-ID: "1001" <
sip:1001@11.22.33.44>;party=calling;privacy=off;screen=no
v=0
o=FreeSWITCH 1665021629 1665021630 IN IP4 11.22.33.44
s=FreeSWITCH
c=IN IP4 11.22.33.44
t=0 0
a=msid-semantic: WMS VUSFGZ4CEjXvMLYzijtMWkwcRx3I8zET
m=audio 0 UDP/TLS/RTP/SAVPF 19 2022-10-06 10:18:25.018122 99.80% [DEBUG] switch_channel.c:3950 (sofia/external/
1000@11.22.33.44) Callstate Change EARLY -> ACTIVE
2022-10-06 10:18:25.018122 99.80% [DEBUG] sofia.c:7499 Channel sofia/external/
1000@11.22.33.44 entering state [completed][200]
EXECUTE [depth=0] sofia/external/
1000@11.22.33.44 sleep(1000)
==============================================
and then the BYE
------------------------------------------------------------------------
ACK sip:1001@11.22.33.44:5080;transport=udp SIP/2.0
Via: SIP/2.0/WSS 11.22.33.44;branch=z9hG4bK8228266
Max-Forwards: 69
To: <
sip:1001@11.22.33.44>;tag=0jtBBc4ryZ8Zg
From: <
sip:1000@11.22.33.44>;tag=jimkkm04qn
Call-ID: aoc0tkcjs47mrj5n1jl4
CSeq: 3752 ACK
Allow: INVITE,ACK,CANCEL,BYE,UPDATE,MESSAGE,OPTIONS,REFER,INFO,NOTIFY
Supported: outbound
User-Agent: JsSIP 3.9.1
Content-Length: 0
recv 462 bytes from wss/[3.7.130.46]:54985 at 10:18:26.584127:
------------------------------------------------------------------------
BYE sip:1001@11.22.33.44:5080;transport=udp SIP/2.0
Via: SIP/2.0/WSS 11.22.33.44;branch=z9hG4bK162798
Max-Forwards: 69
To: <
sip:1001@11.22.33.44>;tag=0jtBBc4ryZ8Zg
From: <
sip:1000@11.22.33.44>;tag=jimkkm04qn
Call-ID: aoc0tkcjs47mrj5n1jl4
CSeq: 3753 BYE
Reason: SIP ;cause=488; text="Not Acceptable Here"Allow: INVITE,ACK,CANCEL,BYE,UPDATE,MESSAGE,OPTIONS,REFER,INFO,NOTIFY
Supported: outbound
User-Agent: JsSIP 3.9.1
Content-Length: 0
--
Shwetank