Server should not fail to start a stream when accessing non-essential data from third party services

[yuzu_pup]

Heya,

 

So I've been pulling my hair out the past few days trying to figure out why my server has been intermittently failing to play new media I uploaded. Turns out the problem came down to a call in the TVDB plugin. Reading over the logs, it seemed to be failing due to a fetch of a movie poster timing out. Trying to hit the URL myself did indeed reveal that they seem to be having issues currently.

 

That's beside the point however. Emby should not fail to play my media if a plugin can't complete an HTTP request. I don't care that my server couldn't download a poster when I'm trying to watch a movie. That's a "log an error, substitute with some default image, and carry on" type of issue.

 

Is the TVDB plugin open-source? I'd be willing to dive in and submit a fix if I can get at the code.

 

Here's the relevant log snippet:

2019-09-01 19:59:56.964 Error HttpServer: Error processing request
	*** Error Report ***
	Version: 4.2.1.0
	Command line: /opt/emby-server/system/EmbyServer.dll -programdata /var/lib/emby -ffdetect /opt/emby-server/bin/ffdetect -ffmpeg /opt/emby-server/bin/ffmpeg -ffprobe /opt/emby-server/bin/ffprobe -restartexitcode 3 -updatepackage emby-server-deb_{version}_amd64.deb
	Operating system: Unix 4.15.0.58
	64-Bit OS: True
	64-Bit Process: True
	User Interactive: True
	Runtime: file:///opt/emby-server/system/System.Private.CoreLib.dll
	Processor count: 4
	Program data path: /var/lib/emby
	Application directory: /opt/emby-server/system
	MediaBrowser.Model.Net.HttpException: MediaBrowser.Model.Net.HttpException: Connection to https://www.thetvdb.com/banners/posters/78878-12.jpg timed out ---> System.Threading.Tasks.TaskCanceledException: The operation was canceled. ---> System.IO.IOException: Unable to read data from the transport connection: Operation canceled. ---> System.Net.Sockets.SocketException: Operation canceled
	   --- End of inner exception stack trace ---
	   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.ThrowException(SocketError error)
	   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.GetResult(Int16 token)
	   at System.Net.Security.SslStreamInternal.<FillBufferAsync>g__InternalFillBufferAsync|38_0[TReadAdapter](TReadAdapter adap, ValueTask`1 task, Int32 min, Int32 initial)
	   at System.Net.Security.SslStreamInternal.ReadAsyncInternal[TReadAdapter](TReadAdapter adapter, Memory`1 buffer)
	   at System.Net.Http.HttpConnection.FillAsync()
	   at System.Net.Http.HttpConnection.ReadNextResponseHeaderLineAsync(Boolean foldedHeadersAllowed)
	   at System.Net.Http.HttpConnection.SendAsyncCore(HttpRequestMessage request, CancellationToken cancellationToken)
	   --- End of inner exception stack trace ---
	   at System.Net.Http.HttpConnection.SendAsyncCore(HttpRequestMessage request, CancellationToken cancellationToken)
	   at System.Net.Http.HttpConnectionPool.SendWithNtConnectionAuthAsync(HttpConnection connection, HttpRequestMessage request, Boolean doRequestAuth, CancellationToken cancellationToken)
	   at System.Net.Http.HttpConnectionPool.SendWithRetryAsync(HttpRequestMessage request, Boolean doRequestAuth, CancellationToken cancellationToken)
	   at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
	   at System.Net.Http.DecompressionHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
	   at System.Net.Http.HttpClient.FinishSendAsyncUnbuffered(Task`1 sendTask, HttpRequestMessage request, CancellationTokenSource cts, Boolean disposeCts)
	   at Emby.Server.Implementations.HttpClientManager.CoreHttpClientManager.SendAsyncInternal(HttpRequestOptions options, String httpMethod)
	   --- End of inner exception stack trace ---
	   at Emby.Server.Implementations.HttpClientManager.CoreHttpClientManager.SendAsyncInternal(HttpRequestOptions options, String httpMethod)
	   at Emby.Server.Implementations.HttpClientManager.CoreHttpClientManager.SendAsync(HttpRequestOptions options, String httpMethod)
	   at MediaBrowser.Providers.Manager.ProviderManager.SaveImage(BaseItem item, String url, ImageType type, Nullable`1 imageIndex, CancellationToken cancellationToken)
	   at Emby.Server.Implementations.Library.LibraryManager.ConvertImageToLocal(BaseItem item, ItemImageInfo image, Int32 imageIndex, CancellationToken cancellationToken)
	   at Emby.Drawing.ImageProcessor.ProcessImage(ImageProcessingOptions options, CancellationToken cancellationToken)
	   at MediaBrowser.Api.Images.ImageService.GetImage(ImageRequest request, Int64 itemId, BaseItem item, Boolean isHeadRequest)
	   at Emby.Server.Implementations.Services.ServiceController.GetTaskResult(Task task)
	   at Emby.Server.Implementations.Services.ServiceHandler.ProcessRequestAsync(HttpListenerHost appHost, IRequest httpReq, IResponse httpRes, RestPath restPath, String responseContentType, CancellationToken cancellationToken)
	   at Emby.Server.Implementations.HttpServer.HttpListenerHost.RequestHandler(IRequest httpReq, ReadOnlyMemory`1 urlString, ReadOnlyMemory`1 host, ReadOnlyMemory`1 localPath, CancellationToken cancellationToken)
	Source: Emby.Server.Implementations
	TargetSite: Void MoveNext()
	InnerException: System.Threading.Tasks.TaskCanceledException: The operation was canceled.
	Source: System.Net.Http
	TargetSite: Void MoveNext()
	   at System.Net.Http.HttpConnection.SendAsyncCore(HttpRequestMessage request, CancellationToken cancellationToken)
	   at System.Net.Http.HttpConnectionPool.SendWithNtConnectionAuthAsync(HttpConnection connection, HttpRequestMessage request, Boolean doRequestAuth, CancellationToken cancellationToken)
	   at System.Net.Http.HttpConnectionPool.SendWithRetryAsync(HttpRequestMessage request, Boolean doRequestAuth, CancellationToken cancellationToken)
	   at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
	   at System.Net.Http.DecompressionHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
	   at System.Net.Http.HttpClient.FinishSendAsyncUnbuffered(Task`1 sendTask, HttpRequestMessage request, CancellationTokenSource cts, Boolean disposeCts)
	   at Emby.Server.Implementations.HttpClientManager.CoreHttpClientManager.SendAsyncInternal(HttpRequestOptions options, String httpMethod)
	InnerException: System.IO.IOException: Unable to read data from the transport connection: Operation canceled.
	Source: System.Net.Sockets
	TargetSite: Void ThrowException(System.Net.Sockets.SocketError)
	   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.ThrowException(SocketError error)
	   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.GetResult(Int16 token)
	   at System.Net.Security.SslStreamInternal.<FillBufferAsync>g__InternalFillBufferAsync|38_0[TReadAdapter](TReadAdapter adap, ValueTask`1 task, Int32 min, Int32 initial)
	   at System.Net.Security.SslStreamInternal.ReadAsyncInternal[TReadAdapter](TReadAdapter adapter, Memory`1 buffer)
	   at System.Net.Http.HttpConnection.FillAsync()
	   at System.Net.Http.HttpConnection.ReadNextResponseHeaderLineAsync(Boolean foldedHeadersAllowed)
	   at System.Net.Http.HttpConnection.SendAsyncCore(HttpRequestMessage request, CancellationToken cancellationToken)
	InnerException: System.Net.Sockets.SocketException: Operation canceled
	Source: 
	TargetSite: 

Edited September 1, 2019 by yuzu_pup

[Happy2Play]

I have never had a image issue prevent or stop playback of any media.  You provided a image processing error, is there a playback error?  But you will probably have to post a server log provided specific times of attempted playback.

[Luke]

Hi there, please attach the complete emby server log. thanks.

[yuzu_pup]

I could not get the error to induce with the exact piece of media I was trying before. It looks like Emby caches images from TVDB. I was able to induce it by performing the following:

1. Edit my server's HOSTS file (/etc/hosts) to point www.thetvdb.com to 0.0.0.0 to ensure failure to communicate with TVDB
2. Edit the metadata of an existing series to point at a series on TVDB I did not have on my server
3. Restart server
4. Force refresh of metadata on the now incorrectly identified series.

This resulted in the server returning a "Stream not available" error when trying to play the media after my server completed the refresh (~1 minute). I was able to confirm the refresh succeeded because all of my media in that series displayed the filename instead of the episode title.

 

Logs are attached.

embyserver.txt

ffmpeg-transcode-e58b8758-10d7-48d7-9271-a1ed09fc8068_1.txt

[yuzu_pup]

Just as a note: other media on my server plays fine. It is just the edited series that fails to play.

[Luke]

@@yuzu_pup would you mind seeing if you're able to reproduce this with the 4.3 beta? Thanks !

[yuzu_pup]

Hey @Luke:

 

Sorry! this issue totally slipped my mind. Did the fix make it into the 4.3 release proper. I can try to repro.

 

Yuzu

[Luke]

@@yuzu_pup, actually I'm wondering if you could try the beta server. That would be extremely helpful as we've updated from .NET Core 2.2 to .NET Core 3.1. That may help reconcile some of the differences across operating systems as I can't reproduce this on Windows but I have seen similar things on both Linux and Android. Thanks !

[Luke]

@@yuzu_pup did you have a chance to try this?