From 79a7b159f911bf68b0c7e7025303e5a2969a6ee2 Mon Sep 17 00:00:00 2001 From: Lunny Xiao Date: Mon, 3 Jul 2023 15:44:15 +0800 Subject: [PATCH 1/4] Add escaped time on debug for slow git commands --- modules/git/command.go | 9 ++++++++- 1 file changed, 8 insertions(+), 1 deletion(-) diff --git a/modules/git/command.go b/modules/git/command.go index ac013d4ea1c7c..a8a30cb71f50f 100644 --- a/modules/git/command.go +++ b/modules/git/command.go @@ -281,6 +281,7 @@ func (c *Command) Run(opts *RunOpts) error { log.Debug("git.Command.RunDir(%s): %s", opts.Dir, c) } + startTime := time.Now() desc := c.desc if desc == "" { if opts.Dir == "" { @@ -327,7 +328,13 @@ func (c *Command) Run(opts *RunOpts) error { } } - if err := cmd.Wait(); err != nil && ctx.Err() != context.DeadlineExceeded { + err := cmd.Wait() + escaped := time.Since(startTime) + if escaped > time.Second { + log.Debug("slow it.Command.Run: %s", c) + } + + if err != nil && ctx.Err() != context.DeadlineExceeded { return err } From 81ceb9d0221166f08cc7b65007625e19254a1a00 Mon Sep 17 00:00:00 2001 From: Lunny Xiao Date: Mon, 3 Jul 2023 22:16:51 +0800 Subject: [PATCH 2/4] Update modules/git/command.go Co-authored-by: Lauris BH --- modules/git/command.go | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/modules/git/command.go b/modules/git/command.go index a8a30cb71f50f..c76871dd8a580 100644 --- a/modules/git/command.go +++ b/modules/git/command.go @@ -329,9 +329,9 @@ func (c *Command) Run(opts *RunOpts) error { } err := cmd.Wait() - escaped := time.Since(startTime) - if escaped > time.Second { - log.Debug("slow it.Command.Run: %s", c) + elapsed := time.Since(startTime) + if elapsed > time.Second { + log.Debug("slow it.Command.Run: %s (%s)", c, elapsed) } if err != nil && ctx.Err() != context.DeadlineExceeded { From 49dce852724ea5fb15a8b27cbae2b2e9624ec174 Mon Sep 17 00:00:00 2001 From: Lunny Xiao Date: Mon, 3 Jul 2023 23:51:02 +0800 Subject: [PATCH 3/4] Update modules/git/command.go Co-authored-by: delvh --- modules/git/command.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/modules/git/command.go b/modules/git/command.go index c76871dd8a580..df3a5059f0ee3 100644 --- a/modules/git/command.go +++ b/modules/git/command.go @@ -331,7 +331,7 @@ func (c *Command) Run(opts *RunOpts) error { err := cmd.Wait() elapsed := time.Since(startTime) if elapsed > time.Second { - log.Debug("slow it.Command.Run: %s (%s)", c, elapsed) + log.Debug("slow git.Command.Run: %s (%s)", c, elapsed) } if err != nil && ctx.Err() != context.DeadlineExceeded { From 3ee4049a2cc7a669e67d3c8bc1ed00e0ef591a51 Mon Sep 17 00:00:00 2001 From: Lunny Xiao Date: Tue, 4 Jul 2023 10:14:09 +0800 Subject: [PATCH 4/4] Make the time elapse more accurate --- modules/git/command.go | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/modules/git/command.go b/modules/git/command.go index a8a30cb71f50f..3cd425a31a29e 100644 --- a/modules/git/command.go +++ b/modules/git/command.go @@ -281,7 +281,6 @@ func (c *Command) Run(opts *RunOpts) error { log.Debug("git.Command.RunDir(%s): %s", opts.Dir, c) } - startTime := time.Now() desc := c.desc if desc == "" { if opts.Dir == "" { @@ -302,6 +301,8 @@ func (c *Command) Run(opts *RunOpts) error { } defer finished() + startTime := time.Now() + cmd := exec.CommandContext(ctx, c.prog, c.args...) if opts.Env == nil { cmd.Env = os.Environ()