Open stevemayhew opened 1 year ago
Logging of time from several hours of playback on an SEI Android TV boxes:
10-02 20:42:06.081 17353 17353 D ExoGeekStat: Now (delta) [NTP: 2023-10-02T20:42:06.136, Window: 2023-10-02T20:42:06.138 (2), currentTimeMillis(): 2023-10-02T20:42:06.076 (-60)
10-02 20:42:12.070 17353 17353 D ExoGeekStat: Now (delta) [NTP: 2023-10-02T20:42:12.129, Window: 2023-10-02T20:42:12.129 (0), currentTimeMillis(): 2023-10-02T20:42:12.067 (-62)
10-02 20:42:18.057 17353 17353 D ExoGeekStat: Now (delta) [NTP: 2023-10-02T20:42:18.117, Window: 2023-10-02T20:42:18.116 (-1), currentTimeMillis(): 2023-10-02T20:42:18.054 (-63)
10-02 20:42:24.056 17353 17353 D ExoGeekStat: Now (delta) [NTP: 2023-10-02T20:42:24.116, Window: 2023-10-02T20:42:24.116 (0), currentTimeMillis(): 2023-10-02T20:42:24.054 (-62)
...
10-03 08:30:38.037 17353 17353 D ExoGeekStat: Now (delta) [NTP: 2023-10-03T08:30:38.210, Window: 2023-10-03T08:30:38.098 (-112), currentTimeMillis(): 2023-10-03T08:30:38.036 (-174)
10-03 08:30:44.041 17353 17353 D ExoGeekStat: Now (delta) [NTP: 2023-10-03T08:30:44.212, Window: 2023-10-03T08:30:44.101 (-111), currentTimeMillis(): 2023-10-03T08:30:44.039 (-173)
10-03 08:30:50.040 17353 17353 D ExoGeekStat: Now (delta) [NTP: 2023-10-03T08:30:50.212, Window: 2023-10-03T08:30:50.101 (-111), currentTimeMillis(): 2023-10-03T08:30:50.039 (-173)
10-03 08:30:56.073 17353 17353 D ExoGeekStat: Now (delta) [NTP: 2023-10-03T08:30:56.246, Window: 2023-10-03T08:30:56.134 (-112), currentTimeMillis(): 2023-10-03T08:30:56.072 (-174)
The logged values are:
Window.getCurrentUnixTimeMs()
System.currentTimeMillis()
Here is the logging code snippet:
SNTPClient.getDate(TimeZone.getDefault(), new SNTPClient.Listener() {
@Override
public void onTimeResponse(long ntpDate, Exception ex) {
timeCheckActive = false;
Timeline timeline = player.getCurrentTimeline();
if (!timeline.isEmpty()) {
StringBuilder logString = new StringBuilder();
Formatter formatter = new Formatter(logString);
int windowIndex = player.getCurrentWindowIndex();
Timeline.Window window = timeline.getWindow(windowIndex, new Timeline.Window());
long currentUnixTimeMs = window.getCurrentUnixTimeMs();
long currentTimeMillis = System.currentTimeMillis();
formatter.format("Now (delta) [NTP: %1$tFT%1$tT.%1$tL, Window: %2$tFT%2$tT.%2$tL (%3$d), currentTimeMillis(): %4$tFT%4$tT.%4$tL (%5$d)",
ntpDate,
currentUnixTimeMs,
currentUnixTimeMs - ntpDate,
currentTimeMillis,
currentTimeMillis - ntpDate);
Log.d(TAG, logString.toString());
}
}
});
The SNTPClient
is the ASOP version
Version
Media3 1.1.1
More version details
Run two Android TV streamers side by side with a set latency target (either via
<ServiceDescription>
or usingMediaItem.Builder(). setLiveConfiguration(...)
). Observe they will lock in to nearly the frame from the start.After several hours of runtime they will drift, potentially 100's of milliseconds apart. The cause is the inaccuracy of
System.elaspedTime()
overDevices that reproduce the issue
Devices that do not reproduce the issue
No response
Reproducible in the demo app?
Yes
Reproduction steps
Expected result
With the proposed fix in the pull request the streams have played over 10 hours with no errors.
Actual result
streams are out of sync in 5 or so hours. Note this may seem like a long time, but imagine a bar or health club setting. Also, there is no recovery by changing the channel (requires force-stop of the application hosting ExoPlayer)
Media
on request, not you may really need at least 5 hours of playback to see the issue.
Bug Report
adb bugreport
to android-media-github@google.com after filing this issue.