Slots get filled twice in FormAction

Hello,

For some reason, when rasa detects an entity in my situation, it filled the corresponding slot twice (and my custom validate function also get executed twice):

In the image above, rasa detected the date entity correctly ‘15/03/2020’, and after my validate function checked that it’s a valid date, it filled the slots ‘day’, ‘month’, ‘year’. The problem is rasa seems to fill and validate the date slot twice. Can anybody help me with this ? Thank you very much.

1 Like

Hi @fuih! Does this also happen outside of Rasa X? What version of Rasa X are you using?

Sorry for responding late, @tyd. I tried talking to the bot on slack and it happened again. My Rasa X version is 0.20.0.

Today i found out that this behavior happens in a specific situation:

  • Situation A (correct behavior):

     User: I want to schedule a meeting (intent: schedule_meeting)
     Bot: What date do you want to schedule a meeting for ?
     User: 15/03/2020 (intent: inform_date)
     (Slots get filled and validated once)
    
  • Situation B (incorrect behavior):

     User: I want to schedule a meeting for 15/3/2020 (intent: schedule_meeting)
     (Slots get filled and validated twice)

@fuih Can you share the relevant story/stories and action code?

Sorry if the code is kinda a mess. There are quite a few of actions and forms so i just took the FormActions corresponding to Book Meeting Room function (in which the bot behaves like above).

stories.md (1.6 KB) actions.py (15.3 KB)

@fuih Can you run your action server and rasa shell in debug mode, go through the incorrect situation, and then share the logs?

127.0.0.1 - - [2019-07-31 17:18:00] "POST /webhook HTTP/1.1" 400 280 0.000000
2019-07-31 17:18:06 DEBUG    rasa_sdk.executor  - Received request to run 'book_meeting_room_date_form'
2019-07-31 17:18:06 DEBUG    rasa_sdk.forms  - There is no active form
2019-07-31 17:18:06 DEBUG    rasa_sdk.forms  - Activated the form 'book_meeting_room_date_form'
2019-07-31 17:18:06 DEBUG    rasa_sdk.forms  - Validating pre-filled required slots: {'date': '31/7/2020'}
2019-07-31 17:18:06 DEBUG    rasa_sdk.forms  - Validating user input '{'intent': {'name': 'book_meeting_room', 'confidence': 0.9507490992546082}, 'entities': [{'start': 36, 'end': 45, 'value': '31/7/2020', 'entity': 'date', 'confidence': 0.9908784135880544, 'extractor': 'CRFEntityExtractor'}], 'intent_ranking': [{'name': 'book_meeting_room', 'confidence': 0.9507490992546082}, {'name': 'search_seat', 'confidence': 0.11632139980792999}, {'name': 'book_lunch', 'confidence': 0.09904080629348755}, {'name': 'search_department', 'confidence': 0.07724202424287796}, {'name': 'greet', 'confidence': 0.05056463181972504}, {'name': 'ask_creator', 'confidence': 0.05035930126905441}, {'name': 'goodbye', 'confidence': 0.04043673723936081}, {'name': 'introduction', 'confidence': 0.031357087194919586}, {'name': 'search_project', 'confidence': 0.027527622878551483}, {'name': 'change_lunch_place', 'confidence': 0.01240589190274477}], 'text': 'tôi muốn đặt phòng họp vào lúc ngày 31/7/2020'}'
2019-07-31 17:18:06 DEBUG    rasa_sdk.forms  - Extracted '31/7/2020' for extra slot 'date'
2019-07-31 17:18:06 DEBUG    rasa_sdk.forms  - Validating extracted slots: {'date': '31/7/2020'}
2019-07-31 17:18:06 DEBUG    rasa_sdk.forms  - No slots left to request, all required slots are filled:
        date: 31/7/2020
        day: None
        month: None
        year: None
2019-07-31 17:18:06 DEBUG    rasa_sdk.forms  - Submitting the form 'book_meeting_room_date_form'
2019-07-31 17:18:06 DEBUG    rasa_sdk.forms  - Deactivating the form 'book_meeting_room_date_form'
2019-07-31 17:18:06 DEBUG    rasa_sdk.executor  - Finished running 'book_meeting_room_date_form'
127.0.0.1 - - [2019-07-31 17:18:06] "POST /webhook HTTP/1.1" 200 1078 0.015359
2019-07-31 17:18:07 DEBUG    rasa_sdk.executor  - Received request to run 'book_meeting_room_time_form'
2019-07-31 17:18:07 DEBUG    rasa_sdk.forms  - There is no active form
2019-07-31 17:18:07 DEBUG    rasa_sdk.forms  - Activated the form 'book_meeting_room_time_form'
2019-07-31 17:18:07 DEBUG    rasa_sdk.forms  - No pre-filled required slots to validate.
2019-07-31 17:18:07 DEBUG    rasa_sdk.forms  - Skipping validation
2019-07-31 17:18:07 DEBUG    rasa_sdk.forms  - Request next slot 'start_time'
2019-07-31 17:18:07 DEBUG    rasa_sdk.executor  - Finished running 'book_meeting_room_time_form'
127.0.0.1 - - [2019-07-31 17:18:07] "POST /webhook HTTP/1.1" 200 751 0.015387

It seems like there are 2 requests to run the form ? And i notice that even though it said:

2019-07-31 17:18:07 DEBUG rasa_sdk.forms - Skipping validation

I actually tested this by using dispatcher.utter_message() in 1 of my validate functions, and the bot did utter twice on Rasa X. So it seems like it validated twice ?

This is odd, but the requests to run the form come from rasa. Can you please post the logs from that server too so that we can see which policy predicted book_meeting_room_date_form the second time?

2019-07-31 17:59:35 DEBUG    rasa.core.agent  - Created a new lock for conversation 'me'
2019-07-31 17:59:35 DEBUG    rasa.core.tracker_store  - Recreating tracker from sender id 'me'
2019-07-31 17:59:35 DEBUG    rasa.core.processor  - Received user message 'tôi muốn đặt phòng họp vào ngày 31/7/2020' with intent '{'name': 'book_meeting_room', 'confidence': 0.9512183666229248}' and entities '[{'start': 32, 'end': 41, 'value': '31/7/2020', 'entity': 'date', 'confidence': 0.9908839034846884, 'extractor': 'CRFEntityExtractor'}]'
2019-07-31 17:59:35 DEBUG    rasa.core.processor  - Current slot values:
        abort_lunch_confirm: None
        book_meeting_room_confirm: None
        change_lunch_confirm: None
        date: 31/7/2020
        day: None
        end_time: None
        list_name: None
        lunch_booked: False
        lunch_confirm: None
        lunch_confirm_full: None
        lunch_place: None
        mode: None
        month: None
        name: None
        name_in_list: None
        other_lunch_place: None
        requested_slot: None
        start_time: None
        user_id: 6
        week: None
        year: None
2019-07-31 17:59:35 DEBUG    rasa.core.processor  - Logged UserUtterance - tracker now has 25 events
2019-07-31 17:59:35 DEBUG    rasa.core.tracker_store  - Tracker with sender_id 'me' stored to database
2019-07-31 17:59:35 DEBUG    rasa.core.policies.memoization  - Current tracker state [None, None, None, {}, {'intent_book_meeting_room': 1.0, 'prev_action_listen': 1.0, 'entity_date': 1.0}]
2019-07-31 17:59:35 DEBUG    rasa.core.policies.memoization  - There is no memorised next action
2019-07-31 17:59:35 DEBUG    rasa.core.featurizers  - Feature 'entity_date' (value: '1.0') could not be found in feature map. Make sure you added all intents and entities to the domain
2019-07-31 17:59:35 DEBUG    rasa.core.policies.two_stage_fallback  - NLU confidence threshold met, confidence of fallback action set to core threshold (0.6).
2019-07-31 17:59:35 DEBUG    rasa.core.policies.form_policy  - There is no active form
2019-07-31 17:59:35 DEBUG    rasa.core.policies.ensemble  - Predicted next action using policy_1_KerasPolicy
2019-07-31 17:59:35 DEBUG    rasa.core.processor  - Predicted next action 'book_meeting_room_date_form' with confidence 0.99.
2019-07-31 17:59:35 DEBUG    rasa.core.actions.action  - Calling action endpoint to run action 'book_meeting_room_date_form'.
2019-07-31 17:59:36 DEBUG    rasa.core.processor  - Action 'book_meeting_room_date_form' ended with events '['BotUttered(text: blah blah, data: {"elements": null, "quick_replies": null, "buttons": null, "attachment": null, "image": null, "custom": null}, metadata: {})', 'BotUttered(text: blah blah, data: {"elements": null, "quick_replies": null, "buttons": null, "attachment": null, "image": null, "custom": null}, metadata: {})', 'BotUttered(text: Không thành vấn đề, Lubot sẽ thực hiện đặt lịch họp cho bạn vào ngày 31/7/2020., data: {"elements": null, "quick_replies": null, "buttons": null, "attachment": null, "image": null, "custom": null}, metadata: {})', 'Form(book_meeting_room_date_form)', 'SlotSet(key: date, value: 31/7/2020)', 'SlotSet(key: day, value: 31)', 'SlotSet(key: month, value: 7)', 'SlotSet(key: year, value: 2020)', 'SlotSet(key: date, value: 31/7/2020)', 'SlotSet(key: day, value: 31)', 'SlotSet(key: month, value: 7)', 'SlotSet(key: year, value: 2020)', 'Form(None)', 'SlotSet(key: requested_slot, value: None)']'
2019-07-31 17:59:36 DEBUG    rasa.core.processor  - Current slot values:
        abort_lunch_confirm: None
        book_meeting_room_confirm: None
        change_lunch_confirm: None
        date: 31/7/2020
        day: 31
        end_time: None
        list_name: None
        lunch_booked: False
        lunch_confirm: None
        lunch_confirm_full: None
        lunch_place: None
        mode: None
        month: 7
        name: None
        name_in_list: None
        other_lunch_place: None
        requested_slot: None
        start_time: None
        user_id: 6
        week: None
        year: 2020
2019-07-31 17:59:36 DEBUG    rasa.core.policies.memoization  - Current tracker state [None, None, {}, {'intent_book_meeting_room': 1.0, 'prev_action_listen': 1.0, 'entity_date': 1.0}, {'intent_book_meeting_room': 1.0, 'entity_date': 1.0, 'prev_book_meeting_room_date_form': 1.0}]
2019-07-31 17:59:36 DEBUG    rasa.core.policies.memoization  - There is no memorised next action
2019-07-31 17:59:36 DEBUG    rasa.core.featurizers  - Feature 'entity_date' (value: '1.0') could not be found in feature map. Make sure you added all intents and entities to the domain
2019-07-31 17:59:36 DEBUG    rasa.core.featurizers  - Feature 'entity_date' (value: '1.0') could not be found in feature map. Make sure you added all intents and entities to the domain
2019-07-31 17:59:36 DEBUG    rasa.core.policies.mapping_policy  - There is no mapped action for the predicted intent, 'book_meeting_room'.
2019-07-31 17:59:36 DEBUG    rasa.core.policies.two_stage_fallback  - NLU confidence threshold met, confidence of fallback action set to core threshold (0.6).
2019-07-31 17:59:36 DEBUG    rasa.core.policies.form_policy  - There is no active form
2019-07-31 17:59:36 DEBUG    rasa.core.policies.ensemble  - Predicted next action using policy_1_KerasPolicy
2019-07-31 17:59:36 DEBUG    rasa.core.processor  - Predicted next action 'action_listen' with confidence 1.00.
2019-07-31 17:59:36 DEBUG    rasa.core.processor  - Action 'action_listen' ended with events '[]'
2019-07-31 17:59:36 DEBUG    rasa.core.tracker_store  - Tracker with sender_id 'me' stored to database
2019-07-31 17:59:36 DEBUG    rasa.core.agent  - Deleted lock for conversation 'me' (unused)

The log from action server no longer has 2 requests, but output on Rasa X still the same.

2019-07-31 18:07:13 DEBUG    rasa_sdk.forms  - There is no active form
2019-07-31 18:07:13 DEBUG    rasa_sdk.forms  - Activated the form 'book_meeting_room_date_form'
2019-07-31 18:07:13 DEBUG    rasa_sdk.forms  - Validating pre-filled required slots: {'date': '31/7/2020'}
2019-07-31 18:07:13 DEBUG    rasa_sdk.forms  - Validating user input '{'intent': {'name': 'book_meeting_room', 'confidence': 0.9512183666229248}, 'entities': [{'start': 32, 'end': 41, 'value': '31/7/2020', 'entity': 'date', 'confidence': 0.9908839034846884, 'extractor': 'CRFEntityExtractor'}], 'intent_ranking': [{'name': 'book_meeting_room', 'confidence': 0.9512183666229248}, {'name': 'search_seat', 'confidence': 0.1119498461484909}, {'name': 'book_lunch', 'confidence': 0.09924900531768799}, {'name': 'search_department', 'confidence': 0.07593046873807907}, {'name': 'greet', 'confidence': 0.052432090044021606}, {'name': 'ask_creator', 'confidence': 0.05089648813009262}, {'name': 'goodbye', 'confidence': 0.042915817350149155}, {'name': 'introduction', 'confidence': 0.03395404666662216}, {'name': 'search_project', 'confidence': 0.019183769822120667}, {'name': 'change_lunch_place', 'confidence': 0.01169959269464016}], 'text': 'tôi muốn đặt phòng họp vào ngày 31/7/2020'}'
2019-07-31 18:07:13 DEBUG    rasa_sdk.forms  - Extracted '31/7/2020' for extra slot 'date'
2019-07-31 18:07:13 DEBUG    rasa_sdk.forms  - Validating extracted slots: {'date': '31/7/2020'}
2019-07-31 18:07:13 DEBUG    rasa_sdk.forms  - No slots left to request, all required slots are filled:
        date: 31/7/2020
        day: None
        month: None
        year: None
2019-07-31 18:07:13 DEBUG    rasa_sdk.forms  - Submitting the form 'book_meeting_room_date_form'
2019-07-31 18:07:13 DEBUG    rasa_sdk.forms  - Deactivating the form 'book_meeting_room_date_form'
2019-07-31 18:07:13 DEBUG    rasa_sdk.executor  - Finished running 'book_meeting_room_date_form'
127.0.0.1 - - [2019-07-31 18:07:13] "POST /webhook HTTP/1.1" 200 1068 0.015590

The ‘blah blah’ is the utter in my validate function.

In the rasa logs you posted, it only gets predicted once?

You are currently getting double validation because date is technically a pre-filled slot because the date slot auto-filled:

2019-07-31 18:07:13 DEBUG    rasa_sdk.forms  - Validating pre-filled required slots: {'date': '31/7/2020'}
2019-07-31 18:07:13 DEBUG    rasa_sdk.forms  - Validating user input '{'intent': {'name': 'book_meeting_room', 'confidence': 0.9512183666229248}, 'entities': [{'start': 32, 'end': 41, 'value': '31/7/2020', 'entity': 'date', 'confidence': 0.9908839034846884, 'extractor': 'CRFEntityExtractor'}], 'intent_ranking': [{'name': 'book_meeting_room', 'confidence': 0.9512183666229248}, {'name': 'search_seat', 'confidence': 0.1119498461484909}, {'name': 'book_lunch', 'confidence': 0.09924900531768799}, {'name': 'search_department', 'confidence': 0.07593046873807907}, {'name': 'greet', 'confidence': 0.052432090044021606}, {'name': 'ask_creator', 'confidence': 0.05089648813009262}, {'name': 'goodbye', 'confidence': 0.042915817350149155}, {'name': 'introduction', 'confidence': 0.03395404666662216}, {'name': 'search_project', 'confidence': 0.019183769822120667}, {'name': 'change_lunch_place', 'confidence': 0.01169959269464016}], 'text': 'tôi muốn đặt phòng họp vào ngày 31/7/2020'}'
2019-07-31 18:07:13 DEBUG    rasa_sdk.forms  - Extracted '31/7/2020' for extra slot 'date'
2019-07-31 18:07:13 DEBUG    rasa_sdk.forms  - Validating extracted slots: {'date': '31/7/2020'}

Which I suppose is a bug on our side if the slot didn’t have anything in it before your original input

Yes i think it’s only get predicted once. I have tried /restart before entering the intent a couple time so i guess the slot is empty ?

Yeah the slot should be empty. I’ll be clearer – what’s happening is that you’re entering the date in the input that is triggering the form. What happens first is that the entity auto-fills the slot during the NLU prediction, before the form action is even predicted. therefore when the form is activated, it is a “pre-filled slot” that is then validated. Then after validating the pre-filled slots, the form tries to validate any slots it picked up from the latest user input, the input that activated the form. so it looks at the entities picked up in the intent and sees if any of those, according to the slot mappings for the form, should fill a slot (which it does) so it tries to then fill the slot again, which sends it through the validation once again.

Does that make sense?

1 Like

Yes, i understand it now, thank you for the clear explaination. So can i temporarily fix this by setting the auto-fill: false for the slots ?

Yes, I believe that should do it, because the form should still pick them up ( the default slot mapping is from an entity of the same name)

1 Like

I have a similar case, as a work around I am setting the auto_fill parameter to false in my domain file for that particular slot. Can you guys please fix this in next update. Thanks!

Hi, I would like to contribute to this problem.

I was still getting the same behavior that slots were set twice using the FormPolicy. This is especially inconvenient when having a validate_{slot} function with an utterance dispatched because then, the utterance is dispatched two times.

I tried to fix the issue by setting the slot in question to auto_fill: false. Now the Slot is not getting set twice anymore, but when I try to use the slot in my answer that is dispatched in submit(), I get a None printed out for this slot.

Maybe this is the same problem I am describing here?

The problem can be solved by getting the slot values in submit() and forwarding them to the utterance template as different named placeholders.

I could see this behavior still existing in rasa 2.8. But I can’t use the workaround which you suggested as the same slot is being used outside of form on another occasion and it has to auto_fill during that flow.

Can you suggest me a better way to override this behavior without setting slot property as auto_fill: false?