Add upstream connection info and download metrics to logging

- Capture TLS version, cipher suite, HTTP version, and remote addr
- Add download bitrate using go-humanize SI formatting
- Use consistent WxH format for dimensions (not struct notation)
- Rename input/output to src/dst for consistency
- Add separate "upstream fetched" log with connection details
This commit is contained in:
2026-01-08 12:47:31 -08:00
parent 7d0ac0a139
commit 77c6744383
4 changed files with 66 additions and 13 deletions

View File

@@ -2,6 +2,7 @@ package handlers
import ( import (
"errors" "errors"
"fmt"
"io" "io"
"net/http" "net/http"
"strconv" "strconv"
@@ -57,7 +58,7 @@ func (s *Handlers) HandleImageEnc() http.HandlerFunc {
s.log.Debug("encrypted image request", s.log.Debug("encrypted image request",
"host", req.SourceHost, "host", req.SourceHost,
"path", req.SourcePath, "path", req.SourcePath,
"size", req.Size, "dimensions", fmt.Sprintf("%dx%d", req.Size.Width, req.Size.Height),
"format", req.Format, "format", req.Format,
) )

View File

@@ -2,11 +2,13 @@ package imgcache
import ( import (
"context" "context"
"crypto/tls"
"errors" "errors"
"fmt" "fmt"
"io" "io"
"net" "net"
"net/http" "net/http"
"net/http/httptrace"
"strings" "strings"
"sync" "sync"
"time" "time"
@@ -164,6 +166,18 @@ func (f *HTTPFetcher) Fetch(ctx context.Context, url string) (*FetchResult, erro
req.Header.Set("User-Agent", f.config.UserAgent) req.Header.Set("User-Agent", f.config.UserAgent)
req.Header.Set("Accept", strings.Join(f.config.AllowedContentTypes, ", ")) req.Header.Set("Accept", strings.Join(f.config.AllowedContentTypes, ", "))
// Use httptrace to capture connection details
var remoteAddr string
trace := &httptrace.ClientTrace{
GotConn: func(info httptrace.GotConnInfo) {
if info.Conn != nil {
remoteAddr = info.Conn.RemoteAddr().String()
}
},
}
req = req.WithContext(httptrace.WithClientTrace(req.Context(), trace))
startTime := time.Now() startTime := time.Now()
resp, err := f.client.Do(req) resp, err := f.client.Do(req)
@@ -178,10 +192,15 @@ func (f *HTTPFetcher) Fetch(ctx context.Context, url string) (*FetchResult, erro
return nil, fmt.Errorf("upstream request failed: %w", err) return nil, fmt.Errorf("upstream request failed: %w", err)
} }
// Get remote address if available // Extract HTTP version (strip "HTTP/" prefix)
var remoteAddr string httpVersion := strings.TrimPrefix(resp.Proto, "HTTP/")
if resp.Request != nil && resp.Request.URL != nil {
remoteAddr = resp.Request.Host // Extract TLS info if available
var tlsVersion, tlsCipherSuite string
if resp.TLS != nil {
tlsVersion = tls.VersionName(resp.TLS.Version)
tlsCipherSuite = tls.CipherSuiteName(resp.TLS.CipherSuite)
} }
// Check status code // Check status code
@@ -216,6 +235,9 @@ func (f *HTTPFetcher) Fetch(ctx context.Context, url string) (*FetchResult, erro
StatusCode: resp.StatusCode, StatusCode: resp.StatusCode,
FetchDurationMs: fetchDuration.Milliseconds(), FetchDurationMs: fetchDuration.Milliseconds(),
RemoteAddr: remoteAddr, RemoteAddr: remoteAddr,
HTTPVersion: httpVersion,
TLSVersion: tlsVersion,
TLSCipherSuite: tlsCipherSuite,
}, nil }, nil
} }

View File

@@ -184,6 +184,12 @@ type FetchResult struct {
FetchDurationMs int64 FetchDurationMs int64
// RemoteAddr is the IP:port of the upstream server // RemoteAddr is the IP:port of the upstream server
RemoteAddr string RemoteAddr string
// HTTPVersion is the protocol version (e.g., "1.1", "2.0")
HTTPVersion string
// TLSVersion is the TLS protocol version (e.g., "TLS 1.3")
TLSVersion string
// TLSCipherSuite is the negotiated cipher suite name
TLSCipherSuite string
} }
// Processor handles image transformation (resize, format conversion) // Processor handles image transformation (resize, format conversion)

View File

@@ -9,6 +9,8 @@ import (
"log/slog" "log/slog"
"net/url" "net/url"
"time" "time"
"github.com/dustin/go-humanize"
) )
// Service implements the ImageCache interface, orchestrating cache, fetcher, and processor. // Service implements the ImageCache interface, orchestrating cache, fetcher, and processor.
@@ -144,6 +146,29 @@ func (s *Service) fetchAndProcess(ctx context.Context, req *ImageRequest) (*Imag
return nil, fmt.Errorf("failed to read upstream response: %w", err) return nil, fmt.Errorf("failed to read upstream response: %w", err)
} }
// Calculate download bitrate
fetchBytes := int64(len(sourceData))
var downloadRate string
if fetchResult.FetchDurationMs > 0 {
seconds := float64(fetchResult.FetchDurationMs) / 1000.0 //nolint:mnd // ms to seconds
bitsPerSecond := float64(fetchBytes*8) / seconds //nolint:mnd // bytes to bits
downloadRate = humanize.SI(bitsPerSecond, "bps")
}
// Log upstream fetch details
s.log.Info("upstream fetched",
"host", req.SourceHost,
"path", req.SourcePath,
"bytes", fetchBytes,
"fetch_ms", fetchResult.FetchDurationMs,
"rate", downloadRate,
"remote_addr", fetchResult.RemoteAddr,
"http", fetchResult.HTTPVersion,
"tls", fetchResult.TLSVersion,
"cipher", fetchResult.TLSCipherSuite,
)
// Validate magic bytes match content type // Validate magic bytes match content type
if err := ValidateMagicBytes(sourceData, fetchResult.ContentType); err != nil { if err := ValidateMagicBytes(sourceData, fetchResult.ContentType); err != nil {
return nil, fmt.Errorf("content validation failed: %w", err) return nil, fmt.Errorf("content validation failed: %w", err)
@@ -167,19 +192,18 @@ func (s *Service) fetchAndProcess(ctx context.Context, req *ImageRequest) (*Imag
processDuration := time.Since(processStart) processDuration := time.Since(processStart)
// Log conversion details // Log conversion details
inputSize := int64(len(sourceData))
outputSize := processResult.ContentLength outputSize := processResult.ContentLength
sizePercent := float64(outputSize) / float64(inputSize) * 100.0 //nolint:mnd // percentage calculation sizePercent := float64(outputSize) / float64(fetchBytes) * 100.0 //nolint:mnd // percentage calculation
s.log.Info("image converted", s.log.Info("image converted",
"host", req.SourceHost, "host", req.SourceHost,
"path", req.SourcePath, "path", req.SourcePath,
"input_format", processResult.InputFormat, "src_format", processResult.InputFormat,
"output_format", req.Format, "dst_format", req.Format,
"input_bytes", inputSize, "src_bytes", fetchBytes,
"output_bytes", outputSize, "dst_bytes", outputSize,
"input_dimensions", fmt.Sprintf("%dx%d", processResult.InputWidth, processResult.InputHeight), "src_dimensions", fmt.Sprintf("%dx%d", processResult.InputWidth, processResult.InputHeight),
"output_dimensions", fmt.Sprintf("%dx%d", processResult.Width, processResult.Height), "dst_dimensions", fmt.Sprintf("%dx%d", processResult.Width, processResult.Height),
"size_ratio", fmt.Sprintf("%.1f%%", sizePercent), "size_ratio", fmt.Sprintf("%.1f%%", sizePercent),
"convert_ms", processDuration.Milliseconds(), "convert_ms", processDuration.Milliseconds(),
"quality", req.Quality, "quality", req.Quality,