From dfb356bcc15a0f46b0afdfb59fdc30bd466a7c38 Mon Sep 17 00:00:00 2001 From: mpapenbr Date: Sat, 31 Aug 2024 12:26:24 +0200 Subject: [PATCH] Use component logging Fixes #69 --- cmd/root.go | 24 ++++-- go.mod | 1 + go.sum | 57 +++++++++++++ internal/processor/cardata.go | 34 +++++--- internal/processor/cars.go | 33 +++++--- internal/processor/driver.go | 2 +- internal/processor/pitboundary.go | 2 +- internal/processor/processor.go | 23 ++++-- internal/processor/race.go | 62 +++++++++----- internal/processor/speedmap.go | 2 +- internal/processor/util.go | 2 +- internal/racelogger.go | 38 +++++---- log/config.go | 52 ++++++++++++ log/context.go | 19 +++++ log/zap.go | 130 +++++++++++++++++++++++++++--- pkg/cmd/check/check.go | 14 ++-- pkg/cmd/record/record.go | 6 +- pkg/cmd/status/status.go | 2 +- pkg/config/config.go | 11 +-- pkg/util/logger.go | 47 ----------- sample/log-dev.yml | 18 +++++ sample/log-prod.yml | 14 ++++ sample/racelogger.yml | 8 +- 23 files changed, 443 insertions(+), 158 deletions(-) create mode 100644 log/config.go create mode 100644 log/context.go delete mode 100644 pkg/util/logger.go create mode 100644 sample/log-dev.yml create mode 100644 sample/log-prod.yml diff --git a/cmd/root.go b/cmd/root.go index c838399..bbfb470 100644 --- a/cmd/root.go +++ b/cmd/root.go @@ -5,6 +5,7 @@ Copyright 2023 mpapenbr package cmd import ( + "context" "fmt" "os" "strings" @@ -13,13 +14,13 @@ import ( "github.com/spf13/pflag" "github.com/spf13/viper" + "github.com/mpapenbr/go-racelogger/log" "github.com/mpapenbr/go-racelogger/pkg/cmd/check" importCmd "github.com/mpapenbr/go-racelogger/pkg/cmd/logimport" pingCmd "github.com/mpapenbr/go-racelogger/pkg/cmd/ping" recordCmd "github.com/mpapenbr/go-racelogger/pkg/cmd/record" statusCmd "github.com/mpapenbr/go-racelogger/pkg/cmd/status" "github.com/mpapenbr/go-racelogger/pkg/config" - "github.com/mpapenbr/go-racelogger/pkg/util" "github.com/mpapenbr/go-racelogger/version" ) @@ -34,7 +35,18 @@ var rootCmd = &cobra.Command{ Long: ``, Version: version.FullVersion, PersistentPreRun: func(cmd *cobra.Command, args []string) { - util.SetupLogger(config.DefaultCliArgs()) + // util.SetupLogger(config.DefaultCliArgs()) + logConfig := log.DefaultDevConfig() + if config.DefaultCliArgs().LogConfig != "" { + var err error + logConfig, err = log.LoadConfig(config.DefaultCliArgs().LogConfig) + if err != nil { + log.Fatal("could not load log config", log.ErrorField(err)) + } + } + l := log.NewWithConfig(logConfig, config.DefaultCliArgs().LogLevel) + cmd.SetContext(log.AddToContext(context.Background(), l)) + log.ResetDefault(l) }, // Uncomment the following line if your bare application @@ -70,10 +82,10 @@ func init() { "log-level", "info", "controls the log level (debug, info, warn, error, fatal)") - rootCmd.PersistentFlags().StringVar(&config.DefaultCliArgs().LogFormat, - "log-format", - "text", - "controls the log output format (json, text)") + rootCmd.PersistentFlags().StringVar(&config.DefaultCliArgs().LogConfig, + "log-config", + "log-prod.yml", + "sets the configuration of the internal logger") rootCmd.PersistentFlags().StringVar(&config.DefaultCliArgs().LogFile, "log-file", "", diff --git a/go.mod b/go.mod index ff8b0c9..16816ca 100644 --- a/go.mod +++ b/go.mod @@ -37,6 +37,7 @@ require ( golang.org/x/sys v0.24.0 // indirect golang.org/x/text v0.17.0 // indirect google.golang.org/genproto/googleapis/rpc v0.0.0-20240528184218-531527333157 // indirect + moul.io/zapfilter v1.7.0 // indirect ) require ( diff --git a/go.sum b/go.sum index 1e55a56..6571132 100644 --- a/go.sum +++ b/go.sum @@ -2,6 +2,7 @@ buf.build/gen/go/mpapenbr/iracelog/grpc/go v1.5.1-20240818164234-8da4d13e1b88.1 buf.build/gen/go/mpapenbr/iracelog/grpc/go v1.5.1-20240818164234-8da4d13e1b88.1/go.mod h1:2z7WgkT7hbeML1+5oyD2cif0VsujRrkyfzVHI35nYgQ= buf.build/gen/go/mpapenbr/iracelog/protocolbuffers/go v1.34.2-20240818164234-8da4d13e1b88.2 h1:7mJORHD56rYpxIkVwoZTFbgz6lEeVWvaZy1F1EkWezo= buf.build/gen/go/mpapenbr/iracelog/protocolbuffers/go v1.34.2-20240818164234-8da4d13e1b88.2/go.mod h1:Nz+56AmPchS6dX/7Rc7t15BbsL+9eEHWvD0DpdMO7OA= +github.com/benbjohnson/clock v1.1.0/go.mod h1:J11/hYXuz8f4ySSvYwY0FKfm+ezbsZBKZxNJlLklBHA= github.com/cpuguy83/go-md2man/v2 v2.0.4/go.mod h1:tgQtvFlXSQOSOSIRvRPT7W67SCa46tRHOmNcaadrF8o= github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= @@ -19,8 +20,11 @@ github.com/hashicorp/hcl v1.0.0 h1:0Anlzjpi4vEasTeNFn2mLJgTSwt0+6sfsiTG8qcWGx4= github.com/hashicorp/hcl v1.0.0/go.mod h1:E5yfLk+7swimpb2L/Alb/PJmXilQ/rhwaUYs4T20WEQ= github.com/inconshreveable/mousetrap v1.1.0 h1:wN+x4NVGpMsO7ErUn/mUI3vEoE6Jt13X2s0bqwp9tc8= github.com/inconshreveable/mousetrap v1.1.0/go.mod h1:vpF70FUmC8bwa3OWnCshd2FqLfsEA9PFc4w1p2J65bw= +github.com/kr/pretty v0.1.0/go.mod h1:dAy3ld7l9f0ibDNOQOHHMYYIIbhfbHSm3C4ZsoJORNo= github.com/kr/pretty v0.3.1 h1:flRD4NNwYAUpkphVc1HcthR4KEIFJ65n8Mw5qdRn3LE= github.com/kr/pretty v0.3.1/go.mod h1:hoEshYVHaxMs3cyo3Yncou5ZscifuDolrwPKZanG3xk= +github.com/kr/pty v1.1.1/go.mod h1:pFQYn66WHrOpPYNljwOMqo10TkYh1fy3cYio2l3bCsQ= +github.com/kr/text v0.1.0/go.mod h1:4Jbv+DJW3UT/LiOwJeYQe1efqtUx/iVham/4vfdArNI= github.com/kr/text v0.2.0 h1:5Nx0Ya0ZqY2ygV366QzturHI13Jq95ApcVaJBhpS+AY= github.com/kr/text v0.2.0/go.mod h1:eLer722TekiGuMkidMxC/pM04lWEeraHUUmBw8l2grE= github.com/magiconair/properties v1.8.7 h1:IeQXZAiQcpL9mgcAe1Nu6cX9LLw6ExEHKjN0VQdvPDY= @@ -31,6 +35,8 @@ github.com/mpapenbr/goirsdk v0.7.0 h1:Zi+CBogQPqo0jXDE32m5tu3FLwNFOfvrTg9PU45h96 github.com/mpapenbr/goirsdk v0.7.0/go.mod h1:ZEW55Aq5nT04GmhvyGibTwdtMiiwvDaMExV/0FTsZzM= github.com/pelletier/go-toml/v2 v2.2.2 h1:aYUidT7k73Pcl9nb2gScu7NSrKCSHIDE89b3+6Wq+LM= github.com/pelletier/go-toml/v2 v2.2.2/go.mod h1:1t835xjRzz80PqgE6HHgN2JOsmgYu/h4qDAS4n929Rs= +github.com/pkg/diff v0.0.0-20200914180035-5b29258ca4f7/go.mod h1:zO8QMzTeZd5cpnIkz/Gn6iK0jDfGicM1nynOkkPIl28= +github.com/pkg/errors v0.8.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= github.com/pmezard/go-difflib v1.0.1-0.20181226105442-5d4384ee4fb2 h1:Jamvg5psRIccs7FGNTlIRMkT8wgtp5eCXdBlqhYGL6U= github.com/pmezard/go-difflib v1.0.1-0.20181226105442-5d4384ee4fb2/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= @@ -43,6 +49,7 @@ github.com/sagikazarmark/slog-shim v0.1.0 h1:diDBnUNK9N/354PgrxMywXnAwEr1QZcOr6g github.com/sagikazarmark/slog-shim v0.1.0/go.mod h1:SrcSrq8aKtyuqEI1uvTDTK1arOWRIczQRv+GVI1AkeQ= github.com/samber/lo v1.47.0 h1:z7RynLwP5nbyRscyvcD043DWYoOcYRv3mV8lBeqOCLc= github.com/samber/lo v1.47.0/go.mod h1:RmDH9Ct32Qy3gduHQuKJ3gW1fMHAnE/fAzQuf6He5cU= +github.com/sergi/go-diff v1.0.0/go.mod h1:0CfEIISq7TuYL3j771MWULgwwjU+GofnZX9QAmXWZgo= github.com/sourcegraph/conc v0.3.0 h1:OQTbbt6P72L20UqAkXXuLOj79LfEanQ+YQFNpLA9ySo= github.com/sourcegraph/conc v0.3.0/go.mod h1:Sdozi7LEKbFPqYX2/J+iBAM6HpqSLTASQIKqDmF7Mt0= github.com/spf13/afero v1.11.0 h1:WJQKhtpdm3v2IzqG8VMqrr6Rf3UYpEF239Jy9wNepM8= @@ -59,6 +66,9 @@ github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+ 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.3.0/go.mod h1:M5WIy9Dh21IEIfnGCwXGc5bZfKNJtfHm1UVUgZn+9EI= +github.com/stretchr/testify v1.4.0/go.mod h1:j7eGeouHqKxXV5pUuKE4zz7dFj8WfuZ+81PSLYec5m4= +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= @@ -66,22 +76,63 @@ github.com/stretchr/testify v1.9.0 h1:HtqpIVDClZ4nwg75+f6Lvsy/wHu+3BoSGCbBAcpTsT github.com/stretchr/testify v1.9.0/go.mod h1:r2ic/lqez/lEtzL7wO/rwa5dbSLXVDPFyf8C91i36aY= github.com/subosito/gotenv v1.6.0 h1:9NlTDc1FTs4qu0DDq7AEtTPNw6SVm7uBMsUCUjABIf8= github.com/subosito/gotenv v1.6.0/go.mod h1:Dk4QP5c2W3ibzajGcXpNraDfq2IrhjMIvMSWPKKo0FU= +github.com/tailscale/depaware v0.0.0-20210622194025-720c4b409502/go.mod h1:p9lPsd+cx33L3H9nNoecRRxPssFKUwwI50I3pZ0yT+8= +github.com/yuin/goldmark v1.2.1/go.mod h1:3hX8gzYuyVAZsxl0MRgGTJEmQBFcNTphYh9decYSb74= +github.com/yuin/goldmark v1.3.5/go.mod h1:mwnBkeHKe2W/ZEtQ+71ViKU8L12m81fl3OWwC1Zlc8k= +go.uber.org/atomic v1.7.0/go.mod h1:fEN4uk6kAWBTFdckzkM89CLk9XfWZrxpCo0nPH17wJc= +go.uber.org/atomic v1.8.0/go.mod h1:fEN4uk6kAWBTFdckzkM89CLk9XfWZrxpCo0nPH17wJc= +go.uber.org/goleak v1.1.11/go.mod h1:cwTWslyiVhfpKIDGSZEM2HlOvcqm+tG4zioyIeLoqMQ= go.uber.org/goleak v1.3.0 h1:2K3zAYmnTNqV73imy9J1T3WC+gmCePx2hEGkimedGto= go.uber.org/goleak v1.3.0/go.mod h1:CoHD4mav9JJNrW/WLlf7HGZPjdw8EucARQHekz1X6bE= +go.uber.org/multierr v1.6.0/go.mod h1:cdWPpRnG4AhwMwsgIHip0KRBQjJy5kYEpYjJxpXp9iU= +go.uber.org/multierr v1.7.0/go.mod h1:7EAYxJLBy9rStEaz58O2t4Uvip6FSURkq8/ppBp95ak= go.uber.org/multierr v1.11.0 h1:blXXJkSxSSfBVBlC76pxqeO+LN3aDfLQo+309xJstO0= go.uber.org/multierr v1.11.0/go.mod h1:20+QtiLqy0Nd6FdQB9TLXag12DsQkrbs3htMFfDN80Y= +go.uber.org/zap v1.20.0/go.mod h1:wjWOCqI0f2ZZrJF/UufIOkiC8ii6tm1iqIsLo76RfJw= go.uber.org/zap v1.27.0 h1:aJMhYGrd5QSmlpLMr2MftRKl7t8J8PTZPA732ud/XR8= go.uber.org/zap v1.27.0/go.mod h1:GB2qFLM7cTU87MWRP2mPIjqfIDnGu+VIO4V/SdhGo2E= +golang.org/x/crypto v0.0.0-20190308221718-c2843e01d9a2/go.mod h1:djNgcEr1/C05ACkg1iLfiJU5Ep61QUkGW8qpdssI0+w= +golang.org/x/crypto v0.0.0-20191011191535-87dc89f01550/go.mod h1:yigFU9vqHzYiE8UmvKecakEJjdnWj3jj499lnFckfCI= +golang.org/x/crypto v0.0.0-20200622213623-75b288015ac9/go.mod h1:LzIPMQfyMNhhGPhUkYOs5KpL4U8rLKemX1yGLhDgUto= golang.org/x/exp v0.0.0-20231214170342-aacd6d4b4611 h1:qCEDpW1G+vcj3Y7Fy52pEM1AWm3abj8WimGYejI3SC4= golang.org/x/exp v0.0.0-20231214170342-aacd6d4b4611/go.mod h1:iRJReGqOEeBhDZGkGbynYwcHlctCvnjTYIamk7uXpHI= +golang.org/x/lint v0.0.0-20190930215403-16217165b5de/go.mod h1:6SW0HCj/g11FgYtHlgUYUwCkIfeOF89ocIRzGO/8vkc= +golang.org/x/mod v0.3.0/go.mod h1:s0Qsj1ACt9ePp/hMypM3fl4fZqREWJwdYDEqhRiZZUA= +golang.org/x/mod v0.4.0/go.mod h1:s0Qsj1ACt9ePp/hMypM3fl4fZqREWJwdYDEqhRiZZUA= +golang.org/x/mod v0.4.2/go.mod h1:s0Qsj1ACt9ePp/hMypM3fl4fZqREWJwdYDEqhRiZZUA= golang.org/x/mod v0.20.0 h1:utOm6MM3R3dnawAiJgn0y+xvuYRsm1RKM/4giyfDgV0= golang.org/x/mod v0.20.0/go.mod h1:hTbmBsO62+eylJbnUtE2MGJUyE7QWk4xUqPFrRgJ+7c= +golang.org/x/net v0.0.0-20190311183353-d8887717615a/go.mod h1:t9HGtf8HONx5eT2rtn7q6eTqICYqUVnKs3thJo3Qplg= +golang.org/x/net v0.0.0-20190404232315-eb5bcb51f2a3/go.mod h1:t9HGtf8HONx5eT2rtn7q6eTqICYqUVnKs3thJo3Qplg= +golang.org/x/net v0.0.0-20190620200207-3b0461eec859/go.mod h1:z5CRVTTTmAJ677TzLLGU+0bjPO0LkuOLi4/5GtJWs/s= +golang.org/x/net v0.0.0-20201021035429-f5854403a974/go.mod h1:sp8m0HH+o8qH0wwXwYZr8TS3Oi6o0r6Gce1SSxlDquU= +golang.org/x/net v0.0.0-20210405180319-a5a99cb37ef4/go.mod h1:p54w0d4576C0XHj96bSt6lcn1PtDYWL6XObtHCRCNQM= golang.org/x/net v0.25.0 h1:d/OCCoBEUq33pjydKrGQhw7IlUPI2Oylr+8qLx49kac= golang.org/x/net v0.25.0/go.mod h1:JkAGAh7GEvH74S6FOH42FLoXpXbE/aqXSrIQjXgsiwM= +golang.org/x/sync v0.0.0-20190423024810-112230192c58/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= +golang.org/x/sync v0.0.0-20201020160332-67f06af15bc9/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= +golang.org/x/sync v0.0.0-20210220032951-036812b2e83c/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= +golang.org/x/sys v0.0.0-20190215142949-d0b11bdaac8a/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= +golang.org/x/sys v0.0.0-20190412213103-97732733099d/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= +golang.org/x/sys v0.0.0-20200930185726-fdedc70b468f/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= +golang.org/x/sys v0.0.0-20201119102817-f84b799fce68/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= +golang.org/x/sys v0.0.0-20210330210617-4fbd30eecc44/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= +golang.org/x/sys v0.0.0-20210510120138-977fb7262007/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.24.0 h1:Twjiwq9dn6R1fQcyiK+wQyHWfaz/BJB+YIpzU/Cv3Xg= golang.org/x/sys v0.24.0/go.mod h1:/VUhepiaJMQUp4+oa/7Zr1D23ma6VTLIYjOOTFZPUcA= +golang.org/x/term v0.0.0-20201126162022-7de9c90e9dd1/go.mod h1:bj7SfCRtBDWHUb9snDiAeCFNEtKQo2Wmx5Cou7ajbmo= +golang.org/x/text v0.3.0/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ= +golang.org/x/text v0.3.3/go.mod h1:5Zoc/QRtKVWzQhOtBMvqHzDpF6irO9z98xDceosuGiQ= golang.org/x/text v0.17.0 h1:XtiM5bkSOt+ewxlOE/aE/AKEHibwj/6gvWMl9Rsh0Qc= golang.org/x/text v0.17.0/go.mod h1:BuEKDfySbSR4drPmRPG/7iBdf8hvFMuRexcpahXilzY= +golang.org/x/tools v0.0.0-20180917221912-90fa682c2a6e/go.mod h1:n7NCudcB/nEzxVGmLbDWY5pfWTLqBcC2KZ6jyYvM4mQ= +golang.org/x/tools v0.0.0-20190311212946-11955173bddd/go.mod h1:LCzVGOaR6xXOjkQ3onu1FJEFr0SW1gC7cKk1uF8kGRs= +golang.org/x/tools v0.0.0-20191119224855-298f0cb1881e/go.mod h1:b+2E5dAYhXwXZwtnZ6UAqBI28+e2cm9otk0dWdXHAEo= +golang.org/x/tools v0.0.0-20201211185031-d93e913c1a58/go.mod h1:emZCQorbCU4vsT4fOWvOPXz4eW1wZW4PmDk9uLelYpA= +golang.org/x/tools v0.1.5/go.mod h1:o0xws9oXOQQZyjljx8fwUC0k7L1pTE6eaCbjGeHmOkk= +golang.org/x/xerrors v0.0.0-20190717185122-a985d3407aa7/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0= +golang.org/x/xerrors v0.0.0-20191011141410-1b5146add898/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0= +golang.org/x/xerrors v0.0.0-20200804184101-5ec99f83aff1/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0= google.golang.org/genproto/googleapis/rpc v0.0.0-20240528184218-531527333157 h1:Zy9XzmMEflZ/MAaA7vNcoebnRAld7FsPW1EeBB7V0m8= google.golang.org/genproto/googleapis/rpc v0.0.0-20240528184218-531527333157/go.mod h1:EfXuqaE1J41VCDicxHzUDm+8rk+7ZdXzHV0IhO/I6s0= google.golang.org/grpc v1.65.0 h1:bs/cUb4lp1G5iImFFd3u5ixQzweKizoZJAwBNLR42lc= @@ -89,10 +140,16 @@ google.golang.org/grpc v1.65.0/go.mod h1:WgYC2ypjlB0EiQi6wdKixMqukr6lBc0Vo+oOgjr google.golang.org/protobuf v1.34.2 h1:6xV6lTsCfpGD21XK49h7MhtcApnLqkfYgPcdHftf6hg= google.golang.org/protobuf v1.34.2/go.mod h1:qYOHts0dSfpeUzUFpOMr/WGzszTmLH+DiWniOlNbLDw= gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= +gopkg.in/check.v1 v1.0.0-20180628173108-788fd7840127/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= gopkg.in/check.v1 v1.0.0-20190902080502-41f04d3bba15 h1:YR8cESwS4TdDjEe65xsg0ogRM/Nc3DYOhEAlW+xobZo= gopkg.in/check.v1 v1.0.0-20190902080502-41f04d3bba15/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= gopkg.in/ini.v1 v1.67.0 h1:Dgnx+6+nfE+IfzjUEISNeydPJh9AXNNsWbGP9KzCsOA= gopkg.in/ini.v1 v1.67.0/go.mod h1:pNLf8WUiyNEtQjuu5G5vTm06TEv9tsIgeAvK8hOrP4k= +gopkg.in/yaml.v2 v2.2.2/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI= +gopkg.in/yaml.v2 v2.2.8/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI= gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= +gopkg.in/yaml.v3 v3.0.0-20210107192922-496545a6307b/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= +moul.io/zapfilter v1.7.0 h1:7aFrG4N72bDH9a2BtYUuUaDS981Dxu3qybWfeqaeBDU= +moul.io/zapfilter v1.7.0/go.mod h1:M+N2s+qZiA+bzRoyKMVRxyuERijS2ovi2pnMyiOGMvc= diff --git a/internal/processor/cardata.go b/internal/processor/cardata.go index e0afcb0..edc45cc 100644 --- a/internal/processor/cardata.go +++ b/internal/processor/cardata.go @@ -1,12 +1,14 @@ package processor import ( + "context" "fmt" commonv1 "buf.build/gen/go/mpapenbr/iracelog/protocolbuffers/go/iracelog/common/v1" racestatev1 "buf.build/gen/go/mpapenbr/iracelog/protocolbuffers/go/iracelog/racestate/v1" trackv1 "buf.build/gen/go/mpapenbr/iracelog/protocolbuffers/go/iracelog/track/v1" "github.com/mpapenbr/goirsdk/irsdk" + "go.uber.org/zap" "github.com/mpapenbr/go-racelogger/log" ) @@ -34,8 +36,8 @@ const ( type carInit struct{} -func (ci *carInit) Enter(cd *CarData) { log.Info("Entering state: carInit") } -func (ci *carInit) Exit(cd *CarData) { log.Info("Leaving state: carInit") } +func (ci *carInit) Enter(cd *CarData) { cd.log.Info("Entering state: carInit") } +func (ci *carInit) Exit(cd *CarData) { cd.log.Info("Leaving state: carInit") } func (ci *carInit) UpdatePre(cd *CarData, cw *carWorkData) { cd.copyWorkData(cw) if cw.trackPos == -1 { @@ -58,8 +60,8 @@ func (ci *carInit) UpdatePost(cd *CarData) {} type carRun struct{} -func (cr *carRun) Enter(cd *CarData) { log.Info("Entering state: carRun") } -func (cr *carRun) Exit(cd *CarData) { log.Info("Leaving state: carRun") } +func (cr *carRun) Enter(cd *CarData) { cd.log.Info("Entering state: carRun") } +func (cr *carRun) Exit(cd *CarData) { cd.log.Info("Leaving state: carRun") } func (cr *carRun) UpdatePre(cd *CarData, cw *carWorkData) { if cw.trackPos == -1 { @@ -103,8 +105,8 @@ func handleInlap(cd *CarData, cw *carWorkData) { type carSlow struct{} -func (cs *carSlow) Enter(cd *CarData) { log.Info("Entering state: carSlow") } -func (cs *carSlow) Exit(cd *CarData) { log.Info("Leaving state: carSlow") } +func (cs *carSlow) Enter(cd *CarData) { cd.log.Info("Entering state: carSlow") } +func (cs *carSlow) Exit(cd *CarData) { cd.log.Info("Leaving state: carSlow") } func (cs *carSlow) UpdatePre(cd *CarData, cw *carWorkData) { if cw.trackPos == -1 { @@ -135,12 +137,12 @@ func (cs *carSlow) UpdatePost(cd *CarData) { type carPit struct{} func (cp *carPit) Enter(cd *CarData) { - log.Info("Entering state: carPit") + cd.log.Info("Entering state: carPit") cd.pitBoundaryProc.processPitEntry(cd.trackPos) } func (cp *carPit) Exit(cd *CarData) { - log.Info("Leaving state: carPit") + cd.log.Info("Leaving state: carPit") cd.pitBoundaryProc.processPitExit(cd.trackPos) } @@ -164,8 +166,8 @@ func (cp *carPit) UpdatePost(cd *CarData) {} type carFinished struct{} -func (cf *carFinished) Enter(cd *CarData) { log.Info("Entering state: carFinished") } -func (cf *carFinished) Exit(cd *CarData) { log.Info("Leaving state: carFinished") } +func (cf *carFinished) Enter(cd *CarData) { cd.log.Info("Entering state: carFinished") } +func (cf *carFinished) Exit(cd *CarData) { cd.log.Info("Leaving state: carFinished") } func (cf *carFinished) UpdatePre(cd *CarData, cw *carWorkData) { // do nothing - final state cd.state = CarStateFinish @@ -174,8 +176,8 @@ func (cf *carFinished) UpdatePost(cd *CarData) {} type carOut struct{} -func (co *carOut) Enter(cd *CarData) { log.Info("Entering state: carOut") } -func (co *carOut) Exit(cd *CarData) { log.Info("Leaving state: carOut") } +func (co *carOut) Enter(cd *CarData) { cd.log.Info("Entering state: carOut") } +func (co *carOut) Exit(cd *CarData) { cd.log.Info("Leaving state: carOut") } func (co *carOut) UpdatePre(cd *CarData, cw *carWorkData) { // this may happen after resets or tow to pit road. // if not on the pit road it may just be a short connection issue. @@ -238,10 +240,12 @@ type CarData struct { startOutLap float64 // session time when car exited pit road inlapTime float64 // gets computed on pit entry outlapTime float64 // gets computed after pit exit on s/f + log *log.Logger } //nolint:whitespace // can't get different linters happy func NewCarData( + ctx context.Context, carIdx int32, carDriverProc *CarDriverProc, pitBoundaryProc *PitBoundaryProc, @@ -262,6 +266,12 @@ func NewCarData( currentSector: -1, lastLap: TimeWithMarker{time: -1, marker: ""}, bestLap: TimeWithMarker{time: -1, marker: ""}, + log: log.GetFromContext(ctx).Named("carData").WithOptions( + zap.Fields( + zap.Int32("carIdx", carIdx), + zap.String("carNum", carDriverProc.GetCurrentDriver(carIdx).CarNumber), + ), + ), } return &ret diff --git a/internal/processor/cars.go b/internal/processor/cars.go index da90038..397e01a 100644 --- a/internal/processor/cars.go +++ b/internal/processor/cars.go @@ -2,6 +2,7 @@ package processor import ( + "context" "fmt" "math" "reflect" @@ -19,6 +20,7 @@ import ( // this means overall standings, gaps, etc. // the data for single cars is processed in CarData type CarProc struct { + ctx context.Context api *irsdk.Irsdk gpd *GlobalProcessingData @@ -41,6 +43,7 @@ type CarProc struct { bestSectionProc *BestSectionProc maxSpeed float64 + log *log.Logger } type finishMarker struct { @@ -117,6 +120,7 @@ func CarManifest(gpd *GlobalProcessingData) []string { //nolint:whitespace // can't get different linters happy func NewCarProc( + ctx context.Context, api *irsdk.Irsdk, gpd *GlobalProcessingData, carDriverProc *CarDriverProc, @@ -126,6 +130,7 @@ func NewCarProc( maxSpeed float64, ) *CarProc { ret := &CarProc{ + ctx: ctx, api: api, gpd: gpd, carDriverProc: carDriverProc, @@ -133,6 +138,7 @@ func NewCarProc( speedmapProc: speedmapProc, messageProc: messageProc, maxSpeed: maxSpeed, + log: log.GetFromContext(ctx).Named("CarProc"), } ret.init() @@ -183,6 +189,7 @@ func (p *CarProc) newCarData(carIdx int) *CarData { } } return NewCarData( + p.ctx, int32(carIdx), p.carDriverProc, p.pitBoundaryProc, @@ -241,7 +248,7 @@ func (p *CarProc) Process() { curStandingsIR := y.SessionInfo.Sessions[sessionNum].ResultsPositions if curStandingsIR != nil && !reflect.DeepEqual(curStandingsIR, p.lastStandingsIR) { - log.Info("New standings available") + p.log.Info("New standings available") // fmt.Printf("Standings-Delta: %v\n", cmp.Diff(curStandingsIR, p.lastStandingsIR)) p.processStandings(curStandingsIR) // standings changed, update @@ -270,7 +277,7 @@ func (p *CarProc) carInfo(carIdx int) { // carId := carData.carDriverProc.GetCurrentDriver(carData.carIdx).CarID // carClassId := carData.carDriverProc.GetCurrentDriver(carData.carIdx).CarClassID - log.Warn("CarInfo", + p.log.Warn("CarInfo", log.String("carNum", carNum), log.Float64("carPos", carData.trackPos), ) @@ -311,7 +318,7 @@ func (p *CarProc) computeTimes(carData *CarData) { if !sector.isStarted() { carData.startSector(i, p.currentTime) - log.Debug("Sector had no start time. Now initialized", + p.log.Debug("Sector had no start time. Now initialized", log.String("carNum", carNum), log.Int("sector", i)) return @@ -331,7 +338,7 @@ func (p *CarProc) computeTimes(carData *CarData) { // compute own laptime if carData.currentSector == 0 { - log.Debug("Car crossed the line", log.String("carNum", carNum)) + p.log.Debug("Car crossed the line", log.String("carNum", carNum)) if carData.isLapStarted() { carData.stopLap(p.currentTime) // no need to call bestSectionProc. This will be handled in processStandings @@ -341,7 +348,7 @@ func (p *CarProc) computeTimes(carData *CarData) { carData.setState(&carFinished{}) carData.stintLap -= 1 carData.lap = carData.lc - log.Info("Car finished the race", log.String("carNum", carNum)) + p.log.Info("Car finished the race", log.String("carNum", carNum)) return } else if len(p.aboutToFinishMarker) > 0 { if float64(carData.lap) > p.aboutToFinishMarker[0].ref { @@ -349,7 +356,7 @@ func (p *CarProc) computeTimes(carData *CarData) { carData.setState(&carFinished{}) carData.stintLap -= 1 carData.lap = carData.lc - log.Info("Car WON the race", log.String("carNum", carNum)) + p.log.Info("Car WON the race", log.String("carNum", carNum)) return } } @@ -376,8 +383,8 @@ func (p *CarProc) calcSpeed(carData *CarData) float64 { // issue warning if car moved backward more than minMoveDistPct if moveDist < 0 && math.Abs(moveDist) > p.minMoveDistPct { //nolint:lll // better readability - log.Warn("Car moved backward???", - log.String("carNum", p.carDriverProc.GetCurrentDriver(carData.carIdx).CarNumber), + carData.log.Warn("Car moved backward???", + // log.String("carNum", p.carDriverProc.GetCurrentDriver(carData.carIdx).CarNumber), log.Float64("prevTrackPos", prevTrackPos), log.Float64("currentTrackPos", currentTrackPos), log.Float64("dist", moveDist), @@ -394,14 +401,14 @@ func (p *CarProc) calcSpeed(carData *CarData) float64 { } speed := float64(p.gpd.TrackInfo.Length) * moveDist / deltaTime * 3.6 if speed > p.maxSpeed { - log.Warn("Speed above maxSpeed. Ignoring", + carData.log.Warn("Speed above maxSpeed. Ignoring", log.Float64("speed", speed), log.Float64("maxSpeed", p.maxSpeed)) return -1 } return speed } else { - log.Debug("Delta time is 0") + p.log.Debug("Delta time is 0") return 0 } // compute speed @@ -440,7 +447,7 @@ func (p *CarProc) calcDelta() { currentRaceOrder[i].trackPos, car.trackPos) if deltaByCarClassSpeemap < 0 { - log.Warn("Negative delta by speedmap", + p.log.Warn("Negative delta by speedmap", log.String("carNum", car.carDriverProc.GetCurrentDriver(car.carIdx).CarNumber), log.Float64("cifPos", currentRaceOrder[i].trackPos), log.Float64("carPos", car.trackPos), @@ -509,7 +516,7 @@ func (p *CarProc) markBestLaps() { } debugBest := func(title string, car []*CarData) { for _, item := range car { - log.Debug("Best lap", + p.log.Debug("Best lap", log.String("title", title), log.String("carNum", item.carDriverProc.GetCurrentDriver(item.carIdx).CarNumber), log.Float64("bestLap", item.bestLap.time), @@ -597,7 +604,7 @@ func (p *CarProc) getInCurrentRaceOrder() []*CarData { } func (p *CarProc) RaceStarts() { - log.Info("Received race start event. ") + p.log.Info("Received race start event. ") // have to check if we need this..... // for _, idx := range p.getProcessableCarIdxs() { // p.carLookup[idx].startLap(p.currentTime) diff --git a/internal/processor/driver.go b/internal/processor/driver.go index 75299e1..05ac2fe 100644 --- a/internal/processor/driver.go +++ b/internal/processor/driver.go @@ -2,6 +2,7 @@ package processor import ( "reflect" + "slices" carv1 "buf.build/gen/go/mpapenbr/iracelog/protocolbuffers/go/iracelog/car/v1" commonv1 "buf.build/gen/go/mpapenbr/iracelog/protocolbuffers/go/iracelog/common/v1" @@ -9,7 +10,6 @@ import ( racestatev1 "buf.build/gen/go/mpapenbr/iracelog/protocolbuffers/go/iracelog/racestate/v1" "github.com/mpapenbr/goirsdk/irsdk" "github.com/mpapenbr/goirsdk/yaml" - "golang.org/x/exp/slices" "google.golang.org/protobuf/types/known/timestamppb" ) diff --git a/internal/processor/pitboundary.go b/internal/processor/pitboundary.go index 6993fd1..170cab1 100644 --- a/internal/processor/pitboundary.go +++ b/internal/processor/pitboundary.go @@ -1,6 +1,6 @@ package processor -import "golang.org/x/exp/slices" +import "slices" type PitBoundaryData struct { min float64 diff --git a/internal/processor/processor.go b/internal/processor/processor.go index c1f6501..8963a6c 100644 --- a/internal/processor/processor.go +++ b/internal/processor/processor.go @@ -1,6 +1,7 @@ package processor import ( + "context" "time" commonv1 "buf.build/gen/go/mpapenbr/iracelog/protocolbuffers/go/iracelog/common/v1" @@ -32,6 +33,7 @@ type Options struct { MaxSpeed float64 // speeds above this value (km/h) are not processed GlobalProcessingData *GlobalProcessingData RecordingDoneChannel chan struct{} + ctx context.Context } func defaultOptions() *Options { @@ -93,6 +95,12 @@ func WithRecordingDoneChannel(c chan struct{}) OptionsFunc { } } +func WithContext(ctx context.Context) OptionsFunc { + return func(o *Options) { + o.ctx = ctx + } +} + type Processor struct { api *irsdk.Irsdk options *Options @@ -111,6 +119,7 @@ type Processor struct { extraInfoOutput chan *racestatev1.PublishEventExtraInfoRequest recording bool racing bool + log *log.Logger } //nolint:whitespace,funlen // can't get different linters happy @@ -133,6 +142,7 @@ func NewProcessor( carDriverProc.SetReportChangeFunc(messageProc.DriverEnteredCar) speedmapProc := NewSpeedmapProc(api, opts.ChunkSize, opts.GlobalProcessingData) carProc := NewCarProc( + opts.ctx, api, opts.GlobalProcessingData, carDriverProc, @@ -141,7 +151,9 @@ func NewProcessor( messageProc, opts.MaxSpeed, ) - raceProc := NewRaceProc(api, + raceProc := NewRaceProc( + opts.ctx, + api, carProc, messageProc, nil) @@ -162,6 +174,7 @@ func NewProcessor( pitBoundaryProc: pitBoundaryProc, recording: true, racing: false, + log: log.GetFromContext(opts.ctx).Named("processor"), } ret.init() return &ret @@ -177,7 +190,7 @@ func (p *Processor) init() { p.sendStateMessage() // if enough data was collected, send it to server if p.pitBoundaryProc.pitEntry.computed && p.pitBoundaryProc.pitExit.computed { - log.Info("Pit entry and exit computed during session, sending to server") + p.log.Info("Pit entry and exit computed during session, sending to server") pitLaneLength := func(entry, exit float32) float32 { if exit > entry { return (exit - entry) * p.options.GlobalProcessingData.TrackInfo.Length @@ -209,7 +222,7 @@ func (p *Processor) init() { p.recording = false // signal recording done p.racing = false // signal racing done if p.options.RecordingDoneChannel != nil { - log.Debug("Signaling recording done") + p.log.Debug("Signaling recording done") close(p.options.RecordingDoneChannel) } } @@ -220,14 +233,14 @@ func (p *Processor) Process() { p.raceProc.Process() if HasDriverChange(&y.DriverInfo, &p.lastDriverInfo) { - log.Info("DriverInfo changed, updating state") + p.log.Info("DriverInfo changed, updating state") var freshYaml iryaml.IrsdkYaml if err := yaml.Unmarshal([]byte(p.api.GetYamlString()), &freshYaml); err != nil { // let's try to repair the yaml and unmarshal again err := yaml.Unmarshal([]byte(p.api.RepairedYaml(p.api.GetYamlString())), &freshYaml) if err != nil { - log.Error("Error unmarshalling irsdk yaml", log.ErrorField(err)) + p.log.Error("Error unmarshalling irsdk yaml", log.ErrorField(err)) return } } diff --git a/internal/processor/race.go b/internal/processor/race.go index 9e85c7b..94f674e 100644 --- a/internal/processor/race.go +++ b/internal/processor/race.go @@ -2,6 +2,7 @@ package processor import ( + "context" "time" "github.com/mpapenbr/goirsdk/irsdk" @@ -23,12 +24,16 @@ type RaceProc struct { messageProc *MessageProc RaceRunCallback func() RaceDoneCallback func() + + stateInvalid, stateRun, stateFinishing, stateCooldown, stateDone raceState } -type RaceInvalid struct{} +type RaceInvalid struct { + log *log.Logger +} -func (ri *RaceInvalid) Enter() { log.Info("Entering state: RaceInvalid") } -func (ri *RaceInvalid) Exit() { log.Info("Leaving state: RaceInvalid") } +func (ri *RaceInvalid) Enter() { ri.log.Info("enter state") } +func (ri *RaceInvalid) Exit() { ri.log.Info("exit state") } func (ri *RaceInvalid) Update(rp *RaceProc) { y := rp.api.GetLatestYaml() sessionNum := justValue(rp.api.GetIntValue("SessionNum")).(int32) @@ -37,7 +42,7 @@ func (ri *RaceInvalid) Update(rp *RaceProc) { if sessionSate == int32(irsdk.StateRacing) { rp.messageProc.RaceStarts() rp.carProc.RaceStarts() - rp.setState(&RaceRun{}) + rp.setState(rp.stateRun) if rp.RaceRunCallback != nil { rp.RaceRunCallback() } @@ -45,10 +50,12 @@ func (ri *RaceInvalid) Update(rp *RaceProc) { } } -type RaceRun struct{} +type RaceRun struct { + log *log.Logger +} -func (rr *RaceRun) Enter() { log.Info("Entering state: RaceRun") } -func (rr *RaceRun) Exit() { log.Info("Leaving state: RaceRun") } +func (rr *RaceRun) Enter() { rr.log.Info("enter state") } +func (rr *RaceRun) Exit() { rr.log.Info("exit state") } // as long as we don't detect the checkered flag we stay in this state func (rr *RaceRun) Update(rp *RaceProc) { @@ -56,62 +63,77 @@ func (rr *RaceRun) Update(rp *RaceProc) { if sessionSate == int32(irsdk.StateCheckered) { rp.messageProc.CheckeredFlagIssued() rp.carProc.CheckeredFlagIssued() - rp.setState(&RaceFinishing{}) + rp.setState(rp.stateFinishing) return } rp.carProc.Process() // call carproc here } -type RaceFinishing struct{} +type RaceFinishing struct { + log *log.Logger +} -func (rf *RaceFinishing) Enter() { log.Info("Entering state: RaceFinishing") } -func (rf *RaceFinishing) Exit() { log.Info("Leaving state: RaceFinishing") } +func (rf *RaceFinishing) Enter() { rf.log.Info("enter state") } +func (rf *RaceFinishing) Exit() { rf.log.Info("exit state") } func (rf *RaceFinishing) Update(rp *RaceProc) { sessionSate := justValue(rp.api.GetIntValue("SessionState")).(int32) if sessionSate == int32(irsdk.StateCoolDown) { rp.markEnterCooldown() - rp.setState(&RaceCooldown{}) + rp.setState(rp.stateCooldown) return } rp.carProc.Process() } -type RaceCooldown struct{} +type RaceCooldown struct { + log *log.Logger +} -func (rc *RaceCooldown) Enter() { log.Info("Entering state: RaceCooldown") } -func (rc *RaceCooldown) Exit() { log.Info("Leaving state: RaceCooldown") } +func (rc *RaceCooldown) Enter() { rc.log.Info("enter state") } +func (rc *RaceCooldown) Exit() { rc.log.Info("exist state") } func (rc *RaceCooldown) Update(rp *RaceProc) { if time.Since(rp.cooldownEntered) > time.Second*5 { rp.messageProc.RecordingDone() - rp.setState(&RaceDone{}) + rp.setState(rp.stateDone) return } rp.carProc.Process() } -type RaceDone struct{} +type RaceDone struct { + log *log.Logger +} -func (rd *RaceDone) Enter() { log.Info("Entering state: RaceDone") } -func (rd *RaceDone) Exit() { log.Info("Leaving state: RaceDone") } +func (rd *RaceDone) Enter() { rd.log.Info("enter state") } +func (rd *RaceDone) Exit() { rd.log.Info("exit state") } func (rd *RaceDone) Update(rp *RaceProc) { rp.onRaceDone() } //nolint:whitespace // can't get different linters happy func NewRaceProc( + ctx context.Context, api *irsdk.Irsdk, carProc *CarProc, messageProc *MessageProc, raceDoneCallback func(), ) *RaceProc { + createLogger := func(name string) *log.Logger { + return log.GetFromContext(ctx).Named("state" + "." + name) + } ret := RaceProc{ api: api, carProc: carProc, messageProc: messageProc, RaceDoneCallback: raceDoneCallback, + stateInvalid: &RaceInvalid{createLogger("invalid")}, + stateRun: &RaceRun{createLogger("run")}, + stateFinishing: &RaceFinishing{createLogger("finishing")}, + stateCooldown: &RaceCooldown{createLogger("cooldown")}, + stateDone: &RaceDone{createLogger("done")}, } - ret.currentState = &RaceInvalid{} + ret.currentState = ret.stateInvalid return &ret } diff --git a/internal/processor/speedmap.go b/internal/processor/speedmap.go index 2a7bfc7..490e608 100644 --- a/internal/processor/speedmap.go +++ b/internal/processor/speedmap.go @@ -3,11 +3,11 @@ package processor import ( "fmt" "math" + "slices" speedmapv1 "buf.build/gen/go/mpapenbr/iracelog/protocolbuffers/go/iracelog/speedmap/v1" "github.com/mpapenbr/goirsdk/irsdk" "github.com/samber/lo" - "golang.org/x/exp/slices" "github.com/mpapenbr/go-racelogger/log" ) diff --git a/internal/processor/util.go b/internal/processor/util.go index 47fe6b3..55ed70d 100644 --- a/internal/processor/util.go +++ b/internal/processor/util.go @@ -5,13 +5,13 @@ import ( "errors" "fmt" "regexp" + "slices" "strconv" carv1 "buf.build/gen/go/mpapenbr/iracelog/protocolbuffers/go/iracelog/car/v1" commonv1 "buf.build/gen/go/mpapenbr/iracelog/protocolbuffers/go/iracelog/common/v1" "github.com/mpapenbr/goirsdk/irsdk" "github.com/mpapenbr/goirsdk/yaml" - "golang.org/x/exp/slices" "github.com/mpapenbr/go-racelogger/log" ) diff --git a/internal/racelogger.go b/internal/racelogger.go index 2034f8f..7b1af04 100644 --- a/internal/racelogger.go +++ b/internal/racelogger.go @@ -57,6 +57,7 @@ type Racelogger struct { config *Config globalData processor.GlobalProcessingData msgLogger *os.File + log *log.Logger } func defaultConfig() *Config { @@ -152,6 +153,7 @@ func NewRaceLogger(cfg ...ConfigFunc) *Racelogger { ), config: c, msgLogger: grpcMsgLog, + log: log.GetFromContext(c.ctx).Named("rl"), } ret.init() @@ -159,7 +161,7 @@ func NewRaceLogger(cfg ...ConfigFunc) *Racelogger { } func (r *Racelogger) Close() { - log.Debug("Closing Racelogger") + r.log.Debug("Closing Racelogger") r.api.Close() r.dataprovider.Close() if r.msgLogger != nil { @@ -213,16 +215,16 @@ func (r *Racelogger) UnregisterProvider() { func (r *Racelogger) init() { r.setupWatchdog(time.Second) - log.Debug("Ensure iRacing simulation is ready to provide data") + r.log.Debug("Ensure iRacing simulation is ready to provide data") for { if r.simIsRunning { break } else { - log.Debug("Waiting for initialized simulation") + r.log.Debug("Waiting for initialized simulation") time.Sleep(time.Second) } } - log.Debug("Telemetry data is available") + r.log.Debug("Telemetry data is available") } func (r *Racelogger) createEventInfo(irYaml *yaml.IrsdkYaml) *eventv1.Event { @@ -285,22 +287,22 @@ func (r *Racelogger) setupWatchdog(interval time.Duration) { for { select { case <-ctx.Done(): - log.Debug("watchdog received ctx.Done") + r.log.Debug("watchdog received ctx.Done") return default: if irsdk.CheckIfSimIsRunning() { if r.api == nil { - log.Debug("Initializing irsdk api") + r.log.Debug("Initializing irsdk api") r.api = irsdk.NewIrsdk() - log.Debug("waiting some seconds before start") + r.log.Debug("waiting some seconds before start") time.Sleep(5 * time.Second) r.api.WaitForValidData() // as long as there are no entries we have to try again for len(r.api.GetValueKeys()) == 0 { r.api.Close() - log.Debug("iRacing not yet ready. Retrying in 5s") + r.log.Debug("iRacing not yet ready. Retrying in 5s") time.Sleep(5 * time.Second) r.api = irsdk.NewIrsdk() r.api.WaitForValidData() @@ -314,14 +316,14 @@ func (r *Racelogger) setupWatchdog(interval time.Duration) { } else if r.config.ensureLiveDataInterval > 0 && time.Since(lastForceLiveData) > r.config.ensureLiveDataInterval { - log.Debug("Forcing live data") + r.log.Debug("Forcing live data") //nolint:errcheck // by design r.api.ReplaySearch(irsdk.ReplaySearchModeEnd) lastForceLiveData = time.Now() } } else { if r.api != nil { - log.Debug("Resetting irsdk api") + r.log.Debug("Resetting irsdk api") r.api.Close() } r.api = nil @@ -357,6 +359,7 @@ func (r *Racelogger) setupMainLoop() { processor.WithSpeedmapPublishInterval(r.config.speedmapPublishInterval), processor.WithSpeedmapSpeedThreshold(r.config.speedmapSpeedThreshold), processor.WithMaxSpeed(r.config.maxSpeed), + processor.WithContext(r.config.ctx), ) r.dataprovider.PublishStateFromChannel(r.eventKey, stateChannel) @@ -370,12 +373,12 @@ func (r *Racelogger) setupMainLoop() { for { select { case <-ctx.Done(): - log.Debug("mainLoop received ctx.Done") + r.log.Debug("mainLoop received ctx.Done") return case _, more := <-recordingDoneChannel: - log.Debug("mainLoop received recordingDoneChannel", log.Bool("more", more)) + r.log.Debug("mainLoop received recordingDoneChannel", log.Bool("more", more)) if !more { - log.Info("Recording done.") + r.log.Info("Recording done.") r.config.cancel() return } @@ -391,7 +394,7 @@ func (r *Racelogger) setupMainLoop() { ok := r.api.GetDataWithDataReadyTimeout(r.config.waitForDataTimeout) getDataDurations = append(getDataDurations, time.Since(startGetData)) if len(getDataDurations) == 120 { - logDurations("getData", getDataDurations) + r.logDurations("getData", getDataDurations) getDataDurations = []time.Duration{} } if ok { @@ -400,7 +403,7 @@ func (r *Racelogger) setupMainLoop() { procDurations = append(procDurations, time.Since(startProc)) if len(procDurations) == 120 { - logDurations("processedData", procDurations) + r.logDurations("processedData", procDurations) procDurations = []time.Duration{} } } else { @@ -413,7 +416,8 @@ func (r *Racelogger) setupMainLoop() { go mainLoop(r.config.ctx) } -func logDurations(msg string, durations []time.Duration) { +func (r *Racelogger) logDurations(msg string, durations []time.Duration) { + myLog := r.log.Named("durations") minTime := 1 * time.Second maxTime := time.Duration(0) sum := int64(0) @@ -442,7 +446,7 @@ func logDurations(msg string, durations []time.Duration) { if validDurations > 0 { avg = time.Duration(sum / int64(validDurations)) } - log.Debug(msg, + myLog.Debug(msg, log.Int("zeroDurations", zeroDurations), log.Int("validDurations", validDurations), log.Duration("min", minTime), diff --git a/log/config.go b/log/config.go new file mode 100644 index 0000000..081d809 --- /dev/null +++ b/log/config.go @@ -0,0 +1,52 @@ +package log + +import ( + "os" + + "go.uber.org/zap" + "go.uber.org/zap/zapcore" + "gopkg.in/yaml.v3" +) + +type Config struct { + DefaultLevel string `yaml:"defaultLevel"` + Loggers map[string]string `yaml:"loggers"` + Zap zap.Config `yaml:"zap"` + Filters []string `yaml:"filters"` +} + +type NamedLoggerConfig struct { + Level string `yaml:"level"` +} + +func DefaultDevConfig() *Config { + z := zap.NewDevelopmentConfig() + z.EncoderConfig.EncodeTime = zapcore.TimeEncoderOfLayout("15:04:05.000") + return &Config{ + DefaultLevel: "info", + Zap: z, + } +} + +func DefaultProdConfig() *Config { + return &Config{ + DefaultLevel: "info", + Zap: zap.NewProductionConfig(), + } +} + +func LoadConfig(filename string) (*Config, error) { + data, err := os.ReadFile(filename) + if err != nil { + return nil, err + } + + cfg := Config{ + Zap: zap.NewProductionConfig(), + } + if err := yaml.Unmarshal(data, &cfg); err != nil { + return nil, err + } + + return &cfg, nil +} diff --git a/log/context.go b/log/context.go new file mode 100644 index 0000000..8997169 --- /dev/null +++ b/log/context.go @@ -0,0 +1,19 @@ +package log + +import "context" + +type loggerKey string // used type to store logger in context + +func AddToContext(ctx context.Context, logger *Logger) context.Context { + return context.WithValue(ctx, loggerKey("logger"), logger) +} + +func GetFromContext(ctx context.Context) *Logger { + if ctx == nil { + return nil + } + if logger, ok := ctx.Value(loggerKey("logger")).(*Logger); ok { + return logger + } + return nil +} diff --git a/log/zap.go b/log/zap.go index 74ac618..e7b07a4 100644 --- a/log/zap.go +++ b/log/zap.go @@ -2,11 +2,16 @@ package log import ( "io" + "maps" "os" + "regexp" + "slices" + "strings" "time" "go.uber.org/zap" "go.uber.org/zap/zapcore" + "moul.io/zapfilter" ) type Level = zapcore.Level @@ -26,8 +31,14 @@ const ( type Field = zap.Field type Logger struct { - l *zap.Logger // zap ensure that zap.Logger is safe for concurrent use - level Level + l *zap.Logger // zap ensure that zap.Logger is safe for concurrent use + level Level + baseConfig *zap.Config + loggerConfigs map[string]string +} + +func (l *Logger) Level() Level { + return l.level } func (l *Logger) Debug(msg string, fields ...Field) { @@ -62,6 +73,51 @@ func (l *Logger) Log(lvl Level, msg string, fields ...Field) { l.l.Log(lvl, msg, fields...) } +func (l *Logger) Named(name string) *Logger { + level := l.level + fullLoggerName := name + if l.l.Name() != "" { + fullLoggerName = l.l.Name() + "." + name + } + loggers := slices.Collect(maps.Keys(l.loggerConfigs)) + bestMatch := findBestMatch(loggers, fullLoggerName) + if bestMatch != "" { + if cfg, ok := l.loggerConfigs[bestMatch]; ok { + if cfg != "" { + lvl, _ := zap.ParseAtomicLevel(cfg) + level = lvl.Level() + } + } + + myConfig := *l.baseConfig + myConfig.Level = zap.NewAtomicLevelAt(level) + lt, _ := myConfig.Build() + return &Logger{ + l: zap.New(lt.Core(), + zap.WithCaller(!l.baseConfig.DisableCaller), + zap.AddStacktrace(zap.ErrorLevel), + AddCallerSkip(1)).Named(fullLoggerName), + + level: lt.Level(), + baseConfig: l.baseConfig, + loggerConfigs: l.loggerConfigs, + } + } + return &Logger{ + l: l.l.Named(name), + level: level, + baseConfig: l.baseConfig, + loggerConfigs: l.loggerConfigs, + } +} + +func (l *Logger) WithOptions(opts ...Option) *Logger { + return &Logger{ + l: l.l.WithOptions(opts...), + level: l.level, + } +} + // function variables for all field types // in github.com/uber-go/zap/field.go @@ -179,7 +235,6 @@ func New(writer io.Writer, level Level, opts ...Option) *Logger { cfg.EncoderConfig.EncodeTime = func(t time.Time, enc zapcore.PrimitiveArrayEncoder) { enc.AppendString(t.Format("2006-01-02T15:04:05.000Z0700")) } - cfg.EncoderConfig.EncodeDuration = zapcore.StringDurationEncoder core := zapcore.NewCore( zapcore.NewJSONEncoder(cfg.EncoderConfig), @@ -193,9 +248,41 @@ func New(writer io.Writer, level Level, opts ...Option) *Logger { return logger } +func NewWithConfig(cfg *Config, level string) *Logger { + if level != "" { + lvl, _ := zap.ParseAtomicLevel(level) + cfg.Zap.Level = lvl + } + + lt, _ := cfg.Zap.Build() + myCore := lt.Core() + if cfg.Filters != nil { + // concatenate items to one string + var filters string + for _, filter := range cfg.Filters { + filters += filter + " " + } + lt = zap.New(zapfilter.NewFilteringCore( + myCore, + zapfilter.MustParseRules(filters)), + ) + } + + logger := &Logger{ + l: zap.New(lt.Core(), + zap.WithCaller(!cfg.Zap.DisableCaller), + zap.AddStacktrace(zap.ErrorLevel), + AddCallerSkip(1)), + level: lt.Level(), + baseConfig: &cfg.Zap, + loggerConfigs: cfg.Loggers, + } + return logger +} + // DevLogger create a new logger for development. // -//nolint:dupl //yes, very similar to ProdLogger +//nolint:dupl //yes, very similar to New func DevLogger(writer io.Writer, level Level, opts ...Option) *Logger { if writer == nil { panic("the writer is nil") @@ -205,7 +292,6 @@ func DevLogger(writer io.Writer, level Level, opts ...Option) *Logger { cfg.EncoderConfig.EncodeTime = func(t time.Time, enc zapcore.PrimitiveArrayEncoder) { enc.AppendString(t.Format("2006-01-02T15:04:05.000")) } - cfg.EncoderConfig.EncodeDuration = zapcore.StringDurationEncoder core := zapcore.NewCore( zapcore.NewConsoleEncoder(cfg.EncoderConfig), zapcore.AddSync(writer), @@ -227,13 +313,39 @@ func (l *Logger) Sync() error { return l.l.Sync() } -func (l *Logger) ZapLogger() *zap.Logger { - return l.l -} - func Sync() error { if std != nil { return std.Sync() } return nil } + +func findBestMatch(stringsList []string, query string) string { + var bestMatch string + queryParts := strings.Split(query, ".") + + for _, s := range stringsList { + sParts := strings.Split(s, ".") + + // we can only match if the query has at least as many parts as the string + if len(sParts) <= len(queryParts) { + matches := true + for i := range sParts { + pattern := "^" + sParts[i] + "$" + matched, _ := regexp.MatchString(pattern, queryParts[i]) + if !matched { + matches = false + break + } + } + + if matches && + (bestMatch == "" || len(sParts) > len(strings.Split(bestMatch, "."))) { + + bestMatch = s + } + } + } + + return bestMatch +} diff --git a/pkg/cmd/check/check.go b/pkg/cmd/check/check.go index 1816e86..3610e8d 100644 --- a/pkg/cmd/check/check.go +++ b/pkg/cmd/check/check.go @@ -20,21 +20,23 @@ func NewVersionCheckCmd() *cobra.Command { Use: "check", Short: "check if racelogger is compatible with the backend server", Run: func(cmd *cobra.Command, args []string) { - checkCompatibility() + checkCompatibility(cmd.Context()) }, } return cmd } -func checkCompatibility() { - log.Debug("Starting...") +func checkCompatibility(ctx context.Context) { + logger := log.GetFromContext(ctx) + + logger.Debug("Starting...") var conn *grpc.ClientConn var err error if conn, err = util.ConnectGrpc(config.DefaultCliArgs()); err != nil { - log.Error("Could not connect to gRPC server", log.ErrorField(err)) + logger.Error("Could not connect to gRPC server", log.ErrorField(err)) return } @@ -42,9 +44,9 @@ func checkCompatibility() { if res, err := c.VersionCheck(context.Background(), &providerv1.VersionCheckRequest{ RaceloggerVersion: version.Version, }); err != nil { - log.Error("error checking compatibility", log.ErrorField(err)) + logger.Error("error checking compatibility", log.ErrorField(err)) } else { - log.Debug("Compatibility check successful", + logger.Debug("Compatibility check successful", log.String("this-racelogger-version", version.Version), log.String("server-version", res.ServerVersion), log.String("minimum-racelogger-version", res.SupportedRaceloggerVersion), diff --git a/pkg/cmd/record/record.go b/pkg/cmd/record/record.go index 5e65d81..bf3f052 100644 --- a/pkg/cmd/record/record.go +++ b/pkg/cmd/record/record.go @@ -29,7 +29,7 @@ func NewRecordCmd() *cobra.Command { Use: "record", Short: "record an iRacing event", RunE: func(cmd *cobra.Command, args []string) error { - return recordEvent(config.DefaultCliArgs()) + return recordEvent(cmd.Context(), config.DefaultCliArgs()) }, } @@ -91,7 +91,7 @@ func NewRecordCmd() *cobra.Command { } //nolint:funlen,gocritic,cyclop // by design -func recordEvent(cfg *config.CliArgs) error { +func recordEvent(cmdCtx context.Context, cfg *config.CliArgs) error { log.Debug("Starting...") log.Debug("Config", log.Any("cfg", cfg)) if ok := util.WaitForSimulation(cfg); !ok { @@ -129,7 +129,7 @@ func recordEvent(cfg *config.CliArgs) error { if cfg.DoNotPersist { recordingMode = providerv1.RecordingMode_RECORDING_MODE_DO_NOT_PERSIST } - ctx, cancel := context.WithCancel(context.Background()) + ctx, cancel := context.WithCancel(cmdCtx) r := internal.NewRaceLogger( internal.WithGrpcConn(conn), internal.WithContext(ctx, cancel), diff --git a/pkg/cmd/status/status.go b/pkg/cmd/status/status.go index 9586682..dbc34a6 100644 --- a/pkg/cmd/status/status.go +++ b/pkg/cmd/status/status.go @@ -30,7 +30,7 @@ func NewStatusCmd() *cobra.Command { } func checkIracingStatus() error { - if util.WaitForSimulation(config.DefaultCliArgs()) { + if !util.WaitForSimulation(config.DefaultCliArgs()) { log.Error(ErrSimulationNotRunning.Error()) return nil } diff --git a/pkg/config/config.go b/pkg/config/config.go index ea408ea..12549ce 100644 --- a/pkg/config/config.go +++ b/pkg/config/config.go @@ -1,15 +1,5 @@ package config -var ( - URL string // Deprecated: URL of WAMP server - Realm string // Deprecated: Realm for the racelog endpoints - Password string // Deprecated: Password for Dataprovider access - - LogLevel string // sets the log level (zap log level values) - LogFormat string // text vs json - -) - //nolint:lll // better readability type CliArgs struct { Addr string // ism gRPC address @@ -20,6 +10,7 @@ type CliArgs struct { TLSCa string // path to TLS CA LogLevel string // sets the log level (zap log level values) LogFormat string // text vs json + LogConfig string // path to log configuration file LogFile string // log file to write to Token string // token for authentication WaitForServices string // duration to wait for other services to be ready diff --git a/pkg/util/logger.go b/pkg/util/logger.go deleted file mode 100644 index b351441..0000000 --- a/pkg/util/logger.go +++ /dev/null @@ -1,47 +0,0 @@ -package util - -import ( - "fmt" - "os" - - "github.com/mpapenbr/go-racelogger/log" - "github.com/mpapenbr/go-racelogger/pkg/config" -) - -func SetupLogger(cfg *config.CliArgs) *log.Logger { - var logger *log.Logger - logFile := os.Stdout - var err error - if cfg.LogFile != "" { - logFile, err = os.Create(cfg.LogFile) - if err != nil { - fmt.Printf("Error creating log file: %s\nLogging to stdout", err) - logFile = os.Stdout - } - } - switch cfg.LogFormat { - case "json": - logger = log.New( - logFile, - parseLogLevel(cfg.LogLevel, log.InfoLevel), - log.WithCaller(true), - log.AddCallerSkip(1)) - default: - logger = log.DevLogger( - logFile, - parseLogLevel(cfg.LogLevel, log.DebugLevel), - log.WithCaller(true), - log.AddCallerSkip(1)) - } - - log.ResetDefault(logger) - return logger -} - -func parseLogLevel(l string, defaultVal log.Level) log.Level { - level, err := log.ParseLevel(l) - if err != nil { - return defaultVal - } - return level -} diff --git a/sample/log-dev.yml b/sample/log-dev.yml new file mode 100644 index 0000000..5671d80 --- /dev/null +++ b/sample/log-dev.yml @@ -0,0 +1,18 @@ +zap: + level: "debug" + development: true + encoding: "console" + outputPaths: + - "stdout" + errorOutputPaths: + - "stderr" + encoderConfig: + levelEncoder: "color" + stacktraceKey: "" + # callerKey: "" + timeEncoder: + layout: "15:04:05.000" + durationEncoder: "string" +loggers: + rl: debug + rl.durations: info diff --git a/sample/log-prod.yml b/sample/log-prod.yml new file mode 100644 index 0000000..12ebf55 --- /dev/null +++ b/sample/log-prod.yml @@ -0,0 +1,14 @@ +zap: + level: "info" + development: false + encoding: "json" + outputPaths: + - "stdout" + errorOutputPaths: + - "stderr" + encoderConfig: + stacktraceKey: "stacktrace" + # callerKey: "" + timeEncoder: + layout: "2006-02-01 15:04:05.000Z0700" + durationEncoder: "string" diff --git a/sample/racelogger.yml b/sample/racelogger.yml index c98097c..b0e6be9 100644 --- a/sample/racelogger.yml +++ b/sample/racelogger.yml @@ -6,8 +6,6 @@ addr: grpc.iracing-tools.de:443 # Enter the dataprovider token token: -log-level: info -log-format: json -# Enter the path to the log file. If not set, logs will be written to stdout -# Existing files will be replaced -#log-file: racelogger.log +# use this config for the logs inside the racelogger +log-config: log-prod.yml +log-file: racelogger.log