Skip to content

Commit

Permalink
Show memory in megabytes
Browse files Browse the repository at this point in the history
  • Loading branch information
nohwnd committed Jun 14, 2024
1 parent 0066ca7 commit 8dc602a
Show file tree
Hide file tree
Showing 16 changed files with 83 additions and 63 deletions.
19 changes: 11 additions & 8 deletions Profiler/Profiler.Format.ps1xml
Original file line number Diff line number Diff line change
Expand Up @@ -11,16 +11,20 @@
<ListEntry>
<ListItems>
<ListItem>
<Label>Top50Duration</Label>
<ScriptBlock>'List top 50 lines based on duration'</ScriptBlock>
<Label>Top50SelfDuration</Label>
<ScriptBlock>'List top 50 lines based on time consumed directly by the line'</ScriptBlock>
</ListItem>
<ListItem>
<Label>Top50SelfMemory</Label>
<ScriptBlock>'List top 50 lines based on the memory consumed directly by the line'</ScriptBlock>
</ListItem>
<ListItem>
<Label>Top50HitCount</Label>
<ScriptBlock>'List top 50 lines based on hit count'</ScriptBlock>
</ListItem>
<ListItem>
<Label>Top50SelfDuration</Label>
<ScriptBlock>'List top 50 lines based on time consumed directly by the line'</ScriptBlock>
<Label>Top50Duration</Label>
<ScriptBlock>'List top 50 lines based on duration'</ScriptBlock>
</ListItem>
<ListItem>
<Label>Top50FunctionDuration</Label>
Expand All @@ -38,10 +42,6 @@
<Label>Top50Memory</Label>
<ScriptBlock>'List top 50 lines based on the memory consumed'</ScriptBlock>
</ListItem>
<ListItem>
<Label>Top50SelfMemory</Label>
<ScriptBlock>'List top 50 lines based on the memory consumed directly by the line'</ScriptBlock>
</ListItem>
<ListItem>
<Label>AllLines</Label>
<ScriptBlock>'Show all lines processed by profiler trace'</ScriptBlock>
Expand All @@ -56,6 +56,9 @@
<ListItem>
<PropertyName>StopwatchDuration</PropertyName>
</ListItem>
<ListItem>
<PropertyName>ScriptBlock</PropertyName>
</ListItem>
</ListItems>
</ListEntry>
</ListEntries>
Expand Down
6 changes: 3 additions & 3 deletions Profiler/Profiler.psd1
Original file line number Diff line number Diff line change
Expand Up @@ -8,7 +8,7 @@
RootModule = 'Profiler.psm1'

# Version number of this module.
ModuleVersion = '4.2.0'
ModuleVersion = '4.3.0'

# Supported PSEditions
# CompatiblePSEditions = @()
Expand All @@ -26,10 +26,10 @@ CompanyName = 'nohwnd'
Copyright = '(c) nohwnd. All rights reserved.'

# Description of the functionality provided by this module
Description = 'Script, ScriptBlock and module performance profiler for PowerShell 5, and PowerShell 7.'
Description = 'Script, ScriptBlock and module performance profiler for PowerShell 5.1, and PowerShell 7.'

# Minimum version of the PowerShell engine required by this module
PowerShellVersion = '5.0.0'
PowerShellVersion = '5.1.0'

# Name of the PowerShell host required by this module
# PowerShellHostName = ''
Expand Down
5 changes: 4 additions & 1 deletion Profiler/Trace-Script.ps1
Original file line number Diff line number Diff line change
Expand Up @@ -143,7 +143,7 @@ function Trace-Script {
$trace = $result.Trace

$scriptBlocks = $out.ScriptBlocks
$traceCount = $trace.Count
$traceCount = $trace.Count-4 # 2 first and 2 last events are internal events of Profiler

Write-Host -ForegroundColor Magenta "Processing $($traceCount) trace events. $(if (1000000 -lt $traceCount) { "This might take a while..."})"

Expand Down Expand Up @@ -174,6 +174,8 @@ function Trace-Script {
$line.SelfPercent = [Math]::Round($line.SelfDuration.Ticks / $ticks, 5, [System.MidpointRounding]::AwayFromZero) * 100
$line.MemoryPercent = if (0 -ne $totalMem) { [Math]::Round($line.Memory / $totalMem, 5, [System.MidpointRounding]::AwayFromZero) * 100 } else { 100 }
$line.SelfMemoryPercent = if (0 -ne $totalMem) { [Math]::Round($line.SelfMemory / $totalMem, 5, [System.MidpointRounding]::AwayFromZero) * 100 } else { 100 }
$line.Memory = [Math]::Round($line.Memory, 5, [System.MidpointRounding]::AwayFromZero)
$line.SelfMemory = [Math]::Round($line.SelfMemory, 5, [System.MidpointRounding]::AwayFromZero)
$line
}
Write-TimeAndRestart $sw
Expand Down Expand Up @@ -266,6 +268,7 @@ function Trace-Script {
# this way we can get the partial object out for
# debugging when this fails on someones system
$script:processedTrace = [Profiler.Trace]::new()
$script:processedTrace.ScriptBlock = $ScriptBlock
$script:processedTrace.TotalDuration = $total
$script:processedTrace.StopwatchDuration = $out.Stopwatch
$script:processedTrace.Events = $trace
Expand Down
3 changes: 2 additions & 1 deletion Profiler/Trace-ScriptInternal.ps1
Original file line number Diff line number Diff line change
Expand Up @@ -64,7 +64,8 @@ function Trace-ScriptInternal {

$out.Stopwatch = $result.Stopwatch
$out.ScriptBlocks = $result.ScriptBlocks
Write-Host -Foreground Magenta "Tracing done. Got $($trace.Count) trace events."
$traceCount = $result.Trace.Count - 4 # 2 first and 2 last events are internal events of Profiler
Write-Host -Foreground Magenta "Tracing done. Got $($traceCount) trace events."
$result
}

Expand Down
10 changes: 5 additions & 5 deletions csharp/Profiler/CommandHit.cs
Original file line number Diff line number Diff line change
Expand Up @@ -10,17 +10,17 @@ public class CommandHit
/// <summary>
/// Line number of the command in the file or ScriptBlock.
/// </summary>
public uint Line { get; set; }
public int Line { get; set; }

/// <summary>
/// Column of the command in the file or ScriptBlock.
/// </summary>
public uint Column { get; set; }
public int Column { get; set; }

/// <summary>
/// Number of hits on command.
/// </summary>
public uint HitCount { get; set; } = 1;
public int HitCount { get; set; } = 1;

/// <summary>
/// Time used exclusively by this command
Expand All @@ -34,8 +34,8 @@ public class CommandHit

public CommandHit(Hit hit)
{
Line = (uint)hit.Line;
Column = (uint)hit.Column;
Line = (int)hit.Line;
Column = (int)hit.Column;
SelfDuration = hit.SelfDuration;
Text = hit.Text;
}
Expand Down
25 changes: 13 additions & 12 deletions csharp/Profiler/Hit.cs
Original file line number Diff line number Diff line change
Expand Up @@ -85,22 +85,23 @@ public struct Hit

public bool Folded;

// HeapSize at the start of the hit.
public long HeapSize;
// HeapSize at the start of the hit in MB.
public decimal HeapSize;

// WorkingSet at the start of the hit.
public long WorkingSet;
// WorkingSet at the start of the hit in MB.
public decimal WorkingSet;

// HeapSize heapSize consumed by the hit (endHeapSize - startHeapSize).
public long SelfHeapSize;
// HeapSize heapSize consumed by the hit (endHeapSize - startHeapSize) in MB.
public decimal SelfHeapSize;

// Working set consumed by the hit.
public long SelfWorkingSet;
// Working set consumed by the hit in MB.
public decimal SelfWorkingSet;

// Working set consumed by the hit.
public long AllocatedBytes;
// Working set consumed by the hit in MB.
public decimal AllocatedBytes;

public long SelfAllocatedBytes;
// Bytes allocated by this hit in MB.
public decimal SelfAllocatedBytes;

public int Gc0;
public int SelfGc0;
Expand All @@ -112,6 +113,6 @@ public struct Hit
public int SelfGc2;


public long TotalBytes;
public decimal TotalBytes;
public int TotalGc;
}
18 changes: 9 additions & 9 deletions csharp/Profiler/LineProfile.cs
Original file line number Diff line number Diff line change
Expand Up @@ -11,7 +11,7 @@ public class LineProfile
/// <summary>
/// Percent of total duration used by line including all the code it calls.
/// </summary>
public double Percent { get; set; } = 0.00;
public decimal Percent { get; set; } = 0;

/// <summary>
/// Time used by line including subcalls.
Expand All @@ -22,7 +22,7 @@ public class LineProfile
/// <summary>
/// Percent of total duration used by line, excluding the code it calls.
/// </summary>
public double SelfPercent { get; set; } = 0.00;
public decimal SelfPercent { get; set; } = 0;

/// <summary>
/// Time used exclusively by this line.
Expand All @@ -33,22 +33,22 @@ public class LineProfile
/// <summary>
/// Percent of total memory used by line including all the code it calls.
/// </summary>
public double MemoryPercent { get; set; } = 0.00;
public decimal MemoryPercent { get; set; } = 0;

/// <summary>
/// Memory consumed by line and all subcalls.
/// </summary>
public long Memory { get; set; }
public decimal Memory { get; set; }

/// <summary>
/// Percent of total memory used by line, excluding the code it calls.
/// </summary>
public double SelfMemoryPercent { get; set; } = 0.00;
public decimal SelfMemoryPercent { get; set; } = 0;

/// <summary>
/// Memory consumed exclusively by this line.
/// </summary>
public long SelfMemory { get; set; }
public decimal SelfMemory { get; set; }

/// <summary>
/// Garbage collections happening on this line and in all subcalls (all generations).
Expand All @@ -64,7 +64,7 @@ public class LineProfile
/// <summary>
/// Number of hits on line.
/// </summary>
public uint HitCount { get; set; } = 0;
public int HitCount { get; set; } = 0;

/// <summary>
/// Name of file or id of ScriptBlock the line belongs to.
Expand All @@ -74,7 +74,7 @@ public class LineProfile
/// <summary>
/// Line number in the file or ScriptBlock.
/// </summary>
public uint? Line { get; set; }
public int? Line { get; set; }

/// <summary>
/// Function that called this line.
Expand Down Expand Up @@ -104,5 +104,5 @@ public class LineProfile
/// <summary>
/// All command hits in this line using column as key.
/// </summary>
public IDictionary<uint, CommandHit> CommandHits { get; set; } = new Dictionary<uint, CommandHit>();
public IDictionary<int, CommandHit> CommandHits { get; set; } = new Dictionary<int, CommandHit>();
}
18 changes: 9 additions & 9 deletions csharp/Profiler/LineProfileView.cs
Original file line number Diff line number Diff line change
Expand Up @@ -24,7 +24,7 @@ public LineProfileView(LineProfile line)
/// <summary>
/// Percent of total duration used by line including all the code it calls.
/// </summary>
public double Percent => _line.Percent;
public decimal Percent => _line.Percent;

/// <summary>
/// Time used by line including subcalls.
Expand All @@ -35,7 +35,7 @@ public LineProfileView(LineProfile line)
/// <summary>
/// Percent of total duration used by line, excluding the code it calls.
/// </summary>
public double SelfPercent => _line.SelfPercent;
public decimal SelfPercent => _line.SelfPercent;

/// <summary>
/// Time used exclusively by this line.
Expand All @@ -45,22 +45,22 @@ public LineProfileView(LineProfile line)
/// <summary>
/// Percent of total memory used by line including all the code it calls.
/// </summary>
public double MemoryPercent => _line.MemoryPercent;
public decimal MemoryPercent => _line.MemoryPercent;

/// <summary>
/// Memory used by this line.
/// </summary>
public long Memory => _line.Memory;
public decimal Memory => _line.Memory;

/// <summary>
/// Percent of total memory used by line.
/// </summary>
public double SelfMemoryPercent => _line.SelfMemoryPercent;
public decimal SelfMemoryPercent => _line.SelfMemoryPercent;

/// <summary>
/// Memory used exclusively by this line.
/// </summary>
public long SelfMemory => _line.SelfMemory;
public decimal SelfMemory => _line.SelfMemory;

/// <summary>
/// Garbage collection count that happened on this line.
Expand All @@ -77,7 +77,7 @@ public LineProfileView(LineProfile line)
/// <summary>
/// Number of hits on line.
/// </summary>
public uint HitCount => _line.HitCount;
public int HitCount => _line.HitCount;

/// <summary>
/// Name of file or id of ScriptBlock the line belongs to.
Expand All @@ -87,7 +87,7 @@ public LineProfileView(LineProfile line)
/// <summary>
/// Line number in the file or ScriptBlock.
/// </summary>
public uint? Line => _line.Line;
public int? Line => _line.Line;

/// <summary>
/// Function that called this line.
Expand Down Expand Up @@ -117,5 +117,5 @@ public LineProfileView(LineProfile line)
/// <summary>
/// All command hits in this line using column as key.
/// </summary>
public IDictionary<uint, CommandHit> CommandHits => _line.CommandHits;
public IDictionary<int, CommandHit> CommandHits => _line.CommandHits;
}
17 changes: 12 additions & 5 deletions csharp/Profiler/ProfilerTracer.cs
Original file line number Diff line number Diff line change
Expand Up @@ -46,13 +46,20 @@ public class ProfilerTracer : ITracer
// timespan ticks are 10k per millisecond, but the stopwatch can have different resolution
// calculate the diff between the timestamps and convert it to 10k per ms ticks
//
// cast the frequency to double to avoid whole number division. On systems where frequency
// cast the frequency to decimal to avoid whole number division. On systems where frequency
// is smaller than ticks per second this otherwise results in 0, and all timestamps then
// become positive infinity because of timestamp / 0 = ∞ or when cast to long: -9223372036854775808
private static double _tickDivider = ((double)Stopwatch.Frequency) / TimeSpan.TicksPerSecond;
private static decimal _tickDivider = ((decimal)Stopwatch.Frequency) / TimeSpan.TicksPerSecond;
private const string ScriptBlockName = "<ScriptBlock>";
private readonly bool _usePreciseMemoryMeasurement;
internal int _index = 0;
internal Hit _previousHit;
internal readonly decimal _megaByte = 1024 * 1024;

public ProfilerTracer()
{
_usePreciseMemoryMeasurement = Environment.GetEnvironmentVariable("POWERSHELL_PROFILER_PRECISE_MEMORY_MEASUREMENT") == "1";
}

public List<Hit> Hits { get; } = new List<Hit>();
public Dictionary<Guid, ScriptBlock> ScriptBlocks { get; } = new Dictionary<Guid, ScriptBlock>();
Expand All @@ -75,9 +82,9 @@ public void Trace(string _, IScriptExtent extent, ScriptBlock scriptBlock, int l
var gc2 = GC.CollectionCount(2);

#if NET5_0_OR_GREATER
var allocatedBytes = GC.GetTotalAllocatedBytes(precise: false);
var allocatedBytes = GC.GetTotalAllocatedBytes(precise: _usePreciseMemoryMeasurement) / _megaByte;
#else
var allocatedBytes = GC.GetTotalMemory(forceFullCollection: false);
var allocatedBytes = GC.GetTotalMemory(forceFullCollection: false) / _megaByte;
#endif

// we are using structs so we need to insert the final struct to the
Expand Down Expand Up @@ -144,7 +151,7 @@ public void Trace(string _, IScriptExtent extent, ScriptBlock scriptBlock, int l
}

private void SetSelfValuesAndAddToHits(ref Hit eventRecord, long timestamp,
long workingSet, long heapSize, long allocatedBytes,
decimal workingSet, decimal heapSize, decimal allocatedBytes,
int gc0, int gc1, int gc2)
{
eventRecord.SelfWorkingSet = workingSet - eventRecord.WorkingSet;
Expand Down
4 changes: 2 additions & 2 deletions csharp/Profiler/Profiler_ProcessFunctions.cs
Original file line number Diff line number Diff line change
Expand Up @@ -87,10 +87,10 @@ public static Dictionary<string, LineProfile> ProcessFunctions(List<Hit> trace)
// on the same line so we can see which commands contributed to the line duration
//if we need to count duration we can do it by moving this to the next part of the code
// where we process each hit on the line
if (!lineProfile.CommandHits.TryGetValue((uint)hit.Column, out var commandHit))
if (!lineProfile.CommandHits.TryGetValue((int)hit.Column, out var commandHit))
{
commandHit = new CommandHit(hit);
lineProfile.CommandHits.Add((uint)hit.Column, commandHit);
lineProfile.CommandHits.Add((int)hit.Column, commandHit);
}
else
{
Expand Down
6 changes: 3 additions & 3 deletions csharp/Profiler/Profiler_ProcessLines.cs
Original file line number Diff line number Diff line change
Expand Up @@ -71,7 +71,7 @@ public static Dictionary<Guid, File> ProcessLines(List<Hit> trace, Dictionary<Gu
lineProfile = new LineProfile
{
File = file.Name,
Line = (uint)lineNumber,
Line = (int)lineNumber,
Text = text,
Function = hit.Function,
Module = hit.Module,
Expand Down Expand Up @@ -141,10 +141,10 @@ public static Dictionary<Guid, File> ProcessLines(List<Hit> trace, Dictionary<Gu
// on the same line so we can see which commands contributed to the line duration
// if we need to count duration we can do it by moving this to the next part of the code
// where we process each hit on the line
if (!lineProfile.CommandHits.TryGetValue((uint)hit.Column, out var commandHit))
if (!lineProfile.CommandHits.TryGetValue((int)hit.Column, out var commandHit))
{
commandHit = new CommandHit(hit);
lineProfile.CommandHits.Add((uint)hit.Column, commandHit);
lineProfile.CommandHits.Add((int)hit.Column, commandHit);
}
else
{
Expand Down
Loading

0 comments on commit 8dc602a

Please sign in to comment.