Good News and Bad News, Pivot and Turn - Building DDTJ Day 6

Last week I spent 5 days building and designing the DDTJ project. Hopefully, Ill complete the MVP by this weekend. As we left the series last week, I was stuck. This week theres a bit of an improvement

There are a lot of variations on the good news/bad news joke. Im sure you all know some form of it Heres a programming oriented one:

developer: so i have good news and bad news

manager: what's the good news?

developer: i've discovered that the "5 second rule" only applies to food

manager: and the bad news?

developer: i dropped our tables

Kat Maddox (@ctrlshifti) January 21, 2021

In that spirit, Ive made some progress and we are now collecting some data The bad news: I had to throw away a lot of concepts and performance is roughly 700x worse than without our instrumentation. Ugh.

How did I get Here?

Last week I was still modeling the objects stored locally when debugging the remote VM. As you may recall, the debug API needs to copy objects locally so we can later on analyze them. We cant leave this in the target VM as the data will get lost as the VM continues.

I created a data model and implemented a debugger of sorts that effectively automatically debugs the application and stores all the data. Unfortunately, this isnt as simple as one would hope.

Initially, I thought Id use the step over API to review individual lines. This includes some problems:

• I dont know what a line contains without looking at the source/bytecode and I dont want to get into that complexity
• I cant have two instances of a step over monitor at the same time. This is something Ill need for nested method calls, threads, etc.

So using the approach of stepping over code isnt practical for this tool

Method Enter/Exit

Luckily, pretty much any debugging API supports setting a method enter/exit event. This lets us monitor all the important points and log all the relevant information. Perfect Almost

Heres the problem, say we have code like:

public void myMethod(int x) {    otherObject.otherMethod(x, y);}

Ill get 4 events for this sequence:

Method enter to myMethodMethod enter to otherMethodMethod exit on otherMethodMethod exit on myMethod

So far, so good. But heres the thing. I need to log the invocation of otherMethod inside myMethod so I can mock that later on.

How would I do that?

We need to analyze the data and see the data related to myMethods call hierarchy.

The solution is to somehow know that the enter event and the exit events are related. Initially, I tried to create the exit event dynamically and restrict it to a specific object instance. But that fails with recursion.

Ive tried several approaches. I now have one that works, but it isnt ideal

The Current Approach

I create a uniquely repeatable string when method entry occurs. Its built with roughly this formula:

threadId + object instance id (if not static) + frame count + callstack

This is a relatively long string, but its unique. We place an object in the map with this as a key when entering a method. Then, when exiting the method, we find the object using an identical key.

We can now connect the method entry/exit and as a result log all the data we need.

Performance

Unfortunately, that isnt enough. 700x is way above a reasonable 10x or bearable 20x reduction in performance for a debugging environment. Normally we need to stay away from premature optimizations, but if theres a conceptual flaw in the architecture, we need to understand it. 700x isnt something we can realistically work with.

So my next focus is to get the current code in shape for a pull request and then move on to understand the performance implications and what exactly causes this overhead.

I have a lot of theories on the subject, but experience taught me to ignore them. A lot of times, the things we think are expensive turn out to be a tiny bump. The things we discounted end up being the big penalty. A profiler will tell us where time is wasted and I can evaluate based on facts. Right now I dont want to look. If I do, I wont be able to stop and its important to stop, synchronize with the trunk and move iteratively.

Tomorrow

This has been a short post since Im still pretty busy getting the PR out and bringing the tests up to speed. Once its done, I hope to get to the profiling session.
At the current rate, I think my initial goal of having a tool that can generate tests for spring boot might be high for this week. Ill lower the expectations to debugging a hello world application and generating a simple test case. After everything Ive been through with this API, it seems like a pretty ambitious goal too.

If you want to keep up with the latest updates on this series and the many other things I work on then follow me on twitter.