-
Notifications
You must be signed in to change notification settings - Fork 74
/
scribe.go
281 lines (240 loc) · 8.55 KB
/
scribe.go
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
// Copyright 2015-2018 trivago N.V.
//
// Licensed under the Apache License, Version 2.0 (the "License");
// you may not use this file except in compliance with the License.
// You may obtain a copy of the License at
//
// http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing, software
// distributed under the License is distributed on an "AS IS" BASIS,
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
// See the License for the specific language governing permissions and
// limitations under the License.
package producer
import (
"fmt"
"github.com/artyom/fb303"
"github.com/artyom/scribe"
"github.com/artyom/thrift"
"github.com/trivago/gollum/core"
"github.com/trivago/tgo"
"github.com/trivago/tgo/tmath"
"sync"
"time"
)
// Scribe producer
//
// This producer allows sending messages to Facebook's scribe service.
//
// Parameters
//
// - Address: Defines the host and port of a scrive endpoint.
// By default this parameter is set to "localhost:1463".
//
// - ConnectionBufferSizeKB: Sets the connection socket buffer size in KB.
// By default this parameter is set to 1024.
//
// - HeartBeatIntervalSec: Defines the interval in seconds used to query scribe
// for status updates.
// By default this parameter is set to 1.
//
// - WindowSize: Defines the maximum number of messages send to scribe in one
// call. The WindowSize will reduce when scribe is returing "try later" to
// reduce load on the scribe server. It will slowly rise again for each
// successful write until WindowSize is reached again.
// By default this parameter is set to 2048.
//
// - ConnectionTimeoutSec: Defines the time in seconds after which a connection
// timeout is assumed. This can happen during writes or status reads.
// By default this parameter is set to 5.
//
// - Category: Maps a stream to a scribe category. You can define the wildcard
// stream (*) here, too. When set, all streams that do not have a specific
// mapping will go to this category (including reserved streams like _GOLLUM_).
// If no category mappings are set the stream name is used as category.
// By default this parameter is set to an empty list.
//
// Examples
//
// logs:
// Type: producer.Scribe"
// Stream: ["*", "_GOLLUM"]
// Address: "scribe01:1463"
// HeartBeatIntervalSec: 10
// Category:
// "access" : "accesslogs"
// "error" : "errorlogs"
// "_GOLLUM_" : "gollumlogs"
type Scribe struct {
core.BatchedProducer `gollumdoc:"embed_type"`
scribe *scribe.ScribeClient
transport *thrift.TFramedTransport
socket *thrift.TSocket
categoryGuard *sync.RWMutex
category map[core.MessageStreamID]string
lastHeartBeat time.Time
windowSize int
bufferSizeByte int `config:"ConnectionBufferSizeKB" default:"1024" metric:"kb"`
heartBeatInterval time.Duration `config:"HeartBeatIntervalSec" default:"5" metric:"sec"`
maxWindowSize int `config:"WindowSize" default:"2048"`
connectionTimeout time.Duration `config:"ConnectionTimeoutSec" default:"5" metric:"sec"`
}
const (
scribeMetricMessages = "Scribe:Messages-"
scribeMetricMessagesSec = "Scribe:MessagesSec-"
scribeMetricWindowSize = "Scribe:WindowSize"
scribeMaxRetries = 30
scribeMaxSleepTimeMs = 3000
)
func init() {
core.TypeRegistry.Register(Scribe{})
}
// Configure initializes this producer with values from a plugin config.
func (prod *Scribe) Configure(conf core.PluginConfigReader) {
prod.SetStopCallback(prod.close)
host := conf.GetString("Address", "localhost:1463")
prod.category = conf.GetStreamMap("Categories", "")
prod.windowSize = prod.maxWindowSize
prod.categoryGuard = new(sync.RWMutex)
// Initialize scribe connection
var err error
prod.socket, err = thrift.NewTSocketTimeout(host, prod.connectionTimeout)
conf.Errors.Push(err)
prod.transport = thrift.NewTFramedTransport(prod.socket)
binProtocol := thrift.NewTBinaryProtocol(prod.transport, false, false)
prod.scribe = scribe.NewScribeClientProtocol(prod.transport, binProtocol, binProtocol)
tgo.Metric.New(scribeMetricWindowSize)
tgo.Metric.SetI(scribeMetricWindowSize, prod.windowSize)
for _, category := range prod.category {
metricName := scribeMetricMessages + category
tgo.Metric.New(metricName)
tgo.Metric.NewRate(metricName, scribeMetricMessagesSec+category, time.Second, 10, 3, true)
}
}
func (prod *Scribe) tryOpenConnection() bool {
if !prod.transport.IsOpen() {
if err := prod.transport.Open(); err != nil {
prod.Logger.Error("Connection error:", err)
return false // ### return, cannot connect ###
}
prod.socket.Conn().(bufferedConn).SetWriteBuffer(prod.bufferSizeByte)
prod.lastHeartBeat = time.Now().Add(prod.heartBeatInterval)
prod.Logger.Info("Connection opened")
}
if time.Since(prod.lastHeartBeat) < prod.heartBeatInterval {
return true // ### return, assume alive ###
}
prod.lastHeartBeat = time.Now()
// Check status only when not sending, otherwise scribe gets confused
err := prod.Batch.AfterFlushDo(func() error {
status, err := prod.scribe.GetStatus()
if err != nil {
return err
}
switch status {
case fb303.FbStatus_DEAD:
return fmt.Errorf("Service dead")
case fb303.FbStatus_STOPPING:
return fmt.Errorf("Service stopping")
case fb303.FbStatus_STOPPED:
return fmt.Errorf("Service stopped")
}
return nil // ### return, all is well ###
})
if err == nil {
return true
}
prod.Logger.WithError(err).Error("Scribe status check failed")
prod.transport.Close()
return false
}
func (prod *Scribe) sendBatch() core.AssemblyFunc {
if prod.tryOpenConnection() {
return prod.transformMessages
}
if prod.IsStopping() {
return prod.tryFallbackForMessages
}
return nil
}
func (prod *Scribe) tryFallbackForMessages(messages []*core.Message) {
for _, msg := range messages {
prod.TryFallback(msg)
}
}
func (prod *Scribe) addCategory(streamID core.MessageStreamID) string {
prod.categoryGuard.Lock()
defer prod.categoryGuard.Unlock()
category, exists := prod.category[core.WildcardStreamID]
if exists {
return category
}
category = core.StreamRegistry.GetStreamName(streamID)
metricName := scribeMetricMessages + category
tgo.Metric.New(metricName)
tgo.Metric.NewRate(metricName, scribeMetricMessagesSec+category, time.Second, 10, 3, true)
prod.category[streamID] = category
return category
}
func (prod *Scribe) transformMessages(messages []*core.Message) {
logBuffer := make([]*scribe.LogEntry, len(messages))
// Convert messages to scribe log format
for idx, msg := range messages {
prod.categoryGuard.RLock()
category, exists := prod.category[msg.GetStreamID()]
prod.categoryGuard.RUnlock()
if !exists {
category = prod.addCategory(msg.GetStreamID())
}
logBuffer[idx] = &scribe.LogEntry{
Category: category,
Message: string(msg.GetPayload()),
}
tgo.Metric.Inc(scribeMetricMessages + category)
}
// Try to send the whole batch.
// If this fails, reduce the number of items send until sending succeeds.
idxStart := 0
for retryCount := 0; retryCount < scribeMaxRetries; retryCount++ {
idxEnd := tmath.MinI(len(logBuffer), idxStart+prod.windowSize)
resultCode, err := prod.scribe.Log(logBuffer[idxStart:idxEnd])
if resultCode == scribe.ResultCode_OK {
idxStart = idxEnd
if idxStart < len(logBuffer) {
retryCount = -1 // incremented to 0 after continue
continue // ### continue, data left to send ###
}
// Grow the window on success so we don't get stuck at 1
if prod.windowSize < prod.maxWindowSize {
prod.windowSize = tmath.MinI(prod.windowSize*2, prod.maxWindowSize)
}
return // ### return, success ###
}
if err != nil || resultCode != scribe.ResultCode_TRY_LATER {
prod.Logger.WithError(err).Errorf("Scribe error %d", resultCode)
prod.transport.Close() // reconnect
prod.tryFallbackForMessages(messages[idxStart:])
return // ### return, failure ###
}
// Scribe said "try again".
// Reduce window size to reduce load on server
prod.windowSize = tmath.MaxI(1, prod.windowSize/2)
tgo.Metric.SetI(scribeMetricWindowSize, prod.windowSize)
time.Sleep(time.Duration(scribeMaxSleepTimeMs/scribeMaxRetries) * time.Millisecond)
}
prod.Logger.Errorf("Server seems to be busy")
prod.tryFallbackForMessages(messages[idxStart:])
}
func (prod *Scribe) close() {
defer func() {
prod.transport.Close()
prod.WorkerDone()
}()
prod.DefaultClose()
}
// Produce writes to a buffer that is sent to scribe.
func (prod *Scribe) Produce(workers *sync.WaitGroup) {
prod.AddMainWorker(workers)
prod.BatchMessageLoop(workers, prod.sendBatch)
}