justforfunc #15: a code review with logging, errors, and signals

hi I'm Francis Campo and this it just a welcome to episode number 15 of just a funky today we're going to go back to one of our favorite things here I just found which is to do a contribute and I'm going to be doing a good review something really simple that one of my co-workers sandeep ganesh road using go in order to basically read from standard input and then send to Google clappa for logging but also you could imagine dates logging to anywhere else and also send it to the upload standard upload it may seem like it's a simple program but actually there's a lot of things that could go wrong with it we're going to be talking about error handling what's the best way of doing error handling in such a small program we're going to be talking about how do you handle things like control see if you get a signal how do you handle it which means that we're going to be using channels and we're going to be using concurrency and we're going to be using a bunch of different things all together to make sure that a program is as robust as possible so some let's select I'm going to start with a directory that has only the code that's on the broad and before we start defining anything let's see what the problem does for now so the first thing it does is well creates background contact if you don't know what the context is go check the episode on it I think that is only 9 or 10 or maybe both so go check it out there will be a link somewhere there so we define after that we find two flags the project the project name so in Google cloud platform there is always a project ID and we want to know where those where those logs should be centered also what is the log name which is the name of the loved to write before two default default okay so when you're actually logging something you need to give a name to that log so we can then find it in our logging console we'll so we'll see that later don't do not worry too much about the basically reflects the project and the logging we part those flags we then get the values of the project ID and long name if the project is empty we fail so we print and otherwise we check if what we're receiving is a pipe if we're not able to check then we're going to panic otherwise we'll say hey there's nothing piped in so there is nothing clogged oh I understand because even either it's a pipe or it's on our input like from a command we don't want to be doing that we don't want to be logging apparently so that's that's why make sense then we're going to create a login client with project ideas we saw before if that fails we will of fatal we're going to create a client logger so a logger itself and here's where we use the log name and then for we're going to create a standard scanner from the stern line input which is going to allow us to read line by line and for every line we're going to get the text of the line print it to standard output and then send it to lock to the logger by using these logger the log with a logging entry then we check as we always should if the scanner fail if we fail by while reading anything then we just log fatal otherwise we close the client and close the clothing the client will also flush and finally we finish by saying finish logging so any five lines of code not very complicated but there's actually a lot of subtle ways these for a good cell to do what it's supposed to so let's see them one by one I would like to start with something quite simple which is a what a one this firms do is to everything that comes from standard input goes to standard output and whatever sales go sit on that error that's why we have two outputs right start output is the actual output of the command it's on the error if something goes wrong now in this we kind of doing that but not really literally errors the possible errors we can have so when the project is empty we we do F thumbprint F this will print to standard output and then return so this will fail with exit code zero which is like not failing so let's see what I mean by that so they Google Go Go bill and I run this actually middle go bill lock type so it generates a binary name lock pipe and execute by itself you see this green arrow that means that the error code was zero I wanted to be red I want it to be something like if you do something that doesn't exist you see this red arrow that means that the error code the return code was not there also if I run this command in I'm typing it too to some output let's call it a failure when I run it I would like to see the whole error drag it here and here we're saying that one of the lines the required flag - B - - P project was not satisfied goes into standard error that's what we feel seed here but this one please - superior project IV goes to standard standard output so what I'm going to do is I'm going to say instead of print F 2 standard print F and send it to standard error okay so now if we do go build again and I run load pipe and I send it to aux I can see the whole thing but still this is saying that the command worked correctly which is know what I want to do so instead I'm going to do OS exit of 2 and then I do any return because always exit will actually stop this program and set the return code to - so let's go build again and I will run it ok perfect now we get the whole output here and also we see that this file that they are the return code is not 0 choosing which I wanted to I really don't care as long it's not really good ok what about this case here well in this case it will panic so it will panic and print something to start an error but I do not see why we should do this as a panic instead let's simply do a printf could I could not start standard input and this year okay and this goes to standard error and then OS exit off - okay similarly here we're going to exactly the same if these fails we're going to do exactly the same again so to create flying and if this fails we're going to do exactly the same again let me copy paste again so you get the thing it's not very complicated but the good thing is that then the whole behavior is going to be more uniform no matter how the program fails it will fail pretty much always in the same way showing you the same the same thing and then here F print f OS DD are finished logging now I would say that printing this is not very unique song communiques what you say is that no output is good output right so if I print if I bring anything some people will interpret that something fell so it is better if everything works not to print anything interest on the error so I'm just going to drop that line cool so now that we have of this I realize that well why don't we simply say instead of having this I'm going to call this error F and I think that I change that pretty much everywhere okay Multi cursors are amazing okay song RF so we can have our argument our format which is string our argument which is a bunch of interfaces and what this going to do is going to do going to print format and arts then OS exit off - okay so now we do pretty much everything we handle every are doing exactly the same which you know I like okay so go bill - no lock pipe round the pipe and it felt in some way if I do ox it tells but still shows everything correctly if I did these now how do I never remember how to do how to really make to to is it may be like this oh no it's doing it like this okay cool so now we don't get anything to standard output but we redirected some that error with that little ampersand to ox and an ox we had that error message cool so everything works as we expected nice okay so the next step is to make sure that we do the error handing in in a correct order or at least as little as possible but as much needed okay so we're going to start by going numb by line and seeing where the errors are handled or handle or not and whether they should be handled or not or in the order or something else cool so a flag the parse returns a slashes as like the strings which is the arguments and also an error these are packaged that some deep wanted to use which i think is pretty cute it allows you to have short and long form which is you know if you use a command line you might appreciate that and also requires you to have required so you can say these values require or not and then before which is the default value for the for the flag it has not been defined so you know it's a little bit more feature fool than the standard library I would still use the same elaborate to be honest but let's keep it like that why not these returns an error and we're ignoring it so what I'm going to do is since these already print whenever there's an argument that fails already print something we could do always exit of one here directly because since these actually checks for required so if we do go wrong of Loctite the girl this should fail drag Lea exercise one if I do egg okay so this might be the way to do it oh cool so now since these fails because the project was not specify we actually need to check for this so there's one left prompt to check good then we're checking if we can start or not then we're checking if the type is named or not which is good we create a client we create a scanner I'm going to change the name of this because I always call it s and I feel like it's easier then we're getting the text we print again we're logging in okay so now here's another problem we take import the air in the scanner and we check in for the error in the client or closed but if there's an error in the scanner which means we felt somehow to read some line then what we do is we we panic plop we panic we exit the problem without closing right like we didn't close the client here so what I'm going to do is I'm actually going to move it to the other way so I'm going to say first we close the client no matter what if closing the client sells I'm okay stopping the execution and not printing anything else otherwise I will actually check for did we beat all the lines and if something fell then we are why do I do this because otherwise if we exit without clothing we will not flush the client which means that some of the lines that we thought we have logged will not be actually logged so that that's basically the whole problem let's let's try to run it actually so if I do get billed it again and I do log type g-cloud config g-cloud config list okay so I mean I'm using a readiness project so I'm going to do clock by - P of this project nothing is piping not nothing is type in so there is nothing to lock okay so let's do a cat and back to that so now anything that I write here will be sent to the program so if I do hello and then I exit cool so I did control D to finish the standard input line so if this actually work we should be able to go to a Google Cloud console in my project then go here to logging logging logs and let's see hello just for funk friends see like flush and there you go it appears cool so we we see that this problem is actually working in these indeed logging to the output here and also logging to the console cool are we done now we're not there's more to do here let's see what else we could do so next I'm going to do a couple changes that make the problem a little bit smaller one of them is going to be project ID we get a pointer to that value here and then we reference the pointer to you this year so what I'm going to propose is to simply use the project ID directly there and then we can track this same for log name we do exactly the same there's no point doing that okay so that makes a little bit simpler also I'm a big fan of using of declare variables ready for you use them this is not see where you need to predict air things from time to time so I prefer to use these right before you use the context which is right here cool and we could say I was using context anywhere else we're not so we could we could even say that this could be use here directly but you know that's not a big difference but at least the context is declared right before we use it I'm going to move this up here a little bit and now the program looks a little bit better for me just a little bit simpler you know we'll still around 80 lines of code even though I change a bunch of things right so next what we're going to do is we're going to try to simplify the part where we're reading from standard input and sending it to standard output and to log so this actually has a it is pretty common to do this thing where we have one stream of data coming from one way of reader and we want to obtain a needle reader we want to keep on reading from there and also we want to send all the things that we receive from the reader to a writer and if you see bread and seeing it on like left to right you see bottom to like bottom up you can imagine something that goes like you have the reader you're reading you send it to a writer and also you send it to your own code and if you see the shape scale like 80 so that's what is collective you're the same way this is called a t-shirt right so the whole idea is that we're going to have that shape happens pretty often throwing your code you have some places where you do something like this the standard library offers the type specifically for this so what we're going to do is we're going to simply create a standard so we're going to create a new reader from that on that input so we're going to have rather than two standard input here we're going to have a reader which is IOT reader and preciate culty reader there you go and that receives two parameters and we don't a writer we're going to be reading from standard input and writing the standard output now that's a reader so we can use it directly here too and now these parts of reading from some their input and sending it just on the output not needed because we're already doing it through the to reader so we can drop this part and then move these texts here there you go this does exactly the same thing as before but it is much simpler and if you know what a key reader is and now you do this code is also very simple to understand okay okay so the next step now there are program works and looks pretty nice is to make sure that it handles all of the errors and all the use cases and one of the errors that could happen to processes is that they receive a signal now signals are signals that are sent across process on Mass Oasis and they allow you to do things like request at processor stop in this case for instance we can say an interrupt signal we can send that with control seed directly or we could also use the queue command on Linux and Mac OS and I will happen is that our program will handle it gracefully or not and something will happen so let's see if this is working correctly in our frontal now I'm going to add back our thumped to standard error saying the finish okay and I want to make sure that this is actually printed because if it is printed then it means that we indeed closed the client and then we check that all the input was correctly handled and then we finally exit right so this is what I want to make sure that this that happens so if I do if I compile my program and I run log PI dash p who cut that and then here I would not cut PS I have my Catherine I lock by P R so I'm going to kill - 2 o'clock pipe sorry not to apply to the process ad okay so now we should be able to see that the program finish without saying absolutely anything not awesome right like that is that is not what we want let's try it again so I may do hello a print hello permission denied sure that that's okay we'll see look at that in a minute umm if I do PS kill - - for this and go back here nothing silence not good we won't want to make sure that we actually log everything like the we call close so how do we handle that well what we need to do is we need to use the OS / single package in order to handle signals so we can do it up here at the beginning and do signal doesn't notify and that will add our OS signal package of their signal the knife I get to argument well one argument then verily calculating all signals and the first one is going to be signals which is going to be a channel of signal we're going to pass signals and then we want to pass all the signals that we want to handle and I'm going to say that we only want to hallo interrupts which is the control C and also the - - that we said actually if you look at the documentation we should be able to see that sig int it defined to be - so the signal with value to go so that signal this program now will not do anything new but a new value a new signal will be sent to the signal channel whenever a signal in shape so we could do something like go fight signals let's receive our signal so let's receive our signal and then we're going to our F received signal and I the signal we'll see and of course we actually call that because then you go with it okay so with this now what we're doing is we're actually doing something with that signal what we're doing is not naturally correct because we will probably will actually not get to the end of the program and run our log here saying everything finished okay but let's see what it does now so if I do my go bill and then I run Padma pipe and now I'll go here so PS like kill that kill the shoot to that and now receive signal interrupts and then now we saw why this finish now the bomb is that as we're saying we did not print anything right so now we want to do is we want to be able to have either we receive a mail line from the sky and we send it to the logger or we receive a signal and then we exit so how else can we do this well the way to do this correctly is to please go routines so what I'm going to do it and they're going sorry not to use ghovat is to use what's your routines but also to use channels so here what I'm going to do is I'm going to create so I'm going to move this a little bit lower going to move this here so rather than scanning and logging directly what I'm going to do is I'm going to have lines with the channel of strings and I'm going to create a new routine that going to simply go I go funk and doing something wrong if this is not formatting it correctly why is it for other you go it's pretty low oh this does not come back okay cool so we're going to move this inside and remember to close to flush first okay and lines so whenever we receive things we're not going to LA get which going to send F dot text to lines and then we're going to have a for loop with a select statement and if we receive something from lines we're going to log so this now can be done down here sorry not text that line but also if we receive something from signals we're going to s print F received signal terminating program after receive signal signal to the standard error we're going to also do something really similar to this right I'm failing so if we get an error we will still rule pin the errors and we were not able to read anymore so we're going to be finishing but this is we're going to finish this girl routine how do we know that we finish this guillotine okay climb to close a reachable code yay because we won't break here and actually we won't break main loop so brain glove okay this might be a little bit complicated but let me explain so we've broken our program into two different go routines we actually yeah two different routines technically three or more but the two that we've written is one go routine that going to be reinforced on that input and sending to standard output to the team leader and for every line we read we also send it to lines lines which is a channel we're going to be reading it from if something sells we will print an error but continue next we receive a signal we're going to break the loop so if we receive a signal and we initialize that up here we will exit the loop [Music] let me initialize this with the there you go I like that better with a logger everything logger related initialize at the beginning so we initialize our signals we receive a signal we will print the signal and brake loop which means that we will go and close the client flush all the buffers and then print finished okay if we are done reading from lines we should also exit so the way to communicate that is to say fair closed of lines and if not okay then break loop that means that there's no more line coming in it might be because there's no more lines or simply because something fell we do not know we do not really care instead we're going to do is whatever line is closed we know that we're supposed to finish the problem cool let's try to run it so go build a show pipe we run this on one side we do PS we sent killed us to this and Terminator pearl after receive a tional interrupt oh we should have control and of their control n here and control and up here I feel like we have control and everywhere maybe we should just simply add control and here that before the simpler so now I can drop it I cannot drop it from there I can not drop it from there but all the error F you can swap it from here I can drop it from here you can drop it from here or F go and our program still will finish but now finished okay just to make sure that this actually works better now let's do it again so PS kill - - - that fits ok and finished ok so now we know that these actually create escape we can get rid of this now I want to make sure that these actually works so what it can do is go bill - race - oh love pipe and this will generate a binary that has data race detector enable which means that our program will be waste lower but fine because basically will allow us to make sure that what we're doing is probably correct doesn't mean that is 100% correct but it might detect some errors if there are so let's try to run that now so with lad hello ring hello and it fells and we'll figure out we'll figure that one out in a minute but okay so we have PS kill - sweet - this we come back here program is done everything work correctly and not data bracelet was detected so this looks pretty good now to finish we're going to try to understand what's going on with this permission denied so so permission denied is story no more in this case because what I'm doing is I'm running and I'm trying to log stuff to a project name through like set foo and this is not possible because I do not own the project named foo probably this one and probably someone owns it but someone probably that side uses a platform quite early on I imagine probably a Googler so I'm not able to do this but I only discover it whenever I try to learn something and that fails and I could say there's a way to whenever an error occurs I will receive like I can send a mess I can pass a callback so that function would be cool with the error and then I can panic or area for whatever I want to do but the problem is that I do not want to do that because I want to log as much as possible so if log in one of the lines fails it's okay just continue keep going with your life I don't know want to just stop the whole logging because one line but I want to make sure that whenever I start lock pipe if this is not correct it should do something about it right so when we create the time we can check that the climb has all the needed authorization all the rights all that we own the project and we can actually log and to do this we're going we're going to do ping we're going to pass the context let's say that we want to do context with time and so after one second if we're not able to ping after one second then something is wrong so we which is going to fail that will return an error and if that error is a new fail to King log logging service and they are imbrue exit that that way what is from King received too many arguments okay sorry context and cancel differ cancel past the context okay so complete with time up with returns context with a time out and also ping sorry a function that we need to call whenever we've done with that context we could do this very castle that is a way of doing it the other way of doing it that is probably better is to actually call Council here in Castle here but I do not turn up about this tiny context that if we leave it there running for long it's not really an issue because it's not something that we're going to be doing repeated repetitively we just do it once at the beginning of the problem so this is fine in my opinion okay so go build again I'm reading with great data wave detection why not just to make sure everything is okay we're doing CAD lock type tool and the color the color does not have permission and the pro- cool so now we're able to actually see that this this program is not correct but if we do it just for funk test the program does not complain just yet I can do hello just for funk in a head so you should be able to see it somewhere we'll send that well we saw he doesn't complain is the pin which will go to us to make sure that we can log so you will see this at the beginning is the only way this is this can be done which you know it's sad but that's how it is and then we see how it just for funk in a thread safe way cool so then I can do control C and we receive the interrupt so everything exit and everything to sport correctly great so with these we're done with the episode let's see all the things that we modified first we made sure that all the errors were handled the same way uniformly and all being sent to standard error nuts on their output and then making sure that we always exit with an error code is not zero is something failed which allows us to you know understand better what the how the problem did then we also change it little things like make sure that all the variables are defined right before the years and stuff like that makes your code a little bit simpler to follow we added a key reader that allowed us to remove one step by saying everything that comes first on our input should go to standard output and also we would like to read from it for something else which is the logical set of things and then finally we make sure that the signals were correctly handled and to do so we actually added concurrency with tunnels and select statements great so I hope you enjoyed this episode from now on these episodes are going to be coming on Mondays every two weeks so make sure that you subscribe so you don't miss any of the next episodes let me know if you have any ideas you can send your ideas either on Twitter at front desk or directly to a form that I created just for you it's called form just for fun comm so you can go there and semi send me all of your ideas questions or any proposal propositions you might have as always thanks for watching if your going to be a gopher con in Denver on Wednesday I will be there too so come say hi and if not see you in two weeks you [Music]

Channel: justforfunc: Programming in Go

Views: 18,634

Keywords: golang, justforfunc, logging, programming

Id: c5ufcpTGIJM

Length: 37min 45sec (2265 seconds)

Published: Mon Jul 10 2017

Reddit Comments

[u/parnmatt]

Another great code review. I wonder if 35:20 is an intended pun

[u/recurrency]

love your vids u/campoy!! would you mind sharing your vs code setup? can't seem to get all that nice autocomplete etc you got there