2018-11-19 17:47:03 -05:00
|
|
|
/*
|
2019-09-23 16:34:28 -04:00
|
|
|
* MinIO Cloud Storage, (C) 2018, 2019 MinIO, Inc.
|
2018-11-19 17:47:03 -05:00
|
|
|
*
|
|
|
|
|
* 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.
|
|
|
|
|
*/
|
|
|
|
|
|
|
|
|
|
package logger
|
|
|
|
|
|
|
|
|
|
import (
|
2019-09-23 16:34:28 -04:00
|
|
|
"bytes"
|
|
|
|
|
"fmt"
|
|
|
|
|
"io"
|
2018-11-19 17:47:03 -05:00
|
|
|
"net/http"
|
2020-02-11 22:38:02 -05:00
|
|
|
"net/url"
|
2020-05-19 21:34:02 -04:00
|
|
|
"strconv"
|
2019-08-12 23:32:34 -04:00
|
|
|
"time"
|
2018-11-19 17:47:03 -05:00
|
|
|
|
2019-08-12 23:32:34 -04:00
|
|
|
"github.com/gorilla/mux"
|
2018-11-19 17:47:03 -05:00
|
|
|
"github.com/minio/minio/cmd/logger/message/audit"
|
|
|
|
|
)
|
|
|
|
|
|
|
|
|
|
// ResponseWriter - is a wrapper to trap the http response status code.
|
|
|
|
|
type ResponseWriter struct {
|
|
|
|
|
http.ResponseWriter
|
2019-09-23 16:34:28 -04:00
|
|
|
StatusCode int
|
2020-04-30 14:27:19 -04:00
|
|
|
// Log body of 4xx or 5xx responses
|
|
|
|
|
LogErrBody bool
|
|
|
|
|
// Log body of all responses
|
|
|
|
|
LogAllBody bool
|
|
|
|
|
|
2019-09-23 16:34:28 -04:00
|
|
|
TimeToFirstByte time.Duration
|
|
|
|
|
StartTime time.Time
|
|
|
|
|
// number of bytes written
|
|
|
|
|
bytesWritten int
|
|
|
|
|
// Internal recording buffer
|
|
|
|
|
headers bytes.Buffer
|
|
|
|
|
body bytes.Buffer
|
|
|
|
|
// Indicate if headers are written in the log
|
|
|
|
|
headersLogged bool
|
2018-11-19 17:47:03 -05:00
|
|
|
}
|
|
|
|
|
|
|
|
|
|
// NewResponseWriter - returns a wrapped response writer to trap
|
|
|
|
|
// http status codes for auditiing purposes.
|
|
|
|
|
func NewResponseWriter(w http.ResponseWriter) *ResponseWriter {
|
2019-08-12 23:32:34 -04:00
|
|
|
return &ResponseWriter{
|
|
|
|
|
ResponseWriter: w,
|
2019-09-23 16:34:28 -04:00
|
|
|
StatusCode: http.StatusOK,
|
|
|
|
|
StartTime: time.Now().UTC(),
|
2019-08-12 23:32:34 -04:00
|
|
|
}
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
func (lrw *ResponseWriter) Write(p []byte) (int, error) {
|
|
|
|
|
n, err := lrw.ResponseWriter.Write(p)
|
2019-09-23 16:34:28 -04:00
|
|
|
lrw.bytesWritten += n
|
|
|
|
|
if lrw.TimeToFirstByte == 0 {
|
|
|
|
|
lrw.TimeToFirstByte = time.Now().UTC().Sub(lrw.StartTime)
|
|
|
|
|
}
|
|
|
|
|
if !lrw.headersLogged {
|
|
|
|
|
// We assume the response code to be '200 OK' when WriteHeader() is not called,
|
|
|
|
|
// that way following Golang HTTP response behavior.
|
2020-10-08 12:29:10 -04:00
|
|
|
lrw.WriteHeader(http.StatusOK)
|
2019-09-23 16:34:28 -04:00
|
|
|
}
|
2020-04-30 14:27:19 -04:00
|
|
|
if (lrw.LogErrBody && lrw.StatusCode >= http.StatusBadRequest) || lrw.LogAllBody {
|
2019-09-23 16:34:28 -04:00
|
|
|
// Always logging error responses.
|
|
|
|
|
lrw.body.Write(p)
|
|
|
|
|
}
|
2019-08-12 23:32:34 -04:00
|
|
|
if err != nil {
|
|
|
|
|
return n, err
|
|
|
|
|
}
|
|
|
|
|
return n, err
|
2018-11-19 17:47:03 -05:00
|
|
|
}
|
|
|
|
|
|
2019-09-23 16:34:28 -04:00
|
|
|
// Write the headers into the given buffer
|
|
|
|
|
func (lrw *ResponseWriter) writeHeaders(w io.Writer, statusCode int, headers http.Header) {
|
|
|
|
|
n, _ := fmt.Fprintf(w, "%d %s\n", statusCode, http.StatusText(statusCode))
|
|
|
|
|
lrw.bytesWritten += n
|
|
|
|
|
for k, v := range headers {
|
|
|
|
|
n, _ := fmt.Fprintf(w, "%s: %s\n", k, v[0])
|
|
|
|
|
lrw.bytesWritten += n
|
|
|
|
|
}
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
// BodyPlaceHolder returns a dummy body placeholder
|
|
|
|
|
var BodyPlaceHolder = []byte("<BODY>")
|
|
|
|
|
|
|
|
|
|
// Body - Return response body.
|
|
|
|
|
func (lrw *ResponseWriter) Body() []byte {
|
|
|
|
|
// If there was an error response or body logging is enabled
|
|
|
|
|
// then we return the body contents
|
2020-04-30 14:27:19 -04:00
|
|
|
if (lrw.LogErrBody && lrw.StatusCode >= http.StatusBadRequest) || lrw.LogAllBody {
|
2019-09-23 16:34:28 -04:00
|
|
|
return lrw.body.Bytes()
|
|
|
|
|
}
|
|
|
|
|
// ... otherwise we return the <BODY> place holder
|
|
|
|
|
return BodyPlaceHolder
|
|
|
|
|
}
|
|
|
|
|
|
2018-11-19 17:47:03 -05:00
|
|
|
// WriteHeader - writes http status code
|
|
|
|
|
func (lrw *ResponseWriter) WriteHeader(code int) {
|
2019-09-23 16:34:28 -04:00
|
|
|
if !lrw.headersLogged {
|
2020-10-08 12:29:10 -04:00
|
|
|
lrw.StatusCode = code
|
2019-09-23 16:34:28 -04:00
|
|
|
lrw.writeHeaders(&lrw.headers, code, lrw.ResponseWriter.Header())
|
|
|
|
|
lrw.headersLogged = true
|
2020-10-08 12:29:10 -04:00
|
|
|
lrw.ResponseWriter.WriteHeader(code)
|
2019-09-23 16:34:28 -04:00
|
|
|
}
|
2018-11-19 17:47:03 -05:00
|
|
|
}
|
|
|
|
|
|
|
|
|
|
// Flush - Calls the underlying Flush.
|
|
|
|
|
func (lrw *ResponseWriter) Flush() {
|
|
|
|
|
lrw.ResponseWriter.(http.Flusher).Flush()
|
|
|
|
|
}
|
|
|
|
|
|
2019-09-23 16:34:28 -04:00
|
|
|
// Size - reutrns the number of bytes written
|
|
|
|
|
func (lrw *ResponseWriter) Size() int {
|
|
|
|
|
return lrw.bytesWritten
|
|
|
|
|
}
|
|
|
|
|
|
2018-11-19 17:47:03 -05:00
|
|
|
// AuditLog - logs audit logs to all audit targets.
|
2020-06-05 01:07:55 -04:00
|
|
|
func AuditLog(w http.ResponseWriter, r *http.Request, api string, reqClaims map[string]interface{}, filterKeys ...string) {
|
2020-04-30 01:17:36 -04:00
|
|
|
// Fast exit if there is not audit target configured
|
|
|
|
|
if len(AuditTargets) == 0 {
|
|
|
|
|
return
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
var (
|
|
|
|
|
statusCode int
|
|
|
|
|
timeToResponse time.Duration
|
|
|
|
|
timeToFirstByte time.Duration
|
|
|
|
|
)
|
|
|
|
|
|
2020-04-30 14:27:19 -04:00
|
|
|
st, ok := w.(*ResponseWriter)
|
2018-11-19 17:47:03 -05:00
|
|
|
if ok {
|
2020-04-30 14:27:19 -04:00
|
|
|
statusCode = st.StatusCode
|
2020-04-30 01:17:36 -04:00
|
|
|
timeToResponse = time.Now().UTC().Sub(st.StartTime)
|
2020-04-30 14:27:19 -04:00
|
|
|
timeToFirstByte = st.TimeToFirstByte
|
2018-11-19 17:47:03 -05:00
|
|
|
}
|
2019-08-12 23:32:34 -04:00
|
|
|
|
|
|
|
|
vars := mux.Vars(r)
|
|
|
|
|
bucket := vars["bucket"]
|
2020-02-11 22:38:02 -05:00
|
|
|
object, err := url.PathUnescape(vars["object"])
|
|
|
|
|
if err != nil {
|
|
|
|
|
object = vars["object"]
|
|
|
|
|
}
|
2019-08-12 23:32:34 -04:00
|
|
|
|
2020-04-30 01:17:36 -04:00
|
|
|
entry := audit.ToEntry(w, r, reqClaims, globalDeploymentID)
|
2020-06-05 01:07:55 -04:00
|
|
|
for _, filterKey := range filterKeys {
|
|
|
|
|
delete(entry.ReqClaims, filterKey)
|
|
|
|
|
delete(entry.ReqQuery, filterKey)
|
|
|
|
|
delete(entry.ReqHeader, filterKey)
|
|
|
|
|
delete(entry.RespHeader, filterKey)
|
|
|
|
|
}
|
2020-04-30 01:17:36 -04:00
|
|
|
entry.API.Name = api
|
|
|
|
|
entry.API.Bucket = bucket
|
|
|
|
|
entry.API.Object = object
|
|
|
|
|
entry.API.Status = http.StatusText(statusCode)
|
|
|
|
|
entry.API.StatusCode = statusCode
|
2020-05-19 21:34:02 -04:00
|
|
|
entry.API.TimeToResponse = strconv.FormatInt(timeToResponse.Nanoseconds(), 10) + "ns"
|
|
|
|
|
// ttfb will be recorded only for GET requests, Ignore such cases where ttfb will be empty.
|
|
|
|
|
if timeToFirstByte != 0 {
|
|
|
|
|
entry.API.TimeToFirstByte = strconv.FormatInt(timeToFirstByte.Nanoseconds(), 10) + "ns"
|
|
|
|
|
}
|
2020-04-30 01:17:36 -04:00
|
|
|
|
2018-11-19 17:47:03 -05:00
|
|
|
// Send audit logs only to http targets.
|
|
|
|
|
for _, t := range AuditTargets {
|
2019-10-11 21:50:54 -04:00
|
|
|
_ = t.Send(entry, string(All))
|
2018-11-19 17:47:03 -05:00
|
|
|
}
|
|
|
|
|
}
|
