Logging example, step 3: Adding parameters values
Up until now, our logging aspect writes messages that include constant text and compile-time expressions. Let's now introduce the values of parameters and the method return value, which are known at run time.
It's important to include parameter values in traces because they offer valuable context to help developers comprehend the application's state during execution. With this contextual information, you can diagnose and debug problems more easily, decreasing the time spent recreating issues and tracing through code paths, resulting in a more stable and reliable application.
The code with the transformation from the new aspect can be seen below:
1internal static class Calculator
2{
3 [Log]
4 public static double Add( double a, double b ) => a + b;
5
6 [Log]
7 public static double Divide( double a, double b ) => a / b;
8
9 [Log]
10 public static void IntegerDivide( int a, int b, out int quotient, out int remainder )
11 {
12 quotient = a / b;
13 remainder = a % b;
14 }
15}
1using System;
2
3internal static class Calculator
4{
5 [Log]
6 public static double Add( double a, double b ) { Console.WriteLine($"Calculator.Add(a = {{{a}}}, b = {{{b}}}) started.");
7 try
8 {
9 double result;
10 result = a + b;Console.WriteLine($"Calculator.Add(a = {{{a}}}, b = {{{b}}}) returned {result}.");
11 return (double)result;
12 }
13 catch (Exception e)
14 {
15 Console.WriteLine($"Calculator.Add(a = {{{a}}}, b = {{{b}}}) failed: {e.Message}");
16 throw;
17 }
18 }
19
20 [Log]
21 public static double Divide( double a, double b ) { Console.WriteLine($"Calculator.Divide(a = {{{a}}}, b = {{{b}}}) started.");
22 try
23 {
24 double result;
25 result = a / b;Console.WriteLine($"Calculator.Divide(a = {{{a}}}, b = {{{b}}}) returned {result}.");
26 return (double)result;
27 }
28 catch (Exception e)
29 {
30 Console.WriteLine($"Calculator.Divide(a = {{{a}}}, b = {{{b}}}) failed: {e.Message}");
31 throw;
32 }
33 }
34
35 [Log]
36 public static void IntegerDivide( int a, int b, out int quotient, out int remainder )
37 {
38Console.WriteLine($"Calculator.IntegerDivide(a = {{{a}}}, b = {{{b}}}, quotient = <out> , remainder = <out> ) started.");
39 try
40 {
41 quotient = a / b;
42 remainder = a % b;
43object result = null;
44 Console.WriteLine($"Calculator.IntegerDivide(a = {{{a}}}, b = {{{b}}}, quotient = {{{quotient}}}, remainder = {{{remainder}}}) succeeded.");
45 return;
46 }
47 catch (Exception e)
48 {
49 Console.WriteLine($"Calculator.IntegerDivide(a = {{{a}}}, b = {{{b}}}, quotient = <out> , remainder = <out> ) failed: {e.Message}");
50 throw;
51 }
52 }
53}
Warning
Adding sensitive information such as user credentials, personal data, etc., to logs can pose a security risk. Exercise caution when adding parameter values to logs and avoid exposing sensitive data. To remove sensitive information from the logs, see Logging example, step 7: Removing sensitive data
Implementation
The aspect is as follows:
1using Metalama.Framework.Aspects;
2using Metalama.Framework.Code;
3using Metalama.Framework.Code.SyntaxBuilders;
4
5public class LogAttribute : OverrideMethodAspect
6{
7 public override dynamic? OverrideMethod()
8 {
9 // Write entry message.
10 var entryMessage = BuildInterpolatedString( false );
11 entryMessage.AddText( " started." );
12 Console.WriteLine( entryMessage.ToValue() );
13
14 try
15 {
16 // Invoke the method and store the result in a variable.
17 var result = meta.Proceed();
18
19 // Display the success message. The message is different when the method is void.
20 var successMessage = BuildInterpolatedString( true );
21
22 if ( meta.Target.Method.ReturnType.Is( typeof(void) ) )
23 {
24 // When the method is void, display a constant text.
25 successMessage.AddText( " succeeded." );
26 }
27 else
28 {
29 // When the method has a return value, add it to the message.
30 successMessage.AddText( " returned " );
31 successMessage.AddExpression( result );
32 successMessage.AddText( "." );
33 }
34
35 Console.WriteLine( successMessage.ToValue() );
36
37 return result;
38 }
39 catch ( Exception e )
40 {
41 // Display the failure message.
42 var failureMessage = BuildInterpolatedString( false );
43 failureMessage.AddText( " failed: " );
44 failureMessage.AddExpression( e.Message );
45 Console.WriteLine( failureMessage.ToValue() );
46
47 throw;
48 }
49 }
50
51 // Builds an InterpolatedStringBuilder with the beginning of the message.
52 private static InterpolatedStringBuilder BuildInterpolatedString( bool includeOutParameters )
53 {
54 var stringBuilder = new InterpolatedStringBuilder();
55
56 // Include the type and method name.
57 stringBuilder.AddText( meta.Target.Type.ToDisplayString( CodeDisplayFormat.MinimallyQualified ) );
58 stringBuilder.AddText( "." );
59 stringBuilder.AddText( meta.Target.Method.Name );
60 stringBuilder.AddText( "(" );
61 var i = meta.CompileTime( 0 );
62
63 // Include a placeholder for each parameter.
64 foreach ( var p in meta.Target.Parameters )
65 {
66 var comma = i > 0 ? ", " : "";
67
68 if ( p.RefKind == RefKind.Out && !includeOutParameters )
69 {
70 // When the parameter is 'out', we cannot read the value.
71 stringBuilder.AddText( $"{comma}{p.Name} = <out> " );
72 }
73 else
74 {
75 // Otherwise, add the parameter value.
76 stringBuilder.AddText( $"{comma}{p.Name} = {{" );
77 stringBuilder.AddExpression( p.Value );
78 stringBuilder.AddText( "}" );
79 }
80
81 i++;
82 }
83
84 stringBuilder.AddText( ")" );
85
86 return stringBuilder;
87 }
88}
As you can see, the aspect's code is much more complex.
The most straightforward approach to generate an interpolated string from an aspect is to use the InterpolatedStringBuilder class and to add literal parts, known at compile time and constant at run time, and run-time expressions, unknown at compile time.
The BuildInterpolatedString method of the aspect class is responsible for constructing the InterpolatedStringBuilder. Please note that BuildInterpolatedString is not a template method. It is a method that executes entirely at compile time. It has an includeOutParameters parameter that determines if the values of the out parameters are available when the interpolated string is in use.
Firstly,
BuildInterpolatedStringappends the name of the current type and method using the AddText method. Then, it iterates through the collection of parameters of the current method. This collection is available on the expressionmeta.Target.Parameters.In the
foreachloop,BuildInterpolatedStringmethod checks if the parameter isout. IfincludeOutParametersparameter isfalse, the method appends a constant text. However, if the parameter can be read, the method adds an expression using the AddExpression method.
Below is the OverrideMethod method. As with previous examples, this method is a template containing both run-time and compile-time code.
Firstly,
OverrideMethodcallsBuildInterpolatedStringto get the InterpolatedStringBuilder. Note that the interpolated string created byBuildInterpolatedStringonly includes the name and parameters of the method. We still want to append more information to the strings, such as the textstarted,succeeded,returnedorfailed.Then, we write the entry message. The aspect calls the ToValue method to get the interpolated string from the InterpolatedStringBuilder and passes it to
Console.WriteLine. Note that the ToValue method does not really return an interpolated string but returns a run-time object ofdynamictype that, when used in a run-time context, expands into the interpolated string.Finally, we write the success message. We want to write a different message when the method is
voidthan when it returns a value. We implement this choice with theifin the method. As theifconditionmeta.Target.Method.ReturnType.Is(typeof(void))is a compile-time expression, Metalama interprets the entireifat compile time. Notice the specific background color of the compile-time.