Raspberry Pi: demo.py sometimes work, sometimes not

[tonka3000]

Hey @undera ,

I have troubles to get the demo.py example from your repo to work always. It worked multiple times (3-4 times), but most of the time the hub switches off WARNING:hub:Hub switches off, before an action can be started and the program stuck on that state. The bot turns off after 10 seconds of not interaction which is the default as far as I can tell. I've tried it on my mac, but no bluetooth backend seems to support MacOS so not test possible. For me it looks like the program on the pi is so slow (maybe wait for an event) and reach timeout before.

Hardware: raspberry pi 3 B, Lego Boost Robot
python: 3.7.3
virtual env: yes, with python3 -m venv
Bluetooth backend: bluepy 1.3.0
Firmware-Version: 2.0.00.0017

Here is the application stdout from demo.py. It extremely fast found the hub but it stuck on the line INFO:hub:Attached peripheral: LEDRGB on port 0x32 for some time, so it seems that the program is waiting for something here.

INFO:root:Trying get_connection_bluepy
INFO:comms-bluepy:Discovering devices...
INFO:comms-bluepy:Discovering devices...
INFO:comms:Found LEGO Move Hub at 00:16:53:ba:05:69
INFO:hub:Attached peripheral: EncodedMotor on port 0x0
INFO:hub:Attached peripheral: EncodedMotor on port 0x1
INFO:hub:Attached peripheral: VisionSensor on port 0x2
INFO:hub:Attached peripheral: EncodedMotor on port 0x3
INFO:hub:Attached peripheral: EncodedMotor on port 0x10
INFO:hub:Attached peripheral: LEDRGB on port 0x32 //<= stuck for multiple seconds here
INFO:hub:Attached peripheral: TiltSensor on port 0x3a
INFO:hub:Attached peripheral: Current on port 0x3b
INFO:hub:Attached peripheral: Voltage on port 0x3c
WARNING:hub:Have not dedicated class for peripheral type 0x42 on port 0x46
INFO:hub:Attached peripheral: Peripheral on port 0x46
WARNING:hub:Hub switches off

Maybe you have an idea how I can debug that problem.

Greetings

Tonka

[undera]

The proper way to troubleshoot this is to enable DEBUG level logging in demo.py (instead of INFO). Then run it again and share the log.

[tonka3000]

Hey,

here is the log.

INFO:root:Trying get_connection_bluepy
DEBUG:comms-bluepy:Trying to connect client to MoveHub with MAC: None
INFO:comms-bluepy:Discovering devices...
DEBUG:comms:Checking device: LEGO Move Hub, MAC: 00:16:53:ba:01:50
INFO:comms:Found LEGO Move Hub at 00:16:53:ba:01:50
DEBUG:comms-bluepy:Writing to handle 15: b'0100'
DEBUG:hub:Waiting for builtin devices to appear: (None, None, None, None, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (None, None, None, None, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (None, None, None, None, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (None, None, None, None, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (None, None, None, None, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (None, None, None, None, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (None, None, None, None, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (None, None, None, None, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (None, None, None, None, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (None, None, None, None, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (None, None, None, None, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (None, None, None, None, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (None, None, None, None, None, None, None)
DEBUG:comms-bluepy:Incoming notification
DEBUG:hub:Notification on 14: b'0f0004000127000000001000000010'
DEBUG:hub:Decoded message: MsgHubAttachedIO({'payload': b'27000000001000000010', 'port': 0, 'event': 1})
DEBUG:hub:Handling msg with <bound method MoveHub._handle_device_change of <pylgbst.hub.MoveHub object at 0x74886f30>>: MsgHubAttachedIO({'payload': b'27000000001000000010', 'port': 0, 'event': 1})
INFO:hub:Attached peripheral: EncodedMotor on port 0x0
DEBUG:comms-bluepy:Incoming notification
DEBUG:hub:Notification on 14: b'0f0004010127000000001000000010'
DEBUG:hub:Decoded message: MsgHubAttachedIO({'payload': b'27000000001000000010', 'port': 1, 'event': 1})
DEBUG:hub:Handling msg with <bound method MoveHub._handle_device_change of <pylgbst.hub.MoveHub object at 0x74886f30>>: MsgHubAttachedIO({'payload': b'27000000001000000010', 'port': 1, 'event': 1})
INFO:hub:Attached peripheral: EncodedMotor on port 0x1
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, None, None, None, None, None)
DEBUG:comms-bluepy:Incoming notification
DEBUG:hub:Notification on 14: b'0f0004020125000000001000000010'
DEBUG:hub:Decoded message: MsgHubAttachedIO({'payload': b'25000000001000000010', 'port': 2, 'event': 1})
DEBUG:hub:Handling msg with <bound method MoveHub._handle_device_change of <pylgbst.hub.MoveHub object at 0x74886f30>>: MsgHubAttachedIO({'payload': b'25000000001000000010', 'port': 2, 'event': 1})
INFO:hub:Attached peripheral: VisionSensor on port 0x2
DEBUG:comms-bluepy:Incoming notification
DEBUG:hub:Notification on 14: b'0f0004030126000000001000000010'
DEBUG:hub:Decoded message: MsgHubAttachedIO({'payload': b'26000000001000000010', 'port': 3, 'event': 1})
DEBUG:hub:Handling msg with <bound method MoveHub._handle_device_change of <pylgbst.hub.MoveHub object at 0x74886f30>>: MsgHubAttachedIO({'payload': b'26000000001000000010', 'port': 3, 'event': 1})
INFO:hub:Attached peripheral: EncodedMotor on port 0x3
DEBUG:comms-bluepy:Incoming notification
DEBUG:hub:Notification on 14: b'090004100227000001'
DEBUG:hub:Decoded message: MsgHubAttachedIO({'payload': b'27000001', 'port': 16, 'event': 2})
DEBUG:hub:Handling msg with <bound method MoveHub._handle_device_change of <pylgbst.hub.MoveHub object at 0x74886f30>>: MsgHubAttachedIO({'payload': b'27000001', 'port': 16, 'event': 2})
INFO:hub:Attached peripheral: EncodedMotor on port 0x10
DEBUG:comms-bluepy:Incoming notification
DEBUG:hub:Notification on 14: b'0f0004320117000000000106000020'
DEBUG:hub:Decoded message: MsgHubAttachedIO({'payload': b'17000000000106000020', 'port': 50, 'event': 1})
DEBUG:hub:Handling msg with <bound method MoveHub._handle_device_change of <pylgbst.hub.MoveHub object at 0x74886f30>>: MsgHubAttachedIO({'payload': b'17000000000106000020', 'port': 50, 'event': 1})
INFO:hub:Attached peripheral: LEDRGB on port 0x32
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, None, None, None)
DEBUG:comms-bluepy:Incoming notification
DEBUG:hub:Notification on 14: b'0f00043a0128000000001000000102'
DEBUG:hub:Decoded message: MsgHubAttachedIO({'payload': b'28000000001000000102', 'port': 58, 'event': 1})
DEBUG:hub:Handling msg with <bound method MoveHub._handle_device_change of <pylgbst.hub.MoveHub object at 0x74886f30>>: MsgHubAttachedIO({'payload': b'28000000001000000102', 'port': 58, 'event': 1})
INFO:hub:Attached peripheral: TiltSensor on port 0x3a
DEBUG:comms-bluepy:Incoming notification
DEBUG:hub:Notification on 14: b'0f00043b0115000200000000000100'
DEBUG:hub:Decoded message: MsgHubAttachedIO({'payload': b'15000200000000000100', 'port': 59, 'event': 1})
DEBUG:hub:Handling msg with <bound method MoveHub._handle_device_change of <pylgbst.hub.MoveHub object at 0x74886f30>>: MsgHubAttachedIO({'payload': b'15000200000000000100', 'port': 59, 'event': 1})
DEBUG:hub:Waiting for builtin devices to appear: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, TiltSensor on port 0x3a, None, None)
INFO:hub:Attached peripheral: Current on port 0x3b
DEBUG:comms-bluepy:Incoming notification
DEBUG:hub:Notification on 14: b'0f00043c0114000200000000000100'
DEBUG:hub:Decoded message: MsgHubAttachedIO({'payload': b'14000200000000000100', 'port': 60, 'event': 1})
DEBUG:hub:Handling msg with <bound method MoveHub._handle_device_change of <pylgbst.hub.MoveHub object at 0x74886f30>>: MsgHubAttachedIO({'payload': b'14000200000000000100', 'port': 60, 'event': 1})
INFO:hub:Attached peripheral: Voltage on port 0x3c
DEBUG:comms-bluepy:Incoming notification
DEBUG:hub:Notification on 14: b'0f0004460142000100000000000010'
DEBUG:hub:Decoded message: MsgHubAttachedIO({'payload': b'42000100000000000010', 'port': 70, 'event': 1})
DEBUG:hub:Handling msg with <bound method MoveHub._handle_device_change of <pylgbst.hub.MoveHub object at 0x74886f30>>: MsgHubAttachedIO({'payload': b'42000100000000000010', 'port': 70, 'event': 1})
WARNING:hub:Have not dedicated class for peripheral type 0x42 on port 0x46
INFO:hub:Attached peripheral: Peripheral on port 0x46
DEBUG:comms-bluepy:Incoming notification
DEBUG:hub:Notification on 14: b'04000230'
DEBUG:hub:Decoded message: MsgHubAction({'payload': b'', 'needs_reply': False, 'action': 48})
DEBUG:hub:Handling msg with <bound method Hub._handle_action of <pylgbst.hub.MoveHub object at 0x74886f30>>: MsgHubAction({'payload': b'', 'needs_reply': False, 'action': 48})
WARNING:hub:Hub switches off
DEBUG:hub:All devices are present: (EncodedMotor on port 0x0, EncodedMotor on port 0x1, EncodedMotor on port 0x10 (ports 0x0 and 0x1 combined), LEDRGB on port 0x32, TiltSensor on port 0x3a, Current on port 0x3b, Voltage on port 0x3c)
DEBUG:hub:Send message: MsgHubProperties({'payload': b'', 'needs_reply': False, 'property': 1, 'operation': 5, 'parameters': b''})
DEBUG:hub:Waiting for sync reply to MsgHubProperties({'payload': b'0105', 'needs_reply': True, 'property': 1, 'operation': 5, 'parameters': b''})...
DEBUG:comms-bluepy:Writing to handle 14: b'0500010105'

[undera]

So it looks like there is indeed something that makes pylgbst to not receive any incoming messages from BLE after LEDRGB attach message. The library is helpless here, since it simply does not get any communication from underlying BLE stack.
This can be either hardware problem, or underlying library problem, bluepy in your case.

I would give a try to another connection library, for example pygatt. Again, I don't see anything that would cause such a pause on the library side (I can be wrong, though, since I did not write that part of library).

[tonka3000]

I tried every other backend, but non of them work. Always with the following error (here for gatt), seems like a different kind f problem here.

INFO:root:Trying get_connection_bluepy
INFO:root:Trying get_connection_bluegiga
INFO:root:Trying get_connection_gatt
Module 'dbus' not found
Please run: sudo apt-get install python3-dbus
See also: https://github.com/getsenic/gatt-python#installing-gatt-sdk-for-python
INFO:root:Trying get_connection_bleak
INFO:root:Trying get_connection_gattool
INFO:root:Trying get_connection_gattlib
Traceback (most recent call last):
  File "demo.py", line 259, in <module>
    hub = MoveHub(**parameters)
  File "/home/pi/lego/env/lib/python3.7/site-packages/pylgbst/hub.py", line 201, in __init__
    connection = get_connection_auto(hub_name="LEGO Move Hub")
  File "/home/pi/lego/env/lib/python3.7/site-packages/pylgbst/__init__.py", line 75, in get_connection_auto
    raise Exception("Failed to autodetect connection, make sure you have installed prerequisites")
Exception: Failed to autodetect connection, make sure you have installed prerequisites
Exception ignored in: <function Hub.__del__ at 0x76509468>
Traceback (most recent call last):
  File "/home/pi/lego/env/lib/python3.7/site-packages/pylgbst/hub.py", line 52, in __del__
    if self.connection and self.connection.is_alive():
AttributeError: 'MoveHub' object has no attribute 'connection'

I also used gattctl --discover and get following message

Module 'dbus' not found
Please run: sudo apt-get install python3-dbus
See also: https://github.com/getsenic/gatt-python#installing-gatt-sdk-for-python

So I run sudo apt-get install python3-dbus but it's already installed.

I checked it also on another raspberry pi, same issue there.

I also tried your bleak-troubleshooting #70 branch with following log

INFO:root:Trying get_connection_bluepy
INFO:root:Trying get_connection_bluegiga
INFO:root:Trying get_connection_gatt
Module 'dbus' not found
Please run: sudo apt-get install python3-dbus
See also: https://github.com/getsenic/gatt-python#installing-gatt-sdk-for-python
INFO:root:Trying get_connection_bleak
INFO:comms-bleak:Discovering devices... Press green button on Hub
INFO:bleak.backends.bluezdbus.discovery:LEGO Move Hub, 00:16:53:BA:05:69 (-91 dBm), Object Path: /org/bluez/hci0/dev_00_16_53_BA_05_69
INFO:bleak.backends.bluezdbus.discovery:LEGO Move Hub, 00:16:53:BA:05:69 (-91 dBm), Object Path: /org/bluez/hci0/dev_00_16_53_BA_05_69
INFO:comms:Found LEGO Move Hub at 00:16:53:BA:05:69
INFO:comms-bleak:Device matched: <bleak.backends.device.BLEDevice object at 0x75d0e8d0>
INFO:bleak.backends.bluezdbus.discovery:LEGO Move Hub, 00:16:53:BA:05:69 (-77 dBm), Object Path: /org/bluez/hci0/dev_00_16_53_BA_05_69
INFO:bleak.backends.bluezdbus.discovery:LEGO Move Hub, 00:16:53:BA:05:69 (-77 dBm), Object Path: /org/bluez/hci0/dev_00_16_53_BA_05_69
DEBUG:bleak.backends.bluezdbus.client:Connecting to BLE device @ 00:16:53:BA:05:69 with hci0
DEBUG:bleak.backends.bluezdbus.client:Connection successful.
DEBUG:bleak.backends.bluezdbus.client:Get Services...
DEBUG:bleak.backends.bluezdbus.client:
Primary Service
        /org/bluez/hci0/dev_00_16_53_BA_05_69/service000c
        00001623-1212-efde-1623-785feabcd123
        Unknown
DEBUG:bleak.backends.bluezdbus.client:
Characteristic
        /org/bluez/hci0/dev_00_16_53_BA_05_69/service000c/char000d
        00001624-1212-efde-1623-785feabcd123
        Unknown
DEBUG:bleak.backends.bluezdbus.client:
Descriptor
        /org/bluez/hci0/dev_00_16_53_BA_05_69/service000c/char000d/desc000f
        00002902-0000-1000-8000-00805f9b34fb
        Client Characteristic Configuration
DEBUG:bleak.backends.bluezdbus.client:
Primary Service
        /org/bluez/hci0/dev_00_16_53_BA_05_69/service0001
        00001801-0000-1000-8000-00805f9b34fb
        Generic Attribute Profile
DEBUG:bleak.backends.bluezdbus.client:
Characteristic
        /org/bluez/hci0/dev_00_16_53_BA_05_69/service0001/char0002
        00002a05-0000-1000-8000-00805f9b34fb
        Service Changed
DEBUG:bleak.backends.bluezdbus.client:
Descriptor
        /org/bluez/hci0/dev_00_16_53_BA_05_69/service0001/char0002/desc0004
        00002902-0000-1000-8000-00805f9b34fb
        Client Characteristic Configuration
DEBUG:bleak.backends.bluezdbus.client:DBUS: path: /org/bluez/hci0/dev_00_16_53_BA_05_69/service000c/char000d, domain: org.bluez.GattCharacteristic1, body: {'Notifying': True}
DEBUG:bleak.backends.bluezdbus.client:DBUS: path: /org/bluez/hci0/dev_00_16_53_BA_05_69/service000c/char000d, domain: org.bluez.GattCharacteristic1, body: {'WriteAcquired': True}
INFO:bleak.backends.bluezdbus.client:GATT Char Properties Changed: /org/bluez/hci0/dev_00_16_53_BA_05_69/service000c/char000d | [{'WriteAcquired': True}, []]
DEBUG:bleak.backends.bluezdbus.client:Write Characteristic 00001624-1212-efde-1623-785feabcd123 | /org/bluez/hci0/dev_00_16_53_BA_05_69/service000c/char000d: bytearray(b'\x01\x00')
WARNING:hub:Got only these devices: (None, None, None, None, None, None, None)
DEBUG:bleak.backends.bluezdbus.client:DBUS: path: /org/bluez/hci0/dev_00_16_53_BA_05_69/service000c/char000d, domain: org.bluez.GattCharacteristic1, body: {'WriteAcquired': False}
INFO:bleak.backends.bluezdbus.client:GATT Char Properties Changed: /org/bluez/hci0/dev_00_16_53_BA_05_69/service000c/char000d | [{'WriteAcquired': False}, []]
DEBUG:bleak.backends.bluezdbus.client:DBUS: path: /org/bluez/hci0/dev_00_16_53_BA_05_69/service000c/char000d, domain: org.bluez.GattCharacteristic1, body: {'Value': [15, 0, 4, 0, 1, 39, 0, 0, 0, 0, 16, 0, 0, 0, 16]}
INFO:bleak.backends.bluezdbus.client:GATT Char Properties Changed: /org/bluez/hci0/dev_00_16_53_BA_05_69/service000c/char000d | [{'Value': [15, 0, 4, 0, 1, 39, 0, 0, 0, 0, 16, 0, 0, 0, 16]}, []]
DEBUG:bleak.backends.bluezdbus.client:DBUS: path: /org/bluez/hci0/dev_00_16_53_BA_05_69/service000c/char000d, domain: org.bluez.GattCharacteristic1, body: {'Value': [15, 0, 4, 1, 1, 39, 0, 0, 0, 0, 16, 0, 0, 0, 16]}
INFO:bleak.backends.bluezdbus.client:GATT Char Properties Changed: /org/bluez/hci0/dev_00_16_53_BA_05_69/service000c/char000d | [{'Value': [15, 0, 4, 1, 1, 39, 0, 0, 0, 0, 16, 0, 0, 0, 16]}, []]
DEBUG:bleak.backends.bluezdbus.client:DBUS: path: /org/bluez/hci0/dev_00_16_53_BA_05_69/service000c/char000d, domain: org.bluez.GattCharacteristic1, body: {'Value': [15, 0, 4, 2, 1, 37, 0, 0, 0, 0, 16, 0, 0, 0, 16]}
INFO:hub:Attached peripheral: EncodedMotor on port 0x0
INFO:bleak.backends.bluezdbus.client:GATT Char Properties Changed: /org/bluez/hci0/dev_00_16_53_BA_05_69/service000c/char000d | [{'Value': [15, 0, 4, 2, 1, 37, 0, 0, 0, 0, 16, 0, 0, 0, 16]}, []]
INFO:hub:Attached peripheral: EncodedMotor on port 0x1
DEBUG:bleak.backends.bluezdbus.client:DBUS: path: /org/bluez/hci0/dev_00_16_53_BA_05_69/service000c/char000d, domain: org.bluez.GattCharacteristic1, body: {'Value': [15, 0, 4, 3, 1, 38, 0, 0, 0, 0, 16, 0, 0, 0, 16]}
INFO:bleak.backends.bluezdbus.client:GATT Char Properties Changed: /org/bluez/hci0/dev_00_16_53_BA_05_69/service000c/char000d | [{'Value': [15, 0, 4, 3, 1, 38, 0, 0, 0, 0, 16, 0, 0, 0, 16]}, []]
INFO:hub:Attached peripheral: VisionSensor on port 0x2
DEBUG:bleak.backends.bluezdbus.client:DBUS: path: /org/bluez/hci0/dev_00_16_53_BA_05_69/service000c/char000d, domain: org.bluez.GattCharacteristic1, body: {'Value': [9, 0, 4, 16, 2, 39, 0, 0, 1]}
INFO:bleak.backends.bluezdbus.client:GATT Char Properties Changed: /org/bluez/hci0/dev_00_16_53_BA_05_69/service000c/char000d | [{'Value': [9, 0, 4, 16, 2, 39, 0, 0, 1]}, []]
INFO:hub:Attached peripheral: EncodedMotor on port 0x3
DEBUG:bleak.backends.bluezdbus.client:DBUS: path: /org/bluez/hci0/dev_00_16_53_BA_05_69/service000c/char000d, domain: org.bluez.GattCharacteristic1, body: {'Value': [15, 0, 4, 50, 1, 23, 0, 0, 0, 0, 1, 6, 0, 0, 32]}
INFO:bleak.backends.bluezdbus.client:GATT Char Properties Changed: /org/bluez/hci0/dev_00_16_53_BA_05_69/service000c/char000d | [{'Value': [15, 0, 4, 50, 1, 23, 0, 0, 0, 0, 1, 6, 0, 0, 32]}, []]
INFO:hub:Attached peripheral: EncodedMotor on port 0x10
DEBUG:bleak.backends.bluezdbus.client:DBUS: path: /org/bluez/hci0/dev_00_16_53_BA_05_69/service000c/char000d, domain: org.bluez.GattCharacteristic1, body: {'Value': [15, 0, 4, 58, 1, 40, 0, 0, 0, 0, 16, 0, 0, 1, 2]}
INFO:bleak.backends.bluezdbus.client:GATT Char Properties Changed: /org/bluez/hci0/dev_00_16_53_BA_05_69/service000c/char000d | [{'Value': [15, 0, 4, 58, 1, 40, 0, 0, 0, 0, 16, 0, 0, 1, 2]}, []]
DEBUG:bleak.backends.bluezdbus.client:DBUS: path: /org/bluez/hci0/dev_00_16_53_BA_05_69/service000c/char000d, domain: org.bluez.GattCharacteristic1, body: {'Value': [15, 0, 4, 59, 1, 21, 0, 2, 0, 0, 0, 0, 0, 1, 0]}
INFO:hub:Attached peripheral: LEDRGB on port 0x32
INFO:bleak.backends.bluezdbus.client:GATT Char Properties Changed: /org/bluez/hci0/dev_00_16_53_BA_05_69/service000c/char000d | [{'Value': [15, 0, 4, 59, 1, 21, 0, 2, 0, 0, 0, 0, 0, 1, 0]}, []]
DEBUG:bleak.backends.bluezdbus.client:DBUS: path: /org/bluez/hci0/dev_00_16_53_BA_05_69/service000c/char000d, domain: org.bluez.GattCharacteristic1, body: {'Value': [15, 0, 4, 60, 1, 20, 0, 2, 0, 0, 0, 0, 0, 1, 0]}
INFO:bleak.backends.bluezdbus.client:GATT Char Properties Changed: /org/bluez/hci0/dev_00_16_53_BA_05_69/service000c/char000d | [{'Value': [15, 0, 4, 60, 1, 20, 0, 2, 0, 0, 0, 0, 0, 1, 0]}, []]
INFO:hub:Attached peripheral: TiltSensor on port 0x3a
DEBUG:bleak.backends.bluezdbus.client:DBUS: path: /org/bluez/hci0/dev_00_16_53_BA_05_69/service000c/char000d, domain: org.bluez.GattCharacteristic1, body: {'Value': [15, 0, 4, 70, 1, 66, 0, 1, 0, 0, 0, 0, 0, 0, 16]}
INFO:bleak.backends.bluezdbus.client:GATT Char Properties Changed: /org/bluez/hci0/dev_00_16_53_BA_05_69/service000c/char000d | [{'Value': [15, 0, 4, 70, 1, 66, 0, 1, 0, 0, 0, 0, 0, 0, 16]}, []]
DEBUG:bleak.backends.bluezdbus.client:DBUS: path: /org/bluez/hci0/dev_00_16_53_BA_05_69/service000c/char000d, domain: org.bluez.GattCharacteristic1, body: {'Value': [5, 0, 5, 255, 5]}
INFO:hub:Attached peripheral: Current on port 0x3b
INFO:bleak.backends.bluezdbus.client:GATT Char Properties Changed: /org/bluez/hci0/dev_00_16_53_BA_05_69/service000c/char000d | [{'Value': [5, 0, 5, 255, 5]}, []]
DEBUG:bleak.backends.bluezdbus.client:DBUS: path: /org/bluez/hci0/dev_00_16_53_BA_05_69/service000c/char000d, domain: org.bluez.GattCharacteristic1, body: {'Value': [4, 0, 2, 48]}
INFO:bleak.backends.bluezdbus.client:GATT Char Properties Changed: /org/bluez/hci0/dev_00_16_53_BA_05_69/service000c/char000d | [{'Value': [4, 0, 2, 48]}, []]
INFO:hub:Attached peripheral: Voltage on port 0x3c
DEBUG:bleak.backends.bluezdbus.client:DBUS: path: /org/bluez/hci0/dev_00_16_53_BA_05_69/service000c/char000d, domain: org.bluez.GattCharacteristic1, body: {'Value': [4, 0, 2, 49]}
WARNING:hub:Have not dedicated class for peripheral type 0x42 on port 0x46
INFO:bleak.backends.bluezdbus.client:GATT Char Properties Changed: /org/bluez/hci0/dev_00_16_53_BA_05_69/service000c/char000d | [{'Value': [4, 0, 2, 49]}, []]
DEBUG:bleak.backends.bluezdbus.client:DBUS: path: /org/bluez/hci0/dev_00_16_53_BA_05_69, domain: org.bluez.Device1, body: {'ServicesResolved': False, 'Connected': False}
DEBUG:bleak.backends.bluezdbus.client:Device 00:16:53:BA:05:69 disconnected.
INFO:hub:Attached peripheral: Peripheral on port 0x46
DEBUG:bleak.backends.bluezdbus.client:Removing rule PropChanged, ID: 1
WARNING:hub:Command error: Command 0xff caused error 0x5: Command NOT recognized
WARNING:hub:Hub switches off
Traceback (most recent call last):
  File "demo.py", line 259, in <module>
    hub = MoveHub(**parameters)
  File "/home/pi/lego/env/lib/python3.7/site-packages/pylgbst/hub.py", line 220, in __init__
    self._report_status()
  File "/home/pi/lego/env/lib/python3.7/site-packages/pylgbst/hub.py", line 237, in _report_status
    name = self.send(MsgHubProperties(MsgHubProperties.ADVERTISE_NAME, MsgHubProperties.UPD_REQUEST))
  File "/home/pi/lego/env/lib/python3.7/site-packages/pylgbst/hub.py", line 71, in send
    self.connection.write(self.HUB_HARDWARE_HANDLE, msgbytes)
  File "/home/pi/lego/env/lib/python3.7/site-packages/pylgbst/comms/cbleak.py", line 88, in write
Exception in thread Thread-1:
Traceback (most recent call last):
  File "/usr/lib/python3.7/threading.py", line 917, in _bootstrap_inner
    self.run()
  File "/usr/lib/python3.7/threading.py", line 865, in run
    self._target(*self._args, **self._kwargs)
  File "/home/pi/lego/env/lib/python3.7/site-packages/pylgbst/comms/cbleak.py", line 96, in _processing
    handler(handle, data)
  File "/home/pi/lego/env/lib/python3.7/site-packages/pylgbst/hub.py", line 96, in _notify
    handler(msg)
  File "/home/pi/lego/env/lib/python3.7/site-packages/pylgbst/hub.py", line 125, in _handle_action
    self.connection.disconnect()
  File "/home/pi/lego/env/lib/python3.7/site-packages/pylgbst/comms/cbleak.py", line 72, in disconnect
    if self.is_alive():
  File "/home/pi/lego/env/lib/python3.7/site-packages/pylgbst/comms/cbleak.py", line 78, in is_alive
    return self._loop.run_until_complete(self._client.is_connected())
  File "/usr/lib/python3.7/asyncio/base_events.py", line 571, in run_until_complete
    self.run_forever()
  File "/usr/lib/python3.7/asyncio/base_events.py", line 526, in run_forever
    raise RuntimeError('This event loop is already running')
RuntimeError: This event loop is already running

    self._loop.run_until_complete(self._client.write_gatt_char(MOVE_HUB_HW_UUID_CHAR, data))
  File "/usr/lib/python3.7/asyncio/base_events.py", line 584, in run_until_complete
    return future.result()
  File "/home/pi/lego/env/lib/python3.7/site-packages/bleak/backends/bluezdbus/client.py", line 536, in write_gatt_char
    ).asFuture(self.loop)
txdbus.error.RemoteError: org.bluez.Error.Failed: Not connected

Greetings

Tonka

[undera]

Do you have bluez installed? It is installed with sudo apt-get install bluez

[tonka3000]

bluez is also installed

[undera]

/home/pi/lego/env/lib - are you using some sort of virtualenv? If yes, then you need to install python dbus lib into that virtual env (pip install dbus-python or so, might also need some libs, see https://stackoverflow.com/questions/13365697/install-python-dbus-in-virtualenv), or use system-site-packages option of it.

[tonka3000]

installing dbus-python via pip install dbus-python does not work for gatt, but it worked for bleak. With bleak it works most of the time. The strange thing is that I can not really find out under which conditions it does not work (I also check the bluetooth distance, but it did not change that much).

[memegraf]

Hi, i was struggling with rpi and my lego boost. thanks to this issue i got the demo.py running within docker on rpi3. maybe you can make use of it: https://gitlab.com/tigabeatz/rpi-docker-lego

i needed

RUN pip3 install bluepy pylgbst dbus-python gatt gobject PyGObject \
 && git clone https://github.com/undera/pylgbst.git

and

RUN apt-get update && apt-get install -y \
    build-essential git wget make libical-dev libdbus-1-dev libglib2.0-dev libreadline-dev libudev-dev systemd pkg-config libcairo2-dev gcc python3-dev libgirepository1.0-dev

to run the demo.py i start it with gatt and the boosts mac, otherwise i do not get connections:

mh=$(timeout -s INT 10s hcitool lescan | grep 'Move Hub')
mhmac=$(echo $mh | tr -d ' Move Hub')
python3 /usr/src/app/pylgbst/examples/demo.py -c "gatt://${mhmac}"