Bugzilla – Bug 8727
MusicIP import failing
Last modified: 2009-07-31 10:24:47 UTC
I am using: SqueezeCenter Version: 7.1 - 21263 @ Fri Jun 27 08:22:07 PDT 2008 - Windows XP - EN - cp1252 and MusicIP Mixer Version: 1.9 I have the automatic rescan plugin enabled in SqueezeCenter and have it set to run every day at 4:00 AM (set to look for "New and Changed Music". Prior to that, I have a job that runs on my computer and adds new files to my MusicIP library. I can see the new files in the MusicIP library (both in the GUI and via the web interface), and I can make mixes off these new files (both in the GUI and via the web interface), but they do not show up as mixable in SqueezeCenter. I have the MusicIP reload interval set to 0 since I don't want the rescan triggered automatically, I want to have it scheduled via the "Automatic Rescan" plugin. However, as you can see from the results of a nightly rescan, MIP is not getting imported: Directory Scan (3 of 3) Complete 01:17:03 Playlist Scan (24 of 24) Complete 00:01:50 Merge Various Artists (6262 of 6262) Complete 00:01:53 Database Cleanup #1 (60989 of 60989) Complete 00:13:27 Database Cleanup #2 Complete 00:01:08 Database Optimize Complete 00:03:17 SqueezeCenter has finished scanning your music collection. 01:38:38 My directory is getting scanned properly, and music that used to be mixable via MIP is still mixable in SqueezeCenter, but recently added tracks (which are mixable via MusicIP directly) are not showing as mixable in SqueezeCenter. When I set the MusicIP reload interval to a number higher than 0, a rescan was triggered immediately, and it did appear to import MusicIP data, but the newly added tracks were still not mixable.
"new and changed" rescans will respect the rescan interval setting. At 0 this means disabled. Since this is nightly, and presumably, while sleeping try using the wipe and rescan option.
Is this a change in 7? In 6.5, when I had the rescan interval set to 0, the nightly "new & changed" still got all the MIP information - that's why I thought this was a bug. Another question: are you recommending I do 1 clear & rescan, or that I have my nightly rescan always clear? Thank you.
Don't know whether this has been changed. But would it work if you set the timeout to something linke 86400 (24h)?
I did a clear & rescan last night (with the MIP reload interval set to 0), and here are the results: Directory Scan (60251 of 60251) Complete 03:44:36 MusicIP Import (1327 of 60124) Running 04:24:21 \\readynas_nv\media\Music\MP3\The Mountain Goats\On Juhu Beach\01 Hotel Road.mp3 ( of ) ( of ) ( of ) ( of ) ( of ) ( of ) ( of ) ( of ) ( of ) SqueezeCenter has finished scanning your music collection.08:08:57 All those empty parentheses above appeared as un-filled dots in the progress bar for MusicIP. Squeezecenter reports that the scan is complete, but as you can see, only 1327 out of the 60124 MIP tracks got imported. I still see many tracks in SqueezeCenter that are not mixable, but which are mixable via MusicIP GUI & web interface. I haven't changed my reload interval yet as this appears to be an issue with the scanner itself - the MIP import is not finishing.
Please upload your server.log
Created attachment 3588 [details] Server & Scanner Logs
Comment on attachment 3588 [details] Server & Scanner Logs Here are my server and scanner logs (I chose "1000 lines" for each). I didn't have any extra debugging enabled during the clear & rescan, please let me know if you want me to run it again with any debug flags. Thank you for your help.
From these logs I only see that MusicIP has gone away at some point. But that was in the afternoon, no message at night. Please set logging for musicip to debug, too, then upload another copy of server.log. Thanks!
(In reply to comment #8) > From these logs I only see that MusicIP has gone away at some point. But that > was in the afternoon, no message at night. > > Please set logging for musicip to debug, too, then upload another copy of > server.log. Thanks! > Michael, just to be clear: what steps do you want me to reproduce when I have musicip debugging turned on? Should I keep the reload interval set to 0? Should I do a full clear & rescan? And is there any other debugging I should enable? Thank you, Jordan
Sorry for the delay. Yes, please run a re-scan (doesn't need to be wipe & rescan). Once this is running fine we'll have to take care of the nightly issue. You seem to be using your music collection stored on a NAS/server. Could you please give me some more detail about your setup?
punting post 7.2
Just got back into town from a long trip - I will run the scan and post my server log later on today or tomorrow. By the way, it appears I'm not the only one having this issue: http://forums.slimdevices.com/showthread.php?p=323233#post323233
Created attachment 3690 [details] Log file This is the log file I generated by doing a scan ("new & changed") starting SqueezeCenter with these settings: "c:\Program Files\SqueezeCenter\server\squeezecenter.exe" --d_musicmagic --d_scan --d_import --logfile=c:\slimserver.log --d_server --d_startup --d_cli
Hello again, I keep my music library on an Infrant ReadyNas NV device, but I am running SqueezeCenter off of my Windows XP PC. I've had it set up this way since I first installed SlimServer 6.2 back in the day. SlimServer/SqueezeCenter accesses the files via this type of path: \\Readynas_nv\media\music\... etc. What else would be helpful for you to know? Thank you.
"Scan Interval set to 0, rescanning disabled" - you seem to have disabled automatic scanning?
(In reply to comment #15) > "Scan Interval set to 0, rescanning disabled" - you seem to have disabled > automatic scanning? > My MusicIP reload interval is set to 0, as noted previously in the bug. When I set it to anything higher, it just kicks off repeated rescans constantly, but they never succeed in importing all the MusicIP tracks. Do you want me to set it to a higher interval and run the scan again? (I had asked that previously but I thought you wanted me to leave it where it was).
The thread you've been refering to has a solution: http://forums.slimdevices.com/showthread.php?p=323233#post323233#10 Do you know that guy in the trenchcoat too? :-) You might also follow up on that thread, as this guy has an idea what was breaking his configuration. We have to find out at which point and why the MusicIP seems to be aborted. We can take care of the nightly scans once you can do a full rescan. > "c:\Program Files\SqueezeCenter\server\squeezecenter.exe" --d_musicmagic > --d_scan --d_import --logfile=c:\slimserver.log --d_server --d_startup --d_cli These parameters don't exist any more in SC7. Please set logging options in Settings/Advanced/Logging. Enable logging for MusicIP and the scan* options. Then run the rescan. I just tested this on my local installation. The reload interval should be irrelevant.
Michael, Thank you for your continued help here - sorry for all the back and forth. I had an old batch file I used to use when I needed to debug & log, but now I see those parameters are useless. I will run the scan again with the debug options turned on that you indicated. I know that I do have some .cue files in my collection, but SS has always played them fine. I don't know if I have any embedded cue files in my tags...not quite sure how to search the collection for those. The import doesn't always seem to break on the same song consistently, so I don't know where to start looking. But I'll scan again with the debug options you indicated and post my new log file. Thank you again.
Created attachment 3705 [details] Server and scanner logs from rescan Ran the rescan with all scan* and MusicIP logging options set to "debug." Zip file contains server.log and 1000 lines of scanner.log.
I just upgraded SC 7.0.1 to SC 7.1.0 (on Win XP SP3). MIP 1.9 MIP Plugin checked. Basic Settings/ Music Folder is blank. Advanced/MIP/Reload Interval set to 0 SC 7.1.0 initiated a "Clear and Rescan" of my library as part of the upgrade. It picked up all 29,000 tracks but did not find the playlists in MusicIP. I restarted the computer, confirmed that I can create a MusicIP mix in SqueezeCenter (in other words the MusicIP plugin works) and then initiated a "rescan playlists only". Again the MusicIP playlists did not appear in SqueezeCentre. SC 7.0.1 picked up the playlists in MusicIP and called them something like "MusicIP Playlist Playlist Name" The workaround is to save the playlists in MIP using the "Save as playlist" function then do a "Rescan playlists only" in SC. To recreate this, make a mix in MIP and name it, then do a "Rescan playlists only"
(In reply to comment #20) > SC 7.1.0 initiated a "Clear and Rescan" of my library as part of the upgrade. > It picked up all 29,000 tracks but did not find the playlists in MusicIP. John, I think you are describing a different issue than what's happening here - this bug described a problem importing tracks from MIP, not importing pre-existing playlists.
Jordan, I thought my problem was related to yours. Should I open a new bug? I am going to my wife's house (400Km away) where I have another SB3 and computer system. I will upgrade it to SC7.1.0 and will see if the MIP mixes are imported. I also emailed support, but due to time zone differences (Australia / West Coast USA) there is a overnight delay in response.
Question : Should I open a new bug for this problem ? I upgraded a second system (WinXP SP3) from SC 7.0.1 to SC 7.1.0 and once more playlists in MIP were not picked up by the scan process.
(In reply to comment #24) > Question : Should I open a new bug for this problem ? > > I upgraded a second system (WinXP SP3) from SC 7.0.1 to SC 7.1.0 and once more > playlists in MIP were not picked up by the scan process. > Yes, I would say you should open a new bug.
Jordan, I have created bug 9002 >>-> https://bugs-archive.lyrion.org/show_bug.cgi?id=9002 Please accept my apologies if you thought I was trying to hijack your bug, I did think it was further proof of scanning problems with MIP.
(In reply to comment #17) > These parameters don't exist any more in SC7. Please set logging options in > Settings/Advanced/Logging. Enable logging for MusicIP and the scan* options. > Then run the rescan. Michael, were you able to glean any information from my latest log files? Thank you.
I'm sorry, I haven't had time to take a closer look yet.
Jordan - from what I see in the logs your scan is shut down at some point due to some failure in the MusicIP scanner. Please enable debugging for plugin.musicip and launch a rescan. After it has stopped (very likely without finishing), please upload the scanner.log and a file called mmm-song-data.txt. You should find it in SC's cache folder (it's the data MusicIP is returning to SC). It might help us find the file and reason why the analysis is failing.
(In reply to comment #29) > Jordan - from what I see in the logs your scan is shut down at some point due > to some failure in the MusicIP scanner. Please enable debugging for > plugin.musicip and launch a rescan. After it has stopped (very likely without > finishing), please upload the scanner.log and a file called mmm-song-data.txt. > You should find it in SC's cache folder (it's the data MusicIP is returning to > SC). It might help us find the file and reason why the analysis is failing. > OK, I reran the scan with the MusicIP plugin and scan* logging options set to "debug." I have also included mmm-song-data.txt in the zip file with the logs. Here is what the web interface reported from the scan: Directory Scan (186 of 186) Complete 00:46:01 MusicIP Import (1325 of 60167) Running 01:08:53 \\readynas_nv\media\Music\MP3\The Mountain Goats\On Juhu Beach\01 Hotel Road.mp3 ( of ) ( of ) ( of ) ( of ) ( of ) ( of ) ( of ) ( of ) ( of ) SqueezeCenter has finished scanning your music collection. 01:54:54 Thank you again very much for your help with this.
Created attachment 3817 [details] Latest server & scanner logs + mmm-song-data.txt
Jordan - scanner.log is still missing the plugin.musicip debug data. This really would help a lot, as it lists all the tracks as they are imported. While trying to import your file SC failed at the same track over and over again. But then I don't have you music files. It would be better if we knew where it failed on your installation. From your log file I guess the failure is at track 1328. According to mmm-song-data.txt this might be the following track: \\readynas_nv\media\Music\Hi-Fi\Bud Powell\The Legacy\disc 2 - ...With Mingus\01 How High The Moon.flac If it continues failing at this point, could you please move that folder outside your music collection and try again?
(In reply to comment #32) > Jordan - scanner.log is still missing the plugin.musicip debug data. This > really would help a lot, as it lists all the tracks as they are imported. While Michael, I don't understand - I turned on musicip debug logging before running the scan (as I have the last couple times I posted my logs here). Can you think of any reason the debug info isn't showing up in my log file? I will try removing that song and seeing what happens. And I would be happy to post another log with the right info, but I'm not sure how else to force it to include musicip debug information other than setting "(plugin.musicip) - MusicIP Mix & Export Logging" to "Debug" in the "Logging" area of the settings? Thanks, Jordan
That's odd. Try checking the "Save logging settings...", then restart SC and verify the log settings. Run the scan. Then disable the debugging again (checking the above again - to save the disabled state).
Michael, I checked the "save logging settings" box, shut down SS, backed up and deleted server.log & scanner.log, restarted SS, reran the music scan, and verified that there is indeed much more information in the scanner & server logs than there was last time. I also took a look at the song you identified in your last post - that whole album had its track numbers set to "-1." I corrected that, but it did not appear to fix the problem; the scan still stops at the same place. I have done a spot check for embedded cue files (since that seemed to be causing this issue for someone else) but haven't found any yet - I'm not entirely sure which songs I should be checking. I will post the latest logs in a second, as well as the mmm-song-data.txt. Thank you again for your help.
Created attachment 3821 [details] Server & scanner logs with correct debug information.
I took a look through the logs and it looks like the last song it tried to import was "\\Readynas_nv\media\Music\Hi-Fi\The Watson Twins\Fire Songs\01 How Am I to Be.flac." That song actually did have an embedded cuesheet! (Are those supported by SqueezeCenter?) I disabled the embedded cuesheet (for that file only, not for the other tracks in the album) so I can test and see if it will scan past that song now. I'll post the scan results when it finishes. If this is the problem, I believe this is a bug in the importer, no? In the meantime, is there any way to search my library for all files that have an embedded cuesheet?
Cue sheets should be ok. But could you please verify it's values? Does the cue sheet have some title information?
I rashly removed the cuesheet in question from that file before reading it closely, but here is the embedded cuesheet from Track 2 from the same album: --------------------------------- REM DATE 2008 PERFORMER "Watson Twins" TITLE "Fire Songs" FILE "DUMMY" WAVE TRACK 01 AUDIO TITLE "Lady Love Me" ISRC USVG20802010 INDEX 01 00:00:00 ---------------------------------
Sorry, I spoke too soon. Even though I had unchecked "enable embedded cuesheet for this file" in foobar2000, it looks like Track 1 of that album still has an embedded cuesheet. Here is its value: ------------------------------- REM DATE 2008 PERFORMER "Watson Twins" TITLE "Fire Songs" FILE "DUMMY" WAVE TRACK 01 AUDIO TITLE "How Am I to Be" ISRC USVG20802009 INDEX 01 00:00:00 -------------------------------
crash is probably due to a bad $albumObj ($albumObj->title). see ~line 2173-2185 of Schema.pm (rather than line 2016 which doesn't appear to have any code)
(In reply to comment #41) > crash is probably due to a bad $albumObj ($albumObj->title). see ~line > 2173-2185 of Schema.pm (rather than line 2016 which doesn't appear to have any > code) In my installation, C:\Program Files\SqueezeCenter\server\Slim\schema.pm does indeed have code on line 2016, here's lines 2004-2020: ------------------------------------- # we may have an album object already.. # But mark it undef first - bug 3685 my $albumObj = undef; if (!$create && $isLocal) { $albumObj = $track->album; # Bug: 4140 # If the track is from a FLAC cue sheet, the original entry # will have a 'No Album' album. See if we have a real album name. my $noAlbum = string('NO_ALBUM'); if ($album && $albumObj->title eq $noAlbum && $album ne $noAlbum) { $create = 1; } } -------------------------------------
Hmm... thought I had commented on this: I run into the "same" issue at home, MIP crashing at some point in the scan. A full wipe/rescan fixed it for me. Did you ever try this?
(In reply to comment #43) > Hmm... thought I had commented on this: I run into the "same" issue at home, > MIP crashing at some point in the scan. A full wipe/rescan fixed it for me. Did > you ever try this? Yes, I tried that (see Comment #4 above) and got the same result. I am trying it again today and expect I will get the same result - there's something wrong with the scanner code when it finds an embedded cue sheet in a FLAC file, apparently.
Created attachment 3862 [details] Logs from clear & rescan These are the logs from doing a total clear & rescan.
(In reply to comment #43) As you can see in the latest log files, it crashes at exactly the same place during the MusicIP import section of the full wipe & rescan.
I was just looking at the changelog for 7.2, and it mentions bug #4443, which seems like it might be the same problem. I'm installing 7.2 now and will try a scan with it ASAP.
Turns out this was a dup. of 4443 - I didn't think to search again once the problem had been identified; I thought this was a MusicIP problem, not a scanner problem. Interestingly the song(s) in question import fine via directory scan, just not via MusicIP. Either way, upgrading to 7.2 solved this issue for me. Thank you. *** This bug has been marked as a duplicate of bug 4443 ***
Sorry, typo in previous comment - that's 8443, not 4443. *** This bug has been marked as a duplicate of bug 8443 ***
thanks for following up on this issue!
Reduce number of active targets for SC