Merge f86258cd13 into 47ea6b5092

server/utils/ffmpegHelpers.js

@@ -106,6 +106,8 @@ module.exports.resizeImage = resizeImage
  */
 module.exports.downloadPodcastEpisode = (podcastEpisodeDownload) => {
   return new Promise(async (resolve) => {
+    const FFMPEG_PROGRESS_STALL_TIMEOUT_MS = 60000
+
     // Some podcasts fail due to user agent strings
     // See: https://github.com/advplyr/audiobookshelf/issues/3246 (requires iTMS user agent)
     // See: https://github.com/advplyr/audiobookshelf/issues/4401 (requires no iTMS user agent)
@@ -195,6 +197,31 @@ module.exports.downloadPodcastEpisode = (podcastEpisodeDownload) => {
 
     ffmpeg.addOutput(podcastEpisodeDownload.targetPath)
 
+    let ffmpegProgressWatchdog = null
+    let lastFfmpegProgressAt = 0
+    let killedForNoProgress = false
+
+    const clearProgressWatchdog = () => {
+      if (ffmpegProgressWatchdog) {
+        clearTimeout(ffmpegProgressWatchdog)
+        ffmpegProgressWatchdog = null
+      }
+    }
+
+    const scheduleProgressWatchdog = () => {
+      clearProgressWatchdog()
+      ffmpegProgressWatchdog = setTimeout(() => {
+        const timeSinceLastProgressMs = Date.now() - lastFfmpegProgressAt
+        if (timeSinceLastProgressMs < FFMPEG_PROGRESS_STALL_TIMEOUT_MS) {
+          return
+        }
+
+        killedForNoProgress = true
+        Logger.error(`[FfmpegHelpers] downloadPodcastEpisode: No ffmpeg progress for ${timeSinceLastProgressMs}ms, stopping download for "${podcastEpisodeDownload.url}"`)
+        ffmpeg.kill('SIGKILL')
+      }, FFMPEG_PROGRESS_STALL_TIMEOUT_MS)
+    }
+
     const stderrLines = []
     ffmpeg.on('stderr', (stderrLine) => {
       if (typeof stderrLine === 'string') {
@@ -203,8 +230,14 @@ module.exports.downloadPodcastEpisode = (podcastEpisodeDownload) => {
     })
     ffmpeg.on('start', (cmd) => {
       Logger.debug(`[FfmpegHelpers] downloadPodcastEpisode: Cmd: ${cmd}`)
+      lastFfmpegProgressAt = Date.now()
+      scheduleProgressWatchdog()
     })
     ffmpeg.on('error', (err) => {
+      clearProgressWatchdog()
+      if (killedForNoProgress) {
+        Logger.error(`[FfmpegHelpers] downloadPodcastEpisode: Killed after stalled progress for "${podcastEpisodeDownload.url}"`)
+      }
       Logger.error(`[FfmpegHelpers] downloadPodcastEpisode: Error ${err}`)
       if (stderrLines.length) {
         Logger.error(`Full stderr dump for episode url "${podcastEpisodeDownload.url}": ${stderrLines.join('\n')}`)
@@ -214,6 +247,9 @@ module.exports.downloadPodcastEpisode = (podcastEpisodeDownload) => {
       })
     })
     ffmpeg.on('progress', (progress) => {
+      lastFfmpegProgressAt = Date.now()
+      scheduleProgressWatchdog()
+
       let progressPercent = 0
       if (finalSizeInBytes && progress.targetSize && !isNaN(progress.targetSize)) {
         const finalSizeInKb = Math.floor(finalSizeInBytes / 1000)
@@ -222,6 +258,7 @@ module.exports.downloadPodcastEpisode = (podcastEpisodeDownload) => {
       Logger.debug(`[FfmpegHelpers] downloadPodcastEpisode: Progress estimate ${progressPercent.toFixed(0)}% (${progress?.targetSize || 'N/A'} KB) for "${podcastEpisodeDownload.url}"`)
     })
     ffmpeg.on('end', () => {
+      clearProgressWatchdog()
       Logger.debug(`[FfmpegHelpers] downloadPodcastEpisode: Complete`)
       resolve({
         success: true

server/utils/fileUtils.js

@@ -297,6 +297,8 @@ module.exports.getFilePathItemFromFileUpdate = (fileUpdate) => {
  */
 module.exports.downloadFile = (url, filepath, contentTypeFilter = null) => {
   return new Promise(async (resolve, reject) => {
+    const DOWNLOAD_STALL_TIMEOUT_MS = 60000
+
     Logger.debug(`[fileUtils] Downloading file to ${filepath}`)
     axios({
       url,
@@ -310,9 +312,42 @@ module.exports.downloadFile = (url, filepath, contentTypeFilter = null) => {
       httpsAgent: global.DisableSsrfRequestFilter?.(url) ? null : ssrfFilter(url)
     })
       .then((response) => {
+        let isSettled = false
+        let downloadStallWatchdog = null
+
+        const clearDownloadStallWatchdog = () => {
+          if (downloadStallWatchdog) {
+            clearTimeout(downloadStallWatchdog)
+            downloadStallWatchdog = null
+          }
+        }
+
+        const scheduleDownloadStallWatchdog = () => {
+          clearDownloadStallWatchdog()
+          downloadStallWatchdog = setTimeout(() => {
+            Logger.error(`[fileUtils] File "${Path.basename(filepath)}" download stalled (no data for ${DOWNLOAD_STALL_TIMEOUT_MS}ms)`)
+            const timeoutError = new Error(`Download stalled for ${DOWNLOAD_STALL_TIMEOUT_MS}ms`)
+            response.data.destroy(timeoutError)
+            writer.destroy(timeoutError)
+            settle(timeoutError)
+          }, DOWNLOAD_STALL_TIMEOUT_MS)
+        }
+
+        const settle = (error = null) => {
+          if (isSettled) return
+          isSettled = true
+          clearDownloadStallWatchdog()
+          if (error) {
+            reject(error)
+          } else {
+            resolve()
+          }
+        }
+
         // Validate content type
         if (contentTypeFilter && !contentTypeFilter?.(response.headers?.['content-type'])) {
-          return reject(new Error(`Invalid content type "${response.headers?.['content-type'] || ''}"`))
+          response.data.destroy(new Error('Invalid content type'))
+          return settle(new Error(`Invalid content type "${response.headers?.['content-type'] || ''}"`))
         }
 
         const totalSize = parseInt(response.headers['content-length'], 10)
@@ -322,8 +357,11 @@ module.exports.downloadFile = (url, filepath, contentTypeFilter = null) => {
         const writer = fs.createWriteStream(filepath)
         response.data.pipe(writer)
 
+        scheduleDownloadStallWatchdog()
+
         let lastProgress = 0
         response.data.on('data', (chunk) => {
+          scheduleDownloadStallWatchdog()
           downloadedSize += chunk.length
           const progress = totalSize ? Math.round((downloadedSize / totalSize) * 100) : 0
           if (progress >= lastProgress + 5) {
@@ -332,8 +370,11 @@ module.exports.downloadFile = (url, filepath, contentTypeFilter = null) => {
           }
         })
 
-        writer.on('finish', resolve)
+        response.data.on('error', (err) => {
-        writer.on('error', reject)
+          settle(err)
+        })
+        writer.on('finish', () => settle())
+        writer.on('error', (err) => settle(err))
       })
       .catch((err) => {
         Logger.error(`[fileUtils] Failed to download file "${filepath}"`, err)