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

Insert a new log level 4 for HTTP IN and HTTP OUT that will log how long the request took. 

This is only printed if debug http level >= 4 and the request didn't take more than the time considered 'long', in which case the existing log message is printed.
This displaces the previous log levels 4 and 5 which are now 5 and 6 respectively.
0.7.4-extended
Justin Clark-Casey (justincc) 2012-09-20 23:18:19 +01:00
parent 195625b5e7
commit 1ebde81d6a
3 changed files with 87 additions and 32 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

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

@ -54,6 +54,12 @@ namespace OpenSim.Framework.Servers.HttpServer
private static readonly ILog m_log = LogManager.GetLogger(MethodBase.GetCurrentMethod().DeclaringType);
private HttpServerLogWriter httpserverlog = new HttpServerLogWriter();
/// <summary>
/// Gets or sets the debug level.
/// </summary>
/// <value>
/// See MainServer.DebugLevel.
/// </value>
public int DebugLevel { get; set; }
private volatile int NotSocketErrors = 0;
@ -529,8 +535,8 @@ namespace OpenSim.Framework.Servers.HttpServer
if (DebugLevel >= 3)
m_log.DebugFormat(
"[BASE HTTP SERVER]: HTTP IN {0} content type handler {1} {2}",
request.ContentType, request.HttpMethod, request.Url.PathAndQuery);
"[BASE HTTP SERVER]: HTTP IN {0} content type handler {1} {2} from {3}",
request.ContentType, request.HttpMethod, request.Url.PathAndQuery, request.RemoteIPEndPoint);
buffer = HandleHTTPRequest(request, response);
break;
@ -541,8 +547,8 @@ namespace OpenSim.Framework.Servers.HttpServer
if (DebugLevel >= 3)
m_log.DebugFormat(
"[BASE HTTP SERVER]: HTTP IN {0} content type handler {1} {2}",
request.ContentType, request.HttpMethod, request.Url.PathAndQuery);
"[BASE HTTP SERVER]: HTTP IN {0} content type handler {1} {2} from {3}",
request.ContentType, request.HttpMethod, request.Url.PathAndQuery, request.RemoteIPEndPoint);
buffer = HandleLLSDRequests(request, response);
break;
@ -640,7 +646,18 @@ namespace OpenSim.Framework.Servers.HttpServer
uriString,
requestHandler != null ? requestHandler.Name : "",
requestHandler != null ? requestHandler.Description : "",
request.RemoteIPEndPoint.ToString(),
request.RemoteIPEndPoint,
tickdiff);
}
else if (DebugLevel >= 4)
{
m_log.DebugFormat(
"[BASE HTTP SERVER]: HTTP IN {0} {1} {2} {3} from {4} took {5}ms",
requestMethod,
uriString,
requestHandler != null ? requestHandler.Name : "",
requestHandler != null ? requestHandler.Description : "",
request.RemoteIPEndPoint,
tickdiff);
}
}
@ -649,30 +666,30 @@ namespace OpenSim.Framework.Servers.HttpServer
private void LogIncomingToStreamHandler(OSHttpRequest request, IRequestHandler requestHandler)
{
m_log.DebugFormat(
"[BASE HTTP SERVER]: HTTP IN stream handler {0} {1} {2} {3}",
request.HttpMethod, request.Url.PathAndQuery, requestHandler.Name, requestHandler.Description);
"[BASE HTTP SERVER]: HTTP IN stream handler {0} {1} {2} {3} from {4}",
request.HttpMethod, request.Url.PathAndQuery, requestHandler.Name, requestHandler.Description, request.RemoteIPEndPoint);
if (DebugLevel >= 4)
if (DebugLevel >= 5)
LogIncomingInDetail(request);
}
private void LogIncomingToContentTypeHandler(OSHttpRequest request)
{
m_log.DebugFormat(
"[BASE HTTP SERVER]: HTTP IN {0} content type handler {1} {2}",
request.ContentType, request.HttpMethod, request.Url.PathAndQuery);
"[BASE HTTP SERVER]: HTTP IN {0} content type handler {1} {2} from {3}",
request.ContentType, request.HttpMethod, request.Url.PathAndQuery, request.RemoteIPEndPoint);
if (DebugLevel >= 4)
if (DebugLevel >= 5)
LogIncomingInDetail(request);
}
private void LogIncomingToXmlRpcHandler(OSHttpRequest request)
{
m_log.DebugFormat(
"[BASE HTTP SERVER]: HTTP IN assumed generic XMLRPC request {0} {1}",
request.HttpMethod, request.Url.PathAndQuery);
"[BASE HTTP SERVER]: HTTP IN assumed generic XMLRPC request {0} {1} from {2}",
request.HttpMethod, request.Url.PathAndQuery, request.RemoteIPEndPoint);
if (DebugLevel >= 4)
if (DebugLevel >= 5)
LogIncomingInDetail(request);
}
@ -682,7 +699,7 @@ namespace OpenSim.Framework.Servers.HttpServer
{
string output;
if (DebugLevel == 4)
if (DebugLevel == 5)
{
const int sampleLength = 80;
char[] sampleChars = new char[sampleLength];

48
OpenSim/Framework/Servers/MainServer.cs
View File

@ -51,8 +51,9 @@ namespace OpenSim.Framework.Servers
/// If DebugLevel >= 1 then short warnings are logged when receiving bad input data.
/// If DebugLevel >= 2 then long warnings are logged when receiving bad input data.
/// If DebugLevel >= 3 then short notices about all incoming non-poll HTTP requests are logged.
/// If DebugLevel >= 4 then the start of the body of incoming non-poll HTTP requests will be logged.
/// If DebugLevel >= 5 then the entire body of incoming non-poll HTTP requests will be logged.
/// If DebugLevel >= 4 then the time taken to fulfill the request is logged.
/// If DebugLevel >= 5 then the start of the body of incoming non-poll HTTP requests will be logged.
/// If DebugLevel >= 6 then the entire body of incoming non-poll HTTP requests will be logged.
/// </remarks>
public static int DebugLevel
{
@ -115,15 +116,17 @@ namespace OpenSim.Framework.Servers
"Debug", false, "debug http", "debug http <in|out|all> [<level>]",
"Turn on http request logging.",
"If in or all and\n"
+ " level <= 0, then no extra logging is done.\n"
+ " level >= 1, then short warnings are logged when receiving bad input data.\n"
+ " level >= 2, then long warnings are logged when receiving bad input data.\n"
+ " level >= 3, then short notices about all incoming non-poll HTTP requests are logged.\n"
+ " level >= 4, then a sample from the beginning of the incoming data is logged.\n"
+ " level >= 5, then the entire incoming data is logged.\n"
+ " level <= 0 then no extra logging is done.\n"
+ " level >= 1 then short warnings are logged when receiving bad input data.\n"
+ " level >= 2 then long warnings are logged when receiving bad input data.\n"
+ " level >= 3 then short notices about all incoming non-poll HTTP requests are logged.\n"
+ " level >= 4 then the time taken to fulfill the request is logged.\n"
+ " level >= 5 then a sample from the beginning of the incoming data is logged.\n"
+ " level >= 6 then the entire incoming data is logged.\n"
+ " no level is specified then the current level is returned.\n\n"
+ "If out or all and\n"
+ " level >= 3. then short notices about all outgoing requests going through WebUtil are logged.\n",
+ " level >= 3 then short notices about all outgoing requests going through WebUtil are logged.\n"
+ " level >= 4 then the time taken to fulfill the request is logged.\n",
HandleDebugHttpCommand);
}
@ -135,7 +138,7 @@ namespace OpenSim.Framework.Servers
{
if (cmdparams.Length < 3)
{
MainConsole.Instance.Output("Usage: debug http <in|out|all> 0..5");
MainConsole.Instance.Output("Usage: debug http <in|out|all> 0..6");
return;
}
@ -145,12 +148,23 @@ namespace OpenSim.Framework.Servers
string subCommand = cmdparams[2];
if (subCommand == "in")
if (subCommand.ToLower() == "in")
{
inReqs = true;
else if (subCommand == "out")
}
else if (subCommand.ToLower() == "out")
{
outReqs = true;
else
}
else if (subCommand.ToLower() == "all")
{
allReqs = true;
}
else
{
MainConsole.Instance.Output("You must specify in, out or all");
return;
}
if (cmdparams.Length >= 4)
{
@ -172,22 +186,22 @@ namespace OpenSim.Framework.Servers
if (allReqs || inReqs)
{
MainServer.DebugLevel = newDebug;
MainConsole.Instance.OutputFormat("In debug level set to {0}", newDebug);
MainConsole.Instance.OutputFormat("IN debug level set to {0}", newDebug);
}
if (allReqs || outReqs)
{
WebUtil.DebugLevel = newDebug;
MainConsole.Instance.OutputFormat("Out debug level set to {0}", newDebug);
MainConsole.Instance.OutputFormat("OUT debug level set to {0}", newDebug);
}
}
else
{
if (allReqs || inReqs)
MainConsole.Instance.OutputFormat("Current in debug level is {0}", MainServer.DebugLevel);
MainConsole.Instance.OutputFormat("Current IN debug level is {0}", MainServer.DebugLevel);
if (allReqs || outReqs)
MainConsole.Instance.OutputFormat("Current out debug level is {0}", WebUtil.DebugLevel);
MainConsole.Instance.OutputFormat("Current OUT debug level is {0}", WebUtil.DebugLevel);
}
}

24
OpenSim/Framework/WebUtil.cs
View File

@ -250,6 +250,10 @@ namespace OpenSim.Framework
strBuffer != null
? (strBuffer.Length > MaxRequestDiagLength ? strBuffer.Remove(MaxRequestDiagLength) : strBuffer)
: "");
else if (DebugLevel >= 4)
m_log.DebugFormat(
"[WEB UTIL]: HTTP OUT {0} took {1}ms, {2}ms writing",
reqnum, tickdiff, tickdata);
}
m_log.DebugFormat(
@ -405,6 +409,10 @@ namespace OpenSim.Framework
queryString != null
? (queryString.Length > MaxRequestDiagLength) ? queryString.Remove(MaxRequestDiagLength) : queryString
: "");
else if (DebugLevel >= 4)
m_log.DebugFormat(
"[WEB UTIL]: HTTP OUT {0} took {1}ms, {2}ms writing",
reqnum, tickdiff, tickdata);
}
m_log.WarnFormat("[SERVICE FORM]: <{0}> form request to {1} failed: {2}", reqnum, url, errorMessage);
@ -879,6 +887,12 @@ namespace OpenSim.Framework
tickdata,
originalRequest);
}
else if (WebUtil.DebugLevel >= 4)
{
m_log.DebugFormat(
"[WEB UTIL]: HTTP OUT {0} took {1}ms, {2}ms writing",
reqnum, tickdiff, tickdata);
}
}
}
@ -995,6 +1009,10 @@ namespace OpenSim.Framework
tickdiff,
tickdata,
obj.Length > WebUtil.MaxRequestDiagLength ? obj.Remove(WebUtil.MaxRequestDiagLength) : obj);
else if (WebUtil.DebugLevel >= 4)
m_log.DebugFormat(
"[WEB UTIL]: HTTP OUT {0} took {1}ms, {2}ms writing",
reqnum, tickdiff, tickdata);
return respstring;
}
@ -1144,6 +1162,12 @@ namespace OpenSim.Framework
tickdata,
originalRequest);
}
else if (WebUtil.DebugLevel >= 4)
{
m_log.DebugFormat(
"[WEB UTIL]: HTTP OUT {0} took {1}ms, {2}ms writing",
reqnum, tickdiff, tickdata);
}
return deserial;
}