...

Source file src/golang.conradwood.net/go-easyops/server/unary_interceptor.go

Documentation: golang.conradwood.net/go-easyops/server

     1  package server
     2  
     3  import (
     4  	"context"
     5  	"fmt"
     6  
     7  	//	fw "golang.conradwood.net/apis/framework"
     8  	ge "golang.conradwood.net/apis/goeasyops"
     9  	"golang.conradwood.net/go-easyops/auth"
    10  	"golang.conradwood.net/go-easyops/cmdline"
    11  	"golang.conradwood.net/go-easyops/ctx"
    12  	"golang.conradwood.net/go-easyops/ctx/shared"
    13  	"golang.conradwood.net/go-easyops/errors"
    14  	pp "golang.conradwood.net/go-easyops/profiling"
    15  	"golang.conradwood.net/go-easyops/prometheus"
    16  	"google.golang.org/grpc"
    17  
    18  	//	"google.golang.org/grpc/metadata"
    19  	"flag"
    20  	"time"
    21  
    22  	"google.golang.org/grpc/status"
    23  )
    24  
    25  var (
    26  	print_errs = flag.Bool("ge_grpc_print_errors", false, "if true print grpc errors before they propagate to the caller")
    27  )
    28  
    29  /*******************************************************************************************
    30  * gRPC calls this interceptor for each call. Be fast and reliable
    31  *******************************************************************************************/
    32  
    33  // we authenticate a client here
    34  func (sd *serverDef) UnaryAuthInterceptor(in_ctx context.Context, req interface{}, info *grpc.UnaryServerInfo, handler grpc.UnaryHandler) (interface{}, error) {
    35  	pp.ServerRpcEntered()
    36  	defer pp.ServerRpcDone()
    37  	startRPC()
    38  	defer stopRPC()
    39  	cs := &rpccall{
    40  		ServiceName: ServiceNameFromUnaryInfo(info),
    41  		MethodName:  MethodNameFromUnaryInfo(info),
    42  		Started:     time.Now(),
    43  	}
    44  	if cmdline.IsDebugRPCServer() {
    45  		fmt.Printf("[go-easyops] Debug-rpc called unary rpc \"%s\"\n", info.FullMethod)
    46  	}
    47  
    48  	started := time.Now()
    49  
    50  	var outbound_ctx context.Context
    51  	var err error
    52  
    53  	ctx_build_by := 0
    54  	// we try both types of context parsing (since we can be called by either, old or new service)
    55  	if cmdline.ContextWithBuilder() {
    56  		ctx_build_by = 1
    57  		outbound_ctx, _, err = sd.V1inbound2outbound(in_ctx, cs)
    58  		if err != nil {
    59  			return nil, err
    60  		}
    61  		cmdline.DebugfContext("(unaryinterceptor) Inbound Context: %s\n%s\n----\n", ctx.Context2String(in_ctx), shared.LocalState2string(ctx.GetLocalState(in_ctx)))
    62  		cmdline.DebugfContext("(unaryinterceptor) New Context    : %s\n%s\n----\n", ctx.Context2String(outbound_ctx), shared.LocalState2string(ctx.GetLocalState(outbound_ctx)))
    63  	} else {
    64  		panic("obsolete codepath")
    65  	}
    66  	if err != nil {
    67  		return nil, err
    68  	}
    69  	if cmdline.IsDebugRPCServer() {
    70  		fmt.Printf("[go-easyops] context created through path %d\n", ctx_build_by)
    71  	}
    72  	//fmt.Printf("LS: %#v\n", ls)
    73  	//fmt.Printf("Method: \"%s\"\n", method)
    74  	stdMetrics.concurrent_server_requests.With(prometheus.Labels{
    75  		"method":      cs.MethodName,
    76  		"servicename": cs.ServiceName,
    77  	}).Inc()
    78  	defer stdMetrics.concurrent_server_requests.With(prometheus.Labels{
    79  		"method":      cs.MethodName,
    80  		"servicename": cs.ServiceName,
    81  	}).Dec()
    82  
    83  	grpc_server_requests.With(prometheus.Labels{
    84  		"method":      cs.MethodName,
    85  		"servicename": cs.ServiceName,
    86  	}).Inc()
    87  	track_inbound_call(cs.ServiceName, cs.MethodName, auth.GetService(outbound_ctx))
    88  	print_inbound_debug(cs, outbound_ctx)
    89  	/*************** now call the rpc implementation *****************/
    90  	i, err := handler(outbound_ctx, req)
    91  	if i == nil && err == nil {
    92  		fmt.Printf("[go-easyops] BUG: \"%s.%s\" returned no proto and no error\n", cs.ServiceName, cs.MethodName)
    93  	}
    94  	if cmdline.IsDebugRPCServer() {
    95  		//		fmt.Printf("[go-easyops: result: %v %v\n", i, err)
    96  		fmt.Printf("[go-easyops] Debug-rpc Request: \"%s.%s\" timing: %0.2fs\n", cs.ServiceName, cs.MethodName, time.Since(started).Seconds())
    97  	}
    98  	if err == nil {
    99  		grpc_server_req_durations.WithLabelValues(cs.ServiceName, cs.MethodName).Observe(time.Since(cs.Started).Seconds())
   100  		return i, nil
   101  	}
   102  	// it failed!
   103  	dur := time.Since(cs.Started).Seconds()
   104  	if dur > 5 { // >5 seconds processing time? warn
   105  		fmt.Printf("[go-easyops] Debug-rpc Timeout: \"%s.%s\" (called from %s) took rather long: %0.2fs (and failed: %s)\n", cs.ServiceName, cs.MethodName, auth.UserIDString(auth.GetService(outbound_ctx)), dur, errors.ErrorStringWithStackTrace(err))
   106  	}
   107  	if cmdline.IsDebugRPCServer() || *print_errs {
   108  		us := auth.UserIDString(auth.GetUser(outbound_ctx))
   109  		fmt.Printf("[go-easyops] Debug-rpc Fail: \"%s %s\" (called from %s as user %s) failed:\n", cs.ServiceName, cs.MethodName, auth.UserIDString(auth.GetService(outbound_ctx)), us)
   110  		fmt.Printf("[go-easyops] Debug-rpc Fail:    %s\n", errors.ErrorStringWithStackTrace(err))
   111  		fmt.Printf("[go-easyops] Debug-rpc Fail:    %s\n", err)
   112  	}
   113  	incFailure(cs.ServiceName, cs.MethodName, err)
   114  	//stdMetrics.grpc_failed_requests.With(prometheus.Labels{"method": method, "servicename": def.name}).Inc()
   115  
   116  	// get status from error
   117  	st := status.Convert(err)
   118  	/*
   119  		fm := &fw.CallTrace{
   120  			Message: fmt.Sprintf("[go-easyops] GRPC error in method %s.%s()", cs.ServiceName, cs.MethodName),
   121  			Method:  cs.MethodName,
   122  			Service: cs.ServiceName,
   123  		}
   124  		st = AddStatusDetail(st, fm)
   125  	*/
   126  	gerr := &ge.GRPCError{
   127  		LogMessage:  fmt.Sprintf("%s", err),
   128  		MethodName:  cs.MethodName,
   129  		ServiceName: cs.ServiceName,
   130  	}
   131  	calling_svc := auth.GetService(outbound_ctx)
   132  	if calling_svc != nil {
   133  		gerr.CallingServiceID = calling_svc.ID
   134  		gerr.CallingServiceEmail = calling_svc.Email
   135  	}
   136  	st = AddErrorDetail(st, gerr)
   137  	re := st.Err()
   138  	sd.logError(outbound_ctx, cs, re)
   139  	eh := sd.errorHandler
   140  	if eh != nil {
   141  		eh(outbound_ctx, cs.MethodName, err)
   142  	}
   143  	return i, st.Err()
   144  }
   145  
   146  func (sd *serverDef) V1inbound2outbound(in_ctx context.Context, rc *rpccall) (context.Context, shared.LocalState, error) {
   147  	if sd.local_service == nil {
   148  		cmdline.DebugfContext("[go-easyops] WARNING, in server.unary_interceptor, we are converting inbound2outbound without a local service account\n")
   149  	}
   150  	u := auth.GetUser(in_ctx)
   151  	if u != nil && u.ServiceAccount {
   152  		return nil, nil, errors.Unauthenticated(in_ctx, "user %s is a serviceaccount", u.ID)
   153  	}
   154  	octx := ctx.Inbound2Outbound(in_ctx, sd.local_service)
   155  	ls := ctx.GetLocalState(octx)
   156  	err := sd.checkAccess(octx, rc)
   157  	if err != nil {
   158  		if cmdline.IsDebugRPCServer() {
   159  			fmt.Printf("[go-easyops] checkaccess error: %s (peer=%s)\n", err, peerFromContext(octx))
   160  			fmt.Printf("[go-easyops] Context: %#v\n", ctx.Context2String(octx))
   161  		}
   162  		return nil, nil, err
   163  	}
   164  	if ls == nil {
   165  		panic("no localstate in newly converted inbound context")
   166  	}
   167  	return octx, ls, nil
   168  }
   169  

View as plain text