internal/worker: add verbose logging to /poll to diagnose failures

Change-Id: I89c4c20ec23d2de4e46734e0eb70d70eae5dc3cc
Reviewed-on: https://go-review.googlesource.com/c/pkgsite/+/522241
Run-TryBot: Robert Findley <rfindley@google.com>
kokoro-CI: kokoro <noreply+kokoro@google.com>
Reviewed-by: Jamal Carvalho <jamal@golang.org>
TryBot-Result: Gopher Robot <gobot@golang.org>
diff --git a/internal/worker/server.go b/internal/worker/server.go
index bb2a2b0..9f7416e 100644
--- a/internal/worker/server.go
+++ b/internal/worker/server.go
@@ -418,19 +418,30 @@
 func (s *Server) handlePollIndex(w http.ResponseWriter, r *http.Request) (err error) {
 	defer derrors.Wrap(&err, "handlePollIndex(%q)", r.URL.Path)
 	ctx := r.Context()
+	if deadline, ok := ctx.Deadline(); ok {
+		log.Infof(ctx, "polling at %v with deadline %v", time.Now(), deadline)
+	}
+
+	// log.Infof(ctx, "", limit)
 	limit := parseLimitParam(r, 10)
+	log.Infof(ctx, "got limit %v; getting the latest index timestamp", limit)
 	since, err := s.db.LatestIndexTimestamp(ctx)
 	if err != nil {
+		log.Errorf(ctx, "failed to get timestamp: %v", err)
 		return err
 	}
+	log.Infof(ctx, "last timestamp was %v; querying versions from the index", since)
 	modules, err := s.indexClient.GetVersions(ctx, since, limit)
 	if err != nil {
+		log.Errorf(ctx, "failed to get versions: %v", err)
 		return err
 	}
+	log.Infof(ctx, "found %v modules from the index; inserting them into the database", len(modules))
 	if err := s.db.InsertIndexVersions(ctx, modules); err != nil {
+		log.Errorf(ctx, "failed to insert into the database: %v", err)
 		return err
 	}
-	log.Infof(ctx, "Inserted %d modules from the index", len(modules))
+	log.Infof(ctx, "inserted %d modules from the index", len(modules))
 	s.computeProcessingLag(ctx)
 	s.computeUnprocessedModules(ctx)
 	recordWorkerDBInfo(ctx, s.workerDBInfo())