Merge pull request #219 from ueckoken/use-slog

backend/state-manager/cmd/main.go

@@ -2,20 +2,70 @@ package main
 
 import (
 	"context"
-	"log"
+	"log/slog"
+	"net"
+	"net/http"
 	"os"
 	"os/signal"
+	"time"
 
+	"github.com/go-chi/chi/v5"
+	"github.com/go-chi/chi/v5/middleware"
+	"github.com/go-chi/httplog/v2"
 	"github.com/joho/godotenv"
+	"github.com/ueckoken/plarail2023/backend/spec/state/v1/statev1connect"
 	connectHandler "github.com/ueckoken/plarail2023/backend/state-manager/pkg/connect"
 	"github.com/ueckoken/plarail2023/backend/state-manager/pkg/mqtt_handler"
+	"golang.org/x/net/http2"
+	"golang.org/x/net/http2/h2c"
 	"golang.org/x/sync/errgroup"
 )
 
+type AppEnv uint
+
+const (
+	Dev AppEnv = iota
+	Test
+	Prod
+)
+
+var appEnv AppEnv = Dev
+var (
+	version = "develop"
+	commit  = "deadbeef"
+)
+
+func init() {
+	switch os.Getenv("APP_ENV") {
+	case "prod":
+		appEnv = Prod
+	case "test":
+		appEnv = Test
+	default:
+		appEnv = Dev
+	}
+	logger := func(appEnv AppEnv) *slog.Logger {
+		switch appEnv {
+		case Prod:
+			return slog.New(slog.NewJSONHandler(os.Stderr, &slog.HandlerOptions{
+				Level:     slog.LevelDebug,
+				AddSource: true,
+			}))
+		default:
+			return slog.New(slog.NewTextHandler(os.Stderr, &slog.HandlerOptions{
+				Level:     slog.LevelDebug,
+				AddSource: true,
+			}))
+		}
+	}(appEnv)
+	logger = logger.With("version", version).With("commit", commit).With("app_env", appEnv)
+	slog.SetDefault(logger)
+}
+
 func main() {
 	err := godotenv.Load(".env")
 	if err != nil {
-		panic(err)
+		slog.Default().Error("Error loading .env file")
 	}
 	baseCtx, cancel := context.WithCancel(context.Background())
 	defer cancel()
@@ -24,21 +74,52 @@ func main() {
 
 	go func() {
 		<-ctx.Done()
-		log.Println("signal received")
+		slog.Default().Info("signal received")
 	}()
 
 	eg, ctx := errgroup.WithContext(ctx)
-	eg.Go(func() error {
-		log.Println("start connect server")
-		return connectHandler.StartHandler(ctx)
-	})
+
+	r := chi.NewRouter()
+	// r.Use(middleware.Recoverer)
+	r.Use(middleware.Heartbeat("/debug/ping"))
+	r.Mount("/debug", middleware.Profiler())
+	r.Handle(statev1connect.NewStateManagerServiceHandler(&connectHandler.StateManagerServer{}))
+	r.Use(httplog.RequestLogger(
+		httplog.NewLogger(
+			"http_server",
+			httplog.Options{
+				JSON:           appEnv == Prod,
+				Concise:        false,
+				RequestHeaders: true,
+				Writer:         os.Stdout,
+				Tags: map[string]string{
+					"version": version,
+					"commit":  commit,
+				},
+				LogLevel: slog.LevelInfo,
+			},
+		),
+	),
+	)
+
+	srv := &http.Server{
+		Addr:              net.JoinHostPort("0.0.0.0", "8080"),
+		Handler:           h2c.NewHandler(r, &http2.Server{}),
+		ReadHeaderTimeout: 60 * time.Second,
+		BaseContext:       func(net.Listener) context.Context { return ctx },
+	}
+	eg.Go(srv.ListenAndServe)
 	//go operation.Handler()
 	eg.Go(func() error {
-		log.Println("start mqtt handler")
+		slog.Default().Info("start mqtt handler")
 		return mqtt_handler.StartHandler(ctx)
 	})
 
 	if err := eg.Wait(); err != nil {
-		log.Fatalln("error in sub goroutine at main: ", err)
+		slog.Default().Error("error in sub goroutine at main", err)
 	}
+	newCtx, srvTimeOutCancel := context.WithTimeout(context.Background(), 3*time.Second)
+	defer srvTimeOutCancel()
+	srv.Shutdown(newCtx)
+  <-newCtx.Done()
 }

backend/state-manager/pkg/connect/connect_handler.go

@@ -3,21 +3,13 @@ package connect_handler
 import (
 	"context"
 	"errors"
-	"fmt"
-	"log"
-	"net"
-	"net/http"
-	"time"
+	"log/slog"
 
 	"connectrpc.com/connect"
-	"github.com/go-chi/chi/v5"
-	"github.com/go-chi/chi/v5/middleware"
+
 	statev1 "github.com/ueckoken/plarail2023/backend/spec/state/v1"
-	"github.com/ueckoken/plarail2023/backend/spec/state/v1/statev1connect"
 	db "github.com/ueckoken/plarail2023/backend/state-manager/pkg/db"
 	"github.com/ueckoken/plarail2023/backend/state-manager/pkg/mqtt_handler"
-	"golang.org/x/net/http2"
-	"golang.org/x/net/http2/h2c"
 )
 
 type StateManagerServer struct{}
@@ -93,12 +85,12 @@ func (s *StateManagerServer) UpdatePointState(
 			connect.CodeUnknown,
 			errors.New("db error"),
 		)
-		log.Println(err)
+		slog.Default().Error("db error", err)
 		return nil, err
 	}
 	mqtt_handler.NotifyStateUpdate("point", req.Msg.State.Id, req.Msg.State.State.String())
-	res := connect.NewResponse(&statev1.UpdatePointStateResponse{})
-	return res, nil
+
+	return connect.NewResponse(&statev1.UpdatePointStateResponse{}), nil
 }
 
 func (s *StateManagerServer) GetPointStates(
@@ -120,19 +112,19 @@ func (s *StateManagerServer) UpdateStopState(
 	ctx context.Context,
 	req *connect.Request[statev1.UpdateStopStateRequest],
 ) (*connect.Response[statev1.UpdateStopStateResponse], error) {
-	defer db.C()
 	db.Open()
+	defer db.C()
 	err := db.UpdateStop(req.Msg.State)
 	if err != nil {
 		err = connect.NewError(
 			connect.CodeUnknown,
 			errors.New("db error"),
 		)
+		slog.Default().Error("db connection error", err)
 		return nil, err
 	}
-	res := connect.NewResponse(&statev1.UpdateStopStateResponse{})
 	mqtt_handler.NotifyStateUpdate("stop", req.Msg.State.Id, req.Msg.State.State.String())
-	return res, nil
+	return connect.NewResponse(&statev1.UpdateStopStateResponse{}), nil
 }
 
 func (s *StateManagerServer) GetStopStates(
@@ -171,36 +163,3 @@ func (s *StateManagerServer) UpdateTrainUUID(
 	)
 	return nil, err
 }
-
-func StartHandler(ctx context.Context) error {
-	r := chi.NewRouter()
-	r.Use(middleware.Recoverer)
-	r.Use(middleware.Heartbeat("/debug/ping"))
-	// TODO: slogとかでいい感じにログを吐くハンドラを入れる
-
-	r.Mount("/debug", middleware.Profiler())
-	r.Handle(statev1connect.NewStateManagerServiceHandler(&StateManagerServer{}))
-
-	srv := &http.Server{
-		Addr:              net.JoinHostPort("0.0.0.0", "8080"),
-		Handler:           h2c.NewHandler(r, &http2.Server{}),
-		ReadHeaderTimeout: 60 * time.Second,
-		BaseContext:       func(net.Listener) context.Context { return ctx },
-	}
-	errC := make(chan error)
-	go func() {
-		err := srv.ListenAndServe()
-		errC <- err
-	}()
-	for {
-		select {
-		case <-ctx.Done():
-			newCtx, cancel := context.WithTimeout(context.Background(), 3*time.Second)
-			defer cancel()
-			return srv.Shutdown(newCtx)
-
-		case err := <-errC:
-			return fmt.Errorf("failed to start http server: %w", err)
-		}
-	}
-}

backend/state-manager/pkg/db/db.go

@@ -7,6 +7,7 @@ package db
 import (
 	"context"
 	"log"
+	"log/slog"
 	"os"
 
 	statev1 "github.com/ueckoken/plarail2023/backend/spec/state/v1"
@@ -21,24 +22,29 @@ var client *mongo.Client
 
 func Open() {
 	var err error
-	//log.Println("Connecting to MongoDB...")
+	slog.Default().Debug("Connecting to MongoDB...")
 	uri := os.Getenv("MONGODB_URI")
 	if uri == "" {
 		log.Fatal("No MONGODB_URI set")
 	}
+	// TODO: Open関数がctxを受けるようにして、そのctxの子contextをDBのコネクションに使う
 	client, err = mongo.Connect(context.TODO(), options.Client().ApplyURI(uri))
 	if err != nil {
+		// TODO: return err, do not panic!
+		slog.Default().Error("database connection failed", slog.Any("err", err))
 		panic(err)
 	}
-	//log.Println("Connected to DB!")
+	slog.Default().Debug("connected to DB")
 }
 
 func C() {
-	//log.Println("Closing connection to DB...")
+	slog.Default().Debug("Closing connection to DB...")
+	// TODO: contextを受けて、その子contextをDBクライアントに渡す
 	if err := client.Disconnect(context.TODO()); err != nil {
+		slog.Default().Error("DB Connection Closing failed")
 		log.Println(err)
 	}
-	//log.Println("Connection closed!")
+	slog.Default().Debug("DB Connection is successfully closed")
 }
 
 /*
@@ -81,6 +87,7 @@ func GetPoints() []*statev1.PointAndState {
 	collection := client.Database("state-manager").Collection("points")
 	cursor, err := collection.Find(context.Background(), bson.M{})
 	if err != nil {
+		slog.Default().Warn("Get Points failed", slog.Any("err", err))
 		panic(err)
 	}
 	var result []*statev1.PointAndState

go.mod

@@ -6,6 +6,7 @@ require (
 	connectrpc.com/connect v1.12.0
 	github.com/eclipse/paho.mqtt.golang v1.4.3
 	github.com/go-chi/chi/v5 v5.0.10
+	github.com/go-chi/httplog/v2 v2.0.7
 	github.com/joho/godotenv v1.5.1
 	go.mongodb.org/mongo-driver v1.13.0
 	golang.org/x/net v0.18.0
@@ -50,6 +51,7 @@ require (
 	golang.org/x/term v0.14.0 // indirect
 	golang.org/x/text v0.14.0 // indirect
 	golang.org/x/time v0.3.0 // indirect
+	golang.org/x/tools v0.15.0 // indirect
 	google.golang.org/appengine v1.6.7 // indirect
 	gopkg.in/inf.v0 v0.9.1 // indirect
 	gopkg.in/yaml.v2 v2.4.0 // indirect

go.sum

@@ -10,6 +10,8 @@ github.com/emicklei/go-restful/v3 v3.9.0 h1:XwGDlfxEnQZzuopoqxwSEllNcCOM9DhhFyhF
 github.com/emicklei/go-restful/v3 v3.9.0/go.mod h1:6n3XBCmQQb25CM2LCACGz8ukIrRry+4bhvbpWn3mrbc=
 github.com/go-chi/chi/v5 v5.0.10 h1:rLz5avzKpjqxrYwXNfmjkrYYXOyLJd37pz53UFHC6vk=
 github.com/go-chi/chi/v5 v5.0.10/go.mod h1:DslCQbL2OYiznFReuXYUmQ2hGd1aDpCnlMNITLSKoi8=
+github.com/go-chi/httplog/v2 v2.0.7 h1:2vQTW3HWftsR3mVoUkv9taDFkswxn8S4hC+6VNefKdU=
+github.com/go-chi/httplog/v2 v2.0.7/go.mod h1:/XXdxicJsp4BA5fapgIC3VuTD+z0Z/VzukoB3VDc1YE=
 github.com/go-logr/logr v1.2.0/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A=
 github.com/go-logr/logr v1.2.4 h1:g01GSCwiDw2xSZfjJ2/T9M+S6pFdcNtFYsp+Y43HYDQ=
 github.com/go-logr/logr v1.2.4/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A=
@@ -130,8 +132,6 @@ golang.org/x/sync v0.0.0-20190423024810-112230192c58/go.mod h1:RxMgew5VJxzue5/jJ
 golang.org/x/sync v0.0.0-20190911185100-cd5d95a43a6e/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM=
 golang.org/x/sync v0.0.0-20201020160332-67f06af15bc9/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM=
 golang.org/x/sync v0.0.0-20220722155255-886fb9371eb4/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM=
-golang.org/x/sync v0.1.0 h1:wsuoTGHzEhffawBOhz5CYhcrV4IdKZbEyZjBMuTp12o=
-golang.org/x/sync v0.1.0/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM=
 golang.org/x/sync v0.5.0 h1:60k92dhOjHxJkrqnwsfl8KuaHbn/5dl0lUPUklKo3qE=
 golang.org/x/sync v0.5.0/go.mod h1:Czt+wKu1gCyEFDUtn0jG5QVvpJ6rzVqr5aXyt9drQfk=
 golang.org/x/sys v0.0.0-20190215142949-d0b11bdaac8a/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY=
@@ -164,8 +164,8 @@ golang.org/x/tools v0.0.0-20191119224855-298f0cb1881e/go.mod h1:b+2E5dAYhXwXZwtn
 golang.org/x/tools v0.0.0-20200619180055-7c47624df98f/go.mod h1:EkVYQZoAsY45+roYkvgYkIh4xh/qjgUK9TdY2XT94GE=
 golang.org/x/tools v0.0.0-20210106214847-113979e3529a/go.mod h1:emZCQorbCU4vsT4fOWvOPXz4eW1wZW4PmDk9uLelYpA=
 golang.org/x/tools v0.1.12/go.mod h1:hNGJHUnrk76NpqgfD5Aqm5Crs+Hm0VOH/i9J2+nxYbc=
-golang.org/x/tools v0.8.0 h1:vSDcovVPld282ceKgDimkRSC8kpaH1dgyc9UMzlt84Y=
-golang.org/x/tools v0.8.0/go.mod h1:JxBZ99ISMI5ViVkT1tr6tdNmXeTrcpVSD3vZ1RsRdN4=
+golang.org/x/tools v0.15.0 h1:zdAyfUGbYmuVokhzVmghFl2ZJh5QhcfebBgmVPFYA+8=
+golang.org/x/tools v0.15.0/go.mod h1:hpksKq4dtpQWS1uQ61JkdqWM3LscIS6Slf+VVkm+wQk=
 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=