First Last Prev Next    This bug is not in your last search results.
Bug 2373 - playlist play CLI command slow / doesn't play
: playlist play CLI command slow / doesn't play
Status: RESOLVED FIXED
Product: Logitech Media Server
Classification: Unclassified
Component: CLI
: 6.5b3
: PC Debian Linux
: P3 normal (vote)
: ---
Assigned To: Dan Sully
:
Depends on:
Blocks:
  Show dependency tree / graph
 
Reported: 2005-10-25 21:53 UTC by Jason Holtzapple
Modified: 2008-12-18 11:11 UTC (History)
2 users (show)

See Also:
Category: ---

Attachments
Allow playlistcontrol cmd:playlist_name (873 bytes, patch)
2006-09-25 15:10 UTC, Dan Sully 		Details | Diff
v10145 log (22.18 KB, text/plain)
2006-10-03 21:23 UTC, Jason Holtzapple 		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 Jason Holtzapple 2005-10-25 21:53:14 UTC 
I run a sequence of commands out of cron every night:
mixer volume 4, playlist shuffle 1, playlist play sleepytime

The last command takes a very long time to run (over 30 seconds according
to the debug output below) even though the playlist is only about 200
songs long. There is something going wrong because the player never actually
starts playing the playlist although the playmode does change to play.
This worked fine until 6.2 (or a recent nightly release).

Playing the playlist in question from the remote or web UI works fine
only the CLI seems to have trouble.

2005-10-25 21:39:22.4121 CLI: Parsing command: Found client [00:04:20:05:60:8a]
2005-10-25 21:39:22.4126 CLI: Parsing command: Found command, value [mixer]
2005-10-25 21:39:22.4128 CLI: Parsing command: Found param [1], value [volume]
2005-10-25 21:39:22.4131 CLI: Parsing command: Found param [2], value [4]
2005-10-25 21:39:22.4133 CLI: Processing command [mixer]
2005-10-25 21:39:22.4135 CLI: Forwarding [mixer] to Command.pm
2005-10-25 21:39:22.4165 CLI: Response: 00%3A04%3A20%3A05%3A60%3A8a mixer volume 4
2005-10-25 21:39:22.4182 CLI: Sending response...
2005-10-25 21:39:22.4188 CLI: No more messages to send to 127.0.0.1:60975
2005-10-25 21:39:24.4233 CLI: Parsing command: Found client [00:04:20:05:60:8a]
2005-10-25 21:39:24.4237 CLI: Parsing command: Found command, value [playlist]
2005-10-25 21:39:24.4240 CLI: Parsing command: Found param [1], value [shuffle]
2005-10-25 21:39:24.4242 CLI: Parsing command: Found param [2], value [1]
2005-10-25 21:39:24.4246 CLI: Processing command [playlist]
2005-10-25 21:39:24.4248 CLI: Forwarding [playlist] to Command.pm
2005-10-25 21:39:24.4352 CLI: Response: 00%3A04%3A20%3A05%3A60%3A8a playlist
shuffle 1
2005-10-25 21:39:24.4369 CLI: Sending response...
2005-10-25 21:39:24.4373 CLI: No more messages to send to 127.0.0.1:60975
2005-10-25 21:39:26.4432 CLI: Parsing command: Found client [00:04:20:05:60:8a]
2005-10-25 21:39:26.4436 CLI: Parsing command: Found command, value [playlist]
2005-10-25 21:39:26.4439 CLI: Parsing command: Found param [1], value [play]
2005-10-25 21:39:26.4441 CLI: Parsing command: Found param [2], value [sleepytime]
2005-10-25 21:39:26.4444 CLI: Processing command [playlist]
2005-10-25 21:39:26.4446 CLI: Forwarding [playlist] to Command.pm
2005-10-25 21:39:59.9231 CLI: Response: 00%3A04%3A20%3A05%3A60%3A8a playlist
play %2Fhome%2Fs
lim%2Fplaylists%2Fsleepytime.m3u
2005-10-25 21:39:59.9381 CLI: Sending response...
2005-10-25 21:39:59.9387 CLI: No more messages to send to 127.0.0.1:60975
2005-10-25 21:40:01.9419 CLI: Parsing command: Found command, value [exit]
2005-10-25 21:40:01.9423 CLI: Processing command [exit]
2005-10-25 21:40:01.9427 CLI: Response: exit
2005-10-25 21:40:01.9433 CLI: Sending response...
2005-10-25 21:40:01.9436 CLI: No more messages to send to 127.0.0.1:60975
2005-10-25 21:40:01.9445 CLI: Closed connection with 127.0.0.1:60975 (0 active
connections)
Comment 1 KDF 2005-10-26 00:00:26 UTC 
Jason, could you add d_command and d_source output for that missing 30 seconds?

Fred, any thoughts?
Comment 2 Fred 2005-10-26 03:38:03 UTC 
On 6.2 from the remote or the web UI, playing a playlists uses playlist IDs, not the name/path any 
longer (i.e. through command.pm "loadtracks" and not through "playlist play"). This part has seen little 
testing recently, only non updated CLI clients would use it...

Jason, if you know the playlist ID of "sleepytime" (or figure it out using the "playlists" command), you 
can use "playlistcontrol cmd:load playlist_id:XXX". You can maybe try it from a telnet session to see if 
that takes as long.

KDF, we know have 3 different playlist manipulation code, playlistcontrol, xxxtracks and playlist add. It 
is my intention to try and unify it to avoid this kind of problems. 
I will have a look to the playlist code to see if I can spot anything.
Comment 3 Jason Holtzapple 2005-10-26 08:27:51 UTC 
Here is some debugging output with command and source added:

I did try 'playlistcontrol cmd:load playlist_id:40' and that loaded the playlist
almost immediately. But if the playlist IDs change when playlists are added or
removed this isn't a great solution for me.

2005-10-26 08:03:26.8640 CLI: Accepted connection from 127.0.0.1:60916 (1 active
 connections)
2005-10-26 08:03:26.8667 CLI: Parsing command: Found client [00:04:20:05:60:8a]
2005-10-26 08:03:26.8673 CLI: Parsing command: Found command, value [mixer]
2005-10-26 08:03:26.8675 CLI: Parsing command: Found param [1], value [volume]
2005-10-26 08:03:26.8678 CLI: Parsing command: Found param [2], value [4]
2005-10-26 08:03:26.8680 CLI: Processing command [mixer]
2005-10-26 08:03:26.8683 CLI: Forwarding [mixer] to Command.pm
2005-10-26 08:03:26.8686  Executing command 00:04:20:05:60:8a: mixer (volume) (4
) () () () () ()
2005-10-26 08:03:26.8714  Returning array: mixer (volume) (4) () () () () ()
2005-10-26 08:03:26.8722 CLI: Response: 00%3A04%3A20%3A05%3A60%3A8a mixer volume
 4
2005-10-26 08:03:26.8737 CLI: Sending response...
2005-10-26 08:03:26.8742 CLI: No more messages to send to 127.0.0.1:60916
2005-10-26 08:03:26.8762 CLI: Parsing command: Found client [00:04:20:05:60:8a]
2005-10-26 08:03:26.8767 CLI: Parsing command: Found command, value [playlist]
2005-10-26 08:03:26.8771 CLI: Parsing command: Found param [1], value [shuffle]
2005-10-26 08:03:26.8773 CLI: Parsing command: Found param [2], value [1]
2005-10-26 08:03:26.8776 CLI: Processing command [playlist]
2005-10-26 08:03:26.8778 CLI: Forwarding [playlist] to Command.pm
2005-10-26 08:03:26.8782  Executing command 00:04:20:05:60:8a: playlist (shuffle
) (1) () () () () ()
2005-10-26 08:03:26.8832  Returning array: playlist (shuffle) (1) () () () () ()
2005-10-26 08:03:26.8841 CLI: Response: 00%3A04%3A20%3A05%3A60%3A8a playlist shu
ffle 1
2005-10-26 08:03:26.8871 CLI: Sending response...
2005-10-26 08:03:26.8877 CLI: No more messages to send to 127.0.0.1:60916
2005-10-26 08:03:26.8898 CLI: Parsing command: Found client [00:04:20:05:60:8a]
2005-10-26 08:03:26.8904 CLI: Parsing command: Found command, value [playlist]
2005-10-26 08:03:26.8906 CLI: Parsing command: Found param [1], value [play]
2005-10-26 08:03:26.8909 CLI: Parsing command: Found param [2], value [sleepytim
e]
2005-10-26 08:03:26.8912 CLI: Processing command [playlist]
2005-10-26 08:03:26.8914 CLI: Forwarding [playlist] to Command.pm
2005-10-26 08:03:26.8918  Executing command 00:04:20:05:60:8a: playlist (play) (
sleepytime) () () () () ()
2005-10-26 08:03:26.8932 Backtrace:

   frame 0: Slim::Player::Source::playmode (/home/slim/SlimServer_v6.2.0/Slim/Co
ntrol/Command.pm line 603)
   frame 1: Slim::Control::Command::execute (/home/slim/SlimServer_v6.2.0/Slim/C
ontrol/CLI.pm line 589)
   frame 2: Slim::Control::CLI::cli_command_command (/home/slim/SlimServer_v6.2.
0/Slim/Control/CLI.pm line 454)
   frame 3: Slim::Control::CLI::cli_process (/home/slim/SlimServer_v6.2.0/Slim/C
ontrol/CLI.pm line 291)
   frame 4: Slim::Control::CLI::client_socket_buf_parse (/home/slim/SlimServer_v
6.2.0/Slim/Control/CLI.pm line 252)
   frame 5: Slim::Control::CLI::client_socket_read (/home/slim/SlimServer_v6.2.0
/Slim/Networking/Select.pm line 111)
   frame 6: Slim::Networking::Select::select (/home/slim/slimserver/slimserver.p
l line 634)
   frame 7: main::idle (/home/slim/slimserver/slimserver.pl line 570)
   frame 8: main::main (/home/slim/slimserver/slimserver.pl line 1226)

2005-10-26 08:03:26.8937 00:04:20:05:60:8a: Switching to mode stop from pause
2005-10-26 08:03:26.8940 00:04:20:05:60:8a New play mode: stop
2005-10-26 08:03:26.8943 Stopping and clearing out old chunks for client 00:04:2
0:05:60:8a
2005-10-26 08:03:26.8965 Resetting song queue
2005-10-26 08:03:26.8970 Song queue is now 0
2005-10-26 08:03:26.8976 00:04:20:05:60:8a: Current playmode: stop
2005-10-26 08:03:26.9020 Adding song index 0 to song queue
2005-10-26 08:03:26.9024 Clearing out song queue first
2005-10-26 08:03:26.9027 Song queue is now 0
2005-10-26 08:03:57.0811 Backtrace:

   frame 0: Slim::Player::Source::playmode (/home/slim/SlimServer_v6.2.0/Slim/Pl
ayer/Source.pm line 765)
   frame 1: Slim::Player::Source::jumpto (/home/slim/SlimServer_v6.2.0/Slim/Cont
rol/Command.pm line 1430)
   frame 2: Slim::Control::Command::load_done (/home/slim/SlimServer_v6.2.0/Slim
/Utils/Scan.pm line 129)
   frame 3: Slim::Utils::Scan::addToList (/home/slim/SlimServer_v6.2.0/Slim/Cont
rol/Command.pm line 664)
   frame 4: Slim::Control::Command::execute (/home/slim/SlimServer_v6.2.0/Slim/C
ontrol/CLI.pm line 589)
   frame 5: Slim::Control::CLI::cli_command_command (/home/slim/SlimServer_v6.2.
0/Slim/Control/CLI.pm line 454)
   frame 6: Slim::Control::CLI::cli_process (/home/slim/SlimServer_v6.2.0/Slim/C
ontrol/CLI.pm line 291)
   frame 7: Slim::Control::CLI::client_socket_buf_parse (/home/slim/SlimServer_v
6.2.0/Slim/Control/CLI.pm line 252)
   frame 8: Slim::Control::CLI::client_socket_read (/home/slim/SlimServer_v6.2.0
/Slim/Networking/Select.pm line 111)
   frame 9: Slim::Networking::Select::select (/home/slim/slimserver/slimserver.p
l line 634)
   frame 10: main::idle (/home/slim/slimserver/slimserver.pl line 570)
   frame 11: main::main (/home/slim/slimserver/slimserver.pl line 1226)

2005-10-26 08:03:57.0819 00:04:20:05:60:8a: Switching to mode stop from stop
2005-10-26 08:03:57.0821  Already in playmode stop : ignoring mode change
2005-10-26 08:03:57.0824 jumping to 0
2005-10-26 08:03:57.0827 Adding song index 0 to song queue
2005-10-26 08:03:57.0829 Clearing out song queue first
2005-10-26 08:03:57.0832 Song queue is now 0
2005-10-26 08:03:57.0849 Backtrace:

   frame 0: Slim::Player::Source::playmode (/home/slim/SlimServer_v6.2.0/Slim/Pl
ayer/Source.pm line 796)
   frame 1: Slim::Player::Source::jumpto (/home/slim/SlimServer_v6.2.0/Slim/Cont
rol/Command.pm line 1430)
   frame 2: Slim::Control::Command::load_done (/home/slim/SlimServer_v6.2.0/Slim
/Utils/Scan.pm line 129)
   frame 3: Slim::Utils::Scan::addToList (/home/slim/SlimServer_v6.2.0/Slim/Cont
rol/Command.pm line 664)
   frame 4: Slim::Control::Command::execute (/home/slim/SlimServer_v6.2.0/Slim/C
ontrol/CLI.pm line 589)
   frame 5: Slim::Control::CLI::cli_command_command (/home/slim/SlimServer_v6.2.
0/Slim/Control/CLI.pm line 454)
   frame 6: Slim::Control::CLI::cli_process (/home/slim/SlimServer_v6.2.0/Slim/C
ontrol/CLI.pm line 291)
   frame 7: Slim::Control::CLI::client_socket_buf_parse (/home/slim/SlimServer_v
6.2.0/Slim/Control/CLI.pm line 252)
   frame 8: Slim::Control::CLI::client_socket_read (/home/slim/SlimServer_v6.2.0
/Slim/Networking/Select.pm line 111)
   frame 9: Slim::Networking::Select::select (/home/slim/slimserver/slimserver.p
l line 634)
   frame 10: main::idle (/home/slim/slimserver/slimserver.pl line 570)
   frame 11: main::main (/home/slim/slimserver/slimserver.pl line 1226)

2005-10-26 08:03:57.0857 00:04:20:05:60:8a: Switching to mode play from stop
2005-10-26 08:03:57.0985 openSong on: file:///export/music/various_artists/donni
e_darko/donnie_darko_-_17_gary_jules_-_mad_world.mp3
2005-10-26 08:03:57.1128 openSong: getting duration  185.991836734694, size 3890
200, endian  and offset 417 for file:///export/music/various_artists/donnie_dark
o/donnie_darko_-_17_gary_jules_-_mad_world.mp3
2005-10-26 08:03:57.1139 Setting maxBitRate for Master Bedroom to: 0
2005-10-26 08:03:57.1144 Setting maxBitRate for Master Bedroom to: 0
2005-10-26 08:03:57.1182 Setting maxBitRate for Master Bedroom to: 0
2005-10-26 08:03:57.1189 Setting maxBitRate for Master Bedroom to: 0
2005-10-26 08:03:57.1192 undermax = 1, type = mp3, squeezebox = 00:04:20:05:60:8
a, lame = 
2005-10-26 08:03:57.1196 checking formats for: mp3-aif-squeezebox-00:04:20:05:60
:8a
2005-10-26 08:03:57.1199 checking formats for: mp3-aif-*-00:04:20:05:60:8a
2005-10-26 08:03:57.1201 checking formats for: mp3-aif-squeezebox-*
2005-10-26 08:03:57.1203 checking formats for: mp3-aif-*-*
2005-10-26 08:03:57.1206 checking formats for: mp3-wav-squeezebox-00:04:20:05:60
:8a
2005-10-26 08:03:57.1208 checking formats for: mp3-wav-*-00:04:20:05:60:8a
2005-10-26 08:03:57.1210 checking formats for: mp3-wav-squeezebox-*
2005-10-26 08:03:57.1212 checking formats for: mp3-wav-*-*
2005-10-26 08:03:57.1215 checking formats for: mp3-mp3-squeezebox-00:04:20:05:60
:8a
2005-10-26 08:03:57.1217 checking formats for: mp3-mp3-*-00:04:20:05:60:8a
2005-10-26 08:03:57.1219 checking formats for: mp3-mp3-squeezebox-*
2005-10-26 08:03:57.1223 checking formats for: mp3-mp3-*-*
2005-10-26 08:03:57.1225 Checking to see if mp3-mp3-*-* is enabled
2005-10-26 08:03:57.1228 There are 8 disabled formats...
2005-10-26 08:03:57.1231 Testing wma-wav-*-* vs mp3-mp3-*-*
2005-10-26 08:03:57.1233 Testing wma-mp3-*-* vs mp3-mp3-*-*
2005-10-26 08:03:57.1235 Testing shn-wav-*-* vs mp3-mp3-*-*
2005-10-26 08:03:57.1237 Testing shn-mp3-*-* vs mp3-mp3-*-*
2005-10-26 08:03:57.1240 Testing mpc-wav-*-* vs mp3-mp3-*-*
2005-10-26 08:03:57.1242 Testing mpc-mp3-*-* vs mp3-mp3-*-*
2005-10-26 08:03:57.1244 Testing mpc-aif-*-* vs mp3-mp3-*-*
2005-10-26 08:03:57.1246 Testing mov-mp3-*-* vs mp3-mp3-*-*
2005-10-26 08:03:57.1248 Testing mov-aif-*-* vs mp3-mp3-*-*
2005-10-26 08:03:57.1251    enabled
2005-10-26 08:03:57.1253   Found command: -
2005-10-26 08:03:57.1260 Setting maxBitRate for Master Bedroom to: 0
2005-10-26 08:03:57.1266 Setting maxBitRate for Master Bedroom to: 0
2005-10-26 08:03:57.1269 Matched Format: mp3 Type: mp3 Command: - 
2005-10-26 08:03:57.1272 openSong: this is an mp3 file: file:///export/music/var
ious_artists/donnie_darko/donnie_darko_-_17_gary_jules_-_mad_world.mp3
2005-10-26 08:03:57.1275   file type: mp3 format: mp3 inrate: 167 maxRate: 0
2005-10-26 08:03:57.1277   command: -
2005-10-26 08:03:57.1281 openSong: opening file /export/music/various_artists/do
nnie_darko/donnie_darko_-_17_gary_jules_-_mad_world.mp3
2005-10-26 08:03:57.1286  seeking in 417 into /export/music/various_artists/donn
ie_darko/donnie_darko_-_17_gary_jules_-_mad_world.mp3
2005-10-26 08:03:57.1291 Streaming with format: mp3
2005-10-26 08:03:57.1511 00:04:20:05:60:8a New play mode: play
2005-10-26 08:03:57.1560 00:04:20:05:60:8a: Current playmode: play
2005-10-26 08:03:59.6133  Returning array: playlist (play) (/home/slim/playlists
/sleepytime.m3u) () () () () ()
2005-10-26 08:03:59.6145 CLI: Response: 00%3A04%3A20%3A05%3A60%3A8a playlist pla
y %2Fhome%2Fslim%2Fplaylists%2Fsleepytime.m3u
2005-10-26 08:03:59.6316 CLI: Sending response...
2005-10-26 08:03:59.6326 CLI: No more messages to send to 127.0.0.1:60916
2005-10-26 08:03:59.6397 CLI: Parsing command: Found command, value [exit]
2005-10-26 08:03:59.6403 CLI: Processing command [exit]
2005-10-26 08:03:59.6407 CLI: Response: exit
2005-10-26 08:03:59.6413 CLI: Sending response...
2005-10-26 08:03:59.6473 CLI: No more messages to send to 127.0.0.1:60916
2005-10-26 08:03:59.6489 CLI: Closed connection with 127.0.0.1:60916 (0 active c
onnections)
2005-10-26 08:04:17.0083  Executing command 00:04:20:02:03:f1: power (0) () () (
) () () ()
2005-10-26 08:04:17.0104  Returning array: power (0) () () () () () ()
Comment 4 KDF 2005-10-26 11:42:03 UTC 
I'm still not sure why play->playlist doens't work.  I had been using for the
alarms and it seemed ok.  I can't see anything that flags the cause from the
log, except that there is still a 30s gap of nothing. Is it possible to get the
id from a url using CLI?  you could use playtracks then. However, to allow the
freedom of playing an arbitrary url, having play work would be nice. what about
d_info, d_parse, d_scan? anything at all that fills in that gap might give a hint.

integrating play commands would be nice (skins currently are forced to use the
old play command for radio urls in playlists and BMF, but the new playtracks for
all other objects).  Probably need some warning on when that will hit just to
make sure everything else falls into line with the combined API.  That, or
branch it for a few days.  Trunk is unstable now so for a while there is room to
play.
Comment 5 Jason Holtzapple 2005-10-26 12:34:24 UTC 
I turned on those additional debug flags and it looks as though each file in the
playlist is getting rescanned for metadata. This explains why some of my shorter
playlists (15 items or less) are working in a similar setup and this longer one
is causing a big pause. Can the scan be smarter and only re-read the metadata if
the modification time of the file has changed? Here is a small portion of the
relevant part of the debug log:

2005-10-26 12:23:43.5419   entry from file:
/export/music/windy_and_carl/consciousness/windy_and_
carl_-_consciousness_-_05_consciousness.mp3
2005-10-26 12:23:43.5474
isFile(/export/music/windy_and_carl/consciousness/windy_and_carl_-_consc
iousness_-_05_consciousness.mp3) == 1
2005-10-26 12:23:43.5511     entry:
file:///export/music/windy_and_carl/consciousness/windy_and_c
arl_-_consciousness_-_05_consciousness.mp3
2005-10-26 12:23:43.5601 Merging entry for
file:///export/music/windy_and_carl/consciousness/wind
y_and_carl_-_consciousness_-_05_consciousness.mp3
2005-10-26 12:23:43.5637 reading tags for:
file:///export/music/windy_and_carl/consciousness/wind
y_and_carl_-_consciousness_-_05_consciousness.mp3
2005-10-26 12:23:43.5683 mp3 file type for
/export/music/windy_and_carl/consciousness/windy_and_c
arl_-_consciousness_-_05_consciousness.mp3
2005-10-26 12:23:43.6161 Updating
file:///export/music/windy_and_carl/consciousness/windy_and_car
l_-_consciousness_-_05_consciousness.mp3 : TAG to 1
2005-10-26 12:23:43.6193 Updating
file:///export/music/windy_and_carl/consciousness/windy_and_car
l_-_consciousness_-_05_consciousness.mp3 : BLOCKALIGN to 1
2005-10-26 12:23:43.6223 Updating
file:///export/music/windy_and_carl/consciousness/windy_and_car
l_-_consciousness_-_05_consciousness.mp3 : TITLESORT to CONSCIOUSNESS
2005-10-26 12:23:43.6259 Updating
file:///export/music/windy_and_carl/consciousness/windy_and_car
l_-_consciousness_-_05_consciousness.mp3 : TRACKNUM to 5
2005-10-26 12:23:43.6290 Updating
file:///export/music/windy_and_carl/consciousness/windy_and_car
l_-_consciousness_-_05_consciousness.mp3 : AUDIO to 1
2005-10-26 12:23:43.6319 Updating
file:///export/music/windy_and_carl/consciousness/windy_and_car
l_-_consciousness_-_05_consciousness.mp3 : REPLAY_GAIN to +0.210000
2005-10-26 12:23:43.6354 Updating
file:///export/music/windy_and_carl/consciousness/windy_and_car
l_-_consciousness_-_05_consciousness.mp3 : REMOTE to 0
2005-10-26 12:23:43.6384 Updating
file:///export/music/windy_and_carl/consciousness/windy_and_car
l_-_consciousness_-_05_consciousness.mp3 : TITLE to Consciousness
2005-10-26 12:23:43.6419 Updating
file:///export/music/windy_and_carl/consciousness/windy_and_car
l_-_consciousness_-_05_consciousness.mp3 : VBR_SCALE to 78
2005-10-26 12:23:43.6448 Updating
file:///export/music/windy_and_carl/consciousness/windy_and_car
l_-_consciousness_-_05_consciousness.mp3 : SIZE to 20580220
2005-10-26 12:23:43.6482 Updating
file:///export/music/windy_and_carl/consciousness/windy_and_car
l_-_consciousness_-_05_consciousness.mp3 : FS to 20581087
2005-10-26 12:23:43.6513 Updating
file:///export/music/windy_and_carl/consciousness/windy_and_car
l_-_consciousness_-_05_consciousness.mp3 : OFFSET to 417
2005-10-26 12:23:43.6544 Updating
file:///export/music/windy_and_carl/consciousness/windy_and_car
l_-_consciousness_-_05_consciousness.mp3 : YEAR to 2001
2005-10-26 12:23:43.6577 Updating
file:///export/music/windy_and_carl/consciousness/windy_and_car
l_-_consciousness_-_05_consciousness.mp3 : SECS to 762.775510204081
2005-10-26 12:23:43.6610 Updating
file:///export/music/windy_and_carl/consciousness/windy_and_car
l_-_consciousness_-_05_consciousness.mp3 : REPLAY_PEAK to 0.650359
2005-10-26 12:23:43.6644 Updating
file:///export/music/windy_and_carl/consciousness/windy_and_car
l_-_consciousness_-_05_consciousness.mp3 : CT to mp3
2005-10-26 12:23:43.6676 Updating
file:///export/music/windy_and_carl/consciousness/windy_and_car
l_-_consciousness_-_05_consciousness.mp3 : RATE to 44100
2005-10-26 12:23:43.6707 Updating
file:///export/music/windy_and_carl/consciousness/windy_and_car
l_-_consciousness_-_05_consciousness.mp3 : TAGVERSION to ID3v1.1
2005-10-26 12:23:43.6739 Updating
file:///export/music/windy_and_carl/consciousness/windy_and_car
l_-_consciousness_-_05_consciousness.mp3 : TITLESEARCH to CONSCIOUSNESS
2005-10-26 12:23:43.6775 Updating
file:///export/music/windy_and_carl/consciousness/windy_and_car
l_-_consciousness_-_05_consciousness.mp3 : AGE to 1079980820
2005-10-26 12:23:43.6809 Updating
file:///export/music/windy_and_carl/consciousness/windy_and_car
l_-_consciousness_-_05_consciousness.mp3 : BITRATE to 215000
Comment 6 Dan Sully 2005-11-02 16:36:16 UTC 
The scan is already that smart.. we check the time stamp.
Comment 7 Fred 2006-01-31 19:18:50 UTC 
Playlistcontrol and playlist XXalbum now go through playlist loadtracks listref once they have calculated the list of songs. This is an improvement, but changing playlist XXXitem (the one we're having a problem with here) is much harder. It uses the old "let's recurse the directories" async approach, adding to the playlist along the way.

Just to report on the progress of my intention to unify playlist management :-)
Comment 8 Dan Sully 2006-04-29 13:30:12 UTC 
Fred - what's the status of this?
Comment 9 Fred 2006-04-30 14:31:37 UTC 
Well, like I said I'd need to access the DB directly. To me this is not a bug but an enhancement request. The thing is if this could be much faster, some people would not bother interfacing the DB directly...
Comment 10 Dan Sully 2006-06-09 17:03:10 UTC 
Fred - will fixing this be easier with the new DB code in 6.5 ?

Thanks
Comment 11 Fred 2006-06-09 17:49:32 UTC 
Most likely. I am working now on fixing the CLI following the changes...
Comment 12 Jason Holtzapple 2006-06-09 23:42:51 UTC 
This issue seems to have gone away in the latest versions of 6.3. I see the target milestone is 6.5 so I'll leave the bug open just in case there is further optimization to be done in the 6.5 timeframe.
Comment 13 Dan Sully 2006-06-14 19:40:46 UTC 
Ok - I'm marking this as fixed then.

Fred's changes can either be done (I know they're in Fred's head) - or an enhancement request can be opened..
Comment 14 Jason Holtzapple 2006-09-16 08:25:34 UTC 
This issue seems to have come back. I tried

SlimServer Version: 6.5b3 - 9781 - Debian - EN - iso-8859-1
Perl Version: 5.8.8 i686-linux
MySQL Version: 4.1.11-Debian_4sarge7-log

And playlists played by name in the CLI load but don't start playing. Here's the log I got. The sequence of commands to the CLI is the same as the original bug except I am using 10 as the mixer volume.

2006-09-16 08:17:31.4049 CLI: Accepted connection from 127.0.0.1:58547 (1 active connections)
2006-09-16 08:17:31.4103 CLI: 127.0.0.1:58547 - Buffered [00:04:20:05:60:8a mixer volume 10
]
2006-09-16 08:17:31.4139 CLI: Parsing command: Found client [00:04:20:05:60:8a]
2006-09-16 08:17:31.4179 CLI: Processing request [mixer]
2006-09-16 08:17:31.4211 CLI: Dispatching [mixer]
2006-09-16 08:17:31.4241 
2006-09-16 08:17:31.4299 Request: Command [00:04:20:05:60:8a->mixer volume] from CLI  (Done)
2006-09-16 08:17:31.4334    Param: [_newvalue] = [10]
2006-09-16 08:17:31.4413 CLI: 127.0.0.1:58547 - Sending response [00%3A04%3A20%3A05%3A60%3A8a mixer volume 1...]
2006-09-16 08:17:31.4444 CLI: Sent response to 127.0.0.1:58547
2006-09-16 08:17:31.4498 CLI: 127.0.0.1:58547 - Buffered [00:04:20:05:60:8a playlist shuffle 1
]
2006-09-16 08:17:31.4536 CLI: Parsing command: Found client [00:04:20:05:60:8a]
2006-09-16 08:17:31.4574 CLI: Processing request [playlist]
2006-09-16 08:17:31.4605 CLI: Dispatching [playlist]
2006-09-16 08:17:31.4635 
2006-09-16 08:17:31.4678 Reshuffling, current song index: 140, preserve song? yes
2006-09-16 08:17:31.4764 Playlist: Jumping to song index: 0
2006-09-16 08:17:31.4793 new playlistindex: 0
2006-09-16 08:17:31.4833 Request: Command [00:04:20:05:60:8a->playlist shuffle] from CLI  (Done)
2006-09-16 08:17:31.4867    Param: [_newvalue] = [1]
2006-09-16 08:17:31.4934 modifyPlaylistCallback: savecurrsong is 1
2006-09-16 08:17:31.5021 CLI: 127.0.0.1:58547 - Sending response [00%3A04%3A20%3A05%3A60%3A8a playlist shuffle ...]
2006-09-16 08:17:31.5053 CLI: Sent response to 127.0.0.1:58547
2006-09-16 08:17:31.5103 CLI: 127.0.0.1:58547 - Buffered [00:04:20:05:60:8a playlist play /export/home/slim/playlists/sleepytime.m3u
]
2006-09-16 08:17:31.5139 CLI: Parsing command: Found client [00:04:20:05:60:8a]
2006-09-16 08:17:31.5179 CLI: Processing request [playlist]
2006-09-16 08:17:31.5210 CLI: Dispatching [playlist]
2006-09-16 08:17:31.5240 
2006-09-16 08:17:31.5279 00:04:20:05:60:8a: Switching to mode stop from play
2006-09-16 08:17:31.5319 00:04:20:05:60:8a New play mode: stop
2006-09-16 08:17:31.5355 Stopping and clearing out old chunks for client 00:04:20:05:60:8a
2006-09-16 08:17:31.5412 Resetting song queue
2006-09-16 08:17:31.5441 Song queue is now 0
2006-09-16 08:17:31.5490 Playlist: Jumping to song index: 0
2006-09-16 08:17:31.5521 new playlistindex: 0
2006-09-16 08:17:31.5554 00:04:20:05:60:8a: Current playmode: stop
2006-09-16 08:17:31.5827 Adding song index 0 to song queue
2006-09-16 08:17:31.5857 Clearing out song queue first
2006-09-16 08:17:31.5888 Song queue is now 0
2006-09-16 08:17:31.5927 Playlist: Jumping to song index: 0
2006-09-16 08:17:31.5957 new playlistindex: 0
2006-09-16 08:17:31.6013 scanPathOrURL: Finding valid files in: /export/home/slim/playlists/sleepytime.m3u
2006-09-16 08:17:31.6060 About to look for files in /export/home/slim/playlists/sleepytime.m3u
2006-09-16 08:17:31.6184 For files with extensions in: [(?i-xsm:\.(?:ape|wma|asf|wax|asx|lnk|wpl|shn|wav|wave|mp3|mp2|m3u|pls|xspf|flc|flac|m4a|mov|m4b|mp4|mp+|mpc|ogg|aif|aiff)$)]
2006-09-16 08:17:31.6390 Found 1 files in /export/home/slim/playlists/sleepytime.m3u
2006-09-16 08:17:31.6907 findFrameBoundaries: start: [2403] end: [0]
2006-09-16 08:17:31.8301 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:31.9437 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:32.0553 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:32.1662 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:32.2819 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:32.3942 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:32.5077 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:32.6190 findFrameBoundaries: start: [866] end: [0]
2006-09-16 08:17:32.7427 findFrameBoundaries: start: [1872] end: [0]
2006-09-16 08:17:32.8642 findFrameBoundaries: start: [2347] end: [0]
2006-09-16 08:17:32.9910 findFrameBoundaries: start: [2083] end: [0]
2006-09-16 08:17:33.1157 findFrameBoundaries: start: [1427] end: [0]
2006-09-16 08:17:33.2280 findFrameBoundaries: start: [1836] end: [0]
2006-09-16 08:17:33.3412 findFrameBoundaries: start: [2020] end: [0]
2006-09-16 08:17:33.4543 findFrameBoundaries: start: [1721] end: [0]
2006-09-16 08:17:33.5766 findFrameBoundaries: start: [2141] end: [0]
2006-09-16 08:17:33.6898 findFrameBoundaries: start: [2039] end: [0]
2006-09-16 08:17:33.8019 findFrameBoundaries: start: [823] end: [0]
2006-09-16 08:17:33.9123 findFrameBoundaries: start: [1737] end: [0]
2006-09-16 08:17:34.0325 findFrameBoundaries: start: [1643] end: [0]
2006-09-16 08:17:34.1488 findFrameBoundaries: start: [1725] end: [0]
2006-09-16 08:17:34.2667 findFrameBoundaries: start: [1695] end: [0]
2006-09-16 08:17:34.3891 findFrameBoundaries: start: [2522] end: [0]
2006-09-16 08:17:34.5039 findFrameBoundaries: start: [805] end: [0]
2006-09-16 08:17:34.6177 findFrameBoundaries: start: [1963] end: [0]
2006-09-16 08:17:34.7300 findFrameBoundaries: start: [758] end: [0]
2006-09-16 08:17:34.8427 findFrameBoundaries: start: [2541] end: [0]
2006-09-16 08:17:34.9551 findFrameBoundaries: start: [667] end: [0]
2006-09-16 08:17:35.0689 findFrameBoundaries: start: [2648] end: [0]
2006-09-16 08:17:35.1848 findFrameBoundaries: start: [1474] end: [0]
2006-09-16 08:17:35.2969 findFrameBoundaries: start: [1424] end: [0]
2006-09-16 08:17:35.4254 findFrameBoundaries: start: [2068] end: [0]
2006-09-16 08:17:35.5476 findFrameBoundaries: start: [2412] end: [0]
2006-09-16 08:17:35.6824 findFrameBoundaries: start: [1696] end: [0]
2006-09-16 08:17:35.8014 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:35.9135 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:36.0276 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:36.1597 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:36.2715 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:36.3825 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:36.4960 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:36.6328 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:36.7463 findFrameBoundaries: start: [2469] end: [0]
2006-09-16 08:17:36.8686 findFrameBoundaries: start: [1592] end: [0]
2006-09-16 08:17:36.9883 findFrameBoundaries: start: [944] end: [0]
2006-09-16 08:17:37.1122 findFrameBoundaries: start: [1526] end: [0]
2006-09-16 08:17:37.2362 findFrameBoundaries: start: [2265] end: [0]
2006-09-16 08:17:37.3551 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:37.4774 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:37.5932 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:37.7035 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:37.8150 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:37.9264 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:38.0383 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:38.1498 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:38.2605 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:38.3734 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:38.4842 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:38.5977 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:38.7110 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:38.8215 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:38.9319 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:39.0443 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:39.1581 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:39.2699 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:39.3825 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:39.4934 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:39.6056 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:39.7172 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:39.8287 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:39.9399 findFrameBoundaries: start: [417] end: [3829553]
2006-09-16 08:17:40.0607 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:40.1710 findFrameBoundaries: start: [417] end: [4675663]
2006-09-16 08:17:40.2840 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:40.3960 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:40.5104 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:40.6238 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:40.7370 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:40.8498 findFrameBoundaries: start: [614] end: [0]
2006-09-16 08:17:40.9634 findFrameBoundaries: start: [2333] end: [0]
2006-09-16 08:17:41.0759 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:41.2019 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:41.3137 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:41.4269 findFrameBoundaries: start: [2404] end: [0]
2006-09-16 08:17:41.6205 findFrameBoundaries: start: [796] end: [0]
2006-09-16 08:17:41.9212 findFrameBoundaries: start: [816] end: [0]
2006-09-16 08:17:42.1097 findFrameBoundaries: start: [1545] end: [0]
2006-09-16 08:17:42.2967 findFrameBoundaries: start: [1543] end: [0]
2006-09-16 08:17:42.4851 findFrameBoundaries: start: [2306] end: [4477146]
2006-09-16 08:17:42.6770 findFrameBoundaries: start: [887] end: [0]
2006-09-16 08:17:42.8637 findFrameBoundaries: start: [1523] end: [0]
2006-09-16 08:17:43.0476 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:43.1643 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:43.2758 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:43.3866 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:43.4966 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:43.6102 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:43.7226 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:43.8340 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:43.9449 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:44.0560 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:44.1704 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:44.2835 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:44.3942 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:44.5063 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:44.6229 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:44.7368 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:44.8487 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:44.9598 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:45.0721 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:45.1879 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:45.3086 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:45.4220 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:45.5346 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:45.6448 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:45.7572 findFrameBoundaries: start: [2510] end: [0]
2006-09-16 08:17:45.8694 findFrameBoundaries: start: [2432] end: [0]
2006-09-16 08:17:45.9879 findFrameBoundaries: start: [834] end: [0]
2006-09-16 08:17:46.1184 findFrameBoundaries: start: [1667] end: [0]
2006-09-16 08:17:46.2447 findFrameBoundaries: start: [710] end: [0]
2006-09-16 08:17:46.3623 findFrameBoundaries: start: [1414] end: [0]
2006-09-16 08:17:46.4803 findFrameBoundaries: start: [1705] end: [0]
2006-09-16 08:17:46.6045 findFrameBoundaries: start: [956] end: [0]
2006-09-16 08:17:46.7496 findFrameBoundaries: start: [2457] end: [0]
2006-09-16 08:17:46.8693 findFrameBoundaries: start: [1870] end: [0]
2006-09-16 08:17:46.9910 findFrameBoundaries: start: [1231] end: [0]
2006-09-16 08:17:47.1149 findFrameBoundaries: start: [889] end: [0]
2006-09-16 08:17:47.2345 findFrameBoundaries: start: [1084] end: [0]
2006-09-16 08:17:47.3526 findFrameBoundaries: start: [2580] end: [0]
2006-09-16 08:17:47.4693 findFrameBoundaries: start: [971] end: [0]
2006-09-16 08:17:47.5835 findFrameBoundaries: start: [1696] end: [0]
2006-09-16 08:17:47.6959 findFrameBoundaries: start: [1489] end: [0]
2006-09-16 08:17:47.8094 findFrameBoundaries: start: [1495] end: [0]
2006-09-16 08:17:47.9217 findFrameBoundaries: start: [1466] end: [0]
2006-09-16 08:17:48.0343 findFrameBoundaries: start: [2549] end: [0]
2006-09-16 08:17:48.1932 findFrameBoundaries: start: [2315] end: [0]
2006-09-16 08:17:48.3653 findFrameBoundaries: start: [2349] end: [0]
2006-09-16 08:17:48.5250 findFrameBoundaries: start: [1631] end: [0]
2006-09-16 08:17:48.6377 findFrameBoundaries: start: [2130] end: [0]
2006-09-16 08:17:48.7484 findFrameBoundaries: start: [1508] end: [0]
2006-09-16 08:17:48.8615 findFrameBoundaries: start: [2095] end: [0]
2006-09-16 08:17:48.9735 findFrameBoundaries: start: [2115] end: [0]
2006-09-16 08:17:49.0854 findFrameBoundaries: start: [1160] end: [0]
2006-09-16 08:17:49.2017 findFrameBoundaries: start: [2159] end: [0]
2006-09-16 08:17:49.3167 findFrameBoundaries: start: [2187] end: [0]
2006-09-16 08:17:49.4311 findFrameBoundaries: start: [2055] end: [0]
2006-09-16 08:17:49.5450 findFrameBoundaries: start: [1273] end: [0]
2006-09-16 08:17:49.6572 findFrameBoundaries: start: [1875] end: [0]
2006-09-16 08:17:49.7726 findFrameBoundaries: start: [1390] end: [0]
2006-09-16 08:17:49.8855 findFrameBoundaries: start: [2509] end: [0]
2006-09-16 08:17:50.0010 findFrameBoundaries: start: [2638] end: [0]
2006-09-16 08:17:50.1147 findFrameBoundaries: start: [1514] end: [0]
2006-09-16 08:17:50.2308 findFrameBoundaries: start: [1049] end: [0]
2006-09-16 08:17:50.3449 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:50.4574 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:50.5712 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:50.6843 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:50.7946 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:50.9059 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:51.0180 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:51.1323 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:51.2543 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:51.3665 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:51.4801 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:51.5933 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:51.7060 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:51.8173 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:52.0574 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:52.1717 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:52.2826 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:52.3961 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:52.5088 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:52.6248 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:52.7371 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:52.8492 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:52.9609 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:53.0736 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:53.1908 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:53.3037 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:53.4160 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:53.5319 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:53.6441 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:53.7563 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:53.8684 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:53.9800 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:54.0934 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:54.2083 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:54.3205 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:54.4328 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:54.5482 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:54.6605 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:54.7724 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:54.8841 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:54.9954 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:55.1083 findFrameBoundaries: start: [1738] end: [0]
2006-09-16 08:17:55.2266 findFrameBoundaries: start: [2360] end: [0]
2006-09-16 08:17:55.3417 findFrameBoundaries: start: [1418] end: [0]
2006-09-16 08:17:55.4562 findFrameBoundaries: start: [1414] end: [0]
2006-09-16 08:17:55.5709 findFrameBoundaries: start: [1250] end: [0]
2006-09-16 08:17:55.6836 findFrameBoundaries: start: [1050] end: [0]
2006-09-16 08:17:55.7958 findFrameBoundaries: start: [2682] end: [0]
2006-09-16 08:17:55.9066 findFrameBoundaries: start: [2389] end: [0]
2006-09-16 08:17:56.0149 findFrameBoundaries: start: [866] end: [0]
2006-09-16 08:17:56.1375 findFrameBoundaries: start: [2439] end: [0]
2006-09-16 08:17:56.2625 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:56.3750 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:56.4901 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:56.6033 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:56.7160 findFrameBoundaries: start: [1742] end: [0]
2006-09-16 08:17:56.8308 findFrameBoundaries: start: [663] end: [0]
2006-09-16 08:17:56.9459 findFrameBoundaries: start: [2526] end: [0]
2006-09-16 08:17:57.0605 findFrameBoundaries: start: [1509] end: [0]
2006-09-16 08:17:57.1758 findFrameBoundaries: start: [772] end: [0]
2006-09-16 08:17:57.2895 findFrameBoundaries: start: [417] end: [0]
2006-09-16 08:17:57.4013 findFrameBoundaries: start: [2376] end: [0]
2006-09-16 08:17:59.0313 Reshuffling, current song index: -1, preserve song? no
2006-09-16 08:17:59.0392 Playlist: Jumping to song index: 0
2006-09-16 08:17:59.0422 new playlistindex: 0
2006-09-16 08:17:59.0455 00:04:20:05:60:8a: Switching to mode stop from stop
2006-09-16 08:17:59.0485  Already in playmode stop : ignoring mode change
2006-09-16 08:17:59.0520 jumping to 0
2006-09-16 08:17:59.0554 Adding song index 0 to song queue
2006-09-16 08:17:59.0586 Clearing out song queue first
2006-09-16 08:17:59.0615 Song queue is now 0
2006-09-16 08:17:59.0659 00:04:20:05:60:8a: Switching to mode play from stop
2006-09-16 08:17:59.0813 openSong on: file:///export/music/brian_eno/shutov_assembly/brian_eno_-_the_shutov_assembly_-_01_triennale.mp3
2006-09-16 08:17:59.0868 openSong: duration: [246.126] size: [5685975] endian [] offset: [1738] for file:///export/music/brian_eno/shutov_assembly/brian_eno_-_the_shutov_assembly_-_01_triennale.mp3
2006-09-16 08:17:59.0909 Setting maxBitRate for Master Bedroom to: 320
2006-09-16 08:17:59.0946 Setting maxBitRate for Master Bedroom to: 320
2006-09-16 08:17:59.0995 Setting maxBitRate for Master Bedroom to: 320
2006-09-16 08:17:59.1031 Setting maxBitRate for Master Bedroom to: 320
2006-09-16 08:17:59.1099 undermax = 1, type = mp3, squeezebox = 00:04:20:05:60:8a
2006-09-16 08:17:59.1132 checking formats for: mp3-aif-squeezebox-00:04:20:05:60:8a
2006-09-16 08:17:59.1161 checking formats for: mp3-aif-*-00:04:20:05:60:8a
2006-09-16 08:17:59.1194 checking formats for: mp3-aif-squeezebox-*
2006-09-16 08:17:59.1228 checking formats for: mp3-aif-*-*
2006-09-16 08:17:59.1260 checking formats for: mp3-wav-squeezebox-00:04:20:05:60:8a
2006-09-16 08:17:59.1317 checking formats for: mp3-wav-*-00:04:20:05:60:8a
2006-09-16 08:17:59.1352 checking formats for: mp3-wav-squeezebox-*
2006-09-16 08:17:59.1387 checking formats for: mp3-wav-*-*
2006-09-16 08:17:59.1418 checking formats for: mp3-mp3-squeezebox-00:04:20:05:60:8a
2006-09-16 08:17:59.1447 checking formats for: mp3-mp3-*-00:04:20:05:60:8a
2006-09-16 08:17:59.1483 checking formats for: mp3-mp3-squeezebox-*
2006-09-16 08:17:59.1516 checking formats for: mp3-mp3-*-*
2006-09-16 08:17:59.1547 Checking to see if mp3-mp3-*-* is enabled
2006-09-16 08:17:59.1581    enabled
2006-09-16 08:17:59.1613   Found command: -
2006-09-16 08:17:59.1651 Setting maxBitRate for Master Bedroom to: 320
2006-09-16 08:17:59.1690 Setting maxBitRate for Master Bedroom to: 320
2006-09-16 08:17:59.1753 Matched Format: mp3 Type: mp3 Command: - 
2006-09-16 08:17:59.1792 openSong: this is an mp3 file: file:///export/music/brian_eno/shutov_assembly/brian_eno_-_the_shutov_assembly_-_01_triennale.mp3
2006-09-16 08:17:59.1823   file type: mp3 format: mp3 inrate: 184 maxRate: 320
2006-09-16 08:17:59.1852   command: -
2006-09-16 08:17:59.1888 openSong: opening file /export/music/brian_eno/shutov_assembly/brian_eno_-_the_shutov_assembly_-_01_triennale.mp3
2006-09-16 08:17:59.1925 openSong: seeking in 1738 into /export/music/brian_eno/shutov_assembly/brian_eno_-_the_shutov_assembly_-_01_triennale.mp3
2006-09-16 08:17:59.1958 openSong: Streaming with format: mp3
2006-09-16 08:17:59.2237 Playlist: Jumping to song index: 0
2006-09-16 08:17:59.2267 new playlistindex: 0
2006-09-16 08:17:59.2330 00:04:20:05:60:8a New play mode: play
2006-09-16 08:17:59.2411 Playlist: Jumping to song index: 0
2006-09-16 08:17:59.2440 new playlistindex: 0
2006-09-16 08:17:59.2472 00:04:20:05:60:8a: Current playmode: play
2006-09-16 08:17:59.2519 Request: Callback disabled
2006-09-16 08:17:59.2552 Request: Command [00:04:20:05:60:8a->playlist play] from CLI  (Done)
2006-09-16 08:17:59.2592    Param: [_item] = [/export/home/slim/playlists/sleepytime.m3u]
2006-09-16 08:17:59.2668 modifyPlaylistCallback: savecurrsong is 1
2006-09-16 08:17:59.2709 modifyPlaylistCallback: finding client playlist for: [00:04:20:05:60:8a]
2006-09-16 08:17:59.2909 modifyPlaylistCallback: calling setTracks()
2006-09-16 08:18:00.9197 CLI: 127.0.0.1:58547 - Sending response [00%3A04%3A20%3A05%3A60%3A8a playlist play %2Fexport%2Fhome%2Fslim%2Fplaylists%2Fsleepytime.m3...]
2006-09-16 08:18:00.9235 CLI: Sent response to 127.0.0.1:58547
2006-09-16 08:18:00.9294 CLI: 127.0.0.1:58547 - Buffered [exit
]
2006-09-16 08:18:00.9348 Request [exit]: no match in dispatchDB!
2006-09-16 08:18:00.9392 CLI: Processing request [exit]
2006-09-16 08:18:00.9432 CLI: 127.0.0.1:58547 - Sending response [exi...]
2006-09-16 08:18:00.9468 CLI: Sent response to 127.0.0.1:58547
2006-09-16 08:18:00.9511 CLI: Closed connection with 127.0.0.1:58547 (0 active connections)
2006-09-16 08:18:01.0362 modifyPlaylistCallback: savecurrsong is 1
2006-09-16 08:18:01.0648 modifyPlaylistCallback: savecurrsong is 0
2006-09-16 08:18:01.1106 modifyPlaylistCallback: savecurrsong is 1
2006-09-16 08:18:01.1143 modifyPlaylistCallback: finding client playlist for: [00:04:20:05:60:8a]
2006-09-16 08:18:01.1384 modifyPlaylistCallback: calling setTracks()
Comment 15 Fred 2006-09-16 08:45:36 UTC 
does it fails to play or is it just long? From the log, it is opening all the files...
Comment 16 Jason Holtzapple 2006-09-16 14:03:27 UTC 
It doesn't play at all. The symptoms are the same as before, where the playlist eventually loads, the first song starts scrolling, the player is on mode 'play' but the first track doesn't play.
Comment 17 Fred 2006-09-17 06:13:12 UTC 
I guess it does play if you use playlistcontrol with the playlist_id, right?
Comment 18 Jason Holtzapple 2006-09-17 09:29:09 UTC 
Do you recommend that I should take another strategy toward playing playlists with the CLI? Should I do a playlist query by search string and just use the resulting playlist_id in another command?
Comment 19 Fred 2006-09-17 09:46:26 UTC 
No. Well, that would fix your issue, but maybe not the bug.

I am just checking the issue is SlimServer treats the playlist as new content, when it should not. If you have no trouble with the ID, it gives us a hint of where the problem lies.

You also report it does not work by simply using the playlist name, when it did. Correct?
Comment 20 Dan Sully 2006-09-17 14:37:09 UTC 
Moving this ahead, as it's not going to be fixed for 6.5
Comment 21 Jason Holtzapple 2006-09-17 20:26:57 UTC 
Using playlist control with the playlist_id loads and plays the playlist almost immediately.
Comment 22 Fred 2006-09-18 03:59:03 UTC 
Could you try redoing your command enabling d_command in addition to the other debug flags you had on?

The bug here is that is does not play. It takes time because SlimServer reloads all tracks from the playlist, which may be considered "normal" behavior given you are not targetting the database (Dan to decide on this point). If you hit the DB, all goes well.

Now your issue is you cannot use the DB id because it can change following rescans. It seems "playlist play sleepytime.m3u" used to work (this is the command in the first log) but you now use the full path (playlist play /export/home/slim/playlists/sleepytime.m3u). Did you change because the old way no longer works? There is a number of stunts performed by "playlist play" to figure out what its parameter is and I think removing one possibility (a barenaked playlist file name) cannot hurt. Would a "playlistcontrol cmd:play playlist_name:sleepytime" work for you? This would search for sleepytime as a DB playlist and play it by id.
Comment 23 Jason Holtzapple 2006-09-18 21:34:32 UTC 
I tried changing to the full path of the playlist from just 'sleepytime' to see if would be any faster, but it was not.

playlistcontrol cmd:play playlist_name:sleepytime doesn't seem to do anything.
playlistcontrol cmd:load playlist_name:sleepytime takes even longer than playlist play and doesn't play anything. The end result is the same as playlist play though.

I think I already had d_command enabled before. Here is a log with d_cli, d_command and d_source

2006-09-18 21:20:20.0079 
2006-09-18 21:20:20.0715 Request: Command [00:04:20:04:14:90->power] (Done)
2006-09-18 21:20:20.0720    Param: [_newvalue] = [0]
2006-09-18 21:20:28.4996 CLI: Accepted connection from 127.0.0.1:38706 (1 active connections)
2006-09-18 21:20:28.5017 CLI: 127.0.0.1:38706 - Buffered [00:04:20:05:60:8a mixer volume 20
]
2006-09-18 21:20:28.5024 CLI: Parsing command: Found client [00:04:20:05:60:8a]
2006-09-18 21:20:28.5035 CLI: Processing request [mixer]
2006-09-18 21:20:28.5038 CLI: Dispatching [mixer]
2006-09-18 21:20:28.5040 
2006-09-18 21:20:28.5068 Request: Command [00:04:20:05:60:8a->mixer volume] from CLI  (Done)
2006-09-18 21:20:28.5073    Param: [_newvalue] = [20]
2006-09-18 21:20:28.5108 CLI: 127.0.0.1:38706 - Sending response [00%3A04%3A20%3A05%3A60%3A8a mixer volume 2...]
2006-09-18 21:20:28.5113 CLI: Sent response to 127.0.0.1:38706
2006-09-18 21:20:28.5146 CLI: 127.0.0.1:38706 - Buffered [00:04:20:05:60:8a playlist shuffle 1
]
2006-09-18 21:20:28.5154 CLI: Parsing command: Found client [00:04:20:05:60:8a]
2006-09-18 21:20:28.5165 CLI: Processing request [playlist]
2006-09-18 21:20:28.5169 CLI: Dispatching [playlist]
2006-09-18 21:20:28.5170 
2006-09-18 21:20:28.5242 Request: Command [00:04:20:05:60:8a->playlist shuffle] from CLI  (Done)
2006-09-18 21:20:28.5247    Param: [_newvalue] = [1]
2006-09-18 21:20:28.5321 CLI: 127.0.0.1:38706 - Sending response [00%3A04%3A20%3A05%3A60%3A8a playlist shuffle ...]
2006-09-18 21:20:28.5325 CLI: Sent response to 127.0.0.1:38706
2006-09-18 21:20:28.5371 CLI: 127.0.0.1:38706 - Buffered [00:04:20:05:60:8a playlist play /export/home/slim/playlists/sleepytime.m3u
]
2006-09-18 21:20:28.5379 CLI: Parsing command: Found client [00:04:20:05:60:8a]
2006-09-18 21:20:28.5392 CLI: Processing request [playlist]
2006-09-18 21:20:28.5396 CLI: Dispatching [playlist]
2006-09-18 21:20:28.5398 
2006-09-18 21:20:28.5503 00:04:20:05:60:8a: Switching to mode stop from play
2006-09-18 21:20:28.5516 00:04:20:05:60:8a New play mode: stop
2006-09-18 21:20:28.5521 Stopping and clearing out old chunks for client 00:04:20:05:60:8a
2006-09-18 21:20:28.5721 Resetting song queue
2006-09-18 21:20:28.5725 Song queue is now 0
2006-09-18 21:20:28.5749 00:04:20:05:60:8a: Current playmode: stop
2006-09-18 21:20:28.5894 Adding song index 0 to song queue
2006-09-18 21:20:28.5898 Clearing out song queue first
2006-09-18 21:20:28.5900 Song queue is now 0
2006-09-18 21:20:28.5933 scanPathOrURL: Finding valid files in: /export/home/slim/playlists/sleepytime.m3u
2006-09-18 21:20:28.5948 About to look for files in /export/home/slim/playlists/sleepytime.m3u
2006-09-18 21:20:28.6037 For files with extensions in: [(?i-xsm:\.(?:ape|wma|asf|wax|asx|lnk|wpl|shn|wav|wave|mp3|mp2|m3u|pls|xspf|flc|flac|m4a|mov|m4b|mp4|mp+|mpc|ogg|aif|aiff)$)]
2006-09-18 21:20:28.6188 Found 1 files in /export/home/slim/playlists/sleepytime.m3u
2006-09-18 21:20:28.8568 findFrameBoundaries: start: [2403] end: [0]
2006-09-18 21:20:29.8311 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:30.3535 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:30.5756 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:30.8191 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:30.9898 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:31.2134 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:31.4823 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:31.6947 findFrameBoundaries: start: [866] end: [0]
2006-09-18 21:20:31.9399 findFrameBoundaries: start: [1872] end: [0]
2006-09-18 21:20:32.2435 findFrameBoundaries: start: [2347] end: [0]
2006-09-18 21:20:32.5008 findFrameBoundaries: start: [2083] end: [0]
2006-09-18 21:20:32.7874 findFrameBoundaries: start: [1427] end: [0]
2006-09-18 21:20:33.1037 findFrameBoundaries: start: [1836] end: [0]
2006-09-18 21:20:33.4503 findFrameBoundaries: start: [2020] end: [0]
2006-09-18 21:20:33.6700 findFrameBoundaries: start: [1721] end: [0]
2006-09-18 21:20:33.9498 findFrameBoundaries: start: [2141] end: [0]
2006-09-18 21:20:34.2922 findFrameBoundaries: start: [2039] end: [0]
2006-09-18 21:20:34.5753 findFrameBoundaries: start: [823] end: [0]
2006-09-18 21:20:34.7640 findFrameBoundaries: start: [1737] end: [0]
2006-09-18 21:20:35.1305 findFrameBoundaries: start: [1643] end: [0]
2006-09-18 21:20:35.3722 findFrameBoundaries: start: [1725] end: [0]
2006-09-18 21:20:35.6227 findFrameBoundaries: start: [1695] end: [0]
2006-09-18 21:20:35.8797 findFrameBoundaries: start: [2522] end: [0]
2006-09-18 21:20:36.1491 findFrameBoundaries: start: [805] end: [0]
2006-09-18 21:20:36.3602 findFrameBoundaries: start: [1963] end: [0]
2006-09-18 21:20:36.5413 findFrameBoundaries: start: [758] end: [0]
2006-09-18 21:20:36.7838 findFrameBoundaries: start: [2541] end: [0]
2006-09-18 21:20:37.0495 findFrameBoundaries: start: [667] end: [0]
2006-09-18 21:20:37.2625 findFrameBoundaries: start: [2648] end: [0]
2006-09-18 21:20:37.5579 findFrameBoundaries: start: [1474] end: [0]
2006-09-18 21:20:37.8074 findFrameBoundaries: start: [1424] end: [0]
2006-09-18 21:20:38.1324 findFrameBoundaries: start: [2068] end: [0]
2006-09-18 21:20:38.4017 findFrameBoundaries: start: [2412] end: [0]
2006-09-18 21:20:38.6239 findFrameBoundaries: start: [1696] end: [0]
2006-09-18 21:20:39.0055 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:39.5338 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:39.7563 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:39.9562 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:40.1338 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:40.3258 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:40.5875 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:40.8187 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:41.0287 findFrameBoundaries: start: [2469] end: [0]
2006-09-18 21:20:41.2343 findFrameBoundaries: start: [1592] end: [0]
2006-09-18 21:20:41.4291 findFrameBoundaries: start: [944] end: [0]
2006-09-18 21:20:41.6539 findFrameBoundaries: start: [1526] end: [0]
2006-09-18 21:20:41.8655 findFrameBoundaries: start: [2265] end: [0]
2006-09-18 21:20:42.0520 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:42.2711 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:42.4412 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:42.6602 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:42.8797 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:43.0885 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:43.3049 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:43.5014 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:43.6759 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:43.8705 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:44.0720 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:44.3475 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:44.6290 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:44.9080 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:45.1141 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:45.3368 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:45.5586 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:45.7366 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:45.9198 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:46.1538 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:46.3820 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:46.6011 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:46.7982 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:46.9637 findFrameBoundaries: start: [417] end: [3829553]
2006-09-18 21:20:47.2008 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:47.3793 findFrameBoundaries: start: [417] end: [4675663]
2006-09-18 21:20:47.6020 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:47.7746 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:48.1526 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:48.3909 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:48.5809 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:48.8264 findFrameBoundaries: start: [614] end: [0]
2006-09-18 21:20:49.0223 findFrameBoundaries: start: [2333] end: [0]
2006-09-18 21:20:49.4210 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:49.6136 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:49.8616 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:50.1283 findFrameBoundaries: start: [2404] end: [0]
2006-09-18 21:20:50.4635 findFrameBoundaries: start: [796] end: [0]
2006-09-18 21:20:50.7349 findFrameBoundaries: start: [816] end: [0]
2006-09-18 21:20:51.0132 findFrameBoundaries: start: [1545] end: [0]
2006-09-18 21:20:51.3812 findFrameBoundaries: start: [1543] end: [0]
2006-09-18 21:20:51.6818 findFrameBoundaries: start: [2306] end: [4477146]
2006-09-18 21:20:51.9800 findFrameBoundaries: start: [887] end: [0]
2006-09-18 21:20:52.2625 findFrameBoundaries: start: [1523] end: [0]
2006-09-18 21:20:52.5545 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:52.8312 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:53.0665 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:53.3197 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:53.5251 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:53.7156 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:53.9195 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:54.1153 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:54.3922 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:54.5866 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:54.7905 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:54.9916 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:55.1798 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:55.3849 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:55.5765 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:55.7783 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:56.0340 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:56.2659 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:56.4861 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:56.6880 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:56.9407 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:57.1677 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:57.3679 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:57.5560 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:20:57.7362 findFrameBoundaries: start: [2510] end: [0]
2006-09-18 21:20:57.9454 findFrameBoundaries: start: [2432] end: [0]
2006-09-18 21:20:58.2104 findFrameBoundaries: start: [834] end: [0]
2006-09-18 21:20:58.4213 findFrameBoundaries: start: [1667] end: [0]
2006-09-18 21:20:58.6444 findFrameBoundaries: start: [710] end: [0]
2006-09-18 21:20:58.8437 findFrameBoundaries: start: [1414] end: [0]
2006-09-18 21:20:59.0802 findFrameBoundaries: start: [1705] end: [0]
2006-09-18 21:20:59.4872 findFrameBoundaries: start: [956] end: [0]
2006-09-18 21:20:59.7053 findFrameBoundaries: start: [2457] end: [0]
2006-09-18 21:20:59.9375 findFrameBoundaries: start: [1870] end: [0]
2006-09-18 21:21:00.1422 findFrameBoundaries: start: [1231] end: [0]
2006-09-18 21:21:00.3586 findFrameBoundaries: start: [889] end: [0]
2006-09-18 21:21:00.5721 findFrameBoundaries: start: [1084] end: [0]
2006-09-18 21:21:00.7822 findFrameBoundaries: start: [2580] end: [0]
2006-09-18 21:21:01.0413 findFrameBoundaries: start: [971] end: [0]
2006-09-18 21:21:01.2107 findFrameBoundaries: start: [1696] end: [0]
2006-09-18 21:21:01.3715 findFrameBoundaries: start: [1489] end: [0]
2006-09-18 21:21:01.5869 findFrameBoundaries: start: [1495] end: [0]
2006-09-18 21:21:01.7881 findFrameBoundaries: start: [1466] end: [0]
2006-09-18 21:21:02.0001 findFrameBoundaries: start: [2549] end: [0]
2006-09-18 21:21:02.2870 findFrameBoundaries: start: [2315] end: [0]
2006-09-18 21:21:02.5106 findFrameBoundaries: start: [2349] end: [0]
2006-09-18 21:21:02.7312 findFrameBoundaries: start: [1631] end: [0]
2006-09-18 21:21:02.9511 findFrameBoundaries: start: [2130] end: [0]
2006-09-18 21:21:03.1855 findFrameBoundaries: start: [1508] end: [0]
2006-09-18 21:21:03.3790 findFrameBoundaries: start: [2095] end: [0]
2006-09-18 21:21:03.5973 findFrameBoundaries: start: [2115] end: [0]
2006-09-18 21:21:03.7916 findFrameBoundaries: start: [1160] end: [0]
2006-09-18 21:21:04.0370 findFrameBoundaries: start: [2159] end: [0]
2006-09-18 21:21:04.3196 findFrameBoundaries: start: [2187] end: [0]
2006-09-18 21:21:04.5274 findFrameBoundaries: start: [2055] end: [0]
2006-09-18 21:21:04.7260 findFrameBoundaries: start: [1273] end: [0]
2006-09-18 21:21:04.9340 findFrameBoundaries: start: [1875] end: [0]
2006-09-18 21:21:05.1286 findFrameBoundaries: start: [1390] end: [0]
2006-09-18 21:21:05.3498 findFrameBoundaries: start: [2509] end: [0]
2006-09-18 21:21:05.5560 findFrameBoundaries: start: [2638] end: [0]
2006-09-18 21:21:05.7618 findFrameBoundaries: start: [1514] end: [0]
2006-09-18 21:21:06.0060 findFrameBoundaries: start: [1049] end: [0]
2006-09-18 21:21:06.2138 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:06.4293 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:06.6122 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:06.7844 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:07.0249 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:07.2595 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:07.5201 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:07.6744 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:07.9000 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:08.1742 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:08.3544 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:08.5169 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:08.7412 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:08.9877 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:09.2579 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:09.4405 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:09.7469 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:09.9205 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:10.0894 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:10.2805 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:10.4821 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:10.6908 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:10.8811 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:11.0744 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:11.2563 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:11.4313 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:11.6301 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:11.8173 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:12.2095 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:12.4052 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:12.6407 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:12.8493 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:13.0459 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:13.2349 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:13.4783 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:13.7002 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:13.9066 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:14.0874 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:14.3157 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:14.5205 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:14.7231 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:14.9459 findFrameBoundaries: start: [1738] end: [0]
2006-09-18 21:21:15.1191 findFrameBoundaries: start: [2360] end: [0]
2006-09-18 21:21:15.3365 findFrameBoundaries: start: [1418] end: [0]
2006-09-18 21:21:15.5489 findFrameBoundaries: start: [1414] end: [0]
2006-09-18 21:21:15.7481 findFrameBoundaries: start: [1250] end: [0]
2006-09-18 21:21:15.9301 findFrameBoundaries: start: [1050] end: [0]
2006-09-18 21:21:16.1479 findFrameBoundaries: start: [2682] end: [0]
2006-09-18 21:21:16.3246 findFrameBoundaries: start: [2389] end: [0]
2006-09-18 21:21:16.5591 findFrameBoundaries: start: [866] end: [0]
2006-09-18 21:21:16.7514 findFrameBoundaries: start: [2439] end: [0]
2006-09-18 21:21:16.9752 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:17.2505 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:17.5164 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:17.7393 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:17.9621 findFrameBoundaries: start: [1742] end: [0]
2006-09-18 21:21:18.2891 findFrameBoundaries: start: [663] end: [0]
2006-09-18 21:21:18.6052 findFrameBoundaries: start: [2526] end: [0]
2006-09-18 21:21:18.8221 findFrameBoundaries: start: [1509] end: [0]
2006-09-18 21:21:19.1391 findFrameBoundaries: start: [772] end: [0]
2006-09-18 21:21:19.5166 findFrameBoundaries: start: [417] end: [0]
2006-09-18 21:21:19.7165 findFrameBoundaries: start: [2376] end: [0]
2006-09-18 21:21:20.2418 
2006-09-18 21:21:20.4095 Request: Command [00:04:20:05:60:8a->power] (Done)
2006-09-18 21:21:20.4103    Param: [_newvalue] = [0]
2006-09-18 21:21:21.9094 00:04:20:05:60:8a: Switching to mode stop from stop
2006-09-18 21:21:21.9101  Already in playmode stop : ignoring mode change
2006-09-18 21:21:21.9104 jumping to 0
2006-09-18 21:21:21.9107 Adding song index 0 to song queue
2006-09-18 21:21:21.9110 Clearing out song queue first
2006-09-18 21:21:21.9113 Song queue is now 0
2006-09-18 21:21:21.9128 00:04:20:05:60:8a: Switching to mode play from stop
2006-09-18 21:21:21.9622 openSong on: file:///export/music/stars_of_the_lid/tired_sounds_of_stars_of_the_lid/stars_of_the_lid_-_the_tired_sounds_of_-_101_requiem_for_dying_mothers_part_1.mp3
2006-09-18 21:21:21.9650 openSong: duration: [397.871] size: [9768876] endian [] offset: [2549] for file:///export/music/stars_of_the_lid/tired_sounds_of_stars_of_the_lid/stars_of_the_lid_-_the_tired_sounds_of_-_101_requiem_for_dying_mothers_part_1.mp3
2006-09-18 21:21:21.9662 Setting maxBitRate for Master Bedroom to: 320
2006-09-18 21:21:21.9671 Setting maxBitRate for Master Bedroom to: 320
2006-09-18 21:21:21.9688 Setting maxBitRate for Master Bedroom to: 320
2006-09-18 21:21:21.9697 Setting maxBitRate for Master Bedroom to: 320
2006-09-18 21:21:21.9769 undermax = 1, type = mp3, squeezebox = 00:04:20:05:60:8a
2006-09-18 21:21:21.9778 checking formats for: mp3-aif-squeezebox-00:04:20:05:60:8a
2006-09-18 21:21:21.9781 checking formats for: mp3-aif-*-00:04:20:05:60:8a
2006-09-18 21:21:21.9783 checking formats for: mp3-aif-squeezebox-*
2006-09-18 21:21:21.9785 checking formats for: mp3-aif-*-*
2006-09-18 21:21:21.9788 checking formats for: mp3-wav-squeezebox-00:04:20:05:60:8a
2006-09-18 21:21:21.9790 checking formats for: mp3-wav-*-00:04:20:05:60:8a
2006-09-18 21:21:21.9793 checking formats for: mp3-wav-squeezebox-*
2006-09-18 21:21:21.9795 checking formats for: mp3-wav-*-*
2006-09-18 21:21:21.9797 checking formats for: mp3-mp3-squeezebox-00:04:20:05:60:8a
2006-09-18 21:21:21.9800 checking formats for: mp3-mp3-*-00:04:20:05:60:8a
2006-09-18 21:21:21.9802 checking formats for: mp3-mp3-squeezebox-*
2006-09-18 21:21:21.9804 checking formats for: mp3-mp3-*-*
2006-09-18 21:21:21.9806 Checking to see if mp3-mp3-*-* is enabled
2006-09-18 21:21:21.9809    enabled
2006-09-18 21:21:21.9811   Found command: -
2006-09-18 21:21:21.9852 Setting maxBitRate for Master Bedroom to: 320
2006-09-18 21:21:21.9862 Setting maxBitRate for Master Bedroom to: 320
2006-09-18 21:21:21.9896 Matched Format: mp3 Type: mp3 Command: - 
2006-09-18 21:21:21.9903 openSong: this is an mp3 file: file:///export/music/stars_of_the_lid/tired_sounds_of_stars_of_the_lid/stars_of_the_lid_-_the_tired_sounds_of_-_101_requiem_for_dying_mothers_part_1.mp3
2006-09-18 21:21:21.9908   file type: mp3 format: mp3 inrate: 196 maxRate: 320
2006-09-18 21:21:21.9911   command: -
2006-09-18 21:21:21.9916 openSong: opening file /export/music/stars_of_the_lid/tired_sounds_of_stars_of_the_lid/stars_of_the_lid_-_the_tired_sounds_of_-_101_requiem_for_dying_mothers_part_1.mp3
2006-09-18 21:21:21.9923 openSong: seeking in 2549 into /export/music/stars_of_the_lid/tired_sounds_of_stars_of_the_lid/stars_of_the_lid_-_the_tired_sounds_of_-_101_requiem_for_dying_mothers_part_1.mp3
2006-09-18 21:21:21.9930 openSong: Streaming with format: mp3
2006-09-18 21:21:22.1042 00:04:20:05:60:8a New play mode: play
2006-09-18 21:21:22.1094 00:04:20:05:60:8a: Current playmode: play
2006-09-18 21:21:22.1115 Request: Callback disabled
2006-09-18 21:21:22.1132 Request: Command [00:04:20:05:60:8a->playlist play] from CLI  (Done)
2006-09-18 21:21:22.1138    Param: [_item] = [/export/home/slim/playlists/sleepytime.m3u]
2006-09-18 21:21:24.0599 CLI: 127.0.0.1:38706 - Sending response [00%3A04%3A20%3A05%3A60%3A8a playlist play %2Fexport%2Fhome%2Fslim%2Fplaylists%2Fsleepytime.m3...]
2006-09-18 21:21:24.0621 CLI: Sent response to 127.0.0.1:38706
2006-09-18 21:21:24.0659 CLI: 127.0.0.1:38706 - Buffered [exit
]
2006-09-18 21:21:24.0685 Request [exit]: no match in dispatchDB!
2006-09-18 21:21:24.0696 CLI: Processing request [exit]
2006-09-18 21:21:24.0712 CLI: 127.0.0.1:38706 - Sending response [exi...]
2006-09-18 21:21:24.0805 CLI: Sent response to 127.0.0.1:38706
2006-09-18 21:21:24.0832 CLI: Closed connection with 127.0.0.1:38706 (0 active connections)
Comment 24 Dan Sully 2006-09-25 15:10:45 UTC 
Created attachment 1594 [details]
Allow playlistcontrol cmd:playlist_name

Ok, so this is really an enhancement request as fred suggests.

Fred - the solution to me seems to be something like this patch.

Thoughts
Comment 25 Dan Sully 2006-09-27 17:04:33 UTC 
Ping. Anyone? Bueller?
Comment 26 Fred 2006-09-28 07:56:59 UTC 
Looks good Dan. Want me to patch it in and document?

Now aparently we still have the issue the playlist DOES NOT PLAY if the path is used. I can't see anything wrong in the trace below, it changes to play mode and starts streaming. The only odd thing is the "power 0" command in the middle? Jason?
Comment 27 Jason Holtzapple 2006-09-28 08:36:16 UTC 
I don't know where the extra power 0 is coming from: this is all I am doing from cron

mixer volume 20
playlist shuffle 1
playlist play /export/home/slim/playlists/sleepytime.m3u
Comment 28 Dan Sully 2006-10-02 13:17:16 UTC 
I've commited the patch.

Jason - 'playlist play' on a playlist will cause the playlist to be scanned by Slim::Utils::Scanner
Comment 29 Jason Holtzapple 2006-10-03 08:50:29 UTC 
I'll test this patch tonight. Should I specify the playlist name (sleepytime), the full path (/export/home/slim/playlists/sleepytime.m3u) or does it matter?
Comment 30 Dan Sully 2006-10-03 09:57:56 UTC 
Subject: Re:  playlist play CLI command slow / doesn't play

Just the playlist name.
Comment 31 Jason Holtzapple 2006-10-03 21:23:36 UTC 
Created attachment 1618 [details]
v10145 log
Comment 32 Jason Holtzapple 2006-10-03 21:24:33 UTC 
I tried this version:

SlimServer Version: 6.5.1 - 10145 - Debian - EN - iso-8859-1
Server IP address: 192.168.1.7
Perl Version: 5.8.8 i686-linux
MySQL Version: 4.1.11-Debian_4sarge7-log

And the behavior is still the same as before - the playlist doesn't play. I attached a new debug log.
Comment 33 Dan Sully 2006-10-03 21:44:40 UTC 
Jason - you need to do:

playlistcontrol cmd:load playlist_name:sleepytime
Comment 34 Jason Holtzapple 2006-10-05 11:40:26 UTC 
OK! This seems to work. Thank you very much. I'll close the request.
First Last Prev Next    This bug is not in your last search results.