Saturday, 7 February 2015

Fixing LightwaveRF UDP Power Measurements

The thing that got me into this Geek blogging lark was a challenge from an old boss to look into how home automation equipment works.  This culminated in a posting on how to take power measurements on a Raspberry Pi and post them to an online measurements logging site (COSM, now called Xively).

Those measurements were happily up, working and logging for over 3 years until they abruptly stopped working towards the end of last year.  Looking at the LightwaveRF control unit (the so called WiFi link) the firmware version is now 2.91Q.  A bit of interweb searching tells me that this version was introduced at some point in late 2014 and I'm guessing it's that which has caused the problem.  (In an old posting I noticed that I had version 2.28).

It's taken me a while to get round to it  but I've finally investigated and fixed the problem that stopped the measurements working.  Here's what I did...

Step 1 was to check the IP address used for the LightwaveRF control unit.  Reminder: the way to get measurements is to send the string "123,@?\0" in a UDP segment to port 9760 on  the IP address that the LightwaveRF control unit sits on.  The response comes back on port 9761.

The IP address of the LightwaveRF control unit is defined as a constant in my script so I had to make sure that the one I had defined was still the correct one.  A quick check of my router "LAN IP Address" settings (which means the same IP address is always allocated to the same MAC address) showed that it was all OK.

Step 2 was to use tcpdump to work out what was going on on my LAN between my Raspberry Pi and the LightwaveRF control unit.

The command sudo tcpdump -n -i any -s0 -vv -X host 192.168.0.2 means:

"-n" means don't resolve addresses, "-i any" means any interface, "-s0" means all the packet, "-vv" means very verbose, "-X" means give us the full packet.

The log I got was:

15:31:24.446184 IP (tos 0x0, ttl 64, id 3918, offset 0, flags [DF], proto UDP (17), length 35)
    192.168.0.5.46246 > 192.168.0.2.9760: [udp sum ok] UDP, length 7
        0x0000:  4500 0023 0f4e 4000 4011 aa24 c0a8 0005  E..#.N@.@..$....
        0x0010:  c0a8 0002 b4a6 2620 000f ff13 3132 332c  ......&.....123,
        0x0020:  403f 00                                  @?.
15:31:24.651793 IP (tos 0x0, ttl 100, id 63682, offset 0, flags [none], proto UDP (17), length 56)
    192.168.0.2.9760 > 255.255.255.255.9761: [udp sum ok] UDP, length 28
        0x0000:  4500 0038 f8c2 0000 6411 9d48 c0a8 0002  E..8....d..H....
        0x0010:  ffff ffff 2620 2621 0024 38ed 3132 332c  ....&.&!.$8.123,
        0x0020:  3f57 3d35 3739 2c39 3536 312c 3632 3531  ?W=579,9561,6251
        0x0030:  2c35 3630 343b 0d0a                      ,5604;..
15:31:27.110984 IP (tos 0x0, ttl 100, id 63683, offset 0, flags [none], proto UDP (17), length 196)
    192.168.0.2.4096 > 255.255.255.255.9761: [udp sum ok] UDP, length 168
        0x0000:  4500 00c4 f8c3 0000 6411 9cbb c0a8 0002  E.......d.......
        0x0010:  ffff ffff 1000 2621 00b0 a208 2a21 7b22  ......&!....*!{"
        0x0020:  7472 616e 7322 3a32 3631 3335 362c 226d  trans":261356,"m
        0x0030:  6163 223a 2230 333a 3031 3a35 4222 2c22  ac":"03:01:5B","
        0x0040:  7469 6d65 223a 3134 3232 3830 3436 3836  time":1422804686
        0x0050:  2c22 7072 6f64 223a 2270 7772 4d74 7222  ,"prod":"pwrMtr"
        0x0060:  2c22 7365 7269 616c 223a 2242 4332 4246  ,"serial":"BC2BF
        0x0070:  4522 2c22 7369 676e 616c 223a 3535 2c22  E","signal":55,"
        0x0080:  7479 7065 223a 2265 6e65 7267 7922 2c22  type":"energy","
        0x0090:  6355 7365 223a 3537 372c 226d 6178 5573  cUse":577,"maxUs
        0x00a0:  6522 3a39 3536 312c 2274 6f64 5573 6522  e":9561,"todUse"
        0x00b0:  3a36 3235 332c 2279 6573 5573 6522 3a35  :6253,"yesUse":5
        0x00c0:  3630 347d                                604}

The first packet is the command sent from my Python script.

The second and third packets are from the LightwaveRF control unit.  There are two points to notice:

1)The response is now sent to 255.255.255.255, the zero network broadcast address.  I assume that this means you can have several hosts on the same network logging and broadcasting their results.

2)There is now two responses from the control unit.  One looks to be in the same format as before (four comma separated values) and the other looks to be some longer format that needs investigating.

However what I also spotted was that the responses in the new format seem to come without me actually sending the "123,@?\0" string.  This was puzzling until I realised that the control unit was broadcasting out measurements without being prompted, i.e. without me sending anything in the first place.  A simpler tcpdump shows:

pi@raspberrypi ~/lightwaverf $ sudo tcpdump -n -i any -s0 host 192.168.0.2
tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
listening on any, link-type LINUX_SLL (Linux cooked), capture size 65535 bytes
18:26:36.135825 IP 192.168.0.2.4096 > 255.255.255.255.9761: UDP, length 169
18:26:51.291677 IP 192.168.0.2.4096 > 255.255.255.255.9761: UDP, length 169
18:27:06.344437 IP 192.168.0.2.4096 > 255.255.255.255.9761: UDP, length 169
18:27:21.501676 IP 192.168.0.2.4096 > 255.255.255.255.9761: UDP, length 169
18:27:36.553111 IP 192.168.0.2.4096 > 255.255.255.255.9761: UDP, length 169
18:27:51.708639 IP 192.168.0.2.4096 > 255.255.255.255.9761: UDP, length 169
18:28:06.761778 IP 192.168.0.2.4096 > 255.255.255.255.9761: UDP, length 169
18:28:21.917158 IP 192.168.0.2.4096 > 255.255.255.255.9761: UDP, length 169

Here you can see a measurement being broadcast every 15 seconds.

So these are the problems that need fixing....

Problem 1 was easy to fix.  Changing a constant to:

UDP_IP = "255.255.255.255"

Means that when these commands are run:

sock = socket.socket(socket.AF_INET, socket.SOCK_DGRAM) # UDP
sock.bind((UDP_IP, UDP_PORT))

...the script binds to 255.255.255.255 to capture the response.

Problem 2 was a bit harder to fix.  Capturing and printing the new string showed it to be of this format:

*!"trans":261534,"mac":"03:01:5B","time":1422813309,"prod":"pwrMtr","serial":"BC2BFE","signal":55,"type":"energy","cUse":1504,"maxUse":9561,"todUse":7696,"yesUse":5604}

So a series of comma and colon separated values.  The initial values look to be useful metadata (e.g. MAC address, power meter etc) which would be useful in a multi-measurement, multi-unit environment.  However for me it's just the last 4 elements I need (current power, max power used today, cumulative today and cumulative yesterday).

I updated the code to remove the old measurement handling statements and to interpret the new measurement types.

The code below is the key new element added.  I also removed the code handling the old response format.  As the control unit just broadcasts energy measurements I no longer have to run a script to poll for information.  This should make the overall system more reliable...

#Put result into an array and get rid of the superfluous bits
      ResultArray = data.split(',')
      MeasurementCSV = TrimAndTidy(ResultArray[7]) + ',' + TrimAndTidy(ResultArray[8]) + ',' + TrimAndTidy(ResultArray[9]) + ',' + TrimAndTidy(ResultArray[10])
      print 'Measurement CSV >>> ' + MeasurementCSV

Here I simple split the string into parts (based upon the comma) and then send it to a tidy up function.  This is a simple piece of code:

def TrimAndTidy(InputString):
  #First split based upon the : and then remove a }
  try:
    ArrayOfVals = InputString.split(':')
    return ArrayOfVals[1].replace('}','')
  except:  #Just return a zero
    return '0'

That simply splits based upon the colon and cleans up the extra } at the end of the response string.

As an aside, one of the thing the code does is log to a local log file (in CSV format).  The log file is 32Meg in size and will have several hundred thousand rows of data it.  I smell some excellent geek action analysing those files to look for trends....

Here it is working again, huzzah!



...and here's all the code:

#v1=Just Watts measurement.  V2=Added other4 values.  V3=Added  GBP values.  V4=Added errorlogging.  V5=Handled lightwaverf response format changes
#V6=Removed old methodology

#Change IP address un comment chmod before putting on the phone "server"

#Import statements
import socket
import datetime
from os import chdir
import httplib
import sys

#Some constants for this, the server (192.168.0.5)
UDP_IP = "255.255.255.255" #Changed 31/01/2015 when Lightwaverf box started sending responses to broadcast address
UDP_PORT = 9761            #Responses always sent to this port

#These are constants related to the COSM feed
TimeZoneOffset = "+00:00"
MyFeedID = "YOUR_ID_HERE"
MyWattsNowAPIKey = "YOUR_KEY_HERE"
MyWattsCostAPIKey ="YOUR_KEY_HERE"
MyWattsNowDataStream = "WattsNow"
MyMaxWattsDataStream = "WattsNow_Max"
MyCumulativeWattsDataStream = "WattsNow_Cumulative"
MyYesterdayTotalDataStream = "WattsNow_TotalYesterday"
MyCumulativeCostDataStream = "WattsNow_CostToday"
MyCostYesterdayDataStream = "WattsNow_CostYesterday"


#Constants related to costs
UnitCost =11.68
DailyCost = 18.00

#This is a Python function that writes a log file.  Used for debugging purposes
def WriteDebugLog(StrToLog):
  #Form a date and time for this
  #Get the date and time
  DateToday = datetime.date.today()
  TimeNow = datetime.datetime.now()

  #Form the string we will write to screen and local file
  LogFileString = str(DateToday) + "," + str(TimeNow) + "," + StrToLog


  #And log to file.  "a" means append if necessary
  #COMMENT OUT THE 3 ROWS BELOW ELSE UNLESS YOU NEED THE LOG
  logfile = open("energy_measurements_log_file.txt", "a")
  logfile.write(LogFileString + "\n")
  logfile.close()
  return

#This is a Python function to log to COSM
def SendToCOSM(ValToSend,KeyToUse,FeedToUse,DataStreamToUse):
  #Use this try statement to capture errors
  try:
    #Write to our debug log file
    WriteDebugLog("Start of write to COSM Function. " + DataStreamToUse)

    #First form the string to send.  Here be an example '2012-09-30T22:00:00.676045+01:00,66'
    #So we need some date geekery for this
    #Get a variable to hold the date
    today = datetime.datetime.now()

    #Create an overall string with the story so far
    MyDateTimeString = today.strftime("%Y-%m-%d") + "T"

    #Now for the time bit - First the format string
    FormattedTime = today.strftime("%H:%M:%S")    #Get the formatted time

    #Now form the full monty string
    MyDateTimeString = MyDateTimeString + FormattedTime + TimeZoneOffset + "," + ValToSend

    #And get it's length
    MyStrLen = str(len(MyDateTimeString))

    #Print what we got so far
    print 'FullString:', MyDateTimeString

    #Now do the HTTP magic - Connect to the server
    h = httplib.HTTP('api.cosm.com')

    # build url we want to request
    FullURL = 'http://api.cosm.com/v2/feeds/'+ FeedToUse + '/datastreams/' + DataStreamToUse + '/datapoints.csv'

    #Print the URI string we will use
    print "Full URL: " + FullURL

    # POST our data.
    h.putrequest('POST',FullURL)

    # setup the user agent
    h.putheader('X-ApiKey',KeyToUse)
    h.putheader('Content-Length',MyStrLen)

    # we're done with the headers....
    h.endheaders()

    #Send the data
    h.send(MyDateTimeString)

    #Get the response from the request
    returncode, returnmsg,headers = h.getreply()

    #display whatever the results are....
    f = h.getfile()
    MyData = f.read()
    print f.read()

    #Write to our debug log file
    WriteDebugLog("End of write to COSM Function")

    #Now just return
    return
  #Catch an exception
  except Exception, err:
    #Write a log with the error
    print "Got us an exception: " + str(err)
    #WriteDebugLog("Caught this error in log to COSM function: " + str(err)

#This function calculates the cost in pounds for the electricity used.
#The formula is ((WattHours/ 1000) * (UnitCost / 100)) + (DailyCharge / 100)
def CalculateCosts(InWattHours):
  #WattHours comes in as a string so need to turn to a number

  #Added 26/10/2014 - First check InWattHours
  print "InWattHours: " + InWattHours

  if (";" in InWattHours):
    print "Caught a rogue InWattHours: " + InWattHours
    CostInPoundsFloat = "0"
  else:
    #do the calculation
    CostInPoundsFloat = ((float(InWattHours) / 1000) * (UnitCost / 100)) + (DailyCost / 100)

    #Round it to 2 decimal places
    CostInPoundsFloat = round(CostInPoundsFloat,2)

  #return a string
  return str(CostInPoundsFloat)

#New def added 01/02/2015 to handle the new format of command response.  Example
#*!{"trans":261395,"mac":"03:01:5B","time":1422806123,"prod":"pwrMtr","serial":"BC2BFE","signal":57,"type":"energy","cUse":809,"maxUse":9561,"todUse":6349,"yesUse":5604}
#Will get one of the pieces from within the commas.  Need to get the part after the colon and if required trim off a }
def TrimAndTidy(InputString):
  #First split based upon the : and then remove a }
  try:
    ArrayOfVals = InputString.split(':')
    return ArrayOfVals[1].replace('}','')
  except:  #Just return a zero
    return '0'

########################################
#Now we start the main part of the code
########################################


#Change directory that we will write to
chdir('/home/pi/lightwaverf')

#Tell the user we've started
print "UDP server started.  Waiting for response...."

#Bind a socket
sock = socket.socket(socket.AF_INET, socket.SOCK_DGRAM) # UDP
sock.bind((UDP_IP, UDP_PORT))

#Now just loop unit you receive a response
while True:
    #Read data from the buffer
    data, addr = sock.recvfrom(1024) #buffer size is 1024

    #Write to our debug log file
    WriteDebugLog("What we read from the buffer: " + data)

    #A debug print
    print 'I just read this >>> ' + data

    try:
      #Put result into an array and get rid of the superfluous bits
      ResultArray = data.split(',')
      MeasurementCSV = TrimAndTidy(ResultArray[7]) + ',' + TrimAndTidy(ResultArray[8]) + ',' + TrimAndTidy(ResultArray[9]) + ',' + TrimAndTidy(ResultArray[10])
      print 'Measurement CSV >>> ' + MeasurementCSV

      #Write to our debug log file
      WriteDebugLog("Just the measurements after removing the command prefix: " + MeasurementCSV)

      #Get the date and time
      today = datetime.date.today()
      TheTime = datetime.datetime.now()

      #Form the string we will write to screen and local file
      OutString = str(today) + "," + str(TheTime) + "," + MeasurementCSV

      #Print the result...
      print OutString

      #Write to our debug log file
      WriteDebugLog("The string that we will log to the log file: " + OutString)

      #And log to file.  "a" means append if necessary
      logfile = open("energy_measurements.csv", "a")
      logfile.write(OutString)
      logfile.close()

      #Write to our debug log file
      WriteDebugLog("Have just written the log file CSV")

      #Split the string and assign to variables
      SplitMeasurement = MeasurementCSV.split(',')
      WattsNow = SplitMeasurement[0]            #The power value for now (Watts)
      MaxWatts = SplitMeasurement[1]            #The max power today (Watts)
      CumToday = SplitMeasurement[2]            #Cumulative today (Watt Hours)
      TotalYesterday = SplitMeasurement[3]      #Total yesterday (Watt Hours)

      #Write to our debug log file
      WriteDebugLog("Have just split the string in 4")

      #Print the output
      print "Watts Now [W]:" + WattsNow
      print "Max Watts Today [W]:" + MaxWatts
      print "Cumulative Today [Wh]:" + CumToday
      print "Total Yesterday [Wh]:" + TotalYesterday

      #Write to our debug log file
      WriteDebugLog("Have just printed the measurements to screen")

      #Log to COSM dude!!! First check it's not 0 as that looks rubbish!
      if WattsNow == "0":
        print "Not sending as it's 0 Watts"

        #Write to our debug log file
        WriteDebugLog("Saw that the Watts measurement was 0 so didn't log to COSM")
      elif (WattsNow.isdigit() == False):
        print "Not sending as it's not a numeric Watts value"

        #Write to our debug log file
        WriteDebugLog("Saw that the Watts measurement was not a number so didn't log to COSM.  Measurement >> " + WattsNow)
      else:
        SendToCOSM(WattsNow,MyWattsNowAPIKey,MyFeedID,MyWattsNowDataStream)
        SendToCOSM(MaxWatts,MyWattsNowAPIKey,MyFeedID,MyMaxWattsDataStream)
        SendToCOSM(CumToday,MyWattsNowAPIKey,MyFeedID,MyCumulativeWattsDataStream)
        SendToCOSM(TotalYesterday,MyWattsNowAPIKey,MyFeedID,MyYesterdayTotalDataStream)

        #Write to our debug log file
        WriteDebugLog("Have just sent the 4 measurements to COSM.  Now calculate costs.")

        #Now calculate the costs
        CumulativeCost = CalculateCosts(CumToday)
        TotalYesterdayCost = CalculateCosts(TotalYesterday)

        print "Cumulative Cost GBP" + CumulativeCost
        print "TotalCost GBP" + TotalYesterdayCost

        #Write to our debug log file
        WriteDebugLog("Have calculated costs. Was cumulative GBP" + CumulativeCost + "and yesterday GBP" + TotalYesterdayCost + ". Now send to COSM")

        #Send them to COSM
        SendToCOSM(CumulativeCost,MyWattsCostAPIKey,MyFeedID,MyCumulativeCostDataStream)
        SendToCOSM(TotalYesterdayCost,MyWattsCostAPIKey,MyFeedID,MyCostYesterdayDataStream)

        #Write to our debug log file
        WriteDebugLog("Sent costs to COSM.")
    except Exception, err:
      #Write a log with the error
      print "Got us an exception: " + str(err)
      #WriteDebugLog("Caught this error in the main area of code: " + str(err)