chore(inputs.opcua): Add trace logging for gather cycle timing diagnostics

Add Tracef instrumentation throughout the OPC UA read client gather
cycle to help diagnose performance issues where collection exceeds
the configured interval. The trace logs cover connection checks, PLC
read request/response timing, node value updates, metric construction,
and accumulator delivery, making it straightforward to identify whether
delays originate from the PLC or from Telegraf processing.

Author: skartikey

plugins/inputs/opcua/opcua.go

@@ -35,6 +35,9 @@ func (o *OpcUA) Init() (err error) {
 }
 
 func (o *OpcUA) Gather(acc telegraf.Accumulator) error {
+	gatherStart := time.Now()
+	o.Log.Tracef("Gather starting for %d nodes...", len(o.client.NodeIDs))
+
 	// Force reconnection every time if a threshold is 0
 	if o.client.ReconnectErrorThreshold == 0 {
 		o.client.forceReconnect = true
@@ -44,6 +47,8 @@ func (o *OpcUA) Gather(acc telegraf.Accumulator) error {
 	metrics, err := o.client.currentValues()
 	if err != nil {
 		o.consecutiveErrors++
+		o.Log.Tracef("Gather failed after %s: %v (consecutive errors: %d)",
+			time.Since(gatherStart), err, o.consecutiveErrors)
 
 		// Force reconnection based on an error threshold: if threshold > 0, reconnect after
 		// reaching the specified number of consecutive errors; if a threshold = 0, we already
@@ -57,10 +62,13 @@ func (o *OpcUA) Gather(acc telegraf.Accumulator) error {
 	// Reset error counter on success
 	o.consecutiveErrors = 0
 
+	addStart := time.Now()
 	// Parse the resulting data into metrics
 	for _, m := range metrics {
 		acc.AddMetric(m)
 	}
+	o.Log.Tracef("Gather complete: %d metrics added to accumulator in %s, total gather time %s",
+		len(metrics), time.Since(addStart), time.Since(gatherStart))
 	return nil
 }
 

plugins/inputs/opcua/read_client.go

@@ -141,15 +141,19 @@ func (o *readClient) ensureConnected() error {
 }
 
 func (o *readClient) currentValues() ([]telegraf.Metric, error) {
+	connectStart := time.Now()
 	if err := o.ensureConnected(); err != nil {
 		return nil, err
 	}
+	o.Log.Tracef("Connection check took %s", time.Since(connectStart))
 
 	if state := o.State(); state != opcua.Connected {
 		return nil, fmt.Errorf("not connected, in state %q", state)
 	}
 
+	readStart := time.Now()
 	if err := o.read(); err != nil {
+		o.Log.Tracef("Read failed after %s: %v", time.Since(readStart), err)
 		// We do not return the disconnect error, as this would mask the
 		// original problem, but we do log it
 		if derr := o.Disconnect(context.Background()); derr != nil {
@@ -158,16 +162,22 @@ func (o *readClient) currentValues() ([]telegraf.Metric, error) {
 
 		return nil, err
 	}
+	o.Log.Tracef("OPC UA read of %d nodes took %s", len(o.NodeIDs), time.Since(readStart))
 
+	metricStart := time.Now()
 	metrics := make([]telegraf.Metric, 0, len(o.NodeMetricMapping))
+	var skipped int
 	// Parse the resulting data into metrics
 	for i := range o.NodeIDs {
 		if !o.StatusCodeOK(o.LastReceivedData[i].Quality) {
+			skipped++
 			continue
 		}
 
 		metrics = append(metrics, o.MetricForNode(i))
 	}
+	o.Log.Tracef("Metric construction took %s (%d metrics, %d skipped due to bad quality)",
+		time.Since(metricStart), len(metrics), skipped)
 
 	return metrics, nil
 }
@@ -185,18 +195,26 @@ func (o *readClient) read() error {
 		count++
 
 		// Try to update the values for all registered nodes
+		o.Log.Tracef("Sending OPC UA read request for %d %s nodes (attempt %d)...",
+			len(o.reqIDs), nodeTypeLabel(o.Workarounds.UseUnregisteredReads), count)
+		requestStart := time.Now()
 		resp, err := o.Client.Read(o.ctx, req)
+		plcDuration := time.Since(requestStart)
 		if err == nil {
 			// Success, update the node values and exit
 			o.ReadSuccess.Incr(1)
 			o.forceReconnect = false
+			o.Log.Tracef("OPC UA read response received in %s, updating %d node values...", plcDuration, len(resp.Results))
+			updateStart := time.Now()
 			for i, d := range resp.Results {
 				o.UpdateNodeValue(i, d)
 			}
+			o.Log.Tracef("Node value update took %s", time.Since(updateStart))
 			return nil
 		}
 
 		o.ReadError.Incr(1)
+		o.Log.Tracef("OPC UA read request failed after %s: %v", plcDuration, err)
 
 		isSessionError := errors.Is(err, ua.StatusBadSessionIDInvalid) ||
 			errors.Is(err, ua.StatusBadSessionNotActivated) ||