diff options
author | Mic Bowman | 2011-01-05 14:32:00 -0800 |
---|---|---|
committer | Mic Bowman | 2011-01-05 14:32:00 -0800 |
commit | 984a9b408534d42f18bd072f70f9e2b31a691f9f (patch) | |
tree | 744cf6daa420a2aa4446200b5012b7237ee7ffaf /OpenSim/Framework | |
parent | removed the early return on agentupdates, this was debugging code (diff) | |
download | opensim-SC_OLD-984a9b408534d42f18bd072f70f9e2b31a691f9f.zip opensim-SC_OLD-984a9b408534d42f18bd072f70f9e2b31a691f9f.tar.gz opensim-SC_OLD-984a9b408534d42f18bd072f70f9e2b31a691f9f.tar.bz2 opensim-SC_OLD-984a9b408534d42f18bd072f70f9e2b31a691f9f.tar.xz |
Added more performance checks to the HTTP server. Each request
coming through the WebUtil fns has a request id in the header
that can match the request to the actual work done by the service
Diffstat (limited to '')
-rw-r--r-- | OpenSim/Framework/Servers/HttpServer/BaseHttpServer.cs | 16 | ||||
-rw-r--r-- | OpenSim/Framework/WebUtil.cs | 115 |
2 files changed, 83 insertions, 48 deletions
diff --git a/OpenSim/Framework/Servers/HttpServer/BaseHttpServer.cs b/OpenSim/Framework/Servers/HttpServer/BaseHttpServer.cs index 3343f60..86ad7aa 100644 --- a/OpenSim/Framework/Servers/HttpServer/BaseHttpServer.cs +++ b/OpenSim/Framework/Servers/HttpServer/BaseHttpServer.cs | |||
@@ -346,9 +346,15 @@ namespace OpenSim.Framework.Servers.HttpServer | |||
346 | /// <param name="response"></param> | 346 | /// <param name="response"></param> |
347 | public virtual void HandleRequest(OSHttpRequest request, OSHttpResponse response) | 347 | public virtual void HandleRequest(OSHttpRequest request, OSHttpResponse response) |
348 | { | 348 | { |
349 | string reqnum = "unknown"; | ||
350 | int tickstart = Environment.TickCount; | ||
351 | |||
349 | try | 352 | try |
350 | { | 353 | { |
351 | //m_log.Debug("[BASE HTTP SERVER]: Handling request to " + request.RawUrl); | 354 | // OpenSim.Framework.WebUtil.OSHeaderRequestID |
355 | if (request.Headers["opensim-request-id"] != null) | ||
356 | reqnum = String.Format("{0}:{1}",request.RemoteIPEndPoint,request.Headers["opensim-request-id"]); | ||
357 | // m_log.DebugFormat("[BASE HTTP SERVER]: <{0}> handle request for {1}",reqnum,request.RawUrl); | ||
352 | 358 | ||
353 | Thread.CurrentThread.CurrentCulture = new CultureInfo("en-US", true); | 359 | Thread.CurrentThread.CurrentCulture = new CultureInfo("en-US", true); |
354 | 360 | ||
@@ -576,6 +582,14 @@ namespace OpenSim.Framework.Servers.HttpServer | |||
576 | m_log.ErrorFormat("[BASE HTTP SERVER]: HandleRequest() threw {0}", e); | 582 | m_log.ErrorFormat("[BASE HTTP SERVER]: HandleRequest() threw {0}", e); |
577 | SendHTML500(response); | 583 | SendHTML500(response); |
578 | } | 584 | } |
585 | finally | ||
586 | { | ||
587 | // Every month or so this will wrap and give bad numbers, not really a problem | ||
588 | // since its just for reporting, 200ms limit can be adjusted | ||
589 | int tickdiff = Environment.TickCount - tickstart; | ||
590 | if (tickdiff > 200) | ||
591 | m_log.InfoFormat("[BASE HTTP SERVER]: slow request <{0}> for {1} took {2} ms",reqnum,request.RawUrl,tickdiff); | ||
592 | } | ||
579 | } | 593 | } |
580 | 594 | ||
581 | private bool TryGetStreamHandler(string handlerKey, out IRequestHandler streamHandler) | 595 | private bool TryGetStreamHandler(string handlerKey, out IRequestHandler streamHandler) |
diff --git a/OpenSim/Framework/WebUtil.cs b/OpenSim/Framework/WebUtil.cs index a00ea88..d88d095 100644 --- a/OpenSim/Framework/WebUtil.cs +++ b/OpenSim/Framework/WebUtil.cs | |||
@@ -51,7 +51,15 @@ namespace OpenSim.Framework | |||
51 | MethodBase.GetCurrentMethod().DeclaringType); | 51 | MethodBase.GetCurrentMethod().DeclaringType); |
52 | 52 | ||
53 | private static int m_requestNumber = 0; | 53 | private static int m_requestNumber = 0; |
54 | 54 | ||
55 | // this is the header field used to communicate the local request id | ||
56 | // used for performance and debugging | ||
57 | public const string OSHeaderRequestID = "opensim-request-id"; | ||
58 | |||
59 | // number of milliseconds a call can take before it is considered | ||
60 | // a "long" call for warning & debugging purposes | ||
61 | public const int LongCallTime = 200; | ||
62 | |||
55 | /// <summary> | 63 | /// <summary> |
56 | /// Send LLSD to an HTTP client in application/llsd+json form | 64 | /// Send LLSD to an HTTP client in application/llsd+json form |
57 | /// </summary> | 65 | /// </summary> |
@@ -146,34 +154,41 @@ namespace OpenSim.Framework | |||
146 | public static OSDMap ServiceOSDRequest(string url, OSDMap data, string method, int timeout) | 154 | public static OSDMap ServiceOSDRequest(string url, OSDMap data, string method, int timeout) |
147 | { | 155 | { |
148 | int reqnum = m_requestNumber++; | 156 | int reqnum = m_requestNumber++; |
149 | m_log.DebugFormat("[WEB UTIL]: <{0}> start osd request for {1}, method {2}",reqnum,url,method); | 157 | // m_log.DebugFormat("[WEB UTIL]: <{0}> start osd request for {1}, method {2}",reqnum,url,method); |
150 | 158 | ||
151 | string errorMessage = "unknown error"; | 159 | string errorMessage = "unknown error"; |
152 | int tickstart = Util.EnvironmentTickCount(); | 160 | int tickstart = Util.EnvironmentTickCount(); |
161 | int tickdata = 0; | ||
162 | |||
153 | try | 163 | try |
154 | { | 164 | { |
155 | HttpWebRequest request = (HttpWebRequest)WebRequest.Create(url); | 165 | HttpWebRequest request = (HttpWebRequest)WebRequest.Create(url); |
156 | request.Method = method; | 166 | request.Method = method; |
157 | request.Timeout = timeout; | 167 | request.Timeout = timeout; |
158 | //request.KeepAlive = false; | 168 | request.KeepAlive = false; |
159 | 169 | request.MaximumAutomaticRedirections = 10; | |
170 | request.ReadWriteTimeout = timeout / 4; | ||
171 | request.Headers[OSHeaderRequestID] = reqnum.ToString(); | ||
172 | |||
160 | // If there is some input, write it into the request | 173 | // If there is some input, write it into the request |
161 | if (data != null) | 174 | if (data != null) |
162 | { | 175 | { |
163 | string strBuffer = OSDParser.SerializeJsonString(data); | 176 | string strBuffer = OSDParser.SerializeJsonString(data); |
164 | byte[] buffer = System.Text.Encoding.UTF8.GetBytes(strBuffer); | 177 | byte[] buffer = System.Text.Encoding.UTF8.GetBytes(strBuffer); |
165 | 178 | ||
166 | request.ContentType = "application/json"; | 179 | request.ContentType = "application/json"; |
167 | request.ContentLength = buffer.Length; //Count bytes to send | 180 | request.ContentLength = buffer.Length; //Count bytes to send |
168 | using (Stream requestStream = request.GetRequestStream()) | 181 | using (Stream requestStream = request.GetRequestStream()) |
169 | { | 182 | requestStream.Write(buffer, 0, buffer.Length); //Send it |
170 | requestStream.Write(buffer, 0, strBuffer.Length); //Send it | ||
171 | } | ||
172 | } | 183 | } |
173 | 184 | ||
174 | using (WebResponse webResponse = request.GetResponse()) | 185 | // capture how much time was spent writing, this may seem silly |
186 | // but with the number concurrent requests, this often blocks | ||
187 | tickdata = Util.EnvironmentTickCountSubtract(tickstart); | ||
188 | |||
189 | using (WebResponse response = request.GetResponse()) | ||
175 | { | 190 | { |
176 | using (Stream responseStream = webResponse.GetResponseStream()) | 191 | using (Stream responseStream = response.GetResponseStream()) |
177 | { | 192 | { |
178 | string responseStr = null; | 193 | string responseStr = null; |
179 | responseStr = responseStream.GetStreamString(); | 194 | responseStr = responseStream.GetStreamString(); |
@@ -199,12 +214,12 @@ namespace OpenSim.Framework | |||
199 | { | 214 | { |
200 | // This just dumps a warning for any operation that takes more than 100 ms | 215 | // This just dumps a warning for any operation that takes more than 100 ms |
201 | int tickdiff = Util.EnvironmentTickCountSubtract(tickstart); | 216 | int tickdiff = Util.EnvironmentTickCountSubtract(tickstart); |
202 | if (tickdiff > 100) | 217 | if (tickdiff > LongCallTime) |
203 | m_log.WarnFormat("[WEB UTIL]: request <{0}> (URI:{1}, METHOD:{2}) took {3} milliseconds", | 218 | m_log.InfoFormat("[WEB UTIL]: osd request <{0}> (URI:{1}, METHOD:{2}) took {3}ms overall, {4}ms writing", |
204 | reqnum,url,method,tickdiff); | 219 | reqnum,url,method,tickdiff,tickdata); |
205 | } | 220 | } |
206 | 221 | ||
207 | m_log.WarnFormat("[WEB UTIL] <{0}> request failed: {1}",reqnum,errorMessage); | 222 | m_log.WarnFormat("[WEB UTIL] <{0}> osd request failed: {1}",reqnum,errorMessage); |
208 | return ErrorResponseMap(errorMessage); | 223 | return ErrorResponseMap(errorMessage); |
209 | } | 224 | } |
210 | 225 | ||
@@ -248,7 +263,7 @@ namespace OpenSim.Framework | |||
248 | catch (Exception e) | 263 | catch (Exception e) |
249 | { | 264 | { |
250 | // don't need to treat this as an error... we're just guessing anyway | 265 | // don't need to treat this as an error... we're just guessing anyway |
251 | m_log.DebugFormat("[WEB UTIL] couldn't decode result: <{0}>",response); | 266 | m_log.DebugFormat("[WEB UTIL] couldn't decode <{0}>: {1}",response,e.Message); |
252 | } | 267 | } |
253 | 268 | ||
254 | return result; | 269 | return result; |
@@ -260,26 +275,44 @@ namespace OpenSim.Framework | |||
260 | /// </summary> | 275 | /// </summary> |
261 | public static OSDMap PostToService(string url, NameValueCollection data) | 276 | public static OSDMap PostToService(string url, NameValueCollection data) |
262 | { | 277 | { |
278 | return ServiceFormRequest(url,data,10000); | ||
279 | } | ||
280 | |||
281 | public static OSDMap ServiceFormRequest(string url, NameValueCollection data, int timeout) | ||
282 | { | ||
263 | int reqnum = m_requestNumber++; | 283 | int reqnum = m_requestNumber++; |
264 | string method = data["RequestMethod"] != null ? data["RequestMethod"] : "unknown"; | 284 | string method = (data != null && data["RequestMethod"] != null) ? data["RequestMethod"] : "unknown"; |
265 | m_log.DebugFormat("[WEB UTIL]: <{0}> start form request for {1}, method {2}",reqnum,url,method); | 285 | // m_log.DebugFormat("[WEB UTIL]: <{0}> start form request for {1}, method {2}",reqnum,url,method); |
266 | 286 | ||
267 | string errorMessage; | 287 | string errorMessage = "unknown error"; |
268 | int tickstart = Util.EnvironmentTickCount(); | 288 | int tickstart = Util.EnvironmentTickCount(); |
289 | int tickdata = 0; | ||
269 | 290 | ||
270 | try | 291 | try |
271 | { | 292 | { |
272 | string queryString = BuildQueryString(data); | 293 | |
273 | byte[] requestData = System.Text.Encoding.UTF8.GetBytes(queryString); | ||
274 | |||
275 | HttpWebRequest request = (HttpWebRequest)HttpWebRequest.Create(url); | 294 | HttpWebRequest request = (HttpWebRequest)HttpWebRequest.Create(url); |
276 | request.Method = "POST"; | 295 | request.Method = "POST"; |
277 | request.ContentLength = requestData.Length; | 296 | request.Timeout = timeout; |
278 | request.ContentType = "application/x-www-form-urlencoded"; | 297 | request.KeepAlive = false; |
298 | request.MaximumAutomaticRedirections = 10; | ||
299 | request.ReadWriteTimeout = timeout / 4; | ||
300 | request.Headers[OSHeaderRequestID] = reqnum.ToString(); | ||
279 | 301 | ||
280 | Stream requestStream = request.GetRequestStream(); | 302 | if (data != null) |
281 | requestStream.Write(requestData, 0, requestData.Length); | 303 | { |
282 | requestStream.Close(); | 304 | string queryString = BuildQueryString(data); |
305 | byte[] buffer = System.Text.Encoding.UTF8.GetBytes(queryString); | ||
306 | |||
307 | request.ContentLength = buffer.Length; | ||
308 | request.ContentType = "application/x-www-form-urlencoded"; | ||
309 | using (Stream requestStream = request.GetRequestStream()) | ||
310 | requestStream.Write(buffer, 0, buffer.Length); | ||
311 | } | ||
312 | |||
313 | // capture how much time was spent writing, this may seem silly | ||
314 | // but with the number concurrent requests, this often blocks | ||
315 | tickdata = Util.EnvironmentTickCountSubtract(tickstart); | ||
283 | 316 | ||
284 | using (WebResponse response = request.GetResponse()) | 317 | using (WebResponse response = request.GetResponse()) |
285 | { | 318 | { |
@@ -287,22 +320,10 @@ namespace OpenSim.Framework | |||
287 | { | 320 | { |
288 | string responseStr = null; | 321 | string responseStr = null; |
289 | 322 | ||
290 | try | 323 | responseStr = responseStream.GetStreamString(); |
291 | { | 324 | OSD responseOSD = OSDParser.Deserialize(responseStr); |
292 | responseStr = responseStream.GetStreamString(); | 325 | if (responseOSD.Type == OSDType.Map) |
293 | OSD responseOSD = OSDParser.Deserialize(responseStr); | 326 | return (OSDMap)responseOSD; |
294 | if (responseOSD.Type == OSDType.Map) | ||
295 | return (OSDMap)responseOSD; | ||
296 | else | ||
297 | errorMessage = "Response format was invalid."; | ||
298 | } | ||
299 | catch (Exception ex) | ||
300 | { | ||
301 | if (!String.IsNullOrEmpty(responseStr)) | ||
302 | errorMessage = "Failed to parse the response:\n" + responseStr; | ||
303 | else | ||
304 | errorMessage = "Failed to retrieve the response: " + ex.Message; | ||
305 | } | ||
306 | } | 327 | } |
307 | } | 328 | } |
308 | } | 329 | } |
@@ -322,12 +343,12 @@ namespace OpenSim.Framework | |||
322 | finally | 343 | finally |
323 | { | 344 | { |
324 | int tickdiff = Util.EnvironmentTickCountSubtract(tickstart); | 345 | int tickdiff = Util.EnvironmentTickCountSubtract(tickstart); |
325 | if (tickdiff > 100) | 346 | if (tickdiff > LongCallTime) |
326 | m_log.WarnFormat("[WEB UTIL]: request <{0}> (URI:{1}, METHOD:{2}) took {3} milliseconds", | 347 | m_log.InfoFormat("[WEB UTIL]: form request <{0}> (URI:{1}, METHOD:{2}) took {3}ms overall, {4}ms writing", |
327 | reqnum,url,method,tickdiff); | 348 | reqnum,url,method,tickdiff,tickdata); |
328 | } | 349 | } |
329 | 350 | ||
330 | m_log.WarnFormat("[WEB UTIL]: <{0}> request failed: {1}",reqnum,errorMessage); | 351 | m_log.WarnFormat("[WEB UTIL]: <{0}> form request failed: {1}",reqnum,errorMessage); |
331 | return ErrorResponseMap(errorMessage); | 352 | return ErrorResponseMap(errorMessage); |
332 | } | 353 | } |
333 | 354 | ||