use latest log format

This commit is contained in:
Siyuan Miao 2025-04-11 00:31:29 +02:00
parent bafbc3da4c
commit 4571362202
7 changed files with 60 additions and 48 deletions

View File

@ -169,7 +169,7 @@ func SaveConfig() error {
configLock.Lock() configLock.Lock()
defer configLock.Unlock() defer configLock.Unlock()
logger.Tracef("Saving config to %s", configPath) logger.Trace().Str("path", configPath).Msg("Saving config")
file, err := os.Create(configPath) file, err := os.Create(configPath)
if err != nil { if err != nil {

View File

@ -1,5 +1,9 @@
package websecure 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()

View File

@ -11,7 +11,7 @@ import (
"strings" "strings"
"time" "time"
"github.com/pion/logging" "github.com/rs/zerolog"
"golang.org/x/net/idna" "golang.org/x/net/idna"
) )
@ -19,7 +19,7 @@ const selfSignerCAMagicName = "__ca__"
type SelfSigner struct { type SelfSigner struct {
store *CertStore store *CertStore
log logging.LeveledLogger log *zerolog.Logger
caInfo pkix.Name caInfo pkix.Name
@ -30,7 +30,7 @@ type SelfSigner struct {
func NewSelfSigner( func NewSelfSigner(
store *CertStore, store *CertStore,
log logging.LeveledLogger, log *zerolog.Logger,
defaultDomain, defaultDomain,
defaultOrg, defaultOrg,
defaultOU, defaultOU,
@ -64,12 +64,12 @@ func (s *SelfSigner) createSelfSignedCert(hostname string) *tls.Certificate {
if hostname != selfSignerCAMagicName { if hostname != selfSignerCAMagicName {
ca = s.getCA() ca = s.getCA()
if ca == nil { if ca == nil {
s.log.Errorf("Failed to get CA certificate") s.log.Error().Msg("Failed to get CA certificate")
return nil 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) // lock the store while creating the certificate (do not move upwards)
s.store.certLock.Lock() s.store.certLock.Lock()
@ -77,7 +77,7 @@ func (s *SelfSigner) createSelfSignedCert(hostname string) *tls.Certificate {
priv, err := ecdsa.GenerateKey(elliptic.P256(), rand.Reader) priv, err := ecdsa.GenerateKey(elliptic.P256(), rand.Reader)
if err != nil { 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 return nil
} }
@ -86,7 +86,7 @@ func (s *SelfSigner) createSelfSignedCert(hostname string) *tls.Certificate {
serialNumber, err := generateSerialNumber() serialNumber, err := generateSerialNumber()
if err != nil { 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 return nil
} }
@ -139,7 +139,7 @@ func (s *SelfSigner) createSelfSignedCert(hostname string) *tls.Certificate {
if ca != nil { if ca != nil {
parent, err = x509.ParseCertificate(ca.Certificate[0]) parent, err = x509.ParseCertificate(ca.Certificate[0])
if err != nil { 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 return nil
} }
parentPriv = ca.PrivateKey.(*ecdsa.PrivateKey) 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) certBytes, err := x509.CreateCertificate(rand.Reader, &cert, parent, &priv.PublicKey, parentPriv)
if err != nil { if err != nil {
s.log.Errorf("Failed to create certificate: %v", err) s.log.Error().Err(err).Msg("Failed to create certificate")
return nil return nil
} }
@ -175,12 +175,12 @@ func (s *SelfSigner) GetCertificate(info *tls.ClientHelloInfo) (*tls.Certificate
hostname = strings.Split(info.Conn.LocalAddr().String(), ":")[0] 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 // convert hostname to punycode
h, err := idna.Lookup.ToASCII(hostname) h, err := idna.Lookup.ToASCII(hostname)
if err != nil { 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 hostname = s.DefaultDomain
} else { } else {
hostname = h hostname = h

View File

@ -8,7 +8,7 @@ import (
"strings" "strings"
"sync" "sync"
"github.com/pion/logging" "github.com/rs/zerolog"
) )
type CertStore struct { type CertStore struct {
@ -17,16 +17,20 @@ type CertStore struct {
storePath string storePath string
log logging.LeveledLogger log *zerolog.Logger
}
func NewCertStore(storePath string, log *zerolog.Logger) *CertStore {
if log == nil {
log = &defaultLogger
} }
func NewCertStore(storePath string) *CertStore {
return &CertStore{ return &CertStore{
certificates: make(map[string]*tls.Certificate), certificates: make(map[string]*tls.Certificate),
certLock: &sync.Mutex{}, certLock: &sync.Mutex{},
storePath: storePath, storePath: storePath,
log: defaultLogger, log: log,
} }
} }
@ -42,7 +46,7 @@ func (s *CertStore) ensureStorePath() error {
} }
if os.IsNotExist(err) { 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) err = os.MkdirAll(s.storePath, 0755)
if err != nil { if err != nil {
return fmt.Errorf("Failed to create TLS store path: %w", err) return fmt.Errorf("Failed to create TLS store path: %w", err)
@ -56,13 +60,13 @@ func (s *CertStore) ensureStorePath() error {
func (s *CertStore) LoadCertificates() { func (s *CertStore) LoadCertificates() {
err := s.ensureStorePath() err := s.ensureStorePath()
if err != nil { if err != nil {
s.log.Errorf(err.Error()) //nolint:errcheck s.log.Error().Err(err).Msg("Failed to ensure store path")
return return
} }
files, err := os.ReadDir(s.storePath) files, err := os.ReadDir(s.storePath)
if err != nil { 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 return
} }
@ -86,13 +90,13 @@ func (s *CertStore) loadCertificate(hostname string) {
cert, err := tls.LoadX509KeyPair(crtFile, keyFile) cert, err := tls.LoadX509KeyPair(crtFile, keyFile)
if err != nil { 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 return
} }
s.certificates[hostname] = &cert 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 // 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 // add recover to avoid panic
defer func() { defer func() {
if r := recover(); r != nil { 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 { if !ignoreWarning {
return nil, fmt.Errorf("Certificate does not match hostname: %w", err) 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 // check if certificate already exists
tlsCert := s.certificates[hostname] tlsCert := s.certificates[hostname]
if tlsCert == nil { 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 return
} }
err := s.ensureStorePath() err := s.ensureStorePath()
if err != nil { if err != nil {
s.log.Errorf(err.Error()) //nolint:errcheck s.log.Error().Err(err).Msg("Failed to ensure store path")
return return
} }
@ -158,14 +162,14 @@ func (s *CertStore) saveCertificate(hostname string) {
crtFile := path.Join(s.storePath, hostname+".crt") crtFile := path.Join(s.storePath, hostname+".crt")
if err := keyToFile(tlsCert, keyFile); err != nil { if err := keyToFile(tlsCert, keyFile); err != nil {
s.log.Errorf(err.Error()) s.log.Error().Err(err).Msg("Failed to save key file")
return return
} }
if err := certToFile(tlsCert, crtFile); err != nil { if err := certToFile(tlsCert, crtFile); err != nil {
s.log.Errorf(err.Error()) s.log.Error().Err(err).Msg("Failed to save certificate")
return return
} }
s.log.Infof("Saved certificate for %s", hostname) s.log.Info().Str("hostname", hostname).Msg("Saved certificate")
} }

View File

@ -95,7 +95,7 @@ func onRPCMessage(message webrtc.DataChannelMessage, session *Session) {
return 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] handler, ok := rpcHandlers[request.Method]
if !ok { if !ok {
errorResponse := JSONRPCResponse{ errorResponse := JSONRPCResponse{
@ -110,7 +110,7 @@ func onRPCMessage(message webrtc.DataChannelMessage, session *Session) {
return 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) result, err := callRPCHandler(handler, request.Params)
if err != nil { if err != nil {
errorResponse := JSONRPCResponse{ errorResponse := JSONRPCResponse{
@ -126,7 +126,7 @@ func onRPCMessage(message webrtc.DataChannelMessage, session *Session) {
return 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{ response := JSONRPCResponse{
JSONRPC: "2.0", JSONRPC: "2.0",
Result: result, Result: result,
@ -144,7 +144,7 @@ func rpcGetDeviceID() (string, error) {
} }
func rpcReboot(force bool) 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{} args := []string{}
if force { if force {
@ -154,7 +154,7 @@ func rpcReboot(force bool) error {
cmd := exec.Command("reboot", args...) cmd := exec.Command("reboot", args...)
err := cmd.Start() err := cmd.Start()
if err != nil { 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) return fmt.Errorf("failed to reboot: %w", err)
} }

1
log.go
View File

@ -50,6 +50,7 @@ var (
displayLogger = getLogger("display") displayLogger = getLogger("display")
usbLogger = getLogger("usb") usbLogger = getLogger("usb")
ginLogger = getLogger("gin") ginLogger = getLogger("gin")
websecureLogger = getLogger("websecure")
) )
func updateLogLevel() { func updateLogLevel() {

View File

@ -35,15 +35,15 @@ type TLSState struct {
func initCertStore() { func initCertStore() {
if certStore != nil { 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 return
} }
certStore = websecure.NewCertStore(tlsStorePath) certStore = websecure.NewCertStore(tlsStorePath, &websecureLogger)
certStore.LoadCertificates() certStore.LoadCertificates()
certSigner = websecure.NewSelfSigner( certSigner = websecure.NewSelfSigner(
certStore, certStore,
logger, &websecureLogger,
webSecureSelfSignedDefaultDomain, webSecureSelfSignedDefaultDomain,
webSecureSelfSignedOrganization, webSecureSelfSignedOrganization,
webSecureSelfSignedOU, webSecureSelfSignedOU,
@ -61,7 +61,7 @@ func getCertificate(info *tls.ClientHelloInfo) (*tls.Certificate, error) {
return certStore.GetCertificate(webSecureCustomCertificateName), nil 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 return nil, nil
} }
@ -123,15 +123,15 @@ func setTLSState(s TLSState) error {
} }
if !isChanged { 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 return nil
} }
if config.TLSMode == "" { 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() stopWebSecureServer()
} else { } else {
logger.Tracef("Starting websecure server, as TLS mode is enabled") websecureLogger.Info().Msg("Starting websecure server, as TLS mode is enabled")
startWebSecureServer() startWebSecureServer()
} }
@ -166,12 +166,15 @@ func runWebSecureServer() {
GetCertificate: getCertificate, GetCertificate: getCertificate,
}, },
} }
logger.Infof("Starting websecure server on %s", webSecureListen) websecureLogger.Info().Str("listen", webSecureListen).Msg("Starting websecure server")
go func() { go func() {
for _ = range stopTLS { for _ = range stopTLS {
logger.Infof("Shutting down websecure server") websecureLogger.Info().Msg("Shutting down websecure server")
server.Shutdown(context.Background()) 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() { func stopWebSecureServer() {
if !tlsStarted { if !tlsStarted {
logger.Warnf("Websecure server is not running, not stopping it") websecureLogger.Info().Msg("Websecure server is not running, not stopping it")
return return
} }
stopTLS <- struct{}{} stopTLS <- struct{}{}
@ -191,7 +194,7 @@ func stopWebSecureServer() {
func startWebSecureServer() { func startWebSecureServer() {
if tlsStarted { 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 return
} }
startTLS <- struct{}{} startTLS <- struct{}{}
@ -199,7 +202,7 @@ func startWebSecureServer() {
func RunWebSecureServer() { func RunWebSecureServer() {
for _ = range startTLS { 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 { if certStore == nil {
initCertStore() initCertStore()
} }