Bug 3574 - Many songs won't play in 6.5
: Many songs won't play in 6.5
Status: RESOLVED FIXED
Product: Logitech Media Server
Classification: Unclassified
Component: Streaming From SlimServer
: 6.5b1
: PC Windows XP
: P2 major (vote)
: ---
Assigned To: Dan Sully
:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2006-06-15 14:03 UTC by James Craig
Modified: 2008-09-15 14:39 UTC (History)
0 users

See Also:
Category: ---


Attachments
Example file that won't play (zipped) (3.20 MB, application/octet-stream)
2006-06-26 23:29 UTC, James Craig
Details

Note You need to log in before you can comment on or make changes to this bug.
Description James Craig 2006-06-15 14:03:46 UTC
At least 50% of my songs no longer play in SS6.5. 
They appear in the library but SlimServer can't play them!
Same songs play fine in pre-split scanner 6.5 or 6.2. Some are mp3s, some are m4a.

SlimServer Version: 6.5b1 - 7994 - Windows XP - EN - cp1252

This is example output from d_source.

2006-06-15 21:58:32.3529 92:be:92:55:ac:7c: Current playmode: stop
2006-06-15 21:58:32.3531 jumping to 1
2006-06-15 21:58:32.3534 Adding song index 1 to song queue
2006-06-15 21:58:32.3537 Clearing out song queue first
2006-06-15 21:58:32.3540 Song queue is now 1
2006-06-15 21:58:32.3551 92:be:92:55:ac:7c: Switching to mode play from stop
2006-06-15 21:58:32.3820 openSong on: file:///E:/Compilations/Live%20at%20the%20Social,%20Vol.%203%20-%20Andrew%20Weat/1
4%20Max%20Is%20the%20Mentor.mp3
2006-06-15 21:58:32.3842 Use of uninitialized value in concatenation (.) or string at /PerlApp/Slim/Player/Source.pm lin
e 1368.
2006-06-15 21:58:32.3896 openSong: getting duration  195.474, size , endian  and offset 0 for file:///E:/Compilations/Li
ve%20at%20the%20Social,%20Vol.%203%20-%20Andrew%20Weat/14%20Max%20Is%20the%20Mentor.mp3
2006-06-15 21:58:32.3907 Setting maxBitRate for Study to: 0
2006-06-15 21:58:32.3911 Setting maxBitRate for Study to: 0
2006-06-15 21:58:32.3921 Setting maxBitRate for Study to: 0
2006-06-15 21:58:32.3928 Setting maxBitRate for Study to: 0
2006-06-15 21:58:32.3933 undermax = 1, type = mp3, softsqueeze = 92:be:92:55:ac:7c
2006-06-15 21:58:32.3939 checking formats for: mp3-flc-softsqueeze-92:be:92:55:ac:7c
2006-06-15 21:58:32.3949 checking formats for: mp3-flc-*-92:be:92:55:ac:7c
2006-06-15 21:58:32.3955 checking formats for: mp3-flc-softsqueeze-*
2006-06-15 21:58:32.3959 checking formats for: mp3-flc-*-*
2006-06-15 21:58:32.3964 checking formats for: mp3-aif-softsqueeze-92:be:92:55:ac:7c
2006-06-15 21:58:32.3969 checking formats for: mp3-aif-*-92:be:92:55:ac:7c
2006-06-15 21:58:32.3974 checking formats for: mp3-aif-softsqueeze-*
2006-06-15 21:58:32.3978 checking formats for: mp3-aif-*-*
2006-06-15 21:58:32.3982 checking formats for: mp3-wav-softsqueeze-92:be:92:55:ac:7c
2006-06-15 21:58:32.3987 checking formats for: mp3-wav-*-92:be:92:55:ac:7c
2006-06-15 21:58:32.3992 checking formats for: mp3-wav-softsqueeze-*
2006-06-15 21:58:32.3996 checking formats for: mp3-wav-*-*
2006-06-15 21:58:32.4001 checking formats for: mp3-mp3-softsqueeze-92:be:92:55:ac:7c
2006-06-15 21:58:32.4006 checking formats for: mp3-mp3-*-92:be:92:55:ac:7c
2006-06-15 21:58:32.4010 checking formats for: mp3-mp3-softsqueeze-*
2006-06-15 21:58:32.4015 checking formats for: mp3-mp3-*-*
2006-06-15 21:58:32.4019 Checking to see if mp3-mp3-*-* is enabled
2006-06-15 21:58:32.4027    enabled
2006-06-15 21:58:32.4032   Found command: -
2006-06-15 21:58:32.4037 Setting maxBitRate for Study to: 0
2006-06-15 21:58:32.4043 Setting maxBitRate for Study to: 0
2006-06-15 21:58:32.4048 Matched Format: mp3 Type: mp3 Command: -
2006-06-15 21:58:32.4052 openSong: this is an mp3 file: file:///E:/Compilations/Live%20at%20the%20Social,%20Vol.%203%20-
%20Andrew%20Weat/14%20Max%20Is%20the%20Mentor.mp3
2006-06-15 21:58:32.4060   file type: mp3 format: mp3 inrate: 139 maxRate: 0
2006-06-15 21:58:32.4066   command: -
2006-06-15 21:58:32.4071 openSong: opening file E:\Compilations\Live at the Social, Vol. 3 - Andrew Weat\14 Max Is the M
entor.mp3
2006-06-15 21:58:32.4087 openSong: seeking in 0 into E:\Compilations\Live at the Social, Vol. 3 - Andrew Weat\14 Max Is
the Mentor.mp3
2006-06-15 21:58:32.4098 openSong: Streaming with format: mp3
2006-06-15 21:58:32.4147 92:be:92:55:ac:7c New play mode: play
2006-06-15 21:58:32.4208 92:be:92:55:ac:7c: Current playmode: play
2006-06-15 21:58:32.5229 Setting maxBitRate for Study to: 0
2006-06-15 21:58:32.5235 Setting maxBitRate for Study to: 0
2006-06-15 21:58:32.8063 We need to send 0 seconds of silence...
2006-06-15 21:58:32.8069 sending 0 bytes of silence
2006-06-15 21:58:32.8073 Use of uninitialized value in numeric gt (>) at /PerlApp/Slim/Player/Source.pm line 1687.
2006-06-15 21:58:32.8079 Use of uninitialized value in subtraction (-) at /PerlApp/Slim/Player/Source.pm line 1689.
2006-06-15 21:58:32.8085 Use of uninitialized value in concatenation (.) or string at /PerlApp/Slim/Player/Source.pm lin
e 1690.
2006-06-15 21:58:32.8091 Reduced chunksize to 0 at end of file ( - 0)
2006-06-15 21:58:32.8095 Use of uninitialized value in numeric gt (>) at /PerlApp/Slim/Player/Source.pm line 1699.
2006-06-15 21:58:32.8101 Use of uninitialized value in concatenation (.) or string at /PerlApp/Slim/Player/Source.pm lin
e 1739.
2006-06-15 21:58:32.8107 end of file or error on socket, opening next song, (song pos: 0(tell says: . 0 but true), total
bytes: )
2006-06-15 21:58:32.8113 Didn't stream any bytes for this song, so just mark it as played
2006-06-15 21:58:32.8118 opening next song...
2006-06-15 21:58:32.8132 the next song is number 2, was 1
Comment 1 James Craig 2006-06-25 07:39:36 UTC
Two more people have reported a similar issue in the forums. http://forums.slimdevices.com/showthread.php?t=24864
Comment 2 Dan Sully 2006-06-26 17:42:15 UTC
Can you please attach one of the files in question to this bug?

Thanks
Comment 3 James Craig 2006-06-26 23:29:42 UTC
Created attachment 1284 [details]
Example file that won't play (zipped)

d_source log (same song as before but last night's version of 6.5)

2006-06-27 07:27:29.6919 Setting maxBitRate for Study to: 0
2006-06-27 07:27:29.6921 Matched Format: mp3 Type: mp3 Command: -
2006-06-27 07:27:29.6956 openSong: this is an mp3 file: file:///E:/Compilations/Live%20at%20the%20Social,%20Vol.%203%20-
%20Andrew%20Weat/14%20Max%20Is%20the%20Mentor.mp3
2006-06-27 07:27:29.6959   file type: mp3 format: mp3 inrate: 139 maxRate: 0
2006-06-27 07:27:29.6961   command: -
2006-06-27 07:27:29.6966 openSong: opening file E:\Compilations\Live at the Social, Vol. 3 - Andrew Weat\14 Max Is the M
entor.mp3
2006-06-27 07:27:29.6976 openSong: seeking in 0 into E:\Compilations\Live at the Social, Vol. 3 - Andrew Weat\14 Max Is
the Mentor.mp3
2006-06-27 07:27:29.6990 openSong: Streaming with format: mp3
2006-06-27 07:27:29.9062 92:be:92:55:ac:7c New play mode: play
2006-06-27 07:27:29.9185 92:be:92:55:ac:7c: Current playmode: play
2006-06-27 07:27:30.0904 Setting maxBitRate for Study to: 0
2006-06-27 07:27:30.0909 Setting maxBitRate for Study to: 0
2006-06-27 07:27:30.5781 iTunesUpdate: Creating new PlayerStatus for Study (92:be:92:55:ac:7c)
2006-06-27 07:27:30.5895 iTunesUpdate: Starting a new song
2006-06-27 07:27:30.6219 iTunesUpdate: Starting to time file:///E:/Compilations/Live%20at%20the%20Social,%20Vol.%203%20-
%20Andrew%20Weat/14%20Max%20Is%20the%20Mentor.mp3
2006-06-27 07:27:30.6747 We need to send 0 seconds of silence...
2006-06-27 07:27:30.7067 sending 0 bytes of silence
2006-06-27 07:27:30.7074 Reduced chunksize to 0 at end of file ( - 0)
2006-06-27 07:27:30.7077 end of file or error on socket, opening next song, (song pos: 0(tell says: . 0 but true), total
bytes: )
2006-06-27 07:27:30.7079 Didn't stream any bytes for this song, so just mark it as played
2006-06-27 07:27:30.7081 opening next song...
Comment 4 Dan Sully 2006-06-27 11:02:02 UTC
James - that track works for me.

What does the line from --d_source that looks like this say for you?

openSong: duration: [170.068] size: [3401254] endian [] offset: [2048] for ...

It should be exactly the same.

If not, can you wipe & rescan?

Could you also try disabling the iTunesUpdate plugin?

Thanks.
Comment 5 James Craig 2006-06-27 15:46:54 UTC
OK
Disabled all non-standard plugins
Ran "scanner.exe --wipe --itunes"
Restarted SlimServer "slim.exe --d_source"
Started the example track:

2006-06-27 23:44:57.3086 openSong on: file:///E:/Compilations/Live%20at%20the%20Social,%20Vol.%203%20-%20Andrew%20Weat/1
4%20Max%20Is%20the%20Mentor.mp3
2006-06-27 23:44:57.3108 openSong: getting duration  195.474, size , endian  and offset 0 for file:///E:/Compilations/Li
ve%20at%20the%20Social,%20Vol.%203%20-%20Andrew%20Weat/14%20Max%20Is%20the%20Mentor.mp3
Comment 6 Dan Sully 2006-06-27 15:48:14 UTC
James - doesn't look like you're on the latest build.

The openSong() line should look like what I pasted - with brackets, etc.
Comment 7 James Craig 2006-06-28 14:27:30 UTC
had to wait for new .exe... this is what it looks like now:
2006-06-28 22:24:28.1915 openSong: duration: [195.474] size: [] endian [] offset: [0] for file:///E:/Compilations/Live%2
0at%20the%20Social,%20Vol.%203%20-%20Andrew%20Weat/14%20Max%20Is%20the%20Mentor.mp3

should there really be 3 slashes after file:?

will go and re-scan now...
Comment 8 Dan Sully 2006-06-28 14:32:09 UTC
Yes, the 3 slashes is fine..

Please let me know the result of the rescan.

For some reason, the file size & offset aren't making it into the database, which will cause audio not play.
Comment 9 James Craig 2006-06-28 14:55:57 UTC
Exactly the same after the wipe & rescan - which i can now do from the web interface;
2006-06-28 22:51:14.9119 openSong: duration: [195.474] size: [] endian [] offset: [0] for file:///E:/Compilations/Live%2
0at%20the%20Social,%20Vol.%203%20-%20Andrew%20Weat/14%20Max%20Is%20the%20Mentor.mp3
Comment 10 Dan Sully 2006-06-28 15:08:59 UTC
James - I just tried to reproduce on both Mac & Windows, and have been unable to.

Are you running SlimServer as a service? Is E: a network drive?

Trying to come up with possible suggestions..
Comment 11 James Craig 2006-06-29 02:23:17 UTC
I have a feeling what the problem is. 
If I "browse music" to the same track it works. 
So, compare the SQL from iTunes scan with filesystem scan:

Filesystem:
2006-06-29 08:43:55.4777 INSERT INTO tracks (audio, audio_offset, audio_size, bitrate, block_alignment, content_type, drm, filesize, lossless, remote, samplerate, secs, tagversion, timestamp, title, titlesearch, titlesort, url, year) VALUES
 (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) (`1', `256', `5390119', `128000', `1', `mp3', `0', `5390803',`0', `0', `44100', `336.9011875', `ID3v2.3.0', `1101645811', `Me And Giuliani Down By The Schoolyard [LFO Remix]', `ME AND GIULIANI DOWN BY THE SCHOOLYARD [LFO REMIX]', `ME AND GIULIANI DOWN BY THE SCHOOLYARD [LFO REMIX]', `file:///E:/!!!/!!!%20vs%20LFO/Me%20And%20Giuliani%20Down%20By%20The%20Schoolya.mp3', `2004')

iTunes:
2006-06-29 08:20:27.8046 INSERT INTO tracks (audio, bitrate, content_type, filesize, playcount, rating, remote, samplerate, secs, title, titlesearch, titlesort, tracknum, url, year) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) (`1',`143000', `mp3', `3855463', `1', `60', `0', `44100', `214.334', `Lab Drunk', `LAB DRUNK', `LAB DRUNK', `19', `file:///E:/RZA/RZA%20as%20Bobby%20Digital%20in%20Stereo/19%20Lab%20Drunk.mp3', `1998')

It looks to me like iTunes scan never populates audio_size and audio_offset values, which are what openSong is using?
Comment 12 Dan Sully 2006-06-29 08:50:40 UTC
Fixed in change 8203