private void LogHttpRequestStats(IResourceApiController controller, LogHttpRequestStatsParams logHttpRequestStatsParams, string databaseName, long curReq) { if (Logger.IsDebugEnabled == false) { return; } if (controller is StudioController || controller is HardRouteController || controller is SilverlightController) { return; } var message = string.Format(CultureInfo.InvariantCulture, "Request #{0,4:#,0}: {1,-7} - {2,5:#,0} ms - {5,-10} - {3} - {4}", curReq, logHttpRequestStatsParams.HttpMethod, logHttpRequestStatsParams.Stopwatch.ElapsedMilliseconds, logHttpRequestStatsParams.ResponseStatusCode, logHttpRequestStatsParams.RequestUri, databaseName); if (Logger.IsDebugEnabled) { Logger.Debug(message); } if (Logger.IsDebugEnabled && string.IsNullOrWhiteSpace(logHttpRequestStatsParams.CustomInfo) == false) { Logger.Debug(logHttpRequestStatsParams.CustomInfo); } }
private void TraceTraffic(IResourceApiController controller, LogHttpRequestStatsParams logHttpRequestStatsParams, string resourceName, HttpResponseMessage response) { if (HasAnyHttpTraceEventTransport() == false) { return; } RavenJObject timingsJson = null; if (controller is IndexController) { var jsonContent = response.Content as JsonContent; if (jsonContent != null && jsonContent.Data != null) { timingsJson = jsonContent.Data.Value <RavenJObject>("TimingsInMilliseconds"); } } NotifyTrafficWatch( string.IsNullOrEmpty(resourceName) == false ? resourceName : Constants.SystemDatabase, new TrafficWatchNotification() { RequestUri = logHttpRequestStatsParams.RequestUri, ElapsedMilliseconds = logHttpRequestStatsParams.Stopwatch.ElapsedMilliseconds, CustomInfo = logHttpRequestStatsParams.CustomInfo, HttpMethod = logHttpRequestStatsParams.HttpMethod, ResponseStatusCode = logHttpRequestStatsParams.ResponseStatusCode, TenantName = NormalizeTennantName(resourceName), TimeStamp = SystemTime.UtcNow, InnerRequestsCount = logHttpRequestStatsParams.InnerRequestsCount, QueryTimings = timingsJson } ); }
private void IncrementRequestNumberAndLog(IResourceApiController controller, HttpControllerContext controllerContext) { if (controller is StudioController || controller is HardRouteController || controller is SilverlightController) { return; } var curReq = Interlocked.Increment(ref reqNum); controllerContext.Request.Properties["requestNum"] = curReq; if (Logger.IsDebugEnabled) { Logger.Debug(string.Format(CultureInfo.InvariantCulture, "Receive Request #{0,4:#,0}: {1,-7} - {2} - {3}", curReq, controller.InnerRequest.Method.Method, controller.ResourceName, controller.InnerRequest.RequestUri)); } }
private void MarkRequestDuration(IResourceApiController controller, long elapsedMilliseconds) { switch (controller.ResourceType) { case ResourceType.Database: if (landlord.IsDatabaseLoaded(controller.ResourceName ?? Constants.SystemDatabase)) { controller.MarkRequestDuration(elapsedMilliseconds); } break; case ResourceType.FileSystem: break; case ResourceType.TimeSeries: break; case ResourceType.Counter: break; default: throw new NotSupportedException(controller.ResourceType.ToString()); } }
private void FinalizeRequestProcessing(IResourceApiController controller, HttpResponseMessage response, Stopwatch sw) { LogHttpRequestStatsParams logHttpRequestStatsParam = null; try { StringBuilder sb = null; if (controller.CustomRequestTraceInfo != null && controller.CustomRequestTraceInfo.Count > 0) { sb = new StringBuilder(); foreach (var action in controller.CustomRequestTraceInfo) { try { action(sb); } catch (Exception e) { Logger.WarnException("Could not gather information to log request stats custom info, so far got " + sb, e); } sb.AppendLine(); } while (sb.Length > 0) { if (!char.IsWhiteSpace(sb[sb.Length - 1])) { break; } sb.Length--; } } var innerRequest = controller.InnerRequest; var httpRequestHeaders = innerRequest.Headers; var httpContentHeaders = innerRequest.Content == null ? null : innerRequest.Content.Headers; logHttpRequestStatsParam = new LogHttpRequestStatsParams( sw, new Lazy <HttpHeaders>(() => RavenBaseApiController.CloneRequestHttpHeaders(httpRequestHeaders, httpContentHeaders)), controller.InnerRequest.Method.Method, response != null ? (int)response.StatusCode : 500, controller.InnerRequest.RequestUri.ToString(), sb != null ? sb.ToString() : null, controller.InnerRequestsCount ); } catch (Exception e) { Logger.WarnException("Could not gather information to log request stats", e); } if (logHttpRequestStatsParam == null || sw == null) { return; } sw.Stop(); MarkRequestDuration(controller, sw.ElapsedMilliseconds); object requestNumber; if (controller.InnerRequest.Properties.TryGetValue("requestNum", out requestNumber) && requestNumber is long) { LogHttpRequestStats(controller, logHttpRequestStatsParam, controller.ResourceName, (long)requestNumber); } if (controller.IsInternalRequest == false) { TraceTraffic(controller, logHttpRequestStatsParam, controller.ResourceName, response); } RememberRecentRequests(logHttpRequestStatsParam, controller.ResourceName); }
public async Task <HttpResponseMessage> HandleActualRequest(IResourceApiController controller, HttpControllerContext controllerContext, Func <Task <HttpResponseMessage> > action, Func <HttpException, HttpResponseMessage> onHttpException) { HttpResponseMessage response = null; cancellationToken.ThrowIfCancellationRequested(); Stopwatch sw = Stopwatch.StartNew(); try { LastRequestTime = SystemTime.UtcNow; Interlocked.Increment(ref concurrentRequests); IncrementRequestNumberAndLog(controller, controllerContext); RequestWebApiEventArgs args = await controller.TrySetupRequestToProperResource().ConfigureAwait(false); if (args != null) { OnBeforeRequest(args); try { if (controllerContext.Request.Headers.Contains(Constants.RavenClientVersion)) { if (controller.RejectClientRequests) { response = new HttpResponseMessage(HttpStatusCode.ServiceUnavailable) { Content = new MultiGetSafeStringContent("This service is not accepting clients calls") }; } else if (IsInHotSpareMode) { response = new HttpResponseMessage(HttpStatusCode.ServiceUnavailable) { Content = new MultiGetSafeStringContent("This service is not accepting clients calls because this is a 'Hot Spare' server") }; } else { response = await action().ConfigureAwait(false); } } else { response = await action().ConfigureAwait(false); } } finally { OnAfterRequest(args); } } } catch (HttpException httpException) { response = onHttpException(httpException); } finally { Interlocked.Decrement(ref concurrentRequests); try { FinalizeRequestProcessing(controller, response, sw); } catch (Exception e) { var aggregateException = e as AggregateException; if (aggregateException != null) { e = aggregateException.ExtractSingleInnerException(); } Logger.ErrorException("Could not finalize request properly", e); } } return(response); }