Transcoding doesn't stop after stopping playback

[tsavisky 1]

Hi, I know this topic has been brought up a few times, but I haven't seen any resolution to it yet. I was finally able to identify a couple logs that are for streams that remain open after user ends playback.  The user is remotely connecting to my emby server from a Roku Tv and after they stop playing/exit the app the server continues to transcode in the temp folder until disk space runs out and my server becomes sluggish (which is usually when I notice the issue). A restart will typically clear the temp folder, but its frustrating having to babysit the server. I've attached 2 log files and a screenshot showing the temp files are still on my drive and growing. 

ffmpeg-transcode-f229e386-a898-4399-8322-8811e3ebe222_1.txt ffmpeg-transcode-18e5f25f-caee-417d-b859-b9e8b8b619a1_1.txt

[ebr 14919]

7 hours ago, tsavisky said:

and after they stop playing/exit the app

Hi.  Do you know exactly how they are doing that?

[tsavisky 1]

They said they end the stream by hitting the back button. They don't just turn off the TV or hit the home button. 

[Luke 37091]

Hi, can you please attach the corresponding emby server log as well? Thanks.

[econ 74]

I am seeing this exact issue as well.  It is happening with a Roku, Fire Stick and Chrome.  I will post the server log later this evening.

[tsavisky 1]

Here are the two server logs that capture the time frame of the transcoding logs I uploaded.

embyserver-63804067200.txt embyserver-63803980800.txt

[Happy2Play 8293]

Looks like the transcode is deleted as neither subfolder exists (961FF7 or 405193).

2022-11-13 20:20:29.559 Info App: ProcessRun 'StreamTranscode f229e3': Stopping ffmpeg process with q command for C:\Users\Server\AppData\Roaming\Emby-Server\transcoding-temp\961FF7\961FF7_0.ts
2022-11-13 20:20:29.639 Info App: AppendExtraLogData - Read graph file: C:\Users\Server\AppData\Roaming\Emby-Server\logs\ffmpeg-transcode-f229e386-a898-4399-8322-8811e3ebe222_1graph.txt
2022-11-13 20:20:29.653 Info App: AppendExtraLogData - Deserialized GraphData fileStream: 20,224.00 bytes Graph Count: 1
2022-11-13 20:20:29.653 Info App: AppendExtraLogData - File Deleted
2022-11-13 20:20:29.710 Info App: ProcessRun 'StreamTranscode f229e3' Process exited with code 0 - Succeeded

2022-11-14 19:26:09.780 Info App: ProcessRun 'StreamTranscode 18e5f2': Stopping ffmpeg process with q command for C:\Users\Server\AppData\Roaming\Emby-Server\transcoding-temp\405193\405193_0.ts
2022-11-14 19:26:10.293 Info App: AppendExtraLogData - Read graph file: C:\Users\Server\AppData\Roaming\Emby-Server\logs\ffmpeg-transcode-18e5f25f-caee-417d-b859-b9e8b8b619a1_1graph.txt
2022-11-14 19:26:10.294 Info App: AppendExtraLogData - Deserialized GraphData fileStream: 20,224.00 bytes Graph Count: 1
2022-11-14 19:26:10.294 Info App: AppendExtraLogData - File Deleted
2022-11-14 19:26:10.296 Info App: ProcessRun 'StreamTranscode 18e5f2' Process exited with code 0 - Succeeded

But the source stream remains.  But devs will have to comment.

[econ 74]

Attaching my log as promised as well.

embyserver.txt

[econ 74]

attaching log of another instance of the transcoding stream filling up the entire server hard drive.

embyserver-63804382923 (1).txt

[Luke 37091]

4 minutes ago, econ said:

attaching log of another instance of the transcoding stream filling up the entire server hard drive.

embyserver-63804382923 (1).txt 33.24 MB · 0 downloads

Can you please describe what exactly you did?

[econ 74]

In this case, user is just playing live tv within chrome. They stop playback normally and the stream continues on the server filling up the hard drive. It’s happening almost daily for the past week. 

[Happy2Play 8293]

@Luke 

Am I understanding econ last log correctly, the SharedSource (stream) starts

2022-11-18 04:59:51.866 Info SharedHttpPipelineSource: Beginning SharedHttpPipelineSource stream to C:\Users\user\AppData\Roaming\Emby-Server\transcoding-temp\db7b4961f21a4dffa4dbbe53a064480a.ts

Emby Transcodes that stream for the client.

2022-11-18 05:00:04.607 Info App: ProcessRun 'StreamTranscode 0699a6' Execute: C:\Users\user\AppData\Roaming\Emby-Server\system\ffmpeg.exe -loglevel +timing -y -print_graphs_file "C:\Users\user\AppData\Roaming\Emby-Server\logs\ffmpeg-transcode-0699a69a-4e06-4801-8df5-24866f7e09a5_1graph.txt" -copyts -start_at_zero -analyzeduration 3000000 -f mpegts -c:v:0 mpeg2video -i "http://127.0.0.1:8090/LiveTv/LiveStreamFiles/db7b4961f21a4dffa4dbbe53a064480a/stream.ts" -filter_complex "[0:0]yadif@f1=mode=send_frame:parity=auto:deint=all[f1_out0]" -map [f1_out0] -map 0:3 -sn -c:v:0 libx264 -g:v:0 90 -maxrate:v:0 1242999 -bufsize:v:0 2485998 -sc_threshold:v:0 0 -keyint_min:v:0 90 -r:v:0 29.970029830932617 -pix_fmt:v:0 yuv420p -preset:v:0 veryfast -profile:v:0 high -level:v:0 3.0 -x264opts:v:0 "subme=0:me_range=4:rc_lookahead=10:partitions=none" -crf:v:0 23 -c:a:0 libmp3lame -ab:a:0 192000 -ac:a:0 2 -metadata:s:a:0 language=eng -disposition:a:0 default -fflags +discardcorruptts+fillwallclockdts -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format mpegts -segment_list "C:\Users\user\AppData\Roaming\Emby-Server\transcoding-temp\E4CDA1\E4CDA1.m3u8" -segment_list_type m3u8 -segment_time 00:00:03.000 -segment_list_entry_prefix hls/E4CDA1/ -segment_start_number 0 -individual_header_trailer 0 -write_header_trailer 0 -segment_write_temp 1 "C:\Users\user\AppData\Roaming\Emby-Server\transcoding-temp\E4CDA1\E4CDA1_%d.ts"
2022-11-18 05:00:04.611 Debug App: ProcessRun 'StreamTranscode 0699a6' Started.

Client stops and cleans up transcode

2022-11-18 05:27:02.403 Info App: ProcessRun 'StreamTranscode 0699a6': Stopping ffmpeg process with q command for C:\Users\user\AppData\Roaming\Emby-Server\transcoding-temp\E4CDA1\E4CDA1_0.ts
2022-11-18 05:27:04.035 Debug EncodingManager: Deleting temp folder C:\Users\user\AppData\Roaming\Emby-Server\transcoding-temp\E4CDA1

But have source stream for an additional 10 hours?

2022-11-18 15:42:00.053 Info SharedHttpPipelineSource: Deleting temp files C:\Users\user\AppData\Roaming\Emby-Server\transcoding-temp\db7b4961f21a4dffa4dbbe53a064480a.ts

 

[econ 74]

That’s correct I believe. 

[Luke 37091]

OK I was able to reproduce. This is due to double clicking the play button.

We'll be doing a 4.7.10 maintenance release and we'll include the fix for this as part of that .Thanks.

[justinrh 174]

To learn the unlearned, even if the user was watching TV for 10 hours, the disk would not fill up, right?  The way I think it works is the temp files are deleted as they are 'consumed' by the client (at least within some buffer window).  So in this person's case, the stream is never consumed so the transcode file just keeps increasing.  Is that somewhat correct?

[Luke 37091]

On 11/19/2022 at 8:40 AM, justinrh said:

To learn the unlearned, even if the user was watching TV for 10 hours, the disk would not fill up, right?  The way I think it works is the temp files are deleted as they are 'consumed' by the client (at least within some buffer window).  So in this person's case, the stream is never consumed so the transcode file just keeps increasing.  Is that somewhat correct?

Currently there is no limit to the live TV buffer but we plan to change that in future updates.

[econ 74]

On 11/18/2022 at 6:54 PM, Luke said:

OK I was able to reproduce. This is due to double clicking the play button.

We'll be doing a 4.7.10 maintenance release and we'll include the fix for this as part of that .Thanks.

Even after the upgrade to 4.7.10, I am still seeing the issue with a live tv stream continuing to increase in size after the user closes out of viewing.  The file isn't deleted from the transcoding folder until a server reboot.

embyserver-63806081936.txt

[Luke 37091]

4 minutes ago, econ said:

Even after the upgrade to 4.7.10, I am still seeing the issue with a live tv stream continuing to increase in size after the user closes out of viewing.  The file isn't deleted from the transcoding folder until a server reboot.

embyserver-63806081936.txt 3.05 MB · 0 downloads

Hi, there is no playback activity in this log file. Please provide the correct log file for the time the problem was experienced along with some discussion of the user playback activity. Thanks.

[Happy2Play 8293]

Is a question of when this stream started as the log is 5 hours.  So sometime before the midnight rollover log.

2022-12-08 05:24:25.223 Error GraphRunner: GraphRunnerTimestampFixup
	*** Error Report ***

There is not enough space on the disk. : 'C:\Users\user\AppData\Roaming\Emby-Server\transcoding-temp\13843fa358424cf6bfe55aa10907c1cc.ts')

2022-12-08 05:24:25.230 Debug SharedHttpPipelineSource: Streaming loop finished
2022-12-08 05:24:25.230 Info SharedHttpPipelineSource: SharedHttpPipelineSource is done streaming.
2022-12-08 05:24:25.230 Debug SharedHttpPipelineSource: Exit streaming task

 

[EODCrafter 180]

On 11/20/2022 at 11:32 AM, Luke said:

Currently there is no limit to the live TV buffer but we plan to change that in future updates.

Please!

[tsavisky 1]

Hey guys, had this happen again running 4.7.10.0.  Same user as before but this time from an iphone apparently. See attached logs. Transcoding-temp file got up to 143GB before I restarted the server. 

ffmpeg-transcode-2affa7c2-15c2-4fc0-9efb-f3d43515d7b8_1.txt embyserver.txt

[Luke 37091]

On 12/13/2022 at 11:20 PM, tsavisky said:

Hey guys, had this happen again running 4.7.10.0.  Same user as before but this time from an iphone apparently. See attached logs. Transcoding-temp file got up to 143GB before I restarted the server. 

ffmpeg-transcode-2affa7c2-15c2-4fc0-9efb-f3d43515d7b8_1.txt 46.85 kB · 0 downloads embyserver.txt 4.38 MB · 0 downloads

Hi, have you updated to Emby Server 4.7.11 and Emby for iOS 2.2.6? Are you still running into this?

[Przemek 54]

Hello, I also have noticed that issue recently. Now I reload guides and reboot Emby and it looks OK.

[justinrh 174]

I saw this myself recently.