From 21e7a693b5a630f602913a9a3c918c8e364ffe1d Mon Sep 17 00:00:00 2001
From: Rafael da Fonseca <rafael.fonseca@wildlifestudios.com>
Date: Tue, 6 Aug 2024 14:58:41 +0100
Subject: [PATCH] Improve connection error logs (#417)

* Improve connection error logs
* Use docker compose 2.x
---
 Makefile                     | 12 ++++++------
 README.md                    |  2 +-
 examples/demo/chat/README.md |  2 +-
 pkg/service/handler.go       |  7 ++++++-
 pkg/service/handler_test.go  |  6 ++++--
 5 files changed, 18 insertions(+), 11 deletions(-)

diff --git a/Makefile b/Makefile
index 1e16ac3e..3b651fc9 100644
--- a/Makefile
+++ b/Makefile
@@ -37,11 +37,11 @@ setup-protobuf-macos:
 	@go install github.com/golang/protobuf/protoc-gen-go@latest
 
 run-jaeger-aio:
-	@docker-compose -f ./examples/testing/docker-compose-jaeger.yml up -d
+	@docker compose -f ./examples/testing/docker-compose-jaeger.yml up -d
 	@echo "Access jaeger UI @ http://localhost:16686"
 
 run-chat-example:
-	@cd examples/testing && docker-compose up -d etcd nats && cd ../demo/chat/ && go run main.go
+	@cd examples/testing && docker compose up -d etcd nats && cd ../demo/chat/ && go run main.go
 
 run-cluster-example-frontend-tracing:
 	@PITAYA_METRICS_PROMETHEUS_PORT=9090 OTEL_SDK_DISABLED=false OTEL_SERVICE_NAME=example-frontend OTEL_EXPORTER_OTLP_ENDPOINT=http://localhost:4317 OTEL_EXPORTER_OTLP_PROTOCOL=grpc OTEL_TRACES_SAMPLER=parentbased_traceidratio OTEL_TRACES_SAMPLER_ARG="1" go run examples/demo/cluster/main.go
@@ -98,16 +98,16 @@ ensure-testing-bin:
 	@[ -f ./examples/testing/server ] || go build -o ./examples/testing/server ./examples/testing/main.go
 
 ensure-testing-deps:
-	@cd ./examples/testing && docker-compose up -d
+	@cd ./examples/testing && docker compose up -d
 
 ensure-e2e-deps-grpc:
-	@cd ./examples/testing && docker-compose up -d etcd
+	@cd ./examples/testing && docker compose up -d etcd
 
 kill-testing-deps:
-	@cd ./examples/testing && docker-compose down; true
+	@cd ./examples/testing && docker compose down; true
 
 kill-jaeger:
-	@docker-compose -f ./examples/testing/docker-compose-jaeger.yml down; true
+	@docker compose -f ./examples/testing/docker-compose-jaeger.yml down; true
 
 e2e-test: e2e-test-nats e2e-test-grpc
 
diff --git a/README.md b/README.md
index 83e0a15c..67b3659f 100644
--- a/README.md
+++ b/README.md
@@ -43,7 +43,7 @@ Here's one example of running Pitaya:
 
 Start etcd (This command requires docker-compose and will run an etcd container locally. An etcd may be run without docker if preferred.)
 ```
-cd ./examples/testing && docker-compose up -d etcd
+cd ./examples/testing && docker compose up -d etcd
 ```
 run the connector frontend server from cluster_grpc example
 ```
diff --git a/examples/demo/chat/README.md b/examples/demo/chat/README.md
index 8a4238fb..c564a381 100644
--- a/examples/demo/chat/README.md
+++ b/examples/demo/chat/README.md
@@ -9,7 +9,7 @@ refs: https://github.com/topfreegames/pitaya
 
 ## Run
 ```
-docker-compose -f ../../testing/docker-compose.yml up -d etcd nats
+docker compose -f ../../testing/docker-compose.yml up -d etcd nats
 go run main.go
 ```
 
diff --git a/pkg/service/handler.go b/pkg/service/handler.go
index 1553dd52..d3155864 100644
--- a/pkg/service/handler.go
+++ b/pkg/service/handler.go
@@ -189,7 +189,12 @@ func (h *HandlerService) Handle(conn acceptor.PlayerConn) {
 			} else if err == constants.ErrConnectionClosed {
 				logger.Log.Debugf("Connection no longer available while reading next available message: %s", err.Error())
 			} else {
-				logger.Log.Errorf("Error reading next available message: %s", err.Error())
+				// Differentiate errors for valid sessions, to avoid noise from load balancer healthchecks and other internet noise
+				if a.GetStatus() != constants.StatusStart {
+					logger.Log.Errorf("Error reading next available message for UID: %s, Build: %s, error: %s", a.GetSession().UID(), "a.GetSession().GetHandshakeData().Sys.BuildNumber", err.Error())
+				} else {
+					logger.Log.Debugf("Error reading next available message on initial connection: %s", err.Error())
+				}
 			}
 
 			return
diff --git a/pkg/service/handler_test.go b/pkg/service/handler_test.go
index 322170d3..a80e9984 100644
--- a/pkg/service/handler_test.go
+++ b/pkg/service/handler_test.go
@@ -418,16 +418,18 @@ func TestHandlerServiceHandle(t *testing.T) {
 	mockAgent.EXPECT().SendHandshakeResponse().Return(nil)
 
 	mockSession := mocks.NewMockSession(ctrl)
+	mockSession.EXPECT().GetHandshakeData().Return(&session.HandshakeData{Sys: session.HandshakeClientData{BuildNumber: "10"}}).AnyTimes()
 	mockSession.EXPECT().SetHandshakeData(gomock.Any()).Times(1)
 	mockSession.EXPECT().ValidateHandshake(gomock.Any()).Times(1)
-	mockSession.EXPECT().UID().Return("uid").Times(1)
+	mockSession.EXPECT().UID().Return("uid").AnyTimes()
 	mockSession.EXPECT().ID().Return(int64(1)).Times(2)
 	mockSession.EXPECT().Set(constants.IPVersionKey, constants.IPv4)
 	mockSession.EXPECT().Close()
 
 	mockAgent.EXPECT().String().Return("")
+	mockAgent.EXPECT().GetStatus().AnyTimes()
 	mockAgent.EXPECT().SetStatus(constants.StatusHandshake)
-	mockAgent.EXPECT().GetSession().Return(mockSession).Times(7)
+	mockAgent.EXPECT().GetSession().Return(mockSession).AnyTimes()
 	mockAgent.EXPECT().IPVersion().Return(constants.IPv4)
 	mockAgent.EXPECT().RemoteAddr().Return(&mockAddr{}).AnyTimes()
 	mockAgent.EXPECT().SetLastAt().Do(func() {