From 01277c361f84bf3809671100222b5f3fcb0ee8c7 Mon Sep 17 00:00:00 2001 From: lhchavez Date: Thu, 2 Dec 2021 06:46:06 -0800 Subject: [PATCH] Add even more tracing (#28) Now every function that interacts with git2go should in theory be traced, both here and in githttp. --- cmd/omegaup-gitserver/health_test.go | 5 +- cmd/omegaup-translate-problem/main.go | 6 +- cmd/omegaup-translate-problem/main_test.go | 4 +- cmd/omegaup-update-problem/main.go | 5 +- cmd/omegaup-update-problem/main_test.go | 11 +- go.mod | 2 +- go.sum | 2 + handler.go | 118 +++++++++++++-------- handler_test.go | 28 +++-- ziphandler.go | 29 ++++- ziphandler_test.go | 13 ++- 11 files changed, 151 insertions(+), 72 deletions(-) diff --git a/cmd/omegaup-gitserver/health_test.go b/cmd/omegaup-gitserver/health_test.go index 2e4c8fc..ad98a04 100644 --- a/cmd/omegaup-gitserver/health_test.go +++ b/cmd/omegaup-gitserver/health_test.go @@ -1,6 +1,7 @@ package main import ( + "context" "errors" "io" "io/ioutil" @@ -32,6 +33,8 @@ func TestHealth(t *testing.T) { defer os.RemoveAll(tmpDir) } + ctx := context.Background() + log := base.StderrLog(false) ts := httptest.NewUnstartedServer(nil) _, portString, err := net.SplitHostPort(ts.Listener.Addr().String()) @@ -69,7 +72,7 @@ func TestHealth(t *testing.T) { problemAlias := "sumas" - repo, err := gitserver.InitRepository(path.Join(tmpDir, problemAlias)) + repo, err := gitserver.InitRepository(ctx, path.Join(tmpDir, problemAlias)) if err != nil { t.Fatalf("Failed to initialize git repository: %v", err) } diff --git a/cmd/omegaup-translate-problem/main.go b/cmd/omegaup-translate-problem/main.go index bb11bdf..a8b84f1 100644 --- a/cmd/omegaup-translate-problem/main.go +++ b/cmd/omegaup-translate-problem/main.go @@ -453,6 +453,7 @@ func createPackfileFromMergedCommit( } func unmergeRepository( + ctx context.Context, sourceRepositoryPath, destRepositoryPath string, ignoreCommitter bool, @@ -468,7 +469,7 @@ func unmergeRepository( } defer sourceRepo.Free() - destRepo, err := gitserver.InitRepository(destRepositoryPath) + destRepo, err := gitserver.InitRepository(ctx, destRepositoryPath) if err != nil { return nil, errors.Wrapf( err, @@ -606,6 +607,7 @@ func main() { os.Exit(1) } + ctx := context.Background() operation := args[0] sourceRepositoryPath := args[1] destRepositoryPath := args[2] @@ -635,7 +637,7 @@ func main() { } defer f.Close() - report, err := unmergeRepository(sourceRepositoryPath, destRepositoryPath, *ignoreCommitter, log) + report, err := unmergeRepository(ctx, sourceRepositoryPath, destRepositoryPath, *ignoreCommitter, log) if err != nil { log.Crit( "failed to unmerge repository", diff --git a/cmd/omegaup-translate-problem/main_test.go b/cmd/omegaup-translate-problem/main_test.go index a53e9f2..cc2303a 100644 --- a/cmd/omegaup-translate-problem/main_test.go +++ b/cmd/omegaup-translate-problem/main_test.go @@ -1,6 +1,7 @@ package main import ( + "context" "io/ioutil" "os" "path" @@ -18,6 +19,7 @@ func TestRoundtrip(t *testing.T) { if os.Getenv("PRESERVE") == "" { defer os.RemoveAll(dirName) } + ctx := context.Background() log := base.StderrLog(false) @@ -27,7 +29,7 @@ func TestRoundtrip(t *testing.T) { if err := mergeRepository("testdata/sumas.git", mergedPath, log); err != nil { t.Fatalf("failed to merge repository: %v", err) } - got, err := unmergeRepository(mergedPath, unmergedPath, false, log) + got, err := unmergeRepository(ctx, mergedPath, unmergedPath, false, log) if err != nil { t.Fatalf("failed to unmerge repository: %v", err) } diff --git a/cmd/omegaup-update-problem/main.go b/cmd/omegaup-update-problem/main.go index 6831ffa..7c59e8c 100644 --- a/cmd/omegaup-update-problem/main.go +++ b/cmd/omegaup-update-problem/main.go @@ -330,7 +330,7 @@ func commitBlobs( return nil, err } - updatedFiles, err := gitserver.GetUpdatedFiles(repo, updatedRefs) + updatedFiles, err := gitserver.GetUpdatedFiles(ctx, repo, updatedRefs) if err != nil { log.Error("failed to get updated files", "err", err) } @@ -358,6 +358,7 @@ func main() { os.Exit(1) } + ctx := context.Background() var repo *git.Repository commitCallback := func() error { return nil } if _, err := os.Stat(*repositoryPath); os.IsNotExist(err) { @@ -373,7 +374,7 @@ func main() { os.Exit(1) } - repo, err = gitserver.InitRepository(dir) + repo, err = gitserver.InitRepository(ctx, dir) if err != nil { log.Crit("Failed to init bare repository", "err", err) os.Exit(1) diff --git a/cmd/omegaup-update-problem/main_test.go b/cmd/omegaup-update-problem/main_test.go index 6ba0ba8..f64ae4a 100644 --- a/cmd/omegaup-update-problem/main_test.go +++ b/cmd/omegaup-update-problem/main_test.go @@ -3,6 +3,7 @@ package main import ( "archive/zip" "bytes" + "context" "io" "io/ioutil" "os" @@ -20,6 +21,8 @@ import ( ) func getTreeOid(t *testing.T, extraFileContents map[string]io.Reader, log log15.Logger) *git.Oid { + t.Helper() + ctx := context.Background() tmpdir, err := ioutil.TempDir("", "gitrepo") if err != nil { t.Fatalf("Failed to create tempdir: %v", err) @@ -45,7 +48,7 @@ func getTreeOid(t *testing.T, extraFileContents map[string]io.Reader, log log15. t.Fatalf("Failed to write zip: %v", err) } - repo, err := gitserver.InitRepository(tmpdir) + repo, err := gitserver.InitRepository(ctx, tmpdir) if err != nil { t.Fatalf("Failed to initialize bare repository: %v", err) } @@ -202,8 +205,9 @@ func TestProblemUpdateZip(t *testing.T) { if os.Getenv("PRESERVE") == "" { defer os.RemoveAll(tmpdir) } + ctx := context.Background() - repo, err := gitserver.InitRepository(tmpdir) + repo, err := gitserver.InitRepository(ctx, tmpdir) if err != nil { t.Fatalf("Failed to initialize bare repository: %v", err) } @@ -335,8 +339,9 @@ func TestProblemUpdateBlobs(t *testing.T) { if os.Getenv("PRESERVE") == "" { defer os.RemoveAll(tmpdir) } + ctx := context.Background() - repo, err := gitserver.InitRepository(tmpdir) + repo, err := gitserver.InitRepository(ctx, tmpdir) if err != nil { t.Fatalf("Failed to initialize bare repository: %v", err) } diff --git a/go.mod b/go.mod index a00f226..b928a3e 100644 --- a/go.mod +++ b/go.mod @@ -14,7 +14,7 @@ require ( github.com/mattn/go-sqlite3 v1.14.8 github.com/newrelic/go-agent/v3 v3.15.1 github.com/o1egl/paseto v1.0.0 - github.com/omegaup/githttp/v2 v2.2.0 + github.com/omegaup/githttp/v2 v2.2.1 github.com/omegaup/go-base/tracing/newrelic v0.0.0-20211201150123-3ace5d86e12a github.com/omegaup/go-base/v2 v2.3.0 github.com/omegaup/quark v1.8.0 diff --git a/go.sum b/go.sum index 133678e..f69a8e4 100644 --- a/go.sum +++ b/go.sum @@ -222,6 +222,8 @@ github.com/oklog/run v1.0.0/go.mod h1:dlhp/R75TPv97u0XWUtDeV/lRKWPKSdTuV0TZvrmrQ github.com/olekukonko/tablewriter v0.0.0-20170122224234-a0225b3f23b5/go.mod h1:vsDQFd/mU46D+Z4whnwzcISnGGzXWMclvtLoiIKAKIo= github.com/omegaup/githttp/v2 v2.2.0 h1:KehjPh4s0L9Oj3HG7bMykqa/tZ3hDATpNQ6q9ql9in8= github.com/omegaup/githttp/v2 v2.2.0/go.mod h1:QOU20srNzkvDPsJpFbloR9yWrlwCcRW7Q2d9tIW3x/M= +github.com/omegaup/githttp/v2 v2.2.1 h1:dEpQDSQB7HOGDuX5oh93YqT/f3Be1QsnO+r03P6jopI= +github.com/omegaup/githttp/v2 v2.2.1/go.mod h1:QOU20srNzkvDPsJpFbloR9yWrlwCcRW7Q2d9tIW3x/M= github.com/omegaup/go-base/tracing/newrelic v0.0.0-20211201150123-3ace5d86e12a h1:vORkEPKY98j2/dqacWsrj/4uEM3qecgLMjwPZgBGH04= github.com/omegaup/go-base/tracing/newrelic v0.0.0-20211201150123-3ace5d86e12a/go.mod h1:oFTFEE0LxFk4ahZfZe+rV0aPdJbtSiDoTlvrGZXqTyY= github.com/omegaup/go-base/v2 v2.3.0 h1:u5juOm0O96ZeuJu3xYSwvyGtstIkCEDT/F016gzSfow= diff --git a/handler.go b/handler.go index b1b8a16..4731787 100644 --- a/handler.go +++ b/handler.go @@ -238,7 +238,12 @@ func NewGitProtocol(opts GitProtocolOpts) *githttp.GitProtocol { return githttp.NewGitProtocol(opts.GitProtocolOpts) } -func getProblemSettings(repo *git.Repository, tree *git.Tree) (*common.ProblemSettings, error) { +func getProblemSettings( + ctx context.Context, + repo *git.Repository, + tree *git.Tree, +) (*common.ProblemSettings, error) { + defer tracing.FromContext(ctx).StartSegment("getProblemSettings").End() settingsJSONEntry, err := tree.EntryByPath("settings.json") if err != nil { return nil, base.ErrorWithCategory( @@ -355,9 +360,11 @@ func extractExampleCasesFromStatement( } func extractExampleCases( - repository *git.Repository, + ctx context.Context, + repo *git.Repository, tree *git.Tree, ) (map[string]*common.LiteralCaseSettings, error) { + defer tracing.FromContext(ctx).StartSegment("preprocessMaster").End() exampleCases := make(map[string]*common.LiteralCaseSettings) for _, examplesDirectory := range []string{"examples", "interactive/examples"} { @@ -376,7 +383,7 @@ func extractExampleCases( ) } - examplesTree, err := repository.LookupTree(entry.Id) + examplesTree, err := repo.LookupTree(entry.Id) if err != nil { return nil, base.ErrorWithCategory( ErrInternalGit, @@ -409,7 +416,7 @@ func extractExampleCases( ) } - inputBlob, err := repository.LookupBlob(inputEntry.Id) + inputBlob, err := repo.LookupBlob(inputEntry.Id) if err != nil { return nil, base.ErrorWithCategory( ErrInternalGit, @@ -423,7 +430,7 @@ func extractExampleCases( } defer inputBlob.Free() - outputBlob, err := repository.LookupBlob(outputEntry.Id) + outputBlob, err := repo.LookupBlob(outputEntry.Id) if err != nil { return nil, base.ErrorWithCategory( ErrInternalGit, @@ -459,7 +466,7 @@ func extractExampleCases( ) } - statementsTree, err := repository.LookupTree(entry.Id) + statementsTree, err := repo.LookupTree(entry.Id) if err != nil { return nil, base.ErrorWithCategory( ErrInternalGit, @@ -479,7 +486,7 @@ func extractExampleCases( continue } - statementBlob, err := repository.LookupBlob(statementEntry.Id) + statementBlob, err := repo.LookupBlob(statementEntry.Id) if err != nil { if git.IsErrorCode(err, git.ErrorCodeNotFound) { continue @@ -507,14 +514,15 @@ func extractExampleCases( func validateUpdateMaster( ctx context.Context, - repository *git.Repository, + repo *git.Repository, newCommit *git.Commit, allowDirectPush bool, hardOverallWallTimeLimit base.Duration, interactiveSettingsCompiler InteractiveSettingsCompiler, log log15.Logger, ) error { - it, err := repository.NewReferenceIteratorGlob("refs/changes/*") + defer tracing.FromContext(ctx).StartSegment("validateUpdateMaster").End() + it, err := repo.NewReferenceIteratorGlob("refs/changes/*") if err != nil { return base.ErrorWithCategory( ErrInternalGit, @@ -579,7 +587,7 @@ func validateUpdateMaster( errors.New("statements/ directory is not a tree"), ) } - statementsTree, err := repository.LookupTree(statementsTreeEntry.Id) + statementsTree, err := repo.LookupTree(statementsTreeEntry.Id) if err != nil { return base.ErrorWithCategory( ErrInternalGit, @@ -602,7 +610,7 @@ func validateUpdateMaster( } // Validate and re-generate the problem settings. - problemSettings, err := getProblemSettings(repository, tree) + problemSettings, err := getProblemSettings(ctx, repo, tree) if err != nil { // getProblemSettings already wrapped the error correctly. return err @@ -617,7 +625,7 @@ func validateUpdateMaster( errors.New("tests/ directory is not a tree"), ) } - testsTree, err := repository.LookupTree(testsTreeEntry.Id) + testsTree, err := repo.LookupTree(testsTreeEntry.Id) if err != nil { return base.ErrorWithCategory( ErrInternalGit, @@ -636,7 +644,7 @@ func validateUpdateMaster( errors.New("tests/tests.json is missing"), ) } - testSettingsJSONBlob, err := repository.LookupBlob(testSettingsJSONEntry.Id) + testSettingsJSONBlob, err := repo.LookupBlob(testSettingsJSONEntry.Id) if err != nil { return base.ErrorWithCategory( ErrInternalGit, @@ -731,7 +739,7 @@ func validateUpdateMaster( errors.New("interactive/ directory is not a tree"), ) } - interactiveTree, err := repository.LookupTree(interactiveTreeEntry.Id) + interactiveTree, err := repo.LookupTree(interactiveTreeEntry.Id) if err != nil { return base.ErrorWithCategory( ErrInternalGit, @@ -800,7 +808,7 @@ func validateUpdateMaster( ) } if distribLang == "" { - mainSourceBlob, err := repository.LookupBlob(mainSourceOid) + mainSourceBlob, err := repo.LookupBlob(mainSourceOid) if err != nil { return base.ErrorWithCategory( ErrInteractiveBadLayout, @@ -828,7 +836,7 @@ func validateUpdateMaster( ), ) } else { - mainDistribSourceBlob, err := repository.LookupBlob(mainDistribSourceOid) + mainDistribSourceBlob, err := repo.LookupBlob(mainDistribSourceOid) if err != nil { return base.ErrorWithCategory( ErrInternalGit, @@ -844,7 +852,7 @@ func validateUpdateMaster( mainDistribSourceContents = mainDistribSourceBlob.Contents() } - idlFileBlob, err := repository.LookupBlob(idlFileOid) + idlFileBlob, err := repo.LookupBlob(idlFileOid) if err != nil { return base.ErrorWithCategory( ErrInternalGit, @@ -947,7 +955,7 @@ func validateUpdateMaster( Tolerance: problemSettings.Validator.Tolerance, }, } - if problemDistribSettings.Cases, err = extractExampleCases(repository, tree); err != nil { + if problemDistribSettings.Cases, err = extractExampleCases(ctx, repo, tree); err != nil { // extractExampleCases already wrapped the error correctly. return err } @@ -961,7 +969,7 @@ func validateUpdateMaster( fmt.Sprintf("validator.distrib.%s", *problemSettings.Validator.Lang), ) if validatorDistribTreeEntry != nil { - validatorDistribBlob, err := repository.LookupBlob(validatorDistribTreeEntry.Id) + validatorDistribBlob, err := repo.LookupBlob(validatorDistribTreeEntry.Id) if err != nil { return base.ErrorWithCategory( ErrInternalGit, @@ -1001,14 +1009,15 @@ func validateUpdateMaster( return nil } -func validateUpdatePublished(repository *git.Repository, newCommit *git.Commit) error { - head, err := repository.Head() +func validateUpdatePublished(ctx context.Context, repo *git.Repository, newCommit *git.Commit) error { + defer tracing.FromContext(ctx).StartSegment("validateUpdatePublished").End() + head, err := repo.Head() if err != nil { // The master branch has not been yet created. return ErrPublishedNotFromMaster } defer head.Free() - descendant, err := repository.DescendantOf(head.Target(), newCommit.Id()) + descendant, err := repo.DescendantOf(head.Target(), newCommit.Id()) if err != nil { return base.ErrorWithCategory( ErrInternalGit, @@ -1027,7 +1036,12 @@ func validateUpdatePublished(repository *git.Repository, newCommit *git.Commit) return nil } -func (p *gitProtocol) validateUpdateConfig(repository *git.Repository, oldCommit, newCommit *git.Commit) error { +func (p *gitProtocol) validateUpdateConfig( + ctx context.Context, + repo *git.Repository, + oldCommit, newCommit *git.Commit, +) error { + defer tracing.FromContext(ctx).StartSegment("validateUpdateConfig").End() newTree, err := newCommit.Tree() if err != nil { return base.ErrorWithCategory( @@ -1058,7 +1072,7 @@ func (p *gitProtocol) validateUpdateConfig(repository *git.Repository, oldCommit errors.New("refs/meta/config can only contain a single config.json file"), ) } - configBlob, err := repository.LookupBlob(treeEntry.Id) + configBlob, err := repo.LookupBlob(treeEntry.Id) if err != nil { return base.ErrorWithCategory( ErrInternalGit, @@ -1097,7 +1111,8 @@ func (p *gitProtocol) validateUpdateConfig(repository *git.Repository, oldCommit return nil } -func validateUpdateReview(repository *git.Repository, oldCommit, newCommit *git.Commit) error { +func validateUpdateReview(ctx context.Context, repo *git.Repository, oldCommit, newCommit *git.Commit) error { + defer tracing.FromContext(ctx).StartSegment("validateUpdateReview").End() iterationUUID := "" for _, line := range strings.Split(newCommit.Message(), "\n") { @@ -1162,7 +1177,7 @@ func validateUpdateReview(repository *git.Repository, oldCommit, newCommit *git. ) } - reviewBlob, err := repository.LookupBlob(treeEntry.Id) + reviewBlob, err := repo.LookupBlob(treeEntry.Id) if err != nil { return base.ErrorWithCategory( ErrInternalGit, @@ -1209,7 +1224,7 @@ func validateUpdateReview(repository *git.Repository, oldCommit, newCommit *git. ), ) } - masterCommit, err := repository.LookupCommit(masterCommitOid) + masterCommit, err := repo.LookupCommit(masterCommitOid) if err != nil { return base.ErrorWithCategory( ErrReviewBadLayout, @@ -1264,7 +1279,7 @@ func validateUpdateReview(repository *git.Repository, oldCommit, newCommit *git. newEntry = ledgerEntry } - reviewBlob, err := repository.LookupBlob(treeEntry.Id) + reviewBlob, err := repo.LookupBlob(treeEntry.Id) if err != nil { return base.ErrorWithCategory( ErrInternalGit, @@ -1403,9 +1418,11 @@ func validateUpdateReview(repository *git.Repository, oldCommit, newCommit *git. } func (p *gitProtocol) validateChange( - repository *git.Repository, + ctx context.Context, + repo *git.Repository, oldCommit, newCommit *git.Commit, ) error { + defer tracing.FromContext(ctx).StartSegment("validateChange").End() newTree, err := newCommit.Tree() if err != nil { return base.ErrorWithCategory( @@ -1439,7 +1456,7 @@ func (p *gitProtocol) validateChange( if treeEntry == nil || treeEntry.Type != git.ObjectBlob { return ErrChangeMissingSettingsJSON } - settingsBlob, err := repository.LookupBlob(treeEntry.Id) + settingsBlob, err := repo.LookupBlob(treeEntry.Id) if err != nil { return base.ErrorWithCategory( ErrInternalGit, @@ -1470,11 +1487,12 @@ func (p *gitProtocol) validateChange( func (p *gitProtocol) validateUpdate( ctx context.Context, - repository *git.Repository, + repo *git.Repository, level githttp.AuthorizationLevel, command *githttp.GitCommand, oldCommit, newCommit *git.Commit, ) error { + defer tracing.FromContext(ctx).StartSegment("validateUpdate").End() requestContext := request.FromContext(ctx) p.log.Info( @@ -1494,7 +1512,7 @@ func (p *gitProtocol) validateUpdate( // Since we allow non-fast-forward refs globally, we need to check if the // published branch is the one being updated. if command.ReferenceName != "refs/heads/published" && - !githttp.ValidateFastForward(repository, newCommit, command.Reference) { + !githttp.ValidateFastForward(repo, newCommit, command.Reference) { p.log.Error( "non-fast-forward is not allowed for this branch", "ref", command.ReferenceName, @@ -1544,7 +1562,7 @@ func (p *gitProtocol) validateUpdate( } return validateUpdateMaster( ctx, - repository, + repo, newCommit, p.allowDirectPushToMaster, p.hardOverallWallTimeLimit, @@ -1560,7 +1578,7 @@ func (p *gitProtocol) validateUpdate( ) return githttp.ErrForbidden } - return validateUpdatePublished(repository, newCommit) + return validateUpdatePublished(ctx, repo, newCommit) } else if command.ReferenceName == "refs/meta/config" { if !requestContext.Request.IsAdmin { p.log.Error( @@ -1570,7 +1588,7 @@ func (p *gitProtocol) validateUpdate( ) return githttp.ErrForbidden } - return p.validateUpdateConfig(repository, oldCommit, newCommit) + return p.validateUpdateConfig(ctx, repo, oldCommit, newCommit) } else if command.ReferenceName == "refs/meta/review" { if !requestContext.Request.CanEdit && !requestContext.Request.HasSolved { p.log.Error( @@ -1580,7 +1598,7 @@ func (p *gitProtocol) validateUpdate( ) return githttp.ErrForbidden } - return validateUpdateReview(repository, oldCommit, newCommit) + return validateUpdateReview(ctx, repo, oldCommit, newCommit) } if !requestContext.Request.CanEdit && !requestContext.Request.HasSolved { @@ -1591,17 +1609,19 @@ func (p *gitProtocol) validateUpdate( ) return githttp.ErrForbidden } - return p.validateChange(repository, oldCommit, newCommit) + return p.validateChange(ctx, repo, oldCommit, newCommit) } func (p *gitProtocol) preprocessMaster( ctx context.Context, - originalRepository *git.Repository, + originalRepo *git.Repository, tmpDir string, originalPackPath string, originalCommands []*githttp.GitCommand, ) (string, []*githttp.GitCommand, error) { - originalCommit, err := originalRepository.LookupCommit(originalCommands[0].New) + txn := tracing.FromContext(ctx) + defer txn.StartSegment("preprocessMaster").End() + originalCommit, err := originalRepo.LookupCommit(originalCommands[0].New) if err != nil { return originalPackPath, originalCommands, base.ErrorWithCategory( ErrInternalGit, @@ -1622,7 +1642,7 @@ func (p *gitProtocol) preprocessMaster( }) description := &commitDescriptions[len(commitDescriptions)-1] - ref, err := originalRepository.References.Lookup(description.ReferenceName) + ref, err := originalRepo.References.Lookup(description.ReferenceName) if err != nil { if git.IsErrorCode(err, git.ErrorCodeNotFound) { continue @@ -1639,7 +1659,7 @@ func (p *gitProtocol) preprocessMaster( defer ref.Free() description.Reference = ref - commit, err := originalRepository.LookupCommit(ref.Target()) + commit, err := originalRepo.LookupCommit(ref.Target()) if err != nil { return originalPackPath, originalCommands, base.ErrorWithCategory( ErrInternalGit, @@ -1655,7 +1675,7 @@ func (p *gitProtocol) preprocessMaster( description.ParentCommit = commit } - masterRef, err := originalRepository.References.Lookup("refs/heads/master") + masterRef, err := originalRepo.References.Lookup("refs/heads/master") var masterCommit *git.Commit if err != nil && !git.IsErrorCode(err, git.ErrorCodeNotFound) { return originalPackPath, originalCommands, base.ErrorWithCategory( @@ -1669,7 +1689,7 @@ func (p *gitProtocol) preprocessMaster( if masterRef != nil { defer masterRef.Free() - masterCommit, err = originalRepository.LookupCommit(masterRef.Target()) + masterCommit, err = originalRepo.LookupCommit(masterRef.Target()) if err != nil { return originalPackPath, originalCommands, base.ErrorWithCategory( ErrInternalGit, @@ -1691,8 +1711,9 @@ func (p *gitProtocol) preprocessMaster( } newPackPath := filepath.Join(tmpDir, "new.pack") + spliceCommitSegment := txn.StartSegment("SpliceCommit") newCommands, err := githttp.SpliceCommit( - originalRepository, + originalRepo, originalCommit, masterCommit, requestContext.UpdatedFiles, @@ -1705,6 +1726,7 @@ func (p *gitProtocol) preprocessMaster( newPackPath, p.log, ) + spliceCommitSegment.End() if err != nil { return originalPackPath, originalCommands, base.ErrorWithCategory( ErrInternalGit, @@ -1719,14 +1741,15 @@ func (p *gitProtocol) preprocessMaster( func (p *gitProtocol) preprocess( ctx context.Context, - originalRepository *git.Repository, + originalRepo *git.Repository, tmpDir string, originalPackPath string, originalCommands []*githttp.GitCommand, ) (string, []*githttp.GitCommand, error) { + defer tracing.FromContext(ctx).StartSegment("preprocess").End() p.log.Info("Updating", "reference", originalCommands) if originalCommands[0].ReferenceName == "refs/heads/master" { - return p.preprocessMaster(ctx, originalRepository, tmpDir, originalPackPath, originalCommands) + return p.preprocessMaster(ctx, originalRepo, tmpDir, originalPackPath, originalCommands) } return originalPackPath, originalCommands, nil } @@ -1761,8 +1784,11 @@ func NewGitHandler(opts GitHandlerOpts) http.Handler { // InitRepository is a wrapper around git.CreateRepository() that also adds // omegaUp-specific files to the repository. func InitRepository( + ctx context.Context, repositoryPath string, ) (*git.Repository, error) { + defer tracing.FromContext(ctx).StartSegment("InitRepository").End() + repo, err := git.InitRepository(repositoryPath, true) if err != nil { return nil, base.ErrorWithCategory( diff --git a/handler_test.go b/handler_test.go index d70db8b..99a81c4 100644 --- a/handler_test.go +++ b/handler_test.go @@ -288,6 +288,7 @@ func TestInvalidRef(t *testing.T) { if os.Getenv("PRESERVE") == "" { defer os.RemoveAll(tmpDir) } + ctx := context.Background() log := base.StderrLog(false) ts := httptest.NewServer(NewGitHandler(GitHandlerOpts{ @@ -307,7 +308,7 @@ func TestInvalidRef(t *testing.T) { problemAlias := "sumas" { - repo, err := InitRepository(path.Join(tmpDir, problemAlias)) + repo, err := InitRepository(ctx, path.Join(tmpDir, problemAlias)) if err != nil { t.Fatalf("Failed to initialize git repository: %v", err) } @@ -366,6 +367,7 @@ func TestDelete(t *testing.T) { if os.Getenv("PRESERVE") == "" { defer os.RemoveAll(tmpDir) } + ctx := context.Background() log := base.StderrLog(false) ts := httptest.NewServer(NewGitHandler(GitHandlerOpts{ @@ -385,7 +387,7 @@ func TestDelete(t *testing.T) { problemAlias := "sumas" { - repo, err := InitRepository(path.Join(tmpDir, problemAlias)) + repo, err := InitRepository(ctx, path.Join(tmpDir, problemAlias)) if err != nil { t.Fatalf("Failed to initialize git repository: %v", err) } @@ -447,6 +449,7 @@ func TestServerCreateReview(t *testing.T) { if os.Getenv("PRESERVE") == "" { defer os.RemoveAll(tmpDir) } + ctx := context.Background() log := base.StderrLog(false) ts := httptest.NewServer(NewGitHandler(GitHandlerOpts{ @@ -466,7 +469,7 @@ func TestServerCreateReview(t *testing.T) { problemAlias := "sumas" { - repo, err := InitRepository(path.Join(tmpDir, problemAlias)) + repo, err := InitRepository(ctx, path.Join(tmpDir, problemAlias)) if err != nil { t.Fatalf("Failed to initialize git repository: %v", err) } @@ -1242,6 +1245,7 @@ func TestPushGitbomb(t *testing.T) { if os.Getenv("PRESERVE") == "" { defer os.RemoveAll(tmpDir) } + ctx := context.Background() log := base.StderrLog(false) ts := httptest.NewServer(NewGitHandler(GitHandlerOpts{ @@ -1261,7 +1265,7 @@ func TestPushGitbomb(t *testing.T) { problemAlias := "sumas" { - repo, err := InitRepository(path.Join(tmpDir, problemAlias)) + repo, err := InitRepository(ctx, path.Join(tmpDir, problemAlias)) if err != nil { t.Fatalf("Failed to initialize git repository: %v", err) } @@ -1365,6 +1369,7 @@ func TestConfig(t *testing.T) { if os.Getenv("PRESERVE") == "" { defer os.RemoveAll(tmpDir) } + ctx := context.Background() log := base.StderrLog(false) ts := httptest.NewServer(NewGitHandler(GitHandlerOpts{ @@ -1384,7 +1389,7 @@ func TestConfig(t *testing.T) { problemAlias := "sumas" { - repo, err := InitRepository(path.Join(tmpDir, problemAlias)) + repo, err := InitRepository(ctx, path.Join(tmpDir, problemAlias)) if err != nil { t.Fatalf("Failed to initialize git repository: %v", err) } @@ -1718,6 +1723,7 @@ func TestInteractive(t *testing.T) { if os.Getenv("PRESERVE") == "" { defer os.RemoveAll(tmpDir) } + ctx := context.Background() log := base.StderrLog(false) ts := httptest.NewServer(NewGitHandler(GitHandlerOpts{ @@ -1747,7 +1753,7 @@ func TestInteractive(t *testing.T) { problemAlias := "sumas" - repo, err := InitRepository(path.Join(tmpDir, problemAlias)) + repo, err := InitRepository(ctx, path.Join(tmpDir, problemAlias)) if err != nil { t.Fatalf("Failed to initialize git repository: %v", err) } @@ -1837,6 +1843,7 @@ int main(int argc, char* argv[]) { defer masterTree.Free() problemSettings, err := getProblemSettings( + ctx, repo, masterTree, ) @@ -1887,6 +1894,7 @@ func TestExampleCases(t *testing.T) { if os.Getenv("PRESERVE") == "" { defer os.RemoveAll(tmpDir) } + ctx := context.Background() log := base.StderrLog(false) ts := httptest.NewServer(NewGitHandler(GitHandlerOpts{ @@ -1906,7 +1914,7 @@ func TestExampleCases(t *testing.T) { problemAlias := "sumas" - repo, err := InitRepository(path.Join(tmpDir, problemAlias)) + repo, err := InitRepository(ctx, path.Join(tmpDir, problemAlias)) if err != nil { t.Fatalf("Failed to initialize git repository: %v", err) } @@ -2219,6 +2227,7 @@ func TestStatements(t *testing.T) { if os.Getenv("PRESERVE") == "" { defer os.RemoveAll(tmpDir) } + ctx := context.Background() log := base.StderrLog(false) ts := httptest.NewServer(NewGitHandler(GitHandlerOpts{ @@ -2238,7 +2247,7 @@ func TestStatements(t *testing.T) { problemAlias := "sumas" - repo, err := InitRepository(path.Join(tmpDir, problemAlias)) + repo, err := InitRepository(ctx, path.Join(tmpDir, problemAlias)) if err != nil { t.Fatalf("Failed to initialize git repository: %v", err) } @@ -2320,6 +2329,7 @@ func TestTests(t *testing.T) { if os.Getenv("PRESERVE") == "" { defer os.RemoveAll(tmpDir) } + ctx := context.Background() log := base.StderrLog(false) ts := httptest.NewServer(NewGitHandler(GitHandlerOpts{ @@ -2339,7 +2349,7 @@ func TestTests(t *testing.T) { problemAlias := "sumas" - repo, err := InitRepository(path.Join(tmpDir, problemAlias)) + repo, err := InitRepository(ctx, path.Join(tmpDir, problemAlias)) if err != nil { t.Fatalf("Failed to initialize git repository: %v", err) } diff --git a/ziphandler.go b/ziphandler.go index 52dbb5b..c976ed7 100644 --- a/ziphandler.go +++ b/ziphandler.go @@ -182,9 +182,11 @@ type UpdateResult struct { } func getAllFilesForCommit( + ctx context.Context, repo *git.Repository, commitID *git.Oid, ) (map[string]*git.Oid, error) { + defer tracing.FromContext(ctx).StartSegment("getAllFilesForCommit").End() if commitID.IsZero() { return map[string]*git.Oid{}, nil } @@ -240,9 +242,11 @@ func getAllFilesForCommit( // GetUpdatedFiles returns the files that were updated in the master branch. func GetUpdatedFiles( + ctx context.Context, repo *git.Repository, updatedRefs []githttp.UpdatedRef, ) ([]UpdatedFile, error) { + defer tracing.FromContext(ctx).StartSegment("GetUpdatedFiles").End() var masterUpdatedRef *githttp.UpdatedRef for _, updatedRef := range updatedRefs { if updatedRef.Name != "refs/heads/master" { @@ -283,7 +287,7 @@ func GetUpdatedFiles( ) } - fromIDs, err := getAllFilesForCommit(repo, fromCommitID) + fromIDs, err := getAllFilesForCommit(ctx, repo, fromCommitID) if err != nil { return nil, base.ErrorWithCategory( ErrInternalGit, @@ -294,7 +298,7 @@ func GetUpdatedFiles( ), ) } - toIDs, err := getAllFilesForCommit(repo, toCommitID) + toIDs, err := getAllFilesForCommit(ctx, repo, toCommitID) if err != nil { return nil, base.ErrorWithCategory( ErrInternalGit, @@ -355,6 +359,7 @@ func isValidProblemFile(filename string) bool { // specified contents plus a subset of the parent commit's tree, depending of // the value of zipMergeStrategy. func CreatePackfile( + ctx context.Context, contents map[string]io.Reader, settings *common.ProblemSettings, zipMergeStrategy ZipMergeStrategy, @@ -365,6 +370,7 @@ func CreatePackfile( w io.Writer, log log15.Logger, ) (*git.Oid, error) { + defer tracing.FromContext(ctx).StartSegment("CreatePackfile").End() odb, err := repo.Odb() if err != nil { return nil, base.ErrorWithCategory( @@ -866,10 +872,12 @@ func CreatePackfile( } func getUpdatedProblemSettings( + ctx context.Context, problemSettings *common.ProblemSettings, repo *git.Repository, parent *git.Oid, ) (*common.ProblemSettings, error) { + defer tracing.FromContext(ctx).StartSegment("getUpdatedProblemSettings").End() parentCommit, err := repo.LookupCommit(parent) if err != nil { return nil, base.ErrorWithCategory( @@ -938,6 +946,7 @@ func getUpdatedProblemSettings( // ConvertZipToPackfile receives a .zip file from the caller and converts it // into a git packfile that can be used to update the repository. func ConvertZipToPackfile( + ctx context.Context, problemFiles common.ProblemFiles, settings *common.ProblemSettings, zipMergeStrategy ZipMergeStrategy, @@ -949,6 +958,7 @@ func ConvertZipToPackfile( w io.Writer, log log15.Logger, ) (*git.Oid, error) { + defer tracing.FromContext(ctx).StartSegment("ConvertZipToPackfile").End() contents := make(map[string]io.Reader) inCases := make(map[string]struct{}) @@ -1025,6 +1035,7 @@ func ConvertZipToPackfile( if settings != nil { var err error if settings, err = getUpdatedProblemSettings( + ctx, settings, repo, parent, @@ -1034,6 +1045,7 @@ func ConvertZipToPackfile( } return CreatePackfile( + ctx, contents, settings, zipMergeStrategy, @@ -1091,6 +1103,7 @@ func ConvertZipToPackfile( ) return CreatePackfile( + ctx, contents, settings, zipMergeStrategy, @@ -1122,6 +1135,7 @@ func PushZip( protocol *githttp.GitProtocol, log log15.Logger, ) (*UpdateResult, error) { + defer tracing.FromContext(ctx).StartSegment("PushZip").End() oldOid := &git.Oid{} var reference *git.Reference if ok, _ := repo.IsHeadUnborn(); !ok { @@ -1153,6 +1167,7 @@ func PushZip( defer os.Remove(packfile.Name()) newOid, err := ConvertZipToPackfile( + ctx, problemFiles, problemSettings, zipMergeStrategy, @@ -1202,7 +1217,7 @@ func PushZip( return nil, err } - updatedFiles, err := GetUpdatedFiles(repo, updatedRefs) + updatedFiles, err := GetUpdatedFiles(ctx, repo, updatedRefs) if err != nil { return nil, errors.Wrap( err, @@ -1403,12 +1418,14 @@ func (h *zipUploadHandler) handleGitUploadZip( } var repo *git.Repository + openRepoSegment := txn.StartSegment("open repository") commitCallback := func() error { return nil } if requestContext.Request.Create { dir, err := ioutil.TempDir(filepath.Dir(repositoryPath), "repository") if err != nil { h.log.Error("Failed to create temporary directory", "err", err) w.WriteHeader(http.StatusInternalServerError) + openRepoSegment.End() return } defer os.RemoveAll(dir) @@ -1416,13 +1433,15 @@ func (h *zipUploadHandler) handleGitUploadZip( if err := os.Chmod(dir, 0755); err != nil { h.log.Error("Failed to chmod temporary directory", "err", err) w.WriteHeader(http.StatusInternalServerError) + openRepoSegment.End() return } - repo, err = InitRepository(dir) + repo, err = InitRepository(ctx, dir) if err != nil { h.log.Error("failed to init repository", "err", err) w.WriteHeader(http.StatusInternalServerError) + openRepoSegment.End() return } commitCallback = func() error { @@ -1433,9 +1452,11 @@ func (h *zipUploadHandler) handleGitUploadZip( if err != nil { h.log.Error("failed to open repository", "err", err) w.WriteHeader(http.StatusInternalServerError) + openRepoSegment.End() return } } + openRepoSegment.End() defer repo.Free() acquireLockSegment := txn.StartSegment("acquire lock") diff --git a/ziphandler_test.go b/ziphandler_test.go index e1db17c..05a63ff 100644 --- a/ziphandler_test.go +++ b/ziphandler_test.go @@ -2,6 +2,7 @@ package gitserver import ( "bytes" + "context" "encoding/json" "fmt" "io" @@ -235,10 +236,11 @@ func TestConvertZip(t *testing.T) { if os.Getenv("PRESERVE") == "" { defer os.RemoveAll(tmpDir) } + ctx := context.Background() problemAlias := "sumas" - repo, err := InitRepository(path.Join(tmpDir, problemAlias)) + repo, err := InitRepository(ctx, path.Join(tmpDir, problemAlias)) if err != nil { t.Fatalf("Failed to initialize git repository: %v", err) } @@ -259,6 +261,7 @@ func TestConvertZip(t *testing.T) { commitMessage := "Initial commit" zipOid, err := ConvertZipToPackfile( + ctx, common.NewProblemFilesFromMap( fileContents, "problem.zip", @@ -473,10 +476,11 @@ func TestZiphandlerStatements(t *testing.T) { if os.Getenv("PRESERVE") == "" { defer os.RemoveAll(tmpDir) } + ctx := context.Background() problemAlias := "sumas" - repo, err := InitRepository(path.Join(tmpDir, problemAlias)) + repo, err := InitRepository(ctx, path.Join(tmpDir, problemAlias)) if err != nil { t.Fatalf("Failed to initialize git repository: %v", err) } @@ -516,6 +520,7 @@ func TestZiphandlerStatements(t *testing.T) { commitMessage := "Initial commit" _, err = ConvertZipToPackfile( + ctx, common.NewProblemFilesFromMap( testcase.fileContents, "problem.zip", @@ -556,10 +561,11 @@ func TestTestplan(t *testing.T) { if os.Getenv("PRESERVE") == "" { defer os.RemoveAll(tmpDir) } + ctx := context.Background() problemAlias := "sumas" - repo, err := InitRepository(path.Join(tmpDir, problemAlias)) + repo, err := InitRepository(ctx, path.Join(tmpDir, problemAlias)) if err != nil { t.Fatalf("Failed to initialize git repository: %v", err) } @@ -587,6 +593,7 @@ func TestTestplan(t *testing.T) { commitMessage := "Initial commit" _, err = ConvertZipToPackfile( + ctx, common.NewProblemFilesFromMap( fileContents, "problem.zip",