From a4aa8dafac74c55ca617fd4491f5c274d27c1b04 Mon Sep 17 00:00:00 2001 From: Julien Neuhart Date: Mon, 1 Jul 2019 17:11:23 +0200 Subject: [PATCH] WIP: refactoring logging system --- Makefile | 9 +- build/tests/docker-entrypoint.sh | 1 - cmd/gotenberg/main.go | 162 +++++++++---------------------- go.mod | 4 +- go.sum | 11 ++- internal/app/api/api.go | 45 +++------ internal/app/api/handler.go | 36 ++++--- internal/app/api/middleware.go | 112 +++++++++++---------- internal/app/api/resource.go | 61 +++++------- internal/pkg/notify/doc.go | 5 - internal/pkg/notify/notify.go | 35 ------- internal/pkg/pm2/chrome.go | 14 +-- internal/pkg/pm2/pm2.go | 59 +++++------ internal/pkg/pm2/unoconv.go | 8 +- internal/pkg/printer/markdown.go | 7 +- internal/pkg/printer/office.go | 7 +- internal/pkg/rand/doc.go | 7 -- internal/pkg/rand/rand.go | 17 ---- internal/pkg/rand/rand_test.go | 16 --- 19 files changed, 225 insertions(+), 391 deletions(-) delete mode 100644 internal/pkg/notify/doc.go delete mode 100644 internal/pkg/notify/notify.go delete mode 100644 internal/pkg/rand/doc.go delete mode 100644 internal/pkg/rand/rand.go delete mode 100644 internal/pkg/rand/rand_test.go diff --git a/Makefile b/Makefile index 0af767b0..0651d971 100644 --- a/Makefile +++ b/Makefile @@ -3,6 +3,11 @@ VERSION=snapshot DOCKER_USER= DOCKER_PASSWORD= DOCKER_REPOSITORY=thecodingmachine +DEFAULT_WAIT_TIMEOUT=10 +DEFAULT_LISTEN_PORT=3000 +DISABLE_GOOGLE_CHROME=0 +DISABLE_UNOCONV=0 +LOG_LEVEL=INFO # generate documentation. doc: @@ -28,11 +33,11 @@ tests: # build Docker image. image: docker build -t $(DOCKER_REPOSITORY)/gotenberg:base -f build/base/Dockerfile . - docker build --build-arg GOLANG_VERSION=$(GOLANG_VERSION) --build-arg VERSION=$(VERSION) -t $(DOCKER_REPO)/gotenberg:$(VERSION) -f build/package/Dockerfile . + docker build --build-arg GOLANG_VERSION=$(GOLANG_VERSION) --build-arg VERSION=$(VERSION) -t $(DOCKER_REPOSITORY)/gotenberg:$(VERSION) -f build/package/Dockerfile . # start the API using previously built Docker image. gotenberg: - docker run -it --rm -e DEBUG_PROCESS_STARTUP=1 -p "3000:3000" $(DOCKER_REPOSITORY)/gotenberg:$(VERSION) + docker run -it --rm -e DEFAULT_WAIT_TIMEOUT=$(DEFAULT_WAIT_TIMEOUT) -e DEFAULT_LISTEN_PORT=$(DEFAULT_LISTEN_PORT) -e DISABLE_GOOGLE_CHROME=$(DISABLE_GOOGLE_CHROME) -e DISABLE_UNOCONV=$(DISABLE_UNOCONV) -e LOG_LEVEL=$(LOG_LEVEL) -p "3000:$(DEFAULT_LISTEN_PORT)" $(DOCKER_REPOSITORY)/gotenberg:$(VERSION) # publish Gotenberg images according to version. publish: diff --git a/build/tests/docker-entrypoint.sh b/build/tests/docker-entrypoint.sh index fa2f311a..91cc7d79 100755 --- a/build/tests/docker-entrypoint.sh +++ b/build/tests/docker-entrypoint.sh @@ -10,7 +10,6 @@ go test github.com/thecodingmachine/gotenberg/internal/pkg/pm2 -run TestUnoconvS # Running others tests. go test -race -cover -covermode=atomic github.com/thecodingmachine/gotenberg/internal/app/api -go test -race -cover -covermode=atomic github.com/thecodingmachine/gotenberg/internal/pkg/rand # Finally testing processes shutdown. go test github.com/thecodingmachine/gotenberg/internal/pkg/pm2 -run TestChromeShutdown diff --git a/cmd/gotenberg/main.go b/cmd/gotenberg/main.go index 9d6a3088..c3382512 100644 --- a/cmd/gotenberg/main.go +++ b/cmd/gotenberg/main.go @@ -6,12 +6,11 @@ import ( "net/http" "os" "os/signal" - "strconv" "time" - "github.com/labstack/echo/v4" "github.com/thecodingmachine/gotenberg/internal/app/api" - "github.com/thecodingmachine/gotenberg/internal/pkg/notify" + conf "github.com/thecodingmachine/gotenberg/internal/pkg/config" + log "github.com/thecodingmachine/gotenberg/internal/pkg/logger" "github.com/thecodingmachine/gotenberg/internal/pkg/pm2" ) @@ -19,116 +18,37 @@ import ( // nolint: gochecknoglobals var version = "snapshot" -const ( - defaultWaitTimeoutEnvVar = "DEFAULT_WAIT_TIMEOUT" - defaultListenPortEnvVar = "DEFAULT_LISTEN_PORT" - disableGoogleChromeEnvVar = "DISABLE_GOOGLE_CHROME" - disableUnoconvEnvVar = "DISABLE_UNOCONV" - disableHealthcheckLoggingEnvVar = "DISABLE_HEALTHCHECK_LOGGING" - debugProcessStartup = "DEBUG_PROCESS_STARTUP" -) - -func mustParseEnvVar() *api.Options { - opts := api.DefaultOptions() - if os.Getenv(defaultWaitTimeoutEnvVar) != "" { - defaultWaitTimeout, err := strconv.ParseFloat(os.Getenv(defaultWaitTimeoutEnvVar), 64) - if err != nil { - notify.ErrPrint(fmt.Errorf("%s: wrong value: want float got %v", defaultWaitTimeoutEnvVar, err)) - os.Exit(1) - } - opts.DefaultWaitTimeout = defaultWaitTimeout - } - if v, ok := os.LookupEnv(defaultListenPortEnvVar); ok { - defaultListener, err := strconv.ParseUint(os.Getenv(defaultListenPortEnvVar), 10, 64) - if err != nil { - notify.ErrPrint(fmt.Errorf("%s: wrong value: want uint got %v", defaultListenPortEnvVar, err)) - os.Exit(1) - } - if defaultListener > 65535 { - notify.ErrPrint(fmt.Errorf("%s: wrong value: want uint < 65535 got %v", defaultListenPortEnvVar, defaultListener)) - os.Exit(1) - } - opts.DefaultListenPort = v - } - // checkBoolEnv is a convenience function for reading - // an env var with a bool value where - // `1` is true and `0` is false. - checkBoolEnv := func(name string) bool { - if v, ok := os.LookupEnv(name); ok { - if v != "1" && v != "0" { - notify.ErrPrint(fmt.Errorf("%s: wrong value: want \"0\" or \"1\" got %v", name, v)) - os.Exit(1) - } - return v == "1" - } - return false - } - opts.EnableChromeEndpoints = !checkBoolEnv(disableGoogleChromeEnvVar) - opts.EnableUnoconvEndpoints = !checkBoolEnv(disableUnoconvEnvVar) - opts.EnableHealthcheckLogging = !checkBoolEnv(disableHealthcheckLoggingEnvVar) - opts.DebugProcessStartup = checkBoolEnv(debugProcessStartup) - return opts -} - -func mustStartProcesses(opts *api.Options) []pm2.Process { - var processes []pm2.Process - if opts.EnableChromeEndpoints { - processes = append(processes, pm2.NewChrome(opts.DebugProcessStartup)) - } - if opts.EnableUnoconvEndpoints { - processes = append(processes, pm2.NewUnoconv(opts.DebugProcessStartup)) - } - for _, p := range processes { - notify.Printf("starting %s with PM2...", p.Fullname()) - if err := p.Start(); err != nil { - notify.ErrPrint(err) - os.Exit(1) - } - } - return processes -} - -func mustStartAPI(srv *echo.Echo, port string) { - notify.Printf("http server started on port %v", port) - if err := srv.Start(fmt.Sprintf(":%v", port)); err != nil { - if err != http.ErrServerClosed { - notify.ErrPrint(err) - os.Exit(1) - } - } -} - -func mustShutdownProcesses(processes []pm2.Process) { - for _, p := range processes { - notify.Printf("shutting down %s with PM2... (Ctrl+C to force)", p.Fullname()) - if err := p.Shutdown(); err != nil { - notify.ErrPrint(err) - os.Exit(1) - } - } -} - -func mustShutdownAPI(srv *echo.Echo) { - // create a deadline to wait for. - ctx, cancel := context.WithTimeout(context.Background(), 120*time.Second) - defer cancel() - // doesn't block if no connections, but will otherwise wait - // until the timeout deadline. - notify.Print("shutting down http server... (Ctrl+C to force)") - if err := srv.Shutdown(ctx); err != nil { - notify.ErrPrint(err) - os.Exit(1) - } -} - func main() { - notify.Printf("Gotenberg %s", version) - opts := mustParseEnvVar() - srv := api.New(opts) - processes := mustStartProcesses(opts) - // run our API in a goroutine so that it doesn't block.s + config, err := conf.FromEnv() + systemLogger := log.New(config.LogLevel(), "system") + if err != nil { + systemLogger.Fatal(err) + } + systemLogger.Infof("Gotenberg %s", version) + // start PM2 processes. + var processes []pm2.Process + if config.EnableChromeEndpoints() { + processes = append(processes, pm2.NewChrome(systemLogger)) + } + if config.EnableUnoconvEndpoints() { + processes = append(processes, pm2.NewUnoconv(systemLogger)) + } + for _, p := range processes { + systemLogger.Infof("starting %s with PM2...", p.Fullname()) + if err := p.Start(); err != nil { + systemLogger.Fatal(err) + } + } + // run our API in a goroutine so that it doesn't block. + // create our API. + srv := api.New(config) go func() { - mustStartAPI(srv, opts.DefaultListenPort) + systemLogger.Infof("http server started on port %s", config.DefaultListenPort()) + if err := srv.Start(fmt.Sprintf(":%s", config.DefaultListenPort())); err != nil { + if err != http.ErrServerClosed { + systemLogger.Fatal(err) + } + } }() quit := make(chan os.Signal, 1) // we'll accept graceful shutdowns when quit via SIGINT (Ctrl+C) @@ -136,8 +56,22 @@ func main() { signal.Notify(quit, os.Interrupt) // block until we receive our signal. <-quit - mustShutdownAPI(srv) - mustShutdownProcesses(processes) - notify.Print("bye!") + // create a deadline to wait for. + ctx, cancel := context.WithTimeout(context.Background(), 120*time.Second) + defer cancel() + // doesn't block if no connections, but will otherwise wait + // until the timeout deadline. + systemLogger.Info("shutting down http server...") + if err := srv.Shutdown(ctx); err != nil { + systemLogger.Fatal(err) + } + // shutdown PM2 processes. + for _, p := range processes { + systemLogger.Infof("shutting down %s with PM2...", p.Fullname()) + if err := p.Shutdown(); err != nil { + systemLogger.Fatal(err) + } + } + systemLogger.Info("bye!") os.Exit(0) } diff --git a/go.mod b/go.mod index d67246a6..85ced362 100644 --- a/go.mod +++ b/go.mod @@ -3,7 +3,6 @@ module github.com/thecodingmachine/gotenberg go 1.12 require ( - github.com/davecgh/go-spew v1.1.1 // indirect github.com/google/go-cmp v0.2.0 // indirect github.com/gorilla/websocket v1.4.0 // indirect github.com/labstack/echo/v4 v4.0.0 @@ -14,10 +13,11 @@ require ( github.com/microcosm-cc/bluemonday v1.0.1 github.com/russross/blackfriday/v2 v2.0.1 github.com/shurcooL/sanitized_anchor_name v0.0.0-20170918181015-86672fcb3f95 // indirect + github.com/sirupsen/logrus v1.4.2 github.com/stretchr/testify v1.3.0 github.com/valyala/fasttemplate v1.0.1 // indirect golang.org/x/crypto v0.0.0-20190325154230-a5d413f7728c // indirect golang.org/x/net v0.0.0-20181201002055-351d144fa1fc // indirect golang.org/x/sync v0.0.0-20181108010431-42b317875d0f - golang.org/x/sys v0.0.0-20190322080309-f49334f85ddc // indirect + golang.org/x/sys v0.0.0-20190621062556-bf70e4678053 // indirect ) diff --git a/go.sum b/go.sum index 2e6eae15..32ff4bc2 100644 --- a/go.sum +++ b/go.sum @@ -7,6 +7,8 @@ github.com/google/go-cmp v0.2.0 h1:+dTQ8DZQJz0Mb/HjFlkptS1FeQ4cWSnN941F8aEG4SQ= github.com/google/go-cmp v0.2.0/go.mod h1:oXzfMopK8JAjlY9xF4vHSVASa0yLyX7SntLO5aqRK0M= github.com/gorilla/websocket v1.4.0 h1:WDFjx/TMzVgy9VdMMQi2K2Emtwi2QcUQsztZ/zLaH/Q= github.com/gorilla/websocket v1.4.0/go.mod h1:E7qHFY5m1UJ88s3WnNqhKjPHQ0heANvMoAMk2YaljkQ= +github.com/konsorten/go-windows-terminal-sequences v1.0.1 h1:mweAR1A6xJ3oS2pRaGiHgQ4OO8tzTaLawm8vnODuwDk= +github.com/konsorten/go-windows-terminal-sequences v1.0.1/go.mod h1:T0+1ngSBFLxvqU3pZ+m/2kptfBszLMUkC4ZK/EgS/cQ= github.com/labstack/echo/v4 v4.0.0 h1:q1GH+caIXPP7H2StPIdzy/ez9CO0EepqYeUg6vi9SWM= github.com/labstack/echo/v4 v4.0.0/go.mod h1:tZv7nai5buKSg5h/8E6zz4LsD/Dqh9/91Mvs7Z5Zyno= github.com/labstack/gommon v0.2.8 h1:JvRqmeZcfrHC5u6uVleB4NxxNbzx6gpbJiQknDbKQu0= @@ -30,7 +32,11 @@ github.com/russross/blackfriday/v2 v2.0.1 h1:lPqVAte+HuHNfhJ/0LC98ESWRz8afy9tM/0 github.com/russross/blackfriday/v2 v2.0.1/go.mod h1:+Rmxgy9KzJVeS9/2gXHxylqXiyQDYRxCVz55jmeOWTM= github.com/shurcooL/sanitized_anchor_name v0.0.0-20170918181015-86672fcb3f95 h1:/vdW8Cb7EXrkqWGufVMES1OH2sU9gKVb2n9/1y5NMBY= github.com/shurcooL/sanitized_anchor_name v0.0.0-20170918181015-86672fcb3f95/go.mod h1:1NzhyTcUVG4SuEtjjoZeVRXNmyL/1OwPU0+IJeTBvfc= +github.com/sirupsen/logrus v1.4.2 h1:SPIRibHv4MatM3XXNO2BJeFLZwZ2LvZgfQ5+UNI2im4= +github.com/sirupsen/logrus v1.4.2/go.mod h1:tLMulIdttU9McNUspp0xgXVQah82FyeX6MwdIuYE2rE= github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= +github.com/stretchr/objx v0.1.1/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= +github.com/stretchr/testify v1.2.2/go.mod h1:a8OnRcib4nhh0OaRAV+Yts87kKdq0PP7pXfy6kDkUVs= github.com/stretchr/testify v1.3.0 h1:TivCn/peBQ7UY8ooIcPgZFpTNSz0Q2U6UrFlUfqbe0Q= github.com/stretchr/testify v1.3.0/go.mod h1:M5WIy9Dh21IEIfnGCwXGc5bZfKNJtfHm1UVUgZn+9EI= github.com/valyala/bytebufferpool v1.0.0 h1:GqA5TC/0021Y/b9FG4Oi9Mr3q7XYx6KllzawFIhcdPw= @@ -49,5 +55,6 @@ golang.org/x/sync v0.0.0-20181108010431-42b317875d0f/go.mod h1:RxMgew5VJxzue5/jJ golang.org/x/sys v0.0.0-20190129075346-302c3dd5f1cc/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= golang.org/x/sys v0.0.0-20190215142949-d0b11bdaac8a/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= golang.org/x/sys v0.0.0-20190222072716-a9d3bda3a223/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= -golang.org/x/sys v0.0.0-20190322080309-f49334f85ddc h1:4gbWbmmPFp4ySWICouJl6emP0MyS31yy9SrTlAGFT+g= -golang.org/x/sys v0.0.0-20190322080309-f49334f85ddc/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= +golang.org/x/sys v0.0.0-20190422165155-953cdadca894/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= +golang.org/x/sys v0.0.0-20190621062556-bf70e4678053 h1:T0MJjz97TtCXa3ZNW2Oenb3KQWB91K965zMEbIJ4ThA= +golang.org/x/sys v0.0.0-20190621062556-bf70e4678053/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= diff --git a/internal/app/api/api.go b/internal/app/api/api.go index d00e01eb..23db1d6f 100644 --- a/internal/app/api/api.go +++ b/internal/app/api/api.go @@ -1,51 +1,32 @@ package api -import "github.com/labstack/echo/v4" +import ( + "github.com/labstack/echo/v4" + conf "github.com/thecodingmachine/gotenberg/internal/pkg/config" +) const pingEndpoint = "/ping" -// Options allows to customize the behaviour -// of the API. -type Options struct { - DefaultWaitTimeout float64 - DefaultListenPort string - EnableChromeEndpoints bool - EnableUnoconvEndpoints bool - EnableHealthcheckLogging bool - DebugProcessStartup bool -} - -// DefaultOptions returns default options. -func DefaultOptions() *Options { - return &Options{ - DefaultWaitTimeout: 10, - DefaultListenPort: "3000", - EnableChromeEndpoints: true, - EnableUnoconvEndpoints: true, - EnableHealthcheckLogging: true, - } -} - // New returns an API. -func New(opts *Options) *echo.Echo { +func New(config *conf.Config) *echo.Echo { api := echo.New() api.HideBanner = true api.HidePort = true - api.Use(handleLogging(opts.EnableHealthcheckLogging)) + api.Use(contextMiddleware(config)) + api.Use(loggingMiddleware()) + api.Use(finalizeMiddleware()) api.GET(pingEndpoint, func(c echo.Context) error { return nil }) - g := api.Group("/convert") - g.Use(handleContext(opts)) - g.Use(handleError()) - g.POST("/merge", merge) - if !opts.EnableChromeEndpoints && !opts.EnableUnoconvEndpoints { + api.POST("/merge", merge) + if !config.EnableChromeEndpoints() && !config.EnableUnoconvEndpoints() { return api } - if opts.EnableChromeEndpoints { + g := api.Group("/convert") + if config.EnableChromeEndpoints() { g.POST("/html", convertHTML) g.POST("/url", convertURL) g.POST("/markdown", convertMarkdown) } - if opts.EnableUnoconvEndpoints { + if config.EnableUnoconvEndpoints() { g.POST("/office", convertOffice) } return api diff --git a/internal/app/api/handler.go b/internal/app/api/handler.go index f350e452..69e97763 100644 --- a/internal/app/api/handler.go +++ b/internal/app/api/handler.go @@ -6,8 +6,8 @@ import ( "os" "github.com/labstack/echo/v4" + "github.com/labstack/gommon/random" "github.com/thecodingmachine/gotenberg/internal/pkg/printer" - "github.com/thecodingmachine/gotenberg/internal/pkg/rand" ) type errBadRequest struct { @@ -20,7 +20,7 @@ func (e *errBadRequest) Error() string { func merge(c echo.Context) error { ctx := c.(*resourceContext) - opts, err := ctx.resource.mergePrinterOptions() + opts, err := ctx.resource.mergePrinterOptions(ctx.config.DefaultWaitTimeout()) if err != nil { return &errBadRequest{err} } @@ -34,7 +34,7 @@ func merge(c echo.Context) error { func convertHTML(c echo.Context) error { ctx := c.(*resourceContext) - opts, err := ctx.resource.chromePrinterOptions() + opts, err := ctx.resource.chromePrinterOptions(ctx.config.DefaultWaitTimeout()) if err != nil { return &errBadRequest{err} } @@ -48,7 +48,7 @@ func convertHTML(c echo.Context) error { func convertMarkdown(c echo.Context) error { ctx := c.(*resourceContext) - opts, err := ctx.resource.chromePrinterOptions() + opts, err := ctx.resource.chromePrinterOptions(ctx.config.DefaultWaitTimeout()) if err != nil { return &errBadRequest{err} } @@ -65,7 +65,7 @@ func convertMarkdown(c echo.Context) error { func convertURL(c echo.Context) error { ctx := c.(*resourceContext) - opts, err := ctx.resource.chromePrinterOptions() + opts, err := ctx.resource.chromePrinterOptions(ctx.config.DefaultWaitTimeout()) if err != nil { return &errBadRequest{err} } @@ -79,7 +79,7 @@ func convertURL(c echo.Context) error { func convertOffice(c echo.Context) error { ctx := c.(*resourceContext) - opts, err := ctx.resource.officePrinterOptions() + opts, err := ctx.resource.officePrinterOptions(ctx.config.DefaultWaitTimeout()) if err != nil { return &errBadRequest{err} } @@ -105,10 +105,7 @@ func convertOffice(c echo.Context) error { } func convert(ctx *resourceContext, p printer.Printer) error { - baseFilename, err := rand.Get() - if err != nil { - return err - } + baseFilename := random.String(32) filename := fmt.Sprintf("%s.pdf", baseFilename) fpath := fmt.Sprintf("%s/%s", ctx.resource.formFilesDirPath, filename) // if no webhook URL given, run conversion @@ -118,11 +115,12 @@ func convert(ctx *resourceContext, p printer.Printer) error { if err := p.Print(fpath); err != nil { return err } - if ctx.resource.has(resultFilename) { - filename, err = ctx.resource.get(resultFilename) - if err != nil { - return &errBadRequest{err} - } + if !ctx.resource.has(resultFilename) { + return ctx.Attachment(fpath, filename) + } + filename, err := ctx.resource.get(resultFilename) + if err != nil { + return &errBadRequest{err} } return ctx.Attachment(fpath, filename) } @@ -132,23 +130,23 @@ func convert(ctx *resourceContext, p printer.Printer) error { go func() { defer ctx.resource.close() // nolint: errcheck if err := p.Print(fpath); err != nil { - ctx.Logger().Error(err) + ctx.logger.Error(err) return } f, err := os.Open(fpath) if err != nil { - ctx.Logger().Error(err) + ctx.logger.Error(err) return } defer f.Close() // nolint: errcheck webhook, err := ctx.resource.get(webhookURL) if err != nil { - ctx.Logger().Error(err) + ctx.logger.Error(err) return } resp, err := http.Post(webhook, "application/pdf", f) /* #nosec */ if err != nil { - ctx.Logger().Error(err) + ctx.logger.Error(err) return } defer resp.Body.Close() // nolint: errcheck diff --git a/internal/app/api/middleware.go b/internal/app/api/middleware.go index a3329f6d..1cb35b97 100644 --- a/internal/app/api/middleware.go +++ b/internal/app/api/middleware.go @@ -6,70 +6,84 @@ import ( "strings" "github.com/labstack/echo/v4" - "github.com/labstack/echo/v4/middleware" + "github.com/labstack/gommon/random" + conf "github.com/thecodingmachine/gotenberg/internal/pkg/config" + log "github.com/thecodingmachine/gotenberg/internal/pkg/logger" ) -func handleLogging(enableHealthcheckLogging bool) echo.MiddlewareFunc { - if enableHealthcheckLogging { - // default logging middleware. - return middleware.Logger() - } - // middleware for skipping logging when the ping endpoint is called. - return middleware.LoggerWithConfig(middleware.LoggerConfig{ - Skipper: func(c echo.Context) bool { - return c.Request().URL.Path == pingEndpoint - }, - }) -} - -func handleContext(opts *Options) echo.MiddlewareFunc { - // middleware for extending default context with our - // custom constext. +func contextMiddleware(config *conf.Config) echo.MiddlewareFunc { + // middleware for extending the default context + // with one of our own context. return func(next echo.HandlerFunc) echo.HandlerFunc { return func(c echo.Context) error { - ctx := &resourceContext{c, opts, nil} - r, err := newResource(ctx) - if err != nil { - if resourceErr := r.close(); resourceErr != nil { - c.Logger().Error(resourceErr) + // generate a unique identifier for our request. + trace := random.String(32) + // create the logger for this request using + // the previous identifier as trace. + logger := log.New(config.LogLevel(), trace) + // extend the current echo context with our standard + // context. + ctx := newStandardContext(c, logger, config) + // if the endpoint is not for liveness, make a + // context with resource. + if ctx.Path() != pingEndpoint { + ctx, err := ctx.withResource(trace) + if err != nil { + ctx.Error(err) + return ctx.logEndOfRequest(err) } - return err } - ctx.resource = r return next(ctx) } } } -func handleError() echo.MiddlewareFunc { - // middleware for handling errors and removing resources - // once the request has been handled. +func loggingMiddleware() echo.MiddlewareFunc { + // middleware for enabling logging. return func(next echo.HandlerFunc) echo.HandlerFunc { return func(c echo.Context) error { - err := next(c) - ctx := c.(*resourceContext) - // if a webhookURL has been given, - // do not remove the resources here because - // we don't know if the result file has been - // generated or sent. - if !ctx.resource.has(webhookURL) { - if resourceErr := ctx.resource.close(); resourceErr != nil { - c.Logger().Error(resourceErr) - } - } + ctx := c.(*standardContext) + err := next(ctx) if err != nil { - if _, ok := err.(*echo.HTTPError); ok { - return err - } - if _, ok := err.(*errBadRequest); ok { - return echo.NewHTTPError(http.StatusBadRequest, err.Error()) - } - if strings.Contains(err.Error(), context.DeadlineExceeded.Error()) { - return echo.NewHTTPError(http.StatusRequestTimeout) - } - return echo.NewHTTPError(http.StatusInternalServerError, err.Error()) + ctx.Error(err) } - return nil + return ctx.logEndOfRequest(err) + } + } +} + +func finalizeMiddleware() echo.MiddlewareFunc { + // middleware for removing resources at the end of a request + // and for improving response in case of error. + return func(next echo.HandlerFunc) echo.HandlerFunc { + return func(c echo.Context) error { + err := next(c) + ctx, ok := c.(*resourceContext) + // a resource is associated with the context. + if ok { + // if a webhookURL has been given, + // do not remove the resources here because + // we don't know if the result file has been + // generated or sent. + if !ctx.resource.has(webhookURL) { + if resourceErr := ctx.resource.close(); resourceErr != nil { + ctx.logger.Error(err) + } + } + } + if err == nil { + return nil + } + if _, ok := err.(*echo.HTTPError); ok { + return err + } + if _, ok := err.(*errBadRequest); ok { + return echo.NewHTTPError(http.StatusBadRequest, err.Error()) + } + if strings.Contains(err.Error(), context.DeadlineExceeded.Error()) { + return echo.NewHTTPError(http.StatusRequestTimeout, err.Error()) + } + return echo.NewHTTPError(http.StatusInternalServerError, err.Error()) } } } diff --git a/internal/app/api/resource.go b/internal/app/api/resource.go index 6648466d..5a359cee 100644 --- a/internal/app/api/resource.go +++ b/internal/app/api/resource.go @@ -10,7 +10,6 @@ import ( "github.com/labstack/echo/v4" "github.com/thecodingmachine/gotenberg/internal/pkg/printer" - "github.com/thecodingmachine/gotenberg/internal/pkg/rand" ) const ( @@ -31,53 +30,41 @@ const ( type resource struct { formValues map[string]string formFilesDirPath string - opts *Options } -type resourceContext struct { - echo.Context - opts *Options - resource *resource -} - -func newResource(ctx *resourceContext) (*resource, error) { +func newResource(c echo.Context, dirPath string) (*resource, error) { r := &resource{ - formValues: formValues(ctx), - opts: ctx.opts, - } - dirPath, err := rand.Get() - if err != nil { - return r, err + formValues: formValues(c), } r.formFilesDirPath = dirPath if err := os.MkdirAll(dirPath, 0755); err != nil { return nil, fmt.Errorf("%s: making directory: %v", dirPath, err) } - if err := formFiles(ctx, dirPath); err != nil { + if err := formFiles(c, dirPath); err != nil { return r, err } return r, nil } -func formValues(ctx *resourceContext) map[string]string { +func formValues(c echo.Context) map[string]string { v := make(map[string]string) - v[resultFilename] = ctx.FormValue(resultFilename) - v[waitTimeout] = ctx.FormValue(waitTimeout) - v[webhookURL] = ctx.FormValue(webhookURL) - v[remoteURL] = ctx.FormValue(remoteURL) - v[waitDelay] = ctx.FormValue(waitDelay) - v[paperWidth] = ctx.FormValue(paperWidth) - v[paperHeight] = ctx.FormValue(paperHeight) - v[marginTop] = ctx.FormValue(marginTop) - v[marginBottom] = ctx.FormValue(marginBottom) - v[marginLeft] = ctx.FormValue(marginLeft) - v[marginRight] = ctx.FormValue(marginRight) - v[landscape] = ctx.FormValue(landscape) + v[resultFilename] = c.FormValue(resultFilename) + v[waitTimeout] = c.FormValue(waitTimeout) + v[webhookURL] = c.FormValue(webhookURL) + v[remoteURL] = c.FormValue(remoteURL) + v[waitDelay] = c.FormValue(waitDelay) + v[paperWidth] = c.FormValue(paperWidth) + v[paperHeight] = c.FormValue(paperHeight) + v[marginTop] = c.FormValue(marginTop) + v[marginBottom] = c.FormValue(marginBottom) + v[marginLeft] = c.FormValue(marginLeft) + v[marginRight] = c.FormValue(marginRight) + v[landscape] = c.FormValue(landscape) return v } -func formFiles(ctx *resourceContext, dirPath string) error { - form, err := ctx.MultipartForm() +func formFiles(c echo.Context, dirPath string) error { + form, err := c.MultipartForm() if err != nil { return fmt.Errorf("getting multipart form: %v", err) } @@ -117,8 +104,8 @@ func (r *resource) close() error { const defaultHeaderFooterHTML string = "" -func (r *resource) chromePrinterOptions() (*printer.ChromeOptions, error) { - timeout, err := r.float64(waitTimeout, r.opts.DefaultWaitTimeout) +func (r *resource) chromePrinterOptions(defaultWaitTimeout float64) (*printer.ChromeOptions, error) { + timeout, err := r.float64(waitTimeout, defaultWaitTimeout) if err != nil { return nil, err } @@ -177,8 +164,8 @@ func (r *resource) chromePrinterOptions() (*printer.ChromeOptions, error) { }, nil } -func (r *resource) officePrinterOptions() (*printer.OfficeOptions, error) { - timeout, err := r.float64(waitTimeout, r.opts.DefaultWaitTimeout) +func (r *resource) officePrinterOptions(defaultWaitTimeout float64) (*printer.OfficeOptions, error) { + timeout, err := r.float64(waitTimeout, defaultWaitTimeout) if err != nil { return nil, err } @@ -192,8 +179,8 @@ func (r *resource) officePrinterOptions() (*printer.OfficeOptions, error) { }, nil } -func (r *resource) mergePrinterOptions() (*printer.MergeOptions, error) { - timeout, err := r.float64(waitTimeout, r.opts.DefaultWaitTimeout) +func (r *resource) mergePrinterOptions(defaultWaitTimeout float64) (*printer.MergeOptions, error) { + timeout, err := r.float64(waitTimeout, defaultWaitTimeout) if err != nil { return nil, err } diff --git a/internal/pkg/notify/doc.go b/internal/pkg/notify/doc.go deleted file mode 100644 index d60f45c6..00000000 --- a/internal/pkg/notify/doc.go +++ /dev/null @@ -1,5 +0,0 @@ -/* -Package notify helps displaying nice outputs -to the user. -*/ -package notify diff --git a/internal/pkg/notify/notify.go b/internal/pkg/notify/notify.go deleted file mode 100644 index 6690e2cc..00000000 --- a/internal/pkg/notify/notify.go +++ /dev/null @@ -1,35 +0,0 @@ -package notify - -import ( - "fmt" - "os" - - "github.com/labstack/gommon/color" -) - -// Print prints a message to stdout. -func Print(message string) { - stdout := color.New() - stdout.SetOutput(os.Stdout) - stdout.Printf("⇨ %s\n", message) -} - -// Printf prints a formatted message to stdout. -func Printf(format string, a ...interface{}) { - message := fmt.Sprintf(format, a...) - Print(message) -} - -// WarnPrint prints a warning to stderr. -func WarnPrint(err error) { - stderr := color.New() - stderr.SetOutput(os.Stderr) - stderr.Printf("%s\n", color.Yellow(fmt.Sprintf("⇨ warn: %v", err))) -} - -// ErrPrint prints an error to stderr. -func ErrPrint(err error) { - stderr := color.New() - stderr.SetOutput(os.Stderr) - stderr.Printf("%s\n", color.Red(fmt.Sprintf("⇨ error: %v", err))) -} diff --git a/internal/pkg/pm2/chrome.go b/internal/pkg/pm2/chrome.go index bad71c3e..aa04d4f1 100644 --- a/internal/pkg/pm2/chrome.go +++ b/internal/pkg/pm2/chrome.go @@ -5,6 +5,7 @@ import ( "time" "github.com/mafredri/cdp/devtool" + log "github.com/thecodingmachine/gotenberg/internal/pkg/logger" ) const warmupTime = 10 * time.Second @@ -15,9 +16,9 @@ type chrome struct { // NewChrome returns a Google Chrome // headless process. -func NewChrome(debug bool) Process { +func NewChrome(logger *log.StandardLogger) Process { return &chrome{ - manager: &processManager{verbose: debug}, + manager: &processManager{logger: logger}, } } @@ -60,19 +61,18 @@ func (p *chrome) viable() bool { // check if Google Chrome is correctly running. ctx, cancel := context.WithCancel(context.Background()) defer cancel() - p.manager.notifyf(`%v: checking Chrome liveness via debug version endpoint -'http://localhost:9222/json/version'`, p.name()) + p.manager.logger.Debugf("%s: checking liveness via debug version endpoint http://localhost:9222/json/version", p.Fullname()) v, err := devtool.New("http://localhost:9222").Version(ctx) if err != nil { - p.manager.notifyf("%s: %s version endpoint returned error: %v", p.name(), p.Fullname(), err) + p.manager.logger.Debugf("%s: debug version endpoint returned error: %v", p.Fullname(), err) return false } - p.manager.notifyf("%s: %s returned version info: %+v", p.name(), p.Fullname(), *v) + p.manager.logger.Debugf("%s: debug version endpoint returned version info: %+v", p.Fullname(), *v) return true } func (p *chrome) warmup() { - p.manager.notifyf("%s: allowing %s %v to startup", p.name(), p.Fullname(), warmupTime) + p.manager.logger.Debugf("%s: allowing %v to startup", p.Fullname(), warmupTime) time.Sleep(warmupTime) } diff --git a/internal/pkg/pm2/pm2.go b/internal/pkg/pm2/pm2.go index fe2498d6..2850c9ac 100644 --- a/internal/pkg/pm2/pm2.go +++ b/internal/pkg/pm2/pm2.go @@ -6,9 +6,8 @@ import ( "io" "os/exec" "strings" - "time" - "github.com/thecodingmachine/gotenberg/internal/pkg/notify" + log "github.com/thecodingmachine/gotenberg/internal/pkg/logger" ) const ( @@ -31,7 +30,7 @@ type Process interface { type processManager struct { heuristicState int32 - verbose bool + logger *log.StandardLogger } func (m *processManager) start(p Process) error { @@ -83,43 +82,35 @@ func (m *processManager) pm2(p Process, cmdName string) error { "pm2", cmdArgs..., ) - m.notifyf("executing command '%v'", strings.Join(cmd.Args, " ")) - if m.verbose { - processStdErr, err := cmd.StderrPipe() - if err != nil { - return fmt.Errorf("failed getting stderr from %s: %s", p.Fullname(), err) - } - processStdOut, err := cmd.StdoutPipe() - if err != nil { - return fmt.Errorf("failed getting stdout from %s: %s", p.Fullname(), err) - } - readFromPipe := func(name string, reader io.ReadCloser) { - r := bufio.NewReader(reader) - defer reader.Close() // nolint: errcheck - for { - line, _, err := r.ReadLine() - if err != nil { - if err != io.EOF { - m.notifyf("error reading from %s for process %s", name, p.Fullname()) - } - break - } - if len(line) != 0 { - m.notifyf("%s %s: %s", p.name(), name, string(line)) + m.logger.Debugf("executing command: %v", strings.Join(cmd.Args, " ")) + processStdOut, err := cmd.StdoutPipe() + if err != nil { + return fmt.Errorf("failed getting stdout from %s: %s", p.Fullname(), err) + } + processStdErr, err := cmd.StderrPipe() + if err != nil { + return fmt.Errorf("failed getting stderr from %s: %s", p.Fullname(), err) + } + readFromPipe := func(outputType string, reader io.ReadCloser) { + r := bufio.NewReader(reader) + defer reader.Close() // nolint: errcheck + for { + line, _, err := r.ReadLine() + if err != nil { + if err != io.EOF { + m.logger.Errorf("error reading from %s for process %s", outputType, p.Fullname()) } + break + } + if len(line) != 0 { + m.logger.Debugf("%s %s: %s", p.Fullname(), outputType, string(line)) } } - go readFromPipe("stdout", processStdOut) - go readFromPipe("stderr", processStdErr) } + go readFromPipe("stdout", processStdOut) + go readFromPipe("stderr", processStdErr) if err := cmd.Start(); err != nil { return fmt.Errorf("%s %s with PM2: %v", cmdName, p.Fullname(), err) } return nil } - -func (m *processManager) notifyf(format string, args ...interface{}) { - if m.verbose { - notify.Printf(fmt.Sprintf("%v: %s", time.Now().Format(time.RFC3339), format), args...) - } -} diff --git a/internal/pkg/pm2/unoconv.go b/internal/pkg/pm2/unoconv.go index e7274f69..9350ab26 100644 --- a/internal/pkg/pm2/unoconv.go +++ b/internal/pkg/pm2/unoconv.go @@ -1,14 +1,18 @@ package pm2 +import ( + log "github.com/thecodingmachine/gotenberg/internal/pkg/logger" +) + type unoconv struct { manager *processManager } // NewUnoconv returns a unoconv listener // process. -func NewUnoconv(debug bool) Process { +func NewUnoconv(logger *log.StandardLogger) Process { return &unoconv{ - manager: &processManager{verbose: debug}, + manager: &processManager{logger: logger}, } } diff --git a/internal/pkg/printer/markdown.go b/internal/pkg/printer/markdown.go index 0bbaa518..9c84830c 100644 --- a/internal/pkg/printer/markdown.go +++ b/internal/pkg/printer/markdown.go @@ -7,9 +7,9 @@ import ( "io/ioutil" "path/filepath" + "github.com/labstack/gommon/random" "github.com/microcosm-cc/bluemonday" "github.com/russross/blackfriday/v2" - "github.com/thecodingmachine/gotenberg/internal/pkg/rand" ) // NewMarkdown returns a Markdown printer. @@ -27,10 +27,7 @@ func NewMarkdown(fpath string, opts *ChromeOptions) (Printer, error) { if err := tmpl.Execute(&buffer, data); err != nil { return nil, fmt.Errorf("%s: executing template: %v", fpath, err) } - baseFilename, err := rand.Get() - if err != nil { - return nil, err - } + baseFilename := random.String(32) dst := fmt.Sprintf("%s/%s.html", dirPath, baseFilename) if err := ioutil.WriteFile(dst, buffer.Bytes(), 0644); err != nil { return nil, fmt.Errorf("%s: writing file: %v", dst, err) diff --git a/internal/pkg/printer/office.go b/internal/pkg/printer/office.go index 6a104ccf..8e83824e 100644 --- a/internal/pkg/printer/office.go +++ b/internal/pkg/printer/office.go @@ -9,7 +9,7 @@ import ( "sync" "time" - "github.com/thecodingmachine/gotenberg/internal/pkg/rand" + "github.com/labstack/gommon/random" ) type office struct { @@ -38,10 +38,7 @@ func (p *office) Print(destination string) error { fpaths := make([]string, len(p.fpaths)) dirPath := filepath.Dir(destination) for i, fpath := range p.fpaths { - baseFilename, err := rand.Get() - if err != nil { - return err - } + baseFilename := random.String(32) tmpDest := fmt.Sprintf("%s/%d%s.pdf", dirPath, i, baseFilename) if err := unoconv(ctx, fpath, tmpDest, p.opts); err != nil { return err diff --git a/internal/pkg/rand/doc.go b/internal/pkg/rand/doc.go deleted file mode 100644 index 35fa53e7..00000000 --- a/internal/pkg/rand/doc.go +++ /dev/null @@ -1,7 +0,0 @@ -/* -Package rand helps generating a random string. - -It should be used for creating directory and -file names in order to avoid collision. -*/ -package rand diff --git a/internal/pkg/rand/rand.go b/internal/pkg/rand/rand.go deleted file mode 100644 index 6291b515..00000000 --- a/internal/pkg/rand/rand.go +++ /dev/null @@ -1,17 +0,0 @@ -package rand - -import ( - "crypto/rand" - "encoding/hex" - "fmt" -) - -// Get returns a random string. -func Get() (string, error) { - randBytes := make([]byte, 16) - _, err := rand.Read(randBytes) - if err != nil { - return "", fmt.Errorf("creating random string: %v", err) - } - return hex.EncodeToString(randBytes), nil -} diff --git a/internal/pkg/rand/rand_test.go b/internal/pkg/rand/rand_test.go deleted file mode 100644 index c171539c..00000000 --- a/internal/pkg/rand/rand_test.go +++ /dev/null @@ -1,16 +0,0 @@ -package rand - -import ( - "testing" - - "github.com/stretchr/testify/assert" - "github.com/stretchr/testify/require" -) - -func TestGet(t *testing.T) { - rand1, err := Get() - require.Nil(t, err) - rand2, err := Get() - require.Nil(t, err) - assert.NotEqual(t, rand1, rand2) -}