Add comprehensive logging and debug endpoints for production troubleshooting

- Add request logging middleware to main.go - Add debug handler with health, config, stats, and test-dns endpoints - Add detailed logging to DynDNS handler - Add logging to Technitium DNS client - Add database Ping() and GetStats() methods - New endpoints: - /health - detailed health status with database and DNS checks - /debug/config - sanitized configuration - /debug/stats - database statistics - /debug/test-dns - live DNS test endpoint This will help diagnose production issues with DNS updates.
2026-02-02 22:14:24 -05:00
parent ad494fa623
commit 01694f66a8
5 changed files with 266 additions and 0 deletions
--- a/cmd/server/main.go
+++ b/cmd/server/main.go
@@ -45,6 +45,25 @@ func main() {
 	gin.SetMode(gin.ReleaseMode)
 	router := gin.New()
 	router.Use(gin.Recovery())
+	// Add request logging middleware
+	router.Use(func(c *gin.Context) {
+		start := time.Now()
+		path := c.Request.URL.Path
+		raw := c.Request.URL.RawQuery
+
+		c.Next()
+
+		latency := time.Since(start)
+		clientIP := c.ClientIP()
+		method := c.Request.Method
+		statusCode := c.Writer.Status()
+
+		if raw != "" {
+			path = path + "?" + raw
+		}
+
+		log.Printf("[%s] %s %s %d %v", clientIP, method, path, statusCode, latency)
+	})

 	if len(cfg.TrustedProxies) > 0 {
 		router.SetTrustedProxies(cfg.TrustedProxies)
@@ -55,9 +74,16 @@ func main() {

 	webHandler := handlers.NewWebHandler(db, cfg)
 	dynHandler := handlers.NewDynDNSHandler(db, dnsClient, cfg)
+	debugHandler := handlers.NewDebugHandler(db, dnsClient, cfg)

 	router.GET("/", webHandler.Index)

+	// Debug/health endpoints (no rate limiting)
+	router.GET("/health", debugHandler.Health)
+	router.GET("/debug/config", debugHandler.ConfigDebug)
+	router.GET("/debug/stats", debugHandler.Stats)
+	router.GET("/debug/test-dns", debugHandler.TestDNS)
+
 	api := router.Group("/api")
 	api.Use(rateLimiter.RateLimitByIP())
 	{
--- a/internal/database/db.go
+++ b/internal/database/db.go
@@ -54,6 +54,42 @@ func (db *DB) Close() error {
 	return db.conn.Close()
 }

+// Ping checks if the database connection is alive
+func (db *DB) Ping() error {
+	return db.conn.Ping()
+}
+
+// GetStats returns database statistics
+func (db *DB) GetStats() (map[string]interface{}, error) {
+	stats := make(map[string]interface{})
+
+	// Get total spaces count
+	var totalSpaces int
+	err := db.conn.QueryRow("SELECT COUNT(*) FROM spaces").Scan(&totalSpaces)
+	if err != nil {
+		return nil, err
+	}
+	stats["total_spaces"] = totalSpaces
+
+	// Get spaces with IPs (active)
+	var activeSpaces int
+	err = db.conn.QueryRow("SELECT COUNT(*) FROM spaces WHERE last_ip IS NOT NULL").Scan(&activeSpaces)
+	if err != nil {
+		return nil, err
+	}
+	stats["active_spaces"] = activeSpaces
+
+	// Get recently updated (last 24 hours)
+	var recentlyUpdated int
+	err = db.conn.QueryRow("SELECT COUNT(*) FROM spaces WHERE updated_at > datetime('now', '-1 day')").Scan(&recentlyUpdated)
+	if err != nil {
+		return nil, err
+	}
+	stats["recently_updated_24h"] = recentlyUpdated
+
+	return stats, nil
+}
+
 func (db *DB) CreateSpace(ctx context.Context, subdomain string) (*models.Space, error) {
 	token, err := generateToken()
 	if err != nil {
--- a/internal/dns/technitium.go
+++ b/internal/dns/technitium.go
@@ -5,6 +5,7 @@ import (
 	"encoding/json"
 	"fmt"
 	"io"
+	"log"
 	"net/http"
 	"net/url"
 	"time"
@@ -91,6 +92,7 @@ func (c *Client) AddWildcardARecord(zone, hostname, ip string, ttl int) error {

 func (c *Client) addRecord(req AddRecordRequest) error {
 	endpoint := fmt.Sprintf("%s/api/dns/records/add", c.baseURL)
+	log.Printf("[DNS] Adding record: domain=%s, type=%s, ip=%s", req.Domain, req.Type, req.IPAddress)

 	formData := url.Values{}
 	formData.Set("domain", req.Domain)
@@ -103,6 +105,7 @@ func (c *Client) addRecord(req AddRecordRequest) error {

 	httpReq, err := http.NewRequest("POST", endpoint, bytes.NewBufferString(formData.Encode()))
 	if err != nil {
+		log.Printf("[DNS] Failed to create request: %v", err)
 		return fmt.Errorf("failed to create request: %w", err)
 	}

@@ -110,37 +113,50 @@ func (c *Client) addRecord(req AddRecordRequest) error {

 	if c.token != "" {
 		httpReq.Header.Set("Authorization", "Basic "+c.token)
+		log.Printf("[DNS] Using token auth")
 	} else if c.username != "" && c.password != "" {
 		httpReq.SetBasicAuth(c.username, c.password)
+		log.Printf("[DNS] Using basic auth (username: %s)", c.username)
+	} else {
+		log.Printf("[DNS] Warning: No authentication configured!")
 	}

+	log.Printf("[DNS] Sending request to %s", endpoint)
 	resp, err := c.httpClient.Do(httpReq)
 	if err != nil {
+		log.Printf("[DNS] Request failed: %v", err)
 		return fmt.Errorf("failed to execute request: %w", err)
 	}
 	defer resp.Body.Close()

 	body, err := io.ReadAll(resp.Body)
 	if err != nil {
+		log.Printf("[DNS] Failed to read response: %v", err)
 		return fmt.Errorf("failed to read response body: %w", err)
 	}

+	log.Printf("[DNS] Response status: %d, body: %s", resp.StatusCode, string(body))
+
 	if resp.StatusCode != http.StatusOK {
 		return fmt.Errorf("HTTP error %d: %s", resp.StatusCode, string(body))
 	}

 	var apiResp APIResponse
 	if err := json.Unmarshal(body, &apiResp); err != nil {
+		log.Printf("[DNS] Failed to parse response: %v", err)
 		return fmt.Errorf("failed to parse response: %w", err)
 	}

 	if apiResp.Status != "ok" {
 		if apiResp.Error != nil {
+			log.Printf("[DNS] API error: %s - %s", apiResp.Error.Code, apiResp.Error.Message)
 			return fmt.Errorf("API error: %s - %s", apiResp.Error.Code, apiResp.Error.Message)
 		}
+		log.Printf("[DNS] API error: status not ok")
 		return fmt.Errorf("API error: status not ok")
 	}

+	log.Printf("[DNS] Record added successfully")
 	return nil
 }

--- a/internal/handlers/debug.go
+++ b/internal/handlers/debug.go
@@ -0,0 +1,169 @@
+package handlers
+
+import (
+	"fmt"
+	"net/http"
+	"os"
+	"runtime"
+	"time"
+
+	"git.dws.rip/DWS/dyn/internal/config"
+	"git.dws.rip/DWS/dyn/internal/database"
+	"git.dws.rip/DWS/dyn/internal/dns"
+	"github.com/gin-gonic/gin"
+)
+
+// DebugHandler provides diagnostic endpoints for production troubleshooting
+type DebugHandler struct {
+	db        *database.DB
+	dns       *dns.Client
+	config    *config.Config
+	startTime string
+}
+
+// NewDebugHandler creates a new debug handler
+func NewDebugHandler(db *database.DB, dnsClient *dns.Client, cfg *config.Config) *DebugHandler {
+	return &DebugHandler{
+		db:        db,
+		dns:       dnsClient,
+		config:    cfg,
+		startTime: time.Now().Format(time.RFC3339),
+	}
+}
+
+// Health returns detailed health status
+func (h *DebugHandler) Health(c *gin.Context) {
+	health := gin.H{
+		"status":     "healthy",
+		"version":    getVersion(),
+		"uptime":     h.startTime,
+		"go_version": runtime.Version(),
+	}
+
+	// Check database
+	if err := h.db.Ping(); err != nil {
+		health["database"] = gin.H{"status": "unhealthy", "error": err.Error()}
+		health["status"] = "degraded"
+	} else {
+		health["database"] = gin.H{"status": "healthy"}
+	}
+
+	// Check Technitium connectivity
+	if err := h.testTechnitiumConnection(); err != nil {
+		health["technitium"] = gin.H{"status": "unhealthy", "error": err.Error()}
+		health["status"] = "degraded"
+	} else {
+		health["technitium"] = gin.H{"status": "healthy"}
+	}
+
+	// Config (without secrets)
+	health["config"] = gin.H{
+		"base_domain":      h.config.BaseDomain,
+		"space_subdomain":  h.config.SpaceSubdomain,
+		"zone":             h.config.GetZone(),
+		"technitium_url":   h.config.TechnitiumURL,
+		"rate_limit_ip":    h.config.RateLimitPerIP,
+		"rate_limit_token": h.config.RateLimitPerToken,
+	}
+
+	c.JSON(http.StatusOK, health)
+}
+
+// TestDNS attempts to create and delete a test DNS record
+func (h *DebugHandler) TestDNS(c *gin.Context) {
+	testSubdomain := "test-health-check-" + fmt.Sprintf("%d", time.Now().Unix())
+	testIP := "1.2.3.4"
+	zone := h.config.GetZone()
+
+	results := gin.H{
+		"zone":      zone,
+		"subdomain": testSubdomain,
+		"test_ip":   testIP,
+	}
+
+	// Try to add a record
+	err := h.dns.AddARecord(zone, testSubdomain, testIP, 60)
+	if err != nil {
+		results["add_record"] = gin.H{"success": false, "error": err.Error()}
+		c.JSON(http.StatusServiceUnavailable, results)
+		return
+	}
+	results["add_record"] = gin.H{"success": true}
+
+	// Try to add wildcard
+	err = h.dns.AddWildcardARecord(zone, testSubdomain, testIP, 60)
+	if err != nil {
+		results["add_wildcard"] = gin.H{"success": false, "error": err.Error()}
+		c.JSON(http.StatusServiceUnavailable, results)
+		return
+	}
+	results["add_wildcard"] = gin.H{"success": true}
+
+	// Cleanup - delete the test records
+	err = h.dns.DeleteRecord(zone, testSubdomain, "A")
+	if err != nil {
+		results["cleanup"] = gin.H{"warning": "Failed to cleanup test record", "error": err.Error()}
+	} else {
+		results["cleanup"] = gin.H{"success": true}
+	}
+
+	// Delete wildcard
+	err = h.dns.DeleteRecord(zone, "*."+testSubdomain, "A")
+	if err != nil {
+		results["cleanup_wildcard"] = gin.H{"warning": "Failed to cleanup wildcard", "error": err.Error()}
+	}
+
+	results["overall"] = "success"
+	c.JSON(http.StatusOK, results)
+}
+
+// ConfigDebug shows current configuration (sanitized)
+func (h *DebugHandler) ConfigDebug(c *gin.Context) {
+	cfg := gin.H{
+		"server_port":          h.config.ServerPort,
+		"database_path":        h.config.DatabasePath,
+		"technitium_url":       h.config.TechnitiumURL,
+		"base_domain":          h.config.BaseDomain,
+		"space_subdomain":      h.config.SpaceSubdomain,
+		"zone":                 h.config.GetZone(),
+		"rate_limit_per_ip":    h.config.RateLimitPerIP,
+		"rate_limit_per_token": h.config.RateLimitPerToken,
+		"trusted_proxies":      h.config.TrustedProxies,
+		// Don't expose credentials!
+		"has_token":    h.config.TechnitiumToken != "",
+		"has_username": h.config.TechnitiumUsername != "",
+		"has_password": h.config.TechnitiumPassword != "",
+	}
+
+	c.JSON(http.StatusOK, cfg)
+}
+
+// Stats returns database statistics
+func (h *DebugHandler) Stats(c *gin.Context) {
+	stats, err := h.db.GetStats()
+	if err != nil {
+		c.JSON(http.StatusInternalServerError, gin.H{"error": err.Error()})
+		return
+	}
+
+	c.JSON(http.StatusOK, stats)
+}
+
+func (h *DebugHandler) testTechnitiumConnection() error {
+	// Try a simple operation - add and immediately delete a test record
+	testSubdomain := "conn-test" + fmt.Sprintf("%d", time.Now().Unix())
+	err := h.dns.AddARecord(h.config.GetZone(), testSubdomain, "127.0.0.1", 1)
+	if err != nil {
+		return err
+	}
+	// Cleanup
+	h.dns.DeleteRecord(h.config.GetZone(), testSubdomain, "A")
+	return nil
+}
+
+func getVersion() string {
+	if v := os.Getenv("VERSION"); v != "" {
+		return v
+	}
+	return "dev"
+}
--- a/internal/handlers/handlers.go
+++ b/internal/handlers/handlers.go
@@ -3,6 +3,7 @@ package handlers
 import (
 	"context"
 	"encoding/base64"
+	"log"
 	"net"
 	"net/http"
 	"strings"
@@ -170,14 +171,19 @@ func NewDynDNSHandler(db *database.DB, dnsClient *dns.Client, cfg *config.Config
 func (h *DynDNSHandler) Update(c *gin.Context) {
 	token, err := extractBasicAuthPassword(c)
 	if err != nil {
+		log.Printf("[DynDNS] Auth extraction error: %v", err)
 		c.String(http.StatusUnauthorized, "badauth")
 		return
 	}

 	hostname := c.Query("hostname")
 	myip := c.Query("myip")
+	clientIP := c.ClientIP()
+
+	log.Printf("[DynDNS] Update request from %s: hostname=%s, myip=%s", clientIP, hostname, myip)

 	if hostname == "" {
+		log.Printf("[DynDNS] Error: hostname missing")
 		c.String(http.StatusBadRequest, "nohost")
 		return
 	}
@@ -187,54 +193,67 @@ func (h *DynDNSHandler) Update(c *gin.Context) {

 	space, err := h.db.GetSpaceByToken(ctx, token)
 	if err != nil {
+		log.Printf("[DynDNS] Database error getting space: %v", err)
 		c.String(http.StatusServiceUnavailable, "911")
 		return
 	}
 	if space == nil {
+		log.Printf("[DynDNS] Invalid token provided")
 		c.String(http.StatusUnauthorized, "badauth")
 		return
 	}

 	expectedFQDN := space.GetFQDN(h.config.GetZone())
 	if hostname != expectedFQDN {
+		log.Printf("[DynDNS] Hostname mismatch: expected %s, got %s", expectedFQDN, hostname)
 		c.String(http.StatusBadRequest, "nohost")
 		return
 	}

 	if myip == "" {
 		myip = c.ClientIP()
+		log.Printf("[DynDNS] Using client IP: %s", myip)
 	}

 	if net.ParseIP(myip) == nil {
+		log.Printf("[DynDNS] Invalid IP format: %s", myip)
 		c.String(http.StatusBadRequest, "dnserr")
 		return
 	}

 	zone := h.config.GetZone()
+	log.Printf("[DynDNS] Updating DNS: zone=%s, subdomain=%s, ip=%s", zone, space.Subdomain, myip)

 	err = h.dns.AddARecord(zone, space.Subdomain, myip, 300)
 	if err != nil {
+		log.Printf("[DynDNS] Failed to add A record: %v", err)
 		c.String(http.StatusServiceUnavailable, "911")
 		return
 	}
+	log.Printf("[DynDNS] A record added successfully")

 	err = h.dns.AddWildcardARecord(zone, space.Subdomain, myip, 300)
 	if err != nil {
+		log.Printf("[DynDNS] Failed to add wildcard A record: %v", err)
 		c.String(http.StatusServiceUnavailable, "911")
 		return
 	}
+	log.Printf("[DynDNS] Wildcard A record added successfully")

 	if space.LastIP == myip {
+		log.Printf("[DynDNS] IP unchanged: %s", myip)
 		c.String(http.StatusOK, "nochg %s", myip)
 		return
 	}

 	err = h.db.UpdateSpaceIP(ctx, token, myip)
 	if err != nil {
+		log.Printf("[DynDNS] Failed to update space IP in database: %v", err)
 		c.String(http.StatusServiceUnavailable, "911")
 		return
 	}

+	log.Printf("[DynDNS] Update successful: %s -> %s", hostname, myip)
 	c.String(http.StatusOK, "good %s", myip)
 }