Skip to content
Permalink
Browse files

logger interface

  • Loading branch information...
pjdufour-truss committed Mar 14, 2019
1 parent 28e70bb commit fe45ce64df5413e18a36937e66484889d424283f
Showing with 524 additions and 264 deletions.
  1. +3 −2 bin/run-e2e-test-docker
  2. +15 −15 cmd/generate_shipment_edi/main.go
  3. +13 −0 cmd/webserver/logger.go
  4. +39 −32 cmd/webserver/main.go
  5. +12 −3 cmd/webserver/main_test.go
  6. +0 −35 cmd/webserver/webserverLogger.go
  7. +1 −0 docs/README.md
  8. +65 −0 docs/how-to/add-application-logging.md
  9. +1 −1 pkg/auth/auth_test.go
  10. +4 −4 pkg/auth/authentication/auth.go
  11. +2 −2 pkg/auth/authentication/auth_test.go
  12. +1 −2 pkg/auth/authentication/client_cert.go
  13. +1 −2 pkg/auth/authentication/devlocal.go
  14. +11 −0 pkg/auth/authentication/logger.go
  15. +3 −3 pkg/auth/authentication/login_gov.go
  16. +7 −7 pkg/auth/cookie.go
  17. +1 −1 pkg/auth/hostname_detector.go
  18. +11 −0 pkg/auth/logger.go
  19. +5 −5 pkg/awardqueue/awardqueue.go
  20. +2 −1 pkg/awardqueue/awardqueue_test.go
  21. +15 −0 pkg/awardqueue/logger.go
  22. +0 −5 pkg/db/sequence/sequencer_test.go
  23. +2 −2 pkg/dpsauth/auth.go
  24. +1 −1 pkg/dpsauth/cookie_test.go
  25. +10 −0 pkg/dpsauth/logger.go
  26. +8 −9 pkg/edi/invoice/generator.go
  27. +8 −8 pkg/edi/invoice/generator_test.go
  28. +15 −0 pkg/edi/invoice/logger.go
  29. +3 −3 pkg/handlers/apitests.go
  30. +8 −5 pkg/handlers/contexts.go
  31. +5 −5 pkg/handlers/errors.go
  32. +0 −1 pkg/handlers/internalapi/move_queue_items.go
  33. +1 −0 pkg/handlers/internalapi/shipments.go
  34. +1 −2 pkg/handlers/internalapi/users.go
  35. +15 −0 pkg/handlers/logger.go
  36. +2 −3 pkg/handlers/publicapi/generic_move_documents.go
  37. +0 −1 pkg/handlers/publicapi/move_documents.go
  38. +2 −4 pkg/handlers/responders.go
  39. +0 −8 pkg/iws/iws_test.go
  40. +1 −0 pkg/logging/log.go
  41. +1 −1 pkg/models/estimate_helper.go
  42. +14 −0 pkg/models/logger.go
  43. +12 −0 pkg/notifications/logger.go
  44. +2 −3 pkg/notifications/move_approved.go
  45. +2 −6 pkg/notifications/move_canceled.go
  46. +2 −5 pkg/notifications/move_submitted.go
  47. +3 −3 pkg/notifications/notification_sender.go
  48. +1 −1 pkg/notifications/notification_stub.go
  49. +1 −1 pkg/notifications/notification_test.go
  50. +2 −2 pkg/paperwork/generator.go
  51. +10 −0 pkg/paperwork/logger.go
  52. +1 −1 pkg/paperwork/paperwork_test.go
  53. +14 −0 pkg/rateengine/logger.go
  54. +2 −2 pkg/rateengine/rateengine.go
  55. +2 −2 pkg/rateengine/rateengine_test.go
  56. +2 −2 pkg/route/bing_planner.go
  57. +2 −2 pkg/route/here_planner.go
  58. +11 −0 pkg/route/logger.go
  59. +1 −1 pkg/route/planner_test.go
  60. +13 −0 pkg/server/logger.go
  61. +2 −12 pkg/server/server.go
  62. +1 −1 pkg/server/server_test.go
  63. +27 −0 pkg/server/std_logger.go
  64. +3 −7 pkg/services/invoice/invoice_service_test.go
  65. +15 −0 pkg/services/invoice/logger.go
  66. +3 −2 pkg/services/invoice/process_invoice.go
  67. +1 −0 pkg/services/invoice/process_invoice_test.go
  68. +5 −5 pkg/services/invoice/send_to_gex_http_test.go
  69. +1 −1 pkg/services/invoice/store_invoice.go
  70. +0 −5 pkg/services/paperwork/create_form_test.go
  71. +1 −1 pkg/services/shipment/deliver_and_price_shipment_test.go
  72. +14 −0 pkg/services/shipment/logger.go
  73. +1 −2 pkg/services/shipment/process_recalculate_shipment.go
  74. +1 −1 pkg/services/shipment/recalculate_shipment.go
  75. +1 −1 pkg/services/shipment/recalculate_shipment_test.go
  76. +3 −4 pkg/storage/filesystem.go
  77. +1 −2 pkg/storage/filesystem_test.go
  78. +14 −0 pkg/storage/logger.go
  79. +3 −4 pkg/storage/memory.go
  80. +1 −2 pkg/storage/memory_test.go
  81. +2 −3 pkg/storage/s3.go
  82. +3 −4 pkg/testdatagen/scenario/e2ebasic.go
  83. +14 −0 pkg/testdatagen/scenario/logger.go
  84. +12 −0 pkg/uploader/logger.go
  85. +2 −2 pkg/uploader/uploader.go
  86. +1 −1 pkg/uploader/uploader_test.go
@@ -44,6 +44,8 @@ $DOCKER_RUN \
-e DOD_CA_PACKAGE="/config/tls/Certificates_PKCS7_v5.4_DoD.der.p7b" \
-e DPS_AUTH_COOKIE_SECRET_KEY \
-e DPS_COOKIE_EXPIRES_IN_MINUTES \
-e EIA_KEY \
-e EIA_URL \
-e ENV="test" \
-e HERE_MAPS_APP_CODE \
-e HERE_MAPS_APP_ID \
@@ -71,11 +73,10 @@ $DOCKER_RUN \
--link="milmove-db-test:database" \
--read-only \
--detach \
--rm \
${CONTAINER}:latest

# If your container is exiting unexpectedly try uncommenting this code to see the output:
# docker logs -f ${CONTAINER}
docker logs -f ${CONTAINER}

# Grab the IP address of the running container
E2E_IP=$(docker inspect -f '{{range .NetworkSettings.Networks}}{{.IPAddress}}{{end}}' ${CONTAINER})
@@ -65,32 +65,32 @@ func main() {
sendToGex := v.GetBool("gex")
transactionName := v.GetString("transaction-name")
if shipmentIDString == "" || approverEmail == "" {
log.Fatal("Usage: go run cmd/generate_shipment_edi/main.go --shipmentID <29cb984e-c70d-46f0-926d-cd89e07a6ec3> --approver <officeuser1@example.com> --gex false")
logger.Fatal("Usage: go run cmd/generate_shipment_edi/main.go --shipmentID <29cb984e-c70d-46f0-926d-cd89e07a6ec3> --approver <officeuser1@example.com> --gex false")
}

db, err := pop.Connect("development")
if err != nil {
log.Fatal(err)
logger.Fatal(err.Error())
}

shipmentID := uuid.Must(uuid.FromString(shipmentIDString))
shipment, err := invoice.FetchShipmentForInvoice{DB: db}.Call(shipmentID)
if err != nil {
log.Fatal(err)
logger.Fatal(err.Error())
}

approver, err := models.FetchOfficeUserByEmail(db, approverEmail)
if err != nil {
log.Fatalf("Could not fetch office user with e-mail %s: %v", approverEmail, err)
logger.Fatal("Could not fetch office user with e-mail", zap.String("email", approverEmail), zap.Error(err))
}

var invoiceModel models.Invoice
verrs, err := invoice.CreateInvoice{DB: db, Clock: clock.New()}.Call(*approver, &invoiceModel, shipment)
if err != nil {
log.Fatal(err)
logger.Fatal(err.Error())
}
if verrs.HasAny() {
log.Fatal(verrs)
logger.Fatal(verrs.Error())
}

var sendToGexHTTP services.GexSender
@@ -113,7 +113,7 @@ func main() {
)
}

resp, err := processInvoice(db, shipment, invoiceModel, sendToGex, &transactionName, sendToGexHTTP)
resp, err := processInvoice(db, shipment, invoiceModel, sendToGex, &transactionName, sendToGexHTTP, logger)
if resp != nil {
fmt.Printf("status code: %v\n", resp.StatusCode)
}
@@ -122,27 +122,27 @@ func main() {
}
}

func processInvoice(db *pop.Connection, shipment models.Shipment, invoiceModel models.Invoice, sendToGex bool, transactionName *string, gexSender services.GexSender) (resp *http.Response, err error) {
func processInvoice(db *pop.Connection, shipment models.Shipment, invoiceModel models.Invoice, sendToGex bool, transactionName *string, gexSender services.GexSender, logger *zap.Logger) (resp *http.Response, err error) {
defer func() {
if err != nil || (resp != nil && resp.StatusCode != 200) {
// Update invoice record as failed
invoiceModel.Status = models.InvoiceStatusSUBMISSIONFAILURE
verrs, deferErr := db.ValidateAndSave(&invoiceModel)
if deferErr != nil {
log.Fatal(deferErr)
logger.Fatal(deferErr.Error())
}
if verrs.HasAny() {
log.Fatal(verrs)
logger.Fatal(verrs.Error())
}
} else {
// Update invoice record as submitted
shipmentLineItems := shipment.ShipmentLineItems
verrs, deferErr := invoice.UpdateInvoiceSubmitted{DB: db}.Call(&invoiceModel, shipmentLineItems)
if deferErr != nil {
log.Fatal(deferErr)
logger.Fatal(deferErr.Error())
}
if verrs.HasAny() {
log.Fatal(verrs)
logger.Fatal(verrs.Error())
}
}
}()
@@ -151,13 +151,13 @@ func processInvoice(db *pop.Connection, shipment models.Shipment, invoiceModel m
if sendToGex {
icnSequencer, err = sequence.NewRandomSequencer(ediinvoice.ICNRandomMin, ediinvoice.ICNRandomMax)
if err != nil {
log.Fatal("Could not create random sequencer for ICN", err)
logger.Fatal("Could not create random sequencer for ICN", zap.Error(err))
}
} else {
icnSequencer = sequence.NewDatabaseSequencer(db, ediinvoice.ICNSequenceName)
}

invoice858C, err := ediinvoice.Generate858C(shipment, invoiceModel, db, false, icnSequencer, clock.New())
invoice858C, err := ediinvoice.Generate858C(shipment, invoiceModel, db, false, icnSequencer, clock.New(), logger)
if err != nil {
return nil, err
}
@@ -170,7 +170,7 @@ func processInvoice(db *pop.Connection, shipment models.Shipment, invoiceModel m
}
resp, err := gexSender.SendToGex(invoice858CString, *transactionName)
if resp == nil || err != nil {
log.Fatal("Gex Sender had no response", err)
logger.Fatal("Gex Sender had no response", zap.Error(err))
}

fmt.Printf("status code: %v, error: %v\n", resp.StatusCode, err)
@@ -0,0 +1,13 @@
package main

import (
"go.uber.org/zap"
)

type logger interface {
Debug(msg string, fields ...zap.Field)
Info(msg string, fields ...zap.Field)
Error(msg string, fields ...zap.Field)
Warn(msg string, fields ...zap.Field)
Fatal(msg string, fields ...zap.Field)
}
@@ -279,7 +279,7 @@ func initFlags(flag *pflag.FlagSet) {
flag.String("eia-url", "", "Url for Energy Information Administration (EIA) api")
}

func initDODCertificates(v *viper.Viper, logger *webserverLogger) ([]tls.Certificate, *x509.CertPool, error) {
func initDODCertificates(v *viper.Viper, logger logger) ([]tls.Certificate, *x509.CertPool, error) {

// https://tools.ietf.org/html/rfc7468#section-2
// - https://stackoverflow.com/questions/20173472/does-go-regexps-any-charcter-match-newline
@@ -376,7 +376,7 @@ func initDODCertificates(v *viper.Viper, logger *webserverLogger) ([]tls.Certifi

}

func initRoutePlanner(v *viper.Viper, logger *zap.Logger) route.Planner {
func initRoutePlanner(v *viper.Viper, logger logger) route.Planner {
hereClient := &http.Client{Timeout: hereRequestTimeout}
return route.NewHEREPlanner(
logger,
@@ -387,7 +387,7 @@ func initRoutePlanner(v *viper.Viper, logger *zap.Logger) route.Planner {
v.GetString("here-maps-app-code"))
}

func initHoneycomb(v *viper.Viper, logger *webserverLogger) bool {
func initHoneycomb(v *viper.Viper, logger logger) bool {

honeycombAPIHost := v.GetString("honeycomb-api-host")
honeycombAPIKey := v.GetString("honeycomb-api-key")
@@ -412,15 +412,15 @@ func initHoneycomb(v *viper.Viper, logger *webserverLogger) bool {
return false
}

func initRBSPersonLookup(v *viper.Viper, logger *webserverLogger) (*iws.RBSPersonLookup, error) {
func initRBSPersonLookup(v *viper.Viper, logger logger) (*iws.RBSPersonLookup, error) {
return iws.NewRBSPersonLookup(
v.GetString("iws-rbs-host"),
v.GetString("dod-ca-package"),
v.GetString("move-mil-dod-tls-cert"),
v.GetString("move-mil-dod-tls-key"))
}

func initDatabase(v *viper.Viper, logger *webserverLogger) (*pop.Connection, error) {
func initDatabase(v *viper.Viper, logger logger) (*pop.Connection, error) {

env := v.GetString("env")
dbName := v.GetString("db-name")
@@ -711,7 +711,7 @@ func checkStorage(v *viper.Viper) error {
return nil
}

func startListener(srv *server.NamedServer, logger *webserverLogger, useTLS bool) {
func startListener(srv *server.NamedServer, logger logger, useTLS bool) {
logger.Info("Starting listener",
zap.String("name", srv.Name),
zap.Duration("idle-timeout", srv.IdleTimeout),
@@ -745,13 +745,20 @@ func main() {
env := v.GetString("env")
isDevOrTest := env == "development" || env == "test"

zapLogger, err := logging.Config(env, v.GetBool("debug-logging"))
logger, err := logging.Config(env, v.GetBool("debug-logging"))
if err != nil {
log.Fatalf("Failed to initialize Zap logging due to %v", err)
}
zap.ReplaceGlobals(zapLogger)

logger := &webserverLogger{zapLogger}
fields := make([]zap.Field, 0)
if len(gitBranch) > 0 {
fields = append(fields, zap.String("git_branch", gitBranch))
}
if len(gitCommit) > 0 {
fields = append(fields, zap.String("git_commit", gitCommit))
}
logger = logger.With(fields...)
zap.ReplaceGlobals(logger)

logger.Debug("webserver starting up")

@@ -800,7 +807,7 @@ func main() {
tspHostname := v.GetString("http-tsp-server-name")

// Register Login.gov authentication provider for My.(move.mil)
loginGovProvider := authentication.NewLoginGovProvider(loginGovHostname, loginGovSecretKey, zapLogger)
loginGovProvider := authentication.NewLoginGovProvider(loginGovHostname, loginGovSecretKey, logger)
err = loginGovProvider.RegisterProvider(
myHostname,
v.GetString("login-gov-my-client-id"),
@@ -817,12 +824,12 @@ func main() {
useSecureCookie := !isDevOrTest
// Session management and authentication middleware
noSessionTimeout := v.GetBool("no-session-timeout")
sessionCookieMiddleware := auth.SessionCookieMiddleware(zapLogger, clientAuthSecretKey, noSessionTimeout, myHostname, officeHostname, tspHostname, useSecureCookie)
maskedCSRFMiddleware := auth.MaskedCSRFMiddleware(zapLogger, noSessionTimeout, useSecureCookie)
userAuthMiddleware := authentication.UserAuthMiddleware(zapLogger)
clientCertMiddleware := authentication.ClientCertMiddleware(zapLogger, dbConnection)
sessionCookieMiddleware := auth.SessionCookieMiddleware(logger, clientAuthSecretKey, noSessionTimeout, myHostname, officeHostname, tspHostname, useSecureCookie)
maskedCSRFMiddleware := auth.MaskedCSRFMiddleware(logger, noSessionTimeout, useSecureCookie)
userAuthMiddleware := authentication.UserAuthMiddleware(logger)
clientCertMiddleware := authentication.ClientCertMiddleware(logger, dbConnection)

handlerContext := handlers.NewHandlerContext(dbConnection, zapLogger)
handlerContext := handlers.NewHandlerContext(dbConnection, logger)
handlerContext.SetCookieSecret(clientAuthSecretKey)
handlerContext.SetUseSecureCookie(useSecureCookie)
if noSessionTimeout {
@@ -845,11 +852,11 @@ func main() {
logger.Fatal("Failed to create a new AWS client config provider", zap.Error(err))
}
sesService := ses.New(sesSession)
handlerContext.SetNotificationSender(notifications.NewNotificationSender(sesService, awsSESDomain, zapLogger))
handlerContext.SetNotificationSender(notifications.NewNotificationSender(sesService, awsSESDomain, logger))
} else {
domain := "milmovelocal"
logger.Info("Using local email backend", zap.String("domain", domain))
handlerContext.SetNotificationSender(notifications.NewStubNotificationSender(domain, zapLogger))
handlerContext.SetNotificationSender(notifications.NewStubNotificationSender(domain, logger))
}

build := v.GetString("build")
@@ -859,7 +866,7 @@ func main() {

// Get route planner for handlers to calculate transit distances
// routePlanner := route.NewBingPlanner(logger, bingMapsEndpoint, bingMapsKey)
routePlanner := initRoutePlanner(v, zapLogger)
routePlanner := initRoutePlanner(v, logger)
handlerContext.SetPlanner(routePlanner)

// Set SendProductionInvoice for ediinvoice
@@ -890,18 +897,18 @@ func main() {
aws := awssession.Must(awssession.NewSession(&aws.Config{
Region: aws.String(awsS3Region),
}))
storer = storage.NewS3(awsS3Bucket, awsS3KeyNamespace, zapLogger, aws)
storer = storage.NewS3(awsS3Bucket, awsS3KeyNamespace, logger, aws)
} else if storageBackend == "memory" {
logger.Info("Using memory storage backend",
zap.String("root", path.Join(localStorageRoot, localStorageWebRoot)),
zap.String("web root", localStorageWebRoot))
fsParams := storage.NewMemoryParams(localStorageRoot, localStorageWebRoot, zapLogger)
fsParams := storage.NewMemoryParams(localStorageRoot, localStorageWebRoot, logger)
storer = storage.NewMemory(fsParams)
} else {
logger.Info("Using local storage backend",
zap.String("root", path.Join(localStorageRoot, localStorageWebRoot)),
zap.String("web root", localStorageWebRoot))
fsParams := storage.NewFilesystemParams(localStorageRoot, localStorageWebRoot, zapLogger)
fsParams := storage.NewFilesystemParams(localStorageRoot, localStorageWebRoot, logger)
storer = storage.NewFilesystem(fsParams)
}
handlerContext.SetFileStorer(storer)
@@ -1026,7 +1033,7 @@ func main() {
} else {
protocol = "https"
}
zapLogger.Info("Request",
logger.Info("Request",
zap.String("git-branch", gitBranch),
zap.String("git-commit", gitCommit),
zap.String("accepted-language", r.Header.Get("accepted-language")),
@@ -1061,7 +1068,7 @@ func main() {
}

ordersMux := goji.SubMux()
ordersDetectionMiddleware := auth.HostnameDetectorMiddleware(zapLogger, v.GetString("http-orders-server-name"))
ordersDetectionMiddleware := auth.HostnameDetectorMiddleware(logger, v.GetString("http-orders-server-name"))
ordersMux.Use(ordersDetectionMiddleware)
ordersMux.Use(noCacheMiddleware)
ordersMux.Use(clientCertMiddleware)
@@ -1076,7 +1083,7 @@ func main() {
site.Handle(pat.Get("/orders/v0/*"), ordersMux)

dpsMux := goji.SubMux()
dpsDetectionMiddleware := auth.HostnameDetectorMiddleware(zapLogger, v.GetString("http-dps-server-name"))
dpsDetectionMiddleware := auth.HostnameDetectorMiddleware(logger, v.GetString("http-dps-server-name"))
dpsMux.Use(dpsDetectionMiddleware)
dpsMux.Use(noCacheMiddleware)
dpsMux.Use(clientCertMiddleware)
@@ -1091,12 +1098,12 @@ func main() {
site.Handle(pat.New("/dps/v0/*"), dpsMux)

sddcDPSMux := goji.SubMux()
sddcDetectionMiddleware := auth.HostnameDetectorMiddleware(zapLogger, sddcHostname)
sddcDetectionMiddleware := auth.HostnameDetectorMiddleware(logger, sddcHostname)
sddcDPSMux.Use(sddcDetectionMiddleware)
sddcDPSMux.Use(noCacheMiddleware)
site.Handle(pat.New("/dps_auth/*"), sddcDPSMux)
sddcDPSMux.Handle(pat.Get("/set_cookie"),
dpsauth.NewSetCookieHandler(zapLogger,
dpsauth.NewSetCookieHandler(logger,
dpsAuthSecretKey,
dpsCookieDomain,
dpsCookieSecret,
@@ -1160,7 +1167,7 @@ func main() {
internalAPIMux.Use(noCacheMiddleware)
internalAPIMux.Handle(pat.New("/*"), internalapi.NewInternalAPIHandler(handlerContext))

authContext := authentication.NewAuthContext(zapLogger, loginGovProvider, loginGovCallbackProtocol, loginGovCallbackPort)
authContext := authentication.NewAuthContext(logger, loginGovProvider, loginGovCallbackProtocol, loginGovCallbackPort)
authMux := goji.SubMux()
root.Handle(pat.New("/auth/*"), authMux)
authMux.Handle(pat.Get("/login-gov"), authentication.RedirectHandler{Context: authContext})
@@ -1191,7 +1198,7 @@ func main() {
}

// Serve index.html to all requests that haven't matches a previous route,
root.HandleFunc(pat.Get("/*"), indexHandler(build, zapLogger))
root.HandleFunc(pat.Get("/*"), indexHandler(build, logger))

var httpHandler http.Handler
if useHoneycomb {
@@ -1206,7 +1213,7 @@ func main() {
Name: "no-tls",
Host: listenInterface,
Port: v.GetInt("no-tls-port"),
Logger: zapLogger,
Logger: logger,
HTTPHandler: httpHandler,
})
if err != nil {
@@ -1218,7 +1225,7 @@ func main() {
Name: "tls",
Host: listenInterface,
Port: v.GetInt("tls-port"),
Logger: zapLogger,
Logger: logger,
HTTPHandler: httpHandler,
ClientAuth: tls.NoClientCert,
Certificates: certificates,
@@ -1232,7 +1239,7 @@ func main() {
Name: "mutual-tls",
Host: listenInterface,
Port: v.GetInt("mutual-tls-port"),
Logger: zapLogger,
Logger: logger,
HTTPHandler: httpHandler,
ClientAuth: tls.RequireAndVerifyClientCert,
Certificates: certificates,
@@ -1322,7 +1329,7 @@ func fileHandler(entrypoint string) http.HandlerFunc {
}

// indexHandler returns a handler that will serve the resulting content
func indexHandler(buildDir string, logger *zap.Logger) http.HandlerFunc {
func indexHandler(buildDir string, logger logger) http.HandlerFunc {

indexPath := path.Join(buildDir, "index.html")
// #nosec - indexPath does not come from user input
Oops, something went wrong.

0 comments on commit fe45ce6

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