Applying library settings taking several days after Core migration

May I kindly bring my above question to your attention once again?

Hi @Hans_Valeton,

Has this completed since posting your last message? Are there any remaining issues in 1.7?

Yes, this is to be expected after upgrading to a new version.

You can certainly do so in the feature request area of this site. The way that VPNs work is that they route all of your network traffic through the VPN, including traffic that Roon needs to operate properly. You can make a post there, but I can’t make any promises for behavioral changes in this regard.

Once we have activated diagnostics mode, it is active for a short period of time while we work on your case. Once the case is closed out, diagnostic mode is automatically de-activated.

Hi, @noris, thanks for all your answers!

The re-scanning has taken about four days to complete. Yesterday evening it was finally finished and because the spinning wheel was still busy, saying Roon was “applying library settings” and I knew from experience that this would only stop if I restarted the Core, I did just that. After the restart the spinning wheel was absent. Phew…
I looked in the newly created log and saw this line:

11/24 20:44:54 Trace: [library] finished with 217479 dirty tracks 12169 dirty albums 65576 dirty performers 39213 dirty works 76622 dirty performances 1280 dirty genres 80077 dirty auxfiles 133 dirty countries 9 dirty periods 55 dirty forms 5071 dirty places 1818 dirty creditroles 878 dirty labels 0 clumping tracks, 0 clumping auxfiles 0 compute tracks, 0 deleted tracks, 217479 tracks to (re)load, 0 tracks to retain, 80077 auxfiles to (re)load, 0 auxfiles to retain, and 412339 changed objects

In short, all of my tracks, albums etc are “dirty”. I have tried to find some explanation on this term but have not yet found anything helpful or conclusive. Should I be worried about all this “dirtyness”? Please explain!

And yes, there are still issues:
Whenever I make a change in the album or track editor and then click “save” it always takes 20 seconds (!) before the operation is finished


In the above screenshot I had just changed one setting, under “prefer roon or file” concerning the track title.
The “saving…” duration is fairly consistent over all types of (small ) changes that I apply. After (re-)identifying an album containing 103 tracks the saving action takes about 24 seconds:

Taking into account that there are still 3799 unidentified albums,
image
having to wait so long for the “save” to finish is really unworkable.
This is the cpu activity during the “save” action on the laptop running the core:

This is the CPU usage with nothing going on:

Is committing data to the database really so costly in terms of cpu and time?? I am quite puzzled by this.

Hi @Hans_Valeton,

Dirty tracks mean that the tracks need to be re-indexed, likely because you are performing edits on the tracks.

Does the same delay happen when trying to edit albums with a smaller track count?

Editing tracks also edits the database, some CPU activity should be expected.

OK, but so many of my files, and so often, seem to be labelled as “dirty” in the logs. They can’t all need to be re-indexed, can they?
How should I interpret the following lines in the log? The number of Dirty Tracks seems to change constantly. Is that caused by a "[metadatasvc] REQ "?

11/27 16:13:44 Trace: [library/compute] computing 3 tracks
11/27 16:13:44 Trace: [dbperf] flush 557349 bytes, 183 ops in 17 ms (cumulative 1734054648 bytes, 659001 ops in 156079 ms)
11/27 16:13:44 Trace: [roonapi] [apiclient 192.168.1.24:52906] CONTINUE Changed {“zones_seek_changed”:[{“zone_id”:“1601b610afefb77513b8c154e45991cf80cb”,“queue_time_remaining”:2909,“seek_position”:68}]}
11/27 16:13:45 Trace: [B&W MM-1] [HighQuality, 16/44 FLAC => 16/44] [100% buf] [PLAYING @ 1:08/3:30] Night Boat to Cairo - Madness
11/27 16:13:45 Trace: [library] finished with 665 dirty tracks 48 dirty albums 94 dirty performers 209 dirty works 224 dirty performances 23 dirty genres 0 clumping tracks, 0 clumping auxfiles 3 compute tracks, 0 deleted tracks, 52 tracks to (re)load, 0 tracks to retain, 0 auxfiles to (re)load, 0 auxfiles to retain, and 1211 changed objects
11/27 16:13:45 Trace: [library] endmutation in 553ms
11/27 16:13:45 Trace: [metadatasvc] REQ [1099] https://metadataserver.roonlabs.net/md/4/updatemetadata?uid=4d35e36f-9f3c-424b-a5fd-5cb28ff8bb7a&lid=&token=d8fbdaeb-06cf-420f-a289-65b09393cbcb&metadataid[]=7b004d5430303533393132303838&metadataid[]=7b004d5430303533393132313030&metadataid[]=7b004d5430303533393132303930&metadataid[]=7b004d5430303533393132313031&metadataid[]=7b004d5430303533393132303835&metadataid[]=7b004d5430303533393132303839&metadataid[]=7b004d5430303533393132303935&metadataid[]=7b004d5430303533393132303836&metadataid[]=7b004d5430303533393132303837&metadataid[]=7b004d5430303533393132303931&metadataid[]=7b004d5430303533393132303932&metadataid[]=7b004d5430303533393132303936&metadataid[]=7b004d5430303533393132303937&metadataid[]=7b004d5430303533393132303938&metadataid[]=7b004d5430303533393132303934&metadataid[]=7b004d5430303533393132303933&metadataid[]=7b004d5430303533393132313032&metadataid[]=7b004d5430303533393132303939&metadataid[]=6100313735303035303230343237333633&metadataid[]=6100313735303035303230343237333634&metadataid[]=6100313735303035303230343237333635&metadataid[]=7b004d5430303534333433353634&metadataid[]=7b004d5430303534333433353537&metadataid[]=7b004d5430303534333433353738&metadataid[]=7b004d5430303534333433353734&metadataid[]=7b004d5430303534333433353534&metadataid[]=7b004d5430303534333433353735&metadataid[]=7b004d5430303534333433353532&metadataid[]=7b004d5430303534333433353536&metadataid[]=7b004d5430303534333433353731&metadataid[]=7b004d5430303534333433353533&metadataid[]=7b004d5430303534333433353631&metadataid[]=7b004d5430303534333433353535&metadataid[]=7b004d5430303534333433353733&metadataid[]=7b004d5430303534333433353637&metadataid[]=7b004d5430303534333433353830&metadataid[]=7b004d5430303534333433353633&metadataid[]=7b004d5430303534333433353630&metadataid[]=7b004d5430303534333433353538&metadataid[]=7b004d5430303534333433353732&metadataid[]=7b004d5430303534333433353636&metadataid[]=7b004d5430303534333433353539&metadataid[]=7b004d5430303534333433353638&metadataid[]=7b004d5430303534333433353632&metadataid[]=7b004d5430303534333433353739&metadataid[]=7b004d5430303534333433353736&metadataid[]=7b004d5430303534333433353730&metadataid[]=7b004d5430303534333433353737&metadataid[]=7b004d5430303534333433353639&metadataid[]=7b004d5430303534333433353635&metadataid[]=7b004d5430303534333433353531&metadataid[]=79004d5730303032393939373533&metadataid[]=79004d5730303031383334313236&metadataid[]=79004d5730303033303333373935
**11/27 16:13:45 Trace: [metadatasvc] GOT [1099] (133ms) Sooloos.Msg.Metadata.UpdateMetadataResponse: **
11/27 16:13:45 Trace: [metadatasvc] REQ [1100] https://metadataserver.roonlabs.net/md/4/getmetadata?uid=4d35e36f-9f3c-424b-a5fd-5cb28ff8bb7a&lid=&token=d8fbdaeb-06cf-420f-a289-65b09393cbcb&metadataid[]=7b004d5430303533393132303838&metadataid[]=7a004d4e30303030303534363637&metadataid[]=79004d5730303032393939373533&metadataid[]=5e01935b3dee0fcee342ae4485cc1060cf86&metadataid[]=7b004d5430303533393132313030&metadataid[]=7b004d5430303533393132303930&metadataid[]=7b004d5430303533393132313031&metadataid[]=7b004d5430303533393132303835&metadataid[]=7b004d5430303533393132303839&metadataid[]=7b004d5430303533393132303935&metadataid[]=7b004d5430303533393132303836&metadataid[]=7b004d5430303533393132303837&metadataid[]=7b004d5430303533393132303931&metadataid[]=7b004d5430303533393132303932&metadataid[]=7b004d5430303533393132303936&metadataid[]=7b004d5430303533393132303937&metadataid[]=7b004d5430303533393132303938&metadataid[]=7b004d5430303533393132303934&metadataid[]=7b004d5430303533393132303933&metadataid[]=7b004d5430303533393132313032&metadataid[]=7b004d5430303533393132303939&metadataid[]=6100313735303035303230343237333633&metadataid[]=6100313735303035303230343237333634&metadataid[]=6100313735303035303230343237333635&metadataid[]=7c004d4330303032333933363433&metadataid[]=7c004d4330303032333935323932
11/27 16:13:45 Trace: [dbperf] flush 0 bytes, 0 ops in 2 ms (cumulative 1734054648 bytes, 659001 ops in 156081 ms)
**11/27 16:13:45 Trace: [metadatasvc] GOT [1100] (120ms) Sooloos.Msg.Metadata.GetMetadataResponse: **
11/27 16:13:45 Info: [updatemetadata] advancing metadata timestamp on 51 tracks
11/27 16:13:45 Trace: [library/compute] computing 8 tracks
11/27 16:13:45 Trace: [dbperf] flush 390371 bytes, 133 ops in 11 ms (cumulative 1734445019 bytes, 659134 ops in 156092 ms)
11/27 16:13:45 Trace: [roonapi] [apiclient 192.168.1.24:52906] CONTINUE Changed {“zones_seek_changed”:[{“zone_id”:“1601b610afefb77513b8c154e45991cf80cb”,“queue_time_remaining”:2908,“seek_position”:69}]}
11/27 16:13:45 Trace: [library] finished with 185 dirty tracks 17 dirty albums 30 dirty performers 74 dirty works 86 dirty performances 19 dirty genres 0 clumping tracks, 0 clumping auxfiles 8 compute tracks, 0 deleted tracks, 54 tracks to (re)load, 0 tracks to retain, 0 auxfiles to (re)load, 0 auxfiles to retain, and 360 changed objects
11/27 16:13:45 Trace: [library] endmutation in 526ms
11/27 16:13:45 Trace: [metadatasvc] REQ [1101] https://metadataserver.roonlabs.net/md/4/updatemetadata?uid=4d35e36f-9f3c-424b-a5fd-5cb28ff8bb7a&lid=&token=d8fbdaeb-06cf-420f-a289-65b09393cbcb&metadataid[]=7b004d5430303533353434383930&metadataid[]=7b004d5430303533353434383834&metadataid[]=7b004d5430303533353434383835&metadataid[]=7b004d5430303533353434383833&metadataid[]=7b004d5430303533353434383931&metadataid[]=7b004d5430303533353434383837&metadataid[]=7b004d5430303533353434383838&metadataid[]=7b004d5430303533353434383836&metadataid[]=7b004d5430303533353434383839&metadataid[]=7b004d5430303231363539343132&metadataid[]=7b004d5430303231363538343332&metadataid[]=7b004d5430303332363134383834&metadataid[]=7b004d5430303239333831393035&metadataid[]=7b004d5430303231363539313239&metadataid[]=7b004d5430303231363538363333&metadataid[]=7b004d5430303330393032303136&metadataid[]=7b004d5430303231363539343636&metadataid[]=7b004d5430303231363539323239&metadataid[]=7b004d5430303231363539313733&metadataid[]=7b004d5430303231363539323932&metadataid[]=7b004d5430303236303331323234&metadataid[]=7b004d5430303237363233373036&metadataid[]=7b004d5430303231363539353830&metadataid[]=7b004d5430303231363539333131&metadataid[]=7b004d5430303531313135353438&metadataid[]=7b004d5430303531313135353439&metadataid[]=7b004d5430303531313135353431&metadataid[]=7b004d5430303531313135353437&metadataid[]=7b004d5430303531313135353433&metadataid[]=7b004d5430303531313135353434&metadataid[]=7b004d5430303531313135353432&metadataid[]=7b004d5430303531313135353436&metadataid[]=7b004d5430303531313135353435&metadataid[]=7b004d5430303231363538353835&metadataid[]=7b004d5430303231363534313539&metadataid[]=7b004d5430303237363338373532&metadataid[]=7b004d5430303231363534353433&metadataid[]=6100313630353732393138363439303634&metadataid[]=6100313630353732393138363439303633&metadataid[]=6100313630353732393138363439303630&metadataid[]=6100313630353732393138363439303632&metadataid[]=6100313630353732393138363439303635&metadataid[]=6100313630353732393138363439303631&metadataid[]=7b004d5430303231353538363137&metadataid[]=7b004d5430303231353538333938&metadataid[]=7b004d5430303239333836313638&metadataid[]=7b004d5430303332363431393832&metadataid[]=7b004d5430303231353636303734&metadataid[]=7b004d5430303231353539333831&metadataid[]=7b004d5430303237353438373036&metadataid[]=7b004d5430303231353538393131&metadataid[]=79004d5730303032393631303132&metadataid[]=79004d5730303031343230383439&metadataid[]=79004d5730303032363630333839&metadataid[]=79004d5730303031373939383639&metadataid[]=3e012d05f291707ade478f3814274fe107fc&metadataid[]=79004d5730303031383035383339
**11/27 16:13:46 Trace: [metadatasvc] GOT [1101] (143ms) Sooloos.Msg.Metadata.UpdateMetadataResponse: **
11/27 16:13:46 Trace: [metadatasvc] REQ [1102] https://metadataserver.roonlabs.net/md/4/getmetadata?uid=4d35e36f-9f3c-424b-a5fd-5cb28ff8bb7a&lid=&token=d8fbdaeb-06cf-420f-a289-65b09393cbcb&metadataid[]=7b004d5430303533353434383930&metadataid[]=7a004d4e30303032323136363635&metadataid[]=7c004d4330303032333638383030&metadataid[]=79004d5730303032393631303132&metadataid[]=5e0193a54effb9d6ab48bc2251df07f4f92a&metadataid[]=7a004d4e30303032323637363131&metadataid[]=7b004d5430303533353434383834&metadataid[]=7c004d4330303032333636383133&metadataid[]=7b004d5430303533353434383835&metadataid[]=7b004d5430303533353434383833&metadataid[]=7b004d5430303533353434383931&metadataid[]=7b004d5430303533353434383837&metadataid[]=7b004d5430303533353434383838&metadataid[]=7b004d5430303533353434383836&metadataid[]=7b004d5430303533353434383839&metadataid[]=7b004d5430303231363539343132&metadataid[]=7a004d4e30303030313332323431&metadataid[]=79004d5730303031343230383439&metadataid[]=7b004d5430303231363538343332&metadataid[]=7b004d5430303332363134383834&metadataid[]=7b004d5430303239333831393035&metadataid[]=7b004d5430303231363539313239&metadataid[]=7b004d5430303231363538363333&metadataid[]=7b004d5430303330393032303136&metadataid[]=7b004d5430303231363539343636&metadataid[]=7b004d5430303231363539323239&metadataid[]=7c004d4330303032343135363531&metadataid[]=7b004d5430303231363539313733&metadataid[]=7c004d4330303032333635383837&metadataid[]=7b004d5430303231363539323932&metadataid[]=7b004d5430303236303331323234&metadataid[]=7c004d4330303032343238303536&metadataid[]=7b004d5430303237363233373036&metadataid[]=7b004d5430303231363539353830&metadataid[]=7b004d5430303231363539333131&metadataid[]=7b004d5430303531313135353438&metadataid[]=7c004d4330303032333736353932&metadataid[]=7b004d5430303531313135353439&metadataid[]=7b004d5430303531313135353431&metadataid[]=7b004d5430303531313135353437&metadataid[]=7b004d5430303531313135353433&metadataid[]=7b004d5430303531313135353434&metadataid[]=7b004d5430303531313135353432&metadataid[]=7c004d4330303032363131313638&metadataid[]=7b004d5430303531313135353436&metadataid[]=7b004d5430303531313135353435&metadataid[]=7b004d5430303231363538353835&metadataid[]=79004d5730303031373939383639&metadataid[]=7a004d4e30303030373532383832&metadataid[]=7b004d5430303231363534313539&metadataid[]=7b004d5430303237363338373532&metadataid[]=7b004d5430303231363534353433&metadataid[]=6100313630353732393138363439303634&metadataid[]=64017444a75ad18eb9a025944771c50b9883&metadataid[]=3e012d05f291707ade478f3814274fe107fc&metadataid[]=6100313630353732393138363439303633&metadataid[]=6100313630353732393138363439303630&metadataid[]=6401459ce816e22feda55c6f1712d068e9cc&metadataid[]=6100313630353732393138363439303632&metadataid[]=6100313630353732393138363439303635&metadataid[]=6100313630353732393138363439303631&metadataid[]=6401d5b4446d0d08ba5e82f9161f3a100f37&metadataid[]=7b004d5430303231353538363137&metadataid[]=5e01d4d7e2732410114cb97b037cd323c34b&metadataid[]=7a004d4e30303031363337343434&metadataid[]=7a004d4e30303031323436313034&metadataid[]=7a004d4e30303031373337363537&metadataid[]=5e01e9aa8800a8f4d44898c4804757f4c8aa&metadataid[]=5e01b6db048dad8045428a5982ffc682d045&metadataid[]=79004d5730303031383035383339&metadataid[]=7b004d5430303231353538333938&metadataid[]=7b004d5430303239333836313638&metadataid[]=7b004d5430303332363431393832&metadataid[]=7b004d5430303231353636303734&metadataid[]=7b004d5430303231353539333831&metadataid[]=7b004d5430303237353438373036&metadataid[]=7b004d5430303231353538393131
11/27 16:13:46 Trace: [dbperf] flush 0 bytes, 0 ops in 5 ms (cumulative 1734445019 bytes, 659134 ops in 156097 ms)
**11/27 16:13:46 Trace: [metadatasvc] GOT [1102] (195ms) Sooloos.Msg.Metadata.GetMetadataResponse: **
11/27 16:13:46 Info: [updatemetadata] advancing metadata timestamp on 51 tracks
11/27 16:13:46 Trace: [library/compute] computing 20 tracks
11/27 16:13:46 Trace: [dbperf] flush 543644 bytes, 207 ops in 17 ms (cumulative 1734988663 bytes, 659341 ops in 156114 ms)
11/27 16:13:46 Trace: [roonapi] [apiclient 192.168.1.24:52906] CONTINUE Changed {“zones_seek_changed”:[{“zone_id”:“1601b610afefb77513b8c154e45991cf80cb”,“queue_time_remaining”:2907,“seek_position”:70}]}
11/27 16:13:46 Trace: [library] finished with 464 dirty tracks 29 dirty albums 61 dirty performers 142 dirty works 152 dirty performances 17 dirty genres 0 clumping tracks, 0 clumping auxfiles 20 compute tracks, 0 deleted tracks, 56 tracks to (re)load, 0 tracks to retain, 0 auxfiles to (re)load, 0 auxfiles to retain, and 856 changed objects
11/27 16:13:46 Trace: [library] endmutation in 519ms

These are the Core logs pertaining to the period after moving the Core from the laptop to the PC:

Maybe a pop album containing 10 tracks would take 20 seconds but not much less.
However, I owe you an upate:
Some two days ago, I have relocated the Core from the i5 Windows laptop back to my desktop (i7 Windows PC) again. Since then performance has been much better. Committing to the database (“Save”) may take a second, perhaps sometimes two, but it is completely workable now. Somehow I don’t believe this difference in performance can be attributed solely to the difference between the i5 and the i7 processors. Perhaps some other factors play a role, such as the fact that I had (and still have) the Roon Extensions manager service running on the laptop. Your thoughts, please?

Hello,

Once in a while and totally out of the blue (at least so it seems to me), Roon starts with “Applying Library Settings”. I notice that because the spinning wheel starts turning and when I click on it, I get to see this:


The PC then is quite busy, especially the GPU:

Tonight again I have just noticed that the spinning wheel had started again and out of curiosity checked the current log. I found this entry of some 40 minutes ago:

12/01 23:19:46 Info: [bgwork] begin bg operation applying_library_settings @ 8/10

Now I have been in this situation quite a few times before, and using Roon for playing music has proven quite unreliable while it was busy “Applying Library Settings”. And I have also found that restarting the Roon Core plus Windows Remote Client (they both reside on my Windows i7, 16 GB RAM PC for the time being) was the only way to end this “Applying Library Settings”. Apparently it wasn’t needed after all?

Now my questions are:

  1. Does Roon start this “Applying Library Settings” action all by itself? Or is it triggered by something I did?
  2. Will it ever stop when left to its own devices? (I have the distinct impression that it will not, because I have never seen the blue progress bar reach completion, in fact the nearer to completion it gets, the slower the progress becomes…)
  3. As I have not changed any library settings in the past few days, except for playing around with the metadata preferences settings for one album, what in the world is Roon doing “Applying Library Settings”? Surely the metadata preferences of one album do not influence the rest of Roon’s database?
  4. What does “@ 8/10” mean in the log entry?

Notes:
I have over 217,000 tracks
Up until today have always had to restart the Roon core to be able to use Roon in an acceptably responsive manner again, after it had started the aforementioned action.

Part of the log showing lots of small changes to the library being made
(Are these representations of the “Applying Library Settings” process?):

12/01 23:20:42 Trace: [library] endmutation in 719ms
12/01 23:20:42 Trace: [library] endmutation in 13ms
12/01 23:20:42 Trace: [library] endmutation in 38ms
12/01 23:20:42 Trace: [library] endmutation in 15ms
12/01 23:20:42 Trace: [library] endmutation in 14ms
12/01 23:20:42 Trace: [library] endmutation in 17ms
12/01 23:20:42 Trace: [library] endmutation in 26ms
12/01 23:20:43 Trace: [library] endmutation in 11ms
12/01 23:20:43 Trace: [library] endmutation in 19ms
12/01 23:20:43 Trace: [library] endmutation in 11ms
12/01 23:20:43 Trace: [library] endmutation in 11ms
12/01 23:20:43 Trace: [library] endmutation in 13ms
12/01 23:20:43 Trace: [library] endmutation in 11ms
12/01 23:20:43 Trace: [library] endmutation in 12ms
12/01 23:20:43 Trace: [library] endmutation in 105ms
12/01 23:20:43 Trace: [library] endmutation in 19ms
12/01 23:20:43 Trace: [library] endmutation in 60ms
12/01 23:20:43 Trace: [library] endmutation in 29ms
12/01 23:20:43 Trace: [library] endmutation in 34ms
12/01 23:20:43 Trace: [library] endmutation in 14ms
12/01 23:20:43 Trace: [library] endmutation in 17ms
12/01 23:20:43 Trace: [library] endmutation in 11ms
12/01 23:20:43 Trace: [library] endmutation in 17ms
12/01 23:20:44 Trace: [library] endmutation in 24ms
12/01 23:20:44 Trace: [library] endmutation in 11ms
12/01 23:20:44 Trace: [library] endmutation in 31ms
12/01 23:20:44 Trace: [library] endmutation in 14ms
12/01 23:20:44 Trace: [library] endmutation in 18ms
12/01 23:20:44 Trace: [library] endmutation in 13ms
12/01 23:20:44 Trace: [library] endmutation in 17ms
12/01 23:20:44 Trace: [library] endmutation in 13ms
12/01 23:20:44 Trace: [library] endmutation in 16ms
12/01 23:20:44 Trace: [library] endmutation in 13ms
12/01 23:20:44 Trace: [library] endmutation in 31ms
12/01 23:20:44 Trace: [library] endmutation in 14ms
12/01 23:20:45 Trace: [library] endmutation in 28ms
12/01 23:20:45 Trace: [library] endmutation in 12ms
12/01 23:20:45 Trace: [library] endmutation in 14ms
12/01 23:20:45 Trace: [library] endmutation in 39ms
12/01 23:20:45 Trace: [library] endmutation in 18ms
12/01 23:20:45 Trace: [library] endmutation in 13ms
12/01 23:20:45 Trace: [library] endmutation in 14ms
12/01 23:20:46 Trace: [library] endmutation in 12ms
12/01 23:20:46 Trace: [library] endmutation in 11ms
12/01 23:20:46 Trace: [library] endmutation in 22ms
12/01 23:20:46 Trace: [library] endmutation in 16ms
12/01 23:20:46 Trace: [library] endmutation in 96ms
12/01 23:20:46 Trace: [library] endmutation in 90ms
12/01 23:20:46 Trace: [library] endmutation in 26ms
12/01 23:20:46 Trace: [library] endmutation in 18ms
12/01 23:20:46 Trace: [library] endmutation in 16ms
12/01 23:20:47 Trace: [library] endmutation in 20ms
12/01 23:20:47 Trace: [library] endmutation in 20ms
12/01 23:20:47 Trace: [library] endmutation in 15ms
12/01 23:20:47 Trace: [library] endmutation in 19ms
12/01 23:20:47 Trace: [library] endmutation in 14ms
12/01 23:20:47 Trace: [library] endmutation in 18ms
12/01 23:20:47 Trace: [library] endmutation in 55ms
12/01 23:20:47 Trace: [library] endmutation in 59ms
12/01 23:20:47 Trace: [library] endmutation in 11ms
12/01 23:20:47 Trace: [library] endmutation in 33ms
12/01 23:20:47 Trace: [library] endmutation in 14ms
12/01 23:20:47 Trace: [library] endmutation in 15ms
12/01 23:20:47 Trace: [library] endmutation in 16ms
12/01 23:20:48 Trace: [library] endmutation in 21ms
12/01 23:20:48 Trace: [library] endmutation in 14ms
12/01 23:20:48 Trace: [library] endmutation in 91ms
12/01 23:20:48 Trace: [library] endmutation in 11ms
12/01 23:20:48 Trace: [library] endmutation in 11ms
12/01 23:20:48 Trace: [library] endmutation in 34ms
12/01 23:20:48 Trace: [library] endmutation in 20ms
12/01 23:20:48 Trace: [library] endmutation in 12ms
12/01 23:20:49 Trace: [library] endmutation in 11ms
12/01 23:20:49 Trace: [library] endmutation in 11ms
12/01 23:20:49 Trace: [library] endmutation in 20ms
12/01 23:20:49 Trace: [library] endmutation in 15ms
12/01 23:20:49 Trace: [library] endmutation in 99ms
12/01 23:20:49 Trace: [library] endmutation in 32ms
12/01 23:20:49 Trace: [library] endmutation in 64ms
12/01 23:20:49 Trace: [library] endmutation in 14ms
12/01 23:20:49 Info: [importstatus] notifying 11 imports completed
12/01 23:20:49 Trace: [library] endmutation in 13ms
12/01 23:20:49 Trace: [library] endmutation in 14ms
12/01 23:20:49 Trace: [library] endmutation in 18ms
12/01 23:20:49 Trace: [library] endmutation in 11ms
12/01 23:20:50 Trace: [library] endmutation in 29ms
12/01 23:20:50 Trace: [library] endmutation in 16ms
12/01 23:20:50 Trace: [library] endmutation in 15ms
12/01 23:20:50 Trace: [library] endmutation in 90ms
12/01 23:20:50 Trace: [library] endmutation in 14ms
12/01 23:20:50 Trace: [library] endmutation in 14ms
12/01 23:20:50 Trace: [library] endmutation in 11ms
12/01 23:20:50 Trace: [library] endmutation in 11ms
12/01 23:20:50 Trace: [library] endmutation in 11ms
12/01 23:20:50 Trace: [library] endmutation in 70ms
12/01 23:20:50 Trace: [analysis] analysis completed in 9198ms for 193s of FLAC 48kHz 24bit audio. loudness=-15,4558463836025LUFS dbTP=-0,968301488370507 noisestartms=286 noiseendms=189306 isdts=False mqa=0 for track 57170994 url=M:\1_KLAS\ZZ_Verzamel\Viool\Paganini & Schubert- Works for Violin & Piano [24-48] (Vilde Frang, Michail Lifits 2019)\08 D 895; Andante -.flac
12/01 23:20:50 Trace: [library] finished with 1 dirty tracks 1 dirty albums 3 dirty performers 1 dirty works 1 dirty performances 0 clumping tracks, 0 clumping auxfiles 0 compute tracks, 0 deleted tracks, 1 tracks to (re)load, 0 tracks to retain, 0 auxfiles to (re)load, 0 auxfiles to retain, and 7 changed objects
12/01 23:20:50 Trace: [dbperf] flush 5605 bytes, 2 ops in 0 ms (cumulative 16118811 bytes, 8649 ops in 269387 ms)
12/01 23:20:50 Trace: [library] endmutation in 120ms
12/01 23:20:50 Trace: [analysis] analyzing trackid=57171250 url=M:\1_KLAS\ZZ_Verzamel\Viool\Paganini & Schubert- Works for Violin & Piano [24-48] (Vilde Frang, Michail Lifits 2019)\09 D 895; Allegro.flac
12/01 23:20:50 Trace: [library] endmutation in 18ms
12/01 23:20:51 Trace: [library] endmutation in 12ms
12/01 23:20:51 Trace: [library] endmutation in 11ms
12/01 23:20:51 Trace: [library] endmutation in 11ms
12/01 23:20:51 Trace: [library] endmutation in 12ms
12/01 23:20:51 Trace: [library] endmutation in 14ms
12/01 23:20:51 Trace: [library] endmutation in 11ms
12/01 23:20:51 Trace: [library] endmutation in 24ms
12/01 23:20:51 Trace: [library] endmutation in 11ms
12/01 23:20:51 Trace: [library] endmutation in 12ms
12/01 23:20:51 Trace: Successful POST response from https://push.roonlabs.com/push/1/connect
12/01 23:20:51 Trace: [push] connecting to 34.73.93.77:9200
12/01 23:20:51 Trace: [library] endmutation in 12ms
12/01 23:20:51 Trace: [push] connected
12/01 23:20:51 Trace: [library] endmutation in 11ms
12/01 23:20:51 Trace: [library] endmutation in 29ms
12/01 23:20:51 Trace: [library] endmutation in 11ms
12/01 23:20:51 Trace: [library] endmutation in 13ms
12/01 23:20:51 Trace: [library] endmutation in 11ms
12/01 23:20:51 Trace: [analysis] analysis completed in 10534ms for 209s of FLAC 48kHz 24bit audio. loudness=-25,6520978808178LUFS dbTP=-9,05639186435067 noisestartms=338 noiseendms=204958 isdts=False mqa=0 for track 57169458 url=M:\1_KLAS\ZZ_Verzamel\Viool\Paganini & Schubert- Works for Violin & Piano [24-48] (Vilde Frang, Michail Lifits 2019)\02 D 934; Andante molto -.flac
12/01 23:20:52 Trace: [library] finished with 1 dirty tracks 1 dirty albums 3 dirty performers 1 dirty works 1 dirty performances 0 clumping tracks, 0 clumping auxfiles 0 compute tracks, 0 deleted tracks, 1 tracks to (re)load, 0 tracks to retain, 0 auxfiles to (re)load, 0 auxfiles to retain, and 7 changed objects
12/01 23:20:52 Trace: [dbperf] flush 5628 bytes, 2 ops in 0 ms (cumulative 16124439 bytes, 8651 ops in 269387 ms)
12/01 23:20:52 Trace: [library] endmutation in 113ms
12/01 23:20:52 Trace: [analysis] analyzing trackid=57171506 url=M:\1_KLAS\ZZ_Verzamel\Viool\Paganini & Schubert- Works for Violin & Piano [24-48] (Vilde Frang, Michail Lifits 2019)\10 Cantabile in D Major, Op. 17, MS 109.flac
12/01 23:20:52 Trace: [library] endmutation in 12ms
12/01 23:20:52 Trace: [library] endmutation in 26ms
12/01 23:20:52 Trace: [library] endmutation in 23ms
12/01 23:20:52 Trace: [library] endmutation in 16ms
12/01 23:20:52 Trace: [library] endmutation in 12ms
12/01 23:20:52 Trace: [library] endmutation in 17ms
12/01 23:20:52 Trace: [library] endmutation in 11ms
12/01 23:20:52 Trace: [library] endmutation in 13ms
12/01 23:20:53 Trace: [library] endmutation in 21ms
12/01 23:20:53 Trace: [library] endmutation in 13ms
12/01 23:20:53 Trace: [library] endmutation in 11ms
12/01 23:20:53 Trace: [library] endmutation in 14ms
12/01 23:20:53 Trace: [library] endmutation in 21ms
12/01 23:20:53 Trace: [analysis] analysis completed in 12417ms for 270s of FLAC 48kHz 24bit audio. loudness=-15,2667625423507LUFS dbTP=-0,46413295020357 noisestartms=0 noiseendms=259350 isdts=False mqa=0 for track 57170226 url=M:\1_KLAS\ZZ_Verzamel\Viool\Paganini & Schubert- Works for Violin & Piano [24-48] (Vilde Frang, Michail Lifits 2019)\05 D 934; Allegro vivace - Allegretto - Presto.flac
12/01 23:20:53 Trace: [library] finished with 1 dirty tracks 1 dirty albums 3 dirty performers 1 dirty works 1 dirty performances 0 clumping tracks, 0 clumping auxfiles 0 compute tracks, 0 deleted tracks, 1 tracks to (re)load, 0 tracks to retain, 0 auxfiles to (re)load, 0 auxfiles to retain, and 7 changed objects
12/01 23:20:53 Trace: [dbperf] flush 5831 bytes, 2 ops in 0 ms (cumulative 16130270 bytes, 8653 ops in 269387 ms)
12/01 23:20:53 Trace: [library] endmutation in 91ms
12/01 23:20:53 Trace: [analysis] analyzing trackid=57171762 url=M:\1_KLAS\ZZ_Verzamel\Viool\Paganini & Schubert- Works for Violin & Piano [24-48] (Vilde Frang, Michail Lifits 2019)\11 Grand Caprice (Naar Schuberts 'Der Erlkönig', D 328), Op.26.flac
12/01 23:20:53 Trace: [library] endmutation in 18ms
12/01 23:20:54 Trace: [library] endmutation in 32ms
12/01 23:20:54 Trace: [library] endmutation in 21ms
12/01 23:20:55 Trace: [library] endmutation in 28ms
12/01 23:20:55 Trace: [library] endmutation in 12ms
12/01 23:20:55 Trace: [library] endmutation in 13ms
12/01 23:20:55 Trace: [library] endmutation in 11ms
12/01 23:20:55 Trace: [library] endmutation in 11ms
12/01 23:20:55 Trace: [library] endmutation in 22ms
12/01 23:20:55 Trace: [library] endmutation in 13ms
12/01 23:20:55 Trace: [library] endmutation in 93ms
12/01 23:20:56 Trace: [library] endmutation in 12ms
12/01 23:20:56 Trace: [library] endmutation in 18ms
12/01 23:20:56 Trace: [analysis] analysis completed in 14718ms for 314s of FLAC 48kHz 24bit audio. loudness=-15,8954761538776LUFS dbTP=-0,448794609186864 noisestartms=416 noiseendms=313092 isdts=False mqa=0 for track 57169714 url=M:\1_KLAS\ZZ_Verzamel\Viool\Paganini & Schubert- Works for Violin & Piano [24-48] (Vilde Frang, Michail Lifits 2019)\03 D 934; Allegretto -.flac
12/01 23:20:56 Trace: [library] finished with 1 dirty tracks 1 dirty albums 3 dirty performers 1 dirty works 1 dirty performances 0 clumping tracks, 0 clumping auxfiles 0 compute tracks, 0 deleted tracks, 1 tracks to (re)load, 0 tracks to retain, 0 auxfiles to (re)load, 0 auxfiles to retain, and 7 changed objects
12/01 23:20:56 Trace: [dbperf] flush 5603 bytes, 2 ops in 0 ms (cumulative 16135873 bytes, 8655 ops in 269387 ms)
12/01 23:20:56 Trace: [library] endmutation in 94ms
12/01 23:20:56 Trace: [library] endmutation in 15ms
12/01 23:20:56 Trace: [library] endmutation in 15ms
12/01 23:20:56 Trace: [library] endmutation in 11ms
12/01 23:20:56 Trace: [library] endmutation in 13ms
12/01 23:20:56 Info: [stats] 14724mb Virtual, 3559mb Physical, 2293mb Managed, 2757 Handles, 90 Threads
12/01 23:20:56 Trace: [library] endmutation in 11ms
12/01 23:20:56 Trace: [library] endmutation in 11ms
12/01 23:20:57 Trace: [library] endmutation in 31ms
12/01 23:20:57 Trace: [analysis] analysis completed in 15605ms for 301s of FLAC 48kHz 24bit audio. loudness=-17,7865730071525LUFS dbTP=-0,466711642510865 noisestartms=286 noiseendms=289302 isdts=False mqa=0 for track 57170738 url=M:\1_KLAS\ZZ_Verzamel\Viool\Paganini & Schubert- Works for Violin & Piano [24-48] (Vilde Frang, Michail Lifits 2019)\07 S427; Valse Caprice Nr.6 in a; Allegro con strepito (naar Schuberts Valses noble.flac
12/01 23:20:57 Trace: [library] finished with 1 dirty tracks 1 dirty albums 2 dirty performers 0 clumping tracks, 0 clumping auxfiles 0 compute tracks, 0 deleted tracks, 1 tracks to (re)load, 0 tracks to retain, 0 auxfiles to (re)load, 0 auxfiles to retain, and 4 changed objects
12/01 23:20:57 Trace: [dbperf] flush 6472 bytes, 2 ops in 0 ms (cumulative 16142345 bytes, 8657 ops in 269387 ms)
12/01 23:20:57 Trace: [library] endmutation in 112ms
12/01 23:20:57 Trace: [library] endmutation in 25ms
12/01 23:20:57 Trace: [library] endmutation in 24ms
12/01 23:20:57 Trace: [library] endmutation in 16ms
12/01 23:20:57 Trace: [library] endmutation in 27ms
12/01 23:20:57 Trace: [library] endmutation in 11ms
12/01 23:20:58 Trace: [library] endmutation in 11ms
12/01 23:20:58 Trace: [library] endmutation in 11ms
12/01 23:20:59 Trace: [library] endmutation in 27ms
12/01 23:20:59 Trace: [library] endmutation in 16ms
12/01 23:20:59 Trace: [library] endmutation in 12ms
12/01 23:20:59 Trace: [library] endmutation in 11ms
12/01 23:20:59 Trace: [library] endmutation in 31ms

It’s time to go to bed. Just one more screenshot, taken 50 minutes after the previous one of the progess bar:

EDIT (09:00):
The following morning, some eight hours later, the spinning wheel is still busy and no progress whatsoever has been made:

EDIT (another 2 hours later, 11:00):
The progress bar has actually moved!

EDIT (15:50)
The progress bar has moved again!

EDIT (23:00)
Now it looks like it’s very nearly there!

EDIT (the next day, 15:10)
I can’t see any difference with the day before:

Hi @Hans_Valeton,

I appreciate your patience through this holiday period until your case reached my queue again.

This shouldn’t take this long, can you confirm if you started with a fresh database on the new PC or have you restored the existing database from the i5 to the i7?

I recall that there were some problematic traces I saw in your last Core, and we thought that this was due to the VPN, but now I’m wondering if there are deeper issues here.

I would like to propose a test here, which is to set the database aside and import the content as fresh. Once you have done so, can you let me know if you are seeing similar issues and delays? You can use these instructions to do so:

Hello @noris,

Thanks for your reply.

“This” meaning the “Applying Library Settings” process? An if so, could you please answer the first and third questions in my previous post:

Which traces where those?

I hesitate to do this, because of the many hours I have already spent in grooming the Core database.
Or do you suggest I reinstate the current database (via a backup restore) after we’re done testing?

And how long should this test take? It’s not clear to me if the application of library settings is a case of “normal maintenance”, business as usual so to speak, done once every so many days, or that it is in my case rogue behaviour?

Would it be useful to start testing with just a small part of my Flac library in a watched folder? Perhaps that way we could get our test results sooner? I seem to remember that all of the twoo weeks (and some days more) of my free trial were spent waiting for Roon to scan my Flac library, perform the background audio analysis and the application of the library settings. So you can imagine I’m not all that keen on doing that all over again.
By the way: I started my free trial with the Roon Core as well as the Remote Client on my i7 PC. Only later, after it had become stable did I move the Core to my laptop.
Would it be wise to install Roon differently, this time? I read somewhere that it would improve performance if the Roon Server is first installed and the Client is installed later (on the same machine). Can you confirm that?
I do seem to remember that, when starting out the first time, the GPU usage was enormous during the first two weeks. And the GPU is only connected to the Windows Client, is it not?

I started with a restore of the core database backup that I made on my i5 laptop.

Hi @Hans_Valeton,

I wanted to escalate your case a bit, so appreciate your patience until I had a chance to discuss your case with the technical team. We reviewed the case and I have some feedback for you:

  1. We should choose just one specific issue to focus on at a time, I suggest that we focus on the applying library settings taking a while.

  2. Since you have quite a large database it would be unexpected to take a long time to apply library settings if the machine were dedicated just to Roon. Since this appears to be a multi-purpose machine, it is possible that it would take longer.

  3. It is still not clear what exactly the effect of the VPN is on the system here. If possible, we would suggest to completely disable this aspect just to remove some variables from the equation.

  4. The CPU behavior you noticed might be due to listening to music at the same time as trying to make the changes to your library. Playing music requires CPU power, as does making changes to the database, the combination of both might have triggered the CPU usage you were seeing.

  5. You mentioned that rebooting your Core often gets you out of the “Applying Library Settings” state. The only way we will know if the progress bar actually ends as expected would be by letting Roon try to complete this process over an extended period of time, such as a week or so. If the behavior still does not end after a week, the logs would provide much more useful information as to what is going on. I know you mentioned you spent two weeks waiting for import to complete, but at which stage was your library at that point, in the “Applying library settings” stage or in the importing music/analysis stage?

I brought up the test I/you proposed earlier of using a smaller subset of tracks and the technical team has noted that when you library grows to it’s current track limit again it might re-occur since the smaller subset might not have the same database needs as the big subset does.

Yes, RoonServer wouldn’t use the GPU since it doesn’t have an interface. The Roon App however does. If you want, you can try restoring your database to RoonServer to see if it helps.

Hi @noris,

Monday, 12/09/2019 12h45:
Too many variables, I’m starting from scratch.
Just now I’ve uninstalled everything Roon from both my PC and my laptop.
Then I installed RoonServer on my PC, followed by the Roon client, both 64 bit.
The watched folders are:


which amounts to my entire collection minus some “various” stuff, that are of no importance anyway and make up only a very tiny portion of my library.

I have not yet installed the extensions manager on any machine, which I had previously running on my laptop.
I will keep you posted.
Monday, 12/09/2019 13h01:

Monday, 12/09/2019 13h37:


Monday, 12/09/2019 15h03:

Monday, 12/09/2019 15h10:
Just noticed a discrepancy between the number of unidentified albums (348) and the fact that the spinning wheel activity pop-up screen says that the number of added and identified tracks is the same (9714). How is that possible?:

Monday, 12/09/2019 16h34:

Monday, 12/09/2019 20h43:

Monday, 12/09/2019 23h30:

Tuesday, 12/10/2019 09h55:

Tuesday, 12/10/2019 14h03:

Tuesday, 12/10/2019 16h23:
Yippie, we’re halfway:

Tuesday, 12/10/2019 21h00:
I’ve had to restart my PC (at about 19h30) for an unrelated reason, and so now the counters look a bit different…

Wednesday, 12/11/2019 10h40:

The eight cores of the i7 (slightly overclocked for the period of building the Core database) can just about keep up with the demand:

Wednesday, 12/11/2019 19h30:

Thursday, 12/12/2019 12h48:
Finally! Completion!

I have made a backup immediately after the ingestion of the library had completed.
And now I guess I’ll have to wait and see if Roon will start never-ending “Applying Library Setting” actions, or not…

Roon’s import library settings on the new likely differ from the old (Roon installs have default config options).

In order to apply those settings Roon in effect needs to rescan every file and update its database to reflect these settings. I takes ages to run a DB update like this - so learned the hard way to check import settings before ingesting a library.

Thanks, @evand, I have indeed learned the same lesson. As you can see I have just started anew from scratch and the first thing after starting up was set import setttings the way I want them.

Unfortunately I had forgotten to set the option “Use genres extracted from file tags” to “Yes”.
image
So now, Wednesday 12/12/2019 16h09, I’m looking at:


I’m very curious how long this will take. On the positive side: at least this time I know where the “Applying Library Settings” is coming from, since I started it myself!

Update:
Just a few minutes later, the action has already finished! Attaboy!

Hi @Hans_Valeton,

Thanks for starting from scratch, it looks like applying library settings is much better this time around!

Ok, so we have confirmed that the new database has imported all the tracks properly and applying library settings only takes a few minutes now on the new database, which is a great sign. I’m not quite sure where this leaves up as for next steps. Would you be content with using the database in it’s current form?

It seems like there is something going on with the old database, triggering this behavior. If you’re happy with continuing to use the new database, we can go ahead and close this case, but if you have further questions do let me know. Thanks!

Hi @noris, thanks for your reply.

Well, let’s not celebrate too soon! The troubles I had with the “Applying Lbrary Settings” always occurred when Roon started this action all by itself, NOT instigated by me. So I think it’s wise to wait for
at least a week and see if those rogue processes are a thing of the past now.

I am in two minds about this. I did already invest a lot of time in my previous database, identifying at least some huindreds of the more than 3000 unidentified albums.
Would it be safe to restore the latest backup I made of the old database and just see what happens then? I could always go back to the new database, having made a backup of the current one.
Your thoughts, please!

This is a link to the 54 log files that were written during the ingestion of my library into the new Core database as well as the first application of (altered) library settings.
I did have to move the log files, say ten at a time, to a seperate folder in order to prevent them from being overwritten, and afterwards renamed them, preserving the original order.


Please let me know if the link doesn’t work. I have just redone my Dropbox settings and am not sure if it all works out.

Hello @Hans_Valeton,

Doesn’t sound like a bad idea to me, I would keep the current database and see if is still remains stable.

You might want to set the current database aside instead of overwriting it, you can use similar instructions to Roon_old that we did except instead of calling it Roon_old you can call it Roon_stable or something similar.

I’m not quite sure what to do with these logs. I might be useful to have, but from what you have mentioned the current database is behaving as expected, right? The link Dropbox link works as expected though so your settings in that regard seem good :+1:

I just thought they might come in handy and be compared to the older ones you received from me in which you saw some disturbing “traces”?

Okay, so that’s what I’m settled on doing.

Good idea. It’s going to be interesting to try this out in a week or so. I’ll keep you posted!

1 Like

Hi @Hans_Valeton,

Just wanted to let you know I took a look through the new logs, and I’m not seeing any Critical or Name Resolution failures in them that I was seeing in the old log sets, which is a good sign so far. Do let me know how your further testing goes!

Hi @noris,
Thanks for having a look through the logs.
At the moment I’m not usinig Roon very much, because I’ve decided to completely overhaul my collection in terms of tagging. I am hoping that as soon as I have changed all my composer tags from the format “Bach, Johann Sebastian (1685-1750)” to “Johann Sebastian Bach”, Roon will be in a better position to identify my classical albums. And another future project intended to increase the conversion rate from Unidentified to Identified is to change the way I use the Album tag. At the moment my Album tags are filled with “Composer - Composition (Main Performers Year of recording)” and so there mostly are more than one different Album tages within the scope of one fysical folder on the NAS. After starting to use Roon (only two omths ago) I soon realized that having one Album tag for the entire folder might be the better option. Perhaps I also need to translate all of the composition names from Dutch to English…
In short: lots of work to do!
So now most of my time is spent writing scripts for MediaMonkey…
Once all this is finished I will be using Roon a lot more and let you know of any future mishaps (if any) with the application of library settings.

1 Like

This topic was automatically closed 365 days after the last reply. New replies are no longer allowed.