Hello there,
I am using Rasa 1.10.7 and am running the server as follows:
rasa run --port 5002 --credentials credentials.yml --endpoints endpoints.yml --cors "*" --debug
I have been experiencing issues when doing a locust stress test (GitHub - salgieri/rasa-locust-stress-test: This is a basic example of how you can generate hundreds of simultaneous user connects to a Rasa instance, and send multiple conversational messages.). I have been running one instance of my rasa chatbot and have chosen 10 users to use the bot concurrently.
For up to 3 users my bot works fine and can handle all of the incoming messages. A snipet of the log when it’s working fine:
2020-10-10 14:11:45 DEBUG rasa.core.policies.mapping_policy - The mapped action, 'action_get_produtos', for this intent, 'produtos', was executed last so MappingPolicy is returning to action_listen.
2020-10-10 14:11:45 DEBUG rasa.core.policies.ensemble - Predicted next action using policy_0_MappingPolicy
2020-10-10 14:11:45 DEBUG rasa.core.processor - Predicted next action 'action_listen' with confidence 1.00.
2020-10-10 14:11:45 DEBUG rasa.core.processor - Action 'action_listen' ended with events '[]'.
2020-10-10 14:11:45 DEBUG rasa.core.lock_store - Deleted lock for conversation '95b8d811f3d14d5fb2be68e5447f7833'.
2020-10-10 14:11:52 DEBUG rasa.core.processor - Received user message 'oi' with intent '{'name': 'menu', 'confidence': 0.9912355542182922}' and entities '[]'
2020-10-10 14:11:52 DEBUG rasa.core.processor - Logged UserUtterance - tracker now has 104 events.
2020-10-10 14:11:52 DEBUG rasa.core.policies.mapping_policy - The predicted intent 'menu' is mapped to action 'action_menu' in the domain.
2020-10-10 14:11:52 DEBUG rasa.core.policies.ensemble - Predicted next action using policy_0_MappingPolicy
2020-10-10 14:11:52 DEBUG rasa.core.processor - Predicted next action 'action_menu' with confidence 1.00.
2020-10-10 14:11:52 DEBUG rasa.core.actions.action - Calling action endpoint to run action 'action_menu'.
2020-10-10 14:11:55 DEBUG rasa.core.processor - Received user message 'Vendas' with intent '{'name': 'vendas', 'confidence': 0.9595022201538086}' and entities '[]'
2020-10-10 14:11:55 DEBUG rasa.core.processor - Logged UserUtterance - tracker now has 120 events.
2020-10-10 14:11:55 DEBUG rasa.core.policies.mapping_policy - The predicted intent 'vendas' is mapped to action 'action_get_vendas' in the domain.
2020-10-10 14:11:55 DEBUG rasa.core.policies.ensemble - Predicted next action using policy_0_MappingPolicy
2020-10-10 14:11:55 DEBUG rasa.core.processor - Predicted next action 'action_get_vendas' with confidence 1.00.
2020-10-10 14:11:55 DEBUG rasa.core.actions.action - Calling action endpoint to run action 'action_get_vendas'.
2020-10-10 14:11:56 DEBUG rasa.core.processor - Action 'action_menu' ended with events '[BotUttered('Olá! Voce pode pode me dizer o que deseja. Por exemplo: 'Qual é a filial com o maior faturamento no ano de 2010?' ou 'Preço médio
por filial'.', {"elements": null, "quick_replies": null, "buttons": null, "attachment": null, "image": null, "custom": null}, {}, 1602349916.9670641), BotUttered('Alternativamente, você pode escolher uma das opções abaixo', {"elements"
: null, "quick_replies": null, "buttons": [{"type": "postback", "title": "KPIs", "payload": "/kpis"}, {"type": "postback", "title": "Vendas", "payload": "/vendas"}, {"type": "postback", "title": "Produtos", "payload": "/produtos"}, {"t
ype": "postback", "title": "Funcion\u00e1rios", "payload": "/rep_info"}, {"type": "postback", "title": "Log\u00edstica", "payload": "/logistica"}, {"type": "postback", "title": "Filtros", "payload": "/filtros"}], "attachment": null, "i
mage": null, "custom": null}, {"button_type": "vertical"}, 1602349916.9670641), BotUttered('Posteriormente, se quiser voltar ao menu, digite 'menu'.', {"elements": null, "quick_replies": null, "buttons": null, "attachment": null, "imag
e": null, "custom": null}, {}, 1602349916.9670641)]'.
2020-10-10 14:11:56 DEBUG rasa.core.processor - Current slot values:
Ano: None
Filial: None
Mes: None
campo: None
campo_valor: None
requested_slot: None
selected_dimensions: {'Ano': '2010'}
username: None
2020-10-10 14:11:56 DEBUG rasa.core.policies.mapping_policy - The mapped action, 'action_menu', for this intent, 'menu', was executed last so MappingPolicy is returning to action_listen.
2020-10-10 14:11:56 DEBUG rasa.core.policies.ensemble - Predicted next action using policy_0_MappingPolicy
2020-10-10 14:11:56 DEBUG rasa.core.processor - Predicted next action 'action_listen' with confidence 1.00.
2020-10-10 14:11:56 DEBUG rasa.core.processor - Action 'action_listen' ended with events '[]'.
2020-10-10 14:11:56 DEBUG rasa.core.lock_store - Deleted lock for conversation '99693285e8184183bf1301b3a8e5f0c5'.
2020-10-10 14:11:59 DEBUG rasa.core.processor - Action 'action_get_vendas' ended with events '[BotUttered('No ano de 2010, o faturamento é de R$ 128.800.994,80 e está maior (+55.84%) em relação ao mesmo período do ano passado (R$ 8
2.649.597,16). ', {"elements": null, "quick_replies": null, "buttons": null, "attachment": null, "image": null, "custom": null}, {}, 1602349919.3649654), BotUttered('O número de vendas cresceu (+53.69%): R$ 6.094,00.', {"elements": nul
l, "quick_replies": null, "buttons": null, "attachment": null, "image": null, "custom": null}, {}, 1602349919.3649654), BotUttered('O ticket médio no ano é de R$ 21.021,04.', {"elements": null, "quick_replies": null, "buttons": null, "
attachment": null, "image": null, "custom": null}, {}, 1602349919.365966), BotUttered('
Filtros considerados:
Ano: 2010
', {"elements": null, "quick_replies": null, "buttons": null, "attachment": null, "image": null, "custom": null}, {}, 1602349919.365966), BotUttered('Você pode clicar o botão se quiser ver o gráfico.', {"elements": null, "quick
_replies": null, "buttons": [{"type": "postback", "title": "Gr\u00e1fico", "payload": "/grafico_comp_fat"}], "attachment": null, "image": null, "custom": null}, {}, 1602349919.365966), <rasa.core.events.SlotSet object at 0x000001602980
8C88>, <rasa.core.events.SlotSet object at 0x0000016029808388>, <rasa.core.events.SlotSet object at 0x0000016029808688>, <rasa.core.events.SlotSet object at 0x0000016029808908>]'.
However, after 3 users, the bot isn’t able to process the incoming messages, has a delay, and then repeats these messages multiple times when they finally do get sent. I receive in my log:
2020-10-10 13:37:11 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID '6ff3b9d7b8a0468b87fb077d5f178026'. Retrying...
2020-10-10 13:37:12 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID 'c205092364d34d90a2fe709295c3f786'. Retrying...
2020-10-10 13:37:12 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID '55da7d8e065447c4a66fba90d13d2816'. Retrying...
2020-10-10 13:37:12 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID '6ef27dc541d84c119d1a81011815e364'. Retrying...
2020-10-10 13:37:12 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID 'e9da2149c98545bf81cb4c8e753a9a5c'. Retrying...
2020-10-10 13:37:12 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID 'e42551e1de53482898aafeacadf25547'. Retrying...
2020-10-10 13:37:12 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID 'dbe69765628340edbe3c506146157760'. Retrying...
2020-10-10 13:37:12 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID 'e9da2149c98545bf81cb4c8e753a9a5c'. Retrying...
2020-10-10 13:37:12 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID '6ef27dc541d84c119d1a81011815e364'. Retrying...
2020-10-10 13:37:12 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID '04eb1e80b8a542df83a7bfb23f41c55f'. Retrying...
2020-10-10 13:37:13 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID 'a53e0bc44ba64763b852fa27495f2b23'. Retrying...
2020-10-10 13:37:13 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID '6ef27dc541d84c119d1a81011815e364'. Retrying...
2020-10-10 13:37:13 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID '1a05e522d0f8412bbebd8edd52503c67'. Retrying...
2020-10-10 13:37:13 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID 'dbe69765628340edbe3c506146157760'. Retrying...
2020-10-10 13:37:13 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID 'e42551e1de53482898aafeacadf25547'. Retrying...
2020-10-10 13:37:13 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID '6ff3b9d7b8a0468b87fb077d5f178026'. Retrying...
2020-10-10 13:37:13 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID '55da7d8e065447c4a66fba90d13d2816'. Retrying...
2020-10-10 13:37:13 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID 'a53e0bc44ba64763b852fa27495f2b23'. Retrying...
2020-10-10 13:37:13 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID 'e42551e1de53482898aafeacadf25547'. Retrying...
2020-10-10 13:37:13 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID 'c205092364d34d90a2fe709295c3f786'. Retrying...
2020-10-10 13:37:13 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID 'a53e0bc44ba64763b852fa27495f2b23'. Retrying...
2020-10-10 13:37:13 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID '04eb1e80b8a542df83a7bfb23f41c55f'. Retrying...
2020-10-10 13:37:13 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID '6ff3b9d7b8a0468b87fb077d5f178026'. Retrying...
2020-10-10 13:37:14 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID 'c205092364d34d90a2fe709295c3f786'. Retrying...
2020-10-10 13:37:14 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID '55da7d8e065447c4a66fba90d13d2816'. Retrying...
2020-10-10 13:37:14 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID '6ef27dc541d84c119d1a81011815e364'. Retrying...
2020-10-10 13:37:14 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID 'e9da2149c98545bf81cb4c8e753a9a5c'. Retrying...
2020-10-10 13:37:14 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID 'e42551e1de53482898aafeacadf25547'. Retrying...
2020-10-10 13:37:14 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID 'dbe69765628340edbe3c506146157760'. Retrying...
2020-10-10 13:37:14 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID 'e9da2149c98545bf81cb4c8e753a9a5c'. Retrying...
2020-10-10 13:37:14 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID '6ef27dc541d84c119d1a81011815e364'. Retrying...
2020-10-10 13:37:14 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID '04eb1e80b8a542df83a7bfb23f41c55f'. Retrying...
2020-10-10 13:37:15 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID 'a53e0bc44ba64763b852fa27495f2b23'. Retrying...
2020-10-10 13:37:15 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID '6ef27dc541d84c119d1a81011815e364'. Retrying...
2020-10-10 13:37:15 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID 'dbe69765628340edbe3c506146157760'. Retrying...
2020-10-10 13:37:15 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID '1a05e522d0f8412bbebd8edd52503c67'. Retrying...
2020-10-10 13:37:15 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID 'e42551e1de53482898aafeacadf25547'. Retrying...
2020-10-10 13:37:15 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID '6ff3b9d7b8a0468b87fb077d5f178026'. Retrying...
2020-10-10 13:37:15 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID '55da7d8e065447c4a66fba90d13d2816'. Retrying...
2020-10-10 13:37:15 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID 'a53e0bc44ba64763b852fa27495f2b23'. Retrying...
2020-10-10 13:37:15 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID 'e42551e1de53482898aafeacadf25547'. Retrying...
2020-10-10 13:37:15 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID 'a53e0bc44ba64763b852fa27495f2b23'. Retrying...
2020-10-10 13:37:15 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID 'c205092364d34d90a2fe709295c3f786'. Retrying...
2020-10-10 13:37:15 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID '04eb1e80b8a542df83a7bfb23f41c55f'. Retrying...
2020-10-10 13:37:15 DEBUG rasa.core.channels.socketio - User 55da7d8e065447c4a66fba90d13d2816 disconnected from socketIO endpoint.
2020-10-10 13:37:15 DEBUG rasa.core.channels.socketio - User dbe69765628340edbe3c506146157760 disconnected from socketIO endpoint.
2020-10-10 13:37:15 DEBUG rasa.core.channels.socketio - User 1a05e522d0f8412bbebd8edd52503c67 disconnected from socketIO endpoint.
2020-10-10 13:37:15 DEBUG rasa.core.channels.socketio - User c205092364d34d90a2fe709295c3f786 disconnected from socketIO endpoint.
2020-10-10 13:37:15 DEBUG rasa.core.channels.socketio - User 6ff3b9d7b8a0468b87fb077d5f178026 disconnected from socketIO endpoint.
2020-10-10 13:37:15 DEBUG rasa.core.channels.socketio - User e9da2149c98545bf81cb4c8e753a9a5c disconnected from socketIO endpoint.
2020-10-10 13:37:15 DEBUG rasa.core.channels.socketio - User 04eb1e80b8a542df83a7bfb23f41c55f disconnected from socketIO endpoint.
2020-10-10 13:37:15 DEBUG rasa.core.channels.socketio - User 6ef27dc541d84c119d1a81011815e364 disconnected from socketIO endpoint.
2020-10-10 13:37:15 DEBUG rasa.core.channels.socketio - User e42551e1de53482898aafeacadf25547 disconnected from socketIO endpoint.
2020-10-10 13:37:15 DEBUG rasa.core.channels.socketio - User a53e0bc44ba64763b852fa27495f2b23 disconnected from socketIO endpoint.
2020-10-10 13:37:15 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID '6ff3b9d7b8a0468b87fb077d5f178026'. Retrying...
2020-10-10 13:37:16 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID 'c205092364d34d90a2fe709295c3f786'. Retrying...
2020-10-10 13:37:16 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID '55da7d8e065447c4a66fba90d13d2816'. Retrying...
2020-10-10 13:37:16 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID '6ef27dc541d84c119d1a81011815e364'. Retrying...
2020-10-10 13:37:16 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID 'e9da2149c98545bf81cb4c8e753a9a5c'. Retrying...
2020-10-10 13:37:16 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID 'e42551e1de53482898aafeacadf25547'. Retrying...
2020-10-10 13:37:16 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID 'dbe69765628340edbe3c506146157760'. Retrying...
Does anyone know the source of this problem as well as how to fix it? Does it have to do with ngrok or timeouts or the capabilities of rasa itself?
I have tried increasing the number of sanic workers to 2 but this had no effect. What is the source of this problem?
Best regards,
Robyn
