Add logs for sfu-ws

Add some logs for debugging.
FIXME: sfu-ws endless send offer when use plan-b.

Author: cgojin

sfu-ws/README.md

@@ -1,4 +1,5 @@
 # sfu-ws
+
 sfu-ws is a many-to-many websocket based SFU. This is a more advanced version of [broadcast](https://github.com/pion/webrtc/tree/master/examples/broadcast)
 and demonstrates the following features.
 
@@ -10,6 +11,7 @@ and demonstrates the following features.
 * Support for multiple browsers
 
 We also provide a flutter client that supports the following platforms
+
 * Android, iOS
 * Web
 * MacOS (Windows, Linux and Fuschia in the [future](https://github.com/flutter-webrtc/flutter-webrtc#functionality))
@@ -18,20 +20,33 @@ For a production application you should also explore [simulcast](https://github.
 metrics and robust error handling.
 
 ## Instructions
+
 ### Download sfu-ws
+
 This example requires you to clone the repo since it is serving static HTML.
 
-```
+```sh
 mkdir -p $GOPATH/src/github.com/pion
 cd $GOPATH/src/github.com/pion
 git clone https://github.com/pion/example-webrtc-applications.git
 cd webrtc/examples/sfu-ws
 ```
 
 ### Run sfu-ws
-Execute `go run *.go`
+
+```sh
+# Run sfu-ws
+go run *.go
+
+# Run sfu-ws with logs
+PION_LOG_INFO=sfu-ws go run *.go
+
+# Run sfu-ws with all logs
+PION_LOG_TRACE=all go run *.go
+```
 
 ### Open the Web UI
+
 Open [http://localhost:8080](http://localhost:8080). This will automatically connect and send your video. Now join from other tabs and browsers!
 
 Congrats, you have used Pion WebRTC! Now start building something cool

sfu-ws/main.go

@@ -4,13 +4,13 @@ import (
 	"encoding/json"
 	"flag"
 	"io/ioutil"
-	"log"
 	"net/http"
 	"sync"
 	"text/template"
 	"time"
 
 	"github.com/gorilla/websocket"
+	"github.com/pion/logging"
 	"github.com/pion/rtcp"
 	"github.com/pion/webrtc/v3"
 )
@@ -26,6 +26,8 @@ var (
 	listLock        sync.RWMutex
 	peerConnections []peerConnectionState
 	trackLocals     map[string]*webrtc.TrackLocalStaticRTP
+
+	log = logging.NewDefaultLoggerFactory().NewLogger("sfu-ws")
 )
 
 type websocketMessage struct {
@@ -43,7 +45,6 @@ func main() {
 	flag.Parse()
 
 	// Init other state
-	log.SetFlags(0)
 	trackLocals = map[string]*webrtc.TrackLocalStaticRTP{}
 
 	// Read index.html from disk into memory, serve whenever anyone requests /
@@ -58,8 +59,8 @@ func main() {
 
 	// index.html handler
 	http.HandleFunc("/", func(w http.ResponseWriter, r *http.Request) {
-		if err := indexTemplate.Execute(w, "ws://"+r.Host+"/websocket"); err != nil {
-			log.Fatal(err)
+		if err = indexTemplate.Execute(w, "ws://"+r.Host+"/websocket"); err != nil {
+			log.Errorf("Failed to parse index template: %v", err)
 		}
 	})
 
@@ -71,14 +72,18 @@ func main() {
 	}()
 
 	// start HTTP server
-	log.Fatal(http.ListenAndServe(*addr, nil))
+	if err = http.ListenAndServe(*addr, nil); err != nil {
+		log.Errorf("Failed to start http server: %v", err)
+	}
 }
 
 // Add to list of tracks and fire renegotation for all PeerConnections
 func addTrack(t *webrtc.TrackRemote) *webrtc.TrackLocalStaticRTP {
 	listLock.Lock()
 	defer func() {
 		listLock.Unlock()
+
+		// FIXED: If server and client use plan-b, this code will cause endless send offer to the client
 		signalPeerConnections()
 	}()
 
@@ -165,9 +170,12 @@ func signalPeerConnections() {
 
 			offerString, err := json.Marshal(offer)
 			if err != nil {
+				log.Errorf("Failed to marshal offer to json: %v", err)
 				return true
 			}
 
+			log.Infof("Send offer to client: %v\n", offer)
+
 			if err = peerConnections[i].websocket.WriteJSON(&websocketMessage{
 				Event: "offer",
 				Data:  string(offerString),
@@ -220,7 +228,7 @@ func websocketHandler(w http.ResponseWriter, r *http.Request) {
 	// Upgrade HTTP request to Websocket
 	unsafeConn, err := upgrader.Upgrade(w, r, nil)
 	if err != nil {
-		log.Print("upgrade:", err)
+		log.Errorf("Failed to upgrade HTTP to Websocket: ", err)
 		return
 	}
 
@@ -232,7 +240,7 @@ func websocketHandler(w http.ResponseWriter, r *http.Request) {
 	// Create new PeerConnection
 	peerConnection, err := webrtc.NewPeerConnection(webrtc.Configuration{})
 	if err != nil {
-		log.Print(err)
+		log.Errorf("Failed to creates a PeerConnection: %v", err)
 		return
 	}
 
@@ -244,7 +252,7 @@ func websocketHandler(w http.ResponseWriter, r *http.Request) {
 		if _, err := peerConnection.AddTransceiverFromKind(typ, webrtc.RTPTransceiverInit{
 			Direction: webrtc.RTPTransceiverDirectionRecvonly,
 		}); err != nil {
-			log.Print(err)
+			log.Errorf("Failed to add transceiver: %v", err)
 			return
 		}
 	}
@@ -262,31 +270,37 @@ func websocketHandler(w http.ResponseWriter, r *http.Request) {
 
 		candidateString, err := json.Marshal(i.ToJSON())
 		if err != nil {
-			log.Println(err)
+			log.Errorf("Failed to marshal candidate to json: %v", err)
 			return
 		}
 
+		log.Infof("Send candidate to client: %s\n", candidateString)
+
 		if writeErr := c.WriteJSON(&websocketMessage{
 			Event: "candidate",
 			Data:  string(candidateString),
 		}); writeErr != nil {
-			log.Println(writeErr)
+			log.Errorf("Failed to write JSON: %v", writeErr)
 		}
 	})
 
 	// If PeerConnection is closed remove it from global list
 	peerConnection.OnConnectionStateChange(func(p webrtc.PeerConnectionState) {
+		log.Infof("Connection state change: %s\n", p)
+
 		switch p {
 		case webrtc.PeerConnectionStateFailed:
 			if err := peerConnection.Close(); err != nil {
-				log.Print(err)
+				log.Errorf("Failed to close PeerConnection: %v", err)
 			}
 		case webrtc.PeerConnectionStateClosed:
 			signalPeerConnections()
 		}
 	})
 
 	peerConnection.OnTrack(func(t *webrtc.TrackRemote, _ *webrtc.RTPReceiver) {
+		log.Infof("Got remote track: Kind=%s, ID=%s, PayloadType=%d\n", t.Kind(), t.ID(), t.PayloadType())
+
 		// Create a track to fan out our incoming video to all peers
 		trackLocal := addTrack(t)
 		defer removeTrack(trackLocal)
@@ -304,43 +318,57 @@ func websocketHandler(w http.ResponseWriter, r *http.Request) {
 		}
 	})
 
+	peerConnection.OnICEConnectionStateChange(func(is webrtc.ICEConnectionState) {
+		log.Infof("ICE connection state changed: %s\n", is)
+	})
+
 	// Signal for the new PeerConnection
 	signalPeerConnections()
 
 	message := &websocketMessage{}
 	for {
 		_, raw, err := c.ReadMessage()
 		if err != nil {
-			log.Println(err)
+			log.Errorf("Failed to read message: %v", err)
 			return
-		} else if err := json.Unmarshal(raw, &message); err != nil {
-			log.Println(err)
+		}
+
+		log.Infof("Got message: %s", raw)
+
+		if err := json.Unmarshal(raw, &message); err != nil {
+			log.Errorf("Failed to unmarshal json to message: %v", err)
 			return
 		}
 
 		switch message.Event {
 		case "candidate":
 			candidate := webrtc.ICECandidateInit{}
 			if err := json.Unmarshal([]byte(message.Data), &candidate); err != nil {
-				log.Println(err)
+				log.Errorf("Failed to unmarshal json to candidate: %v", err)
 				return
 			}
 
+			log.Infof("Got candidate: %v\n", candidate)
+
 			if err := peerConnection.AddICECandidate(candidate); err != nil {
-				log.Println(err)
+				log.Errorf("Failed to add ICE candidate: %v", err)
 				return
 			}
 		case "answer":
 			answer := webrtc.SessionDescription{}
 			if err := json.Unmarshal([]byte(message.Data), &answer); err != nil {
-				log.Println(err)
+				log.Errorf("Failed to unmarshal json to answer: %v", err)
 				return
 			}
 
+			log.Infof("Got answer: %v\n", answer)
+
 			if err := peerConnection.SetRemoteDescription(answer); err != nil {
-				log.Println(err)
+				log.Errorf("Failed to set remote description: %v", err)
 				return
 			}
+		default:
+			log.Errorf("unknown message: %+v", message)
 		}
 	}
 }