consul/vendor/github.com/Azure/go-autorest/logger/logger_test.go

package logger

// Copyright 2017 Microsoft Corporation
//
//  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.

import (
	"fmt"
	"io/ioutil"
	"net/http"
	"os"
	"path"
	"regexp"
	"strings"
	"testing"
)

func TestNilLogger(t *testing.T) {
	// verify no crash with no logging
	Instance.WriteRequest(nil, Filter{})
}

const (
	reqURL                = "https://fakething/dot/com"
	reqHeaderKey          = "x-header"
	reqHeaderVal          = "value"
	reqBody               = "the request body"
	respHeaderKey         = "response-header"
	respHeaderVal         = "something"
	respBody              = "the response body"
	logFileTimeStampRegex = `\(\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\.\d{7}(-\d{2}:\d{2}|Z)\)`
)

func TestLogReqRespNoBody(t *testing.T) {
	err := os.Setenv("AZURE_GO_SDK_LOG_LEVEL", "info")
	if err != nil {
		t.Fatalf("failed to set log level: %v", err)
	}
	lf := path.Join(os.TempDir(), "testloggingbasic.log")
	err = os.Setenv("AZURE_GO_SDK_LOG_FILE", lf)
	if err != nil {
		t.Fatalf("failed to set log file: %v", err)
	}
	initDefaultLogger()
	if Level() != LogInfo {
		t.Fatalf("wrong log level: %d", Level())
	}
	// create mock request and response for logging
	req, err := http.NewRequest(http.MethodGet, reqURL, nil)
	if err != nil {
		t.Fatalf("failed to create mock request: %v", err)
	}
	req.Header.Add(reqHeaderKey, reqHeaderVal)
	Instance.WriteRequest(req, Filter{})
	resp := &http.Response{
		Status:     "200 OK",
		StatusCode: 200,
		Proto:      "HTTP/1.0",
		ProtoMajor: 1,
		ProtoMinor: 0,
		Request:    req,
		Header:     http.Header{},
	}
	resp.Header.Add(respHeaderKey, respHeaderVal)
	Instance.WriteResponse(resp, Filter{})
	if fl, ok := Instance.(fileLogger); ok {
		fl.logFile.Close()
	} else {
		t.Fatal("expected Instance to be fileLogger")
	}
	// parse log file to ensure contents match
	b, err := ioutil.ReadFile(lf)
	if err != nil {
		t.Fatalf("failed to read log file: %v", err)
	}
	parts := strings.Split(string(b), "\n")
	reqMatch := fmt.Sprintf("%s INFO: REQUEST: %s %s", logFileTimeStampRegex, req.Method, req.URL.String())
	respMatch := fmt.Sprintf("%s INFO: RESPONSE: %d %s", logFileTimeStampRegex, resp.StatusCode, resp.Request.URL.String())
	if !matchRegex(t, reqMatch, parts[0]) {
		t.Fatalf("request header doesn't match: %s", parts[0])
	}
	if !matchRegex(t, fmt.Sprintf("(?i)%s: %s", reqHeaderKey, reqHeaderVal), parts[1]) {
		t.Fatalf("request header entry doesn't match: %s", parts[1])
	}
	if !matchRegex(t, respMatch, parts[2]) {
		t.Fatalf("response header doesn't match: %s", parts[2])
	}
	if !matchRegex(t, fmt.Sprintf("(?i)%s: %s", respHeaderKey, respHeaderVal), parts[3]) {
		t.Fatalf("response header value doesn't match: %s", parts[3])
	}
	// disable logging
	err = os.Setenv("AZURE_GO_SDK_LOG_LEVEL", "")
	if err != nil {
		t.Fatalf("failed to clear log level: %v", err)
	}
}

func TestLogReqRespWithBody(t *testing.T) {
	err := os.Setenv("AZURE_GO_SDK_LOG_LEVEL", "debug")
	if err != nil {
		t.Fatalf("failed to set log level: %v", err)
	}
	lf := path.Join(os.TempDir(), "testloggingfull.log")
	err = os.Setenv("AZURE_GO_SDK_LOG_FILE", lf)
	if err != nil {
		t.Fatalf("failed to set log file: %v", err)
	}
	initDefaultLogger()
	if Level() != LogDebug {
		t.Fatalf("wrong log level: %d", Level())
	}
	// create mock request and response for logging
	req, err := http.NewRequest(http.MethodGet, reqURL, strings.NewReader(reqBody))
	if err != nil {
		t.Fatalf("failed to create mock request: %v", err)
	}
	req.Header.Add(reqHeaderKey, reqHeaderVal)
	Instance.WriteRequest(req, Filter{})
	resp := &http.Response{
		Status:     "200 OK",
		StatusCode: 200,
		Proto:      "HTTP/1.0",
		ProtoMajor: 1,
		ProtoMinor: 0,
		Request:    req,
		Header:     http.Header{},
		Body:       ioutil.NopCloser(strings.NewReader(respBody)),
	}
	resp.Header.Add(respHeaderKey, respHeaderVal)
	Instance.WriteResponse(resp, Filter{})
	if fl, ok := Instance.(fileLogger); ok {
		fl.logFile.Close()
	} else {
		t.Fatal("expected Instance to be fileLogger")
	}
	// parse log file to ensure contents match
	b, err := ioutil.ReadFile(lf)
	if err != nil {
		t.Fatalf("failed to read log file: %v", err)
	}
	parts := strings.Split(string(b), "\n")
	reqMatch := fmt.Sprintf("%s INFO: REQUEST: %s %s", logFileTimeStampRegex, req.Method, req.URL.String())
	respMatch := fmt.Sprintf("%s INFO: RESPONSE: %d %s", logFileTimeStampRegex, resp.StatusCode, resp.Request.URL.String())
	if !matchRegex(t, reqMatch, parts[0]) {
		t.Fatalf("request header doesn't match: %s", parts[0])
	}
	if !matchRegex(t, fmt.Sprintf("(?i)%s: %s", reqHeaderKey, reqHeaderVal), parts[1]) {
		t.Fatalf("request header value doesn't match: %s", parts[1])
	}
	if !matchRegex(t, reqBody, parts[2]) {
		t.Fatalf("request body doesn't match: %s", parts[2])
	}
	if !matchRegex(t, respMatch, parts[3]) {
		t.Fatalf("response header doesn't match: %s", parts[3])
	}
	if !matchRegex(t, fmt.Sprintf("(?i)%s: %s", respHeaderKey, respHeaderVal), parts[4]) {
		t.Fatalf("response header value doesn't match: %s", parts[4])
	}
	if !matchRegex(t, respBody, parts[5]) {
		t.Fatalf("response body doesn't match: %s", parts[5])
	}
	// disable logging
	err = os.Setenv("AZURE_GO_SDK_LOG_LEVEL", "")
	if err != nil {
		t.Fatalf("failed to clear log level: %v", err)
	}
}

func matchRegex(t *testing.T, pattern, s string) bool {
	match, err := regexp.MatchString(pattern, s)
	if err != nil {
		t.Fatalf("regexp failure: %v", err)
	}
	return match
}