Feedback on svn-1340

[grommet]

Continuing on the issue I first posted in the svn-1333 thread…

I just installed svn-1340 (win32) and the songs.db now builds to full size very quickly. Improvement, I thnk! But, startup is still slow on full scan… as I’m typing this posting, it’s crawling through iTunes to augment data (I think) and Firefly is still not ready to accept connections.

I started this at 2006-08-13 02:22 and it’s still chugging… here are some recent log entries:

2006-08-13 02:40:17 (f3f11f6d): Scanning iTunes id #3768

2006-08-13 02:40:17 (f3f11f6d): scan_path: file://localhost/D:/The Producers/16 - Where Did We Go Right.mp3

2006-08-13 02:40:17 (f3f11f6d): Executing: select * from songs where upper(path)=upper('D:The Producers16 - Where Did We Go Right.mp3') and idx=0

2006-08-13 02:40:18 (f3f11f6d): Executing: select count(*) from songs where path='D:The Producers16 - Where Did We Go Right.mp3' and idx=0

2006-08-13 02:40:18 (f3f11f6d): Executing: UPDATE songs SET title='Where Did We Go Right?',artist='Matthew Broderick/Nathan Lane',

album='The Producers [Original Broadway Cast Recording]',genre='Soundtrack',comment='CRC: A8605C01',type='mp3',composer='Mel Brooks',orchestra='Original Broadway Cast',conductor='',grouping='',url='',bitrate=229,samplerate=44100,song_length=137351,file_size=3935268,year=2001,track=16,

total_tracks=0,disc=0,total_discs=0,time_modified=1154925173,db_timestamp=1155462018,bpm=0,disabled=0,compilation=1,rating=0,sample_count=0,codectype='mpeg' WHERE path='D:The Producers16 - Where Did We Go Right.mp3' and idx=0

2006-08-13 02:40:18 (f3f11f6d): Rows: 1

2006-08-13 02:40:18 (f3f11f6d): Scanning iTunes id #3769

2006-08-13 02:40:18 (f3f11f6d): scan_path: file://localhost/D:/The Producers/17 - Betrayed.mp3

2006-08-13 02:40:18 (f3f11f6d): Executing: select * from songs where upper(path)=upper('D:The Producers17 - Betrayed.mp3') and idx=0

2006-08-13 02:40:18 (f3f11f6d): Executing: select count(*) from songs where path='D:The Producers17 - Betrayed.mp3' and idx=0

2006-08-13 02:40:18 (f3f11f6d): Executing: UPDATE songs SET title='Betrayed',artist='Nathan Lane',

album='The Producers [Original Broadway Cast Recording]',genre='Soundtrack',comment='CRC: 961B0005',type='mp3',composer='Mel Brooks',orchestra='Original Broadway Cast',conductor='',grouping='',url='',bitrate=220,samplerate=44100,song_length=294191,file_size=8115251,year=2001,track=17,

total_tracks=0,disc=0,total_discs=0,time_modified=1154925174,db_timestamp=1155462018,bpm=0,disabled=0,compilation=1,rating=0,sample_count=0,codectype='mpeg' WHERE path='D:The Producers17 - Betrayed.mp3' and idx=0

2006-08-13 02:40:18 (f3f11f6d): Rows: 1

2006-08-13 02:40:18 (f3f11f6d): Scanning iTunes id #3770

2006-08-13 02:40:18 (f3f11f6d): scan_path: file://localhost/D:/The Producers/18 - 'Til Him.mp3

2006-08-13 02:40:18 (f3f11f6d): Executing: select * from songs where upper(path)=upper('D:The Producers18 - ''Til Him.mp3') and idx=0

2006-08-13 02:40:18 (f3f11f6d): Executing: select count(*) from songs where path='D:The Producers18 - ''Til Him.mp3' and idx=0

2006-08-13 02:40:18 (f3f11f6d): Executing: UPDATE songs SET title='''Til Him',artist='Ensemble/Matthew Broderick/Nathan Lane',

album='The Producers [Original Broadway Cast Recording]',genre='Soundtrack',comment='CRC: 2FD3DBCE',type='mp3',composer='Mel Brooks',orchestra='Original Broadway Cast',conductor='',grouping='',url='',bitrate=208,samplerate=44100,song_length=222197,file_size=5798931,year=2001,track=18,

total_tracks=0,disc=0,total_discs=0,time_modified=1154925174,db_timestamp=1155462018,bpm=0,disabled=0,compilation=1,rating=0,sample_count=0,codectype='mpeg' WHERE path='D:The Producers18 - ''Til Him.mp3' and idx=0

2006-08-13 02:40:18 (f3f11f6d): Rows: 1

2006-08-13 02:40:18 (f3f11f6d): Scanning iTunes id #3771

2006-08-13 02:40:18 (f3f11f6d): scan_path: file://localhost/D:/The Producers/19 - Prisoners Of Love (Leo & Max).mp3

2006-08-13 02:40:18 (f3f11f6d): Executing: select * from songs where upper(path)=upper('D:The Producers19 - Prisoners Of Love (Leo & Max).mp3') and idx=0

2006-08-13 02:40:19 (f3f11f6d): Executing: select count(*) from songs where path='D:The Producers19 - Prisoners Of Love (Leo & Max).mp3' and idx=0

2006-08-13 02:40:19 (f3f11f6d): Executing: UPDATE songs SET title='Prisoners of Love (Leo & Max)',artist='Cady Huffman/Gary Beach/Matthew Broderick',

album='The Producers [Original Broadway Cast Recording]',genre='Soundtrack',comment='CRC: D01BD5A9',type='mp3',composer='Mel Brooks',orchestra='Original Broadway Cast',conductor='',grouping='',url='',bitrate=247,samplerate=44100,song_length=254693,file_size=7880541,year=2001,track=19,

total_tracks=0,disc=0,total_discs=0,time_modified=1154925174,db_timestamp=1155462019,bpm=0,disabled=0,compilation=1,rating=0,sample_count=0,codectype='mpeg' WHERE path='D:The Producers19 - Prisoners Of Love (Leo & Max).mp3' and idx=0

2006-08-13 02:40:19 (f3f11f6d): Rows: 1

2006-08-13 02:40:19 (f3f11f6d): Scanning iTunes id #3772

2006-08-13 02:40:19 (f3f11f6d): scan_path: file://localhost/D:/The Producers/20 - Goodbye!.mp3

2006-08-13 02:40:19 (f3f11f6d): Executing: select * from songs where upper(path)=upper('D:The Producers20 - Goodbye!.mp3') and idx=0

2006-08-13 02:40:19 (f3f11f6d): Executing: select count(*) from songs where path='D:The Producers20 - Goodbye!.mp3' and idx=0

2006-08-13 02:40:19 (f3f11f6d): Executing: UPDATE songs SET title='Goodbye!',artist='Company',album=

'The Producers [Original Broadway Cast Recording]',genre='Soundtrack',comment='CRC: 649FD1CB',type='mp3',composer='Mel Brooks',orchestra='Original Broadway Cast',conductor='',grouping='',url='',bitrate=232,samplerate=44100,song_length=35866,file_size=1043480,year=2001,track=20,

total_tracks=0,disc=0,total_discs=0,time_modified=1154925175,db_timestamp=1155462019,bpm=0,disabled=0,compilation=1,rating=0,sample_count=0,codectype='mpeg' WHERE path='D:The Producers20 - Goodbye!.mp3' and idx=0

So, something is still different/slower than “fast” svn-1236, at least when iTunes XML is enabled… ❓

Update: It’s 2006-08-13 03:16:25 now and it’s still not done!
Update: 2006-08-13 03:22:02 (f3f11f6d): Serving 20629 songs. Startup complete in 3577 seconds That’s painfully slow, even with debug set to 9.

When I turn off process_m3u (which disables iTunes XML, correct?)… I get excellent fresh scan startup performance again:
2006-08-13 03:30:15 (f3f11f6d): Serving 20586 songs. Startup complete in 84 seconds

[fizze]

interesting.
I started 1340 on my slug as I type this.

I do have process_m3u enabled, but I dont even have an iTunes.XML file (at least none that I am aware of), so something else is going on here …?
🙄

[grommet]

As before, any songs that are referenced in my test .m3u Playlist has the actual filename as the “Name” of the song and not the song name in the metadata. (The rest of the song metadata is correct.) If I remove the playlist, all is fine.

In the log, I see Path not found errors for each entry when it parses the playlist… even though the path is valid. Not sure if this actually means anything. Example:

2006-08-13 05:07:29 (f3f11f6d): Checking C:Documents and SettingsgrommetMy DocumentsMy MusicBen Folds - Make Me Mommy.mp3

2006-08-13 05:07:29 (f3f11f6d): Executing: select * from songs where upper(path)=upper('C:Documents and SettingsgrommetMy DocumentsMy MusicBen Folds - Make Me Mommy.mp3') and idx=0

2006-08-13 05:07:29 (f3f11f6d): Executing: INSERT INTO updated VALUES (1067)

2006-08-13 05:07:29 (f3f11f6d): Rows: 15825

2006-08-13 05:07:29 (f3f11f6d): Resolved C:Documents and SettingsgrommetMy DocumentsMy MusicBen Folds - Make Me Mommy.mp3 to 1067

2006-08-13 05:07:29 (f3f11f6d): Executing: select type from playlists where id=3

2006-08-13 05:07:29 (f3f11f6d): Executing: select count(*) from songs where id=1067

2006-08-13 05:07:29 (f3f11f6d): Executing: insert into playlistitems (playlistid, songid) values (3,1067)

2006-08-13 05:07:29 (f3f11f6d): Rows: 15826

2006-08-13 05:07:29 (f3f11f6d): Checking C:Documents and SettingsgrommetMy DocumentsMy MusicMy Playlists

2006-08-13 05:07:29 (f3f11f6d): Executing: select * from songs where upper(path)=upper('C:Documents and SettingsgrommetMy DocumentsMy MusicMy Playlists') and idx=0

2006-08-13 05:07:29 (f3f11f6d): Playlist entry  bad: Path not found

The entry in the .m3u located in C:Documents and SettingsgrommetMy DocumentsMy MusicMy Playlists looks like this:

#EXTINF:0,Ben Folds - Make Me Mommy.mp3

..Ben Folds - Make Me Mommy.mp3

Here is what Firefly did in the initial scan:

2006-08-13 03:37:30 (f3f11f6d): Rows: 1

2006-08-13 03:37:30 (f3f11f6d): Found C:Documents and SettingsgrommetMy DocumentsMy Music/Ben Folds - Make Me Mommy.mp3

2006-08-13 03:37:30 (f3f11f6d): Found music file: Ben Folds - Make Me Mommy.mp3

2006-08-13 03:37:30 (f3f11f6d): Codec type: mpeg

2006-08-13 03:37:30 (f3f11f6d):  Title: Make Me Mommy

2006-08-13 03:37:30 (f3f11f6d):  Track 4 of 0

2006-08-13 03:37:30 (f3f11f6d):  Genre: 20

2006-08-13 03:37:30 (f3f11f6d):  Album: Rockin' the Suburbs CD5 (UK)

2006-08-13 03:37:30 (f3f11f6d):  Orchestra: Ben Folds

2006-08-13 03:37:30 (f3f11f6d):  Artist: Ben Folds

2006-08-13 03:37:30 (f3f11f6d):  Year: 2001

2006-08-13 03:37:30 (f3f11f6d): Got id3 tag successfully

2006-08-13 03:37:30 (f3f11f6d): Found ID3 header

2006-08-13 03:37:30 (f3f11f6d): Header length: 2078

2006-08-13 03:37:30 (f3f11f6d): Reading in new block at 2088

2006-08-13 03:37:30 (f3f11f6d): valid header at 0

2006-08-13 03:37:30 (f3f11f6d): Found valid frame at 0828

2006-08-13 03:37:30 (f3f11f6d): Checking at 0a9a

2006-08-13 03:37:30 (f3f11f6d):  MPEG Version: 1

2006-08-13 03:37:30 (f3f11f6d):  Layer: 3

2006-08-13 03:37:30 (f3f11f6d):  Sample Rate: 44100

2006-08-13 03:37:30 (f3f11f6d):  Bit Rate: 192

2006-08-13 03:37:30 (f3f11f6d): Starting aggressive file length scan

2006-08-13 03:37:30 (f3f11f6d): Starting frame count

2006-08-13 03:37:30 (f3f11f6d): File appears to be CBR... quitting frame count

2006-08-13 03:37:30 (f3f11f6d):  Song Length: 138323

2006-08-13 03:37:30 (f3f11f6d):  Date Added: 1049993663

2006-08-13 03:37:30 (f3f11f6d):  Codec: mpeg

2006-08-13 03:37:30 (f3f11f6d): Executing: INSERT INTO songs VALUES (NULL,'C:Documents and SettingsgrommetMy DocumentsMy MusicBen Folds - Make Me Mommy.mp3','Ben Folds - Make Me Mommy.mp3','Make Me Mommy','Ben Folds','Rockin'' the Suburbs CD5 (UK)','Alternative','','mp3','','Ben Folds','','','',192,44100,138323,3321856,2001,4,0,0,0,0,0,0,0,0,2,'MPEG audio file',1049993663,1118503651,0,1155465450,0,0,0,'mpeg',0,0,0)

And here is what happens when it sees the iTunes reference:

2006-08-13 05:08:20 (f3f11f6d): Scanning iTunes id #302

2006-08-13 05:08:20 (f3f11f6d): scan_path: file://localhost/C:/Documents and Settings/grommet/My Documents/My Music/Ben Folds - Make Me Mommy.mp3

2006-08-13 05:08:20 (f3f11f6d): Executing: select * from songs where upper(path)=upper('C:Documents and SettingsgrommetMy DocumentsMy MusicBen Folds - Make Me Mommy.mp3') and idx=0

2006-08-13 05:08:20 (f3f11f6d): Executing: INSERT INTO updated VALUES (1067)

2006-08-13 05:08:20 (f3f11f6d): Rows: 16575

2006-08-13 05:08:20 (f3f11f6d): Executing: select count(*) from songs where path='C:Documents and SettingsgrommetMy DocumentsMy MusicBen Folds - Make Me Mommy.mp3' and idx=0

2006-08-13 05:08:20 (f3f11f6d): Executing: UPDATE songs SET title='Make Me Mommy',artist='Ben Folds',album='Rockin'' the Suburbs CD5 (UK)',genre='Alternative',comment='',type='mp3',composer='',orchestra='Ben Folds',conductor='',grouping='',url='',bitrate=192,samplerate=44100,song_length=138318,file_size=3321856,year=2001,track=4,total_tracks=0,disc=0,total_discs=0,

time_modified=1118503651,db_timestamp=1155470900,bpm=0,disabled=0,compilation=0,rating=0,sample_count=0,codectype='mpeg' WHERE path='C:Documents and SettingsgrommetMy DocumentsMy MusicBen Folds - Make Me Mommy.mp3' and idx=0

2006-08-13 05:08:20 (f3f11f6d): Rows: 16576

2006-08-13 05:08:20 (f3f11f6d): Executing: insert into updated (id) select id from songs where path='C:Documents and SettingsgrommetMy DocumentsMy MusicBen Folds - Make Me Mommy.mp3' and idx=0

2006-08-13 05:08:20 (f3f11f6d): Rows: 16577

[fizze]

Sorry to ask blunt, whats your point ?
The DB field “title” clearly has the right info.
I run 1340 too, and just checked on them playlists, on the SB everything is displayed fine….
🙄

And finally the correct playlist order. thanks ron 🙂

[rpedde]

What is your mp3_dir set to?

[grommet]

Ron, in that last test post (playlist oddities):
mp3_dir =C:Documents and SettingsgrommetMy DocumentsMy Music

For the first post (speed test), it was D: for one test and the above “default” path for another. Same results, different boxes.

fizze, my point is… I don’t see it displayed “fine” for some reason! (I’m on win32, so it’s bound to be different.) This is fairly new behavior for me.

[fizze]

Well, maybe its the m3u playlist ?
I created them with winamp, ages ago.

[grommet]

I can confirm the RSP playlist sorting bug is resolved. In addition, the random ordering I saw on .m3u playlists is gone for both RSP and DAAP… it’s all in correct order now. Yay!

So, I did get to test a little more… and my odd filename display vs. playlist issue is most likely a problem with iTunes and the iTunes XML I was testing with. I didn’t get any “track name is filename” issues until I augmented the data with the iTunes .XML. Until then, it’s all fine. So, I rebuilt the iTunes database… and I think it’s better now.

The “Playlist entry bad: Path not found” error that I see in debug log when parsing my .m3u file is probably the blank line entries. There should be some text between “entry” and “bad” if there is something wrong in the file, right? So, I guess that’s a bug… Firefly should not consider blank lines as errors when parsing .m3u files.

Update: Another benchmark for a full scan on a fairly busy box, including iTunes XML… again, it’s the “Playlist loop” part that includes the iTunes XML parsing that is taking a long time:

2006-08-14 10:06:07 (f3f11f6d): Starting mp3 scan

2006-08-14 10:12:05 (f3f11f6d): Ending song scan

2006-08-14 10:12:06 (f3f11f6d): Processing playlists

2006-08-14 11:04:07 (f3f11f6d): Finished playlist loop

2006-08-14 11:04:09 (f3f11f6d): Serving 20642 songs.  Startup complete in 3662 seconds

[rpedde]

@grommet wrote:

Update: Another benchmark for a full scan on a fairly busy box, including iTunes XML… again, it’s the “Playlist loop” part that includes the iTunes XML parsing that is taking a long time:

hopefully fixed in tonights drop.

— Ron

[grommet]

So, if that is fixed… everything is looking very good, Ron! Now I can bug you about the missing WMA size/sample rate info… and the missing additional WM/Composer entries, again. 8)

[Author]

Posts