diff --git a/OpenSim/Framework/RestClient.cs b/OpenSim/Framework/RestClient.cs index b89160f7e2..66031a851f 100644 --- a/OpenSim/Framework/RestClient.cs +++ b/OpenSim/Framework/RestClient.cs @@ -259,6 +259,7 @@ namespace OpenSim.Framework HttpResponseMessage responseMessage = null; HttpRequestMessage request = null; HttpClient client = null; + bool bodyTimedOut = false; try { client = WebUtil.GetNewGlobalHttpClient(DefaultTimeout); @@ -286,15 +287,24 @@ namespace OpenSim.Framework responseMessage = client.Send(request, HttpCompletionOption.ResponseHeadersRead); responseMessage.EnsureSuccessStatusCode(); - using CancellationTokenSource cts = new(30000); - using Stream respStream = responseMessage.Content.ReadAsStream(cts.Token); - int length = respStream.Read(_readbuf, 0, BufferSize); - while (length > 0) + using Stream respStream = responseMessage.Content.ReadAsStream(); + using(CancellationTokenSource cts = new(WebUtil.EstimatedReceiveTimeout(responseMessage.Content.Headers, true))) { - _resource.Write(_readbuf, 0, length); - length = respStream.Read(_readbuf, 0, BufferSize); + _ = cts.Token.Register(() => + { + bodyTimedOut = true; + respStream?.Close(); + }); + + int length = respStream.Read(_readbuf, 0, BufferSize); + while (length > 0) + { + _resource.Write(_readbuf, 0, length); + length = respStream.Read(_readbuf, 0, BufferSize); + } } } + catch (HttpRequestException e) { if(uri is not null) @@ -335,6 +345,9 @@ namespace OpenSim.Framework _resource.Seek(0, SeekOrigin.Begin); } + if (bodyTimedOut) + m_log.Error($"[REST CLIENT] Data receive timeout from: {uri}"); + if (WebUtil.DebugLevel >= 5) WebUtil.LogOutgoingDetail("[REST CLIENT]", _resource); @@ -372,7 +385,7 @@ namespace OpenSim.Framework request.Content.Headers.TryAddWithoutValidation("Content-Type", "application/xml"); request.Content.Headers.TryAddWithoutValidation("Content-Length", src.Length.ToString()); - responseMessage = client.Send(request, HttpCompletionOption.ResponseContentRead); + responseMessage = client.Send(request, HttpCompletionOption.ResponseHeadersRead); responseMessage.EnsureSuccessStatusCode(); } catch (HttpRequestException e) diff --git a/OpenSim/Framework/Util.cs b/OpenSim/Framework/Util.cs index 7c0c5f90a7..d7f6ad69c0 100644 --- a/OpenSim/Framework/Util.cs +++ b/OpenSim/Framework/Util.cs @@ -280,12 +280,24 @@ namespace OpenSim.Framework return UTF8.GetBytes(s); } + [MethodImpl(MethodImplOptions.AggressiveInlining)] + public static byte[] UTF8Getbytes(string s, int len) + { + return UTF8.GetBytes(s, 0, len); + } + [MethodImpl(MethodImplOptions.AggressiveInlining)] public static byte[] UTF8NBGetbytes(string s) { return UTF8NoBomEncoding.GetBytes(s); } + [MethodImpl(MethodImplOptions.AggressiveInlining)] + public static byte[] UTF8NBGetbytes(string s, int len) + { + return UTF8NoBomEncoding.GetBytes(s, 0 , len); + } + /// /// Well known UUID for the blank texture used in the Linden SL viewer version 1.20 (and hopefully onwards) /// diff --git a/OpenSim/Framework/WebUtil.cs b/OpenSim/Framework/WebUtil.cs index 0d4f3cc459..ad66364351 100644 --- a/OpenSim/Framework/WebUtil.cs +++ b/OpenSim/Framework/WebUtil.cs @@ -33,9 +33,13 @@ using System.Globalization; using System.IO; using System.IO.Compression; using System.Net; +using System.Net.Http; +using System.Net.Http.Headers; using System.Net.Security; +using System.Security.Authentication; using System.Security.Cryptography.X509Certificates; using System.Reflection; +using System.Runtime.CompilerServices; using System.Text; using System.Threading; using System.Web; @@ -46,9 +50,6 @@ using log4net; using Nwc.XmlRpc; using OpenMetaverse.StructuredData; using OpenSim.Framework.ServiceAuth; -using System.Net.Http; -using System.Security.Authentication; -using System.Runtime.CompilerServices; namespace OpenSim.Framework { @@ -265,39 +266,6 @@ namespace OpenSim.Framework return client; } - /// - /// PUT JSON-encoded data to a web service that returns LLSD or - /// JSON data - /// - [MethodImpl(MethodImplOptions.AggressiveInlining)] - public static OSDMap PutToServiceCompressed(string url, OSDMap data, int timeout) - { - return ServiceOSDRequest(url, data, "PUT", timeout, true, false); - } - - [MethodImpl(MethodImplOptions.AggressiveInlining)] - public static OSDMap PutToService(string url, OSDMap data, int timeout) - { - return ServiceOSDRequest(url, data, "PUT", timeout, false, false); - } - - [MethodImpl(MethodImplOptions.AggressiveInlining)] - public static OSDMap PostToService(string url, OSDMap data, int timeout, bool rpc) - { - return ServiceOSDRequest(url, data, "POST", timeout, false, rpc); - } - - [MethodImpl(MethodImplOptions.AggressiveInlining)] - public static OSDMap PostToServiceCompressed(string url, OSDMap data, int timeout) - { - return ServiceOSDRequest(url, data, "POST", timeout, true, false); - } - - [MethodImpl(MethodImplOptions.AggressiveInlining)] - public static OSDMap GetFromService(string url, int timeout) - { - return ServiceOSDRequest(url, null, "GET", timeout, false, false); - } [MethodImpl(MethodImplOptions.AggressiveInlining)] public static void LogOutgoingDetail(Stream outputStream) @@ -334,13 +302,10 @@ namespace OpenSim.Framework [MethodImpl(MethodImplOptions.AggressiveInlining)] public static void LogOutgoingDetail(string context, string output) { - if (DebugLevel >= 5) - { - if (output.Length > MaxRequestDiagLength) - output = output[..MaxRequestDiagLength] + "..."; - } - - m_log.Debug($"[LOGHTTP]: {context} {Util.BinaryToASCII(output)}"); + if (DebugLevel >= 5 && output.Length > MaxRequestDiagLength) + m_log.Debug($"[LOGHTTP]: {context} {Util.BinaryToASCII(output[..MaxRequestDiagLength])}"); + else + m_log.Debug($"[LOGHTTP]: {context} {Util.BinaryToASCII(output)}"); } [MethodImpl(MethodImplOptions.AggressiveInlining)] @@ -355,6 +320,56 @@ namespace OpenSim.Framework LogOutgoingDetail($"RESPONSE {reqnum}: ", input); } + /// + /// PUT JSON-encoded data to a web service that returns LLSD or + /// JSON data + /// + [MethodImpl(MethodImplOptions.AggressiveInlining)] + public static OSDMap PutToServiceCompressed(string url, OSDMap data, int timeout) + { + return ServiceOSDRequest(url, data, "PUT", timeout, true, false); + } + + [MethodImpl(MethodImplOptions.AggressiveInlining)] + public static OSDMap PutToService(string url, OSDMap data, int timeout) + { + return ServiceOSDRequest(url, data, "PUT", timeout, false, false); + } + + public static int EstimatedReceiveTimeout(HttpContentHeaders headers, bool keepalive) + { + if (headers.ContentLength is long contentLength) + { + int t = (int)(contentLength/1024L); + if( t > 55000) + return 60000; + return t + 5000; + } + if(keepalive) // this is ilegal without contentlenght + { + return 5000; + } + return 30000; + } + + [MethodImpl(MethodImplOptions.AggressiveInlining)] + public static OSDMap PostToService(string url, OSDMap data, int timeout, bool rpc) + { + return ServiceOSDRequest(url, data, "POST", timeout, false, rpc); + } + + [MethodImpl(MethodImplOptions.AggressiveInlining)] + public static OSDMap PostToServiceCompressed(string url, OSDMap data, int timeout) + { + return ServiceOSDRequest(url, data, "POST", timeout, true, false); + } + + [MethodImpl(MethodImplOptions.AggressiveInlining)] + public static OSDMap GetFromService(string url, int timeout) + { + return ServiceOSDRequest(url, null, "GET", timeout, false, false); + } + public static OSDMap ServiceOSDRequest(string url, OSDMap data, string method, int timeout, bool compressed, bool rpc, bool keepalive = false) { int reqnum = RequestNumber++; @@ -367,6 +382,7 @@ namespace OpenSim.Framework int sendlen = 0; int rcvlen = 0; + bool bodyTimedOut = false; HttpResponseMessage responseMessage = null; HttpRequestMessage request = null; HttpClient client = null; @@ -425,14 +441,21 @@ namespace OpenSim.Framework responseMessage = client.Send(request, HttpCompletionOption.ResponseHeadersRead); responseMessage.EnsureSuccessStatusCode(); - using CancellationTokenSource cts = new(30000); - Stream resStream = responseMessage.Content.ReadAsStream(cts.Token); + Stream resStream = responseMessage.Content.ReadAsStream(); if (resStream is not null) { + string responseStr; using StreamReader reader = new(resStream); - string responseStr = reader.ReadToEnd(); - if (WebUtil.DebugLevel >= 5) - WebUtil.LogResponseDetail(reqnum, responseStr); + using (CancellationTokenSource cts = new(EstimatedReceiveTimeout(responseMessage.Content.Headers,keepalive))) + { + _ = cts.Token.Register(() => + { + bodyTimedOut = true; + resStream?.Close(); + }); + responseStr = reader.ReadToEnd(); + } + if (DebugLevel >= 5) LogResponseDetail(reqnum, responseStr); rcvlen = responseStr.Length; return CanonicalizeResults(responseStr); } @@ -454,7 +477,11 @@ namespace OpenSim.Framework client?.Dispose(); ticks = Util.EnvironmentTickCountSubtract(ticks); - if (ticks > LongCallTime) + if(bodyTimedOut) + { + errorMessage = $"[WEB UTIL]: receive timeout {reqnum} {method} {url} ({ticks}ms); " + errorMessage; + } + else if (ticks > LongCallTime) { m_log.Info($"[WEB UTIL]: SvcOSD {reqnum} {method} {url} took {ticks}ms, {sendlen}/{rcvlen}bytes"); } @@ -477,25 +504,29 @@ namespace OpenSim.Framework /// _RawResult == the raw string that came back /// _Result == the OSD unpacked string /// + [MethodImpl(MethodImplOptions.AggressiveInlining)] private static OSDMap CanonicalizeResults(string response) { - OSDMap result = new() - { - // Default values - ["Success"] = OSD.FromBoolean(true), - ["success"] = OSD.FromBoolean(true), - ["_RawResult"] = OSD.FromString(response), - ["_Result"] = new OSDMap() - }; - if (response.Equals("true", StringComparison.OrdinalIgnoreCase)) - return result; + { + return new OSDMap() + { + ["Success"] = OSD.FromBoolean(true), + ["success"] = OSD.FromBoolean(true), + ["_RawResult"] = OSD.FromString(response), + ["_Result"] = new OSDMap() + }; + } if (response.Equals("false", StringComparison.OrdinalIgnoreCase)) { - result["Success"] = OSD.FromBoolean(false); - result["success"] = OSD.FromBoolean(false); - return result; + return new OSDMap() + { + ["Success"] = OSD.FromBoolean(false), + ["success"] = OSD.FromBoolean(false), + ["_RawResult"] = OSD.FromString(response), + ["_Result"] = new OSDMap() + }; } try @@ -503,8 +534,13 @@ namespace OpenSim.Framework OSD responseOSD = OSDParser.Deserialize(response); if (responseOSD.Type == OSDType.Map) { - result["_Result"] = (OSDMap)responseOSD; - return result; + return new OSDMap() + { + ["Success"] = OSD.FromBoolean(true), + ["success"] = OSD.FromBoolean(true), + ["_RawResult"] = OSD.FromString(response), + ["_Result"] = (OSDMap)responseOSD + }; } } catch @@ -513,7 +549,13 @@ namespace OpenSim.Framework //m_log.DebugFormat("[WEB UTIL] couldn't decode <{0}>: {1}",response,e.Message); } - return result; + return new OSDMap() + { + ["Success"] = OSD.FromBoolean(true), + ["success"] = OSD.FromBoolean(true), + ["_RawResult"] = OSD.FromString(response), + ["_Result"] = new OSDMap() + }; } #endregion JSONRequest @@ -542,6 +584,7 @@ namespace OpenSim.Framework int sendlen = 0; int rcvlen = 0; + bool bodyTimedOut = false; HttpResponseMessage responseMessage = null; HttpRequestMessage request = null; HttpClient client = null; @@ -553,16 +596,7 @@ namespace OpenSim.Framework request.Headers.ExpectContinue = false; request.Headers.TransferEncodingChunked = false; - - //if (keepalive) - //{ - // request.Headers.TryAddWithoutValidation("Keep-Alive", "timeout=30, max=10"); - // request.Headers.TryAddWithoutValidation("Connection", "Keep-Alive"); - // request.Headers.ConnectionClose = false; - //} - //else - request.Headers.TryAddWithoutValidation("Connection", "close"); - + request.Headers.TryAddWithoutValidation("Connection", "close"); request.Headers.TryAddWithoutValidation(OSHeaderRequestID, reqnum.ToString()); if (data is not null) @@ -572,7 +606,7 @@ namespace OpenSim.Framework if (DebugLevel >= 5) LogOutgoingDetail("SEND", reqnum, queryString); - byte[] buffer = System.Text.Encoding.UTF8.GetBytes(queryString); + byte[] buffer = Encoding.UTF8.GetBytes(queryString); queryString = null; sendlen = buffer.Length; @@ -591,9 +625,18 @@ namespace OpenSim.Framework responseMessage = client.Send(request, HttpCompletionOption.ResponseHeadersRead); responseMessage.EnsureSuccessStatusCode(); - using CancellationTokenSource cts = new(30000); - using StreamReader reader = new(responseMessage.Content.ReadAsStream(cts.Token)); - string responseStr = reader.ReadToEnd(); + string responseStr; + Stream str = responseMessage.Content.ReadAsStream(); + using StreamReader reader = new(str); + using(CancellationTokenSource cts = new(EstimatedReceiveTimeout(responseMessage.Content.Headers,false))) + { + _ = cts.Token.Register(() => + { + bodyTimedOut = true; + str?.Close(); + }); + responseStr = reader.ReadToEnd(); + } rcvlen = responseStr.Length; if (DebugLevel >= 5) LogResponseDetail(reqnum, responseStr); @@ -620,7 +663,11 @@ namespace OpenSim.Framework client?.Dispose(); ticks = Util.EnvironmentTickCountSubtract(ticks); - if (ticks > LongCallTime) + if(bodyTimedOut) + { + errorMessage = $"[LOGHTTP] Data receive timeout {reqnum} '{method}' to {url} ({ticks}ms); " + errorMessage; + } + else if (ticks > LongCallTime) { m_log.Info( $"[LOGHTTP]: Slow ServiceForm request {reqnum} '{method}' to {url} took {ticks}ms, {sendlen}/{rcvlen}bytes"); @@ -665,17 +712,16 @@ namespace OpenSim.Framework /// This is similar to the Uri constructor that takes a base /// Uri and the relative path, except this method can append a relative /// path fragment on to an existing relative path - public static Uri Combine(this Uri uri, string fragment) + public static Uri Combine(Uri uri, string fragment) { string fragment1 = uri.Fragment; - string fragment2 = fragment; if (!fragment1.EndsWith('/')) fragment1 += '/'; - if (fragment2.StartsWith('/')) - fragment2 = fragment2[1..]; + if (fragment.StartsWith('/')) + fragment = fragment[1..]; - return new Uri(uri, fragment1 + fragment2); + return new Uri(uri, fragment1 + fragment); } /// @@ -687,7 +733,7 @@ namespace OpenSim.Framework /// Relative path fragment to append to the end /// of the Uri, or an absolute Uri to return unmodified /// The combined Uri - public static Uri Combine(this Uri uri, Uri fragment) + public static Uri Combine(Uri uri, Uri fragment) { if (fragment.IsAbsoluteUri) return fragment; @@ -1154,6 +1200,8 @@ namespace OpenSim.Framework string respstring = string.Empty; int sendlen = 0; int rcvlen = 0; + bool bodyTimedOut = false; + try { client = WebUtil.GetNewGlobalHttpClient(timeoutsecs * 1000); @@ -1182,7 +1230,7 @@ namespace OpenSim.Framework sendlen = data.Length; if (WebUtil.DebugLevel >= 5) - WebUtil.LogOutgoingDetail("SEND", reqnum, System.Text.Encoding.UTF8.GetString(data)); + WebUtil.LogOutgoingDetail("SEND", reqnum, Encoding.UTF8.GetString(data)); request.Content = new ByteArrayContent(data); request.Content.Headers.TryAddWithoutValidation("Content-Type", "application/x-www-form-urlencoded"); @@ -1194,15 +1242,26 @@ namespace OpenSim.Framework if ((responseMessage.Content.Headers.ContentLength is long contentLength) && contentLength != 0) { - using CancellationTokenSource cts = new(30000); - using StreamReader reader = new(responseMessage.Content.ReadAsStream(cts.Token)); - respstring = reader.ReadToEnd(); + Stream str = responseMessage.Content.ReadAsStream(); + using StreamReader reader = new(str); + using (CancellationTokenSource cts = new(WebUtil.EstimatedReceiveTimeout(responseMessage.Content.Headers, keepalive))) + { + _ = cts.Token.Register(() => + { + bodyTimedOut = true; + str?.Close(); + }); + respstring = reader.ReadToEnd(); + } rcvlen = respstring.Length; } } catch (Exception e) { - m_log.Info($"[FORMS]: Error receiving response from {requestUrl}: {e.Message}"); + if(bodyTimedOut) + m_log.Info($"[FORMS]: request {reqnum} {method} {requestUrl} receive timeout"); + else + m_log.Info($"[FORMS]: Error receiving response from {requestUrl}: {e.Message}"); throw; } finally @@ -1213,7 +1272,11 @@ namespace OpenSim.Framework } ticks = Util.EnvironmentTickCountSubtract(ticks); - if (ticks > WebUtil.LongCallTime) + if(bodyTimedOut) + { + m_log.Info($"[FORMS]: request {reqnum} {method} {requestUrl} receive timeout ({ticks}ms)"); + } + else if (ticks > WebUtil.LongCallTime) { m_log.Info($"[FORMS]: request {reqnum} {method} {requestUrl} took {ticks}ms, {sendlen}/{rcvlen}bytes"); } @@ -1248,6 +1311,8 @@ namespace OpenSim.Framework string respstring = String.Empty; int sendlen = 0; int rcvlen = 0; + bool bodyTimedOut = false; + try { client = WebUtil.GetNewGlobalHttpClient(timeoutsecs * 1000); @@ -1274,20 +1339,31 @@ namespace OpenSim.Framework request.Content.Headers.TryAddWithoutValidation("Content-Length", sendlen.ToString()); if (WebUtil.DebugLevel >= 5) - WebUtil.LogOutgoingDetail("SEND", reqnum, System.Text.Encoding.UTF8.GetString(data)); + WebUtil.LogOutgoingDetail("SEND", reqnum, Encoding.UTF8.GetString(data)); responseMessage = client.Send(request, HttpCompletionOption.ResponseHeadersRead); if ((responseMessage.Content.Headers.ContentLength is long contentLength) && contentLength != 0) { - using CancellationTokenSource cts = new(30000); - using StreamReader reader = new(responseMessage.Content.ReadAsStream(cts.Token)); - respstring = reader.ReadToEnd(); + Stream str = responseMessage.Content.ReadAsStream(); + using StreamReader reader = new(str); + using (CancellationTokenSource cts = new(WebUtil.EstimatedReceiveTimeout(responseMessage.Content.Headers, keepalive))) + { + _ = cts.Token.Register(() => + { + bodyTimedOut = true; + str?.Close(); + }); + respstring = reader.ReadToEnd(); + } } } catch (Exception e) { - m_log.Info($"[FORMS]: Error receiving response from {requestUrl}: {e.Message}"); + if(bodyTimedOut) + m_log.Info($"[FORMS]: request {reqnum} POST {requestUrl} receive timeout"); + else + m_log.Info($"[FORMS]: Error receiving response from {requestUrl}: {e.Message}"); throw; } finally @@ -1298,7 +1374,9 @@ namespace OpenSim.Framework } ticks = Util.EnvironmentTickCountSubtract(ticks); - if (ticks > WebUtil.LongCallTime) + if(bodyTimedOut) + m_log.Info($"[FORMS]: request {reqnum} POST {requestUrl} receive timeout ({ticks}ms)"); + else if (ticks > WebUtil.LongCallTime) { m_log.Info($"[FORMS]: request {reqnum} POST {requestUrl} took {ticks}ms {sendlen}/{rcvlen}bytes"); } @@ -1381,6 +1459,7 @@ namespace OpenSim.Framework HttpResponseMessage responseMessage = null; HttpRequestMessage request = null; HttpClient client = null; + bool bodyTimedOut = false; try { @@ -1424,7 +1503,7 @@ namespace OpenSim.Framework request.Content.Headers.TryAddWithoutValidation("Content-Length", sendlen.ToString()); } - responseMessage = client.Send(request, HttpCompletionOption.ResponseContentRead); + responseMessage = client.Send(request, HttpCompletionOption.ResponseHeadersRead); responseMessage.EnsureSuccessStatusCode(); int rcvlen = 0; @@ -1432,8 +1511,16 @@ namespace OpenSim.Framework { rcvlen = (int)contentLength; using Stream respStream = responseMessage.Content.ReadAsStream(); - deserial = XMLResponseHelper.LogAndDeserialize( - reqnum, respStream, contentLength); + using (CancellationTokenSource cts = new(WebUtil.EstimatedReceiveTimeout(responseMessage.Content.Headers, true))) + { + _ = cts.Token.Register(() => + { + bodyTimedOut = true; + respStream?.Close(); + }); + deserial = XMLResponseHelper.LogAndDeserialize( + reqnum, respStream, contentLength); + } } else { @@ -1441,7 +1528,11 @@ namespace OpenSim.Framework } ticks = Util.EnvironmentTickCountSubtract(ticks); - if (ticks > WebUtil.LongCallTime) + if(bodyTimedOut) + { + m_log.Info($"[LOGHTTP]: receive timeout {reqnum} {method} {requestUrl} ({ticks}ms)"); + } + else if (ticks > WebUtil.LongCallTime) { m_log.Info($"[LOGHTTP]: Slow SRestObjReq {reqnum} {method} {requestUrl} took {ticks}ms, {rcvlen}bytes"); } @@ -1475,7 +1566,10 @@ namespace OpenSim.Framework } catch (Exception e) { - m_log.Debug($"[SRestObjReq]: Exception on response from {method} {requestUrl}: {e.Message}"); + if(bodyTimedOut) + m_log.Info($"[LOGHTTP]: receive timeout {reqnum} {method} {requestUrl}"); + else + m_log.Debug($"[SRestObjReq]: Exception on response from {method} {requestUrl}: {e.Message}"); } finally { @@ -1490,7 +1584,6 @@ namespace OpenSim.Framework public static TResponse MakeGetRequest(string requestUrl, int pTimeout, IServiceAuth auth) { int reqnum = WebUtil.RequestNumber++; - if (WebUtil.DebugLevel >= 3) m_log.Debug($"[LOGHTTP]: HTTP OUT {reqnum} SRestObjReq GET {requestUrl}"); @@ -1499,6 +1592,7 @@ namespace OpenSim.Framework HttpResponseMessage responseMessage = null; HttpRequestMessage request = null; HttpClient client = null; + bool bodyTimedOut = false; try { client = WebUtil.GetNewGlobalHttpClient(pTimeout); @@ -1518,7 +1612,7 @@ namespace OpenSim.Framework //else // request.Headers.TryAddWithoutValidation("Connection", "close"); - responseMessage = client.Send(request, HttpCompletionOption.ResponseContentRead); + responseMessage = client.Send(request, HttpCompletionOption.ResponseHeadersRead); responseMessage.EnsureSuccessStatusCode(); int rcvlen = 0; @@ -1526,8 +1620,16 @@ namespace OpenSim.Framework { rcvlen = (int)contentLength; using Stream respStream = responseMessage.Content.ReadAsStream(); - deserial = XMLResponseHelper.LogAndDeserialize( - reqnum, respStream, contentLength); + using (CancellationTokenSource cts = new(WebUtil.EstimatedReceiveTimeout(responseMessage.Content.Headers, true))) + { + _ = cts.Token.Register(() => + { + bodyTimedOut = true; + respStream?.Close(); + }); + deserial = XMLResponseHelper.LogAndDeserialize( + reqnum, respStream, contentLength); + } } else { @@ -1535,7 +1637,11 @@ namespace OpenSim.Framework } ticks = Util.EnvironmentTickCountSubtract(ticks); - if (ticks > WebUtil.LongCallTime) + if(bodyTimedOut) + { + m_log.Info($"[SRestObjReq]: GET receive timeout {reqnum} {requestUrl} ({ticks}ms)"); + } + else if (ticks > WebUtil.LongCallTime) { m_log.Info($"[LOGHTTP]: Slow SRestObjReq GET {reqnum} {requestUrl} took {ticks}ms, {rcvlen}bytes"); } @@ -1567,7 +1673,10 @@ namespace OpenSim.Framework } catch (Exception e) { - m_log.Debug($"[SRestObjReq]: Exception on response from GET {requestUrl}: {e.Message}"); + if(bodyTimedOut) + m_log.Debug($"[SRestObjReq]: GET receive timeout {reqnum} {requestUrl}"); + else + m_log.Debug($"[SRestObjReq]: Exception on response from GET {requestUrl}: {e.Message}"); } finally { @@ -1614,7 +1723,7 @@ namespace OpenSim.Framework } dataBuffer = ms.ToArray(); - WebUtil.LogResponseDetail(reqnum, System.Text.Encoding.UTF8.GetString(dataBuffer)); + WebUtil.LogResponseDetail(reqnum, Encoding.UTF8.GetString(dataBuffer)); ms.Position = 0; return (TResponse)deserializer.Deserialize(ms); diff --git a/OpenSim/Region/CoreModules/Scripting/HttpRequest/ScriptsHttpRequests.cs b/OpenSim/Region/CoreModules/Scripting/HttpRequest/ScriptsHttpRequests.cs index 0d477b13a0..520ad07064 100644 --- a/OpenSim/Region/CoreModules/Scripting/HttpRequest/ScriptsHttpRequests.cs +++ b/OpenSim/Region/CoreModules/Scripting/HttpRequest/ScriptsHttpRequests.cs @@ -595,11 +595,14 @@ namespace OpenSim.Region.CoreModules.Scripting.HttpRequest if (Removed) return; + bool bodyTimedOut = false; HttpResponseMessage responseMessage = null; HttpRequestMessage request = null; + HttpClient client = null; + try { - HttpClient client = RequestModule.GetHttpClient(HttpVerifyCert); + client = RequestModule.GetHttpClient(HttpVerifyCert); request = new (new HttpMethod(HttpMethod), Url); int datalen; @@ -644,26 +647,35 @@ namespace OpenSim.Region.CoreModules.Scripting.HttpRequest else len = -1; - using CancellationTokenSource cts = new(30000); - Stream resStream = responseMessage.Content.ReadAsStream(cts.Token); + using Stream resStream = responseMessage.Content.ReadAsStream(); if(resStream is not null) { - int maxBytes = (len < 0 || len > HttpBodyMaxLen) ? HttpBodyMaxLen : len; - byte[] buf = new byte[maxBytes]; - int totalBodyBytes = 0; - int count; - do - { - count = resStream.Read(buf, totalBodyBytes, maxBytes - totalBodyBytes); - totalBodyBytes += count; - } while (count > 0 && totalBodyBytes < maxBytes); // any more data to read? - resStream.Dispose(); + byte[] buf; - if (totalBodyBytes > 0) + using(CancellationTokenSource cts = new(WebUtil.EstimatedReceiveTimeout(responseMessage.Content.Headers, false))) + { + _ = cts.Token.Register(() => + { + bodyTimedOut = true; + resStream?.Close(); + }); + + int maxBytes = (len < 0 || len > HttpBodyMaxLen) ? HttpBodyMaxLen : len; + buf = new byte[maxBytes]; + + int count; + do + { + count = resStream.Read(buf, totalBodyBytes, maxBytes - totalBodyBytes); + totalBodyBytes += count; + } while (count > 0 && totalBodyBytes < maxBytes && !Removed); // any more data to read? + } + + if (!Removed && totalBodyBytes > 0) { string tempString = Util.UTF8.GetString(buf, 0, totalBodyBytes); - ResponseBody = tempString.Replace("\r", ""); + ResponseBody = tempString.ReplaceLineEndings("\n"); } } } @@ -682,8 +694,16 @@ namespace OpenSim.Region.CoreModules.Scripting.HttpRequest { if (!Removed) { + if(bodyTimedOut) + { + Status = 408; + + ResponseBody = "Request timeout"; + RequestModule.GotCompletedRequest(this); + } + // We need to resubmit ? - if (Status == (int)HttpStatusCode.MovedPermanently || + else if (Status == (int)HttpStatusCode.MovedPermanently || Status == (int)HttpStatusCode.Found || Status == (int)HttpStatusCode.SeeOther || Status == (int)HttpStatusCode.TemporaryRedirect) @@ -757,8 +777,10 @@ namespace OpenSim.Region.CoreModules.Scripting.HttpRequest RequestModule.GotCompletedRequest(this); } } + responseMessage?.Dispose(); - request.Dispose(); + request?.Dispose(); + client?.Dispose(); } } diff --git a/OpenSim/Services/Connectors/Inventory/XInventoryServicesConnector.cs b/OpenSim/Services/Connectors/Inventory/XInventoryServicesConnector.cs index e6c38aaba0..269569b736 100644 --- a/OpenSim/Services/Connectors/Inventory/XInventoryServicesConnector.cs +++ b/OpenSim/Services/Connectors/Inventory/XInventoryServicesConnector.cs @@ -34,9 +34,11 @@ using OpenSim.Server.Base; using OpenSim.Services.Interfaces; using System; using System.Collections.Generic; +using System.IO; using System.Net.Http; using System.Reflection; using System.Text; +using System.Threading; using System.Web; namespace OpenSim.Services.Connectors @@ -747,7 +749,7 @@ namespace OpenSim.Services.Connectors if (string.IsNullOrEmpty(obj)) { m_log.Warn($"[XInventory]: empty post data"); - return new Dictionary(); + return []; } Dictionary respDic = null; @@ -757,6 +759,8 @@ namespace OpenSim.Services.Connectors HttpResponseMessage responseMessage = null; HttpRequestMessage request = null; HttpClient client = null; + bool bodyTimedOut = false; + try { client = WebUtil.GetNewGlobalHttpClient(m_requestTimeout); @@ -789,13 +793,26 @@ namespace OpenSim.Services.Connectors if ((responseMessage.Content.Headers.ContentLength is long contentLength) && contentLength != 0) { - rcvlen = (int)contentLength; - respDic = ServerUtils.ParseXmlResponse(responseMessage.Content.ReadAsStream()); + using Stream respStream = responseMessage.Content.ReadAsStream(); + using (CancellationTokenSource cts = new(WebUtil.EstimatedReceiveTimeout(responseMessage.Content.Headers, true))) + { + _ = cts.Token.Register(() => + { + bodyTimedOut = true; + respStream?.Close(); + }); + + rcvlen = (int)contentLength; + respDic = ServerUtils.ParseXmlResponse(respStream); + } } } catch (Exception e) { - m_log.Info($"[XInventory]: Error receiving response from {m_InventoryURL}: {e.Message}"); + if(bodyTimedOut) + m_log.Info($"[XInventory]: TImeout on receiving POST response from {m_InventoryURL}"); + else + m_log.Info($"[XInventory]: Error receiving response from {m_InventoryURL}: {e.Message}"); throw; } finally @@ -806,7 +823,11 @@ namespace OpenSim.Services.Connectors } ticks = Util.EnvironmentTickCountSubtract(ticks); - if (ticks > WebUtil.LongCallTime) + if(bodyTimedOut) + { + m_log.Info($"[XInventory]: POST receive timeout {m_InventoryURL} ({ticks}ms)"); + } + else if (ticks > WebUtil.LongCallTime) { m_log.Info($"[XInventory]: POST {m_InventoryURL} took {ticks}ms {sendlen}/{rcvlen}bytes"); }