Bug 11858 - Randomly skips first tune of ALAC albums
: Randomly skips first tune of ALAC albums
Status: CLOSED FIXED
Product: Logitech Media Server
Classification: Unclassified
Component: Transcoding
: 7.3.3
: Macintosh MacOS X 10.4
: -- normal (vote)
: 7.4.0
Assigned To: Alan Young
:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2009-04-20 07:36 UTC by Eric Seaberg
Modified: 2009-10-05 14:33 UTC (History)
2 users (show)

See Also:
Category: ---


Attachments
7.3_26120 log (25.65 KB, application/octet-stream)
2009-04-21 08:35 UTC, Eric Seaberg
Details
7.4_26132 log (35.51 KB, application/octet-stream)
2009-04-21 08:43 UTC, Eric Seaberg
Details
7.4_26132 log AFTER rescan (78.31 KB, application/octet-stream)
2009-04-21 09:10 UTC, Eric Seaberg
Details
7.4 log, nightly of 4/25 (46.84 KB, application/octet-stream)
2009-04-26 09:54 UTC, Eric Seaberg
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Eric Seaberg 2009-04-20 07:36:06 UTC
This started with 7.3.3 and still exists in 7.4 nightlies. Clicking from album-to-album, SC will randomly skip the first song of an ALAC encoded album. Even clicking on the song itself will never allow it to play.

I can certainly send a copy of the transcoding log to help... sorry I didn't think of that when I had 7.4 installed.  At least, I assume it's a transcode problem.

I've reverted back to the 'official' Version: 7.3.2 - 24695 @ Tue Jan 20 07:06:41 PST 2009 and it's great.
Comment 1 Alan Young 2009-04-21 01:09:55 UTC
Please supply a logfile, along with a commentary of what happened when, at level player.source=info.
Comment 2 Eric Seaberg 2009-04-21 08:35:23 UTC
Created attachment 5146 [details]
7.3_26120 log

As requested. This is the latest 7.3 nightly and NOW, of course, is working fine. I loaded 7.4 after this and found albums where the first song was passed everytime! I then reloaded this version of 7.3 and played the same albums without problems  I will attach a log for 7.4 after I submit this.
Comment 3 Eric Seaberg 2009-04-21 08:43:01 UTC
Created attachment 5147 [details]
7.4_26132 log

This is the log of the latest 7.4 nightly playing the same songs as I did in 7.3.  The albums where the first song was skipped are: 

[09-04-21 08:20:03.0640] Slim::Player::Song::new (64) index 0 -> file:///Volumes/Music/Rhonda%20Smith/Intellipop/01%20ITP.m4a

[09-04-21 08:21:13.4998] Slim::Player::Song::new (64) index 0 -> file:///Volumes/Music/Richard%20Marx/Richard%20Marx/01%20Should%27ve%20Known%20Better.m4a

Then went back to the first one again to confirm it still is skipped:

[09-04-21 08:21:29.5170] Slim::Player::Song::new (64) index 0 -> file:///Volumes/Music/Rhonda%20Smith/Intellipop/01%20ITP.m4a

These same songs played in 7.3.
Comment 4 Eric Seaberg 2009-04-21 08:44:24 UTC
At this point I've reloaded 7.4 and am doing a complete library rescan to see what happens.  I'll try the same songs and come back with another logfile.

Thanks...
Comment 5 Eric Seaberg 2009-04-21 09:10:10 UTC
Created attachment 5148 [details]
7.4_26132 log AFTER rescan

I did a complete rescan of the library and came up with different results.  More info later.
Comment 6 Eric Seaberg 2009-04-21 09:13:30 UTC
Previously in 7.4 we got this:

[09-04-21 08:20:03.4034] Slim::Player::StreamingController::_playersMessage (711) Problem: Can't open file for:: file:///Volumes/Music/Rhonda%20Smith/Intellipop/01%20ITP.m4a

After a rescan we get this:

[09-04-21 09:02:56.2550] Slim::Player::StreamingController::_setPlayingState (1882) new playing state BUFFERING
[09-04-21 09:02:56.2555] Slim::Player::StreamingController::_setStreamingState (1895) new streaming state STREAMING

...and the same song is playing.  However, there were other that didn't play before that STILL don't play now.

Anything else I can try?  I've reverted back to 7.3.3 for now and it's working.
Comment 7 Alan Young 2009-04-23 02:12:41 UTC
My suspicion is that this is an artefact of the various changes that have been going on with support for AAC, etc. and that, if everything is working in 7.3.3 after a proper rescan then all is well and no further action is necessary at this stage.

For the record, the log of the problem in 7.3.3 shows that the problem tracks were not recognized as ALAC and were being played as AAC, which failed. A rescan should indeed have fixed this.

If, as you say, some tracks still fail on 7.4, the more details would be useful. It is not clear from your reports: did these tracks also fail with 7.3.2 or earlier?
Comment 8 Eric Seaberg 2009-04-23 04:34:04 UTC
Alan, none of the songs that failed in 7.4 have failed before.  I'm currently out-of-town doing a TV shoot in Memphis but can look a little more into this on Friday when I get back to San Diego.  Give me a few more specifics and I'll see what I can find.  Thanks.
Comment 9 Alan Young 2009-04-23 09:04:23 UTC
I guess a log of one of the failing tracks, failing.
Comment 10 Eric Seaberg 2009-04-26 09:54:09 UTC
Created attachment 5159 [details]
7.4 log, nightly of 4/25

At this point, 7.4 was rejecting the first track of every other album selected to play.  Reverting to 7.3.3_26209 plays the same files without error.
Comment 11 Alan Young 2009-04-28 01:57:17 UTC
Thanks for the help. I think I have found at least a contributory bug. There is a bad merge related to ALAC in the 7.4 code.

But with this bad merge I am at a loss to understand why any of the ALAC tracks play properly.

Please can you use the Web interface (in 7.4) to look at the details of the first and second tracks from one of these problem albums. What does it say about the file type, format, etc. in each case? (You need to click on the track title from either the browse or now-playing pane so that the detailed information appears in the left-hand pane.)
Comment 12 Eric Seaberg 2009-04-28 07:29:06 UTC
Alan, going to the Rhonda Smith album, the first song is:

Comment: Adjusted by iVolume 12/05/2006 20:55:38
Track Number: 1
File Format: Apple Lossless
Duration: 4:39
Volume Adjustment: -4.14 dB
Bitrate: 848kbps VBR
Sample Rate: 44.1 kHz
File Length: 30,827,818
Location: /Volumes/Music/Rhonda Smith/Intellipop/01 ITP.m4a
Date Modified: Thursday, March 13, 2008, 8:31 PM 

This song, typically, does NOT play with 7.4.  The next song does:

Comment: Adjusted by iVolume 12/05/2006 20:55:38
Track Number: 2
File Format: Apple Lossless
Duration: 4:17
Volume Adjustment: -4.14 dB
Bitrate: 959kbps VBR
Sample Rate: 44.1 kHz
File Length: 32,071,442
Location: /Volumes/Music/Rhonda Smith/Intellipop/02 Say.m4a

I haven't tried playing song three, but can try that later on to see if it's ONLY the first or if others are affected.
Comment 13 Alan Young 2009-05-04 11:12:54 UTC
This may have been fixed by 7.4 change 26352, although, as I said in an earlier comment, I am unsure how it could have worked at all (before the fix above).
Comment 14 Eric Seaberg 2009-05-04 21:58:45 UTC
I just DL'd and installed 7.4-26358 and you are correct, the files that previously didn't play now do so.  Do you know what you fixed?  ;-)

Glad I could have a small part in this!!  Thanks.
Comment 15 Eric Seaberg 2009-05-04 22:00:49 UTC
BTW, this nightly worked WITHOUT having to rescan the library, even though I'm now doing it just to be safe.
Comment 16 Alan Young 2009-05-04 23:42:41 UTC
Indeed, you should not need to rescan.

What I changed was which types were recognized as *possibly* being Apple lossless. In 7.4 previously, this was only 'aac'. I added 'm4a' and 'mov' (probably unnecessary).  Without that change, I do not understand how any Apple lossless .m4a files would have played properly. But I admit that I do not fully understand the various mappings that occur between the internal (and database) designation of content-type, and the filename suffix.

I plan further changes in this area which should make handling of such filetypes more reliable; see bug 11947.

I'll close this bug now.
Comment 17 James Richardson 2009-10-05 14:33:24 UTC
This bug has been marked as fixed in the 7.4.0 release version of SqueezeBox Server!
    * SqueezeCenter: 28672
    * Squeezebox 2 and 3: 130
    * Transporter: 80
    * Receiver: 65
    * Boom: 50
    * Controller: 7790
    * Radio: 7790  

Please see the Release Notes for all the details: http://wiki.slimdevices.com/index.php/Release_Notes

If you haven't already, please download and install the new version from http://www.logitechsqueezebox.com/support/download-squeezebox-server.html

If you are still experiencing this problem, feel free to reopen the bug with your new comments and we'll have another look.