diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index b88929f..705a1c8 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -14,7 +14,7 @@ jobs: strategy: fail-fast: false matrix: - module: ["dbkit", "dbkit/sqlite", "mailkit", "goncierge", "gonsole", "gonsole/auth", "gonsole/auth/sqlite", "pluginkit", "pluginkit/graphwire"] + module: ["dbkit", "dbkit/sqlite", "mailkit", "goncierge", "gonsole", "gonsole/auth", "gonsole/auth/sqlite", "pluginkit", "pluginkit/features", "pluginkit/graphwire"] defaults: run: working-directory: ${{ matrix.module }} @@ -99,7 +99,7 @@ jobs: strategy: fail-fast: false matrix: - module: ["dbkit", "dbkit/postgres", "dbkit/sqlite", "mailkit", "goncierge", "gonsole", "gonsole/auth", "gonsole/auth/postgres", "gonsole/auth/sqlite", "pluginkit", "pluginkit/graphwire", "postgresblob"] + module: ["dbkit", "dbkit/postgres", "dbkit/sqlite", "mailkit", "goncierge", "gonsole", "gonsole/auth", "gonsole/auth/postgres", "gonsole/auth/sqlite", "pluginkit", "pluginkit/features", "pluginkit/graphwire", "postgresblob"] steps: - uses: actions/checkout@9c091bb21b7c1c1d1991bb908d89e4e9dddfe3e0 # v7.0.0 with: @@ -121,7 +121,7 @@ jobs: strategy: fail-fast: false matrix: - module: ["dbkit", "dbkit/postgres", "dbkit/sqlite", "mailkit", "goncierge", "gonsole", "gonsole/auth", "gonsole/auth/postgres", "gonsole/auth/sqlite", "pluginkit", "pluginkit/graphwire", "postgresblob"] + module: ["dbkit", "dbkit/postgres", "dbkit/sqlite", "mailkit", "goncierge", "gonsole", "gonsole/auth", "gonsole/auth/postgres", "gonsole/auth/sqlite", "pluginkit", "pluginkit/features", "pluginkit/graphwire", "postgresblob"] defaults: run: working-directory: ${{ matrix.module }} diff --git a/pluginkit/CHANGELOG.md b/pluginkit/CHANGELOG.md index 78b03e3..9526be8 100644 --- a/pluginkit/CHANGELOG.md +++ b/pluginkit/CHANGELOG.md @@ -3,6 +3,13 @@ Releases of this module are tagged `pluginkit/vX.Y.Z`. Releases up to 0.5.1 were tagged `vX.Y.Z` in `github.com/gopherium/pluginkit`. +## Unreleased + +- `NewHook` collects the plugins that implement an interface into a `Hook`. `Hook.Fire` calls an action on each in registration order and `Filter` passes a value through each, every call inside its own recover. +- One firing shares `HookSettings.Budget` as a context deadline. The plugins after a slow one are still called, and an error that matches the ended context counts as `ContextEnded`, not as that plugin's fault. +- After a firing runs over its budget, the next `TimedFirings` firings time each plugin, without the time of `Report`, and a timed firing whose plugins together run over is charged to the slowest. `Stats` returns every counter, and `HookSettings.Report` receives each error and panic as a `HookFailure` and must not panic. +- `HookStats.UnchargedOverruns` counts the timed firings that ran over while their plugins together kept the budget, and `HookStats.TimedReportTime` the time `Report` took in timed firings. + ## 0.9.0 - 2026-11-05 - `wire.Manifest` holds one `plugin.json` as data, reading `version`, `license`, `did`, `requires`, `tested`, `engines`, `uninstall`, `hooks`, `defines`, `jobs` and `settings`, with every other key kept raw in `Extra`. diff --git a/pluginkit/features/.golangci.yml b/pluginkit/features/.golangci.yml new file mode 100644 index 0000000..1b3b888 --- /dev/null +++ b/pluginkit/features/.golangci.yml @@ -0,0 +1,36 @@ +version: "2" + +linters: + default: standard + enable: + - depguard + - lll + - misspell + - revive + - unconvert + - unparam + settings: + lll: + line-length: 120 + revive: + rules: + - name: blank-imports + disabled: true + - name: exported + depguard: + rules: + dependency-purity: + list-mode: strict + allow: + - $gostd + - github.com/cucumber/godog + - github.com/gopherium/framework/pluginkit + +formatters: + enable: + - gofmt + - goimports + settings: + goimports: + local-prefixes: + - github.com/gopherium/framework diff --git a/pluginkit/features/features_test.go b/pluginkit/features/features_test.go new file mode 100644 index 0000000..c339027 --- /dev/null +++ b/pluginkit/features/features_test.go @@ -0,0 +1,39 @@ +// SPDX-License-Identifier: Apache-2.0 + +package features_test + +import ( + "os" + "testing" + + "github.com/cucumber/godog" +) + +// wipTag selects the scenarios no code makes pass yet. +const wipTag = "@wip" + +// runFeature runs one feature file as its own suite, refusing undefined steps. +func runFeature(t *testing.T, path string, initialize func(*godog.ScenarioContext)) { + t.Helper() + tags := "~" + wipTag + if os.Getenv("PLUGINKIT_BDD_WIP") != "" { + tags = "" + } + suite := godog.TestSuite{ + ScenarioInitializer: initialize, + Options: &godog.Options{ + Format: "pretty", + Paths: []string{path}, + Tags: tags, + Strict: true, + TestingT: t, + }, + } + if suite.Run() != 0 { + t.Error("the feature did not pass") + } +} + +func TestHooks(t *testing.T) { + runFeature(t, "hooks.feature", initializeHooks(t)) +} diff --git a/pluginkit/features/go.mod b/pluginkit/features/go.mod new file mode 100644 index 0000000..148e6cf --- /dev/null +++ b/pluginkit/features/go.mod @@ -0,0 +1,20 @@ +module github.com/gopherium/framework/pluginkit/features + +go 1.27.3 + +require ( + github.com/cucumber/godog v0.16.0 + github.com/gopherium/framework/pluginkit v0.0.0 +) + +require ( + github.com/cucumber/gherkin/go/v42 v42.0.0 // indirect + github.com/cucumber/messages/go/v34 v34.2.0 // indirect + github.com/google/uuid v1.6.0 // indirect + github.com/hashicorp/go-immutable-radix v1.3.1 // indirect + github.com/hashicorp/go-memdb v1.3.5 // indirect + github.com/hashicorp/golang-lru v0.5.4 // indirect + github.com/spf13/pflag v1.0.10 // indirect +) + +replace github.com/gopherium/framework/pluginkit => ../ diff --git a/pluginkit/features/go.sum b/pluginkit/features/go.sum new file mode 100644 index 0000000..32fc51b --- /dev/null +++ b/pluginkit/features/go.sum @@ -0,0 +1,28 @@ +github.com/cucumber/gherkin/go/v42 v42.0.0 h1:Ulh3E2awUUSSja+wonP/IOQ+ycmiZwZbgmzqk5H8JNI= +github.com/cucumber/gherkin/go/v42 v42.0.0/go.mod h1:CsaumaO2dR9XvBc6ZyiGLMhWCKtTRDxgoxqJigSjSSg= +github.com/cucumber/godog v0.16.0 h1:ezQbgItuWqZrjPUQwLJ3muwIlvzXBOfZso5QZfG7efE= +github.com/cucumber/godog v0.16.0/go.mod h1:EDUX9yCqANK+GpbftMDeu61sUDtdLuo1JJgXD2n3bbM= +github.com/cucumber/messages/go/v34 v34.2.0 h1:VCbcNOMz+f8ccjjOOx1NLBNhwvE7/X49Atc8klJa+i8= +github.com/cucumber/messages/go/v34 v34.2.0/go.mod h1:LYUPjqlTS1kS0pdkdf6sS5uirnjwiIzEGyXPezXNhL8= +github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c= +github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= +github.com/google/uuid v1.6.0 h1:NIvaJDMOsjHA8n1jAhLSgzrAzy1Hgr+hNrb57e+94F0= +github.com/google/uuid v1.6.0/go.mod h1:TIyPZe4MgqvfeYDBFedMoGGpEw/LqOeaOT+nhxU+yHo= +github.com/hashicorp/go-immutable-radix v1.3.1 h1:DKHmCUm2hRBK510BaiZlwvpD40f8bJFeZnpfm2KLowc= +github.com/hashicorp/go-immutable-radix v1.3.1/go.mod h1:0y9vanUI8NX6FsYoO3zeMjhV/C5i9g4Q3DwcSNZ4P60= +github.com/hashicorp/go-memdb v1.3.5 h1:b3taDMxCBCBVgyRrS1AZVHO14ubMYZB++QpNhBg+Nyo= +github.com/hashicorp/go-memdb v1.3.5/go.mod h1:8IVKKBkVe+fxFgdFOYxzQQNjz+sWCyHCdIC/+5+Vy1Y= +github.com/hashicorp/go-uuid v1.0.0/go.mod h1:6SBZvOh/SIDV7/2o3Jml5SYk/TvGqwFJ/bN7x4byOro= +github.com/hashicorp/go-uuid v1.0.2 h1:cfejS+Tpcp13yd5nYHWDI6qVCny6wyX2Mt5SGur2IGE= +github.com/hashicorp/go-uuid v1.0.2/go.mod h1:6SBZvOh/SIDV7/2o3Jml5SYk/TvGqwFJ/bN7x4byOro= +github.com/hashicorp/golang-lru v0.5.0/go.mod h1:/m3WP610KZHVQ1SGc6re/UDhFvYD7pJ4Ao+sR/qLZy8= +github.com/hashicorp/golang-lru v0.5.4 h1:YDjusn29QI/Das2iO9M0BHnIbxPeyuCHsjMW+lJfyTc= +github.com/hashicorp/golang-lru v0.5.4/go.mod h1:iADmTwqILo4mZ8BN3D2Q6+9jd8WM5uGBxy+E8yxSoD4= +github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM= +github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= +github.com/spf13/pflag v1.0.10 h1:4EBh2KAYBwaONj6b2Ye1GiHfwjqyROoF4RwYO+vPwFk= +github.com/spf13/pflag v1.0.10/go.mod h1:McXfInJRrz4CZXVZOBLb0bTZqETkiAhM9Iw0y3An2Bg= +github.com/stretchr/testify v1.11.1 h1:7s2iGBzp5EwR7/aIZr8ao5+dra3wiQyKjjFuvgVKu7U= +github.com/stretchr/testify v1.11.1/go.mod h1:wZwfW3scLgRK+23gO65QZefKpKQRnfz6sD981Nm4B6U= +gopkg.in/yaml.v3 v3.0.1 h1:fxVm/GzAzEWqLHuvctI91KS9hhNmmWOoWu0XTYJS7CA= +gopkg.in/yaml.v3 v3.0.1/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= diff --git a/pluginkit/features/hooks.feature b/pluginkit/features/hooks.feature new file mode 100644 index 0000000..5a9331e --- /dev/null +++ b/pluginkit/features/hooks.feature @@ -0,0 +1,169 @@ +Feature: Calling the plugins that implement a hook + A hook is a named moment where an application calls every plugin that + implements one interface, in the order the plugins were registered. An + action tells each plugin that something happened, and a filter passes a + value through each plugin. One firing of a hook shares one time budget + among all its plugins. A plugin that fails, panics or runs slow never + stops the plugins after it. The counters name the plugin that failed or + panicked, and the slowest one once the firings after an overrun are + timed. The report is the application's own function that receives each + error and panic of a plugin. + + Scenario: Every plugin that implements the hook is called in order + Given the plugins "seo-basics" and "analytics" implement the hook "public.head-tags" + And the plugin "theme" is registered without implementing it + And the plugin "feed" implements the hook "public.head-tags" + When the hook fires + Then "seo-basics", "analytics" and "feed" are called in that order + + Scenario: A failing plugin leaves the plugins after it running + Given the plugins "analytics", "feed" and "seo-basics" implement the hook "content.changed" + And "feed" fails with "index unavailable" + When the hook fires + Then "analytics", "feed" and "seo-basics" are called in that order + And the report holds "pluginkit: feed content.changed: index unavailable" + And "feed" is counted 1 error + + Scenario: A panicking plugin leaves the plugins after it running + Given the plugins "analytics", "feed" and "seo-basics" implement the hook "content.changed" + And "feed" panics with "boom" + When the hook fires + Then "analytics", "feed" and "seo-basics" are called in that order + And the report holds "pluginkit: feed content.changed panicked: boom" with the stack of the panic + And "feed" is counted 1 panic + + Scenario: The plugins after a slow one are still called + Given the plugins "analytics", "feed" and "seo-basics" implement the hook "public.head-tags" + And the hook has a budget of 2 ms + And "analytics" takes 5 ms + When the hook fires + Then "analytics", "feed" and "seo-basics" are called in that order + And "feed" and "seo-basics" are called after the deadline passed + And the hook is counted 1 overrun + + Scenario: An error caused by the ended deadline is not the plugin's fault + Given the plugins "analytics" and "search" implement the hook "content.changed" + And the hook has a budget of 2 ms + And "analytics" takes 5 ms + And "search" fails with the error of its ended context + When the hook fires + Then "search" is counted 0 errors and 1 call whose context ended + And the report marks the failure of "search" as caused by the ended context + + Scenario: An error of its own after the deadline still counts against the plugin + Given the plugins "analytics" and "search" implement the hook "content.changed" + And the hook has a budget of 2 ms + And "analytics" takes 5 ms + And "search" fails with "index unavailable" + When the hook fires + Then "search" is counted 1 error and 0 calls whose context ended + + Scenario: A plugin that hides the context's error behind its own text is counted an error + Given the plugins "analytics" and "search" implement the hook "content.changed" + And the hook has a budget of 2 ms + And "analytics" takes 5 ms + And "search" fails with the text of its ended context but not the error itself + When the hook fires + Then "search" is counted 1 error and 0 calls whose context ended + + Scenario: After the deadline, an error that panics when the hook unwraps it counts as a panic of its plugin + Given the plugins "analytics", "search" and "feed" implement the hook "content.changed" + And the hook has a budget of 2 ms + And "analytics" takes 5 ms + And "search" fails with an error that panics when it is unwrapped + When the hook fires + Then "analytics", "search" and "feed" are called in that order + And "search" is counted 1 panic + + Scenario: A panic in the report reaches the code that fired the hook + Given the plugins "analytics" and "feed" implement the hook "content.changed" + And "analytics" fails with "index unavailable" + And the report panics with "report broken" + When the hook fires + Then the firing panics with "report broken" + And "feed" is not called + + Scenario: An untimed overrun charges no plugin + Given the plugins "analytics", "reviews" and "feed" implement the hook "public.head-tags" + And the hook has a budget of 2 ms and times each plugin for 20 firings after an overrun + And "analytics" takes 3 ms + When the hook fires + Then the hook is counted 1 overrun + And no plugin is charged an overrun + And the hook is counted 0 timed overruns that no plugin is charged for + + Scenario: A timed overrun is charged to the slowest plugin + Given the plugins "reviews", "analytics" and "feed" implement the hook "public.head-tags" + And the hook has a budget of 2 ms and times each plugin for 20 firings after an overrun + And the hook has run over its budget once + When the hook fires while the plugins take + | plugin | ms | + | reviews | 0.5 | + | analytics | 1.2 | + | feed | 0.9 | + Then "analytics" is charged 1 overrun + And "reviews" and "feed" are charged no overrun + + Scenario: The time the report takes is not charged to the failing plugin + Given the plugins "reviews", "analytics" and "feed" implement the hook "public.head-tags" + And the hook has a budget of 2 ms and times each plugin for 20 firings after an overrun + And the report takes 1.5 ms + And "reviews" fails with "rating unavailable" + And the hook has run over its budget once + When the hook fires while the plugins take + | plugin | ms | + | reviews | 0.1 | + | analytics | 1.2 | + | feed | 0.9 | + Then "analytics" is charged 1 overrun + And "reviews" and "feed" are charged no overrun + And the hook is counted 0 timed overruns that no plugin is charged for + And the report is counted 1.5 ms in the timed firings + + Scenario: A firing that only the report runs over its budget charges no plugin + Given the plugins "reviews" and "analytics" implement the hook "public.head-tags" + And the hook has a budget of 2 ms and times each plugin for 20 firings after an overrun + And the report takes 3 ms + And "reviews" fails with "rating unavailable" + And the hook has run over its budget once + When the hook fires while the plugins take + | plugin | ms | + | reviews | 0.1 | + | analytics | 0.5 | + Then the hook is counted 2 overruns + And no plugin is charged an overrun + And the hook is counted 1 timed overrun that no plugin is charged for + And the report is counted 3 ms in the timed firings + + Scenario: Each plugin is timed only for the firings after an overrun + Given the plugins "analytics" and "feed" implement the hook "public.head-tags" + And the hook has a budget of 2 ms and times each plugin for 3 firings after an overrun + And the hook has run over its budget once + When the hook fires 5 times within its budget + Then "analytics" and "feed" are each timed in 3 firings + And no plugin is charged an overrun + + Scenario: An overrun among the timed firings starts the timing again in full + Given the plugins "analytics" and "feed" implement the hook "public.head-tags" + And the hook has a budget of 2 ms and times each plugin for 4 firings after an overrun + And the hook has run over its budget once + And the hook fires 2 times within its budget + And the hook has run over its budget once + When the hook fires 5 times within its budget + Then "analytics" and "feed" are each timed in 7 firings + + Scenario: A filter passes the value through every plugin + Given the plugins "brand" and "suffix" implement the filter hook "page.title" + And "brand" puts "Example: " before the title + And "suffix" puts " | Home" after the title + When the hook filters the title "Hello" + Then the title becomes "Example: Hello | Home" + + Scenario: A filter keeps the incoming value when a plugin fails or panics + Given the plugins "brand", "broken", "loud" and "suffix" implement the filter hook "page.title" + And "brand" puts "Example: " before the title + And "broken" fails with "no title" + And "loud" panics with "boom" + And "suffix" puts " | Home" after the title + When the hook filters the title "Hello" + Then the title becomes "Example: Hello | Home" diff --git a/pluginkit/features/steps_hooks_test.go b/pluginkit/features/steps_hooks_test.go new file mode 100644 index 0000000..530f2df --- /dev/null +++ b/pluginkit/features/steps_hooks_test.go @@ -0,0 +1,604 @@ +// SPDX-License-Identifier: Apache-2.0 + +package features_test + +import ( + "context" + "errors" + "fmt" + "regexp" + "slices" + "strings" + "testing" + "testing/synctest" + "time" + + "github.com/cucumber/godog" + + "github.com/gopherium/framework/pluginkit" +) + +// handler is the interface an action hook calls. +type handler interface { + Handle(ctx context.Context) error +} + +// titler is the interface a filter hook calls. +type titler interface { + Title(ctx context.Context, title string) (string, error) +} + +// identified is the least a plugin offers a hook. +type identified interface { + ID() string +} + +// quoted finds every quoted name in a list such as "a", "b" and "c". +var quoted = regexp.MustCompile(`"([^"]*)"`) + +// names returns the quoted names of list, in order. +func names(list string) []string { + var found []string + for _, match := range quoted.FindAllStringSubmatch(list, -1) { + found = append(found, match[1]) + } + return found +} + +// scenePlugin is a plugin of a scenario, doing what the scenario's steps tell it. +type scenePlugin struct { + id string + takes time.Duration + panics string + fail func(ctx context.Context) error + before, after string + world *hookWorld +} + +// ID returns the plugin's id. +func (p *scenePlugin) ID() string { + return p.id +} + +// Handle records the call, takes the plugin's time, then panics or fails as told. +func (p *scenePlugin) Handle(ctx context.Context) error { + p.world.calls = append(p.world.calls, p.id) + p.world.late[p.id] = ctx.Err() != nil + time.Sleep(p.takes) + if p.panics != "" { + panic(p.panics) + } + if p.fail != nil { + return p.fail(ctx) + } + return nil +} + +// Title handles the call, then returns title between the plugin's words, or nothing on a failure. +func (p *scenePlugin) Title(ctx context.Context, title string) (string, error) { + if err := p.Handle(ctx); err != nil { + return "", err + } + return p.before + title + p.after, nil +} + +// bystander is a plugin that implements no hook interface. +type bystander struct { + id string +} + +// ID returns the plugin's id. +func (b bystander) ID() string { + return b.id +} + +// unwrapPanics is an error whose Unwrap panics. +type unwrapPanics struct{} + +// Error returns the error's text. +func (unwrapPanics) Error() string { + return "index write failed" +} + +// Unwrap panics with the text unwrapped. +func (unwrapPanics) Unwrap() error { + panic("unwrapped") +} + +// hookWorld is the state of one scenario. +type hookWorld struct { + t *testing.T + name string + budget time.Duration + timedFirings int + plugins []identified + byID map[string]*scenePlugin + calls []string + late map[string]bool + failures []pluginkit.HookFailure + reportTakes time.Duration + reportPanics string + escaped any + actions *pluginkit.Hook[handler] + title string +} + +// hookWorldKey carries a scenario's world in its context. +type hookWorldKey struct{} + +// worldOf returns the world of the scenario ctx belongs to. +func worldOf(ctx context.Context) *hookWorld { + return ctx.Value(hookWorldKey{}).(*hookWorld) +} + +// plugin returns the plugin id of the scenario ctx belongs to, failing when the scenario never named it. +func plugin(ctx context.Context, id string) (*scenePlugin, error) { + if p, ok := worldOf(ctx).byID[id]; ok { + return p, nil + } + return nil, fmt.Errorf("no plugin %q in this scenario", id) +} + +// settings returns the hook settings of the scenario, reporting into its failures. +func (w *hookWorld) settings() pluginkit.HookSettings { + return pluginkit.HookSettings{Budget: w.budget, TimedFirings: w.timedFirings, Report: w.report} +} + +// report records failure, takes the scenario's report time, then panics when the scenario says so. +func (w *hookWorld) report(failure pluginkit.HookFailure) { + w.failures = append(w.failures, failure) + time.Sleep(w.reportTakes) + if w.reportPanics != "" { + panic(w.reportPanics) + } +} + +// hook builds the action hook of the scenario once and returns it. +func (w *hookWorld) hook() (*pluginkit.Hook[handler], error) { + if w.actions != nil { + return w.actions, nil + } + hook, err := pluginkit.NewHook[handler](w.name, w.plugins, w.settings()) + w.actions = hook + return hook, err +} + +// onFakeClock runs fn on a fake clock, so a scenario's times pass in no real time, keeping a panic that leaves fn. +func (w *hookWorld) onFakeClock(fn func()) { + synctest.Test(w.t, func(*testing.T) { + defer func() { + if escaped := recover(); escaped != nil { + w.escaped = escaped + } + }() + fn() + }) +} + +// hookStats returns the counters of the action hook, failing when it never fired. +func (w *hookWorld) hookStats() (pluginkit.HookStats, error) { + if w.actions == nil { + return pluginkit.HookStats{}, errors.New("the hook never fired") + } + return w.actions.Stats(), nil +} + +// statsOf returns the counters of the plugin id in the action hook. +func (w *hookWorld) statsOf(id string) (pluginkit.PluginStats, error) { + if w.actions == nil { + return pluginkit.PluginStats{}, errors.New("the hook never fired") + } + for _, stats := range w.actions.Stats().Plugins { + if stats.ID == id { + return stats, nil + } + } + return pluginkit.PluginStats{}, fmt.Errorf("no counters for %s", id) +} + +// implement registers the plugins of list, in order after any registered before, as implementing the hook name. +func implement(ctx context.Context, list, name string) { + w := worldOf(ctx) + w.name = name + for _, id := range names(list) { + p := &scenePlugin{id: id, world: w} + w.plugins = append(w.plugins, p) + w.byID[id] = p + } +} + +// registerBystander registers a plugin that implements no hook interface. +func registerBystander(ctx context.Context, id string) { + w := worldOf(ctx) + w.plugins = append(w.plugins, bystander{id: id}) +} + +// setBudget gives the hook a budget of text milliseconds, such as 1.9, read exactly. +func setBudget(ctx context.Context, text string) error { + budget, err := time.ParseDuration(text + "ms") + worldOf(ctx).budget = budget + return err +} + +// setTiming gives the hook a budget and a count of firings timed after an overrun. +func setTiming(ctx context.Context, text string, timedFirings int) error { + worldOf(ctx).timedFirings = timedFirings + return setBudget(ctx, text) +} + +// setTakes makes the plugin id take text milliseconds on each call. +func setTakes(ctx context.Context, id, text string) error { + p, err := plugin(ctx, id) + if err != nil { + return err + } + p.takes, err = time.ParseDuration(text + "ms") + return err +} + +// setFailure makes the plugin id fail with fail. +func setFailure(ctx context.Context, id string, fail func(ctx context.Context) error) error { + p, err := plugin(ctx, id) + if err == nil { + p.fail = fail + } + return err +} + +// failsWith makes the plugin id fail with its own error text. +func failsWith(ctx context.Context, id, text string) error { + return setFailure(ctx, id, func(context.Context) error { return errors.New(text) }) +} + +// failsWithEndedContext makes the plugin id fail with the error of its ended context, or with only its text. +func failsWithEndedContext(ctx context.Context, id, what string) error { + verb := "%w" + if what == "text" { + verb = "%v" + } + return setFailure(ctx, id, func(ctx context.Context) error { return fmt.Errorf("index write: "+verb, ctx.Err()) }) +} + +// failsWithPanickyUnwrap makes the plugin id fail with an error whose Unwrap panics. +func failsWithPanickyUnwrap(ctx context.Context, id string) error { + return setFailure(ctx, id, func(context.Context) error { return unwrapPanics{} }) +} + +// setReportTakes makes the report take text milliseconds on each failure. +func setReportTakes(ctx context.Context, text string) error { + takes, err := time.ParseDuration(text + "ms") + worldOf(ctx).reportTakes = takes + return err +} + +// reportPanicsWith makes the report panic with text on each failure. +func reportPanicsWith(ctx context.Context, text string) { + worldOf(ctx).reportPanics = text +} + +// panicsWith makes the plugin id panic with text. +func panicsWith(ctx context.Context, id, text string) error { + p, err := plugin(ctx, id) + if err == nil { + p.panics = text + } + return err +} + +// putsAround makes the plugin id put text before or after the title it filters. +func putsAround(ctx context.Context, id, text, where string) error { + p, err := plugin(ctx, id) + if err != nil { + return err + } + if where == "before" { + p.before = text + } else { + p.after = text + } + return nil +} + +// handle calls Handle on one plugin of the hook. +func handle(ctx context.Context, h handler) error { + return h.Handle(ctx) +} + +// fireTimes fires the action hook n times on the fake clock. +func fireTimes(ctx context.Context, n int) error { + w := worldOf(ctx) + hook, err := w.hook() + if err != nil { + return err + } + w.onFakeClock(func() { + for range n { + hook.Fire(context.Background(), handle) + } + }) + return nil +} + +// fire fires the action hook once. +func fire(ctx context.Context) error { + return fireTimes(ctx, 1) +} + +// overrunOnce fires the action hook once with every call taking twice its budget. +func overrunOnce(ctx context.Context) error { + w := worldOf(ctx) + hook, err := w.hook() + if err != nil { + return err + } + w.onFakeClock(func() { + hook.Fire(context.Background(), func(context.Context, handler) error { + time.Sleep(2 * w.budget) + return nil + }) + }) + return nil +} + +// fireWhileTaking fires the action hook once after giving each plugin of table the milliseconds beside it. +func fireWhileTaking(ctx context.Context, table *godog.Table) error { + for _, row := range table.Rows[1:] { + if err := setTakes(ctx, row.Cells[0].Value, row.Cells[1].Value); err != nil { + return err + } + } + return fire(ctx) +} + +// filterTitle passes title through the filter hook of the scenario. +func filterTitle(ctx context.Context, title string) error { + w := worldOf(ctx) + hook, err := pluginkit.NewHook[titler](w.name, w.plugins, w.settings()) + if err != nil { + return err + } + w.onFakeClock(func() { + w.title = pluginkit.Filter(context.Background(), hook, title, + func(ctx context.Context, t titler, title string) (string, error) { return t.Title(ctx, title) }) + }) + return nil +} + +// calledInOrder checks that the plugins of list, and no others, were called in that order. +func calledInOrder(ctx context.Context, list string) error { + if called, want := worldOf(ctx).calls, names(list); !slices.Equal(called, want) { + return fmt.Errorf("called %q, want %q", called, want) + } + return nil +} + +// notCalled checks that the plugin id was never called. +func notCalled(ctx context.Context, id string) error { + if slices.Contains(worldOf(ctx).calls, id) { + return fmt.Errorf("%s was called", id) + } + return nil +} + +// calledLate checks that every plugin of list was called after the firing's deadline had passed. +func calledLate(ctx context.Context, list string) error { + for _, id := range names(list) { + if !worldOf(ctx).late[id] { + return fmt.Errorf("%s was called before the deadline passed", id) + } + } + return nil +} + +// reportHolds checks that a reported failure has the text want, and the panicking plugin's stack only when named. +func reportHolds(ctx context.Context, want, stack string) error { + failures := worldOf(ctx).failures + for _, failure := range failures { + if failure.Err.Error() == want && strings.Contains(failure.Stack, "(*scenePlugin).Handle") == (stack != "") { + return nil + } + } + return fmt.Errorf("reported %+v, want %q%s", failures, want, stack) +} + +// reportMarksContextEnded checks that the failure of the plugin id is marked as caused by the ended context. +func reportMarksContextEnded(ctx context.Context, id string) error { + failures := worldOf(ctx).failures + for _, failure := range failures { + if failure.ID == id && failure.ContextEnded { + return nil + } + } + return fmt.Errorf("reported %+v, want a failure of %s marked as context ended", failures, id) +} + +// countedFailures checks the errors or panics counted for the plugin id. +func countedFailures(ctx context.Context, id string, want int, kind string) error { + stats, err := worldOf(ctx).statsOf(id) + if err != nil { + return err + } + got := stats.Errors + if kind == "panic" || kind == "panics" { + got = stats.Panics + } + if got != uint64(want) { + return fmt.Errorf("%s is counted %d %s, want %d", id, got, kind, want) + } + return nil +} + +// countedErrorsAndEnded checks the errors and the calls whose context ended counted for the plugin id. +func countedErrorsAndEnded(ctx context.Context, id string, errs, ended int) error { + stats, err := worldOf(ctx).statsOf(id) + if err != nil { + return err + } + if stats.Errors != uint64(errs) || stats.ContextEnded != uint64(ended) { + return fmt.Errorf("%s is counted %+v, want %d errors and %d calls whose context ended", id, stats, errs, ended) + } + return nil +} + +// hookOverruns checks the overruns counted on the hook. +func hookOverruns(ctx context.Context, want int) error { + stats, err := worldOf(ctx).hookStats() + if err == nil && stats.Overruns != uint64(want) { + err = fmt.Errorf("the hook is counted %d overruns, want %d", stats.Overruns, want) + } + return err +} + +// unchargedOverruns checks the timed overruns the hook counted with no plugin charged. +func unchargedOverruns(ctx context.Context, want int) error { + stats, err := worldOf(ctx).hookStats() + if err == nil && stats.UnchargedOverruns != uint64(want) { + err = fmt.Errorf("the hook is counted %d timed overruns that no plugin is charged for, want %d", + stats.UnchargedOverruns, want) + } + return err +} + +// reportTimed checks the time the report took in the timed firings, text milliseconds such as 1.5. +func reportTimed(ctx context.Context, text string) error { + stats, err := worldOf(ctx).hookStats() + if err != nil { + return err + } + want, err := time.ParseDuration(text + "ms") + if err == nil && stats.TimedReportTime != want { + err = fmt.Errorf("the report is counted %v in the timed firings, want %v", stats.TimedReportTime, want) + } + return err +} + +// chargedOverruns checks the overruns charged to the plugin id. +func chargedOverruns(ctx context.Context, id string, want int) error { + stats, err := worldOf(ctx).statsOf(id) + if err == nil && stats.Overruns != uint64(want) { + err = fmt.Errorf("%s is charged %d overruns, want %d", id, stats.Overruns, want) + } + return err +} + +// chargedNone checks that no plugin of list is charged an overrun. +func chargedNone(ctx context.Context, list string) error { + for _, id := range names(list) { + if err := chargedOverruns(ctx, id, 0); err != nil { + return err + } + } + return nil +} + +// noPluginCharged checks that no plugin of the hook is charged an overrun. +func noPluginCharged(ctx context.Context) error { + for id := range worldOf(ctx).byID { + if err := chargedOverruns(ctx, id, 0); err != nil { + return err + } + } + return nil +} + +// timedIn checks that every plugin of list was timed in want firings. +func timedIn(ctx context.Context, list string, want int) error { + for _, id := range names(list) { + stats, err := worldOf(ctx).statsOf(id) + if err == nil && stats.TimedCalls != uint64(want) { + err = fmt.Errorf("%s was timed in %d firings, want %d", id, stats.TimedCalls, want) + } + if err != nil { + return err + } + } + return nil +} + +// firingPanicked checks that a firing panicked with want, and takes that panic as expected. +func firingPanicked(ctx context.Context, want string) error { + w := worldOf(ctx) + if w.escaped != want { + return fmt.Errorf("the firing panicked with %v, want %q", w.escaped, want) + } + w.escaped = nil + return nil +} + +// noPanicLeft fails a scenario whose firing panicked when no step expected it. +func noPanicLeft(ctx context.Context, _ *godog.Scenario, _ error) (context.Context, error) { + if escaped := worldOf(ctx).escaped; escaped != nil { + return ctx, fmt.Errorf("a firing panicked with %v", escaped) + } + return ctx, nil +} + +// titleBecomes checks the title the filter returned. +func titleBecomes(ctx context.Context, want string) error { + if got := worldOf(ctx).title; got != want { + return fmt.Errorf("the title became %q, want %q", got, want) + } + return nil +} + +// initializeHooks returns the steps of the hooks feature, each scenario with its own world on t's fake clock. +func initializeHooks(t *testing.T) func(*godog.ScenarioContext) { + return func(sc *godog.ScenarioContext) { + sc.Before(func(ctx context.Context, _ *godog.Scenario) (context.Context, error) { + w := &hookWorld{ + t: t, budget: time.Hour, timedFirings: 20, byID: map[string]*scenePlugin{}, late: map[string]bool{}, + } + return context.WithValue(ctx, hookWorldKey{}, w), nil + }) + sc.After(noPanicLeft) + givenHooks(sc) + whenHooks(sc) + thenHooks(sc) + } +} + +// givenHooks registers the steps that set a scenario up. +func givenHooks(sc *godog.ScenarioContext) { + sc.Step(`^the plugins? (.+) implements? the (?:filter )?hook "([^"]*)"$`, implement) + sc.Step(`^the plugin "([^"]*)" is registered without implementing it$`, registerBystander) + sc.Step(`^the hook has a budget of (\S+) ms$`, setBudget) + sc.Step(`^the hook has a budget of (\S+) ms and times each plugin for (\d+) firings after an overrun$`, setTiming) + sc.Step(`^"([^"]*)" takes (\S+) ms$`, setTakes) + sc.Step(`^"([^"]*)" fails with "([^"]*)"$`, failsWith) + sc.Step(`^"([^"]*)" fails with the (error|text) of its ended context(?: but not the error itself)?$`, + failsWithEndedContext) + sc.Step(`^"([^"]*)" fails with an error that panics when it is unwrapped$`, failsWithPanickyUnwrap) + sc.Step(`^the report takes (\S+) ms$`, setReportTakes) + sc.Step(`^the report panics with "([^"]*)"$`, reportPanicsWith) + sc.Step(`^"([^"]*)" panics with "([^"]*)"$`, panicsWith) + sc.Step(`^"([^"]*)" puts "([^"]*)" (before|after) the title$`, putsAround) + sc.Step(`^the hook has run over its budget once$`, overrunOnce) +} + +// whenHooks registers the steps that fire a scenario's hook. +func whenHooks(sc *godog.ScenarioContext) { + sc.Step(`^the hook fires$`, fire) + sc.Step(`^the hook fires (\d+) times within its budget$`, fireTimes) + sc.Step(`^the hook fires while the plugins take$`, fireWhileTaking) + sc.Step(`^the hook filters the title "([^"]*)"$`, filterTitle) +} + +// thenHooks registers the steps that check what a scenario's firing did. +func thenHooks(sc *godog.ScenarioContext) { + sc.Step(`^(.+) are called in that order$`, calledInOrder) + sc.Step(`^"([^"]*)" is not called$`, notCalled) + sc.Step(`^(.+) are called after the deadline passed$`, calledLate) + sc.Step(`^the report holds "([^"]*)"( with the stack of the panic)?$`, reportHolds) + sc.Step(`^the report marks the failure of "([^"]*)" as caused by the ended context$`, reportMarksContextEnded) + sc.Step(`^"([^"]*)" is counted (\d+) (errors?|panics?)$`, countedFailures) + sc.Step(`^"([^"]*)" is counted (\d+) errors? and (\d+) calls? whose context ended$`, countedErrorsAndEnded) + sc.Step(`^the hook is counted (\d+) overruns?$`, hookOverruns) + sc.Step(`^"([^"]*)" is charged (\d+) overruns?$`, chargedOverruns) + sc.Step(`^(.+) are charged no overrun$`, chargedNone) + sc.Step(`^no plugin is charged an overrun$`, noPluginCharged) + sc.Step(`^the hook is counted (\d+) timed overruns? that no plugin is charged for$`, unchargedOverruns) + sc.Step(`^the report is counted (\S+) ms in the timed firings$`, reportTimed) + sc.Step(`^(.+) are each timed in (\d+) firings$`, timedIn) + sc.Step(`^the firing panics with "([^"]*)"$`, firingPanicked) + sc.Step(`^the title becomes "([^"]*)"$`, titleBecomes) +} diff --git a/pluginkit/hook.go b/pluginkit/hook.go new file mode 100644 index 0000000..134bfe5 --- /dev/null +++ b/pluginkit/hook.go @@ -0,0 +1,317 @@ +// SPDX-License-Identifier: Apache-2.0 + +package pluginkit + +import ( + "context" + "errors" + "fmt" + "reflect" + "runtime/debug" + "sync/atomic" + "time" +) + +// HookSettings are the values a hook runs under, each one required. +type HookSettings struct { + // Budget is the time one firing gives all its plugins together, the time of Report included. + Budget time.Duration + // TimedFirings is how many firings after an overrun time each plugin. + TimedFirings int + // Report receives every error and panic of a plugin inside the firing, from any goroutine at once, and must not panic. + Report func(HookFailure) +} + +// HookFailure is one error or panic of one plugin in one firing of a hook. +type HookFailure struct { + Hook string + ID string + // Panicked is true for a panic the hook recovered. + Panicked bool + // ContextEnded is true for an error that matches the firing's context after that context ended. + ContextEnded bool + // Err names the plugin and the hook, and for an error wraps the plugin's error, whose methods are the plugin's code. + Err error + // Stack is the stack of a panic, and empty for an error. + Stack string +} + +// HookStats are the counters of a hook, its plugins in registration order. +type HookStats struct { + Name string + Firings uint64 + Overruns uint64 + // UnchargedOverruns counts the timed firings that ran over their budget while their plugins together kept it. + UnchargedOverruns uint64 + // TimedReportTime is the total time Report took in the timed firings. + TimedReportTime time.Duration + Plugins []PluginStats +} + +// PluginStats are the counters of one plugin in one hook. +type PluginStats struct { + ID string + Errors uint64 + Panics uint64 + ContextEnded uint64 + // Overruns counts the timed firings whose plugins together ran over the budget, with this plugin as the slowest. + Overruns uint64 + // TimedCalls counts the calls timed while firings were timed after an overrun. + TimedCalls uint64 + // TimedTime is the total time of those calls, without the time Report took. + TimedTime time.Duration +} + +// pluginCounters are the live counters of one plugin in one hook. +type pluginCounters struct { + errors, panics, contextEnded, overruns, timedCalls atomic.Uint64 + timedTime atomic.Int64 +} + +// Hook calls, in registration order, the plugins that implement the interface C. +type Hook[C any] struct { + name string + settings HookSettings + ids []string + plugins []C + counters []pluginCounters + firings atomic.Uint64 + overruns atomic.Uint64 + timed atomic.Int64 + + uncharged atomic.Uint64 + reportTime atomic.Int64 +} + +// NewHook returns the hook called name over the plugins that implement C, refusing what it cannot run under. +func NewHook[C any, P interface{ ID() string }](name string, plugins []P, settings HookSettings) (*Hook[C], error) { + if err := checkHook(name, settings, reflect.TypeFor[C]()); err != nil { + return nil, err + } + hook := &Hook[C]{name: name, settings: settings} + seen := make(map[string]struct{}, len(plugins)) + for _, p := range plugins { + id := p.ID() + if _, ok := seen[id]; ok { + return nil, fmt.Errorf("pluginkit: hook %s: duplicate id %q", name, id) + } + seen[id] = struct{}{} + if plugin, ok := any(p).(C); ok { + hook.ids = append(hook.ids, id) + hook.plugins = append(hook.plugins, plugin) + } + } + hook.counters = make([]pluginCounters, len(hook.plugins)) + return hook, nil +} + +// checkHook refuses a hook name, settings or interface type a hook cannot run under. +func checkHook(name string, settings HookSettings, hookType reflect.Type) error { + if name == "" { + return errors.New("pluginkit: the hook name is empty") + } + if settings.Budget <= 0 { + return fmt.Errorf("pluginkit: hook %s: the budget must stand above zero, got %v", name, settings.Budget) + } + if settings.TimedFirings <= 0 { + return fmt.Errorf("pluginkit: hook %s: the timed firings must stand above zero, got %d", + name, settings.TimedFirings) + } + if settings.Report == nil { + return fmt.Errorf("pluginkit: hook %s: the report is nil", name) + } + if hookType.Kind() != reflect.Interface { + return fmt.Errorf("pluginkit: hook %s: %v is not an interface", name, hookType) + } + return nil +} + +// Fire calls call on every plugin of the hook in order, under one budget, past any plugin's error or panic. +func (h *Hook[C]) Fire(ctx context.Context, call func(ctx context.Context, plugin C) error) { + if len(h.plugins) == 0 { + return + } + h.fire(ctx, call) +} + +// Filter passes value through every plugin of hook in order, keeping the incoming value on an error or a panic. +func Filter[C, V any](ctx context.Context, hook *Hook[C], value V, + call func(ctx context.Context, plugin C, value V) (V, error)) V { + if len(hook.plugins) == 0 { + return value + } + hook.fire(ctx, func(ctx context.Context, plugin C) error { + next, err := call(ctx, plugin, value) + if err == nil { + value = next + } + return err + }) + return value +} + +// Stats returns the counters of the hook and of each of its plugins. +func (h *Hook[C]) Stats() HookStats { + stats := HookStats{ + Name: h.name, + Firings: h.firings.Load(), + Overruns: h.overruns.Load(), + UnchargedOverruns: h.uncharged.Load(), + TimedReportTime: time.Duration(h.reportTime.Load()), + Plugins: make([]PluginStats, len(h.ids)), + } + for i, id := range h.ids { + c := &h.counters[i] + stats.Plugins[i] = PluginStats{ + ID: id, + Errors: c.errors.Load(), + Panics: c.panics.Load(), + ContextEnded: c.contextEnded.Load(), + Overruns: c.overruns.Load(), + TimedCalls: c.timedCalls.Load(), + TimedTime: time.Duration(c.timedTime.Load()), + } + } + return stats +} + +// fire runs one firing, counting an overrun, charged to the slowest plugin when timed plugins ran over together. +func (h *Hook[C]) fire(ctx context.Context, call func(context.Context, C) error) { + h.firings.Add(1) + began := time.Now() + ctx, cancel := context.WithDeadline(ctx, began.Add(h.settings.Budget)) + defer cancel() + timed, slowest := h.takeTimedFiring(), -1 + if timed { + slowest = h.callTimed(ctx, call) + } else { + for i, plugin := range h.plugins { + h.report(i, run(ctx, plugin, call)) + } + } + if time.Since(began) <= h.settings.Budget { + return + } + h.overruns.Add(1) + if slowest >= 0 { + h.counters[slowest].overruns.Add(1) + } else if timed { + h.uncharged.Add(1) + } + h.timed.Store(int64(h.settings.TimedFirings)) +} + +// takeTimedFiring reports whether this firing is one of those timed after an overrun, using one up. +func (h *Hook[C]) takeTimedFiring() bool { + for { + left := h.timed.Load() + if left <= 0 { + return false + } + if h.timed.CompareAndSwap(left, left-1) { + return true + } + } +} + +// callTimed calls and times every plugin in order, returning the slowest, or -1 when together they kept the budget. +func (h *Hook[C]) callTimed(ctx context.Context, call func(context.Context, C) error) int { + slowest, longest, total := 0, time.Duration(0), time.Duration(0) + for i, plugin := range h.plugins { + began := time.Now() + out := run(ctx, plugin, call) + took := time.Since(began) + total += took + h.counters[i].timedCalls.Add(1) + h.counters[i].timedTime.Add(int64(took)) + if took > longest { + slowest, longest = i, took + } + h.reportTime.Add(int64(h.report(i, out))) + } + if total <= h.settings.Budget { + return -1 + } + return slowest +} + +// report counts and reports what went wrong in one call of plugin i, if anything did, returning the time Report took. +func (h *Hook[C]) report(i int, out *outcome) time.Duration { + if out == nil { + return 0 + } + failure := h.failureOf(i, out) + began := time.Now() + h.settings.Report(failure) + return time.Since(began) +} + +// failureOf counts what went wrong in a call of plugin i and returns it as the failure Report receives. +func (h *Hook[C]) failureOf(i int, out *outcome) HookFailure { + failure := HookFailure{Hook: h.name, ID: h.ids[i]} + counters := &h.counters[i] + named := "pluginkit: " + failure.ID + " " + h.name + if out.panicked { + failure.Panicked, failure.Stack = true, out.stack + failure.Err = panicError(named + " panicked: " + out.text) + counters.panics.Add(1) + return failure + } + failure.Err = &pluginError{text: named + ": " + out.text, err: out.err} + failure.ContextEnded = out.ended + if failure.ContextEnded { + counters.contextEnded.Add(1) + } else { + counters.errors.Add(1) + } + return failure +} + +// outcome is what went wrong in one call of a plugin, a panic with its stack or an error, with its text. +type outcome struct { + panicked bool + stack string + text string + err error + // ended is true for an error that matches the firing's context after that context ended. + ended bool +} + +// run calls one plugin inside a recover, answering nil when the call succeeded, else what went wrong. +func run[C any](ctx context.Context, plugin C, call func(context.Context, C) error) (out *outcome) { + defer func() { + if recovered := recover(); recovered != nil { + out = &outcome{panicked: true, stack: string(debug.Stack()), text: describe(recovered)} + } + }() + if err := call(ctx, plugin); err != nil { + return &outcome{err: err, text: describe(err), ended: ctx.Err() != nil && errors.Is(err, ctx.Err())} + } + return nil +} + +// describe returns v as fmt prints it, or its type when printing it panics. +func describe(v any) (text string) { + defer func() { + if recover() != nil { + text = fmt.Sprintf("%T whose text panicked", v) + } + }() + return fmt.Sprint(v) +} + +// pluginError is a plugin's error with the plugin and the hook named before its text. +type pluginError struct { + text string + err error +} + +// Error returns the error's text. +func (e *pluginError) Error() string { + return e.text +} + +// Unwrap returns the plugin's own error. +func (e *pluginError) Unwrap() error { + return e.err +} diff --git a/pluginkit/hook_budget_test.go b/pluginkit/hook_budget_test.go new file mode 100644 index 0000000..1eb8e86 --- /dev/null +++ b/pluginkit/hook_budget_test.go @@ -0,0 +1,579 @@ +// SPDX-License-Identifier: Apache-2.0 + +package pluginkit_test + +import ( + "context" + "errors" + "fmt" + "runtime" + "strings" + "testing" + "testing/synctest" + "time" + + "github.com/gopherium/framework/pluginkit" +) + +// budget is the time one firing of the test hooks gives all their plugins. +const budget = 2 * time.Millisecond + +// timedHook builds a hook with budget that times each plugin for timedFirings firings after an overrun. +func timedHook(t *testing.T, timedFirings int, plugins ...identified) (*pluginkit.Hook[greeter], *reports) { + t.Helper() + r := &reports{} + return greetHook(t, settingsOf(budget, timedFirings, r), plugins...), r +} + +// overrunOnce fires hook once with every call taking twice the budget. +func overrunOnce(t *testing.T, hook *pluginkit.Hook[greeter]) { + t.Helper() + hook.Fire(t.Context(), func(context.Context, greeter) error { + time.Sleep(2 * budget) + return nil + }) +} + +// fireTimes fires hook n times. +func fireTimes(t *testing.T, hook *pluginkit.Hook[greeter], n int) { + t.Helper() + for range n { + hook.Fire(t.Context(), greet) + } +} + +func TestAFiringRunsUnderOneDeadlineOfItsBudget(t *testing.T) { + t.Parallel() + + synctest.Test(t, func(t *testing.T) { + var afterStart []time.Duration + hook, _ := timedHook(t, 20, &hookPlugin{id: "alpha", takes: budget / 2, log: &callLog{}}, + &hookPlugin{id: "beta", log: &callLog{}}) + began := time.Now() + + hook.Fire(t.Context(), func(ctx context.Context, g greeter) error { + deadline, ok := ctx.Deadline() + if !ok { + t.Error("a plugin got a context with no deadline") + } + afterStart = append(afterStart, deadline.Sub(began)) + return g.Greet(ctx) + }) + + wantEqual(t, "deadlines after the start", afterStart, []time.Duration{budget, budget}) + }) +} + +func TestThePluginsAfterASlowOneAreStillCalled(t *testing.T) { + t.Parallel() + + synctest.Test(t, func(t *testing.T) { + log := &callLog{} + hook, r := timedHook(t, 20, &hookPlugin{id: "analytics", takes: 5 * time.Millisecond, log: log}, + &hookPlugin{id: "feed", log: log}) + + hook.Fire(t.Context(), greet) + + wantEqual(t, "called", log.called(), []string{"analytics", "feed"}) + wantEqual(t, "called after the deadline", log.late, []bool{false, true}) + if stats := hook.Stats(); stats.Overruns != 1 { + t.Errorf("Stats().Overruns = %d, want 1", stats.Overruns) + } + if got := r.all(); len(got) != 0 { + t.Errorf("reported %+v, want nothing, since no plugin failed", got) + } + }) +} + +func TestAFiringThatRunsPastItsOwnDeadlineIsAnOverrun(t *testing.T) { + t.Parallel() + + const firings = 100 + hook := greetHook(t, settingsOf(20*time.Microsecond, 20, &reports{}), &hookPlugin{id: "alpha", log: &callLog{}}) + + for range firings { + hook.Fire(t.Context(), func(ctx context.Context, _ greeter) error { + deadline, _ := ctx.Deadline() + for !time.Now().After(deadline) { + runtime.Gosched() + } + return nil + }) + } + + if got := hook.Stats().Overruns; got != firings { + t.Errorf("Stats().Overruns = %d, want %d, one for each firing that ran past its deadline", got, firings) + } +} + +func TestACallerDeadlineBeforeTheBudgetIsNoOverrun(t *testing.T) { + t.Parallel() + + synctest.Test(t, func(t *testing.T) { + ctx, cancel := context.WithTimeout(t.Context(), 500*time.Microsecond) + defer cancel() + hook, _ := timedHook(t, 20, &hookPlugin{id: "alpha", takes: 1500 * time.Microsecond, log: &callLog{}}) + + hook.Fire(ctx, greet) + + if got := hook.Stats().Overruns; got != 0 { + t.Errorf("Stats().Overruns = %d, want 0, since the firing stayed inside its budget", got) + } + }) +} + +func TestAFiringThatTakesExactlyItsBudgetIsNoOverrun(t *testing.T) { + t.Parallel() + + synctest.Test(t, func(t *testing.T) { + hook, _ := timedHook(t, 20, &hookPlugin{id: "alpha", takes: budget, log: &callLog{}}) + + hook.Fire(t.Context(), greet) + + if stats := hook.Stats(); stats.Overruns != 0 { + t.Errorf("Stats().Overruns = %d, want 0", stats.Overruns) + } + }) +} + +func TestAnUntimedOverrunChargesNoPlugin(t *testing.T) { + t.Parallel() + + synctest.Test(t, func(t *testing.T) { + hook, _ := timedHook(t, 20, &hookPlugin{id: "analytics", takes: 3 * time.Millisecond, log: &callLog{}}) + + hook.Fire(t.Context(), greet) + + wantEqual(t, "Stats()", hook.Stats(), pluginkit.HookStats{ + Name: "content.changed", Firings: 1, Overruns: 1, Plugins: []pluginkit.PluginStats{{ID: "analytics"}}, + }) + }) +} + +func TestTheFiringsAfterAnOverrunTimeEachPlugin(t *testing.T) { + t.Parallel() + + tests := map[string]struct { + timedFirings, fires int + alpha, beta time.Duration + want []pluginkit.PluginStats + }{ + "for one firing when the setting says one": {1, 3, budget / 4, budget / 2, []pluginkit.PluginStats{ + {ID: "alpha", TimedCalls: 1, TimedTime: budget / 4}, + {ID: "beta", TimedCalls: 1, TimedTime: budget / 2}, + }}, + "for as many firings as the setting says": {3, 5, budget / 4, budget / 2, []pluginkit.PluginStats{ + {ID: "alpha", TimedCalls: 3, TimedTime: 3 * budget / 4}, + {ID: "beta", TimedCalls: 3, TimedTime: 3 * budget / 2}, + }}, + "charging an overrun between equal plugins to the first": {20, 1, budget, budget, []pluginkit.PluginStats{ + {ID: "alpha", Overruns: 1, TimedCalls: 1, TimedTime: budget}, + {ID: "beta", TimedCalls: 1, TimedTime: budget}, + }}, + } + for name, tc := range tests { + t.Run(name, func(t *testing.T) { + t.Parallel() + + synctest.Test(t, func(t *testing.T) { + hook, _ := timedHook(t, tc.timedFirings, &hookPlugin{id: "alpha", takes: tc.alpha, log: &callLog{}}, + &hookPlugin{id: "beta", takes: tc.beta, log: &callLog{}}) + overrunOnce(t, hook) + + fireTimes(t, hook, tc.fires) + + wantEqual(t, "Stats().Plugins", hook.Stats().Plugins, tc.want) + }) + }) + } +} + +func TestAnOverrunInsideTheWindowOpensItAgain(t *testing.T) { + t.Parallel() + + synctest.Test(t, func(t *testing.T) { + slow := &hookPlugin{id: "alpha", log: &callLog{}} + hook, _ := timedHook(t, 3, slow) + overrunOnce(t, hook) + fireTimes(t, hook, 1) + slow.takes = 2 * budget + fireTimes(t, hook, 1) + slow.takes = 0 + + fireTimes(t, hook, 5) + + wantEqual(t, "alpha's counters", statsByID(hook)["alpha"], pluginkit.PluginStats{ + ID: "alpha", Overruns: 1, TimedCalls: 5, TimedTime: 2 * budget, + }) + }) +} + +func TestATimedOverrunIsChargedToTheSlowestPlugin(t *testing.T) { + t.Parallel() + + synctest.Test(t, func(t *testing.T) { + hook, _ := timedHook(t, 20, + &hookPlugin{id: "reviews", takes: 500 * time.Microsecond, log: &callLog{}}, + &hookPlugin{id: "analytics", takes: 1200 * time.Microsecond, log: &callLog{}}, + &hookPlugin{id: "feed", takes: 900 * time.Microsecond, log: &callLog{}}) + overrunOnce(t, hook) + + fireTimes(t, hook, 1) + + wantEqual(t, "Stats()", hook.Stats(), pluginkit.HookStats{ + Name: "content.changed", Firings: 2, Overruns: 2, Plugins: []pluginkit.PluginStats{ + {ID: "reviews", TimedCalls: 1, TimedTime: 500 * time.Microsecond}, + {ID: "analytics", Overruns: 1, TimedCalls: 1, TimedTime: 1200 * time.Microsecond}, + {ID: "feed", TimedCalls: 1, TimedTime: 900 * time.Microsecond}, + }, + }) + }) +} + +func TestATimedOverrunIsChargedToTheSlowestOfThatFiringOnly(t *testing.T) { + t.Parallel() + + synctest.Test(t, func(t *testing.T) { + alpha := &hookPlugin{id: "alpha", takes: 1500 * time.Microsecond, log: &callLog{}} + beta := &hookPlugin{id: "beta", log: &callLog{}} + hook, _ := timedHook(t, 20, alpha, beta) + overrunOnce(t, hook) + fireTimes(t, hook, 1) + alpha.takes, beta.takes = 600*time.Microsecond, 1600*time.Microsecond + + fireTimes(t, hook, 1) + + wantEqual(t, "Stats().Plugins", hook.Stats().Plugins, []pluginkit.PluginStats{ + {ID: "alpha", TimedCalls: 2, TimedTime: 2100 * time.Microsecond}, + {ID: "beta", Overruns: 1, TimedCalls: 2, TimedTime: 1600 * time.Microsecond}, + }) + }) +} + +// slowText is an error whose text takes 3 ms to build. +type slowText struct{} + +// Error returns the error's text after 3 ms. +func (slowText) Error() string { + time.Sleep(3 * time.Millisecond) + return "rating unavailable" +} + +func TestTheTimeOfReportIsLeftOutOfThePluginsTime(t *testing.T) { + t.Parallel() + + tests := map[string]struct { + err error + panics any + reviews, analytics time.Duration + uncharged uint64 + want []pluginkit.PluginStats + }{ + "so a firing that only Report runs over charges no plugin": { + errors.New("rating unavailable"), nil, 0, 500 * time.Microsecond, 1, []pluginkit.PluginStats{ + {ID: "reviews", Errors: 1, TimedCalls: 1}, + {ID: "analytics", TimedCalls: 1, TimedTime: 500 * time.Microsecond}, + }, + }, + "so plugins that together take exactly the budget charge none": { + errors.New("rating unavailable"), nil, budget, 0, 1, []pluginkit.PluginStats{ + {ID: "reviews", Errors: 1, TimedCalls: 1, TimedTime: budget}, + {ID: "analytics", TimedCalls: 1}, + }, + }, + "so plugins that together run over charge the slowest of their own times": { + errors.New("rating unavailable"), nil, 200 * time.Microsecond, 1900 * time.Microsecond, 0, + []pluginkit.PluginStats{ + {ID: "reviews", Errors: 1, TimedCalls: 1, TimedTime: 200 * time.Microsecond}, + {ID: "analytics", Overruns: 1, TimedCalls: 1, TimedTime: 1900 * time.Microsecond}, + }, + }, + "but the time of the plugin's own error text stays the plugin's": { + slowText{}, nil, 0, 500 * time.Microsecond, 0, []pluginkit.PluginStats{ + {ID: "reviews", Errors: 1, Overruns: 1, TimedCalls: 1, TimedTime: 3 * time.Millisecond}, + {ID: "analytics", TimedCalls: 1, TimedTime: 500 * time.Microsecond}, + }, + }, + "and so does the time of the text of its panic": { + nil, slowText{}, 0, 500 * time.Microsecond, 0, []pluginkit.PluginStats{ + {ID: "reviews", Panics: 1, Overruns: 1, TimedCalls: 1, TimedTime: 3 * time.Millisecond}, + {ID: "analytics", TimedCalls: 1, TimedTime: 500 * time.Microsecond}, + }, + }, + } + for name, tc := range tests { + t.Run(name, func(t *testing.T) { + t.Parallel() + + synctest.Test(t, func(t *testing.T) { + settings := pluginkit.HookSettings{Budget: budget, TimedFirings: 20, Report: func(pluginkit.HookFailure) { + time.Sleep(3 * time.Millisecond) + }} + hook := greetHook(t, settings, + &hookPlugin{id: "reviews", takes: tc.reviews, fail: failWith(tc.err), panics: tc.panics, log: &callLog{}}, + &hookPlugin{id: "analytics", takes: tc.analytics, log: &callLog{}}) + overrunOnce(t, hook) + + fireTimes(t, hook, 1) + + wantEqual(t, "Stats()", hook.Stats(), pluginkit.HookStats{ + Name: "content.changed", Firings: 2, Overruns: 2, UnchargedOverruns: tc.uncharged, + TimedReportTime: 3 * time.Millisecond, Plugins: tc.want, + }) + }) + }) + } +} + +func TestAFiringThatOnlyReportRunsOverTimesTheFiringsAfterIt(t *testing.T) { + t.Parallel() + + tests := map[string]struct { + timed bool + want pluginkit.HookStats + }{ + "from an untimed firing, counting no timed overrun or report time": {false, pluginkit.HookStats{ + Name: "content.changed", Firings: 6, Overruns: 1, + Plugins: []pluginkit.PluginStats{{ID: "alpha", Errors: 6, TimedCalls: 3}}, + }}, + "from a timed firing, in full again": {true, pluginkit.HookStats{ + Name: "content.changed", Firings: 7, Overruns: 2, UnchargedOverruns: 1, TimedReportTime: 3 * time.Millisecond, + Plugins: []pluginkit.PluginStats{{ID: "alpha", Errors: 6, TimedCalls: 4}}, + }}, + } + for name, tc := range tests { + t.Run(name, func(t *testing.T) { + t.Parallel() + + synctest.Test(t, func(t *testing.T) { + reportTakes := 3 * time.Millisecond + settings := pluginkit.HookSettings{Budget: budget, TimedFirings: 3, Report: func(pluginkit.HookFailure) { + time.Sleep(reportTakes) + }} + hook := greetHook(t, settings, + &hookPlugin{id: "alpha", fail: failWith(errors.New("index unavailable")), log: &callLog{}}) + if tc.timed { + overrunOnce(t, hook) + } + fireTimes(t, hook, 1) + reportTakes = 0 + + fireTimes(t, hook, 5) + + wantEqual(t, "Stats()", hook.Stats(), tc.want) + }) + }) + } +} + +func TestAPanicInReportLeavesFire(t *testing.T) { + t.Parallel() + + for name, timed := range map[string]bool{"an untimed firing": false, "a timed firing": true} { + t.Run(name, func(t *testing.T) { + t.Parallel() + + synctest.Test(t, func(t *testing.T) { + log := &callLog{} + settings := pluginkit.HookSettings{Budget: budget, TimedFirings: 20, Report: func(pluginkit.HookFailure) { + panic("report broken") + }} + hook := greetHook(t, settings, + &hookPlugin{id: "alpha", fail: failWith(errors.New("index unavailable")), log: log}, + &hookPlugin{id: "beta", log: log}) + if timed { + overrunOnce(t, hook) + } + + defer func() { + if got := recover(); got != "report broken" { + t.Errorf("Fire() panicked with %v, want the panic of Report", got) + } + wantEqual(t, "called", log.called(), []string{"alpha"}) + }() + hook.Fire(t.Context(), greet) + }) + }) + } +} + +func TestAPluginThatRunsIntoTheDeadlineAndReturnsItsErrorCountsAsContextEnded(t *testing.T) { + t.Parallel() + + synctest.Test(t, func(t *testing.T) { + hook, _ := timedHook(t, 20, &hookPlugin{ + id: "search", takes: 3 * time.Millisecond, fail: func(ctx context.Context) error { return ctx.Err() }, + log: &callLog{}, + }) + + hook.Fire(t.Context(), greet) + + wantEqual(t, "search's counters", statsByID(hook)["search"], pluginkit.PluginStats{ID: "search", ContextEnded: 1}) + }) +} + +func TestAFiringAfterAnOverrunKeepsTheOrderTheDeadlineAndTheRecover(t *testing.T) { + t.Parallel() + + synctest.Test(t, func(t *testing.T) { + log := &callLog{} + hook, r := timedHook(t, 20, &hookPlugin{id: "analytics", takes: 3 * time.Millisecond, log: log}, + &hookPlugin{id: "search", fail: func(ctx context.Context) error { return ctx.Err() }, log: log}, + &hookPlugin{id: "feed", fail: failWith(errors.New("feed unavailable")), log: log}, + &hookPlugin{id: "seo", panics: "boom", log: log}) + overrunOnce(t, hook) + + hook.Fire(t.Context(), greet) + + wantEqual(t, "called", log.called(), []string{"analytics", "search", "feed", "seo"}) + wantEqual(t, "called after the deadline", log.late, []bool{false, true, true, true}) + wantEqual(t, "Stats().Plugins", hook.Stats().Plugins, []pluginkit.PluginStats{ + {ID: "analytics", Overruns: 1, TimedCalls: 1, TimedTime: 3 * time.Millisecond}, + {ID: "search", ContextEnded: 1, TimedCalls: 1}, + {ID: "feed", Errors: 1, TimedCalls: 1}, + {ID: "seo", Panics: 1, TimedCalls: 1}, + }) + wantEqual(t, "reported", shapesOf(r.all()), []failureShape{ + { + Hook: "content.changed", ID: "search", ContextEnded: true, + Err: "pluginkit: search content.changed: context deadline exceeded", + }, + {Hook: "content.changed", ID: "feed", Err: "pluginkit: feed content.changed: feed unavailable"}, + { + Hook: "content.changed", ID: "seo", Err: "pluginkit: seo content.changed panicked: boom", + Panicked: true, Stacked: true, + }, + }) + }) +} + +// endedErrorCase is what one plugin returns after the firing's deadline, the counters and the report that follow. +type endedErrorCase struct { + fail func(ctx context.Context) error + counters pluginkit.PluginStats + failure failureShape +} + +// endedErrorCases lists the errors a plugin can return once the deadline has passed. +func endedErrorCases() map[string]endedErrorCase { + ended := pluginkit.PluginStats{ID: "search", ContextEnded: 1} + failed := pluginkit.PluginStats{ID: "search", Errors: 1} + return map[string]endedErrorCase{ + "the context's error": { + fail: func(ctx context.Context) error { return ctx.Err() }, counters: ended, + failure: failureShape{ContextEnded: true, Err: "context deadline exceeded"}, + }, + "the context's error wrapped": { + fail: func(ctx context.Context) error { return fmt.Errorf("index write: %w", ctx.Err()) }, + counters: ended, failure: failureShape{ContextEnded: true, Err: "index write: context deadline exceeded"}, + }, + "an error of its own": { + fail: failWith(errors.New("index unavailable")), counters: failed, + failure: failureShape{Err: "index unavailable"}, + }, + "the context's text without the error": { + fail: func(ctx context.Context) error { return fmt.Errorf("index write: %v", ctx.Err()) }, + counters: failed, failure: failureShape{Err: "index write: context deadline exceeded"}, + }, + "another context's error": { + fail: failWith(context.Canceled), counters: failed, failure: failureShape{Err: "context canceled"}, + }, + } +} + +func TestAnErrorAfterTheDeadlineCountsAsContextEndedOnlyWhenItIsTheContextsError(t *testing.T) { + t.Parallel() + + for name, tc := range endedErrorCases() { + t.Run(name, func(t *testing.T) { + t.Parallel() + + synctest.Test(t, func(t *testing.T) { + hook, r := timedHook(t, 20, &hookPlugin{id: "analytics", takes: 5 * time.Millisecond, log: &callLog{}}, + &hookPlugin{id: "search", fail: tc.fail, log: &callLog{}}) + + hook.Fire(t.Context(), greet) + + wantEqual(t, "search's counters", statsByID(hook)["search"], tc.counters) + want := tc.failure + want.Hook, want.ID, want.Err = "content.changed", "search", "pluginkit: search content.changed: "+want.Err + wantEqual(t, "reported", shapesOf(r.all()), []failureShape{want}) + }) + }) + } +} + +func TestTheContextsErrorBeforeTheDeadlineCountsAsAnError(t *testing.T) { + t.Parallel() + + synctest.Test(t, func(t *testing.T) { + hook, _ := timedHook(t, 20, &hookPlugin{id: "search", fail: failWith(context.DeadlineExceeded), log: &callLog{}}) + + hook.Fire(t.Context(), greet) + + if search := statsByID(hook)["search"]; search.Errors != 1 || search.ContextEnded != 0 { + t.Errorf("search's counters = %+v, want one error, since the context had not ended", search) + } + }) +} + +func TestTheCallersCanceledContextCountsAsContextEnded(t *testing.T) { + t.Parallel() + + synctest.Test(t, func(t *testing.T) { + ctx, cancel := context.WithCancel(t.Context()) + cancel() + hook, r := timedHook(t, 20, &hookPlugin{id: "search", fail: func(ctx context.Context) error { return ctx.Err() }, + log: &callLog{}}) + + hook.Fire(ctx, greet) + + failure := onlyFailure(t, r) + wantEqual(t, "reported", shapesOf([]pluginkit.HookFailure{failure}), []failureShape{{ + Hook: "content.changed", ID: "search", Err: "pluginkit: search content.changed: context canceled", + ContextEnded: true, + }}) + if !errors.Is(failure.Err, context.Canceled) { + t.Errorf("reported error = %v, want context.Canceled in its chain", failure.Err) + } + if hook.Stats().Overruns != 0 { + t.Errorf("Stats().Overruns = %d, want 0, since no time passed", hook.Stats().Overruns) + } + }) +} + +// unwrapPanics is an error whose Unwrap panics. +type unwrapPanics struct{} + +// Error returns the error's text. +func (unwrapPanics) Error() string { + return "index write failed" +} + +// Unwrap panics with the text unwrapped. +func (unwrapPanics) Unwrap() error { + panic("unwrapped") +} + +func TestAnErrorWhoseUnwrapPanicsCountsAsAPanicOfItsPlugin(t *testing.T) { + t.Parallel() + + ctx, cancel := context.WithCancel(t.Context()) + cancel() + log, r := &callLog{}, &reports{} + hook := greetHook(t, settingsOf(time.Hour, 20, r), + &hookPlugin{id: "search", fail: failWith(unwrapPanics{}), log: log}, &hookPlugin{id: "feed", log: log}) + + hook.Fire(ctx, greet) + + wantEqual(t, "called", log.called(), []string{"search", "feed"}) + failure := onlyFailure(t, r) + wantEqual(t, "reported", shapesOf([]pluginkit.HookFailure{failure}), []failureShape{{ + Hook: "content.changed", ID: "search", Err: "pluginkit: search content.changed panicked: unwrapped", + Panicked: true, Stacked: true, + }}) + if !strings.Contains(failure.Stack, "unwrapPanics.Unwrap") { + t.Errorf("reported stack = %q, want the stack of the panic in Unwrap", failure.Stack) + } + wantEqual(t, "search's counters", statsByID(hook)["search"], pluginkit.PluginStats{ID: "search", Panics: 1}) +} diff --git a/pluginkit/hook_test.go b/pluginkit/hook_test.go new file mode 100644 index 0000000..5a51be2 --- /dev/null +++ b/pluginkit/hook_test.go @@ -0,0 +1,539 @@ +// SPDX-License-Identifier: Apache-2.0 + +package pluginkit_test + +import ( + "context" + "errors" + "fmt" + "reflect" + "slices" + "strings" + "sync" + "testing" + "time" + + "github.com/gopherium/framework/pluginkit" +) + +// greeter is the interface the test hooks call. +type greeter interface { + Greet(ctx context.Context) error +} + +// titler is the interface the test filters call. +type titler interface { + Title(ctx context.Context, title string) (string, error) +} + +// identified is the least a plugin offers a hook. +type identified interface { + ID() string +} + +// callLog records which plugins a firing called, in order, and whether each saw its context ended. +type callLog struct { + mu sync.Mutex + ids []string + late []bool +} + +// add records a call of the plugin id under ctx. +func (l *callLog) add(ctx context.Context, id string) { + l.mu.Lock() + defer l.mu.Unlock() + l.ids = append(l.ids, id) + l.late = append(l.late, ctx.Err() != nil) +} + +// called returns the ids of every call, in order. +func (l *callLog) called() []string { + l.mu.Lock() + defer l.mu.Unlock() + return slices.Clone(l.ids) +} + +// hookPlugin is a plugin whose Greet and Title take its time, then panic or fail as its fields say. +type hookPlugin struct { + id string + takes time.Duration + panics any + fail func(ctx context.Context) error + suffix string + log *callLog +} + +// ID returns the plugin's id. +func (p *hookPlugin) ID() string { + return p.id +} + +// Greet records the call, takes the plugin's time, then panics or fails as told. +func (p *hookPlugin) Greet(ctx context.Context) error { + p.log.add(ctx, p.id) + time.Sleep(p.takes) + if p.panics != nil { + panic(p.panics) + } + if p.fail != nil { + return p.fail(ctx) + } + return nil +} + +// Title greets, then returns title with the plugin's suffix, beside any failure. +func (p *hookPlugin) Title(ctx context.Context, title string) (string, error) { + err := p.Greet(ctx) + return title + p.suffix, err +} + +// bystander is a plugin that implements no hook interface. +type bystander struct { + id string + log *callLog +} + +// ID returns the plugin's id. +func (b bystander) ID() string { + return b.id +} + +// failWith returns a failure that always answers err. +func failWith(err error) func(context.Context) error { + return func(context.Context) error { return err } +} + +// reports collects every failure a hook reports, from any goroutine. +type reports struct { + mu sync.Mutex + failures []pluginkit.HookFailure +} + +// add records one failure. +func (r *reports) add(failure pluginkit.HookFailure) { + r.mu.Lock() + defer r.mu.Unlock() + r.failures = append(r.failures, failure) +} + +// all returns every failure reported so far. +func (r *reports) all() []pluginkit.HookFailure { + r.mu.Lock() + defer r.mu.Unlock() + return slices.Clone(r.failures) +} + +// settingsOf returns hook settings with budget and timed firings, reporting into r. +func settingsOf(budget time.Duration, timedFirings int, r *reports) pluginkit.HookSettings { + return pluginkit.HookSettings{Budget: budget, TimedFirings: timedFirings, Report: r.add} +} + +// greetHook builds the hook content.changed of greeters over plugins, stopping the test when it is refused. +func greetHook(t *testing.T, settings pluginkit.HookSettings, plugins ...identified) *pluginkit.Hook[greeter] { + t.Helper() + hook, err := pluginkit.NewHook[greeter]("content.changed", plugins, settings) + if err != nil { + t.Fatalf("NewHook() error = %v, want nil", err) + } + return hook +} + +// greet calls Greet on one plugin of a hook. +func greet(ctx context.Context, g greeter) error { + return g.Greet(ctx) +} + +// retitle calls Title on one plugin of a filter. +func retitle(ctx context.Context, t titler, title string) (string, error) { + return t.Title(ctx, title) +} + +// statsByID returns the counters of every plugin of a hook, keyed by id. +func statsByID(hook *pluginkit.Hook[greeter]) map[string]pluginkit.PluginStats { + byID := make(map[string]pluginkit.PluginStats) + for _, plugin := range hook.Stats().Plugins { + byID[plugin.ID] = plugin + } + return byID +} + +// wantEqual checks that got deeply equals want, naming what was compared. +func wantEqual(t *testing.T, what string, got, want any) { + t.Helper() + if !reflect.DeepEqual(got, want) { + t.Errorf("%s = %+v, want %+v", what, got, want) + } +} + +// failureShape is a reported failure with its error as text and its stack only as present or absent. +type failureShape struct { + Hook, ID, Err string + Panicked, ContextEnded bool + Stacked bool +} + +// shapesOf returns the shape of each failure, in order. +func shapesOf(failures []pluginkit.HookFailure) []failureShape { + shapes := make([]failureShape, len(failures)) + for i, f := range failures { + shapes[i] = failureShape{ + Hook: f.Hook, ID: f.ID, Err: f.Err.Error(), Panicked: f.Panicked, ContextEnded: f.ContextEnded, + Stacked: f.Stack != "", + } + } + return shapes +} + +// onlyFailure returns the one failure r holds, stopping the test when it holds another number. +func onlyFailure(t *testing.T, r *reports) pluginkit.HookFailure { + t.Helper() + failures := r.all() + if len(failures) != 1 { + t.Fatalf("reported %d failures, want 1", len(failures)) + } + return failures[0] +} + +func TestNewHookKeepsOnlyImplementersInRegistrationOrder(t *testing.T) { + t.Parallel() + + log := &callLog{} + hook := greetHook(t, settingsOf(time.Hour, 20, &reports{}), + &hookPlugin{id: "gamma", log: log}, bystander{id: "theme", log: log}, &hookPlugin{id: "alpha", log: log}) + + hook.Fire(t.Context(), greet) + + wantEqual(t, "called", log.called(), []string{"gamma", "alpha"}) + wantEqual(t, "Stats()", hook.Stats(), pluginkit.HookStats{ + Name: "content.changed", Firings: 1, + Plugins: []pluginkit.PluginStats{{ID: "gamma"}, {ID: "alpha"}}, + }) +} + +func TestNewHookRefusesWhatItCannotRun(t *testing.T) { + t.Parallel() + + r := &reports{} + tests := map[string]struct { + name string + settings pluginkit.HookSettings + plugins []identified + want string + }{ + "an empty name": {"", settingsOf(time.Hour, 20, r), nil, "pluginkit: the hook name is empty"}, + "a zero budget": { + "content.changed", settingsOf(0, 20, r), nil, + "pluginkit: hook content.changed: the budget must stand above zero, got 0s", + }, + "a negative budget": { + "content.changed", settingsOf(-time.Millisecond, 20, r), nil, + "pluginkit: hook content.changed: the budget must stand above zero, got -1ms", + }, + "zero timed firings": { + "content.changed", settingsOf(time.Hour, 0, r), nil, + "pluginkit: hook content.changed: the timed firings must stand above zero, got 0", + }, + "negative timed firings": { + "content.changed", settingsOf(time.Hour, -1, r), nil, + "pluginkit: hook content.changed: the timed firings must stand above zero, got -1", + }, + "a nil report": { + "content.changed", pluginkit.HookSettings{Budget: time.Hour, TimedFirings: 20}, nil, + "pluginkit: hook content.changed: the report is nil", + }, + "two plugins with one id": { + "content.changed", settingsOf(time.Hour, 20, r), + []identified{bystander{id: "alpha"}, &hookPlugin{id: "beta"}, &hookPlugin{id: "alpha"}}, + `pluginkit: hook content.changed: duplicate id "alpha"`, + }, + } + for name, tc := range tests { + t.Run(name, func(t *testing.T) { + t.Parallel() + + hook, err := pluginkit.NewHook[greeter](tc.name, tc.plugins, tc.settings) + + if err == nil || err.Error() != tc.want { + t.Errorf("NewHook() error = %v, want %q", err, tc.want) + } + if hook != nil { + t.Errorf("NewHook() = %v, want nil", hook) + } + }) + } +} + +func TestNewHookRefusesATypeThatIsNotAnInterface(t *testing.T) { + t.Parallel() + + hook, err := pluginkit.NewHook[*hookPlugin]("content.changed", []identified{}, settingsOf(time.Hour, 20, &reports{})) + + want := "pluginkit: hook content.changed: *pluginkit_test.hookPlugin is not an interface" + if err == nil || err.Error() != want { + t.Errorf("NewHook() error = %v, want %q", err, want) + } + if hook != nil { + t.Errorf("NewHook() = %v, want nil", hook) + } +} + +func TestNewHookTakesAnyAsTheInterface(t *testing.T) { + t.Parallel() + + var ids []string + hook, err := pluginkit.NewHook[any]("content.changed", + []identified{&hookPlugin{id: "alpha"}, bystander{id: "theme"}}, settingsOf(time.Hour, 20, &reports{})) + if err != nil { + t.Fatalf("NewHook() error = %v, want nil", err) + } + + hook.Fire(t.Context(), func(_ context.Context, plugin any) error { + ids = append(ids, plugin.(identified).ID()) + return nil + }) + + if !slices.Equal(ids, []string{"alpha", "theme"}) { + t.Errorf("called = %q, want every plugin", ids) + } +} + +func TestNewHookTakesTheHostsPluginList(t *testing.T) { + t.Parallel() + + var calls []string + hook, err := pluginkit.NewHook[greeter]("content.changed", + []pluginkit.Plugin{&fakePlugin{id: "alpha", calls: &calls}}, settingsOf(time.Hour, 20, &reports{})) + if err != nil { + t.Fatalf("NewHook() error = %v, want nil", err) + } + + if got := hook.Stats().Plugins; len(got) != 0 { + t.Errorf("Stats().Plugins = %+v, want none, since the plugin is no greeter", got) + } +} + +func TestAFiringWithNoPluginAllocatesNothingAndCountsNothing(t *testing.T) { + r := &reports{} + hook := greetHook(t, settingsOf(time.Hour, 20, r), bystander{id: "theme"}) + filter, err := pluginkit.NewHook[titler]("page.title", []identified{bystander{id: "theme"}}, + settingsOf(time.Hour, 20, r)) + if err != nil { + t.Fatalf("NewHook() error = %v, want nil", err) + } + ctx := t.Context() + + allocs := testing.AllocsPerRun(100, func() { + hook.Fire(ctx, func(ctx context.Context, g greeter) error { return g.Greet(ctx) }) + if got := pluginkit.Filter(ctx, filter, "Hello", retitle); got != "Hello" { + t.Errorf("Filter() = %q, want the title unchanged", got) + } + }) + + if allocs != 0 { + t.Errorf("a firing with no plugin allocated %v times, want 0", allocs) + } + if got := hook.Stats().Firings + filter.Stats().Firings; got != 0 { + t.Errorf("firings counted = %d, want 0", got) + } +} + +func TestFireGoesOnPastAnErrorAndCountsIt(t *testing.T) { + t.Parallel() + + errIndex := errors.New("index unavailable") + log, r := &callLog{}, &reports{} + hook := greetHook(t, settingsOf(time.Hour, 20, r), + &hookPlugin{id: "alpha", log: log}, &hookPlugin{id: "beta", fail: failWith(errIndex), log: log}, + &hookPlugin{id: "gamma", log: log}) + + hook.Fire(t.Context(), greet) + + wantEqual(t, "called", log.called(), []string{"alpha", "beta", "gamma"}) + failure := onlyFailure(t, r) + wantEqual(t, "reported", shapesOf([]pluginkit.HookFailure{failure}), []failureShape{ + {Hook: "content.changed", ID: "beta", Err: "pluginkit: beta content.changed: index unavailable"}, + }) + if !errors.Is(failure.Err, errIndex) { + t.Errorf("reported error = %v, want the plugin's error in its chain", failure.Err) + } + wantEqual(t, "beta's counters", statsByID(hook)["beta"], pluginkit.PluginStats{ID: "beta", Errors: 1}) +} + +func TestFireRecoversAPanicCountsItAndReportsItsStack(t *testing.T) { + t.Parallel() + + log, r := &callLog{}, &reports{} + hook := greetHook(t, settingsOf(time.Hour, 20, r), + &hookPlugin{id: "alpha", log: log}, &hookPlugin{id: "beta", panics: "boom", log: log}, + &hookPlugin{id: "gamma", log: log}) + + hook.Fire(t.Context(), greet) + + wantEqual(t, "called", log.called(), []string{"alpha", "beta", "gamma"}) + failure := onlyFailure(t, r) + wantEqual(t, "reported", shapesOf([]pluginkit.HookFailure{failure}), []failureShape{{ + Hook: "content.changed", ID: "beta", Err: "pluginkit: beta content.changed panicked: boom", + Panicked: true, Stacked: true, + }}) + if !strings.Contains(failure.Stack, "(*hookPlugin).Greet") { + t.Errorf("reported stack = %q, want the stack of the panic", failure.Stack) + } + wantEqual(t, "beta's counters", statsByID(hook)["beta"], pluginkit.PluginStats{ID: "beta", Panics: 1}) +} + +// selfPanicking is an error and a panic value whose text panics with itself, a panic fmt does not catch. +type selfPanicking struct{} + +// Error panics with the error itself. +func (selfPanicking) Error() string { + panic(selfPanicking{}) +} + +func TestAPluginValueWhoseTextPanicsIsReportedByItsType(t *testing.T) { + t.Parallel() + + tests := map[string]struct { + plugin *hookPlugin + failure failureShape + counters pluginkit.PluginStats + }{ + "a returned error": { + &hookPlugin{id: "alpha", fail: failWith(selfPanicking{})}, + failureShape{Err: "pluginkit: alpha content.changed: pluginkit_test.selfPanicking whose text panicked"}, + pluginkit.PluginStats{ID: "alpha", Errors: 1}, + }, + "a panic value": { + &hookPlugin{id: "alpha", panics: selfPanicking{}}, + failureShape{ + Err: "pluginkit: alpha content.changed panicked: pluginkit_test.selfPanicking whose text panicked", + Panicked: true, Stacked: true, + }, + pluginkit.PluginStats{ID: "alpha", Panics: 1}, + }, + } + for name, tc := range tests { + t.Run(name, func(t *testing.T) { + t.Parallel() + + log, r := &callLog{}, &reports{} + tc.plugin.log = log + hook := greetHook(t, settingsOf(time.Hour, 20, r), tc.plugin, &hookPlugin{id: "beta", log: log}) + + hook.Fire(t.Context(), greet) + + wantEqual(t, "called", log.called(), []string{"alpha", "beta"}) + want := tc.failure + want.Hook, want.ID = "content.changed", "alpha" + wantEqual(t, "reported", shapesOf(r.all()), []failureShape{want}) + wantEqual(t, "alpha's counters", statsByID(hook)["alpha"], tc.counters) + }) + } +} + +func TestFilterPassesTheValueThroughEveryPluginPastOnesThatFail(t *testing.T) { + t.Parallel() + + tests := map[string]*hookPlugin{ + "no failure": {id: "middle", suffix: " and more"}, + "an error": {id: "middle", suffix: " and more", fail: failWith(errors.New("no title"))}, + "a panic": {id: "middle", suffix: " and more", panics: "boom"}, + } + wants := map[string]string{"no failure": "Hello | Example and more | Home", "an error": "Hello | Example | Home", + "a panic": "Hello | Example | Home"} + for name, middle := range tests { + t.Run(name, func(t *testing.T) { + t.Parallel() + + log := &callLog{} + middle.log = log + hook, err := pluginkit.NewHook[titler]("page.title", []identified{ + &hookPlugin{id: "brand", suffix: " | Example", log: log}, middle, + &hookPlugin{id: "suffix", suffix: " | Home", log: log}, + }, settingsOf(time.Hour, 20, &reports{})) + if err != nil { + t.Fatalf("NewHook() error = %v, want nil", err) + } + + got := pluginkit.Filter(t.Context(), hook, "Hello", retitle) + + if got != wants[name] { + t.Errorf("Filter() = %q, want %q", got, wants[name]) + } + if called := log.called(); !slices.Equal(called, []string{"brand", "middle", "suffix"}) { + t.Errorf("called = %q, want every plugin in order", called) + } + }) + } +} + +func TestConcurrentFiringsCountEveryFailure(t *testing.T) { + t.Parallel() + + const firings = 50 + r := &reports{} + hook := greetHook(t, settingsOf(time.Hour, 20, r), + &hookPlugin{id: "alpha", log: &callLog{}}, + &hookPlugin{id: "beta", fail: failWith(errors.New("index unavailable")), log: &callLog{}}, + &hookPlugin{id: "gamma", panics: "boom", log: &callLog{}}) + + var wg sync.WaitGroup + for range firings { + wg.Go(func() { hook.Fire(context.Background(), greet) }) + } + wg.Wait() + + wantEqual(t, "Stats()", hook.Stats(), pluginkit.HookStats{ + Name: "content.changed", Firings: firings, + Plugins: []pluginkit.PluginStats{{ID: "alpha"}, {ID: "beta", Errors: firings}, {ID: "gamma", Panics: firings}}, + }) + if got := len(r.all()); got != 2*firings { + t.Errorf("reported %d failures, want %d", got, 2*firings) + } +} + +func TestConcurrentTimedFiringsCountEveryTimedCallAndCharge(t *testing.T) { + t.Parallel() + + const firings = 50 + hook := greetHook(t, settingsOf(time.Nanosecond, firings+1, &reports{}), + &hookPlugin{id: "alpha", takes: time.Microsecond, log: &callLog{}}, + &hookPlugin{id: "beta", takes: time.Microsecond, log: &callLog{}}) + hook.Fire(t.Context(), greet) + + var wg sync.WaitGroup + for range firings { + wg.Go(func() { hook.Fire(context.Background(), greet) }) + } + wg.Wait() + + stats := hook.Stats() + charged := stats.Plugins[0].Overruns + stats.Plugins[1].Overruns + wantEqual(t, "overruns, charged and uncharged", []uint64{stats.Overruns, charged, stats.UnchargedOverruns}, + []uint64{firings + 1, firings, 0}) + for _, plugin := range stats.Plugins { + if plugin.TimedCalls != firings { + t.Errorf("%s was timed in %d firings, want %d", plugin.ID, plugin.TimedCalls, firings) + } + } +} + +func BenchmarkFireWithTwoHundredPlugins(b *testing.B) { + plugins := make([]identified, 200) + for i := range plugins { + plugins[i] = &hookPlugin{id: fmt.Sprintf("plugin-%03d", i), log: &callLog{}} + } + for name, limit := range map[string]time.Duration{"untimed": time.Hour, "timed": time.Nanosecond} { + b.Run(name, func(b *testing.B) { + hook, err := pluginkit.NewHook[greeter]("content.changed", plugins, settingsOf(limit, 1<<30, &reports{})) + if err != nil { + b.Fatalf("NewHook() error = %v, want nil", err) + } + ctx := context.Background() + hook.Fire(ctx, func(context.Context, greeter) error { return nil }) + + for b.Loop() { + hook.Fire(ctx, func(context.Context, greeter) error { return nil }) + } + }) + } +} diff --git a/pluginkit/pluginkit.go b/pluginkit/pluginkit.go index 16f3ec9..f97d471 100644 --- a/pluginkit/pluginkit.go +++ b/pluginkit/pluginkit.go @@ -1,7 +1,8 @@ // SPDX-License-Identifier: Apache-2.0 // Package pluginkit provides compile-time plugin infrastructure: a lifecycle -// contract, a plugin host, and route guarding for plugin namespaces. +// contract, a plugin host, hooks that call every plugin implementing an +// interface, and route guarding for plugin namespaces. package pluginkit import (