Merge pull request #637 from isucon/less-log

ログの出力を抑制

bench/benchmarker/scenario/scenario.go

@@ -2,6 +2,7 @@ package scenario
 
 import (
 	"context"
+	"fmt"
 	"log/slog"
 	"net/http"
 	"sync"
@@ -264,7 +265,16 @@ LOOP:
 			}
 
 			if s.world.Time%world.LengthOfHour == 0 {
-				slog.Debug("仮想世界の時間が60分経過", slog.Int64("time", s.world.Time), slog.Int("timeout", s.world.TimeoutTickCount))
+				if num := s.world.NotInvitedUserCount.Load(); num > 0 {
+					s.contestantLogger.Info(fmt.Sprintf("これまでに地域内の評判によって%d人が新規登録しました", num))
+				}
+				if num := s.world.InvitedUserCount.Load(); num > 0 {
+					s.contestantLogger.Info(fmt.Sprintf("これまでに既存ユーザーの招待経由で%d人が新規登録しました", num))
+				}
+				if num := s.world.LeavedUserCount.Load(); num > 0 {
+					s.contestantLogger.Warn(fmt.Sprintf("これまでに低評価なライドによって%d人が利用をやめました", num))
+				}
+				slog.Debug("時間経過", slog.Int64("tick", s.world.Time))
 			}
 		}
 	}

bench/benchmarker/world/world.go

@@ -62,6 +62,13 @@ type World struct {
 
 	// TimeoutTickCount タイムアウトしたTickの累計数
 	TimeoutTickCount int
+
+	// LeavedUserCount 離脱したユーザーの数
+	LeavedUserCount atomic.Int32
+	// InvitedUserCount 招待されたユーザーの数
+	InvitedUserCount atomic.Int32
+	// NotInvitedUserCount 招待されずに登録したユーザーの数
+	NotInvitedUserCount atomic.Int32
 }
 
 func NewWorld(tickTimeout time.Duration, completedRequestChan chan *Request, client WorldClient, contestantLogger *slog.Logger) *World {
@@ -94,15 +101,16 @@ func (w *World) Tick(ctx *Context) error {
 		for _, region := range w.Regions {
 			increase := int(math.Round(w.userIncrease * (float64(region.UserSatisfactionScore()) / 5)))
 			if increase > 0 {
-				w.contestantLogger.Info("地域内の評判を元にユーザーが増加します", slog.String("region", region.Name), slog.Int("increase", increase))
 				for range increase {
 					w.waitingTickCount.Add(1)
 					go func() {
 						defer w.waitingTickCount.Add(-1)
 						_, err := w.CreateUser(ctx, &CreateUserArgs{Region: region})
 						if err != nil {
 							w.handleTickError(err)
+							return
 						}
+						w.NotInvitedUserCount.Add(1)
 					}()
 				}
 			}
@@ -413,15 +421,16 @@ func (w *World) PublishEvent(e Event) {
 		w.CompletedRequestChan <- data.Request
 		go func() {
 			if data.Request.CalculateEvaluation().Score() > 2 && data.Request.User.InvCodeUsedCount < 3 {
-				w.contestantLogger.Info("既存ユーザーからの招待によってユーザーが増加します", slog.String("region", data.Request.User.Region.Name))
 				_, err := w.CreateUser(nil, &CreateUserArgs{Region: data.Request.User.Region, Inviter: data.Request.User})
 				if err != nil {
 					w.handleTickError(err)
+					return
 				}
+				w.InvitedUserCount.Add(1)
 			}
 		}()
 	case *EventUserLeave:
-		w.contestantLogger.Warn("ライドの評価が悪かったためユーザーが離脱しました")
+		w.LeavedUserCount.Add(1)
 	case *EventSoftError:
 		w.handleTickError(data.Error)
 	}

bench/payment/handler.go

@@ -86,7 +86,7 @@ func (s *Server) PostPaymentsHandler(w http.ResponseWriter, r *http.Request) {
 
 	// キューが詰まっていても確率で成功させる
 	if rand.IntN(5) == 0 {
-		slog.Debug("決済キューが詰まったが、確率で成功させる")
+		slog.Debug("決済が詰まったが成功")
 
 		go s.queue.process(p)
 		<-p.processChan
@@ -110,9 +110,9 @@ func (s *Server) PostPaymentsHandler(w http.ResponseWriter, r *http.Request) {
 			<-p.processChan
 			p.locked.Store(false)
 		}()
-		slog.Debug("決済キューが詰まったが、キューに積んでエラーを返す")
+		slog.Debug("決済が詰まったが、キューに積んでエラー")
 	} else {
-		slog.Debug("決済キューが詰まって、キューに積まずにエラーを返す")
+		slog.Debug("決済が詰まってエラー")
 	}
 
 	// 不安定なエラーを再現