From d15a3b10a3031b9552d67d2e2d435a689b448e2f Mon Sep 17 00:00:00 2001 From: Oren Hurvitz Date: Thu, 24 Apr 2014 14:19:03 +0300 Subject: When sending JSON-RPC calls (for UserProfile), use WebUtil instead of constructing the HTTP requests manually. This allows the calls to be logged when using "debug http all 6". --- .../Servers/HttpServer/JsonRpcRequestManager.cs | 175 +++++++++------------ OpenSim/Framework/WebUtil.cs | 24 +-- 2 files changed, 89 insertions(+), 110 deletions(-) (limited to 'OpenSim/Framework') diff --git a/OpenSim/Framework/Servers/HttpServer/JsonRpcRequestManager.cs b/OpenSim/Framework/Servers/HttpServer/JsonRpcRequestManager.cs index a44f471..ed6a14c 100644 --- a/OpenSim/Framework/Servers/HttpServer/JsonRpcRequestManager.cs +++ b/OpenSim/Framework/Servers/HttpServer/JsonRpcRequestManager.cs @@ -48,7 +48,6 @@ namespace OpenSim.Framework.Servers.HttpServer { } - #region Web Util /// /// Sends json-rpc request with a serializable type. /// @@ -70,64 +69,62 @@ namespace OpenSim.Framework.Servers.HttpServer public bool JsonRpcRequest(ref object parameters, string method, string uri, string jsonId) { if (jsonId == null) - throw new ArgumentNullException ("jsonId"); + throw new ArgumentNullException("jsonId"); if (uri == null) - throw new ArgumentNullException ("uri"); + throw new ArgumentNullException("uri"); if (method == null) - throw new ArgumentNullException ("method"); + throw new ArgumentNullException("method"); if (parameters == null) - throw new ArgumentNullException ("parameters"); - - // Prep our payload - OSDMap json = new OSDMap(); - - json.Add("jsonrpc", OSD.FromString("2.0")); - json.Add("id", OSD.FromString(jsonId)); - json.Add("method", OSD.FromString(method)); - - json.Add("params", OSD.SerializeMembers(parameters)); - - string jsonRequestData = OSDParser.SerializeJsonString(json); - byte[] content = Encoding.UTF8.GetBytes(jsonRequestData); - - HttpWebRequest webRequest = (HttpWebRequest)WebRequest.Create(uri); - - webRequest.ContentType = "application/json-rpc"; - webRequest.Method = "POST"; - - //Stream dataStream = webRequest.GetRequestStream(); - //dataStream.Write(content, 0, content.Length); - //dataStream.Close(); - - using (Stream dataStream = webRequest.GetRequestStream()) - dataStream.Write(content, 0, content.Length); - - WebResponse webResponse = null; + throw new ArgumentNullException("parameters"); + + OSDMap request = new OSDMap(); + request.Add("jsonrpc", OSD.FromString("2.0")); + request.Add("id", OSD.FromString(jsonId)); + request.Add("method", OSD.FromString(method)); + request.Add("params", OSD.SerializeMembers(parameters)); + + OSDMap response; try { - webResponse = webRequest.GetResponse(); + response = WebUtil.PostToService(uri, request, 10000, true); + } + catch (Exception e) + { + m_log.Debug(string.Format("JsonRpc request '{0}' failed", method), e); + return false; + } + + if (!response.ContainsKey("_Result")) + { + m_log.DebugFormat("JsonRpc request '{0}' returned an invalid response: {1}", + method, OSDParser.SerializeJsonString(response)); + return false; } - catch (WebException e) + response = (OSDMap)response["_Result"]; + + OSD data; + + if (response.ContainsKey("error")) { - Console.WriteLine("Web Error" + e.Message); - Console.WriteLine ("Please check input"); + data = response["error"]; + m_log.DebugFormat("JsonRpc request '{0}' returned an error: {1}", + method, OSDParser.SerializeJsonString(data)); return false; } - - using (webResponse) - using (Stream rstream = webResponse.GetResponseStream()) + + if (!response.ContainsKey("result")) { - OSDMap mret = (OSDMap)OSDParser.DeserializeJson(rstream); - - if (mret.ContainsKey("error")) - return false; - - // get params... - OSD.DeserializeMembers(ref parameters, (OSDMap)mret["result"]); - return true; + m_log.DebugFormat("JsonRpc request '{0}' returned an invalid response: {1}", + method, OSDParser.SerializeJsonString(response)); + return false; } + + data = response["result"]; + OSD.DeserializeMembers(ref parameters, (OSDMap)data); + + return true; } - + /// /// Sends json-rpc request with OSD parameter. /// @@ -135,7 +132,7 @@ namespace OpenSim.Framework.Servers.HttpServer /// The rpc request. /// /// - /// data - incoming as parameters, outgong as result/error + /// data - incoming as parameters, outgoing as result/error /// /// /// Json-rpc method to call. @@ -148,64 +145,46 @@ namespace OpenSim.Framework.Servers.HttpServer /// public bool JsonRpcRequest(ref OSD data, string method, string uri, string jsonId) { - OSDMap map = new OSDMap(); - - map["jsonrpc"] = "2.0"; - if(string.IsNullOrEmpty(jsonId)) - map["id"] = UUID.Random().ToString(); - else - map["id"] = jsonId; - - map["method"] = method; - map["params"] = data; - - string jsonRequestData = OSDParser.SerializeJsonString(map); - byte[] content = Encoding.UTF8.GetBytes(jsonRequestData); - - HttpWebRequest webRequest = (HttpWebRequest)WebRequest.Create(uri); - webRequest.ContentType = "application/json-rpc"; - webRequest.Method = "POST"; - - using (Stream dataStream = webRequest.GetRequestStream()) - dataStream.Write(content, 0, content.Length); - - WebResponse webResponse = null; + if (string.IsNullOrEmpty(jsonId)) + jsonId = UUID.Random().ToString(); + + OSDMap request = new OSDMap(); + request.Add("jsonrpc", OSD.FromString("2.0")); + request.Add("id", OSD.FromString(jsonId)); + request.Add("method", OSD.FromString(method)); + request.Add("params", data); + + OSDMap response; try { - webResponse = webRequest.GetResponse(); + response = WebUtil.PostToService(uri, request, 10000, true); } - catch (WebException e) + catch (Exception e) { - Console.WriteLine("Web Error" + e.Message); - Console.WriteLine ("Please check input"); + m_log.Debug(string.Format("JsonRpc request '{0}' failed", method), e); return false; } - - using (webResponse) - using (Stream rstream = webResponse.GetResponseStream()) + + if (!response.ContainsKey("_Result")) { - OSDMap response = new OSDMap(); - try - { - response = (OSDMap)OSDParser.DeserializeJson(rstream); - } - catch (Exception e) - { - m_log.DebugFormat("[JSONRPC]: JsonRpcRequest Error {0}", e.Message); - return false; - } - - if (response.ContainsKey("error")) - { - data = response["error"]; - return false; - } - - data = response; - - return true; + m_log.DebugFormat("JsonRpc request '{0}' returned an invalid response: {1}", + method, OSDParser.SerializeJsonString(response)); + return false; } + response = (OSDMap)response["_Result"]; + + if (response.ContainsKey("error")) + { + data = response["error"]; + m_log.DebugFormat("JsonRpc request '{0}' returned an error: {1}", + method, OSDParser.SerializeJsonString(data)); + return false; + } + + data = response; + + return true; } - #endregion Web Util + } } diff --git a/OpenSim/Framework/WebUtil.cs b/OpenSim/Framework/WebUtil.cs index 768ff16..8f5bc0c 100644 --- a/OpenSim/Framework/WebUtil.cs +++ b/OpenSim/Framework/WebUtil.cs @@ -127,41 +127,41 @@ namespace OpenSim.Framework /// public static OSDMap PutToServiceCompressed(string url, OSDMap data, int timeout) { - return ServiceOSDRequest(url,data, "PUT", timeout, true); + return ServiceOSDRequest(url,data, "PUT", timeout, true, false); } public static OSDMap PutToService(string url, OSDMap data, int timeout) { - return ServiceOSDRequest(url,data, "PUT", timeout, false); + return ServiceOSDRequest(url,data, "PUT", timeout, false, false); } - public static OSDMap PostToService(string url, OSDMap data, int timeout) + public static OSDMap PostToService(string url, OSDMap data, int timeout, bool rpc) { - return ServiceOSDRequest(url, data, "POST", timeout, false); + return ServiceOSDRequest(url, data, "POST", timeout, false, rpc); } public static OSDMap PostToServiceCompressed(string url, OSDMap data, int timeout) { - return ServiceOSDRequest(url, data, "POST", timeout, true); + return ServiceOSDRequest(url, data, "POST", timeout, true, false); } public static OSDMap GetFromService(string url, int timeout) { - return ServiceOSDRequest(url, null, "GET", timeout, false); + return ServiceOSDRequest(url, null, "GET", timeout, false, false); } - - public static OSDMap ServiceOSDRequest(string url, OSDMap data, string method, int timeout, bool compressed) + + public static OSDMap ServiceOSDRequest(string url, OSDMap data, string method, int timeout, bool compressed, bool rpc) { if (SerializeOSDRequestsPerEndpoint) { lock (EndPointLock(url)) { - return ServiceOSDRequestWorker(url, data, method, timeout, compressed); + return ServiceOSDRequestWorker(url, data, method, timeout, compressed, rpc); } } else { - return ServiceOSDRequestWorker(url, data, method, timeout, compressed); + return ServiceOSDRequestWorker(url, data, method, timeout, compressed, rpc); } } @@ -217,7 +217,7 @@ namespace OpenSim.Framework LogOutgoingDetail("RESPONSE: ", input); } - private static OSDMap ServiceOSDRequestWorker(string url, OSDMap data, string method, int timeout, bool compressed) + private static OSDMap ServiceOSDRequestWorker(string url, OSDMap data, string method, int timeout, bool compressed, bool rpc) { int reqnum = RequestNumber++; @@ -251,7 +251,7 @@ namespace OpenSim.Framework byte[] buffer = System.Text.Encoding.UTF8.GetBytes(strBuffer); - request.ContentType = "application/json"; + request.ContentType = rpc ? "application/json-rpc" : "application/json"; if (compressed) { -- cgit v1.1 From bc06db3df45d8dd61338c5b1426fd0161731f7cd Mon Sep 17 00:00:00 2001 From: Oren Hurvitz Date: Thu, 24 Apr 2014 14:21:05 +0300 Subject: - Created a standard function to send XML-RPC requests, which logs them like we do for other types of HTTP activity. - Changed OpenProfileClient to use the new XML-RPC sending function - Improved logging in WebUtil --- .../Framework/Servers/HttpServer/BaseHttpServer.cs | 2 +- OpenSim/Framework/WebUtil.cs | 212 ++++++++++++++------- 2 files changed, 139 insertions(+), 75 deletions(-) (limited to 'OpenSim/Framework') diff --git a/OpenSim/Framework/Servers/HttpServer/BaseHttpServer.cs b/OpenSim/Framework/Servers/HttpServer/BaseHttpServer.cs index 4f71db9..e8aa278 100644 --- a/OpenSim/Framework/Servers/HttpServer/BaseHttpServer.cs +++ b/OpenSim/Framework/Servers/HttpServer/BaseHttpServer.cs @@ -705,7 +705,7 @@ namespace OpenSim.Framework.Servers.HttpServer } } - WebUtil.LogResponseDetail(output); + WebUtil.LogResponseDetail(null, output); } if (!response.SendChunked && response.ContentLength64 <= 0) diff --git a/OpenSim/Framework/WebUtil.cs b/OpenSim/Framework/WebUtil.cs index 8f5bc0c..d7f6bc8 100644 --- a/OpenSim/Framework/WebUtil.cs +++ b/OpenSim/Framework/WebUtil.cs @@ -39,7 +39,9 @@ using System.Text; using System.Web; using System.Xml; using System.Xml.Serialization; +using System.Xml.Linq; using log4net; +using Nwc.XmlRpc; using OpenMetaverse.StructuredData; using XMLResponseHelper = OpenSim.Framework.SynchronousRestObjectRequester.XMLResponseHelper; @@ -191,9 +193,9 @@ namespace OpenSim.Framework } } - public static void LogOutgoingDetail(string output) + public static void LogOutgoingDetail(string type, int reqnum, string output) { - LogOutgoingDetail("", output); + LogOutgoingDetail(string.Format("{0} {1}: ", type, reqnum), output); } public static void LogOutgoingDetail(string context, string output) @@ -207,14 +209,15 @@ namespace OpenSim.Framework m_log.DebugFormat("[LOGHTTP]: {0}{1}", context, Util.BinaryToASCII(output)); } - public static void LogResponseDetail(Stream inputStream) + public static void LogResponseDetail(int reqnum, Stream inputStream) { - LogOutgoingDetail("RESPONSE: ", inputStream); + LogOutgoingDetail(string.Format("RESPONSE {0}: ", reqnum), inputStream); } - public static void LogResponseDetail(string input) + public static void LogResponseDetail(int? reqnum, string input) { - LogOutgoingDetail("RESPONSE: ", input); + string context = (reqnum == null) ? "" : string.Format("RESPONSE {0}: ", reqnum.Value); + LogOutgoingDetail(context, input); } private static OSDMap ServiceOSDRequestWorker(string url, OSDMap data, string method, int timeout, bool compressed, bool rpc) @@ -222,9 +225,8 @@ namespace OpenSim.Framework int reqnum = RequestNumber++; if (DebugLevel >= 3) - m_log.DebugFormat( - "[LOGHTTP]: HTTP OUT {0} ServiceOSD {1} {2} (timeout {3}, compressed {4})", - reqnum, method, url, timeout, compressed); + m_log.DebugFormat("[LOGHTTP]: HTTP OUT {0} JSON-RPC {1} to {2}", + reqnum, method, url); string errorMessage = "unknown error"; int tickstart = Util.EnvironmentTickCount(); @@ -247,7 +249,7 @@ namespace OpenSim.Framework strBuffer = OSDParser.SerializeJsonString(data); if (DebugLevel >= 5) - LogOutgoingDetail(strBuffer); + LogOutgoingDetail("SEND", reqnum, strBuffer); byte[] buffer = System.Text.Encoding.UTF8.GetBytes(strBuffer); @@ -291,9 +293,8 @@ namespace OpenSim.Framework using (StreamReader reader = new StreamReader(responseStream)) { string responseStr = reader.ReadToEnd(); - // m_log.DebugFormat("[LOGHTTP]: <{0}> response is <{1}>",reqnum,responseStr); if (WebUtil.DebugLevel >= 5) - WebUtil.LogResponseDetail(responseStr); + WebUtil.LogResponseDetail(reqnum, responseStr); return CanonicalizeResults(responseStr); } } @@ -316,24 +317,23 @@ namespace OpenSim.Framework { int tickdiff = Util.EnvironmentTickCountSubtract(tickstart); if (tickdiff > LongCallTime) + { m_log.InfoFormat( - "[LOGHTTP]: Slow ServiceOSD request {0} {1} {2} took {3}ms, {4}ms writing, {5}", - reqnum, - method, - url, - tickdiff, - tickdata, + "[LOGHTTP]: Slow JSON-RPC request {0} {1} to {2} took {3}ms, {4}ms writing, {5}", + reqnum, method, url, tickdiff, tickdata, strBuffer != null ? (strBuffer.Length > MaxRequestDiagLength ? strBuffer.Remove(MaxRequestDiagLength) : strBuffer) : ""); + } else if (DebugLevel >= 4) - m_log.DebugFormat( - "[LOGHTTP]: HTTP OUT {0} took {1}ms, {2}ms writing", + { + m_log.DebugFormat("[LOGHTTP]: HTTP OUT {0} took {1}ms, {2}ms writing", reqnum, tickdiff, tickdata); + } } m_log.DebugFormat( - "[LOGHTTP]: ServiceOSD request {0} {1} {2} FAILED: {3}", reqnum, url, method, errorMessage); + "[LOGHTTP]: JSON-RPC request {0} {1} to {2} FAILED: {3}", reqnum, method, url, errorMessage); return ErrorResponseMap(errorMessage); } @@ -411,9 +411,8 @@ namespace OpenSim.Framework string method = (data != null && data["RequestMethod"] != null) ? data["RequestMethod"] : "unknown"; if (DebugLevel >= 3) - m_log.DebugFormat( - "[LOGHTTP]: HTTP OUT {0} ServiceForm {1} {2} (timeout {3})", - reqnum, method, url, timeout); + m_log.DebugFormat("[LOGHTTP]: HTTP OUT {0} ServiceForm '{1}' to {2}", + reqnum, method, url); string errorMessage = "unknown error"; int tickstart = Util.EnvironmentTickCount(); @@ -435,7 +434,7 @@ namespace OpenSim.Framework queryString = BuildQueryString(data); if (DebugLevel >= 5) - LogOutgoingDetail(queryString); + LogOutgoingDetail("SEND", reqnum, queryString); byte[] buffer = System.Text.Encoding.UTF8.GetBytes(queryString); @@ -457,7 +456,7 @@ namespace OpenSim.Framework { string responseStr = reader.ReadToEnd(); if (WebUtil.DebugLevel >= 5) - WebUtil.LogResponseDetail(responseStr); + WebUtil.LogResponseDetail(reqnum, responseStr); OSD responseOSD = OSDParser.Deserialize(responseStr); if (responseOSD.Type == OSDType.Map) @@ -483,23 +482,22 @@ namespace OpenSim.Framework { int tickdiff = Util.EnvironmentTickCountSubtract(tickstart); if (tickdiff > LongCallTime) + { m_log.InfoFormat( - "[LOGHTTP]: Slow ServiceForm request {0} {1} {2} took {3}ms, {4}ms writing, {5}", - reqnum, - method, - url, - tickdiff, - tickdata, + "[LOGHTTP]: Slow ServiceForm request {0} '{1}' to {2} took {3}ms, {4}ms writing, {5}", + reqnum, method, url, tickdiff, tickdata, queryString != null ? (queryString.Length > MaxRequestDiagLength) ? queryString.Remove(MaxRequestDiagLength) : queryString : ""); + } else if (DebugLevel >= 4) - m_log.DebugFormat( - "[LOGHTTP]: HTTP OUT {0} took {1}ms, {2}ms writing", + { + m_log.DebugFormat("[LOGHTTP]: HTTP OUT {0} took {1}ms, {2}ms writing", reqnum, tickdiff, tickdata); + } } - m_log.WarnFormat("[LOGHTTP]: ServiceForm request {0} {1} {2} failed: {2}", reqnum, method, url, errorMessage); + m_log.WarnFormat("[LOGHTTP]: ServiceForm request {0} '{1}' to {2} failed: {3}", reqnum, method, url, errorMessage); return ErrorResponseMap(errorMessage); } @@ -779,8 +777,7 @@ namespace OpenSim.Framework int reqnum = WebUtil.RequestNumber++; if (WebUtil.DebugLevel >= 3) - m_log.DebugFormat( - "[LOGHTTP]: HTTP OUT {0} AsynchronousRequestObject {1} {2}", + m_log.DebugFormat("[LOGHTTP]: HTTP OUT {0} AsynchronousRequestObject {1} to {2}", reqnum, verb, requestUrl); int tickstart = Util.EnvironmentTickCount(); @@ -822,7 +819,7 @@ namespace OpenSim.Framework byte[] data = buffer.ToArray(); if (WebUtil.DebugLevel >= 5) - WebUtil.LogOutgoingDetail(System.Text.Encoding.UTF8.GetString(data)); + WebUtil.LogOutgoingDetail("SEND", reqnum, System.Text.Encoding.UTF8.GetString(data)); request.BeginGetRequestStream(delegate(IAsyncResult res) { @@ -840,7 +837,8 @@ namespace OpenSim.Framework { using (Stream respStream = response.GetResponseStream()) { - deserial = XMLResponseHelper.LogAndDeserialize(respStream, response.ContentLength); + deserial = XMLResponseHelper.LogAndDeserialize( + reqnum, respStream, response.ContentLength); } } catch (System.InvalidOperationException) @@ -867,7 +865,8 @@ namespace OpenSim.Framework { using (Stream respStream = response.GetResponseStream()) { - deserial = XMLResponseHelper.LogAndDeserialize(respStream, response.ContentLength); + deserial = XMLResponseHelper.LogAndDeserialize( + reqnum, respStream, response.ContentLength); } } catch (System.InvalidOperationException) @@ -938,18 +937,13 @@ namespace OpenSim.Framework } m_log.InfoFormat( - "[LOGHTTP]: [ASYNC REQUEST]: Slow request {0} {1} {2} took {3}ms, {4}ms writing, {5}", - reqnum, - verb, - requestUrl, - tickdiff, - tickdata, + "[LOGHTTP]: Slow AsynchronousRequestObject request {0} {1} to {2} took {3}ms, {4}ms writing, {5}", + reqnum, verb, requestUrl, tickdiff, tickdata, originalRequest); } else if (WebUtil.DebugLevel >= 4) { - m_log.DebugFormat( - "[LOGHTTP]: HTTP OUT {0} took {1}ms, {2}ms writing", + m_log.DebugFormat("[LOGHTTP]: HTTP OUT {0} took {1}ms, {2}ms writing", reqnum, tickdiff, tickdata); } } @@ -981,8 +975,7 @@ namespace OpenSim.Framework int reqnum = WebUtil.RequestNumber++; if (WebUtil.DebugLevel >= 3) - m_log.DebugFormat( - "[LOGHTTP]: HTTP OUT {0} SynchronousRestForms {1} {2}", + m_log.DebugFormat("[LOGHTTP]: HTTP OUT {0} SynchronousRestForms {1} to {2}", reqnum, verb, requestUrl); int tickstart = Util.EnvironmentTickCount(); @@ -1012,7 +1005,7 @@ namespace OpenSim.Framework byte[] data = buffer.ToArray(); if (WebUtil.DebugLevel >= 5) - WebUtil.LogOutgoingDetail(System.Text.Encoding.UTF8.GetString(data)); + WebUtil.LogOutgoingDetail("SEND", reqnum, System.Text.Encoding.UTF8.GetString(data)); Stream requestStream = null; try @@ -1058,21 +1051,20 @@ namespace OpenSim.Framework int tickdiff = Util.EnvironmentTickCountSubtract(tickstart); if (tickdiff > WebUtil.LongCallTime) + { m_log.InfoFormat( - "[LOGHTTP]: [FORMS]: Slow request {0} {1} {2} took {3}ms, {4}ms writing, {5}", - reqnum, - verb, - requestUrl, - tickdiff, - tickdata, + "[LOGHTTP]: Slow SynchronousRestForms request {0} {1} to {2} took {3}ms, {4}ms writing, {5}", + reqnum, verb, requestUrl, tickdiff, tickdata, obj.Length > WebUtil.MaxRequestDiagLength ? obj.Remove(WebUtil.MaxRequestDiagLength) : obj); + } else if (WebUtil.DebugLevel >= 4) - m_log.DebugFormat( - "[LOGHTTP]: HTTP OUT {0} took {1}ms, {2}ms writing", + { + m_log.DebugFormat("[LOGHTTP]: HTTP OUT {0} took {1}ms, {2}ms writing", reqnum, tickdiff, tickdata); + } if (WebUtil.DebugLevel >= 5) - WebUtil.LogResponseDetail(respstring); + WebUtil.LogResponseDetail(reqnum, respstring); return respstring; } @@ -1114,8 +1106,7 @@ namespace OpenSim.Framework int reqnum = WebUtil.RequestNumber++; if (WebUtil.DebugLevel >= 3) - m_log.DebugFormat( - "[LOGHTTP]: HTTP OUT {0} SynchronousRestObject {1} {2}", + m_log.DebugFormat("[LOGHTTP]: HTTP OUT {0} SynchronousRestObject {1} to {2}", reqnum, verb, requestUrl); int tickstart = Util.EnvironmentTickCount(); @@ -1155,7 +1146,7 @@ namespace OpenSim.Framework byte[] data = buffer.ToArray(); if (WebUtil.DebugLevel >= 5) - WebUtil.LogOutgoingDetail(System.Text.Encoding.UTF8.GetString(data)); + WebUtil.LogOutgoingDetail("SEND", reqnum, System.Text.Encoding.UTF8.GetString(data)); try { @@ -1185,7 +1176,8 @@ namespace OpenSim.Framework { using (Stream respStream = resp.GetResponseStream()) { - deserial = XMLResponseHelper.LogAndDeserialize(respStream, resp.ContentLength); + deserial = XMLResponseHelper.LogAndDeserialize( + reqnum, respStream, resp.ContentLength); } } else @@ -1236,18 +1228,13 @@ namespace OpenSim.Framework } m_log.InfoFormat( - "[LOGHTTP]: [SynchronousRestObjectRequester]: Slow request {0} {1} {2} took {3}ms, {4}ms writing, {5}", - reqnum, - verb, - requestUrl, - tickdiff, - tickdata, + "[LOGHTTP]: Slow SynchronousRestObject request {0} {1} to {2} took {3}ms, {4}ms writing, {5}", + reqnum, verb, requestUrl, tickdiff, tickdata, originalRequest); } else if (WebUtil.DebugLevel >= 4) { - m_log.DebugFormat( - "[LOGHTTP]: HTTP OUT {0} took {1}ms, {2}ms writing", + m_log.DebugFormat("[LOGHTTP]: HTTP OUT {0} took {1}ms, {2}ms writing", reqnum, tickdiff, tickdata); } } @@ -1263,7 +1250,7 @@ namespace OpenSim.Framework public static class XMLResponseHelper { - public static TResponse LogAndDeserialize(Stream respStream, long contentLength) + public static TResponse LogAndDeserialize(int reqnum, Stream respStream, long contentLength) { XmlSerializer deserializer = new XmlSerializer(typeof(TResponse)); @@ -1272,7 +1259,7 @@ namespace OpenSim.Framework byte[] data = new byte[contentLength]; Util.ReadStream(respStream, data); - WebUtil.LogResponseDetail(System.Text.Encoding.UTF8.GetString(data)); + WebUtil.LogResponseDetail(reqnum, System.Text.Encoding.UTF8.GetString(data)); using (MemoryStream temp = new MemoryStream(data)) return (TResponse)deserializer.Deserialize(temp); @@ -1284,4 +1271,81 @@ namespace OpenSim.Framework } } } + + + public static class XMLRPCRequester + { + private static readonly ILog m_log = LogManager.GetLogger(MethodBase.GetCurrentMethod().DeclaringType); + + public static Hashtable SendRequest(Hashtable ReqParams, string method, string url) + { + int reqnum = WebUtil.RequestNumber++; + + if (WebUtil.DebugLevel >= 3) + m_log.DebugFormat("[LOGHTTP]: HTTP OUT {0} XML-RPC '{1}' to {2}", + reqnum, method, url); + + int tickstart = Util.EnvironmentTickCount(); + string responseStr = null; + + try + { + ArrayList SendParams = new ArrayList(); + SendParams.Add(ReqParams); + + XmlRpcRequest Req = new XmlRpcRequest(method, SendParams); + + if (WebUtil.DebugLevel >= 5) + { + string str = Req.ToString(); + str = XElement.Parse(str).ToString(SaveOptions.DisableFormatting); + WebUtil.LogOutgoingDetail("SEND", reqnum, str); + } + + XmlRpcResponse Resp = Req.Send(url, 30000); + + try + { + responseStr = Resp.ToString(); + responseStr = XElement.Parse(responseStr).ToString(SaveOptions.DisableFormatting); + + if (WebUtil.DebugLevel >= 5) + WebUtil.LogResponseDetail(reqnum, responseStr); + } + catch (Exception e) + { + m_log.Error("Error parsing XML-RPC response", e); + } + + if (Resp.IsFault) + { + m_log.DebugFormat( + "[LOGHTTP]: XML-RPC request {0} '{1}' to {2} FAILED: FaultCode={3}, FaultMessage={4}", + reqnum, method, url, Resp.FaultCode, Resp.FaultString); + return null; + } + + Hashtable RespData = (Hashtable)Resp.Value; + return RespData; + } + finally + { + int tickdiff = Util.EnvironmentTickCountSubtract(tickstart); + if (tickdiff > WebUtil.LongCallTime) + { + m_log.InfoFormat( + "[LOGHTTP]: Slow XML-RPC request {0} '{1}' to {2} took {3}ms, {4}", + reqnum, method, url, tickdiff, + responseStr != null + ? (responseStr.Length > WebUtil.MaxRequestDiagLength ? responseStr.Remove(WebUtil.MaxRequestDiagLength) : responseStr) + : ""); + } + else if (WebUtil.DebugLevel >= 4) + { + m_log.DebugFormat("[LOGHTTP]: HTTP OUT {0} took {1}ms", reqnum, tickdiff); + } + } + } + + } } -- cgit v1.1