Updated to #1600, and averageSince seems to work again.
Thx @J-N-K
Ok. With #1600 my version should work.
I’ll check the #1600 and when its all working again i’ll come back to the averageSince in detail
1 Like
averageSince is not working…
2019-05-26 17:32:11.671 [INFO ] [.smarthome.model.script.Betrieb.rule] - Verbrauch Kühlschrank Durchschnitt: -0.4727427382590133
mysql> select avg(value) from item0041 where time >= ‘2019-05-26 16:33:00’ and time <= ‘2019-05-26 17:33:00’;
±-----------+
| avg(value) |
±-----------+
| 15.3125 |
±-----------+
1 row in set (0.00 sec)
| 2019-05-26 16:34:49 | 122.5 |
| 2019-05-26 16:35:18 | 0 |
| 2019-05-26 16:40:05 | 0 |
| 2019-05-26 16:50:04 | 0 |
| 2019-05-26 17:00:06 | 0 |
| 2019-05-26 17:10:05 | 0 |
| 2019-05-26 17:20:04 | 0 |
| 2019-05-26 17:30:03 | 0 |
164 x Active x 80 x 2.5.0.201905250306 x org.openhab.core.model.persistence
165 x Active x 80 x 2.5.0.201905250326 x org.openhab.core.model.persistence.ide
166 x Active x 80 x 2.5.0.201905250330 x org.openhab.core.model.persistence.runtime
179 x Active x 80 x 2.5.0.201905250305 x org.openhab.core.persistence
250 x Active x 80 x 1.14.0.201905210308 x org.openhab.persistence.jdbc
After update its waiting:
164 x Waiting x 80 x 2.5.0.201905261232 x org.openhab.core.model.persistence
165 x Active x 80 x 2.5.0.201905250326 x org.openhab.core.model.persistence.ide
166 x Active x 80 x 2.5.0.201905250330 x org.openhab.core.model.persistence.runtime
179 x Active x 80 x 2.5.0.201905250305 x org.openhab.core.persistence
250 x Active x 80 x 1.14.0.201905210308 x org.openhab.persistence.jdbc
After restart it is “Active”:
164 x Active x 80 x 2.5.0.201905261232 x org.openhab.core.model.persistence
165 x Active x 80 x 2.5.0.201905250326 x org.openhab.core.model.persistence.ide
166 x Active x 80 x 2.5.0.201905250330 x org.openhab.core.model.persistence.runtime
179 x Active x 80 x 2.5.0.201905250305 x org.openhab.core.persistence
250 x Active x 80 x 1.14.0.201905210308 x org.openhab.persistence.jdbc
That looks good so far. Now please enable the logging and show what happens.
2019-05-26 17:49:00.039 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558889404000, value: 0.0
2019-05-26 17:49:00.039 [TRACE] [nce.extensions.PersistenceExtensions] - first TS: 1558889404000
2019-05-26 17:49:00.040 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558890006000, value: 0.0
2019-05-26 17:49:00.040 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558890605000, value: 0.0
2019-05-26 17:49:00.041 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558891204000, value: 0.0
2019-05-26 17:49:00.045 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558891803000, value: 0.0
2019-05-26 17:49:00.045 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558892019000, value: 142.3000030517578
2019-05-26 17:49:00.046 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558892089000, value: 128.10000610351562
2019-05-26 17:49:00.046 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558892857000, value: 126.69999694824219
2019-05-26 17:49:00.049 [TRACE] [nce.extensions.PersistenceExtensions] - last TS: 1558885740049, value: 126.69999694824219
2019-05-26 17:49:00.050 [INFO ] [.smarthome.model.script.Betrieb.rule] - Verbrauch Kühlschrank Durchschnitt: 212.6234952811568
That’s what I expected. Haave a look at the first TS and the last TS: 1558889404000 and 1558885740049. The last timestamp is smaller than the first one.
1558889404 is equivalent to 26.05.2019 - 18:50:04 (UTC+1)
1558885740 is equivalent to 26.05.2019 - 17:49:00 (UTC+1)
Which time zone are you in? I guess the last one is correct and the first one should in fact be 16:50. Since that is in the Database, There seems to be a bug in the conversion of the database-timestamp to the unix time-stamp.
openHab should be running in
EXTRA_JAVA_OPTS: “-Duser.timezone=Europe/Berlin”
you are right, the first should be 16:50
any idea what i can do?
Can you try SELECT @@session.time_zone;? Does that show “Europe/Berlin”,too? And what about SELECT @@global.time_zone;?
mysql> SELECT @@session.time_zone;
±--------------------+
| @@session.time_zone |
±--------------------+
| SYSTEM |
±--------------------+
1 row in set (0.00 sec)
mysql> SELECT @@global.time_zone;
±-------------------+
| @@global.time_zone |
±-------------------+
| SYSTEM |
±-------------------+
1 row in set (0.00 sec)
Ok, thinking about it the problem seems to be:
- values are persisted with UTC+2 (CEST)
- the database stores them with UTC+2
- when queried, the stored values are returned as UTC+2
- the persistence service „thinks“ they are UTC and adds two hours
I‘m not sure where the problem is, i.e. if „by design“ it should store UTC and the conversion is ok or if the should be stored in local time and should not be converted when queried.
Documentation says:
When you insert a
TIMESTAMPvalue into a table, MySQL converts it from your connection’s time zone to UTC for storage. When you query aTIMESTAMPvalue, MySQL converts the UTC value back to your connection’s time zone. Notice that this conversion does not take place for other temporal data types such asDATETIME.
So it should be stored as UTC.
Why is the “first TS” wrong and the “last TS” correct?
The last timestamp is the current value, that is not read from the database but taken at the time of the average-calculation.
Is the value really stored as TIMESTAMP (in the MySQL-sense)? Or ist it a DATETIME? That your query above looks more like a DATETIME. If it is indeed DATETIME, MySQL does no conversion, that should happen before storing (or after querying) data by the client.
The persistence service (JDBC in your case) reads the database and delivers timestamp/value-pairs. Since the persistence service is an abstraction layer between the database and the persistence extensions (where averageSince is located) we cannot judge from the fact that the output is timestamp that the input is also timestamp, it could be anything.
mysql> SELECT DATA_TYPE FROM INFORMATION_SCHEMA.COLUMNS WHERE table_name = ‘item0041’ AND COLUMN_NAME = ‘time’;
±----------+
| DATA_TYPE |
±----------+
| timestamp |
±----------+
1 row in set (0.35 sec)
but maybe its a wrong configuration:
url=jdbc:mysql://ip:3306/openhab_db?useUnicode=true&useJDBCCompliantTimezoneShift=true&useLegacyDatetimeCode=false&serverTimezone=UTC
now its working again:
url=jdbc:mysql://ip:3306/openhab_db?useUnicode=true&useJDBCCompliantTimezoneShift=true&useLegacyDatetimeCode=false&serverTimezone=Europe/Vienna
2019-05-26 19:49:00.026 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558889405000, value: 0.0
2019-05-26 19:49:00.026 [TRACE] [nce.extensions.PersistenceExtensions] - first TS: 1558889405000
2019-05-26 19:49:00.026 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558890005000, value: 0.0
2019-05-26 19:49:00.027 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558890233000, value: 141.89999389648438
2019-05-26 19:49:00.027 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558890301000, value: 127.5999984741211
2019-05-26 19:49:00.027 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558890604000, value: 127.5999984741211
2019-05-26 19:49:00.027 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558891204000, value: 127.5999984741211
2019-05-26 19:49:00.027 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558891805000, value: 127.5999984741211
2019-05-26 19:49:00.027 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558892088000, value: 122.5
2019-05-26 19:49:00.027 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558892135000, value: 14.199999809265137
2019-05-26 19:49:00.027 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558892156000, value: 0.0
2019-05-26 19:49:00.028 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558892385000, value: 14.199999809265137
2019-05-26 19:49:00.028 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558892388000, value: 0.0
2019-05-26 19:49:00.028 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558892404000, value: 0.0
2019-05-26 19:49:00.028 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558892420000, value: 14.399999618530273
2019-05-26 19:49:00.028 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558892429000, value: 0.0
2019-05-26 19:49:00.029 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558892474000, value: 14.199999809265137
2019-05-26 19:49:00.029 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558892478000, value: 0.0
2019-05-26 19:49:00.029 [TRACE] [nce.extensions.PersistenceExtensions] - last TS: 1558892940029, value: 0.0
2019-05-26 19:49:00.029 [INFO ] [.smarthome.model.script.Betrieb.rule] - Verbrauch Kühlschrank Durchschnitt: 73.03357242498279
thx @J-N-K for all your help
1 Like
Glad you got it sorted out. You can just disable logging as mentioned above, The bundle will be updated to a standard bundle on the next update. It doesn’t hurt until then
the timestamps (first, last) now are ok, but the calculation seems wrong anyway…
2019-05-26 20:05:00.027 [DEBUG] [jdbc.internal.JdbcPersistenceService] - JDBC::query: item is Powermessurement_EG_Kuelschrank
2019-05-26 20:05:00.028 [DEBUG] [persistence.jdbc.internal.JdbcMapper] - JDBC::getHistItemFilterQuery filter=‘true’ numberDecimalcount=‘3’ table=‘item0041’ item=‘Powermessurement_EG_Kuelschrank (Type=NumberItem, State=0.0)’ itemName=‘Powermessurement_EG_Kuelschrank’
2019-05-26 20:05:00.028 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::getHistItemFilterQueryProvider filter = org.openhab.core.persistence.FilterCriteria@681cbf67, numberDecimalcount = 3, table = item0041, simpleName = Powermessurement_EG_Kuelschrank
2019-05-26 20:05:00.029 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::query queryString = SELECT time, value FROM item0041 WHERE TIME>‘2019-05-26 19:05:00’ ORDER BY time ASC
2019-05-26 20:05:00.029 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::doGetHistItemFilterQuery sql=SELECT time, value FROM item0041 WHERE TIME>‘2019-05-26 19:05:00’ ORDER BY time ASC
2019-05-26 20:05:00.030 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::ItemResultHandler::handleResult getState value = ‘127.5999984741211’, getClass = ‘class java.lang.Double’, clazz = ‘Double’
2019-05-26 20:05:00.030 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::ItemResultHandler::handleResult getState value = ‘127.5999984741211’, getClass = ‘class java.lang.Double’, clazz = ‘Double’
2019-05-26 20:05:00.031 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::ItemResultHandler::handleResult getState value = ‘127.5999984741211’, getClass = ‘class java.lang.Double’, clazz = ‘Double’
2019-05-26 20:05:00.031 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::ItemResultHandler::handleResult getState value = ‘127.5999984741211’, getClass = ‘class java.lang.Double’, clazz = ‘Double’
2019-05-26 20:05:00.031 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::ItemResultHandler::handleResult getState value = ‘122.5’, getClass = ‘class java.lang.Double’, clazz = ‘Double’
2019-05-26 20:05:00.031 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::ItemResultHandler::handleResult getState value = ‘14.199999809265137’, getClass = ‘class java.lang.Double’, clazz = ‘Double’
2019-05-26 20:05:00.031 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::ItemResultHandler::handleResult getState value = ‘0.0’, getClass = ‘class java.lang.Double’, clazz = ‘Double’
2019-05-26 20:05:00.032 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::ItemResultHandler::handleResult getState value = ‘14.199999809265137’, getClass = ‘class java.lang.Double’, clazz = ‘Double’
2019-05-26 20:05:00.032 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::ItemResultHandler::handleResult getState value = ‘0.0’, getClass = ‘class java.lang.Double’, clazz = ‘Double’
2019-05-26 20:05:00.032 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::ItemResultHandler::handleResult getState value = ‘0.0’, getClass = ‘class java.lang.Double’, clazz = ‘Double’
2019-05-26 20:05:00.033 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::ItemResultHandler::handleResult getState value = ‘14.399999618530273’, getClass = ‘class java.lang.Double’, clazz = ‘Double’
2019-05-26 20:05:00.033 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::ItemResultHandler::handleResult getState value = ‘0.0’, getClass = ‘class java.lang.Double’, clazz = ‘Double’
2019-05-26 20:05:00.033 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::ItemResultHandler::handleResult getState value = ‘14.199999809265137’, getClass = ‘class java.lang.Double’, clazz = ‘Double’
2019-05-26 20:05:00.033 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::ItemResultHandler::handleResult getState value = ‘0.0’, getClass = ‘class java.lang.Double’, clazz = ‘Double’
2019-05-26 20:05:00.034 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::ItemResultHandler::handleResult getState value = ‘0.0’, getClass = ‘class java.lang.Double’, clazz = ‘Double’
2019-05-26 20:05:00.034 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::ItemResultHandler::handleResult getState value = ‘14.399999618530273’, getClass = ‘class java.lang.Double’, clazz = ‘Double’
2019-05-26 20:05:00.035 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::ItemResultHandler::handleResult getState value = ‘0.0’, getClass = ‘class java.lang.Double’, clazz = ‘Double’
2019-05-26 20:05:00.035 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::ItemResultHandler::handleResult getState value = ‘0.0’, getClass = ‘class java.lang.Double’, clazz = ‘Double’
2019-05-26 20:05:00.035 [DEBUG] [jdbc.internal.JdbcPersistenceService] - JDBC::query: query for Powermessurement_EG_Kuelschrank returned 18 rows in 8 ms
2019-05-26 20:05:00.036 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558890301000, value: 127.5999984741211
2019-05-26 20:05:00.040 [TRACE] [nce.extensions.PersistenceExtensions] - first TS: 1558890301000
2019-05-26 20:05:00.040 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558890604000, value: 127.5999984741211
2019-05-26 20:05:00.041 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558891204000, value: 127.5999984741211
2019-05-26 20:05:00.041 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558891805000, value: 127.5999984741211
2019-05-26 20:05:00.041 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558892088000, value: 122.5
2019-05-26 20:05:00.041 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558892135000, value: 14.199999809265137
2019-05-26 20:05:00.041 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558892156000, value: 0.0
2019-05-26 20:05:00.041 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558892385000, value: 14.199999809265137
2019-05-26 20:05:00.041 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558892388000, value: 0.0
2019-05-26 20:05:00.041 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558892404000, value: 0.0
2019-05-26 20:05:00.041 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558892420000, value: 14.399999618530273
2019-05-26 20:05:00.042 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558892429000, value: 0.0
2019-05-26 20:05:00.042 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558892474000, value: 14.199999809265137
2019-05-26 20:05:00.042 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558892478000, value: 0.0
2019-05-26 20:05:00.042 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558893004000, value: 0.0
2019-05-26 20:05:00.042 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558893305000, value: 14.399999618530273
2019-05-26 20:05:00.042 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558893308000, value: 0.0
2019-05-26 20:05:00.042 [TRACE] [nce.extensions.PersistenceExtensions] - TS: 1558893605000, value: 0.0
2019-05-26 20:05:00.042 [TRACE] [nce.extensions.PersistenceExtensions] - last TS: 1558893900042, value: 0.0
2019-05-26 20:05:00.043 [INFO ] [.smarthome.model.script.Betrieb.rule] - Verbrauch Kühlschrank Durchschnitt: 65.30209911224467
with Statement:
mysql> SELECT avg(value) FROM item0041 WHERE TIME>‘2019-05-26 19:05:00’ ORDER BY time ASC;
±-------------------+
| avg(value) |
±-------------------+
| 39.127777364518906 |
±-------------------+
1 row in set (0.00 sec)
You can‘t compare those values. What MySQL does is a simple arithmetic average of all values. But have a look at the timestamps: they are not equally spaced. Imagine for a simple example:
00:00 0
00:10 100
00:15 0
00:30 20
01:00 0
Plot that and tell me: Do you think that 24 is a Good average? What openhab does is calculating the integral
(100+0)/210+(0+100)/25+(20+0)/215+(0+20)/230
And dividing by 60. this is mathematically correct imo.
1 Like
I see, for my rule both calculations a valid and the less acurate arithmetical would be enough.
Thx a lot!
I didn’t read through everything, but this sounds similar to this issue… Type Conversion / persistence issue?, where the timezone in the container running the db server was not set properly.