Skip to content
Permalink
Browse files

Use custom logger for sql debug logging

  • Loading branch information...
mraerino committed Sep 10, 2019
1 parent b4606ff commit e50215cf432ea358e60f6da949051de5a0775634
Showing with 110 additions and 57 deletions.
  1. +3 −1 api/api.go
  2. +28 −0 api/db_logger.go
  3. +10 −8 api/download.go
  4. +7 −5 api/instance.go
  5. +11 −9 api/order.go
  6. +15 −13 api/payments.go
  7. +5 −4 api/reports.go
  8. +14 −12 api/user.go
  9. +16 −0 context/context.go
  10. +1 −5 models/connection_logger.go
@@ -98,6 +98,7 @@ func NewAPIWithVersion(ctx context.Context, globalConfig *conf.GlobalConfigurati

r.Route("/", func(r *router) {
r.UseBypass(logger)
r.Use(api.loggingDB)
if globalConfig.MultiInstanceMode {
r.Use(api.loadInstanceConfig)
}
@@ -147,9 +148,10 @@ func NewAPIWithVersion(ctx context.Context, globalConfig *conf.GlobalConfigurati

if globalConfig.MultiInstanceMode {
// Operator microservice API
r.WithBypass(logger).With(api.verifyOperatorRequest).Get("/", api.GetAppManifest)
r.WithBypass(logger).With(api.loggingDB).With(api.verifyOperatorRequest).Get("/", api.GetAppManifest)
r.Route("/instances", func(r *router) {
r.UseBypass(logger)
r.Use(api.loggingDB)
r.Use(api.verifyOperatorRequest)

r.Post("/", api.CreateInstance)
@@ -0,0 +1,28 @@
package api

import (
"context"
"net/http"

"github.com/jinzhu/gorm"
gcontext "github.com/netlify/gocommerce/context"
"github.com/netlify/gocommerce/models"
)

func (a *API) loggingDB(w http.ResponseWriter, r *http.Request) (context.Context, error) {
if a.db == nil {
return r.Context(), nil
}

log := getLogEntry(r)
db := a.db.New()
db.SetLogger(models.NewDBLogger(log))

return gcontext.WithDB(r.Context(), db), nil
}

// DB provides callers with a database instance configured for request logging
func (a *API) DB(r *http.Request) *gorm.DB {
ctx := r.Context()
return gcontext.GetDB(ctx)
}
@@ -15,21 +15,22 @@ const maxIPsPerDay = 50
// DownloadURL returns a signed URL to download a purchased asset.
func (a *API) DownloadURL(w http.ResponseWriter, r *http.Request) error {
ctx := r.Context()
db := a.DB(r)
downloadID := chi.URLParam(r, "download_id")
logEntrySetField(r, "download_id", downloadID)
claims := gcontext.GetClaims(ctx)
assets := gcontext.GetAssetStore(ctx)

download := &models.Download{}
if result := a.db.Where("id = ?", downloadID).First(download); result.Error != nil {
if result := db.Where("id = ?", downloadID).First(download); result.Error != nil {
if result.RecordNotFound() {
return notFoundError("Download not found")
}
return internalServerError("Error during database query").WithInternalError(result.Error)
}

order := &models.Order{}
if result := a.db.Where("id = ?", download.OrderID).First(order); result.Error != nil {
if result := db.Where("id = ?", download.OrderID).First(order); result.Error != nil {
if result.RecordNotFound() {
return notFoundError("Download order not found")
}
@@ -44,7 +45,7 @@ func (a *API) DownloadURL(w http.ResponseWriter, r *http.Request) error {
return unauthorizedError("This download has not been paid yet")
}

rows, err := a.db.Model(&models.Event{}).
rows, err := db.Model(&models.Event{}).
Select("count(distinct(ip))").
Where("order_id = ? and created_at > ? and changes = 'download'", order.ID, time.Now().Add(-24*time.Hour)).
Rows()
@@ -66,7 +67,7 @@ func (a *API) DownloadURL(w http.ResponseWriter, r *http.Request) error {
return internalServerError("Error signing download").WithInternalError(err)
}

tx := a.db.Begin()
tx := db.Begin()
tx.Model(download).Updates(map[string]interface{}{"download_count": gorm.Expr("download_count + 1")})
var subject string
if claims != nil {
@@ -81,12 +82,13 @@ func (a *API) DownloadURL(w http.ResponseWriter, r *http.Request) error {
// DownloadList lists all purchased downloads for an order or a user.
func (a *API) DownloadList(w http.ResponseWriter, r *http.Request) error {
ctx := r.Context()
db := a.DB(r)
orderID := gcontext.GetOrderID(ctx)
log := getLogEntry(r)

order := &models.Order{}
if orderID != "" {
if result := a.db.Where("id = ?", orderID).First(order); result.Error != nil {
if result := db.Where("id = ?", orderID).First(order); result.Error != nil {
if result.RecordNotFound() {
return notFoundError("Download order not found")
}
@@ -106,10 +108,10 @@ func (a *API) DownloadList(w http.ResponseWriter, r *http.Request) error {
}
}

orderTable := a.db.NewScope(models.Order{}).QuotedTableName()
downloadsTable := a.db.NewScope(models.Download{}).QuotedTableName()
orderTable := db.NewScope(models.Order{}).QuotedTableName()
downloadsTable := db.NewScope(models.Download{}).QuotedTableName()

query := a.db.Joins("join " + orderTable + " ON " + downloadsTable + ".order_id = " + orderTable + ".id and " + orderTable + ".payment_state = 'paid'")
query := db.Joins("join " + orderTable + " ON " + downloadsTable + ".order_id = " + orderTable + ".id and " + orderTable + ".payment_state = 'paid'")
if order != nil {
query = query.Where(orderTable+".id = ?", order.ID)
} else {
@@ -16,7 +16,7 @@ func (a *API) loadInstance(w http.ResponseWriter, r *http.Request) (context.Cont
instanceID := chi.URLParam(r, "instance_id")
logEntrySetField(r, "instance_id", instanceID)

i, err := models.GetInstance(a.db, instanceID)
i, err := models.GetInstance(a.DB(r), instanceID)
if err != nil {
if models.IsNotFoundError(err) {
return nil, notFoundError("Instance not found")
@@ -47,12 +47,14 @@ type InstanceResponse struct {
}

func (a *API) CreateInstance(w http.ResponseWriter, r *http.Request) error {
db := a.DB(r)

params := InstanceRequestParams{}
if err := json.NewDecoder(r.Body).Decode(&params); err != nil {
return badRequestError("Error decoding params: %v", err)
}

_, err := models.GetInstanceByUUID(a.db, params.UUID)
_, err := models.GetInstanceByUUID(db, params.UUID)
if err != nil {
if !models.IsNotFoundError(err) {
return internalServerError("Database error looking up instance").WithInternalError(err)
@@ -66,7 +68,7 @@ func (a *API) CreateInstance(w http.ResponseWriter, r *http.Request) error {
UUID: params.UUID,
BaseConfig: params.BaseConfig,
}
if err = models.CreateInstance(a.db, &i); err != nil {
if err = models.CreateInstance(db, &i); err != nil {
return internalServerError("Database error creating instance").WithInternalError(err)
}

@@ -95,15 +97,15 @@ func (a *API) UpdateInstance(w http.ResponseWriter, r *http.Request) error {
i.BaseConfig = params.BaseConfig
}

if err := models.UpdateInstance(a.db, i); err != nil {
if err := models.UpdateInstance(a.DB(r), i); err != nil {
return internalServerError("Database error updating instance").WithInternalError(err)
}
return sendJSON(w, http.StatusOK, i)
}

func (a *API) DeleteInstance(w http.ResponseWriter, r *http.Request) error {
i := gcontext.GetInstance(r.Context())
if err := models.DeleteInstance(a.db, i); err != nil {
if err := models.DeleteInstance(a.DB(r), i); err != nil {
return internalServerError("Database error deleting instance").WithInternalError(err)
}

@@ -85,6 +85,7 @@ func (a *API) withOrderID(w http.ResponseWriter, r *http.Request) (context.Conte
// ClaimOrders will look for any orders with no user id belonging to an email and claim them
func (a *API) ClaimOrders(w http.ResponseWriter, r *http.Request) error {
ctx := r.Context()
db := a.DB(r)
log := getLogEntry(r)
instanceID := gcontext.GetInstanceID(ctx)

@@ -103,7 +104,7 @@ func (a *API) ClaimOrders(w http.ResponseWriter, r *http.Request) error {
})

// now find all the order associated with that email
query := orderQuery(a.db)
query := orderQuery(db)
query = query.Where(&models.Order{
InstanceID: instanceID,
UserID: "",
@@ -115,7 +116,7 @@ func (a *API) ClaimOrders(w http.ResponseWriter, r *http.Request) error {
return internalServerError("Failed to query for orders with email: %s", claims.Email).WithInternalError(res.Error)
}

tx := a.db.Begin()
tx := db.Begin()

// create the user
user := models.User{
@@ -154,7 +155,7 @@ func (a *API) ReceiptView(w http.ResponseWriter, r *http.Request) error {
logEntrySetField(r, "order_id", id)

order := &models.Order{}
if result := orderQuery(a.db).Preload("Transactions").First(order, "id = ?", id); result.Error != nil {
if result := orderQuery(a.DB(r)).Preload("Transactions").First(order, "id = ?", id); result.Error != nil {
if result.RecordNotFound() {
return notFoundError("Order not found")
}
@@ -198,7 +199,7 @@ func (a *API) ResendOrderReceipt(w http.ResponseWriter, r *http.Request) error {
}

order := &models.Order{}
if result := orderQuery(a.db).Preload("Transactions").First(order, "id = ?", id); result.Error != nil {
if result := orderQuery(a.DB(r)).Preload("Transactions").First(order, "id = ?", id); result.Error != nil {
if result.RecordNotFound() {
return notFoundError("Order not found")
}
@@ -246,7 +247,7 @@ func (a *API) OrderList(w http.ResponseWriter, r *http.Request) error {

var err error
params := r.URL.Query()
query := orderQuery(a.db)
query := orderQuery(a.DB(r))
query, err = parseOrderParams(query, params)
if err != nil {
return badRequestError("Bad parameters in query: %v", err)
@@ -286,7 +287,7 @@ func (a *API) OrderView(w http.ResponseWriter, r *http.Request) error {
log := getLogEntry(r)

order := &models.Order{}
if result := orderQuery(a.db).First(order, "id = ?", id); result.Error != nil {
if result := orderQuery(a.DB(r)).First(order, "id = ?", id); result.Error != nil {
if result.RecordNotFound() {
return notFoundError("Order not found")
}
@@ -338,7 +339,7 @@ func (a *API) OrderCreate(w http.ResponseWriter, r *http.Request) error {
"email": params.Email,
"currency": params.Currency,
}).Debug("Created order, starting to process request")
tx := a.db.Begin()
tx := a.DB(r).Begin()

order.IP = r.RemoteAddr
order.MetaData = params.MetaData
@@ -425,6 +426,7 @@ func (a *API) OrderCreate(w http.ResponseWriter, r *http.Request) error {
// There are also blocks to changing certain fields after the state has been locked
func (a *API) OrderUpdate(w http.ResponseWriter, r *http.Request) error {
ctx := r.Context()
db := a.DB(r)
orderID := gcontext.GetOrderID(ctx)
log := getLogEntry(r)
claims := gcontext.GetClaims(ctx)
@@ -440,7 +442,7 @@ func (a *API) OrderUpdate(w http.ResponseWriter, r *http.Request) error {
// verify that the order exists
existingOrder := new(models.Order)

rsp := orderQuery(a.db).First(existingOrder, "id = ?", orderID)
rsp := orderQuery(db).First(existingOrder, "id = ?", orderID)
if rsp.RecordNotFound() {
return notFoundError("Failed to find order with id '%s'", orderID)
}
@@ -486,7 +488,7 @@ func (a *API) OrderUpdate(w http.ResponseWriter, r *http.Request) error {
changes = append(changes, "vatnumber")
}

tx := a.db.Begin()
tx := db.Begin()

//
// handle the addresses
@@ -45,7 +45,7 @@ func (a *API) PaymentListForUser(w http.ResponseWriter, r *http.Request) error {
return notFoundError("Couldn't find a record for " + userID)
}

trans, httpErr := queryForTransactions(a.db, log, "user_id = ?", userID)
trans, httpErr := queryForTransactions(a.DB(r), log, "user_id = ?", userID)
if httpErr != nil {
return httpErr
}
@@ -60,7 +60,7 @@ func (a *API) PaymentListForOrder(w http.ResponseWriter, r *http.Request) error
orderID := gcontext.GetOrderID(ctx)
claims := gcontext.GetClaims(ctx)

order, httpErr := queryForOrder(a.db, orderID, log)
order, httpErr := queryForOrder(a.DB(r), orderID, log)
if httpErr != nil {
return httpErr
}
@@ -138,7 +138,7 @@ func (a *API) PaymentCreate(w http.ResponseWriter, r *http.Request) error {
}

orderID := gcontext.GetOrderID(ctx)
tx := a.db.Begin()
tx := a.DB(r).Begin()
order := &models.Order{}
loader := tx.
Preload("LineItems").
@@ -237,9 +237,10 @@ func (a *API) PaymentCreate(w http.ResponseWriter, r *http.Request) error {
func (a *API) PaymentConfirm(w http.ResponseWriter, r *http.Request) error {
ctx := r.Context()
log := getLogEntry(r)
db := a.DB(r)

payID := chi.URLParam(r, "payment_id")
trans, httpErr := a.getTransaction(payID)
trans, httpErr := getTransaction(db, payID)
if httpErr != nil {
return httpErr
}
@@ -260,7 +261,7 @@ func (a *API) PaymentConfirm(w http.ResponseWriter, r *http.Request) error {
}

order := &models.Order{}
if rsp := a.db.Find(order, "id = ?", trans.OrderID); rsp.Error != nil {
if rsp := db.Find(order, "id = ?", trans.OrderID); rsp.Error != nil {
if rsp.RecordNotFound() {
return notFoundError("Order not found")
}
@@ -286,7 +287,7 @@ func (a *API) PaymentConfirm(w http.ResponseWriter, r *http.Request) error {
return internalServerError("Error on provider while trying to confirm: %v. Try again later.", err)
}

tx := a.db.Begin()
tx := db.Begin()

if trans.InvoiceNumber == 0 {
invoiceNumber, err := models.NextInvoiceNumber(tx, order.InstanceID)
@@ -311,7 +312,7 @@ func (a *API) PaymentConfirm(w http.ResponseWriter, r *http.Request) error {
func (a *API) PaymentList(w http.ResponseWriter, r *http.Request) error {
log := getLogEntry(r)
instanceID := gcontext.GetInstanceID(r.Context())
query := a.db.Where("instance_id = ?", instanceID)
query := a.DB(r).Where("instance_id = ?", instanceID)

query, err := parsePaymentQueryParams(query, r.URL.Query())
if err != nil {
@@ -328,7 +329,7 @@ func (a *API) PaymentList(w http.ResponseWriter, r *http.Request) error {
// PaymentView returns information about a single payment. It is only available to admins.
func (a *API) PaymentView(w http.ResponseWriter, r *http.Request) error {
payID := chi.URLParam(r, "payment_id")
trans, httpErr := a.getTransaction(payID)
trans, httpErr := getTransaction(a.DB(r), payID)
if httpErr != nil {
return httpErr
}
@@ -339,6 +340,7 @@ func (a *API) PaymentView(w http.ResponseWriter, r *http.Request) error {
// refunds if desired. It is only available to admins.
func (a *API) PaymentRefund(w http.ResponseWriter, r *http.Request) error {
ctx := r.Context()
db := a.DB(r)
config := gcontext.GetConfig(ctx)
params := PaymentParams{Currency: "USD"}
err := json.NewDecoder(r.Body).Decode(&params)
@@ -347,7 +349,7 @@ func (a *API) PaymentRefund(w http.ResponseWriter, r *http.Request) error {
}

payID := chi.URLParam(r, "payment_id")
trans, httpErr := a.getTransaction(payID)
trans, httpErr := getTransaction(db, payID)
if httpErr != nil {
return httpErr
}
@@ -369,7 +371,7 @@ func (a *API) PaymentRefund(w http.ResponseWriter, r *http.Request) error {
}

log := getLogEntry(r)
order, httpErr := queryForOrder(a.db, trans.OrderID, log)
order, httpErr := queryForOrder(db, trans.OrderID, log)
if httpErr != nil {
return httpErr
}
@@ -398,7 +400,7 @@ func (a *API) PaymentRefund(w http.ResponseWriter, r *http.Request) error {
Status: models.PendingState,
}

tx := a.db.Begin()
tx := db.Begin()
tx.Create(m)
provID := provider.Name()
log.Debugf("Starting refund to %s", provID)
@@ -480,8 +482,8 @@ func (a *API) PreauthorizePayment(w http.ResponseWriter, r *http.Request) error
// ------------------------------------------------------------------------------------------------
// Helpers
// ------------------------------------------------------------------------------------------------
func (a *API) getTransaction(payID string) (*models.Transaction, *HTTPError) {
trans, err := models.GetTransaction(a.db, payID)
func getTransaction(db *gorm.DB, payID string) (*models.Transaction, *HTTPError) {
trans, err := models.GetTransaction(db, payID)
if err != nil {
return nil, internalServerError("Error while querying for transactions").WithInternalError(err)
}

0 comments on commit e50215c

Please sign in to comment.
You can’t perform that action at this time.