github.com/jiasir/docker@v1.3.3-0.20170609024000-252e610103e7/daemon/logger/splunk/splunk.go (about)

     1  // Package splunk provides the log driver for forwarding server logs to
     2  // Splunk HTTP Event Collector endpoint.
     3  package splunk
     4  
     5  import (
     6  	"bytes"
     7  	"compress/gzip"
     8  	"crypto/tls"
     9  	"crypto/x509"
    10  	"encoding/json"
    11  	"fmt"
    12  	"io"
    13  	"io/ioutil"
    14  	"net/http"
    15  	"net/url"
    16  	"os"
    17  	"strconv"
    18  	"sync"
    19  	"time"
    20  
    21  	"github.com/Sirupsen/logrus"
    22  	"github.com/docker/docker/daemon/logger"
    23  	"github.com/docker/docker/daemon/logger/loggerutils"
    24  	"github.com/docker/docker/pkg/urlutil"
    25  )
    26  
    27  const (
    28  	driverName                    = "splunk"
    29  	splunkURLKey                  = "splunk-url"
    30  	splunkTokenKey                = "splunk-token"
    31  	splunkSourceKey               = "splunk-source"
    32  	splunkSourceTypeKey           = "splunk-sourcetype"
    33  	splunkIndexKey                = "splunk-index"
    34  	splunkCAPathKey               = "splunk-capath"
    35  	splunkCANameKey               = "splunk-caname"
    36  	splunkInsecureSkipVerifyKey   = "splunk-insecureskipverify"
    37  	splunkFormatKey               = "splunk-format"
    38  	splunkVerifyConnectionKey     = "splunk-verify-connection"
    39  	splunkGzipCompressionKey      = "splunk-gzip"
    40  	splunkGzipCompressionLevelKey = "splunk-gzip-level"
    41  	envKey                        = "env"
    42  	envRegexKey                   = "env-regex"
    43  	labelsKey                     = "labels"
    44  	tagKey                        = "tag"
    45  )
    46  
    47  const (
    48  	// How often do we send messages (if we are not reaching batch size)
    49  	defaultPostMessagesFrequency = 5 * time.Second
    50  	// How big can be batch of messages
    51  	defaultPostMessagesBatchSize = 1000
    52  	// Maximum number of messages we can store in buffer
    53  	defaultBufferMaximum = 10 * defaultPostMessagesBatchSize
    54  	// Number of messages allowed to be queued in the channel
    55  	defaultStreamChannelSize = 4 * defaultPostMessagesBatchSize
    56  )
    57  
    58  const (
    59  	envVarPostMessagesFrequency = "SPLUNK_LOGGING_DRIVER_POST_MESSAGES_FREQUENCY"
    60  	envVarPostMessagesBatchSize = "SPLUNK_LOGGING_DRIVER_POST_MESSAGES_BATCH_SIZE"
    61  	envVarBufferMaximum         = "SPLUNK_LOGGING_DRIVER_BUFFER_MAX"
    62  	envVarStreamChannelSize     = "SPLUNK_LOGGING_DRIVER_CHANNEL_SIZE"
    63  )
    64  
    65  type splunkLoggerInterface interface {
    66  	logger.Logger
    67  	worker()
    68  }
    69  
    70  type splunkLogger struct {
    71  	client    *http.Client
    72  	transport *http.Transport
    73  
    74  	url         string
    75  	auth        string
    76  	nullMessage *splunkMessage
    77  
    78  	// http compression
    79  	gzipCompression      bool
    80  	gzipCompressionLevel int
    81  
    82  	// Advanced options
    83  	postMessagesFrequency time.Duration
    84  	postMessagesBatchSize int
    85  	bufferMaximum         int
    86  
    87  	// For synchronization between background worker and logger.
    88  	// We use channel to send messages to worker go routine.
    89  	// All other variables for blocking Close call before we flush all messages to HEC
    90  	stream     chan *splunkMessage
    91  	lock       sync.RWMutex
    92  	closed     bool
    93  	closedCond *sync.Cond
    94  }
    95  
    96  type splunkLoggerInline struct {
    97  	*splunkLogger
    98  
    99  	nullEvent *splunkMessageEvent
   100  }
   101  
   102  type splunkLoggerJSON struct {
   103  	*splunkLoggerInline
   104  }
   105  
   106  type splunkLoggerRaw struct {
   107  	*splunkLogger
   108  
   109  	prefix []byte
   110  }
   111  
   112  type splunkMessage struct {
   113  	Event      interface{} `json:"event"`
   114  	Time       string      `json:"time"`
   115  	Host       string      `json:"host"`
   116  	Source     string      `json:"source,omitempty"`
   117  	SourceType string      `json:"sourcetype,omitempty"`
   118  	Index      string      `json:"index,omitempty"`
   119  }
   120  
   121  type splunkMessageEvent struct {
   122  	Line   interface{}       `json:"line"`
   123  	Source string            `json:"source"`
   124  	Tag    string            `json:"tag,omitempty"`
   125  	Attrs  map[string]string `json:"attrs,omitempty"`
   126  }
   127  
   128  const (
   129  	splunkFormatRaw    = "raw"
   130  	splunkFormatJSON   = "json"
   131  	splunkFormatInline = "inline"
   132  )
   133  
   134  func init() {
   135  	if err := logger.RegisterLogDriver(driverName, New); err != nil {
   136  		logrus.Fatal(err)
   137  	}
   138  	if err := logger.RegisterLogOptValidator(driverName, ValidateLogOpt); err != nil {
   139  		logrus.Fatal(err)
   140  	}
   141  }
   142  
   143  // New creates splunk logger driver using configuration passed in context
   144  func New(info logger.Info) (logger.Logger, error) {
   145  	hostname, err := info.Hostname()
   146  	if err != nil {
   147  		return nil, fmt.Errorf("%s: cannot access hostname to set source field", driverName)
   148  	}
   149  
   150  	// Parse and validate Splunk URL
   151  	splunkURL, err := parseURL(info)
   152  	if err != nil {
   153  		return nil, err
   154  	}
   155  
   156  	// Splunk Token is required parameter
   157  	splunkToken, ok := info.Config[splunkTokenKey]
   158  	if !ok {
   159  		return nil, fmt.Errorf("%s: %s is expected", driverName, splunkTokenKey)
   160  	}
   161  
   162  	tlsConfig := &tls.Config{}
   163  
   164  	// Splunk is using autogenerated certificates by default,
   165  	// allow users to trust them with skipping verification
   166  	if insecureSkipVerifyStr, ok := info.Config[splunkInsecureSkipVerifyKey]; ok {
   167  		insecureSkipVerify, err := strconv.ParseBool(insecureSkipVerifyStr)
   168  		if err != nil {
   169  			return nil, err
   170  		}
   171  		tlsConfig.InsecureSkipVerify = insecureSkipVerify
   172  	}
   173  
   174  	// If path to the root certificate is provided - load it
   175  	if caPath, ok := info.Config[splunkCAPathKey]; ok {
   176  		caCert, err := ioutil.ReadFile(caPath)
   177  		if err != nil {
   178  			return nil, err
   179  		}
   180  		caPool := x509.NewCertPool()
   181  		caPool.AppendCertsFromPEM(caCert)
   182  		tlsConfig.RootCAs = caPool
   183  	}
   184  
   185  	if caName, ok := info.Config[splunkCANameKey]; ok {
   186  		tlsConfig.ServerName = caName
   187  	}
   188  
   189  	gzipCompression := false
   190  	if gzipCompressionStr, ok := info.Config[splunkGzipCompressionKey]; ok {
   191  		gzipCompression, err = strconv.ParseBool(gzipCompressionStr)
   192  		if err != nil {
   193  			return nil, err
   194  		}
   195  	}
   196  
   197  	gzipCompressionLevel := gzip.DefaultCompression
   198  	if gzipCompressionLevelStr, ok := info.Config[splunkGzipCompressionLevelKey]; ok {
   199  		var err error
   200  		gzipCompressionLevel64, err := strconv.ParseInt(gzipCompressionLevelStr, 10, 32)
   201  		if err != nil {
   202  			return nil, err
   203  		}
   204  		gzipCompressionLevel = int(gzipCompressionLevel64)
   205  		if gzipCompressionLevel < gzip.DefaultCompression || gzipCompressionLevel > gzip.BestCompression {
   206  			err := fmt.Errorf("Not supported level '%s' for %s (supported values between %d and %d).",
   207  				gzipCompressionLevelStr, splunkGzipCompressionLevelKey, gzip.DefaultCompression, gzip.BestCompression)
   208  			return nil, err
   209  		}
   210  	}
   211  
   212  	transport := &http.Transport{
   213  		TLSClientConfig: tlsConfig,
   214  	}
   215  	client := &http.Client{
   216  		Transport: transport,
   217  	}
   218  
   219  	source := info.Config[splunkSourceKey]
   220  	sourceType := info.Config[splunkSourceTypeKey]
   221  	index := info.Config[splunkIndexKey]
   222  
   223  	var nullMessage = &splunkMessage{
   224  		Host:       hostname,
   225  		Source:     source,
   226  		SourceType: sourceType,
   227  		Index:      index,
   228  	}
   229  
   230  	// Allow user to remove tag from the messages by setting tag to empty string
   231  	tag := ""
   232  	if tagTemplate, ok := info.Config[tagKey]; !ok || tagTemplate != "" {
   233  		tag, err = loggerutils.ParseLogTag(info, loggerutils.DefaultTemplate)
   234  		if err != nil {
   235  			return nil, err
   236  		}
   237  	}
   238  
   239  	attrs, err := info.ExtraAttributes(nil)
   240  	if err != nil {
   241  		return nil, err
   242  	}
   243  
   244  	var (
   245  		postMessagesFrequency = getAdvancedOptionDuration(envVarPostMessagesFrequency, defaultPostMessagesFrequency)
   246  		postMessagesBatchSize = getAdvancedOptionInt(envVarPostMessagesBatchSize, defaultPostMessagesBatchSize)
   247  		bufferMaximum         = getAdvancedOptionInt(envVarBufferMaximum, defaultBufferMaximum)
   248  		streamChannelSize     = getAdvancedOptionInt(envVarStreamChannelSize, defaultStreamChannelSize)
   249  	)
   250  
   251  	logger := &splunkLogger{
   252  		client:                client,
   253  		transport:             transport,
   254  		url:                   splunkURL.String(),
   255  		auth:                  "Splunk " + splunkToken,
   256  		nullMessage:           nullMessage,
   257  		gzipCompression:       gzipCompression,
   258  		gzipCompressionLevel:  gzipCompressionLevel,
   259  		stream:                make(chan *splunkMessage, streamChannelSize),
   260  		postMessagesFrequency: postMessagesFrequency,
   261  		postMessagesBatchSize: postMessagesBatchSize,
   262  		bufferMaximum:         bufferMaximum,
   263  	}
   264  
   265  	// By default we verify connection, but we allow use to skip that
   266  	verifyConnection := true
   267  	if verifyConnectionStr, ok := info.Config[splunkVerifyConnectionKey]; ok {
   268  		var err error
   269  		verifyConnection, err = strconv.ParseBool(verifyConnectionStr)
   270  		if err != nil {
   271  			return nil, err
   272  		}
   273  	}
   274  	if verifyConnection {
   275  		err = verifySplunkConnection(logger)
   276  		if err != nil {
   277  			return nil, err
   278  		}
   279  	}
   280  
   281  	var splunkFormat string
   282  	if splunkFormatParsed, ok := info.Config[splunkFormatKey]; ok {
   283  		switch splunkFormatParsed {
   284  		case splunkFormatInline:
   285  		case splunkFormatJSON:
   286  		case splunkFormatRaw:
   287  		default:
   288  			return nil, fmt.Errorf("Unknown format specified %s, supported formats are inline, json and raw", splunkFormat)
   289  		}
   290  		splunkFormat = splunkFormatParsed
   291  	} else {
   292  		splunkFormat = splunkFormatInline
   293  	}
   294  
   295  	var loggerWrapper splunkLoggerInterface
   296  
   297  	switch splunkFormat {
   298  	case splunkFormatInline:
   299  		nullEvent := &splunkMessageEvent{
   300  			Tag:   tag,
   301  			Attrs: attrs,
   302  		}
   303  
   304  		loggerWrapper = &splunkLoggerInline{logger, nullEvent}
   305  	case splunkFormatJSON:
   306  		nullEvent := &splunkMessageEvent{
   307  			Tag:   tag,
   308  			Attrs: attrs,
   309  		}
   310  
   311  		loggerWrapper = &splunkLoggerJSON{&splunkLoggerInline{logger, nullEvent}}
   312  	case splunkFormatRaw:
   313  		var prefix bytes.Buffer
   314  		if tag != "" {
   315  			prefix.WriteString(tag)
   316  			prefix.WriteString(" ")
   317  		}
   318  		for key, value := range attrs {
   319  			prefix.WriteString(key)
   320  			prefix.WriteString("=")
   321  			prefix.WriteString(value)
   322  			prefix.WriteString(" ")
   323  		}
   324  
   325  		loggerWrapper = &splunkLoggerRaw{logger, prefix.Bytes()}
   326  	default:
   327  		return nil, fmt.Errorf("Unexpected format %s", splunkFormat)
   328  	}
   329  
   330  	go loggerWrapper.worker()
   331  
   332  	return loggerWrapper, nil
   333  }
   334  
   335  func (l *splunkLoggerInline) Log(msg *logger.Message) error {
   336  	message := l.createSplunkMessage(msg)
   337  
   338  	event := *l.nullEvent
   339  	event.Line = string(msg.Line)
   340  	event.Source = msg.Source
   341  
   342  	message.Event = &event
   343  	logger.PutMessage(msg)
   344  	return l.queueMessageAsync(message)
   345  }
   346  
   347  func (l *splunkLoggerJSON) Log(msg *logger.Message) error {
   348  	message := l.createSplunkMessage(msg)
   349  	event := *l.nullEvent
   350  
   351  	var rawJSONMessage json.RawMessage
   352  	if err := json.Unmarshal(msg.Line, &rawJSONMessage); err == nil {
   353  		event.Line = &rawJSONMessage
   354  	} else {
   355  		event.Line = string(msg.Line)
   356  	}
   357  
   358  	event.Source = msg.Source
   359  
   360  	message.Event = &event
   361  	logger.PutMessage(msg)
   362  	return l.queueMessageAsync(message)
   363  }
   364  
   365  func (l *splunkLoggerRaw) Log(msg *logger.Message) error {
   366  	message := l.createSplunkMessage(msg)
   367  
   368  	message.Event = string(append(l.prefix, msg.Line...))
   369  	logger.PutMessage(msg)
   370  	return l.queueMessageAsync(message)
   371  }
   372  
   373  func (l *splunkLogger) queueMessageAsync(message *splunkMessage) error {
   374  	l.lock.RLock()
   375  	defer l.lock.RUnlock()
   376  	if l.closedCond != nil {
   377  		return fmt.Errorf("%s: driver is closed", driverName)
   378  	}
   379  	l.stream <- message
   380  	return nil
   381  }
   382  
   383  func (l *splunkLogger) worker() {
   384  	timer := time.NewTicker(l.postMessagesFrequency)
   385  	var messages []*splunkMessage
   386  	for {
   387  		select {
   388  		case message, open := <-l.stream:
   389  			if !open {
   390  				l.postMessages(messages, true)
   391  				l.lock.Lock()
   392  				defer l.lock.Unlock()
   393  				l.transport.CloseIdleConnections()
   394  				l.closed = true
   395  				l.closedCond.Signal()
   396  				return
   397  			}
   398  			messages = append(messages, message)
   399  			// Only sending when we get exactly to the batch size,
   400  			// This also helps not to fire postMessages on every new message,
   401  			// when previous try failed.
   402  			if len(messages)%l.postMessagesBatchSize == 0 {
   403  				messages = l.postMessages(messages, false)
   404  			}
   405  		case <-timer.C:
   406  			messages = l.postMessages(messages, false)
   407  		}
   408  	}
   409  }
   410  
   411  func (l *splunkLogger) postMessages(messages []*splunkMessage, lastChance bool) []*splunkMessage {
   412  	messagesLen := len(messages)
   413  	for i := 0; i < messagesLen; i += l.postMessagesBatchSize {
   414  		upperBound := i + l.postMessagesBatchSize
   415  		if upperBound > messagesLen {
   416  			upperBound = messagesLen
   417  		}
   418  		if err := l.tryPostMessages(messages[i:upperBound]); err != nil {
   419  			logrus.Error(err)
   420  			if messagesLen-i >= l.bufferMaximum || lastChance {
   421  				// If this is last chance - print them all to the daemon log
   422  				if lastChance {
   423  					upperBound = messagesLen
   424  				}
   425  				// Not all sent, but buffer has got to its maximum, let's log all messages
   426  				// we could not send and return buffer minus one batch size
   427  				for j := i; j < upperBound; j++ {
   428  					if jsonEvent, err := json.Marshal(messages[j]); err != nil {
   429  						logrus.Error(err)
   430  					} else {
   431  						logrus.Error(fmt.Errorf("Failed to send a message '%s'", string(jsonEvent)))
   432  					}
   433  				}
   434  				return messages[upperBound:messagesLen]
   435  			}
   436  			// Not all sent, returning buffer from where we have not sent messages
   437  			return messages[i:messagesLen]
   438  		}
   439  	}
   440  	// All sent, return empty buffer
   441  	return messages[:0]
   442  }
   443  
   444  func (l *splunkLogger) tryPostMessages(messages []*splunkMessage) error {
   445  	if len(messages) == 0 {
   446  		return nil
   447  	}
   448  	var buffer bytes.Buffer
   449  	var writer io.Writer
   450  	var gzipWriter *gzip.Writer
   451  	var err error
   452  	// If gzip compression is enabled - create gzip writer with specified compression
   453  	// level. If gzip compression is disabled, use standard buffer as a writer
   454  	if l.gzipCompression {
   455  		gzipWriter, err = gzip.NewWriterLevel(&buffer, l.gzipCompressionLevel)
   456  		if err != nil {
   457  			return err
   458  		}
   459  		writer = gzipWriter
   460  	} else {
   461  		writer = &buffer
   462  	}
   463  	for _, message := range messages {
   464  		jsonEvent, err := json.Marshal(message)
   465  		if err != nil {
   466  			return err
   467  		}
   468  		if _, err := writer.Write(jsonEvent); err != nil {
   469  			return err
   470  		}
   471  	}
   472  	// If gzip compression is enabled, tell it, that we are done
   473  	if l.gzipCompression {
   474  		err = gzipWriter.Close()
   475  		if err != nil {
   476  			return err
   477  		}
   478  	}
   479  	req, err := http.NewRequest("POST", l.url, bytes.NewBuffer(buffer.Bytes()))
   480  	if err != nil {
   481  		return err
   482  	}
   483  	req.Header.Set("Authorization", l.auth)
   484  	// Tell if we are sending gzip compressed body
   485  	if l.gzipCompression {
   486  		req.Header.Set("Content-Encoding", "gzip")
   487  	}
   488  	res, err := l.client.Do(req)
   489  	if err != nil {
   490  		return err
   491  	}
   492  	defer res.Body.Close()
   493  	if res.StatusCode != http.StatusOK {
   494  		var body []byte
   495  		body, err = ioutil.ReadAll(res.Body)
   496  		if err != nil {
   497  			return err
   498  		}
   499  		return fmt.Errorf("%s: failed to send event - %s - %s", driverName, res.Status, body)
   500  	}
   501  	io.Copy(ioutil.Discard, res.Body)
   502  	return nil
   503  }
   504  
   505  func (l *splunkLogger) Close() error {
   506  	l.lock.Lock()
   507  	defer l.lock.Unlock()
   508  	if l.closedCond == nil {
   509  		l.closedCond = sync.NewCond(&l.lock)
   510  		close(l.stream)
   511  		for !l.closed {
   512  			l.closedCond.Wait()
   513  		}
   514  	}
   515  	return nil
   516  }
   517  
   518  func (l *splunkLogger) Name() string {
   519  	return driverName
   520  }
   521  
   522  func (l *splunkLogger) createSplunkMessage(msg *logger.Message) *splunkMessage {
   523  	message := *l.nullMessage
   524  	message.Time = fmt.Sprintf("%f", float64(msg.Timestamp.UnixNano())/float64(time.Second))
   525  	return &message
   526  }
   527  
   528  // ValidateLogOpt looks for all supported by splunk driver options
   529  func ValidateLogOpt(cfg map[string]string) error {
   530  	for key := range cfg {
   531  		switch key {
   532  		case splunkURLKey:
   533  		case splunkTokenKey:
   534  		case splunkSourceKey:
   535  		case splunkSourceTypeKey:
   536  		case splunkIndexKey:
   537  		case splunkCAPathKey:
   538  		case splunkCANameKey:
   539  		case splunkInsecureSkipVerifyKey:
   540  		case splunkFormatKey:
   541  		case splunkVerifyConnectionKey:
   542  		case splunkGzipCompressionKey:
   543  		case splunkGzipCompressionLevelKey:
   544  		case envKey:
   545  		case envRegexKey:
   546  		case labelsKey:
   547  		case tagKey:
   548  		default:
   549  			return fmt.Errorf("unknown log opt '%s' for %s log driver", key, driverName)
   550  		}
   551  	}
   552  	return nil
   553  }
   554  
   555  func parseURL(info logger.Info) (*url.URL, error) {
   556  	splunkURLStr, ok := info.Config[splunkURLKey]
   557  	if !ok {
   558  		return nil, fmt.Errorf("%s: %s is expected", driverName, splunkURLKey)
   559  	}
   560  
   561  	splunkURL, err := url.Parse(splunkURLStr)
   562  	if err != nil {
   563  		return nil, fmt.Errorf("%s: failed to parse %s as url value in %s", driverName, splunkURLStr, splunkURLKey)
   564  	}
   565  
   566  	if !urlutil.IsURL(splunkURLStr) ||
   567  		!splunkURL.IsAbs() ||
   568  		(splunkURL.Path != "" && splunkURL.Path != "/") ||
   569  		splunkURL.RawQuery != "" ||
   570  		splunkURL.Fragment != "" {
   571  		return nil, fmt.Errorf("%s: expected format scheme://dns_name_or_ip:port for %s", driverName, splunkURLKey)
   572  	}
   573  
   574  	splunkURL.Path = "/services/collector/event/1.0"
   575  
   576  	return splunkURL, nil
   577  }
   578  
   579  func verifySplunkConnection(l *splunkLogger) error {
   580  	req, err := http.NewRequest(http.MethodOptions, l.url, nil)
   581  	if err != nil {
   582  		return err
   583  	}
   584  	res, err := l.client.Do(req)
   585  	if err != nil {
   586  		return err
   587  	}
   588  	if res.Body != nil {
   589  		defer res.Body.Close()
   590  	}
   591  	if res.StatusCode != http.StatusOK {
   592  		var body []byte
   593  		body, err = ioutil.ReadAll(res.Body)
   594  		if err != nil {
   595  			return err
   596  		}
   597  		return fmt.Errorf("%s: failed to verify connection - %s - %s", driverName, res.Status, body)
   598  	}
   599  	return nil
   600  }
   601  
   602  func getAdvancedOptionDuration(envName string, defaultValue time.Duration) time.Duration {
   603  	valueStr := os.Getenv(envName)
   604  	if valueStr == "" {
   605  		return defaultValue
   606  	}
   607  	parsedValue, err := time.ParseDuration(valueStr)
   608  	if err != nil {
   609  		logrus.Error(fmt.Sprintf("Failed to parse value of %s as duration. Using default %v. %v", envName, defaultValue, err))
   610  		return defaultValue
   611  	}
   612  	return parsedValue
   613  }
   614  
   615  func getAdvancedOptionInt(envName string, defaultValue int) int {
   616  	valueStr := os.Getenv(envName)
   617  	if valueStr == "" {
   618  		return defaultValue
   619  	}
   620  	parsedValue, err := strconv.ParseInt(valueStr, 10, 32)
   621  	if err != nil {
   622  		logrus.Error(fmt.Sprintf("Failed to parse value of %s as integer. Using default %d. %v", envName, defaultValue, err))
   623  		return defaultValue
   624  	}
   625  	return int(parsedValue)
   626  }