First Last Prev Next    This bug is not in your last search results.
Bug 1452 - volume drops from 40 to 7
: volume drops from 40 to 7
Status: RESOLVED WORKSFORME
Product: Logitech Media Server
Classification: Unclassified
Component: Audio
: 6.1.1
: PC Linux (other)
: P2 normal (vote)
: Future
Assigned To: Dan Sully
:
Depends on:
Blocks:
  Show dependency tree / graph
 
Reported: 2005-04-26 21:08 UTC by Jack Coates
Modified: 2011-03-16 04:19 UTC (History)
0 users

See Also:
Category: ---

Attachments
gzipped log (27.70 KB, application/octet-stream)
2005-06-13 07:56 UTC, Jack Coates 		Details
View All Add an attachment (proposed patch, testcase, etc.)

Note You need to log in before you can comment on or make changes to this bug.
Description Jack Coates 2005-04-26 21:08:07 UTC 
This has happened intermittently with all 6.x version, but won't happen while
any debugging is on of course... Mandrake 10.1, installing via RPM. I have a
SliMP3 and a wired SBG, synchronized (vol and power synchronized too). The
reproduction is to do the following (with web UI or remote):
1) power on the players
2) select an automatic playlist, either by browsing to year/album/artist or by
using a search function. I don't use many saved playlists, so I don't know if
this makes a difference.
3) play. The first song will be at volume 40 -- when switching to the second,
both players will drop volume to 7.

This reproduction method works about half the time, and I haven't been able to
capture any log information. These are MP3 tracks. I use AudioScrobbler and
AlienBBC plugins.
Comment 1 KDF 2005-04-27 01:37:40 UTC 
try d_slimproto, d_command, and d_prefs
volume is a hard one to track (if its not ir triggered), without adding specific
code.
Comment 2 Blackketter Dean 2005-05-20 16:22:08 UTC 
Jack:  do you have any logging information that you can include here?  I'm not seeing this and I haven't 
heard any other reports...
Comment 3 Blackketter Dean 2005-06-07 16:08:40 UTC 
Jack: is this still happening for you?
Comment 4 Jack Coates 2005-06-07 18:13:16 UTC 
Yes, but more intermittently. 6.0.x, will try 6.1 tonight
Comment 5 Jack Coates 2005-06-12 17:14:57 UTC 
[jack@felix jack]$ rpm -q slimserver
slimserver-2005_06_09-1

Still there.... nothing in the log without the d_* statements suggested by kdf
(I had turned them off for a bit, and that's when it happened). I've got
debugging back on and all it's doing is increasing the lag between Slimp3 and SBG.

Ooh, did get something at a song transfer (though it's not the 40 to 7 bug).
Looks like both buffers empty out between songs, causing proto errors?

2005-06-12 17:10:49.1681 Got Slimproto frame, op STAT, length 29,
IO::Socket::INET=GLOB(0x9829e38)
2005-06-12 17:10:49.1687 00:04:20:05:59:be Squeezebox stream status:
        fullness:        229375 (99%)
        bytes_received   5044135
Use of uninitialized value in concatenation (.) or string at
/usr/local/slimserver/Slim/Player/Squeezebox.pm line 524.
Use of uninitialized value in concatenation (.) or string at
/usr/local/slimserver/Slim/Player/Squeezebox.pm line 524.
Use of uninitialized value in concatenation (.) or string at
/usr/local/slimserver/Slim/Player/Squeezebox.pm line 524.
2005-06-12 17:10:49.1693 *************stream called: q paused:  format:  url:
2005-06-12 17:10:49.1697 Backtrace:

   frame 0: Slim::Player::Squeezebox::stream
(/usr/local/slimserver/Slim/Player/Squeezebox.pm line 192)
   frame 1: Slim::Player::Squeezebox::stop
(/usr/local/slimserver/Slim/Player/Source.pm line 553)
   frame 2: Slim::Player::Source::underrun
(/usr/local/slimserver/Slim/Networking/Slimproto.pm line 501)
   frame 3: Slim::Networking::Slimproto::process_slimproto_frame
(/usr/local/slimserver/Slim/Networking/Slimproto.pm line 236)
   frame 4: Slim::Networking::Slimproto::client_readable
(/usr/local/slimserver/Slim/Networking/Select.pm line 115)
   frame 5: Slim::Networking::Select::select
(/usr/local/slimserver/slimserver.pl line 625)
   frame 6: main::idle (/usr/local/slimserver/slimserver.pl line 568)
   frame 7: main::main (/usr/local/slimserver/slimserver.pl line 1155)

2005-06-12 17:10:49.1700 starting with decoder with format: m autostart: 0
threshold: 255 samplesize: ? samplerate: ? endian: ? channels: ?
2005-06-12 17:10:49.1702 sending strm frame of length: 76 request string:
GET /stream.mp3?player=00:04:20:05:59:be HTTP/1.0
2005-06-12 17:10:49.1730 Got Slimproto frame, op STAT, length 29,
IO::Socket::INET=GLOB(0x9829e38)
2005-06-12 17:10:49.1736 00:04:20:05:59:be Squeezebox stream status:
        fullness:        0 (0%)
        bytes_received   0
2005-06-12 17:10:49.1742 Got Slimproto frame, op STAT, length 29,
IO::Socket::INET=GLOB(0x9829e38)
2005-06-12 17:10:49.1745 00:04:20:05:59:be Squeezebox stream status:
        fullness:        0 (0%)
        bytes_received   0
Use of uninitialized value in concatenation (.) or string at
/usr/local/slimserver/Slim/Player/Squeezebox.pm line 524.
Use of uninitialized value in concatenation (.) or string at
/usr/local/slimserver/Slim/Player/Squeezebox.pm line 524.
Use of uninitialized value in concatenation (.) or string at
/usr/local/slimserver/Slim/Player/Squeezebox.pm line 524.
2005-06-12 17:10:49.2027 *************stream called: q paused:  format:  url:
2005-06-12 17:10:49.2032 Backtrace:

   frame 0: Slim::Player::Squeezebox::stream
(/usr/local/slimserver/Slim/Player/Squeezebox.pm line 192)
   frame 1: Slim::Player::Squeezebox::stop
(/usr/local/slimserver/Slim/Player/Source.pm line 448)
   frame 2: Slim::Player::Source::playmode
(/usr/local/slimserver/Slim/Player/Source.pm line 572)
   frame 3: Slim::Player::Source::skipahead
(/usr/local/slimserver/Slim/Player/Sync.pm line 342)
   frame 4: Slim::Player::Sync::checkSync
(/usr/local/slimserver/Slim/Networking/Protocol.pm line 66)
   frame 5: Slim::Networking::Protocol::processMessage
(/usr/local/slimserver/Slim/Networking/Protocol.pm line 139)
   frame 6: Slim::Networking::Protocol::readUDP
(/usr/local/slimserver/Slim/Networking/Select.pm line 115)
   frame 7: Slim::Networking::Select::select
(/usr/local/slimserver/slimserver.pl line 625)
   frame 8: main::idle (/usr/local/slimserver/slimserver.pl line 568)
   frame 9: main::main (/usr/local/slimserver/slimserver.pl line 1155)

2005-06-12 17:10:49.2035 starting with decoder with format: m autostart: 0
threshold: 255 samplesize: ? samplerate: ? endian: ? channels: ?
2005-06-12 17:10:49.2037 sending strm frame of length: 76 request string:
GET /stream.mp3?player=00:04:20:05:59:be HTTP/1.0


2005-06-12 17:10:54.1036 Setting prefs 00:04:20:05:59:be-currentSong equal to 1
2005-06-12 17:10:54.1042 Setting prefs 00:04:20:04:03:39-currentSong equal to 1
2005-06-12 17:10:54.1527 *************stream called: s paused:
Slim::Player::SLIMP3=ARRAY(0x9ffc768) format: mp3 url:
file:///mnt/music/Apples%20In%20Stereo/Velocity%20Of%20Sound/02_Rainfall.mp3
2005-06-12 17:10:54.1533 Backtrace:

   frame 0: Slim::Player::Squeezebox::stream
(/usr/local/slimserver/Slim/Player/Squeezebox.pm line 144)
   frame 1: Slim::Player::Squeezebox::play
(/usr/local/slimserver/Slim/Player/Source.pm line 468)
   frame 2: Slim::Player::Source::playmode
(/usr/local/slimserver/Slim/Player/Source.pm line 579)
   frame 3: Slim::Player::Source::skipahead
(/usr/local/slimserver/Slim/Player/Sync.pm line 342)
   frame 4: Slim::Player::Sync::checkSync
(/usr/local/slimserver/Slim/Networking/Protocol.pm line 66)
   frame 5: Slim::Networking::Protocol::processMessage
(/usr/local/slimserver/Slim/Networking/Protocol.pm line 139)
   frame 6: Slim::Networking::Protocol::readUDP
(/usr/local/slimserver/Slim/Networking/Select.pm line 115)
   frame 7: Slim::Networking::Select::select
(/usr/local/slimserver/slimserver.pl line 625)
   frame 8: main::idle (/usr/local/slimserver/slimserver.pl line 568)
   frame 9: main::main (/usr/local/slimserver/slimserver.pl line 1155)

2005-06-12 17:10:54.1536 starting with decoder with format: m autostart: 0
threshold: 128 samplesize: ? samplerate: ? endian: ? channels: ?
2005-06-12 17:10:54.1539 sending strm frame of length: 76 request string:
GET /stream.mp3?player=00:04:20:05:59:be HTTP/1.0



2005-06-12 17:10:54.4284 Got Slimproto frame, op STAT, length 29,
IO::Socket::INET=GLOB(0x9829e38)
2005-06-12 17:10:54.4289 00:04:20:05:59:be Squeezebox stream status:
        fullness:        0 (0%)
        bytes_received   0
2005-06-12 17:10:54.4295 Got Slimproto frame, op STAT, length 29,
IO::Socket::INET=GLOB(0x9829e38)
2005-06-12 17:10:54.4299 00:04:20:05:59:be Squeezebox stream status:
        fullness:        0 (0%)
        bytes_received   0
2005-06-12 17:10:54.4306 Got Slimproto frame, op STAT, length 29,
IO::Socket::INET=GLOB(0x9829e38)
2005-06-12 17:10:54.4311 00:04:20:05:59:be Squeezebox stream status:
        fullness:        0 (0%)
        bytes_received   0
2005-06-12 17:10:54.4316 Got Slimproto frame, op STAT, length 29,
IO::Socket::INET=GLOB(0x9829e38)
2005-06-12 17:10:54.4320 00:04:20:05:59:be Squeezebox stream status:
        fullness:        0 (0%)
        bytes_received   0
2005-06-12 17:10:54.4326 Got Slimproto frame, op STAT, length 29,
IO::Socket::INET=GLOB(0x9829e38)
2005-06-12 17:10:54.4329 00:04:20:05:59:be Squeezebox stream status:
        fullness:        0 (0%)
        bytes_received   0
2005-06-12 17:10:54.4335 Got Slimproto frame, op STAT, length 29,
IO::Socket::INET=GLOB(0x9829e38)
2005-06-12 17:10:54.4338 00:04:20:05:59:be Squeezebox stream status:
        fullness:        0 (0%)
        bytes_received   0
2005-06-12 17:10:54.4344 Got Slimproto frame, op STAT, length 29,
IO::Socket::INET=GLOB(0x9829e38)
2005-06-12 17:10:54.4347 00:04:20:05:59:be Squeezebox stream status:
        fullness:        0 (0%)
        bytes_received   0
2005-06-12 17:10:54.4353 Got Slimproto frame, op STAT, length 29,
IO::Socket::INET=GLOB(0x9829e38)
2005-06-12 17:10:54.4356 00:04:20:05:59:be Squeezebox stream status:
        fullness:        0 (0%)
        bytes_received   0
2005-06-12 17:10:54.4362 Got Slimproto frame, op STAT, length 29,
IO::Socket::INET=GLOB(0x9829e38)
2005-06-12 17:10:54.4365 00:04:20:05:59:be Squeezebox stream status:
        fullness:        0 (0%)
        bytes_received   0
2005-06-12 17:10:54.4371 Got Slimproto frame, op STAT, length 29,
IO::Socket::INET=GLOB(0x9829e38)
2005-06-12 17:10:54.4374 00:04:20:05:59:be Squeezebox stream status:
        fullness:        0 (0%)
        bytes_received   0
2005-06-12 17:10:54.4631 Got Slimproto frame, op STAT, length 29,
IO::Socket::INET=GLOB(0x9829e38)
2005-06-12 17:10:54.4636 00:04:20:05:59:be Squeezebox stream status:
        fullness:        0 (0%)
        bytes_received   0
2005-06-12 17:10:54.4642 Got Slimproto frame, op RESP, length 137,
IO::Socket::INET=GLOB(0x9829e38)
2005-06-12 17:10:54.4644 Squeezebox got HTTP response:
HTTP/1.0 200 OK
Date: Mon, 13 Jun 2005 00:10:54 GMT
Server: SlimServer (6.1.0 - trunk)
Connection: close
Content-Type: audio/mpeg


2005-06-12 17:10:54.5201 Got Slimproto frame, op STAT, length 29,
IO::Socket::INET=GLOB(0x9829e38)
2005-06-12 17:10:54.5207 00:04:20:05:59:be Squeezebox stream status:
        fullness:        8400 (3%)
        bytes_received   8400
Use of uninitialized value in concatenation (.) or string at
/usr/local/slimserver/Slim/Player/Squeezebox.pm line 524.
Use of uninitialized value in concatenation (.) or string at
/usr/local/slimserver/Slim/Player/Squeezebox.pm line 524.
Use of uninitialized value in concatenation (.) or string at
/usr/local/slimserver/Slim/Player/Squeezebox.pm line 524.
2005-06-12 17:10:54.5215 *************stream called: u paused:  format:  url:
2005-06-12 17:10:54.5219 Backtrace:

   frame 0: Slim::Player::Squeezebox::stream
(/usr/local/slimserver/Slim/Player/Squeezebox.pm line 169)
   frame 1: Slim::Player::Squeezebox::resume
(/usr/local/slimserver/Slim/Player/Sync.pm line 322)
   frame 2: Slim::Player::Sync::checkSync
(/usr/local/slimserver/Slim/Networking/Slimproto.pm line 497)
   frame 3: Slim::Networking::Slimproto::process_slimproto_frame
(/usr/local/slimserver/Slim/Networking/Slimproto.pm line 236)
   frame 4: Slim::Networking::Slimproto::client_readable
(/usr/local/slimserver/Slim/Networking/Select.pm line 115)
   frame 5: Slim::Networking::Select::select
(/usr/local/slimserver/slimserver.pl line 625)
   frame 6: main::idle (/usr/local/slimserver/slimserver.pl line 568)
   frame 7: main::main (/usr/local/slimserver/slimserver.pl line 1155)

2005-06-12 17:10:54.5222 starting with decoder with format: m autostart: 1
threshold: 255 samplesize: ? samplerate: ? endian: ? channels: ?
2005-06-12 17:10:54.5225 sending strm frame of length: 76 request string:
GET /stream.mp3?player=00:04:20:05:59:be HTTP/1.0


2005-06-12 17:10:54.5262 Got Slimproto frame, op STAT, length 29,
IO::Socket::INET=GLOB(0x9829e38)
2005-06-12 17:10:54.5267 00:04:20:05:59:be Squeezebox stream status:
        fullness:        9798 (4%)
        bytes_received   9800
Comment 6 Jack Coates 2005-06-13 07:56:44 UTC 
Created attachment 546 [details]
gzipped log
Comment 7 Blackketter Dean 2005-06-13 15:57:07 UTC 
Jack: do you have volume synced in your sync setup?  

there's nothing obvious in the log that's the issue.
Comment 8 Jack Coates 2005-06-13 16:02:53 UTC 
yes, volume and power are synced. Both drop volume at the same time. I upgraded
to 6/13 nightly and it hasn't recurred yet (I'm sure it will, though).
Comment 9 KDF 2005-08-09 09:55:42 UTC 
is this still cropping up in 6.1.2 or 6.2 builds, Jack?
Comment 10 Jack Coates 2005-08-12 20:49:09 UTC 
It does seem to have gone away when I upgraded my SliMP3 to a SB2. I suspect
there's something to do with synchronization between the two different
generation devices.
Comment 11 Jack Coates 2005-09-11 09:16:48 UTC 
It's back, now with an SBG and a SB2, nothing logged...
Comment 12 Jack Coates 2005-10-23 07:54:54 UTC 
I quit synchronizing but made no other changes (still 6.1.1, SB2 and SBG) and
the problem seems to be gone. So, looks like the volume synchronization code.
Comment 13 Dan Sully 2006-08-23 15:33:06 UTC 
Jack - is this still an issue with 6.5?
Comment 14 Jack Coates 2006-08-25 19:20:56 UTC 
I think it's gone... running 6.3 now, haven't had it happen in a very long time.
First Last Prev Next    This bug is not in your last search results.