VPLAY-12472 [CSAT][AAMP] Add logging for buffering start/end and buffering duration by lashmintha · Pull Request #1160 · rdkcentral/aamp

lashmintha · 2026-03-10T13:39:37Z

Reason for change: Added buffering duration in the telementary along with buffer start and end
Risks: Low
Test Procedure: Refer jira ticket
Priority: P1

Copilot

Pull request overview

Adds telemetry/logging to capture buffering start/end events along with buffering duration.

Changes:

Introduces a new member to track buffering start time for duration calculations.
Updates buffer change event handling to compute and log buffering duration.
Sends buffering duration (dur) as an int field in telemetry events.

Reviewed changes

Copilot reviewed 2 out of 2 changed files in this pull request and generated 4 comments.

File	Description
priv_aamp.h	Adds member variable to store buffering start time.
priv_aamp.cpp	Computes/logs buffering duration and includes it in telemetry payload.

priv_aamp.cpp

priv_aamp.h

priv_aamp.cpp

Copilot

Pull request overview

Copilot reviewed 2 out of 2 changed files in this pull request and generated 3 comments.

priv_aamp.cpp

Copilot

Pull request overview

Copilot reviewed 2 out of 2 changed files in this pull request and generated 3 comments.

priv_aamp.h

priv_aamp.cpp

…ering duration Reason for change: Added buffering duration in the telementary along with buffer start and end Risks: Low Test Procedure: Refer jira ticket Priority: P1 Signed-off-by: lashminthaj <lashminthaj17@gmail.com>

Copilot

Pull request overview

Copilot reviewed 2 out of 2 changed files in this pull request and generated 5 comments.

priv_aamp.cpp

Copilot · 2026-03-24T14:34:41Z

priv_aamp.cpp

 	std::string telemetryName = bufferingStopped?"VideoBufferingStart":"VideoBufferingEnd";
-	at2.send(telemetryName,{/*int data*/},{/*string data*/},{/*float data*/});
+	std::map<std::string,int> intData;
+	intData["dur"] = static_cast<int>(bufferingDurationMs);


bufferingDurationMs is cast from long long to int for telemetry without bounds checking. If the value is negative (time jump) or exceeds INT_MAX, this will wrap/truncate and emit incorrect telemetry. Consider clamping to a safe range before casting (e.g., 0..INT_MAX) or changing the telemetry schema to avoid narrowing if that’s supported.

Suggested change

intData["dur"] = static_cast<int>(bufferingDurationMs);

long long clampedDurationMs = bufferingDurationMs;

if (clampedDurationMs < 0)

{

clampedDurationMs = 0;

}

else if (clampedDurationMs > static_cast<long long>(INT_MAX))

{

clampedDurationMs = static_cast<long long>(INT_MAX);

}

intData["dur"] = static_cast<int>(clampedDurationMs);

priv_aamp.cpp

Signed-off-by: Philip Stroffolino <philip_stroffolino@cable.comcast.com>

Copilot

Pull request overview

Copilot reviewed 2 out of 2 changed files in this pull request and generated 3 comments.

Copilot · 2026-03-24T18:49:14Z

priv_aamp.h

+	// from GStreamer error callbacks (via ScheduleRetune), with no common lock held at the
+	// call site. The compound check-and-set operations in SendBufferChangeEvent use
+	// compare_exchange_strong / exchange to keep the read-modify-write sequences race-free.
+	std::atomic<long long> mBufferingStartTimeMS;


mBufferingStartTimeMS has no in-class initializer. There are alternate PrivateInstanceAAMP constructor definitions used by unit-test fakes/mocks (e.g. test/utests/drm/mocks/aampMocks.cpp, test/utests/fakes/FakePrivateInstanceAAMP.cpp) that don't initialize this new member, leaving the atomic's value indeterminate. That can yield undefined behavior / bogus buffering durations when SendBufferChangeEvent() does compare_exchange_strong/exchange. Prefer giving the member an in-class initializer (e.g., {-1}) or updating all constructors to initialize it.

Suggested change

std::atomic<long long> mBufferingStartTimeMS;

std::atomic<long long> mBufferingStartTimeMS{-1};

priv_aamp.cpp

Copilot · 2026-03-24T18:49:15Z

priv_aamp.cpp

 	std::string telemetryName = bufferingStopped?"VideoBufferingStart":"VideoBufferingEnd";
-	at2.send(telemetryName,{/*int data*/},{/*string data*/},{/*float data*/});
+	std::map<std::string,int> intData;
+	intData["dur"] = static_cast<int>(bufferingDurationMs);


bufferingDurationMs is a long long but is narrowed to int for telemetry. If the buffering episode (or an unpaired start/end due to an error path) exceeds INT_MAX milliseconds, the cast becomes implementation-defined and can produce incorrect/negative values. Consider clamping to std::numeric_limits<int>::max() (or sending duration via a wider telemetry field type if available).

Suggested change

intData["dur"] = static_cast<int>(bufferingDurationMs);

int durationForTelemetry;

if (bufferingDurationMs < 0)

{

durationForTelemetry = 0;

}

else if (bufferingDurationMs > INT_MAX)

{

durationForTelemetry = INT_MAX;

}

else

{

durationForTelemetry = static_cast<int>(bufferingDurationMs);

}

intData["dur"] = durationForTelemetry;

Signed-off-by: Philip Stroffolino <philip_stroffolino@cable.comcast.com>

Co-authored-by: Copilot <175728472+Copilot@users.noreply.github.com>

Copilot

Pull request overview

Copilot reviewed 3 out of 3 changed files in this pull request and generated 2 comments.

Copilot · 2026-03-25T00:41:22Z

priv_aamp.cpp

+	std::map<std::string,int> intData;
+	intData["dur"] = static_cast<int>(bufferingDurationMs);
+	at2.send(telemetryName, intData, {/*string data*/}, {/*float data*/});


bufferingDurationMs is a long long but is unconditionally narrowed to int for telemetry (static_cast<int>(bufferingDurationMs)). If a buffering episode is very long (or if the start timestamp is ever corrupted/uninitialized), this can overflow and send a negative/garbled duration. Clamp to INT_MAX (and 0) before casting, or extend the telemetry API usage to carry a 64-bit value if supported.

Copilot · 2026-03-25T00:41:23Z

test/utests/tests/PrivAampTests/PrivAampTests.cpp

+	p_aamp->SendBufferChangeEvent(true);
+	long long t2 = p_aamp->GetBufferingStartTimeMS();
+	ASSERT_GE(t2, 0LL);
+	EXPECT_GT(t2, t1); // monotonic: second start must be later than first


This test asserts EXPECT_GT(t2, t1) using NOW_STEADY_TS_MS, which is a millisecond-truncated steady-clock counter. On platforms with coarse clock resolution, t2 can legitimately equal t1 even when time advanced (still monotonic), making the test flaky. Consider relaxing to EXPECT_GE(t2, t1) or structuring the assertion to avoid requiring a strict 1ms tick boundary.

Suggested change

EXPECT_GT(t2, t1); // monotonic: second start must be later than first

EXPECT_GE(t2, t1); // monotonic: second start must not be earlier than first

lashmintha requested a review from a team as a code owner March 10, 2026 13:39

Copilot AI review requested due to automatic review settings March 10, 2026 13:39

Copilot AI reviewed Mar 10, 2026

View reviewed changes

priv_aamp.cpp Show resolved Hide resolved

priv_aamp.cpp Show resolved Hide resolved

priv_aamp.h Outdated Show resolved Hide resolved

priv_aamp.cpp Show resolved Hide resolved

lashmintha force-pushed the feature/VPLAY-12472_2 branch from e0c6209 to d217590 Compare March 10, 2026 13:55

Copilot started reviewing on behalf of lashmintha March 10, 2026 13:55 View session

Vinish100 reviewed Mar 10, 2026

View reviewed changes

priv_aamp.cpp Show resolved Hide resolved

Copilot AI review requested due to automatic review settings March 11, 2026 15:11

Copilot started reviewing on behalf of pstroffolino March 11, 2026 15:13 View session

Copilot AI reviewed Mar 11, 2026

View reviewed changes

priv_aamp.cpp Show resolved Hide resolved

priv_aamp.cpp Show resolved Hide resolved

priv_aamp.cpp Outdated Show resolved Hide resolved

Copilot AI review requested due to automatic review settings March 19, 2026 16:00

Copilot AI reviewed Mar 19, 2026

View reviewed changes

priv_aamp.h Outdated Show resolved Hide resolved

priv_aamp.h Show resolved Hide resolved

priv_aamp.cpp Outdated Show resolved Hide resolved

lashmintha force-pushed the feature/VPLAY-12472_2 branch from 8f9f94f to 65786fd Compare March 23, 2026 15:51

Merge branch 'dev_sprint_25_2' into feature/VPLAY-12472_2

edaa138

Copilot AI review requested due to automatic review settings March 24, 2026 14:28

Copilot started reviewing on behalf of pstroffolino March 24, 2026 14:29 View session

Copilot AI reviewed Mar 24, 2026

View reviewed changes

pstroffolino and others added 2 commits March 24, 2026 14:02

Reason for Change: fixes for various copilot raised edge cases

23c1f11

Signed-off-by: Philip Stroffolino <philip_stroffolino@cable.comcast.com>

Merge branch 'dev_sprint_25_2' into feature/VPLAY-12472_2

174ba8b

Copilot AI review requested due to automatic review settings March 24, 2026 18:45

Copilot started reviewing on behalf of pstroffolino March 24, 2026 18:45 View session

Copilot AI reviewed Mar 24, 2026

View reviewed changes

pstroffolino and others added 2 commits March 24, 2026 19:03

Reason for Change: l1 test added

7bacb32

Signed-off-by: Philip Stroffolino <philip_stroffolino@cable.comcast.com>

Apply suggestions from code review

0a41cff

Co-authored-by: Copilot <175728472+Copilot@users.noreply.github.com>

Copilot AI review requested due to automatic review settings March 25, 2026 00:36

Copilot started reviewing on behalf of pstroffolino March 25, 2026 00:37 View session

pstroffolino merged commit 1284ce2 into dev_sprint_25_2 Mar 25, 2026
9 checks passed

pstroffolino deleted the feature/VPLAY-12472_2 branch March 25, 2026 00:37

Copilot AI reviewed Mar 25, 2026

View reviewed changes

-	intData["dur"] = static_cast<int>(bufferingDurationMs);
+	long long clampedDurationMs = bufferingDurationMs;
+	if (clampedDurationMs < 0)
+	{
+		clampedDurationMs = 0;
+	}
+	else if (clampedDurationMs > static_cast<long long>(INT_MAX))
+	{
+		clampedDurationMs = static_cast<long long>(INT_MAX);
+	}
+	intData["dur"] = static_cast<int>(clampedDurationMs);

	std::atomic<long long> mBufferingStartTimeMS;
	std::atomic<long long> mBufferingStartTimeMS{-1};

-	intData["dur"] = static_cast<int>(bufferingDurationMs);
+	int durationForTelemetry;
+	if (bufferingDurationMs < 0)
+	{
+		durationForTelemetry = 0;
+	}
+	else if (bufferingDurationMs > INT_MAX)
+	{
+		durationForTelemetry = INT_MAX;
+	}
+	else
+	{
+		durationForTelemetry = static_cast<int>(bufferingDurationMs);
+	}
+	intData["dur"] = durationForTelemetry;

	EXPECT_GT(t2, t1); // monotonic: second start must be later than first
	EXPECT_GE(t2, t1); // monotonic: second start must not be earlier than first

Conversation

lashmintha commented Mar 10, 2026

Uh oh!

Copilot AI left a comment

Choose a reason for hiding this comment

Pull request overview

Reviewed changes

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Copilot AI left a comment

Choose a reason for hiding this comment

Pull request overview

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Copilot AI left a comment

Choose a reason for hiding this comment

Pull request overview

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Copilot AI left a comment

Choose a reason for hiding this comment

Pull request overview

Uh oh!

Uh oh!

Uh oh!

Copilot AI Mar 24, 2026

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

Copilot AI left a comment

Choose a reason for hiding this comment

Pull request overview

Uh oh!

Copilot AI Mar 24, 2026

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Copilot AI Mar 24, 2026

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Copilot AI left a comment

Choose a reason for hiding this comment

Pull request overview

Uh oh!

Copilot AI Mar 25, 2026

Choose a reason for hiding this comment

Uh oh!

Copilot AI Mar 25, 2026

Choose a reason for hiding this comment

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

4 participants