[alerts-dispatcher] update to build again :) also fixes a concurrent map access

go/src/infra/monitoring/analyzer/analyzer.go

 // Copyright 2015 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 package analyzer
 
 import (
         "errors"
         "expvar"
         "fmt"
+        "regexp"
         "sort"
         "strings"
+        "sync"
         "time"
 
         "github.com/luci/luci-go/common/logging/gologger"
 
         "infra/monitoring/client"
         "infra/monitoring/messages"
 )
 
 const (
         // StepCompletedRun is a synthetic step name used to indicate the build run is complete.
-        StepCompletedRun   = "completed run"
-        treeCloserPri      = 0
-        reliableFailureSev = 0
-        newFailureSev      = 1
-        staleMasterSev     = 0
-        staleBuilderSev    = 0
-        hungBuilderSev     = 1
-        idleBuilderSev     = 1
-        offlineBuilderSev  = 1
-        resOK              = float64(1)
-        resInfraFailure    = float64(4)
+        StepCompletedRun = "completed run"
+
+        // Order of severity, worst to least bad.
+        treeCloserSev = iota
+        staleMasterSev
+        infraFailureSev
+        reliableFailureSev
+        newFailureSev
+        staleBuilderSev
+        hungBuilderSev
+        idleBuilderSev
+        offlineBuilderSev
+
+        // Step result values.
+        resOK           = float64(1)
+        resInfraFailure = float64(4)
 )
 
 var (
         log     = gologger.Get()
         expvars = expvar.NewMap("analyzer")
+        cpRE    = regexp.MustCompile("Cr-Commit-Position: (.*)@{#([0-9]+)}")
 )
 
 var (
         errNoBuildSteps      = errors.New("No build steps")
         errNoRecentBuilds    = errors.New("No recent builds")
         errNoCompletedBuilds = errors.New("No completed builds")
 )
 
 // StepAnalyzer reasons about a stepFailure and produces a set of reasons for the
 // failure.  It also indicates whether or not it recognizes the stepFailure.
@@ skipping 38 matching lines @@
         OfflineBuilderThresh time.Duration
 
         // IdleBuilderCountThresh is the maximum number of builds a builder may have in queue
         // while in the "idle" state before triggering an "idle builder" alert.
         IdleBuilderCountThresh int64
 
         // StaleMasterThreshold is the maximum age that master data from CBE can be before
         // triggering a "stale master" alert.
         StaleMasterThreshold time.Duration
 
-        // MasterCfgs is a map of master name to MasterConfig
-        MasterCfgs map[string]messages.MasterConfig
+        // Gatekeeper is a the parsed gatekeeper.json config file.
+        Gatekeeper *GatekeeperRules
 
         // These limit the scope analysis, useful for debugging.
         MasterOnly  string
         BuilderOnly string
         BuildOnly   int64
 
+        // rslck protects revisionSummaries from concurrent access.
+        rslck             *sync.Mutex
         revisionSummaries map[string]messages.RevisionSummary
 
         // Now is useful for mocking the system clock in testing and simulating time
         // during replay.
         Now func() time.Time
 }
 
 // New returns a new Analyzer. If client is nil, it assigns a default implementation.
 // maxBuilds is the maximum number of builds to check, per builder.
 func New(c client.Reader, minBuilds, maxBuilds int) *Analyzer {
         if c == nil {
                 c = client.NewReader(nil)
         }
 
         return &Analyzer{
                 Reader:                 c,
                 MaxRecentBuilds:        maxBuilds,
                 MinRecentBuilds:        minBuilds,
                 HungBuilderThresh:      3 * time.Hour,
                 OfflineBuilderThresh:   90 * time.Minute,
                 IdleBuilderCountThresh: 50,
                 StaleMasterThreshold:   10 * time.Minute,
                 StepAnalyzers: []StepAnalyzer{
                         &TestFailureAnalyzer{Reader: c},
                         &CompileFailureAnalyzer{Reader: c},
                 },
-                MasterCfgs: map[string]messages.MasterConfig{},
-
+                Gatekeeper:        &GatekeeperRules{},
+                rslck:             &sync.Mutex{},
                 revisionSummaries: map[string]messages.RevisionSummary{},
                 Now: func() time.Time {
                         return time.Now()
                 },
         }
 }
 
 // MasterAlerts returns alerts generated from the master.
 func (a *Analyzer) MasterAlerts(master string, be *messages.BuildExtract) []messages.Alert {
         ret := []messages.Alert{}
 
         // Copied logic from builder_messages.
         // No created_timestamp should be a warning sign, no?
         if be.CreatedTimestamp == messages.EpochTime(0) {
                 return ret
         }
         expvars.Add("MasterAlerts", 1)
         defer expvars.Add("MasterAlerts", -1)
         elapsed := a.Now().Sub(be.CreatedTimestamp.Time())
         if elapsed > a.StaleMasterThreshold {
                 ret = append(ret, messages.Alert{
                         Key:       fmt.Sprintf("stale master: %v", master),
                         Title:     fmt.Sprintf("Stale %s master data", master),
-                        Body:      fmt.Sprintf("%s elapsed since last update.", elapsed),
+                        Body:      fmt.Sprintf("%dh %2dm elapsed since last update.", int(elapsed.Hours()), int(elapsed.Minutes())),
                         StartTime: messages.TimeToEpochTime(be.CreatedTimestamp.Time()),
                         Severity:  staleMasterSev,
                         Time:      messages.TimeToEpochTime(a.Now()),
                         Links:     []messages.Link{{"Master", client.MasterURL(master)}},
-                        // No type or extension for now.
+                        Type:      "stale-master",
+                        // No extension for now.
                 })
         }
         if elapsed < 0 {
                 // Add this to the alerts returned, rather than just log it?
                 log.Errorf("Master %s timestamp is newer than current time (%s): %s old.", master, a.Now(), elapsed)
         }
 
         return ret
 }
 
@@ skipping 158 matching lines @@
         switch b.State {
         case messages.StateBuilding:
                 if elapsed > a.HungBuilderThresh && lastStep != StepCompletedRun {
                         alerts = append(alerts, messages.Alert{
                                 Key:      fmt.Sprintf("%s.%s.hung", masterName, builderName),
                                 Title:    fmt.Sprintf("%s.%s is hung in step %s.", masterName, builderName, lastStep),
                                 Body:     fmt.Sprintf("%s.%s has been building for %v (last step update %s), past the alerting threshold of %v", masterName, builderName, elapsed, lastUpdated.Time(), a.HungBuilderThresh),
                                 Severity: hungBuilderSev,
                                 Time:     messages.TimeToEpochTime(a.Now()),
                                 Links:    links,
+                                Type:     "hung-builder",
                         })
                         // Note, just because it's building doesn't mean it's in a good state. If the last N builds
                         // all failed (for some large N) then this might still be alertable.
                 }
         case messages.StateOffline:
                 if elapsed > a.OfflineBuilderThresh {
                         alerts = append(alerts, messages.Alert{
                                 Key:      fmt.Sprintf("%s.%s.offline", masterName, builderName),
                                 Title:    fmt.Sprintf("%s.%s is offline.", masterName, builderName),
                                 Body:     fmt.Sprintf("%s.%s has been offline for %v (last step update %s %v), past the alerting threshold of %v", masterName, builderName, elapsed, lastUpdated.Time(), float64(lastUpdated), a.OfflineBuilderThresh),
                                 Severity: offlineBuilderSev,
                                 Time:     messages.TimeToEpochTime(a.Now()),
                                 Links:    links,
+                                Type:     "offline-builder",
                         })
                 }
         case messages.StateIdle:
                 if b.PendingBuilds > a.IdleBuilderCountThresh {
                         alerts = append(alerts, messages.Alert{
                                 Key:      fmt.Sprintf("%s.%s.idle", masterName, builderName),
                                 Title:    fmt.Sprintf("%s.%s is idle with too many pending builds.", masterName, builderName),
                                 Body:     fmt.Sprintf("%s.%s is idle with %d pending builds, past the alerting threshold of %d", masterName, builderName, b.PendingBuilds, a.IdleBuilderCountThresh),
                                 Severity: idleBuilderSev,
                                 Time:     messages.TimeToEpochTime(a.Now()),
                                 Links:    links,
+                                Type:     "idle-builder",
                         })
                 }
         default:
                 log.Errorf("Unknown %s.%s builder state: %s", masterName, builderName, b.State)
         }
 
         // Check for alerts on the most recent complete build
         log.Infof("Checking %d most recent builds for alertable step failures: %s/%s", len(recentBuildIDs), masterName, builderName)
         as, es := a.builderStepAlerts(masterName, builderName, []int64{lastCompletedBuild.Number})
 
@@ skipping 113 matching lines @@
                         mergedBF.RegressionRanges = append(mergedBF.RegressionRanges, messages.RegressionRange{
                                 Repo:      repo,
                                 Positions: uniques(pos),
                                 Revisions: uniques(revs),
                         })
                 }
 
                 sort.Sort(byRepo(mergedBF.RegressionRanges))
 
                 if len(mergedBF.Builders) > 1 {
-                        merged.Title = fmt.Sprintf("%s (failing on %d builders)", step, len(mergedBF.Builders))
+                        merged.Title = fmt.Sprintf("%s failing on %d builders", step, len(mergedBF.Builders))
+                        builderNames := []string{}
+                        for _, b := range mergedBF.Builders {
+                                builderNames = append(builderNames, b.Name)
+                        }
+                        merged.Body = strings.Join(builderNames, ", ")
                 }
                 merged.Extension = mergedBF
                 mergedAlerts = append(mergedAlerts, merged)
         }
 
         return mergedAlerts
 }
 
 // GetRevisionSummaries returns a slice of RevisionSummaries for the list of hashes.
 func (a *Analyzer) GetRevisionSummaries(hashes []string) ([]messages.RevisionSummary, error) {
         ret := []messages.RevisionSummary{}
         for _, h := range hashes {
+                a.rslck.Lock()
                 s, ok := a.revisionSummaries[h]
+                a.rslck.Unlock()
                 if !ok {
                         return nil, fmt.Errorf("Unrecognized hash:  %s", h)
                 }
                 ret = append(ret, s)
         }
 
         return ret, nil
 }
 
 // builderStepAlerts scans the steps of recent builds done on a particular builder,
@@ skipping 186 matching lines @@
                 // goroutine/channel because the reasonsForFailure call potentially
                 // blocks on IO.
                 if failure.step.Name == "steps" {
                         // check results to see if it's an array of [4]
                         // That's a purple failure, which should go to infra/trooper.
                         log.Infof("steps results: %+v", failure.step)
                         if len(failure.step.Results) > 0 {
                                 if r, ok := failure.step.Results[0].(float64); ok && r == resInfraFailure {
                                         // TODO: Create a trooper alert about this.
                                         log.Errorf("INFRA FAILURE: %+v", failure)
+                                        alr := messages.Alert{
+                                                Title:    fmt.Sprintf("%s infra failure", failure.builderName),
+                                                Body:     fmt.Sprintf("On step %s", failure.step.Name),
+                                                Type:     "infra-failure",
+                                                Severity: infraFailureSev,
+                                        }
+                                        rs <- res{
+                                                f:   failure,
+                                                a:   &alr,
+                                                err: nil,
+                                        }
                                 }
                         }
                         continue
                         // The actual breaking step will appear later.
                 }
 
                 // Check the gatekeeper configs to see if this is ignorable.
-                if a.excludeFailure(failure.masterName, failure.builderName, failure.step.Name) {
+                if a.Gatekeeper.ExcludeFailure(failure.masterName, failure.builderName, failure.step.Name) {
                         continue
                 }
 
                 // Gets the named revision number from gnumbd metadata.
                 getCommitPos := func(b messages.Build, name string) (string, bool) {
                         for _, p := range b.Properties {
                                 if p[0] == name {
                                         s, ok := p[1].(string)
                                         return s, ok
                                 }
                         }
                         return "", false
                 }
 
                 scannedFailures = append(scannedFailures, failure)
                 go func(f stepFailure) {
                         expvars.Add("StepFailures", 1)
                         defer expvars.Add("StepFailures", -1)
                         alr := messages.Alert{
-                                Title: fmt.Sprintf("Builder step failure: %s.%s", f.masterName, f.builderName),
-                                Time:  messages.EpochTime(a.Now().Unix()),
-                                Type:  "buildfailure",
+                                Title:    fmt.Sprintf("%s step failure", f.builderName),
+                                Body:     fmt.Sprintf("%s failing on %s/%s", f.step.Name, f.masterName, f.builderName),
+                                Time:     messages.EpochTime(a.Now().Unix()),
+                                Type:     "buildfailure",
+                                Severity: newFailureSev,
                         }
 
                         regRanges := []messages.RegressionRange{}
                         revisionsByRepo := map[string][]string{}
 
                         // Get gnumbd sequence numbers for whatever this build pulled in.
                         chromiumPos, ok := getCommitPos(f.build, "got_revision_cp")
                         if ok {
                                 regRanges = append(regRanges, messages.RegressionRange{
                                         Repo:      "chromium",
@@ skipping 23 matching lines @@
                                         Repo:      "nacl",
                                         Positions: []string{naclPos},
                                 })
                         }
 
                         for _, change := range f.build.SourceStamp.Changes {
                                 revisionsByRepo[change.Repository] = append(revisionsByRepo[change.Repository], change.Revision)
                                 // change.Revision is *not* always a git hash. Sometimes it is a position from gnumbd.
                                 // change.Revision is git hash or gnumbd depending on what exactly? Not obvious at this time.
                                 // A potential problem here is when multiple repos have overlapping gnumbd ranges.
+                                parts := cpRE.FindAllStringSubmatch(change.Comments, -1)
+                                pos, branch := "", ""
+                                if len(parts) > 0 {
+                                        branch = parts[0][1]
+                                        pos = parts[0][2]
+                                }
+                                a.rslck.Lock()
                                 a.revisionSummaries[change.Revision] = messages.RevisionSummary{
                                         GitHash:     change.Revision,
                                         Link:        change.Revlink,
                                         Description: trunc(change.Comments),
                                         Author:      change.Who,
                                         When:        change.When,
+                                        Position:    pos,
+                                        Branch:      branch,
                                 }
+                                a.rslck.Unlock()
                         }
 
                         for repo, revisions := range revisionsByRepo {
                                 regRanges = append(regRanges, messages.RegressionRange{
                                         Repo:      repo,
                                         Revisions: revisions,
                                 })
                         }
 
                         // If the builder has been failing on the same step for multiple builds in a row,
                         // we should have only one alert but indicate the range of builds affected.
                         // These are set in FirstFailure and LastFailure.
                         bf := messages.BuildFailure{
                                 // FIXME: group builders?
                                 Builders: []messages.AlertedBuilder{
                                         {
                                                 Name:          f.builderName,
                                                 URL:           client.BuilderURL(f.masterName, f.builderName),
                                                 StartTime:     f.build.CreatedTimestamp,
                                                 FirstFailure:  f.build.Number,
                                                 LatestFailure: f.build.Number,
                                         },
                                 },
-                                TreeCloser:       a.wouldCloseTree(f.masterName, f.builderName, f.step.Name),
+                                TreeCloser:       a.Gatekeeper.WouldCloseTree(f.masterName, f.builderName, f.step.Name),
                                 RegressionRanges: regRanges,
                         }
 
+                        if bf.TreeCloser {
+                                alr.Severity = treeCloserSev
+                        }
+
                         reasons := a.reasonsForFailure(f)
                         for _, r := range reasons {
                                 bf.Reasons = append(bf.Reasons, messages.Reason{
                                         TestName: r,
                                         Step:     f.step.Name,
                                         URL:      f.URL(),
                                 })
                         }
 
                         alr.Key = alertKey(f.masterName, f.builderName, f.step.Name)
@@ skipping 54 matching lines @@
 
         if !recognized {
                 // TODO: log and report frequently encountered unrecognized builder step
                 // failure names.
                 log.Errorf("Unrecognized step step failure type, unable to find reasons: %s", f.step.Name)
         }
 
         return ret
 }
 
-func (a *Analyzer) excludeFailure(master, builder, step string) bool {
-        mc, ok := a.MasterCfgs[master]
-        if !ok {
-                log.Errorf("Can't filter unknown master %s", master)
-                return false
-        }
-
-        for _, ebName := range mc.ExcludedBuilders {
-                if ebName == "*" || ebName == builder {
-                        return true
-                }
-        }
-
-        // Not clear that builder_alerts even looks at the rest of these condtions
-        // even though they're specified in gatekeeper.json
-        for _, s := range mc.ExcludedSteps {
-                if step == s {
-                        return true
-                }
-        }
-
-        bc, ok := mc.Builders[builder]
-        if !ok {
-                if bc, ok = mc.Builders["*"]; !ok {
-                        log.Warningf("Unknown %s builder %s", master, builder)
-                        return true
-                }
-        }
-
-        for _, esName := range bc.ExcludedSteps {
-                if esName == step || esName == "*" {
-                        return true
-                }
-        }
-
-        return false
-}
-
-func (a *Analyzer) wouldCloseTree(master, builder, step string) bool {
-        mc, ok := a.MasterCfgs[master]
-        if !ok {
-                log.Errorf("Missing master cfg: %s", master)
-                return false
-        }
-        bc, ok := mc.Builders[builder]
-        if !ok {
-                bc, ok = mc.Builders["*"]
-                if ok {
-                        return true
-                }
-        }
-
-        for _, xstep := range bc.ExcludedSteps {
-                if xstep == step {
-                        return false
-                }
-        }
-
-        csteps := []string{}
-        csteps = append(csteps, bc.ClosingSteps...)
-        csteps = append(csteps, bc.ClosingOptional...)
-
-        for _, cs := range csteps {
-                if cs == "*" || cs == step {
-                        return true
-                }
-        }
-
-        return false
-}
-
 // unexpected returns the set of expected xor actual.
 func unexpected(expected, actual []string) []string {
         e, a := make(map[string]bool), make(map[string]bool)
         for _, s := range expected {
                 e[s] = true
         }
         for _, s := range actual {
                 a[s] = true
         }
 
@@ skipping 17 matching lines @@
         masterName  string
         builderName string
         build       messages.Build
         step        messages.Step
 }
 
 // URL returns a url to builder step failure page.
 func (f stepFailure) URL() string {
         return client.StepURL(f.masterName, f.builderName, f.step.Name, f.build.Number)
 }