microsoft / BotBuilder-Samples

Welcome to the Bot Framework samples repository. Here you will find task-focused samples in C#, JavaScript/TypeScript, and Python to help you get started with the Bot Framework SDK!
https://github.com/Microsoft/botframework
MIT License
4.39k stars 4.88k forks source link

Unexplained errors while replying to a conversation #2738

Closed saikiran2603 closed 4 years ago

saikiran2603 commented 4 years ago

Version

botbuilder-integration-aiohttp>=4.9.1

Describe the bug

We have deployed a teams bot with python SDK. Intermittently when the users are trying to converse with the bot we get exceptions in the SDK

concurrent.futures._base.CancelledError if "MemberNotFoundInConversation" in e.args[0]: IndexError: tuple index out of range

although if the same user retries the same message again , right away everything works fine. Due to this we are unable to scale the bot further.

To Reproduce

Steps to reproduce the behavior: Intermittent issue, Start the bot and monitor the conversation logs

Expected behavior

  1. Give clear error message explaining where is the issue
  2. Bot should respond to the user

Screenshots

Error type 1

[2020-09-11 04:23:37 +0000] [12] [DEBUG] [on_turn_error] unhandled error: DEBUG:aiohttp.web: [on_turn_error] unhandled error: Traceback (most recent call last): File "/usr/local/lib/python3.7/site-packages/botbuilder/core/bot_adapter.py", line 128, in run_pipeline context, callback File "/usr/local/lib/python3.7/site-packages/botbuilder/core/middleware_set.py", line 69, in receive_activity_with_status return await self.receive_activity_internal(context, callback) File "/usr/local/lib/python3.7/site-packages/botbuilder/core/middleware_set.py", line 79, in receive_activity_internal return await callback(context) File "/usr/local/lib/python3.7/site-packages/botbuilder/core/activity_handler.py", line 68, in on_turn await self.on_message_activity(turn_context) File "/teams-connector/bot/teams_bot.py", line 112, in on_message_activity await turn_context.send_activity(row['text']) File "/usr/local/lib/python3.7/site-packages/botbuilder/core/turn_context.py", line 170, in send_activity result = await self.send_activities([activity_or_text]) File "/usr/local/lib/python3.7/site-packages/botbuilder/core/turn_context.py", line 217, in send_activities return await self._emit(self._on_send_activities, output, logic()) File "/usr/local/lib/python3.7/site-packages/botbuilder/core/turn_context.py", line 295, in _emit return await logic File "/usr/local/lib/python3.7/site-packages/botbuilder/core/turn_context.py", line 212, in logic responses = await self.adapter.send_activities(self, output) File "/usr/local/lib/python3.7/site-packages/botbuilder/core/bot_framework_adapter.py", line 728, in send_activities raise error File "/usr/local/lib/python3.7/site-packages/botbuilder/core/bot_framework_adapter.py", line 714, in send_activities activity.conversation.id, activity.reply_to_id, activity File "/usr/local/lib/python3.7/site-packages/botframework/connector/aio/operations_async/_conversations_operations_async.py", line 529, in reply_to_activity request, stream=False, operation_config File "/usr/local/lib/python3.7/site-packages/msrest/async_client.py", line 115, in async_send pipeline_response = await self.config.pipeline.run(request, kwargs) File "/usr/local/lib/python3.7/site-packages/msrest/pipeline/async_abc.py", line 159, in run return await first_node.send(pipeline_request, kwargs) # type: ignore File "/usr/local/lib/python3.7/site-packages/msrest/pipeline/async_abc.py", line 79, in send response = await self.next.send(request, kwargs) # type: ignore File "/usr/local/lib/python3.7/site-packages/msrest/pipeline/async_requests.py", line 106, in send return await self.next.send(request, kwargs) File "/usr/local/lib/python3.7/site-packages/msrest/pipeline/async_abc.py", line 79, in send response = await self.next.send(request, kwargs) # type: ignore File "/usr/local/lib/python3.7/site-packages/msrest/pipeline/async_abc.py", line 79, in send response = await self.next.send(request, kwargs) # type: ignore File "/usr/local/lib/python3.7/site-packages/msrest/pipeline/async_requests.py", line 85, in send await self.driver.send(request.http_request, kwargs) File "/usr/local/lib/python3.7/site-packages/msrest/universal_http/async_requests.py", line 91, in send return await super(AsyncRequestsHTTPSender, self).send(request, **requests_kwargs) File "/usr/local/lib/python3.7/site-packages/msrest/universal_http/async_requests.py", line 79, in send await future concurrent.futures._base.CancelledError

Error Type 2

[on_turn_error] unhandled error: tuple index out of range DEBUG:aiohttp.web: [on_turn_error] unhandled error: tuple index out of range Traceback (most recent call last): File "/teams-connector/bot/teams_bot.py", line 162, in get_member_details turn_context, turn_context.activity.from_property.id File "/usr/local/lib/python3.7/site-packages/botbuilder/core/teams/teams_info.py", line 175, in get_member connector_client, conversation_id, member_id File "/usr/local/lib/python3.7/site-packages/botbuilder/core/teams/teams_info.py", line 264, in _get_member conversation_id, member_id File "/usr/local/lib/python3.7/site-packages/botframework/connector/aio/operations_async/_conversations_operations_async.py", line 731, in get_conversation_member request, stream=False, operation_config File "/usr/local/lib/python3.7/site-packages/msrest/async_client.py", line 115, in async_send pipeline_response = await self.config.pipeline.run(request, kwargs) File "/usr/local/lib/python3.7/site-packages/msrest/pipeline/async_abc.py", line 159, in run return await first_node.send(pipeline_request, kwargs) # type: ignore File "/usr/local/lib/python3.7/site-packages/msrest/pipeline/async_abc.py", line 79, in send response = await self.next.send(request, kwargs) # type: ignore File "/usr/local/lib/python3.7/site-packages/msrest/pipeline/async_requests.py", line 106, in send return await self.next.send(request, kwargs) File "/usr/local/lib/python3.7/site-packages/msrest/pipeline/async_abc.py", line 79, in send response = await self.next.send(request, kwargs) # type: ignore File "/usr/local/lib/python3.7/site-packages/msrest/pipeline/async_abc.py", line 79, in send response = await self.next.send(request, kwargs) # type: ignore File "/usr/local/lib/python3.7/site-packages/msrest/pipeline/async_requests.py", line 85, in send await self.driver.send(request.http_request, kwargs) File "/usr/local/lib/python3.7/site-packages/msrest/universal_http/async_requests.py", line 91, in send return await super(AsyncRequestsHTTPSender, self).send(request, **requests_kwargs) File "/usr/local/lib/python3.7/site-packages/msrest/universal_http/async_requests.py", line 79, in send await future concurrent.futures._base.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/usr/local/lib/python3.7/site-packages/botbuilder/core/bot_adapter.py", line 128, in run_pipeline context, callback File "/usr/local/lib/python3.7/site-packages/botbuilder/core/middleware_set.py", line 69, in receive_activity_with_status return await self.receive_activity_internal(context, callback) File "/usr/local/lib/python3.7/site-packages/botbuilder/core/middleware_set.py", line 79, in receive_activity_internal return await callback(context) File "/usr/local/lib/python3.7/site-packages/botbuilder/core/activity_handler.py", line 68, in on_turn await self.on_message_activity(turn_context) File "/teams-connector/bot/teams_bot.py", line 75, in on_message_activity email_id, name, tenant_id = await self.get_member_details(turn_context) File "/teams-connector/bot/teams_bot.py", line 165, in get_member_details if "MemberNotFoundInConversation" in e.args[0]: IndexError: tuple index out of range

`

Additional context

we used below starter code, and more or less have the same structure https://github.com/microsoft/BotBuilder-Samples/tree/main/samples/python/57.teams-conversation-bot

v-kydela commented 4 years ago

Thank you for the report, @saikiran2603

I would like to help but I have a few questions:

  1. Are you saying you have only seen this error in logs and have not reproduced the error yourself?
  2. Are the errors showing up in app insights or somewhere else?
  3. Shall we assume your bot is only accessed from Teams and not Web Chat, Emulator, etc.?
saikiran2603 commented 4 years ago

@v-kydela thanks !!

  1. Yes the error is not reproducible at will. If i test it some times i do get this error , but i cannot pinpoint any reason / event which causes this error, it appears to be on random.
  2. I can see these errors in my docker container logs. Also once i get this error my application is designed to respond to the user saying , the bot faced some issues etc , like shown in 57 Teams conversation bot example. This message does get sent to the user whenever i see this error in the logs
  3. Yes its a Teams bot only. and we are not using emulator yet.

I have raised a similar request in botbuilder sdk repo as well, since i didnt know which is the right repo to raise this issue , https://github.com/microsoft/botbuilder-python/issues/1384

v-kydela commented 4 years ago

@saikiran2603 - I will go ahead and address the issue here for now. I can see that this is an intermittent issue, but it may still be necessary to come up with some semblance of a way to reproduce the issue so we have a way to tell if it's "fixed." For example, if you talked to the bot for 10 minutes without getting an error would that be an indication that the issue is resolved? Or if you sent 100 messages? Or if you opened 10 threads with the bot? Or if you signed out and back in 10 times?

Once you've gained some confidence around being able to tell if the issue is present or not, you can see if the issue occurs in other configurations and that will help us pinpoint the cause of the issue. For example:

  1. Does the issue occur if you deploy without a Docker container?
  2. Does the issue occur if you run the bot locally?
  3. Does the issue occur if you use the sample without your modifications?
saikiran2603 commented 4 years ago

@v-kydela Sure that sounds good !

to answer your questions ,

  1. I havent tested it but i suspect it does. I will test this today and get back,
  2. Yes
  3. I need to test this. I will report back on this.
v-kydela commented 4 years ago

@saikiran2603 - Have you tested the sample without your modifications?

v-kydela commented 4 years ago

@saikiran2603 - Are you still working on this?

saikiran2603 commented 4 years ago

@v-kydela yes i tested it without any modifications and without docker, but i am still unable to reproduce the issue at will .. it does not occur always in both the situations

Sorry for the delay, !

saikiran2603 commented 4 years ago

These are the logs when i was able to re produce the issue

Case 1

[2020-09-24 05:31:05 +0000] [13] [DEBUG] [on_turn_error] unhandled error: tuple index out of range DEBUG:aiohttp.web: [on_turn_error] unhandled error: tuple index out of range Traceback (most recent call last): File "/teams-connector/bot/teams_bot.py", line 162, in get_member_details turn_context, turn_context.activity.from_property.id File "/usr/local/lib/python3.7/site-packages/botbuilder/core/teams/teams_info.py", line 175, in get_member connector_client, conversation_id, member_id File "/usr/local/lib/python3.7/site-packages/botbuilder/core/teams/teams_info.py", line 264, in _get_member conversation_id, member_id File "/usr/local/lib/python3.7/site-packages/botframework/connector/aio/operations_async/_conversations_operations_async.py", line 731, in get_conversation_member request, stream=False, operation_config File "/usr/local/lib/python3.7/site-packages/msrest/async_client.py", line 115, in async_send pipeline_response = await self.config.pipeline.run(request, kwargs) File "/usr/local/lib/python3.7/site-packages/msrest/pipeline/async_abc.py", line 159, in run return await first_node.send(pipeline_request, kwargs) # type: ignore File "/usr/local/lib/python3.7/site-packages/msrest/pipeline/async_abc.py", line 79, in send response = await self.next.send(request, kwargs) # type: ignore File "/usr/local/lib/python3.7/site-packages/msrest/pipeline/async_requests.py", line 106, in send return await self.next.send(request, kwargs) File "/usr/local/lib/python3.7/site-packages/msrest/pipeline/async_abc.py", line 79, in send response = await self.next.send(request, kwargs) # type: ignore File "/usr/local/lib/python3.7/site-packages/msrest/pipeline/async_abc.py", line 79, in send response = await self.next.send(request, kwargs) # type: ignore File "/usr/local/lib/python3.7/site-packages/msrest/pipeline/async_requests.py", line 85, in send await self.driver.send(request.http_request, kwargs) File "/usr/local/lib/python3.7/site-packages/msrest/universal_http/async_requests.py", line 91, in send return await super(AsyncRequestsHTTPSender, self).send(request, **requests_kwargs) File "/usr/local/lib/python3.7/site-packages/msrest/universal_http/async_requests.py", line 79, in send await future concurrent.futures._base.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/usr/local/lib/python3.7/site-packages/botbuilder/core/bot_adapter.py", line 128, in run_pipeline context, callback File "/usr/local/lib/python3.7/site-packages/botbuilder/core/middleware_set.py", line 69, in receive_activity_with_status return await self.receive_activity_internal(context, callback) File "/usr/local/lib/python3.7/site-packages/botbuilder/core/middleware_set.py", line 79, in receive_activity_internal return await callback(context) File "/usr/local/lib/python3.7/site-packages/botbuilder/core/activity_handler.py", line 68, in on_turn await self.on_message_activity(turn_context) File "/teams-connector/bot/teams_bot.py", line 75, in on_message_activity email_id, name, tenant_id = await self.get_member_details(turn_context) File "/teams-connector/bot/teams_bot.py", line 165, in get_member_details if "MemberNotFoundInConversation" in e.args[0]: IndexError: tuple index out of range [2020-09-24 05:31:05 +0000] [13] [DEBUG] None DEBUG:aiohttp.web:None

Case 2 [on_turn_error] unhandled error: DEBUG:aiohttp.web: [on_turn_error] unhandled error: Traceback (most recent call last): File "/usr/local/lib/python3.7/site-packages/botbuilder/core/bot_adapter.py", line 128, in run_pipeline context, callback File "/usr/local/lib/python3.7/site-packages/botbuilder/core/middleware_set.py", line 69, in receive_activity_with_status return await self.receive_activity_internal(context, callback) File "/usr/local/lib/python3.7/site-packages/botbuilder/core/middleware_set.py", line 79, in receive_activity_internal return await callback(context) File "/usr/local/lib/python3.7/site-packages/botbuilder/core/activity_handler.py", line 68, in on_turn await self.on_message_activity(turn_context) File "/teams-connector/bot/teams_bot.py", line 112, in on_message_activity await turn_context.send_activity(row['text']) File "/usr/local/lib/python3.7/site-packages/botbuilder/core/turn_context.py", line 170, in send_activity result = await self.send_activities([activity_or_text]) File "/usr/local/lib/python3.7/site-packages/botbuilder/core/turn_context.py", line 217, in send_activities return await self._emit(self._on_send_activities, output, logic()) File "/usr/local/lib/python3.7/site-packages/botbuilder/core/turn_context.py", line 295, in _emit return await logic File "/usr/local/lib/python3.7/site-packages/botbuilder/core/turn_context.py", line 212, in logic responses = await self.adapter.send_activities(self, output) File "/usr/local/lib/python3.7/site-packages/botbuilder/core/bot_framework_adapter.py", line 728, in send_activities raise error File "/usr/local/lib/python3.7/site-packages/botbuilder/core/bot_framework_adapter.py", line 714, in send_activities activity.conversation.id, activity.reply_to_id, activity File "/usr/local/lib/python3.7/site-packages/botframework/connector/aio/operations_async/_conversations_operations_async.py", line 529, in reply_to_activity request, stream=False, operation_config File "/usr/local/lib/python3.7/site-packages/msrest/async_client.py", line 115, in async_send pipeline_response = await self.config.pipeline.run(request, kwargs) File "/usr/local/lib/python3.7/site-packages/msrest/pipeline/async_abc.py", line 159, in run return await first_node.send(pipeline_request, kwargs) # type: ignore File "/usr/local/lib/python3.7/site-packages/msrest/pipeline/async_abc.py", line 79, in send response = await self.next.send(request, kwargs) # type: ignore File "/usr/local/lib/python3.7/site-packages/msrest/pipeline/async_requests.py", line 106, in send return await self.next.send(request, kwargs) File "/usr/local/lib/python3.7/site-packages/msrest/pipeline/async_abc.py", line 79, in send response = await self.next.send(request, kwargs) # type: ignore File "/usr/local/lib/python3.7/site-packages/msrest/pipeline/async_abc.py", line 79, in send response = await self.next.send(request, kwargs) # type: ignore File "/usr/local/lib/python3.7/site-packages/msrest/pipeline/async_requests.py", line 85, in send await self.driver.send(request.http_request, kwargs) File "/usr/local/lib/python3.7/site-packages/msrest/universal_http/async_requests.py", line 91, in send return await super(AsyncRequestsHTTPSender, self).send(request, **requests_kwargs) File "/usr/local/lib/python3.7/site-packages/msrest/universal_http/async_requests.py", line 79, in send await future concurrent.futures._base.CancelledError [2020-09-23 04:02:41 +0000] [13] [DEBUG] None DEBUG:aiohttp.web:None

Although i still cannot figure out when this issue occours and at what configuration, it still appears on random and the error message does not help me figure out what might be the issue either :(

v-kydela commented 4 years ago

@saikiran2603 - Yes, I already understood that you cannot reproduce the issue at will. I thought we had agreed that we needed a way for you to determine if the issue is present or not, though. What method had you been using before to see if the issue occurs while testing locally, etc.? Are you sending a certain amount of messages, for example?

saikiran2603 commented 4 years ago

I thought we had agreed that we needed a way for you to determine if the issue is present or not, though.

Yes i still am on the same page.

What method had you been using before to see if the issue occurs while testing locally, etc.? Are you sending a certain amount of messages, for example?

I would just start conversing with the bot , and sometimes i would see the error after hours of testing or sometimes much quicker. I could not figure out a pattern there. And i cannot replicate the issue every time.

As for the below questions

  1. Does the issue occur if you deploy without a Docker container? Yes , but i don't have logs to show this.
  2. Does the issue occur if you run the bot locally? Yes
  3. Does the issue occur if you use the sample without your modifications? I didn't see this error yet,
v-kydela commented 4 years ago

@saikiran2603 - If the error occurs in your code but not the sample then that would narrow down the cause of the issue to just the changes you've made. You may email your code to me if you'd like to share it privately. I can see in your stack trace references to a file called "/teams-connector/bot/teams_bot.py" which I'm guessing must be in your project.

v-kydela commented 4 years ago

@saikiran2603 - Are you still working on this?

saikiran2603 commented 4 years ago

Yes , i am mailing the code to you ..

v-kydela commented 4 years ago

@saikiran2603 - I haven't received an email yet. What address did you mail it to?

v-kydela commented 4 years ago

@saikiran2603 - Do you still need help?

v-kydela commented 4 years ago

I am closing this issue due to inactivity. We are still happy to provide help if you need any, though it may be a good idea to make a new post if that's the case. Please have a look at this to find out the best places to ask for help, and consider asking questions on Stack Overflow.

master0v commented 2 years ago

Having the same issue in 4.14.2