Pumpenmonitoring - Triggering Item unzuverlässig

int5749 · Beitrag von **int5749** » 12. Jan 2022 15:42

Update: Ich verstehe die Welt nicht mehr.

Seit der Änderung (und es war im gesamten OH System nur diese eine Änderung) mit dem Einbau der zusätzlichen Loggings, tritt der Fehler nicht mehr auf. Insgesamt ist die Pumpe mind. 35x angesprungen (da es nicht mehr regnet, kommt nicht mehr so viel Wasser nach und die Abstände werden größer).

So schön es ist, wenn ein Fehler nicht mehr auftritt, so frustrierend ist ist nicht zu wissen woran es gelegen hat

udo1toni · Beitrag von **udo1toni** » 12. Jan 2022 20:03

Ja, hässlich.

int5749 · Beitrag von **int5749** » 13. Jan 2022 07:46

udo1toni hat geschrieben: ↑12. Jan 2022 20:03 Ja, hässlich.

So etwas lässt mir natürlich keine Ruhe und ich habe gestern noch einiges an Zeit investiert. Zum Schluß habe ich das zusätzliche Logging wieder entfernt und der Fehler war wieder da

Ich habe mal (bei einigen Blöcken) die Schaltzustände ergänzt aus dem Event-Log.

Code: Alles auswählen

2022-01-12 21:29:44.455 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'ki.rules'	<< Logging raus

2022-01-12 21:31:26.313 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'PumpDrainage_vSwitch' received command ON
2022-01-12 21:31:26.316 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpDrainage_vSwitch' changed from OFF to ON
2022-01-12 21:31:26.316 [INFO ] [org.openhab.core.model.script.Water ] - 1642019486
2022-01-12 21:31:26.319 [INFO ] [org.openhab.core.model.script.Water ] - Alarmtimer für Entwässerungspumpe gestartet
2022-01-12 21:31:30.437 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'PumpDrainage_vSwitch' received command OFF
2022-01-12 21:31:30.443 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpDrainage_vSwitch' changed from ON to OFF
2022-01-12 21:31:30.987 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe lief 4 Sekunden

2022-01-12 22:01:39.841 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'PumpWasteWater_vSwitch' received command ON
2022-01-12 22:01:39.847 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpWasteWater_vSwitch' changed from OFF to ON
2022-01-12 22:01:42.578 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'PumpWasteWater_vSwitch' received command OFF
2022-01-12 22:01:42.582 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpWasteWater_vSwitch' changed from ON to OFF
2022-01-12 22:01:44.150 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'PumpFeedingWater_vSwitch' received command ON
2022-01-12 22:01:44.152 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpFeedingWater_vSwitch' changed from OFF to ON
2022-01-12 22:01:44.153 [INFO ] [org.openhab.core.model.script.Water ] - Hauswasserwerk ist angelaufen
2022-01-12 22:01:44.153 [INFO ] [org.openhab.core.model.script.Water ] - Watchdog für Hauswasserwerk gestartet
2022-01-12 22:01:46.229 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'PumpFeedingWater_vSwitch' received command OFF
2022-01-12 22:01:46.234 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpFeedingWater_vSwitch' changed from ON to OFF
2022-01-12 22:01:47.563 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'PumpDrainage_vSwitch' received command ON
2022-01-12 22:01:47.571 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpDrainage_vSwitch' changed from OFF to ON
2022-01-12 22:01:47.568 [INFO ] [org.openhab.core.model.script.Water ] - 1642021307
2022-01-12 22:01:47.568 [INFO ] [org.openhab.core.model.script.Water ] - Alarmtimer für Entwässerungspumpe gestartet
2022-01-12 22:01:52.168 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'PumpDrainage_vSwitch' received command OFF
2022-01-12 22:01:52.173 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpDrainage_vSwitch' changed from ON to OFF
2022-01-12 22:01:52.928 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe lief 5 Sekunden
2022-01-12 22:01:54.154 [INFO ] [org.openhab.core.model.script.Water ] - Watchdog für Hauswasserwerk beendet

2022-01-12 22:08:38.558 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe ist angelaufen.
2022-01-12 22:08:39.375 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe lief 411 Sekunden
2022-01-12 22:08:39.376 [ERROR] [internal.handler.ScriptActionHandler] - Script execution of rule with UID 'ki-19' failed: cannot invoke method public abstract boolean org.openhab.core.model.script.actions.Timer.cancel() on null in ki
2022-01-12 22:08:43.740 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe zieht derzeit 13.13 mA.
2022-01-12 22:08:48.734 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe zieht derzeit 12.96 mA.
2022-01-12 22:08:51.891 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe hat abgeschaltet.
2022-01-12 22:08:52.652 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe lief 424 Sekunden
2022-01-12 22:08:52.653 [ERROR] [internal.handler.ScriptActionHandler] - Script execution of rule with UID 'ki-19' failed: cannot invoke method public abstract boolean org.openhab.core.model.script.actions.Timer.cancel() on null in ki

Dreimal kurz überlegt und ..... Nein, das kann nicht sein, das ein Logging dies beeinflusst

Also Logging wieder rein und .... ich konnte den Fehler endlich "reproduzieren" (wenn auch noch nicht die Ursache erkennen)

Code: Alles auswählen

2022-01-12 22:10:23.504 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'ki.rules'	<< Logging rein

<< manuelle Tests >>
2022-01-12 22:10:40.807 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'PumpWasteWater_vSwitch' received command ON
2022-01-12 22:10:40.810 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpWasteWater_vSwitch' changed from OFF to ON
2022-01-12 22:10:43.179 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'PumpWasteWater_vSwitch' received command OFF
2022-01-12 22:10:43.181 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpWasteWater_vSwitch' changed from ON to OFF
2022-01-12 22:10:44.466 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'PumpFeedingWater_vSwitch' received command ON
2022-01-12 22:10:44.471 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpFeedingWater_vSwitch' changed from OFF to ON
2022-01-12 22:10:44.468 [INFO ] [org.openhab.core.model.script.Water ] - Hauswasserwerk ist angelaufen
2022-01-12 22:10:44.469 [INFO ] [org.openhab.core.model.script.Water ] - Watchdog für Hauswasserwerk gestartet
2022-01-12 22:10:46.445 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'PumpFeedingWater_vSwitch' received command OFF
2022-01-12 22:10:46.448 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpFeedingWater_vSwitch' changed from ON to OFF
2022-01-12 22:10:47.798 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'PumpDrainage_vSwitch' received command ON
2022-01-12 22:10:47.802 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpDrainage_vSwitch' changed from OFF to ON
2022-01-12 22:10:47.800 [INFO ] [org.openhab.core.model.script.Water ] - 1642021847
2022-01-12 22:10:47.801 [INFO ] [org.openhab.core.model.script.Water ] - Alarmtimer für Entwässerungspumpe gestartet
2022-01-12 22:10:49.767 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'PumpDrainage_vSwitch' received command OFF
2022-01-12 22:10:49.771 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpDrainage_vSwitch' changed from ON to OFF
2022-01-12 22:10:50.070 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe lief 2 Sekunden
2022-01-12 22:10:54.470 [INFO ] [org.openhab.core.model.script.Water ] - Watchdog für Hauswasserwerk beendet

<< Eigenständig Angelaufen >>
22022-01-13 00:23:01.196 [INFO ] [hab.event.GroupItemStateChangedEvent] - Item 'gPump' changed from 0.0 to 18.16 through PumpDrainage_Power
2022-01-13 00:23:01.196 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpDrainage_Power' changed from 0.0 to 18.16
022-01-13 00:23:01.200 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe ist angelaufen.
2022-01-13 00:23:01.202 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpDrainage_vSwitch' changed from OFF to ON
2022-01-13 00:23:01.978 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe lief 7934 Sekunden

2022-01-13 00:23:01.979 [ERROR] [internal.handler.ScriptActionHandler] - Script execution of rule with UID 'ki-19' failed: cannot invoke method public abstract boolean org.openhab.core.model.script.actions.Timer.cancel() on null in ki

2022-01-13 00:23:06.254 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpDrainage_Power' changed from 18.16 to 13.1
2022-01-13 00:23:06.254 [INFO ] [hab.event.GroupItemStateChangedEvent] - Item 'gPump' changed from 18.16 to 13.1 through PumpDrainage_Power
2022-01-13 00:23:06.265 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe zieht derzeit 13.1 mA.
2022-01-13 00:23:11.249 [INFO ] [hab.event.GroupItemStateChangedEvent] - Item 'gPump' changed from 13.1 to 12.780000000000001 through PumpDrainage_Power
2022-01-13 00:23:11.250 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpDrainage_Power' changed from 13.1 to 12.780000000000001
2022-01-13 00:23:11.253 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe zieht derzeit 12.780000000000001 mA.
2022-01-13 00:23:14.529 [INFO ] [hab.event.GroupItemStateChangedEvent] - Item 'gPump' changed from 12.780000000000001 to 1.09 through PumpDrainage_Power
2022-01-13 00:23:14.529 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpDrainage_Power' changed from 12.780000000000001 to 1.09
2022-01-13 00:23:14.532 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe zieht derzeit 1.09 mA.
2022-01-13 00:23:16.244 [INFO ] [hab.event.GroupItemStateChangedEvent] - Item 'gPump' changed from 1.09 to 0.0 through PumpDrainage_Power
2022-01-13 00:23:16.245 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpDrainage_Power' changed from 1.09 to 0.0
2022-01-13 00:23:16.248 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe hat abgeschaltet.
2022-01-13 00:23:16.250 [INFO ] [org.openhab.core.model.script.Water ] - 1642029796
2022-01-13 00:23:16.250 [INFO ] [org.openhab.core.model.script.Water ] - Alarmtimer für Entwässerungspumpe gestartet
2022-01-13 00:23:16.252 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpDrainage_vSwitch' changed from ON to OFF
2022-01-13 00:24:01.983 [INFO ] [org.openhab.core.model.script.Water ] - Watchdog für Entwässerungspumpe wird gelöscht

<< Eigenständig Angelaufen >>
2022-01-13 02:46:26.201 [INFO ] [hab.event.GroupItemStateChangedEvent] - Item 'gPump' changed from 0.0 to 7.0 through PumpDrainage_Power
2022-01-13 02:46:26.201 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpDrainage_Power' changed from 0.0 to 7.0
2022-01-13 02:46:26.206 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpDrainage_vSwitch' changed from OFF to ON
2022-01-13 02:46:26.204 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe ist angelaufen.
2022-01-13 02:46:26.734 [INFO ] [hab.event.GroupItemStateChangedEvent] - Item 'gPump' changed from 7.0 to 13.8 through PumpDrainage_Power
2022-01-13 02:46:26.734 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpDrainage_Power' changed from 7.0 to 13.8
2022-01-13 02:46:26.738 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe zieht derzeit 13.8 mA.
2022-01-13 02:46:26.942 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe lief 8590 Sekunden

2022-01-13 02:46:26.943 [ERROR] [internal.handler.ScriptActionHandler] - Script execution of rule with UID 'ki-19' failed: cannot invoke method public abstract boolean org.openhab.core.model.script.actions.Timer.cancel() on null in ki

2022-01-13 02:46:28.271 [INFO ] [hab.event.GroupItemStateChangedEvent] - Item 'gPump' changed from 13.8 to 13.31 through PumpDrainage_Power
2022-01-13 02:46:28.272 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpDrainage_Power' changed from 13.8 to 13.31
2022-01-13 02:46:28.275 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe zieht derzeit 13.31 mA.
2022-01-13 02:46:33.267 [INFO ] [hab.event.GroupItemStateChangedEvent] - Item 'gPump' changed from 13.31 to 12.94 through PumpDrainage_Power
2022-01-13 02:46:33.267 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpDrainage_Power' changed from 13.31 to 12.94
2022-01-13 02:46:33.273 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe zieht derzeit 12.94 mA.
2022-01-13 02:46:38.262 [INFO ] [hab.event.GroupItemStateChangedEvent] - Item 'gPump' changed from 12.94 to 12.780000000000001 through PumpDrainage_Power
2022-01-13 02:46:38.263 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpDrainage_Power' changed from 12.94 to 12.780000000000001
2022-01-13 02:46:38.265 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe zieht derzeit 12.780000000000001 mA.
2022-01-13 02:46:39.533 [INFO ] [hab.event.GroupItemStateChangedEvent] - Item 'gPump' changed from 12.780000000000001 to 4.09 through PumpDrainage_Power
2022-01-13 02:46:39.534 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpDrainage_Power' changed from 12.780000000000001 to 4.09
2022-01-13 02:46:39.536 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe zieht derzeit 4.09 mA.
2022-01-13 02:46:43.257 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpDrainage_Power' changed from 4.09 to 0.0
2022-01-13 02:46:43.257 [INFO ] [hab.event.GroupItemStateChangedEvent] - Item 'gPump' changed from 4.09 to 0.0 through PumpDrainage_Power
2022-01-13 02:46:43.261 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpDrainage_vSwitch' changed from ON to OFF
2022-01-13 02:46:43.260 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe hat abgeschaltet.
2022-01-13 02:46:44.013 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe lief 8607 Sekunden

2022-01-13 02:46:44.014 [ERROR] [internal.handler.ScriptActionHandler] - Script execution of rule with UID 'ki-19' failed: cannot invoke method public abstract boolean org.openhab.core.model.script.actions.Timer.cancel() on null in ki

Der Unterschied: Solange nur die Entwässerungspumpe anläuft und entsprechend beendet wird, klappt die Rule wie erwartet. Das Problem tritt offensichtlich auf, wenn eine der beiden anderen Pumpen anläuft/beendet wird. Da scheint die Rule irgendwie durcheinander zu kommen?

Derzeit ist folgende Rule aus den Test noch aktiv:

Code: Alles auswählen

var long Drainage_Starttime
var Number Drainage_Length

var Timer t_watchdogdrainage = null	//Timer zur Überwachung der Entwässerungspumpe
var Timer t_watchdogfeeding = null	//Timer zur Überwachung des Hauswasserwerks

rule "Pump Action"      //(Aktion und Meldung)
when
    Member of gPumpOn received update
then
    val actions = getActions("pushover", "pushover:pushover-account:account")
    switch(triggeringItem.name.split("_").get(0)) {
        case "PumpDrainage"     : {				// Entwässerungspumpe EIN
            val strLabel = PumpDrainage_vSwitch.label
            if (triggeringItem.state == ON) {
                if (t_watchdogdrainage === null) {
                    Drainage_Starttime = new DateTimeType().zonedDateTime.toInstant.toEpochMilli / 1000
                    logInfo("Water", Drainage_Starttime.toString)
                    logInfo("Water", "Alarmtimer für {} gestartet", strLabel)
                    actions.sendMessageToDevice("iPhone", strLabel + " ist angelaufen.", "Notification")

                    t_watchdogdrainage = createTimer(now.plusSeconds(45),[ |
                        if (PumpDrainage_vSwitch.state == ON) {
                            Drainage_Length = (new DateTimeType().zonedDateTime.toInstant.toEpochMilli / 1000) - Drainage_Starttime
                            actions.sendMessageToDevice("iPhone", PumpDrainage_vSwitch.label + " läuft seit " + Drainage_Length.toString + " Sekunden!", "Alert: " + OffsetDateTime.now().toString)
                            if (Parents.state == ON) {
                                if (SleepMode.state == 1) {
                                    Steckd_OG_Schlafz_Schrank.sendCommand(ON)
                                    Lampe_OG_Flur_Deko.sendCommand(ON)
                                } else if (Night.state == ON && SleepMode.state == 0) {
                                    Lampe_EG_Deko_Wand.sendCommand(ON)
                                }
                            }
							logInfo("Water","Watchdog für {} wird erneut gestartet", strLabel)
                            t_watchdogdrainage.reschedule(now.plusSeconds(30))
                        } else if (PumpDrainage_vSwitch.state == (OFF)) {
							logInfo("Water","Watchdog für {} wird gelöscht", strLabel)
                            t_watchdogdrainage = null
                        }
                    ])
                }
            } else {							// Entwässerungspumpe AUS (zur Überwachung)
                Drainage_Length = (new DateTimeType().zonedDateTime.toInstant.toEpochMilli / 1000) - Drainage_Starttime
                actions.sendMessageToDevice("iPhone", strLabel + " hat nach " + Drainage_Length.toString + " Sekunden abgeschaltet.", "Notification")
                logInfo("Water", "{} lief {} Sekunden", strLabel, Drainage_Length.toString)

                t_watchdogdrainage.cancel
                t_watchdogdrainage = null
                return;
            }
        }
        case "PumpFeedingWater" : {				// Hauswasserwerk EIN
            if(triggeringItem.state == ON) {	//raus weil Gardena Binding noch nicht aktiv      && myIrrigationSwitchVis.state == ON) 
                logInfo("Water", "{} ist angelaufen", PumpFeedingWater_vSwitch.label)
				if (t_watchdogfeeding === null) {
                    logInfo("Water", "Watchdog für {} gestartet", PumpFeedingWater_vSwitch.label)
                    t_watchdogfeeding = createTimer(now.plusSeconds(10), [ |
                        if (PumpFeedingWater_vSwitch.state == (ON)) {
                            if(Parents.state == ON) {
                                logInfo("Water", "Lampe_EG_Deko_Wand.sendCommand(ON)")
                            } else {
                                actions.sendMessageToDevice("iPhone", PumpFeedingWater_vSwitch.label + " läuft seit 10 Sekunden!", "Alert")
                                t_watchdogfeeding.reschedule(now.plusSeconds(10))
                                logInfo("Water", "{} läuft 10 Sec.", PumpFeedingWater_vSwitch.label)
                            }
                        } else {
                            t_watchdogfeeding = null
                            logInfo("Water", "Watchdog für {} beendet", PumpFeedingWater_vSwitch.label)
                        }
                    ])
                }
            }
        }
        case "PumpWasteWater"   : {				// Schmutzwasserpumpe EIN
            if (triggeringItem.state == ON && Washer_Power.state == 0) {
                actions.sendMessageToDevice("iPhone", "Warum läuft die " + PumpWasteWater_vSwitch.label + "?", "Alert")
            }
        }
    }
end

Viele Grüße

int5749 · Beitrag von **int5749** » 13. Jan 2022 08:45

Wenn ich mir diesen Block anschaue

Code: Alles auswählen

<< Eigenständig Angelaufen >>
22022-01-13 00:23:01.196 [INFO ] [hab.event.GroupItemStateChangedEvent] - Item 'gPump' changed from 0.0 to 18.16 through PumpDrainage_Power
2022-01-13 00:23:01.196 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpDrainage_Power' changed from 0.0 to 18.16
022-01-13 00:23:01.200 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe ist angelaufen.
2022-01-13 00:23:01.202 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpDrainage_vSwitch' changed from OFF to ON
2022-01-13 00:23:01.978 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe lief 7934 Sekunden

fällt auf, dass die Pumpe um 00:23:01 anläuft und der Status von PumpDrainage_vSwitch eigentlich ON sein müsste.
Eigentlich sollte der Status ja schon bekannt sein, da eine Status Änderung die Rule triggered. Dennoch arbeitet die Rule den else Teil ab und rechnet die Sekunden. Teilt man die Sekunden nun durch 60, landet man ziemlich genau beim letzten Lauf der Pumpe. Ggfs müsste ich die beiden Variablen ebenfalls zurücksetzen, wobei dadurch zumindest das Fehlverhalten erkannt wurde. Denn eigentlich ist es Wurscht, was in diesen Variablen steht, da diese (wenn die Rule sauber läuft) mit den aktuellen Werten befüllt werden.

Derzeit finde ich noch keine Erklärung, warum der else Part abgearbeitet wird, obwohl der Status des triggernden Item ON ist.

udo1toni · Beitrag von **udo1toni** » 13. Jan 2022 15:55

Eventuell läuft die Rule zeitgleich mehrfach. Eventuell wäre es besser, den Trigger auf changed zu ändern, statt received update.
Diese Zeile:

Code: Alles auswählen

022-01-13 00:23:01.200 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe ist angelaufen.

stammt nicht aus dieser Rule! Oder Du hast nicht den aktuellen Code gepostet... Im Code steht nur an zwei Stellen das Wort "angelaufen", und die eine Stelle ist ein pushover, welches nicht im log landet. Die andere Stelle wird nur ausgeführt, wenn das Hauswasserwerk läuft. und muss entsprechend ein anderes Label ausgeben.

int5749 · Beitrag von **int5749** » 13. Jan 2022 17:30

udo1toni hat geschrieben: ↑13. Jan 2022 15:55 Diese Zeile:
Code: Alles auswählen
022-01-13 00:23:01.200 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe ist angelaufen.
stammt nicht aus dieser Rule! Oder Du hast nicht den aktuellen Code gepostet... Im Code steht nur an zwei Stellen das Wort "angelaufen", und die eine Stelle ist ein pushover, welches nicht im log landet. Die andere Stelle wird nur ausgeführt, wenn das Hauswasserwerk läuft. und muss entsprechend ein anderes Label ausgeben.

Klassisches Jain

Ja, es ist (war) der aktuelle Code.
Nein, es stammt nicht aus der zuletzt geposteten Rule. Die Rule, aus der dies stammt war im ersten Thread und triggered quasi die andere und diese hatte ich nicht noch einmal gepostet, da es ja keine Änderungen gab.

Ich habe dies zum Anlass genommen und das Logging für alle 3 Pumpen gerade gezogen und ein weiteres generelles Logging eingebaut.

Die nun aktiven Rules lauten

Code: Alles auswählen

var long Drainage_Starttime
var Number Drainage_Length

var Timer t_watchdogdrainage = null	//Timer zur Überwachung der Entwässerungspumpe
var Timer t_watchdogfeeding = null	//Timer zur Überwachung des Hauswasserwerks

rule PumpMonitor
when
	Member of gPump changed
then
	val myPump = gPumpOn.members.filter[ i|i.name.contains(triggeringItem.name.split("_").get(0))].head
	if (triggeringItem.state > 0 && previousState == 0 && myPump.state != ON) {
		myPump.postUpdate(ON)
		logInfo("Water", "{} wurde aktiviert.", triggeringItem.label)    // <------ angelaufen geändert um Verwechslung zu vermeiden,
	} else if (triggeringItem.state > 0 && previousState > 0) {
		logInfo("Water", "{} zieht derzeit {} mA.", triggeringItem.label, triggeringItem.state)
	} else if (triggeringItem.state == 0 && previousState > 0 && myPump.state != OFF) {
		myPump.postUpdate(OFF)
		logInfo("Water", "{} hat abgeschaltet.", triggeringItem.label)
	}
end

rule "Pump Action"      //(Aktion und Meldung)
when
	Member of gPumpOn received update
then
	val actions = getActions("pushover", "pushover:pushover-account:account")
	logInfo("Water", "{} ist angelaufen mit Status: {}", triggeringItem.name.split("_").get(0), triggeringItem.state)      // <------ Generelles Logging
	switch(triggeringItem.name.split("_").get(0)) {
		case "PumpDrainage"     : {				// Entwässerungspumpe EIN
			val strLabel = PumpDrainage_vSwitch.label
			if (triggeringItem.state == ON) {
				logInfo("Water", "{} ist angelaufen", strLabel)
				if (t_watchdogdrainage === null) {
					Drainage_Starttime = new DateTimeType().zonedDateTime.toInstant.toEpochMilli / 1000
					logInfo("Water", Drainage_Starttime.toString)
					logInfo("Water", "Watchdog für {} gestartet", strLabel)	// <------ Standadisiert
					actions.sendMessageToDevice("iPhone", strLabel + " ist angelaufen.", "Notification")

					t_watchdogdrainage = createTimer(now.plusSeconds(45),[ |
						if (PumpDrainage_vSwitch.state == ON) {
							Drainage_Length = (new DateTimeType().zonedDateTime.toInstant.toEpochMilli / 1000) - Drainage_Starttime
							actions.sendMessageToDevice("iPhone", PumpDrainage_vSwitch.label + " läuft seit " + Drainage_Length.toString + " Sekunden!", "Alert")
							if (Parents.state == ON) {
								if (SleepMode.state == 1) {
									Steckd_OG_Schlafz_Schrank.sendCommand(ON)
									Lampe_OG_Flur_Deko.sendCommand(ON)
								} else if (Night.state == ON && SleepMode.state == 0) {
									Lampe_EG_Deko_Wand.sendCommand(ON)
								}
							}
							logInfo("Water","Watchdog für {} wird erneut gestartet", strLabel)
							t_watchdogdrainage.reschedule(now.plusSeconds(30))
						} else if (PumpDrainage_vSwitch.state == (OFF)) {
							logInfo("Water","Watchdog für {} wird gelöscht", strLabel)
							t_watchdogdrainage = null
						}
					])
				}
			} else {							// Entwässerungspumpe AUS (zur Überwachung)
				Drainage_Length = (new DateTimeType().zonedDateTime.toInstant.toEpochMilli / 1000) - Drainage_Starttime
				actions.sendMessageToDevice("iPhone", strLabel + " hat nach " + Drainage_Length.toString + " Sekunden abgeschaltet.", "Notification")
				logInfo("Water", "{} lief {} Sekunden", strLabel, Drainage_Length.toString)

				t_watchdogdrainage.cancel
				t_watchdogdrainage = null
				return;
			}
		}
		case "PumpFeedingWater" : {				// Hauswasserwerk EIN
			val strLabel = PumpFeedingWater_vSwitch.label	// <------ Standadisiert
			if(triggeringItem.state == ON) {	//raus weil Gardena Binding noch nicht aktiv      && myIrrigationSwitchVis.state == ON) 
				logInfo("Water", "{} ist angelaufen", strLabel)	// <------ Standadisiert
				if (t_watchdogfeeding === null) {
					logInfo("Water", "Watchdog für {} gestartet", strLabel)
					t_watchdogfeeding = createTimer(now.plusSeconds(10), [ |
						if (PumpFeedingWater_vSwitch.state == (ON)) {
							if(Parents.state == ON) {
								logInfo("Water", "Lampe_EG_Deko_Wand.sendCommand(ON)")
							} else {
								actions.sendMessageToDevice("iPhone", strLabel + " läuft seit 10 Sekunden!", "Alert")
								t_watchdogfeeding.reschedule(now.plusSeconds(10))
								logInfo("Water", "{} läuft 10 Sec.", strLabel)
							}
						} else {
							t_watchdogfeeding = null
							logInfo("Water", "Watchdog für {} beendet", strLabel)
						}
					])
				}
			}
		}
		case "PumpWasteWater"   : {				// Schmutzwasserpumpe EIN
			val strLabel = PumpWasteWater_vSwitch.label	// <------ Standadisiert
			if (triggeringItem.state == ON && Washer_Power.state == 0) {
				actions.sendMessageToDevice("iPhone", "Warum läuft die " + strLabel + "?", "Alert")
			}
		}
	}
end

Ich werde zunächst noch einmal mit diesem Status testen, ob ich den Fehler forcieren kann.

udo1toni hat geschrieben: ↑13. Jan 2022 15:55 Eventuell läuft die Rule zeitgleich mehrfach. Eventuell wäre es besser, den Trigger auf changed zu ändern, statt received update.

Über die "Triggering-Rule" wird aber doch ein postUpdate gesendet? Sollte ich trotzdem auf changed ändern?

Viele Grüße

int5749 · Beitrag von **int5749** » 13. Jan 2022 18:15

So, anbei noch einmal das konsolidierte Log mit den Tests mit der zuletzt geposteten Rule(s)

Code: Alles auswählen

2022-01-13 17:19:51.200 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'ki.rules'

2022-01-13 17:37:49.933 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'PumpWasteWater_vSwitch' received command ON
2022-01-13 17:37:49.936 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpWasteWater_vSwitch' changed from OFF to ON
2022-01-13 17:37:49.939 [INFO ] [org.openhab.core.model.script.Water ] - PumpWasteWater ist angelaufen mit Status: ON
2022-01-13 17:37:52.854 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'PumpWasteWater_vSwitch' received command OFF
2022-01-13 17:37:52.856 [INFO ] [org.openhab.core.model.script.Water ] - PumpWasteWater ist angelaufen mit Status: OFF
2022-01-13 17:37:52.857 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpWasteWater_vSwitch' changed from ON to OFF
2022-01-13 17:37:53.706 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'PumpFeedingWater_vSwitch' received command ON
2022-01-13 17:37:53.709 [INFO ] [org.openhab.core.model.script.Water ] - PumpFeedingWater ist angelaufen mit Status: ON
2022-01-13 17:37:53.710 [INFO ] [org.openhab.core.model.script.Water ] - Hauswasserwerk ist angelaufen
2022-01-13 17:37:53.711 [INFO ] [org.openhab.core.model.script.Water ] - Watchdog für Hauswasserwerk gestartet
2022-01-13 17:37:53.713 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpFeedingWater_vSwitch' changed from OFF to ON
2022-01-13 17:37:57.391 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'PumpFeedingWater_vSwitch' received command OFF
2022-01-13 17:37:57.393 [INFO ] [org.openhab.core.model.script.Water ] - PumpFeedingWater ist angelaufen mit Status: OFF
2022-01-13 17:37:57.400 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpFeedingWater_vSwitch' changed from ON to OFF
2022-01-13 17:37:59.109 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'PumpDrainage_vSwitch' received command ON
2022-01-13 17:37:59.112 [INFO ] [org.openhab.core.model.script.Water ] - PumpDrainage ist angelaufen mit Status: OFF
2022-01-13 17:37:59.114 [ERROR] [internal.handler.ScriptActionHandler] - Script execution of rule with UID 'ki-19' failed: An error occurred during the script execution: Could not invoke method: org.eclipse.xtext.xbase.lib.LongExtensions.operator_minus(long,long) on instance: null in ki
2022-01-13 17:37:59.117 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpDrainage_vSwitch' changed from OFF to ON
2022-01-13 17:38:01.591 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'PumpDrainage_vSwitch' received command OFF
2022-01-13 17:38:01.593 [INFO ] [org.openhab.core.model.script.Water ] - PumpDrainage ist angelaufen mit Status: OFF
2022-01-13 17:38:01.595 [ERROR] [internal.handler.ScriptActionHandler] - Script execution of rule with UID 'ki-19' failed: An error occurred during the script execution: Could not invoke method: org.eclipse.xtext.xbase.lib.LongExtensions.operator_minus(long,long) on instance: null in ki
2022-01-13 17:38:01.595 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpDrainage_vSwitch' changed from ON to OFF
2022-01-13 17:38:03.713 [INFO ] [org.openhab.core.model.script.Water ] - Watchdog für Hauswasserwerk beendet
2022-01-13 17:38:09.764 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'PumpDrainage_vSwitch' received command ON
2022-01-13 17:38:09.766 [INFO ] [org.openhab.core.model.script.Water ] - PumpDrainage ist angelaufen mit Status: ON
2022-01-13 17:38:09.768 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe ist angelaufen
2022-01-13 17:38:09.769 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpDrainage_vSwitch' changed from OFF to ON
2022-01-13 17:38:09.769 [INFO ] [org.openhab.core.model.script.Water ] - 1642091889
2022-01-13 17:38:09.770 [INFO ] [org.openhab.core.model.script.Water ] - Watchdog für Entwässerungspumpe gestartet
2022-01-13 17:38:11.508 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'PumpDrainage_vSwitch' received command OFF
2022-01-13 17:38:11.510 [INFO ] [org.openhab.core.model.script.Water ] - PumpDrainage ist angelaufen mit Status: OFF
2022-01-13 17:38:11.512 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpDrainage_vSwitch' changed from ON to OFF
2022-01-13 17:38:11.792 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe lief 2 Sekunden


2022-01-13 17:46:19.900 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'PumpDrainage_vSwitch' received command ON
2022-01-13 17:46:19.902 [INFO ] [org.openhab.core.model.script.Water ] - PumpDrainage ist angelaufen mit Status: ON
2022-01-13 17:46:19.903 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe ist angelaufen
2022-01-13 17:46:19.904 [INFO ] [org.openhab.core.model.script.Water ] - 1642092379
2022-01-13 17:46:19.905 [INFO ] [org.openhab.core.model.script.Water ] - Watchdog für Entwässerungspumpe gestartet
2022-01-13 17:46:19.907 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpDrainage_vSwitch' changed from OFF to ON
2022-01-13 17:46:23.937 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'PumpDrainage_vSwitch' received command OFF
2022-01-13 17:46:23.938 [INFO ] [org.openhab.core.model.script.Water ] - PumpDrainage ist angelaufen mit Status: OFF
2022-01-13 17:46:23.941 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpDrainage_vSwitch' changed from ON to OFF
2022-01-13 17:46:24.677 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe lief 4 Sekunden
2022-01-13 17:46:27.538 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'PumpDrainage_vSwitch' received command ON
2022-01-13 17:46:27.540 [INFO ] [org.openhab.core.model.script.Water ] - PumpDrainage ist angelaufen mit Status: OFF
2022-01-13 17:46:27.541 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe ist angelaufen
2022-01-13 17:46:27.542 [INFO ] [org.openhab.core.model.script.Water ] - 1642092387
2022-01-13 17:46:27.543 [INFO ] [org.openhab.core.model.script.Water ] - Watchdog für Entwässerungspumpe gestartet
2022-01-13 17:46:27.545 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpDrainage_vSwitch' changed from OFF to ON
2022-01-13 17:46:30.225 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'PumpDrainage_vSwitch' received command OFF
2022-01-13 17:46:30.227 [INFO ] [org.openhab.core.model.script.Water ] - PumpDrainage ist angelaufen mit Status: OFF
2022-01-13 17:46:30.230 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpDrainage_vSwitch' changed from ON to OFF
2022-01-13 17:46:30.787 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe lief 3 Sekunden
2022-01-13 17:46:36.294 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'PumpWasteWater_vSwitch' received command ON
2022-01-13 17:46:36.296 [INFO ] [org.openhab.core.model.script.Water ] - PumpWasteWater ist angelaufen mit Status: OFF
2022-01-13 17:46:36.299 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpWasteWater_vSwitch' changed from OFF to ON
2022-01-13 17:46:37.709 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'PumpWasteWater_vSwitch' received command OFF
2022-01-13 17:46:37.712 [INFO ] [org.openhab.core.model.script.Water ] - PumpWasteWater ist angelaufen mit Status: OFF
2022-01-13 17:46:37.713 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpWasteWater_vSwitch' changed from ON to OFF
2022-01-13 17:46:39.088 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'PumpDrainage_vSwitch' received command ON
2022-01-13 17:46:39.090 [INFO ] [org.openhab.core.model.script.Water ] - PumpDrainage ist angelaufen mit Status: ON
2022-01-13 17:46:39.091 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe ist angelaufen
2022-01-13 17:46:39.092 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpDrainage_vSwitch' changed from OFF to ON
2022-01-13 17:46:39.093 [INFO ] [org.openhab.core.model.script.Water ] - 1642092399
2022-01-13 17:46:39.094 [INFO ] [org.openhab.core.model.script.Water ] - Watchdog für Entwässerungspumpe gestartet
2022-01-13 17:46:41.143 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'PumpDrainage_vSwitch' received command OFF
2022-01-13 17:46:41.144 [INFO ] [org.openhab.core.model.script.Water ] - PumpDrainage ist angelaufen mit Status: ON
2022-01-13 17:46:41.146 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe ist angelaufen
2022-01-13 17:46:41.148 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpDrainage_vSwitch' changed from ON to OFF
2022-01-13 17:46:54.636 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'PumpDrainage_vSwitch' received command ON
2022-01-13 17:46:54.642 [INFO ] [org.openhab.core.model.script.Water ] - PumpDrainage ist angelaufen mit Status: OFF
2022-01-13 17:46:54.648 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpDrainage_vSwitch' changed from OFF to ON
2022-01-13 17:46:55.204 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe lief 15 Sekunden
2022-01-13 17:46:56.834 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'PumpDrainage_vSwitch' received command OFF
2022-01-13 17:46:56.836 [INFO ] [org.openhab.core.model.script.Water ] - PumpDrainage ist angelaufen mit Status: OFF
2022-01-13 17:46:56.839 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PumpDrainage_vSwitch' changed from ON to OFF
2022-01-13 17:46:57.072 [INFO ] [org.openhab.core.model.script.Water ] - Entwässerungspumpe lief 17 Sekunden
2022-01-13 17:46:57.073 [ERROR] [internal.handler.ScriptActionHandler] - Script execution of rule with UID 'ki-19' failed: cannot invoke method public abstract boolean org.openhab.core.model.script.actions.Timer.cancel() on null in ki

Scheinbar kann ich das Ereignis/den Fehler forcieren, wenn ich die Pumpen kurz hintereinander laufen lasse :-/ Wobei die Rule doch dann jeweils schon fertig sein sollte? Der Timer läuft doch "autark" weiter, oder nicht? Defacto kann ich nicht ausschließen, das eine Pumpe anläuft während eine andere kurz zuvor beendet wurde oder sogar noch läuft. Müsste ich dies dann in 3 unterschiedliche Rules packen??

Viele Grüße

int5749 · Beitrag von **int5749** » 13. Jan 2022 18:36

udo1toni hat geschrieben: ↑13. Jan 2022 15:55 Eventuell wäre es besser, den Trigger auf changed zu ändern, statt received update.

So, als finalen Schritt habe ich nun auch dies geändert. (Immer eins nach dem anderen, damit ich den Überblick über die Auswirkungen behalte)

Im Anschluß konnte ich wild die Pumpen schalten ein-aus-zeitgleich-aus-usw und zu keinem Zeitpunkt erschien der "Exception-Error" im log.

Bleibt natürlich die Frage, warum mit OH 3.2 der Trigger "sensibler" geworden ist, denn die Rule lief in der alten Version bestimmr schon 1 Jahr. (evtl. schon 3.1, aber da ich auch die 3.2M-Versionen mitgenommen hatte bin ich nicht mehr sicher seit wann dies auftrat)

Evtl. noch etwas früh für ein Halleluja, aber im Moment sieht das schon wieder sehr gut aus und ich werde beobachen

Bis hierhin schon einmal einen Dank für Deine Geduld und Muße und wenn es dies gewesen war, habe ich nebenher noch eine aufgeräumte Rule

Ist doch auch schön.

Viele Grüße

int5749 · Beitrag von **int5749** » 15. Jan 2022 19:11

Es scheint tatsächlich an dem Trigger Member of myGroup changed gelegen zu haben.
Seit der Änderung ist der Fehler nicht mehr aufgetreten. Egal ob und wie wild ich die virtuellen Schalter in der Sitemap betätige (sogar parallel alle Pumpen laufen und unterschiedlich stoppen) oder ob die Entwässerungspumpe über den Schwimmerschalter aktiviert wird.

Nochmals einen Dank für Geduld und Support

Pumpenmonitoring - Triggering Item unzuverlässig

Re: Pumpenmonitoring - Triggering Item unzuverlässig

Re: Pumpenmonitoring - Triggering Item unzuverlässig

Re: Pumpenmonitoring - Triggering Item unzuverlässig

Re: Pumpenmonitoring - Triggering Item unzuverlässig

Re: Pumpenmonitoring - Triggering Item unzuverlässig

Re: Pumpenmonitoring - Triggering Item unzuverlässig

Re: Pumpenmonitoring - Triggering Item unzuverlässig

Re: Pumpenmonitoring - Triggering Item unzuverlässig

Re: Pumpenmonitoring - Triggering Item unzuverlässig