OpenHAB3 MQTT Configuration with Text Files on Windows 10

Setup, Configuration and Use Migration
1

I have successfully been interfacing my Arduino Mega 2560-based home security system to OpenHAB 2.5.12 on Windows 10. They communicate through a mqtt broker. The Arduino handles all I/O devices; OH is used for the UI and high-level controls like presence detection, wemo light switches, etc. I am now migrating to OH3.0.1 and I use TEXT FILES to configure my systems. My operational OH2 install is using the mqtt1 rev 1.8.3 binding. My desire is to upgraded to OH3 without any legacy bindings. I have spent 2+ days fighting MQTT and am now desperate for help. Any help will be much appreciated by me, and I’m sure, by others that are similarly struggling.

My addons folder contains: openhab-addons-3.0.1.kar
My conf\services\addons.cfg file contains: binding = http,mqtt,wemo,exec,mail
My conf\services\mqtt.cfg file was NOT auto generated. I copied it from my OH2.5.12 install and contains:
hsbroker.url=tcp://10.0.0.9:1883
hsbroker.clientId=openhab
hsbroker.keepAlive=10
My conf\things\HS5150.things file defines 1 bridge WITHOUT any things:
Bridge mqtt:broker:hsbroker “hsbroker” [ host=“10.0.0.9”, secure=false ] {}
My conf\rules\HS5150.rules file contains:
val mqttActions = getActions(“mqtt”,“mqtt:hsbroker:embedded-mqtt-broker”) and executes when System started as evidenced by log message “Thing ‘mqtt:broker:hsbroker’ changed from OFFLINE to ONLINE”. From what I read this is required to import Thing actions.

My OH needs to publish and subscribe to hsbroker. For the legacy mqtt1 binding:
My OH2 conf\items\HS5150.items file contains a single publish:
String OHOB_WM_String “OHOB_WM_string [%s]” {mqtt=">[hsbroker:/WatchMan/OHOB_WM_String:state:*:${itemName} = ${state}]"}

and many subscribes with the following syntax:
Number OHC_Driveway_South “Driveway South [%d]” (gControl) {mqtt="<[hsbroker:/OHIB/OHC/12:state:default]"}

After much searching I have not found absolutely clear documentation regarding the syntax for the new mqqt binding. My best sources are:

From what I gleaned my publish should be:
String OHOB_WM_String “OHOB_WM_string [%s]” {channel=“mqtt:broker:hsbroker:topic:WatchMan/OHOB_WM_String:state:*:${itemName} = ${state}”}
however I get log error cannot parse and illegal characters.
I tried something very simple:
String OHOB_WM_String “… OHOB_string Initialization …[%s]” {channel=“mqtt:hsbroker:topic:ABC”}
This startsup without errors but nothing is received by the broker as evidenced by the handy troubleshooting program mqtt.fx.

I have not tried subscribing to the broker yet; I’ve had enough trouble publishing. I need to get publishing working first to build my confidence. However, I don’t see any lazy-V (> or <) in the new mqtt syntax. The legacy mqtt1 binding item syntax implied publish (>) or subscribe (<).

The subscribe should look similar to the publish?
Is it possible that the String to publish and each Number in my .item file needs to be a Thing? I hope and suspect not.
Subscriptions should be changed from Number OHC_Driveway_South “Driveway South [%d]” (gControl) {mqtt="<[hsbroker:/OHIB/OHC/12:state:default]"}
to what?

As I said, any help will be much appreciated by me, and I’m sure, by others that are similarly struggling.

Summary

This text will be hidden

2

It’s of no use at all in OH3

You can’t. It’s simply not supported in OH3.

I don’t know where you got that, it’s nonsense.

What you have to do -

Install MQTT binding

Add a broker bridge Thing (not a System broker,just a broker) to connect to your MQTT broker.

Add various Things, roughly representing each device or service you will use.

To each of these, add channels for each piece of data, configuring there topics to subscribe to, topics to publish to, and transformations required.

These channels get linked to your Items.

3

Converting an MQTT1 installation.

4

That’s good because OH 3 doesn’t support legacy OH 1.x bindings.

You shouldn’t spin your wheels so long. We are usually happy to help. Have you had a look at the MQTT binding’s docs? It is quite different from the way the 1.x binding works. You’ve not indicated that you’ve looked there.

In general I don’t support .things files. It’s a huge time sink. So I won’t be able to help with that, but a lot of what you are trying shows that you don’t really have an understanding of OH 2/3 concepts (how Things work in particular) nor how the MQTT binding works. As with many similar bindings, there is a bridge Thing that must be manually created that contains the connection to the broker parameters. Then with MQTT you create Generic MQTT Things and Channels on the Thing where you define the topics subscribed to and published to. You link your Items to the Channel. All the config is on the Channel though.

But a growing pet peeve of mine is even if you don’t plan on using the UI in the end, why not create at least that first Thing using the UI. It’s all right there in the forms.

An example Broker:

image
image1562×1948 202 KB

The generated code shown on the code tab:

UID: mqtt:broker:broker
label: Mosquitto MQTT Broker2
thingTypeUID: mqtt:broker
configuration:
  lwtQos: 2
  publickeypin: true
  clientID: openhab
  keepAlive: 60
  lwtMessage: OFFLINE
  lwtTopic: openhab/status
  secure: false
  certificatepin: true
  password: password
  qos: 2
  reconnectTime: 60000
  port: 1883
  host: argus.koshak.net
  lwtRetain: true
  username: username
  enableDiscovery: false

A specific Channel config for a Generic MQTT Thing:

image
image1548×1942 257 KB

and the generated code for this MQTT Thing

UID: mqtt:topic:mosquitto:basement_sensors
label: Basement Sensors
thingTypeUID: mqtt:topic
configuration:
  payloadNotAvailable: Connection Lost
  availabilityTopic: basement-sensors/status/LWT
  payloadAvailable: Connected
bridgeUID: mqtt:broker:broker
location: Den
channels:
  - id: light
    channelTypeUID: mqtt:number
    label: Light Level
    description: null
    configuration:
      stateTopic: basement-sensors/light/light
  - id: temp
    channelTypeUID: mqtt:number
    label: Temperature
    description: null
    configuration:
      stateTopic: basement-sensors/climate/temperature
      unit: °F
  - id: humi
    channelTypeUID: mqtt:number
    label: Humidity
    description: null
    configuration:
      stateTopic: basement-sensors/climate/humidity
      unit: "%"
  - id: online
    channelTypeUID: mqtt:switch
    label: Online Status
    description: null
    configuration:
      stateTopic: basement-sensors/status/LWT
      off: Connection Lost
      on: Connected

All the possible parameters are right there in the form. They even have explanations. And if you want to go to a .things file you can look at the code and write your .things files as all the names and values for the parameters are right there in the YAML.

The Getting Started Tutorial also has a page dedicated to showing how to use the MQTT Binding. Adding Things - Advanced | openHAB. It’s all UI based, but you should be able to at least get the over all concepts. From there you should be able to translate them to .things files.

Over all, the replies so far should be useful to you. But you really need to step back I think and get a better understanding about how the binding works. Don’t assume that anything you know from the 1.x binding still applies, because it doesn’t. The 2/3 binding is completely different.

5

rossko57
Thank you very much for your reply.

Remembering I use text files to configure OH,

1 - Is it possible to run OH3 with the org.openhab.binding.mqtt-1.8.3 binding?

2 - If so, do you recommend against using the mqtt1 or migrating to the new mqtt binding?

3 - If I use the new binging then, from your reply:
3A - I should delete the mqtt.cfg file - it is useless for OH3
3B - Install MQTT binding (that’s automatically loaded upon startup)

3C - In the .things file add a broker bridge in the .things file:
Bridge mqtt:broker:hsbroker “hsbroker” [ host=“10.0.0.9”, secure=false ] { move 3D and 3E here }

3D - In the .things file add 1 Outbound Thing to publish the string item OHOB_WM_String:
Thing topic OutboundThing “OH OutBound to WatchMan” {
Channels:
Type string: OHOB_WM_String [stateTopic="/WatchMan/OHOB_WM_String"]
}
Is the syntax correct?
Should anything be added before closing the brace?

3E - In the .things file add1 Inbound Thing to subscribe 20+ Number item sensors:
Thing topic InBoundThing “OH InBound from WatchMan” {
Channels:
Type number: OHC_Driveway_South [stateTopic="/OHIB/OHC/12:state:default"]
Type number: OHC_Driveway_Center [stateTopic="/OHIB/OHC/13:state:default"]
Type number: OHC_Driveway_North [stateTopic="/OHIB/OHC/14:state:default"]
etc.
etc.
}
Is the syntax correct?
Should anything be added before closing the brace?

    Can channels from 3D and 3E be combined inside one Thing topic even though data is following opposite directions?  I would guess combined to be ok.

4 - In the .items file link each of the 20+ channels to an item Number:
Number OHC_Driveway_South “Driveway South [%d]” (gControl) {mqtt=channel=“mqtt:topic:hsbroker:/OHIB/OHC/12:state:default”}
Number OHC_Driveway_Center “Driveway Mid [%d]” (gControl) {mqtt="<[hsbroker:/OHIB/OHC/13:state:default"}
Number OHC_Driveway_North “Driveway North [%d]” (gControl) {mqtt="<[hsbroker:/OHIB/OHC/14:state:default"}
etc.
etc.
Is the syntax correct?
Should anything be added before closing the brace?

If you do recommend using legacy mqtt1 with OH3 per #2 above, how should I configure it?
I have not been able to successfully use it under OH3.
Perhaps I need to restart my Windows 10 between attempts?

  • Restore the addons.cfg file with:
    binding = mqtt1
  • Restore the conf\services\mqtt.cfg file with:
    hsbroker.url=tcp://10.0.0.9:1883
    hsbroker.clientId=openhab
    hsbroker.keepAlive=10
  • Put openhab-addons-legacy-2.5.12.kar file in the addons folder?
  • Put openhab-addons-legacy.kar file (rev removed) in the addons folder?
  • Put org.openhab.binding.mqtt-1.8.3.kar file in the addons folder?
  • Put org.openhab.binding.mqtt.kar file (rev remove) in the addons folder?

Thanks again. :slight_smile:

6

Forget about MQTT1 - it will not work in OH3.

1 Like
7

OK, I understand mqtt1 is out of the picture. That simplifies my life - either freeze as 2.5.12 or migrate to OH3.

Are my steps 3 and 4 correct for moving forward? I’m about ready to field another similar system. I hate to put something in the field that is already frozen.

8

No

You can use them


Bridge mqtt:broker:myMQTTBroker [ host ="192.168.1.148", secure =false, username ="bed", password ="room" , clientID ="myMQTTClient" ]
{
 
    Thing topic fan1 "Dining FAN" [ availabilityTopic="IFANdining/tele/LWT", payloadAvailable="Online", payloadNotAvailable="Offline"] {
    Channels:
        Type switch : Power1   "Dining Light "  [ stateTopic = "IFANdining/stat/POWER", commandTopic = "IFANdining/cmnd/POWER", on="ON", off="OFF" ]
        Type dimmer : fanspeed "Fan Speed"      [ stateTopic = "IFANdining/stat/FANSPEED", transformationPattern = "JSONPATH:$.FanSpeed", commandTopic ="IFANdining/cmnd/FANSPEED", 0="OFF", 1="LOW", 2="MED", 3="HIGH", 2=100  ]
        Type switch : reachable "Reachable"     [ stateTopic = "IFANdining/tele/LWT",	on="Online",	off="Offline" ]
      }
}

You can only have one bridge per broker

Items

Switch Dining_light "Dining Light" { ga="Light", channel="mqtt:topic:myMQTTBroker:fan1:Power1" }
Dimmer Dining_fan "Dining Fan" { ga="Fan" [ speeds="0=off:zero,1=slow:low:one:on,2=medium:two,3=high:three:100", lang="en", ordered=true, roomHint="Dining" ], channel="mqtt:topic:myMQTTBroker:fan1:fanspeed" }
Switch Reachable "Online" {channel="mqtt:topic:myMQTTBroker:fan1:reachable"}
9

No. None of the 1.x version bindings work in OH 3.

Yes

??? The binding gets installed based on the contents of your addons.cfg file, unless you’ve changed something since your first post.

Again, where are you getting this syntax? See Items | openHAB

If using .things files you may need to restart openHAB between edits. You will never need to restart Windows for this.

No 1.x version binding works in OH 3.

I can’t comment on most of step 3. Step 4 is wrong. Please review the docs and examples. James just posted a good example for .things files. The link above shows how to link an Item to a Channel. It’s super simple: channel="channelID".

10

You’ll find out as you work the examples, but no - channel stateTopic= is to be subscribed to, and used to update the Item state via channel.
Channel commandTopic= is to publish to, using Item commands as MQTT message payload.

11

I think I’m catching on.
Does the following look correct?
Do I need to combine all 4 channels into 1 Thing topic?
Do I need to include anything between the Thing topic square brackets?
What is the “ga” in the items example: Switch Dining_light “Dining Light” { ga=“Light”, channel=“mqtt:topic:myMQTTBroker:fan1:Power1” }

REFERENCES:

string: This channel can show the received text on the given topic and can send text to a given topic
number: This channel can show the received number on the given topic and can send a number to a given topic. It can have a min, max and step values.

.things

Bridge mqtt:broker:hsbroker “hsbroker” [ host=“10.0.0.9”, secure=false ] {

Thing topic OutboundThing “To WatchMan”  [] {
	Channels:
	Type string: OHOB_WM_String      "" [commandTopic="/WatchMan/OHOB_WM_String"]
}

Thing topic InBoundThing “From WatchMan” [] {
	Channels:
	Type number: OHC_Driveway_South  "" [stateTopic="/OHIB/OHC/12"]
	Type number: OHC_Driveway_Center "" [stateTopic="/OHIB/OHC/13"]
	Type number: OHC_Driveway_North  "" [stateTopic="/OHIB/OHC/14"]
}

}

.items

String OHOB_WM_String “Outbound String[%s]” {channel=“mqtt:topic:hsbroker:OutBoundThing:OHOB_WM_String"}

Number OHC_Driveway_South “Driveway South [%d]” {channel=“mqtt:topic:hsbroker:InBoundThing:OHC_Driveway_South”}
Number OHC_Driveway_Center “Driveway Mid [%d]” {channel=“mqtt:topic:hsbroker:InBoundThing:OHC_Driveway_Center"}
Number OHC_Driveway_North “Driveway North [%d]” {channel=“mqtt:topic:hsbroker:InBoundThing:OHC_Driveway_North"}

More thanks to you.

12

You can break it up how ever you want. But typically you’ll have one Thing per device. A device will have 1 or more Channels. Each Channel can subscribe to one topic and/or publish to one topic.

I don’t use .things files. But there are several examples linked to in this thread that should answer the question.

Google Assistant metadata telling it that the item is controllable and it’s a light.

13

I found an excellent reference that discusses converting an MQTT1 Installation = openhab2-addons/xtend_examples.md at master · fguiraldelli/openhab2-addons · GitHub

I believe I have followed community suggestions provided above and the referenced instructions, but I continue to be unsuccessful. I was thinking maybe I have a name conflict so I changed those to be unique. Still no success. I’m also running mqtt.fx on 2 Windows 10 computers and I can publish and scribe to topics, but nothing comes out of or goes into OpenHAB.

I’m fresh out of ideas. Spent 12 intense hours on this today :frowning:

My code is copied and pasted as follows:

REFERENCES:

string: This channel can show the received text on the given topic and can send text to a given topic
number: This channel can show the received number on the given topic and can send a number to a given topic. It can have a min, max and step values.

When using .things and .items files for configuration, items and channels follow the format of:
: “” { channel=“mqtt:topic:::” }

.rules (when System Started)
val mqttActions = getActions(“mqtt”,“mqtt:broker:hsbroker”)
actions.publishMQTT(“SomeTopic”, “SomePayload”)

.things

Bridge mqtt:broker:hsbroker “hsbroker” [ host=“10.0.0.9”, secure=false ] {

Thing topic OutboundThing "To WatchMan"   {
	Channels:
	Type string: mqttTest0  "Friendly Name 0" [commandTopic="/WatchMan/OHOB_WM_String"]
}

Thing topic InBoundThing "From WatchMan"  {
	Channels:
	Type number: mqttTest1  "Friendly Name 1" [stateTopic="/OHIB/OHC/12"]
	Type number: mqttTest2  "Friendly Name 2" [stateTopic="/OHIB/OHC/13"]
	Type number: mqttTest3  "Friendly Name 3" [stateTopic="/OHIB/OHC/14"]
}

}

.items

String OHOB_WM_String “Outbound String[%s]” {channel=“mqtt:topic:hsbroker:OutBoundThing:mqttTest0”}

Number xxx_Driveway_South “Driveway South [%d]” {channel=“mqtt:topic:hsbroker:InBoundThing:mqttTest1”}
Number xxx_Driveway_Center “Driveway Mid [%d]” {channel=“mqtt:topic:hsbroker:InBoundThing:mqttTest2”}
Number xxx_Driveway_North “Driveway North [%d]” {channel=“mqtt:topic:hsbroker:InBoundThing:mqttTest3”}

.rules

rule “mqttTEST”
when
Item xxx_Driveway_South received update or
Item xxx_Driveway_Center received update or
Item xxx_Driveway_North received update
then
logInfo(“mqttTEST”, “>>>>> RUNNING RULE = mqttTEST”)
end

14

That’s just a fork of the link we provided in the third post in this thread - what improvements does this fork have?

Please reformat your last post to use code fences, then we can start looking into it.

Probably also worth describing what this means:

Do your openHAB logs show anything useful? Be aware that when using files openHAB sometimes fails to register changes on save (at least on Linux). To remedy this you can do this.

It is unusual to use a leading / in a topic - check the best practices on this page. Are you certain this is what you need?

15

The binding SHOULD have something to say about broker connection. Look in your openhab.log.

If nothing, is the binding installed? Check packages on your karaf console.

If binding installed, is your xxx.things file being loaded? Again. your openhab.log SHOULD have messages about that.

16

It’ll look something like

openhab.log:2021-03-18 08:21:50.624 [INFO ] [.transport.mqtt.MqttBrokerConnection] - Starting MQTT broker connection to 'argus.koshak.net' with clientid openhab

when it successfully connects.

17

I awoke this morning with additional troubleshooting ideas. I added to my .things, .items, and .rules files to include an echo test string and Things channel syntax change. However, first I need to reply to your suggestions, and thank you for your help.

  • I’ll use “fences” now that I learnedhow to use them. Thank you for the reference.
  • I have found OH3 does not execute rules that are triggered with System started when configuration files are saved. Therefore I always kill and restart OH3. This is awkward but appears to be arequirement.
rule "Startup_Initializations"
	when
		System started
	then
  • The MQTT Essentials Best Practices reference resonated with 1 of my troubleshooting ideas. With mqtt1 the slash / is used as a level separator. I remember a google reference where the colon appeared to be used in the .things channel definition. So I’m not sure which of the following is correct; 1, 2, 3 or 4, 5, 6?
	Bridge mqtt:broker:hsbroker "hsbroker" [ host="10.0.0.9", secure=false ] { 
 
		Thing topic OutboundThing "To WatchMan"   {
			Channels:
			Type string: mqttTest0  "Friendly Name 0" [commandTopic="/WatchMan/OHOB_WM_String"]
		}

		Thing topic InBoundThing "From WatchMan" 
		{
			Channels:
			Type number: mqttEchoTest   "EchoTest Name"   [stateTopic="SomeTopic"]
			Type number: mqttTest1  	"Friendly Name 1" [stateTopic="/OHIB/OHC/12"]
			Type number: mqttTest2 		"Friendly Name 2" [stateTopic="/OHIB/OHC/13"]
			Type number: mqttTest3  	"Friendly Name 3" [stateTopic="/OHIB/OHC/14"]
			Type number: mqttTest4  	"Friendly Name 4" [stateTopic=":OHIB:OHC:12"]
			Type number: mqttTest5  	"Friendly Name 5" [stateTopic=":OHIB:OHC:13"]
			Type number: mqttTest6  	"Friendly Name 6" [stateTopic=":OHIB:OHC:14"]
		}
	}
  • My interpretation of the log files is that startup is NOT consistent. For example, in the following 1st log mqtt is initializing at 09:43:00.719 but there is no mention of things going online. In the subsequent 2nd log mqtt is initialized at 10:22:55.720 and things logs are split before and after 10:22:55.720. Why were things not logged in the 1st log? Perhaps there is a timing race problem in OH3?

1st log:

openhab> log:tail
09:42:09.402 [WARN ] [.core.karaf.internal.FeatureInstaller] - The ui add-on 'classic' does not exist - ignoring it.
09:42:10.464 [INFO ] [del.core.internal.ModelRepositoryImpl] - Loading model 'HS5150.items'
09:42:11.979 [INFO ] [del.core.internal.ModelRepositoryImpl] - Loading model 'mapdb.persist'
09:42:12.369 [INFO ] [del.core.internal.ModelRepositoryImpl] - Loading model 'HS5150.sitemap'
09:42:12.822 [INFO ] [del.core.internal.ModelRepositoryImpl] - Validation issues found in configuration model 'HS5150.sitemap', using it anyway:
Sitemap should contain either only frames or none at all
09:42:13.088 [INFO ] [del.core.internal.ModelRepositoryImpl] - Loading model 'HS5150.things'
09:42:15.009 [INFO ] [del.core.internal.ModelRepositoryImpl] - Loading model 'HS5150.rules'
09:42:43.505 [INFO ] [del.core.internal.ModelRepositoryImpl] - Validation issues found in configuration model 'HS5150.rules', using it anyway:
This expression is not allowed in this context, since it doesn't cause any side effects.
09:42:44.333 [INFO ] [b.core.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
09:42:46.426 [INFO ] [org.openhab.ui.internal.UIService    ] - Started UI on port 8080
09:42:55.030 [INFO ] [.io.openhabcloud.internal.CloudClient] - Connected to the openHAB Cloud service (UUID = c86a53f2-1c89-4f8f-996c-521ad3c68bce, base URL = http://localhost:8080)
09:42:56.327 [WARN ] [.core.thing.internal.ThingManagerImpl] - Initializing handler for thing 'mqtt:broker:hsbroker' takes more than 5000ms.
09:43:00.719 [INFO ] [o.transport.mqtt.MqttBrokerConnection] - Starting MQTT broker connection to '10.0.0.9' with clientid fa6e97ee-9d56-415a-98db-829bcf94fa9e
09:43:09.257 [WARN ] [.core.karaf.internal.FeatureInstaller] - The ui add-on 'classic' does not exist - ignoring it.
09:43:18.746 [INFO ] [.model.script.Startup_Initializations] - >>>>> RUNNING RULE = Startup_Initializations.  Pausing for 999 msec
09:43:19.759 [INFO ] [.model.script.Startup_Initializations] - >>>>> RUNNING RULE = Startup_Initializations at 03/19/21 @ 09:43:19 AM
09:43:19.759 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'Date' changed from 2021-03-19T09:40:05.673486700-0700 to 2021-03-19T09:43:19.759857600-0700
09:43:19.775 [INFO ] [.model.script.Startup_Initializations] - >>>>> OpenHAB IS DELAYING 60 SECONDS TO ALLOW IT TO ORGANIZE ITSELF
09:44:34.649 [INFO ] [.model.script.Startup_Initializations] - >>>>> ReStarting OH HS5150
09:44:34.649 [INFO ] [.model.script.Startup_Initializations] - >>>>> ReStarting OH HS5150
09:44:34.649 [INFO ] [.model.script.Startup_Initializations] - >>>>> ReStarting OH HS5150
09:44:34.649 [INFO ] [.model.script.Startup_Initializations] - >>>>> ReStarting OH HS5150
09:44:34.649 [INFO ] [.model.script.Startup_Initializations] - >>>>> ReStarting OH HS5150
09:44:34.649 [INFO ] [.model.script.Startup_Initializations] - >>>>> ReStarting OH HS5150
09:44:34.649 [INFO ] [.model.script.Startup_Initializations] - >>>>> ReStarting OH HS5150
09:44:34.649 [INFO ] [.model.script.Startup_Initializations] - >>>>> ReStarting OH HS5150
09:44:34.664 [INFO ] [.model.script.Startup_Initializations] - >>>>> ReStarting OH HS5150
09:44:34.664 [INFO ] [.model.script.Startup_Initializations] - >>>>> ReStarting OH HS5150
09:44:35.666 [INFO ] [.model.script.Startup_Initializations] - >>>>>>>>>>>>> RULE = Startup_Initializations.  Ready to publish via actions.publishMQTT
09:44:35.666 [INFO ] [.model.script.Startup_Initializations] - >>>>>>>>>>>>> RULE = Startup_Initializations.  mqttActions = org.openhab.binding.mqtt.internal.action.MQTTActions@53cde000
09:44:42.678 [ERROR] [.internal.handler.ScriptActionHandler] - Script execution of rule with UID 'HS5150-1' failed: An error occurred during the script execution: index=0, size=0 in HS5150
09:44:42.678 [INFO ] [re.automation.internal.RuleEngineImpl] - Rule engine started.
09:44:50.208 [INFO ] [ab.core.model.script.Update_OHCstring] - >>>>> ENTERED RULE = Update_OHCstring.  Roberts_Counter_Now = 0 GreenFlag = 1 Traffic_BrakeOHOB = 0 second = 50
09:44:50.208 [INFO ] [ab.core.model.script.Update_OHCstring] - >>>>> RUNNING RULE = Update_OHCstring.  Roberts_Counter_Now = 0
09:44:50.208 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'Date' changed from 2021-03-19T09:43:19.759857600-0700 to 2021-03-19T09:44:50.208694300-0700
09:44:50.224 [INFO ] [ab.core.model.script.Update_OHCstring] - >>>>> OpenHAB is READY 03/19/21 @ 09:44:50 AM
09:44:54.557 [INFO ] [ab.core.model.script.Update_OHCstring] - >>>>>>>>>>>>> RULE = Update_OHCstring.  Ready to publish via actions.publishMQTT
09:44:54.572 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'OHOB_WM_String' changed from
03/19/21 @ 09:39:20 AM >
MsgStamp:2;
00:25;
MsgStamp:2;
EOS< to

2nd log:

openhab> log:tail
10:20:58.154 [WARN ] [org.apache.karaf.shell.ssh.Activator ] - Error starting activator
java.lang.IllegalStateException: Service not tracked for class interface org.osgi.service.cm.ConfigurationAdmin
        at org.apache.karaf.util.tracker.BaseActivator.getTrackedService(BaseActivator.java:369) ~[bundleFile:?]
        at org.apache.karaf.util.tracker.BaseActivator.ensureStartupConfiguration(BaseActivator.java:154) ~[bundleFile:?]
        at org.apache.karaf.shell.ssh.Activator.doStart(Activator.java:96) ~[bundleFile:?]
        at org.apache.karaf.util.tracker.BaseActivator.run(BaseActivator.java:312) [bundleFile:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
        at java.lang.Thread.run(Thread.java:834) [?:?]
10:21:08.616 [WARN ] [.core.karaf.internal.FeatureInstaller] - The ui add-on 'classic' does not exist - ignoring it.
10:21:09.632 [INFO ] [del.core.internal.ModelRepositoryImpl] - Loading model 'HS5150.items'
10:21:11.162 [INFO ] [del.core.internal.ModelRepositoryImpl] - Loading model 'mapdb.persist'
10:21:11.584 [INFO ] [del.core.internal.ModelRepositoryImpl] - Loading model 'HS5150.sitemap'
10:21:12.115 [INFO ] [del.core.internal.ModelRepositoryImpl] - Validation issues found in configuration model 'HS5150.sitemap', using it anyway:
Sitemap should contain either only frames or none at all
10:21:12.349 [INFO ] [del.core.internal.ModelRepositoryImpl] - Loading model 'HS5150.things'
10:21:14.714 [INFO ] [del.core.internal.ModelRepositoryImpl] - Loading model 'HS5150.rules'
10:22:01.206 [INFO ] [del.core.internal.ModelRepositoryImpl] - Validation issues found in configuration model 'HS5150.rules', using it anyway:
This expression is not allowed in this context, since it doesn't cause any side effects.
10:22:06.035 [INFO ] [b.core.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
10:22:08.874 [WARN ] [.core.karaf.internal.FeatureInstaller] - The ui add-on 'classic' does not exist - ignoring it.
10:22:13.538 [INFO ] [org.openhab.ui.internal.UIService    ] - Started UI on port 8080
10:22:23.975 [INFO ] [.io.openhabcloud.internal.CloudClient] - Connected to the openHAB Cloud service (UUID = c86a53f2-1c89-4f8f-996c-521ad3c68bce, base URL = http://localhost:8080)
10:22:53.565 [ERROR] [.internal.handler.ScriptActionHandler] - Script execution of rule with UID 'HS5150-1' failed: The name 'Pause_Time' cannot be resolved to an item or type; line 361, column 102, length 10 in HS5150
10:22:53.783 [INFO ] [re.automation.internal.RuleEngineImpl] - Rule engine started.
10:22:54.346 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'mqtt:topic:hsbroker:OutboundThing' changed from UNINITIALIZED to UNINITIALIZED (BRIDGE_UNINITIALIZED)
10:22:54.549 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'mqtt:topic:hsbroker:InBoundThing' changed from UNINITIALIZED to UNINITIALIZED (BRIDGE_UNINITIALIZED)
10:22:54.736 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'mail:smtp:GmailThing' changed from UNINITIALIZED to INITIALIZING
10:22:54.877 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'mail:smtp:GmailThing' changed from INITIALIZING to ONLINE
10:22:54.970 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'mqtt:broker:hsbroker' changed from UNINITIALIZED to INITIALIZING
10:22:55.064 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'mqtt:broker:hsbroker' changed from INITIALIZING to OFFLINE
10:22:55.158 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'mqtt:topic:hsbroker:InBoundThing' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING
10:22:55.173 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'mqtt:topic:hsbroker:OutboundThing' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING
10:22:55.205 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'mqtt:topic:hsbroker:InBoundThing' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE)
10:22:55.220 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'mqtt:topic:hsbroker:OutboundThing' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE)
10:22:55.720 [INFO ] [o.transport.mqtt.MqttBrokerConnection] - Starting MQTT broker connection to '10.0.0.9' with clientid 115e6f9c-f257-4333-9e5e-e5c05aea0884
10:22:55.845 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'mqtt:broker:hsbroker' changed from OFFLINE to ONLINE
10:22:55.876 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'mqtt:topic:hsbroker:OutboundThing' changed from OFFLINE (BRIDGE_OFFLINE) to ONLINE
10:22:55.876 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'mqtt:topic:hsbroker:InBoundThing' changed from OFFLINE (BRIDGE_OFFLINE) to ONLINE
10:23:16.816 [INFO ] [enhab.core.model.script.Timed_Control] - >>>>> WatchmansEchoStatus = 3
10:23:16.889 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'Date' changed from 2021-03-19T10:20:38.333884400-0700 to 2021-03-19T10:23:16.800580-0700
10:23:16.885 [INFO ] [ab.core.model.script.Update_OHCstring] - >>>>> ENTERED RULE = Update_OHCstring.  Roberts_Counter_Now = 0 GreenFlag = 1 Traffic_BrakeOHOB = 0 second = 16
10:23:17.000 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'WatchmansEchoStatus' changed from 3 to 1
10:23:17.035 [INFO ] [ab.core.model.script.Update_OHCstring] - >>>>> RUNNING RULE = Update_OHCstring.  Roberts_Counter_Now = 0
10:23:17.042 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'OH_Events_Log' changed from Timed_Control texting 9252345805@tmomail.net to Presence set to C111
10:23:17.075 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'OH_Events_Log' changed from Presence set to C111 to Timed_Control texting 9252345805@tmomail.net
10:23:17.043 [INFO ] [ab.core.model.script.Update_OHCstring] - >>>>> OpenHAB is READY 03/19/21 @ 10:23:16 AM
10:23:17.106 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'Date' changed from 2021-03-19T10:23:16.800580-0700 to 2021-03-19T10:23:17.043936500-0700
10:23:21.320 [INFO ] [ab.core.model.script.Update_OHCstring] - >>>>>>>>>>>>> RULE = Update_OHCstring.  Ready to publish via actions.publishMQTT
10:23:21.320 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'OHOB_WM_String' changed from
03/19/21 @ 10:20:38 AM >
MsgStamp:215;
00:25;
MsgStamp:215;
EOS< to
  • I added code at the end of the System started triggered .rules file to help eliminate possible Things issues per below. I tried both val mqqtActions and val mqqtActions, and i added actions.publishMQTT("SomeTopic", "SomePayload") to circumvent Things channels.
	// Import Thing Actions -----------------------------------------------------------------------------------------		
		//	https://community.openhab.org/t/sendmail-not-working-2-5-0-m2/80041/4
		val	mailActions = getActions("mail", "mail:smtp:GmailThing")
	//	var	mailActions = getActions("mail", "mail:smtp:GmailThing")
		logInfo("Startup_Initializations", ">>>>>>>>>>>>> RULE = Startup_Initializations.  mailActions = " + mailActions)
		Thread::sleep(1000)	//	Configuration Delay
		
		//	https://www.openhab.org/blog/2018-12-16-mqtt-arrives-in-the-modern-openhab-2-x-architecture.html
		//	https://github.com/fguiraldelli/openhab2-addons/blob/master/bundles/org.openhab.binding.mqtt.generic/xtend_examples.md
		logInfo("Startup_Initializations", ">>>>>>>>>>>>> RULE = Startup_Initializations.  Ready to publish via actions.publishMQTT")
		val	mqttActions = getActions("mqtt","mqtt:broker:hsbroker")
	//	var	mqttActions = getActions("mqtt","mqtt:broker:hsbroker")
		logInfo("Startup_Initializations", ">>>>>>>>>>>>> RULE = Startup_Initializations.  mqttActions = " + mqttActions)
		Thread::sleep(7000)	//	Configuration Delay
		actions.publishMQTT("SomeTopic", "SomePayload")
		logInfo("Startup_Initializations", ">>>>>>>>>>>>> RULE = Startup_Initializations.  Published via actions.publishMQTT")
	
	logInfo("Startup_Initializations", "<<<<< EXITING RULE = Startup_Initializations")
  • This 3rd log further demonstrated non-repeatability pointing to a possible system initialization race condition. Note again no mention of things online.

3rd Log

openhab> log:tail
10:49:37.565 [WARN ] [org.apache.karaf.shell.ssh.Activator ] - Error starting activator
java.lang.IllegalStateException: Service not tracked for class interface org.osgi.service.cm.ConfigurationAdmin
        at org.apache.karaf.util.tracker.BaseActivator.getTrackedService(BaseActivator.java:369) ~[bundleFile:?]
        at org.apache.karaf.util.tracker.BaseActivator.ensureStartupConfiguration(BaseActivator.java:154) ~[bundleFile:?]
        at org.apache.karaf.shell.ssh.Activator.doStart(Activator.java:96) ~[bundleFile:?]
        at org.apache.karaf.util.tracker.BaseActivator.run(BaseActivator.java:312) [bundleFile:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
        at java.lang.Thread.run(Thread.java:834) [?:?]
10:49:48.956 [WARN ] [.core.karaf.internal.FeatureInstaller] - The ui add-on 'classic' does not exist - ignoring it.
10:49:50.127 [INFO ] [del.core.internal.ModelRepositoryImpl] - Loading model 'HS5150.items'
10:49:51.721 [INFO ] [del.core.internal.ModelRepositoryImpl] - Loading model 'mapdb.persist'
10:49:52.112 [INFO ] [del.core.internal.ModelRepositoryImpl] - Loading model 'HS5150.sitemap'
10:49:52.596 [INFO ] [del.core.internal.ModelRepositoryImpl] - Validation issues found in configuration model 'HS5150.sitemap', using it anyway:
Sitemap should contain either only frames or none at all
10:49:52.924 [INFO ] [del.core.internal.ModelRepositoryImpl] - Loading model 'HS5150.things'
10:49:54.954 [INFO ] [b.core.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
10:49:55.048 [INFO ] [del.core.internal.ModelRepositoryImpl] - Loading model 'HS5150.rules'
10:50:26.864 [INFO ] [del.core.internal.ModelRepositoryImpl] - Validation issues found in configuration model 'HS5150.rules', using it anyway:
This expression is not allowed in this context, since it doesn't cause any side effects.
10:50:29.910 [INFO ] [org.openhab.ui.internal.UIService    ] - Started UI on port 8080
10:50:39.580 [INFO ] [.io.openhabcloud.internal.CloudClient] - Connected to the openHAB Cloud service (UUID = c86a53f2-1c89-4f8f-996c-521ad3c68bce, base URL = http://localhost:8080)
10:50:41.444 [WARN ] [.core.thing.internal.ThingManagerImpl] - Initializing handler for thing 'mqtt:broker:hsbroker' takes more than 5000ms.
10:50:43.464 [INFO ] [o.transport.mqtt.MqttBrokerConnection] - Starting MQTT broker connection to '10.0.0.9' with clientid 1777005a-6466-4ddd-a07b-0caa1230b9ea
10:50:48.884 [WARN ] [.core.karaf.internal.FeatureInstaller] - The ui add-on 'classic' does not exist - ignoring it.
10:51:03.015 [INFO ] [.model.script.Startup_Initializations] - >>>>> RUNNING RULE = Startup_Initializations.  Pausing for 999 msec
10:51:04.017 [INFO ] [.model.script.Startup_Initializations] - >>>>> RUNNING RULE = Startup_Initializations at 03/19/21 @ 10:51:04 AM
10:51:04.033 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'Date' changed from 2021-03-19T10:49:05.582678100-0700 to 2021-03-19T10:51:04.017930500-0700
10:51:04.049 [INFO ] [.model.script.Startup_Initializations] - >>>>> OpenHAB IS DELAYING 60 SECONDS TO ALLOW IT TO ORGANIZE ITSELF
10:52:19.956 [INFO ] [.model.script.Startup_Initializations] - >>>>> ReStarting OH HS5150
10:52:19.971 [INFO ] [.model.script.Startup_Initializations] - >>>>> ReStarting OH HS5150
10:52:19.971 [INFO ] [.model.script.Startup_Initializations] - >>>>> ReStarting OH HS5150
10:52:19.971 [INFO ] [.model.script.Startup_Initializations] - >>>>> ReStarting OH HS5150
10:52:19.971 [INFO ] [.model.script.Startup_Initializations] - >>>>> ReStarting OH HS5150
10:52:19.971 [INFO ] [.model.script.Startup_Initializations] - >>>>> ReStarting OH HS5150
10:52:19.971 [INFO ] [.model.script.Startup_Initializations] - >>>>> ReStarting OH HS5150
10:52:19.971 [INFO ] [.model.script.Startup_Initializations] - >>>>> ReStarting OH HS5150
10:52:19.971 [INFO ] [.model.script.Startup_Initializations] - >>>>> ReStarting OH HS5150
10:52:19.971 [INFO ] [.model.script.Startup_Initializations] - >>>>> ReStarting OH HS5150
10:52:19.987 [INFO ] [.model.script.Startup_Initializations] - >>>>> Persistence RestoreOnStartup 1 second timer starting now **********************
10:52:20.002 [INFO ] [.model.script.Startup_Initializations] - >>>>>>>>>>>>> RULE = Startup_Initializations.  mailActions = org.openhab.binding.mail.internal.action.SendMailActions@1a802c2c
10:52:21.000 [INFO ] [.model.script.Startup_Initializations] - >>>>> Persistence RestoreOnStartup 1 second timer expired ***************************
10:52:21.031 [INFO ] [.model.script.Startup_Initializations] - >>>>> OpenHAB is ReStarting OH HS5150 03/19/21 @ 10:51:04 AM.  NOW NOTIFY THE WORLD  MS0
10:52:21.031 [INFO ] [.model.script.Startup_Initializations] - >>>>>>>>>>>>> RULE = Startup_Initializations.  Ready to publish via actions.publishMQTT
10:52:21.031 [INFO ] [openhab.event.ItemCommandEvent       ] - Item 'IP_HS5150_Exec_R' received command OFF
10:52:21.046 [INFO ] [.model.script.Startup_Initializations] - >>>>>>>>>>>>> RULE = Startup_Initializations.  mqttActions = org.openhab.binding.mqtt.internal.action.MQTTActions@a83a4a8
10:52:21.046 [WARN ] [core.internal.scheduler.SchedulerImpl] - Scheduled job failed and stopped
java.lang.reflect.UndeclaredThrowableException: null
        at com.sun.proxy.$Proxy469.apply(Unknown Source) ~[?:?]
        at org.openhab.core.model.script.actions.ScriptExecution.lambda$0(ScriptExecution.java:82) ~[?:?]
        at org.openhab.core.internal.scheduler.SchedulerImpl.lambda$12(SchedulerImpl.java:166) ~[bundleFile:?]
        at org.openhab.core.internal.scheduler.SchedulerImpl.lambda$1(SchedulerImpl.java:76) [bundleFile:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
        at java.lang.Thread.run(Thread.java:834) [?:?]
Caused by: org.openhab.core.model.script.engine.ScriptExecutionException: The name 'mailActions' cannot be resolved to an item or type; line 568, column 4, length 11
        at org.openhab.core.model.script.interpreter.ScriptInterpreter.invokeFeature(ScriptInterpreter.java:141) ~[?:?]
        at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter._doEvaluate(XbaseInterpreter.java:992) ~[?:?]
        at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter._doEvaluate(XbaseInterpreter.java:955) ~[?:?]
        at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.doEvaluate(XbaseInterpreter.java:236) ~[?:?]
        at org.openhab.core.model.script.interpreter.ScriptInterpreter.doEvaluate(ScriptInterpreter.java:226) ~[?:?]
        at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.internalEvaluate(XbaseInterpreter.java:216) ~[?:?]
        at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter._doEvaluate(XbaseInterpreter.java:858) ~[?:?]
        at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.doEvaluate(XbaseInterpreter.java:232) ~[?:?]
        at org.openhab.core.model.script.interpreter.ScriptInterpreter.doEvaluate(ScriptInterpreter.java:226) ~[?:?]
        at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.internalEvaluate(XbaseInterpreter.java:216) ~[?:?]
        at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter._doEvaluate(XbaseInterpreter.java:459) ~[?:?]
        at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.doEvaluate(XbaseInterpreter.java:240) ~[?:?]
        at org.openhab.core.model.script.interpreter.ScriptInterpreter.doEvaluate(ScriptInterpreter.java:226) ~[?:?]
        at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.internalEvaluate(XbaseInterpreter.java:216) ~[?:?]
        at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter._doEvaluate(XbaseInterpreter.java:472) ~[?:?]
        at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.doEvaluate(XbaseInterpreter.java:256) ~[?:?]
        at org.openhab.core.model.script.interpreter.ScriptInterpreter.doEvaluate(ScriptInterpreter.java:226) ~[?:?]
        at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.internalEvaluate(XbaseInterpreter.java:216) ~[?:?]
        at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter._doEvaluate(XbaseInterpreter.java:459) ~[?:?]
        at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.doEvaluate(XbaseInterpreter.java:240) ~[?:?]
        at org.openhab.core.model.script.interpreter.ScriptInterpreter.doEvaluate(ScriptInterpreter.java:226) ~[?:?]
        at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.internalEvaluate(XbaseInterpreter.java:216) ~[?:?]
        at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.evaluate(XbaseInterpreter.java:202) ~[?:?]
        at org.eclipse.xtext.xbase.interpreter.impl.ClosureInvocationHandler.doInvoke(ClosureInvocationHandler.java:47) ~[?:?]
        at org.eclipse.xtext.xbase.interpreter.impl.AbstractClosureInvocationHandler.invoke(AbstractClosureInvocationHandler.java:30) ~[?:?]
        ... 10 more
10:52:21.062 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'Date' changed from 2021-03-19T10:51:04.017930500-0700 to 2021-03-19T10:52:21.031134400-0700
10:52:28.071 [ERROR] [.internal.handler.ScriptActionHandler] - Script execution of rule with UID 'HS5150-1' failed: An error occurred during the script execution: index=0, size=0 in HS5150
10:52:28.071 [INFO ] [re.automation.internal.RuleEngineImpl] - Rule engine started.
10:52:30.441 [INFO ] [ab.core.model.script.Update_OHCstring] - >>>>> ENTERED RULE = Update_OHCstring.  Roberts_Counter_Now = 0 GreenFlag = 1 Traffic_BrakeOHOB = 0 second = 30
10:52:30.441 [INFO ] [ab.core.model.script.Update_OHCstring] - >>>>> RUNNING RULE = Update_OHCstring.  Roberts_Counter_Now = 0
10:52:30.472 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'Date' changed from 2021-03-19T10:52:21.031134400-0700 to 2021-03-19T10:52:30.457342900-0700
10:52:30.472 [INFO ] [ab.core.model.script.Update_OHCstring] - >>>>> OpenHAB is READY 03/19/21 @ 10:52:30 AM
10:52:33.624 [INFO ] [ab.core.model.script.Update_OHCstring] - >>>>>>>>>>>>> RULE = Update_OHCstring.  Ready to publish via actions.publishMQTT
10:52:33.624 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'OHOB_WM_String' changed from
  • Notice also at 10:52:21.046 the log message is shown. The following line of code to be executed is a 7 second pause followed by actions.publishMQTT("SomeTopic", "SomePayload") upon which the code fail.
  • I have a different rule that triggers on Time cron "0/10 * * * * ?" that also fails
logInfo("Update_OHCstring", ">>>>>>>>>>>>> RULE = Update_OHCstring.  Ready to publish via actions.publishMQTT")
			actions.publishMQTT("SomeTopic", "SomePayload")
			logInfo("Update_OHCstring", ">>>>>>>>>>>>> RULE = Update_OHCstring.  Published via actions.publishMQTT")


11:17:20.392 [INFO ] [ab.core.model.script.Update_OHCstring] - >>>>>>>>>>>>> RULE = Update_OHCstring.  Ready to publish via actions.publishMQTT
11:17:20.392 [ERROR] [.internal.handler.ScriptActionHandler] - Script execution of rule with UID 'HS5150-7' failed: An error occurred during the script execution: index=0, size=0 in HS5150
  • I think my next step is to write a very simple .rule file with nothing more than the actions.publishMQTT.

Any thoughts?
Why the inconsistencies as evidenced by the log files?
A OH3 error? Probably not.
A mqtt error? Probably not.
A race issue? Seems likely.

Thanks again

18

Might I suggest again setting up at least one of these Things in the UI. It’s almost impossible to make a syntax error setting things up in the UI. Once it’s working the way you want you can look at the code tab and translate that to a .things file.

I’ve seen conflicting reports on this so I’m not sure what to make of it. Based on the behavior I assume that the triggers are not working like they always have (which was what I’ve been told) and System started is in fact using the new start levels (it’s probably equivalent to OH reaching start level 20 or start level 100). If that’s the case, openHAB only reaches those levels one during startup. Reloading a .rules file doesn’t cause openHAB to restart so there is no start level event to trigger the rule again.

Frankly, this is closer to the expected behavior of a trigger called “System started”.

Anyway, to work around this you can just click the play button in the UI to manually run the rule. I’m sure there is a command one can issue in the Karaf console as well to manually run the rule.

The point hfniumzinc was trying to make is that typically MQTT topics do not start with the leading /. It’s allowed but considered to be bad practice to use topics like that. These days the only time one usually sees a topic path that starts with “/” is because it’s either really old or it was custom written by someone who is not all that familiar with MQTT.

Assuming that someone other than you wrote what ever is publishing to these topics, they almost certainly do not use a leading “/”.

4, 5, and 6 are definitely wrong. 1, 2, and 3 depend on what the actual topics the publisher is really publishing to. It could be publishing to “/OHIB/OHC/12” but is most likely publishing to “OHIB/OHC/12”.

Assuming the Things didn’t in fact initialize then the Broker Thing itself is not initialized and therefore there is no way to get the publishMQTT action for that Broker Thing.

It would be better to not put the call to the action in a lambda. Just use a Thread::sleep instead of a Timer. Long running rules are not that big of a deal in OH 3 like they were in OH 2. Besides, you are just testing and experimenting to make things work. Once it works you can move back to using Timers.

I couldn’t say. It’s probably not a race condition because Things being loaded is essentially an independent process. And it takes seconds. If the Things don’t show up by the time the rules run, especially with the timers in place, they are not going to show up.

Also, you are not showing the logs until after OH comes up enough to log into the Karaf console. By that time the Things may have already loaded. Though this line seems relevant:

09:42:56.327 [WARN ] [.core.thing.internal.ThingManagerImpl] - Initializing handler for thing 'mqtt:broker:hsbroker' takes more than 5000ms.

I don’t think there has been any discussion about Things files being loaded inconsistently so I couldn’t say what is causing this problem.

19

I’m going to declare partial success .:slight_smile:
After stripping the .items and .rules files to bare minimum I found MY MY MY 1st error:

actions.publishMQTT("SomeTopic", "SomePayload")

should be

mqttActions.publishMQTT("SomeTopic", "SomePayload")

Such an obvious error. I triple checked my typing against a google thread that was flat out wrong. When I went back to the OpenHAB Binding Rules Actions documentation and reviewed it word by word I found the issue. That documentation also shows

val mqttActions = getActions("mqtt","mqtt:systemBroker:embedded-mqtt-broker")

That seems to be wrong? I would expect it should be

var mqttActions = getActions("mqtt","mqtt:systemBroker:embedded-mqtt-broker")

Do you agree?

Another thing I learned is that mqttActions needs to be made global when it is used in multiple rules.

My next step goal is to publish a string each time the string is updated via
myString.postUpdate("my message string.....")
Can I expect mqtt to publish on update as mqtt1 does?

After that I need to create many Things channels, and bind Number Items to mqtt.

BTW - Do you know how to squelch this superfluous log message I always get:

[WARN ] [.core.karaf.internal.FeatureInstaller] - The ui add-on 'classic' does not exist - ignoring it.

Big thanks to the Community again.

20

These are all valid usage;

val bananas = getActions("mqtt","mqtt:systemBroker:some-mqtt-broker")

rule "one"
...
   bananas.publishMQTT("Some/Topic", "SomePayload")
...

rule "two"
...
    val apples = getActions("mqtt","mqtt:systemBroker:some-mqtt-broker")
   .apples.publishMQTT("Some/Topic", "SomePayload")
...

The rule two construction of getting the actions when they are needed is sometimes preferred, because the “global” method of getting the actions at rule file load time can mess up at system boot time if the binding has not fully initialized at rule file load time. Your broker might not be ready yet, for example.

val or var doesn’t matter here.

No.
If you mean publish via Item/channel, then you must send a command.

You can do what you like when you like with a rule, of course.

Don’t ask for ClassicUI in your addons.cfg
It doesn’t exist in OH3.