Jump to content

Stuttering Playback

KarmaPolice

By KarmaPolice
in Linux

 Share

Recommended Posts

KarmaPolice

KarmaPolice   16

Posted
Posted

I'm getting significant stuttering on Emby in several apps (web, kodi, chromecast)... 

 

Attached is the server log and the ffmpeg log.

 

I'm noticing the following behavior...

 

Transcoding functions really quickly... however the actual playback stutters quite a bit... if i pause for a while and come back, it will seem to buffer and play ok for a little while, but then start to stutter dramatically again when it "catches up"... 

 

I'm noticing the slowdowns seem to be related to the time between "#.ts" get requests... You can see from the snippet below this is taking ~10 seconds per .ts file request... I'm not clear what these .ts files are, so not sure how to analyze...

 

You can also see in the snippet that ffmpeg exits gracefully, I assume this means the transcode is complete on disk and just waiting to be read... 

 

The experience is roughly as follows:

  • See hls1/main/2.ts GET request
  • Video starts playing for 3-4 seconds
  • Video pauses
  • See hls1/main/3.ts GET request
  • Video resumes playing for 3-4 seconds
  • Video pauses
  • repeat...
2018-05-17 22:06:21.774 Info HttpServer: HTTP GET http://my.server.com:8096/videos/ad92bf839f10ccc99f50e0a9b636c013/hls1/main/2.ts?DeviceId=14c883917567bd6fdcd55ed0bb569e37d58e0c6e&MediaSourceId=ad92bf839f10ccc99f50e0a9b636c013&VideoCodec=h264&AudioCodec=mp3,aac&AudioStreamIndex=1&VideoBitrate=96167724&AudioBitrate=384000&PlaySessionId=e55963bf300c4b2d8b284e9b8b20645c&TranscodingMaxAudioChannels=2&RequireAvc=true&Tag=a1ad882aecc255058ba79e57717d1d6e&SegmentContainer=ts&MinSegments=1&BreakOnNonKeyFrames=True&h264-profile=high,main,baseline,constrainedbaseline,high10&h264-level=51&h264-deinterlace=true. Host=my.server.com, X-Real-IP=162.158.142.41, X-Forwarded-For=clt.ip.add.ress, 162.158.142.41, Connection=Keep-Alive, Accept-Encoding=gzip, CF-IPCountry=US, CF-RAY=41cbcb45ea0c39b8-PHX, X-Forwarded-Proto=https, CF-Visitor={"scheme":"https"}, user-agent=Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/66.0.3359.181 Safari/537.36, accept=*/*, dnt=1, referer=https://my.server.com/web/videoosd.html, accept-language=en-US,en;q=0.9, cookie=__cfduid=d6b36a10794b4b73f101f89f476b988ed1522636125, CF-Connecting-IP=clt.ip.add.ress
2018-05-17 22:06:21.803 Info HttpServer: HTTP Response 200 to clt.ip.add.ress, 162.158.142.41. Time: 29ms. http://my.server.com:8096/videos/ad92bf839f10ccc99f50e0a9b636c013/hls1/main/2.ts?DeviceId=14c883917567bd6fdcd55ed0bb569e37d58e0c6e&MediaSourceId=ad92bf839f10ccc99f50e0a9b636c013&VideoCodec=h264&AudioCodec=mp3,aac&AudioStreamIndex=1&VideoBitrate=96167724&AudioBitrate=384000&PlaySessionId=e55963bf300c4b2d8b284e9b8b20645c&TranscodingMaxAudioChannels=2&RequireAvc=true&Tag=a1ad882aecc255058ba79e57717d1d6e&SegmentContainer=ts&MinSegments=1&BreakOnNonKeyFrames=True&h264-profile=high,main,baseline,constrainedbaseline,high10&h264-level=51&h264-deinterlace=true 
2018-05-17 22:06:22.086 Info HttpServer: WS ws://my.server.com:8096/embywebsocket?api_key=33ad202cb5154b9aace4d99a4ac2132c&deviceId=69EE17F832274DCB412B8FDC36F9EBEABBD6AAF2. UserAgent: 
2018-05-17 22:06:22.086 Debug HttpServer: Web socket connection allowed
2018-05-17 22:06:22.087 Debug SessionManager: Creating new WebSocketController
2018-05-17 22:06:22.087 Info App: App Activity: app: Kodi, version: 3.0.25a, deviceId: 69EE17F832274DCB412B8FDC36F9EBEABBD6AAF2, deviceName: Kodi (kodi)
2018-05-17 22:06:22.635 Info HttpServer: HTTP GET http://my.server.com:8096/Sessions?deviceId=14c883917567bd6fdcd55ed0bb569e37d58e0c6e. UserAgent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/66.0.3359.181 Safari/537.36
2018-05-17 22:06:22.677 Info HttpServer: HTTP Response 200 to clt.ip.add.ress, 162.158.142.41. Time: 42ms. http://my.server.com:8096/Sessions?deviceId=14c883917567bd6fdcd55ed0bb569e37d58e0c6e 
2018-05-17 22:06:22.780 Info HttpServer: HTTP GET http://my.server.com:8096/Sessions?deviceId=14c883917567bd6fdcd55ed0bb569e37d58e0c6e. UserAgent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/66.0.3359.181 Safari/537.36
2018-05-17 22:06:22.781 Info HttpServer: HTTP Response 200 to clt.ip.add.ress, 162.158.142.41. Time: 1ms. http://my.server.com:8096/Sessions?deviceId=14c883917567bd6fdcd55ed0bb569e37d58e0c6e 
2018-05-17 22:06:34.463 Debug App: Disposing stream resources
2018-05-17 22:06:34.468 Info App: FFMpeg exited with code 0
2018-05-17 22:06:40.629 Info HttpServer: HTTP GET http://my.server.com:8096/videos/ad92bf839f10ccc99f50e0a9b636c013/hls1/main/3.ts?DeviceId=14c883917567bd6fdcd55ed0bb569e37d58e0c6e&MediaSourceId=ad92bf839f10ccc99f50e0a9b636c013&VideoCodec=h264&AudioCodec=mp3,aac&AudioStreamIndex=1&VideoBitrate=96167724&AudioBitrate=384000&PlaySessionId=e55963bf300c4b2d8b284e9b8b20645c&TranscodingMaxAudioChannels=2&RequireAvc=true&Tag=a1ad882aecc255058ba79e57717d1d6e&SegmentContainer=ts&MinSegments=1&BreakOnNonKeyFrames=True&h264-profile=high,main,baseline,constrainedbaseline,high10&h264-level=51&h264-deinterlace=true. Host=my.server.com, X-Real-IP=162.158.142.41, X-Forwarded-For=clt.ip.add.ress, 162.158.142.41, Connection=Keep-Alive, Accept-Encoding=gzip, CF-IPCountry=US, CF-RAY=41cbcbbbcdc039b8-PHX, X-Forwarded-Proto=https, CF-Visitor={"scheme":"https"}, user-agent=Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/66.0.3359.181 Safari/537.36, accept=*/*, dnt=1, referer=https://my.server.com/web/videoosd.html, accept-language=en-US,en;q=0.9, cookie=__cfduid=d6b36a10794b4b73f101f89f476b988ed1522636125, CF-Connecting-IP=clt.ip.add.ress
2018-05-17 22:06:40.636 Info HttpServer: HTTP Response 200 to clt.ip.add.ress, 162.158.142.41. Time: 7ms. http://my.server.com:8096/videos/ad92bf839f10ccc99f50e0a9b636c013/hls1/main/3.ts?DeviceId=14c883917567bd6fdcd55ed0bb569e37d58e0c6e&MediaSourceId=ad92bf839f10ccc99f50e0a9b636c013&VideoCodec=h264&AudioCodec=mp3,aac&AudioStreamIndex=1&VideoBitrate=96167724&AudioBitrate=384000&PlaySessionId=e55963bf300c4b2d8b284e9b8b20645c&TranscodingMaxAudioChannels=2&RequireAvc=true&Tag=a1ad882aecc255058ba79e57717d1d6e&SegmentContainer=ts&MinSegments=1&BreakOnNonKeyFrames=True&h264-profile=high,main,baseline,constrainedbaseline,high10&h264-level=51&h264-deinterlace=true 
2018-05-17 22:06:40.737 Info HttpServer: HTTP POST http://my.server.com:8096/Sessions/Playing/Progress. UserAgent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/66.0.3359.181 Safari/537.36
2018-05-17 22:06:40.739 Info HttpServer: HTTP Response 204 to clt.ip.add.ress, 162.158.142.41. Time: 2ms. http://my.server.com:8096/Sessions/Playing/Progress 
2018-05-17 22:06:40.741 Info HttpServer: HTTP GET http://my.server.com:8096/Sessions?deviceId=14c883917567bd6fdcd55ed0bb569e37d58e0c6e. UserAgent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/66.0.3359.181 Safari/537.36
2018-05-17 22:06:40.743 Info HttpServer: HTTP Response 200 to clt.ip.add.ress, 162.158.142.41. Time: 1ms. http://my.server.com:8096/Sessions?deviceId=14c883917567bd6fdcd55ed0bb569e37d58e0c6e 
2018-05-17 22:06:51.256 Info HttpServer: HTTP POST http://my.server.com:8096/Sessions/Playing/Progress. UserAgent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/66.0.3359.181 Safari/537.36
2018-05-17 22:06:51.258 Info HttpServer: HTTP Response 204 to clt.ip.add.ress, 162.158.142.41. Time: 2ms. http://my.server.com:8096/Sessions/Playing/Progress 
2018-05-17 22:06:51.949 Error HttpServer: Error in SharpWebSocket: An exception has occurred while receiving a message.. Exception.Message: The header part of a frame cannot be read from the data source.
2018-05-17 22:06:51.963 Debug SessionManager: Disposing session controller WebSocketController
2018-05-17 22:06:56.879 Info HttpServer: HTTP GET http://my.server.com:8096/Sessions?deviceId=14c883917567bd6fdcd55ed0bb569e37d58e0c6e. UserAgent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/66.0.3359.181 Safari/537.36
2018-05-17 22:06:56.882 Info HttpServer: HTTP Response 200 to clt.ip.add.ress, 162.158.142.41. Time: 3ms. http://my.server.com:8096/Sessions?deviceId=14c883917567bd6fdcd55ed0bb569e37d58e0c6e 
2018-05-17 22:06:56.885 Info HttpServer: HTTP POST http://my.server.com:8096/Sessions/Playing/Progress. UserAgent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/66.0.3359.181 Safari/537.36
2018-05-17 22:06:56.887 Info HttpServer: HTTP POST http://my.server.com:8096/Sessions/Playing/Progress. UserAgent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/66.0.3359.181 Safari/537.36
2018-05-17 22:06:56.889 Info HttpServer: HTTP Response 204 to clt.ip.add.ress, 162.158.142.41. Time: 3ms. http://my.server.com:8096/Sessions/Playing/Progress 
2018-05-17 22:06:56.889 Info HttpServer: HTTP Response 204 to clt.ip.add.ress, 162.158.142.41. Time: 3ms. http://my.server.com:8096/Sessions/Playing/Progress 
2018-05-17 22:06:57.015 Info HttpServer: HTTP GET http://my.server.com:8096/videos/ad92bf839f10ccc99f50e0a9b636c013/hls1/main/4.ts?DeviceId=14c883917567bd6fdcd55ed0bb569e37d58e0c6e&MediaSourceId=ad92bf839f10ccc99f50e0a9b636c013&VideoCodec=h264&AudioCodec=mp3,aac&AudioStreamIndex=1&VideoBitrate=96167724&AudioBitrate=384000&PlaySessionId=e55963bf300c4b2d8b284e9b8b20645c&TranscodingMaxAudioChannels=2&RequireAvc=true&Tag=a1ad882aecc255058ba79e57717d1d6e&SegmentContainer=ts&MinSegments=1&BreakOnNonKeyFrames=True&h264-profile=high,main,baseline,constrainedbaseline,high10&h264-level=51&h264-deinterlace=true. Host=my.server.com, X-Real-IP=162.158.142.41, X-Forwarded-For=clt.ip.add.ress, 162.158.142.41, Connection=Keep-Alive, Accept-Encoding=gzip, CF-IPCountry=US, CF-RAY=41cbcc222aec39b8-PHX, X-Forwarded-Proto=https, CF-Visitor={"scheme":"https"}, user-agent=Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/66.0.3359.181 Safari/537.36, accept=*/*, dnt=1, referer=https://my.server.com/web/videoosd.html, accept-language=en-US,en;q=0.9, cookie=__cfduid=d6b36a10794b4b73f101f89f476b988ed1522636125, CF-Connecting-IP=clt.ip.add.ress
2018-05-17 22:06:57.021 Info HttpServer: HTTP Response 200 to clt.ip.add.ress, 162.158.142.41. Time: 6ms. http://my.server.com:8096/videos/ad92bf839f10ccc99f50e0a9b636c013/hls1/main/4.ts?DeviceId=14c883917567bd6fdcd55ed0bb569e37d58e0c6e&MediaSourceId=ad92bf839f10ccc99f50e0a9b636c013&VideoCodec=h264&AudioCodec=mp3,aac&AudioStreamIndex=1&VideoBitrate=96167724&AudioBitrate=384000&PlaySessionId=e55963bf300c4b2d8b284e9b8b20645c&TranscodingMaxAudioChannels=2&RequireAvc=true&Tag=a1ad882aecc255058ba79e57717d1d6e&SegmentContainer=ts&MinSegments=1&BreakOnNonKeyFrames=True&h264-profile=high,main,baseline,constrainedbaseline,high10&h264-level=51&h264-deinterlace=true

I thought this might be a networking issue, but then I tested the network and everything seems ok per iperf as seen here:

>iperf3.exe -c srv.ip.add.ress -p 5201 -i 1
Connecting to host srv.ip.add.ress, port 5201
[  4] local clt.ip.add.ress port 53361 connected to srv.ip.add.ress port 5201
[ ID] Interval           Transfer     Bandwidth
[  4]   0.00-1.00   sec  2.88 MBytes  24.1 Mbits/sec
[  4]   1.00-2.00   sec  3.75 MBytes  31.5 Mbits/sec
[  4]   2.00-3.00   sec  3.75 MBytes  31.5 Mbits/sec
[  4]   3.00-4.00   sec  3.75 MBytes  31.4 Mbits/sec
[  4]   4.00-5.00   sec  3.75 MBytes  31.5 Mbits/sec
[  4]   5.00-6.00   sec  3.75 MBytes  31.5 Mbits/sec
[  4]   6.00-7.00   sec  3.88 MBytes  32.5 Mbits/sec
[  4]   7.00-8.00   sec  3.62 MBytes  30.4 Mbits/sec
[  4]   8.00-9.00   sec  3.75 MBytes  31.4 Mbits/sec
[  4]   9.00-10.00  sec  3.88 MBytes  32.6 Mbits/sec
- - - - - - - - - - - - - - - - - - - - - - - - -
[ ID] Interval           Transfer     Bandwidth
[  4]   0.00-10.00  sec  36.8 MBytes  30.8 Mbits/sec                  sender
[  4]   0.00-10.00  sec  36.6 MBytes  30.7 Mbits/sec                  receiver

iperf Done.

Would love some ideas, as i'm totally stumped at this point... i've tested just about everything and every way i can think of regarding the network or otherwise at this point... 

server_log.txt

ffmpeg_log.txt

Link to comment
Share on other sites
KarmaPolice

KarmaPolice   16

Posted
  • Author
Posted

Are you still seeing this?

 

It resolved... turned out it was something to do with cloudflare bogging down... not sure why, but it is what it is and is all better now...

Link to comment
Share on other sites

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...