Bug 4350 - "All Songs" and "Search" Bug
: "All Songs" and "Search" Bug
Status: CLOSED FIXED
Product: Logitech Media Server
Classification: Unclassified
Component: Player UI
: 6.5.1
: Macintosh MacOS X 10
: P2 major (vote)
: ---
Assigned To: Chris Owens
:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2006-10-11 21:42 UTC by Brad Moody
Modified: 2011-03-16 04:18 UTC (History)
3 users (show)

See Also:
Category: ---


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Brad Moody 2006-10-11 21:42:57 UTC
Executing a word search for a track (ie type "dress" and receive back list of all songs containing "dress" in title) results in accurate search.  However, selecting "play" or "add to playlist" for the "all songs" option causes slimserver to attempt to load all songs in the library (22,000 plus) as a single playlist, essentially shutting down the service for an extended period of time and sometimes causing Safari to crash while waiting for the webpage to refresh.  

Also happens when word searching using remote control and Squeezebox.

From the mysql debug log:

2006-10-10 18:38:24.8552 ERROR: Request: Error when trying to run function coderef [Slim::Control::Commands::playlistXtracksCommand]: [panic: sv_setpvn called with negative strlen at /System/Library/Perl/5.8.1/darwin-thread-multi-2level/Encode.pm line 164.
]

2006-10-10 18:38:24.8693 Request: Command [00:04:20:05:02:94->playlist loadtracks] (Bad dispatch!)
2006-10-10 18:38:24.8697    Param: [_what] = [HASH(0x8b6f854)]
2006-10-10 19:09:47.0006 Cache: Skipping cleanup, server is busy
2006-10-10 19:19:47.0006 Cache: Skipping cleanup, server is busy
2006-10-10 19:29:47.0006 Cache: Skipping cleanup, server is busy
2006-10-10 19:39:47.0476 Cache: Skipping cleanup, server is busy
2006-10-10 19:49:47.0006 Cache: Skipping cleanup, server is busy
2006-10-10 19:59:47.0006 Cache: Skipping cleanup, server is busy
2006-10-10 20:09:47.0006 Cache: Skipping cleanup, server is busy


VERSION INFO
SlimServer Version: 6.5.1 - 10260 - Mac OS X 10.3.9 (7W98) - EN - utf8
Server IP address: 10.0.1.13
Perl Version: 5.8.1 darwin-thread-multi-2level
MySQL Version: 5.0.22-standard

Thanks, you all are great!
Brad Moody
Comment 1 KDF 2006-10-11 22:13:35 UTC
I suspect this is yet another case of old templates left behind, as it seems to work for me having tried to reproduce the problem.  Please trey removing the entire HTML directory, reinstall 6.5.1 and clear any browser caches.

if this is still a problem, please right click on the all songs play link, select properties and paste the full url that is given in the dialog box for the loadtracks subcommand.

it should look something like this:
command=playlist&subcommand=loadtracks&track.titlesearch=xxxxx
oh, and which skin are you using?
Comment 2 Brad Moody 2006-10-12 21:41:06 UTC
(In reply to comment #1)
> I suspect this is yet another case of old templates left behind, as it seems to
> work for me having tried to reproduce the problem.  Please trey removing the
> entire HTML directory, reinstall 6.5.1 and clear any browser caches.
> 
> if this is still a problem, please right click on the all songs play link,
> select properties and paste the full url that is given in the dialog box for
> the loadtracks subcommand.
> 
> it should look something like this:
> command=playlist&subcommand=loadtracks&track.titlesearch=xxxxx
> oh, and which skin are you using?
> 
fishbone skin (black) but checked with Purple skin also and still had the issue.  remember that the problem also shows when searching with the remote and squeezebox interface.
followed your suggestions: deleted safari browser cache, opened pref pane package for slimserver, found the html folder and deleted, reinstalled 6.5.1.
no joy. for example:
used advance search to find all tracks with "dress"
thirteen returned.   i right click on "play" for one of the thirteen tracks and cut and paste the following url:
http://10.0.1.13:9000/status_header.html?command=playlist&subcommand=loadtracks&track.id=14974&player=00%3A04%3A20%3A05%3A02%3A94
i right click on "play" for "all songs" and the url is:
http://10.0.1.13:9000/status_header.html?command=playlist&subcommand=loadtracks&searchRef=searchTrackResults&player=00%3A04%3A20%3A05%3A02%3A94 

don't know if it's related but there is other strange behavior in the way slimserver is organizing tunes. for example, with slimserver displaying artists alphabetically, i click on 5th dimension. i have their one cheesy hit "aquarius." it doesn't show up. Instead I get "No Album by.... and what follows are about 100 different artists.  the url for the "play" option for this list of 100 random artists is:
http://10.0.1.13:9000/status_header.html?command=playlist&subcommand=loadtracks&contributor.id=27&album.id=3&player=00%3A04%3A20%3A05%3A02%3A94

i wonder if this is an itunes problem. slimserver is set to interface with itunes and itunes just updated (again!) to 7.0.1.  I updated to this version. when the "all songs" problem first cropped up, i thought it might be a bad xml file from itunes so i trashed it and had itunes rebuild.  no help here either.

ideas? thanks for the prompt reply.
brad
Comment 3 KDF 2006-10-12 22:47:48 UTC
odd.  that same url works fine here.  what we should do is work toward what is done in the normal search: create a url that can recreate the search rather than refer to the resulting list.  the play command then reruns teh search to make sure the right results are sent.  Using the list as it does now, has some faults, namely a problem storing those results after some lengths of time.
Comment 4 Brad Moody 2006-10-16 08:50:35 UTC
I went back and completely cleaned out all slim files this weekend, including the MySQL files and some others that don't go away when you delete just the preference pane.  I then wiped the iTunes xml file and let iTunes rebuild.  I then re-installed slimserver.  After the expected delay rebuilding the database, I had better luck with the search feature.  Now, using the web interface (trying several different skins), it returns good search results and allows you to create and play the complete list by clicking the "play" button next to "All Songs."  Using the remote control and squeezebox, however, still results in the same problem: "All Songs" loads every song in the library.  Using the softsqueeze interface from a remote computer also still results in the problem.  Hmmm...
Comment 5 KDF 2006-10-16 09:53:54 UTC
ok, so lets focus on player UI.  What are you searching?  Artist/Album/Song?  Is the resulting item part of a various artist album? what is the output of d_command when you press play on the remote?
Comment 6 KDF 2006-10-16 22:01:06 UTC
oddly, this is working for me, so I really am curious what conditions are at play.  
Comment 7 Brad Moody 2006-10-17 11:09:07 UTC
Squeezebox starts on the Now Playing screen.  From there:
1. Down arrow to Search;
2. Right arrow takes me to Albums;
3. Down arrow through Artists to Songs;
4. Key in each letter of requested title;
5. Right arrow to initiate search;
6. Squeezebox displays first song of however many songs returned by search;
7. Up arrow takes me to "All Songs";
8. Play button;
9. Zonked.

Sorry this is so long but here is what the debug log showed with the d-command option selected. You can see there are 
some other things going on here that might give a clue.  I recognize CPAN as a source of Perl code but otherwise it's way over my head.  Also, in the course of trying to figure out what was going on a couple of days ago, perl crashed.  I have the log file if you want it.

If each of the "Request" lines is supposed to be a button press, I promise I did not press that many buttons!

Brad
________________
2006-10-16 19:55:39.3534 Request: Command [wipecache] (Done)
2006-10-16 19:55:41.772 defaults[585] 
The domain/default pair of (kCFPreferencesAnyApplication, AppleLocale) does not exist
Use of uninitialized value in chomp at /Library/PreferencePanes/SlimServer.prefPane/Contents/server/Slim/Utils/Unicode.pm line 95.
Use of uninitialized value in subroutine entry at /Library/PreferencePanes/SlimServer.prefPane/Contents/server/Slim/Utils/Unicode.pm line 102.
2006-10-16 19:55:41.841 defaults[586] 
The domain/default pair of (kCFPreferencesAnyApplication, AppleLanguages) does not exist
Use of uninitialized value in chomp at /Library/PreferencePanes/SlimServer.prefPane/Contents/server/Slim/Utils/Unicode.pm line 110.
Use of uninitialized value in substitution (s///) at /Library/PreferencePanes/SlimServer.prefPane/Contents/server/Slim/Utils/Unicode.pm line 112.
Use of uninitialized value in split at /Library/PreferencePanes/SlimServer.prefPane/Contents/server/Slim/Utils/Unicode.pm line 113.
v-strings are deprecated at /Library/PreferencePanes/SlimServer.prefPane/Contents/server/CPAN/Template/Document.pm line 41.
v-strings are deprecated at /Library/PreferencePanes/SlimServer.prefPane/Contents/server/CPAN/Template/Document.pm line 45.
2006-10-16 19:55:43.3045 SlimServer OSDetect init...
2006-10-16 19:55:43.3057 SlimServer OS Specific init...
2006-10-16 19:55:43.3059 SlimServer settings init...
2006-10-16 19:55:43.3349 SlimServer strings init...
2006-10-16 19:55:43.7811 SlimServer Info init...
2006-10-16 19:55:45.0643 SlimServer changing process priority to 0
2006-10-16 19:55:45.1928 SlimServer done init...
2006-10-16 19:56:54.9107 About to look for files in /Users/bradmoody/Music
2006-10-16 19:56:54.9140 For files with extensions in: [(?i-xsm:\.(?:mp+|mpc|wma|mp3|mp2|mov|m4b|m4a|mp4|aif|aiff|shn|ogg|ape|wav|wave|flac|flc|cue)$)]
2006-10-16 19:57:20.8223 Found 22667 files in /Users/bradmoody/Music
Use of uninitialized value in length at /Library/PreferencePanes/SlimServer.prefPane/Contents/server/lib/MP3/Info.pm line 756, <$fh> line 1.
2006-10-16 20:15:11.2213 
2006-10-16 20:15:11.2261 
2006-10-16 20:15:11.2441 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:11.2448    Param: [_buttoncode] = [done]
2006-10-16 20:15:11.2452    Param: [_time] = [2045.925]
2006-10-16 20:15:11.2456    Param: [_orFunction] = [1]
2006-10-16 20:15:11.2462 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:11.2469    Param: [_ircode] = [7689906f]
2006-10-16 20:15:11.2472    Param: [_time] = [2045.925]
2006-10-16 20:15:11.4108 
2006-10-16 20:15:11.4131 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:11.4136    Param: [_ircode] = [7689906f]
2006-10-16 20:15:11.4139    Param: [_time] = [2046.033]
2006-10-16 20:15:12.1682 
2006-10-16 20:15:12.1714 
2006-10-16 20:15:12.1787 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:12.1794    Param: [_buttoncode] = [down]
2006-10-16 20:15:12.1798    Param: [_time] = [2046.875]
2006-10-16 20:15:12.1800    Param: [_orFunction] = [1]
2006-10-16 20:15:12.1806 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:12.1810    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:12.1814    Param: [_time] = [2046.875]
2006-10-16 20:15:12.2759 
2006-10-16 20:15:12.2786 
2006-10-16 20:15:12.2827 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:12.2832    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:12.2835    Param: [_time] = [2046.981]
2006-10-16 20:15:12.2838    Param: [_orFunction] = [1]
2006-10-16 20:15:12.2843 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:12.2847    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:12.2850    Param: [_time] = [2046.981]
2006-10-16 20:15:14.1566 
2006-10-16 20:15:14.1595 
2006-10-16 20:15:14.1744 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:14.1749    Param: [_buttoncode] = [exit_right]
2006-10-16 20:15:14.1753    Param: [_time] = [2048.862]
2006-10-16 20:15:14.1755    Param: [_orFunction] = [1]
2006-10-16 20:15:14.1760 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:14.1763    Param: [_ircode] = [7689d02f]
2006-10-16 20:15:14.1768    Param: [_time] = [2048.862]
2006-10-16 20:15:14.2687 
2006-10-16 20:15:14.2705 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:14.2709    Param: [_ircode] = [7689d02f]
2006-10-16 20:15:14.2712    Param: [_time] = [2048.971]
2006-10-16 20:15:15.3091 
2006-10-16 20:15:15.3126 
2006-10-16 20:15:15.3190 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:15.3195    Param: [_buttoncode] = [down]
2006-10-16 20:15:15.3201    Param: [_time] = [2050.017]
2006-10-16 20:15:15.3207    Param: [_orFunction] = [1]
2006-10-16 20:15:15.3214 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:15.3217    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:15.3220    Param: [_time] = [2050.017]
2006-10-16 20:15:15.4177 
2006-10-16 20:15:15.4203 
2006-10-16 20:15:15.4228 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:15.5160    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:15.5166    Param: [_time] = [2050.125]
2006-10-16 20:15:15.5170    Param: [_orFunction] = [1]
2006-10-16 20:15:15.5176 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:15.5180    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:15.5183    Param: [_time] = [2050.125]
2006-10-16 20:15:15.8260 
2006-10-16 20:15:15.8288 
2006-10-16 20:15:18.3936 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:18.3960    Param: [_buttoncode] = [exit_right]
2006-10-16 20:15:18.3978    Param: [_time] = [2050.515]
2006-10-16 20:15:18.3987    Param: [_orFunction] = [1]
2006-10-16 20:15:18.4027 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:18.4037    Param: [_ircode] = [7689d02f]
2006-10-16 20:15:18.4067    Param: [_time] = [2050.515]
2006-10-16 20:15:18.4169 
2006-10-16 20:15:18.4192 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:18.4197    Param: [_ircode] = [7689d02f]
2006-10-16 20:15:18.4202    Param: [_time] = [2050.622]
2006-10-16 20:15:19.2936 
2006-10-16 20:15:19.2965 
2006-10-16 20:15:19.3424 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:19.3429    Param: [_buttoncode] = [numberScroll_2]
2006-10-16 20:15:19.3432    Param: [_time] = [2054.001]
2006-10-16 20:15:19.3437    Param: [_orFunction] = [1]
2006-10-16 20:15:19.3443 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:19.3447    Param: [_ircode] = [768908f7]
2006-10-16 20:15:19.3450    Param: [_time] = [2054.001]
2006-10-16 20:15:19.4009 
2006-10-16 20:15:19.4027 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:19.4031    Param: [_ircode] = [768908f7]
2006-10-16 20:15:19.4034    Param: [_time] = [2054.109]
2006-10-16 20:15:19.8852 
2006-10-16 20:15:19.8881 
2006-10-16 20:15:20.0100 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:20.0105    Param: [_buttoncode] = [numberScroll_2]
2006-10-16 20:15:20.0109    Param: [_time] = [2054.594]
2006-10-16 20:15:20.0111    Param: [_orFunction] = [1]
2006-10-16 20:15:20.0222 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:20.0227    Param: [_ircode] = [768908f7]
2006-10-16 20:15:20.0231    Param: [_time] = [2054.594]
2006-10-16 20:15:20.9265 
2006-10-16 20:15:20.9294 
2006-10-16 20:15:20.9402 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:20.9409    Param: [_buttoncode] = [down]
2006-10-16 20:15:20.9413    Param: [_time] = [2055.633]
2006-10-16 20:15:20.9416    Param: [_orFunction] = [1]
2006-10-16 20:15:20.9422 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:20.9425    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:20.9428    Param: [_time] = [2055.633]
2006-10-16 20:15:21.0321 
2006-10-16 20:15:21.0345 
2006-10-16 20:15:21.0373 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:21.0380    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:21.0384    Param: [_time] = [2055.741]
2006-10-16 20:15:21.0387    Param: [_orFunction] = [1]
2006-10-16 20:15:21.0393 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:21.0396    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:21.0402    Param: [_time] = [2055.741]
2006-10-16 20:15:21.1451 
2006-10-16 20:15:21.1485 
2006-10-16 20:15:21.1510 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:21.1515    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:21.1520    Param: [_time] = [2055.849]
2006-10-16 20:15:21.1523    Param: [_orFunction] = [1]
2006-10-16 20:15:21.1529 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:21.1533    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:21.1536    Param: [_time] = [2055.849]
2006-10-16 20:15:21.2489 
2006-10-16 20:15:21.2513 
2006-10-16 20:15:21.2594 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:21.2600    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:21.2605    Param: [_time] = [2055.956]
2006-10-16 20:15:21.2608    Param: [_orFunction] = [1]
2006-10-16 20:15:21.2627 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:21.2632    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:21.2635    Param: [_time] = [2055.956]
2006-10-16 20:15:21.3907 
2006-10-16 20:15:21.3931 
2006-10-16 20:15:21.4082 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:21.4087    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:21.4094    Param: [_time] = [2056.065]
2006-10-16 20:15:21.4104    Param: [_orFunction] = [1]
2006-10-16 20:15:21.4122 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:21.4127    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:21.4136    Param: [_time] = [2056.065]
2006-10-16 20:15:21.4872 
2006-10-16 20:15:21.4906 
2006-10-16 20:15:21.4986 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:21.4993    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:21.4997    Param: [_time] = [2056.173]
2006-10-16 20:15:21.5000    Param: [_orFunction] = [1]
2006-10-16 20:15:21.5008 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:21.5012    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:21.5015    Param: [_time] = [2056.173]
2006-10-16 20:15:21.5915 
2006-10-16 20:15:21.5939 
2006-10-16 20:15:21.5966 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:21.5972    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:21.5978    Param: [_time] = [2056.281]
2006-10-16 20:15:21.5981    Param: [_orFunction] = [1]
2006-10-16 20:15:21.5988 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:21.5993    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:21.5996    Param: [_time] = [2056.281]
2006-10-16 20:15:21.6800 
2006-10-16 20:15:21.6832 
2006-10-16 20:15:21.7112 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:21.7117    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:21.7122    Param: [_time] = [2056.388]
2006-10-16 20:15:21.7126    Param: [_orFunction] = [1]
2006-10-16 20:15:21.7158 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:21.7163    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:21.7167    Param: [_time] = [2056.388]
2006-10-16 20:15:21.8067 
2006-10-16 20:15:21.8103 
2006-10-16 20:15:21.8947 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:21.8952    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:21.8955    Param: [_time] = [2056.496]
2006-10-16 20:15:21.8960    Param: [_orFunction] = [1]
2006-10-16 20:15:21.8966 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:21.8970    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:21.8976    Param: [_time] = [2056.496]
2006-10-16 20:15:21.9253 
2006-10-16 20:15:21.9284 
2006-10-16 20:15:22.0329 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:22.0337    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:22.0341    Param: [_time] = [2056.604]
2006-10-16 20:15:22.0345    Param: [_orFunction] = [1]
2006-10-16 20:15:22.0351 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:22.0354    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:22.0357    Param: [_time] = [2056.604]
2006-10-16 20:15:22.0503 
2006-10-16 20:15:22.0530 
2006-10-16 20:15:22.0635 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:22.0641    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:22.0644    Param: [_time] = [2056.712]
2006-10-16 20:15:22.0647    Param: [_orFunction] = [1]
2006-10-16 20:15:22.0656 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:22.0660    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:22.0664    Param: [_time] = [2056.712]
2006-10-16 20:15:22.1117 
2006-10-16 20:15:22.1146 
2006-10-16 20:15:22.2243 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:22.2251    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:22.2255    Param: [_time] = [2056.82]
2006-10-16 20:15:22.2264    Param: [_orFunction] = [1]
2006-10-16 20:15:22.2272 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:22.2276    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:22.2280    Param: [_time] = [2056.82]
2006-10-16 20:15:22.2530 
2006-10-16 20:15:22.2557 
2006-10-16 20:15:22.2647 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:22.2653    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:22.2659    Param: [_time] = [2056.928]
2006-10-16 20:15:22.2663    Param: [_orFunction] = [1]
2006-10-16 20:15:22.2670 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:22.2674    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:22.2677    Param: [_time] = [2056.928]
2006-10-16 20:15:22.3779 
2006-10-16 20:15:22.3809 
2006-10-16 20:15:22.3905 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:22.3910    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:22.3913    Param: [_time] = [2057.036]
2006-10-16 20:15:22.3918    Param: [_orFunction] = [1]
2006-10-16 20:15:22.3925 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:22.3938    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:22.3942    Param: [_time] = [2057.036]
2006-10-16 20:15:22.4844 
2006-10-16 20:15:22.4871 
2006-10-16 20:15:22.5201 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:22.5206    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:22.5209    Param: [_time] = [2057.144]
2006-10-16 20:15:22.5212    Param: [_orFunction] = [1]
2006-10-16 20:15:22.5222 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:22.5226    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:22.5230    Param: [_time] = [2057.144]
2006-10-16 20:15:22.6392 
2006-10-16 20:15:22.6428 
2006-10-16 20:15:22.6641 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:22.6647    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:22.6650    Param: [_time] = [2057.253]
2006-10-16 20:15:22.6656    Param: [_orFunction] = [1]
2006-10-16 20:15:22.6663 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:22.6668    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:22.6671    Param: [_time] = [2057.253]
2006-10-16 20:15:22.6725 
2006-10-16 20:15:22.6755 
2006-10-16 20:15:22.7721 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:22.7727    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:22.7730    Param: [_time] = [2057.361]
2006-10-16 20:15:22.7733    Param: [_orFunction] = [1]
2006-10-16 20:15:22.7739 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:22.7743    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:22.7750    Param: [_time] = [2057.361]
2006-10-16 20:15:22.8418 
2006-10-16 20:15:22.8456 
2006-10-16 20:15:22.8951 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:22.8958    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:22.8962    Param: [_time] = [2057.467]
2006-10-16 20:15:22.8965    Param: [_orFunction] = [1]
2006-10-16 20:15:22.8972 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:22.8976    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:22.8984    Param: [_time] = [2057.467]
2006-10-16 20:15:22.9696 
2006-10-16 20:15:22.9727 
2006-10-16 20:15:22.9894 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:22.9903    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:22.9907    Param: [_time] = [2057.575]
2006-10-16 20:15:22.9911    Param: [_orFunction] = [1]
2006-10-16 20:15:22.9917 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:22.9921    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:22.9927    Param: [_time] = [2057.575]
2006-10-16 20:15:22.9980 
2006-10-16 20:15:23.1549 
2006-10-16 20:15:23.1746 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:23.1751    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:23.1755    Param: [_time] = [2057.684]
2006-10-16 20:15:23.1758    Param: [_orFunction] = [1]
2006-10-16 20:15:23.1767 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:23.1779    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:23.1784    Param: [_time] = [2057.684]
2006-10-16 20:15:23.1823 
2006-10-16 20:15:23.1847 
2006-10-16 20:15:23.2387 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:23.2395    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:23.2399    Param: [_time] = [2057.791]
2006-10-16 20:15:23.2402    Param: [_orFunction] = [1]
2006-10-16 20:15:23.2408 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:23.2412    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:23.2416    Param: [_time] = [2057.791]
2006-10-16 20:15:23.2470 
2006-10-16 20:15:23.2496 
2006-10-16 20:15:23.2575 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:23.2580    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:23.2583    Param: [_time] = [2057.901]
2006-10-16 20:15:23.2587    Param: [_orFunction] = [1]
2006-10-16 20:15:23.2595 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:23.2599    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:23.2603    Param: [_time] = [2057.901]
2006-10-16 20:15:23.3359 
2006-10-16 20:15:23.3383 
2006-10-16 20:15:23.3669 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:23.3674    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:23.3678    Param: [_time] = [2058.007]
2006-10-16 20:15:23.3681    Param: [_orFunction] = [1]
2006-10-16 20:15:23.3688 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:23.3692    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:23.3695    Param: [_time] = [2058.007]
2006-10-16 20:15:23.4778 
2006-10-16 20:15:23.4801 
2006-10-16 20:15:23.5095 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:23.5102    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:23.5106    Param: [_time] = [2058.115]
2006-10-16 20:15:23.5109    Param: [_orFunction] = [1]
2006-10-16 20:15:23.5116 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:23.5120    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:23.5123    Param: [_time] = [2058.115]
2006-10-16 20:15:23.6054 
2006-10-16 20:15:23.6079 
2006-10-16 20:15:23.6279 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:23.6285    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:23.6289    Param: [_time] = [2058.223]
2006-10-16 20:15:23.6292    Param: [_orFunction] = [1]
2006-10-16 20:15:23.6298 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:23.6302    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:23.6305    Param: [_time] = [2058.223]
2006-10-16 20:15:23.6507 
2006-10-16 20:15:23.6532 
2006-10-16 20:15:23.6929 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:23.7039    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:23.7045    Param: [_time] = [2058.331]
2006-10-16 20:15:23.7050    Param: [_orFunction] = [1]
2006-10-16 20:15:23.7057 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:23.7061    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:23.7065    Param: [_time] = [2058.331]
2006-10-16 20:15:23.7318 
2006-10-16 20:15:23.7343 
2006-10-16 20:15:23.8518 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:23.8523    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:23.8528    Param: [_time] = [2058.439]
2006-10-16 20:15:23.8531    Param: [_orFunction] = [1]
2006-10-16 20:15:23.8538 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:23.8542    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:23.8546    Param: [_time] = [2058.439]
2006-10-16 20:15:23.8632 
2006-10-16 20:15:23.8661 
2006-10-16 20:15:23.9669 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:23.9675    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:23.9679    Param: [_time] = [2058.547]
2006-10-16 20:15:23.9682    Param: [_orFunction] = [1]
2006-10-16 20:15:23.9689 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:23.9693    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:23.9696    Param: [_time] = [2058.547]
2006-10-16 20:15:23.9729 
2006-10-16 20:15:23.9859 
2006-10-16 20:15:23.9949 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:24.0569    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:24.0575    Param: [_time] = [2058.655]
2006-10-16 20:15:24.0579    Param: [_orFunction] = [1]
2006-10-16 20:15:24.0589 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:24.0594    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:24.0598    Param: [_time] = [2058.655]
2006-10-16 20:15:24.1655 
2006-10-16 20:15:24.1682 
2006-10-16 20:15:24.1762 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:24.1769    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:24.1775    Param: [_time] = [2058.763]
2006-10-16 20:15:24.1779    Param: [_orFunction] = [1]
2006-10-16 20:15:24.1785 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:24.1789    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:24.1793    Param: [_time] = [2058.763]
2006-10-16 20:15:24.1838 
2006-10-16 20:15:24.1862 
2006-10-16 20:15:24.2603 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:24.2611    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:24.2630    Param: [_time] = [2058.87]
2006-10-16 20:15:24.2635    Param: [_orFunction] = [1]
2006-10-16 20:15:24.2750 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:24.2756    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:24.2761    Param: [_time] = [2058.87]
2006-10-16 20:15:24.2805 
2006-10-16 20:15:24.2829 
2006-10-16 20:15:24.3761 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:24.3766    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:24.3770    Param: [_time] = [2058.979]
2006-10-16 20:15:24.3777    Param: [_orFunction] = [1]
2006-10-16 20:15:24.3784 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:24.3789    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:24.3793    Param: [_time] = [2058.979]
2006-10-16 20:15:24.4053 
2006-10-16 20:15:24.4079 
2006-10-16 20:15:24.4177 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:24.4183    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:24.4187    Param: [_time] = [2059.086]
2006-10-16 20:15:24.4190    Param: [_orFunction] = [1]
2006-10-16 20:15:24.4197 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:24.4202    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:24.4206    Param: [_time] = [2059.086]
2006-10-16 20:15:24.4953 
2006-10-16 20:15:24.4982 
2006-10-16 20:15:24.6033 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:24.6039    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:24.6043    Param: [_time] = [2059.194]
2006-10-16 20:15:24.6046    Param: [_orFunction] = [1]
2006-10-16 20:15:24.6053 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:24.6057    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:24.6060    Param: [_time] = [2059.194]
2006-10-16 20:15:24.6096 
2006-10-16 20:15:24.6234 
2006-10-16 20:15:24.7339 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:24.7346    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:24.7350    Param: [_time] = [2059.302]
2006-10-16 20:15:24.7353    Param: [_orFunction] = [1]
2006-10-16 20:15:24.7360 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:24.7364    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:24.7368    Param: [_time] = [2059.302]
2006-10-16 20:15:24.7686 
2006-10-16 20:15:24.7715 
2006-10-16 20:15:24.8017 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:24.8023    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:24.8027    Param: [_time] = [2059.411]
2006-10-16 20:15:24.8030    Param: [_orFunction] = [1]
2006-10-16 20:15:24.8037 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:24.8044    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:24.8052    Param: [_time] = [2059.411]
2006-10-16 20:15:24.8395 
2006-10-16 20:15:24.8423 
2006-10-16 20:15:24.9582 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:24.9588    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:24.9592    Param: [_time] = [2059.52]
2006-10-16 20:15:24.9595    Param: [_orFunction] = [1]
2006-10-16 20:15:24.9609 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:24.9618    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:24.9623    Param: [_time] = [2059.52]
2006-10-16 20:15:24.9785 
2006-10-16 20:15:24.9819 
2006-10-16 20:15:25.0030 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:25.0036    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:25.0040    Param: [_time] = [2059.626]
2006-10-16 20:15:25.0043    Param: [_orFunction] = [1]
2006-10-16 20:15:25.0050 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:25.0054    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:25.0058    Param: [_time] = [2059.626]
2006-10-16 20:15:25.1591 
2006-10-16 20:15:25.1622 
2006-10-16 20:15:25.2596 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:25.2602    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:25.2606    Param: [_time] = [2059.735]
2006-10-16 20:15:25.2609    Param: [_orFunction] = [1]
2006-10-16 20:15:25.2629 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:25.2635    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:25.2639    Param: [_time] = [2059.735]
2006-10-16 20:15:26.1369 
2006-10-16 20:15:26.1402 
2006-10-16 20:15:26.1523 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:26.1529    Param: [_buttoncode] = [up]
2006-10-16 20:15:26.1538    Param: [_time] = [2060.839]
2006-10-16 20:15:26.1542    Param: [_orFunction] = [1]
2006-10-16 20:15:26.1564 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:26.1570    Param: [_ircode] = [7689e01f]
2006-10-16 20:15:26.1575    Param: [_time] = [2060.839]
2006-10-16 20:15:26.2390 
2006-10-16 20:15:26.2418 
2006-10-16 20:15:26.2446 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:26.2453    Param: [_buttoncode] = [up_repeat]
2006-10-16 20:15:26.2457    Param: [_time] = [2060.946]
2006-10-16 20:15:26.2461    Param: [_orFunction] = [1]
2006-10-16 20:15:26.2470 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:26.2520    Param: [_ircode] = [7689e01f]
2006-10-16 20:15:26.2526    Param: [_time] = [2060.946]
2006-10-16 20:15:26.4939 
2006-10-16 20:15:26.4971 
2006-10-16 20:15:26.5050 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:26.5056    Param: [_buttoncode] = [up]
2006-10-16 20:15:26.5060    Param: [_time] = [2061.198]
2006-10-16 20:15:26.5065    Param: [_orFunction] = [1]
2006-10-16 20:15:26.5073 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:26.5077    Param: [_ircode] = [7689e01f]
2006-10-16 20:15:26.5081    Param: [_time] = [2061.198]
2006-10-16 20:15:26.5965 
2006-10-16 20:15:26.5993 
2006-10-16 20:15:26.6024 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:26.6030    Param: [_buttoncode] = [up_repeat]
2006-10-16 20:15:26.6034    Param: [_time] = [2061.306]
2006-10-16 20:15:26.6038    Param: [_orFunction] = [1]
2006-10-16 20:15:26.6045 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:26.6049    Param: [_ircode] = [7689e01f]
2006-10-16 20:15:26.6053    Param: [_time] = [2061.306]
2006-10-16 20:15:26.8072 
2006-10-16 20:15:26.8105 
2006-10-16 20:15:26.8244 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:26.8250    Param: [_buttoncode] = [up]
2006-10-16 20:15:26.8259    Param: [_time] = [2061.512]
2006-10-16 20:15:26.8263    Param: [_orFunction] = [1]
2006-10-16 20:15:26.8271 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:26.8276    Param: [_ircode] = [7689e01f]
2006-10-16 20:15:26.8280    Param: [_time] = [2061.512]
2006-10-16 20:15:26.9200 
2006-10-16 20:15:26.9228 
2006-10-16 20:15:26.9256 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:26.9261    Param: [_buttoncode] = [up_repeat]
2006-10-16 20:15:26.9266    Param: [_time] = [2061.621]
2006-10-16 20:15:26.9269    Param: [_orFunction] = [1]
2006-10-16 20:15:26.9277 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:26.9281    Param: [_ircode] = [7689e01f]
2006-10-16 20:15:26.9285    Param: [_time] = [2061.621]
2006-10-16 20:15:27.2628 
2006-10-16 20:15:27.2666 
2006-10-16 20:15:27.2745 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:27.2750    Param: [_buttoncode] = [up]
2006-10-16 20:15:27.2758    Param: [_time] = [2061.971]
2006-10-16 20:15:27.2763    Param: [_orFunction] = [1]
2006-10-16 20:15:27.2770 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:27.2775    Param: [_ircode] = [7689e01f]
2006-10-16 20:15:27.2841    Param: [_time] = [2061.971]
2006-10-16 20:15:27.6447 
2006-10-16 20:15:27.6479 
2006-10-16 20:15:27.6564 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:27.6570    Param: [_buttoncode] = [up]
2006-10-16 20:15:27.6576    Param: [_time] = [2062.353]
2006-10-16 20:15:27.6580    Param: [_orFunction] = [1]
2006-10-16 20:15:27.6586 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:27.6591    Param: [_ircode] = [7689e01f]
2006-10-16 20:15:27.6594    Param: [_time] = [2062.353]
2006-10-16 20:15:28.1687 
2006-10-16 20:15:28.1718 
2006-10-16 20:15:28.1805 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:28.1811    Param: [_buttoncode] = [up]
2006-10-16 20:15:28.1819    Param: [_time] = [2062.875]
2006-10-16 20:15:28.1825    Param: [_orFunction] = [1]
2006-10-16 20:15:28.1840 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:28.1846    Param: [_ircode] = [7689e01f]
2006-10-16 20:15:28.1851    Param: [_time] = [2062.875]
2006-10-16 20:15:28.2749 
2006-10-16 20:15:28.2775 
2006-10-16 20:15:28.2801 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:28.2808    Param: [_buttoncode] = [up_repeat]
2006-10-16 20:15:28.2812    Param: [_time] = [2062.983]
2006-10-16 20:15:28.2816    Param: [_orFunction] = [1]
2006-10-16 20:15:28.2825 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:28.2830    Param: [_ircode] = [7689e01f]
2006-10-16 20:15:28.2840    Param: [_time] = [2062.983]
2006-10-16 20:15:28.8373 
2006-10-16 20:15:28.8405 
2006-10-16 20:15:28.8498 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:28.8504    Param: [_buttoncode] = [up]
2006-10-16 20:15:28.8514    Param: [_time] = [2063.547]
2006-10-16 20:15:28.8519    Param: [_orFunction] = [1]
2006-10-16 20:15:28.8526 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:28.8531    Param: [_ircode] = [7689e01f]
2006-10-16 20:15:28.8534    Param: [_time] = [2063.547]
2006-10-16 20:15:29.8953 
2006-10-16 20:15:29.8982 
2006-10-16 20:15:29.9605 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:29.9610    Param: [_buttoncode] = [exit_right]
2006-10-16 20:15:29.9615    Param: [_time] = [2064.601]
2006-10-16 20:15:29.9622    Param: [_orFunction] = [1]
2006-10-16 20:15:29.9629 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:29.9633    Param: [_ircode] = [7689d02f]
2006-10-16 20:15:29.9637    Param: [_time] = [2064.601]
2006-10-16 20:15:30.0014 
2006-10-16 20:15:30.0066 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:30.0071    Param: [_ircode] = [7689d02f]
2006-10-16 20:15:30.0076    Param: [_time] = [2064.71]
2006-10-16 20:15:31.1857 
2006-10-16 20:15:31.1890 
2006-10-16 20:15:31.2321 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:31.2327    Param: [_buttoncode] = [down]
2006-10-16 20:15:31.2332    Param: [_time] = [2065.84]
2006-10-16 20:15:31.2337    Param: [_orFunction] = [1]
2006-10-16 20:15:31.2344 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:31.2348    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:31.2352    Param: [_time] = [2065.84]
2006-10-16 20:15:31.2790 
2006-10-16 20:15:31.2815 
2006-10-16 20:15:31.2843 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:31.2848    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:31.2853    Param: [_time] = [2065.948]
2006-10-16 20:15:31.2857    Param: [_orFunction] = [1]
2006-10-16 20:15:31.2969 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:31.2975    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:31.2980    Param: [_time] = [2065.948]
2006-10-16 20:15:32.3599 
2006-10-16 20:15:32.3632 
2006-10-16 20:15:32.3716 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:32.3722    Param: [_buttoncode] = [down]
2006-10-16 20:15:32.3731    Param: [_time] = [2067.07]
2006-10-16 20:15:32.3735    Param: [_orFunction] = [1]
2006-10-16 20:15:32.3742 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:32.3747    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:32.3751    Param: [_time] = [2067.07]
2006-10-16 20:15:32.4695 
2006-10-16 20:15:32.4727 
2006-10-16 20:15:32.4757 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:32.4763    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:32.4767    Param: [_time] = [2067.179]
2006-10-16 20:15:32.4771    Param: [_orFunction] = [1]
2006-10-16 20:15:32.4790 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:32.4796    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:32.4800    Param: [_time] = [2067.179]
2006-10-16 20:15:33.2329 
2006-10-16 20:15:33.2362 
2006-10-16 20:15:33.2648 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:33.2654    Param: [_buttoncode] = [down]
2006-10-16 20:15:33.2663    Param: [_time] = [2067.941]
2006-10-16 20:15:33.2669    Param: [_orFunction] = [1]
2006-10-16 20:15:33.2676 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:33.2681    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:33.2686    Param: [_time] = [2067.941]
2006-10-16 20:15:33.3824 
2006-10-16 20:15:33.3849 
2006-10-16 20:15:33.3879 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:33.3888    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:33.3893    Param: [_time] = [2068.049]
2006-10-16 20:15:33.3931    Param: [_orFunction] = [1]
2006-10-16 20:15:33.3943 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:33.3949    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:33.3953    Param: [_time] = [2068.049]
2006-10-16 20:15:34.3977 
2006-10-16 20:15:34.4007 
2006-10-16 20:15:34.4129 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:34.4135    Param: [_buttoncode] = [down]
2006-10-16 20:15:34.4139    Param: [_time] = [2069.107]
2006-10-16 20:15:34.4144    Param: [_orFunction] = [1]
2006-10-16 20:15:34.4151 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:34.4156    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:34.4160    Param: [_time] = [2069.107]
2006-10-16 20:15:34.5084 
2006-10-16 20:15:34.5110 
2006-10-16 20:15:34.5140 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:34.5146    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:34.5151    Param: [_time] = [2069.216]
2006-10-16 20:15:34.5155    Param: [_orFunction] = [1]
2006-10-16 20:15:34.5163 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:34.5168    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:34.5172    Param: [_time] = [2069.216]
2006-10-16 20:15:35.1729 
2006-10-16 20:15:35.1761 
2006-10-16 20:15:35.1846 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:35.1852    Param: [_buttoncode] = [down]
2006-10-16 20:15:35.1857    Param: [_time] = [2069.883]
2006-10-16 20:15:35.1861    Param: [_orFunction] = [1]
2006-10-16 20:15:35.1867 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:35.1873    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:35.1879    Param: [_time] = [2069.883]
2006-10-16 20:15:35.2819 
2006-10-16 20:15:35.2847 
2006-10-16 20:15:35.2874 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:35.2880    Param: [_buttoncode] = [down_repeat]
2006-10-16 20:15:35.2886    Param: [_time] = [2069.991]
2006-10-16 20:15:35.2890    Param: [_orFunction] = [1]
2006-10-16 20:15:35.2898 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:35.2902    Param: [_ircode] = [7689b04f]
2006-10-16 20:15:35.2907    Param: [_time] = [2069.991]
2006-10-16 20:15:38.7479 
2006-10-16 20:15:38.7513 
2006-10-16 20:15:38.7546 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:38.7551    Param: [_buttoncode] = [passback]
2006-10-16 20:15:38.7560    Param: [_time] = [2073.458]
2006-10-16 20:15:38.7565    Param: [_orFunction] = [1]
2006-10-16 20:15:38.7571 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:38.7579    Param: [_ircode] = [768910ef]
2006-10-16 20:15:38.7585    Param: [_time] = [2073.458]
2006-10-16 20:15:38.8546 
2006-10-16 20:15:38.8571 
2006-10-16 20:15:38.8597 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:38.8603    Param: [_buttoncode] = [passback]
2006-10-16 20:15:38.8608    Param: [_time] = [2073.565]
2006-10-16 20:15:38.8612    Param: [_orFunction] = [1]
2006-10-16 20:15:38.8633 Request: Command [00:04:20:05:02:94->ir] (Done)
2006-10-16 20:15:38.8638    Param: [_ircode] = [768910ef]
2006-10-16 20:15:38.8643    Param: [_time] = [2073.565]
2006-10-16 20:15:39.0072 
2006-10-16 20:15:39.0242 
2006-10-16 20:15:39.2444 Request: Command [00:04:20:05:02:94->playlist loadtracks] (Done)
2006-10-16 20:15:39.2450    Param: [_what] = [HASH(0x52c44f0)]
2006-10-16 20:15:39.2460 Request: Command [00:04:20:05:02:94->button] (Done)
2006-10-16 20:15:39.2466    Param: [_buttoncode] = [passback]
2006-10-16 20:15:39.2487    Param: [_time] = [2073.714]
2006-10-16 20:15:39.2493    Param: [_orFunction] = [1]
Use of uninitialized value in string eq at /Library/PreferencePanes/SlimServer.prefPane/Contents/server/lib/MP3/Info.pm line 823, <$fh> line 1.
Use of uninitialized value in string eq at /Library/PreferencePanes/SlimServer.prefPane/Contents/server/lib/MP3/Info.pm line 823, <$fh> line 1.
Use of uninitialized value in string eq at /Library/PreferencePanes/SlimServer.prefPane/Contents/server/lib/MP3/Info.pm line 823, <$fh> line 1.
Use of uninitialized value in string eq at /Library/PreferencePanes/SlimServer.prefPane/Contents/server/lib/MP3/Info.pm line 823, <$fh> line 1.
Use of uninitialized value in string eq at /Library/PreferencePanes/SlimServer.prefPane/Contents/server/lib/MP3/Info.pm line 823, <$fh> line 1.
Use of uninitialized value in string eq at /Library/PreferencePanes/SlimServer.prefPane/Contents/server/lib/MP3/Info.pm line 823, <$fh> line 1.
Use of uninitialized value in string eq at /Library/PreferencePanes/SlimServer.prefPane/Contents/server/lib/MP3/Info.pm line 823, <$fh> line 1.
Use of uninitialized value in string eq at /Library/PreferencePanes/SlimServer.prefPane/Contents/server/lib/MP3/Info.pm line 823, <$fh> line 1.
Wide character in syswrite at /Library/PreferencePanes/SlimServer.prefPane/Contents/server/Slim/Networking/Select.pm line 293.
2006-10-16 20:23:55.0374 Got to the END.
Size mismatch on APIC
Comment 8 Brad Moody 2006-10-17 11:16:07 UTC
I hope I am not roaming too far afield but using both squeezebox and a remote softsqueeze, my playlists generated from a search for songs routine has zonked slimserver twice.  Maybe there is a clue here as well.  The slimserver log for the most recent event:

2006-10-16 11:17:21.5692 SlimServer done init...
2006-10-16 11:20:51.9734 ERROR: playmode: Couldn't gotoNext song on playlist, stopping

2006-10-16 11:20:52.2562 ERROR: Error executing 'INSERT INTO playlist_track (playlist, position, track) VALUES (?, ?, ?)': DBD::mysql::st execute failed: Cannot add or update a child row: a foreign key constraint fails (`slimserver/playlist_track`, CONSTRAINT `playlist_track_ibfk_1` FOREIGN KEY (`track`) REFERENCES `tracks` (`id`) ON DELETE CASCADE) at /Library/PreferencePanes/SlimServer.prefPane/Contents/server/CPAN/DBIx/Class/Storage/DBI.pm line 771.

2006-10-16 11:20:52.2566 ERROR: Backtrace follows:

2006-10-16 11:20:52.2575 Backtrace:

   frame 0: Slim::Schema::Storage::throw_exception (/Library/PreferencePanes/SlimServer.prefPane/Contents/server/CPAN/DBIx/Class/Storage/DBI.pm line 773)
   frame 1: DBIx::Class::Storage::DBI::_execute (/Library/PreferencePanes/SlimServer.prefPane/Contents/server/CPAN/DBIx/Class/Storage/DBI.pm line 788)
   frame 2: DBIx::Class::Storage::DBI::insert (/Library/PreferencePanes/SlimServer.prefPane/Contents/server/CPAN/DBIx/Class/Row.pm line 75)
   frame 3: DBIx::Class::Row::insert (/Library/PreferencePanes/SlimServer.prefPane/Contents/server/CPAN/DBIx/Class/PK/Auto.pm line 43)
   frame 4: DBIx::Class::PK::Auto::insert (/Library/PreferencePanes/SlimServer.prefPane/Contents/server/CPAN/DBIx/Class/ResultSet.pm line 1335)
   frame 5: DBIx::Class::ResultSet::create (/Library/PreferencePanes/SlimServer.prefPane/Contents/server/Slim/Schema/Playlist.pm line 108)
   frame 6: Slim::Schema::Playlist::_addTracksToPlaylist (/Library/PreferencePanes/SlimServer.prefPane/Contents/server/Slim/Schema/Playlist.pm line 45)
   frame 7: Slim::Schema::Playlist::__ANON__ (/Library/PreferencePanes/SlimServer.prefPane/Contents/server/CPAN/DBIx/Class/Schema.pm line 584)
   frame 8: (eval) (/Library/PreferencePanes/SlimServer.prefPane/Contents/server/CPAN/DBIx/Class/Schema.pm line 572)
   frame 9: DBIx::Class::Schema::txn_do (/Library/PreferencePanes/SlimServer.prefPane/Contents/server/Slim/Schema/Playlist.pm line 46)
   frame 10: (eval) (/Library/PreferencePanes/SlimServer.prefPane/Contents/server/Slim/Schema/Playlist.pm line 39)
   frame 11: Slim::Schema::Playlist::setTracks (/Library/PreferencePanes/SlimServer.prefPane/Contents/server/Slim/Player/Playlist.pm line 757)
   frame 12: Slim::Player::Playlist::modifyPlaylistCallback (/Library/PreferencePanes/SlimServer.prefPane/Contents/server/Slim/Control/Request.pm line 1640)
   frame 13: Slim::Control::Request::notify (/Library/PreferencePanes/SlimServer.prefPane/Contents/server/Slim/Control/Request.pm line 753)
   frame 14: Slim::Control::Request::checkNotifications (./slimserver.pl line 469)
   frame 15: main::idle (./slimserver.pl line 445)
   frame 16: main::main (./slimserver.pl line 1071)

2006-10-16 11:20:52.2610 ERROR: Carp::Clan::__ANON__(): Error executing 'INSERT INTO playlist_track (playlist, position, track) VALUES (?, ?, ?)': DBD::mysql::st execute failed: Cannot add or update a child row: a foreign key constraint fails (`slimserver/playlist_track`, CONSTRAINT `playlist_track_ibfk_1` FOREIGN KEY (`track`) REFERENCES `tracks` (`id`) ON DELETE CASCADE) at /Library/PreferencePanes/SlimServer.prefPane/Contents/server/CPAN/DBIx/Class/Storage/DBI.pm line 771.

2006-10-16 11:20:52.2615 ERROR: Backtrace follows:

2006-10-16 11:20:52.2620 Backtrace:

   frame 0: Slim::Schema::throw_exception (/Library/PreferencePanes/SlimServer.prefPane/Contents/server/CPAN/DBIx/Class/Schema.pm line 606)
   frame 1: DBIx::Class::Schema::txn_do (/Library/PreferencePanes/SlimServer.prefPane/Contents/server/Slim/Schema/Playlist.pm line 46)
   frame 2: (eval) (/Library/PreferencePanes/SlimServer.prefPane/Contents/server/Slim/Schema/Playlist.pm line 39)
   frame 3: Slim::Schema::Playlist::setTracks (/Library/PreferencePanes/SlimServer.prefPane/Contents/server/Slim/Player/Playlist.pm line 757)
   frame 4: Slim::Player::Playlist::modifyPlaylistCallback (/Library/PreferencePanes/SlimServer.prefPane/Contents/server/Slim/Control/Request.pm line 1640)
   frame 5: Slim::Control::Request::notify (/Library/PreferencePanes/SlimServer.prefPane/Contents/server/Slim/Control/Request.pm line 753)
   frame 6: Slim::Control::Request::checkNotifications (./slimserver.pl line 469)
   frame 7: main::idle (./slimserver.pl line 445)
   frame 8: main::main (./slimserver.pl line 1071)

2006-10-16 11:28:06.3543 Got sigterm.
2006-10-16 11:28:06.3548 SlimServer cleaning up.
061016 11:28:06 [Note] /Library/PreferencePanes/SlimServer.prefPane/Contents/server/Bin/darwin/mysqld: Normal shutdown

2006-10-16 11:28:06.5699 ERROR: DBI Connection failed: DBI connect('hostname=127.0.0.1;port=9092;database=slimserver:mysql_socket=/Users/bradmoody/Library/Caches/SlimServer/slimserver-mysql.sock','slimserver',...) failed: Can't connect to MySQL server on '127.0.0.1' (61) at /Library/PreferencePanes/SlimServer.prefPane/Contents/server/CPAN/DBIx/Class/Storage/DBI.pm line 652

2006-10-16 11:28:06.5704 ERROR: Backtrace follows:

2006-10-16 11:28:06.5713 Backtrace:

   frame 0: Slim::Schema::Storage::throw_exception (/Library/PreferencePanes/SlimServer.prefPane/Contents/server/CPAN/DBIx/Class/Storage/DBI.pm line 658)
   frame 1: DBIx::Class::Storage::DBI::_connect (/Library/PreferencePanes/SlimServer.prefPane/Contents/server/CPAN/DBIx/Class/Storage/DBI.pm line 616)
   frame 2: DBIx::Class::Storage::DBI::_populate_dbh (/Library/PreferencePanes/SlimServer.prefPane/Contents/server/CPAN/DBIx/Class/Storage/DBI.pm line 543)
   frame 3: DBIx::Class::Storage::DBI::ensure_connected (/Library/PreferencePanes/SlimServer.prefPane/Contents/server/CPAN/DBIx/Class/Storage/DBI.pm line 557)
   frame 4: DBIx::Class::Storage::DBI::dbh (/Library/PreferencePanes/SlimServer.prefPane/Contents/server/Slim/Schema.pm line 247)
   frame 5: (eval) (/Library/PreferencePanes/SlimServer.prefPane/Contents/server/Slim/Schema.pm line 247)
   frame 6: Slim::Schema::disconnect (./slimserver.pl line 1037)
   frame 7: main::cleanup (/Library/PreferencePanes/SlimServer.prefPane/Contents/server/Slim/bootstrap.pm line 310)
   frame 8: Slim::bootstrap::sigterm (/System/Library/Perl/5.8.1/darwin-thread-multi-2level/IO/Select.pm line 191)
   frame 9: (eval) (/System/Library/Perl/5.8.1/darwin-thread-multi-2level/IO/Select.pm line 191)
   frame 10: IO::Select::select (/Library/PreferencePanes/SlimServer.prefPane/Contents/server/Slim/Networking/Select.pm line 201)
   frame 11: Slim::Networking::Select::select (./slimserver.pl line 492)
   frame 12: main::idle (./slimserver.pl line 445)
   frame 13: main::main (./slimserver.pl line 1071)

061016 11:28:08  InnoDB: Starting shutdown...
061016 11:28:10  InnoDB: Shutdown completed; log sequence number 0 140041763
061016 11:28:10 [Note] /Library/PreferencePanes/SlimServer.prefPane/Contents/server/Bin/darwin/mysqld: Shutdown complete

Comment 9 KDF 2006-10-17 13:21:11 UTC
First log, it is this info that I'm looking for:

2006-10-16 20:15:39.2444 Request: Command [00:04:20:05:02:94->playlist
loadtracks] (Done)
2006-10-16 20:15:39.2450    Param: [_what] = [HASH(0x52c44f0)]


However, the HASH makes is hard to debug the details.  The server needs a slight change in
/Library/PreferencePanes/SlimServer.prefPane/Contents/server/Slim/Control/Request.pm

change line 1780 (should be 1780 or thereabouts) from:
msg("   Param: [$key] = [$val]\n");

 to:
msg("   Param: [$key] = [%s]\n",Data::Dump::dump($val));

try the log again, and that HASH should then show a much more expanded set of details.  

Comment 10 Brad Moody 2006-10-18 04:46:12 UTC
Ok , made the changes to the file. stopped and restarted slim server, repeated the same search using the remote. Got this on the log:

2006-10-18 06:29:51.2480 ERROR: Request: Error when trying to run function coderef [Slim::Control::Commands::playlistXtracksCommand]: [panic: sv_setpvn called with negative strlen at /System/Library/Perl/5.8.1/darwin-thread-multi-2level/Encode.pm line 164.
]

2006-10-18 06:29:51.2642 Request: Command [00:04:20:05:02:94->playlist loadtracks] (Bad dispatch!)
2006-10-18 06:29:51.2647    Param: [_what] = [HASH(0x53f2a78)]

Helpful?
Brad
Comment 11 KDF 2006-10-19 14:33:23 UTC
sadly, not what I was hoping to see.  that HASH should have been expanded to show the contents. 

I realised I made a slight error in the change.
this:

	while (my ($key, $val) = each %{$self->{'_params'}}) {

    		msg("   Param: [$key] = [$val]\n");
 	}

becomes this:

	while (my ($key, $val) = each %{$self->{'_params'}}) {

    		msgf("   Param: [$key] = [%s]\n",Data::Dump::dump($val));
 	}

I should expect that OSX does not use a packaged version of the server like we have in Windows, so a SERVER RESTART should result in output much like this (which is causing a new search as part of the playback):


 Request: Command [ba:43:80:ae:96:cd->playlist loadtracks] (Done)
    Param: [_what] = [{ "me.titlesearch" => { like => ["WITH%", "% WITH%"] } }]
 Request: Command [ba:43:80:ae:96:cd->button] (Done)
    Param: [_buttoncode] = ["passback"]
    Param: [_time] = ["14244.03"]
    Param: [_orFunction] = [1] 


In my case: Search -> Songs -> "WITH", then right, up, press play on ALL SONGS 
Comment 12 Brad Moody 2006-10-19 22:12:40 UTC
OK, pasted  your revised code into the request.pm file. stopped and restarted slimserver. searched via remote on squeezebox for songs with word "dress."
twelve songs returned. arrow up key to "all songs" and pressed play. log file shows:

2006-10-20 00:08:32.4419 ERROR: Request: Error when trying to run function coderef [Slim::Control::Commands::playlistXtracksCommand]: [panic: sv_setpvn called with negative strlen at /System/Library/Perl/5.8.1/darwin-thread-multi-2level/Encode.pm line 164.
]

2006-10-20 00:08:32.4427 Request: Command [00:04:20:05:02:94->playlist loadtracks] (Bad dispatch!)
2006-10-20 00:08:32.4544    Param: [_what] = [{ "me.titlesearch" => { like => ["DRESS%", "% DRESS%"] } }]

Helpful now?
Brad
Comment 13 KDF 2006-10-19 22:44:02 UTC
yup.  it proves that the search is correct.  Something is wrong with the Encode module.
Dan, is this an error that you are familiar with?
Comment 14 Chris Owens 2006-10-23 10:32:25 UTC
Dan, is this a bug you think we can fix for 6.5.1?
Comment 15 Dan Sully 2006-10-23 11:22:02 UTC
This sounds like some wierd OS X 10.3 perl bug.

Brad - is it possible for you to upgrade to 10.4?

Or barring that, upgrade the Encode module?

You'll need the developer tools on your machine.

Feel up to it?

Thanks
Comment 16 Brad Moody 2006-10-23 13:10:11 UTC
I've got the developer tools installed already, used to run some x11 applications.
I have fiddled some with downloading various perl modules from CPAN using Terminal, trying to get a perl script up and running on a laptop computer (not running slimserver). Not particularly successful here but it was a learning experience.  If tweaking the ENCODE module is nothing more than cutting and pasting code that provide me using a text edit tool, I should be up for it.    

Have 10.4 on a new laptop but hate to spend the money upgrading for the computer running slim. The computer running slimserver is an older g4 getting long in the tooth and will probably be replaced in the next 6 months.  One thought: put slimserver on the new computer and see if the bug repeats to at least confirm it's a perl issue with 10.3.

You tell me which way you want to go.

Question, why does the OS matter? Did 10.4 come with a different version of perl? I thought the slimserver install included the perl modules needed to run the program.  

Best,
Brad  
Comment 17 Dan Sully 2006-10-23 13:20:05 UTC
To answer your last question first:

Yes, 10.3 and 10.4 come with different versions of perl, and the Encode module is part of 'Core' perl, IE: something that comes with perl itself, not something we ship with.

If you download:

http://search.cpan.org/CPAN/authors/id/D/DA/DANKOGAI/Encode-2.18.tar.gz

Then untar it, and cd to the directory created. Run:

perl Makefile.PL
make
make test
sudo make install UNINST=1

The sudo line will ask for your password.
Comment 18 Brad Moody 2006-10-23 20:33:12 UTC
Well, if at first you don't succeed...
Downloaded Encode file, it untarred itself to a folder on the desktop. I cd'd my way to it in Terminal and then typed in the "perl Makefile.PL" instruction.  Here's what Terminal spit back:
[Downstairs-Computer:~/Desktop/Encode-2] bradmood% cd /Users/bradmoody/Desktop/Encode-2/Encode-2.18 
[Downstairs-Computer:~/Desktop/Encode-2/Encode-2.18] bradmood% perl Makefile.PL
Checking if your kit is complete...
Looks good

Error: Unable to locate installed Perl libraries or Perl source code.

It is recommended that you install perl in a standard location before
building extensions. Some precompiled versions of perl do not contain
these header files, so you cannot build extensions. In such a case,
please build and install your perl from a fresh perl distribution. It
usually solves this kind of problem.

(You get this message, because MakeMaker could not find "/System/Library/Perl/5.8.1/darwin-thread-multi-2level/CORE/perl.h")

Now why is this problem occurring? I see perl dutifully located in /System/Library/Perl/5.8.1 (though there is no "darwin-thread etc." located within that folder (directory in unix talk, yes?).  I then used the "perl -V" command and got this back:

[Downstairs-Computer:~/Desktop/Encode-2/Encode-2.18] bradmood% perl -V
Summary of my perl5 (revision 5.0 version 8 subversion 1 RC3) configuration:
  Platform:
    osname=darwin, osvers=7.0, archname=darwin-thread-multi-2level
    uname='darwin hampsten 7.0 darwin kernel version 6.0: fri jul 25 16:58:41 pdt 2003; root:xnu-344.frankd.rootsxnu-344.frankd~objrelease_ppc power macintosh powerpc '
    config_args='-ds -e -Dprefix=/usr -Dccflags=-g  -pipe  -Dldflags=-Dman3ext=3pm -Duseithreads -Duseshrplib'
    hint=recommended, useposix=true, d_sigaction=define
    usethreads=define use5005threads=undef useithreads=define usemultiplicity=define
    useperlio=define d_sfio=undef uselargefiles=define usesocks=undef
    use64bitint=undef use64bitall=undef uselongdouble=undef
    usemymalloc=n, bincompat5005=undef
  Compiler:
    cc='cc', ccflags ='-g -pipe -pipe -fno-common -DPERL_DARWIN -no-cpp-precomp -fno-strict-aliasing -I/usr/local/include',
    optimize='-Os',
    cppflags='-no-cpp-precomp -g -pipe -pipe -fno-common -DPERL_DARWIN -no-cpp-precomp -fno-strict-aliasing -I/usr/local/include'
    ccversion='', gccversion='3.3 20030304 (Apple Computer, Inc. build 1495)', gccosandvers=''
    intsize=4, longsize=4, ptrsize=4, doublesize=8, byteorder=4321
    d_longlong=define, longlongsize=8, d_longdbl=define, longdblsize=8
    ivtype='long', ivsize=4, nvtype='double', nvsize=8, Off_t='off_t', lseeksize=8
    alignbytes=8, prototype=define
  Linker and Libraries:
    ld='MACOSX_DEPLOYMENT_TARGET=10.3 cc', ldflags ='-L/usr/local/lib'
    libpth=/usr/local/lib /usr/lib
    libs=-ldbm -ldl -lm -lc
    perllibs=-ldl -lm -lc
    libc=/usr/lib/libc.dylib, so=dylib, useshrplib=true, libperl=libperl.dylib
    gnulibc_version=''
  Dynamic Linking:
    dlsrc=dl_dyld.xs, dlext=bundle, d_dlsymun=undef, ccdlflags=' '
    cccdlflags=' ', lddlflags='-bundle -undefined dynamic_lookup -L/usr/local/lib'


Characteristics of this binary (from libperl): 
  Compile-time options: MULTIPLICITY USE_ITHREADS USE_LARGE_FILES PERL_IMPLICIT_CONTEXT
  Locally applied patches:
        RC3
  Built under darwin
  Compiled at Jan  9 2006 21:11:03
  @INC:
    /System/Library/Perl/5.8.1/darwin-thread-multi-2level
    /System/Library/Perl/5.8.1
    /Library/Perl/5.8.1/darwin-thread-multi-2level
    /Library/Perl/5.8.1
    /Library/Perl
    /Network/Library/Perl/5.8.1/darwin-thread-multi-2level
    /Network/Library/Perl/5.8.1
    /Network/Library/Perl
    .

I'm in your hands again.
Brad
Comment 19 Dan Sully 2006-10-23 20:42:33 UTC
Subject: Re:  "All Songs" and "Search" Bug

>Error: Unable to locate installed Perl libraries or Perl source code.

Make sure that all the Development & XCode libraries are installed. You might
also need 'BSD Subsystem'.

Comment 20 Brad Moody 2006-10-24 20:34:41 UTC
Ok, for some reason, the macintosh developer tools and related packages installed the files we needed to /System/Library/Perl/darwin/Core instead of /System/Library/Perl/5.8.1/darwin-thread-multi-2level where the Encode module was looking.  I copied all of the .h files from the /System/Library/Perl/darwin/Core file (including the perl.h file that was specifically referenced in the prompt I got back from Terminal when trying to update the Encode module last night) to System/Library/Perl/5.8.1/darwin-thread-multi-2level/Core.  I then fired up terminal again and tried to update the Encode module.  Here is the text from Terminal:

Last login: Tue Oct 24 22:16:05 on ttyp1
Welcome to Darwin!
[Downstairs-Computer:~] bradmood% cd /Encode-2.18 
[Downstairs-Computer:/Encode-2.18] bradmood% perl Makefile.PL
Writing Makefile for Encode::Byte
Writing Makefile for Encode::CN
Writing Makefile for Encode::EBCDIC
Writing Makefile for Encode::JP
Writing Makefile for Encode::KR
Writing Makefile for Encode::Symbol
Writing Makefile for Encode::TW
Writing Makefile for Encode::Unicode
Writing Makefile for Encode
[Downstairs-Computer:/Encode-2.18] bradmood% make
cp Encode/README.e2x blib/lib/Encode/README.e2x
cp Encode/_PM.e2x blib/lib/Encode/_PM.e2x
cp lib/Encode/Supported.pod blib/lib/Encode/Supported.pod
cp lib/Encode/Alias.pm blib/lib/Encode/Alias.pm
cp lib/Encode/Unicode/UTF7.pm blib/lib/Encode/Unicode/UTF7.pm
cp lib/Encode/MIME/Header/ISO_2022_JP.pm blib/lib/Encode/MIME/Header/ISO_2022_JP.pm
cp Encode/encode.h blib/lib/Encode/encode.h
cp Encode/Changes.e2x blib/lib/Encode/Changes.e2x
cp lib/Encode/MIME/Header.pm blib/lib/Encode/MIME/Header.pm
cp lib/Encode/JP/JIS7.pm blib/lib/Encode/JP/JIS7.pm
cp lib/Encode/KR/2022_KR.pm blib/lib/Encode/KR/2022_KR.pm
cp lib/Encode/Guess.pm blib/lib/Encode/Guess.pm
cp lib/Encode/PerlIO.pod blib/lib/Encode/PerlIO.pod
cp Encode/ConfigLocal_PM.e2x blib/lib/Encode/ConfigLocal_PM.e2x
cp Encode/_T.e2x blib/lib/Encode/_T.e2x
cp lib/Encode/CN/HZ.pm blib/lib/Encode/CN/HZ.pm
cp lib/Encode/Encoding.pm blib/lib/Encode/Encoding.pm
cp Encode/Makefile_PL.e2x blib/lib/Encode/Makefile_PL.e2x
cp lib/Encode/CJKConstants.pm blib/lib/Encode/CJKConstants.pm
cp lib/Encode/Config.pm blib/lib/Encode/Config.pm
cp lib/Encode/Encoder.pm blib/lib/Encode/Encoder.pm
cp Encode.pm blib/lib/Encode.pm
cp encoding.pm blib/lib/encoding.pm
cp lib/Encode/JP/H2Z.pm blib/lib/Encode/JP/H2Z.pm
cp Byte.pm ../blib/lib/Encode/Byte.pm
/usr/bin/perl  ../bin/enc2xs -"Q" -"O" -o byte_t.c -f byte_t.fnm
Reading iso-8859-2 (iso-8859-2)
Reading iso-8859-3 (iso-8859-3)
Reading iso-8859-4 (iso-8859-4)
Reading iso-8859-5 (iso-8859-5)
Reading iso-8859-6 (iso-8859-6)
Reading iso-8859-7 (iso-8859-7)
Reading iso-8859-8 (iso-8859-8)
Reading iso-8859-9 (iso-8859-9)
Reading iso-8859-10 (iso-8859-10)
Reading iso-8859-11 (iso-8859-11)
Reading iso-8859-13 (iso-8859-13)
Reading iso-8859-14 (iso-8859-14)
Reading iso-8859-15 (iso-8859-15)
Reading iso-8859-16 (iso-8859-16)
Reading AdobeStandardEncoding (AdobeStandardEncoding)
Reading cp1006 (cp1006)
Reading cp1250 (cp1250)
Reading cp1251 (cp1251)
Reading cp1252 (cp1252)
Reading cp1253 (cp1253)
Reading cp1254 (cp1254)
Reading cp1255 (cp1255)
Reading cp1256 (cp1256)
Reading cp1257 (cp1257)
Reading cp1258 (cp1258)
Reading cp424 (cp424)
Reading cp437 (cp437)
Reading cp737 (cp737)
Reading cp775 (cp775)
Reading cp850 (cp850)
Reading cp852 (cp852)
Reading cp855 (cp855)
Reading cp856 (cp856)
Reading cp857 (cp857)
Reading cp860 (cp860)
Reading cp861 (cp861)
Reading cp862 (cp862)
Reading cp863 (cp863)
Reading cp864 (cp864)
Reading cp865 (cp865)
Reading cp866 (cp866)
Reading cp869 (cp869)
Reading cp874 (cp874)
Reading gsm0338 (gsm0338)
Reading hp-roman8 (hp-roman8)
Reading koi8-f (koi8-f)
Reading koi8-r (koi8-r)
Reading koi8-u (koi8-u)
Reading MacArabic (MacArabic)
Reading MacCentralEurRoman (MacCentralEurRoman)
Reading MacCroatian (MacCroatian)
Reading MacCyrillic (MacCyrillic)
Reading MacFarsi (MacFarsi)
Reading MacGreek (MacGreek)
Reading MacHebrew (MacHebrew)
Reading MacIcelandic (MacIcelandic)
Reading MacRomanian (MacRomanian)
Reading MacRumanian (MacRumanian)
Reading MacRoman (MacRoman)
Reading MacSami (MacSami)
Reading MacThai (MacThai)
Reading MacTurkish (MacTurkish)
Reading MacUkrainian (MacUkrainian)
Reading nextstep (nextstep)
Reading viscii (viscii)
Writing compiled form
14272 bytes in string tables
4545 bytes (24.2%) saved spotting duplicates
10 bytes (0.07%) saved using substrings
/usr/bin/perl /System/Library/Perl/5.8.1/ExtUtils/xsubpp  -nolinenumbers -typemap /System/Library/Perl/5.8.1/ExtUtils/typemap  Byte.xs > Byte.xsc && mv Byte.xsc Byte.c
cc -c  -I../Encode -g -pipe -pipe -fno-common -DPERL_DARWIN -no-cpp-precomp -fno-strict-aliasing -I/usr/local/include -Os   -DVERSION=\"2.02\" -DXS_VERSION=\"2.02\"  "-I/System/Library/Perl/5.8.1/darwin-thread-multi-2level/CORE"   Byte.c
cc -c  -I../Encode -g -pipe -pipe -fno-common -DPERL_DARWIN -no-cpp-precomp -fno-strict-aliasing -I/usr/local/include -Os   -DVERSION=\"2.02\" -DXS_VERSION=\"2.02\"  "-I/System/Library/Perl/5.8.1/darwin-thread-multi-2level/CORE"   byte_t.c
Running Mkbootstrap for Encode::Byte ()
chmod 644 Byte.bs
rm -f ../blib/arch/auto/Encode/Byte/Byte.bundle
LD_RUN_PATH="" MACOSX_DEPLOYMENT_TARGET=10.3 cc  -bundle -undefined dynamic_lookup -L/usr/local/lib Byte.o byte_t.o  -o ../blib/arch/auto/Encode/Byte/Byte.bundle      
ld: -undefined: unknown argument: dynamic_lookup
make[1]: *** [../blib/arch/auto/Encode/Byte/Byte.bundle] Error 1
make: *** [subdirs] Error 2
[Downstairs-Computer:/Encode-2.18] bradmood% make test
rm -f ../blib/arch/auto/Encode/Byte/Byte.bundle
LD_RUN_PATH="" MACOSX_DEPLOYMENT_TARGET=10.3 cc  -bundle -undefined dynamic_lookup -L/usr/local/lib Byte.o byte_t.o  -o ../blib/arch/auto/Encode/Byte/Byte.bundle      
ld: -undefined: unknown argument: dynamic_lookup
make[1]: *** [../blib/arch/auto/Encode/Byte/Byte.bundle] Error 1
make: *** [subdirs] Error 2
[Downstairs-Computer:/Encode-2.18] bradmood% exit

As you can see, I stopped after the errors came back because it did not look right.  
Progress, I suppose but still need more guidance from you. Thanks.
Brad
Comment 21 Dan Sully 2006-10-24 21:30:02 UTC
Subject: Re:  "All Songs" and "Search" Bug

>As you can see, I stopped after the errors came back because it did not look
>right.  
>Progress, I suppose but still need more guidance from you. Thanks.

It really sounds like something is messed up with your perl / OS X install.

Is this OS X Server by any chance?

Comment 22 Brad Moody 2006-10-28 19:59:24 UTC
No, it's 10.3.9.  Is there a good way to make a fresh install of perl? 

I have no idea why perl would be messed up on this computer.  I have not made any changes, additions or deletions to any perl files on this computer.  Other than slimserver, I don't know of any other perl programs that run on it with any regularity. looking at the crash log for perl, it has gone down 16 times since 10.3.9 was installed in June of 2005.  4 of those instances have been since I updated slimserver to 6.5.1. Again, slimserver basically runs 24/7 and get's fairly heavy use.

Brad
Comment 23 Chris Owens 2006-11-03 15:32:40 UTC
I've researched it a bit, and it doesn't look like there's a way to selectively repair perl on osx.

I assume you've been installing the regular updates from Apple?  You haven't had problems with any of your other software?
Comment 24 Brad Moody 2006-11-03 15:41:05 UTC
No, the OS is generally stable. Occasional freezes when firewire hard drives connect. Run a variety of apps, too.
So now I am looking at a reinstall of the OS? This can't be right. 
I'm going to put slimserver on my laptop running 10.4 and see how it responds.  I think I would rather pay for a copy of 10.4 than wipe and reinstall 10.3.
b
Comment 25 Chris Owens 2006-11-08 11:44:46 UTC
That would be great if you could do that, Brad.  You might also try posting to the forums to see if there's anyone else who's seen this.  I'd love to be able to reproduce this, and any additional info would help.
Comment 26 KDF 2007-05-18 08:23:01 UTC
any new information on this one?
Comment 27 Brad Moody 2007-05-18 08:52:58 UTC
you know, I decided to take the easy route and upgraded to OSX 10.4. Since then, no problems.  I should have said something earlier because I think you will want to close out this bug report. Brad. PS I hope that the new owners of the company are treating you all well.
Comment 28 Chris Owens 2007-05-18 16:54:31 UTC
Not bad so far, Brad.