func (s *S) TestReconnect(c *C) {
l, err := net.Listen("tcp", ":0")
c.Assert(err, IsNil)
err = l.Close()
c.Assert(err, IsNil)
msgc := make(chan *rfc5424.Message)
handler := func(msg *rfc5424.Message) {
msgc <- msg
}
addr := l.Addr().String()
_, err = s.discd.AddServiceAndRegister("test-reconnect", addr)
c.Assert(err, IsNil)
donec := make(chan struct{})
defer close(donec)
sc, err := connect(s.discd, "test-reconnect", donec)
c.Assert(err, IsNil)
l, err = net.Listen("tcp", addr)
c.Assert(err, IsNil)
go runServer(l, handler)
want := rfc5424.NewMessage(&rfc5424.Header{Version: 1}, []byte("test message"))
_, err = sc.Write(rfc6587.Bytes(want))
c.Assert(err, IsNil)
c.Assert(<-msgc, DeepEquals, want)
}
func (s *ServerTestSuite) TestServerDurability(c *C) {
srv := testServer(c)
c.Assert(srv.Start(), IsNil)
defer srv.Shutdown()
cl := testClient(c, srv)
conn, err := net.Dial("tcp", srv.SyslogAddr().String())
c.Assert(err, IsNil)
defer conn.Close()
zero := 0
rc, err := cl.GetLog("app-A", &logagg.LogOpts{Follow: true, Lines: &zero})
c.Assert(err, IsNil)
for _, msg := range appAMessages {
conn.Write(rfc6587.Bytes(msg))
}
var got client.Message
dec := json.NewDecoder(rc)
for _, want := range appAMessages {
c.Assert(dec.Decode(&got), IsNil)
c.Assert(got.HostID, Equals, string(want.Hostname))
c.Assert(got.Stream, Equals, utils.StreamType(want))
c.Assert(got.Timestamp.Equal(want.Timestamp), Equals, true)
procType, jobID := splitProcID(want.ProcID)
c.Assert(got.ProcessType, Equals, string(procType))
c.Assert(got.JobID, Equals, string(jobID))
}
}
func (m *LogMux) drainTo(w io.Writer) {
defer close(m.donec)
g := grohl.NewContext(grohl.Data{"at": "logmux_drain"})
for {
msg, ok := <-m.logc
if !ok {
return // shutdown
}
_, err := w.Write(rfc6587.Bytes(msg))
if err != nil {
g.Log(grohl.Data{"status": "error", "err": err.Error()})
// write logs to local logger when the writer fails
g.Log(grohl.Data{"msg": msg.String()})
for msg := range m.logc {
g.Log(grohl.Data{"msg": msg.String()})
}
return // shutdown
}
}
}
func (s *ServerTestSuite) TestHostCursors(c *C) {
srv := testServer(c)
srv.testMessageHook = make(chan struct{}, 1)
c.Assert(srv.Start(), IsNil)
defer srv.Shutdown()
cl := testClient(c, srv)
conn, err := net.Dial("tcp", srv.SyslogAddr().String())
c.Assert(err, IsNil)
defer conn.Close()
assertCursors := func(expected map[string]utils.HostCursor) {
cursors, err := cl.GetCursors()
c.Assert(err, IsNil)
c.Assert(cursors, DeepEquals, expected)
}
write := func(msg *rfc5424.Message) {
conn.Write(rfc6587.Bytes(msg))
<-srv.testMessageHook
}
// write some messages
msg1, msg2 := newSeqMessage("host1", 1, 0), newSeqMessage("host2", 1, 0)
write(msg1)
write(msg2)
assertCursors(map[string]utils.HostCursor{
"host1": {msg1.Timestamp, 1},
"host2": {msg2.Timestamp, 1},
})
// test new timestamp with seq rolled over
msg3 := newSeqMessage("host1", 1, 1)
write(msg3)
assertCursors(map[string]utils.HostCursor{
"host1": {msg3.Timestamp, 1},
"host2": {msg2.Timestamp, 1},
})
// test same timestamp with new seq
msg4 := newSeqMessage("host1", 2, 1)
write(msg4)
assertCursors(map[string]utils.HostCursor{
"host1": {msg4.Timestamp, 2},
"host2": {msg2.Timestamp, 1},
})
}
func (s *S) TestDurableWrite(c *C) {
l, err := net.Listen("tcp", ":0")
c.Assert(err, IsNil)
msgc := make(chan *rfc5424.Message)
handler := func(msg *rfc5424.Message) {
msgc <- msg
}
go runServer(l, handler)
donec := make(chan struct{})
defer close(donec)
sc, err := connect(s.discd, "test-broken", donec)
c.Assert(err, IsNil)
addr := l.Addr().String()
_, err = s.discd.AddServiceAndRegister("test-broken", addr)
c.Assert(err, IsNil)
hdr := &rfc5424.Header{}
for i := 0; i < 10; i++ {
want := rfc5424.NewMessage(hdr, []byte(fmt.Sprintf("line %d", i+1)))
_, err = sc.Write(rfc6587.Bytes(want))
c.Assert(err, IsNil)
if i%2 == 0 {
// break the underlying connection before the next Write
c.Assert(sc.Conn.Close(), IsNil)
}
got := <-msgc
c.Assert(want, DeepEquals, got)
}
}
func (l *appLog) Write(msg message) {
l.l.Write(append(rfc6587.Bytes(msg.Message), '\n'))
l.m.broadcast(l.appID, msg)
}
func (m *Mux) addAggregator(addr string) {
l := m.logger.New("fn", "addAggregator", "addr", addr)
// TODO(titanous): add dial timeout
conn, err := net.Dial("tcp", addr)
if err != nil {
l.Error("failed to connect to aggregator", "error", err)
return
}
l.Info("connected to aggregator")
host, _, _ := net.SplitHostPort(addr)
c, _ := client.New("http://" + host)
cursors, err := c.GetCursors()
if err != nil {
// TODO(titanous): retry
l.Error("failed to get cursors from aggregator", "error", err)
conn.Close()
return
}
var aggCursor *utils.HostCursor
if c, ok := cursors[m.hostID]; ok {
aggCursor = &c
}
if aggCursor != nil {
l.Info("got cursor", "cursor.timestamp", aggCursor.Time, "cursor.seq", aggCursor.Seq)
} else {
l.Info("no cursor for host")
}
appLogs, err := m.logFiles("")
if err != nil {
l.Error("failed to get local log files", "error", err)
conn.Close()
return
}
bufferedMessages := make(chan message)
firehose := make(chan message)
done := make(chan struct{})
// subscribe to all messages
unsubscribe := m.subscribe(firehoseApp, firehose)
bufferCursors := make(map[string]utils.HostCursor)
var bufferCursorsMtx sync.Mutex
go func() {
l := m.logger.New("fn", "sendToAggregator", "addr", addr)
defer unsubscribe()
defer conn.Close()
defer close(done)
bm := bufferedMessages // make a copy so we can nil it later
for {
var m message
var ok bool
select {
case m, ok = <-bm:
if !ok {
bm = nil
continue
}
case m, ok = <-firehose:
if !ok {
return
}
// if app in list of app logs and cursor from reading files, skip
appID := string(m.Message.AppName)
if _, ok := appLogs[appID]; ok {
bufferCursorsMtx.Lock()
c, ok := bufferCursors[appID]
bufferCursorsMtx.Unlock()
if !ok || c.After(*m.HostCursor) {
continue
}
}
}
if _, err := conn.Write(rfc6587.Bytes(m.Message)); err != nil {
l.Error("failed to write message", "error", err)
return
}
}
}()
for appID, logs := range appLogs {
for i, name := range logs {
func() {
l := l.New("log", name)
f, err := os.Open(name)
if err != nil {
l.Error("failed to open log file", "error", err)
return
}
defer f.Close()
sc := bufio.NewScanner(f)
sc.Split(rfc6587.SplitWithNewlines)
var cursor *utils.HostCursor
cursorSaved := false
scan:
for sc.Scan() {
msgBytes := sc.Bytes()
// slice in msgBytes could get modified on next Scan(), need to copy it
msgCopy := make([]byte, len(msgBytes)-1)
copy(msgCopy, msgBytes)
var msg *rfc5424.Message
msg, cursor, err = utils.ParseMessage(msgCopy)
if err != nil {
l.Error("failed to parse message", "msg", string(msgCopy), "error", err)
continue
}
if aggCursor != nil && !cursor.After(*aggCursor) {
continue
}
select {
case bufferedMessages <- message{cursor, msg}:
case <-done:
return
}
}
if err := sc.Err(); err != nil {
l.Error("failed to scan message", "error", err)
return
}
if !cursorSaved && i == len(appLogs[appID])-1 {
// last file, send cursor to processing goroutine
bufferCursorsMtx.Lock()
bufferCursors[appID] = *cursor
bufferCursorsMtx.Unlock()
cursorSaved = true
// read to end of file again
goto scan
}
}()
}
}
close(bufferedMessages)
}
