Essayez d'implémenter le journal structuré gRPC facilement et simplement avec grpc_zap

introduction

Nous avons adopté le gRPC au sein de l'équipe et procédons au développement, Il existe encore peu d'articles en japonais, notamment des articles détaillés sur l'implémentation des logs. C'était difficile à trouver et il fallait du temps pour recueillir des informations. .. Par conséquent, j'aimerais partager des informations avec l'équipe et écrire un article en plus de mon mémorandum.

Cette fois, lors du développement d'un serveur gRPC en langage Go, La sortie de journal à grande vitesse est possible et est intégrée à grpc-middleware Implémentons un journal structuré simple et simple en utilisant grpc_zap. De plus, cet article n'aborde pas les grandes lignes et le mécanisme du gRPC.

Qu'est-ce que grpc_zap?

Uber peut utiliser zapLogger fourni par OSS et l'incorporer dans gRPC C'est un paquet intégré dans grpc-middleware comme l'un des intercepteurs. Les journaux structurés Zap sont faciles à implémenter et peuvent être combinés avec grpc_ctxtags Vous pouvez ajouter librement des champs.

Échantillon et environnement d'exploitation

Sample est disponible sur le référentiel GitHub. Je vais expliquer sur la base de cet exemple.

L'environnement d'exploitation est confirmé ci-dessous.

OS: macOS Catalina 10.15.4 @ 2.7GHz 2Core, 16GB
Docker Desktop: 2.3.0.5(48029), Engine:19.03.12

Exigences

Cette fois, considérons un serveur gRPC qui peut obtenir des informations sur les étudiants lors d'une demande. gRPC utilise «Protocol Buffer (protobuf)» comme IDL commun aux serveurs et aux clients. Étant donné que de nombreuses implémentations ont été utilisées, protobuf est également utilisé dans cet article.

proto/sample.proto


package sample;

service Student {
    //Obtenir des informations sur les étudiants
    rpc Get (StudentRequest) returns (StudentResponse) {}
}

message StudentRequest {
    int32 id = 1;       //Carte d'étudiant que vous souhaitez obtenir
}

message StudentResponse {
    int32 id = 1;       //Carte d'étudiant
    string name = 2;    //Nom
    int32 age = 3;      //âge
    School school = 4;  //École affiliée
}

message School {
    int32 id = 1;       //ID de l'école
    string name = 2;    //nom de l'école
    string grade = 3;   //Année scolaire
}

Si vous demandez avec une carte d'étudiant, vous pouvez obtenir l'étudiant et son école / note comme réponse. Je suppose un simple serveur gRPC.

la mise en oeuvre

Le premier est le fichier main.go.

main.go


package main

import (
	"log"
	"net"

	"google.golang.org/grpc"
	"google.golang.org/grpc/codes"
	"google.golang.org/grpc/reflection"
	grpc_middleware "github.com/grpc-ecosystem/go-grpc-middleware"
	grpc_zap "github.com/grpc-ecosystem/go-grpc-middleware/logging/zap"
	grpc_ctxtags "github.com/grpc-ecosystem/go-grpc-middleware/tags"
	"go.uber.org/zap"
	"go.uber.org/zap/zapcore"

	sv "github.com/y-harashima/grpc-sample/server"
	pb "github.com/y-harashima/grpc-sample/proto"
)

func main() {

	port, err := net.Listen("tcp", ":50051")
	if err != nil {
		log.Fatal(err)
	}
        
    //zap logger et paramètres d'options
	zap, _ := zap.NewProduction()     // --- ①
	zap_opt := grpc_zap.WithLevels(          // --- ②
		func(c codes.Code) zapcore.Level {   
			var l zapcore.Level              
			switch c {                       
			case codes.OK:                   
				l = zapcore.InfoLevel        
				                             
			case codes.Internal:             
				l = zapcore.ErrorLevel       

			default:
				l = zapcore.DebugLevel
			}
			return l
		},
	)
    //Configurer Interceptor et initialiser le serveur gRPC
	grpc := grpc.NewServer(    // --- ③
		grpc_middleware.WithUnaryServerChain(    
			grpc_ctxtags.UnaryServerInterceptor(),   
			grpc_zap.UnaryServerInterceptor(zap, zap_opt),
		),
	)
	
	server := &sv.Server{}
	pb.RegisterStudentServer(grpc, server)
	reflection.Register(grpc)
	log.Println("Server process starting...")
	if err := grpc.Serve(port); err != nil {
		log.Fatal(err)
	}
}

Je voudrais expliquer un par un.


zap, _ := zap.NewProduction()

Tout d'abord, initialisez le zap Logger. Vous en aurez besoin lors de son intégration dans grpc_zap. Ici, il s'agit de NewProduction (), mais par souci de clarté lors de la sortie du journal Il est sorti sous forme de journal structuré comprenant le niveau de journal. (Il existe également une fonction d'initialisation appelée NewDevelopment (), Il semble que le niveau de journalisation n'est pas inclus dans JSON et est affiché ici)


    zap_opt := grpc_zap.WithLevels(
        func(c codes.Code) zapcore.Level {   
            var l zapcore.Level              
            switch c {                       
            case codes.OK:                   
                l = zapcore.InfoLevel        

            case codes.Internal:             
                l = zapcore.ErrorLevel       

            default:
                l = zapcore.DebugLevel
            }
            return l
        },
    )

grpc_zap définit le niveau de journalisation correspondant au code d'état Il est relativement facile de définir une option. Si vous définissez le niveau de journalisation que vous souhaitez distribuer à codes.Code de grpc comme dans l'exemple d'implémentation, Au niveau de journal correspondant, spécifiez simplement le code d'état lors de l'implémentation de la réponse Il sortira.


	grpc := grpc.NewServer(
		grpc_middleware.WithUnaryServerChain(    
			grpc_ctxtags.UnaryServerInterceptor(),   
			grpc_zap.UnaryServerInterceptor(zap, zap_opt),
		),
	)

Intégrez Interceptor lors de l'initialisation du serveur gRPC. S'il n'y a qu'un seul intercepteur à intégrer, utilisez WithUnaryServerChain Il n'a pas besoin d'être assemblé, mais cette fois je veux ajouter des champs arbitraires au journal structuré, donc Utilisez WithUnaryServerChain pour intégrer grpc_ctxtags et grpc_zap.

Ensuite, regardons le fichier server.go, qui est la partie réponse.

server/server.go


package server

import (
	"context"

	"google.golang.org/grpc/codes"
	"google.golang.org/grpc/status"
	grpc_ctxtags "github.com/grpc-ecosystem/go-grpc-middleware/tags"
	pb "github.com/y-harashima/grpc-sample/proto"
)

type Server struct{}

func (s *Server) Get(ctx context.Context, req *pb.StudentRequest) (*pb.StudentResponse, error) {
	if req.Id == 1 {
		res := &pb.StudentResponse{
			Id: 1,
			Name: "Taro",
			Age: 11,
			School: &pb.School{
				Id: 1,
				Name: "ABC school",
				Grade: "5th",
			},
		}
        //Définir les champs à enregistrer
		log := map[string]interface{}{  // --- ②
			"name": res.Name, 
			"age": res.Age, 
			"school_name": res.School.Name,
			"school_grade": res.School.Grade,
		}
		grpc_ctxtags.Extract(ctx).Set("data", log)
		return res, nil
	} else {
		grpc_ctxtags.Extract(ctx).Set("request_id", req.Id) // --- ①
		return nil, status.Errorf(codes.Internal, "No students found.") // --- ③
	}
}

Pour l'unité de traitement, lorsque l'ID demandé est 1, les informations de «Taro» sont renvoyées. C'est une réponse simple. L'ordre de l'explication n'est pas le même que le flux de code, mais je vais l'expliquer étape par étape.


		grpc_ctxtags.Extract(ctx).Set("request_id", req.Id)

Vous pouvez utiliser grpc_ctxtags pour ajouter un champ au journal de contexte. En ajoutant Set (key, value) au contexte passé en argument Il peut être placé sur la sortie de grpc_zap.


		log := map[string]interface{}{
			"name": res.Name, 
			"age": res.Age, 
			"school_name": res.School.Name,
			"school_grade": res.School.Grade,
		}
		grpc_ctxtags.Extract(ctx).Set("data", log)
		return res, nil

Puisque la valeur à définir est prise en charge par le type interface {}, elle peut également être prise en charge par map. Si la valeur à passer est map [string] interface {}, le nom et la valeur de la clé seront structurés respectivement, donc Il est également possible d'imbriquer et de sortir. Dans le cas d'une réponse normale, en traitant de la même manière que le gRPC normal, Le grpc_zap intégré en tant qu'intercepteur produira un journal structuré. C'est très facile et simple car vous pouvez obtenir un journal structuré sans configuration compliquée.


		return nil, status.Errorf(codes.Internal, "No students found.")

Même si vous renvoyez le traitement avec une erreur, implémentez simplement le traitement des erreurs tel quel Il peut être généré sous forme de journal de réponse, mais si vous utilisez le package gRPC status Il est possible de gérer l'erreur en spécifiant le code d'état. En combinant avec l'option grpc_zap définie dans main.go Il est émis au niveau du journal qui correspond au code d'état. Dans l'exemple ci-dessus, il sera affiché sous forme de journal «Niveau d'erreur».

tester

Faisons un test post-implémentation. Dans l'exemple, main.go est exécuté avec docker-compose.

grpc-sample/


docker-compose up -d --build

Le test de fonctionnement de gRPC est effectué par [gRPCurl](https://github.com/fullstorydev/grpcurl), [evans](https://github.com/ktr0731/evans), etc. Cette fois, nous utiliserons gRPCurl.

shell


grpcurl -plaintext -d '{"id": 1}' localhost:50051 sample.Student.Get
{
  "id": 1,
  "name": "Taro",
  "age": 11,
  "school": {
    "id": 1,
    "name": "ABC school",
    "grade": "5th"
  }
} 

shell


grpcurl -plaintext -d '{"id": 2}' localhost:50051 sample.Student.Get
ERROR:
  Code: Internal
  Message: No students found.

Il a été confirmé que si l'ID est 1, un traitement normal se produit, sinon une erreur se produit. En cas d'erreur, il est affiché comme spécifié par code.Internal. Vérifions le journal de sortie.

docker-logs(OK)


{
  "level":"info",
  "ts":1602527196.8505046,
  "caller":"zap/options.go:203",
  "msg":"finished unary call with code OK",
  "grpc.start_time":"2020-10-12T18:26:36Z", 
  "system":"grpc",
  "span.kind":"server",
  "grpc.service":"sample.Student",
  "grpc.method":"Get",
  "peer.address":"192.168.208.1:54062",
  "data":{
    "age":11,
    "name":"Taro",
    "school_grade":"5th",
    "school_name":"ABC school"
  },
  "grpc.code":"OK",
  "grpc.time_ms":0.03400000184774399
}

docker-log(Error)


{
  "level":"error",
  "ts":1602651069.7882483,
  "caller":"zap/options.go:203",
  "msg":"finished unary call with code Internal",
  "grpc.start_time":"2020-10-14T04:51:09Z",
  "system":"grpc",
  "span.kind":"server",
  "grpc.service":"sample.Student",
  "grpc.method":"Get",
  "peer.address":"192.168.208.1:54066",
  "request_id":2,
  "error":"rpc error: code = Internal desc = No students found.",
  "grpc.code":"Internal",
  "grpc.time_ms":1.3320000171661377,
  "stacktrace":"github.com/grpc-ecosystem/go-grpc-middleware/logging/zap.DefaultMessageProducer\n\t/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/logging/zap/options.go:203\ngithub.com/grpc-ecosystem/go-grpc-middleware/logging/zap.UnaryServerInterceptor.func1\n\t/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/logging/zap/server_interceptors.go:39\ngithub.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryServer.func1.1.1\n\t/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/chain.go:25\ngithub.com/grpc-ecosystem/go-grpc-middleware/tags.UnaryServerInterceptor.func1\n\t/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/tags/interceptors.go:23\ngithub.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryServer.func1.1.1\n\t/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/chain.go:25\ngithub.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryServer.func1\n\t/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/chain.go:34\ngithub.com/y-harashima/grpc-sample/proto._Student_Get_Handler\n\t/app/proto/sample.pb.go:389\ngoogle.golang.org/grpc.(*Server).processUnaryRPC\n\t/go/pkg/mod/google.golang.org/[email protected]/server.go:1210\ngoogle.golang.org/grpc.(*Server).handleStream\n\t/go/pkg/mod/google.golang.org/[email protected]/server.go:1533\ngoogle.golang.org/grpc.(*Server).serveStreams.func1.2\n\t/go/pkg/mod/google.golang.org/[email protected]/server.go:871"
}

(Ce qui précède est formaté avec des sauts de ligne et des retraits pour plus de lisibilité)

Vous pouvez voir que le journal au format JSON est généré. De plus, en utilisant grpc_ctxtags, les champs suivants ont été ajoutés.

docker-logs(OK, extrait)


  "data":{
    "age":11,
    "name":"Taro",
    "school_grade":"5th",
    "school_name":"ABC school"
  },

docker-logs(Erreur, extrait)


  "request_id":2,

Site de référence

Enfin, c'est un site de référence.

Sommaire

En utilisant grpc_zap, nous avons pu facilement et simplement incorporer zapLogger dans gRPC. De plus, vous pouvez ajouter des champs avec grpc_ctxtags et définir le niveau de journalisation avec Option. Je pense que c'est relativement facile à mettre en œuvre et flexible à personnaliser. Je pense qu'il est facile de concevoir un journal, alors veuillez l'utiliser. Soulignant ・ Un partage tel que "Il y a aussi un tel usage!" Est le bienvenu.

Recommended Posts

Essayez d'implémenter le journal structuré gRPC facilement et simplement avec grpc_zap
Essayons gRPC avec Go et Docker
Essayez d'utiliser l'API Twitter rapidement et facilement avec Python
Essayez d'implémenter RBM avec chainer.
Essayez d'implémenter XOR avec PyTorch
Essayez d'implémenter le parfum avec Go
Processus d'authentification avec gRPC et authentification Firebase
Communiquez entre Elixir et Python avec gRPC
Essayez d'implémenter XOR avec l'API fonctionnelle Keras
Essayez facilement la génération automatique d'images avec DCGAN-tensor flow
Téléchargez facilement des mp3 / mp4 avec python et youtube-dl!
Gérez les journaux structurés avec GCP Cloud Logging
Essayez d'implémenter Yuma avec Brainf * ck 512 lignes (générer et exécuter du code avec Python)