private void TraceTraffic(RavenBaseApiController controller, LogHttpRequestStatsParams logHttpRequestStatsParams, string databaseName) { if (HasAnyHttpTraceEventTransport() == false) return; NotifyTrafficWatch( new TrafficWatchNotification() { RequestUri = logHttpRequestStatsParams.RequestUri, ElapsedMilliseconds = logHttpRequestStatsParams.Stopwatch.ElapsedMilliseconds, CustomInfo = logHttpRequestStatsParams.CustomInfo, HttpMethod = logHttpRequestStatsParams.HttpMethod, ResponseStatusCode = logHttpRequestStatsParams.ResponseStatusCode, TenantName = NormalizeTennantName(databaseName), TimeStamp = SystemTime.UtcNow, InnerRequestsCount = logHttpRequestStatsParams.InnerRequestsCount } ); }
private void LogHttpRequestStats(RavenBaseApiController controller, LogHttpRequestStatsParams logHttpRequestStatsParams, string databaseName, long curReq) { if (Logger.IsDebugEnabled == false) return; if (controller is StudioController || controller is HardRouteController || controller is SilverlightController) return; // we filter out requests for the UI because they fill the log with information // we probably don't care about them anyway. That said, we do output them if they take too // long. if (logHttpRequestStatsParams.Headers["Raven-Timer-Request"] == "true" && logHttpRequestStatsParams.Stopwatch.ElapsedMilliseconds <= 25) 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); Logger.Debug(message); if (string.IsNullOrWhiteSpace(logHttpRequestStatsParams.CustomInfo) == false) { Logger.Debug(logHttpRequestStatsParams.CustomInfo); } }
private void RememberRecentRequests(LogHttpRequestStatsParams requestLog, string databaseName) { if (string.IsNullOrWhiteSpace(databaseName)) databaseName = Constants.SystemDatabase; var traces = tracedRequests.GetOrAdd(databaseName, new ConcurrentQueue<LogHttpRequestStatsParams>()); LogHttpRequestStatsParams _; while (traces.Count > 50 && traces.TryDequeue(out _)) { } traces.Enqueue(requestLog); }
private void FinalizeRequestProcessing(RavenBaseApiController 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) { action(sb); sb.AppendLine(); } while (sb.Length > 0) { if (!char.IsWhiteSpace(sb[sb.Length - 1])) break; sb.Length--; } } logHttpRequestStatsParam = new LogHttpRequestStatsParams( sw, GetHeaders(controller.InnerHeaders), 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(); if (landlord.IsDatabaseLoaded(controller.TenantName ?? Constants.SystemDatabase)) { controller.MarkRequestDuration(sw.ElapsedMilliseconds); } var curReq = Interlocked.Increment(ref reqNum); LogHttpRequestStats(controller, logHttpRequestStatsParam, controller.TenantName, curReq); if (controller.IsInternalRequest == false) { TraceTraffic(controller, logHttpRequestStatsParam, controller.TenantName); } RememberRecentRequests(logHttpRequestStatsParam, controller.TenantName); }
private void LogHttpRequestStats(LogHttpRequestStatsParams logHttpRequestStatsParams, string databaseName) { if (Logger.IsDebugEnabled == false) return; // we filter out requests for the UI because they fill the log with information // we probably don't care about them anyway. That said, we do output them if they take too // long. if (logHttpRequestStatsParams.Headers["Raven-Timer-Request"] == "true" && logHttpRequestStatsParams.Stopwatch.ElapsedMilliseconds <= 25) return; var curReq = Interlocked.Increment(ref reqNum); Logger.Debug("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 (string.IsNullOrWhiteSpace(logHttpRequestStatsParams.CustomInfo) == false) Logger.Debug(logHttpRequestStatsParams.CustomInfo); }
private void FinalizeRequestProcessing(RavenBaseApiController controller, HttpResponseMessage response, Stopwatch sw) { LogHttpRequestStatsParams logHttpRequestStatsParam = null; try { StringBuilder sb = null; if (controller.CustomRequestTraceInfo != null) { sb = new StringBuilder(); foreach (var action in controller.CustomRequestTraceInfo) { action(sb); sb.AppendLine(); } while (sb.Length > 0) { if (!char.IsWhiteSpace(sb[sb.Length - 1])) break; sb.Length--; } } logHttpRequestStatsParam = new LogHttpRequestStatsParams( sw, GetHeaders(controller.InnerHeaders), controller.InnerRequest.Method.Method, response != null ? (int) response.StatusCode : 500, controller.InnerRequest.RequestUri.PathAndQuery, sb != null ? sb.ToString() : null ); } catch (Exception e) { Logger.WarnException("Could not gather information to log request stats", e); } if (logHttpRequestStatsParam == null || sw == null) return; sw.Stop(); controller.MarkRequestDuration(sw.ElapsedMilliseconds); LogHttpRequestStats(logHttpRequestStatsParam, controller.TenantName); TraceRequest(logHttpRequestStatsParam, controller.TenantName); }
private void LogHttpRequestStats(RavenBaseApiController 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); Logger.Debug(message); if (string.IsNullOrWhiteSpace(logHttpRequestStatsParams.CustomInfo) == false) { Logger.Debug(logHttpRequestStatsParams.CustomInfo); } }