internal/{frontend,postgres}: gather timing stats

Collect the elapsed time for various functions on the serving path of
the unit page.

Change-Id: Ib4d16f9ad84532f4870f360566e6ed30554a1357
Reviewed-on: https://go-review.googlesource.com/c/pkgsite/+/262578
Trust: Jonathan Amsterdam <jba@google.com>
Run-TryBot: Jonathan Amsterdam <jba@google.com>
TryBot-Result: kokoro <noreply+kokoro@google.com>
Reviewed-by: Julie Qiu <julie@golang.org>
diff --git a/internal/frontend/details.go b/internal/frontend/details.go
index 79c31d1..1b80e43 100644
--- a/internal/frontend/details.go
+++ b/internal/frontend/details.go
@@ -22,6 +22,7 @@
 	"golang.org/x/pkgsite/internal/derrors"
 	"golang.org/x/pkgsite/internal/experiment"
 	"golang.org/x/pkgsite/internal/log"
+	"golang.org/x/pkgsite/internal/middleware"
 	"golang.org/x/pkgsite/internal/postgres"
 	"golang.org/x/pkgsite/internal/stdlib"
 )
@@ -92,6 +93,8 @@
 // stdlib module pages are handled at "/std", and requests to "/mod/std" will
 // be redirected to that path.
 func (s *Server) serveDetails(w http.ResponseWriter, r *http.Request, ds internal.DataSource) (err error) {
+	defer middleware.ElapsedStat(r.Context(), "serveDetails")()
+
 	if r.Method != http.MethodGet {
 		return &serverError{status: http.StatusMethodNotAllowed}
 	}
diff --git a/internal/frontend/doc.go b/internal/frontend/doc.go
index 9b5f02e..c81eef5 100644
--- a/internal/frontend/doc.go
+++ b/internal/frontend/doc.go
@@ -17,6 +17,7 @@
 	"golang.org/x/pkgsite/internal/experiment"
 	"golang.org/x/pkgsite/internal/godoc"
 	"golang.org/x/pkgsite/internal/log"
+	"golang.org/x/pkgsite/internal/middleware"
 	"golang.org/x/pkgsite/internal/stdlib"
 )
 
@@ -51,6 +52,8 @@
 
 func renderDoc(ctx context.Context, u *internal.Unit) (_ *DocumentationDetails, err error) {
 	defer derrors.Wrap(&err, "renderDoc")
+	defer middleware.ElapsedStat(ctx, "renderDoc")()
+
 	start := time.Now()
 	docPkg, err := godoc.DecodePackage(u.Documentation.Source)
 	if err != nil {
diff --git a/internal/frontend/server.go b/internal/frontend/server.go
index 59b6296..2b79738 100644
--- a/internal/frontend/server.go
+++ b/internal/frontend/server.go
@@ -412,6 +412,8 @@
 
 // servePage is used to execute all templates for a *Server.
 func (s *Server) servePage(ctx context.Context, w http.ResponseWriter, templateName string, page interface{}) {
+	defer middleware.ElapsedStat(ctx, "servePage")()
+
 	buf, err := s.renderPage(ctx, templateName, page)
 	if err != nil {
 		log.Errorf(ctx, "s.renderPage(%q, %+v): %v", templateName, page, err)
@@ -426,6 +428,8 @@
 
 // renderPage executes the given templateName with page.
 func (s *Server) renderPage(ctx context.Context, templateName string, page interface{}) ([]byte, error) {
+	defer middleware.ElapsedStat(ctx, "renderPage")()
+
 	tmpl, err := s.findTemplate(templateName)
 	if err != nil {
 		return nil, err
diff --git a/internal/frontend/unit_main.go b/internal/frontend/unit_main.go
index f43aa68..76c8050 100644
--- a/internal/frontend/unit_main.go
+++ b/internal/frontend/unit_main.go
@@ -15,6 +15,7 @@
 	"golang.org/x/pkgsite/internal/experiment"
 	"golang.org/x/pkgsite/internal/godoc"
 	"golang.org/x/pkgsite/internal/log"
+	"golang.org/x/pkgsite/internal/middleware"
 	"golang.org/x/pkgsite/internal/postgres"
 )
 
@@ -79,6 +80,8 @@
 }
 
 func fetchMainDetails(ctx context.Context, ds internal.DataSource, um *internal.UnitMeta, expandReadme bool) (_ *MainDetails, err error) {
+	defer middleware.ElapsedStat(ctx, "fetchMainDetails")()
+
 	unit, err := ds.GetUnit(ctx, um, internal.WithReadme|internal.WithDocumentation|internal.WithSubdirectories|internal.WithImports)
 	if err != nil {
 		return nil, err
@@ -123,6 +126,8 @@
 		// TODO: Deprecate godoc.Parse. The sidenav and body can
 		// either be rendered using separate functions, or all this content can
 		// be passed to the template via the UnitPage struct.
+		end := middleware.ElapsedStat(ctx, "godoc Parses")
+
 		b, err := godoc.Parse(docHTML, godoc.BodySection)
 		if err != nil {
 			return nil, err
@@ -138,8 +143,11 @@
 			return nil, err
 		}
 		mobileOutline = m
+		end()
 
+		end = middleware.ElapsedStat(ctx, "sourceFiles")
 		files, err = sourceFiles(unit)
+		end()
 		if err != nil {
 			return nil, err
 		}
@@ -176,6 +184,8 @@
 
 // readmeContent renders the readme to html.
 func readmeContent(ctx context.Context, um *internal.UnitMeta, readme *internal.Readme) (safehtml.HTML, error) {
+	defer middleware.ElapsedStat(ctx, "readmeContent")()
+
 	if um.IsRedistributable && readme != nil {
 		mi := moduleInfo(um)
 		readme, err := ReadmeHTML(ctx, mi, readme)
diff --git a/internal/postgres/details.go b/internal/postgres/details.go
index 37006fe..4de0dad 100644
--- a/internal/postgres/details.go
+++ b/internal/postgres/details.go
@@ -17,12 +17,14 @@
 	"github.com/google/safehtml/uncheckedconversions"
 	"golang.org/x/pkgsite/internal"
 	"golang.org/x/pkgsite/internal/derrors"
+	"golang.org/x/pkgsite/internal/middleware"
 )
 
 // GetNestedModules returns the latest major version of all nested modules
 // given a modulePath path prefix with or without major version.
 func (db *DB) GetNestedModules(ctx context.Context, modulePath string) (_ []*internal.ModuleInfo, err error) {
 	defer derrors.Wrap(&err, "GetNestedModules(ctx, %v)", modulePath)
+	defer middleware.ElapsedStat(ctx, "GetNestedModules")()
 
 	query := `
 		SELECT DISTINCT ON (series_path)
@@ -74,6 +76,8 @@
 // Instead of supporting pagination, this query runs with a limit.
 func (db *DB) GetImportedBy(ctx context.Context, pkgPath, modulePath string, limit int) (paths []string, err error) {
 	defer derrors.Wrap(&err, "GetImportedBy(ctx, %q, %q)", pkgPath, modulePath)
+	defer middleware.ElapsedStat(ctx, "GetImportedBy")()
+
 	if pkgPath == "" {
 		return nil, fmt.Errorf("pkgPath cannot be empty: %w", derrors.InvalidArgument)
 	}
diff --git a/internal/postgres/licenses.go b/internal/postgres/licenses.go
index f5435b3..2f0a65b 100644
--- a/internal/postgres/licenses.go
+++ b/internal/postgres/licenses.go
@@ -16,11 +16,13 @@
 	"github.com/lib/pq"
 	"golang.org/x/pkgsite/internal/derrors"
 	"golang.org/x/pkgsite/internal/licenses"
+	"golang.org/x/pkgsite/internal/middleware"
 	"golang.org/x/pkgsite/internal/stdlib"
 )
 
 func (db *DB) getLicenses(ctx context.Context, fullPath, modulePath string, pathID int) (_ []*licenses.License, err error) {
 	defer derrors.Wrap(&err, "getLicenses(ctx, %d)", pathID)
+	defer middleware.ElapsedStat(ctx, "getLicenses")()
 
 	query := `
 		SELECT
diff --git a/internal/postgres/path.go b/internal/postgres/path.go
index d9a25c4..4fe881b 100644
--- a/internal/postgres/path.go
+++ b/internal/postgres/path.go
@@ -13,6 +13,7 @@
 	"github.com/lib/pq"
 	"golang.org/x/pkgsite/internal"
 	"golang.org/x/pkgsite/internal/derrors"
+	"golang.org/x/pkgsite/internal/middleware"
 	"golang.org/x/pkgsite/internal/stdlib"
 )
 
@@ -48,6 +49,7 @@
 // 3. In the unlikely event of two paths at the same version, pick the longer module path.
 func (db *DB) GetUnitMeta(ctx context.Context, path, requestedModulePath, requestedVersion string) (_ *internal.UnitMeta, err error) {
 	defer derrors.Wrap(&err, "DB.GetUnitMeta(ctx, %q, %q, %q)", path, requestedModulePath, requestedVersion)
+	defer middleware.ElapsedStat(ctx, "GetUnitMeta")()
 
 	var (
 		constraints []string
diff --git a/internal/postgres/unit.go b/internal/postgres/unit.go
index 2e95e85..c16a88f 100644
--- a/internal/postgres/unit.go
+++ b/internal/postgres/unit.go
@@ -16,6 +16,7 @@
 	"golang.org/x/pkgsite/internal/database"
 	"golang.org/x/pkgsite/internal/derrors"
 	"golang.org/x/pkgsite/internal/experiment"
+	"golang.org/x/pkgsite/internal/middleware"
 	"golang.org/x/pkgsite/internal/stdlib"
 )
 
@@ -24,6 +25,8 @@
 // TODO(golang/go#39629): remove pID.
 func (db *DB) GetUnit(ctx context.Context, um *internal.UnitMeta, fields internal.FieldSet) (_ *internal.Unit, err error) {
 	defer derrors.Wrap(&err, "GetUnit(ctx, %q, %q, %q)", um.Path, um.ModulePath, um.Version)
+	defer middleware.ElapsedStat(ctx, "GetUnit")()
+
 	pathID, err := db.getPathID(ctx, um.Path, um.ModulePath, um.Version)
 	if err != nil {
 		return nil, err
@@ -37,7 +40,7 @@
 		} else {
 			readme, err = db.getModuleReadme(ctx, u.ModulePath, u.Version)
 		}
-          	if err != nil && !errors.Is(err, derrors.NotFound) {
+		if err != nil && !errors.Is(err, derrors.NotFound) {
 			return nil, err
 		}
 		u.Readme = readme
@@ -82,6 +85,7 @@
 
 func (db *DB) getPathID(ctx context.Context, fullPath, modulePath, resolvedVersion string) (_ int, err error) {
 	defer derrors.Wrap(&err, "getPathID(ctx, %q, %q, %q)", fullPath, modulePath, resolvedVersion)
+	defer middleware.ElapsedStat(ctx, "getPathID")()
 	var pathID int
 	query := `
 		SELECT p.id
@@ -105,6 +109,7 @@
 // getDocumentation returns the documentation corresponding to pathID.
 func (db *DB) getDocumentation(ctx context.Context, pathID int) (_ *internal.Documentation, err error) {
 	defer derrors.Wrap(&err, "getDocumentation(ctx, %d)", pathID)
+	defer middleware.ElapsedStat(ctx, "getDocumentation")()
 	var (
 		doc     internal.Documentation
 		docHTML string
@@ -139,6 +144,7 @@
 // getReadme returns the README corresponding to the modulePath and version.
 func (db *DB) getReadme(ctx context.Context, pathID int) (_ *internal.Readme, err error) {
 	defer derrors.Wrap(&err, "getReadme(ctx, %d)", pathID)
+	defer middleware.ElapsedStat(ctx, "getReadme")()
 	var readme internal.Readme
 	err = db.db.QueryRow(ctx, `
 		SELECT file_path, contents
@@ -182,6 +188,7 @@
 // getImports returns the imports corresponding to pathID.
 func (db *DB) getImports(ctx context.Context, pathID int) (_ []string, err error) {
 	defer derrors.Wrap(&err, "getImports(ctx, %d)", pathID)
+	defer middleware.ElapsedStat(ctx, "getImports")()
 	var imports []string
 	collect := func(rows *sql.Rows) error {
 		var path string
@@ -204,6 +211,7 @@
 // module version, including the package that lives at fullPath, if present.
 func (db *DB) getPackagesInUnit(ctx context.Context, fullPath, modulePath, resolvedVersion string) (_ []*internal.PackageMeta, err error) {
 	defer derrors.Wrap(&err, "DB.getPackagesInUnit(ctx, %q, %q, %q)", fullPath, modulePath, resolvedVersion)
+	defer middleware.ElapsedStat(ctx, "getPackagesInUnit")()
 
 	query := `
 		SELECT