Add ability to turn on/off logging of outgoing HTTP requests flowing through WebUtil.

This is for debugging purposes.
This is controlled via the "debug http" command which can already log incoming requests.
This now gains a mandatory parameter of in, out or all to control what is logged.
Log messages are also shortened and labelled and HTTP IN or HTTP OUT to be consistent with existing UDP PACKET IN and PACKET OUT messages.

OpenSim/Framework/Servers/HttpServer/BaseHttpServer.cs

@@ -529,7 +529,7 @@ namespace OpenSim.Framework.Servers.HttpServer
     
                             if (DebugLevel >= 3)
                                 m_log.DebugFormat(
-                                    "[BASE HTTP SERVER]: Found a {0} content type handler for {1} {2}",
+                                    "[BASE HTTP SERVER]: HTTP IN {0} content type handler {1} {2}",
                                     request.ContentType, request.HttpMethod, request.Url.PathAndQuery);
     
                             buffer = HandleHTTPRequest(request, response);
@@ -541,7 +541,7 @@ namespace OpenSim.Framework.Servers.HttpServer
     
                             if (DebugLevel >= 3)
                                 m_log.DebugFormat(
-                                    "[BASE HTTP SERVER]: Found a {0} content type handler for {1} {2}",
+                                    "[BASE HTTP SERVER]: HTTP IN {0} content type handler {1} {2}",
                                     request.ContentType, request.HttpMethod, request.Url.PathAndQuery);
     
                             buffer = HandleLLSDRequests(request, response);
@@ -649,7 +649,7 @@ namespace OpenSim.Framework.Servers.HttpServer
         private void LogIncomingToStreamHandler(OSHttpRequest request, IRequestHandler requestHandler)
         {
             m_log.DebugFormat(
-                "[BASE HTTP SERVER]: Found stream handler for {0} {1} {2} {3}",
+                "[BASE HTTP SERVER]: HTTP IN stream handler {0} {1} {2} {3}",
                 request.HttpMethod, request.Url.PathAndQuery, requestHandler.Name, requestHandler.Description);
 
             if (DebugLevel >= 4)
@@ -659,7 +659,7 @@ namespace OpenSim.Framework.Servers.HttpServer
         private void LogIncomingToContentTypeHandler(OSHttpRequest request)
         {
             m_log.DebugFormat(
-                "[BASE HTTP SERVER]: Found a {0} content type handler for {1} {2}",
+                "[BASE HTTP SERVER]: HTTP IN {0} content type handler {1} {2}",
                 request.ContentType, request.HttpMethod, request.Url.PathAndQuery);
 
             if (DebugLevel >= 4)
@@ -669,7 +669,7 @@ namespace OpenSim.Framework.Servers.HttpServer
         private void LogIncomingToXmlRpcHandler(OSHttpRequest request)
         {
             m_log.DebugFormat(
-                "[BASE HTTP SERVER]: Assuming a generic XMLRPC request for {0} {1}",
+                "[BASE HTTP SERVER]: HTTP IN assumed generic XMLRPC request {0} {1}",
                 request.HttpMethod, request.Url.PathAndQuery);
 
             if (DebugLevel >= 4)

OpenSim/Framework/Servers/MainServer.cs

@@ -48,9 +48,11 @@ namespace OpenSim.Framework.Servers
         /// Control the printing of certain debug messages.
         /// </summary>
         /// <remarks>
-        /// If DebugLevel >= 1, then short warnings are logged when receiving bad input data.
+        /// 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 >= 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 >= 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.
         /// </remarks>
         public static int DebugLevel
         {
@@ -102,7 +104,6 @@ namespace OpenSim.Framework.Servers
             get { return new Dictionary<uint, BaseHttpServer>(m_Servers); }
         }
 
-
         public static void RegisterHttpConsoleCommands(ICommandConsole console)
         {
             console.Commands.AddCommand(
@@ -111,15 +112,18 @@ namespace OpenSim.Framework.Servers
                 "Show all registered http handlers", HandleShowHttpHandlersCommand);
 
             console.Commands.AddCommand(
-                "Debug", false, "debug http", "debug http [<level>]",
+                "Debug", false, "debug http", "debug http <in|out|all> [<level>]",
-                "Turn on inbound non-poll http request debugging.",
+                "Turn on http request logging.",
-                  "If level <= 0, then no extra logging is done.\n"
+                "If in or all and\n"
-                + "If level >= 1, then short warnings are logged when receiving bad input data.\n"
+                    + "  level <= 0, then no extra logging is done.\n"
-                + "If level >= 2, then long warnings are logged when receiving bad input data.\n"
+                    + "  level >= 1, then short warnings are logged when receiving bad input data.\n"
-                + "If level >= 3, then short notices about all incoming non-poll HTTP requests are logged.\n"
+                    + "  level >= 2, then long warnings are logged when receiving bad input data.\n"
-                + "If level >= 4, then a sample from the beginning of the incoming data is logged.\n"
+                    + "  level >= 3, then short notices about all incoming non-poll HTTP requests are logged.\n"
-                + "If level >= 5, then the entire incoming data is logged.\n"
+                    + "  level >= 4, then a sample from the beginning of the incoming data is logged.\n"
-                + "If no level is specified then the current level is returned.",
+                    + "  level >= 5, 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",
                 HandleDebugHttpCommand);
         }
 
@@ -127,24 +131,63 @@ namespace OpenSim.Framework.Servers
         /// Turn on some debugging values for OpenSim.
         /// </summary>
         /// <param name="args"></param>
-        private static void HandleDebugHttpCommand(string module, string[] args)
+        private static void HandleDebugHttpCommand(string module, string[] cmdparams)
         {
-            if (args.Length == 3)
+            if (cmdparams.Length < 3)
             {
+                MainConsole.Instance.Output("Usage: debug http <in|out|all> 0..5");
+                return;
+            }
+
+            bool inReqs = false;
+            bool outReqs = false;
+            bool allReqs = false;
+
+            string subCommand = cmdparams[2];
+
+            if (subCommand == "in")
+                inReqs = true;
+            else if (subCommand == "out")
+                outReqs = true;
+            else
+                allReqs = true;
+
+            if (cmdparams.Length >= 4)
+            {
+                string rawNewDebug = cmdparams[3];
                 int newDebug;
-                if (int.TryParse(args[2], out newDebug))
+
+                if (!int.TryParse(rawNewDebug, out newDebug))
+                {
+                    MainConsole.Instance.OutputFormat("{0} is not a valid debug level", rawNewDebug);
+                    return;
+                }
+
+                if (newDebug < 0 || newDebug > 5)
+                {
+                    MainConsole.Instance.OutputFormat("{0} is outside the valid debug level range of 0..5", newDebug);
+                    return;
+                }
+
+                if (allReqs || inReqs)
                 {
                     MainServer.DebugLevel = newDebug;
-                    MainConsole.Instance.OutputFormat("Debug http 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);
                 }
-            }
-            else if (args.Length == 2)
-            {
-                MainConsole.Instance.OutputFormat("Current debug http level is {0}", MainServer.DebugLevel);
             }
             else
             {
-                MainConsole.Instance.Output("Usage: debug http 0..5");
+                if (allReqs || inReqs)
+                    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);
             }
         }
 

OpenSim/Framework/WebUtil.cs

@@ -53,6 +53,14 @@ namespace OpenSim.Framework
                 LogManager.GetLogger(
                 MethodBase.GetCurrentMethod().DeclaringType);
 
+        /// <summary>
+        /// Control the printing of certain debug messages.
+        /// </summary>
+        /// <remarks>
+        /// If DebugLevel >= 3 then short notices about outgoing HTTP requests are logged.
+        /// </remarks>
+        public static int DebugLevel { get; set; }
+
         /// <summary>
         /// Request number for diagnostic purposes.
         /// </summary>
@@ -146,7 +154,11 @@ namespace OpenSim.Framework
         private static OSDMap ServiceOSDRequestWorker(string url, OSDMap data, string method, int timeout, bool compressed)
         {
             int reqnum = RequestNumber++;
-            // m_log.DebugFormat("[WEB UTIL]: <{0}> start osd request for {1}, method {2}",reqnum,url,method);
+
+            if (DebugLevel >= 3)
+                m_log.DebugFormat(
+                    "[WEB UTIL]: HTTP OUT {0} ServiceOSD {1} {2} (timeout {3}, compressed {4})",
+                    reqnum, method, url, timeout, compressed);
 
             string errorMessage = "unknown error";
             int tickstart = Util.EnvironmentTickCount();
@@ -317,7 +329,11 @@ namespace OpenSim.Framework
         {
             int reqnum = RequestNumber++;
             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);
+
+            if (DebugLevel >= 3)
+                m_log.DebugFormat(
+                    "[WEB UTIL]: HTTP OUT {0} ServiceForm {1} {2} (timeout {3})",
+                    reqnum, method, url, timeout);
             
             string errorMessage = "unknown error";
             int tickstart = Util.EnvironmentTickCount();
@@ -643,7 +659,6 @@ namespace OpenSim.Framework
         /// <returns></returns>
         public static string[] GetPreferredImageTypes(string accept)
         {
-
             if (accept == null || accept == string.Empty)
                 return new string[0];
 
@@ -695,13 +710,15 @@ namespace OpenSim.Framework
                 string requestUrl, TRequest obj, Action<TResponse> action)
         {
             int reqnum = WebUtil.RequestNumber++;
-            // m_log.DebugFormat("[WEB UTIL]: <{0}> start osd request for {1}, method {2}",reqnum,url,method);
+
+            if (WebUtil.DebugLevel >= 3)
+                m_log.DebugFormat(
+                    "[WEB UTIL]: HTTP OUT {0} AsynchronousRequestObject {1} {2}",
+                    reqnum, verb, requestUrl);
 
             int tickstart = Util.EnvironmentTickCount();
             int tickdata = 0;
 
-            //            m_log.DebugFormat("[ASYNC REQUEST]: Starting {0} {1}", verb, requestUrl);
-
             Type type = typeof(TRequest);
 
             WebRequest request = WebRequest.Create(requestUrl);
@@ -882,7 +899,11 @@ namespace OpenSim.Framework
         public static string MakeRequest(string verb, string requestUrl, string obj)
         {
             int reqnum = WebUtil.RequestNumber++;
-            // m_log.DebugFormat("[WEB UTIL]: <{0}> start osd request for {1}, method {2}",reqnum,url,method);
+
+            if (WebUtil.DebugLevel >= 3)
+                m_log.DebugFormat(
+                    "[WEB UTIL]: HTTP OUT {0} SynchronousRestForms {1} {2}",
+                    reqnum, verb, requestUrl);
 
             int tickstart = Util.EnvironmentTickCount();
             int tickdata = 0;
@@ -998,7 +1019,11 @@ namespace OpenSim.Framework
         public static TResponse MakeRequest<TRequest, TResponse>(string verb, string requestUrl, TRequest obj)
         {
             int reqnum = WebUtil.RequestNumber++;
-            // m_log.DebugFormat("[WEB UTIL]: <{0}> start osd request for {1}, method {2}",reqnum,url,method);
+
+            if (WebUtil.DebugLevel >= 3)
+                m_log.DebugFormat(
+                    "[WEB UTIL]: HTTP OUT {0} SynchronousRestObject {1} {2}",
+                    reqnum, verb, requestUrl);
 
             int tickstart = Util.EnvironmentTickCount();
             int tickdata = 0;