Rasa Conversations are not responding (intermittently)

srinivas.b · March 23, 2021, 10:13am

Hello, We are facing some intermittent issues during our conversations where the conversations go unresponsive or clueless as rasa is predicting “action_listen” instead of the appropriate form action. Please provide us suggestions or corrections in our implementations (if any) to resolve the issue at earliest. This is impacting our business as customers are facing these issues frequently.

Current configurations in our implementation:

Rasa 1.10.3.
Policy Configurations:
- {“name”: “app.custom.custom_keras_policy.CustomKerasPolicy”,“priority”:1,“epochs”: 300,“batch_size”: 64,“random_seed”: 42,“validation_split”: 0,“featurizer”: [{“name”: “MaxHistoryTrackerFeaturizer”,“max_history”: 5,“state_featurizer”: [{“name”: “BinarySingleStateFeaturizer”}]}]}
- {“name”: “AugmentedMemoizationPolicy”,“priority”:2,“max_history”: 6}
- {“name”: “FallbackPolicy”,“priority”:3,“nlu_threshold”: 0.3,“core_threshold”: 0.3,“ambiguity_threshold”: 0,“fallback_action_name”: “action_default_fallback”}
- {“name”:“FormPolicy”,“priority”:4}
- {“name”:“MappingPolicy”,“priority”:5}
We are using MySQL for storing the tracker states and which we are cleaning past 1hr events for every 1hr. (Means at 2’O clock we clean all events before 1’O clock).
Not configuring anything related to Session (Defaults session_config holds).
All our stories are simple form based stories looks similar to below
- new_trash_can
  - form_action_new_trash_can
  - form{“name”:“form_action_new_trash_can”}
  - form{“name”:null}

Scenario1: Start a new conversation (using /) and rasa predicts “action_listen” instead of the form “form_action_ootb_welcome”

Story Definition:

ootb_welcome
- form_action_ootb_welcome
- form{“name”:“form_action_ootb_welcome”}
- form{“name”:null}

Below are the logs where we observed action_listen was predicted instead of form_action_ootb_welcome. Here the AugmentedMemoizationPolicy does not predict the form action (may be due to max_history setting, we are okay here), but we expect Keras policy to predict the form action

rasa.core.processor | DEBUG | [processor.py:471-_parse_message()] | Received user message '/ootb_welcome' with intent '{'name': 'ootb_welcome', 'confidence': 1.0}' and entities '[]'
rasa.core.processor | DEBUG | [processor.py:507-_handle_message_with_tracker()] | Logged UserUtterance - tracker now has 43 events.
rasa.core.policies.fallback | DEBUG | [fallback.py:171-predict_action_probabilities()] | NLU confidence threshold met, confidence of fallback action set to core threshold (0.3).
rasa.core.policies.form_policy | DEBUG | [form_policy.py:165-predict_action_probabilities()] | There is no active form
rasa.core.policies.mapping_policy | DEBUG | [mapping_policy.py:159-predict_action_probabilities()] | There is no mapped action for the predicted intent, 'ootb_welcome'.
rasa.core.policies.memoization | DEBUG | [memoization.py:195-predict_action_probabilities()] | Current tracker state [None, None, None, {'slot_sys_dialog_interaction_state_1': 1.0}, {'prev_action_listen': 1.0, 'slot_sys_dialog_interaction_state_1': 1.0}, {'prev_form_action_ootb_what_can_you_do': 1.0, 'slot_sys_dialog_interaction_state_1': 1.0, 'intent_ootb_welcome': 1.0}]
rasa.core.policies.memoization | DEBUG | [memoization.py:299-_recall_using_delorean()] | Launch DeLorean...
rasa.core.policies.memoization | DEBUG | [memoization.py:319-_recall_using_delorean()] | Current tracker state [None, None, None, None, {'slot_sys_dialog_interaction_state_1': 1.0}, {'prev_form_action_ootb_what_can_you_do': 1.0, 'slot_sys_dialog_interaction_state_1': 1.0, 'intent_ootb_welcome': 1.0}]
rasa.core.policies.memoization | DEBUG | [memoization.py:211-predict_action_probabilities()] | There is no memorised next action
rasa.core.policies.ensemble | DEBUG | [ensemble.py:538-probabilities_using_best_policy()] | Predicted next action using policy_2_CustomKerasPolicy
rasa.core.processor | DEBUG | [processor.py:308-predict_next_action()] | Predicted next action 'action_listen' with confidence 1.00.
rasa.core.processor | DEBUG | [processor.py:711-_log_action_on_tracker()] | Action 'action_listen' ended with events '[]'.

Working scenario logs where form action “'form_action_ootb_welcome” is predicted using AugmentedMemoizationPolicy

rasa.core.processor | DEBUG | [processor.py:471-_parse_message()] | Received user message '/ootb_welcome' with intent '{'name': 'ootb_welcome', 'confidence': 1.0}' and entities '[]'
rasa.core.processor | DEBUG | [processor.py:507-_handle_message_with_tracker()] | Logged UserUtterance - tracker now has 4 events.
rasa.core.policies.fallback | DEBUG | [fallback.py:171-predict_action_probabilities()] | NLU confidence threshold met, confidence of fallback action set to core threshold (0.3).
rasa.core.policies.form_policy | DEBUG | [form_policy.py:165-predict_action_probabilities()] | There is no active form
rasa.core.policies.memoization | DEBUG | [memoization.py:195-predict_action_probabilities()] | Current tracker state [None, None, None, None, {'slot_sys_dialog_interaction_state_1': 1.0}, {'prev_action_listen': 1.0, 'slot_sys_dialog_interaction_state_1': 1.0, 'intent_ootb_welcome': 1.0}]
rasa.core.policies.memoization | DEBUG | [memoization.py:199-predict_action_probabilities()] | There is a memorised next action 'form_action_ootb_welcome'
rasa.core.policies.ensemble | DEBUG | [ensemble.py:538-probabilities_using_best_policy()] | Predicted next action using policy_4_AugmentedMemoizationPolicy
rasa.core.processor | DEBUG | [processor.py:308-predict_next_action()] | Predicted next action 'form_action_ootb_welcome' with confidence 1.00.
rasa.core.actions.action | DEBUG | [action.py:546-run()] | Calling action endpoint to run action 'form_action_ootb_welcome'.
rasa.core.processor | DEBUG | [processor.py:711-_log_action_on_tracker()] | Action 'form_action_ootb_welcome' ended with events '[BotUttered('utter_intent_ootb_what_can_you_do', {"elements": null, "quick_replies": null, "buttons": null, "attachment": null, "image": null, "custom": null}, {}, 1615370693.4402285), <rasa.core.events.Form object at 0x0000023ED4ADEE08>, <rasa.core.events.Form object at 0x0000023ED4ADE1C8>, <rasa.core.events.SlotSet object at 0x0000023ED4ADE948>]'.

Scenario2: Start a new conversation (using /), rasa predicts the form properly and during the slot filling it predicts “action_listen” instead of the form action “form_action_new_trash_can” even though a form was already active.

Story Definition:

new_trash_can
- form_action_new_trash_can
- form{“name”:" form_action_new_trash_can"}
- form{“name”:null}

Below are the logs we observed where action_listen was predicted instead of form_action_new_trash_can. Here the Form policy did not choose the intended form action though the form is active where as in working scenario shown further below it did predict the form action appropriately.

rasa.core.processor | DEBUG |  | [processor.py:471-_parse_message()] | Received user message 'Yes' with intent '{'name': 'smalltalk_confirmation_yes', 'confidence': 0.954254686832428}' and entities '[]'
rasa.core.processor | DEBUG |  | [processor.py:507-_handle_message_with_tracker()] | Logged UserUtterance - tracker now has 40 events.
rasa.core.policies.memoization | DEBUG |  | [memoization.py:195-predict_action_probabilities()] | Current tracker state [None, None, None, None, {'slot_sys_dialog_interaction_state_1': 1.0}, {'intent_new_trash_can': 1.0, 'slot_sys_dialog_interaction_state_1': 1.0, 'prev_action_listen': 1.0, 'entity_trash_can_type_entity': 1.0}]
rasa.core.policies.memoization | DEBUG |  | [memoization.py:299-_recall_using_delorean()] | Launch DeLorean...
rasa.core.policies.memoization | DEBUG |  | [memoization.py:311-_recall_using_delorean()] | Current tracker state [None, None, None, None, None, {'slot_sys_dialog_interaction_state_1': 1.0}]
rasa.core.policies.memoization | DEBUG |  | [memoization.py:199-predict_action_probabilities()] | There is a memorised next action 'action_listen'
rasa.core.policies.fallback | DEBUG |  | [fallback.py:171-predict_action_probabilities()] | NLU confidence threshold met, confidence of fallback action set to core threshold (0.35).
rasa.core.policies.form_policy | DEBUG |  | [form_policy.py:147-predict_action_probabilities()] | There is an active form 'form_action_new_trash_can'
rasa.core.policies.mapping_policy | DEBUG |  | [mapping_policy.py:159-predict_action_probabilities()] | There is no mapped action for the predicted intent, 'smalltalk_confirmation_yes'.
rasa.core.policies.ensemble | DEBUG |  | [ensemble.py:538-probabilities_using_best_policy()] | Predicted next action using policy_3_FormPolicy
rasa.core.processor | DEBUG |  | [processor.py:308-predict_next_action()] | Predicted next action 'action_listen' with confidence 1.00.
rasa.core.processor | DEBUG |  | [processor.py:711-_log_action_on_tracker()] | Action 'action_listen' ended with events '[]'.

Working scenario logs where form action “'form_action_new_trash_can” is predicted using FormPolicy.

rasa.core.processor | DEBUG |  | [processor.py:471-_parse_message()] | Received user message 'Yes' with intent '{'name': 'smalltalk_confirmation_yes', 'confidence': 0.954254686832428}' and entities '[]'
rasa.core.processor | DEBUG |  | [processor.py:507-_handle_message_with_tracker()] | Logged UserUtterance - tracker now has 14 events.
rasa.core.featurizers | DEBUG |  | [featurizers.py:121-encode()] | Feature 'intent_smalltalk_confirmation_yes' (value: '1.0') could not be found in feature map. Make sure you added all intents and entities to the domain
rasa.core.policies.memoization | DEBUG |  | [memoization.py:195-predict_action_probabilities()] | Current tracker state [None, None, {'slot_sys_dialog_interaction_state_1': 1.0}, {'intent_new_trash_can': 1.0, 'slot_sys_dialog_interaction_state_1': 1.0, 'prev_action_listen': 1.0, 'entity_trash_can_type_entity': 1.0}, {'slot_sys_dialog_interaction_state_12': 1.0, 'prev_form_action_new_trash_can': 1.0, 'intent_new_trash_can': 1.0, 'active_form_form_action_new_trash_can': 1.0, 'entity_trash_can_type_entity': 1.0}, {'slot_sys_dialog_interaction_state_12': 1.0, 'intent_smalltalk_confirmation_yes': 1.0, 'prev_action_listen': 1.0, 'active_form_form_action_new_trash_can': 1.0}]
rasa.core.policies.memoization | DEBUG |  | [memoization.py:299-_recall_using_delorean()] | Launch DeLorean...
rasa.core.policies.memoization | DEBUG |  | [memoization.py:319-_recall_using_delorean()] | Current tracker state [None, None, None, None, {'slot_sys_dialog_interaction_state_1': 1.0}, {'intent_smalltalk_confirmation_yes': 1.0, 'slot_sys_dialog_interaction_state_1': 1.0, 'prev_action_listen': 1.0}]
rasa.core.policies.memoization | DEBUG |  | [memoization.py:211-predict_action_probabilities()] | There is no memorised next action
rasa.core.policies.fallback | DEBUG |  | [fallback.py:171-predict_action_probabilities()] | NLU confidence threshold met, confidence of fallback action set to core threshold (0.35).
rasa.core.policies.form_policy | DEBUG |  | [form_policy.py:147-predict_action_probabilities()] | There is an active form 'form_action_new_trash_can'
rasa.core.policies.ensemble | DEBUG |  | [ensemble.py:538-probabilities_using_best_policy()] | Predicted next action using policy_3_FormPolicy
rasa.core.processor | DEBUG |  | [processor.py:308-predict_next_action()] | Predicted next action 'form_action_new_trash_can' with confidence 1.00.
rasa.core.actions.action | DEBUG |  | [action.py:546-run()] | Calling action endpoint to run action 'form_action_new_trash_can'.
rasa.core.processor | DEBUG |  | [processor.py:711-_log_action_on_tracker()] | Action 'form_action_new_trash_can' ended with events '[<rasa.core.events.SlotSet object at 0x7f04200cca90>, <rasa.core.events.SlotSet object at 0x7f03d2aef550>, <rasa.core.events.SlotSet object at 0x7f03d2aeff50>]'.

stephens · March 23, 2021, 3:08pm

If ootb_welcome and new_trash_can should always invoke their associated forms, you could setup a rule as shown on the forms page instead of the stories.

kishoresurisetty · March 24, 2021, 4:56am

@stephens - I guess the RulePolicy is introduced in 2.x, but we are currently on 1.10.3 version of Rasa.

On further investigation in to this, we have realized that the latest_action_name in the tracker is populated with the form action name (form_action_new_trash_can) which is causing the FormPolicy to predict “action_listen” as per the code shown below. The last_action_name is supposed to be “action_listen” when the bot is waiting for the user input.

File: rasa\core\policies\form_policy.py

def predict_action_probabilities(
    self, tracker: DialogueStateTracker, domain: Domain
) -> List[float]:
    """Predicts the corresponding form action if there is an active form"""
    result = self._default_predictions(domain)

    if tracker.active_form.get("name"):
        logger.debug(
            "There is an active form '{}'".format(tracker.active_form["name"])
        )
        if tracker.latest_action_name == ACTION_LISTEN_NAME:
            # predict form action after user utterance

            if tracker.active_form.get("rejected"):
                if self.state_is_unhappy(tracker, domain):
                    tracker.update(FormValidation(False))
                    return result

            idx = domain.index_for_action(tracker.active_form["name"])
            result[idx] = 1.0

        elif tracker.latest_action_name == tracker.active_form.get("name"):
            # predict action_listen after form action
            idx = domain.index_for_action(ACTION_LISTEN_NAME)
            result[idx] = 1.0
    else:
        logger.debug("There is no active form")

    return result

Looking at the events table in MySQL store, we see that the entries in the proper order w.r.t Id column (PK), but the timestamp looks same for both form action (form_action_new_trash_can) and “action_listen”.

Further looking into the SQLTrackerStore code that retrieve the events, we see that events are retrieved in the order of timestamp. But, when the multiple events have the same timestamp, they are retrieved in nondeterministic order causing the aforementioned intermittent behavior.

File: rasa\core\tracker_store.py

def _event_query(self, session: "Session", sender_id: Text) -> "Query":
    """Provide the query to retrieve the conversation events for a specific sender.

    Args:
        session: Current database session.
        sender_id: Sender id whose conversation events should be retrieved.

    Returns:
        Query to get the conversation events.
    """
    # Subquery to find the timestamp of the latest `SessionStarted` event
    session_start_sub_query = (
        session.query(sa.func.max(self.SQLEvent.timestamp).label("session_start"))
        .filter(
            self.SQLEvent.sender_id == sender_id,
            self.SQLEvent.type_name == SessionStarted.type_name,
        )
        .subquery()
    )

    event_query = session.query(self.SQLEvent).filter(
        self.SQLEvent.sender_id == sender_id
    )
    if not self.load_events_from_previous_conversation_sessions:
        event_query = event_query.filter(
            # Find events after the latest `SessionStarted` event or return all
            # events
            sa.or_(
                self.SQLEvent.timestamp >= session_start_sub_query.c.session_start,
                session_start_sub_query.c.session_start.is_(None),
            )
        )

    return **event_query.order_by(self.SQLEvent.timestamp)**

As a solution, we are currently thinking of extending SQLTrackerStore class and overriding “_event_query” method to update the order_by clause to include the Id column for sorting along with timestamp column.

Is there any better solution other than making this code change? Is this addressed already in any of the 1.x versions above 1.10.3.

stephens · March 24, 2021, 5:02am

You’re on a very old release. I can’t speak to all of the changes since 1.10.3 but recommend you upgrade because there have been many bug fixes and improvements since this releases.

kishoresurisetty · March 24, 2021, 1:21pm

I don’t see this addressed in the latest versions also.

github.com

RasaHQ/rasa/blob/e2759589e308de1120364035256d6169776c8c55/rasa/core/tracker_store.py#L1090


    if not fetch_events_from_all_sessions:
        event_query = event_query.filter(
            # Find events after the latest `SessionStarted` event or return all
            # events
            sa.or_(
                self.SQLEvent.timestamp >= session_start_sub_query.c.session_start,
                session_start_sub_query.c.session_start.is_(None),
            )
        )

    return event_query.order_by(self.SQLEvent.timestamp)

def save(self, tracker: DialogueStateTracker) -> None:
    """Update database with events from the current conversation."""

    if self.event_broker:
        self.stream_events(tracker)

    with self.session_scope() as session:
        # only store recent events
        events = self._additional_events(session, tracker)

I also see that the timestamps are still generated in epoch seconds which is causing all the events from custom action to have the same timestamp when things happen within a second. Generating timestamps with more precision (like nanoseconds) would have eliminated this issue and not needing to add additional Id column in the sort order as we were planning to customize rasa code.

e.timestamp = time.time()

github.com

RasaHQ/rasa/blob/e2759589e308de1120364035256d6169776c8c55/rasa/shared/core/trackers.py#L692



    Args:
        new_events: Events to apply.
        domain: The current model's domain.
        override_timestamp: If `True` refresh all timestamps of the events. As the
            events are usually created at some earlier point, this makes sure that
            all new events come after any current tracker events.
    """
    for e in new_events:
        if override_timestamp:
            e.timestamp = time.time()
        self.update(e, domain)

def as_story(self, include_source: bool = False) -> "Story":
    """Dump the tracker as a story in the Rasa Core story format.

    Returns the dumped tracker as a string.
    """
    from rasa.shared.core.training_data.structures import Story

    story_name = (

self.timestamp = timestamp or time.time()

github.com

RasaHQ/rasa/blob/e2759589e308de1120364035256d6169776c8c55/rasa/shared/core/events.py#L223


how to update its state as the events occur.
"""

type_name = "event"

def __init__(
    self,
    timestamp: Optional[float] = None,
    metadata: Optional[Dict[Text, Any]] = None,
) -> None:
    self.timestamp = timestamp or time.time()
    self._metadata = metadata or {}

@property
def metadata(self) -> Dict[Text, Any]:
    # Needed for compatibility with Rasa versions <1.4.0. Previous versions
    # of Rasa serialized trackers using the pickle module. For the moment,
    # Rasa still supports loading these serialized trackers with pickle,
    # but will use JSON in any subsequent save operations. Versions of
    # trackers serialized with pickle won't include the `_metadata`
    # attribute in their events, so it is necessary to define this getter