Skip to content

feat: rework logging #45

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
mxab merged 6 commits into from
Aug 31, 2025
Merged

feat: rework logging #45

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
6 commits
Select commit Hold shift + click to select a range
c39e522
feat: rework logging
mxab Aug 30, 2025
26b82b3
chore: remove unused code
mxab Aug 31, 2025
63291ad
fixup! chore: remove unused code
mxab Aug 31, 2025
a0bce30
chore: ensure defaults test, remove unreached code
mxab Aug 31, 2025
a5e22eb
chore: go mod tidy
mxab Aug 31, 2025
87ea02a
fix: loggerfactory text logs
mxab Aug 31, 2025
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
14 changes: 10 additions & 4 deletions README.md
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -299,7 +299,9 @@ The OpenTelemetry exporter can be configured using the following settings in the
```hcl
telemetry {
logging {
type = "otel" # Use OpenTelemetry
otel {
enabled = true # Enable OpenTelemetry logging
}
}
metrics {
enabled = true # Enable metrics collection
Expand All @@ -314,15 +316,19 @@ The OTLP exporter is configured using the common OpenTelemetry environment varia

### slog logging

To use `log/slog` for logging, you can configure the telemetry logging settings in your NACP configuration file. This allows you to set the logging type, level, and handler.
To use `log/slog` for logging, you can configure the telemetry logging settings in your NACP configuration file. This allows you to add json and text slog handlers.

```hcl
telemetry {
logging {
type = "slog" # Use slog for logging

level = "info" # Set the logging level (e.g., debug, info, warn, error)
slog {
handler = "text" # Set the slog handler (e.g., text, json)
json = true # Adds the json slog handler (defaults to false)
text = true # Adds the text slog handler (defaults to false)

text_out = "stderr" # default "stdout"
json_out = "stdout" # same
}
}
}
Expand Down
133 changes: 51 additions & 82 deletions cmd/nacp/nacp.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -24,6 +24,7 @@ import (

"github.com/mxab/nacp/admissionctrl/remoteutil"
"github.com/mxab/nacp/admissionctrl/types"
"github.com/mxab/nacp/logutil"
nacpOtel "github.com/mxab/nacp/otel"

"log/slog"
Expand All @@ -39,7 +40,6 @@ import (
"github.com/notaryproject/notation-go/dir"
"github.com/notaryproject/notation-go/verifier/truststore"

"go.opentelemetry.io/contrib/bridges/otelslog"
"go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp"
)

Expand Down Expand Up @@ -111,15 +111,15 @@ func resolveTokenAccessor(ctx context.Context, transport http.RoundTripper, noma

return &aclToken, nil
}
func NewProxyAsHandlerFunc(nomadAddress *url.URL, jobHandler *admissionctrl.JobHandler, appLogger *slog.Logger, transport http.RoundTripper) http.HandlerFunc {
func NewProxyAsHandlerFunc(nomadAddress *url.URL, jobHandler *admissionctrl.JobHandler, logger *slog.Logger, transport http.RoundTripper) http.HandlerFunc {

proxy := newProxyHandler(nomadAddress, jobHandler, appLogger, transport)
proxy := newProxyHandler(nomadAddress, jobHandler, logger, transport)
handlerFunc := http.HandlerFunc(proxy)
handlerFunc = otelhttp.NewHandler(handlerFunc, "/").(http.HandlerFunc)

return handlerFunc
}
func newProxyHandler(nomadAddress *url.URL, jobHandler *admissionctrl.JobHandler, appLogger *slog.Logger, transport http.RoundTripper) func(http.ResponseWriter, *http.Request) {
func newProxyHandler(nomadAddress *url.URL, jobHandler *admissionctrl.JobHandler, logger *slog.Logger, transport http.RoundTripper) func(http.ResponseWriter, *http.Request) {

proxy := httputil.NewSingleHostReverseProxy(nomadAddress)

Expand All @@ -138,14 +138,14 @@ func newProxyHandler(nomadAddress *url.URL, jobHandler *admissionctrl.JobHandler
var err error

if isRegister(resp.Request) {
err = handRegisterResponse(resp, appLogger)
err = handRegisterResponse(resp, logger)
} else if isPlan(resp.Request) {
err = handleJobPlanResponse(resp, appLogger)
err = handleJobPlanResponse(resp, logger)
} else if isValidate(resp.Request) {
err = handleJobValdidateResponse(resp, appLogger)
err = handleJobValdidateResponse(resp, logger)
}
if err != nil {
appLogger.ErrorContext(resp.Request.Context(), "Preparing response failed", "error", err)
logger.ErrorContext(resp.Request.Context(), "Preparing response failed", "error", err)
return err
}

Expand All @@ -166,34 +166,34 @@ func newProxyHandler(nomadAddress *url.URL, jobHandler *admissionctrl.JobHandler
if jobHandler.ResolveToken() {
tokenInfo, err := resolveTokenAccessor(ctx, transport, nomadAddress, token)
if err != nil {
appLogger.ErrorContext(ctx, "Resolving token failed", "error", err)
logger.ErrorContext(ctx, "Resolving token failed", "error", err)
writeError(w, err)
}
if tokenInfo != nil {
reqCtx.AccessorID = tokenInfo.AccessorID
reqCtx.TokenInfo = tokenInfo
}
appLogger.InfoContext(ctx, "Request received", "path", r.URL.Path, "method", r.Method, "clientIP", reqCtx.ClientIP, "accessorID", reqCtx.AccessorID)
logger.InfoContext(ctx, "Request received", "path", r.URL.Path, "method", r.Method, "clientIP", reqCtx.ClientIP, "accessorID", reqCtx.AccessorID)
} else {
appLogger.InfoContext(ctx, "Request received", "path", r.URL.Path, "method", r.Method, "clientIP", reqCtx.ClientIP)
logger.InfoContext(ctx, "Request received", "path", r.URL.Path, "method", r.Method, "clientIP", reqCtx.ClientIP)
}

ctx = context.WithValue(ctx, "request_context", reqCtx)
r = r.WithContext(ctx)

var err error
if isRegister(r) {
r, err = handleRegister(r, appLogger, jobHandler)
r, err = handleRegister(r, logger, jobHandler)

} else if isPlan(r) {
r, err = handlePlan(r, appLogger, jobHandler)
r, err = handlePlan(r, logger, jobHandler)

} else if isValidate(r) {
r, err = handleValidate(r, appLogger, jobHandler)
r, err = handleValidate(r, logger, jobHandler)

}
if err != nil {
appLogger.WarnContext(ctx, "Error applying admission controllers", "error", err)
logger.WarnContext(ctx, "Error applying admission controllers", "error", err)
writeError(w, err)

} else {
Expand All @@ -205,7 +205,7 @@ func newProxyHandler(nomadAddress *url.URL, jobHandler *admissionctrl.JobHandler

}

func handRegisterResponse(resp *http.Response, applogger *slog.Logger) error {
func handRegisterResponse(resp *http.Response, logger *slog.Logger) error {

warnings, ok := resp.Request.Context().Value(ctxWarnings).([]error)
if !ok && len(warnings) == 0 {
Expand Down Expand Up @@ -254,7 +254,7 @@ func checkIfGzipAndTransformReader(resp *http.Response, reader io.ReadCloser) (b
}
return isGzip, reader, nil
}
func handleJobPlanResponse(resp *http.Response, applogger *slog.Logger) error {
func handleJobPlanResponse(resp *http.Response, logger *slog.Logger) error {
warnings, ok := resp.Request.Context().Value(ctxWarnings).([]error)
if !ok && len(warnings) == 0 {
return nil
Expand Down Expand Up @@ -286,7 +286,7 @@ func handleJobPlanResponse(resp *http.Response, applogger *slog.Logger) error {
}
return nil
}
func handleJobValdidateResponse(resp *http.Response, appLogger *slog.Logger) error {
func handleJobValdidateResponse(resp *http.Response, logger *slog.Logger) error {

ctx := resp.Request.Context()
validationErr, okErr := ctx.Value(ctxValidationError).(error)
Expand Down Expand Up @@ -528,20 +528,26 @@ func isValidate(r *http.Request) bool {
return (r.Method == "PUT" || r.Method == "POST") && r.URL.Path == "/v1/validate/job"
}

func buildSlogHandler(json bool, level slog.Level) slog.Handler {
opts := &slog.HandlerOptions{
Level: level,
}
if json {
return slog.NewJSONHandler(os.Stdout, opts)
}
return slog.NewTextHandler(os.Stdout, opts)
}

// https://www.codedodle.com/go-reverse-proxy-example.html
// https://joshsoftware.wordpress.com/2021/05/25/simple-and-powerful-reverseproxy-in-go/

func main() {

configPtr := flag.String("config", "", "point to a nacp config file")
bootstrapLoggerHandlerPtr := flag.Bool("bootstrap-json-logger", false, "use json for initial logging until config is loaded")
flag.Parse()
var bootstrapLogger *slog.Logger
if *bootstrapLoggerHandlerPtr {
bootstrapLogger = slog.New(slog.NewJSONHandler(os.Stdout, nil))
} else {
bootstrapLogger = slog.New(slog.NewTextHandler(os.Stdout, nil))
}
slog.SetDefault(bootstrapLogger)

slog.SetDefault(slog.New(buildSlogHandler(*bootstrapLoggerHandlerPtr, slog.LevelInfo)))

c, err := buildConfig(*configPtr)
if err != nil {
Expand All @@ -561,37 +567,27 @@ func run(c *config.Config) (err error) {
ctx, stop := signal.NotifyContext(context.Background(), os.Interrupt)
defer stop()

loggerFactory, err := buildLoggerFactory(c)
if err != nil {
return fmt.Errorf("failed to build logger factory: %w", err)
}
rootFactory, leveler := logutil.NewLoggerFactoryFromConfig(c.Telemetry.Logging)

appLogger := rootFactory.GetLogger("nacp")
slog.SetDefault(appLogger)

logger := loggerFactory("nacp")
slog.SetDefault(logger)
appLogger := logger
setupOtel := c.Telemetry.Logging.IsOtel() || c.Telemetry.Metrics.Enabled || c.Telemetry.Tracing.Enabled
setupOtel := *c.Telemetry.Logging.OtelLogging.Enabled || c.Telemetry.Metrics.Enabled || c.Telemetry.Tracing.Enabled
if setupOtel {
// Set up OpenTelemetry.
otelShutdown, err := nacpOtel.SetupOTelSDK(ctx, c.Telemetry.Logging.IsOtel(), c.Telemetry.Metrics.Enabled, c.Telemetry.Tracing.Enabled, version)
otelShutdown, err := nacpOtel.SetupOTelSDK(ctx, *c.Telemetry.Logging.OtelLogging.Enabled, c.Telemetry.Metrics.Enabled, c.Telemetry.Tracing.Enabled, version, leveler.GetSeverietier())
if err != nil {
return fmt.Errorf("failed to setup OpenTelemetry: %w", err)
}
// Handle shutdown properly so nothing leaks.
// https://opentelemetry.io/docs/languages/go/getting-started/
defer func() {
err = errors.Join(err, otelShutdown(context.Background()))

}()

}

level := slog.Level(0)
if err := level.UnmarshalText([]byte(c.Telemetry.Logging.Level)); err != nil {
return fmt.Errorf("failed to parse log level: %w", err)
}
slog.SetLogLoggerLevel(level)

server, err := buildServer(c, loggerFactory)
server, err := buildServer(c, rootFactory)

if err != nil {
return fmt.Errorf("failed to build server: %w", err)
Expand Down Expand Up @@ -627,34 +623,7 @@ func run(c *config.Config) (err error) {

}

func buildLoggerFactory(c *config.Config) (lf loggerFactory, err error) {
if c.Telemetry.Logging.IsSlog() {
if c.Telemetry.Logging.SlogLogging.Handler == "json" {
lf = func(_ string) *slog.Logger {
return slog.New(slog.NewJSONHandler(os.Stdout, nil))
}

} else if c.Telemetry.Logging.SlogLogging.Handler == "text" {
lf = func(_ string) *slog.Logger {
return slog.New(slog.NewTextHandler(os.Stdout, nil))
}

} else {
return nil, fmt.Errorf("invalid slog logging handler, only json and text are supported")
}

} else if c.Telemetry.Logging.IsOtel() {
lf = func(name string) *slog.Logger {
return otelslog.NewLogger(name)
}

} else {
return nil, fmt.Errorf("invalid logging type, only slog and otel are supported")
}
return
}

func buildServer(c *config.Config, loggerFactory loggerFactory) (*http.Server, error) {
func buildServer(c *config.Config, loggerFactory *logutil.LoggerFactory) (*http.Server, error) {
backend, err := url.Parse(c.Nomad.Address)
if err != nil {
return nil, fmt.Errorf("failed to parse nomad address: %w", err)
Expand Down Expand Up @@ -696,11 +665,11 @@ func buildServer(c *config.Config, loggerFactory loggerFactory) (*http.Server, e

jobMutators,
jobValidators,
loggerFactory("handler"),
loggerFactory.GetLogger("handler"),
resolveToken,
)

handlerFunc := NewProxyAsHandlerFunc(backend, jobHandler, loggerFactory("proxy-handler"), instrumentedProxyTransport)
handlerFunc := NewProxyAsHandlerFunc(backend, jobHandler, loggerFactory.GetLogger("proxy-handler"), instrumentedProxyTransport)

bind := fmt.Sprintf("%s:%d", c.Bind, c.Port)
var tlsConfig *tls.Config
Expand Down Expand Up @@ -760,7 +729,7 @@ func createTlsConfig(caFile string, noClientCert bool) (*tls.Config, error) {
return tlsConfig, nil
}

func createMutators(c *config.Config, loggerFactory loggerFactory) ([]admissionctrl.JobMutator, bool, error) {
func createMutators(c *config.Config, loggerFactory *logutil.LoggerFactory) ([]admissionctrl.JobMutator, bool, error) {
var jobMutators []admissionctrl.JobMutator
var resolveToken bool
for _, m := range c.Mutators {
Expand All @@ -769,18 +738,18 @@ func createMutators(c *config.Config, loggerFactory loggerFactory) ([]admissionc
}
switch m.Type {
case "opa_json_patch":
notationVerifier, err := buildVerifierIfEnabled(m.OpaRule.Notation, loggerFactory("notation_verifier"))
notationVerifier, err := buildVerifierIfEnabled(m.OpaRule.Notation, loggerFactory.GetLogger("notation_verifier"))
if err != nil {
return nil, resolveToken, err
}
mutator, err := mutator.NewOpaJsonPatchMutator(m.Name, m.OpaRule.Filename, m.OpaRule.Query, loggerFactory("opa_mutator"), notationVerifier)
mutator, err := mutator.NewOpaJsonPatchMutator(m.Name, m.OpaRule.Filename, m.OpaRule.Query, loggerFactory.GetLogger("opa_mutator"), notationVerifier)
if err != nil {
return nil, resolveToken, err
}
jobMutators = append(jobMutators, mutator)

case "json_patch_webhook":
mutator, err := mutator.NewJsonPatchWebhookMutator(m.Name, m.Webhook.Endpoint, m.Webhook.Method, loggerFactory("json_patch_webhook_mutator"))
mutator, err := mutator.NewJsonPatchWebhookMutator(m.Name, m.Webhook.Endpoint, m.Webhook.Method, loggerFactory.GetLogger("json_patch_webhook_mutator"))
if err != nil {
return nil, resolveToken, err
}
Expand All @@ -793,7 +762,7 @@ func createMutators(c *config.Config, loggerFactory loggerFactory) ([]admissionc
}
return jobMutators, resolveToken, nil
}
func createValidators(c *config.Config, loggerFactory loggerFactory) ([]admissionctrl.JobValidator, bool, error) {
func createValidators(c *config.Config, loggerFactory *logutil.LoggerFactory) ([]admissionctrl.JobValidator, bool, error) {
var jobValidators []admissionctrl.JobValidator
var resolveToken bool
for _, v := range c.Validators {
Expand All @@ -802,28 +771,28 @@ func createValidators(c *config.Config, loggerFactory loggerFactory) ([]admissio
}
switch v.Type {
case "opa":
notationVerifier, err := buildVerifierIfEnabled(v.Notation, loggerFactory("notation_verifier"))
notationVerifier, err := buildVerifierIfEnabled(v.Notation, loggerFactory.GetLogger("notation_verifier"))
if err != nil {
return nil, resolveToken, err
}
opaValidator, err := validator.NewOpaValidator(v.Name, v.OpaRule.Filename, v.OpaRule.Query, loggerFactory("opa_validator"), notationVerifier)
opaValidator, err := validator.NewOpaValidator(v.Name, v.OpaRule.Filename, v.OpaRule.Query, loggerFactory.GetLogger("opa_validator"), notationVerifier)
if err != nil {
return nil, resolveToken, err
}
jobValidators = append(jobValidators, opaValidator)

case "webhook":
validator, err := validator.NewWebhookValidator(v.Name, v.Webhook.Endpoint, v.Webhook.Method, loggerFactory("webhook_validator"))
validator, err := validator.NewWebhookValidator(v.Name, v.Webhook.Endpoint, v.Webhook.Method, loggerFactory.GetLogger("webhook_validator"))
if err != nil {
return nil, resolveToken, err
}
jobValidators = append(jobValidators, validator)
case "notation":
notationVerifier, err := buildVerifier(v.Notation, loggerFactory("notation_verifier"))
notationVerifier, err := buildVerifier(v.Notation, loggerFactory.GetLogger("notation_verifier"))
if err != nil {
return nil, resolveToken, err
}
validator := validator.NewNotationValidator(loggerFactory("notation_validator"), v.Name, notationVerifier)
validator := validator.NewNotationValidator(loggerFactory.GetLogger("notation_validator"), v.Name, notationVerifier)

jobValidators = append(jobValidators, validator)

Expand Down
Loading