OpenSim
/
OpenSimMirror
1
0
Fork 0
Code Issues Pull Requests Releases Wiki Activity

Added more performance checks to the HTTP server. Each request 

coming through the WebUtil fns has a request id in the header
that can match the request to the actual work done by the service
viewer-2-initial-appearance
Mic Bowman 2011-01-05 14:32:00 -08:00
parent 6a5d52b4c8
commit 984a9b4085
2 changed files with 83 additions and 48 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

16
OpenSim/Framework/Servers/HttpServer/BaseHttpServer.cs
View File

@ -346,9 +346,15 @@ namespace OpenSim.Framework.Servers.HttpServer
/// <param name="response"></param> /// <param name="response"></param>
public virtual void HandleRequest(OSHttpRequest request, OSHttpResponse response) public virtual void HandleRequest(OSHttpRequest request, OSHttpResponse response)
{ {
string reqnum = "unknown";
int tickstart = Environment.TickCount;
try try
{ {
//m_log.Debug("[BASE HTTP SERVER]: Handling request to " + request.RawUrl); // OpenSim.Framework.WebUtil.OSHeaderRequestID
if (request.Headers["opensim-request-id"] != null)
reqnum = String.Format("{0}:{1}",request.RemoteIPEndPoint,request.Headers["opensim-request-id"]);
// m_log.DebugFormat("[BASE HTTP SERVER]: <{0}> handle request for {1}",reqnum,request.RawUrl);
Thread.CurrentThread.CurrentCulture = new CultureInfo("en-US", true); Thread.CurrentThread.CurrentCulture = new CultureInfo("en-US", true);
@ -576,6 +582,14 @@ namespace OpenSim.Framework.Servers.HttpServer
m_log.ErrorFormat("[BASE HTTP SERVER]: HandleRequest() threw {0}", e); m_log.ErrorFormat("[BASE HTTP SERVER]: HandleRequest() threw {0}", e);
SendHTML500(response); SendHTML500(response);
} }
finally
{
// Every month or so this will wrap and give bad numbers, not really a problem
// since its just for reporting, 200ms limit can be adjusted
int tickdiff = Environment.TickCount - tickstart;
if (tickdiff > 200)
m_log.InfoFormat("[BASE HTTP SERVER]: slow request <{0}> for {1} took {2} ms",reqnum,request.RawUrl,tickdiff);
}
} }
private bool TryGetStreamHandler(string handlerKey, out IRequestHandler streamHandler) private bool TryGetStreamHandler(string handlerKey, out IRequestHandler streamHandler)

115
OpenSim/Framework/WebUtil.cs
View File

@ -51,7 +51,15 @@ namespace OpenSim.Framework
MethodBase.GetCurrentMethod().DeclaringType); MethodBase.GetCurrentMethod().DeclaringType);
private static int m_requestNumber = 0; private static int m_requestNumber = 0;
// this is the header field used to communicate the local request id
// used for performance and debugging
public const string OSHeaderRequestID = "opensim-request-id";
// number of milliseconds a call can take before it is considered
// a "long" call for warning & debugging purposes
public const int LongCallTime = 200;
/// <summary> /// <summary>
/// Send LLSD to an HTTP client in application/llsd+json form /// Send LLSD to an HTTP client in application/llsd+json form
/// </summary> /// </summary>
@ -146,34 +154,41 @@ namespace OpenSim.Framework
public static OSDMap ServiceOSDRequest(string url, OSDMap data, string method, int timeout) public static OSDMap ServiceOSDRequest(string url, OSDMap data, string method, int timeout)
{ {
int reqnum = m_requestNumber++; int reqnum = m_requestNumber++;
m_log.DebugFormat("[WEB UTIL]: <{0}> start osd request for {1}, method {2}",reqnum,url,method); // m_log.DebugFormat("[WEB UTIL]: <{0}> start osd request for {1}, method {2}",reqnum,url,method);
string errorMessage = "unknown error"; string errorMessage = "unknown error";
int tickstart = Util.EnvironmentTickCount(); int tickstart = Util.EnvironmentTickCount();
int tickdata = 0;
try try
{ {
HttpWebRequest request = (HttpWebRequest)WebRequest.Create(url); HttpWebRequest request = (HttpWebRequest)WebRequest.Create(url);
request.Method = method; request.Method = method;
request.Timeout = timeout; request.Timeout = timeout;
//request.KeepAlive = false; request.KeepAlive = false;
request.MaximumAutomaticRedirections = 10;
request.ReadWriteTimeout = timeout / 4;
request.Headers[OSHeaderRequestID] = reqnum.ToString();
// If there is some input, write it into the request // If there is some input, write it into the request
if (data != null) if (data != null)
{ {
string strBuffer = OSDParser.SerializeJsonString(data); string strBuffer = OSDParser.SerializeJsonString(data);
byte[] buffer = System.Text.Encoding.UTF8.GetBytes(strBuffer); byte[] buffer = System.Text.Encoding.UTF8.GetBytes(strBuffer);
request.ContentType = "application/json"; request.ContentType = "application/json";
request.ContentLength = buffer.Length; //Count bytes to send request.ContentLength = buffer.Length; //Count bytes to send
using (Stream requestStream = request.GetRequestStream()) using (Stream requestStream = request.GetRequestStream())
{ requestStream.Write(buffer, 0, buffer.Length); //Send it
requestStream.Write(buffer, 0, strBuffer.Length); //Send it
}
} }
using (WebResponse webResponse = request.GetResponse()) // capture how much time was spent writing, this may seem silly
// but with the number concurrent requests, this often blocks
tickdata = Util.EnvironmentTickCountSubtract(tickstart);
using (WebResponse response = request.GetResponse())
{ {
using (Stream responseStream = webResponse.GetResponseStream()) using (Stream responseStream = response.GetResponseStream())
{ {
string responseStr = null; string responseStr = null;
responseStr = responseStream.GetStreamString(); responseStr = responseStream.GetStreamString();
@ -199,12 +214,12 @@ namespace OpenSim.Framework
{ {
// This just dumps a warning for any operation that takes more than 100 ms // This just dumps a warning for any operation that takes more than 100 ms
int tickdiff = Util.EnvironmentTickCountSubtract(tickstart); int tickdiff = Util.EnvironmentTickCountSubtract(tickstart);
if (tickdiff > 100) if (tickdiff > LongCallTime)
m_log.WarnFormat("[WEB UTIL]: request <{0}> (URI:{1}, METHOD:{2}) took {3} milliseconds", m_log.InfoFormat("[WEB UTIL]: osd request <{0}> (URI:{1}, METHOD:{2}) took {3}ms overall, {4}ms writing",
reqnum,url,method,tickdiff); reqnum,url,method,tickdiff,tickdata);
} }
m_log.WarnFormat("[WEB UTIL] <{0}> request failed: {1}",reqnum,errorMessage); m_log.WarnFormat("[WEB UTIL] <{0}> osd request failed: {1}",reqnum,errorMessage);
return ErrorResponseMap(errorMessage); return ErrorResponseMap(errorMessage);
} }
@ -248,7 +263,7 @@ namespace OpenSim.Framework
catch (Exception e) catch (Exception e)
{ {
// don't need to treat this as an error... we're just guessing anyway // don't need to treat this as an error... we're just guessing anyway
m_log.DebugFormat("[WEB UTIL] couldn't decode result: <{0}>",response); m_log.DebugFormat("[WEB UTIL] couldn't decode <{0}>: {1}",response,e.Message);
} }
return result; return result;
@ -259,27 +274,45 @@ namespace OpenSim.Framework
/// JSON data /// JSON data
/// </summary> /// </summary>
public static OSDMap PostToService(string url, NameValueCollection data) public static OSDMap PostToService(string url, NameValueCollection data)
{
return ServiceFormRequest(url,data,10000);
}
public static OSDMap ServiceFormRequest(string url, NameValueCollection data, int timeout)
{ {
int reqnum = m_requestNumber++; int reqnum = m_requestNumber++;
string method = data["RequestMethod"] != null ? data["RequestMethod"] : "unknown"; string method = (data != null && data["RequestMethod"] != null) ? data["RequestMethod"] : "unknown";
m_log.DebugFormat("[WEB UTIL]: <{0}> start form request for {1}, method {2}",reqnum,url,method); // m_log.DebugFormat("[WEB UTIL]: <{0}> start form request for {1}, method {2}",reqnum,url,method);
string errorMessage; string errorMessage = "unknown error";
int tickstart = Util.EnvironmentTickCount(); int tickstart = Util.EnvironmentTickCount();
int tickdata = 0;
try try
{ {
string queryString = BuildQueryString(data);
byte[] requestData = System.Text.Encoding.UTF8.GetBytes(queryString);
HttpWebRequest request = (HttpWebRequest)HttpWebRequest.Create(url); HttpWebRequest request = (HttpWebRequest)HttpWebRequest.Create(url);
request.Method = "POST"; request.Method = "POST";
request.ContentLength = requestData.Length; request.Timeout = timeout;
request.ContentType = "application/x-www-form-urlencoded"; request.KeepAlive = false;
request.MaximumAutomaticRedirections = 10;
request.ReadWriteTimeout = timeout / 4;
request.Headers[OSHeaderRequestID] = reqnum.ToString();
Stream requestStream = request.GetRequestStream(); if (data != null)
requestStream.Write(requestData, 0, requestData.Length); {
requestStream.Close(); string queryString = BuildQueryString(data);
byte[] buffer = System.Text.Encoding.UTF8.GetBytes(queryString);
request.ContentLength = buffer.Length;
request.ContentType = "application/x-www-form-urlencoded";
using (Stream requestStream = request.GetRequestStream())
requestStream.Write(buffer, 0, buffer.Length);
}
// capture how much time was spent writing, this may seem silly
// but with the number concurrent requests, this often blocks
tickdata = Util.EnvironmentTickCountSubtract(tickstart);
using (WebResponse response = request.GetResponse()) using (WebResponse response = request.GetResponse())
{ {
@ -287,22 +320,10 @@ namespace OpenSim.Framework
{ {
string responseStr = null; string responseStr = null;
try responseStr = responseStream.GetStreamString();
{ OSD responseOSD = OSDParser.Deserialize(responseStr);
responseStr = responseStream.GetStreamString(); if (responseOSD.Type == OSDType.Map)
OSD responseOSD = OSDParser.Deserialize(responseStr); return (OSDMap)responseOSD;
if (responseOSD.Type == OSDType.Map)
return (OSDMap)responseOSD;
else
errorMessage = "Response format was invalid.";
}
catch (Exception ex)
{
if (!String.IsNullOrEmpty(responseStr))
errorMessage = "Failed to parse the response:\n" + responseStr;
else
errorMessage = "Failed to retrieve the response: " + ex.Message;
}
} }
} }
} }
@ -322,12 +343,12 @@ namespace OpenSim.Framework
finally finally
{ {
int tickdiff = Util.EnvironmentTickCountSubtract(tickstart); int tickdiff = Util.EnvironmentTickCountSubtract(tickstart);
if (tickdiff > 100) if (tickdiff > LongCallTime)
m_log.WarnFormat("[WEB UTIL]: request <{0}> (URI:{1}, METHOD:{2}) took {3} milliseconds", m_log.InfoFormat("[WEB UTIL]: form request <{0}> (URI:{1}, METHOD:{2}) took {3}ms overall, {4}ms writing",
reqnum,url,method,tickdiff); reqnum,url,method,tickdiff,tickdata);
} }
m_log.WarnFormat("[WEB UTIL]: <{0}> request failed: {1}",reqnum,errorMessage); m_log.WarnFormat("[WEB UTIL]: <{0}> form request failed: {1}",reqnum,errorMessage);
return ErrorResponseMap(errorMessage); return ErrorResponseMap(errorMessage);
} }