aboutsummaryrefslogtreecommitdiffstatshomepage
path: root/OpenSim
diff options
context:
space:
mode:
authorJustin Clark-Casey (justincc)2012-09-20 23:18:19 +0100
committerJustin Clark-Casey (justincc)2012-09-20 23:18:19 +0100
commita5b3989e5db0a3b22e44b84412227a8e487bcef2 (patch)
tree31b2f0293de73d102f0f8d08975655cf993c8137 /OpenSim
parentAdd ability to turn on/off logging of outgoing HTTP requests flowing through ... (diff)
downloadopensim-SC_OLD-a5b3989e5db0a3b22e44b84412227a8e487bcef2.zip
opensim-SC_OLD-a5b3989e5db0a3b22e44b84412227a8e487bcef2.tar.gz
opensim-SC_OLD-a5b3989e5db0a3b22e44b84412227a8e487bcef2.tar.bz2
opensim-SC_OLD-a5b3989e5db0a3b22e44b84412227a8e487bcef2.tar.xz
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.
Diffstat (limited to 'OpenSim')
-rw-r--r--OpenSim/Framework/Servers/HttpServer/BaseHttpServer.cs47
-rw-r--r--OpenSim/Framework/Servers/MainServer.cs48
-rw-r--r--OpenSim/Framework/WebUtil.cs24
3 files changed, 87 insertions, 32 deletions
diff --git a/OpenSim/Framework/Servers/HttpServer/BaseHttpServer.cs b/OpenSim/Framework/Servers/HttpServer/BaseHttpServer.cs
index f93b3dd..4e04dd8 100644
--- a/OpenSim/Framework/Servers/HttpServer/BaseHttpServer.cs
+++ b/OpenSim/Framework/Servers/HttpServer/BaseHttpServer.cs
@@ -54,6 +54,12 @@ namespace OpenSim.Framework.Servers.HttpServer
54 private static readonly ILog m_log = LogManager.GetLogger(MethodBase.GetCurrentMethod().DeclaringType); 54 private static readonly ILog m_log = LogManager.GetLogger(MethodBase.GetCurrentMethod().DeclaringType);
55 private HttpServerLogWriter httpserverlog = new HttpServerLogWriter(); 55 private HttpServerLogWriter httpserverlog = new HttpServerLogWriter();
56 56
57 /// <summary>
58 /// Gets or sets the debug level.
59 /// </summary>
60 /// <value>
61 /// See MainServer.DebugLevel.
62 /// </value>
57 public int DebugLevel { get; set; } 63 public int DebugLevel { get; set; }
58 64
59 private volatile int NotSocketErrors = 0; 65 private volatile int NotSocketErrors = 0;
@@ -529,8 +535,8 @@ namespace OpenSim.Framework.Servers.HttpServer
529 535
530 if (DebugLevel >= 3) 536 if (DebugLevel >= 3)
531 m_log.DebugFormat( 537 m_log.DebugFormat(
532 "[BASE HTTP SERVER]: HTTP IN {0} content type handler {1} {2}", 538 "[BASE HTTP SERVER]: HTTP IN {0} content type handler {1} {2} from {3}",
533 request.ContentType, request.HttpMethod, request.Url.PathAndQuery); 539 request.ContentType, request.HttpMethod, request.Url.PathAndQuery, request.RemoteIPEndPoint);
534 540
535 buffer = HandleHTTPRequest(request, response); 541 buffer = HandleHTTPRequest(request, response);
536 break; 542 break;
@@ -541,8 +547,8 @@ namespace OpenSim.Framework.Servers.HttpServer
541 547
542 if (DebugLevel >= 3) 548 if (DebugLevel >= 3)
543 m_log.DebugFormat( 549 m_log.DebugFormat(
544 "[BASE HTTP SERVER]: HTTP IN {0} content type handler {1} {2}", 550 "[BASE HTTP SERVER]: HTTP IN {0} content type handler {1} {2} from {3}",
545 request.ContentType, request.HttpMethod, request.Url.PathAndQuery); 551 request.ContentType, request.HttpMethod, request.Url.PathAndQuery, request.RemoteIPEndPoint);
546 552
547 buffer = HandleLLSDRequests(request, response); 553 buffer = HandleLLSDRequests(request, response);
548 break; 554 break;
@@ -640,7 +646,18 @@ namespace OpenSim.Framework.Servers.HttpServer
640 uriString, 646 uriString,
641 requestHandler != null ? requestHandler.Name : "", 647 requestHandler != null ? requestHandler.Name : "",
642 requestHandler != null ? requestHandler.Description : "", 648 requestHandler != null ? requestHandler.Description : "",
643 request.RemoteIPEndPoint.ToString(), 649 request.RemoteIPEndPoint,
650 tickdiff);
651 }
652 else if (DebugLevel >= 4)
653 {
654 m_log.DebugFormat(
655 "[BASE HTTP SERVER]: HTTP IN {0} {1} {2} {3} from {4} took {5}ms",
656 requestMethod,
657 uriString,
658 requestHandler != null ? requestHandler.Name : "",
659 requestHandler != null ? requestHandler.Description : "",
660 request.RemoteIPEndPoint,
644 tickdiff); 661 tickdiff);
645 } 662 }
646 } 663 }
@@ -649,30 +666,30 @@ namespace OpenSim.Framework.Servers.HttpServer
649 private void LogIncomingToStreamHandler(OSHttpRequest request, IRequestHandler requestHandler) 666 private void LogIncomingToStreamHandler(OSHttpRequest request, IRequestHandler requestHandler)
650 { 667 {
651 m_log.DebugFormat( 668 m_log.DebugFormat(
652 "[BASE HTTP SERVER]: HTTP IN stream handler {0} {1} {2} {3}", 669 "[BASE HTTP SERVER]: HTTP IN stream handler {0} {1} {2} {3} from {4}",
653 request.HttpMethod, request.Url.PathAndQuery, requestHandler.Name, requestHandler.Description); 670 request.HttpMethod, request.Url.PathAndQuery, requestHandler.Name, requestHandler.Description, request.RemoteIPEndPoint);
654 671
655 if (DebugLevel >= 4) 672 if (DebugLevel >= 5)
656 LogIncomingInDetail(request); 673 LogIncomingInDetail(request);
657 } 674 }
658 675
659 private void LogIncomingToContentTypeHandler(OSHttpRequest request) 676 private void LogIncomingToContentTypeHandler(OSHttpRequest request)
660 { 677 {
661 m_log.DebugFormat( 678 m_log.DebugFormat(
662 "[BASE HTTP SERVER]: HTTP IN {0} content type handler {1} {2}", 679 "[BASE HTTP SERVER]: HTTP IN {0} content type handler {1} {2} from {3}",
663 request.ContentType, request.HttpMethod, request.Url.PathAndQuery); 680 request.ContentType, request.HttpMethod, request.Url.PathAndQuery, request.RemoteIPEndPoint);
664 681
665 if (DebugLevel >= 4) 682 if (DebugLevel >= 5)
666 LogIncomingInDetail(request); 683 LogIncomingInDetail(request);
667 } 684 }
668 685
669 private void LogIncomingToXmlRpcHandler(OSHttpRequest request) 686 private void LogIncomingToXmlRpcHandler(OSHttpRequest request)
670 { 687 {
671 m_log.DebugFormat( 688 m_log.DebugFormat(
672 "[BASE HTTP SERVER]: HTTP IN assumed generic XMLRPC request {0} {1}", 689 "[BASE HTTP SERVER]: HTTP IN assumed generic XMLRPC request {0} {1} from {2}",
673 request.HttpMethod, request.Url.PathAndQuery); 690 request.HttpMethod, request.Url.PathAndQuery, request.RemoteIPEndPoint);
674 691
675 if (DebugLevel >= 4) 692 if (DebugLevel >= 5)
676 LogIncomingInDetail(request); 693 LogIncomingInDetail(request);
677 } 694 }
678 695
@@ -682,7 +699,7 @@ namespace OpenSim.Framework.Servers.HttpServer
682 { 699 {
683 string output; 700 string output;
684 701
685 if (DebugLevel == 4) 702 if (DebugLevel == 5)
686 { 703 {
687 const int sampleLength = 80; 704 const int sampleLength = 80;
688 char[] sampleChars = new char[sampleLength]; 705 char[] sampleChars = new char[sampleLength];
diff --git a/OpenSim/Framework/Servers/MainServer.cs b/OpenSim/Framework/Servers/MainServer.cs
index b7a133e..72f9cce 100644
--- a/OpenSim/Framework/Servers/MainServer.cs
+++ b/OpenSim/Framework/Servers/MainServer.cs
@@ -51,8 +51,9 @@ namespace OpenSim.Framework.Servers
51 /// If DebugLevel >= 1 then short warnings are logged when receiving bad input data. 51 /// If DebugLevel >= 1 then short warnings are logged when receiving bad input data.
52 /// If DebugLevel >= 2 then long warnings are logged when receiving bad input data. 52 /// If DebugLevel >= 2 then long warnings are logged when receiving bad input data.
53 /// If DebugLevel >= 3 then short notices about all incoming non-poll HTTP requests are logged. 53 /// If DebugLevel >= 3 then short notices about all incoming non-poll HTTP requests are logged.
54 /// If DebugLevel >= 4 then the start of the body of incoming non-poll HTTP requests will be logged. 54 /// If DebugLevel >= 4 then the time taken to fulfill the request is logged.
55 /// If DebugLevel >= 5 then the entire body of incoming non-poll HTTP requests will be logged. 55 /// If DebugLevel >= 5 then the start of the body of incoming non-poll HTTP requests will be logged.
56 /// If DebugLevel >= 6 then the entire body of incoming non-poll HTTP requests will be logged.
56 /// </remarks> 57 /// </remarks>
57 public static int DebugLevel 58 public static int DebugLevel
58 { 59 {
@@ -115,15 +116,17 @@ namespace OpenSim.Framework.Servers
115 "Debug", false, "debug http", "debug http <in|out|all> [<level>]", 116 "Debug", false, "debug http", "debug http <in|out|all> [<level>]",
116 "Turn on http request logging.", 117 "Turn on http request logging.",
117 "If in or all and\n" 118 "If in or all and\n"
118 + " level <= 0, then no extra logging is done.\n" 119 + " level <= 0 then no extra logging is done.\n"
119 + " level >= 1, then short warnings are logged when receiving bad input data.\n" 120 + " level >= 1 then short warnings are logged when receiving bad input data.\n"
120 + " level >= 2, then long warnings are logged when receiving bad input data.\n" 121 + " level >= 2 then long warnings are logged when receiving bad input data.\n"
121 + " level >= 3, then short notices about all incoming non-poll HTTP requests are logged.\n" 122 + " level >= 3 then short notices about all incoming non-poll HTTP requests are logged.\n"
122 + " level >= 4, then a sample from the beginning of the incoming data is logged.\n" 123 + " level >= 4 then the time taken to fulfill the request is logged.\n"
123 + " level >= 5, then the entire incoming data is logged.\n" 124 + " level >= 5 then a sample from the beginning of the incoming data is logged.\n"
125 + " level >= 6 then the entire incoming data is logged.\n"
124 + " no level is specified then the current level is returned.\n\n" 126 + " no level is specified then the current level is returned.\n\n"
125 + "If out or all and\n" 127 + "If out or all and\n"
126 + " level >= 3. then short notices about all outgoing requests going through WebUtil are logged.\n", 128 + " level >= 3 then short notices about all outgoing requests going through WebUtil are logged.\n"
129 + " level >= 4 then the time taken to fulfill the request is logged.\n",
127 HandleDebugHttpCommand); 130 HandleDebugHttpCommand);
128 } 131 }
129 132
@@ -135,7 +138,7 @@ namespace OpenSim.Framework.Servers
135 { 138 {
136 if (cmdparams.Length < 3) 139 if (cmdparams.Length < 3)
137 { 140 {
138 MainConsole.Instance.Output("Usage: debug http <in|out|all> 0..5"); 141 MainConsole.Instance.Output("Usage: debug http <in|out|all> 0..6");
139 return; 142 return;
140 } 143 }
141 144
@@ -145,12 +148,23 @@ namespace OpenSim.Framework.Servers
145 148
146 string subCommand = cmdparams[2]; 149 string subCommand = cmdparams[2];
147 150
148 if (subCommand == "in") 151 if (subCommand.ToLower() == "in")
152 {
149 inReqs = true; 153 inReqs = true;
150 else if (subCommand == "out") 154 }
155 else if (subCommand.ToLower() == "out")
156 {
151 outReqs = true; 157 outReqs = true;
152 else 158 }
159 else if (subCommand.ToLower() == "all")
160 {
153 allReqs = true; 161 allReqs = true;
162 }
163 else
164 {
165 MainConsole.Instance.Output("You must specify in, out or all");
166 return;
167 }
154 168
155 if (cmdparams.Length >= 4) 169 if (cmdparams.Length >= 4)
156 { 170 {
@@ -172,22 +186,22 @@ namespace OpenSim.Framework.Servers
172 if (allReqs || inReqs) 186 if (allReqs || inReqs)
173 { 187 {
174 MainServer.DebugLevel = newDebug; 188 MainServer.DebugLevel = newDebug;
175 MainConsole.Instance.OutputFormat("In debug level set to {0}", newDebug); 189 MainConsole.Instance.OutputFormat("IN debug level set to {0}", newDebug);
176 } 190 }
177 191
178 if (allReqs || outReqs) 192 if (allReqs || outReqs)
179 { 193 {
180 WebUtil.DebugLevel = newDebug; 194 WebUtil.DebugLevel = newDebug;
181 MainConsole.Instance.OutputFormat("Out debug level set to {0}", newDebug); 195 MainConsole.Instance.OutputFormat("OUT debug level set to {0}", newDebug);
182 } 196 }
183 } 197 }
184 else 198 else
185 { 199 {
186 if (allReqs || inReqs) 200 if (allReqs || inReqs)
187 MainConsole.Instance.OutputFormat("Current in debug level is {0}", MainServer.DebugLevel); 201 MainConsole.Instance.OutputFormat("Current IN debug level is {0}", MainServer.DebugLevel);
188 202
189 if (allReqs || outReqs) 203 if (allReqs || outReqs)
190 MainConsole.Instance.OutputFormat("Current out debug level is {0}", WebUtil.DebugLevel); 204 MainConsole.Instance.OutputFormat("Current OUT debug level is {0}", WebUtil.DebugLevel);
191 } 205 }
192 } 206 }
193 207
diff --git a/OpenSim/Framework/WebUtil.cs b/OpenSim/Framework/WebUtil.cs
index 7c4e852..64d61f1 100644
--- a/OpenSim/Framework/WebUtil.cs
+++ b/OpenSim/Framework/WebUtil.cs
@@ -250,6 +250,10 @@ namespace OpenSim.Framework
250 strBuffer != null 250 strBuffer != null
251 ? (strBuffer.Length > MaxRequestDiagLength ? strBuffer.Remove(MaxRequestDiagLength) : strBuffer) 251 ? (strBuffer.Length > MaxRequestDiagLength ? strBuffer.Remove(MaxRequestDiagLength) : strBuffer)
252 : ""); 252 : "");
253 else if (DebugLevel >= 4)
254 m_log.DebugFormat(
255 "[WEB UTIL]: HTTP OUT {0} took {1}ms, {2}ms writing",
256 reqnum, tickdiff, tickdata);
253 } 257 }
254 258
255 m_log.DebugFormat( 259 m_log.DebugFormat(
@@ -405,6 +409,10 @@ namespace OpenSim.Framework
405 queryString != null 409 queryString != null
406 ? (queryString.Length > MaxRequestDiagLength) ? queryString.Remove(MaxRequestDiagLength) : queryString 410 ? (queryString.Length > MaxRequestDiagLength) ? queryString.Remove(MaxRequestDiagLength) : queryString
407 : ""); 411 : "");
412 else if (DebugLevel >= 4)
413 m_log.DebugFormat(
414 "[WEB UTIL]: HTTP OUT {0} took {1}ms, {2}ms writing",
415 reqnum, tickdiff, tickdata);
408 } 416 }
409 417
410 m_log.WarnFormat("[SERVICE FORM]: <{0}> form request to {1} failed: {2}", reqnum, url, errorMessage); 418 m_log.WarnFormat("[SERVICE FORM]: <{0}> form request to {1} failed: {2}", reqnum, url, errorMessage);
@@ -879,6 +887,12 @@ namespace OpenSim.Framework
879 tickdata, 887 tickdata,
880 originalRequest); 888 originalRequest);
881 } 889 }
890 else if (WebUtil.DebugLevel >= 4)
891 {
892 m_log.DebugFormat(
893 "[WEB UTIL]: HTTP OUT {0} took {1}ms, {2}ms writing",
894 reqnum, tickdiff, tickdata);
895 }
882 } 896 }
883 } 897 }
884 898
@@ -995,6 +1009,10 @@ namespace OpenSim.Framework
995 tickdiff, 1009 tickdiff,
996 tickdata, 1010 tickdata,
997 obj.Length > WebUtil.MaxRequestDiagLength ? obj.Remove(WebUtil.MaxRequestDiagLength) : obj); 1011 obj.Length > WebUtil.MaxRequestDiagLength ? obj.Remove(WebUtil.MaxRequestDiagLength) : obj);
1012 else if (WebUtil.DebugLevel >= 4)
1013 m_log.DebugFormat(
1014 "[WEB UTIL]: HTTP OUT {0} took {1}ms, {2}ms writing",
1015 reqnum, tickdiff, tickdata);
998 1016
999 return respstring; 1017 return respstring;
1000 } 1018 }
@@ -1144,6 +1162,12 @@ namespace OpenSim.Framework
1144 tickdata, 1162 tickdata,
1145 originalRequest); 1163 originalRequest);
1146 } 1164 }
1165 else if (WebUtil.DebugLevel >= 4)
1166 {
1167 m_log.DebugFormat(
1168 "[WEB UTIL]: HTTP OUT {0} took {1}ms, {2}ms writing",
1169 reqnum, tickdiff, tickdata);
1170 }
1147 1171
1148 return deserial; 1172 return deserial;
1149 } 1173 }