Closed CrappyTan closed 6 years ago
vkolotov
commented
6 years ago I don't see this much on my set up. This happens when your Bluez crashes (IO error) or when it just hangs or something... As I said, I had it only once or so, hence there is not any logic to recover from this in the Bluetooth Manager, just some logic to catch this only. See if it happens to you again, report it and just restart Bluez to recover.
CrappyTan
commented
6 years ago Starting bluetooth on the pi does make it work but as it is, this is causing my wife much angst :) "Why have the blinds not opened/closed again?!"
19:48:38.547 [DEBUG] [h.manager.transport.tinyb.TinyBDevice] - Checking if device connected: tinyb://00:1A:7D:DA:71:06/F3:95:30:3E:DD:4A 19:48:38.553 [DEBUG] [h.manager.transport.tinyb.TinyBDevice] - Getting RSSI: tinyb://00:1A:7D:DA:71:06/F3:95:30:3E:DD:4A 19:48:38.560 [DEBUG] [h.manager.transport.tinyb.TinyBDevice] - Getting TxPower: tinyb://00:1A:7D:DA:71:06/F3:95:30:3E:DD:4A 19:48:39.418 [DEBUG] [h.manager.transport.tinyb.TinyBDevice] - Getting blocked: tinyb://00:1A:7D:DA:71:06/C1:03:74:91:05:6C 19:48:39.428 [DEBUG] [h.manager.transport.tinyb.TinyBDevice] - Checking if device connected: tinyb://00:1A:7D:DA:71:06/C1:03:74:91:05:6C 19:48:39.435 [DEBUG] [h.manager.transport.tinyb.TinyBDevice] - Getting RSSI: tinyb://00:1A:7D:DA:71:06/C1:03:74:91:05:6C 19:48:39.457 [DEBUG] [h.manager.transport.tinyb.TinyBDevice] - Getting TxPower: tinyb://00:1A:7D:DA:71:06/C1:03:74:91:05:6C 1
Why would it be blocked? Nothing else is connected to the blinds.
vkolotov
commented
6 years ago Yeah, I understand your pain :) Nah... ignore that "blocked". It tries to get its "blocked" state. There is nothing wrong with that piece of log. Is there anything else?
It would be better to enable BM DEBUG logs:
log:set DEBUG org.sputnikdev.bluetooth.manager.implthanks. I'll add the new debug and see what it says in a bit.
Got something else though - not sure if it's related or not; Karaf service keeps crashing. In var/messages I always see this just before a crash -
Sep 17 20:17:01 homeauto CRON[1471]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly) Sep 17 20:18:11 homeauto systemd[1]: Created slice User Slice of root. Sep 17 20:18:11 homeauto systemd[1]: Starting User Manager for UID 0... Sep 17 20:18:11 homeauto systemd[1]: Started Session c1 of user root. Sep 17 20:18:11 homeauto systemd[1566]: Reached target Paths. Sep 17 20:18:11 homeauto systemd[1566]: Reached target Timers. Sep 17 20:18:11 homeauto systemd[1566]: Listening on GnuPG cryptographic agent and passphrase cache. Sep 17 20:18:11 homeauto systemd[1566]: Listening on GnuPG cryptographic agent (access for web browsers). Sep 17 20:18:11 homeauto systemd[1566]: Listening on GnuPG network certificate management daemon. Sep 17 20:18:11 homeauto systemd[1566]: Listening on GnuPG cryptographic agent and passphrase cache (restricted). Sep 17 20:18:11 homeauto systemd[1566]: Listening on GnuPG cryptographic agent (ssh-agent emulation). Sep 17 20:18:11 homeauto systemd[1566]: Reached target Sockets. Sep 17 20:18:11 homeauto systemd[1566]: Reached target Basic System. Sep 17 20:18:11 homeauto systemd[1566]: Reached target Default. Sep 17 20:18:11 homeauto systemd[1566]: Startup finished in 71ms. Sep 17 20:18:11 homeauto systemd[1]: Started User Manager for UID 0. Sep 17 20:19:52 homeauto karaf[507]: Error in `/usr/bin/java': double free or corruption (fasttop): 0x5f8ffbc0 Sep 17 20:19:52 homeauto systemd[1]: openhab2.service: Main process exited, code=killed, status=6/ABRT Sep 17 20:19:54 homeauto karaf[1747]: Can't connect to the container. The container is not running. Sep 17 20:19:54 homeauto systemd[1]: openhab2.service: Control process exited, code=exited status=1 Sep 17 20:19:54 homeauto systemd[1]: openhab2.service: Unit entered failed state. Sep 17 20:19:54 homeauto systemd[1]: openhab2.service: Failed with result 'signal'. Sep 17 20:19:59 homeauto systemd[1]: openhab2.service: Service hold-off time over, scheduling restart. Sep 17 20:19:59 homeauto systemd[1]: Stopped openHAB 2 - empowering the smart home. Sep 17 20:19:59 homeauto systemd[1]: Started openHAB 2 - empowering the smart home. Sep 17 20:20:05 homeauto karaf[1876]: 2018-09-17 20:20:05,940 CM Configuration Updater (ManagedService Update: pid=[org.ops4j.pax.logging]) ERROR appender RollingRandomAccessFile has no parameter that matches element RegexFilter
If I disable the three BT bindings (bundle:stop) it seems to run ok. Trouble is, it's a bit random. Sometimes it crashes every hour, sometimes twice in 15 minutes, once, a whole day was OK.
Thoughts? This is PRi 3B+, newish SD card (reports no errors) and OH installed on USB stick.
vkolotov
commented
6 years ago Wow... never seen this before. Do you use onboard bluetoot adapter?
Just a thought... as the binding is very chatty in logs, it may cause some issues. I normally disable logs as soon as possible. Otherwise log files gets filled up quickly. Could you try to run it without any logs enabled (e.g. enable INFO level)? Just to exclude this from table.
vkolotov
commented
6 years ago Another thing to consider, BT adapters have limit number of connection they can open and keep connected. How many of devices are connected to your PI? Normally it is 6-8 simultaneous connections, if it is more than this, more adapters can be used.
CrappyTan
commented
6 years ago I've reduced the logging back to normal. Still crashing :( I am using the on-board adaptor (I had a second USB one but since removed it). I am only connected (things) to two BT items but the Inbox shows another 12. It's not polling / connecting to those is it?
Logs still showing
Sep 18 22:31:16 homeauto karaf[25950]: Error in `/usr/bin/java': double free or corruption (fasttop): 0x5f9fe7e8 Sep 18 22:31:17 homeauto systemd[1]: openhab2.service: Main process exited, code=killed, status=6/ABRT Sep 18 22:31:18 homeauto karaf[30809]: Can't connect to the container. The container is not running. Sep 18 22:31:18 homeauto systemd[1]: openhab2.service: Control process exited, code=exited status=1 Sep 18 22:31:18 homeauto systemd[1]: openhab2.service: Unit entered failed state. Sep 18 22:31:18 homeauto systemd[1]: openhab2.service: Failed with result 'signal'. Sep 18 22:31:24 homeauto systemd[1]: openhab2.service: Service hold-off time over, scheduling restart. Sep 18 22:31:24 homeauto systemd[1]: Stopped openHAB 2 - empowering the smart home. Sep 18 22:31:24 homeauto systemd[1]: Started openHAB 2 - empowering the smart home.
CrappyTan
commented
6 years ago I've disabled the bindings (bundle:stop) and see how it behaves overnight.
vkolotov
commented
6 years ago Do you run OpenJDK? It is not recommended. Pls install Oracle JDK.
vkolotov
commented
6 years ago This also I bet is related to TinyB library that we use (that is a middle layer between Bluez/Dbus and the binding). We are trying to get rid of it by implementing another transport layer that talks to DBus directly. It is taking some time, not sure when it is going to be ready.
Just in general, BlueGiga adapters (Bluegiga transport) is more stable than generic adapters. Another option is to get some BlueGiga adapters (there are some on aliexpress).
vkolotov
commented
6 years ago But still, if you are running OpenJDK - this is the cause. I have never seen any issues like that before (double free or corruption).
CrappyTan
commented
6 years ago I removed openjdk and reverted to oracle. Well, it's all gone bad now. None of the UIs work, bundle:list does not show your binding any more and the error log is full of errors. See here for some error detail: https://community.openhab.org/t/httpservicestarted-could-not-start-the-servlet-context-for-context-path-no-uis-working/51970
Been mucking about with it for a while now (most of the week). I need to find another way to do and test these things without breaking my whole house.
vkolotov
commented
6 years ago hey @CrispinP, as a java developer (12 years of experience) I do really recommend you to use Oracle JDK. This is the original JDK that every company use out there. It is the standard.
Furthermore, even Kai and Co recommend to install either Oracle JDK or zulu (don't know much about zulu): https://www.openhab.org/docs/installation/#prerequisites
I'm 100% sure the issues you have can be resolved.
vkolotov
commented
6 years ago how have you installed oracle jdk? have you removed openjdk?
CrappyTan
commented
6 years ago I thought I had read that zulu was better performance for the pi. Sure I read it on the forums. Nonetheless, I'll use whatever you tell me to :)
How did I install it? Tbh, I cannot remember. I have 3 versions installed now - when I run alternatives -config java. I'll check when I'm home again in an hour.
Categorically, what and how should I install it on rpi?
Thanks
CrappyTan
commented
6 years ago I've now solved all these problems. I'll open a fresh issue with the crashing.
I've had this working for a day after working out the gatt files. This evening I see the blinds have not worked and in OH logs I see the following:
If I try connect to the blinds visa another rpi it works. If I down/up the controller on the OH RPi it makes no difference. I did not try edit the binding to see if that worked. A reboot of the RPi did make it work.
All the while this was happening I could still operate the other blinds.
Thoughts?