PDA

View Full Version : Slim::Plugin::CLI::Plugin::cli_process (627) Request [artist] failed with error: Bad.



mkanet
2008-09-26, 14:26
Hi, I just realized I am getting a non-stop error message reported in my server.log file. This error message happens 24/7 once every second. How can I fix this problem? I am using the latest non-beta release of SqueezeCenter: verion 7.2

PS: I dont have any 3rd party plugins installed. All my options are pretty close to their defaults:

Thanks in advance to help get this resolved!

Server.log:

[08-09-26 14:17:47.0158] Slim::Plugin::CLI::Plugin::cli_process (627) Request [artist] failed with error: Bad dispatch!
[08-09-26 14:17:52.0155] Slim::Control::Request::execute (1800) Error: While trying to run function coderef [Slim::Control::Queries::cursonginfoQuery]: [Can't call method "name" on an undefined value at /<C:\Program Files\SqueezeCenter\server\squeezecenter.exe>Slim/Control/Queries.pm line 882.

mkanet
2008-09-27, 18:53
^bump^ This error happens on a completely clean install over and over again.

andyg
2008-09-27, 19:53
Hmm, thanks, I've fixed that crash. But you must be running something that's using the CLI.

mkanet
2008-09-27, 20:11
Hi Andy, thanks for responding. I would really appreciate if you could tell me what I can do next. As far as I know, I thought I just have a stock version of Squeezecenter 7.2 (upgraded from 7.1.. upgraded from 7.01). I only use Squeezecenter now with Softsqueeze. I seem to get these errors banging away every second 24/7.... with or without softqueeze.

Thanks for helping out.


Hmm, thanks, I've fixed that crash. But you must be running something that's using the CLI.

mkanet
2008-09-28, 09:58
Andy, when you say, "Hmm, thanks, I've fixed that crash..", does that means you just fixed this problem shortly after I reported it? Am I supposed to download the latest beta build to fix this problem? This constant banging away of my log file once every second with this message seems to be slowing down my machine.. especially over time.

Thanks for your help!
-Michael

andyg
2008-09-28, 10:25
Yes, download the latest 7.2.1 nightly. Still doesn't explain what is causing the requests.

mkanet
2008-09-28, 11:11
Andy, here's youre problem (see below debugview and respective squeezecenter.exe PID). Debugview shows a problem banging away several times a second. It looks like a bug. You can also see the server.log file the error is still generated over and over again.

I am also getting a new error message in server.log from version 7.2.1 complaining about "My Radio Stations (v0.1)" is incompatible with this version. Looks like a second minor bug .




[08-09-28 10:54:40.9059] Slim::Utils::PluginManager::enablePlugins (406) Couldn't load Slim::Plugin::MyRadio::Plugin. Error: Plugin is incompatible with this version of SqueezeCenter. Please update.
[08-09-28 10:57:47.0415] Slim::Control::Request::renderAsArray (2256) Error: request should set useIxHashes in Slim::Control::Request->new()
[08-09-28 10:57:47.0421] Slim::Control::Request::renderAsArray (2256) Backtrace:

frame 0: Slim::Utils::Log::logBacktrace (/<C:\Program Files\SqueezeCenter\server\squeezecenter.exe>Slim/Control/Request.pm line 2256)
frame 1: Slim::Control::Request::renderAsArray (C:/Program Files/SqueezeCenter/server/Slim/Plugin/CLI/Plugin.pm line 684)
frame 2: Slim::Plugin::CLI::Plugin::cli_request_write (C:/Program Files/SqueezeCenter/server/Slim/Plugin/CLI/Plugin.pm line 999)
frame 3: Slim::Plugin::CLI::Plugin::cli_subscribe_notificat ion (/<C:\Program Files\SqueezeCenter\server\squeezecenter.exe>Slim/Control/Request.pm line 2068)
frame 4: (eval) (/<C:\Program Files\SqueezeCenter\server\squeezecenter.exe>Slim/Control/Request.pm line 2068)
frame 5: Slim::Control::Request::notify (/<C:\Program Files\SqueezeCenter\server\squeezecenter.exe>Slim/Control/Request.pm line 844)
frame 6: Slim::Control::Request::checkNotifications (slimserver.pl line 510)
frame 7: main::idle (slimserver.pl line 45)
frame 8: PerlSvc::Startup (/<C:\Program Files\SqueezeCenter\server\squeezecenter.exe>PerlSvc.pm line 95)
frame 9: PerlSvc::_startup (slimserver.pl line 0)
frame 10: (eval) (slimserver.pl line 0)

[08-09-28 10:57:47.0434] Slim::Control::Request::renderAsArray (2256) Error: request should set useIxHashes in Slim::Control::Request->new()
[08-09-28 10:57:47.0437] Slim::Control::Request::renderAsArray (2256) Backtrace:

frame 0: Slim::Utils::Log::logBacktrace (/<C:\Program Files\SqueezeCenter\server\squeezecenter.exe>Slim/Control/Request.pm line 2256)
frame 1: Slim::Control::Request::renderAsArray (C:/Program Files/SqueezeCenter/server/Slim/Plugin/CLI/Plugin.pm line 684)
frame 2: Slim::Plugin::CLI::Plugin::cli_request_write (C:/Program Files/SqueezeCenter/server/Slim/Plugin/CLI/Plugin.pm line 999)
frame 3: Slim::Plugin::CLI::Plugin::cli_subscribe_notificat ion (/<C:\Program Files\SqueezeCenter\server\squeezecenter.exe>Slim/Control/Request.pm line 2068)
frame 4: (eval) (/<C:\Program Files\SqueezeCenter\server\squeezecenter.exe>Slim/Control/Request.pm line 2068)
frame 5: Slim::Control::Request::notify (/<C:\Program Files\SqueezeCenter\server\squeezecenter.exe>Slim/Control/Request.pm line 844)
frame 6: Slim::Control::Request::checkNotifications (slimserver.pl line 510)
frame 7: main::idle (slimserver.pl line 45)
frame 8: PerlSvc::Startup (/<C:\Program Files\SqueezeCenter\server\squeezecenter.exe>PerlSvc.pm line 95)
frame 9: PerlSvc::_startup (slimserver.pl line 0)
frame 10: (eval) (slimserver.pl line 0)

[08-09-28 10:57:47.0451] Slim::Control::Request::renderAsArray (2256) Error: request should set useIxHashes in Slim::Control::Request->new()
[08-09-28 10:57:47.0457] Slim::Control::Request::renderAsArray (2256) Backtrace:

frame 0: Slim::Utils::Log::logBacktrace (/<C:\Program Files\SqueezeCenter\server\squeezecenter.exe>Slim/Control/Request.pm line 2256)
frame 1: Slim::Control::Request::renderAsArray (C:/Program Files/SqueezeCenter/server/Slim/Plugin/CLI/Plugin.pm line 684)
frame 2: Slim::Plugin::CLI::Plugin::cli_request_write (C:/Program Files/SqueezeCenter/server/Slim/Plugin/CLI/Plugin.pm line 999)
frame 3: Slim::Plugin::CLI::Plugin::cli_subscribe_notificat ion (/<C:\Program Files\SqueezeCenter\server\squeezecenter.exe>Slim/Control/Request.pm line 2068)
frame 4: (eval) (/<C:\Program Files\SqueezeCenter\server\squeezecenter.exe>Slim/Control/Request.pm line 2068)
frame 5: Slim::Control::Request::notify (/<C:\Program Files\SqueezeCenter\server\squeezecenter.exe>Slim/Control/Request.pm line 844)
frame 6: Slim::Control::Request::checkNotifications (slimserver.pl line 510)
frame 7: main::idle (slimserver.pl line 45)
frame 8: PerlSvc::Startup (/<C:\Program Files\SqueezeCenter\server\squeezecenter.exe>PerlSvc.pm line 95)
frame 9: PerlSvc::_startup (slimserver.pl line 0)
frame 10: (eval) (slimserver.pl line 0)

[08-09-28 10:57:47.0469] Slim::Control::Request::renderAsArray (2256) Error: request should set useIxHashes in Slim::Control::Request->new()
[08-09-28 10:57:47.0473] Slim::Control::Request::renderAsArray (2256) Backtrace:

frame 0: Slim::Utils::Log::logBacktrace (/<C:\Program Files\SqueezeCenter\server\squeezecenter.exe>Slim/Control/Request.pm line 2256)
frame 1: Slim::Control::Request::renderAsArray (C:/Program Files/SqueezeCenter/server/Slim/Plugin/CLI/Plugin.pm line 684)
frame 2: Slim::Plugin::CLI::Plugin::cli_request_write (C:/Program Files/SqueezeCenter/server/Slim/Plugin/CLI/Plugin.pm line 999)
frame 3: Slim::Plugin::CLI::Plugin::cli_subscribe_notificat ion (/<C:\Program Files\SqueezeCenter\server\squeezecenter.exe>Slim/Control/Request.pm line 2068)
frame 4: (eval) (/<C:\Program Files\SqueezeCenter\server\squeezecenter.exe>Slim/Control/Request.pm line 2068)
frame 5: Slim::Control::Request::notify (/<C:\Program Files\SqueezeCenter\server\squeezecenter.exe>Slim/Control/Request.pm line 844)
frame 6: Slim::Control::Request::checkNotifications (slimserver.pl line 510)
frame 7: main::idle (slimserver.pl line 45)
frame 8: PerlSvc::Startup (/<C:\Program Files\SqueezeCenter\server\squeezecenter.exe>PerlSvc.pm line 95)
frame 9: PerlSvc::_startup (slimserver.pl line 0)
frame 10: (eval) (slimserver.pl line 0)

[08-09-28 10:57:50.0137] Slim::Control::Request::execute (1887) Error: While trying to run function coderef [Slim::Control::Queries::cursonginfoQuery]: [Can't call method "name" on an undefined value at /<C:\Program Files\SqueezeCenter\server\squeezecenter.exe>Slim/Control/Queries.pm line 882.
]
[08-09-28 10:57:50.0145] Slim::Plugin::CLI::Plugin::cli_process (627) Request [artist] failed with error: Bad dispatch!
[08-09-28 10:57:55.0151] Slim::Control::Request::execute (1887) Error: While trying to run function coderef [Slim::Control::Queries::cursonginfoQuery]: [Can't call method "name" on an undefined value at /<C:\Program Files\SqueezeCenter\server\squeezecenter.exe>Slim/Control/Queries.pm line 882.
]

mkanet
2008-09-28, 12:26
Yeah, I know, I was speechless too after seeing that ;)

mkanet
2008-09-29, 13:37
Hi Andy, still standing by for a fix. Let me know if there's further debug information that I need to provide.

BTW, thanks for your sincere effort to get this resolved soon,
Michael

andyg
2008-09-29, 13:53
Are you saying the latest 7.2.1 nightly didn't fix the problem?

mkanet
2008-09-29, 14:01
Yes Andy. I hope you dont take this the wrong way, but did you look at the Debugview and server.log output after upgrading to 7.2.1?


Are you saying the latest 7.2.1 nightly didn't fix the problem?

Triode
2008-09-29, 14:22
Michael,

Its difficult to see what is causing these requests. Could you enable control.command debbugging on the logging web page and then post what you see in the log.

Thanks

mkanet
2008-09-29, 14:42
Hi Andy, I have looked and looked, but I cant find any documentation on how to enable control.command logging. I have also searched all over the web interface for logging features. Can you please tell me where to turn this on and where to grab the information?

Thanks!
Michael

mkanet
2008-09-29, 16:47
Okay, I have the control.command logging file. But it's too big to post here. Even, after a short period of time of logging. I dont want to truncate the file in case I accidentally omit important clues.

I can post this log file for download privately. However, I'm not sure who to send a private message that can actually fix the problem.

I will PM the download link to Andy and Triode

Thanks,
Michael

PS: Below are the errors I get now consistently without debugging enabled:



[08-09-29 16:49:31.0339] Slim::Plugin::CLI::Plugin::cli_process (627) Request [artist] failed with error: Bad dispatch!
[08-09-29 16:49:36.0134] Slim::Control::Request::execute (1887) Error: While trying to run function coderef [Slim::Control::Queries::cursonginfoQuery]: [Can't call method "name" on an undefined value at /<C:\PROGRA~1\SQUEEZ~1\server\SQUEEZ~1.EXE>Slim/Control/Queries.pm line 882.

mkanet
2008-09-29, 23:52
[08-09-29 23:40:26.0132] Slim::Plugin::CLI::Plugin::cli_process (627) Request [artist] failed with error: Bad dispatch!
[08-09-29 23:40:31.0134] Slim::Control::Request::execute (1887) Error: While trying to run function coderef [Slim::Control::Queries::cursonginfoQuery]: [Can't call method "name" on an undefined value at /<C:\PROGRA~1\SQUEEZ~1\server\SQUEEZ~1.EXE>Slim/Control/Queries.pm line 882.
]

mkanet
2008-10-01, 09:00
I found the problem. I just realized I am using something that calls the CLI very 5 seconds. The developer's response when I asked for him to fix this problem is below. Any chance you can make a little change in the next nightly build to keep it quiet during the below query:

Michael,

It's a bug in squeezecenter. SlimPlayer plugin issues the following CLI commands repeatedly (5 seconds apart):
<playerid> artist ?
If the current playing stream is a remote stream (internet radio) then squeezecenter will fail on the artist ? command and log an error in server.log.
The CLI api does not state this command is only allowed when non remote streams are playing, so I consider this to be a bug in SC. In this case the artist ? query should probably fail silently.

Triode
2008-10-01, 12:27
Please could you raise a bug on http://bugs.slimdevices.com/ so we can track this.

mkanet
2008-10-01, 12:49
Hi, Triode, bug has been filed and you have been CC'ed. I hesitated on creating a bug initially, because my experience has been bug reports (by me anyway) get generally ignored or pushed off so far, its not even worth spending the time to report the bug.

mkanet
2008-10-01, 15:13
Holy cow, now I feel bad. After only a couple of hours within posting the bug, the problem was fixed and available for the next nightly build :)

"Fixed in svn 23373 - please test the next nightly"

mkanet
2009-02-27, 17:55
Ohhh Triode.... Please check your PM :) I think what I asked you to do wasnt a good idea.. I just realized it broke something else!

EDIT: I reopened the original bug #9622. I'm not sure if that was the right way to do it or submit a new bug.