Merge pull request #13326 from NejcZdovc/hotfix/#13257-logging

Improves twitch logging time

app/browser/api/ledger.js

@@ -2543,6 +2543,10 @@ const onMediaRequest = (state, xhr, type, tabId) => {
   const parsed = ledgerUtil.getMediaData(xhr, type)
   const mediaId = ledgerUtil.getMediaId(parsed, type)
 
+  if (clientOptions.loggingP) {
+    console.log('Media request', parsed, `Media id: ${mediaId}`)
+  }
+
   if (mediaId == null) {
     return state
   }
@@ -2562,6 +2566,9 @@ const onMediaRequest = (state, xhr, type, tabId) => {
   if (!ledgerPublisher) {
     ledgerPublisher = require('bat-publisher')
   }
+  if (clientOptions.loggingP) {
+    console.log('LOGGED EVENT', parsed, `Media id: ${mediaId}`, `Media key: ${mediaKey}`, `Duration: ${duration}ms (${duration / 1000}s)`)
+  }
 
   let revisited = true
   const activeTabId = tabState.getActiveTabId(state)
@@ -2570,8 +2577,11 @@ const onMediaRequest = (state, xhr, type, tabId) => {
     currentMediaKey = mediaKey
   }
 
-  const stateData = ledgerUtil.generateMediaCacheData(parsed, type)
+  const stateData = ledgerUtil.generateMediaCacheData(state, parsed, type, mediaKey)
   const cache = ledgerVideoCache.getDataByVideoId(state, mediaKey)
+  if (clientOptions.loggingP) {
+    console.log('Media cache data: ', stateData.toJS())
+  }
 
   if (!cache.isEmpty()) {
     if (!stateData.isEmpty()) {

app/common/constants/twitchEvents.js

@@ -3,10 +3,15 @@
  * You can obtain one at http://mozilla.org/MPL/2.0/. */
 
 const events = {
+  BUFFER_EMPTY: 'buffer-empty',
+  BUFFER_REFILL: 'buffer-refill',
   MINUTE_WATCHED: 'minute-watched',
-  START: 'video-play',
+  PLAY_MANIFEST: 'video_play_master_manifest',
   PLAY_PAUSE: 'player_click_playpause',
-  SEEK: 'vod_seek'
+  SEEK: 'player_click_vod_seek',
+  START: 'video-play',
+  END: 'video_end',
+  VIDEO_ERROR: 'video_error'
 }
 
 module.exports = events

app/common/lib/ledgerUtil.js

@@ -227,12 +227,7 @@ const getMediaId = (data, type) => {
     case ledgerMediaProviders.TWITCH:
       {
         if (
-          ([
-            twitchEvents.MINUTE_WATCHED,
-            twitchEvents.START,
-            twitchEvents.PLAY_PAUSE,
-            twitchEvents.SEEK
-          ].includes(data.event)) &&
+          Object.values(twitchEvents).includes(data.event) &&
           data.properties
         ) {
           id = data.properties.channel
@@ -327,7 +322,7 @@ const getMediaDuration = (state, data, mediaKey, type) => {
   return duration
 }
 
-const generateMediaCacheData = (parsed, type) => {
+const generateMediaCacheData = (state, parsed, type, mediaKey) => {
   let data = Immutable.Map()
 
   if (parsed == null) {
@@ -337,28 +332,65 @@ const generateMediaCacheData = (parsed, type) => {
   switch (type) {
     case ledgerMediaProviders.TWITCH:
       {
-        data = generateTwitchCacheData(parsed)
+        data = generateTwitchCacheData(state, parsed, mediaKey)
         break
       }
   }
 
   return data
 }
 
-const generateTwitchCacheData = (parsed) => {
+const generateTwitchCacheData = (state, parsed, mediaKey) => {
   if (parsed == null) {
     return Immutable.Map()
   }
 
+  const statusConst = {
+    playing: 'playing',
+    paused: 'paused'
+  }
+
+  const previousData = ledgerVideoCache.getDataByVideoId(state, mediaKey)
+  let status = statusConst.playing
+
+  if (
+    (
+      parsed.event === twitchEvents.PLAY_PAUSE &&
+      previousData.get('event') !== twitchEvents.PLAY_PAUSE
+    ) || // user clicked pause (we need to exclude seeking while paused)
+    (
+      parsed.event === twitchEvents.PLAY_PAUSE &&
+      previousData.get('event') === twitchEvents.PLAY_PAUSE &&
+      previousData.get('status') === statusConst.playing
+    ) || // user clicked pause as soon as he clicked played
+    (
+      parsed.event === twitchEvents.SEEK &&
+      previousData.get('status') === statusConst.paused
+    ) // seeking video while it is paused
+  ) {
+    status = statusConst.paused
+  }
+
+  // User pauses a video, then seek it and play it again
+  if (
+    parsed.event === twitchEvents.PLAY_PAUSE &&
+    previousData.get('event') === twitchEvents.SEEK &&
+    previousData.get('status') === statusConst.paused
+  ) {
+    status = statusConst.playing
+  }
+
   if (parsed.properties) {
     return Immutable.fromJS({
       event: parsed.event,
-      time: parsed.properties.time
+      time: parsed.properties.time,
+      status
     })
   }
 
   return Immutable.fromJS({
-    event: parsed.event
+    event: parsed.event,
+    status
   })
 }
 
@@ -393,31 +425,42 @@ const getTwitchDuration = (state, data, mediaKey) => {
   }
 
   const previousData = ledgerVideoCache.getDataByVideoId(state, mediaKey)
+  const oldEvent = previousData.get('event')
   const twitchMinimumSeconds = 10
 
-  if (previousData.isEmpty() && data.event === twitchEvents.START) {
+  if (data.event === twitchEvents.START && oldEvent === twitchEvents.START) {
+    return 0
+  }
+
+  if (data.event === twitchEvents.START) {
     return twitchMinimumSeconds * milliseconds.second
   }
 
-  const oldMedia = ledgerVideoCache.getDataByVideoId(state, mediaKey)
   let time = 0
   const currentTime = parseFloat(data.properties.time)
   const oldTime = parseFloat(previousData.get('time'))
+  const currentEvent = data.event
 
-  if (
-    data.event === twitchEvents.PLAY_PAUSE &&
-    oldMedia.get('event') !== twitchEvents.PLAY_PAUSE
-  ) {
-    // User paused a video
-    time = currentTime - oldTime
-  } else if (previousData.get('event') === twitchEvents.START) {
+  if (oldEvent === twitchEvents.START) {
     // From video play event to x event
     time = currentTime - oldTime - twitchMinimumSeconds
-  } else if (data.event === twitchEvents.MINUTE_WATCHED) {
-    // Minute watched event
-    time = currentTime - oldTime
-  } else if (data.event === twitchEvents.SEEK && oldMedia.get('event') !== twitchEvents.PLAY_PAUSE) {
-    // Vod seek event
+  } else if (
+    currentEvent === twitchEvents.MINUTE_WATCHED || // Minute watched
+    currentEvent === twitchEvents.BUFFER_EMPTY || // Run out of buffer
+    currentEvent === twitchEvents.VIDEO_ERROR || // Video has some problems
+    currentEvent === twitchEvents.END || // Video ended
+    (currentEvent === twitchEvents.SEEK && previousData.get('status') !== 'paused') || // Vod seek
+    (
+      currentEvent === twitchEvents.PLAY_PAUSE &&
+      (
+        (
+          oldEvent !== twitchEvents.PLAY_PAUSE &&
+          oldEvent !== twitchEvents.SEEK
+        ) ||
+        previousData.get('status') === 'playing'
+      )
+    ) // User paused a video
+  ) {
     time = currentTime - oldTime
   }
 
@@ -436,7 +479,7 @@ const getTwitchDuration = (state, data, mediaKey) => {
   // we get seconds back, so we need to convert it into ms
   time = time * milliseconds.second
 
-  return Math.floor(time)
+  return time
 }
 
 const getYouTubeDuration = (data) => {

docs/state.md

@@ -93,7 +93,10 @@ AppStore
     ledgerVideos: {
       [mediaKey]: {
         publisher: string // publisher key
-        beatData: object // data that we get from a heartbeat
+        // Twitch
+        event: string, // event that was send to Twitch
+        time: number, // timestamp that we will log in the ledger
+        status: string // playing status: playing or paused
       }
     }
   }