Emby ignoring internet streaming limit?

[Luke 42077]

19 hours ago, mbc0 said:

Just found this in the log

2024-06-09 10:12:30.076 Info App: User policy for bryde4. EnablePlaybackRemuxing: True EnableVideoPlaybackTranscoding: True EnableAudioPlaybackTranscoding: True
2024-06-09 10:12:30.076 Info App: RemoteClientBitrateLimit: 3000000, RemoteIp: host5, IsInLocalNetwork: False
2024-06-09 10:12:30.076 Info App: Bitrate exceeds DirectPlay limit: media bitrate: 6381883, max bitrate: 3000000
2024-06-09 10:12:30.076 Info App: Bitrate exceeds DirectStream limit: media bitrate: 6381883, max bitrate: 3000000
2024-06-09 10:12:30.077 Info App: RemoteClientBitrateLimit: 3000000, RemoteIp: host5, IsInLocalNetwork: False
2024-06-09 10:12:30.077 Info App: Bitrate exceeds DirectPlay limit: media bitrate: 6381883, max bitrate: 3000000
2024-06-09 10:12:30.077 Info App: Bitrate exceeds DirectStream limit: media bitrate: 6381883, max bitrate: 3000000
2024-06-09 10:12:30.077 Info App: RemoteClientBitrateLimit: 3000000, RemoteIp: host5, IsInLocalNetwork: False
2024-06-09 10:12:30.077 Info Server: http/1.1 Response 200 to host5. Time: 20ms. POST http://host4:8096/emby/Items/1074050/PlaybackInfo?UserId=25f305c44113447388479c94337ce180&StartTimeTicks=0&IsPlayback=false&AutoOpenLiveStream=false&MaxStreamingBitrate=734003200&X-Emby-Client=Emby for Android&X-Emby-Device-Name=Bryan's Fire TV&X-Emby-Device-Id=8f004588af3db658&X-Emby-Client-Version=3.3.82&X-Emby-Token=x_secret1_x&X-Emby-Language=en-gb&reqformat=json

Please attach the complete log file. Thanks.

[mbc0 68]

1 hour ago, Luke said:

Please attach the complete log file. Thanks.

Thanks Luke,

embylog.zip

[Luke 42077]

On 6/9/2024 at 6:12 AM, mbc0 said:

Hi, 

Not had a chance to look at this but still having issues unfortunately, 

This is the current situation as my parents are watching now despite manually setting the user to 3mb/s

 

I have manually set their user to 3mb/s (pic below)

 

Emby Global settings are also set to 3 (pic below) all other users obey this global setting so any idea how I can fix this?

 

What time did this occur? The log has a lot of activity so it's not easy to find. Thanks.

[mbc0 68]

52 minutes ago, Luke said:

What time did this occur? The log has a lot of activity so it's not easy to find. Thanks.

[Happy2Play 9780]

4 minutes ago, mbc0 said:

But the log end at 2024-06-09 11:34:11.604

[mbc0 68]

Sorry, I sent the wrong time, they also tried several times from 10:09 2024-06-09, there are quite a few attempt due to the fact their internet speed (and mine) is not great and Emby trying to stream 6mbps

[Happy2Play 9780]

Can you post the ffmpeg log as it appears it is sending a 3M stream even if the UI is showing different.

Quote

2024-06-09 10:09:22.982 Info Server: http/1.1 GET http://host4:8096/emby/videos/1074050/master.m3u8?DeviceId=8f004588af3db658&MediaSourceId=56556bd352959e262ac74911cd1d637c&PlaySessionId=f947205217b94fed9ff8f401a354e9c1&api_key=x_secret1_x&VideoCodec=h264,mpeg2video,hevc&AudioCodec=ac3,aac,mp3,mp2&VideoBitrate=2808000&AudioBitrate=192000&AudioStreamIndex=1&TranscodingMaxAudioChannels=6&SegmentContainer=m4s,ts&SegmentLength=3&MinSegments=1&BreakOnNonKeyFrames=True&SubtitleStreamIndexes=-1&ManifestSubtitles=vtt&hevc-profile=Main,Main10,Rext&h264-level=51&TranscodeReasons=ContainerBitrateExceedsLimit,DirectPlayError&allowVideoStreamCopy=false. Source Ip: host9, Connection=keep-alive, Host=host10, User-Agent=Emby/3.3.82 (Linux;Android 7.1.2) AndroidXMedia3/1.1.1, Accept-Encoding=gzip

Quote

2024-06-09 10:09:23.456 Info App: ProcessRun 'StreamTranscode e7c3d5' Execute: /app/emby/bin/ffmpeg -loglevel +timing -y -print_graphs_file "/config/logs/ffmpeg-transcode-e7c3d589-54bf-4a13-9353-a575359b2300_1graph.txt" -copyts -start_at_zero -init_hw_device "cuda=cuda:0" -f matroska,webm -c:v:0 h264 -threads:v:0 1 -hwaccel:v:0 cuda -hwaccel_output_format:v:0 cuda -noautorotate -i "/unraidshares/sport/sporttvdb/Formula 1 (1950)/Season 2024/Formula 1 (1950) - S2024E47 - Canada Qualifying - WEBDL-1080p - h264 AAC.mkv" -filter_complex "[0:0]scale_cuda@f1=w=1280:h=720,setsar@f2=sar=sar[f2_out0]" -map [f2_out0] -map 0:1 -sn -c:v:0 h264_nvenc -b:v:0 2808000 -g:v:0 150 -maxrate:v:0 2808000 -bufsize:v:0 5616000 -keyint_min:v:0 150 -r:v:0 50 -profile:v:0 main -c:a:0 copy -metadata:s:a:0 language=eng -disposition:a:0 default -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format mpegts -segment_list "/config/transcoding-temp/0CF158/0CF158.m3u8" -segment_list_type m3u8 -segment_time 00:00:03.000 -segment_start_number 0 -individual_header_trailer 0 -write_header_trailer 0 -segment_write_temp 1 "/config/transcoding-temp/0CF158/0CF158_%d.ts"

 

[mbc0 68]

Here is the log, 

Even though I had anonymise log contents enabled it still showed my server address twice!  I have removed that now, is that expected behaviour?

 

 

ffmpeglog.rar

 

[Luke 42077]

the ffmpeg log example looks like the limits are being respected. earlier you showed a screenshot of something direct playing that might be at a higher bitrate.

this is what i'm having trouble finding in the log due to the large amount of activity it contains. Maybe you can get the problem to happen again and then carefully take note of the app, device, content being played, what time it was being played, and the server log? Thanks.

[Happy2Play 9780]

8 minutes ago, mbc0 said:

Here is the log, 

Even though I had anonymise log contents enabled it still showed my server address twice!  I have removed that now, is that expected behaviour?

 

 

ffmpeglog.rar 5.47 kB · 0 downloads

 

Yes this is a issue @Lukestill needs to address in ffmpeg logs.

Devs will have to look at this as the transcode actually fails

2024-06-09 10:08:35.874 Info App: ProcessRun 'StreamTranscode 59a92c' Execute: /app/emby/bin/ffmpeg -loglevel +timing -y -print_graphs_file "/config/logs/ffmpeg-transcode-59a92cf2-b4cd-4288-aae1-048b1a969e19_1graph.txt" -copyts -start_at_zero -init_hw_device "cuda=cuda:0" -f matroska,webm -c:v:0 h264 -threads:v:0 1 -hwaccel:v:0 cuda -hwaccel_output_format:v:0 cuda -noautorotate -i "/unraidshares/sport/sporttvdb/Formula 1 (1950)/Season 2024/Formula 1 (1950) - S2024E47 - Canada Qualifying - WEBDL-1080p - h264 AAC.mkv" -filter_complex "[0:0]scale_cuda@f1=w=1280:h=720,setsar@f2=sar=sar[f2_out0]" -map [f2_out0] -map 0:1 -sn -c:v:0 h264_nvenc -b:v:0 2808000 -g:v:0 150 -maxrate:v:0 2808000 -bufsize:v:0 5616000 -keyint_min:v:0 150 -r:v:0 50 -profile:v:0 main -c:a:0 copy -metadata:s:a:0 language=eng -disposition:a:0 default -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format mpegts -segment_list "/config/transcoding-temp/DF3EA8/DF3EA8.m3u8" -segment_list_type m3u8 -segment_time 00:00:03.000 -segment_start_number 0 -individual_header_trailer 0 -write_header_trailer 0 -segment_write_temp 1 "/config/transcoding-temp/DF3EA8/DF3EA8_%d.ts"
2024-06-09 10:08:45.341 Info Server: http/1.1 GET http://host4:8096/emby/videos/1074050/hls1/main/0.ts?PlaySessionId=af6a90248e9e4dba8e321514a697f62a. Source Ip: host9, Connection=keep-alive, Host=host10, User-Agent=Emby/3.3.82 (Linux;Android 7.1.2) AndroidXMedia3/1.1.1, Accept-Encoding=identity
2024-06-09 10:08:45.448 Info App: ProcessRun 'StreamTranscode 59a92c': Stopping ffmpeg process with q command for /config/transcoding-temp/DF3EA8/DF3EA8_0.ts
2024-06-09 10:08:45.547 Info App: AppendExtraLogData - Read graph file: /config/logs/ffmpeg-transcode-59a92cf2-b4cd-4288-aae1-048b1a969e19_1graph.txt
2024-06-09 10:08:45.548 Warn App: AppendExtraLogData: Unable read graph output file: /config/logs/ffmpeg-transcode-59a92cf2-b4cd-4288-aae1-048b1a969e19_1graph.txt
2024-06-09 10:08:45.697 Info App: ProcessRun 'StreamTranscode 59a92c' Process exited with code 137 - Failed

So I am not sure how the file is bypassing failed transcode and still playing.

This is only a issue in 3.3.82 per all your posts correct?  I only have 3.3.95

[mbc0 68]

Ah, ok, progress!

This is the only user with Firestick 3.3.82 and the only user with the streaming limit issue, all others obey the 3mb stream limit.

Basically, as the transcode fails it is defaulting back to the direct stream?

Many thanks

[Happy2Play 9780]

4 minutes ago, mbc0 said:

Basically, as the transcode fails it is defaulting back to the direct stream?

It is not supposed to but can't see in the log it actually doing that.

[mbc0 68]

ok, if you look at this log you will see playback started at 2024-06-09 22:37:05.092

embyserver-63853574400.zip

Here is the ffmpeg log

ffmpeg-transcode-a0453ba3-c2f8-4e1d-9467-cbc066832795_1.txt

 

Thank you

[Luke 42077]

12 minutes ago, mbc0 said:

ok, if you look at this log you will see playback started at 2024-06-09 22:37:05.092

embyserver-63853574400.zip 919.73 kB · 1 download

Here is the ffmpeg log

ffmpeg-transcode-a0453ba3-c2f8-4e1d-9467-cbc066832795_1.txt 484.97 kB · 2 downloads

 

Thank you

It looks like it's transcoding the whole way through.

[mbc0 68]

So the interface showing direct play 6mb/s is wrong?

 

[Happy2Play 9780]

3 minutes ago, mbc0 said:

So the interface showing direct play 6mb/s is wrong?

 

The ffmpeg log is for a different user and client.  As server log session and ffmpeg log session do not match.

App: AndroidTv 2.0.98a
fs-keelan
User-Agent: Emby/2.0.98a (Linux;Android 9) ExoPlayerLib/2.18.7

So you are saying this is showing direct play 6mb on dashboard even though it is transcoding to 3mb?

Edited June 11, 2024 by Happy2Play

[mbc0 68]

I thought the same about the ffmpeg log but I checked the ffmpeg logs before and after that one and the one I uploaded was the only one that had the same timestamp 2024-06-09 22:37:05.092 so maybe an ffmpeg log was not created for that stream? even though it should have been transcoding?

Whenever the user Bryde4 plays anything it shows on the dashboard as direct stream as if it is a local user above the 3mb limit

 

[Happy2Play 9780]

2 minutes ago, mbc0 said:

Whenever the user Bryde4 plays anything it shows on the dashboard as direct stream as if it is a local user above the 3mb limit

That is the conflicting info as log show transcoding attempt.  But here is bryde4 session

2024-06-09 22:36:55.528 Info Server: http/1.1 GET http://host8:8096/emby/videos/1074500/hls1/main/0.ts?PlaySessionId=796e89706b3a464fa53092372959b114. Source Ip: host9, Connection=keep-alive, Host=host10, User-Agent=Emby/3.3.82 (Linux;Android 7.1.2) AndroidXMedia3/1.1.1, Accept-Encoding=identity
2024-06-09 22:36:55.530 Info App: Starting transcoding because currentTranscodingIndex=null
2024-06-09 22:36:55.556 Info App: >> ThrottleBySegmentRequest: Initialize - TargetBufferSize: 120s
2024-06-09 22:36:55.557 Info App: ProcessRun 'StreamTranscode a552be' Execute: /app/emby/bin/ffmpeg -loglevel +timing -y -print_graphs_file "/config/logs/ffmpeg-transcode-a552bed6-092b-4305-96f7-cbcd0db2a1a7_1graph.txt" -copyts -start_at_zero -init_hw_device "cuda=cuda:0" -f matroska,webm -c:v:0 h264 -threads:v:0 1 -hwaccel:v:0 cuda -hwaccel_output_format:v:0 cuda -noautorotate -i "/unraidshares/sport/sporttvdb/Formula 1 (1950)/Season 2024/Formula 1 (1950) - S2024E48 - Canada Race - WEBDL-1080p - h264 AAC.mkv" -filter_complex "[0:0]scale_cuda@f1=w=1280:h=720,setsar@f2=sar=sar[f2_out0]" -map [f2_out0] -map 0:1 -sn -c:v:0 h264_nvenc -b:v:0 2808000 -g:v:0 150 -maxrate:v:0 2808000 -bufsize:v:0 5616000 -keyint_min:v:0 150 -r:v:0 50 -profile:v:0 main -c:a:0 copy -metadata:s:a:0 language=eng -disposition:a:0 default -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format mpegts -segment_list "/config/transcoding-temp/9AEE73/9AEE73.m3u8" -segment_list_type m3u8 -segment_time 00:00:03.000 -segment_start_number 0 -individual_header_trailer 0 -write_header_trailer 0 -segment_write_temp 1 "/config/transcoding-temp/9AEE73/9AEE73_%d.ts"

 

[mbc0 68]

2 minutes ago, Happy2Play said:

That is the conflicting info as log show transcoding attempt.  But here is bryde4 session

2024-06-09 22:36:55.528 Info Server: http/1.1 GET http://host8:8096/emby/videos/1074500/hls1/main/0.ts?PlaySessionId=796e89706b3a464fa53092372959b114. Source Ip: host9, Connection=keep-alive, Host=host10, User-Agent=Emby/3.3.82 (Linux;Android 7.1.2) AndroidXMedia3/1.1.1, Accept-Encoding=identity
2024-06-09 22:36:55.530 Info App: Starting transcoding because currentTranscodingIndex=null
2024-06-09 22:36:55.556 Info App: >> ThrottleBySegmentRequest: Initialize - TargetBufferSize: 120s
2024-06-09 22:36:55.557 Info App: ProcessRun 'StreamTranscode a552be' Execute: /app/emby/bin/ffmpeg -loglevel +timing -y -print_graphs_file "/config/logs/ffmpeg-transcode-a552bed6-092b-4305-96f7-cbcd0db2a1a7_1graph.txt" -copyts -start_at_zero -init_hw_device "cuda=cuda:0" -f matroska,webm -c:v:0 h264 -threads:v:0 1 -hwaccel:v:0 cuda -hwaccel_output_format:v:0 cuda -noautorotate -i "/unraidshares/sport/sporttvdb/Formula 1 (1950)/Season 2024/Formula 1 (1950) - S2024E48 - Canada Race - WEBDL-1080p - h264 AAC.mkv" -filter_complex "[0:0]scale_cuda@f1=w=1280:h=720,setsar@f2=sar=sar[f2_out0]" -map [f2_out0] -map 0:1 -sn -c:v:0 h264_nvenc -b:v:0 2808000 -g:v:0 150 -maxrate:v:0 2808000 -bufsize:v:0 5616000 -keyint_min:v:0 150 -r:v:0 50 -profile:v:0 main -c:a:0 copy -metadata:s:a:0 language=eng -disposition:a:0 default -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format mpegts -segment_list "/config/transcoding-temp/9AEE73/9AEE73.m3u8" -segment_list_type m3u8 -segment_time 00:00:03.000 -segment_start_number 0 -individual_header_trailer 0 -write_header_trailer 0 -segment_write_temp 1 "/config/transcoding-temp/9AEE73/9AEE73_%d.ts"

 

OK! Got it!

ffmpeg-transcode-a552bed6-092b-4305-96f7-cbcd0db2a1a7_1.rar

[Happy2Play 9780]

1 minute ago, mbc0 said:

OK! Got it!

ffmpeg-transcode-a552bed6-092b-4305-96f7-cbcd0db2a1a7_1.rar 357.78 kB · 0 downloads

Yes per the log is shows transcoded and is sending 3mb stream

22:36:55.771   Stream #0:0 (h264) -> scale_cuda:default
22:36:55.771   setsar:default -> Stream #0:0 (h264_nvenc)
22:36:55.771   Stream #0:1 -> #0:1 (copy)
22:36:55.771 Press [q] to stop, [?] for help
>> ThrottleBySegmentRequest: Latest request position unknown
>> ThrottleBySegmentRequest: Latest request position unknown
>> ThrottleBySegmentRequest: Latest request position unknown
>> ThrottleBySegmentRequest: Latest request position unknown
22:37:03.813 Output #0, segment, to '/config/transcoding-temp/9AEE73/9AEE73_%d.ts':
22:37:03.813   Metadata:
22:37:03.813     encoder         : Lavf59.27.100
22:37:03.813   Stream #0:0: Video: h264 (Main), cuda(progressive), 1280x720 [SAR 1:1 DAR 16:9], q=2-31, 2808 kb/s, 50 fps, 90k tbn
22:37:03.813     Metadata:
22:37:03.813       encoder         : Lavc59.37.100 h264_nvenc
22:37:03.813     Side data:
22:37:03.813       cpb: bitrate max/min/avg: 2808000/0/2808000 buffer size: 5616000 vbv_delay: N/A

But have no idea how a client can provide the wrong info here.

[mbc0 68]

ok, very strange! but good to know it is actually transcoding.  Anything else I can do to help diagnose?  it is only this one user that shows incorrectly

[Happy2Play 9780]

@Luke@ebrwould client log help here?  But I guess this is technically a server issue reporting this playback.

Don't really know versioning on this client as OP issue is with 3.3.82.

Edited June 12, 2024 by Happy2Play

[Happy2Play 9780]

5 minutes ago, mbc0 said:

ok, very strange! but good to know it is actually transcoding.  Anything else I can do to help diagnose?  it is only this one user that shows incorrectly

Does Stats for Nerd show direct play or transcoding to the user?

[Luke 42077]

12 minutes ago, mbc0 said:

ok, very strange! but good to know it is actually transcoding.  Anything else I can do to help diagnose?  it is only this one user that shows incorrectly

Do they have an app update available? can you get it to happen again?

[mbc0 68]

It happens every time but they are in their 80's & 90's so incredibly difficult to remind them how to play something let alone stats for nerds! next time I visit I will investigate further.

Thanks for all your help!