diff --git a/config.go b/config.go index a52845e..f19b6e0 100644 --- a/config.go +++ b/config.go @@ -169,7 +169,7 @@ func SaveConfig() error { configLock.Lock() defer configLock.Unlock() - logger.Tracef("Saving config to %s", configPath) + logger.Trace().Str("path", configPath).Msg("Saving config") file, err := os.Create(configPath) if err != nil { diff --git a/internal/websecure/log.go b/internal/websecure/log.go index 7643ac1..f45767e 100644 --- a/internal/websecure/log.go +++ b/internal/websecure/log.go @@ -1,5 +1,9 @@ package websecure -import "github.com/pion/logging" +import ( + "os" -var defaultLogger = logging.NewDefaultLoggerFactory().NewLogger("websecure") + "github.com/rs/zerolog" +) + +var defaultLogger = zerolog.New(os.Stdout).With().Str("component", "websecure").Logger() diff --git a/internal/websecure/selfsign.go b/internal/websecure/selfsign.go index 120873d..77efa37 100644 --- a/internal/websecure/selfsign.go +++ b/internal/websecure/selfsign.go @@ -11,7 +11,7 @@ import ( "strings" "time" - "github.com/pion/logging" + "github.com/rs/zerolog" "golang.org/x/net/idna" ) @@ -19,7 +19,7 @@ const selfSignerCAMagicName = "__ca__" type SelfSigner struct { store *CertStore - log logging.LeveledLogger + log *zerolog.Logger caInfo pkix.Name @@ -30,7 +30,7 @@ type SelfSigner struct { func NewSelfSigner( store *CertStore, - log logging.LeveledLogger, + log *zerolog.Logger, defaultDomain, defaultOrg, defaultOU, @@ -64,12 +64,12 @@ func (s *SelfSigner) createSelfSignedCert(hostname string) *tls.Certificate { if hostname != selfSignerCAMagicName { ca = s.getCA() if ca == nil { - s.log.Errorf("Failed to get CA certificate") + s.log.Error().Msg("Failed to get CA certificate") return nil } } - s.log.Infof("Creating self-signed certificate for %s", hostname) + s.log.Info().Str("hostname", hostname).Msg("Creating self-signed certificate") // lock the store while creating the certificate (do not move upwards) s.store.certLock.Lock() @@ -77,7 +77,7 @@ func (s *SelfSigner) createSelfSignedCert(hostname string) *tls.Certificate { priv, err := ecdsa.GenerateKey(elliptic.P256(), rand.Reader) if err != nil { - s.log.Errorf("Failed to generate private key: %v", err) + s.log.Error().Err(err).Msg("Failed to generate private key") return nil } @@ -86,7 +86,7 @@ func (s *SelfSigner) createSelfSignedCert(hostname string) *tls.Certificate { serialNumber, err := generateSerialNumber() if err != nil { - s.log.Errorf("Failed to generate serial number: %v", err) + s.log.Error().Err(err).Msg("Failed to generate serial number") return nil } @@ -139,7 +139,7 @@ func (s *SelfSigner) createSelfSignedCert(hostname string) *tls.Certificate { if ca != nil { parent, err = x509.ParseCertificate(ca.Certificate[0]) if err != nil { - s.log.Errorf("Failed to parse parent certificate: %v", err) + s.log.Error().Err(err).Msg("Failed to parse parent certificate") return nil } parentPriv = ca.PrivateKey.(*ecdsa.PrivateKey) @@ -147,7 +147,7 @@ func (s *SelfSigner) createSelfSignedCert(hostname string) *tls.Certificate { certBytes, err := x509.CreateCertificate(rand.Reader, &cert, parent, &priv.PublicKey, parentPriv) if err != nil { - s.log.Errorf("Failed to create certificate: %v", err) + s.log.Error().Err(err).Msg("Failed to create certificate") return nil } @@ -175,12 +175,12 @@ func (s *SelfSigner) GetCertificate(info *tls.ClientHelloInfo) (*tls.Certificate hostname = strings.Split(info.Conn.LocalAddr().String(), ":")[0] } - s.log.Infof("TLS handshake for %s, SupportedProtos: %v", hostname, info.SupportedProtos) + s.log.Info().Str("hostname", hostname).Strs("supported_protos", info.SupportedProtos).Msg("TLS handshake") // convert hostname to punycode h, err := idna.Lookup.ToASCII(hostname) if err != nil { - s.log.Warnf("Hostname %s is not valid: %w, from %s", hostname, err, info.Conn.RemoteAddr()) + s.log.Warn().Str("hostname", hostname).Err(err).Str("remote_addr", info.Conn.RemoteAddr().String()).Msg("Hostname is not valid") hostname = s.DefaultDomain } else { hostname = h diff --git a/internal/websecure/store.go b/internal/websecure/store.go index f11d437..7da2dee 100644 --- a/internal/websecure/store.go +++ b/internal/websecure/store.go @@ -8,7 +8,7 @@ import ( "strings" "sync" - "github.com/pion/logging" + "github.com/rs/zerolog" ) type CertStore struct { @@ -17,16 +17,20 @@ type CertStore struct { storePath string - log logging.LeveledLogger + log *zerolog.Logger } -func NewCertStore(storePath string) *CertStore { +func NewCertStore(storePath string, log *zerolog.Logger) *CertStore { + if log == nil { + log = &defaultLogger + } + return &CertStore{ certificates: make(map[string]*tls.Certificate), certLock: &sync.Mutex{}, storePath: storePath, - log: defaultLogger, + log: log, } } @@ -42,7 +46,7 @@ func (s *CertStore) ensureStorePath() error { } if os.IsNotExist(err) { - s.log.Tracef("TLS store directory does not exist, creating directory") + s.log.Trace().Str("path", s.storePath).Msg("TLS store directory does not exist, creating directory") err = os.MkdirAll(s.storePath, 0755) if err != nil { return fmt.Errorf("Failed to create TLS store path: %w", err) @@ -56,13 +60,13 @@ func (s *CertStore) ensureStorePath() error { func (s *CertStore) LoadCertificates() { err := s.ensureStorePath() if err != nil { - s.log.Errorf(err.Error()) //nolint:errcheck + s.log.Error().Err(err).Msg("Failed to ensure store path") return } files, err := os.ReadDir(s.storePath) if err != nil { - s.log.Errorf("Failed to read TLS directory: %v", err) + s.log.Error().Err(err).Msg("Failed to read TLS directory") return } @@ -86,13 +90,13 @@ func (s *CertStore) loadCertificate(hostname string) { cert, err := tls.LoadX509KeyPair(crtFile, keyFile) if err != nil { - s.log.Errorf("Failed to load certificate for %s: %w", hostname, err) + s.log.Error().Err(err).Str("hostname", hostname).Msg("Failed to load certificate") return } s.certificates[hostname] = &cert - s.log.Infof("Loaded certificate for %s", hostname) + s.log.Info().Str("hostname", hostname).Msg("Loaded certificate") } // GetCertificate returns the certificate for the given hostname @@ -119,7 +123,7 @@ func (s *CertStore) ValidateAndSaveCertificate(hostname string, cert string, key // add recover to avoid panic defer func() { if r := recover(); r != nil { - s.log.Errorf("Failed to verify hostname: %v", r) + s.log.Error().Interface("recovered", r).Msg("Failed to verify hostname") } }() @@ -127,7 +131,7 @@ func (s *CertStore) ValidateAndSaveCertificate(hostname string, cert string, key if !ignoreWarning { return nil, fmt.Errorf("Certificate does not match hostname: %w", err) } - s.log.Warnf("Certificate does not match hostname: %v", err) + s.log.Warn().Err(err).Msg("Certificate does not match hostname") } } @@ -144,13 +148,13 @@ func (s *CertStore) saveCertificate(hostname string) { // check if certificate already exists tlsCert := s.certificates[hostname] if tlsCert == nil { - s.log.Errorf("Certificate for %s does not exist, skipping saving certificate", hostname) + s.log.Error().Str("hostname", hostname).Msg("Certificate for hostname does not exist, skipping saving certificate") return } err := s.ensureStorePath() if err != nil { - s.log.Errorf(err.Error()) //nolint:errcheck + s.log.Error().Err(err).Msg("Failed to ensure store path") return } @@ -158,14 +162,14 @@ func (s *CertStore) saveCertificate(hostname string) { crtFile := path.Join(s.storePath, hostname+".crt") if err := keyToFile(tlsCert, keyFile); err != nil { - s.log.Errorf(err.Error()) + s.log.Error().Err(err).Msg("Failed to save key file") return } if err := certToFile(tlsCert, crtFile); err != nil { - s.log.Errorf(err.Error()) + s.log.Error().Err(err).Msg("Failed to save certificate") return } - s.log.Infof("Saved certificate for %s", hostname) + s.log.Info().Str("hostname", hostname).Msg("Saved certificate") } diff --git a/jsonrpc.go b/jsonrpc.go index 6ca537e..d56b8ea 100644 --- a/jsonrpc.go +++ b/jsonrpc.go @@ -95,7 +95,7 @@ func onRPCMessage(message webrtc.DataChannelMessage, session *Session) { return } - logger.Tracef("Received RPC request: Method=%s, Params=%v, ID=%w", request.Method, request.Params, request.ID) + logger.Trace().Str("method", request.Method).Interface("params", request.Params).Interface("id", request.ID).Msg("Received RPC request") handler, ok := rpcHandlers[request.Method] if !ok { errorResponse := JSONRPCResponse{ @@ -110,7 +110,7 @@ func onRPCMessage(message webrtc.DataChannelMessage, session *Session) { return } - logger.Tracef("Calling RPC handler: %s, ID=%w", request.Method, request.ID) + logger.Trace().Str("method", request.Method).Interface("id", request.ID).Msg("Calling RPC handler") result, err := callRPCHandler(handler, request.Params) if err != nil { errorResponse := JSONRPCResponse{ @@ -126,7 +126,7 @@ func onRPCMessage(message webrtc.DataChannelMessage, session *Session) { return } - logger.Tracef("RPC handler returned: %v, ID=%w", result, request.ID) + logger.Trace().Interface("result", result).Interface("id", request.ID).Msg("RPC handler returned") response := JSONRPCResponse{ JSONRPC: "2.0", Result: result, @@ -144,7 +144,7 @@ func rpcGetDeviceID() (string, error) { } func rpcReboot(force bool) error { - logger.Info("Got reboot request from JSONRPC, rebooting...") + logger.Info().Msg("Got reboot request from JSONRPC, rebooting...") args := []string{} if force { @@ -154,7 +154,7 @@ func rpcReboot(force bool) error { cmd := exec.Command("reboot", args...) err := cmd.Start() if err != nil { - logger.Errorf("failed to reboot: %v", err) + logger.Error().Err(err).Msg("failed to reboot") return fmt.Errorf("failed to reboot: %w", err) } diff --git a/log.go b/log.go index 6824a3f..5dac1f6 100644 --- a/log.go +++ b/log.go @@ -50,6 +50,7 @@ var ( displayLogger = getLogger("display") usbLogger = getLogger("usb") ginLogger = getLogger("gin") + websecureLogger = getLogger("websecure") ) func updateLogLevel() { diff --git a/web_tls.go b/web_tls.go index 40bc90b..048e9fa 100644 --- a/web_tls.go +++ b/web_tls.go @@ -35,15 +35,15 @@ type TLSState struct { func initCertStore() { if certStore != nil { - logger.Warnf("TLS store already initialized, it should not be initialized again") + websecureLogger.Warn().Msg("TLS store already initialized, it should not be initialized again") return } - certStore = websecure.NewCertStore(tlsStorePath) + certStore = websecure.NewCertStore(tlsStorePath, &websecureLogger) certStore.LoadCertificates() certSigner = websecure.NewSelfSigner( certStore, - logger, + &websecureLogger, webSecureSelfSignedDefaultDomain, webSecureSelfSignedOrganization, webSecureSelfSignedOU, @@ -61,7 +61,7 @@ func getCertificate(info *tls.ClientHelloInfo) (*tls.Certificate, error) { return certStore.GetCertificate(webSecureCustomCertificateName), nil } - logger.Infof("TLS mode is disabled but WebSecure is running, returning nil") + websecureLogger.Info().Msg("TLS mode is disabled but WebSecure is running, returning nil") return nil, nil } @@ -123,15 +123,15 @@ func setTLSState(s TLSState) error { } if !isChanged { - logger.Tracef("TLS enabled state is not changed, not starting/stopping websecure server") + websecureLogger.Info().Msg("TLS enabled state is not changed, not starting/stopping websecure server") return nil } if config.TLSMode == "" { - logger.Tracef("Stopping websecure server, as TLS mode is disabled") + websecureLogger.Info().Msg("Stopping websecure server, as TLS mode is disabled") stopWebSecureServer() } else { - logger.Tracef("Starting websecure server, as TLS mode is enabled") + websecureLogger.Info().Msg("Starting websecure server, as TLS mode is enabled") startWebSecureServer() } @@ -166,12 +166,15 @@ func runWebSecureServer() { GetCertificate: getCertificate, }, } - logger.Infof("Starting websecure server on %s", webSecureListen) + websecureLogger.Info().Str("listen", webSecureListen).Msg("Starting websecure server") go func() { for _ = range stopTLS { - logger.Infof("Shutting down websecure server") - server.Shutdown(context.Background()) + websecureLogger.Info().Msg("Shutting down websecure server") + err := server.Shutdown(context.Background()) + if err != nil { + websecureLogger.Error().Err(err).Msg("Failed to shutdown websecure server") + } } }() @@ -183,7 +186,7 @@ func runWebSecureServer() { func stopWebSecureServer() { if !tlsStarted { - logger.Warnf("Websecure server is not running, not stopping it") + websecureLogger.Info().Msg("Websecure server is not running, not stopping it") return } stopTLS <- struct{}{} @@ -191,7 +194,7 @@ func stopWebSecureServer() { func startWebSecureServer() { if tlsStarted { - logger.Warnf("Websecure server is already running, not starting it again") + websecureLogger.Info().Msg("Websecure server is already running, not starting it again") return } startTLS <- struct{}{} @@ -199,7 +202,7 @@ func startWebSecureServer() { func RunWebSecureServer() { for _ = range startTLS { - logger.Tracef("Starting websecure server, as we have received a start signal") + websecureLogger.Info().Msg("Starting websecure server, as we have received a start signal") if certStore == nil { initCertStore() }