Rich:  What version of SC are you running? also, what version of firmware is on your controller.

Can you try to get a log file for us of this error?  Get an SD card, format it as FAT or FAT32, then create a folder on it called "LOG".  Put this SD card into the slot of your Controller, then try to reproduce the crash again.

Once it has happened, copy the log file from the SD card into this bug.

I'm running the released version of 7.2.  The FW on the controller is whatever version came with 7.2.

I actually don't own an SD card at this point.  I will get a hold of one and perform the steps you've outlined to collect the log file.  It will be handy to have just in case I have to do an update from it one day.  

I will try to have this early next week.

 

FYI, I have an SD card on order that I should have in a week.  I'm assuming 1GB is enough.  The procedure looks pretty straight forward.  I've logged into my controller via ssh to the command prompt, so that's not a problem.

A few questions:
- The directory name is case sensitive?  It must be "LOG"?
- Are actual log files put here or will it be a .core file from a crash?

Another tidbit of info - while I was logged into the controller and had "top" running, the crash would not occur.  Once I logged out, it would happen again.  A timing issue?  Memeory corruption?

Thanks!

 

this is an interesting bug...

i wonder tho, why slim doesn't just have you upload a few mp3s so they can reproduce?

also, did you remove the assumed offending tags on an CD that crashed the SBC, and see if it still crashed it with them removed?  that would essentially prove the issue culprit imo.

it highlights another issue imo...  

the SBC, as well as SC, SB, and everything else should be able to report these logs/errors via the internet.  if users want to opt out, fine, but all the errors these things run into should be reported to slim so they can see in aggregate whats going on in practice.

i constantly have issues with SN dropping out when winamp doesn't.  an automatic log that repors this to slim would be great.  not to mention the SBC losing connectivity issue.

Rich: please upload and example file with the tags that cause the crash.  I can test it here as well.

The log directory on the SD card is not case sensitive, only word sensitive.  it must be "log"  TXT files will be generated there.

On the controller, go to Settings > Advanced > Logging >  from here, you can turn various logs on and off.  I would suggest you turn the following to DEBUG:

slimserver
slimeserver.cache
net.comment

BTW: the "logging" feature will only show up once you have the SD card with a log folder inserted.

Created attachment 4035 [details]
Log file from problem scenario

Attached is the log file from when I run the scenario.  I have set the log settings as suggested earlier.

One thing I noticed was that when the controller reboots, the contents of the log directory are cleared and logging is started fresh.  I tried copying the messages file to another file while it was hung, but when it came back up, it was gone.

So, what I did was take the battery cover off and ran the scenario.  Just as it started rebooting, I popped the batter out.  The resulting log file is attached.

An interesting datapoint is that when the GUI on the controller is hung, I still have a functioning command prompt when logged in remotely and I can see the size of the log file grow until it reboots.

Let me know if you need anything else.  To my eyes, it looks like this log file doesn't contain what you need.

Thanks!
Rich

Created attachment 4036 [details]
Suspected problematic mp3 file

This is the mp3 file with the composer tag added that I believe is causing the problem.

I'm reluctant to remove the tag at this point because I don't want to find myself where I can't recreate the problem again.  Though if you feel it is worth while at this point to take that risk, let me know.

I'm not too concerned about resolving my problem - I'm pretty sure I can get around it.  I just want you guys to be able to get something useful out of this since it looks like a nasty bug lurking.

One more datapoint that I think is relevant:

Via the web interface, the track that I uploaded does NOT show up under Johannes Schmoelling's albums, yet it does via the controller.

I should also mention that I'm using the MusicIP integration via the headless server on Linux.

Thanks for the log and file.  I am unable to reproduce this error with the provided file, or ones I created myself.

May I suggest you disable all the 3rd party plugins you have enabled, then test again.

Let me know what you find out.

More information...

Today I've identified 2 other artists in my library that if I browse using the controller the controller UI will hang and eventually restart itself.  These are both artists that I have not added anything new for months.  No composer tags are involved.

So, I think the composer tag piece was a red herring.  I latched onto that because the behavior I was seeing was new and the composer tag was something recently added.  

This is actually really worrisome to me since I now don't know how I could get around it.

Another data point that may be relevant - I have noticed at times when making MusicIP mixes that the title of the song shown in the playlist was incorrect.  The album and artist was correct, but the song title was wrong.  No, the artist of the track is not one of the problematic ones.

I'll try disabling the MusicIP plugin first and see how it goes.  It will be a bummer to have to live without it since I've come to use it rather heavily.  My wife is using it now too!

Are the log files useful?  Let me know any logs you need and I'll capture them.  Now that I have an SD card I can turn these around quickly.  Also, this problem is very easily recreated for me, so it's easy to capture logs.

Thanks!

In SC, go to settings > Advanced > Logging.  Turn the following to DEBUG:

(player.jive) - JIVE
*musicIP

restart SC
go to Settings > Status: locate the LOG folder location, open the log
Recreate the error, and watch the log
Paste any errors you notice here

THEN

Turn off MusicIP and try it again, tell me if this changes the behavior.

I turned off MusicIP earlier today and replicated the problem.  To ensure everything was correct, I did a "clear and rescan" operation after turning MusicIP off and stopping/restarting SqueezeCenter.  MusicIP does not show up in the menus, so I am sure it is turned off.

So, I would say it doesn't look like a MusicIP issue.

I'll collect the logs as you requested and post any errors here.

This is turning into a strange problem.

Just to be clear - disabling MusicIP did not change the behavior.

I enabled the logging as requested and I'm not seeing any entries in the log file.  This is without MusicIP enabled since I see the problem there.  It is one less factor to worry about.

I should note that when I enabled the logging and restarted SC, it would go back to ERROR.  This is even with checking the checkbox at the top of the webpage.  Without restarting SC, the setting seemed to hold.

What's next?

Another data point:  Thinking perhaps artwork was a factor, I removed the artwork for the artists where I'm seeing trouble.  In one case, I removed artwork for one album and another I removed it from all of them.  In both cases, the hang occurs as it always has.

Without MusicIP enabled, I can browse music via Music Folder.  Browsing this way there is no hang.

Let me now what you'd like me to try next.

Thanks!
Rich

Ben, Richard, any suggestions here?  I think we have narrowed the issue down to MusicIP.

Rich: can you try a Factory Reset on your Controller, lets see if that clears the error up.

Actually, if you look at comment #13, disabling MusicIP did not change the behavior.

I performed the factory reset and there is no change in behavior.  


On a separate note...
The setup for the controller seems to have been improved.  I had to go through
it twice, but I may have made a mistake typing in the SC password.  At least
this time it asked me for it!  The second time worked like a charm.  A much
better experience than the 1st time I configured the controller.

Regarding the problem at hand, let me know what steps you'd like me to perform
next.

Anything new with this?  There was a flurry of activity and now it seems to have died.

Do you have what you need from me to fix this?

Thanks!

fwiw: I think it's not related to one particular file. I see this exact behaviour right now with _any_ artist. I'll try to investigate tomorrow. It's diner time.

Oh, and this is SC 7.3/r23174, firmware 2874

Created attachment 4060 [details]
Log from around the reboots

Ben/Richard - what logging option should I turn on on the Controller? I can't see anything specific to browsing when it crashes. It always ends with the following lines:

Sep 25 20:43:47 SqueezeboxController user.info jive: (NetworkThread.lua:249) - NOTIFY: playerModeChange(Player {Mister T}, play)
Sep 25 20:43:47 SqueezeboxController user.info jive: (NetworkThread.lua:249) - NOTIFY: playerTrackChange(Player {Mister T}, 7729)
Sep 25 20:43:47 SqueezeboxController user.info jive: (NowPlayingApplet.lua:173) - Notification received that track has changed
Sep 25 20:43:47 SqueezeboxController user.info jive: (NetworkThread.lua:249) - NOTIFY: playerPlaylistChange(Player {Mister T})
Sep 25 20:43:47 SqueezeboxController user.info jive: (NetworkThread.lua:249) - NOTIFY: cometDisconnected(Comet {edelzwerg})
Sep 25 20:43:47 SqueezeboxController user.info jive: (NetworkThread.lua:249) - NOTIFY: serverDisconnected(SlimServer {edelzwerg}, 1)
Sep 25 20:43:47 SqueezeboxController user.info jive: (SlimDiscoveryApplet.lua:422) - serverDisconnected SlimServer {edelzwerg}
Sep 25 20:43:47 SqueezeboxController user.info jive: (Wireless.lua:561) - iwconfig power on
Sep 25 20:43:47 SqueezeboxController user.info jive: (NetworkThread.lua:249) - NOTIFY: cometConnected(Comet {edelzwerg})
Sep 25 20:43:47 SqueezeboxController user.info jive: (SlimServer.lua:518) - SlimServer {edelzwerg} connected
Sep 25 20:43:47 SqueezeboxController user.info jive: (NetworkThread.lua:249) - NOTIFY: serverConnected(SlimServer {edelzwerg})
Sep 25 20:43:47 SqueezeboxController user.info jive: (SlimDiscoveryApplet.lua:436) - serverConnected
Sep 25 20:43:47 SqueezeboxController user.info jive: (SlimServer.lua:494) - SlimServer {SqueezeNetwork}:disconnect
Sep 25 20:43:47 SqueezeboxController user.info jive: (NetworkThread.lua:249) - NOTIFY: cometDisconnected(Comet {SqueezeNetwork})
Sep 25 20:43:47 SqueezeboxController user.info jive: (NetworkThread.lua:249) - NOTIFY: serverDisconnected(SlimServer {SqueezeNetwork}, 0)
Sep 25 20:43:47 SqueezeboxController user.info jive: (SlimDiscoveryApplet.lua:422) - serverDisconnected SlimServer {SqueezeNetwork}
Sep 25 20:43:48 SqueezeboxController user.info jive: (SlimBrowserApplet.lua:982) - _menuSink()
Sep 25 20:43:48 SqueezeboxController user.info jive: (SlimBrowserApplet.lua:502) - _connectingToPlayer popup hide
Sep 25 20:43:48 SqueezeboxController user.info jive: (SqueezeboxJiveApplet.lua:316) - CCYY=2008 MM=09 DD=25 hh=20 mm=43 ss=49 TZ=+02:00

if you set player.browse.data to debug you'll get dumps of the JSON data from SC

this is looking a lot like Bug 9554...

Indeed. 9554 was the bug I was looking for when I found this one. And I think there's been more of this. I remember one report mentioning the reboot during the animation (which is the case for me too).

*** This bug has been marked as a duplicate of bug 9554 ***