lastUpdate returns wrong value

[palkor]

Hi,

I'm trying to monitor if a device is dead. I've read forum and it seemed to be ease. I planned to use lastUpdate attribute to find out when the device reported its presence. However when I read lastUpdate in my script, it returns wrong value.

My script:

Code: Select all

return {
	on = {
		timer = {
			'every minute',
		}
	},
    logging = 
    { 
        level = domoticz.LOG_DEBUG,
    }, 
	execute = function(domoticz, timer)
	    domoticz.log("Brama updated: " .. domoticz.devices('Brama').lastUpdate.rawDateTime)
	end
}

Logs shows the following info:

2020-10-24 15:12:51.195 (Wemos D1 Mini Pro garage) Light/Switch (Brama)
2020-10-24 15:12:51.188 Status: User: Admin initiated a switch command (11/Brama/Off)
2020-10-24 15:13:01.511 (Wemos D1 Mini Pro garage) Light/Switch (Brama)
2020-10-24 15:13:01.439 Status: dzVents: Info: ------ Start internal script: Lost_brama_monitoring:, trigger: "every minute"
2020-10-24 15:13:01.498 Status: User: Admin initiated a switch command (11/Brama/Off)
2020-10-24 15:13:01.805 Status: dzVents: Debug: Processing device-adapter for Brama: Switch device adapter
2020-10-24 15:13:01.806 Status: dzVents: Info: Brama updated: 2020-10-22 18:55:20
2020-10-24 15:13:01.813 Status: dzVents: Info: ------ Finished Lost_brama_monitoring

As you can see, 'Brama' switch is getting updated, however lastUpdate reports wrong value. The 'Devices' screen is accurate:

lastSeen.png (26.71 KiB) Viewed 580 times

Domoticz: 2020.2 (build 12461) - I've updated to Beta because I've read somewhere in the forum that there were some bugs in Stable
dzVents Version: 3.0.14

I'm sure I'm doing something wrong... Any help appreciated.

Regards,
Pawel

[waaren]

I'm trying to monitor if a device is dead. I've read forum and it seemed to be ease. I planned to use lastUpdate attribute to find out when the device reported its presence. However when I read lastUpdate in my script, it returns wrong value.

I don't know if it is related but last seen is not the same as lastUpdate. Last seen is only stored in memory and can be the result of a keepalive ping while lastUpdate is the value from the database just before the script is triggered.
Some things to check:

• do you see the same behaviour with devices other then the Wemos connected ones?
• can you try the same script but not with the name but with the device id?
• can you check the database?

  Code: Select all

  sqlite3 <domoticz dir>/domoticz.db "select "select name, id, lastUpdate from devicestatus where name is 'Brama' " 
  

• what do you see with?

  Code: Select all

  http://<domoticz IP:domoticz port>/json.htm?type=devices&rid=11

[palkor]

Thanks for instant reply, waaren!

Testing with ID instead of name returned the same result.

database as well as API contain valid values:

Code: Select all

sqlite3 domoticz.db  "select name, id, lastUpdate from devicestatus where name is 'Brama' "
Brama|11|2020-10-24 18:06:54

curl -s 'http://<domoticz-ip>:8080/json.htm?type=devices&rid=11' | grep Last
                        "LastUpdate" : "2020-10-24 18:04:58",

I looked at the logs for 'Brama' and saw that what dzVents reports as a lastUpdate is actually the time when the device state changed:

Code: Select all

2020-10-22 18:55:20	Closed	Admin
2020-10-22 18:52:38	Open	Admin

I'm afraid there is something wrong with my domoticz . I've added another line to my script to test another device, as you requested. But logs doesn't show another log line. I've tried with different IDXes (not only 10) - same result.

Code: Select all

execute = function(domoticz, timer)
    -- new log
    domoticz.log("Other-updated: " .. domoticz.devices(10).lastUpdate.rawDateTime, domoticz.LOG_DEBUG)
    -- old log
    domoticz.log("Brama-updated: " .. domoticz.devices(11).lastUpdate.rawDateTime, domoticz.LOG_DEBUG)
end

2020-10-24 18:18:00.878 Status: dzVents: Info: ------ Start internal script: Lost_brama_monitoring:, trigger: "every minute"
2020-10-24 18:18:01.088 Status: dzVents: Debug: Processing device-adapter for Brama: Switch device adapter
2020-10-24 18:18:01.089 Status: dzVents: Debug: Brama-updated: 2020-10-22 18:55:20
2020-10-24 18:18:01.089 Status: dzVents: Info: ------ Finished Lost_brama_monitoring

sqlite3 domoticz.db  "select name, id, lastUpdate from devicestatus where id is '10' "
Temperatura w garazu|10|2020-10-24 18:19:47

[waaren]

I'm afraid there is something wrong with my domoticz . I've added another line to my script to test another device, as you requested. But logs doesn't show another log line. I've tried with different IDXes (not only 10) - same result.

From the looks of it it seems that your domoticz is looking t another database?
What do you see when you give a

Code: Select all

sudo ps -ef | grep domo

[waaren]

I'm afraid there is something wrong with my domoticz . I've added another line to my script to test another device, as you requested. But logs doesn't show another log line. I've tried with different IDXes (not only 10) - same result.

From the looks of it it seems that your domoticz is looking at another database?
What do you see when you give a

Code: Select all

sudo ps -ef | grep domo

[palkor]

Only one process.

Code: Select all

pi@raspberrypi:~/domoticz $ sudo ps -ef | grep domo
root       455     1 12 Oct14 ?        1-06:56:19 /home/pi/domoticz/domoticz -daemon -www 8080 -sslwww 443
pi       20746 14286  2 19:28 pts/1    00:00:00 grep --color=auto domo
pi@raspberrypi:~/domoticz $ 

I've tried to find another DB. Seems to be only the only one.

Code: Select all

pi@raspberrypi:~ $ sudo find / -name domoticz.db
/home/pi/domoticz/domoticz.db

I've updated switch name via Web GUI and ran SQL query to find if it see my update. It does. So it looks like it's the same database.
I've also opened and closed the gate (and automatically changed the state of the '11' switch). It reflected in what dzVents sees, that is lastUpdate is the time when the device's state changed.

Code: Select all

2020-10-24 19:53:55.036 (Wemos D1 Mini Pro garage) Light/Switch (GarageGate)
2020-10-24 19:53:55.003 Status: User: Admin initiated a switch command (11/GarageGate/Off)
2020-10-24 19:54:01.145 Status: dzVents: Info: ------ Start internal script: Lost_brama_monitoring:, trigger: "every minute"
2020-10-24 19:54:01.363 Status: dzVents: Debug: Processing device-adapter for Temperatura w garazu: Temperature device adapter
2020-10-24 19:54:01.363 Status: dzVents: Debug: Other-updated: 2020-10-24 19:53:54
2020-10-24 19:54:01.379 Status: dzVents: Debug: Processing device-adapter for GarageGate: Switch device adapter
2020-10-24 19:54:01.380 Status: dzVents: Debug: Brama-updated: 2020-10-24 19:25:19
2020-10-24 19:54:01.380 Status: dzVents: Info: ------ Finished Lost_brama_monitoring

What's strange is that at this moment my script also reports another device's state, the one that it couldn't report previously

[waaren]

What's strange is that at this moment my script also reports another device's state, the one that it couldn't report previously

Did you check your database health?

Check this post To check (and repair when needed) the domoticz database

[palkor]

Code: Select all

sudo sqlite3 domoticz.db  'SELECT name as Tablename ,SUM("pgsize")/4096 Size FROM "dbstat" WHERE name IN (SELECT name FROM "sqlite_master" WHERE type == "table" ) GROUP BY name HAVING Size > 10 ORDER BY size DESC;'
LightingLog|22
pi@raspberrypi:~/domoticz $ sudo sqlite3 domoticz.db "SELECT Key, LENGTH(SValue) size FROM Preferences WHERE LENGTH(sValue) > 1000;"

I thought there could be something wrong with my db because I didn't get any output so I tested with lower values.

Code: Select all

pi@raspberrypi:~/domoticz $ sudo sqlite3 domoticz.db
SQLite version 3.27.2 2019-02-25 16:06:06
Enter ".help" for usage hints.
sqlite> SELECT Key, LENGTH(SValue) size FROM Preferences WHERE LENGTH(sValue) > 1000;
sqlite> SELECT Key, LENGTH(SValue) size FROM Preferences WHERE LENGTH(sValue) > 100;
sqlite> SELECT Key, LENGTH(SValue) size FROM Preferences WHERE LENGTH(sValue) > 10;
RaspCamParams|18
UVCParams|39
ZWaveNetworkKey|94
HTTPURL|100
HTTPPostContentType|24
Location|19
WebLocalNetworks|23
SecPassword|32
ProtectionPassword|32
WebPassword|32

Then did vacuum

Code: Select all

sqlite> vacuum;
sqlite> PRAGMA integrity_check(10000);
ok
sqlite> PRAGMA foreign_key_check;
sqlite> 

I did not follow with any repairs, as it seems that there was nothing to repair.
I started domoticz service again and nothing changed. dzVents still reports the timestamp when a switch changed its state as a lastUpdate. SQL query returns valid timestamp.

BTW when I ran the first SQL command I got error Error: no such table: sqlite_schema. I've found https://sqlite.org/forum/forumpost/d90adfbb0a that my db version is older and that I need to use sqlite_master table instead of sqlite_schema.

Code: Select all

sudo sqlite3 domoticz.db  'SELECT sqlite_version() AS version;'
3.27.2

However I have no idea if that has anything to do with my problem...

[waaren]

However I have no idea if that has anything to do with my problem...

Probably not as domoticz uses an internal version (amalgation) of sqlite, independent of the sqlite version of the OS.
Could you set dzvents Log Level to Debug(everything) via the buttons [setup] [settings] [other]

like below. You will get a domoticzData.lua file in <domoticz dir>/scripts/dzVents/ directory with all data dzVents receive from domoticz. Search for the device giving the wrong lastUpdate time.

debug.png (19.74 KiB) Viewed 533 times

[palkor]

Here's what I got after setting log level to debug:

Code: Select all

-- Persistent Data
local multiRefObjects = {

} -- multiRefObjects
local obj1 = {
-- objects from 1 to 6, I've removed them
        [7] = {
                ["batteryLevel"] = 255;
                ["timedOut"] = true;
                ["changed"] = false;
                ["switchTypeValue"] = 2;
                ["deviceType"] = "Light/Switch";
                ["baseType"] = "device";
                ["deviceID"] = "0001405B";
                ["description"] = "";
                ["lastLevel"] = 0;
                ["lastUpdate"] = "2020-10-24 20:48:16";
                ["signalLevel"] = 12;
                ["data"] = {
                        ["hardwareName"] = "Wemos D1 Mini Pro garage";
                        ["_nValue"] = 0;
                        ["hardwareID"] = 4;
                        ["protected"] = false;
                        ["usedByCamera"] = false;
                        ["hardwareType"] = "Dummy (Does nothing, use for virtual switches only)";
                        ["levelVal"] = 0;
                        ["unit"] = 1;
                        ["hardwareTypeValue"] = 15;
                        ["icon"] = "contact";
                        ["maxDimLevel"] = 100;
                        ["_state"] = "Closed";
                };
                ["protected"] = false;
                ["switchType"] = "Contact";
                ["name"] = "GarageGate";
                ["id"] = 11;
                ["rawData"] = {
                        [1] = "0";
                };
                ["subType"] = "Switch";
        };

At the same time

Code: Select all

pi@raspberrypi:~/domoticz $ sqlite3 domoticz.db  "select name, id, lastUpdate from devicestatus where id is '11' "
GarageGate|11|2020-10-25 14:21:56

[waaren]

Here's what I got after setting log level to debug:

Did you change the name of the device?

I cannot reproduce the issue. All device lastUpdates on my systems are the same in the database and in dzVents. And again this is not the same as the last seen value in the devices tab.

[palkor]

Yes, I changed device name at the time when you suggested that domoticz might be looking at another database. I changed it via web page and this change was reflected in the db. In my previous post the same new name (GarageGate) is seen in the db and the domoticzData.lua file.

It looks like I need to reinstall domoticz but for me it's a time consuming task. I'll try either to do the database backup and the restore in the new instance or install from the scratch. In the meantime I plan to write some crontab based Python/Bash script that will pull data via API/SQL to detect zombie devices.

Thank you very much for the time you spent on my case.