github.com/opensearch-project/opensearch-go/v2@v2.3.0/opensearchtransport/logger.go (about) 1 // SPDX-License-Identifier: Apache-2.0 2 // 3 // The OpenSearch Contributors require contributions made to 4 // this file be licensed under the Apache-2.0 license or a 5 // compatible open source license. 6 // 7 // Modifications Copyright OpenSearch Contributors. See 8 // GitHub history for details. 9 10 // Licensed to Elasticsearch B.V. under one or more contributor 11 // license agreements. See the NOTICE file distributed with 12 // this work for additional information regarding copyright 13 // ownership. Elasticsearch B.V. licenses this file to you under 14 // the Apache License, Version 2.0 (the "License"); you may 15 // not use this file except in compliance with the License. 16 // You may obtain a copy of the License at 17 // 18 // http://www.apache.org/licenses/LICENSE-2.0 19 // 20 // Unless required by applicable law or agreed to in writing, 21 // software distributed under the License is distributed on an 22 // "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY 23 // KIND, either express or implied. See the License for the 24 // specific language governing permissions and limitations 25 // under the License. 26 27 package opensearchtransport 28 29 import ( 30 "bufio" 31 "bytes" 32 "encoding/json" 33 "fmt" 34 "io" 35 "io/ioutil" 36 "net/http" 37 "net/url" 38 "strconv" 39 "strings" 40 "time" 41 ) 42 43 var debugLogger DebuggingLogger 44 45 // Logger defines an interface for logging request and response. 46 // 47 type Logger interface { 48 // LogRoundTrip should not modify the request or response, except for consuming and closing the body. 49 // Implementations have to check for nil values in request and response. 50 LogRoundTrip(*http.Request, *http.Response, error, time.Time, time.Duration) error 51 // RequestBodyEnabled makes the client pass a copy of request body to the logger. 52 RequestBodyEnabled() bool 53 // ResponseBodyEnabled makes the client pass a copy of response body to the logger. 54 ResponseBodyEnabled() bool 55 } 56 57 // DebuggingLogger defines the interface for a debugging logger. 58 // 59 type DebuggingLogger interface { 60 Log(a ...interface{}) error 61 Logf(format string, a ...interface{}) error 62 } 63 64 // TextLogger prints the log message in plain text. 65 // 66 type TextLogger struct { 67 Output io.Writer 68 EnableRequestBody bool 69 EnableResponseBody bool 70 } 71 72 // ColorLogger prints the log message in a terminal-optimized plain text. 73 // 74 type ColorLogger struct { 75 Output io.Writer 76 EnableRequestBody bool 77 EnableResponseBody bool 78 } 79 80 // CurlLogger prints the log message as a runnable curl command. 81 // 82 type CurlLogger struct { 83 Output io.Writer 84 EnableRequestBody bool 85 EnableResponseBody bool 86 } 87 88 // JSONLogger prints the log message as JSON. 89 // 90 type JSONLogger struct { 91 Output io.Writer 92 EnableRequestBody bool 93 EnableResponseBody bool 94 } 95 96 // debuggingLogger prints debug messages as plain text. 97 // 98 type debuggingLogger struct { 99 Output io.Writer 100 } 101 102 // LogRoundTrip prints the information about request and response. 103 // 104 func (l *TextLogger) LogRoundTrip(req *http.Request, res *http.Response, err error, start time.Time, dur time.Duration) error { 105 fmt.Fprintf(l.Output, "%s %s %s [status:%d request:%s]\n", 106 start.Format(time.RFC3339), 107 req.Method, 108 req.URL.String(), 109 resStatusCode(res), 110 dur.Truncate(time.Millisecond), 111 ) 112 if l.RequestBodyEnabled() && req != nil && req.Body != nil && req.Body != http.NoBody { 113 var buf bytes.Buffer 114 if req.GetBody != nil { 115 b, _ := req.GetBody() 116 buf.ReadFrom(b) 117 } else { 118 buf.ReadFrom(req.Body) 119 } 120 logBodyAsText(l.Output, &buf, ">") 121 } 122 if l.ResponseBodyEnabled() && res != nil && res.Body != nil && res.Body != http.NoBody { 123 defer res.Body.Close() 124 var buf bytes.Buffer 125 buf.ReadFrom(res.Body) 126 logBodyAsText(l.Output, &buf, "<") 127 } 128 if err != nil { 129 fmt.Fprintf(l.Output, "! ERROR: %v\n", err) 130 } 131 return nil 132 } 133 134 // RequestBodyEnabled returns true when the request body should be logged. 135 func (l *TextLogger) RequestBodyEnabled() bool { return l.EnableRequestBody } 136 137 // ResponseBodyEnabled returns true when the response body should be logged. 138 func (l *TextLogger) ResponseBodyEnabled() bool { return l.EnableResponseBody } 139 140 // LogRoundTrip prints the information about request and response. 141 // 142 func (l *ColorLogger) LogRoundTrip(req *http.Request, res *http.Response, err error, start time.Time, dur time.Duration) error { 143 query, _ := url.QueryUnescape(req.URL.RawQuery) 144 if query != "" { 145 query = "?" + query 146 } 147 148 var ( 149 status string 150 color string 151 ) 152 153 status = res.Status 154 switch { 155 case res.StatusCode > 0 && res.StatusCode < 300: 156 color = "\x1b[32m" 157 case res.StatusCode > 299 && res.StatusCode < 500: 158 color = "\x1b[33m" 159 case res.StatusCode > 499: 160 color = "\x1b[31m" 161 default: 162 status = "ERROR" 163 color = "\x1b[31;4m" 164 } 165 166 fmt.Fprintf(l.Output, "%6s \x1b[1;4m%s://%s%s\x1b[0m%s %s%s\x1b[0m \x1b[2m%s\x1b[0m\n", 167 req.Method, 168 req.URL.Scheme, 169 req.URL.Host, 170 req.URL.Path, 171 query, 172 color, 173 status, 174 dur.Truncate(time.Millisecond), 175 ) 176 177 if l.RequestBodyEnabled() && req != nil && req.Body != nil && req.Body != http.NoBody { 178 var buf bytes.Buffer 179 if req.GetBody != nil { 180 b, _ := req.GetBody() 181 buf.ReadFrom(b) 182 } else { 183 buf.ReadFrom(req.Body) 184 } 185 fmt.Fprint(l.Output, "\x1b[2m") 186 logBodyAsText(l.Output, &buf, " »") 187 fmt.Fprint(l.Output, "\x1b[0m") 188 } 189 190 if l.ResponseBodyEnabled() && res != nil && res.Body != nil && res.Body != http.NoBody { 191 defer res.Body.Close() 192 var buf bytes.Buffer 193 buf.ReadFrom(res.Body) 194 fmt.Fprint(l.Output, "\x1b[2m") 195 logBodyAsText(l.Output, &buf, " «") 196 fmt.Fprint(l.Output, "\x1b[0m") 197 } 198 199 if err != nil { 200 fmt.Fprintf(l.Output, "\x1b[31;1m» ERROR \x1b[31m%v\x1b[0m\n", err) 201 } 202 203 if l.RequestBodyEnabled() || l.ResponseBodyEnabled() { 204 fmt.Fprintf(l.Output, "\x1b[2m%s\x1b[0m\n", strings.Repeat("─", 80)) 205 } 206 return nil 207 } 208 209 // RequestBodyEnabled returns true when the request body should be logged. 210 func (l *ColorLogger) RequestBodyEnabled() bool { return l.EnableRequestBody } 211 212 // ResponseBodyEnabled returns true when the response body should be logged. 213 func (l *ColorLogger) ResponseBodyEnabled() bool { return l.EnableResponseBody } 214 215 // LogRoundTrip prints the information about request and response. 216 // 217 func (l *CurlLogger) LogRoundTrip(req *http.Request, res *http.Response, err error, start time.Time, dur time.Duration) error { 218 var b bytes.Buffer 219 220 var query string 221 qvalues := url.Values{} 222 for k, v := range req.URL.Query() { 223 if k == "pretty" { 224 continue 225 } 226 for _, qv := range v { 227 qvalues.Add(k, qv) 228 } 229 } 230 if len(qvalues) > 0 { 231 query = qvalues.Encode() 232 } 233 234 b.WriteString(`curl`) 235 if req.Method == "HEAD" { 236 b.WriteString(" --head") 237 } else { 238 fmt.Fprintf(&b, " -X %s", req.Method) 239 } 240 241 if len(req.Header) > 0 { 242 for k, vv := range req.Header { 243 if k == "Authorization" || k == "User-Agent" { 244 continue 245 } 246 v := strings.Join(vv, ",") 247 b.WriteString(fmt.Sprintf(" -H '%s: %s'", k, v)) 248 } 249 } 250 251 // If by some oddity we end up with a nil req.URL, we handle it gracefully. 252 if req.URL == nil { 253 b.WriteString(" '") 254 } else { 255 b.WriteString(fmt.Sprintf(" '%s://%s%s", req.URL.Scheme, req.URL.Host, req.URL.Path)) 256 } 257 b.WriteString("?pretty") 258 if query != "" { 259 fmt.Fprintf(&b, "&%s", query) 260 } 261 b.WriteString("'") 262 263 if req != nil && req.Body != nil && req.Body != http.NoBody { 264 var buf bytes.Buffer 265 if req.GetBody != nil { 266 b, _ := req.GetBody() 267 buf.ReadFrom(b) 268 } else { 269 buf.ReadFrom(req.Body) 270 } 271 272 b.Grow(buf.Len()) 273 b.WriteString(" -d \\\n'") 274 json.Indent(&b, buf.Bytes(), "", " ") 275 b.WriteString("'") 276 } 277 278 b.WriteRune('\n') 279 280 var status string 281 status = res.Status 282 283 fmt.Fprintf(&b, "# => %s [%s] %s\n", start.UTC().Format(time.RFC3339), status, dur.Truncate(time.Millisecond)) 284 if l.ResponseBodyEnabled() && res != nil && res.Body != nil && res.Body != http.NoBody { 285 var buf bytes.Buffer 286 buf.ReadFrom(res.Body) 287 288 b.Grow(buf.Len()) 289 b.WriteString("# ") 290 json.Indent(&b, buf.Bytes(), "# ", " ") 291 } 292 293 b.WriteString("\n") 294 if l.ResponseBodyEnabled() && res != nil && res.Body != nil && res.Body != http.NoBody { 295 b.WriteString("\n") 296 } 297 298 b.WriteTo(l.Output) 299 300 return nil 301 } 302 303 // RequestBodyEnabled returns true when the request body should be logged. 304 func (l *CurlLogger) RequestBodyEnabled() bool { return l.EnableRequestBody } 305 306 // ResponseBodyEnabled returns true when the response body should be logged. 307 func (l *CurlLogger) ResponseBodyEnabled() bool { return l.EnableResponseBody } 308 309 // LogRoundTrip prints the information about request and response. 310 // 311 func (l *JSONLogger) LogRoundTrip(req *http.Request, res *http.Response, err error, start time.Time, dur time.Duration) error { 312 // TODO: Research performance optimization of using sync.Pool 313 314 bsize := 200 315 var b = bytes.NewBuffer(make([]byte, 0, bsize)) 316 var v = make([]byte, 0, bsize) 317 318 appendTime := func(t time.Time) { 319 v = v[:0] 320 v = t.AppendFormat(v, time.RFC3339) 321 b.Write(v) 322 } 323 324 appendQuote := func(s string) { 325 v = v[:0] 326 v = strconv.AppendQuote(v, s) 327 b.Write(v) 328 } 329 330 appendInt := func(i int64) { 331 v = v[:0] 332 v = strconv.AppendInt(v, i, 10) 333 b.Write(v) 334 } 335 336 port := req.URL.Port() 337 338 b.WriteRune('{') 339 // -- Timestamp 340 b.WriteString(`"@timestamp":"`) 341 appendTime(start.UTC()) 342 b.WriteRune('"') 343 // -- Event 344 b.WriteString(`,"event":{`) 345 b.WriteString(`"duration":`) 346 appendInt(dur.Nanoseconds()) 347 b.WriteRune('}') 348 // -- URL 349 b.WriteString(`,"url":{`) 350 b.WriteString(`"scheme":`) 351 appendQuote(req.URL.Scheme) 352 b.WriteString(`,"domain":`) 353 appendQuote(req.URL.Hostname()) 354 if port != "" { 355 b.WriteString(`,"port":`) 356 b.WriteString(port) 357 } 358 b.WriteString(`,"path":`) 359 appendQuote(req.URL.Path) 360 b.WriteString(`,"query":`) 361 appendQuote(req.URL.RawQuery) 362 b.WriteRune('}') // Close "url" 363 // -- HTTP 364 b.WriteString(`,"http":`) 365 // ---- Request 366 b.WriteString(`{"request":{`) 367 b.WriteString(`"method":`) 368 appendQuote(req.Method) 369 if l.RequestBodyEnabled() && req != nil && req.Body != nil && req.Body != http.NoBody { 370 var buf bytes.Buffer 371 if req.GetBody != nil { 372 b, _ := req.GetBody() 373 buf.ReadFrom(b) 374 } else { 375 buf.ReadFrom(req.Body) 376 } 377 378 b.Grow(buf.Len() + 8) 379 b.WriteString(`,"body":`) 380 appendQuote(buf.String()) 381 } 382 b.WriteRune('}') // Close "http.request" 383 // ---- Response 384 b.WriteString(`,"response":{`) 385 b.WriteString(`"status_code":`) 386 appendInt(int64(resStatusCode(res))) 387 if l.ResponseBodyEnabled() && res != nil && res.Body != nil && res.Body != http.NoBody { 388 defer res.Body.Close() 389 var buf bytes.Buffer 390 buf.ReadFrom(res.Body) 391 392 b.Grow(buf.Len() + 8) 393 b.WriteString(`,"body":`) 394 appendQuote(buf.String()) 395 } 396 b.WriteRune('}') // Close "http.response" 397 b.WriteRune('}') // Close "http" 398 // -- Error 399 if err != nil { 400 b.WriteString(`,"error":{"message":`) 401 appendQuote(err.Error()) 402 b.WriteRune('}') // Close "error" 403 } 404 b.WriteRune('}') 405 b.WriteRune('\n') 406 b.WriteTo(l.Output) 407 408 return nil 409 } 410 411 // RequestBodyEnabled returns true when the request body should be logged. 412 func (l *JSONLogger) RequestBodyEnabled() bool { return l.EnableRequestBody } 413 414 // ResponseBodyEnabled returns true when the response body should be logged. 415 func (l *JSONLogger) ResponseBodyEnabled() bool { return l.EnableResponseBody } 416 417 // Log prints the arguments to output in default format. 418 // 419 func (l *debuggingLogger) Log(a ...interface{}) error { 420 _, err := fmt.Fprint(l.Output, a...) 421 return err 422 } 423 424 // Logf prints formats the arguments and prints them to output. 425 // 426 func (l *debuggingLogger) Logf(format string, a ...interface{}) error { 427 _, err := fmt.Fprintf(l.Output, format, a...) 428 return err 429 } 430 431 func logBodyAsText(dst io.Writer, body io.Reader, prefix string) { 432 scanner := bufio.NewScanner(body) 433 for scanner.Scan() { 434 s := scanner.Text() 435 if s != "" { 436 fmt.Fprintf(dst, "%s %s\n", prefix, s) 437 } 438 } 439 } 440 441 func duplicateBody(body io.ReadCloser) (io.ReadCloser, io.ReadCloser, error) { 442 var ( 443 b1 bytes.Buffer 444 b2 bytes.Buffer 445 tr = io.TeeReader(body, &b2) 446 ) 447 _, err := b1.ReadFrom(tr) 448 if err != nil { 449 return ioutil.NopCloser(io.MultiReader(&b1, errorReader{err: err})), ioutil.NopCloser(io.MultiReader(&b2, errorReader{err: err})), err 450 } 451 defer func() { body.Close() }() 452 453 return ioutil.NopCloser(&b1), ioutil.NopCloser(&b2), nil 454 } 455 456 func resStatusCode(res *http.Response) int { 457 if res == nil { 458 return -1 459 } 460 return res.StatusCode 461 } 462 463 type errorReader struct{ err error } 464 465 func (r errorReader) Read(p []byte) (int, error) { return 0, r.err }