Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Scanning Media Library is incredibly slow #3722

Closed
davispuh opened this issue Jul 28, 2020 · 73 comments
Closed

Scanning Media Library is incredibly slow #3722

davispuh opened this issue Jul 28, 2020 · 73 comments
Labels
bug Something isn't working

Comments

@davispuh
Copy link

Describe the bug

After update to 10.6.0 library scanning seems to be stuck. It had all scanned previously.
In logs didn't saw anything useful just #3611
And there's thousands of OnRefreshStart/OnRefreshComplete lines in log.

System:

  • OS: Arch Linux
  • Virtualization: None
  • Clients: Browser
  • Browser: Firefox
  • Jellyfin Version: 10.6.0
  • Playback: N/A
  • Installed Plugins: AudioDB, Bookshelf, Fanart, LDAP-Auth, MusicBrainz, Open Subtitles, Playback Reporting, Reports
  • Reverse Proxy: nginx
  • Base URL: none
  • Networking: NAT
  • Storage: local

To Reproduce

  1. Have library fully scanned on previous version
  2. Update to 10.6.0
  3. Run Scan Media Library
  4. See library scan stuck

Expected behavior
Complete library scanning successfully.

Logs

[2020-07-28 03:18:08.448 +03:00] [INF] [1] Main: Jellyfin version: "10.6.0"
[2020-07-28 03:18:08.723 +03:00] [INF] [1] Main: Environment Variables: ["[JELLYFIN_LOG_DIR, /var/lib/jellyfin/log]", "[JELLYFIN_DATA_DIRECTORY, /var/lib/jellyfin]", "[JELLYFIN_CACHE_DIRECTORY, /var/cache/jellyfin]", "[JELLYFIN_ADD_OPTS, ]"]
[2020-07-28 03:18:08.728 +03:00] [INF] [1] Main: Arguments: ["/usr/lib/jellyfin/jellyfin.dll", "--datadir", "/var/lib/jellyfin", "--cachedir", "/var/cache/jellyfin", ""]
[2020-07-28 03:18:08.729 +03:00] [INF] [1] Main: Operating system: "Linux"
[2020-07-28 03:18:08.730 +03:00] [INF] [1] Main: Architecture: X64
[2020-07-28 03:18:08.731 +03:00] [INF] [1] Main: 64-Bit Process: True
[2020-07-28 03:18:08.731 +03:00] [INF] [1] Main: User Interactive: True
[2020-07-28 03:18:08.731 +03:00] [INF] [1] Main: Processor count: 24
[2020-07-28 03:18:08.731 +03:00] [INF] [1] Main: Program data path: "/var/lib/jellyfin"
[2020-07-28 03:18:08.731 +03:00] [INF] [1] Main: Web resources path: "/usr/lib/jellyfin/jellyfin-web"
[2020-07-28 03:18:08.731 +03:00] [INF] [1] Main: Application directory: "/usr/lib/jellyfin/"
[2020-07-28 03:18:09.693 +03:00] [INF] [1] Emby.Server.Implementations.AppBase.BaseConfigurationManager: Setting cache path: "/var/cache/jellyfin"
[2020-07-28 03:18:09.836 +03:00] [INF] [1] Emby.Server.Implementations.ApplicationHost: Loading assemblies
[2020-07-28 03:18:09.981 +03:00] [INF] [1] Emby.Server.Implementations.ApplicationHost: Loaded assembly "OpenSubtitlesHandler, Version=0.0.0.0, Culture=neutral, PublicKeyToken=null" from "/var/lib/jellyfin/plugins/Open Subtitles/OpenSubtitlesHandler.dll"
[2020-07-28 03:18:09.982 +03:00] [INF] [1] Emby.Server.Implementations.ApplicationHost: Loaded assembly "Jellyfin.Plugin.OpenSubtitles, Version=9.0.0.0, Culture=neutral, PublicKeyToken=null" from "/var/lib/jellyfin/plugins/Open Subtitles/Jellyfin.Plugin.OpenSubtitles.dll"
[2020-07-28 03:18:09.983 +03:00] [INF] [1] Emby.Server.Implementations.ApplicationHost: Loaded assembly "Jellyfin.Plugin.Fanart, Version=5.0.0.0, Culture=neutral, PublicKeyToken=null" from "/var/lib/jellyfin/plugins/Fanart/Jellyfin.Plugin.Fanart.dll"
[2020-07-28 03:18:09.995 +03:00] [INF] [1] Emby.Server.Implementations.ApplicationHost: Loaded assembly "Jellyfin.Plugin.PlaybackReporting, Version=7.0.0.0, Culture=neutral, PublicKeyToken=null" from "/var/lib/jellyfin/plugins/Playback Reporting/Jellyfin.Plugin.PlaybackReporting.dll"
[2020-07-28 03:18:09.996 +03:00] [INF] [1] Emby.Server.Implementations.ApplicationHost: Loaded assembly "Jellyfin.Plugin.TMDbBoxSets, Version=6.0.0.0, Culture=neutral, PublicKeyToken=null" from "/var/lib/jellyfin/plugins/TMDb Box Sets/Jellyfin.Plugin.TMDbBoxSets.dll"
[2020-07-28 03:18:09.997 +03:00] [INF] [1] Emby.Server.Implementations.ApplicationHost: Loaded assembly "Trakt, Version=10.0.0.0, Culture=neutral, PublicKeyToken=null" from "/var/lib/jellyfin/plugins/Trakt/Trakt.dll"
[2020-07-28 03:18:10.043 +03:00] [INF] [1] Emby.Server.Implementations.ApplicationHost: Loaded assembly "Jellyfin.Plugin.Reports, Version=8.0.0.0, Culture=neutral, PublicKeyToken=null" from "/var/lib/jellyfin/plugins/Reports/Jellyfin.Plugin.Reports.dll"
[2020-07-28 03:18:10.044 +03:00] [INF] [1] Emby.Server.Implementations.ApplicationHost: Loaded assembly "Jellyfin.Plugin.Bookshelf, Version=4.0.0.0, Culture=neutral, PublicKeyToken=null" from "/var/lib/jellyfin/plugins/Bookshelf/Jellyfin.Plugin.Bookshelf.dll"
[2020-07-28 03:18:10.045 +03:00] [INF] [1] Emby.Server.Implementations.ApplicationHost: Loaded assembly "LDAP-Auth, Version=9.0.0.0, Culture=neutral, PublicKeyToken=null" from "/var/lib/jellyfin/plugins/LDAP Authentication/LDAP-Auth.dll"
[2020-07-28 03:18:10.046 +03:00] [INF] [1] Emby.Server.Implementations.ApplicationHost: Loaded assembly "Novell.Directory.Ldap.NETStandard, Version=3.2.0.0, Culture=neutral, PublicKeyToken=null" from "/var/lib/jellyfin/plugins/LDAP Authentication/Novell.Directory.Ldap.NETStandard.dll"
[2020-07-28 03:18:11.517 +03:00] [WRN] [1] Microsoft.EntityFrameworkCore.Model.Validation: The entity type '"AccessSchedule"' is configured to use schema '"jellyfin"'. SQLite does not support schemas. This configuration will be ignored by the SQLite provider.
[2020-07-28 03:18:11.518 +03:00] [WRN] [1] Microsoft.EntityFrameworkCore.Model.Validation: The entity type '"ActivityLog"' is configured to use schema '"jellyfin"'. SQLite does not support schemas. This configuration will be ignored by the SQLite provider.
[2020-07-28 03:18:11.518 +03:00] [WRN] [1] Microsoft.EntityFrameworkCore.Model.Validation: The entity type '"ImageInfo"' is configured to use schema '"jellyfin"'. SQLite does not support schemas. This configuration will be ignored by the SQLite provider.
[2020-07-28 03:18:11.518 +03:00] [WRN] [1] Microsoft.EntityFrameworkCore.Model.Validation: The entity type '"Permission"' is configured to use schema '"jellyfin"'. SQLite does not support schemas. This configuration will be ignored by the SQLite provider.
[2020-07-28 03:18:11.518 +03:00] [WRN] [1] Microsoft.EntityFrameworkCore.Model.Validation: The entity type '"Preference"' is configured to use schema '"jellyfin"'. SQLite does not support schemas. This configuration will be ignored by the SQLite provider.
[2020-07-28 03:18:11.518 +03:00] [WRN] [1] Microsoft.EntityFrameworkCore.Model.Validation: The entity type '"User"' is configured to use schema '"jellyfin"'. SQLite does not support schemas. This configuration will be ignored by the SQLite provider.
[2020-07-28 03:18:27.619 +03:00] [INF] [1] Main: Kestrel listening on all interfaces
[2020-07-28 03:18:27.909 +03:00] [INF] [1] Emby.Server.Implementations.ApplicationHost: Running startup tasks
[2020-07-28 03:18:27.910 +03:00] [INF] [1] Jellyfin.Plugin.PlaybackReporting.TaskCleanDb: TaskCleanDb Loaded
[2020-07-28 03:18:27.912 +03:00] [INF] [1] Jellyfin.Plugin.PlaybackReporting.TaskRunBackup: TaskRunBackup Loaded
[2020-07-28 03:18:27.956 +03:00] [INF] [1] Emby.Server.Implementations.ScheduledTasks.TaskManager: Daily trigger for "Playback Reporting Trim Db" set to fire at 07/29/2020 00:00, which is 20:41:32.0434778 from now.
[2020-07-28 03:18:27.961 +03:00] [INF] [1] Emby.Server.Implementations.ScheduledTasks.TaskManager: Daily trigger for "Extract Chapter Images" set to fire at 07/29/2020 02:00, which is 22:41:32.0383726 from now.
[2020-07-28 03:18:28.955 +03:00] [INF] [1] MediaBrowser.MediaEncoding.Encoder.MediaEncoder: Found ffmpeg version "4.3.1"
[2020-07-28 03:18:28.997 +03:00] [INF] [1] MediaBrowser.MediaEncoding.Encoder.MediaEncoder: Available "decoders": ["h264", "h264_qsv", "h264_cuvid", "hevc", "hevc_qsv", "hevc_cuvid", "mpeg2video", "mpeg2_qsv", "mpeg2_cuvid", "mpeg4", "mpeg4_cuvid", "msmpeg4", "vc1_qsv", "vc1_cuvid", "vp8_cuvid", "vp8_qsv", "vp9_cuvid", "vp9_qsv", "aac", "ac3", "mp3"]
[2020-07-28 03:18:29.031 +03:00] [INF] [1] MediaBrowser.MediaEncoding.Encoder.MediaEncoder: Available "encoders": ["libx264", "h264_nvenc", "h264_omx", "h264_qsv", "h264_v4l2m2m", "h264_vaapi", "libx265", "hevc_nvenc", "hevc_qsv", "hevc_vaapi", "mpeg4", "msmpeg4", "libvpx", "libvpx-vp9", "aac", "ac3", "libmp3lame", "libopus", "libvorbis", "srt"]
[2020-07-28 03:18:29.064 +03:00] [INF] [1] MediaBrowser.MediaEncoding.Encoder.MediaEncoder: Available hwaccel types: ["vdpau", "cuda", "vaapi", "qsv", "drm"]
[2020-07-28 03:18:29.064 +03:00] [INF] [1] MediaBrowser.MediaEncoding.Encoder.MediaEncoder: FFmpeg: Custom: "/usr/bin/ffmpeg"
[2020-07-28 03:18:29.065 +03:00] [INF] [1] Emby.Server.Implementations.ApplicationHost: ServerId: "020f206a01ab45648c07c02afc47349e"
[2020-07-28 03:18:29.486 +03:00] [INF] [15] Emby.Server.Implementations.ApplicationHost: Executed all pre-startup entry points in 0:00:00.4094019
[2020-07-28 03:18:29.486 +03:00] [INF] [15] Emby.Server.Implementations.ApplicationHost: Core startup complete
[2020-07-28 03:18:29.486 +03:00] [INF] [15] Jellyfin.Plugin.PlaybackReporting.EventMonitorEntryPoint: EventMonitorEntryPoint Running
[2020-07-28 03:18:29.495 +03:00] [INF] [15] Jellyfin.Plugin.PlaybackReporting.Data.ActivityRepository: Sqlite version: 3.31.1
[2020-07-28 03:18:29.496 +03:00] [INF] [15] Jellyfin.Plugin.PlaybackReporting.Data.ActivityRepository: Sqlite compiler options: COMPILER=gcc-5.4.0 20160609,DEFAULT_FOREIGN_KEYS,ENABLE_COLUMN_METADATA,ENABLE_FTS3_PARENTHESIS,ENABLE_FTS4,ENABLE_FTS5,ENABLE_JSON1,ENABLE_RTREE,THREADSAFE=1
[2020-07-28 03:18:29.499 +03:00] [INF] [15] Jellyfin.Plugin.PlaybackReporting.Data.ActivityRepository: Default journal_mode for "/var/lib/jellyfin/data/playback_reporting.db" is "delete"
[2020-07-28 03:18:29.499 +03:00] [INF] [15] Jellyfin.Plugin.PlaybackReporting.Data.ActivityRepository: Initialize PlaybackActivity Repository
[2020-07-28 03:18:29.504 +03:00] [INF] [15] Jellyfin.Plugin.PlaybackReporting.Data.ActivityRepository: PlaybackActivity table schema OK
[2020-07-28 03:18:29.504 +03:00] [INF] [15] Jellyfin.Plugin.PlaybackReporting.Data.ActivityRepository: Expected : "datecreated:datetime|userid:text|itemid:text|itemtype:text|itemname:text|playbackmethod:text|clientname:text|devicename:text|playduration:int"
[2020-07-28 03:18:29.504 +03:00] [INF] [15] Jellyfin.Plugin.PlaybackReporting.Data.ActivityRepository: Received : "datecreated:datetime|userid:text|itemid:text|itemtype:text|itemname:text|playbackmethod:text|clientname:text|devicename:text|playduration:int"
[2020-07-28 03:18:29.742 +03:00] [INF] [15] Emby.Server.Implementations.ApplicationHost: Executed all post-startup entry points in 0:00:00.2562449
[2020-07-28 03:18:29.743 +03:00] [INF] [15] Main: Startup complete 0:00:21.7861418
[2020-07-28 03:18:29.835 +03:00] [INF] [6] Emby.Server.Implementations.IO.LibraryMonitor: Watching directory /mnt/Movies
[2020-07-28 03:18:29.867 +03:00] [INF] [4] Emby.Server.Implementations.IO.LibraryMonitor: Watching directory /mnt/Photo
[2020-07-28 03:18:47.582 +03:00] [INF] [35] Emby.Server.Implementations.HttpServer.HttpListenerHost: WS "::ffff:127.0.0.1" requestseconds
[2020-07-28 03:19:06.186 +03:00] [INF] [35] Emby.Server.Implementations.ScheduledTasks.TaskManager: ExecuteQueuedTasks
[2020-07-28 03:19:27.967 +03:00] [INF] [10] Emby.Server.Implementations.ScheduledTasks.TaskManager: "IntervalTrigger" fired for task: "Scan Media Library"
[2020-07-28 03:19:27.968 +03:00] [INF] [10] Emby.Server.Implementations.ScheduledTasks.TaskManager: Queueing task "RefreshMediaLibraryTask"
[2020-07-28 03:19:27.968 +03:00] [INF] [35] Emby.Server.Implementations.ScheduledTasks.TaskManager: Executing "Scan Media Library"
[2020-07-28 03:19:27.994 +03:00] [INF] [35] Emby.Server.Implementations.IO.LibraryMonitor: Stopping directory watching for path "/mnt/Photo"
[2020-07-28 03:19:27.996 +03:00] [INF] [35] Emby.Server.Implementations.IO.LibraryMonitor: Stopping directory watching for path "/mnt/Movies"
[2020-07-28 03:19:28.002 +03:00] [INF] [35] Emby.Server.Implementations.Library.LibraryManager: Validating media library
[2020-07-28 03:19:28.986 +03:00] [INF] [35] MediaBrowser.Providers.Manager.ProviderManager: OnRefreshStart "13f2c14a8032762b207f77c64f6985b6"
[2020-07-28 03:19:28.987 +03:00] [INF] [35] MediaBrowser.Providers.Manager.ProviderManager: OnRefreshComplete "13f2c14a8032762b207f77c64f6985b6"
[2020-07-28 03:19:28.987 +03:00] [INF] [35] MediaBrowser.Providers.Manager.ProviderManager: OnRefreshStart "9cea7bbc58ea2060c485e628675d9581"
[2020-07-28 03:19:28.989 +03:00] [INF] [35] MediaBrowser.Providers.Manager.ProviderManager: OnRefreshComplete "9cea7bbc58ea2060c485e628675d9581"
[...]
[2020-07-28 03:20:22.622 +03:00] [ERR] [22] Emby.Server.Implementations.Library.LibraryManager: Cannnot get image dimensions for "/mnt/Music/Song/Folder.jpg"
Non-success codec result: Unimplemented
Jellyfin.Drawing.Skia.SkiaCodecException: Exception of type 'Jellyfin.Drawing.Skia.SkiaCodecException' was thrown.
   at Jellyfin.Drawing.Skia.SkiaHelper.EnsureSuccess(SKCodecResult result) in /mnt/AUR/jellyfin/src/jellyfin-10.6.0/Jellyfin.Drawing.Skia/SkiaHelper.cs:line 21
   at Jellyfin.Drawing.Skia.SkiaEncoder.GetImageSize(String path) in /mnt/AUR/jellyfin/src/jellyfin-10.6.0/Jellyfin.Drawing.Skia/SkiaEncoder.cs:line 223
   at Emby.Drawing.ImageProcessor.GetImageDimensions(String path) in /mnt/AUR/jellyfin/src/jellyfin-10.6.0/Emby.Drawing/ImageProcessor.cs:line 316
   at Emby.Drawing.ImageProcessor.GetImageDimensions(BaseItem item, ItemImageInfo info) in /mnt/AUR/jellyfin/src/jellyfin-10.6.0/Emby.Drawing/ImageProcessor.cs:line 307
   at Emby.Server.Implementations.Library.LibraryManager.UpdateImages(BaseItem item, Boolean forceUpdate) in /mnt/AUR/jellyfin/src/jellyfin-10.6.0/Emby.Server.Implementations/Library/LibraryManager.cs:line 1909
[2020-07-28 03:20:22.641 +03:00] [ERR] [22] Emby.Server.Implementations.Library.LibraryManager: Cannnot get image dimensions for "/var/lib/jellyfin/metadata/library/a1/a102435cd82cc538d0a4857d7f8992a5/folder.png"
Non-success codec result: InvalidInput
Jellyfin.Drawing.Skia.SkiaCodecException: Exception of type 'Jellyfin.Drawing.Skia.SkiaCodecException' was thrown.
   at Jellyfin.Drawing.Skia.SkiaHelper.EnsureSuccess(SKCodecResult result) in /mnt/AUR/jellyfin/src/jellyfin-10.6.0/Jellyfin.Drawing.Skia/SkiaHelper.cs:line 21
   at Jellyfin.Drawing.Skia.SkiaEncoder.GetImageSize(String path) in /mnt/AUR/jellyfin/src/jellyfin-10.6.0/Jellyfin.Drawing.Skia/SkiaEncoder.cs:line 223
   at Emby.Drawing.ImageProcessor.GetImageDimensions(String path) in /mnt/AUR/jellyfin/src/jellyfin-10.6.0/Emby.Drawing/ImageProcessor.cs:line 316
   at Emby.Drawing.ImageProcessor.GetImageDimensions(BaseItem item, ItemImageInfo info) in /mnt/AUR/jellyfin/src/jellyfin-10.6.0/Emby.Drawing/ImageProcessor.cs:line 307
   at Emby.Server.Implementations.Library.LibraryManager.UpdateImages(BaseItem item, Boolean forceUpdate) in /mnt/AUR/jellyfin/src/jellyfin-10.6.0/Emby.Server.Implementations/Library/LibraryManager.cs:line 1909
[2020-07-28 03:20:22.716 +03:00] [ERR] [22] Emby.Server.Implementations.Library.LibraryManager: Cannnot get image dimensions for "/var/lib/jellyfin/metadata/library/59/597a00c86333c1869492833322ee4ae9/folder.png"
Non-success codec result: InvalidInput
Jellyfin.Drawing.Skia.SkiaCodecException: Exception of type 'Jellyfin.Drawing.Skia.SkiaCodecException' was thrown.
   at Jellyfin.Drawing.Skia.SkiaHelper.EnsureSuccess(SKCodecResult result) in /mnt/AUR/jellyfin/src/jellyfin-10.6.0/Jellyfin.Drawing.Skia/SkiaHelper.cs:line 21
   at Jellyfin.Drawing.Skia.SkiaEncoder.GetImageSize(String path) in /mnt/AUR/jellyfin/src/jellyfin-10.6.0/Jellyfin.Drawing.Skia/SkiaEncoder.cs:line 223
   at Emby.Drawing.ImageProcessor.GetImageDimensions(String path) in /mnt/AUR/jellyfin/src/jellyfin-10.6.0/Emby.Drawing/ImageProcessor.cs:line 316
   at Emby.Drawing.ImageProcessor.GetImageDimensions(BaseItem item, ItemImageInfo info) in /mnt/AUR/jellyfin/src/jellyfin-10.6.0/Emby.Drawing/ImageProcessor.cs:line 307
   at Emby.Server.Implementations.Library.LibraryManager.UpdateImages(BaseItem item, Boolean forceUpdate) in /mnt/AUR/jellyfin/src/jellyfin-10.6.0/Emby.Server.Implementations/Library/LibraryManager.cs:line 1909
[2020-07-28 03:20:22.778 +03:00] [ERR] [22] Emby.Server.Implementations.Library.LibraryManager: Cannnot get image dimensions for "/mnt/Photo/P123456.ORF"
Non-success codec result: Unimplemented
Jellyfin.Drawing.Skia.SkiaCodecException: Exception of type 'Jellyfin.Drawing.Skia.SkiaCodecException' was thrown.
   at Jellyfin.Drawing.Skia.SkiaHelper.EnsureSuccess(SKCodecResult result) in /mnt/AUR/jellyfin/src/jellyfin-10.6.0/Jellyfin.Drawing.Skia/SkiaHelper.cs:line 21
   at Jellyfin.Drawing.Skia.SkiaEncoder.GetImageSize(String path) in /mnt/AUR/jellyfin/src/jellyfin-10.6.0/Jellyfin.Drawing.Skia/SkiaEncoder.cs:line 223
   at Emby.Drawing.ImageProcessor.GetImageDimensions(String path) in /mnt/AUR/jellyfin/src/jellyfin-10.6.0/Emby.Drawing/ImageProcessor.cs:line 316
   at Emby.Drawing.ImageProcessor.GetImageDimensions(BaseItem item, ItemImageInfo info) in /mnt/AUR/jellyfin/src/jellyfin-10.6.0/Emby.Drawing/ImageProcessor.cs:line 307
   at Emby.Server.Implementations.Library.LibraryManager.UpdateImages(BaseItem item, Boolean forceUpdate) in /mnt/AUR/jellyfin/src/jellyfin-10.6.0/Emby.Server.Implementations/Library/LibraryManager.cs:line 1909
[...]
[2020-07-28 03:21:31.335 +03:00] [INF] [35] MediaBrowser.Providers.Manager.ProviderManager: OnRefreshStart "e087774cae717451078ba4ef15e2511a"
[2020-07-28 03:21:31.372 +03:00] [INF] [35] MediaBrowser.Providers.Manager.ProviderManager: OnRefreshComplete "e087774cae717451078ba4ef15e2511a"
[2020-07-28 03:21:31.372 +03:00] [INF] [35] MediaBrowser.Providers.Manager.ProviderManager: OnRefreshStart "76f54896f364a586d9c072977d4a7c8c"

Screenshots

attels

@davispuh davispuh added the bug Something isn't working label Jul 28, 2020
@crobibero
Copy link
Member

It's likely not stuck, upgrading to 10.6 causes a blurhash to be generated for every image. After the initial scan on 10.6 future scans should be normal speed.

@davispuh
Copy link
Author

Looks like you might be right, but something is terribly wrong with performance. How it could be this slow...

In log look at time gap between entries.

[2020-07-28 17:36:40.277 +03:00] [INF] [31] MediaBrowser.Providers.Manager.ProviderManager: OnRefreshStart "4c179b8df38cd2c892c8735a8d2e2eb0"
[2020-07-28 19:56:41.274 +03:00] [INF] [31] MediaBrowser.Providers.Manager.ProviderManager: OnRefreshComplete "4c179b8df38cd2c892c8735a8d2e2eb0"
[2020-07-28 19:56:41.275 +03:00] [INF] [31] MediaBrowser.Providers.Manager.ProviderManager: OnRefreshStart "5ba06af9726f0c43f748ff3a86516a51"
[2020-07-28 20:14:56.914 +03:00] [INF] [31] MediaBrowser.Providers.Manager.ProviderManager: OnRefreshComplete "5ba06af9726f0c43f748ff3a86516a51"
[2020-07-28 20:14:56.914 +03:00] [INF] [31] MediaBrowser.Providers.Manager.ProviderManager: OnRefreshStart "81aff09733080966db5f8d5426b4f046"
[2020-07-28 20:56:36.017 +03:00] [INF] [31] MediaBrowser.Providers.Manager.ProviderManager: OnRefreshComplete "81aff09733080966db5f8d5426b4f046"
[2020-07-28 20:56:36.017 +03:00] [INF] [31] MediaBrowser.Providers.Manager.ProviderManager: OnRefreshStart "57ebe333698cdbdb73fca54431a2dc8d"

I've been running it on 3.4GHz 24-Core CPU with 32GB RAM for 7 hours and the progress haven't increased even by 0.01%

@doughnet
Copy link

Same issue I am having. I have a fresh installation (first impression of Jellyfin isn't that great).

I have only 4 movies in a folder and it has not completed scanning of 1 file.

@geek-baba
Copy link

I have 15K Movies and 800 TV Shows and its taking 5 to 7 days to scan new library, its running on 20 Cores Xeon server with 388 GB RAM with P5000 Graphics Card. Something needs to be done for future release to address this issue...

System:    Distro: Ubuntu 20.04.1 LTS (Focal Fossa) Kernel: 5.4.0-42-generic x86_64 bits: 64 Console: tty 0            
Machine:   Type: Server System: Dell product: Precision 7920 Rack           
CPU:       2x 10-Core: Intel Xeon Silver 4114 type: MT MCP SMP speed: 800 MHz min/max: 800/3000 MHz 
Memory:    RAM: total: 376.39 GiB used: 11.85 GiB (3.1%)
Graphics:  Device-1: NVIDIA GP104GL [Quadro P5000] driver: nvidia v: 450.57 
           Display: server: X.org 1.20.8 driver: modesetting,nvidia tty: 204x61           
Network:   Device-1: Intel Ethernet 10-Gigabit X540-AT2 driver: ixgbe 
           Device-2: Intel Ethernet 10-Gigabit X540-AT2 driver: ixgbe            
Drives:    Local Storage: total: 238.47 GiB used: 260.60 GiB (109.3%) 
           ID-1: /dev/nvme0n1 vendor: Sabrent model: Rocket Q size: 931.51 GiB 
           ID-2: /dev/nvme1n1 vendor: Samsung model: SSD 950 PRO 256GB size: 238.47 GiB

@ghost
Copy link

ghost commented Aug 4, 2020

It's likely not stuck, upgrading to 10.6 causes a blurhash to be generated for every image. After the initial scan on 10.6 future scans should be normal speed.

@crobibero This unfortunately doesn't appear to be the case. The first library scan after 10.6 took almost 10 hours to complete, but instead of subsequent scans performing at pre-10.6 speeds, a scan of my movie library, for example, with only one new movie added takes several hours to complete where previously it would finish in under a minute.

@cvium
Copy link
Member

cvium commented Aug 4, 2020

Is this still an issue in 10.6.2?

@ghost
Copy link

ghost commented Aug 4, 2020

@cvium Yes.

@cvium
Copy link
Member

cvium commented Aug 4, 2020

Any improvements? Scanning is pretty fast for me, but I only have 400 movies and 5000 episodes.

@ghost
Copy link

ghost commented Aug 5, 2020

@cvium I started a new library scan yesterday and unfortunately it still takes several hours to complete each time.

@davispuh davispuh changed the title Scan Media Library is stuck Scanning Media Library is incredibly slow Aug 5, 2020
@davispuh
Copy link
Author

davispuh commented Aug 5, 2020

Well the main issue I submitted was about library scanning being stuck. It didn't advance not even by 0.1% in several days. But now I updated to 10.6.2 and my library scanning have been completed so it's not stuck thus I just renamed this issue.

I don't know if my scanning completed because of update to 10.6.2 or because it's been more than a week of library scanning :D

@ghost
Copy link

ghost commented Aug 5, 2020

@davispuh Can you start a new library scan and see how long it takes to complete?

@davispuh
Copy link
Author

davispuh commented Aug 5, 2020

Well after first scan has been completed rescanning isn't that bad. Takes 21mins. So I guess first scan is just super slow or after update from 10.5 to 10.6

attels

@bugfixin
Copy link
Contributor

bugfixin commented Aug 6, 2020

I'm curious if this is related to an issue I found - for those with slow scans, do you have a lot of movie files located within the same directory? (i.e. each movie is not in its own directory)?

@doughnet
Copy link

doughnet commented Aug 6, 2020

I put in 5 movies and tried a fresh install. After 12 hours I cancelled it and deleted the software.

@davispuh
Copy link
Author

davispuh commented Aug 6, 2020

I'm curious if this is related to an issue I found - for those with slow scans, do you have a lot of movie files located within the same directory? (i.e. each movie is not in its own directory)?

Not movies, but I've photo library where couple of hundred photos in each folder.

@ghost
Copy link

ghost commented Aug 6, 2020

I'm curious if this is related to an issue I found - for those with slow scans, do you have a lot of movie files located within the same directory? (i.e. each movie is not in its own directory)?

@bugfixin No, each movie has its own folder.

@cvium
Copy link
Member

cvium commented Aug 6, 2020

I put in 5 movies and tried a fresh install. After 12 hours I cancelled it and deleted the software.

@doughnet You did a fresh install and added a library with only 5 movies and it didn't complete the scan within the 12 hours?

@doughnet
Copy link

doughnet commented Aug 6, 2020

I put in 5 movies and tried a fresh install. After 12 hours I cancelled it and deleted the software.

@doughnet You did a fresh install and added a library with only 5 movies and it didn't complete the scan within the 12 hours?

Correct. I've used Plex since it's beta years. But I dislike their limitations on how many sharing users can be done so looking for an alternative.

I did a fresh install at home on a fresh OS (Ubuntu 20.04 LXC Proxmox) and am passing through my graphics card being shared by all my LXC. Did a fresh install and made a local (not even Shared network) folder with 5 movies that were x265 codec. I let it run over night and later in the day I killed the VM since it had not progressed any percentage.

Try adding a new library with 1 movie and see how long it takes.

@bugfixin
Copy link
Contributor

bugfixin commented Aug 6, 2020

@doughnet it sounds like you're running into the same issue found here: #3558 (comment) - are you able/willing to build jellyfin yourself for testing the solution?

@doughnet
Copy link

doughnet commented Aug 6, 2020

@doughnet it sounds like you're running into the same issue found here: #3558 (comment) - are you able/willing to build jellyfin yourself for testing the solution?

doing a native build right now. i assume that is what you are requesting.

EDIT: Finished doing ./build.sh -t native -p ubuntu.amd64

now what to do?

@bugfixin
Copy link
Contributor

bugfixin commented Aug 7, 2020

You'll have to install it and run it, e.g. via apt install ./jellyfin-server_10.6.*.deb (after uninstalling the existing jellyfin-server) - though I'm not certain of the details for doing it on ubuntu specifically.

@doughnet
Copy link

doughnet commented Aug 7, 2020

I don't see a .deb rile after the build. There a specific location it's at after building?

@bugfixin
Copy link
Contributor

bugfixin commented Aug 7, 2020

It might be somewhere like ~/bin/ubuntu.amd64

@ghost
Copy link

ghost commented Aug 8, 2020

I've been keeping an eye on the time it takes for the periodic library scans to complete for the past few days and have observed that it has stayed completely consistent. The scheduled task runs at midnight every day and always takes 10 hours to complete with zero new media added inbetween scans. I've been using Jellyfin since March 2019 on the same hardware and never experienced library scans this long prior to upgrading to 10.6.0+.

@cvium
Copy link
Member

cvium commented Aug 8, 2020

@whalehub How did you install jf and what's the OS etc.?

@ghost
Copy link

ghost commented Aug 9, 2020

@cvium I'm running Jellyfin inside Docker on Debian 10 using the linuxserver.io image. Jellyfin is served behind Nginx.

@cvium
Copy link
Member

cvium commented Aug 9, 2020

@whalehub I am wondering if you're encountering the same issue as doughnet albeit in a smaller scale. Lsio uses our .deb file, which I suspect is built using an old SDK, where threads can deadlock.

@ghost
Copy link

ghost commented Aug 9, 2020

@cvium Should I give the official Jellyfin image a try?

Edit: I just tested the official Docker image and it suffers from the same issue.

@cvium
Copy link
Member

cvium commented Feb 19, 2021

This bug has been known for a while now, so it would be helpful if you would include version number, size of library, number of users etc.

If the slow scanning is related to users, then it should be fixed in 10.7 RC. If any of you would be willing to backup your 10.6 install and try out the RC release, it would be very helpful.

Some parts of the scanning has also been parallelized in 10.7 RC.

cc @whalehub @bugfixin @spn1025

@n-peugnet
Copy link

I had this problem with 10.6.4 and I could not wait any longer so I decided to install 10.7.0~RC3. The scan's and search's duration are back to normal and everything is snappier. I do not have any other issue with this release candidate by the way, it is perfect.

@cvium
Copy link
Member

cvium commented Feb 19, 2021

Based on #4364 (comment) I think it's safe to close this issue.

Let me know if it's still a problem in the RC.

@cvium cvium closed this as completed Feb 19, 2021
@deepzeafish
Copy link

I'm still experiencing this issue with 10.7.7.

I'm running jellyfin on a Raspberry Pi model 3B. It's a fresh setup, and I'm scanning a library of 168 movies.

The system does not show high cpu or network load. There are occasional 'bursts' of cpu load with 30%. Most of the time the system is just idling.

@meanOtaku
Copy link

The system does not show high cpu or network load. There are occasional 'bursts' of cpu load with 30%. Most of the time the system is just idling.
same

@nRaecheR
Copy link

nRaecheR commented Jan 17, 2022

Same problem with 10.8.0-RC from last week. The media scan takes 2 hours every day on 9:30 o'clock on my setup. During this time the inotify functionality will be disabled and new files won't show up in the library. Two threads of Jellyfin consumes two cores of the CPU for 100%.

3423515 <username>   20   0 8020M 2400M 20180 R 171.  7.6  4:56.74 ./jellyfin/jellyfin --datadir /config --cachedir /cache --ffmpeg /usr/lib/jellyfin-ffmpeg/ffmpeg
   9913 <username>  20   0 8020M 2400M 20180 S 85.7  7.6 21h33:57 ./jellyfin/jellyfin --datadir /config --cachedir /cache --ffmpeg /usr/lib/jellyfin-ffmpeg/ffmpeg

and the last line in the log during this time is

[2022-01-17 09:28:52.012 +01:00] [INF] [145] Emby.Server.Implementations.Library.LibraryManager: Validating media library
...
[2022-01-17 11:01:37.340 +01:00] [INF] [107] Emby.Server.Implementations.ScheduledTasks.TaskManager: "Scan Media Library" Completed after 92 minute(s) and 45 seconds
[2022-01-17 11:01:37.340 +01:00] [INF] [107] Emby.Server.Implementations.ScheduledTasks.TaskManager: ExecuteQueuedTasks
[2022-01-17 11:01:37.486 +01:00] [INF] [67] Emby.Server.Implementations.IO.LibraryMonitor: Watching directory "/media2/<directory>"
[2022-01-17 11:01:37.838 +01:00] [INF] [165] Emby.Server.Implementations.IO.LibraryMonitor: Watching directory "/media1"
[2022-01-17 11:33:03.603 +01:00] [INF] [35] Emby.Server.Implementations.ScheduledTasks.TaskManager: "IntervalTrigger" fired for task: "Download missing subtitles"
[2022-01-17 11:33:03.603 +01:00] [INF] [35] Emby.Server.Implementations.ScheduledTasks.TaskManager: Queuing task "SubtitleScheduledTask"
[2022-01-17 11:33:03.603 +01:00] [INF] [196] Emby.Server.Implementations.ScheduledTasks.TaskManager: Executing "Download missing subtitles"
[2022-01-17 11:33:03.603 +01:00] [INF] [196] Emby.Server.Implementations.ScheduledTasks.TaskManager: "Download missing subtitles" Completed after 0 minute(s) and 0 seconds
[2022-01-17 11:33:03.604 +01:00] [INF] [196] Emby.Server.Implementations.ScheduledTasks.TaskManager: ExecuteQueuedTasks
[2022-01-17 11:33:03.838 +01:00] [INF] [35] Emby.Server.Implementations.ScheduledTasks.TaskManager: "IntervalTrigger" fired for task: "Clean Log Directory"
[2022-01-17 11:33:03.838 +01:00] [INF] [35] Emby.Server.Implementations.ScheduledTasks.TaskManager: Queuing task "DeleteLogFileTask"
[2022-01-17 11:33:03.838 +01:00] [INF] [196] Emby.Server.Implementations.ScheduledTasks.TaskManager: Executing "Clean Log Directory"
[2022-01-17 11:33:03.840 +01:00] [INF] [196] Emby.Server.Implementations.ScheduledTasks.TaskManager: "Clean Log Directory" Completed after 0 minute(s) and 0 seconds
[2022-01-17 11:33:03.840 +01:00] [INF] [196] Emby.Server.Implementations.ScheduledTasks.TaskManager: ExecuteQueuedTasks
[2022-01-17 11:33:04.602 +01:00] [INF] [196] Emby.Server.Implementations.ScheduledTasks.TaskManager: "IntervalTrigger" fired for task: "TasksRefreshChannels"
[2022-01-17 11:33:04.602 +01:00] [INF] [196] Emby.Server.Implementations.ScheduledTasks.TaskManager: Queuing task "RefreshChannelsScheduledTask"
[2022-01-17 11:33:04.602 +01:00] [INF] [196] Emby.Server.Implementations.ScheduledTasks.TaskManager: Executing "TasksRefreshChannels"
[2022-01-17 11:33:04.603 +01:00] [INF] [196] Emby.Server.Implementations.ScheduledTasks.TaskManager: "TasksRefreshChannels" Completed after 0 minute(s) and 0 seconds
[2022-01-17 11:33:04.603 +01:00] [INF] [196] Emby.Server.Implementations.ScheduledTasks.TaskManager: ExecuteQueuedTasks
[2022-01-17 11:33:10.622 +01:00] [INF] [196] Emby.Server.Implementations.ScheduledTasks.TaskManager: "IntervalTrigger" fired for task: "Clean Transcode Directory"
[2022-01-17 11:33:10.622 +01:00] [INF] [196] Emby.Server.Implementations.ScheduledTasks.TaskManager: Queuing task "DeleteTranscodeFileTask"
[2022-01-17 11:33:10.622 +01:00] [INF] [197] Emby.Server.Implementations.ScheduledTasks.TaskManager: Executing "Clean Transcode Directory"
[2022-01-17 11:33:10.628 +01:00] [INF] [197] Emby.Server.Implementations.ScheduledTasks.TaskManager: "Clean Transcode Directory" Completed after 0 minute(s) and 0 seconds
[2022-01-17 11:33:10.628 +01:00] [INF] [197] Emby.Server.Implementations.ScheduledTasks.TaskManager: ExecuteQueuedTasks
[2022-01-17 11:33:14.223 +01:00] [INF] [197] Emby.Server.Implementations.ScheduledTasks.TaskManager: "IntervalTrigger" fired for task: "Clean Cache Directory"
[2022-01-17 11:33:14.223 +01:00] [INF] [197] Emby.Server.Implementations.ScheduledTasks.TaskManager: Queuing task "DeleteCacheFileTask"
[2022-01-17 11:33:14.223 +01:00] [INF] [197] Emby.Server.Implementations.ScheduledTasks.TaskManager: Executing "Clean Cache Directory"
[2022-01-17 11:33:14.651 +01:00] [INF] [197] Emby.Server.Implementations.ScheduledTasks.TaskManager: "Clean Cache Directory" Completed after 0 minute(s) and 0 seconds
[2022-01-17 11:33:14.651 +01:00] [INF] [197] Emby.Server.Implementations.ScheduledTasks.TaskManager: ExecuteQueuedTasks

This is all on a AMD Ryzen 5 PRO 4650G 6-Core Processor, not a Raspberry Pi or any other underpowered device.

@VigibotDev
Copy link

I have a dedicated Jellyfin server on native Debian 11 (no VM and no docker) with i9 9900K (8 cores 16 thread) 64GB of RAM all is very fast but Jellyfin front-end become unusable slow forever when I add large number of TV Show. I must restart the service AND launch a full scan to repair... There is a bug for sure. Software become slow without any ressources usage !

@exaveal
Copy link

exaveal commented May 15, 2022

Same problem here. I'm new to Jellyfin and installed version 10.7.7. Library Scan took 2 days for 917 Movies, 7000 Songs, 2125 Episodes of Series.
When adding an album (max. 20 Songs) to the music library, Jellyfin cannot be used for around 30 minutes. The player just shows the loading circle.

That's really frustrating. How can this be "closed"?

@voarsh2
Copy link

voarsh2 commented Oct 10, 2022

Hmm.
Every time I scan my library after a short while playback is impossible until the scan is finished, or until I cancel/restart Jellyfin....

@xenago
Copy link

xenago commented Dec 27, 2022

Why has this issue been closed? Scanning renders jellyfin completely unusable until it has completed, even on NVME/optane. How is that acceptable?

@cvium
Copy link
Member

cvium commented Dec 27, 2022

#3722 (comment)

@xenago
Copy link

xenago commented Dec 27, 2022

? It is stated above that users should advise if this is a problem... it is

#3722 (comment)

#3722 (comment)

#3722 (comment)

#3722 (comment)

#3722 (comment)

@cvium
Copy link
Member

cvium commented Dec 27, 2022

This issue is over 2 years old. We have made many changes since. It does not mean that all issues are resolved, but the original issue was reported to be solved. Hence, it was closed.

@ecwilsonaz
Copy link

ecwilsonaz commented Dec 30, 2022

It doesn't make sense to close an issue that is still so severe -- my first scan of a 12TB Kodi library is almost at 2 days, and I see countless mentions across forums about this still being a problem. I'm not an engineer. But perhaps someone could find a way to pinpoint the biggest bottlenecks in the current scan process so that progress can be made. Based on what I've read elsewhere (like this reddit post from 3 months ago), I gather that one contributing factor could be:

  • During scan it reads the media files even with all middlewares and options disabled at library creation.
  • [Whereas] in Plex it's possible to tell the Scanner to not generate any kind of thumbnails and also don't read file's audio streams. In Plex audio stream check happens when the opening the file.

Another idea I've seen posted around are that perhaps an await call is hard-blocking the whole server. This would make some sense given that the CPU/RAM usage are low throughout:

I just looked through the code. async/await don't actually do what people think they do and if you're not paying attention while using them there's a bunch of pitfalls that actually block the whole process.

As for why that would make the UI slow:

However that's just masking the symptoms: there's contention between the media scanning and the webserver. Making media scanning faster doesn't fix the problem, it just makes it less teeth-grindingly painful.

Edit: FYI to anyone reading this, I see there's a duplicate issue here that's still open: #2600 If you combine the comment count from both issues, this is by far the most commented issue outstanding and one that likely sends many first-timers to Plex.

@davispuh
Copy link
Author

When I opened this issue then it was Scanning Media Library is incredibly slow and even today, that's still the case so I don't consider this issue to be fixed. Yes some things were fixed and it was improved, yes, it is faster than it was then but it's still not really acceptable. It's probably many different things together causing it being slow rather than single thing that can be fixed alone.

Also it's that I stopped caring and I think that's the case for most people, we have just accepted that's how it is and how it's been for many years. Basically someone needs to put some serious time into looking into why it's so slow and I don't think anyone has really worked on it. And it's not just about first scan either, even next scans seems to be quite slow and it's making whole Web UI slow whenever it's scanning.

@VigibotDev
Copy link

+1 for "And it's not just about first scan either, even next scans seems to be quite slow and it's making whole Web UI slow whenever it's scanning." the webserver process should not be slowed down by another task, especially since the processor load never exceeds a few percent on a core i9.

@bill-mcgonigle
Copy link

How can I increase logging to get helpful information about what's going on with the library scan? 10.9.0 daily on Debian Bullseye.

From the existing log, I see ffprobe doing bursts of about 20 files every 3-4 hours. Each ffprobe takes approximately 0.09 seconds, and the jellyfin processes are using close to 0% CPU and disk I/O is trivial most of the time. If I strace the processes/threads they're mostly all calling futex() waiting on locks from each other, checking the dotnet CLR pipes in /tmp somewhat often.

Once in a while something touches library.db but it's usually something like an hour between writes.

Seems like something is deadlocked and something is waking it up on occasion, but certainly I don't know this codebase well enough to guess. At the current rate the music library will be done scanning in about six weeks.

As far as the hardware, if I use the same command to probe the music library, it finishes in under ten minutes:

# time find /storage/music -type f -exec /usr/lib/jellyfin-ffmpeg/ffprobe -analyzeduration 200M -i file:"{}" -threads 0 -v warning -print_format json -show_streams -show_format > /dev/null 2>&1  \; 

real    9m0.475s
user    1m13.792s
sys     0m54.103s

@nikolajsheller
Copy link

nikolajsheller commented May 25, 2023

The media scanning and webserver contention is still at issue, and becomes a showstopper on large libraries.
The webserver becomes unusable when scanning is running for extended periods. Relevant on 10.8.10.

This issue really shouldn't be marked as closed.

@VigibotDev
Copy link

Slow on scanning / and on dashboard even on a core i9 with a lot unused core !!!!! a process management problem...

@nikolajsheller
Copy link

I'm digging into the code to see if I can get an idea about where the problem is.

It is not: CPU, IO or network bound.

There seems to be some sort of contention between the web-server thread that generates the HTML for the browser and the media scanner (thread? async?). it is not yet clear to me if it is a shared database or data structure or where contention is arising.

@VigibotDev
Copy link

VigibotDev commented May 30, 2023

When I delete a huge music library, when it go to 99.8% and log activity slow down for the same work,
[INF] Removing item, Type: "MusicArtist", Name: "...", Path: "/....

I get very slow GUI responses,

I tryed (system.xml) :

  <LibraryScanFanoutConcurrency>4</LibraryScanFanoutConcurrency>
  <LibraryMetadataRefreshConcurrency>4</LibraryMetadataRefreshConcurrency>

(because it run on a 8 core / 16 threads)
with a bit better GUI performance but I'm not sure if it's placebo...
there is a strange bottleneck somewhere... CPU never jump up... This is a slow software bottleneck do not consume CPU :(

@VigibotDev
Copy link

VigibotDev commented May 30, 2023

I try also :

 <LibraryScanFanoutConcurrency>64</LibraryScanFanoutConcurrency>
 <LibraryMetadataRefreshConcurrency>64</LibraryMetadataRefreshConcurrency>

(to make 4 thread for 1 logical core)

Scan mush faster and I get a better CPU usage, and same GUI response...
More thread look better for powerful CPU...

I make more try when my huge music library is not on the jellyfin database anymore. Because delete is very slow.

@VigibotDev
Copy link

VigibotDev commented May 31, 2023

To remove about 600000 music file on a powerfull i9 server where library.db is on a fast SSD ; I need to temporally re-mount the filesystem with write barrier=0 (unsafe) to get a huge bump in performance. the library.db size is 2.5GB with music and down to 1GB without music. I remove barrier=0 when scan finished. Without this trick the web interface get unusable for few days !
Changing LibraryScanFanoutConcurrency / LibraryMetadataRefreshConcurrency don't help I keep 0 default (ajust to nbCores)

@GouZi2019

This comment was marked as abuse.

@xenago
Copy link

xenago commented Feb 2, 2024

Are there any maintainers available to reopen this issue? It should not be closed as this remains a major problem (and likely the main showstopper for new users).

See also
#2600

@felix920506
Copy link
Member

Hi @xenago , please explain how this one is not a duplicate of #2600

@xenago
Copy link

xenago commented Feb 2, 2024

@felix920506 Is the other issue intended as the place for all discussion about slow scanning problems? My understanding is that #2600 ("Very slow initial Library scan") is specifically about the first/setup scan being extremely slow, but this issue is about usually slow scan operations on existing libraries - e.g. the last few comments just above mention slowdown when items were deleted from a library

@felix920506
Copy link
Member

@xenago after confirming with the devs, nothing different happens with the initial scan and subsequent scans. The issue in #2600 is more like scanning is slow when there is a large amount of changed items

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests