Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

WebRTC ICE negotiation on AWS #637

Open
franck-malka opened this issue Dec 9, 2021 · 13 comments
Open

WebRTC ICE negotiation on AWS #637

franck-malka opened this issue Dec 9, 2021 · 13 comments

Comments

@franck-malka
Copy link

Any help is appreciated to solve WebRTC ICE negotiation on an AWS instance.

On AWS, the instance hosting the SIPSorcery stack has its own private address.
there are 2 ways to give public access to the AWS instance.

1/ assign a public IP to the instance; in this case the public IP is routed to the instance but is not configured in the instance OS itself; Similarly to a NAT public to private scenario.

2/ have a load balancer to front-end the instance, in this case the public access is with the load balancer and the traffic is forwarded from the load balancer to the internal private IP of the SIPSorcery stack instance.

In both scenarios, the ICE negotiation fails when we try to setup a WebRTC channel.

See traces bellow using scenario 1/
07:09:14,596 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | UAS call progressing with Trying.
07:09:14,601 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | UAS call progressing with Ringing.
07:09:15,238 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | CreateRtpSocket attempting to create and bind RTP socket(s) on [::]:0.
07:09:15,238 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | CreateBoundUdpSocket attempting to create and bind UDP socket(s) on [::]:0.
07:09:15,239 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | CreateBoundUdpSocket successfully bound on [::]:38953, dual mode True.
07:09:15,239 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | Successfully bound RTP socket [::]:38953 (dual mode True).
07:09:15,244 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | RTPChannel for [::]:38953 started.
07:09:15,252 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | RTP ICE Channel discovered 2 local candidates.
07:09:15,268 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | Excluding audio format 117:L16 from audio extras source supported list.
07:09:15,269 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | Excluding audio format 118:L16 from audio extras source supported list.
07:09:15,288 | WRN | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | Excluding unrecognised well known media format ID 63.
07:09:15,303 | WRN | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | Excluding unrecognised well known media format ID 63.
07:09:15,303 | WRN | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | Excluding unrecognised well known media format ID 63.
07:09:15,318 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | RTP ICE Channel remote credentials set.
07:09:15,326 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | RTP ICE Channel received remote candidate: 842163049 1 udp 1677729535 62.90.39.198 31667 typ srflx raddr 0.0.0.0 rport 0 generation 0
07:09:15,332 | WRN | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | Excluding unrecognised well known media format ID 63.
07:09:15,335 | WRN | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | Excluding unrecognised well known media format ID 63.
07:09:15,356 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | Adding new candidate pair to checklist for: udp:[::]:38953 (host)->udp:62.90.39.198:31667 (srflx)
07:09:15,358 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | ICE RTP channel sending connectivity check for udp:[::]:38953 (host)->udp:62.90.39.198:31667 (srflx) from [::]:38953 to 62.90.39.198:31667 (use candidate False).
07:09:15,905 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | ICE RTP channel sending connectivity check for udp:[::]:38953 (host)->udp:62.90.39.198:31667 (srflx) from [::]:38953 to 62.90.39.198:31667 (use candidate False).
07:09:16,406 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | ICE RTP channel sending connectivity check for udp:[::]:38953 (host)->udp:62.90.39.198:31667 (srflx) from [::]:38953 to 62.90.39.198:31667 (use candidate False).
07:09:16,982 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | ICE RTP channel sending connectivity check for udp:[::]:38953 (host)->udp:62.90.39.198:31667 (srflx) from [::]:38953 to 62.90.39.198:31667 (use candidate False).
07:09:17,503 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | ICE RTP channel sending connectivity check for udp:[::]:38953 (host)->udp:62.90.39.198:31667 (srflx) from [::]:38953 to 62.90.39.198:31667 (use candidate False).
07:09:18,045 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | ICE RTP channel sending connectivity check for udp:[::]:38953 (host)->udp:62.90.39.198:31667 (srflx) from [::]:38953 to 62.90.39.198:31667 (use candidate False).
07:09:18,585 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | ICE RTP channel sending connectivity check for udp:[::]:38953 (host)->udp:62.90.39.198:31667 (srflx) from [::]:38953 to 62.90.39.198:31667 (use candidate False).
07:09:19,088 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | ICE RTP channel sending connectivity check for udp:[::]:38953 (host)->udp:62.90.39.198:31667 (srflx) from [::]:38953 to 62.90.39.198:31667 (use candidate False).
07:09:19,626 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | ICE RTP channel sending connectivity check for udp:[::]:38953 (host)->udp:62.90.39.198:31667 (srflx) from [::]:38953 to 62.90.39.198:31667 (use candidate False).
07:09:20,234 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | ICE RTP channel sending connectivity check for udp:[::]:38953 (host)->udp:62.90.39.198:31667 (srflx) from [::]:38953 to 62.90.39.198:31667 (use candidate False).
07:09:20,735 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | ICE RTP channel sending connectivity check for udp:[::]:38953 (host)->udp:62.90.39.198:31667 (srflx) from [::]:38953 to 62.90.39.198:31667 (use candidate False).
07:09:21,341 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | ICE RTP channel sending connectivity check for udp:[::]:38953 (host)->udp:62.90.39.198:31667 (srflx) from [::]:38953 to 62.90.39.198:31667 (use candidate False).
07:09:21,874 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | ICE RTP channel sending connectivity check for udp:[::]:38953 (host)->udp:62.90.39.198:31667 (srflx) from [::]:38953 to 62.90.39.198:31667 (use candidate False).
07:09:22,046 | WRN | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | SendRtcpReport cannot be called on a secure session before calling SetSecurityContext.
07:09:22,411 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | ICE RTP channel sending connectivity check for udp:[::]:38953 (host)->udp:62.90.39.198:31667 (srflx) from [::]:38953 to 62.90.39.198:31667 (use candidate False).
07:09:23,059 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | ICE RTP channel sending connectivity check for udp:[::]:38953 (host)->udp:62.90.39.198:31667 (srflx) from [::]:38953 to 62.90.39.198:31667 (use candidate False).
07:09:23,559 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | ICE RTP channel sending connectivity check for udp:[::]:38953 (host)->udp:62.90.39.198:31667 (srflx) from [::]:38953 to 62.90.39.198:31667 (use candidate False).
07:09:24,095 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | ICE RTP channel sending connectivity check for udp:[::]:38953 (host)->udp:62.90.39.198:31667 (srflx) from [::]:38953 to 62.90.39.198:31667 (use candidate False).
07:09:24,713 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | ICE RTP channel sending connectivity check for udp:[::]:38953 (host)->udp:62.90.39.198:31667 (srflx) from [::]:38953 to 62.90.39.198:31667 (use candidate False).
07:09:25,304 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | ICE RTP channel sending connectivity check for udp:[::]:38953 (host)->udp:62.90.39.198:31667 (srflx) from [::]:38953 to 62.90.39.198:31667 (use candidate False).
07:09:25,781 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | ICE RTP channel sending connectivity check for udp:[::]:38953 (host)->udp:62.90.39.198:31667 (srflx) from [::]:38953 to 62.90.39.198:31667 (use candidate False).
07:09:26,409 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | ICE RTP channel sending connectivity check for udp:[::]:38953 (host)->udp:62.90.39.198:31667 (srflx) from [::]:38953 to 62.90.39.198:31667 (use candidate False).
07:09:26,939 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | ICE RTP channel sending connectivity check for udp:[::]:38953 (host)->udp:62.90.39.198:31667 (srflx) from [::]:38953 to 62.90.39.198:31667 (use candidate False).
07:09:27,132 | WRN | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | SendRtcpReport cannot be called on a secure session before calling SetSecurityContext.
07:09:27,469 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | ICE RTP channel sending connectivity check for udp:[::]:38953 (host)->udp:62.90.39.198:31667 (srflx) from [::]:38953 to 62.90.39.198:31667 (use candidate False).
07:09:28,075 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | ICE RTP channel sending connectivity check for udp:[::]:38953 (host)->udp:62.90.39.198:31667 (srflx) from [::]:38953 to 62.90.39.198:31667 (use candidate False).
07:09:28,665 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | ICE RTP channel sending connectivity check for udp:[::]:38953 (host)->udp:62.90.39.198:31667 (srflx) from [::]:38953 to 62.90.39.198:31667 (use candidate False).
07:09:29,194 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | ICE RTP channel sending connectivity check for udp:[::]:38953 (host)->udp:62.90.39.198:31667 (srflx) from [::]:38953 to 62.90.39.198:31667 (use candidate False).
07:09:29,728 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | ICE RTP channel sending connectivity check for udp:[::]:38953 (host)->udp:62.90.39.198:31667 (srflx) from [::]:38953 to 62.90.39.198:31667 (use candidate False).
07:09:30,200 | WRN | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | SendRtcpReport cannot be called on a secure session before calling SetSecurityContext.
07:09:30,233 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | ICE RTP channel sending connectivity check for udp:[::]:38953 (host)->udp:62.90.39.198:31667 (srflx) from [::]:38953 to 62.90.39.198:31667 (use candidate False).
07:09:30,767 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | ICE RTP channel sending connectivity check for udp:[::]:38953 (host)->udp:62.90.39.198:31667 (srflx) from [::]:38953 to 62.90.39.198:31667 (use candidate False).
07:09:31,273 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | ICE RTP channel sending connectivity check for udp:[::]:38953 (host)->udp:62.90.39.198:31667 (srflx) from [::]:38953 to 62.90.39.198:31667 (use candidate False).
07:09:31,364 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | ICE RTP channel checks for checklist entry have timed out, state being set to failed: udp:[::]:38953 (host)->udp:62.90.39.198:31667 (srflx).
07:09:31,365 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | Peer connection closed with reason ice disconnection.
07:09:31,365 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | RtpIceChannel for [::]:38953 closed.
07:09:31,430 | DBG | SeriousSIP.SIPSorcery | 1b43rddd6hgvfqimp2pr | RTPChannel closing, RTP receiver on port 38953. Reason: ice disconnection.
@sipsorcery
Copy link
Member

There's no obvious reason I can think of that the configuration wouldn't work. From the logs it seems nothing was received from the remote peer on 62.90.39.198:31667. Do you have any logs from it? Also double check you don't have a firewall on your AWS isntacne blocking access to the ephemeral port range used by the RTP sockets.

@franck-malka
Copy link
Author

What port ranges should be allowed in the FW?

@sipsorcery
Copy link
Member

sipsorcery commented Dec 9, 2021 •
edited
Loading

It depends on your OS.

See Ephemeral Ports.

@franck-malka
Copy link
Author

franck-malka commented Dec 9, 2021 via email

@franck-malka
Copy link
Author

in fact stun procedure is completed,
it's the ice connectivity check that time out

ICE RTP channel checks for checklist entry have timed out

@franck-malka
Copy link
Author

I made the same test with the latest code, but now there is a problem with the certificate that wasn't present with the older code

13/12/2021 10:42:46|Error|<>c__DisplayClass71_0.b__0|Authentication failed, see inner exception.
13/12/2021 10:42:46|Debug|<>c__DisplayClass71_0.b__0|System.Security.Authentication.AuthenticationException: Authentication failed, see inner exception.
---> System.ComponentModel.Win32Exception (0x80090327): Une erreur inconnue s’est produite lors du traitement du certificat.
--- End of inner exception stack trace ---
at System.Net.Security.SslStream.ForceAuthenticationAsync[TIOAdapter](TIOAdapter adapter, Boolean receiveFirst, Byte[] reAuthenticationData, Boolean isApm)
at System.Net.Security.SslStream.ProcessAuthentication(Boolean isAsync, Boolean isApm, CancellationToken cancellationToken)
at System.Net.Security.SslStream.AuthenticateAsServer(SslServerAuthenticationOptions sslServerAuthenticationOptions)
at System.Net.Security.SslStream.AuthenticateAsServer(X509Certificate serverCertificate, Boolean clientCertificateRequired, SslProtocols enabledSslProtocols, Boolean checkCertificateRevocation)
at WebSocketSharp.Net.WebSockets.TcpListenerWebSocketContext..ctor(TcpClient tcpClient, String protocol, Boolean secure, ServerSslConfiguration sslConfig, Logger log)
at WebSocketSharp.Server.WebSocketServer.<>c__DisplayClass71_0.b__0(Object state)

@franck-malka
Copy link
Author

I had to specific the tls version in the SIPWebSocketChannel constructor to solve this problem.

sslConfig.EnabledSslProtocols = System.Security.Authentication.SslProtocols.Tls12;

now the socket is established but the ICE negotiation still fails

@franck-malka
Copy link
Author

I can see the
STUN BindingRequest
STUN BindingSuccessResponse

But the ICE RTP Channel is timing out
16:32:31,265 | DBG | sipsorcery | svgi34gj8fdgj3r4keht | ICE RTP channel sending connectivity check for udp:[::]:47443 (host)->udp:172.25.208.1:59837 (host) from [::]:47443 to 172.25.208.1:59837 (use candidate False).
16:32:31,317 | DBG | sipsorcery | svgi34gj8fdgj3r4keht | ICE RTP channel sending connectivity check for udp:[::]:47443 (host)->udp:172.23.64.1:59838 (host) from [::]:47443 to 172.23.64.1:59838 (use candidate False).
16:32:31,416 | DBG | sipsorcery | svgi34gj8fdgj3r4keht | ICE RTP channel sending connectivity check for udp:[::]:47443 (host)->udp:62.90.39.198:58189 (srflx) from [::]:47443 to 62.90.39.198:58189 (use candidate False).
16:32:31,464 | DBG | sipsorcery | svgi34gj8fdgj3r4keht | ICE RTP channel checks for checklist entry have timed out, state being set to failed: udp:[::]:47443 (host)->udp:192.168.253.14:59834 (host).
16:32:31,464 | DBG | sipsorcery | svgi34gj8fdgj3r4keht | ICE RTP channel checks for checklist entry have timed out, state being set to failed: udp:[::]:47443 (host)->udp:192.168.137.1:59835 (host).
16:32:31,464 | DBG | sipsorcery | svgi34gj8fdgj3r4keht | ICE RTP channel sending connectivity check for udp:[::]:47443 (host)->udp:192.168.253.14:9 (host) from [::]:47443 to 192.168.253.14:9 (use candidate False).
16:32:31,516 | DBG | sipsorcery | svgi34gj8fdgj3r4keht | ICE RTP channel checks for checklist entry have timed out, state being set to failed: udp:[::]:47443 (host)->udp:192.168.88.19:59836 (host).
16:32:31,516 | DBG | sipsorcery | svgi34gj8fdgj3r4keht | ICE RTP channel sending connectivity check for udp:[::]:47443 (host)->udp:192.168.137.1:9 (host) from [::]:47443 to 192.168.137.1:9 (use candidate False).
16:32:31,565 | DBG | sipsorcery | svgi34gj8fdgj3r4keht | ICE RTP channel checks for checklist entry have timed out, state being set to failed: udp:[::]:47443 (host)->udp:172.25.208.1:59837 (host).
16:32:31,565 | DBG | sipsorcery | svgi34gj8fdgj3r4keht | ICE RTP channel sending connectivity check for udp:[::]:47443 (host)->udp:192.168.88.19:9 (host) from [::]:47443 to 192.168.88.19:9 (use candidate False).
16:32:31,617 | DBG | sipsorcery | svgi34gj8fdgj3r4keht | ICE RTP channel checks for checklist entry have timed out, state being set to failed: udp:[::]:47443 (host)->udp:172.23.64.1:59838 (host).
16:32:31,618 | DBG | sipsorcery | svgi34gj8fdgj3r4keht | ICE RTP channel sending connectivity check for udp:[::]:47443 (host)->udp:172.25.208.1:9 (host) from [::]:47443 to 172.25.208.1:9 (use candidate False).
16:32:31,665 | DBG | sipsorcery | svgi34gj8fdgj3r4keht | ICE RTP channel checks for checklist entry have timed out, state being set to failed: udp:[::]:47443 (host)->udp:62.90.39.198:58189 (srflx).
16:32:31,666 | DBG | sipsorcery | svgi34gj8fdgj3r4keht | ICE RTP channel sending connectivity check for udp:[::]:47443 (host)->udp:172.23.64.1:9 (host) from [::]:47443 to 172.23.64.1:9 (use candidate False).
16:32:31,716 | DBG | sipsorcery | svgi34gj8fdgj3r4keht | ICE RTP channel checks for checklist entry have timed out, state being set to failed: udp:[::]:47443 (host)->udp:192.168.253.14:9 (host).
16:32:31,816 | DBG | sipsorcery | svgi34gj8fdgj3r4keht | ICE RTP channel checks for checklist entry have timed out, state being set to failed: udp:[::]:47443 (host)->udp:192.168.137.1:9 (host).
16:32:31,816 | DBG | sipsorcery | svgi34gj8fdgj3r4keht | ICE RTP channel checks for checklist entry have timed out, state being set to failed: udp:[::]:47443 (host)->udp:192.168.88.19:9 (host).
16:32:31,865 | DBG | sipsorcery | svgi34gj8fdgj3r4keht | ICE RTP channel checks for checklist entry have timed out, state being set to failed: udp:[::]:47443 (host)->udp:172.25.208.1:9 (host).
16:32:31,917 | DBG | sipsorcery | svgi34gj8fdgj3r4keht | ICE RTP channel checks for checklist entry have timed out, state being set to failed: udp:[::]:47443 (host)->udp:172.23.64.1:9 (host).

@sipsorcery
Copy link
Member

Can you get a WireShark trace from the machine using hte sipsorcery library? The logs you've provided don't show any STUN messages being received.

@franck-malka
Copy link
Author

pcap shared via email

@franck-malka
Copy link
Author

I see the Binding Request user is sent from the client to the AWS private IP rather than to the AWS public IP
That's explain why the request is not reaching the sipsorcery server...

@franck-malka
Copy link
Author

workaround i found is to assign the public ip address to the interface of the AWS instance and configure the channel with 0.0.0.0

@franck-malka
Copy link
Author

and implement the SendSecureAsync function

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@sipsorcery @franck-malka