14324: Use logrus in Azure driver. Fix Sirupsen->sirupsen in imports
[arvados.git] / services / keep-balance / balance_run_test.go
index 08cfcce5849e4bb98440f40a8e241fefce74b352..7e2adcfedd4dc33b67ccae5301813cb531f6af9d 100644 (file)
@@ -9,7 +9,6 @@ import (
        "fmt"
        "io"
        "io/ioutil"
-       "log"
        "net/http"
        "net/http/httptest"
        "strings"
@@ -17,7 +16,7 @@ import (
        "time"
 
        "git.curoverse.com/arvados.git/sdk/go/arvados"
-
+       "github.com/sirupsen/logrus"
        check "gopkg.in/check.v1"
 )
 
@@ -184,7 +183,8 @@ func (s *stubServer) serveFooBarFileCollections() *reqTracker {
                if strings.Contains(r.Form.Get("filters"), `modified_at`) {
                        io.WriteString(w, `{"items_available":0,"items":[]}`)
                } else {
-                       io.WriteString(w, `{"items_available":2,"items":[
+                       io.WriteString(w, `{"items_available":3,"items":[
+                               {"uuid":"zzzzz-4zz18-aaaaaaaaaaaaaaa","portable_data_hash":"fa7aeb5140e2848d39b416daeef4ffc5+45","manifest_text":". 37b51d194a7513e45b56f6524f2d51f2+3 0:3:bar\n","modified_at":"2014-02-03T17:22:54Z"},
                                {"uuid":"zzzzz-4zz18-ehbhgtheo8909or","portable_data_hash":"fa7aeb5140e2848d39b416daeef4ffc5+45","manifest_text":". 37b51d194a7513e45b56f6524f2d51f2+3 0:3:bar\n","modified_at":"2014-02-03T17:22:54Z"},
                                {"uuid":"zzzzz-4zz18-znfnqtbbv4spc3w","portable_data_hash":"1f4b0bc7583c2a7f9102c395f4ffc5e3+45","manifest_text":". acbd18db4cc2f85cedef654fccc4a4d8+3 0:3:foo\n","modified_at":"2014-02-03T17:22:54Z"}]}`)
                }
@@ -282,7 +282,7 @@ type runSuite struct {
 }
 
 // make a log.Logger that writes to the current test's c.Log().
-func (s *runSuite) logger(c *check.C) *log.Logger {
+func (s *runSuite) logger(c *check.C) *logrus.Logger {
        r, w := io.Pipe()
        go func() {
                buf := make([]byte, 10000)
@@ -299,7 +299,9 @@ func (s *runSuite) logger(c *check.C) *log.Logger {
                        }
                }
        }()
-       return log.New(w, "", log.LstdFlags)
+       logger := logrus.New()
+       logger.Out = w
+       return logger
 }
 
 func (s *runSuite) SetUpTest(c *check.C) {
@@ -308,7 +310,9 @@ func (s *runSuite) SetUpTest(c *check.C) {
                        AuthToken: "xyzzy",
                        APIHost:   "zzzzz.arvadosapi.com",
                        Client:    s.stub.Start()},
-               KeepServiceTypes: []string{"disk"}}
+               KeepServiceTypes: []string{"disk"},
+               RunPeriod:        arvados.Duration(time.Second),
+       }
        s.stub.serveDiscoveryDoc()
        s.stub.logf = c.Logf
 }
@@ -330,7 +334,9 @@ func (s *runSuite) TestRefuseZeroCollections(c *check.C) {
        s.stub.serveKeepstoreIndexFoo4Bar1()
        trashReqs := s.stub.serveKeepstoreTrash()
        pullReqs := s.stub.serveKeepstorePull()
-       _, err := (&Balancer{}).Run(s.config, opts)
+       srv, err := NewServer(s.config, opts)
+       c.Assert(err, check.IsNil)
+       _, err = srv.Run()
        c.Check(err, check.ErrorMatches, "received zero collections")
        c.Check(trashReqs.Count(), check.Equals, 4)
        c.Check(pullReqs.Count(), check.Equals, 0)
@@ -349,7 +355,9 @@ func (s *runSuite) TestServiceTypes(c *check.C) {
        s.stub.serveKeepstoreMounts()
        indexReqs := s.stub.serveKeepstoreIndexFoo4Bar1()
        trashReqs := s.stub.serveKeepstoreTrash()
-       _, err := (&Balancer{}).Run(s.config, opts)
+       srv, err := NewServer(s.config, opts)
+       c.Assert(err, check.IsNil)
+       _, err = srv.Run()
        c.Check(err, check.IsNil)
        c.Check(indexReqs.Count(), check.Equals, 0)
        c.Check(trashReqs.Count(), check.Equals, 0)
@@ -367,7 +375,9 @@ func (s *runSuite) TestRefuseNonAdmin(c *check.C) {
        s.stub.serveKeepstoreMounts()
        trashReqs := s.stub.serveKeepstoreTrash()
        pullReqs := s.stub.serveKeepstorePull()
-       _, err := (&Balancer{}).Run(s.config, opts)
+       srv, err := NewServer(s.config, opts)
+       c.Assert(err, check.IsNil)
+       _, err = srv.Run()
        c.Check(err, check.ErrorMatches, "current user .* is not .* admin user")
        c.Check(trashReqs.Count(), check.Equals, 0)
        c.Check(pullReqs.Count(), check.Equals, 0)
@@ -386,7 +396,9 @@ func (s *runSuite) TestDetectSkippedCollections(c *check.C) {
        s.stub.serveKeepstoreIndexFoo4Bar1()
        trashReqs := s.stub.serveKeepstoreTrash()
        pullReqs := s.stub.serveKeepstorePull()
-       _, err := (&Balancer{}).Run(s.config, opts)
+       srv, err := NewServer(s.config, opts)
+       c.Assert(err, check.IsNil)
+       _, err = srv.Run()
        c.Check(err, check.ErrorMatches, `Retrieved 2 collections with modtime <= .* but server now reports there are 3 collections.*`)
        c.Check(trashReqs.Count(), check.Equals, 4)
        c.Check(pullReqs.Count(), check.Equals, 0)
@@ -405,21 +417,24 @@ func (s *runSuite) TestDryRun(c *check.C) {
        s.stub.serveKeepstoreIndexFoo4Bar1()
        trashReqs := s.stub.serveKeepstoreTrash()
        pullReqs := s.stub.serveKeepstorePull()
-       var bal Balancer
-       _, err := bal.Run(s.config, opts)
+       srv, err := NewServer(s.config, opts)
+       c.Assert(err, check.IsNil)
+       bal, err := srv.Run()
        c.Check(err, check.IsNil)
        for _, req := range collReqs.reqs {
                c.Check(req.Form.Get("include_trash"), check.Equals, "true")
+               c.Check(req.Form.Get("include_old_versions"), check.Equals, "true")
        }
        c.Check(trashReqs.Count(), check.Equals, 0)
        c.Check(pullReqs.Count(), check.Equals, 0)
-       stats := bal.getStatistics()
-       c.Check(stats.pulls, check.Not(check.Equals), 0)
-       c.Check(stats.underrep.replicas, check.Not(check.Equals), 0)
-       c.Check(stats.overrep.replicas, check.Not(check.Equals), 0)
+       c.Check(bal.stats.pulls, check.Not(check.Equals), 0)
+       c.Check(bal.stats.underrep.replicas, check.Not(check.Equals), 0)
+       c.Check(bal.stats.overrep.replicas, check.Not(check.Equals), 0)
 }
 
 func (s *runSuite) TestCommit(c *check.C) {
+       s.config.Listen = ":"
+       s.config.ManagementToken = "xyzzy"
        opts := RunOptions{
                CommitPulls: true,
                CommitTrash: true,
@@ -433,20 +448,29 @@ func (s *runSuite) TestCommit(c *check.C) {
        s.stub.serveKeepstoreIndexFoo4Bar1()
        trashReqs := s.stub.serveKeepstoreTrash()
        pullReqs := s.stub.serveKeepstorePull()
-       var bal Balancer
-       _, err := bal.Run(s.config, opts)
+       srv, err := NewServer(s.config, opts)
+       c.Assert(err, check.IsNil)
+       bal, err := srv.Run()
        c.Check(err, check.IsNil)
        c.Check(trashReqs.Count(), check.Equals, 8)
        c.Check(pullReqs.Count(), check.Equals, 4)
-       stats := bal.getStatistics()
        // "foo" block is overreplicated by 2
-       c.Check(stats.trashes, check.Equals, 2)
+       c.Check(bal.stats.trashes, check.Equals, 2)
        // "bar" block is underreplicated by 1, and its only copy is
        // in a poor rendezvous position
-       c.Check(stats.pulls, check.Equals, 2)
+       c.Check(bal.stats.pulls, check.Equals, 2)
+
+       metrics := s.getMetrics(c, srv)
+       c.Check(metrics, check.Matches, `(?ms).*\narvados_keep_total_bytes 15\n.*`)
+       c.Check(metrics, check.Matches, `(?ms).*\narvados_keepbalance_changeset_compute_seconds_sum [0-9\.]+\n.*`)
+       c.Check(metrics, check.Matches, `(?ms).*\narvados_keepbalance_changeset_compute_seconds_count 1\n.*`)
+       c.Check(metrics, check.Matches, `(?ms).*\narvados_keep_dedup_byte_ratio 1\.5\n.*`)
+       c.Check(metrics, check.Matches, `(?ms).*\narvados_keep_dedup_block_ratio 1\.5\n.*`)
 }
 
 func (s *runSuite) TestRunForever(c *check.C) {
+       s.config.Listen = ":"
+       s.config.ManagementToken = "xyzzy"
        opts := RunOptions{
                CommitPulls: true,
                CommitTrash: true,
@@ -463,7 +487,14 @@ func (s *runSuite) TestRunForever(c *check.C) {
 
        stop := make(chan interface{})
        s.config.RunPeriod = arvados.Duration(time.Millisecond)
-       go RunForever(s.config, opts, stop)
+       srv, err := NewServer(s.config, opts)
+       c.Assert(err, check.IsNil)
+
+       done := make(chan bool)
+       go func() {
+               srv.RunForever(stop)
+               close(done)
+       }()
 
        // Each run should send 4 pull lists + 4 trash lists. The
        // first run should also send 4 empty trash lists at
@@ -473,6 +504,21 @@ func (s *runSuite) TestRunForever(c *check.C) {
                time.Sleep(time.Millisecond)
        }
        stop <- true
+       <-done
        c.Check(pullReqs.Count() >= 16, check.Equals, true)
        c.Check(trashReqs.Count(), check.Equals, pullReqs.Count()+4)
+       c.Check(s.getMetrics(c, srv), check.Matches, `(?ms).*\narvados_keepbalance_changeset_compute_seconds_count `+fmt.Sprintf("%d", pullReqs.Count()/4)+`\n.*`)
+}
+
+func (s *runSuite) getMetrics(c *check.C, srv *Server) string {
+       resp, err := http.Get("http://" + srv.listening + "/metrics")
+       c.Assert(err, check.IsNil)
+       c.Check(resp.StatusCode, check.Equals, http.StatusUnauthorized)
+
+       resp, err = http.Get("http://" + srv.listening + "/metrics?api_token=xyzzy")
+       c.Assert(err, check.IsNil)
+       c.Check(resp.StatusCode, check.Equals, http.StatusOK)
+       buf, err := ioutil.ReadAll(resp.Body)
+       c.Check(err, check.IsNil)
+       return string(buf)
 }