diff options
| -rw-r--r-- | CHANGELOG.md | 2 | ||||
| -rw-r--r-- | CONTRIBUTING.md | 36 | ||||
| -rw-r--r-- | internal/helper/command.go | 37 | ||||
| -rw-r--r-- | internal/supervisor/supervisor.go | 10 |
4 files changed, 73 insertions, 12 deletions
diff --git a/CHANGELOG.md b/CHANGELOG.md index e3e3711cb..719c71741 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -2,6 +2,8 @@ UNRELEASED +- Export environment variables for git debugging + https://gitlab.com/gitlab-org/gitaly/merge_requests/306 - Fix bugs in RepositoryService.FetchRemote https://gitlab.com/gitlab-org/gitaly/merge_requests/300 - Respawn gitaly-ruby when it crashes diff --git a/CONTRIBUTING.md b/CONTRIBUTING.md index 1344126de..dbe11307a 100644 --- a/CONTRIBUTING.md +++ b/CONTRIBUTING.md @@ -126,3 +126,39 @@ the traditional author-reviewer 1-author-reviewer 1-reviewer 2-author-reviewer 2 - To get **coverage**: `make cover` - **Clean**: `make clean` - All-in-one: `make verify build test` + +## Debug Logging + +Debug logging can be enabled in Gitaly through the `GITALY_DEBUG` environment variable: + +``` +$ GITALY_DEBUG=1 ./gitaly config.toml +``` + +## Git Tracing + +Gitaly will reexport `GIT_TRACE*` [environment variables](https://git-scm.com/book/en/v2/Git-Internals-Environment-Variables) if they are set. + +This can be an aid to debugging some sets of problems. For example, if you would like to know what git is going internally, you can set `GIT_TRACE=true`: + +Note that since git stderr stream will be logged at debug level, you need to enable debug logging too. + +```shell +$ GITALY_DEBUG=1 GIT_TRACE=true ./gitaly config.toml +... +DEBU[0015] 13:04:08.646399 git.c:322 trace: built-in: git 'gc' grpc.method=GarbageCollect grpc.request.repoPath="gitlab/gitlab-design.git" grpc.request.repoStorage=default grpc.request.topLevelGroup=gitlab grpc.service=gitaly.RepositoryService peer.address= span.kind=server system=grpc +DEBU[0015] 13:04:08.649346 run-command.c:626 trace: run_command: 'pack-refs' '--all' '--prune' grpc.method=GarbageCollect grpc.request.repoPath="gitlab/gitlab-design.git" grpc.request.repoStorage=default grpc.request.topLevelGroup=gitlab grpc.service=gitaly.RepositoryService peer.address= span.kind=server system=grpc +DEBU[0015] 13:04:08.652240 git.c:322 trace: built-in: git 'pack-refs' '--all' '--prune' grpc.method=GarbageCollect grpc.request.repoPath="gitlab/gitlab-design.git" grpc.request.repoStorage=default grpc.request.topLevelGroup=gitlab grpc.service=gitaly.RepositoryService peer.address= span.kind=server system=grpc +DEBU[0015] 13:04:08.655497 run-command.c:626 trace: run_command: 'reflog' 'expire' '--all' grpc.method=GarbageCollect grpc.request.repoPath="gitlab/gitlab-design.git" grpc.request.repoStorage=default grpc.request.topLevelGroup=gitlab grpc.service=gitaly.RepositoryService peer.address= span.kind=server system=grpc +DEBU[0015] 13:04:08.658331 git.c:322 trace: built-in: git 'reflog' 'expire' '--all' grpc.method=GarbageCollect grpc.request.repoPath="gitlab/gitlab-design.git" grpc.request.repoStorage=default grpc.request.topLevelGroup=gitlab grpc.service=gitaly.RepositoryService peer.address= span.kind=server system=grpc +DEBU[0015] 13:04:08.669787 run-command.c:626 trace: run_command: 'repack' '-d' '-l' '-A' '--unpack-unreachable=2.weeks.ago' grpc.method=GarbageCollect grpc.request.repoPath="gitlab/gitlab-design.git" grpc.request.repoStorage=default grpc.request.topLevelGroup=gitlab grpc.service=gitaly.RepositoryService peer.address= span.kind=server system=grpc +DEBU[0015] 13:04:08.672589 git.c:322 trace: built-in: git 'repack' '-d' '-l' '-A' '--unpack-unreachable=2.weeks.ago' grpc.method=GarbageCollect grpc.request.repoPath="gitlab/gitlab-design.git" grpc.request.repoStorage=default grpc.request.topLevelGroup=gitlab grpc.service=gitaly.RepositoryService peer.address= span.kind=server system=grpc +DEBU[0015] 13:04:08.673185 run-command.c:626 trace: run_command: 'pack-objects' '--keep-true-parents' '--non-empty' '--all' '--reflog' '--indexed-objects' '--write-bitmap-index' '--unpack-unreachable=2.weeks.ago' '--local' '--delta-base-offset' 'objects/pack/.tmp-60361-pack' grpc.method=GarbageCollect grpc.request.repoPath="gitlab/gitlab-design.git" grpc.request.repoStorage=default grpc.request.topLevelGroup=gitlab grpc.service=gitaly.RepositoryService peer.address= span.kind=server system=grpc +DEBU[0015] 13:04:08.675955 git.c:322 trace: built-in: git 'pack-objects' '--keep-true-parents' '--non-empty' '--all' '--reflog' '--indexed-objects' '--write-bitmap-index' '--unpack-unreachable=2.weeks.ago' '--local' '--delta-base-offset' 'objects/pack/.tmp-60361-pack' grpc.method=GarbageCollect grpc.request.repoPath="gitlab/gitlab-design.git" grpc.request.repoStorage=default grpc.request.topLevelGroup=gitlab grpc.service=gitaly.RepositoryService peer.address= span.kind=server system=grpc +DEBU[0037] 13:04:30.737687 run-command.c:626 trace: run_command: 'prune' '--expire' '2.weeks.ago' grpc.method=GarbageCollect grpc.request.repoPath="gitlab/gitlab-design.git" grpc.request.repoStorage=default grpc.request.topLevelGroup=gitlab grpc.service=gitaly.RepositoryService peer.address= span.kind=server system=grpc +DEBU[0037] 13:04:30.753856 git.c:322 trace: built-in: git 'prune' '--expire' '2.weeks.ago' grpc.method=GarbageCollect grpc.request.repoPath="gitlab/gitlab-design.git" grpc.request.repoStorage=default grpc.request.topLevelGroup=gitlab grpc.service=gitaly.RepositoryService peer.address= span.kind=server system=grpc +DEBU[0037] 13:04:31.071140 run-command.c:626 trace: run_command: 'worktree' 'prune' '--expire' '3.months.ago' grpc.method=GarbageCollect grpc.request.repoPath="gitlab/gitlab-design.git" grpc.request.repoStorage=default grpc.request.topLevelGroup=gitlab grpc.service=gitaly.RepositoryService peer.address= span.kind=server system=grpc +DEBU[0037] 13:04:31.074736 git.c:322 trace: built-in: git 'worktree' 'prune' '--expire' '3.months.ago' grpc.method=GarbageCollect grpc.request.repoPath="gitlab/gitlab-design.git" grpc.request.repoStorage=default grpc.request.topLevelGroup=gitlab grpc.service=gitaly.RepositoryService peer.address= span.kind=server system=grpc +DEBU[0037] 13:04:31.076135 run-command.c:626 trace: run_command: 'rerere' 'gc' grpc.method=GarbageCollect grpc.request.repoPath="gitlab/gitlab-design.git" grpc.request.repoStorage=default grpc.request.topLevelGroup=gitlab grpc.service=gitaly.RepositoryService peer.address= span.kind=server system=grpc +DEBU[0037] 13:04:31.079286 git.c:322 trace: built-in: git 'rerere' 'gc' grpc.method=GarbageCollect grpc.request.repoPath="gitlab/gitlab-design.git" grpc.request.repoStorage=default grpc.request.topLevelGroup=gitlab grpc.service=gitaly.RepositoryService peer.address= span.kind=server system=grpc +``` diff --git a/internal/helper/command.go b/internal/helper/command.go index 4cd1597e4..06b9a59e3 100644 --- a/internal/helper/command.go +++ b/internal/helper/command.go @@ -19,6 +19,22 @@ import ( log "github.com/Sirupsen/logrus" ) +// exportedEnvVars contains a list of environment variables +// that are always exported to child processes on spawn +var exportedEnvVars = []string{ + "HOME", + "PATH", + "LD_LIBRARY_PATH", + "TZ", + + // Export git tracing variables for easier debugging + "GIT_TRACE", + "GIT_TRACE_PACK_ACCESS", + "GIT_TRACE_PACKET", + "GIT_TRACE_PERFORMANCE", + "GIT_TRACE_SETUP", +} + // Command encapsulates operations with commands creates with NewCommand type Command struct { io.Reader @@ -67,13 +83,12 @@ func NewCommand(ctx context.Context, cmd *exec.Cmd, stdin io.Reader, stdout, std // Explicitly set the environment for the command cmd.Env = []string{ - fmt.Sprintf("HOME=%s", os.Getenv("HOME")), - fmt.Sprintf("PATH=%s", os.Getenv("PATH")), - fmt.Sprintf("LD_LIBRARY_PATH=%s", os.Getenv("LD_LIBRARY_PATH")), - fmt.Sprintf("TZ=%s", os.Getenv("TZ")), "GIT_TERMINAL_PROMPT=0", } - cmd.Env = append(cmd.Env, env...) + + // Export env vars + cmd.Env = exportEnvironment(cmd.Env) + if dir, ok := objectdirhandler.ObjectDir(ctx); ok { cmd.Env = append(cmd.Env, fmt.Sprintf("GIT_OBJECT_DIRECTORY=%s", dir)) } @@ -105,7 +120,7 @@ func NewCommand(ctx context.Context, cmd *exec.Cmd, stdin io.Reader, stdout, std cmd.Stderr = stderr } else { // If we don't do something with cmd.Stderr, Git errors will be lost - cmd.Stderr = os.Stderr + cmd.Stderr = grpc_logrus.Extract(ctx).WriterLevel(log.InfoLevel) } if err := cmd.Start(); err != nil { @@ -115,6 +130,16 @@ func NewCommand(ctx context.Context, cmd *exec.Cmd, stdin io.Reader, stdout, std return command, nil } +func exportEnvironment(env []string) []string { + for _, envVarName := range exportedEnvVars { + if val, ok := os.LookupEnv(envVarName); ok { + env = append(env, fmt.Sprintf("%s=%s", envVarName, val)) + } + } + + return env +} + // Close will send a SIGTERM signal to the process group // belonging to the `cmd` process func (c *Command) Close() error { diff --git a/internal/supervisor/supervisor.go b/internal/supervisor/supervisor.go index 5dea07e06..5228b6b0f 100644 --- a/internal/supervisor/supervisor.go +++ b/internal/supervisor/supervisor.go @@ -2,7 +2,6 @@ package supervisor import ( "fmt" - "os" "os/exec" "sync" "time" @@ -56,13 +55,12 @@ func New(env []string, args []string, dir string) (*Process, error) { return p, nil } -func (p *Process) start() (*exec.Cmd, error) { +func (p *Process) start(logger *log.Entry) (*exec.Cmd, error) { cmd := exec.Command(p.args[0], p.args[1:]...) cmd.Env = p.env cmd.Dir = p.dir - cmd.Stdout = os.Stdout - cmd.Stderr = os.Stderr - + cmd.Stdout = logger.WriterLevel(log.InfoLevel) + cmd.Stderr = logger.WriterLevel(log.InfoLevel) return cmd, cmd.Start() } @@ -84,7 +82,7 @@ func watch(p *Process) { } } - cmd, err := p.start() + cmd, err := p.start(logger) if err != nil { crashes++ logger.WithError(err).Error("start failed") |