Indigo Server Error

Posted on
Wed Jan 24, 2018 10:27 am
DrLove offline
Posts: 260
Joined: Dec 12, 2014
Location: Sweden

Indigo Server Error

Hi!

Not using any email plugin and my server is crashing every day now for a few days, from being rock solid for years.

Indigo log at shutdown:

Code: Select all
2018-01-24 14:02:57.202   Z-Wave   received "Ljus kök/vrum1 - vrum1 spots E+S (dim)" power load to 5.7 W
2018-01-24 14:03:00.431   Schedule   Uppdatera FTX verkningsgrad
2018-01-24 14:03:00.433   Schedule   Garage klimatstyrning
2018-01-24 14:03:09.994   OWServer   Getting OWServer data...
2018-01-24 14:03:12.137   OWServer     Total of 0 servers polled.
2018-01-24 14:03:12.139   OWServer     Total of 24 devices updated.
2018-01-24 14:03:12.139   OWServer   OWServer data parsed successfully.
2018-01-24 14:03:31.488   WUnderground   European weather alert Information provided by , <a href='http://meteoalarm.eu/'>EUMETNET - MeteoAlarm</a> Note: Time delays between this website and <a href='http://meteoalarm.eu/'>Meteoalarm.eu</a> are possible. For the most up-to-date information about alert levels as published by the participating National Meteorological Services, please visit <a href='http://meteoalarm.eu/'>Meteoalarm</a>. For terms of use of this information, and copyright information, see <a href='http://meteoalarm.eu/'>Meteoalarm</a> Terms of Use.
2018-01-24 14:03:45.480   Z-Wave   received "Energiprobe - luftavfuktare garage" energy total to 95.91 kWh
2018-01-24 14:04:00.434   Schedule   Uppdatera FTX verkningsgrad
2018-01-24 14:04:00.436   Schedule   Garage klimatstyrning
2018-01-24 14:04:07.203   OWServer   Getting OWServer data...
2018-01-24 14:04:09.174   OWServer     Total of 0 servers polled.
2018-01-24 14:04:09.175   OWServer     Total of 24 devices updated.
2018-01-24 14:04:09.176   OWServer   OWServer data parsed successfully.
2018-01-24 14:04:20.652   Z-Wave   received "116 - Energimätare - Power Reader NQ-92021" status update battery level 100%
2018-01-24 14:04:20.932   Z-Wave   received "Energimätare - Power Reader NQ-92021" energy total to 47664.474 kWh
2018-01-24 14:04:20.934   Trigger   Uppdatera husets momentana effekt
2018-01-24 14:04:25.433   Schedule   Uppdatera husets momentana effekt (delayed action)
2018-01-24 14:04:30.430   Schedule   Uppdatera husets momentana effekt (delayed action)
2018-01-24 14:04:30.445   Schedule   Uppdatera husets momentana effekt (delayed action)
2018-01-24 14:05:00.426   Schedule   Uppdatera FTX verkningsgrad
2018-01-24 14:05:00.435   Schedule   Logga 5 min intervall
2018-01-24 14:05:00.436   Schedule   Logga växthusdata 5 min intervall
2018-01-24 14:05:00.438   Action Group   Logga växthusdata
2018-01-24 14:05:00.439   Schedule   Garage klimatstyrning
2018-01-24 14:05:02.429   Schedule   Logga 5 min intervall (delayed action)
2018-01-24 14:05:04.253   OWServer   Getting OWServer data...
2018-01-24 14:05:06.538   OWServer     Total of 0 servers polled.
2018-01-24 14:05:06.542   OWServer     Total of 24 devices updated.
2018-01-24 14:05:06.542   OWServer   OWServer data parsed successfully.
2018-01-24 14:05:26.942   Error   TriggerAction() caught exception: std::bad_alloc
2018-01-24 14:05:26.945   Error   TriggerAction() caught exception: std::bad_alloc



2018-01-24 14:05:26.958   Error   std::bad_alloc


Console app system log:

Code: Select all
Jan 24 14:05:24 HA-mini IndigoServer[699]: IndigoServer(699,0xb0806000) malloc: *** mach_vm_map(size=1048576) failed (error code=3)
Jan 24 14:05:26 HA-mini IndigoServer[699]: IndigoServer(699,0xa6f3b1c0) malloc: *** mach_vm_map(size=1048576) failed (error code=3)
Jan 24 14:05:26 HA-mini IndigoServer[699]: Error   TriggerAction() caught exception: std::bad_alloc
Jan 24 14:05:26 HA-mini IndigoServer[699]: IndigoServer(699,0xa6f3b1c0) malloc: *** mach_vm_map(size=1048576) failed (error code=3)
Jan 24 14:05:26 HA-mini IndigoServer[699]: Error   
Jan 24 14:05:26 HA-mini IndigoServer[699]: Error   std::bad_alloc
Jan 24 14:05:27 HA-mini IndigoServer[699]: IndigoServer(699,0xa6f3b1c0) malloc: *** mach_vm_map(size=1048576) failed (error code=3)
Jan 24 14:05:27 HA-mini IndigoPluginHost[731]: received unexpected packet response GetDevice (waiting for )
Jan 24 14:05:27 HA-mini IndigoServer[699]: IndigoServer(699,0xa6f3b1c0) malloc: *** mach_vm_map(size=1048576) failed (error code=3)
Jan 24 14:05:27 HA-mini IndigoServer[699]: IndigoServer(699,0xb0a90000) malloc: *** mach_vm_map(size=1048576) failed (error code=3)
Jan 24 14:05:27 HA-mini IndigoPluginHost[718]: connection to server failed or was dropped
Jan 24 14:05:27 HA-mini IndigoPluginHost[729]: connection to server failed or was dropped
Jan 24 14:05:27 HA-mini IndigoPluginHost[718]: Quitting Indigo Plugin Host - received quit signal
Jan 24 14:05:27 HA-mini IndigoPluginHost[727]: connection to server failed or was dropped
Jan 24 14:05:27 HA-mini IndigoPluginHost[718]: Beacon - Error in plugin execution _preShutdown:
     File "/Library/Application Support/Perceptive Automation/Indigo 7/IndigoPluginHost.app/Contents/PlugIns/plugin_base.py", line 379, in _preShutdown
     File "/Library/Application Support/Perceptive Automation/Indigo 7/IndigoPluginHost.app/Contents/PlugIns/plugin_base.py", line 1203, in _triggerEnumAndStopProcessing
Jan 24 14:05:27 HA-mini IndigoPluginHost[726]: connection to server failed or was dropped
Jan 24 14:05:27 HA-mini IndigoPluginHost[719]: connection to server failed or was dropped
Jan 24 14:05:27 HA-mini IndigoPluginHost[721]: connection to server failed or was dropped
Jan 24 14:05:27 HA-mini IndigoPluginHost[716]: connection to server failed or was dropped
Jan 24 14:05:27 HA-mini IndigoPluginHost[716]: Quitting Indigo Plugin Host - received quit signal
Jan 24 14:05:27 HA-mini IndigoPluginHost[716]: Airfoil Pro - Error in plugin execution _preShutdown:
     File "/Library/Application Support/Perceptive Automation/Indigo 7/IndigoPluginHost.app/Contents/PlugIns/plugin_base.py", line 379, in _preShutdown
     File "/Library/Application Support/Perceptive Automation/Indigo 7/IndigoPluginHost.app/Contents/PlugIns/plugin_base.py", line 1203, in _triggerEnumAndStopProcessing
Jan 24 14:05:27 HA-mini IndigoPluginHost[719]: Quitting Indigo Plugin Host - received quit signal
Jan 24 14:05:27 HA-mini IndigoPluginHost[731]: connection to server failed or was dropped
Jan 24 14:05:27 HA-mini IndigoPluginHost[719]: Cynical Denon - Error in plugin execution _preShutdown:
     File "/Library/Application Support/Perceptive Automation/Indigo 7/IndigoPluginHost.app/Contents/PlugIns/plugin_base.py", line 379, in _preShutdown
     File "/Library/Application Support/Perceptive Automation/Indigo 7/IndigoPluginHost.app/Contents/PlugIns/plugin_base.py", line 1203, in _triggerEnumAndStopProcessing
Jan 24 14:05:27 HA-mini IndigoPluginHost[735]: connection to server failed or was dropped
Jan 24 14:05:27 HA-mini IndigoPluginHost[721]: Quitting Indigo Plugin Host - received quit signal
Jan 24 14:05:27 HA-mini IndigoPluginHost[721]: DevicesAndVariables - Error in plugin execution _preShutdown:
     File "/Library/Application Support/Perceptive Automation/Indigo 7/IndigoPluginHost.app/Contents/PlugIns/plugin_base.py", line 379, in _preShutdown
     File "/Library/Application Support/Perceptive Automation/Indigo 7/IndigoPluginHost.app/Contents/PlugIns/plugin_base.py", line 1203, in _triggerEnumAndStopProcessing
Jan 24 14:05:27 HA-mini IndigoPluginHost[730]: connection to server failed or was dropped
Jan 24 14:05:27 HA-mini IndigoPluginHost[730]: Quitting Indigo Plugin Host - received quit signal
Jan 24 14:05:27 HA-mini IndigoPluginHost[730]: Simple Serial Plugin - Error in plugin execution _preShutdown:
     File "/Library/Application Support/Perceptive Automation/Indigo 7/IndigoPluginHost.app/Contents/PlugIns/plugin_base.py", line 379, in _preShutdown
     File "/Library/Application Support/Perceptive Automation/Indigo 7/IndigoPluginHost.app/Contents/PlugIns/plugin_base.py", line 1203, in _triggerEnumAndStopProcessing


and so on...


Yesterday , 14:05:02 (almost the exact time as today) was the last log entry from Indigo, it was not an error.

Hope some one can help!

Love Kull (yes it's my name)
Blog (in Swedish)
Sweden

Posted on
Wed Jan 24, 2018 10:52 am
jay (support) offline
Site Admin
User avatar
Posts: 18199
Joined: Mar 19, 2008
Location: Austin, Texas

Re: Indigo Server Error

A couple of questions:

  1. Is your disk full by any chance?
  2. When you open Activity Monitor do you see any apps using a large amount of memory?
  3. Have you rebooted your Mac?

[MODERATOR NOTE] moved to separate topic since it's a new issue.

Jay (Indigo Support)
Twitter | Facebook | LinkedIn

Posted on
Wed Jan 24, 2018 10:55 am
jay (support) offline
Site Admin
User avatar
Posts: 18199
Joined: Mar 19, 2008
Location: Austin, Texas

Re: Indigo Server Error

Also, try doing a disk repair.

Jay (Indigo Support)
Twitter | Facebook | LinkedIn

Posted on
Wed Jan 24, 2018 12:14 pm
DrLove offline
Posts: 260
Joined: Dec 12, 2014
Location: Sweden

Re: Indigo Server Error

[quote="jay (support)"]A couple of questions:

  1. Is your disk full by any chance?
  2. When you open Activity Monitor do you see any apps using a large amount of memory?
  3. Have you rebooted your Mac?


  1. No, 77 GB free
  2. No, not right now anyway
  3. Yes, yesterday after fail

Doing a disk repair right now...

Maybe a bad RAM-memory? When I opened the Activity Monitor the app crashed..

//L

Love Kull (yes it's my name)
Blog (in Swedish)
Sweden

Posted on
Wed Jan 24, 2018 1:55 pm
jay (support) offline
Site Admin
User avatar
Posts: 18199
Joined: Mar 19, 2008
Location: Austin, Texas

Re: Indigo Server Error

Yeah, definitely sounds like a hardware problem. I think there was a tool around somewhere that allowed memory testing.

Jay (Indigo Support)
Twitter | Facebook | LinkedIn

Posted on
Thu Jan 25, 2018 8:24 am
DrLove offline
Posts: 260
Joined: Dec 12, 2014
Location: Sweden

Re: Indigo Server Error

Hi!

14:06, same thing different error in Indigo:

Code: Select all
.
.
.
2018-01-25 14:05:14.162   OWServer   Getting OWServer data...
2018-01-25 14:05:16.287   OWServer     Total of 0 servers polled.
2018-01-25 14:05:16.288   OWServer     Total of 24 devices updated.
2018-01-25 14:05:16.288   OWServer   OWServer data parsed successfully.
2018-01-25 14:05:28.768   Z-Wave   received "Energiprobe - diskmaskin" energy total to 163.08 kWh
2018-01-25 14:06:00.444   Schedule   Uppdatera FTX verkningsgrad
2018-01-25 14:06:00.448   Schedule   Garage klimatstyrning
2018-01-25 14:06:11.364   OWServer   Getting OWServer data...
2018-01-25 14:06:13.608   OWServer     Total of 0 servers polled.
2018-01-25 14:06:13.610   OWServer     Total of 24 devices updated.
2018-01-25 14:06:13.611   OWServer   OWServer data parsed successfully.

2018-01-25 14:06:40.333   Error   ProcessPacketStream() caught exception: UnexpectedNullError\

CRASH!


System log:

Code: Select all
Jan 25 14:03:19 --- last message repeated 2 times ---
Jan 25 14:06:06 HA-mini com.apple.xpc.launchd[1] (com.apple.ReportCrash[27857]): Endpoint has been activated through legacy launch(3) APIs. Please switch to XPC or bootstrap_check_in(): com.apple.ReportCrash
Jan 25 14:06:39 HA-mini IndigoServer[13939]: IndigoServer(13939,0xb0144000) malloc: *** mach_vm_map(size=1048576) failed (error code=3)
   *** error: can't allocate region securely
   *** set a breakpoint in malloc_error_break to debug
Jan 25 14:06:39 HA-mini IndigoServer[13939]: IndigoServer(13939,0xb0554000) malloc: *** mach_vm_map(size=1048576) failed (error code=3)
   *** error: can't allocate region securely
   *** set a breakpoint in malloc_error_break to debug
Jan 25 14:06:39 --- last message repeated 14 times ---
Jan 25 14:06:39 HA-mini IndigoServer[13939]: IndigoServer(13939,0xb03ce000) malloc: *** mach_vm_map(size=1048576) failed (error code=3)
   *** error: can't allocate region securely
   *** set a breakpoint in malloc_error_break to debug
Jan 25 14:06:39 --- last message repeated 7 times ---

And so on...


Strange that it happens almost at the same time every day... what is going on!

I'll by new RAM-modules (Corsair 8GB (2x4GB) / 1066MHz / DDR3 / CL7 /Apple OK) today and see if that helps :/
Actually nice that it is so not-intermittent, easier to see if new RAM's helped.

//L

Love Kull (yes it's my name)
Blog (in Swedish)
Sweden

Posted on
Thu Jan 25, 2018 11:08 am
jay (support) offline
Site Admin
User avatar
Posts: 18199
Joined: Mar 19, 2008
Location: Austin, Texas

Re: Indigo Server Error

What else is happening on your Mac around that time? Backups maybe? Something that would cause memory usage to go up?

Jay (Indigo Support)
Twitter | Facebook | LinkedIn

Posted on
Thu Jan 25, 2018 11:10 am
matt (support) offline
Site Admin
User avatar
Posts: 21411
Joined: Jan 27, 2003
Location: Texas

Re: Indigo Server Error

Also, in Indigo's Event Log is the crash always preceded by OWServer performing logic/actions? It is possible it is chewing through all your memory.

Also, if you are using Indigo's built-in email scanning then try temporarily disabling that for a few days (via Indigo's preferences dialog) to see if that prevents the crash.

Image

Posted on
Thu Jan 25, 2018 12:34 pm
DrLove offline
Posts: 260
Joined: Dec 12, 2014
Location: Sweden

Re: Indigo Server Error

It looks like it, but OWS is pulling every 1 minute 24/7 so it seams odd it would crash Indigo every day at 14:05 +- 1 minute.

Not using mail scanning.

Switched to new RAM modules, hope it helps...

Best regards, L

Love Kull (yes it's my name)
Blog (in Swedish)
Sweden

Posted on
Thu Jan 25, 2018 2:33 pm
DaveL17 offline
User avatar
Posts: 6742
Joined: Aug 20, 2013
Location: Chicago, IL, USA

Re: Indigo Server Error

Please do make sure that you’re using the most current version of OWS in case that’s a factor. I’ve been running that version without issue, but that doesn’t mean it’s not what’s causing your problem.

I’d hate for you to buy new RAM if it’s the plugin’s fault all along.


Sent from my iPhone using Tapatalk

I came here to drink milk and kick ass....and I've just finished my milk.

[My Plugins] - [My Forums]

Posted on
Thu Jan 25, 2018 2:47 pm
Colorado4Wheeler offline
User avatar
Posts: 2794
Joined: Jul 20, 2009
Location: Colorado

Re: Indigo Server Error

I would analyze every schedule you have that runs at that time, there's sure to be a very strong clue right there. For me I know my Comcast dies regularly and I have to reboot my modem - the past few nights it's been almost exactly at 11pm and when that happens it's chaos with all my various always-connected devices and if you end up in an race condition or huge loop as a result of something like that it could chew through system resources in a flash.

My Modest Contributions to Indigo:

HomeKit Bridge | Device Extensions | Security Manager | LCD Creator | Room-O-Matic | Smart Dimmer | Scene Toggle | Powermiser | Homebridge Buddy

Check Them Out Here

Posted on
Fri Jan 26, 2018 7:37 am
DrLove offline
Posts: 260
Joined: Dec 12, 2014
Location: Sweden

Re: Indigo Server Error

Like a clock... 14:05 today:

Code: Select all
2018-01-26 14:03:24.685   OWServer   Getting OWServer data...
2018-01-26 14:03:26.597   OWServer     Total of 0 servers polled.
2018-01-26 14:03:26.599   OWServer     Total of 24 devices updated.
2018-01-26 14:03:26.600   OWServer   OWServer data parsed successfully.
2018-01-26 14:04:00.568   Schedule   Uppdatera FTX verkningsgrad
2018-01-26 14:04:00.570   Schedule   Garage klimatstyrning
2018-01-26 14:04:21.683   OWServer   Getting OWServer data...
2018-01-26 14:04:24.285   OWServer     Total of 0 servers polled.
2018-01-26 14:04:24.287   OWServer     Total of 24 devices updated.
2018-01-26 14:04:24.287   OWServer   OWServer data parsed successfully.
2018-01-26 14:05:00.568   Schedule   Uppdatera FTX verkningsgrad
2018-01-26 14:05:00.570   Schedule   Logga 5 min intervall
2018-01-26 14:05:00.572   Schedule   Logga växthusdata 5 min intervall
2018-01-26 14:05:00.572   Action Group   Logga växthusdata
2018-01-26 14:05:00.573   Schedule   Garage klimatstyrning
2018-01-26 14:05:02.570   Schedule   Logga 5 min intervall (delayed action)
2018-01-26 14:05:19.431   OWServer   Getting OWServer data...
2018-01-26 14:05:22.448   OWServer     Total of 0 servers polled.
2018-01-26 14:05:22.450   OWServer     Total of 24 devices updated.
2018-01-26 14:05:22.450   OWServer   OWServer data parsed successfully.
2018-01-26 14:05:35.519   Error   RunThread() caught exception: std::bad_alloc
2018-01-26 14:05:35.680   Error   ProcessPacketStream() caught exception: UnexpectedNullError
2018-01-26 14:05:36.211   Error   ProcessPacketStream() caught exception: UnexpectedNullError
2018-01-26 14:05:36.360   Error   ProcessPacketStream() caught exception: UnexpectedNullError


sys log:

Code: Select all
Jan 26 14:05:35 HA-mini IndigoServer[737]: IndigoServer(737,0xb0c20000) malloc: *** mach_vm_map(size=1048576) failed (error code=3)
   *** error: can't allocate region securely

and so on...


Today I was prepared and was logged in over remote desktop, no strange memory load or cpu load around the crash (activity monitor updates every second so can have missed it).

New RAM did not solve it and OWS doing it's thing right before.
I was running OWS v1.0.0.1 and I have now (after todays crash) updated to 1.0.0.4, hope it helps.

Could it be the HDD? The "mach_vm_map" has something to do w/ virtual memory right?

Love Kull (yes it's my name)
Blog (in Swedish)
Sweden

Posted on
Fri Jan 26, 2018 7:50 am
DaveL17 offline
User avatar
Posts: 6742
Joined: Aug 20, 2013
Location: Chicago, IL, USA

Re: Indigo Server Error

Love -

I think OWS would show up in activity monitor if it were coughing up a hairball. Let's see what updating to the most current version does for you. I went back and looked over the major changes that I've made to the plugin and everything going back to November has been relatively minor. Another thing to try is to disable the plugin and see if that makes a difference.

Given that you have OWS updating once per minute, it doesn't surprise me that it shows up right before the error--but that still doesn't mean that it is innocent in all this.

I came here to drink milk and kick ass....and I've just finished my milk.

[My Plugins] - [My Forums]

Posted on
Fri Jan 26, 2018 9:21 am
matt (support) offline
Site Admin
User avatar
Posts: 21411
Joined: Jan 27, 2003
Location: Texas

Re: Indigo Server Error

I'm leaning towards this being a bug somewhere (Indigo Server, Indigo Plugin, or a script Indigo is running) that is trying to allocate either 1 huge chunk of memory, or is stuck in a loop that is doing memory allocates (eventually, and possibly quickly once the loop starts, exhausting all memory). If the problem still occurs after the OWS update, then I'd suggest trying to disable different plugins every night to narrow down where the problem is occurring.

I don't think this is a memory or hardware problem at this point.

Image

Posted on
Fri Jan 26, 2018 9:39 am
DrLove offline
Posts: 260
Joined: Dec 12, 2014
Location: Sweden

Re: Indigo Server Error

After OWS update I now had a crash at 15:17 (not even an hour after OWS update), that made me disable OWS to see if that helps. I'm not sure it's OWS but I'll start there.

Code: Select all
2018-01-26 15:17:03.043   OWServer   Getting OWServer data...
2018-01-26 15:17:05.075   OWServer     Total of 0 servers polled.
2018-01-26 15:17:05.075   OWServer     Total of 24 devices updated.
2018-01-26 15:17:05.075   OWServer   OWServer data parsed successfully.
2018-01-26 15:17:06.256   Z-Wave   received "Energiprobe - kyl/frys" energy total to 226.17 kWh


OWS was not the last event in the log this time.

Code: Select all
Jan 26 15:17:35 HA-mini IndigoServer[4936]: IndigoServer(4936,0xb0734000) malloc: *** mach_vm_map(size=1048576) failed (error code=3)
   *** error: can't allocate region securely
   *** set a breakpoint in malloc_error_break to debug


The sys log error appears about 30 seconds after last entry in Indigo log, I think something happened in Indigo that triggered the error but the Indigo log did not catch what it was before crash, that makes this kind of hard to debug.

//L

Love Kull (yes it's my name)
Blog (in Swedish)
Sweden

Who is online

Users browsing this forum: No registered users and 5 guests