Android App Client call to web App Client receiver failed very often

shipon-eye commented 3 years ago

Describe the bug I am trying to call from Android App Client to WebApp Client. Most of the time I get CallState=None in the Caller app(Android App) and on the web client nothing happens after generating the token. 60-70% of the times it fails.

Sometimes, the call connected with the web client but shows lots of error log(mentioned below) and the Video quality is not good.

By the way, Android App Client to Android App Client works 95% time :) . Though it shows some camera-related error like libc: Access denied finding property "vendor.camera.hal1.packagelist" libc: Access denied finding property "vendor.camera.aux.packagelist"

To Reproduce Steps to reproduce the behavior: Android Client to Web Client Call

Expected behavior The connection should succeed with quality video communication.

Desktop (please complete the following information):

OS: Window 10
Browser Microsoft Edge/Chrome
Version [e.g. 22]

Smartphone (please complete the following information):

Device: Samsung Note Lite
OS: Android 10

Console log when the connection is successful but low quality(Android app to web app):

ECS - Config fetch complete 11.af8c7df….js:1 azure:ACS:warning 11/4/2020, 5:28:17:98 [CallClient] [JS.TsCalling.SignalingAgent] ffffffff: CSA[d4f53123-cbcb-477b-9878-3c290c261beb][Idle] Unable to parse endpoint metadata 11.af8c7df….js:1 azure:ACS:warning 11/4/2020, 5:28:18:799 [CallClient] [JS.TsCalling.Pluginless] ffffffff: PluginlessStack/CallTelemetry Unable to find event for name _ParticipantJoined 11.af8c7df….js:1 azure:ACS:warning 11/4/2020, 5:28:18:828 [CallClient] [JS.TsCalling.MediaAgent] ffffffff: MA/DeviceManager/MediaStreamManager/MediaStream:2/MultStrat Could not obtain constrained media stream, will attempt weaker policy 11.af8c7df….js:1 azure:ACS:warning 11/4/2020, 5:28:18:831 [CallClient] [JS.TsCalling.MediaAgent] ffffffff: MA/DeviceManager/MediaStreamManager/MediaStream:2/MultStrat Could not obtain constrained media stream, will attempt weaker policy 11.af8c7df….js:1 azure:ACS:warning 11/4/2020, 5:28:18:833 [CallClient] [JS.TsCalling.MediaAgent] ffffffff: MA/DeviceManager/MediaStreamManager/MediaStream:2/MultStrat Could not obtain constrained media stream, will attempt weaker policy 11.af8c7df….js:1 Send request, method: GET, URL: https://worldaz.turn.skype.com/relay, Request options: {"headers":{},"retry":{},"reporting":{"serviceName":"ngcCallController-GET"},"payload":null,"timeout":25000} 11.af8c7df….js:1 azure:ACS:warning 11/4/2020, 5:28:21:193 [CallClient] [JS.TsCalling.MediaAgentUnsafe] ffffffff: MA/webrtc2-2/SSM Sender with media type Video does not exist, do not update media stream 11.af8c7df….js:1 azure:ACS:warning 11/4/2020, 5:28:21:348 [CallClient] [JS.TsCalling.MediaAgentUnsafe] ffffffff: MA/webrtc2-2/SSM Sender with media type Audio does not exist, do not update media stream 11.af8c7df….js:1 azure:ACS:warning 11/4/2020, 5:28:22:400 [CallClient] [JS.TsCalling.MediaAgent] ffffffff: MA/webrtc2-2 On ICE candidate error turn:52.158.35.205:443?transport=tcp | 192.168.7.x:60144: code 600: Address not associated with the desired network interface. 11.af8c7df….js:1 Video Stream updated: true 11.af8c7df….js:1 azure:ACS:warning 11/4/2020, 5:28:26:772 [CallClient] [JS.TsCalling.MediaAgent] ffffffff: MA/webrtc2-2 On ICE candidate error turn:52.158.35.205:443?transport=tcp | 192.168.7.x:60144: code 701: 11.af8c7df….js:1 azure:ACS:warning 11/4/2020, 5:28:52:421 [CallClient] [JS.TsCalling.SignalingAgent] ffffffff: CSA[d4f53123-cbcb-477b-9878-3c290c261beb][Connected]/Broker timeout subscription 11.af8c7df….js:1 azure:ACS:warning 11/4/2020, 5:28:52:422 [CallClient] [JS.TsCalling.SignalingAgent] ffffffff: CSA[d4f53123-cbcb-477b-9878-3c290c261beb][Connected]/[HTTP] [a6ec7ae4][cancelRequest]Unable to cancel request=BrokerSubscribe, requestId=34c941bd-c0f8-4dc4-82ff-1f27c1502c28 11.af8c7df….js:1 azure:ACS:warning 11/4/2020, 5:28:54:250 [CallClient] [JS.TsCalling.SignalingAgent] ffffffff: CSA[d4f53123-cbcb-477b-9878-3c290c261beb][Connected]/Broker _handleSubscriptionFailure, received status 498, stop subscribing 11.af8c7df….js:1 azure:ACS:warning 11/4/2020, 5:29:1:895 [CallClient] [JS.TsCalling.MediaAgent] ffffffff: MA/webrtc2-2 On ICE candidate error stun:52.158.35.205:3478 | 192.168.0.x:58984: code 701: STUN allocate request timed out. 11.af8c7df….js:1 azure:ACS:warning 11/4/2020, 5:29:1:936 [CallClient] [JS.TsCalling.MediaAgent] ffffffff: MA/webrtc2-2 On ICE candidate error turn:52.158.35.205:3478?transport=udp | 192.168.0.x:58984: code 701: TURN allocate request timed out. Please assist me to create stable communication among multiple platforms.

Regards Habib

mariusu-msft commented 3 years ago

Hi,

Thanks for your report. Would you mind sharing a couple of call Ids for 100% failed cases?

You can get the call Id by inspecting the property Id of the Call object. https://docs.microsoft.com/en-us/azure/communication-services/concepts/troubleshooting-info?tabs=csharp%2Candroid%2Cdotnet#access-your-call-id

@kagbakpem can you help investigate and reproduce this? Have you encountered any of the errors reported for Android?

Thanks, Marius

shipon-eye commented 3 years ago

Hello Marius, Thanks for the reply.

Failed Call Ids: e1f6d94e-e48a-4358-b51a-b0589ad13eec 274426f9-d17d-489f-b0d5-a38cea914dd2

Successful Call Id: 424c4ffb-1c75-4127-aa8a-7d763e9c9650

Regards Habib

mariusu-msft commented 3 years ago

Hi,

Telemetry indicates that we were not able to reach the Web endpoint.

In case of a failed call, from a web endpoint, can you collect full logs and share them here if they don't contain any sensitive information?

import { AzureLogger } from '@azure/logger'; 

AzureLogger.verbose = (...args) => { console.info(...args); } 
AzureLogger.info = (...args) => { console.info(...args); } 
AzureLogger.warning = (...args) => { console.info(...args); } 
AzureLogger.error = (...args) => { console.info(...args); } 

callClient = new CallClient({logger: AzureLogger});

Thanks, Marius

shipon-eye commented 3 years ago

Hello Marius, Please check the log below:

Failed Call ID: a4f7aa7d-e306-4daa-bf39-f703c7487a2d

Android client self-created Log:

2020-11-05 14:59:16.008 3086-3086/com.xpertmemos.inpocket E/ACS: createAgent: creating 2020-11-05 14:59:16.864 3086-5845/com.xpertmemos.inpocket E/libc: Access denied finding property "vendor.camera.aux.packagelist" 2020-11-05 14:59:16.868 3086-5845/com.xpertmemos.inpocket E/libc: Access denied finding property "vendor.camera.aux.packagelist" 2020-11-05 14:59:16.869 3086-5845/com.xpertmemos.inpocket E/libc: Access denied finding property "vendor.camera.aux.packagelist" 2020-11-05 14:59:16.870 3086-5845/com.xpertmemos.inpocket E/libc: Access denied finding property "vendor.camera.aux.packagelist" 2020-11-05 14:59:16.872 3086-5845/com.xpertmemos.inpocket E/libc: Access denied finding property "vendor.camera.aux.packagelist" 2020-11-05 14:59:16.966 3086-3086/com.xpertmemos.inpocket E/ACS: startCall: start 2020-11-05 14:59:18.879 3086-3086/com.xpertmemos.inpocket E/ACS: startCall: started 2020-11-05 14:59:18.880 3086-3086/com.xpertmemos.inpocket E/ACS: startCall: callid a4f7aa7d-e306-4daa-bf39-f703c7487a2d 2020-11-05 14:59:18.880 3086-3086/com.xpertmemos.inpocket E/ACS: createAgent: created 2020-11-05 14:59:18.935 3086-3086/com.xpertmemos.inpocket E/libc: Access denied finding property "vendor.camera.aux.packagelist" 2020-11-05 14:59:18.937 3086-3086/com.xpertmemos.inpocket E/libc: Access denied finding property "vendor.camera.aux.packagelist" 2020-11-05 14:59:19.026 3086-5818/com.xpertmemos.inpocket E/libc: Access denied finding property "vendor.camera.aux.packagelist" 2020-11-05 14:59:19.047 3086-5877/com.xpertmemos.inpocket E/libc: Access denied finding property "vendor.camera.aux.packagelist" 2020-11-05 14:59:19.048 3086-5877/com.xpertmemos.inpocket E/libc: Access denied finding property "vendor.camera.hal1.packagelist" 2020-11-05 14:59:19.622 3086-5818/com.xpertmemos.inpocket E/ACS: Status: Connecting 2020-11-05 14:59:29.898 3086-5857/com.xpertmemos.inpocket E/ACS: Status: None

Web Client Logs:

sdk.bundle.js:200 Send request, method: GET, URL: https://trap.skype.com/tokens, Request options: {"headers":{"X-Skypetoken":"eyJhbGciOiJSUzI1NiIsImtpZCI6IjEwMiIsInR5cCI6IkpXVCJ9.eyJza3lwZWlkIjoiYWNzOmIwN2IxYTY2LWNmNTMtNDMyZC1hYzRmLTRhNDhlZDE4ODFiOV8wMDAwMDAwNi0yY2Y0LWFmMjAtNmNmMS0wNTQ4MjIwMDFjMzIiLCJzY3AiOjE3OTIsImNzaSI6IjE2MDQ1NjY3NTYiLCJpYXQiOjE2MDQ1NjY3NTcsImV4cCI6MTYwNDY1MzE1NiwiYWNzU2NvcGUiOiJ2b2lwIiwicmVzb3VyY2VJZCI6ImIwN2IxYTY2LWNmNTMtNDMyZC1hYzRmLTRhNDhlZDE4ODFiOSJ9.JeYZNPiAjamFT008MsIPl3k1yBRpgtz7hERVO-u_-PTkHyOcL19vMlTEYCWaobG3w5yL-sv4DAjzJA47mUTFlyCwsx16GXZ4n5gmBoOWLoHoDEbCjY_C1WWbNaAJ7LLQOBSv7g7S_qNxmRW9DoQ4BkTTggDXAbusCIt9SYADuik-zNnpnQzim5mYIxuUQLO9Opd7kaMOuYUFsq52ivjOgyyINmG2m4D2LolgCQS-mELP13CyUT2P9mEyhUXqGesYVH29_pfB_B7WW49Bc7D4-tyn4k035WVTtsTAd1q32fEwWCL8eZrzQilE7RT67mokZupssNN0e340xVwQeRITpw","api-version":2},"retry":{},"reporting":{"serviceName":"ngcCallController-GET"},"payload":null,"timeout":null} azure-call.component.ts:95 11/5/2020, 14:59:19:424 [CallClient] [JS.TsCalling.Pluginless] ffffffff: PluginlessStack/CallRegistry/[554d1928][login] login azure-call.component.ts:95 11/5/2020, 14:59:19:426 [CallClient] [JS.TsCalling.Pluginless] ffffffff: PluginlessStack/CallRegistry/[554d1928][initialize] initialize azure-call.component.ts:95 11/5/2020, 14:59:19:426 [CallClient] Trouterservice registerMessageHandler azure-call.component.ts:95 11/5/2020, 14:59:19:427 [CallClient][Trouter] [Trouter] registerMessageHandler is called azure-call.component.ts:95 11/5/2020, 14:59:19:428 [CallClient] Trouterservice registerMessageHandler azure-call.component.ts:95 11/5/2020, 14:59:19:428 [CallClient][Trouter] [Trouter] registerMessageHandler is called azure-call.component.ts:95 11/5/2020, 14:59:19:429 [CallClient] [JS.TsCalling.Pluginless] ffffffff: PluginlessStack/CallRegistry/[554d1928][initialize] Call registry init, endpointMetadata, azure-call.component.ts:95 11/5/2020, 14:59:19:452 [CallClient] [JS.TsCalling.MediaAgent] ffffffff: MA/DeviceManager/PermissionManager Permission state for microphone changed unknown -> granted azure-call.component.ts:95 11/5/2020, 14:59:19:453 [CallClient] [JS.TsCalling.MediaAgent] ffffffff: MA/DeviceManager Device event: permissions_state_changed: {"microphone":"granted","camera":"unknown"} azure-call.component.ts:95 11/5/2020, 14:59:19:487 [CallClient] [JS.TsCalling.MediaAgent] ffffffff: MA/DeviceManager/PermissionManager Permission state for camera changed unknown -> granted azure-call.component.ts:95 11/5/2020, 14:59:19:488 [CallClient] [JS.TsCalling.MediaAgent] ffffffff: MA/DeviceManager Device event: permissions_state_changed: {"microphone":"granted","camera":"granted"} azure-call.component.ts:95 11/5/2020, 14:59:20:108 [CallClient] [JS.TsCalling.MediaAgent] ffffffff: MA/DeviceManager/DeviceEnumerator/DeviceList Device lists updated and changed azure-call.component.ts:95 11/5/2020, 14:59:20:108 [CallClient] [JS.TsCalling.MediaAgent] ffffffff: MA/DeviceManager/DeviceEnumerator/DeviceList microphone|input(4)|-communications|default:groupId|default(u2)|-defaultId azure-call.component.ts:95 11/5/2020, 14:59:20:109 [CallClient] [JS.TsCalling.MediaAgent] ffffffff: MA/DeviceManager/DeviceEnumerator/DeviceList camera|input(2)|default:noSynthetic|default(u3) azure-call.component.ts:95 11/5/2020, 14:59:20:109 [CallClient] [JS.TsCalling.MediaAgent] ffffffff: MA/DeviceManager/DeviceEnumerator/DeviceList speaker|input(3)|-communications|default:firstNonDefault|default(u4)|-defaultId azure-call.component.ts:95 11/5/2020, 14:59:20:110 [CallClient] [JS.TsCalling.MediaAgent] ffffffff: MA/DeviceManager/DeviceEnumerator/DeviceList compositeAudio azure-call.component.ts:95 11/5/2020, 14:59:20:112 [CallClient] [JS.TsCalling.MediaAgent] ffffffff: MA/DeviceManager/DeviceEnumerator/DeviceSelection Changed due to device list change: {"deviceId":"u5","label":"u6","kind":"audioinput","groupId":"u7","type":"microphone","guid":"u2","isSystemDefault":true},{"deviceId":"u8","label":"u9","kind":"videoinput","groupId":"u10","type":"camera","guid":"u3","isSystemDefault":true,"position":"u11"},{"deviceId":"u12","label":"u13","kind":"audiooutput","groupId":"u7","type":"speaker","guid":"u4","isSystemDefault":true} azure-call.component.ts:95 11/5/2020, 14:59:20:114 [CallClient] [JS.TsCalling.MediaAgent] ffffffff: MA/DeviceManager Device event: selected_devices_changed: "{\"microphone\":\"u14\",\"camera\":\"u11\",\"speaker\":\"u14\"}" azure-call.component.ts:95 11/5/2020, 14:59:20:119 [CallClient] [JS.TsCalling.MediaAgent] ffffffff: MA/DeviceManager Device event: devices_changed: ["{\"label\":\"u14\",\"isSystemDefault\":true,\"kind\":\"audioinput\",\"type\":\"microphone\"}","{\"label\":\"u15\",\"isSystemDefault\":false,\"kind\":\"audioinput\",\"type\":\"microphone\"}","{\"label\":\"u11\",\"isSystemDefault\":true,\"kind\":\"videoinput\",\"type\":\"camera\"}","{\"label\":\"u11\",\"isSystemDefault\":false,\"kind\":\"videoinput\",\"type\":\"camera\"}","{\"label\":\"u14\",\"isSystemDefault\":true,\"kind\":\"audiooutput\",\"type\":\"speaker\"}"] azure-call.component.ts:95 11/5/2020, 14:59:20:121 [CallClient] [JS.TsCalling.MediaAgent] ffffffff: MA/DeviceManager Renderers updates finished azure-call.component.ts:95 11/5/2020, 14:59:20:123 [CallClient][DeviceManager] tsDevicesList:[{"id":"microphone:1f3689eb298d3caabfc1756cf79c2857ca010793296dc605c228c4619b3900da","browserId":"1f3689eb298d3caabfc1756cf79c2857ca010793296dc605c228c4619b3900da","label":"Microphone (Realtek(R) Audio)","kind":2,"isSystemDefault":true},{"id":"microphone:47fa8e37baa7e667f7d59246ce428b707b6309f9a6ab58780fa663bf7dd0a9d3","browserId":"47fa8e37baa7e667f7d59246ce428b707b6309f9a6ab58780fa663bf7dd0a9d3","label":"Microphone (DroidCam Virtual Audio)","kind":2,"isSystemDefault":false},{"id":"camera:292463ff68c6c1812132b2aebaad6a2e0371753afa3d3c83c6a7301ecc850019","browserId":"292463ff68c6c1812132b2aebaad6a2e0371753afa3d3c83c6a7301ecc850019","label":"DroidCam Source 3","kind":1,"position":0},{"id":"camera:29f3ff0d3b30ea75f564a23d5c56f81bb4571d2061bbdb6e60c155f034c624d6","browserId":"29f3ff0d3b30ea75f564a23d5c56f81bb4571d2061bbdb6e60c155f034c624d6","label":"DroidCam Source 2","kind":1,"position":0},{"id":"speaker:ecf7c4aeda47319598e6427132ea8d21d62222331d6dda576d3e78b8a2e67475","browserId":"ecf7c4aeda47319598e6427132ea8d21d62222331d6dda576d3e78b8a2e67475","label":"Speakers (Realtek(R) Audio)","kind":3,"isSystemDefault":true}] sdk.bundle.js:232 ECS - Config fetch complete azure-call.component.ts:93 11/5/2020, 14:59:20:293 [CallClient] [RootToolsManager] Reloading ULBaseline config - new config: %@ azure-call.component.ts:93 11/5/2020, 14:59:20:294 [CallClient] [RootToolsManager] Reloading ECS config for AsyncMediaClient->ULLogUpload - new config: %@ azure-call.component.ts:93 11/5/2020, 14:59:20:295 [CallClient] [RootToolsManager] Reloading ECS config for teamsddl->ULLogUpload - new config: %@ azure-call.component.ts:93 11/5/2020, 14:59:20:296 [CallClient] [RootToolsManager] Reloading ECS config for Notifications->ULLogUpload - new config: %@ azure-call.component.ts:93 11/5/2020, 14:59:20:297 [CallClient] [RootToolsManager] Reloading ECS config for SkypeAudioLibrary->ULLogUpload - new config: %@ azure-call.component.ts:93 11/5/2020, 14:59:20:299 [CallClient] [RootToolsManager] Reloading ECS config for SkypeCallQuality->LiveDebugging - new config: %@ azure-call.component.ts:93 11/5/2020, 14:59:20:300 [CallClient] [RootToolsManager] Reloading ECS config for SkypeCalling->LiveDebugging - new config: %@ azure-call.component.ts:93 11/5/2020, 14:59:20:301 [CallClient] [RootToolsManager] Reloading ECS config for SkypeRealTimeMedia->ULLogUpload - new config: %@ azure-call.component.ts:93 11/5/2020, 14:59:20:303 [CallClient] [RootToolsManager] Reloading ECS config for SkypeMediaStack->ULLogUpload - new config: %@ azure-call.component.ts:93 11/5/2020, 14:59:20:304 [CallClient] [RootToolsManager] Reloading ECS config for SkypeResourceManager->ULLogUpload - new config: %@ azure-call.component.ts:93 11/5/2020, 14:59:20:306 [CallClient] [RootToolsManager] Reloading ECS config for SkypeRootTools->ULLogUpload - new config: %@ azure-call.component.ts:93 11/5/2020, 14:59:20:307 [CallClient] [RootToolsManager] Reloading ECS config for SkypeRootTools->DDLTest - new config: %@ azure-call.component.ts:93 11/5/2020, 14:59:20:309 [CallClient] [RootToolsManager] Reloading ECS config for SkypeRootTools->S4L_JS_Buffer - new config: %@ azure-call.component.ts:93 11/5/2020, 14:59:20:310 [CallClient] [RootToolsManager] Reloading ECS config for SkypeTransport->ULLogUpload - new config: %@ azure-call.component.ts:93 11/5/2020, 14:59:20:311 [CallClient] [RootToolsManager] Reloading ECS config for SkypeVideoLibrary->ULLogUpload - new config: %@ azure-call.component.ts:93 11/5/2020, 14:59:20:313 [CallClient] [RootToolsManager] Reloading ECS config for TrouterClientCorelib->ULLogUpload - new config: %@ azure-call.component.ts:93 11/5/2020, 14:59:20:315 [CallClient] [RootToolsManager] Reloading ECS config for SkypeIoT->ULLogUpload - new config: %@ azure-call.component.ts:93 11/5/2020, 14:59:20:317 [CallClient] [RootToolsManager] Reloading ECS config for MediaAgent->ULLogUpload - new config: %@ azure-call.component.ts:93 11/5/2020, 14:59:20:319 [CallClient] [RootToolsManager] Reloading ECS config for S4L_CMC->ULLogUpload - new config: %@ azure-call.component.ts:93 11/5/2020, 14:59:20:321 [CallClient] [RootToolsManager] Reloading ECS config for S4L_Telemetry->ULLogUpload - new config: %@ azure-call.component.ts:93 11/5/2020, 14:59:20:323 [CallClient] [RootToolsManager] Reloading ECS config for SCT->ULLogUpload - new config: %@ azure-call.component.ts:93 11/5/2020, 14:59:20:325 [CallClient] [RootToolsManager] Reloading ECS config for SkypeQualityController->ULLogUpload - new config: %@ azure-call.component.ts:93 11/5/2020, 14:59:20:326 [CallClient] [RootToolsManager] Reloading ECS config for S4L_Feedback->ULLogUpload - new config: %@ azure-call.component.ts:93 11/5/2020, 14:59:20:328 [CallClient] [RootToolsManager] Reloading ECS config for MDN_TRAP->ULLogUpload - new config: %@ azure-call.component.ts:93 11/5/2020, 14:59:20:329 [CallClient] [RootToolsManager] Reloading ECS config for Identity->ULLogUpload - new config: %@ azure-call.component.ts:93 11/5/2020, 14:59:20:331 [CallClient] [RootToolsManager] Reloading ECS config for RtcPalVideoConfiguration->ULLogUpload - new config: %@ azure-call.component.ts:93 11/5/2020, 14:59:20:333 [CallClient] [RootToolsManager] Reloading ECS config for Broadcast->ULLogUpload - new config: %@ azure-call.component.ts:93 11/5/2020, 14:59:20:335 [CallClient] [RootToolsManager] Reloading ECS config for S4L_SISU->ULLogUpload - new config: %@ azure-call.component.ts:93 11/5/2020, 14:59:20:338 [CallClient] [RootToolsManager] Reloading ECS config for S4L_Messaging->ULLogUpload - new config: %@ azure-call.component.ts:93 11/5/2020, 14:59:20:340 [CallClient] [RootToolsManager] Reloading ECS config for SkypeWebMedia->ULLogUpload - new config: %@ azure-call.component.ts:95 11/5/2020, 14:59:20:344 [CallClient] [JS.TsCalling.MediaAgent] ffffffff: MA/configProvider Settings updated: {"activeSpeaker":{"timeToPromote":3000},"dtmf":{"toneDuration":200,"toneGap":100},"ortcAllowedMediaContentType":["application/sdp","application/sdp-ngc-0.5","application/sdp-ngc-1.0"],"webrtcAllowedMediaContentType":["application/sdp","application/sdp-ngc-0.5","application/sdp-ngc-1.0"],"webrtcVideoCapabilityMaxFS":3600,"webrtcMultiPartyRecvVideoMaxFS":3600,"webrtcCameraOpenFs":3600,"webrtcMultipartyMaxScalingFs":3600,"webrtcMaxScalingFs":3600,"iceServerTransport":"tls,tcp,udp","webrtcEnabledTransportCC":true,"webrtcRejectedFeatures":"byPass","webrtcRequiredFeatures":"nonByPass","webrtcSimulcastSessionEnabled":true,"webrtcFmtParamListSupported":true,"webrtcAllowRestoreKeyframe":true,"permissions":{"usePositiveInAdp":false,"useNegativeInAdp":false,"adpFallback":true,"adpFallbackAudio":true,"adpFallbackVideo":true,"adpRequestAVLast":true,"rememberNegative":false},"devices":{"blacklist":{"microphone":"","camera":"(ir camera|avstream media device)","speaker":"stereo mix \("},"compositeAudioDevices":false,"compositeLabelMatchingThreshold":0.5,"compositeAudioDeviceLabelMatchingHints":[],"piiSafeWords":["virtual","display","high definition","integrated","built-in","usb","test","default","citrix hdx","panoramic"]},"webrtcSendBandwidthNotificationsEnabled":true,"allowedAudioCodecs1on1":[],"allowedAudioCodecsMultiparty":[],"allowedVideoCodecs1on1":[],"allowedVideoCodecsMultiparty":[],"preferSdesSrtp1on1":false,"telemetryTenants":{"signaling":"53fdaa090eb946b5a1d6cbdeb4f2ef66-bcbf6380-2590-41cc-ae60-9e467cd51835-7413","media":"1cae5691997646c98b01d15beddae7a3-ce16e198-bc32-420f-ac64-42bb916111af-6865"},"transmitProfileTimings":[],"isSourceIdMappingEnabled":true,"allowMediaLegIdUpdate":true} azure-call.component.ts:95 11/5/2020, 14:59:20:345 [CallClient] [JS.TsCalling.Pluginless] ffffffff: onEcsUpdate, ecsTag="Pb/tl3MBsh6c4+5HQOMy6RRM2IfxFvEHIE/cskfAMa4=", ecsConfig={"enableEncryptedHttp":false,"enableEncryptedHttpForBroker":false,"enableNewTransportStack":true,"csaTimeoutConfiguration":{"httpConnectionHedgingTimeoutInMs":4000,"httpConnectionHedgedRetryTimeoutInMs":6000,"httpHedgedRequestTransportForkingDelayInMs":1000,"udpConnectionHedgingTimeoutInMs":1000,"udpCanaryTimeoutMs":2000},"mcr":{"enabled":false,"serviceFqdn":"https://api.mcr.skype.com","getMissedCallsUrl":"/clients/v1/users/skype/%destinationId%/missed-calls?anchor=","markReadStatusUrl":"/clients/v1/users/skype/%destinationId%/missed-calls/%anchor%/read-status?value=read"},"enableThirdPartyCallControl":true,"pstnContentPayload":true,"enableDeltaRoster":true,"enableDeltaRosterWeb":false,"enableDeltaRosterOneToOne":false,"mediaConfiguration_TransportVersion":"4","brokerExclusively":false,"ngIncoming":{"isBrokerEnabled":true,"isUdpCanaryEnabled":true},"ngOutgoing":{"isBrokerEnabled":true,"isEmergencyCallingEnabled":true},"conversationServiceUrl":"https://api3.cc.skype.com/conv/","callControllerServiceUrl":"https://api3.cc.skype.com","udpTransportUrl":"udp://api3.cc.skype.com:3478","keyDistributionUrl":"https://api3.cc.skype.com/kd/","EarlyRinging":3,"udpSignalingFastTimeoutMs":1500,"udpSignalingRetransmitTimeoutMs":600,"udpSignalingRetransmitCount":2,"udpSignalingMaxPacketSize":1470,"csaCallModalityEventPrioBoost":1,"cacheTrouterResponses":true,"autoJoinOnRedirect":true,"enableGroupCallEventMessagesOnService":true,"p2pForkDelayInMs":-1,"csaHttpPrioBoost":1,"csaVideoPrioBoost":1,"enableUdpFragmentation":true,"enableUdpKeepAlive":true,"enableDnsCache":false,"enableUdpAlways":true,"supportCompressedTrouterPayload":true,"allowBrokerSubscribeBatching":true,"disableForwardingTimerOnClient":true,"mediaConfiguration_IceClientVersion":"6","mediaConfiguration_SimulateReinviteEnabled":"1","mediaConfiguration_ContactServerTimeoutIncrement":"0","mediaConfiguration_DisabledPipes":"2","enableCallMerge":true,"mediaConfiguration_EnableH264AVC":"1","mediaConfiguration_EnableRtx":"1","mediaConfiguration_DisableVC1":"1","mediaConfiguration_EnableAVMultiplexing":"1"} azure-call.component.ts:95 11/5/2020, 14:59:20:346 [CallClient] [JS.TsCalling.SignalingAgent] ffffffff: SignalingAgent [bcabe2b5] updateSignalingAgentConfig, SignalingAgentConfig: {"conversationServiceUrl":"https://api3.cc.skype.com/conv/","languageCode":"en","clientInformation":"SpoolWeb(3617/1.0.0.0)/TsCallingVersion=2020.35.01.23/Ovb=fa5f52a3a4632db56101a3d0e5c93e0bcbee52dd","emergencyCallCountry":"","useInternalHttpDispatcher":"true","supportsHostlessGroupCalls":"true","doHostlessCalling":"true","shouldServiceSendCallEventMessages":"true","shouldServiceSendNGCUpgradeMessages":"true","supportsCompressedServicePayload":"true","handleNewOfferRequest":"true","handleMediaOfferFromPushNotification":"true","isWebRtcEnabled":"true","supportsSynchronousTrouterResponse":"true","autoJoinOnConflict":"true","brokerEnabledOutgoing":"true","brokerEnabledIncoming":"true","brokerExclusively":"false","brokerRequestBatching":"true","isGVCOutgoingEnabled":"true","isGVCJoiningEnabled":"true","enableTokenCache":"true","httpRequestDispatcher":"[object Object]","telemetryManager":"[object Object]","logger":"[object Object]","skypeToken":"()=>this._callAgent.tokenProvider()","trouterServiceProvider":"[object Object]","piiScrubber":"[object Object]","handleRosterFromCreateAndJoin":"true","cloudScreenSharingFlag":"enabled","endConflictedCall":"false","autoResolveConflictedCall":"false","handleUnmuteMuteFromResponse":"false","forceTrouterReconnectOnNetworkOnline":"true","attemptHttpRequestWithCachedSkypetoken":"true","enableTokenPrefetch":"false","hedgeDelayMs":"3000","hedgeMaxParallelAttempts":"3","overrideDisplayName":"false","enableDeltaRosterWeb":"false","processSelfDataFromSubscribeResponse":"true","uploadLogRequestUrl":"undefined","isConversationServiceUrlFromEcs":"true","isUploadLogRequestUrlFromEcs":"false","sendProgressFromCC":"undefined","ecsEtag":"\"Pb/tl3MBsh6c4+5HQOMy6RRM2IfxFvEHIE/cskfAMa4=\""} azure-call.component.ts:95 11/5/2020, 14:59:20:347 [CallClient] [JS.TsCalling.SignalingAgent] ffffffff: SignalingAgent [bcabe2b5] ecsEtag="Pb/tl3MBsh6c4+5HQOMy6RRM2IfxFvEHIE/cskfAMa4=" azure-call.component.ts:95 11/5/2020, 14:59:20:802 [CallClient] [JS.TsCalling.MediaAgentUnsafe] ffffffff: RM relays from trap, {"Skype":[{"addresses":["13.107.8.2"],"fqdns":[],"tcpPort":443,"udpPort":3478,"type":"msturn","expires":172800,"username":"AgAAJEhtOBsB1rTkp+OKPysFmmQXA5/1x68+Y/xpUbYAAAAEAGK1/S/NcJ2bAd2XSvLDLLzoMLg=","password":"En48TQAQasZj2arPAXXBwtUxPoA=","realm":"\"rtcmedia\""}],"Lync":[{"addresses":["mr.skype.net"],"fqdns":[],"tcpPort":443,"udpPort":3478,"type":"msturn","expires":172800,"username":"AgAAJEhtOBsB1rTkp+OKPysFmmQXA5/1x68+Y/xpUbYAAAAEAGK1/S/NcJ2bAd2XSvLDLLzoMLg=","password":"En48TQAQasZj2arPAXXBwtUxPoA=","realm":"\"rtcmedia\""}],"Turn":[{"addresses":["52.113.193.150"],"fqdns":["eu.turn.teams.microsoft.com"],"tcpPort":443,"udpPort":3478,"tlsPort":443,"type":"turn","expires":172800,"username":"AgAAJEhtOBsB1rTkp+OKPysFmmQXA5/1x68+Y/xpUbYAAAAEAGK1/S/NcJ2bAd2XSvLDLLzoMLg=","password":"En48TQAQasZj2arPAXXBwtUxPoA=","realm":"\"rtcmedia\""}]} azure-call.component.ts:95 11/5/2020, 14:59:20:938 [CallClient][Trouter] [Connection] Register request successful azure-call.component.ts:95 11/5/2020, 14:59:20:938 [CallClient][Trouter] [Connection] dispatching connected azure-call.component.ts:95 11/5/2020, 14:59:20:939 [CallClient][Trouter] [ManagerFsm] Ignoring event 'onRegistered(true)' in state 'Connected' azure-call.component.ts:93 11/5/2020, 14:59:20:939 [CallClient][Trouter] [Connection] Current connectionID will expire in 78138 seconds azure-call.component.ts:93 11/5/2020, 14:59:20:940 [CallClient][Trouter] [Connection] Starting registration timeout for 78108 sec azure-call.component.ts:95 11/5/2020, 14:59:59:317 [CallClient][Trouter] [Connection] Ping interval fired azure-call.component.ts:95 11/5/2020, 14:59:59:318 [CallClient][Trouter] [Connection] emitting ping event azure-call.component.ts:95 11/5/2020, 14:59:59:510 [CallClient][Trouter] [Connection] onPingResponse azure-call.component.ts:95 11/5/2020, 15:0:39:317 [CallClient][Trouter] [Connection] Ping interval fired azure-call.component.ts:95 11/5/2020, 15:0:39:318 [CallClient][Trouter] [Connection] emitting ping event azure-call.component.ts:95 11/5/2020, 15:0:39:447 [CallClient][Trouter] [Connection] onPingResponse azure-call.component.ts:95 11/5/2020, 15:1:19:319 [CallClient][Trouter] [Connection] Ping interval fired azure-call.component.ts:95 11/5/2020, 15:1:19:320 [CallClient][Trouter] [Connection] emitting ping event azure-call.component.ts:95 11/5/2020, 15:1:19:488 [CallClient][Trouter] [Connection] onPingResponse azure-call.component.ts:95 11/5/2020, 15:1:59:323 [CallClient][Trouter] [Connection] Ping interval fired azure-call.component.ts:95 11/5/2020, 15:1:59:324 [CallClient][Trouter] [Connection] emitting ping event azure-call.component.ts:95 11/5/2020, 15:1:59:526 [CallClient][Trouter] [Connection] onPingResponse azure-call.component.ts:95 11/5/2020, 15:2:39:317 [CallClient][Trouter] [Connection] Ping interval fired azure-call.component.ts:95 11/5/2020, 15:2:39:317 [CallClient][Trouter] [Connection] emitting ping event azure-call.component.ts:95 11/5/2020, 15:2:39:465 [CallClient][Trouter] [Connection] onPingResponse azure-call.component.ts:95 11/5/2020, 15:3:19:317 [CallClient][Trouter] [Connection] Ping interval fired .... ......Continue pinging Regards Habib

akania commented 3 years ago

Hi Habib, can you please capture web log - from the very beginning ( have console open before page loads ) , crucial part we're missing here is logged earlier, log that you've attached unfortunately doesn't show the full picture and it's difficult to pin point what's the issue.

Thank you, Artur

mariusu-msft commented 3 years ago

Hi @shipon-eye,

Could you capture log from the very beginning please and share?

Please see Artur's message above.

Thanks, Marius

ghost commented 3 years ago

This issue has been automatically marked as stale because it has been marked as requiring author feedback but has not had any activity for 4 days. It will be closed if no further activity occurs within 3 days of this comment.

Azure / Communication

Android App Client call to web App Client receiver failed very often #91