search

openhab / openhab1-addons

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

[MCP23017] When binding is installed on Openhabian 1.3 (with OH 2.1), Openhab cannot start. #5237

Open szymic1 opened 7 years ago

szymic1 commented 7 years ago

When MCP23017 binding is installed on Openhaian 1.3 (with OH 2.1), OH cannot start.

Expected Behavior

OH shoud start when I put MCP23017 binding jar in /usr/share/openhab2/addons.

Current Behavior

I've tried to install MCP23017 binding (from https://openhab.ci.cloudbees.com/job/openHAB1-Addons/lastSuccessfulBuild/artifact/bundles/binding/org.openhab.binding.mcp23017/target/ ). but when I copied this to adds directory there are problem with starting Openhab. In the openhablog there are following information. "Started dashboard.." is displayed every 10seconds (in a loop):

2017-07-02 12:48:31.703 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at http://192.168.1.10:8080
2017-07-02 12:48:31.720 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at https://192.168.1.10:8443
2017-07-02 12:48:46.125 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'test.items'
2017-07-02 12:48:54.990 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'test.rules'
2017-07-02 12:49:44.305 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at http://192.168.1.10:8080
2017-07-02 12:49:44.322 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at https://192.168.1.10:8443

It happens when system start but it also happen when OH running and I put MCP file on runnnign system. This binding works on OH 2.0 without problem.

Possible Solution

Only uninstalling MCP binding helps.

Steps to Reproduce (for bugs)

  1. Install Openhabian 1.3 from SD image
  2. Copy MCP binding file to /usr/share/openhab2/addons ( download binding from https://openhab.ci.cloudbees.com/job/openHAB1-Addons/lastSuccessfulBuild/artifact/bundles/binding/org.openhab.binding.mcp23017/target/3 I've used org.openhab.binding.mcp23017-1.11.0-SNAPSHOT.jar but 1.10 also does not work)
  3. Now you should see loop in openhab.log log messages

Your Environment

Raspberry 2, Openhabian 1.3, with Razberry hut

9037568 commented 7 years ago

Since you indicated this binding works in OH 2.0, but fails in OH 2.1, the problem likely lies in ESH, because the binding hasn't changed.

Try opening this issue in the ESH issue tracker.

szymic1 commented 7 years ago

To be honest I do not know where is problem. I wonder if the old binding need not be modified to work with the new OH - I do not know. I create issue for OH and make a link to this.

szymic1 commented 7 years ago

Task related to smarthome and openhab-cor was closed @kaikreuzer suggests that is problem of binding.

9037568 commented 7 years ago

I just merged Kai's fix. Can you try again with the latest snapshot jar next time it gets built? (ie. with a build after 1491)

kaikreuzer commented 7 years ago

Build is through: https://openhab.ci.cloudbees.com/job/openHAB1-Addons/1492/

szymic1 commented 7 years ago

To test this fix should I upgrade my OH to the newest snapshot or we are talking about newe version of binding file (https://openhab.ci.cloudbees.com/job/openHAB1-Addons/1492/org.openhab.binding$org.openhab.binding.mcp23017/)

szymic1 commented 7 years ago

I've installed the newest version of MCP binding, nothing changed problem still exists.

9037568 commented 7 years ago

I tried this. Since I'm not running on a Raspberry Pi, I get the new error:

20:32:14.678 [ERROR] [ng.mcp23017.internal.MCP23017Binding] - MCP23017 Binding needs to be run a Raspberry Pi - deactivating it here.

If @szymic1 can submit a debug log, we might be able to debug further.

kaikreuzer commented 7 years ago

@9037568 This message is normal - I added it through my PR to signal to the user that the binding won't work as expected. Nonetheless, it does not crash anymore, but further in the log you will see that it starts its services and that the bundle is active as expected (without causing any restarts of the dashboard).

szymic1 commented 7 years ago

When I've put new version of MCP binding I've got loop (the same situation as before). Log with level DEBUG can be found here: https://drive.google.com/open?id=0B68VuZDaIVt5MlZJSFlfSzk1c2s

My reproduction steps: 1) installation of Openhabian 1.3 2) copying MCP binding to addson directory

2017-07-13 22:44:52.303 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui
2017-07-13 22:44:53.385 [INFO ] [assic.internal.servlet.WebAppServlet] - Started Classic UI at /classicui/app
2017-07-13 22:48:11.423 [INFO ] [b.core.service.AbstractActiveService] - mcp23017 Refresh Service has been started
2017-07-13 22:49:26.644 [INFO ] [basic.internal.servlet.WebAppServlet] - Stopped Basic UI
2017-07-13 22:49:36.416 [INFO ] [assic.internal.servlet.WebAppServlet] - Stopped Classic UI
2017-07-13 22:49:36.535 [INFO ] [ui.habmin.internal.servlet.HABminApp] - Stopped HABmin servlet
2017-07-13 22:49:37.185 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Stopped Paper UI
2017-07-13 22:49:37.216 [INFO ] [panel.internal.HABPanelDashboardTile] - Stopped HABPanel
2017-07-13 22:49:37.239 [INFO ] [.dashboard.internal.DashboardService] - Stopped dashboard
2017-07-13 22:51:08.109 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at http://192.168.1.6:8080
2017-07-13 22:51:08.129 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at https://192.168.1.6:8443
2017-07-13 22:52:22.825 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at http://192.168.1.6:8080
2017-07-13 22:52:22.843 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at https://192.168.1.6:8443
2017-07-13 22:53:16.788 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at http://192.168.1.6:8080
2017-07-13 22:53:16.808 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at https://192.168.1.6:8443
2017-07-13 22:54:04.344 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at http://192.168.1.6:8080
2017-07-13 22:54:04.361 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at https://192.168.1.6:8443
2017-07-13 22:54:52.950 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at http://192.168.1.6:8080
9037568 commented 7 years ago

@kaikreuzer - yes, I was aware of that, but thanks for pointing it out.

9037568 commented 7 years ago

Thanks, @szymic1.

Please turn on DEBUG logging for the org.openhab.ui.dashboard and org.openhab.binding.MCP23017 packages and recapture. I don't see any ERRORs in the log, which I would've thought would be occurring to produce the looping restarts...

These lines are interesting, but more detail is needed:

2017-07-14 08:37:47.319 [INFO ] [org.apache.felix.fileinstall        ] - Installing bundle org.openhab.binding.mcp23017 / 1.11.0.201707130521
...
2017-07-14 08:37:47.464 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.binding.mcp23017 (208): Starting destruction process
2017-07-14 08:37:47.464 [DEBUG] [org.eclipse.jetty.jmx.ObjectMBean   ] - Method Cache: dump()
2017-07-14 08:37:47.466 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.binding.mcp23017 (208): Not an extended bundle or destruction of extension already finished
...
2017-07-14 08:37:48.365 [DEBUG] [mpl.info.InfoBundleTrackerCustomizer] - Ignore incorrect info null provided by bundle org.openhab.binding.mcp23017
9037568 commented 7 years ago

Oh, also, please show your configurations (items/rules/sitemap). What bindings do you have installed?

szymic1 commented 7 years ago

only MCP. Installing MCP binding was a first (and last) step after finishing Openhabian installation. I have not modified items/rules/sitemaps. That is why it is very easy to reproduce - this bug happen on default installation.

phili007 commented 7 years ago

Hallo, have the same Problem, has install completely new openhabian 1.3 Image and Version OH2.1 but active Compatiblity to 1.x, after the copy MCP23017 Snapshot 1.11 to Add-on, and the OH Panic, the karaf console eject the session, have set log to DEBUG, but not realy informativ.

2017-07-17 17:47:04.886 [INFO ] [org.apache.felix.fileinstall ] - Installing bundle org.openhab.binding.mcp23017 / 1.11.0.201707160110 2017-07-17 17:47:04.944 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.binding.mcp23017 (187): Starting destruction process 2017-07-17 17:47:04.947 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.binding.mcp23017 (187): Not an extended bundle or destruction of extension already finished 2017-07-17 17:47:05.408 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.binding.mcp23017 (187): Starting destruction process 2017-07-17 17:47:05.409 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.binding.mcp23017 (187): Not an extended bundle or destruction of extension already finished 2017-07-17 17:47:05.491 [DEBUG] [mpl.info.InfoBundleTrackerCustomizer] - Ignore incorrect info null provided by bundle org.openhab.binding.mcp23017 2017-07-17 17:47:05.537 [DEBUG] [com.pi4j.util.NativeLibraryLoader ] - Attempting to load [libpi4j.so] using path: [/lib/raspberrypi/static/libpi4j.so] 2017-07-17 17:47:06.037 [DEBUG] [rg.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers 2017-07-17 17:47:06.188 [DEBUG] [com.pi4j.util.NativeLibraryLoader ] - Library [libpi4j.so] has already been loaded; no need to load again. 2017-07-17 17:47:06.192 [DEBUG] [com.pi4j.util.NativeLibraryLoader ] - Library [libpi4j.so] has already been loaded; no need to load again. 2017-07-17 17:47:06.196 [DEBUG] [com.pi4j.util.NativeLibraryLoader ] - Library [libpi4j.so] has already been loaded; no need to load again. 2017-07-17 17:47:06.198 [DEBUG] [com.pi4j.util.NativeLibraryLoader ] - Library [libpi4j.so] loaded successfully using embedded resource file: [/lib/raspberrypi/static/libpi4j.so] 2017-07-17 17:47:06.264 [DEBUG] [com.pi4j.util.NativeLibraryLoader ] - Library [libpi4j.so] has already been loaded; no need to load again.

after this Point - the OH2 Panic an restart, after remove MCP from add-on Folder it will possible to connect stable Karaf, bevor OH2 Panic all 20 secounds.

The library for MCP Need "pi4j-core.jar, pi4j-gpio-extension.jar, quick-json-1.0.2.3.jar" they must also be copied, have test this, PI4J was "Active" but this MCP OH2 Panic.

You have idea, to solve this.

szymic1 commented 7 years ago

I've made tests on Rp3 and it also exist on this platform :( The reproduction steps were the same as for Rp2

szymic1 commented 7 years ago

the karaf console eject the session,

In my test Karaf consolre restart every few seconds but also all UI interfaces cannot start.

9037568 commented 7 years ago

In that case, @szymic1 I hope that you can provide a full debug log.

szymic1 commented 7 years ago

Log is the same as for Rp2 (few comments above) https://drive.google.com/open?id=0B68VuZDaIVt5MlZJSFlfSzk1c2s

9037568 commented 7 years ago

The log file, I'm afraid, doesn't give much useful info.

It looks like the OH system is starting over and over again. I count 5 loops in this log. But there are no errors flagged, and I can't see a reason why OH would be restarting.

Have you checked the Pi's system logs for clues?

You could also try inquiring in the community forum for clues on why the DashboardService is repeatedly restarting.

9037568 commented 7 years ago

Oh, one other thing you should check. The status of the binding in the karaf console.

bundle:list | grep mcp
bundle:status <bundleId>
szymic1 commented 7 years ago

I tried to check but I have to reinstall OH once again after installation of MCP I cannot login to Karaf console (and I alos cannot switch on DEBUG mode). I will look at Rpi log file when I return to home.

NickolayGerasimenko commented 7 years ago

have the same issue with fresh raspbian release

previously all works great with MCP23017 binding 1.9 and 1.11 with following version of raspbian

http://downloads.raspberrypi.org/raspbian_lite/images/raspbian_lite-2017-04-10/

So something wrong with linux kernel or some system libs where changed!!!!

image

NickolayGerasimenko commented 7 years ago

Kernel downgrade as described here solved the issue:

sudo rpi-update 52241088c1da59a359110d39c1875cda56496764

https://community.openhab.org/t/how-to-install-mcp23017-binding-with-jar-file/29348/25?u=stnick

9037568 commented 7 years ago

The post from @NickolayGerasimenko does not describe the same problem as originally reported in this thread.

phili007 commented 7 years ago

Have downgrade kernel form 4.9.35 to 4.4.50 and it works perfect with MCP23017, same configuration, don't change anything at the configuration. MCP hast Problem with 4.9.x

Software state : openhabian 1.3 new Installation with OH 2.2 snapshot

Step's : sudo rpi-update 52241088c1da59a359110d39c1875cda56496764 reboot connect Karaf:

188 | Resolved | 80 | 2.2.0.201707190537 | openHAB 1.x Compatibility Layer 195 | Resolved | 80 | 1.11.0.201707160110 | openHAB GPIO Binding 196 | Resolved | 80 | 1.11.0.201707160110 | openHAB GPIO IO Module 197 | Resolved | 80 | 1.11.0.201707160110 | openHAB mcp23017 Binding

remove org.openhab.binding.mcp23017-1.11.0-SNAPSHOT.jar file from add-on folder wait sort time copy org.openhab.binding.mcp23017-1.11.0-SNAPSHOT.jar file to add-on Folder connect karaf:

188 | Active | 80 | 2.2.0.201707190537 | openHAB 1.x Compatibility Layer 195 | Active | 80 | 1.11.0.201707160110 | openHAB GPIO Binding 196 | Active | 80 | 1.11.0.201707160110 | openHAB GPIO IO Module 198 | Active | 80 | 1.11.0.201707160110 | openHAB mcp23017 Binding

logout karaf sudo /etc/init.d/openhab2 restart alle MCP23017 works with this kernel 👍

falkena commented 7 years ago

Hi everybody,

i integrated and rebuild MCP* bindings against current Pi4J snapshot. This should solve openHAB start issues (https://www.raspberrypi.org/forums/viewtopic.php?t=182191#p1156722). Jar’s can be found here: https://github.com/falkena/binaries

Can somebody else test, please? If it works, i’ll open PR with fix.

Thanks and kind regards,

Alexander

szmolnar commented 7 years ago

Alexander, I tried your fox without luck, MCB binding is not loaded.

My system is a Rpi3 with DebianSketch (4.9.41-v7+), running OH2.1.0.

szmolnar commented 7 years ago

phili007,

Thanks for the solution, it's working!

hr3 commented 7 years ago

Hello falkena, I have the same problem with #1036 (Kernel = Linux 4.9.35-v7+) sudo update 52241088c1da59a359110d39c1875cda56496764 isn't possible in a openHABian-installation. If I copy the org.openhab.binding.mcp3424-1.11.0-SNAPSHOT.jar and ...mcp23017... with 839KB (there are also files with 629KB) in the addons library I get

2017-09-11 17:28:17.081 [INFO ] [b.core.service.AbstractActiveService] - mcp3424 Refresh Service has been started
2017-09-11 17:28:17.196 [INFO ] [b.core.service.AbstractActiveService] - mcp23017 Refresh Service has been started

but the bindings aren't displayed.