From f901a3820497e0d99accb6f5f60f6517e07c2c8f Mon Sep 17 00:00:00 2001 From: Oren Hurvitz Date: Thu, 28 Nov 2013 23:07:14 +0200 Subject: Improved logging of HTTP requests - MemoryBuffer isn't seekable, so we can't log it. Log the string instead. - Handle compressed streams - Don't attempt to dump binary data. Either don't log it at all (if we know it's binary), or at least convert non-ASCII characters to ASCII. - Log responses to HTTP requests - Use the same log prefix for all of these log messages ("[LOGHTTP]"), to make them easy to see at a glance - Increased the snippet length to 200 (80 doesn't show enough), and add "..." only if the message was actually truncated Resolves http://opensimulator.org/mantis/view.php?id=6949 --- .../Framework/Servers/HttpServer/BaseHttpServer.cs | 52 ++++++++++++++++------ 1 file changed, 38 insertions(+), 14 deletions(-) (limited to 'OpenSim/Framework/Servers/HttpServer') diff --git a/OpenSim/Framework/Servers/HttpServer/BaseHttpServer.cs b/OpenSim/Framework/Servers/HttpServer/BaseHttpServer.cs index e243002..19231e1 100644 --- a/OpenSim/Framework/Servers/HttpServer/BaseHttpServer.cs +++ b/OpenSim/Framework/Servers/HttpServer/BaseHttpServer.cs @@ -46,6 +46,7 @@ using CoolHTTPListener = HttpServer.HttpListener; using HttpListener=System.Net.HttpListener; using LogPrio=HttpServer.LogPrio; using OpenSim.Framework.Monitoring; +using System.IO.Compression; namespace OpenSim.Framework.Servers.HttpServer { @@ -690,6 +691,23 @@ namespace OpenSim.Framework.Servers.HttpServer if (buffer != null) { + if (WebUtil.DebugLevel >= 5) + { + string output = System.Text.Encoding.UTF8.GetString(buffer); + + if (WebUtil.DebugLevel >= 6) + { + // Always truncate binary blobs. We don't have a ContentType, so detect them using the request name. + if ((requestHandler != null && requestHandler.Name == "GetMesh")) + { + if (output.Length > WebUtil.MaxRequestDiagLength) + output = output.Substring(0, WebUtil.MaxRequestDiagLength) + "..."; + } + } + + WebUtil.LogResponseDetail(output); + } + if (!response.SendChunked && response.ContentLength64 <= 0) response.ContentLength64 = buffer.LongLength; @@ -743,7 +761,7 @@ namespace OpenSim.Framework.Servers.HttpServer if (tickdiff > 3000 && requestHandler != null && requestHandler.Name != "GetTexture") { m_log.InfoFormat( - "[BASE HTTP SERVER]: Slow handling of {0} {1} {2} {3} {4} from {5} took {6}ms", + "[LOGHTTP] Slow handling of {0} {1} {2} {3} {4} from {5} took {6}ms", RequestNumber, requestMethod, uriString, @@ -755,7 +773,7 @@ namespace OpenSim.Framework.Servers.HttpServer else if (DebugLevel >= 4) { m_log.DebugFormat( - "[BASE HTTP SERVER]: HTTP IN {0} :{1} took {2}ms", + "[LOGHTTP] HTTP IN {0} :{1} took {2}ms", RequestNumber, Port, tickdiff); @@ -766,7 +784,7 @@ namespace OpenSim.Framework.Servers.HttpServer private void LogIncomingToStreamHandler(OSHttpRequest request, IRequestHandler requestHandler) { m_log.DebugFormat( - "[BASE HTTP SERVER]: HTTP IN {0} :{1} stream handler {2} {3} {4} {5} from {6}", + "[LOGHTTP] HTTP IN {0} :{1} stream handler {2} {3} {4} {5} from {6}", RequestNumber, Port, request.HttpMethod, @@ -782,7 +800,7 @@ namespace OpenSim.Framework.Servers.HttpServer private void LogIncomingToContentTypeHandler(OSHttpRequest request) { m_log.DebugFormat( - "[BASE HTTP SERVER]: HTTP IN {0} :{1} {2} content type handler {3} {4} from {5}", + "[LOGHTTP] HTTP IN {0} :{1} {2} content type handler {3} {4} from {5}", RequestNumber, Port, string.IsNullOrEmpty(request.ContentType) ? "not set" : request.ContentType, @@ -797,7 +815,7 @@ namespace OpenSim.Framework.Servers.HttpServer private void LogIncomingToXmlRpcHandler(OSHttpRequest request) { m_log.DebugFormat( - "[BASE HTTP SERVER]: HTTP IN {0} :{1} assumed generic XMLRPC request {2} {3} from {4}", + "[LOGHTTP] HTTP IN {0} :{1} assumed generic XMLRPC request {2} {3} from {4}", RequestNumber, Port, request.HttpMethod, @@ -810,26 +828,32 @@ namespace OpenSim.Framework.Servers.HttpServer private void LogIncomingInDetail(OSHttpRequest request) { - using (StreamReader reader = new StreamReader(Util.Copy(request.InputStream), Encoding.UTF8)) + if (request.ContentType == "application/octet-stream") + return; // never log these; they're just binary data + + Stream inputStream = Util.Copy(request.InputStream); + + if (request.ContentType == "application/x-gzip") + inputStream = new GZipStream(inputStream, System.IO.Compression.CompressionMode.Decompress); + + using (StreamReader reader = new StreamReader(inputStream, Encoding.UTF8)) { string output; if (DebugLevel == 5) { - const int sampleLength = 80; - char[] sampleChars = new char[sampleLength + 3]; - reader.Read(sampleChars, 0, sampleLength); - sampleChars[80] = '.'; - sampleChars[81] = '.'; - sampleChars[82] = '.'; - output = new string(sampleChars); + char[] chars = new char[WebUtil.MaxRequestDiagLength + 1]; // +1 so we know to add "..." only if needed + int len = reader.Read(chars, 0, WebUtil.MaxRequestDiagLength + 1); + output = new string(chars, 0, Math.Min(len, WebUtil.MaxRequestDiagLength)); + if (len > WebUtil.MaxRequestDiagLength) + output += "..."; } else { output = reader.ReadToEnd(); } - m_log.DebugFormat("[BASE HTTP SERVER]: {0}", output.Replace("\n", @"\n")); + m_log.DebugFormat("[LOGHTTP] {0}", Util.BinaryToASCII(output)); } } -- cgit v1.1