[SOLVED] OH2: Can I invite someone to comment on my start-up log please

Max_G · July 13, 2019, 1:38am

My OH restarted, and comes up with the following log.
Can someone cast an eye over it and comment on what they see needs addressing, please?

I left the full start-up log intact, to provide context. The questions are, does this look like a reasonable sequence? Are things ‘responding’ as expected? Does something stick out?
I have further questions at the end. But have an unbiased look first. (It is best read when copied to notepad with full length lines.)

2019-07-11 20:00:00.041 [INFO ] [xtr064.internal.FritzboxTr064Binding] - Fritzbox Reconnect Job executed
2019-07-11 20:00:00.046 [INFO ] [g.fritzboxtr064.internal.CallMonitor] - Lost connection to Fritzbox because of interrupt
2019-07-11 20:00:05.050 [INFO ] [g.fritzboxtr064.internal.CallMonitor] - Connected to FritzBox on 192.168.1.1:1012
2019-07-11 20:17:28.780 [WARN ] [g.dispatch.internal.ConfigDispatcher] - The file /etc/openhab2/services/mqtt.cfg subsequently defines the exclusive PID 'org.openhab.mqtt'. Overriding existing configuration now.
2019-07-11 22:08:28.475 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'sysinfo.items'
2019-07-11 22:08:28.783 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'openings.items'
2019-07-11 22:08:29.012 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'weather.items'
2019-07-11 22:08:29.225 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'sppro_bms.items'
2019-07-11 22:08:29.390 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'irrigation1.items'
2019-07-11 22:08:29.545 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'geoLocation.items'
2019-07-11 22:08:29.628 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'fritzbox.items'
2019-07-11 22:08:29.746 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'house_sensors.items'
2019-07-11 22:08:29.823 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'shed.items'
2019-07-11 22:08:29.920 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'maingate.items'
2019-07-11 22:08:29.986 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'groups.items'
2019-07-11 22:08:30.166 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'watersystem.items'
2019-07-11 22:08:30.224 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'astro.items'
2019-07-11 22:08:30.271 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'lights.items'
2019-07-11 22:08:30.371 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'powerpoints.items'
2019-07-11 22:08:30.409 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'main.items'
2019-07-11 22:08:31.209 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'rrd4j.persist'
2019-07-11 22:08:31.277 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'mapdb.persist'
2019-07-11 22:08:40.162 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'max01.rules'
2019-07-11 22:08:41.737 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'other.rules'
2019-07-11 22:08:42.681 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'maingate.rules'
2019-07-11 22:08:45.235 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'weather.rules'
2019-07-11 22:08:48.952 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'watersystem.rules'
2019-07-11 22:08:50.222 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'shed.rules'
2019-07-11 22:08:50.909 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'init.rules'
2019-07-11 22:08:54.957 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'geoLocation.rules'
2019-07-11 22:09:05.751 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'sppro_bms.rules'
2019-07-11 22:09:14.906 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'irrigation1.rules'
2019-07-11 22:09:15.896 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'fritzbox.rules'
2019-07-11 22:09:16.814 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
2019-07-11 22:09:17.566 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'demo.sitemap'
2019-07-11 22:09:17.815 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'max01.sitemap'
2019-07-11 22:09:17.963 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'irrigation.sitemap'
2019-07-11 22:09:18.449 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'main.things'
2019-07-11 22:09:20.810 [INFO ] [thome.binding.astro.internal.job.Job] - Scheduled Astro event-jobs for thing astro:sun:home
2019-07-11 22:09:20.864 [INFO ] [ding.astro.handler.AstroThingHandler] - Scheduled Positional job astro:sun:home every 60 seconds
2019-07-11 22:09:20.952 [INFO ] [thome.binding.astro.internal.job.Job] - Scheduled Astro event-jobs for thing astro:sun:minus90
2019-07-11 22:09:21.375 [INFO ] [thome.binding.astro.internal.job.Job] - Scheduled Astro event-jobs for thing astro:moon:home
2019-07-11 22:09:22.292 [WARN ] [e.jetty.util.thread.ThreadPoolBudget] - Low configured threads: (max=8 - required=1)=7 < warnAt=8 for QueuedThreadPool[ServletModel-12]@b0aac5{STARTING,8<=0<=8,i=0,q=0}[ReservedThreadExecutor@12fc6bb{s=0/1,p=0}]
2019-07-11 22:09:22.900 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at http://192.168.1.5:8080
2019-07-11 22:09:22.904 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at https://192.168.1.5:8443
2019-07-11 22:09:24.205 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'ntp:ntp:local' to inbox.
2019-07-11 22:09:31.087 [INFO ] [smarthome.model.script.watersystem.0] - loading rule and initialise state(s)
2019-07-11 22:09:43.520 [INFO ] [smarthome.model.script.Irrigation1.0] - System Start: Irrigation 1 rules
2019-07-11 22:09:43.725 [INFO ] [.eclipse.smarthome.model.script.init] - initialise states...
2019-07-11 22:09:43.739 [INFO ] [.eclipse.smarthome.model.script.init] - initialise states...
2019-07-11 22:09:43.790 [INFO ] [smarthome.model.script.Irrigation1.0] - System Start: Irrigation 1 rules
2019-07-11 22:09:43.933 [WARN ] [nce.extensions.PersistenceExtensions] - There is no queryable persistence service registered with the id 'rrd4j'
2019-07-11 22:09:43.933 [WARN ] [nce.extensions.PersistenceExtensions] - There is no queryable persistence service registered with the id 'rrd4j'
2019-07-11 22:09:43.938 [ERROR] [ntime.internal.engine.RuleEngineImpl] - Error during the execution of startup rule 'Update Tank Irrigation Level max / min values': cannot invoke method public abstract org.eclipse.smarthome.core.types.State org.eclipse.smarthome.core.persistence.HistoricItem.getState() on null
2019-07-11 22:09:43.938 [ERROR] [ntime.internal.engine.RuleEngineImpl] - Error during the execution of startup rule 'Update Tank Irrigation Level max / min values': cannot invoke method public abstract org.eclipse.smarthome.core.types.State org.eclipse.smarthome.core.persistence.HistoricItem.getState() on null
2019-07-11 22:09:45.932 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui
2019-07-11 22:09:48.374 [INFO ] [b.core.service.AbstractActiveService] - FritzboxTr064 Refresh Service has been started
2019-07-11 22:09:48.386 [INFO ] [tzboxtr064.internal.PhonebookManager] - Downloading phonebook ID 0
2019-07-11 22:09:48.403 [INFO ] [b.core.service.AbstractActiveService] - Expire Refresh Service has been started
2019-07-11 22:09:48.482 [INFO ] [penhab.io.transport.mqtt.MqttService] - MQTT Service initialization completed.
2019-07-11 22:09:48.491 [INFO ] [t.mqtt.internal.MqttBrokerConnection] - Starting MQTT broker connection 'mymosquitto'
2019-07-11 22:10:00.697 [INFO ] [smarthome.model.script.watersystem.0] - loading rule and initialise state(s)
2019-07-11 22:10:00.881 [INFO ] [.eclipse.smarthome.model.script.init] - initialise states...
2019-07-11 22:10:00.886 [WARN ] [nce.extensions.PersistenceExtensions] - There is no queryable persistence service registered with the id 'rrd4j'
2019-07-11 22:10:15.143 [ERROR] [ntime.internal.engine.RuleEngineImpl] - Error during the execution of startup rule 'Update Tank Irrigation Level max / min values': cannot invoke method public abstract org.eclipse.smarthome.core.types.State org.eclipse.smarthome.core.persistence.HistoricItem.getState() on null
2019-07-11 22:10:15.142 [INFO ] [smarthome.model.script.Irrigation1.0] - System Start: Irrigation 1 rules
2019-07-11 22:10:22.032 [INFO ] [g.fritzboxtr064.internal.CallMonitor] - Connected to FritzBox on 192.168.1.1:1012
2019-07-11 22:10:37.177 [INFO ] [smarthome.model.script.Irrigation1.0] - System Start: Irrigation 1 rules
2019-07-11 22:10:42.307 [INFO ] [smarthome.model.script.watersystem.0] - loading rule and initialise state(s)
2019-07-11 22:10:42.454 [INFO ] [.eclipse.smarthome.model.script.init] - initialise states...
2019-07-11 22:10:42.459 [WARN ] [nce.extensions.PersistenceExtensions] - There is no queryable persistence service registered with the id 'rrd4j'
2019-07-11 22:10:42.464 [ERROR] [ntime.internal.engine.RuleEngineImpl] - Error during the execution of startup rule 'Update Tank Irrigation Level max / min values': cannot invoke method public abstract org.eclipse.smarthome.core.types.State org.eclipse.smarthome.core.persistence.HistoricItem.getState() on null
2019-07-11 22:10:43.335 [ERROR] [ntime.internal.engine.RuleEngineImpl] - Rule 'Monitor traffic': An error occurred during the script execution: Could not invoke method: org.eclipse.smarthome.model.script.lib.NumberExtensions.operator_minus(java.lang.Number,java.lang.Number) on instance: null
2019-07-11 22:11:09.522 [INFO ] [.eclipse.smarthome.model.script.init] - initialise states...
2019-07-11 22:11:09.523 [INFO ] [smarthome.model.script.watersystem.0] - loading rule and initialise state(s)
2019-07-11 22:11:09.527 [INFO ] [smarthome.model.script.Irrigation1.0] - System Start: Irrigation 1 rules
2019-07-11 22:11:09.529 [WARN ] [nce.extensions.PersistenceExtensions] - There is no queryable persistence service registered with the id 'rrd4j'
2019-07-11 22:11:09.532 [ERROR] [ntime.internal.engine.RuleEngineImpl] - Error during the execution of startup rule 'Update Tank Irrigation Level max / min values': cannot invoke method public abstract org.eclipse.smarthome.core.types.State org.eclipse.smarthome.core.persistence.HistoricItem.getState() on null
2019-07-11 22:11:09.563 [ERROR] [ntime.internal.engine.RuleEngineImpl] - Rule 'Notify of log reader messages': The name 'emailToMax' cannot be resolved to an item or type; line 69, column 11, length 10
2019-07-11 22:11:23.209 [INFO ] [smarthome.model.script.watersystem.0] - loading rule and initialise state(s)
2019-07-11 22:11:36.705 [INFO ] [smarthome.model.script.Irrigation1.0] - System Start: Irrigation 1 rules
2019-07-11 22:11:36.705 [WARN ] [nce.extensions.PersistenceExtensions] - There is no queryable persistence service registered with the id 'rrd4j'
2019-07-11 22:11:36.708 [INFO ] [.eclipse.smarthome.model.script.init] - initialise states...
2019-07-11 22:11:36.711 [ERROR] [ntime.internal.engine.RuleEngineImpl] - Error during the execution of startup rule 'Update Tank Irrigation Level max / min values': cannot invoke method
2019-07-11 22:11:37.660 [ERROR] [ntime.internal.engine.RuleEngineImpl] - Rule 'Monitor traffic': An error occurred during the script execution: Could not invoke method: org.eclipse.smart
2019-07-11 22:11:42.924 [ERROR] [ntime.internal.engine.RuleEngineImpl] - Rule 'Geo Location Max': Could not cast NULL to java.lang.Number; line 99, column 42, length 33
2019-07-11 22:11:44.936 [ERROR] [pse.smarthome.core.items.GenericItem] - Tried to set invalid state null##null (StringType) on item fbox_IncomingCallResolved of type CallItem, ignoring i
2019-07-11 22:11:45.127 [ERROR] [pse.smarthome.core.items.GenericItem] - Tried to set invalid state null##null (StringType) on item fbox_IncomingCall of type CallItem, ignoring it
2019-07-11 22:11:45.361 [ERROR] [pse.smarthome.core.items.GenericItem] - Tried to set invalid state null##null (StringType) on item fboxOutgoingCall of type CallItem, ignoring it
2019-07-11 22:11:45.431 [ERROR] [pse.smarthome.core.items.GenericItem] - Tried to set invalid state null##null (StringType) on item fboxIncomingCallResolved of type CallItem, ignoring it
2019-07-11 22:11:45.678 [ERROR] [pse.smarthome.core.items.GenericItem] - Tried to set invalid state null##null (StringType) on item fbox_OutgoingCall of type CallItem, ignoring it
2019-07-11 22:11:45.711 [ERROR] [pse.smarthome.core.items.GenericItem] - Tried to set invalid state null##null (StringType) on item fboxIncomingCall of type CallItem, ignoring it
2019-07-11 22:12:03.219 [INFO ] [marthome.model.script.Irrigation1.30] - Irrigation1: stopping = cancelling timer(s)
2019-07-11 22:12:03.230 [INFO ] [marthome.model.script.Irrigation1.31] - Irrigation1: turning OFF all valves regardless of state
2019-07-11 22:12:03.290 [INFO ] [.model.script.GridSupportManualOff.1] - GridSupportManual set to OFF
2019-07-11 22:12:03.787 [INFO ] [eather.internal.common.WeatherConfig] - ProviderConfig[providerName=FORECASTIO,apiKey=1c1bbf3b13bac5b092bd7a763fa62ce3]
2019-07-11 22:12:03.805 [INFO ] [eather.internal.common.WeatherConfig] - LocationConfig[providerName=FORECASTIO,language=en,updateInterval=10,latitude=-27.3164855,longitude=152.3701568,w
2019-07-11 22:12:03.807 [INFO ] [eather.internal.common.WeatherConfig] - LocationConfig[providerName=YAHOO,language=en,updateInterval=10,latitude=<null>,longitude=<null>,woeid=1102162,lo
2019-07-11 22:12:05.535 [INFO ] [marthome.model.script.Irrigation1.00] - Irrigation1 -> enabled.
2019-07-11 22:12:05.539 [INFO ] [marthome.model.script.Irrigation1.30] - Irrigation1: stopping = cancelling timer(s)
2019-07-11 22:12:05.543 [INFO ] [marthome.model.script.Irrigation1.31] - Irrigation1: turning OFF all valves regardless of state
2019-07-11 22:12:05.560 [INFO ] [.smarthome.model.script.TankFilledUp] - Tank_Irrigation_Demand............: OFF
2019-07-11 22:12:05.568 [INFO ] [rthome.model.script.HWS_BoostTimer.3] - test Shed_RC41_HotWaterSystem = Early Morning Boost OFF
2019-07-11 22:12:06.725 [INFO ] [se.smarthome.model.script.BorePump.3] - Bore Pump: stopped
2019-07-11 22:12:06.787 [INFO ] [thome.model.script.ProfitLossTotal.1] - ProfitLossTotal yesterday.0.: 52.64
2019-07-11 22:12:06.830 [INFO ] [ternal.scheduler.WeatherJobScheduler] - Starting and scheduling weatherJob-argyle with interval of 10 minutes
2019-07-11 22:12:06.831 [INFO ] [thome.model.script.ProfitLossTotal.1] - ProfitLossTotal yesterday.1.: 52.64
2019-07-11 22:12:06.836 [INFO ] [thome.model.script.ProfitLossTotal.2] - ProfitLoss updated (night)..: 1.39
2019-07-11 22:12:06.839 [INFO ] [thome.model.script.ProfitLossTotal.3] - ProfitLoss corrections......: 0.000
2019-07-11 22:12:06.842 [INFO ] [ternal.scheduler.WeatherJobScheduler] - Disabling weather locationId 'home', no binding available
2019-07-11 22:12:06.847 [INFO ] [thome.model.script.ProfitLossTotal.4] - ProfitLossTotal new today...: 54.030
2019-07-11 22:12:06.912 [INFO ] [thome.model.script.ProfitLossTotal.5] - Import......................: -1.87
2019-07-11 22:12:06.916 [INFO ] [thome.model.script.ProfitLossTotal.6] - ImportTotalYear.1...........: -358.481
2019-07-11 22:12:06.927 [INFO ] [thome.model.script.ProfitLossTotal.7] - ImportTotalYear w Correction: -358.4810
2019-07-11 22:12:06.953 [INFO ] [thome.model.script.ProfitLossTotal.8] - ImportTotalYear.2...........: -360.3510
2019-07-11 22:12:42.836 [INFO ] [e.smarthome.model.script.fBbox.Mon.0] - byteIn................ 1071210116
2019-07-12 00:00:00.008 [INFO ] [xtr064.internal.FritzboxTr064Binding] - Fritzbox Reconnect Job executed
2019-07-12 00:00:00.015 [INFO ] [g.fritzboxtr064.internal.CallMonitor] - Lost connection to Fritzbox because of interrupt

What catches my attention is:

2019-07-11 20:17:28.780 [WARN ] [g.dispatch.internal.ConfigDispatcher] - The file /etc/openhab2/services/mqtt.cfg subsequently defines the exclusive PID 'org.openhab.mqtt'. Overriding existing configuration now.

What does this mean?

2019-07-11 22:09:22.292 [WARN ] [e.jetty.util.thread.ThreadPoolBudget] - Low configured threads: (max=8 - required=1)=7 < warnAt=8 for QueuedThreadPool[ServletModel-12]@b0aac5{STARTING,8<=0<=8,i=0,q=0}[ReservedThreadExecutor@12fc6bb{s=0/1,p=0}]

Do I need to worry about this, and what can I do to fix it?
Seems to be related to "Low configured threads" warning

2019-07-11 22:09:43.933 [WARN ] [nce.extensions.PersistenceExtensions] - There is no queryable persistence service registered with the id 'rrd4j'

Weird, it is working once the system is up.

2019-07-11 22:09:43.938 [ERROR] [ntime.internal.engine.RuleEngineImpl] - Error during the execution of startup rule 'Update Tank Irrigation Level max / min values': cannot invoke method public abstract org.eclipse.smarthome.core.types.State org.eclipse.smarthome.core.persistence.HistoricItem.getState() on null

?

2019-07-11 22:11:09.563 [ERROR] [ntime.internal.engine.RuleEngineImpl] - Rule 'Notify of log reader messages': The name 'emailToMax' cannot be resolved to an item or type; line 69, column 11, length 10

… yest this rule file has this at the beginning:

val String emailToMax   = "myEmail@gmail.com"

… and the rule looks like htis:

// ----- 190210-1010 Notify of log reader messages
rule "Notify of log reader messages"
  when
    Channel "logreader:reader:openhablog:newErrorEvent" triggered
  then
    if (blnEmailLock_errMsg == false) {
      errMsgCount = errMsgCount + 1

      if (errMsgCount < 5) {
        sendMail(
          emailToMax,
          "rPi3OHv2: encountered errors in openHAB.log",
          "rPi3OHv2: " + logreaderLastError.state
        )

      } else {
        sendMail(
          emailToMax,
          "rPi3OHv2: encountered " + errMsgCount + " errors in openHAB.log",
          "rPi3OHv2: " + logreaderLastError.state + ". Further error messages have been suppressed for 6 hours."
        )
        blnEmailLock_errMsg = true
      }
    }
end

… and sending of mail eventually works; meaning I get these messages after start-up; maybe something hasn’t loaded yet.

2019-07-11 22:11:36.711 [ERROR] [ntime.internal.engine.RuleEngineImpl] - Error during the execution of startup rule 'Update Tank Irrigation Level max / min values': cannot invoke method

the related rule is:

// ----- 170306 MaxG: update min max for irrigation tank level -----
rule "Update Tank Irrigation Level max / min values"
  when
    Item Tank_Irrigation_Level changed or
    Time cron "1 0 0 * * ?" or
    System started
  then
    val startOfDay = now.withTimeAtStartOfDay     // toDateMidnight

    if (Tank_Irrigation_Level !== null) {
      Tank_Irrigation_Level_Max.postUpdate((Tank_Irrigation_Level.maximumSince(startOfDay).state as DecimalType).intValue)
      Tank_Irrigation_Level_Min.postUpdate((Tank_Irrigation_Level.minimumSince(startOfDay).state as DecimalType).intValue)
    }
end

… and works under normal operation.

2019-07-11 22:11:37.660 [ERROR] [ntime.internal.engine.RuleEngineImpl] - Rule 'Monitor traffic': An error occurred during the script execution: Could not invoke method: org.eclipse.smart

realted rule:

// ----- 190126 MaxG: monitor traffic
rule "Monitor traffic"
  when
    Item fbox_WanTotalBytesReceived received update
  then
    val byteIn      = fbox_WanTotalBytesReceived.state as DecimalType
    val byteInMB    = byteIn / (1024 * 1024)
    val byteOutMB   = fbox_WanTotalBytesSent.state as DecimalType / (1024 * 1024)
    val byteTotMB   = byteInMB + byteOutMB

    val byteInPrev  = fbox_WanTotalBytesReceivedPrev.state
    var byteInDelta = (byteIn - byteInPrev) / 1024

    if (byteInDelta < 0) {
        logInfo("fBbox.Mon.0", "byteIn................ {}", byteIn)
      byteInDelta = 0
    }

    fbox_WanTotal_MB_Sent.postUpdate(byteOutMB)
    fbox_WanTotal_MB_Rec.postUpdate(byteInMB)
    fbox_WanTotal_MB_Total.postUpdate(byteTotMB)

    fbox_WanTotalBytesReceivedPrev.postUpdate(byteIn)
    fbox_WanTotal_RecDelta.postUpdate(byteInDelta)
end

Works under normal operation.

2019-07-11 22:11:42.924 [ERROR] [ntime.internal.engine.RuleEngineImpl] - Rule 'Geo Location Max': Could not cast NULL to java.lang.Number; line 99, column 42, length 33

related rule fragment:

      // 181014: see if we reached the gateTriggerRadius for opening the gate
      if (MaxG_DistanceFromHome.state <= GateTriggerRadius.state as Number) {

indicating this item: GateTriggerRadius.state

2019-07-11 22:11:44.936 [ERROR] [pse.smarthome.core.items.GenericItem] - Tried to set invalid state null##null (StringType) on item fbox_IncomingCallResolved of type CallItem, ignoring i

… and following lines; Would I have to initialise these values somehow? I thought it would grab these from the Fritzbox?!

2019-07-11 22:12:03.807 [INFO ] [eather.internal.common.WeatherConfig] - LocationConfig[providerName=YAHOO,language=en,updateInterval=10,latitude=<null>,longitude=<null>,woeid=1102155,lo

Seems a left over somewhere in the config I will fix. Have no Yahoo, ended service earlier this year anyway.

I reckon the ‘rrd4j’ errors show, because persistence hasn’t loaded yet?! IS there a way to fix it.

Any feedback (also on rules shown) including improvements or flaws much appreciated.

In any case, you’re a champ if you made it to the end of this post. Thank you.

J-N-K · July 13, 2019, 6:09am

I think there is nothing to worry about. You could add null-checks to your rules, (check if the item is null before calling getState or using its value) but If everything is doing fine after startup this is more cosmetic.

You are right about the missing persistence service. I know of no way to fix that.

Max_G · July 13, 2019, 9:30am

Thanks. Will take the null checks on board.

rrdj4 is loaded with all the other ‘models’, seemingly present…?

The reason I posted it that I do not like error message appear for no apparent reason.

rlkoshak · July 13, 2019, 2:23pm

What version of OH?

Over all this is a reasonably clean boot. No exceptions with stack traces at least.

I don’t personally use .things files any more but I would have expected oh to try to load them first. But it’s a known issue that oh loads these files in parallel which can result in bad behavior like rules that trigger before items are done loading, for example.

I think there is an issue already opened for the low configured threads.

The no queriable persistence service can be caused by the parallel start up problem mentioned above. The rule triggered before rrd4j was started.

The monitor traffic role error can also be caused by the loading order problem. In this case either the Item used in a minus calculation either doesn’t exist yet or it has a non-number state.

The null#null errors seem to come from the binding but I can’t tell. I don’t use CallItems nor any binding that would use that. But null#null is unlikely to be a state you would try to set these items to in a rule.

The disabling location home looks like a missconfiguration of the weather binding you are using.

But some or all of your system started rules errored out instead of finishing. This too points to oh’s broken file loading and parsing.

There are work arounds posted here and there which usually involve a script that holds the rules in some other location and moved them back after a time.

Max_G · July 15, 2019, 11:05am

Thanks for looking into this.
I’ve got OH v 2.4.0-1
Have fixed the YAHOO config.

What is the alternative? Or better way of doing this?
I use them for network:pingdevice, and logreader:reader:openhablog

rlkoshak · July 15, 2019, 3:38pm

I use PaperUI and autodiscovery for 95% of my Things. For the remaining 5% I manually create them using PaperUI.

When I transitioned from MQTT 1.x to 2.x, I created one MQTT 2 Thing using PaperUI, stopped OH, and copy/paste/edit to create the rest of the Things I needed that were similar (e.g. I created one Generic Thing for my Sonoffs, then I manually edited the JSONDB to add the Things for all the rest). I hind sight, I would probably take a different approach. I’d still create the MQTT 2 Generic Thing for one of the Sonoffs, but instead of stopping OH and manually editing the JSONDB I’d use the REST API to pull the JSON for the Thing and then use the REST API to create the new Things using an edited version of the pulled JSON.

Many of the problems you are experiencing come from how openHAB loads the text config files. I’ve experienced some of the same problems, though usually a second restart will work. These startup problems are not a problem when OH loads it’s settings from JSONDB instead of text configs (it’s a lot faster too). So I’ve been slowly moving as much as possible from text configs to JSONDB. Next on the list is Items. Hopefully by that point the Rules will have some important fixes and I can move my Rules over to NGRE. Work is currently being done to support .persist and .sitemap files, but they probably won’t be done until OH 3 sometime next year.

Max_G · July 21, 2019, 6:09am

Again, thank you for your detailed response.

What kept me from using anything other than config files, is the compartmentalisation of items. I have some 580 items, and a single page in PaperUI is not really helpful; in particular that it also sorts on the clear text name, not on the item name.

Some 11 .items files (here line count not item count)

    4 astro.items
  101 fritzbox.items
   27 geoLocation.items
   90 groups.items
   18 house_sensors.items
   67 irrigation1.items
   77 lights.items
   17 maingate.items
   53 main.items
   58 openings.items
    4 powerpoints.items
   60 shed.items
   66 sppro_bms.items
   25 sysinfo.items
   52 watersystem.items
  109 weather.items

I reckon I wait and keep quiet to see what OH3 will bring

rlkoshak · July 21, 2019, 3:27pm

PaperUI does provide a search function. And the REST API also provides a search function. I’m finding a lot of good ways to find and sort and work with Items through the REST API docs as well (e.g. using tags to group Items together).

I’m also finding that with JSR223 Rules we have the ability to set and read metadata on Items. With this capability, the need to store stuff in separate Items is not as great allowing for the elimination of a lot of Items.

I’m definitely not claiming that PaperUI is great. But I can say that OH itself starts up much better and runs much better when not using text based configs.