Contextual information about APEX Debug Path Info

Contextual information about APEX Debug Path Info

Where to start? I guess right here...

Someone approached me at a conference and were explaining that their application was experiencing performance problems and if I had any tips to understand what was happening.

My go-to answer is to get that Application in Debug Mode. Work out whats happening and resolve it from there.

Safely back home, I was mulling over the question, potential answers, and I decided to research further. It didn't take long before I found Michelle's blog on 15 Top Tips to tune your Oracle APEX Performance. This blog is awesome 🤩, a first-class read, its so well written and the tips are really helpful. I recommend you read it right now.

OK. Finished reading Michelle's blog? There was one thing that piqued my interest and that was tip number 3: The #TIMING# substitution variable.

I decided to investigate further, after all, #TIMING# appears as one of only 2 tips on the Best Practices to Improve Performance page of the official APEX documentation. Did you know there was such a page?

On this page it says:

Improve performance by using bind variables and including a #TIMING# substitution string in the region footer.

I'm interpreting this as.... Improve performance by:

  • Using bind variables

  • Including a #TIMING# substitution string in the region footer.

I'm really not sure how adding a string in region footer will speed anything up... If it actually did, then wouldn't it be applied to all regions by default? 🤔 ... however, for now, lets assume that the #TIMING# substitution string has some magical performance enhancement powers (spoiler: It doesn't).

But what is a substitution string? In the documentation, in section 3.10.4, It lists all the Substitution Strings.

If we scroll down to where TIMING should be (things are roughly in alphabetical order, but not 100%)... its absent.

So is it a Substitution String or is it not?

Lets try it out anyway. I have a couple of charts on a page, so I add #TIMING# to the Footer Text of each region one-by-one because its not possible to bulk select multiple regions and change all the Footer Text all at once.

There we go. Lets run the app. The app contains 2 identical charts with the same SQL. One is called Employees, the other is called People.

We have timings on both charts. Both are 0.00. So basically the same, wouldn't you agree?

Well... OK. I now, know my charts take 0.00 seconds. Why only 2 decimal places though? the debug shows 5 decimal places 🤷. Also who is the intended audience for this? the Developer or the User? What's the User going to do with this information? Not a lot to be honest. I'd argue this is Developer/Debug Information.

In Jorge's blog, he provides CSS so that its hidden from the user, and only revealed when Show Layout Columns button on the APEX Developer Toolbar is clicked.

I'm agreeing with Jorge, that this is developer information only and should be shielded from the user.

But whats this X link at the bottom of Jorge's blog?

Wait, What? I thought pretty-much most of APEX was AJAX data loading components. This is devastating news for #TIMING# 🙈

Lets check out what Peter says. Let's change the People chart, so that it delays for 6 seconds by changing the source to PL/SQL Function Body returning SQL Query.

DECLARE
  v_start_time TIMESTAMP;
BEGIN
  -- Store the current timestamp
  v_start_time := systimestamp;

  -- Loop until 3 seconds have passed
  WHILE systimestamp - v_start_time < INTERVAL '6' SECOND LOOP
    NULL; -- Do nothing, just wait
  END LOOP;

  -- Your SQL query
  RETURN q'~
    SELECT EMPNO,
           ENAME,
           JOB,
           MGR,
           HIREDATE,
           SAL,
           COMM,
           DEPTNO
      FROM EMP
  ~';
END;

Lets give it a run

The People chart is taking 6 seconds to run, but the timing is 0.00 seconds. When the Chart finally displays (after 6 seconds), lets look at the debug.

Ah Ha. The true timings are all in the debug!

Whats happening, is that its takes 0.00 seconds to render the frame of the region and 6.0216 to fetch the data.

Proof - Timing is useless 😃

I can't just leave it like this... I want to fix #TIMING#, but how?

  • The true timing is only kept within the ajax plugin debug (see above)

  • But that only works when debug is on

  • If debug is off, it's not workable.

  • Even if I extract the real timing and transplant it in to the region…

    • #TIMING# is really debug anyway (see Jorge's blog)

    • All Region templates are different, so transplanting it into a consistent place will be grueling to develop

    • Do the users even care about true-timing?

  • Should I even bother? Should I just log it as an APEX Idea?

If only I could fix the Path Info, to make it more descriptive 🤔

Only the APEX Team can do this though.

A solution is in the form of the AjaxIdentifer is right there in debug. You've probably seen this a 1000 times without noticing its ever there.

Here is it, right in the middle of the picture below, prefixed by Run PLUGIN=

if I can match this AjaxIdentifer with...

...Dynamic Actions through apex.da.gEventList...or...

...Page Source where APEX elements are initialized...

...then I know which Debug Log is associated with each APEX Component 🎉

As I said, I have no control over the APEX debug, but I do have Pretius Developer Tool & that already has a Debug page... so I by examining the Debug Logs and using some insane regular expressions, I can parse out all the AjaxIdentifers, and then associate the AJAX Plugin Debug Logs with the APEX Components 🤓

I'm talking this level of regular expression insanity.

/apex\.widget\.tree\.init\s*\(\s*'R([^']+)_tree',.*?"regionStaticId":"([^"]+)",.*?"ajaxIdentifier":"([^"]+)"/g;

All this has now been coded into version 23.2.2 of Pretius Developer Tool and is totally free to use.

Lets see the final work in action.

The above picture is Pretius Developer Tool, showing clearly the association between AJAX Plugin Debug Logs with the APEX Components. As you can see from the new Component column, the People Region takes 6.0235 seconds and the Employees Region takes 0.0216 seconds (not 0.00 seconds).

This functionally works on the majority of components, here's the Dashboard Feature page

Its also supports items too i.e Combobox, facets, radios, etc. You'll need to check the readme file for a full support list. However due to some inconsistencies in APEX, some components fail to log the AjaxIdentifer in the debug... making this approach impossible to support the following

  • Reports: IG, Cards

  • Items: List Manager

  • Regions: Dynamic Content Regions, Template Components

Perhaps the APEX Team could fix this in a future release?

Here is another screenshot showing Dark Mode support, Plugin Support, Execute Server Side Code Dynamic Actions and Region Display Selector.

Notice that debug logs are grouped by page load, so that you can see exactly when happens after each page load.

Do check out Pretius Developer Tool, as it does provide much more functionality. Including

  • Revealer: Displays client and session info that is not immediately available to you as a developer

  • Reload Frame: Provides you with a convenient single click for reloading a modal dialog page

  • Visual Build Options: Glows page components in blue/red, giving you a visual clue on whether a certain component will be included/excluded on export

  • Developer Bar Enhancements

    • Quick Page Designer Access: Use a keyboard shortcut to quickly navigate to any Application & Page in your workspace

    • Glows the Debug Icon red when Debug is on

    • Shared Components icon appears on the Developer Bar (replacing the Home button)

ENJOY!

Whats the picture? It's Bilton Viaduct which carries the Nidderdale Greenway