/// <summary>
/// Saves an <see cref="ITimingSession"/>.
/// </summary>
/// <param name="session"></param>
protected override void Save(ITimingSession session)
{
//if (!Logger.Value.IsInfoEnabled)
//{
// return;
//}
if (session == null)
{
return;
}
SaveSessionJson(session);
if (session.Timings == null)
{
return;
}
foreach (var timing in session.Timings)
{
if (timing == null)
{
continue;
}
SaveTimingJson(session, timing);
}
}
private PureProfilingEntity FormatTimingSession(ITimingSession session)
{
PureProfilingEntity v = new PureProfilingEntity();
v.SEQ = Pure.Data.IdGenerateManager.Snowflake.NextId().ToString(); // Guid.NewGuid().ToString();
v.MachineName = session.MachineName;
v.Type = session.Type;
v.SessionId = session.Id.ToString();
v.Id = session.Id.ToString();
v.ParentId = session.ParentId != null?session.ParentId.ToString() : "";
v.Name = session.Name;
v.Started = session.Started;
v.StartMilliseconds = session.StartMilliseconds;
v.DurationMilliseconds = session.DurationMilliseconds;
v.Tags = session.Tags != null?session.Tags.ToString() : "";
v.Sort = session.Sort;
//var sb = new StringBuilder();
//sb.Append("{");
//AppendDataFields(sb, session.Data);
//sb.Append("}");
//v.Data = sb.ToString();
SetAllFieldDataField(v, session.Data);
return(v);
}
private static async Task <string> DoWork()
{
ProfilingSession.Start("DoWork");
// Avoid GC of session
_current = ProfilingSession.Current;
ITimingSession timingSession = ProfilingSession.Current.Profiler.GetTimingSession();
using (ProfilingSession.Current.Step("child1"))
{
await Task.WhenAll(Task.Run(() =>
{
using (ProfilingSession.Current.Step("child1.1"))
{
Thread.Sleep(10);
}
}),
Task.Run(() =>
{
using (ProfilingSession.Current.Step("child1.2"))
{
Thread.Sleep(20);
}
}));
}
ProfilingSession.Stop();
string report = GetReport(timingSession);
return(report);
}
public async Task SaveDbSessionAsync(ITimingSession session, IDbConnection conn, IDbTransaction trans)
{
var dbSession = session.Timings.Where(x => x.Type == "db");
foreach (var item in dbSession)
{
await conn.ExecuteAsync
(
@"INSERT INTO [dbo].[NanoprofilerLog]
([mainId],[sessionId],[parentId],[machine],[type],[name],[started],[druation],[executetype],[parameters])
VALUES
(@mainId,@sessionId,@parentId,@machine,@type,@name,@started,@druation,@executetype ,@parameters)",
new
{
mainId = item.Id.ToString(),
sessionid = session.Id.ToString(),
parentId = item.ParentId.ToString(), //對應SaveMainSession的mainId
machine = session.MachineName,
type = item.Type, //總共分session和setp和db，這個是db
name = item.Name, //紀錄執行的sql或sp名稱
started = item.Started,
druation = item.DurationMilliseconds,
executetype = item.Data.FirstOrDefault(x => x.Key == "executeType").Value, //查詢或非查詢
parameters = item.Data.FirstOrDefault(x => x.Key == "parameters").Value //參數包含型別和丟進去的數值
},
trans
);
}
}
/// <summary>
/// Initializes a <see cref="Profiler"/> class instance.
/// </summary>
/// <param name="name">The profiler name.</param>
/// <param name="storage">The profiler storage.</param>
/// <param name="tags">Tags of the profiler.</param>
public Profiler(string name, IProfilingStorage storage, TagCollection tags)
{
if (string.IsNullOrEmpty(name))
{
throw new ArgumentNullException("name");
}
if (storage == null)
{
throw new ArgumentNullException("storage");
}
_storage = storage;
_stopwatch = new Stopwatch();
_stopwatch.Start();
DateTime now = DateTime.Now;
if (ConfigurationHelper.LoadPureProfilerConfigurationSection().EnableUtcTime)
{
now = DateTime.UtcNow;
}
_timingSession = new TimingSession(this, name, tags)
{
Started = now
};
var rootTiming = new ProfilingStep(this, "root", null);
_timingSession.AddTiming(rootTiming);
}
private void PrintDrillUpLink(StringBuilder sb, ITimingSession session, string baseViewPath)
{
if (session.Data == null || !session.Data.ContainsKey("correlationId"))
{
return;
}
var correlationId = session.Data["correlationId"];
Guid?drillUpSessionId = null;
if (DrillUpHandler == null)
{
var drillUpSession = ProfilingSession.CircularBuffer.FirstOrDefault(s => s.Timings != null && s.Timings.Any(t => t.Data != null && t.Data.ContainsKey("correlationId") && t.Data["correlationId"] == correlationId));
if (drillUpSession != null)
{
drillUpSessionId = drillUpSession.Id;
}
}
else
{
drillUpSessionId = DrillUpHandler(correlationId);
}
if (!drillUpSessionId.HasValue)
{
return;
}
sb.Append("[<a href=\"");
sb.Append(baseViewPath);
sb.Append("/");
sb.Append(drillUpSessionId);
sb.Append("\">drill up</a>] ");
}
public async Task SaveMainSessionAsync(ITimingSession session, IDbConnection conn, IDbTransaction trans)
{
await conn.ExecuteAsync
(
@"INSERT INTO [dbo].[NanoprofilerLog]
([mainId],[sessionId],[machine],[type],[name],[started],[dbdruation],[druation],[requesttype],[clientip],[dbcount])
VALUES
(@mainId,@sessionId,@machine,@type,@name,@started,@dbdruation,@druation,@requesttype,@clientip,@dbcount)",
new
{
mainId = session.Id.ToString(), //主id，不重覆
sessionId = session.Id.ToString(), //每次api共同的id
machine = session.MachineName, //呼叫的電腦名稱
type = session.Type, //總共分session和setp和db，這個是session
name = session.Name, //api的名字
started = session.Started, //開始時間
dbdruation = session.Data.FirstOrDefault(x => x.Key == "dbDruation").Value, //db耗時
druation = session.DurationMilliseconds, //api的總耗時
requesttype = session.Data.FirstOrDefault(x => x.Key == "requestType").Value, //request的方式，以我的例子是web
clientip = session.Data.FirstOrDefault(x => x.Key == "clientIp").Value,
dbcount = session.Data.FirstOrDefault(x => x.Key == "dbCount").Value //這次api呼叫了多少個連線，如果有兩個sp就會有兩個連線
},
trans
);
}
/// <summary>
/// Saves an <see cref="ITimingSession"/>.
/// </summary>
/// <param name="session"></param>
protected override void Save(ITimingSession session)
{
if (!Logger.Value.IsEnabled(LogLevel.Information))
{
return;
}
if (session == null)
{
return;
}
SaveSessionJson(session);
if (session.Timings == null)
{
return;
}
foreach (var timing in session.Timings)
{
if (timing == null)
{
continue;
}
SaveTimingJson(session, timing);
}
}
protected override void Save(ITimingSession session)
{
//this._iNanoProfilerService.Save(session); //射後不理
//this._iNanoProfilerService.Save(session).Wait();
AsyncHelper.RunSync(() => this._iNanoProfilerService.SaveAsync(session));
}
private void PrintTiming(ITimingSession session, ITiming timing, StringBuilder sb, double factor, string baseViewPath)
{
sb.Append("<li><span class=\"timing\" style=\"padding-left: ");
var start = Math.Floor(timing.StartMilliseconds * factor);
if (start > 300)
{
start = 300;
}
sb.Append(start);
sb.Append("px\"><span class=\"bar ");
sb.Append(timing.Type);
sb.Append("\" title=\"");
sb.Append(HttpUtility.HtmlEncode(timing.Name.Replace("\r\n", " ")));
sb.Append("\" style=\"width: ");
var width = (int)Math.Round(timing.DurationMilliseconds * factor);
if (width > 300)
{
width = 300;
}
else if (width == 0)
{
width = 1;
}
sb.Append(width);
sb.Append("px\"></span><span class=\"start\">+");
sb.Append(timing.StartMilliseconds);
sb.Append("</span><span class=\"duration\">");
sb.Append(timing.DurationMilliseconds);
sb.Append("</span></span>");
var hasChildTimings = session.Timings.Any(s => s.ParentId == timing.Id);
if (hasChildTimings)
{
sb.Append("<input type=\"checkbox\" id=\"t_");
sb.Append(timing.Id.ToString());
sb.Append("\" checked=\"checked\" /><label for=\"t_");
sb.Append(timing.Id.ToString());
sb.Append("\">");
PrintDataLink(sb, timing);
PrintDrillDownLink(sb, timing, baseViewPath);
sb.Append(HttpUtility.HtmlEncode(timing.Name.Replace("\r\n", " ")));
sb.Append("</label>");
sb.Append("<ul>");
PrintTimings(session, timing.Id, sb, factor, baseViewPath);
sb.Append("</ul>");
}
else
{
sb.Append("<span class=\"leaf\">");
PrintDataLink(sb, timing);
PrintDrillDownLink(sb, timing, baseViewPath);
sb.Append(HttpUtility.HtmlEncode(timing.Name.Replace("\r\n", " ")));
sb.Append("</span>");
}
sb.Append("</li>");
}
private void PrintTimings(ITimingSession session, Guid parentId, StringBuilder sb, double factor, string baseViewPath)
{
var timings = session.Timings.Where(s => s.ParentId == parentId);
foreach (var timing in timings)
{
PrintTiming(session, timing, sb, factor, baseViewPath);
}
}
/// <summary>
/// What to do on internal queue overflow.
///
/// By default, it will delay the enqueue of session for at most 5000ms and log exception.
/// </summary>
/// <param name="session">The <see cref="ITimingSession"/> being enqueued when internal queue overflow.</param>
protected virtual void OnQueueOverflow(ITimingSession session)
{
// On overflow, never block the main thread running,
// simply throw away the item at the top of the queue, enqueue the new item and log the event
// so basically, the queue works like a ring buffer
ITimingSession temp;
TryDequeue(out temp);
Enqueue(session);
Logger.Error(OnQueueOverflowEventMessage);
}
private void SaveTimingJson(ITimingSession session, ITiming timing)
{
var sb = new StringBuilder();
sb.Append("{");
AppendSessionSharedFields(sb, session);
AppendTimingFields(sb, timing);
sb.Append("}");
Logger.Value.Info(sb.ToString());
}
private void SaveSessionJson(ITimingSession session)
{
var sb = new StringBuilder();
sb.Append("{");
AppendSessionSharedFields(sb, session);
AppendTimingFields(sb, session);
sb.Append("}");
Logger.Value.LogInformation(sb.ToString());
}
/// <summary>
/// Saves a profiling timing session.
/// </summary>
/// <param name="session">The <see cref="ITimingSession"/> to be saved.</param>
public void SaveSession(ITimingSession session)
{
if (MaxQueueLength == Inline)
{
Save(session);
}
else if (Count < MaxQueueLength || MaxQueueLength == Infinite)
{
Enqueue(session);
InvokeThreadStart();
}
else
{
OnQueueOverflow(session);
}
}
/// <summary>
/// Saves an <see cref="ITimingSession"/>.
/// </summary>
/// <param name="session"></param>
protected override void Save(ITimingSession session)
{
try
{
//if (!Logger.Value.IsInfoEnabled)
//{
// return;
//}
if (session == null)
{
return;
}
var v = FormatTimingSession(session);
//SaveSessionJson(session);
using (var db = new PureProfilingDbContext())
{
if (session.Timings == null)
{
return;
}
long errorCount = 0;
foreach (var timing in session.Timings)
{
if (timing == null)
{
continue;
}
//SaveTimingJson(session, timing);
var v2 = FormatTiming(session, timing);
db.Insert <PureProfilingEntity>(v2, null);
errorCount += v2.ErrorCount;
}
v.ErrorCount = errorCount;
db.Insert <PureProfilingEntity>(v, null);
}
}
catch (Exception ex)
{
System.Diagnostics.Debug.WriteLine("PureProfiler DatabaseProfilingStorage Save error:" + ex);
}
}
private PureProfilingEntity FormatTiming(ITimingSession session, ITiming timing)
{
PureProfilingEntity v = new PureProfilingEntity();
v.SEQ = Pure.Data.IdGenerateManager.Snowflake.NextId().ToString(); // Guid.NewGuid().ToString();
v.MachineName = session.MachineName;
v.SessionId = session.Id.ToString();
v.Type = timing.Type;
v.Id = timing.Id.ToString();
v.ParentId = timing.ParentId != null?timing.ParentId.ToString() : "";
v.Name = timing.Name;
v.Started = timing.Started;
v.StartMilliseconds = timing.StartMilliseconds;
v.DurationMilliseconds = timing.DurationMilliseconds;
v.Tags = timing.Tags != null?timing.Tags.ToString() : "";
v.Sort = timing.Sort;
//var sb = new StringBuilder();
//sb.Append("{");
//AppendDataFields(sb, timing.Data);
//sb.Append("}");
//v.Data = sb.ToString();
SetAllFieldDataField(v, timing.Data);
if (timing.Tags != null && timing.Tags.Contains(ProfilingSession.FailOnErrorMark))
{
v.ErrorCount = 1;
}
else
{
v.ErrorCount = 0;
}
return(v);
}
private static void AddAggregationFields(ITimingSession session)
{
if (session.Timings == null || !session.Timings.Any())
{
return;
}
var groups = session.Timings.GroupBy(timing => timing.Type);
foreach (var group in groups)
{
if (string.Equals("step", group.Key))
{
continue;
}
session.Data[group.Key + "Count"] = group.Count().ToString(CultureInfo.InvariantCulture);
session.Data[group.Key + "Duration"] = ((long)group.Sum(timing => timing.DurationMilliseconds)).ToString(CultureInfo.InvariantCulture);
}
}
public TimingSessionWrapper(ITimingSession session)
{
if (session == null)
{
return;
}
MachineName = session.MachineName;
Timings = session.Timings;
Type = session.Type;
Id = session.Id;
ParentId = session.ParentId;
Name = session.Name;
Started = session.Started;
StartMilliseconds = session.StartMilliseconds;
DurationMilliseconds = session.DurationMilliseconds;
Tags = session.Tags;
Sort = session.Sort;
Data = session.Data;
}
public async Task SaveRootSessionAsync(ITimingSession session, IDbConnection conn, IDbTransaction trans)
{
var rootSession = session.Timings.FirstOrDefault(x => x.Type == "step");
await conn.ExecuteAsync
(
@"INSERT INTO [dbo].[NanoprofilerLog]
([mainId],[sessionId],[machine],[type],[parentId],[name],[druation])
VALUES
(@mainId,@sessionId,@machine,@type,@parentId,@name,@druation)",
new
{
mainId = rootSession.Id.ToString(),
sessionid = session.Id.ToString(),
machine = session.MachineName,
type = rootSession.Type, //總共分session和setp和db，這個是setp
parentId = rootSession.ParentId.ToString(), //對應SaveMainSession的mainId
name = rootSession.Name, //紀錄root
druation = rootSession.DurationMilliseconds //耗時
},
trans
);
}
/// <summary>
/// 儲存NanoProfiler監控的資料
/// </summary>
/// <param name="session">監控的資料</param>
/// <returns></returns>
public async Task SaveAsync(ITimingSession session)
{
try
{
using (var conn = this._iConnectionHelper.GetNorthwindConnection(false))
{
conn.Open();
using (IDbTransaction trans = conn.BeginTransaction())
{
await SaveMainSessionAsync(session, conn, trans); //請見圖示
await SaveRootSessionAsync(session, conn, trans); //請見圖示
await SaveDbSessionAsync(session, conn, trans); //請見圖示
trans.Commit();
}
}
}
catch (Exception ex)
{
throw ex;
}
}
/// <summary>
/// Initializes a <see cref="Profiler"/> class instance.
/// </summary>
/// <param name="name">The profiler name.</param>
/// <param name="storage">The profiler storage.</param>
/// <param name="tags">Tags of the profiler.</param>
public Profiler(string name, IProfilingStorage storage, TagCollection tags)
{
if (string.IsNullOrEmpty(name))
{
throw new ArgumentNullException("name");
}
if (storage == null)
{
throw new ArgumentNullException("storage");
}
_storage = storage;
_stopwatch = new Stopwatch();
_stopwatch.Start();
_timingSession = new TimingSession(this, name, tags)
{
Started = DateTime.UtcNow
};
var rootTiming = new ProfilingStep(this, "root", null);
_timingSession.AddTiming(rootTiming);
}
private static string GetReport(ITimingSession timingSession)
{
long totalMs = timingSession.DurationMilliseconds;
var sb = new StringBuilder();
sb.AppendLine($"Profiling session: [{timingSession.Name}], {totalMs} ms total)");
IEnumerable <ITiming> timingsParentFirst = TraverseTimingsPreOrder(timingSession,
timingSession.Timings.ToList());
foreach (ITiming timing in timingsParentFirst)
{
int depth = GetDepth(timing);
var depthString = new string('>', depth);
sb.AppendLine($"{depthString} {timing.Name} = {timing.DurationMilliseconds} ms");
}
sb.AppendLine();
string report = sb.ToString();
return(report);
}
private PureProfilingEntity Format(ITimingSession session)
{
PureProfilingEntity v = new PureProfilingEntity();
v.SEQ = Pure.Data.IdGenerateManager.Snowflake.NextId().ToString(); // Guid.NewGuid().ToString();
v.MachineName = session.MachineName;
v.Type = session.Type;
v.Id = session.Id.ToString();
v.ParentId = session.ParentId.ToString();
v.Name = session.Name;
v.Started = session.Started;
v.StartMilliseconds = session.StartMilliseconds;
v.DurationMilliseconds = session.DurationMilliseconds;
v.Tags = session.Tags;
v.Sort = session.Sort;
v.MachineName = session.MachineName;
v.MachineName = session.MachineName;
v.MachineName = session.MachineName;
v.MachineName = session.MachineName;
v.MachineName = session.MachineName;
return(v);
}
/// <summary>
/// 儲存NanoProfiler監控的資料
/// </summary>
/// <param name="session">監控的資料</param>
/// <returns></returns>
public async Task SaveAsync(ITimingSession session)
{
await this._iNanoProfilerRepository.SaveAsync(session);
}
/// <summary>
/// Enqueues a session to internal queue.
/// </summary>
/// <param name="session">The <see cref="ITimingSession"/> to be enqueued.</param>
protected void Enqueue(ITimingSession session)
{
_sessionQueue.Enqueue(session);
}
/// <summary>
/// Tries to dequeue a session from internal queue for processing.
/// </summary>
/// <param name="session">The <see cref="ITimingSession"/> to be dequeued.</param>
/// <returns>Returns the dequeued <see cref="ITimingSession"/>.</returns>
protected bool TryDequeue(out ITimingSession session)
{
return(_sessionQueue.TryDequeue(out session));
}
void IProfilingStorage.SaveSession(ITimingSession session)
{
SaveSession(session);
}
public void SaveSession(ITimingSession session)
{
_onReport?.Invoke(session);
}
/// <summary>
/// Saves an <see cref="ITimingSession"/>.
/// </summary>
/// <param name="session"></param>
protected override void Save(ITimingSession session)
{
// no operation
}
