9037568
commented
7 years ago If you could provide a debug log, that would be useful.
Closed MichaelGottschlich closed 6 years ago
9037568
commented
7 years ago If you could provide a debug log, that would be useful.
MichaelGottschlich
commented
7 years ago Launching the openHAB runtime... OpenJDK 64-Bit Server VM warning: If the number of processors is expected to increase from one, then you should configure the number of parallel GC threads appropriately using -XX:ParallelGCThreads=N Listening for transport dt_socket at address: 5005
__ _____ _____ __ / / / / | / ) / \/ \/ _ \/ \/ /_/ / /| | / | / // / // / / / / / / |/ // / __/ ._/__// /// /// |/____/ /_/ 2.0.0-SNAPSHOT Build #644
Hit '
openhab> log:tail
11:01:47.479 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at /start
11:01:47.968 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app
11:01:48.056 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /ui
11:01:48.190 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
Exception in thread "KNXnet/IP receiver" java.lang.ArrayIndexOutOfBoundsException: 128
at tuwien.auto.calimero.cemi.CEMILDataEx.putAddInfo(CEMILDataEx.java:568)
at tuwien.auto.calimero.cemi.CEMILDataEx.readAddInfo(CEMILDataEx.java:484)
at tuwien.auto.calimero.cemi.CEMILDataEx.
userdata/logs/openhab.log:
2016-12-19 11:01:47.479 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at /start 2016-12-19 11:01:47.968 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app 2016-12-19 11:01:48.056 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /ui 2016-12-19 11:01:48.190 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel 2016-12-19 11:01:49.686 [INFO ] [nx.internal.connection.KNXConnection] - Established connection to KNX bus on 192.168.0.30:3671 in mode TUNNEL. 2016-12-19 11:02:49.640 [ERROR] [tuwien.auto.calimero ] - KNXnet/IP Tunneling 192.168.0.30:3671: send disconnect failed java.net.SocketException: Socket is closed at java.net.DatagramSocket.send(DatagramSocket.java:658)[:1.8.0_111] at tuwien.auto.calimero.knxnetip.ConnectionBase.close(ConnectionBase.java:463)[191:org.openhab.binding.knx:1.9.0.201612160210] at tuwien.auto.calimero.knxnetip.ClientConnection$HeartbeatMonitor.run(ClientConnection.java:432)[191:org.openhab.binding.knx:1.9.0.201612160210] 2016-12-19 11:02:49.642 [WARN ] [nx.internal.connection.KNXConnection] - KNX link has been lost (reason: heartbeat communication failure on object tunneling link link (closed) 192.168.0.30:3671 TP1 medium, device 1.0.255, hopcount 6) 2016-12-19 11:02:49.664 [ERROR] [tuwien.auto.calimero ] - KNXnet/IP Tunneling 192.168.0.30:3671: close connection - heartbeat communication failure java.net.SocketException: Socket is closed at java.net.DatagramSocket.send(DatagramSocket.java:658)[:1.8.0_111] at tuwien.auto.calimero.knxnetip.ClientConnection$HeartbeatMonitor.run(ClientConnection.java:409)[191:org.openhab.binding.knx:1.9.0.201612160210] 2016-12-19 11:02:49.665 [ERROR] [.binding.knx.internal.bus.KNXBinding] - Received detach Event. 2016-12-19 11:05:14.738 [INFO ] [panel.internal.HABPanelDashboardTile] - Stopped HABPanel 2016-12-19 11:05:14.749 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Stopped Paper UI 2016-12-19 11:05:14.803 [INFO ] [basic.internal.servlet.WebAppServlet] - Stopped Basic UI 2016-12-19 11:05:14.845 [INFO ] [.dashboard.internal.DashboardService] - Stopped dashboard
J-N-K
commented
7 years ago Just from looking at the latest changes in Calimero;
https://github.com/calimero-project/calimero-core/commit/2a31d994728975ef1531c5dba818e3ec6c1423b8
changes the array size excatly where the fault occurs.
watou
commented
7 years ago Well spotted, @J-N-K! @lewie would it make sense to update the binding to the official 2.3 Calimero Core release and check for regressions?
MichaelGottschlich
commented
7 years ago Hello, is there a problem to update lib?
Give a manual to build Runtime Distribution package?
jochenkluger
commented
7 years ago Hi, any news on this one?
MichaelGottschlich
commented
7 years ago Hi,
i had rebuld addon for openhabe1.8.3 with new libary of Calimero(v2.3). This has fix java.lang.ArrayIndexOutOfBoundsException.
My next problem is tuwien.auto.calimero.exception.KNXTimeoutException if i send an comand to knx bus. Is the same Problem KNXCoreTypeMapperTest.java:1528?
LOG:
./start_debug.sh
Launching the openHAB runtime in debug mode...
Listening for transport dt_socket at address: 8001
osgi> 12:03:12.952 [DEBUG] [.s.internal.SchedulerActivator:36 ] - Scheduler has been started.
12:03:13.078 [INFO ] [uartz.impl.StdSchedulerFactory:1175 ] - Using default implementation for ThreadExecutor
12:03:13.185 [INFO ] [rtz.core.SchedulerSignalerImpl:61 ] - Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl
12:03:13.187 [INFO ] [rg.quartz.core.QuartzScheduler:243 ] - Quartz Scheduler v.2.1.7 created.
12:03:13.192 [INFO ] [org.quartz.simpl.RAMJobStore :154 ] - RAMJobStore initialized.
12:03:13.197 [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.
12:03:13.198 [INFO ] [uartz.impl.StdSchedulerFactory:1324 ] - Quartz scheduler 'openHAB-job-scheduler' initialized from specified file: './etc/quartz.properties'
12:03:13.200 [INFO ] [uartz.impl.StdSchedulerFactory:1328 ] - Quartz scheduler version: 2.1.7
12:03:13.202 [INFO ] [rg.quartz.core.QuartzScheduler:534 ] - Scheduler openHAB-job-scheduler_$_NON_CLUSTERED started.
12:03:13.215 [DEBUG] [o.config.core.ConfigDispatcher:146 ] - Processing openHAB default configuration file '/root/configurations/openhab_default.cfg'.
12:03:13.503 [DEBUG] [o.config.core.ConfigDispatcher:168 ] - Processing openHAB main configuration file '/root/configurations/openhab.cfg'.
12:03:13.806 [DEBUG] [.o.core.internal.CoreActivator:93 ] - UUID file already exists at '/root/webapps/static/uuid' with content 'e8cffac9-f386-4689-9f33-20887d295d04'
12:03:13.813 [DEBUG] [.o.core.internal.CoreActivator:115 ] - Created file '/root/webapps/static/version' with content '1.8.3'
12:03:13.815 [INFO ] [.o.core.internal.CoreActivator:61 ] - openHAB runtime has been started (v1.8.3).
12:03:13.889 [DEBUG] [a.internal.AutoUpdateActivator:31 ] - AutoUpdate binding has been started.
12:03:16.592 [DEBUG] [.p.i.PersistenceModelActivator:23 ] - Registered 'persistence' configuration parser
12:03:16.637 [DEBUG] [.c.t.i.TransformationActivator:38 ] - Transformation Service has been started.
12:03:16.735 [DEBUG] [m.internal.MultimediaActivator:34 ] - Multimedia I/O bundle has been started.
12:03:16.788 [DEBUG] [.s.i.DiscoveryServiceActivator:27 ] - Discovery service has been started.
12:03:16.802 [INFO ] [o.o.i.s.i.DiscoveryServiceImpl:93 ] - mDNS service has been started
12:03:16.831 [DEBUG] [.io.transport.mqtt.MqttService:123 ] - Starting MQTT Service...
12:03:16.897 [INFO ] [o.o.i.s.i.DiscoveryServiceImpl:48 ] - Service Discovery initialization completed (bound to address: 192.168.0.3).
12:03:17.135 [DEBUG] [.i.internal.ItemModelActivator:24 ] - Registered 'item' configuration parser
12:03:17.405 [DEBUG] [o.o.c.i.items.ItemRegistryImpl:137 ] - Item provider 'GenericItemProvider' has been added.
12:03:19.353 [DEBUG] [.o.m.s.i.SitemapModelActivator:23 ] - Registered 'sitemap' configuration parser
12:03:19.582 [DEBUG] [io.rest.internal.RESTActivator:33 ] - REST API has been started.
12:03:19.737 [INFO ] [org.atmosphere.util.IOUtils :370 ] - META-INF/services/org.atmosphere.cpr.AtmosphereFramework not found in class loader
12:03:19.814 [INFO ] [sphere.cpr.AtmosphereFramework:2601 ] - Atmosphere is using org.atmosphere.cpr.DefaultAnnotationProcessor for processing annotation
12:03:19.817 [INFO ] [cpr.DefaultAnnotationProcessor:138 ] - AnnotationProcessor class org.atmosphere.cpr.DefaultAnnotationProcessor$BytecodeBasedAnnotationProcessor being used
12:03:19.864 [WARN ] [cpr.DefaultAnnotationProcessor:178 ] - Unable to detect annotations. Application may fail to deploy.
12:03:19.956 [INFO ] [sphere.cpr.AtmosphereFramework:1891 ] - Auto detecting atmosphere handlers /WEB-INF/classes/
12:03:20.006 [INFO ] [sphere.cpr.AtmosphereFramework:639 ] - Installed AtmosphereHandler org.atmosphere.handler.ReflectorServletProcessor mapped to context-path /* and Broadcaster Class org.atmosphere.jersey.JerseyBroadcaster
12:03:20.007 [INFO ] [sphere.cpr.AtmosphereFramework:1945 ] - Auto detecting WebSocketHandler in /WEB-INF/classes/
12:03:20.010 [INFO ] [sphere.cpr.AtmosphereFramework:1602 ] - Installed WebSocketProtocol org.atmosphere.websocket.protocol.SimpleHttpProtocol
12:03:20.090 [INFO ] [.a.h.ReflectorServletProcessor:103 ] - Installing Servlet com.sun.jersey.spi.container.servlet.ServletContainer
12:03:20.418 [INFO ] [c.s.j.s.i.a.WebApplicationImpl:815 ] - Initiating Jersey application, version 'Jersey: 1.18.1 02/19/2014 03:28 AM'
12:03:20.424 [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
12:03:20.568 [INFO ] [j.s.i.a.DeferredResourceConfig:101 ] - Instantiated the Application class org.openhab.io.rest.RESTApplication
12:03:22.717 [INFO ] [sphere.cpr.AtmosphereFramework:2435 ] - AtmosphereInterceptor CORS Interceptor Support will always be executed first
12:03:22.719 [INFO ] [sphere.cpr.AtmosphereFramework:2404 ] - Installed AtmosphereInterceptor CORS Interceptor Support with priority FIRST_BEFORE_DEFAULT
12:03:22.721 [INFO ] [sphere.cpr.AtmosphereFramework:2404 ] - Installed AtmosphereInterceptor Default Response's Headers Interceptor with priority AFTER_DEFAULT
12:03:22.725 [INFO ] [sphere.cpr.AtmosphereFramework:2404 ] - Installed AtmosphereInterceptor Android Interceptor Support with priority AFTER_DEFAULT
12:03:22.729 [INFO ] [sphere.cpr.AtmosphereFramework:2404 ] - Installed AtmosphereInterceptor SSE Interceptor Support with priority AFTER_DEFAULT
12:03:22.731 [INFO ] [sphere.cpr.AtmosphereFramework:2404 ] - Installed AtmosphereInterceptor JSONP Interceptor Support with priority AFTER_DEFAULT
12:03:22.735 [INFO ] [sphere.cpr.AtmosphereFramework:2404 ] - Installed AtmosphereInterceptor Atmosphere JavaScript Protocol with priority AFTER_DEFAULT
12:03:22.737 [INFO ] [sphere.cpr.AtmosphereFramework:2404 ] - Installed AtmosphereInterceptor Browser disconnection detection with priority AFTER_DEFAULT
12:03:22.747 [INFO ] [sphere.cpr.AtmosphereFramework:935 ] - Using EndpointMapper class org.atmosphere.util.DefaultEndpointMapper
12:03:22.750 [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
12:03:22.751 [INFO ] [sphere.cpr.AtmosphereFramework:949 ] - Default Broadcaster Class: org.atmosphere.jersey.JerseyBroadcaster
12:03:22.752 [INFO ] [sphere.cpr.AtmosphereFramework:950 ] - Broadcaster Polling Wait Time 100
12:03:22.753 [INFO ] [sphere.cpr.AtmosphereFramework:951 ] - Shared ExecutorService supported: true
12:03:22.754 [INFO ] [sphere.cpr.AtmosphereFramework:958 ] - Messaging Thread Pool Size: 10
12:03:22.755 [INFO ] [sphere.cpr.AtmosphereFramework:968 ] - Async I/O Thread Pool Size: 10
12:03:22.756 [INFO ] [sphere.cpr.AtmosphereFramework:979 ] - Using BroadcasterFactory: org.atmosphere.cpr.DefaultBroadcasterFactory
12:03:22.757 [INFO ] [sphere.cpr.AtmosphereFramework:980 ] - Using WebSocketProcessor: org.atmosphere.websocket.DefaultWebSocketProcessor
12:03:22.759 [INFO ] [sphere.cpr.AtmosphereFramework:990 ] - Invoke AtmosphereInterceptor on WebSocket message true
12:03:22.760 [INFO ] [sphere.cpr.AtmosphereFramework:991 ] - HttpSession supported: false
12:03:22.761 [INFO ] [sphere.cpr.AtmosphereFramework:993 ] - Atmosphere is using DefaultAtmosphereObjectFactory for dependency injection and object creation
12:03:22.763 [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.
12:03:22.766 [INFO ] [sphere.cpr.AtmosphereFramework:996 ] - Atmosphere Framework 2.2.5 started.
12:03:22.768 [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
12:03:22.770 [INFO ] [penhab.io.rest.RESTApplication:144 ] - Started REST API at /rest
12:03:22.773 [DEBUG] [o.o.i.s.i.DiscoveryServiceImpl:66 ] - Registering new service _openhab-server._tcp.local. at port 8080
12:03:25.426 [DEBUG] [o.o.i.s.i.DiscoveryServiceImpl:66 ] - Registering new service _openhab-server-ssl._tcp.local. at port 8443
12:03:25.825 [INFO ] [c.internal.ModelRepositoryImpl:80 ] - Loading model 'TestWand.sitemap'
12:03:26.332 [INFO ] [c.internal.ModelRepositoryImpl:80 ] - Loading model 'testWand.items'
12:03:26.418 [DEBUG] [i.internal.GenericItemProvider:154 ] - Processing binding configs for items from model 'testWand.items'
12:03:26.426 [DEBUG] [i.internal.GenericItemProvider:133 ] - Read items from model 'testWand.items'
12:03:28.248 [INFO ] [.o.u.w.i.servlet.WebAppServlet:80 ] - Started Classic UI at /classicui/openhab.app
12:03:28.924 [DEBUG] [.r.internal.RuleModelActivator:42 ] - Registered 'rules' configuration parser
12:03:28.962 [DEBUG] [m.r.internal.engine.RuleEngine:77 ] - Started rule engine
12:03:31.576 [DEBUG] [.o.b.knx.internal.KNXActivator:32 ] - KNX binding has been started.
12:03:31.707 [DEBUG] [i.internal.GenericItemProvider:341 ] - Start processing binding configuration of Item 'Lampe (Type=DimmerItem, State=Uninitialized)' with 'KNXGenericBindingProvider' reader.
12:03:31.716 [TRACE] [.o.b.k.i.dpt.KNXCoreTypeMapper:521 ] - toTypeClass looking for dptId = 1.001
12:03:31.723 [TRACE] [.o.b.k.i.dpt.KNXCoreTypeMapper:521 ] - toTypeClass looking for dptId = 3.007
12:03:31.725 [DEBUG] [i.internal.GenericItemProvider:341 ] - Start processing binding configuration of Item 'Jalousie (Type=RollershutterItem, State=Uninitialized)' with 'KNXGenericBindingProvider' reader.
12:03:31.726 [TRACE] [.o.b.k.i.dpt.KNXCoreTypeMapper:521 ] - toTypeClass looking for dptId = 1.008
12:03:31.727 [TRACE] [.o.b.k.i.dpt.KNXCoreTypeMapper:521 ] - toTypeClass looking for dptId = 1.010
12:03:31.742 [TRACE] [.b.knx.internal.bus.KNXBinding:335 ] - allBindingsChanged() msg received.
12:03:31.747 [DEBUG] [.b.knx.internal.bus.KNXBinding:76 ] - Calimero library version 2.3
12:03:31.748 [TRACE] [.b.knx.internal.bus.KNXBinding:77 ] - KNXBinding: activating
12:03:31.757 [TRACE] [.k.i.bus.KNXBusReaderScheduler:50 ] - Starting auto refresh scheduler
12:03:31.758 [DEBUG] [.k.i.bus.KNXBusReaderScheduler:52 ] - Starting reader task.
12:03:31.764 [DEBUG] [.k.i.bus.KNXBusReaderScheduler:56 ] - Starting schedule executor.
12:03:31.764 [DEBUG] [.KNXBindingDatapointReaderTask:60 ] - Autorefresh: Waiting for new item in reader queue
12:03:31.772 [DEBUG] [b.k.i.connection.KNXConnection:329 ] - KNXBinding configuration present. Setting up KNX bus connection.
12:03:31.774 [DEBUG] [b.k.i.connection.KNXConnection:447 ] - Not connected yet. Trying to connect.
12:03:31.816 [DEBUG] [sqlPersistenceServiceActivator:31 ] - mySQL persistence bundle has been started.
12:03:31.825 [INFO ] [tuwien.auto.calimero :51 ] - KNXnet/IP Tunneling 192.168.0.2:3671: establish connection from /192.168.0.3:60802 to /192.168.0.2:3671
12:03:31.840 [DEBUG] [tuwien.auto.calimero :53 ] - KNXnet/IP Tunneling 192.168.0.2:3671: wait for connect response from /192.168.0.2:3671 ...
12:03:31.850 [DEBUG] [.p.m.i.MysqlPersistenceService:519 ] - mySQL: Attempting to connect to database jdbc:mysql://192.168.0.4:3306/openhab
12:03:31.852 [DEBUG] [tuwien.auto.calimero :53 ] - KNXnet/IP Tunneling 192.168.0.2:3671: using server-assigned data endpoint /192.168.0.2:3671
12:03:31.855 [INFO ] [tuwien.auto.calimero :51 ] - KNXnet/IP Tunneling 192.168.0.2:3671: connection established
12:03:31.864 [INFO ] [b.k.i.connection.KNXConnection:238 ] - Established connection to KNX bus on 192.168.0.2:3671 in mode TUNNEL.
12:03:31.865 [TRACE] [.b.knx.internal.bus.KNXBinding:364 ] - connectionEstablished() msg received. Initializing readable DPs.
12:03:31.878 [DEBUG] [b.k.i.connection.KNXConnection:457 ] - Success: connected.
12:03:32.626 [DEBUG] [.p.m.i.MysqlPersistenceService:522 ] - mySQL: Connected to database jdbc:mysql://192.168.0.4:3306/openhab
12:03:32.652 [DEBUG] [.p.m.i.MysqlPersistenceService:195 ] - mySQL configuration complete.
12:03:32.658 [DEBUG] [.p.internal.PersistenceManager:146 ] - Initializing mysql persistence service.
12:03:32.666 [DEBUG] [c.internal.ModelRepositoryImpl:64 ] - Configuration model 'mysql.persist' can not be found
12:04:31.857 [DEBUG] [tuwien.auto.calimero :53 ] - KNXnet/IP Tunneling 192.168.0.2:3671: sending connection state request, attempt 1
12:05:31.861 [DEBUG] [tuwien.auto.calimero :53 ] - KNXnet/IP Tunneling 192.168.0.2:3671: sending connection state request, attempt 1
12:06:31.862 [DEBUG] [tuwien.auto.calimero :53 ] - KNXnet/IP Tunneling 192.168.0.2:3671: sending connection state request, attempt 1
12:07:16.606 [INFO ] [c.internal.ModelRepositoryImpl:80 ] - Loading model 'mysql.persist'
12:07:31.864 [DEBUG] [tuwien.auto.calimero :53 ] - KNXnet/IP Tunneling 192.168.0.2:3671: sending connection state request, attempt 1
12:08:26.673 [INFO ] [c.internal.ModelRepositoryImpl:98 ] - Refreshing model 'mysql.persist'
12:08:26.810 [DEBUG] [.p.m.i.MysqlPersistenceService:613 ] - mySQL query: item is Lampe
12:08:26.811 [ERROR] [.p.m.i.MysqlPersistenceService:632 ] - mySQL: Unable to find table for query 'Lampe'.
12:08:26.816 [DEBUG] [.p.m.i.MysqlPersistenceService:613 ] - mySQL query: item is Jalousie
12:08:26.817 [ERROR] [.p.m.i.MysqlPersistenceService:632 ] - mySQL: Unable to find table for query 'Jalousie'.
12:08:26.873 [DEBUG] [.p.internal.PersistenceManager:428 ] - Scheduled strategy mysql.everyHour with cron expression 0 0 * * * ?
12:08:26.878 [DEBUG] [.p.internal.PersistenceManager:428 ] - Scheduled strategy mysql.everyDay with cron expression 0 0 0 * * ?
12:08:31.865 [DEBUG] [tuwien.auto.calimero :53 ] - KNXnet/IP Tunneling 192.168.0.2:3671: sending connection state request, attempt 1
12:09:22.824 [INFO ] [runtime.busevents :22 ] - Lampe received command OFF
12:09:22.848 [DEBUG] [.p.m.i.MysqlPersistenceService:266 ] - mySQL: no Table found for itemName=Lampe get:null
12:09:22.908 [DEBUG] [.p.m.i.MysqlPersistenceService:288 ] - mySQL: new item Lampe is Item1
12:09:22.910 [DEBUG] [.p.m.i.MysqlPersistenceService:248 ] - mySQL: Use ItemType DIMMERITEM (TINYINT) for Item DIMMERITEM
12:09:22.912 [DEBUG] [.p.m.i.MysqlPersistenceService:313 ] - mySQL: query: CREATE TABLE Item1 (Time DATETIME, Value TINYINT, PRIMARY KEY(Time));
12:09:22.919 [DEBUG] [.p.m.i.MysqlPersistenceService:319 ] - mySQL: Table created for item 'Lampe' with datatype TINYINT in SQL database.
12:09:22.927 [DEBUG] [.p.m.i.MysqlPersistenceService:455 ] - mySQL: Stored item 'Lampe' as '0'[0] in SQL database at 2017-05-08 12:09:22.921.
12:09:22.928 [DEBUG] [.p.m.i.MysqlPersistenceService:457 ] - mySQL: query: INSERT INTO Item1 (TIME, VALUE) VALUES(NOW(),?) ON DUPLICATE KEY UPDATE VALUE=?;
12:09:22.932 [TRACE] [.b.knx.internal.bus.KNXBinding:110 ] - Received command (item='Lampe', command='OFF')
12:09:22.937 [TRACE] [.o.b.k.i.dpt.KNXCoreTypeMapper:521 ] - toTypeClass looking for dptId = 1.001
12:09:22.938 [TRACE] [.o.b.k.i.dpt.KNXCoreTypeMapper:521 ] - toTypeClass looking for dptId = 3.007
12:09:22.940 [TRACE] [.b.knx.internal.bus.KNXBinding:489 ] - found 1 compatible datapoints for item Lampe (org.openhab.core.library.types.OnOffType)
12:09:22.946 [DEBUG] [tuwien.auto.calimero :53 ] - DPTXlator: Boolean (main type 1) loaded
12:09:22.948 [DEBUG] [tuwien.auto.calimero :53 ] - DPTXlator: Boolean controlled (main type 2) loaded
12:09:22.949 [DEBUG] [tuwien.auto.calimero :53 ] - DPTXlator: 3 Bit controlled (main type 3) loaded
12:09:22.950 [DEBUG] [tuwien.auto.calimero :53 ] - DPTXlator: 8 Bit unsigned value (main type 5) loaded
12:09:22.951 [DEBUG] [tuwien.auto.calimero :53 ] - DPTXlator: 8 Bit signed value (main type 6) loaded
12:09:22.952 [DEBUG] [tuwien.auto.calimero :53 ] - DPTXlator: 2 octet unsigned value (main type 7) loaded
12:09:22.953 [DEBUG] [tuwien.auto.calimero :53 ] - DPTXlator: 2 octet float value (main type 9) loaded
12:09:22.954 [DEBUG] [tuwien.auto.calimero :53 ] - DPTXlator: Time (main type 10) loaded
12:09:22.955 [DEBUG] [tuwien.auto.calimero :53 ] - DPTXlator: Date (main type 11) loaded
12:09:22.956 [DEBUG] [tuwien.auto.calimero :53 ] - DPTXlator: 4 octet unsigned value (main type 12) loaded
12:09:22.958 [DEBUG] [tuwien.auto.calimero :53 ] - DPTXlator: 4 octet signed value (main type 13) loaded
12:09:22.959 [DEBUG] [tuwien.auto.calimero :53 ] - DPTXlator: 4 octet float value (main type 14) loaded
12:09:22.960 [DEBUG] [tuwien.auto.calimero :53 ] - DPTXlator: String (main type 16) loaded
12:09:22.961 [DEBUG] [tuwien.auto.calimero :53 ] - DPTXlator: Scene number (main type 17) loaded
12:09:22.962 [DEBUG] [tuwien.auto.calimero :53 ] - DPTXlator: Scene control (main type 18) loaded
12:09:22.963 [DEBUG] [tuwien.auto.calimero :53 ] - DPTXlator: Date with time (main type 19) loaded
12:09:22.963 [DEBUG] [tuwien.auto.calimero :53 ] - DPTXlator: UTF-8 string (main type 28) loaded
12:09:22.966 [DEBUG] [tuwien.auto.calimero :53 ] - DPTXlator: 64 Bit signed value (main type 29) loaded
12:09:22.967 [DEBUG] [tuwien.auto.calimero :53 ] - DPTXlator: RGB color value (main type 232) loaded
12:09:22.970 [INFO ] [tuwien.auto.calimero :51 ] - calimero.link.192.168.0.2:3671: send message to 2/1/1, wait for confirmation
12:09:22.974 [DEBUG] [tuwien.auto.calimero :53 ] - calimero.link.192.168.0.2:3671: cEMI L-Data.req from 1.1.1 to 2/1/1, low priority hop count 6 repeat tpdu 00 80
12:09:22.979 [DEBUG] [tuwien.auto.calimero :53 ] - KNXnet/IP Tunneling 192.168.0.2:3671: sending cEMI frame seq 0, wait for cEMI.con, attempt 1 (channel 3) 06 10 04 20 00 15 04 03 00 00 11 00 bc e0 11 01 11 01 01 00 80
12:09:23.008 [DEBUG] [tuwien.auto.calimero :53 ] - KNXnet/IP Tunneling 192.168.0.2:3671: received cEMI L-Data.con with req 0
12:09:23.012 [DEBUG] [tuwien.auto.calimero :53 ] - calimero.link.192.168.0.2:3671: confirmation of 2/1/1
12:09:25.982 [WARN ] [.b.knx.internal.bus.KNXBinding:152 ] - Value 'OFF' could not be sent to the KNX bus using datapoint 'command DP 2/1/1 'Lampe', DPT main 0 id 1.001, low priority' - retrying one time: no confirmation reply received for L-Data.req from 1.1.1 to 2/1/1, low priority hop count 6 repeat tpdu 00 80
12:09:26.059 [WARN ] [tuwien.auto.calimero :49 ] - KNXnet/IP Tunneling 192.168.0.2:3671: response timeout waiting for confirmation
tuwien.auto.calimero.exception.KNXTimeoutException: no confirmation reply received for L-Data.req from 1.1.1 to 2/1/1, low priority hop count 6 repeat tpdu 00 80
at tuwien.auto.calimero.knxnetip.ClientConnection.doExtraBlockingModes(ClientConnection.java:239) ~[na:na]
at tuwien.auto.calimero.knxnetip.ConnectionBase.send(ConnectionBase.java:269) ~[na:na]
at tuwien.auto.calimero.knxnetip.KNXnetIPTunnel.send(KNXnetIPTunnel.java:149) ~[na:na]
at tuwien.auto.calimero.link.KNXNetworkLinkIP.onSend(KNXNetworkLinkIP.java:263) ~[na:na]
at tuwien.auto.calimero.link.AbstractLink.send(AbstractLink.java:304) ~[na:na]
at tuwien.auto.calimero.link.KNXNetworkLinkIP.sendRequestWait(KNXNetworkLinkIP.java:240) ~[na:na]
at tuwien.auto.calimero.process.ProcessCommunicatorImpl.write(ProcessCommunicatorImpl.java:466) ~[na:na]
at tuwien.auto.calimero.process.ProcessCommunicatorImpl.write(ProcessCommunicatorImpl.java:438) ~[na:na]
at org.openhab.binding.knx.internal.bus.KNXBinding.writeToKNX(KNXBinding.java:149) ~[na:na]
at org.openhab.binding.knx.internal.bus.KNXBinding.internalReceiveCommand(KNXBinding.java:112) ~[na:na]
at org.openhab.core.binding.AbstractBinding.receiveCommand(AbstractBinding.java:97) ~[na:na]
at org.openhab.core.events.AbstractEventSubscriber.handleEvent(AbstractEventSubscriber.java:42) ~[na:na]
at org.eclipse.equinox.internal.event.EventHandlerWrapper.handleEvent(EventHandlerWrapper.java:197) ~[na:na]
at org.eclipse.equinox.internal.event.EventHandlerTracker.dispatchEvent(EventHandlerTracker.java:197) ~[na:na]
at org.eclipse.equinox.internal.event.EventHandlerTracker.dispatchEvent(EventHandlerTracker.java:1) ~[na:na]
at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) ~[na:na]
at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) ~[na:na]
at org.eclipse.equinox.internal.event.EventAdminImpl.dispatchEvent(EventAdminImpl.java:135) ~[na:na]
at org.eclipse.equinox.internal.event.EventAdminImpl.sendEvent(EventAdminImpl.java:78) ~[na:na]
at org.eclipse.equinox.internal.event.EventComponent.sendEvent(EventComponent.java:39) ~[na:na]
at org.openhab.core.internal.events.EventPublisherImpl.sendCommand(EventPublisherImpl.java:56) ~[na:na]
at org.openhab.ui.webapp.internal.servlet.CmdServlet.service(CmdServlet.java:95) ~[na:na]
at org.eclipse.equinox.http.servlet.internal.ServletRegistration.service(ServletRegistration.java:61) ~[na:na]
at org.eclipse.equinox.http.servlet.internal.ProxyServlet.processAlias(ProxyServlet.java:128) ~[na:na]
at org.eclipse.equinox.http.servlet.internal.ProxyServlet.service(ProxyServlet.java:60) ~[na:na]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:848) ~[javax.servlet_3.0.0.v201112011016.jar:na]
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:598) ~[na:na]
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:486) ~[na:na]
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:231) ~[na:na]
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1065) ~[na:na]
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:413) ~[na:na]
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:192) ~[na:na]
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:999) ~[na:na]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117) ~[na:na]
at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:250) ~[na:na]
at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:149) ~[na:na]
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:111) ~[na:na]
at org.eclipse.jetty.server.Server.handle(Server.java:350) ~[na:na]
at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:454) ~[na:na]
at org.eclipse.jetty.server.AbstractHttpConnection.headerComplete(AbstractHttpConnection.java:890) ~[na:na]
at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.headerComplete(AbstractHttpConnection.java:944) ~[na:na]
at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:630) ~[na:na]
at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:230) ~[na:na]
at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:77) ~[na:na]
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:606) ~[na:na]
at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:46) ~[na:na]
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:603) ~[na:na]
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:538) ~[na:na]
at java.lang.Thread.run(Thread.java:745) ~[na:1.8.0_65]
12:09:26.062 [INFO ] [tuwien.auto.calimero :51 ] - calimero.link.192.168.0.2:3671: send message to 2/1/1, wait for confirmation
12:09:26.063 [DEBUG] [tuwien.auto.calimero :53 ] - calimero.link.192.168.0.2:3671: cEMI L-Data.req from 1.1.1 to 2/1/1, low priority hop count 6 repeat tpdu 00 80
12:09:26.063 [DEBUG] [tuwien.auto.calimero :53 ] - KNXnet/IP Tunneling 192.168.0.2:3671: sending cEMI frame seq 1, wait for cEMI.con, attempt 1 (channel 3) 06 10 04 20 00 15 04 03 01 00 11 00 bc e0 11 01 11 01 01 00 80
12:09:26.064 [DEBUG] [tuwien.auto.calimero :53 ] - KNXnet/IP Tunneling 192.168.0.2:3671: received cEMI L-Data.con with req 1
12:09:26.064 [DEBUG] [tuwien.auto.calimero :53 ] - calimero.link.192.168.0.2:3671: confirmation of 2/1/1
12:09:28.989 [ERROR] [.b.knx.internal.bus.KNXBinding:161 ] - Value 'OFF' could not be sent to the KNX bus using datapoint 'command DP 2/1/1 'Lampe', DPT main 0 id 1.001, low priority' - giving up after second try: no confirmation reply received for L-Data.req from 1.1.1 to 2/1/1, low priority hop count 6 repeat tpdu 00 80
12:09:29.107 [WARN ] [tuwien.auto.calimero :49 ] - KNXnet/IP Tunneling 192.168.0.2:3671: response timeout waiting for confirmation
tuwien.auto.calimero.exception.KNXTimeoutException: no confirmation reply received for L-Data.req from 1.1.1 to 2/1/1, low priority hop count 6 repeat tpdu 00 80
at tuwien.auto.calimero.knxnetip.ClientConnection.doExtraBlockingModes(ClientConnection.java:239) ~[na:na]
at tuwien.auto.calimero.knxnetip.ConnectionBase.send(ConnectionBase.java:269) ~[na:na]
at tuwien.auto.calimero.knxnetip.KNXnetIPTunnel.send(KNXnetIPTunnel.java:149) ~[na:na]
at tuwien.auto.calimero.link.KNXNetworkLinkIP.onSend(KNXNetworkLinkIP.java:263) ~[na:na]
at tuwien.auto.calimero.link.AbstractLink.send(AbstractLink.java:304) ~[na:na]
at tuwien.auto.calimero.link.KNXNetworkLinkIP.sendRequestWait(KNXNetworkLinkIP.java:240) ~[na:na]
at tuwien.auto.calimero.process.ProcessCommunicatorImpl.write(ProcessCommunicatorImpl.java:466) ~[na:na]
at tuwien.auto.calimero.process.ProcessCommunicatorImpl.write(ProcessCommunicatorImpl.java:438) ~[na:na]
at org.openhab.binding.knx.internal.bus.KNXBinding.writeToKNX(KNXBinding.java:158) ~[na:na]
at org.openhab.binding.knx.internal.bus.KNXBinding.internalReceiveCommand(KNXBinding.java:112) ~[na:na]
at org.openhab.core.binding.AbstractBinding.receiveCommand(AbstractBinding.java:97) ~[na:na]
at org.openhab.core.events.AbstractEventSubscriber.handleEvent(AbstractEventSubscriber.java:42) ~[na:na]
at org.eclipse.equinox.internal.event.EventHandlerWrapper.handleEvent(EventHandlerWrapper.java:197) ~[na:na]
at org.eclipse.equinox.internal.event.EventHandlerTracker.dispatchEvent(EventHandlerTracker.java:197) ~[na:na]
at org.eclipse.equinox.internal.event.EventHandlerTracker.dispatchEvent(EventHandlerTracker.java:1) ~[na:na]
at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) ~[na:na]
at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) ~[na:na]
at org.eclipse.equinox.internal.event.EventAdminImpl.dispatchEvent(EventAdminImpl.java:135) ~[na:na]
at org.eclipse.equinox.internal.event.EventAdminImpl.sendEvent(EventAdminImpl.java:78) ~[na:na]
at org.eclipse.equinox.internal.event.EventComponent.sendEvent(EventComponent.java:39) ~[na:na]
at org.openhab.core.internal.events.EventPublisherImpl.sendCommand(EventPublisherImpl.java:56) ~[na:na]
at org.openhab.ui.webapp.internal.servlet.CmdServlet.service(CmdServlet.java:95) ~[na:na]
at org.eclipse.equinox.http.servlet.internal.ServletRegistration.service(ServletRegistration.java:61) ~[na:na]
at org.eclipse.equinox.http.servlet.internal.ProxyServlet.processAlias(ProxyServlet.java:128) ~[na:na]
at org.eclipse.equinox.http.servlet.internal.ProxyServlet.service(ProxyServlet.java:60) ~[na:na]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:848) ~[javax.servlet_3.0.0.v201112011016.jar:na]
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:598) ~[na:na]
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:486) ~[na:na]
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:231) ~[na:na]
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1065) ~[na:na]
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:413) ~[na:na]
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:192) ~[na:na]
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:999) ~[na:na]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117) ~[na:na]
at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:250) ~[na:na]
at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:149) ~[na:na]
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:111) ~[na:na]
at org.eclipse.jetty.server.Server.handle(Server.java:350) ~[na:na]
at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:454) ~[na:na]
at org.eclipse.jetty.server.AbstractHttpConnection.headerComplete(AbstractHttpConnection.java:890) ~[na:na]
at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.headerComplete(AbstractHttpConnection.java:944) ~[na:na]
at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:630) ~[na:na]
at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:230) ~[na:na]
at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:77) ~[na:na]
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:606) ~[na:na]
at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:46) ~[na:na]
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:603) ~[na:na]
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:538) ~[na:na]
at java.lang.Thread.run(Thread.java:745) ~[na:1.8.0_65]
12:09:31.867 [DEBUG] [tuwien.auto.calimero :53 ] - KNXnet/IP Tunneling 192.168.0.2:3671: sending connection state request, attempt 1
12:10:31.868 [DEBUG] [tuwien.auto.calimero :53 ] - KNXnet/IP Tunneling 192.168.0.2:3671: sending connection state request, attempt 1
12:11:31.870 [DEBUG] [tuwien.auto.calimero :53 ] - KNXnet/IP Tunneling 192.168.0.2:3671: sending connection state request, attempt 1
12:12:31.872 [DEBUG] [tuwien.auto.calimero :53 ] - KNXnet/IP Tunneling 192.168.0.2:3671: sending connection state request, attempt 1
12:13:31.874 [DEBUG] [tuwien.auto.calimero :53 ] - KNXnet/IP Tunneling 192.168.0.2:3671: sending connection state request, attempt 1
Hi, i had rebuild the binding with current dev version of Calimero(v.2.4) project and it works for at moment.
Expected Behavior
I had download openHAB 2 Beta offline Snapshot from website and start over start_debug.sh and install knx bindung.
12:22:56.467 [INFO ] [nx.internal.connection.KNXConnection] - KNXBinding configuration is not present. Please check your configuration file or if not needed remove the KNX addon. 12:22:56.481 [INFO ] [core.karaf.internal.FeatureInstaller] - Installed 'openhab-binding-knx1' 12:22:56.485 [INFO ] [smarthome.event.ExtensionEvent ] - Extension 'binding-knx1' has been installed. 12:24:22.214 [INFO ] [nx.internal.connection.KNXConnection] - Established connection to KNX bus on 10.17.10.30:3671 in mode TUNNEL. Exception in thread "KNXnet/IP receiver" java.lang.ArrayIndexOutOfBoundsException: 128 at tuwien.auto.calimero.cemi.CEMILDataEx.putAddInfo(CEMILDataEx.java:568) at tuwien.auto.calimero.cemi.CEMILDataEx.readAddInfo(CEMILDataEx.java:484) at tuwien.auto.calimero.cemi.CEMILDataEx.(CEMILDataEx.java:166)
at tuwien.auto.calimero.cemi.CEMIFactory.create(CEMIFactory.java:88)
at tuwien.auto.calimero.knxnetip.servicetype.ServiceRequest.(ServiceRequest.java:83)
at tuwien.auto.calimero.knxnetip.servicetype.PacketHelper.getServiceRequest(PacketHelper.java:88)
at tuwien.auto.calimero.knxnetip.ConnectionBase.getServiceRequest(ConnectionBase.java:533)
at tuwien.auto.calimero.knxnetip.KNXnetIPTunnel.handleServiceType(KNXnetIPTunnel.java:166)
at tuwien.auto.calimero.knxnetip.ReceiverLoop.onReceive(ReceiverLoop.java:85)
at tuwien.auto.calimero.internal.UdpSocketLooper.loop(UdpSocketLooper.java:134)
at tuwien.auto.calimero.knxnetip.ReceiverLoop.run(ReceiverLoop.java:67)
at java.lang.Thread.run(Thread.java:745)
Please update knx binding package to new version on calimero project.
Possible Solution
https://sourceforge.net/p/calimero/discussion/485103/thread/0fb3306b/?limit=25
Steps to Reproduce (for bugs)
Context
knx binding is not working
Your Environment
Version used: openhab> version 4.0.4 openhab> version-list openhab-binding-knx1 Version | Repository | Repository URL
1.9.0.SNAPSHOT | openhab-aggregate-xml | mvn:org.openhab.distro/openhab-aggregate-xml/2.0.0-SNAPSHOT/xml/features
Environment name and version: openjdk version "1.8.0_111" OpenJDK Runtime Environment (build 1.8.0_111-b15) OpenJDK 64-Bit Server VM (build 25.111-b15, mixed mode)
Operating System and version: centos 6.8