microsoftgraph / microsoftgraph/microsoft-graph-comms-samples

Video call ending on Bot (while another video call is running) causes overload/cpu core lock until the last video call ends

Open
#549 1 comment 0 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

Dominant language
No language data
Stars
253
Forks
275
Avg merge
1d 5h
Merged PRs (30d)
1

Description

Describe the issue
I have a single bot that is recording >2 video calls. If one of the calls end there is a large CPU spike and an entire CPU core gets locked up. It only gets released when the last video call ends on the bot.

This only happens if two of the participants in the call are being recorded by the same bot. This issue can be replicated reliably.

If, for example, it is a two person video call and each individual is being recorded by a different bot, the issue does not occur. If all the participants are on the same bot but turn off video before the call ends, the issue does not occur.

I've listed the scenario Id and call Ids of a meeting that encountered this issue further below. In said meeting as each participant left we are seeing a warning and error, TryGetEndpointQoe and GetAllChannelsQoe respectively, quoting the scenario Id from AvMP.

When the last participant leaves/ends the call we see neither until the last video call on the bot ends (3 minutes later in this example). We also see a warning from DeleteEndpointWorkitemBegin quoting the scenario Id at this time (Log lines from AvMP below). It is only then do we see CPU usage return to normal.

I've compared the code to the sample and I see no difference that would lead to this.

Expected behavior
Spike/cpu lock not to occcur

Graph SDK (please complete the following information):
Microsoft.Graph.Communications.Calls.Media 1.2.0.4161
Microsoft.Skype.Bots.Media 1.23.0.49-alpha

Call ID
Below is an example call where this has occurred. Call was approximately 10:52pm UTC 19/05/2022.

Scenario ID: 2f79c9dd-a208-471e-8b8d-7bf78be384d0

Call IDs:
541f5b00-cf3f-402b-b234-85373e0854e5
881f5f00-8ec1-4dac-9337-9f7324368e1f
701f5b00-cb82-4aa7-8043-5ba7006d2cf1

Logs

(Time stamps are UTC)

Received when a participant leaves, except on the last participant

2022-05-19 10:56:26,105 WARN - MicrosoftTeamsPolicyBotHost - PolicyBotEngine: [AvMP][AppId:] TL_WARN(TF_COMPONENT) [HostName]4544.71::05/19/2022-10:56:26.105.000006ED (AVMP,TryGetEndpointQoe:Context.cs(6373)) ([cid:2f79c9dd-a208-471e-8b8d-7bf78be384d0])[MP] GetEndpointQoe: context[d79f48b9-e19b-4dd6-8034-72510b6d2f49] Endpoint not found

2022-05-19 10:56:26,106 ERROR - MicrosoftTeamsPolicyBotHost - PolicyBotEngine: [AvMP][AppId:] TL_ERROR(TF_COMPONENT) [HostName]4544.71::05/19/2022-10:56:26.106.000006EE (AVMP,GetAllChannelsQoe:Context.cs(6335)) ([cid:2f79c9dd-a208-471e-8b8d-7bf78be384d0])[MP] GetAllChannelsQoe: context[d79f48b9-e19b-4dd6-8034-72510b6d2f49] Endpoints not found

2022-05-19 10:56:27,294 WARN - MicrosoftTeamsPolicyBotHost - PolicyBotEngine: [AvMP][AppId:] TL_WARN(TF_COMPONENT) [HostName]4544.4::05/19/2022-10:56:27.294.000006EF (AVMP,ProcessDominantSpeakerChanged:Context.cs(4878)) ([cid:2f79c9dd-a208-471e-8b8d-7bf78be384d0])ProcessDominantSpeakerChanged: PreviousDominantAudioChannel field of RtpDominantSpeakerChangedEvent is null.

Received on last video call ending on bot

2022-05-19 11:00:24,726 WARN - MicrosoftTeamsPolicyBotHost - PolicyBotEngine: [AvMP][AppId:] TL_WARN(TF_COMPONENT) [HostName]4544.86::05/19/2022-11:00:24.726.00000772 (AVMP,DeleteEndpointWorkitemBegin:Context.cs(959)) ([cid:2f79c9dd-a208-471e-8b8d-7bf78be384d0])[MP] DeleteEndpointWorkitemBegin - replaying delete results due to delete replay

2022-05-19 11:00:24,762 WARN - MicrosoftTeamsPolicyBotHost - PolicyBotEngine: [AvMP][AppId:] TL_WARN(TF_COMPONENT) [HostName]4544.48::05/19/2022-11:00:24.762.00000773 (AVMP,TryGetEndpointQoe:Context.cs(6373)) ([cid:2f79c9dd-a208-471e-8b8d-7bf78be384d0])[MP] GetEndpointQoe: context[9044cbfd-5f06-4c12-84fe-c1f5d70a3b03] Endpoint not found

2022-05-19 11:00:24,763 ERROR - MicrosoftTeamsPolicyBotHost - PolicyBotEngine: [AvMP][AppId:] TL_ERROR(TF_COMPONENT) [HostName]4544.48::05/19/2022-11:00:24.763.00000774 (AVMP,GetAllChannelsQoe:Context.cs(6335)) ([cid:2f79c9dd-a208-471e-8b8d-7bf78be384d0])[MP] GetAllChannelsQoe: context[9044cbfd-5f06-4c12-84fe-c1f5d70a3b03] Endpoints not found

Contributor guide

No contributing guide indexed for this repository

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Start by reproducing the multi-call, shared-bot scenario described for Microsoft.Graph.Communications.Calls.Media 1.2.0.4161 and Microsoft.Skype.Bots.Media 1.23.0.49-alpha. Review the TryGetEndpointQoe, GetAllChannelsQoe, ProcessDominantSpeakerChanged, and DeleteEndpointWorkitemBegin log events around participant and call termination. Done means ending one call no longer causes a sustained CPU spike or core lock while another video call remains active.

Written by the indexing model from the issue text.

Assessment

Domain
audio-video-rtc
Issue type
Bug
Difficulty
5/5
Estimated time
Over a week
Activity status
Stale
Clarity
Needs clarification
Newbie friendliness
20/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.