instrument logging to determine LE failures

main.go

@@ -1,4 +1,4 @@
-// Command leproxy implements https reverse proxy with automatic Letsencrypt usage for multiple
+// Command reverse implements https reverse proxy with automatic Letsencrypt usage for multiple
 // hostnames/backends
 package main
 
@@ -45,9 +45,13 @@ var faviconData []byte
 var faviconContentType string
 
 func main() {
+	log.I.Ln("=== REVERSE PROXY STARTING ===")
+	log.I.Ln("PID:", os.Getpid())
+	log.I.Ln("Time:", time.Now().Format(time.RFC3339))
 	ctx, cancel := signal.NotifyContext(context.Background(), os.Interrupt)
 	defer cancel()
 	if err := run(ctx); err != nil {
+		log.E.Ln("FATAL ERROR:", err)
 		log2.Fatal(err)
 	}
 }
@@ -259,17 +263,31 @@ func HelpRequested() (help bool) {
 var cfg *C
 
 func run(ctx context.Context) error {
+	log.I.Ln("[RUN] Starting run() function")
 	var err error
 	cfg = &C{}
 	if err = env.Load(cfg, &env.Options{SliceSep: ","}); chk.T(err) {
+		log.E.Ln("[RUN] Failed to load environment config:", err)
 		return err
 	}
+	log.I.Ln("[RUN] Environment config loaded successfully")
+	log.I.Ln("[RUN] REVERSE_LISTEN:", cfg.Addr)
+	log.I.Ln("[RUN] REVERSE_HTTP:", cfg.HTTP)
+	log.I.Ln("[RUN] REVERSE_MAP:", cfg.Conf)
+	log.I.Ln("[RUN] REVERSE_CACHE:", cfg.Cache)
+	log.I.Ln("[RUN] REVERSE_EMAIL:", cfg.Email)
+	log.I.Ln("[RUN] REVERSE_HSTS:", cfg.HSTS)
+	log.I.Ln("[RUN] REVERSE_CERTS:", cfg.Certs)
+
 	if cfg.Conf == "" || strings.Contains(cfg.Conf, "~") {
 		cfg.Conf = strings.Replace(cfg.Conf, "~", os.Getenv("HOME"), 1)
 	}
 	if cfg.Cache == "" || strings.Contains(cfg.Cache, "~") {
 		cfg.Cache = strings.Replace(cfg.Cache, "~", os.Getenv("HOME"), 1)
 	}
+	log.I.Ln("[RUN] Expanded config path:", cfg.Conf)
+	log.I.Ln("[RUN] Expanded cache path:", cfg.Cache)
+
 	if GetEnv() {
 		PrintEnv(cfg, os.Stdout)
 		os.Exit(0)
@@ -287,12 +305,16 @@ func run(ctx context.Context) error {
 		return fmt.Errorf("failed to load favicon: %v", err)
 	}
 
+	log.I.Ln("[RUN] Calling setupServer...")
 	srv, httpHandler, err := setupServer(
 		cfg.Addr, cfg.Conf, cfg.Cache, cfg.Email, cfg.HSTS, cfg,
 	)
 	if err != nil {
+		log.E.Ln("[RUN] setupServer failed:", err)
 		return err
 	}
+	log.I.Ln("[RUN] setupServer completed successfully")
+
 	srv.ReadHeaderTimeout = 5 * time.Second
 	if cfg.RTo > 0 {
 		srv.ReadTimeout = cfg.RTo
@@ -300,18 +322,31 @@ func run(ctx context.Context) error {
 	if cfg.WTo > 0 {
 		srv.WriteTimeout = cfg.WTo
 	}
+	log.I.Ln("[RUN] Server timeouts configured - ReadHeader:", srv.ReadHeaderTimeout, "Read:", srv.ReadTimeout, "Write:", srv.WriteTimeout)
+
 	group, ctx := errgroup.WithContext(ctx)
 	if cfg.HTTP != "" {
+		log.I.Ln("[RUN] Setting up HTTP server for ACME challenges on", cfg.HTTP)
+		// Wrap httpHandler with debug logging for ACME challenges
+		debugACMEHandler := &acmeDebugHandler{handler: httpHandler}
 		httpServer := http.Server{
 			Addr:         cfg.HTTP,
-			Handler:      httpHandler,
+			Handler:      debugACMEHandler,
 			ReadTimeout:  10 * time.Second,
 			WriteTimeout: 10 * time.Second,
 		}
-		group.Go(func() error { return httpServer.ListenAndServe() })
+		group.Go(func() error {
+			log.I.Ln("[HTTP] Starting HTTP server on", cfg.HTTP, "for ACME HTTP-01 challenges")
+			err := httpServer.ListenAndServe()
+			if err != nil && err != http.ErrServerClosed {
+				log.E.Ln("[HTTP] HTTP server error:", err)
+			}
+			return err
+		})
 		group.Go(
 			func() error {
 				<-ctx.Done()
+				log.I.Ln("[HTTP] Context done, shutting down HTTP server")
 				ctx, cancel := context.WithTimeout(
 					context.Background(), time.Second,
 				)
@@ -319,28 +354,45 @@ func run(ctx context.Context) error {
 				return httpServer.Shutdown(ctx)
 			},
 		)
+	} else {
+		log.I.Ln("[RUN] WARNING: No HTTP server configured - ACME HTTP-01 challenges will NOT work!")
 	}
 	if srv.ReadTimeout != 0 || srv.WriteTimeout != 0 || cfg.Idle == 0 {
-		group.Go(func() error { return srv.ListenAndServeTLS("", "") })
+		group.Go(func() error {
+			log.I.Ln("[HTTPS] Starting HTTPS server on", srv.Addr, "with standard timeouts")
+			err := srv.ListenAndServeTLS("", "")
+			if err != nil && err != http.ErrServerClosed {
+				log.E.Ln("[HTTPS] HTTPS server error:", err)
+			}
+			return err
+		})
 	} else {
 		group.Go(
 			func() error {
+				log.I.Ln("[HTTPS] Starting HTTPS server on", srv.Addr, "with idle timeout mode")
 				ln, err := net.Listen("tcp", srv.Addr)
 				if err != nil {
+					log.E.Ln("[HTTPS] Failed to create TCP listener:", err)
 					return err
 				}
 				defer ln.Close()
+				log.I.Ln("[HTTPS] TCP listener created, wrapping with keep-alive (idle:", cfg.Idle, ")")
 				ln = tcpKeepAliveListener{
 					d:           cfg.Idle,
 					TCPListener: ln.(*net.TCPListener),
 				}
-				return srv.ServeTLS(ln, "", "")
+				err = srv.ServeTLS(ln, "", "")
+				if err != nil && err != http.ErrServerClosed {
+					log.E.Ln("[HTTPS] ServeTLS error:", err)
+				}
+				return err
 			},
 		)
 	}
 	group.Go(
 		func() error {
 			<-ctx.Done()
+			log.I.Ln("[HTTPS] Context done, shutting down HTTPS server")
 			ctx, cancel := context.WithTimeout(
 				context.Background(), time.Second,
 			)
@@ -348,101 +400,243 @@ func run(ctx context.Context) error {
 			return srv.Shutdown(ctx)
 		},
 	)
+	log.I.Ln("[RUN] All goroutines started, waiting for completion or shutdown signal")
 	return group.Wait()
 }
 
+// acmeDebugHandler wraps an http.Handler to log ACME challenge requests
+type acmeDebugHandler struct {
+	handler http.Handler
+}
+
+func (h *acmeDebugHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
+	log.I.Ln("[ACME-HTTP] Incoming HTTP request:")
+	log.I.Ln("[ACME-HTTP]   Method:", r.Method)
+	log.I.Ln("[ACME-HTTP]   Host:", r.Host)
+	log.I.Ln("[ACME-HTTP]   URL:", r.URL.String())
+	log.I.Ln("[ACME-HTTP]   Path:", r.URL.Path)
+	log.I.Ln("[ACME-HTTP]   RemoteAddr:", r.RemoteAddr)
+	log.I.Ln("[ACME-HTTP]   User-Agent:", r.UserAgent())
+
+	// Check if this is an ACME challenge request
+	if strings.HasPrefix(r.URL.Path, "/.well-known/acme-challenge/") {
+		log.I.Ln("[ACME-HTTP] *** ACME HTTP-01 CHALLENGE DETECTED ***")
+		token := strings.TrimPrefix(r.URL.Path, "/.well-known/acme-challenge/")
+		log.I.Ln("[ACME-HTTP]   Challenge token:", token)
+		log.I.Ln("[ACME-HTTP]   Full challenge URL: http://"+r.Host+r.URL.Path)
+	}
+
+	// Wrap response writer to capture status code
+	wrapper := &responseDebugWrapper{ResponseWriter: w, statusCode: 200}
+	h.handler.ServeHTTP(wrapper, r)
+
+	log.I.Ln("[ACME-HTTP] Response status:", wrapper.statusCode)
+	if strings.HasPrefix(r.URL.Path, "/.well-known/acme-challenge/") {
+		if wrapper.statusCode == 200 {
+			log.I.Ln("[ACME-HTTP] *** ACME CHALLENGE RESPONSE SUCCESS ***")
+		} else {
+			log.E.Ln("[ACME-HTTP] *** ACME CHALLENGE RESPONSE FAILED ***")
+		}
+	}
+}
+
+// responseDebugWrapper captures the HTTP status code for logging
+type responseDebugWrapper struct {
+	http.ResponseWriter
+	statusCode int
+}
+
+func (w *responseDebugWrapper) WriteHeader(code int) {
+	w.statusCode = code
+	w.ResponseWriter.WriteHeader(code)
+}
+
 // TLSConfig returns a TLSConfig that works with a LetsEncrypt automatic SSL cert issuer as well
 // as any provided .pem certificates from providers.
 //
 // The certs are provided in the form "example.com:/path/to/cert.pem"
 func TLSConfig(m *autocert.Manager, certs ...string) (tc *tls.Config) {
+	log.I.Ln("[TLS-CONFIG] Initializing TLS configuration")
+	log.I.Ln("[TLS-CONFIG] Number of pre-loaded certificates:", len(certs))
 	certMap := make(map[string]*tls.Certificate)
 	var mx sync.Mutex
 	for _, cert := range certs {
+		log.I.Ln("[TLS-CONFIG] Processing certificate spec:", cert)
 		split := strings.Split(cert, ":")
 		if len(split) != 2 {
-			log.E.F("invalid certificate parameter format: `%s`", cert)
+			log.E.F("[TLS-CONFIG] Invalid certificate parameter format: `%s`", cert)
 			continue
 		}
 		var err error
 		var c tls.Certificate
-		if c, err = tls.LoadX509KeyPair(
-			split[1]+".crt", split[1]+".key",
-		); chk.E(err) {
+		certPath := split[1] + ".crt"
+		keyPath := split[1] + ".key"
+		log.I.Ln("[TLS-CONFIG] Loading certificate for domain:", split[0])
+		log.I.Ln("[TLS-CONFIG]   Cert file:", certPath)
+		log.I.Ln("[TLS-CONFIG]   Key file:", keyPath)
+		if c, err = tls.LoadX509KeyPair(certPath, keyPath); chk.E(err) {
+			log.E.Ln("[TLS-CONFIG] Failed to load certificate:", err)
 			continue
 		}
+		log.I.Ln("[TLS-CONFIG] Successfully loaded certificate for:", split[0])
 		certMap[split[0]] = &c
 	}
+	log.I.Ln("[TLS-CONFIG] Pre-loaded certificates in map:", len(certMap))
+	for domain := range certMap {
+		log.I.Ln("[TLS-CONFIG]   - Domain:", domain)
+	}
+
 	tc = m.TLSConfig()
+	log.I.Ln("[TLS-CONFIG] Base TLS config from autocert.Manager obtained")
+
 	tc.GetCertificate = func(helo *tls.ClientHelloInfo) (
 		cert *tls.Certificate, err error,
 	) {
+		log.I.Ln("[TLS-CERT] GetCertificate called for SNI:", helo.ServerName)
+		log.I.Ln("[TLS-CERT]   Client connection from:", helo.Conn.RemoteAddr())
+		log.I.Ln("[TLS-CERT]   Supported versions:", helo.SupportedVersions)
+		log.I.Ln("[TLS-CERT]   Supported cipher suites count:", len(helo.CipherSuites))
+
 		mx.Lock()
 		var own string
 		for i := range certMap {
 			// to also handle explicit subdomain certs, prioritize over a root wildcard.
 			if helo.ServerName == i {
+				log.I.Ln("[TLS-CERT]   Exact match found in certMap:", i)
 				own = i
 				break
 			}
 			// if it got to us and ends in the same name dot tld assume the subdomain was
 			// redirected or it's a wildcard certificate, thus only the ending needs to match.
 			if strings.HasSuffix(helo.ServerName, i) {
+				log.I.Ln("[TLS-CERT]   Suffix match found in certMap:", i, "for", helo.ServerName)
 				own = i
 				break
 			}
 		}
 		if own != "" {
+			log.I.Ln("[TLS-CERT] Using pre-loaded certificate for:", own)
 			defer mx.Unlock()
 			return certMap[own], nil
 		}
 		mx.Unlock()
-		return m.GetCertificate(helo)
+
+		log.I.Ln("[TLS-CERT] No pre-loaded cert found, requesting from ACME/autocert for:", helo.ServerName)
+		log.I.Ln("[TLS-CERT] *** ACME CERTIFICATE FETCH STARTING ***")
+		startTime := time.Now()
+		cert, err = m.GetCertificate(helo)
+		elapsed := time.Since(startTime)
+		if err != nil {
+			log.E.Ln("[TLS-CERT] *** ACME CERTIFICATE FETCH FAILED ***")
+			log.E.Ln("[TLS-CERT]   Error:", err)
+			log.E.Ln("[TLS-CERT]   Elapsed time:", elapsed)
+			log.E.Ln("[TLS-CERT]   This likely means:")
+			log.E.Ln("[TLS-CERT]     1. Domain not in host policy whitelist")
+			log.E.Ln("[TLS-CERT]     2. HTTP-01 challenge failed (port 80 not accessible)")
+			log.E.Ln("[TLS-CERT]     3. Let's Encrypt rate limiting")
+			log.E.Ln("[TLS-CERT]     4. DNS not resolving to this server")
+			return nil, err
+		}
+		log.I.Ln("[TLS-CERT] *** ACME CERTIFICATE FETCH SUCCESS ***")
+		log.I.Ln("[TLS-CERT]   Domain:", helo.ServerName)
+		log.I.Ln("[TLS-CERT]   Elapsed time:", elapsed)
+		return cert, nil
 	}
+	log.I.Ln("[TLS-CONFIG] TLS configuration complete")
 	return
 }
 
 func setupServer(
 	addr, mapfile, cacheDir, email string, hsts bool, a *C,
 ) (*http.Server, http.Handler, error) {
+	log.I.Ln("[SETUP] Starting server setup")
+	log.I.Ln("[SETUP]   Listen address:", addr)
+	log.I.Ln("[SETUP]   Mapping file:", mapfile)
+	log.I.Ln("[SETUP]   Cache directory:", cacheDir)
+	log.I.Ln("[SETUP]   Email:", email)
+	log.I.Ln("[SETUP]   HSTS enabled:", hsts)
+
+	log.I.Ln("[SETUP] Reading mapping file...")
 	mapping, err := readMapping(mapfile)
 	if err != nil {
+		log.E.Ln("[SETUP] Failed to read mapping file:", err)
 		return nil, nil, err
 	}
+	log.I.Ln("[SETUP] Mapping file loaded successfully, entries:", len(mapping))
+	for host, backend := range mapping {
+		log.I.Ln("[SETUP]   Host:", host, "->", backend)
+	}
+
+	log.I.Ln("[SETUP] Setting up proxy handlers...")
 	proxy, err := setProxy(mapping)
 	if err != nil {
+		log.E.Ln("[SETUP] Failed to set up proxy:", err)
 		return nil, nil, err
 	}
+	log.I.Ln("[SETUP] Proxy handlers configured")
+
 	if hsts {
+		log.I.Ln("[SETUP] Wrapping proxy with HSTS handler")
 		proxy = &hstsProxy{proxy}
 	}
+
+	log.I.Ln("[SETUP] Creating cache directory:", cacheDir)
 	if err := os.MkdirAll(cacheDir, 0700); err != nil {
+		log.E.Ln("[SETUP] Failed to create cache directory:", err)
 		return nil, nil, fmt.Errorf(
 			"cannot create cache directory %q: %v", cacheDir, err,
 		)
 	}
+	log.I.Ln("[SETUP] Cache directory ready")
+
+	// List existing cached certificates
+	files, _ := os.ReadDir(cacheDir)
+	log.I.Ln("[SETUP] Existing items in cache directory:", len(files))
+	for _, f := range files {
+		log.I.Ln("[SETUP]   Cached item:", f.Name())
+	}
+
+	hostnames := keys(mapping)
+	log.I.Ln("[SETUP] Configuring autocert.Manager")
+	log.I.Ln("[SETUP]   HostPolicy whitelist:", hostnames)
+	log.I.Ln("[SETUP]   Email:", email)
+	log.I.Ln("[SETUP]   Cache:", cacheDir)
+
 	m := autocert.Manager{
 		Prompt:     autocert.AcceptTOS,
 		Cache:      autocert.DirCache(cacheDir),
-		HostPolicy: autocert.HostWhitelist(keys(mapping)...),
+		HostPolicy: autocert.HostWhitelist(hostnames...),
 		Email:      email,
 	}
+	log.I.Ln("[SETUP] autocert.Manager configured")
+
+	log.I.Ln("[SETUP] Creating HTTPS server")
 	srv := &http.Server{
 		Handler:   proxy,
 		Addr:      addr,
 		TLSConfig: TLSConfig(&m, a.Certs...),
 	}
-	return srv, m.HTTPHandler(nil), nil
+	log.I.Ln("[SETUP] HTTPS server created")
+
+	httpHandler := m.HTTPHandler(nil)
+	log.I.Ln("[SETUP] HTTP handler for ACME challenges created")
+	log.I.Ln("[SETUP] Server setup complete")
+
+	return srv, httpHandler, nil
 }
 
 func setProxy(mapping map[string]string) (http.Handler, error) {
+	log.I.Ln("[SET-PROXY] Setting up proxy mappings")
 	if len(mapping) == 0 {
+		log.E.Ln("[SET-PROXY] Empty mapping - no hosts to proxy")
 		return nil, fmt.Errorf("empty mapping")
 	}
 	mux := http.NewServeMux()
 	for hostname, backendAddr := range mapping {
 		hn, ba := hostname, backendAddr // intentional shadowing
+		log.I.Ln("[SET-PROXY] Processing host:", hn, "->", ba)
 		if strings.ContainsRune(hn, os.PathSeparator) {
+			log.E.Ln("[SET-PROXY] Invalid hostname (contains path separator):", hn)
 			return nil, fmt.Errorf("invalid hostname: %q", hn)
 		}
 		network := "tcp"
@@ -451,22 +645,28 @@ func setProxy(mapping map[string]string) (http.Handler, error) {
 			// calculated in a way compatible with some other
 			// implementations (i.e. uwsgi)
 			network, ba = "unix", ba+string(byte(0))
+			log.I.Ln("[SET-PROXY]   Using abstract unix socket:", ba)
 		} else if strings.HasPrefix(ba, "git+") {
+			log.I.Ln("[SET-PROXY]   Setting up Go vanity redirect")
 			GoVanity(hn, ba, mux)
 			addFaviconHandler(hn, mux)
 			continue
 		} else if filepath.IsAbs(ba) {
 			network = "unix"
+			log.I.Ln("[SET-PROXY]   Absolute path detected, checking type...")
 			switch {
 			case strings.HasSuffix(ba, string(os.PathSeparator)):
 				// path specified as directory with explicit trailing slash; add
 				// this path as static site
+				log.I.Ln("[SET-PROXY]   Setting up static file server for directory:", ba)
 				fs := http.FileServer(http.Dir(ba))
 				mux.Handle(hn+"/", fs)
 				addFaviconHandler(hn, mux)
 				continue
 			case strings.HasSuffix(ba, "nostr.json"):
+				log.I.Ln("[SET-PROXY]   Setting up NIP-05 nostr.json handler")
 				if err := NostrDNS(hn, ba, mux); err != nil {
+					log.E.Ln("[SET-PROXY]   Failed to set up NostrDNS:", err)
 					continue
 				}
 				addFaviconHandler(hn, mux)
@@ -475,16 +675,25 @@ func setProxy(mapping map[string]string) (http.Handler, error) {
 		} else if u, err := url.Parse(ba); err == nil {
 			switch u.Scheme {
 			case "http", "https":
-				rp := newSingleHostReverseProxy(u)
-				rp.ErrorLog = log2.New(io.Discard, "", 0)
+				log.I.Ln("[SET-PROXY]   Setting up HTTP(S) reverse proxy to:", u.String())
+				rp := newSingleHostReverseProxyWithDebug(u, hn)
+				rp.ErrorLog = log2.New(os.Stderr, "[PROXY-ERR-"+hn+"] ", log2.LstdFlags)
 				rp.BufferPool = bufPool{}
 				mux.Handle(hn+"/", rp)
 				addFaviconHandler(hn, mux)
 				continue
 			}
 		}
+		log.I.Ln("[SET-PROXY]   Setting up generic reverse proxy, network:", network, "backend:", ba)
+		// Capture variables for closure
+		capturedNetwork := network
+		capturedBA := ba
+		capturedHN := hn
 		rp := &httputil.ReverseProxy{
 			Director: func(req *http.Request) {
+				log.I.Ln("[PROXY-DIR]", capturedHN, "- Director called for:", req.Method, req.URL.Path)
+				log.I.Ln("[PROXY-DIR]   Original Host:", req.Host)
+				log.I.Ln("[PROXY-DIR]   Remote Addr:", req.RemoteAddr)
 				req.URL.Scheme = "http"
 				req.URL.Host = req.Host
 				// Backward-compatible header widely used by apps
@@ -494,41 +703,85 @@ func setProxy(mapping map[string]string) (http.Handler, error) {
 				req.Header.Set("X-Forwarded-For", split[0])
 				// Standard RFC 7239 Forwarded header
 				appendForwardedHeader(req)
+				log.I.Ln("[PROXY-DIR]   Forwarding to:", capturedNetwork, capturedBA)
 			},
 			Transport: &http.Transport{
 				Dial: func(netw, addr string) (net.Conn, error) {
-					return net.DialTimeout(network, ba, 5*time.Second)
+					log.I.Ln("[PROXY-DIAL]", capturedHN, "- Dialing backend:", capturedNetwork, capturedBA)
+					startTime := time.Now()
+					conn, err := net.DialTimeout(capturedNetwork, capturedBA, 5*time.Second)
+					elapsed := time.Since(startTime)
+					if err != nil {
+						log.E.Ln("[PROXY-DIAL]", capturedHN, "- Connection FAILED after", elapsed)
+						log.E.Ln("[PROXY-DIAL]   Error:", err)
+						log.E.Ln("[PROXY-DIAL]   Check if backend is running and accessible")
+						return nil, err
+					}
+					log.I.Ln("[PROXY-DIAL]", capturedHN, "- Connected to backend in", elapsed)
+					return conn, nil
 				},
 			},
-			ErrorLog:   log2.New(os.Stderr, "reverse", 0),
+			ErrorLog:   log2.New(os.Stderr, "[PROXY-ERR-"+hn+"] ", log2.LstdFlags),
 			BufferPool: bufPool{},
+			ModifyResponse: func(resp *http.Response) error {
+				log.I.Ln("[PROXY-RESP]", capturedHN, "- Response:", resp.StatusCode, resp.Status)
+				log.I.Ln("[PROXY-RESP]   Content-Type:", resp.Header.Get("Content-Type"))
+				log.I.Ln("[PROXY-RESP]   Content-Length:", resp.ContentLength)
+				return nil
+			},
+			ErrorHandler: func(w http.ResponseWriter, r *http.Request, err error) {
+				log.E.Ln("[PROXY-ERROR]", capturedHN, "- Error handling request:", r.Method, r.URL.Path)
+				log.E.Ln("[PROXY-ERROR]   Error:", err)
+				log.E.Ln("[PROXY-ERROR]   This may indicate:")
+				log.E.Ln("[PROXY-ERROR]     1. Backend server is not running")
+				log.E.Ln("[PROXY-ERROR]     2. Backend server crashed")
+				log.E.Ln("[PROXY-ERROR]     3. Network issue connecting to backend")
+				log.E.Ln("[PROXY-ERROR]     4. Backend timeout")
+				w.WriteHeader(http.StatusBadGateway)
+				w.Write([]byte("502 Bad Gateway - Backend connection failed"))
+			},
 		}
 		mux.Handle(hn+"/", rp)
 		// Add favicon handler for this hostname
 		addFaviconHandler(hn, mux)
 	}
+	log.I.Ln("[SET-PROXY] All proxy mappings configured")
 	return mux, nil
 }
 
 func readMapping(file string) (map[string]string, error) {
+	log.I.Ln("[READ-MAPPING] Opening mapping file:", file)
 	f, err := os.Open(file)
 	if err != nil {
+		log.E.Ln("[READ-MAPPING] Failed to open file:", err)
 		return nil, err
 	}
 	defer f.Close()
 	m := make(map[string]string)
 	sc := bufio.NewScanner(f)
+	lineNum := 0
 	for sc.Scan() {
+		lineNum++
 		if b := sc.Bytes(); len(b) == 0 || b[0] == '#' {
+			log.I.Ln("[READ-MAPPING] Line", lineNum, ": (skipped - empty or comment)")
 			continue
 		}
 		s := strings.SplitN(sc.Text(), ":", 2)
 		if len(s) != 2 {
+			log.E.Ln("[READ-MAPPING] Line", lineNum, ": Invalid format:", sc.Text())
 			return nil, fmt.Errorf("invalid line: %q", sc.Text())
 		}
-		m[strings.TrimSpace(s[0])] = strings.TrimSpace(s[1])
+		host := strings.TrimSpace(s[0])
+		backend := strings.TrimSpace(s[1])
+		log.I.Ln("[READ-MAPPING] Line", lineNum, ":", host, "->", backend)
+		m[host] = backend
 	}
-	return m, sc.Err()
+	if err := sc.Err(); err != nil {
+		log.E.Ln("[READ-MAPPING] Scanner error:", err)
+		return nil, err
+	}
+	log.I.Ln("[READ-MAPPING] Mapping file parsed successfully, total entries:", len(m))
+	return m, nil
 }
 
 func keys(m map[string]string) []string {
@@ -544,6 +797,18 @@ type hstsProxy struct {
 }
 
 func (p *hstsProxy) ServeHTTP(w http.ResponseWriter, r *http.Request) {
+	log.I.Ln("[HSTS-PROXY] Incoming HTTPS request:")
+	log.I.Ln("[HSTS-PROXY]   Method:", r.Method)
+	log.I.Ln("[HSTS-PROXY]   Host:", r.Host)
+	log.I.Ln("[HSTS-PROXY]   URL:", r.URL.String())
+	log.I.Ln("[HSTS-PROXY]   Path:", r.URL.Path)
+	log.I.Ln("[HSTS-PROXY]   RemoteAddr:", r.RemoteAddr)
+	log.I.Ln("[HSTS-PROXY]   TLS:", r.TLS != nil)
+	if r.TLS != nil {
+		log.I.Ln("[HSTS-PROXY]   TLS ServerName (SNI):", r.TLS.ServerName)
+		log.I.Ln("[HSTS-PROXY]   TLS Version:", r.TLS.Version)
+	}
+	log.I.Ln("[HSTS-PROXY] Setting HSTS header and forwarding to handler")
 	w.Header().Set(
 		"Strict-Transport-Security",
 		"max-age=31536000; includeSubDomains; preload",
@@ -662,6 +927,58 @@ func newSingleHostReverseProxy(target *url.URL) *httputil.ReverseProxy {
 	return &httputil.ReverseProxy{Director: director}
 }
 
+// newSingleHostReverseProxyWithDebug is like newSingleHostReverseProxy but with debug logging
+func newSingleHostReverseProxyWithDebug(target *url.URL, hostname string) *httputil.ReverseProxy {
+	targetQuery := target.RawQuery
+	director := func(req *http.Request) {
+		log.I.Ln("[PROXY-SINGLE]", hostname, "- Director called")
+		log.I.Ln("[PROXY-SINGLE]   Method:", req.Method)
+		log.I.Ln("[PROXY-SINGLE]   Original URL:", req.URL.String())
+		log.I.Ln("[PROXY-SINGLE]   Host:", req.Host)
+		log.I.Ln("[PROXY-SINGLE]   RemoteAddr:", req.RemoteAddr)
+
+		req.URL.Scheme = target.Scheme
+		req.URL.Host = target.Host
+		req.URL.Path = singleJoiningSlash(target.Path, req.URL.Path)
+		if targetQuery == "" || req.URL.RawQuery == "" {
+			req.URL.RawQuery = targetQuery + req.URL.RawQuery
+		} else {
+			req.URL.RawQuery = targetQuery + "&" + req.URL.RawQuery
+		}
+		if _, ok := req.Header["User-Agent"]; !ok {
+			req.Header.Set("User-Agent", "")
+		}
+		// Backward-compatible header widely used by apps
+		req.Header.Set("X-Forwarded-Proto", "https")
+		clientIP := remoteIP(req.RemoteAddr)
+		split := strings.Split(clientIP, ",")
+		req.Header.Set("X-Forwarded-For", split[0])
+		// Standard RFC 7239 Forwarded header
+		appendForwardedHeader(req)
+
+		log.I.Ln("[PROXY-SINGLE]   Forwarding to:", req.URL.String())
+	}
+
+	return &httputil.ReverseProxy{
+		Director: director,
+		ModifyResponse: func(resp *http.Response) error {
+			log.I.Ln("[PROXY-SINGLE]", hostname, "- Response received")
+			log.I.Ln("[PROXY-SINGLE]   Status:", resp.StatusCode, resp.Status)
+			log.I.Ln("[PROXY-SINGLE]   Content-Type:", resp.Header.Get("Content-Type"))
+			log.I.Ln("[PROXY-SINGLE]   Content-Length:", resp.ContentLength)
+			return nil
+		},
+		ErrorHandler: func(w http.ResponseWriter, r *http.Request, err error) {
+			log.E.Ln("[PROXY-SINGLE]", hostname, "- ERROR handling request")
+			log.E.Ln("[PROXY-SINGLE]   Request:", r.Method, r.URL.Path)
+			log.E.Ln("[PROXY-SINGLE]   Error:", err)
+			log.E.Ln("[PROXY-SINGLE]   Target was:", target.String())
+			w.WriteHeader(http.StatusBadGateway)
+			w.Write([]byte("502 Bad Gateway - Backend connection failed"))
+		},
+	}
+}
+
 func singleJoiningSlash(a, b string) string {
 	aslash := strings.HasSuffix(a, "/")
 	bslash := strings.HasPrefix(b, "/")