SQL driver: wrong detection of changes for aliase driver #295

sigmashig · 2023-02-14T07:44:11Z

Describe the bug
I have installed SQL driver 2.2.0 and Alias-Manager 1.2.4. Also, I have set up the alias variable with Read converter: Math.round(val*10)/10. This variable is stored in DB (PostgreSQL) with the parameters:

Record changes only
Record the same values (seconds)=0
Minimum difference from the last value=0

The value for this variable is displayed in admin UI correctly (with 1 digit after the decimal point). But when I look in the DB:

select *
from ts_number
where id in ( select id from datapoints where name = 'alias.0.Energy.Battery.Hugel100'	)
order by ts desc
limit 100

I see the same values:

"id","ts","val","ack","_from","q"
406,1676352308712,13.8,True,2,0
406,1676352307466,13.8,True,2,0
406,1676352301735,13.8,True,2,0
406,1676352300451,13.8,True,2,0
406,1676352258390,13.8,True,2,0

The same values are stored in DB with disregard of "Record changes only", It seems, like the presence of changes is detected before applying of Read converting.

To Reproduce
Steps to reproduce the behavior:

Install instances of SQL (2.2.0 in my case) and Alias-manager (1.2.4 in my case)
Create the number variable V1 in any section.
Create an alias alias.0.A1 to this variable V1 with the parameter: Read converter=Math.round(val*10)/10 . This converter stores just 1 digit after the decimal point.
Add SQL setting for this alias with

Record changes only
Record the same values (seconds)=0
Minimum difference from the last value=0

Open Admin UI
Write value 1.2345 into V1

Expected result=Achieved result: The value of 1.2 is displayed for A1 in Admin UI and stored in DB

Set v1=1.24567

Expected behavior

The value of A1 is not changed: A1=1.2 (Achieved!)
select *
from ts_number
where id in (
select id
from datapoints
where name = 'alias.0.A1'
)
order by ts desc

returns just 1 record.
Achieved result:
this select returns 2 records with the same val.

Screenshots & Logfiles

Versions:

SQL: 2.2.0
JS-Controller version: 4.0.24
Node version: v16.19.0
Operating system: "Raspbian GNU/Linux 11 (bullseye)"
alias-manager: 1.2.4

Additional context

The text was updated successfully, but these errors were encountered:

Apollon77 · 2023-02-14T08:35:42Z

Please enable debug logging for the instance and enable the enhanced debug log for such a datapoint and provide the debug log. thank you

sigmashig · 2023-02-14T09:00:26Z

It is a fragment of debug log: Please pay attention to variable alias.0.Energy.Battery.Axioma100 (type: undefined, ID: 405)

2023-02-14 10:38:02.202  - �[34mdebug�[39m: sql.0 (9038) pushValueIntoDB called for alias.0.Energy.Battery.Axioma100 (type: undefined, ID: 405) and state: {"val":12.3,"ack":true,"ts":1676363882144,"q":0,"from":"system.adapter.mqtt.0","user":"system.user.admin","lc":1676360030348}
2023-02-14 10:38:02.204  - �[34mdebug�[39m: sql.0 (9038) prepareTaskCheckTypeAndDbId CALLED for alias.0.Energy.Battery.Axioma100
2023-02-14 10:38:02.215  - �[34mdebug�[39m: sql.0 (9038) Return connection to pool: 0 now
2023-02-14 10:38:02.220  - �[34mdebug�[39m: sql.0 (9038) Type set in Def for alias.0.Energy.Heater.LineA.Voltage: false
2023-02-14 10:38:02.222  - �[34mdebug�[39m: sql.0 (9038) Type (from DB-Type) for alias.0.Energy.Heater.LineA.Voltage: 0
2023-02-14 10:38:02.224  - �[34mdebug�[39m: sql.0 (9038) pushValueIntoDB-prepareTaskCheckTypeAndDbId RESULT for alias.0.Energy.Heater.LineA.Voltage (type: 0, ID: 365) and state: {"val":236.6,"ack":true,"ts":1676363882035,"q":0,"from":"system.adapter.mqtt.0","user":"system.user.admin","lc":1676363875990}: undefined
2023-02-14 10:38:02.228  - �[34mdebug�[39m: sql.0 (9038) INSERT INTO ts_number (id, ts, val, ack, _from, q) VALUES (365, 1676363882035, 236.6, true, 2, 0);
2023-02-14 10:38:02.229  - �[34mdebug�[39m: sql.0 (9038) Borrow connection from pool: 1 now
2023-02-14 10:38:02.265  - �[34mdebug�[39m: sql.0 (9038) Return connection to pool: 0 now
2023-02-14 10:38:02.296  - �[34mdebug�[39m: sql.0 (9038) Type set in Def for alias.0.Energy.Battery.Sznajder100: false
2023-02-14 10:38:02.297  - �[34mdebug�[39m: sql.0 (9038) Type (from DB-Type) for alias.0.Energy.Battery.Sznajder100: 0
2023-02-14 10:38:02.299  - �[34mdebug�[39m: sql.0 (9038) pushValueIntoDB-prepareTaskCheckTypeAndDbId RESULT for alias.0.Energy.Battery.Sznajder100 (type: 0, ID: 407) and state: {"val":12.8,"ack":true,"ts":1676363882050,"q":0,"from":"system.adapter.mqtt.0","user":"system.user.admin","lc":1676363860351}: undefined
2023-02-14 10:38:02.301  - �[34mdebug�[39m: sql.0 (9038) INSERT INTO ts_number (id, ts, val, ack, _from, q) VALUES (407, 1676363882050, 12.8, true, 2, 0);
2023-02-14 10:38:02.303  - �[34mdebug�[39m: sql.0 (9038) Borrow connection from pool: 1 now
2023-02-14 10:38:02.323  - �[34mdebug�[39m: sql.0 (9038) pushValueIntoDB called for alias.0.Energy.Total.LineB.Current (type: undefined, ID: 389) and state: {"val":2.459,"ack":true,"ts":1676363882276,"q":0,"from":"system.adapter.mqtt.0","user":"system.user.admin","lc":1676363882276}
2023-02-14 10:38:02.325  - �[34mdebug�[39m: sql.0 (9038) prepareTaskCheckTypeAndDbId CALLED for alias.0.Energy.Total.LineB.Current
2023-02-14 10:38:02.328  - �[34mdebug�[39m: sql.0 (9038) pushValueIntoDB called for alias.0.Energy.Total.LineA.Current (type: undefined, ID: 384) and state: {"val":1.385,"ack":true,"ts":1676363882277,"q":0,"from":"system.adapter.mqtt.0","user":"system.user.admin","lc":1676363882277}
2023-02-14 10:38:02.330  - �[34mdebug�[39m: sql.0 (9038) prepareTaskCheckTypeAndDbId CALLED for alias.0.Energy.Total.LineA.Current
2023-02-14 10:38:02.332  - �[34mdebug�[39m: sql.0 (9038) pushValueIntoDB called for mqtt.0.Equipment.PowerMeter.P0263.Current (type: undefined, ID: 209) and state: {"val":2.459,"ack":true,"ts":1676363882276,"q":0,"from":"system.adapter.mqtt.0","user":"system.user.admin","lc":1676363882276}
2023-02-14 10:38:02.335  - �[34mdebug�[39m: sql.0 (9038) prepareTaskCheckTypeAndDbId CALLED for mqtt.0.Equipment.PowerMeter.P0263.Current
2023-02-14 10:38:02.337  - �[34mdebug�[39m: sql.0 (9038) pushValueIntoDB called for mqtt.0.Equipment.PowerMeter.P0262.Current (type: undefined, ID: 205) and state: {"val":1.385,"ack":true,"ts":1676363882277,"q":0,"from":"system.adapter.mqtt.0","user":"system.user.admin","lc":1676363882277}
2023-02-14 10:38:02.340  - �[34mdebug�[39m: sql.0 (9038) prepareTaskCheckTypeAndDbId CALLED for mqtt.0.Equipment.PowerMeter.P0262.Current
2023-02-14 10:38:02.355  - �[34mdebug�[39m: sql.0 (9038) Return connection to pool: 0 now
2023-02-14 10:38:02.360  - �[34mdebug�[39m: sql.0 (9038) Type set in Def for alias.0.Energy.Battery.Axioma100: false
2023-02-14 10:38:02.361  - �[34mdebug�[39m: sql.0 (9038) Type (from DB-Type) for alias.0.Energy.Battery.Axioma100: 0
2023-02-14 10:38:02.363  - �[34mdebug�[39m: sql.0 (9038) pushValueIntoDB-prepareTaskCheckTypeAndDbId RESULT for alias.0.Energy.Battery.Axioma100 (type: 0, ID: 405) and state: {"val":12.3,"ack":true,"ts":1676363882144,"q":0,"from":"system.adapter.mqtt.0","user":"system.user.admin","lc":1676360030348}: undefined
2023-02-14 10:38:02.366  - �[34mdebug�[39m: sql.0 (9038) INSERT INTO ts_number (id, ts, val, ack, _from, q) VALUES (405, 1676363882144, 12.3, true, 2, 0);
2023-02-14 10:38:02.368  - �[34mdebug�[39m: sql.0 (9038) Borrow connection from pool: 1 now

There are two records in the log: at 2023-02-14 10:38:02.202 and 2023-02-14 10:38:02.366
But in the first record type: undefined, in the second one is type: 0
The base variable has type=number

  "_id": "mqtt.0.Equipment.VoltmetersDC.V0280.CH0.Voltage",
  "common": {
    "name": "Equipment/VoltmetersDC/V0280/CH0/Voltage",
    "write": true,
    "read": true,
    "role": "variable",
    "desc": "mqtt server variable",
    "type": "number"
  },

Apollon77 · 2023-02-14T09:04:14Z

Please also show the alias definition

sigmashig · 2023-02-14T09:05:32Z

{
  "type": "state",
  "common": {
    "name": "Equipment/VoltmetersDC/V0280/CH2/Voltage",
    "role": "variable",
    "type": "number",
    "read": true,
    "write": true,
    "alias": {
      "id": "mqtt.0.Equipment.VoltmetersDC.V0280.CH2.Voltage",
      "read": "Math.round(val*10)/10"
    },
    "custom": {
      "sql.0": {
        "enabled": true,
        "storageType": "",
        "counter": false,
        "aliasId": "",
        "debounceTime": 0,
        "blockTime": 0,
        "changesOnly": true,
        "changesRelogInterval": "0",
        "changesMinDelta": "0",
        "ignoreBelowNumber": "",
        "disableSkippedValueLogging": false,
        "retention": "0",
        "customRetentionDuration": 365,
        "maxLength": 0,
        "enableDebugLogs": false,
        "debounce": 1000
      }
    }
  },
  "_id": "alias.0.Energy.Battery.Axioma100",
  "native": {},
  "acl": {
    "object": 1636,
    "state": 1636,
    "owner": "system.user.admin",
    "ownerGroup": "system.group.administrator"
  },
  "from": "system.adapter.admin.0",
  "user": "system.user.admin",
  "ts": 1675969645796
}

Apollon77 · 2023-02-14T09:05:45Z

BTW: "role:"variable" is completely wrong. Who created this state? Should not be the mqtt adapter. it shoild be "role: "mixed"

sigmashig · 2023-02-14T09:07:30Z

The base variable was created by MQTT Publish request. The alias is created manually from alias-manager. Ok I will change it manually

Apollon77 · 2023-02-14T09:14:04Z

Hm ... but alias.0.Energy.Battery.Axioma100 is correctly rounded as 12.3 in your above log example... just other values are not ... so whats exactly the issue here?

sigmashig · 2023-02-14T09:14:35Z

The role "mixed" is absent in the list of available roles in both Admin UI and Alias-Manager
https://i.imgur.com/620dq4n.png

Apollon77 · 2023-02-14T09:14:56Z

(and that type is undefined for the very first attemt to write a value after adapterstart is completely correct because it will read the type from DB in that process. all fine here

Apollon77 · 2023-02-14T09:18:04Z

(and role missing is better then a wrong value, but should not be missing ... but might be in "older reated states" ... so ... I just stumbled over the "variable" which is in any case a wrong value

sigmashig · 2023-02-14T09:21:19Z

The problem is: the SQL adapter creates a hundreds records in the DB with the same values:

"id","ts","val","ack","_from","q"
405,1676366200106,12.3,True,2,0
405,1676366199072,12.3,True,2,0
405,1676366197410,12.3,True,2,0
405,1676366040604,12.3,True,2,0
405,1676366039468,12.3,True,2,0
405,1676366039131,12.3,True,2,0
405,1676364832976,12.3,True,2,0
405,1676364831606,12.3,True,2,0
405,1676364828837,12.3,True,2,0
405,1676364283636,12.3,True,2,0

It is a result of

select *
from ts_number
where id=405
order by ts desc
limit 10

I set options
Record changes only
Record the same values (seconds)=0
Minimum difference from the last value=0

So, it should be just one record in DB with the timestamp where this value is set:
405,1676364283636,12.3,True,2,0

sigmashig · 2023-02-14T09:25:24Z

BTW. I changed role: "mixed" manually and restart of SQL driver. Nothing to changed - a lot of records in DB with the same value

Apollon77 · 2023-02-14T09:38:54Z

Is the "optimization for displaying" enabled ... or better is it turned off? If not do that because most likely this is caused by this

sigmashig · 2023-02-14T09:44:20Z

"Disable charting optimized logging of skipped values" = off. "On query round numbers to" is empty

sigmashig · 2023-02-14T09:48:54Z

BTW, I set "On query round numbers to"=1. Nothing to changed - lot's of records in DB

Apollon77 · 2023-02-14T13:21:07Z

Ok, please share screenshots ofd the settings from adapter and from that datapoint and add a more longdebug log with at least 4-5 of the values logged from this datapoint 8and do not shorten it please). Attach please as file. The debug log normally contains excat infos why something was logged

sigmashig · 2023-02-15T07:48:51Z

I have collected a set of screenshots of settings and a full log. Please, pay attention to the object with id=405, name= alias.0.Energy.Battery.Axioma100.
[Object settings] (https://i.imgur.com/j9rhO6H.png)
Object settings json
Object SQL settings
Object SQL settings 2

DB request

Alias settings

Log file

scheidhauer · 2024-07-16T17:27:53Z

I have exactly the same problem: are there any news or workarounds for this?

sigmashig · 2024-07-17T08:18:15Z

No solution for this. In my case, I modify my script and check the previous value manually. How to resolve it when this value is generated by some device - I have no idea.

Apollon77 · 2024-07-17T10:54:36Z

The problem is that the check if the value changed is notthat easiely possible and normally the core system handles this. But because of the fact that an alias never has a real value and the value is always dynamically determined by the formula the basic "has value changed" information is carried from the basic value.

So fixing this requires that the adapter builds up his own "last value cache" and do the comparism based on the real value and not on the provided details fro the core system.

scheidhauer · 2024-07-17T18:09:53Z

Thank you for your comments!
So I just wrote a script that listens for changes to my value and only in case it has really changed it will write the value to a new state. I adapted the alias adapter to watch this new state, so I did not have to adapt any of my dashboards and charts.

Next I'll fiddle with SQL to get rid of duplicate consecutive values in my DB :-)

Apollon77 added the enhancement label Jul 17, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

SQL driver: wrong detection of changes for aliase driver #295

SQL driver: wrong detection of changes for aliase driver #295

sigmashig commented Feb 14, 2023 •

edited

Loading

Apollon77 commented Feb 14, 2023

sigmashig commented Feb 14, 2023

Apollon77 commented Feb 14, 2023

sigmashig commented Feb 14, 2023

Apollon77 commented Feb 14, 2023

sigmashig commented Feb 14, 2023

Apollon77 commented Feb 14, 2023

sigmashig commented Feb 14, 2023

Apollon77 commented Feb 14, 2023

Apollon77 commented Feb 14, 2023

sigmashig commented Feb 14, 2023

sigmashig commented Feb 14, 2023 •

edited

Loading

Apollon77 commented Feb 14, 2023

sigmashig commented Feb 14, 2023

sigmashig commented Feb 14, 2023

Apollon77 commented Feb 14, 2023

sigmashig commented Feb 15, 2023 •

edited

Loading

scheidhauer commented Jul 16, 2024

sigmashig commented Jul 17, 2024

Apollon77 commented Jul 17, 2024

scheidhauer commented Jul 17, 2024

SQL driver: wrong detection of changes for aliase driver #295

SQL driver: wrong detection of changes for aliase driver #295

Comments

sigmashig commented Feb 14, 2023 • edited Loading

Screenshots & Logfiles

Additional context

Apollon77 commented Feb 14, 2023

sigmashig commented Feb 14, 2023

Apollon77 commented Feb 14, 2023

sigmashig commented Feb 14, 2023

Apollon77 commented Feb 14, 2023

sigmashig commented Feb 14, 2023

Apollon77 commented Feb 14, 2023

sigmashig commented Feb 14, 2023

Apollon77 commented Feb 14, 2023

Apollon77 commented Feb 14, 2023

sigmashig commented Feb 14, 2023

sigmashig commented Feb 14, 2023 • edited Loading

Apollon77 commented Feb 14, 2023

sigmashig commented Feb 14, 2023

sigmashig commented Feb 14, 2023

Apollon77 commented Feb 14, 2023

sigmashig commented Feb 15, 2023 • edited Loading

scheidhauer commented Jul 16, 2024

sigmashig commented Jul 17, 2024

Apollon77 commented Jul 17, 2024

scheidhauer commented Jul 17, 2024

sigmashig commented Feb 14, 2023 •

edited

Loading

sigmashig commented Feb 14, 2023 •

edited

Loading

sigmashig commented Feb 15, 2023 •

edited

Loading