openhab / openhab1-addons

Add-ons for openHAB 1.x
Eclipse Public License 2.0
3.43k stars 1.7k forks source link

Error during the execution of startup rule #3502

Closed kirantpatil closed 8 years ago

kirantpatil commented 8 years ago

I did build the OH v1.7.1 with XBee binding using "mvn clean install".

Now added demo.rules, demo.items and did run ./start_debug.sh and its output is below with Error while applying rule.

kpatil  ⋯  distribution  target  runtime  java -version

java version "1.8.0_60" Java(TM) SE Runtime Environment (build 1.8.0_60-b27) Java HotSpot(TM) 64-Bit Server VM (build 25.60-b23, mixed mode)

kpatil  ⋯  distribution  target  runtime  ./start_debug.sh

Launching the openHAB runtime in debug mode... Listening for transport dt_socket at address: 8001 osgi> 13:12:07.628 [DEBUG] [.s.internal.SchedulerActivator:36 ] - Scheduler has been started. 13:12:07.702 [INFO ] [uartz.impl.StdSchedulerFactory:1175 ] - Using default implementation for ThreadExecutor 13:12:07.730 [INFO ] [rtz.core.SchedulerSignalerImpl:61 ] - Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl 13:12:07.731 [INFO ] [rg.quartz.core.QuartzScheduler:243 ] - Quartz Scheduler v.2.1.7 created. 13:12:07.732 [INFO ] [org.quartz.simpl.RAMJobStore :154 ] - RAMJobStore initialized. 13:12:07.734 [INFO ] [rg.quartz.core.QuartzScheduler:268 ] - Scheduler meta-data: Quartz Scheduler (v2.1.7) 'openHAB-job-scheduler' with instanceId 'NON_CLUSTERED' Scheduler class: 'org.quartz.core.QuartzScheduler' - running locally. NOT STARTED. Currently in standby mode. Number of jobs executed: 0 Using thread pool 'org.quartz.simpl.SimpleThreadPool' - with 2 threads. Using job-store 'org.quartz.simpl.RAMJobStore' - which does not support persistence. and is not clustered.

13:12:07.735 [INFO ] [uartz.impl.StdSchedulerFactory:1324 ] - Quartz scheduler 'openHAB-job-scheduler' initialized from specified file: './etc/quartz.properties' 13:12:07.735 [INFO ] [uartz.impl.StdSchedulerFactory:1328 ] - Quartz scheduler version: 2.1.7 13:12:07.736 [INFO ] [rg.quartz.core.QuartzScheduler:534 ] - Scheduler openHAB-job-scheduler_$_NON_CLUSTERED started. 13:12:07.742 [DEBUG] [o.config.core.ConfigDispatcher:146 ] - Processing openHAB default configuration file '/home/kpatil/Documents/homeautomation/openhab/distribution/target/runtime/configurations/openhab_default.cfg'. 13:12:07.743 [DEBUG] [o.config.core.ConfigDispatcher:168 ] - Processing openHAB main configuration file '/home/kpatil/Documents/homeautomation/openhab/distribution/target/runtime/configurations/openhab.cfg'. 13:12:08.205 [DEBUG] [.o.core.internal.CoreActivator:93 ] - UUID file already exists at '/home/kpatil/Documents/homeautomation/openhab/distribution/target/runtime/webapps/static/uuid' with content '3e59a8c8-3412-49b4-a24d-6c9d3edae870' 13:12:08.207 [DEBUG] [.o.core.internal.CoreActivator:115 ] - Created file '/home/kpatil/Documents/homeautomation/openhab/distribution/target/runtime/webapps/static/version' with content '1.7.1' 13:12:08.208 [INFO ] [.o.core.internal.CoreActivator:61 ] - openHAB runtime has been started (v1.7.1). 13:12:08.252 [DEBUG] [a.internal.AutoUpdateActivator:31 ] - AutoUpdate binding has been started. 13:12:10.198 [DEBUG] [.p.i.PersistenceModelActivator:23 ] - Registered 'persistence' configuration parser 13:12:10.269 [DEBUG] [.c.t.i.TransformationActivator:38 ] - Transformation Service has been started. 13:12:10.359 [DEBUG] [m.internal.MultimediaActivator:34 ] - Multimedia I/O bundle has been started. 13:12:10.403 [DEBUG] [.s.i.DiscoveryServiceActivator:27 ] - Discovery service has been started. 13:12:10.413 [INFO ] [o.o.i.s.i.DiscoveryServiceImpl:93 ] - mDNS service has been started 13:12:10.457 [DEBUG] [.io.transport.mqtt.MqttService:123 ] - Starting MQTT Service... 13:12:10.721 [DEBUG] [.i.internal.ItemModelActivator:24 ] - Registered 'item' configuration parser 13:12:10.899 [INFO ] [o.o.i.s.i.DiscoveryServiceImpl:53 ] - Service Discovery initialization completed. 13:12:10.942 [DEBUG] [o.o.c.i.items.ItemRegistryImpl:137 ] - Item provider 'GenericItemProvider' has been added. 13:12:12.378 [DEBUG] [.o.m.s.i.SitemapModelActivator:23 ] - Registered 'sitemap' configuration parser 13:12:12.582 [DEBUG] [io.rest.internal.RESTActivator:33 ] - REST API has been started. 13:12:12.687 [INFO ] [org.atmosphere.util.IOUtils :370 ] - META-INF/services/org.atmosphere.cpr.AtmosphereFramework not found in class loader 13:12:12.745 [INFO ] [sphere.cpr.AtmosphereFramework:2601 ] - Atmosphere is using org.atmosphere.cpr.DefaultAnnotationProcessor for processing annotation 13:12:12.748 [INFO ] [cpr.DefaultAnnotationProcessor:138 ] - AnnotationProcessor class org.atmosphere.cpr.DefaultAnnotationProcessor$BytecodeBasedAnnotationProcessor being used 13:12:12.771 [WARN ] [cpr.DefaultAnnotationProcessor:178 ] - Unable to detect annotations. Application may fail to deploy. 13:12:12.874 [INFO ] [sphere.cpr.AtmosphereFramework:1891 ] - Auto detecting atmosphere handlers /WEB-INF/classes/ 13:12:12.898 [INFO ] [sphere.cpr.AtmosphereFramework:639 ] - Installed AtmosphereHandler org.atmosphere.handler.ReflectorServletProcessor mapped to context-path /* and Broadcaster Class org.atmosphere.jersey.JerseyBroadcaster 13:12:12.900 [INFO ] [sphere.cpr.AtmosphereFramework:1945 ] - Auto detecting WebSocketHandler in /WEB-INF/classes/ 13:12:12.901 [INFO ] [sphere.cpr.AtmosphereFramework:1602 ] - Installed WebSocketProtocol org.atmosphere.websocket.protocol.SimpleHttpProtocol 13:12:12.976 [INFO ] [.a.h.ReflectorServletProcessor:103 ] - Installing Servlet com.sun.jersey.spi.container.servlet.ServletContainer 13:12:13.139 [INFO ] [c.s.j.s.i.a.WebApplicationImpl:815 ] - Initiating Jersey application, version 'Jersey: 1.18.1 02/19/2014 03:28 AM' 13:12:13.143 [INFO ] [c.s.j.s.i.a.WebApplicationImpl:826 ] - Adding the following classes declared in META-INF/services/jersey-server-components to the resource configuration: class org.atmosphere.jersey.AtmosphereResourceConfigurator 13:12:13.265 [INFO ] [j.s.i.a.DeferredResourceConfig:101 ] - Instantiated the Application class org.openhab.io.rest.RESTApplication 13:12:14.677 [INFO ] [sphere.cpr.AtmosphereFramework:2435 ] - AtmosphereInterceptor CORS Interceptor Support will always be executed first 13:12:14.678 [INFO ] [sphere.cpr.AtmosphereFramework:2404 ] - Installed AtmosphereInterceptor CORS Interceptor Support with priority FIRST_BEFORE_DEFAULT 13:12:14.678 [INFO ] [sphere.cpr.AtmosphereFramework:2404 ] - Installed AtmosphereInterceptor Default Response's Headers Interceptor with priority AFTER_DEFAULT 13:12:14.680 [INFO ] [sphere.cpr.AtmosphereFramework:2404 ] - Installed AtmosphereInterceptor Android Interceptor Support with priority AFTER_DEFAULT 13:12:14.682 [INFO ] [sphere.cpr.AtmosphereFramework:2404 ] - Installed AtmosphereInterceptor SSE Interceptor Support with priority AFTER_DEFAULT 13:12:14.683 [INFO ] [sphere.cpr.AtmosphereFramework:2404 ] - Installed AtmosphereInterceptor JSONP Interceptor Support with priority AFTER_DEFAULT 13:12:14.688 [INFO ] [sphere.cpr.AtmosphereFramework:2404 ] - Installed AtmosphereInterceptor Atmosphere JavaScript Protocol with priority AFTER_DEFAULT 13:12:14.689 [INFO ] [sphere.cpr.AtmosphereFramework:2404 ] - Installed AtmosphereInterceptor Browser disconnection detection with priority AFTER_DEFAULT 13:12:14.697 [INFO ] [sphere.cpr.AtmosphereFramework:935 ] - Using EndpointMapper class org.atmosphere.util.DefaultEndpointMapper 13:12:14.715 [WARN ] [sphere.cpr.AtmosphereFramework:941 ] - No BroadcasterCache configured. Broadcasted message between client reconnection will be LOST. It is recommended to configure the org.atmosphere.cache.UUIDBroadcasterCache 13:12:14.716 [INFO ] [sphere.cpr.AtmosphereFramework:949 ] - Default Broadcaster Class: org.atmosphere.jersey.JerseyBroadcaster 13:12:14.719 [INFO ] [sphere.cpr.AtmosphereFramework:950 ] - Broadcaster Polling Wait Time 100 13:12:14.720 [INFO ] [sphere.cpr.AtmosphereFramework:951 ] - Shared ExecutorService supported: true 13:12:14.721 [INFO ] [sphere.cpr.AtmosphereFramework:958 ] - Messaging Thread Pool Size: 10 13:12:14.722 [INFO ] [sphere.cpr.AtmosphereFramework:968 ] - Async I/O Thread Pool Size: 10 13:12:14.722 [INFO ] [sphere.cpr.AtmosphereFramework:979 ] - Using BroadcasterFactory: org.atmosphere.cpr.DefaultBroadcasterFactory 13:12:14.725 [INFO ] [sphere.cpr.AtmosphereFramework:980 ] - Using WebSocketProcessor: org.atmosphere.websocket.DefaultWebSocketProcessor 13:12:14.726 [INFO ] [sphere.cpr.AtmosphereFramework:990 ] - Invoke AtmosphereInterceptor on WebSocket message true 13:12:14.726 [INFO ] [sphere.cpr.AtmosphereFramework:991 ] - HttpSession supported: false 13:12:14.726 [INFO ] [sphere.cpr.AtmosphereFramework:993 ] - Atmosphere is using DefaultAtmosphereObjectFactory for dependency injection and object creation 13:12:14.727 [INFO ] [sphere.cpr.AtmosphereFramework:994 ] - Atmosphere is using async support: org.atmosphere.container.JettyAsyncSupportWithWebSocket running under container: jetty/8.1.3.v20120522 with WebSocket enabled. 13:12:14.729 [INFO ] [sphere.cpr.AtmosphereFramework:996 ] - Atmosphere Framework 2.2.5 started. 13:12:14.730 [INFO ] [sphere.cpr.AtmosphereFramework:998 ] -

For Atmosphere Framework Commercial Support, visit 
http://www.async-io.org/ or send an email to support@async-io.org

13:12:14.731 [INFO ] [penhab.io.rest.RESTApplication:144 ] - Started REST API at /rest 13:12:14.732 [DEBUG] [o.o.i.s.i.DiscoveryServiceImpl:66 ] - Registering new service _openhab-server._tcp.local. at port 8080 13:12:15.980 [INFO ] [sphere.cpr.AtmosphereFramework:1053 ] - Latest version of Atmosphere's JavaScript Client 2.2.12 13:12:15.981 [INFO ] [sphere.cpr.AtmosphereFramework:1060 ] -

Atmosphere Framework Updates
Minor available (bugs fixes): 2.2.8
Major available (new features): 2.4.1

13:12:18.542 [DEBUG] [o.o.i.s.i.DiscoveryServiceImpl:66 ] - Registering new service _openhab-server-ssl._tcp.local. at port 8443 13:12:19.775 [INFO ] [c.internal.ModelRepositoryImpl:80 ] - Loading model 'demo.sitemap' 13:12:20.263 [INFO ] [c.internal.ModelRepositoryImpl:80 ] - Loading model 'demo.script' 13:12:20.508 [INFO ] [c.internal.ModelRepositoryImpl:80 ] - Loading model 'demo.items' 13:12:20.633 [DEBUG] [i.internal.GenericItemProvider:154 ] - Processing binding configs for items from model 'demo.items' 13:12:20.645 [DEBUG] [i.internal.GenericItemProvider:133 ] - Read items from model 'demo.items' 13:12:21.490 [INFO ] [.o.u.w.i.servlet.WebAppServlet:79 ] - Started Classic UI at /openhab.app 13:12:22.166 [DEBUG] [.r.internal.RuleModelActivator:42 ] - Registered 'rules' configuration parser 13:12:22.184 [DEBUG] [m.r.internal.engine.RuleEngine:77 ] - Started rule engine 13:12:30.752 [INFO ] [c.internal.ModelRepositoryImpl:80 ] - Loading model 'demo.rules' 13:12:31.073 [DEBUG] [.r.i.engine.RuleTriggerManager:438 ] - Scheduled rule Set random room temperatures with cron expression 0 0/5 * * * ? 13:12:31.075 [DEBUG] [.r.i.engine.RuleTriggerManager:438 ] - Scheduled rule Update max and min temperatures with cron expression 0 0 0 * * ? 13:12:31.078 [DEBUG] [.r.i.engine.RuleTriggerManager:438 ] - Scheduled rule Persistence Demo with cron expression 0 * * * * ? 13:12:31.089 [DEBUG] [m.r.internal.engine.RuleEngine:264 ] - Executing startup rule 'Initialize light states' 13:12:31.678 [DEBUG] [riptExtensionClassNameProvider:63 ] - Script actions have changed: TransformationActionService, PingActionService, HTTPActionService, ExecActionService, AudioActionService, 13:12:32.568 [ERROR] [m.r.internal.engine.RuleEngine:278 ] - Error during the execution of startup rule 'Initialize light states': Could not invoke method: org.openhab.model.script.actions.BusEvent.postUpdate(org.openhab.core.items.Item,java.lang.Number) on instance: null 13:12:32.569 [DEBUG] [m.r.internal.engine.RuleEngine:264 ] - Executing startup rule 'Initialize heating states' 13:12:32.750 [ERROR] [m.r.internal.engine.RuleEngine:278 ] - Error during the execution of startup rule 'Initialize heating states': Could not invoke method: org.openhab.model.script.actions.BusEvent.postUpdate(org.openhab.core.items.Item,java.lang.Number) on instance: null 13:12:32.751 [DEBUG] [m.r.internal.engine.RuleEngine:264 ] - Executing startup rule 'Initialize contact states' 13:12:32.975 [ERROR] [m.r.internal.engine.RuleEngine:278 ] - Error during the execution of startup rule 'Initialize contact states': Could not invoke method: org.openhab.model.script.actions.BusEvent.postUpdate(org.openhab.core.items.Item,java.lang.Number) on instance: null 13:12:32.979 [DEBUG] [m.r.internal.engine.RuleEngine:264 ] - Executing startup rule 'Initialize Location' 13:12:33.033 [DEBUG] [m.r.internal.engine.RuleEngine:264 ] - Executing startup rule 'Set random room temperatures' 13:12:33.040 [INFO ] [runtime.busevents :26 ] - DemoLocation state updated to 52.52°N, 13.40°W, 0.00 m 13:12:33.292 [INFO ] [runtime.busevents :26 ] - Temperature_GF_Corridor state updated to 18.10000000 13:12:33.300 [INFO ] [runtime.busevents :26 ] - Temperature_GF_Toilet state updated to 19.10000000 13:12:33.303 [INFO ] [runtime.busevents :26 ] - Temperature_GF_Living state updated to 19.30000000 13:12:33.309 [INFO ] [runtime.busevents :26 ] - Temperature_GF_Kitchen state updated to 19.10000000 13:12:33.313 [INFO ] [runtime.busevents :26 ] - Temperature_FF_Bath state updated to 19.40000000 13:12:33.317 [INFO ] [runtime.busevents :26 ] - Temperature_FF_Office state updated to 19.40000000 13:12:33.334 [INFO ] [runtime.busevents :26 ] - Temperature_FF_Child state updated to 18.90000000 13:12:33.338 [INFO ] [runtime.busevents :26 ] - Temperature_FF_Bed state updated to 17.60000000 13:12:33.340 [DEBUG] [m.r.internal.engine.RuleEngine:264 ] - Executing startup rule 'Update max and min temperatures' 13:12:33.569 [WARN ] [.o.c.p.e.PersistenceExtensions:711 ] - There is no queryable persistence service registered with the name 'rrd4j' 13:12:33.571 [ERROR] [m.r.internal.engine.RuleEngine:278 ] - Error during the execution of startup rule 'Update max and min temperatures': cannot invoke method public abstract org.openhab.core.types.State org.openhab.core.persistence.HistoricItem.getState() on null 13:12:33.620 [WARN ] [t.i.s.MapTransformationService:67 ] - Could not find a mapping for '-' in the file 'en.map'. 13:12:33.622 [WARN ] [t.i.s.MapTransformationService:67 ] - Could not find a mapping for '-' in the file 'en.map'. 13:12:37.114 [WARN ] [t.i.s.MapTransformationService:67 ] - Could not find a mapping for '-' in the file 'en.map'. 13:12:47.246 [WARN ] [t.i.s.MapTransformationService:67 ] - Could not find a mapping for '-' in the file 'en.map'. 13:12:47.248 [WARN ] [t.i.s.MapTransformationService:67 ] - Could not find a mapping for '-' in the file 'en.map'. 13:13:00.013 [DEBUG] [.o.m.r.i.engine.ExecuteRuleJob:53 ] - Executing scheduled rule 'Persistence Demo' 13:13:00.044 [WARN ] [.o.c.p.e.PersistenceExtensions:711 ] - There is no queryable persistence service registered with the name 'rrd4j' 13:13:00.045 [WARN ] [.o.c.p.e.PersistenceExtensions:131 ] - There is no queryable persistence service registered with the name 'rrd4j' 13:14:00.002 [DEBUG] [.o.m.r.i.engine.ExecuteRuleJob:53 ] - Executing scheduled rule 'Persistence Demo' 13:14:00.005 [WARN ] [.o.c.p.e.PersistenceExtensions:711 ] - There is no queryable persistence service registered with the name 'rrd4j' 13:14:00.005 [WARN ] [.o.c.p.e.PersistenceExtensions:131 ] - There is no queryable persistence service registered with the name 'rrd4j' 13:14:14.965 [WARN ] [t.i.s.MapTransformationService:67 ] - Could not find a mapping for '-' in the file 'en.map'. 13:14:14.966 [WARN ] [t.i.s.MapTransformationService:67 ] - Could not find a mapping for '-' in the file 'en.map'. 13:14:30.753 [WARN ] [t.i.s.MapTransformationService:67 ] - Could not find a mapping for '-' in the file 'en.map'. 13:15:00.003 [DEBUG] [.o.m.r.i.engine.ExecuteRuleJob:53 ] - Executing scheduled rule 'Persistence Demo' 13:15:00.003 [DEBUG] [.o.m.r.i.engine.ExecuteRuleJob:53 ] - Executing scheduled rule 'Set random room temperatures' 13:15:00.006 [WARN ] [.o.c.p.e.PersistenceExtensions:711 ] - There is no queryable persistence service registered with the name 'rrd4j' 13:15:00.006 [WARN ] [.o.c.p.e.PersistenceExtensions:131 ] - There is no queryable persistence service registered with the name 'rrd4j' 13:15:00.008 [INFO ] [runtime.busevents :26 ] - Temperature_GF_Corridor state updated to 20.50000000 13:15:00.012 [INFO ] [runtime.busevents :26 ] - Temperature_GF_Toilet state updated to 21.50000000 13:15:00.016 [INFO ] [runtime.busevents :26 ] - Temperature_GF_Living state updated to 20.90000000 13:15:00.016 [INFO ] [runtime.busevents :26 ] - Temperature_GF_Kitchen state updated to 21.80000000 13:15:00.020 [INFO ] [runtime.busevents :26 ] - Temperature_FF_Bath state updated to 20.00000000 13:15:00.022 [INFO ] [runtime.busevents :26 ] - Temperature_FF_Office state updated to 20.70000000 13:15:00.024 [INFO ] [runtime.busevents :26 ] - Temperature_FF_Child state updated to 18.60000000 13:15:00.029 [INFO ] [runtime.busevents :26 ] - Temperature_FF_Bed state updated to 19.70000000 13:15:00.032 [WARN ] [t.i.s.MapTransformationService:67 ] - Could not find a mapping for '-' in the file 'en.map'.

Thanks.

kirantpatil commented 8 years ago

The solution from this google group worked for me as well. https://groups.google.com/forum/#!msg/openhab/hGnsvgcxgDw/iiOSAeZF8MMJ

The solution is below.

I managed to get permanently rid of the errormessages by changing :

    Heating?.members.forEach(heating|
        postUpdate(heating, if(Math::random > 0.8) ON else OFF)

to Heating?.members.forEach(heatingelement | heatingelement.postUpdate( if(Math::random > 0.8) ON else OFF)