Troubleshooting library scan times

[Edrock200 53]

Hey guys,

No issues with emby, everything is working great! Nice work ok 4.6.7.

I'm trying to troubleshoot an issue with scan times and I'm not sure what else to do. I have 2 identical emby servers, both attached to a Nas over 1gbs links. Both can saturate the links and as far as I can tell have identical performance. One emby takes 30m or so for a full scan. The other takes 2.5+h. This is consistently repeatable.

I've checked the following:

Embys at same version

Both embys using same docker repo/image (official emby docker)

Library settings are identical (agents, image grabbers, etc.)

Plugin sets are identical and configured identically

SAN performance appears identical to both servers

mounts/libraries/paths are identical as well as their permissions

Config folder permissions are identical

Differences are that one is more utilized than the other and has more watch history, not sure if the scanner throttles based on server usage or not. However I do not have plugins, that I know of, which would need extra time for stats like Statistics or Reports.

I'm guessing the next step is debug logging during a full scan, but the debug logs can be like drinking from a firehose. So was just wondering if you have any tips or tricks in terms of what to search for in the logs to find delays or anomalies with scans.

Which also reminds me I haven't done a db vacuum on either yet, would that help?

To be clear, I'm 99% sure it's something on my end and NOT with Emby. I'm just not sure where else to look.

Thanks in advance for any help. 

Ed

[moviepalace4K 29]

what are the hardware specifications of the two computers that the Emby server runs on?

[Edrock200 53]

@streamz4k I should have mentioned that, my bad. Fairly close, the faster one is actually slightly lower spec'd. Faster scan node: i7-8700, 2x1tb nvme in raid zero, 1gb nic, 32GBGB RAM. Official emby docker container. Host on kernel 5.4 low latency. Emby premiere and igpu active.

 

Slower node: i9 9900, 64GB RAM, 2x1tb nvme in raid zero. Host on same 5.4 kernel 5.4 low latency and official emby docker container. Emby premiere and igpu active.

 

Both point to a mergerfs share with the same San source, and a local meta data folder with posters, nfos and srts that exist on the local drives, but merge in. This metadata folder syncs across nodes with syncthing. Union has San as read only but metadata path as rw, so anything written to mergerfs volume writes to local metadata folder if that makes sense.

Thanks in advance for any insights/advice.

 

Edit: should also note avg CPU util is under 30% on both, usually under 20%. Nic load at peak is like 300mbs but even that is bursts of a few seconds. Generally stays under 100mbs on both. Doing an ls -alR on the union share is fast, can traverse thousands of folders in seconds. Copying a file from San to local on either node can saturate the 1gbs link.

Edited December 12, 2021 by Edrock200

[Edrock200 53]

So in digging into this further, I did finally find one difference that may be of significance. Faster scan server is on mergerfs 2.32 whereas slower was on 2.28. Updated the slower to 2.32, restarted the merger mount and emby, initated a scan. Fingers crossed.

[Luke 42081]

Let us know how you get on. Thanks.

[Edrock200 53]

Unfortunately no dice. I do see it seems to be detecting a lot of existing movies as new on each scan for some reason. I'll dig into some of those titles to see if anything obvious pops up. 

Edited December 13, 2021 by Edrock200

[Edrock200 53]

Still no luck finding a root cause. Debug logs don't seem to show what it's doing during the first chunk of a full scan, towards the end it shows the ffprobes and plugins. Can you share what it is that emby looks for to deem a media item has changed, e.g. file modify time, folder modify time, file size, checksum, etc? And does this pertain to assets as well such as srts, nfos, etc? This may help me narrow the issue. 

[Luke 42081]

It's file modify time.

[Edrock200 53]

Thank you. I think I found something, but not sure yet, and if so not sure why it's affecting one more than the other. I did a find against my mediafolder for any file modified within the last 24h. And a ton of .nfo files came back. I also recalled seeing a lot of nfo files being detected in the debug logs. So I need to find out why the modify time of the nfo files were changed, however, still doesn't explain why one server scans faster given that both see the same modified nfo files. I confirmed both have the nfo reader on in each library.

As a test, I am disabling the nfo reader on the slower scanning emby's libraries and running a full scan.

[Luke 42081]

Let us know how you get on. Thanks.

[Edrock200 53]

Still haven't found any rhyme or reason for the difference, other than one emby server is slightly more utilized than the other. The nfos enabled or disabled didnt make much of a difference. The only thing I can think of at this point is perhaps some sort of db corruption or bloat. Tried vacuuming and raising the cache level a bit but it's fairly consistent in scan times, one being ~3x faster than the other. I'm considering building another one and scanning in the media, then seeing if subsequent scans are fast like the other node. If so, is there an easy way to migrate users and watch history?

[Luke 42081]

Regarding migration I would take a look at this: https://support.emby.media/support/solutions/articles/44001159936-backup

Thanks.

[Edrock200 53]

Thank you. Will prob try this over the holidays. Will keep you posted 

[Luke 42081]

Let us know how you get on. Thanks.

[Edrock200 53]

Yeah. as far as I can tell, it must just be either a load issue (e.g. maybe emby throttles scans when streams are active?), or some extra things that happen when there is user watch history and such in play maybe? Otherwise I'm at a loss. In this test case - cloned existing emby server to new server which consisted of - 

copied emby config dir

deleted connect.txt, device.txt, wan.dat

deleted all db's except for library.db

deleted config/data/devices/*

edited system.xml to update URL and change value to force setup wizard to run again

sqlite3 library.db to "delete from UserDatas"

Fired up emby, setup a new admin account.

Confirmed library settings and plugins were identical.

registered key, enabled gpu transcoding,

Restarted emby once more to ensure all updated settings took effect

Kicked off full scan on old emby and new emby.

Old Emby server - Full scan - 3h 25m and 17 seconds.

New Emby server - 20m and 13 seconds.

Is there any terms or ideas of what to look for when parsing through a debug log that was captured while a scan was running? Even though the debug log is very verbose, it seems to log the initial scan request, reading of the root/library xml files, but then is relatively "quiet" until it gets to the ~90% mark, then has a lot of ffprobe entries for new/changed content it detected during the scan.

[Luke 42081]

Quote

then has a lot of ffprobe entries for new/changed content it detected during the scan.

You probably want to find the library scan time first from when there are no changes and use that as a baseline for the best possible case.