diff --git a/OpenSim/Addons/os-webrtc-janus/Janus/JanusMessages.cs b/OpenSim/Addons/os-webrtc-janus/Janus/JanusMessages.cs index 098b93d5b0..5b426cccf7 100644 --- a/OpenSim/Addons/os-webrtc-janus/Janus/JanusMessages.cs +++ b/OpenSim/Addons/os-webrtc-janus/Janus/JanusMessages.cs @@ -102,6 +102,11 @@ namespace osWebRtcVoice m_message["apisecret"] = pToken; } + public void AddAdminToken(string pToken) + { + m_message["admin_secret"] = pToken; + } + // Note that the session_id is a long number in the JSON so we convert the string. public string sessionId { diff --git a/OpenSim/Addons/os-webrtc-janus/Janus/JanusPlugin.cs b/OpenSim/Addons/os-webrtc-janus/Janus/JanusPlugin.cs index eabca6393f..9ce6ceeec3 100644 --- a/OpenSim/Addons/os-webrtc-janus/Janus/JanusPlugin.cs +++ b/OpenSim/Addons/os-webrtc-janus/Janus/JanusPlugin.cs @@ -29,10 +29,6 @@ using System; using System.Reflection; using System.Threading.Tasks; -using OpenSim.Framework; -using OpenSim.Services.Interfaces; -using OpenSim.Services.Base; - using OpenMetaverse.StructuredData; using OpenMetaverse; @@ -92,10 +88,10 @@ namespace osWebRtcVoice bool ret = false; try { - var resp = await _JanusSession.SendToSession(new AttachPluginReq(PluginName)); + JanusMessageResp resp = await _JanusSession.SendToSession(new AttachPluginReq(PluginName)); if (resp is not null && resp.isSuccess) { - var handleResp = new AttachPluginResp(resp); + AttachPluginResp handleResp = new(resp); PluginId = handleResp.pluginId; PluginUri = _JanusSession.SessionUri + "/" + PluginId; m_log.DebugFormat("{0} Activate. Plugin attached. ID={1}, URL={2}", LogHeader, PluginId, PluginUri); @@ -130,7 +126,7 @@ namespace osWebRtcVoice _JanusSession.OnEvent -= Handle_Event; _JanusSession.OnMessage -= Handle_Message; // We send the 'detach' message to the plugin URI - var resp = await _JanusSession.SendToJanus(new DetachPluginReq(), PluginUri); + JanusMessageResp resp = await _JanusSession.SendToJanus(new DetachPluginReq(), PluginUri); if (resp is not null && resp.isSuccess) { m_log.DebugFormat("{0} Detach. Detached", LogHeader); diff --git a/OpenSim/Addons/os-webrtc-janus/Janus/JanusRoom.cs b/OpenSim/Addons/os-webrtc-janus/Janus/JanusRoom.cs index ce811573b7..32bd745430 100644 --- a/OpenSim/Addons/os-webrtc-janus/Janus/JanusRoom.cs +++ b/OpenSim/Addons/os-webrtc-janus/Janus/JanusRoom.cs @@ -30,7 +30,6 @@ using System.Reflection; using OpenMetaverse.StructuredData; -using Nini.Config; using log4net; using System.Threading.Tasks; @@ -114,16 +113,22 @@ namespace osWebRtcVoice m_log.Error($"{LogHeader} JoinRoom. Recovery failed: could not clear previous room membership. Resp={joinResp}"); } } -/* else { +/* if (joinResp is not null && joinResp.AudioBridgeReturnCode == "joined" && joinResp.ParticipantId <= 0) { - m_log.Error($"{LogHeader} JoinRoom. Joined response contains invalid participant id {joinResp.ParticipantId} for room {RoomId}. Resp={joinResp}"); + m_log.ErrorFormat("{0} JoinRoom. Joined response contains invalid participant id {1} for room {2}", + LogHeader, joinResp.ParticipantId, RoomId); + if (m_log.IsDebugEnabled) + m_log.DebugFormat("{0} JoinRoom. Invalid participant detail: {1}", LogHeader, joinResp.ToString()); } - m_log.Error($"{LogHeader} JoinRoom. Failed to join room {RoomId}. Resp={joinResp}"); - } */ + m_log.ErrorFormat("{0} JoinRoom. Failed to join room {1}", LogHeader, RoomId); + if (m_log.IsDebugEnabled) + m_log.DebugFormat("{0} JoinRoom. Failure detail: {1}", LogHeader, joinResp?.ToString() ?? "null"); + + } } catch (Exception e) { @@ -171,9 +176,10 @@ namespace osWebRtcVoice if (!string.Equals(display, pDisplay, StringComparison.Ordinal)) continue; +// long participantId = participant.TryGetValue("id", out OSD idNode) ? idNode.AsLong() : 0L; +// if (participantId <= 0) +// continue; int participantId = participant.TryGetValue("id", out OSD idNode) ? (int)idNode.AsLong() : 0; - if (participantId <= 0) - continue; JanusMessageResp leaveRespRaw = await _AudioBridge.SendPluginMsg(new AudioBridgeLeaveRoomReq(roomId, participantId)); AudioBridgeResp leaveResp = new(leaveRespRaw); diff --git a/OpenSim/Addons/os-webrtc-janus/Janus/JanusSession.cs b/OpenSim/Addons/os-webrtc-janus/Janus/JanusSession.cs index c26476513d..751d65fa84 100644 --- a/OpenSim/Addons/os-webrtc-janus/Janus/JanusSession.cs +++ b/OpenSim/Addons/os-webrtc-janus/Janus/JanusSession.cs @@ -47,13 +47,15 @@ namespace osWebRtcVoice private static readonly ILog m_log = LogManager.GetLogger(MethodBase.GetCurrentMethod().DeclaringType); private static readonly string LogHeader = "[JANUS SESSION]"; + // Set to true to enable Janus session debug logging. + private bool _DebugEnabled = false; // Set to 'true' to get the messages send and received from Janus private bool _MessageDetails = false; - private string _JanusServerURI = String.Empty; - private string _JanusAPIToken = String.Empty; - private string _JanusAdminURI = String.Empty; - private string _JanusAdminToken = String.Empty; + private string _JanusServerURI = string.Empty; + private string _JanusAPIToken = string.Empty; + private string _JanusAdminURI = string.Empty; + private string _JanusAdminToken = string.Empty; public string JanusServerURI => _JanusServerURI; public string JanusAdminURI => _JanusAdminURI; @@ -69,9 +71,11 @@ namespace osWebRtcVoice public bool IsConnected { get; set; } // Wrapper around the session connection to Janus-gateway - public JanusSession(string pServerURI, string pAPIToken, string pAdminURI, string pAdminToken, bool pDebugMessages = false) + public JanusSession(string pServerURI, string pAPIToken, string pAdminURI, string pAdminToken, bool pDebugEnabled = false, bool pDebugMessages = false) { - m_log.DebugFormat("{0} JanusSession constructor", LogHeader); +// m_log.DebugFormat("{0} JanusSession constructor", LogHeader); + _DebugEnabled = pDebugEnabled; + DebugLog("{0} JanusSession constructor", LogHeader); _JanusServerURI = pServerURI; _JanusAPIToken = pAPIToken; _JanusAdminURI = pAdminURI; @@ -103,7 +107,7 @@ namespace osWebRtcVoice bool ret = false; try { - var resp = await SendToJanus(new CreateSessionReq()); + JanusMessageResp resp = await SendToJanus(new CreateSessionReq()); if (resp is not null && resp.isSuccess) { var sessionResp = new CreateSessionResp(resp); @@ -111,6 +115,7 @@ namespace osWebRtcVoice IsConnected = true; SessionUri = _JanusServerURI + "/" + SessionId; m_log.DebugFormat("{0} CreateSession. Created. ID={1}, URL={2}", LogHeader, SessionId, SessionUri); +// DebugLog("{0} CreateSession. Created. ID={1}, URL={2}", LogHeader, SessionId, SessionUri); ret = true; StartLongPoll(); } @@ -137,6 +142,7 @@ namespace osWebRtcVoice { // Note that setting IsConnected to false will cause the long poll to exit m_log.Debug($"{LogHeader} DestroySession. Destroyed"); +// Debug("{0} DestroySession. Destroyed", LogHeader); } else { @@ -148,10 +154,12 @@ namespace osWebRtcVoice case 458: // This is the error code for a session that is already destroyed m_log.Debug($"{LogHeader} DestroySession: session already destroyed"); +// DebugLog("{0} DestroySession: session already destroyed", LogHeader); break; case 459: // This is the error code for handle already destroyed if (_MessageDetails) m_log.Debug($"{LogHeader} DestroySession: Handle not found"); +// if (_MessageDetails) DebugLog("{0} DestroySession: Handle not found", LogHeader); break; default: m_log.Error($"{LogHeader} DestroySession: failed {eResp.errorReason}"); @@ -160,8 +168,9 @@ namespace osWebRtcVoice } else { - m_log.Error($"{LogHeader} DestroySession: failed. Resp: {resp}"); - } + m_log.Error($"{LogHeader} DestroySession: failed response"); + if (m_log.IsDebugEnabled) + m_log.DebugFormat("{0} DestroySession: response detail {1}", LogHeader, resp.ToString()); } } } catch (Exception e) @@ -210,6 +219,23 @@ namespace osWebRtcVoice { _Plugins.Add(pPlugin.PluginName, pPlugin); } + + private void DebugLog(string pFormat, params object[] pArgs) + { + if (_DebugEnabled) + { + m_log.DebugFormat(pFormat, pArgs); + } + } + + private void DebugLog(string message) + { + if (_DebugEnabled) + { + m_log.Debug(message); + } + } + // ==================================================================== // Post to the session public async Task SendToSession(JanusMessageReq pReq) @@ -241,11 +267,12 @@ namespace osWebRtcVoice /// /// /// - public async Task SendToJanus(JanusMessageReq pReq, string pURI) + public async Task SendToJanus(JanusMessageReq pReq, string pURI, bool admin = false) { - AddJanusHeaders(pReq); + AddJanusHeaders(pReq, admin); // m_log.DebugFormat("{0} SendToJanus", LogHeader); if (_MessageDetails) m_log.DebugFormat("{0} SendToJanus. URI={1}, req={2}", LogHeader, pURI, pReq.ToJson()); +// if (_MessageDetails) DebugLog("{0} SendToJanus. URI={1}, req={2}", LogHeader, pURI, pReq.ToJson()); JanusMessageResp ret = null; try @@ -273,6 +300,7 @@ namespace osWebRtcVoice { // Some messages are asynchronous and completed with an event if (_MessageDetails) m_log.DebugFormat("{0} SendToJanus: ack response {1}", LogHeader, respStr); +// if (_MessageDetails) DebugLog("{0} SendToJanus: ack response {1}", LogHeader, respStr); /* if (_OutstandingRequests.TryGetValue(pReq.TransactionId, out OutstandingRequest outstandingRequest)) { @@ -291,6 +319,8 @@ namespace osWebRtcVoice // If the response is not an ack, that means a synchronous request/response so return the response _= _OutstandingRequests.TryRemove(pReq.TransactionId, out _); if (_MessageDetails) m_log.DebugFormat("{0} SendToJanus: response {1}", LogHeader, respStr); +// if (_MessageDetails) DebugLog("{0} SendToJanus: response {1}", LogHeader, respStr); + } } else @@ -319,7 +349,7 @@ namespace osWebRtcVoice /// private async Task SendToJanusNoWait(JanusMessageReq pReq, string pURI) { - JanusMessageResp ret = new JanusMessageResp(); + JanusMessageResp ret = new(); AddJanusHeaders(pReq); @@ -346,13 +376,24 @@ namespace osWebRtcVoice } // There are various headers that are in most Janus requests. Add them here. - private void AddJanusHeaders(JanusMessageReq pReq) + private void AddJanusHeaders(JanusMessageReq pReq, bool admin = false) { // Authentication token - if (!string.IsNullOrEmpty(_JanusAPIToken)) + if(admin) { - pReq.AddAPIToken(_JanusAPIToken); + if (!string.IsNullOrEmpty(_JanusAdminToken)) + { + pReq.AddAdminToken(_JanusAdminToken); + } } + else + { + if (!string.IsNullOrEmpty(_JanusAPIToken)) + { + pReq.AddAPIToken(_JanusAPIToken); + } + } + // Transaction ID that matches responses to requests if (string.IsNullOrEmpty(pReq.TransactionId)) { @@ -380,16 +421,16 @@ namespace osWebRtcVoice return false; } - if(_OutstandingRequests.TryGetValue(pTransactionId, out pOutstandingRequest)) + if (_OutstandingRequests.TryGetValue(pTransactionId, out pOutstandingRequest)) return true; - pOutstandingRequest = null; + pOutstandingRequest = null; return false; } public Task SendToJanusAdmin(JanusMessageReq pReq) { - return SendToJanus(pReq, _JanusAdminURI); + return SendToJanus(pReq, _JanusAdminURI, true); } public Task GetFromJanus() @@ -428,7 +469,10 @@ namespace osWebRtcVoice else { m_log.ErrorFormat("{0} GetFromJanus: response not successful {1}", LogHeader, response); - var eResp = new ErrorResp("GETERROR"); +// m_log.ErrorFormat("{0} GetFromJanus: response not successful", LogHeader); +// if (m_log.IsDebugEnabled) +// m_log.DebugFormat("{0} GetFromJanus: response detail {1}", LogHeader, response); + ErrorResp eResp = new("GETERROR"); // Add the sessionId so the proper session can be shut down eResp.AddSessionId(SessionId); if (response is not null) @@ -445,6 +489,8 @@ namespace osWebRtcVoice catch (TaskCanceledException e) { if (_MessageDetails) m_log.DebugFormat("{0} GetFromJanus: task canceled: {1}", LogHeader, e.Message); +// if (_MessageDetails) DebugLog("{0} GetFromJanus: task canceled: {1}", LogHeader, e.Message); + ErrorResp eResp = new("GETERROR"); eResp.SetError(499, "Task canceled"); ret = eResp; @@ -509,7 +555,9 @@ namespace osWebRtcVoice { bool running = true; - m_log.DebugFormat("{0} EventLongPoll", LogHeader); + m_log.Debug($"{LogHeader} EventLongPoll"); +// DebugLog($"{LogHeader} EventLongPoll"); + Task.Run(async () => { while (running && IsConnected) { @@ -618,6 +666,20 @@ namespace osWebRtcVoice else { m_log.ErrorFormat("{0} EventLongPoll: event no outstanding request {1}", LogHeader, resp.ToString()); + // Janus often pushes plugin events without a transaction id (normal async flow). + // Keep unknown transaction ids visible, but do not treat missing transaction ids as errors. + if (string.IsNullOrEmpty(resp.TransactionId)) + { + m_log.DebugFormat("{0} EventLongPoll: async event with no transaction {1}", LogHeader, resp.ToString()); +// if (_MessageDetails) DebugLog("{0} EventLongPoll: async event with no transaction {1}", LogHeader, resp.ToString()); + } + else + { + m_log.WarnFormat("{0} EventLongPoll: event with unknown transaction", LogHeader); + if (m_log.IsDebugEnabled) + m_log.DebugFormat("{0} EventLongPoll: unknown transaction detail {1}", LogHeader, resp.ToString()); + } + OnEvent?.Invoke(eventResp); } break; @@ -697,15 +759,11 @@ namespace osWebRtcVoice try { - switch (value.Type) + return value.Type switch { - case OSDType.Integer: - case OSDType.Binary: - case OSDType.Array: - return value.AsLong().ToString(); - default: - return value.AsString(); - } + OSDType.Integer or OSDType.Binary or OSDType.Array => value.AsLong().ToString(), + _ => value.AsString(), + }; } catch { diff --git a/OpenSim/Addons/os-webrtc-janus/Janus/JanusViewerSession.cs b/OpenSim/Addons/os-webrtc-janus/Janus/JanusViewerSession.cs index 936bca0c0e..e1c096487c 100644 --- a/OpenSim/Addons/os-webrtc-janus/Janus/JanusViewerSession.cs +++ b/OpenSim/Addons/os-webrtc-janus/Janus/JanusViewerSession.cs @@ -26,8 +26,8 @@ */ using System.Reflection; +using System.Threading; using System.Threading.Tasks; - using OMV = OpenMetaverse; using OpenMetaverse.StructuredData; @@ -55,6 +55,7 @@ namespace osWebRtcVoice // Janus keeps track of the user by this ID public int ParticipantId { get; set; } +// public long ParticipantId { get; set; } // Connections to the Janus server public JanusSession Session { get; set; } @@ -67,12 +68,18 @@ namespace osWebRtcVoice // Contains "type" and "sdp" fields public OSDMap Answer { get; set; } + private int _disconnectStarted; + public string DisconnectReason { get; private set; } + private readonly SemaphoreSlim _provisionLock = new SemaphoreSlim(1, 1); + public SemaphoreSlim ProvisionLock => _provisionLock; + public JanusViewerSession(IWebRtcVoiceService pVoiceService) { ViewerSessionID = OMV.UUID.Random().ToString(); VoiceService = pVoiceService; m_log.Debug($"{LogHeader} JanusViewerSession created {ViewerSessionID}"); } + public JanusViewerSession(string pViewerSessionID, IWebRtcVoiceService pVoiceService) { ViewerSessionID = pViewerSessionID; @@ -80,6 +87,16 @@ namespace osWebRtcVoice m_log.Debug($"{LogHeader} JanusViewerSession created {ViewerSessionID}"); } + public bool TryStartDisconnect(string pReason) + { + if (Interlocked.CompareExchange(ref _disconnectStarted, 1, 0) == 0) + { + DisconnectReason = pReason; + return true; + } + return false; + } + // Send the messages to the voice service to try and get rid of the session // IVoiceViewerSession.Shutdown public async Task Shutdown() @@ -87,19 +104,19 @@ namespace osWebRtcVoice m_log.Debug($"{LogHeader} JanusViewerSession shutdown {ViewerSessionID}"); if (Room is not null) { - var rm = Room; + JanusRoom rm = Room; Room = null; - await rm.LeaveRoom(this); + _ = await rm.LeaveRoom(this).ConfigureAwait(false); } if (AudioBridge is not null) { - var ab = AudioBridge; + JanusAudioBridge ab = AudioBridge; AudioBridge = null; - await ab.Detach(); + _ = await ab.Detach().ConfigureAwait(false); } if (Session is not null) { - var s = Session; + JanusSession s = Session; Session = null; _ = await s.DestroySession().ConfigureAwait(false); s.Dispose(); diff --git a/OpenSim/Addons/os-webrtc-janus/Janus/WebRtcJanusService.cs b/OpenSim/Addons/os-webrtc-janus/Janus/WebRtcJanusService.cs index a277160433..0291051492 100644 --- a/OpenSim/Addons/os-webrtc-janus/Janus/WebRtcJanusService.cs +++ b/OpenSim/Addons/os-webrtc-janus/Janus/WebRtcJanusService.cs @@ -25,18 +25,18 @@ * SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. */ -using System; -using System.Reflection; -using System.Threading.Tasks; - +using log4net; +using Nini.Config; +using OpenMetaverse; +using OpenMetaverse.StructuredData; using OpenSim.Framework; using OpenSim.Services.Base; - -using OpenMetaverse.StructuredData; -using OpenMetaverse; - -using Nini.Config; -using log4net; +using System; +using System.Collections.Concurrent; +using System.Collections.Generic; +using System.Reflection; +using System.Threading; +using System.Threading.Tasks; namespace osWebRtcVoice { @@ -53,14 +53,26 @@ namespace osWebRtcVoice private string _JanusAdminURI = string.Empty; private string _JanusAdminToken = string.Empty; + private bool _JanusDebug = false; private bool _MessageDetails = false; + // Maximum ICE candidates accepted from one VoiceSignalingRequest call. + // <= 0 means no limit. + private int _MaxSignalingCandidatesPerRequest = 20; + // Delay between a disconnect and next join for same agent. + private int _RejoinCooldownMs = 250; + + private readonly ConcurrentDictionary _LastDisconnectByAgent = new ConcurrentDictionary(); + private long _VoiceFlowCounter; + // An extra "viewer session" that is created initially. Used to verify the service // is working and for a handle for the console commands. private JanusViewerSession _ViewerSession; public WebRtcJanusService(IConfigSource pConfig) : base(pConfig) { +// WebRtcDebugControl.ApplyFromConfig(pConfig); + Assembly assembly = Assembly.GetExecutingAssembly(); string version = assembly.GetName().Version?.ToString() ?? "unknown"; @@ -78,14 +90,32 @@ namespace osWebRtcVoice _JanusAPIToken = janusConfig.GetString("APIToken", string.Empty); _JanusAdminURI = janusConfig.GetString("JanusGatewayAdminURI", string.Empty); _JanusAdminToken = janusConfig.GetString("AdminAPIToken", string.Empty); - // Debugging options - _MessageDetails = janusConfig.GetBoolean("MessageDetails", false); if (string.IsNullOrEmpty(_JanusServerURI) || string.IsNullOrEmpty(_JanusAPIToken) || string.IsNullOrEmpty(_JanusAdminURI) || string.IsNullOrEmpty(_JanusAdminToken)) { _log.Error($"{LogHeader} JanusWebRtcVoice configuration section missing required fields"); _Enabled = false; + return; + } + + // Debugging options + _JanusDebug = janusConfig.GetBoolean("JanusDebug", false); + _MessageDetails = janusConfig.GetBoolean("MessageDetails", false); + + _MaxSignalingCandidatesPerRequest = janusConfig.GetInt("MaxSignalingCandidatesPerRequest", 20); + if (_MaxSignalingCandidatesPerRequest < 0) + { + _log.WarnFormat("{0} MaxSignalingCandidatesPerRequest < 0 ({1}), using 0 (unlimited)", + LogHeader, _MaxSignalingCandidatesPerRequest); + _MaxSignalingCandidatesPerRequest = 0; + } + + _RejoinCooldownMs = janusConfig.GetInt("RejoinCooldownMs", 250); + if (_RejoinCooldownMs < 0) + { + _log.WarnFormat("{0} RejoinCooldownMs < 0 ({1}), using 0", LogHeader, _RejoinCooldownMs); + _RejoinCooldownMs = 0; } if (_Enabled) @@ -119,7 +149,7 @@ namespace osWebRtcVoice private bool StartConnectionToJanus() { _log.DebugFormat("{0} StartConnectionToJanus", LogHeader); - _ViewerSession = new JanusViewerSession(this); + _ViewerSession = new JanusViewerSession(this); //bad return ConnectToSessionAndAudioBridge(_ViewerSession).Result; } @@ -158,12 +188,23 @@ namespace osWebRtcVoice { if (pResp is not null) { - var sessionId = pResp.sessionId; + string sessionId = pResp.sessionId; _log.Debug($"{LogHeader} Handle_Hangup: {pResp.RawBody}, sessionId={sessionId}"); if (VoiceViewerSession.TryGetViewerSessionByVSSessionId(sessionId, out IVoiceViewerSession viewerSession)) { // There is a viewer session associated with this session - DisconnectViewerSession(viewerSession as JanusViewerSession); +// DisconnectViewerSession(viewerSession as JanusViewerSession); + + // A Janus hangup can happen during a normal room switch/re-offer cycle. + // Keep the viewer session alive and only clear the per-call state. + if (viewerSession is JanusViewerSession janusViewerSession) + { + janusViewerSession.ParticipantId = 0; + janusViewerSession.Answer = null; + janusViewerSession.Offer = string.Empty; + janusViewerSession.OfferOrig = string.Empty; + janusViewerSession.Room = null; + } } else { @@ -172,11 +213,62 @@ namespace osWebRtcVoice } } + private void Handle_Disconnect(EventResp pResp) + { + if (pResp is null) + return; + + if (VoiceViewerSession.TryGetViewerSessionByVSSessionId(pResp.sessionId, out IVoiceViewerSession viewerSession)) + { + DisconnectViewerSession(viewerSession as JanusViewerSession, "disconnect"); + } + else + { + _log.DebugFormat("{0} Handle_Disconnect: no session found. SessionId={1}", LogHeader, pResp.sessionId); + } + } + + private static string FlowTag(long pFlowId, JanusViewerSession pViewerSession) + { + return $"flow={pFlowId}, viewer_session={pViewerSession?.ViewerSessionID ?? ""}"; + } + + private async Task EnforceRejoinCooldown(UUID pAgentId, JanusViewerSession pViewerSession, long pFlowId) + { + if (_RejoinCooldownMs <= 0) + return; + + if (_LastDisconnectByAgent.TryGetValue(pAgentId, out DateTime lastDisconnectUtc)) + { + int elapsedMs = (int)(DateTime.UtcNow - lastDisconnectUtc).TotalMilliseconds; + int waitMs = _RejoinCooldownMs - elapsedMs; + if (waitMs > 0) + { + _log.DebugFormat("{0} ProvisionVoiceAccountRequest: applying rejoin cooldown {1}ms ({2})", + LogHeader, waitMs, FlowTag(pFlowId, pViewerSession)); + await Task.Delay(waitMs); + } + } + } + // Disconnect the viewer session. This is called when the viewer logs out or hangs up. - private void DisconnectViewerSession(JanusViewerSession pViewerSession) + + private void DisconnectViewerSession(JanusViewerSession pViewerSession, string pReason) { if (pViewerSession is not null) { + if (!pViewerSession.TryStartDisconnect(pReason)) + { + _log.DebugFormat("{0} DisconnectViewerSession: duplicate disconnect suppressed. viewer_session={1}, reason={2}, firstReason={3}", + LogHeader, pViewerSession.ViewerSessionID, pReason, pViewerSession.DisconnectReason); + return; + } + + int roomId = pViewerSession.Room is not null ? pViewerSession.Room.RoomId : 0; + _LastDisconnectByAgent[pViewerSession.AgentId] = DateTime.UtcNow; + _log.InfoFormat("{0} ProvisionVoiceAccountRequest: disconnected by {1}. agent={2}, scene={3}, room={4}, participant={5}, viewer_session={6}", + LogHeader, pReason, pViewerSession.AgentId, pViewerSession.RegionId, roomId, pViewerSession.ParticipantId, pViewerSession.ViewerSessionID); + Task.Run(() => { VoiceViewerSession.RemoveViewerSession(pViewerSession.ViewerSessionID); @@ -200,6 +292,7 @@ namespace osWebRtcVoice OSDMap ret = null; string errorMsg = null; JanusViewerSession viewerSession = pSession as JanusViewerSession; + long flowId = Interlocked.Increment(ref _VoiceFlowCounter); if (viewerSession is not null) { if (viewerSession.Session is null) @@ -215,9 +308,12 @@ namespace osWebRtcVoice // The client is logging out. Exit the room. if (viewerSession.Room is not null) { - await viewerSession.Room.LeaveRoom(viewerSession); + _ = await viewerSession.Room.LeaveRoom(viewerSession).ConfigureAwait(false); viewerSession.Room = null; } + + // The client is logging out. Disconnect the entire Janus viewer session. + DisconnectViewerSession(viewerSession, "logout"); return new OSDMap { { "response", "closed" } @@ -237,43 +333,52 @@ namespace osWebRtcVoice if (pRequest.TryGetOSDMap("jsep", out OSDMap jsep)) { - // The jsep is the SDP from the client. This is the client's request to connect to the audio bridge. - string jsepType = jsep["type"].AsString(); - string jsepSdp = jsep["sdp"].AsString(); - if (jsepType == "offer") + await viewerSession.ProvisionLock.WaitAsync().ConfigureAwait(false); + + try { - // The client is sending an offer. Find the right room and join it. - // _log.DebugFormat("{0} ProvisionVoiceAccountRequest: jsep type={1} sdp={2}", LogHeader, jsepType, jsepSdp); - viewerSession.Room = await viewerSession.AudioBridge.SelectRoom(pSceneID.ToString(), - channel_type, isSpatial, parcel_local_id, channel_id).ConfigureAwait(false); - if (viewerSession.Room is null) + // The jsep is the SDP from the client. This is the client's request to connect to the audio bridge. + string jsepType = jsep["type"].AsString(); + string jsepSdp = jsep["sdp"].AsString(); + if (jsepType == "offer") { - errorMsg = "room selection failed"; - _log.Error($"{LogHeader} ProvisionVoiceAccountRequest: room selection failed"); - } - else { - viewerSession.Offer = jsepSdp; - viewerSession.OfferOrig = jsepSdp; - viewerSession.AgentId = pUserID; - if (await viewerSession.Room.JoinRoom(viewerSession).ConfigureAwait(false)) + // The client is sending an offer. Find the right room and join it. + // _log.DebugFormat("{0} ProvisionVoiceAccountRequest: jsep type={1} sdp={2}", LogHeader, jsepType, jsepSdp); + viewerSession.Room = await viewerSession.AudioBridge.SelectRoom(pSceneID.ToString(), + channel_type, isSpatial, parcel_local_id, channel_id).ConfigureAwait(false); + if (viewerSession.Room is null) { - ret = new OSDMap + errorMsg = "room selection failed"; + _log.Error($"{LogHeader} ProvisionVoiceAccountRequest: room selection failed"); + } + else { + viewerSession.Offer = jsepSdp; + viewerSession.OfferOrig = jsepSdp; + viewerSession.AgentId = pUserID; + if (await viewerSession.Room.JoinRoom(viewerSession).ConfigureAwait(false)) { - { "jsep", viewerSession.Answer }, - { "viewer_session", viewerSession.ViewerSessionID } - }; - } - else - { - errorMsg = "JoinRoom failed"; - _log.Error($"{LogHeader} ProvisionVoiceAccountRequest: JoinRoom failed"); + ret = new OSDMap + { + { "jsep", viewerSession.Answer }, + { "viewer_session", viewerSession.ViewerSessionID } + }; + } + else + { + errorMsg = "JoinRoom failed"; + _log.Error($"{LogHeader} ProvisionVoiceAccountRequest: JoinRoom failed"); + } } } + else + { + errorMsg = "jsep type not offer"; + _log.Error($"{LogHeader} ProvisionVoiceAccountRequest: jsep type={jsepType} not offer"); + } } - else + finally { - errorMsg = "jsep type not offer"; - _log.Error($"{LogHeader} ProvisionVoiceAccountRequest: jsep type={jsepType} not offer"); + viewerSession.ProvisionLock.Release(); } } else @@ -296,6 +401,11 @@ namespace osWebRtcVoice { "response", "failed" }, { "error", errorMsg } }; + _log.WarnFormat("{0} ProvisionVoiceAccountRequest: failed ({1}) error={2}", LogHeader, FlowTag(flowId, viewerSession), errorMsg); + } + else + { + _log.DebugFormat("{0} ProvisionVoiceAccountRequest: end ({1})", LogHeader, FlowTag(flowId, viewerSession)); } return ret; @@ -312,12 +422,13 @@ namespace osWebRtcVoice OSDMap ret = null; JanusViewerSession viewerSession = pSession as JanusViewerSession; JanusMessageResp resp = null; + long flowId = Interlocked.Increment(ref _VoiceFlowCounter); if (viewerSession is not null) { // The request should be an array of candidates if (pRequest.TryGetOSDMap("candidate", out OSDMap candidate)) { - if (candidate.TryGetBool("completed", out bool iscompleted) && iscompleted) + if (candidate.TryGetValue("completed", out OSD ocompleted) && ocompleted.AsBoolean()) { // The client has finished sending candidates resp = await viewerSession.Session.TrickleCompleted(viewerSession).ConfigureAwait(false); @@ -325,13 +436,29 @@ namespace osWebRtcVoice } else { + OSDArray candidatesArray = + [ + new OSDMap() + { + { "candidate", candidate.ContainsKey("candidate") ? candidate["candidate"].AsString() : String.Empty }, + { "sdpMid", candidate.ContainsKey("sdpMid") ? candidate["sdpMid"].AsString() : String.Empty }, + { "sdpMLineIndex", candidate.ContainsKey("sdpMLineIndex") ? candidate["sdpMLineIndex"].AsLong() : 0 } + } + ]; + resp = await viewerSession.Session.TrickleCandidates(viewerSession, candidatesArray); + _log.DebugFormat("{0} VoiceSignalingRequest: single candidate", LogHeader); } } else if (pRequest.TryGetOSDArray("candidates", out OSDArray candidates)) { - OSDArray candidatesArray = new OSDArray(); + OSDArray candidatesArray = []; + int sourceCount = candidates.Count; + int candidateLimit = _MaxSignalingCandidatesPerRequest; foreach (OSDMap cand in candidates) { + if (candidateLimit > 0 && candidatesArray.Count >= candidateLimit) + break; + candidatesArray.Add(new OSDMap() { { "candidate", cand["candidate"].AsString() }, { "sdpMid", cand["sdpMid"].AsString() }, @@ -339,7 +466,15 @@ namespace osWebRtcVoice }); } resp = await viewerSession.Session.TrickleCandidates(viewerSession, candidatesArray).ConfigureAwait(false); - _log.Debug($"{LogHeader} VoiceSignalingRequest: {candidatesArray.Count} candidates"); + if (candidateLimit > 0 && sourceCount > candidatesArray.Count) + { + _log.WarnFormat("{0} VoiceSignalingRequest: capped candidates {1}/{2} (MaxSignalingCandidatesPerRequest={3})", + LogHeader, candidatesArray.Count, sourceCount, candidateLimit); + } + else + { + _log.DebugFormat("{0} VoiceSignalingRequest: {1} candidates", LogHeader, candidatesArray.Count); + } } else { @@ -392,17 +527,41 @@ namespace osWebRtcVoice if (_Enabled) { MainConsole.Instance.Commands.AddCommand("Webrtc", false, "janus info", "janus info", - "Show Janus server information", + "Show Janus server information in human-readable form (use 'janus info json' for raw JSON)", HandleJanusInfo); + MainConsole.Instance.Commands.AddCommand("Webrtc", false, "janus show", + "janus show", + "Alias for 'janus info'", + HandleJanusShow); MainConsole.Instance.Commands.AddCommand("Webrtc", false, "janus list rooms", "janus list rooms", "List the rooms on the Janus server", HandleJanusListRooms); + MainConsole.Instance.Commands.AddCommand("Webrtc", false, "janus list sessions", + "janus list sessions", + "List active Janus sessions (admin API)", + HandleJanusListSessions); + MainConsole.Instance.Commands.AddCommand("Webrtc", false, "janus list", + "janus list", + "List Janus rooms and sessions (shortcut for diagnostics)", + HandleJanusList); + MainConsole.Instance.Commands.AddCommand("Webrtc", false, "janus room", + "janus room ", + "Show one room with participant details", + HandleJanusRoom); + // List rooms // List participants in a room } } + private void HandleJanusList(string module, string[] cmdparms) + { + WriteOut("janus list: showing rooms then sessions"); + HandleJanusListRooms(module, cmdparms); + HandleJanusListSessions(module, cmdparms); + } + private void HandleJanusInfo(string module, string[] cmdparms) { if (_ViewerSession is not null && _ViewerSession.Session is not null) @@ -410,10 +569,132 @@ namespace osWebRtcVoice WriteOut("{0} Janus session: {1}", LogHeader, _ViewerSession.Session.SessionId); string infoURI = _ViewerSession.Session.JanusServerURI + "/info"; - var resp = _ViewerSession.Session.GetFromJanus(infoURI).Result; - - if (resp is not null) - MainConsole.Instance.Output(resp.ToJson()); + JanusMessageResp resp = _ViewerSession.Session.GetFromJanus(infoURI).Result; + if (resp is null) + { + WriteOut("{0} Failed to query Janus /info", LogHeader); + return; + } + + bool requestJson = cmdparms is not null + && cmdparms.Length > 2 + && cmdparms[2].Equals("json", StringComparison.OrdinalIgnoreCase); + + resp = _ViewerSession.Session.GetFromJanus(infoURI).Result; + + if (requestJson) + { + MainConsole.Instance.Output(resp.ToJson()); + return; + } + + OSDMap info = resp.RawBody; + if (info is null || info.Count == 0) + { + WriteOut("{0} Janus /info returned no data", LogHeader); + return; + } + + PrintJanusInfo(info, "janus info json"); + } + } + + private void HandleJanusShow(string module, string[] cmdparms) + { + if (_ViewerSession is not null && _ViewerSession.Session is not null) + { + WriteOut("{0} Janus session: {1}", LogHeader, _ViewerSession.Session.SessionId); + string infoURI = _ViewerSession.Session.JanusServerURI + "/info"; + JanusMessageResp resp = _ViewerSession.Session.GetFromJanus(infoURI).Result; + if (resp is null) + { + WriteOut("{0} Failed to query Janus /info", LogHeader); + return; + } + + OSDMap info = resp.RawBody; + if (info is null || info.Count == 0) + { + WriteOut("{0} Janus /info returned no data", LogHeader); + return; + } + + PrintJanusInfo(info, "janus info json"); + } + } + + private void PrintJanusInfo(OSDMap info, string jsonHintCommand) + { + WriteOut(""); + WriteOut("Janus Server Info"); + WriteOut(" Name : {0}", GetMapString(info, "name")); + WriteOut(" Server Name : {0}", GetMapString(info, "server-name")); + WriteOut(" Version : {0} ({1})", GetMapString(info, "version_string"), GetMapString(info, "version")); + WriteOut(" Author : {0}", GetMapString(info, "author")); + WriteOut(" Local IP : {0}", GetMapString(info, "local-ip")); + WriteOut(" New Sessions : {0}", GetMapString(info, "accepting-new-sessions")); + + WriteOut(""); + WriteOut("Session / Timeouts"); + WriteOut(" session-timeout : {0}", GetMapString(info, "session-timeout")); + WriteOut(" reclaim-timeout : {0}", GetMapString(info, "reclaim-session-timeout")); + WriteOut(" candidates-time : {0}", GetMapString(info, "candidates-timeout")); + + WriteOut(""); + WriteOut("ICE / Network"); + WriteOut(" ice-lite : {0}", GetMapString(info, "ice-lite")); + WriteOut(" ice-tcp : {0}", GetMapString(info, "ice-tcp")); + WriteOut(" full-trickle : {0}", GetMapString(info, "full-trickle")); + WriteOut(" mdns-enabled : {0}", GetMapString(info, "mdns-enabled")); + WriteOut(" dtls-mtu : {0}", GetMapString(info, "dtls-mtu")); + + WriteOut(""); + WriteOut("Security"); + WriteOut(" api_secret : {0}", GetMapString(info, "api_secret")); + WriteOut(" auth_token : {0}", GetMapString(info, "auth_token")); + + WriteOut(""); + WriteOut("Transports"); + PrintNamedModuleMap(info, "transports"); + + WriteOut(""); + WriteOut("Plugins"); + PrintNamedModuleMap(info, "plugins"); + + WriteOut(""); + WriteOut("Tip: use '{0}' for full JSON output", jsonHintCommand); + } + + private static string GetMapString(OSDMap map, string key) + { + if (map is not null && map.TryGetValue(key, out OSD value) && value is not null) + { + return value.AsString(); + } + return "-"; + } + + private void PrintNamedModuleMap(OSDMap root, string key) + { + if (!root.TryGetValue(key, out OSD node) || node is not OSDMap entries || entries.Count == 0) + { + WriteOut(" (none)"); + return; + } + + foreach (string entryKey in entries.Keys) + { + OSD entryValue = entries[entryKey]; + if (entryValue is OSDMap detail) + { + string version = detail.TryGetValue("version_string", out OSD v) ? v.AsString() : "-"; + string name = detail.TryGetValue("name", out OSD n) ? n.AsString() : entryKey; + WriteOut(" - {0} [{1}]", name, version); + } + else + { + WriteOut(" - {0}", entryKey); + } } } @@ -421,16 +702,16 @@ namespace osWebRtcVoice { if (_ViewerSession is not null && _ViewerSession.Session is not null && _ViewerSession.AudioBridge is not null) { - var ab = _ViewerSession.AudioBridge; - var resp = ab.SendAudioBridgeMsg(new AudioBridgeListRoomsReq()).Result; + JanusAudioBridge ab = _ViewerSession.AudioBridge; + AudioBridgeResp resp = ab.SendAudioBridgeMsg(new AudioBridgeListRoomsReq()).Result; if (resp is not null && resp.isSuccess) { if (resp.PluginRespData.TryGetValue("list", out OSD list)) { MainConsole.Instance.Output(""); MainConsole.Instance.Output( - " {0,10} {1,15} {2,5} {3,10} {4,7} {5,7}", - "Room", "Description", "Num", "SampleRate", "Spatial", "Recording"); + " {0,10} {1,15} {2,5} {3,10} {4,7} {5,7} {6}", + "Room", "Description", "Num", "SampleRate", "Spatial", "Recording", "MappedSession"); foreach (OSDMap room in list as OSDArray) { int roomid = room["room"].AsInteger(); @@ -447,10 +728,14 @@ namespace osWebRtcVoice { foreach (OSDMap participant in participants as OSDArray) { - MainConsole.Instance.Output(" {0}/{1},muted={2},talking={3},pos={4}", - participant["id"].AsLong(), participant["display"], participant["muted"], - participant["talking"], participant["spatial_position"]); - } + long participantId = participant.TryGetValue("id", out OSD participantIdNode) + ? participantIdNode.AsLong() + : 0L; + string mapping = BuildParticipantMapping(participantId); + MainConsole.Instance.Output(" {0}/{1},muted={2},talking={3},pos={4} {5}", + participantId, participant["display"], participant["muted"], + participant["talking"], participant["spatial_position"], + string.IsNullOrEmpty(mapping) ? "mapped=" : mapping.Substring(2)); } } } } @@ -467,6 +752,166 @@ namespace osWebRtcVoice } } + private async void HandleJanusListSessions(string module, string[] cmdparms) + { + if (_ViewerSession is null || _ViewerSession.Session is null) + return; + + JanusMessageResp resp = await _ViewerSession.Session.SendToJanusAdmin(new JanusMessageReq("list_sessions")); + if (resp is null) + { + WriteOut("Failed to get sessions (no response)"); + return; + } + + if (!resp.isSuccess) + { + if (resp.isError) + { + ErrorResp err = new(resp); + WriteOut("Failed to get sessions: {0} ({1})", err.errorReason, err.errorCode); + } + else + { + WriteOut("Failed to get sessions: {0}", resp.ReturnCode); + } + return; + } + + OSD sessionsNode = null; + if (!resp.RawBody.TryGetValue("sessions", out sessionsNode) && resp.dataSection is not null) + { + resp.dataSection.TryGetValue("sessions", out sessionsNode); + } + + if (sessionsNode is not OSDArray sessions) + { + WriteOut("No sessions field in admin response"); + return; + } + + WriteOut("Active Janus sessions: {0}", sessions.Count); + foreach (OSD session in sessions) + { + string janusSessionId = session.AsLong().ToString(); + if (VoiceViewerSession.TryGetViewerSessionByVSSessionId(janusSessionId, out IVoiceViewerSession viewerSession)) + { + WriteOut(" - {0} viewer_session={1} agent={2} scene={3}", + janusSessionId, + viewerSession.ViewerSessionID, + viewerSession.AgentId, + viewerSession.RegionId); + } + else + { + WriteOut(" - {0}", janusSessionId); + } + } + } + + private async void HandleJanusRoom(string module, string[] cmdparms) + { + if (_ViewerSession is null || _ViewerSession.Session is null || _ViewerSession.AudioBridge is null) + return; + + if (cmdparms is null || cmdparms.Length < 3 || !int.TryParse(cmdparms[2], out int roomId)) + { + WriteOut("Usage: janus room "); + return; + } + + JanusAudioBridge ab = _ViewerSession.AudioBridge; + AudioBridgeResp roomsResp = await ab.SendAudioBridgeMsg(new AudioBridgeListRoomsReq()); + if (roomsResp is null || !roomsResp.isSuccess || roomsResp.PluginRespData is null) + { + WriteOut("Failed to get room list"); + return; + } + + if (!roomsResp.PluginRespData.TryGetValue("list", out OSD listNode) || listNode is not OSDArray roomList) + { + WriteOut("No rooms available"); + return; + } + + OSDMap foundRoom = null; + foreach (OSDMap room in roomList) + { + if (room is not null && room.TryGetValue("room", out OSD roomOsd) && roomOsd.AsInteger() == roomId) + { + foundRoom = room; + break; + } + } + + if (foundRoom is null) + { + WriteOut("Room {0} not found", roomId); + return; + } + + WriteOut(""); + WriteOut("Room {0}", roomId); + WriteOut(" Description : {0}", GetMapString(foundRoom, "description")); + WriteOut(" Participants: {0}", GetMapString(foundRoom, "num_participants")); + WriteOut(" SampleRate : {0}", GetMapString(foundRoom, "sampling_rate")); + WriteOut(" Spatial : {0}", GetMapString(foundRoom, "spatial_audio")); + WriteOut(" Recording : {0}", GetMapString(foundRoom, "record")); + + AudioBridgeResp participantResp = await ab.SendAudioBridgeMsg(new AudioBridgeListParticipantsReq(roomId)); + if (participantResp is null || participantResp.PluginRespData is null || + !participantResp.PluginRespData.TryGetValue("participants", out OSD participantsNode) || + participantsNode is not OSDArray participants) + { + WriteOut(" Participant list not available"); + return; + } + + WriteOut(" Participant details:"); + if (participants.Count == 0) + { + WriteOut(" (none)"); + return; + } + + foreach (OSDMap participant in participants) + { + long participantId = participant.TryGetValue("id", out OSD participantIdNode) + ? participantIdNode.AsLong() + : 0L; + string mapping = BuildParticipantMapping(participantId); + WriteOut(" - {0}/{1}, muted={2}, talking={3}, pos={4}{5}", + participantId, + GetMapString(participant, "display"), + GetMapString(participant, "muted"), + GetMapString(participant, "talking"), + GetMapString(participant, "spatial_position"), + mapping); + } + } + + private static string BuildParticipantMapping(long participantId) + { + if (participantId <= 0) + return ""; + + lock (VoiceViewerSession.ViewerSessions) + { + foreach (KeyValuePair entry in VoiceViewerSession.ViewerSessions) + { + if (entry.Value is JanusViewerSession janusViewerSession && janusViewerSession.ParticipantId == participantId) + { + return string.Format(", viewer_session={0}, agent={1}, scene={2}", + entry.Key, + entry.Value.AgentId, + entry.Value.RegionId); + } + } + } + + return ""; + } + private void WriteOut(string msg, params object[] args) { // m_log.InfoFormat(msg, args); diff --git a/bin/config/os-webrtc-janus.ini.example b/bin/config/os-webrtc-janus.ini.example index 02eaaee67f..cdd62c6755 100644 --- a/bin/config/os-webrtc-janus.ini.example +++ b/bin/config/os-webrtc-janus.ini.example @@ -20,7 +20,7 @@ ; APIKey to access the Janus Gateway. Must be set to the same value as the Janus Gateway. APIToken = APITokenToNeverCheckIn ; URI to access the admin port on Janus Gateway - JanusGatewayAdminURI = http://janus.example.org/admin + JanusGatewayAdminURI = http://janus.example.org:14224/admin ; APIKey to access the admin port on the Janus Gateway. Must be set to the same value as the Janus Gateway. AdminAPIToken = AdminAPITokenToNeverCheckIn ; Debugging: output to log file messages sent and received from Janus. Very verbose.