Did more stress testing under debug mode. Was just able to bring it to the same state when custom action stopped responding.
Interesting observation: Using a different Facebook user account and everything still working. It is just failing for the Facebook user that I was doing stress testing with.
Log for the failing request:
2020-01-20 23:35:55,589 [DEBUG] Recreating tracker for id ‘2422564777865934’
2020-01-20 23:35:55,749 [DEBUG] Received user message ‘17’ with intent ‘{‘name’: ‘answer’, ‘confidence’: 0.973506510257721}’ and entities ‘[{‘start’: 0, ‘end’: 2, ‘value’: ‘17’, ‘entity’: ‘integer_answer’, ‘confidence’: 0.7800877713410326, ‘extractor’: ‘CRFEntityExtractor’}]’
2020-01-20 23:35:55,750 [DEBUG] Current slot values:
a_b_ans: 1,0,0
q_num: 7
score: 0
start_time: 1579562803.7872338
2020-01-20 23:35:55,750 [DEBUG] Logged UserUtterance - tracker now has 5058 events
2020-01-20 23:35:55,831 [DEBUG] Current tracker state [{‘slot_start_time_0’: 1.0, ‘entity_integer_answer’: 1.0, ‘slot_a_b_ans_0’: 1.0, ‘intent_answer’: 1.0, ‘slot_score_0’: 1.0, ‘slot_q_num_0’: 1.0, ‘prev_action_listen’: 1.0}, {‘slot_start_time_0’: 1.0, ‘entity_integer_answer’: 1.0, ‘slot_a_b_ans_0’: 1.0, ‘intent_answer’: 1.0, ‘slot_score_0’: 1.0, ‘prev_action_multiplication_table_challenge’: 1.0, ‘slot_q_num_0’: 1.0}, {‘slot_start_time_0’: 1.0, ‘entity_integer_answer’: 1.0, ‘slot_a_b_ans_0’: 1.0, ‘intent_answer’: 1.0, ‘slot_score_0’: 1.0, ‘slot_q_num_0’: 1.0, ‘prev_action_listen’: 1.0}, {‘slot_start_time_0’: 1.0, ‘entity_integer_answer’: 1.0, ‘slot_a_b_ans_0’: 1.0, ‘intent_answer’: 1.0, ‘slot_score_0’: 1.0, ‘prev_action_multiplication_table_challenge’: 1.0, ‘slot_q_num_0’: 1.0}, {‘slot_start_time_0’: 1.0, ‘entity_integer_answer’: 1.0, ‘slot_a_b_ans_0’: 1.0, ‘intent_answer’: 1.0, ‘slot_score_0’: 1.0, ‘slot_q_num_0’: 1.0, ‘prev_action_listen’: 1.0}]
2020-01-20 23:35:55,832 [DEBUG] There is no memorised next action
2020-01-20 23:35:55,903 [DEBUG] Feature ‘entity_integer_answer’ (value: ‘1.0’) could not be found in feature map. Make sure you added all intents and entities to the domain
2020-01-20 23:35:55,904 [DEBUG] Feature ‘entity_integer_answer’ (value: ‘1.0’) could not be found in feature map. Make sure you added all intents and entities to the domain
2020-01-20 23:35:55,904 [DEBUG] Feature ‘entity_integer_answer’ (value: ‘1.0’) could not be found in feature map. Make sure you added all intents and entities to the domain
2020-01-20 23:35:55,904 [DEBUG] Feature ‘entity_integer_answer’ (value: ‘1.0’) could not be found in feature map. Make sure you added all intents and entities to the domain
2020-01-20 23:35:55,905 [DEBUG] Feature ‘entity_integer_answer’ (value: ‘1.0’) could not be found in feature map. Make sure you added all intents and entities to the domain
2020-01-20 23:35:55,911 [DEBUG] Predicted next action using policy_1_KerasPolicy
2020-01-20 23:35:55,912 [DEBUG] Predicted next action ‘action_multiplication_table_challenge’ with confidence 1.00.
2020-01-20 23:35:55,931 [DEBUG] Calling action endpoint to run action ‘action_multiplication_table_challenge’.
2020-01-20 23:35:56,017 [ERROR] Encountered an exception while running action ‘action_multiplication_table_challenge’. Bot will continue, but the actions events are lost. Please check the logs of your action server for more information.
2020-01-20 23:35:56,018 [DEBUG] Failed to execute custom action.
Traceback (most recent call last):
File “/build/lib/python3.6/site-packages/rasa/core/actions/action.py”, line 494, in run
json=json_body, method=“post”, timeout=DEFAULT_REQUEST_TIMEOUT
File “/usr/local/lib/python3.6/asyncio/coroutines.py”, line 110, in next
return self.gen.send(None)
File “/build/lib/python3.6/site-packages/rasa/utils/endpoints.py”, line 150, in request
resp.status, resp.reason, await resp.content.read()
rasa.utils.endpoints.ClientResponseError: 413, Request Entity Too Large, body=‘b’\r\n413 Request Entity Too Large\r\n\r\n
413 Request Entity Too Large
\r\n
nginx/1.10.3 (Ubuntu)\r\n\r\n\r\n’’
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
File “/build/lib/python3.6/site-packages/rasa/core/processor.py”, line 503, in _run_action
events = await action.run(output_channel, nlg, tracker, self.domain)
File “/usr/local/lib/python3.6/asyncio/coroutines.py”, line 110, in next
return self.gen.send(None)
File “/build/lib/python3.6/site-packages/rasa/core/actions/action.py”, line 517, in run
raise Exception(“Failed to execute custom action.”) from e
Exception: Failed to execute custom action.
2020-01-20 23:35:56,021 [DEBUG] Action ‘action_multiplication_table_challenge’ ended with events ‘’
2020-01-20 23:35:56,022 [DEBUG] Current slot values:
a_b_ans: 1,0,0
q_num: 7
score: 0
start_time: 1579562803.7872338
2020-01-20 23:35:56,107 [DEBUG] Current tracker state [{‘slot_start_time_0’: 1.0, ‘entity_integer_answer’: 1.0, ‘slot_a_b_ans_0’: 1.0, ‘intent_answer’: 1.0, ‘slot_score_0’: 1.0, ‘prev_action_multiplication_table_challenge’: 1.0, ‘slot_q_num_0’: 1.0}, {‘slot_start_time_0’: 1.0, ‘entity_integer_answer’: 1.0, ‘slot_a_b_ans_0’: 1.0, ‘intent_answer’: 1.0, ‘slot_score_0’: 1.0, ‘slot_q_num_0’: 1.0, ‘prev_action_listen’: 1.0}, {‘slot_start_time_0’: 1.0, ‘entity_integer_answer’: 1.0, ‘slot_a_b_ans_0’: 1.0, ‘intent_answer’: 1.0, ‘slot_score_0’: 1.0, ‘prev_action_multiplication_table_challenge’: 1.0, ‘slot_q_num_0’: 1.0}, {‘slot_start_time_0’: 1.0, ‘entity_integer_answer’: 1.0, ‘slot_a_b_ans_0’: 1.0, ‘intent_answer’: 1.0, ‘slot_score_0’: 1.0, ‘slot_q_num_0’: 1.0, ‘prev_action_listen’: 1.0}, {‘slot_start_time_0’: 1.0, ‘entity_integer_answer’: 1.0, ‘slot_a_b_ans_0’: 1.0, ‘intent_answer’: 1.0, ‘slot_score_0’: 1.0, ‘prev_action_multiplication_table_challenge’: 1.0, ‘slot_q_num_0’: 1.0}]
2020-01-20 23:35:56,108 [DEBUG] There is no memorised next action
2020-01-20 23:35:56,160 [DEBUG] Feature ‘entity_integer_answer’ (value: ‘1.0’) could not be found in feature map. Make sure you added all intents and entities to the domain
2020-01-20 23:35:56,161 [DEBUG] Feature ‘entity_integer_answer’ (value: ‘1.0’) could not be found in feature map. Make sure you added all intents and entities to the domain
2020-01-20 23:35:56,162 [DEBUG] Feature ‘entity_integer_answer’ (value: ‘1.0’) could not be found in feature map. Make sure you added all intents and entities to the domain
2020-01-20 23:35:56,162 [DEBUG] Feature ‘entity_integer_answer’ (value: ‘1.0’) could not be found in feature map. Make sure you added all intents and entities to the domain
2020-01-20 23:35:56,162 [DEBUG] Feature ‘entity_integer_answer’ (value: ‘1.0’) could not be found in feature map. Make sure you added all intents and entities to the domain
2020-01-20 23:35:56,167 [DEBUG] There is no mapped action for the predicted intent, ‘answer’.
2020-01-20 23:35:56,168 [DEBUG] Predicted next action using policy_1_KerasPolicy
2020-01-20 23:35:56,168 [DEBUG] Predicted next action ‘action_listen’ with confidence 1.00.
2020-01-20 23:35:56,169 [DEBUG] Action ‘action_listen’ ended with events ‘’
2020-01-20 23:35:56,226 [DEBUG] Deleted lock for conversation ‘2422564777865934’.
Log for the working request using a different Facebook user:
2020-01-20 23:36:21,003 [DEBUG] Recreating tracker for id ‘2693248870743672’
2020-01-20 23:36:21,012 [DEBUG] Received user message ‘3’ with intent ‘{‘name’: ‘answer’, ‘confidence’: 0.973506510257721}’ and entities ‘[{‘start’: 0, ‘end’: 1, ‘value’: ‘3’, ‘entity’: ‘integer_answer’, ‘confidence’: 0.7800877713410326, ‘extractor’: ‘CRFEntityExtractor’}]’
2020-01-20 23:36:21,013 [DEBUG] Current slot values:
a_b_ans: 3,1,3
q_num: 2
score: 1
start_time: 1579563304.9819882
2020-01-20 23:36:21,014 [DEBUG] Logged UserUtterance - tracker now has 213 events
2020-01-20 23:36:21,017 [DEBUG] Current tracker state [{‘slot_start_time_0’: 1.0, ‘entity_integer_answer’: 1.0, ‘slot_a_b_ans_0’: 1.0, ‘intent_answer’: 1.0, ‘slot_score_0’: 1.0, ‘slot_q_num_0’: 1.0, ‘prev_action_listen’: 1.0}, {‘slot_start_time_0’: 1.0, ‘entity_integer_answer’: 1.0, ‘slot_a_b_ans_0’: 1.0, ‘intent_answer’: 1.0, ‘slot_score_0’: 1.0, ‘prev_action_multiplication_table_challenge’: 1.0, ‘slot_q_num_0’: 1.0}, {‘slot_start_time_0’: 1.0, ‘entity_integer_answer’: 1.0, ‘slot_a_b_ans_0’: 1.0, ‘intent_answer’: 1.0, ‘slot_score_0’: 1.0, ‘slot_q_num_0’: 1.0, ‘prev_action_listen’: 1.0}, {‘slot_start_time_0’: 1.0, ‘entity_integer_answer’: 1.0, ‘slot_a_b_ans_0’: 1.0, ‘intent_answer’: 1.0, ‘slot_score_0’: 1.0, ‘prev_action_multiplication_table_challenge’: 1.0, ‘slot_q_num_0’: 1.0}, {‘slot_start_time_0’: 1.0, ‘entity_integer_answer’: 1.0, ‘slot_a_b_ans_0’: 1.0, ‘intent_answer’: 1.0, ‘slot_score_0’: 1.0, ‘slot_q_num_0’: 1.0, ‘prev_action_listen’: 1.0}]
2020-01-20 23:36:21,018 [DEBUG] There is no memorised next action
2020-01-20 23:36:21,021 [DEBUG] Feature ‘entity_integer_answer’ (value: ‘1.0’) could not be found in feature map. Make sure you added all intents and entities to the domain
2020-01-20 23:36:21,022 [DEBUG] Feature ‘entity_integer_answer’ (value: ‘1.0’) could not be found in feature map. Make sure you added all intents and entities to the domain
2020-01-20 23:36:21,023 [DEBUG] Feature ‘entity_integer_answer’ (value: ‘1.0’) could not be found in feature map. Make sure you added all intents and entities to the domain
2020-01-20 23:36:21,023 [DEBUG] Feature ‘entity_integer_answer’ (value: ‘1.0’) could not be found in feature map. Make sure you added all intents and entities to the domain
2020-01-20 23:36:21,024 [DEBUG] Feature ‘entity_integer_answer’ (value: ‘1.0’) could not be found in feature map. Make sure you added all intents and entities to the domain
2020-01-20 23:36:21,029 [DEBUG] Predicted next action using policy_1_KerasPolicy
2020-01-20 23:36:21,029 [DEBUG] Predicted next action ‘action_multiplication_table_challenge’ with confidence 1.00.
2020-01-20 23:36:21,030 [DEBUG] Calling action endpoint to run action ‘action_multiplication_table_challenge’.
2020-01-20 23:36:21,065 [DEBUG] Action ‘action_multiplication_table_challenge’ ended with events ‘[‘BotUttered(text: Correct!, data: {“elements”: null, “quick_replies”: null, “buttons”: null, “attachment”: null, “image”: null, “custom”: null}, metadata: {})’, ‘BotUttered(text: (3) 2 X 1 = ?, data: {“elements”: null, “quick_replies”: null, “buttons”: null, “attachment”: null, “image”: null, “custom”: null}, metadata: {})’, ‘SlotSet(key: a_b_ans, value: 2,1,2)’, ‘SlotSet(key: q_num, value: 3)’, ‘SlotSet(key: score, value: 2)’, ‘SlotSet(key: start_time, value: 1579563304.9819882)’]’
2020-01-20 23:36:21,066 [DEBUG] Current slot values:
a_b_ans: 2,1,2
q_num: 3
score: 2
start_time: 1579563304.9819882
2020-01-20 23:36:21,823 [DEBUG] Current tracker state [{‘slot_start_time_0’: 1.0, ‘entity_integer_answer’: 1.0, ‘slot_a_b_ans_0’: 1.0, ‘intent_answer’: 1.0, ‘slot_score_0’: 1.0, ‘prev_action_multiplication_table_challenge’: 1.0, ‘slot_q_num_0’: 1.0}, {‘slot_start_time_0’: 1.0, ‘entity_integer_answer’: 1.0, ‘slot_a_b_ans_0’: 1.0, ‘intent_answer’: 1.0, ‘slot_score_0’: 1.0, ‘slot_q_num_0’: 1.0, ‘prev_action_listen’: 1.0}, {‘slot_start_time_0’: 1.0, ‘entity_integer_answer’: 1.0, ‘slot_a_b_ans_0’: 1.0, ‘intent_answer’: 1.0, ‘slot_score_0’: 1.0, ‘prev_action_multiplication_table_challenge’: 1.0, ‘slot_q_num_0’: 1.0}, {‘slot_start_time_0’: 1.0, ‘entity_integer_answer’: 1.0, ‘slot_a_b_ans_0’: 1.0, ‘intent_answer’: 1.0, ‘slot_score_0’: 1.0, ‘slot_q_num_0’: 1.0, ‘prev_action_listen’: 1.0}, {‘slot_start_time_0’: 1.0, ‘entity_integer_answer’: 1.0, ‘slot_a_b_ans_0’: 1.0, ‘intent_answer’: 1.0, ‘slot_score_0’: 1.0, ‘prev_action_multiplication_table_challenge’: 1.0, ‘slot_q_num_0’: 1.0}]
2020-01-20 23:36:21,824 [DEBUG] There is no memorised next action
2020-01-20 23:36:21,827 [DEBUG] Feature ‘entity_integer_answer’ (value: ‘1.0’) could not be found in feature map. Make sure you added all intents and entities to the domain
2020-01-20 23:36:21,828 [DEBUG] Feature ‘entity_integer_answer’ (value: ‘1.0’) could not be found in feature map. Make sure you added all intents and entities to the domain
2020-01-20 23:36:21,828 [DEBUG] Feature ‘entity_integer_answer’ (value: ‘1.0’) could not be found in feature map. Make sure you added all intents and entities to the domain
2020-01-20 23:36:21,829 [DEBUG] Feature ‘entity_integer_answer’ (value: ‘1.0’) could not be found in feature map. Make sure you added all intents and entities to the domain
2020-01-20 23:36:21,829 [DEBUG] Feature ‘entity_integer_answer’ (value: ‘1.0’) could not be found in feature map. Make sure you added all intents and entities to the domain
2020-01-20 23:36:21,835 [DEBUG] There is no mapped action for the predicted intent, ‘answer’.
2020-01-20 23:36:21,836 [DEBUG] Predicted next action using policy_1_KerasPolicy
2020-01-20 23:36:21,836 [DEBUG] Predicted next action ‘action_listen’ with confidence 1.00.
2020-01-20 23:36:21,837 [DEBUG] Action ‘action_listen’ ended with events ‘’
2020-01-20 23:36:21,841 [DEBUG] Deleted lock for conversation ‘2693248870743672’.