SQL driver: wrong detection of changes for aliase driver

[sigmashig]

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:

1. Install instances of SQL (2.2.0 in my case) and Alias-manager (1.2.4 in my case)
2. Create the number variable V1 in any section.
3. 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.
4. Add SQL setting for this alias with

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

5. Open Admin UI
6. 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

7. Set v1=1.24567

Expected behavior

1. The value of A1 is not changed: A1=1.2 (Achieved!)
2. 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

[Apollon77]

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]

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  - debug: 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  - debug: sql.0 (9038) prepareTaskCheckTypeAndDbId CALLED for alias.0.Energy.Battery.Axioma100
2023-02-14 10:38:02.215  - debug: sql.0 (9038) Return connection to pool: 0 now
2023-02-14 10:38:02.220  - debug: sql.0 (9038) Type set in Def for alias.0.Energy.Heater.LineA.Voltage: false
2023-02-14 10:38:02.222  - debug: sql.0 (9038) Type (from DB-Type) for alias.0.Energy.Heater.LineA.Voltage: 0
2023-02-14 10:38:02.224  - debug: 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  - debug: 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  - debug: sql.0 (9038) Borrow connection from pool: 1 now
2023-02-14 10:38:02.265  - debug: sql.0 (9038) Return connection to pool: 0 now
2023-02-14 10:38:02.296  - debug: sql.0 (9038) Type set in Def for alias.0.Energy.Battery.Sznajder100: false
2023-02-14 10:38:02.297  - debug: sql.0 (9038) Type (from DB-Type) for alias.0.Energy.Battery.Sznajder100: 0
2023-02-14 10:38:02.299  - debug: 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  - debug: 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  - debug: sql.0 (9038) Borrow connection from pool: 1 now
2023-02-14 10:38:02.323  - debug: 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  - debug: sql.0 (9038) prepareTaskCheckTypeAndDbId CALLED for alias.0.Energy.Total.LineB.Current
2023-02-14 10:38:02.328  - debug: 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  - debug: sql.0 (9038) prepareTaskCheckTypeAndDbId CALLED for alias.0.Energy.Total.LineA.Current
2023-02-14 10:38:02.332  - debug: 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  - debug: sql.0 (9038) prepareTaskCheckTypeAndDbId CALLED for mqtt.0.Equipment.PowerMeter.P0263.Current
2023-02-14 10:38:02.337  - debug: 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  - debug: sql.0 (9038) prepareTaskCheckTypeAndDbId CALLED for mqtt.0.Equipment.PowerMeter.P0262.Current
2023-02-14 10:38:02.355  - debug: sql.0 (9038) Return connection to pool: 0 now
2023-02-14 10:38:02.360  - debug: sql.0 (9038) Type set in Def for alias.0.Energy.Battery.Axioma100: false
2023-02-14 10:38:02.361  - debug: sql.0 (9038) Type (from DB-Type) for alias.0.Energy.Battery.Axioma100: 0
2023-02-14 10:38:02.363  - debug: 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  - debug: 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  - debug: 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]

Please also show the alias definition

[sigmashig]

{
  "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]

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

[sigmashig]

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

[Apollon77]

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]

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]

(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]

(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]

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]

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]

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]

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

[sigmashig]

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

[Apollon77]

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]

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]

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

[sigmashig]

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]

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]

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 :-)