openHAB 4.0 SNAPSHOT discussion

rlkoshak · February 21, 2023, 1:43pm

Well, this is embarrassing. I know that folder shouldn’t be there and I don’t know how it got there. I must have done a mv .. instead of mv ~ at some point during testing without realizing it (probably when I was trying to get openhab-js 4.0 installed with npm and it kept installing the older version). It’s been there for a few weeks. Weird how it’s only now generating errors.

Anyway, that was the problem. I think for the first time since I’ve installed the OH 4.0 SNAPSHOT my startup is without significant errors and everything appears to work. I still have to restart after OH comes up after a cache clearing but issues are open for that.

Thanks! I apologize for the false alarm but at least now I know what it means when I see that and can help users in the future when I see it.

4u2fast · February 23, 2023, 10:01am

Hi,
I just updated to latest Snapshot.
after installation the Harmony binding seems to be dead

2023-02-23 10:59:22.165 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'harmonyhub:hub:HarmonyHub' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (DISABLED)
2023-02-23 10:59:24.651 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'harmonyhub:hub:HarmonyHub' changed from UNINITIALIZED (DISABLED) to UNINITIALIZED (NOT_YET_READY)
2023-02-23 10:59:24.652 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'harmonyhub:hub:HarmonyHub' changed from UNINITIALIZED (NOT_YET_READY) to UNINITIALIZED (HANDLER_MISSING_ERROR)

did clear the cache and full reboot, harmony reboot, no change.
can ping the hub !
any idea ?
thanks
Thomas

J-N-K · February 23, 2023, 10:39am

See Binding in "NOT_YET_READY" state after recent core changes · Issue #3394 · openhab/openhab-core · GitHub

4u2fast · February 24, 2023, 3:58pm

one more issue i noticed while saving a rule is the below error

2023-02-24 16:56:06.085 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'marantz.rules'
2023-02-24 16:56:06.138 [WARN ] [el.core.internal.ModelRepositoryImpl] - Configuration model 'marantz.rules' is either empty or cannot be parsed correctly!
2023-02-24 16:56:06.139 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'marantz.rules'

var Timer Wait_Timer = null 

rule "Load Marantz.rules"
when
    System started
then
    logInfo("info", "Loaded model 'Marantz.rules'")
end

rule "Dialogpegel +"
when 
Item DialogPlus  changed to ON
then
if( DialogPlus.state == ON ){
	logInfo("TV Dialogpegel +","TV Dialogpegel +")
	marantz_command.sendCommand("PSDIL UP")
	DialogPlus.sendCommand(OFF)}
end

	rule "Dialogpegel -"
when 
Item DialogMinus  changed to ON
then
if( DialogMinus.state == ON ){
	logInfo("TV Dialogpegel -","TV Dialogpegel -")
	marantz_command.sendCommand("PSDIL DOWN")
	DialogMinus.sendCommand(OFF)}
end

rule "TV on" 
when 
Item Marantz_power changed to ON
then {
	LG_TV1_Power.sendCommand(ON)
	logInfo("TV und Amiblight AN", "TV und Amiblight AN")
	if (Wait_Timer === null)  {
		Wait_Timer = createTimer(now.plusSeconds(7)) [ |
		if( LedDeviceEnabled.state == OFF ) {
		HyperionEnabled.sendCommand(ON)
		LedDeviceEnabled.sendCommand(ON)
		logInfo("Amiblight AN" , "Ambilight an")
		Wait_Timer = null  } 
		if( LedDeviceEnabled.state.state == ON ) {
		HyperionEnabled.sendCommand(ON)
		LedDeviceEnabled.sendCommand(ON)
		logInfo("Amiblight AN", "Ambilight war an")
		Wait_Timer = null  }
		]
	 }}
end
	
rule "TV off" 
when 
Item Marantz_power changed to OFF
then {
		LG_TV1_Power.sendCommand(OFF)
		logInfo("TV und Ambilight AUS" , "TV und Ambilight AUS")
		HyperionEnabled.sendCommand(OFF)
		LedDeviceEnabled.sendCommand(OFF)
	 }
end

what’s wrong in this rule ? btw the rule is working !

thanks
Thomas

J-N-K · February 24, 2023, 6:03pm

Probably nothing. Which OS are you using? Can you reproduce it every time?

Udo_Hartmann · February 24, 2023, 10:57pm

Better don’t use + or - as part of the logger name as well as of rule names.

Please be aware that the first string argument of logInfo() is part of the logger name. This is not meant to be a specific text. All log commands with the same logger name can be controlled as a group. Let’S say you are using logInfo, logWarn and logError, you can set the same logger name to all of them. If setting the log level to WARN, logInfo messages will be suppressed, while logWarn and logError will be still logged. There even es a logDebug command, you have to set the log level to Debug to get these messages. and the log level is set per logger name, so the common way would be to use maybe

logInfo("marantz","TV Dialogpegel +")

and all stuff regarding marantz will be logged with this name. Ich you don’t want to see these messages, just set org.openhab.core.model.script.marantz to WARN.

mhilbush · February 25, 2023, 12:00am

I just started seeing this on recent snapshot builds (I’m on 3320). My openHAB runs on Ubuntu 22.04 and exposes a Samba share, If I edit a file on the Samba share using my Mac (using vscode, vi, or any other editor), I see that behavior when I save the file.

This happened a really, really long time ago (openHAB 2.x?), but I suspect something recently changed that causes it to occur again.

mhilbush · February 25, 2023, 12:24am

There are many posts about this issue from 2015-2018.

The most relevant issue I could find on GH is this.

github.com/eclipse-archived/smarthome

"Configuration model x.rules is either empty or cannot be parsed correctly" error

opened 01:11PM - 30 Aug 17 UTC

Dan1001

Hi, I'm running OH2.2 snapshot on Ubuntu 14.04. I usually use SublimeText as …an editor, editing locally. When I use Visual Studio and the OH extension (also locally) I get the above error when editing rules. I appreciate a number of people have experienced similar issues with a variety of editors when editing across a Samba networked drive, but a local problem seems unusual, and it was suggested I raise as an issue (see [here](https://community.openhab.org/t/visual-studio-code-openhab-extension/30205/72)). thanks! Dan

mhilbush · February 25, 2023, 12:49am

@J-N-K Is it possible that this was reintroduced as part of the refactoring of the WatchService?

J-N-K · February 25, 2023, 7:32am

Probably, but I need to find a way to reproduce it, that‘s why I‘m asking. I‘ll see if I can setup something like that.

florian-h05 · February 25, 2023, 8:28am

FYI: Snapshots builds are missing since the addons build is failing for two days due to a failing test after a core change, see [feed] Test failing due to recent core change · Issue #14497 · openhab/openhab-addons · GitHub.

J-N-K · February 25, 2023, 11:00am

I don’t see you issue, but I do see multiple reloads for a single file save. I’ll investigate that

mhilbush · February 25, 2023, 12:31pm

@J-N-K This is the old bit of code that worked around the issue.

github.com

openhab/openhab-core/blob/c349c0114e5a505b8ddaa4c0b0c269f176c53ab1/bundles/org.openhab.core/src/main/java/org/openhab/core/service/WatchQueueReader.java#L349


      
           * @param event the {@link WatchEvent} itself
           * @param resolvedPath the resolved {@link Path} for this event
           * @param services the {@link AbstractWatchService}s that subscribe to this event
           */
          private void processModificationEvent(WatchKey key, WatchEvent<?> event, Path resolvedPath,
                  Set<AbstractWatchService> services) {
              synchronized (notifications) {
                  for (AbstractWatchService service : services) {
                      logger.trace("Modification event for {} ", resolvedPath);
                      removeScheduledNotifications(key, service, resolvedPath, true);
                      ScheduledFuture<?> future = scheduler.schedule(() -> {
                          logger.trace("Executing job for {}", resolvedPath);
                          if (removeScheduledNotifications(key, service, resolvedPath, false)) {
                              logger.trace("Job removed itself for {}", resolvedPath);
                          } else {
                              logger.trace("Job couldn't find itself for {}", resolvedPath);
                          }
                          if (checkAndTrackContent(service, resolvedPath)) {
                              service.processWatchEvent(event, event.kind(), resolvedPath);
                          } else {
                              logger.trace("File content '{}' has not changed, skipping modification event", resolvedPath);

And this is the original commit that added it.

Hope this helps.

4u2fast · February 25, 2023, 1:30pm

I have replaced all + and minus, still the same, running Debian 11.6 as Proxmox VM.
File was edited via samba share with win10 pnotepad.
if I modify the file with Nano locally the problem is gone !
Thanks
Thomas

J-N-K · February 25, 2023, 1:57pm

The problem with this approach is that we effectively lose events.

What I see is the sequence DELETE - CREATE - DELETE- CREATE when in fact the file was modified. If we discard everything except the last event (which is what the code above does), we end up with CREATE. In the current implementation of model repository and script file watchers it doesn’t matter as they handle CREATE and MODIFY in the same way, but in general DELETE would remove (whatever) and CREATE would add (whatever), while MODIFY would first remove and the add (whatever), so if we discard the DELETE event it could be that (whatever) is added twice.

mhilbush · February 25, 2023, 2:14pm

Yeah, the original “fix” was not ideal, as it only worked around the problem.

BTW, it’s a bit more messy with items, as a simple change to the file now give you this, which can be short or long depending on how extensively the items are used in rules…

2023-02-25 09:12:35.219 [WARN ] [dule.handler.ItemStateTriggerHandler] - Item 'gPresence' needed for rule 'hvac-automation-2' removed. Trigger '0' will no longer work.
2023-02-25 09:12:35.219 [WARN ] [dule.handler.ItemStateTriggerHandler] - Item 'gPresence' needed for rule 'presence-3' removed. Trigger '0' will no longer work.
2023-02-25 09:12:35.219 [WARN ] [dule.handler.ItemStateTriggerHandler] - Item 'gPresence' needed for rule 'hvac-automation-1' removed. Trigger '0' will no longer work.
2023-02-25 09:12:35.219 [WARN ] [dule.handler.ItemStateTriggerHandler] - Item 'gPresence' needed for rule 'presence-2' removed. Trigger '0' will no longer work.
2023-02-25 09:12:35.219 [WARN ] [dule.handler.ItemStateTriggerHandler] - Item 'gPresence' needed for rule 'presence-1' removed. Trigger '0' will no longer work.
2023-02-25 09:12:35.219 [WARN ] [dule.handler.ItemStateTriggerHandler] - Item 'PresenceMark' needed for rule 'presence-4' removed. Trigger '0' will no longer work.
2023-02-25 09:12:35.219 [WARN ] [dule.handler.ItemStateTriggerHandler] - Item 'Uptime_Mark' needed for rule 'presence-7' removed. Trigger '0' will no longer work.
2023-02-25 09:12:35.219 [WARN ] [dule.handler.ItemStateTriggerHandler] - Item 'PresenceCathy' needed for rule 'presence-5' removed. Trigger '0' will no longer work.
2023-02-25 09:12:35.219 [WARN ] [dule.handler.ItemStateTriggerHandler] - Item 'Uptime_Cathy' needed for rule 'presence-8' removed. Trigger '0' will no longer work.
2023-02-25 09:12:35.219 [WARN ] [dule.handler.ItemStateTriggerHandler] - Item 'PresenceMelanie' needed for rule 'presence-6' removed. Trigger '0' will no longer work.
2023-02-25 09:12:35.219 [WARN ] [dule.handler.ItemStateTriggerHandler] - Item 'Uptime_Melanie' needed for rule 'presence-9' removed. Trigger '0' will no longer work.
2023-02-25 09:12:35.239 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'unifi.items'
2023-02-25 09:12:35.250 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'unifi.items'
2023-02-25 09:12:35.255 [INFO ] [dule.handler.ItemStateTriggerHandler] - Item 'gPresence' needed for rule 'hvac-automation-2' added. Trigger '0' will now work.
2023-02-25 09:12:35.255 [INFO ] [dule.handler.ItemStateTriggerHandler] - Item 'gPresence' needed for rule 'presence-3' added. Trigger '0' will now work.
2023-02-25 09:12:35.255 [INFO ] [dule.handler.ItemStateTriggerHandler] - Item 'gPresence' needed for rule 'hvac-automation-1' added. Trigger '0' will now work.
2023-02-25 09:12:35.255 [INFO ] [dule.handler.ItemStateTriggerHandler] - Item 'gPresence' needed for rule 'presence-2' added. Trigger '0' will now work.
2023-02-25 09:12:35.255 [INFO ] [dule.handler.ItemStateTriggerHandler] - Item 'gPresence' needed for rule 'presence-1' added. Trigger '0' will now work.
2023-02-25 09:12:35.257 [INFO ] [dule.handler.ItemStateTriggerHandler] - Item 'PresenceMark' needed for rule 'presence-4' added. Trigger '0' will now work.
2023-02-25 09:12:35.257 [INFO ] [g.openhab.core.model.script.presence] - PRESENCE: Mark is home
2023-02-25 09:12:35.264 [INFO ] [dule.handler.ItemStateTriggerHandler] - Item 'Uptime_Mark' needed for rule 'presence-7' added. Trigger '0' will now work.
2023-02-25 09:12:35.267 [INFO ] [dule.handler.ItemStateTriggerHandler] - Item 'PresenceCathy' needed for rule 'presence-5' added. Trigger '0' will now work.
2023-02-25 09:12:35.267 [INFO ] [g.openhab.core.model.script.presence] - PRESENCE: Cathy is home
2023-02-25 09:12:35.272 [INFO ] [dule.handler.ItemStateTriggerHandler] - Item 'Uptime_Cathy' needed for rule 'presence-8' added. Trigger '0' will now work.
2023-02-25 09:12:35.273 [INFO ] [dule.handler.ItemStateTriggerHandler] - Item 'PresenceMelanie' needed for rule 'presence-6' added. Trigger '0' will now work.
2023-02-25 09:12:35.273 [INFO ] [g.openhab.core.model.script.presence] - PRESENCE: Melanie is away
2023-02-25 09:12:35.277 [INFO ] [dule.handler.ItemStateTriggerHandler] - Item 'Uptime_Melanie' needed for rule 'presence-9' added. Trigger '0' will now work.

J-N-K · February 25, 2023, 3:14pm

I think I have a solution for that, but I need a working “latest snapshot” for that. I believe this should be available tomorrow, now that the add-ons build has been fixed

Udo_Hartmann · February 25, 2023, 7:25pm

Oh.

Maybe CR+LF instead of only LF.
I’m not sure if it’s even possible to switch between both modes.

HFM · February 28, 2023, 6:30pm

Hi Rich,

I think this could be introduced before 4.0.

I migrated from 3.3 stable to 3.4.2 stable and have the same problems like you.

2023-02-28 18:18:15.646 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - Creating ZWave discovery service for zwave:serial_zstick:23fcd2f523 with scan time of 60
2023-02-28 18:18:15.647 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Active zwave:serial_zstick:23fcd2f523
2023-02-28 18:18:15.647 [INFO ] [zwave.handler.ZWaveControllerHandler] - Attempting to add listener when controller is null
2023-02-28 18:18:15.670 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Initializing ZWave serial controller.
2023-02-28 18:18:15.671 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Initializing ZWave Controller zwave:serial_zstick:23fcd2f523.

After that nothing. When I switch the docker images everything is fine with the hardware.
So maybe this not dependent from Java 17?
Maybe you found a solution?

Have a good one!
HFM

rlkoshak · February 28, 2023, 7:13pm

I forgot about that issue. I’ve not actually seen that in awhile, or if I have, it occurs after a clearing of the cache and I need to reboot for the Shelly binding problems and it goes away. ON the latest snapshot Zigbee and Zwave work just fine for me.