add conditionals for logging to actually test performance

This commit is contained in:
Qrakhen 2025-11-18 22:49:32 +01:00
parent 367b334b79
commit 4f6d0fdf5b
9 changed files with 142 additions and 13 deletions

View File

@ -62,12 +62,16 @@ public static class Benchmark
if (!_clocks.TryGetValue(key, out Stopwatch sw))
{
#if LOG
_logger.Debug($"No clock found for '{key}', start one first using Benchmark.Start()");
#endif
return 0;
}
sw.Stop();
#if LOG
_logger.Debug($" ::: {key}:{line} > {message ?? "Elapsed"}: {sw.Elapsed}");
#endif
if (keep)
sw.Start();

View File

@ -76,12 +76,16 @@ public class Digester : ISteppable<Token>
public Function Digest()
{
#if LOG
_logger.Method();
#endif
TokenPosition previousPosition = _reader.CurrentPosition;
Next();
while (!Done && !Match(T.Eof)) {
Token token = Current;
#if LOG
_logger.Verbose($"Digesting {token}");
#endif
if (previousPosition == _reader.CurrentPosition) {
ErrorAtCurrent("Loop detected / could not digest further");
break;
@ -91,8 +95,12 @@ public class Digester : ISteppable<Token>
SegmentBuilder _debug = Builder.Function.Segment;
Function function = FinishBuilder();
#if LOG
_logger.Debug($"Digest done, instruction set:");
#endif
#if LOG
_logger.Verbose(_debug.Debug());
#endif
return function;
}
@ -118,7 +126,9 @@ public class Digester : ISteppable<Token>
internal void Process()
{
#if LOG
_logger.Method();
#endif
if (Match(T.Class)) DeclareClass();
else if (Match(T.Function)) DeclareFunction();
else if (Match(T.Var)) DeclareVariable();
@ -127,7 +137,9 @@ public class Digester : ISteppable<Token>
internal void Statement()
{
#if LOG
_logger.Method();
#endif
if (Match(T.If)) If();
else if (Match(T.Else)) Else();
else if (Match(T.While)) While();
@ -147,7 +159,9 @@ public class Digester : ISteppable<Token>
internal void Expression()
{
#if LOG
_logger.Method();
#endif
ParseExpression();
if (Builder.Type == FunctionType.Code && Check(T.Eof))
Emit(Op.Print); // if we got presented with only an expression on top-level code and no ; at the end,
@ -166,7 +180,9 @@ public class Digester : ISteppable<Token>
internal void Context()
{
#if LOG
_logger.Method();
#endif
BeginScope();
Block();
EndScope();
@ -174,7 +190,9 @@ public class Digester : ISteppable<Token>
internal void Block()
{
#if LOG
_logger.Method();
#endif
while (!Check(T.ContextClose) && !Check(T.Eof))
Process();
Consume(T.ContextClose, "Expected '}' after context");
@ -182,7 +200,9 @@ public class Digester : ISteppable<Token>
internal void WeightedDigest(Weight precedence)
{
#if LOG
_logger.Method();
#endif
Next();
Rule rule = ExpressionParser.Get(Previous.Type);
if (rule.Prefix == null) {
@ -204,7 +224,9 @@ public class Digester : ISteppable<Token>
internal void DeclareClass()
{
#if LOG
_logger.Method();
#endif
Consume(T.Identifier, "Expected a class name.");
// we need both a global name constant and a local declaration for this class
string name = Previous.Value!;
@ -250,7 +272,9 @@ public class Digester : ISteppable<Token>
internal void DeclareFunction()
{
#if LOG
_logger.Method();
#endif
long global = ParseVariable();
InitializeLocal();
CreateFunction(FunctionType.Function);
@ -260,7 +284,9 @@ public class Digester : ISteppable<Token>
internal void DeclareMember()
{
// todo: only methods allowed atm, add fields and shit too
#if LOG
_logger.Method();
#endif
Consume(T.Identifier, "Expected method name.", false);
long identifier = IdentifierConstant(Previous.Value!);
FunctionType type = FunctionType.Method;
@ -272,7 +298,9 @@ public class Digester : ISteppable<Token>
internal void DeclareVariable()
{
#if LOG
_logger.Method();
#endif
long global = ParseVariable();
if (Match(T.Equal))
ParseExpression();
@ -284,19 +312,25 @@ public class Digester : ISteppable<Token>
internal void Export()
{
#if LOG
_logger.Method();
#endif
throw new NotImplementedException($"Import is not yet implemented. Sorry, it's difficult.");
}
internal void Import()
{
#if LOG
_logger.Method();
#endif
throw new NotImplementedException($"Import is not yet implemented. Sorry, it's difficult.");
}
internal void If()
{
#if LOG
_logger.Method();
#endif
Consume(T.GroupOpen, "Expected '(' after if");
ParseExpression();
Consume(T.GroupClose, "Expected ')' after condition");
@ -318,13 +352,17 @@ public class Digester : ISteppable<Token>
internal void Else()
{
#if LOG
_logger.Method();
#endif
ErrorAtPrevious("This 'else' is very alone :( Have you meant to place it after an 'if'?");
}
internal void While()
{
#if LOG
_logger.Method();
#endif
long start = Function.CurrentInstruction;
Consume(T.GroupOpen, "Expected while condition to be placed inside parentheses. Missing '('.", false);
ParseExpression();
@ -339,14 +377,18 @@ public class Digester : ISteppable<Token>
internal void Do()
{
#if LOG
_logger.Method();
#endif
// todo: just do a while loop here with synthetic counter variables checked at end
throw new NotImplementedException();
}
internal void For()
{
#if LOG
_logger.Method();
#endif
BeginScope();
Consume(T.GroupOpen, "Expected '(' after for statement");
if (Match(T.Semicolon)) {
@ -390,7 +432,9 @@ public class Digester : ISteppable<Token>
internal void Return()
{
#if LOG
_logger.Method();
#endif
if (Builder.Type == FunctionType.Code) {
ErrorAtPrevious($"Interesting approach, but that won't work.");
return;
@ -412,7 +456,9 @@ public class Digester : ISteppable<Token>
internal void Print()
{
#if LOG
_logger.Method();
#endif
ParseExpression();
Consume(T.Semicolon, "Expected ';' after print call.");
Emit(Op.Print);
@ -420,41 +466,53 @@ public class Digester : ISteppable<Token>
internal void PrintGlobals()
{
#if LOG
_logger.Method();
#endif
Consume(T.Semicolon, "Expected ';' after print call.");
Emit(Op.PrintGlobals);
}
internal void PrintStack()
{
#if LOG
_logger.Method();
#endif
Consume(T.Semicolon, "Expected ';' after print call.");
Emit(Op.PrintStack);
}
internal void PrintExpr()
{
#if LOG
_logger.Method();
#endif
Consume(T.Semicolon, "Expected ';' after print call.");
Emit(Op.PrintExpr);
}
internal void TypeOf()
{
#if LOG
_logger.Method();
#endif
ParseExpression();
Emit(Op.Typeof);
}
internal void BeginScope()
{
#if LOG
_logger.Method();
#endif
Builder.ScopeDepth++;
}
internal void EndScope()
{
#if LOG
_logger.Method();
#endif
Builder.ScopeDepth--;
while (Builder.Locals.Count > 0 &&
Builder.Locals.Peek().Depth > Builder.ScopeDepth) {
@ -469,7 +527,9 @@ public class Digester : ISteppable<Token>
internal void CreateFunction(FunctionType type)
{
#if LOG
_logger.Method();
#endif
Builder next = CreateBuilder(type);
BeginScope();
Consume(T.GroupOpen, "Expected '(' to start argument list.");
@ -506,7 +566,9 @@ public class Digester : ISteppable<Token>
internal void AddLocal(string? name)
{
#if LOG
_logger.Method(name);
#endif
Builder.Locals.Push(new Local(ThrowIfEmpty(name), -1));
}
@ -515,7 +577,9 @@ public class Digester : ISteppable<Token>
if (Builder.ScopeDepth == 0)
return;
#if LOG
_logger.Method(name);
#endif
for (int i = 0; i < Builder.Locals.Count; i++) {
Local local = Builder.Locals[i];
// skip if the most recent local isn't even in our scope
@ -562,22 +626,30 @@ public class Digester : ISteppable<Token>
internal long IdentifierConstant(string? name)
{
#if LOG
_logger.Method(name);
#endif
return MakeConstant(String.Make(name ??
throw new TokenException("Empty string value for identifier detected", _reader, Current)));
}
internal long MakeConstant(Value value)
{
#if LOG
_logger.Method(value.ToString());
#endif
long constant = Function.Segment.Constants.Add(value);
#if LOG
_logger.Verbose($"Registered constant {value} at index {constant}");
#endif
return constant;
}
internal long ParseVariable()
{
#if LOG
_logger.Method();
#endif
string? name = Consume(T.Identifier, "Missing identifier for variable").Value;
if (Builder.ScopeDepth == 0)
return IdentifierConstant(name);
@ -590,7 +662,9 @@ public class Digester : ISteppable<Token>
if (Builder.ScopeDepth == 0)
return;
#if LOG
_logger.Method();
#endif
var local = Builder.Locals.Peek();
local.Depth = Builder.ScopeDepth;
Builder.Locals.Set(Builder.Locals.Position - 1, local);
@ -598,7 +672,9 @@ public class Digester : ISteppable<Token>
internal void DefineVariable(long index)
{
#if LOG
_logger.Method(index.ToString());
#endif
if (Builder.ScopeDepth > 0) {
InitializeLocal();
} else {
@ -627,10 +703,12 @@ public class Digester : ISteppable<Token>
/// </summary>
internal void Emit(params byte[] data)
{
#if LOG
if (data.Length == 1)
_logger.Verbose($"Emitting {new Instruction(data[0])}");
else if (data.Length > 1)
_logger.Verbose($"Emitting {string.Join(' ', data)}");
#endif
foreach (var value in data)
Function.Segment.Instructions.Add(value);
}
@ -778,9 +856,13 @@ public class Digester : ISteppable<Token>
private void ReportError(Token token, string errorMessage)
{
#if LOG
_logger.Method();
#endif
ErrorPosition = token.Position;
#if LOG
_logger.Error($"At token index {token.Position}: {errorMessage}");
#endif
if (ThrowOnError)
throw new TokenException($"At token index {token.Position}: {errorMessage}", _reader, token);
Error?.Invoke(token, errorMessage);

View File

@ -114,16 +114,16 @@ public static class ExpressionParser
static void ArrayAdd(Digester digester, bool canAssign)
{
digester.ParseExpression();
digester.Emit(OpCode.ArrayAdd);
digester.Emit(OpCode.AddItem);
}
static void Accessor(Digester digester, bool canAssign)
{
digester.ParseExpression();
digester.Consume(TokenType.ArrayClose, "expected ] after array accessor");
if (canAssign && digester.Match(TokenType.ArrayAdd)) {
if (canAssign && digester.Match(TokenType.AddItem)) {
digester.ParseExpression();
digester.Emit(OpCode.ArrayAdd);
digester.Emit(OpCode.AddItem);
} else if (canAssign && digester.Match(TokenType.Equal)) {
digester.ParseExpression();
digester.Emit(OpCode.SetItem);
@ -254,8 +254,8 @@ public static class ExpressionParser
_rules[TokenType.ContextClose] = new Rule(null, null, Weight.None);
_rules[TokenType.ArrayOpen] = new Rule(Array, Accessor, Weight.Call);
_rules[TokenType.ArrayClose] = new Rule(null, null, Weight.None);
_rules[TokenType.ArrayAdd] = new Rule(null, ArrayAdd, Weight.None);
_rules[TokenType.ArrayRemove] = new Rule(null, null, Weight.None);
_rules[TokenType.AddItem] = new Rule(null, ArrayAdd, Weight.None);
_rules[TokenType.RemoveItem] = new Rule(null, null, Weight.None);
_rules[TokenType.Colon] = new Rule(null, Dot, Weight.Call);
_rules[TokenType.Comma] = new Rule(null, null, Weight.None);
_rules[TokenType.Dot] = new Rule(null, Dot, Weight.Call);

View File

@ -52,9 +52,13 @@ public class Runner : IDisposable
public ExecutionResult Run(Stream stream)
{
#if LOG
_logger.Method();
#endif
if (Stack.Position < 0) {
#if LOG
_logger.Warn($"Something went wrong, stack cursor is at {Stack.Position}. Resetting Stack.");
#endif
Stack.Decimate(0);
}
using Reader reader = new Reader(stream);
@ -72,11 +76,15 @@ public class Runner : IDisposable
private ExecutionResult Execute()
{
#if LOG
_logger.Method();
#endif
Call call = Calls.Peek(-1);
do {
Op opCode = call.Instruction.Next();
#if LOG
_logger.Verbose($"OpCode: {opCode}");
#endif
if (TestFlag(opCode, Op.F_Operation)) {
Value result = ValueOperation.Resolve(PopOperation(opCode));
@ -105,7 +113,9 @@ public class Runner : IDisposable
Push(Value.Void);
else
Push(Globals[name]);
#if LOG
_logger.Verbose($"got global {name} ({Peek()})");
#endif
break;
}
@ -116,7 +126,9 @@ public class Runner : IDisposable
if (!Globals.Has(name))
return Error($"tried to set a value of non-existing global variable");
Globals[name] = Pop();
#if LOG
_logger.Verbose($"set global {name} = {Globals[name]}");
#endif
break;
}
@ -125,20 +137,26 @@ public class Runner : IDisposable
if (string.IsNullOrEmpty(name))
return Error($"tried to define global variable with empty name");
Globals[name] = Pop();
#if LOG
_logger.Verbose($"defined global {name} as {Globals[name]}");
#endif
break;
}
case Op.GetLocal: {
long slot = call.Instruction.NextDynamic();
#if LOG
_logger.Verbose($"getting slot {slot} which is {call.StackPtr.Get(slot)}");
#endif
Push(call.StackPtr.Get(slot));
break;
}
case Op.SetLocal: {
long slot = call.Instruction.NextDynamic();
#if LOG
_logger.Verbose($"setting stackptr {slot} to {Peek()}");
#endif
call.StackPtr.Set(slot, Peek());
break;
}
@ -429,7 +447,9 @@ public class Runner : IDisposable
private bool InvokeNative(Value target, NativeExtension extension, int argumentCount)
{
#if LOG
_logger.Method(extension);
#endif
if (argumentCount != extension.Parameters.Length) {
Error($"{extension} expects {extension.Parameters.Length} arguments, received {argumentCount}");
return false;
@ -448,7 +468,9 @@ public class Runner : IDisposable
private bool Invoke(Context closure, int argumentCount)
{
#if LOG
_logger.Method();
#endif
if (argumentCount != closure.Function.ArgumentCount) {
Error($"Expected {closure.Function.ArgumentCount} arguments but got {argumentCount}");
return false;
@ -554,25 +576,33 @@ public class Runner : IDisposable
private Value Peek(int delta = -1)
{
#if LOG
_logger.Method();
#endif
return Stack.Peek(delta);
}
private Value Pop()
{
#if LOG
_logger.Method();
#endif
return Stack.Pop();
}
private void Push(Value value)
{
#if LOG
_logger.Method($"{value}");
#endif
Stack.Push(value);
}
private Operation PopOperation(Op code)
{
#if LOG
_logger.Method(code);
#endif
if ((code & Op.F_Unary) == Op.F_Unary)
return new Operation(code, Pop(), default);
Value right = Pop();
@ -582,8 +612,12 @@ public class Runner : IDisposable
private ExecutionResult Error(string message, object? context = null, bool @throw = true)
{
#if LOG
_logger.Method(message);
#endif
#if LOG
_logger.Error(message, context);
#endif
Panic();
if (@throw)
throw new QampException(message, context);
@ -592,13 +626,17 @@ public class Runner : IDisposable
private void Panic()
{
#if LOG
_logger.Method();
#endif
Stack.Decimate(0);
}
public void Dispose()
{
#if LOG
_logger.Method();
#endif
}
}

View File

@ -17,7 +17,9 @@ public static class ValueOperation
public static Value Resolve(Operation operation)
{
#if LOG
_logger.Method($"{operation.Left} {operation.OpCode} {operation.Right}");
#endif
return _operations[operation.OpCode].Invoke(operation);
}
@ -72,7 +74,9 @@ public static class ValueOperation
public static Value Not(Operation operation)
{
Value value = operation.Left;
#if LOG
_logger.Method($"{value}");
#endif
Assert.NotVoid(value);
ulong inner = value.Unsigned;
return new Value(inner == 0);

View File

@ -7,5 +7,6 @@
<AllowUnsafeBlocks>true</AllowUnsafeBlocks>
<BaseOutputPath>..\Build\</BaseOutputPath>
<Platforms>AnyCPU;x64</Platforms>
<DefineConstants>DEV;XD</DefineConstants>
</PropertyGroup>
</Project>

View File

@ -26,8 +26,8 @@ public class DefaultDialect : Dialect
Define(ContextClose, "}");
Define(ArrayOpen, "[");
Define(ArrayClose, "]");
Define(ArrayAdd, "<+");
Define(ArrayRemove, "->");
Define(AddItem, "<+");
Define(RemoveItem, "->");
Define(Comma, ",");
Define(Dot, ".");
Define(Colon, ":");
@ -93,8 +93,8 @@ public class ClassicDialect : DefaultDialect
public ClassicDialect()
{
Define(Null, "_");
Define(ArrayAdd, "<+");
Define(ArrayRemove, "->");
Define(AddItem, "<+");
Define(RemoveItem, "->");
Define(Equal, "<~");
Define(This, ".~");
Define(Var, "*~");

View File

@ -323,7 +323,7 @@ public class Reader : IReader<Token>, IDisposable
Check(':') ?
MakeToken(Return, buffer + Next()) :
Check('+') ?
MakeToken(ArrayAdd, buffer + Next()) :
MakeToken(AddItem, buffer + Next()) :
Check('<') ?
MakeToken(BitwiseLeft, buffer + Next()) :
Check('=') ?

View File

@ -24,8 +24,8 @@ public enum TokenType
ArrayClose = Bracket | 6,
ListOpen = Bracket | 7,
ArrayAdd,
ArrayRemove,
AddItem,
RemoveItem,
Comma,
Dot,