Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

sasl auth often fails with errors in asynchat/asyncore #180

Open
solidgoldbomb opened this issue May 30, 2015 · 0 comments
Open

sasl auth often fails with errors in asynchat/asyncore #180

solidgoldbomb opened this issue May 30, 2015 · 0 comments

Comments

@solidgoldbomb
Copy link
Contributor

I've been regularly seeing authentication failures with SASL on connect. These failures coincide with errors (from asynchat) showing up on the jenni console. I have reduced my config to having only the sasl module enabled. This issue occurs with/without SSL enabled so I can also capture the TCP stream with wireshark.

This doesn't happen 100% of the time, but is very repeatable, so if there are any tests you would like me to run, just let me know.

This test was run against 15c076a but this was also happening before the recent merges.

my config

# Lines that begin with a "#" are comments.
# Remove the "#" from the beginning of a line to make those lines active.

name = 'sgb-bot, based on jenni'
nick = 'solidgoldbomb'
host = 'irc.freenode.net'
port = 6667
ssl  = False
sasl = True
channels = ['###sgb-bot-test',]

# You can also specify nick@hostmask
# For example: yano@unaffiliated/yano
owner = 'me'

# password is the NickServ password, serverpass is the server password
password = 'thepasswordforthisaccount'

# These are people who will be able to use admin.py's functions...
admins = [owner,]

# Enable raw logging of everything jenni sees.
# logged to the folder 'log'
logging = True

# Block modules from specific channels
# To not block anything for a channel, just don't mention it
excludes = {}

# If you want to enumerate a list of modules rather than disabling
# some, use "enable = ['example']", which takes precedent over exclude
#
enable = [
    'sasl',
]

# EOF

jenni console

$ ./jenni -c ~/.jenni/solidgoldbomb.py
Registered modules: sasl
(.*) | sasl.irc_001, high priority
(.*) | sasl.irc_903, high priority
(.*) | sasl.irc_904, high priority
(.*) | sasl.irc_905, high priority
(.*) | sasl.irc_906, high priority
(.*) | sasl.irc_907, high priority
(.*) | sasl.irc_authenticated, high priority
(.*) | sasl.irc_cap, high priority
Connecting to irc.freenode.net:6667... connected!
1433026626.33
[__WRITE FAILED] deque index out of range
1433026626.43
[__WRITE FAILED] deque index out of range
1433026626.57
[__WRITE FAILED] deque index out of range
Traceback (most recent call last):
  File "/usr/lib/python2.7/asyncore.py", line 91, in write
    obj.handle_write_event()
  File "/usr/lib/python2.7/asyncore.py", line 468, in handle_write_event
    self.handle_write()
  File "/usr/lib/python2.7/asynchat.py", line 174, in handle_write
    self.initiate_send()
  File "/usr/lib/python2.7/asynchat.py", line 244, in initiate_send
    del self.producer_fifo[0]
IndexError: deque index out of range

1433026628.32
[__WRITE FAILED] deque index out of range
1433026630.28
[__WRITE FAILED] deque index out of range

From the raw.log file, it is clear that something is going wrong. From the packet capture, you can see that messages are doubled-up which causes issues with AUTHENTICATE.

raw.log (passwords sanitized)

1433026617.23   CAP LS
1433026617.23   NICK solidgoldbomb
1433026617.23   USER solidgoldbomb +iw solidgoldbomb :sgb-bot, based on jenni
1433026617.33   :orwell.freenode.net NOTICE * :*** Looking up your hostname...
1433026617.43   :orwell.freenode.net NOTICE * :*** Checking Ident
1433026617.43   :orwell.freenode.net NOTICE * :*** Found your hostname
1433026626.22   :orwell.freenode.net NOTICE * :*** No Ident response
1433026626.32   :orwell.freenode.net CAP * LS :account-notify extended-join identify-msg multi-prefix sasl
1433026626.43   :orwell.freenode.net CAP solidgoldbomb ACK :multi-prefix sasl 
1433026626.57   :orwell.freenode.net CAP solidgoldbomb ACK :multi-prefix sasl 
1433026626.68   AUTHENTICATE +
1433026626.68   AUTHENTICATE aGFoYSwgeW91IHRob3VnaHQgaXQgd291bGQgYmUgbXkgcGFzc3dvcmQK
1433026627.27   :orwell.freenode.net 904 solidgoldbomb :SASL authentication failed
1433026627.27   CAP END
1433026628.32   AUTHENTICATE +
1433026629.27   :orwell.freenode.net 904 solidgoldbomb :SASL authentication failed
1433026629.27   CAP END
1433026630.28   :orwell.freenode.net 904 solidgoldbomb :SASL authentication failed
1433026631.27   :orwell.freenode.net 904 solidgoldbomb :SASL authentication failed
1433026631.27   CAP END
1433026632.26   :orwell.freenode.net 906 solidgoldbomb :SASL authentication aborted
1433026632.26   CAP END
1433026632.26   :orwell.freenode.net 001 solidgoldbomb :Welcome to the freenode Internet Relay Chat Network solidgoldbomb
1433026632.27   :orwell.freenode.net 002 solidgoldbomb :Your host is orwell.freenode.net[185.30.166.38/6667], running version ircd-seven-1.1.3
1433026632.27   :orwell.freenode.net 003 solidgoldbomb :This server was created Sun Mar 15 2015 at 18:30:44 UTC
1433026632.27   :orwell.freenode.net 004 solidgoldbomb orwell.freenode.net ircd-seven-1.1.3 DOQRSZaghilopswz CFILMPQSbcefgijklmnopqrstvz bkloveqjfI
1433026632.27   :orwell.freenode.net 005 solidgoldbomb CHANTYPES=# EXCEPTS INVEX CHANMODES=eIbq,k,flj,CFLMPQScgimnprstz CHANLIMIT=#:120 PREFIX=(ov)@+ MAXLIST=bqeI:100 MODES=4 NETWORK=freenode KNOCK STATUSMSG=@+ CALLERID=g :are supported by this server
1433026632.27   :orwell.freenode.net 005 solidgoldbomb CASEMAPPING=rfc1459 CHARSET=ascii NICKLEN=16 CHANNELLEN=50 TOPICLEN=390 ETRACE CPRIVMSG CNOTICE DEAF=D MONITOR=100 FNC TARGMAX=NAMES:1,LIST:1,KICK:1,WHOIS:1,PRIVMSG:4,NOTICE:4,ACCEPT:,MONITOR: :are supported by this server
1433026632.27   :orwell.freenode.net 005 solidgoldbomb EXTBAN=$,ajrxz WHOX CLIENTVER=3.0 SAFELIST ELIST=CTU :are supported by this server
1433026632.27   :orwell.freenode.net 251 solidgoldbomb :There are 158 users and 84429 invisible on 27 servers
1433026632.27   :orwell.freenode.net 252 solidgoldbomb 22 :IRC Operators online
1433026632.27   :orwell.freenode.net 253 solidgoldbomb 9 :unknown connection(s)
1433026632.27   :orwell.freenode.net 254 solidgoldbomb 58549 :channels formed
1433026632.27   :orwell.freenode.net 255 solidgoldbomb :I have 3440 clients and 1 servers
1433026632.27   :orwell.freenode.net 265 solidgoldbomb 3440 4308 :Current local users 3440, max 4308
1433026632.27   :orwell.freenode.net 266 solidgoldbomb 84587 97572 :Current global users 84587, max 97572
1433026632.27   :orwell.freenode.net 250 solidgoldbomb :Highest connection count: 4309 (4308 clients) (306857 connections received)
1433026632.27   :orwell.freenode.net 375 solidgoldbomb :- orwell.freenode.net Message of the Day - 
1433026632.27   :orwell.freenode.net 372 solidgoldbomb :- Welcome to orwell.freenode.net in Amsterdam, NL.
...
1433026632.37   :orwell.freenode.net 376 solidgoldbomb :End of /MOTD command.
1433026632.37   :solidgoldbomb MODE solidgoldbomb :+i
1433026632.37   :NickServ!NickServ@services. NOTICE solidgoldbomb :This nickname is registered. Please choose a different nickname, or identify via �/msg NickServ identify <password>�.
1433026632.37   :NickServ!NickServ@services. NOTICE solidgoldbomb :You have 30 seconds to identify to your nickname before it is changed.

tcp stream captured in wireshark (passwords sanitized)

CAP LS
:orwell.freenode.net NOTICE * :*** Looking up your hostname...
NICK solidgoldbomb
USER solidgoldbomb +iw solidgoldbomb :sgb-bot, based on jenni
:orwell.freenode.net NOTICE * :*** Checking Ident
:orwell.freenode.net NOTICE * :*** Found your hostname
:orwell.freenode.net NOTICE * :*** No Ident response
:orwell.freenode.net CAP * LS :account-notify extended-join identify-msg multi-prefix sasl
CAP REQ :multi-prefix sasl
CAP REQ :multi-prefix sasl
:orwell.freenode.net CAP solidgoldbomb ACK :multi-prefix sasl 
:orwell.freenode.net CAP solidgoldbomb ACK :multi-prefix sasl 
AUTHENTICATE PLAIN
AUTHENTICATE PLAIN
AUTHENTICATE +
AUTHENTICATE PLAIN
AUTHENTICATE PLAIN
AUTHENTICATE aGFoYSwgeW91IHRob3VnaHQgaXQgd291bGQgYmUgbXkgcGFzc3dvcmQK
AUTHENTICATE aGFoYSwgeW91IHRob3VnaHQgaXQgd291bGQgYmUgbXkgcGFzc3dvcmQK
:orwell.freenode.net 904 solidgoldbomb :SASL authentication failed
CAP END
AUTHENTICATE +
AUTHENTICATE aGFoYSwgeW91IHRob3VnaHQgaXQgd291bGQgYmUgbXkgcGFzc3dvcmQK
AUTHENTICATE aGFoYSwgeW91IHRob3VnaHQgaXQgd291bGQgYmUgbXkgcGFzc3dvcmQK
:orwell.freenode.net 904 solidgoldbomb :SASL authentication failed
CAP END
:orwell.freenode.net 904 solidgoldbomb :SASL authentication failed
CAP END
CAP END
:orwell.freenode.net 904 solidgoldbomb :SASL authentication failed
CAP END
:orwell.freenode.net 906 solidgoldbomb :SASL authentication aborted
:orwell.freenode.net 001 solidgoldbomb :Welcome to the freenode Internet Relay Chat Network solidgoldbomb
:orwell.freenode.net 002 solidgoldbomb :Your host is orwell.freenode.net[185.30.166.38/6667], running version ircd-seven-1.1.3
:orwell.freenode.net 003 solidgoldbomb :This server was created Sun Mar 15 2015 at 18:30:44 UTC
:orwell.freenode.net 004 solidgoldbomb orwell.freenode.net ircd-seven-1.1.3 DOQRSZaghilopswz CFILMPQSbcefgijklmnopqrstvz bkloveqjfI
:orwell.freenode.net 005 solidgoldbomb CHANTYPES=# EXCEPTS INVEX CHANMODES=eIbq,k,flj,CFLMPQScgimnprstz CHANLIMIT=#:120 PREFIX=(ov)@+ MAXLIST=bqeI:100 MODES=4 NETWORK=freenode KNOCK STATUSMSG=@+ CALLERID=g :are supported by this server
:orwell.freenode.net 005 solidgoldbomb CASEMAPPING=rfc1459 CHARSET=ascii NICKLEN=16 CHANNELLEN=50 TOPICLEN=390 ETRACE CPRIVMSG CNOTICE DEAF=D MONITOR=100 FNC TARGMAX=NAMES:1,LIST:1,KICK:1,WHOIS:1,PRIVMSG:4,NOTICE:4,ACCEPT:,MONITOR: :are supported by this server
:orwell.freenode.net 005 solidgoldbomb EXTBAN=$,ajrxz WHOX CLIENTVER=3.0 SAFELIST ELIST=CTU :are supported by this server
:orwell.freenode.net 251 solidgoldbomb :There are 158 users and 84429 invisible on 27 servers
:orwell.freenode.net 252 solidgoldbomb 22 :IRC Operators online
:orwell.freenode.net 253 solidgoldbomb 9 :unknown connection(s)
:orwell.freenode.net 254 solidgoldbomb 58549 :channels formed
:orwell.freenode.net 255 solidgoldbomb :I have 3440 clientCAP END
s and 1 servers
:orwell.freenode.net 265 solidgoldbomb 3440 4308 :Current local users 3440, max 4308
:orwell.freenode.net 266 solidgoldbomb 84587 97572 :Current global users 84587, max 97572
:orwell.freenode.net 250 solidgoldbomb :Highest connection count: 4309 (4308 clients) (306857 connections received)
:orwell.freenode.net 375 solidgoldbomb :- orwell.freenode.net Message of the Day - 
:orwell.freenode.net 372 solidgoldbomb :- Welcome to orwell.freenode.net in Amsterdam, NL.
...
:orwell.freenode.net 376 solidgoldbomb :End of /MOTD command.
:solidgoldbomb MODE solidgoldbomb :+i
:NickServ!NickServ@services. NOTICE solidgoldbomb :This nickname is registered. Please choose a different nickname, or identify via ./msg NickServ identify <password>..
:NickServ!NickServ@services. NOTICE solidgoldbomb :You have 30 seconds to identify to your nickname before it is changed.
@kaneda kaneda added this to the Short Term milestone Jun 1, 2015
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

2 participants