hexops / valast

Convert Go values to their AST
Other
308 stars 16 forks source link

add VALAST_PROFILE to emit performance profiling information #6

Closed slimsag closed 3 years ago

slimsag commented 3 years ago

This can be useful for debugging why some complex/nested data structures, such as those reported in https://github.com/sourcegraph/sourcegraph/pull/18189 are not being handled quickly by Valast:

$ VALAST_PROFILE=t go test -v -run='TestUnionMerge/#02' ./cmd/frontend/graphqlbackend/
=== RUN   TestUnionMerge
=== RUN   TestUnionMerge/#02
valast: profile
1242026902ns: *graphqlbackend.SearchResultsResolver
  1242001613ns: graphqlbackend.SearchResultsResolver
    1241965682ns: []graphqlbackend.SearchResultResolver
      631554070ns: *graphqlbackend.RepositoryResolver
        631552406ns: *graphqlbackend.RepositoryResolver
          631549333ns: graphqlbackend.RepositoryResolver
            631541623ns: *types.Repo
              409622256ns: types.Repo
                194531303ns: api.RepoName
      610281838ns: *graphqlbackend.RepositoryResolver
        610280747ns: *graphqlbackend.RepositoryResolver
          610277705ns: graphqlbackend.RepositoryResolver
            610242182ns: *types.Repo
              408077957ns: types.Repo
                185258694ns: api.RepoName
      7893ns: *graphqlbackend.FileMatchResolver
        7140ns: *graphqlbackend.FileMatchResolver
          5401ns: graphqlbackend.FileMatchResolver
            3438ns: graphqlbackend.FileMatch
              536ns: string
      33541ns: *graphqlbackend.FileMatchResolver
        31856ns: *graphqlbackend.FileMatchResolver
          29326ns: graphqlbackend.FileMatchResolver
            15457ns: graphqlbackend.FileMatch
              581ns: string
      7347ns: *graphqlbackend.CommitSearchResultResolver
        6671ns: *graphqlbackend.CommitSearchResultResolver
          5591ns: graphqlbackend.CommitSearchResultResolver
            509ns: string
            1856ns: *graphqlbackend.highlightedString
              702ns: graphqlbackend.highlightedString
      14634ns: *graphqlbackend.CommitSearchResultResolver
        13880ns: *graphqlbackend.CommitSearchResultResolver
          12711ns: graphqlbackend.CommitSearchResultResolver
            623ns: string
            8674ns: *graphqlbackend.highlightedString
              7160ns: graphqlbackend.highlightedString
      7210ns: *graphqlbackend.CommitSearchResultResolver
        6198ns: *graphqlbackend.CommitSearchResultResolver
          4549ns: graphqlbackend.CommitSearchResultResolver
            591ns: string
      49168ns: *graphqlbackend.CommitSearchResultResolver
        34915ns: *graphqlbackend.CommitSearchResultResolver
          27193ns: graphqlbackend.CommitSearchResultResolver
valast: profile
1246689469ns: *graphqlbackend.SearchResultsResolver
  1246683327ns: graphqlbackend.SearchResultsResolver
    1246675918ns: []graphqlbackend.SearchResultResolver
      605954511ns: *graphqlbackend.RepositoryResolver
        605951599ns: *graphqlbackend.RepositoryResolver
          605948656ns: graphqlbackend.RepositoryResolver
            605939227ns: *types.Repo
              398690970ns: types.Repo
                196774754ns: api.RepoName
      640656293ns: *graphqlbackend.RepositoryResolver
        640655289ns: *graphqlbackend.RepositoryResolver
          640647478ns: graphqlbackend.RepositoryResolver
            640634530ns: *types.Repo
              415481187ns: types.Repo
                191840428ns: api.RepoName
      11750ns: *graphqlbackend.FileMatchResolver
        11086ns: *graphqlbackend.FileMatchResolver
          9437ns: graphqlbackend.FileMatchResolver
            7961ns: graphqlbackend.FileMatch
              657ns: string
      7593ns: *graphqlbackend.FileMatchResolver
        6844ns: *graphqlbackend.FileMatchResolver
          5599ns: graphqlbackend.FileMatchResolver
            3269ns: graphqlbackend.FileMatch
              497ns: string
      10136ns: *graphqlbackend.CommitSearchResultResolver
        9470ns: *graphqlbackend.CommitSearchResultResolver
          8263ns: graphqlbackend.CommitSearchResultResolver
            484ns: string
            1711ns: *graphqlbackend.highlightedString
              530ns: graphqlbackend.highlightedString
      7516ns: *graphqlbackend.CommitSearchResultResolver
        6869ns: *graphqlbackend.CommitSearchResultResolver
          5810ns: graphqlbackend.CommitSearchResultResolver
            585ns: string
            2194ns: *graphqlbackend.highlightedString
              706ns: graphqlbackend.highlightedString
      5283ns: *graphqlbackend.CommitSearchResultResolver
        4576ns: *graphqlbackend.CommitSearchResultResolver
          3292ns: graphqlbackend.CommitSearchResultResolver
            544ns: string
      9954ns: *graphqlbackend.CommitSearchResultResolver
        8253ns: *graphqlbackend.CommitSearchResultResolver
          6366ns: graphqlbackend.CommitSearchResultResolver
--- PASS: TestUnionMerge (2.78s)
    --- PASS: TestUnionMerge/#02 (2.78s)
PASS
ok      github.com/sourcegraph/sourcegraph/cmd/frontend/graphqlbackend  3.230s

Signed-off-by: Stephen Gutekanst stephen@hexops.com