Logging and Diagnostics

In this segment, we will discuss logging inside of your gRPC communication. When you are running your applications in production, you will definitely need logging because logging is something that records what application is doing. And you will always be able to diagnose if anything is wrong with your application by looking at its logs. Out-of-the-box ASP.netcore supports logger interface that comes from Microsoft extensions logging namespace. You can also apply a category to your login by passing object type into it.

There are many different logging libraries that are available for ASP.netcore. However, this time, we are using just an out-of-the-box one because all libraries use different implementations. So it will be just impossible to cover them all. Despite this, the basic principles remain the same. Previously, we were passing logger object into our GreeterService However, we weren’t doing anything with it. Now we have added the calls to it to log information.

So this time, every time we are initiating RPC call over gRPC, we are logging the name of the call under the context of this gRPC service. Information is a log level that tells us that is the general information that is being written into the log. The entries of this type indicate that the application is working as expected. However, normally, there are some other levels as well, which we can have a look at by expanding this. The default logger that we are using has four levels, log information, which you have already mentioned, log debug, which you will normally not view in production.

However, if you are running your application in staging environment, or on a development server, this method will generate the entries to see how the application works in detail. Log error will only log the errors. You would use log error if you need to record an error and log warning is something that isn’t quite an error, but the application is doing something that isn’t expected. You will need to warn your users.

These four log categories are present in pretty much any logger implementation. However, some implementations take it one step further. For example, there is also a fatal log level, which records an error that kills the application. And sometimes there is also a trace log level, which on severity scale, falls somewhere between info and debug. By default, the log level is set in your app settings to JSON file. If you change this value to anything else, it will not record any information that is below this category. In our case, because the default level is information, it will not record any debug log entries. For Microsoft category, the log level is set to Warning. This means that in this case, only errors and warning messages will be recorded. Neither information nor debug will be recorded.

Finally, for the category of Microsoft hosting lifetime. It’s, once again on the information level that is recorded. Everything above the information level will be recorded, but nothing below it will. As well as recording our own log messages, we can also set the logger to record the information that gRPC communication itself is output in. By default, it’s also sets to information. Because when you don’t explicitly mention it here, the default will be used. However, we do have an option of explicitly defining gRPC category in here. As well as doing it in here, we can do it in the code.

If we go to our program file of our Grpc service project, we can explicitly apply login level. If we do it in here, it will overwrite any values found in our settings file. And in our case, we are setting gRPC filter to log level debug. What this means is that if we launch our application, you will be seeing additional log entries in it that you haven’t been seeing before. Let’s launch our service ad application to have a look at it.

Once again, we are pressing control + F5 to launch it in a non-debug mode. And this is what happens. The log output is being logged into our console. On the left hand side, you see the log level. Info is in green, warning is in yellow, errors would be in red. However, this time you are also seeing debug entries. In our case, it just supplies some verbose information. If you examine it, it is just mapping methods from our greater service object to the actual gRPC mechanism.

As well as log in our gRPC communication on the server, we can do it on the client. To demonstrate this, we have added a console login to our client. We have done so by adding a NuGet package to it. Once again, I have chosen to use Microsoft’s default logger, which comes from Microsoft.extensions.logging package, and because for demo purposes, we are only interested in console login. The only login provider that I have added comes from Microsoft.extens ions.logging.console package. And here is how you implement it on the client.

Before you create your client, we need to create a logger from a logger factory. Because we have added console logger provider, we are calling AddConsole method and we are setting minimum login level to debug, but just to demonstrate it in action and to log everything into our console. The logger will then go into gRPC channel options object that we are initiating here to create a gRPC channel. And the logger factory that we have created goes into a Logger Factory field of that object.

The rest of the code is the same. So it will work in exactly the same way as before. But this time, we will see far more entries in the console than only those that we have explicitly written into the console ourselves. Let’s demonstrate it in action. We still have our gRPC service running. And now we will setup gRPC client as a startup project. We will go to our user repository to copy the password. And once again, we will be authenticated as Mike London, who is all admin user. So Mike London is the user name while the password comes from the clipboard.

As you can see, we have a lot of log entries. The information is quite verbose because most of these entries are debug. You probably won’t need them in production. But despite this, they might still be useful on a development server. And this is how you use login in gRPC. As well as recording specific log entries, it will be useful if your application also applies tracing and metrics. Tracing and metrics are similar concepts. Essentially, they only record some primitive data, such as durations and counters.

For example, by using metrics, you will be able to record a number of errors. And those errors can then be plotted on the graph. And then when you see a spike on a time series graph, you can then go into your logs and have a look at detailed error messages in the logs. In this case log entries are detailed data, while metrics are lightweight data. There are many metrics and tracing libraries that are available. And all of them implement this in different ways.

However, for demonstration purposes, .Net comes with a tool called dot net counters. And this is what you can enable by installing it. To install the tool, you will need to execute the following command, dot net space tool space install space double dash global, if you want to get it installed globally, followed by the tool name, dot net dash counters. This tool will enable you to output your metrics into the console application. I will not run the script because I already have this tool installed.

We still have our server and the service run-in. So we can paste our password and log in as the admin user. Since we have our tool installed, this is how we can apply it to trace our metrics. To monitor our server application, we use dot net dash counters space monitor. Then we supply process ID parameter followed by gRPC.asp.netcore.server.

To find your process ID, do the following. Open your task manager, click on Details tab, and locate the process that is associated with your gRPC application. So for gRPC service, in our case, the process ID is 1344. And this is what we have answered here. It is now waiting for gRPC calls to be made. To enable metrics on our client, the process is similar. Once again, the process ID is the one that corresponds with the process that is associated with the client.

In our case, it’s 11060. But to let our system know that it’s a gRPC client, we are using gRPC.net.client. And now we can make a couple of calls to see it in action. So once again, we’ve copied our password into the clipboard and will use Mike London as our admin user. If we now look at our console windows with the metrics, we see this information. Metrics for both client and the service have been recorded in here. In a real life situation, you’ll be using a tool such as application insights or data dog, and your metrics will be sent to a specialized server, where you will be able to visualize them and put them in graphs. And this concludes our segment on gRPC metrics.