Long delay (3 minutes) before and after playing a file

[TobyTentakel 25]

I posted the issue in the EmbyCon subforum as well yesterday, but it seems it is actually an issue with the server.

For quite some time I have a strange problem with the Embycon client for Kodi accessing the Emby server (latest beta running on a Synology), connected via ethernet.

Browsing is relatively fast, but whenever I start a video, I have a delay of 2 to 3 minutes before the file plays. The same happens if I stop the video. While the video is playing, there are no problems, delays, lag, etc. This happens consistently and independently of the video source (with or without transcoding, low or high resolution, etc.)

I did an analysis of the log file on the server and saw that for the most part, responses to requests came within a few milliseconds, as expected. However, updating or querying the playstate for the selected item (PlaystateService/ItemsService) always takes long (20+40+60 seconds in the example below, especially at timestamp 2025-03-30 15:24:59.792). Since the delays happen on the server when processing the command, I don't think it is an issue with Kodi/Embycon

Any idea what could be causing this and where I should look or how I can prevent this?

2025-03-30 15:24:36.298 Info VideoService-0HNAPK35QSV1L:00000002: http/1.1 Response 200 to host2. Time: 7ms. HEAD http://192.168.2.112:8096/emby/videos/1882857/original.mp4?DeviceId=b83a444759034c548f87352c5907ad07&MediaSourceId=mediasource_1882857&PlaySessionId=ba911d6896ed445587606eb89bb4488a&api_key=x_secret2_x

2025-03-30 15:24:40.434 Info PlaystateService-0HNAPK35QSV1M:00000001: http/1.1 POST http://192.168.2.112:8096/emby/Sessions/Playing/Stopped?. Source Ip: host2, UserAgent: EmbyCon-1.11.37

2025-03-30 15:24:40.435 Info SessionManager: Playback stopped reported by app Kodi EmbyCon 1.11.37 on EmbyCon playing Mr. Bean: The Animated Series - S4, Ep16 - Bei den Pfadfindern. Position: 646152 ms. PlaySessionId: ba911d6896ed445587606eb89bb4488a

2025-03-30 15:24:40.456 Info SessionManager: Removed playSession ba911d6896ed445587606eb89bb4488a from session 34d22dd6ead21231e106c222ca701b27

2025-03-30 15:24:40.456 Info PlaystateService-0HNAPK35QSV1M:00000001: http/1.1 Response 204 to host2. Time: 23ms. POST http://192.168.2.112:8096/emby/Sessions/Playing/Stopped?

2025-03-30 15:24:40.525 Info HlsSegmentService-0HNAPK35QSV1O:00000001: http/1.1 DELETE http://192.168.2.112:8096/emby/Videos/ActiveEncodings?DeviceId=b83a444759034c548f87352c5907ad07. Source Ip: host2, Host=192.168.2.112:8096, User-Agent=EmbyCon-1.11.37, Accept-Charset=UTF-8,*, Accept-Encoding=gzip, X-Emby-Authorization=MediaBrowser UserId="7fc799abad1e4981ab174ff0d8a690ec",Client="Kodi EmbyCon",Device="EmbyCon",DeviceId="b83a444759034c548f87352c5907ad07",Version="1.11.37", X-MediaBrowser-Token=x_secret2_x

2025-03-30 15:24:40.525 Info HlsSegmentService-0HNAPK35QSV1O:00000001: http/1.1 Response 204 to host2. Time: 4ms. DELETE http://192.168.2.112:8096/emby/Videos/ActiveEncodings?DeviceId=b83a444759034c548f87352c5907ad07

2025-03-30 15:24:40.571 Info PlaystateService-0HNAPK35QSV1P:00000001: http/1.1 POST http://192.168.2.112:8096/emby/Users/7fc799abad1e4981ab174ff0d8a690ec/PlayedItems/1882857?. Source Ip: host2, UserAgent: EmbyCon-1.11.37

2025-03-30 15:24:59.792 Info PlaystateService-0HNAPK35QSV1P:00000001: http/1.1 Response 200 to host2. Time: 19220ms. POST http://192.168.2.112:8096/emby/Users/7fc799abad1e4981ab174ff0d8a690ec/PlayedItems/1882857?

2025-03-30 15:25:38.653 Info ItemsService-0HNAPK35QSV1R:00000001: http/1.1 Response 500 to host2. Time: 38762ms. GET http://192.168.2.112:8096/emby/Users/7fc799abad1e4981ab174ff0d8a690ec/Items?Recursive=True&limit=1&Fields=DateCreated,Etag&SortBy=DatePlayed&SortOrder=Descending&IncludeItemTypes=Movie,Episode,Audio&ImageTypeLimit=0&format=json

2025-03-30 15:25:57.612 Info ItemsService-0HNAPK35QSV1S:00000001: http/1.1 Response 500 to host2. Time: 57721ms. GET http://192.168.2.112:8096/emby/Users/7fc799abad1e4981ab174ff0d8a690ec/Items?Recursive=True&limit=1&Fields=DateCreated,Etag&SortBy=DateCreated&SortOrder=Descending&IncludeItemTypes=Movie,Episode,Audio&ImageTypeLimit=0&format=json

2025-03-30 15:25:57.745 Info TvShowsService-0HNAPK35QSV1T:00000001: http/1.1 Response 500 to host2. Time: 48066ms. GET http://192.168.2.112:8096/emby/Shows/7606/Seasons?userId=7fc799abad1e4981ab174ff0d8a690ec&Fields=DateCreated,EpisodeCount,SeasonCount,Path,Genres,Studios,Etag,Taglines,SortName,RecursiveItemCount,ChildCount,ProductionLocations,CriticRating,OfficialRating,CommunityRating,PremiereDate,ProductionYear,AirTime,Status,Tags,MediaStreams,Overview&format=json

2025-03-30 15:27:20.534 Info MediaInfoService-0HNAPK35QSV29:00000001: http/1.1 POST http://192.168.2.112:8096/emby/Items/8979/PlaybackInfo?MaxStreamingBitrate=75000000. Source Ip: host2, UserAgent: EmbyCon-1.11.37

2025-03-30 15:27:20.538 Info App: User policy for O. EnablePlaybackRemuxing: True EnableVideoPlaybackTranscoding: True EnableAudioPlaybackTranscoding: True

2025-03-30 15:27:20.538 Info SessionManager: Adding playSession 0395d225141f487ab4cbcbb695148013 to session 34d22dd6ead21231e106c222ca701b27

2025-03-30 15:27:20.538 Info MediaInfoService-0HNAPK35QSV29:00000001: http/1.1 Response 200 to host2. Time: 4ms. POST http://192.168.2.112:8096/emby/Items/8979/PlaybackInfo?MaxStreamingBitrate=75000000

 

[Luke 42077]

 

Hi there, let's look at an example. Please attach the information requested in how to report a media playback issue. Thanks!

 

[TobyTentakel 25]

Attached are two full server logs, one from March 30, with the minute long delays (check timestamp 2025-03-30 15:24:59.792 and following) and one from April 1, with a newly created user, where the delays are much shorter, but still noticeable (check timestamp 2025-04-01 14:48:14.127).

 

embyserver.txt embyserver-63878966049.txt

[Luke 42077]

How does playing in the Emby web app compare?

[TobyTentakel 25]

Emby web app or Android app work just fine, no delay

[Luke 42077]

OK we are looking into it. Thanks.

[TobyTentakel 25]

From what I could gather by looking at the library.db file (which is several gigabytes big on my system), the delay gets longer the more entries in the table UserDatas the specific user has. For the user with the minute-long delays, I have more than 2000 rows in that table, for a newly created user with very short delay, I only have 4 entries.

I therefore suspect that Embycon is (unlike the other clients) sending an update to this table (with requests like POST http://192.168.2.112:8096/emby/Users/.../PlayedItems/xxx) that takes a long time to process on the server.

[TobyTentakel 25]

Short update: my current solution is to create a new user every week on Monday and use that until the end of the week for playback of my videos. That way, the delays are tolerable, but of course this is an inconvenient workaround

[Lazarus_Long 80]

Was this every resolved for you?

[TobyTentakel 25]

Nope, still happening :(

[Luke 42077]

8 hours ago, TobyTentakel said:

Nope, still happening

HI, can we please look at a new example?

How to Report a Problem

Thanks.

[Luke 42077]

@TobyTentakel?

[TobyTentakel 25]

I was ill the past weeks, I'll see that I can make the logs in the next days.