WSS -> UDP B2BUA : "TCP not supported" about go-sip-ua

[cloudwebrtc]

Did you try to add ;transport=wss here?
I guess the recipient must specify the transport type so that the transport layer can choose the correct transport.

sipUri := fmt.Sprintf("sip:%s@%s", called.User().String(), nextHop.PrivateIP)
change to like this:
sipUri := fmt.Sprintf("sip:%s@%s;transport=%s", called.User().String(), nextHop.PrivateIP, nextHop.Transport)

[IdlePhysicist]

I have not tried transport=wss in the recipient SIP URI, because the recipient is a SIP server that only accepts UDP.

I had originally used a similar method to what you describe but I decided to use the Clone method of UriParams() and Add method of Params() because I felt it neater than fmt.Sprintf. If you look at "sipURI" in the logs above you see that transport=udp was appended. Like this:

	clonedUriParams := to.Address.UriParams().Clone() // URI params cloned from incoming INVITE
	clonedUriParams.Add("transport", sip.String{"udp"}) // Transport param added

	sipUri := fmt.Sprintf("sip:%s@%s", called.User().String(), nextHop.PrivateIP)
	recipient, errParse := parser.ParseSipUri(sipUri)
	if errParse != nil {
		log.Err(errParse).Send()
		return 500
	}
	recipient.SetUriParams(clonedUriParams) // URI params added to new SIP URI for B-leg.

Though I have now gone back and implemented sipUri := fmt.Sprintf("sip:%s@%s;transport=%s", called.User().String(), nextHop.PrivateIP, "udp"), but I am still getting the same error.

[IdlePhysicist]

I have added some extra debug logs to your library (see patch below for what I added). As above I am deliberately setting my recipient SIP URI to transport=UDP the INVITE for my B-leg is produced with the correct transport (checked using request.Transport().

But when I check the transport in the RequestWithContext method, it has transformed into TCP (once again checked with request.Transport()). Please see the log messages below.

Can you explain why this is happening? It does not happen when the A-leg is a UDP call. In that case the B-leg is a UDP call as desired.

Logs

[2021-06-18 15:01:40.691] DEBUG UserAgent: set transport for request to UDP

[2021-06-18 15:01:40.691]  INFO UserAgent: buildRequest INVITE (with transport 'UDP') => 
INVITE sip:[email protected]:5060;transport=UDP SIP/2.0
CSeq: 1 INVITE
From: <sip:[email protected]>;tag=sc7SH9jO
To: <sip:[email protected];lang=fr>
Call-ID: o7hcnngnmgisqk7uadhp
Contact: <sip:[email protected]:5060;transport=udp>;+sip.instance="<urn:uuid:16649225-d046-11eb-b083-0e23671bdf6b>"
Max-Forwards: 70
User-Agent: GoSIP
Content-Length: 0


[2021-06-18 15:01:40.692] DEBUG UserAgent: request =>
INVITE sip:[email protected]:5060;transport=UDP SIP/2.0
CSeq: 1 INVITE
From: <sip:[email protected]>;tag=sc7SH9jO
To: <sip:[email protected];lang=fr>
Call-ID: o7hcnngnmgisqk7uadhp
Contact: <sip:[email protected]:5060;transport=udp>;+sip.instance="<urn:uuid:16649225-d046-11eb-b083-0e23671bdf6b>"
Max-Forwards: 70
User-Agent: GoSIP
Content-Length: 2365
Content-Type: application/sdp

v=0
o=- 5791547600189269081 2 IN IP4 127.0.0.1
s=-
t=0 0
a=group:BUNDLE 0
a=extmap-allow-mixed
a=msid-semantic: WMS FpxmJycZpxus8bUpPSCvscSElOoeLCLI291F
m=audio 53787 UDP/TLS/RTP/SAVPF 111 103 104 9 0 8 106 105 13 110 112 113 126
c=IN IP4 3.82.235.213
a=rtcp:9 IN IP4 0.0.0.0
a=candidate:2177299787 1 udp 2122260223 10.3.56.26 58898 typ host generation 0 network-id 1
a=candidate:2530088836 1 udp 2122194687 192.168.1.106 54835 typ host generation 0 network-id 2 network-cost 10
a=candidate:3477408187 1 tcp 1518280447 10.3.56.26 9 typ host tcptype active generation 0 network-id 1
a=candidate:3628985204 1 tcp 1518214911 192.168.1.106 9 typ host tcptype active generation 0 network-id 2 network-cost 10
a=candidate:1659335591 1 udp 1686052607 69.12.102.8 58898 typ srflx raddr 10.3.56.26 rport 58898 generation 0 network-id 1
a=candidate:3976257884 1 udp 8331007 3.82.235.213 53787 typ relay raddr 69.12.102.8 rport 51596 generation 0 network-id 1
a=ice-ufrag:XGDT
a=ice-pwd:zMClP4NQM2GMfzOVkwmjetLk
a=ice-options:trickle
a=fingerprint:sha-256 6C:1B:0D:46:E3:B3:BE:9D:A2:BE:DE:D8:CF:EF:37:32:E7:93:BB:F8:BD:87:26:41:5F:ED:0B:F4:60:A5:42:F9
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=extmap:5 urn:ietf:params:rtp-hdrext:sdes:rtp-stream-id
a=extmap:6 urn:ietf:params:rtp-hdrext:sdes:repaired-rtp-stream-id
a=sendrecv
a=msid:FpxmJycZpxus8bUpPSCvscSElOoeLCLI291F caf73e6c-b82b-4a5c-a35d-af3277cb0c5f
a=rtcp-mux
a=rtpmap:111 opus/48000/2
a=rtcp-fb:111 transport-cc
a=fmtp:111 minptime=10;useinbandfec=1
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:2625577532 cname:GcurqOXlFo1hDp3s
a=ssrc:2625577532 msid:FpxmJycZpxus8bUpPSCvscSElOoeLCLI291F caf73e6c-b82b-4a5c-a35d-af3277cb0c5f
a=ssrc:2625577532 mslabel:FpxmJycZpxus8bUpPSCvscSElOoeLCLI291F
a=ssrc:2625577532 label:caf73e6c-b82b-4a5c-a35d-af3277cb0c5f

[2021-06-18 15:01:40.692] DEBUG UserAgent: request transport ==> TCP

[2021-06-18 15:01:40.692]  INFO UserAgent: request transport ===> TCP

[2021-06-18 15:01:40.692] DEBUG transaction.Layer: client transaction created destination= request_id=980e8452-bd4e-411a-9aa1-d651dc89f263 source= transaction_key=z9hG4bK.Kgl4Ms3BLN8wng3L7jRzFzgR7EuQYcyM__INVITE transaction_layer_ptr=0xc000200080 transaction_ptr=0xc0002d1c20 transport=
[2021-06-18 15:01:40.692] DEBUG transaction.ClientTx: initialising INVITE transaction FSM destination= request_id=980e8452-bd4e-411a-9aa1-d651dc89f263 source= transaction_key=z9hG4bK.Kgl4Ms3BLN8wng3L7jRzFzgR7EuQYcyM__INVITE transaction_layer_ptr=0xc000200080 transaction_ptr=0xc0002d1c20 transport=
[2021-06-18 15:01:40.692] DEBUG transaction.ClientTx: act_trans_err destination= request_id=980e8452-bd4e-411a-9aa1-d651dc89f263 source= transaction_key=z9hG4bK.Kgl4Ms3BLN8wng3L7jRzFzgR7EuQYcyM__INVITE transaction_layer_ptr=0xc000200080 transaction_ptr=0xc0002d1c20 transport=
[2021-06-18 15:01:40.692] DEBUG transaction.ClientTx: act_delete destination= request_id=980e8452-bd4e-411a-9aa1-d651dc89f263 source= transaction_key=z9hG4bK.Kgl4Ms3BLN8wng3L7jRzFzgR7EuQYcyM__INVITE transaction_layer_ptr=0xc000200080 transaction_ptr=0xc0002d1c20 transport=
[2021-06-18 15:01:40.692] DEBUG transaction.ClientTx: transaction done destination= request_id=980e8452-bd4e-411a-9aa1-d651dc89f263 source= transaction_key=z9hG4bK.Kgl4Ms3BLN8wng3L7jRzFzgR7EuQYcyM__INVITE transaction_layer_ptr=0xc000200080 transaction_ptr=0xc0002d1c20 transport=
[2021-06-18 15:01:40.692] ERROR UserAgent: INVITE: Request [INVITE] failed, err => transport.UnsupportedProtocolError: protocol TCP is not supported

Patch

diff --git a/go.mod b/go.mod
index d205898..e9e2ce1 100644
--- a/go.mod
+++ b/go.mod
@@ -18,3 +18,5 @@ require (
 	google.golang.org/api v0.43.0
 	gopkg.in/check.v1 v1.0.0-20190902080502-41f04d3bba15 // indirect
 )
+
+replace github.com/ghettovoice/gosip => ../gosip
diff --git a/pkg/ua/ua.go b/pkg/ua/ua.go
index 13f8a2d..6511bb0 100644
--- a/pkg/ua/ua.go
+++ b/pkg/ua/ua.go
@@ -88,7 +88,18 @@ func (ua *UserAgent) buildRequest(
 	recipient sip.SipUri,
 	callID *sip.CallID) (*sip.Request, error) {
 
-	builder := sip.NewRequestBuilder().SetMethod(method).SetFrom(from).SetTo(to).SetContact(contact).SetRecipient(recipient.Clone())
+	builder := sip.NewRequestBuilder().
+		SetMethod(method).
+		SetFrom(from).
+		SetTo(to).
+		SetContact(contact).
+		SetRecipient(recipient.Clone())
+
+	transport, ok := recipient.UriParams().Get("transport")
+	if ok {
+		builder.SetTransport(transport.String())
+		ua.Log().Debugf("set transport for request to %s\n", transport.String())
+	}
 
 	if callID != nil {
 		builder.SetCallID(callID)
@@ -100,7 +111,7 @@ func (ua *UserAgent) buildRequest(
 		return nil, err
 	}
 
-	//ua.Log().Infof("buildRequest %s => \n%v", method, req)
+	ua.Log().Infof("buildRequest %s (with transport '%s') => \n%v", method, req.Transport(), req)
 	return &req, nil
 }
 
@@ -114,7 +125,7 @@ func (ua *UserAgent) SendRegister(profile *account.Profile, recipient sip.SipUri
 	return register, nil
 }
 
-func (ua *UserAgent) Invite(profile *account.Profile, target sip.Uri, recipient sip.SipUri, body *string) (*session.Session, error) {
+func (ua *UserAgent) Invite(profile *account.Profile, target sip.Uri, recipient sip.SipUri, body *string, callID *sip.CallID) (*session.Session, error) {
 
 	from := &sip.Address{
 		DisplayName: sip.String{Str: profile.DisplayName},
@@ -128,7 +139,7 @@ func (ua *UserAgent) Invite(profile *account.Profile, target sip.Uri, recipient
 		Uri: target,
 	}
 
-	request, err := ua.buildRequest(sip.INVITE, from, to, contact, recipient, nil)
+	request, err := ua.buildRequest(sip.INVITE, from, to, contact, recipient, callID)
 	if err != nil {
 		ua.Log().Errorf("INVITE: err = %v", err)
 		return nil, err
@@ -145,6 +156,9 @@ func (ua *UserAgent) Invite(profile *account.Profile, target sip.Uri, recipient
 		authorizer = auth.NewClientAuthorizer(profile.AuthInfo.AuthUser, profile.AuthInfo.Password)
 	}
 
+	ua.Log().Debugf("request =>\n%v", *request)
+	ua.Log().Debugf("request transport ==> %+v\n", (*request).Transport())
+
 	resp, err := ua.RequestWithContext(context.TODO(), *request, authorizer, false, 1)
 	if err != nil {
 		ua.Log().Errorf("INVITE: Request [INVITE] failed, err => %v", err)
@@ -294,6 +308,7 @@ func (ua *UserAgent) handleInvite(request sip.Request, tx sip.ServerTransaction)
 // RequestWithContext .
 func (ua *UserAgent) RequestWithContext(ctx context.Context, request sip.Request, authorizer sip.Authorizer, waitForResult bool, attempt int) (sip.Response, error) {
 	s := ua.config.SipStack
+	ua.Log().Infof("request transport ===> %s\n", request.Transport())
 	tx, err := s.Request(request)
 	if err != nil {
 		return nil, err

[cloudwebrtc]

@IdlePhysicist Hey, How do I reproduce your issue? Now we have a b2bua,
Register a sip over UDP A and sip over WebSocket B separately, and using A call to B can reproduce the issue?

[IdlePhysicist]

@cloudwebrtc I was not explicitly registering any endpoints using a SIP REGISTER method, but I did put a single entry into my registry map, which represents the "next hop" in the call, i.e. the destination of the B-leg of the B2B call.

Basically I start listeners on WSS, TLS, and UDP. I initiate a WSS call to the application from my browser. I expect the application of initiate a B-leg over UDP to a media server that sets up the rest of the call.

That is where the call fails. The INVITE that the application should send to the "next hop" is never sent because of protocol error.

ERROR UserAgent: INVITE: Request [INVITE] failed, err => transport.UnsupportedProtocolError: protocol TCP is not supported

Example code

My `registry` is just an `interface` around a `map`.

registry.Server is the following:

type Server struct {
	Active bool
	PrivateIP string
}

Here is the code where I create my b2bua, I am also using a different logger than you are.

type cuppa struct {
	stack    *stack.SipStack
	calls    map[string]*b2bCall
	registry registry.Registry
	ua       *ua.UserAgent
}

func newCuppa(listeners map[string]params, host string) (*cuppa, error) {

        c.registry.Add(config.GetString("nextHop"), &registry.Server{PrivateIP: config.GetString("nextHop")})

        /* <set up listeners here> */

	ua := ua.NewUserAgent(&ua.UserAgentConfig{SipStack: stack})

	// This is the brunt of the "dialplan"
	ua.InviteStateHandler = func(sess *session.Session, req *sip.Request, resp *sip.Response, state session.Status) {
		log.Info().
			Str("method", "InviteStateHandler").
			Str("direction", string(sess.Direction())).
			Str("state", string(state)).
			Send()

		switch state {
		case session.InviteReceived:
			timer := newRequestTimer("invite")
			defer timer.ObserveDuration()

			to, _ := (*req).To()
			from, _ := (*req).From()
			caller := from.Address
			called := to.Address

			requests.With(prometheus.Labels{"category": "total"}).Inc()

			log.Debug().
				Str("to", to.String()).
				Interface("toParams", to.Params.Items()).
				Interface("to.URIParams", called.UriParams().Items()).
				Str("from", from.String()).
				Interface("fromParams", from.Params.Items()).
				Interface("fromURIParams", caller.UriParams().Items()).
				Send()

			// Check to see if we want to block this request.
			if !checkRequest(caller, called) {
				requests.With(prometheus.Labels{"category": "blocked"}).Inc()
				return
			}

			log.Info().
				Str("method", "InviteStateHandler").
				Str("direction", string(sess.Direction())).
				Send()

			doInvite := func(nextHop *registry.Server) int {
				displayName := ""
				if from.DisplayName != nil {
					displayName = from.DisplayName.String()
				}

				profile := account.NewProfile(caller, displayName, nil, 0, stack)

				sipUri := fmt.Sprintf("sip:%s@%s:5060;transport=UDP", called.User().String(), nextHop.PrivateIP)
				recipient, errParse := parser.ParseSipUri(sipUri)
				if errParse != nil {
					log.Err(errParse).Send()
					return 500
				}

				// Grab the Incoming call id for the next leg. Nil if not found...
				incomingCallID, _ := (*req).CallID()

				log.Debug().Str("sipURI", recipient.String()).
					//Str("newParams", newParams.String()).
					Send()
				log.Debug().Str("called", called.String()).Send()

				offer := sess.RemoteSdp()
				newLeg, err := ua.Invite(profile, called, recipient, &offer, incomingCallID)
				if err != nil {
					log.Err(err).
						Str("call-id", (*req).GetHeaders("Call-ID")[0].Value()).
						Msg("B-leg session err")
					return 500
				}

				c.addCall(sess.CallID().Value(), sess, newLeg)
				return 200
			}

			// Get nextHop from registry
			nextHop, ok := c.registry.Get(config.GetString("nextHop"))
			if nextHop != nil && ok {
				sess.Provisional(100, "Trying")
				status := doInvite(nextHop.(*registry.Server))
				switch status {
				case 200:
					// This is our golden log message
					log.Info().
						Str("method", "InviteStateHandler").
						Str("direction", string(sess.Direction())).
						Str("call-id", (*req).GetHeaders("Call-ID")[0].Value()).
						Int64("currentCalls", callsCurrent).
						Send()
					// If our doInvite func was a success then return here
					return
				case 500:
					sess.Reject(500, "server error")
					return
				}
			}
			sess.Reject(404, "Not found")

The handling of other SIP methods is effectively the same as in your b2bua example, so I will not include it here.

[IdlePhysicist]

I have tested again with your latest commit faa07bd I still have the same issue.

[cloudwebrtc]

I highly suspect that A B leg’s Call-ID is the same, causing session map access conflicts

https://github.com/cloudwebrtc/go-sip-ua/blob/master/pkg/ua/ua.go#L38

[cloudwebrtc]

You can try to generate a new CallID here

// Grab the Incoming call id for the next leg. Nil if not found...
incomingCallID, _ := (*req).CallID()

[IdlePhysicist]

I understand your point about the call-id reuse. That was actually a new thing that I had added, when I originally filed the issue I was not doing that. I will retest to see if that makes a difference but I doubt it will.

EDIT: Confirmed generating a new call-id for the second leg makes no difference.

[cloudwebrtc]

I think you need to use a debugging tool to monitor why the memory of the transport in the request has been modified. Logs alone seem to be unable to locate the issue.

From the code snippets you provided, there seems to be no issue.

[ghettovoice]

Hi there!
@IdlePhysicist sorry for the late reaction, I was busy.

Regarding of switching sip request transport protocol. UDP transport can be switched to TCP for the outbound request if request is too big. As RFC suggests to switch to TCP transport if request >= MTU - 200 (MTU by default 1500). https://github.com/ghettovoice/gosip/blob/master/sip/request.go#L166

@IdlePhysicist from your sip log I see that INVITE has body of 2365 bytes, so it can't be sent via UDP without breaking the message and transport layer tries to send it via TCP. But as I understand the TCP listener is not enabled. When you start TCP listener then support of this transport will be enabled. Not the be solution, but this how it works right now.
As I see from @cloudwebrtc b2bua example here https://github.com/cloudwebrtc/go-sip-ua/blob/master/examples/b2bua/b2bua/b2bua.go#L84, go-sip-ua doesn't setup any listeners by default. So you need to setup them yourself. Maybe I'm wrong about go-sip-ua, but gosip doesn't set anything.

[IdlePhysicist]

@ghettovoice Thank you for getting back to me!

You are totally correct about the request size. I removed the length condition from request.Transport() and my calls started to work. It looks like I will need to do some SDP processing if I wish to be RFC compliant.