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, &params.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, &params.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  }