mirror of
https://github.com/caddyserver/caddy.git
synced 2026-11-01 00:41:31 -04:00
events: tell CertMagic which events are worth emitting (#8010)
CertMagic assembles an event's data before emit() can look at OnEvent, because Go evaluates arguments first, so tls_get_certificate costs a map and a ClientHello copy on every handshake even when nothing will read them. caddyserver/certmagic#406 added Config.ShouldEmitFunc so an embedder can answer that question first. Export App.ShouldEmit and pass it along with OnEvent. The predicate has to account for every observer, not just subscribed handlers: Emit writes a debug line for each event, so an event is observable whenever debug logging is on. Emit now asks the same method it exports, so the two cannot drift. Benchmarks are included; measurements are in the pull request.
This commit is contained in:
1 parent
ac834b5dc7
commit
4978c54f81
5 files changed
+75
-16
No files matched your search
@@ -199,6 +199,17 @@ func (app *App) On(eventName string, handler Handler) error {
|
||||
})
|
||||
}
|
||||
|
||||
// ShouldEmit reports whether emitting the named event could be observed by
|
||||
// anything: a handler subscribed to it by name or to all events, or the debug
|
||||
// log that Emit writes for every event. Emitters that assemble event data
|
||||
// before calling Emit can use it to skip that work; it is the same question
|
||||
// Emit answers internally, exported so callers do not have to guess.
|
||||
func (app *App) ShouldEmit(eventName string) bool {
|
||||
return app.subscriptions[eventName] != nil ||
|
||||
app.subscriptions[""] != nil ||
|
||||
app.logger.Core().Enabled(zapcore.DebugLevel)
|
||||
}
|
||||
|
||||
// Emit creates and dispatches an event named eventName to all relevant handlers with
|
||||
// the metadata data. Events are emitted and propagated synchronously. The returned Event
|
||||
// value will have any additional information from the invoked handlers.
|
||||
@@ -212,14 +223,11 @@ func (app *App) Emit(ctx caddy.Context, eventName string, data map[string]any) c
|
||||
zap.String("name", eventName), zap.Error(err))
|
||||
}
|
||||
|
||||
// A handler can only be reached through subscriptions to this event by
|
||||
// name or to all events, so if neither is bound, nothing can observe
|
||||
// this event and the only remaining output is the debug log below.
|
||||
// Bail out before deriving loggers and registering replacer values:
|
||||
// some events, such as tls_get_certificate, are emitted on every TLS
|
||||
// handshake, where that work is significant and always wasted.
|
||||
if app.subscriptions[eventName] == nil && app.subscriptions[""] == nil &&
|
||||
!app.logger.Core().Enabled(zapcore.DebugLevel) {
|
||||
// bail out before deriving loggers and registering replacer values if
|
||||
// nothing can observe this event: some events, such as
|
||||
// tls_get_certificate, are emitted on every TLS handshake, where that
|
||||
// work is significant and always wasted
|
||||
if !app.ShouldEmit(eventName) {
|
||||
return e
|
||||
}
|
||||
|
||||
|
||||
@@ -92,6 +92,54 @@ func TestEmitDispatchesToCatchAllSubscriber(t *testing.T) {
|
||||
}
|
||||
}
|
||||
|
||||
// Emit writes a debug line for every event, so with debug logging on an event
|
||||
// is observable even when nothing is subscribed. A predicate that answered
|
||||
// only about subscribers would silence that line.
|
||||
func TestShouldEmit(t *testing.T) {
|
||||
app, _, cancel := testApp(t)
|
||||
defer cancel()
|
||||
|
||||
if app.ShouldEmit("cert_obtained") {
|
||||
t.Error("nothing is subscribed and debug is off; should not emit")
|
||||
}
|
||||
|
||||
if err := app.On("cert_obtained", new(countingHandler)); err != nil {
|
||||
t.Fatal(err)
|
||||
}
|
||||
if !app.ShouldEmit("cert_obtained") {
|
||||
t.Error("a handler is bound by name; should emit")
|
||||
}
|
||||
if app.ShouldEmit("tls_get_certificate") {
|
||||
t.Error("nothing is bound to this event; should not emit")
|
||||
}
|
||||
}
|
||||
|
||||
func TestShouldEmitWithCatchAllSubscriber(t *testing.T) {
|
||||
app, _, cancel := testApp(t)
|
||||
defer cancel()
|
||||
|
||||
if err := app.Subscribe(&Subscription{Handlers: []Handler{new(countingHandler)}}); err != nil {
|
||||
t.Fatal(err)
|
||||
}
|
||||
if !app.ShouldEmit("tls_get_certificate") {
|
||||
t.Error("a catch-all subscription observes every event; should emit")
|
||||
}
|
||||
}
|
||||
|
||||
func TestShouldEmitWithDebugLogging(t *testing.T) {
|
||||
app, _, cancel := testApp(t)
|
||||
defer cancel()
|
||||
app.logger = zap.New(zapcore.NewCore(
|
||||
zapcore.NewJSONEncoder(zap.NewProductionEncoderConfig()),
|
||||
zapcore.AddSync(io.Discard),
|
||||
zapcore.DebugLevel,
|
||||
))
|
||||
|
||||
if !app.ShouldEmit("tls_get_certificate") {
|
||||
t.Error("debug logging observes every event; should emit")
|
||||
}
|
||||
}
|
||||
|
||||
// Some events, such as tls_get_certificate, are emitted on every TLS
|
||||
// handshake, whether or not anything is subscribed to them.
|
||||
func BenchmarkEmitNoSubscribers(b *testing.B) {
|
||||
|
||||
@@ -57,7 +57,7 @@ func benchCert(tb testing.TB) tls.Certificate {
|
||||
// benchmarkCertLookup measures CertMagic's GetCertificate, which Caddy calls
|
||||
// once per TLS handshake. CertMagic emits "tls_get_certificate" there, so this
|
||||
// shows what the events app costs a handshake when nothing is subscribed.
|
||||
func benchmarkCertLookup(b *testing.B, onEvent func(context.Context, string, map[string]any) error) {
|
||||
func benchmarkCertLookup(b *testing.B, onEvent func(context.Context, string, map[string]any) error, shouldEmit func(string) bool) {
|
||||
b.Helper()
|
||||
|
||||
var cfg *certmagic.Config
|
||||
@@ -68,9 +68,10 @@ func benchmarkCertLookup(b *testing.B, onEvent func(context.Context, string, map
|
||||
b.Cleanup(cache.Stop)
|
||||
|
||||
cfg = certmagic.New(cache, certmagic.Config{
|
||||
Storage: &certmagic.FileStorage{Path: b.TempDir()},
|
||||
Logger: zap.NewNop(),
|
||||
OnEvent: onEvent,
|
||||
Storage: &certmagic.FileStorage{Path: b.TempDir()},
|
||||
Logger: zap.NewNop(),
|
||||
OnEvent: onEvent,
|
||||
ShouldEmitFunc: shouldEmit,
|
||||
})
|
||||
if _, err := cfg.CacheUnmanagedTLSCertificate(context.Background(), benchCert(b), nil); err != nil {
|
||||
b.Fatal(err)
|
||||
@@ -107,5 +108,5 @@ func BenchmarkCertLookupWithEventsApp(b *testing.B) {
|
||||
|
||||
benchmarkCertLookup(b, func(_ context.Context, name string, data map[string]any) error {
|
||||
return app.Emit(ctx, name, data).Aborted
|
||||
})
|
||||
}, app.ShouldEmit)
|
||||
}
|
||||
@@ -366,6 +366,7 @@ func (ap *AutomationPolicy) makeCertMagicConfig(tlsApp *TLS, issuers []certmagic
|
||||
RenewalWindowRatio: ap.RenewalWindowRatio,
|
||||
KeySource: keySource,
|
||||
OnEvent: tlsApp.onEvent,
|
||||
ShouldEmitFunc: tlsApp.events.ShouldEmit,
|
||||
OnDemand: ond,
|
||||
ReusePrivateKeys: ap.ReusePrivateKeys,
|
||||
OCSP: certmagic.OCSPConfig{
|
||||
|
||||
@@ -255,9 +255,10 @@ func (t *TLS) Provision(ctx caddy.Context) error {
|
||||
// commands like validate can be a better test
|
||||
certCacheMu.RLock()
|
||||
magic := certmagic.New(certCache, certmagic.Config{
|
||||
Storage: ctx.Storage(),
|
||||
Logger: t.logger,
|
||||
OnEvent: t.onEvent,
|
||||
Storage: ctx.Storage(),
|
||||
Logger: t.logger,
|
||||
OnEvent: t.onEvent,
|
||||
ShouldEmitFunc: t.events.ShouldEmit,
|
||||
OCSP: certmagic.OCSPConfig{
|
||||
DisableStapling: t.DisableOCSPStapling,
|
||||
},
|
||||
|
||||
Reference in new issue
Block a user