Add logging for playlist alignment across variants and renditions (different playlist URIs)

#7482

Author: robwalch

src/controller/audio-stream-controller.ts

@@ -581,7 +581,7 @@ class AudioStreamController
       if (!newDetails.alignedSliding) {
         // Align audio rendition with the "main" playlist on discontinuity change
         // or program-date-time (PDT)
-        alignStream(mainDetails, newDetails);
+        alignStream(mainDetails, newDetails, this);
         sliding = newDetails.fragmentStart;
       }
     }
@@ -1047,7 +1047,7 @@ class AudioStreamController
           mainDetails &&
           mainDetails.fragmentStart !== track.details.fragmentStart
         ) {
-          alignStream(mainDetails, track.details);
+          alignStream(mainDetails, track.details, this);
         }
       } else {
         super.loadFragment(frag, track, targetBufferTime);

src/controller/base-stream-controller.ts

@@ -1795,7 +1795,7 @@ export default class BaseStreamController
     const firstLevelLoad = !previousDetails;
     const aligned = details.alignedSliding && Number.isFinite(slidingStart);
     if (firstLevelLoad || (!aligned && !slidingStart)) {
-      alignStream(switchDetails, details);
+      alignStream(switchDetails, details, this);
       const alignedSlidingStart = details.fragmentStart;
       this.log(
         `Live playlist sliding: ${alignedSlidingStart.toFixed(2)} start-sn: ${

src/controller/subtitle-stream-controller.ts

@@ -16,7 +16,6 @@ import {
   getAesModeFromFullSegmentMethod,
   isFullSegmentEncryption,
 } from '../utils/encryption-methods-util';
-import { addSliding } from '../utils/level-helper';
 import { subtitleOptionsIdentical } from '../utils/media-option-attributes';
 import type { FragmentTracker } from './fragment-tracker';
 import type Hls from '../hls';
@@ -315,7 +314,7 @@ export class SubtitleStreamController
       }
       if (!newDetails.alignedSliding) {
         // line up live playlist with main so that fragments in range are loaded
-        alignStream(mainDetails, newDetails);
+        alignStream(mainDetails, newDetails, this);
         sliding = newDetails.fragmentStart;
       }
     }

src/utils/discontinuities.ts

@@ -1,5 +1,5 @@
 import { adjustSliding } from './level-helper';
-import { logger } from './logger';
+import type { ILogger } from './logger';
 import type { Fragment } from '../loader/fragment';
 import type { LevelDetails } from '../loader/level-details';
 
@@ -62,22 +62,23 @@ export function adjustSlidingStart(sliding: number, details: LevelDetails) {
 export function alignStream(
   switchDetails: LevelDetails | undefined,
   details: LevelDetails,
+  logger: ILogger,
 ) {
   if (!switchDetails) {
     return;
   }
-  alignDiscontinuities(details, switchDetails);
+  alignDiscontinuities(details, switchDetails, logger);
   if (!details.alignedSliding) {
     // If the PTS wasn't figured out via discontinuity sequence that means there was no CC increase within the level.
     // Aligning via Program Date Time should therefore be reliable, since PDT should be the same within the same
     // discontinuity sequence.
-    alignMediaPlaylistByPDT(details, switchDetails);
+    alignMediaPlaylistByPDT(details, switchDetails, logger);
   }
   if (!details.alignedSliding && !details.skippedSegments) {
     // Try to align on sn so that we pick a better start fragment.
     // Do not perform this on playlists with delta updates as this is only to align levels on switch
     // and adjustSliding only adjusts fragments after skippedSegments.
-    adjustSliding(switchDetails, details, false);
+    adjustSliding(switchDetails, details, false, logger);
   }
 }
 
@@ -90,6 +91,7 @@ export function alignStream(
 export function alignDiscontinuities(
   details: LevelDetails,
   refDetails: LevelDetails | undefined,
+  logger: ILogger,
 ) {
   if (!shouldAlignOnDiscontinuities(refDetails, details)) {
     return;
@@ -100,8 +102,10 @@ export function alignDiscontinuities(
   if (!refFrag || !frag) {
     return;
   }
-  logger.log(`Aligning playlist at start of dicontinuity sequence ${targetCC}`);
   const delta = refFrag.start - frag.start;
+  logger.log(
+    `Aligning playlists using dicontinuity sequence ${targetCC} (diff: ${delta})`,
+  );
   adjustSlidingStart(delta, details);
 }
 
@@ -121,6 +125,7 @@ export function alignDiscontinuities(
 export function alignMediaPlaylistByPDT(
   details: LevelDetails,
   refDetails: LevelDetails,
+  logger: ILogger,
 ) {
   if (!details.hasProgramDateTime || !refDetails.hasProgramDateTime) {
     return;
@@ -157,9 +162,13 @@ export function alignMediaPlaylistByPDT(
   const dateDifference = (targetPDT - refPDT) / 1000;
   if (Math.abs(dateDifference) > Math.max(60, details.totalduration)) {
     // Do not align on PDT if ranges differ significantly
+    logger.log(
+      `Cannot align playlists using PDT without overlap (${Math.abs(dateDifference)} > ${details.totalduration})`,
+    );
     return;
   }
 
   const delta = dateDifference - (frag.start - refFrag.start);
+  logger.log(`Aligning playlists using PDT (diff: ${delta})`);
   adjustSlidingStart(delta, details);
 }

src/utils/level-helper.ts

@@ -475,27 +475,38 @@ export function adjustSliding(
   oldDetails: LevelDetails,
   newDetails: LevelDetails,
   matchingStableVariantOrRendition: boolean = true,
-): void {
+  logger?: ILogger,
+): number {
   const delta =
     newDetails.startSN + newDetails.skippedSegments - oldDetails.startSN;
   const oldFragments = oldDetails.fragments;
   const advancedOrStable = delta >= 0;
   let sliding = 0;
   if (advancedOrStable && delta < oldFragments.length) {
     sliding = oldFragments[delta].start;
+    logger?.log(
+      `Aligning playlists based on SN ${newDetails.startSN} (diff: ${sliding})`,
+    );
   } else if (advancedOrStable && newDetails.startSN === oldDetails.endSN + 1) {
     sliding = oldDetails.fragmentEnd;
+    logger?.log(
+      `Aligning playlists based on first/last SN ${newDetails.startSN} (diff: ${sliding})`,
+    );
   } else if (advancedOrStable && matchingStableVariantOrRendition) {
     // align with expected position (updated playlist start sequence is past end sequence of last update)
     sliding = oldDetails.fragmentStart + delta * newDetails.levelTargetDuration;
   } else if (!newDetails.skippedSegments && newDetails.fragmentStart === 0) {
     // align new start with old (playlist switch has a sequence with no overlap and should not be used for alignment)
     sliding = oldDetails.fragmentStart;
+    logger?.log(
+      `Aligning playlists based on first SN ${newDetails.startSN} (diff: ${sliding})`,
+    );
   } else {
     // new details already has a sliding offset or has skipped segments
-    return;
+    return sliding; // 0
   }
   addSliding(newDetails, sliding);
+  return sliding;
 }
 
 export function addSliding(details: LevelDetails, sliding: number) {

tests/unit/utils/discontinuities.ts

@@ -11,6 +11,7 @@ import {
   alignMediaPlaylistByPDT,
   shouldAlignOnDiscontinuities,
 } from '../../../src/utils/discontinuities';
+import { logger } from '../../../src/utils/logger';
 import type { MediaFragment } from '../../../src/loader/fragment';
 
 chai.use(sinonChai);
@@ -176,7 +177,7 @@ describe('discontinuities', function () {
       startCC: 0,
       endCC: 0,
     });
-    alignMediaPlaylistByPDT(lastLevel.details, refDetails);
+    alignMediaPlaylistByPDT(lastLevel.details, refDetails, logger);
     expect(
       lastLevel.details,
       `actual:\n\n${JSON.stringify(
@@ -312,7 +313,7 @@ describe('discontinuities', function () {
       startCC: 2,
       endCC: 4,
     });
-    alignMediaPlaylistByPDT(details, lastLevel.details as LevelDetails);
+    alignMediaPlaylistByPDT(details, lastLevel.details as LevelDetails, logger);
     expect(details).to.deep.equal(detailsExpected);
   });
 
@@ -420,7 +421,7 @@ describe('discontinuities', function () {
       startCC: 2,
       endCC: 3,
     });
-    alignMediaPlaylistByPDT(details, lastLevel.details);
+    alignMediaPlaylistByPDT(details, lastLevel.details, logger);
 
     expect(detailsExpected).to.deep.equal(
       details,
@@ -439,7 +440,7 @@ describe('discontinuities', function () {
       const curDetails = objToLevelDetails({
         fragments: mockFrags.map(objToFragment),
       });
-      alignDiscontinuities(curDetails, prevDetails);
+      alignDiscontinuities(curDetails, prevDetails, logger);
       expect(curDetails).to.have.property('alignedSliding').which.is.true;
       expect(curDetails.fragments[0].start).to.equal(20);
     });
@@ -455,7 +456,7 @@ describe('discontinuities', function () {
       const curDetails = objToLevelDetails({
         fragments: mockFrags.map(objToFragment),
       });
-      alignDiscontinuities(curDetails, prevDetails);
+      alignDiscontinuities(curDetails, prevDetails, logger);
       expect(curDetails).to.have.property('alignedSliding').which.is.true;
       expect(curDetails.fragments[0].start).to.equal(20);
     });
@@ -475,7 +476,7 @@ describe('discontinuities', function () {
           { start: 8.5, startPTS: 4.5, endPTS: 12.5, duration: 4, cc: 3 },
         ].map(objToFragment),
       });
-      alignDiscontinuities(curDetails, prevDetails);
+      alignDiscontinuities(curDetails, prevDetails, logger);
       expect(curDetails).to.have.property('alignedSliding').which.is.true;
       expect(curDetails.fragments[0].start).to.equal(24);
     });
@@ -484,7 +485,11 @@ describe('discontinuities', function () {
       const curDetails = objToLevelDetails({
         fragments: mockFrags.map(objToFragment),
       });
-      alignDiscontinuities(curDetails, objToLevelDetails({ fragments: [] }));
+      alignDiscontinuities(
+        curDetails,
+        objToLevelDetails({ fragments: [] }),
+        logger,
+      );
       expect(curDetails).to.have.property('alignedSliding').which.is.false;
       expect(curDetails.fragments[0].start).to.equal(0);
     });
@@ -496,6 +501,7 @@ describe('discontinuities', function () {
       alignDiscontinuities(
         curDetails,
         objToLevelDetails({ fragments: [{ cc: 10 }].map(objToFragment) }),
+        logger,
       );
       expect(curDetails).to.have.property('alignedSliding').which.is.false;
       expect(curDetails.fragments[0].start).to.equal(0);
@@ -508,6 +514,7 @@ describe('discontinuities', function () {
       alignDiscontinuities(
         curDetails,
         objToLevelDetails({ fragments: [{ cc: 0 }].map(objToFragment) }),
+        logger,
       );
       expect(curDetails).to.have.property('alignedSliding').which.is.false;
     });