.Net Foundation On .NET, 30 Mar 2018

Previous Meeting Next Meeting

⏯

youtube image

►

From YouTube: Debugging and Diagnostics of Durable Functions

Description

Durable Functions is an extension that lets you create stateful workflows with code using Azure Functions. We've spoken about getting started with Durable Functions before in a previous episode, but there was still much more to discuss. So we invited Chris Gillum (@cgillum) back on the show, and this time he will be talking about debugging and diagnosing your stateful code in Durable Functions.

01:41 - Where to find documentation?
02:12 - Quick recap on creating a durable function
04:14 - Logging with replays
08:33 - Checking the status of a running function
11:14 - Querying the history of a function

Take a look at the follow links to learn more about diagnosing your Durable Functions code.

Application Insights docs: https://docs.microsoft.com/en-us/azure/application-insights/?WT.mc_id=ondotnet-channel9-cephilli
Durable Functions on GitHub: https://github.com/Azure/azure-functions-durable-extension
Durable Functions documentation: https://docs.microsoft.com/en-us/azure/azure-functions/durable-functions-overview?WT.mc_id=ondotnet-channel9-cephilli
Diagnostics in Durable Functions: https://docs.microsoft.com/en-us/azure/azure-functions/durable-functions-diagnostics?WT.mc_id=ondotnet-channel9-cephilli
Create a Free Account (Azure): https://aka.ms/azft-net

A

Okay, welcome to another episode of the on.net show.

A

And today we've got chris gillum who's actually been on the show before to talk about azure functions.

A

So just quickly introduce yourself again and then what is it that we're going to talk about. yeah? My name is chris.

B

I am a software engineer in the azure function's team and specifically we're going to talk about durable, functions. and you- and I have talked about this before. durable, function's,, yeah.

A

So,? Why did we need to talk about this again?.

B

Because,, why wouldn't you want to talk about it? Again?.

B

So,, what I hope to cover this time around was actually how to do some debugging and diagnostics of durable functions.

A

When things go, badly. yes. so,, we do a great job of showing what you can.

B

Do and all the fun things that you can start, but how do you figure it out when it goes wrong.

A

Okay. now,, when.

A

I have thought about this space before,.

A

There's dev diagnostics to.

A

Help me build the right code in the first place.

C

There's production diagnostics.

A

How do I find out how.

A

Things are doing in production or actually know things are going, badly, find out what the root cause is? and then the last is some kind of like analytics of how the app is being used..

C

Which ones of these are we going to talk about today?.

A

So we're going to touch on a little bit of all those,.

B

Local development debugging,, as well as production, debugging and analytics.

B

okay.. So where do we start?.

A

Sure. well,, I guess just as a reminder,.

B

This is an open source projects from github.

B

we're actually a proper extension of azure functions that has its own repo here,.

B

Azure functions, durable, extension.

C

So anybody can go to this,.

B

You can find links to our documentation in various topics, and, in fact, a lot of the things that we're going to talk about are going to be in this diagnostics in durable, functions,.

B

A topic which you can find here. so, lots of good stuff there., but the first thing I kind of wanted to jump into.

B

Was more of the development experience.

B

So, just as a recap, two different types of functions in durable, functions.

B

You have your orchestrator functions, which uses orchestrator trigger., that is the the main purpose of this,, is to call the activity, functions and sequence them or run them in parallel, and in this case I just have a very simple call, one after the other, save the outputs and this sayhello activity trigger simply just returns: a string.

B

right. yeah,. I remember.

A

The diagrams that you had last time., right. and so just f5c. To start this project.

B

This is an azure functions project which you can create in the recent versions of visual studio and that's going to go ahead and start this up. and just to begin, I'm going to- actually,.

B

Let's wait for this to happen. so, we've got a couple of endpoints that we've defined in here.. One of them allows me to start one of my orchestrator functions by name.

B

I'm just using a regular htp trigger.

A

Right. now, are these on your machine currently, or are these are somehow on azure already? so,. This is completely on my local machine right, now.

B

I'm using the azure storage, emulator and everything.

B

so,, nothing is leaving this laptop yet.

B

So, I'm going to go ahead and start this function.

B

Right and this http command,.

A

It's basically like curl. yeah. sorry,, I'm using http pi.

B

I like it because it's really good with doing json things.

A

Yeah, totally. much better than curl,, or at least much easier.

A

yes,. The read out is nicer..

A

Curl is very black and white.

B

And so basically, I just get hello_tokyo, hello_seattle, hello_london.

B

Basically,, just what I told it to print in my activity: function. so,, nothing super interesting or exciting, there,.

B

But what I wanted to show is what.

B

Happens when you add logging statements to the orchestrator function. now,, this is important because a lot of people when they look at durable functions,, they don't necessarily read all the docs..

B

They stop at a certain point and forget that one of the important runtime behaviors of these orchestrator functions,, what kind of makes them stateful and long running and durable, is that they actually replay each time after resuming from an await call.

B

Replay from the beginning. so,, I'm just going to add these log statements..

B

Let's go ahead and run this and see what happens.

B

So,, I'm just going to start this guy back up again.

A

Right. so, that log was trace writer.

A

Does that have anything to do with the iloggerinterface that you talked about at the start?

A

or that's kind of slightly separate?.

B

It's slightly separate., it's the old style logging that we used to do.

B

We also support ilogger,, but for simplicity case I'm just using the trace writer for this one.

B

So, the function cls has started up., I'm going to run this again. and we're actually going to see something. Maybe a little.

B

Bit surprising, when you look at this.

A

Love to be surprised. yes. we're actually going to see that we're.

B

Starting up multiple times, here.

B

starting up,, hello, tokyo., starting up,, hello, seattle., starting up,, hello, london.

B

and then at the very end. We get that "done" message.

B

So,, this is something you have to be very aware of when doing logging, when writing an orchestrator, function.

B

and so,. Typically, what our guidances around this is,.

B

If you do need to add log statements, here, we have this nice little context. Dot is.

B

Replaying check that you.

B

Can do before you log statements, here.

B

yeah,, I would say that was surprising.

A

It's not something that you would expect right. Away.

B

We're looking into ways to maybe make this a little bit simpler, so you don't have to think about it.

B

yeah,, because that statement is a bit bizarre.

A

It is a bit bizarre, but.

B

Certainly something we want folks to be aware: of.

B

A

So,, if I run this again.

B

Now that I have these, if checks, and I'll mention again that this is all in preview,.

B

So we're still finalizing it.

B

so that one seemed to do the same thing as before..

B

Sorry,, I made a mistake: here,.

A

Which is why we're debugging. yeah,? I think you wanted a knot. There,.

B

I should have actually caught that., so if we run this again.

B

If it is not replaying,, please log that.

A

If it does it again, we'll be really confused.

B

So now we started that.

B

Again and now we get the output that we expect.

B

So again, this is just more of,, be aware, there is this replay behavior.

B

same thing you need to be aware of. If you're attaching break points., you may hit the same breakpoint multiple times for a single execution.

A

Something to be aware: of,.

B

Something to be kind of prepared, for.

A

Yeah, that reminds me a little bit of multithreaded debugging.

A

yeah, for sure.

B

So, anyways,, that's just something I wanted to cover a little bit regarding local development..

A

What's maybe a little bit more interesting.

B

Just one question on those traces, is,.

A

I certainly see how those are useful for local debugging.

C

Now,, would you recommend that people.

A

Remove those before going to production?

A

or what's the thought on that? or it's fine, to leave those in place?.

B

It's fine to leave those in place. so,, typically for production. What we advise people to.

B

Do is configure application insights on your function, app. and when you create the function app in the portal,.

B

You're actually going to see an option to configure application. Insights.

B

And once you do that,.

B

You'll be able to have a link here in your overview page, which will take you directly to your application. Insights instance and you'll be able to see all those trace statements show up there.

B

So this is just a regular feature of azure functions.

A

Right., and so you set it on the whole application, as opposed to on a function by function, basis?.

B

That's right.. It makes sense. okay. so, one other new feature. We.

B

Recently rolled out was the ability to- so last.

B

Time we showed you can query the status of one of these orchestrations that you.

B

Started but to improve diagnosability,.

B

Another thing that we added was this ability to.

B

See the actual execution history from this rest, api.

B

So, we ran this orchestration.

B

We got back an hpp, 202 accepted..

B

We got back this location header..

B

What's the difference between.

A

200 and 202?- I actually don't know that.

A

So 200 is okay.

B

We did the thing that you asked us to do..

B

202 accepted means, that, "I got your request., I'm going to go. Do some work in the background now..

B

It may not be done yet." and then often what you do is return a location header like this one which says "here's.

B

Where you can go to check on status of that long running request that you just started.".

A

So,, that means there was no immediate payload,, at least with respect to what you asked.

B

But there's a way to get it. Later. interesting.

B

And so this is a common pattern for people who.

B

Build http apis that maybe take a long time to run.

B

And so we have support for that out of the box.

B

When you start these functions, you can get links to that.

B

Is it a polling idea, then?.

A

So you have this location api., I'm certainly familiar with paging systems, where you have a next url,.

A

So that's a little bit like that,, except there's only one next., but with the next one,. The expectation is next, is immediately available.

A

Whereas with this, it might not be., if I call on this url immediately,.

C

Will I just wait, or what does that look like?.

A

Yeah,, it's definitely a polling based epi.

B

Okay, polling. actually,. Let me surround this with quotes.

B

Sometimes the windows command line is confused.

B

In this case, because this is a really short function,.

B

It is actually going to return to 200 okay.

B

Because it was done because it was done., I see. whereas, if it was still waiting,.

A

We would still get these 202s? is that right??

A

That's right. you'd still get the 202s,.

B

You'd still get the location header, and that is a signal back to you to say that it is still running, keep querying at this end-point.

A

Okay. I'd buy that.

A

Yes, there may be.

B

A retry after header, as well suggesting, "try, again in five seconds",, that sort of a thing.

B

What we get here, is you get? When was this thing created, when it was updated and inputs and outputs and rans.

B

You could see the raw output that this orchestrator function returned..

B

It doesn't tell you anything about what actually happened in the process.

B

And so, one thing that we've also added and feel free to interrupt me with questions is,. I can say-.

A

Right,, like duration, isn't there, for example.

A

Well,, you can compute that from.

B

The last updated time and the created time.

A

I wasn't sure if it was literally just the gap between those two. yes,, but what you can also do. Is,.

B

If you say show history,, we are actually going to show you what were the different things that your function did and when did it do them.

B

so for example,, the first event, was, "we started the execution". next one was, "we completed this activity called say hello." right., and we give you the time stamps for all of those..

B

So this is super loosely,.

A

I always like analogies.

B

Because you know how well those work.

A

This is super loosely. The call stack for your function, kind, of?.

B

Yes, kind of.: that is a good way to think about it.

B

And in this case we can also,, if you add another parameter, "showhistoryoutputs_equals_true,", you can also.

B

See what were the values that each of these function calls returned.?

B

Now we make that another query string parameter because in some cases it could be like a big payload and you don't necessarily want to dump all that information. Every time.

A

It can even be binary data,, it might not even be textual?.

B

Sure., it could be some basics,, the foreign coded image or something.

B

yes.. So you may not want to look at that. Every time.

B

you can see the outputs of these individual activities.

B

Okay., so that is a useful thing that you can do to get more information.

B

About what did my functional orchestration, do,.

B

What were the outputs., what about app insights?.

A

I see it hiding back there. yes.

C

I feel like our watchers would like to see.

A

That, in less of a console, window.

B

Yes., you know where we are going with this.

B

One thing I was hoping to do too: is,.

B

I have a function app deployed in azure already,.

B

And I am just going to go through my history: here.

A

So no more local host, here? yes,. We are not doing local host anymore.

B

I have basically a map reduced orchestration which goes through and it's doing, map reduce on nine gigabytes of taxi data for new york city in 2017.

B

It's a good chunk of data.. We like this scenario.. I am just going to go ahead and kick this off., and this is going to start running in the background..

B

Now this application is configured with application, insights.

B

and so,. One of the things that we can do is again,.

B

If you go to the portal and you've configured app insights,, we just have the link right here that you can click into to go directly to that app insight's instance.

B

Again, nothing special for durable, functions,, yet.

B

But when you actually get into application insights,.

B

We have some interesting things: here.

B

There is a traces collection and you can just do.

B

A simple-, sometimes, if I click on the wrong thing,, weird stuff, happens.

B

I am just going to do a query over the traces collection and we get a bunch of logs spew that comes out here, and some of this is just generic for azure functions..

B

But buried inside we also have some special traces in here for durable, functions.

B

> okay. in fact,. We can actually see,.

B

I think in here some traces that say,.

B

"We are processing these data files"., but anyways,. What I wanted to highlight, was,.

B

If you dig into this,, there is actually a property here called "custom dimensions.", and if you dig further into that,, you can actually see that we have a category called "host.triggers.durabletask.".

B

That is how you know that it is actually our extension. That's emitting this tracking data for these orchestrations.

B

That is going to tell you things: like, "this was an activity. Function", "was, this a replay, execution or not?", "what was the instance id?" and so on, and so forth. and so,. There is a lot of useful information buried in here..

B

What I was hoping to do, was,.

B

I am going to scroll down here..

B

I actually have some completed queries.

B

You can do some interesting filters here to get more information about what happened. so for example,. If I just wanted to query only my durable functions traces,, I can do that.

A

So we just cleaned up the data, a whole bunch?.

B

Yes. and then another trick that I like to do and.

B

I'm just going to apologize for the copy paste, here,.

B

But we can take those custom dimensions and we can actually extend them out into proper things that we return and we can do operations on those..

B

We can filter, for example, based on, "do, not show me any replays,. I just want to show like the actual execution.".

B

Yes. and I can do something like filter, "hey,.

B

Make sure that this is not a replay" when I query.

B

For my instance, history.

B

And then, let's clean this up, even more., let us say,, I see all these columns.

B

I don't necessarily know what they are talking about., let's just project a few- that I actually care. About.

B

There is this project keyword in the application.

B

This is the application insights' query language..

B

It is a little bit like select.

A

Exactly. so,, we run that and.

B

Now we have a slightly more clean view of what is going on here.. I can see my function name,, I can see that, "this particular orchestration was scheduled.".

B

We scheduled the "get data files" function, which is going to go and get a list of files. It needs to process.

B

We are going to see some weight points, we're going to see a bunch of activity functions which process the data in parallel. those all get scheduled. Basically around the same time here, if we look at the time stamps.

B

We can actually see the history here in application. Insights..

B

You can even get really fancy if you want and do some interesting aggregations.

B

Now, there is this interesting, summarize keyword.

A

Which is kind of the sql group buy.

B

I use that all the time.

B

in this case,- maybe I want to get the latest status.

B

On every function, orchestration.

B

Instance that I have ever run. and basically,, I can see, I've run a whole bunch of these instances,. I can see what was the last thing that happened,, what state are they in.?

B

This one is still running, so it is started. State.

B

These other ones have completed.

B

really just get an overview of,. I kicked off,.

B

All these jobs are running in the background, in my serverless environment,. How do I know you know what status they are? In.

B

and application insights is a great way of doing that.

B

I really wanted to highlight this for folks who, like durable, functions.,.

A

Absolutely. now, you and I know this query language is.

A

Cousteau and for the folks at home that want to try this,.

A

If you type in "cousteau", you'll actually get some documents that define this language and help you use it..

A

That is certainly the way I learned how to use it.

C

That could be helpful.

B

Yes. definitely. dig into this query: language, you can do a lot of really cool stuff with it. yes, and I actually found,.

A

Day, one of using it, I was a little bit intimidated by it,.

A

But after just a couple of days of using it, I found that I could just quickly bang out these queries and answer any question that I needed.

A

for sure. and one thing that I find helpful too is,.

B

You can save these queries as well, and.

B

They give you a nice place where you can go and pull them back up. Later.

A

So,, if you have things that you like to look for,.

B

Just stash those away,, you can pull them back up. Later.

A

Right. kind of like saved queries on vsts., yes exactly., but it's in the cloud.

A

okay,. Well, this was awesome. great.. I think we learned a bunch and I liked.

A

That last time you were here, it was the pitch-on,.

A

The service you work on,, but this time it was super helpful in terms of how you actually do this in practice,, because it turns out only part of your time is writing. Code..

A

A big part of your time is actually understanding how your service or your application, actually works,.

B

And then you figure out what to do next, based on that.

C

A

Awesome., that was another episode of on.net.

A

Chris showed us how to do diagnostics and.

A

Analytics with application insights for durable functions. thanks for watching.