twilio / twilio-video.js

Twilio’s Programmable Video JavaScript SDK
https://www.twilio.com/docs/video/javascript
Other
571 stars 218 forks source link

Room State Turns into Reconnecting When the Other Participant Lost Internet Connection #1725

Open nuynait opened 2 years ago

nuynait commented 2 years ago

This only happens under room type peer-to-peer it works all right on room type group.

Reproduce

Steps to reproduce the issue:

  1. Connect to the video call on web using the first computer as person A.
  2. Connect to the video call on web using the second computer as person B.
  3. While person A and person B are talking, disconnected the internet for person B only.

Expected behavior:

Only person B lost the connection. The room state for person A should not be affected and remain connected.

Actual behavior:

The room state for person A changed to reconnecting for a while then eventually drop to disconnected.

Code

Code for room creation and access:

We create the room in nodeJS server and join the room in front-end React using the token provided from the server.

In nodeJS server, we created the room using:

const Twilio = require('twilio') // v3.66.1

...

const ROOM_TYPE = {
  'one-to-one': {
    type: 'peer-to-peer',
    accountSid: config.twilio.rooms.group?.account_sid ?? '',
    authToken: config.twilio.rooms.group?.auth_token ?? '',
    conversationSid: config.twilio.rooms.group?.conversation_sid ?? '',
    keySid: config.twilio.rooms.group?.video_sid ?? '',
    secret: config.twilio.rooms.group?.video_secret ?? '',
  },
  'one-to-many': {
    type: 'group',
    accountSid: config.twilio.rooms.group?.account_sid ?? '',
    authToken: config.twilio.rooms.group?.auth_token ?? '',
    conversationSid: config.twilio.rooms.group?.conversation_sid ?? '',
    keySid: config.twilio.rooms.group?.video_sid ?? '',
    secret: config.twilio.rooms.group?.video_secret ?? '',
  },
}

...

const createVideoTokens = async () => {
  const { user } = context
  const { authToken, accountSid, keySid, conversationSid, secret, type } =
    ROOM_TYPE[maxAttendees > 1 ? 'one-to-many' : 'one-to-one']

  const twilioClient = new Twilio(accountSid, authToken)

  const room = await twilioClient.video.rooms.create({
    type, // The disconection issue only appears in "peer-to-peer" type.
  })

  const conversationClient = twilioClient.conversations.services(conversationSid)

  try {
    await conversationClient.conversations(room.sid).fetch()
  } catch (e) {
    try {
      await conversationClient.conversations.create({ uniqueName: room.sid, 'timers.closed': 'P1D' })
    } catch (e) {
      // TODO: Inform application that the conversation is unavailable
    }
  }

  const videoGrant = new VideoGrant({
    room: room.sid,
    ttl: 7200,
  })

  const chatGrant = new ChatGrant({
    serviceSid: conversationSid,
  })

  return {
    // We return the token and some other information with our own objects to use later and send to participants via internal apis.
    ),
  }
}

Here is our connect function in the front-end React:

import Video from 'twilio-video' // v2.20.1

const connect = useCallback(
    async (isHost, token) => {
            // isHost: If the person connects as a host
            // token: Token we get from our nodeJS server. Created by `createVideoTokens` function.
      setIsConnecting(true)
      try {
        const options = {
          ...optionsRef.current,
          dominantSpeaker: isHost,
          bandwidthProfile: {
            ...optionsRef.current.bandwidthProfile,
            video: {
              ...optionsRef.current.bandwidthProfile.video,
              mode: 'grid',
              contentPreferencesMode: 'manual',
            },
          },
          tracks: localTracks,
        }
        const newRoom = await Video.connect(token, options)

        setRoom(newRoom) // we store the room into React state.

        newRoom.setMaxListeners(15)

        const disconnect = () => newRoom.disconnect()

        newRoom.once('disconnected', () => {
          setTimeout(() => setRoom(null))
          window.removeEventListener('beforeunload', disconnect)
          isMobile && window.removeEventListener('pagehide', disconnect)
        })
        window.twilioRoom = newRoom

        window.addEventListener('beforeunload', disconnect)
        isMobile && window.addEventListener('pagehide', disconnect)

        const [, dataTrack] = localTracks

        newRoom.localParticipant.on('trackPublished', ({ track }) => {
          track === dataTrack && dataTrackPublishedRef.current.resolve()
        })

        newRoom.localParticipant.on('trackPublicationFailed', (error, track) => {
          track === dataTrack && dataTrackPublishedRef.current.reject(error)
        })
      } catch (error) {
        console.log(error)
        onError(error)
      }

      setIsConnecting(false)
    },
    [localTracks, onError]
  )

Logs

Here is the log for person A that should not change the room state when person B gets disconnected.

Short version:

2022-02-28T20:14:55.103Z warn [PeerConnectionV2 #1: a2efc935-b93f-48a3-b5b3-087e968ef1e7] ICE Connection Monitor detected inactivity
log @ log.js:179
warn @ log.js:239
(anonymous) @ peerconnection.js:792
_onIceConnectionStateChanged @ iceconnectionmonitor.js:112
emit @ events.js:157
dispatchEvent @ eventtarget.js:22
(anonymous) @ index.js:292
log.js:179 2022-02-28T20:14:55.104Z warn [PeerConnectionV2 #1: a2efc935-b93f-48a3-b5b3-087e968ef1e7] An ICE restart has been scheduled
log @ log.js:179
warn @ log.js:239
_initiateIceRestartBackoff @ peerconnection.js:954
(anonymous) @ peerconnection.js:794
_onIceConnectionStateChanged @ iceconnectionmonitor.js:112
emit @ events.js:157
dispatchEvent @ eventtarget.js:22
(anonymous) @ index.js:292
log.js:179 2022-02-28T20:14:55.106Z info [Room #1: RM5c2a60af0dc49a540258524c673d5720] Transitioned to state: reconnecting
log.js:179 2022-02-28T20:14:55.107Z warn [PeerConnectionV2 #1: a2efc935-b93f-48a3-b5b3-087e968ef1e7] Attempting to restart ICE

More detailed:

2022-02-28T20:14:33.125Z debug [RemoteVideoTrack #2: MT1ee547fe395b87d01d18406fcd4ce042] Dimensions changed: Object
log.js:179 2022-02-28T20:14:35.188Z debug [TwilioConnection #1: wss://global.vss.twilio.com/signaling] Outgoing: {"type":"heartbeat"}
log.js:179 2022-02-28T20:14:36.141Z debug [TwilioConnection #1: wss://global.vss.twilio.com/signaling] Incoming: {"type":"heartbeat"}
log.js:179 2022-02-28T20:14:39.993Z debug [TwilioConnection #1: wss://global.vss.twilio.com/signaling] Outgoing: {"type":"heartbeat"}
log.js:179 2022-02-28T20:14:40.179Z info [connect #1] event Object
log.js:179 2022-02-28T20:14:40.242Z debug [TwilioConnection #1: wss://global.vss.twilio.com/signaling] Incoming: {"type":"heartbeat"}
log.js:179 2022-02-28T20:14:44.341Z debug [TwilioConnection #1: wss://global.vss.twilio.com/signaling] Incoming: {"type":"heartbeat"}
log.js:179 2022-02-28T20:14:44.969Z debug [TwilioConnection #1: wss://global.vss.twilio.com/signaling] Outgoing: {"type":"heartbeat"}
log.js:179 2022-02-28T20:14:48.342Z debug [TwilioConnection #1: wss://global.vss.twilio.com/signaling] Incoming: {"type":"heartbeat"}
log.js:179 2022-02-28T20:14:49.771Z debug [TwilioConnection #1: wss://global.vss.twilio.com/signaling] Outgoing: {"type":"heartbeat"}
log.js:179 2022-02-28T20:14:50.027Z info [connect #1] event {elapsedTime: 30314, group: 'quality', level: 'info', name: 'stats-report', timestamp: 1646079290027, …}
log.js:179 2022-02-28T20:14:50.028Z info [connect #1] event {elapsedTime: 30314, group: 'quality', level: 'info', name: 'active-ice-candidate-pair', timestamp: 1646079290027, …}
log.js:179 2022-02-28T20:14:52.442Z debug [TwilioConnection #1: wss://global.vss.twilio.com/signaling] Incoming: {"type":"heartbeat"}
log.js:179 2022-02-28T20:14:54.575Z debug [TwilioConnection #1: wss://global.vss.twilio.com/signaling] Outgoing: {"type":"heartbeat"}
log.js:179 2022-02-28T20:14:55.102Z debug [PeerConnectionV2 #1: a2efc935-[REDACTED]-087e968ef1e7] ICE connection state is "disconnected"
log.js:179 2022-02-28T20:14:55.103Z warn [PeerConnectionV2 #1: a2efc935-b93f-48a3-b5b3-087e968ef1e7] ICE Connection Monitor detected inactivity
log @ log.js:179
warn @ log.js:239
(anonymous) @ peerconnection.js:792
_onIceConnectionStateChanged @ iceconnectionmonitor.js:112
emit @ events.js:157
dispatchEvent @ eventtarget.js:22
(anonymous) @ index.js:292
log.js:179 2022-02-28T20:14:55.104Z warn [PeerConnectionV2 #1: a2efc935-b93f-48a3-b5b3-087e968ef1e7] An ICE restart has been scheduled
log @ log.js:179
warn @ log.js:239
_initiateIceRestartBackoff @ peerconnection.js:954
(anonymous) @ peerconnection.js:794
_onIceConnectionStateChanged @ iceconnectionmonitor.js:112
emit @ events.js:157
dispatchEvent @ eventtarget.js:22
(anonymous) @ index.js:292
log.js:179 2022-02-28T20:14:55.106Z info [Room #1: RM5c2a60af0dc49a540258524c673d5720] Transitioned to state: reconnecting
log.js:179 2022-02-28T20:14:55.107Z warn [PeerConnectionV2 #1: a2efc935-b93f-48a3-b5b3-087e968ef1e7] Attempting to restart ICE
log @ log.js:179
warn @ log.js:239
_initiateIceRestart @ peerconnection.js:926
(anonymous) @ peerconnection.js:425
emit @ events.js:153
push../node_modules/backoff/lib/backoff.js.Backoff.onBackoff_ @ backoff.js:53
setTimeout (async)
push../node_modules/backoff/lib/backoff.js.Backoff.backoff @ backoff.js:45
_initiateIceRestartBackoff @ peerconnection.js:956
(anonymous) @ peerconnection.js:794
_onIceConnectionStateChanged @ iceconnectionmonitor.js:112
emit @ events.js:157
dispatchEvent @ eventtarget.js:22
(anonymous) @ index.js:292
log.js:179 2022-02-28T20:14:55.108Z debug [PeerConnectionV2 #1: a2efc935-b93f-48a3-b5b3-087e968ef1e7] Starting ICE reconnect timeout: 30000
useRoomState.js:12 [KC-Debug] Room State Changed:  reconnecting
ReconnectingNotification.js:10 [KC-Debug] Reconnecting Notification is showing. Check roomState:  reconnecting
2useRoomState.js:12 [KC-Debug] Room State Changed:  reconnecting
log.js:179 2022-02-28T20:14:55.221Z debug [TwilioConnection #1: wss://global.vss.twilio.com/signaling] Outgoing: {"body":{"session":"94733ff0b4abb50db37b36ed84212c025c2a60af0dc49a540258524c673d57208cad0f0968ffb528982c2f3e21b42cfe7131b0338860376332cd536dd6cad327","type":"update","version":2,"peer_connections":[{"description":{"type":"offer","revision":3,"sdp":"v=0\r\no=- 5144826439767498829 4 IN IP4 127.0.0.1\r\ns=-\r\nt=0 0\r\na=group:BUNDLE 0 1 2 3 4\r\na=extmap-allow-mixed\r\na=msid-semantic: WMS\r\nm=audio 9 UDP/TLS/RTP/SAVPF 111 63 103 104 9 0 8 106 105 13 110 112 113 126\r\nc=IN IP4 0.0.0.0\r\na=rtcp:9 IN IP4 0.0.0.0\r\na=ice-ufrag:Zq9d\r\na=ice-pwd:lRxQHyepgpc05ffk4NHQcmFd\r\na=ice-options:trickle\r\na=fingerprint:sha-256 0F:E6:4F:BD:BB:56:56:40:70:85:6F:A0:43:9B:29:00:98:EF:D6:25:C1:79:AE:DB:86:96:C7:31:E4:A6:78:AE\r\na=setup:actpass\r\na=mid:0\r\na=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level\r\na=extmap:2 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time\r\na=extmap:3 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01\r\na=extmap:4 urn:ietf:params:rtp-hdrext:sdes:mid\r\na=recvonly\r\na=rtcp-mux\r\na=rtpmap:111 opus/48000/2\r\na=rtcp-fb:111 transport-cc\r\na=fmtp:111 minptime=10;useinbandfec=1\r\na=rtpmap:63 red/48000/2\r\na=fmtp:63 111/111\r\na=rtpmap:103 ISAC/16000\r\na=rtpmap:104 ISAC/32000\r\na=rtpmap:9 G722/8000\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:8 PCMA/8000\r\na=rtpmap:106 CN/32000\r\na=rtpmap:105 CN/16000\r\na=rtpmap:13 CN/8000\r\na=rtpmap:110 telephone-event/48000\r\na=rtpmap:112 telephone-event/32000\r\na=rtpmap:113 telephone-event/16000\r\na=rtpmap:126 telephone-event/8000\r\nm=video 9 UDP/TLS/RTP/SAVPF 102 127 125 108 124 123 114 96 97 99 101 121 120 107 109 119 117 36 115 62 98 100 122 35 116 118 37\r\nc=IN IP4 0.0.0.0\r\na=rtcp:9 IN IP4 0.0.0.0\r\na=ice-ufrag:Zq9d\r\na=ice-pwd:lRxQHyepgpc05ffk4NHQcmFd\r\na=ice-options:trickle\r\na=fingerprint:sha-256 0F:E6:4F:BD:BB:56:56:40:70:85:6F:A0:43:9B:29:00:98:EF:D6:25:C1:79:AE:DB:86:96:C7:31:E4:A6:78:AE\r\na=setup:actpass\r\na=mid:1\r\na=extmap:14 urn:ietf:params:rtp-hdrext:toffset\r\na=extmap:2 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time\r\na=extmap:13 urn:3gpp:video-orientation\r\na=extmap:3 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01\r\na=extmap:5 http://www.webrtc.org/experiments/rtp-hdrext/playout-delay\r\na=extmap:6 http://www.webrtc.org/experiments/rtp-hdrext/video-content-type\r\na=extmap:7 http://www.webrtc.org/experiments/rtp-hdrext/video-timing\r\na=extmap:8 http://www.webrtc.org/experiments/rtp-hdrext/color-space\r\na=extmap:4 urn:ietf:params:rtp-hdrext:sdes:mid\r\na=extmap:10 urn:ietf:params:rtp-hdrext:sdes:rtp-stream-id\r\na=extmap:11 urn:ietf:params:rtp-hdrext:sdes:repaired-rtp-stream-id\r\na=recvonly\r\na=rtcp-mux\r\na=rtcp-rsize\r\na=rtpmap:102 H264/90000\r\na=rtcp-fb:102 goog-remb\r\na=rtcp-fb:102 transport-cc\r\na=rtcp-fb:102 ccm fir\r\na=rtcp-fb:102 nack\r\na=rtcp-fb:102 nack pli\r\na=fmtp:102 level-asymmetry-allowed=1;packetization-mode=1;profile-level-id=42001f\r\na=rtpmap:127 H264/90000\r\na=rtcp-fb:127 goog-remb\r\na=rtcp-fb:127 transport-cc\r\na=rtcp-fb:127 ccm fir\r\na=rtcp-fb:127 nack\r\na=rtcp-fb:127 nack pli\r\na=fmtp:127 level-asymmetry-allowed=1;packetization-mode=0;profile-level-id=42001f\r\na=rtpmap:125 H264/90000\r\na=rtcp-fb:125 goog-remb\r\na=rtcp-fb:125 transport-cc\r\na=rtcp-fb:125 ccm fir\r\na=rtcp-fb:125 nack\r\na=rtcp-fb:125 nack pli\r\na=fmtp:125 level-asymmetry-allowed=1;packetization-mode=1;profile-level-id=42e01f\r\na=rtpmap:108 H264/90000\r\na=rtcp-fb:108 goog-remb\r\na=rtcp-fb:108 transport-cc\r\na=rtcp-fb:108 ccm fir\r\na=rtcp-fb:108 nack\r\na=rtcp-fb:108 nack pli\r\na=fmtp:108 level-asymmetry-allowed=1;packetization-mode=0;profile-level-id=42e01f\r\na=rtpmap:124 H264/90000\r\na=rtcp-fb:124 goog-remb\r\na=rtcp-fb:124 transport-cc\r\na=rtcp-fb:124 ccm fir\r\na=rtcp-fb:124 nack\r\na=rtcp-fb:124 nack pli\r\na=fmtp:124 level-asymmetry-allowed=1;packetization-mode=1;profile-level-id=4d001f\r\na=rtpmap:123 H264/90000\r\na=rtcp-fb:123 goog-remb\r\na=rtcp-fb:123 transport-cc\r\na=rtcp-fb:123 ccm fir\r\na=rtcp-fb:123 nack\r\na=rtcp-fb:123 nack pli\r\na=fmtp:123 level-asymmetry-allowed=1;packetization-mode=0;profile-level-id=4d001f\r\na=rtpmap:114 H264/90000\r\na=rtcp-fb:114 goog-remb\r\na=rtcp-fb:114 transport-cc\r\na=rtcp-fb:114 ccm fir\r\na=rtcp-fb:114 nack\r\na=rtcp-fb:114 nack pli\r\na=fmtp:114 level-asymmetry-allowed=1;packetization-mode=1;profile-level-id=640032\r\na=rtpmap:96 VP8/90000\r\na=rtcp-fb:96 goog-remb\r\na=rtcp-fb:96 transport-cc\r\na=rtcp-fb:96 ccm fir\r\na=rtcp-fb:96 nack\r\na=rtcp-fb:96 nack pli\r\na=rtpmap:97 rtx/90000\r\na=fmtp:97 apt=96\r\na=rtpmap:99 rtx/90000\r\na=fmtp:99 apt=98\r\na=rtpmap:101 rtx/90000\r\na=fmtp:101 apt=100\r\na=rtpmap:121 rtx/90000\r\na=fmtp:121 apt=102\r\na=rtpmap:120 rtx/90000\r\na=fmtp:120 apt=127\r\na=rtpmap:107 rtx/90000\r\na=fmtp:107 apt=125\r\na=rtpmap:109 rtx/90000\r\na=fmtp:109 apt=108\r\na=rtpmap:119 rtx/90000\r\na=fmtp:119 apt=124\r\na=rtpmap:117 rtx/90000\r\na=fmtp:11
log.js:179 2022-02-28T20:14:56.445Z debug [TwilioConnection #1: wss://global.vss.twilio.com/signaling] Incoming: {"type":"heartbeat"}
log.js:179 2022-02-28T20:15:00.097Z debug [TwilioConnection #1: wss://global.vss.twilio.com/signaling] Outgoing: {"type":"heartbeat"}
log.js:179 2022-02-28T20:15:00.102Z info [connect #1] event {elapsedTime: 40388, group: 'quality', level: 'info', name: 'stats-report', timestamp: 1646079300101, …}
log.js:179 2022-02-28T20:15:00.544Z debug [TwilioConnection #1: wss://global.vss.twilio.com/signaling] Incoming: {"type":"heartbeat"}
log.js:179 2022-02-28T20:15:04.544Z debug [TwilioConnection #1: wss://global.vss.twilio.com/signaling] Incoming: {"type":"heartbeat"}
log.js:179 2022-02-28T20:15:04.897Z debug [TwilioConnection #1: wss://global.vss.twilio.com/signaling] Outgoing: {"type":"heartbeat"}
log.js:179 2022-02-28T20:15:05.812Z debug [TwilioConnection #1: wss://global.vss.twilio.com/signaling] Incoming: {"body":{"version":2,"type":"update","sid":"RM5c2a60af0dc49a540258524c673d5720","name":"RM5c2a60af0dc49a540258524c673d5720","participant":{"sid":"PA8cad0f0968ffb528982c2f3e21b42cfe","identity":"Kinetic Commerce","tracks":[],"revision":2,"state":"connected"},"participants":[{"sid":"PA87f69a127276cca0fd7d586c5ab5cc72","identity":"Tianyun Shan","tracks":[{"kind":"video","priority":"standard","id":"ea89d24f-21fd-4dd1-bf4c-7ea7afa8740c","enabled":true,"sid":"MT1ee547fe395b87d01d18406fcd4ce042","name":"camera-1646078980329","state":"ready"},{"kind":"data","priority":"standard","id":"36bd91e3-a4ef-426a-baed-a0545c015b93","enabled":true,"sid":"MTb54f198e5f39af8ba02751aa1ee4a607","name":"46edc8b8-9de8-4eaa-b174-d977565621dd","state":"ready"},{"kind":"audio","priority":"standard","id":"e86cfc49-803c-45c4-ba59-f64b9f590adb","enabled":false,"sid":"MT4230133a614b4670e9fd996cb6b9a8fb","name":"7e3b9abf-d9da-4997-bd0b-86afd8d1fca1","state":"ready"}],"revision":10,"state":"reconnecting"}],"recording":{"enabled":false,"revision":1,"is_recording":false},"subscribed":{"revision":3,"tracks":[{"id":"36bd91e3-a4ef-426a-baed-a0545c015b93","sid":"MTb54f198e5f39af8ba02751aa1ee4a607"},{"id":"ea89d24f-21fd-4dd1-bf4c-7ea7afa8740c","sid":"MT1ee547fe395b87d01d18406fcd4ce042"},{"id":"e86cfc49-803c-45c4-ba59-f64b9f590adb","sid":"MT4230133a614b4670e9fd996cb6b9a8fb"}]}},"type":"msg"}
log.js:179 2022-02-28T20:15:05.813Z debug [RemoteParticipant #2: PA87f69a127276cca0fd7d586c5ab5cc72] Transitioned to state: reconnecting
log.js:179 2022-02-28T20:15:08.681Z debug [TwilioConnection #1: wss://global.vss.twilio.com/signaling] Incoming: {"type":"heartbeat"}
log.js:179 2022-02-28T20:15:09.704Z debug [TwilioConnection #1: wss://global.vss.twilio.com/signaling] Outgoing: {"type":"heartbeat"}
log.js:179 2022-02-28T20:15:10.025Z info [connect #1] event {elapsedTime: 50312, group: 'quality', level: 'info', name: 'stats-report', timestamp: 1646079310025, …}
log.js:179 2022-02-28T20:15:10.026Z info [connect #1] event {elapsedTime: 50313, group: 'quality', level: 'info', name: 'active-ice-candidate-pair', timestamp: 1646079310026, …}
log.js:179 2022-02-28T20:15:12.776Z debug [TwilioConnection #1: wss://global.vss.twilio.com/signaling] Incoming: {"type":"heartbeat"}
log.js:179 2022-02-28T20:15:14.506Z debug [TwilioConnection #1: wss://global.vss.twilio.com/signaling] Outgoing: {"type":"heartbeat"}
log.js:179 2022-02-28T20:15:16.874Z debug [TwilioConnection #1: wss://global.vss.twilio.com/signaling] Incoming: {"type":"heartbeat"}
log.js:179 2022-02-28T20:15:19.307Z debug [TwilioConnection #1: wss://global.vss.twilio.com/signaling] Outgoing: {"type":"heartbeat"}
log.js:179 2022-02-28T20:15:20.033Z info [connect #1] event {elapsedTime: 60320, group: 'quality', level: 'info', name: 'stats-report', timestamp: 1646079320033, …}
log.js:179 2022-02-28T20:15:20.951Z debug [TwilioConnection #1: wss://global.vss.twilio.com/signaling] Incoming: {"type":"heartbeat"}
log.js:179 2022-02-28T20:15:24.108Z debug [TwilioConnection #1: wss://global.vss.twilio.com/signaling] Outgoing: {"type":"heartbeat"}
log.js:179 2022-02-28T20:15:25.046Z debug [TwilioConnection #1: wss://global.vss.twilio.com/signaling] Incoming: {"type":"heartbeat"}
log.js:179 2022-02-28T20:15:25.107Z debug [LocalParticipant #1: PA8cad0f0968ffb528982c2f3e21b42cfe] Transitioned to state: disconnected
log.js:179 2022-02-28T20:15:25.107Z debug [LocalParticipant #1: PA8cad0f0968ffb528982c2f3e21b42cfe] Removing Track event reemitters
log.js:179 2022-02-28T20:15:25.108Z debug [LocalParticipant #1: PA8cad0f0968ffb528982c2f3e21b42cfe] Transitioned to state: disconnected
log.js:179 2022-02-28T20:15:25.108Z debug [LocalParticipant #1: PA8cad0f0968ffb528982c2f3e21b42cfe] Removing LocalTrack event listeners
log.js:179 2022-02-28T20:15:25.108Z info [LocalParticipant #1: PA8cad0f0968ffb528982c2f3e21b42cfe] LocalParticipant disconnected. Stopping 0 automatically-acquired LocalTracks
log.js:179 2022-02-28T20:15:25.108Z info [Room #1: RM5c2a60af0dc49a540258524c673d5720] Transitioned to state: disconnected
log.js:179 2022-02-28T20:15:25.123Z debug [RemoteVideoTrack #2: MT1ee547fe395b87d01d18406fcd4ce042] Attempting to detach from elements: [video.video-root-115]

One more thing

One thing that I want to point out is that it only be able to reproduce on our deployed server.

To reproduce this issue on localhost, I will have to do exactly the following:

  1. Run our front-end react and back-end react server on computer (COM-A).
  2. Person A join the room using computer (COM-A)
  3. Person B join the room using computer (COM-B)
  4. Disconnect network in computer (COM-A)

In that case, I can reproduce that and both A and B will reconnecting and eventually change to disconnected.

Note that if I:

  1. Have front-end react server running on (COM-A)
  2. person B join the room using (COM-B)
  3. person A join the room using (COM-C)

In this case, disconnecting any network (COM-A or COM-B or COM-C) will not cause any unexpected behavior. Everything is as expected.

Footer

Software versions:

PikaJoyce commented 2 years ago

Hi @nuynait,

Thanks for opening this issue with us.

Could you please provide a link of your deployed app so I could investigate further? Also, could you please provide a room sid in which this occurs so I can review logs from my end as well?

One thing I noticed is between your last note and it's relation to a group room. It seems to be expected behavior. For example, if your server loses network connection, then your participants will no longer be able to connect. In the case with peer-to-peer, which participant is hosting the node server in your example?

Best, Joyce

halostatue commented 2 years ago

@PikaJoyce I’m working with @nuynait on this. Am I understanding you correctly that if the host of a group room loses network, the room is wholly disconnected?

PikaJoyce commented 2 years ago

Hi @halostatue

I'm sorry, I meant the computer running the node server. For example in the steps to reproduce, if person B was the computer also running the node server, and person B disconnected from a network.

nuynait commented 2 years ago

Hi @PikaJoyce

First, in our deployed version, any participant lost its connection will cause the other participant to disconnect from the room for peer-to-peer type room only.

In the one more thing, I was trying to reproduce on localhost, because debugging on the deployed server directly is hard. So I'm trying to reproduce this issue on localhost. I want to show everything I know in the issue, so I included what I find when I test on localhost at the end of my notes.

On that last note, the server we are using is the front-end react server and a back-end node server. At the point when I disconnect the network, the app is already in the video call and have the room connected. My understanding is that it's interacting with the Twilio server now. The disconnect from its front-end React server and our back-end node server should not cause the Twilio call to be disconnected.

The proof is if you see the last part I mentioned,(on localhost) if I have person A and B connecting to our server from two other computers, then if I disconnect the server network, person A and B can continue doing video calls without issue.

If I have person A and server running on the same computer, then person B on the other, disconnect person A in my opinion should not kick out person B. The actual case is it also disconnect person B in a peer-to-peer type room. However, this exact same experience will not happen in a group-type room. In the group-type room, it will still keep person B connected in the room.


For providing a link to the deployed app, I'm not sure if I can provide that right now. Will need to discuss that with the team.

For room sid, any peer-to-peer type room will have this issue. If you want I can tomorrow, create a peer-to-peer call and make this happen then send you the room sid.


Thank you very much for your time and help Joyce.

I'm sorry that you might feel confused when reading some parts of my notes. I'm not a very good writer. Apologize again if I'm causing you troubles here. Please feel free to let me know any time if there's anything in my writing you have questions about.

Best wishes, Jerry Shan

PikaJoyce commented 2 years ago

Hi Jerry,

Thank you for clarifying and please don't apologize! So, I've tried this across several of our own applications such as the react app and our own testing application, all of which are deployed but I unfortunately haven't been able to reproduce it.

Since I'm unable to reproduce it, I'm thinking it may have something to do with this portion :

        const disconnect = () => newRoom.disconnect()

        newRoom.once('disconnected', () => {
          setTimeout(() => setRoom(null))
          window.removeEventListener('beforeunload', disconnect)
          isMobile && window.removeEventListener('pagehide', disconnect)
        })

I want to dig a little bit deeper into this portion here. To me, this reads that when there is a disconnected event. You call disconnect. But every participant runs this? Please correct me if I'm wrong here.

I only noticed this because we are also not handling any participant disconnected events which might be what you need here. Cleaning up once a participant has left the room versus cleaning up when a room disconnects.

Here's some extra documentation, here's another one but it's for reconnection states rather than disconnected.

You can alternatively try using room.on('participantDisconnected', ...) as well.

Again, please correct me if I'm wrong. But regardless I hope this helps and if none of my suggestions are working, could you please test it out on the react app and let me know your results?

Thank you! Joyce

nuynait commented 2 years ago

Hi PikaJoyce,

Thanks so much for your kindness. I appreciate all those time you spent helping me find the issue in my code. I have spent a decent amount of time going over my codes and the documentation you provided. Here is my understanding:

        const disconnect = () => newRoom.disconnect()

        newRoom.once('disconnected', () => {
          setTimeout(() => setRoom(null))
          window.removeEventListener('beforeunload', disconnect)
          isMobile && window.removeEventListener('pagehide', disconnect)
        })
        window.twilioRoom = newRoom

        window.addEventListener('beforeunload', disconnect)
        isMobile && window.addEventListener('pagehide', disconnect)

This part of the code is not an issue. It means when the beforeunload event is fired for the window, we disconnect the room. I think this is used to disconnect the room if the user closes the webpage. Afterwards, if the room has been disconnected, we will remove our cached room state and remove the window event listener. All these make sense and the problem still persists after I remove this block of code.


Update 2022-03-16

I am able to reproduce the issue in your react app.

I have forked it here. Please see the README.md for more details.

I have made a screencast and here is a download link

Please feel free to reach me with any questions.

Sincerely, Jerry Shan

PikaJoyce commented 2 years ago

Hi @nuynait,

Thanks for the update and for trying it out! I'll begin some investigations today and update you when I get to it!

Best, Joyce

PikaJoyce commented 2 years ago

Hey @nuynait,

Thank you for your patience! So I got to try it out. I have so far been able to test two scenarios.

  1. Computer A - Hosting ngrok + Device B => Computer A turns off network => Reproduced
  2. Computer A - Hosting ngrok + Device B => Device B turns off network => Reproduced

I believe that this is a known issue after consulting with the team about this. Here's a little bit of insight as to why this happens. If we look at this diagram we can see that Twilio does not have a hand in the media exchange in P2P rooms. So in cases like this, if a participant loses network and reconnection is never established within 30 seconds, both participants lose connection to the room as they're both thrown into a reconnecting state since we do not know which of the two participants have network issues.

The workaround for this would be for the person who loses network (and is unable to reconnect) to actually leave the room before the reconnection timer runs out. This should allow for the other participant that does not have network issues to stay in the room.

As this is a known issue, I've filed an internal ticket to track this issue (VIDEO-9283)

I will be keeping this issue open and update this thread as they come.

Thank you again for your patience and thorough explanations!

Best, Joyce

artemSQS commented 2 years ago

Hi @PikaJoyce,

Is there any news about this issue? I still experience the same problem. You mentioned this workaround:

The workaround for this would be for the person who loses network (and is unable to reconnect) to actually leave the room before the reconnection timer runs out. This should allow for the other participant that does not have network issues to stay in the room.

How could I achieve this? As I understand if such participant loses internet connection he can't really tell that he needs to disconnect form the room. Maybe it can be handled on the backend? Perhaps there is some Video REST API route that can be used to disconnect specific participant?

PikaJoyce commented 2 years ago

Hi @artemSQS,

Thank you for the question. Currently there hasn't been any movement as fixing this issue will require an entire overhaul to our current product to solve this.

My suggestion to work around this is you can listen in on the reconnecting room event and disconnect that participant as soon as the attempt to reconnect occurs.

Best, Joyce