Script runtime notification [Solved]

[guldi3]

Hello

I updated my Raspi to Buster and istalled the newes version of Domoticz. Now I have a notification or an error in the protocol log:

Code: Select all

2020-05-31 10:43:15.439 Error: dzVents: Error: (3.0.2) ------ Finished SolarWatt after >9 seconds. (using 8.552 seconds CPU time !)
2020-05-31 10:44:05.665 Status: dzVents: !Info: ------ Finished SolarWatt after >5 seconds. (using 5.047 seconds CPU time !)
2020-05-31 10:44:15.845 Error: dzVents: Error: (3.0.2) ------ Finished SolarWatt after >8 seconds. (using 8.604 seconds CPU time !)

"SolarWatt" is the script I created inside Domoticz script editor...

Is there any option to change the time limit to 10 and 15 seconds for this notifications?

Thanks for your help

Best regards

Rolf

[waaren]

"SolarWatt" is the script I created inside Domoticz script editor...
Is there any option to change the time limit to 10 and 15 seconds for this notifications?

Not possible to change the notification time. In fact it is a warning that your script takes too long and is blocking the complete event system.

Can you share the script. It might be possible to change the logic in such a way that part of the processing will take place in the background and will no longer block the event system for such a long time.

[guldi3]

Thanks Warren for your Help

Below is the code. Sorry for mixed language and not perfect scripting structure. I removed outcommented code for debugging and personal information.

Code: Select all

return {
   on = {
      timer = { 'every minute' },
      httpResponses = { 'energyRetrievedSolarWatt' }
   },
   data = {
        PowerIn = { history = true, maxItems = 20 },
        PowerOut = { history = true, maxItems = 20 },
        PowerWP = { history = true, maxItems = 1440 },
        WorkTimeWP = { history = true, maxItems = 50 },
        PowerEKZ = { history = true, maxItems = 20 }, --positiv: Bezug / negativ: Einspeisung
        LockWP = { initial = 19 }, --Counter for locking WP
        LastPowerWP = { initial = 0 },
        LimitOn = { initial = -6000 },
        LimitOff = { initial = 1000}, --Strom Bezug
        Counter = { initial = 0 },
        'DelayWP',
        'CounterMail'
    },
   execute = function(domoticz, item)
      if (item.isTimer) then
         domoticz.log('Timer!!!', domoticz.LOG_INFO)
         domoticz.openURL({
            url = 'http://192.168.xx.xx/rest/kiwigrid/wizard/devices',
            method = 'GET',
            callback = 'energyRetrievedSolarWatt'
         })
      elseif (item.isHTTPResponse) then
         if (item.ok) then -- statusCode == 2xx
    		domoticz.log('HTTP Solarwatt Responnse received...', domoticz.LOG_INFO)
    		
    		local Time = require('Time')
    		local t = Time()
    		local PowerWP = -99999
            local PowerIn = -99999
            local PowerOut = -99999
            local PowerPool = -99999
            local PowerHausPool = -99999
            local PowerForecast = 0
            local PowerHaus = 0
            local PowerEKZ = 0
            domoticz.data.initialize('LimitOn')
            domoticz.data.initialize('LimitOff')
            if (CounterMail == nil or CounterMail < 0 or CounterMail > 60) then CounterMail = 0 end
            
            -- Werte aus Solarwatt (Kiwigrid) Energiemanager auslesen
    		for i,v in ipairs(item.json['result']['items']) do
    		    if (v['tagValues']['IdName']['value'] == 'Wärmepumpe') then
                    PowerWP = v['tagValues']['PowerIn']['value']
                elseif (v['tagValues']['IdName']['value'] == 'Standort Guldener') then
                    PowerIn  = v['tagValues']['PowerIn']['value']
                    PowerOut = v['tagValues']['PowerOut']['value']
                    PowerEKZ = PowerIn - PowerOut
                    PowerForecast = 0;
                    for iforecast=1,96,1 do 
                        PowerForecast = PowerForecast + v['tagValues']['PowerProductionForecastValues']['value'][iforecast] 
                    end
                    PowerForecast = PowerForecast / 4
                elseif (v['tagValues']['IdName']['value'] == 'Pool' or v['tagValues']['IdName']['value'] == 'S0-Energiezähler 1 (0d16ffff0b0bffff1312ffff10ffff)') then --Pool
                    PowerPool  = v['tagValues']['PowerIn']['value']
                elseif (v['tagValues']['IdName']['value'] == 'S0-Energiezähler 1 (ERC04-100005801)') then --Pool
                    PowerHausPool  = v['tagValues']['PowerIn']['value']
                end
    		end
            PowerHaus = PowerHausPool - PowerPool
            if (CounterMail == 0) then
    		    if (PowerWP == -99999) then 
    		        domoticz.email('Domoticz capture error!','Keine Werte für Wärmepumpezähler erhalten!','[email protected]') 
    		        CounterMail = 60
    		    end 
    		    if (PowerIn == -99999) then 
    		        domoticz.email('Domoticz capture error!','Keine Werte für Standortzähler (PowerIn) erhalten!','[email protected]') 
    		        CounterMail = 60
    		    end 
    		    if (PowerOut == -99999) then 
    		        domoticz.email('Domoticz capture error!','Keine Werte für Standortzähler (PowerOut) erhalten!','[email protected]')
    		        CounterMail = 60
    		    end 
    		    if (PowerForecast == 0) then 
    		        domoticz.email('Domoticz capture error!','Keine Werte für Standortzähler (PowerForecast) erhalten!','[email protected]')
    		        CounterMail = 60
    		    end 
    		    if (PowerPool == -99999) then 
    		        domoticz.email('Domoticz capture error!','Keine Werte für Poolzähler erhalten!','[email protected]')
    		        CounterMail = 60
    		    end 
    		    if (PowerHausPool == -99999) then 
    		        domoticz.email('Domoticz capture error!','Keine Werte für Hauszähler erhalten!','[email protected]')
    		        CounterMail = 60
    		    end 
    		else
    		    CounterMail = CounterMail - 1
    		end


    		--Werte in Zähler von Domoticz schreiben
            domoticz.devices('Pool').updateEnergy(domoticz.utils.round(PowerPool,0))
            domoticz.devices('Wärmepumpe').updateEnergy(domoticz.utils.round(PowerWP,0))
            domoticz.devices('Haushalt').updateEnergy(domoticz.utils.round(PowerHaus,0))
            domoticz.devices('Bezug').updateEnergy(domoticz.utils.round(PowerIn,0))
            domoticz.devices('Einspeisung').updateEnergy(domoticz.utils.round(PowerOut,0))

            if (t.matchesRule('at 04:45-04:50')) then
                if (PowerForecast > 0) then 
                    domoticz.devices('Vorhersage').updateCustomSensor(domoticz.utils.round(PowerForecast/1000,1))
                else
                domoticz.log('HTTP Forcast.Solar send...', domoticz.LOG_ERROR)
                domoticz.openURL({
                    url = 'https://api.forecast.solar/estimate/47.266549/8.734622/45/-31/17.4',
                    method = 'GET',
                    callback = 'solarForecast'
                })
                end
            end
                
            
            --History für AVG anlegen
            domoticz.data.PowerIn.add(PowerIn)
            domoticz.data.PowerOut.add(PowerOut)
            domoticz.data.PowerWP.add(PowerWP)
            domoticz.data.PowerEKZ.add(PowerEKZ)
            
    		if (domoticz.data.LastPowerWP > 1000 and PowerWP < 1000) then
    		    domoticz.data.initialize('LockWP')
    		    domoticz.log('WP swiched off -> initialize LockWP', domoticz.LOG_ERROR)
    		    if ((domoticz.devices('Freigabe WP').active) and t.matchesRule('at 06:55-20:05'))  then
    		        domoticz.devices('Freigabe WP').switchOff()
    		    end
		    end
		    domoticz.data.LastPowerWP = PowerWP
    		if (domoticz.data.LockWP > 0) then
    		    domoticz.data.LockWP = domoticz.data.LockWP - 1
    		end
    		
    		--Count working WP Compressors and Time
    		domoticz.data.Counter = domoticz.data.Counter + 1
    		if (PowerWP < 2500) then
    		    if (domoticz.devices('Wärmepumpe Kompressor').level ~= 0) then 
    		        domoticz.devices('Wärmepumpe Kompressor').switchSelector(0) 
		            domoticz.data.WorkTimeWP.add(domoticz.data.Counter)
		            domoticz.log('WP worked for '..domoticz.data.Counter..' minutes. AVG: '..domoticz.utils.round(domoticz.data.WorkTimeWP.avgSince('24:00:00'),0)..' minutes...', domoticz.LOG_ERROR)
		            domoticz.devices('Arbeitszeit WP').updateText(domoticz.data.Counter..' Minuten ('..domoticz.utils.round(domoticz.data.WorkTimeWP.avgSince('24:00:00'),0)..')')
		            domoticz.data.DelayWP = domoticz.utils.round(domoticz.data.WorkTimeWP.avgSince('24:00:00'),0) * 0.8
		            if (domoticz.data.DelayWP < 0) then domoticz.data.DelayWP = 0 end
		        end
    		end
    		if (PowerWP > 2500 and PowerWP < 7250) then
    		    if (domoticz.devices('Wärmepumpe Kompressor').level == 0) then 
    		        domoticz.devices('Wärmepumpe Kompressor').switchSelector(10) 
		            domoticz.data.initialize('Counter')
		        end
    		end
    		if (PowerWP > 7250 and PowerWP < 12500) then
    		    if (domoticz.devices('Wärmepumpe Kompressor').level == 10) then domoticz.devices('Wärmepumpe Kompressor').switchSelector(20) end
    		end
    		if (PowerWP > 12500) then
    		    if (domoticz.devices('Wärmepumpe Kompressor').level == 20) then domoticz.devices('Wärmepumpe Kompressor').switchSelector(30) end
    		end
    		
    		
    		-- Energie Otimierer    
    		if (domoticz.devices('Energie Optimierer').active) then
    		    
    		--Switch control
    		
                    --Ausschalt - Limit
                    local limitLow = 0;
                    limitLow = domoticz.data.LimitOn + 1500 + domoticz.data.PowerWP.avgSince('00:05:00');
       		        if ((tonumber(domoticz.devices('Wärmepumpe Kompressor').level) > 0) or (limitLow > domoticz.data.LimitOff)) then
       		            limitLow = domoticz.data.LimitOff
       		        end
       		        domoticz.devices('LimitLow').updateTemperature(-limitLow);
       		        
                    --Einschalte - Limit
           		    local limitHigh = 0
    		        if (tonumber(domoticz.devices('Wärmepumpe Kompressor').level) > 0) then
    		            limitHigh = limitLow;
    		        elseif ((domoticz.data.LimitOn + domoticz.data.PowerWP.avgSince('00:05:00') )<0) then limitHigh = domoticz.data.LimitOn + domoticz.data.PowerWP.avgSince('00:05:00') end
       		        domoticz.devices('LimitHight').updateTemperature(-limitHigh);
       		        domoticz.devices('Limitten').updateCurrent(-limitHigh,-limitLow,-domoticz.data.PowerEKZ.avgSince('00:05:00'));
                    domoticz.devices('PowerEKZ').updateTemperature(-domoticz.data.PowerEKZ.avgSince('00:05:00'));


    		    
                -- Zeitschaltuhr
                if (t.matchesRule('at 20:05-06:55') and (domoticz.devices('Wärmepumpe Sommerbetrieb').active == false or tonumber(domoticz.devices('Vorhersage')._state) < 60) or domoticz.devices('Wärmepumpe Sommerbetrieb').active == true and t.matchesRule('at 20:05-05:00')) then
                    if (domoticz.devices('Freigabe WP').active == false) then
                        domoticz.log('Im Zeitfenster Niedertarif!!!', domoticz.LOG_ERROR)
                        domoticz.devices('Freigabe WP').switchOn()
                        domoticz.devices('Status Optimierer').updateText('Niedertarif -> On')
                    end
                else
                    -- Verbrauchsoptimierer
                    
                    --Ausschalten
                    if (domoticz.devices('Freigabe WP').active) then
                        if (domoticz.data.PowerEKZ.avgSince('00:05:00') > limitLow) then
                            domoticz.devices('Freigabe WP').switchOff()
                            domoticz.log('Freigabe WP ausgeschaltet! PowerEKZ(' .. domoticz.utils.round(domoticz.data.PowerEKZ.avgSince('00:05:00'),0) .. ') > '..domoticz.utils.round(limitLow,0), domoticz.LOG_ERROR)
                            domoticz.devices('Status Optimierer').updateText('Aus: PowerEKZ avg('..domoticz.utils.round(domoticz.data.PowerEKZ.avgSince('00:05:00'),0) .. ') > Limit('..domoticz.utils.round(limitLow,0)..')')
                        end
                    else
                    
                    --Einschalten
                        if (domoticz.data.PowerEKZ.avgSince('00:05:00')  < limitHigh) then
                            if ((domoticz.data.DelayWP < domoticz.data.Counter or domoticz.devices('Wärmepumpe Kompressor').level == 0 or t.matchesRule('at 10:59-12:01')) and domoticz.data.LockWP == 0) then
                                --Einschaltbedingung erfüllt
                                domoticz.devices('Freigabe WP').switchOn()
                                domoticz.log('Freigabe WP eingeschaltet! PowerEKZ AVG(' .. domoticz.utils.round(domoticz.data.PowerEKZ.avgSince('00:05:00'),0) .. ') <min('..domoticz.data.LimitOn..' + WP (' .. domoticz.utils.round(domoticz.data.PowerWP.avgSince('00:05:00'),0) .. '),0) Limit:'..domoticz.utils.round(limitHigh,0)..'!', domoticz.LOG_ERROR)
                                domoticz.devices('Status Optimierer').updateText('On: PowerEKZ avg(' .. domoticz.utils.round(domoticz.data.PowerEKZ.avgSince('00:05:00'),0) .. ') <  Limit('..domoticz.utils.round(limitHigh,0)..')')
                            elseif (domoticz.data.LockWP > 0) then  --WP is in 15min block
                                --Einschaltbedingung NICHT erfüllt
                                domoticz.devices('Status Optimierer').updateText('WP Locked: PowerEKZ avg(' .. domoticz.utils.round(domoticz.data.PowerEKZ.avgSince('00:05:00'),0) .. ') <  Limit('..domoticz.utils.round(limitHigh,0)..')')
                            else
                                --Einschaltbedingung NICHT erfüllt
                                domoticz.devices('Status Optimierer').updateText('Delayed: PowerEKZ avg(' .. domoticz.utils.round(domoticz.data.PowerEKZ.avgSince('00:05:00'),0) .. ') <  Limit('..domoticz.utils.round(limitHigh,0)..')')
                            end
                        end
                    end
                end
            else  --Optimierer Ausgeschalten
                domoticz.log(domoticz.devices('Status Optimierer').text, domoticz.LOG_ERROR)
    		    if (domoticz.devices('Status Optimierer').text ~= 'Optimierer deaktiviert!') then domoticz.devices('Status Optimierer').updateText('Optimierer deaktiviert!') end
            end
         if (domoticz.devices('Freigabe WP').active) then domoticz.devices('WPFreigabe').updateTemperature(10000); else domoticz.devices('WPFreigabe').updateTemperature(0); end
         end
      end
   end
}

[waaren]

Below is the code. Sorry for mixed language and not perfect scripting structure. I removed outcommented code for debugging and personal information.

The only potential performance problem I see in this script is the large number of maxItems in persistent historical data. Especial the maxItems = 1440 in PowerWP is very high and does require dzVents to do large amounts of disk IO every minute.
WIthout having analyzed the script in detail, I do not see a particular reason to have such an enormous amount of history. Can you explain why you need / want this ? ( I only see that you look at the average of the last 5 minutes. )


from the wiki

Reminder: don’t store too much data. Only put in what you really need!

and

Again, make sure you don’t put too much stuff in your persisted data as it may slow things down too much.

I also see that you initialize some of your persistent data every script execution. (LimitOn, LimitOff) I don't understand why you use persistent data for these values.

[guldi3]

Thanks waaren for this helpful inputs.

I reduce the maxItem to 20 (that was an old idea I no more use). That has reduced the running time. Now the script uses about 4 seconds. Most time consumation is in the initial part of script. It use near 4 seconds from start message to the first code (line 31).

Log:

Code: Select all

2020-05-31 15:15:02.773 Status: dzVents: Info: ------ Start internal script: SolarWatt: HTTPResponse: "energyRetrievedSolarWatt"
2020-05-31 15:15:06.353 Status: dzVents: Info: HTTP Solarwatt Responnse received...
2020-05-31 15:15:06.664 Status: dzVents: Info: ------ Finished SolarWatt 

Now, I'm in the Limit and no more log message are generated.

Thanks waaren

Best regards

Rolf