[receiver/iis] Fix error log when no items are in the request queue (#…

…23234)

.chloggen/fix_iis-scrape-queue-failure.yaml

@@ -0,0 +1,11 @@
+# One of 'breaking', 'deprecation', 'new_component', 'enhancement', 'bug_fix'
+change_type: bug_fix
+
+# The name of the component, or a single word describing the area of concern, (e.g. filelogreceiver)
+component: iisreceiver
+
+# A brief description of the change.  Surround your text with quotes ("") if it needs to start with a backtick (`).
+note: Removes error message on every scrape where no items are present in the queue.
+
+# Mandatory: One or more tracking issues related to the change. You can use the PR number here if no issue exists.
+issues: [14575]

pkg/winperfcounters/internal/third_party/telegraf/win_perf_counters/performance_query.go

@@ -25,7 +25,6 @@ type PerformanceQuery interface {
 	AddCounterToQuery(counterPath string) (PDH_HCOUNTER, error)
 	AddEnglishCounterToQuery(counterPath string) (PDH_HCOUNTER, error)
 	GetCounterPath(counterHandle PDH_HCOUNTER) (string, error)
-	ExpandWildCardPath(counterPath string) ([]string, error)
 	GetFormattedCounterValueDouble(hCounter PDH_HCOUNTER) (float64, error)
 	GetFormattedCounterArrayDouble(hCounter PDH_HCOUNTER) ([]CounterValue, error)
 	CollectData() error
@@ -125,24 +124,6 @@ func (m *PerformanceQueryImpl) GetCounterPath(counterHandle PDH_HCOUNTER) (strin
 	return "", NewPdhError(ret)
 }
 
-// ExpandWildCardPath  examines local computer and returns those counter paths that match the given counter path which contains wildcard characters.
-func (m *PerformanceQueryImpl) ExpandWildCardPath(counterPath string) ([]string, error) {
-	var bufSize uint32
-	var buff []uint16
-	var ret uint32
-
-	if ret = PdhExpandWildCardPath(counterPath, nil, &bufSize); ret == PDH_MORE_DATA {
-		buff = make([]uint16, bufSize)
-		bufSize = uint32(len(buff))
-		ret = PdhExpandWildCardPath(counterPath, &buff[0], &bufSize)
-		if ret == ERROR_SUCCESS {
-			list := UTF16ToStringArray(buff)
-			return list, nil
-		}
-	}
-	return nil, NewPdhError(ret)
-}
-
 // GetFormattedCounterValueDouble computes a displayable value for the specified counter
 func (m *PerformanceQueryImpl) GetFormattedCounterValueDouble(hCounter PDH_HCOUNTER) (float64, error) {
 	var counterType uint32
@@ -210,6 +191,24 @@ func (m *PerformanceQueryImpl) IsVistaOrNewer() bool {
 	return PdhAddEnglishCounterSupported()
 }
 
+// ExpandWildCardPath examines local computer and returns those counter paths that match the given counter path which contains wildcard characters.
+func ExpandWildCardPath(counterPath string) ([]string, error) {
+	var bufSize uint32
+	var buff []uint16
+	var ret uint32
+
+	if ret = PdhExpandWildCardPath(counterPath, nil, &bufSize); ret == PDH_MORE_DATA {
+		buff = make([]uint16, bufSize)
+		bufSize = uint32(len(buff))
+		ret = PdhExpandWildCardPath(counterPath, &buff[0], &bufSize)
+		if ret == ERROR_SUCCESS {
+			list := UTF16ToStringArray(buff)
+			return list, nil
+		}
+	}
+	return nil, NewPdhError(ret)
+}
+
 // UTF16PtrToString converts Windows API LPTSTR (pointer to string) to go string
 func UTF16PtrToString(s *uint16) string {
 	if s == nil {

pkg/winperfcounters/watcher.go

@@ -45,6 +45,15 @@ func NewWatcher(object, instance, counterName string) (PerfCounterWatcher, error
 	return counter, nil
 }
 
+// NewWatcherFromPath creates new PerfCounterWatcher by provided path.
+func NewWatcherFromPath(path string) (PerfCounterWatcher, error) {
+	counter, err := newPerfCounter(path, true)
+	if err != nil {
+		return nil, fmt.Errorf("failed to create perf counter with path %v: %w", path, err)
+	}
+	return counter, nil
+}
+
 func counterPath(object, instance, counterName string) string {
 	if instance != "" {
 		instance = fmt.Sprintf("(%s)", instance)
@@ -118,6 +127,11 @@ func (pc *perfCounter) ScrapeData() ([]CounterValue, error) {
 	return vals, nil
 }
 
+// ExpandWildCardPath examines the local computer and returns those counter paths that match the given counter path which contains wildcard characters.
+func ExpandWildCardPath(counterPath string) ([]string, error) {
+	return win_perf_counters.ExpandWildCardPath(counterPath)
+}
+
 func removeTotalIfMultipleValues(vals []CounterValue) []CounterValue {
 	if len(vals) == 0 {
 		return vals

receiver/iisreceiver/recorder.go

@@ -101,9 +101,10 @@ var appPoolPerfCounterRecorders = []perfCounterRecorderConf{
 			"CurrentQueueSize": func(mb *metadata.MetricsBuilder, ts pcommon.Timestamp, val float64) {
 				mb.RecordIisRequestQueueCountDataPoint(ts, int64(val))
 			},
-			"MaxQueueItemAge": func(mb *metadata.MetricsBuilder, ts pcommon.Timestamp, val float64) {
-				mb.RecordIisRequestQueueAgeMaxDataPoint(ts, int64(val))
-			},
 		},
 	},
 }
+
+func recordMaxQueueItemAge(mb *metadata.MetricsBuilder, ts pcommon.Timestamp, val float64) {
+	mb.RecordIisRequestQueueAgeMaxDataPoint(ts, int64(val))
+}

receiver/iisreceiver/scraper.go

@@ -8,6 +8,9 @@ package iisreceiver // import "github.com/open-telemetry/opentelemetry-collector
 
 import (
 	"context"
+	"fmt"
+	"regexp"
+	"strings"
 	"time"
 
 	"go.opentelemetry.io/collector/component"
@@ -30,10 +33,13 @@ type iisReceiver struct {
 	totalWatcherRecorders   []watcherRecorder
 	siteWatcherRecorders    []watcherRecorder
 	appPoolWatcherRecorders []watcherRecorder
+	queueMaxAgeWatchers     []instanceWatcher
 	metricBuilder           *metadata.MetricsBuilder
 
 	// for mocking
-	newWatcher func(string, string, string) (winperfcounters.PerfCounterWatcher, error)
+	newWatcher         func(string, string, string) (winperfcounters.PerfCounterWatcher, error)
+	newWatcherFromPath func(string) (winperfcounters.PerfCounterWatcher, error)
+	expandWildcardPath func(string) ([]string, error)
 }
 
 // watcherRecorder is a struct containing perf counter watcher along with corresponding value recorder.
@@ -42,14 +48,22 @@ type watcherRecorder struct {
 	recorder recordFunc
 }
 
+// instanceWatcher is a struct containing a perf counter watcher, along with the single instance the watcher records.
+type instanceWatcher struct {
+	watcher  winperfcounters.PerfCounterWatcher
+	instance string
+}
+
 // newIisReceiver returns an iisReceiver
 func newIisReceiver(settings receiver.CreateSettings, cfg *Config, consumer consumer.Metrics) *iisReceiver {
 	return &iisReceiver{
-		params:        settings.TelemetrySettings,
-		config:        cfg,
-		consumer:      consumer,
-		metricBuilder: metadata.NewMetricsBuilder(cfg.MetricsBuilderConfig, settings),
-		newWatcher:    winperfcounters.NewWatcher,
+		params:             settings.TelemetrySettings,
+		config:             cfg,
+		consumer:           consumer,
+		metricBuilder:      metadata.NewMetricsBuilder(cfg.MetricsBuilderConfig, settings),
+		newWatcher:         winperfcounters.NewWatcher,
+		newWatcherFromPath: winperfcounters.NewWatcherFromPath,
+		expandWildcardPath: winperfcounters.ExpandWildCardPath,
 	}
 }
 
@@ -60,6 +74,7 @@ func (rcvr *iisReceiver) start(ctx context.Context, host component.Host) error {
 	rcvr.totalWatcherRecorders = rcvr.buildWatcherRecorders(totalPerfCounterRecorders, errs)
 	rcvr.siteWatcherRecorders = rcvr.buildWatcherRecorders(sitePerfCounterRecorders, errs)
 	rcvr.appPoolWatcherRecorders = rcvr.buildWatcherRecorders(appPoolPerfCounterRecorders, errs)
+	rcvr.queueMaxAgeWatchers = rcvr.buildMaxQueueItemAgeWatchers(errs)
 
 	return errs.Combine()
 }
@@ -69,8 +84,19 @@ func (rcvr *iisReceiver) scrape(ctx context.Context) (pmetric.Metrics, error) {
 	var errs error
 	now := pcommon.NewTimestampFromTime(time.Now())
 
-	rcvr.scrapeInstanceMetrics(now, rcvr.siteWatcherRecorders, metadata.WithIisSite)
-	rcvr.scrapeInstanceMetrics(now, rcvr.appPoolWatcherRecorders, metadata.WithIisApplicationPool)
+	// Maintain maps of site -> {val, recordFunc} and app -> {val, recordFunc}
+	// so that we can emit all metrics for a particular instance (site or app_pool) at once,
+	// keeping them in a single resource metric.
+
+	siteToRecorders := map[string][]valRecorder{}
+	rcvr.scrapeInstanceMetrics(rcvr.siteWatcherRecorders, siteToRecorders)
+	rcvr.emitInstanceMap(now, siteToRecorders, metadata.WithIisSite)
+
+	appToRecorders := map[string][]valRecorder{}
+	rcvr.scrapeInstanceMetrics(rcvr.appPoolWatcherRecorders, appToRecorders)
+	rcvr.scrapeMaxQueueAgeMetrics(appToRecorders)
+	rcvr.emitInstanceMap(now, appToRecorders, metadata.WithIisApplicationPool)
+
 	rcvr.scrapeTotalMetrics(now)
 
 	return rcvr.metricBuilder.Emit(), errs
@@ -100,12 +126,7 @@ type valRecorder struct {
 	record recordFunc
 }
 
-func (rcvr *iisReceiver) scrapeInstanceMetrics(now pcommon.Timestamp, wrs []watcherRecorder, resourceOption func(string) metadata.ResourceMetricsOption) {
-	// Maintain a map of instance -> {val, recordFunc}
-	// so that we can emit all metrics for a particular instance (site, app_pool) at once,
-	// keeping them in a single resource metric.
-	instanceToRecorders := map[string][]valRecorder{}
-
+func (rcvr *iisReceiver) scrapeInstanceMetrics(wrs []watcherRecorder, instanceToRecorders map[string][]valRecorder) {
 	for _, wr := range wrs {
 		counterValues, err := wr.watcher.ScrapeData()
 		if err != nil {
@@ -130,7 +151,40 @@ func (rcvr *iisReceiver) scrapeInstanceMetrics(now pcommon.Timestamp, wrs []watc
 		}
 	}
 
-	// record all metrics for each instance, then emit them all as a single resource metric
+}
+
+var negativeDenominatorError = "A counter with a negative denominator value was detected.\r\n"
+
+func (rcvr *iisReceiver) scrapeMaxQueueAgeMetrics(appToRecorders map[string][]valRecorder) {
+	for _, wr := range rcvr.queueMaxAgeWatchers {
+		counterValues, err := wr.watcher.ScrapeData()
+
+		var value float64
+		switch {
+		case err != nil && strings.HasSuffix(err.Error(), negativeDenominatorError):
+			// This error occurs when there are no items in the queue;
+			// in this case, we would like to emit a 0 instead of logging an error (this is an expected scenario).
+			value = 0
+		case err != nil:
+			rcvr.params.Logger.Warn("some performance counters could not be scraped; ", zap.Error(err))
+			continue
+		case len(counterValues) == 0:
+			// No counters scraped
+			continue
+		default:
+			value = counterValues[0].Value
+		}
+
+		appToRecorders[wr.instance] = append(appToRecorders[wr.instance],
+			valRecorder{
+				val:    value,
+				record: recordMaxQueueItemAge,
+			})
+	}
+}
+
+// emitInstanceMap records all metrics for each instance, then emits them all as a single resource metric
+func (rcvr *iisReceiver) emitInstanceMap(now pcommon.Timestamp, instanceToRecorders map[string][]valRecorder, resourceOption func(string) metadata.ResourceMetricsOption) {
 	for instanceName, recorders := range instanceToRecorders {
 		for _, recorder := range recorders {
 			recorder.record(rcvr.metricBuilder, now, recorder.val)
@@ -146,6 +200,7 @@ func (rcvr iisReceiver) shutdown(ctx context.Context) error {
 	errs = multierr.Append(errs, closeWatcherRecorders(rcvr.totalWatcherRecorders))
 	errs = multierr.Append(errs, closeWatcherRecorders(rcvr.siteWatcherRecorders))
 	errs = multierr.Append(errs, closeWatcherRecorders(rcvr.appPoolWatcherRecorders))
+	errs = multierr.Append(errs, closeInstanceWatchers(rcvr.queueMaxAgeWatchers))
 	return errs
 }
 
@@ -166,6 +221,49 @@ func (rcvr *iisReceiver) buildWatcherRecorders(confs []perfCounterRecorderConf,
 	return wrs
 }
 
+var maxQueueItemAgeInstanceRegex = regexp.MustCompile(`\\HTTP Service Request Queues\((?P<instance>[^)]+)\)\\MaxQueueItemAge$`)
+
+// buildMaxQueueItemAgeWatchers builds a watcher for each individual instance of the MaxQueueItemAge counter.
+// This is done in order to capture the error when scraping each individual instance, because we want to ignore
+// negative denominator errors.
+func (rcvr *iisReceiver) buildMaxQueueItemAgeWatchers(scrapeErrors *scrapererror.ScrapeErrors) []instanceWatcher {
+	wrs := []instanceWatcher{}
+
+	paths, err := rcvr.expandWildcardPath(`\HTTP Service Request Queues(*)\MaxQueueItemAge`)
+	if err != nil {
+		scrapeErrors.AddPartial(1, fmt.Errorf("failed to expand wildcard path for MaxQueueItemAge: %w", err))
+		return wrs
+	}
+
+	for _, path := range paths {
+		matches := maxQueueItemAgeInstanceRegex.FindStringSubmatch(path)
+		if len(matches) != 2 {
+			scrapeErrors.AddPartial(1, fmt.Errorf("failed to extract instance from %q", path))
+			continue
+		}
+
+		instanceName := matches[1]
+
+		if instanceName == "_Total" {
+			// skip total instance
+			continue
+		}
+
+		watcher, err := rcvr.newWatcherFromPath(path)
+		if err != nil {
+			scrapeErrors.AddPartial(1, fmt.Errorf("failed to create watcher from %q: %w", path, err))
+			continue
+		}
+
+		wrs = append(wrs, instanceWatcher{
+			instance: instanceName,
+			watcher:  watcher,
+		})
+	}
+
+	return wrs
+}
+
 func closeWatcherRecorders(wrs []watcherRecorder) error {
 	var errs error
 	for _, wr := range wrs {
@@ -176,3 +274,14 @@ func closeWatcherRecorders(wrs []watcherRecorder) error {
 	}
 	return errs
 }
+
+func closeInstanceWatchers(wrs []instanceWatcher) error {
+	var errs error
+	for _, wr := range wrs {
+		err := wr.watcher.Close()
+		if err != nil {
+			errs = multierr.Append(errs, err)
+		}
+	}
+	return errs
+}