mmpy_bot: Weird crash with 2.0.0

Describe the bug I am seeing a weird issue on a fresh install where after a few seconds of the bot running it catches an exception after which the bot is unresponsive.

How To Reproduce

python3 -m venv testing
source testing/bin/activate
python3 -m pip install mmpy_bot
python3 run.py

Expected behavior The bot to run without issues 😄

Operating Environment (please complete the following information):

OS: Ubuntu 20.04
Python Version: 3.8.5
Mattermost Version: 5.33.0
mmpy_bot Version: 2.0.0

Additional context Here is the traceback info:

$ python3 ../run.py
[03/19/2021 11:18:56] Starting bot Bot.
[03/19/2021 11:18:56] Scheduler thread started.
[03/19/2021 11:18:56] Websocket authentification OK
Traceback (most recent call last):
  File "/home/attzonko/repos/testing/lib/python3.8/site-packages/websockets/protocol.py", line 827, in transfer_data
    message = await self.read_message()
  File "/home/attzonko/repos/testing/lib/python3.8/site-packages/websockets/protocol.py", line 895, in read_message
    frame = await self.read_data_frame(max_size=self.max_size)
  File "/home/attzonko/repos/testing/lib/python3.8/site-packages/websockets/protocol.py", line 971, in read_data_frame
    frame = await self.read_frame(max_size)
  File "/home/attzonko/repos/testing/lib/python3.8/site-packages/websockets/protocol.py", line 1047, in read_frame
    frame = await Frame.read(
  File "/home/attzonko/repos/testing/lib/python3.8/site-packages/websockets/framing.py", line 105, in read
    data = await reader(2)
  File "/usr/lib/python3.8/asyncio/streams.py", line 721, in readexactly
    raise exceptions.IncompleteReadError(incomplete, n)
asyncio.exceptions.IncompleteReadError: 0 bytes read on a total of 2 expected bytes

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "../run.py", line 16, in <module>
    bot.run()
  File "/home/attzonko/repos/testing/lib/python3.8/site-packages/mmpy_bot/bot.py", line 88, in run
    self.event_handler.start()
  File "/home/attzonko/repos/testing/lib/python3.8/site-packages/mmpy_bot/event_handler.py", line 44, in start
    self.driver.init_websocket(self._handle_event)
  File "/home/attzonko/repos/testing/lib/python3.8/site-packages/mattermostdriver/driver.py", line 148, in init_websocket
    loop.run_until_complete(self.websocket.connect(event_handler))
  File "/usr/lib/python3.8/asyncio/base_events.py", line 616, in run_until_complete
    return future.result()
  File "/home/attzonko/repos/testing/lib/python3.8/site-packages/mattermostdriver/websocket.py", line 50, in connect
    await self._start_loop(websocket, event_handler)
  File "/home/attzonko/repos/testing/lib/python3.8/site-packages/mattermostdriver/websocket.py", line 61, in _start_loop
    await asyncio.wait_for(
  File "/usr/lib/python3.8/asyncio/tasks.py", line 483, in wait_for
    return fut.result()
  File "/home/attzonko/repos/testing/lib/python3.8/site-packages/mattermostdriver/websocket.py", line 101, in _wait_for_message
    message = await websocket.recv()
  File "/home/attzonko/repos/testing/lib/python3.8/site-packages/websockets/protocol.py", line 509, in recv
    await self.ensure_open()
  File "/home/attzonko/repos/testing/lib/python3.8/site-packages/websockets/protocol.py", line 803, in ensure_open
    raise self.connection_closed_exc()
websockets.exceptions.ConnectionClosedError: code = 1006 (connection closed abnormally [internal]), no reason

About this issue

Original URL
State: closed
Created 3 years ago
Comments: 21 (11 by maintainers)

Most upvoted comments

Reverting back to MM 5.32.1 makes the ping/pong issue in websockets go away:

client > Frame(fin=True, opcode=9, data=b'\xa27\xd0\x08', rsv1=False, rsv2=False, rsv3=False)
DEBUG:websockets.protocol:client > Frame(fin=True, opcode=9, data=b'\xa27\xd0\x08', rsv1=False, rsv2=False, rsv3=False)
client - event = data_received(<6 bytes>)
DEBUG:websockets.protocol:client - event = data_received(<6 bytes>)
client < Frame(fin=True, opcode=10, data=b'\xa27\xd0\x08', rsv1=False, rsv2=False, rsv3=False)
DEBUG:websockets.protocol:client < Frame(fin=True, opcode=10, data=b'\xa27\xd0\x08', rsv1=False, rsv2=False, rsv3=False)
client - received solicited pong: a237d008
DEBUG:websockets.protocol:client - received solicited pong: a237d008

I created a post on forum.mattermost.org: https://forum.mattermost.org/t/issue-seen-with-websocket-connection/11411/4

attzonko on Mar 22, 2021

There is some hope this was fixed by MM: https://github.com/Vaelor/python-mattermost-driver/issues/79#issuecomment-804234147

The docker image I am using still seems to be on version 33.0, so I will confirm the fix once that is updated.

https://mattermost.atlassian.net/browse/MM-34000 https://docs.mattermost.com/administration/changelog.html (5.33.1)

attzonko on Mar 22, 2021

Ok, I haven’t seen this occur upon bot start-up either. I can only trigger the exception when severing the connection between the bot and MM. I will create a separate issue for addressing the issue with re-establishing connectivity.

@attzonko, have you been able to reproduce this issue on another system/VM?

ttuffin on Mar 22, 2021

Sphinx 3.5.3 (not sure what that’s for, but even if I downgrade to 3.5.2 it all works)

Sphinx is needed only to generate documentation. Shouldn’t affect the bot.

unode on Mar 20, 2021