Slow scan_check? #28
Comments
|
Could you please restart with -m 4 or -m 5 capturing output, and repeat scancheck, and send output? |
|
Perhaps -m 5 is a bit too verbose... scan_check produces a gazillion (well 2329866 before I ctrl-c'd after 30s) lines of `202308015:49:14 2023-03-21 14:49:14.25: Cmd: scan_check? ........ 202308015:49:33 2023-03-21 14:49:33.56: isRecordingEntry: checking entry vo2321_ow_322-0459a_3 against ^r11095_on_080-1447b(_ds[^_\.]+)?$ |
|
With -m 4 only silence after scan_check |
|
Another attempt at -m 5 on a fresh non-recording jive5ab, scan_set takes time to run, but a subsequent scan_check? returns instantly. Log file for just these two commands - 192 MB! |
|
It seems the scan for chunks takes ages. That is the big difference between If you manage to compile & run this specific commit (1a147cd) you should see that both the Somehow I think the slowness is related to either the machine doing something timeconsuming in parallel, or being very full/having LOADS of chunk names to filter. Hmmm. |
Well, about 70% full so it can only get worse ;) it seems to take about the same time with -m 3 (scan_check) as with -m 5 (scan_set) when -m 5 is piped only to a file and not teed to stdout. Interestingly the change to this release was to take advantage of "-D" as exactly this issue was hitting the first 6-8s of the recordings since yesterday, now the 'dead-time' has jumped to post-scan! Machine's idle apart from this, but grepping for isRecordingEntry gives 1668982 matches in the 192 MB log so that's probably how many individual scan-directories there are. Like I said I didn't see anything much happening in either iotop or htop, but I can double check later with your suggested commit. |
|
Righty maybe I blinked the first time but running 1a147cd .... Initially Then subsequent alternating calls to scan_set & scan_check take 7.6ish s each. During which all 4 cores boost to 4.3 GHz and show about 50% usage with 36 extra threads created. Could it be 36 threads on 4 cores is a bit too much and they're starting to fight over core time? Note that on this buff jive5ab is typically pinned to just 2 cores anyway. 1 core saved for network & 1 core for "everything else". |
Yes, the start-up delay (checking for duplicate recording names) suffers from the exact same issue. I take it the reason this was not happening before was because an older version (say
The threads are 1:1 for each mount point to scan - if we don't parallelise scanning them then it would take even longer. However, in this case, I really don't know which is the bottle neck: the disk I/O (36 threads trying to execute |
|
Hmph somebody's cleaned up the buff overnight... With 3.0.0 there was a startup-delay but scan_check was instant. Currently at about 40% full now 4 cores fairly consistent scan_check & scan_set 4.1s |
|
so it's not the amount of CPUs/cores but really the actual opening directories and scanning the entries by the looks of it.
https://pubs.opengroup.org/onlinepubs/9699919799/functions/nftw.html So within |
Running jive5ab built from issue25 commit d31d7ce results in a rather lethargic scan_check?
Recordings here are single-threaded VDIF_8000-512-16-2
In 'some' flavour of jive5ab-3.0.0 scan_check returns before you have time to blink e.g.
Restarting with issue25, things become a lot more laid back
FS seems to have an 8s timeout for scan_check and a small proportion of these calls end up taking >8s.
Monitoring with htop and iotop, nothing particularly seems to be happening during scan_check.
Oddly in the last example that took the longest, the scan was a mere 2.75 GB, whilst the others at 4-8 GB were marginally quicker.
The text was updated successfully, but these errors were encountered: