UsageStats: Add traces when sending usage stats (#55474)

This commit is contained in:
Emil Tullstedt 2022-09-26 15:10:54 +02:00 committed by GitHub
parent d07abdd23c
commit f7a3e50b23
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
3 changed files with 83 additions and 32 deletions

View File

@ -7,6 +7,7 @@ import (
"github.com/grafana/grafana/pkg/api/routing"
"github.com/grafana/grafana/pkg/infra/kvstore"
"github.com/grafana/grafana/pkg/infra/log"
"github.com/grafana/grafana/pkg/infra/tracing"
"github.com/grafana/grafana/pkg/infra/usagestats"
"github.com/grafana/grafana/pkg/plugins"
"github.com/grafana/grafana/pkg/setting"
@ -18,19 +19,21 @@ type UsageStats struct {
RouteRegister routing.RouteRegister
pluginStore plugins.Store
log log.Logger
log log.Logger
tracer tracing.Tracer
externalMetrics []usagestats.MetricsFunc
sendReportCallbacks []usagestats.SendReportCallbackFunc
}
func ProvideService(cfg *setting.Cfg, pluginStore plugins.Store, kvStore kvstore.KVStore, routeRegister routing.RouteRegister) *UsageStats {
func ProvideService(cfg *setting.Cfg, pluginStore plugins.Store, kvStore kvstore.KVStore, routeRegister routing.RouteRegister, tracer tracing.Tracer) *UsageStats {
s := &UsageStats{
Cfg: cfg,
RouteRegister: routeRegister,
pluginStore: pluginStore,
kvStore: kvstore.WithNamespace(kvStore, 0, "infra.usagestats"),
log: log.New("infra.usagestats"),
tracer: tracer,
}
s.registerAPIEndpoints()
@ -65,8 +68,8 @@ func (uss *UsageStats) Run(ctx context.Context) error {
for {
select {
case <-sendReportTicker.C:
if err := uss.sendUsageStats(ctx); err != nil {
uss.log.Warn("Failed to send usage stats", "error", err)
if traceID, err := uss.sendUsageStats(ctx); err != nil {
uss.log.Warn("Failed to send usage stats", "error", err, "traceID", traceID)
}
lastSent = time.Now()

View File

@ -4,13 +4,18 @@ import (
"bytes"
"context"
"encoding/json"
"fmt"
"net/http"
"reflect"
"runtime"
"strings"
"time"
"github.com/google/uuid"
"go.opentelemetry.io/otel/attribute"
"go.opentelemetry.io/otel/codes"
"github.com/grafana/grafana/pkg/infra/tracing"
"github.com/grafana/grafana/pkg/infra/usagestats"
)
@ -18,8 +23,8 @@ var usageStatsURL = "https://stats.grafana.org/grafana-usage-report"
func (uss *UsageStats) GetUsageReport(ctx context.Context) (usagestats.Report, error) {
version := strings.ReplaceAll(uss.Cfg.BuildVersion, ".", "_")
metrics := map[string]interface{}{}
start := time.Now()
edition := "oss"
if uss.Cfg.IsEnterprise {
@ -44,16 +49,18 @@ func (uss *UsageStats) GetUsageReport(ctx context.Context) (usagestats.Report, e
metrics["stats.valid_license.count"] = 0
}
uss.log.FromContext(ctx).Debug("Collected usage stats", "metricCount", len(metrics), "version", report.Version, "os", report.Os, "arch", report.Arch, "edition", report.Edition, "duration", time.Since(start))
return report, nil
}
func (uss *UsageStats) gatherMetrics(ctx context.Context, metrics map[string]interface{}) {
ctx, span := uss.tracer.Start(ctx, "UsageStats.GatherLoop")
defer span.End()
totC, errC := 0, 0
for _, fn := range uss.externalMetrics {
fnMetrics, err := fn(ctx)
fnMetrics, err := uss.runMetricsFunc(ctx, fn)
totC++
if err != nil {
uss.log.Error("Failed to fetch external metrics", "error", err)
errC++
continue
}
@ -66,47 +73,82 @@ func (uss *UsageStats) gatherMetrics(ctx context.Context, metrics map[string]int
metrics["stats.usagestats.debug.collect.error.count"] = errC
}
func (uss *UsageStats) runMetricsFunc(ctx context.Context, fn usagestats.MetricsFunc) (map[string]interface{}, error) {
start := time.Now()
ctx, span := uss.tracer.Start(ctx, "UsageStats.Gather")
fnName := runtime.FuncForPC(reflect.ValueOf(fn).Pointer()).Name()
span.SetAttributes("usageStats.function", fnName, attribute.Key("usageStats.function").String(fnName))
defer span.End()
fnMetrics, err := fn(ctx)
if err != nil {
uss.log.FromContext(ctx).Error("Failed to fetch usage stats from provider", "error", err, "duration", time.Since(start), "function", fnName)
span.SetStatus(codes.Error, fmt.Sprintf("failed to fetch usage stats from provider: %v", err))
return nil, err
}
uss.log.FromContext(ctx).Debug("Successfully fetched usage stats from provider", "duration", time.Since(start), "function", fnName)
return fnMetrics, nil
}
func (uss *UsageStats) RegisterMetricsFunc(fn usagestats.MetricsFunc) {
uss.externalMetrics = append(uss.externalMetrics, fn)
}
func (uss *UsageStats) sendUsageStats(ctx context.Context) error {
func (uss *UsageStats) sendUsageStats(ctx context.Context) (string, error) {
if !uss.Cfg.ReportingEnabled {
return nil
return "", nil
}
uss.log.Debug("Sending anonymous usage stats", "url", usageStatsURL)
ctx, span := uss.tracer.Start(ctx, "UsageStats.BackgroundJob")
defer span.End()
traceID := tracing.TraceIDFromContext(ctx, false)
uss.log.FromContext(ctx).Debug("Sending anonymous usage stats", "url", usageStatsURL)
start := time.Now()
report, err := uss.GetUsageReport(ctx)
if err != nil {
return err
return traceID, err
}
out, err := json.MarshalIndent(report, "", " ")
if err != nil {
return err
return traceID, err
}
data := bytes.NewBuffer(out)
sendUsageStats(uss, data)
return nil
err = sendUsageStats(uss, ctx, data)
if err != nil {
return traceID, err
}
uss.log.FromContext(ctx).Info("Sent usage stats", "duration", time.Since(start))
return traceID, nil
}
// sendUsageStats sends usage statistics.
//
// Stubbable by tests.
var sendUsageStats = func(uss *UsageStats, data *bytes.Buffer) {
go func() {
client := http.Client{Timeout: 5 * time.Second}
resp, err := client.Post(usageStatsURL, "application/json", data)
if err != nil {
uss.log.Error("Failed to send usage stats", "err", err)
return
}
if err := resp.Body.Close(); err != nil {
uss.log.Warn("Failed to close response body", "err", err)
}
}()
var sendUsageStats = func(uss *UsageStats, ctx context.Context, data *bytes.Buffer) error {
ctx, span := uss.tracer.Start(ctx, "UsageStats.Send")
defer span.End()
client := http.Client{Timeout: 5 * time.Second}
req, err := http.NewRequestWithContext(ctx, http.MethodPost, usageStatsURL, data)
if err != nil {
span.SetStatus(codes.Error, fmt.Sprintf("failed to create request for usage stats: %v", err))
return err
}
req.Header.Set("Content-Type", "application/json")
uss.tracer.Inject(ctx, req.Header, span)
resp, err := client.Do(req)
if err != nil {
span.SetStatus(codes.Error, fmt.Sprintf("failed to send usage stats: %v", err))
return err
}
if err := resp.Body.Close(); err != nil {
uss.log.FromContext(ctx).Warn("Failed to close response body after sending usage stats", "err", err)
}
return nil
}
func (uss *UsageStats) GetUsageStatsId(ctx context.Context) string {

View File

@ -12,6 +12,8 @@ import (
"testing"
"time"
"github.com/grafana/grafana/pkg/infra/tracing"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
@ -45,7 +47,7 @@ func TestMetrics(t *testing.T) {
return map[string]interface{}{metricName: 1}, nil
})
err := uss.sendUsageStats(context.Background())
_, err := uss.sendUsageStats(context.Background())
require.NoError(t, err)
t.Run("Given reporting not enabled and sending usage stats", func(t *testing.T) {
@ -54,12 +56,13 @@ func TestMetrics(t *testing.T) {
sendUsageStats = origSendUsageStats
})
statsSent := false
sendUsageStats = func(uss *UsageStats, b *bytes.Buffer) {
sendUsageStats = func(uss *UsageStats, ctx context.Context, b *bytes.Buffer) error {
statsSent = true
return nil
}
uss.Cfg.ReportingEnabled = false
err := uss.sendUsageStats(context.Background())
_, err := uss.sendUsageStats(context.Background())
require.NoError(t, err)
require.False(t, statsSent)
@ -105,8 +108,10 @@ func TestMetrics(t *testing.T) {
})
usageStatsURL = ts.URL
err := uss.sendUsageStats(context.Background())
require.NoError(t, err)
go func() {
_, err := uss.sendUsageStats(context.Background())
require.NoError(t, err)
}()
// Wait for fake HTTP server to receive a request
var resp httpResp
@ -240,5 +245,6 @@ func createService(t *testing.T, cfg setting.Cfg, sqlStore sqlstore.Store, withD
&fakePluginStore{},
kvstore.ProvideService(sqlStore),
routing.NewRouteRegister(),
tracing.InitializeTracerForTest(),
)
}