private int FlushLoop()
{
_UploadingNow = true;
int processedCount = 0;
try
{
int queueSize = _MessageBuffer.Count;
// StackifyLib.Utils.StackifyAPILogger.Log("FlushLoop - count: " + queueSize + " for " + _LogClient.LoggerName);
//CanSend() does an IdentifyApp so there is a chance this could take a while
if (queueSize > 0 && _LogClient.CanUpload())
{
_QueueTooBig = queueSize < Logger.MaxLogBufferSize;
bool keepGoing = false;
int flushTimes = 0;
//Keep flushing
do
{
int count = FlushOnce();
if (count >= 100)
{
keepGoing = true;
}
else
{
keepGoing = false;
}
flushTimes++;
processedCount += count;
} while (keepGoing && flushTimes < 25);
_QueueTooBig = _MessageBuffer.Count < Logger.MaxLogBufferSize;
}
}
catch (Exception ex)
{
StackifyAPILogger.Log("#LogQueue #FlushLoop failed", ex);
}
_UploadingNow = false;
return(processedCount);
}
protected override void Dispose(bool disposing)
{
try
{
StackifyAPILogger.Log("TraceListener closing");
_logClient.Close();
//This is to force the metrics queue to flush as well
StackifyLib.Internal.Metrics.MetricClient.StopMetricsQueue("TraceListener OnClose");
}
catch
{
}
base.Dispose(disposing);
}
private static GetMetricResponse GetMonitorInfo(MetricAggregate metric)
{
try
{
if (HttpClient.IsRecentError() || !HttpClient.MatchedClientDeviceApp())
{
return(null);
}
GetMetricRequest request = new GetMetricRequest();
if (HttpClient.AppIdentity != null)
{
request.DeviceAppID = HttpClient.AppIdentity.DeviceAppID;
request.DeviceID = HttpClient.AppIdentity.DeviceID;
request.AppNameID = HttpClient.AppIdentity.AppNameID;
}
request.MetricName = metric.Name;
request.MetricTypeID = (short)metric.MetricType;
request.Category = metric.Category;
string jsonData = JsonConvert.SerializeObject(request);
var response =
HttpClient.SendJsonAndGetResponse(
(HttpClient.BaseAPIUrl) +
"Metrics/GetMetricInfo",
jsonData);
if (response.Exception == null && response.StatusCode == HttpStatusCode.OK)
{
var metricResponse = JsonConvert.DeserializeObject <GetMetricResponse>(response.ResponseText);
return(metricResponse);
}
return(null);
}
catch (Exception e)
{
StackifyAPILogger.Log("Error getting monitor info " + e.Message);
return(null);
}
}
private static void PurgeOldMetrics(DateTime purgeOlderThan)
{
try
{
//beginning of this method we save off latest aggregates before upload or purge
//purge old stuff
//if uploading disabled it purges everything
//if success uploading then should be nothing to purge as that is already done above
var oldMetrics = _AggregateMetrics.Where(x => x.Value.OccurredUtc < purgeOlderThan).ToList();
MetricAggregate oldval;
oldMetrics.ForEach(x => _AggregateMetrics.TryRemove(x.Key, out oldval));
}
catch (Exception ex)
{
StackifyAPILogger.Log("Error purging metrics " + ex.ToString());
}
}
public static void QueueMetric(Metric metric)
{
_metricsEverUsed = true;
try
{
//set a sanity cap
if (MetricQueue.Count < 100000)
{
MetricQueue.Enqueue(metric);
// RT-561: Incremented Metrics Broken
if (metric.IsIncrement)
{
var nameKey = metric.CalcNameKey();
if (LastAggregates.ContainsKey(metric.CalcNameKey()))
{
LastAggregates[nameKey].OccurredUtc = metric.Occurred;
LastAggregates[nameKey].Value += metric.Value;
}
else
{
var agg = new MetricAggregate(metric);
agg.OccurredUtc = metric.Occurred;
agg.Value = metric.Value;
LastAggregates.TryAdd(nameKey, agg);
}
}
}
else
{
StackifyAPILogger.Log("No longer queuing new metrics because more than 100000 are queued", true);
}
}
catch (Exception ex)
{
StackifyAPILogger.Log(ex.ToString());
}
}
public override void ActivateOptions()
{
StackifyAPILogger.Log("ActiveOptions on log4net appender");
try
{
//if (!String.IsNullOrEmpty(globalContextKeys))
//{
// _GlobalContextKeys = globalContextKeys.Split(',').Select(s => s.Trim()).ToList();
//}
//if (!String.IsNullOrEmpty(threadContextKeys))
//{
// _ThreadContextKeys = threadContextKeys.Split(',').Select(s => s.Trim()).ToList();
//}
//if (!String.IsNullOrEmpty(logicalThreadContextKeys))
//{
// _LogicalThreadContextKeys = logicalThreadContextKeys.Split(',').Select(s => s.Trim()).ToList();
//}
if (!String.IsNullOrEmpty(callContextKeys))
{
_CallContextKeys = callContextKeys.Split(',').Select(s => s.Trim()).ToList();
}
// _HasContextKeys = _GlobalContextKeys.Any() || _ThreadContextKeys.Any() || _LogicalThreadContextKeys.Any() || _CallContextKeys.Any();
_HasContextKeys = _CallContextKeys.Any();
_logClient = CreateLogClient(apiKey, uri);
}
catch (Exception ex)
{
StackifyAPILogger.Log(ex.Message, true);
}
base.ActivateOptions();
}
private static void Aggregate(MetricAggregate aggregate)
{
try
{
var aggKey = aggregate.AggregateKey();
MetricAggregate agg;
if (AggregateMetrics.TryGetValue(aggKey, out agg) == false)
{
if (AggregateMetrics.Count > 1000)
{
StackifyAPILogger.Log("No longer aggregating new metrics because more than 1000 are queued", true);
return;
}
StackifyAPILogger.Log($"Creating aggregate for {aggKey}");
AggregateMetrics[aggKey] = aggregate;
agg = aggregate;
}
if (aggregate.MetricType == MetricType.MetricLast)
{
agg.Count = 1;
agg.Value = aggregate.Value;
}
else
{
agg.Count += aggregate.Count;
agg.Value += aggregate.Value;
}
AggregateMetrics[aggKey] = agg;
}
catch (Exception ex)
{
StackifyAPILogger.Log($"Error in StackifyLib with aggregating metrics\r\n{ex}");
}
}
private void WriteToStackify(string level, string message)
{
try
{
//make sure the buffer isn't overflowing
//if it is skip since we can't do anything with the message
if (Logger.PrefixEnabled() || _logClient.CanQueue())
{
LogMsg msg = new LogMsg();
msg.Msg = message;
msg.Level = level;
}
else
{
StackifyAPILogger.Log("Unable to send log because the queue is full");
}
}
catch (Exception ex)
{
StackifyAPILogger.Log(ex.ToString());
}
}
private static void Aggregate(MetricAggregate aggregate)
{
try
{
string aggKey = aggregate.AggregateKey();
MetricAggregate agg;
if (!_AggregateMetrics.TryGetValue(aggKey, out agg))
{
if (_AggregateMetrics.Count > 1000)
{
Utils.StackifyAPILogger.Log("No longer aggregating new metrics because more than 1000 are queued");
return;
}
StackifyAPILogger.Log("Creating aggregate for " + aggKey);
_AggregateMetrics[aggKey] = aggregate;
agg = aggregate;
}
if (aggregate.MetricType == MetricType.MetricLast)
{
agg.Count = 1;
agg.Value = aggregate.Value;
}
else
{
agg.Count += aggregate.Count;
agg.Value += aggregate.Value;
}
_AggregateMetrics[aggKey] = agg;
}
catch (Exception ex)
{
StackifyAPILogger.Log("Error in StackifyLib with aggregating metrics");
}
}
protected override void Write(LogEventInfo logEvent)
{
try
{
//make sure the buffer isn't overflowing
//if it is skip since we can't do anything with the message
if (StackifyLib.Logger.PrefixEnabled() || _logClient.CanQueue())
{
var logMsg = Translate(logEvent);
if (logMsg != null)
{
_logClient.QueueMessage(logMsg);
}
}
else
{
StackifyAPILogger.Log("Unable to send log because the queue is full");
}
}
catch (Exception ex)
{
StackifyAPILogger.Log(ex.ToString());
}
}
internal HttpClient.StackifyWebResponse SendLogsByGroups(LogMsg[] messages)
{
try
{
StackifyAPILogger.Log("Trying to SendLogs");
EnsureHttpClient();
var identified = _HttpClient.IdentifyApp();
if (_HttpClient.IsRecentError())
{
return(new HttpClient.StackifyWebResponse()
{
Exception = new Exception("Unable to send logs at this time due to recent error: " + (_HttpClient.LastErrorMessage ?? ""))
});
}
if (!identified)
{
return(new HttpClient.StackifyWebResponse()
{
Exception = new Exception("Unable to send logs at this time. Unable to identify app")
});
}
var groups = SplitLogsToGroups(messages);
string jsonData = JsonConvert.SerializeObject(groups, new JsonSerializerSettings()
{
NullValueHandling = NullValueHandling.Ignore
});
string urlToUse = (_HttpClient.BaseAPIUrl) + "Log/SaveMultipleGroups";
if (!_ServicePointSet)
{
#if NETFULL
ServicePointManager.FindServicePoint(urlToUse, null).ConnectionLimit = 10;
#endif
_ServicePointSet = true;
}
StackifyAPILogger.Log("Sending " + messages.Length.ToString() + " log messages via send multi groups");
var response =
_HttpClient.SendJsonAndGetResponse(
urlToUse,
jsonData, jsonData.Length > 5000);
messages = null;
groups = null;
return(response);
}
catch (Exception ex)
{
Utils.StackifyAPILogger.Log(ex.ToString());
return(new HttpClient.StackifyWebResponse()
{
Exception = ex
});
}
}
/// <summary>
/// Read everything in the queue up to a certain time point
/// </summary>
private static void ReadAllQueuedMetrics()
{
// read only up until now so it doesn't get stuck in an endless loop
// Loop through add sum up the totals of the counts and values by aggregate key then pass it all in at once to update the aggregate dictionary so it is done in one pass
// key is the aggregate key which is the metric name, type and rounded minute of the occurrence
var maxDate = DateTime.UtcNow;
StackifyAPILogger.Log($"ReadAllQueuedMetrics {maxDate}");
var batches = new Dictionary <string, MetricAggregate>();
long processed = 0;
Metric metric;
while (MetricQueue.TryDequeue(out metric))
{
processed++;
metric.CalcAndSetAggregateKey();
if (batches.ContainsKey(metric.AggregateKey) == false)
{
var nameKey = metric.CalcNameKey();
var agg = new MetricAggregate(metric);
if (metric.IsIncrement)
{
if (LastAggregates.ContainsKey(nameKey))
{
// if wanting to do increments we need to grab the last value so we know what to increment
metric.Value = LastAggregates[nameKey].Value;
}
}
batches[metric.AggregateKey] = agg;
// if it is null don't do anything
// we are doing it where the aggregates are created so we don't do it one very single metric, just once per batch to optimize performance
if (metric.Settings != null)
{
MetricSettings[nameKey] = metric.Settings;
}
}
batches[metric.AggregateKey].Count++;
if (metric.IsIncrement)
{
// safety
var val = batches[metric.AggregateKey].Value;
if (val.Equals(double.MinValue) || val.Equals(double.MaxValue))
{
batches[metric.AggregateKey].Value = 0;
StackifyAPILogger.Log($"Read queued metrics reset increment {metric.AggregateKey} to zero due to min/max value of {val}");
}
//add or subtract
batches[metric.AggregateKey].Value += metric.Value;
// allow negative?
if (metric.Settings != null && batches[metric.AggregateKey].Value < 0 && metric.Settings.AllowNegativeGauge == false)
{
batches[metric.AggregateKey].Value = 0;
}
}
else if (metric.MetricType == MetricType.MetricLast)
{
//should end up the last value
batches[metric.AggregateKey].Value = metric.Value;
}
else
{
batches[metric.AggregateKey].Value += metric.Value;
}
if (metric.Occurred > maxDate)
{
//we don't need anything more this recent so bail
break;
}
}
StackifyAPILogger.Log($"Read queued metrics processed {processed} for max date {maxDate}");
foreach (KeyValuePair <string, MetricAggregate> batch in batches)
{
Aggregate(batch.Value);
}
}
public static void LoadSettings()
{
try
{
CaptureErrorPostdata = Get("Stackify.CaptureErrorPostdata", bool.FalseString).Equals(bool.TrueString, StringComparison.CurrentCultureIgnoreCase);
CaptureServerVariables = Get("Stackify.CaptureServerVariables", bool.FalseString).Equals(bool.TrueString, StringComparison.CurrentCultureIgnoreCase);
CaptureSessionVariables = Get("Stackify.CaptureSessionVariables", bool.FalseString).Equals(bool.TrueString, StringComparison.CurrentCultureIgnoreCase);
CaptureErrorHeaders = Get("Stackify.CaptureErrorHeaders", bool.TrueString).Equals(bool.TrueString, StringComparison.CurrentCultureIgnoreCase);
CaptureErrorCookies = Get("Stackify.CaptureErrorCookies", bool.FalseString).Equals(bool.TrueString, StringComparison.CurrentCultureIgnoreCase);
ApiKey = Get("Stackify.ApiKey", ApiKey ?? string.Empty);
AppName = Get("Stackify.AppName", AppName ?? string.Empty);
Environment = Get("Stackify.Environment", Environment ?? string.Empty);
CaptureErrorHeadersWhitelist = Get("Stackify.CaptureErrorHeadersWhitelist", string.Empty);
if (string.IsNullOrEmpty(CaptureErrorHeadersWhitelist) == false)
{
ErrorHeaderGoodKeys = CaptureErrorHeadersWhitelist.Split(",".ToCharArray(), StringSplitOptions.RemoveEmptyEntries).ToList();
}
CaptureErrorHeadersBlacklist = Get("Stackify.CaptureErrorHeadersBlacklist", string.Empty);
if (string.IsNullOrEmpty(CaptureErrorHeadersBlacklist) == false)
{
ErrorHeaderBadKeys = CaptureErrorHeadersBlacklist.Split(",".ToCharArray(), StringSplitOptions.RemoveEmptyEntries).ToList();
}
CaptureErrorCookiesWhitelist = Get("Stackify.CaptureErrorCookiesWhitelist", string.Empty);
if (string.IsNullOrEmpty(CaptureErrorCookiesWhitelist) == false)
{
ErrorCookiesGoodKeys = CaptureErrorCookiesWhitelist.Split(",".ToCharArray(), StringSplitOptions.RemoveEmptyEntries).ToList();
}
CaptureErrorCookiesBlacklist = Get("Stackify.CaptureErrorCookiesBlacklist", string.Empty);
if (string.IsNullOrEmpty(CaptureErrorCookiesBlacklist) == false)
{
ErrorCookiesBadKeys = CaptureErrorCookiesBlacklist.Split(",".ToCharArray(), StringSplitOptions.RemoveEmptyEntries).ToList();
}
CaptureErrorSessionWhitelist = Get("Stackify.CaptureErrorSessionWhitelist", string.Empty);
if (string.IsNullOrEmpty(CaptureErrorSessionWhitelist) == false)
{
ErrorSessionGoodKeys = CaptureErrorSessionWhitelist.Split(",".ToCharArray(), StringSplitOptions.RemoveEmptyEntries).ToList();
}
// SF-6804: Frequent Calls to GetEC2InstanceId
var captureEc2InstanceMetadataUpdateThresholdMinutes = Get("Stackify.Ec2InstanceMetadataUpdateThresholdMinutes", string.Empty);
if (string.IsNullOrWhiteSpace(captureEc2InstanceMetadataUpdateThresholdMinutes) == false)
{
if (int.TryParse(captureEc2InstanceMetadataUpdateThresholdMinutes, out int minutes) && minutes != 0)
{
Ec2InstanceMetadataUpdateThresholdMinutes = minutes;
}
}
// SF-6204: Allow local overrides of EC2 detection
var isEc2 = Get("Stackify.IsEC2", string.Empty);
if (string.IsNullOrWhiteSpace(isEc2) == false)
{
IsEc2 = isEc2.Equals(bool.TrueString, StringComparison.CurrentCultureIgnoreCase);
}
// RT-297
var apiLog = Get("Stackify.ApiLog", string.Empty);
if (string.IsNullOrWhiteSpace(apiLog) == false)
{
ApiLog = apiLog.Equals(bool.TrueString, StringComparison.CurrentCultureIgnoreCase);
}
var loggingJsonMaxFields = Get("Stackify.Logging.JsonMaxFields", "50");
if (string.IsNullOrWhiteSpace(loggingJsonMaxFields) == false)
{
if (int.TryParse(loggingJsonMaxFields, out int maxFields) && maxFields > 0 && maxFields < 100)
{
LoggingJsonMaxFields = maxFields;
}
}
}
catch (Exception ex)
{
StackifyAPILogger.Log("#Config #LoadSettings failed", ex);
}
}
internal LogMsg Translate(LoggingEvent loggingEvent)
{
if (loggingEvent == null)
{
return(null);
}
//don't log our own logging causing a loop
if (loggingEvent.RenderedMessage.IndexOf("StackifyLib:", StringComparison.OrdinalIgnoreCase) > -1)
{
return(null);
}
var msg = new LogMsg();
if (loggingEvent.Level != null)
{
msg.Level = loggingEvent.Level.DisplayName;
}
try
{
msg.SrcMethod = loggingEvent.LoggerName;
if (logMethodNames ?? false)
{
var frames = StackifyLib.Logger.GetCurrentStackTrace(loggingEvent.LoggerName, 1, true);
if (frames.Any())
{
var first = frames.First();
msg.SrcMethod = first.Method;
msg.SrcLine = first.LineNum;
}
}
}
catch (Exception ex)
{
StackifyAPILogger.Log("Error evaluating source method " + ex.ToString());
}
var diags = GetDiagnosticContextProperties();
if (diags != null && diags.ContainsKey("transid"))
{
msg.TransID = diags["transid"].ToString();
diags.Remove("transid");
}
StackifyError error = null;
object messageObject = null;
string errorAdditionalMessage = null;
if (loggingEvent.MessageObject != null && loggingEvent.MessageObject is StackifyError)
{
//Message Object was an exception
error = (StackifyError)loggingEvent.MessageObject;
messageObject = error.ToString();
errorAdditionalMessage = null;
}
else if (loggingEvent.MessageObject != null && loggingEvent.MessageObject is Exception)
{
//Message Object was an exception
error = StackifyError.New((Exception)loggingEvent.MessageObject);
messageObject = error.ToString();
errorAdditionalMessage = null;
}
else if (loggingEvent.ExceptionObject != null)
{
//Exception was passed in
if (loggingEvent.ExceptionObject is StackifyError)
{
error = loggingEvent.ExceptionObject as StackifyError;
}
else
{
error = StackifyError.New(loggingEvent.ExceptionObject);
}
errorAdditionalMessage = loggingEvent.RenderedMessage;
messageObject = loggingEvent.MessageObject;
}
else
{
messageObject = loggingEvent.MessageObject;
}
//messageObject is not an object we need to serialize.
if (messageObject == null || messageObject is string || messageObject.GetType().FullName == "log4net.Util.SystemStringFormat")
{
//passing null to the serialize object since we can't serialize the logged object. We only need to get potential diags.
msg.data = StackifyLib.Utils.HelperFunctions.SerializeDebugData(null, false, diags);
msg.Msg = loggingEvent.RenderedMessage;
}
else if (messageObject is StackifyLib.Models.LogMessage)
{
var item = messageObject as StackifyLib.Models.LogMessage;
msg.data = StackifyLib.Utils.HelperFunctions.SerializeDebugData(item.json, true, diags);
msg.Msg = item.message;
}
else
{
//try to serialize the messageObject since we know its not a string
msg.data = StackifyLib.Utils.HelperFunctions.SerializeDebugData(messageObject, false, diags);
msg.Msg = loggingEvent.RenderedMessage;
}
if (error != null)
{
msg.Msg += "\r\n" + error.ToString();
}
if (!string.IsNullOrWhiteSpace(errorAdditionalMessage) && error != null)
{
//if something besides just the exception was logged, add that message to our error object
error.SetAdditionalMessage(errorAdditionalMessage);
}
else if (msg.Msg == null && error != null)
{
msg.Msg = error.ToString();
}
if (error == null && (loggingEvent.Level == Level.Error || loggingEvent.Level == Level.Fatal))
{
StringException stringEx = new StringException(loggingEvent.RenderedMessage);
stringEx.TraceFrames = new List <TraceFrame>();
stringEx.TraceFrames = StackifyLib.Logger.GetCurrentStackTrace(loggingEvent.LoggerName);
if (stringEx.TraceFrames.Any())
{
var first = stringEx.TraceFrames.First();
msg.SrcMethod = first.Method;
msg.SrcLine = first.LineNum;
}
//Make error out of log message
error = StackifyError.New(stringEx);
}
if (error != null && !StackifyError.IgnoreError(error) && _logClient.ErrorShouldBeSent(error))
{
msg.Ex = error;
}
else if (error != null && msg.Msg != null)
{
msg.Msg += " #errorgoverned";
}
return(msg);
}
private int FlushOnce()
{
// StackifyLib.Utils.StackifyAPILogger.Log("Calling FlushOnceAsync");
int messageSize = 0;
var chunk = new List <LogMsg>();
//we only want to do this once at a time but the actual send is done async
long startMs = (long)DateTime.UtcNow.Subtract(_Epoch).TotalMilliseconds;
try
{
while (true)
{
LogMsg msg;
if (_MessageBuffer.TryDequeue(out msg))
{
//do not log our own messages. This is to prevent any sort of recursion that could happen since calling to send this will cause even more logging to happen
if (msg.Msg != null && msg.Msg != null && msg.Msg.Contains("StackifyLib:"))
{
//skip!
continue;
}
chunk.Add(msg);
messageSize++;
//if we get something newer than when we started reading, break so it doesn't keep reading perpetually.
//Let it finish so the timer can run again and do a new batch
if (msg.EpochMs > startMs)
{
break;
}
//send this packet in a batch
if (messageSize > 100)
{
break;
}
}
else
{
break;
}
}
if (chunk.Any())
{
var response = _LogClient.SendLogsByGroups(chunk.ToArray());
if (response != null && response.Exception != null)
{
Utils.StackifyAPILogger.Log("Requeueing log messages due to error: " + response.Exception.ToString(), true);
if (response.IsClientError())
{
Utils.StackifyAPILogger.Log("#LogQueue Not requeueing log messages due to client error: " + response.StatusCode, true);
}
else
{
try
{
bool messagesSentTooManyTimes = EnqueueForRetransmission(chunk);
if (messagesSentTooManyTimes)
{
Utils.StackifyAPILogger.Log("#LogQueue Some messages not queued again due to too many failures uploading");
}
}
catch (Exception ex2)
{
Utils.StackifyAPILogger.Log("#LogQueue Error trying to requeue messages " + ex2.ToString());
}
}
}
}
}
catch (Exception ex)
{
StackifyAPILogger.Log("#LogQueue #FlushOnce failed", ex);
EnqueueForRetransmission(chunk);
}
return(messageSize);
}
//private struct ThreadUsage
//{
// public string SrcMethod { get; set; }
// public string TransID { get; set; }
//}
//ConcurrentDictionary<string, ThreadUsage> _ThreadInfo = new ConcurrentDictionary<string, ThreadUsage>();
/// <summary>
/// Should call CanSend() before this. Did not also put that call in here to improve performance. Makes more sense to do it earlier so it can skip other steps up the chain.
/// </summary>
/// <param name="msg"></param>
public void QueueLogMessage(Models.LogMsg msg)
{
try
{
if (msg == null)
{
return;
}
if (!_TimerStarted)
{
EnsureTimer();
}
try
{
if (string.IsNullOrEmpty(msg.Th))
{
msg.Th = System.Threading.Thread.CurrentThread.ManagedThreadId.ToString();
}
}
catch
{
// ignore
}
#if NETFULL
try
{
if (string.IsNullOrEmpty(msg.TransID))
{
var stackifyRequestID = CallContext.LogicalGetData("Stackify-RequestID");
if (stackifyRequestID != null)
{
msg.TransID = stackifyRequestID.ToString();
}
}
if (string.IsNullOrEmpty(msg.TransID))
{
//gets from Trace.CorrelationManager.ActivityId but doesnt assume it is guid since it technically doesn't have to be
//not calling the CorrelationManager method because it blows up if it isn't a guid
var correltionManagerId = CallContext.LogicalGetData("E2ETrace.ActivityID");
if (correltionManagerId != null && correltionManagerId is Guid && ((Guid)correltionManagerId) != Guid.Empty)
{
msg.TransID = correltionManagerId.ToString();
}
}
if (string.IsNullOrEmpty(msg.TransID))
{
if (_IsWebApp &&
System.Web.Hosting.HostingEnvironment.IsHosted &&
System.Web.HttpContext.Current != null &&
System.Web.HttpContext.Current.Handler != null)
{
msg.TransID = System.Web.HttpContext.Current.Request.GetHashCode().ToString();
}
}
}
catch (System.Web.HttpException ex)
{
StackifyAPILogger.Log("Request not available \r\n" + ex.ToString());
}
catch (Exception ex)
{
StackifyAPILogger.Log("Error figuring out TransID \r\n" + ex.ToString());
}
if (_IsWebApp &&
System.Web.Hosting.HostingEnvironment.IsHosted &&
System.Web.HttpContext.Current != null &&
System.Web.HttpContext.Current.Handler != null)
{
var context = System.Web.HttpContext.Current;
msg.UrlFull = context.Request.Url.ToString();
if (context.Items.Contains("Stackify.ReportingUrl"))
{
msg.UrlRoute = context.Items["Stackify.ReportingUrl"].ToString();
}
else
{
var resolver = new RouteResolver(new HttpContextWrapper(context));
var route = resolver.GetRoute();
if (!string.IsNullOrEmpty(route.Action))
{
msg.UrlRoute = route.ToString();
}
}
if (string.IsNullOrEmpty(msg.UrlRoute))
{
if (string.IsNullOrWhiteSpace(context.Request.AppRelativeCurrentExecutionFilePath) == false)
{
HelperFunctions.CleanPartialUrl(context.Request.AppRelativeCurrentExecutionFilePath.TrimStart('~'));
}
}
}
#endif
_MessageBuffer.Enqueue(msg);
}
catch (Exception ex)
{
StackifyAPILogger.Log("#LogQueue #QueueLogMessage failed", ex);
}
}
public StackifyTraceListener()
{
StackifyAPILogger.Log("Composite C1 TraceListener created");
}
private void OnTimer(Object stateInfo)
{
if (_PauseUpload)
{
return;
}
_timer.Change(-1, -1); //disable while it does this so it does fire multiple times
try
{
//remove messages in the queue that are old
if (!_LogClient.IsAuthorized() && _MessageBuffer.Count > 0)
{
var cutoff = (long)DateTime.UtcNow.AddMinutes(-5).Subtract(_Epoch).TotalMilliseconds;
while (true)
{
LogMsg msg;
if (_MessageBuffer.TryPeek(out msg) && msg.EpochMs < cutoff)
{
LogMsg msg2;
_MessageBuffer.TryDequeue(out msg2);
}
else
{
break;
}
}
if (_timer != null && !_StopRequested)
{
_timer.Change(_FlushInterval, _FlushInterval);
}
return;
}
}
catch (Exception ex)
{
StackifyAPILogger.Log("#LogQueue #OnTimer failed", ex);
}
try
{
int processedCount = FlushLoop();
//auto adjust how often we send based on how the rate of which data is being logged
if (processedCount >= 100)
{
if (_FlushInterval.TotalSeconds > 1)
{
_FlushInterval = TimeSpan.FromSeconds(_FlushInterval.TotalSeconds / 2);
StackifyAPILogger.Log(string.Format("#LogQueue Adjust log flush interval down to {0:0.00} seconds", _FlushInterval.TotalSeconds));
}
}
else if (processedCount < 10 && _FlushInterval != TimeSpan.FromSeconds(5))
{
double proposedSeconds = _FlushInterval.TotalSeconds * 1.25;
if (proposedSeconds < 1)
{
proposedSeconds = 1;
}
else if (proposedSeconds > 5)
{
proposedSeconds = 5;
}
if (_FlushInterval.TotalSeconds < proposedSeconds)
{
_FlushInterval = TimeSpan.FromSeconds(proposedSeconds);
StackifyAPILogger.Log(string.Format("#LogQueue Adjust log flush interval up to {0:0.00} seconds", _FlushInterval.TotalSeconds));
}
}
}
catch (Exception ex)
{
StackifyAPILogger.Log("#LogQueue #QueueLogMessage failed", ex);
}
if (_timer != null && !_StopRequested)
{
_timer.Change(_FlushInterval, _FlushInterval);
}
}
/// <summary>
/// Read everything in the queue up to a certain time point
/// </summary>
private static void ReadAllQueuedMetrics()
{
DateTime maxDate = DateTime.UtcNow; //read only up until now so it doesn't get stuck in an endless loop
//Loop through add sum up the totals of the counts and values by aggregate key then pass it all in at once to update the aggregate dictionary so it is done in one pass
//key is the aggregate key which is the metric name, type and rounded minute of the occurrence
StackifyAPILogger.Log("ReadAllQueuedMetrics " + maxDate);
var batches = new Dictionary <string, MetricAggregate>();
long processed = 0;
Metric metric;
while (_MetricQueue.TryDequeue(out metric))
{
processed++;
metric.CalcAndSetAggregateKey();
if (!batches.ContainsKey(metric.AggregateKey))
{
string nameKey = metric.CalcNameKey();
if (metric.IsIncrement && _LastAggregates.ContainsKey(nameKey))
{
//if wanting to do increments we need to grab the last value so we know what to increment
metric.Value = _LastAggregates[nameKey].Value;
}
batches[metric.AggregateKey] = new MetricAggregate(metric);
//if it is null don't do anything
//we are doing it where the aggregates are created so we don't do it one very single metric, just once per batch to optimize performance
if (metric.Settings != null)
{
_MetricSettings[nameKey] = metric.Settings;
}
}
batches[metric.AggregateKey].Count++;
if (metric.IsIncrement)
{
//add or subtract
batches[metric.AggregateKey].Value += metric.Value;
if (metric.Settings != null && batches[metric.AggregateKey].Value < 0 && !metric.Settings.AllowNegativeGauge)
{
batches[metric.AggregateKey].Value = 0;
}
}
else if (metric.MetricType == MetricType.MetricLast)
{
//should end up the last value
batches[metric.AggregateKey].Value = metric.Value;
}
else
{
batches[metric.AggregateKey].Value += metric.Value;
}
if (metric.Occurred > maxDate)
{
//we don't need anything more this recent so bail
break;
}
}
StackifyLib.Utils.StackifyAPILogger.Log(string.Format("Read queued metrics processed {0} for max date {1}", processed, maxDate));
foreach (var batch in batches)
{
Aggregate(batch.Value);
}
}
private static bool UploadAggregates(List <KeyValuePair <string, MetricAggregate> > metrics)
{
var allSuccess = true;
if (metrics.Count == 0)
{
return(true);
}
var identifyResult = HttpClient.IdentifyApp();
if (identifyResult && HttpClient.MatchedClientDeviceApp() && HttpClient.IsRecentError() == false && HttpClient.IsAuthorized())
{
StackifyAPILogger.Log($"Uploading Aggregate Metrics: {metrics.Count}");
foreach (KeyValuePair <string, MetricAggregate> keyValuePair in metrics)
{
GetMetricResponse monitorInfo;
// in case the appid changes on the server side somehow and we need to update the monitorids we are adding the appid to the key
// calling IdentifyApp() above will sometimes cause the library to sync with the server with the appid
var keyWithAppId = string.Format("{0}-{1}", keyValuePair.Value.NameKey, HttpClient.AppIdentity.DeviceAppID);
if (MontorIdList.ContainsKey(keyWithAppId) == false)
{
monitorInfo = GetMonitorInfo(keyValuePair.Value);
if (monitorInfo != null && monitorInfo.MonitorID != null && monitorInfo.MonitorID > 0)
{
MontorIdList[keyWithAppId] = monitorInfo;
}
else if (monitorInfo != null && monitorInfo.MonitorID == null)
{
StackifyAPILogger.Log($"Unable to get metric info for {keyWithAppId} MonitorID is null");
MontorIdList[keyWithAppId] = monitorInfo;
}
else
{
StackifyAPILogger.Log($"Unable to get metric info for {keyWithAppId}");
allSuccess = false;
}
}
else
{
monitorInfo = MontorIdList[keyWithAppId];
}
if (monitorInfo == null || monitorInfo.MonitorID == null)
{
StackifyAPILogger.Log($"Metric info missing for {keyWithAppId}");
keyValuePair.Value.MonitorID = null;
allSuccess = false;
}
else
{
keyValuePair.Value.MonitorID = monitorInfo.MonitorID;
}
}
//get the identified ones
List <KeyValuePair <string, MetricAggregate> > toUpload = metrics.Where(x => x.Value.MonitorID != null).ToList();
var success = UploadMetrics(toUpload.Select(x => x.Value).ToList());
if (success == false)
{
//error uploading so add them back in
toUpload.ForEach(x => AggregateMetrics.TryAdd(x.Key, x.Value));
allSuccess = false;
}
else
{
//worked so remove them
toUpload.ForEach(x =>
{
MetricAggregate removed;
AggregateMetrics.TryRemove(x.Key, out removed);
});
}
}
else
{
StackifyAPILogger.Log($"Metrics not uploaded. Identify Result: {identifyResult}, Metrics API Enabled: {HttpClient.MatchedClientDeviceApp()}");
//if there was an issue trying to identify the app we could end up here and will want to try again later
allSuccess = false;
//add them back to the queue
metrics.ForEach(x => AggregateMetrics.TryAdd(x.Key, x.Value));
}
return(allSuccess);
}
public static bool UploadMetrics(DateTime currentMinute)
{
var success = false;
var metrics = new List <KeyValuePair <string, MetricAggregate> >();
try
{
//read everything up to now
ReadAllQueuedMetrics();
//ensures all the aggregate keys exists for any previous metrics so we report zeros on no changes
HandleZeroReports(currentMinute);
List <MetricAggregate> getForRecent = AggregateMetrics
.Where(x => x.Value.OccurredUtc <currentMinute && x.Value.OccurredUtc> DateTime.UtcNow.AddMinutes(-5))
.Select(x => x.Value)
.ToList();
SetLatestAggregates(getForRecent);
//skip messing with HttpClient if nothing to do
if (AggregateMetrics.Count == 0)
{
return(true);
}
if (HttpClient.MatchedClientDeviceApp() == false)
{
// purgeOlderThan = DateTime.UtcNow;
StackifyAPILogger.Log("Upload metrics skipped because we were unable to match the app to an app in Stackify");
}
else if (HttpClient.IsAuthorized() == false)
{
// purgeOlderThan = DateTime.UtcNow;
StackifyAPILogger.Log("Upload metrics skipped authorization failure");
}
else if (HttpClient.IsRecentError() == false)
{
//If something happens at 2:39:45. The OccurredUtc is a rounded down value to 2:39. So we add a minute to ensure the minute has fully elapsed
//We are doing 65 seconds to just a little lag time for queue processing
//doing metric counters only every 30 seconds.
metrics = AggregateMetrics
.Where(x => x.Value.OccurredUtc < currentMinute)
.Take(50)
.ToList();
if (metrics.Count > 0)
{
//only getting metrics less than 10 minutes old to drop old data in case we get backed up
//they are removed from the _AggregateMetrics in the upload function upon success
success = UploadAggregates(metrics
.Where(x => x.Value.OccurredUtc > DateTime.UtcNow.AddMinutes(-10))
.ToList());
}
}
else
{
StackifyAPILogger.Log("Upload metrics skipped and delayed due to recent error");
}
}
catch (Exception ex)
{
success = false;
StackifyAPILogger.Log($"Error uploading metrics {ex}");
//if an error put them back in
try
{
metrics.ForEach(x => AggregateMetrics.TryAdd(x.Key, x.Value));
}
catch (Exception ex2)
{
StackifyAPILogger.Log($"Error adding metrics back to upload list {ex2}");
}
}
return(success);
}
/// <summary>
/// Used to make sure we report 0 values if nothing new comes in
/// </summary>
public static void HandleZeroReports(DateTime currentMinute)
{
foreach (var item in _LastAggregates)
{
MetricSetting setting;
if (_MetricSettings.TryGetValue(item.Value.NameKey, out setting))
{
if (setting == null)
{
MetricSetting remove;
_MetricSettings.TryRemove(item.Value.NameKey, out remove);
continue;
}
MetricAggregate agg = new MetricAggregate(item.Value.Category, item.Value.Name, item.Value.MetricType);
agg.OccurredUtc = currentMinute;
switch (item.Value.MetricType)
{
case MetricType.Counter:
setting.AutoReportLastValueIfNothingReported = false; //do not allow this
break;
case MetricType.CounterTime:
setting.AutoReportLastValueIfNothingReported = false; //do not allow this
break;
case MetricType.MetricAverage:
break;
case MetricType.MetricLast:
break;
}
if (setting.AutoReportZeroIfNothingReported)
{
agg.Count = 1;
agg.Value = 0;
}
else if (setting.AutoReportLastValueIfNothingReported)
{
agg.Count = item.Value.Count;
agg.Value = item.Value.Value;
}
else
{
continue;
}
string aggKey = agg.AggregateKey();
if (!_AggregateMetrics.ContainsKey(aggKey))
{
agg.NameKey = item.Value.NameKey;
StackifyAPILogger.Log("Creating 0 default value for " + aggKey);
_AggregateMetrics[aggKey] = agg;
}
}
}
}
private static bool UploadAggregates(List <KeyValuePair <string, MetricAggregate> > metrics)
{
bool allSuccess = true;
bool identifyResult = _httpClient.IdentifyApp();
if (identifyResult && _httpClient.MatchedClientDeviceApp() && !_httpClient.IsRecentError() && _httpClient.IsAuthorized())
{
StackifyAPILogger.Log("Uploading Aggregate Metrics: " + metrics.Count);
foreach (var keyValuePair in metrics)
{
GetMetricResponse monitorInfo;
//in case the appid changes on the server side somehow and we need to update the monitorids we are adding the appid to the key
//calling IdentifyApp() above will sometimes cause the library to sync with the server with the appid
string keyWithAppID = string.Format("{0}-{1}", keyValuePair.Value.NameKey, _httpClient.AppIdentity.DeviceAppID);
if (!_MontorIDList.ContainsKey(keyWithAppID))
{
monitorInfo = GetMonitorInfo(keyValuePair.Value);
if (monitorInfo != null && monitorInfo.MonitorID != null && monitorInfo.MonitorID > 0)
{
_MontorIDList[keyWithAppID] = monitorInfo;
}
else if (monitorInfo != null && monitorInfo.MonitorID == null)
{
StackifyAPILogger.Log("Unable to get metric info for " + keyWithAppID + " MonitorID is null");
_MontorIDList[keyWithAppID] = monitorInfo;
}
else
{
StackifyAPILogger.Log("Unable to get metric info for " + keyWithAppID);
allSuccess = false;
}
}
else
{
monitorInfo = _MontorIDList[keyWithAppID];
}
if (monitorInfo == null || monitorInfo.MonitorID == null)
{
StackifyAPILogger.Log("Metric info missing for " + keyWithAppID);
keyValuePair.Value.MonitorID = null;
allSuccess = false;
}
else
{
keyValuePair.Value.MonitorID = monitorInfo.MonitorID;
}
}
//get the identified ones
var toUpload = metrics.Where(x => x.Value.MonitorID != null).ToList();
bool success = UploadMetrics(toUpload.Select(x => x.Value).ToList());
if (!success)
{
//error uploading so add them back in
toUpload.ForEach(x => _AggregateMetrics.TryAdd(x.Key, x.Value));
allSuccess = false;
}
else
{
//worked so remove them
MetricAggregate removed;
toUpload.ForEach(x => _AggregateMetrics.TryRemove(x.Key, out removed));
}
}
else
{
StackifyAPILogger.Log("Metrics not uploaded. Identify Result: " + identifyResult + ", Metrics API Enabled: " + _httpClient.MatchedClientDeviceApp());
//if there was an issue trying to identify the app we could end up here and will want to try again later
allSuccess = false;
//add them back to the queue
metrics.ForEach(x => _AggregateMetrics.TryAdd(x.Key, x.Value));
}
return(allSuccess);
}
