Jump to content

ghost stream cooked my NAS's processor overnight (~15 hrs)

EatPrilosec

By EatPrilosec
in Linux

 Share

Recommended Posts

EatPrilosec

EatPrilosec 22

Posted
Posted




basic environment info:
host 

$ cat /etc/*-release
PRETTY_NAME="Debian GNU/Linux 12 (bookworm)"
NAME="Debian GNU/Linux"
VERSION_ID="12"
VERSION="12 (bookworm)"
VERSION_CODENAME=bookworm
ID=debian

official docker container w/intel hw accel (n100, UHD Graphics 730, Alder Lake)

yesterday (6/29) i was using a pixel 8 pro, android 14, to watch a 4k HDR video, i believe transcoded to 1080p 40mbps, when suddenly it froze. i backed out, moved closer to the router and tried again ang got the good ol' "No compatible streams are currently available. Please try again later or contact your system administrator for details." error. 

i tried another video, sdr, prolly 480p directplay iirc, and forced it to transcode to 144p test hw accel. worked fine. went back to the 4k hdr, playback error. i then tested every other hdr movie (the other 2 lol) i had, playback error.

about 30 mins later, i had gotten to my computer and opened the server dashboard, the 4k movie i was trying to watch, was reported as playing, transcoding, but the bar was full, and the counter wasn't moving. i tried pressing the stop button a few times, nothing happened. so i restarted the emby server using the three dots. stream went away, movies started playing again, chalked it up to a random occurrence (for now, until it happens again) 

i wake up this morning and go to use my nas for some unrelated cpu intensive stuff and its notably slower than normal so i open htop to check it out, and an ffmpeg is using 101% of cpu, and has been for 14 hours, my temp is 83c. highest I've ever seen it. obviously, and to be extra clear, i am not claiming emby liability for any hardware damage it could have done, nor have i noticed any, but this is scary. i  sudo kill 'd  the process before getting the command line arguments, or screenshot, but i have the log for the transcode and it confirms the runtime thankfully. 

i know it wouldn't have mattered because i restarted the server, but does emby have ANY failsafe for a ghost stream if i hadn't killed it, like, if that ffmpeg process kept going for X amt of hours, would emby have killed it? for now im going to turn on throttling just in case, and try to write a script to kill ffmpeg processes longer than 6-7 hrs or so, just in case it happens again. ill get the script to email me if it happens, so i can grab the transcode log again.

ffmpeg-transcode-bca6ffef-2c5c-421d-8f81-bd8a127686bf_1.txt

Luke Emby Team

Luke 42077

Posted
Posted

Hi, please attach the main emby server log as well. Thanks.

Luke Emby Team

Luke 42077

Posted
Posted

Hi, I don't think your high cpu usage is related to this. I think it's related to all of the plugins that you've installed. I would try removing these plugins: 

2024-06-30 21:57:29.212 Info App: Loading Emby.AdminBuddy, Version=1.0.0.2, Culture=neutral, PublicKeyToken=null from /config/plugins/AdminBuddy.dll
2024-06-30 21:57:29.212 Info App: Loading DiskSpace, Version=1.0.6.3, Culture=neutral, PublicKeyToken=null from /config/plugins/DiskSpace.dll
2024-06-30 21:57:29.212 Info App: Loading ClassificationMapper, Version=1.0.0.4, Culture=neutral, PublicKeyToken=null from /config/plugins/ClassificationMapper.dll
2024-06-30 21:57:29.212 Info App: Loading EpMetaRefresh, Version=1.0.0.1, Culture=neutral, PublicKeyToken=null from /config/plugins/EpMetaRefresh.dll
2024-06-30 21:57:29.212 Info App: Loading Emby.MediaInfo, Version=1.0.1.20, Culture=neutral, PublicKeyToken=null from /config/plugins/Emby.MediaInfo.dll
2024-06-30 21:57:29.212 Info App: Loading Emby.SubKiller, Version=1.0.0.9, Culture=neutral, PublicKeyToken=null from /config/plugins/Emby.SubKiller.dll
2024-06-30 21:57:29.212 Info App: Loading VirtualTV, Version=2.0.3.0, Culture=neutral, PublicKeyToken=null from /config/plugins/VirtualTV.dll
2024-06-30 21:57:29.212 Info App: Loading Emby.DiagnosticsPlugin, Version=4.8.0.80, Culture=neutral, PublicKeyToken=null from /config/plugins/Emby.DiagnosticsPlugin.dll
2024-06-30 21:57:29.212 Info App: Loading Emby.TranscodingTestPlugin, Version=4.8.0.67, Culture=neutral, PublicKeyToken=null from /config/plugins/Emby.TranscodingTestPlugin.dll
2024-06-30 21:57:29.213 Info App: Loading MovieThemeSongs, Version=1.8.1.0, Culture=neutral, PublicKeyToken=null from /config/plugins/moviethemesongs.dll
2024-06-30 21:57:29.213 Info App: Loading MovieThemeVideos, Version=1.8.2.0, Culture=neutral, PublicKeyToken=null from /config/plugins/MovieThemeVideos.dll

Then restart the server and see how things compare.

isamudaison

isamudaison 12

Posted
Posted

I noticed this as well, seems to have started happening after 4.8.8 upgrade. I'm running a 5.15 kernel and nvidia transcoder. I found ffmpeg had processes gone awry, pegging actual CPU cores - killing them solved it (however, the dashboard UI still incorrectly shows a bunch of 'in-progress' transcodes).

EatPrilosec

EatPrilosec 22

Posted
  • Author
Posted (edited)
On 7/2/2024 at 2:46 AM, Luke said:

Hi, I don't think your high cpu usage is related to this. I think it's related to all of the plugins that you've installed. I would try removing these plugins: 

2024-06-30 21:57:29.212 Info App: Loading Emby.AdminBuddy, Version=1.0.0.2, Culture=neutral, PublicKeyToken=null from /config/plugins/AdminBuddy.dll
2024-06-30 21:57:29.212 Info App: Loading DiskSpace, Version=1.0.6.3, Culture=neutral, PublicKeyToken=null from /config/plugins/DiskSpace.dll
2024-06-30 21:57:29.212 Info App: Loading ClassificationMapper, Version=1.0.0.4, Culture=neutral, PublicKeyToken=null from /config/plugins/ClassificationMapper.dll
2024-06-30 21:57:29.212 Info App: Loading EpMetaRefresh, Version=1.0.0.1, Culture=neutral, PublicKeyToken=null from /config/plugins/EpMetaRefresh.dll
2024-06-30 21:57:29.212 Info App: Loading Emby.MediaInfo, Version=1.0.1.20, Culture=neutral, PublicKeyToken=null from /config/plugins/Emby.MediaInfo.dll
2024-06-30 21:57:29.212 Info App: Loading Emby.SubKiller, Version=1.0.0.9, Culture=neutral, PublicKeyToken=null from /config/plugins/Emby.SubKiller.dll
2024-06-30 21:57:29.212 Info App: Loading VirtualTV, Version=2.0.3.0, Culture=neutral, PublicKeyToken=null from /config/plugins/VirtualTV.dll
2024-06-30 21:57:29.212 Info App: Loading Emby.DiagnosticsPlugin, Version=4.8.0.80, Culture=neutral, PublicKeyToken=null from /config/plugins/Emby.DiagnosticsPlugin.dll
2024-06-30 21:57:29.212 Info App: Loading Emby.TranscodingTestPlugin, Version=4.8.0.67, Culture=neutral, PublicKeyToken=null from /config/plugins/Emby.TranscodingTestPlugin.dll
2024-06-30 21:57:29.213 Info App: Loading MovieThemeSongs, Version=1.8.1.0, Culture=neutral, PublicKeyToken=null from /config/plugins/moviethemesongs.dll
2024-06-30 21:57:29.213 Info App: Loading MovieThemeVideos, Version=1.8.2.0, Culture=neutral, PublicKeyToken=null from /config/plugins/MovieThemeVideos.dll

Then restart the server and see how things compare.

i actually installed more plugins after this happened, and my servers cpu is currently 30-60. emby is not the only thing it runs. it only tops out like that when i transcode (not direct play) a 4k HDR video. thats expected. the problem is the stream lasted 15 hrs and only stopped because i manually killed the process via PID in a SSH terminal. also the movie is i think only 2 or 3 hrs. 

  

elapsed=14:57:58.21 frame= 1110 fps=0.0 q=26.0 Lq=-1.0 q=-1.0 size=N/A time=00:00:00.00 bitrate=N/A throttle=off speed=3.8e-09x    
video:315949kB audio:2170kB subtitle:0kB other streams:0kB global headers:2kB muxing overhead: unknown
Exiting normally, received signal 15.
EXIT

the " elapsed=14:57:58.21  frame= 1110 fps=0.0 " part being the issue. 

Edited by EatPrilosec
EatPrilosec

EatPrilosec 22

Posted
  • Author
Posted (edited)
22 hours ago, isamudaison said:

I noticed this as well, seems to have started happening after 4.8.8 upgrade. I'm running a 5.15 kernel and nvidia transcoder. I found ffmpeg had processes gone awry, pegging actual CPU cores - killing them solved it (however, the dashboard UI still incorrectly shows a bunch of 'in-progress' transcodes).

i can share my ffmpeg monitor/kill script once i get it working nicely if youre interested

fwiw, im using a 6.5.13 kernel

Edited by EatPrilosec
isamudaison

isamudaison 12

Posted
Posted
14 minutes ago, EatPrilosec said:

i can share my ffmpeg monitor/kill script once i get it working nicely if youre interested

fwiw, im using a 6.5.13 kernel

That's probably a good best-practice 'in general', but currently my Emby container restarts once a week (unrelated to this issue) and that should suffice for now. I did notice your list of plugins & mine share one common entry - Emby.DiagnosticsPlugin. I've removed that one and am keeping an eye on it for now, will report back next week to see if the issue has been resolved.

  • Like 1
EatPrilosec

EatPrilosec 22

Posted
  • Author
Posted (edited)
5 hours ago, isamudaison said:

That's probably a good best-practice 'in general', but currently my Emby container restarts once a week (unrelated to this issue) and that should suffice for now. I did notice your list of plugins & mine share one common entry - Emby.DiagnosticsPlugin. I've removed that one and am keeping an eye on it for now, will report back next week to see if the issue has been resolved.

ill keep mine installed just to see the difference. 

heres the script so far in case you want it. does NOT need to be ran in the container for it to work, btw. systemd service example at the bottom

the script will
 

  • check for rampent ffmpeg streams
  • with a filter check for unrelated streams
  • kill the ffmpeg process gracefully, at first, or forcefully if needed.
  • copy the log(s) to the script folder, organized by stream UUID. and all the embyserver.txt logs, for redundancy.

  

#!/bin/bash

#vars
RunHowOftenInMinutes=1.5

TimeBeforeKill_Hours=3
TimeBeforeKill_Minutes=30

EmbyLogFolder=/DockerData/emby/programdata/logs

### comma-separated list of filters (using grep) of terms to ignore in an ffmpeg command line. (useful if you have security cameras)
ffmpeg_process_filters="/Storage/Media/CCTV,SOME_PATHS/YOU/WANT/IGNORED"

#vars end

TimeBeforeKill=$(((($TimeBeforeKill_Hours * 60) + ($TimeBeforeKill_Minutes)) * 60 ))

while true; do
  rest=$RunHowOftenInMinutes
  while read -r ffmpeg_instance; do

    ### collect ffmpeg pids and runtime
    ThisPID=`echo "$ffmpeg_instance"|tr -s ' '|cut -d" " -f1` 
    ThisTIME=`echo "$ffmpeg_instance"|tr -s ' '|cut -d" " -f2` 
    ThisLINE=`ps -o command= $ThisPID` 

    ### ignore if not past threshold
    if [ ! $ThisTIME -ge $TimeBeforeKill ]; then
        continue
    fi

    ### ignore filters
    for i in ${ffmpeg_process_filters//,/ }
    do
        echo checking for $i in runline
        echo
        thisfilterfound=0
        echo $ThisLINE | grep "$i" >/dev/null && thisfilterfound=1
        if [ $thisfilterfound -eq 1 ]; then
          echo found $i in runline, skipping
          echo
          continue
        fi
    done

    echo "---------------------------------------------------------------"
    echo Found a possible runaway ghost stream
    echo
    echo PID: $ThisPID
    echo Runtime: $((ThisTIME / 3600)) hrs and $(( (ThisTIME % 3600) / 60 )) minutes
    echo
    echo Command: $ThisLINE
    echo
    echo
    echo attempting to kill ffmpeg PID $ThisPID
    echo
    exit
    ### Kill Ghost Streams

    export killed="NONE (failed to kill)"
    echo attempting SIGINT kill on ffmpeg PID $ThisPID
    echo
    kill -n 2 $ThisPID 
    sleep 15
    ps $ThisPID >/dev/null || export killed=SIGINT 

    if [ "$killed" == "NONE (failed to kill)" ];then 
      echo attempting SIGTERM kill on ffmpeg PID $ThisPID
      echo
      kill -n 15 $ThisPID 
      sleep 15
      ps $ThisPID >/dev/null || export killed=SIGTERM
    fi

    if [ "$killed" == "NONE (failed to kill)" ];then  
      echo attempting SIGKILL kill on ffmpeg PID $ThisPID
      echo
      kill -n 9 $ThisPID 
      sleep 15
      ps $ThisPID >/dev/null || export killed=SIGKILL
    fi 
    
  
    echo "Killed via $killed"
    echo

    ### find log

    GraphFile=`echo $ThisLINE | grep -oE '\-print_graphs_file /.*/ffmpeg-.*-(.*)_.*.txt'`

    GraphFile=${GraphFile##*/}

    
    UUID=` echo ${GraphFile} |sed 's/ffmpeg-transcode-//' |sed 's/ffmpeg-directstream-//' | cut -d_ -f1`

    TCLogFilePrefix="ffmpeg-transcode-$UUID"
    DSLogFilePrefix="ffmpeg-directstream-$UUID"

    ### copy in script directory 

    SOURCE=${BASH_SOURCE[0]}
    while [ -L "$SOURCE" ]; do # resolve $SOURCE until the file is no longer a symlink
      DIR=$( cd -P "$( dirname "$SOURCE" )" >/dev/null 2>&1 && pwd )
      SOURCE=$(readlink "$SOURCE")
      [[ $SOURCE != /* ]] && SOURCE=$DIR/$SOURCE # if $SOURCE was a relative symlink, we need to resolve it relative to the path where the symlink file was located
    done
    ScriptDir=$( cd -P "$( dirname "$SOURCE" )" >/dev/null 2>&1 && pwd )

    mkdir -p $ScriptDir/KilledTranscodes/$UUID >/dev/null 2>&1
    mkdir $ScriptDir/KilledTranscodes/$UUID/embyservers >/dev/null 2>&1

    cp $EmbyLogFolder/${TCLogFilePrefix}* $ScriptDir/KilledTranscodes/$UUID/ >/dev/null 2>&1
    cp $EmbyLogFolder/${DSLogFilePrefix}* $ScriptDir/KilledTranscodes/$UUID/ >/dev/null 2>&1
    cp $EmbyLogFolder/$GraphFile $ScriptDir/KilledTranscodes/$UUID/ >/dev/null 2>&1
    cp $EmbyLogFolder/embyserver*.txt $ScriptDir/KilledTranscodes/$UUID/embyservers/ >/dev/null 2>&1


    echo logs copied to $ScriptDir/KilledTranscodes/$UUID/
    echo "---------------------------------------------------------------"
    echo
  done < <(ps -o pid=,etimes= -C ffmpeg)

  ### sleep until next check
  rest=`bc <<< "scale=2; $rest*60"`
  echo waiting for $rest seconds

  sleep $rest

done

exit 0

service file example:

[Unit]
Description=ffmonkill service

[Service]
ExecStart=/path/to/script/ffmonkill.sh

[Install]
WantedBy=multi-user.target

 

Edited by EatPrilosec
  • Like 1
isamudaison

isamudaison 12

Posted
Posted

Just a bit of an update here: After removing the Diagnostic plugin, it seems like all the 'stuck stream' issues have gone away. Ironic! I'll continue to monitor and report back towards the end of the week.

  • Thanks 1
EatPrilosec

EatPrilosec 22

Posted
  • Author
Posted

i have had all my 4k john wicks playing in the background for a week or so off and on, has not happened again, with diagnostics plugin still installed.

im going to keep my script going for safe measure and pretend this steam never happened lol

  • Thanks 1
sa2000

sa2000 674

Posted
Posted (edited)

Looked at the transcoder ffmpeg log and the server log from the 29th June, the transcoder log showed no activity after segment 2615 (3 second segments) was being processed for the emby client app - a remote WAN connection from a It seems that the remote device streaming this video - a Pixel 8 Pro running Plex for Android 3.4.08 - with server running on 4.8.8.0.  

22:12:52.109 [segment @ 0x1cc26c0] Opening '/transcode/t-temp/transcoding-temp/02747D/02747D_2614.ts.tmp' for writing
22:12:52.819 [segment @ 0x1cc26c0] Opening '/transcode/t-temp/transcoding-temp/02747D/02747D.m3u8.tmp' for writing
22:12:52.819 SegmentComplete=video:0 Index=2614 Start=7842.042333 End=7845.045333 Duration=3.003000 offset_pts=0 start_pts=7842042333 Frames=72 filename=02747D_2614.ts
22:12:52.819 [segment @ 0x1cc26c0] Opening '/transcode/t-temp/transcoding-temp/02747D/02747D_2615.ts.tmp' for writing
22:12:52.957 [hevc_qsv @ 0x19eee80] A decode call did not consume any data: expect more data at input (-10)
    Last message repeated 2 times
13:10:39.779 Finishing stream 1:0 without any data written to it.
13:10:39.820 Output #1, segment, to '/transcode/t-temp/transcoding-temp/02747D/02747D_s8_%d.vtt':
13:10:39.820   Metadata:
13:10:39.820     encoder         : Lavf59.27.100
13:10:39.820   Stream #1:0: Subtitle: webvtt (default)
13:10:39.820     Metadata:
13:10:39.820       encoder         : Lavc59.37.100 webvtt
13:10:39.820   Stream #1:1: Video: hevc (Main 10), yuv420p10le(tv, bt2020nc/bt2020/smpte2084), 3840x2160 [SAR 1:1 DAR 16:9], q=2-31, Level 153, 23.98 fps, 23.98 tbr, 23.98 tbn
13:10:39.820     Side data:
13:10:39.820       DOVI configuration record: version: 1.0, profile: 7, level: 6, rpu flag: 1, el flag: 1, bl flag: 1, compatibility id: 6

The server log shows that after requesting segment 2615, the android device was no longer in communication with the server until just over an hour later coming back on a different WAN IP address and started a new direct play stream playback session for another video at 23:16. i don't know if there is a problem with the video "John Wick Chapter 3 - Parabellum (2019) Remux-2160p Proper.mkv" around that offset - would be around 2 hours 10 minutes in 

The server log shows no further activity for the orphaned transcoder playback session and this is the server log during the period when the android device stopped requesting transcoded segments for the John Wick movie and started direct play for another movie 

2024-06-29 22:13:19.551 Info Server: http/1.1 GET http://emby_remote_ip/emby/videos/70767/hls1/subs/2615.vtt?PlaySessionId=abe97ea57af64b32b2db14ce097b8b18&VttTimestampMap=900000&CurrentSubtitleStreamIndex=8. Connection=Upgrade, Host=emby_remote_ip, User-Agent=Emby/3.4.08 (Linux;Android 14) AndroidXMedia3/1.1.1, Accept-Encoding=identity, X-Real-IP=host28, X-Forwarded-For=host28
2024-06-29 22:13:21.848 Info Server: http/1.1 GET http://emby_remote_ip/emby/videos/70767/hls1/main/2615.ts?PlaySessionId=abe97ea57af64b32b2db14ce097b8b18. Connection=Upgrade, Host=emby_remote_ip, User-Agent=Emby/3.4.08 (Linux;Android 14) AndroidXMedia3/1.1.1, Accept-Encoding=identity, X-Real-IP=host28, X-Forwarded-For=host28
2024-06-29 22:13:21.849 Info App: Returning empty segment at the end. RequestedSeconds: 7845, RuntimeSeconds: 7846.336, SegmentLength: 3
2024-06-29 22:13:21.853 Info Server: http/1.1 Response 200 to host28. Time: 6ms. GET http://emby_remote_ip/emby/videos/70767/hls1/main/2615.ts?PlaySessionId=abe97ea57af64b32b2db14ce097b8b18
2024-06-29 22:13:25.581 Info Server: http/1.1 Response 200 to host28. Time: 6031ms. GET http://emby_remote_ip/emby/videos/70767/hls1/subs/2615.vtt?PlaySessionId=abe97ea57af64b32b2db14ce097b8b18&VttTimestampMap=900000&CurrentSubtitleStreamIndex=8
2024-06-29 23:16:47.135 Info Server: http/1.1 POST http://emby_remote_ip/emby/Sessions/Capabilities/Full?X-Emby-Client=Emby for Android&X-Emby-Device-Name=Pixel 8 Pro&X-Emby-Device-Id=7e0d7f0f19d5f141&X-Emby-Client-Version=3.4.08&X-Emby-Token=x_secret2_x&X-Emby-Language=en-us&reqformat=json. UserAgent: Mozilla/5.0 (Linux; Android 14; Pixel 8 Pro Build/AP2A.240605.024; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/126.0.6478.133 Mobile Safari/537.36
2024-06-29 23:16:47.136 Info Server: http/1.1 Response 204 to host36. Time: 1ms. POST http://emby_remote_ip/emby/Sessions/Capabilities/Full?X-Emby-Client=Emby for Android&X-Emby-Device-Name=Pixel 8 Pro&X-Emby-Device-Id=7e0d7f0f19d5f141&X-Emby-Client-Version=3.4.08&X-Emby-Token=x_secret2_x&X-Emby-Language=en-us&reqformat=json
. . . 
2024-06-29 23:16:51.382 Info Server: http/1.1 POST http://emby_remote_ip/emby/Items/71631/PlaybackInfo?UserId=2703a7ddf3e942229a39fb01acf17d8f&StartTimeTicks=0&IsPlayback=false&AutoOpenLiveStream=false&MaxStreamingBitrate=8000001&X-Emby-Client=Emby for Android&X-Emby-Device-Name=Pixel 8 Pro&X-Emby-Device-Id=7e0d7f0f19d5f141&X-Emby-Client-Version=3.4.08&X-Emby-Token=x_secret2_x&X-Emby-Language=en-us&reqformat=json. UserAgent: Mozilla/5.0 (Linux; Android 14; Pixel 8 Pro Build/AP2A.240605.024; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/126.0.6478.133 Mobile Safari/537.36
2024-06-29 23:16:51.391 Info App: User policy for EatPrilosec. EnablePlaybackRemuxing: True EnableVideoPlaybackTranscoding: True EnableAudioPlaybackTranscoding: True
2024-06-29 23:16:51.398 Info Server: http/1.1 Response 200 to host36. Time: 16ms. POST http://emby_remote_ip/emby/Items/71631/PlaybackInfo?UserId=2703a7ddf3e942229a39fb01acf17d8f&StartTimeTicks=0&IsPlayback=false&AutoOpenLiveStream=false&MaxStreamingBitrate=8000001&X-Emby-Client=Emby for Android&X-Emby-Device-Name=Pixel 8 Pro&X-Emby-Device-Id=7e0d7f0f19d5f141&X-Emby-Client-Version=3.4.08&X-Emby-Token=x_secret2_x&X-Emby-Language=en-us&reqformat=json
2024-06-29 23:16:52.100 Info HttpClient: GET https://image.tmdb.org/t/p/original/silK3Pdugbf1YOtIdXev1eZxzvF.jpg
2024-06-29 23:16:52.694 Info Server: http/1.1 POST http://emby_remote_ip/emby/Items/71631/PlaybackInfo?UserId=2703a7ddf3e942229a39fb01acf17d8f&StartTimeTicks=1088500000&IsPlayback=true&AutoOpenLiveStream=true&AudioStreamIndex=1&SubtitleStreamIndex=-1&MediaSourceId=0a2e3889c164ee14c33bc216cc0f2932&MaxStreamingBitrate=8000001&X-Emby-Client=Emby for Android&X-Emby-Device-Name=Pixel 8 Pro&X-Emby-Device-Id=7e0d7f0f19d5f141&X-Emby-Client-Version=3.4.08&X-Emby-Token=x_secret2_x&X-Emby-Language=en-us&reqformat=json. UserAgent: Mozilla/5.0 (Linux; Android 14; Pixel 8 Pro Build/AP2A.240605.024; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/126.0.6478.133 Mobile Safari/537.36
2024-06-29 23:16:52.698 Info App: User policy for EatPrilosec. EnablePlaybackRemuxing: True EnableVideoPlaybackTranscoding: True EnableAudioPlaybackTranscoding: True
2024-06-29 23:16:52.698 Info SessionManager: Adding playSession 6ad2fbca31de476d9d3e0b3958f78d42 to session d3713008d59c7afb3563043cdfa7e6f4
2024-06-29 23:16:52.698 Info Server: http/1.1 Response 200 to host36. Time: 5ms. POST http://emby_remote_ip/emby/Items/71631/PlaybackInfo?UserId=2703a7ddf3e942229a39fb01acf17d8f&StartTimeTicks=1088500000&IsPlayback=true&AutoOpenLiveStream=true&AudioStreamIndex=1&SubtitleStreamIndex=-1&MediaSourceId=0a2e3889c164ee14c33bc216cc0f2932&MaxStreamingBitrate=8000001&X-Emby-Client=Emby for Android&X-Emby-Device-Name=Pixel 8 Pro&X-Emby-Device-Id=7e0d7f0f19d5f141&X-Emby-Client-Version=3.4.08&X-Emby-Token=x_secret2_x&X-Emby-Language=en-us&reqformat=json
2024-06-29 23:16:52.711 Info Server: http/1.1 POST http://emby_remote_ip/emby/Items/71631/PlaybackInfo?UserId=2703a7ddf3e942229a39fb01acf17d8f&StartTimeTicks=0&IsPlayback=false&AutoOpenLiveStream=false&MaxStreamingBitrate=8000001&X-Emby-Client=Emby for Android&X-Emby-Device-Name=Pixel 8 Pro&X-Emby-Device-Id=7e0d7f0f19d5f141&X-Emby-Client-Version=3.4.08&X-Emby-Token=x_secret2_x&X-Emby-Language=en-us&reqformat=json. UserAgent: Mozilla/5.0 (Linux; Android 14; Pixel 8 Pro Build/AP2A.240605.024; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/126.0.6478.133 Mobile Safari/537.36
2024-06-29 23:16:52.712 Info App: User policy for EatPrilosec. EnablePlaybackRemuxing: True EnableVideoPlaybackTranscoding: True EnableAudioPlaybackTranscoding: True
2024-06-29 23:16:52.712 Info Server: http/1.1 Response 200 to host36. Time: 2ms. POST http://emby_remote_ip/emby/Items/71631/PlaybackInfo?UserId=2703a7ddf3e942229a39fb01acf17d8f&StartTimeTicks=0&IsPlayback=false&AutoOpenLiveStream=false&MaxStreamingBitrate=8000001&X-Emby-Client=Emby for Android&X-Emby-Device-Name=Pixel 8 Pro&X-Emby-Device-Id=7e0d7f0f19d5f141&X-Emby-Client-Version=3.4.08&X-Emby-Token=x_secret2_x&X-Emby-Language=en-us&reqformat=json
2024-06-29 23:16:53.482 Info Server: http/1.1 GET http://emby_remote_ip/emby/videos/71631/original.mp4?DeviceId=7e0d7f0f19d5f141&MediaSourceId=0a2e3889c164ee14c33bc216cc0f2932&PlaySessionId=6ad2fbca31de476d9d3e0b3958f78d42&api_key=x_secret2_x. Connection=Upgrade, Host=emby_remote_ip, User-Agent=Emby/3.4.08 (Linux;Android 14) AndroidXMedia3/1.1.1, Accept-Encoding=identity, X-Real-IP=host36, X-Forwarded-For=host36, icy-metadata=1
2024-06-29 23:17:00.375 Info Server: http/1.1 Response 200 to host36. Time: 6893ms. GET http://emby_remote_ip/emby/videos/71631/original.mp4?DeviceId=7e0d7f0f19d5f141&MediaSourceId=0a2e3889c164ee14c33bc216cc0f2932&PlaySessionId=6ad2fbca31de476d9d3e0b3958f78d42&api_key=x_secret2_x

 

@Lukeis the gap in the ffmpeg log between 22:12:52.957 and 13:10:39.779 indicative of a problem with handling the movie file data around that offset ? 

22:12:52.819 [segment @ 0x1cc26c0] Opening '/transcode/t-temp/transcoding-temp/02747D/02747D_2615.ts.tmp' for writing
22:12:52.957 [hevc_qsv @ 0x19eee80] A decode call did not consume any data: expect more data at input (-10)
    Last message repeated 2 times
13:10:39.779 Finishing stream 1:0 without any data written to it.
13:10:39.820 Output #1, segment, to '/transcode/t-temp/transcoding-temp/02747D/02747D_s8_%d.vtt':

It actually went back to segment 2601 after this.

and what should / expected to happen to an orphaned transcoder process? Does it run to the end? The android phone device that instigated this transcode switched to streaming a different movie at 23:16 - Direct Playing. 

Edited by sa2000
  • Thanks 1
  • 2 weeks later...
EatPrilosec

EatPrilosec 22

Posted
  • Author
Posted

just to comment on your observations:

On 7/11/2024 at 6:50 AM, sa2000 said:

i don't know if there is a problem with the video "John Wick Chapter 3 - Parabellum (2019) Remux-2160p Proper.mkv" around that offset - would be around 2 hours 10 minutes in 

 

fwiw, ive plyed the full video before, and after this event with no issues. but during the event, none of the 4k vids i tried worked (transcoded) until i manually killed the stray ffmpeg process, and yes, it was on the pixel 8 pro, from wan, that the video initially stopped working. it just froze, so i backed out and tried again, and got the error. pressing stop on the dashboard on the stream did nothing, restarting the server made transcoding 4k fail (but not other formats)  

i also remember trying other audio streams with the same error result. 

 

On 7/11/2024 at 6:50 AM, sa2000 said:

and what should / expected to happen to an orphaned transcoder process? Does it run to the end? The android phone device that instigated this transcode switched to streaming a different movie at 23:16 - Direct Playing. 

while the pixel was streaming the directplay, the dashboard showed one stream, and it would flicker between the ghost stream and the direct play stream. it was very odd.

at this point my theory is the cause was a stray bug with intel hw tone mapping on this non-typical processor? 

 

Happy2Play

Happy2Play 9780

Posted
Posted
14 hours ago, EatPrilosec said:

while the pixel was streaming the directplay, the dashboard showed one stream, and it would flicker between the ghost stream and the direct play stream. it was very odd

Yes all abandoned/duplicate sessions from same device client will bounce back and forth just like opening two browser tabs and playing something in each as the server see the device with two sessions whether active or stuck/abandoned on occasion.  And the only way to clear is restarting Emby.  As this is not limited to any specific client and there are several topics recently on it so not sure is something is amiss in current release.  But in the end it appears Random as no one can consistently replicate the issue so far.

  • Like 1

Create an account or sign in to comment

You need to be a member in order to leave a comment

Create an account

Sign up for a new account in our community. It's easy!

Register a new account

Sign in

Already have an account? Sign in here.

Sign In Now
 Share
Go to topic listing
×
×
  • Create New...