Move ssl/tls related error to debug loglevel, to avoid log cluttering.
This commit is contained in:
10
AGENTS.md
10
AGENTS.md
@@ -257,6 +257,16 @@ Checks `X-Forwarded-For` header first (for proxied requests), then falls back to
|
|||||||
- `WriteTimeout`: configurable via `backup_timeout` (converted to `time.Duration`)
|
- `WriteTimeout`: configurable via `backup_timeout` (converted to `time.Duration`)
|
||||||
- TLS minimum version: TLS 1.3 (when HTTPS enabled)
|
- TLS minimum version: TLS 1.3 (when HTTPS enabled)
|
||||||
|
|
||||||
|
### TLS Error Handling
|
||||||
|
|
||||||
|
The server uses a `serverWrapper` type to intercept and classify errors from `Serve()` and `ServeTLS()`. TLS-specific errors are logged at debug level to reduce log clutter:
|
||||||
|
|
||||||
|
- Uses `errors.As` to detect TLS error types: `tls.AlertError`, `tls.CertificateVerificationError`, `tls.ECHRejectionError`, `tls.RecordHeaderError`
|
||||||
|
- Also checks for "tls:" prefix in error messages
|
||||||
|
- Additionally uses `http.Server.ErrorLog` with a custom logger that writes at debug level for net/http's internal TLS-related messages
|
||||||
|
|
||||||
|
This ensures client-side TLS errors (handshake failures, certificate issues) don't clutter production logs.
|
||||||
|
|
||||||
## Dependencies
|
## Dependencies
|
||||||
|
|
||||||
- `github.com/hjson/hjson-go` v3.3.0 — HJSON config parsing
|
- `github.com/hjson/hjson-go` v3.3.0 — HJSON config parsing
|
||||||
|
|||||||
13
README.md
13
README.md
@@ -111,6 +111,19 @@ good enough cypher.
|
|||||||
|
|
||||||
And one more thing user and password are mandatory, we should have at least some minimal barriers, right?
|
And one more thing user and password are mandatory, we should have at least some minimal barriers, right?
|
||||||
|
|
||||||
|
## Logging
|
||||||
|
|
||||||
|
Backer logs events via Go's `slog`. Log levels: error, warn, info, debug.
|
||||||
|
|
||||||
|
### TLS Error Handling
|
||||||
|
|
||||||
|
TLS handshake errors and other client-side SSL/TLS errors are logged at **debug** level to reduce log clutter.
|
||||||
|
This includes:
|
||||||
|
- Certificate verification failures
|
||||||
|
- Handshake failures
|
||||||
|
- Protocol errors
|
||||||
|
- TLS-specific connection issues
|
||||||
|
|
||||||
## Special Thanks
|
## Special Thanks
|
||||||
|
|
||||||
This project was developed with the assistance of **opencode** (AI co-programmer powered by MIMO). The AI helped with:
|
This project was developed with the assistance of **opencode** (AI co-programmer powered by MIMO). The AI helped with:
|
||||||
|
|||||||
@@ -2,6 +2,7 @@
|
|||||||
package main
|
package main
|
||||||
|
|
||||||
import (
|
import (
|
||||||
|
"errors"
|
||||||
"flag"
|
"flag"
|
||||||
"fmt"
|
"fmt"
|
||||||
"net/http"
|
"net/http"
|
||||||
@@ -43,7 +44,7 @@ func main() {
|
|||||||
log.Infof("Starting backer version %s at %s", version, server.Addr)
|
log.Infof("Starting backer version %s at %s", version, server.Addr)
|
||||||
|
|
||||||
if backer.C.NoHTTPS {
|
if backer.C.NoHTTPS {
|
||||||
if err := server.ListenAndServe(); err != nil && err != http.ErrServerClosed {
|
if err := server.Serve(); err != nil && !errors.Is(err, http.ErrServerClosed) {
|
||||||
log.Fatalf("Failed to start server: %v", err)
|
log.Fatalf("Failed to start server: %v", err)
|
||||||
}
|
}
|
||||||
} else {
|
} else {
|
||||||
@@ -55,7 +56,7 @@ func main() {
|
|||||||
log.Fatalf("Certificate key file error: %v", err)
|
log.Fatalf("Certificate key file error: %v", err)
|
||||||
}
|
}
|
||||||
|
|
||||||
if err := server.ListenAndServeTLS(backer.C.Cert, backer.C.Key); err != nil && err != http.ErrServerClosed {
|
if err := server.ServeTLS(backer.C.Cert, backer.C.Key); err != nil && !errors.Is(err, http.ErrServerClosed) {
|
||||||
log.Fatalf("Failed to start server: %v", err)
|
log.Fatalf("Failed to start server: %v", err)
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|||||||
@@ -3,6 +3,7 @@ package backer
|
|||||||
import (
|
import (
|
||||||
"context"
|
"context"
|
||||||
"crypto/tls"
|
"crypto/tls"
|
||||||
|
"errors"
|
||||||
"fmt"
|
"fmt"
|
||||||
"io"
|
"io"
|
||||||
"net"
|
"net"
|
||||||
@@ -14,6 +15,36 @@ import (
|
|||||||
"backer/internal/log"
|
"backer/internal/log"
|
||||||
)
|
)
|
||||||
|
|
||||||
|
// isTLSError checks if the given error is TLS-related.
|
||||||
|
// It checks for both TLS-specific error types and error messages containing "tls:".
|
||||||
|
func isTLSError(err error) bool {
|
||||||
|
if err == nil {
|
||||||
|
return false
|
||||||
|
}
|
||||||
|
|
||||||
|
var alertErr *tls.AlertError
|
||||||
|
if errors.As(err, &alertErr) && alertErr != nil {
|
||||||
|
return true
|
||||||
|
}
|
||||||
|
|
||||||
|
var certErr *tls.CertificateVerificationError
|
||||||
|
if errors.As(err, &certErr) && certErr != nil {
|
||||||
|
return true
|
||||||
|
}
|
||||||
|
|
||||||
|
var echErr *tls.ECHRejectionError
|
||||||
|
if errors.As(err, &echErr) && echErr != nil {
|
||||||
|
return true
|
||||||
|
}
|
||||||
|
|
||||||
|
var recordErr *tls.RecordHeaderError
|
||||||
|
if errors.As(err, &recordErr) && recordErr != nil {
|
||||||
|
return true
|
||||||
|
}
|
||||||
|
|
||||||
|
return strings.HasPrefix(err.Error(), "tls:")
|
||||||
|
}
|
||||||
|
|
||||||
// withServerHeader wraps a handler to add Server header to all responses.
|
// withServerHeader wraps a handler to add Server header to all responses.
|
||||||
func withServerHeader(next http.Handler) http.Handler {
|
func withServerHeader(next http.Handler) http.Handler {
|
||||||
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
|
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
|
||||||
@@ -23,7 +54,8 @@ func withServerHeader(next http.Handler) http.Handler {
|
|||||||
}
|
}
|
||||||
|
|
||||||
// NewServer starts new server instance with given config file.
|
// NewServer starts new server instance with given config file.
|
||||||
func NewServer(configPath string) (*http.Server, error) {
|
// It returns a serverWrapper that intercepts and classifies server errors.
|
||||||
|
func NewServer(configPath string) (*serverWrapper, error) { //nolint: revive
|
||||||
_ = log.Init("info", "") // Initialize logger with defaults for early logging.
|
_ = log.Init("info", "") // Initialize logger with defaults for early logging.
|
||||||
|
|
||||||
if err := LoadConfig(configPath); err != nil {
|
if err := LoadConfig(configPath); err != nil {
|
||||||
@@ -139,21 +171,27 @@ func NewServer(configPath string) (*http.Server, error) {
|
|||||||
// HTTP mode if nohttps is enabled in config.
|
// HTTP mode if nohttps is enabled in config.
|
||||||
// HTTPS mode if nohttps is disabled in config.
|
// HTTPS mode if nohttps is disabled in config.
|
||||||
if C.NoHTTPS {
|
if C.NoHTTPS {
|
||||||
return &http.Server{
|
return &serverWrapper{
|
||||||
|
Server: &http.Server{
|
||||||
|
Addr: fmt.Sprintf("%s:%d", C.Address, C.Port),
|
||||||
|
Handler: withServerHeader(mux),
|
||||||
|
ReadHeaderTimeout: readHeaderTimeout,
|
||||||
|
WriteTimeout: time.Duration(C.BackupTimeout) * time.Minute,
|
||||||
|
ErrorLog: log.DebugLogger(),
|
||||||
|
},
|
||||||
|
}, nil
|
||||||
|
}
|
||||||
|
|
||||||
|
return &serverWrapper{
|
||||||
|
Server: &http.Server{
|
||||||
Addr: fmt.Sprintf("%s:%d", C.Address, C.Port),
|
Addr: fmt.Sprintf("%s:%d", C.Address, C.Port),
|
||||||
Handler: withServerHeader(mux),
|
Handler: withServerHeader(mux),
|
||||||
ReadHeaderTimeout: readHeaderTimeout,
|
ReadHeaderTimeout: readHeaderTimeout,
|
||||||
WriteTimeout: time.Duration(C.BackupTimeout) * time.Minute,
|
WriteTimeout: time.Duration(C.BackupTimeout) * time.Minute,
|
||||||
}, nil
|
TLSConfig: &tls.Config{
|
||||||
}
|
MinVersion: tls.VersionTLS13,
|
||||||
|
},
|
||||||
return &http.Server{
|
ErrorLog: log.DebugLogger(),
|
||||||
Addr: fmt.Sprintf("%s:%d", C.Address, C.Port),
|
|
||||||
Handler: withServerHeader(mux),
|
|
||||||
ReadHeaderTimeout: readHeaderTimeout,
|
|
||||||
WriteTimeout: time.Duration(C.BackupTimeout) * time.Minute,
|
|
||||||
TLSConfig: &tls.Config{
|
|
||||||
MinVersion: tls.VersionTLS13,
|
|
||||||
},
|
},
|
||||||
}, nil
|
}, nil
|
||||||
}
|
}
|
||||||
@@ -235,4 +273,42 @@ func getCompressionAlgorithm(requestedExt string) string {
|
|||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
|
// serverWrapper wraps http.Server to intercept and classify errors.
|
||||||
|
type (
|
||||||
|
serverWrapper struct {
|
||||||
|
*http.Server
|
||||||
|
}
|
||||||
|
)
|
||||||
|
|
||||||
|
// Serve starts the server and classifies any errors returned.
|
||||||
|
// TLS-related errors are logged at debug level, other errors at warn level.
|
||||||
|
func (sw *serverWrapper) Serve() error {
|
||||||
|
err := sw.ListenAndServe()
|
||||||
|
|
||||||
|
if err != nil {
|
||||||
|
if isTLSError(err) {
|
||||||
|
log.Debugf("Server error: %v", err)
|
||||||
|
} else {
|
||||||
|
log.Warnf("Server error: %v", err)
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
return err
|
||||||
|
}
|
||||||
|
|
||||||
|
// ServeTLS starts the TLS server and classifies any errors returned.
|
||||||
|
func (sw *serverWrapper) ServeTLS(certFile, keyFile string) error {
|
||||||
|
err := sw.ListenAndServeTLS(certFile, keyFile)
|
||||||
|
|
||||||
|
if err != nil {
|
||||||
|
if isTLSError(err) {
|
||||||
|
log.Debugf("Server TLS error: %v", err)
|
||||||
|
} else {
|
||||||
|
log.Warnf("Server TLS error: %v", err)
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
return err
|
||||||
|
}
|
||||||
|
|
||||||
/* vim: setlocal ft=go noet ai ts=4 sw=4 sts=4: */
|
/* vim: setlocal ft=go noet ai ts=4 sw=4 sts=4: */
|
||||||
|
|||||||
@@ -2,9 +2,12 @@
|
|||||||
package log
|
package log
|
||||||
|
|
||||||
import (
|
import (
|
||||||
|
"context"
|
||||||
"fmt"
|
"fmt"
|
||||||
|
"log"
|
||||||
"log/slog"
|
"log/slog"
|
||||||
"os"
|
"os"
|
||||||
|
"strings"
|
||||||
"time"
|
"time"
|
||||||
)
|
)
|
||||||
|
|
||||||
@@ -13,6 +16,13 @@ var (
|
|||||||
Log *os.File
|
Log *os.File
|
||||||
)
|
)
|
||||||
|
|
||||||
|
// slogWriter implements io.Writer to redirect standard log to slog.
|
||||||
|
type (
|
||||||
|
slogWriter struct {
|
||||||
|
handler slog.Handler
|
||||||
|
}
|
||||||
|
)
|
||||||
|
|
||||||
// Init sets up logger stuff.
|
// Init sets up logger stuff.
|
||||||
// level can be error, warn, info, debug; if something other is supplied, info level is selected.
|
// level can be error, warn, info, debug; if something other is supplied, info level is selected.
|
||||||
func Init(level, filename string) error {
|
func Init(level, filename string) error {
|
||||||
@@ -122,6 +132,44 @@ func Debugf(format string, a ...any) {
|
|||||||
slog.Debug(fmt.Sprintf(format, a...))
|
slog.Debug(fmt.Sprintf(format, a...))
|
||||||
}
|
}
|
||||||
|
|
||||||
|
// DebugLogger returns a standard library logger that writes to debug level.
|
||||||
|
// This is useful for assigning to http.Server.ErrorLog to move TLS handshake
|
||||||
|
// and other client-side errors to debug level.
|
||||||
|
func DebugLogger() *log.Logger {
|
||||||
|
opts := &slog.HandlerOptions{
|
||||||
|
Level: slog.LevelDebug,
|
||||||
|
}
|
||||||
|
|
||||||
|
handler := slog.NewTextHandler(Log, opts)
|
||||||
|
|
||||||
|
return log.New(&slogWriter{handler: handler}, "", 0)
|
||||||
|
}
|
||||||
|
|
||||||
|
// Write implements io.Writer. It differentiates TLS/SSL errors from other errors.
|
||||||
|
// TLS-related errors are logged at debug level, while other errors (handler issues,
|
||||||
|
// unexpected behavior) are logged at warn level.
|
||||||
|
func (w *slogWriter) Write(p []byte) (int, error) {
|
||||||
|
msg := string(p)
|
||||||
|
|
||||||
|
isTLSError := strings.Contains(msg, "tls") ||
|
||||||
|
strings.Contains(msg, "ssl") ||
|
||||||
|
strings.Contains(msg, "TLS") ||
|
||||||
|
strings.Contains(msg, "SSL") ||
|
||||||
|
strings.Contains(msg, "handshake") ||
|
||||||
|
strings.Contains(msg, "certificate")
|
||||||
|
|
||||||
|
level := slog.LevelWarn
|
||||||
|
if isTLSError {
|
||||||
|
level = slog.LevelDebug
|
||||||
|
}
|
||||||
|
|
||||||
|
record := slog.NewRecord(time.Now(), level, msg, 0)
|
||||||
|
|
||||||
|
_ = w.handler.Handle(context.TODO(), record)
|
||||||
|
|
||||||
|
return len(p), nil
|
||||||
|
}
|
||||||
|
|
||||||
// Fatal logs args at error level and quits with status code 1.
|
// Fatal logs args at error level and quits with status code 1.
|
||||||
func Fatal(args ...any) {
|
func Fatal(args ...any) {
|
||||||
slog.Error(fmt.Sprint(args...))
|
slog.Error(fmt.Sprint(args...))
|
||||||
|
|||||||
Reference in New Issue
Block a user