Looking at better logging in debug mode for snmp (#706)

* Looking at better logging in debug mode for snmp

* Adding log level to Uptime metrics

pkg/eggs/logger/logger.go

@@ -13,6 +13,7 @@ type Underlying interface {
 	Infof(lp string, f string, params ...interface{})
 	Warnf(lp string, f string, params ...interface{})
 	Errorf(lp string, f string, params ...interface{})
+	GetLogLevel() string
 }
 
 // ---------------

pkg/eggs/logger/testing/logger.go

@@ -52,3 +52,6 @@ func (l *testUnderlyingL) Warnf(lp string, f string, params ...interface{}) {
 func (l *testUnderlyingL) Errorf(lp string, f string, params ...interface{}) {
 	l.logf("%s [ERROR] %s", lp, fmt.Sprintf(f, params...))
 }
+func (l *testUnderlyingL) GetLogLevel() string {
+	return "debug"
+}

pkg/inputs/snmp/metadata/poll.go

@@ -255,7 +255,9 @@ func (p *Poller) toFlows(dd *kt.DeviceData) ([]*kt.JCHF, error) {
 	}
 
 	// Also any device level tags
-	cs := map[string]string{}
+	cs := map[string]string{ // Set log level as a SysLogLevel key here so that Uptime metrics get it only.
+		"SysLogLevel": p.log.GetLogger().GetUnderlyingLogger().GetLogLevel(),
+	}
 	p.conf.SetUserTags(cs)
 	for k, v := range cs {
 		if strings.HasPrefix(v, TagValuePrefix) { // See if we can find this value in the MDS instead.

pkg/inputs/snmp/metrics/device_metrics.go

@@ -81,6 +81,14 @@ func (dm *DeviceMetrics) Poll(ctx context.Context, server *gosnmp.GoSNMP, pinger
 	return dm.pollFromConfig(ctx, server, pinger)
 }
 
+func (dm *DeviceMetrics) GetNumberMibsFailed() int64 {
+	return dm.metrics.Missing.Value()
+}
+
+func (dm *DeviceMetrics) GetNumberMibsTotal() int {
+	return len(dm.oids)
+}
+
 type wrapper struct {
 	variable gosnmp.SnmpPDU
 	mib      *kt.Mib

pkg/inputs/snmp/metrics/interface_metrics.go

@@ -101,6 +101,10 @@ var (
 	MAX_COUNTER_INTS = 250
 )
 
+func (im *InterfaceMetrics) GetNumberMibsTotal() int {
+	return len(im.oidMap)
+}
+
 // PollSNMPCounter polls SNMP for counter statistics like # bytes and packets transferred.
 func (im *InterfaceMetrics) Poll(ctx context.Context, server *gosnmp.GoSNMP, lastDeviceMetrics []*kt.JCHF) ([]*kt.JCHF, error) {
 	im.mux.Lock()

pkg/inputs/snmp/metrics/poll.go

@@ -244,6 +244,10 @@ func (p *Poller) StartLoop(ctx context.Context) {
 				}
 
 				// Great!  We finished the poll in the same block we started it in!
+				p.log.Debugf("Metrics Poll: In %v polled %d mibs, %d missing.",
+					time.Now().Sub(startTime),
+					p.deviceMetrics.GetNumberMibsTotal()+p.interfaceMetrics.GetNumberMibsTotal(),
+					p.deviceMetrics.GetNumberMibsFailed())
 				p.jchfChan <- flows
 
 			case <-statusCheck.C: // Send in on a seperate timer status about how this system is working.

pkg/inputs/snmp/util/util.go

@@ -8,7 +8,9 @@ import (
 	"encoding/hex"
 	"fmt"
 	"net"
+	"reflect"
 	"regexp"
+	"runtime"
 	"strconv"
 	"strings"
 	"time"
@@ -162,11 +164,13 @@ func WalkOID(ctx context.Context, device *kt.SnmpDeviceConfig, oid string, serve
 		case <-time.After(try.sleep):
 		}
 
+		st := time.Now()
 		results, err = try.walk(oid)
 		if err == nil {
 			if i > 0 {
 				log.Infof("%s SNMP retry %d on OID %s succeeded", logName, i, oid)
 			}
+			log.Debugf("(%s) polling %s using %s took %v. attempt %d of %d.", device.DeviceIP, oid, runtime.FuncForPC(reflect.ValueOf(try.walk).Pointer()).Name(), time.Now().Sub(st), i, len(tries))
 			return results, nil
 		}
 

pkg/sinks/nr/nr.go

@@ -317,7 +317,6 @@ func (s *NRSink) sendNR(ctx context.Context, payload *kt.Output, url string) {
 					cbErr = err
 					s.metrics.DeliveryErr.Mark(1)
 				} else {
-					s.Debugf("NR Success: %v UUID: %s, RID: %s", nr.Success, nr.Uuid, nr.RequestId)
 					s.metrics.DeliveryWin.Mark(1)
 				}
 			}

pkg/util/logger/logger.go

@@ -90,6 +90,10 @@ func New(level Level) (l *Logger) {
 	return
 }
 
+func (l *Logger) GetLogLevel() string {
+	return l.level.String()
+}
+
 func (l *Logger) Printf(level Level, prefix, format string, v ...interface{}) {
 	if l == nil {
 		// nil logger - ignore