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
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
- Read the whole issue, then the project's contributing guide.
- Comment on the issue to say you are picking it up — it saves two people doing the same work.
- Fork the repository and make your change on a branch.
- 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