diff --git a/README.md b/README.md index f4554c0..a08dcfa 100644 --- a/README.md +++ b/README.md @@ -1,2 +1,11 @@ # golang-modules +[![Go Reference](https://pkg.go.dev/badge/github.com/ibrt/golang-modules.svg)](https://pkg.go.dev/github.com/ibrt/golang-modules) +[![CI](https://github.com/ibrt/golang-modules/actions/workflows/ci.yml/badge.svg)](https://github.com/ibrt/golang-modules/actions/workflows/ci.yml) +[![codecov](https://codecov.io/github/ibrt/golang-modules/branch/main/graph/badge.svg?token=96DEYB5CZ9)](https://codecov.io/github/ibrt/golang-modules) + Reusable modules for building services in Go. + +### Developers + +Contributions are welcome, please check in on proposed implementation before sending a PR. You can validate your changes +by running `./validate.sh` from the root of the repo. \ No newline at end of file diff --git a/cfgm/cfg.go b/cfgm/cfg.go index 9e4f7cd..4795960 100644 --- a/cfgm/cfg.go +++ b/cfgm/cfg.go @@ -1,3 +1,4 @@ +// Package cfgm implements a configuration module. package cfgm import ( diff --git a/cfgm/cfg_test.go b/cfgm/cfg_test.go index 1a0c404..392f969 100644 --- a/cfgm/cfg_test.go +++ b/cfgm/cfg_test.go @@ -2,10 +2,9 @@ package cfgm_test import ( "context" - "os" "testing" - "github.com/ibrt/golang-utils/errorz" + "github.com/ibrt/golang-utils/envz" "github.com/ibrt/golang-utils/fixturez" . "github.com/onsi/gomega" @@ -25,7 +24,7 @@ type TestConfigMixin interface { } type TestConfigMixinImpl struct { - MixinKey string `env:"MIXIN_KEY_EC2B754B,required"` + MixinKey string `env:"MIXIN_KEY_EC2B754B,notEmpty"` } func (*TestConfigMixinImpl) Config() { @@ -37,7 +36,7 @@ func (v *TestConfigMixinImpl) GetMixin() *TestConfigMixinImpl { } type TestConfig struct { - Key string `env:"KEY_EC2B754B,required"` + Key string `env:"KEY_EC2B754B,notEmpty"` TestConfigMixinImpl } @@ -50,14 +49,16 @@ type Suite struct { } func TestSuite(t *testing.T) { - errorz.MaybeMustWrap(os.Setenv("TEST_KEY_EC2B754B", "Value")) - errorz.MaybeMustWrap(os.Setenv("TEST_MIXIN_KEY_EC2B754B", "MixinValue")) - fixturez.RunSuite(t, &Suite{ CFG: &tcfgm.Helper[*TestConfig]{ - ConfigLoader: cfgm.MustNewEnvConfigLoader[*TestConfig](&cfgm.EnvConfigLoaderOptions{ - Prefix: "TEST_", - }), + ConfigLoader: func(ctx context.Context) (*TestConfig, error) { + return &TestConfig{ + Key: "Value", + TestConfigMixinImpl: TestConfigMixinImpl{ + MixinKey: "MixinValue", + }, + }, nil + }, }, }) } @@ -78,3 +79,47 @@ func (*Suite) TestMustGet(ctx context.Context, g *WithT) { cfgm.MustGet[cfgm.Config](ctx) }).ToNot(Panic()) } + +func (*Suite) TestEnvConfigLoader(ctx context.Context, g *WithT) { + envz.WithEnv( + map[string]string{ + "TEST_KEY_EC2B754B": "Value", + "TEST_MIXIN_KEY_EC2B754B": "MixinValue", + }, + func() { + cfg, err := cfgm.MustNewEnvConfigLoader[*TestConfig](&cfgm.EnvConfigLoaderOptions{Prefix: "TEST_"})(ctx) + g.Expect(err).ToNot(HaveOccurred()) + g.Expect(cfg).To(Equal(&TestConfig{ + Key: "Value", + TestConfigMixinImpl: TestConfigMixinImpl{ + MixinKey: "MixinValue", + }, + })) + }) + + envz.WithEnv( + map[string]string{ + "KEY_EC2B754B": "Value", + "MIXIN_KEY_EC2B754B": "MixinValue", + }, + func() { + cfg, err := cfgm.MustNewEnvConfigLoader[*TestConfig](nil)(ctx) + g.Expect(err).ToNot(HaveOccurred()) + g.Expect(cfg).To(Equal(&TestConfig{ + Key: "Value", + TestConfigMixinImpl: TestConfigMixinImpl{ + MixinKey: "MixinValue", + }, + })) + }) + + envz.WithEnv( + map[string]string{ + "KEY_EC2B754B": "", + "MIXIN_KEY_EC2B754B": "", + }, + func() { + _, err := cfgm.MustNewEnvConfigLoader[*TestConfig](nil)(ctx) + g.Expect(err).To(MatchError("env: environment variable \"KEY_EC2B754B\" should not be empty; environment variable \"MIXIN_KEY_EC2B754B\" should not be empty")) + }) +} diff --git a/clkm/clk.go b/clkm/clk.go index 30a3854..a7183f2 100644 --- a/clkm/clk.go +++ b/clkm/clk.go @@ -1,3 +1,4 @@ +// Package clkm implements a clock module. package clkm import ( diff --git a/clkm/tclkm/clk.go b/clkm/tclkm/clk.go index da1fad1..889de6e 100644 --- a/clkm/tclkm/clk.go +++ b/clkm/tclkm/clk.go @@ -26,14 +26,14 @@ type RealHelper struct { releaser injectz.Releaser } -// BeforeSuite implements fixturez.BeforeSuite. +// BeforeSuite implements [fixturez.BeforeSuite]. func (h *RealHelper) BeforeSuite(ctx context.Context, _ *gomega.WithT) context.Context { injector, releaser := clkm.Initializer(ctx) h.releaser = releaser return injector(ctx) } -// AfterSuite implements fixturez.AfterSuite. +// AfterSuite implements [fixturez.AfterSuite]. func (h *RealHelper) AfterSuite(_ context.Context, _ *gomega.WithT) { h.releaser() h.releaser = nil @@ -41,23 +41,28 @@ func (h *RealHelper) AfterSuite(_ context.Context, _ *gomega.WithT) { // MockHelper is a test helper. type MockHelper struct { - Mock *clock.Mock + mock *clock.Mock } -// BeforeSuite implements fixturez.BeforeSuite. +// BeforeSuite implements [fixturez.BeforeSuite]. func (h *MockHelper) BeforeSuite(ctx context.Context, _ *gomega.WithT) context.Context { - h.Mock = clock.NewMock() - h.Mock.Set(time.Now()) - return clkm.NewSingletonInjector(h.Mock)(ctx) + h.mock = clock.NewMock() + h.mock.Set(time.Now()) + return clkm.NewSingletonInjector(h.mock)(ctx) } -// AfterSuite implements fixturez.AfterSuite. +// AfterSuite implements [fixturez.AfterSuite]. func (h *MockHelper) AfterSuite(_ context.Context, _ *gomega.WithT) { - h.Mock = nil + h.mock = nil } -// BeforeTest implements fixturez.BeforeTest. +// BeforeTest implements [fixturez.BeforeTest]. func (h *MockHelper) BeforeTest(ctx context.Context, _ *gomega.WithT, _ *gomock.Controller) context.Context { - h.Mock.Set(time.Now().UTC()) + h.mock.Set(time.Now().UTC()) return ctx } + +// GetMock returns the mock. +func (h *MockHelper) GetMock() *clock.Mock { + return h.mock +} diff --git a/clkm/tclkm/clk_test.go b/clkm/tclkm/clk_test.go index 0ddabc6..a917f81 100644 --- a/clkm/tclkm/clk_test.go +++ b/clkm/tclkm/clk_test.go @@ -26,7 +26,7 @@ func (s *RealSuite) TestRealHelper(ctx context.Context, g *WithT) { } type MockSuite struct { - Clock *tclkm.MockHelper + CLK *tclkm.MockHelper } func TestMockSuite(t *testing.T) { @@ -35,6 +35,6 @@ func TestMockSuite(t *testing.T) { func (s *MockSuite) TestMockHelper(ctx context.Context, g *WithT) { now := time.Now().Add(-time.Minute) - s.Clock.Mock.Set(now) + s.CLK.GetMock().Set(now) g.Expect(clkm.MustGet(ctx).Now()).To(Equal(now)) } diff --git a/go.mod b/go.mod index 1abb2af..0191051 100644 --- a/go.mod +++ b/go.mod @@ -5,15 +5,30 @@ go 1.23 require ( github.com/benbjohnson/clock v1.3.5 github.com/caarlos0/env/v11 v11.2.2 - github.com/ibrt/golang-utils v0.8.0 + github.com/honeycombio/libhoney-go v1.24.0 + github.com/ibrt/golang-utils v0.10.0 github.com/onsi/gomega v1.36.1 + github.com/sirupsen/logrus v1.9.3 go.uber.org/mock v0.5.0 ) require ( github.com/davecgh/go-spew v1.1.1 // indirect + github.com/facebookgo/clock v0.0.0-20150410010913-600d898af40a // indirect + github.com/facebookgo/limitgroup v0.0.0-20150612190941-6abd8d71ec01 // indirect + github.com/facebookgo/muster v0.0.0-20150708232844-fd3d7953fd52 // indirect + github.com/fatih/color v1.18.0 // indirect github.com/google/go-cmp v0.6.0 // indirect + github.com/google/uuid v1.6.0 // indirect + github.com/klauspost/compress v1.17.9 // indirect + github.com/mattn/go-colorable v0.1.13 // indirect + github.com/mattn/go-isatty v0.0.20 // indirect + github.com/rodaine/table v1.3.0 // indirect + github.com/vmihailenco/msgpack/v5 v5.4.1 // indirect + github.com/vmihailenco/tagparser/v2 v2.0.0 // indirect golang.org/x/net v0.32.0 // indirect + golang.org/x/sys v0.28.0 // indirect golang.org/x/text v0.21.0 // indirect + gopkg.in/alexcesaro/statsd.v2 v2.0.0 // indirect gopkg.in/yaml.v3 v3.0.1 // indirect ) diff --git a/go.sum b/go.sum index eb6ac9b..74bf977 100644 --- a/go.sum +++ b/go.sum @@ -1,9 +1,26 @@ +github.com/DataDog/zstd v1.5.6 h1:LbEglqepa/ipmmQJUDnSsfvA8e8IStVcGaFWDuxvGOY= +github.com/DataDog/zstd v1.5.6/go.mod h1:g4AWEaM3yOg3HYfnJ3YIawPnVdXJh9QME85blwSAmyw= github.com/benbjohnson/clock v1.3.5 h1:VvXlSJBzZpA/zum6Sj74hxwYI2DIxRWuNIoXAzHZz5o= github.com/benbjohnson/clock v1.3.5/go.mod h1:J11/hYXuz8f4ySSvYwY0FKfm+ezbsZBKZxNJlLklBHA= github.com/caarlos0/env/v11 v11.2.2 h1:95fApNrUyueipoZN/EhA8mMxiNxrBwDa+oAZrMWl3Kg= github.com/caarlos0/env/v11 v11.2.2/go.mod h1:JBfcdeQiBoI3Zh1QRAWfe+tpiNTmDtcCj/hHHHMx0vc= +github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= 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/facebookgo/clock v0.0.0-20150410010913-600d898af40a h1:yDWHCSQ40h88yih2JAcL6Ls/kVkSE8GFACTGVnMPruw= +github.com/facebookgo/clock v0.0.0-20150410010913-600d898af40a/go.mod h1:7Ga40egUymuWXxAe151lTNnCv97MddSOVsjpPPkityA= +github.com/facebookgo/ensure v0.0.0-20200202191622-63f1cf65ac4c h1:8ISkoahWXwZR41ois5lSJBSVw4D0OV19Ht/JSTzvSv0= +github.com/facebookgo/ensure v0.0.0-20200202191622-63f1cf65ac4c/go.mod h1:Yg+htXGokKKdzcwhuNDwVvN+uBxDGXJ7G/VN1d8fa64= +github.com/facebookgo/limitgroup v0.0.0-20150612190941-6abd8d71ec01 h1:IeaD1VDVBPlx3viJT9Md8if8IxxJnO+x0JCGb054heg= +github.com/facebookgo/limitgroup v0.0.0-20150612190941-6abd8d71ec01/go.mod h1:ypD5nozFk9vcGw1ATYefw6jHe/jZP++Z15/+VTMcWhc= +github.com/facebookgo/muster v0.0.0-20150708232844-fd3d7953fd52 h1:a4DFiKFJiDRGFD1qIcqGLX/WlUMD9dyLSLDt+9QZgt8= +github.com/facebookgo/muster v0.0.0-20150708232844-fd3d7953fd52/go.mod h1:yIquW87NGRw1FU5p5lEkpnt/QxoH5uPAOUlOVkAUuMg= +github.com/facebookgo/stack v0.0.0-20160209184415-751773369052 h1:JWuenKqqX8nojtoVVWjGfOF9635RETekkoH6Cc9SX0A= +github.com/facebookgo/stack v0.0.0-20160209184415-751773369052/go.mod h1:UbMTZqLaRiH3MsBH8va0n7s1pQYcu3uTb8G4tygF4Zg= +github.com/facebookgo/subset v0.0.0-20200203212716-c811ad88dec4 h1:7HZCaLC5+BZpmbhCOZJ293Lz68O7PYrF2EzeiFMwCLk= +github.com/facebookgo/subset v0.0.0-20200203212716-c811ad88dec4/go.mod h1:5tD+neXqOorC30/tWg0LCSkrqj/AR6gu8yY8/fpw1q0= +github.com/fatih/color v1.18.0 h1:S8gINlzdQ840/4pfAwic/ZE0djQEH3wM94VfqLTZcOM= +github.com/fatih/color v1.18.0/go.mod h1:4FelSpRwEGDpQ12mAdzqdOukCy4u8WUtOY6lkT/6HfU= github.com/go-logr/logr v1.4.2 h1:6pFjapn8bFcIbiKo3XT4j/BhANplGihG6tvd+8rYgrY= github.com/go-logr/logr v1.4.2/go.mod h1:9T104GzyrTigFIr8wt5mBrctHMim0Nb2HLGrmQ40KvY= github.com/go-task/slim-sprig/v3 v3.0.0 h1:sUs3vkvUymDpBKi3qH1YSqBQk9+9D/8M2mN1vB6EwHI= @@ -12,23 +29,64 @@ github.com/google/go-cmp v0.6.0 h1:ofyhxvXcZhMsU5ulbFiLKl/XBFqE1GSq7atu8tAmTRI= github.com/google/go-cmp v0.6.0/go.mod h1:17dUlkBOakJ0+DkrSSNjCkIjxS6bF9zb3elmeNGIjoY= github.com/google/pprof v0.0.0-20240827171923-fa2c70bbbfe5 h1:5iH8iuqE5apketRbSFBy+X1V0o+l+8NF1avt4HWl7cA= github.com/google/pprof v0.0.0-20240827171923-fa2c70bbbfe5/go.mod h1:vavhavw2zAxS5dIdcRluK6cSGGPlZynqzFM8NdvU144= -github.com/ibrt/golang-utils v0.8.0 h1:gZ/ECjSoOZJIS6PJ83dSbU0fGN5Efobl5XTO7Cy/fzY= -github.com/ibrt/golang-utils v0.8.0/go.mod h1:KQF3oD7IWvTri0Plm/tAVwppoh16f4r8zGO+FCMzyiA= +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/honeycombio/libhoney-go v1.24.0 h1:PPgVrd8FOiQeL24FOEuhF9SFA3oDgaA/AU/Agu2ZKkA= +github.com/honeycombio/libhoney-go v1.24.0/go.mod h1:oW9gF/appfQoDjtXfcfH5hp5v3F0xpTy42+NBRCYk9k= +github.com/ibrt/golang-utils v0.10.0 h1:ntyERVySjMYEv4HLxWRpdUHVNqm1n6DU4722rsiCyEs= +github.com/ibrt/golang-utils v0.10.0/go.mod h1:KQF3oD7IWvTri0Plm/tAVwppoh16f4r8zGO+FCMzyiA= +github.com/klauspost/compress v1.17.9 h1:6KIumPrER1LHsvBVuDa0r5xaG0Es51mhhB9BQB2qeMA= +github.com/klauspost/compress v1.17.9/go.mod h1:Di0epgTjJY877eYKx5yC51cX2A2Vl2ibi7bDH9ttBbw= +github.com/mattn/go-colorable v0.1.13 h1:fFA4WZxdEF4tXPZVKMLwD8oUnCTTo08duU7wxecdEvA= +github.com/mattn/go-colorable v0.1.13/go.mod h1:7S9/ev0klgBDR4GtXTXX8a3vIGJpMovkB8vQcUbaXHg= +github.com/mattn/go-isatty v0.0.16/go.mod h1:kYGgaQfpe5nmfYZH+SKPsOc2e4SrIfOl2e/yFXSvRLM= +github.com/mattn/go-isatty v0.0.20 h1:xfD0iDuEKnDkl03q4limB+vH+GxLEtL/jb4xVJSWWEY= +github.com/mattn/go-isatty v0.0.20/go.mod h1:W+V8PltTTMOvKvAeJH7IuucS94S2C6jfK/D7dTCTo3Y= +github.com/mattn/go-runewidth v0.0.16 h1:E5ScNMtiwvlvB5paMFdw9p4kSQzbXFikJ5SQO6TULQc= +github.com/mattn/go-runewidth v0.0.16/go.mod h1:Jdepj2loyihRzMpdS35Xk/zdY8IAYHsh153qUoGf23w= github.com/onsi/ginkgo/v2 v2.20.1 h1:YlVIbqct+ZmnEph770q9Q7NVAz4wwIiVNahee6JyUzo= github.com/onsi/ginkgo/v2 v2.20.1/go.mod h1:lG9ey2Z29hR41WMVthyJBGUBcBhGOtoPF2VFMvBXFCI= github.com/onsi/gomega v1.36.1 h1:bJDPBO7ibjxcbHMgSCoo4Yj18UWbKDlLwX1x9sybDcw= github.com/onsi/gomega v1.36.1/go.mod h1:PvZbdDc8J6XJEpDK4HCuRBm8a6Fzp9/DmhC9C7yFlog= +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/rivo/uniseg v0.2.0 h1:S1pD9weZBuJdFmowNwbpi7BJ8TNftyUImj/0WQi72jY= +github.com/rivo/uniseg v0.2.0/go.mod h1:J6wj4VEh+S6ZtnVlnTBMWIodfgj8LQOQFoIToxlJtxc= +github.com/rodaine/table v1.3.0 h1:4/3S3SVkHnVZX91EHFvAMV7K42AnJ0XuymRR2C5HlGE= +github.com/rodaine/table v1.3.0/go.mod h1:47zRsHar4zw0jgxGxL9YtFfs7EGN6B/TaS+/Dmk4WxU= +github.com/sirupsen/logrus v1.9.3 h1:dueUQJ1C2q9oE3F7wvmSGAaVtTmUizReu6fjN8uqzbQ= +github.com/sirupsen/logrus v1.9.3/go.mod h1:naHLuLoDiP4jHNo9R0sCBMtWGeIprob74mVsIT4qYEQ= +github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= +github.com/stretchr/objx v0.4.0/go.mod h1:YvHI0jy2hoMjB+UWwv71VJQ9isScKT/TqJzVSSt89Yw= +github.com/stretchr/objx v0.5.0/go.mod h1:Yh+to48EsGEfYuaHDzXPcE3xhTkx73EhmCGUpEOglKo= +github.com/stretchr/objx v0.5.2/go.mod h1:FRsXN1f5AsAjCGJKqEizvkpNtU+EGNCLh3NxZ/8L+MA= +github.com/stretchr/testify v1.7.0/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg= +github.com/stretchr/testify v1.7.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg= +github.com/stretchr/testify v1.8.0/go.mod h1:yNjHg4UonilssWZ8iaSj1OCr/vHnekPRkoO+kdMU+MU= +github.com/stretchr/testify v1.8.4/go.mod h1:sz/lmYIOXD/1dqDmKjjqLyZ2RngseejIcXlSw2iwfAo= +github.com/stretchr/testify v1.9.0 h1:HtqpIVDClZ4nwg75+f6Lvsy/wHu+3BoSGCbBAcpTsTg= +github.com/stretchr/testify v1.9.0/go.mod h1:r2ic/lqez/lEtzL7wO/rwa5dbSLXVDPFyf8C91i36aY= +github.com/vmihailenco/msgpack/v5 v5.4.1 h1:cQriyiUvjTwOHg8QZaPihLWeRAAVoCpE00IUPn0Bjt8= +github.com/vmihailenco/msgpack/v5 v5.4.1/go.mod h1:GaZTsDaehaPpQVyxrf5mtQlH+pc21PIudVV/E3rRQok= +github.com/vmihailenco/tagparser/v2 v2.0.0 h1:y09buUbR+b5aycVFQs/g70pqKVZNBmxwAhO7/IwNM9g= +github.com/vmihailenco/tagparser/v2 v2.0.0/go.mod h1:Wri+At7QHww0WTrCBeu4J6bNtoV6mEfg5OIWRZA9qds= go.uber.org/mock v0.5.0 h1:KAMbZvZPyBPWgD14IrIQ38QCyjwpvVVV6K/bHl1IwQU= go.uber.org/mock v0.5.0/go.mod h1:ge71pBPLYDk7QIi1LupWxdAykm7KIEFchiOqd6z7qMM= golang.org/x/net v0.32.0 h1:ZqPmj8Kzc+Y6e0+skZsuACbx+wzMgo5MQsJh9Qd6aYI= golang.org/x/net v0.32.0/go.mod h1:CwU0IoeOlnQQWJ6ioyFrfRuomB8GKF6KbYXZVyeXNfs= +golang.org/x/sys v0.0.0-20220715151400-c0bba94af5f8/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= +golang.org/x/sys v0.0.0-20220811171246-fbc7d0a398ab/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= +golang.org/x/sys v0.6.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.28.0 h1:Fksou7UEQUWlKvIdsqzJmUmCX3cZuD2+P3XyyzwMhlA= golang.org/x/sys v0.28.0/go.mod h1:/VUhepiaJMQUp4+oa/7Zr1D23ma6VTLIYjOOTFZPUcA= golang.org/x/text v0.21.0 h1:zyQAAkrwaneQ066sspRyJaG9VNi/YJ1NfzcGB3hZ/qo= golang.org/x/text v0.21.0/go.mod h1:4IBbMaMmOPCJ8SecivzSH54+73PCFmPWxNTLm+vZkEQ= golang.org/x/tools v0.24.0 h1:J1shsA93PJUEVaUSaay7UXAyE8aimq3GW0pjlolpa24= golang.org/x/tools v0.24.0/go.mod h1:YhNqVBIfWHdzvTLs0d8LCuMhkKUgSUKldakyV7W/WDQ= +gopkg.in/alexcesaro/statsd.v2 v2.0.0 h1:FXkZSCZIH17vLCO5sO2UucTHsH9pc+17F6pl3JVCwMc= +gopkg.in/alexcesaro/statsd.v2 v2.0.0/go.mod h1:i0ubccKGzBVNBpdGV5MocxyA/XlLUJzA7SLonnE4drU= gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405 h1:yhCVgyC4o1eVCa2tZl7eS0r+SDo693bJlVdllGtEeKM= gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= +gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= 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/logm/adapter.go b/logm/adapter.go new file mode 100644 index 0000000..58e085a --- /dev/null +++ b/logm/adapter.go @@ -0,0 +1,79 @@ +package logm + +import ( + "context" +) + +var ( + _ Log = (*adapterLogImpl)(nil) +) + +type adapterLogImpl struct { + ctx context.Context + rawLog RawLog +} + +// EmitDebug implements the Log interface. +func (l *adapterLogImpl) EmitDebug(format string, options ...EmitOption) { + l.rawLog.EmitDebug(l.ctx, format, options...) +} + +// EmitInfo implements the Log interface. +func (l *adapterLogImpl) EmitInfo(format string, options ...EmitOption) { + l.rawLog.EmitInfo(l.ctx, format, options...) +} + +// EmitWarning implements the Log interface. +func (l *adapterLogImpl) EmitWarning(err error) { + l.rawLog.EmitWarning(l.ctx, err) +} + +// EmitError implements the Log interface. +func (l *adapterLogImpl) EmitError(err error) { + l.rawLog.EmitError(l.ctx, err) +} + +// EmitTraceLink implements the Log interface. +func (l *adapterLogImpl) EmitTraceLink(link *TraceLink) { + l.rawLog.EmitTraceLink(l.ctx, link) +} + +// Begin implements the Log interface. +func (l *adapterLogImpl) Begin(name string, options ...BeginOption) (context.Context, func()) { + return l.rawLog.Begin(l.ctx, name, options...) +} + +// SetErrorFlag implements the Log interface. +func (l *adapterLogImpl) SetErrorFlag() { + l.rawLog.SetErrorFlag(l.ctx) +} + +// SetUser implements the Log interface. +func (l *adapterLogImpl) SetUser(user *User) { + l.rawLog.SetUser(l.ctx, user) +} + +// SetPropagatingField implements the Log interface. +func (l *adapterLogImpl) SetPropagatingField(k string, v any) { + l.rawLog.SetPropagatingField(l.ctx, k, v) +} + +// SetMetadataKey implements the Log interface. +func (l *adapterLogImpl) SetMetadataKey(k string, v any) { + l.rawLog.SetMetadataKey(l.ctx, k, v) +} + +// SetErrorMetadataKey implements the Log interface. +func (l *adapterLogImpl) SetErrorMetadataKey(k string, v any) { + l.rawLog.SetErrorMetadataKey(l.ctx, k, v) +} + +// GetCurrentTraceLink implements the Log interface. +func (l *adapterLogImpl) GetCurrentTraceLink() *TraceLink { + return l.rawLog.GetCurrentTraceLink(l.ctx) +} + +// Flush implements the RawLog interface. +func (l *adapterLogImpl) Flush() { + l.rawLog.Flush(l.ctx) +} diff --git a/logm/background.go b/logm/background.go new file mode 100644 index 0000000..4057010 --- /dev/null +++ b/logm/background.go @@ -0,0 +1,117 @@ +package logm + +import ( + "context" + "sync" + + "github.com/honeycombio/libhoney-go" + "github.com/ibrt/golang-utils/errorz" + "github.com/ibrt/golang-utils/idz" + + "github.com/ibrt/golang-modules/clkm" +) + +var ( + _ RawLog = (*backgroundLogImpl)(nil) +) + +type backgroundLogImpl struct { + client *libhoney.Client +} + +// EmitDebug implements the [RawLog] interface. +func (bL *backgroundLogImpl) EmitDebug(ctx context.Context, format string, options ...EmitOption) { + o := newEmitOptions(options...) + e := newAttachableEvent(ctx, bL.client, "", "debug") + addDebugFields(e, format, o) + errorz.MaybeMustWrap(e.Send()) +} + +// EmitInfo implements the [RawLog] interface. +func (bL *backgroundLogImpl) EmitInfo(ctx context.Context, format string, options ...EmitOption) { + o := newEmitOptions(options...) + e := newAttachableEvent(ctx, bL.client, "", "info") + addInfoFields(e, format, o) + errorz.MaybeMustWrap(e.Send()) +} + +// EmitWarning implements the [RawLog] interface. +func (bL *backgroundLogImpl) EmitWarning(ctx context.Context, err error) { + maybeSetIsEmitted(err) + e := newAttachableEvent(ctx, bL.client, "", "warning") + addWarningFields(e, err) + errorz.MaybeMustWrap(e.Send()) +} + +// EmitError implements the [RawLog] interface. +func (bL *backgroundLogImpl) EmitError(ctx context.Context, err error) { + maybeSetIsEmitted(err) + e := newAttachableEvent(ctx, bL.client, "", "error") + addErrorFields(e, err) + errorz.MaybeMustWrap(e.Send()) +} + +// EmitTraceLink implements the [RawLog] interface. +func (bL *backgroundLogImpl) EmitTraceLink(ctx context.Context, _ *TraceLink) { + bL.EmitWarning(ctx, errorz.Errorf("called EmitTraceLink in background Log")) +} + +// Begin implements the [RawLog] interface. +func (bL *backgroundLogImpl) Begin(ctx context.Context, name string, options ...BeginOption) (context.Context, func()) { + o := newBeginOptions(options...) + + sL := &spanLogImpl{ + m: &sync.Mutex{}, + b: bL.client.NewBuilder(), + startTime: clkm.MustGet(ctx).Now(), + name: name, + traceID: idz.MustNewRandomUUID(), + parentID: "", + spanID: idz.MustNewRandomUUID(), + metadata: o.metadata, + errMetadata: o.errMetadata, + hasErrorFlag: false, + } + + sL.b.AddField("trace.trace_id", sL.traceID) + ctx = NewSingletonInjector(sL)(ctx) + + return ctx, func() { + sL.end(ctx) + } +} + +// SetUser implements the [RawLog] interface. +func (bL *backgroundLogImpl) SetUser(ctx context.Context, _ *User) { + bL.EmitWarning(ctx, errorz.Errorf("called SetUser in background Log")) +} + +// SetPropagatingField implements the [RawLog] interface. +func (bL *backgroundLogImpl) SetPropagatingField(ctx context.Context, _ string, _ any) { + bL.EmitWarning(ctx, errorz.Errorf("called SetPropagatingField in background Log")) +} + +// SetMetadataKey implements the [RawLog] interface. +func (bL *backgroundLogImpl) SetMetadataKey(ctx context.Context, _ string, _ any) { + bL.EmitWarning(ctx, errorz.Errorf("called SetMetadataKey in background Log")) +} + +// SetErrorMetadataKey implements the [RawLog] interface. +func (bL *backgroundLogImpl) SetErrorMetadataKey(ctx context.Context, _ string, _ any) { + bL.EmitWarning(ctx, errorz.Errorf("called SetErrorMetadataKey in background Log")) +} + +// SetErrorFlag implements the [RawLog] interface. +func (bL *backgroundLogImpl) SetErrorFlag(ctx context.Context) { + bL.EmitWarning(ctx, errorz.Errorf("called SetErrorFlag in background Log")) +} + +// GetCurrentTraceLink implements the [RawLog] interface. +func (bL *backgroundLogImpl) GetCurrentTraceLink(_ context.Context) *TraceLink { + return nil +} + +// Flush implements the [RawLog] interface. +func (bL *backgroundLogImpl) Flush(_ context.Context) { + bL.client.Flush() +} diff --git a/logm/background_test.go b/logm/background_test.go new file mode 100644 index 0000000..89029ea --- /dev/null +++ b/logm/background_test.go @@ -0,0 +1,252 @@ +package logm_test + +import ( + "context" + "fmt" + "net/http" + "testing" + + "github.com/ibrt/golang-utils/fixturez" + "github.com/ibrt/golang-utils/idz" + . "github.com/onsi/gomega" + . "github.com/onsi/gomega/gstruct" + + "github.com/ibrt/golang-modules/clkm" + "github.com/ibrt/golang-modules/clkm/tclkm" + "github.com/ibrt/golang-modules/logm" + "github.com/ibrt/golang-modules/logm/tlogm" +) + +type testCompleteError struct { + message string + name string + status int +} + +func newTestCompleteError(message, name string, status int) *testCompleteError { + return &testCompleteError{ + message: message, + name: name, + status: status, + } +} + +func (e *testCompleteError) Error() string { + return e.message +} + +func (e *testCompleteError) GetErrorName() string { + return e.name +} + +func (e *testCompleteError) GetErrorHTTPStatus() int { + return e.status +} + +type BackgroundSuite struct { + CLK *tclkm.MockHelper + LOG *tlogm.MockHelper +} + +func TestBackgroundSuite(t *testing.T) { + fixturez.RunSuite(t, &BackgroundSuite{}) +} + +func (s *BackgroundSuite) TestBackgroundEmitDebug(ctx context.Context, g *WithT) { + logm.MustGet(ctx).EmitDebug("emit: background: debug: %v", + logm.EmitA("arg"), + logm.EmitM("ebdk", "ebdv")) + + g.Expect(s.LOG.GetMock().GetEvents()). + To(HaveExactElements( + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(clkm.MustGet(ctx).Now()), + "Data": And( + HaveKeyWithValue("debug", true), + HaveKeyWithValue("debug.message", "emit: background: debug: arg"), + HaveKeyWithValue("debug.metadata.ebdk", "ebdv"), + HaveKeyWithValue("name", "debug"), + ), + })))) +} + +func (s *BackgroundSuite) TestBackgroundEmitInfo(ctx context.Context, g *WithT) { + logm.MustGet(ctx).EmitInfo("emit: background: info: %v", + logm.EmitA("arg"), + logm.EmitM("ebik", "ebiv")) + + g.Expect(s.LOG.GetMock().GetEvents()). + To(HaveExactElements( + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(clkm.MustGet(ctx).Now()), + "Data": And( + HaveKeyWithValue("info", true), + HaveKeyWithValue("info.message", "emit: background: info: arg"), + HaveKeyWithValue("info.metadata.ebik", "ebiv"), + HaveKeyWithValue("name", "info"), + ), + })))) +} + +func (s *BackgroundSuite) TestBackgroundEmitWarning(ctx context.Context, g *WithT) { + logm.MustGet(ctx).EmitWarning( + newTestCompleteError( + "emit: background: warning", "emit-background-warning", http.StatusBadRequest)) + + g.Expect(s.LOG.GetMock().GetEvents()). + To(HaveExactElements( + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(clkm.MustGet(ctx).Now()), + "Data": And( + HaveKeyWithValue("warning", "emit-background-warning"), + HaveKeyWithValue("warning.message", "emit: background: warning"), + HaveKeyWithValue("warning.dump", HavePrefix("(errorz.dump)")), + HaveKeyWithValue("warning.status", http.StatusBadRequest), + HaveKeyWithValue("name", "warning"), + ), + })))) + + s.LOG.GetMock().ClearEvents() + logm.MustGet(ctx).EmitWarning(fmt.Errorf("emit: background: warning")) + + g.Expect(s.LOG.GetMock().GetEvents()). + To(HaveExactElements( + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(clkm.MustGet(ctx).Now()), + "Data": And( + HaveKeyWithValue("warning", "generic"), + HaveKeyWithValue("warning.message", "emit: background: warning"), + HaveKeyWithValue("warning.dump", HavePrefix("(errorz.dump)")), + Not(HaveKey("warning.status")), + HaveKeyWithValue("name", "warning"), + ), + })))) +} + +func (s *BackgroundSuite) TestBackgroundEmitError(ctx context.Context, g *WithT) { + logm.MustGet(ctx).EmitError( + newTestCompleteError( + "emit: background: error", "emit-background-error", http.StatusBadRequest)) + + g.Expect(s.LOG.GetMock().GetEvents()). + To(HaveExactElements( + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(clkm.MustGet(ctx).Now()), + "Data": And( + HaveKeyWithValue("error", "emit-background-error"), + HaveKeyWithValue("error.message", "emit: background: error"), + HaveKeyWithValue("error.dump", HavePrefix("(errorz.dump)")), + HaveKeyWithValue("error.status", http.StatusBadRequest), + HaveKeyWithValue("name", "error"), + ), + })))) + + s.LOG.GetMock().ClearEvents() + logm.MustGet(ctx).EmitError(fmt.Errorf("emit: background: error")) + + g.Expect(s.LOG.GetMock().GetEvents()). + To(HaveExactElements( + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(clkm.MustGet(ctx).Now()), + "Data": And( + HaveKeyWithValue("error", "generic"), + HaveKeyWithValue("error.message", "emit: background: error"), + HaveKeyWithValue("error.dump", HavePrefix("(errorz.dump)")), + Not(HaveKey("error.status")), + HaveKeyWithValue("name", "error"), + ), + })))) +} + +func (s *BackgroundSuite) TestBackgroundEmitTraceLink(ctx context.Context, g *WithT) { + logm.MustGet(ctx).EmitTraceLink(&logm.TraceLink{ + TraceID: idz.MustNewRandomUUID(), + SpanID: idz.MustNewRandomUUID(), + }) + + g.Expect(s.LOG.GetMock().GetEvents()). + To(HaveExactElements( + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(clkm.MustGet(ctx).Now()), + "Data": And( + HaveKeyWithValue("warning", "generic"), + HaveKeyWithValue("warning.message", "called EmitTraceLink in background Log"), + ), + })))) +} + +func (s *BackgroundSuite) TestBackgroundSetUser(ctx context.Context, g *WithT) { + logm.MustGet(ctx).SetUser(&logm.User{ + ID: idz.MustNewRandomUUID(), + }) + + g.Expect(s.LOG.GetMock().GetEvents()). + To(HaveExactElements( + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(clkm.MustGet(ctx).Now()), + "Data": And( + HaveKeyWithValue("warning", "generic"), + HaveKeyWithValue("warning.message", "called SetUser in background Log"), + ), + })))) +} + +func (s *BackgroundSuite) TestBackgroundSetPropagatingField(ctx context.Context, g *WithT) { + logm.MustGet(ctx).SetPropagatingField("k", "v") + + g.Expect(s.LOG.GetMock().GetEvents()). + To(HaveExactElements( + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(clkm.MustGet(ctx).Now()), + "Data": And( + HaveKeyWithValue("warning", "generic"), + HaveKeyWithValue("warning.message", "called SetPropagatingField in background Log"), + ), + })))) +} + +func (s *BackgroundSuite) TestBackgroundSetMetadataKey(ctx context.Context, g *WithT) { + logm.MustGet(ctx).SetMetadataKey("k", "v") + + g.Expect(s.LOG.GetMock().GetEvents()). + To(HaveExactElements( + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(clkm.MustGet(ctx).Now()), + "Data": And( + HaveKeyWithValue("warning", "generic"), + HaveKeyWithValue("warning.message", "called SetMetadataKey in background Log"), + ), + })))) +} + +func (s *BackgroundSuite) TestBackgroundSetErrorMetadataKey(ctx context.Context, g *WithT) { + logm.MustGet(ctx).SetErrorMetadataKey("k", "v") + + g.Expect(s.LOG.GetMock().GetEvents()). + To(HaveExactElements( + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(clkm.MustGet(ctx).Now()), + "Data": And( + HaveKeyWithValue("warning", "generic"), + HaveKeyWithValue("warning.message", "called SetErrorMetadataKey in background Log"), + ), + })))) +} + +func (s *BackgroundSuite) TestBackgroundSetErrorFlag(ctx context.Context, g *WithT) { + logm.MustGet(ctx).SetErrorFlag() + + g.Expect(s.LOG.GetMock().GetEvents()). + To(HaveExactElements( + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(clkm.MustGet(ctx).Now()), + "Data": And( + HaveKeyWithValue("warning", "generic"), + HaveKeyWithValue("warning.message", "called SetErrorFlag in background Log"), + ), + })))) +} + +func (s *BackgroundSuite) TestBackgroundGetCurrentTraceLink(ctx context.Context, g *WithT) { + g.Expect(logm.MustGet(ctx).GetCurrentTraceLink()).To(BeNil()) +} diff --git a/logm/config.go b/logm/config.go new file mode 100644 index 0000000..bf84ff3 --- /dev/null +++ b/logm/config.go @@ -0,0 +1,62 @@ +package logm + +import ( + "encoding" + + "github.com/ibrt/golang-utils/errorz" + "github.com/sirupsen/logrus" + + "github.com/ibrt/golang-modules/cfgm" +) + +var ( + _ encoding.TextUnmarshaler = (*LogConfigLogrusOutput)(nil) + _ cfgm.Config = (*LogConfig)(nil) + _ LogConfigMixin = (*LogConfig)(nil) +) + +// LogConfigLogrusOutput describes the acceptable values for [LogConfig.LogrusOutput]. +type LogConfigLogrusOutput string + +// Known LogConfigLogrusOutput values. +const ( + LogConfigLogrusOutputDisabled LogConfigLogrusOutput = cfgm.DisabledValue + LogConfigLogrusOutputHuman LogConfigLogrusOutput = "human" + LogConfigLogrusOutputJSON LogConfigLogrusOutput = "json" +) + +// UnmarshalText implements the [encoding.TextUnmarshaler] interface. +func (l *LogConfigLogrusOutput) UnmarshalText(text []byte) error { + switch v := LogConfigLogrusOutput(text); v { + case LogConfigLogrusOutputDisabled, LogConfigLogrusOutputHuman, LogConfigLogrusOutputJSON: + *l = v + return nil + default: + return errorz.Errorf("invalid value for LogConfigLogrusOutput: '%s'", v) + } +} + +// LogConfigMixin describes the module configuration. +type LogConfigMixin interface { + cfgm.Config + GetLogConfig() *LogConfig +} + +// LogConfig describes the module configuration. +type LogConfig struct { + HoneycombAPIKey string `env:"LOG_HONEYCOMB_API_KEY,required"` + HoneycombDataset string `env:"LOG_HONEYCOMB_DATASET,required"` + HoneycombSampleRate uint `env:"LOG_HONEYCOMB_SAMPLE_RATE,required"` + LogrusOutput LogConfigLogrusOutput `env:"LOG_LOGRUS_OUTPUT,required"` + LogrusLevel logrus.Level `env:"LOG_LOGRUS_LEVEL,required"` +} + +// Config implements the [cfgm.Config] interface. +func (c *LogConfig) Config() { + // intentionally empty +} + +// GetLogConfig implements the [LogConfigMixin] interface. +func (c *LogConfig) GetLogConfig() *LogConfig { + return c +} diff --git a/logm/config_test.go b/logm/config_test.go new file mode 100644 index 0000000..d17c4cb --- /dev/null +++ b/logm/config_test.go @@ -0,0 +1,57 @@ +package logm_test + +import ( + "testing" + + "github.com/caarlos0/env/v11" + "github.com/ibrt/golang-utils/envz" + "github.com/ibrt/golang-utils/fixturez" + . "github.com/onsi/gomega" + "github.com/sirupsen/logrus" + + "github.com/ibrt/golang-modules/cfgm" + "github.com/ibrt/golang-modules/logm" +) + +type ConfigSuite struct { + // intentionally empty +} + +func TestConfigSuite(t *testing.T) { + fixturez.RunSuite(t, &ConfigSuite{}) +} + +func (*ConfigSuite) TestLogConfig(g *WithT) { + envz.WithEnv( + map[string]string{ + "LOG_HONEYCOMB_API_KEY": cfgm.DisabledValue, + "LOG_HONEYCOMB_DATASET": "test", + "LOG_HONEYCOMB_SAMPLE_RATE": "1", + "LOG_LOGRUS_OUTPUT": cfgm.DisabledValue, + "LOG_LOGRUS_LEVEL": logrus.InfoLevel.String(), + }, + func() { + logCfg, err := env.ParseAs[logm.LogConfig]() + g.Expect(err).ToNot(HaveOccurred()) + g.Expect(logCfg).To(Equal(logm.LogConfig{ + HoneycombAPIKey: cfgm.DisabledValue, + HoneycombDataset: "test", + HoneycombSampleRate: 1, + LogrusOutput: cfgm.DisabledValue, + LogrusLevel: logrus.InfoLevel, + })) + }) + + envz.WithEnv( + map[string]string{ + "LOG_HONEYCOMB_API_KEY": cfgm.DisabledValue, + "LOG_HONEYCOMB_DATASET": "test", + "LOG_HONEYCOMB_SAMPLE_RATE": "1", + "LOG_LOGRUS_OUTPUT": "invalid", + "LOG_LOGRUS_LEVEL": logrus.InfoLevel.String(), + }, + func() { + _, err := env.ParseAs[logm.LogConfig]() + g.Expect(err).To(MatchError(`env: parse error on field "LogrusOutput" of type "logm.LogConfigLogrusOutput": invalid value for LogConfigLogrusOutput: 'invalid'`)) + }) +} diff --git a/logm/fields.go b/logm/fields.go new file mode 100644 index 0000000..008ccd0 --- /dev/null +++ b/logm/fields.go @@ -0,0 +1,247 @@ +package logm + +import ( + "context" + "fmt" + "reflect" + "regexp" + "strings" + "time" + + "github.com/honeycombio/libhoney-go" + "github.com/ibrt/golang-utils/errorz" + "github.com/ibrt/golang-utils/jsonz" + "github.com/ibrt/golang-utils/memz" + + "github.com/ibrt/golang-modules/clkm" +) + +// Some commonly used field keys. +const ( + StandardKeyParams = "params" + StandardKeySecondaryParams = "secondaryParams" +) + +type errorMetadataKey int + +const ( + isEmittedErrorMetadataKey errorMetadataKey = iota +) + +var ( + traceLinkRegexp = regexp.MustCompile(`^([\da-f]{8}-[\da-f]{4}-[\da-f]{4}-[\da-f]{4}-[\da-f]{12})-([\da-f]{8}-[\da-f]{4}-[\da-f]{4}-[\da-f]{4}-[\da-f]{12})$`) +) + +// TraceLink describes a link annotation. +type TraceLink struct { + TraceID string + SpanID string +} + +// Serialize the [*TraceLink]. +func (l *TraceLink) Serialize() string { + if l == nil { + return "" + } + if l.TraceID != "" && l.SpanID != "" { + return fmt.Sprintf("%v-%v", l.TraceID, l.SpanID) + } + return "" +} + +// MaybeParseTraceLink parses a serialized [*TraceLink]. +func MaybeParseTraceLink(traceLink string) *TraceLink { + matches := traceLinkRegexp.FindStringSubmatch(traceLink) + + if len(matches) != 3 { + return nil + } + + return &TraceLink{ + TraceID: matches[1], + SpanID: matches[2], + } +} + +// User describes a user. +type User struct { + ID string + Email string +} + +type fieldValueLen interface { + string | map[string]any | []string | EmitMetadata +} + +type fieldValueNumeric interface { + int | float64 +} + +type addField interface { + AddField(string, any) +} + +type newEvent interface { + NewEvent() *libhoney.Event +} + +func maybeAddLenField[T fieldValueLen](af addField, prefix, key string, value T) { + if len(value) == 0 { + return + } + + if prefix != "" { + if !strings.HasSuffix(prefix, ".") { + prefix += "." + } + } + + af.AddField(prefix+key, value) +} + +func maybeAddNumericField[T fieldValueNumeric](af addField, key string, value T) { + if value != 0 { + af.AddField(key, value) + } +} + +func addLocationFields(af addField, framesSource error) { + frames := memz.FilterSlice(errorz.GetFrames(framesSource), func(f *errorz.Frame) bool { + return f.ShortPackage != "logm" + }) + + if len(frames) > 0 { + maybeAddLenField(af, "", "location", frames[0].Summary) + maybeAddLenField(af, "", "location.short", frames[0].ShortLocation) + maybeAddLenField(af, "", "location.frames", memz.TransformSlice(frames, func(_ int, f *errorz.Frame) string { return f.Summary })) + } +} + +func maybeAddSpanEventAnnotationFields(af addField, spanID string) { + if spanID != "" { + af.AddField("meta.annotation_type", "span_event") + af.AddField("trace.parent_id", spanID) + } +} + +func maybeAddUserFields(af addField, user *User) { + if user != nil { + maybeAddLenField(af, "", "scope.user", user.ID) + maybeAddLenField(af, "", "scope.user.email", user.Email) + } +} + +func addMetadataFields(af addField, prefix string, metadata map[string]any) { + if prefix != "" { + if !strings.HasSuffix(prefix, ".") { + prefix += "." + } + } + + for k, v := range metadata { + if k == StandardKeyParams || k == StandardKeySecondaryParams { + k = StandardKeyParams + + if m, ok := maybeFlattenMetadataValue(v); ok { + for kk, vv := range m { + af.AddField(prefix+k+"."+kk, vv) + } + continue + } + } + + af.AddField(prefix+k, v) + } +} + +func maybeFlattenMetadataValue(v any) (map[string]any, bool) { + m, err := errorz.Catch1(func() (map[string]any, error) { + if reflect.Indirect(reflect.ValueOf(v)).Type().Kind() != reflect.Struct { + return nil, errorz.Errorf("not a struct") + } + + return jsonz.Unmarshal[map[string]any](jsonz.MustMarshal(v)) + }) + if err != nil || m == nil { + return nil, false + } + + return m, true +} + +func addDebugFields(af addField, format string, o *emitOptions) { + addLocationFields(af, nil) + af.AddField("debug", true) + maybeAddLenField(af, "", "debug.message", fmt.Sprintf(format, o.args...)) + addMetadataFields(af, "debug.metadata", o.metadata) +} + +func addInfoFields(af addField, format string, o *emitOptions) { + addLocationFields(af, nil) + af.AddField("info", true) + maybeAddLenField(af, "", "info.message", fmt.Sprintf(format, o.args...)) + addMetadataFields(af, "info.metadata", o.metadata) +} + +func addWarningFields(af addField, err error) { + addLocationFields(af, err) + af.AddField("warning", getWarningName(err)) + af.AddField("warning.message", err.Error()) + af.AddField("warning.dump", errorz.SDump(err)) + maybeAddNumericField(af, "warning.status", errorz.GetHTTPStatus(err, 0)) +} + +func addErrorFields(af addField, err error) { + addLocationFields(af, err) + af.AddField("error", getErrorName(err)) + af.AddField("error.message", err.Error()) + af.AddField("error.dump", errorz.SDump(err)) + maybeAddNumericField(af, "error.status", errorz.GetHTTPStatus(err, 0)) +} + +func newAttachableEvent(ctx context.Context, ne newEvent, attachedSpanID, name string) *libhoney.Event { + e := ne.NewEvent() + e.Timestamp = clkm.MustGet(ctx).Now() + maybeAddSpanEventAnnotationFields(e, attachedSpanID) + e.AddField("name", name) + return e +} + +func newTraceLinkEvent(ctx context.Context, ne newEvent, attachedSpanID string, traceLink *TraceLink) *libhoney.Event { + e := ne.NewEvent() + e.Timestamp = clkm.MustGet(ctx).Now() + e.AddField("meta.annotation_type", "link") + e.AddField("trace.parent_id", attachedSpanID) + e.AddField("trace.link.trace_id", traceLink.TraceID) + e.AddField("trace.link.span_id", traceLink.SpanID) + e.AddField("name", "link-annotation") + return e +} + +func newTraceableEvent(ctx context.Context, ne newEvent, name, spanID, parentSpanID string, startTime time.Time) *libhoney.Event { + e := ne.NewEvent() + e.Timestamp = startTime + addLocationFields(e, nil) + e.AddField("duration_ms", float64(clkm.MustGet(ctx).Now().Sub(startTime))/float64(time.Millisecond)) + e.AddField("name", name) + e.AddField("trace.span_id", spanID) + maybeAddLenField(e, "", "trace.parent_id", parentSpanID) + return e +} + +func getWarningName(err error) string { + return errorz.GetName(err, "generic") +} + +func getErrorName(err error) string { + return errorz.GetName(err, "generic") +} + +func maybeSetIsEmitted(err error) { + errorz.MaybeSetMetadata(err, isEmittedErrorMetadataKey, true) +} + +func getIsEmitted(err error) bool { + isEmitted, ok := errorz.MaybeGetMetadata[bool](err, isEmittedErrorMetadataKey) + return ok && isEmitted +} diff --git a/logm/fields_test.go b/logm/fields_test.go new file mode 100644 index 0000000..f074274 --- /dev/null +++ b/logm/fields_test.go @@ -0,0 +1,419 @@ +package logm + +import ( + "context" + "fmt" + "net/http" + "testing" + "time" + + "github.com/honeycombio/libhoney-go" + "github.com/ibrt/golang-utils/errorz" + "github.com/ibrt/golang-utils/fixturez" + "github.com/ibrt/golang-utils/idz" + "github.com/ibrt/golang-utils/memz" + . "github.com/onsi/gomega" + + "github.com/ibrt/golang-modules/clkm" + "github.com/ibrt/golang-modules/clkm/tclkm" +) + +var ( + _ addField = (*testAddField)(nil) + _ newEvent = (*testNewEvent)(nil) + _ error = (*testCompleteError)(nil) + _ errorz.ErrorName = (*testCompleteError)(nil) + _ errorz.ErrorHTTPStatus = (*testCompleteError)(nil) +) + +type testAddField struct { + fields map[string]any +} + +func newTestAddField() *testAddField { + return &testAddField{ + fields: make(map[string]any), + } +} + +func (t *testAddField) AddField(k string, v any) { + t.fields[k] = v +} + +type testNewEvent struct { + events []*libhoney.Event +} + +func newTestNewEvent() *testNewEvent { + return &testNewEvent{ + events: make([]*libhoney.Event, 0), + } +} + +func (t *testNewEvent) NewEvent() *libhoney.Event { + e := libhoney.NewEvent() + t.events = append(t.events, e) + return e +} + +type testCompleteError struct { + message string + name string + status int +} + +func newTestCompleteError(message, name string, status int) *testCompleteError { + return &testCompleteError{ + message: message, + name: name, + status: status, + } +} + +func (e *testCompleteError) Error() string { + return e.message +} + +func (e *testCompleteError) GetErrorName() string { + return e.name +} + +func (e *testCompleteError) GetErrorHTTPStatus() int { + return e.status +} + +type FieldsSuite struct { + CLK *tclkm.MockHelper +} + +func TestFieldsSuite(t *testing.T) { + fixturez.RunSuite(t, &FieldsSuite{}) +} + +func (*FieldsSuite) TestTraceLink(g *WithT) { + tID := idz.MustNewRandomUUID() + sID := idz.MustNewRandomUUID() + + g.Expect(MaybeParseTraceLink(memz.Ptr(TraceLink{ + // intentionally empty + }).Serialize())).To(BeNil()) + + g.Expect(MaybeParseTraceLink(memz.Ptr(TraceLink{ + TraceID: tID, + }).Serialize())).To(BeNil()) + + g.Expect(MaybeParseTraceLink(memz.Ptr(TraceLink{ + SpanID: sID, + }).Serialize())).To(BeNil()) + + g.Expect(MaybeParseTraceLink(memz.Ptr(TraceLink{ + TraceID: tID, + SpanID: sID, + }).Serialize())).To(Equal(&TraceLink{ + TraceID: tID, + SpanID: sID, + })) + + g.Expect(MaybeParseTraceLink(tID)).To(BeNil()) + g.Expect(MaybeParseTraceLink(fmt.Sprintf("%v-", tID))).To(BeNil()) + g.Expect((*TraceLink)(nil).Serialize()).To(Equal("")) +} + +func (*FieldsSuite) TestMaybeAddLenField(g *WithT) { + { + af := newTestAddField() + maybeAddLenField(af, "prefix", "key", "") + g.Expect(af.fields).To(BeEmpty()) + } + { + af := newTestAddField() + maybeAddLenField(af, "prefix", "key", "value") + g.Expect(af.fields).To(Equal(map[string]any{"prefix.key": "value"})) + } + { + af := newTestAddField() + maybeAddLenField(af, "", "key", "value") + g.Expect(af.fields).To(Equal(map[string]any{"key": "value"})) + } +} + +func (*FieldsSuite) TestMaybeAddNumericField(g *WithT) { + { + af := newTestAddField() + maybeAddNumericField(af, "key", 0) + g.Expect(af.fields).To(BeEmpty()) + } + { + af := newTestAddField() + maybeAddNumericField(af, "key", 1) + g.Expect(af.fields).To(Equal(map[string]any{"key": 1})) + } +} + +func (*FieldsSuite) TestAddLocationFields(g *WithT) { + err := errorz.Errorf("test error") + + frames := memz.FilterSlice(errorz.GetFrames(err), func(f *errorz.Frame) bool { + return f.ShortPackage != "logm" + }) + + af := newTestAddField() + addLocationFields(af, err) + + g.Expect(af.fields).To(And( + HaveKeyWithValue("location", frames[0].Summary), + HaveKeyWithValue("location.short", frames[0].ShortLocation), + HaveKeyWithValue("location.frames", Not(BeEmpty())), + )) +} + +func (*FieldsSuite) TestMaybeAddSpanEventAnnotationFields(g *WithT) { + { + af := newTestAddField() + maybeAddSpanEventAnnotationFields(af, "") + g.Expect(af.fields).To(BeEmpty()) + } + { + af := newTestAddField() + maybeAddSpanEventAnnotationFields(af, "span-id") + g.Expect(af.fields).To(Equal(map[string]any{ + "meta.annotation_type": "span_event", + "trace.parent_id": "span-id", + })) + } +} + +func (*FieldsSuite) TestMaybeAddUserFields(g *WithT) { + { + af := newTestAddField() + maybeAddUserFields(af, nil) + g.Expect(af.fields).To(BeEmpty()) + } + { + af := newTestAddField() + maybeAddUserFields(af, &User{ + ID: "user-id", + Email: "user-email", + }) + g.Expect(af.fields).To(Equal(map[string]any{ + "scope.user": "user-id", + "scope.user.email": "user-email", + })) + } +} + +func (*FieldsSuite) TestAddMetadataFields(g *WithT) { + type testStruct struct { + Key string `json:"key"` + } + + { + af := newTestAddField() + addMetadataFields(af, "", map[string]any{"k1": "v1"}) + g.Expect(af.fields).To(Equal(map[string]any{ + "k1": "v1", + })) + } + { + af := newTestAddField() + addMetadataFields(af, "prefix", map[string]any{"k1": "v1", "k2": &testStruct{Key: "v2"}}) + g.Expect(af.fields).To(Equal(map[string]any{ + "prefix.k1": "v1", + "prefix.k2": &testStruct{Key: "v2"}, + })) + } + { + af := newTestAddField() + addMetadataFields(af, "prefix", map[string]any{"k1": "v1", StandardKeyParams: &testStruct{Key: "v2"}}) + g.Expect(af.fields).To(Equal(map[string]any{ + "prefix.k1": "v1", + "prefix.params.key": "v2", + })) + } +} + +func (*FieldsSuite) TestMaybeFlattenMetadataValue(g *WithT) { + type testStruct struct { + Key string `json:"key"` + } + + { + m, ok := maybeFlattenMetadataValue(nil) + g.Expect(m).To(BeNil()) + g.Expect(ok).To(BeFalse()) + } + { + m, ok := maybeFlattenMetadataValue(1) + g.Expect(m).To(BeNil()) + g.Expect(ok).To(BeFalse()) + } + { + m, ok := maybeFlattenMetadataValue(map[string]any{}) + g.Expect(m).To(BeNil()) + g.Expect(ok).To(BeFalse()) + } + { + m, ok := maybeFlattenMetadataValue(testStruct{Key: "value"}) + g.Expect(m).To(Equal(map[string]any{"key": "value"})) + g.Expect(ok).To(BeTrue()) + } + { + m, ok := maybeFlattenMetadataValue(&testStruct{Key: "value"}) + g.Expect(m).To(Equal(map[string]any{"key": "value"})) + g.Expect(ok).To(BeTrue()) + } +} + +func (*FieldsSuite) TestAddDebugFields(g *WithT) { + af := newTestAddField() + addDebugFields(af, "fmt: %v", newEmitOptions(EmitA(1), EmitM("k", "v"))) + + g.Expect(af.fields).To(And( + HaveKeyWithValue("location", Not(BeEmpty())), + HaveKeyWithValue("debug", true), + HaveKeyWithValue("debug.message", "fmt: 1"), + HaveKeyWithValue("debug.metadata.k", "v"), + )) +} + +func (*FieldsSuite) TestAddInfoFields(g *WithT) { + af := newTestAddField() + addInfoFields(af, "fmt: %v", newEmitOptions(EmitA(1), EmitM("k", "v"))) + + g.Expect(af.fields).To(And( + HaveKeyWithValue("location", Not(BeEmpty())), + HaveKeyWithValue("info", true), + HaveKeyWithValue("info.message", "fmt: 1"), + HaveKeyWithValue("info.metadata.k", "v"), + )) +} + +func (*FieldsSuite) TestAddWarningFields(g *WithT) { + { + af := newTestAddField() + addWarningFields(af, errorz.Errorf("test error")) + + g.Expect(af.fields).To(And( + HaveKeyWithValue("location", Not(BeEmpty())), + HaveKeyWithValue("warning", "generic"), + HaveKeyWithValue("warning.message", "test error"), + HaveKeyWithValue("warning.dump", HavePrefix("(errorz.dump)")), + Not(HaveKey("warning.status")), + )) + } + { + af := newTestAddField() + addWarningFields(af, newTestCompleteError("test error", "name", http.StatusBadRequest)) + + g.Expect(af.fields).To(And( + HaveKeyWithValue("location", Not(BeEmpty())), + HaveKeyWithValue("warning", "name"), + HaveKeyWithValue("warning.message", "test error"), + HaveKeyWithValue("warning.dump", HavePrefix("(errorz.dump)")), + HaveKeyWithValue("warning.status", http.StatusBadRequest), + )) + } +} + +func (*FieldsSuite) TestAddErrorFields(g *WithT) { + { + af := newTestAddField() + addErrorFields(af, errorz.Errorf("test error")) + + g.Expect(af.fields).To(And( + HaveKeyWithValue("location", Not(BeEmpty())), + HaveKeyWithValue("error", "generic"), + HaveKeyWithValue("error.message", "test error"), + HaveKeyWithValue("error.dump", HavePrefix("(errorz.dump)")), + Not(HaveKey("error.status")), + )) + } + { + af := newTestAddField() + addErrorFields(af, newTestCompleteError("test error", "name", http.StatusBadRequest)) + + g.Expect(af.fields).To(And( + HaveKeyWithValue("location", Not(BeEmpty())), + HaveKeyWithValue("error", "name"), + HaveKeyWithValue("error.message", "test error"), + HaveKeyWithValue("error.dump", HavePrefix("(errorz.dump)")), + HaveKeyWithValue("error.status", http.StatusBadRequest), + )) + } +} + +func (*FieldsSuite) TestNewAttachableEvent(ctx context.Context, g *WithT) { + ne := newTestNewEvent() + e := newAttachableEvent(ctx, ne, "attached-span-id", "name") + + g.Expect(e.Timestamp).To(Equal(clkm.MustGet(ctx).Now())) + g.Expect(e.Fields()).To(Equal(map[string]any{ + "meta.annotation_type": "span_event", + "trace.parent_id": "attached-span-id", + "name": "name", + })) +} + +func (*FieldsSuite) TestNewTraceLinkEvent(ctx context.Context, g *WithT) { + ne := newTestNewEvent() + + e := newTraceLinkEvent( + ctx, ne, "attached-span-id", + &TraceLink{ + TraceID: "trace-id", + SpanID: "span-id", + }) + + g.Expect(e.Timestamp).To(Equal(clkm.MustGet(ctx).Now())) + + g.Expect(e.Fields()).To(Equal(map[string]any{ + "meta.annotation_type": "link", + "trace.parent_id": "attached-span-id", + "trace.link.trace_id": "trace-id", + "trace.link.span_id": "span-id", + "name": "link-annotation", + })) +} + +func (*FieldsSuite) TestNewTraceableEvent(ctx context.Context, g *WithT) { + ne := newTestNewEvent() + startTime := clkm.MustGet(ctx).Now().Add(-time.Second) + e := newTraceableEvent(ctx, ne, "name", "span-id", "parent-span-id", startTime) + + g.Expect(e.Timestamp).To(Equal(startTime)) + + g.Expect(e.Fields()).To(And( + HaveKeyWithValue("location", Not(BeEmpty())), + HaveKeyWithValue("duration_ms", BeNumerically("==", 1000)), + HaveKeyWithValue("name", "name"), + HaveKeyWithValue("trace.span_id", "span-id"), + HaveKeyWithValue("trace.parent_id", "parent-span-id"), + )) +} + +func (*FieldsSuite) TestGetWarningName(g *WithT) { + g.Expect(getWarningName(nil)).To(Equal("")) + g.Expect(getWarningName(fmt.Errorf("test error"))).To(Equal("generic")) + g.Expect(getWarningName(newTestCompleteError("", "name", 0))).To(Equal("name")) +} + +func (*FieldsSuite) TestGetErrorName(g *WithT) { + g.Expect(getErrorName(nil)).To(Equal("")) + g.Expect(getErrorName(fmt.Errorf("test error"))).To(Equal("generic")) + g.Expect(getErrorName(newTestCompleteError("", "name", 0))).To(Equal("name")) +} + +func (*FieldsSuite) TestIsEmitted(g *WithT) { + { + err := fmt.Errorf("test error") + g.Expect(getIsEmitted(err)).To(BeFalse()) + maybeSetIsEmitted(err) + g.Expect(getIsEmitted(err)).To(BeFalse()) + } + { + err := errorz.Errorf("test error") + g.Expect(getIsEmitted(err)).To(BeFalse()) + maybeSetIsEmitted(err) + g.Expect(getIsEmitted(err)).To(BeTrue()) + } +} diff --git a/logm/log.go b/logm/log.go new file mode 100644 index 0000000..fd5ddb1 --- /dev/null +++ b/logm/log.go @@ -0,0 +1,97 @@ +// Package logm implements a logging module. +package logm + +import ( + "context" + + "github.com/honeycombio/libhoney-go" + "github.com/ibrt/golang-utils/errorz" + "github.com/ibrt/golang-utils/injectz" + + "github.com/ibrt/golang-modules/cfgm" + "github.com/ibrt/golang-modules/clkm" +) + +type contextKey int + +const ( + logContextKey contextKey = iota +) + +// Log describes the module (with cached context). +type Log interface { + EmitDebug(format string, options ...EmitOption) + EmitInfo(format string, options ...EmitOption) + EmitWarning(err error) + EmitError(err error) + EmitTraceLink(traceLink *TraceLink) + Begin(name string, options ...BeginOption) (context.Context, func()) + SetUser(user *User) + SetPropagatingField(k string, v any) + SetMetadataKey(k string, v any) + SetErrorMetadataKey(k string, v any) + SetErrorFlag() + GetCurrentTraceLink() *TraceLink + Flush() +} + +// RawLog describes the module. +type RawLog interface { + EmitDebug(ctx context.Context, format string, options ...EmitOption) + EmitInfo(ctx context.Context, format string, options ...EmitOption) + EmitWarning(ctx context.Context, err error) + EmitError(ctx context.Context, err error) + EmitTraceLink(ctx context.Context, linkAnnotation *TraceLink) + Begin(ctx context.Context, name string, options ...BeginOption) (context.Context, func()) + SetErrorFlag(ctx context.Context) + SetUser(ctx context.Context, user *User) + SetPropagatingField(ctx context.Context, k string, v any) + SetMetadataKey(ctx context.Context, k string, v any) + SetErrorMetadataKey(ctx context.Context, k string, v any) + GetCurrentTraceLink(ctx context.Context) *TraceLink + Flush(ctx context.Context) +} + +// NewInitializer returns a new [injectz.Initializer] that configures the given client-level fields. +func NewInitializer(clientFields map[string]any) injectz.Initializer { + return func(ctx context.Context) (injectz.Injector, injectz.Releaser) { + clkm.MustGet(ctx) + logCfg := cfgm.MustGet[LogConfigMixin](ctx).GetLogConfig() + + client, err := libhoney.NewClient(libhoney.ClientConfig{ + APIKey: logCfg.HoneycombAPIKey, + Dataset: logCfg.HoneycombDataset, + SampleRate: logCfg.HoneycombSampleRate, + Transmission: NewSink( + MustNewDefaultLogrusLogger(ctx), + MustNewDefaultHoneycombSender(ctx)), + }) + errorz.MaybeMustWrap(err) + + for k, v := range clientFields { + client.AddField(k, v) + } + + return NewSingletonInjector(NewRawLogFromClient(client)), func() { client.Close() } + } +} + +// NewRawLogFromClient initializes a new [RawLog] using the given [*libhoney.Client]. +func NewRawLogFromClient(client *libhoney.Client) RawLog { + return &backgroundLogImpl{ + client: client, + } +} + +// NewSingletonInjector injects. +func NewSingletonInjector(log RawLog) injectz.Injector { + return injectz.NewSingletonInjector(logContextKey, log) +} + +// MustGet extracts, panics if not found. +func MustGet(ctx context.Context) Log { + return &adapterLogImpl{ + ctx: ctx, + rawLog: ctx.Value(logContextKey).(RawLog), + } +} diff --git a/logm/options.go b/logm/options.go new file mode 100644 index 0000000..c312b3f --- /dev/null +++ b/logm/options.go @@ -0,0 +1,135 @@ +package logm + +var ( + _ EmitOption = (EmitOptionFunc)(nil) + _ EmitOption = (EmitArgs)(nil) + _ EmitOption = (EmitMetadata)(nil) +) + +// EmitOption describes an option. +type EmitOption interface { + Apply(o *emitOptions) +} + +type emitOptions struct { + args []any + metadata EmitMetadata +} + +func newEmitOptions(options ...EmitOption) *emitOptions { + o := &emitOptions{ + metadata: EmitMetadata{}, + } + + for _, option := range options { + option.Apply(o) + } + return o +} + +// EmitOptionFunc is a shorthand for EmitOption. +type EmitOptionFunc func(o *emitOptions) + +// Apply implements the EmitOption interface. +func (f EmitOptionFunc) Apply(o *emitOptions) { + f(o) +} + +// EmitArgs describes a list of args. +type EmitArgs []any + +// Apply implements the EmitOption interface. +func (a EmitArgs) Apply(o *emitOptions) { + o.args = append(o.args, a...) +} + +// EmitA is a shorthand for EmitArgs. +func EmitA(a ...any) EmitArgs { + return a +} + +// EmitMetadata describes metadata. +type EmitMetadata map[string]any + +// Apply implements the EmitOption interface. +func (m EmitMetadata) Apply(o *emitOptions) { + for k, v := range m { + o.metadata[k] = v + } +} + +// EmitM is a shorthand for EmitMetadata. +func EmitM(k string, v any) EmitOptionFunc { + return func(o *emitOptions) { + o.metadata[k] = v + } +} + +var ( + _ BeginOption = (BeginOptionFunc)(nil) + _ BeginOption = (BeginMetadata)(nil) +) + +// BeginOption describes an option. +type BeginOption interface { + Apply(o *beginOptions) +} + +type beginOptions struct { + metadata BeginMetadata + errMetadata BeginErrMetadata +} + +func newBeginOptions(options ...BeginOption) *beginOptions { + o := &beginOptions{ + metadata: BeginMetadata{}, + errMetadata: BeginErrMetadata{}, + } + + for _, option := range options { + option.Apply(o) + } + return o +} + +// BeginOptionFunc is a shorthand for BeginOption. +type BeginOptionFunc func(o *beginOptions) + +// Apply implements the BeginOption interface. +func (f BeginOptionFunc) Apply(o *beginOptions) { + f(o) +} + +// BeginMetadata describes metadata. +type BeginMetadata map[string]any + +// Apply implements the BeginOption interface. +func (m BeginMetadata) Apply(o *beginOptions) { + for k, v := range m { + o.metadata[k] = v + } +} + +// BeginM is a shorthand for BeginMetadata. +func BeginM(k string, v any) BeginOptionFunc { + return func(o *beginOptions) { + o.metadata[k] = v + } +} + +// BeginErrMetadata describes metadata that is applied only in error cases. +type BeginErrMetadata map[string]any + +// Apply implements the BeginOption interface. +func (m BeginErrMetadata) Apply(o *beginOptions) { + for k, v := range m { + o.errMetadata[k] = v + } +} + +// BeginErrM is a shorthand for BeginErrMetadata. +func BeginErrM(k string, v any) BeginOptionFunc { + return func(o *beginOptions) { + o.errMetadata[k] = v + } +} diff --git a/logm/options_test.go b/logm/options_test.go new file mode 100644 index 0000000..ccff893 --- /dev/null +++ b/logm/options_test.go @@ -0,0 +1,48 @@ +package logm + +import ( + "testing" + + "github.com/ibrt/golang-utils/fixturez" + . "github.com/onsi/gomega" +) + +type OptionsSuite struct { + // intentionally empty +} + +func TestOptionsSuite(t *testing.T) { + fixturez.RunSuite(t, &OptionsSuite{}) +} + +func (*OptionsSuite) TestEmitOptions(g *WithT) { + g.Expect(newEmitOptions( + EmitA(1, 2, 3), + EmitM("k1", "v1"), + EmitMetadata{"k2": "v2"})). + To(Equal(&emitOptions{ + args: []any{1, 2, 3}, + metadata: map[string]any{ + "k1": "v1", + "k2": "v2", + }, + })) +} + +func (*OptionsSuite) TestBeginOptions(g *WithT) { + g.Expect(newBeginOptions( + BeginM("k1", "v1"), + BeginMetadata{"k2": "v2"}, + BeginErrM("ek1", "ev1"), + BeginErrMetadata{"ek2": "ev2"})). + To(Equal(&beginOptions{ + metadata: map[string]any{ + "k1": "v1", + "k2": "v2", + }, + errMetadata: map[string]any{ + "ek1": "ev1", + "ek2": "ev2", + }, + })) +} diff --git a/logm/sink.go b/logm/sink.go new file mode 100644 index 0000000..b23dbe6 --- /dev/null +++ b/logm/sink.go @@ -0,0 +1,185 @@ +package logm + +import ( + "context" + "fmt" + "time" + + "github.com/honeycombio/libhoney-go" + "github.com/honeycombio/libhoney-go/transmission" + "github.com/ibrt/golang-utils/errorz" + "github.com/ibrt/golang-utils/outz" + "github.com/sirupsen/logrus" + + "github.com/ibrt/golang-modules/cfgm" + "github.com/ibrt/golang-modules/clkm" +) + +var ( + _ transmission.Sender = (*Sink)(nil) +) + +var ( + messageKeys = []string{ + "debug.message", + "info.message", + "warning.message", + "error.message", + } +) + +// MustNewDefaultLogrusLogger initializes a default [*logrus.Logger] using the [LogConfigMixin] from context. +func MustNewDefaultLogrusLogger(ctx context.Context) *logrus.Logger { + if logCfg := cfgm.MustGet[LogConfigMixin](ctx).GetLogConfig(); logCfg.LogrusOutput != LogConfigLogrusOutputDisabled { + logger := outz.NewLogger() + logger.SetLevel(logCfg.LogrusLevel) + + switch v := logCfg.LogrusOutput; v { + case LogConfigLogrusOutputHuman: + logger.SetFormatter(outz.NewHumanLogFormatter().SetInitTime(clkm.MustGet(ctx).Now())) + case LogConfigLogrusOutputJSON: + logger.SetFormatter(&logrus.JSONFormatter{TimestampFormat: time.RFC3339Nano}) + default: + errorz.MustErrorf("invalid value for LogConfigLogrusOutput: '%s'", v) + } + + return logger + } + + return nil +} + +// MustNewDefaultHoneycombSender initializes a default [transmission.Sender] using the [LogConfigMixin] from context. +func MustNewDefaultHoneycombSender(ctx context.Context) transmission.Sender { + if apiKey := cfgm.MustGet[LogConfigMixin](ctx).GetLogConfig().HoneycombAPIKey; apiKey != "" && apiKey != cfgm.DisabledValue { + return &transmission.Honeycomb{ + BatchTimeout: libhoney.DefaultBatchTimeout, + BlockOnSend: true, + MaxBatchSize: libhoney.DefaultMaxBatchSize, + MaxConcurrentBatches: libhoney.DefaultMaxConcurrentBatches, + PendingWorkCapacity: libhoney.DefaultPendingWorkCapacity, + } + } + + return nil +} + +// Sink describes a sink. +type Sink struct { + l *logrus.Logger + s transmission.Sender + c chan transmission.Response +} + +// NewSink initializes a new [*Sink]. +func NewSink(logger *logrus.Logger, sender transmission.Sender) *Sink { + s := &Sink{ + l: logger, + s: sender, + } + + if sender == nil { + s.c = make(chan transmission.Response) + } + + return s +} + +// Add implements the transmission.Sender interface. +func (s *Sink) Add(e *transmission.Event) { + if s.l != nil { + logrus.NewEntry(s.l). + WithTime(e.Timestamp). + WithFields(e.Data). + Log(s.getLevel(e.Data), s.getMessage(e.Data)) + } + + if s.s != nil { + s.s.Add(e) + } +} + +func (s *Sink) getLevel(data map[string]any) logrus.Level { + if _, ok := data["debug"]; ok { + return logrus.DebugLevel + } else if _, ok := data["info"]; ok { + return logrus.InfoLevel + } else if _, ok := data["warning"]; ok { + return logrus.WarnLevel + } else if _, ok := data["error"]; ok { + return logrus.ErrorLevel + } else { + return logrus.DebugLevel + } +} + +func (s *Sink) getMessage(data map[string]any) string { + msg := "" + + for _, k := range messageKeys { + if v, ok := data[k].(string); ok && v != "" { + msg = v + break + } + } + + if name, ok := data["name"].(string); ok && name != "" { + if msg != "" { + return fmt.Sprintf("%v: %v", name, msg) + } + return name + } + + return msg +} + +// Start implements the transmission.Sender interface. +func (s *Sink) Start() error { + if s.s != nil { + return s.s.Start() + } + + return nil +} + +// Stop implements the transmission.Sender interface. +func (s *Sink) Stop() error { + if s.s != nil { + return s.s.Stop() + } + + close(s.c) + return nil +} + +// Flush implements the transmission.Sender interface. +func (s *Sink) Flush() error { + if s.s != nil { + return s.s.Flush() + } + + return nil +} + +// TxResponses implements the transmission.Sender interface. +func (s *Sink) TxResponses() chan transmission.Response { + if s.s != nil { + return s.s.TxResponses() + } + + return s.c +} + +// SendResponse implements the transmission.Sender interface. +func (s *Sink) SendResponse(response transmission.Response) bool { + if s.s != nil { + return s.s.SendResponse(response) + } + + select { + case s.c <- response: + return false + default: + return true + } +} diff --git a/logm/sink_test.go b/logm/sink_test.go new file mode 100644 index 0000000..40f4360 --- /dev/null +++ b/logm/sink_test.go @@ -0,0 +1,291 @@ +package logm_test + +import ( + "context" + "fmt" + "sync/atomic" + "testing" + "time" + + "github.com/honeycombio/libhoney-go" + "github.com/honeycombio/libhoney-go/transmission" + "github.com/ibrt/golang-utils/fixturez" + "github.com/ibrt/golang-utils/outz" + . "github.com/onsi/gomega" + "github.com/sirupsen/logrus" + + "github.com/ibrt/golang-modules/cfgm" + "github.com/ibrt/golang-modules/clkm" + "github.com/ibrt/golang-modules/clkm/tclkm" + "github.com/ibrt/golang-modules/logm" + "github.com/ibrt/golang-modules/logm/tlogm" +) + +type SinkSuite struct { + CLK *tclkm.MockHelper +} + +func TestSinkSuite(t *testing.T) { + fixturez.RunSuite(t, &SinkSuite{}) +} + +func (s *SinkSuite) TestSink_Logger_Other(ctx context.Context, g *WithT) { + outz.MustBeginOutputCapture(outz.OutputSetupSirupsenLogrus) + defer outz.ResetOutputCapture() + + logger := outz.NewLogger() + logger.SetFormatter(&logrus.JSONFormatter{TimestampFormat: time.RFC3339Nano}) + logger.SetLevel(logrus.DebugLevel) + + sink := logm.NewSink(logger, nil) + sink.Add(&transmission.Event{ + Timestamp: clkm.MustGet(ctx).Now(), + Data: map[string]any{ + "name": "name", + "k": "v", + }, + }) + + outBuf, errBuf := outz.MustEndOutputCapture() + g.Expect(outBuf).To(Equal("")) + + g.Expect(errBuf).To(Equal(fmt.Sprintf( + "{\"k\":\"v\",\"level\":\"debug\",\"msg\":\"name\",\"name\":\"name\",\"time\":\"%v\"}\n", + clkm.MustGet(ctx).Now().Format(time.RFC3339Nano)))) +} + +func (s *SinkSuite) TestSink_Logger_Debug(ctx context.Context, g *WithT) { + outz.MustBeginOutputCapture(outz.OutputSetupSirupsenLogrus) + defer outz.ResetOutputCapture() + + logger := outz.NewLogger() + logger.SetFormatter(&logrus.JSONFormatter{TimestampFormat: time.RFC3339Nano}) + logger.SetLevel(logrus.DebugLevel) + + sink := logm.NewSink(logger, nil) + sink.Add(&transmission.Event{ + Timestamp: clkm.MustGet(ctx).Now(), + Data: map[string]any{ + "debug": true, + "debug.message": "msg", + "k": "v", + "name": "name", + }, + }) + + outBuf, errBuf := outz.MustEndOutputCapture() + g.Expect(outBuf).To(Equal("")) + + g.Expect(errBuf).To(Equal(fmt.Sprintf( + "{\"debug\":true,\"debug.message\":\"msg\",\"k\":\"v\",\"level\":\"debug\",\"msg\":\"name: msg\",\"name\":\"name\",\"time\":\"%v\"}\n", + clkm.MustGet(ctx).Now().Format(time.RFC3339Nano)))) +} + +func (s *SinkSuite) TestSink_Logger_Info(ctx context.Context, g *WithT) { + outz.MustBeginOutputCapture(outz.OutputSetupSirupsenLogrus) + defer outz.ResetOutputCapture() + + logger := outz.NewLogger() + logger.SetFormatter(&logrus.JSONFormatter{TimestampFormat: time.RFC3339Nano}) + logger.SetLevel(logrus.DebugLevel) + + sink := logm.NewSink(logger, nil) + sink.Add(&transmission.Event{ + Timestamp: clkm.MustGet(ctx).Now(), + Data: map[string]any{ + "info": true, + "k": "v", + }, + }) + + outBuf, errBuf := outz.MustEndOutputCapture() + g.Expect(outBuf).To(Equal("")) + + g.Expect(errBuf).To(Equal(fmt.Sprintf( + "{\"info\":true,\"k\":\"v\",\"level\":\"info\",\"msg\":\"\",\"time\":\"%v\"}\n", + clkm.MustGet(ctx).Now().Format(time.RFC3339Nano)))) +} + +func (s *SinkSuite) TestSink_Logger_Warning(ctx context.Context, g *WithT) { + outz.MustBeginOutputCapture(outz.OutputSetupSirupsenLogrus) + defer outz.ResetOutputCapture() + + logger := outz.NewLogger() + logger.SetFormatter(&logrus.JSONFormatter{TimestampFormat: time.RFC3339Nano}) + logger.SetLevel(logrus.DebugLevel) + + sink := logm.NewSink(logger, nil) + sink.Add(&transmission.Event{ + Timestamp: clkm.MustGet(ctx).Now(), + Data: map[string]any{ + "warning": true, + "k": "v", + }, + }) + + outBuf, errBuf := outz.MustEndOutputCapture() + g.Expect(outBuf).To(Equal("")) + + g.Expect(errBuf).To(Equal(fmt.Sprintf( + "{\"k\":\"v\",\"level\":\"warning\",\"msg\":\"\",\"time\":\"%v\",\"warning\":true}\n", + clkm.MustGet(ctx).Now().Format(time.RFC3339Nano)))) +} + +func (s *SinkSuite) TestSink_Logger_Error(ctx context.Context, g *WithT) { + outz.MustBeginOutputCapture(outz.OutputSetupSirupsenLogrus) + defer outz.ResetOutputCapture() + + logger := outz.NewLogger() + logger.SetFormatter(&logrus.JSONFormatter{TimestampFormat: time.RFC3339Nano}) + logger.SetLevel(logrus.DebugLevel) + + sink := logm.NewSink(logger, nil) + sink.Add(&transmission.Event{ + Timestamp: clkm.MustGet(ctx).Now(), + Data: map[string]any{ + "error": true, + "k": "v", + }, + }) + + outBuf, errBuf := outz.MustEndOutputCapture() + g.Expect(outBuf).To(Equal("")) + + g.Expect(errBuf).To(Equal(fmt.Sprintf( + "{\"error\":true,\"k\":\"v\",\"level\":\"error\",\"msg\":\"\",\"time\":\"%v\"}\n", + clkm.MustGet(ctx).Now().Format(time.RFC3339Nano)))) +} + +func (s *SinkSuite) TestSink_Responses(g *WithT) { + sink := logm.NewSink(nil, nil) + g.Expect(sink.SendResponse(transmission.Response{})).To(BeTrue()) + g.Expect(sink.Flush()).To(Succeed()) + + ok := &atomic.Bool{} + closed := &atomic.Bool{} + + go func() { + defer func() { + closed.Store(true) + }() + + for range sink.TxResponses() { + ok.Store(true) + } + }() + + g.Eventually(func() bool { return sink.SendResponse(transmission.Response{}) }, "1s", "10ms").Should(BeFalse()) + g.Eventually(ok.Load, "1s", "10ms").Should(BeTrue()) + g.Expect(sink.Stop()).To(Succeed()) + g.Eventually(closed.Load, "1s", "10ms").Should(BeTrue()) +} + +func (s *SinkSuite) TestSink_Sender(ctx context.Context, g *WithT) { + sender := tlogm.NewMockSender() + sink := logm.NewSink(nil, sender) + + g.Expect(sink.Start()).To(Succeed()) + + sink.Add(&transmission.Event{Timestamp: clkm.MustGet(ctx).Now()}) + g.Expect(sender.GetEvents()).To(HaveExactElements(&transmission.Event{Timestamp: clkm.MustGet(ctx).Now()})) + + g.Expect(sink.SendResponse(transmission.Response{})).To(BeTrue()) + g.Expect(sink.Flush()).To(Succeed()) + + ok := &atomic.Bool{} + closed := &atomic.Bool{} + + go func() { + defer func() { + closed.Store(true) + }() + + for range sink.TxResponses() { + ok.Store(true) + } + }() + + g.Eventually(func() bool { return sink.SendResponse(transmission.Response{}) }, "1s", "10ms").Should(BeFalse()) + g.Eventually(ok.Load, "1s", "10ms").Should(BeTrue()) + g.Expect(sink.Stop()).To(Succeed()) + g.Eventually(closed.Load, "1s", "10ms").Should(BeTrue()) +} + +func (s *SinkSuite) TestSink_Noop(g *WithT) { + sink := logm.NewSink(nil, nil) + g.Expect(sink.Start()).To(BeNil()) + g.Expect(func() { sink.Add(nil) }).ToNot(Panic()) + g.Expect(sink.Flush()).To(BeNil()) + g.Expect(sink.Stop()).To(BeNil()) +} + +func (s *SinkSuite) TestMustNewDefaultLogrusLogger(ctx context.Context, g *WithT) { + { + g.Expect( + logm.MustNewDefaultLogrusLogger( + cfgm.NewSingletonInjector[logm.LogConfigMixin](&logm.LogConfig{ + LogrusOutput: cfgm.DisabledValue, + LogrusLevel: logrus.InfoLevel, + })(ctx))). + To(BeNil()) + } + { + logger := logm.MustNewDefaultLogrusLogger( + cfgm.NewSingletonInjector[logm.LogConfigMixin](&logm.LogConfig{ + LogrusOutput: logm.LogConfigLogrusOutputHuman, + LogrusLevel: logrus.WarnLevel, + })(ctx)) + + g.Expect(logger).ToNot(BeNil()) + g.Expect(logger.Level).To(Equal(logrus.WarnLevel)) + + _, ok := logger.Formatter.(*outz.HumanLogFormatter) + g.Expect(ok).To(BeTrue()) + } + { + logger := logm.MustNewDefaultLogrusLogger( + cfgm.NewSingletonInjector[logm.LogConfigMixin](&logm.LogConfig{ + LogrusOutput: logm.LogConfigLogrusOutputJSON, + LogrusLevel: logrus.TraceLevel, + })(ctx)) + + g.Expect(logger).ToNot(BeNil()) + g.Expect(logger.Level).To(Equal(logrus.TraceLevel)) + + _, ok := logger.Formatter.(*logrus.JSONFormatter) + g.Expect(ok).To(BeTrue()) + } + + g.Expect(func() { + logm.MustNewDefaultLogrusLogger( + cfgm.NewSingletonInjector[logm.LogConfigMixin](&logm.LogConfig{ + LogrusOutput: "invalid", + LogrusLevel: logrus.TraceLevel, + })(ctx)) + }).To(PanicWith(MatchError("invalid value for LogConfigLogrusOutput: 'invalid'"))) +} + +func (s *SinkSuite) TestMustNewDefaultHoneycombSender(ctx context.Context, g *WithT) { + { + g.Expect( + logm.MustNewDefaultHoneycombSender( + cfgm.NewSingletonInjector[logm.LogConfigMixin](&logm.LogConfig{ + HoneycombAPIKey: cfgm.DisabledValue, + })(ctx))). + To(BeNil()) + } + { + g.Expect( + logm.MustNewDefaultHoneycombSender( + cfgm.NewSingletonInjector[logm.LogConfigMixin](&logm.LogConfig{ + HoneycombAPIKey: "test-honeycomb-api-key", + })(ctx))). + To(Equal(&transmission.Honeycomb{ + BatchTimeout: libhoney.DefaultBatchTimeout, + BlockOnSend: true, + MaxBatchSize: libhoney.DefaultMaxBatchSize, + MaxConcurrentBatches: libhoney.DefaultMaxConcurrentBatches, + PendingWorkCapacity: libhoney.DefaultPendingWorkCapacity, + })) + } +} diff --git a/logm/span.go b/logm/span.go new file mode 100644 index 0000000..de8585a --- /dev/null +++ b/logm/span.go @@ -0,0 +1,181 @@ +package logm + +import ( + "context" + "fmt" + "strings" + "sync" + "time" + + "github.com/honeycombio/libhoney-go" + "github.com/ibrt/golang-utils/errorz" + "github.com/ibrt/golang-utils/idz" + + "github.com/ibrt/golang-modules/clkm" +) + +var ( + _ RawLog = (*spanLogImpl)(nil) +) + +type spanLogImpl struct { + m *sync.Mutex + b *libhoney.Builder + startTime time.Time + name string + traceID string + parentID string + spanID string + metadata map[string]any + errMetadata map[string]any + hasErrorFlag bool +} + +// EmitDebug implements the RawLog interface. +func (sL *spanLogImpl) EmitDebug(ctx context.Context, format string, options ...EmitOption) { + sL.m.Lock() + defer sL.m.Unlock() + + o := newEmitOptions(options...) + e := newAttachableEvent(ctx, sL.b, sL.spanID, "debug") + addDebugFields(e, format, o) + errorz.MaybeMustWrap(e.Send()) +} + +// EmitInfo implements the RawLog interface. +func (sL *spanLogImpl) EmitInfo(ctx context.Context, format string, options ...EmitOption) { + sL.m.Lock() + defer sL.m.Unlock() + + o := newEmitOptions(options...) + e := newAttachableEvent(ctx, sL.b, sL.spanID, "info") + addInfoFields(e, format, o) + errorz.MaybeMustWrap(e.Send()) +} + +// EmitWarning implements the RawLog interface. +func (sL *spanLogImpl) EmitWarning(ctx context.Context, err error) { + sL.m.Lock() + defer sL.m.Unlock() + + maybeSetIsEmitted(err) + e := newAttachableEvent(ctx, sL.b, sL.spanID, "warning") + addWarningFields(e, err) + errorz.MaybeMustWrap(e.Send()) +} + +// EmitError implements the RawLog interface. +func (sL *spanLogImpl) EmitError(ctx context.Context, err error) { + sL.m.Lock() + defer sL.m.Unlock() + + maybeSetIsEmitted(err) + sL.hasErrorFlag = true + e := newAttachableEvent(ctx, sL.b, sL.spanID, "error") + addErrorFields(e, err) + errorz.MaybeMustWrap(e.Send()) +} + +// EmitTraceLink implements the RawLog interface. +func (sL *spanLogImpl) EmitTraceLink(ctx context.Context, traceLink *TraceLink) { + sL.m.Lock() + defer sL.m.Unlock() + + if traceLink != nil && traceLink.Serialize() != "" { + e := newTraceLinkEvent(ctx, sL.b, sL.spanID, traceLink) + errorz.MaybeMustWrap(e.Send()) + } +} + +// Begin implements the RawLog interface. +func (sL *spanLogImpl) Begin(ctx context.Context, name string, options ...BeginOption) (context.Context, func()) { + sL.m.Lock() + defer sL.m.Unlock() + + o := newBeginOptions(options...) + + nsL := &spanLogImpl{ + m: &sync.Mutex{}, + b: sL.b.Clone(), + startTime: clkm.MustGet(ctx).Now(), + name: name, + traceID: sL.traceID, + parentID: sL.spanID, + spanID: idz.MustNewRandomUUID(), + metadata: o.metadata, + errMetadata: o.errMetadata, + hasErrorFlag: false, + } + + ctx = NewSingletonInjector(nsL)(ctx) + + return ctx, func() { + nsL.end(ctx) + } +} + +func (sL *spanLogImpl) end(ctx context.Context) { + sL.m.Lock() + defer sL.m.Unlock() + + e := newTraceableEvent(ctx, sL.b, sL.name, sL.spanID, sL.parentID, sL.startTime) + addMetadataFields(e, "scope.metadata", sL.metadata) + + if sL.hasErrorFlag { + e.AddField("error", true) + addMetadataFields(e, "scope.metadata", sL.errMetadata) + } + + errorz.MaybeMustWrap(e.Send()) +} + +// SetUser implements the RawLog interface. +func (sL *spanLogImpl) SetUser(_ context.Context, user *User) { + sL.m.Lock() + defer sL.m.Unlock() + maybeAddUserFields(sL.b, user) +} + +// SetPropagatingField implements the RawLog interface. +func (sL *spanLogImpl) SetPropagatingField(_ context.Context, k string, v any) { + sL.m.Lock() + defer sL.m.Unlock() + sL.b.AddField(fmt.Sprintf("scope.%v", strings.TrimPrefix(k, "scope.")), v) +} + +// SetMetadataKey implements the RawLog interface. +func (sL *spanLogImpl) SetMetadataKey(_ context.Context, k string, v any) { + sL.m.Lock() + defer sL.m.Unlock() + sL.metadata[k] = v +} + +// SetErrorMetadataKey implements the RawLog interface. +func (sL *spanLogImpl) SetErrorMetadataKey(_ context.Context, k string, v any) { + sL.m.Lock() + defer sL.m.Unlock() + sL.errMetadata[k] = v +} + +// SetErrorFlag implements the RawLog interface. +func (sL *spanLogImpl) SetErrorFlag(_ context.Context) { + sL.m.Lock() + defer sL.m.Unlock() + sL.hasErrorFlag = true +} + +// GetCurrentTraceLink implements the RawLog interface. +func (sL *spanLogImpl) GetCurrentTraceLink(_ context.Context) *TraceLink { + sL.m.Lock() + defer sL.m.Unlock() + + return &TraceLink{ + TraceID: sL.traceID, + SpanID: sL.spanID, + } +} + +// Flush implements the RawLog interface. +func (sL *spanLogImpl) Flush(_ context.Context) { + // do nothing: flushing is only enabled on the background log +} diff --git a/logm/span_test.go b/logm/span_test.go new file mode 100644 index 0000000..c8b68c8 --- /dev/null +++ b/logm/span_test.go @@ -0,0 +1,220 @@ +package logm_test + +import ( + "context" + "net/http" + "testing" + "time" + + "github.com/ibrt/golang-utils/fixturez" + . "github.com/onsi/gomega" + . "github.com/onsi/gomega/gstruct" + + "github.com/ibrt/golang-modules/clkm" + "github.com/ibrt/golang-modules/clkm/tclkm" + "github.com/ibrt/golang-modules/logm" + "github.com/ibrt/golang-modules/logm/tlogm" +) + +type SpanSuite struct { + CLK *tclkm.MockHelper + LOG *tlogm.MockHelper +} + +func TestSpanSuite(t *testing.T) { + fixturez.RunSuite(t, &SpanSuite{}) +} + +func (s *SpanSuite) TestSpan(ctx context.Context, g *WithT) { + // + s.CLK.GetMock().Add(time.Second) + t1 := clkm.MustGet(ctx).Now() + + ctx, e1 := logm.MustGet(ctx).Begin("S1") + g.Expect(logm.MustGet(ctx).GetCurrentTraceLink().Serialize()).ToNot(BeEmpty()) + logm.MustGet(ctx).SetUser(&logm.User{ID: "user-id", Email: "user-email"}) + logm.MustGet(ctx).SetMetadataKey("k01", "v01") + + s.CLK.GetMock().Add(time.Second) + t2 := clkm.MustGet(ctx).Now() + + logm.MustGet(ctx).EmitDebug("emit: span: debug: %v", + logm.EmitA("arg"), + logm.EmitMetadata{"k02": "v02"}) + + logm.MustGet(ctx).EmitInfo("emit: span: info: %v", + logm.EmitA("arg"), + logm.EmitMetadata{"k02": "v02"}) + + // + s.CLK.GetMock().Add(time.Second) + t3 := clkm.MustGet(ctx).Now() + + ctx, e2 := logm.MustGet(ctx).Begin("S2") + logm.MustGet(ctx).SetPropagatingField("kp", "vp") + logm.MustGet(ctx).SetMetadataKey("k03", "v03") + logm.MustGet(ctx).SetErrorFlag() + + s.CLK.GetMock().Add(time.Second) + t4 := clkm.MustGet(ctx).Now() + + logm.MustGet(ctx).EmitWarning( + newTestCompleteError("emit: span: warning", "emit-span-warning", http.StatusBadRequest)) + + // + s.CLK.GetMock().Add(time.Second) + t5 := clkm.MustGet(ctx).Now() + + ctx, e3 := logm.MustGet(ctx).Begin("S3") + logm.MustGet(ctx).SetMetadataKey("k05", "v05") + + s.CLK.GetMock().Add(time.Second) + t6 := clkm.MustGet(ctx).Now() + + logm.MustGet(ctx).EmitTraceLink(&logm.TraceLink{ + TraceID: "link-trace-id", + SpanID: "link-span-id"}) + + logm.MustGet(ctx).EmitError( + newTestCompleteError("emit: span: error", "emit-span-error", http.StatusBadRequest)) + + s.CLK.GetMock().Add(time.Second) + + e3() + // + + s.CLK.GetMock().Add(time.Second) + + e2() + // + + s.CLK.GetMock().Add(time.Second) + + e1() + // + + g.Expect(s.LOG.GetMock().GetEvents()). + To(HaveExactElements( + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t2), + "Data": And( + HaveKeyWithValue("debug", true), + HaveKeyWithValue("debug.message", "emit: span: debug: arg"), + HaveKeyWithValue("debug.metadata.k02", "v02"), + HaveKeyWithValue("name", "debug"), + HaveKeyWithValue("meta.annotation_type", "span_event"), + HaveKeyWithValue("scope.user", "user-id"), + HaveKeyWithValue("scope.user.email", "user-email"), + HaveKey("trace.trace_id"), + HaveKey("trace.parent_id"), + Not(HaveKey("trace.span_id")), + ), + })), + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t2), + "Data": And( + HaveKeyWithValue("info", true), + HaveKeyWithValue("info.message", "emit: span: info: arg"), + HaveKeyWithValue("info.metadata.k02", "v02"), + HaveKeyWithValue("name", "info"), + HaveKeyWithValue("meta.annotation_type", "span_event"), + HaveKeyWithValue("scope.user", "user-id"), + HaveKeyWithValue("scope.user.email", "user-email"), + HaveKey("trace.trace_id"), + HaveKey("trace.parent_id"), + Not(HaveKey("trace.span_id")), + ), + })), + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t4), + "Data": And( + HaveKeyWithValue("warning", "emit-span-warning"), + HaveKeyWithValue("warning.message", "emit: span: warning"), + HaveKeyWithValue("warning.dump", HavePrefix("(errorz.dump)")), + HaveKeyWithValue("warning.status", http.StatusBadRequest), + HaveKeyWithValue("name", "warning"), + HaveKeyWithValue("meta.annotation_type", "span_event"), + HaveKeyWithValue("scope.user", "user-id"), + HaveKeyWithValue("scope.user.email", "user-email"), + HaveKeyWithValue("scope.kp", "vp"), + HaveKey("trace.trace_id"), + HaveKey("trace.parent_id"), + Not(HaveKey("trace.span_id")), + ), + })), + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t6), + "Data": And( + HaveKeyWithValue("name", "link-annotation"), + HaveKeyWithValue("meta.annotation_type", "link"), + HaveKeyWithValue("trace.link.trace_id", "link-trace-id"), + HaveKeyWithValue("trace.link.span_id", "link-span-id"), + HaveKeyWithValue("scope.user", "user-id"), + HaveKeyWithValue("scope.user.email", "user-email"), + HaveKeyWithValue("scope.kp", "vp"), + HaveKey("trace.trace_id"), + HaveKey("trace.parent_id"), + Not(HaveKey("trace.span_id")), + ), + })), + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t6), + "Data": And( + HaveKeyWithValue("error", "emit-span-error"), + HaveKeyWithValue("error.message", "emit: span: error"), + HaveKeyWithValue("error.dump", HavePrefix("(errorz.dump)")), + HaveKeyWithValue("error.status", http.StatusBadRequest), + HaveKeyWithValue("name", "error"), + HaveKeyWithValue("meta.annotation_type", "span_event"), + HaveKeyWithValue("scope.user", "user-id"), + HaveKeyWithValue("scope.user.email", "user-email"), + HaveKeyWithValue("scope.kp", "vp"), + HaveKey("trace.trace_id"), + HaveKey("trace.parent_id"), + Not(HaveKey("trace.span_id")), + ), + })), + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t5), + "Data": And( + HaveKeyWithValue("name", "S3"), + HaveKeyWithValue("duration_ms", float64(2000)), + HaveKeyWithValue("scope.user", "user-id"), + HaveKeyWithValue("scope.user.email", "user-email"), + HaveKeyWithValue("scope.metadata.k05", "v05"), + HaveKeyWithValue("scope.kp", "vp"), + HaveKey("trace.trace_id"), + HaveKey("trace.parent_id"), + HaveKey("trace.span_id"), + ), + })), + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t3), + "Data": And( + HaveKeyWithValue("error", true), + HaveKeyWithValue("name", "S2"), + HaveKeyWithValue("duration_ms", float64(5000)), + HaveKeyWithValue("scope.user", "user-id"), + HaveKeyWithValue("scope.user.email", "user-email"), + HaveKeyWithValue("scope.metadata.k03", "v03"), + HaveKeyWithValue("scope.kp", "vp"), + HaveKey("trace.trace_id"), + HaveKey("trace.parent_id"), + HaveKey("trace.span_id"), + ), + })), + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1), + "Data": And( + HaveKeyWithValue("name", "S1"), + HaveKeyWithValue("duration_ms", float64(8000)), + HaveKeyWithValue("scope.user", "user-id"), + HaveKeyWithValue("scope.user.email", "user-email"), + HaveKeyWithValue("scope.metadata.k01", "v01"), + HaveKey("trace.trace_id"), + Not(HaveKey("trace.parent_id")), + HaveKey("trace.span_id"), + ), + })), + )) +} diff --git a/logm/tlogm/log.go b/logm/tlogm/log.go new file mode 100644 index 0000000..fae7818 --- /dev/null +++ b/logm/tlogm/log.go @@ -0,0 +1,77 @@ +package tlogm + +import ( + "context" + "runtime" + + "github.com/honeycombio/libhoney-go" + "github.com/ibrt/golang-utils/fixturez" + "github.com/ibrt/golang-utils/outz" + "github.com/onsi/gomega" + "github.com/sirupsen/logrus" + "go.uber.org/mock/gomock" + + "github.com/ibrt/golang-modules/clkm" + "github.com/ibrt/golang-modules/logm" +) + +var ( + _ fixturez.BeforeSuite = (*MockHelper)(nil) + _ fixturez.AfterSuite = (*MockHelper)(nil) + _ fixturez.BeforeTest = (*MockHelper)(nil) +) + +// MockHelper is a test helper. +type MockHelper struct { + EnableLogrusOutput bool + mock *MockSender + client *libhoney.Client +} + +// BeforeSuite implements [fixturez.BeforeSuite]. +func (h *MockHelper) BeforeSuite(ctx context.Context, g *gomega.WithT) context.Context { + mock := NewMockSender() + var logger *logrus.Logger + + if h.EnableLogrusOutput { + logger = outz.NewLogger() + logger.SetLevel(logrus.TraceLevel) + logger.SetFormatter(outz.NewHumanLogFormatter().SetInitTime(clkm.MustGet(ctx).Now())) + } + + client, err := libhoney.NewClient(libhoney.ClientConfig{ + APIKey: "test-honeycomb-api-key", + Dataset: "test-dataset", + SampleRate: 1, + Transmission: logm.NewSink(logger, mock), + }) + g.Expect(err).To(gomega.Succeed()) + + h.mock = mock + h.client = client + + return logm.NewSingletonInjector(logm.NewRawLogFromClient(client))(ctx) +} + +// AfterSuite implements [fixturez.AfterSuite]. +func (h *MockHelper) AfterSuite(_ context.Context, _ *gomega.WithT) { + h.client.Flush() + h.client.Close() + + // Yield to other goroutines to ensure logs are fully flushed. + runtime.Gosched() + + h.mock = nil + h.client = nil +} + +// BeforeTest implements [fixturez.BeforeTest]. +func (h *MockHelper) BeforeTest(ctx context.Context, _ *gomega.WithT, _ *gomock.Controller) context.Context { + h.mock.ClearEvents() + return ctx +} + +// GetMock returns the mock. +func (h *MockHelper) GetMock() *MockSender { + return h.mock +} diff --git a/logm/tlogm/mocks.go b/logm/tlogm/mocks.go new file mode 100644 index 0000000..815ed5b --- /dev/null +++ b/logm/tlogm/mocks.go @@ -0,0 +1,87 @@ +package tlogm + +import ( + "sync" + + "github.com/honeycombio/libhoney-go/transmission" + "github.com/ibrt/golang-utils/memz" +) + +var ( + _ transmission.Sender = (*MockSender)(nil) +) + +// MockSender implements the transmission.Sender interface. +type MockSender struct { + m *sync.Mutex + events []*transmission.Event + c chan transmission.Response +} + +// NewMockSender initializes a new MockSender. +func NewMockSender() *MockSender { + return &MockSender{ + m: &sync.Mutex{}, + events: make([]*transmission.Event, 0), + c: make(chan transmission.Response), + } +} + +// GetEvents returns the events. +func (s *MockSender) GetEvents() []*transmission.Event { + s.m.Lock() + defer s.m.Unlock() + return memz.ShallowCopySlice(s.events) +} + +// ClearEvents clears the events. +func (s *MockSender) ClearEvents() { + s.m.Lock() + defer s.m.Unlock() + s.events = make([]*transmission.Event, 0) +} + +// Add implements the transmission.Sender interface. +func (s *MockSender) Add(e *transmission.Event) { + s.m.Lock() + defer s.m.Unlock() + s.events = append(s.events, e) +} + +// Start implements the transmission.Sender interface. +func (s *MockSender) Start() error { + return nil +} + +// Stop implements the transmission.Sender interface. +func (s *MockSender) Stop() error { + s.m.Lock() + defer s.m.Unlock() + + s.events = nil + close(s.c) + return nil +} + +// Flush implements the transmission.Sender interface. +func (s *MockSender) Flush() error { + return nil +} + +// TxResponses implements the transmission.Sender interface. +func (s *MockSender) TxResponses() chan transmission.Response { + return s.c +} + +// SendResponse implements the transmission.Sender interface. +func (s *MockSender) SendResponse(response transmission.Response) bool { + s.m.Lock() + defer s.m.Unlock() + + select { + case s.c <- response: + return false + default: + return true + } +} diff --git a/logm/wrap.go b/logm/wrap.go new file mode 100644 index 0000000..04b0c06 --- /dev/null +++ b/logm/wrap.go @@ -0,0 +1,162 @@ +package logm + +import ( + "context" + + "github.com/ibrt/golang-utils/errorz" +) + +// Wrap0 traces a function that returns (error). +func Wrap0( + ctx context.Context, + name string, + f func(ctx context.Context) error, + options ...BeginOption) error { + + ctx, end := MustGet(ctx).Begin(name, options...) + defer end() + + err := errorz.Catch0Ctx(ctx, func(ctx context.Context) error { + return errorz.MaybeWrap(f(ctx)) + }) + maybeHandleError(ctx, err) + return errorz.MaybeWrap(err) +} + +// Wrap0Panic traces a function that returns (error). It panics if the returned error is non-nil. +func Wrap0Panic( + ctx context.Context, + name string, + f func(ctx context.Context) error, + options ...BeginOption) { + + ctx, end := MustGet(ctx).Begin(name, options...) + defer end() + + err := errorz.Catch0Ctx(ctx, func(ctx context.Context) error { + return errorz.MaybeWrap(f(ctx)) + }) + maybeHandleError(ctx, err) + errorz.MaybeMustWrap(err) +} + +// Wrap1 traces a function that returns (T, error). +func Wrap1[T any]( + ctx context.Context, + name string, + f func(ctx context.Context) (T, error), + options ...BeginOption) (T, error) { + + ctx, end := MustGet(ctx).Begin(name, options...) + defer end() + + out, err := errorz.Catch1Ctx(ctx, func(ctx context.Context) (T, error) { + out, err := f(ctx) + return out, errorz.MaybeWrap(err) + }) + maybeHandleError(ctx, err) + return out, errorz.MaybeWrap(err) +} + +// Wrap1Panic traces a function that returns (T, error). It panics if the returned error is non-nil. +func Wrap1Panic[T any]( + ctx context.Context, + name string, + f func(ctx context.Context) (T, error), + options ...BeginOption) T { + + ctx, end := MustGet(ctx).Begin(name, options...) + defer end() + + out, err := errorz.Catch1Ctx(ctx, func(ctx context.Context) (T, error) { + out, err := f(ctx) + return out, errorz.MaybeWrap(err) + }) + maybeHandleError(ctx, err) + errorz.MaybeMustWrap(err) + return out +} + +// Wrap2 traces a function that returns (T1, T2, error). +func Wrap2[T1 any, T2 any]( + ctx context.Context, + name string, + f func(ctx context.Context) (T1, T2, error), + options ...BeginOption) (T1, T2, error) { + + ctx, end := MustGet(ctx).Begin(name, options...) + defer end() + + out1, out2, err := errorz.Catch2Ctx(ctx, func(ctx context.Context) (T1, T2, error) { + out1, out2, err := f(ctx) + return out1, out2, errorz.MaybeWrap(err) + }) + maybeHandleError(ctx, err) + return out1, out2, errorz.MaybeWrap(err) +} + +// Wrap2Panic traces a function that returns (T1, T2, error). It panics if the returned error is non-nil. +func Wrap2Panic[T1 any, T2 any]( + ctx context.Context, + name string, + f func(ctx context.Context) (T1, T2, error), + options ...BeginOption) (T1, T2) { + + ctx, end := MustGet(ctx).Begin(name, options...) + defer end() + + out1, out2, err := errorz.Catch2Ctx(ctx, func(ctx context.Context) (T1, T2, error) { + out1, out2, err := f(ctx) + return out1, out2, errorz.MaybeWrap(err) + }) + maybeHandleError(ctx, err) + errorz.MaybeMustWrap(err) + return out1, out2 +} + +// Wrap3 traces a function that returns (T1, T2, T2, error). +func Wrap3[T1 any, T2 any, T3 any]( + ctx context.Context, + name string, + f func(ctx context.Context) (T1, T2, T3, error), + options ...BeginOption) (T1, T2, T3, error) { + + ctx, end := MustGet(ctx).Begin(name, options...) + defer end() + + out1, out2, out3, err := errorz.Catch3Ctx(ctx, func(ctx context.Context) (T1, T2, T3, error) { + out1, out2, out3, err := f(ctx) + return out1, out2, out3, errorz.MaybeWrap(err) + }) + maybeHandleError(ctx, err) + return out1, out2, out3, errorz.MaybeWrap(err) +} + +// Wrap3Panic traces a function that returns (T1, T2, T2, error). It panics if the returned error is non-nil. +func Wrap3Panic[T1 any, T2 any, T3 any]( + ctx context.Context, + name string, + f func(ctx context.Context) (T1, T2, T3, error), + options ...BeginOption) (T1, T2, T3) { + + ctx, end := MustGet(ctx).Begin(name, options...) + defer end() + + out1, out2, out3, err := errorz.Catch3Ctx(ctx, func(ctx context.Context) (T1, T2, T3, error) { + out1, out2, out3, err := f(ctx) + return out1, out2, out3, errorz.MaybeWrap(err) + }) + maybeHandleError(ctx, err) + errorz.MaybeMustWrap(err) + return out1, out2, out3 +} + +func maybeHandleError(ctx context.Context, err error) { + if err != nil { + if getIsEmitted(err) { + MustGet(ctx).SetErrorFlag() + } else { + MustGet(ctx).EmitError(err) + } + } +} diff --git a/logm/wrap_test.go b/logm/wrap_test.go new file mode 100644 index 0000000..8806d13 --- /dev/null +++ b/logm/wrap_test.go @@ -0,0 +1,1010 @@ +package logm_test + +import ( + "context" + "testing" + "time" + + "github.com/ibrt/golang-utils/errorz" + "github.com/ibrt/golang-utils/fixturez" + . "github.com/onsi/gomega" + . "github.com/onsi/gomega/gstruct" + + "github.com/ibrt/golang-modules/clkm" + "github.com/ibrt/golang-modules/clkm/tclkm" + "github.com/ibrt/golang-modules/logm" + "github.com/ibrt/golang-modules/logm/tlogm" +) + +type WrapSuite struct { + Clock *tclkm.MockHelper + Log *tlogm.MockHelper +} + +func TestWrapSuite(t *testing.T) { + fixturez.RunSuite(t, &WrapSuite{}) +} + +func (s *WrapSuite) TestWrap0_Success(ctx context.Context, g *WithT) { + t1 := clkm.MustGet(ctx).Now() + + g.Expect(logm.Wrap0(ctx, "wrap0", + func(ctx context.Context) error { + logm.MustGet(ctx).SetMetadataKey("k01", "v01") + + logm.MustGet(ctx).EmitInfo("emit: span: info: %v", + logm.EmitA("arg"), + logm.EmitMetadata{"k02": "v02"}) + + s.Clock.GetMock().Add(time.Second) + return nil + }, + logm.BeginM("kw", "vw"), logm.BeginErrM("kew", "vew"))). + To(Succeed()) + + g.Expect(s.Log.GetMock().GetEvents()). + To(HaveExactElements( + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1), + "Data": And( + HaveKeyWithValue("info", true), + HaveKeyWithValue("info.message", "emit: span: info: arg"), + HaveKeyWithValue("info.metadata.k02", "v02"), + HaveKeyWithValue("meta.annotation_type", "span_event"), + HaveKey("trace.trace_id"), + HaveKey("trace.parent_id"), + Not(HaveKey("trace.span_id")), + ), + })), + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1), + "Data": And( + HaveKeyWithValue("name", "wrap0"), + HaveKeyWithValue("duration_ms", float64(1000)), + HaveKeyWithValue("scope.metadata.k01", "v01"), + HaveKeyWithValue("scope.metadata.kw", "vw"), + HaveKey("trace.trace_id"), + HaveKey("trace.span_id"), + Not(HaveKey("trace.parent_id")), + Not(HaveKey("scope.metadata.kew")), + ), + })), + )) +} + +func (s *WrapSuite) TestWrap0_Error(ctx context.Context, g *WithT) { + t1 := clkm.MustGet(ctx).Now() + + g.Expect(logm.Wrap0(ctx, "wrap0", + func(ctx context.Context) error { + s.Clock.GetMock().Add(time.Second) + return errorz.Errorf("test error") + }, + logm.BeginErrM("kew", "vew"), + logm.BeginErrM(logm.StandardKeyParams, + struct { + K string `json:"kews"` + }{ + K: "vews", + }), + logm.BeginErrM(logm.StandardKeySecondaryParams, + struct { + K string `json:"kewss"` + }{ + K: "vewss", + }))). + To(MatchError("test error")) + + g.Expect(s.Log.GetMock().GetEvents()). + To(HaveExactElements( + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1.Add(time.Second)), + "Data": And( + HaveKeyWithValue("error", "generic"), + HaveKeyWithValue("error.message", "test error"), + HaveKeyWithValue("meta.annotation_type", "span_event"), + HaveKeyWithValue("name", "error"), + HaveKey("trace.trace_id"), + HaveKey("trace.parent_id"), + Not(HaveKey("trace.span_id")), + ), + })), + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1), + "Data": And( + HaveKeyWithValue("error", true), + HaveKeyWithValue("name", "wrap0"), + HaveKeyWithValue("duration_ms", float64(1000)), + HaveKeyWithValue("scope.metadata.kew", "vew"), + HaveKeyWithValue("scope.metadata.params.kews", "vews"), + HaveKeyWithValue("scope.metadata.params.kewss", "vewss"), + HaveKey("trace.trace_id"), + HaveKey("trace.span_id"), + Not(HaveKey("trace.parent_id")), + ), + })), + )) +} + +func (s *WrapSuite) TestWrap0_Error_Emitted(ctx context.Context, g *WithT) { + t1 := clkm.MustGet(ctx).Now() + + g.Expect( + logm.Wrap0(ctx, "wrap0_outer", + func(ctx context.Context) error { + s.Clock.GetMock().Add(time.Second) + return logm.Wrap0(ctx, "wrap0_inner", + func(ctx context.Context) error { + s.Clock.GetMock().Add(time.Second) + return errorz.Errorf("test error") + }, + logm.BeginErrM("kew", "vew"), + logm.BeginErrM(logm.StandardKeyParams, + struct { + K string `json:"kews"` + }{ + K: "vews", + })) + })). + To(MatchError("test error")) + + g.Expect(s.Log.GetMock().GetEvents()). + To(HaveExactElements( + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1.Add(2 * time.Second)), + "Data": And( + HaveKeyWithValue("error", "generic"), + HaveKeyWithValue("error.message", "test error"), + HaveKeyWithValue("meta.annotation_type", "span_event"), + HaveKeyWithValue("name", "error"), + HaveKey("trace.trace_id"), + HaveKey("trace.parent_id"), + Not(HaveKey("trace.span_id")), + ), + })), + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1.Add(time.Second)), + "Data": And( + HaveKeyWithValue("error", true), + HaveKeyWithValue("name", "wrap0_inner"), + HaveKeyWithValue("duration_ms", float64(1000)), + HaveKeyWithValue("scope.metadata.kew", "vew"), + HaveKeyWithValue("scope.metadata.params.kews", "vews"), + HaveKey("trace.trace_id"), + HaveKey("trace.span_id"), + HaveKey("trace.parent_id"), + ), + })), + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1), + "Data": And( + HaveKeyWithValue("error", true), + HaveKeyWithValue("name", "wrap0_outer"), + HaveKeyWithValue("duration_ms", float64(2000)), + HaveKey("trace.trace_id"), + HaveKey("trace.span_id"), + Not(HaveKey("trace.parent_id")), + ), + })), + )) +} + +func (s *WrapSuite) TestWrap0_Panic(ctx context.Context, g *WithT) { + t1 := clkm.MustGet(ctx).Now() + + g.Expect(logm.Wrap0(ctx, "wrap0", + func(ctx context.Context) error { + s.Clock.GetMock().Add(time.Second) + panic(errorz.Errorf("test error")) + })). + To(MatchError("test error")) + + g.Expect(s.Log.GetMock().GetEvents()). + To(HaveExactElements( + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1.Add(time.Second)), + "Data": And( + HaveKeyWithValue("error", "generic"), + HaveKeyWithValue("error.message", "test error"), + HaveKeyWithValue("meta.annotation_type", "span_event"), + HaveKeyWithValue("name", "error"), + HaveKey("trace.trace_id"), + HaveKey("trace.parent_id"), + Not(HaveKey("trace.span_id")), + ), + })), + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1), + "Data": And( + HaveKeyWithValue("error", true), + HaveKeyWithValue("name", "wrap0"), + HaveKeyWithValue("duration_ms", float64(1000)), + HaveKey("trace.trace_id"), + HaveKey("trace.span_id"), + Not(HaveKey("trace.parent_id")), + ), + })), + )) +} + +func (s *WrapSuite) TestWrap0Panic_Success(ctx context.Context, g *WithT) { + t1 := clkm.MustGet(ctx).Now() + + g.Expect( + func() { + logm.Wrap0Panic(ctx, "wrap0", + func(ctx context.Context) error { + logm.MustGet(ctx).SetMetadataKey("k01", "v01") + + logm.MustGet(ctx).EmitInfo("emit: span: info: %v", + logm.EmitA("arg"), + logm.EmitMetadata{"k02": "v02"}) + + s.Clock.GetMock().Add(time.Second) + return nil + }, + logm.BeginM("kw", "vw"), logm.BeginErrM("kew", "vew")) + }). + ToNot(Panic()) + + g.Expect(s.Log.GetMock().GetEvents()). + To(HaveExactElements( + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1), + "Data": And( + HaveKeyWithValue("info", true), + HaveKeyWithValue("info.message", "emit: span: info: arg"), + HaveKeyWithValue("info.metadata.k02", "v02"), + HaveKeyWithValue("meta.annotation_type", "span_event"), + HaveKey("trace.trace_id"), + HaveKey("trace.parent_id"), + Not(HaveKey("trace.span_id")), + ), + })), + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1), + "Data": And( + HaveKeyWithValue("name", "wrap0"), + HaveKeyWithValue("duration_ms", float64(1000)), + HaveKeyWithValue("scope.metadata.k01", "v01"), + HaveKeyWithValue("scope.metadata.kw", "vw"), + HaveKey("trace.trace_id"), + HaveKey("trace.span_id"), + Not(HaveKey("trace.parent_id")), + Not(HaveKey("scope.metadata.kew")), + ), + })), + )) +} + +func (s *WrapSuite) TestWrap0Panic_Error(ctx context.Context, g *WithT) { + t1 := clkm.MustGet(ctx).Now() + + g.Expect( + func() { + logm.Wrap0Panic(ctx, "wrap0", + func(ctx context.Context) error { + s.Clock.GetMock().Add(time.Second) + return errorz.Errorf("test error") + }, + logm.BeginErrM("kew", "vew"), + logm.BeginErrM(logm.StandardKeyParams, + struct { + K string `json:"kews"` + }{ + K: "vews", + })) + }). + To(PanicWith(MatchError("test error"))) + + g.Expect(s.Log.GetMock().GetEvents()). + To(HaveExactElements( + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1.Add(time.Second)), + "Data": And( + HaveKeyWithValue("error", "generic"), + HaveKeyWithValue("error.message", "test error"), + HaveKeyWithValue("meta.annotation_type", "span_event"), + HaveKeyWithValue("name", "error"), + HaveKey("trace.trace_id"), + HaveKey("trace.parent_id"), + Not(HaveKey("trace.span_id")), + ), + })), + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1), + "Data": And( + HaveKeyWithValue("error", true), + HaveKeyWithValue("name", "wrap0"), + HaveKeyWithValue("duration_ms", float64(1000)), + HaveKeyWithValue("scope.metadata.kew", "vew"), + HaveKeyWithValue("scope.metadata.params.kews", "vews"), + HaveKey("trace.trace_id"), + HaveKey("trace.span_id"), + Not(HaveKey("trace.parent_id")), + ), + })), + )) +} + +func (s *WrapSuite) TestWrap1_Success(ctx context.Context, g *WithT) { + t1 := clkm.MustGet(ctx).Now() + + out, err := logm.Wrap1(ctx, "wrap1", + func(ctx context.Context) (string, error) { + logm.MustGet(ctx).SetMetadataKey("k01", "v01") + + logm.MustGet(ctx).EmitInfo("emit: span: info: %v", + logm.EmitA("arg"), + logm.EmitMetadata{"k02": "v02"}) + + s.Clock.GetMock().Add(time.Second) + return "test", nil + }, + logm.BeginMetadata{"kw": "vw"}, logm.BeginErrMetadata{"kew": "vew"}) + g.Expect(err).To(Succeed()) + g.Expect(out).To(Equal("test")) + + g.Expect(s.Log.GetMock().GetEvents()). + To(HaveExactElements( + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1), + "Data": And( + HaveKeyWithValue("info", true), + HaveKeyWithValue("info.message", "emit: span: info: arg"), + HaveKeyWithValue("info.metadata.k02", "v02"), + HaveKeyWithValue("meta.annotation_type", "span_event"), + HaveKeyWithValue("name", "info"), + HaveKey("trace.trace_id"), + HaveKey("trace.parent_id"), + Not(HaveKey("trace.span_id")), + Not(HaveKey("scope.metadata.kew")), + ), + })), + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1), + "Data": And( + HaveKeyWithValue("name", "wrap1"), + HaveKeyWithValue("duration_ms", float64(1000)), + HaveKeyWithValue("scope.metadata.k01", "v01"), + HaveKeyWithValue("scope.metadata.kw", "vw"), + HaveKey("trace.trace_id"), + HaveKey("trace.span_id"), + Not(HaveKey("trace.parent_id")), + ), + })), + )) +} + +func (s *WrapSuite) TestWrap1_Error(ctx context.Context, g *WithT) { + t1 := clkm.MustGet(ctx).Now() + + out, err := logm.Wrap1(ctx, "wrap1", + func(ctx context.Context) (string, error) { + s.Clock.GetMock().Add(time.Second) + return "", errorz.Errorf("test error") + }, logm.BeginErrMetadata{"kew": "vew"}) + g.Expect(err).To(MatchError("test error")) + g.Expect(out).To(Equal("")) + + g.Expect(s.Log.GetMock().GetEvents()). + To(HaveExactElements( + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1.Add(time.Second)), + "Data": And( + HaveKeyWithValue("error", "generic"), + HaveKeyWithValue("error.message", "test error"), + HaveKeyWithValue("meta.annotation_type", "span_event"), + HaveKeyWithValue("name", "error"), + HaveKey("trace.trace_id"), + HaveKey("trace.parent_id"), + Not(HaveKey("trace.span_id")), + ), + })), + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1), + "Data": And( + HaveKeyWithValue("error", true), + HaveKeyWithValue("name", "wrap1"), + HaveKeyWithValue("duration_ms", float64(1000)), + HaveKeyWithValue("scope.metadata.kew", "vew"), + HaveKey("trace.trace_id"), + HaveKey("trace.span_id"), + Not(HaveKey("trace.parent_id")), + ), + })), + )) +} + +func (s *WrapSuite) TestWrap1_Panic(ctx context.Context, g *WithT) { + t1 := clkm.MustGet(ctx).Now() + + out, err := logm.Wrap1(ctx, "wrap1", + func(ctx context.Context) (string, error) { + s.Clock.GetMock().Add(time.Second) + panic(errorz.Errorf("test error")) + }) + g.Expect(err).To(MatchError("test error")) + g.Expect(out).To(Equal("")) + + g.Expect(s.Log.GetMock().GetEvents()). + To(HaveExactElements( + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1.Add(time.Second)), + "Data": And( + HaveKeyWithValue("error", "generic"), + HaveKeyWithValue("error.message", "test error"), + HaveKeyWithValue("meta.annotation_type", "span_event"), + HaveKeyWithValue("name", "error"), + HaveKey("trace.trace_id"), + HaveKey("trace.parent_id"), + Not(HaveKey("trace.span_id")), + ), + })), + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1), + "Data": And( + HaveKeyWithValue("error", true), + HaveKeyWithValue("name", "wrap1"), + HaveKeyWithValue("duration_ms", float64(1000)), + HaveKey("trace.trace_id"), + HaveKey("trace.span_id"), + Not(HaveKey("trace.parent_id")), + ), + })), + )) +} + +func (s *WrapSuite) TestWrap1Panic_Success(ctx context.Context, g *WithT) { + t1 := clkm.MustGet(ctx).Now() + + g.Expect( + func() { + out := logm.Wrap1Panic(ctx, "wrap1", + func(ctx context.Context) (string, error) { + logm.MustGet(ctx).SetMetadataKey("k01", "v01") + + logm.MustGet(ctx).EmitInfo("emit: span: info: %v", + logm.EmitA("arg"), + logm.EmitMetadata{"k02": "v02"}) + + s.Clock.GetMock().Add(time.Second) + return "test", nil + }, + logm.BeginMetadata{"kw": "vw"}, logm.BeginErrMetadata{"kew": "vew"}) + g.Expect(out).To(Equal("test")) + }). + ToNot(Panic()) + + g.Expect(s.Log.GetMock().GetEvents()). + To(HaveExactElements( + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1), + "Data": And( + HaveKeyWithValue("info", true), + HaveKeyWithValue("info.message", "emit: span: info: arg"), + HaveKeyWithValue("info.metadata.k02", "v02"), + HaveKeyWithValue("meta.annotation_type", "span_event"), + HaveKeyWithValue("name", "info"), + HaveKey("trace.trace_id"), + HaveKey("trace.parent_id"), + Not(HaveKey("trace.span_id")), + Not(HaveKey("scope.metadata.kew")), + ), + })), + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1), + "Data": And( + HaveKeyWithValue("name", "wrap1"), + HaveKeyWithValue("duration_ms", float64(1000)), + HaveKeyWithValue("scope.metadata.k01", "v01"), + HaveKeyWithValue("scope.metadata.kw", "vw"), + HaveKey("trace.trace_id"), + HaveKey("trace.span_id"), + Not(HaveKey("trace.parent_id")), + ), + })), + )) +} + +func (s *WrapSuite) TestWrap1Panic_Error(ctx context.Context, g *WithT) { + t1 := clkm.MustGet(ctx).Now() + + g.Expect( + func() { + logm.Wrap1Panic(ctx, "wrap1", + func(ctx context.Context) (string, error) { + s.Clock.GetMock().Add(time.Second) + return "", errorz.Errorf("test error") + }, logm.BeginErrMetadata{"kew": "vew"}) + }). + To(PanicWith(MatchError("test error"))) + + g.Expect(s.Log.GetMock().GetEvents()). + To(HaveExactElements( + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1.Add(time.Second)), + "Data": And( + HaveKeyWithValue("error", "generic"), + HaveKeyWithValue("error.message", "test error"), + HaveKeyWithValue("meta.annotation_type", "span_event"), + HaveKeyWithValue("name", "error"), + HaveKey("trace.trace_id"), + HaveKey("trace.parent_id"), + Not(HaveKey("trace.span_id")), + ), + })), + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1), + "Data": And( + HaveKeyWithValue("error", true), + HaveKeyWithValue("name", "wrap1"), + HaveKeyWithValue("duration_ms", float64(1000)), + HaveKeyWithValue("scope.metadata.kew", "vew"), + HaveKey("trace.trace_id"), + HaveKey("trace.span_id"), + Not(HaveKey("trace.parent_id")), + ), + })), + )) +} + +func (s *WrapSuite) TestWrap2_Success(ctx context.Context, g *WithT) { + t1 := clkm.MustGet(ctx).Now() + + out1, out2, err := logm.Wrap2(ctx, "wrap2", + func(ctx context.Context) (string, string, error) { + logm.MustGet(ctx).SetMetadataKey("k01", "v01") + + logm.MustGet(ctx).EmitInfo("emit: span: info: %v", + logm.EmitA("arg"), + logm.EmitMetadata{"k02": "v02"}) + + s.Clock.GetMock().Add(time.Second) + return "t1", "t2", nil + }, + logm.BeginM("kw", "vw"), logm.BeginErrM("kew", "vew")) + g.Expect(err).To(Succeed()) + g.Expect(out1).To(Equal("t1")) + g.Expect(out2).To(Equal("t2")) + + g.Expect(s.Log.GetMock().GetEvents()). + To(HaveExactElements( + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1), + "Data": And( + HaveKeyWithValue("info", true), + HaveKeyWithValue("info.message", "emit: span: info: arg"), + HaveKeyWithValue("info.metadata.k02", "v02"), + HaveKeyWithValue("meta.annotation_type", "span_event"), + HaveKeyWithValue("name", "info"), + HaveKey("trace.trace_id"), + HaveKey("trace.parent_id"), + Not(HaveKey("trace.span_id")), + ), + })), + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1), + "Data": And( + HaveKeyWithValue("name", "wrap2"), + HaveKeyWithValue("duration_ms", float64(1000)), + HaveKeyWithValue("scope.metadata.k01", "v01"), + HaveKeyWithValue("scope.metadata.kw", "vw"), + HaveKey("trace.trace_id"), + HaveKey("trace.span_id"), + Not(HaveKey("trace.parent_id")), + Not(HaveKey("scope.metadata.kew")), + ), + })), + )) +} + +func (s *WrapSuite) TestWrap2_Error(ctx context.Context, g *WithT) { + t1 := clkm.MustGet(ctx).Now() + + out1, out2, err := logm.Wrap2(ctx, "wrap2", + func(ctx context.Context) (string, string, error) { + s.Clock.GetMock().Add(time.Second) + return "", "", errorz.Errorf("test error") + }, logm.BeginErrM("kew", "vew"), logm.BeginErrM(logm.StandardKeyParams, "p")) + g.Expect(err).To(MatchError("test error")) + g.Expect(out1).To(Equal("")) + g.Expect(out2).To(Equal("")) + + g.Expect(s.Log.GetMock().GetEvents()). + To(HaveExactElements( + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1.Add(time.Second)), + "Data": And( + HaveKeyWithValue("error", "generic"), + HaveKeyWithValue("error.message", "test error"), + HaveKeyWithValue("meta.annotation_type", "span_event"), + HaveKeyWithValue("name", "error"), + HaveKey("trace.trace_id"), + HaveKey("trace.parent_id"), + Not(HaveKey("trace.span_id")), + ), + })), + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1), + "Data": And( + HaveKeyWithValue("error", true), + HaveKeyWithValue("name", "wrap2"), + HaveKeyWithValue("duration_ms", float64(1000)), + HaveKeyWithValue("scope.metadata.kew", "vew"), + HaveKeyWithValue("scope.metadata.params", "p"), + HaveKey("trace.trace_id"), + HaveKey("trace.span_id"), + Not(HaveKey("trace.parent_id")), + ), + })), + )) +} + +func (s *WrapSuite) TestWrap2_Panic(ctx context.Context, g *WithT) { + t1 := clkm.MustGet(ctx).Now() + + out1, out2, err := logm.Wrap2(ctx, "wrap2", + func(ctx context.Context) (string, string, error) { + s.Clock.GetMock().Add(time.Second) + panic(errorz.Errorf("test error")) + }) + g.Expect(err).To(MatchError("test error")) + g.Expect(out1).To(Equal("")) + g.Expect(out2).To(Equal("")) + + g.Expect(s.Log.GetMock().GetEvents()). + To(HaveExactElements( + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1.Add(time.Second)), + "Data": And( + HaveKeyWithValue("error", "generic"), + HaveKeyWithValue("error.message", "test error"), + HaveKeyWithValue("meta.annotation_type", "span_event"), + HaveKeyWithValue("name", "error"), + HaveKey("trace.trace_id"), + HaveKey("trace.parent_id"), + Not(HaveKey("trace.span_id")), + ), + })), + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1), + "Data": And( + HaveKeyWithValue("error", true), + HaveKeyWithValue("name", "wrap2"), + HaveKeyWithValue("duration_ms", float64(1000)), + HaveKey("trace.trace_id"), + HaveKey("trace.span_id"), + Not(HaveKey("trace.parent_id")), + ), + })), + )) +} + +func (s *WrapSuite) TestWrap2Panic_Success(ctx context.Context, g *WithT) { + t1 := clkm.MustGet(ctx).Now() + + g.Expect( + func() { + out1, out2 := logm.Wrap2Panic(ctx, "wrap2", + func(ctx context.Context) (string, string, error) { + logm.MustGet(ctx).SetMetadataKey("k01", "v01") + + logm.MustGet(ctx).EmitInfo("emit: span: info: %v", + logm.EmitA("arg"), + logm.EmitMetadata{"k02": "v02"}) + + s.Clock.GetMock().Add(time.Second) + return "t1", "t2", nil + }, + logm.BeginM("kw", "vw"), logm.BeginErrM("kew", "vew")) + g.Expect(out1).To(Equal("t1")) + g.Expect(out2).To(Equal("t2")) + }). + ToNot(Panic()) + + g.Expect(s.Log.GetMock().GetEvents()). + To(HaveExactElements( + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1), + "Data": And( + HaveKeyWithValue("info", true), + HaveKeyWithValue("info.message", "emit: span: info: arg"), + HaveKeyWithValue("info.metadata.k02", "v02"), + HaveKeyWithValue("meta.annotation_type", "span_event"), + HaveKeyWithValue("name", "info"), + HaveKey("trace.trace_id"), + HaveKey("trace.parent_id"), + Not(HaveKey("trace.span_id")), + ), + })), + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1), + "Data": And( + HaveKeyWithValue("name", "wrap2"), + HaveKeyWithValue("duration_ms", float64(1000)), + HaveKeyWithValue("scope.metadata.k01", "v01"), + HaveKeyWithValue("scope.metadata.kw", "vw"), + HaveKey("trace.trace_id"), + HaveKey("trace.span_id"), + Not(HaveKey("trace.parent_id")), + Not(HaveKey("scope.metadata.kew")), + ), + })), + )) +} + +func (s *WrapSuite) TestWrap2Panic_Error(ctx context.Context, g *WithT) { + t1 := clkm.MustGet(ctx).Now() + + g.Expect( + func() { + logm.Wrap2Panic(ctx, "wrap2", + func(ctx context.Context) (string, string, error) { + s.Clock.GetMock().Add(time.Second) + return "", "", errorz.Errorf("test error") + }, logm.BeginErrM("kew", "vew"), logm.BeginErrM(logm.StandardKeyParams, "p")) + }). + To(PanicWith(MatchError("test error"))) + + g.Expect(s.Log.GetMock().GetEvents()). + To(HaveExactElements( + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1.Add(time.Second)), + "Data": And( + HaveKeyWithValue("error", "generic"), + HaveKeyWithValue("error.message", "test error"), + HaveKeyWithValue("meta.annotation_type", "span_event"), + HaveKeyWithValue("name", "error"), + HaveKey("trace.trace_id"), + HaveKey("trace.parent_id"), + Not(HaveKey("trace.span_id")), + ), + })), + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1), + "Data": And( + HaveKeyWithValue("error", true), + HaveKeyWithValue("name", "wrap2"), + HaveKeyWithValue("duration_ms", float64(1000)), + HaveKeyWithValue("scope.metadata.kew", "vew"), + HaveKeyWithValue("scope.metadata.params", "p"), + HaveKey("trace.trace_id"), + HaveKey("trace.span_id"), + Not(HaveKey("trace.parent_id")), + ), + })), + )) +} + +func (s *WrapSuite) TestWrap3_Success(ctx context.Context, g *WithT) { + t1 := clkm.MustGet(ctx).Now() + + out1, out2, out3, err := logm.Wrap3(ctx, "wrap3", + func(ctx context.Context) (string, string, string, error) { + logm.MustGet(ctx).SetMetadataKey("k01", "v01") + + logm.MustGet(ctx).EmitInfo("emit: span: info: %v", + logm.EmitA("arg"), + logm.EmitMetadata{"k02": "v02"}) + + s.Clock.GetMock().Add(time.Second) + return "t1", "t2", "t3", nil + }, + logm.BeginM("kw", "vw"), logm.BeginErrM("kew", "vew")) + g.Expect(err).To(Succeed()) + g.Expect(out1).To(Equal("t1")) + g.Expect(out2).To(Equal("t2")) + g.Expect(out3).To(Equal("t3")) + + g.Expect(s.Log.GetMock().GetEvents()). + To(HaveExactElements( + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1), + "Data": And( + HaveKeyWithValue("info", true), + HaveKeyWithValue("info.message", "emit: span: info: arg"), + HaveKeyWithValue("info.metadata.k02", "v02"), + HaveKeyWithValue("meta.annotation_type", "span_event"), + HaveKeyWithValue("name", "info"), + HaveKey("trace.trace_id"), + HaveKey("trace.parent_id"), + Not(HaveKey("trace.span_id")), + ), + })), + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1), + "Data": And( + HaveKeyWithValue("name", "wrap3"), + HaveKeyWithValue("duration_ms", float64(1000)), + HaveKeyWithValue("scope.metadata.k01", "v01"), + HaveKeyWithValue("scope.metadata.kw", "vw"), + HaveKey("trace.trace_id"), + HaveKey("trace.span_id"), + Not(HaveKey("trace.parent_id")), + Not(HaveKey("scope.metadata.kew")), + ), + })), + )) +} + +func (s *WrapSuite) TestWrap3_Error(ctx context.Context, g *WithT) { + t1 := clkm.MustGet(ctx).Now() + + out1, out2, out3, err := logm.Wrap3(ctx, "wrap3", + func(ctx context.Context) (string, string, string, error) { + logm.MustGet(ctx).SetErrorMetadataKey("kew", "vew") + s.Clock.GetMock().Add(time.Second) + return "", "", "", errorz.Errorf("test error") + }) + g.Expect(err).To(MatchError("test error")) + g.Expect(out1).To(Equal("")) + g.Expect(out2).To(Equal("")) + g.Expect(out3).To(Equal("")) + + g.Expect(s.Log.GetMock().GetEvents()). + To(HaveExactElements( + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1.Add(time.Second)), + "Data": And( + HaveKeyWithValue("error", "generic"), + HaveKeyWithValue("error.message", "test error"), + HaveKeyWithValue("meta.annotation_type", "span_event"), + HaveKeyWithValue("name", "error"), + HaveKey("trace.trace_id"), + HaveKey("trace.parent_id"), + Not(HaveKey("trace.span_id")), + ), + })), + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1), + "Data": And( + HaveKeyWithValue("error", true), + HaveKeyWithValue("name", "wrap3"), + HaveKeyWithValue("duration_ms", float64(1000)), + HaveKeyWithValue("scope.metadata.kew", "vew"), + HaveKey("trace.trace_id"), + HaveKey("trace.span_id"), + Not(HaveKey("trace.parent_id")), + ), + })), + )) +} + +func (s *WrapSuite) TestWrap3_Panic(ctx context.Context, g *WithT) { + t1 := clkm.MustGet(ctx).Now() + + out1, out2, out3, err := logm.Wrap3(ctx, "wrap3", + func(ctx context.Context) (string, string, string, error) { + s.Clock.GetMock().Add(time.Second) + panic(errorz.Errorf("test error")) + }) + g.Expect(err).To(MatchError("test error")) + g.Expect(out1).To(Equal("")) + g.Expect(out2).To(Equal("")) + g.Expect(out3).To(Equal("")) + + g.Expect(s.Log.GetMock().GetEvents()). + To(HaveExactElements( + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1.Add(time.Second)), + "Data": And( + HaveKeyWithValue("error", "generic"), + HaveKeyWithValue("error.message", "test error"), + HaveKeyWithValue("meta.annotation_type", "span_event"), + HaveKeyWithValue("name", "error"), + HaveKey("trace.trace_id"), + HaveKey("trace.parent_id"), + Not(HaveKey("trace.span_id")), + ), + })), + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1), + "Data": And( + HaveKeyWithValue("error", true), + HaveKeyWithValue("name", "wrap3"), + HaveKeyWithValue("duration_ms", float64(1000)), + HaveKey("trace.trace_id"), + HaveKey("trace.span_id"), + Not(HaveKey("trace.parent_id")), + ), + })), + )) +} + +func (s *WrapSuite) TestWrap3Panic_Success(ctx context.Context, g *WithT) { + t1 := clkm.MustGet(ctx).Now() + + g.Expect( + func() { + out1, out2, out3 := logm.Wrap3Panic(ctx, "wrap3", + func(ctx context.Context) (string, string, string, error) { + logm.MustGet(ctx).SetMetadataKey("k01", "v01") + + logm.MustGet(ctx).EmitInfo("emit: span: info: %v", + logm.EmitA("arg"), + logm.EmitMetadata{"k02": "v02"}) + + s.Clock.GetMock().Add(time.Second) + return "t1", "t2", "t3", nil + }, + logm.BeginM("kw", "vw"), logm.BeginErrM("kew", "vew")) + g.Expect(out1).To(Equal("t1")) + g.Expect(out2).To(Equal("t2")) + g.Expect(out3).To(Equal("t3")) + }). + ToNot(Panic()) + + g.Expect(s.Log.GetMock().GetEvents()). + To(HaveExactElements( + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1), + "Data": And( + HaveKeyWithValue("info", true), + HaveKeyWithValue("info.message", "emit: span: info: arg"), + HaveKeyWithValue("info.metadata.k02", "v02"), + HaveKeyWithValue("meta.annotation_type", "span_event"), + HaveKeyWithValue("name", "info"), + HaveKey("trace.trace_id"), + HaveKey("trace.parent_id"), + Not(HaveKey("trace.span_id")), + ), + })), + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1), + "Data": And( + HaveKeyWithValue("name", "wrap3"), + HaveKeyWithValue("duration_ms", float64(1000)), + HaveKeyWithValue("scope.metadata.k01", "v01"), + HaveKeyWithValue("scope.metadata.kw", "vw"), + HaveKey("trace.trace_id"), + HaveKey("trace.span_id"), + Not(HaveKey("trace.parent_id")), + Not(HaveKey("scope.metadata.kew")), + ), + })), + )) +} + +func (s *WrapSuite) TestWrap3Panic_Error(ctx context.Context, g *WithT) { + t1 := clkm.MustGet(ctx).Now() + + g.Expect( + func() { + logm.Wrap3Panic(ctx, "wrap3", + func(ctx context.Context) (string, string, string, error) { + logm.MustGet(ctx).SetErrorMetadataKey("kew", "vew") + s.Clock.GetMock().Add(time.Second) + return "", "", "", errorz.Errorf("test error") + }) + }). + To(PanicWith(MatchError("test error"))) + + g.Expect(s.Log.GetMock().GetEvents()). + To(HaveExactElements( + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1.Add(time.Second)), + "Data": And( + HaveKeyWithValue("error", "generic"), + HaveKeyWithValue("error.message", "test error"), + HaveKeyWithValue("meta.annotation_type", "span_event"), + HaveKeyWithValue("name", "error"), + HaveKey("trace.trace_id"), + HaveKey("trace.parent_id"), + Not(HaveKey("trace.span_id")), + ), + })), + PointTo(MatchFields(IgnoreExtras, Fields{ + "Timestamp": Equal(t1), + "Data": And( + HaveKeyWithValue("error", true), + HaveKeyWithValue("name", "wrap3"), + HaveKeyWithValue("duration_ms", float64(1000)), + HaveKeyWithValue("scope.metadata.kew", "vew"), + HaveKey("trace.trace_id"), + HaveKey("trace.span_id"), + Not(HaveKey("trace.parent_id")), + ), + })), + )) +}