Logging, Monitoring, and Telemetry in ASP.NET Core 6 with Serilog

[Music] okay gentlemen we have created a new asp.net core web application and this is dot net six the latest version the latest preview please note that we created a web api which uses the minimal api so the new version of setting up the app and we also created a controller a traditional controller as we are used to it let's quickly clean up the project and i ask you to follow along you can remove the demo data weatherforecast.cs just remove it then you can rename the controller maybe you call it i don't know log demo controller log demo controller would be a good name here's it log demo controller and you can delete the entire code inside the log demo controller so at the end of the day you just have an empty log demo controller let me also quickly recap a feature that i personally like very much so what i typically do is i put the namespace statement in the first line add a semicolon and then i can remove the curly braces that removes one level of indentation and i like that better that is the new modal in the newer version of c-sharp but it's essentially yeah up to you whether you want to have this structure or the structure with the indentation let's take a look at how we can add logging monitoring in telemetry out of the box asp.net core adds logging functionality so what you can essentially do if you have a controller for instance you could add an http get here and say this is a public i don't know string call it ping and we just return pong very very simple that will be available at log demo with an http get and it should return pong the built-in functionality for logging in asp.net core is that you create a constructor this constructor gets a dependency injection parameter which is called i logger and you add as a template parameter the log demo controller let's call it logger this one store it and then inside of your method you can simply say logger.log i don't know information for instance inside of ping something like this okay this is dependency injection built into asp.net core applied to the i logger you can then simply run your app then you will get this one and this one give me a sec and then you can say log demo it should say pong and you see here you get logging trivial thing very simple and definitely not enough for our purposes but it is okay if you want to have basic logging in asp.net core simple things should be simple right but complex things should be possible and this is what we are going to add in a minute or so so let's quickly summarize here in the constructor inject the i logger give it the the context which is the name of the controller and then you can use methods like log warning log information log fatal or whatever you want does anybody need more time good next step now asp.net core supports a bunch of interesting scenarios especially things like logging to the console it works pretty well if that is what you want to have for a single single app then it i'm perfectly fine with it go for it it will work properly but what if you want to log to a database or log server maybe prometheus for kubernetes or application insights in azure or anything else that you might use in your i don't know internship at one company now there is a very very popular library and this library we're going to use it's called siri log here you can google it just google for siri lord siri log is very popular and i think one of the most used logging monitoring and telemetry libraries currently in the dot net space the biggest advantage of siri log besides of its great api is this one provided syncs syncs are log targets let's take a look at those syncs for a second see all those syncs here are professional logging targets it might be a log server from amazon it might be a log server for application insights it from from microsoft it might be a database like couchdb you can log to the console you can log to elastic you can send logs by email you can log to files you get for free automatic rollover so a new file is created maybe every hour and the file name is automatically generated and so on and so on you see lots and lots of of things and that's the big advantage of siri log you in your code you use serilock and then you can flexibly add a log target that fits your needs maybe in one app it's sufficient to log to the console the next app would like to log to the database and the next app would like to log to application insights because it's running in azure your code will stay the same only the configuration will change get the idea it's like writing an app for multiple databases sql server oracle mysql and so on you're writing an app for multiple log systems and siri log is the abstraction in the middle understood so let's add siri log to our application and that's surprisingly or luckily easy of course we will add it by adding a nougat package so please right click on the solution choose nougat package and then look for siri log seri log here in the nougat packages we will use a specific serilog version specific for asp.net core but still take a look at the download numbers you see that one 316 million downloads that's really a thing so what we are looking for is serilog for asp.net core see that one serilog asp.net core that's the first one we want to install feel free to take the latest development version i'm fine with that one you can also take the latest stable one but i think hey we are we are living on the edge right so let's add the latest pre-release serilog asp.net core i will zoom in oops sorry let me first yeah serilog asp.net core the second thing that i like to install is serilog timings serilog timings can you remember what i told you about performance analysis with logging why is my web api slow was it the database query or was it the second query or was it my business logic you want to do you want to have a log of all the things that happened in your app and you want to have it at runtime not just at development time by using the debugger on your machine and serial up timings makes it super super simple to log the duration of certain operations like a database query okay so please add serilock timings also to your app take the latest pre-release i'm fine with that and last but not least we need to take a sink we can use a sync like console or file that's built in we don't need to reference them explicitly they are built into the cereal package but we can use different sinks and i would like to demonstrate a sink let me quickly show you that one that is really nice for learning because it's so low-key it's so easy to use it's sec there is a company called data lust and they created a system which is called sec it's part of my github repository but it can also open this this website up directly by typing in the url sec and this is the big advantage can be installed locally and sec is free for personal use so we can install it on all your machines and we can easily use it if we want to use application insights we need an azure account and we need to create an application insights and maybe if we store a little bit more data we have to pay for it it would be very professional but we have to organize a lot of things maybe even money to use it and sec for personal usage for teaching and learning is free and can be installed locally so what i ask you for is first to go to asp.net core back here and look for siri log and sec serilog and sec and here you see you get the sync for sec don't get me wrong i'm not saying that sec is the only or best log server not at all it's a good thing it's a rather small one for small teams or personal use but the principle is exactly the same it doesn't matter whether you use elastic or sac or application insights the general principle is always the same so adding the sec sync was the first thing that we need for our next exercise and then i ask you to download and install sec on your machine okay welcome back after the break i heard that the sec download didn't finish over this cool internet yet no problem let it run the background it's perfectly fine we will get back to that in a second we have enough to deal with before we really get started the first thing is i would like to set up um serilock together with you and um yeah i made this i finished this task for you so what you can do is you can take a look at our courses github repository and there you will find the folder lectures and here api error handling and here you have the server and then you see the program.cs and we will now copy a bunch of lines from this file i will walk you through all the necessary lines let me send you this link through discord so you do not have to look it up on your own and then we are going to copy some things for it for your records i have added lots and lots of documentation to this lectures sample app so you do not need to write everything down you can find all the necessary documentation links directly in the source code commands okay the first thing is we want to make sure that we get logging even for the startup of the web application so the first thing that we will do in program.cs is setting up a logger that is a serilog logger what we do is we say let's give us a logger configuration make sure that we log all information messages because during system startup we want to see everything now this one is not that important i will not go into the details if you want to know more please read the docs use the console logger because during startup we don't have anything else we haven't even read the configuration file yet so how should we get a database connection string for instance this is the very very early stage of booting up the application so we need to log to the console if something crashes on that in that phase and last we create the bootstrap loader which is logger which is the logger for the bootstrapping process so please copy these few lines and put them in your program.cs at the very beginning you will have to add some usings siri log and i think here you need serilog events and i think then we are good good that will give us a serie log bootstrap logger [Applause] next i would like to enclose everything in a try catch block i assume that you know what a try catch block is so please do that let's clean up a little bit something like this let's catch the exception and let's do it finally once we are done with everything now you can take a look at my github repository what we should do in the catch case and in the finally case in the catch case we are going to log the exception this is really critical a fatal error because that means that our app couldn't start properly so this is what we want to copy for the exception case making sure that we see fatal exceptions and last but not least finally this one log and close uh cl log close and flush means write everything to the log and at the end we can say return zero by convention console apps should return zero in case of everything went well and a non-zero return value indicates an error that's just best practice it's a little bit more complicated if you take a look at the details but it's fine okay this is the first step and if you want to give it a try you can run it nothing special will happen the app will come up we can take a look at the app output and nothing really happened yet it should still start everything is good but let's try the siri log logger so inside of the try statement just to know just to note that we are here we are going to say log.information and here we say starting the web host okay something like this give me a sec and if you run it now again let's take a look at the output oops i was too fast here what happened where am i so now i'm here see this output is from siri log the rest of the output here is from the traditional core console logging so we have now succeeded in building a siri log logger for the booting process but we have not succeeded in changing the asp.net core console logging towards sirilog that will be our next step you had a question a question next we want to set up the final logger and just like with databases we do not want to hard code things like write to console or write to application insights or write to sec directly in our code what we want to do is we want to do exactly the same that we do with databases we want to write the connection information the configuration information in the app settings json file this is where i want to easily switch from console to file from file to sec from sec to application insights i don't want to change my application code at all everything should be configured through the app settings json file and this is exactly what we are going to do so you do not need to look up the details of uh of siri log and app settings json because i did it for you so please go one level up and open the app settings json file in the app settings json file i edit again the documentation links but you find the default configuration of siri log immediately in that file so you see that one the whole siri log session section this is what you need so please copy this section and you can also replace the default logging section that is inside of your app settings json because we are going to use sirilog instead of asp.net core let's quickly take a look at what we find inside of this file the first line this using line here this one tells serilog where we want to write our logs to and the good news is we don't have to choose we can send our logs to multiple locations we can write it in a file for later analysis we can print it on the screen for console and we can send it to sec if we want so you can have multiple syncs at the same time i guess uh sec the sec download has not finished yet has it yes it has then please take a second to install sec at the end once you have installed sec you can run the sec service administration and just press next next next next next you don't need to configure anything and if you succeeded you should be able to launch this program browse sec and that should give you this ui so let's take a few minutes and make sure that sec runs on all your machines so one thing is still missing now we have everything in the app settings json by the way if you take a look down here you can add additional information additional configuration information for the console logger for the file logger it will log into a folder called logs for the sec that should be the default port and so on and so on if you want to know the details about how to configure all this stuff please take a look at the documentation link and read the necessary details there for us we need to change or add an additional setting in program.cs because now we have to tell asp.net core that it should use siri log and it should read the settings from app settings json and this is done with another statement in our program.cs so go into the program.cs and the thing that we need in order to make sirilog read our config file is this line here it says builder.host.userlog and we are going to tell the system that it should read the configuration data from our configuration context which is appsettings.json the rest is detailed information that we don't need to care about it just works copy this one and put it after the create builder state step this one and this will make sure as i said that sirilog reads our app settings json this one so we had a bootstrapper logger now we made serilog read the app settings json file and the last step that we need is do we have to exchange asp.net logging with sirilog logging so please take this one and put it after the app builder blur once you had that you can run it again your app and if you didn't make a mistake the output should approximately look like that can you see that one that indicates already that it looks like serilog output so if you manage to do that we are good i will show you that i copied two things first this one for reading the configuration and this one this is for logging the requests so again this here is for reading app settings and additionally it enables sierra log and the second one to be more specific now this is the middleware for logging every request i should see this output and now comes the important thing if i go to sec here and if i press reload i immediately without doing anything should see all the details nice and then i can click on one and i see all the details i see the host i see the path i see the method i see the request id and i see a lot of other information so i already see what's going on that's nice isn't it for instance if i want to have all the http get requests i can simply go up there and say please filter based on the method you see you get nice intellisense let me zoom up a little bit so you see better method equals to get and if you press enter you see all the get requests can we move this one and you will again get everything later on we can easily use these toggles here on the right hand side we can say show me all errors currently there are no errors show me all warnings currently there are no warnings i think you get the idea right we can do some statistics with some queries see if we run sec for a longer amount of time we will get a nice statistics at what clock hour we have how many requests we can analyze whether users are using our app during the night or not so now we have replaced serilog and now you see a lot of the things in practice which i told you previously in theory also if you take a look in your solution explorer you should now have a folder which says logs and inside of the folder logs you have a log txt and you can easily take a look at the generated logs down there so exactly what we discussed before it's not enough to just log on the console we want to log to a file to store it for later analysis maybe we want to use that for machine learning purposes to detect certain malicious attackers and we can also store it to a professional log server like sec to have a nice query language to build dashboards to do log analysis to do real-time monitoring of our servers in real world sec would not run on your local computer but you would have a dedicated computer running sec and all your servers will send their logs towards the sec server and then you can use the ui that you saw here to analyze the logs and the behaviors of all your servers in your data center again sec is a small to medium solution if you want to use that for tens of thousands of servers or if you are in the google cloud or amazon cloud or azure cloud they have their own logging servers which work even better and which offer even more functionalities like than than sec absolutely you can sp you can configure the log file name you can configure how often a new log file is created you can configure the retention period so you can decide that certain old logs are automatically deleted everything just take a look at the code that i gave you it contains a link you see to the provided syncs if you follow this link just look up the file sync here and if you scroll down you will see all the different settings for instance here rolling interval see that one you see you can define the output template and a lot of other things that you can configure here yep so it's really powerful now let's write a little bit of code uh we will not write it we will just copy it because the code is so simple it doesn't pay off to write it manually we will simply copy it from my prepared parts and yeah with that we can progress a little faster first let's stay inside of program.cs i ask you to go into my preparedprogram.cs and copy the first two mapget methods these mapget methods just to refresh your memories this is the asp.net core minimal api that we talked about at the beginning of this semester so you see this is very simple it just answers for pop ping and this here answers for request context but then inside of the second one we have something interesting we get something which is called the eye diagnostic context and then we set something on the diagnostic context we set a user id of course this is a dummy value please imagine that you have a real username here somebody logged in somebody sent you a token and you take the username from the token and let's see what that has to do with login copy these two map gets and put them somewhere here between the map controllers and the apperon somewhere here the eye diagnostic context is a part of siri log this is something that siri log gives you it's easier to try it than to theoretically talk about it so run your app once it runs you can maybe put the app on one side and put serilog on the other side sirilock has the possibility that you can click here and say display everything starting with now because then you have an empty area and here you can say tail that will automatically refresh your view when something happens so you can go on the right hand side and simply run for instance ping that will return pong and see on the left hand side you immediately see what's going on now let's take this request context thing you can also take a look at my screen because it's it works exactly the same on your machine if i call this request context and if i take a look in siri log again i will see the request of the here request context here it is and we see the http request and yeah that's the point please take a look here and the important thing is this one and the important thing is this one so what you can essentially do is you can add additional diagnostics metadata to your api requests because during log analysis you sometimes are not interested in technical details just like the http status code but you simply want to see everything that a certain user did imagine that a user calls you they use a friends in france tells you something is wrong and you want to quickly see what franz did in the last 30 minutes then you need to understand what requests came from france so you have to store his user id somehow because otherwise you don't see it from the log and that's the point here it's possible very easily possible with serilog to add additional diagnostics informations to your requests and then you can filter with it so i can go here and i can simply say user id equals someone something like this and that will give me immediately all the requests that came from someone and in my sample this would be france and of course i don't have a friend so yeah i don't get anything but i can i think you get the point right so remember that with the eye diagnostic context you can add additional information that you might need to analyze your logs properly the next example that i would like to show you is in the log demo controller please open the log demo controller and here we also already saw that we are using asp.net core logging with the i logger so let's check whether this ilogger nicely integrates into siri log run your app go for log demo slash ping how did i call it blog demo oh yes sorry i didn't call it ping i'm sorry yep pong so if i take a look here in sac you will see that i now also have the log messages which i wrote with i logger from asp.net core so if you use if you have an application that is already using asp.net core logging and you add serilog your logs are not lost they are just redirected to serilog and whatever syncs you have configured they are automatically inside of this one a very important feature of asp.net core is the request id please take a look at my screen see that one every http request that comes into your system gets a unique id and you can correlate all the log files all the log messages that have been written in the context of this http request with this id so what i can do is i can copy this request id give me a second and i can say request id equals to this one and if i run it you see i see all the things which went which happened during this one request i see that it was for log demo i see the asp.net core logging i see a lot of automatically added logs and i see also the the response message here and i see that it took in total here 187 milliseconds so with the request id i can find everything let me make one final demo and then i'll take questions okay please add something to your app throw new invalid operation exception something bad happened okay just throw an exception then you can remove the return statement please use your imagination that would be an error when accessing the database that would be some division by zero because you screwed up when writing the application code whatever reason there is an exception so let's try this one restart your app or press hot reload i don't care both work and then we call it again so here log demo boom crash i don't care let's continue okay we get an unhandled exception now let's take a look at sec what we now have see that one we have errors first we have the http request which is marked as an error because we were returning the http status code 500 which is an internal server error but even more important we can click here on that one and we will see first the unhandled exception we will see the request id so we can try to find out what was the reason for the problem and then we see the entire sect trace you see it here and with that stack trace i should be able to detect what's what was going on you said at the beginning at the blackboard session you said server crashed i need to find out why this is exactly the information that should lead you on the track of the problem and now we can also use the filtering you see click on errors and you will see all the errors so it's pretty simple to keep track of all your problems just put a large computer monitor inside of your office at the wall press on tail and then just every now and then take a look at your monitor if you have new eras the next example that i would like to do together with you is a timing example i would like to show you how we can record some timings okay let's do that no sorry i forgot something i'm very sorry not the timing we need to do something more basic first please add another http get this one public i don't know string huh what are we going to do create customer right and the route should be customers and maybe add some strange id and that's good id id something like this and then we want to log something please write the following logger dot log information oops sorry log information something like this and then we use creating customer id id a very strange format isn't it aren't we used to do string interpolation something like dollar blah and then something like id this is what we usually do in c sharp right this is the template string marker but i don't do that here and i ask you to follow along okay and we just return something that's all nothing special it is important that i use the placeholder with the name of the parameter here let me show you why let's run the log demo customers 42 43 okay if i go to sec again not just the errors what you will get with the log message here is the log message i don't know if you see that on the video beamer do you see that the 43 has a slightly different color no but it does the point is that i now get the id as a separate field in my database so it's not just a string anymore yes it is a string because it says creating customer 43 but it is also structured logging because i can now filter on the id 43 get the idea i don't need to do a string search where the log message contains 43 no i can really add a structural filter just like with the sql statement i can do a where clause so what i can do is i can say id equals to 43 and i will get exactly that log and that is super super powerful and it's important to do structured logging it's not enough to just write something on the console can you remember what i did what i told you at the beginning at this blackboard session i told you that it's not enough to write strings on the console because they you cannot analyze them properly now you can and now we can go to timing now we can easily combine the timing uh here with the with the sample of the structured logging that that's fine let's combine the timing here imagine that we are going to do a database query here in this create customer maybe an insert operation for that we do the following we say using operation dot time operation dot time we need serilog timings and here we can give this thing a name do some db query and here we can say thread dot sleep for 500 milliseconds just to simulate a database query of course in reality we would use async await and we would use entity framework and we would say a weight save changes async and all the stuff you know this you know the drill now here i'm just simulating something that takes 500 milliseconds and the important thing is this operation.time with the using block so what it will automatically do it will automatically create a stopwatch and stop the timing here and log the timing to the log so if you rerun the app here operation.time everything is part of our lectures github repository so if you can't follow just take a look at the github repo and if i say log demo customers43 it will take a second and if i take a look at sec it will tell me if i remove here we are it will tell me that here that it took 509.1 milliseconds to execute the database query i can click on the details and you will see the exact elapsed time and again try to follow i i know that you might not see the value now but imagine that you are a devops person and you are not just responsible for writing correct code but you have to run this app this is super critical imagine you have hundreds of thousands of these requests in your database and you want to have a statistical analysis how long does this database query take and maybe it took 500 milliseconds but suddenly it takes three seconds and you have a problem and now you know why because then you know exactly what the problem is that's what i mean with having a built-in x-ray machine rent into your app because you can take a look in the app while it's running wasn't super complicated was it program.cs three four lines little bit of app settings json and we are good so let me think about what else we have no the siri lock part is pretty done let me check my notes yes the sirilog part is pretty done so we will change the topic a little bit we still are in the era of error handling and logging but we are going to take a look at the slightly different angle of logging monitoring and telemetry

Channel: Rainer Stropek

Views: 1,183

Keywords: C#, ASP.NET Core, .NET 6, ASP.NET Core 6, Logging, Monitoring, Telemetry, Serilog, Seq, DevOps, HTL Leonding

Id: hJ0QHRV3RPQ

Length: 44min 22sec (2662 seconds)

Published: Sun Nov 14 2021