Questions about async functions and flexibility [Solved]

[Timmiej93]

I have a script that turns on multiple devices at a specific time. These devices can be a bit hit and miss on connectivity when the weather is cold, so I have implemented some basic checking. This uses semi-asynchronous functions, which I think is leading to errors.

The basic setup of the script:

Code: Select all

local ips = {
	a = "192.168.2.2",
	b = "192.168.2.4",
}

for _,ip in pairs(ips) do
	switchDevice(ip, true)
end

local function switchDevice(ip, turnOn)

	os.execute("curl IP+command for Tasmota")
	
	local failedAttempts = 0
	while (true) do
		-- Wait for 2 seconds
		os.execute("ping -c 3 google.com")
		
		local function getSonoffIsOn(ip)
			-- Function that uses another script, that checks if the device actually turned on, returns a boolean
		end

		-- Some checks and log entries to see if the devices have turned on or not
	end
end

Pastebin version for those who prefer it

As you can see, there's quite a bit of recursion and waiting going on in this script.

Now the issue is that the script seems to end prematurely. When I execute it, one of the devices will turn on (either a or b, it's random), and some of the log statements will print. However, way before it should, the log also says "------- Finished ExteriorDecorationLights". To me, this looks like the script isn't waiting for the ping calls, just loops through the for loop two times, and then calls it quits.

So now I'm wondering, is it even possible to use this method? Can I call a function in a proper asynchronous way, similar to how openURL() works? Can I simply put the switchDevice() function in a different lua file, or make it a module, and will it work then? All suggestions are welcome.

For those who are interested in looking if it's just me messing something up in my code, here's the entire script. Please note: this contains a lot of debugging things, like trying to add a log message through the JSON API.
Pastebin

Code: Select all

return {
	on = {
		timer = {
			"at sunset",
			"at 23:30 on sun,mon,tue,wed,thu",
			"at 0:30 on fri,sat",
		},

		scenes = {
			'Test'
		},
		
	},

	logging = {
        level = domoticz.LOG_ERROR,
        level = domoticz.LOG_DEBUG,
        marker = "ExteriorDecorationLights :"
    },

    data = {
        counter = { initial = 0 }
    },

	execute = function(domoticz, triggeredItem, triggerInfo)
	    
	    local DEVICE_IPs = {
	        patioSockets = "192.168.2.2",
	        treeLights = "192.168.2.4",
        }
        
        domoticz.data.initialize("counter")
        for _,ip in pairs(DEVICE_IPs) do
            domoticz.data.counter = domoticz.data.counter + 1
        end
        
	    domoticz.log("\n\n"..triggerInfo.scriptName)
	    
        local function isNotDST(domoticz, isOnAction)
    	    local month = domoticz.time.month
    	    domoticz.log("isDST :: Month: "..month, domoticz.LOG_DEBUG)
    	    local day = domoticz.time.day
    	    domoticz.log("isDST :: Day: "..day, domoticz.LOG_DEBUG)
    	    local wday = domoticz.time.wday - 1
    	    if (wday <= 0) then wday = 7 end
    	    domoticz.log("isDST :: Weekday: "..wday, domoticz.LOG_DEBUG)
    	    
    	    if (month < 3 or month > 10) then return false end
    	    if (month > 3 and month < 10) then return true end
    	    
    	    local previousSunday = day - wday
    	    if (isOnAction) then
    	        return (month == 3 and previousSunday < 25) or (month == 10 and previousSunday >= 25)
	        else
	            return (month == 3 and previousSunday <= 25)
            end
        end
	    
	    local function switchDevice(ip, turnOn)
	        local cmd = "curl \""..ip.."/cm?user=admin&password=***&cmnd=power%20"..(turnOn and "on" or "off").."\""
            os.execute(cmd)
            
	        domoticz.log("switchDevice :: Attempting to switch on "..ip, domoticz.LOG_DEBUG)
        
            local failedAttempts = 0
            while (true) do
                -- One of the only decent ways to wait for x seconds in lua
                local timeout = 2
        	    os.execute("ping -c "..(timeout+1).." google.com")
        	    
                local function getSonoffIsOn(ip)
            	    local cmd = "lua /home/Tim/domoticz/scripts/getSonoffIsOn.lua \""..ip.."\""
            	    local f = assert(io.popen(cmd, "r"))
            	    local s = assert(f:read("*a"))
            	    f:close()
            	    s = s:gsub("^%s*(.-)%s*$", "%1")
            	    return (s == "true")
        	    end
        	    
                -- If action mathces result (action=on/result=on) or more than 60 failed attempts
        	    if ((turnOn and getSonoffIsOn(ip)) or (not turnOn and not getSonoffIsOn(ip)) or failedAttempts >= 30) then
        	        
        	        if (turnOn and getSonoffIsOn(ip)) then
                        addToLogText("- ".."IP "..ip.." turned on with "..failedAttempts.." failed attempts".."\n")
                    end
                    if (not turnOn and not getSonoffIsOn(ip)) then
                        addToLogText("- ".."IP "..ip.." turned off with "..failedAttempts.." failed attempts".."\n")
                    end
                    if (failedAttempts >= 60) then
                        addToLogText("- ".."60 failed attempts for IP "..ip.."\n")
                    end
        	        
        	        domoticz.data.counter = domoticz.data.counter - 1
        	        domoticz.log("counter "..domoticz.data.counter, domoticz.LOG_DEBUG)
        	        if (domoticz.data.counter == 0) then
                        domoticz.log("blablablalgalksdfjlasdkjf asdklfjaslkvjalwenkfalszdkfj ", domoticz.LOG_DEBUG)
                        printLogText()
                        
                        domoticz.devices("Dimmer").dimTo(100)
    	            end
    	            
    	            os.execute(" curl 'localhost:8080/json.htm?type=command&param=addlogmessage&message=TESTTEST'")
    	            
        	        break
    	        end
    	        domoticz.log("switchDevice :: Nr. of failed attempts: "..failedAttempts, domoticz.LOG_DEBUG)
    	        failedAttempts = failedAttempts + 1
	        end
        end
    
        local logText = ""
        local function addToLogText(text)
            domoticz.log("1 "..text, domoticz.LOG_DEBUG)
            logText = logText..text
            domoticz.log("logtext "..logText, domoticz.LOG_DEBUG)
        end
        local function printLogText()
            print("print")
            domoticz.devices("CustomLog").updateText(logText)
        end

	    
	    local turnOn = false
	    if (triggerInfo.trigger ~= nil) then
	        turnOn = string.match(triggerInfo.trigger, "at sunset")
        end
        if (triggeredItem.name == "Test") then
            -- 109 == Tree lights
            turnOn = (not domoticz.devices(109).active)
        end
        
	    if (not isNotDST(domoticz, turnOn)) then
	        return
        end

        for _,ip in pairs(DEVICE_IPs) do
            addToLogText("Attempting to switch device "..ip.." "..(turnOn and "on" or "false").."\n")
            
            domoticz.log("turn on: "..tostring(turnOn), domoticz.LOG_DEBUG)

            if (turnOn) then
                switchDevice(ip, true)
            else
                switchDevice(ip, false)
            end
 	    end
    end
}

Log output:

Code: Select all

2020-10-29 20:24:48.418 Status: dzVents: Info: ExteriorDecorationLights ::
2020-10-29 20:24:48.418
2020-10-29 20:24:48.418 ExteriorDecorationLights
2020-10-29 20:24:48.420 Status: dzVents: Debug: ExteriorDecorationLights :: Processing device-adapter for Tree Lights (Tree Socket 2): Switch device adapter
2020-10-29 20:24:48.420 Status: dzVents: Debug: ExteriorDecorationLights :: isDST :: Month: 10
2020-10-29 20:24:48.421 Status: dzVents: Debug: ExteriorDecorationLights :: isDST :: Day: 29
2020-10-29 20:24:48.421 Status: dzVents: Debug: ExteriorDecorationLights :: isDST :: Weekday: 4
2020-10-29 20:24:48.421 Status: dzVents: Debug: ExteriorDecorationLights :: 1 Attempting to switch device 192.168.2.2 on
2020-10-29 20:24:48.421
2020-10-29 20:24:48.421 Status: dzVents: Debug: ExteriorDecorationLights :: logtext Attempting to switch device 192.168.2.2 on
2020-10-29 20:24:48.421
2020-10-29 20:24:48.421 Status: dzVents: Debug: ExteriorDecorationLights :: turn on: true
2020-10-29 20:24:48.635 Status: dzVents: Debug: ExteriorDecorationLights :: switchDevice :: Attempting to switch on 192.168.2.2
2020-10-29 20:24:51.245 Status: dzVents: Info: ExteriorDecorationLights :: ------ Finished ExteriorDecorationLights

[waaren]

Now the issue is that the script seems to end prematurely.

The domoticz event system is single threaded. This means that you block the entire event system for as long as your script is active. To prevent even more damage, domoticz kills every event that takes more then 10 seconds.

There are several ways you can handle this using real async methods. My preference would be to use combinations of

domoticz.openUR()L and trigger httpResponses,
domoticz.emitEvent() and trigger customEvents,

but it is also possible to switch a dummy device or user variable after x seconds and have the script also trigger on those

Check the wiki for custom Events

[Timmiej93]

How sure are you about blocking the system as long as the script is active? I've had the "script running for more than 10 seconds" warning before, but that never seemed to freeze my Domoticz instance, nor did it seem to kill that specific script.

Is it possible to use openURL on anything other than URL calls?
emitEvent sounds interesting. Of course I searched for everything related to functions, but I never thought about events. Doh.

When you say "switch a dummy device or user variable after x seconds", do you mean doing that by the afterSec, afterMin, etc functions? If so, Isn't it so that those only start counting after the entire script has finished?

[waaren]

How sure are you about blocking the system as long as the script is active? I've had the "script running for more than 10 seconds" warning before, but that never seemed to freeze my Domoticz instance, nor did it seem to kill that specific script.

Pretty sure
Here is what happens in domoticz - dzVents

1. The domoticz eventsystem sends a trigger to dzVents.lua (This is the only script in the dzVents framework domoticz knows about)
2. dzVents.lua looks at all user script (in fact these are Lua modules) to see which ones needs triggering on this event.
3. Assume these are A, B, C and D
4. Control is handed over to module A
5. A finished after 1 second and dzVents hands over control to module B
6. B is busy for more the 10 seconds -> domoticz kills dzVents.lua but module B stays alive
7. modules C and D will not start anymore on this trigger

1. The domoticz eventsystem sends a new trigger to dzVents.lua

So now you have a module that is no longer connected to its main script with potential conflicts when it sends commands back to domoticz via the commandArray.

See below for a test script but better not use it on a system where your home automation depends on

Is it possible to use openURL on anything other than URL calls?

No. but an API URL call exists that will trigger a customEvent

Code: Select all

 /json.htm?type=command&param=customevent&event=<MyEvent>&data=myData

(in a dzVents script that's also possible using emitEvent)

When you say "switch a dummy device or user variable after x seconds", do you mean doing that by the afterSec, afterMin, etc functions? If so, Isn't it so that those only start counting after the entire script has finished?

Yes but that's also true for openURL and emitEvent. That is why you should not cause a delay in you scripts. Almost all my scripts are ready in less then 0.1 second and I have no scripts taking more then 1 second.

test script

Spoiler: show

Code: Select all

return 
{
    on = 
    {
        devices = 
        {
            119, 
            88,
        },
    },

    logging = 
    {
        level = domoticz.LOG_DEBUG,
        marker = 'test Kill',
    },

    execute = function(dz,item)
        if item.id == 119 then
            counter = 1    
            while counter < 50 do
                os.execute('sleep 6')
                dz.log(dz.time.rawTime .. ' Counter is now ' .. counter ,dz.LOG_DEBUG)
                counter = counter + 1
                dz.devices(88).switchOn() 
            end
            
        else
            dz.log('When does this make it to the log?',dz.LOG_ERROR)
        end
    end
}

[Timmiej93]

How sure are you about blocking the system as long as the script is active? I've had the "script running for more than 10 seconds" warning before, but that never seemed to freeze my Domoticz instance, nor did it seem to kill that specific script.

Pretty sure
Here is what happens in domoticz - dzVents

1. The domoticz eventsystem sends a trigger to dzVents.lua (This is the only script in the dzVents framework domoticz knows about)
2. dzVents.lua looks at all user script (in fact these are Lua modules) to see which ones needs triggering on this event.
3. Assume these are A, B, C and D
4. Control is handed over to module A
5. A finished after 1 second and dzVents hands over control to module B
6. B is busy for more the 10 seconds -> domoticz kills dzVents.lua but module B stays alive
7. modules C and D will not start anymore on this trigger

1. The domoticz eventsystem sends a new trigger to dzVents.lua

So now you have a module that is no longer connected to its main script with potential conflicts when it sends commands back to domoticz via the commandArray.

I can't put it any other way: That makes a lot of sense, thanks for the clear explanation.

Your reply has given me a lot of insight in how to create better dzVents scripts, thanks a lot!