voximplant / flutter_voximplant

Voximplant Flutter SDK
MIT License
9 stars 7 forks source link

AddIceCandidate: ICE candidates can't be added without any remote session description #42

Closed henriquetroiano closed 1 year ago

henriquetroiano commented 1 year ago

Hey guys! I found a bug (and a trick to prevent the bug, while you fix that):

I'm using Flutter 3.0.5, Android 10 (Galaxy S9 real device, SM G9650). Stack trace on the end of issue :)

The problem:

I'm only able to receive calls if I do a call first. Why? I don't know yet.

If I receive a call before I make a call, i get the error: "AddIceCandidate: ICE candidates can't be added without any remote session description".

But if I make a call first, everything goes ok!

The temporary solution: maybe this solution can help you to find the bug:

I make a call after the login, for a existing user, but this user is not used by nobody. The user 001 is only there to receive the first call. But JUST MAKE A CALL does not solve the bug. The bug only disappears if I run CallService().notifyCallIsEnded(call.callId); on onCallDisconnected and/or onCallFailed events from this first call.

Stack Traces:

Simple Stack Trace

```ruby Restarted application in 3.000ms. I/VOXSDK (13130): Client [LOGGED_IN] setClientSessionListener: com.voximplant.flutter_voximplant.ClientModule@49f5fec I/VOXSDK (13130): Client [LOGGED_IN] setClientLoginListener: com.voximplant.flutter_voximplant.ClientModule@49f5fec I/VOXSDK (13130): Client [LOGGED_IN] setClientIncomingCallListener: com.voximplant.flutter_voximplant.ClientModule@49f5fec I/VOXSDK (13130): Client [LOGGED_IN] disconnect I/VOXSDK (13130): Authenticator [LOGGED_IN] disconnect I/VOXSDK (13130): GWConnection[CONNECTED]: closeConnection I/VOXSDK (13130): GWConnector: stop I/VOXSDK (13130): GWReconnector: stop I/VOXSDK (13130): GWConnection[DISCONNECTING]: SEND: {"type":"close","seq":7} I/VOXSDK (13130): GWConnection[DISCONNECTING]: waitAckForCloseAndCloseTransport I/VOXSDK (13130): GWConnection[DISCONNECTING]: onMessage: {"seq" : 7 , "type" : "ack"} I/VOXSDK (13130): WS[gw,2677112]: close I/VOXSDK (13130): WS[gw,2677112]: onClosing: code: 1000, reason: I/VOXSDK (13130): WS[gw,2677112]: onClosed: code: 1000, reason: W/VOXSDK (13130): GWConnection[DISCONNECTING]: onClose: com.voximplant.sdk.internal.signaling.transport.VoxWebSocket@2677112 W/VOXSDK (13130): GWConnection[DISCONNECTING]: onClose: com.voximplant.sdk.internal.signaling.transport.VoxWebSocket@2677112 I/VOXSDK (13130): Authenticator [LOGGED_IN] onWSClose: reason: I/VOXSDK (13130): Client [DISCONNECTED] onDisconnected I/VOXSDK (13130): CallManager: endAllCalls: no calls I/VOXSDK (13130): VoxAudioManager: stopHeadsetMonitoring D/VOXSDK (13130): VoxAudioManager: stop E/VOXSDK (13130): VoxAudioManager: Trying to stop AudioManager in incorrect state: PREINITIALIZED I/VOXSDK (13130): Invoke onConnectionClosed I/VOXFLUTTER(13130): VoximplantPlugin: onConnectionClosed E/VOXFLUTTER(13130): VoximplantPlugin: onConnectionClosed: result is null D/VOXSDK (13130): VoxBluetoothManager: stop: BT state=HEADSET_UNAVAILABLE D/VOXSDK (13130): VoxBluetoothManager: stopScoAudio: skip due to invalid state HEADSET_UNAVAILABLE D/VOXSDK (13130): VoxBluetoothManager: cancelTimer D/VOXSDK (13130): VoxBluetoothManager: stop done: BT state=UNINITIALIZED I/VOXSDK (13130): Client [DISCONNECTED] getClientState: connectWasCalled: false, loginWasCalled: false I/flutter (13130): AuthService: client state is changed: VIClientState.Disconnected I/flutter (13130): AuthService: client state is changed: VIClientState.Disconnected I/VOXSDK (13130): Client [DISCONNECTED] disconnect I/VOXSDK (13130): Authenticator [DISCONNECTED] disconnect I/VOXSDK (13130): Authenticator [DISCONNECTED] onWSClose: reason: null I/VOXSDK (13130): Client [DISCONNECTED] onDisconnected I/VOXSDK (13130): CallManager: endAllCalls: no calls I/VOXSDK (13130): VoxAudioManager: stopHeadsetMonitoring I/VOXSDK (13130): Invoke onConnectionClosed I/VOXFLUTTER(13130): VoximplantPlugin: onConnectionClosed E/VOXFLUTTER(13130): VoximplantPlugin: onConnectionClosed: result is null D/VOXSDK (13130): VoxAudioManager: stop E/VOXSDK (13130): VoxAudioManager: Trying to stop AudioManager in incorrect state: PREINITIALIZED E/VOXSDK (13130): VoxAudioManager: unregisterReceiver: Receiver not registered: com.voximplant.sdk.internal.hardware.VoxAudioManager$WiredHeadsetReceiver@e8a52b4 I/flutter (13130): AuthService: client state is changed: VIClientState.Disconnected D/VOXSDK (13130): VoxBluetoothManager: stop: BT state=UNINITIALIZED I/VOXSDK (13130): Client [DISCONNECTED] getClientState: connectWasCalled: false, loginWasCalled: false I/flutter (13130): AuthService: client state is changed: VIClientState.Disconnected I/flutter (13130): AuthService: client state is changed: VIClientState.Connecting I/VOXSDK (13130): Client [DISCONNECTED] connect: connectivity check: false I/VOXSDK (13130): Authenticator [REQUEST_TO_BALANCER] 582ac2d9-f695-4a7a-98ae-188940b6cca6 I/VOXSDK (13130): Authenticator [REQUEST_TO_BALANCER] onResponse I/VOXSDK (13130): Authenticator [REQUEST_TO_BALANCER] onResponse: response code is successful I/VOXSDK (13130): GWConnection[DISCONNECTED]: openConnection I/VOXSDK (13130): GWConnector: start: version: android-2.32.4_flutter-3.5.1 I/VOXSDK (13130): GWConnector: start: created transport: 8915546, for: web-gw-br-12-99.voximplant.com I/VOXSDK (13130): WS[gw,8915546]: open I/VOXSDK (13130): WS[gw,8915546]: onOpen I/VOXSDK (13130): GWConnector: onOpen: 8915546 I/VOXSDK (13130): GWConnection[CONNECTING]: onTransportConnected: com.voximplant.sdk.internal.signaling.transport.VoxWebSocket@8915546 I/VOXSDK (13130): GWConnection[CONNECTING]: onMessage: {"id" : "189.1.168.99_7F5FF857DD1C6631.1663964112.3968063_431226" , "type" : "id"} I/VOXSDK (13130): GWConnection[CONNECTING]: onMessage: {"seq" : 0 , "type" : "lastrx"} I/VOXSDK (13130): GWConnection[CONNECTING]: SEND: {"type":"lastrx","seq":0} I/VOXSDK (13130): GWConnection[CONNECTING]: onMessage: {"payload" : {"name" : "__createConnection" , "params" : []} , "seq" : 1 , "type" : "msg"} I/VOXSDK (13130): GWConnection[CONNECTED]: connection is established I/VOXSDK (13130): Authenticator [CONNECTING] onConnected I/VOXSDK (13130): Client [CONNECTED] onConnected I/VOXSDK (13130): VoxAudioManager: startHeadsetMonitoring I/VOXSDK (13130): Invoke onConnectionEstablished I/VOXFLUTTER(13130): VoximplantPlugin: onConnectionEstablished D/VOXSDK (13130): VoxBluetoothManager: start D/VOXSDK (13130): VoxBluetoothManager: BluetoothAdapter: enabled=false, state=BA_OFF, name=Galaxy S9+ de Caio, address=02:00:00:00:00:00 D/BluetoothHeadset(13130): BTStateChangeCB is registed by 13130 @ com.example.audio_call2 D/VOXSDK (13130): VoxBluetoothManager: HEADSET profile state: BA_DISCONNECTED D/VOXSDK (13130): VoxBluetoothManager: Bluetooth proxy for headset profile has started D/VOXSDK (13130): VoxBluetoothManager: start done: BT state=HEADSET_UNAVAILABLE I/VOXSDK (13130): Client [CONNECTED] getClientState: connectWasCalled: false, loginWasCalled: false I/flutter (13130): AuthService: client state is changed: VIClientState.Connected I/VOXSDK (13130): GWConnection[CONNECTED]: SEND: {"type":"ack","seq":1} I/ViewRootImpl@4b5fede[MainActivity](13130): ViewPostIme pointer 0 I/ViewRootImpl@4b5fede[MainActivity](13130): ViewPostIme pointer 1 I/flutter (13130): LoginScreen: login with password: username: 200@vn3.henriquetroiano.n2 I/VOXSDK (13130): Client [CONNECTED] disconnect I/VOXSDK (13130): Authenticator [CONNECTED] disconnect I/VOXSDK (13130): GWConnection[CONNECTED]: closeConnection I/VOXSDK (13130): GWConnector: stop I/VOXSDK (13130): GWReconnector: stop I/VOXSDK (13130): GWConnection[DISCONNECTING]: SEND: {"type":"close","seq":1} I/VOXSDK (13130): GWConnection[DISCONNECTING]: waitAckForCloseAndCloseTransport I/VOXSDK (13130): GWConnection[DISCONNECTING]: onMessage: {"seq" : 1 , "type" : "ack"} I/VOXSDK (13130): WS[gw,8915546]: close I/VOXSDK (13130): WS[gw,8915546]: onClosing: code: 1000, reason: I/VOXSDK (13130): WS[gw,8915546]: onClosed: code: 1000, reason: W/VOXSDK (13130): GWConnection[DISCONNECTING]: onClose: com.voximplant.sdk.internal.signaling.transport.VoxWebSocket@8915546 W/VOXSDK (13130): GWConnection[DISCONNECTING]: onClose: com.voximplant.sdk.internal.signaling.transport.VoxWebSocket@8915546 I/VOXSDK (13130): Authenticator [CONNECTED] onWSClose: reason: I/VOXSDK (13130): Client [DISCONNECTED] onDisconnected I/VOXSDK (13130): CallManager: endAllCalls: no calls I/VOXSDK (13130): VoxAudioManager: stopHeadsetMonitoring I/VOXSDK (13130): Invoke onConnectionClosed I/VOXFLUTTER(13130): VoximplantPlugin: onConnectionClosed E/VOXFLUTTER(13130): VoximplantPlugin: onConnectionClosed: result is null D/VOXSDK (13130): VoxAudioManager: stop E/VOXSDK (13130): VoxAudioManager: Trying to stop AudioManager in incorrect state: PREINITIALIZED D/VOXSDK (13130): VoxBluetoothManager: stop: BT state=HEADSET_UNAVAILABLE D/VOXSDK (13130): VoxBluetoothManager: stopScoAudio: skip due to invalid state HEADSET_UNAVAILABLE D/VOXSDK (13130): VoxBluetoothManager: cancelTimer D/VOXSDK (13130): VoxBluetoothManager: stop done: BT state=UNINITIALIZED I/VOXSDK (13130): Client [DISCONNECTED] getClientState: connectWasCalled: false, loginWasCalled: false I/flutter (13130): AuthService: client state is changed: VIClientState.Disconnected I/flutter (13130): AuthService: client state is changed: VIClientState.Disconnected I/VOXSDK (13130): Client [DISCONNECTED] disconnect I/VOXSDK (13130): Authenticator [DISCONNECTED] disconnect I/VOXSDK (13130): Authenticator [DISCONNECTED] onWSClose: reason: null I/VOXSDK (13130): Client [DISCONNECTED] onDisconnected I/VOXSDK (13130): CallManager: endAllCalls: no calls I/VOXSDK (13130): VoxAudioManager: stopHeadsetMonitoring I/VOXSDK (13130): Invoke onConnectionClosed I/VOXFLUTTER(13130): VoximplantPlugin: onConnectionClosed E/VOXFLUTTER(13130): VoximplantPlugin: onConnectionClosed: result is null D/VOXSDK (13130): VoxAudioManager: stop E/VOXSDK (13130): VoxAudioManager: Trying to stop AudioManager in incorrect state: PREINITIALIZED E/VOXSDK (13130): VoxAudioManager: unregisterReceiver: Receiver not registered: com.voximplant.sdk.internal.hardware.VoxAudioManager$WiredHeadsetReceiver@e8a52b4 D/VOXSDK (13130): VoxBluetoothManager: stop: BT state=UNINITIALIZED I/VOXSDK (13130): Client [DISCONNECTED] getClientState: connectWasCalled: false, loginWasCalled: false I/flutter (13130): AuthService: client state is changed: VIClientState.Disconnected I/flutter (13130): AuthService: client state is changed: VIClientState.Disconnected I/VOXSDK (13130): Client [DISCONNECTED] disconnect I/VOXSDK (13130): Authenticator [DISCONNECTED] disconnect I/VOXSDK (13130): Authenticator [DISCONNECTED] onWSClose: reason: null I/VOXSDK (13130): Client [DISCONNECTED] onDisconnected I/VOXSDK (13130): CallManager: endAllCalls: no calls I/VOXSDK (13130): VoxAudioManager: stopHeadsetMonitoring I/VOXSDK (13130): Invoke onConnectionClosed I/VOXFLUTTER(13130): VoximplantPlugin: onConnectionClosed E/VOXFLUTTER(13130): VoximplantPlugin: onConnectionClosed: result is null D/VOXSDK (13130): VoxAudioManager: stop E/VOXSDK (13130): VoxAudioManager: Trying to stop AudioManager in incorrect state: PREINITIALIZED E/VOXSDK (13130): VoxAudioManager: unregisterReceiver: Receiver not registered: com.voximplant.sdk.internal.hardware.VoxAudioManager$WiredHeadsetReceiver@e8a52b4 D/VOXSDK (13130): VoxBluetoothManager: stop: BT state=UNINITIALIZED I/flutter (13130): AuthService: client state is changed: VIClientState.Disconnected I/VOXSDK (13130): Client [DISCONNECTED] getClientState: connectWasCalled: false, loginWasCalled: false I/flutter (13130): AuthService: client state is changed: VIClientState.Disconnected I/flutter (13130): AuthService: client state is changed: VIClientState.Connecting I/VOXSDK (13130): Client [DISCONNECTED] connect: connectivity check: false I/VOXSDK (13130): Authenticator [REQUEST_TO_BALANCER] d85829f2-f6f5-4b01-a056-bb5aa013a12d I/VOXSDK (13130): Authenticator [REQUEST_TO_BALANCER] onResponse I/VOXSDK (13130): Authenticator [REQUEST_TO_BALANCER] onResponse: response code is successful I/VOXSDK (13130): GWConnection[DISCONNECTED]: openConnection I/VOXSDK (13130): GWConnector: start: version: android-2.32.4_flutter-3.5.1 I/VOXSDK (13130): GWConnector: start: created transport: 5d9beda, for: web-gw-br-11-195.voximplant.com I/VOXSDK (13130): WS[gw,5d9beda]: open I/VOXSDK (13130): WS[gw,5d9beda]: onOpen I/VOXSDK (13130): GWConnector: onOpen: 5d9beda I/VOXSDK (13130): WS[gw,5d9beda]: onMessage: listener is not set, keep the message I/VOXSDK (13130): GWConnection[CONNECTING]: onTransportConnected: com.voximplant.sdk.internal.signaling.transport.VoxWebSocket@5d9beda I/VOXSDK (13130): WS[gw,5d9beda]: onMessage: listener is not set, keep the message I/VOXSDK (13130): WS[gw,5d9beda]: send unconsumed messages to a new listener I/VOXSDK (13130): GWConnection[CONNECTING]: onMessage: {"id" : "129.227.121.195_894C362F2F2CFF73.1663964119.5797400_633092" , "type" : "id"} I/VOXSDK (13130): GWConnection[CONNECTING]: onMessage: {"seq" : 0 , "type" : "lastrx"} I/VOXSDK (13130): GWConnection[CONNECTING]: SEND: {"type":"lastrx","seq":0} I/VOXSDK (13130): GWConnection[CONNECTING]: onMessage: {"payload" : {"name" : "__createConnection" , "params" : []} , "seq" : 1 , "type" : "msg"} I/VOXSDK (13130): GWConnection[CONNECTED]: connection is established I/VOXSDK (13130): Authenticator [CONNECTING] onConnected I/VOXSDK (13130): Client [CONNECTED] onConnected I/VOXSDK (13130): VoxAudioManager: startHeadsetMonitoring D/VOXSDK (13130): VoxBluetoothManager: start I/VOXSDK (13130): Invoke onConnectionEstablished I/VOXFLUTTER(13130): VoximplantPlugin: onConnectionEstablished D/VOXSDK (13130): VoxBluetoothManager: BluetoothAdapter: enabled=false, state=BA_OFF, name=Galaxy S9+ de Caio, address=02:00:00:00:00:00 D/BluetoothHeadset(13130): BTStateChangeCB is registed by 13130 @ com.example.audio_call2 D/VOXSDK (13130): VoxBluetoothManager: HEADSET profile state: BA_DISCONNECTED D/VOXSDK (13130): VoxBluetoothManager: Bluetooth proxy for headset profile has started D/VOXSDK (13130): VoxBluetoothManager: start done: BT state=HEADSET_UNAVAILABLE I/VOXSDK (13130): Client [CONNECTED] getClientState: connectWasCalled: false, loginWasCalled: false I/flutter (13130): AuthService: client state is changed: VIClientState.Connected I/VOXSDK (13130): Client [CONNECTED] login: user = 200@vn3.henriquetroiano.n2.voximplant.com I/flutter (13130): AuthService: client state is changed: VIClientState.LoggingIn I/VOXSDK (13130): GWConnection[CONNECTED]: SEND: login 200@vn3.henriquetroiano.n2.voximplant.com, seq: 1 I/VOXSDK (13130): GWConnection[CONNECTED]: onMessage: loginSuccessful, seq: 2 I/VOXSDK (13130): MessengerManager: onMessage: client is logged in I/VOXSDK (13130): Invoke onLoginSuccessful I/VOXFLUTTER(13130): VoximplantPlugin: onLoginSuccessful I/VOXSDK (13130): Client [LOGGED_IN] getClientState: connectWasCalled: false, loginWasCalled: false I/flutter (13130): AuthService: client state is changed: VIClientState.LoggedIn I/flutter (13130): LoginScreen: login with password: displayName: 200 I/VOXSDK (13130): GWConnection[CONNECTED]: onMessage: {"payload" : {"name" : "onICEConfig" , "params" : ["24BFC349A20E0F47.1663964124.5797455",[{"urls" : ["stun:turn.voximplant.com:3478"]},{"urls" : ["stun:turn.voximplant.com:443"]},{"credential" : "5LIeXVC1eRvNzDz8wr9SgM/q/bI=" , "ttl" : 86400 , "urls" : ["turn:turn.voximplant.com:3478?transport=udp","turn:turn.voximplant.com:3478?transport=tcp"] , "username" : "1664050524:eyJhY2MiIDogNDUxNzYzOSAsICJiLmIiIDogIjE3My4wLjE0Ni4xNjY6ODAwMSIgLCAiYi5tIiA6ICI2OS4xNjcuMTc4LjkyOjgwMDEiICwgImRiLmIiIDogIjE3My4wLjE0Ni4xNjY6MzAwNCIgLCAiZGIubSIgOiAiNjkuMTY3LjE3OC45MjozMDA0IiAsICJkaWQiIDogMTA1MDE4OTIgLCAicmVzb3VyY2UiIDogODIgLCAic2Vzc2lvbi1pZCIgOiAiRThEMERENERDQ0QyQkI4NS4xNjYzOTY0MTIzLjE4MTA3OF8xMjkuMjI3LjEyMS4xOTQiICwgInNlc3Npb25kYi1pZCIgOiAiNTAxNTU2NTUzIiAsICJ1aWQiIDogNTMxOTEzOX0="},{"credential" : "5LIeXVC1eRvNzDz8wr9SgM/q/bI=" , "ttl" : 86400 , "urls" : ["turn:turn.voximplant.com:443?transport=udp","turn:turn.voximplant.com:443?transport=tcp"] , "username" : "1664050524:eyJhY2MiIDogNDUxNzYzOSAsICJiLmIiIDogIjE3My4wLjE0Ni4xNjY6ODAwMSIgLCAiYi5tIiA6ICI2OS4xNjcuMTc4LjkyOjgwMDEiICwgImRiLmIiIDogIjE3My4wLjE0Ni4xNjY6MzAwNCIgLCAiZGIubSIgOiAiNjkuMTY3LjE3OC45MjozMDA0IiAsICJkaWQiIDogMTA1MDE4OTIgLCAicmVzb3VyY2UiIDogODIgLCAic2Vzc2lvbi1pZCIgOiAiRThEMERENERDQ0QyQkI4NS4xNjYzOTY0MTIzLjE4MTA3OF8xMjkuMjI3LjEyMS4xOTQiICwgInNlc3Npb25kYi1pZCIgOiAiNTAxNTU2NTUzIiAsICJ1aWQiIDogNTMxOTEzOX0="}]]} , "seq" : 3 , "type" : "msg"} I/VOXSDK (13130): GWConnection[CONNECTED]: onMessage: {"payload" : {"name" : "handleIncomingConnection" , "params" : ["24BFC349A20E0F47.1663964124.5797455","sip:202@vn3.henriquetroiano.voximplant.com","202",{"VI-Call-ID" : "knegA_vCS7uLMgjJi6ipmUe4nRtmz0C7jflvvjWlnbc" , "VI-Session-ID" : "E8D0DD4DCCD2BB85.1663964123.181078_129.227.121.194"},"v=0\r\no=VIMS 234 1 IN IP4 129.227.121.194\r\ns=VIMS\r\nc=IN IP4 129.227.121.194\r\nb=TIAS:13888000\r\nt=0 0\r\na=fingerprint:sha-256 F5:09:AD:E2:26:8E:9B:E0:C5:D9:1E:9C:88:AE:44:47:A6:1F:8A:B2:94:6E:22:8F:48:EC:D7:51:0E:BB:67:06\r\na=msid-semantic:WMS *\r\na=group:BUNDLE vi_0\r\na=ice-ufrag:099D2B89\r\na=ice-pwd:A01F18CA7E3318DC35B4E0AE94BB\r\nm=audio 8044 UDP/TLS/RTP/SAVPF 114 0 8 9 100 101\r\nb=TIAS:64000\r\nb=AS:64\r\na=mid:vi_0\r\na=rtpmap:114 opus/48000/2\r\na=fmtp:114 minptime=10; useinbandfec=1; stereo=0; usedtx=0\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:8 PCMA/8000\r\na=rtpmap:9 G722/8000\r\na=rtpmap:100 ilbc/8000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\na=sendrecv\r\na=rtcp-mux\r\na=setup:actpass\r\na=candidate:1 1 UDP 100 129.227.121.194 8044 typ host generation 0\r\na=end-of-candidates\r\na=msid:- 84fbca9b-6a15-4e35-af71-514bf5f58667\r\na=ssrc:453169676 msid:- 84fbca9b-6a15-4e35-af71-514bf5f58667\r\na=ssrc:453169676 cname:ETLe9+ul/mrj9noj\r\na=ssrc:453169676 mslabel:-\r\na=ssrc:453169676 label:84fbca9b-6a15-4e35-af71-514bf5f58667\r\na=ptime:20\r\n","{\"conferenceCall\" : false , \"endpoints\" : {\"\" : {\"mids\" : {\"vi_0\" : \"audio\"} , \"place\" : 0 , \"tracks\" : {\"84fbca9b-6a15-4e35-af71-514bf5f58667\" : \"audio\"} , \"type\" : \"call\"}}}"]} , "seq" : 4 , "type" : "msg"} I/VOXSDK (13130): CallManager: incomingCall: incoming call from server I/VOXSDK (13130): GWConnection[CONNECTED]: onMessage: {"payload" : {"name" : "handleSIPInfo" , "params" : ["24BFC349A20E0F47.1663964124.5797455","voximplant","sdpfrag","[[0,\"a=candidate:r1 1 UDP 99 129.227.121.195 24482 typ srflx raddr 129.227.121.194 rport 8044\"]]",{}]} , "seq" : 5 , "type" : "msg"} D/VOXSDK (13130): PCVideoParameters: Preferred video codec: VP8 I/VOXSDK (13130): EndpointManager [24BFC349A20E0F47.1663964124.5797455] createEndpoint: Endpoint[24BFC349A20E0F47.1663964124.5797455] I/VOXSDK (13130): PCStream iceServers = [[stun:turn.voximplant.com:3478] [:] [TLS_CERT_POLICY_SECURE] [] [null] [null], [stun:turn.voximplant.com:443] [:] [TLS_CERT_POLICY_SECURE] [] [null] [null]] I/VOXSDK (13130): PCStream creating a peer connection D/VOXSDK (13130): PCStream createRTCConfiguration I/VOXSDK (13130): PCStream peer connection is created: org.webrtc.PeerConnection@75bc7a9 V/VOXSDK (13130): PCStream [24BFC349A20E0F47.1663964124.5797455] setAndroidContext I/VOXSDK (13130): PCStream [24BFC349A20E0F47.1663964124.5797455] initPeerConnection D/VOXSDK (13130): PCVideoParameters: Preferred video codec: VP8 D/VOXSDK (13130): Call [24BFC349A20E0F47.1663964124.5797455, NOT_STARTED]created: video receive: false, video send: false ,video support enabled = true) I/VOXSDK (13130): EndpointManager [24BFC349A20E0F47.1663964124.5797455] findEndpointById: 24BFC349A20E0F47.1663964124.5797455 found I/VOXSDK (13130): Endpoint [24BFC349A20E0F47.1663964124.5797455] setUserInfo: mDisplayName: 202, sip uri: sip:202@vn3.henriquetroiano.voximplant.com I/VOXSDK (13130): Invoke onIncomingCall I/VOXSDK (13130): Call [24BFC349A20E0F47.1663964124.5797455, NOT_STARTED]candidateArray: [vi_0:0:candidate:r1 1 UDP 99 129.227.121.195 24482 typ srflx raddr 129.227.121.194 rport 8044::UNKNOWN] E/VOXSDK (13130): sdp_offer_answer.cc(line 2307): AddIceCandidate: ICE candidates can't be added without any remote session description. I/VOXSDK (13130): PCStream [24BFC349A20E0F47.1663964124.5797455] addRemoteIceCandidate: add to queued candidates I/VOXSDK (13130): Call [24BFC349A20E0F47.1663964124.5797455, NOT_STARTED]addCallListener:com.voximplant.flutter_voximplant.CallModule@98ea4cf I/VOXSDK (13130): Endpoint [24BFC349A20E0F47.1663964124.5797455] setEndpointListener: com.voximplant.flutter_voximplant.CallModule@98ea4cf I/VOXSDK (13130): Invoke onEndpointAdded I/VOXSDK (13130): Endpoint [24BFC349A20E0F47.1663964124.5797455] setEndpointListener: com.voximplant.flutter_voximplant.CallModule@98ea4cf I/VOXSDK (13130): GWConnection[CONNECTED]: SEND: {"type":"ack","seq":5} I/VOXSDK (13130): GWConnection[CONNECTED]: onMessage: {"seq" : 1 , "type" : "ack"} I/VOXSDK (13130): GWConnection[CONNECTED]: handleAckMessage: removed message with seq: 1 I/VOXSDK (13130): GWConnection[CONNECTED]: handleAckMessage: all confirmed messages are removed from queue I/VOXSDK (13130): GWConnection[CONNECTED]: SEND: {"type":"msg","payload":{"name":"__ping","params":[]},"seq":2} I/VOXSDK (13130): GWConnection[CONNECTED]: onMessage: {"payload" : {"name" : "__pong" , "params" : []} , "seq" : 6 , "type" : "msg"} I/VOXSDK (13130): GWConnection[CONNECTED]: SEND: {"type":"ack","seq":6} I/VOXSDK (13130): GWConnection[CONNECTED]: onMessage: {"seq" : 2 , "type" : "ack"} I/VOXSDK (13130): GWConnection[CONNECTED]: handleAckMessage: removed message with seq: 2 I/VOXSDK (13130): GWConnection[CONNECTED]: handleAckMessage: all confirmed messages are removed from queue ```

Full Stack Trace

```ruby [full_stack_trace.txt](https://github.com/voximplant/flutter_voximplant/files/9636915/full_stack_trace.txt) ```

henriquetroiano commented 1 year ago

The code I used after login to prevent that while fix not come:

Trick Sample

```ruby VIAuthResult authResult = await _client.login(username, password); await _saveAuthDetails(username, authResult.loginTokens); _displayName = authResult.displayName; Future.delayed(const Duration(seconds: 1)).then((_) async { try { final CallService _callService = CallService(); VICall call = await _callService.makeAudioCall('001'); VIAudioDeviceManager _audioDeviceManager; _audioDeviceManager = Voximplant().audioDeviceManager; _audioDeviceManager.onAudioDeviceChanged = (VIAudioDeviceManager v1, VIAudioDevice v2) => {}; call.onCallDisconnected = (VICall call, Map data, bool b) { CallService().notifyCallIsEnded(call.callId); }; call.onCallFailed = (VICall call, int v, String s, Map m) { CallService().notifyCallIsEnded(call.callId); }; call.onCallConnected = (VICall c, Map m) { Future.delayed(const Duration(seconds: 2)).then((_) { c.hangup(); }); }; call.onCallRinging = (VICall c, Map m) { Future.delayed(const Duration(seconds: 2)).then((_) { c.hangup(); }); }; } catch (e) { print('calltest failed $e'); } }); ```

henriquetroiano commented 1 year ago

And a call log, without using the trick to prevent this behavior: In this case, the target phone does not ring. I can see the log advising me that a call was received, but fails with the "ICE candidate" error like the first log I send here (the simple or full flutter log)

Call Logs Session ID 501678685 link: https://storage-gw-br-01.voximplant.com/voxdata-br-logs-secure/2022/09/24/YjJiNzgwMmIzYTJjMmY2YzBhYmI4NmMzOWI1ZDE5ZDQvaHR0cDovL3d3dy1ici0xMS0xOTUudm94aW1wbGFudC5jb206ODA4MC9sb2dzLzIwMjIvMDkvMjQvMTIzNTM2XzBDOTk4M0Y4Q0ZDNEFDQUIuMTY2NDAyMjkzNi4yNDYyNjVfMTI5LjIyNy4xMjEuMTk1LmxvZw--?sessionid=501678685&session_id=2b8820b246ee44338319aa897862eac2&account_id=5319139

Call Logs Session ID: 501678685

```ruby 2022-09-24 12:35:36 Loading scenario direct 2022-09-24 12:35:36 Sent event to JS onPhoneEvent with params [{accessSecureURL = https://www-br-11-195.voximplant.com:12093/request/0C9983F8CFC4ACAB.1664022936.246265_129.227.121.195/D50D845B47D23EF3 ; accessURL = http://129.227.121.195:12092/request/0C9983F8CFC4ACAB.1664022936.246265_129.227.121.195/D50D845B47D23EF3 ; accountId = 5319139 ; applicationId = 10501892 ; config = {acceptReInviteByDefault = true ; } ; initiatorCountry = BR ; logURL = https://storage-gw-br-01.voximplant.com/voxdata-br-logs-secure/2022/09/24/YjJiNzgwMmIzYTJjMmY2YzBhYmI4NmMzOWI1ZDE5ZDQvaHR0cDovL3d3dy1ici0xMS0xOTUudm94aW1wbGFudC5jb206ODA4MC9sb2dzLzIwMjIvMDkvMjQvMTIzNTM2XzBDOTk4M0Y4Q0ZDNEFDQUIuMTY2NDAyMjkzNi4yNDYyNjVfMTI5LjIyNy4xMjEuMTk1LmxvZw--?sessionid=501678685 ; name = Application.Started ; nluAddresses = [https://ai-eu-1.voximplant.com/ ; ] ; sessionId = 501678685 ; userId = 4269076 ; } ; ] 2022-09-24 12:35:36 Sent event to JS onPhoneEvent with params [{callerid = 202 ; destination = 200 ; displayName = 202 ; fromURI = sip:202@vn3.henriquetroiano.voximplant.com ; headers = {VI-Authenticated-Caller = 202 ; VI-Browser = voxmobile ; VI-Client-Device = WebRTC ; VI-Client-IP = 187.22.131.166 ; VI-Client-Type = user ; VI-ClientVersion = android-2.32.4_flutter-3.5.1 ; } ; id = 11B503472F22EC0D.1664022936.246264 ; name = Application.CallAlerting ; requestIP = 129.227.121.194:52281 ; scheme = {"" : {"audio" : [{"codecs" : [114,9,100,0,8,101] , "direction" : "sendrecv" , "flows" : [{"cname" : "Sl5OrwPlqaM+HQCt" , "uniq" : 0}] , "msid" : "- 19b80afc-c51f-496a-9117-05d4933e98f3" , "type" : "audio" , "uniq" : 0}] , "place" : 0 , "type" : "call" , "video" : [] , "vox-params" : ["platform android","clver android-2.32.4_flutter-3.5.1"]}} ; toURI = sip:200@vn3.henriquetroiano.voximplant.com ; } ; ] 2022-09-24 12:35:36 Executing JS command: EnableMediaStatistics with params [{id = 11B503472F22EC0D.1664022936.246264 ; } ; ] 2022-09-24 12:35:36 Enable media statistics for 11B503472F22EC0D.1664022936.246264 : https://storage-gw-br-01.voximplant.com/voxdata-br-logs-secure/2022/09/24/OWNkMzI1N2E5MmIyMTUxNzFmMzM4ZDE4MDEyZjk1MjgvaHR0cDovL3d3dy1ici0xMS0xOTUudm94aW1wbGFudC5jb206ODA4MC9sb2dzLzIwMjIvMDkvMjQvMEM5OTgzRjhDRkM0QUNBQi4xNjY0MDIyOTM2LjI0NjI2NV8xMjkuMjI3LjEyMS4xOTVfMTFCNTAzNDcyRjIyRUMwRC4xNjY0MDIyOTM2LjI0NjI2NC5jc3Y-?sessionid=501678685 2022-09-24 12:35:36 Executing JS command: CallUser with params [{id = Z8p5bGysSRWJG7tVSSYQltV8Z22JjkTxu6kvvFpZPI4 ; } ; {audioLevelExtension = NULL ; callerid = 202 ; displayName = 202 ; headers = NULL ; maxVideoBitrate = NULL ; mixStreams = NULL ; scheme = {"" : {"audio" : [{"codecs" : [114,9,100,0,8,101] , "direction" : "sendrecv" , "flows" : [{"cname" : "Sl5OrwPlqaM+HQCt" , "uniq" : 0}] , "msid" : "- 19b80afc-c51f-496a-9117-05d4933e98f3" , "type" : "audio" , "uniq" : 0}] , "place" : 0 , "type" : "call" , "video" : [] , "vox-params" : ["platform android","clver android-2.32.4_flutter-3.5.1"]}} ; username = 200 ; video = NULL ; videoOrientationExtension = NULL ; } ; ] 2022-09-24 12:35:36 Executing JS command: EnableMediaStatistics with params [{id = Z8p5bGysSRWJG7tVSSYQltV8Z22JjkTxu6kvvFpZPI4 ; } ; ] 2022-09-24 12:35:36 Executing JS command: SendMediaBetween with params [{id1 = 11B503472F22EC0D.1664022936.246264 ; id2 = Z8p5bGysSRWJG7tVSSYQltV8Z22JjkTxu6kvvFpZPI4 ; } ; ] 2022-09-24 12:35:37 Sent event to JS onPhoneEvent with params [{headers = {} ; id = Z8p5bGysSRWJG7tVSSYQltV8Z22JjkTxu6kvvFpZPI4 ; name = Call.Ringing ; } ; ] 2022-09-24 12:35:37 Executing JS command: Ring with params [{headers = NULL ; id = 11B503472F22EC0D.1664022936.246264 ; } ; ] 2022-09-24 12:35:37 Sent event to JS onPhoneEvent with params [{headers = {} ; id = Z8p5bGysSRWJG7tVSSYQltV8Z22JjkTxu6kvvFpZPI4 ; name = Call.Ringing ; } ; ] 2022-09-24 12:35:37 Executing JS command: Ring with params [{headers = NULL ; id = 11B503472F22EC0D.1664022936.246264 ; } ; ] 2022-09-24 12:36:36 Terminating call 11B503472F22EC0D.1664022936.246264 (timeout reached) 2022-09-24 12:36:36 Sent event to JS onPhoneEvent with params [{cost = 0 ; direction = ; duration = 0 ; headers = {Reason = ; } ; id = 11B503472F22EC0D.1664022936.246264 ; internalCode = 408 ; name = Call.Disconnected ; reason = Request Timeout ; } ; ] 2022-09-24 12:36:36 Executing JS command: terminating with params [] 2022-09-24 12:36:36 Terminating (onClose) 2022-09-24 12:36:36 Executing JS command: close with params {CpuMillis = 64 ; } 2022-09-24 12:36:36 Normal termination 2022-09-24 12:36:36 Session terminated ```

henriquetroiano commented 1 year ago

The Scenario code:

Scenario Code

```ruby VoxEngine.addEventListener(AppEvents.CallAlerting, (e) => { const newCall = VoxEngine.callUser({ username: e.destination, callerid: e.callerid, displayName: e.displayName, // video: true, scheme: e.scheme }); VoxEngine.easyProcess(e.call, newCall, () => {}); }); ```

YuliaGrigorieva commented 1 year ago

Hello @henriquetroiano !

Thank you for reaching out to us and providing the logs.

According to the client logs and call session logs, you receive an incoming call, but do not answer it. VoxEngine ends the call after a 60 sec timeout.

The error message "AddIceCandidate: ICE candidates can't be added without any remote session description" is expected in this case as the SDK can receive remote ice candidates just after it receives an incoming call. And the SDK handles this case queueing the candidates until the call is answered and the remote SDP is set.

So for now, I do not see the issues on the SDK side, however there might be some issues with 3rd party package itegration.

Could you please let me know:

  1. if the issue is reproducible with the demo app
  2. do you use any packages with ConnectionService functionality? In the full logs I see mentions of com.hiennv.flutter_callkit_incoming package.

Best regards, Yulia Grigorieva

henriquetroiano commented 1 year ago

Hi @YuliaGrigorieva !

With the demo app, without any changes, when I call from softphone from voximplant control panel, the first call and all the others ring on the app, but, when I accept these calls, the call is not accepted and the softphone keeps ringing until 60s reached and them both end the call. This is a strange bug.

henriquetroiano commented 1 year ago

You can try it out now with the fresh app from example and softphone from voximplant control panel

henriquetroiano commented 1 year ago

image

This issue is reproducible with the fresh example app calling to another fresh example app

henriquetroiano commented 1 year ago

And i'm being charged !

henriquetroiano commented 1 year ago

I've noticed that should be a scenario bug.

I'll give the working scenario and the older scenario that causes the bug:

Working Scenario

```ruby require(Modules.PushService); VoxEngine.addEventListener(AppEvents.CallAlerting, (e) => { const newCall = VoxEngine.callUser({ username: e.destination, callerid: e.callerid, displayName: e.displayName, video: true, scheme: e.scheme }); VoxEngine.easyProcess(e.call, newCall, () => {}); }); ```

NOT Working Scenario

```ruby require(Modules.PushService); VoxEngine.addEventListener(AppEvents.CallAlerting, (e) => { const newCall = VoxEngine.callUser({ username: e.destination, callerid: e.callerid, displayName: e.displayName, video: true, scheme: e.scheme }); VoxEngine.easyProcess(newCall, e.call, () => { }); // let newCall = null; // if (e.destination.includes('sip')) { // const sipData = JSON.parse(VoxEngine.customData()); // var PBXoptions = { // server: { // host: 'hoomweb.rvrtelecom.com.br:5060', // port: 5060 // }, // sip: { // login: sipData.authUser, // password: sipOpts.password // } // }; // // incoming call event properties // var incomingCall = event.call; // Call: Incoming call that triggered the event // var callerId = event.callerid; // String: CallerID for current call // var customData = event.customData; // Optional String: Custom data that was passed from client with the call // var destination = event.destination; // String: Dialed number // var displayName = event.displayName; // String: Displayable name of the caller // var fromURI = event.fromURI; // String: CallerID with domain or SIP URI for incoming SIP call // var headers = event.headers; // Object: Custom SIP headers received with the call (ones starting with "X-") // var name = event.name; // String: The name of the event - "Application.CallAlerting" // var toURI = event.toURI; // String: Dialed SIP URI // // VoxEngine.callSIP(to, callerid, displayName, password, authUser, extraHeaders, video, outProxy) // // to - String: SIP URI to make call to // // callerid - String (optional): CallerID that will be displayed to called user. If not specified, "anonymous@appname.accname.voximplant.com" string will be sent, where "appname" is the Voximplant application name and "accname" is the Voximplant account name. // // displayName - String (optional): Name of calling user, that will be displayed to called user // // password - String (optional): Password for SIP Authentication // // authUser - String (optional): Username for SIP Authentication. If not specified, callerid is used as username for authentication // // extraHeaders - Object (optional): Optional custom parameters (SIP headers) that should be passed with call (INVITE) message. Parameter names must start with "X-" to be processed by application // // video - Boolean (optional): Specifies if call should have video support. Please note that price for audio-only and video calls is different! // // outProxy - String (optional) - Specifies outbound proxy // var sipOpts = { // to: 'sip:' + PBXoptions.sip.login + '@' + PBXoptions.server.host, // callerid: sipData.callerid, // displayName: sipData.displayName, // password: PBXoptions.sip.password, // authUser: PBXoptions.sip.login, // extraHeaders: {}, // video: false, // outProxy: null // }; // var sipCall = VoxEngine.callSIP(sipOpts.to, sipOpts.callerid, sipOpts.displayName, sipOpts.password, sipOpts.authUser, sipOpts.extraHeaders, sipOpts.video, sipOpts.outProxy); // VoxEngine.sendMediaBetween(incomingCall, sipCall); // Start sending media from mediaUnit1 to mediaUnit2 and vice versa // VoxEngine.easyProcess(incomingCall, sipCall); // Adds all default event listeners to pass signaling information between two calls // /* comment this section if it is not required to release voximplant virtual telephone number after redirection */ // var forwardOptions = { // onEstablishedCallback: function (incoming, outgoing) { // Logger.write(' >>> forwardCallToSIP, onEstablishedCallback()'); // var key; // if (typeof incoming === 'object') { for (key in incoming) { Logger.write(' > incoming' + '[' + key + ']: ' + incoming[key]); } } // else { Logger.write(' >>>>>> incoming call: ' + incoming); } // if (typeof outgoing === 'object') { for (key in outgoing) { Logger.write(' > outgoing' + '[' + key + ']: ' + outgoing[key]); } } // else { Logger.write(' >>>>>> outgoing call: ' + outgoing); } // }, // video: false // }; // VoxEngine.forwardCallToSIP(forwardOptions.onEstablishedCallback, forwardOptions.video); // forward call to Sip // /* comment this section if it is not required to release voximplant virtual telephone number after redirection */ // } else { // newCall = VoxEngine.callUser({ // username: e.destination, // callerid: e.callerid, // displayName: e.displayName, // // video: true, // scheme: e.scheme // }); // VoxEngine.easyProcess(newCall, e.call, () => { }); // } }); ```

henriquetroiano commented 1 year ago

Does the comment section causes a bug in scenario ?

YuliaGrigorieva commented 1 year ago

It seems the issue is caused by easyProcess params order.

working scenario: VoxEngine.easyProcess(e.call, newCall, () => {}); not working scenario: VoxEngine.easyProcess(newCall, e.call, () => { });

However, the order of e.call and newCall matters as per the documentation:

 * @param {Call} call1 Incoming alerting call
 * @param {Call} call2 Newly created outgoing call

Best regards, Yulia Grigorieva

henriquetroiano commented 1 year ago

Oh sure, thanks! My mistake. I'll close this issue.