1package 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 17import ( 18 "fmt" 19 "io/ioutil" 20 "net/http" 21 "os" 22 "path" 23 "regexp" 24 "strings" 25 "testing" 26) 27 28func TestNilLogger(t *testing.T) { 29 // verify no crash with no logging 30 Instance.WriteRequest(nil, Filter{}) 31} 32 33const ( 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 44func 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 108func 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 179func 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