Type Conversion / persistence issue?

(Stefan) #1
  • Platform information:
    • Hardware: Rpi3
    • OS: Openhabian (Raspbian GNU/Linux 9.9 (stretch))
    • Java Runtime Environment: openjdk version “1.8.0_152”
      OpenJDK Runtime Environment (Zulu Embedded 8.25.0.76-linux-aarch32hf) (build 1.8.0_152-b76)
      OpenJDK Client VM (Zulu Embedded 8.25.0.76-linux-aarch32hf) (build 25.152-b76, mixed mode, Evaluation)
    • openHAB version: 2.4.0

I’ve been trying to setup the Washing Machine State System with Bouncy State Elimination using Persistence as written here.

items

Switch Wasmachine "Wasmachine"                                  <washingmachine>    (gWaskamer, gWitgoed)                           { mqtt=">[sonoff1:cmnd/sonoff_wasmachine/POWER:command:*:default], <[sonoff1:stat/sonoff_wasmachine/POWER:state:default]" }
Switch Droger "Droger"                                          <dryer>             (gWaskamer, gWitgoed)                           { mqtt=">[sonoff1:cmnd/sonoff_droger/POWER:command:*:default], <[sonoff1:stat/sonoff_droger/POWER:state:default]" }

Number Wasmachine_watt "Wasmachine verbruik [%.1f W]"                   <energy> (gVerbruik)        { mqtt="<[sonoff1:tele/sonoff_wasmachine/SENSOR:state:JSONPATH($.ENERGY.Power)]" }
Number Wasmachine_voltage "Wasmachine voltage [%d V]"			        <energy> (gVerbruik)        { mqtt="<[sonoff1:tele/sonoff_wasmachine/SENSOR:state:JSONPATH($.ENERGY.Voltage)]" }
Number Wasmachine_ampere "Wasmachine ampere [%.3f А]"			        <energy> (gVerbruik)		{ mqtt="<[sonoff1:tele/sonoff_wasmachine/SENSOR:state:JSONPATH($.ENERGY.Current)]" }
Number Wasmachine_today	"Wasmachine verbruik vandaag [%.3f kWh]"		<line> (gVerbruik)			{ mqtt="<[sonoff1:tele/sonoff_wasmachine/SENSOR:state:JSONPATH($.ENERGY.Today)]" }
Number Wasmachine_yesterday	"Wasmachine verbruik gisteren [%.3f kWh]"	<line> (gVerbruik)			{ mqtt="<[sonoff1:tele/sonoff_wasmachine/SENSOR:state:JSONPATH($.ENERGY.Yesterday)]" }
Number Wasmachine_total	"Wasmachine verbruik totaal [%.3f kWh]"	        <line> (gVerbruik)			{ mqtt="<[sonoff1:tele/sonoff_wasmachine/SENSOR:state:JSONPATH($.ENERGY.Total)]" }
Number Wasmachine_Status "Wasmachine Status [%d]"                       <washingmachine>
Number Droger_watt "Droger verbruik [%.1f W]"                           <energy> (gVerbruik)        { mqtt="<[sonoff1:tele/sonoff_droger/SENSOR:state:JSONPATH($.ENERGY.Power)]" }
Number Droger_voltage "Droger voltage [%d V]"			                <energy> (gVerbruik)		{ mqtt="<[sonoff1:tele/sonoff_droger/SENSOR:state:JSONPATH($.ENERGY.Voltage)]" }
Number Droger_ampere "Droger ampere [%.3f А]"			                <energy> (gVerbruik)		{ mqtt="<[sonoff1:tele/sonoff_droger/SENSOR:state:JSONPATH($.ENERGY.Current)]" }
Number Droger_today	"Droger vandaag [%.3f kWh]"			                <line> (gVerbruik)      	{ mqtt="<[sonoff1:tele/sonoff_droger/SENSOR:state:JSONPATH($.ENERGY.Today)]" } 
Number Droger_yesterday	"Droger gisteren [%.3f kWh]"	                <line> (gVerbruik)			{ mqtt="<[sonoff1:tele/sonoff_droger/SENSOR:state:JSONPATH($.ENERGY.Yesterday)]" }
Number Droger_total	"Droger gisteren [%.3f kWh]"	                    <line> (gVerbruik)			{ mqtt="<[sonoff1:tele/sonoff_droger/SENSOR:state:JSONPATH($.ENERGY.Total)]" }
Number Droger_Status "Droger Status [%d]"                               <dryer>

Rules

val Number MODE_OFF = 0
val Number MODE_STANDBY = 1
val Number MODE_ACTIVE = 2
val Number MODE_FINISHED = 3



rule "Wasmachine Consumption State Machine"
when
    Item Wasmachine_watt changed
then
    if ((Wasmachine_watt.averageSince(now.minusMinutes(2)) as Number) < 1) Wasmachine_Status.postUpdate(MODE_OFF)
    else if ((Wasmachine_watt.averageSince(now.minusMinutes(2)) as Number) > 10) Wasmachine_Status.postUpdate(MODE_ACTIVE)
    else if ((Wasmachine_watt.averageSince(now.minusMinutes(2)) as Number) < 4) {
        if (Wasmachine_Status.state == MODE_OFF) Wasmachine_Status.postUpdate(MODE_STANDBY)
        else if (Wasmachine_Status.state == MODE_ACTIVE) Wasmachine_Status.postUpdate(MODE_FINISHED)
    }
end

rule "Droger Consumption State Machine"
when
    Item Droger_watt changed
then
    //val Number nAvg = Droger_watt.averageSince(now.minusMinutes(2)) as Number
    //logInfo("nAvg value", "nAvg" + nAvg)
    if ((Droger_watt.averageSince(now.minusMinutes(2)) as Number) < 1) {
        logInfo("Verbruik", "Droger watt = " + (Droger_watt.averageSince(now.minusMinutes(2)) as Number))
        logInfo("Verbruik", "1 Drogerstatus = " + Droger_Status.state.toString + " " + Droger_watt.averageSince(now.minusMinutes(2)) + " " + Droger_watt.state.toString)
//Droger watt = null
//1 Drogerstatus = 0 null 1        
        Droger_Status.postUpdate(MODE_OFF)
    }
    else if ((Droger_watt.averageSince(now.minusMinutes(2)) as Number) > 100) {
        logInfo("Verbruik", "2 Drogerstatus = " + Droger_Status.state.toString)
        Droger_Status.postUpdate(MODE_ACTIVE)
    }
    else if ((Droger_watt.averageSince(now.minusMinutes(2)) as Number) < 3) {
        logInfo("Verbruik", "3 Drogerstatus = " + Droger_Status.state.toString)
            if (Droger_Status.state == MODE_OFF) {
                Droger_Status.postUpdate(MODE_STANDBY)
                logInfo("Verbruik", "4 Drogerstatus = " + Droger_Status.state.toString)
            } else if (Droger_Status.state == MODE_ACTIVE) {
                Droger_Status.postUpdate(MODE_FINISHED) 
                logInfo("Verbruik", "5 Drogerstatus = " + Droger_Status.state.toString)
            }
    }
end

jdbc is selected as default persistence service.

Droger_watt persistence using jdbc with mariadb:

The database gets filled, so why is Droger_watt.averageSince(now.minusMinutes(2)) as Number always returned as null?

It looks very similair as this post, but it was never resolved.
If I follow the instructions there this should work:
logInfo("Verbruik", "Droger watt = " + Droger_watt.averageSince(now.minusMinutes(2)).toString)

But I get this error:
Error: Rule 'Droger Consumption State Machine': cannot invoke method public java.lang.String org.eclipse.smarthome.core.library.types.DecimalType.toString() on null

The same error when I add as Number to that logInfo line.

I’ve been fighting with this code for a few hours, I don’t see it anymore. Who can help me?

NB the washingmachine part is also not working, I just added some extra logging to the dryer, both rules do the same.

0 Likes

(Rich Koshak) #2

I think averageSince returns a primitive float. What if you leave off all the casting a toStrings and just print it as is?

0 Likes

(Stefan) #3
rule "Wasmachine Consumption State Machine"
when
    Item Wasmachine_watt changed
then
    if ((Wasmachine_watt.averageSince(now.minusMinutes(2)) as Number) < 1) Wasmachine_Status.postUpdate(MODE_OFF)
    else if ((Wasmachine_watt.averageSince(now.minusMinutes(2)) as Number) > 10) Wasmachine_Status.postUpdate(MODE_ACTIVE)
    else if ((Wasmachine_watt.averageSince(now.minusMinutes(2)) as Number) < 4) {
        if (Wasmachine_Status.state == MODE_OFF) Wasmachine_Status.postUpdate(MODE_STANDBY)
        else if (Wasmachine_Status.state == MODE_ACTIVE) Wasmachine_Status.postUpdate(MODE_FINISHED)
    }
end

rule "Droger Consumption State Machine"
when
    Item Droger_watt changed
then
    //val Number nAvg = Droger_watt.averageSince(now.minusMinutes(2)) as Number
    //logInfo("nAvg value", "nAvg" + nAvg)
    if ((Droger_watt.averageSince(now.minusMinutes(2)) as Number) < 1) {
        logInfo("Verbruik", "Droger watt = " + Droger_watt.averageSince(now.minusMinutes(2)))
        logInfo("Verbruik", "Droger watt = " + (Droger_watt.averageSince(now.minusMinutes(2)) as Number))
        logInfo("Verbruik", "1 Drogerstatus = " + Droger_Status.state + " " + Droger_watt.averageSince(now.minusMinutes(2)) + " " + Droger_watt.state)      
        Droger_Status.postUpdate(MODE_OFF)
    }
    else if ((Droger_watt.averageSince(now.minusMinutes(2)) as Number) > 100) {
        logInfo("Verbruik", "2 Drogerstatus = " + Droger_Status.state)
        Droger_Status.postUpdate(MODE_ACTIVE)
    }
    else if ((Droger_watt.averageSince(now.minusMinutes(2)) as Number) < 3) {
        logInfo("Verbruik", "3 Drogerstatus = " + Droger_Status.state)
            if (Droger_Status.state == MODE_OFF) {
                Droger_Status.postUpdate(MODE_STANDBY)
                logInfo("Verbruik", "4 Drogerstatus = " + Droger_Status.state)
            } else if (Droger_Status.state == MODE_ACTIVE) {
                Droger_Status.postUpdate(MODE_FINISHED) 
                logInfo("Verbruik", "5 Drogerstatus = " + Droger_Status.state)
            }
    }
end

Log

2019-05-11 18:10:44.339 [INFO ] [ipse.smarthome.model.script.Verbruik] - Droger watt = null
2019-05-11 18:10:44.347 [INFO ] [ipse.smarthome.model.script.Verbruik] - Droger watt = null
2019-05-11 18:10:44.360 [INFO ] [ipse.smarthome.model.script.Verbruik] - 1 Drogerstatus = 0 null 502
0 Likes

(Rich Koshak) #4

Ok, now we know for sure that the call is in fact returning null. Unfortunately, type errors also generate a null error so tested like this have to be performed to tell the difference.

Since you’ve shown that data is in the database all I can recommend is to for an issue. See How to file an Issue.

I think this would be in the core but I’m not positive.

0 Likes

(Stefan) #5

OK thanks, I’ll open an issue in core.

0 Likes

(Udo Hartmann) #6

Which persistence do you use? jdbc or mariadb? Did you setup the persistence service as default persistence service yet?

0 Likes

(Stefan) #7

I use JDBC, which stores it data in a mariadb:

jdbc.cfg

############################ JDBC Persistence Service ##################################
# I N S T A L L   J D B C   P E R S I S T E N C E   S E R V I C E 
#
# https://github.com/openhab/openhab/wiki/JDBC-Persistence
#
# Tested databases/url-prefix: jdbc:derby, jdbc:h2, jdbc:hsqldb, jdbc:mariadb, jdbc:mysql, jdbc:postgresql, jdbc:sqlite
# 
# derby, h2, hsqldb, sqlite can be embedded, 
# If no database is available it will be created, for example the url 'jdbc:h2:./testH2' creates a new DB in OpenHab Folder. 
#
# Create new database, for example on a MySQL-Server use: 
# CREATE DATABASE 'yourDB' CHARACTER SET utf8 COLLATE utf8_general_ci;

# D A T A B A S E  C O N F I G
# Some URL-Examples, 'service' identifies and activates internally the correct jdbc driver.
# required database url like 'jdbc:<service>:<host>[:<port>;<attributes>]'
# url=jdbc:derby:./testDerby;create=true
# url=jdbc:h2:./testH2
# url=jdbc:hsqldb:./testHsqlDb
# url=jdbc:mariadb://192.168.0.1:3306/testMariadb
# url=jdbc:mysql://192.168.0.1:3306/testMysql
# url=jdbc:postgresql://192.168.0.1:5432/testPostgresql
# url=jdbc:sqlite:./testSqlite.db
# url=jdbc:mariadb://10.0.0.173:3306/OpenHAB
url=jdbc:mariadb://10.0.0.173:3306/OpenHAB2019

# required database user
user=openhab

# required database password
password=xxx

# E R R O R   H A N D L I N G
# optional when Service is deactivated (optional, default: 0 -> ignore) 
#errReconnectThreshold=

# I T E M   O P E R A T I O N S
# optional tweaking SQL datatypes
# see: https://mybatis.github.io/mybatis-3/apidocs/reference/org/apache/ibatis/type/JdbcType.html   
# see: http://www.h2database.com/html/datatypes.html
# see: http://www.postgresql.org/docs/9.3/static/datatype.html
# defaults:
#sqltype.CALL          =   VARCHAR(200)
#sqltype.COLOR         =   VARCHAR(70)
#sqltype.CONTACT       =   VARCHAR(6)
#sqltype.DATETIME      =   DATETIME
#sqltype.DIMMER        =   TINYINT
#sqltype.LOCATION      =   VARCHAR(30)
#sqltype.NUMBER        =   DOUBLE
#sqltype.ROLLERSHUTTER =   TINYINT
#sqltype.STRING        =   VARCHAR(65500)
#sqltype.SWITCH        =   VARCHAR(6)

# For Itemtype "Number" default decimal digit count (optional, default: 3) 
#numberDecimalcount=

# T A B L E   O P E R A T I O N S
# Tablename Prefix String (optional, default: "item") 
# for Migration from MYSQL-Bundle set to 'Item'.
#tableNamePrefix=item

# Tablename Prefix generation, using Item real names or "item" (optional, default: false -> "item") 
# If true, 'tableNamePrefix' is ignored.
tableUseRealItemNames=false

# Tablename Suffix length (optional, default: 4 -> 0001-9999) 
# for Migration from MYSQL-Bundle set to 0.
#tableIdDigitCount=

# Rename existing Tables using tableUseRealItemNames and tableIdDigitCount (optional, default: false) 
# USE WITH CARE! Deactivate after Renaming is done!
#rebuildTableNames=false

# D A T A B A S E  C O N N E C T I O N S
# Some embeded Databases can handle only one Connection (optional, default: configured per database in packet org.openhab.persistence.jdbc.db.* )
# see: https://github.com/brettwooldridge/HikariCP/issues/256
# jdbc.maximumPoolSize = 1
# jdbc.minimumIdle = 1

# T I M E K E E P I N G
# (optional, default: false) 
#enableLogTime=true
#Manual options
# See https://community.openhab.org/t/jdbc-mariadb-problem-persisting-string-items/39774
#sqltype.STRING        =   VARCHAR(4096)

image

0 Likes

(Stefan) #8

For reference: https://github.com/openhab/openhab-core/issues/816

0 Likes

(Scott Rushworth) #9

I just saw your issue posted in GH and I do not think this is a bug. I use jdbc for persistence with MariaDB, and this works for me…

logWarn("Rules", "test [{}]", HEM1_Total_Power.averageSince(now.minusMinutes(5)))

Please save this into a rule file and check the log to see if you get the same result. If so, you should double check that your Item is actually being persisted. Maybe your default persistence is set to something other than jdbc?

rule "Test"
when
    System started
then
    logWarn("Rules", "Test: Start")
    logWarn("Rules", "lastUpdate [{}]", Droger_watt.lastUpdate)
    logWarn("Rules", "changedSince [{}]", Droger_watt.changedSince(now.minusMinutes(5)))
    logWarn("Rules", "averageSince [{}]", Droger_watt.averageSince(now.minusMinutes(5)))
    logWarn("Rules", "Test: End")
end
1 Like

(Stefan) #10
2019-05-13 20:37:40.507 [WARN ] [eclipse.smarthome.model.script.Rules] - Test: Start
2019-05-13 20:37:40.514 [WARN ] [eclipse.smarthome.model.script.Rules] - lastUpdate [2019-05-13T18:35:00.400+02:00]
2019-05-13 20:37:40.524 [WARN ] [eclipse.smarthome.model.script.Rules] - changedSince [false]
2019-05-13 20:37:40.530 [WARN ] [eclipse.smarthome.model.script.Rules] - averageSince [{}]
2019-05-13 20:37:40.533 [WARN ] [eclipse.smarthome.model.script.Rules] - Test: End

My jdbc.persist is quite simple:

// persistence strategies have a name and a definition and are referred to in the "Items" section
Strategies {
    // if no strategy is specified for an item entry below, the default list will be used
    everyMinute	: "0 * * * * ?"
    every5Minutes : "0 */5 * * * ?"
    everyHour   : "0 0 * * * ?"
    everyDay    : "0 0 0 * * ?"
    default = everyChange
}

/* 
 * Each line in this section defines for which item(s) which strategy(ies) should be applied.
 * You can list single items, use "*" for all items or "groupitem*" for all members of a group
 * item (excl. the group item itself).
 */

Items {
    * : strategy = everyChange, every5Minutes, restoreOnStartup
}

JDBC is my default persistence service:

image

0 Likes

(Scott Rushworth) #11

That test wasn’t valid :slightly_frowning_face:. When an Item’s state hasn’t changed, averageSince will return null because there is no persisted data within that time interval. I misspoke before, because persistence is not in openhab-core, but we’re talking about PersistenceExtensions which are. So your issue is in the right repo to request that the current value be included in averageSince. After a brief look at the code, I believe this functionality could be added by simply changing this line to return the current value instead of null.

Your rule is triggering on change, so you’d expect that this wouldn’t be an issue, but persistence takes some time after a change to write to the database. So it is possible that the value has not been persisted before the commands in the rule are executed. Based on your persistence data, this could occasionally be making the interval since the last change larger than 2 minutes and causing the error. I think it would be better to use maximumSince, because it does not return null if the Item hasn’t changed. Although, if you really want to use averageSince, you could try changing the interval to 3 minutes or add an every1Minute strategy. In either case, you should add handling of null values.

For our power monitoring rules, I use a timer for debouncing the values (no persistence needed).

1 Like

(Stefan) #12

I did some additional testing (specifically specify jdbc and change 2 to 3 minutes):

rule "Droger Consumption State Machine"
when
    Item Droger_watt changed
then
    if ((Droger_watt.averageSince(now.minusMinutes(3), "jdbc")as Number) == null) {
      logWarn("Rules", "Test: Start")
      logWarn("Rules", "lastUpdate [{}]", Droger_watt.lastUpdate)
      logWarn("Rules", "changedSince [{}]", Droger_watt.changedSince(now.minusMinutes(5), "jdbc"))
      logWarn("Rules", "averageSince [{}]", Droger_watt.averageSince(now.minusMinutes(5), "jdbc"))
      logWarn("Rules", "Test: End")
    return;
    }
    //val Number nAvg = Droger_watt.averageSince(now.minusMinutes(3)) as Number
    //logInfo("nAvg value", "nAvg" + nAvg)
    if (((Droger_watt.averageSince(now.minusMinutes(3), "jdbc")) as Number) < 1) {
        //logInfo("Verbruik", "Droger watt = " + Droger_watt.averageSince(now.minusMinutes(3)) + PowerAverage)
        logInfo("Verbruik", "Droger watt = " + (Droger_watt.averageSince(now.minusMinutes(3), "jdbc") as Number))
        logInfo("Verbruik", "1 Drogerstatus = " + Droger_Status.state + " " + Droger_watt.averageSince(now.minusMinutes(3), "jdbc") + " " + Droger_watt.state)      
        Droger_Status.postUpdate(MODE_OFF)
    }
    else if ((Droger_watt.averageSince(now.minusMinutes(3), "jdbc") as Number) > 100) {
        logInfo("Verbruik", "2 Drogerstatus = " + Droger_Status.state)
        Droger_Status.postUpdate(MODE_ACTIVE)
    }
    else if ((Droger_watt.averageSince(now.minusMinutes(3), "jdbc") as Number) < 3) {
        logInfo("Verbruik", "3 Drogerstatus = " + Droger_Status.state)
            if (Droger_Status.state == MODE_OFF) {
                Droger_Status.postUpdate(MODE_STANDBY)
                logInfo("Verbruik", "4 Drogerstatus = " + Droger_Status.state)
            } else if (Droger_Status.state == MODE_ACTIVE) {
                Droger_Status.postUpdate(MODE_FINISHED) 
                logInfo("Verbruik", "5 Drogerstatus = " + Droger_Status.state)
            }
    }
end

Still failure:

2019-05-14 17:31:55.870 [WARN ] [eclipse.smarthome.model.script.Rules] - Test: Start
2019-05-14 17:31:55.877 [WARN ] [eclipse.smarthome.model.script.Rules] - lastUpdate [2019-05-14T15:31:55.844+02:00]
2019-05-14 17:31:55.888 [WARN ] [eclipse.smarthome.model.script.Rules] - changedSince [false]
2019-05-14 17:31:55.895 [WARN ] [eclipse.smarthome.model.script.Rules] - averageSince [{}]
2019-05-14 17:31:55.898 [WARN ] [eclipse.smarthome.model.script.Rules] - Test: End

When I change my persistence to RRD4J it works:

2019-05-14 17:32:07.727 [WARN ] [eclipse.smarthome.model.script.Rules] - Test: Start
2019-05-14 17:32:07.744 [WARN ] [eclipse.smarthome.model.script.Rules] - lastUpdate [2019-05-14T17:32:00.000+02:00]
2019-05-14 17:32:07.776 [WARN ] [eclipse.smarthome.model.script.Rules] - changedSince [true]
2019-05-14 17:32:07.790 [WARN ] [eclipse.smarthome.model.script.Rules] - averageSince [0.8072691558751039]
2019-05-14 17:32:07.796 [WARN ] [eclipse.smarthome.model.script.Rules] - Test: End

What I do notice now:

jdbc: 2019-05-14 17:31:55.877 - lastUpdate [2019-05-14T15:31:55.844+02:00]

rrd4j: 2019-05-14 17:32:07.727 - lastUpdate [2019-05-14T17:32:00.000+02:00]

Should i read the +02:00 as this time is displayed with an +2 hour offset, or as this time should add +2 hour offset? If jdbc is incorrect, could this be causing the averageSince to fail?

0 Likes

(Scott Rushworth) #13

The +02:00 is the UTC offset… your time is 2 hours later than UTC, so subtract 2 from your local time to get UTC.

This could absolutely be causing averageSince to return null. Since the log entry shows the correct offset, it looks like your database is using system time and the clock is set to the wrong time. I would just go check that, but if you want to dig deeper, on the server running MariaDB, run…

mysql -u root -p
show GLOBAL VARIABLES like 'time_zone';

If time_zone comes up as SYSTEM, your system clock is incorrect. If it comes up as something other than your timezone or SYSTEM, you’ll need to find out how/where it got changed and correct it.

0 Likes

(Stefan) #14

Yep that did the trick. Apparently LXC containers default to the UTC timezone. I never noticed. I changed the default profile to use my timezone, reset the timezone on all my containers, removed rrd4j persistence and issue resolved:

2019-05-14 20:29:21.280 [INFO ] [ipse.smarthome.model.script.Verbruik] - Droger watt = 0.5003822051979907
2019-05-14 20:29:21.297 [INFO ] [ipse.smarthome.model.script.Verbruik] - 1 Drogerstatus = 0 0.5004493457190371 1

Thank you for your help and expertise @5iver! I’ll close the GH issue.

1 Like

(Rich Koshak) #15

This is true of most containers as far as I am aware. At least with Docker containers the standard is to pass in the /etc/timezone and /etc/localtime from the host into the container (read only) so that the time settings inside the container matches the host.

0 Likes