Merge branch 'master' into gRPC-endpoints

Makefile

@@ -17,6 +17,13 @@ backend_build:
 	docker exec -it postgres createdb --username=root --owner=root df
 	docker run --name migrateup --rm --privileged=true -v $(PWD)/bff/db/migration:/migrations --network host migrate/migrate -path=/migrations/ -database $(DB_URL) up
 
+rebuild:
+	docker stop df-bff_api_1
+	docker stop df-bff_postgres_1
+	docker rm df-bff_api_1
+	docker rmi df-bff_api
+	make backend
+
 backend:
 	docker-compose -f ./bff/docker-compose.yaml -p df-bff up -d
 
@@ -95,4 +102,4 @@ evans:
 count_lines:
 	cloc --exclude-dir=.history,.git .
 
-.PHONY: postgres migratenew createdb dropdb migrateup migratedown sqlc sqlcinit test server backend_build backend backend-stop reset_docker proto evans count_lines
+.PHONY: reset_docker backend_build rebuild backend backend dev network postgres migratenew migrateup migratedown createdb dropdb sqlc sqlcinit test coverage server mock proto evans count_lines

bff/gapi/logger.go

@@ -0,0 +1,99 @@
+package gapi
+
+import (
+	"context"
+	"log/slog"
+	"net/http"
+	"time"
+
+	"google.golang.org/grpc"
+	"google.golang.org/grpc/codes"
+	"google.golang.org/grpc/status"
+)
+
+func GrpcLogger(
+	ctx context.Context,
+	req interface{},
+	info *grpc.UnaryServerInfo,
+	handler grpc.UnaryHandler,
+) (resp interface{}, err error) {
+	startTime := time.Now()
+	result, err := handler(ctx, req)
+	duration := time.Since(startTime)
+
+	statusCode := codes.Unknown
+	if st, ok := status.FromError(err); ok {
+		statusCode = st.Code()
+	}
+
+	if err != nil {
+		slog.Error("received a gRPC request",
+			slog.String("protocol", "grpc"),
+			slog.String("endpoint", info.FullMethod),
+			slog.Int("status_code", int(statusCode)),
+			slog.String("status_text", statusCode.String()),
+			slog.Duration("duration", duration),
+			slog.String("error", err.Error()),
+		)
+	} else {
+		slog.Info("received a gRPC request",
+			slog.String("protocol", "grpc"),
+			slog.String("endpoint", info.FullMethod),
+			slog.Int("status_code", int(statusCode)),
+			slog.String("status_text", statusCode.String()),
+			slog.Duration("duration", duration),
+		)
+	}
+
+	return result, err
+}
+
+type ResponseRecorder struct {
+	http.ResponseWriter
+	StatusCode int
+	Body       []byte
+}
+
+func (rec *ResponseRecorder) WriteHeader(statusCode int) {
+	rec.StatusCode = statusCode
+	rec.ResponseWriter.WriteHeader(statusCode)
+}
+
+func (rec *ResponseRecorder) Write(body []byte) (int, error) {
+	rec.Body = body
+	return rec.ResponseWriter.Write(body)
+}
+
+func HttpLogger(handler http.Handler) http.Handler {
+	return http.HandlerFunc(func(res http.ResponseWriter, req *http.Request) {
+		startTime := time.Now()
+		rec := &ResponseRecorder{
+			ResponseWriter: res,
+			StatusCode:     http.StatusOK,
+		}
+
+		handler.ServeHTTP(rec, req)
+		duration := time.Since(startTime)
+
+		if rec.StatusCode != http.StatusOK {
+			slog.Error("received a HTTP request",
+				slog.String("protocol", "http"),
+				slog.String("method", req.Method),
+				slog.String("endpoint", req.RequestURI),
+				slog.Int("status_code", rec.StatusCode),
+				slog.String("status_text", http.StatusText(rec.StatusCode)),
+				slog.Duration("duration", duration),
+				slog.String("body", string(rec.Body)),
+			)
+		} else {
+			slog.Info("received a HTTP request",
+				slog.String("protocol", "http"),
+				slog.String("method", req.Method),
+				slog.String("endpoint", req.RequestURI),
+				slog.Int("status_code", rec.StatusCode),
+				slog.String("status_text", http.StatusText(rec.StatusCode)),
+				slog.Duration("duration", duration),
+			)
+		}
+	})
+}

bff/gapi/server.go

@@ -2,6 +2,8 @@ package gapi
 
 import (
 	"fmt"
+	"log/slog"
+	"os"
 
 	db "github.com/itsscb/df/bff/db/sqlc"
 	"github.com/itsscb/df/bff/pb"
@@ -29,5 +31,21 @@ func NewServer(config util.Config, store db.Store) (*Server, error) {
 		tokenMaker: tokenMaker,
 	}
 
+	logLevel := slog.LevelError
+	if config.Environment == "development" {
+		logLevel = slog.LevelDebug
+	}
+
+	opts := slog.HandlerOptions{
+		Level: logLevel,
+	}
+	logger := slog.New(slog.NewTextHandler(os.Stdout, &opts))
+
+	if config.LogOutput == "json" {
+		logger = slog.New(slog.NewJSONHandler(os.Stdout, &opts))
+	}
+
+	slog.SetDefault(logger)
+
 	return server, nil
 }

bff/go.mod

@@ -60,6 +60,7 @@ require (
 	golang.org/x/net v0.15.0 // indirect
 	golang.org/x/sys v0.12.0 // indirect
 	golang.org/x/text v0.13.0 // indirect
+	golang.org/x/tools v0.13.0 // indirect
 	google.golang.org/genproto v0.0.0-20230803162519-f966b187b2e5 // indirect
 	gopkg.in/ini.v1 v1.67.0 // indirect
 	gopkg.in/yaml.v3 v3.0.1 // indirect

bff/go.sum

@@ -330,8 +330,8 @@ golang.org/x/mod v0.2.0/go.mod h1:s0Qsj1ACt9ePp/hMypM3fl4fZqREWJwdYDEqhRiZZUA=
 golang.org/x/mod v0.3.0/go.mod h1:s0Qsj1ACt9ePp/hMypM3fl4fZqREWJwdYDEqhRiZZUA=
 golang.org/x/mod v0.4.0/go.mod h1:s0Qsj1ACt9ePp/hMypM3fl4fZqREWJwdYDEqhRiZZUA=
 golang.org/x/mod v0.4.1/go.mod h1:s0Qsj1ACt9ePp/hMypM3fl4fZqREWJwdYDEqhRiZZUA=
-golang.org/x/mod v0.11.0 h1:bUO06HqtnRcc/7l71XBe4WcqTZ+3AH1J59zWDDwLKgU=
+golang.org/x/mod v0.12.0 h1:rmsUpXtvNzj340zd98LZ4KntptpfRHwpFOHG188oHXc=
-golang.org/x/mod v0.11.0/go.mod h1:iBbtSCu2XBx23ZKBPSOrRkjjQPZFPuis4dIYUhu/chs=
+golang.org/x/mod v0.12.0/go.mod h1:iBbtSCu2XBx23ZKBPSOrRkjjQPZFPuis4dIYUhu/chs=
 golang.org/x/net v0.0.0-20180724234803-3673e40ba225/go.mod h1:mL1N/T3taQHkDXs73rZJwtUhF3w3ftmwwsq0BUmARs4=
 golang.org/x/net v0.0.0-20180826012351-8a410e7b638d/go.mod h1:mL1N/T3taQHkDXs73rZJwtUhF3w3ftmwwsq0BUmARs4=
 golang.org/x/net v0.0.0-20190108225652-1e06a53dbb7e/go.mod h1:mL1N/T3taQHkDXs73rZJwtUhF3w3ftmwwsq0BUmARs4=
@@ -486,8 +486,8 @@ golang.org/x/tools v0.0.0-20201208233053-a543418bbed2/go.mod h1:emZCQorbCU4vsT4f
 golang.org/x/tools v0.0.0-20210105154028-b0ab187a4818/go.mod h1:emZCQorbCU4vsT4fOWvOPXz4eW1wZW4PmDk9uLelYpA=
 golang.org/x/tools v0.0.0-20210108195828-e2f9c7f1fc8e/go.mod h1:emZCQorbCU4vsT4fOWvOPXz4eW1wZW4PmDk9uLelYpA=
 golang.org/x/tools v0.1.0/go.mod h1:xkSsbof2nBLbhDlRMhhhyNLN/zl3eTqcnHD5viDpcZ0=
-golang.org/x/tools v0.9.1 h1:8WMNJAz3zrtPmnYC7ISf5dEn3MT0gY7jBJfw27yrrLo=
+golang.org/x/tools v0.13.0 h1:Iey4qkscZuv0VvIt8E0neZjtPVQFSc870HQ448QgEmQ=
-golang.org/x/tools v0.9.1/go.mod h1:owI94Op576fPu3cIGQeHs3joujW/2Oc6MtlxbF5dfNc=
+golang.org/x/tools v0.13.0/go.mod h1:HvlwmtVNQAhOuCjW7xxvovg8wbNq7LwfXh/k7wXUl58=
 golang.org/x/xerrors v0.0.0-20190717185122-a985d3407aa7/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0=
 golang.org/x/xerrors v0.0.0-20191011141410-1b5146add898/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0=
 golang.org/x/xerrors v0.0.0-20191204190536-9bdfabe68543/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0=

bff/main.go

@@ -6,6 +6,7 @@ import (
 	"embed"
 	"io/fs"
 	"log"
+	"log/slog"
 	"net"
 	"net/http"
 	"time"
@@ -59,12 +60,12 @@ func main() {
 func runDBMigration(migrationURL string, dbSource string, retries int) {
 	migration, err := migrate.New(migrationURL, dbSource)
 	if err != nil {
-		log.Printf("could not create migrate instance. Retrying %d more times...\n", retries)
+		slog.Warn("could not migrate db instance. Retrying...")
 
 		count := 1
 		var e error
-		for _ = range time.Tick(3 * time.Second) {
+		for range time.Tick(3 * time.Second) {
-			log.Printf("retry: %d/%d\n", count, retries)
+			slog.Info("migrate db", slog.Int("retry number", count), slog.Int("max retries", retries))
 			migration, e = migrate.New(migrationURL, dbSource)
 			if e == nil || count >= retries {
 				break
@@ -80,7 +81,7 @@ func runDBMigration(migrationURL string, dbSource string, retries int) {
 		log.Fatal("failed to run migrate up")
 	}
 
-	log.Println("db migrated successfully")
+	slog.Info("db migrated successfully")
 }
 
 func runGRPCServer(config util.Config, store db.Store) {
@@ -89,7 +90,8 @@ func runGRPCServer(config util.Config, store db.Store) {
 		log.Fatalf("could not start server: %s", err)
 	}
 
-	grpcServer := grpc.NewServer()
+	grpcLogger := grpc.UnaryInterceptor(gapi.GrpcLogger)
+	grpcServer := grpc.NewServer(grpcLogger)
 	pb.RegisterDfServer(grpcServer, server)
 	reflection.Register(grpcServer)
 
@@ -98,7 +100,8 @@ func runGRPCServer(config util.Config, store db.Store) {
 		log.Fatal("cannot create gRPC server:", err)
 	}
 
-	log.Printf("start gRPC server at %s", listener.Addr().String())
+	slog.Info("start gRPC server", slog.String("address", listener.Addr().String()))
+
 	err = grpcServer.Serve(listener)
 	if err != nil {
 		log.Fatal("cannot start gRPC server:", err)
@@ -142,8 +145,9 @@ func runGatewayServer(config util.Config, store db.Store, swaggerFS http.FileSys
 		log.Fatal("cannot create listener")
 	}
 
-	log.Printf("start HTTP gateway server at %s\n", listener.Addr().String())
+	slog.Info("start HTTP gateway server", slog.String("address", listener.Addr().String()))
-	err = http.Serve(listener, mux)
+	handler := gapi.HttpLogger(mux)
+	err = http.Serve(listener, handler)
 	if err != nil {
 		log.Fatal("cannot start HTTP gateway server")
 	}