From 046807d940cd6573e770d860eaa46d4158b8c816 Mon Sep 17 00:00:00 2001
From: Sergey Yakubov <sergey.yakubov@desy.de>
Date: Fri, 26 Nov 2021 12:55:45 +0100
Subject: [PATCH] updated logs for fts and discovery

---
 .../src/asapo_discovery/server/get_version.go |  3 +-
 .../src/asapo_discovery/server/routes.go      |  8 +-
 .../src/asapo_discovery/server/routes_test.go | 25 +++---
 .../asapo_file_transfer/server/transfer.go    | 88 ++++++++++---------
 4 files changed, 65 insertions(+), 59 deletions(-)

diff --git a/discovery/src/asapo_discovery/server/get_version.go b/discovery/src/asapo_discovery/server/get_version.go
index 7c1127df3..655b7052b 100644
--- a/discovery/src/asapo_discovery/server/get_version.go
+++ b/discovery/src/asapo_discovery/server/get_version.go
@@ -27,10 +27,11 @@ func extractProtocol(r *http.Request) (string, error) {
 }
 
 func routeGetVersion(w http.ResponseWriter, r *http.Request) {
-	log_str := "processing get version"
+	log_str := "processing get version request"
 	logger.Debug(log_str)
 
 	if ok := checkDiscoveryApiVersion(w, r); !ok {
+		logger.Debug("checkDiscoveryApiVersion failed")
 		return
 	}
 	keys := r.URL.Query()
diff --git a/discovery/src/asapo_discovery/server/routes.go b/discovery/src/asapo_discovery/server/routes.go
index 2e0b31972..9cbc5b920 100644
--- a/discovery/src/asapo_discovery/server/routes.go
+++ b/discovery/src/asapo_discovery/server/routes.go
@@ -15,12 +15,15 @@ func getService(service string) (answer []byte, code int) {
 		answer, err = requestHandler.GetSingleService(service)
 
 	}
-	log_str := "processing get " + service
+	log_str := "processing get " + service + " request"
 	if err != nil {
 		logger.Error(log_str + " - " + err.Error())
 		return []byte(err.Error()), http.StatusInternalServerError
 	}
-	logger.Debug(log_str + " -  got " + string(answer))
+	logger.WithFields(map[string]interface{}{
+		"service": service,
+		"answer":  string(answer),
+	}).Debug("processing get service request")
 	return answer, http.StatusOK
 }
 
@@ -39,7 +42,6 @@ func validateProtocol(w http.ResponseWriter, r *http.Request, client string) boo
 		logger.Error(log_str + " - " + hint)
 		return false
 	}
-	logger.Debug(log_str + " - ok")
 	return true
 }
 
diff --git a/discovery/src/asapo_discovery/server/routes_test.go b/discovery/src/asapo_discovery/server/routes_test.go
index 394a26250..98db36704 100644
--- a/discovery/src/asapo_discovery/server/routes_test.go
+++ b/discovery/src/asapo_discovery/server/routes_test.go
@@ -1,17 +1,17 @@
 package server
 
 import (
+	"asapo_common/logger"
+	"asapo_common/utils"
 	"asapo_common/version"
+	"asapo_discovery/common"
+	"asapo_discovery/request_handler"
 	"github.com/stretchr/testify/mock"
 	"github.com/stretchr/testify/suite"
-	"asapo_common/logger"
-	"asapo_common/utils"
 	"net/http"
 	"net/http/httptest"
 	"strings"
 	"testing"
-	"asapo_discovery/request_handler"
-	"asapo_discovery/common"
 )
 
 func containsMatcher(substr string) func(str string) bool {
@@ -74,8 +74,8 @@ var receiverTests = []requestTest {
 func (suite *GetServicesTestSuite) TestGetReceivers() {
 	for _,test:= range receiverTests {
 		if test.code == http.StatusOK {
-			logger.MockLog.On("Debug", mock.MatchedBy(containsMatcher("validating producer")))
-			logger.MockLog.On("Debug", mock.MatchedBy(containsMatcher("processing get "+common.NameReceiverService)))
+			logger.MockLog.On("WithFields", mock.Anything)
+			logger.MockLog.On("Debug", mock.MatchedBy(containsMatcher("request")))
 		} else {
 			logger.MockLog.On("Error", mock.MatchedBy(containsMatcher("validating producer")))
 		}
@@ -99,8 +99,8 @@ var brokerTests = []requestTest {
 func (suite *GetServicesTestSuite) TestGetBroker() {
 	for _,test:= range brokerTests {
 		if test.code == http.StatusOK {
-			logger.MockLog.On("Debug", mock.MatchedBy(containsMatcher("validating consumer")))
-			logger.MockLog.On("Debug", mock.MatchedBy(containsMatcher("processing get "+common.NameBrokerService)))
+			logger.MockLog.On("WithFields", mock.Anything)
+			logger.MockLog.On("Debug", mock.MatchedBy(containsMatcher("request")))
 		} else {
 			logger.MockLog.On("Error", mock.MatchedBy(containsMatcher("validating consumer")))
 		}
@@ -117,7 +117,8 @@ func (suite *GetServicesTestSuite) TestGetBroker() {
 
 
 func (suite *GetServicesTestSuite) TestGetMongo() {
-	logger.MockLog.On("Debug", mock.MatchedBy(containsMatcher("processing get "+common.NameMongoService)))
+	logger.MockLog.On("WithFields", mock.Anything)
+	logger.MockLog.On("Debug", mock.MatchedBy(containsMatcher("request")))
 
 	w := doRequest("/asapo-mongodb")
 
@@ -127,8 +128,8 @@ func (suite *GetServicesTestSuite) TestGetMongo() {
 }
 
 func (suite *GetServicesTestSuite) TestGetFts() {
-	logger.MockLog.On("Debug", mock.MatchedBy(containsMatcher("processing get "+common.NameFtsService)))
-	logger.MockLog.On("Debug", mock.MatchedBy(containsMatcher("validating")))
+	logger.MockLog.On("WithFields", mock.Anything)
+	logger.MockLog.On("Debug", mock.MatchedBy(containsMatcher("request")))
 
 	w := doRequest("/" + version.GetDiscoveryApiVersion()+"/asapo-file-transfer?protocol=v0.1")
 
@@ -138,7 +139,7 @@ func (suite *GetServicesTestSuite) TestGetFts() {
 }
 
 func (suite *GetServicesTestSuite) TestGetVersions() {
-	logger.MockLog.On("Debug", mock.MatchedBy(containsMatcher("processing get version")))
+	logger.MockLog.On("Debug", mock.MatchedBy(containsMatcher("request")))
 
 	w := doRequest("/" + version.GetDiscoveryApiVersion() + "/version")
 
diff --git a/file_transfer/src/asapo_file_transfer/server/transfer.go b/file_transfer/src/asapo_file_transfer/server/transfer.go
index 2e0cfb927..9dffe4b13 100644
--- a/file_transfer/src/asapo_file_transfer/server/transfer.go
+++ b/file_transfer/src/asapo_file_transfer/server/transfer.go
@@ -11,10 +11,8 @@ import (
 	"os"
 	"path"
 	"path/filepath"
-	"strconv"
 )
 
-
 type fileTransferRequest struct {
 	Folder   string
 	FileName string
@@ -23,109 +21,113 @@ type fileTransferRequest struct {
 func Exists(name string) bool {
 	f, err := os.Open(name)
 	defer f.Close()
-	return err==nil
+	return err == nil
 }
 
-func checkClaim(r *http.Request,ver utils.VersionNum,request* fileTransferRequest) (int,error) {
+func checkClaim(r *http.Request, ver utils.VersionNum, request *fileTransferRequest) (int, error) {
 	var extraClaim structs.FolderTokenTokenExtraClaim
 	if err := utils.JobClaimFromContext(r, nil, &extraClaim); err != nil {
-		return http.StatusInternalServerError,err
+		return http.StatusInternalServerError, err
 	}
 	if ver.Id > 1 {
 		request.Folder = extraClaim.RootFolder
-		return http.StatusOK,nil
+		return http.StatusOK, nil
 	}
 
-	if extraClaim.RootFolder!=request.Folder {
-		err_txt := "access forbidden for folder "+request.Folder
-		log.Error("cannot transfer file: "+err_txt)
+	if extraClaim.RootFolder != request.Folder {
+		err_txt := "access forbidden for folder " + request.Folder
+		log.Error("cannot transfer file: " + err_txt)
 		return http.StatusUnauthorized, errors.New(err_txt)
 	}
-	return http.StatusOK,nil
+	return http.StatusOK, nil
 }
 
-func checkFileExists(r *http.Request,name string) (int,error) {
+func checkFileExists(r *http.Request, name string) (int, error) {
 	if !Exists(name) {
-		err_txt := "file "+name+" does not exist or cannot be read"
-		log.Error("cannot transfer file: "+err_txt)
-		return http.StatusNotFound,errors.New(err_txt)
+		err_txt := "file " + name + " does not exist or cannot be read"
+		log.Error("cannot transfer file: " + err_txt)
+		return http.StatusNotFound, errors.New(err_txt)
 	}
-	return http.StatusOK,nil
+	return http.StatusOK, nil
 
 }
 
-func checkRequest(r *http.Request, ver utils.VersionNum) (string,int,error) {
+func checkRequest(r *http.Request, ver utils.VersionNum) (string, int, error) {
 	var request fileTransferRequest
-	err := utils.ExtractRequest(r,&request)
+	err := utils.ExtractRequest(r, &request)
 	if err != nil {
-		return "",http.StatusBadRequest,err
+		return "", http.StatusBadRequest, err
 	}
 
-	if status,err := checkClaim(r,ver, &request); err != nil {
-		return "",status,err
+	if status, err := checkClaim(r, ver, &request); err != nil {
+		return "", status, err
 	}
 	var fullName string
 	if ver.Id == 1 { // protocol v0.1
-		fullName = filepath.Clean(request.Folder+string(os.PathSeparator)+request.FileName)
+		fullName = filepath.Clean(request.Folder + string(os.PathSeparator) + request.FileName)
 	} else {
-		fullName = filepath.Clean(request.Folder+string(os.PathSeparator)+request.FileName)
+		fullName = filepath.Clean(request.Folder + string(os.PathSeparator) + request.FileName)
 	}
 
-	if status,err := checkFileExists(r,fullName); err != nil {
-		return "",status,err
+	if status, err := checkFileExists(r, fullName); err != nil {
+		return "", status, err
 	}
-	return fullName,http.StatusOK,nil
+	return fullName, http.StatusOK, nil
 }
 
 func serveFile(w http.ResponseWriter, r *http.Request, fullName string) {
 	_, file := path.Split(fullName)
 	w.Header().Set("Content-Disposition", "attachment; filename=\""+file+"\"")
-	log.Debug("Transferring file " + fullName)
-	http.ServeFile(w,r, fullName)
+
+	log.WithFields(map[string]interface{}{
+		"name": fullName,
+	}).Debug("transferring file")
+
+	http.ServeFile(w, r, fullName)
 }
 
 func serveFileSize(w http.ResponseWriter, r *http.Request, fullName string) {
 	var fsize struct {
-		FileSize int64  `json:"file_size"`
+		FileSize int64 `json:"file_size"`
 	}
 
 	fi, err := os.Stat(fullName)
 	if err != nil {
-		utils.WriteServerError(w,err,http.StatusBadRequest)
-		log.Error("Error getting file size for " + fullName+": "+err.Error())
+		utils.WriteServerError(w, err, http.StatusBadRequest)
+		log.Error("error getting file size for " + fullName + ": " + err.Error())
 	}
-	log.Debug("Sending file size "+strconv.FormatInt(fi.Size(),10)+" for " + fullName)
+
+	log.WithFields(map[string]interface{}{
+		"name": fullName,
+		"size": fi.Size(),
+	}).Debug("sending file size")
 
 	fsize.FileSize = fi.Size()
-	b,_ := json.Marshal(&fsize)
+	b, _ := json.Marshal(&fsize)
 	w.Write(b)
 }
 
-
-func checkFtsApiVersion(w http.ResponseWriter, r *http.Request) (utils.VersionNum,bool) {
+func checkFtsApiVersion(w http.ResponseWriter, r *http.Request) (utils.VersionNum, bool) {
 	return utils.PrecheckApiVersion(w, r, version.GetFtsApiVersion())
 }
 
 func routeFileTransfer(w http.ResponseWriter, r *http.Request) {
-	ver, ok := checkFtsApiVersion(w, r);
+	ver, ok := checkFtsApiVersion(w, r)
 	if !ok {
 		return
 	}
 
-	fullName, status,err := checkRequest(r,ver);
+	fullName, status, err := checkRequest(r, ver)
 	if err != nil {
-		utils.WriteServerError(w,err,status)
+		utils.WriteServerError(w, err, status)
 		return
 	}
 
 	sizeonly := r.URL.Query().Get("sizeonly")
- 	if (sizeonly != "true") {
-		serveFile(w,r,fullName)
+	if sizeonly != "true" {
+		serveFile(w, r, fullName)
 	} else {
-		serveFileSize(w,r,fullName)
+		serveFileSize(w, r, fullName)
 	}
 
-
-
-
 }
-- 
GitLab