Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Rasa logs clogged with 1000s of entries after slots or templates are removed #4887

Closed
tangochris opened this issue Dec 2, 2019 · 9 comments
Labels
type:bug 🐛 Inconsistencies or issues which will cause an issue or problem for users or implementors.

Comments

@tangochris
Copy link

tangochris commented Dec 2, 2019

Rasa version: 1.4.6

Rasa X version (if used & relevant): 0.22.2

Issue: If there is a slot or template in your conversation history that no longer exists, Rasa throws 1000s of warnings and errors per second.

Error (including full traceback):

The problem isn't so much the error, but that the error occurs thousands of times after one user action. Example error:

2019-12-02 20:26:17 ERROR rasa.core.trackers - Tried to set non existent slot 'topic'. Make sure you added all your slots to your domain file.

Command or request that led to error:
We removed 3 slots from our language model and renamed about 160 templates. When any user with those slots or the renamed templates in their history tries to access the bot, it plugs the logs with 1000s of entries per second.

Screen Shot 2019-12-02 at 1 31 48 PM

@tangochris tangochris added the type:bug 🐛 Inconsistencies or issues which will cause an issue or problem for users or implementors. label Dec 2, 2019
@sara-tagger
Copy link
Collaborator

sara-tagger commented Dec 3, 2019

Thanks for raising this issue, @wochinge will get back to you about it soon✨

Please also check out the docs and the forum in case your issue was raised there too 🤗

@tangochris
Copy link
Author

Additional information: In our case, this occurs with users that have a very long conversation history. This issue will likely be helped by limiting the length of tracker #3011

@tangochris
Copy link
Author

Noticed that this is the same error as #3294, which is closed, but apparently not resolved.

@wochinge
Copy link
Contributor

wochinge commented Dec 4, 2019

Hi @tangochris ,

  • can you please run rasa with --debug and attach the logs?
  • do you have a rough number of events included in your tracker?
  • When you're saying "In our case, this occurs with users that have a very long conversation history.", does this mean that you don't have this problem with smaller trackers?

@wochinge wochinge added the status:more-details-needed Waiting for the user to provide more details / stacktraces / answer a question label Dec 4, 2019
@tangochris
Copy link
Author

tangochris commented Dec 4, 2019

@wochinge

can you please run rasa with --debug

We are always running it with --debug.

and attach the logs?

The logs are on AWS CloudWatch and we're not yet piping them anywhere, so I don't have a quick way to download them. Here are the first 1000 log entries for a single second. Note this is for one user accessing the bot.

rasa-production-20191204-160644.log

do you have a rough number of events included in your tracker?

The user with the issue has 6500 events in their tracker.

When you're saying "In our case, this occurs with users that have a very long conversation history.", does this mean that you don't have this problem with smaller trackers?

Correct. If a user has no conversation history, the bot works fine for them. (Exception: if another user with history has accessed bot within last hour, the server is locked up and won't respond to anyone.)

@no-response no-response bot removed the status:more-details-needed Waiting for the user to provide more details / stacktraces / answer a question label Dec 4, 2019
@tangochris tangochris changed the title Rasa becomes unresponsive if you try to set a slot that doesn't exist Rasa becomes unresponsive if there are non-existent slots or renamed templates in user's history Dec 5, 2019
@tangochris tangochris changed the title Rasa becomes unresponsive if there are non-existent slots or renamed templates in user's history Rasa becomes unresponsive if there are non-existent slots or deleted templates in user's history Dec 5, 2019
@tangochris tangochris changed the title Rasa becomes unresponsive if there are non-existent slots or deleted templates in user's history Rasa logs clogged with 1000s of entries after slots or templates are removed Dec 5, 2019
@tangochris
Copy link
Author

@wochinge Updated original title, issue and comments: the issue I described was not causing the slowness. Because there were 1000s of warnings and errors per second about non-existent slots and templates, it obscured the most important log entry. Once we got rid of the errors by re-adding the unused slots and templates to domain.yml, we noticed this:

2019-12-05 20:33:35 DEBUG    rasa.core.policies.memoization  - Launch DeLorean...

Every time the DeLorean launched, there were no more log entries for 2 minutes (while Rasa was frozen). So this problem is the same as #3011. We have a user (our client) with 6500 events in their history. Every time they access the bot, it freezes while Tracker rebuilds their history.

@wochinge
Copy link
Contributor

wochinge commented Dec 6, 2019

Hi @tangochris ,

thanks a lot for your detailed issue description and the information. 6500 events is a lot 🙂
Your issues should be resolved as soon as we have implemented #4887 (will be part of one of the next minors). With the session concept Rasa will only handle the events of the latest user session and not all events. l Is it okay for you if I mark this issue as a duplicate of #4887 and close it for now?

@tangochris
Copy link
Author

@wochinge I'll close this. But this issue is #4887... did you mean #3011 or another ticket?

@s0288
Copy link

s0288 commented Dec 22, 2020

Hi @tangochris , I'm running into the exact same issue that you were describing here:

Issue: If there is a slot or template in your conversation history that no longer exists, Rasa throws 1000s of warnings and errors per second.

Error (including full traceback):

The problem isn't so much the error, but that the error occurs thousands of times after one user action

I'm trying to understand whether I'm doing something wrong or whether this has not been fixed. Did you figure out how to deal with users that have slots in their conversation history that are not part of the model/domain anymore?

My logs are clogged with these errors :(

wochinge suggested here (#3011) to set max_history, which I have set to 5.

Example cases for my problem:

rasa_1      | 2020-12-22 12:20:39 ERROR    rasa.shared.core.trackers  - Tried to set non existent slot 'reflect_remedy'. Make sure you added all your slots to your domain file.
rasa_1      | 2020-12-22 12:20:39 ERROR    rasa.shared.core.trackers  - Tried to set non existent slot 'reflect_situation'. Make sure you added all your slots to your domain file.
rasa_1      | 2020-12-22 12:20:39 ERROR    rasa.shared.core.trackers  - Tried to set non existent slot 'reflect_remedy'. Make sure you added all your slots to your domain file.
rasa_1      | 2020-12-22 12:20:39 ERROR    rasa.shared.core.trackers  - Tried to set non existent slot 'requested_slot'. Make sure you added all your slots to your domain file.
rasa_1      | 2020-12-22 12:20:39 ERROR    rasa.shared.core.trackers  - Tried to set non existent slot 'reflect_situation'. Make sure you added all your slots to your domain file.
rasa_1      | 2020-12-22 12:20:39 ERROR    rasa.shared.core.trackers  - Tried to set non existent slot 'requested_slot'. Make sure you added all your slots to your domain file.
rasa_1      | 2020-12-22 12:20:39 ERROR    rasa.shared.core.trackers  - Tried to set non existent slot 'reflect_remedy'. Make sure you added all your slots to your domain file.
rasa_1      | 2020-12-22 12:20:39 ERROR    rasa.shared.core.trackers  - Tried to set non existent slot 'reflect_situation'. Make sure you added all your slots to your domain file.
rasa_1      | 2020-12-22 12:20:39 ERROR    rasa.shared.core.trackers  - Tried to set non existent slot 'reflect_remedy'. Make sure you added all your slots to your domain file.
rasa_1      | 2020-12-22 12:20:39 ERROR    rasa.shared.core.trackers  - Tried to set non existent slot 'requested_slot'. Make sure you added all your slots to your domain file.
rasa_1      | 2020-12-22 12:20:39 ERROR    rasa.shared.core.trackers  - Tried to set non existent slot 'reflect_situation'. Make sure you added all your slots to your domain file.
rasa_1      | 2020-12-22 12:20:39 ERROR    rasa.shared.core.trackers  - Tried to set non existent slot 'requested_slot'. Make sure you added all your slots to your domain file.
rasa_1      | 2020-12-22 12:20:39 ERROR    rasa.shared.core.trackers  - Tried to set non existent slot 'reflect_remedy'. Make sure you added all your slots to your domain file.
rasa_1      | 2020-12-22 12:20:39 ERROR    rasa.shared.core.trackers  - Tried to set non existent slot 'reflect_situation'. Make sure you added all your slots to your domain file.
rasa_1      | 2020-12-22 12:20:39 ERROR    rasa.shared.core.trackers  - Tried to set non existent slot 'reflect_remedy'. Make sure you added all your slots to your domain file.
rasa_1      | 2020-12-22 12:20:39 ERROR    rasa.shared.core.trackers  - Tried to set non existent slot 'requested_slot'. Make sure you added all your slots to your domain file.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
type:bug 🐛 Inconsistencies or issues which will cause an issue or problem for users or implementors.
Projects
None yet
Development

No branches or pull requests

4 participants