Re: [SlimDevices: SqueezeCenter] Logitech Media Server unresponsive, debug help please
As I am having the same problems with LMS' unsresposiveness I've tried a lot of different things in the past. I have a quite special Setup at home with MS Active Directory and therfore own DNS-Servers which makes it quite hard to debug for me as there are many more possible sources of error compared to a simple PC-Setup. I think I nailed *my* problem down to DNS-issues - whenever one of mysb.com-Server goes down for maintenance or so and my LMS is deferred to another mysb.com-Server through DNS-round robin my LSM quits this with this log entry: Code: Slim::Networking::SqueezeNetwork::Players::_players_error (368) Unable to get players from SN: Connect timed out: Bad file descriptor, retrying in 900 seconds After this log-entry my LMS does not respond anymore and seizes to work again until I restart my LMS. At the moment I configured my DNS-Server to only resolve one iP-Adress for www.mysqueezebox.com (i chose 79.125.111.32) and since I did that four days ago I had no anomalies in LSM yet. In a normal PC-Setup the same can be done by enterin this ip to the local hosts-file. Best regards, Florian ElwoodSC's Profile: http://forums.slimdevices.com/member.php?userid=30764 View this thread: http://forums.slimdevices.com/showthread.php?t=107537 ___ Squeezecenter mailing list Squeezecenter@lists.slimdevices.com http://lists.slimdevices.com/mailman/listinfo/squeezecenter
Re: [SlimDevices: SqueezeCenter] Logitech Media Server unresponsive, debug help please
That sounds very much very much like the issue that is bugging me for at least 6 months now - my log Looks quite similar, apart from the file open issue. http://forums.slimdevices.com/showthread.php?107368-LMS-auf-Windows-Server-bleibt-stehen (sorry, in german and no solution yet) I'm quite sure it's about connectivity to mysb.com - in your case because of the VPN, in my case (probably) due to DNS-issues. Can LMS be made more robust when there are Problems connecting to mysb.com? I my case it all started with a LMS 7.9.x nightly I installed mid 2016 IIRC. Best regards, Flo ElwoodSC's Profile: http://forums.slimdevices.com/member.php?userid=30764 View this thread: http://forums.slimdevices.com/showthread.php?t=107537 ___ Squeezecenter mailing list Squeezecenter@lists.slimdevices.com http://lists.slimdevices.com/mailman/listinfo/squeezecenter
Re: [SlimDevices: SqueezeCenter] LMS 7.9 Nightly stops working after some time
I might be up to something I found when I set network.http to "Information": Code: [17-02-23 14:21:07.5653] Slim::Web::HTTP::processHTTP (348) HTTP request: from 10.1.1.3:55210 (Slim::Web::HTTP::ClientConn=GLOB(0x9152ec4)) for POST HTTP/1.1 /cometd [17-02-23 14:21:07.5662] Slim::Web::HTTP::sendResponse (1976) Sent 471 to 10.1.1.3:55210 [17-02-23 14:21:07.5663] Slim::Web::HTTP::sendResponse (1982) No more segments to send to 10.1.1.3:55210 [17-02-23 14:21:07.5665] Slim::Web::HTTP::sendResponse (1938) No segment to send to 10.1.1.3:55210, waiting for next request... [17-02-23 14:21:07.6226] Slim::Web::HTTP::acceptHTTP (265) Accepted connection 7 from 10.1.1.3:55211 [17-02-23 14:21:07.8661] Slim::Web::HTTP::processHTTP (348) HTTP request: from 10.1.1.3:55211 (Slim::Web::HTTP::ClientConn=GLOB(0x933cd04)) for POST HTTP/1.1 /cometd [17-02-23 14:21:07.8671] Slim::Web::HTTP::sendResponse (1976) Sent 404 to 10.1.1.3:55211 [17-02-23 14:21:07.8673] Slim::Web::HTTP::sendResponse (1982) No more segments to send to 10.1.1.3:55211 [17-02-23 14:21:07.8675] Slim::Web::HTTP::sendResponse (1938) No segment to send to 10.1.1.3:55211, waiting for next request... [17-02-23 14:21:07.9062] Slim::Web::HTTP::processHTTP (339) Client at 10.1.1.3:55210 disconnected. (Client closed) [17-02-23 14:21:07.9064] Slim::Web::HTTP::closeHTTPSocket (2393) Closing HTTP socket Slim::Web::HTTP::ClientConn=GLOB(0x9152ec4) with 10.1.1.3:55210 (Client closed) [17-02-23 14:21:07.9122] Slim::Web::HTTP::processHTTP (339) Client at 10.1.1.3:55211 disconnected. (Client closed) [17-02-23 14:21:07.9124] Slim::Web::HTTP::closeHTTPSocket (2393) Closing HTTP socket Slim::Web::HTTP::ClientConn=GLOB(0x933cd04) with 10.1.1.3:55211 (Client closed) [17-02-23 14:21:08.0559] Slim::Web::HTTP::acceptHTTP (265) Accepted connection 6 from 10.1.1.3:55212 [17-02-23 14:21:08.0738] Slim::Web::HTTP::processHTTP (348) HTTP request: from 10.1.1.3:55212 (Slim::Web::HTTP::ClientConn=GLOB(0x932d154)) for POST HTTP/1.1 /cometd [17-02-23 14:21:08.0746] Slim::Web::HTTP::sendResponse (1976) Sent 420 to 10.1.1.3:55212 [17-02-23 14:21:08.0748] Slim::Web::HTTP::sendResponse (1982) No more segments to send to 10.1.1.3:55212 [17-02-23 14:21:08.0750] Slim::Web::HTTP::sendResponse (1938) No segment to send to 10.1.1.3:55212, waiting for next request... [17-02-23 14:21:08.1382] Slim::Web::HTTP::processHTTP (348) HTTP request: from 10.1.1.3:55212 (Slim::Web::HTTP::ClientConn=GLOB(0x932d154)) for POST HTTP/1.1 /cometd [17-02-23 14:21:08.1392] Slim::Web::HTTP::sendResponse (1976) Sent 471 to 10.1.1.3:55212 [17-02-23 14:21:08.1393] Slim::Web::HTTP::sendResponse (1982) No more segments to send to 10.1.1.3:55212 [17-02-23 14:21:08.1398] Slim::Web::HTTP::processHTTP (348) HTTP request: from 10.1.1.13:56226 (Slim::Web::HTTP::ClientConn=GLOB(0x9165bbc)) for POST HTTP/1.1 /jsonrpc.js [17-02-23 14:21:08.1414] Slim::Web::HTTP::sendResponse (1938) No segment to send to 10.1.1.3:55212, waiting for next request... [17-02-23 14:21:08.1416] Slim::Web::HTTP::sendResponse (1976) Sent 939 to 10.1.1.13:56226 [17-02-23 14:21:08.1418] Slim::Web::HTTP::sendResponse (1982) No more segments to send to 10.1.1.13:56226 [17-02-23 14:21:08.1421] Slim::Web::HTTP::sendResponse (1938) No segment to send to 10.1.1.13:56226, waiting for next request... [17-02-23 14:21:08.2069] Slim::Web::HTTP::acceptHTTP (265) Accepted connection 7 from 10.1.1.3:55213 [17-02-23 14:21:08.4376] Slim::Web::HTTP::processHTTP (348) HTTP request: from 10.1.1.3:55213 (Slim::Web::HTTP::ClientConn=GLOB(0x953c4cc)) for POST HTTP/1.1 /cometd [17-02-23 14:21:08.4387] Slim::Web::HTTP::sendResponse (1976) Sent 405 to 10.1.1.3:55213 [17-02-23 14:21:08.4388] Slim::Web::HTTP::sendResponse (1982) No more segments to send to 10.1.1.3:55213 [17-02-23 14:21:08.4390] Slim::Web::HTTP::sendResponse (1938) No segment to send to 10.1.1.3:55213, waiting for next request... [17-02-23 14:21:08.4853] Slim::Web::HTTP::processHTTP (339) Client at 10.1.1.3:55212 disconnected. (Client closed) [17-02-23 14:21:08.4854] Slim::Web::HTTP::closeHTTPSocket (2393) Closing HTTP socket Slim::Web::HTTP::ClientConn=GLOB(0x932d154) with 10.1.1.3:55212 (Client closed) [17-02-23 14:21:08.4911] Slim::Web::HTTP::processHTTP (339) Client at 10.1.1.3:55213 disconnected. (Client closed) [17-02-23 14:21:08.4913] Slim::Web::HTTP::closeHTTPSocket (2393) Closing HTTP socket Slim::Web::HTTP::ClientConn=GLOB(0x953c4cc) with 10.1.1.3:55213 (Client closed) [17-02-23 14:21:08.6173] Slim::Web::HTTP::acceptHTTP (265) Accepted connection 6 from 10.1.1.3:55214 [17-02-23 14:21:08.6392] Slim::Web::HTTP::processHTTP (348) HTTP request: from 10.1.1.3:55214 (Slim::Web::HTTP::ClientConn=GLOB(0x932c0cc)) for POST HTTP/1.1 /cometd [17-02-23 14:21:08.6401] Slim::Web::HTTP::sendResponse (1976) Sent 420 to 10.1.1.3:55214 [17-02-23 14:21:08.6402]
Re: [SlimDevices: SqueezeCenter] LMS 7.9 Nightly stops working after some time
mherger wrote:
> > Is there any other way to interact with the server? Can I get status
> > Infos of the Server trough CLI? If so, how? :)
>
> telnet yourserver 9090
>
> (replace "yourserver" with its IP address if you can't ping it by name).
>
> If that connects, then LMS is still kind of alive. Then type eg.
> "serverstatus" followed by the enter key. Would that respond?
>
> --
>
> Michael
Today morning it happened again, logfile now Shows this:
Code:
[17-02-23 06:31:01.1772] Slim::Plugin::MusicMagic::Plugin::_musicipError
(528) MusicIP: http error, no response.
[17-02-23 06:44:48.0061] Slim::Web::JSONRPC::handleURI (109) POST data:
[{"id":52,"method":"slim.request","params":["",["serverstatus",0,255]]}]
[17-02-23 06:44:48.0065] Slim::Web::JSONRPC::requestMethod (406)
Dispatching...
[17-02-23 06:47:01.1901] Slim::Plugin::MusicMagic::Plugin::_musicipError
(528) MusicIP: http error, no response.
[17-02-23 06:49:01.1913] Slim::Plugin::MusicMagic::Plugin::_musicipError
(528) MusicIP: http error, no response.
[17-02-23 06:51:01.1924] Slim::Plugin::MusicMagic::Plugin::_musicipError
(528) MusicIP: http error, no response.
[17-02-23 06:53:01.1935] Slim::Plugin::MusicMagic::Plugin::_musicipError
(528) MusicIP: http error, no response.
[17-02-23 06:55:01.1956] Slim::Plugin::MusicMagic::Plugin::_musicipError
(528) MusicIP: http error, no response.
[17-02-23 06:57:01.1966] Slim::Plugin::MusicMagic::Plugin::_musicipError
(528) MusicIP: http error, no response.
[17-02-23 06:59:01.1979] Slim::Plugin::MusicMagic::Plugin::_musicipError
(528) MusicIP: http error, no response.
[17-02-23 07:01:01.1987] Slim::Plugin::MusicMagic::Plugin::_musicipError
(528) MusicIP: http error, no response.
[17-02-23 07:03:01.2008] Slim::Plugin::MusicMagic::Plugin::_musicipError
(528) MusicIP: http error, no response.
[17-02-23 07:05:01.2020] Slim::Plugin::MusicMagic::Plugin::_musicipError
(528) MusicIP: http error, no response.
[17-02-23 07:07:01.2029] Slim::Plugin::MusicMagic::Plugin::_musicipError
(528) MusicIP: http error, no response.
[17-02-23 07:09:01.2042] Slim::Plugin::MusicMagic::Plugin::_musicipError
(528) MusicIP: http error, no response.
[17-02-23 07:11:01.2152] Slim::Plugin::MusicMagic::Plugin::_musicipError
(528) MusicIP: http error, no response.
[17-02-23 07:13:01.2080] Slim::Plugin::MusicMagic::Plugin::_musicipError
(528) MusicIP: http error, no response.
[17-02-23 07:15:01.2093] Slim::Plugin::MusicMagic::Plugin::_musicipError
(528) MusicIP: http error, no response.
MusicIP is running on the same machine on port 10002 an is operational
at the Moment. The issue occured in the past as well when MusicIP was
disabled.
LMS CLI works, "serverstatus" Returns:
Code:
serverstatus
serverstatus lastscan%3A1487815536 version%3A7.9.0
uuid%3Aca6cd6bb-408c-4a46-bc26-bafefe607ec5 mac%3A68%3A05%3Aca%3A21%3A6e%3A46
info%20total%20albums%3A2799 info%20total%20artists%3A5712
info%20total%20genres%3A119 info%20total%20songs%3A36754
info%20total%20duration%3A10382957.02 player%20count%3A5
other%20player%20count%3A0
^[[A
%1B%5BA
LMS is obviosly not totally dead, currently my Radio stream started at
~6:25 still runs but WebUI, other Players and iPeng does not work.
ElwoodSC's Profile: http://forums.slimdevices.com/member.php?userid=30764
View this thread: http://forums.slimdevices.com/showthread.php?t=106940
___
Squeezecenter mailing list
Squeezecenter@lists.slimdevices.com
http://lists.slimdevices.com/mailman/listinfo/squeezecenter
Re: [SlimDevices: SqueezeCenter] LMS 7.9 Nightly stops working after some time
Mnyb wrote: > Sorry for being late with obvius Q . > > "Web-UI does not respond" is this on the same machine that runs the > server ? > If not is LMS really dead can it be interacted with on the machine that > actually runs LMS No, LMS is really dead or at least unresponsive. No matter whether I try the WebUI from a remote machine or on the LMS-Server itself. All squeezeboxes get a connection error - only prevouisly started radio-streams keep on running. Is there any other way to interact with the server? Can I get status Infos of the Server trough CLI? If so, how? :) ElwoodSC's Profile: http://forums.slimdevices.com/member.php?userid=30764 View this thread: http://forums.slimdevices.com/showthread.php?t=106940 ___ Squeezecenter mailing list Squeezecenter@lists.slimdevices.com http://lists.slimdevices.com/mailman/listinfo/squeezecenter
Re: [SlimDevices: SqueezeCenter] LMS 7.9 Nightly stops working after some time
mherger wrote: > > Still having the same issue, last time it took about three days until > > the issue reappeared. And again, I had the "request not > > dispatchable"-Errors in my log. > > These messages usually mean that a player has lost connection to the > server, but some client (web UI, mobile app, whatever) was still > requesting information for that player. Sounds like a network issue > between your player and your server. > > "Can't connect to remote server - timed out waiting for data" either > that server is dead (which I can't imagine for TuneIn), or there's a > network problem. > > I know, despite all the signs: there's not network problem. Really? > > -- > > Michael As all signs suggest network problems I wrote a poweshell-script that pings all my squeezeboxes from the machine running LMS and logging all lost packets with a timestamp. As all my squeezeboxes are on wifi there will probably some lost packages, I hope to see what log entries corelate to those lost packets. Apart from that, even if a sequeezebox loses connection to the server for a couple of miliseconds - why is the server dying on that disconnection? Michael, could you instruct me on what exactly to log in LMS to nail down that issue? If I set everything to debug I'll get a huuuge logfile as it takes 1-2 days for the issue to reappear. ElwoodSC's Profile: http://forums.slimdevices.com/member.php?userid=30764 View this thread: http://forums.slimdevices.com/showthread.php?t=106940 ___ Squeezecenter mailing list Squeezecenter@lists.slimdevices.com http://lists.slimdevices.com/mailman/listinfo/squeezecenter
Re: [SlimDevices: SqueezeCenter] LMS 7.9 Nightly stops working after some time
Still having the same issue, last time it took about three days until the issue reappeared. And again, I had the "request not dispatchable"-Errors in my log. If I find no solution the only thing that can do is to restart LMS every night by script - but I'd like to pinpoint the root cause and not just cure the symptoms. Any more ideas from you guys? Any goot ideas on what to log on top of the default logging settings? ElwoodSC's Profile: http://forums.slimdevices.com/member.php?userid=30764 View this thread: http://forums.slimdevices.com/showthread.php?t=106940 ___ Squeezecenter mailing list Squeezecenter@lists.slimdevices.com http://lists.slimdevices.com/mailman/listinfo/squeezecenter
Re: [SlimDevices: SqueezeCenter] LMS 7.9 Nightly stops working after some time
Still have my original Problem - here's the log from today, 18:45 when the Problem appeared: Code: [17-02-13 18:34:09.1034] Slim::Web::JSONRPC::requestMethod (443) 00:04:20:2d:30:65: request not dispatchable! [17-02-13 18:34:09.1807] Slim::Web::JSONRPC::requestMethod (443) 00:04:20:2d:30:65: request not dispatchable! [17-02-13 18:34:09.1815] Slim::Web::JSONRPC::requestMethod (443) 00:04:20:2d:30:65: request not dispatchable! [17-02-13 20:01:52.0224] Slim::Utils::Scanner::Remote::__ANON__ (193) Error: Can't connect to remote server to retrieve playlist for, http://opml.radiotime.com/Tune.ashx?id=s17494=aac,ogg,mp3,wmpro,wma,wmvoice=16=3b1ce301c1e0772f52bb3b9b59573b28: Timed out waiting for data. [17-02-13 20:01:52.0236] Slim::Utils::Scanner::Remote::__ANON__ (193) Error: Can't connect to remote server to retrieve playlist for, http://opml.radiotime.com/Tune.ashx?id=s17494=aac,ogg,mp3,wmpro,wma,wmvoice=16=3b1ce301c1e0772f52bb3b9b59573b28: Timed out waiting for data. [17-02-13 20:01:52.0240] Slim::Utils::Scanner::Remote::__ANON__ (193) Error: Can't connect to remote server to retrieve playlist for, http://opml.radiotime.com/Tune.ashx?id=s17494=aac,ogg,mp3,wmpro,wma,wmvoice=16=3b1ce301c1e0772f52bb3b9b59573b28: Timed out waiting for data. [17-02-13 20:01:52.0243] Slim::Utils::Scanner::Remote::__ANON__ (193) Error: Can't connect to remote server to retrieve playlist for, http://opml.radiotime.com/Tune.ashx?id=s17494=aac,ogg,mp3,wmpro,wma,wmvoice=16=3b1ce301c1e0772f52bb3b9b59573b28: Timed out waiting for data. [17-02-13 20:01:52.0247] Slim::Utils::Scanner::Remote::__ANON__ (193) Error: Can't connect to remote server to retrieve playlist for, http://opml.radiotime.com/Tune.ashx?id=s17494=aac,ogg,mp3,wmpro,wma,wmvoice=16=3b1ce301c1e0772f52bb3b9b59573b28: Timed out waiting for data. As before, there was no Network outage - and even if there was one the Server should not stop working, right? ElwoodSC's Profile: http://forums.slimdevices.com/member.php?userid=30764 View this thread: http://forums.slimdevices.com/showthread.php?t=106940 ___ Squeezecenter mailing list Squeezecenter@lists.slimdevices.com http://lists.slimdevices.com/mailman/listinfo/squeezecenter
Re: [SlimDevices: SqueezeCenter] LMS 7.9 Nightly stops working after some time
DJanGo wrote: > did you read the posted server.log? > > > Code: > > 17-02-05 13:15:13.2696] Slim::Networking::UDP::init (39) FATAL:* There is already another copy of the Logitech Media Server running on this machine.* (Only one usage of each socket address (protocol/network address/port) is normally permitted.) > > > seems easy. > That was directly after installation when the interactive LMS-instance > was running and I tried to start the Service. Now there is of course > only one running instance of LMS > > is that true? > > My MS.COM credentials are now entered (correctly ;)) - that log entry > was also from setup Phase. > > > Code: > > Error: missing string > > > seems you run some oldish plugins. > > True - I first did not change the Default Installation and there were > all plugins activated that are part of a default Installation. Changed > that as well by now. > The most relevant log entries are those - at least they were at the time my son recognised that the server was not responding anymore: Code: [17-02-06 19:33:21.5120] Slim::Utils::Scanner::Remote::__ANON__ (193) Error: Can't connect to remote server to retrieve playlist for, http://opml.radiotime.com/Tune.ashx?id=s17494=aac,ogg,mp3,wmpro,wma,wmvoice=16=834c60bb10e447c53a5ace93dc0658b3: Timed out waiting for data. [17-02-06 19:35:30.0796] Slim::Networking::SqueezeNetwork::Players::_players_error (368) Unable to get players from SN: Timed out waiting for data, retrying in 900 seconds [17-02-06 19:40:21.0651] Slim::Networking::SqueezeNetwork::Players::_players_error (368) Unable to get players from SN: Timed out waiting for data, retrying in 900 seconds [17-02-06 19:41:23.0004] Slim::Networking::SqueezeNetwork::Players::_players_error (368) Unable to get players from SN: Unerwarteter Fehler beim Prüfen Ihres mysqueezebox.com-Kontos. Überprüfen Sie, ob die Netzwerkverbindung ordnungsgemäß funktioniert., retrying in 1800 seconds [17-02-06 19:42:31.3912] main::init (388) Starting Logitech Media Server (v7.9.0, 1485931015, Wed Feb 1 06:44:25 CUT 2017) perl 5.014001 - MSWin32-x86-multi-thread best regards, Florian ElwoodSC's Profile: http://forums.slimdevices.com/member.php?userid=30764 View this thread: http://forums.slimdevices.com/showthread.php?t=106940 ___ Squeezecenter mailing list Squeezecenter@lists.slimdevices.com http://lists.slimdevices.com/mailman/listinfo/squeezecenter
Re: [SlimDevices: SqueezeCenter] LMS 7.9 Nightly stops working after some time
I just unplugged the network cable for a short time to simulate a network glitch - but that didn't stop the Server from working... I know that unplugging a cable is different from packetloss trough a faulty cable - but I'm quite sure that I don't have a network Problem with my Server. There a many Services running on my Server (Hyper-V Host with ~10 running VMs) that do not Show any anomalies. I now have disabled nearly all the Default plugins to a Minimum set of needed plugins and will continue to watch what happens. I'm still searching for: - hints on which logging Topics I should set to debug to get more relevant Information - Nightly 7.9 builds from Mid 2016 (or, of course if available, any other 7.9 build from that time) Regards, Florian ElwoodSC's Profile: http://forums.slimdevices.com/member.php?userid=30764 View this thread: http://forums.slimdevices.com/showthread.php?t=106940 ___ Squeezecenter mailing list Squeezecenter@lists.slimdevices.com http://lists.slimdevices.com/mailman/listinfo/squeezecenter
Re: [SlimDevices: SqueezeCenter] LMS 7.9 Nightly stops working after some time
bpa wrote: > Network outage could mean just no network connection from LMS server to > players etc. For example, my LMS server uses a Homeplug connection and > this drops out every so often ( a known but unresolved Homeplug issue) > and there are similar "Unable to get players" messages logged when that > happens. > > That said, there are al ot of missing string message for DEEZER, SPOTIFY > etc which I would not have expected. It make em think there is something > odd in your installation. By homeplug you mean Powerline-Adapters? If so that would not be applicable as my Server is connected trough Ethernet to my internet-router, a FritzBox 7490. I've seen the missing string messages as well an could not make any sense from them. LMS is freshly installed and configured with the LMS nightly from Feb. 1st - I'm of the Impression that there is something broken in the current nightlies. The error occured about 5 months ago - at that time I already was on nightlies. Does anyone have nightly 7.9 build from around mid 2016? cheers, Flo ElwoodSC's Profile: http://forums.slimdevices.com/member.php?userid=30764 View this thread: http://forums.slimdevices.com/showthread.php?t=106940 ___ Squeezecenter mailing list Squeezecenter@lists.slimdevices.com http://lists.slimdevices.com/mailman/listinfo/squeezecenter
Re: [SlimDevices: SqueezeCenter] LMS 7.9 Nightly stops working after some time
No, there was no Network outage at that time - I think, I even watched Amazon Prime at that time so Internet was available as well. And even if there was a network problem LMS should not stop working, right? I'm a little clueless on which logging areas I should enable to pinpoint my issue - any tips for that? The plugins are not yet sorted out, as I reinstalled two days ago they are still on default. ElwoodSC's Profile: http://forums.slimdevices.com/member.php?userid=30764 View this thread: http://forums.slimdevices.com/showthread.php?t=106940 ___ Squeezecenter mailing list Squeezecenter@lists.slimdevices.com http://lists.slimdevices.com/mailman/listinfo/squeezecenter
