logger_test.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  	"fmt"
    19  	"io/ioutil"
    20  	"net/http"
    21  	"os"
    22  	"path"
    23  	"regexp"
    24  	"strings"
    25  	"testing"
    26  )
    27  
    28  func TestNilLogger(t *testing.T) {
    29  	// verify no crash with no logging
    30  	Instance.WriteRequest(nil, Filter{})
    31  }
    32  
    33  const (
    34  	reqURL                = "https://fakething/dot/com"
    35  	reqHeaderKey          = "x-header"
    36  	reqHeaderVal          = "value"
    37  	reqBody               = "the request body"
    38  	respHeaderKey         = "response-header"
    39  	respHeaderVal         = "something"
    40  	respBody              = "the response body"
    41  	logFileTimeStampRegex = `\(\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\.\d{7}(-\d{2}:\d{2}|Z)\)`
    42  )
    43  
    44  func TestLogReqRespNoBody(t *testing.T) {
    45  	err := os.Setenv("AZURE_GO_SDK_LOG_LEVEL", "info")
    46  	if err != nil {
    47  		t.Fatalf("failed to set log level: %v", err)
    48  	}
    49  	lf := path.Join(os.TempDir(), "testloggingbasic.log")
    50  	err = os.Setenv("AZURE_GO_SDK_LOG_FILE", lf)
    51  	if err != nil {
    52  		t.Fatalf("failed to set log file: %v", err)
    53  	}
    54  	initDefaultLogger()
    55  	if Level() != LogInfo {
    56  		t.Fatalf("wrong log level: %d", Level())
    57  	}
    58  	// create mock request and response for logging
    59  	req, err := http.NewRequest(http.MethodGet, reqURL, nil)
    60  	if err != nil {
    61  		t.Fatalf("failed to create mock request: %v", err)
    62  	}
    63  	req.Header.Add(reqHeaderKey, reqHeaderVal)
    64  	Instance.WriteRequest(req, Filter{})
    65  	resp := &http.Response{
    66  		Status:     "200 OK",
    67  		StatusCode: 200,
    68  		Proto:      "HTTP/1.0",
    69  		ProtoMajor: 1,
    70  		ProtoMinor: 0,
    71  		Request:    req,
    72  		Header:     http.Header{},
    73  	}
    74  	resp.Header.Add(respHeaderKey, respHeaderVal)
    75  	Instance.WriteResponse(resp, Filter{})
    76  	if fl, ok := Instance.(fileLogger); ok {
    77  		fl.logFile.Close()
    78  	} else {
    79  		t.Fatal("expected Instance to be fileLogger")
    80  	}
    81  	// parse log file to ensure contents match
    82  	b, err := ioutil.ReadFile(lf)
    83  	if err != nil {
    84  		t.Fatalf("failed to read log file: %v", err)
    85  	}
    86  	parts := strings.Split(string(b), "\n")
    87  	reqMatch := fmt.Sprintf("%s INFO: REQUEST: %s %s", logFileTimeStampRegex, req.Method, req.URL.String())
    88  	respMatch := fmt.Sprintf("%s INFO: RESPONSE: %d %s", logFileTimeStampRegex, resp.StatusCode, resp.Request.URL.String())
    89  	if !matchRegex(t, reqMatch, parts[0]) {
    90  		t.Fatalf("request header doesn't match: %s", parts[0])
    91  	}
    92  	if !matchRegex(t, fmt.Sprintf("(?i)%s: %s", reqHeaderKey, reqHeaderVal), parts[1]) {
    93  		t.Fatalf("request header entry doesn't match: %s", parts[1])
    94  	}
    95  	if !matchRegex(t, respMatch, parts[2]) {
    96  		t.Fatalf("response header doesn't match: %s", parts[2])
    97  	}
    98  	if !matchRegex(t, fmt.Sprintf("(?i)%s: %s", respHeaderKey, respHeaderVal), parts[3]) {
    99  		t.Fatalf("response header value doesn't match: %s", parts[3])
   100  	}
   101  	// disable logging
   102  	err = os.Setenv("AZURE_GO_SDK_LOG_LEVEL", "")
   103  	if err != nil {
   104  		t.Fatalf("failed to clear log level: %v", err)
   105  	}
   106  }
   107  
   108  func TestLogReqRespWithBody(t *testing.T) {
   109  	err := os.Setenv("AZURE_GO_SDK_LOG_LEVEL", "debug")
   110  	if err != nil {
   111  		t.Fatalf("failed to set log level: %v", err)
   112  	}
   113  	lf := path.Join(os.TempDir(), "testloggingfull.log")
   114  	err = os.Setenv("AZURE_GO_SDK_LOG_FILE", lf)
   115  	if err != nil {
   116  		t.Fatalf("failed to set log file: %v", err)
   117  	}
   118  	initDefaultLogger()
   119  	if Level() != LogDebug {
   120  		t.Fatalf("wrong log level: %d", Level())
   121  	}
   122  	// create mock request and response for logging
   123  	req, err := http.NewRequest(http.MethodGet, reqURL, strings.NewReader(reqBody))
   124  	if err != nil {
   125  		t.Fatalf("failed to create mock request: %v", err)
   126  	}
   127  	req.Header.Add(reqHeaderKey, reqHeaderVal)
   128  	Instance.WriteRequest(req, Filter{})
   129  	resp := &http.Response{
   130  		Status:     "200 OK",
   131  		StatusCode: 200,
   132  		Proto:      "HTTP/1.0",
   133  		ProtoMajor: 1,
   134  		ProtoMinor: 0,
   135  		Request:    req,
   136  		Header:     http.Header{},
   137  		Body:       ioutil.NopCloser(strings.NewReader(respBody)),
   138  	}
   139  	resp.Header.Add(respHeaderKey, respHeaderVal)
   140  	Instance.WriteResponse(resp, Filter{})
   141  	if fl, ok := Instance.(fileLogger); ok {
   142  		fl.logFile.Close()
   143  	} else {
   144  		t.Fatal("expected Instance to be fileLogger")
   145  	}
   146  	// parse log file to ensure contents match
   147  	b, err := ioutil.ReadFile(lf)
   148  	if err != nil {
   149  		t.Fatalf("failed to read log file: %v", err)
   150  	}
   151  	parts := strings.Split(string(b), "\n")
   152  	reqMatch := fmt.Sprintf("%s INFO: REQUEST: %s %s", logFileTimeStampRegex, req.Method, req.URL.String())
   153  	respMatch := fmt.Sprintf("%s INFO: RESPONSE: %d %s", logFileTimeStampRegex, resp.StatusCode, resp.Request.URL.String())
   154  	if !matchRegex(t, reqMatch, parts[0]) {
   155  		t.Fatalf("request header doesn't match: %s", parts[0])
   156  	}
   157  	if !matchRegex(t, fmt.Sprintf("(?i)%s: %s", reqHeaderKey, reqHeaderVal), parts[1]) {
   158  		t.Fatalf("request header value doesn't match: %s", parts[1])
   159  	}
   160  	if !matchRegex(t, reqBody, parts[2]) {
   161  		t.Fatalf("request body doesn't match: %s", parts[2])
   162  	}
   163  	if !matchRegex(t, respMatch, parts[3]) {
   164  		t.Fatalf("response header doesn't match: %s", parts[3])
   165  	}
   166  	if !matchRegex(t, fmt.Sprintf("(?i)%s: %s", respHeaderKey, respHeaderVal), parts[4]) {
   167  		t.Fatalf("response header value doesn't match: %s", parts[4])
   168  	}
   169  	if !matchRegex(t, respBody, parts[5]) {
   170  		t.Fatalf("response body doesn't match: %s", parts[5])
   171  	}
   172  	// disable logging
   173  	err = os.Setenv("AZURE_GO_SDK_LOG_LEVEL", "")
   174  	if err != nil {
   175  		t.Fatalf("failed to clear log level: %v", err)
   176  	}
   177  }
   178  
   179  func matchRegex(t *testing.T, pattern, s string) bool {
   180  	match, err := regexp.MatchString(pattern, s)
   181  	if err != nil {
   182  		t.Fatalf("regexp failure: %v", err)
   183  	}
   184  	return match
   185  }
   186
View as plain text