[Bug]: telemetry truncation time grows with the square of the operation count for size-limited exporters other than LambdaLogExporter

Đang mở
  • Có gì không ổn?
#877 0 bình luận 0 reaction 0 người được giao Xem trên GitHub

Maintainer thường phản hồi trong vòng 1 ngày

Chưa có ai nhận issue này.

Đánh giá

Độ khó
4/5
Thời gian dự kiến
3-5 ngày
Mức phù hợp với người mới
54/100
Loại issue
Lỗi
Độ rõ ràng
Đặc tả rõ ràng
Mức độ hoạt động
Sôi nổi
Công nghệ
aws, java
Lĩnh vực
backend, performance

Hướng nghiên cứu

Start with telemetry-exporter/src/main/java/software/amazon/lambda/durable/telemetry/Truncation.java, especially truncateRecord and Meter.fits, then trace how DurableExecutionTelemetry.exportRecord chooses the truncation path. Compare the built-in exporter renderings and the bounded meter behavior described in the issue. Done means oversized records truncate without the reported repeated full-record measurement cost while preserving the record format and correct truncation results.

Do mô hình lập chỉ mục viết ra từ nội dung của issue.

Mô tả

bug pkg:telemetry
Expected Behavior

For every built-in size-limited exporter, truncating an oversized record takes a small share of the invocation, whatever the number of operations.

Actual Behavior

DurableExecutionTelemetry.exportRecord truncates with Truncation.truncateMeasured for LambdaLogExporter, and with Truncation.truncateRecord for every other exporter. truncateRecord passes bounded = false. So when a rendered record is over its limit, Meter.fits measures it before it considers each operation, once in the result step and again in the operation step. The work grows with the square of the operation count. A record that already fits returns after one measurement.

With the limit and rendering of CloudWatchLogsExporter (256,000 bytes, operations by name), truncating a record of 4,000 simple successful steps took 15.4 s on JDK 21.0.13 at tag v3.0.1. With the same limit and the array rendering, it took 3.5 s for 2,000 operations and 14.8 s for 4,000. The LambdaLogExporter path truncated a 30,000-operation record in 0.6 s.

Every other built-in exporter with a default limit takes the slow path when a record is over its limit: CloudWatchLogsExporter, SQSExporter and EventBridgeExporter (256,000 bytes), DynamoDBExporter (400,000), FirehoseExporter, AuroraExporter, RedshiftExporter and OTelExporter (1,000,000), S3Exporter (5,000,000) and OpenSearchExporter (10,000,000). FileExporter and HttpExporter take it too when a limit is configured.

The time is spent before the invocation returns:

  • TelemetryPlugin.onInvocationEnd waits for the export through ExportScheduler.drain, which has no deadline.
  • DurableExecutor calls onInvocationEnd before it returns the invocation output.
  • The final record also includes operations from earlier invocations. With the default settings it lists every named top-level operation of the execution. So a long execution truncates its accumulated operations when it ends.
  • With EmitMode.ON_CHANGE, the plugin also exports records during the invocation.
Steps to Reproduce

Check out tag v3.0.1. Add this test to telemetry-exporter/src/test/java/software/amazon/lambda/durable/telemetry/, then run mvn -pl telemetry-exporter -am -Djacoco.skip=true -Dtest=TruncationTimeTest -Dsurefire.failIfNoSpecifiedTests=false test:

package software.amazon.lambda.durable.telemetry;

import java.time.Instant;
import java.time.ZoneOffset;
import java.time.format.DateTimeFormatter;
import org.junit.jupiter.api.Test;

class TruncationTimeTest {
    private static final DateTimeFormatter TS =
            DateTimeFormatter.ofPattern("yyyy-MM-dd'T'HH:mm:ss.SSS'Z'").withZone(ZoneOffset.UTC);

    @Test
    void truncateRecordTime() {
        DurableExecutionTelemetryRecord record = new DurableExecutionTelemetryRecord();
        record.executionArn =
                "arn:aws:lambda:us-east-1:123456789012:function:demo:$LATEST/durable-execution/run-1/inv-1";
        record.status = "SUCCEEDED";
        Instant start = Instant.parse("2026-10-28T00:00:00Z");
        for (int i = 0; i < 4000; i++) {
            Instant s = start.plusMillis(i * 10L);
            record.operations.add(new OperationRecord()
                    .id("op-" + i)
                    .name("step-" + i)
                    .type("STEP")
                    .subType("Step")
                    .status("SUCCEEDED")
                    .startTime(TS.format(s))
                    .endTime(TS.format(s.plusMillis(3)))
                    .durationMs(3L)
                    .attempt(1));
        }

        // CloudWatchLogsExporter's limit and rendering: 256,000 bytes, operations by name.
        long t0 = System.nanoTime();
        DurableExecutionTelemetryRecord out =
                Truncation.truncateRecord(record, 256_000, DurableExecutionTelemetryRecord::toByNameWireMap);
        System.out.printf(
                "truncateRecord: %.1f s, kept %d operations, dropped %d%n",
                (System.nanoTime() - t0) / 1e9, out.operations().size(), out.droppedOperations);
    }
}

It prints a time of about 15 s and kept 1568 operations, dropped 2432.

SDK Version

aws-durable-execution-sdk-java-plugin-telemetry-exporter 3.0.1. main has the same truncation code.

Java Version

21

Is this a regression?

No

Additional Context

Two changes would remove most of the cost. Neither changes the public API or the record format.

  1. Measure once after the error causes are removed. Then, in the result step, measure again only after an operation loses its result. With the default content settings no operation has a result. So today that step measures the full record once per operation and drops nothing.
  2. Use the bounded meter for the built-in renderings whose per-drop shrink has a known upper bound. truncateMeasured documents that bound for the record's JSON and for that JSON embedded as one string value. The array and by-name wire maps fit it, and so does the OTel body, which embeds the rendered record as a string. OperationsFormat.BOTH holds the operations array and the derived by-name map, so its bound must cover the shrink of both. A custom render keeps exact checks. For a rendering that the bound covers, the bounded meter returns the same record as checking after every drop.

The Go SDK had the same problem (Go SDK #153: Truncate re-renders the whole record per dropped operation) and fixed it with a binary search over the drop count (Go SDK PR #154: binary-search the Truncate drop count).

Code at the commit I read:

Ngôn ngữ chính
Java
Star
28
Fork
18
Merge trung bình
16 giờ 53 phút
Pull request đã merge (30 ngày)
63

Chuẩn bị môi trường

Bắt đầu từ đâu

  1. Đọc hết issue, rồi đọc hướng dẫn đóng góp của dự án.
  2. Bình luận trên issue rằng bạn sẽ nhận — tránh hai người làm cùng một việc.
  3. Fork repository và làm thay đổi trên một nhánh.
  4. Mở pull request có tham chiếu số hiệu của issue.

Issue khác của aws/aws-durable-execution-sdk-java

Tất cả issue của aws/aws-durable-execution-sdk-java

Issue tương tự

Thêm issue về Java

Nhận issue mới trong hộp thư của bạn

Bản tóm tắt ngắn những issue GitHub phù hợp với người mới.