Edit: the key seems to be that the failing movies are all 4k. I’m not trying to live stream these, so I thought transcoding would work fine. It tends to fail right at the end, after transcoding seems to be complete, or near complete. I am able to play the Output.mkv file in the temporary Plex transcode folder just fine, though I don’t know if transcoding goes quite all the way to completion because when it fails the file vanishes right away.
Hi. While trying to download movies from my server to my Android tablet, some movies always fail while others succeed. Attached is a log from the most recent failure.
Server Version#: 1.25.2.5319
Player Version#: 8.27.2.29938
From client:
12-31 05:31:41.217 i: [OkHttpDownloader] Checking space after 2087454720 bytes.
12-31 05:32:00.262 i: [OkHttpDownloader] Checking space after 2092699648 bytes.
12-31 05:32:24.449 i: [OkHttpDownloader] Checking space after 2097944576 bytes.
12-31 05:32:39.761 i: [OkHttpDownloader] Checking space after 2103189497 bytes.
12-31 05:32:58.799 i: [OkHttpDownloader] Checking space after 2108434425 bytes.
12-31 05:33:15.765 i: [OkHttpDownloader] Checking space after 2113679353 bytes.
12-31 05:33:35.195 i: [OkHttpDownloader] Checking space after 2118924281 bytes.
12-31 05:33:53.445 i: [OkHttpDownloader] Checking space after 2124169209 bytes.
12-31 05:34:04.847 i: [EventSource (LocalServer)] Message: {"ActivityNotification":{"event":"updated","uuid":"f2e5518d-45c8-4555-a2bb-173b0008d4e2","Activity":{"uuid":"f2e5518d-45c8-4555-a2bb-173b0008d4e2","type":"grabber.grab","cancellable":true,"userID":1,"title":"Downloading","subtitle":"Waterworld (1995)","progress":69,"Context":{"currentSize":2126667769,"grabber":"tv.plex.grabbers.download","itemKey":"/library/metadata/146131","itemMediaIndex":"0","itemRatingKey":"146131","source":"server://59b0d5d03ea468bb6fc66e3406b058239474261f/com.plexapp.plugins.library","status":"inprogress","subscriptionID":"19"}}}}
12-31 05:34:04.855 i: [EventSource (LocalServer)] Message: {"ActivityNotification":{"event":"updated","uuid":"47f81910-c9e8-4d8f-a011-f71e09700ee2","Activity":{"uuid":"47f81910-c9e8-4d8f-a011-f71e09700ee2","type":"provider.subscription.refresh","cancellable":false,"userID":1,"title":"Refreshing Sub","subtitle":"Downloading","progress":69,"Context":{"completed":0,"ratingKey":"146131","refreshing":"0","source":"server://59b0d5d03ea468bb6fc66e3406b058239474261f/com.plexapp.plugins.library","subscriptionID":"19","total":1,"waiting":"0"}}}}
12-31 05:34:04.871 i: Fetching [method:GET] http://127.0.0.1:32500/media/subscriptions/19?includeTarget=1&X-Plex-Account-ID=1&X-Plex-Language=en-us
12-31 05:34:04.884 i: [HttpServer] /127.0.0.1:49448 - GET /media/subscriptions/19
12-31 05:34:04.896 i: [Fetch] Fetched 1 items from /media/subscriptions/19?includeTarget=1&X-Plex-Account-ID=1.
12-31 05:34:14.199 e: [OkHttpDownloader] Exception downloading /storage/5065-9F6C/Android/data/com.plexapp.android/files/2/15/.grab/698677f5da9c3ac9d9705d44da40aec2dfabc9a1-local/Waterworld (1995).mkv
12-31 05:34:14.219 e: An exception occurred: java.net.SocketTimeoutException: timeout
12-31 05:34:14.220 i: [DownloadQueueManager] Download failed: 698677f5da9c3ac9d9705d44da40aec2dfabc9a1
12-31 05:34:14.220 e: Stacktrace: java.net.SocketTimeoutException: timeout
at f.d0.newTimeoutException(SourceFile:1)
at f.d.access$newTimeoutException(SourceFile:1)
at f.d$d.read(SourceFile:6)
at f.y.w(SourceFile:5)
at f.y.f0(SourceFile:1)
at f.y.I0(SourceFile:1)
at okhttp3.internal.http1.Http1ExchangeCodec$ChunkedSource.readChunkSize(SourceFile:3)
at okhttp3.internal.http1.Http1ExchangeCodec$ChunkedSource.read(SourceFile:4)
at okhttp3.internal.connection.Exchange$ResponseBodySource.read(SourceFile:2)
at f.y.read(SourceFile:6)
at okhttp3.internal.cache.CacheInterceptor$cacheWritingResponse$cacheWritingSource$1.read(SourceFile:1)
at f.y.read(SourceFile:6)
at com.plexapp.plex.mediaprovider.podcasts.offline.b0.l(SourceFile:1)
at com.plexapp.plex.mediaprovider.podcasts.offline.b0.k(SourceFile:19)
at com.plexapp.plex.mediaprovider.podcasts.offline.b0.e(SourceFile:1)
at com.plexapp.plex.mediaprovider.podcasts.offline.b0$a.onResponse(SourceFile:1)
at okhttp3.internal.connection.RealCall$AsyncCall.run(SourceFile:7)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
at java.lang.Thread.run(Thread.java:923)
Caused by: java.net.SocketException: Socket closed
at java.net.SocketInputStream.read(SocketInputStream.java:209)
at java.net.SocketInputStream.read(SocketInputStream.java:144)
at com.android.org.conscrypt.ConscryptEngineSocket$SSLInputStream.readFromSocket(ConscryptEngineSocket.java:936)
at com.android.org.conscrypt.ConscryptEngineSocket$SSLInputStream.processDataFromSocket(ConscryptEngineSocket.java:900)
at com.android.org.conscrypt.ConscryptEngineSocket$SSLInputStream.readUntilDataAvailable(ConscryptEngineSocket.java:815)
at com.android.org.conscrypt.ConscryptEngineSocket$SSLInputStream.read(ConscryptEngineSocket.java:788)
at f.q.read(SourceFile:5)
at f.d$d.read(SourceFile:3)
... 17 more
12-31 05:34:17.213 i: [DownloadQueueManager] Network conditions are fine, download really failed
12-31 05:34:17.214 w: [DownloadQueueManager] Adding 698677f5da9c3ac9d9705d44da40aec2dfabc9a1 to the failed list: Unknown issue occurred.
12-31 05:34:17.215 i: [DownloadQueueManager] Current download queue is empty and there is content that failed
12-31 05:34:17.216 i: [DownloadNotificationManager] Displaying error notification (Some items could not be downloaded).
12-31 05:34:17.222 i: [DownloadServiceHandler] Switching to 'waiting for downloads' after download queue finished
12-31 05:34:17.223 i: [DownloadServiceHandler] New state is WaitingForDownloads
From server around same time:
Dec 31, 2021 05:31:18.652 [24868] DEBUG - Activity: updated activity d0323d8b-b01f-4c34-b828-63f1d5557034 - completed 69.6% - Media download by maryhma
Dec 31, 2021 05:31:18.752 [24872] DEBUG - Activity: updated activity d0323d8b-b01f-4c34-b828-63f1d5557034 - completed 69.6% - Media download by maryhma
Dec 31, 2021 05:31:18.867 [24868] DEBUG - Activity: updated activity d0323d8b-b01f-4c34-b828-63f1d5557034 - completed 69.6% - Media download by maryhma
Dec 31, 2021 05:31:18.991 [24868] DEBUG - Activity: updated activity d0323d8b-b01f-4c34-b828-63f1d5557034 - completed 69.6% - Media download by maryhma
Dec 31, 2021 05:31:19.124 [24872] DEBUG - Activity: updated activity d0323d8b-b01f-4c34-b828-63f1d5557034 - completed 69.6% - Media download by maryhma
Dec 31, 2021 05:31:19.280 [24872] DEBUG - Activity: updated activity d0323d8b-b01f-4c34-b828-63f1d5557034 - completed 69.6% - Media download by maryhma
Dec 31, 2021 05:31:21.804 [24868] DEBUG - Auth: authenticated user 9569558 as maryhma
Dec 31, 2021 05:31:21.804 [49744] DEBUG - Request: [72.130.82.110:40086 (WAN)] GET /video/:/transcode/universal/stop?session=7a7ce67a518c36fd7686d545e921d114d095bad1 (8 live) TLS GZIP Signed-in Token (maryhma)
Dec 31, 2021 05:31:21.805 [58156] DEBUG - [Transcode] Killing job.
Dec 31, 2021 05:31:21.806 [24868] DEBUG - Completed: [72.130.82.110:40086] 200 GET /video/:/transcode/universal/stop?session=7a7ce67a518c36fd7686d545e921d114d095bad1 (8 live) TLS GZIP 1ms 195 bytes (pipelined: 802)
Dec 31, 2021 05:31:21.870 [58156] DEBUG - [Transcode] Job was already killed, not killing again.
Dec 31, 2021 05:31:21.870 [58156] DEBUG - [Transcode] Stopping transcode session 7a7ce67a518c36fd7686d545e921d114d095bad1
Dec 31, 2021 05:31:21.870 [31848] DEBUG - Jobs: 'C:\Program Files (x86)\Plex\Plex Media Server\Plex Transcoder.exe' exit code for process 66860 is -1059143458 (intentional termination)
Dec 31, 2021 05:31:21.871 [98840] DEBUG - Activity: Ended activity 14343bdc-afba-4f05-b3a4-7035e24bcdce.
Dec 31, 2021 05:31:21.872 [98840] DEBUG - Notifying consumer that data is complete.
Dec 31, 2021 05:31:21.879 [74464] DEBUG - [TranscodeOutputStream] Input processing thread exited after writing 2128609280 bytes, m_closed=0, m_endOfFileReached=0, session->isStopped()=1
Dec 31, 2021 05:31:21.881 [58156] DEBUG - [Transcode] Transcoder: Cleaning old transcode directories.
Dec 31, 2021 05:31:21.882 [58156] DEBUG - [Transcode] Transcoder: Cleaning old transcode directory: "t:\plextemp\Transcode\Sessions\plex-transcode-7a7ce67a518c36fd7686d545e921d114d095bad1-3178f47b-2d3c-48d1-b394-1938e8d3d887"
Dec 31, 2021 05:31:21.883 [58156] ERROR - [Transcode] Transcoder: Failed to delete session directory (boost::filesystem::remove: The process cannot access the file because it is being used by another process: "t:\plextemp\Transcode\Sessions\plex-transcode-7a7ce67a518c36fd7686d545e921d114d095bad1-3178f47b-2d3c-48d1-b394-1938e8d3d887\Output.mkv")
Dec 31, 2021 05:31:21.883 [58156] DEBUG - [Transcode] Whacked session 7a7ce67a518c36fd7686d545e921d114d095bad1, 0 remaining.
Dec 31, 2021 05:31:21.883 [58156] DEBUG - Cleaning directory for session 7a7ce67a518c36fd7686d545e921d114d095bad1 (t:\plextemp\Transcode\Sessions\plex-transcode-7a7ce67a518c36fd7686d545e921d114d095bad1-3178f47b-2d3c-48d1-b394-1938e8d3d887)
Dec 31, 2021 05:31:21.884 [58156] ERROR - Failed to delete session directory (boost::filesystem::remove: The process cannot access the file because it is being used by another process: "t:\plextemp\Transcode\Sessions\plex-transcode-7a7ce67a518c36fd7686d545e921d114d095bad1-3178f47b-2d3c-48d1-b394-1938e8d3d887\Output.mkv")
Dec 31, 2021 05:31:21.887 [58156] DEBUG - Streaming Resource: Terminating session 07596168:7a7ce67a518c36fd7686d545e921d114d095bad1 which is using static transcoder slot. Used slots is now 0
Dec 31, 2021 05:31:21.889 [58156] DEBUG - Streaming Resource: Terminated session 07596168:7a7ce67a518c36fd7686d545e921d114d095bad1 with reason Client stopped playback.
Dec 31, 2021 05:31:21.889 [58156] DEBUG - Streaming Resource: Removing session 07596168:7a7ce67a518c36fd7686d545e921d114d095bad1
Dec 31, 2021 05:31:21.970 [24868] ERROR - [TranscodeOutputStream] Session appears to have died from under us
Dec 31, 2021 05:31:21.971 [24868] DEBUG - Activity: Ended activity d0323d8b-b01f-4c34-b828-63f1d5557034.
Thanks
