improving logging

cmd/gotenberg/main.go

@@ -26,6 +26,7 @@ func main() {
 		systemLogger.FatalOp(op, err)
 	}
 	systemLogger.InfofOp(op, "Gotenberg %s", version)
+	systemLogger.DebugfOp(op, "configuration: %+v", config)
 	// start PM2 processes.
 	var processes []pm2.Process
 	if config.EnableChromeEndpoints() {

internal/app/api/pkg/handler/html.go

@@ -12,6 +12,7 @@ import (
 func HTML(c echo.Context) error {
 	const op = "handler.HTML"
 	ctx := context.MustCastFromEchoContext(c)
+	ctx.StandardLogger().DebugfOp(op, "html request")
 	r := ctx.Resource()
 	opts, err := r.ChromePrinterOptions()
 	if err != nil {

internal/app/api/pkg/handler/markdown.go

@@ -12,6 +12,7 @@ import (
 func Markdown(c echo.Context) error {
 	const op = "handler.Markdown"
 	ctx := context.MustCastFromEchoContext(c)
+	ctx.StandardLogger().DebugfOp(op, "markdown request")
 	r := ctx.Resource()
 	opts, err := r.ChromePrinterOptions()
 	if err != nil {

internal/app/api/pkg/handler/merge.go

@@ -12,6 +12,7 @@ import (
 func Merge(c echo.Context) error {
 	const op = "handler.Merge"
 	ctx := context.MustCastFromEchoContext(c)
+	ctx.StandardLogger().DebugfOp(op, "merge request")
 	r := ctx.Resource()
 	opts, err := r.MergePrinterOptions()
 	if err != nil {

internal/app/api/pkg/handler/office.go

@@ -12,6 +12,7 @@ import (
 func Office(c echo.Context) error {
 	const op = "handler.Office"
 	ctx := context.MustCastFromEchoContext(c)
+	ctx.StandardLogger().DebugfOp(op, "office request")
 	r := ctx.Resource()
 	opts, err := r.OfficePrinterOptions()
 	if err != nil {

internal/app/api/pkg/handler/url.go

@@ -13,6 +13,7 @@ import (
 func URL(c echo.Context) error {
 	const op = "handler.URL"
 	ctx := context.MustCastFromEchoContext(c)
+	ctx.StandardLogger().DebugfOp(op, "url request")
 	r := ctx.Resource()
 	opts, err := r.ChromePrinterOptions()
 	if err != nil {

internal/app/api/pkg/middleware/context.go

@@ -30,8 +30,7 @@ func Context(config *config.Config) echo.MiddlewareFunc {
 			// if the endpoint is not for healthcheck, associate a
 			// resource to our custom context.
 			if err := ctx.WithResource(trace); err != nil {
-				// required to have a correct status code
+				// required to have a correct status code.
-				// in the logs.
 				ctx.Error(err)
 				return ctx.LogRequestResult(err, false)
 			}

internal/app/api/pkg/middleware/error.go

@@ -35,8 +35,7 @@ func Error() echo.MiddlewareFunc {
 			default:
 				httpErr = echo.NewHTTPError(http.StatusInternalServerError, errMessage)
 			}
-			// required to have a correct status code
+			// required to have a correct status code.
-			// in the logs.
 			ctx.Error(httpErr)
 			return httpErr
 		}

internal/app/api/pkg/resource/resource.go

@@ -85,19 +85,27 @@ func New(c echo.Context, logger *logger.Logger, config *config.Config, dirPath s
 func formValues(c echo.Context, logger *logger.Logger) map[string]string {
 	const op = "resource.formValues"
 	v := make(map[string]string)
-	v[ResultFilenameFormField] = c.FormValue(ResultFilenameFormField)
+	fetch := func(formField string) string {
-	v[WaitTimeoutFormField] = c.FormValue(WaitTimeoutFormField)
+		value := c.FormValue(formField)
-	v[WebhookURLFormField] = c.FormValue(WebhookURLFormField)
+		if value == "" {
-	v[RemoteURLFormField] = c.FormValue(RemoteURLFormField)
+			logger.DebugfOp(op, "'%s' is empty", formField)
-	v[WaitDelayFormField] = c.FormValue(WaitDelayFormField)
+			return value
-	v[PaperWidthFormField] = c.FormValue(PaperWidthFormField)
+		}
-	v[PaperHeightFormField] = c.FormValue(PaperHeightFormField)
+		logger.DebugfOp(op, "'%s' retrieved, got '%s'", formField, value)
-	v[MarginTopFormField] = c.FormValue(MarginTopFormField)
+		return value
-	v[MarginBottomFormField] = c.FormValue(MarginBottomFormField)
+	}
-	v[MarginLeftFormField] = c.FormValue(MarginLeftFormField)
+	v[ResultFilenameFormField] = fetch(ResultFilenameFormField)
-	v[MarginRightFormField] = c.FormValue(MarginRightFormField)
+	v[WaitTimeoutFormField] = fetch(WaitTimeoutFormField)
-	v[LandscapeFormField] = c.FormValue(LandscapeFormField)
+	v[WebhookURLFormField] = fetch(WebhookURLFormField)
-	logger.DebugfOp(op, "%v", v)
+	v[RemoteURLFormField] = fetch(RemoteURLFormField)
+	v[WaitDelayFormField] = fetch(WaitDelayFormField)
+	v[PaperWidthFormField] = fetch(PaperWidthFormField)
+	v[PaperHeightFormField] = fetch(PaperHeightFormField)
+	v[MarginTopFormField] = fetch(MarginTopFormField)
+	v[MarginBottomFormField] = fetch(MarginBottomFormField)
+	v[MarginLeftFormField] = fetch(MarginLeftFormField)
+	v[MarginRightFormField] = fetch(MarginRightFormField)
+	v[LandscapeFormField] = fetch(LandscapeFormField)
 	return v
 }
 
@@ -221,7 +229,7 @@ func (r *Resource) ChromePrinterOptions() (*printer.ChromeOptions, error) {
 		MarginRight:  marginRight,
 		Landscape:    landscape,
 	}
-	r.logger.DebugfOp(op, "%v", opts)
+	r.logger.DebugfOp(op, "printer options: %+v", opts)
 	return opts, nil
 }
 
@@ -242,7 +250,7 @@ func (r *Resource) OfficePrinterOptions() (*printer.OfficeOptions, error) {
 		WaitTimeout: waitTimeout,
 		Landscape:   landscape,
 	}
-	r.logger.DebugfOp(op, "%v", opts)
+	r.logger.DebugfOp(op, "printer options: %+v", opts)
 	return opts, nil
 }
 
@@ -258,7 +266,7 @@ func (r *Resource) MergePrinterOptions() (*printer.MergeOptions, error) {
 	opts := &printer.MergeOptions{
 		WaitTimeout: waitTimeout,
 	}
-	r.logger.DebugfOp(op, "%v", opts)
+	r.logger.DebugfOp(op, "printer options: %+v", opts)
 	return opts, nil
 }
 
@@ -384,13 +392,12 @@ func (r *Resource) Fpaths(exts ...string) ([]string, error) {
 	const op = "resource.Fpaths"
 	var fpaths []string
 	err := filepath.Walk(r.formFilesDirPath, func(path string, info os.FileInfo, _ error) error {
-		const walkOp = "resource.filepath.Walk"
 		if info.IsDir() {
 			return nil
 		}
 		fpath, err := r.Fpath(info.Name())
 		if err != nil {
-			return &standarderror.Error{Op: walkOp, Err: err}
+			return &standarderror.Error{Op: op, Err: err}
 		}
 		for _, ext := range exts {
 			if filepath.Ext(fpath) == ext {

internal/pkg/pm2/chrome.go

@@ -9,7 +9,7 @@ import (
 	"github.com/thecodingmachine/gotenberg/internal/pkg/standarderror"
 )
 
-const warmupTime = 10 * time.Second
+const chromeWarmupTime = 10 * time.Second
 
 type chrome struct {
 	manager *processManager
@@ -93,13 +93,13 @@ func (p *chrome) viable() bool {
 }
 
 func (p *chrome) warmup() {
-	const debugOp = "pm2.chrome.warmup"
+	const op = "pm2.chrome.warmup"
 	p.manager.logger.DebugfOp(
-		debugOp,
+		op,
 		"allowing %v to startup",
-		warmupTime,
+		chromeWarmupTime,
 	)
-	time.Sleep(warmupTime)
+	time.Sleep(chromeWarmupTime)
 }
 
 // Compile-time checks to ensure type implements desired interfaces.

internal/pkg/pm2/unoconv.go

@@ -1,10 +1,14 @@
 package pm2
 
 import (
+	"time"
+
 	"github.com/thecodingmachine/gotenberg/internal/pkg/logger"
 	"github.com/thecodingmachine/gotenberg/internal/pkg/standarderror"
 )
 
+const unoconvWarmupTime = 5 * time.Second
+
 type unoconv struct {
 	manager *processManager
 }
@@ -56,7 +60,13 @@ func (p *unoconv) viable() bool {
 }
 
 func (p *unoconv) warmup() {
-	// let's do nothing.
+	const op = "pm2.unoconv.warmup"
+	p.manager.logger.DebugfOp(
+		op,
+		"allowing %v to startup",
+		unoconvWarmupTime,
+	)
+	time.Sleep(unoconvWarmupTime)
 }
 
 // Compile-time checks to ensure type implements desired interfaces.