search

L235 / hat-collector

GNU General Public License v2.0
0 stars 4 forks source link

Bot does not recover from exception #29

Closed L235 closed 2 years ago

L235 commented 2 years ago

Describe the bug A clear and concise description of what the bug is.

To reproduce Steps to reproduce the behavior:

  1. Go to '...'
  2. Click on '....'
  3. Scroll down to '....'
  4. See error

Expected behavior A clear and concise description of what you expected to happen.

Console output If available, add console output.

2022-08-30 05:45:18 ERROR    Unexpected event from stream error: {"message":"Local: Broker transport failure","code":-195,"errno":-195,"origin":"kafka"}
2022-08-30 05:45:18 INFO     Quit
2022-08-30 05:45:18 ERROR    Unclosed connection
client_connection: Connection<ConnectionKey(host='stream.wikimedia.org', port=443, is_ssl=True, ssl=None, proxy=None, proxy_auth=None, proxy_headers_hash=None)>
./go-beta.sh: 3: exit: Illegal number: -1
2022-08-30 05:45:21 INFO     Connecting to DB
2022-08-30 05:45:21 INFO     Preparing bot
2022-08-30 05:45:21 INFO     Running bot
2022-08-30 05:45:26 INFO     Syncing report channels
2022-08-30 05:45:26 INFO     Running query: SELECT lower(name) FROM channels
2022-08-30 05:45:26 INFO     Syncing rules
2022-08-30 05:45:26 INFO     Running query: SELECT wiki, type, pattern, lower(channel), ignore FROM rules ORDER BY ignore DESC
2022-08-30 05:45:27 ERROR    Encountered error on socket.
pydle.features.rfc1459.protocol.ServerError: Closing Link: wikimedia/bot/hat-collector (Excess Flood)
2022-08-30 05:45:31 INFO     Syncing report channels
2022-08-30 05:45:31 INFO     Running query: SELECT lower(name) FROM channels
2022-08-30 05:45:31 INFO     Syncing rules
2022-08-30 05:45:31 INFO     Running query: SELECT wiki, type, pattern, lower(channel), ignore FROM rules ORDER BY ignore DESC
2022-08-30 05:45:32 ERROR    Encountered error on socket.
pydle.features.rfc1459.protocol.ServerError: Closing Link: wikimedia/bot/hat-collector (Excess Flood)
2022-08-30 05:45:40 INFO     Syncing report channels
2022-08-30 05:45:40 INFO     Running query: SELECT lower(name) FROM channels
2022-08-30 05:45:40 INFO     Syncing rules
2022-08-30 05:45:40 INFO     Running query: SELECT wiki, type, pattern, lower(channel), ignore FROM rules ORDER BY ignore DESC
2022-08-30 05:45:40 ERROR    Encountered error on socket.
pydle.features.rfc1459.protocol.ServerError: Closing Link: wikimedia/bot/hat-collector (Excess Flood)
2022-08-30 05:45:45 INFO     Syncing report channels
2022-08-30 05:45:45 INFO     Running query: SELECT lower(name) FROM channels
2022-08-30 05:45:45 INFO     Syncing rules
2022-08-30 05:45:45 INFO     Running query: SELECT wiki, type, pattern, lower(channel), ignore FROM rules ORDER BY ignore DESC
2022-08-30 05:45:46 ERROR    Encountered error on socket.
pydle.features.rfc1459.protocol.ServerError: Closing Link: wikimedia/bot/hat-collector (Excess Flood)
2022-08-30 05:45:54 INFO     Syncing report channels
2022-08-30 05:45:54 INFO     Running query: SELECT lower(name) FROM channels
2022-08-30 05:45:54 INFO     Syncing rules
2022-08-30 05:45:54 INFO     Running query: SELECT wiki, type, pattern, lower(channel), ignore FROM rules ORDER BY ignore DESC
2022-08-30 05:45:54 ERROR    Encountered error on socket.
pydle.features.rfc1459.protocol.ServerError: Closing Link: wikimedia/bot/hat-collector (Excess Flood)
2022-08-30 05:45:58 INFO     Syncing report channels
2022-08-30 05:45:58 INFO     Running query: SELECT lower(name) FROM channels
2022-08-30 05:45:58 INFO     Syncing rules
2022-08-30 05:45:58 INFO     Running query: SELECT wiki, type, pattern, lower(channel), ignore FROM rules ORDER BY ignore DESC
2022-08-30 05:45:59 ERROR    Encountered error on socket.
pydle.features.rfc1459.protocol.ServerError: Closing Link: wikimedia/bot/hat-collector (Excess Flood)
2022-08-30 05:46:04 INFO     Syncing report channels
2022-08-30 05:46:04 INFO     Running query: SELECT lower(name) FROM channels
2022-08-30 05:46:04 INFO     Syncing rules
2022-08-30 05:46:04 INFO     Running query: SELECT wiki, type, pattern, lower(channel), ignore FROM rules ORDER BY ignore DESC
2022-08-30 05:46:05 ERROR    Encountered error on socket.
pydle.features.rfc1459.protocol.ServerError: Closing Link: wikimedia/bot/hat-collector (Excess Flood)
2022-08-30 05:46:08 INFO     Syncing report channels
2022-08-30 05:46:08 INFO     Running query: SELECT lower(name) FROM channels
2022-08-30 05:46:08 INFO     Syncing rules
2022-08-30 05:46:08 INFO     Running query: SELECT wiki, type, pattern, lower(channel), ignore FROM rules ORDER BY ignore DESC
2022-08-30 05:46:08 ERROR    Encountered error on socket.
pydle.features.rfc1459.protocol.ServerError: Closing Link: wikimedia/bot/hat-collector (Excess Flood)
2022-08-30 05:46:11 INFO     Syncing report channels
2022-08-30 05:46:11 INFO     Running query: SELECT lower(name) FROM channels
2022-08-30 05:46:11 INFO     Syncing rules
2022-08-30 05:46:11 INFO     Running query: SELECT wiki, type, pattern, lower(channel), ignore FROM rules ORDER BY ignore DESC
2022-08-30 05:46:12 ERROR    Encountered error on socket.
pydle.features.rfc1459.protocol.ServerError: Closing Link: wikimedia/bot/hat-collector (Excess Flood)
2022-08-30 05:46:16 INFO     Syncing report channels
2022-08-30 05:46:16 INFO     Running query: SELECT lower(name) FROM channels
2022-08-30 05:46:16 INFO     Syncing rules
2022-08-30 05:46:16 INFO     Running query: SELECT wiki, type, pattern, lower(channel), ignore FROM rules ORDER BY ignore DESC
2022-08-30 05:46:17 ERROR    Encountered error on socket.
pydle.features.rfc1459.protocol.ServerError: Closing Link: wikimedia/bot/hat-collector (Excess Flood)
2022-08-30 05:46:21 INFO     Syncing report channels
2022-08-30 05:46:21 INFO     Running query: SELECT lower(name) FROM channels
2022-08-30 05:46:21 INFO     Syncing rules
2022-08-30 05:46:21 INFO     Running query: SELECT wiki, type, pattern, lower(channel), ignore FROM rules ORDER BY ignore DESC
2022-08-30 05:46:22 ERROR    Task exception was never retrieved
future: <Task finished name='Task-1039' coro=<BasicClient.handle_forever() done, defined at /data/project/hat-collector/.local/share/virtualenvs/hat-collector-beta-Vi1f6vgq/lib/python3.9/site-packages/pydle/client.py:363> exception=SSLError(1, '[SSL: APPLICATION_DATA_AFTER_CLOSE_NOTIFY] application data after close notify (_ssl.c:2745)')>
Traceback (most recent call last):
  File "/data/project/hat-collector/.local/share/virtualenvs/hat-collector-beta-Vi1f6vgq/lib/python3.9/site-packages/pydle/client.py", line 367, in handle_forever
    data = await self.connection.recv(timeout=self.READ_TIMEOUT)
  File "/data/project/hat-collector/.local/share/virtualenvs/hat-collector-beta-Vi1f6vgq/lib/python3.9/site-packages/pydle/connection.py", line 115, in recv
    return await asyncio.wait_for(self.reader.readline(), timeout=timeout)
  File "/usr/lib/python3.9/asyncio/tasks.py", line 481, in wait_for
    return fut.result()
  File "/usr/lib/python3.9/asyncio/streams.py", line 540, in readline
    line = await self.readuntil(sep)
  File "/usr/lib/python3.9/asyncio/streams.py", line 632, in readuntil
    await self._wait_for_data('readuntil')
  File "/usr/lib/python3.9/asyncio/streams.py", line 517, in _wait_for_data
    await self._waiter
  File "/usr/lib/python3.9/asyncio/sslproto.py", line 528, in data_received
    ssldata, appdata = self._sslpipe.feed_ssldata(data)
  File "/usr/lib/python3.9/asyncio/sslproto.py", line 206, in feed_ssldata
    self._sslobj.unwrap()
  File "/usr/lib/python3.9/ssl.py", line 948, in unwrap
    return self._sslobj.shutdown()
ssl.SSLError: [SSL: APPLICATION_DATA_AFTER_CLOSE_NOTIFY] application data after close notify (_ssl.c:2745)

Environment:

L235 commented 2 years ago

Hm, the restart is not working:

2022-08-30 07:21:58 ERROR    Task exception was never retrieved
future: <Task finished name='Task-5' coro=<BasicClient.handle_forever() done, defined at /data/project/hat-collector/.local/share/virtualenvs/hat-collector-beta-Vi1f6vgq/lib/python3.9/site-packages/pydle/client.py:363> exception=SSLError(1, '[SSL: APPLICATION_DATA_AFTER_CLOSE_NOTIFY] application data after close notify (_ssl.c:2745)')>
Traceback (most recent call last):
  File "/data/project/hat-collector/.local/share/virtualenvs/hat-collector-beta-Vi1f6vgq/lib/python3.9/site-packages/pydle/client.py", line 367, in handle_forever
    data = await self.connection.recv(timeout=self.READ_TIMEOUT)
  File "/data/project/hat-collector/.local/share/virtualenvs/hat-collector-beta-Vi1f6vgq/lib/python3.9/site-packages/pydle/connection.py", line 115, in recv
    return await asyncio.wait_for(self.reader.readline(), timeout=timeout)
  File "/usr/lib/python3.9/asyncio/tasks.py", line 481, in wait_for
    return fut.result()
  File "/usr/lib/python3.9/asyncio/streams.py", line 540, in readline
    line = await self.readuntil(sep)
  File "/usr/lib/python3.9/asyncio/streams.py", line 632, in readuntil
    await self._wait_for_data('readuntil')
  File "/usr/lib/python3.9/asyncio/streams.py", line 517, in _wait_for_data
    await self._waiter
  File "/usr/lib/python3.9/asyncio/sslproto.py", line 528, in data_received
    ssldata, appdata = self._sslpipe.feed_ssldata(data)
  File "/usr/lib/python3.9/asyncio/sslproto.py", line 206, in feed_ssldata
    self._sslobj.unwrap()
  File "/usr/lib/python3.9/ssl.py", line 948, in unwrap
    return self._sslobj.shutdown()
ssl.SSLError: [SSL: APPLICATION_DATA_AFTER_CLOSE_NOTIFY] application data after close notify (_ssl.c:2745)
L235 commented 2 years ago

I have determined that the proximate cause of the Excess Flood (pydle.features.rfc1459.protocol.ServerError: Closing Link: wikimedia/bot/hat-collector (Excess Flood)) was having too many channels all at once at the beginning. Joining 21 channels was OK; 22 caused the Excess Flood error.

PhantomTech commented 2 years ago

I've added rate limiting to sync_channels() on the branch

PhantomTech commented 2 years ago

Done better in #30

L235 commented 2 years ago

I'm gonna chalk the bot's failure to recover from the exception to the specifics of the Excess Flood, not the bot's general failure to try to reconnect. I think we can therefore close this.