diff --git a/internal/webrtc/cursor/image.go b/internal/webrtc/cursor/image.go index 3bacf281..469109b6 100644 --- a/internal/webrtc/cursor/image.go +++ b/internal/webrtc/cursor/image.go @@ -13,7 +13,7 @@ import ( func NewImage(desktop types.DesktopManager) *ImageCtx { return &ImageCtx{ - logger: log.With().Str("module", "cursor-image").Logger(), + logger: log.With().Str("module", "webrtc").Str("submodule", "cursor-image").Logger(), desktop: desktop, listeners: map[uintptr]*func(entry *ImageEntry){}, cache: map[uint64]*ImageEntry{}, @@ -50,10 +50,12 @@ func (manager *ImageCtx) Start() { (*emit)(entry) } }) + + manager.logger.Info().Msg("starting") } func (manager *ImageCtx) Shutdown() { - manager.logger.Info().Msgf("shutting down") + manager.logger.Info().Msg("shutdown") manager.emitMu.Lock() for key := range manager.listeners { diff --git a/internal/webrtc/cursor/position.go b/internal/webrtc/cursor/position.go index 958e7d3d..de5994fd 100644 --- a/internal/webrtc/cursor/position.go +++ b/internal/webrtc/cursor/position.go @@ -12,7 +12,7 @@ import ( func NewPosition(desktop types.DesktopManager) *PositionCtx { return &PositionCtx{ - logger: log.With().Str("module", "cursor-position").Logger(), + logger: log.With().Str("module", "webrtc").Str("submodule", "cursor-position").Logger(), desktop: desktop, listeners: map[uintptr]*func(x, y int){}, } @@ -26,7 +26,7 @@ type PositionCtx struct { } func (manager *PositionCtx) Shutdown() { - manager.logger.Info().Msgf("shutting down") + manager.logger.Info().Msg("shutdown") manager.emitMu.Lock() for key := range manager.listeners { diff --git a/internal/webrtc/handler.go b/internal/webrtc/handler.go index 2eef5a52..5267703e 100644 --- a/internal/webrtc/handler.go +++ b/internal/webrtc/handler.go @@ -5,6 +5,8 @@ import ( "encoding/binary" "github.com/pion/webrtc/v3" + + "demodesk/neko/internal/types" ) const ( @@ -38,7 +40,10 @@ type PayloadKey struct { Key uint32 } -func (manager *WebRTCManagerCtx) handle(msg webrtc.DataChannelMessage) error { +func (manager *WebRTCManagerCtx) handle(msg webrtc.DataChannelMessage, session types.Session) error { + // add session id to logger context + logger := manager.logger.With().Str("session_id", session.ID()).Logger() + buffer := bytes.NewBuffer(msg.Data) header := &PayloadHeader{} hbytes := make([]byte, 3) @@ -68,13 +73,11 @@ func (manager *WebRTCManagerCtx) handle(msg webrtc.DataChannelMessage) error { return err } - manager.logger. - Debug(). + manager.desktop.Scroll(int(payload.X), int(payload.Y)) + logger.Trace(). Int16("x", payload.X). Int16("y", payload.Y). Msg("scroll") - - manager.desktop.Scroll(int(payload.X), int(payload.Y)) case OP_KEY_DOWN: payload := &PayloadKey{} if err := binary.Read(buffer, binary.BigEndian, payload); err != nil { @@ -82,11 +85,10 @@ func (manager *WebRTCManagerCtx) handle(msg webrtc.DataChannelMessage) error { } if err := manager.desktop.KeyDown(payload.Key); err != nil { - manager.logger.Warn().Err(err).Msg("key down failed") - break + logger.Warn().Err(err).Uint32("key", payload.Key).Msg("key down failed") + } else { + logger.Trace().Uint32("key", payload.Key).Msg("key down") } - - manager.logger.Debug().Msgf("key down %d", payload.Key) case OP_KEY_UP: payload := &PayloadKey{} if err := binary.Read(buffer, binary.BigEndian, payload); err != nil { @@ -94,11 +96,10 @@ func (manager *WebRTCManagerCtx) handle(msg webrtc.DataChannelMessage) error { } if err := manager.desktop.KeyUp(payload.Key); err != nil { - manager.logger.Warn().Err(err).Msg("key up failed") - break + logger.Warn().Err(err).Uint32("key", payload.Key).Msg("key up failed") + } else { + logger.Trace().Uint32("key", payload.Key).Msg("key up") } - - manager.logger.Debug().Msgf("key up %d", payload.Key) case OP_BTN_DOWN: payload := &PayloadKey{} if err := binary.Read(buffer, binary.BigEndian, payload); err != nil { @@ -106,11 +107,10 @@ func (manager *WebRTCManagerCtx) handle(msg webrtc.DataChannelMessage) error { } if err := manager.desktop.ButtonDown(payload.Key); err != nil { - manager.logger.Warn().Err(err).Msg("button down failed") - break + logger.Warn().Err(err).Uint32("key", payload.Key).Msg("button down failed") + } else { + logger.Trace().Uint32("key", payload.Key).Msg("button down") } - - manager.logger.Debug().Msgf("button down %d", payload.Key) case OP_BTN_UP: payload := &PayloadKey{} if err := binary.Read(buffer, binary.BigEndian, payload); err != nil { @@ -118,11 +118,10 @@ func (manager *WebRTCManagerCtx) handle(msg webrtc.DataChannelMessage) error { } if err := manager.desktop.ButtonUp(payload.Key); err != nil { - manager.logger.Warn().Err(err).Msg("button up failed") - break + logger.Warn().Err(err).Uint32("key", payload.Key).Msg("button up failed") + } else { + logger.Trace().Uint32("key", payload.Key).Msg("button up") } - - manager.logger.Debug().Msgf("button up %d", payload.Key) } return nil diff --git a/internal/webrtc/logger.go b/internal/webrtc/logger.go index 90c0d7e2..92f57a82 100644 --- a/internal/webrtc/logger.go +++ b/internal/webrtc/logger.go @@ -81,6 +81,6 @@ func (l loggerFactory) NewLogger(subsystem string) logging.LeveledLogger { return logger{ subsystem: subsystem, - logger: l.logger.With().Str("subsystem", subsystem).Logger(), + logger: l.logger.With().Str("submodule", "pion").Str("subsystem", subsystem).Logger(), } } diff --git a/internal/webrtc/manager.go b/internal/webrtc/manager.go index 0da67ed5..cbad880b 100644 --- a/internal/webrtc/manager.go +++ b/internal/webrtc/manager.go @@ -80,6 +80,8 @@ func (manager *WebRTCManagerCtx) Start() { audio.RemoveListener(&audioListener) } + manager.curImage.Start() + manager.logger.Info(). Bool("icelite", manager.config.ICELite). Bool("icetrickle", manager.config.ICETrickle). @@ -87,12 +89,10 @@ func (manager *WebRTCManagerCtx) Start() { Str("nat1to1", strings.Join(manager.config.NAT1To1IPs, ",")). Str("epr", fmt.Sprintf("%d-%d", manager.config.EphemeralMin, manager.config.EphemeralMax)). Msg("webrtc starting") - - manager.curImage.Start() } func (manager *WebRTCManagerCtx) Shutdown() error { - manager.logger.Info().Msgf("webrtc shutting down") + manager.logger.Info().Msg("webrtc shutdown") manager.curImage.Shutdown() manager.curPosition.Shutdown() @@ -106,7 +106,9 @@ func (manager *WebRTCManagerCtx) ICEServers() []types.ICEServer { } func (manager *WebRTCManagerCtx) CreatePeer(session types.Session, videoID string) (*webrtc.SessionDescription, error) { + // add session id to logger context logger := manager.logger.With().Str("session_id", session.ID()).Logger() + logger.Info().Msg("creating webrtc peer") // Create MediaEngine engine, err := manager.mediaEngine(videoID) @@ -155,13 +157,13 @@ func (manager *WebRTCManagerCtx) CreatePeer(session types.Session, videoID strin // create video track videoStream, ok := manager.capture.Video(videoID) if !ok { - manager.logger.Warn().Str("videoID", videoID).Msg("video stream not found") + logger.Warn().Str("video_id", videoID).Msg("video stream not found") return nil, err } videoTrack, err := webrtc.NewTrackLocalStaticSample(videoStream.Codec().Capability, "video", "stream") if err != nil { - manager.logger.Warn().Err(err).Msg("unable to create video track") + logger.Warn().Err(err).Msg("unable to create video track") return nil, err } @@ -171,7 +173,7 @@ func (manager *WebRTCManagerCtx) CreatePeer(session types.Session, videoID strin // The peerConnection has been closed. return } - manager.logger.Warn().Err(err).Msg("video pipeline failed to write") + logger.Warn().Err(err).Msg("video pipeline failed to write") } } @@ -180,7 +182,7 @@ func (manager *WebRTCManagerCtx) CreatePeer(session types.Session, videoID strin // should be stream started if videoStream.ListenersCount() == 0 { if err := videoStream.Start(); err != nil { - manager.logger.Warn().Err(err).Msg("unable to start video pipeline") + logger.Warn().Err(err).Msg("unable to start video pipeline") return nil, err } } @@ -239,6 +241,7 @@ func (manager *WebRTCManagerCtx) CreatePeer(session types.Session, videoID strin } peer := &WebRTCPeerCtx{ + logger: logger, api: api, connection: connection, changeVideo: changeVideo, @@ -248,7 +251,7 @@ func (manager *WebRTCManagerCtx) CreatePeer(session types.Session, videoID strin cursorImage := func(entry *cursor.ImageEntry) { if err := peer.SendCursorImage(entry.Cursor, entry.Image); err != nil { - manager.logger.Warn().Err(err).Msg("could not send cursor image") + logger.Warn().Err(err).Msg("could not send cursor image") } } @@ -258,7 +261,7 @@ func (manager *WebRTCManagerCtx) CreatePeer(session types.Session, videoID strin } if err := peer.SendCursorPosition(x, y); err != nil { - manager.logger.Warn().Err(err).Msg("could not send cursor position") + logger.Warn().Err(err).Msg("could not send cursor position") } } @@ -306,7 +309,7 @@ func (manager *WebRTCManagerCtx) CreatePeer(session types.Session, videoID strin if err == nil { cursorImage(entry) } else { - manager.logger.Warn().Err(err).Msg("failed to get cursor image") + logger.Warn().Err(err).Msg("failed to get cursor image") } // send initial cursor position @@ -324,7 +327,7 @@ func (manager *WebRTCManagerCtx) CreatePeer(session types.Session, videoID strin return } - if err = manager.handle(message); err != nil { + if err = manager.handle(message, session); err != nil { logger.Warn().Err(err).Msg("data handle failed") } }) diff --git a/internal/webrtc/peer.go b/internal/webrtc/peer.go index dc212819..13047408 100644 --- a/internal/webrtc/peer.go +++ b/internal/webrtc/peer.go @@ -4,10 +4,12 @@ import ( "sync" "github.com/pion/webrtc/v3" + "github.com/rs/zerolog" ) type WebRTCPeerCtx struct { mu sync.Mutex + logger zerolog.Logger api *webrtc.API connection *webrtc.PeerConnection dataChannel *webrtc.DataChannel @@ -59,6 +61,7 @@ func (peer *WebRTCPeerCtx) SetVideoID(videoID string) error { peer.mu.Lock() defer peer.mu.Unlock() + peer.logger.Info().Str("video_id", videoID).Msg("change video id") return peer.changeVideo(videoID) }