ref/services/identity: Print a stack trace whenever a call takes too
long.
Change-Id: I3c5c4b7df5e8f37a2bdb5a83ba0cb4d94d82bbf9
diff --git a/services/identity/internal/revocation/sql_database.go b/services/identity/internal/revocation/sql_database.go
index 482c240..0e88eda 100644
--- a/services/identity/internal/revocation/sql_database.go
+++ b/services/identity/internal/revocation/sql_database.go
@@ -8,6 +8,8 @@
"database/sql"
"encoding/hex"
"fmt"
+ "os"
+ "runtime/pprof"
"time"
)
@@ -27,22 +29,53 @@
}
func (s *sqlDatabase) InsertCaveat(thirdPartyCaveatID string, revocationCaveatID []byte) error {
- _, err := s.insertCaveatStmt.Exec(thirdPartyCaveatID, hex.EncodeToString(revocationCaveatID))
+ return dumpStackTraceIfTakingTooLong(fmt.Sprintf("InsertCaveat(%v, %v)", thirdPartyCaveatID, revocationCaveatID), func() error {
+ _, err := s.insertCaveatStmt.Exec(thirdPartyCaveatID, hex.EncodeToString(revocationCaveatID))
+ return err
+ })
+}
+
+func dumpStackTraceIfTakingTooLong(tag string, f func() error) error {
+ ch := make(chan error)
+ go dumpStack(ch, tag, time.Now())
+ err := f()
+ ch <- err
+ close(ch)
return err
}
+func dumpStack(ch chan error, tag string, start time.Time) {
+ timeout := 5 * time.Minute
+ select {
+ case <-time.After(timeout):
+ fmt.Fprintf(os.Stderr, "%v hasn't completed for %v\n", tag, time.Since(start))
+ fmt.Fprintf(os.Stderr, "Stack trace:\n")
+ pprof.Lookup("goroutine").WriteTo(os.Stderr, 2)
+ fmt.Fprintln(os.Stderr)
+ dumpStack(ch, tag, start)
+ case err := <-ch:
+ fmt.Fprintf(os.Stderr, "%v completed with %v\n", tag, err)
+ }
+}
+
func (s *sqlDatabase) Revoke(thirdPartyCaveatID string) error {
_, err := s.revokeStmt.Exec(time.Now(), thirdPartyCaveatID)
return err
}
func (s *sqlDatabase) IsRevoked(revocationCaveatID []byte) (bool, error) {
- rows, err := s.isRevokedStmt.Query(hex.EncodeToString(revocationCaveatID))
- defer rows.Close()
- if err != nil {
- return false, err
- }
- return rows.Next(), nil
+ var revoked bool
+ err := dumpStackTraceIfTakingTooLong(fmt.Sprintf("IsRevoked(%v)", revocationCaveatID), func() error {
+ rows, err := s.isRevokedStmt.Query(hex.EncodeToString(revocationCaveatID))
+ defer rows.Close()
+ if err != nil {
+ revoked = false
+ return err
+ }
+ revoked = rows.Next()
+ return nil
+ })
+ return revoked, err
}
func (s *sqlDatabase) RevocationTime(thirdPartyCaveatID string) (*time.Time, error) {