logger.go

Documentation: github.com/Azure/go-autorest/logger

     1  package logger
     2  
     3  // Copyright 2017 Microsoft Corporation
     4  //
     5  //  Licensed under the Apache License, Version 2.0 (the "License");
     6  //  you may not use this file except in compliance with the License.
     7  //  You may obtain a copy of the License at
     8  //
     9  //      http://www.apache.org/licenses/LICENSE-2.0
    10  //
    11  //  Unless required by applicable law or agreed to in writing, software
    12  //  distributed under the License is distributed on an "AS IS" BASIS,
    13  //  WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
    14  //  See the License for the specific language governing permissions and
    15  //  limitations under the License.
    16  
    17  import (
    18  	"bytes"
    19  	"fmt"
    20  	"io"
    21  	"io/ioutil"
    22  	"net/http"
    23  	"net/url"
    24  	"os"
    25  	"strings"
    26  	"sync"
    27  	"time"
    28  )
    29  
    30  // LevelType tells a logger the minimum level to log. When code reports a log entry,
    31  // the LogLevel indicates the level of the log entry. The logger only records entries
    32  // whose level is at least the level it was told to log. See the Log* constants.
    33  // For example, if a logger is configured with LogError, then LogError, LogPanic,
    34  // and LogFatal entries will be logged; lower level entries are ignored.
    35  type LevelType uint32
    36  
    37  const (
    38  	// LogNone tells a logger not to log any entries passed to it.
    39  	LogNone LevelType = iota
    40  
    41  	// LogFatal tells a logger to log all LogFatal entries passed to it.
    42  	LogFatal
    43  
    44  	// LogPanic tells a logger to log all LogPanic and LogFatal entries passed to it.
    45  	LogPanic
    46  
    47  	// LogError tells a logger to log all LogError, LogPanic and LogFatal entries passed to it.
    48  	LogError
    49  
    50  	// LogWarning tells a logger to log all LogWarning, LogError, LogPanic and LogFatal entries passed to it.
    51  	LogWarning
    52  
    53  	// LogInfo tells a logger to log all LogInfo, LogWarning, LogError, LogPanic and LogFatal entries passed to it.
    54  	LogInfo
    55  
    56  	// LogDebug tells a logger to log all LogDebug, LogInfo, LogWarning, LogError, LogPanic and LogFatal entries passed to it.
    57  	LogDebug
    58  
    59  	// LogAuth is a special case of LogDebug, it tells a logger to also log the body of an authentication request and response.
    60  	// NOTE: this can disclose sensitive information, use with care.
    61  	LogAuth
    62  )
    63  
    64  const (
    65  	logNone    = "NONE"
    66  	logFatal   = "FATAL"
    67  	logPanic   = "PANIC"
    68  	logError   = "ERROR"
    69  	logWarning = "WARNING"
    70  	logInfo    = "INFO"
    71  	logDebug   = "DEBUG"
    72  	logAuth    = "AUTH"
    73  	logUnknown = "UNKNOWN"
    74  )
    75  
    76  // ParseLevel converts the specified string into the corresponding LevelType.
    77  func ParseLevel(s string) (lt LevelType, err error) {
    78  	switch strings.ToUpper(s) {
    79  	case logFatal:
    80  		lt = LogFatal
    81  	case logPanic:
    82  		lt = LogPanic
    83  	case logError:
    84  		lt = LogError
    85  	case logWarning:
    86  		lt = LogWarning
    87  	case logInfo:
    88  		lt = LogInfo
    89  	case logDebug:
    90  		lt = LogDebug
    91  	case logAuth:
    92  		lt = LogAuth
    93  	default:
    94  		err = fmt.Errorf("bad log level '%s'", s)
    95  	}
    96  	return
    97  }
    98  
    99  // String implements the stringer interface for LevelType.
   100  func (lt LevelType) String() string {
   101  	switch lt {
   102  	case LogNone:
   103  		return logNone
   104  	case LogFatal:
   105  		return logFatal
   106  	case LogPanic:
   107  		return logPanic
   108  	case LogError:
   109  		return logError
   110  	case LogWarning:
   111  		return logWarning
   112  	case LogInfo:
   113  		return logInfo
   114  	case LogDebug:
   115  		return logDebug
   116  	case LogAuth:
   117  		return logAuth
   118  	default:
   119  		return logUnknown
   120  	}
   121  }
   122  
   123  // Filter defines functions for filtering HTTP request/response content.
   124  type Filter struct {
   125  	// URL returns a potentially modified string representation of a request URL.
   126  	URL func(u *url.URL) string
   127  
   128  	// Header returns a potentially modified set of values for the specified key.
   129  	// To completely exclude the header key/values return false.
   130  	Header func(key string, val []string) (bool, []string)
   131  
   132  	// Body returns a potentially modified request/response body.
   133  	Body func(b []byte) []byte
   134  }
   135  
   136  func (f Filter) processURL(u *url.URL) string {
   137  	if f.URL == nil {
   138  		return u.String()
   139  	}
   140  	return f.URL(u)
   141  }
   142  
   143  func (f Filter) processHeader(k string, val []string) (bool, []string) {
   144  	if f.Header == nil {
   145  		return true, val
   146  	}
   147  	return f.Header(k, val)
   148  }
   149  
   150  func (f Filter) processBody(b []byte) []byte {
   151  	if f.Body == nil {
   152  		return b
   153  	}
   154  	return f.Body(b)
   155  }
   156  
   157  // Writer defines methods for writing to a logging facility.
   158  type Writer interface {
   159  	// Writeln writes the specified message with the standard log entry header and new-line character.
   160  	Writeln(level LevelType, message string)
   161  
   162  	// Writef writes the specified format specifier with the standard log entry header and no new-line character.
   163  	Writef(level LevelType, format string, a ...interface{})
   164  
   165  	// WriteRequest writes the specified HTTP request to the logger if the log level is greater than
   166  	// or equal to LogInfo.  The request body, if set, is logged at level LogDebug or higher.
   167  	// Custom filters can be specified to exclude URL, header, and/or body content from the log.
   168  	// By default no request content is excluded.
   169  	WriteRequest(req *http.Request, filter Filter)
   170  
   171  	// WriteResponse writes the specified HTTP response to the logger if the log level is greater than
   172  	// or equal to LogInfo.  The response body, if set, is logged at level LogDebug or higher.
   173  	// Custom filters can be specified to exclude URL, header, and/or body content from the log.
   174  	// By default no response content is excluded.
   175  	WriteResponse(resp *http.Response, filter Filter)
   176  }
   177  
   178  // Instance is the default log writer initialized during package init.
   179  // This can be replaced with a custom implementation as required.
   180  var Instance Writer
   181  
   182  // default log level
   183  var logLevel = LogNone
   184  
   185  // Level returns the value specified in AZURE_GO_AUTOREST_LOG_LEVEL.
   186  // If no value was specified the default value is LogNone.
   187  // Custom loggers can call this to retrieve the configured log level.
   188  func Level() LevelType {
   189  	return logLevel
   190  }
   191  
   192  func init() {
   193  	// separated for testing purposes
   194  	initDefaultLogger()
   195  }
   196  
   197  func initDefaultLogger() {
   198  	// init with nilLogger so callers don't have to do a nil check on Default
   199  	Instance = nilLogger{}
   200  	llStr := strings.ToLower(os.Getenv("AZURE_GO_SDK_LOG_LEVEL"))
   201  	if llStr == "" {
   202  		return
   203  	}
   204  	var err error
   205  	logLevel, err = ParseLevel(llStr)
   206  	if err != nil {
   207  		fmt.Fprintf(os.Stderr, "go-autorest: failed to parse log level: %s\n", err.Error())
   208  		return
   209  	}
   210  	if logLevel == LogNone {
   211  		return
   212  	}
   213  	// default to stderr
   214  	dest := os.Stderr
   215  	lfStr := os.Getenv("AZURE_GO_SDK_LOG_FILE")
   216  	if strings.EqualFold(lfStr, "stdout") {
   217  		dest = os.Stdout
   218  	} else if lfStr != "" {
   219  		lf, err := os.Create(lfStr)
   220  		if err == nil {
   221  			dest = lf
   222  		} else {
   223  			fmt.Fprintf(os.Stderr, "go-autorest: failed to create log file, using stderr: %s\n", err.Error())
   224  		}
   225  	}
   226  	Instance = fileLogger{
   227  		logLevel: logLevel,
   228  		mu:       &sync.Mutex{},
   229  		logFile:  dest,
   230  	}
   231  }
   232  
   233  // the nil logger does nothing
   234  type nilLogger struct{}
   235  
   236  func (nilLogger) Writeln(LevelType, string) {}
   237  
   238  func (nilLogger) Writef(LevelType, string, ...interface{}) {}
   239  
   240  func (nilLogger) WriteRequest(*http.Request, Filter) {}
   241  
   242  func (nilLogger) WriteResponse(*http.Response, Filter) {}
   243  
   244  // A File is used instead of a Logger so the stream can be flushed after every write.
   245  type fileLogger struct {
   246  	logLevel LevelType
   247  	mu       *sync.Mutex // for synchronizing writes to logFile
   248  	logFile  *os.File
   249  }
   250  
   251  func (fl fileLogger) Writeln(level LevelType, message string) {
   252  	fl.Writef(level, "%s\n", message)
   253  }
   254  
   255  func (fl fileLogger) Writef(level LevelType, format string, a ...interface{}) {
   256  	if fl.logLevel >= level {
   257  		fl.mu.Lock()
   258  		defer fl.mu.Unlock()
   259  		fmt.Fprintf(fl.logFile, "%s %s", entryHeader(level), fmt.Sprintf(format, a...))
   260  		fl.logFile.Sync()
   261  	}
   262  }
   263  
   264  func (fl fileLogger) WriteRequest(req *http.Request, filter Filter) {
   265  	if req == nil || fl.logLevel < LogInfo {
   266  		return
   267  	}
   268  	b := &bytes.Buffer{}
   269  	fmt.Fprintf(b, "%s REQUEST: %s %s\n", entryHeader(LogInfo), req.Method, filter.processURL(req.URL))
   270  	// dump headers
   271  	for k, v := range req.Header {
   272  		if ok, mv := filter.processHeader(k, v); ok {
   273  			fmt.Fprintf(b, "%s: %s\n", k, strings.Join(mv, ","))
   274  		}
   275  	}
   276  	if fl.shouldLogBody(req.Header, req.Body) {
   277  		// dump body
   278  		body, err := ioutil.ReadAll(req.Body)
   279  		if err == nil {
   280  			fmt.Fprintln(b, string(filter.processBody(body)))
   281  			if nc, ok := req.Body.(io.Seeker); ok {
   282  				// rewind to the beginning
   283  				nc.Seek(0, io.SeekStart)
   284  			} else {
   285  				// recreate the body
   286  				req.Body = ioutil.NopCloser(bytes.NewReader(body))
   287  			}
   288  		} else {
   289  			fmt.Fprintf(b, "failed to read body: %v\n", err)
   290  		}
   291  	}
   292  	fl.mu.Lock()
   293  	defer fl.mu.Unlock()
   294  	fmt.Fprint(fl.logFile, b.String())
   295  	fl.logFile.Sync()
   296  }
   297  
   298  func (fl fileLogger) WriteResponse(resp *http.Response, filter Filter) {
   299  	if resp == nil || fl.logLevel < LogInfo {
   300  		return
   301  	}
   302  	b := &bytes.Buffer{}
   303  	fmt.Fprintf(b, "%s RESPONSE: %d %s\n", entryHeader(LogInfo), resp.StatusCode, filter.processURL(resp.Request.URL))
   304  	// dump headers
   305  	for k, v := range resp.Header {
   306  		if ok, mv := filter.processHeader(k, v); ok {
   307  			fmt.Fprintf(b, "%s: %s\n", k, strings.Join(mv, ","))
   308  		}
   309  	}
   310  	if fl.shouldLogBody(resp.Header, resp.Body) {
   311  		// dump body
   312  		defer resp.Body.Close()
   313  		body, err := ioutil.ReadAll(resp.Body)
   314  		if err == nil {
   315  			fmt.Fprintln(b, string(filter.processBody(body)))
   316  			resp.Body = ioutil.NopCloser(bytes.NewReader(body))
   317  		} else {
   318  			fmt.Fprintf(b, "failed to read body: %v\n", err)
   319  		}
   320  	}
   321  	fl.mu.Lock()
   322  	defer fl.mu.Unlock()
   323  	fmt.Fprint(fl.logFile, b.String())
   324  	fl.logFile.Sync()
   325  }
   326  
   327  // returns true if the provided body should be included in the log
   328  func (fl fileLogger) shouldLogBody(header http.Header, body io.ReadCloser) bool {
   329  	ct := header.Get("Content-Type")
   330  	return fl.logLevel >= LogDebug && body != nil && !strings.Contains(ct, "application/octet-stream")
   331  }
   332  
   333  // creates standard header for log entries, it contains a timestamp and the log level
   334  func entryHeader(level LevelType) string {
   335  	// this format provides a fixed number of digits so the size of the timestamp is constant
   336  	return fmt.Sprintf("(%s) %s:", time.Now().Format("2006-01-02T15:04:05.0000000Z07:00"), level.String())
   337  }
   338
View as plain text