Add hidden transmuxing performance measurments

Author: peaBerberian

src/ts-main/api.ts

@@ -350,14 +350,24 @@ export default class WaspHlsPlayer extends EventEmitter<WaspHlsPlayerEvents> {
     if (this.__worker__ === null) {
       throw new Error("The Player is not initialized or is disposed.");
     }
-    for (const [key, value] of Object.entries(overwrite)) {
+    for (const [key, value] of Object.entries(
+      overwrite as Record<string, unknown>,
+    )) {
       if (value !== undefined) {
-        this.__config__[key as keyof WaspHlsPlayerConfig] = value;
+        if (key in this.__config__) {
+          const typedKey = key as keyof WaspHlsPlayerConfig;
+          (
+            this.__config__ as Record<
+              keyof WaspHlsPlayerConfig,
+              WaspHlsPlayerConfig[keyof WaspHlsPlayerConfig]
+            >
+          )[typedKey] = value as WaspHlsPlayerConfig[keyof WaspHlsPlayerConfig];
+        }
       }
     }
     postMessageToWorker(this.__worker__, {
       type: MainMessageType.UpdateConfig,
-      value: this.__config__,
+      value: overwrite,
     });
   }
 

src/ts-worker/bindings.ts

@@ -55,6 +55,7 @@ import {
   getTrackFragmentDecodeTime,
 } from "./isobmff-utils.js";
 import postMessageToMain from "./postMessage.js";
+import { recordTransmuxProfile } from "./transmux-profiling.js";
 import { getTransmuxedType, createTransmuxer } from "./transmux.js";
 import { formatErrMessage, shouldTransmux } from "./utils.js";
 
@@ -783,11 +784,12 @@ export function addSourceBuffer(
       if (shouldTransmux(typ)) {
         mimeType = getTransmuxedType(typ, mediaType);
       }
+      const transmuxer = mimeType === typ ? null : createTransmuxer();
       const sourceBufferId = nextSourceBufferId;
       sourceBuffers.push({
         lastInitTimescale: undefined,
         id: sourceBufferId,
-        transmuxer: mimeType === typ ? null : createTransmuxer(),
+        transmuxer,
         sourceBuffer: null,
         mediaType,
       });
@@ -830,13 +832,14 @@ export function addSourceBuffer(
         mimeType = getTransmuxedType(typ, mediaType);
       }
       const sourceBuffer = mediaSource.addSourceBuffer(mimeType);
+      const transmuxer = mimeType === typ ? null : createTransmuxer();
       const sourceBufferId = nextSourceBufferId;
       const queuedSourceBuffer = new QueuedSourceBuffer(sourceBuffer);
       sourceBuffers.push({
         lastInitTimescale: undefined,
         id: sourceBufferId,
         sourceBuffer: queuedSourceBuffer,
-        transmuxer: mimeType === typ ? null : createTransmuxer(),
+        transmuxer,
         mediaType,
       });
       contentInfo.mediaSourceObj.nextSourceBufferId++;
@@ -912,9 +915,18 @@ export function appendBuffer(
   const sourceBufferObj = mediaSourceObj.sourceBuffers[sourceBufferObjIdx];
   if (sourceBufferObj.transmuxer !== null) {
     try {
+      const inputBytes = segment.byteLength;
+      const startTime = timerFn();
       const transmuxedData =
         sourceBufferObj.transmuxer.transmuxSegment(segment);
+      const durationMs = timerFn() - startTime;
       if (transmuxedData !== null) {
+        recordTransmuxProfile({
+          durationMs,
+          inputBytes,
+          outputBytes: transmuxedData.byteLength,
+          mediaType: sourceBufferObj.mediaType,
+        });
         segment = transmuxedData;
       } else {
         return AppendBufferResult.error(

src/ts-worker/globals.ts

@@ -7,6 +7,11 @@ import type {
 } from "../ts-common/types.ts";
 import type Transmuxer from "../ts-transmux/index.ts";
 import { Dispatcher, type InitOutput, type MediaType } from "../wasm/index.js";
+import {
+  type HiddenTransmuxProfilingConfig,
+  resetTransmuxProfiling,
+  updateTransmuxProfilingConfig,
+} from "./transmux-profiling.ts";
 
 export interface WorkerInitializationOptions {
   hasMseInWorker: boolean;
@@ -39,6 +44,7 @@ class PlayerInstance {
   ) {
     const dispatcher = new Dispatcher(opts.initialBandwidth);
     updateDispatcherConfig(dispatcher, config);
+    resetTransmuxProfiling();
     this._instanceInfo = {
       wasm,
       dispatcher,
@@ -52,6 +58,7 @@ class PlayerInstance {
     this._instanceInfo?.dispatcher.free();
     jsMemoryResources.freeEverything();
     requestsStore.freeEverything();
+    resetTransmuxProfiling();
   }
 
   public changeContent(content: ContentInfo) {
@@ -63,6 +70,7 @@ class PlayerInstance {
     }
     jsMemoryResources.freeEverything();
     requestsStore.freeEverything();
+    resetTransmuxProfiling();
     this._instanceInfo.content = content;
   }
 
@@ -159,8 +167,9 @@ const I32_MAX_VALUE = 2147483647;
 
 export function updateDispatcherConfig(
   dispatcher: Dispatcher,
-  config: Partial<WaspHlsPlayerConfig>,
+  config: Partial<WaspHlsPlayerConfig> & HiddenTransmuxProfilingConfig,
 ): void {
+  updateTransmuxProfilingConfig(config);
   if (config.bufferGoal !== undefined) {
     dispatcher.set_buffer_goal(config.bufferGoal);
   }

src/ts-worker/transmux-profiling.ts

@@ -0,0 +1,170 @@
+import logger, { LoggerLevel } from "../ts-common/logger";
+import { MediaType } from "../wasm/wasp_hls";
+
+export interface HiddenTransmuxProfilingConfig {
+  transmuxProfiling?: boolean;
+  transmuxProfilingSampleSize?: number;
+  transmuxProfilingSlowThreshold?: number;
+}
+
+interface TransmuxProfilingConfig {
+  enabled: boolean;
+  sampleSize: number;
+  slowThreshold: number;
+}
+
+interface TransmuxProfilingTotals {
+  count: number;
+  totalDurationMs: number;
+  maxDurationMs: number;
+  totalInputBytes: number;
+  totalOutputBytes: number;
+}
+
+const DEFAULT_CONFIG: TransmuxProfilingConfig = {
+  enabled: false,
+  sampleSize: 20,
+  slowThreshold: 12,
+};
+
+const currentConfig: TransmuxProfilingConfig = { ...DEFAULT_CONFIG };
+let totals = createEmptyTotals();
+
+function createEmptyTotals(): TransmuxProfilingTotals {
+  return {
+    count: 0,
+    totalDurationMs: 0,
+    maxDurationMs: 0,
+    totalInputBytes: 0,
+    totalOutputBytes: 0,
+  };
+}
+
+function clampPositiveInteger(value: number, fallback: number): number {
+  if (!Number.isFinite(value) || value < 1) {
+    return fallback;
+  }
+  return Math.floor(value);
+}
+
+function clampNonNegativeNumber(value: number, fallback: number): number {
+  if (!Number.isFinite(value) || value < 0) {
+    return fallback;
+  }
+  return value;
+}
+
+function formatBytesPerMs(bytes: number, durationMs: number): string {
+  if (durationMs <= 0) {
+    return "n/a";
+  }
+  return (bytes / durationMs).toFixed(1);
+}
+
+function mediaTypeToString(mediaType: MediaType): string {
+  switch (mediaType) {
+    case MediaType.Audio:
+      return "audio";
+    case MediaType.Video:
+      return "video";
+    default:
+      return "unknown";
+  }
+}
+
+export function updateTransmuxProfilingConfig(
+  config: HiddenTransmuxProfilingConfig,
+): void {
+  const previousEnabled = currentConfig.enabled;
+  if (config.transmuxProfiling !== undefined) {
+    currentConfig.enabled = config.transmuxProfiling;
+  }
+  if (config.transmuxProfilingSampleSize !== undefined) {
+    currentConfig.sampleSize = clampPositiveInteger(
+      config.transmuxProfilingSampleSize,
+      DEFAULT_CONFIG.sampleSize,
+    );
+  }
+  if (config.transmuxProfilingSlowThreshold !== undefined) {
+    currentConfig.slowThreshold = clampNonNegativeNumber(
+      config.transmuxProfilingSlowThreshold,
+      DEFAULT_CONFIG.slowThreshold,
+    );
+  }
+
+  if (currentConfig.enabled !== previousEnabled || !currentConfig.enabled) {
+    resetTransmuxProfiling();
+  }
+
+  if (
+    currentConfig.enabled &&
+    !previousEnabled &&
+    logger.hasLevel(LoggerLevel.Info)
+  ) {
+    logger.info(
+      "[transmux-profile] enabled sampleSize=",
+      currentConfig.sampleSize,
+      "slowThresholdMs=",
+      currentConfig.slowThreshold,
+    );
+  }
+}
+
+export function resetTransmuxProfiling(): void {
+  totals = createEmptyTotals();
+}
+
+export function recordTransmuxProfile(args: {
+  durationMs: number;
+  inputBytes: number;
+  outputBytes: number;
+  mediaType: MediaType;
+}): void {
+  if (!currentConfig.enabled) {
+    return;
+  }
+
+  totals.count += 1;
+  totals.totalDurationMs += args.durationMs;
+  totals.maxDurationMs = Math.max(totals.maxDurationMs, args.durationMs);
+  totals.totalInputBytes += args.inputBytes;
+  totals.totalOutputBytes += args.outputBytes;
+
+  if (
+    args.durationMs >= currentConfig.slowThreshold &&
+    logger.hasLevel(LoggerLevel.Info)
+  ) {
+    logger.info(
+      "[transmux-profile] slow-segment mediaType=",
+      mediaTypeToString(args.mediaType),
+      "durationMs=",
+      args.durationMs.toFixed(2),
+      "inputBytes=",
+      args.inputBytes,
+      "outputBytes=",
+      args.outputBytes,
+    );
+  }
+
+  if (
+    totals.count % currentConfig.sampleSize === 0 &&
+    logger.hasLevel(LoggerLevel.Info)
+  ) {
+    logger.info(
+      "[transmux-profile] summary segments=",
+      totals.count,
+      "avgMs=",
+      (totals.totalDurationMs / totals.count).toFixed(2),
+      "maxMs=",
+      totals.maxDurationMs.toFixed(2),
+      "avgInputBytes=",
+      Math.round(totals.totalInputBytes / totals.count),
+      "avgOutputBytes=",
+      Math.round(totals.totalOutputBytes / totals.count),
+      "avgInputBytesPerMs=",
+      formatBytesPerMs(totals.totalInputBytes, totals.totalDurationMs),
+      "avgOutputBytesPerMs=",
+      formatBytesPerMs(totals.totalOutputBytes, totals.totalDurationMs),
+    );
+  }
+}