diff --git a/cmd/gotenberg/main.go b/cmd/gotenberg/main.go index 49eaa149..78df8917 100644 --- a/cmd/gotenberg/main.go +++ b/cmd/gotenberg/main.go @@ -1,7 +1,6 @@ package main import ( - "context" "fmt" "net/http" "os" @@ -28,9 +27,8 @@ func main() { systemLogger.InfofOp(op, "Gotenberg %s", version) systemLogger.DebugfOp(op, "configuration: %+v", config) if !config.DisableGoogleChrome() { - // start Google Chrome. - _, err = chrome.Start(context.Background(), systemLogger) - if err != nil { + // start Google Chrome headless. + if err := chrome.Start(systemLogger); err != nil { systemLogger.FatalOp(op, err) } } diff --git a/internal/pkg/chrome/chrome.go b/internal/pkg/chrome/chrome.go index 1be662ac..9a206c85 100644 --- a/internal/pkg/chrome/chrome.go +++ b/internal/pkg/chrome/chrome.go @@ -4,6 +4,8 @@ import ( "context" "os" "os/exec" + "strings" + "syscall" "time" "github.com/mafredri/cdp/devtool" @@ -13,66 +15,26 @@ import ( "github.com/thecodingmachine/gotenberg/internal/pkg/xtime" ) -func Start(ctx context.Context, logger xlog.Logger) (*os.Process, error) { +// Start starts Google Chrome headless in background. +func Start(logger xlog.Logger) error { const op string = "chrome.Start" - logger.DebugOp(op, "starting new Google Chrome process on port 9222...") - resolver := func() (*os.Process, error) { - binary := "google-chrome-stable" - args := []string{ - "--no-sandbox", - "--headless", - // see https://github.com/GoogleChrome/puppeteer/issues/2410. - "--font-render-hinting=medium", - "--remote-debugging-port=9222", - "--disable-gpu", - "--disable-translate", - "--disable-extensions", - "--disable-background-networking", - "--safebrowsing-disable-auto-update", - "--disable-sync", - "--disable-default-apps", - "--hide-scrollbars", - "--metrics-recording-only", - "--mute-audio", - "--no-first-run", - } - cmd, err := xexec.CommandContext(ctx, logger, binary, args...) + logger.DebugOp(op, "starting new Google Chrome headless process on port 9222...") + resolver := func() error { + cmd, err := cmd(logger) if err != nil { - return nil, err + return err } // we try to start the process. xexec.LogBeforeExecute(logger, cmd) if err := cmd.Start(); err != nil { - return cmd.Process, err + return err } - // we wait the process to be ready. - warmup(logger) // if the process failed to start correctly, // we have to restart it. if !isViable(logger) { - return restart(ctx, logger, cmd) + return restart(logger, cmd.Process) } - return cmd.Process, nil - } - proc, err := resolver() - if err != nil { - if errKill := Kill(logger, proc); errKill != nil { - logger.ErrorOp(op, errKill) - } - return nil, xerror.New(op, err) - } - return proc, nil -} - -func Kill(logger xlog.Logger, proc *os.Process) error { - const op string = "chrome.Kill" - resolver := func() error { - logger.DebugOp(op, "removing Google Chrome process using port 9222...") - if proc == nil { - logger.DebugOp(op, "no Google Chrome process using port 9222 found, skipping") - return nil - } - return proc.Kill() + return nil } if err := resolver(); err != nil { return xerror.New(op, err) @@ -80,60 +42,125 @@ func Kill(logger xlog.Logger, proc *os.Process) error { return nil } -func restart(ctx context.Context, logger xlog.Logger, cmd *exec.Cmd) (*os.Process, error) { +func cmd(logger xlog.Logger) (*exec.Cmd, error) { + const op string = "chrome.cmd" + binary := "google-chrome-stable" + args := []string{ + "--no-sandbox", + "--headless", + // see https://github.com/GoogleChrome/puppeteer/issues/2410. + "--font-render-hinting=medium", + "--remote-debugging-port=9222", + "--disable-gpu", + "--disable-translate", + "--disable-extensions", + "--disable-background-networking", + "--safebrowsing-disable-auto-update", + "--disable-sync", + "--disable-default-apps", + "--hide-scrollbars", + "--metrics-recording-only", + "--mute-audio", + "--no-first-run", + } + cmd, err := xexec.Command(logger, binary, args...) + if err != nil { + return nil, xerror.New(op, err) + } + cmd.SysProcAttr = &syscall.SysProcAttr{Setpgid: true} + return cmd, nil +} + +func kill(logger xlog.Logger, proc *os.Process) error { + const op string = "chrome.kill" + logger.DebugOp(op, "killing Google Chrome headless process using port 9222...") + resolver := func() error { + err := syscall.Kill(-proc.Pid, syscall.SIGKILL) + if err == nil { + return nil + } + if strings.Contains(err.Error(), "no such process") { + return nil + } + return err + } + if err := resolver(); err != nil { + return xerror.New(op, err) + } + return nil +} + +func restart(logger xlog.Logger, proc *os.Process) error { const op string = "chrome.restart" - resolver := func() (*os.Process, error) { + logger.DebugOp(op, "restarting Google Chrome headless process using port 9222...") + resolver := func() error { + // kill the existing process first. + if err := kill(logger, proc); err != nil { + return err + } + cmd, err := cmd(logger) + if err != nil { + return err + } // we try to restart the process. xexec.LogBeforeExecute(logger, cmd) if err := cmd.Start(); err != nil { - return cmd.Process, err + return err } - // we wait the process to be ready. - warmup(logger) // if the process failed to restart correctly, // we have to restart it again. if !isViable(logger) { - return restart(ctx, logger, cmd) + return restart(logger, cmd.Process) } - return cmd.Process, nil + return nil } - proc, err := resolver() - if err != nil { - return proc, xerror.New(op, err) + if err := resolver(); err != nil { + return xerror.New(op, err) } - return proc, err + return nil } func isViable(logger xlog.Logger) bool { - const op string = "chrome.isViable" - ctx, cancel := context.WithCancel(context.Background()) - defer cancel() - endpoint := "http://localhost:9222" - logger.DebugfOp( - op, - "checking Google Chrome process viability via endpoint '%s/json/version'", - endpoint, + const ( + op string = "chrome.isViable" + maxViabilityTests int = 5 ) - v, err := devtool.New(endpoint).Version(ctx) - if err != nil { - logger.ErrorfOp( + viable := func() bool { + ctx, cancel := context.WithCancel(context.Background()) + defer cancel() + endpoint := "http://localhost:9222" + logger.DebugfOp( op, - "Google Chrome is not viable as endpoint returned '%v'", - err, + "checking Google Chrome process viability via endpoint '%s/json/version'", + endpoint, ) - return false + v, err := devtool.New(endpoint).Version(ctx) + if err != nil { + logger.ErrorfOp( + op, + "Google Chrome is not viable as endpoint returned '%v'", + err, + ) + return false + } + logger.DebugfOp( + op, + "Google Chrome is viable as endpoint returned '%v'", + v, + ) + return true } - logger.DebugfOp( - op, - "Google Chrome is viable as endpoint returned '%v'", - v, - ) - return true + result := false + for i := 0; i < maxViabilityTests && !result; i++ { + warmup(logger) + result = viable() + } + return result } func warmup(logger xlog.Logger) { const op string = "chrome.warmup" - warmupTime := xtime.Duration(10) + warmupTime := xtime.Duration(0.5) logger.DebugfOp( op, "waiting '%v' for allowing Google Chrome to warmup", diff --git a/internal/pkg/printer/merge.go b/internal/pkg/printer/merge.go index 126301bb..b8d4fa5b 100644 --- a/internal/pkg/printer/merge.go +++ b/internal/pkg/printer/merge.go @@ -59,12 +59,7 @@ func (p mergePrinter) Print(destination string) error { var args []string args = append(args, p.fpaths...) args = append(args, "cat", "output", destination) - cmd, err := xexec.CommandContext(p.ctx, p.logger, "pdftk", args...) - if err != nil { - return err - } - xexec.LogBeforeExecute(p.logger, cmd) - return cmd.Run() + return xexec.Run(p.ctx, p.logger, "pdftk", args...) } if err := resolver(); err != nil { return xcontext.MustHandleError( diff --git a/internal/pkg/printer/office.go b/internal/pkg/printer/office.go index 92ebd7d5..8a21ff2e 100644 --- a/internal/pkg/printer/office.go +++ b/internal/pkg/printer/office.go @@ -5,8 +5,6 @@ import ( "fmt" "os" "path/filepath" - "strings" - "syscall" "github.com/phayes/freeport" "github.com/thecodingmachine/gotenberg/internal/pkg/conf" @@ -106,43 +104,7 @@ func unoconv(ctx context.Context, logger xlog.Logger, fpath, destination string, args = append(args, "--printer", "PaperOrientation=landscape") } args = append(args, "--output", destination, fpath) - cmd, err := xexec.Command( - logger, - "unoconv", - args..., - ) - if err != nil { - return err - } - xexec.LogBeforeExecute(logger, cmd) - // see https://medium.com/@felixge/killing-a-child-process-and-all-of-its-children-in-go-54079af94773. - kill := func() { - err := syscall.Kill(-cmd.Process.Pid, syscall.SIGKILL) - if err == nil { - return - } - if !strings.Contains(err.Error(), "no such process") { - logger.ErrorOp(op, err) - } - } - cmd.SysProcAttr = &syscall.SysProcAttr{Setpgid: true} - if err := cmd.Start(); err != nil { - return err - } - result := make(chan error, 1) - go func() { - result <- cmd.Wait() - }() - select { - case err := <-result: - logger.DebugfOp(op, "command '%s' finished", strings.Join(cmd.Args, " ")) - kill() - return err - case <-ctx.Done(): - logger.DebugfOp(op, "command '%s' failed to finish before context.Context deadline", strings.Join(cmd.Args, " ")) - kill() - return ctx.Err() - } + return xexec.Run(ctx, logger, "unoconv", args...) } if err := resolver(); err != nil { return xerror.New(op, err) diff --git a/internal/pkg/xexec/doc.go b/internal/pkg/xexec/doc.go index e1605a43..9db49c6f 100644 --- a/internal/pkg/xexec/doc.go +++ b/internal/pkg/xexec/doc.go @@ -1,6 +1,7 @@ /* Package xexec helps creating exec.Cmd -with logging. +with logging and executing those commands +without leaking orphan processes. All functions return our standard xerror.Error in case of error. diff --git a/internal/pkg/xexec/xexec.go b/internal/pkg/xexec/xexec.go index b67d7b5a..127f65c6 100644 --- a/internal/pkg/xexec/xexec.go +++ b/internal/pkg/xexec/xexec.go @@ -8,6 +8,7 @@ import ( "io" "os/exec" "strings" + "syscall" "github.com/thecodingmachine/gotenberg/internal/pkg/xerror" "github.com/thecodingmachine/gotenberg/internal/pkg/xlog" @@ -43,6 +44,61 @@ func CommandContext(ctx context.Context, logger xlog.Logger, binary string, args return cmd, nil } +/* +Run runs a command. + +If command finishes or fails to finish +before context.Context deadline, kill the +corresponding process in a way which does +not leak orphan processes. +*/ +func Run(ctx context.Context, logger xlog.Logger, binary string, args ...string) error { + const op string = "xexec.Run" + resolver := func() error { + cmd, err := Command( + logger, + binary, + args..., + ) + if err != nil { + return err + } + LogBeforeExecute(logger, cmd) + // see https://medium.com/@felixge/killing-a-child-process-and-all-of-its-children-in-go-54079af94773. + kill := func() { + err := syscall.Kill(-cmd.Process.Pid, syscall.SIGKILL) + if err == nil { + return + } + if !strings.Contains(err.Error(), "no such process") { + logger.ErrorOp(op, err) + } + } + cmd.SysProcAttr = &syscall.SysProcAttr{Setpgid: true} + if err := cmd.Start(); err != nil { + return err + } + result := make(chan error, 1) + go func() { + result <- cmd.Wait() + }() + select { + case err := <-result: + logger.DebugfOp(op, "command '%s' finished", strings.Join(cmd.Args, " ")) + kill() + return err + case <-ctx.Done(): + logger.DebugfOp(op, "command '%s' failed to finish before context.Context deadline", strings.Join(cmd.Args, " ")) + kill() + return ctx.Err() + } + } + if err := resolver(); err != nil { + return xerror.New(op, err) + } + return nil +} + // LogBeforeExecute logs a command before its execution. func LogBeforeExecute(logger xlog.Logger, cmd *exec.Cmd) { const op string = "xexec.LogBeforeExecute" @@ -87,7 +143,7 @@ func logCommandOutput(logger xlog.Logger, reader io.ReadCloser, outputType strin for { line, _, err := r.ReadLine() if err != nil { - if err != io.EOF { + if err != io.EOF && !strings.Contains(err.Error(), "file already closed") { logger.ErrorOp(op, err) } break diff --git a/internal/pkg/xexec/xexec_test.go b/internal/pkg/xexec/xexec_test.go index bc3806aa..ceffc5c5 100644 --- a/internal/pkg/xexec/xexec_test.go +++ b/internal/pkg/xexec/xexec_test.go @@ -5,6 +5,7 @@ import ( "testing" "github.com/stretchr/testify/assert" + "github.com/thecodingmachine/gotenberg/internal/pkg/xcontext" "github.com/thecodingmachine/gotenberg/test" ) @@ -37,3 +38,16 @@ func TestCommandContext(t *testing.T) { LogBeforeExecute(logger, cmd) assert.Nil(t, err) } + +func TestRun(t *testing.T) { + logger := test.DebugLogger() + // should run without issue. + err := Run(context.Background(), logger, "echo", "Hello", "World") + assert.Nil(t, err) + // should not be OK as context.Context + // should timeout. + ctx, cancel := xcontext.WithTimeout(logger, 0) + defer cancel() + err = Run(ctx, logger, "echo", "Hello", "World") + assert.NotNil(t, err) +} diff --git a/test/cmd/chrome.go b/test/cmd/chrome.go index 82b38fcc..73d96474 100644 --- a/test/cmd/chrome.go +++ b/test/cmd/chrome.go @@ -1,8 +1,6 @@ package main import ( - "context" - "github.com/thecodingmachine/gotenberg/internal/pkg/chrome" "github.com/thecodingmachine/gotenberg/internal/pkg/conf" "github.com/thecodingmachine/gotenberg/internal/pkg/xlog" @@ -15,9 +13,8 @@ func main() { if err != nil { systemLogger.FatalOp(op, err) } - // start Google Chrome. - _, err = chrome.Start(context.Background(), systemLogger) - if err != nil { + // start Google Chrome headless. + if err := chrome.Start(systemLogger); err != nil { systemLogger.FatalOp(op, err) } }