Slower ICE connection when pion is the offerer (vs. browser as offerer)

[Boredbone]

Your environment.

• Version: v4.1.3
• Browser: Microsoft Edge v138.0.3351.65
  • Browser is running on Windows 11.
  • pion is running on the same machine inside WSL1 (Ubuntu 22.04).

What did you do?

When connecting from a browser to a pion, the time from ICEConnectionState: Checking to Connected differs significantly depending on who sends the offer.

I've attached the log:
when the browser issued the offer (browser_offer.txt), the connection was established in 3.9 ms,
but when the pion issued the offer (pion_offer.txt), it took 1.0 s.

What did you expect?

Similar ICE connection times regardless of which side acts as the offerer.

Reproducible Code

package main

import (
	"context"
	"encoding/json"
	"errors"
	"fmt"
	"io"
	"net/http"
	"os"
	"sync"
	"time"

	"github.com/pion/logging"
	"github.com/pion/webrtc/v4"
	"github.com/pion/webrtc/v4/pkg/media"
	"github.com/pion/webrtc/v4/pkg/media/h264reader"

	"github.com/gorilla/websocket"
)

const (
	videoFileName     = "video.h264"
	h264FrameDuration = time.Millisecond * 33
	port              = 8081
)

type Request struct {
	Request string `json:"request"`
}

func printLog(message string) {
	now := time.Now()
	timestamp := now.Format("15:04:05.000")
	fmt.Printf("[%s] %s\n", timestamp, message)
}

type customLogger struct {
	subsystem string
}

func (c customLogger) log(level, msg string) {
	printLog(fmt.Sprintf("[%s]<%s>%s", c.subsystem, level, msg))
}
func (c customLogger) logf(level, format string, args ...any) {
	c.log(level, fmt.Sprintf(format, args...))
}

func (c customLogger) Trace(msg string)                  { c.log("trace", msg) }
func (c customLogger) Tracef(format string, args ...any) { c.logf("trace", format, args...) }
func (c customLogger) Debug(msg string)                  { c.log("debug", msg) }
func (c customLogger) Debugf(format string, args ...any) { c.logf("debug", format, args...) }
func (c customLogger) Info(msg string)                   { c.log("info", msg) }
func (c customLogger) Infof(format string, args ...any)  { c.logf("info", format, args...) }
func (c customLogger) Warn(msg string)                   { c.log("warn", msg) }
func (c customLogger) Warnf(format string, args ...any)  { c.logf("warn", format, args...) }
func (c customLogger) Error(msg string)                  { c.log("error", msg) }
func (c customLogger) Errorf(format string, args ...any) { c.logf("error", format, args...) }

type customLoggerFactory struct{}

func (c customLoggerFactory) NewLogger(subsystem string) logging.LeveledLogger {
	return customLogger{subsystem: subsystem}
}

func must(err error) {
	if err != nil {
		panic(err)
	}
}

var upgrader = websocket.Upgrader{
	CheckOrigin: func(r *http.Request) bool {
		return true
	},
}

func wsHandler(w http.ResponseWriter, r *http.Request) {
	conn, err := upgrader.Upgrade(w, r, nil)
	if err != nil {
		fmt.Printf("Upgrade error:%v\n", err)
		return
	}
	defer conn.Close()

	var wsMutex sync.Mutex

	m := &webrtc.MediaEngine{}

	err = m.RegisterCodec(webrtc.RTPCodecParameters{
		RTPCodecCapability: webrtc.RTPCodecCapability{
			MimeType:     webrtc.MimeTypeH264,
			ClockRate:    90000,
			Channels:     0,
			SDPFmtpLine:  "level-asymmetry-allowed=1;packetization-mode=1;profile-level-id=42e01f",
			RTCPFeedback: nil},
		PayloadType: 96,
	}, webrtc.RTPCodecTypeVideo)
	must(err)

	s := webrtc.SettingEngine{
		LoggerFactory: customLoggerFactory{},
	}
	peerConnection, err := webrtc.NewAPI(
		webrtc.WithMediaEngine(m),
		webrtc.WithSettingEngine(s),
	).NewPeerConnection(webrtc.Configuration{
		ICEServers: []webrtc.ICEServer{
			{
				URLs: []string{"stun:stun.l.google.com:19302"},
			},
		},
	})
	must(err)

	iceConnectedCtx, iceConnectedCtxCancel := context.WithCancel(context.Background())

	{
		videoTrack, err := webrtc.NewTrackLocalStaticSample(
			webrtc.RTPCodecCapability{MimeType: webrtc.MimeTypeH264}, "video", "pion")
		must(err)
		_, err = peerConnection.AddTrack(videoTrack)
		must(err)

		go func() {
			file, err := os.Open(videoFileName)
			must(err)
			h264, err := h264reader.NewReader(file)
			must(err)

			printLog("Waiting connection")

			<-iceConnectedCtx.Done()
			printLog("Start streaming")

			ticker := time.NewTicker(h264FrameDuration)
			for ; true; <-ticker.C {
				nal, h264Err := h264.NextNAL()
				if errors.Is(h264Err, io.EOF) {
					printLog("All video frames parsed and sent")
					os.Exit(0)
				}
				must(err)
				err = videoTrack.WriteSample(media.Sample{Data: nal.Data, Duration: h264FrameDuration})
				must(err)
			}
		}()
	}

	peerConnection.OnICECandidate(func(candidate *webrtc.ICECandidate) {
		if candidate == nil {
			return
		}
		printLog(fmt.Sprintf("\n\nLocal ICE candidate:\n%v\n\n", candidate))

		wsMutex.Lock()
		err = conn.WriteJSON(candidate.ToJSON())
		wsMutex.Unlock()
		must(err)
	})

	var iceStartTime time.Time

	peerConnection.OnICEConnectionStateChange(func(connectionState webrtc.ICEConnectionState) {
		switch connectionState {
		case webrtc.ICEConnectionStateChecking:
			iceStartTime = time.Now()
		case webrtc.ICEConnectionStateConnected:
			printLog(fmt.Sprintf("ICE connection time=%s", time.Since(iceStartTime)))
		}
	})
	peerConnection.OnConnectionStateChange(func(connectionState webrtc.PeerConnectionState) {
		if connectionState == webrtc.PeerConnectionStateConnected {
			iceConnectedCtxCancel()
		}
	})

	for {
		_, message, err := conn.ReadMessage()
		if err != nil {
			printLog(fmt.Sprintf("Read error:%v", err))
			break
		}
		var (
			candidate webrtc.ICECandidateInit
			sdp       webrtc.SessionDescription
			request   Request
		)

		switch {
		case json.Unmarshal(message, &sdp) == nil && sdp.SDP != "":
			printLog(fmt.Sprintf("Remote SDP(%s):\n%s", sdp.Type, sdp.SDP))
			err = peerConnection.SetRemoteDescription(sdp)
			must(err)

			if sdp.Type == webrtc.SDPTypeOffer {
				answer, err := peerConnection.CreateAnswer(nil)
				must(err)
				err = peerConnection.SetLocalDescription(answer)
				must(err)
				printLog(fmt.Sprintf("Local SDP(%s):\n%s\n", answer.Type, answer.SDP))

				wsMutex.Lock()
				err = conn.WriteJSON(answer)
				wsMutex.Unlock()
				must(err)
			}
		case json.Unmarshal(message, &candidate) == nil && candidate.Candidate != "":
			printLog(fmt.Sprintf("\n\nRemote ICE candidate:\n%v\n\n", candidate))
			err = peerConnection.AddICECandidate(candidate)
			must(err)
		case json.Unmarshal(message, &request) == nil && request.Request != "":
			if request.Request == "offer" {
				offer, err := peerConnection.CreateOffer(nil)
				must(err)
				err = peerConnection.SetLocalDescription(offer)
				must(err)
				printLog(fmt.Sprintf("Local SDP(%s):\n%s\n", offer.Type, offer.SDP))

				wsMutex.Lock()
				err = conn.WriteJSON(offer)
				wsMutex.Unlock()
				must(err)
			}
		default:
			printLog(fmt.Sprintf("Unknown message %s", message))
		}
	}
}

func main() {
	if _, err := os.Stat(videoFileName); err != nil {
		panic("Missing video file: " + videoFileName)
	}

	http.Handle("/", http.FileServer(http.Dir(".")))
	http.HandleFunc("/websocket", wsHandler)

	printLog(fmt.Sprintf("Open http://localhost:%d to access this demo", port))
	panic(http.ListenAndServe(fmt.Sprintf(":%d", port), nil))
}

html:

<html>

<body>
  <div id="remoteVideos"></div>
  <br />
  <div><button type="button" class="btn" onclick="sendOffer()">browser offer</button></div>
  <br />
  <div><button type="button" class="btn" onclick="requestOffer()">pion offer</button></div>
</body>

<script>
  function sendOffer() {
    pc.createOffer().then(offer => {
      pc.setLocalDescription(offer)
      socket.send(JSON.stringify(offer))
    })
  }
  function requestOffer() {
    socket.send(JSON.stringify({ "request": "offer" }))
  }

  const socket = new WebSocket(`ws://${window.location.host}/websocket`)
  let pc = new RTCPeerConnection({
    iceServers: [
      {
        urls: 'stun:stun.l.google.com:19302'
      }
    ]
  })

  socket.onmessage = e => {
    console.log(e.data)
    let msg = JSON.parse(e.data)
    if (!msg) {
      return console.log('failed to parse msg')
    }

    if (msg.candidate) {
      pc.addIceCandidate(msg)
    } else if (msg.type) {
      pc.setRemoteDescription(msg)
      if (msg.type === "offer") {
        pc.createAnswer().then(answer => {
          pc.setLocalDescription(answer)
          socket.send(JSON.stringify(answer))
        })
      }
    }
  }

  pc.onicecandidate = e => {
    if (e.candidate && e.candidate.candidate !== "") {
      socket.send(JSON.stringify(e.candidate))
    }
  }

  pc.ontrack = function (event) {
    var el = document.createElement(event.track.kind)
    el.srcObject = event.streams[0]
    el.autoplay = true
    el.controls = true

    document.getElementById('remoteVideos').appendChild(el)
  }

  pc.addTransceiver('video', { 'direction': 'recvonly' })

</script>

</html>

[amanakin]

I think pion doesn't gather local Host candidates by default. You need to specify s.SetIncludeLoopbackCandidate(true) on the SettingEngine to gather these local candidates. Without this, pion treats the browser's candidate as a peer-reflexive candidate, which introduces a 1-second delay: https://github.com/pion/ice/blob/f6a1153ce74696f884ef91577fb4fed4a559cbe1/agent_config.go#L36

[Boredbone]

In pion/ice/selection.go, why is an ICE candidate pair with pendingRequest.isUseCandidate==false not passed to controllingSelector.agent.setSelectedPair in controllingSelector.HandleSuccessResponse?

Even if a valid pair is found early, this condition prevents it from being set immediately, which delays the completion of the connection.

In my environment, I simplified the logic as follows, and the connection completes more quickly:

if s.agent.getSelectedPair() == nil {
		s.agent.setSelectedPair(pair)
}

[arjunshajitech]

In pion/ice/selection.go, why is an ICE candidate pair with pendingRequest.isUseCandidate==false not passed to controllingSelector.agent.setSelectedPair in controllingSelector.HandleSuccessResponse?

Even if a valid pair is found early, this condition prevents it from being set immediately, which delays the completion of the connection.

it’s not guaranteed and is not compliant with the ICE spec, so it’s unreliable and may break in real-world scenarios.

https://datatracker.ietf.org/doc/html/rfc8445/#section-7.2.5.3.2

https://datatracker.ietf.org/doc/html/rfc8445/#section-7.2.5.3.4

[Boredbone]

Thanks, I understand - but I still can't figure out why it takes so long to connect.
It's probably not device-dependent. When I connect from an Android phone over the mobile network to a Raspberry Pi running pion as the offerer, the connection takes about 0.7 seconds longer than when the browser acts as the offerer.
On the other hand, this issue doesn't occur with other WebRTC implementations (such as webrtcbin in GStreamer or janus-gateway).