Group sink add/remove operations expire in InOrderFlowObjectiveManager

Exception:

08:55:42.425 WARN [InOrderFlowObjectiveManager] Flow objective onError DefaultNextObjective{id=1, type=BROADCAST, op=ADD_TO_EXISTING, priority=0, nextTreatments=[DefaultNextTreatment{treatment=DefaultTrafficTreatment{immediate=[OUTPUT:4240], deferred=[], transition=None, meter=[], cleared=false, StatTrigger=null, metadata=null}}], meta=DefaultTrafficSelector {criteria=[VLAN_VID:4000, IPV4_DST:224.0.0.22/32]}, appId=DefaultApplicationId{id=199, name=org.opencord.mcast} , permanent=false, timeout=0}. Reason = INSTALLATIONTIMEOUT
08:55:42.431 DEBUG [CordMcast] Next Objective 1 failed, because INSTALLATIONTIMEOUT

Root cause:

InnerGroupListener of OltPipeline listens to group events. When a group event is received, It notifies InOrderFlowObjectiveManager through the pass() method and removes the group from the pendingGroups cache respectively. Pass() method tells InOrderFlowObjectiveManager that the current operation for this group has been succeeded. In this case, InOrderFlowObjectiveManager removes the current operation for this group from its internal FIFO queue and starts consuming the next waiting one, if any. If there is a waiting operation in the queue, InOrderFlowObjectiveManager sends it to OltPipeline and OltPipeline puts this operation into the pendingGroups queue (actually overwrites the existing one in this case). Having called pass() method successfully, InnerGroupListener removes the group from pendingGroups cache. At this point, in fact, it invalidates the next group operation since InOrderFlowObjectiveManager has just consumed the next event and put it into the pendingGroups cache.

In this situation, InOrderFlowObjectiveManager waits for the result of the current group operation but it never comes. Because InnerGroupListener cannot process group events for the related groups since it has been removed from the pendingGroups cache. After 500secs, the current group operation in InOrderFlowObjectiveManager expires and ends with INSTALLATIONTIMEOUT exception. Note that, the other sink add/removed operations issued for this group wait in the InOrderFlowObjectiveManager's queue to be processed until the timeout occurs for the current operation. The situation completely blocks the sink add/remove operations for this group for 500secs.

private class InnerGroupListener implements GroupListener {
    @Override
    public void event(GroupEvent event) {
        GroupKey key = event.subject().appCookie();
        NextObjective obj = pendingGroups.getIfPresent(key);
        if (obj == null) {
            log.debug("No pending group for {}, moving on", key);
            return;
        }
        log.trace("Event {} for group {}, handling pending" +
                          "NextGroup {}", event.type(), key, obj.id());
        if (event.type() == GroupEvent.Type.GROUP_ADDED ||
                event.type() == GroupEvent.Type.GROUP_UPDATED) {
                flowObjectiveStore.putNextGroup(obj.id(), new OLTPipelineGroup(key));
                pass(obj);
                pendingGroups.invalidate(key);
        } else if (event.type() == GroupEvent.Type.GROUP_REMOVED) {
                flowObjectiveStore.removeNextGroup(obj.id());
                pass(obj);
                pendingGroups.invalidate(key);
        }
    }
}