Feedback on 1236

[mbaker]

Hiya. I haven’t had a chance to peruse all the postings on 1236 so there could be some overlap with some of the others out there.

Overall, thanks for the new release. Working pretty well. However, there have been a few issues that I thought I should share.

Overview:
Windows XP
iTunes library (files on UNC share)
SB 1.5.157
debug level 5

1. Install issue with “file in use”.
I upgraded by shutting down the server from the console and then uninstalling and then installing. The install froze saying that a file was in use and it couldn’t proceed. I think the file was FireflyShell. I rebooted, removed all the files in the install folder, and reinstalled and it all worked fine again.

2. iTunes tmp files
When running Firefly and iTunes at the same time, I’m getting a build-up of iTunes XML temp files in the My DocumentsMy MusiciTunes folder. I’ve had up to 200 files at 8M each. Running iTunes with Firefly turned off produces no tmp files.

3. “completed” systray popups seem premature
I’m getting “completed” pop-ups at unusual times. According to the tail I’ve got running on my log file, they’re happening before it’s completed the scan and started serving files.

4. not picking up iTunes content regularly
I was doing a bunch of ripping in iTunes and the server didn’t seem to be picking it up. I know that sometimes iTunes can be slow to write the XML file so I was quitting iTunes in order to reset the XML file. But hours later no rescan was being done (set to 600). With iTunes off, the rescan seems to be happening pretty regularly.

5. web interface bugs
Love the new UI. Really professional looking. Nice work. In basic mode on the configuration page though, the Config File Location is being cut in half by the box underneath. Also, is the intended behaviour that the countdown bar gets thinner over time? Weird.

6. m3u = iTunes XML
I turned off the M3U scan because I don’t have any and then my XML file wasn’t being read. I had to turn on debug 9 to figure that one out. Could use some documentation/warning that an iTunes XML counts as an M3U playlist.

7. unknown meta flags
With debug level 5 I’m getting a lot of errors saying “unknown meta flag”. Not sure what’s causing that but they’re pretty regular.

8. error adding iTunes playlist
I’ve also been getting a lot of errors saying that it couldn’t add an iTunes playlist that was already available (being served).

9. memory leak
I’m getting an inconsistent memory leak. The biggest problem I had was when I had the server running while ripping a lot of CDs. The server got to 404M the first time and then 200M+ the second time. Stopping and starting the server fixes the problem. I’ve been running the server for hours now with iTunes turned off and the memory use is just fine (4M).

10. missing files
Not all the files I’d expect to be shared are available. Of ~5000 files (based on the extensions I’ve told it to share) I’m missing about 50. Not sure what the connection might be as I’m not sure what they all are. Is there an easy way to get an output from the database with a list of the filenames? Note that in order to check this I turned off the server, deleted the database files, and rebuilt from scratch.

11. long refresh times
The initial build of the full refresh was very quick but subsequent refreshes seem to be taking a long time. Here’s what I’m seeing:

2006-06-19 : Registering Firefly as type (_daap._tcp) on port 9999

2006-06-19 : Registering Firefly as type (_http._tcp) on port 9999

2006-06-19 : select() returned -1 errno 0 An invalid argument was supplied.

2006-06-19 : Registering Firefly (rsp) as type (_rsp._tcp) on port 9999

2006-06-19 : Scanned 4709 songs in  157 seconds

2006-06-19 : Rescanning database

2006-06-19 : Scanning d:my documentsmy musicitunesitunes music library.xml

2006-06-19 : Scanned 4709 songs (was 4709) in 4515 seconds

2006-06-19 : Rescanning database

2006-06-19 : Scanning d:my documentsmy musicitunesitunes music library.xml

2006-06-19 : Scanned 4709 songs (was 4709) in 4383 seconds

2006-06-19 : Rescanning database

2006-06-19 : Scanning d:my documentsmy musicitunesitunes music library.xml

2006-06-19 : Scanned 4709 songs (was 4709) in 4593 seconds

2006-06-19 : Rescanning database

2006-06-19 : Scanning d:my documentsmy musicitunesitunes music library.xml

2006-06-19 : Scanned 4709 songs (was 4709) in 4636 seconds

12. timestamp in log
Any chance of getting a timestamp in the log to go with the datestamp? That would be really helpful with issue tracking and debugging.

I’ve got the level 5 logfile for the latest run including the complete database rebuild. I could easily run it all again at a different logging level if that would be helpful.

Cheers,
Mark

[grommet]

@mbaker wrote:

2. iTunes tmp files
When running Firefly and iTunes at the same time, I’m getting a build-up of iTunes XML temp files in the My DocumentsMy MusiciTunes folder. I’ve had up to 200 files at 8M each. Running iTunes with Firefly turned off produces no tmp files.

iTunes is generating these files when it’s connected to Firefly as a client. The behavior here might be related to Firefly not supporting incremental updates. (You’ll see multiple playlists appear, etc.) So, maybe: http://trac.fireflymediaserver.org/ticket/17 (Future release.)

3. “completed” systray popups seem premature
I’m getting “completed” pop-ups at unusual times. According to the tail I’ve got running on my log file, they’re happening before it’s completed the scan and started serving files.

Yes, I still see that, too. It’s been mentioned. Pretty minor, though…

5. web interface bugs
In basic mode on the configuration page though, the Config File Location is being cut in half by the box underneath.

Known: http://trac.fireflymediaserver.org/ticket/162

is the intended behaviour that the countdown bar gets thinner over time? Weird.

Known. That’s here: http://trac.fireflymediaserver.org/ticket/123

7. unknown meta flags
With debug level 5 I’m getting a lot of errors saying “unknown meta flag”. Not sure what’s causing that but they’re pretty regular.

Known bug: http://trac.fireflymediaserver.org/ticket/83

11. long refresh times
The initial build of the full refresh was very quick but subsequent refreshes seem to be taking a long time.

Odd, I’m seeing much faster performance. For example: “19444 songs in 1166 seconds”

12. timestamp in log
Any chance of getting a timestamp in the log to go with the datestamp? That would be really helpful with issue tracking and debugging.

Known bug: http://trac.fireflymediaserver.org/ticket/158

[mbaker]

Thanks for the pointer to the BugDB. Good to know that things are in such good hands!

That leave 1, 4, 6, 8, 9, 10. Anyone else seeing these?

M

[rpedde]

@mbaker wrote:

1. Install issue with “file in use”.

I saw that once, but then couldn’t replicate it. I send a message to the tray applet to shut itself down, but it appeared that it just plain ignored it once. Don’t know why that happens, and I can’t make it do it at will. 🙁

2. iTunes tmp files

Interesting. If you set “supports update” to “no” in the config page, does it still happen?

4. not picking up iTunes content regularly

Don’t know if that’s an iTunes thing or a me thing. I’ll try and replicate it. This is ticket #171.

6. m3u = iTunes XML

… ticket #172…

8. error adding iTunes playlist

That comes from duplicate playlists. If there is a backup copy of the iTunes xml file or something, then it tries to add another playlist with the same name — the second try at adding it fails.

Arguably, there could be multiple playlists with the same name, but I just haven’t allowed it. I’m not sure why. Confusion, maybe?

9. memory leak

Aaaaah… that makes me think it’s in the itunes xml parsing. Great. No wonder I couldn’t find it on valgrind – my linux box with valgrind doesn’t have (duh) iTunes, so I’m not grinding against a real xml file. I’ll run this to ground. Ticket #173.

10. missing files

You can turn logging up to 5, then watch the logs on scan. You should get some sense of it there.

Otherwise, you can dump the database with something like

sqlite pathtosongs.db ".dump songs"

and importing it into excel or something. You’ll need the sqlite exectable (2.8.whatever) from http://www.sqlite.org. You can also find a sqlite table editor around and open songs.db directly.

As far as scanning performance goes, that’s strange. I wonder if it’s related to the multiple itunes temp files? Wonder if it’s scanning those and trying to import them.

[mbaker]

2. iTunes tmp files

If you set “supports update” to “no” in the config page, does it still happen?

I can’t find a “supports update” in the config file or in either UI. Do you mean “Always Scan”? If you turn that off then it still happens.

I watched it a little yesterday (as it generated 300 TMP files) and it’s definitely Firefly causing the problem because if I stop the server the temp files stop too.

It appears that this version of iTunes creates xml temp files (when the library’s being updated) and then renames them once they’re complete. While ripping CDs I’m seeing the XML file timestamp update every minute or two (and the temp files are generated every minute or two).

The fact that it’s taking so long to rescan won’t be helping matters.

4. not picking up iTunes content regularly

Don’t know if that’s an iTunes thing or a me thing. I’ll try and replicate it. This is ticket #171.

This could be a symptom of the same problem. If the refresh is taking an hour to complete (according to the log) then that would explain why it’s not picking up the changes.

8. error adding iTunes playlist

That comes from duplicate playlists. If there is a backup copy of the iTunes xml file or something, then it tries to add another playlist with the same name — the second try at adding it fails.

Arguably, there could be multiple playlists with the same name, but I just haven’t allowed it. I’m not sure why. Confusion, maybe?

There aren’t multiple playlists in the XML file but if it was picking up some of the content from the TMP files, that could cause the problem. Perhaps the same TMP issue again?

9. memory leak

Aaaaah… that makes me think it’s in the itunes xml parsing. Great. No wonder I couldn’t find it on valgrind – my linux box with valgrind doesn’t have (duh) iTunes, so I’m not grinding against a real xml file. I’ll run this to ground. Ticket #173.

I came home today to find the server running at about 200M when I hadn’t seen it like that for days. I also found a lot of “unknown meta” items in the log (1212 of them). I hadn’t seen any memory problems or meta messages for days? A coincidence?

10. missing files

You can turn logging up to 5, then watch the logs on scan. You should get some sense of it there.

Otherwise, you can dump the database with something like

sqlite pathtosongs.db “.dump songs”

I’ve got the logging on at level 5 but it only gives me the final filename, not the full path which makes it harder to match. I’ll probably turn on debug 9 and then rebuild and see what’s being missed and why.

Cheers,
Mark

[grommet]

The option in .conf would be:

[daap]
supports_update = 0

You might try turning off “Look for shared music” in iTunes Sharing so you don’t see the Firefly server (I assume you are running iTunes on the same box as Firefly in this scenario) and see if that makes any difference…

Also, as I mentioned above, the invalid metadata errors in the log are known and bugged. (You won’t see them unless you have an active iTunes client talking to the Firefly server.) Probably safe to ignore for now…

[mbaker]

Hi there. I’ve been running in heavy debug mode for the last couple of days (and have a nice 130M log file to show for it that I need to do some grawking on).

Grommet, thanks for the config addition. On the meta errors, I know that’s a known bug, but I thought it was interesting that they seem to coincide with the memory leak. I’ll continue monitoring that one.

A couple of tidbits…
I’ve been running with the following settings:

always_scan = 0

scan_type = 2

supports_update = 0

…and with iTunes listening turned off as recommended. But when I rip CDs and the iTunes XML is being updated regularly, I’m still getting lots of TMP files because of the lock on the XML file. Would it be reasonable to take a temporary copy of the XML file for digestion leaving the main file unlocked?

While running in -9 mode I noticed the following behaviour during updates:

...

2006-06-22 : Rows: 506883

2006-06-22 : Adding itunes track #756

2006-06-22 : Executing: select type from playlists where id=443

2006-06-22 : Executing: select count(*) from songs where id=714

2006-06-22 : Executing: insert into playlistitems (playlistid, songid) values (443,714)

2006-06-22 : Rows: 506884...

This appears to be what’s taking all the time on the rescans (taking up to an hour). Surely it shouldn’t have managed to generate 500k rows. I don’t have that many playlists.

Also, when the server restarted, it seemed to decide that doing a full rescan of every song was a good idea. Is that normal? Here’s what I see in the log (this is the start after I’d done a complete rebuild so I wouldn’t have expected so much activity):

...

2006-06-22 : Scanning iTunes id #457

2006-06-22 : scan_path: file://localhost//Horace/multimedia/iTunes/iTunes Music/Nine Inch Nails/Pretty Hate Machine/02 Terrible Lie.mp3

2006-06-22 : Executing: select * from songs where path='\horacemultimediaitunesitunes musicnine inch nailspretty hate machine2 terrible lie.mp3'

2006-06-22 : Executing: INSERT INTO updated VALUES (417)

2006-06-22 : Rows: 1

2006-06-22 : Executing: select count(*) from songs where path='\horacemultimediaitunesitunes musicnine inch nailspretty hate machine2 terrible lie.mp3'

2006-06-22 : Executing: UPDATE songs SET title='Terrible Lie',artist='Nine Inch Nails',album='Pretty Hate Machine',genre='Other',comment='',type='mp3',composer=

'Trent Reznor',orchestra='Nine Inch Nails',conductor='',grouping='',url='',

bitrate=128,samplerate=44100,song_length=282566,file_size=4528935,

year=1989,track=2,total_tracks=0,disc=0,total_discs=0,

time_modified=1105002673,db_timestamp=1150958979,bpm=0,

disabled=0,compilation=0,rating=0,sample_count=0,codectype='mpeg' WHERE path='\horacemultimediaitunesitunes musicnine inch nailspretty hate machine2 terrible lie.mp3'

2006-06-22 : Rows: 1

2006-06-22 : Executing: insert into updated (id) select id from songs where path

='\horacemultimediaitunesitunes musicnine inch nailspretty hate machine2 terrible lie.mp3'

2006-06-22 : Rows: 1

2006-06-22 : Scanning iTunes id #458

...

Thoughts?

M

[mbaker]

Just determined that the meta errors and the memory leak in this release are definitely linked. Turns out it’s related to using iTunes clients with the server.

I had the “look for shared music” in iTunes turned off but was running a tail -f on the log file. I turned the shared music on in itunes and clicked on the Firefly server in itunes and noticed the errors come up in the log. I checked the memory usage and it was up to 11M from 7M.

I repeated the process (turning music sharing off, turning it on, selecting firefly) and I got the errors again and the server was up to 16M. A third attempt and I’m up to 20M.

Enjoy!
M

[mbaker]

I’ve figured out why I’m missing so many files. Firefly seems to be struggling to map files from the iTunes XML to the file system if the file name or path has an accented character. An accent in the iTunes song name or details isn’t a problem, just if it’s in the file path.

Here’s an example of something that doesn’t make it through (iTunes string then filename):

Locationfile://localhost//Horace/multimedia/iTunes/iTunes%20Music/Bj%C3%B6rk/Debut/10%20Violently%20Happy.m4a



\HoraceMultimediaiTunesiTunes MusicBjörkDebutViolently Happy.m4a

The same problem occurs whether the extended character is in the path or the filename.

I’m surprised this isn’t being flagged in the logfile, even with level 9 debug.

Cheers,
Mark

[Flat]

@mbaker wrote:

I’ve figured out why I’m missing so many files. Firefly seems to be struggling to map files from the iTunes XML to the file system if the file name or path has an accented character. An accent in the iTunes song name or details isn’t a problem, just if it’s in the file path.

Hi all
I was just wondering if this “accent problem” could be solved in a future version of firefly ?
I’m running the nightly 1523 on my synology DS-101J. In my iTunes Library some ID3 tags are not correct, the reason is that there is an accent in the file path…
And since I’m french you can imagine the number of the songs !!! 😆
Thanks

[Author]

Posts