phergie/phergie-irc-bot-react

Potential event queue issue

Closed this issue · 28 comments

See this gist. For some reason, the second connection appears to be using the autojoin channels for the first. The simplicity of the AutoJoin plugin suggests that this is an issue within the core, perhaps with the event queue or handling of outgoing events. Thanks to @addshore for reporting this.

The issue can be replicated with the following:

composer.json

{
    "require": {
        "phergie/phergie-irc-bot-react": "~1",
        "phergie/phergie-irc-plugin-react-pong": "~1",
        "phergie/phergie-irc-plugin-react-eventfilter": "~1",
        "phergie/phergie-irc-plugin-react-autojoin": "~1"
    },
    "autoload": {
        "psr-4": {
            "Phergie\\Irc\\Plugin\\React\\Test\\": "src"
        }
    }
}

config.php

<?php
use Phergie\Irc\Connection;
use Phergie\Irc\Plugin\React\Pong\Plugin as PongPlugin;
use Phergie\Irc\Plugin\React\EventFilter\Plugin as EventFilterPlugin;
use Phergie\Irc\Plugin\React\EventFilter\ConnectionFilter;
use Phergie\Irc\Plugin\React\AutoJoin\Plugin as AutoJoinPlugin;

$quakenet = new Connection([
  'serverHostname' => 'irc.quakenet.org',
  'username' => 'Elazar',
  'realname' => 'Matthew Turland',
  'nickname' => 'Phergie3'
]);

$freenode = new Connection([
  'serverHostname' => 'irc.freenode.net',
  'username' => 'Elazar',
  'realname' => 'Matthew Turland',
  'nickname' => 'Phergie3'
]);

return [
  'connections' => [
    $quakenet,
    $freenode,
  ],
  'plugins' => [
    new PongPlugin,
    new EventFilterPlugin([
      'filter' => new ConnectionFilter([$quakenet]),
      'plugins' => [new AutoJoinPlugin(['channels' => '#test'])],
    ]),
    new EventFilterPlugin([
      'filter' => new ConnectionFilter([$freenode]),
      'plugins' => [new AutoJoinPlugin(['channels' => '##add'])],
    ]),
  ],
];

When used, these yield the following output segments:

2015-01-21 19:19:44 DEBUG Phergie3!Elazar@irc.freenode.net :rajaniemi.freenode.net 376 Phergie3 :End of /MOTD command. []
2015-01-21 19:19:44 INFO Event did not pass filter, skipping {"event":"irc.received.rpl_endofmotd","args":["[object] (Phergie\\Irc\\Event\\ServerEvent: {})",[]]}
2015-01-21 19:19:44 INFO Event passed filter, forwarding {"event":"irc.received.rpl_endofmotd","args":["[object] (Phergie\\Irc\\Event\\ServerEvent: {})",[]]}
2015-01-21 19:19:44 INFO Forwarding event to callback {"event":"irc.received.rpl_endofmotd","args":["[object] (Phergie\\Irc\\Event\\ServerEvent: {})",[]],"callback":["[object] (Phergie\\Irc\\Plugin\\React\\AutoJoin\\Plugin: {})","joinChannels"]}
2015-01-21 19:19:44 DEBUG Phergie3!Elazar@irc.freenode.net JOIN :##add []
2015-01-21 19:19:46 DEBUG Phergie3!Elazar@irc.quakenet.org :port80b.se.quakenet.org 376 Phergie3 :End of /MOTD command. []
2015-01-21 19:19:46 INFO Event passed filter, forwarding {"event":"irc.received.rpl_endofmotd","args":["[object] (Phergie\\Irc\\Event\\ServerEvent: {})",[]]}
2015-01-21 19:19:46 INFO Forwarding event to callback {"event":"irc.received.rpl_endofmotd","args":["[object] (Phergie\\Irc\\Event\\ServerEvent: {})",[]],"callback":["[object] (Phergie\\Irc\\Plugin\\React\\AutoJoin\\Plugin: {})","joinChannels"]}
2015-01-21 19:19:46 INFO Event did not pass filter, skipping {"event":"irc.received.rpl_endofmotd","args":["[object] (Phergie\\Irc\\Event\\ServerEvent: {})",["[object] (Phergie\\Irc\\Event\\UserEvent: {})"]]}
2015-01-21 19:19:46 DEBUG Phergie3!Elazar@irc.quakenet.org :port80b.se.quakenet.org NOTICE Phergie3 :on 2 ca 2(4) ft 20(20) []
2015-01-21 19:19:46 DEBUG Phergie3!Elazar@irc.quakenet.org :port80b.se.quakenet.org 221 Phergie3 +i []
2015-01-21 19:19:46 DEBUG Phergie3!Elazar@irc.quakenet.org :Phergie3!~Elazar@ip72-211-85-166.no.no.cox.net MODE Phergie3 +i []
2015-01-21 19:19:51 DEBUG Phergie3!Elazar@irc.freenode.net :Phergie3!~Elazar@ip72-211-85-166.no.no.cox.net JOIN ##add []

Note how no JOIN event appears for the irc.quakenet.org connection.

I am glad you can replicate it and I wasn't simply going mad :)

It looks like the AutoJoin plugin is queueing events correctly and the EventFilter plugin is filtering them correctly, or at least being called as many times as it should be (once per connection per event) and filtering as many times as it should be (once per connection). The issue may be in either of processClientEvent() or processOutgoingEvents() in the Bot class.

Just wondering if there was any progress with this? :)

Afraid not. :( Any help to diagnose the issue further would be much appreciated.

There are potentially a few overlapping things here, but one of the issues is that the event queue is a single shared queue for all connections, but events pushed to the queue don't have any information attached to them about which connection they're for; instead, whichever connection happens to invoke processOutgoingEvents sends all of the events in the queue to that connection.

Two possible solutions:

  • every time an event is pushed to the queue, somehow specify which connection it's associated with
  • have a different event queue for each connection

I think @Renegade334 is right. I believe the better solution to minimize backward compatibility breaks would be to have a separate event queue per connection, since that doesn't require any action on the part of plugin developers. Here's what I'm thinking an implementation of that solution could look like:

  1. The setEventQueue() and getEventQueue() methods, $queue property, and 'eventQueue' configuration setting of the Bot class would become deprecated. Bot would be modified to throw an exception when the methods are called or the configuration setting is used to indicate this deprecation.

  2. A new EventQueueFactoryInterface interface would be created. It would contain a single method, getEventQueue(), that would take a single parameter of type ConnectionInterface. It would return an object of type EventQueueInterface.

  3. A new class EventQueueFactory would be created that implements EventQueueFactoryInterface. Its getEventQueue() method would simply check an internal instance of \SplObjectStorage for an element with a key of the specified ConnectionInterface instance, create one pointing to a new EventQueue instance if one does not already exist, and return the EventQueue instance associated with the ConnectionInterface instance.

  4. New setEventQueueFactory() and getEventQueueFactory() methods, a $queueFactory property, and an 'eventQueueFactory' configuration setting would be added to Bot. This would allow for custom EventQueueFactoryInterface implementations and use the core EventQueueFactory implementation as the default.

  5. Any existing calls to getEventQueue() in Bot will be replaced with calls to the method of the same name on $queueFactory that pass the relevant ConnectionInterface instance.

This solution would cause breaks for anyone currently using a custom EventQueueInterface implementation, but they would have a migration path: create an EventQueueFactoryInterface implementation that returns instances of their EventQueueInterface implementation and configure Bot to use that via the 'eventQueueInterface' configuration setting. This solution should also avoid the need for any backward compatibility breaks affecting existing plugins.

Being that any solution to this issue is likely to have at least some backward compatibility breaks, should the fix require a version bump to 2.x? Any other thoughts, on this particular solution or otherwise from @Renegade334, @addshore, or anyone else interesting in this issue being fixed?

The solution seem reasonable (and will hopefully fix the issue).
It should probably be in a 2.x release.
If noone else cares or has ever noticed this issue then I wouldn't rush to release 2.x, I'm more than happy developing and testing the rest of my code against master or a branch, who knows, maybe I will find other interesting issues such as this!

I don't feel that I have the expertise with the v3 framework to give any valuable input on design decisions! However, sounds reasonable to me as well.

@addshore @Renegade334 Would either of you mind testing out my implementation of the previously discussed solution that's now merged to master?

https://gist.github.com/Renegade334/085c0cd3e39831c81a2a

<Renegade334> basically, out of those three connection filters, only the third one ever ends up actually joining the channel specified by the AutoJoin.
<Renegade334> If you re-order them, then whichever one ends up last out of the 3 in config.php is the one that works, whichever connection/channel combo that ends up being.
<Renegade334> Everything is being called correctly up to the point where the event is committed to the event queue, but when it gets retrieved, extract() returns nothing.
<Renegade334> If I add a second ircJoin command to the joinChannels callback in the AutoJoin plugin, then both of those JOIN events get retrieved from the event queue successfully, but again, only for the plugin that corresponds to the 3rd filter.

Had a look at the object hashes for the EventQueue objects at each step, and they're exactly as they should be: one EventQueue for each connection, the same throughout. For some reason, calling extract() on the same EventQueue object as insert() was just performed on, isn't returning the inserted event in those cases.

This bug was identified as a result of the Monolog formatter calling foreach on the EventQueue object, which has the side-effect of removing all objects from the heap.

Potential mitigations:

  • Override valid() in EventQueue to prevent any iteration over event queue objects (1930797). This is failsafe, and since no Phergie module uses foreach to iterate over event queues, should probably be implemented. It's a crude hack, and will have purists clawing their eyes out, but ah well.
  • Add a dummy interface to the Client namespace, and a new Monolog formatter wrapper to prevent traversing of objects that implement it (Renegade334/phergie-irc-client-react@396081dd). However, this won't affect anyone who doesn't use the default logger.
  • Modify EventFilter to filter out event queue objects from its log context array. Doesn't really address any of the underlying issues.

Is there a reason we can't use @weierophinney's solution, specifically overriding getIterator() and having it return a clone of the queue? I realize we're extending \SplPriorityQueue where he's composing it, but I would think the same solution would still work:

public function getIterator()
{
    return clone $this;
}

You cannot implement IteratorAggregate on a class that already implements Iterator (via SplPriorityQueue). The only way to implement that would be via a wrapper, as per the original solution.

The question is whether or not there is a need to provide the means to non-destructively iterate over the queue. If it's not necessary (ie. stating that Bot::processOutgoingEvents() is the only construct that can read from the queue) then we can short-circuit that behaviour and walk away with thumbs a-twiddling...

Is valid() called for any use cases that are applicable? Otherwise, I'm inclined to say we should have the override throw an exception or emit a warning or something to indicate to the user that it's not supported and why.

I did write the original implementation of valid() emitting an E_USER_NOTICE to notify of the disabled iteration interface. The only downside was that it emitted notices every time the EventFilter filtered an event (whether the event was passed on or not), which had the potential to get quite spammy. That would go away if implemented in combination with the second bullet point, though.

In answer to your question, valid() is inherited directly from Iterator and is only called when the object is being iterated over - ie. when foreach() is called on it.

Hrm. At this point, I'm honestly inclined to implement @weierophinney's composition solution, ugly or no. That would allow iteration and make the whole issue moot. There might be slight BC breakage for anyone typehinting an EventQueue instance against SplPriorityQueue, but that seems like a pretty unlikely use case.

In which case, we would need a new class definition for the EventQueue wrapper, which:

  • implements EventQueueInterface, defines all of the EventQueueInterface methods and passes them to the internal event queue object
  • implements IteratorAggregate and provides the getIterator() method as per above

The existing EventQueue class would then need to be renamed to something like EventQueueInternal.

Not sure I see the need for an extra class. These changes can be made directly to EventQueue:

  • Remove the parent class declaration
  • Add a protected $queue property
  • Replace this block with an assignment to $this->queue of an SplPriorityQueue instance
  • Replace $this / parent references with references to $this->queue as appropriate in extract() and queueRequest()
  • Declare implementation of IteratorAggregate and Countable and add getIterator() and count() methods

We would also need to modify EventQueueInterface to extend IteratorAggregate instead of Iterator, but I think that's a minor enough BC break to be acceptable.

That makes much more sense, however this would prevent being able to override the compare() method, which is called by SplPriorityQueue internally. getPriority() would need to find some way of resolving the EventQueuePriority objects down into a single value that can be compared using the native compare() method. Alternatively, a simple additional class that extended SplPriorityQueue and provided the custom compare() method would do the trick.

Ah, true. And @weierophinney found the same and subclassed \SplPriorityQueue as a result. So, yeah, we'll need an InnerEventQueue class or something to that effect to have the custom compare() implementation. That together with the rest of the solution as described above, using InnerEventQueue for the assignment instead of \SplPriorityQueue, should work.

@Renegade334 Class docblock for EventQueueInternal needs to be updated and should note that it's intended only for internal use by EventQueue. You may also want to verify that tests still pass without updates. Otherwise, looks good.

@Renegade334 @addshore Can one of you verify that the latest merge resolves this bug?

My internal testing at the time showed this to be a fix, but worth double-checking. My test config.php files are retained in the linked gists above for reference.

@elazar What do I need, just master of phergie-irc-bot-react ?

Checked out master of phergie-irc-bot-react and my particular issue has now gone!
In other words I can now use the AutoJoinPlugin across multiple networks instead of my dirty little hack!