"Stop Using Structured Logging in .NET!" | Code Cop #006

hello everybody I'm Nick and welcome to the third episode of content cup the series where we take a look at bad advice usually from LinkedIn Twitter or blog posts and we try to basically turn them into good advice there's tons of bad advice out there and Linkedin specifically will promote anything and in this video specifically what I want to do is take one of those really really bad and harmful pieces of advice that can really harm the performance of your application and try to explain why it is so bad and you should not follow it under any circumstances always this is not a dig to the Creator themselves in fact everything is anonymized this is just about criticizing the advice itself and trying to turn this into good advice if you like our content and you want to see more make sure you subscribe more training check out my courses on D train.com okay so what is this advice I'm talking about well this is the photo that was posted without really any meaningful context and the idea is that hey if you're not actually going to use a parameter in your structured logs then maybe don't have it in the template now the reasoning for this is to not add overhead specifically so it's about performance now trust me when I say this advice the one that says you should not actually use a template but instead use string interpolation or cination to just use it as a plain Tex string it's going to very noticeably harm your application in terms of performance and overhead the good advice is the exact opposite of what the advice is trying to get you to do and I will explain why let's go to the ID now I've brought in the exact same example as it was on that photo and I want to very quickly explain what structure logging is so when you have a log information log log warning or anything this thing over here this is not the message but this is the message template if you want to pass parameters to that template then you can do that by using a comma separated list of parameters after that and if you do that what's going to happen is those parameters will be captured and then they can be dealt with in different ways for example if you use a Json provider for your logs they can be handled as individual parameters in Json so you can do some filtering later and if you're using something like application insights or data dog those will be passed as individual fields in data dog or whatever else you use as your login provider now I'm someone who has really really dived into login.net and basically Master the topic and know exactly how it works behind the scenes and in fact I have a 1 hour long talk on the subject which you can check later I'm going to put a link in description down below it's from NDC conferences where I run talks and work shs but I also have a f length course on login on dome train so everything I'm going to explain in this video come from hands-on experience now let me get one thing out of the way as you can see in the example over here the Creator is using the wear link method to filter the items based on the category the problem with this is that if you do a DOT count to get the count of the items and then return them you open yourself up to multiple enumeration and that's exactly what Ryder is actually telling me here it telling me that whatever is in here will be enumerated multiple times now in this case it won't really be that bad but we're goingon to waste memory which we probably don't need to waste you can easily fix that by forcing some enumeration either to a list or some other type that you might want to return as well so I'm going to use that in both examples because these quiggly lines really bothered me and now that we actually changed this to list we can remove the method over here because we can just get the count from the already numerated list now let's take a look at the two examples the point the Creator is trying to make is that using structure loging presumably because it will store that parameter will actually have some overhead we're going to have to name this parameter and we also going to have to store the count in this case that is an integer so not a big value but a value nonetheless the alternative is to not store it at all so not give it a name not treat it as a special thing and just inline it over here so what is going to happen in here is that my string template when it's computed let's say I want to have one item is something like like this but here's the interesting thing if this has an amount of different parameters because each category can have different numbers of items within it then I'm going to have n different types of strings for this concatenated string and these are unique strings that are not interned so they are allocated every single time this method is called you can have an amount of combinations here and what's going to happen is you're going to have this and this over here as compile time literals so they only going to be allocated once at compile time but the combination of the two strings and the parameter over here will generate one unique string every time you call it and even if something comes in and it has the exact same item count you're still going to allocate a new string even if it already exists in memory because this string will not actually be interned all together it will be allocated every single time the benefit of using structure login over here and treating this as a template is that this string will only be allocated once you won't have any amount of combination of these parameters that could potentially change how many times this is allocated and since this is a compiled time literal it will be interned and every time we come in here we're going to point at the same location in memory now I do want to point something out it is up to the provider itself which is basically where the log will end up into to take these parameters and try to be efficient with them some of them will actually replace these parameters at run time before before they send them to the provider some of them will not do that though and they will do the computation on the provider saving you that memory even if you think at this point right now that you're not going to use one parameter at some point for your logs you should still use structure logging if it's that unimportant that you think you won't filter by it don't add it in the log let's just say found items of the category and move on with your life I don't understand the point where you don't want to actually make use of it because you might not want to make use of it now but when the time comes in the future and you are asked by business to hey we want to see how many this per category we have in the logs then you're going to have to go back and try to I don't know write some rejects to make sense of all this and it's going to be way way worse also if you want to be even more efficient with your logs especially using the buildin logger I highly recommend you use the source generated logger and in case you don't know what that is net allows you to use the logger message attribute on a partial method to turn it into effectively a logging method and by doing that you're allowing the source generator to write the most optimized code it can for the type of thing you want to log so you won't have any boxing which will actually happen here because as we can see in this log information method the parameters are passed as a params object array which will cause boxing and it will cause extra locations but if you are to use the S generated logger you won't have that issue because generic will be used behind the scenes plus you're going to have a tailor made method for that log and that will even remove the minimal overhead you might have by using the built-in log information and passing these parameters down with structure logging there is no no no scenario where if you want to pass down a parameter in your message template you want it to be a raw string especially if it changes the template if it was a constant that never changed then sure but if it was a constant why would you not have it as part of the template this advice is very harmful it will cause many memory allocations around strings and strings are very expensive in fact if you take a look at how much doet has been optimized a lot of that is due to span which allows you to do some fancy allocations around strings which basically prevents them and optimizes them so please do use structure logging even if you don't take my course to see how you can do this efficiently and effectively or you don't watch my talk just know that this is a message template even though Microsoft tells you it's the message no it is not as you can see over here on my ID writer has a different opinion it is the structured message template but now I want to know from you did you know about all the memory issues you can have if you use string concatenation in your logger message template and are you using structure loging if yes with what provider are you using it leave a comment down below and let me know well that's all I had for you for this video thank you very much for watching and as always keep coding

Channel: Nick Chapsas

Views: 46,882

Keywords: Elfocrash, elfo, coding, .netcore, dot net, core, C#, how to code, tutorial, development, software engineering, microsoft, microsoft mvp, .net core, nick chapsas, chapsas, dotnet, .net, code cop, code cop nick chapsas, code cop nick, logging, structure logging, structured logging, serilog, code cop logging, Stop Using Structured Logging in .NET!

Id: XV7N21Dwa-U

Length: 8min 23sec (503 seconds)

Published: Thu Oct 26 2023