github.com/mwhudson/juju@v0.0.0-20160512215208-90ff01f3497f/apiserver/logsink_test.go (about) 1 // Copyright 2015 Canonical Ltd. 2 // Licensed under the AGPLv3, see LICENCE file for details. 3 4 package apiserver_test 5 6 import ( 7 "bufio" 8 "io/ioutil" 9 "net/http" 10 "net/url" 11 "os" 12 "path/filepath" 13 "runtime" 14 "time" 15 16 "github.com/juju/loggo" 17 "github.com/juju/names" 18 jc "github.com/juju/testing/checkers" 19 "github.com/juju/utils" 20 "golang.org/x/net/websocket" 21 gc "gopkg.in/check.v1" 22 "gopkg.in/mgo.v2/bson" 23 24 "github.com/juju/juju/apiserver/params" 25 coretesting "github.com/juju/juju/testing" 26 "github.com/juju/juju/testing/factory" 27 ) 28 29 // logsinkBaseSuite has functionality that's shared between the the 2 logsink related suites 30 type logsinkBaseSuite struct { 31 authHttpSuite 32 } 33 34 func (s *logsinkBaseSuite) logsinkURL(c *gc.C, scheme string) *url.URL { 35 return s.makeURL(c, scheme, "/model/"+s.State.ModelUUID()+"/logsink", nil) 36 } 37 38 type logsinkSuite struct { 39 logsinkBaseSuite 40 machineTag names.Tag 41 password string 42 nonce string 43 logs loggo.TestWriter 44 } 45 46 var _ = gc.Suite(&logsinkSuite{}) 47 48 func (s *logsinkSuite) SetUpTest(c *gc.C) { 49 s.logsinkBaseSuite.SetUpTest(c) 50 s.nonce = "nonce" 51 m, password := s.Factory.MakeMachineReturningPassword(c, &factory.MachineParams{ 52 Nonce: s.nonce, 53 }) 54 s.machineTag = m.Tag() 55 s.password = password 56 57 s.logs.Clear() 58 c.Assert(loggo.RegisterWriter("logsink-tests", &s.logs, loggo.INFO), jc.ErrorIsNil) 59 } 60 61 func (s *logsinkSuite) TestRejectsBadEnvironUUID(c *gc.C) { 62 reader := s.openWebsocketCustomPath(c, "/model/does-not-exist/logsink") 63 assertJSONError(c, reader, `unknown model: "does-not-exist"`) 64 s.assertWebsocketClosed(c, reader) 65 } 66 67 func (s *logsinkSuite) TestNoAuth(c *gc.C) { 68 s.checkAuthFails(c, nil, "no credentials provided") 69 } 70 71 func (s *logsinkSuite) TestRejectsUserLogins(c *gc.C) { 72 user := s.Factory.MakeUser(c, &factory.UserParams{Password: "sekrit"}) 73 header := utils.BasicAuthHeader(user.Tag().String(), "sekrit") 74 s.checkAuthFailsWithEntityError(c, header) 75 } 76 77 func (s *logsinkSuite) TestRejectsBadPassword(c *gc.C) { 78 header := utils.BasicAuthHeader(s.machineTag.String(), "wrong") 79 header.Add(params.MachineNonceHeader, s.nonce) 80 s.checkAuthFailsWithEntityError(c, header) 81 } 82 83 func (s *logsinkSuite) TestRejectsIncorrectNonce(c *gc.C) { 84 header := utils.BasicAuthHeader(s.machineTag.String(), s.password) 85 header.Add(params.MachineNonceHeader, "wrong") 86 s.checkAuthFails(c, header, "machine 0 not provisioned") 87 } 88 89 func (s *logsinkSuite) checkAuthFailsWithEntityError(c *gc.C, header http.Header) { 90 s.checkAuthFails(c, header, "invalid entity name or password") 91 } 92 93 func (s *logsinkSuite) checkAuthFails(c *gc.C, header http.Header, message string) { 94 conn := s.dialWebsocketInternal(c, header) 95 defer conn.Close() 96 reader := bufio.NewReader(conn) 97 assertJSONError(c, reader, message) 98 s.assertWebsocketClosed(c, reader) 99 } 100 101 func (s *logsinkSuite) TestLogging(c *gc.C) { 102 conn := s.dialWebsocket(c) 103 defer conn.Close() 104 reader := bufio.NewReader(conn) 105 106 // Read back the nil error, indicating that all is well. 107 errResult := readJSONErrorLine(c, reader) 108 c.Assert(errResult.Error, gc.IsNil) 109 110 t0 := time.Date(2015, time.June, 1, 23, 2, 1, 0, time.UTC) 111 err := websocket.JSON.Send(conn, ¶ms.LogRecord{ 112 Time: t0, 113 Module: "some.where", 114 Location: "foo.go:42", 115 Level: loggo.INFO, 116 Message: "all is well", 117 }) 118 c.Assert(err, jc.ErrorIsNil) 119 120 t1 := time.Date(2015, time.June, 1, 23, 2, 2, 0, time.UTC) 121 err = websocket.JSON.Send(conn, ¶ms.LogRecord{ 122 Time: t1, 123 Module: "else.where", 124 Location: "bar.go:99", 125 Level: loggo.ERROR, 126 Message: "oh noes", 127 }) 128 c.Assert(err, jc.ErrorIsNil) 129 130 // Wait for the log documents to be written to the DB. 131 logsColl := s.State.MongoSession().DB("logs").C("logs") 132 var docs []bson.M 133 for a := coretesting.LongAttempt.Start(); a.Next(); { 134 err := logsColl.Find(nil).Sort("t").All(&docs) 135 c.Assert(err, jc.ErrorIsNil) 136 if len(docs) == 2 { 137 break 138 } 139 if len(docs) >= 2 { 140 c.Fatalf("saw more log documents than expected") 141 } 142 if !a.HasNext() { 143 c.Fatalf("timed out waiting for log writes") 144 } 145 } 146 147 // Check the recorded logs are correct. 148 modelUUID := s.State.ModelUUID() 149 c.Assert(docs[0]["t"].(time.Time).Sub(t0), gc.Equals, time.Duration(0)) 150 c.Assert(docs[0]["e"], gc.Equals, modelUUID) 151 c.Assert(docs[0]["n"], gc.Equals, s.machineTag.String()) 152 c.Assert(docs[0]["m"], gc.Equals, "some.where") 153 c.Assert(docs[0]["l"], gc.Equals, "foo.go:42") 154 c.Assert(docs[0]["v"], gc.Equals, int(loggo.INFO)) 155 c.Assert(docs[0]["x"], gc.Equals, "all is well") 156 157 c.Assert(docs[1]["t"].(time.Time).Sub(t1), gc.Equals, time.Duration(0)) 158 c.Assert(docs[1]["e"], gc.Equals, modelUUID) 159 c.Assert(docs[1]["n"], gc.Equals, s.machineTag.String()) 160 c.Assert(docs[1]["m"], gc.Equals, "else.where") 161 c.Assert(docs[1]["l"], gc.Equals, "bar.go:99") 162 c.Assert(docs[1]["v"], gc.Equals, int(loggo.ERROR)) 163 c.Assert(docs[1]["x"], gc.Equals, "oh noes") 164 165 // Close connection. 166 err = conn.Close() 167 c.Assert(err, jc.ErrorIsNil) 168 169 // Ensure that no error is logged when the connection is closed 170 // normally. 171 shortAttempt := &utils.AttemptStrategy{ 172 Total: coretesting.ShortWait, 173 Delay: 2 * time.Millisecond, 174 } 175 for a := shortAttempt.Start(); a.Next(); { 176 for _, log := range s.logs.Log() { 177 c.Assert(log.Level, jc.LessThan, loggo.ERROR, gc.Commentf("log: %#v", log)) 178 } 179 } 180 181 // Check that the logsink log file was populated as expected 182 logPath := filepath.Join(s.LogDir, "logsink.log") 183 logContents, err := ioutil.ReadFile(logPath) 184 c.Assert(err, jc.ErrorIsNil) 185 line0 := modelUUID + " machine-0: 2015-06-01 23:02:01 INFO some.where foo.go:42 all is well\n" 186 line1 := modelUUID + " machine-0: 2015-06-01 23:02:02 ERROR else.where bar.go:99 oh noes\n" 187 c.Assert(string(logContents), gc.Equals, line0+line1) 188 189 // Check the file mode is as expected. This doesn't work on 190 // Windows (but this code is very unlikely to run on Windows so 191 // it's ok). 192 if runtime.GOOS != "windows" { 193 info, err := os.Stat(logPath) 194 c.Assert(err, jc.ErrorIsNil) 195 c.Assert(info.Mode(), gc.Equals, os.FileMode(0600)) 196 } 197 } 198 199 func (s *logsinkSuite) dialWebsocket(c *gc.C) *websocket.Conn { 200 return s.dialWebsocketInternal(c, s.makeAuthHeader()) 201 } 202 203 func (s *logsinkSuite) dialWebsocketInternal(c *gc.C, header http.Header) *websocket.Conn { 204 server := s.logsinkURL(c, "wss").String() 205 return s.dialWebsocketFromURL(c, server, header) 206 } 207 208 func (s *logsinkSuite) openWebsocketCustomPath(c *gc.C, path string) *bufio.Reader { 209 server := s.logsinkURL(c, "wss") 210 server.Path = path 211 conn := s.dialWebsocketFromURL(c, server.String(), s.makeAuthHeader()) 212 s.AddCleanup(func(_ *gc.C) { conn.Close() }) 213 return bufio.NewReader(conn) 214 } 215 216 func (s *logsinkSuite) makeAuthHeader() http.Header { 217 header := utils.BasicAuthHeader(s.machineTag.String(), s.password) 218 header.Add(params.MachineNonceHeader, s.nonce) 219 return header 220 }