PDA

View Full Version : 1/14 nightly badly broken



Mark A. Aiken
2004-01-14, 23:33
I stepped up to the 1/14 build in the hopes that it would address the few glitches I'm still experiencing. I updated the SB by holding down 'brightness' -- that appeared to go OK.

Much to my dismay, though, whenever I try to play a track from my SB (all my tracks are FLAC), nothing much happens, and after a few moments, the SB complains that it has lost touch with the server.

I ran the server as "slim --d_source --d_command --d_control --d_protocol" but the output doesn't make the source of the failure very clear. In this case, after briging up the server, I tried to hit jump-fwd to start the next track in the playlist, and the server went down:

2004-01-14 22:26:36.8897 Executing command 00:04:20:05:10:66: ir (7689a05f) (43109.007) () () () ()
2004-01-14 22:26:36.8897 Executing command 00:04:20:05:10:66: button () (43109.007) () () () ()
2004-01-14 22:26:36.8897 Returning array: button () (43109.007) () () () ()
2004-01-14 22:26:36.8897 Returning array: ir (7689a05f) (43109.007) () () () ()
2004-01-14 22:26:36.9991 Executing command 00:04:20:05:10:66: ir (7689a05f) (43109.115) () () () ()
2004-01-14 22:26:36.9991 Returning array: ir (7689a05f) (43109.115) () () () ()
2004-01-14 22:26:37.1553 Executing command 00:04:20:05:10:66: button (jump_fwd) (43109.263) () () () ()
2004-01-14 22:26:37.1553 Executing command 00:04:20:05:10:66: playlist (jump) (+1) () () () ()
2004-01-14 22:26:37.1553 00:04:20:05:10:66: Switching to mode stop
2004-01-14 22:26:37.1553 00:04:20:05:10:66 New play mode: stop
2004-01-14 22:26:37.1553 Stopping and clearing out old chunks for client 00:04:20:05:10:66
Terminating on signal SIGHUP(1)

Mark

kdf
2004-01-14, 23:46
Quoting "Mark A. Aiken" <mark_aiken (AT) hotmail (DOT) com>:

> I stepped up to the 1/14 build in the hopes that it would address the few
> glitches I'm still experiencing. I updated the SB by holding down
> 'brightness' -- that appeared to go OK.
>
> Much to my dismay, though, whenever I try to play a track from my SB (all
> my tracks are FLAC), nothing much happens, and after a few moments, the SB
> complains that it has lost touch with the server.
>
> I ran the server as "slim --d_source --d_command --d_control
> --d_protocol" but the output doesn't make the source of the failure very

please try running it with just --d_source you should see all the info you need
when it tries to open the FLAC files.

-kdf

Mark A. Aiken
2004-01-15, 00:24
Boy am I unhappy now -- I stepped back to 1/13, then 1/10, reflashing my
SB each time, with the same results. Then I gave up and stepped back to 1/9,
which was the build I was using previously, reflashed, and am still
experiencing the same problem! Ugh.

At each stage, I found that I was sometimes able to play one or two
tracks, but browsing to another track to play, or trying to jump forward to
the next playlist track, almost always brings down the server.

I noticed that when the server goes down, it leaves an instance of
FLAC.exe running, and the server won't start again, complaining that another
server is already running, until I kill the FLAC process.

Back on the 1/9 build, I ran with all the flags that seemed remotely
applicable:
"slim --d_cli --d_command --d_control --d_display --d_files --d_firmware --d
_formats --d_info --d_ir --d_paths --d_parse --d_playlist --d_protocol --d_s
erver --d_scheduler --d_slimproto --d_source --d_stream --d_ui". Here is the
last piece of output:

[Lots of stuff about playing a track that did start coming out the
speakers successfully, including extensive decoding information about the
file's path, and how FLAC was started. Then I hit the forward-arrow to jump
to the next track in the playlist]:

line1: Squeezebox Home
line2: Now Playing vfD_rightarrow_Vfd

2004-01-14 23:03:24.3903 Squeezebox stream status:
event_code: vfdc
num_crlf: 4
mas_initiliazed: 112
mas_mode: 11
rptr: 12740
wptr: 8972
bytes_rec_H 0
bytes_rec_L 532480
fullness: 258376
byteoffset: 0
bytes_received 532480
signal_strength: 58
jiffies: 23678
2004-01-14 23:03:25.2341 Executing command 00:04:20:05:10:66: ir (7689a05f)
(24.52) () () () ()
2004-01-14 23:03:25.2341 7689a05f 24.52 1074150205.23412
2004-01-14 23:03:25.2341 irfile entry: Slim_Devices_Remote.ir
2004-01-14 23:03:25.2341 irfile entry: jvc_dvd.ir
2004-01-14 23:03:25.2341 found button fwd for 7689a05f
2004-01-14 23:03:25.2341 irCode not defined: fwd
2004-01-14 23:03:25.2341 irCode = [] timer = [24.52] timediff = [4.759] last
= [jump_fwd]
2004-01-14 23:03:25.2341 irCode: , 00:04:20:05:10:66
2004-01-14 23:03:25.2341 Executing command 00:04:20:05:10:66: button ()
(24.52) () () () ()
2004-01-14 23:03:25.2341 irCode not defined:
2004-01-14 23:03:25.2341 trying to execute button:
2004-01-14 23:03:25.2341 button not implemented in this mode
2004-01-14 23:03:25.2497 Returning array: button () (24.52) () () () ()
2004-01-14 23:03:25.2497 Returning array: ir (7689a05f) (24.52) () () () ()
2004-01-14 23:03:25.3434 Executing command 00:04:20:05:10:66: ir (7689a05f)
(24.629) () () () ()
2004-01-14 23:03:25.3434 7689a05f 24.629 1074150205.3435
2004-01-14 23:03:25.3434 irfile entry: Slim_Devices_Remote.ir
2004-01-14 23:03:25.3434 irfile entry: jvc_dvd.ir
2004-01-14 23:03:25.3434 found button fwd for 7689a05f
2004-01-14 23:03:25.3434 irCode not defined: fwd.repeat
2004-01-14 23:03:25.3434 irCode = [] timer = [24.629] timediff =
[0.109000000000002] last = []
2004-01-14 23:03:25.3434 Returning array: ir (7689a05f) (24.629) () () ()
()
2004-01-14 23:03:25.3903 vfdUpdate european
line1: Squeezebox Home
line2: Now Playing vfD_rightarrow_Vfd

2004-01-14 23:03:25.3903 Squeezebox stream status:
event_code: vfdc
num_crlf: 4
mas_initiliazed: 112
mas_mode: 11
rptr: 189218
wptr: 185926
bytes_rec_H 0
bytes_rec_L 709176
fullness: 258852
byteoffset: 0
bytes_received 709176
signal_strength: 58
jiffies: 24679
2004-01-14 23:03:25.4997 irfile entry: Slim_Devices_Remote.ir
2004-01-14 23:03:25.4997 irfile entry: jvc_dvd.ir
2004-01-14 23:03:25.4997 found button fwd for 7689a05f
2004-01-14 23:03:25.4997 found function jump_fwd for button fwd.single in
mode common from map C:\Program Files\SlimServer\server\IR\Default.map
2004-01-14 23:03:25.4997 irCode: jump_fwd, 00:04:20:05:10:66
2004-01-14 23:03:25.4997 Executing command 00:04:20:05:10:66: button
(jump_fwd) (24.776) () () () ()
2004-01-14 23:03:25.4997 irCode not defined: jump_fwd
2004-01-14 23:03:25.4997 trying to execute button: jump_fwd
2004-01-14 23:03:25.4997 executing button: jump_fwd
2004-01-14 23:03:25.4997 Executing command 00:04:20:05:10:66: playlist
(jump) (+1) () () () ()
2004-01-14 23:03:25.4997 00:04:20:05:10:66: Switching to mode stop
2004-01-14 23:03:25.4997 00:04:20:05:10:66 New play mode: stop
2004-01-14 23:03:25.4997 Stopping and clearing out old chunks for client
00:04:20:05:10:66
2004-01-14 23:03:25.4997 presetting streamed bytes to: 0
2004-01-14 23:03:25.4997 *************stream called: q
2004-01-14 23:03:25.4997 starting with decoder with options: format: m
samplesiz
e: ? samplerate: ? endian: ? channels: ?
Terminating on signal SIGHUP(1)

Just for fun, here is the corresponding section from the spew from
playing the previous track, which started to play successfully (I imagine
this is what the healthy server looks like):

2004-01-14 23:03:20.0778 executing button: jump_fwd
2004-01-14 23:03:20.0778 Executing command 00:04:20:05:10:66: playlist
(jump) (+1) () () () ()
2004-01-14 23:03:20.0778 00:04:20:05:10:66: Switching to mode stop
2004-01-14 23:03:20.0778 Already in playmode stop : ignoring mode change
2004-01-14 23:03:20.0778 00:04:20:05:10:66: Current playmode: stop
2004-01-14 23:03:20 22004-01-14 23:03:20.0778 00:04:20:05:10:66: Switching
to mode play
2004-01-14 23:03:20.0778 presetting streamed bytes to: 0
2004-01-14 23:03:20.0778 openSong on: E:\music\Paris Combo\Living-Room\02 -
Terrien d'eau douce.flac
2004-01-14 23:03:20.0778 openSong: getting duration 186.666666666667, size
2156
7803, and offset 4630 for E:\music\Paris Combo\Living-Room\02 - Terrien
d'eau douce.flac
2004-01-14 23:03:20.0778 checking formats for:
flc-aif-squeezebox-00:04:20:05:10:66
2004-01-14 23:03:20.0778 checking formats for:
flc-wav-squeezebox-00:04:20:05:10:66
2004-01-14 23:03:20.0778 Matched flc-checkformat-squeezebox-*
2004-01-14 23:03:20.0778 openSong: this is an flc file: E:\music\Paris
Combo\Living-Room\02 - Terrien d'eau douce.flac
2004-01-14 23:03:20.0778 file type: flc format: wav
2004-01-14 23:03:20.0778 command:
$flac$ -dcs --force-raw-format --endian=little --sign=signed $FILE$
2004-01-14 23:03:20.1559 Found binary C:\ProgramFiles\FLAC\flac.exe for
flac.exe
2004-01-14 23:03:20.1559 Using command for conversion:
"C:\ProgramFiles\FLAC\flac.exe" -dcs --force-raw-format --endian=little --si
gn=signed "E:\music\Paris Com
bo\Living-Room\02 - Terrien d'eau douce.flac" |
piping
"C:\ProgramFiles\FLAC\flac.exe" -dcs --force-raw-format --endian=little --si
gn=signed "E:\music\Paris Combo\Living-Room\02 - Terrien d'eau douce.flac"
2004-01-14 23:03:21.3122 Streaming with format: wav
2004-01-14 23:03:21.3591 00:04:20:05:10:66 New play mode: play
2004-01-14 23:03:21.3591 volume: 1
2004-01-14 23:03:21.3591 *************stream called: s
2004-01-14 23:03:21.3591 starting with decoder with options: format: p
samplesize: 1 samplerate: 3 endian: 1 channels: 2
2004-01-14 23:03:21.3591 volume: 1

[music ensues]

Help!

Mark

----- Original Message -----
From: "kdf" <slim-mail (AT) deane-freeman (DOT) com>
To: "Slim Devices Discussion" <discuss (AT) lists (DOT) slimdevices.com>
Sent: Wednesday, January 14, 2004 10:46 PM
Subject: [slim] 1/14 nightly badly broken


> Quoting "Mark A. Aiken" <mark_aiken (AT) hotmail (DOT) com>:
>
> > I stepped up to the 1/14 build in the hopes that it would address
the few
> > glitches I'm still experiencing. I updated the SB by holding down
> > 'brightness' -- that appeared to go OK.
> >
> > Much to my dismay, though, whenever I try to play a track from my SB
(all
> > my tracks are FLAC), nothing much happens, and after a few moments, the
SB
> > complains that it has lost touch with the server.
> >
> > I ran the server as "slim --d_source --d_command --d_control
> > --d_protocol" but the output doesn't make the source of the failure very
>
> please try running it with just --d_source you should see all the info you
need
> when it tries to open the FLAC files.
>
> -kdf
>

kdf
2004-01-15, 00:40
Quoting "Mark A. Aiken" <mark_aiken (AT) hotmail (DOT) com>:

> Boy am I unhappy now -- I stepped back to 1/13, then 1/10, reflashing my
> SB each time, with the same results. Then I gave up and stepped back to 1/9,
> which was the build I was using previously, reflashed, and am still
> experiencing the same problem! Ugh.

Unfortunately, many of the lead devs on this stuff are sleeping. Please have
patience. I'm sure it will be fixed within a day. I've bee playing around with
a few flac tunes in teh last few days using cvs updates. I can confirm that
tonight, the same thing happen on my system. I have placed several debug
messages within Source.pm and none of them are coming up. CPU usage drops down
to near nothing, and the server doesn't crash. This would seem to be an
infinite loop that somehow snuck in.

The firmware was update in the latest nightly. Did you upgrade? Did you
downgrade when you went back? I'm trying out a few things myself, but it
getting late even for me :)

cheers,
kdf

Dan Sully
2004-01-15, 00:50
* kdf <slim-mail (AT) deane-freeman (DOT) com> shaped the electrons to say...

> > Boy am I unhappy now -- I stepped back to 1/13, then 1/10, reflashing my
> > SB each time, with the same results. Then I gave up and stepped back to 1/9,
> > which was the build I was using previously, reflashed, and am still
> > experiencing the same problem! Ugh.
>
> Unfortunately, many of the lead devs on this stuff are sleeping. Please have
> patience. I'm sure it will be fixed within a day. I've bee playing around with
> a few flac tunes in teh last few days using cvs updates. I can confirm that
> tonight, the same thing happen on my system. I have placed several debug
> messages within Source.pm and none of them are coming up. CPU usage drops down
> to near nothing, and the server doesn't crash. This would seem to be an
> infinite loop that somehow snuck in.
>
> The firmware was update in the latest nightly. Did you upgrade? Did you
> downgrade when you went back? I'm trying out a few things myself, but it
> getting late even for me :)

I just did a clean checkout of CVS, and am able to play FLAC files just fine.

Note - I have not updated to the latest firmware that was checked in a few days ago.

-D
--
We toons may act idiotic, but we're not stupid.

Mark A. Aiken
2004-01-15, 01:04
Thanks to kdf for weighing in so late. I'm not as freaked out anymore
because I uninstalled the Slimserver and then reinstalled the 1/9 build and
my SB is back to functional again, so I'm no worse off than before. Does the
install process wipe the server install area clean? This issue would seem to
have something to do with persistent state that would survive the install of
a different version...

kdf asks about firmware -- I had picked up the 1/14 build precisely
because I was curious about the new firmware. I did update my SB right after
installing the new build. As I stepped down to previous builds, I updated
the SB each time. When I uninstalled and reinstalled the 1/9 build, I did
NOT update the SB (since I figured I already had the right firmware
version), and my setup nonetheless started working correctly again.

I also saw the server go catatonic a few times with the 1/14 build. The
SB would claim to have lost contact, but the server process would still be
running. However, the 1/14 build definitely just went down serveral times,
as well. After stepping down to earlier builds, it always seemed to crash
rather than zone out.

If anyone's having a lot of trouble reproing this, I can help out, now
that it would seem that I can get back to a working state without too much
trouble. But kdf, it sounds like you have this reproing?

Mark

----- Original Message -----
From: "Dan Sully" <daniel (AT) electricrain (DOT) com>
To: "Slim Devices Discussion" <discuss (AT) lists (DOT) slimdevices.com>
Sent: Wednesday, January 14, 2004 11:50 PM
Subject: [slim] 1/14 nightly badly broken


> * kdf <slim-mail (AT) deane-freeman (DOT) com> shaped the electrons to say...
>
> > > Boy am I unhappy now -- I stepped back to 1/13, then 1/10,
reflashing my
> > > SB each time, with the same results. Then I gave up and stepped back
to 1/9,
> > > which was the build I was using previously, reflashed, and am still
> > > experiencing the same problem! Ugh.
> >
> > Unfortunately, many of the lead devs on this stuff are sleeping. Please
have
> > patience. I'm sure it will be fixed within a day. I've bee playing
around with
> > a few flac tunes in teh last few days using cvs updates. I can confirm
that
> > tonight, the same thing happen on my system. I have placed several
debug
> > messages within Source.pm and none of them are coming up. CPU usage
drops down
> > to near nothing, and the server doesn't crash. This would seem to be an
> > infinite loop that somehow snuck in.
> >
> > The firmware was update in the latest nightly. Did you upgrade? Did
you
> > downgrade when you went back? I'm trying out a few things myself, but
it
> > getting late even for me :)
>
> I just did a clean checkout of CVS, and am able to play FLAC files just
fine.
>
> Note - I have not updated to the latest firmware that was checked in a few
days ago.
>
> -D
> --
> We toons may act idiotic, but we're not stupid.
>

kdf
2004-01-15, 01:11
Quoting Dan Sully <daniel (AT) electricrain (DOT) com>:


> I just did a clean checkout of CVS, and am able to play FLAC files just
> fine.
>
> Note - I have not updated to the latest firmware that was checked in a few
> days ago.

mp3 files are fine. ogg, flac are not so far. well, for me. but I've upgraded
the firmware. trying to downgrade firmware and see what happens.

-kdf

kdf
2004-01-15, 01:51
I've narrowed it down to a line in Source.pm. Inside openNext, there is
closeSong($client). After playing a FLAC or ogg, it stops there. Not crashing,
but no longer responding. I can print some text just before it, but never after.

within closeSong, it stops on: $client->audioFilehandle->close();

I have tried to back up on the firmware, to no avail.

Dan,any ideas from that? I can understand not wanting to get caught in this
loop, but if you do upgrade the firmware and the same problems, maybe you'll
have better luck with it.

cheers,
kdf

kdf
2004-01-15, 02:41
going back to nightly Jan 12 worked for me.

sleep time now.

-kdf

kdf
2004-01-15, 03:01
some more info...its getting stuck after the print statement. This is from
Slim::Utils::Filehandle.pm

if(defined($pipe_data{$class}->{'pidlist'})) {
print "*2";
kill 1, @{$pipe_data{$class}->{'pidlist'}};
wait;
}

-kdf

Roy M. Silvernail
2004-01-15, 04:33
On Thu, 2004-01-15 at 05:01, kdf wrote:
> some more info...its getting stuck after the print statement. This is from
> Slim::Utils::Filehandle.pm
>
> if(defined($pipe_data{$class}->{'pidlist'})) {
> print "*2";
> kill 1, @{$pipe_data{$class}->{'pidlist'}};
> wait;
> }

OK, that would be my neighborhood. Come to think of it, I saw some
strange stuff with 1/14 last night while working on the stream
transcoding.

Does this seem Windows-specific? I developed the process handling code
in FileHandle.pm on Linux, and don't have a Windows box I can test on.

Time to do some research.
--
Roy M. Silvernail is roy (AT) rant-central (DOT) com, and you're not
Never Forget: It's Only 1's and 0's!
SpamAssassin->procmail->/dev/null->bliss
http://www.rant-central.com

Roy M. Silvernail
2004-01-15, 04:35
On Thu, 2004-01-15 at 03:11, kdf wrote:
> Quoting Dan Sully <daniel (AT) electricrain (DOT) com>:
>
>
> > I just did a clean checkout of CVS, and am able to play FLAC files just
> > fine.
> >
> > Note - I have not updated to the latest firmware that was checked in a few
> > days ago.
>
> mp3 files are fine. ogg, flac are not so far. well, for me. but I've upgraded
> the firmware. trying to downgrade firmware and see what happens.

OK, it's definitely the process handling in FileHandle.pm
--
Roy M. Silvernail is roy (AT) rant-central (DOT) com, and you're not
Never Forget: It's Only 1's and 0's!
SpamAssassin->procmail->/dev/null->bliss
http://www.rant-central.com

Roy M. Silvernail
2004-01-15, 04:59
On Thu, 2004-01-15 at 06:35, Roy M. Silvernail wrote:

> OK, it's definitely the process handling in FileHandle.pm

A quick peruse of the perlfork() docs indicates that my *nix
expectations aren't holding up.

Dean, you might want to roll FileHandle.pm back out of the nightlies
until I have a chance to study this a bit.
--
Roy M. Silvernail is roy (AT) rant-central (DOT) com, and you're not
Never Forget: It's Only 1's and 0's!
SpamAssassin->procmail->/dev/null->bliss
http://www.rant-central.com