ITunes blues on reboot

Every time I reboot my server, it comes back up with "Enable Indigo communication" unchecked for my iTunes server device. I've turned off the new "dirt nap" feature with iTunes and Indigo. Any ideas?
Phil

[jay (support)]

I have a feeling this problem and the other one you just posted are related since they both seem to be caused by an inability to write to the file system. You should rerun the Indigo installer since it will attempt to correct any permission issues with your install.

If that doesn't work then try running Disk Utility and perform a repair permissions.

Jay,
Thanks. Did both of those things with no joy. Still have both problems.
Phil

[jay (support)]

Find your database file (in the client running on the same Mac as the server you can command click on the database name in the title bar and select the folder just under it - that will open the folder in the Finder) and look at the date modified on the file. If Indigo is currently running it should show something within the last 30 minutes at the very least.

Also, open the Console app, make sure that All Messages is selected in the left-hand outline view, then type Indigo in the search filter box in the upper right corner. If it finds anything, copy/paste those lines into a reply post (or if there's too much you can email it to indigo DASH support AT perceptiveautomation DOT com, just include a link to this post so we'll know what it's about).

Jay,
Here's the part I think you're looking for, from this morning's restart:

10/31/13 6:32:11.107 PM IndigoServer[333]: NOAA Weather Plus Error Unknown error getting weather for coordinates 38.633, -76.55: <urlopen error timed out>
10/31/13 7:00:00.577 PM IndigoServer[333]: Airfoil Error Speaker Master Bedroom is not available to disconnect from
10/31/13 7:18:58.866 PM Indigo 6[8498]: unable to modify user startup items preference
10/31/13 7:19:06.464 PM Indigo 6[8498]: HandlerError -- all command handlers are disabled
10/31/13 7:19:06.464 PM Indigo 6[8498]: HandlerError -- all command handlers are disabled
10/31/13 7:20:42.613 PM IndigoServer[333]: Quiting Indigo Server - received slow quit signal
10/31/13 7:20:42.613 PM IndigoServer[333]: Quiting Indigo Server - stopping plugins

The database file showed (I checked it just a few minutes ago) that it had been modified less than five minutes prior...so it's getting updates.

Thanks,
Phil

[jay (support)]

Hmmm. Reboot your Mac and then start up the server and client. Then select Help->Email Log… - leave the first two fields with the default data but add your forum username to the end of the subject and send it off. You'll need to have email sending settings configured in the Indigo Preferences.

Oh, and check to see if the iTunes device is disabled again.

One more thing: once you've done the above, go back to the Console app and find all the Indigo entries and email those as well.

Jay,
Thanks for all the support via forum and email. I used to run Mountain Lion Server on that Mac Mini, but found it was 1) more than I needed and 2) too much work. So I downgraded to Mountain Lion (a year ago) then upgraded to Mavericks on release day. I've seen a couple of things lately that make me think the Server software configuration stuff was hanging around and I think that might have fouled up my Mavericks upgrade. Bottom line: Will have to slick the whole hard drive and rebuild.
In the interim, I just created an action on Indigo Startup to Enable my iTunes device. Works just fine until I get around to lugging a keyboard, mouse and monitor down to the basement into my cramped server room for a weekend....
Best,
Phil

Jay,
Just caught this error in my log:

Trigger Indigo Startup
Trigger Enable iTunes
iTunes Debug deviceStartComm: starting thread for 'iTunes'
iTunes Debug getMediaServerList: called
Connected to PowerLinc 2413U interface on port usbserial-A600exe2
PowerLinc address 18.B6.A4, firmware version 9.2
iTunes Debug deviceStartComm: updating from old address prop
iTunes Debug deviceStartComm: adding device id 1173155478 to the active thread queue
iTunes Debug statusThread.run(): creating iTunes Controller...
iTunes Debug statusThread.run(): connecting and logging in at: 2013-11-03 06:21:56.363372
iTunes Debug statusThread.run(): unknown Error for iTunes
iTunes Error iTunes stopped due to the following error (will attempt to recover in 10 seconds):

Traceback (most recent call last):
File "statusThread.py", line 117, in run
File "itunes.py", line 57, in iTunesLogin
File "itunes.py", line 205, in updateCache
AttributeError: 'ITunesController' object has no attribute 'errorLog'


iTunes Debug deviceStopComm: stopping thread for iTunes
iTunes Debug statusThread.run(): closing controller for exit at 2013-11-03 06:22:06.469773
iTunes Error iTunes has an unknown error - disabling
iTunes Debug deviceStopComm: stopping thread for iTunes

This happened after a reboot of the server, and the error message was generated by my workaround trigger (enable iTunes device upon Indigo Startup).

BTW, I just went in manually and enabled the device and it worked just fine.

Does that help?
Phil

[jay (support)]

Not much unfortunately - that's the error that's causing the issue that I'd already told you about. It's also the error that, if the stack trace from python is correct, is not actually possible. If that error is correct then every iTunes device created on every Indigo instance would be failing. The fact that it's getting that error in that location upon boot but only sometimes getting it when your script tries to enable the plugin seems to imply something is very wrong with your install.

There is one other thing that looks very suspicious this time (that I didn't find in your previous logs):

Code: Select all

iTunes Debug deviceStartComm: updating from old address prop

That is an old section of code that was converting an old (possibly 5.0 beta) version of an iTunes device. It seems really unlikely that it should be firing at this point. You should delete all your iTunes devices and recreate them all since it seems one of them (maybe the only one) is not getting updated correctly.

Jay,
Hmmm....I only have one iTunes device and if I delete it, it will delete the entire iTunes trigger/schedule setup I have. While I'm prepared to do it, I'm wondering if there's a way to perhaps do it to preserve those triggers, etc. What if I rename the old one, create a new one, replace the device in the triggers, then delete the old one? That should preserve the triggers, but will it fix the problem?
Thanks,
Phil

EDIT: I tried the above - and it worked. Stopped Indigo and restarted it, and iTunes is working correctly now (no workaround). Dunno what in the world happened, but it seems like everything is normal.

[jay (support)]

Great - keep us posted if any more strangeness happens.

Jay,
You asked for it...

So I did a clean install of Mavericks yesterday (erased hard drive) and reinstalled everything from scratch. I copied over the Indigo database from Time Machine, although I did a fresh install of all plugins to the latest versions, etc. I also copied over the iTunes library file.
iTunes is still at it. Here's the log right after I reloaded the plugin (Indigo said plugin stopped):

Starting plugin "iTunes 1.1.1" (pid 5605)
Started plugin "iTunes 1.1.1"
iTunes Debug deviceStartComm: starting thread for 'iTunes Server'
iTunes Debug getMediaServerList: called
iTunes Debug deviceStartComm: adding device id 1523202327 to the active thread queue
iTunes Debug statusThread.run(): creating iTunes Controller...
iTunes Debug statusThread.run(): connecting and logging in at: 2013-11-10 10:40:14.272175
iTunes Debug statusThread.run(): unknown Error for iTunes Server
iTunes Error iTunes Server stopped due to the following error (will attempt to recover in 10 seconds):

Traceback (most recent call last):
File "statusThread.py", line 117, in run
File "itunes.py", line 57, in iTunesLogin
File "itunes.py", line 205, in updateCache
AttributeError: 'ITunesController' object has no attribute 'errorLog'


iTunes Debug deviceStopComm: stopping thread for iTunes Server
iTunes Debug getDeviceConfigUiValues called
iTunes Debug getDeviceConfigUiValues(): starting pairing thread
iTunes Debug pairingThread: Starting run method
iTunes Debug pairingThread: Waiting for pairing message
iTunes Debug closedDeviceConfigUi: device config dialog closed
iTunes Debug closedDeviceConfigUi: pairing thread exists
iTunes Debug closedDeviceConfigUi: pairing thread is running, cancelling
iTunes Debug pairingThread: Received pairing message
iTunes Debug pairingThread: From host: ('127.0.0.1', 59993)
iTunes Debug pairingThread: Closing down
iTunes Debug statusThread.run(): closing controller for exit at 2013-11-10 10:40:24.355576
iTunes Error iTunes Server has an unknown error - disabling
iTunes Debug deviceStopComm: stopping thread for iTunes Server
iTunes Debug deviceStartComm: starting thread for 'iTunes Server'
iTunes Debug getMediaServerList: called
iTunes Debug deviceStartComm: adding device id 1523202327 to the active thread queue
iTunes Debug statusThread.run(): creating iTunes Controller...
iTunes Debug statusThread.run(): connecting and logging in at: 2013-11-10 10:40:31.346986

So this log reflects a reload of the plugin, while iTunes was running, Indigo disabling comms, me reenabling comms, then ops normal.
Don't know if this helps, but this is the strangeness that's happening...
Best,
Phil

[jay (support)]

Unfortunately, no, it doesn't help since it's exactly the same error in exactly the same (impossible) place in the code. You're the only one reporting the error and I can't recreate it here unfortunately so I can't really do anything about it until someone else starts seeing it. Hopefully then I can start comparing your two environments to see what's in common that could possibly be causing the issue.

[jay (support)]

I've got one more thing to try - send me an email to indigo DASH support AT perceptiveautomation DOT com with a link to this thread and we'll try one more thing.

Just to close out for everyone's sake who might look at this thread in the future - Jay sent a modified version of the plugin that fixed the problem. Suspect that got rolled into 6.0.5. Don't know if it was a bug, a unique condition to my computer, or just life.