OpenCensus를 사용하여 Spanner 구성요소의 지연 시간 검사

참고: OpenCensus는 지원 중단되었습니다. OpenTelemetry를 사용하여 Spanner 관측 가능성 측정항목을 캡처하고 시각화하는 것이 좋습니다. 자세한 내용은 OpenTelemetry를 사용하여 Spanner 구성요소의 지연 시간 검사를 참조하세요.

이 주제에서는 Spanner 구성요소를 검사하여 지연 시간의 원인을 찾고 OpenCensus를 사용하여 해당 지연 시간을 시각화하는 방법을 설명합니다. 이 주제의 구성요소에 대한 대략적인 개요는 Spanner 요청의 지연 시간 지점을 참조하세요.

Spanner 클라이언트 라이브러리는 OpenCensus 계측 프레임워크를 사용하여 통계와 trace를 제공합니다. 이 프레임워크는 클라이언트 내부에 대한 유용한 정보를 제공하며 엔드 투 엔드(왕복) 지연 시간 문제를 해결하는 데 도움이 됩니다. 기본적으로 프레임워크는 사용 중지되어 있습니다.

시작하기 전에

지연 시간 지점 식별의 절차에 따라 지연 시간을 표시하는 구성요소를 찾습니다.

클라이언트 왕복 지연 시간 캡처 및 시각화

클라이언트 왕복 지연 시간은 클라이언트가 Google 프런트엔드(GFE) 및 Spanner API 프런트엔드를 통해 데이터베이스로 전송한 Spanner API 요청의 첫 번째 바이트와 클라이언트가 데이터베이스에서 수신한 응답의 마지막 바이트 사이의 시간(밀리초)입니다.

클라이언트 왕복 지연 시간 캡처

참고: 이 유형의 지연 시간 캡처를 시작하기 전에 OpenCensus와 관련된 커스텀 측정항목을 숙지하세요. OpenCensus 측정항목 라이브러리와 Stackdriver 내보내기 도구를 애플리케이션에서 사용하도록 설정해야 합니다. 이를 사용할 수 있는 방법에 대한 자세한 내용은 OpenCensus 설치를 참조하세요.

클라이언트 왕복 지연 시간을 다음 언어로 캡처할 수 있습니다.

Java

static void captureGrpcMetric(DatabaseClient dbClient) {
  // Add io.grpc:grpc-census and io.opencensus:opencensus-exporter-stats-stackdriver
  //  dependencies to enable gRPC metrics.

  // Register basic gRPC views.
  RpcViews.registerClientGrpcBasicViews();

  // Enable OpenCensus exporters to export metrics to Stackdriver Monitoring.
  // Exporters use Application Default Credentials to authenticate.
  // See https://developers.google.com/identity/protocols/application-default-credentials
  // for more details.
  try {
    StackdriverStatsExporter.createAndRegister();
  } catch (IOException | IllegalStateException e) {
    System.out.println("Error during StackdriverStatsExporter");
  }

  try (ResultSet resultSet =
      dbClient
          .singleUse() // Execute a single read or query against Cloud Spanner.
          .executeQuery(Statement.of("SELECT SingerId, AlbumId, AlbumTitle FROM Albums"))) {
    while (resultSet.next()) {
      System.out.printf(
          "%d %d %s", resultSet.getLong(0), resultSet.getLong(1), resultSet.getString(2));
    }
  }
}

Go

import (
	"context"
	"fmt"
	"io"
	"regexp"

	"cloud.google.com/go/spanner"
	"google.golang.org/api/iterator"

	"contrib.go.opencensus.io/exporter/stackdriver"
	"go.opencensus.io/plugin/ocgrpc"
	"go.opencensus.io/stats/view"
)

var validDatabasePattern = regexp.MustCompile("^projects/(?P<project>[^/]+)/instances/(?P<instance>[^/]+)/databases/(?P<database>[^/]+)$")

func queryWithGRPCMetric(w io.Writer, db string) error {
	projectID, _, _, err := parseDatabaseName(db)
	if err != nil {
		return err
	}

	ctx := context.Background()
	client, err := spanner.NewClient(ctx, db)
	if err != nil {
		return err
	}
	defer client.Close()

	// Register OpenCensus views.
	if err := view.Register(ocgrpc.DefaultClientViews...); err != nil {
		return err
	}

	// Create OpenCensus Stackdriver exporter.
	sd, err := stackdriver.NewExporter(stackdriver.Options{
		ProjectID: projectID,
	})
	if err != nil {
		return err
	}
	// It is imperative to invoke flush before your main function exits
	defer sd.Flush()

	// Start the metrics exporter
	sd.StartMetricsExporter()
	defer sd.StopMetricsExporter()

	stmt := spanner.Statement{SQL: `SELECT SingerId, AlbumId, AlbumTitle FROM Albums`}
	iter := client.Single().Query(ctx, stmt)
	defer iter.Stop()
	for {
		row, err := iter.Next()
		if err == iterator.Done {
			return nil
		}
		if err != nil {
			return err
		}
		var singerID, albumID int64
		var albumTitle string
		if err := row.Columns(&singerID, &albumID, &albumTitle); err != nil {
			return err
		}
		fmt.Fprintf(w, "%d %d %s\n", singerID, albumID, albumTitle)
	}
}

func parseDatabaseName(databaseUri string) (project, instance, database string, err error) {
	matches := validDatabasePattern.FindStringSubmatch(databaseUri)
	if len(matches) == 0 {
		return "", "", "", fmt.Errorf("failed to parse database name from %q according to pattern %q",
			databaseUri, validDatabasePattern.String())
	}
	return matches[1], matches[2], matches[3], nil
}

클라이언트 왕복 지연 시간 시각화

측정항목을 검색한 후 Cloud Monitoring에서 클라이언트 왕복 지연 시간을 시각화할 수 있습니다.

다음 예시는 클라이언트 왕복 지연 시간 측정항목의 5번째 백분위수 지연 시간을 보여주는 그래프입니다. 백분위수 지연 시간을 50번째 또는 99번째 백분위수로 변경하려면 애그리게이터 메뉴를 사용합니다.

프로그램에서 roundtrip_latency라는 OpenCensus 뷰를 만듭니다. 이 문자열은 Cloud Monitoring으로 내보낼 때 측정항목 이름의 일부가 됩니다.

GFE 지연 시간 캡처 및 시각화

Google 프런트엔드(GFE) 지연 시간은 Google 네트워크에서 클라이언트의 리모트 프로시져 콜을 수신한 후 GFE가 응답의 첫 번째 바이트를 수신할 때까지의 시간(밀리초)입니다.

GFE 지연 시간 캡처

GFE 지연 시간을 다음 언어로 캡처할 수 있습니다.

Java

static void captureGfeMetric(DatabaseClient dbClient) {
  // Capture GFE Latency.
  SpannerRpcViews.registerGfeLatencyView();

  // Capture GFE Latency and GFE Header missing count.
  // SpannerRpcViews.registerGfeLatencyAndHeaderMissingCountViews();

  // Capture only GFE Header missing count.
  // SpannerRpcViews.registerGfeHeaderMissingCountView();

  // Enable OpenCensus exporters to export metrics to Stackdriver Monitoring.
  // Exporters use Application Default Credentials to authenticate.
  // See https://developers.google.com/identity/protocols/application-default-credentials
  // for more details.
  try {
    StackdriverStatsExporter.createAndRegister();
  } catch (IOException | IllegalStateException e) {
    System.out.println("Error during StackdriverStatsExporter");
  }

  try (ResultSet resultSet =
      dbClient
          .singleUse() // Execute a single read or query against Cloud Spanner.
          .executeQuery(Statement.of("SELECT SingerId, AlbumId, AlbumTitle FROM Albums"))) {
    while (resultSet.next()) {
      System.out.printf(
          "%d %d %s", resultSet.getLong(0), resultSet.getLong(1), resultSet.getString(2));
    }
  }
}

Go

// We are in the process of adding support in the Cloud Spanner Go Client Library
// to capture the gfe_latency metric.

import (
	"context"
	"fmt"
	"io"
	"strconv"
	"strings"

	spanner "cloud.google.com/go/spanner/apiv1"
	sppb "cloud.google.com/go/spanner/apiv1/spannerpb"
	gax "github.com/googleapis/gax-go/v2"
	"google.golang.org/grpc"
	"google.golang.org/grpc/metadata"

	"contrib.go.opencensus.io/exporter/stackdriver"
	"go.opencensus.io/stats"
	"go.opencensus.io/stats/view"
	"go.opencensus.io/tag"
)

// OpenCensus Tag, Measure and View.
var (
	KeyMethod    = tag.MustNewKey("grpc_client_method")
	GFELatencyMs = stats.Int64("cloud.google.com/go/spanner/gfe_latency",
		"Latency between Google's network receives an RPC and reads back the first byte of the response", "ms")
	GFELatencyView = view.View{
		Name:        "cloud.google.com/go/spanner/gfe_latency",
		Measure:     GFELatencyMs,
		Description: "Latency between Google's network receives an RPC and reads back the first byte of the response",
		Aggregation: view.Distribution(0.0, 0.01, 0.05, 0.1, 0.3, 0.6, 0.8, 1.0, 2.0, 3.0, 4.0, 5.0, 6.0, 8.0, 10.0, 13.0,
			16.0, 20.0, 25.0, 30.0, 40.0, 50.0, 65.0, 80.0, 100.0, 130.0, 160.0, 200.0, 250.0,
			300.0, 400.0, 500.0, 650.0, 800.0, 1000.0, 2000.0, 5000.0, 10000.0, 20000.0, 50000.0,
			100000.0),
		TagKeys: []tag.Key{KeyMethod}}
)

func queryWithGFELatency(w io.Writer, db string) error {
	projectID, _, _, err := parseDatabaseName(db)
	if err != nil {
		return err
	}

	ctx := context.Background()
	client, err := spanner.NewClient(ctx)
	if err != nil {
		return err
	}
	defer client.Close()

	// Register OpenCensus views.
	err = view.Register(&GFELatencyView)
	if err != nil {
		return err
	}

	// Create OpenCensus Stackdriver exporter.
	sd, err := stackdriver.NewExporter(stackdriver.Options{
		ProjectID: projectID,
	})
	if err != nil {
		return err
	}
	// It is imperative to invoke flush before your main function exits
	defer sd.Flush()

	// Start the metrics exporter
	sd.StartMetricsExporter()
	defer sd.StopMetricsExporter()

	// Create a session.
	req := &sppb.CreateSessionRequest{Database: db}
	session, err := client.CreateSession(ctx, req)
	if err != nil {
		return err
	}

	// Execute a SQL query and retrieve the GFE server-timing header in gRPC metadata.
	req2 := &sppb.ExecuteSqlRequest{
		Session: session.Name,
		Sql:     `SELECT SingerId, AlbumId, AlbumTitle FROM Albums`,
	}
	var md metadata.MD
	resultSet, err := client.ExecuteSql(ctx, req2, gax.WithGRPCOptions(grpc.Header(&md)))
	if err != nil {
		return err
	}
	for _, row := range resultSet.GetRows() {
		for _, value := range row.GetValues() {
			fmt.Fprintf(w, "%s ", value.GetStringValue())
		}
		fmt.Fprintf(w, "\n")
	}

	// The format is: "server-timing: gfet4t7; dur=[GFE latency in ms]"
	srvTiming := md.Get("server-timing")[0]
	gfeLtcy, err := strconv.Atoi(strings.TrimPrefix(srvTiming, "gfet4t7; dur="))
	if err != nil {
		return err
	}
	// Record GFE t4t7 latency with OpenCensus.
	ctx, err = tag.New(ctx, tag.Insert(KeyMethod, "ExecuteSql"))
	if err != nil {
		return err
	}
	stats.Record(ctx, GFELatencyMs.M(int64(gfeLtcy)))

	return nil
}

GFE 지연 시간 시각화

측정항목을 검색한 후 Cloud Monitoring에서 GFE 지연 시간을 시각화할 수 있습니다.

다음은 GFE 지연 시간 측정항목에 대한 5번째 백분위수 지연 시간을 보여주는 그래프의 예시입니다. 백분위수 지연 시간을 50번째 또는 99번째 백분위수로 변경하려면 애그리게이터 메뉴를 사용합니다.

프로그램에서 gfe_latency라는 OpenCensus 뷰를 만듭니다. 이 문자열은 Cloud Monitoring으로 내보낼 때 측정항목 이름의 일부가 됩니다.

Spanner API 요청 지연 시간 캡처 및 시각화

Spanner API 요청 지연 시간은 Spanner API 프런트엔드에서 수신한 요청의 첫 번째 바이트와 Spanner API 프런트엔드에서 전송한 응답의 마지막 바이트 간의 시간(초)입니다.

Spanner API 요청 지연 시간 캡처

기본적으로 이 지연 시간은 Cloud Monitoring 측정항목의 일부로 제공됩니다. 캡처하고 내보내기 위해 별도의 작업을 수행할 필요가 없습니다.

Spanner API 요청 지연 시간 시각화

측정항목 탐색기 차트 도구를 사용하여 Cloud Monitoring에서 spanner.googleapis.com/api/request_latencies 측정항목에 대한 그래프를 시각화할 수 있습니다.

다음은 Spanner API 요청 지연 시간 측정항목에 대한 5번째 백분위수 지연 시간을 보여주는 그래프의 예시입니다. 백분위수 지연 시간을 50번째 또는 99번째 백분위수로 변경하려면 애그리게이터 메뉴를 사용합니다.

쿼리 지연 시간 캡처 및 시각화

쿼리 지연 시간은 Spanner 데이터베이스에서 SQL 쿼리를 실행하는 데 걸리는 시간(밀리초)입니다.

쿼리 지연 시간 캡처

다음 언어의 쿼리 지연 시간을 캡처할 수 있습니다.

Java

private static final String MILLISECOND = "ms";
static final List<Double> RPC_MILLIS_BUCKET_BOUNDARIES =
    Collections.unmodifiableList(
        Arrays.asList(
            0.0, 0.01, 0.05, 0.1, 0.3, 0.6, 0.8, 1.0, 2.0, 3.0, 4.0, 5.0, 6.0, 8.0, 10.0, 13.0,
            16.0, 20.0, 25.0, 30.0, 40.0, 50.0, 65.0, 80.0, 100.0, 130.0, 160.0, 200.0, 250.0,
            300.0, 400.0, 500.0, 650.0, 800.0, 1000.0, 2000.0, 5000.0, 10000.0, 20000.0, 50000.0,
            100000.0));
static final Aggregation AGGREGATION_WITH_MILLIS_HISTOGRAM =
    Distribution.create(BucketBoundaries.create(RPC_MILLIS_BUCKET_BOUNDARIES));

static MeasureDouble QUERY_STATS_ELAPSED =
    MeasureDouble.create(
        "cloud.google.com/java/spanner/query_stats_elapsed",
        "The execution of the query",
        MILLISECOND);

// Register the view. It is imperative that this step exists,
// otherwise recorded metrics will be dropped and never exported.
static View QUERY_STATS_LATENCY_VIEW = View
    .create(Name.create("cloud.google.com/java/spanner/query_stats_elapsed"),
        "The execution of the query",
        QUERY_STATS_ELAPSED,
        AGGREGATION_WITH_MILLIS_HISTOGRAM,
        Collections.emptyList());

static ViewManager manager = Stats.getViewManager();
private static final StatsRecorder STATS_RECORDER = Stats.getStatsRecorder();

static void captureQueryStatsMetric(DatabaseClient dbClient) {
  manager.registerView(QUERY_STATS_LATENCY_VIEW);

  // Enable OpenCensus exporters to export metrics to Cloud Monitoring.
  // Exporters use Application Default Credentials to authenticate.
  // See https://developers.google.com/identity/protocols/application-default-credentials
  // for more details.
  try {
    StackdriverStatsExporter.createAndRegister();
  } catch (IOException | IllegalStateException e) {
    System.out.println("Error during StackdriverStatsExporter");
  }

  try (ResultSet resultSet = dbClient.singleUse()
      .analyzeQuery(Statement.of("SELECT SingerId, AlbumId, AlbumTitle FROM Albums"),
          QueryAnalyzeMode.PROFILE)) {

    while (resultSet.next()) {
      System.out.printf(
          "%d %d %s", resultSet.getLong(0), resultSet.getLong(1), resultSet.getString(2));
    }
    Value value = resultSet.getStats().getQueryStats()
        .getFieldsOrDefault("elapsed_time", Value.newBuilder().setStringValue("0 msecs").build());
    double elapasedTime = Double.parseDouble(value.getStringValue().replaceAll(" msecs", ""));
    STATS_RECORDER.newMeasureMap()
        .put(QUERY_STATS_ELAPSED, elapasedTime)
        .record();
  }
}

Go

import (
	"context"
	"fmt"
	"io"
	"strconv"
	"strings"

	"cloud.google.com/go/spanner"
	"google.golang.org/api/iterator"

	"contrib.go.opencensus.io/exporter/stackdriver"
	"go.opencensus.io/stats"
	"go.opencensus.io/stats/view"
	"go.opencensus.io/tag"
)

// OpenCensus Tag, Measure and View.
var (
	QueryStatsElapsed = stats.Float64("cloud.google.com/go/spanner/query_stats_elapsed",
		"The execution of the query", "ms")
	QueryStatsLatencyView = view.View{
		Name:        "cloud.google.com/go/spanner/query_stats_elapsed",
		Measure:     QueryStatsElapsed,
		Description: "The execution of the query",
		Aggregation: view.Distribution(0.0, 0.01, 0.05, 0.1, 0.3, 0.6, 0.8, 1.0, 2.0, 3.0, 4.0, 5.0, 6.0, 8.0, 10.0, 13.0,
			16.0, 20.0, 25.0, 30.0, 40.0, 50.0, 65.0, 80.0, 100.0, 130.0, 160.0, 200.0, 250.0,
			300.0, 400.0, 500.0, 650.0, 800.0, 1000.0, 2000.0, 5000.0, 10000.0, 20000.0, 50000.0,
			100000.0),
		TagKeys: []tag.Key{}}
)

func queryWithQueryStats(w io.Writer, db string) error {
	projectID, _, _, err := parseDatabaseName(db)
	if err != nil {
		return err
	}

	ctx := context.Background()
	client, err := spanner.NewClient(ctx, db)
	if err != nil {
		return err
	}
	defer client.Close()

	// Register OpenCensus views.
	err = view.Register(&QueryStatsLatencyView)
	if err != nil {
		return err
	}

	// Create OpenCensus Stackdriver exporter.
	sd, err := stackdriver.NewExporter(stackdriver.Options{
		ProjectID: projectID,
	})
	if err != nil {
		return err
	}
	// It is imperative to invoke flush before your main function exits
	defer sd.Flush()

	// Start the metrics exporter
	sd.StartMetricsExporter()
	defer sd.StopMetricsExporter()

	// Execute a SQL query and get the query stats.
	stmt := spanner.Statement{SQL: `SELECT SingerId, AlbumId, AlbumTitle FROM Albums`}
	iter := client.Single().QueryWithStats(ctx, stmt)
	defer iter.Stop()
	for {
		row, err := iter.Next()
		if err == iterator.Done {
			// Record query execution time with OpenCensus.
			elapasedTime := iter.QueryStats["elapsed_time"].(string)
			elapasedTimeMs, err := strconv.ParseFloat(strings.TrimSuffix(elapasedTime, " msecs"), 64)
			if err != nil {
				return err
			}
			stats.Record(ctx, QueryStatsElapsed.M(elapasedTimeMs))
			return nil
		}
		if err != nil {
			return err
		}
		var singerID, albumID int64
		var albumTitle string
		if err := row.Columns(&singerID, &albumID, &albumTitle); err != nil {
			return err
		}
		fmt.Fprintf(w, "%d %d %s\n", singerID, albumID, albumTitle)
	}
}

쿼리 지연 시간 시각화

측정항목을 검색한 후 Cloud Monitoring에서 쿼리 지연 시간을 시각화할 수 있습니다.

다음은 쿼리 지연 시간 측정항목에 대한 5번째 백분위수 지연 시간을 보여주는 그래프의 예시입니다. 백분위수 지연 시간을 50번째 또는 99번째 백분위수로 변경하려면 애그리게이터 메뉴를 사용합니다.

프로그램에서 query_stats_elapsed라는 OpenCensus 뷰를 만듭니다. 이 문자열은 Cloud Monitoring으로 내보낼 때 측정항목 이름의 일부가 됩니다.

다음 단계

• OpenCensus 자세히 알아보기

• 측정항목을 사용하여 지연 시간을 진단하는 방법을 알아보세요.