vbatts
/
microservices-demo
1
0
Fork 0
Code Issues Pull Requests Releases Wiki Activity

Change log format to JSON and log destination to stdout (#48) 

* log: change log format to JSON payload for better log in Stackdriver

change the log format in Go written service from text payload to
JSON payload using 3rd party logging library (logrus).

https://cloud.google.com/logging/docs/structured-logging
33a1e118e1/json_formatter.go (L40-L49)

Effected services are frontend, productcatalogservice, checkoutservice,
and shippinservice.

Also change target container registry and locust scenario for testing.

* revert kubernetes manifests to point to the original container registry URLs

* revert skaffold.yaml to point to the original registry

* loadgenerator: revert locust settings
This commit is contained in:
Yoshi Yamaguchi 2018-09-26 08:43:17 +09:00 committed by Ahmet Alp Balkan
parent ab601665d1
commit 6460427bee
11 changed files with 163 additions and 50 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

16
src/checkoutservice/Gopkg.lock generated
View File

@ -56,6 +56,14 @@
revision = "317e0006254c44a0ac427cc52a0e083ff0b9622f"
version = "v2.0.0"
[[projects]]
digest = "1:d867dfa6751c8d7a435821ad3b736310c2ed68945d05b50fb9d23aee0540c8cc"
name = "github.com/sirupsen/logrus"
packages = ["."]
pruneopts = "UT"
revision = "3e01752db0189b9157070a0e1668a620f9a85da2"
version = "v1.0.6"
[[projects]]
name = "go.opencensus.io"
packages = [
@ -77,6 +85,14 @@
revision = "b11f239c032624b045c4c2bfd3d1287b4012ce89"
version = "v0.16.0"
[[projects]]
branch = "master"
digest = "1:3f3a05ae0b95893d90b9b3b5afdb79a9b3d96e4e36e099d841ae602e4aca0da8"
name = "golang.org/x/crypto"
packages = ["ssh/terminal"]
pruneopts = "UT"
revision = "0e37d006457bf46f9e6692014ba72ef82c33022c"
[[projects]]
branch = "master"
name = "golang.org/x/net"

4
src/checkoutservice/Gopkg.toml
View File

@ -41,6 +41,10 @@
name = "github.com/google/uuid"
version = "1.0.0"
[[constraint]]
name = "github.com/sirupsen/logrus"
version = "1.0.6"
[[constraint]]
name = "go.opencensus.io"
version = "0.16.0"

53
src/checkoutservice/main.go
View File

@ -17,7 +17,6 @@ package main
import (
"context"
"fmt"
"log"
"net"
"os"
"time"
@ -25,6 +24,7 @@ import (
"cloud.google.com/go/profiler"
"contrib.go.opencensus.io/exporter/stackdriver"
"github.com/google/uuid"
"github.com/sirupsen/logrus"
"go.opencensus.io/plugin/ocgrpc"
"go.opencensus.io/stats/view"
"go.opencensus.io/trace"
@ -42,6 +42,22 @@ const (
usdCurrency = "USD"
)
var log *logrus.Logger
func init() {
log = logrus.New()
log.Level = logrus.DebugLevel
log.Formatter = &logrus.JSONFormatter{
FieldMap: logrus.FieldMap{
logrus.FieldKeyTime: "timestamp",
logrus.FieldKeyLevel: "severity",
logrus.FieldKeyMsg: "message",
},
TimestampFormat: time.RFC3339Nano,
}
log.Out = os.Stdout
}
type checkoutService struct {
productCatalogSvcAddr string
cartSvcAddr string
@ -68,7 +84,7 @@ func main() {
mustMapEnv(&svc.emailSvcAddr, "EMAIL_SERVICE_ADDR")
mustMapEnv(&svc.paymentSvcAddr, "PAYMENT_SERVICE_ADDR")
log.Printf("service config: %+v", svc)
log.Infof("service config: %+v", svc)
lis, err := net.Listen("tcp", fmt.Sprintf(":%s", port))
if err != nil {
@ -77,16 +93,17 @@ func main() {
srv := grpc.NewServer(grpc.StatsHandler(&ocgrpc.ServerHandler{}))
pb.RegisterCheckoutServiceServer(srv, svc)
healthpb.RegisterHealthServer(srv, svc)
log.Printf("starting to listen on tcp: %q", lis.Addr().String())
log.Fatal(srv.Serve(lis))
log.Infof("starting to listen on tcp: %q", lis.Addr().String())
err = srv.Serve(lis)
log.Fatal(err)
}
func initStats(exporter *stackdriver.Exporter) {
view.RegisterExporter(exporter)
if err := view.Register(ocgrpc.DefaultServerViews...); err != nil {
log.Printf("Error registering default server views")
log.Warn("Error registering default server views")
} else {
log.Printf("Registered default server views")
log.Info("Registered default server views")
}
}
@ -96,21 +113,21 @@ func initTracing() {
for i := 1; i <= 3; i++ {
exporter, err := stackdriver.NewExporter(stackdriver.Options{})
if err != nil {
log.Printf("info: failed to initialize stackdriver exporter: %+v", err)
log.Infof("failed to initialize stackdriver exporter: %+v", err)
} else {
trace.RegisterExporter(exporter)
trace.ApplyConfig(trace.Config{DefaultSampler: trace.AlwaysSample()})
log.Print("registered stackdriver tracing")
log.Info("registered stackdriver tracing")
// Register the views to collect server stats.
initStats(exporter)
return
}
d := time.Second * 10 * time.Duration(i)
log.Printf("sleeping %v to retry initializing stackdriver exporter", d)
log.Infof("sleeping %v to retry initializing stackdriver exporter", d)
time.Sleep(d)
}
log.Printf("warning: could not initialize stackdriver exporter after retrying, giving up")
log.Warn("could not initialize stackdriver exporter after retrying, giving up")
}
func initProfiling(service, version string) {
@ -123,16 +140,16 @@ func initProfiling(service, version string) {
// ProjectID must be set if not running on GCP.
// ProjectID: "my-project",
}); err != nil {
log.Printf("warn: failed to start profiler: %+v", err)
log.Warnf("failed to start profiler: %+v", err)
} else {
log.Print("started stackdriver profiler")
log.Info("started stackdriver profiler")
return
}
d := time.Second * 10 * time.Duration(i)
log.Printf("sleeping %v to retry initializing stackdriver profiler", d)
log.Infof("sleeping %v to retry initializing stackdriver profiler", d)
time.Sleep(d)
}
log.Printf("warning: could not initialize stackdriver profiler after retrying, giving up")
log.Warn("could not initialize stackdriver profiler after retrying, giving up")
}
func mustMapEnv(target *string, envKey string) {
@ -148,7 +165,7 @@ func (cs *checkoutService) Check(ctx context.Context, req *healthpb.HealthCheckR
}
func (cs *checkoutService) PlaceOrder(ctx context.Context, req *pb.PlaceOrderRequest) (*pb.PlaceOrderResponse, error) {
log.Printf("[PlaceOrder] user_id=%q user_currency=%q", req.UserId, req.UserCurrency)
log.Infof("[PlaceOrder] user_id=%q user_currency=%q", req.UserId, req.UserCurrency)
orderID, err := uuid.NewUUID()
if err != nil {
@ -172,7 +189,7 @@ func (cs *checkoutService) PlaceOrder(ctx context.Context, req *pb.PlaceOrderReq
if err != nil {
return nil, status.Errorf(codes.Internal, "failed to charge card: %+v", err)
}
log.Printf("payment went through (transaction_id: %s)", txID)
log.Infof("payment went through (transaction_id: %s)", txID)
shippingTrackingID, err := cs.shipOrder(ctx, req.Address, prep.cartItems)
if err != nil {
@ -190,9 +207,9 @@ func (cs *checkoutService) PlaceOrder(ctx context.Context, req *pb.PlaceOrderReq
}
if err := cs.sendOrderConfirmation(ctx, req.Email, orderResult); err != nil {
log.Printf("failed to send order confirmation to %q: %+v", req.Email, err)
log.Warnf("failed to send order confirmation to %q: %+v", req.Email, err)
} else {
log.Printf("order confirmation email sent to %q", req.Email)
log.Infof("order confirmation email sent to %q", req.Email)
}
resp := &pb.PlaceOrderResponse{Order: orderResult}
return resp, nil

10
src/frontend/main.go
View File

@ -83,7 +83,15 @@ func main() {
ctx := context.Background()
log := logrus.New()
log.Level = logrus.DebugLevel
log.Formatter = &logrus.TextFormatter{}
log.Formatter = &logrus.JSONFormatter{
FieldMap: logrus.FieldMap{
logrus.FieldKeyTime: "timestamp",
logrus.FieldKeyLevel: "severity",
logrus.FieldKeyMsg: "message",
},
TimestampFormat: time.RFC3339Nano,
}
log.Out = os.Stdout
go initProfiling(log, "frontend", "1.0.0")
go initTracing(log)

16
src/productcatalogservice/Gopkg.lock generated
View File

@ -62,6 +62,14 @@
revision = "317e0006254c44a0ac427cc52a0e083ff0b9622f"
version = "v2.0.0"
[[projects]]
digest = "1:d867dfa6751c8d7a435821ad3b736310c2ed68945d05b50fb9d23aee0540c8cc"
name = "github.com/sirupsen/logrus"
packages = ["."]
pruneopts = "UT"
revision = "3e01752db0189b9157070a0e1668a620f9a85da2"
version = "v1.0.6"
[[projects]]
name = "go.opencensus.io"
packages = [
@ -83,6 +91,14 @@
revision = "b11f239c032624b045c4c2bfd3d1287b4012ce89"
version = "v0.16.0"
[[projects]]
branch = "master"
digest = "1:3f3a05ae0b95893d90b9b3b5afdb79a9b3d96e4e36e099d841ae602e4aca0da8"
name = "golang.org/x/crypto"
packages = ["ssh/terminal"]
pruneopts = "UT"
revision = "0e37d006457bf46f9e6692014ba72ef82c33022c"
[[projects]]
branch = "master"
name = "golang.org/x/net"

4
src/productcatalogservice/Gopkg.toml
View File

@ -41,6 +41,10 @@
name = "github.com/google/go-cmp"
version = "0.2.0"
[[constraint]]
name = "github.com/sirupsen/logrus"
version = "1.0.6"
[[constraint]]
name = "go.opencensus.io"
version = "0.16.0"

40
src/productcatalogservice/server.go
View File

@ -20,8 +20,8 @@ import (
"flag"
"fmt"
"io/ioutil"
"log"
"net"
"os"
"strings"
"time"
@ -31,6 +31,7 @@ import (
"cloud.google.com/go/profiler"
"contrib.go.opencensus.io/exporter/stackdriver"
"github.com/golang/protobuf/jsonpb"
"github.com/sirupsen/logrus"
"go.opencensus.io/plugin/ocgrpc"
"go.opencensus.io/stats/view"
"go.opencensus.io/trace"
@ -41,6 +42,7 @@ import (
var (
catalogJSON []byte
log *logrus.Logger
port = flag.Int("port", 3550, "port to listen at")
)
@ -51,7 +53,17 @@ func init() {
log.Fatalf("failed to open product catalog json file: %v", err)
}
catalogJSON = c
log.Printf("successfully parsed product catalog json")
log = logrus.New()
log.Formatter = &logrus.JSONFormatter{
FieldMap: logrus.FieldMap{
logrus.FieldKeyTime: "timestamp",
logrus.FieldKeyLevel: "severity",
logrus.FieldKeyMsg: "message",
},
TimestampFormat: time.RFC3339Nano,
}
log.Out = os.Stdout
log.Info("successfully parsed product catalog json")
}
func main() {
@ -59,7 +71,7 @@ func main() {
go initProfiling("productcatalogservice", "1.0.0")
flag.Parse()
log.Printf("starting grpc server at :%d", *port)
log.Infof("starting grpc server at :%d", *port)
run(*port)
select {}
}
@ -80,9 +92,9 @@ func run(port int) string {
func initStats(exporter *stackdriver.Exporter) {
view.RegisterExporter(exporter)
if err := view.Register(ocgrpc.DefaultServerViews...); err != nil {
log.Printf("Error registering default server views")
log.Info("Error registering default server views")
} else {
log.Printf("Registered default server views")
log.Info("Registered default server views")
}
}
@ -92,21 +104,21 @@ func initTracing() {
for i := 1; i <= 3; i++ {
exporter, err := stackdriver.NewExporter(stackdriver.Options{})
if err != nil {
log.Printf("info: failed to initialize stackdriver exporter: %+v", err)
log.Warnf("failed to initialize stackdriver exporter: %+v", err)
} else {
trace.RegisterExporter(exporter)
trace.ApplyConfig(trace.Config{DefaultSampler: trace.AlwaysSample()})
log.Print("registered stackdriver tracing")
log.Info("registered stackdriver tracing")
// Register the views to collect server stats.
initStats(exporter)
return
}
d := time.Second * 10 * time.Duration(i)
log.Printf("sleeping %v to retry initializing stackdriver exporter", d)
log.Infof("sleeping %v to retry initializing stackdriver exporter", d)
time.Sleep(d)
}
log.Printf("warning: could not initialize stackdriver exporter after retrying, giving up")
log.Warn("could not initialize stackdriver exporter after retrying, giving up")
}
func initProfiling(service, version string) {
@ -119,16 +131,16 @@ func initProfiling(service, version string) {
// ProjectID must be set if not running on GCP.
// ProjectID: "my-project",
}); err != nil {
log.Printf("warn: failed to start profiler: %+v", err)
log.Warnf("failed to start profiler: %+v", err)
} else {
log.Print("started stackdriver profiler")
log.Info("started stackdriver profiler")
return
}
d := time.Second * 10 * time.Duration(i)
log.Printf("sleeping %v to retry initializing stackdriver profiler", d)
log.Infof("sleeping %v to retry initializing stackdriver profiler", d)
time.Sleep(d)
}
log.Printf("warning: could not initialize stackdriver profiler after retrying, giving up")
log.Warn("could not initialize stackdriver profiler after retrying, giving up")
}
type productCatalog struct{}
@ -137,7 +149,7 @@ func parseCatalog() []*pb.Product {
var cat pb.ListProductsResponse
if err := jsonpb.Unmarshal(bytes.NewReader(catalogJSON), &cat); err != nil {
log.Printf("warning: failed to parse the catalog JSON: %v", err)
log.Warnf("failed to parse the catalog JSON: %v", err)
return nil
}
return cat.Products

16
src/shippingservice/Gopkg.lock generated
View File

@ -50,6 +50,14 @@
revision = "317e0006254c44a0ac427cc52a0e083ff0b9622f"
version = "v2.0.0"
[[projects]]
digest = "1:d867dfa6751c8d7a435821ad3b736310c2ed68945d05b50fb9d23aee0540c8cc"
name = "github.com/sirupsen/logrus"
packages = ["."]
pruneopts = "UT"
revision = "3e01752db0189b9157070a0e1668a620f9a85da2"
version = "v1.0.6"
[[projects]]
name = "go.opencensus.io"
packages = [
@ -71,6 +79,14 @@
revision = "b11f239c032624b045c4c2bfd3d1287b4012ce89"
version = "v0.16.0"
[[projects]]
branch = "master"
digest = "1:3f3a05ae0b95893d90b9b3b5afdb79a9b3d96e4e36e099d841ae602e4aca0da8"
name = "golang.org/x/crypto"
packages = ["ssh/terminal"]
pruneopts = "UT"
revision = "0e37d006457bf46f9e6692014ba72ef82c33022c"
[[projects]]
branch = "master"
name = "golang.org/x/net"

4
src/shippingservice/Gopkg.toml
View File

@ -37,6 +37,10 @@
name = "github.com/golang/protobuf"
version = "1.2.0"
[[constraint]]
name = "github.com/sirupsen/logrus"
version = "1.0.6"
[[constraint]]
name = "go.opencensus.io"
version = "0.16.0"

48
src/shippingservice/main.go
View File

@ -16,13 +16,13 @@ package main
import (
"fmt"
"log"
"net"
"os"
"time"
"cloud.google.com/go/profiler"
"contrib.go.opencensus.io/exporter/stackdriver"
"github.com/sirupsen/logrus"
"go.opencensus.io/plugin/ocgrpc"
"go.opencensus.io/stats/view"
"go.opencensus.io/trace"
@ -38,6 +38,22 @@ const (
defaultPort = "50051"
)
var log *logrus.Logger
func init() {
log = logrus.New()
log.Level = logrus.DebugLevel
log.Formatter = &logrus.JSONFormatter{
FieldMap: logrus.FieldMap{
logrus.FieldKeyTime: "timestamp",
logrus.FieldKeyLevel: "severity",
logrus.FieldKeyMsg: "message",
},
TimestampFormat: time.RFC3339Nano,
}
log.Out = os.Stdout
}
func main() {
go initTracing()
go initProfiling("shippingservice", "1.0.0")
@ -56,7 +72,7 @@ func main() {
svc := &server{}
pb.RegisterShippingServiceServer(srv, svc)
healthpb.RegisterHealthServer(srv, svc)
log.Printf("Shipping Service listening on port %s", port)
log.Infof("Shipping Service listening on port %s", port)
// Register reflection service on gRPC server.
reflection.Register(srv)
@ -75,8 +91,8 @@ func (s *server) Check(ctx context.Context, req *healthpb.HealthCheckRequest) (*
// GetQuote produces a shipping quote (cost) in USD.
func (s *server) GetQuote(ctx context.Context, in *pb.GetQuoteRequest) (*pb.GetQuoteResponse, error) {
log.Printf("[GetQuote] received request")
defer log.Printf("[GetQuote] completed request")
log.Info("[GetQuote] received request")
defer log.Info("[GetQuote] completed request")
// 1. Our quote system requires the total number of items to be shipped.
count := 0
@ -100,8 +116,8 @@ func (s *server) GetQuote(ctx context.Context, in *pb.GetQuoteRequest) (*pb.GetQ
// ShipOrder mocks that the requested items will be shipped.
// It supplies a tracking ID for notional lookup of shipment delivery status.
func (s *server) ShipOrder(ctx context.Context, in *pb.ShipOrderRequest) (*pb.ShipOrderResponse, error) {
log.Printf("[ShipOrder] received request")
defer log.Printf("[ShipOrder] completed request")
log.Info("[ShipOrder] received request")
defer log.Info("[ShipOrder] completed request")
// 1. Create a Tracking ID
baseAddress := fmt.Sprintf("%s, %s, %s", in.Address.StreetAddress, in.Address.City, in.Address.State)
id := CreateTrackingId(baseAddress)
@ -115,9 +131,9 @@ func (s *server) ShipOrder(ctx context.Context, in *pb.ShipOrderRequest) (*pb.Sh
func initStats(exporter *stackdriver.Exporter) {
view.RegisterExporter(exporter)
if err := view.Register(ocgrpc.DefaultServerViews...); err != nil {
log.Printf("Error registering default server views")
log.Warn("Error registering default server views")
} else {
log.Printf("Registered default server views")
log.Info("Registered default server views")
}
}
@ -127,21 +143,21 @@ func initTracing() {
for i := 1; i <= 3; i++ {
exporter, err := stackdriver.NewExporter(stackdriver.Options{})
if err != nil {
log.Printf("info: failed to initialize stackdriver exporter: %+v", err)
log.Warnf("failed to initialize stackdriver exporter: %+v", err)
} else {
trace.RegisterExporter(exporter)
trace.ApplyConfig(trace.Config{DefaultSampler: trace.AlwaysSample()})
log.Print("registered stackdriver tracing")
log.Info("registered stackdriver tracing")
// Register the views to collect server stats.
initStats(exporter)
return
}
d := time.Second * 10 * time.Duration(i)
log.Printf("sleeping %v to retry initializing stackdriver exporter", d)
log.Infof("sleeping %v to retry initializing stackdriver exporter", d)
time.Sleep(d)
}
log.Printf("warning: could not initialize stackdriver exporter after retrying, giving up")
log.Warn("could not initialize stackdriver exporter after retrying, giving up")
}
func initProfiling(service, version string) {
@ -154,14 +170,14 @@ func initProfiling(service, version string) {
// ProjectID must be set if not running on GCP.
// ProjectID: "my-project",
}); err != nil {
log.Printf("warn: failed to start profiler: %+v", err)
log.Warnf("failed to start profiler: %+v", err)
} else {
log.Print("started stackdriver profiler")
log.Info("started stackdriver profiler")
return
}
d := time.Second * 10 * time.Duration(i)
log.Printf("sleeping %v to retry initializing stackdriver profiler", d)
log.Infof("sleeping %v to retry initializing stackdriver profiler", d)
time.Sleep(d)
}
log.Printf("warning: could not initialize stackdriver profiler after retrying, giving up")
log.Warn("could not initialize stackdriver profiler after retrying, giving up")
}

2
src/shippingservice/quote.go
View File

@ -50,6 +50,6 @@ func quoteByCountFloat(count int) float64 {
return 0
}
count64 := float64(count)
var p float64 = 1 + (count64 * 0.2)
var p = 1 + (count64 * 0.2)
return count64 + math.Pow(3, p)
}