Node winston logging | logging in Node

now what is going on guys today we are going to take a look at winston what it is why you need it and why you might consider it for your node.js application and what advantages it has over console log for example well let's maybe start with why you would actually consider using a external logging library like winston in favor of something like console.log so the thing is with console.log you can do a lot of things right you can write something to the console you can log something with a certain login level so for example you can log on the info level on the one level and on the error level so that was quite good right so why do you actually or why would you even care about like an additional logging library and the answer is that console.log only writes to the console however you might want to consider writing to a different location so for example you might want to consider to write to a file or you might want to write to a log aggregator and this is actually what this library here uh winston allows you to do so it's like a general purpose logger for node and it allows you to write to different sources and you have very fine-grained control over where you write to and the principle there is actually quite simple so the idea is that you have a logger and then you have an arbitrary amount amount of so-called transports and these transports are basically locations where you write your log messages to so for example you can write to the console but you can also write to a file you might also write to https or like over the network or to some log aggregator and like this log aggregator for example like datadock but there's also others this is very very useful because if you have a lot of logs they only become useful when you can search in them and you know when you can search for trace ids and these kind of things so winston allows you to do all of that and you can also have very fine-grained control over it so for example you can say i want everything for the info warning and error level to be written to the console but i want i don't know the debug logs to be written to a file so you can do that and then in addition you want to write everything to data doc or to some log aggregate so this is totally possible with um winston and yeah winston is probably like one of the most popular packages here i just wanted to mention one more thing before we kind of go inside of the demo and before we see how it works i just wanted to mention logging levels so in general and this is pretty much the same with any logger and with any technology you have different log levels and depending on the severity or the lower the lock level is the higher or the more severe the lock is so basically arrow is like pretty severe right that's why it has like a lock level zero so these are like npm lock levels so there's also java or like other technologies like they might have different log levels but in general the principles is always the same so error for example has like the lowest log level and then you have warning and then you have info so you pretty much always have these three here at least and the idea is that you can take a logger and you can set the log level globally and then it will only log the log level and the ones below it so for example if you have an info logger it will write out all messages for log dot info log.1 and log.arrow but if you have like locked or debug it's not going to lock it out because the current level is set to info or below and this is very useful because if you want to debug something typically it's just a matter of like changing like an environment variable you kind of set the lock level to say debug and then you get like more logs so this is very useful when you're investigating uh some sort of bug yeah so uh that's it pretty much as far as the contents go i would say let's just um jump into the code and let's just see what we can do yeah so before we get into winston let's just see how the um default console log behaves so i'm just going to run this code so i have note 1 installed here it's just like empty project more or less but with norman installed so i have like hot reload and you can see here that it basically outputs all the text so hello text info text 1 text error and that we can also log to different log levels but that by default it's just not shown in the console and if we log out an error it actually or it not only prints the text message message but also the stack trace cool so this is just for reference so that we compare it to how winston is doing it and what we need to do is we need to install this package first and you can see here okay it's called winston so let's copy this let's go to your project and let's npm install this cool and what i typically do is in addition i make or i put the logger inside of a separate directory and i'm going to say touch logger and then index.js yeah let's maybe try to create the simplest possible logger in winston and the way we or what we need to do is we first need to import this package and then in the documentation you can already see like how to use it so here's like one example this one like already writes to two files um yeah let's maybe copy this example anyway and let's just make this simplest possible logger out of this so what i'm gonna do i'm going to remove this these file transports because i don't want to write logs inside of like a file for now i also removed this level info we're going to get to that in a second and they are doing json logging which is fine i'm just going to take simple so they have like a simple built-in format you can see it here winston.format.simple and yeah that's quite decent so i'm just going to take this one as well just for starters and the default metadata i'm going to yeah maybe comment this out because we will probably get to it later okay and the only thing we now need to specify is where do we actually want to um write our logs to and we want to write to the console and what we can do is we can just create a new transport so i can say winston dot transports dot console oops yeah that should be it and let's try to export this exports logger and that's our logo so that's probably the symbols logger you can create and um i will just go here i'm going to comment this out for now and i will import like this logger so i will say logger require logger and then we can see so winston also offers these info worn error and debug methods so let's just try them out i'm just going to say logo.info text info okay and i will also say logger dot warn text warn and i will say logger.era text arrow okay so let's try to run this and let's see what happens so i'm just going to run npm run dev cool and there you have it so this is the simplest type of logger so it basically prints the logging level which is like uh different from the console info right because there will you don't see the level um and then it has a colon and then it prints the text so that is fine i just want to show you something else so let's say i am i will do something like logged or debug and say text debug oops why is the log not there well the answer is quite simple um as i've already mentioned there's like different logging levels in this library and per default if you create a logger with this create locker method the log level is set to info that's why we deleted the line also as well because it's default so that means if the log level is info or anything with a higher severity so warning or error it's going to write it to actually write it to all the transports at the moment we only have one transport which is like the console and that's why you see the info the warning and the error text but the debug level as you can see here is like higher than the info level and that's why we're basically not writing it out and one way to fix this would be to just take this copy this go to our logger and then instead of making this error we can say debug now if we do debug you can see the log actually appears and by the way this is very useful because you can dynamically set like this logging level by an environment variable for example and if something crashes on production or you have any problem you just set this environment variable to like a higher logging level say like debug and then you get more logs so you can investigate what is going on yeah so i just wanted to mention that not that you're surprised why is lockdown debug not working yeah it's because we just don't have it here so i'm going to remove it here as well so as you can see this format here is it's like pretty simple but maybe it's a little bit too simple so let's maybe try to come up with a log format that is good if you are running locally so something that is easy to read for humans and then we will talk about how your log format should look like when you run in production because that is two very different things and what i want to do is i want to create my own um custom log format so for one what i would like to have i want to have a timestamp here simply because i want to know when something happens in order to create your own log format they have this nice method i think it's called printf where is it here it is yeah so in here you can basically specify your own template string so you can say i want to have the timestamp first then i want to have the login level and then i want to have the message okay so and we're just going to copy this and yeah that should be it so i will just copy this paste it in here i'm going to name this log format now we do not need this label here so this label is basically some additional metadata or that you might want to add we're just going to remove this and we'll just say okay we want to have timestamp the level and the message and i'm just going to take this copy this and instead of have this format simple i'm going to put this in here okay and now it's going to get interesting um because you can see oh actually it's not working and yeah so for one we need winston dot and you know what let's destructure this um format what else create logger and then tran transports because i i just don't want to like write this all the time and i'm going to put it like that and like that and like that and like that so hopefully that now works better yeah and that is fine but you can see something is wrong here um we don't have to timestamp and the reason is the logger does not know where to get the timestamp from and this is something that we basically we basically need to tell it uh hey look we want to have like a timestamp and please use this timestamp or please take like a value for this timestamp and then you can actually print it out and here you can also see how this works so they use this combined method and the important thing to understand is what this combined method does so think of like winston like a huge buffet basically of locking options and you can pick all the options that you want to kind of assemble your own custom logger and with combine you can basically say i want to have this and i want to have this and i want to have this so here it says i want to have a label i want to have the timestamp and i want to have like my custom format and this is why this works so i'm just going to take this copy this and i'm just going to go here and i'm going to paste this in here and i think it was format.combine and i will delete that and then i will say okay i want to have the timestamp and then i want to have this log format right so now your logo knows okay i need to have the time step or i will have the timestamp somewhere in this format here and then it's going to print it here okay so let's just save that and let's just uh see how it goes uh oh i think it needs to be format or timestamp you know what actually we could timestamp and what else combine and i think that's it right oh yeah printf and format so let's just destructure this because it just gets annoying you always have to type like format yeah something like that okay so now it should be at least defined yeah and now you can see okay cool we have like the time stamp over here the only thing that is kind of annoying here is that we have like be in mind we're currently trying to build a logger that that is easy to read for humans like why do we have this the time zone here right i don't care so much like about the time zone if i run locally like if you run in a cluster if you run in production always put the timestamp like in any everywhere also in databases by the way like never use like these local date time thing without the timestamp like always use the timestamp because you never know in what server time like the hardware is configured you know or the like vm or in whatever you're running it okay cool so i'm just going to add like some configuration option here and i'm going to say format and i'm going to take like a custom format that i defined here so for example i don't care about the milliseconds so i'm just going to take that let's just see yeah so now you can see it looks kind of clean so we have the time or the date and the time so that is not too bad there's like one more thing that we can do winston offers the option to colorize things so that means instead of just always having the same color you can use colorize to make it a little easier to read and i'm just going to show that color rise you can have winston.format.color colorize and the only important thing is that this formatter must come before any other formatters where the text needs to be colored okay so i'm maybe just take this i go in here and actually yeah the question is now where do we put this it must come before any format you want to colorize so let's try to put this here and let's just see if we had spot difference nice so this is pretty good right and it's kind of nice before it was nothing was colored but now it's at least colored so that's that's good and you know if it's yellow it's a warning if it's red it's an era that's nice you know for development it's nice to see that cool and there's one more thing i want to do and then we're pretty much done with this dev logger here i want to show you something so let's say i want to i have something like new error something something went wrong okay so if i pass this thing an error then i don't see like the stack trace here yeah maybe not ideal right we want to see the stack trace you can go in here and what you can say is hey look i want to have format dot errors and i want to say stack is equal to true so that means if i have an error i definitely want to print like my stack trace yeah and this is like a best practice more or less and what you will see here now is that hey somehow it's not printing the stack trace right even though we told it to uh why is that and the answer is quite simple because here or like in because we have like a custom lock message and in here we're only logging the message but if it's like an error then there is like a different object and this one is actually called stack so what we can do here we can say something like a stack or message which kind of has the advantage that if you put a like an object or like an error as the first parameter inside of this logging thing then it's going to print like the complete error out so in case it's like an error that you're logging then it will print out the complete error so this is kind of nice so yeah you can do a lot of other things with this you could also attach like some some metadata like to your logs this is which is something we haven't talked about yet so the first message here is always like some text but you can also attach like some metadata meta one meta one okay and the interesting part is that you are actually like for now at least not going to see this in here but it will be there so if we were to write this data to a file then we would actually see it and this is also the purpose of this default metadata so let's assume you run inside of a kubernetes cluster and you have i don't know 200 microservices then you want to know from which service these the logs are coming from and then what you could do is you could say okay by default i want to have this default metadata so that in my log aggregator in data.org or whatever you use i can search for logs for this particular service and you can add like any metadata you want okay so now i think we're done with this one i just want to talk about creating loggers in production now the thing is while this format here is kind of nice and while you could certainly improve like a couple of other things here there's a little caveat so format like this is not very useful for production log because like these log aggregators they live from the fact that they can systematically analyze logs and for that you need like a better format so not just one big string but ideally use json logging so when you run in production you definitely want to use json logging and this is like what we want to do and what i'm just going to say now is i'm going to grab this thing here i'm going to put it inside of a function so i will just say build devlogger and i'm going to do it like that i'm going to take this i'm going to cut it i'm going to paste it in here and then i'm going to rename this file to dev logger and obviously now i need like an index.js file again and now our thing will crash obviously so now we have like this function which kind of builds a dev logger and we also export this function and in here let's just say module dot exports equals build dev logger so we're of course going to work on that now but i'm just going to import it so that it stops yelling okay and what i now want to do instead of this dev logger i want to create a logger which you can use in production and actually yeah it's not super similar but like a little bit so what i'm gonna or what i'm gonna do is i'm just going to grab all of this i'm going to copy it and i'm going to paste it and then you can see what you would do differently so for one you would not have like this log format because you definitely want to log in json this is the most important thing because otherwise your log aggregator just doesn't know what to do and you also don't need this colorize which is even let's leave it in and we're going to see what happens okay so maybe if you run across this issue then you know it and in terms of timestamp i want to have the exact timestamp with the time zone so i'm going to delete this custom format i definitely want to have like this errors and the log format i just deleted i want to have the default metadata for sure and yeah service is fine yeah i think actually we could do we have that somewhere here yeah let's delete this we don't need it if you run locally but here we need it we can say okay let's also write to the console but what i want to have is i want to have the yeah let's get rid of that first i want to have jason logging and by the way actually we could okay we're going to delete this anyway but this one we will need so just i'll just make this a little bit so that's a little bit more consistent here okay that's fine oh actually we need to return this right totally forgot about that yeah so return this logger and the same thing here but i'm going to name this build prodlogger and yeah i think that is fine the only thing that i definitely want is i want to have the json format okay okay so we're just going to check out in a second if this is working or not so for one i'm going to export this method and what you now want to do and this is what i would always recommend is depending on where you run you would actually create like a different logger that's why we created these things in the first place so what i'm going to do is i'm going to say let logger equals null and typically you would check the node and variable so if you run in production then this should be production if not it should be development and if it's like if we're running in development then i'm going to say a logger equals this guy here like this and otherwise i'm going to say logger equals build broad logger okay and then i'm going to export like the logger okay there's one more thing for default this node and thing here is not set so what we need to do is we need to go to our script here and what i'm going to do is i'm just going to set this note and fear manually and by the way there's a very good reason why i am doing it in that order because you might say well actually i could have checked for equals equals production as well and i don't think it's a good idea i think you should set it to development because it could be that for whatever reason people forget to set this end for and what this basically does is it says if i know for sure that i am in development because someone set this node f variable to development then i'm going to use the dev logger otherwise so that means if the node environment is production or anything else or even like undefined because no one said it i'm going to build this prod logger over here and i think that makes a lot of sense you know in case you just forget to to build it or in case you just forget to set it it's still going to work i'm going to take this and why is that now not working i'm just a little bit surprised here let's let's go here let's maybe delete this for now oops let's do it like that logo.info is not a function well that's oh wow why is it importing this i only wanted to have that actually it was probably some renaming issue build devlogger has already been declared uh there's some re-importing bug yeah that's the interesting part if you change this on the fly then the n4 change might not kick in so i'm i'm going to restart this and you can see we still have the old logging format and what i'm now going to do is instead of using this nodemon where i set the node environment variable manually i'm just going to run node index.js so without setting like the value and now you can see that all of a sudden we have like json logging which is good for log aggregators so you always want to have that but what is that here right it looks kind of strange and the reason for that is if you have this colorize option then it's going to add like additional text there so that the console knows that it should be colorized but if you use the json logging it's just going to pollute your logs that's why you need to delete this let's run this index.js again right ah and now you can see okay now it's no longer there right but now it's nice right you got the message you got the level you got the service which is like the default metadata which is good and you've got the timestamp with the timezone and in here what you can also do is i think you can also add this meta so any object you add here will be locked as well as metadata and that is typically like very useful uh where is it yeah you can see it here like meta one this is typically very useful because for every field that you add in this object the log aggregator data dog or whatever you use is going to add one additional column and then you can search by the value yeah so that's it pretty much for this logging tutorial i hope you kind of get like a useful insight in how this works of obviously this thing here is not perfect there's like a lot of things you could improve but i think it's like a good start yeah just let me know what you think about this in the comments below i think if you really want to build like a production ready service you should definitely consider the json logging format when you run in production so that's it pretty much thank you so much for watching leave a like and subscribe to the channel if you have a question leave me a comment below you can also send me tweet so my twitter handle is at productioncoder so thank you so much for watching and i'll see in the next video bye

Channel: productioncoder

Views: 13,553

Keywords: winston node js tutorial, winston nodejs, winston nodejs logging, node logging, nodejs logging best practices, nodejs logging, logging with winston, node js console log example, javascript logging, how to make your own javascript cookie logger in 2021, javascript logger, node js logger, nodejs logger example, winston example node js, javascript console.log example, winston http transport, winston vs bunyan, winston js logger, node js winston logger tutorial

Id: A5YiqaQbsyI

Length: 28min 33sec (1713 seconds)

Published: Mon Mar 08 2021