SongKong Jaikoz

SongKong and Jaikoz Music Tagger Community Forum

SongKong batch beeing stuck

Hi Paul,

These days, I’ve been using SongKong a lot for various processing and I experienced multiple issues when processing large amount of files.
So this is not “one off” but appears to be a structural issue.

The attached screenshots come from a batch started with a “fresh” SongKong process (i.e. SongKong exited the relaunched) because the previous batch got stuck, and the new one is still running as I’m writing this report.
At some points, the process consumes all the RAM so I’m even not able to take a screenshot.
The process runs with 12~20% of CPU and up to 11 Mo of RAM. My PC eventually gets stuck.
Then the garbage collector does some cleaning, the RAM used by the process goes down, but no figure increases in the control window. And nothing is logged in the shell window.

What could I do to help the diagnosis?

Regards,
Jérôme

Oh! This may help!

These two lines are repeating endlessly in the log file:

15/05/2021 20.16.45:CEST:FileRenamer:renameSubFolderAndFilenameFromMask:WARNING: New SubFolder/Filename Path is(1):1970\M…\Michael Jackson\Michael Jackson - I Wanna Be Where You Are.mp3
15/05/2021 20.16.45:CEST:SongSaver:checkDuplicatesWithinGrouping:SEVERE: RetryingDupGroup:230930:E:\Musique\#2 Singles classés\1970\M…\Michael Jackson\Michael Jackson - I Wanna Be Where You Are (1).mp3:E:\Musique\#2 Singles classés\1970\M…\Michael Jackson\Michael Jackson - I Wanna Be Where You Are.mp3

Here is the directory content:

E:\Musique\#2 Singles classés\1970\M…\Michael Jackson>dir
 Le volume dans le lecteur E s’appelle Καλλιόπη
 Le numéro de série du volume est DEE9-C7A1

 Répertoire de E:\Musique\#2 Singles classés\1970\M…\Michael Jackson

25/05/2020  23:59    <DIR>          .
25/05/2020  23:59    <DIR>          ..
21/05/2020  20:10            51 252 folder.jpg
15/05/2021  19:16         6 089 495 Michael Jackson - Ain't No Sunshine.mp3
15/05/2021  19:16         4 018 459 Michael Jackson - Ben.mp3
15/05/2021  19:16         5 926 785 Michael Jackson - Don't Stop 'til You Get Enough.mp3
15/05/2021  19:16         4 940 087 Michael Jackson - Got to Be There.mp3
25/05/2020  23:58         6 435 701 Michael Jackson - Greatest Show on Earth.mp3
25/05/2020  23:58         2 969 027 Michael Jackson - I Wanna Be Where You Are (1).mp3
25/05/2020  23:58         4 424 264 Michael Jackson - I Wanna Be Where You Are.mp3
15/05/2021  19:16         9 021 578 Michael Jackson - Maria (You Were the Only One).mp3
15/05/2021  19:16         6 069 640 Michael Jackson - One Day in Your Life.mp3
15/05/2021  19:16         5 950 843 Michael Jackson - Rock With You (1).mp3
15/05/2021  19:16         5 764 451 Michael Jackson - Rock With You.mp3
15/05/2021  19:16         3 736 735 Michael Jackson - Rockin' Robin.mp3
15/05/2021  19:16         3 297 064 Michael Jackson - Shoo-Be-Doo-Be-Doo-Da-Day.mp3
              14 fichier(s)       68 695 381 octets
               2 Rép(s)  1 135 245 647 872 octets libres

E:\Musique\#2 Singles classés\1970\M…\Michael Jackson>

Also, after stopping the bath (that took time and stuck again the PC with memory consumption dramatically increasing), the last error in the report is:

May 15, 2021, 7:59:38 PM

Cancelled class com.jthink.songkong.analyse.analyser.SongSaver:G2980:Michael Jackson: because taken too long

(So this happened before the “looping” error.)

Regards,
Jérôme

Hi, okay I may have fixed this, the issue is with the File save/rename routine and can happen when you actually dont have SongKong set to rename.

Please uninstall SongKong, and redownload and install SongKong 7.3.2. I have uploaded a new version with a single fix so check in Help:About that it now says 01/04/2021 and then retry your test.

Hi Paul,

I updated as explained and the build date is OK.
I may not reproduce exactly as I manually fixed the files (they were duplicate) but I will try and let you know.

What do you mean by “[it] can happen when you actually don’t have SongKong set to rename”?
From my perspective, SongKong was configured to rename files in this batch.

Cheers,
J.

FYI:
I relaunched the processing of the files.
I still observed some random freezing of my PC + memory consumption going like a roller-coaster, but eventually the batch ended normally.

Okay another user reported an issue whereby the renaming function was being called and getting stuck as part of save routine, even though there was no need to run rename because actually Rename Files from Metadata was set to No so that the rename just ended up with the original name. So we fixed this issue in the updated vesion of 7.3.2 shortly after release.

However it seems from what you say then when rename is enabled there can be an issue, which im guessing is related to having multiple duplicate files in the folder. Raised https://jthink.atlassian.net/browse/SONGKONG-2237

Could you try replicate the issue by rerunning against problem batch (since this will still run rename even if already matched) and if you see the slow down then modify debug log settings
in preferences to help us capture exactly where al the processing is going.

Hi Paul,
I’ve sent another debug file tonight.
I performed the batch on a different folder, because the previous one was cleared from the mentioned duplicates, but “as expected”, I got a similar issue, with log files looping on:

18/05/2021 21.33.53:CEST:SongSaver:isAnyFilenameClashesWithExisting:SEVERE: 10290:New Filename Clash:E:\Musique\#2 Singles classés\1980\A…\Axel Bauer\Axel Bauer - Cargo.mp3:For:E:\Musique\#2 Singles classés\1980\A…\Axel Bauer\Axel Bauer - Cargo (1).mp3
18/05/2021 21.33.53:CEST:FileRenamer:renameSubFolderAndFilenameFromMask:WARNING: New SubFolder/Filename Path is(1):1980\A…\Axel Bauer\Axel Bauer - Cargo.mp3
18/05/2021 21.33.53:CEST:SongSaver:checkDuplicatesWithinGrouping:SEVERE: RetryingDupGroup:209712:E:\Musique\#2 Singles classés\1980\A…\Axel Bauer\Axel Bauer - Cargo (1).mp3:E:\Musique\#2 Singles classés\1980\A…\Axel Bauer\Axel Bauer - Cargo.mp3
18/05/2021 21.33.53:CEST:SongSaver:isAnyFilenameClashesWithExisting:SEVERE: 10290:New Filename Clash:E:\Musique\#2 Singles classés\1980\A…\Axel Bauer\Axel Bauer - Cargo.mp3:For:E:\Musique\#2 Singles classés\1980\A…\Axel Bauer\Axel Bauer - Cargo (1).mp3
18/05/2021 21.33.53:CEST:FileRenamer:renameSubFolderAndFilenameFromMask:WARNING: New SubFolder/Filename Path is(1):1980\A…\Axel Bauer\Axel Bauer - Cargo.mp3
18/05/2021 21.33.53:CEST:SongSaver:checkDuplicatesWithinGrouping:SEVERE: RetryingDupGroup:209713:E:\Musique\#2 Singles classés\1980\A…\Axel Bauer\Axel Bauer - Cargo (1).mp3:E:\Musique\#2 Singles classés\1980\A…\Axel Bauer\Axel Bauer - Cargo.mp3
18/05/2021 21.33.53:CEST:SongSaver:isAnyFilenameClashesWithExisting:SEVERE: 10290:New Filename Clash:E:\Musique\#2 Singles classés\1980\A…\Axel Bauer\Axel Bauer - Cargo.mp3:For:E:\Musique\#2 Singles classés\1980\A…\Axel Bauer\Axel Bauer - Cargo (1).mp3
18/05/2021 21.33.53:CEST:FileRenamer:renameSubFolderAndFilenameFromMask:WARNING: New SubFolder/Filename Path is(1):1980\A…\Axel Bauer\Axel Bauer - Cargo.mp3

Report after stop completion
image

Hi, okay I have narrowed the issue down a bit more

I can see in the userlog that is is trying to rename particular files because you have duplicate copies of those files, but every attempt generates the same new filename, and so it continues upto 10 times before giving up

RetryingRename:1:E:\Musique\#2 Singles classés\1980\T…\Timex Social Club\Timex Social Club - Rumors (1).mp3:E:\Musique\#2 Singles classés\1980\T…\Timex Social Club\Timex Social Club - Rumors.mp3
18/05/2021 20.57.32:CEST:SEVERE: RetryingRename:2:E:\Musique\#2 Singles classés\1980\T…\Timex Social Club\Timex Social Club - Rumors (1).mp3:E:\Musique\#2 Singles classés\1980\T…\Timex Social Club\Timex Social Club - Rumors.mp3
18/05/2021 20.57.32:CEST:SEVERE: RetryingRename:8:E:\Musique\#2 Singles classés\1980\T…\Tom Tom Club\Tom Tom Club - Wordy Rappinghood(1).mp3:E:\Musique\#2 Singles classés\1980\T…\Tom Tom Club\Tom Tom Club - Wordy Rappinghood.mp3
18/05/2021 20.57.32:CEST:SEVERE: ++SaveStart:12481:E:\Musique\#2 Singles classés\1980\T…\Tony Carey\Tony Carey - Room With a View.mp3
18/05/2021 20.57.32:CEST:SEVERE: ++SaveComplete:12481:E:\Musique\#2 Singles classés\1980\T…\Tony Carey\Tony Carey - Room With a View.mp3
18/05/2021 20.57.32:CEST:SEVERE: RetryingRename:9:E:\Musique\#2 Singles classés\1980\T…\Tom Tom Club\Tom Tom Club - Wordy Rappinghood(1).mp3:E:\Musique\#2 Singles classés\1980\T…\Tom Tom Club\Tom Tom Club - Wordy Rappinghood.mp3
18/05/2021 20.57.32:CEST:SEVERE: RetryingRename:3:E:\Musique\#2 Singles classés\1980\T…\Timex Social Club\Timex Social Club - Rumors (1).mp3:E:\Musique\#2 Singles classés\1980\T…\Timex Social Club\Timex Social Club - Rumors.mp3
18/05/2021 20.57.32:CEST:SEVERE: >>WorkDone:SongSaver:G7645:Tony Carey:1:99
18/05/2021 20.57.32:CEST:SEVERE: RetryingRename:4:E:\Musique\#2 Singles classés\1980\T…\Timex Social Club\Timex Social Club - Rumors (1).mp3:E:\Musique\#2 Singles classés\1980\T…\Timex Social Club\Timex Social Club - Rumors.mp3
18/05/2021 20.57.32:CEST:SEVERE: >>WorkDone:SongSaver:G7615:Tom Tom Club:1:98
18/05/2021 20.57.32:CEST:SEVERE: RetryingRename:5:E:\Musique\#2 Singles classés\1980\T…\Timex Social Club\Timex Social Club - Rumors (1).mp3:E:\Musique\#2 Singles classés\1980\T…\Timex Social Club\Timex Social Club - Rumors.mp3
18/05/2021 20.57.32:CEST:SEVERE: RetryingRename:6:E:\Musique\#2 Singles classés\1980\T…\Timex Social Club\Timex Social Club - Rumors (1).mp3:E:\Musique\#2 Singles classés\1980\T…\Timex Social Club\Timex Social Club - Rumors.mp3
18/05/2021 20.57.33:CEST:SEVERE: RetryingRename:7:E:\Musique\#2 Singles classés\1980\T…\Timex Social Club\Timex Social Club - Rumors (1).mp3:E:\Musique\#2 Singles classés\1980\T…\Timex Social Club\Timex Social Club - Rumors.mp3`

The reason the filename is always the same is because it tries to modify the album part of your filename mask, but your filename mask has no album field !

I have updated ticket https://jthink.atlassian.net/browse/SONGKONG-2237 and this will certainly be fixed in next SongKong release.

1 Like

Fixed by SongKong 7.4 released 9th June 2021

Hi Paul,
I’m afraid the fix is not perfect.
SongKong report produces unknown errors

##### Jun 10, 2021, 7:43:28 PM
Unknown Error:java.base/java.util.TreeMap$PrivateEntryIterator.nextEntry(TreeMap.java:1206)

and the batch remains stuck.

Support files have been sent.
Let me know if you need any additional information.

J.

Thanks, okay think I have fixed it, just uploaded a new Windows version of SongKong 7.4 for the moment. On Windows because it is same version number you 'll have to actually uninstall existing version, then download and install newly downloaded version.

You can check you have new version by looking at the Help:About window it should say Build Date 10/06/2021, the original version says 09/06/2021

image

Can you let me know if it works please.

Hi Paul,

Unfortunately, it didn’t.
Support files sent again (I emptied the database & logs before launching the batch to ensure a clean log file).
J.

To be clear it fixed the unknown issue but now just seems to be hanging not doing anything ?

Can you increase the debug level please and try again, and maybe leave for longer because in the logs nothing seems to be happening for a period.

Maybe I was impatient, but indeed it appeared stuck.
So I relaunched it with “finest” and went take a shower (it’s very hot in Paris tonight :wink:) and the batch terminated in 2 minutes 57 seconds !
Let’s call it fixed!
Thanks.

Okay but would be useful if you could resend support files in case there is something slowing things down excessively that I could check.