Stream performance metrics (#1785)

* WIP playback metrics

* Playback metrics collecting + APIs. Closes #793

* Cleanup console messages

* Update test

* Increase browser test timeout

* Update browser tests to not fail

webroot/js/components/player.js

@@ -3,9 +3,37 @@
 import videojs from '/js/web_modules/videojs/dist/video.min.js';
 import { getLocalStorage, setLocalStorage } from '../utils/helpers.js';
 import { PLAYER_VOLUME, URL_STREAM } from '../utils/constants.js';
+import PlaybackMetrics from '../metrics/playback.js';
+import LatencyCompensator from './latencyCompensator.js';
 
 const VIDEO_ID = 'video';
 
+const EVENTS = [
+  'loadstart',
+  'progress',
+  'suspend',
+  'abort',
+  'error',
+  'emptied',
+  'stalled',
+  'loadedmetadata',
+  'loadeddata',
+  'canplay',
+  'canplaythrough',
+  'playing',
+  'waiting',
+  'seeking',
+  'seeked',
+  'ended',
+  'durationchange',
+  'timeupdate',
+  'play',
+  'pause',
+  'ratechange',
+  'resize',
+  'volumechange',
+];
+
 // Video setup
 const VIDEO_SRC = {
   src: URL_STREAM,
@@ -37,11 +65,45 @@ const VIDEO_OPTIONS = {
 export const POSTER_DEFAULT = `/img/logo.png`;
 export const POSTER_THUMB = `/thumbnail.jpg`;
 
+function getCurrentlyPlayingSegment(tech, old_segment = null) {
+  var target_media = tech.vhs.playlists.media();
+  var snapshot_time = tech.currentTime();
+
+  var segment;
+  var segment_time;
+
+  // Itinerate trough available segments and get first within which snapshot_time is
+  for (var i = 0, l = target_media.segments.length; i < l; i++) {
+    // Note: segment.end may be undefined or is not properly set
+    if (snapshot_time < target_media.segments[i].end) {
+      segment = target_media.segments[i];
+      break;
+    }
+  }
+
+  // Null segment_time in case it's lower then 0.
+  if (segment) {
+    segment_time = Math.max(
+      0,
+      snapshot_time - (segment.end - segment.duration)
+    );
+    // Because early segments don't have end property
+  } else {
+    segment = target_media.segments[0];
+    segment_time = 0;
+  }
+
+  return segment;
+}
+
 class OwncastPlayer {
   constructor() {
     window.VIDEOJS_NO_DYNAMIC_STYLE = true; // style override
 
+    this.playbackMetrics = new PlaybackMetrics();
+
     this.vjsPlayer = null;
+    this.latencyCompensator = null;
 
     this.appPlayerReadyCallback = null;
     this.appPlayerPlayingCallback = null;
@@ -54,8 +116,9 @@ class OwncastPlayer {
     this.handleVolume = this.handleVolume.bind(this);
     this.handleEnded = this.handleEnded.bind(this);
     this.handleError = this.handleError.bind(this);
+    this.handleWaiting = this.handleWaiting.bind(this);
+    this.handleNoLongerBuffering = this.handleNoLongerBuffering.bind(this);
     this.addQualitySelector = this.addQualitySelector.bind(this);
-
     this.qualitySelectionMenu = null;
   }
 
@@ -63,11 +126,33 @@ class OwncastPlayer {
     this.addAirplay();
     this.addQualitySelector();
 
+    // Keep a reference of the standard vjs xhr function.
+    const oldVjsXhrCallback = videojs.xhr;
+
+    // Override the xhr function to track segment download time.
+    videojs.Vhs.xhr = (...args) => {
+      if (args[0].uri.match('.ts')) {
+        const start = new Date();
+
+        const cb = args[1];
+        args[1] = (request, error, response) => {
+          const end = new Date();
+          const delta = end.getTime() - start.getTime();
+          this.playbackMetrics.trackSegmentDownloadTime(delta);
+          cb(request, error, response);
+        };
+      }
+
+      return oldVjsXhrCallback(...args);
+    };
+
+    // Add a cachebuster param to playlist URLs.
     videojs.Vhs.xhr.beforeRequest = (options) => {
       if (options.uri.match('m3u8')) {
         const cachebuster = Math.random().toString(16).substr(2, 8);
         options.uri = `${options.uri}?cachebust=${cachebuster}`;
       }
+
       return options;
     };
 
@@ -100,16 +185,39 @@ class OwncastPlayer {
   }
 
   handleReady() {
-    this.log('on Ready');
     this.vjsPlayer.on('error', this.handleError);
     this.vjsPlayer.on('playing', this.handlePlaying);
+    this.vjsPlayer.on('waiting', this.handleWaiting);
+    this.vjsPlayer.on('canplaythrough', this.handleNoLongerBuffering);
     this.vjsPlayer.on('volumechange', this.handleVolume);
     this.vjsPlayer.on('ended', this.handleEnded);
 
+    this.vjsPlayer.on('ready', () => {
+      const tech = this.vjsPlayer.tech({ IWillNotUseThisInPlugins: true });
+      tech.on('usage', (e) => {
+        if (e.name === 'vhs-unknown-waiting') {
+          this.playbackMetrics.incrementErrorCount(1);
+        }
+
+        if (e.name === 'vhs-rendition-change-abr') {
+          // Quality variant has changed
+          this.playbackMetrics.incrementQualityVariantChanges();
+        }
+      });
+
+      // Variant changed
+      const trackElements = this.vjsPlayer.textTracks();
+      trackElements.addEventListener('cuechange', function (c) {
+        console.log(c);
+      });
+    });
+
     if (this.appPlayerReadyCallback) {
       // start polling
       this.appPlayerReadyCallback();
     }
+
+    this.vjsPlayer.log.level('debug');
   }
 
   handleVolume() {
@@ -125,6 +233,22 @@ class OwncastPlayer {
       // start polling
       this.appPlayerPlayingCallback();
     }
+
+    setInterval(() => {
+      const tech = this.vjsPlayer.tech({ IWillNotUseThisInPlugins: true });
+      const bandwidth = tech.vhs.systemBandwidth;
+      this.playbackMetrics.trackBandwidth(bandwidth);
+
+      try {
+        const segment = getCurrentlyPlayingSegment(tech);
+        const segmentTime = segment.dateTimeObject.getTime();
+        const now = new Date().getTime();
+        const latency = now - segmentTime;
+        this.playbackMetrics.trackLatency(latency);
+      } catch (err) {
+        console.warn(err);
+      }
+    }, 5000);
   }
 
   handleEnded() {
@@ -139,6 +263,17 @@ class OwncastPlayer {
     if (this.appPlayerEndedCallback) {
       this.appPlayerEndedCallback();
     }
+
+    this.playbackMetrics.incrementErrorCount(1);
+  }
+
+  handleWaiting(e) {
+    // this.playbackMetrics.incrementErrorCount(1);
+    this.playbackMetrics.isBuffering = true;
+  }
+
+  handleNoLongerBuffering() {
+    this.playbackMetrics.isBuffering = false;
   }
 
   log(message) {

webroot/js/metrics/playback.js

@@ -0,0 +1,98 @@
+import { URL_PLAYBACK_METRICS } from '../utils/constants.js';
+const METRICS_SEND_INTERVAL = 10000;
+
+class PlaybackMetrics {
+  constructor() {
+    this.hasPerformedInitialVariantChange = false;
+
+    this.segmentDownloadTime = [];
+    this.bandwidthTracking = [];
+    this.latencyTracking = [];
+    this.errors = 0;
+    this.qualityVariantChanges = 0;
+    this.isBuffering = false;
+
+    setInterval(() => {
+      this.send();
+    }, METRICS_SEND_INTERVAL);
+  }
+
+  incrementErrorCount(count) {
+    this.errors += count;
+  }
+
+  incrementQualityVariantChanges() {
+    // We always start the player at the lowest quality, so let's just not
+    // count the first change.
+    if (!this.hasPerformedInitialVariantChange) {
+      this.hasPerformedInitialVariantChange = true;
+      return;
+    }
+    this.qualityVariantChanges++;
+  }
+
+  trackSegmentDownloadTime(seconds) {
+    this.segmentDownloadTime.push(seconds);
+  }
+
+  trackBandwidth(bps) {
+    this.bandwidthTracking.push(bps);
+  }
+
+  trackLatency(latency) {
+    this.latencyTracking.push(latency);
+  }
+
+  async send() {
+    if (
+      this.segmentDownloadTime.length < 4 ||
+      this.bandwidthTracking.length < 4
+    ) {
+      return;
+    }
+
+    const errorCount = this.errors;
+    const average = (arr) => arr.reduce((p, c) => p + c, 0) / arr.length;
+
+    const averageDownloadDuration = average(this.segmentDownloadTime) / 1000;
+    const roundedAverageDownloadDuration =
+      Math.round(averageDownloadDuration * 1000) / 1000;
+
+    const averageBandwidth = average(this.bandwidthTracking) / 1000;
+    const roundedAverageBandwidth = Math.round(averageBandwidth * 1000) / 1000;
+
+    const averageLatency = average(this.latencyTracking) / 1000;
+    const roundedAverageLatency = Math.round(averageLatency * 1000) / 1000;
+
+    const data = {
+      bandwidth: roundedAverageBandwidth,
+      latency: roundedAverageLatency,
+      downloadDuration: roundedAverageDownloadDuration,
+      errors: errorCount + this.isBuffering ? 1 : 0,
+      qualityVariantChanges: this.qualityVariantChanges,
+    };
+    this.errors = 0;
+    this.qualityVariantChanges = 0;
+    this.segmentDownloadTime = [];
+    this.bandwidthTracking = [];
+    this.latencyTracking = [];
+
+    const options = {
+      method: 'POST',
+      headers: {
+        'Content-Type': 'application/json',
+      },
+      body: JSON.stringify(data),
+    };
+
+    try {
+      fetch(URL_PLAYBACK_METRICS, options);
+    } catch (e) {
+      console.error(e);
+    }
+
+    // console.log(data);
+  }
+}
+
+export default PlaybackMetrics;

webroot/js/utils/constants.js

@@ -17,6 +17,7 @@ export const URL_WEBSOCKET = `${
 }://${location.host}/ws`;
 export const URL_CHAT_REGISTRATION = `/api/chat/register`;
 export const URL_FOLLOWERS = `/api/followers`;
+export const URL_PLAYBACK_METRICS = `/api/metrics/playback`;
 
 export const TIMER_STATUS_UPDATE = 5000; // ms
 export const TIMER_DISABLE_CHAT_AFTER_OFFLINE = 5 * 60 * 1000; // 5 mins