Logic error after rescanning collection?

To get bugs in the current release fixed, please report them here.

Moderator: Gurus

MMuser2011
Posts: 1288
Joined: Mon Oct 17, 2011 8:28 am
Location: Central Europe

Logic error after rescanning collection?

Post by MMuser2011 » Thu Apr 11, 2019 6:46 am

After rescanning my entire collection, MM needs hours (I mean several hours!) after the last track is scanned until the GUI responds and works as expected.

I assume, after rescanning, some SQL magical work should be done, which needs much more time then necessary.

Could you please tell us which steps are performed after the last track is (re)scanned?
What takes so much time to check, I mean, all the tracks are scannend and therefore exists.
Why does further checks need several hours, especially the list with no more found (moved, deleted, renamed) tracks?

For the record:
MM actually runs on a i9-9900k (8 cores, 16 threads) with 32GB RAM on a very fast M.2 SSD
Magic Nodes v4.2 (2011-07-01) SQL Viewer v2.4 (2009-10-25)
ExternalTools v1.4 (2011-05-09) iTunesMonkey 1.0 + Acoustid
Calculate Cover Size v1.7 (2012-10-23) RegExp Find & Replace v4.3 (2011-07-06)

Lowlander
Posts: 45774
Joined: Sat Sep 06, 2003 5:53 pm
Location: MediaMonkey 5

Re: Logic error after rescanning collection?

Post by Lowlander » Thu Apr 11, 2019 9:23 am

Which version of MediaMonkey?

Do you have auto volume analyze enabled?
Lowlander (MediaMonkey user since 2003)

MMuser2011
Posts: 1288
Joined: Mon Oct 17, 2011 8:28 am
Location: Central Europe

Re: Logic error after rescanning collection?

Post by MMuser2011 » Thu Apr 11, 2019 11:09 am

Version: 4.1.24.1883
"Auto volume analyze" is disabled/not checked
Magic Nodes v4.2 (2011-07-01) SQL Viewer v2.4 (2009-10-25)
ExternalTools v1.4 (2011-05-09) iTunesMonkey 1.0 + Acoustid
Calculate Cover Size v1.7 (2012-10-23) RegExp Find & Replace v4.3 (2011-07-06)

Lowlander
Posts: 45774
Joined: Sat Sep 06, 2003 5:53 pm
Location: MediaMonkey 5

Re: Logic error after rescanning collection?

Post by Lowlander » Thu Apr 11, 2019 3:06 pm

A debug log (step 4b) will show what's happening: https://www.mediamonkey.com/forum/viewt ... p?f=7&t=69 You can attach it to a Support Ticket for the developers to analyze.
Lowlander (MediaMonkey user since 2003)

MMuser2011
Posts: 1288
Joined: Mon Oct 17, 2011 8:28 am
Location: Central Europe

Re: Logic error after rescanning collection?

Post by MMuser2011 » Fri Apr 12, 2019 4:23 am

First of all: Thank you for the MM debug version and the inside informations.

The latest rescan for all my songs took 44 minutes.
(from start scanning until the point where MM seems to be frozen with the last "added" song shown in the taskbar,
that's the point, where it takes hours until MM returns to normal working state***)

The following should be noted:
Every step you do works fine. At least for a few hundred or a thousand tracks.
But please think bigger. What about hundreds of thousands or even millions of tracks?
Thanks to the DebugView log I would like to suggest some improvements:

Example:
For every single track you query the MM.DB with
SELECT Songs.* FROM Songs WHERE Songs.IDMedia=? and Songs.SongsPath=?
Even on a very fast system this takes - according to the DebugView-Output -
about 450-600microseconds, or 0.5 miliseconds or 0.0005 seconds.

Again: This is not a problem for a few hundred songs. But for millions?
If you calculate 1 Million tracks you need 1'000'000 x 0.0005 seconds = 500 Seconds = 8,3 Minutes only for this query

And this query is only one of many processed for every track.

I suggest to rethink this process.
Step #1:
Assuming that most of us has some structure for the songfiles,
we could think about something like a folder or an album.
Why not read a whole folder from disk with something like "Directory.EnumerateFiles"?
You make only one call per folder and get all the full names (including paths) for the files in the specified directory.
Then you do the same with only one query with the specified foldername in the MM.DB with
SELECT Songs.* FROM Songs WHERE Songs.IDMedia=? and Songs.SongsPath=FolderName

After matching the songs in memory you have two kind of entries
a) the ones found in DB = all this songs already exists in DB
b) the ones not found in DB = new or changed ones

For b) you have to scan every new file to get the additional tag information. The way it works today.
For a) you only have to scan the files with changed "last modified" timestamp (according to the user settings).

BTW: I don't know which programming language do you use. But with the help of something like this
https://sourceforge.net/projects/fastfileinfo/
original source was: https://www.codeproject.com/Articles/38 ... Enumerator
you can speed up things dramatically.


Step #2:
CREATE TEMP TABLE ScannedSongs_2 ( IDSong INTEGER )
DB exec SQL: INSERT INTO ScannedSongs_2 (IDSong) VALUES (?)

I'm not sure if this table is created in the MM.DB or just as memory table.
Anyway: I would suggest to use transactions for all the INSERT INTO's and not execute it for every single track.
(The same way you do it already to UPDATE Songs SET SongPath=?,Artist=?....)


Step #3:
AddToDatabaseRec: Number of cover candidates: 0
AddToDatabaseRec: Going to save covers

I'm not sure what exactly you are doing to decide to get 0 cover candidates.
In my case I have deactivated the setting "search for covers in the same directory".
So it should not search at all for covers especially not with an additional "file search"- or "cover save"-call.


Step #4:
Prgrs: Updating previous level from: 0 by 10
Prgrs: Updating previous level from: 0.3 by 0.7
Prgrs: Updating previous level from: 510 by 10
Prgrs: Creating a new level.
Prgrs: Deleting a level.

I'm not sure what exactly you are doing while "Updating previous level"
If it is about the volume level per Track or Album:
In my case I have deactivated all the volume leveling settings.
This is confirmed by several "TDevices.disableDiscVolume" log entries.


***
Final words to the endless last step (after rescanning the songs, until the GUI responds again):
MM is actually writing endless lines of
Thread '_ManageTransactions' has started/has finished with 4 or 5 lines of
DB open SQL: SELECT * FORM Songs WHERE Songs.ID=?

5 lines needs about a second.
I assume, you will do that for all tracks.
1'000'000 : 5 = 200'000 seconds = 3'333 minutes = 55,5 hours...

Why just using 2 Threads from all 32 available?
Do you really write only 4 or 5 songs with a single transaction?
Magic Nodes v4.2 (2011-07-01) SQL Viewer v2.4 (2009-10-25)
ExternalTools v1.4 (2011-05-09) iTunesMonkey 1.0 + Acoustid
Calculate Cover Size v1.7 (2012-10-23) RegExp Find & Replace v4.3 (2011-07-06)

Erwin Hanzl
Posts: 267
Joined: Tue Jun 13, 2017 8:47 am
Location: Vienna

Re: Logic error after rescanning collection?

Post by Erwin Hanzl » Mon May 20, 2019 8:52 pm

Hallo MMuser,

mein Englisch ist minimal und Google-Translater nicht viel besser, deshalb erlaube ich mir, Dir in unserer Muttersprache zu antworten.

Die Dimensionen der Zeitspannen und der Kapazität ließen mir keine Ruhe und habe deshalb getestet:
ich möchte vorausschicken: ich verwende weder MagicNodes noch MonkeyRok, noch speichere ich Bilder.
Auch die Felder „Album“ und „Album-Interpret“ sind bei mir nicht belegt.

Meine Musikdateien habe ich auf meine zweite interne Festplatte in einen TEMP-Ordner mehrfach mittels Windows-Explorer kopiert, bis ich genau 20.000 Titel beisammen hatte.

1. Internetverbindung getrennt
2. MM gestartet
3. Optionen / Allgemein – Priorität für Hintergrundprozesse: NORMAL
4. Laustärkenanpassung Allgemein: DEAKTIVIERT
5. Archiv – Dateien auf Duplikate prüfen: AKTIVIERT
6. Archiv – Suche auf Metadaten: ALLES DEAKTIVIERT
7. Archiv / Ordner-Überwachung diesen TEMP-Ordner "Stets überwachen“ und „Beim Start überprüfen“
8. OK
9. Anzahl eingelesene Titel inkl meiner normalen Sammlung: 22.292
10. Nach gestoppten 26 Minuten war alles erledigt – ich konnte sofort herumfuhrwerken - kein einfrieren

Zur Kapazität: diese 20.000 Musikfiles verschlingen 140 GB. Rechne ich das auf 1 Million Titel hoch, so wären dies 6.760 GB oder rund 6,6 TB. Wer hat das schon – na irgendwer sicher.

Wenn ich jetzt Deine angegebene Zeitspanne von 44 Minuten bis zum „Einfrieren“ meiner Zeitspanne von 26 Minuten dagegenhalte und auch noch Deinen schnelleren Rechner mit einbeziehe, so schätze ich Deine Musiksammlung auf mindestens 60.000 Musikdateien.

Meine Ausstattung:
i7-3840QM
32 GB Arbeitsspeicher
Samsung SSD 840 PRO 512GB
Samsung SSD 850 EVO 1TB

Aus dieser meiner Beschreibung kannst Du den Unterschied zu Deiner Konfiguration ausarbeiten und eventuelle Erfolge diesem Forum mitteilen.

Grüße
:D MMW 4.1.25.1885 GOLD Beta :D Meine Einstellungen
:-? MMA 1.3.5.0853 Beta auf Huawei Mate 20 Pro (USB-Kabel-Sync)
:D FindCurrentPlayingTrack 1.3.2 :D Lyrics and Comment Viewer 2.2.0.0 :D CustomFieldsTagger 1.0.3.0 :D Discogs Tagger 5.6.8
:D WIN 10 Pro-1903-64 Bit -- Windows-Defender mit Echtzeitschutz

Peke
Posts: 11994
Joined: Tue Jun 10, 2003 7:21 pm
Location: Serbia
Contact:

Re: Logic error after rescanning collection?

Post by Peke » Tue May 21, 2019 1:00 pm

Hi,
MMuser2011 wrote:
Fri Apr 12, 2019 4:23 am
Why just using 2 Threads from all 32 available?
Can you try same scan using clean MM5 Portable. I tested today 30k of tracks saved on SATA3 SSD and AMD 2700x CPU on M.2 Samsung 970 Pro system drive and scan finished within 12 Minutes. All 16 threads were evenly used.

My System Info:
Image
Best regards,
Pavle
MediaMonkey Team lead QA/Tech Support guru
Admin of Free MediaMonkey addon Site HappyMonkeying
Image
Image
How to add SCREENSHOTS to forum

MMuser2011
Posts: 1288
Joined: Mon Oct 17, 2011 8:28 am
Location: Central Europe

Re: Logic error after rescanning collection?

Post by MMuser2011 » Wed May 22, 2019 3:33 am

Peke wrote:
Tue May 21, 2019 1:00 pm
Can you try same scan using clean MM5 Portable...All 16 threads were evenly used.
Done.

MM5 portable (running the MM.DB on a Samsung SSD 850 PRO 512GB SATA SSD) needs 41 Minute for a complete rescan. So MM5 is slightly faster.
What exactly do you have changed in this process?

And you are right, MM5 uses all 16 Threads (not 32, as I mistakenly wrote based on an outdated gadget. My i9-9900K has 8 Cores, 16 Threads).
Image

The main problem - the GUI freezes after this 41 MM5 minutes - remains unchanged.
One of the 16 threads run constantly at 90%, the other 15 threads shows about 0% to 5% load/utilization.
Magic Nodes v4.2 (2011-07-01) SQL Viewer v2.4 (2009-10-25)
ExternalTools v1.4 (2011-05-09) iTunesMonkey 1.0 + Acoustid
Calculate Cover Size v1.7 (2012-10-23) RegExp Find & Replace v4.3 (2011-07-06)

Peke
Posts: 11994
Joined: Tue Jun 10, 2003 7:21 pm
Location: Serbia
Contact:

Re: Logic error after rescanning collection?

Post by Peke » Thu May 23, 2019 6:09 pm

Hi,
That needs optimization. I would be great to fetch Video during the scan and MM5 Debug log showing where problem lies and move some work off main thread. I do not observe your freeze, but I see your point and that should certainly be corrected.

MM5 is simply better multi thread optimized, especially that MMW takes root in 15+ years of developing when things looked/worked differently.
Best regards,
Pavle
MediaMonkey Team lead QA/Tech Support guru
Admin of Free MediaMonkey addon Site HappyMonkeying
Image
Image
How to add SCREENSHOTS to forum

MMuser2011
Posts: 1288
Joined: Mon Oct 17, 2011 8:28 am
Location: Central Europe

Re: Logic error after rescanning collection?

Post by MMuser2011 » Fri May 24, 2019 2:14 am

You ask for a 41 minutes Video?

Unfortunately, the debugfile gets too large, MM crashes after a certain size.
Magic Nodes v4.2 (2011-07-01) SQL Viewer v2.4 (2009-10-25)
ExternalTools v1.4 (2011-05-09) iTunesMonkey 1.0 + Acoustid
Calculate Cover Size v1.7 (2012-10-23) RegExp Find & Replace v4.3 (2011-07-06)

Peke
Posts: 11994
Joined: Tue Jun 10, 2003 7:21 pm
Location: Serbia
Contact:

Re: Logic error after rescanning collection?

Post by Peke » Tue May 28, 2019 6:33 pm

Hi,
Not all 41 Minute only few last minutes.

What do you mean LOG gets too Large > 2GB?
Best regards,
Pavle
MediaMonkey Team lead QA/Tech Support guru
Admin of Free MediaMonkey addon Site HappyMonkeying
Image
Image
How to add SCREENSHOTS to forum

MMuser2011
Posts: 1288
Joined: Mon Oct 17, 2011 8:28 am
Location: Central Europe

Re: Logic error after rescanning collection?

Post by MMuser2011 » Wed May 29, 2019 3:55 am

DebugView can't list more then 6'646'529 lines in it's listview :wink:

Image

@Peke You got a PM

There you can see what happens after the last track was scanned. The last 150 lines repeats "endlessly".
Magic Nodes v4.2 (2011-07-01) SQL Viewer v2.4 (2009-10-25)
ExternalTools v1.4 (2011-05-09) iTunesMonkey 1.0 + Acoustid
Calculate Cover Size v1.7 (2012-10-23) RegExp Find & Replace v4.3 (2011-07-06)

Post Reply