How does new&changed scanner detect what files to scan?

[slartibartfast]

Turns out it was a caching issue. The artwork finally appeared.

Sent from my Pixel 3a using Tapatalk

Hmm the artwork only appears in "New Music" or "Artists/Albums after playing the album so something seems wrong.

Sent from my Pixel 3a using Tapatalk

[slartibartfast]

Unless it is some kind of caching issue of course. I was clicking on "Artists" then the Artist name to view the album list, I wonder if clicking on "Home" first would have made a difference.

Sent from my Pixel 3a using Tapatalk

Turns out it was a caching issue. The artwork finally appeared.

Sent from my Pixel 3a using Tapatalk

[slartibartfast]

In general "new and changed" scans are much improved. I did find something that trips them up though. If an album folder contains a folder.jpg and the tracks also contain the same embedded artwork, if I remove the embedded artwork and perform a new and changed scan then the album artwork disappears even though the folder.jpg is still there.

Sent from my Pixel 3a using Tapatalk

Unless it is some kind of caching issue of course. I was clicking on "Artists" then the Artist name to view the album list, I wonder if clicking on "Home" first would have made a difference.

Sent from my Pixel 3a using Tapatalk

[slartibartfast]

> In my experience tagging changes aren't always picked up properly in a
> new and changed scan anyway. I always remove and replace the affected
> albums doing a new and changed scan twice.

I've fixed a few of those issues in the past week. Please give it
another try.

In general "new and changed" scans are much improved. I did find something that trips them up though. If an album folder contains a folder.jpg and the tracks also contain the same embedded artwork, if I remove the embedded artwork and perform a new and changed scan then the album artwork disappears even though the folder.jpg is still there.

Sent from my Pixel 3a using Tapatalk

[frank1969]

Not surprisingly that's a lot. Does the fulltext search still provide
some value to you? All those 7k popular terms would only be searched for
in titles, but eg. not in comments.

I'm not saying "turn off FTS" to work around that crash. But I believe
some of the FTS plugin implementation doesn't scale well with larger
libraries.

Yes. I'll keep this in mind and watch this closely.
Till 3 or 4 months ago I had FTS deactivated, but it's really of use for it's more comfortable to type "beatles need love" if I'm looking for albums with "All You Need Is Love" by the Beatles than to call extended search and type "need is love" (need love wouldn't work) in "tyle" field and artist "beatles" in artist field. So FTS is especially more practical if you don't know the exact title but only two words (but maybe not as an exact combination).

[frank1969]

OTOH: could you please check how many lines you have in
Prefs/plugin/fulltext.prefs?

It's 7.317 (so for the first 4 seem to be headlines (see below), it makes sense):
---
_ts_popularTerms: 1644766442
_version: 1
popularTerms:

Anyway, I keep it as "incidentally" too and watch it...

[mherger]

How does new&changed scanner detect whatfiles to scan?

Your crash happened when the FTS plugin tried to create the list of
popular terms. I don't know how any of the recent changes would have
added any additional effort this. So... while I don't like that, let's
consider this a random crash :-/.

OTOH: could you please check how many lines you have in
Prefs/plugin/fulltext.prefs?

[frank1969]

Just did another scan (same beta) that ended (seemingly) regularly:

[22-02-13 16:32:58.8166] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: progress:1644766286||importer||updateStandaloneArt work||16104||16104||1644766378.81439
[22-02-13 16:33:00.3092] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: progress:1644766379.52718||importer||precacheArtwo rk||1||159||
[22-02-13 16:33:03.5565] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: progress:1644766379||importer||precacheArtwork||15 9||159||1644766383.55449
[22-02-13 16:33:09.4125] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: progress:1644766383.61973||importer||dboptimize||1 ||2||
[22-02-13 16:33:46.5057] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: progress:1644766383||importer||dboptimize||2||2||1 644766426.47187
[22-02-13 16:33:46.5113] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: end
[22-02-13 16:33:46.5183] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: exit
[22-02-13 16:33:46.8074] Slim::Schema::wipeCaches (2130) Wiped all in-memory caches.
[22-02-13 16:33:46.8078] Slim::Schema::wipeCaches (2130) Wiped all in-memory caches.
[22-02-13 16:33:46.8094] Slim::Utils::Misc::msg (1343) Warning: [16:33:46.8093] DBIx::Class::ResultSet::update_or_create(): Query returned more than one row. SQL that returns multiple rows is DEPRECATED for ->find and ->single at /<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>Slim/Schema.pm line 1905
[22-02-13 16:33:46.8250] Slim::Schema::wipeCaches (2130) Wiped all in-memory caches.
[22-02-13 16:33:50.8535] Slim::Schema::wipeCaches (2130) Wiped all in-memory caches.
[22-02-13 16:33:50.8545] Slim::Music::Import::nextScanTask (801) remaining scans in queue)
[22-02-13 16:33:58.8082] Slim::Schema::wipeCaches (2130) Wiped all in-memory caches.
[22-02-13 16:33:58.8085] Slim::Schema::wipeCaches (2130) Wiped all in-memory caches.
[22-02-13 16:33:58.8092] Slim::Utils::Misc::msg (1343) Warning: [16:33:58.8092] DBIx::Class::ResultSet::update_or_create(): Query returned more than one row. SQL that returns multiple rows is DEPRECATED for ->find and ->single at /<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>Slim/Schema.pm line 1905
[22-02-13 16:33:58.8208] Slim::Schema::wipeCaches (2130) Wiped all in-memory caches.
[22-02-13 16:34:02.5976] Slim::Schema::wipeCaches (2130) Wiped all in-memory caches.
[22-02-13 16:34:02.5979] Slim::Music::Import::nextScanTask (801) remaining scans in queue)
[22-02-13 16:37:43.8553] Slim::Utils::Misc::msg (1343) Warning: [16:37:43.8553] DBIx::Class::ResultSet::update_or_create(): Query returned more than one row. SQL that returns multiple rows is DEPRECATED for ->find and ->single at /<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>Slim/Schema.pm line 1905

[frank1969]

Argh... how much free disk space would you have, in particular on the
drive where your TEMP folder lives?

Free space on "temp"-device is 136 GB (temp folder right now uses about 300 MB)

Could you please run the inner SELECT in the above statement in SQLite
directly, to get the total number of rows for that query?

Execution finished without errors.
Result: 7313 rows returned in 13175ms

[mherger]

How does new&amp;changed scanner detect whatfiles to scan?

> [22-02-13 11:01:17.0761] Slim::Schema::Storage::throw_exception (121)
> Error: DBI Exception: DBD::SQLite::db selectcol_arrayref failed: out of
> memory [for Statement "
> SELECT term, d FROM (
> SELECT term, SUM(documents) d
> FROM fulltext_terms
> WHERE NOT col IN ('*', 1, 0) AND LENGTH(term) > 1
> GROUP BY term
> ORDER BY d DESC
> )
> WHERE d > 500
> "]

Argh... how much free disk space would you have, in particular on the
drive where your TEMP folder lives?

Could you please run the inner SELECT in the above statement in SQLite
directly, to get the total number of rows for that query?

[frank1969]

r1644703639 looks good again.
The changes I checked worked fine!

One thing only:
At the end of the scan (or I even guess AFTER the end of the scan) server STOPPED.
Can't imagine a memory issue, my machine hast 16 GB (I know, LMS is 32 bit, so it can't use all of it) and the use of scanner/server is usually about 300-500 MB... (and no other app was running only "usual" background action)

If I restarted it showed:

Database Optimize (2 of 2) Complete 00:00:42
The server has finished scanning your media library.
Total Time: 00:56:18 (Sunday, 13. February 2022 / 11.01.15)

so it looks, the server DIDN'T crash but stopped afterwards?

I give You the last entries from server.log - maybe You can see any reason?

[22-02-13 10:05:15.9106] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: progress:1644743057.79672||importer||M:|discoverin g_directory||206||0||
[22-02-13 10:49:32.7410] Slim::Plugin::UPnP::Events::error (326) Subscribe/unsubscribe error: 412 Precondition Failed
[22-02-13 10:49:32.8843] Slim::Plugin::UPnP::Events::error (326) Subscribe/unsubscribe error: 412 Precondition Failed

*** At This Point [22-02-13 11:01:15] server obviously had finished scan***

[22-02-13 11:01:16.9242] Slim::Schema::wipeCaches (2130) Wiped all in-memory caches.
[22-02-13 11:01:16.9247] Slim::Schema::wipeCaches (2130) Wiped all in-memory caches.
[22-02-13 11:01:16.9254] Slim::Utils::Misc::msg (1343) Warning: [11:01:16.9253] DBIx::Class::ResultSet::update_or_create(): Query returned more than one row. SQL that returns multiple rows is DEPRECATED for ->find and ->single at /<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>Slim/Schema.pm line 1905
[22-02-13 11:01:17.0761] Slim::Schema::Storage::throw_exception (121) Error: DBI Exception: DBD::SQLite::db selectcol_arrayref failed: out of memory [for Statement "
SELECT term, d FROM (
SELECT term, SUM(documents) d
FROM fulltext_terms
WHERE NOT col IN ('*', 1, 0) AND LENGTH(term) > 1
GROUP BY term
ORDER BY d DESC
)
WHERE d > 500
"]
[22-02-13 11:01:17.0763] Slim::Schema::Storage::throw_exception (121) Backtrace:

frame 0: Slim::Utils::Log::logBacktrace (/<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>Slim/Schema/Storage.pm line 121)
frame 1: Slim::Schema::Storage::throw_exception (/<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>DBIx/Class/Storage/DBI.pm line 1006)
frame 2: DBIx::Class::Storage:BI::__ANON__ (C:/PROGRA~2/SQUEEZ~1/server/Slim/Plugin/FullTextSearch/Plugin.pm line 587)
frame 3: Slim::Plugin::FullTextSearch::Plugin::_initPopular Terms (C:/PROGRA~2/SQUEEZ~1/server/Slim/Plugin/FullTextSearch/Plugin.pm line 148)
frame 4: Slim::Plugin::FullTextSearch::Plugin::__ANON__ (/<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>Slim/Control/Request.pm line 2058)
frame 5: (eval) (/<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>Slim/Control/Request.pm line 2058)
frame 6: Slim::Control::Request::notify (/<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>Slim/Control/Request.pm line 859)
frame 7: Slim::Control::Request::checkNotifications (slimserver.pl line 715)
frame 8: main::idle (slimserver.pl line 684)
frame 9: main::main (slimserver.pl line 131)
frame 10: PerlSvc::Interactive (/<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>PerlSvc. pm line 99)
frame 11: PerlSvc::_interactive (slimserver.pl line 0)
frame 12: (eval) (slimserver.pl line 0)

[22-02-13 11:01:17.0765] Slim::Control::Request::notify (2060) Error: Failed notify: Carp::Clan::__ANON__(): DBI Exception: DBD::SQLite::db selectcol_arrayref failed: out of memory [for Statement "
SELECT term, d FROM (
SELECT term, SUM(documents) d
FROM fulltext_terms
WHERE NOT col IN ('*', 1, 0) AND LENGTH(term) > 1
GROUP BY term
ORDER BY d DESC
)
WHERE d > 500
"] at /<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>Slim/Schema/Storage.pm line 125
[22-02-13 11:01:17.0771] Slim::Music::Import::nextScanTask (801) remaining scans in queue)

[frank1969]

Argh... that's likely due to my attempt at not running a last,
unnecessary request over the tracks table. I've now committed an
alternative approach, which might actually be slightly faster. But I
preferred the first approach for its simplicity. So... more testing to
do. A new build is on its way.

Thanks!
Scan ran through r1644672553

Will do some tests later and try r1644678709 so it looks it's about other issues...

[mherger]

How does new&amp;changed scanner detect whatfiles to scan?

> Ok, 2nd try, same result:
> "Rescanning Media Library... Geänderte Dateien werden durchsucht (511
> of 298)"

Argh... that's likely due to my attempt at not running a last,
unnecessary request over the tracks table. I've now committed an
alternative approach, which might actually be slightly faster. But I
preferred the first approach for its simplicity. So... more testing to
do. A new build is on its way.

[frank1969]

*** Tested with r1644665330 ***

Ok, 2nd try, same result:
"Rescanning Media Library... Geänderte Dateien werden durchsucht (511 of 298)"

"Information" tab on options says:

Discovering files/directories: M: (1260039 of 1260039) Complete 00:22:32
Removing deleted files: M: (714 of 714) Complete 00:06:37
Scanning changed files: M: (527) Running 00:05:13
M:\_Various\M\Motown Collection\1998 - Motown Collection - Motown Hits Of Gold - CD 3\04 - The Supremes; The Temptations - I'm Gonna Make You Love Me.mp3

Note:
The File mentioned there (M:\_Various\M\...) is actually NOT the last file scanned according to scanner.log

scanner.log says:


[22-02-12 12:51:35.2076] Slim::Utils::Scanner::Local::deleted (636) Handling deleted audio file [...]
[22-02-12 12:51:35.2107] Slim::Schema::Album::rescan (273) Removing unused album: 26137
[22-02-12 12:51:41.9899] Slim::Utils::SQLiteHelper::updateProgress (442) Notify to server: [
"progress:1644666304||importer||M:|directory_delet ed||714||714||1644666701.98934",
]
[22-02-12 12:51:41.9929] Slim::Utils::SQLiteHelper::updateProgress (466) Notify to server OK
[22-02-12 12:51:41.9935] Slim::Utils::Scanner::Local::updateTracks (531) Rescanning changed audio files (298)
[22-02-12 12:51:42.0129] Slim::Utils::SQLiteHelper::updateProgress (442) Notify to server: [
"progress:1644666701.99379||importer||M:|directory _changed||1||298||",
]
[22-02-12 12:51:42.0160] Slim::Utils::SQLiteHelper::updateProgress (466) Notify to server OK
[22-02-12 12:51:42.0165] Slim::Utils::Scanner::Local::changed (967) Handling changed audio track file:///M:/[...]

[...]
* Here are about 295 changed tracks handled *

[22-02-12 12:52:17.9092] Slim::Utils::Scanner::Local::changed (967) Handling changed audio track file:///M:/S/Sonny%20+%20Cher/1965%20-%20Baby%20Don%27t%20Go/07%20-%20Caesar%20+%20Cleo%3B%20Sonny%20+%20Cher%20-%20Do%20You%20Want%20to%20Dance.mp3
[22-02-12 12:52:18.2522] Slim::Utils::Scanner::Local::changed (967) Handling changed audio track file:///M:/S/Sonny%20+%20Cher/1965%20-%20Baby%20Don%27t%20Go/12%20-%20Caesar%20+%20Cleo%3B%20Sonny%20+%20Cher%20-%20Let%20The%20Good%20Times%20Roll.mp3
[22-02-12 12:52:18.2574] Slim::Schema::Contributor::rescan (244) Removing unused contributor: 127316

[22-02-12 12:52:23.4628] Slim::Utils::SQLiteHelper::updateProgress (442) Notify to server: [
"progress:1644666701.99379||importer||M:|directory _changed||318||298||",
]
[22-02-12 12:52:23.4658] Slim::Utils::SQLiteHelper::updateProgress (466) Notify to server OK
[22-02-12 12:52:28.6004] Slim::Utils::SQLiteHelper::updateProgress (442) Notify to server: [
"progress:1644666701.99379||importer||M:|directory _changed||322||298||",
]
[22-02-12 12:52:28.6032] Slim::Utils::SQLiteHelper::updateProgress (466) Notify to server OK
[22-02-12 12:52:33.7420] Slim::Utils::SQLiteHelper::updateProgress (442) Notify to server: [
"progress:1644666701.99379||importer||M:|directory _changed||326||298||",
]
[22-02-12 12:52:33.7451] Slim::Utils::SQLiteHelper::updateProgress (466) Notify to server OK
[22-02-12 12:52:38.9079] Slim::Utils::SQLiteHelper::updateProgress (442) Notify to server: [
"progress:1644666701.99379||importer||M:|directory _changed||330||298||",
]

[...]

]
[22-02-12 12:59:08.6201] Slim::Utils::SQLiteHelper::updateProgress (466) Notify to server OK
[22-02-12 12:59:14.0922] Slim::Utils::SQLiteHelper::updateProgress (442) Notify to server: [
"progress:1644666701.99379||importer||M:|directory _changed||639||298||",
]
[22-02-12 12:59:14.0950] Slim::Utils::SQLiteHelper::updateProgress (466) Notify to server OK
[22-02-12 12:59:19.3689] Slim::Utils::SQLiteHelper::updateProgress (442) Notify to server: [
"progress:1644666701.99379||importer||M:|directory _changed||643||298||",
]
[22-02-12 12:59:19.3718] Slim::Utils::SQLiteHelper::updateProgress (466) Notify to server OK

* [...] and so on *

server.log says:

[22-02-12 12:51:32.5101] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: progress:1644666304.99661||importer||M:|directory_ deleted||712||714||
[22-02-12 12:51:41.9925] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: progress:1644666304||importer||M:|directory_delete d||714||714||1644666701.98934
[22-02-12 12:51:42.0154] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: progress:1644666701.99379||importer||M:|directory_ changed||1||298||
[22-02-12 12:51:47.1941] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: progress:1644666701.99379||importer||M:|directory_ changed||12||298||
[22-02-12 12:51:52.5882] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: progress:1644666701.99379||importer||M:|directory_ changed||30||298||
[22-02-12 12:51:57.5921] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: progress:1644666701.99379||importer||M:|directory_ changed||80||298||
[22-02-12 12:52:02.6086] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: progress:1644666701.99379||importer||M:|directory_ changed||157||298||
[22-02-12 12:52:07.6585] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: progress:1644666701.99379||importer||M:|directory_ changed||247||298||
[22-02-12 12:52:12.6596] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: progress:1644666701.99379||importer||M:|directory_ changed||293||298||
[22-02-12 12:52:17.8212] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: progress:1644666701.99379||importer||M:|directory_ changed||304||298||
[22-02-12 12:52:23.4643] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: progress:1644666701.99379||importer||M:|directory_ changed||318||298||
[22-02-12 12:52:28.6027] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: progress:1644666701.99379||importer||M:|directory_ changed||322||298||
[...]
[22-02-12 13:04:24.7709] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: progress:1644666701.99379||importer||M:|directory_ changed||879||298||
[22-02-12 13:04:29.9774] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: progress:1644666701.99379||importer||M:|directory_ changed||883||298||
[22-02-12 13:04:35.2212] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: progress:1644666701.99379||importer||M:|directory_ changed||887||298||

... and so on for once again 15 minutes now...

[frank1969]

It should certainly not take that much longer.

Yes!
It became quicker till the end and now I started the "2nd try" and it's "as quick as it always was".
Guess there were some windows update in the background this morning, didn't check task manager, sry!
I will report if it "runs through" this time...