diff --git a/cmd/server/main.go b/cmd/server/main.go index 0437a6202..3186800e2 100644 --- a/cmd/server/main.go +++ b/cmd/server/main.go @@ -71,7 +71,6 @@ func main() { // Setup underlying ach service r := server.NewRepositoryInMemory() svc = server.NewService(r) - svc = server.LoggingMiddleware(logger)(svc) // Create HTTP server handler = server.MakeHTTPHandler(svc, r, log.With(logger, "component", "HTTP")) diff --git a/server/batches.go b/server/batches.go index c61ca98fb..1bba33cdc 100644 --- a/server/batches.go +++ b/server/batches.go @@ -11,14 +11,18 @@ import ( "net/http" "github.com/moov-io/ach" + moovhttp "github.com/moov-io/base/http" "github.com/go-kit/kit/endpoint" + "github.com/go-kit/kit/log" "github.com/gorilla/mux" ) type createBatchRequest struct { FileID string Batch *ach.Batch + + requestId string } type createBatchResponse struct { @@ -28,19 +32,26 @@ type createBatchResponse struct { func (r createBatchResponse) error() error { return r.Err } -func createBatchEndpoint(s Service) endpoint.Endpoint { +func createBatchEndpoint(s Service, logger log.Logger) endpoint.Endpoint { return func(_ context.Context, request interface{}) (interface{}, error) { req := request.(createBatchRequest) - id, e := s.CreateBatch(req.FileID, req.Batch) + id, err := s.CreateBatch(req.FileID, req.Batch) + + if req.requestId != "" && logger != nil { + logger.Log("batches", "createBatch", "file", req.FileID, "requestId", req.requestId, "error", err) + } + return createBatchResponse{ ID: id, - Err: e, + Err: err, }, nil } } func decodeCreateBatchRequest(_ context.Context, r *http.Request) (interface{}, error) { var req createBatchRequest + req.requestId = moovhttp.GetRequestId(r) + vars := mux.Vars(r) id, ok := vars["fileID"] if !ok { @@ -58,6 +69,8 @@ func decodeCreateBatchRequest(_ context.Context, r *http.Request) (interface{}, type getBatchesRequest struct { fileID string + + requestId string } type getBatchesResponse struct { @@ -73,6 +86,8 @@ func (r getBatchesResponse) error() error { return r.Err } func decodeGetBatchesRequest(_ context.Context, r *http.Request) (interface{}, error) { var req getBatchesRequest + req.requestId = moovhttp.GetRequestId(r) + vars := mux.Vars(r) id, ok := vars["fileID"] if !ok { @@ -82,9 +97,12 @@ func decodeGetBatchesRequest(_ context.Context, r *http.Request) (interface{}, e return req, nil } -func getBatchesEndpoint(s Service) endpoint.Endpoint { +func getBatchesEndpoint(s Service, logger log.Logger) endpoint.Endpoint { return func(_ context.Context, request interface{}) (interface{}, error) { req := request.(getBatchesRequest) + if req.requestId != "" && logger != nil { + logger.Log("batches", "getBatches", "file", req.fileID, "requestId", req.requestId) + } return getBatchesResponse{ Batches: s.GetBatches(req.fileID), Err: nil, @@ -95,6 +113,8 @@ func getBatchesEndpoint(s Service) endpoint.Endpoint { type getBatchRequest struct { fileID string batchID string + + requestId string } type getBatchResponse struct { @@ -106,6 +126,8 @@ func (r getBatchResponse) error() error { return r.Err } func decodeGetBatchRequest(_ context.Context, r *http.Request) (interface{}, error) { var req getBatchRequest + req.requestId = moovhttp.GetRequestId(r) + vars := mux.Vars(r) fileID, ok := vars["fileID"] if !ok { @@ -121,13 +143,18 @@ func decodeGetBatchRequest(_ context.Context, r *http.Request) (interface{}, err return req, nil } -func getBatchEndpoint(s Service) endpoint.Endpoint { +func getBatchEndpoint(s Service, logger log.Logger) endpoint.Endpoint { return func(_ context.Context, request interface{}) (interface{}, error) { req := request.(getBatchRequest) - batch, e := s.GetBatch(req.fileID, req.batchID) + batch, err := s.GetBatch(req.fileID, req.batchID) + + if req.requestId != "" && logger != nil { + logger.Log("batches", "getBatche", "file", req.fileID, "requestId", req.requestId, "error", err) + } + return getBatchResponse{ Batch: batch, - Err: e, + Err: err, }, nil } } @@ -135,6 +162,8 @@ func getBatchEndpoint(s Service) endpoint.Endpoint { type deleteBatchRequest struct { fileID string batchID string + + requestId string } type deleteBatchResponse struct { @@ -145,6 +174,8 @@ func (r deleteBatchResponse) error() error { return r.Err } func decodeDeleteBatchRequest(_ context.Context, r *http.Request) (interface{}, error) { var req deleteBatchRequest + req.requestId = moovhttp.GetRequestId(r) + vars := mux.Vars(r) fileID, ok := vars["fileID"] if !ok { @@ -160,11 +191,17 @@ func decodeDeleteBatchRequest(_ context.Context, r *http.Request) (interface{}, return req, nil } -func deleteBatchEndpoint(s Service) endpoint.Endpoint { +func deleteBatchEndpoint(s Service, logger log.Logger) endpoint.Endpoint { return func(_ context.Context, request interface{}) (interface{}, error) { req := request.(deleteBatchRequest) + err := s.DeleteBatch(req.fileID, req.batchID) + + if req.requestId != "" && logger != nil { + logger.Log("batches", "deleteBatch", "file", req.fileID, "requestId", req.requestId, "error", err) + } + return deleteBatchResponse{ - Err: s.DeleteBatch(req.fileID, req.batchID), + Err: err, }, nil } } diff --git a/server/files.go b/server/files.go index cdd09bc87..449a5c520 100644 --- a/server/files.go +++ b/server/files.go @@ -13,8 +13,10 @@ import ( "strings" "github.com/moov-io/ach" + moovhttp "github.com/moov-io/base/http" "github.com/go-kit/kit/endpoint" + "github.com/go-kit/kit/log" "github.com/go-kit/kit/metrics/prometheus" "github.com/gorilla/mux" stdprometheus "github.com/prometheus/client_golang/prometheus" @@ -29,6 +31,8 @@ var ( type createFileRequest struct { File *ach.File + + requestId string } type createFileResponse struct { @@ -38,7 +42,7 @@ type createFileResponse struct { func (r createFileResponse) error() error { return r.Err } -func createFileEndpoint(s Service, r Repository) endpoint.Endpoint { +func createFileEndpoint(s Service, r Repository, logger log.Logger) endpoint.Endpoint { return func(_ context.Context, request interface{}) (interface{}, error) { req := request.(createFileRequest) @@ -52,9 +56,14 @@ func createFileEndpoint(s Service, r Repository) endpoint.Endpoint { req.File.ID = NextID() } + err := r.StoreFile(req.File) + if req.requestId != "" && logger != nil { + logger.Log("files", "createFile", "requestId", req.requestId, "error", err) + } + return createFileResponse{ ID: req.File.ID, - Err: r.StoreFile(req.File), + Err: err, }, nil } } @@ -63,6 +72,8 @@ func decodeCreateFileRequest(_ context.Context, request *http.Request) (interfac var r io.Reader var req createFileRequest + req.requestId = moovhttp.GetRequestId(request) + // Sets default values req.File = ach.NewFile() bs, err := ioutil.ReadAll(request.Body) @@ -90,7 +101,9 @@ func decodeCreateFileRequest(_ context.Context, request *http.Request) (interfac return req, nil } -type getFilesRequest struct{} +type getFilesRequest struct { + requestId string +} type getFilesResponse struct { Files []*ach.File `json:"files"` @@ -111,11 +124,15 @@ func getFilesEndpoint(s Service) endpoint.Endpoint { } func decodeGetFilesRequest(_ context.Context, r *http.Request) (interface{}, error) { - return getFilesRequest{}, nil + return getFilesRequest{ + requestId: moovhttp.GetRequestId(r), + }, nil } type getFileRequest struct { ID string + + requestId string } type getFileResponse struct { @@ -125,13 +142,18 @@ type getFileResponse struct { func (r getFileResponse) error() error { return r.Err } -func getFileEndpoint(s Service) endpoint.Endpoint { +func getFileEndpoint(s Service, logger log.Logger) endpoint.Endpoint { return func(_ context.Context, request interface{}) (interface{}, error) { req := request.(getFileRequest) - f, e := s.GetFile(req.ID) + f, err := s.GetFile(req.ID) + + if req.requestId != "" && logger != nil { + logger.Log("files", "getFile", "requestId", req.requestId, "error", err) + } + return getFileResponse{ File: f, - Err: e, + Err: err, }, nil } } @@ -142,11 +164,16 @@ func decodeGetFileRequest(_ context.Context, r *http.Request) (interface{}, erro if !ok { return nil, ErrBadRouting } - return getFileRequest{ID: id}, nil + return getFileRequest{ + ID: id, + requestId: moovhttp.GetRequestId(r), + }, nil } type deleteFileRequest struct { ID string + + requestId string } type deleteFileResponse struct { @@ -155,11 +182,17 @@ type deleteFileResponse struct { func (r deleteFileResponse) error() error { return r.Err } -func deleteFileEndpoint(s Service) endpoint.Endpoint { +func deleteFileEndpoint(s Service, logger log.Logger) endpoint.Endpoint { return func(_ context.Context, request interface{}) (interface{}, error) { req := request.(deleteFileRequest) + err := s.DeleteFile(req.ID) + + if req.requestId != "" && logger != nil { + logger.Log("files", "deleteFile", "requestId", req.requestId, "error", err) + } + return deleteFileResponse{ - Err: s.DeleteFile(req.ID), + Err: err, }, nil } } @@ -170,11 +203,16 @@ func decodeDeleteFileRequest(_ context.Context, r *http.Request) (interface{}, e if !ok { return nil, ErrBadRouting } - return deleteFileRequest{ID: id}, nil + return deleteFileRequest{ + ID: id, + requestId: moovhttp.GetRequestId(r), + }, nil } type getFileContentsRequest struct { ID string + + requestId string } type getFileContentsResponse struct { @@ -183,14 +221,18 @@ type getFileContentsResponse struct { func (v getFileContentsResponse) error() error { return v.Err } -func getFileContentsEndpoint(s Service) endpoint.Endpoint { +func getFileContentsEndpoint(s Service, logger log.Logger) endpoint.Endpoint { return func(_ context.Context, request interface{}) (interface{}, error) { req := request.(getFileContentsRequest) r, err := s.GetFileContents(req.ID) + + if req.requestId != "" && logger != nil { + logger.Log("files", "getFileContents", "requestId", req.requestId, "error", err) + } if err != nil { - // TODO(adam): log? if requestId != "" return getFileContentsResponse{Err: err}, nil } + return r, nil } } @@ -201,11 +243,16 @@ func decodeGetFileContentsRequest(_ context.Context, r *http.Request) (interface if !ok { return nil, ErrBadRouting } - return getFileContentsRequest{ID: id}, nil + return getFileContentsRequest{ + ID: id, + requestId: moovhttp.GetRequestId(r), + }, nil } type validateFileRequest struct { ID string + + requestId string } type validateFileResponse struct { @@ -214,11 +261,17 @@ type validateFileResponse struct { func (v validateFileResponse) error() error { return v.Err } -func validateFileEndpoint(s Service) endpoint.Endpoint { +func validateFileEndpoint(s Service, logger log.Logger) endpoint.Endpoint { return func(_ context.Context, request interface{}) (interface{}, error) { req := request.(validateFileRequest) + err := s.ValidateFile(req.ID) + + if req.requestId != "" && logger != nil { + logger.Log("files", "validateFile", "requestId", req.requestId, "error", err) + } + return validateFileResponse{ - Err: s.ValidateFile(req.ID), + Err: err, }, nil } } @@ -229,5 +282,8 @@ func decodeValidateFileRequest(_ context.Context, r *http.Request) (interface{}, if !ok { return nil, ErrBadRouting } - return validateFileRequest{ID: id}, nil + return validateFileRequest{ + ID: id, + requestId: moovhttp.GetRequestId(r), + }, nil } diff --git a/server/logging.go b/server/logging.go deleted file mode 100644 index fa5d8d088..000000000 --- a/server/logging.go +++ /dev/null @@ -1,143 +0,0 @@ -// Copyright 2018 The Moov Authors -// Use of this source code is governed by an Apache License -// license that can be found in the LICENSE file. - -package server - -import ( - "fmt" - "io" - "time" - - "github.com/moov-io/ach" - - "github.com/go-kit/kit/log" -) - -// Middleware describes a service (as opposed to endpoint) middleware. -type Middleware func(Service) Service - -func LoggingMiddleware(logger log.Logger) Middleware { - return func(next Service) Service { - return &loggingMiddleware{ - next: next, - logger: logger, - } - } -} - -type loggingMiddleware struct { - next Service - logger log.Logger -} - -// timer represents a one-time stoppable time tracker -// it's assumed startTimer() is called to initialize a timer -type timer struct { - start, end time.Time -} - -func startTimer() *timer { - return &timer{ - start: time.Now(), - } -} - -// stop returns the number of milliseconds for the given timer -// and stops the timer. -func (t *timer) stop() int64 { - when := time.Now() - if t.end.IsZero() { - t.end = when - } - return t.end.Sub(t.start).Nanoseconds() / 1e6 -} -func (t *timer) String() string { - return fmt.Sprintf("%dms", t.stop()) -} - -// Middleware endpoints - -func (mw loggingMiddleware) CreateFile(f *ach.FileHeader) (id string, err error) { - t := startTimer() - defer func() { - // f.ID can be empty here if the request does not specify it, do we care? - // The ID is properly generated and stored, so there's no "issue", just flakey logs. - mw.logger.Log("method", "CreateFile", "id", f.ID, "took", t, "err", err) - }() - return mw.next.CreateFile(f) -} - -func (mw loggingMiddleware) GetFile(id string) (f *ach.File, err error) { - t := startTimer() - defer func() { - mw.logger.Log("method", "GetFile", "id", id, "took", t, "err", err) - }() - return mw.next.GetFile(id) -} - -func (mw loggingMiddleware) GetFiles() []*ach.File { - t := startTimer() - defer func() { - mw.logger.Log("method", "GetFiles", "took", t) - }() - return mw.next.GetFiles() -} - -func (mw loggingMiddleware) DeleteFile(id string) (err error) { - t := startTimer() - defer func() { - mw.logger.Log("method", "DeleteFile", "id", id, "took", t) - }() - return mw.next.DeleteFile(id) -} - -func (mw loggingMiddleware) GetFileContents(id string) (io.Reader, error) { - t := startTimer() - defer func() { - mw.logger.Log("method", "GetFileContents", "id", id, "took", t) - }() - return mw.next.GetFileContents(id) -} - -func (mw loggingMiddleware) ValidateFile(id string) error { - t := startTimer() - defer func() { - mw.logger.Log("method", "ValidateFile", "id", id, "took", t) - }() - return mw.next.ValidateFile(id) -} - -//** BATCHES ** // - -func (mw loggingMiddleware) CreateBatch(fileID string, batch ach.Batcher) (id string, err error) { - t := startTimer() - defer func() { - mw.logger.Log("method", "CreateBatch", "FileID", fileID, "batchID", batch.ID, "took", t, "err", err) - }() - return mw.next.CreateBatch(fileID, batch) -} - -func (mw loggingMiddleware) GetBatch(fileID string, batchID string) (b ach.Batcher, err error) { - t := startTimer() - defer func() { - mw.logger.Log("method", "GetBatch", "fileID", fileID, "batchID", batchID, "took", t, "err", err) - }() - return mw.next.GetBatch(fileID, batchID) -} - -func (mw loggingMiddleware) GetBatches(fileID string) []ach.Batcher { - t := startTimer() - defer func() { - mw.logger.Log("method", "GetBatches", "fileID", fileID, "took", t) - }() - return mw.next.GetBatches(fileID) -} - -func (mw loggingMiddleware) DeleteBatch(fileID string, batchID string) (err error) { - t := startTimer() - defer func() { - mw.logger.Log("method", "DeleteBatch", "fileID", fileID, "batchID", batchID, "took", t, "err", err) - }() - return mw.next.DeleteBatch(fileID, batchID) -} diff --git a/server/routing.go b/server/routing.go index aea497ad0..348902208 100644 --- a/server/routing.go +++ b/server/routing.go @@ -99,55 +99,55 @@ func MakeHTTPHandler(s Service, repo Repository, logger log.Logger) http.Handler options..., )) r.Methods("POST").Path("/files/create").Handler(httptransport.NewServer( - createFileEndpoint(s, repo), + createFileEndpoint(s, repo, logger), decodeCreateFileRequest, encodeResponse, options..., )) r.Methods("GET").Path("/files/{id}").Handler(httptransport.NewServer( - getFileEndpoint(s), + getFileEndpoint(s, logger), decodeGetFileRequest, encodeResponse, options..., )) r.Methods("GET").Path("/files/{id}/contents").Handler(httptransport.NewServer( - getFileContentsEndpoint(s), + getFileContentsEndpoint(s, logger), decodeGetFileContentsRequest, encodeTextResponse, options..., )) r.Methods("GET").Path("/files/{id}/validate").Handler(httptransport.NewServer( - validateFileEndpoint(s), + validateFileEndpoint(s, logger), decodeValidateFileRequest, encodeResponse, options..., )) r.Methods("DELETE").Path("/files/{id}").Handler(httptransport.NewServer( - deleteFileEndpoint(s), + deleteFileEndpoint(s, logger), decodeDeleteFileRequest, encodeResponse, options..., )) r.Methods("POST").Path("/files/{fileID}/batches").Handler(httptransport.NewServer( - createBatchEndpoint(s), + createBatchEndpoint(s, logger), decodeCreateBatchRequest, encodeResponse, options..., )) r.Methods("GET").Path("/files/{fileID}/batches").Handler(httptransport.NewServer( - getBatchesEndpoint(s), + getBatchesEndpoint(s, logger), decodeGetBatchesRequest, encodeResponse, options..., )) r.Methods("GET").Path("/files/{fileID}/batches/{batchID}").Handler(httptransport.NewServer( - getBatchEndpoint(s), + getBatchEndpoint(s, logger), decodeGetBatchRequest, encodeResponse, options..., )) r.Methods("DELETE").Path("/files/{fileID}/batches/{batchID}").Handler(httptransport.NewServer( - deleteBatchEndpoint(s), + deleteBatchEndpoint(s, logger), decodeDeleteBatchRequest, encodeResponse, options...,