From 77c67443838b397b9c68363e3a5a4d8347222227 Mon Sep 17 00:00:00 2001 From: sneak Date: Thu, 8 Jan 2026 12:47:31 -0800 Subject: [PATCH] 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 --- internal/handlers/imageenc.go | 3 ++- internal/imgcache/fetcher.go | 30 ++++++++++++++++++++++---- internal/imgcache/imgcache.go | 6 ++++++ internal/imgcache/service.go | 40 ++++++++++++++++++++++++++++------- 4 files changed, 66 insertions(+), 13 deletions(-) diff --git a/internal/handlers/imageenc.go b/internal/handlers/imageenc.go index efe2908..c93b79f 100644 --- a/internal/handlers/imageenc.go +++ b/internal/handlers/imageenc.go @@ -2,6 +2,7 @@ package handlers import ( "errors" + "fmt" "io" "net/http" "strconv" @@ -57,7 +58,7 @@ func (s *Handlers) HandleImageEnc() http.HandlerFunc { s.log.Debug("encrypted image request", "host", req.SourceHost, "path", req.SourcePath, - "size", req.Size, + "dimensions", fmt.Sprintf("%dx%d", req.Size.Width, req.Size.Height), "format", req.Format, ) diff --git a/internal/imgcache/fetcher.go b/internal/imgcache/fetcher.go index c3b78f4..66a07b2 100644 --- a/internal/imgcache/fetcher.go +++ b/internal/imgcache/fetcher.go @@ -2,11 +2,13 @@ package imgcache import ( "context" + "crypto/tls" "errors" "fmt" "io" "net" "net/http" + "net/http/httptrace" "strings" "sync" "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("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() 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) } - // Get remote address if available - var remoteAddr string - if resp.Request != nil && resp.Request.URL != nil { - remoteAddr = resp.Request.Host + // Extract HTTP version (strip "HTTP/" prefix) + httpVersion := strings.TrimPrefix(resp.Proto, "HTTP/") + + // 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 @@ -216,6 +235,9 @@ func (f *HTTPFetcher) Fetch(ctx context.Context, url string) (*FetchResult, erro StatusCode: resp.StatusCode, FetchDurationMs: fetchDuration.Milliseconds(), RemoteAddr: remoteAddr, + HTTPVersion: httpVersion, + TLSVersion: tlsVersion, + TLSCipherSuite: tlsCipherSuite, }, nil } diff --git a/internal/imgcache/imgcache.go b/internal/imgcache/imgcache.go index c5abdc9..f44df71 100644 --- a/internal/imgcache/imgcache.go +++ b/internal/imgcache/imgcache.go @@ -184,6 +184,12 @@ type FetchResult struct { FetchDurationMs int64 // RemoteAddr is the IP:port of the upstream server 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) diff --git a/internal/imgcache/service.go b/internal/imgcache/service.go index 1e43efa..f512265 100644 --- a/internal/imgcache/service.go +++ b/internal/imgcache/service.go @@ -9,6 +9,8 @@ import ( "log/slog" "net/url" "time" + + "github.com/dustin/go-humanize" ) // 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) } + // 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 if err := ValidateMagicBytes(sourceData, fetchResult.ContentType); err != nil { 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) // Log conversion details - inputSize := int64(len(sourceData)) 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", "host", req.SourceHost, "path", req.SourcePath, - "input_format", processResult.InputFormat, - "output_format", req.Format, - "input_bytes", inputSize, - "output_bytes", outputSize, - "input_dimensions", fmt.Sprintf("%dx%d", processResult.InputWidth, processResult.InputHeight), - "output_dimensions", fmt.Sprintf("%dx%d", processResult.Width, processResult.Height), + "src_format", processResult.InputFormat, + "dst_format", req.Format, + "src_bytes", fetchBytes, + "dst_bytes", outputSize, + "src_dimensions", fmt.Sprintf("%dx%d", processResult.InputWidth, processResult.InputHeight), + "dst_dimensions", fmt.Sprintf("%dx%d", processResult.Width, processResult.Height), "size_ratio", fmt.Sprintf("%.1f%%", sizePercent), "convert_ms", processDuration.Milliseconds(), "quality", req.Quality,