ackwell / ninjabot

Ninjabot is not 'Just Another Bot'
10 stars 8 forks source link

linkinfo: race condition #96

Closed gnustomp closed 9 years ago

gnustomp commented 10 years ago

During the processing of URLs, there is a race condition in which two requests are made to the server and information sent to the channel twice. Related error:

ERROR DURING TASK EXECUTION deque index out of range
Traceback (most recent call last):
  File "/home/notackwell/ninjabot/kronos.py", line 469, in threadedcall
    self.execute()
  File "/home/notackwell/ninjabot/kronos.py", line 314, in execute
    self.action(*self.args, **self.kw)
  File "./ninjabot.py", line 232, in send_queue
    self.irc_send(message, now=True)
  File "./ninjabot.py", line 215, in irc_send
    self.push(message_bytes)
  File "/usr/lib/python3.4/asynchat.py", line 190, in push
    self.initiate_send()
  File "/usr/lib/python3.4/asynchat.py", line 250, in initiate_send
    del self.producer_fifo[0]
IndexError: deque index out of range
auscompgeek commented 10 years ago

Are you entirely sure two GET requests are being made to the HTTP server? Remember, linkinfo sends a HEAD request before sending a GET request if it's text/html.

This looks like a race condition whilst sending the message to the IRC server.

Most likely related: issue #92

ackwell commented 10 years ago

Reading over #92, it seems that it was also occurring when linkinfo fired.

Can we confirm if it's a bug with the queue, or a bug in the queue induced by linkinfo, perhaps? I'm yet to hear of a similar issue from any other plugins.

gnustomp commented 10 years ago

s/GET/HEAD/g On 26 Jul 2014 23:00, "David" notifications@github.com wrote:

Are you entirely sure two GET requests are being made to the HTTP server? Remember, linkinfo sends a HEAD request before sending a GET request if it's text/html.

This looks like a race condition whilst sending the message to the IRC server.

Most likely related: issue #92 https://github.com/ackwell/ninjabot/issues/92

— Reply to this email directly or view it on GitHub https://github.com/ackwell/ninjabot/issues/96#issuecomment-50233409.

auscompgeek commented 9 years ago

can confirm this is not a bug induced by linkinfo, we just triggered this race condition with regex:

:benonsoftware!benny@ubuntu/member/benonsoftware PRIVMSG ##hypnotoad :s/victim/"patient"/
ERROR DURING TASK EXECUTION deque index out of range
Traceback (most recent call last):
  File "/home/notackwell/ninjabot/kronos.py", line 469, in threadedcall
    self.execute()
  File "/home/notackwell/ninjabot/kronos.py", line 314, in execute
    self.action(*self.args, **self.kw)
  File "./ninjabot.py", line 232, in send_queue
    self.irc_send(message, now=True)
  File "./ninjabot.py", line 215, in irc_send
    self.push(message_bytes)
  File "/usr/lib/python3.4/asynchat.py", line 190, in push
    self.initiate_send()
  File "/usr/lib/python3.4/asynchat.py", line 250, in initiate_send
    del self.producer_fifo[0]
IndexError: deque index out of range

--------------------
<benonsoftware> s/victim/"patient"/
<NCSSBot> benonsoftware meant to say: loadedice can be the first "patient"
<NCSSBot> benonsoftware meant to say: loadedice can be the first "patient"
auscompgeek commented 9 years ago

So, yeah. This bug is presumably a bug in asynchat, seeing as this occurs in other bots that use asynchat as well (see: myano/jenni).