kdschlosser / MiCasaVerde_Vera

Python library for controlling the MiCasaVerde Vera Z-Wave controller.
MIT License
6 stars 1 forks source link

Event filtering seems incorrect #2

Closed sabolcik closed 6 years ago

sabolcik commented 6 years ago

Hey Keith:

Been using the library and I'm basically trying to poll my nodes that control loads to monitor their energy consumption and write the contents to a lambda database.

I initially created an XML file that had the node names and the variables I wanted to log. I read these into program then I thought I would create a polling loop to log them. What I remembered is that you have the way cool event system that can create callbacks. So I've been playing around with events.

If I setup the event handler to log callbacks for "" or "devices." or even "devices.." these all work. I can watch the event loop and see the event status. So I thought I would get clever and just setup a callback for "devices..Watts." and I can't get that to trigger. I've tried ".Watts.*" and just about every other combo I can think of.

Is there something I am missing in configuring the callbacks? I have been plugging away for a while without much luck.

kdschlosser commented 6 years ago
'devices.*.watts.changed'

or

'*.watts.changed'

The easiest way to do this is to set up a call back that spits out every event that gets triggered and have it print off the event.

def callback(event):
    print event.event

vera.bind('*', callback)

this is going to print them all off. The you make a change to the device you want to know the exact event for and it will print out. then you know the exact event.

any of the segments between the "."'s can be replaced with a this is going to wild card it. so if you wanted to do all devices that have a specific variable then replace the device number with a

You are going to see a service identifier before the variable name. this is because of how the vera runs this too can be wild carded if you want.

The object that is passed to the callback is a gateway to the object that initiated the event as well as it houses the event name and allows you to unbind from within the callback. so if you wanted to know what the new value of watts has been set to

def callback(event):
    print event.name
    print '    watts:', event.watts

vera.bind('*.watts.changed', callback)

if you want to wild card multiple segments there is no need to do

*.*.*.watts.changed

one star will suffice. so instead of doing

devices.*.*.watts.changed

this will work as well

devices.*.watts.changed

and it's funny because you hit just about every single combination except the right one.

There are 3 categories of events

changed
removed
added

the removed and added are for the addition of a plugin, device or a new scene. the changed is only triggered by the change of a property or variable.

sabolcik commented 6 years ago

OK, thanks. I've been playing around for the better part of the day. I didn't actually try your flags as I had already put the filtering in the callback handler to look at the event for

devices.*

and did my filtering there. I managed to get the callbacks to post data to influxdb and was feeling pretty good about the whole thing. Then I discovered that influx doesn't like sparse data sets. So only logging the change of the power variable lends to some undesirable behavior in the temporal database.

So now I need to go back and log the settings from the Vera at some interval. I was planning on keeping the event handler (which would log at a fine granularity when the variable changed) then have a timer callback loop at a longer granularity to fill in the gaps between the change events. I more or less got it working but I think I might be running into some issues with the treading of the callbacks not being safe with your library.

I have 2 questions for you:

Is there already a built in way in your vera library to run another callback outside of the poll loop? I really want 2 loops: a faster polling loop (at a few seconds) to capture when the variables changes state and log it to the database, and a slower one (at a few minutes) to basically fill in datapoints if the variable isn't changing.

I found an example using the thread library that allowed me to create a callback every few minutes. I then go though a list of devices by name and write out the parameters to influx.

I am a little concerned that I might not be thread safe when I start accessing the instance device list in the thread callback handler. Not sure if you have any suggestions on that front.

One final question, is there a way to not have the library rebuild the vera information at initialization? My system is pretty big and it's taking over a minute to do the connect call. That's painful with my rusty python as I debugging a lot and the time to load is getting to be a bottleneck on debugging.

Thanks again for all the great support.

sabolcik commented 6 years ago

Just reread my last comment and saw that it was pretty repetitive. Sorry about that, I am pretty fried.

One final question. There is a problem in my configuration where, for some reason, a few of my light switches don't have the "Watts" parameter. So when I iterate through the device list trying to read Watts it throws an exception. Is there a clean way to check if a variable is included? I am currently just wrapping the getattr call in an try except block but I thought there might be a more elegant way to find that out.

kdschlosser commented 6 years ago

as for the first portion of your explanation.

In what manner is the library not thread safe? I am curious to know this so I can change it. because the update thread is the same thread that fires off the event. so no update to the data set can take place until you have done with whatever it is you need to inside of the event. That being said. This is done by design so the data is not going to change at all while your code is being run in the event. If you have some kind of a loop or anything in that nature inside of a callback I would strongly recommend passing whatever data (not the event object) it is into a new thread so your loop can run without causing issues with stalling the update thread.

data = getattr(device, 'Watts', None)
if data is not None:
    # do your code here
sabolcik commented 6 years ago

The situation I am running into is that the temporal database doesn't like sparse data. So, for example, I am trying to log power usage and temperature for my nodes. If I just use the Vera events when they change this creates a problem for my use case in that the graphing isn't smart enough to realize it should "hold" the last datapoint until it changes. I did some exploration and I could use a data retention policy to try and "fill in" the data by repeating the measurements at a fixed interval but most people seem to recommend just sampling at a standard cadence then using the database to compress the data over time.

Regardless my architecture was to use the Vera event handler to capture the exact moment (at least to the sample interval I set for the Vera update rate) the light turns on then poll it in a timed callback routine at a standard cadence to fill in until it changes again.

I didn't want to build a timer loop in my main routine but rather install a timed callback.

When I enter the callback I use a list of the node names and values I want to poll and step through the getattr call for each one then log the results to the influx database. My Vera poll rate is 5 seconds and my timed callback is at minute intervals. I have about a dozen nodes I am polling for attribute, building a JSON packet for each node, then writing the node to the influx database. It works most of the time then I'll get an (apparently) random exception that says the getattr failed on a Vera device node. I am wondering if that is a result of me colliding with the Vera update thread while it is in the process of updating the device attributes.

I also am not reloading the device list from the vera instance. I setup a call

deviceList = instance.devices

during initialization and then iterate that list by name to get the attributes I am interested in.

I was trying to find a more elegant approach than a blocking loop in my main to do the timer based update of the values. Hence my timed thread callback. I don't know if there is a semaphore in the Vera library I can check to determine if the Vera update thread is running and then jump out of the update and try again later.

I could take the approach of building a while loop that runs in the foreground and just set a variable in the timer callback to set a variable indicating that the timer expired and do all the processing in the foreground. I am, after all, running a loop at the end of my code that says:

while TRUE: time.sleep(0.5)

My ultimate goal is to setup various loggers in my application polling the Vera, my whole house energy monitor, my pool controller, etc. and logging state information. They all have unique ways to query this information so I was going to setup a callback per system to write to the database.

I may already need a semaphore for my own architecture to protect the database write if I start logging from multiple threads for each system.

Any thoughts?

It is certainly possible that this is all pilot error. I'm relearning my programming skills. I can send you a dump of the thread exception and more code details this evening when I am back home by my machine.

Thanks again for the patience and support.

kdschlosser commented 6 years ago

OK you can't collide with the update. because that is exactly what it does. it updates. once the initial instance is created

vera = micasaverde_vera.connect()

the device list is created. there is only 2 ways to update that device list. one is to create a new instance. the second is through the use of the polling loop.

how are you accessing the devices?

if you put all of the nodes you want to get the data from in the same "room" on the vera it becomes even easier to do because you can simply bind an event to all devices that have the Watts changed. and when the event gets triggered simply check the room name.

example pseudo code

import threading
import micasaverde_vera

# this is a thread lock. this will stop dual access to the storage container
# we do want to avoid any corrupted readings.    
update_lock = threading.Lock()

# storage for the Watts
stored_values = dict()

def callback(vera_event):

    # if you have all of the devices in a single common room
    # this will ensure that you do not get devices you do not want.
    if vera_event.room.name == 'Room Name':
        update_lock.acquire()
        stored_values[vera_event.id] = vera_event.watts
        update_lock.release()

update_event = threading.Event()
def update_temporal_database():
    while not update_event.isSet():
        # acquire a lock before passing the readings. this will stop the event 
        # thread from changing any of the readings while you are passing them
        update_lock.acquire()

        for device_id, watts in stored_values.items():
            # do you code needed to send the watts levels into the database.
            # this will pass values even if they have not changed.
            pass

        # release the thread lock
        update_lock.release()

        # set this to the interval in which your database needs to be updated.
        # this is in seconds.
        update_event.wait(1.0)

# you can have the update_temporal_database thread loop exit in 2 ways. we can 
# either make it a daemon thread and that thread will get closed when the 
# process closes.
# or we can set the update_event when a condition happens I have done both 
# in this example. 

t = threading.Thread(
    name='update_temporal_database',
    target=update_temporal_database
)

t.daemon = True
t.start()

vera = micasaverde_vera.connect('192.168.1.1')
vera.bind('devices.*.Watts.changed', callback)
vera.start_polling(0.2)

while True:
    try:
        pass
    except KeyboardInterrupt:
        update_event.set()
        t.join(5.0)
kdschlosser commented 6 years ago

and also do not ever use

while TRUE:
    time.sleep(0.5)

in a loop.

create a thread event and use a non blocking wait from that event.

sabolcik commented 6 years ago

Thanks Keith

Lots for me to unpack there. All great architectural suggestions. I will try those out.

Thinking about your example above it seems like the philosophy is to read the Watts value from all the nodes I am interested in so that if one node changes I "fill in" the data for all nodes even if they haven't changed and update the database. If my usage patterns are such that an event is generated at some reasonable rate I get more time samples in the database even for nodes that haven't changed.

I'm thinking about the case where I expect there to be long periods with no events. Take for example an overnight scenario. None of my lights are changing so for 8 hours I get no watts events and i have the same database issue. That is why I was trying to create the separate timer thread to read the watts values a few times per hour to update them. I don't think the example above handles that case.

I'll eventually need the timer thread for my other devices as well where I don't have a cool architecture like your Vera library to create the callbacks.

Here is my main loop (including the discouraged while TRUE):

logging.basicConfig(level=logging.DEBUG)
logging.info("Connecting to Vera")
ip = micasaverde_vera.discover()

if ip != "":
    logging.info("Found Vera at IP address: " + ip)
else:
    logging.debug("Vera not discovered.  Trying hardcoded address") 
    ip = vera_ip

instance = micasaverde_vera.connect(ip)
deviceList = instance.devices

logging.info("Building Device List")
build_device_list(deviceList)

cbString = 'Devices.*'

logging.info("Installing callback: " + cbString)
instance.bind(cbString, test_callback)

logging.info("Starting polling")
instance.start_polling(5)

logging.info("Connecting to database: " + dbname)
client = InfluxDBClient(host, port, user, password, dbname)

# start timer
timer = RepeatedTimer(60, log_parameter, deviceList, devLogList, "Watts")

while True:
    time.sleep(5)

I pass a reference to deviceList into the log_parameter call which I reference to get the most current vera device values. devLogList is a structure with the name of the device, and a type (light, HVAC, etc). I don't use the vera device info in the call back because some of my binary switched outlets control lights and some control an electric heater so I am trying to distinguish between the sources.

I could avoid passing in the name by using your room suggestion but I do still access my system with the Vera UI so I am trying to keep that view logically organized by physical room.

def log_parameter(devList, devLogList, parameter):
    logging.info(" Logging parameter:" + parameter)
    for name in devLogList:
        logParm = devLogList[name]['type']
        dev = devList[name]
        logging.info("Device name: " + name)
        try:
            value = dev.__getattr__(parameter)
            logging.info("Device value: " + value)
            json_body[0]['measurement'] = parameter
            json_body[0]['tags']['device'] = name
            json_body[0]['tags']['type'] = devLogList[name]['type']
            json_body[0]['fields']['value'] = float(value)
            logging.info("Write points: {0}".format(json_body))
            client.write_points(json_body)
        except:
            logging.info("No parameter: " + parameter)

I have to review my python basics so I'm not sure about the "type" of the devList when I pass it to the callback. If I try the simple form

value = dev.getattr(parameter)

in the callback I was getting an error that getattr wasn't defined. I assumed it might be because the class info for dev was lost in the call. Not your problem but just explaining why I used that format. Also I was playing around with different info I was trying to log so I normally would be putting logging statements in the callback at the info level. I have had the loop running for about an hour without any crash. Will continue to monitor and re-factor based on your suggestions.

Thanks again for your help.

sabolcik commented 6 years ago

I actually did get a crash while I was composing my response. I had logged to the database for about 20 minutes successfully then got this crash.

INFO:root: Logging parameter:Watts
INFO:root:Device name: Microwave Under Cabinet Light
INFO:root:Device value: 0
INFO:root:Write points: [{'fields': {'value': 0.0}, 'tags': {'device': 'Microwave Under Cabinet Light', 'type': 'Light'}, 'measurement': 'Watts'}]
DEBUG:urllib3.connectionpool:Starting new HTTP connection (1): 192.168.86.62
DEBUG:urllib3.connectionpool:http://localhost:8086 "POST /write?db=automation HTTP/1.1" 204 0
INFO:root:Device name: Breakfast Recessed
INFO:root:Device value: 139
INFO:root:Write points: [{'fields': {'value': 139.0}, 'tags': {'device': 'Breakfast Recessed', 'type': 'Light'}, 'measurement': 'Watts'}]
DEBUG:urllib3.connectionpool:http://192.168.86.62:3480 "GET /data_request?id=user_data HTTP/1.1" 200 None
DEBUG:urllib3.connectionpool:http://localhost:8086 "POST /write?db=automation HTTP/1.1" 204 0
INFO:root:Device name: Stereo
INFO:root:Device value: 0.000
INFO:root:Write points: [{'fields': {'value': 0.0}, 'tags': {'device': 'Stereo', 'type': 'AV'}, 'measurement': 'Watts'}]
DEBUG:urllib3.connectionpool:http://localhost:8086 "POST /write?db=automation HTTP/1.1" 204 0
INFO:root:Device name: Living Room
INFO:root:Device value: 0
INFO:root:Write points: [{'fields': {'value': 0.0}, 'tags': {'device': 'Living Room', 'type': 'Light'}, 'measurement': 'Watts'}]

DEBUG:urllib3.connectionpool:http://localhost:8086 "POST /write?db=automation HTTP/1.1" 204 0
Exception in thread Thread-819:
Traceback (most recent call last):
  File "/usr/lib/python2.7/threading.py", line 801, in __bootstrap_inner
    self.run()
  File "/usr/lib/python2.7/threading.py", line 754, in run
    self.__target(*self.__args, **self.__kwargs)
  File "<stdin>", line 72, in _target
  File "<stdin>", line 86, in log_parameter
  File "/home/sabolcik/.local/lib/python2.7/site-packages/micasaverde_vera/devices.py", line 106, in __getitem__
    raise KeyError
KeyError

Will continue refactoring.

kdschlosser commented 6 years ago

ok if you want to read the watts values you would have to change the polling interval on the vera for each device. This can also be done from my library. as long as you have the polling set to run in the library it will always grab the last value as reported by the device.

You should be able to set the polling for all devices to 60 seconds and this should not cause any kind of an issue with performance. what that means is every 60 seconds the vera will ask all of the devices for their current status. and as they report in if there is a change, the polling cycle on the library will trigger an event. if there is no change then no event is triggered.

I guess this is where I am having a hard time grasping what you are exactly trying to accomplish. Because it sounds like maybe you are over thinking it instead of letting it simply work the way it is intended to.

The last code example i gave you is because you said your database needs a constant flow in information going into it. Now that being said you can forgo the callback routine using the bind with the vera and set up your own thread loop to grab the values tho this method has no mechanism in it to be thread safe. where as the latter does.

Let me modify the library so that you will get some better traceback information. like what variable is being looked for. and it's strange as to why it is throwing a keyerror. are you accessing the device attributes as a dictionary or as attributes?

kdschlosser commented 6 years ago

as far as the organization goes you have the ability on the vera to create new variables. so create a new variable unique to the devices you want to data log. then do something like this in the callback

if hasattr(event, 'some_new_variable_name'):
    event.Watts
kdschlosser commented 6 years ago

that error you are getting is doe to a device name or a device index.. how are you making the call to devices to get a specific device??

this can be done more then one way

devices.some_device devices['Some Device'] devices[5]

I updated the devices.py file to print out exactly what is causing the error. so you can simply replace the single file

sabolcik commented 6 years ago

Duh! I should just setup a scene on my Vera that runs at the interval that I want to do the poll and setup a event handler for that scene.

That's clean, only uses your event loop, and allows me to get both the event when the device changes and an event at a standard cadence.

That's too easy.

kdschlosser commented 6 years ago

I am still confused what you mean by poll the devices.

There is a variable for each device. it is called poll... You can set this variable to any number you like.. and this controls at what speed the vera will ask each device if something has changed.

you can set this number from my library or directly in the advanced menu for a device in the vera UI.

no need for any scenes or anything additional. and if something has changed the library will tell you something has changed.

kdschlosser commented 6 years ago

if you bring up a device in my library and then run this

print device.get_variables()

it will print out all variables that are available for that device. you should see a variable in there for poll.. then do

device.poll = 60 

this will set the speed in which the vera asks the device for updates to 60 seconds.

sabolcik commented 6 years ago

Let me clarify what I mean by polling the node. I need to write the current state of the Watts parameter to the temporal database at some interval even if the variable hasn't changed. This is to made the graphing of the data work properly given how the database handles sparse datasets.

For example:

If I turn on a light and it's watts parameter goes from 0 W to 24W the callback I registered on the devices gets called, I retrieve the information on the device, and I write it to the database. So far so good.

Now if the parameter doesn't change for another, for example, 8 hours if I am trying to use some of the standard graphing tools for the database, this one point is all I have and it quickly falls out of my graphing window. When I switch the light off Watts goes back to 0 the callback is called and the correct value is written. So I have 2 points in my database, separated by 8 hours in time.

The database isn't smart enough to realize that the prior point is "held" until the next point shows up when graphing. There are some ways to tell the database to push this measurement forward in time but apparently it's a huge pain in the butt to try and set that up.

So what I am trying to do is after I store that initial point is store the same value over and over again into the database to make graphing and statistics easier. It seems like I could do this in one of two ways:

1) Get all of the wattage values at startup into a data structure and write that data structure to the database at a fixed cadence. When I get a new value for a device use the callback event to just update that device's value in the data structure and write this updated data structure out at my fixed cadence.

2) Have 2 separate callbacks running. One that detects when the device changes and just update that devices information into the database. Then have a second callback that gets called on my fixed cadence time interval reads the wattage for all nodes regardless if they have changed and writes this data to the database.

Both approaches should work and I had gotten my brain fixed on the second approach. So this second callback that I was proposing to use a scene to trigger would read the wattage from all devices once it was called and write that out to the database. I am calling this step of reading all the wattage values regardless if they have changed the "poll".

I also thought that periodically re-establishing the state of the wattage on all devices would handle the case if something funky happened that I might have missed. For example if a node went bad it would be nice to use this time based cadence as a heart beat. Has the measurement really not changed in 8 hours or is the node dead?

I was trying to use a separate timer thread to trigger and recollect all the data from the end nodes. This was bad in that it doesn't seem thread safe as I was accessing the device information from a second callback that wasn't being managed by your Vera library. But if I use a Vera scene to trigger the second callback I am inside of your Vera callback scene and hence, I assume, protected from trying to access device data when your polling timer is also updating it.

I can also confirm that devices.*.Watts.changed doesn't work on my setup as the callback filter. I installed that as a callback and got no events, but installing "devices.*' did allow me to see the proper events. A fully qualified event filter "devices.70.EnergyMetering1.Watts.changed" works and "devices." works, but "devices..Watts.changed" does not.

Thanks for your threading example. That worked great, is clean, and was a very helpful snippet.

I'm pretty fried tonight but will try again tomorrow.

sabolcik commented 6 years ago

I got out of sync with your responses. I will check your new file out tomorrow. And you are correct that running the database thread at my time interval and writing the same data out will work. I just got fixated on asking the Vera for the data instead of just using the existing set of values. That is the most elegant and simplest solution. But the event filters I called out in my earlier email devices.*.Watts.changed doesn't work for me. On Mon, Jan 29, 2018 at 11:22 PM Kevin Schlosser notifications@github.com wrote:

if you bring up a device in my library and then run this

print device.get_variables()

it will print out all variables that are available for that device. you should see a variable in there for poll.. then do

device.poll = 60

this will set the speed in which the vera asks the device for updates to 60 seconds.

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/kdschlosser/MiCasaVerde_Vera/issues/2#issuecomment-361480611, or mute the thread https://github.com/notifications/unsubscribe-auth/AhSL4-E1szJrIeeRRggDZsqDQSWQi4aXks5tPqcJgaJpZM4RvlpC .

sabolcik commented 6 years ago

Sorry my comment wasn't clear should have said your suggestion to just rewrite the same data to the database is the most elegant. On Tue, Jan 30, 2018 at 1:08 AM Ross Sabolcik ross.sabolcik@gmail.com wrote:

I got out of sync with your responses. I will check your new file out tomorrow. And you are correct that running the database thread at my time interval and writing the same data out will work. I just got fixated on asking the Vera for the data instead of just using the existing set of values. That is the most elegant and simplest solution. But the event filters I called out in my earlier email devices.*.Watts.changed doesn't work for me. On Mon, Jan 29, 2018 at 11:22 PM Kevin Schlosser notifications@github.com wrote:

if you bring up a device in my library and then run this

print device.get_variables()

it will print out all variables that are available for that device. you should see a variable in there for poll.. then do

device.poll = 60

this will set the speed in which the vera asks the device for updates to 60 seconds.

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/kdschlosser/MiCasaVerde_Vera/issues/2#issuecomment-361480611, or mute the thread https://github.com/notifications/unsubscribe-auth/AhSL4-E1szJrIeeRRggDZsqDQSWQi4aXks5tPqcJgaJpZM4RvlpC .

kdschlosser commented 6 years ago

Hey no worries. I know how it works. the solution seems way to simple to work properly. that is why you were headed the other route. I will take a look at the event system and see if i can't determine what is going on with it. it should function properly.

do me a favor try this as a binder.

"devices.*.*.Watts.changed"

and also

"devices.*.EnergyMetering1.Watts.changed"

I may have changed it up because of being able to store duplicate variable names on the same device. but they are in different services. EnergyMetering1 being the service. As an example a dimmable light has Dimming1 but it also has Binary1. so you can have duplicate variable names one stored in each service.

I will take a look so i can adjust my direction if that is the case.

kdschlosser commented 6 years ago

So I have been thinking about the thread safe thing. I believe you are correct about it not being thread safe.

I need to put into place locks. because a different thread can be accessing say a device variable while the update thread at the same time could be accessing the same variable. This is going to be quite a bit of work to do. I am going to have to convert any hard coded attributes that I have set up into properties. tho most of them I already have this way. and the devices is a sinch because the code files for those are auto generated.

Then there would be no need to have a secondary data container or even use the call back portion of my library. You would still have to run the polling so the library will get the updates. from there grab all the device instances place them into a list and start a thread to iterate over them and grab the Watts variable. and if it is updated it's updated.

I have to fire up my Vera but I believe there is also a time stamp for the last successful Vera to device poll. you can use this to see if the device is working or not. and then you can act accordingly.

There is also the alerts that can be used in the callback routine. for my library so you can pick up on any problems the Vera is having. the Vera will throw an error if a device drops out for some reason. so we can grab that error and know that there is something wrong as well.

I have some work to do on this thing. I should be able to get the locks into place tonight and I will code up the means to do what you need. I have a plan!

sabolcik commented 6 years ago

Keith:

That's great and much appreciated the library looks more and more useful as I start to think about use cases in my system.

Based on what you called out above I think you are saying that by only using your event callbacks the library is thread safe but if I try to access device variables from a different thread (like inside the write to database callback) the library isn't safe. Is that accurate?

So using your proposed use case of updating a data structure in the device.*.Watts.changed callback by reading the Watts value for the device that triggered the callback should work. Is that correct?

I have tried the various callback filters you suggested. These callbacks fail to detect an event:

'devices.*.*.Watts.changed'
'devices.*.Watts.changed'
'*.Watts.changed'

While these work:

'devices.*.changed'
'devices.*'
kdschlosser commented 6 years ago

there is an asterisks in the bindings I posted to you. I am not sure if you keyed those in or not.. in order for the asterisks to show you either have to escape it with a \ or you need to set it as a code block. A code block is a blank line. then anything typed that is proceeded by 4 spaces. then another blank line. I just want to make sure you are entering the bindings correctly.

Watts should not begin with a capital letter i think. try it with a lowercase w

sabolcik commented 6 years ago

Yeah, I realized there was a formatting error in my comments. I went back and updated the comment in GitHub to select the patterns as code so the * is there. If you read the email you wouldn't have seen the * but they are there in my tests. Didn't try watts with a lower case 'w'. The event that gets passed to the call back shows it with a Watts.

I went through and refactored the code and build up a data structure that holds the most recent vera readings. This structure gets filled in with the current Vera values before I start either the vera polling loop or the vera update loop in an initialization call. After the initialization I start up the vera polling timer and the database thread. The data structure gets written out when the database update thread is called. I use the same structure in the vera event callback and simply update the value for the particular device that created the event and dump all the devices including the new value out to the database.

In this new mode I am only touching the vera devices in initialization (before any threads get created and before I call your start_polling function) and in the vera event callback. If your library doesn't allow an event callback while the polling loop is updating the device structures or a polling interrupt while the event handler is running it should be safe.

I can further simplify as I found it simplest to keep the JSON structure the database wants as one of the elements I store for each device. That could allow me to drop some other fields in the data structure.

Everything is running but I haven't done as much of a stress test on the library as I was doing yesterday when I would read the wattage values for all devices in the timed database callback from the vera library. That architecture did significantly more activity to the library and that is where I saw the attribute crashes. I still need to update to your latest file you created yesterday.

You previously mentioned that I shouldn't call time.sleep() in the infinite poll at the end of my code while I am just letting the threads run and looking for a keyboard interrupt. I'm not sure why. If I just put pass in the infinite while loop my CPU runs at about 40 percent just from the polling. If I put a sleep there I am not hogging the CPU and the vera update loop, callbacks, and database thread all seem to run fine.

time.sleep only blocks the thread it is called in so I assume the other threads are still happily churning away and my anecdotal testing seems to show no lag to when the event handler fires.

I'll keep chugging away. I am currently only logging wattage but will start to log other state variables as well. If you make any progress on the event masks that would be helpful as running with the devices.* mask creates lots of events I don't want and causes the callback to get called much more frequently than necessary.

And thank you for the awesome support and patience. Much appreciated.

kdschlosser commented 6 years ago

Oh no worries m8,

Adding all of these locks is a pretty large project. I am about 1/2 way done (without testing) I had to change all of my attribute calls to self.dict['attribute name'] because I use the getattr method to handle passing the attributes back to the user I had to put a lock there and then I had to put locks on different bits that contained calls togetattr which would cause an issue when it tried to acquire the lock again. so either I had to add a release before each call to getattr or change how i grabbed the variable.

kdschlosser commented 6 years ago

and the reason to not use the sleep is because of how it blocks. I never did a whole lot of poking about into it but the use of threading.Event().wait() is the better way. I am not sure how the inner mechanics work. Its something I have read over and over again. I guess if it works then keep it.. But it is a thread so you can use it for something other then sleeping..

sabolcik commented 6 years ago

Sounds good. Thanks for the continued effort and the feedback on using the threading wait call. My main thread is currently not doing anything but as I start to expand the project I suspect that I will want to do useful work there. When I get home this evening I'll see if my logger is still running and will attempt to use the other device callback masks to see if they trigger.

On Wed, Jan 31, 2018 at 11:57 AM, Kevin Schlosser notifications@github.com wrote:

and the reason to not use the sleep is because of how it blocks. I never did a whole lot of poking about into it but the use of threading.Event().wait() is the better way. I am not sure how the inner mechanics work. Its something I have read over and over again. I guess if it works then keep it.. But it is a thread so you can use it for something other then sleeping..

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/kdschlosser/MiCasaVerde_Vera/issues/2#issuecomment-362016689, or mute the thread https://github.com/notifications/unsubscribe-auth/AhSL44-M666F_J1LDr5gfNNzFBgpgOHYks5tQKmlgaJpZM4RvlpC .

kdschlosser commented 6 years ago

OK sorry this took so long. it was a very large undertaking to get this all right, much bigger then I thought it would be.

But... You will be happy to know that I found the issue with the events. So those are now good to go. And everything has threading locks. so different threads cannot interact with the same object at the same time.

The unfortunate thing is because of how the data is stored if a device is being updated it is going to cause another thread to wait until the update for that device is done.. this process is very quick but that was the only way to go about it.

kdschlosser commented 6 years ago

I am thinking I may implement an update routine that can be called by the user. this way if you simply want to create a single thread that will do an update and then iterate through specific devices you can.

This will allow you to create a single thread that would handle the passing of the watts to your database and any changes there may be would get handled with no other code needed. This would be the ost simplistic approach.

If you plan on using this library for other things besides the watts thing then you would use the polling loop that is built in and have to create your own thread to keep the flow of data rolling into your DB.

sabolcik commented 6 years ago

Hi Kevin:

Great news. I will download the code this evening. I think that the thread blocking won't be a major issue. If the database write collides with the device update and it blocks for a bit it should be OK. I am currently updating the database at a 1 minute interval and polling the vera on a 30 second interval so there should be plenty of time for the database thread to complete before the next vera polling event.

I have my basic application running but started refactoring into cleaner classes. I do think that there was an issue with attributes still crashing with the last code drop but I will try the latest with the thread enhancements. I had the vera loop stop running after a few days but since I put in an exception handler and I wasn't logging my output to a file I can't confirm. I had it crash again last night but haven't reviewed my log files to confirm my hypothesis.

I changed my write to database thread to write the vera wattage plus measurements from my whole house energy monitor and my pool pump controller so I have a more complete view of my overall consumption. In the write to database thread I poll the whole house monitor and pool controller to get the measurements to write. If I add a poll for the vera devices as you proposed it would put all of my data measurements and the write to database in that one thread.

I will be adding other systems and also logging temperature, dim level, etc. from the Vera moving forward. Since I am planning to log more that just wattage I had to rewrite my data structures to be generic and handle other parameters.

Below is an example of how I am logging the data and visualizing it in grafana. There are 2 example images:

1) showing only the vera devices

grafana vera

2) showing the vera devices, my pool pump, and other (my whole house energy monitor minus the total vera consumption minus the pool pump consumption)

grafana total

I'll try out the updated library and give you some feedback in the next few days.

Thanks again for the great support and quick turnaround.

sabolcik commented 6 years ago

I'm about to download and install your latest changes.

I did check my log file and I got an exception but not the attribute exception that I expected. Looks like the connection to the vera got reset which threw an exception. If I wanted to handle that exception would I need to create a new vera instance and reload the device list?

I'll dig through the code and try to figure it out as well but thought you might have an idea.

Thanks.

sabolcik commented 6 years ago

Forgot to include the traceback. Looks like i got a couple of exceptions. Including one to my home energy monitor. The first few look like they are vera related though and maybe addressed with the most recent changes.

The connection aborted was tied to my neurio home energy monitor not the vera. Exception in thread Thread-847: Traceback (most recent call last): File "/usr/lib/python2.7/threading.py", line 801, in __bootstrap_inner self.run() File "/usr/lib/python2.7/threading.py", line 754, in run self.__target(*self.__args, **self.__kwargs) File "/home/sabolcik/.local/lib/python2.7/site-packages/micasaverde_vera/__init__.py", line 577, in _data_handler self.__update(self.devices, 'devices', data) File "/home/sabolcik/.local/lib/python2.7/site-packages/micasaverde_vera/__init__.py", line 465, in __update obj.update_node(data.pop(key, None), True) File "/home/sabolcik/.local/lib/python2.7/site-packages/micasaverde_vera/devices.py", line 119, in update_node found_device.update_node(device, full) File "/home/sabolcik/.MiCasaVerde_Vera/core/devices/binary_light_1.py", line 464, in update_node state['service'] File "/home/sabolcik/.MiCasaVerde_Vera/core/devices/binary_light_1.py", line 452, in check_value variable.replace('.', '') File "/home/sabolcik/.local/lib/python2.7/site-packages/micasaverde_vera/event.py", line 51, in notify event_handler.event_object = event_object File "/home/sabolcik/.local/lib/python2.7/site-packages/micasaverde_vera/event.py", line 79, in event_object self.__callback(self) File "<stdin>", line 125, in device_callback File "/usr/local/lib/python2.7/dist-packages/neurio/__init__.py", line 412, in get_local_current_sample r = requests.get(url, headers=headers) File "/usr/local/lib/python2.7/dist-packages/requests/api.py", line 72, in get return request('get', url, params=params, **kwargs) File "/usr/local/lib/python2.7/dist-packages/requests/api.py", line 58, in request return session.request(method=method, url=url, **kwargs) File "/usr/local/lib/python2.7/dist-packages/requests/sessions.py", line 508, in request resp = self.send(prep, **send_kwargs) File "/usr/local/lib/python2.7/dist-packages/requests/sessions.py", line 618, in send r = adapter.send(request, **kwargs) File "/usr/local/lib/python2.7/dist-packages/requests/adapters.py", line 490, in send raise ConnectionError(err, request=request) ConnectionError: ('Connection aborted.', error(104, 'Connection reset by peer'))

sabolcik commented 6 years ago

Just for the sake of completeness, I forgot that I needed to change a few things in the library to get it to run last time. When I downloaded the latest code I got the same errors. I'll document them here and the default arguments that I used to make them go away:

Traceback (most recent call last):
  File "<stdin>", line 265, in <module>
  File "/home/sabolcik/.local/lib/python2.7/site-packages/micasaverde_vera/__init__.py", line 332, in connect
    return __Vera(ip_address)
  File "/home/sabolcik/.local/lib/python2.7/site-packages/micasaverde_vera/__init__.py", line 293, in __init__
    _VeraBase.__init__(self, ip_address)
  File "/home/sabolcik/.local/lib/python2.7/site-packages/micasaverde_vera/__init__.py", line 422, in __init__
    self.__update(self.scenes, 'scenes', data)
  File "/home/sabolcik/.local/lib/python2.7/site-packages/micasaverde_vera/__init__.py", line 465, in __update
    obj.update_node(data.pop(key, None), True)
  File "/home/sabolcik/.local/lib/python2.7/site-packages/micasaverde_vera/scenes.py", line 113, in update_node
    found_scene = Scene(self, **scene)
  File "/home/sabolcik/.local/lib/python2.7/site-packages/micasaverde_vera/scenes.py", line 172, in __init__
    self.timers = Timers(self, timers)
  File "/home/sabolcik/.local/lib/python2.7/site-packages/micasaverde_vera/scenes.py", line 909, in __init__
    self.timers = list(Timer(self, scene, **timer) for timer in timers)
  File "/home/sabolcik/.local/lib/python2.7/site-packages/micasaverde_vera/scenes.py", line 909, in <genexpr>
    self.timers = list(Timer(self, scene, **timer) for timer in timers)
TypeError: __init__() got an unexpected keyword argument 'interval'

Previously I had simply changed the constructor to add the parameter interval with a value of 0 `class Timer(object):

def __init__(
    self,
    parent,
    scene,
    id,
    name='',
    type='',
    enabled=1,
    days_of_week='',
    time='',
    next_run=0,
    last_run=0,
    **interval = 0**
):`

Similar issue with the Trigger object

Traceback (most recent call last): File "<stdin>", line 265, in <module> File "/home/sabolcik/.local/lib/python2.7/site-packages/micasaverde_vera/__init__.py", line 332, in connect return __Vera(ip_address) File "/home/sabolcik/.local/lib/python2.7/site-packages/micasaverde_vera/__init__.py", line 293, in __init__ _VeraBase.__init__(self, ip_address) File "/home/sabolcik/.local/lib/python2.7/site-packages/micasaverde_vera/__init__.py", line 422, in __init__ self.__update(self.scenes, 'scenes', data) File "/home/sabolcik/.local/lib/python2.7/site-packages/micasaverde_vera/__init__.py", line 465, in __update obj.update_node(data.pop(key, None), True) File "/home/sabolcik/.local/lib/python2.7/site-packages/micasaverde_vera/scenes.py", line 113, in update_node found_scene = Scene(self, **scene) File "/home/sabolcik/.local/lib/python2.7/site-packages/micasaverde_vera/scenes.py", line 171, in __init__ self.triggers = Triggers(self, triggers) File "/home/sabolcik/.local/lib/python2.7/site-packages/micasaverde_vera/scenes.py", line 677, in __init__ Trigger(self, scene, **trigger) for trigger in triggers File "/home/sabolcik/.local/lib/python2.7/site-packages/micasaverde_vera/scenes.py", line 677, in <genexpr> Trigger(self, scene, **trigger) for trigger in triggers TypeError: __init__() got an unexpected keyword argument 'users' Updated constructor: class Trigger(object): def __init__( self, parent, scene, name, device=None, template=None, enabled=1, lua='', encoded_lua=0, arguments=[], last_run=0, last_eval=0, users = 0 ): With those changes I got the code running again. There may be a more elegant way to fix those missing parameters but wanted you to be aware.

kdschlosser commented 6 years ago

OK I updated the library to add the fixes for those items.

I also added threaded events. what this means is that the callback will get called inside of it's own thread for each event that is generated. I added this feature for 2 reasons. first is because I added the locks. the second is so that if a user has long running code inside of the event callback this will not stall the update process from continuing.

I also did quite a bit of code cleanup.

And I incremented the library version so when you run this it will automatically generate new files.

I do not know if you know this or not. But you can check out the files if you like. if you are running on a Windows system the files are located in the %appdata%/MiCasaVerde_Vera folder. and on Linux/Crapintosh in the ~/.MiCasaVerde_Vera folder.

If you change any of the generated files or if you have data corruption on your HDD and the files get damaged, the library will know and it will rebuild them.

kdschlosser commented 6 years ago

and as far as that exception goes. that is not a problem with the library. that is an issue with a connection to something else. and you are running the code that makes that connection from inside of the update thread the vera library is running. My suggestion is to do a base exception catching as soon as the callback gets called. This way it won't stall the library from running

Exception in thread Thread-847: Traceback (most recent call last): File "/usr/lib/python2.7/threading.py", line 801, in bootstrap_inner self.run() File "/usr/lib/python2.7/threading.py", line 754, in run self.target(*self.args, **self.__kwargs) File "/home/sabolcik/.local/lib/python2.7/site-packages/micasaverde_vera/init.py", line 577, in _data_handler self.update(self.devices, 'devices', data) File "/home/sabolcik/.local/lib/python2.7/site-packages/micasaverde_vera/init.py", line 465, in update obj.update_node(data.pop(key, None), True) File "/home/sabolcik/.local/lib/python2.7/site-packages/micasaverde_vera/devices.py", line 119, in update_node found_device.update_node(device, full) File "/home/sabolcik/.MiCasaVerde_Vera/core/devices/binary_light_1.py", line 464, in update_node state['service'] File "/home/sabolcik/.MiCasaVerde_Vera/core/devices/binary_light_1.py", line 452, in check_value variable.replace('.', '') File "/home/sabolcik/.local/lib/python2.7/site-packages/micasaverde_vera/event.py", line 51, in notify event_handler.event_object = event_object File "/home/sabolcik/.local/lib/python2.7/site-packages/micasaverde_vera/event.py", line 79, in event_object self.__callback(self) File "", line 125, in device_callback File "/usr/local/lib/python2.7/dist-packages/neurio/init__.py", line 412, in get_local_current_sample r = requests.get(url, headers=headers) File "/usr/local/lib/python2.7/dist-packages/requests/api.py", line 72, in get return request('get', url, params=params, kwargs) File "/usr/local/lib/python2.7/dist-packages/requests/api.py", line 58, in request return session.request(method=method, url=url, kwargs) File "/usr/local/lib/python2.7/dist-packages/requests/sessions.py", line 508, in request resp = self.send(prep, send_kwargs) File "/usr/local/lib/python2.7/dist-packages/requests/sessions.py", line 618, in send r = adapter.send(request, kwargs) File "/usr/local/lib/python2.7/dist-packages/requests/adapters.py", line 490, in send raise ConnectionError(err, request=request) ConnectionError: ('Connection aborted.', error(104, 'Connection reset by peer'))

I organized the traceback so you can read it easier. But each step through the traceback is a stack trace. if you follow the stacktrace down the list you will see that the error happens inside of the callback from a requests connection error.

def callback(event):
    try:
        # do your code here
        pass
    except Exception:
        import traceback
        traceback.print_exc()

this will print out the traceback but not cause your program to stall if you want to output it to a file

def callback(event):
    try:
        # do your code here
        pass
    except Exception:
        import traceback
        with open(r'Some\Error\File\Location\error.log', 'a') as f:
            f.write('\n' + traceback.format_exc() + '\n')
sabolcik commented 6 years ago

Thanks for the feedback Kevin.

Regarding the comment about checking out the code does that mean like using a revision control tool I can check out the library from github or are you referring that I can use pip or some other package manager to grab it? Relatively new to github so I am still getting my arms around the etiquette and usage.

I did confirm that the event filtering now works with "devices.*.Watts.*" and "devices.*.CurrentTemperature.*".

After further parsing the trace back I did notice the exception was entirely tied to my Neurio and did a try except block. The traceback functionality was not something I had read up on that will be very useful.

I just checked my grafana website and the vera library is still chugging away and logging wattage.

Will continue to beat on the library and let you know if I find anything that behaves unexpectedly or have any further suggestions. Thanks again for the great support, python advice, and patience.

kdschlosser commented 6 years ago

what i mean by check out the files. is that when you run connect to the vera for the first time is this library will read information from the vera from a variety of ways. I have developed a way to use this information to write code dynamically. The benefit from this is the library is able to work with almost any plugin/device for the vera.. current and future, because the library is technically speaking tailored to your vera and what you have installed on it.

those generated python files are located in the directory i provided above. so if you want to know what variables are available. or what functions can be called on a device that is where you can do some poking about.

kdschlosser commented 6 years ago

I wanted to know how you are making out with this and is everything working ok for ya?

sabolcik commented 6 years ago

So far so good.

I have added some other data sources to my logger (Nest thermostat, whole house energy monitor) and those devices (which are not under the control of the Vera) have crashed a few times preventing me from a long continuous run with the Vera. The Vera library itself seems solid. I haven't had any crashes with it.

At one point I thought there was a problem with the library because it was reporting energy usage for a device I was certain was turned off. But when I checked that device it turns out it was actually on.

Thanks for the quick turnaround on the library and the very useful tool. I'll close out this issue.

kdschlosser commented 6 years ago

no worries m8. you should be able to begin the process of removing scenes form the Vera to lighten the load on it. it is much easier to code them up using this library and some python scripting. And you can use the example I gave that is a kind of a console for it. I may build in some kind of a GUI into it.

Once i figure out the device creation ends of things it will really open the doors up. because any device API that is written for python can end up being a device on the vera.