Failed to acquire lock for conversation ID

Hi, when I running rasa(2.8.3), and it gives like…

2022-03-14 09:55:12 DEBUG    rasa.core.lock_store  - Failed to acquire lock for conversation ID '62420ae4264b4d42a9aa00eddae52267' because 2 other item(s) for this conversation ID have to be finished processing first. Retrying in 1 seconds ..

Please share me your valuable feedback, that how can I fix this issue. Thanks all…

@ck4all89 Could you please share the command you’re trying to run, and full content of the logs please?

Hi Anca, thanks for reply.

I run these 2 commands-

**nohup rasa run --ssl-certificate xxxxxxxxxx --ssl-keyfile xxxxxxxxxx -m ./models --endpoints endpoints.yml -p 5005 --credentials credentials.yml --enable-api --cors "*" &**


**nohup python3 -m rasa_sdk --cors "*" --actions actions --ssl-keyfile xxxxxxxxxx --ssl-certificate xxxxxxxxxx &**

And below is the issue, that I get in the terminal-

**rasa.core.lock_store  - Issuing ticket for conversation 'b745401fd622428da0cc7394851d73ea'.**
**2022-03-14 05:45:48 DEBUG    rasa.core.lock_store  - Acquiring lock for conversation 'b745401fd622428da0cc7394851d73ea'.**
**2022-03-14 05:45:48 DEBUG    rasa.core.lock_store  - Failed to acquire lock for conversation ID 'b745401fd622428da0cc7394851d73ea' because 1 other item(s) for this conversation ID have to be finished processing first. Retrying in 1 seconds ...**


For "full content of the logs", can you please share me the process that I can get the Rasa logs.

Please, let me know if you want anything else…

Hey @ck4all89 you can also add --debug to rasa run command to check what exactly is happening behind

Yes, in debug mode (–debug), I run the command, and showing-

**rasa.core.lock_store - Issuing ticket for conversation ‘b745401fd622428da0cc7394851d73ea’.** **2022-03-14 05:45:48 DEBUG rasa.core.lock_store - Acquiring lock for conversation ‘b745401fd622428da0cc7394851d73ea’.** **2022-03-14 05:45:48 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID ‘b745401fd622428da0cc7394851d73ea’ because 1 other item(s) for this conversation ID have to be finished processing first. Retrying in 1 seconds …**

@ck4all89 are you using inmemory lock store or redis lock store?

Hi San,

I used InMemoryLockStore and RedisLockStore, both I had tried.

When I used InMemoryLockStore (as default) it shows in terminal-

2022-03-16 08:45:05 DEBUG rasa.core.actions.forms - Validating extracted slots: {} 2022-03-16 08:45:05 DEBUG rasa.core.actions.action - Calling action endpoint to run action ‘validate_clientAuthForm’. 2022-03-16 08:45:07 DEBUG rasa.core.lock_store - Issuing ticket for conversation ‘65e0d841883b47b381dd32d219d0b224’. 2022-03-16 08:45:07 DEBUG rasa.core.lock_store - Acquiring lock for conversation ‘65e0d841883b47b381dd32d219d0b224’. 2022-03-16 08:45:07 DEBUG rasa.core.lock_store - Failed to acquire lock for conversation ID ‘65e0d841883b47b381dd32d219d0b224’ because 1 other item(s) for this conversation ID have to be finished processing first. Retrying in 1 seconds …


And, when I used RedisLockStore to make changes in endpoints.yml file-


the terminal shows-

2022-03-16 06:10:31 INFO root - Starting Rasa server on https://localhost:5005 2022-03-16 06:10:31 DEBUG rasa.core.utils - Using the default number of Sanic workers (1). 2022-03-16 06:10:31 INFO rasa.model - Loading model models/20220315-110614.tar.gz… 2022-03-16 06:10:32 DEBUG rasa.model - Extracted model to ‘/tmp/tmpgdx7xrtc’. 2022-03-16 06:10:32 DEBUG urllib3.connectionpool - Starting new HTTPS connection (1): api.segment.io:443 2022-03-16 06:10:33 DEBUG urllib3.connectionpool - https://api.segment.io:443 “POST /v1/track HTTP/1.1” 200 21 2022-03-16 06:10:33 INFO root - Enabling coroutine debugging. Loop id 96780128. 2022-03-16 06:10:33 INFO rasa.model - Loading model models/20220315-110614.tar.gz… 2022-03-16 06:10:35 DEBUG rasa.model - Extracted model to ‘/tmp/tmpfvcjqcpr’. 2022-03-16 06:10:35 DEBUG rasa.utils.tensorflow.models - Loading the model from /tmp/tmpfvcjqcpr/nlu/component_5_DIETClassifier.tf_model with finetune_mode=False… 2022-03-16 06:10:35 DEBUG rasa.nlu.classifiers.diet_classifier - Following metrics will be logged during training: 2022-03-16 06:10:35 DEBUG rasa.nlu.classifiers.diet_classifier - t_loss (total loss) 2022-03-16 06:10:35 DEBUG rasa.nlu.classifiers.diet_classifier - i_acc (intent acc) 2022-03-16 06:10:35 DEBUG rasa.nlu.classifiers.diet_classifier - i_loss (intent loss) 2022-03-16 06:10:46 DEBUG rasa.utils.tensorflow.models - Finished loading the model. 2022-03-16 06:10:46 DEBUG rasa.utils.tensorflow.models - Loading the model from /tmp/tmpfvcjqcpr/nlu/component_7_ResponseSelector.tf_model with finetune_mode=False… 2022-03-16 06:10:46 DEBUG rasa.nlu.selectors.response_selector - Following metrics will be logged during training: 2022-03-16 06:10:46 DEBUG rasa.nlu.selectors.response_selector - t_loss (total loss) 2022-03-16 06:10:46 DEBUG rasa.nlu.selectors.response_selector - r_acc (response acc) 2022-03-16 06:10:46 DEBUG rasa.nlu.selectors.response_selector - r_loss (response loss) 2022-03-16 06:10:50 INFO rasa_sdk.endpoint - Starting action endpoint server… 2022-03-16 06:10:50 INFO rasa_sdk.executor - Registered function for ‘action_ask_clientName’. 2022-03-16 06:10:50 INFO rasa_sdk.executor - Registered function for ‘action_ask_clientOrganization’. 2022-03-16 06:10:50 INFO rasa_sdk.executor - Registered function for ‘action_ask_clientEmail’. 2022-03-16 06:10:50 INFO rasa_sdk.executor - Registered function for ‘action_ask_clientPhone’. 2022-03-16 06:10:50 INFO rasa_sdk.executor - Registered function for ‘action_clientAuthFormSubmit’. 2022-03-16 06:10:50 INFO rasa_sdk.executor - Registered function for ‘validate_clientAuthForm’. 2022-03-16 06:10:50 INFO rasa_sdk.endpoint - Action endpoint is up and running on https://0.0.0.0:5055 2022-03-16 06:10:50 DEBUG rasa_sdk.utils - Using the default number of Sanic workers (1). 2022-03-16 06:10:50 DEBUG rasa.utils.tensorflow.models - Finished loading the model. 2022-03-16 06:10:50 DEBUG rasa.utils.tensorflow.models - Loading the model from /tmp/tmpfvcjqcpr/nlu/component_8_ResponseSelector.tf_model with finetune_mode=False… 2022-03-16 06:10:50 DEBUG rasa.nlu.selectors.response_selector - Following metrics will be logged during training: 2022-03-16 06:10:50 DEBUG rasa.nlu.selectors.response_selector - t_loss (total loss) 2022-03-16 06:10:50 DEBUG rasa.nlu.selectors.response_selector - r_acc (response acc) 2022-03-16 06:10:50 DEBUG rasa.nlu.selectors.response_selector - r_loss (response loss) 2022-03-16 06:10:54 DEBUG rasa.utils.tensorflow.models - Finished loading the model. 2022-03-16 06:10:54 DEBUG rasa.utils.tensorflow.models - Loading the model from /tmp/tmpfvcjqcpr/nlu/component_9_ResponseSelector.tf_model with finetune_mode=False… 2022-03-16 06:10:54 DEBUG rasa.nlu.selectors.response_selector - Following metrics will be logged during training: 2022-03-16 06:10:54 DEBUG rasa.nlu.selectors.response_selector - t_loss (total loss) 2022-03-16 06:10:54 DEBUG rasa.nlu.selectors.response_selector - r_acc (response acc) 2022-03-16 06:10:54 DEBUG rasa.nlu.selectors.response_selector - r_loss (response loss) 2022-03-16 06:10:58 DEBUG rasa.utils.tensorflow.models - Finished loading the model. 2022-03-16 06:10:58 DEBUG rasa.core.tracker_store - Attempting to connect to database via ‘mysql+pymysql://xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx’. 2022-03-16 06:10:58 DEBUG rasa.core.tracker_store - Connection to SQL database ‘xxxxxxx’ successful. 2022-03-16 06:10:58 DEBUG rasa.core.tracker_store - Connected to SQLTrackerStore. 2022-03-16 06:10:58 DEBUG rasa.core.lock_store - Connected to lock store ‘RedisLockStore’. 2022-03-16 06:11:00 DEBUG rasa.model - Extracted model to ‘/tmp/tmp_nz3yuii’. 2022-03-16 06:11:00 DEBUG rasa.utils.tensorflow.models - Loading the model from /tmp/tmp_nz3yuii/core/policy_2_UnexpecTEDIntentPolicy/unexpected_intent_policy.tf_model with finetune_mode=False… 2022-03-16 06:11:09 DEBUG rasa.utils.tensorflow.models - Finished loading the model. 2022-03-16 06:11:09 WARNING rasa.shared.utils.common - The UnexpecTED Intent Policy is currently experimental and might change or be removed in the future :microscope: Please share your feedback on it in the forum (https://forum.rasa.com) to help us make this feature ready for production. 2022-03-16 06:11:09 DEBUG rasa.utils.tensorflow.models - Loading the model from /tmp/tmp_nz3yuii/core/policy_3_TEDPolicy/ted_policy.tf_model with finetune_mode=False… 2022-03-16 06:11:18 DEBUG rasa.utils.tensorflow.models - Finished loading the model. 2022-03-16 06:11:18 DEBUG rasa.core.nlg.generator - Instantiated NLG to ‘TemplatedNaturalLanguageGenerator’. 2022-03-16 06:11:18 INFO root - Rasa server is up and running. 2022-03-16 06:11:18 DEBUG rasa.core.channels.socketio - User cp6XV6T60XCEImYAAAAB connected to socketIO endpoint. 2022-03-16 06:11:19 DEBUG rasa.core.channels.socketio - User cp6XV6T60XCEImYAAAAB connected to socketIO endpoint. 2022-03-16 06:11:19 DEBUG rasa.core.channels.socketio - User GQ8LBrHjc7GOTyG1AAAD connected to socketIO endpoint. 2022-03-16 06:11:19 DEBUG rasa.core.channels.socketio - User GQ8LBrHjc7GOTyG1AAAD connected to socketIO endpoint. 2022-03-16 06:12:00 DEBUG rasa.core.channels.socketio - User cp6XV6T60XCEImYAAAAB disconnected from socketIO endpoint. 2022-03-16 06:12:01 DEBUG rasa.core.channels.socketio - User a-eQPq-vwt512F2iAAAF connected to socketIO endpoint. 2022-03-16 06:12:01 DEBUG rasa.core.channels.socketio - User a-eQPq-vwt512F2iAAAF connected to socketIO endpoint. 2022-03-16 06:12:03 DEBUG rasa.core.lock_store - Issuing ticket for conversation ‘a95050c54fa844b78968726953a2d2e6’. 2022-03-16 06:12:03 DEBUG rasa.core.lock_store - Acquiring lock for conversation ‘a95050c54fa844b78968726953a2d2e6’. 2022-03-16 06:12:03 DEBUG rasa.core.lock_store - Acquired lock for conversation ‘a95050c54fa844b78968726953a2d2e6’. 2022-03-16 06:12:03 DEBUG rasa.core.tracker_store - Can’t retrieve tracker matching sender id ‘a95050c54fa844b78968726953a2d2e6’ from SQL storage. Returning None instead. 2022-03-16 06:12:03 DEBUG rasa.core.tracker_store - Tracker with sender_id ‘a95050c54fa844b78968726953a2d2e6’ stored to database 2022-03-16 06:12:03 DEBUG rasa.core.processor - Starting a new session for conversation ID ‘a95050c54fa844b78968726953a2d2e6’. 2022-03-16 06:12:03 DEBUG rasa.core.processor - Policy prediction ended with events ‘[]’. 2022-03-16 06:12:03 DEBUG rasa.core.processor - Action ‘action_session_start’ ended with events ‘[<rasa.shared.core.events.SessionStarted object at 0x7f93b85afd00>, ActionExecuted(action: action_listen, policy: None, confidence: None)]’.

@ck4all89 so this error occurs only in in memory lock store, is it? one possible reason could be is that the action before validate_clientAuthForm is getting into an infinite loop? did you check this?

Hi San, thanks for reply.

I had implemented some codes as follows for my Chat Bot-

rules.yml

stories.yml

and remaining files- domain.yml, config.yml and action.py:

domain.yml (7.4 KB)

config.yml (961 Bytes)

actions.py (4.6 KB)

Also, it works fine on my localhost, but when I run it on aws, then it creating issue.

Please, let me know if I missed anything else… Thanks

@ck4all89 why is there another form activation in your stories.yml? Either you activate-deactivate in rules.yml or you can do that in stories.yml I believe. Anyways, in your story you have put active_loop: clientAuthForm, your story should be like:

intent: get_started
action: clientAuthForm
active_loop: clientAuthForm
active_loop: null
action: action_store_client_details

P.S: I’ve added the custom action from what I understood. You can ignore that also.