From f19997aea30146e52b1dc75bad00c46256be6da0 Mon Sep 17 00:00:00 2001 From: Manuel Kieweg <manuel.kieweg@h-da.de> Date: Wed, 24 Mar 2021 10:40:58 +0000 Subject: [PATCH] added logging to core functionality --- cli/path_traversal.go | 1 - cli/subscribe.go | 1 - cmd/root.go | 14 +++++++++++++- nucleus/gnmi_transport.go | 32 +++++++++++++++++++++++++++++++ nucleus/principalNetworkDomain.go | 12 ++++++++++-- nucleus/southbound.go | 7 ++----- nucleus/southbound_test.go | 12 ------------ nucleus/store.go | 22 +++++++++++++++++++++ 8 files changed, 79 insertions(+), 22 deletions(-) diff --git a/cli/path_traversal.go b/cli/path_traversal.go index 1be78ec58..3513db33b 100644 --- a/cli/path_traversal.go +++ b/cli/path_traversal.go @@ -6,7 +6,6 @@ import ( ) func PathTraversal() error { - log.SetLevel(log.DebugLevel) paths, err := path.ParseSchema(testSchema, "device") if err != nil { return err diff --git a/cli/subscribe.go b/cli/subscribe.go index bfdd9d008..4306775a9 100644 --- a/cli/subscribe.go +++ b/cli/subscribe.go @@ -15,7 +15,6 @@ import ( // Subscribe starts a gNMI subscriber requersting the specified paths on the target and // logs the response to stdout. Only 'stream' mode with 'sample' operation supported. func Subscribe(a, u, p string, sample, heartbeat int64, args...string) error{ - log.SetLevel(log.DebugLevel) sbi := &nucleus.OpenConfig{} tOpts := &nucleus.GnmiTransportOptions{ Config: gnmi.Config{ diff --git a/cmd/root.go b/cmd/root.go index 2ff4970da..24a5fed67 100644 --- a/cmd/root.go +++ b/cmd/root.go @@ -45,6 +45,7 @@ var cfgFile string var username string var password string var address string +var loglevel string // rootCmd represents the base command when called without any subcommands @@ -78,6 +79,7 @@ func init() { rootCmd.PersistentFlags().StringVarP(&username, "username", "u", "admin", "username for a gnmi resource") rootCmd.PersistentFlags().StringVarP(&password, "password", "p", "arista", "password for a gnmi resource") rootCmd.PersistentFlags().StringVarP(&username, "address", "a", "ceos-cocsn.apps.ocp.fbi.h-da.de:6030", "address to a gnmi resource") + rootCmd.PersistentFlags().StringVarP(&loglevel, "log-level", "l", "", "log level 'debug' or 'trace'") } @@ -97,8 +99,18 @@ func initConfig() { if err := viper.ReadInConfig(); err == nil { fmt.Println("Using config file:", viper.ConfigFileUsed()) } - if viper.IsSet("GOSDN_DEBUG") { + + loglevel = viper.GetString("GOSDN_DEBUG") + log.SetReportCaller(true) + switch loglevel { + case "trace": + log.SetLevel(log.TraceLevel) + case "debug": log.SetLevel(log.DebugLevel) + default: + log.SetLevel(log.InfoLevel) + log.SetFormatter(&log.JSONFormatter{}) + log.SetReportCaller(false) } } diff --git a/nucleus/gnmi_transport.go b/nucleus/gnmi_transport.go index 30af29f23..8ac57497b 100644 --- a/nucleus/gnmi_transport.go +++ b/nucleus/gnmi_transport.go @@ -24,6 +24,11 @@ func NewGnmiTransport(opts *GnmiTransportOptions) (*Gnmi, error) { if err != nil { return nil, err } + log.WithFields(log.Fields{ + "target": opts.Addr, + "tls": opts.TLS, + "encoding": opts.Encoding, + }).Info("building new gNMI transport") return &Gnmi{ SetNode: opts.SetNode, RespChan: opts.RespChan, @@ -140,6 +145,9 @@ func extraxtPathElements(path *gpb.Path) []string { // Capabilities calls GNMI capabilities func (g *Gnmi) Capabilities(ctx context.Context) (interface{}, error) { + log.WithFields(log.Fields{ + "target": g.Options.Addr, + }).Info("sending gNMI capabilities request") ctx = gnmi.NewContext(ctx, &g.Options.Config) ctx = context.WithValue(ctx, "config", &g.Options.Config) resp, err := g.client.Capabilities(ctx, &gpb.CapabilityRequest{}) @@ -163,6 +171,11 @@ func (g *Gnmi) get(ctx context.Context, paths [][]string, origin string) (interf // getWithRequest takes a fully formed GetRequest, performs the Get, // and returns any response. func (g *Gnmi) getWithRequest(ctx context.Context, req *gpb.GetRequest) (interface{}, error) { + log.WithFields(log.Fields{ + "target": g.Options.Addr, + "path": req.Path, + }).Info("sending gNMI get request") + resp, err := g.client.Get(ctx, req) if err != nil { return nil, err @@ -174,6 +187,19 @@ func (g *Gnmi) getWithRequest(ctx context.Context, req *gpb.GetRequest) (interfa func (g *Gnmi) set(ctx context.Context, setOps []*gnmi.Operation, exts ...*gnmi_ext.Extension) (*gpb.SetResponse, error) { ctx = gnmi.NewContext(ctx, &g.Options.Config) + targets := make([]string, len(setOps)) + paths := make([][]string, len(setOps)) + values := make([]string, len(setOps)) + for i,v := range setOps { + targets[i] = v.Target + paths[i] = v.Path + values[i] = v.Val + } + log.WithFields(log.Fields{ + "targets": targets, + "paths": paths, + "values": values, + }).Info("sending gNMI set request") return gnmi.Set(ctx, g.client, setOps, exts...) } @@ -182,6 +208,12 @@ func (g *Gnmi) subscribe(ctx context.Context) error { ctx = gnmi.NewContext(ctx, &g.Options.Config) opts := ctx.Value("opts").(*gnmi.SubscribeOptions) go func() { + log.WithFields(log.Fields{ + "address": opts.Target, + "paths": opts.Paths, + "mode": opts.Mode, + "interval": opts.SampleInterval, + }).Info("subscribed to gNMI target") for { resp := <-g.RespChan if resp != nil { diff --git a/nucleus/principalNetworkDomain.go b/nucleus/principalNetworkDomain.go index ec7a80f2b..e0b9fe815 100644 --- a/nucleus/principalNetworkDomain.go +++ b/nucleus/principalNetworkDomain.go @@ -2,6 +2,7 @@ package nucleus import ( "context" + log "github.com/sirupsen/logrus" "encoding/json" "github.com/google/uuid" @@ -149,11 +150,14 @@ func (pnd *pndImplementation) MarshalDevice(uuid uuid.UUID) (string, error) { if err != nil { return "", err } - + log.WithFields(log.Fields{ + "pnd": pnd.id, + "device": uuid, + }).Info("marshalled device") return string(jsonTree), nil } -//Request sends a request for a specific device +//Request sends a get request to a specific device func (pnd *pndImplementation) Request(uuid uuid.UUID, path string) error { d, err := pnd.getDevice(uuid) if err != nil { @@ -178,5 +182,9 @@ func (pnd *pndImplementation) RequestAll(path string) error { return err } } + log.WithFields(log.Fields{ + "pnd": pnd.id, + "path": path, + }).Info("sent request to all devices") return nil } diff --git a/nucleus/southbound.go b/nucleus/southbound.go index 88a6ed5f7..1d82cacfa 100644 --- a/nucleus/southbound.go +++ b/nucleus/southbound.go @@ -33,9 +33,6 @@ type Tapi struct { // The struct holds the YANG schema and a function that // returns an SBI specific SetNode function. type OpenConfig struct { - // deprecated - transport Transport - schema *ytypes.Schema id uuid.UUID } @@ -76,7 +73,7 @@ func (oc *OpenConfig) Unmarshal() func([]byte, []string, interface{}, ...ytypes. } // unmarshal parses a root or 1st level gNMI response to a go struct -// Named return due to how recover works here +// Named return to return appropriate recover error func unmarshal(bytes []byte, fields []string, goStruct interface{}, opt ...ytypes.UnmarshalOpt) (err error) { defer func() { if r := recover(); r != nil { @@ -107,7 +104,7 @@ func unmarshal(bytes []byte, fields []string, goStruct interface{}, opt ...ytype } // iter walks down the provided paths and initializes the ygot.GoStruct. It only works for -// the root level. Watch out for named returns here +// the root level. Named returns to return appropriate recover error // TODO(mk): Fix deeper layers func iter(a ygot.GoStruct, fields []string) (b ygot.GoStruct, f string, err error) { defer func() { diff --git a/nucleus/southbound_test.go b/nucleus/southbound_test.go index c4ebf28f2..e46e992bd 100644 --- a/nucleus/southbound_test.go +++ b/nucleus/southbound_test.go @@ -13,18 +13,12 @@ import ( func testSetupSbi() { var err error - aristaUUID, err = uuid.Parse("d3795249-579c-4be7-8818-29f113cb86ee") - if err != nil { - log.Fatal(err) - } - ocUUID, err = uuid.Parse("5e252b70-38f2-4c99-a0bf-1b16af4d7e67") if err != nil { log.Fatal(err) } } -var aristaUUID uuid.UUID var ocUUID uuid.UUID func TestOpenConfig_Id(t *testing.T) { @@ -41,7 +35,6 @@ func TestOpenConfig_Id(t *testing.T) { { name: "default", fields: fields{ - transport: nil, schema: nil, id: ocUUID, }, @@ -51,7 +44,6 @@ func TestOpenConfig_Id(t *testing.T) { for _, tt := range tests { t.Run(tt.name, func(t *testing.T) { oc := &OpenConfig{ - transport: tt.fields.transport, schema: tt.fields.schema, id: tt.fields.id, } @@ -64,7 +56,6 @@ func TestOpenConfig_Id(t *testing.T) { func TestOpenConfig_SbiIdentifier(t *testing.T) { type fields struct { - transport Transport schema *ytypes.Schema id uuid.UUID } @@ -78,7 +69,6 @@ func TestOpenConfig_SbiIdentifier(t *testing.T) { for _, tt := range tests { t.Run(tt.name, func(t *testing.T) { oc := &OpenConfig{ - transport: tt.fields.transport, schema: tt.fields.schema, id: tt.fields.id, } @@ -95,7 +85,6 @@ func TestOpenConfig_Schema(t *testing.T) { t.Error(err) } type fields struct { - transport Transport schema *ytypes.Schema id uuid.UUID } @@ -109,7 +98,6 @@ func TestOpenConfig_Schema(t *testing.T) { for _, tt := range tests { t.Run(tt.name, func(t *testing.T) { oc := &OpenConfig{ - transport: tt.fields.transport, schema: tt.fields.schema, id: tt.fields.id, } diff --git a/nucleus/store.go b/nucleus/store.go index 5923873d2..33ca95509 100644 --- a/nucleus/store.go +++ b/nucleus/store.go @@ -2,8 +2,11 @@ package nucleus import ( "github.com/google/uuid" + log "github.com/sirupsen/logrus" + "reflect" ) +// Storable provides an interface for the controller's storage architecture. type Storable interface { Id() uuid.UUID } @@ -20,6 +23,10 @@ func (s store) add(item Storable) error { return &ErrAlreadyExists{item: item} } s[item.Id()] = item + log.WithFields(log.Fields{ + "type": reflect.TypeOf(item), + "uuid": item.Id(), + }).Info("storable was added") return nil } @@ -27,6 +34,9 @@ func (s store) get(id uuid.UUID) (Storable, error) { if !s.exists(id) { return nil, &ErrNotFound{id: id} } + log.WithFields(log.Fields{ + "uuid": id, + }).Info("storable was accessed") return s[id], nil } @@ -35,6 +45,9 @@ func (s store) delete(id uuid.UUID) error { return &ErrNotFound{id: id} } delete(s, id) + log.WithFields(log.Fields{ + "uuid": id, + }).Info("storable has been deleted") return nil } @@ -65,6 +78,9 @@ func (s sbiStore) get(id uuid.UUID) (SouthboundInterface, error) { t: "SouthboundInterface", } } + log.WithFields(log.Fields{ + "uuid": id, + }).Info("southbound interface was accessed") return sbi, nil } @@ -84,6 +100,9 @@ func (s pndStore) get(id uuid.UUID) (PrincipalNetworkDomain, error) { t: "PrincipalNetworkDomain", } } + log.WithFields(log.Fields{ + "uuid": id, + }).Info("principal network domain was accessed") return pnd, nil } @@ -103,5 +122,8 @@ func (s deviceStore) get(id uuid.UUID) (*Device, error) { t: "Device", } } + log.WithFields(log.Fields{ + "uuid": id, + }).Info("device was accessed") return device, nil } -- GitLab