diff options
Diffstat (limited to 'OpenSim/Framework')
-rw-r--r-- | OpenSim/Framework/WebUtil.cs | 273 |
1 files changed, 194 insertions, 79 deletions
diff --git a/OpenSim/Framework/WebUtil.cs b/OpenSim/Framework/WebUtil.cs index d2aa538..478d2a7 100644 --- a/OpenSim/Framework/WebUtil.cs +++ b/OpenSim/Framework/WebUtil.cs | |||
@@ -53,19 +53,36 @@ namespace OpenSim.Framework | |||
53 | LogManager.GetLogger( | 53 | LogManager.GetLogger( |
54 | MethodBase.GetCurrentMethod().DeclaringType); | 54 | MethodBase.GetCurrentMethod().DeclaringType); |
55 | 55 | ||
56 | private static int m_requestNumber = 0; | 56 | /// <summary> |
57 | /// Request number for diagnostic purposes. | ||
58 | /// </summary> | ||
59 | public static int RequestNumber = 0; | ||
57 | 60 | ||
58 | // this is the header field used to communicate the local request id | 61 | /// <summary> |
59 | // used for performance and debugging | 62 | /// this is the header field used to communicate the local request id |
63 | /// used for performance and debugging | ||
64 | /// </summary> | ||
60 | public const string OSHeaderRequestID = "opensim-request-id"; | 65 | public const string OSHeaderRequestID = "opensim-request-id"; |
61 | 66 | ||
62 | // number of milliseconds a call can take before it is considered | 67 | /// <summary> |
63 | // a "long" call for warning & debugging purposes | 68 | /// Number of milliseconds a call can take before it is considered |
69 | /// a "long" call for warning & debugging purposes | ||
70 | /// </summary> | ||
64 | public const int LongCallTime = 500; | 71 | public const int LongCallTime = 500; |
65 | 72 | ||
66 | // dictionary of end points | 73 | /// <summary> |
74 | /// The maximum length of any data logged because of a long request time. | ||
75 | /// </summary> | ||
76 | /// <remarks> | ||
77 | /// This is to truncate any really large post data, such as an asset. In theory, the first section should | ||
78 | /// give us useful information about the call (which agent it relates to if applicable, etc.). | ||
79 | /// </remarks> | ||
80 | public const int MaxRequestDiagLength = 100; | ||
81 | |||
82 | /// <summary> | ||
83 | /// Dictionary of end points | ||
84 | /// </summary> | ||
67 | private static Dictionary<string,object> m_endpointSerializer = new Dictionary<string,object>(); | 85 | private static Dictionary<string,object> m_endpointSerializer = new Dictionary<string,object>(); |
68 | |||
69 | 86 | ||
70 | private static object EndPointLock(string url) | 87 | private static object EndPointLock(string url) |
71 | { | 88 | { |
@@ -128,12 +145,13 @@ namespace OpenSim.Framework | |||
128 | 145 | ||
129 | private static OSDMap ServiceOSDRequestWorker(string url, OSDMap data, string method, int timeout, bool compressed) | 146 | private static OSDMap ServiceOSDRequestWorker(string url, OSDMap data, string method, int timeout, bool compressed) |
130 | { | 147 | { |
131 | int reqnum = m_requestNumber++; | 148 | int reqnum = RequestNumber++; |
132 | // m_log.DebugFormat("[WEB UTIL]: <{0}> start osd request for {1}, method {2}",reqnum,url,method); | 149 | // m_log.DebugFormat("[WEB UTIL]: <{0}> start osd request for {1}, method {2}",reqnum,url,method); |
133 | 150 | ||
134 | string errorMessage = "unknown error"; | 151 | string errorMessage = "unknown error"; |
135 | int tickstart = Util.EnvironmentTickCount(); | 152 | int tickstart = Util.EnvironmentTickCount(); |
136 | int tickdata = 0; | 153 | int tickdata = 0; |
154 | string strBuffer = null; | ||
137 | 155 | ||
138 | try | 156 | try |
139 | { | 157 | { |
@@ -148,7 +166,7 @@ namespace OpenSim.Framework | |||
148 | // If there is some input, write it into the request | 166 | // If there is some input, write it into the request |
149 | if (data != null) | 167 | if (data != null) |
150 | { | 168 | { |
151 | string strBuffer = OSDParser.SerializeJsonString(data); | 169 | strBuffer = OSDParser.SerializeJsonString(data); |
152 | byte[] buffer = System.Text.Encoding.UTF8.GetBytes(strBuffer); | 170 | byte[] buffer = System.Text.Encoding.UTF8.GetBytes(strBuffer); |
153 | 171 | ||
154 | if (compressed) | 172 | if (compressed) |
@@ -208,11 +226,18 @@ namespace OpenSim.Framework | |||
208 | } | 226 | } |
209 | finally | 227 | finally |
210 | { | 228 | { |
211 | // This just dumps a warning for any operation that takes more than 100 ms | ||
212 | int tickdiff = Util.EnvironmentTickCountSubtract(tickstart); | 229 | int tickdiff = Util.EnvironmentTickCountSubtract(tickstart); |
213 | if (tickdiff > LongCallTime) | 230 | if (tickdiff > LongCallTime) |
214 | m_log.DebugFormat("[WEB UTIL]: osd request <{0}> (URI:{1}, METHOD:{2}) took {3}ms overall, {4}ms writing", | 231 | m_log.InfoFormat( |
215 | reqnum,url,method,tickdiff,tickdata); | 232 | "[OSD REQUEST]: Slow request to <{0}> {1} {2} took {3}ms, {4}ms writing, {5}", |
233 | reqnum, | ||
234 | method, | ||
235 | url, | ||
236 | tickdiff, | ||
237 | tickdata, | ||
238 | strBuffer != null | ||
239 | ? (strBuffer.Length > MaxRequestDiagLength ? strBuffer.Remove(MaxRequestDiagLength) : strBuffer) | ||
240 | : ""); | ||
216 | } | 241 | } |
217 | 242 | ||
218 | m_log.DebugFormat( | 243 | m_log.DebugFormat( |
@@ -290,17 +315,17 @@ namespace OpenSim.Framework | |||
290 | 315 | ||
291 | private static OSDMap ServiceFormRequestWorker(string url, NameValueCollection data, int timeout) | 316 | private static OSDMap ServiceFormRequestWorker(string url, NameValueCollection data, int timeout) |
292 | { | 317 | { |
293 | int reqnum = m_requestNumber++; | 318 | int reqnum = RequestNumber++; |
294 | string method = (data != null && data["RequestMethod"] != null) ? data["RequestMethod"] : "unknown"; | 319 | string method = (data != null && data["RequestMethod"] != null) ? data["RequestMethod"] : "unknown"; |
295 | // m_log.DebugFormat("[WEB UTIL]: <{0}> start form request for {1}, method {2}",reqnum,url,method); | 320 | // m_log.DebugFormat("[WEB UTIL]: <{0}> start form request for {1}, method {2}",reqnum,url,method); |
296 | 321 | ||
297 | string errorMessage = "unknown error"; | 322 | string errorMessage = "unknown error"; |
298 | int tickstart = Util.EnvironmentTickCount(); | 323 | int tickstart = Util.EnvironmentTickCount(); |
299 | int tickdata = 0; | 324 | int tickdata = 0; |
325 | string queryString = null; | ||
300 | 326 | ||
301 | try | 327 | try |
302 | { | 328 | { |
303 | |||
304 | HttpWebRequest request = (HttpWebRequest)HttpWebRequest.Create(url); | 329 | HttpWebRequest request = (HttpWebRequest)HttpWebRequest.Create(url); |
305 | request.Method = "POST"; | 330 | request.Method = "POST"; |
306 | request.Timeout = timeout; | 331 | request.Timeout = timeout; |
@@ -311,7 +336,7 @@ namespace OpenSim.Framework | |||
311 | 336 | ||
312 | if (data != null) | 337 | if (data != null) |
313 | { | 338 | { |
314 | string queryString = BuildQueryString(data); | 339 | queryString = BuildQueryString(data); |
315 | byte[] buffer = System.Text.Encoding.UTF8.GetBytes(queryString); | 340 | byte[] buffer = System.Text.Encoding.UTF8.GetBytes(queryString); |
316 | 341 | ||
317 | request.ContentLength = buffer.Length; | 342 | request.ContentLength = buffer.Length; |
@@ -354,11 +379,19 @@ namespace OpenSim.Framework | |||
354 | { | 379 | { |
355 | int tickdiff = Util.EnvironmentTickCountSubtract(tickstart); | 380 | int tickdiff = Util.EnvironmentTickCountSubtract(tickstart); |
356 | if (tickdiff > LongCallTime) | 381 | if (tickdiff > LongCallTime) |
357 | m_log.InfoFormat("[WEB UTIL]: form request <{0}> (URI:{1}, METHOD:{2}) took {3}ms overall, {4}ms writing", | 382 | m_log.InfoFormat( |
358 | reqnum,url,method,tickdiff,tickdata); | 383 | "[SERVICE FORM]: Slow request to <{0}> {1} {2} took {3}ms, {4}ms writing, {5}", |
384 | reqnum, | ||
385 | method, | ||
386 | url, | ||
387 | tickdiff, | ||
388 | tickdata, | ||
389 | queryString != null | ||
390 | ? (queryString.Length > MaxRequestDiagLength) ? queryString.Remove(MaxRequestDiagLength) : queryString | ||
391 | : ""); | ||
359 | } | 392 | } |
360 | 393 | ||
361 | m_log.WarnFormat("[WEB UTIL]: <{0}> form request to {1} failed: {2}", reqnum, url, errorMessage); | 394 | m_log.WarnFormat("[SERVICE FORM]: <{0}> form request to {1} failed: {2}", reqnum, url, errorMessage); |
362 | 395 | ||
363 | return ErrorResponseMap(errorMessage); | 396 | return ErrorResponseMap(errorMessage); |
364 | } | 397 | } |
@@ -639,8 +672,6 @@ namespace OpenSim.Framework | |||
639 | 672 | ||
640 | return new string[0]; | 673 | return new string[0]; |
641 | } | 674 | } |
642 | |||
643 | |||
644 | } | 675 | } |
645 | 676 | ||
646 | public static class AsynchronousRestObjectRequester | 677 | public static class AsynchronousRestObjectRequester |
@@ -663,6 +694,12 @@ namespace OpenSim.Framework | |||
663 | public static void MakeRequest<TRequest, TResponse>(string verb, | 694 | public static void MakeRequest<TRequest, TResponse>(string verb, |
664 | string requestUrl, TRequest obj, Action<TResponse> action) | 695 | string requestUrl, TRequest obj, Action<TResponse> action) |
665 | { | 696 | { |
697 | int reqnum = WebUtil.RequestNumber++; | ||
698 | // m_log.DebugFormat("[WEB UTIL]: <{0}> start osd request for {1}, method {2}",reqnum,url,method); | ||
699 | |||
700 | int tickstart = Util.EnvironmentTickCount(); | ||
701 | int tickdata = 0; | ||
702 | |||
666 | // m_log.DebugFormat("[ASYNC REQUEST]: Starting {0} {1}", verb, requestUrl); | 703 | // m_log.DebugFormat("[ASYNC REQUEST]: Starting {0} {1}", verb, requestUrl); |
667 | 704 | ||
668 | Type type = typeof(TRequest); | 705 | Type type = typeof(TRequest); |
@@ -673,12 +710,13 @@ namespace OpenSim.Framework | |||
673 | XmlSerializer deserializer = new XmlSerializer(typeof(TResponse)); | 710 | XmlSerializer deserializer = new XmlSerializer(typeof(TResponse)); |
674 | 711 | ||
675 | request.Method = verb; | 712 | request.Method = verb; |
713 | MemoryStream buffer = null; | ||
676 | 714 | ||
677 | if (verb == "POST") | 715 | if (verb == "POST") |
678 | { | 716 | { |
679 | request.ContentType = "text/xml"; | 717 | request.ContentType = "text/xml"; |
680 | 718 | ||
681 | MemoryStream buffer = new MemoryStream(); | 719 | buffer = new MemoryStream(); |
682 | 720 | ||
683 | XmlWriterSettings settings = new XmlWriterSettings(); | 721 | XmlWriterSettings settings = new XmlWriterSettings(); |
684 | settings.Encoding = Encoding.UTF8; | 722 | settings.Encoding = Encoding.UTF8; |
@@ -700,6 +738,9 @@ namespace OpenSim.Framework | |||
700 | requestStream.Write(buffer.ToArray(), 0, length); | 738 | requestStream.Write(buffer.ToArray(), 0, length); |
701 | requestStream.Close(); | 739 | requestStream.Close(); |
702 | 740 | ||
741 | // capture how much time was spent writing | ||
742 | tickdata = Util.EnvironmentTickCountSubtract(tickstart); | ||
743 | |||
703 | request.BeginGetResponse(delegate(IAsyncResult ar) | 744 | request.BeginGetResponse(delegate(IAsyncResult ar) |
704 | { | 745 | { |
705 | response = request.EndGetResponse(ar); | 746 | response = request.EndGetResponse(ar); |
@@ -725,88 +766,108 @@ namespace OpenSim.Framework | |||
725 | 766 | ||
726 | }, null); | 767 | }, null); |
727 | }, null); | 768 | }, null); |
728 | |||
729 | |||
730 | return; | ||
731 | } | 769 | } |
732 | 770 | else | |
733 | request.BeginGetResponse(delegate(IAsyncResult res2) | ||
734 | { | 771 | { |
735 | try | 772 | request.BeginGetResponse(delegate(IAsyncResult res2) |
736 | { | 773 | { |
737 | // If the server returns a 404, this appears to trigger a System.Net.WebException even though that isn't | ||
738 | // documented in MSDN | ||
739 | response = request.EndGetResponse(res2); | ||
740 | |||
741 | Stream respStream = null; | ||
742 | try | 774 | try |
743 | { | 775 | { |
744 | respStream = response.GetResponseStream(); | 776 | // If the server returns a 404, this appears to trigger a System.Net.WebException even though that isn't |
745 | deserial = (TResponse)deserializer.Deserialize(respStream); | 777 | // documented in MSDN |
746 | } | 778 | response = request.EndGetResponse(res2); |
747 | catch (System.InvalidOperationException) | 779 | |
748 | { | 780 | Stream respStream = null; |
749 | } | 781 | try |
750 | finally | 782 | { |
751 | { | 783 | respStream = response.GetResponseStream(); |
752 | respStream.Close(); | 784 | deserial = (TResponse)deserializer.Deserialize(respStream); |
753 | response.Close(); | 785 | } |
786 | catch (System.InvalidOperationException) | ||
787 | { | ||
788 | } | ||
789 | finally | ||
790 | { | ||
791 | respStream.Close(); | ||
792 | response.Close(); | ||
793 | } | ||
754 | } | 794 | } |
755 | } | 795 | catch (WebException e) |
756 | catch (WebException e) | ||
757 | { | ||
758 | if (e.Status == WebExceptionStatus.ProtocolError) | ||
759 | { | 796 | { |
760 | if (e.Response is HttpWebResponse) | 797 | if (e.Status == WebExceptionStatus.ProtocolError) |
761 | { | 798 | { |
762 | HttpWebResponse httpResponse = (HttpWebResponse)e.Response; | 799 | if (e.Response is HttpWebResponse) |
763 | |||
764 | if (httpResponse.StatusCode != HttpStatusCode.NotFound) | ||
765 | { | 800 | { |
766 | // We don't appear to be handling any other status codes, so log these feailures to that | 801 | HttpWebResponse httpResponse = (HttpWebResponse)e.Response; |
767 | // people don't spend unnecessary hours hunting phantom bugs. | 802 | |
768 | m_log.DebugFormat( | 803 | if (httpResponse.StatusCode != HttpStatusCode.NotFound) |
769 | "[ASYNC REQUEST]: Request {0} {1} failed with unexpected status code {2}", | 804 | { |
770 | verb, requestUrl, httpResponse.StatusCode); | 805 | // We don't appear to be handling any other status codes, so log these feailures to that |
806 | // people don't spend unnecessary hours hunting phantom bugs. | ||
807 | m_log.DebugFormat( | ||
808 | "[ASYNC REQUEST]: Request {0} {1} failed with unexpected status code {2}", | ||
809 | verb, requestUrl, httpResponse.StatusCode); | ||
810 | } | ||
771 | } | 811 | } |
772 | } | 812 | } |
813 | else | ||
814 | { | ||
815 | m_log.ErrorFormat( | ||
816 | "[ASYNC REQUEST]: Request {0} {1} failed with status {2} and message {3}", | ||
817 | verb, requestUrl, e.Status, e.Message); | ||
818 | } | ||
773 | } | 819 | } |
774 | else | 820 | catch (Exception e) |
775 | { | 821 | { |
776 | m_log.ErrorFormat( | 822 | m_log.ErrorFormat( |
777 | "[ASYNC REQUEST]: Request {0} {1} failed with status {2} and message {3}", | 823 | "[ASYNC REQUEST]: Request {0} {1} failed with exception {2}{3}", |
778 | verb, requestUrl, e.Status, e.Message); | 824 | verb, requestUrl, e.Message, e.StackTrace); |
779 | } | 825 | } |
780 | } | 826 | |
781 | catch (Exception e) | 827 | // m_log.DebugFormat("[ASYNC REQUEST]: Received {0}", deserial.ToString()); |
782 | { | 828 | |
783 | m_log.ErrorFormat( | 829 | try |
784 | "[ASYNC REQUEST]: Request {0} {1} failed with exception {2}{3}", | 830 | { |
785 | verb, requestUrl, e.Message, e.StackTrace); | 831 | action(deserial); |
786 | } | 832 | } |
833 | catch (Exception e) | ||
834 | { | ||
835 | m_log.ErrorFormat( | ||
836 | "[ASYNC REQUEST]: Request {0} {1} callback failed with exception {2}{3}", | ||
837 | verb, requestUrl, e.Message, e.StackTrace); | ||
838 | } | ||
839 | |||
840 | }, null); | ||
841 | } | ||
787 | 842 | ||
788 | // m_log.DebugFormat("[ASYNC REQUEST]: Received {0}", deserial.ToString()); | 843 | int tickdiff = Util.EnvironmentTickCountSubtract(tickstart); |
844 | if (tickdiff > WebUtil.LongCallTime) | ||
845 | { | ||
846 | string originalRequest = null; | ||
789 | 847 | ||
790 | try | 848 | if (buffer != null) |
791 | { | ||
792 | action(deserial); | ||
793 | } | ||
794 | catch (Exception e) | ||
795 | { | 849 | { |
796 | m_log.ErrorFormat( | 850 | originalRequest = Encoding.UTF8.GetString(buffer.ToArray()); |
797 | "[ASYNC REQUEST]: Request {0} {1} callback failed with exception {2}{3}", | 851 | |
798 | verb, requestUrl, e.Message, e.StackTrace); | 852 | if (originalRequest.Length > WebUtil.MaxRequestDiagLength) |
853 | originalRequest = originalRequest.Remove(WebUtil.MaxRequestDiagLength); | ||
799 | } | 854 | } |
800 | 855 | ||
801 | }, null); | 856 | m_log.InfoFormat( |
857 | "[ASYNC REQUEST]: Slow request to <{0}> {1} {2} took {3}ms, {4}ms writing, {5}", | ||
858 | reqnum, | ||
859 | verb, | ||
860 | requestUrl, | ||
861 | tickdiff, | ||
862 | tickdata, | ||
863 | originalRequest); | ||
864 | } | ||
802 | } | 865 | } |
803 | } | 866 | } |
804 | 867 | ||
805 | public static class SynchronousRestFormsRequester | 868 | public static class SynchronousRestFormsRequester |
806 | { | 869 | { |
807 | private static readonly ILog m_log = | 870 | private static readonly ILog m_log = LogManager.GetLogger(MethodBase.GetCurrentMethod().DeclaringType); |
808 | LogManager.GetLogger( | ||
809 | MethodBase.GetCurrentMethod().DeclaringType); | ||
810 | 871 | ||
811 | /// <summary> | 872 | /// <summary> |
812 | /// Perform a synchronous REST request. | 873 | /// Perform a synchronous REST request. |
@@ -820,6 +881,12 @@ namespace OpenSim.Framework | |||
820 | /// the request. You'll want to make sure you deal with this as they're not uncommon</exception> | 881 | /// the request. You'll want to make sure you deal with this as they're not uncommon</exception> |
821 | public static string MakeRequest(string verb, string requestUrl, string obj) | 882 | public static string MakeRequest(string verb, string requestUrl, string obj) |
822 | { | 883 | { |
884 | int reqnum = WebUtil.RequestNumber++; | ||
885 | // m_log.DebugFormat("[WEB UTIL]: <{0}> start osd request for {1}, method {2}",reqnum,url,method); | ||
886 | |||
887 | int tickstart = Util.EnvironmentTickCount(); | ||
888 | int tickdata = 0; | ||
889 | |||
823 | WebRequest request = WebRequest.Create(requestUrl); | 890 | WebRequest request = WebRequest.Create(requestUrl); |
824 | request.Method = verb; | 891 | request.Method = verb; |
825 | string respstring = String.Empty; | 892 | string respstring = String.Empty; |
@@ -855,6 +922,9 @@ namespace OpenSim.Framework | |||
855 | { | 922 | { |
856 | if (requestStream != null) | 923 | if (requestStream != null) |
857 | requestStream.Close(); | 924 | requestStream.Close(); |
925 | |||
926 | // capture how much time was spent writing | ||
927 | tickdata = Util.EnvironmentTickCountSubtract(tickstart); | ||
858 | } | 928 | } |
859 | } | 929 | } |
860 | 930 | ||
@@ -893,6 +963,18 @@ namespace OpenSim.Framework | |||
893 | m_log.DebugFormat("[FORMS]: InvalidOperationException on receiving {0} {1}", verb, requestUrl); | 963 | m_log.DebugFormat("[FORMS]: InvalidOperationException on receiving {0} {1}", verb, requestUrl); |
894 | } | 964 | } |
895 | } | 965 | } |
966 | |||
967 | int tickdiff = Util.EnvironmentTickCountSubtract(tickstart); | ||
968 | if (tickdiff > WebUtil.LongCallTime) | ||
969 | m_log.InfoFormat( | ||
970 | "[FORMS]: Slow request to <{0}> {1} {2} took {3}ms, {4}ms writing, {5}", | ||
971 | reqnum, | ||
972 | verb, | ||
973 | requestUrl, | ||
974 | tickdiff, | ||
975 | tickdata, | ||
976 | obj.Length > WebUtil.MaxRequestDiagLength ? obj.Remove(WebUtil.MaxRequestDiagLength) : obj); | ||
977 | |||
896 | return respstring; | 978 | return respstring; |
897 | } | 979 | } |
898 | } | 980 | } |
@@ -915,17 +997,24 @@ namespace OpenSim.Framework | |||
915 | /// the request. You'll want to make sure you deal with this as they're not uncommon</exception> | 997 | /// the request. You'll want to make sure you deal with this as they're not uncommon</exception> |
916 | public static TResponse MakeRequest<TRequest, TResponse>(string verb, string requestUrl, TRequest obj) | 998 | public static TResponse MakeRequest<TRequest, TResponse>(string verb, string requestUrl, TRequest obj) |
917 | { | 999 | { |
1000 | int reqnum = WebUtil.RequestNumber++; | ||
1001 | // m_log.DebugFormat("[WEB UTIL]: <{0}> start osd request for {1}, method {2}",reqnum,url,method); | ||
1002 | |||
1003 | int tickstart = Util.EnvironmentTickCount(); | ||
1004 | int tickdata = 0; | ||
1005 | |||
918 | Type type = typeof(TRequest); | 1006 | Type type = typeof(TRequest); |
919 | TResponse deserial = default(TResponse); | 1007 | TResponse deserial = default(TResponse); |
920 | 1008 | ||
921 | WebRequest request = WebRequest.Create(requestUrl); | 1009 | WebRequest request = WebRequest.Create(requestUrl); |
922 | request.Method = verb; | 1010 | request.Method = verb; |
1011 | MemoryStream buffer = null; | ||
923 | 1012 | ||
924 | if ((verb == "POST") || (verb == "PUT")) | 1013 | if ((verb == "POST") || (verb == "PUT")) |
925 | { | 1014 | { |
926 | request.ContentType = "text/xml"; | 1015 | request.ContentType = "text/xml"; |
927 | 1016 | ||
928 | MemoryStream buffer = new MemoryStream(); | 1017 | buffer = new MemoryStream(); |
929 | 1018 | ||
930 | XmlWriterSettings settings = new XmlWriterSettings(); | 1019 | XmlWriterSettings settings = new XmlWriterSettings(); |
931 | settings.Encoding = Encoding.UTF8; | 1020 | settings.Encoding = Encoding.UTF8; |
@@ -958,6 +1047,9 @@ namespace OpenSim.Framework | |||
958 | { | 1047 | { |
959 | if (requestStream != null) | 1048 | if (requestStream != null) |
960 | requestStream.Close(); | 1049 | requestStream.Close(); |
1050 | |||
1051 | // capture how much time was spent writing | ||
1052 | tickdata = Util.EnvironmentTickCountSubtract(tickstart); | ||
961 | } | 1053 | } |
962 | } | 1054 | } |
963 | 1055 | ||
@@ -1005,6 +1097,29 @@ namespace OpenSim.Framework | |||
1005 | verb, requestUrl, e.Message, e.StackTrace); | 1097 | verb, requestUrl, e.Message, e.StackTrace); |
1006 | } | 1098 | } |
1007 | 1099 | ||
1100 | int tickdiff = Util.EnvironmentTickCountSubtract(tickstart); | ||
1101 | if (tickdiff > WebUtil.LongCallTime) | ||
1102 | { | ||
1103 | string originalRequest = null; | ||
1104 | |||
1105 | if (buffer != null) | ||
1106 | { | ||
1107 | originalRequest = Encoding.UTF8.GetString(buffer.ToArray()); | ||
1108 | |||
1109 | if (originalRequest.Length > WebUtil.MaxRequestDiagLength) | ||
1110 | originalRequest = originalRequest.Remove(WebUtil.MaxRequestDiagLength); | ||
1111 | } | ||
1112 | |||
1113 | m_log.InfoFormat( | ||
1114 | "[SynchronousRestObjectRequester]: Slow request to <{0}> {1} {2} took {3}ms, {4}ms writing, {5}", | ||
1115 | reqnum, | ||
1116 | verb, | ||
1117 | requestUrl, | ||
1118 | tickdiff, | ||
1119 | tickdata, | ||
1120 | originalRequest); | ||
1121 | } | ||
1122 | |||
1008 | return deserial; | 1123 | return deserial; |
1009 | } | 1124 | } |
1010 | } | 1125 | } |