add init duration

Author: adamantal

collector/receiver/telemetryapireceiver/receiver.go

@@ -45,11 +45,12 @@ const (
 	initialQueueSize = 5
 	scopeName        = "github.com/open-telemetry/opentelemetry-lambda/collector/receiver/telemetryapi"
 
-	logReportFmt           = "REPORT RequestId: %s Duration: %.2f ms Billed Duration: %d ms Memory Size: %d MB Max Memory Used: %d MB"
+	logReportFmt           = "REPORT RequestId: %s Duration: %.2f ms Billed Duration: %.0f ms Memory Size: %.0f MB Max Memory Used: %.0f MB"
 	metricBilledDurationMs = "billedDurationMs"
 	metricDurationMs       = "durationMs"
 	metricMaxMemoryUsedMB  = "maxMemoryUsedMB"
 	metricMemorySizeMB     = "memorySizeMB"
+	metricInitDurationMs   = "initDurationMs"
 )
 
 type telemetryAPIReceiver struct {
@@ -277,21 +278,28 @@ func createReportLogRecord(scopeLog *plog.ScopeLogs, record map[string]interface
 	if !ok {
 		return nil
 	}
-	var durationMs float64
-	var billedDurationMs, memorySizeMB, maxMemoryUsedMB int
+	var durationMs, billedDurationMs, memorySizeMB, maxMemoryUsedMB float64
 	if durationMs, ok = metrics[metricDurationMs].(float64); !ok {
 		return nil
 	}
-	if billedDurationMs, ok = metrics[metricBilledDurationMs].(int); !ok {
+	if billedDurationMs, ok = metrics[metricBilledDurationMs].(float64); !ok {
 		return nil
 	}
-	if memorySizeMB, ok = metrics[metricMemorySizeMB].(int); !ok {
+	if memorySizeMB, ok = metrics[metricMemorySizeMB].(float64); !ok {
 		return nil
 	}
-	if maxMemoryUsedMB, ok = metrics[metricMaxMemoryUsedMB].(int); !ok {
+	if maxMemoryUsedMB, ok = metrics[metricMaxMemoryUsedMB].(float64); !ok {
 		return nil
 	}
 
+	// optionally gather information about cold start time
+	var initDurationMs float64
+	if initDurationMsVal, exists := metrics[metricInitDurationMs]; exists {
+		if val, ok := initDurationMsVal.(float64); ok {
+			initDurationMs = val
+		}
+	}
+
 	// gathering requestId
 	requestId := ""
 	if requestId, ok = record["requestId"].(string); !ok {
@@ -300,16 +308,21 @@ func createReportLogRecord(scopeLog *plog.ScopeLogs, record map[string]interface
 
 	// we have all information available, we can create the log record
 	logRecord := scopeLog.LogRecords().AppendEmpty()
-	logRecord.Body().SetStr(
-		fmt.Sprintf(
-			logReportFmt,
-			requestId,
-			durationMs,
-			billedDurationMs,
-			memorySizeMB, 
-			maxMemoryUsedMB,
-		),
+	logRecord.Attributes().PutStr(semconv.AttributeFaaSInvocationID, requestId)
+
+	// building the body of the log record, optionally adding the init duration
+	body := fmt.Sprintf(
+		logReportFmt,
+		requestId,
+		durationMs,
+		billedDurationMs,
+		memorySizeMB,
+		maxMemoryUsedMB,
 	)
+	if initDurationMs > 0 {
+		body += fmt.Sprintf(" Init Duration: %.2f ms", initDurationMs)
+	}
+	logRecord.Body().SetStr(body)
 
 	return &logRecord
 }

collector/receiver/telemetryapireceiver/receiver_test.go

@@ -539,9 +539,9 @@ func TestCreateLogsWithLogReport(t *testing.T) {
 						"requestId": "test-request-id-123",
 						"metrics": map[string]any{
 							"durationMs":       123.45,
-							"billedDurationMs": 124,
-							"memorySizeMB":     512,
-							"maxMemoryUsedMB":  256,
+							"billedDurationMs": float64(124),
+							"memorySizeMB":     float64(512),
+							"maxMemoryUsedMB":  float64(256),
 						},
 					},
 				},
@@ -664,6 +664,56 @@ func TestCreateLogsWithLogReport(t *testing.T) {
 			expectedLogRecords: 0,
 			expectError:        false,
 		},
+		{
+			desc: "platform.report with logReport enabled - with initDurationMs",
+			slice: []event{
+				{
+					Time: "2022-10-12T00:03:50.000Z",
+					Type: "platform.report",
+					Record: map[string]any{
+						"requestId": "test-request-id-123",
+						"metrics": map[string]any{
+							"durationMs":       123.45,
+							"billedDurationMs": 124.0,
+							"memorySizeMB":     512.0,
+							"maxMemoryUsedMB":  256.0,
+							"initDurationMs":   50.5,
+						},
+					},
+				},
+			},
+			logReport:          true,
+			expectedLogRecords: 1,
+			expectedType:       "platform.report",
+			expectedTimestamp:  "2022-10-12T00:03:50.000Z",
+			expectedBody:       "REPORT RequestId: test-request-id-123 Duration: 123.45 ms Billed Duration: 124 ms Memory Size: 512 MB Max Memory Used: 256 MB Init Duration: 50.50 ms",
+			expectError:        false,
+		},
+		{
+			desc: "platform.report with logReport enabled - with invalid initDurationMs type",
+			slice: []event{
+				{
+					Time: "2022-10-12T00:03:50.000Z",
+					Type: "platform.report",
+					Record: map[string]any{
+						"requestId": "test-request-id-123",
+						"metrics": map[string]any{
+							"durationMs":       123.45,
+							"billedDurationMs": 124.0,
+							"memorySizeMB":     512.0,
+							"maxMemoryUsedMB":  256.0,
+							"initDurationMs":   "invalid-string",
+						},
+					},
+				},
+			},
+			logReport:          true,
+			expectedLogRecords: 1,
+			expectedType:       "platform.report",
+			expectedTimestamp:  "2022-10-12T00:03:50.000Z",
+			expectedBody:       "REPORT RequestId: test-request-id-123 Duration: 123.45 ms Billed Duration: 124 ms Memory Size: 512 MB Max Memory Used: 256 MB",
+			expectError:        false,
+		},
 	}
 	for _, tc := range testCases {
 		t.Run(tc.desc, func(t *testing.T) {