Bug in using sasl authentication in combination with timeout triggers a timeout

[mjrider]

PING is not allowed until the connection is completed aka 001 is received from the server in case that it is used as a client
Except the irc3 core plugin send it directly after the user..nick.
This is correct, unless you use sasl authentication, then the sequence is CAP LS / USER / NICK / CAP REQ / ..... / CAP END / PING except with irc3 the sequence it send is CAP LS / USER / NICK / PING / CAP REQ /...../ CAP END

the server will ignore the invalid ping request, and then the irc3 timeouts and reconnect.

Reproduction

• take the examples/humans.py
• add sasl_username and sasl_password to the config
• connect to a server which supports sasl
• remove the 1 of the clients to make it easier to debug

command for running this script: strace -e trace=network -f ./.venv/bin/python test1.py

[pid 447493] recvfrom(6, ":livetest.localhost 020 * :Please wait while we process your connection.\r\n", 262144, 0, NULL, NULL) = 74
[pid 447493] sendto(6, "CAP LS\r\n", 8, 0, NULL, 0) = 8
[pid 447493] sendto(6, "USER irc3 0 * :Irc bot based on irc3 http://irc3.readthedocs.io\r\nNICK jacky\r\n", 77, 0, NULL, 0) = 77
[pid 447493] sendto(6, "PING :884974\r\n", 14, 0, NULL, 0) = 14
[pid 447493] recvfrom(6, ":livetest.localhost CAP * LS :extended-join ircnet.com/extended-join multi-prefi"..., 262144, 0, NULL, NULL) = 141
[pid 447493] sendto(6, "CAP REQ :sasl\r\n", 15, 0, NULL, 0) = 15
[pid 447493] recvfrom(6, ":livetest.localhost CAP jacky ACK :sasl \r\n", 262144, 0, NULL, NULL) = 42
[pid 447493] sendto(6, "AUTHENTICATE PLAIN\r\n", 20, 0, NULL, 0) = 20
[pid 447493] recvfrom(6, "AUTHENTICATE +\r\n", 262144, 0, NULL, NULL) = 16
[pid 447493] sendto(6, "AUTHENTICATE dXNlcjEAdXNlcjEAdXNlcjEtcGFzc3dvcmQxMjM=\r\n", 55, 0, NULL, 0) = 55
[pid 447493] recvfrom(6, ":livetest.localhost 900 jacky [email protected] user1 :You are now lo"..., 262144, 0, NULL, NULL) = 162
[pid 447493] sendto(6, "CAP END\r\n", 9, 0, NULL, 0) = 9
[pid 447493] recvfrom(6, ":livetest.localhost 001 jacky :Welcome to the Internet Relay Network jacky!~irc3"..., 262144, 0, NULL, NULL) = 1037
[pid 447493] recvfrom(6, ":livetest.localhost 265 jacky 2 2 :Current local users 2, max 2\r\n:livetest.local"..., 262144, 0, NULL, NULL) = 305
INFO irc3.jacky Server config: {'STATUSMSG': '+@', 'PREFIX': '(ov)@+', 'CHANTYPES': '#&!+', 'CHANMODES': 'beIR,k,l,imnpstaqr', 'RFC2812': True, 'MODES': '3', 'CHANLIMIT': '#&!+:101', 'NICKLEN': '15', 'TOPICLEN': '255', 'KICKLEN': '255', 'MAXLIST': 'beIR:64', 'CHANNELLEN': '50', 'IDCHAN': '!:5', 'PENALTY': True, 'FNC': True, 'WHOX': True, 'EXCEPTS': 'e', 'INVEX': 'I', 'CASEMAPPING': 'ascii', 'NETWORK': 'IRCnet'}
INFO irc3.jacky Trying to join #irc3
[pid 447493] sendto(6, "JOIN #irc3\r\n", 12, 0, NULL, 0) = 12
[pid 447493] recvfrom(6, ":[email protected] JOIN :#irc3\r\n:livetest.localhost 353 jacky = #irc"..., 262144, 0, NULL, NULL) = 154
INFO irc3.jacky We're waiting a ping for too long. Trying to reconnect...

this is from againts ircnet, but the same happens on more networks

workaround

remove timeout entry in the config, then the ping/pong sequence is not started on connection