From 66a53786e7e41814ce0afed47ece6b433ac54f81 Mon Sep 17 00:00:00 2001 From: td Date: Mon, 10 Jul 2023 14:19:16 +0530 Subject: [PATCH] fix: do not proceed call if getUserMedia fails fix: added a few missing awaits fix: add a workaround for not having state updates for staleCallChecker till sync chore: fix some logging --- lib/src/voip/call.dart | 91 +++++++++++++-------------- lib/src/voip/conn_tester.dart | 5 +- lib/src/voip/group_call.dart | 12 ++-- lib/src/voip/utils.dart | 8 +-- lib/src/voip/voip.dart | 14 ++--- lib/src/voip/voip_room_extension.dart | 31 ++++++--- 6 files changed, 88 insertions(+), 73 deletions(-) diff --git a/lib/src/voip/call.dart b/lib/src/voip/call.dart index 22d8c903d..69fb38971 100644 --- a/lib/src/voip/call.dart +++ b/lib/src/voip/call.dart @@ -358,7 +358,7 @@ class CallSession { final CachedStreamController onCallReplaced = CachedStreamController(); - final CachedStreamController onCallHangup = + final CachedStreamController onCallHangupNotifierForGroupCalls = CachedStreamController(); final CachedStreamController onCallStateChanged = @@ -435,6 +435,7 @@ class CallSession { Timer? inviteTimer; Timer? ringingTimer; + // outgoing call Future initOutboundCall(CallType type) async { await _preparePeerConnection(); setCallState(CallState.kCreateOffer); @@ -444,6 +445,7 @@ class CallSession { } } + // incoming call Future initWithInvite(CallType type, RTCSessionDescription offer, SDPStreamMetadata? metadata, int lifetime, bool isGroupCall) async { if (!isGroupCall) { @@ -491,6 +493,12 @@ class CallSession { final stream = await _getUserMedia(type); if (stream != null) { await addLocalStream(stream, SDPStreamMetadataPurpose.Usermedia); + } else { + // we don't have a localstream, call probably crashed + // for sanity + if (state == CallState.kEnded) { + return; + } } } @@ -597,10 +605,6 @@ class CallSession { // Now we wait for the negotiationneeded event } - void initWithHangup() { - setCallState(CallState.kEnded); - } - Future onAnswerReceived( RTCSessionDescription answer, SDPStreamMetadata? metadata) async { if (metadata != null) { @@ -658,9 +662,9 @@ class CallSession { type: answer.type!); await pc!.setLocalDescription(answer); } - } catch (e) { - _getLocalOfferFailed(e); - Logs().e('[VOIP] onNegotiateReceived => ${e.toString()}'); + } catch (e, s) { + Logs().e('[VOIP] onNegotiateReceived => ', e, s); + await _getLocalOfferFailed(e); return; } @@ -740,8 +744,8 @@ class CallSession { if (pc != null && inviteOrAnswerSent && remotePartyId != null) { try { await pc!.addCandidate(candidate); - } catch (e) { - Logs().e('[VOIP] onCandidatesReceived => ${e.toString()}'); + } catch (e, s) { + Logs().e('[VOIP] onCandidatesReceived => ', e, s); } } else { remoteCandidates.add(candidate); @@ -810,8 +814,8 @@ class CallSession { await _removeStream(localScreenSharingStream!.stream!); fireCallEvent(CallEvent.kFeedsChanged); return false; - } catch (e) { - Logs().e('[VOIP] stopping screen sharing track failed', e); + } catch (e, s) { + Logs().e('[VOIP] stopping screen sharing track failed', e, s); return false; } } @@ -1130,12 +1134,11 @@ class CallSession { /// Reject a call /// This used to be done by calling hangup, but is a separate method and protocol /// event as of MSC2746. - /// Future reject({String? reason, bool shouldEmit = true}) async { - // stop play ringtone - await voip.delegate.stopRingtone(); if (state != CallState.kRinging && state != CallState.kFledgling) { - Logs().e('[VOIP] Call must be in \'ringing|fledgling\' state to reject!'); + Logs().e( + '[VOIP] Call must be in \'ringing|fledgling\' state to reject! (current state was: ${state.toString()}) Calling hangup instead'); + await hangup(reason, shouldEmit); return; } Logs().d('[VOIP] Rejecting call: $callId'); @@ -1146,12 +1149,9 @@ class CallSession { } } - Future hangup([String? reason, bool suppressEvent = false]) async { - // stop play ringtone - await voip.delegate.stopRingtone(); - + Future hangup([String? reason, bool shouldEmit = true]) async { await terminate( - CallParty.kLocal, reason ?? CallErrorCode.UserHangup, !suppressEvent); + CallParty.kLocal, reason ?? CallErrorCode.UserHangup, shouldEmit); try { final res = @@ -1174,11 +1174,11 @@ class CallSession { } Future terminate( - CallParty party, String reason, bool shouldEmit) async { - if (state == CallState.kEnded) { - return; - } - + CallParty party, + String reason, + bool shouldEmit, + ) async { + Logs().d('[VOIP] terminating call'); inviteTimer?.cancel(); inviteTimer = null; @@ -1195,9 +1195,9 @@ class CallSession { hangupParty = party; hangupReason = reason; - if (shouldEmit) { - setCallState(CallState.kEnded); - } + // don't see any reason to wrap this with shouldEmit atm, + // looks like a local state change only + setCallState(CallState.kEnded); if (!isGroupCall) { if (callId != voip.currentCID) return; @@ -1209,7 +1209,7 @@ class CallSession { await cleanUp(); if (shouldEmit) { - onCallHangup.add(this); + onCallHangupNotifierForGroupCalls.add(this); await voip.delegate.handleCallEnded(this); fireCallEvent(CallEvent.kHangup); if ((party == CallParty.kRemote && missedCall)) { @@ -1273,7 +1273,6 @@ class CallSession { // just incase we ended the call but already sent the invite if (state == CallState.kEnded) { await hangup(CallErrorCode.Replaced, false); - setCallState(CallState.kEnded); return; } inviteOrAnswerSent = true; @@ -1313,7 +1312,7 @@ class CallSession { final offer = await pc!.createOffer({}); await _gotLocalOffer(offer); } catch (e) { - _getLocalOfferFailed(e); + await _getLocalOfferFailed(e); return; } finally { makingOffer = false; @@ -1377,9 +1376,9 @@ class CallSession { } } - void onAnsweredElsewhere() { + Future onAnsweredElsewhere() async { Logs().d('Call ID $callId answered elsewhere'); - terminate(CallParty.kRemote, CallErrorCode.AnsweredElsewhere, true); + await terminate(CallParty.kRemote, CallErrorCode.AnsweredElsewhere, true); } Future cleanUp() async { @@ -1388,8 +1387,8 @@ class CallSession { await stream.dispose(); } streams.clear(); - } catch (e) { - Logs().e('[VOIP] cleaning up streams failed', e); + } catch (e, s) { + Logs().e('[VOIP] cleaning up streams failed', e, s); } try { @@ -1397,8 +1396,8 @@ class CallSession { await pc!.close(); await pc!.dispose(); } - } catch (e) { - Logs().e('[VOIP] removing pc failed', e); + } catch (e, s) { + Logs().e('[VOIP] removing pc failed', e, s); } } @@ -1468,7 +1467,7 @@ class CallSession { try { return await voip.delegate.mediaDevices.getUserMedia(mediaConstraints); } catch (e) { - _getUserMediaFailed(e); + await _getUserMediaFailed(e); } return null; } @@ -1481,7 +1480,7 @@ class CallSession { try { return await voip.delegate.mediaDevices.getDisplayMedia(mediaConstraints); } catch (e) { - _getUserMediaFailed(e); + await _getUserMediaFailed(e); } return null; } @@ -1614,15 +1613,15 @@ class CallSession { } } - void _getLocalOfferFailed(dynamic err) { + Future _getLocalOfferFailed(dynamic err) async { Logs().e('Failed to get local offer ${err.toString()}'); fireCallEvent(CallEvent.kError); lastError = CallError( CallErrorCode.LocalOfferFailed, 'Failed to get local offer!', err); - terminate(CallParty.kLocal, CallErrorCode.LocalOfferFailed, false); + await terminate(CallParty.kLocal, CallErrorCode.LocalOfferFailed, false); } - void _getUserMediaFailed(dynamic err) { + Future _getUserMediaFailed(dynamic err) async { if (state != CallState.kConnected) { Logs().w('Failed to get user media - ending call ${err.toString()}'); fireCallEvent(CallEvent.kError); @@ -1630,11 +1629,11 @@ class CallSession { CallErrorCode.NoUserMedia, 'Couldn\'t start capturing media! Is your microphone set up and does this app have permission?', err); - terminate(CallParty.kLocal, CallErrorCode.NoUserMedia, false); + await terminate(CallParty.kLocal, CallErrorCode.NoUserMedia, false); } } - void onSelectAnswerReceived(String? selectedPartyId) { + Future onSelectAnswerReceived(String? selectedPartyId) async { if (direction != CallDirection.kIncoming) { Logs().w('Got select_answer for an outbound call: ignoring'); return; @@ -1649,7 +1648,7 @@ class CallSession { Logs().w( 'Got select_answer for party ID $selectedPartyId: we are party ID $localPartyId.'); // The other party has picked somebody else's answer - terminate(CallParty.kRemote, CallErrorCode.AnsweredElsewhere, true); + await terminate(CallParty.kRemote, CallErrorCode.AnsweredElsewhere, true); } } diff --git a/lib/src/voip/conn_tester.dart b/lib/src/voip/conn_tester.dart index 62b1b23bf..2e00eb13d 100644 --- a/lib/src/voip/conn_tester.dart +++ b/lib/src/voip/conn_tester.dart @@ -64,8 +64,9 @@ class ConnectionTester { } return false; }); - } catch (e) { - Logs().e('[VOIP] ConnectionTester Error while testing TURN server: $e'); + } catch (e, s) { + Logs() + .e('[VOIP] ConnectionTester Error while testing TURN server: ', e, s); } dispose(); diff --git a/lib/src/voip/group_call.dart b/lib/src/voip/group_call.dart index 2f08eba88..272b16a99 100644 --- a/lib/src/voip/group_call.dart +++ b/lib/src/voip/group_call.dart @@ -340,8 +340,8 @@ class GroupCall { }; try { return await voip.delegate.mediaDevices.getDisplayMedia(mediaConstraints); - } catch (e) { - setState(GroupCallState.LocalCallFeedUninitialized); + } catch (e, s) { + Logs().e('[VOIP] _getDisplayMedia failed because,', e, s); } return Null as MediaStream; } @@ -627,10 +627,10 @@ class GroupCall { await sendMemberStateEvent(); return true; - } catch (error) { - Logs().e('Enabling screensharing error', error); + } catch (e, s) { + Logs().e('Enabling screensharing error', e, s); lastError = GroupCallError(GroupCallErrorCode.NoUserMedia, - 'Failed to get screen-sharing stream: ', error); + 'Failed to get screen-sharing stream: ', e); onGroupCallEvent.add(GroupCallEvent.Error); return false; } @@ -994,7 +994,7 @@ class GroupCall { await onStreamsChanged(call); }); - call.onCallHangup.stream.listen((event) async { + call.onCallHangupNotifierForGroupCalls.stream.listen((event) async { await onCallHangup(call); }); diff --git a/lib/src/voip/utils.dart b/lib/src/voip/utils.dart index 8e35e3af1..037da1ecb 100644 --- a/lib/src/voip/utils.dart +++ b/lib/src/voip/utils.dart @@ -10,14 +10,14 @@ Future stopMediaStream(MediaStream? stream) async { for (final track in stream.getTracks()) { try { await track.stop(); - } catch (e) { - Logs().e('[VOIP] stopping track ${track.id} failed', e); + } catch (e, s) { + Logs().e('[VOIP] stopping track ${track.id} failed', e, s); } } try { await stream.dispose(); - } catch (e) { - Logs().e('[VOIP] disposing stream ${stream.id} failed', e); + } catch (e, s) { + Logs().e('[VOIP] disposing stream ${stream.id} failed', e, s); } } } diff --git a/lib/src/voip/voip.dart b/lib/src/voip/voip.dart index 9331043e4..2d6d93463 100644 --- a/lib/src/voip/voip.dart +++ b/lib/src/voip/voip.dart @@ -284,7 +284,7 @@ class VoIP { await delegate.stopRingtone(); } if (call.state == CallState.kRinging) { - call.onAnsweredElsewhere(); + await call.onAnsweredElsewhere(); } return; } @@ -368,7 +368,7 @@ class VoIP { } await call.onRejectReceived(content['reason']); } else { - Logs().v('[VOIP] onCallHangup: Session [$callId] not found!'); + Logs().v('[VOIP] onCallReject: Session [$callId] not found!'); } } @@ -408,7 +408,7 @@ class VoIP { 'Ignoring call select answer for room $roomId claiming to be for call in room ${call.room.id}'); return; } - call.onSelectAnswerReceived(selectedPartyId); + await call.onSelectAnswerReceived(selectedPartyId); } } @@ -486,8 +486,8 @@ class VoIP { } await call.onNegotiateReceived(metadata, RTCSessionDescription(description['sdp'], description['type'])); - } catch (err) { - Logs().e('Failed to complete negotiation ${err.toString()}'); + } catch (e, s) { + Logs().e('Failed to complete negotiation', e, s); } } } @@ -498,8 +498,8 @@ class VoIP { if (session['media'].indexWhere((e) => e['type'] == 'video') != -1) { return CallType.kVideo; } - } catch (err) { - Logs().e('Failed to getCallType ${err.toString()}'); + } catch (e, s) { + Logs().e('Failed to getCallType', e, s); } return CallType.kVoice; diff --git a/lib/src/voip/voip_room_extension.dart b/lib/src/voip/voip_room_extension.dart index 1bc0a8def..707d84e07 100644 --- a/lib/src/voip/voip_room_extension.dart +++ b/lib/src/voip/voip_room_extension.dart @@ -48,7 +48,7 @@ extension GroupCallUtils on Room { if (staleGroupCallsTimer.tryGet(roomId) != null) { staleGroupCallsTimer[roomId]!.cancel(); staleGroupCallsTimer.remove(roomId); - Logs().d('stopped stale group calls checker for room $id'); + Logs().d('[VOIP] stopped stale group calls checker for room $id'); } else { Logs().d('[VOIP] no stale call checker for room found'); } @@ -70,7 +70,22 @@ extension GroupCallUtils on Room { device.expires_ts! < DateTime.now().millisecondsSinceEpoch); } } - return true; + + // Last 30 seconds to get yourself together. + // This saves us from accidentally killing calls which were just created and + // whose state event we haven't recieved yet in sync. + // (option 2 was local echo member state events, but reverting them if anything + // fails sounds pain) + + final expiredfr = groupCallMemberStateEvent.originServerTs + .add(staleCallCheckerDuration) + .millisecondsSinceEpoch < + DateTime.now().millisecondsSinceEpoch; + if (!expiredfr) { + Logs().d( + '[VOIP] Last 30 seconds for state event from ${groupCallMemberStateEvent.senderId}'); + } + return expiredfr; } /// checks for stale calls in a room and sends `m.terminated` if all the @@ -85,7 +100,7 @@ extension GroupCallUtils on Room { } Future singleShotStaleCallCheckerOnRoom() async { - Logs().d('checking for stale group calls in room $id'); + Logs().d('[VOIP] checking for stale group calls in room $id'); // make sure we have all the to-device messages we are supposed to have await client.oneShotSync(); final copyGroupCallIds = @@ -97,7 +112,7 @@ extension GroupCallUtils on Room { if (groupCallEvent.content.tryGet('m.intent') == 'm.room') return; if (!groupCallEvent.content.containsKey('m.terminated')) { - Logs().i('found non terminated group call with id $groupCallId'); + Logs().i('[VOIP] found non terminated group call with id $groupCallId'); // call is not empty but check for stale participants (gone offline) // with expire_ts bool callExpired = true; // assume call is expired @@ -118,7 +133,7 @@ extension GroupCallUtils on Room { if (callExpired) { Logs().i( - 'Group call with only expired timestamps detected, terminating'); + '[VOIP] Group call with only expired timestamps detected, terminating'); await sendGroupCallTerminateEvent(groupCallId); } } @@ -132,7 +147,7 @@ extension GroupCallUtils on Room { final existingStateEvent = getState(EventTypes.GroupCallPrefix, groupCallId); if (existingStateEvent == null) { - Logs().e('could not find group call with id $groupCallId'); + Logs().e('[VOIP] could not find group call with id $groupCallId'); return null; } @@ -144,8 +159,8 @@ extension GroupCallUtils on Room { Logs().i('[VOIP] Group call $groupCallId was killed uwu'); return req; - } catch (e) { - Logs().e('killing stale call $groupCallId failed. reason: $e'); + } catch (e, s) { + Logs().e('[VOIP] killing stale call $groupCallId failed', e, s); return null; } }