Log file data for audio dropouts when playing music files from Windows computer to HT receiver using HDMI cable

Server Version#: Version 1.14.1.5488
Player Version#: Web Client Version 3.77.4

I have PLEX server on a Windows 10 laptop. It is a new laptop (Lenovo Yoga 730) with Intel i7, 256 GB SSD, 8GB RAM, Intel chipset for audio. The laptop is connected to HT receiver using HDMI cable. When listening to music files on the laptop, I don’t use the large 65" plasma TV connected to the HT receiver to control music playback. Instead I use the PLEX app on my iOS iPad. On the laptop, I open a Chrome browser window and go to the PLEX server IP address. On the iPad I then “cast” to the “PLEX Web” program running in the Chrome browser on the laptop. I then start listening to music files that are on the Windows 10 laptop. The laptop transmits PCM to the HT receiver via HDMI cable.

It all works perfectly except for random audio dropouts that last for one or two seconds. They can appear near the start of music file playback, in the middle or near the end. I can get two or three dropouts in one 4 minute music track or i can go 20 minutes with no dropouts. Also it doesn’t seem to matter if mp3, Flac, wav and the resolution of the music file doesn’t seem to matter either (I will double check).

When I hear a dropout i will wait for music to start playing again and then I will hit the little “go back (rewind) 10 seconds” in the PLEX iPad iOS app. The music then starts playing again. The dropout never occurs a second time at the same spot after using rewind.

Questions:

  • Should i use the PLEX Media Player (PMP) on the Windows laptop instead of the PLEX Web program?
  • Is Windows 10 laptop getting busy or is PLEX server getting busy?

When I look at the PLEX logs, there is a file that has timestamps that correspond to the hour I was listening to music. The log is called

Plex Media Server.3.log

When I search for “error”, I see things like the following:

Mar 02, 2019 21:54:34.832 [7708] DEBUG - [Now] Updated play state for /library/metadata/471.
Mar 02, 2019 21:54:34.833 [7708] DEBUG - Statistics: (x062tau99mnj27ehjfnwq7i0) Reporting active playback in state 0 of type 10 (scrobble: 0) for account 1
Mar 02, 2019 21:54:34.833 [13632] DEBUG - handleStreamWrite code 10053: An established connection was aborted by the software in your host machine
Mar 02, 2019 21:54:34.833 [13632] DEBUG - NotificationStream: Removing because of error
Mar 02, 2019 21:54:34.835 [13632] DEBUG - Completed: [127.0.0.1:59951] 200 GET /:/timeline?ratingKey=471&key=%2Flibrary%2Fmetadata%2F471&playbackTime=19037&playQueueItemID=682&state=playing&hasMDE=1&time=19000&duration=444000 (34 live) GZIP 7ms 538 bytes (pipelined: 3)

and thinks like:

Mar 02, 2019 21:54:14.659 [4172] DEBUG - Request: [127.0.0.1:59957 (Loopback)] GET /library/sections/1/all?type=8&includeCollections=1 (34 live) Page 0–1 GZIP Signed-in Token (xxx@gmail.com)
Mar 02, 2019 21:54:14.660 [4172] DEBUG - Setting container serialization range to [0, -1] (total=-1)
Mar 02, 2019 21:54:14.660 [13636] DEBUG - handleStreamRead code 335544539: short read
Mar 02, 2019 21:54:14.660 [13636] WARN - LongPoll: Got error, closing.
Mar 02, 2019 21:54:14.662 [13636] DEBUG - Auth: authenticated user 1 as xxx@gmail.com
Mar 02, 2019 21:54:14.662 [5624] DEBUG - Request: [127.0.0.1:59954 (Loopback)] GET /library/sections/1/firstCharacter?type=8&includeCollections=1 (34 live) GZIP Signed-in Token (xxx@gmail.com)

and

Mar 02, 2019 21:52:17.669 [5624] DEBUG - [Now] Device is Chrome (Chrome).
Mar 02, 2019 21:52:17.672 [5624] DEBUG - [Now] Profile is Web
Mar 02, 2019 21:52:17.672 [5624] DEBUG - [Now] Updated play state for /library/metadata/765.
Mar 02, 2019 21:52:17.673 [5624] DEBUG - Statistics: (x062tau99mnj27ehjfnwq7i0) Reporting active playback in state 0 of type 10 (scrobble: 0) for account 1
Mar 02, 2019 21:52:17.673 [13636] DEBUG - handleStreamWrite code 10053: An established connection was aborted by the software in your host machine
Mar 02, 2019 21:52:17.674 [13636] DEBUG - NotificationStream: Removing because of error
Mar 02, 2019 21:52:17.678 [13636] DEBUG - Completed: [127.0.0.1:59911] 200 GET /:/timeline?ratingKey=765&key=%2Flibrary%2Fmetadata%2F765&playbackTime=29043&playQueueItemID=681&state=playing&hasMDE=1&time=29000&duration=156000 (31 live) GZIP 16ms 539 bytes (pipelined: 1)

I will try upload the log file.

Attached is Plex Media Server.3.log with the errors.

Plex Media Server.3.log (5.0 MB)

Mar 03, 2019 19:44:50.825 [10120] DEBUG - [Now] Device is Konvergo (DESKTOP-V4DRDTI).
Mar 03, 2019 19:44:50.827 [10120] DEBUG - [Now] Profile is Konvergo
Mar 03, 2019 19:44:50.828 [10120] DEBUG - [Now] Updated play state for /library/metadata/362.
Mar 03, 2019 19:44:50.828 [10120] DEBUG - Statistics: (s8uplysv95lj8yi89lom3g14) Reporting active playback in state 0 of type 10 (scrobble: 0) for account 1
Mar 03, 2019 19:44:50.830 [13636] DEBUG - Completed: [127.0.0.1:62275] 200 GET /:/timeline?ratingKey=362&key=%2Flibrary%2Fmetadata%2F362&playbackTime=79130&playQueueItemID=1311&state=playing&hasMDE=1&time=79000&duration=442000 (11 live) GZIP 16ms 489 bytes (pipelined: 10)
Mar 03, 2019 19:44:52.301 [13636] DEBUG - handleStreamWrite code 10053: An established connection was aborted by the software in your host machine
Mar 03, 2019 19:44:52.302 [13636] DEBUG - NotificationStream: Removing because of error
Mar 03, 2019 19:44:53.141 [4272] DEBUG - Statistics: Flushing 5 expired bandwidth entries, 0 expired media entries.
Mar 03, 2019 19:45:00.813 [13636] DEBUG - Auth: authenticated user 1 as xxx.com
Mar 03, 2019 19:45:00.814 [4420] DEBUG - Request: [127.0.0.1:62275 (Loopback)] GET /:/timeline?ratingKey=362&key=%2Flibrary%2Fmetadata%2F362&playbackTime=89146&playQueueItemID=1311&state=playing&hasMDE=1&time=89000&duration=442000 (9 live) GZIP Signed-in Token (xxx@gmail.com)
Mar 03, 2019 19:45:00.816 [4420] DEBUG - Client [zr1mhmt75dk6zg6849774x6r] reporting timeline state playing, progress of 89000/442000ms for guid=, ratingKey=362 url=, key=/library/metadata/362, containerKey=, metadataId=362, source=
Mar 03, 2019 19:45:00.821 [4420] DEBUG - Play progress on 362 ‘6 Suites (Sonatas) for Cello, BWV 1007-12, Suite No. 5 in C Minor, BWV 1011: Prélude’ - got played 89000 ms by account 1!

Mar 03, 2019 20:16:24.489 [9744] DEBUG - [Now] Device is Konvergo (DESKTOP-V4DRDTI).
Mar 03, 2019 20:16:24.496 [9744] DEBUG - [Now] Profile is Konvergo
Mar 03, 2019 20:16:24.496 [9744] DEBUG - [Now] Updated play state for /library/metadata/361.
Mar 03, 2019 20:16:24.497 [9744] DEBUG - Statistics: (s8uplysv95lj8yi89lom3g14) Reporting active playback in state 0 of type 10 (scrobble: 0) for account 1
Mar 03, 2019 20:16:24.501 [13636] DEBUG - Completed: [127.0.0.1:63317] 200 GET /:/timeline?ratingKey=361&key=%2Flibrary%2Fmetadata%2F361&playbackTime=29120&playQueueItemID=2&state=playing&hasMDE=1&time=29000&duration=214000 (7 live) GZIP 16ms 488 bytes (pipelined: 30)
Mar 03, 2019 20:16:24.891 [13636] DEBUG - handleStreamWrite code 10053: An established connection was aborted by the software in your host machine
Mar 03, 2019 20:16:24.892 [13636] DEBUG - NotificationStream: Removing because of error
Mar 03, 2019 20:16:34.485 [13636] DEBUG - Auth: authenticated user 1 as xxx@gmail.com
Mar 03, 2019 20:16:34.486 [9348] DEBUG - Request: [127.0.0.1:63317 (Loopback)] GET /:/timeline?ratingKey=361&key=%2Flibrary%2Fmetadata%2F361&playbackTime=39139&playQueueItemID=2&state=playing&hasMDE=1&time=39000&duration=214000 (6 live) GZIP Signed-in Token (xxxgmail.com)
Mar 03, 2019 20:16:34.488 [9348] DEBUG - Client [hna1kb7wkos9ztrpw5ukgldi] reporting timeline state playing, progress of 39000/214000ms for guid=, ratingKey=361 url=, key=/library/metadata/361, containerKey=, metadataId=361, source=
Mar 03, 2019 20:16:34.489 [9348] DEBUG - [Now] User is xxx@gmail.com (ID: 1)
Mar 03, 2019 20:16:34.491 [9348] DEBUG - [Now] Device is Konvergo (DESKTOP-V4DRDTI).
Mar 03, 2019 20:16:34.496 [9348] DEBUG - [Now] Profile is Konvergo
Mar 03, 2019 20:16:34.497 [9348] DEBUG - [Now] Updated play state for /library/metadata/361.
Mar 03, 2019 20:16:34.497 [9348] DEBUG - Statistics: (s8uplysv95lj8yi89lom3g14) Reporting active playback in state 0 of type 10 (scrobble: 0) for account 1
Mar 03, 2019 20:16:34.500 [13632] DEBUG - Completed: [127.0.0.1:63317] 200 GET /:/timeline?ratingKey=361&key=%2Flibrary%2Fmetadata%2F361&playbackTime=39139&playQueueItemID=2&state=playing&hasMDE=1&time=39000&duration=214000 (6 live) GZIP 15ms 488 bytes (pipelined: 31)

Mar 03, 2019 23:00:16.909 [1892] DEBUG - [Now] Updated play state for /library/metadata/753.
Mar 03, 2019 23:00:16.910 [1892] DEBUG - Statistics: (s8uplysv95lj8yi89lom3g14) Reporting active playback in state 0 of type 10 (scrobble: 0) for account 1
Mar 03, 2019 23:00:16.914 [12716] DEBUG - Completed: [127.0.0.1:57073] 200 GET /:/timeline?ratingKey=753&key=%2Flibrary%2Fmetadata%2F753&playbackTime=19041&playQueueItemID=5&state=playing&hasMDE=1&time=19000&duration=331000 (9 live) GZIP 13ms 487 bytes (pipelined: 9)
Mar 03, 2019 23:00:18.467 [12716] DEBUG - handleStreamWrite code 10053: An established connection was aborted by the software in your host machine
Mar 03, 2019 23:00:18.468 [12716] DEBUG - NotificationStream: Removing because of error
Mar 03, 2019 23:00:26.896 [12712] DEBUG - Auth: authenticated user 1 as xxx@gmail.com
Mar 03, 2019 23:00:26.896 [3156] DEBUG - Request: [127.0.0.1:57073 (Loopback)] GET /:/timeline?ratingKey=753&key=%2Flibrary%2Fmetadata%2F753&playbackTime=29074&playQueueItemID=5&state=playing&hasMDE=1&time=29000&duration=331000 (7 live) GZIP Signed-in Token (xxx@gmail.com)
Mar 03, 2019 23:00:26.897 [3156] DEBUG - Client [jsdpgy83uzfps3xvyi1pxpqf] reporting timeline state playing, progress of 29000/331000ms for guid=, ratingKey=753 url=, key=/library/metadata/753, containerKey=, metadataId=753, source=
Mar 03, 2019 23:00:26.897 [3156] DEBUG - [Now] User is xxx@gmail.com (ID: 1)
Mar 03, 2019 23:00:26.897 [3156] DEBUG - [Now] Device is Konvergo (DESKTOP-V4DRDTI).
Mar 03, 2019 23:00:26.898 [3156] DEBUG - [Now] Profile is Konvergo
Mar 03, 2019 23:00:26.898 [3156] DEBUG - [Now] Updated play state for /library/metadata/753.

This topic was automatically closed 90 days after the last reply. New replies are no longer allowed.