]> git.immae.eu Git - github/Chocobozzz/PeerTube.git/blobdiff - server/lib/live-manager.ts
fetch -> load
[github/Chocobozzz/PeerTube.git] / server / lib / live-manager.ts
index 2fb4b774c1234868ebdb5fb51d47316e9781cb84..563ba2578bbf34d0e3f783e853957f8ff51002f6 100644 (file)
@@ -3,32 +3,32 @@ import * as Bluebird from 'bluebird'
 import * as chokidar from 'chokidar'
 import { FfmpegCommand } from 'fluent-ffmpeg'
 import { appendFile, ensureDir, readFile, stat } from 'fs-extra'
+import { createServer, Server } from 'net'
 import { basename, join } from 'path'
 import { isTestInstance } from '@server/helpers/core-utils'
 import { getLiveMuxingCommand, getLiveTranscodingCommand } from '@server/helpers/ffmpeg-utils'
 import { computeResolutionsToTranscode, getVideoFileFPS, getVideoFileResolution } from '@server/helpers/ffprobe-utils'
-import { logger } from '@server/helpers/logger'
+import { logger, loggerTagsFactory } from '@server/helpers/logger'
 import { CONFIG, registerConfigChangedHandler } from '@server/initializers/config'
 import { MEMOIZE_TTL, P2P_MEDIA_LOADER_PEER_VERSION, VIDEO_LIVE, VIEW_LIFETIME, WEBSERVER } from '@server/initializers/constants'
-import { UserModel } from '@server/models/account/user'
+import { UserModel } from '@server/models/user/user'
 import { VideoModel } from '@server/models/video/video'
 import { VideoFileModel } from '@server/models/video/video-file'
 import { VideoLiveModel } from '@server/models/video/video-live'
 import { VideoStreamingPlaylistModel } from '@server/models/video/video-streaming-playlist'
-import { MStreamingPlaylist, MUserId, MVideoLive, MVideoLiveVideo } from '@server/types/models'
+import { MStreamingPlaylist, MStreamingPlaylistVideo, MUserId, MVideoLive, MVideoLiveVideo } from '@server/types/models'
 import { VideoState, VideoStreamingPlaylistType } from '@shared/models'
 import { federateVideoIfNeeded } from './activitypub/videos'
 import { buildSha256Segment } from './hls'
 import { JobQueue } from './job-queue'
 import { cleanupLive } from './job-queue/handlers/video-live-ending'
 import { PeerTubeSocket } from './peertube-socket'
+import { VideoTranscodingProfilesManager } from './transcoding/video-transcoding-profiles'
 import { isAbleToUploadVideo } from './user'
 import { getHLSDirectory } from './video-paths'
-import { availableEncoders } from './video-transcoding-profiles'
 
 import memoizee = require('memoizee')
-
-const NodeRtmpServer = require('node-media-server/node_rtmp_server')
+const NodeRtmpSession = require('node-media-server/node_rtmp_session')
 const context = require('node-media-server/node_core_ctx')
 const nodeMediaServerLogger = require('node-media-server/node_core_logger')
 
@@ -48,6 +48,8 @@ const config = {
   }
 }
 
+const lTags = loggerTagsFactory('live')
+
 class LiveManager {
 
   private static instance: LiveManager
@@ -63,7 +65,11 @@ class LiveManager {
     return isAbleToUploadVideo(userId, 1000)
   }, { maxAge: MEMOIZE_TTL.LIVE_ABLE_TO_UPLOAD })
 
-  private rtmpServer: any
+  private readonly hasClientSocketsInBadHealthWithCache = memoizee((sessionId: string) => {
+    return this.hasClientSocketsInBadHealth(sessionId)
+  }, { maxAge: MEMOIZE_TTL.LIVE_CHECK_SOCKET_HEALTH })
+
+  private rtmpServer: Server
 
   private constructor () {
   }
@@ -71,20 +77,20 @@ class LiveManager {
   init () {
     const events = this.getContext().nodeEvent
     events.on('postPublish', (sessionId: string, streamPath: string) => {
-      logger.debug('RTMP received stream', { id: sessionId, streamPath })
+      logger.debug('RTMP received stream', { id: sessionId, streamPath, ...lTags(sessionId) })
 
       const splittedPath = streamPath.split('/')
       if (splittedPath.length !== 3 || splittedPath[1] !== VIDEO_LIVE.RTMP.BASE_PATH) {
-        logger.warn('Live path is incorrect.', { streamPath })
+        logger.warn('Live path is incorrect.', { streamPath, ...lTags(sessionId) })
         return this.abortSession(sessionId)
       }
 
       this.handleSession(sessionId, streamPath, splittedPath[2])
-        .catch(err => logger.error('Cannot handle sessions.', { err }))
+        .catch(err => logger.error('Cannot handle sessions.', { err, ...lTags(sessionId) }))
     })
 
     events.on('donePublish', sessionId => {
-      logger.info('Live session ended.', { sessionId })
+      logger.info('Live session ended.', { sessionId, ...lTags(sessionId) })
     })
 
     registerConfigChangedHandler(() => {
@@ -100,23 +106,39 @@ class LiveManager {
 
     // Cleanup broken lives, that were terminated by a server restart for example
     this.handleBrokenLives()
-      .catch(err => logger.error('Cannot handle broken lives.', { err }))
+      .catch(err => logger.error('Cannot handle broken lives.', { err, ...lTags() }))
 
     setInterval(() => this.updateLiveViews(), VIEW_LIFETIME.LIVE)
   }
 
   run () {
-    logger.info('Running RTMP server on port %d', config.rtmp.port)
+    logger.info('Running RTMP server on port %d', config.rtmp.port, lTags())
+
+    this.rtmpServer = createServer(socket => {
+      const session = new NodeRtmpSession(config, socket)
+
+      session.run()
+    })
+
+    this.rtmpServer.on('error', err => {
+      logger.error('Cannot run RTMP server.', { err, ...lTags() })
+    })
 
-    this.rtmpServer = new NodeRtmpServer(config)
-    this.rtmpServer.run()
+    this.rtmpServer.listen(CONFIG.LIVE.RTMP.PORT)
   }
 
   stop () {
-    logger.info('Stopping RTMP server.')
+    logger.info('Stopping RTMP server.', lTags())
 
-    this.rtmpServer.stop()
+    this.rtmpServer.close()
     this.rtmpServer = undefined
+
+    // Sessions is an object
+    this.getContext().sessions.forEach((session: any) => {
+      if (session instanceof NodeRtmpSession) {
+        session.stop()
+      }
+    })
   }
 
   isRunning () {
@@ -165,7 +187,7 @@ class LiveManager {
 
     return readFile(segmentPath)
       .then(data => appendFile(dest, data))
-      .catch(err => logger.error('Cannot copy segment %s to repay directory.', segmentPath, { err }))
+      .catch(err => logger.error('Cannot copy segment %s to replay directory.', segmentPath, { err, ...lTags() }))
   }
 
   buildConcatenatedName (segmentOrPlaylistPath: string) {
@@ -182,7 +204,7 @@ class LiveManager {
       if (videoLive.saveReplay) {
         await this.addSegmentToReplay(hlsVideoPath, previousSegment)
       }
-    }).catch(err => logger.error('Cannot process segments in %s', hlsVideoPath, { err }))
+    }).catch(err => logger.error('Cannot process segments in %s', hlsVideoPath, { err, ...lTags(videoUUID) }))
   }
 
   private getContext () {
@@ -206,13 +228,13 @@ class LiveManager {
   private async handleSession (sessionId: string, streamPath: string, streamKey: string) {
     const videoLive = await VideoLiveModel.loadByStreamKey(streamKey)
     if (!videoLive) {
-      logger.warn('Unknown live video with stream key %s.', streamKey)
+      logger.warn('Unknown live video with stream key %s.', streamKey, lTags(sessionId))
       return this.abortSession(sessionId)
     }
 
     const video = videoLive.Video
     if (video.isBlacklisted()) {
-      logger.warn('Video is blacklisted. Refusing stream %s.', streamKey)
+      logger.warn('Video is blacklisted. Refusing stream %s.', streamKey, lTags(sessionId, video.uuid))
       return this.abortSession(sessionId)
     }
 
@@ -242,7 +264,10 @@ class LiveManager {
 
     const allResolutions = resolutionsEnabled.concat([ session.videoHeight ])
 
-    logger.info('Will mux/transcode live video of original resolution %d.', session.videoHeight, { allResolutions })
+    logger.info(
+      'Will mux/transcode live video of original resolution %d.', session.videoHeight,
+      { allResolutions, ...lTags(sessionId, video.uuid) }
+    )
 
     const [ videoStreamingPlaylist ] = await VideoStreamingPlaylistModel.upsert({
       videoId: video.id,
@@ -257,7 +282,7 @@ class LiveManager {
     return this.runMuxing({
       sessionId,
       videoLive,
-      playlist: videoStreamingPlaylist,
+      playlist: Object.assign(videoStreamingPlaylist, { Video: video }),
       rtmpUrl,
       fps,
       allResolutions
@@ -267,7 +292,7 @@ class LiveManager {
   private async runMuxing (options: {
     sessionId: string
     videoLive: MVideoLiveVideo
-    playlist: MStreamingPlaylist
+    playlist: MStreamingPlaylistVideo
     rtmpUrl: string
     fps: number
     allResolutions: number[]
@@ -297,7 +322,7 @@ class LiveManager {
       })
 
       VideoFileModel.customUpsert(file, 'streaming-playlist', null)
-        .catch(err => logger.error('Cannot create file for live streaming.', { err }))
+        .catch(err => logger.error('Cannot create file for live streaming.', { err, ...lTags(sessionId, videoLive.Video.uuid) }))
     }
 
     const outPath = getHLSDirectory(videoLive.Video)
@@ -317,12 +342,12 @@ class LiveManager {
         outPath,
         resolutions: allResolutions,
         fps,
-        availableEncoders,
-        profile: 'default'
+        availableEncoders: VideoTranscodingProfilesManager.Instance.getAvailableEncoders(),
+        profile: CONFIG.LIVE.TRANSCODING.PROFILE
       })
       : getLiveMuxingCommand(rtmpUrl, outPath)
 
-    logger.info('Running live muxing/transcoding for %s.', videoUUID)
+    logger.info('Running live muxing/transcoding for %s.', videoUUID, lTags(sessionId, videoUUID))
     this.transSessions.set(sessionId, ffmpegExec)
 
     const tsWatcher = chokidar.watch(outPath + '/*.ts')
@@ -331,7 +356,7 @@ class LiveManager {
     const playlistIdMatcher = /^([\d+])-/
 
     const addHandler = segmentPath => {
-      logger.debug('Live add handler of %s.', segmentPath)
+      logger.debug('Live add handler of %s.', segmentPath, lTags(sessionId, videoUUID))
 
       const playlistId = basename(segmentPath).match(playlistIdMatcher)[0]
 
@@ -340,11 +365,23 @@ class LiveManager {
 
       segmentsToProcessPerPlaylist[playlistId] = [ segmentPath ]
 
+      if (this.hasClientSocketsInBadHealthWithCache(sessionId)) {
+        logger.error(
+          'Too much data in client socket stream (ffmpeg is too slow to transcode the video).' +
+          ' Stopping session of video %s.', videoUUID,
+          lTags(sessionId, videoUUID)
+        )
+
+        this.stopSessionOf(videoLive.videoId)
+        return
+      }
+
       // Duration constraint check
       if (this.isDurationConstraintValid(startStreamDateTime) !== true) {
-        logger.info('Stopping session of %s: max duration exceeded.', videoUUID)
+        logger.info('Stopping session of %s: max duration exceeded.', videoUUID, lTags(sessionId, videoUUID))
 
         this.stopSessionOf(videoLive.videoId)
+        return
       }
 
       // Check user quota if the user enabled replay saving
@@ -356,12 +393,12 @@ class LiveManager {
           .then(() => this.isQuotaConstraintValid(user, videoLive))
           .then(quotaValid => {
             if (quotaValid !== true) {
-              logger.info('Stopping session of %s: user quota exceeded.', videoUUID)
+              logger.info('Stopping session of %s: user quota exceeded.', videoUUID, lTags(sessionId, videoUUID))
 
               this.stopSessionOf(videoLive.videoId)
             }
           })
-          .catch(err => logger.error('Cannot stat %s or check quota of %d.', segmentPath, user.id, { err }))
+          .catch(err => logger.error('Cannot stat %s or check quota of %d.', segmentPath, user.id, { err, ...lTags(sessionId, videoUUID) }))
       }
     }
 
@@ -381,21 +418,21 @@ class LiveManager {
 
         setTimeout(() => {
           federateVideoIfNeeded(video, false)
-            .catch(err => logger.error('Cannot federate live video %s.', video.url, { err }))
+            .catch(err => logger.error('Cannot federate live video %s.', video.url, { err, ...lTags(sessionId, videoUUID) }))
 
           PeerTubeSocket.Instance.sendVideoLiveNewState(video)
         }, VIDEO_LIVE.SEGMENT_TIME_SECONDS * 1000 * VIDEO_LIVE.EDGE_LIVE_DELAY_SEGMENTS_NOTIFICATION)
 
       } catch (err) {
-        logger.error('Cannot save/federate live video %d.', videoLive.videoId, { err })
+        logger.error('Cannot save/federate live video %d.', videoLive.videoId, { err, ...lTags(sessionId, videoUUID) })
       } finally {
         masterWatcher.close()
-          .catch(err => logger.error('Cannot close master watcher of %s.', outPath, { err }))
+          .catch(err => logger.error('Cannot close master watcher of %s.', outPath, { err, ...lTags(sessionId, videoUUID) }))
       }
     })
 
     const onFFmpegEnded = () => {
-      logger.info('RTMP transmuxing for video %s ended. Scheduling cleanup', rtmpUrl)
+      logger.info('RTMP transmuxing for video %s ended. Scheduling cleanup', rtmpUrl, lTags(sessionId, videoUUID))
 
       this.transSessions.delete(sessionId)
 
@@ -416,10 +453,15 @@ class LiveManager {
               this.processSegments(outPath, videoUUID, videoLive, segmentsToProcessPerPlaylist[key])
             }
           })
-          .catch(err => logger.error('Cannot close watchers of %s or process remaining hash segments.', outPath, { err }))
+          .catch(err => {
+            logger.error(
+              'Cannot close watchers of %s or process remaining hash segments.', outPath,
+              { err, ...lTags(sessionId, videoUUID) }
+            )
+          })
 
         this.onEndTransmuxing(videoLive.Video.id)
-          .catch(err => logger.error('Error in closed transmuxing.', { err }))
+          .catch(err => logger.error('Error in closed transmuxing.', { err, ...lTags(sessionId, videoUUID) }))
       }, 1000)
     }
 
@@ -429,7 +471,7 @@ class LiveManager {
       // Don't care that we killed the ffmpeg process
       if (err?.message?.includes('Exiting normally')) return
 
-      logger.error('Live transcoding error.', { err, stdout, stderr })
+      logger.error('Live transcoding error.', { err, stdout, stderr, ...lTags(sessionId, videoUUID) })
 
       this.abortSession(sessionId)
     })
@@ -439,12 +481,12 @@ class LiveManager {
     ffmpegExec.run()
   }
 
-  private async onEndTransmuxing (videoId: number, cleanupNow = false) {
+  private async onEndTransmuxing (videoUUID: string, cleanupNow = false) {
     try {
-      const fullVideo = await VideoModel.loadAndPopulateAccountAndServerAndTags(videoId)
+      const fullVideo = await VideoModel.loadAndPopulateAccountAndServerAndTags(videoUUID)
       if (!fullVideo) return
 
-      const live = await VideoLiveModel.loadByVideoId(videoId)
+      const live = await VideoLiveModel.loadByVideoId(fullVideo.id)
 
       if (!live.permanentLive) {
         JobQueue.Instance.createJob({
@@ -465,13 +507,13 @@ class LiveManager {
 
       await federateVideoIfNeeded(fullVideo, false)
     } catch (err) {
-      logger.error('Cannot save/federate new video state of live streaming.', { err })
+      logger.error('Cannot save/federate new video state of live streaming of video %d.', videoUUID, { err, ...lTags(videoUUID) })
     }
   }
 
   private async addSegmentSha (videoUUID: string, segmentPath: string) {
     const segmentName = basename(segmentPath)
-    logger.debug('Adding live sha segment %s.', segmentPath)
+    logger.debug('Adding live sha segment %s.', segmentPath, lTags(videoUUID))
 
     const shaResult = await buildSha256Segment(segmentPath)
 
@@ -486,16 +528,16 @@ class LiveManager {
   private removeSegmentSha (videoUUID: string, segmentPath: string) {
     const segmentName = basename(segmentPath)
 
-    logger.debug('Removing live sha segment %s.', segmentPath)
+    logger.debug('Removing live sha segment %s.', segmentPath, lTags(videoUUID))
 
     const filesMap = this.segmentsSha256.get(videoUUID)
     if (!filesMap) {
-      logger.warn('Unknown files map to remove sha for %s.', videoUUID)
+      logger.warn('Unknown files map to remove sha for %s.', videoUUID, lTags(videoUUID))
       return
     }
 
     if (!filesMap.has(segmentName)) {
-      logger.warn('Unknown segment in files map for video %s and segment %s.', videoUUID, segmentPath)
+      logger.warn('Unknown segment in files map for video %s and segment %s.', videoUUID, segmentPath, lTags(videoUUID))
       return
     }
 
@@ -505,7 +547,7 @@ class LiveManager {
   private isDurationConstraintValid (streamingStartTime: number) {
     const maxDuration = CONFIG.LIVE.MAX_DURATION
     // No limit
-    if (maxDuration === null) return true
+    if (maxDuration < 0) return true
 
     const now = new Date().getTime()
     const max = streamingStartTime + maxDuration
@@ -513,6 +555,30 @@ class LiveManager {
     return now <= max
   }
 
+  private hasClientSocketsInBadHealth (sessionId: string) {
+    const rtmpSession = this.getContext().sessions.get(sessionId)
+
+    if (!rtmpSession) {
+      logger.warn('Cannot get session %s to check players socket health.', sessionId, lTags(sessionId))
+      return
+    }
+
+    for (const playerSessionId of rtmpSession.players) {
+      const playerSession = this.getContext().sessions.get(playerSessionId)
+
+      if (!playerSession) {
+        logger.error('Cannot get player session %s to check socket health.', playerSession, lTags(sessionId))
+        continue
+      }
+
+      if (playerSession.socket.writableLength > VIDEO_LIVE.MAX_SOCKET_WAITING_DATA) {
+        return true
+      }
+    }
+
+    return false
+  }
+
   private async isQuotaConstraintValid (user: MUserId, live: MVideoLive) {
     if (live.saveReplay !== true) return true
 
@@ -522,7 +588,7 @@ class LiveManager {
   private async updateLiveViews () {
     if (!this.isRunning()) return
 
-    if (!isTestInstance()) logger.info('Updating live video views.')
+    if (!isTestInstance()) logger.info('Updating live video views.', lTags())
 
     for (const videoId of this.watchersPerVideo.keys()) {
       const notBefore = new Date().getTime() - VIEW_LIFETIME.LIVE
@@ -543,15 +609,15 @@ class LiveManager {
       const newWatchers = watchers.filter(w => w > notBefore)
       this.watchersPerVideo.set(videoId, newWatchers)
 
-      logger.debug('New live video views for %s is %d.', video.url, numWatchers)
+      logger.debug('New live video views for %s is %d.', video.url, numWatchers, lTags())
     }
   }
 
   private async handleBrokenLives () {
-    const videoIds = await VideoModel.listPublishedLiveIds()
+    const videoUUIDs = await VideoModel.listPublishedLiveUUIDs()
 
-    for (const id of videoIds) {
-      await this.onEndTransmuxing(id, true)
+    for (const uuid of videoUUIDs) {
+      await this.onEndTransmuxing(uuid, true)
     }
   }