Thread overview
My tiny but useful trace debugging code... Any suggestions from more experienced D users?
June 26

A while back (perhaps my first D forum post) I asked about implementing an equivalent of other languages' very useful debug printing macros such as Julia's @show or Nim's dump or Rust's dbg!. Someone on the forum here very helpfully showed me how to do it via D's mixin feature. I have since then refined my own tiny module for doing so, with a few more features. Here is the code for it, in my trace.d module:

public import std.conv;

/// `trace_prefix` provides the common `module_name.function_name-line_number:\t` prefix that is added to each of the tracing functions in this module. The other functions are likely to be more useful, unless a new function is being created that reuses the same trace prefix format.
string trace_prefix(const bool should_mark = false) {
	return `__FUNCTION__ ~ "-" ~ to!string(__LINE__) ~ ` ~ (should_mark ? `"*"` : `""`) ~ `~ ": \t"`;
}

/// `trace_message` outputs any arbitrary string you pass it, but prefixed by an indicator of what module, function, and line number the trace_message is located on, thus aiding print-based debugging.
string trace_message(string message) {
	return `writeln(` ~ trace_prefix() ~ ` ~ q"<` ~ message ~ `>");`;
}

/// `show` eases print debugging by printing both an expression as a string and its corresponding evaluated value. It is intended to be used via `mixin`, such as in `mixin(show("1 + 2")`, which will print something like `module.function-line: 1 + 2 == 3`. The `module.function-line:` prefix helps distinguish debug printing from normal output and also helps to track where output is coming from.
///
/// Printing both an expression's code and the expression's value makes print debugging easier to keep track of accurately (especially when multiple print statements are used, which would otherwise be more easily confused with each other) and less redundant (since `show` being a macro prevents the user from needing to write the expression twice).
///
/// However, assertions (via `assert`) and unit tests (via `unittest`) are often a better way to debug and maintain code than any form of print debugging, because (1) assertions are enforced automatically instead of requiring manual inspection and (2) reading through print statements consumes a lot of time in aggregate whereas assertions are instantaneous and hence much more expedient when well applicable. Nonetheless, print debugging is still very useful and intuitive, especially when you don't know what a value is at all.
string show(string expr) {
  return `writefln(` ~ trace_prefix() ~ `~ "%s == %s", q"<` ~ expr ~ `>", ` ~ expr ~ `);`;
}

/// `trace_scope` returns a mixin string that if mixed in at the beginning of a scope inserts code that logs when the current scope starts and ends, which may be useful for debugging potentially, since it informs of when you are actually inside that scope or not, which may or may not be when you think. Use it by writing `mixin(trace_scope);`, placing it at the top of the scope you intend to trace.
string trace_scope(string scope_name) {
	return
		`writeln(` ~ trace_prefix() ~ ` ~ q"<` ~ scope_name ~ `>" ~ " entered");` ~
		`scope(exit) writeln(` ~ trace_prefix(true) ~ ` ~ q"<` ~ scope_name ~ `>" ~ " exited");`;
}

show is for examining the values of things in a clean and organized way (the most common use case).

trace_message is for any arbitrary string message tagged with the module, function, and line.

trace_scope is for easier printing of when any specific scope starts and ends.

All are useful.

You use them by writing mixin(trace_function_name(...)) and such, since they all return strings and you have to use mixin to apply arbitrary macros in D. For example, try mixin(show(1 + 2)) or mixin(trace_scope(__FUNCTION__)) or similar.

(Unimportantly, you can see that I'm using snake_case, though I've debated on and off using D's camelCase but I've always liked snake_case and PascalCase and other conventions more than camelCase in languages.)

Anyway, I really like how useful this is and basically this kind of print debugging feature should be built in to all modern languages in my opinion (and indeed is in all of the most popular ones in some form and for good reason).

It works fine, but I was wondering what suggestions the D community may have regarding both (1) whether or not better pre-built functionality for this exists in the D standard library and community libraries already and (2) how the above code could be improved to be more readable. I tried to use string format but it didn't even work right when I tried it.

How would you refactor it if you were trying to make it more polished and readable?

D's string-based mixins that support arbitrary string code are useful, but as you can see keeping the quotations delimiters and concatenation operations straight above is not very easy and it took a long time to get these tracing functions working relative to their conceptual simplicity because strings were so subtle and easy to confuse oneself with the quote delimiters.

I also figured that other beginners could benefit from the above.

Such tracing functions provide a far better way of print debugging than just raw print statements, although assertions and unit tests are better in ideal cases because they don't require manual examination, but print debugging is useful for when you don't know what the state of something actually is at all of course.

What are your thoughts, if any?

(PS: Thanks for reading.)

June 27

Oh, and here's another minor update. I've added another public import line to the module to ensure it actually works correctly when imported:

public import std.stdio;

Previously I had carelessly omitted this because I was using trace.d only in contexts where std.stdio had already been imported, but clearly that would need remedied in the general use case.

The public imports make the imports visible in the module of any module that imports trace.d, whereas otherwise such necessary dependencies for use wouldn't be visible.

Text based D macros (string mixins) can't know their dependencies, I'd imagine, hence the reason for adding the two imports (of std.stdio and std.conv).

June 30

I've made another update to my trace.d module.

The changes are:

  • switched to camelCase from snake_case to match most of the D ecosystem
  • added traceFunc for the common case of using traceScope on a function's scope
  • changed some of the functions to use format in their implementations
  • narrowed the public import statements to not muddle the user's namespace as much
  • changed doc comments to multi-line comments and split the text into multiple lines instead of relying on long lines being wrapped in the user's text editor
  • added in qualifiers to all input for slight "const correctness" clarity improvement

There's some subjectivity and slight pros and cons to these changes of course.

Anyway, here is the new code for trace.d:


public import std.stdio: writeln, writefln;
public import std.conv: to;

import std.format;

/**
`tracePrefix` provides the `moduleName.functionName-lineNumber:\t`
prefix that is added to each of the tracing functions in this module.

The other functions in this module are likely to be more useful, unless
you want to reuse this tracing prefix to create a new tracing function.

The `shouldMark` parameter is for preventing confusion in `traceScope`.
**/
string tracePrefix(in bool shouldMark = false) {
	return format(
		`__FUNCTION__ ~ "-" ~ to!string(__LINE__) ~ %s ~ ": \t"`,
		(shouldMark ? `"*"` : `""`)
	);
}

/**
`mixin(traceMessage(message))` outputs whatever arbitrary string you
pass to it, but prefixed by what module, function, and line number the
`traceMessage` call is located on, thus aiding print-based debugging.
**/
string traceMessage(in string message) {
	return format(
		`writeln(%s ~ q"<%s>");`,
		tracePrefix(), message
	);
}

/**
`traceScope` returns a mixin string that if mixed in at the beginning
of a scope inserts code that logs when the current scope starts and
ends, which may be useful for debugging potentially, since it informs
of when you are actually inside that scope or not, which may or may not
be when you think. Use it by writing `mixin(traceScope);`, placing it
at the top of the scope you intend to trace.
**/
string traceScope(in string scopeName) {
	return format(
		`writeln(%s ~ q"<%s>" ~ " entered");` ~
		`scope(exit) writeln(%s ~ q"<%s>" ~ " exited");`,
		tracePrefix(), scopeName,
		tracePrefix(true), scopeName
	);
}

/**
`traceFunc` is shorthand for `traceScope(__FUNCTION__)`, since that
is one of the most common use cases for `traceScope`. The user must
remember to only use `traceFunc` at the top of a function's scope
though, because otherwise if `traceFunc` is placed inside some other
scope within that function then the output will be misleading.
**/
string traceFunc(in string scopeName = __FUNCTION__) {
	return traceScope(scopeName);
}

/**
`show` eases print debugging by printing both an expression as a string
and its corresponding evaluated value. It is intended to be used via
`mixin`, such as in `mixin(show("1 + 2")`, which will print something
like `module.function-line: 1 + 2 == 3`. The `module.function-line:`
prefix helps distinguish debug printing from normal output and also
helps to track where output is coming from.

Printing both an expression's code and the expression's value makes
print debugging easier to keep track of accurately (especially when
multiple print statements are used, which would otherwise be more
easily confused with each other) and less redundant (since `show` being
a macro prevents the user from needing to write the expression twice).

However, assertions (via `assert`) and unit tests (via `unittest`) are
often a better way to debug and maintain code than any form of print
debugging, because (1) assertions are enforced automatically instead of
requiring manual inspection and (2) reading through print statements
consumes a lot of time in aggregate whereas assertions are
instantaneous and hence much more expedient when well applicable.
Nonetheless, print debugging is still very useful and intuitive,
especially when you don't know what a value is at all.
**/
string show(in string expr) {
  return `writefln(` ~ tracePrefix() ~ `~ "%s == %s", q"<` ~ expr ~ `>", ` ~ expr ~ `);`;
}

/*
`debug(logName)` can be prefixed to traces that you only want to show
sometimes, but hardcoding that into this module would probably be a bad
idea. It seems better to leave it to the user's discretion to decide
whether they want each trace function output to show up in regular
output or only in a debug logging mode, though debugging is the intent.
*/

Here's a premade main.d file for testing it, for your convenience:

import std.stdio;

import trace;

void main() {
  mixin(traceFunc);

  mixin(show("1 + 2"));

  immutable int x = 1;
  mixin(show("x"));

  mixin(traceMessage("This is a generic trace message..."));

  writeln("This is a normal (non-trace) print statement just before the end of `main`.");
}

Do you guys think the use of format improves the readability of the code or makes it worse? I'm not entirely sure. I am also still using ~ concatenation for the show case because that one was giving me trouble still for trying to make it more readable.

Also, I hear D has string interpolation but with an odd implementation that makes me wary of using it and I wonder if I should try to use those kinds of strings here or not.

I have also located some related discussions that you may find of value or interest:

Are there preexisting community libraries for this that aren't a mess of dependencies?

It still strikes me as odd that this isn't in the standard library since it is one of the most universally useful things that can exist in any programming language. It's ironic that only a handful of languages support it.

This also strikes me as being proof of the value of macros and indeed I suspect that languages without strong metaprogramming are likely an evolutionary dead end in the long term given how the show macro and tracing functions like these are so clearly universally useful and pragmatically essential for expedient coding.

On the other hand though, all languages have subtle pros and cons like this and features that are or aren't in the standard facilities, etc. D has several such features missing from almost all others, such as its slice operations and nuanced template distinctions.

Relatedly, one thing that I previously felt more negative about but have realized has more upside than I previously thought is D's requirement to use mixin whenever text macros are used. Doing so makes it easier to find locations in a code base that are being expanded by macro magic to do more than meets the eye, which can make navigating and understanding code easier. It makes it so that the most "magic" parts of the code are marked as such. I've not encountered any other language that does that as well.

D is a very practical language overall and I really appreciate the careful thought and dedicated effort that has gone into it. It's nice to have a language that feels like more sane C++ and D does the best job overall of that. It really should be more widely used.