Getting Logging Going Correctly?

1. The problem I’m having:

I am trying to use logging in ServeHTTP (and sub functions from there).

2. Error messages and/or full log output:

I get log information up to the ServeHTTP, but not inside it. I suspect this is because my global variable is not set when accessing ServeHTTP.

2024/05/05 14:40:45 [INFO] Build environment ready
2024/05/05 14:40:45 [INFO] Building Caddy
2024/05/05 14:40:45 [INFO] exec (timeout=0s): /Users/daaronch/.asdf/shims/go mod tidy -e
2024/05/05 14:40:46 [INFO] exec (timeout=0s): /Users/daaronch/.asdf/shims/go build -o /Users/daaronch/code/spartacus/caddy -tags nobadger
2024/05/05 14:40:49 [INFO] Build complete: ./caddy
2024/05/05 14:40:49 [INFO] Cleaning up temporary folder: /Users/daaronch/code/spartacus/buildenv_2024-05-05-1440.3841892330
2024/05/05 14:40:49 [INFO] Running [./caddy run --config caddy.json]

2024/05/05 21:40:50.298	INFO	using provided configuration	{"config_file": "caddy.json", "config_adapter": ""}
2024/05/05 21:40:50.300	INFO	admin	admin endpoint started	{"address": "localhost:2019", "enforce_origin": false, "origins": ["//localhost:2019", "//[::1]:2019", "//127.0.0.1:2019"]}
2024/05/05 21:40:50.300	INFO	http.auto_https	server is listening only on the HTTPS port but has no TLS connection policies; adding one to enable TLS	{"server_name": "spartacus_server", "https_port": 443}
2024/05/05 21:40:50.300	INFO	http.auto_https	enabling automatic HTTP->HTTPS redirects	{"server_name": "spartacus_server"}
2024/05/05 21:40:50.300	INFO	tls.cache.maintenance	started background certificate maintenance	{"cache": "0x14000406e00"}
2024/05/05 21:40:50.301	DEBUG	http.auto_https	adjusted config	{"tls": {"automation":{"policies":[{"subjects":["localhost","127.0.0.1"]},{}]}}, "http": {"servers":{"remaining_auto_https_redirects":{"listen":[":80"],"routes":[{},{}],"logs":{"default_logger_name":"spartacusStdOutLogs"}},"spartacus_server":{"listen":[":443"],"routes":[{"handle":[{"development":true,"handler":"spartacus","posthog":{"endpoint":"https://1e747868-3524-4d27-ad60-2e73e05bb428.mock.pstmn.io"}}]},{}],"tls_connection_policies":[{}],"automatic_https":{},"logs":{"default_logger_name":"spartacusStdOutLogs"}}}}}
2024/05/05 21:40:50.302	INFO	http.handlers.spartacus	Provisioning Spartacus
2024/05/05 21:40:50.302	INFO	http.handlers.spartacus	{https://1e747868-3524-4d27-ad60-2e73e05bb428.mock.pstmn.io  }+
2024/05/05 21:40:50.302	INFO	http.handlers.spartacus	Koala config is empty
2024/05/05 21:40:50.302	INFO	http.handlers.spartacus	Development mode is enabled
2024/05/05 21:40:50.306	INFO	pki.ca.local	root certificate is already trusted by system	{"path": "storage:pki/authorities/local/root.crt"}
2024/05/05 21:40:50.306	INFO	http	enabling HTTP/3 listener	{"addr": ":443"}
2024/05/05 21:40:50.306	DEBUG	http	starting server loop	{"address": "[::]:443", "tls": true, "http3": true}
2024/05/05 21:40:50.306	INFO	http.log	server running	{"name": "spartacus_server", "protocols": ["h1", "h2", "h3"]}
2024/05/05 21:40:50.306	DEBUG	http	starting server loop	{"address": "[::]:80", "tls": false, "http3": false}
2024/05/05 21:40:50.306	INFO	http.log	server running	{"name": "remaining_auto_https_redirects", "protocols": ["h1", "h2", "h3"]}
2024/05/05 21:40:50.306	INFO	http	enabling automatic TLS certificate management	{"domains": ["localhost", "127.0.0.1"]}
2024/05/05 21:40:50.307	WARN	tls	stapling OCSP	{"error": "no OCSP stapling for [localhost]: no OCSP server specified in certificate", "identifiers": ["localhost"]}
2024/05/05 21:40:50.307	DEBUG	tls.cache	added certificate to cache	{"subjects": ["localhost"], "expiration": "2024/05/06 04:43:17.000", "managed": true, "issuer_key": "local", "hash": "4608113bab298e085a4435f98997e45fb4deb4e1fa93637041ad6021e962d5ee", "cache_size": 1, "cache_capacity": 10000}
2024/05/05 21:40:50.307	DEBUG	events	event	{"name": "cached_managed_cert", "id": "1671e066-3bab-4c05-ba63-9b60eb1c7095", "origin": "tls", "data": {"sans":["localhost"]}}
2024/05/05 21:40:50.308	WARN	tls	stapling OCSP	{"error": "no OCSP stapling for [127.0.0.1]: no OCSP server specified in certificate", "identifiers": ["127.0.0.1"]}
2024/05/05 21:40:50.308	DEBUG	tls.cache	added certificate to cache	{"subjects": ["127.0.0.1"], "expiration": "2024/05/06 04:43:17.000", "managed": true, "issuer_key": "local", "hash": "a9566f153dceaa61f0c5608ced32362afc823a22658486b0df2c13f9967d787d", "cache_size": 2, "cache_capacity": 10000}
2024/05/05 21:40:50.308	DEBUG	events	event	{"name": "cached_managed_cert", "id": "89bceb45-f7af-40a6-a1a6-417ef03ea593", "origin": "tls", "data": {"sans":["127.0.0.1"]}}
2024/05/05 21:40:50.308	INFO	autosaved config (load with --resume flag)	{"file": "/Users/daaronch/Library/Application Support/Caddy/autosave.json"}
2024/05/05 21:40:50.308	INFO	serving initial configuration
2024/05/05 21:40:50.317	WARN	tls	storage cleaning happened too recently; skipping for now	{"storage": "FileStorage:/Users/daaronch/Library/Application Support/Caddy", "instance": "9cfc62d9-28c4-469a-bdd5-97fb30adf0e9", "try_again": "2024/05/06 21:40:50.317", "try_again_in": 86399.999999875}
2024/05/05 21:40:50.317	INFO	tls	finished cleaning storage units
2024/05/05 21:40:57.264	INFO	http.log.access.spartacusStdOutLogs	handled request	{"request": {"remote_ip": "127.0.0.1", "remote_port": "61821", "client_ip": "127.0.0.1", "proto": "HTTP/1.1", "method": "POST", "host": "127.0.0.1", "uri": "/", "headers": {"Content-Type": ["application/x-www-form-urlencoded"], "User-Agent": ["curl/8.4.0"], "Accept": ["*/*"], "Content-Length": ["2"]}}, "bytes_read": 0, "user_id": "", "duration": 0.00013025, "size": 0, "status": 308, "resp_headers": {"Server": ["Caddy"], "Connection": ["close"], "Location": ["https://127.0.0.1/"], "Content-Type": []}}

The above should have printed out many more log lines:

var caddyLog *zap.Logger

// ServeHTTP implements caddyhttp.MiddlewareHandler.
func (s Spartacus) ServeHTTP(w http.ResponseWriter, r *http.Request, next caddyhttp.Handler) error {
	caddyLog.Info("Received event")
	caddyLog.Info("Received event")
	caddyLog.Info("Received event")
	caddyLog.Info("Received event")
	caddyLog.Info("Received event")
	caddyLog.Info("Received event")
	caddyLog.Info("Received event")

	// Read the request body
	body := make([]byte, r.ContentLength)
	_, err := r.Body.Read(body)
	if err != nil {
		// caddyLog.Errorf("Failed to read request body: %s", err.Error())
		return err
	}
[...]

3. Caddy version:

❯ xcaddy version
v0.4.0 h1:V4n6nNlkRPmrgE+npteBjS7hgMfw24UEmiIONDpIWSo=

4. How I installed and ran Caddy:

xcaddy run --config caddy.json

a. System environment:

Latest MacOS - 14.4.1 (23E224)

b. Command:

N/A

c. Service/unit/compose file:

N/A

d. My complete Caddy config:

{
    "logging": {
        "logs": {
            "default": {
                "level": "DEBUG"
            }
        }
    },
    "apps": {
        "http": {
            "servers": {
                "spartacus_server": {
                    "listen": [
                        ":443"
                    ],
                    "routes": [
                        {
                            "handle": [
                                {
                                    "handler": "spartacus",
                                    "posthog": {
                                        "endpoint": "https://1e747868-3524-4d27-ad60-2e73e05bb428.mock.pstmn.io"
                                    },
                                    "development": true
                                }
                            ]
                        },
                        {
                            "match": [
                                {
                                    "host": [
                                        "localhost",
                                        "127.0.0.1"
                                    ]
                                }
                            ]
                        }
                    ],
                    "logs": {
                        "default_logger_name": "spartacusStdOutLogs"
                    }
                }
            }
        }
    }
}

5. Links to relevant resources:

Where is this variable? Did you make a global variable? Don’t do that.

You should grab a reference to the logger inside Provision() (with ctx.Logger()) and store it inside your module’s struct (i.e. a field like logger *zap.Logger). Then you do s.logger.Info() or whatever. That’s covered here in the docs Extending Caddy — Caddy Documentation

1 Like

Thanks!

It is a global variable, but that’s what I was confused about, because inside of ServeHTTP, it doesn’t have ctx available, so I’m not sure what to use.

Here’s the entire file - I tried to attach it to the instance, but it doesn’t seem to work:

package spartacus_module

import (
	"fmt"
	"net/http"

	"github.com/bacalhau-project/spartacus/targets"
	sanitize "github.com/bacalhau-project/spartacus/utils"
	"github.com/caddyserver/caddy/v2"
	"github.com/caddyserver/caddy/v2/caddyconfig/caddyfile"
	"github.com/caddyserver/caddy/v2/caddyconfig/httpcaddyfile"
	"github.com/caddyserver/caddy/v2/modules/caddyhttp"
	"go.uber.org/zap"
	"go.uber.org/zap/zapcore"
)

func init() {
	caddy.RegisterModule(Spartacus{})
	httpcaddyfile.RegisterHandlerDirective("spartacus", parseCaddyfile)
}

type Spartacus struct {
	PostHog      PostHogConfig        `json:"posthog,omitempty"`
	Koala        KoalaConfig          `json:"koala,omitempty"`
	PushServices targets.PushServices `json:"push_services,omitempty"`
	Development  bool                 `json:"development,omitempty"`
	LogLevel     string               `json:"log_level,omitempty"`
	Logger       *zap.Logger          `json:"logger,omitempty"`
}

type PostHogConfig struct {
	Endpoint    string `json:"endpoint,omitempty"`
	ProjectKey  string `json:"project_key,omitempty"`
	PersonalKey string `json:"personal_key,omitempty"`
}

type KoalaConfig struct {
	Endpoint string `json:"endpoint,omitempty"`
	Key      string `json:"key,omitempty"`
}

func (Spartacus) CaddyModule() caddy.ModuleInfo {
	return caddy.ModuleInfo{
		ID:  "http.handlers.spartacus",
		New: func() caddy.Module { return new(Spartacus) },
	}
}

func (s *Spartacus) Provision(ctx caddy.Context) error {
	s.Logger = ctx.Logger()
	s.Logger.Info("Provisioning Spartacus")
	return nil
}

func (s *Spartacus) Validate() error {
	if s.PostHog == (PostHogConfig{}) {
		s.Logger.Info("PostHog config is empty")
	} else {
		s.Logger.Info(fmt.Sprintf("%v+", s.PostHog))
	}
	if s.Koala == (KoalaConfig{}) {
		s.Logger.Info("Koala config is empty")
	}

	if s.Development == true {
		s.Logger.Info("Development mode is enabled")
		s.PushServices = &targets.MockPushServices{}
	} else {
		s.Logger.Info("Development mode is disabled")
		s.PushServices = &targets.LivePushServices{}
	}

	return nil
}

// ServeHTTP implements caddyhttp.MiddlewareHandler.
func (s Spartacus) ServeHTTP(w http.ResponseWriter, r *http.Request, next caddyhttp.Handler) error {
	s.Logger.Info("Received event")
	s.Logger.Info("Received event")
	s.Logger.Info("Received event")
	s.Logger.Info("Received event")
	s.Logger.Info("Received event")
	s.Logger.Info("Received event")
	s.Logger.Info("Received event")

	// Read the request body
	body := make([]byte, r.ContentLength)
	_, err := r.Body.Read(body)
	if err != nil {
		// caddyLog.Errorf("Failed to read request body: %s", err.Error())
		return err
	}

	// caddyLog.Info("Received event: %s", zapcore.Field{String: string(body)})

	// Sanitize the event into a map
	eventMap, err := sanitize.SanitizeBodyIntoMap(string(body))
	if err != nil {
		w.WriteHeader(http.StatusBadRequest)
		w.Write([]byte("{\"error\": \"Invalid event data\"}"))
		// caddyLog.Error("Failed to verify event. Contents: %v", zapcore.Field{String: err.Error()})
		return err
	}

	// caddyLog.Debug("Sanitized event: %s", zapcore.Field{Interface: eventMap})

	// Construct the map into an Event struct
	event, err := targets.CreateEventDataForPushing(eventMap)
	if err != nil {
		// caddyLog.Error("Failed to create event data: %s", zapcore.Field{String: err.Error()})
		return err
	}

	// caddyLog.Debug("Created event: %s", zapcore.Field{Interface: event})

	// Push the event to the configured services
	pushErrors := s.PushServices.PushData(event)
	for _, err := range pushErrors {
		s.Logger.Error("Failed to push event to service: %s", zapcore.Field{String: err.Error()})
	}

	s.Logger.Debug("Pushed event to services")

	w.Header().Set("Content-Type", "text/plain")
	w.WriteHeader(http.StatusOK)
	w.Write([]byte("OK"))
	return next.ServeHTTP(w, r)
}

// UnmarshalCaddyfile implements caddyfile.Unmarshaler.
func (s *Spartacus) UnmarshalCaddyfile(d *caddyfile.Dispenser) error {
	d.Next() // consume directive name

	// require an argument
	if !d.NextArg() {
		return d.ArgErr()
	}

	// store the argument
	// s.PostHogEndpoint = d.Val()
	return nil
}

// parseCaddyfile unmarshals tokens from h into a new Middleware.
func parseCaddyfile(h httpcaddyfile.Helper) (caddyhttp.MiddlewareHandler, error) {
	var s Spartacus
	err := s.UnmarshalCaddyfile(h.Dispenser)
	return s, err
}

// Interface guards
var (
	_ caddy.Provisioner           = (*Spartacus)(nil)
	_ caddy.Validator             = (*Spartacus)(nil)
	_ caddyhttp.MiddlewareHandler = (*Spartacus)(nil)
	_ caddyfile.Unmarshaler       = (*Spartacus)(nil)
)

and here’s the log:


2024/05/06 00:45:05.051	INFO	using provided configuration	{"config_file": "caddy.json", "config_adapter": ""}
2024/05/06 00:45:05.053	INFO	admin	admin endpoint started	{"address": "localhost:2019", "enforce_origin": false, "origins": ["//localhost:2019", "//[::1]:2019", "//127.0.0.1:2019"]}
2024/05/06 00:45:05.053	INFO	http.auto_https	server is listening only on the HTTPS port but has no TLS connection policies; adding one to enable TLS	{"server_name": "spartacus_server", "https_port": 443}
2024/05/06 00:45:05.053	INFO	http.auto_https	enabling automatic HTTP->HTTPS redirects	{"server_name": "spartacus_server"}
2024/05/06 00:45:05.053	INFO	tls.cache.maintenance	started background certificate maintenance	{"cache": "0x140000f9000"}
2024/05/06 00:45:05.054	DEBUG	http.auto_https	adjusted config	{"tls": {"automation":{"policies":[{"subjects":["localhost","127.0.0.1"]},{}]}}, "http": {"servers":{"remaining_auto_https_redirects":{"listen":[":80"],"routes":[{},{}],"logs":{"default_logger_name":"spartacusStdOutLogs"}},"spartacus_server":{"listen":[":443"],"routes":[{"handle":[{"development":true,"handler":"spartacus","posthog":{"endpoint":"https://1e747868-3524-4d27-ad60-2e73e05bb428.mock.pstmn.io"}}]},{}],"tls_connection_policies":[{}],"automatic_https":{},"logs":{"default_logger_name":"spartacusStdOutLogs"}}}}}
2024/05/06 00:45:05.054	INFO	http.handlers.spartacus	Provisioning Spartacus
2024/05/06 00:45:05.054	INFO	http.handlers.spartacus	{https://1e747868-3524-4d27-ad60-2e73e05bb428.mock.pstmn.io  }+
2024/05/06 00:45:05.054	INFO	http.handlers.spartacus	Koala config is empty
2024/05/06 00:45:05.054	INFO	http.handlers.spartacus	Development mode is enabled
2024/05/06 00:45:05.058	INFO	pki.ca.local	root certificate is already trusted by system	{"path": "storage:pki/authorities/local/root.crt"}
2024/05/06 00:45:05.058	INFO	http	enabling HTTP/3 listener	{"addr": ":443"}
2024/05/06 00:45:05.058	DEBUG	http	starting server loop	{"address": "[::]:443", "tls": true, "http3": true}
2024/05/06 00:45:05.058	INFO	http.log	server running	{"name": "spartacus_server", "protocols": ["h1", "h2", "h3"]}
2024/05/06 00:45:05.058	DEBUG	http	starting server loop	{"address": "[::]:80", "tls": false, "http3": false}
2024/05/06 00:45:05.058	INFO	http.log	server running	{"name": "remaining_auto_https_redirects", "protocols": ["h1", "h2", "h3"]}
2024/05/06 00:45:05.058	INFO	http	enabling automatic TLS certificate management	{"domains": ["localhost", "127.0.0.1"]}
2024/05/06 00:45:05.060	WARN	tls	storage cleaning happened too recently; skipping for now	{"storage": "FileStorage:/Users/daaronch/Library/Application Support/Caddy", "instance": "9cfc62d9-28c4-469a-bdd5-97fb30adf0e9", "try_again": "2024/05/07 00:45:05.060", "try_again_in": 86399.999999791}
2024/05/06 00:45:05.060	INFO	tls	finished cleaning storage units
2024/05/06 00:45:05.060	WARN	tls	stapling OCSP	{"error": "no OCSP stapling for [localhost]: no OCSP server specified in certificate", "identifiers": ["localhost"]}
2024/05/06 00:45:05.060	DEBUG	tls.cache	added certificate to cache	{"subjects": ["localhost"], "expiration": "2024/05/06 04:43:17.000", "managed": true, "issuer_key": "local", "hash": "4608113bab298e085a4435f98997e45fb4deb4e1fa93637041ad6021e962d5ee", "cache_size": 1, "cache_capacity": 10000}
2024/05/06 00:45:05.060	DEBUG	events	event	{"name": "cached_managed_cert", "id": "3802c315-301a-4de1-b3d7-ef68031007af", "origin": "tls", "data": {"sans":["localhost"]}}
2024/05/06 00:45:05.061	WARN	tls	stapling OCSP	{"error": "no OCSP stapling for [127.0.0.1]: no OCSP server specified in certificate", "identifiers": ["127.0.0.1"]}
2024/05/06 00:45:05.061	DEBUG	tls.cache	added certificate to cache	{"subjects": ["127.0.0.1"], "expiration": "2024/05/06 04:43:17.000", "managed": true, "issuer_key": "local", "hash": "a9566f153dceaa61f0c5608ced32362afc823a22658486b0df2c13f9967d787d", "cache_size": 2, "cache_capacity": 10000}
2024/05/06 00:45:05.061	DEBUG	events	event	{"name": "cached_managed_cert", "id": "54f25cac-5aeb-4457-9e1d-71035852c095", "origin": "tls", "data": {"sans":["127.0.0.1"]}}
2024/05/06 00:45:05.062	INFO	autosaved config (load with --resume flag)	{"file": "/Users/daaronch/Library/Application Support/Caddy/autosave.json"}
2024/05/06 00:45:05.062	INFO	serving initial configuration
2024/05/06 00:45:05.062	INFO	tls.renew	acquiring lock	{"identifier": "localhost"}
2024/05/06 00:45:05.062	INFO	tls.renew	acquiring lock	{"identifier": "127.0.0.1"}
2024/05/06 00:45:05.067	INFO	tls.renew	lock acquired	{"identifier": "localhost"}
2024/05/06 00:45:05.067	INFO	tls.renew	renewing certificate	{"identifier": "localhost", "remaining": 14291.932632}
2024/05/06 00:45:05.067	DEBUG	events	event	{"name": "cert_obtaining", "id": "dde9a381-7473-4c2d-a077-b2f2823830da", "origin": "tls", "data": {"forced":false,"identifier":"localhost","issuer":"local","remaining":14291932632000,"renewal":true}}
2024/05/06 00:45:05.067	DEBUG	pki.ca.local	using intermediate signer	{"serial": "329386816213200608632985564364295353649", "not_before": "2024-05-01 18:59:48 +0000 UTC", "not_after": "2024-05-08 18:59:48 +0000 UTC"}
2024/05/06 00:45:05.071	INFO	tls.renew	lock acquired	{"identifier": "127.0.0.1"}
2024/05/06 00:45:05.071	INFO	tls.renew	renewing certificate	{"identifier": "127.0.0.1", "remaining": 14291.92849}
2024/05/06 00:45:05.071	DEBUG	events	event	{"name": "cert_obtaining", "id": "827708bf-db98-496e-bcad-5113c7211714", "origin": "tls", "data": {"forced":false,"identifier":"127.0.0.1","issuer":"local","remaining":14291928490000,"renewal":true}}
2024/05/06 00:45:05.071	DEBUG	pki.ca.local	using intermediate signer	{"serial": "329386816213200608632985564364295353649", "not_before": "2024-05-01 18:59:48 +0000 UTC", "not_after": "2024-05-08 18:59:48 +0000 UTC"}
2024/05/06 00:45:05.072	INFO	tls.renew	certificate renewed successfully	{"identifier": "127.0.0.1"}
2024/05/06 00:45:05.072	DEBUG	events	event	{"name": "cert_obtained", "id": "4826d804-9386-4574-ab34-d5e6306fca44", "origin": "tls", "data": {"certificate_path":"certificates/local/127.0.0.1/127.0.0.1.crt","identifier":"127.0.0.1","issuer":"local","metadata_path":"certificates/local/127.0.0.1/127.0.0.1.json","private_key_path":"certificates/local/127.0.0.1/127.0.0.1.key","remaining":14291928490000,"renewal":true,"storage_path":"certificates/local/127.0.0.1"}}
2024/05/06 00:45:05.072	INFO	tls.renew	releasing lock	{"identifier": "127.0.0.1"}
2024/05/06 00:45:05.072	INFO	tls	reloading managed certificate	{"identifiers": ["127.0.0.1"]}
2024/05/06 00:45:05.072	INFO	tls.renew	certificate renewed successfully	{"identifier": "localhost"}
2024/05/06 00:45:05.072	DEBUG	events	event	{"name": "cert_obtained", "id": "9fdbd903-dbe4-4638-b7d4-ed69013bf290", "origin": "tls", "data": {"certificate_path":"certificates/local/localhost/localhost.crt","identifier":"localhost","issuer":"local","metadata_path":"certificates/local/localhost/localhost.json","private_key_path":"certificates/local/localhost/localhost.key","remaining":14291932632000,"renewal":true,"storage_path":"certificates/local/localhost"}}
2024/05/06 00:45:05.074	INFO	tls.renew	releasing lock	{"identifier": "localhost"}
2024/05/06 00:45:05.072	WARN	tls	stapling OCSP	{"error": "no OCSP stapling for [127.0.0.1]: no OCSP server specified in certificate", "identifiers": ["127.0.0.1"]}
2024/05/06 00:45:05.074	DEBUG	tls.cache	removed certificate from cache	{"subjects": ["127.0.0.1"], "expiration": "2024/05/06 04:43:17.000", "managed": true, "issuer_key": "local", "hash": "a9566f153dceaa61f0c5608ced32362afc823a22658486b0df2c13f9967d787d", "cache_size": 1, "cache_capacity": 10000}
2024/05/06 00:45:05.074	DEBUG	tls.cache	added certificate to cache	{"subjects": ["127.0.0.1"], "expiration": "2024/05/06 12:45:06.000", "managed": true, "issuer_key": "local", "hash": "0a0a432685df9acab4ed91ba38a2e910f12051b966f5620957aa8e4b95eca845", "cache_size": 2, "cache_capacity": 10000}
2024/05/06 00:45:05.074	INFO	tls.cache	replaced certificate in cache	{"subjects": ["127.0.0.1"], "new_expiration": "2024/05/06 12:45:06.000"}
2024/05/06 00:45:05.074	INFO	tls	reloading managed certificate	{"identifiers": ["localhost"]}
2024/05/06 00:45:05.075	WARN	tls	stapling OCSP	{"error": "no OCSP stapling for [localhost]: no OCSP server specified in certificate", "identifiers": ["localhost"]}
2024/05/06 00:45:05.075	DEBUG	tls.cache	removed certificate from cache	{"subjects": ["localhost"], "expiration": "2024/05/06 04:43:17.000", "managed": true, "issuer_key": "local", "hash": "4608113bab298e085a4435f98997e45fb4deb4e1fa93637041ad6021e962d5ee", "cache_size": 1, "cache_capacity": 10000}
2024/05/06 00:45:05.075	DEBUG	tls.cache	added certificate to cache	{"subjects": ["localhost"], "expiration": "2024/05/06 12:45:06.000", "managed": true, "issuer_key": "local", "hash": "e1e4517d829f28560d34d5e73bb553138503ccdcb5e3d1cf8b8a0b2dabbc57e3", "cache_size": 2, "cache_capacity": 10000}
2024/05/06 00:45:05.075	INFO	tls.cache	replaced certificate in cache	{"subjects": ["localhost"], "new_expiration": "2024/05/06 12:45:06.000"}
2024/05/06 00:45:17.913	INFO	http.log.access.spartacusStdOutLogs	handled request	{"request": {"remote_ip": "127.0.0.1", "remote_port": "65484", "client_ip": "127.0.0.1", "proto": "HTTP/1.1", "method": "POST", "host": "127.0.0.1", "uri": "/", "headers": {"User-Agent": ["curl/8.4.0"], "Accept": ["*/*"], "Content-Length": ["2"], "Content-Type": ["application/x-www-form-urlencoded"]}}, "bytes_read": 0, "user_id": "", "duration": 0.000101458, "size": 0, "status": 308, "resp_headers": {"Server": ["Caddy"], "Connection": ["close"], "Location": ["https://127.0.0.1/"], "Content-Type": []}}

This isn’t a configurable field, so remove the json tags and make it lowercase logger since it doesn’t need to be exported.

Your server served an HTTP → HTTPS redirect, that’s all. Your handlers won’t run unless you make an HTTPS request, or follow the redirect.

1 Like

UGH. Thank you very much. I should have caught that.

Thank you!