aboutsummaryrefslogtreecommitdiffstatshomepage
path: root/OpenSim/Framework
diff options
context:
space:
mode:
authorOren Hurvitz2013-11-28 23:07:14 +0200
committerOren Hurvitz2014-03-25 09:36:53 +0100
commitf901a3820497e0d99accb6f5f60f6517e07c2c8f (patch)
treeced16f5b06d11e2ff109716c0682d27c8d3ed753 /OpenSim/Framework
parentFixed unit tests due to changes in the threadpool (diff)
downloadopensim-SC_OLD-f901a3820497e0d99accb6f5f60f6517e07c2c8f.zip
opensim-SC_OLD-f901a3820497e0d99accb6f5f60f6517e07c2c8f.tar.gz
opensim-SC_OLD-f901a3820497e0d99accb6f5f60f6517e07c2c8f.tar.bz2
opensim-SC_OLD-f901a3820497e0d99accb6f5f60f6517e07c2c8f.tar.xz
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
Diffstat (limited to 'OpenSim/Framework')
-rw-r--r--OpenSim/Framework/Servers/HttpServer/BaseHttpServer.cs52
-rw-r--r--OpenSim/Framework/Util.cs40
-rw-r--r--OpenSim/Framework/WebUtil.cs122
3 files changed, 165 insertions, 49 deletions
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;
46using HttpListener=System.Net.HttpListener; 46using HttpListener=System.Net.HttpListener;
47using LogPrio=HttpServer.LogPrio; 47using LogPrio=HttpServer.LogPrio;
48using OpenSim.Framework.Monitoring; 48using OpenSim.Framework.Monitoring;
49using System.IO.Compression;
49 50
50namespace OpenSim.Framework.Servers.HttpServer 51namespace OpenSim.Framework.Servers.HttpServer
51{ 52{
@@ -690,6 +691,23 @@ namespace OpenSim.Framework.Servers.HttpServer
690 691
691 if (buffer != null) 692 if (buffer != null)
692 { 693 {
694 if (WebUtil.DebugLevel >= 5)
695 {
696 string output = System.Text.Encoding.UTF8.GetString(buffer);
697
698 if (WebUtil.DebugLevel >= 6)
699 {
700 // Always truncate binary blobs. We don't have a ContentType, so detect them using the request name.
701 if ((requestHandler != null && requestHandler.Name == "GetMesh"))
702 {
703 if (output.Length > WebUtil.MaxRequestDiagLength)
704 output = output.Substring(0, WebUtil.MaxRequestDiagLength) + "...";
705 }
706 }
707
708 WebUtil.LogResponseDetail(output);
709 }
710
693 if (!response.SendChunked && response.ContentLength64 <= 0) 711 if (!response.SendChunked && response.ContentLength64 <= 0)
694 response.ContentLength64 = buffer.LongLength; 712 response.ContentLength64 = buffer.LongLength;
695 713
@@ -743,7 +761,7 @@ namespace OpenSim.Framework.Servers.HttpServer
743 if (tickdiff > 3000 && requestHandler != null && requestHandler.Name != "GetTexture") 761 if (tickdiff > 3000 && requestHandler != null && requestHandler.Name != "GetTexture")
744 { 762 {
745 m_log.InfoFormat( 763 m_log.InfoFormat(
746 "[BASE HTTP SERVER]: Slow handling of {0} {1} {2} {3} {4} from {5} took {6}ms", 764 "[LOGHTTP] Slow handling of {0} {1} {2} {3} {4} from {5} took {6}ms",
747 RequestNumber, 765 RequestNumber,
748 requestMethod, 766 requestMethod,
749 uriString, 767 uriString,
@@ -755,7 +773,7 @@ namespace OpenSim.Framework.Servers.HttpServer
755 else if (DebugLevel >= 4) 773 else if (DebugLevel >= 4)
756 { 774 {
757 m_log.DebugFormat( 775 m_log.DebugFormat(
758 "[BASE HTTP SERVER]: HTTP IN {0} :{1} took {2}ms", 776 "[LOGHTTP] HTTP IN {0} :{1} took {2}ms",
759 RequestNumber, 777 RequestNumber,
760 Port, 778 Port,
761 tickdiff); 779 tickdiff);
@@ -766,7 +784,7 @@ namespace OpenSim.Framework.Servers.HttpServer
766 private void LogIncomingToStreamHandler(OSHttpRequest request, IRequestHandler requestHandler) 784 private void LogIncomingToStreamHandler(OSHttpRequest request, IRequestHandler requestHandler)
767 { 785 {
768 m_log.DebugFormat( 786 m_log.DebugFormat(
769 "[BASE HTTP SERVER]: HTTP IN {0} :{1} stream handler {2} {3} {4} {5} from {6}", 787 "[LOGHTTP] HTTP IN {0} :{1} stream handler {2} {3} {4} {5} from {6}",
770 RequestNumber, 788 RequestNumber,
771 Port, 789 Port,
772 request.HttpMethod, 790 request.HttpMethod,
@@ -782,7 +800,7 @@ namespace OpenSim.Framework.Servers.HttpServer
782 private void LogIncomingToContentTypeHandler(OSHttpRequest request) 800 private void LogIncomingToContentTypeHandler(OSHttpRequest request)
783 { 801 {
784 m_log.DebugFormat( 802 m_log.DebugFormat(
785 "[BASE HTTP SERVER]: HTTP IN {0} :{1} {2} content type handler {3} {4} from {5}", 803 "[LOGHTTP] HTTP IN {0} :{1} {2} content type handler {3} {4} from {5}",
786 RequestNumber, 804 RequestNumber,
787 Port, 805 Port,
788 string.IsNullOrEmpty(request.ContentType) ? "not set" : request.ContentType, 806 string.IsNullOrEmpty(request.ContentType) ? "not set" : request.ContentType,
@@ -797,7 +815,7 @@ namespace OpenSim.Framework.Servers.HttpServer
797 private void LogIncomingToXmlRpcHandler(OSHttpRequest request) 815 private void LogIncomingToXmlRpcHandler(OSHttpRequest request)
798 { 816 {
799 m_log.DebugFormat( 817 m_log.DebugFormat(
800 "[BASE HTTP SERVER]: HTTP IN {0} :{1} assumed generic XMLRPC request {2} {3} from {4}", 818 "[LOGHTTP] HTTP IN {0} :{1} assumed generic XMLRPC request {2} {3} from {4}",
801 RequestNumber, 819 RequestNumber,
802 Port, 820 Port,
803 request.HttpMethod, 821 request.HttpMethod,
@@ -810,26 +828,32 @@ namespace OpenSim.Framework.Servers.HttpServer
810 828
811 private void LogIncomingInDetail(OSHttpRequest request) 829 private void LogIncomingInDetail(OSHttpRequest request)
812 { 830 {
813 using (StreamReader reader = new StreamReader(Util.Copy(request.InputStream), Encoding.UTF8)) 831 if (request.ContentType == "application/octet-stream")
832 return; // never log these; they're just binary data
833
834 Stream inputStream = Util.Copy(request.InputStream);
835
836 if (request.ContentType == "application/x-gzip")
837 inputStream = new GZipStream(inputStream, System.IO.Compression.CompressionMode.Decompress);
838
839 using (StreamReader reader = new StreamReader(inputStream, Encoding.UTF8))
814 { 840 {
815 string output; 841 string output;
816 842
817 if (DebugLevel == 5) 843 if (DebugLevel == 5)
818 { 844 {
819 const int sampleLength = 80; 845 char[] chars = new char[WebUtil.MaxRequestDiagLength + 1]; // +1 so we know to add "..." only if needed
820 char[] sampleChars = new char[sampleLength + 3]; 846 int len = reader.Read(chars, 0, WebUtil.MaxRequestDiagLength + 1);
821 reader.Read(sampleChars, 0, sampleLength); 847 output = new string(chars, 0, Math.Min(len, WebUtil.MaxRequestDiagLength));
822 sampleChars[80] = '.'; 848 if (len > WebUtil.MaxRequestDiagLength)
823 sampleChars[81] = '.'; 849 output += "...";
824 sampleChars[82] = '.';
825 output = new string(sampleChars);
826 } 850 }
827 else 851 else
828 { 852 {
829 output = reader.ReadToEnd(); 853 output = reader.ReadToEnd();
830 } 854 }
831 855
832 m_log.DebugFormat("[BASE HTTP SERVER]: {0}", output.Replace("\n", @"\n")); 856 m_log.DebugFormat("[LOGHTTP] {0}", Util.BinaryToASCII(output));
833 } 857 }
834 } 858 }
835 859
diff --git a/OpenSim/Framework/Util.cs b/OpenSim/Framework/Util.cs
index ae720f1..ce4af8b 100644
--- a/OpenSim/Framework/Util.cs
+++ b/OpenSim/Framework/Util.cs
@@ -1510,6 +1510,46 @@ namespace OpenSim.Framework
1510 return result; 1510 return result;
1511 } 1511 }
1512 1512
1513 public static void BinaryToASCII(char[] chars)
1514 {
1515 for (int i = 0; i < chars.Length; i++)
1516 {
1517 char ch = chars[i];
1518 if (ch < 32 || ch > 127)
1519 chars[i] = '.';
1520 }
1521 }
1522
1523 public static string BinaryToASCII(string src)
1524 {
1525 char[] chars = src.ToCharArray();
1526 BinaryToASCII(chars);
1527 return new String(chars);
1528 }
1529
1530 /// <summary>
1531 /// Reads a known number of bytes from a stream.
1532 /// Throws EndOfStreamException if the stream doesn't contain enough data.
1533 /// </summary>
1534 /// <param name="stream">The stream to read data from</param>
1535 /// <param name="data">The array to write bytes into. The array
1536 /// will be completely filled from the stream, so an appropriate
1537 /// size must be given.</param>
1538 public static void ReadStream(Stream stream, byte[] data)
1539 {
1540 int offset = 0;
1541 int remaining = data.Length;
1542
1543 while (remaining > 0)
1544 {
1545 int read = stream.Read(data, offset, remaining);
1546 if (read <= 0)
1547 throw new EndOfStreamException(String.Format("End of stream reached with {0} bytes left to read", remaining));
1548 remaining -= read;
1549 offset += read;
1550 }
1551 }
1552
1513 public static Guid GetHashGuid(string data, string salt) 1553 public static Guid GetHashGuid(string data, string salt)
1514 { 1554 {
1515 byte[] hash = ComputeMD5Hash(data + salt); 1555 byte[] hash = ComputeMD5Hash(data + salt);
diff --git a/OpenSim/Framework/WebUtil.cs b/OpenSim/Framework/WebUtil.cs
index c7f1bdb..7f341d2 100644
--- a/OpenSim/Framework/WebUtil.cs
+++ b/OpenSim/Framework/WebUtil.cs
@@ -89,8 +89,9 @@ namespace OpenSim.Framework
89 /// <remarks> 89 /// <remarks>
90 /// This is to truncate any really large post data, such as an asset. In theory, the first section should 90 /// This is to truncate any really large post data, such as an asset. In theory, the first section should
91 /// give us useful information about the call (which agent it relates to if applicable, etc.). 91 /// give us useful information about the call (which agent it relates to if applicable, etc.).
92 /// This is also used to truncate messages when using DebugLevel 5.
92 /// </remarks> 93 /// </remarks>
93 public const int MaxRequestDiagLength = 100; 94 public const int MaxRequestDiagLength = 200;
94 95
95 /// <summary> 96 /// <summary>
96 /// Dictionary of end points 97 /// Dictionary of end points
@@ -165,35 +166,54 @@ namespace OpenSim.Framework
165 166
166 public static void LogOutgoingDetail(Stream outputStream) 167 public static void LogOutgoingDetail(Stream outputStream)
167 { 168 {
169 LogOutgoingDetail("", outputStream);
170 }
171
172 public static void LogOutgoingDetail(string context, Stream outputStream)
173 {
168 using (StreamReader reader = new StreamReader(Util.Copy(outputStream), Encoding.UTF8)) 174 using (StreamReader reader = new StreamReader(Util.Copy(outputStream), Encoding.UTF8))
169 { 175 {
170 string output; 176 string output;
171 177
172 if (DebugLevel == 5) 178 if (DebugLevel == 5)
173 { 179 {
174 const int sampleLength = 80; 180 char[] chars = new char[WebUtil.MaxRequestDiagLength + 1]; // +1 so we know to add "..." only if needed
175 char[] sampleChars = new char[sampleLength]; 181 int len = reader.Read(chars, 0, WebUtil.MaxRequestDiagLength + 1);
176 reader.Read(sampleChars, 0, sampleLength); 182 output = new string(chars, 0, len);
177 output = new string(sampleChars);
178 } 183 }
179 else 184 else
180 { 185 {
181 output = reader.ReadToEnd(); 186 output = reader.ReadToEnd();
182 } 187 }
183 188
184 LogOutgoingDetail(output); 189 LogOutgoingDetail(context, output);
185 } 190 }
186 } 191 }
187 192
188 public static void LogOutgoingDetail(string output) 193 public static void LogOutgoingDetail(string output)
189 { 194 {
195 LogOutgoingDetail("", output);
196 }
197
198 public static void LogOutgoingDetail(string context, string output)
199 {
190 if (DebugLevel == 5) 200 if (DebugLevel == 5)
191 { 201 {
192 output = output.Substring(0, 80); 202 if (output.Length > MaxRequestDiagLength)
193 output = output + "..."; 203 output = output.Substring(0, MaxRequestDiagLength) + "...";
194 } 204 }
195 205
196 m_log.DebugFormat("[WEB UTIL]: {0}", output.Replace("\n", @"\n")); 206 m_log.DebugFormat("[LOGHTTP]: {0}{1}", context, Util.BinaryToASCII(output));
207 }
208
209 public static void LogResponseDetail(Stream inputStream)
210 {
211 LogOutgoingDetail("RESPONSE: ", inputStream);
212 }
213
214 public static void LogResponseDetail(string input)
215 {
216 LogOutgoingDetail("RESPONSE: ", input);
197 } 217 }
198 218
199 private static OSDMap ServiceOSDRequestWorker(string url, OSDMap data, string method, int timeout, bool compressed) 219 private static OSDMap ServiceOSDRequestWorker(string url, OSDMap data, string method, int timeout, bool compressed)
@@ -202,7 +222,7 @@ namespace OpenSim.Framework
202 222
203 if (DebugLevel >= 3) 223 if (DebugLevel >= 3)
204 m_log.DebugFormat( 224 m_log.DebugFormat(
205 "[WEB UTIL]: HTTP OUT {0} ServiceOSD {1} {2} (timeout {3}, compressed {4})", 225 "[LOGHTTP]: HTTP OUT {0} ServiceOSD {1} {2} (timeout {3}, compressed {4})",
206 reqnum, method, url, timeout, compressed); 226 reqnum, method, url, timeout, compressed);
207 227
208 string errorMessage = "unknown error"; 228 string errorMessage = "unknown error";
@@ -268,7 +288,9 @@ namespace OpenSim.Framework
268 using (StreamReader reader = new StreamReader(responseStream)) 288 using (StreamReader reader = new StreamReader(responseStream))
269 { 289 {
270 string responseStr = reader.ReadToEnd(); 290 string responseStr = reader.ReadToEnd();
271 // m_log.DebugFormat("[WEB UTIL]: <{0}> response is <{1}>",reqnum,responseStr); 291 // m_log.DebugFormat("[LOGHTTP]: <{0}> response is <{1}>",reqnum,responseStr);
292 if (WebUtil.DebugLevel >= 5)
293 WebUtil.LogResponseDetail(responseStr);
272 return CanonicalizeResults(responseStr); 294 return CanonicalizeResults(responseStr);
273 } 295 }
274 } 296 }
@@ -292,7 +314,7 @@ namespace OpenSim.Framework
292 int tickdiff = Util.EnvironmentTickCountSubtract(tickstart); 314 int tickdiff = Util.EnvironmentTickCountSubtract(tickstart);
293 if (tickdiff > LongCallTime) 315 if (tickdiff > LongCallTime)
294 m_log.InfoFormat( 316 m_log.InfoFormat(
295 "[WEB UTIL]: Slow ServiceOSD request {0} {1} {2} took {3}ms, {4}ms writing, {5}", 317 "[LOGHTTP]: Slow ServiceOSD request {0} {1} {2} took {3}ms, {4}ms writing, {5}",
296 reqnum, 318 reqnum,
297 method, 319 method,
298 url, 320 url,
@@ -303,12 +325,12 @@ namespace OpenSim.Framework
303 : ""); 325 : "");
304 else if (DebugLevel >= 4) 326 else if (DebugLevel >= 4)
305 m_log.DebugFormat( 327 m_log.DebugFormat(
306 "[WEB UTIL]: HTTP OUT {0} took {1}ms, {2}ms writing", 328 "[LOGHTTP]: HTTP OUT {0} took {1}ms, {2}ms writing",
307 reqnum, tickdiff, tickdata); 329 reqnum, tickdiff, tickdata);
308 } 330 }
309 331
310 m_log.DebugFormat( 332 m_log.DebugFormat(
311 "[WEB UTIL]: ServiceOSD request {0} {1} {2} FAILED: {3}", reqnum, url, method, errorMessage); 333 "[LOGHTTP]: ServiceOSD request {0} {1} {2} FAILED: {3}", reqnum, url, method, errorMessage);
312 334
313 return ErrorResponseMap(errorMessage); 335 return ErrorResponseMap(errorMessage);
314 } 336 }
@@ -387,7 +409,7 @@ namespace OpenSim.Framework
387 409
388 if (DebugLevel >= 3) 410 if (DebugLevel >= 3)
389 m_log.DebugFormat( 411 m_log.DebugFormat(
390 "[WEB UTIL]: HTTP OUT {0} ServiceForm {1} {2} (timeout {3})", 412 "[LOGHTTP]: HTTP OUT {0} ServiceForm {1} {2} (timeout {3})",
391 reqnum, method, url, timeout); 413 reqnum, method, url, timeout);
392 414
393 string errorMessage = "unknown error"; 415 string errorMessage = "unknown error";
@@ -431,6 +453,8 @@ namespace OpenSim.Framework
431 using (StreamReader reader = new StreamReader(responseStream)) 453 using (StreamReader reader = new StreamReader(responseStream))
432 { 454 {
433 string responseStr = reader.ReadToEnd(); 455 string responseStr = reader.ReadToEnd();
456 if (WebUtil.DebugLevel >= 5)
457 WebUtil.LogResponseDetail(responseStr);
434 OSD responseOSD = OSDParser.Deserialize(responseStr); 458 OSD responseOSD = OSDParser.Deserialize(responseStr);
435 459
436 if (responseOSD.Type == OSDType.Map) 460 if (responseOSD.Type == OSDType.Map)
@@ -457,7 +481,7 @@ namespace OpenSim.Framework
457 int tickdiff = Util.EnvironmentTickCountSubtract(tickstart); 481 int tickdiff = Util.EnvironmentTickCountSubtract(tickstart);
458 if (tickdiff > LongCallTime) 482 if (tickdiff > LongCallTime)
459 m_log.InfoFormat( 483 m_log.InfoFormat(
460 "[WEB UTIL]: Slow ServiceForm request {0} {1} {2} took {3}ms, {4}ms writing, {5}", 484 "[LOGHTTP]: Slow ServiceForm request {0} {1} {2} took {3}ms, {4}ms writing, {5}",
461 reqnum, 485 reqnum,
462 method, 486 method,
463 url, 487 url,
@@ -468,11 +492,11 @@ namespace OpenSim.Framework
468 : ""); 492 : "");
469 else if (DebugLevel >= 4) 493 else if (DebugLevel >= 4)
470 m_log.DebugFormat( 494 m_log.DebugFormat(
471 "[WEB UTIL]: HTTP OUT {0} took {1}ms, {2}ms writing", 495 "[LOGHTTP]: HTTP OUT {0} took {1}ms, {2}ms writing",
472 reqnum, tickdiff, tickdata); 496 reqnum, tickdiff, tickdata);
473 } 497 }
474 498
475 m_log.WarnFormat("[WEB UTIL]: ServiceForm request {0} {1} {2} failed: {2}", reqnum, method, url, errorMessage); 499 m_log.WarnFormat("[LOGHTTP]: ServiceForm request {0} {1} {2} failed: {2}", reqnum, method, url, errorMessage);
476 500
477 return ErrorResponseMap(errorMessage); 501 return ErrorResponseMap(errorMessage);
478 } 502 }
@@ -753,7 +777,7 @@ namespace OpenSim.Framework
753 777
754 if (WebUtil.DebugLevel >= 3) 778 if (WebUtil.DebugLevel >= 3)
755 m_log.DebugFormat( 779 m_log.DebugFormat(
756 "[WEB UTIL]: HTTP OUT {0} AsynchronousRequestObject {1} {2}", 780 "[LOGHTTP]: HTTP OUT {0} AsynchronousRequestObject {1} {2}",
757 reqnum, verb, requestUrl); 781 reqnum, verb, requestUrl);
758 782
759 int tickstart = Util.EnvironmentTickCount(); 783 int tickstart = Util.EnvironmentTickCount();
@@ -793,14 +817,15 @@ namespace OpenSim.Framework
793 817
794 int length = (int)buffer.Length; 818 int length = (int)buffer.Length;
795 request.ContentLength = length; 819 request.ContentLength = length;
820 byte[] data = buffer.ToArray();
796 821
797 if (WebUtil.DebugLevel >= 5) 822 if (WebUtil.DebugLevel >= 5)
798 WebUtil.LogOutgoingDetail(buffer); 823 WebUtil.LogOutgoingDetail(System.Text.Encoding.UTF8.GetString(data));
799 824
800 request.BeginGetRequestStream(delegate(IAsyncResult res) 825 request.BeginGetRequestStream(delegate(IAsyncResult res)
801 { 826 {
802 using (Stream requestStream = request.EndGetRequestStream(res)) 827 using (Stream requestStream = request.EndGetRequestStream(res))
803 requestStream.Write(buffer.ToArray(), 0, length); 828 requestStream.Write(data, 0, length);
804 829
805 // capture how much time was spent writing 830 // capture how much time was spent writing
806 tickdata = Util.EnvironmentTickCountSubtract(tickstart); 831 tickdata = Util.EnvironmentTickCountSubtract(tickstart);
@@ -812,7 +837,11 @@ namespace OpenSim.Framework
812 try 837 try
813 { 838 {
814 using (Stream respStream = response.GetResponseStream()) 839 using (Stream respStream = response.GetResponseStream())
840 {
841 if (WebUtil.DebugLevel >= 5)
842 WebUtil.LogResponseDetail(respStream);
815 deserial = (TResponse)deserializer.Deserialize(respStream); 843 deserial = (TResponse)deserializer.Deserialize(respStream);
844 }
816 } 845 }
817 catch (System.InvalidOperationException) 846 catch (System.InvalidOperationException)
818 { 847 {
@@ -837,7 +866,11 @@ namespace OpenSim.Framework
837 try 866 try
838 { 867 {
839 using (Stream respStream = response.GetResponseStream()) 868 using (Stream respStream = response.GetResponseStream())
869 {
870 if (WebUtil.DebugLevel >= 5)
871 WebUtil.LogResponseDetail(respStream);
840 deserial = (TResponse)deserializer.Deserialize(respStream); 872 deserial = (TResponse)deserializer.Deserialize(respStream);
873 }
841 } 874 }
842 catch (System.InvalidOperationException) 875 catch (System.InvalidOperationException)
843 { 876 {
@@ -907,7 +940,7 @@ namespace OpenSim.Framework
907 } 940 }
908 941
909 m_log.InfoFormat( 942 m_log.InfoFormat(
910 "[ASYNC REQUEST]: Slow request {0} {1} {2} took {3}ms, {4}ms writing, {5}", 943 "[LOGHTTP]: [ASYNC REQUEST]: Slow request {0} {1} {2} took {3}ms, {4}ms writing, {5}",
911 reqnum, 944 reqnum,
912 verb, 945 verb,
913 requestUrl, 946 requestUrl,
@@ -918,7 +951,7 @@ namespace OpenSim.Framework
918 else if (WebUtil.DebugLevel >= 4) 951 else if (WebUtil.DebugLevel >= 4)
919 { 952 {
920 m_log.DebugFormat( 953 m_log.DebugFormat(
921 "[WEB UTIL]: HTTP OUT {0} took {1}ms, {2}ms writing", 954 "[LOGHTTP]: HTTP OUT {0} took {1}ms, {2}ms writing",
922 reqnum, tickdiff, tickdata); 955 reqnum, tickdiff, tickdata);
923 } 956 }
924 } 957 }
@@ -951,7 +984,7 @@ namespace OpenSim.Framework
951 984
952 if (WebUtil.DebugLevel >= 3) 985 if (WebUtil.DebugLevel >= 3)
953 m_log.DebugFormat( 986 m_log.DebugFormat(
954 "[WEB UTIL]: HTTP OUT {0} SynchronousRestForms {1} {2}", 987 "[LOGHTTP]: HTTP OUT {0} SynchronousRestForms {1} {2}",
955 reqnum, verb, requestUrl); 988 reqnum, verb, requestUrl);
956 989
957 int tickstart = Util.EnvironmentTickCount(); 990 int tickstart = Util.EnvironmentTickCount();
@@ -978,15 +1011,16 @@ namespace OpenSim.Framework
978 1011
979 length = (int)obj.Length; 1012 length = (int)obj.Length;
980 request.ContentLength = length; 1013 request.ContentLength = length;
1014 byte[] data = buffer.ToArray();
981 1015
982 if (WebUtil.DebugLevel >= 5) 1016 if (WebUtil.DebugLevel >= 5)
983 WebUtil.LogOutgoingDetail(buffer); 1017 WebUtil.LogOutgoingDetail(System.Text.Encoding.UTF8.GetString(data));
984 1018
985 Stream requestStream = null; 1019 Stream requestStream = null;
986 try 1020 try
987 { 1021 {
988 requestStream = request.GetRequestStream(); 1022 requestStream = request.GetRequestStream();
989 requestStream.Write(buffer.ToArray(), 0, length); 1023 requestStream.Write(data, 0, length);
990 } 1024 }
991 catch (Exception e) 1025 catch (Exception e)
992 { 1026 {
@@ -1036,7 +1070,7 @@ namespace OpenSim.Framework
1036 int tickdiff = Util.EnvironmentTickCountSubtract(tickstart); 1070 int tickdiff = Util.EnvironmentTickCountSubtract(tickstart);
1037 if (tickdiff > WebUtil.LongCallTime) 1071 if (tickdiff > WebUtil.LongCallTime)
1038 m_log.InfoFormat( 1072 m_log.InfoFormat(
1039 "[FORMS]: Slow request {0} {1} {2} took {3}ms, {4}ms writing, {5}", 1073 "[LOGHTTP]: [FORMS]: Slow request {0} {1} {2} took {3}ms, {4}ms writing, {5}",
1040 reqnum, 1074 reqnum,
1041 verb, 1075 verb,
1042 requestUrl, 1076 requestUrl,
@@ -1045,9 +1079,12 @@ namespace OpenSim.Framework
1045 obj.Length > WebUtil.MaxRequestDiagLength ? obj.Remove(WebUtil.MaxRequestDiagLength) : obj); 1079 obj.Length > WebUtil.MaxRequestDiagLength ? obj.Remove(WebUtil.MaxRequestDiagLength) : obj);
1046 else if (WebUtil.DebugLevel >= 4) 1080 else if (WebUtil.DebugLevel >= 4)
1047 m_log.DebugFormat( 1081 m_log.DebugFormat(
1048 "[WEB UTIL]: HTTP OUT {0} took {1}ms, {2}ms writing", 1082 "[LOGHTTP]: HTTP OUT {0} took {1}ms, {2}ms writing",
1049 reqnum, tickdiff, tickdata); 1083 reqnum, tickdiff, tickdata);
1050 1084
1085 if (WebUtil.DebugLevel >= 5)
1086 WebUtil.LogResponseDetail(respstring);
1087
1051 return respstring; 1088 return respstring;
1052 } 1089 }
1053 1090
@@ -1089,7 +1126,7 @@ namespace OpenSim.Framework
1089 1126
1090 if (WebUtil.DebugLevel >= 3) 1127 if (WebUtil.DebugLevel >= 3)
1091 m_log.DebugFormat( 1128 m_log.DebugFormat(
1092 "[WEB UTIL]: HTTP OUT {0} SynchronousRestObject {1} {2}", 1129 "[LOGHTTP]: HTTP OUT {0} SynchronousRestObject {1} {2}",
1093 reqnum, verb, requestUrl); 1130 reqnum, verb, requestUrl);
1094 1131
1095 int tickstart = Util.EnvironmentTickCount(); 1132 int tickstart = Util.EnvironmentTickCount();
@@ -1126,14 +1163,15 @@ namespace OpenSim.Framework
1126 1163
1127 int length = (int)buffer.Length; 1164 int length = (int)buffer.Length;
1128 request.ContentLength = length; 1165 request.ContentLength = length;
1166 byte[] data = buffer.ToArray();
1129 1167
1130 if (WebUtil.DebugLevel >= 5) 1168 if (WebUtil.DebugLevel >= 5)
1131 WebUtil.LogOutgoingDetail(buffer); 1169 WebUtil.LogOutgoingDetail(System.Text.Encoding.UTF8.GetString(data));
1132 1170
1133 try 1171 try
1134 { 1172 {
1135 using (Stream requestStream = request.GetRequestStream()) 1173 using (Stream requestStream = request.GetRequestStream())
1136 requestStream.Write(buffer.ToArray(), 0, length); 1174 requestStream.Write(data, 0, length);
1137 } 1175 }
1138 catch (Exception e) 1176 catch (Exception e)
1139 { 1177 {
@@ -1159,7 +1197,21 @@ namespace OpenSim.Framework
1159 using (Stream respStream = resp.GetResponseStream()) 1197 using (Stream respStream = resp.GetResponseStream())
1160 { 1198 {
1161 XmlSerializer deserializer = new XmlSerializer(typeof(TResponse)); 1199 XmlSerializer deserializer = new XmlSerializer(typeof(TResponse));
1162 deserial = (TResponse)deserializer.Deserialize(respStream); 1200
1201 if (WebUtil.DebugLevel >= 5)
1202 {
1203 byte[] data = new byte[resp.ContentLength];
1204 Util.ReadStream(respStream, data);
1205
1206 WebUtil.LogResponseDetail(System.Text.Encoding.UTF8.GetString(data));
1207
1208 using (MemoryStream temp = new MemoryStream(data))
1209 deserial = (TResponse)deserializer.Deserialize(temp);
1210 }
1211 else
1212 {
1213 deserial = (TResponse)deserializer.Deserialize(respStream);
1214 }
1163 } 1215 }
1164 } 1216 }
1165 else 1217 else
@@ -1210,7 +1262,7 @@ namespace OpenSim.Framework
1210 } 1262 }
1211 1263
1212 m_log.InfoFormat( 1264 m_log.InfoFormat(
1213 "[SynchronousRestObjectRequester]: Slow request {0} {1} {2} took {3}ms, {4}ms writing, {5}", 1265 "[LOGHTTP]: [SynchronousRestObjectRequester]: Slow request {0} {1} {2} took {3}ms, {4}ms writing, {5}",
1214 reqnum, 1266 reqnum,
1215 verb, 1267 verb,
1216 requestUrl, 1268 requestUrl,
@@ -1221,7 +1273,7 @@ namespace OpenSim.Framework
1221 else if (WebUtil.DebugLevel >= 4) 1273 else if (WebUtil.DebugLevel >= 4)
1222 { 1274 {
1223 m_log.DebugFormat( 1275 m_log.DebugFormat(
1224 "[WEB UTIL]: HTTP OUT {0} took {1}ms, {2}ms writing", 1276 "[LOGHTTP]: HTTP OUT {0} took {1}ms, {2}ms writing",
1225 reqnum, tickdiff, tickdata); 1277 reqnum, tickdiff, tickdata);
1226 } 1278 }
1227 } 1279 }
@@ -1234,4 +1286,4 @@ namespace OpenSim.Framework
1234 return deserial; 1286 return deserial;
1235 } 1287 }
1236 } 1288 }
1237} \ No newline at end of file 1289}