Closed logan2611 closed 4 years ago
Attempted to reproduce, using sample Echo example modified to point my IRC server.
$ cat example.py
import pydle
# Simple echo bot.
class MyOwnBot(pydle.Client):
async def on_connect(self):
await self.join('#unkn0wndev')
async def on_message(self, target, source, message):
# don't respond to our own messages, as this leads to a positive feedback loop
if source != self.nickname:
await self.message(target, message)
client = MyOwnBot('MyBot', realname='My Bot')
client.run('localhost', tls=True, tls_verify=False)
using constraint of chanserv setting +q on user join.
Test setup: using IRC environment https://github.com/theunkn0wn1/unrealircd_docker
Configured #unkn0wndev
to be owned by idented user unknown
so +q is set by chanserv when that user connects.
Test run:
example.py
$ python example.py
Unknown command: [irc.unknown.com] 396 ['MyBot', '161D248E.B897F01F.3F699B1A.IP', 'is now your displayed host']
* ChanServ sets mode +q on #unkn0wndev unknown
* ChanServ gives channel operator status to unknown
<unknown> pung
<MyBot> pung
<unknown> ping
<MyBot> ping
<unknown> pong
<MyBot> pong```
@logan2611 by chance can you point me at a server that would emit this nick not registered message?
Unable to reproduce without further information, can you please add this to the top of example.py
and reproduce?
import logging
logging.basicConfig(level=logging.DEBUG)
Peering at code, looks like it has to do with IRCv3 tags not getting processed correctly. https://github.com/Shizmob/pydle/blob/develop/pydle/features/ircv3/tags.py#L65 in specific is most suspect. I would still appreciate some debug logs showing the message pydle is having a hickup over to verify.
Here are those debug logs, starting after the MOTD. I can only seem to reliablely recreate this issue on my own IRC server. I am using Inspircd and Anope for services by the way.
DEBUG:MyOwnBot:(servername):>> JOIN #logan2611
DEBUG:MyOwnBot:(servername):<< :irc.(domain) NOTICE MyBot :*** You are connected to irc.(domain) using TLS (SSL) cipher 'TLS1.3-ECDHE-RSA-AES-256-GCM-AEAD'
DEBUG:MyOwnBot:(servername):<< :MyBot!mybot@(ip) JOIN #logan2611 * :My Bot
DEBUG:MyOwnBot:(servername):>> MODE #logan2611
DEBUG:MyOwnBot:(servername):>> WHO #logan2611 %tnurha,542
DEBUG:MyOwnBot:(servername):<< :irc.(domain) 332 MyBot #logan2611 :(channel description)
DEBUG:MyOwnBot:(servername):<< :irc.(domain) 333 MyBot #logan2611 logan2611 :1602201541
DEBUG:MyOwnBot:(servername):<< :irc.(domain) 353 MyBot = #logan2611 :&@ChanServ!services@services.(domain) MyBot!mybot@(ip)
DEBUG:MyOwnBot:(servername):<< :irc.(domain) 366 MyBot #logan2611 :End of /NAMES list.
DEBUG:MyOwnBot:(servername):<< :irc.(domain) 324 MyBot #logan2611 :+nrt
DEBUG:MyOwnBot:(servername):<< :irc.(domain) 329 MyBot #logan2611 :1601968270
DEBUG:MyOwnBot:(servername):<< :irc.(domain) 354 MyBot 542 services services.(domain) ChanServ 0 :Channel Registration Service
DEBUG:MyOwnBot:(servername):<< :irc.(domain) 354 MyBot 542 mybot (ip) MyBot 0 :My Bot
DEBUG:MyOwnBot:(servername):<< :irc.(domain) 315 MyBot #logan2611 :End of /WHO list.
DEBUG:MyOwnBot:(servername):<< @account=logan2611 :logan26111!logan2611@(ip) JOIN #logan2611 logan2611 :realname
ERROR:asyncio:Task exception was never retrieved
future: <Task finished name='Task-2' coro=<BasicClient.handle_forever() done, defined at /mnt/hdd/Documents/ExampleBot/lib/python3.8/site-packages/pydle/client.py:363> exception=AttributeError("'bool' object has no attribute 'replace'")>
Traceback (most recent call last):
File "/mnt/hdd/Documents/ExampleBot/lib/python3.8/site-packages/pydle/client.py", line 382, in handle_forever
await self.on_data(data)
File "/mnt/hdd/Documents/ExampleBot/lib/python3.8/site-packages/pydle/client.py", line 391, in on_data
message = self._parse_message()
File "/mnt/hdd/Documents/ExampleBot/lib/python3.8/site-packages/pydle/features/ircv3/tags.py", line 121, in _parse_message
return TaggedMessage.parse(message + sep, encoding=self.encoding)
File "/mnt/hdd/Documents/ExampleBot/lib/python3.8/site-packages/pydle/features/ircv3/tags.py", line 70, in parse
value = value.replace(escape, replacement)
AttributeError: 'bool' object has no attribute 'replace'
Looks like it is be getting hung up on :ChanServ!services@services.(domain) MODE #logan2611 +qo logan2611 :logan2611
since when I join another channel I get DEBUG:MyOwnBot:(servername):<< @account=logan2611 :logan26111!logan2611@(ip) JOIN #lolfunnymeme logan2611 :realname
without an error.
Peering at code, looks like it has to do with IRCv3 tags not getting processed correctly. https://github.com/Shizmob/pydle/blob/develop/pydle/features/ircv3/tags.py#L65 in specific is most suspect.
After studying that bit for a moment, I understand that it's handling tags that have no value. Per current IRCv3 docs, tag values are optional, though it is not specified how valueless tags should be interpreted, likely to allow for flexibility in tag semantics. Regardless, a boolean True
value is a logical interpretation of a valueless tag, as in the rose
example here. As far as I'm concerned, that block is mostly fine1 in and of itself.
[EDITED]: Forgot to include the second loop
The problem is in the next two blocks:
https://github.com/Shizmob/pydle/blob/514ad98f5b1640a589e7b5376a2b9f5c47bde2b5/pydle/features/ircv3/tags.py#L69-L76
Here, value
is assumed to always be a string, even though we know it can sometimes be True
. These two loops should only run when value
is a string, but since it isn't, we get the described AttributeError
.
Based on the exception, we can deduce that the problematic message includes a valueless tag. We don't know what the message payload looks like since the exception is thrown in _parse_message
just before on_raw
has a chance to log the message. However, based on the fault above, the specific tag is irrelevant to the fact that valueless tags are handled incorrectly. Regardless, knowing could provide a useful basis for a regression test, so it should be easy enough to obtain with a simple on_data
extension. @logan2611 would just have to add the following:
async def on_data(self, data):
print(f'**!** {data=}')
await super().on_data(data)
Then the offending message should be spat out just before the exception.
1: It doesn't correctly handle empty tag values. Per spec:
Implementations MUST interpret empty tag values (e.g.
foo=
) as equivalent to missing tag values (e.g. foo). Specifications MUST NOT differentiate meaning between tags with empty and missing values.
As that block is currently written, an empty tag would cause value
to be ''
. This should be addressed in another issue.
I can reproduce this exception on the develop
branch by injecting a fake, valueless tag into the data before it gets passed to _parse_message
. Here is the minimal test case I used:
import pydle
class Bot(pydle.Client):
async def on_connect(self):
print('connected')
async def on_data(self, data):
if b'PRIVMSG' in data and b'005' not in data:
# Inject tags into message
data = b'@empty=;missing ' + data
print(data)
await super().on_data(data)
bot = Bot('pydle_test_bot')
bot.run('irc.freenode.net')
The trigger is a (rather lazily detected) PRIVMSG
from any source. Conveniently, Freenode's frigg bot will send a CTCP VERSION
on connection, which automates things a bit. I included both an empty tag and a valueless tag for the sake of completeness, but as mentioned the exception is tied to the latter. Here is the output, if anyone is interested:
[snip] connection registration and MOTD [/snip]
connected
b':pydle_test_bot_ MODE pydle_test_bot_ :+i\r\n'
b':freenode-connect!frigg@freenode/utility-bot/frigg NOTICE pydle_test_bot_ :Welcome to freenode. To protect the network all new connections will be scanned for vulnerabilities. This will not harm your computer, and vulnerable hosts will be notified.\r\n'
b'@empty=;missing :freenode-connect!frigg@freenode/utility-bot/frigg PRIVMSG pydle_test_bot_ :\x01VERSION\x01\r\n'
Task exception was never retrieved
future: <Task finished name='Task-2' coro=<BasicClient.handle_forever() done, defined at /home/zeroknight/repo/pydle/pydle/client.py:363> exception=AttributeError("'bool' object has no attribute 'replace'")>
Traceback (most recent call last):
File "/home/zeroknight/repo/pydle/pydle/client.py", line 382, in handle_forever
await self.on_data(data)
File "./testbot.py", line 15, in on_data
await super().on_data(data)
File "/home/zeroknight/repo/pydle/pydle/client.py", line 391, in on_data
message = self._parse_message()
File "/home/zeroknight/repo/pydle/pydle/features/ircv3/tags.py", line 121, in _parse_message
return TaggedMessage.parse(message + sep, encoding=self.encoding)
File "/home/zeroknight/repo/pydle/pydle/features/ircv3/tags.py", line 70, in parse
value = value.replace(escape, replacement)
AttributeError: 'bool' object has no attribute 'replace'
Thanks, can reproduce with your test case there @ZeroKnight .
When I pointed out the tag being set to True, I very much was just thinking about the datatype mismatch.
In the case where a tag doesn't have a value, Pydle appears to use them as flags and sets them to True.
You do appear to be correct in that pydle does not normalize empty to missing, so we have two issues here.
committing the missing
tag as-is without doing the post-processing escape sequence processing as we do for full tags avoids the exception in the OP but doesn't normalize the tags as per the spec.
Methinks if we checked if the value after the tag is an empty string we could use the same logic for empty=
as missing
there appears to be an existing test for this feature that can be extended, can reproduce with existing test + new test case.
(
rb"@empty=;missing :unknown!orion@161D248E.B897F01F.3F699B1A.IP PRIVMSG #unkn0wndev :ping",
{"empty": True, "missing": True}
),
To get the ball rolling a bit, I started a pull request that should fix this issue. Using my same test case with this change, pydle throws no exception. I enabled contributor pushing, in case you'd like to add a commit for that new test case you mentioned.
Although it looks like a solution has already been mentioned, I'll still paste my logs to be sure, and also test the PR.
**!** data=b'@account=logan2611 :logan2611!logan2611@(ip) JOIN #logan2611 logan2611 :realname\r\n'
DEBUG:MyOwnBot:(servername):<< @account=logan2611 :logan2611!logan2611@(ip) JOIN #logan2611 logan2611 :realname
**!** data=b'@inspircd.org/service;inspircd.org/bot :ChanServ!services@services.(domain) MODE #logan2611 +qo logan2611 :logan2611\r\n'
ERROR:asyncio:Task exception was never retrieved
future: <Task finished name='Task-2' coro=<BasicClient.handle_forever() done, defined at /mnt/hdd/Documents/ExampleBot/lib/python3.8/site-packages/pydle/client.py:363> exception=AttributeError("'bool' object has no attribute 'replace'")>
Traceback (most recent call last):
File "/mnt/hdd/Documents/ExampleBot/lib/python3.8/site-packages/pydle/client.py", line 382, in handle_forever
await self.on_data(data)
File "example.py", line 13, in on_data
await super().on_data(data)
File "/mnt/hdd/Documents/ExampleBot/lib/python3.8/site-packages/pydle/client.py", line 391, in on_data
message = self._parse_message()
File "/mnt/hdd/Documents/ExampleBot/lib/python3.8/site-packages/pydle/features/ircv3/tags.py", line 121, in _parse_message
return TaggedMessage.parse(message + sep, encoding=self.encoding)
File "/mnt/hdd/Documents/ExampleBot/lib/python3.8/site-packages/pydle/features/ircv3/tags.py", line 70, in parse
value = value.replace(escape, replacement)
AttributeError: 'bool' object has no attribute 'replace'
^CTraceback (most recent call last):
File "example.py", line 21, in <module>
client.run('irc.(domain)', tls=True, tls_verify=False)
File "/mnt/hdd/Documents/ExampleBot/lib/python3.8/site-packages/pydle/client.py", line 108, in run
self.eventloop.run_forever()
File "/usr/lib/python3.8/asyncio/base_events.py", line 570, in run_forever
self._run_once()
File "/usr/lib/python3.8/asyncio/base_events.py", line 1823, in _run_once
event_list = self._selector.select(timeout)
File "/usr/lib/python3.8/selectors.py", line 468, in select
fd_event_list = self._selector.poll(timeout, max_ev)
KeyboardInterrupt
data=b'@inspircd.org/service;inspircd.org/bot :ChanServ!services@services.(domain) MODE #logan2611 +qo logan2611 :logan2611\r\n'
Ah, as expected, two valueless tags. Thanks for getting back, @logan2611!
Hi, I was making a simple IRC bot and I noticed that sometimes the bot would seemingly randomly stop working. After some debugging, I eventually figured out that the bot stopped working whenever I joined the channel. I also noticed that on my private IRC server the bot would crash with the same error when NickServ notified the bot that its nickname wasn't registered.
Steps to reproduce:
Error: