When OTTL Goes Off the Rails: Debugging Transformations wit... Edmo Vamerlatti Costa & Tyler Helmuth

This talk covers how to debug OpenTelemetry Transformation Language (OTTL) confidently. The speakers, Tyler Helmuth and Adnan, begin by introducing essential OpenTelemetry data models, detailing the structure of telemetry signals such as logs, metrics, and traces. They emphasize the importance of understanding the internal Pdata model used by the OpenTelemetry Collector for effective debugging. Key debugging tools are discussed, including the debug exporter, debug logs, and the OTL playground, which help trace data manipulation and diagnose issues. Through practical examples, they illustrate common mistakes and the importance of matching data representations within the collector context. Finally, they encourage safe experimentation with OTTL to enhance users' confidence in transforming telemetry data.

Uh welcome everyone. My name is Tyler Helmuth. I am a software engineer at Honeycomb. And my name is Adnan. I'm a software engineer at Elastic. And today we're going to be going over how to debug OTTL with confidence. I want to be clear that this is an open or an intermediate open telemetry session. If you've never heard of open telemetry, if you've never used the open telemetry

collector, or if you've never used the open telemetry transformation language, which we call OTTL, this is going to be a difficult session to follow. Uh we're going to talk about these topics assuming that you've used them before. The good news is if you're interested in these topics and this is your first time and you're looking for someone to explain them to you, there are a lot of

talks this week at KubeCon about open telemetry, about the collector that you can go to. And there's also a lot of talks at previous KubeCons that have been uploaded online that you can find about these topics. So, our agenda today is first we're going to review a couple important data models in open telemetry. Uh as it's really, really important to know the shape of your open telemetry

data when you're using OTTL. Then we're going to review some of the tools that you can use to debug, and we're going to go through some live debugging uh scenarios with you today. All right, first let's review the open telemetry data model. Open telemetry has a very, very structured data model that it uses to represent telemetry. The structure of each data model is broken down into different

signals, uh different types of data. So, things like logs, metrics, traces are examples of signals. Each signal has a resource, a top-level uh object in the data model that represents the application producing the telemetry. It has a set of attributes like service.name, and they're set one time at the beginning when you are starting up your application. Each resource has an instrument a list of instrumentation scopes. Instrumentation

scopes represent the thing producing telemetry. They have fields like a name, a version, more attributes, and then each instrumentation scope has its own slice of items, and those items are based on the type of signal that you're working with. So, for example, logs has a log record, metrics has a list of metrics, and each metrics has a list of data points, and traces have a list of

spans, and then spans can have a list of span events, span links, and so on. Within each one of those items, depending on the signal, they are top-level important fields. These are like right on the the root of the item. They're not attributes. So, for example, a log record has a body. That body is a proper field in the data model. It's not an attribute. Metrics have

a metric type, for example. Spans have a name. These are all proper fields that that are referenced in the proto. They're not a list of attributes, and that's important when we're using OTTL. OTTL does this structured hierarchical data model to help keep the payload small when we're transmitting data. So, if the resources are associated to all of this telemetry, if those attributes are associated to every single

log, we don't want to have to repeat them over and over and over again. And that's where this hierarchical list structure comes from. When the data makes it to the OpenTelemetry Collector, every receiver must transform its payload into the collector's internal data model, which we call Pdata. Pdata is the collector's internal representation of that Protobuf data This contract is what allows processors to work with any receiver,

receive that data, and send it to any exporter. Pdata is what powers all of our processors, all of our connectors. OTTL is designed to work with Pdata. It only knows how the data looks inside the collector in that Pdata format. You You never use OTTL to interact with a receiver payload or to interact with data that's been formatted for export. It must work with Pdata. And this

is the most important thing when you're debugging OTTL. You have to always think about how the data looks as the collector sees it, not how you're seeing it in your back end. And finally, the last recap recap thing is context, OTTL context. Uh this is the the part of OTTL that's providing the data from your statement to the underlying telemetry that you want to transmit. Uh the

There's a lot of interesting implementation details if you if you like programming, but for the talk, what is important is what the context provide, and that is the path. These are the bridge between your statements and the underlying telemetry. So, when you say data point {dot} attribute, for example, in a statement, it is the data point context that is providing the attributes off of that data point

that you're trying to transform, set, reduce, whatever. The context also provides the all of the items in that hierarchy for a particular item. So, for example, if you're working with a data point, the context provides access to that data point's metric, that data point's instrumentation scope, and that data point's resource. Oh, and uh the last thing, if you're ever unsure what OTTL path to use, uh they're

all documented here. I'll I'll pause for a sec so people can take images or whatever. All of these slides are available online as well, so all of the links that we're going to go through today you can get access to after. But all of our OTTL paths are documented online, uh and it's really really important that you use uh defined paths. If you if you if you

guess what a path is, if you guess what the name of something is that you're trying to access, either your statement won't work or the collector won't start. So, if you ever had or questioning, "Hey, what kind of pieces of telemetry can I implement or can I instrument, transform in the collector?" All of the paths are defined here and only use those paths. So, yeah. The debug

tools you're going to be using today are three simple but very powerful tools, which are the debug exporter, debug logs, and the OTTL playground. We're going to go over all of them. So, the debug exporter is a well-known tool that can be used for troubleshooting not only OTTL but the whole collector. All you need to do is to configure this exporter with verbosity set to detailed and

attach that to some pipeline that you want to troubleshooting and then it will start to printing telemetry data directly to the console. For traces, an output would be similar to this one we can see on the screen. And what's useful on the output is that we can inspect the whole telemetry data. We can see the field names, we can see the paths, the attributes, the types, and

their actual values. So, if your statement is changing any part of the data or let's say adding a new attribute, it should appear here. If you're not seeing the data here, you probably have a problem and you need to take a look at that. It's also very useful to spot missing Sometimes you're going to write some statements and they are using some attributes that's being added by

another component like a receiver, an extension, and and that that data is just not there. So, you cannot use that if the data is not there. And this is visible on this output as well. So, all the simple problems can be solved just by enabling this exporter and looking at that output. It's pretty simple to do it. But, of course, it shows how the data looks like

at the end of the pipeline and not how the data was processed through the pipeline. So, if you need more details on that, we definitely going to need to use another tool, which are the debug logs. And yeah, debug logs are the best tool for troubleshooting tricky OTL issues. To enable that, we just need to set change our collector config and set service telemetry log level to

debug. Optionally, we can also export those logs to some OTLP back end so you can be querying them or storing them on your vendor tool. Uh, those logs they provide an audit trail of your data which means they're going to provide step-by-step what happened on the way. We're going to see this in action. Uh, so here we have uh, transform process configuration. This transform process configuration has

two statements. So the first one is just setting the server number to five which means debug. If the log body has the word here on it, yeah. And the second one is just setting the server text to unknown if the log that I'm manipulating has the server number equals to zero which means undefined. So running this config would produce a few log lines. So the first log

line we would see is the initial transform context before running any statement. But what's exactly is the transform context here? So the transform context here is the data that's being manipulated under the hood. So our statements is manipulating logs. So the transform context is the log fields. So we can see a snapshot of the data and we can use this later to compare and determine exactly what

changed. This is how the data entered the processor and you're going to get a line like that for every single data we modify on the processor. Second, after running the first statement, we're going to get a log that's going to show the statement that run. In this case, it was the first one setting the server number to five. Whether the condition matched and again the data. But

this time the data is after running that statement. So we can see what changed compared to the snapshot that we just got on the first And And lastly, we're going to get another log line for the second statement that we have configured. So, different from the previous one, this one didn't match the data, and we can see that on the condition matched the field. Um When the

value is false, it means that the transformation or that the set function that we have there on our statement didn't run, which means that the data didn't change. And as expected, as my wear condition there is looking for, it's a wear number equals to zero, and as I can see on the transform context, my wear number is equals to five. Cool. This pattern, as I mentioned before,

we repeat for every statement that I have on my config and for every data that I'm currently transforming on my processor. Finally, the last two uh we're going to see today is the OTL playground or OTL.run. If you're not familiar with these two, it's a web UI that you can experiment with OTL, the transform processor, processor, and uh you're going to get uh visual diff comparing the

data and the change out of the box. You're going to get debug logs. And all of that, you just need to paste a config, some example, and you're going to be able to run that. You don't need to run a collector. And the most important, that's built using web assembly, which means that we get the the collector code, we compile that, we make that available to the

browser, so we can run and get exactly the same results as running a live collector. All right. It's uh the exciting time of the talk. It's demo time. Just remember that you use the right paths, otherwise you're going to have And let's check >> Should I zoom in some? Let's zoom it in a bit. >> Can you see this? Well, should I zoom in a little bit?

A little bit more. Yeah. Okay, first example. Uh in our log statement pretty basic one, we've got a set function. We want to change our log severity. We want to set it to 17, which is error, uh whenever our log body contains the string error. pretty simple OTTL statement. Uh in this particular scenario, we've got uh two logs and we expect both logs to be changed. Let's

run and see what happens. We only get one log changed, right? So, we expected two things to change. What is wrong with my condition? What's happening? Why didn't Why didn't it match? Why Why isn't my statement running correctly? Pretty common OTTL debug scenario. What we want to do is want to take a look at the execution logs. Uh we've got the debug log turned on. We want

to look at those. We're going to do that in the OTTL playground because it's really convenient for this demo, but please use OTEL the the collector's configuration declarative configuration support. You can You can tell the collector in YAML how to export all of its telemetry, its its metrics, its logs. Use that declarative support. Send all the telemetry somewhere else. Send it to your favorite back end. You

don't actually have to look at these things in a console like we're about to. Uh that's a relatively new feature. Uh it's incredible. Definitely use it. But for now, we're going to look at them in this browser cuz it's faster for live demos. We're going to take a peek at the These are the logs that the collector uh emits when we've got debug turned on for for

OTTL. Again, you can export these. Uh that would be the best way to do it. And we want to We are interested why is our condition not matching? So, going to highlight things. This is our transform after execution. We know that the second log is wasn't transformed, so this is the log we want to look at. Let's look at the condition matched or not. Let's Let's make

sure this isn't like some problem in OTTL. We can see that the condition did not match. Okay, so our condition didn't match, so the statement doesn't run. That matches with OTTL, but that's not matching with our internal data model of what's happening. When we are debugging OTTL, the most important thing to do every single time is to check the assumptions we're making about our data. Does the

data look in like we think it looks? Uh in our case, our assumption is uppercase error, right? Our statement was is match uppercase error. So, our assumption is that our bodies will have uppercase error in the in the string. What does our body actually have? Lowercase error. Lowercase error is not the same as uppercase error, right? Maybe in our back end, however we're viewing this data, maybe

how we got the log bodies, whatever it wasn't working. Uh they're displayed as all uppercase or something. That doesn't matter. What matters when you're using OTTL is how the data looks in the collector. And in this case, the collector is telling us it's a lowercase error. Our condition was never going to match. We were never going to get the transformation that we wanted. Uh in this case,

there's many different ways to solve the problem. The fastest one for me to type out is to do some case-insensitive regex matching. So, let's do that. Switch back to our visual diff. Run it, and we can see now we're getting Okay, example number two. Another pretty common situation. We have a a payload, a logs payload again. And in this case, we have a string in our body

that is a JSON string, right? Pretty common situation. We want to parse that. There's a value in there we want to use for our actual log body. It is elapsed time. And that's what we want to be our log body. We don't want this JSON string. So, we're going to use OTTL to do some some data transformation, clean up our logs, pretty common situation. So, we're going

to use the parse JSON function. We're going to parse our body. We're going to set it into the cache. The cache is a great place to store information in between statements. You can reuse it. And we're going to then grab out the log the body from from the parse JSON string. We're going to use that to set the proper log body, right? Uh let's run this and

see if it works. It did not. What is this? This is not a string. This is some complex object. How did we get here? let's use the playground's debug capabilities and step through each one of these line by line. So, we switch back to our execution Here we have stopped. We are right about to run a statement. Let's step over. We have now run the first statement

and we're waiting at the second statement. Let's investigate what happened. Down here is our again, our after statement execution log. We can see that our conditions match cuz there was no condition, so we're definitely just running our transformation. We parsed our JSON. We were messing with the cache, so what does the cache look like? Here's what the cache looks like. It looks like the cache is a

map. It's got one entry in it keyed on body, and then the value of that entry is a complex map. That makes sense because we just parsed a JSON string. The result of that is a map. Okay, sounds good. If we look closer at this, uh we can see that cache has a key called body. And if we look at our statement again, well, we were keying

on that body. That's not the body we want. We want we want the body that's inside our map. We want this body. That's what we were trying to get out. Looks like we've written our statements incorrectly on this one. So, there's again, there's always many different ways to solve problems with OTTL. In this case, the way I'm going to solve it is to just not add an

extra key. You don't have to do that. You can set the cache directly with another map. That's what parse JSON's providing. Now, we can go back to our visual diff, get rid of our breakpoint, see if this fixes our problem. And it does. We can see we have set the string value based on that internal parse JSON map correctly. All right. For the next example, we're going

to be promoting some attributes from my log. The attributes are the address, and I want to move that into my resource. It's pretty simple, so I'm going to just hit the run button and let's see how it shows. All right. So, looking at the results, I can see a new attribute there, and it has some IP address assigned to that attribute, which looks correct. But this time,

instead of diving to the debug logs, I wanted to think a little bit on the data we are manipulating here. So, we're copying data from the logs, and we're setting that on the resource. So, going back to the log data module, uh we know the resource might have multiple logs, and that I log belongs to a single resource. So, the question I want to ask you now

is, what would happen if this resource has multiple logs, and those logs have different values for the server.address attribute? Yeah. That's a tricky question, actually. Uh and the answer is surprising sometimes, but the value of this new attribute will be randomly assigned. And that's because the data we are manipulating here, resource, is shared among all the logs. So, while processing a log, if I change that data,

it will be visible to all of them. And you need to understand that. The data is live. The shared data is live. So, to illustrate that, I got to quickly change this from set to append. So, the append will keep all the values that it sees while processing those logs. So, let's run and let's see how the diff shows. Yeah. So, now we can see we got

two different values there. so, in fact, the value is not randomly assigned. We are just replacing that over and over again. Every time I see a new log and I set that field, that value will be the one that persists. The last one wins. And And this is really important because this is a very, very common issue uh that happens in all GTL. And you need to

take that into consideration. You need to take that uh how big data works into consideration when writing those statements. This same issue might happen to other signals as well, like metrics and data points or span span events. So, yeah, be careful whatever you're promoting those attributes up. So, for the last example, um uh today, we want to add some metadata data to my metric. I want to

add the type of metadata to my metric. I just want to flag the metric as histogram. If the type of my metric is a histogram, uh so, I going to click on the run And I going to take a look at the data, but I going to mark this option so I can see the unchanged data. Well, looking at the data here, I can see that we

got a new metadata added to my histogram and that's indeed a And I can see that I have another metric on this payload, which is a counter. And I didn't get any metadata to that metric, which looks correct. So, we can conclude that this transformation is correct. The output is correct. But, something feels off on this uh config. Let's take a look into the logs. But before,

just pay attention to this small number on the top of the screen. So, this is the execution time of this it's definitely not precise. It's just an estimation because we are running WebAssembly. We have some overhead added by the playground, but it's still very useful to understand how good or bad my statements are or or to compare the performance between two versions of the same Uh so,

yeah. So, let's take a look at the log. I think we can optimize this somehow. So, looking at the logs, we're going to see hundreds of logs of the after statement execution, yeah? So, it doesn't necessarily mean it's a problem. It just means that we are processing a lot of data. But we know it only have two metrics, so why I'm processing a lot of data here?

So, let's go back to the config and let's take a look. We are accessing metric metadata path here. All right? And we're filtering by the type. So, it's all about metrics, but for some reason I have data point configured here. When I use the data point context, I'm asking OTEL to go through all the metrics that I have on my payload and then go through all the

data points those metrics have to then run this statement. Well, it definitely doesn't make sense. I'm just changing metrics. I'm not using any data point value here. I don't need data point at all. so, I'm going to do experiment here. I'm going to remove the context config. And when I do this, I'm enabling a feature called context inference. So, when I do this, OTEL will look at

my statements, will check the data paths that I'm using, the functions that I'm using, and will determine what's the best context for running it. So, let's if the performance has changed a bit. Yeah. We can see now that I just got two uh logs of the after statement execution, meaning that we run that twice, which is expected as we have two metrics only. And there's an extra

log here that shows the context that it was inferred for my statements, which is metric, and it's correct. And looking again of the execution time, it dropped from two to three milliseconds, which is way faster. So, the conclusion here is uh choosing the right OGT context ensure we are changing the right data, but also ensure we are doing that as efficient as possible. So, if you don't

have any specific reason to choose some specific context, don't do that. Just leverage the context inferer. Even if you change your statements in the future and you add more data paths, the context inferer will adapt and will choose the best context for you. All right, so the key takeaways of this session. The first one is OGT works on P data, we must understand it. We have been

saying this for the whole presentation. I cannot stress this enough. You need to understand the data that you are manipulating, otherwise you won't get the right So, go there, read the data model aspect, and understand the data you are changing. And even before writing any statement, just inspect the data that's passing through your collector. Check how the data looks like. You can do that just enabling the

debug spot. It's pretty simple, and you're going to give some overview of the data, and you're going to be able to spot any problem that you might have there. But if still going off the rails, enable the debug log. They are very powerful. OGT has really good debug logs, as you saw, and they definitely going to shed some lights on the issue. And finally, experiment safely, test

all the edge cases, failures, play with that. You can use the playground for that. It's a nice tool for this use case, and you're definitely going to be deploying your transformations more confident doing that. So, here we're going to leave a few links as well. If you want to know a little bit more about OTTL transform processor, OTTL, just scan them or take after the presentation the

download. Um yeah, thank you. We'd We'd love feedback on the presentation, and also if you have any questions, uh now is a great time. We have at minimum 5 minutes, but I don't think there's a presentation after us, so uh We'll also be around all week uh if you want to ask questions in person and you don't feel comfortable asking now. 1 2 1 2. Great presentation.

Thank you very much. I have a question. Is it possible Is there approach to have this transformation somehow in a CICD pipeline? So, you have some unit tests so that you can check what is the you know, some example payload, and it goes through the OTTL language and check if it gets the output. I guess you maybe already have some reusable Go components for do that or

not yet. Uh so, OTTL, although it's like primarily made for the collector, it is ultimately a package that's exposed in contrib, and it can be imported other places. Um it is extremely restricted to the Pdata library. Like, you'll you would need to import Pdata as well, and and anything that you'd want to send it through it would need to be Pdata, but it can be used outside

of the collector if necessary. Um as long as you can get the data into the shape that you need. I've never used it for CICD pipeline like the what you described specifically, um but the library is available, and you could you could give it a try. Awesome, thanks. Is turning on debug logs for the whole collector obviously means that every component now has debug logs on and

that means it's very busy. Have you considered a mechanism by which or is there a mechanism already to just turn on for one transform processor the debug The collector is all or nothing. It does not have a mechanism at this time to turn on only a single component debug logs. Um Could could Could it? TTL could could transform processor just circumvent circumvent the logger. We could use

its own logger. We'd have to make our own logger. Yeah. Um It's kind of components really shouldn't do that. There's nothing stopping us from doing that like the go code would allow it. We'd have to make sure that like we're not circumventing other things like other expectations that users have when they're when they're emitting telemetry from the collector. Um but we could talk about it. Okay, if

there's no other questions or if you want to ask questions later we'll be around the conference this week. Thank you.