mqtt-io
mqtt-io copied to clipboard
flyte
`feature/trio` hangs on RPi1 B with sensors enabled
- [x] I have read the README.md file and visited the Documentation to see if the information there helps.
Describe the bug
mqtt-io branch feature/trio hangs on RPi1
Expected behavior mqtt-io connects to the mqtt broker and delivers sensor messages
Error messages and traceback
When it hangs interrupting is impossible (even when debugging -m pdb -m mqtt-io).
So this is all I could extract really and may be a red herring:
Caught exception in on_socket_open: [Errno 9] Bad file descriptor
trio.MultiError: KeyboardInterrupt(), KeyboardInterrupt()
> /home/dietpi/.venvs/mqtt-io-trio/lib/python3.7/site-packages/mqtt_io/server.py(92)run()
-> trio.run(self.run_async)
strace showed it waiting on a futex complete strace.log attached:
...
mmap2(NULL, 8392704, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0xb47bf000
mprotect(0xb47c0000, 8388608, PROT_READ|PROT_WRITE) = 0
clone(child_stack=0xb4fbef78, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, parent_tidptr=0xb4fbf4a8, tls=0xb4fbf900, child_tidptr=0xb4fbf4a8) = 1578
futex(0x1df4db8, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 1, NULL, FUTEX_BITSET_MATCH_ANY) = 0
gettimeofday({tv_sec=1654549747, tv_usec=259652}, NULL) = 0
futex(0x433a9c, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 0, {tv_sec=1654549747, tv_nsec=264652000}, FUTEX_BITSET_MATCH_ANY) = 0
futex(0x433aa0, FUTEX_WAIT_PRIVATE, 2, NULL) = 0
futex(0x433aa0, FUTEX_WAKE_PRIVATE, 1) = 0
futex(0x1b97748, FUTEX_WAKE_PRIVATE, 1) = 1
clock_gettime(CLOCK_MONOTONIC, {tv_sec=6747, tv_nsec=254483000}) = 0
futex(0x433a98, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x433aa0, FUTEX_WAKE_PRIVATE, 1) = 1
clock_gettime(CLOCK_MONOTONIC, {tv_sec=6747, tv_nsec=264999000}) = 0
clock_gettime(CLOCK_MONOTONIC, {tv_sec=6747, tv_nsec=267582000}) = 0
futex(0x1c1b278, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 1, NULL, FUTEX_BITSET_MATCH_ANY
Config
mqtt:
host: 192.168.x.x
topic_prefix: mqtt-io/library
ha_discovery:
enabled: yes
sensor_modules:
- name: dht
module: dht22
type: dht22
pin: 4
sensor_inputs:
- name: dht_library_temperature
module: dht
type: temperature
Normalized config
{
"digital_inputs": [],
"digital_outputs": [],
"gpio_modules": [],
"logging":
{
"formatters":
{
"simple":
{ "format": "%(asctime)s %(name)s (%(levelname)s): %(message)s" },
},
"handlers":
{
"console":
{
"class": "logging.StreamHandler",
"formatter": "simple",
"level": "DEBUG",
"stream": "ext://sys.stdout",
},
},
"loggers":
{
"mqtt_gpio":
{ "handlers": ["console"], "level": "DEBUG", "propagate": True },
},
"version": 1,
},
"mqtt":
{
"clean_session": False,
"client_id": "",
"client_module": "mqtt_io.mqtt.asyncio_mqtt",
"ha_discovery":
{ "enabled": True, "name": "MQTT IO", "prefix": "homeassistant" },
"host": "192.168.x.x",
"keepalive": 10,
"password": "",
"port": 1883,
"protocol": "3.1.1",
"reconnect_count": None,
"reconnect_delay": 2,
"status_payload_dead": "dead",
"status_payload_running": "running",
"status_payload_stopped": "stopped",
"status_topic": "status",
"topic_prefix": "mqtt-io/library",
"user": "",
},
"options": { "install_requirements": True },
"sensor_inputs":
[
{
"digits": 2,
"interval": 60,
"module": "dht",
"name": "dht_library_temperature",
"retain": False,
"type": "temperature",
},
],
"sensor_modules":
[
{
"cleanup": True,
"module": "dht22",
"name": "dht",
"pin": 4,
"type": "dht22",
},
],
"stream_modules": [],
}
Hardware
- Platform: Raspberry Pi 1 B rev 2
- Connected hardware: DHT22
System:
- OS: DietPi 7.4.2 "Raspbian GNU/Linux 10 (buster)"
- Python version: Python 3.7.3
- User you're running as: dietpi
- Using a virtualenv?: yes
Additional context This was an attempt to workaround the creeping CPU usage (#236) in case it was asyncio-mqtt related.
Installing mqtt-io feature/trio branch was done as follows:
git checkout feature/trio
## set pyproject.toml version to 2.2.6-post1 to distinguish it from upstream pkg
poetry build
python3 -m ~/.venv/mqtt-io-trio
~/.venv/mqtt-io-trio/bin/python -m pip install dist/mqtt_io-2.2.6.post1-py3-none-any.whl
~/.venv/mqtt-io-trio/bin/python -m mqtt-io ~/mqtt-io-config/debug-config.yml
I note that it only hangs when sensor inputs are configured. With a sensor module but no sensor inputs it connects to the broker and the mqtt-io/library/status running message is received.
Should i be suspicious of the "client_module": "mqtt_io.mqtt.asyncio_mqtt", in the normalized config?
Do I need to explicitly switch it to anyio-mqtt?
Upgraded to Debian 11 (Bullseye) with python3.9.
Same behaviour (2.6.6 and develop work but has the same rising CPU issue)
Enabled more logging.
Config:
mqtt:
host: 192.168.x.x
topic_prefix: mqtt-io/library
sensor_modules:
- name: dht
module: dht22
type: dht22
pin: 4
sensor_inputs:
- name: dht_library_temperature
module: dht
type: temperature
# Adafruit_DHT needs manual install for py39 armv6l
options:
install_requirements: no
logging:
version: 1
handlers:
console:
class: logging.StreamHandler
formatter: default
level: DEBUG
formatters:
default:
format: "%(asctime)s %(name)s [%(levelname)-8s] %(message)s"
datefmt: "%Y-%m-%d %H:%M:%S"
loggers:
anyio_mqtt:
level: DEBUG
handlers:
- console
propagate: yes
paho:
level: DEBUG
handlers:
- console
propagate: yes
mqtt:
level: DEBUG
handlers:
- console
propagate: yes
mqtt_io:
level: DEBUG
handlers:
- console
propagate: yes
Log:
2022-06-08 11:49:40 anyio_mqtt [DEBUG ] _hold_stream_open(MemoryObjectSendStream(_state=MemoryObjectStreamState(max_buffer_size=0, buffer=deque([]), open_send_channels=1, open_receive_channels=1, waiting_receivers=OrderedDict(), waiting_senders=OrderedDict()), _closed=False)) started
2022-06-08 11:49:40 anyio_mqtt [DEBUG ] _handle_state_changes() started
2022-06-08 11:49:40 anyio_mqtt [DEBUG ] _handle_state_changes() opened _internal_state_rx
2022-06-08 11:49:40 anyio_mqtt [DEBUG ] _hold_stream_open(MemoryObjectSendStream(_state=MemoryObjectStreamState(max_buffer_size=0, buffer=deque([]), open_send_channels=1, open_receive_channels=1, waiting_receivers=OrderedDict(), waiting_senders=OrderedDict()), _closed=False)) started
2022-06-08 11:49:40 anyio_mqtt [DEBUG ] _hold_stream_open(MemoryObjectReceiveStream(_state=MemoryObjectStreamState(max_buffer_size=0, buffer=deque([]), open_send_channels=1, open_receive_channels=1, waiting_receivers=OrderedDict(), waiting_senders=OrderedDict()), _closed=False)) started
2022-06-08 11:49:40 anyio_mqtt [DEBUG ] connect() called
2022-06-08 11:49:40 anyio_mqtt [DEBUG ] New state: State.CONNECTING
2022-06-08 11:49:40 anyio_mqtt [DEBUG ] Unable to send new state (State.CONNECTING) to external state stream
2022-06-08 11:49:40 anyio_mqtt [DEBUG ] _reconnect_loop() started
2022-06-08 11:49:40 anyio_mqtt [DEBUG ] (Re)connecting...
2022-06-08 11:49:40 anyio_mqtt [DEBUG ] do_reconnect() started
2022-06-08 11:49:40 anyio_mqtt [DEBUG ] _hold_stream_open(MemoryObjectSendStream(_state=MemoryObjectStreamState(max_buffer_size=0, buffer=deque([]), open_send_channels=1, open_receive_channels=1, waiting_receivers=OrderedDict([(<anyio._backends._trio.Event object at 0xb5a7c238>, [])]), waiting_senders=OrderedDict()), _closed=False)) started
2022-06-08 11:49:41 anyio_mqtt [DEBUG ] _misc_loop() started
2022-06-08 11:49:41 anyio_mqtt [DEBUG ] _on_socket_open()
(Why am I only getting anyio_mqtt logs and not other modules?)
Same behaviour (2.6.6 and develop work but has the same rising CPU issue)
rising CPU issue should be fixed now with version 2.2.8 (#301)
If this error is still present, please reopen this issue or create a new one.
This issue wasn't actually about #301. But trying to find a workaround for #301 is how I discovered this issue in the first place.
Either way I think feature/trio has been abandoned so closing this is appropriate.