An APEX application is basically a group of pages that are linked together via buttons, hyperlinks, tabs, etc. When a user navigates through the application, submits data, or requests to view an APEX page, there are actually two phases that the APEX engine goes through to provide the correct information back to the user:

The reason these phases are important to debugging is that APEX breaks down the logging of debug information into these same component parts. When the application server tier connects to the Oracle database that contains the APEX installation, it grabs a connection from the database connection pool and uses that to service the user's APEX request. You see this sequence in Figure 6-1.

Figure 6-1. Simplified APEX request/response

Phase one (ACCEPT) of servicing the user's requests is to process the current page and the user's input. Because the state of the connection from the pool cannot be guaranteed to match the requirements of the user's APEX session, the first thing that APEX does is to alter the session, setting the desired NLS parameters and session settings. Figure 6-2 shows this portion of phase one processing.

Once the database session is in the proper state, APEX then begins checking to see if the APEX session is still valid, whether the user has authorization to run the page, retrieving session state from the APEX data dictionary tables, setting session state that may have been altered by the user, and then running the page processing components as defined in the metadata.

The last steps of the processing is to decide which programmatic branch to take, which in turn decides which page will then be rendered and sent to the user. APEX always takes the first branch whose condition evaluates to true.

Figure 6-2. APEX page phases

Phase two (SHOW) is to render the page identified by the branching section of Phase one. Because it is possible for page rendering to be called directly via a URL, this phase also walks through the process of altering the database session, retrieving the APEX session state from the metadata tables, and executing any required security checks. Figure 6-2 also shows phase two processing.

Once everything is set, APEX then walks through the process of rendering the page as defined in the APEX metadata and presenting that page to the user via the application server. Once the application server sees that the original request has been fully satisfied, it returns the Oracle database connection back to the connection pool to be reused.

The two phases can be mapped directly to the page definition screen as indicated in Figure 6-3. Furthermore, each step is timed. Time is measured from the beginning of the current step to the beginning of the subsequent step. When debugging is turned on, these times are saved into the APEX Dictionary along with the step detail.

Figure 6-3. Mapping the phases to the APEX page definition

The two-phase process of ACCEPT and SHOW iterates as the user navigates through and uses an APEX application. At some point, you may run into issues in development where you want to see exactly what is happening during the execution of either one, or both, of these phases. This is where APEX Debugging comes in.

APEX Debugging indicates to APEX that it should emit information about exactly what it's doing during each of these phases. Unlike earlier versions, APEX 4 does not emit the debug information into the page being processed or rendered, but instead stores the full debug information in a set of tables in the APEX schema.

The 4.0 approach is superior in that the debugging information persists beyond the lifetime of the rendered page so that you can view and analyze multiple runs of a single page, comparing and contrasting their debug output to see how changes you may have made might have affected the processing or performance.

Turning interactive debugging on is a very straightforward process and can be done in one of two ways: via the Developer Toolbar or via the URL. The Developer Toolbar will be visible if you are running an application while you are also logged in to the application's parent workspace as a developer. Figure 6-4 shows the Developer Toolbar and highlights the Debug button, which toggles Debug mode on and off.

Figure 6-4. APEX Developer Toolbar highlighting the Debug button

You may also enable Debug mode by setting the DEBUG component of the APEX URL to YES. Following is both the URL syntax and an example of using the debug component to enable debug:

http://server/apex/f?p=App:Page:Session:Request:Debug:ClearCache
:ItemNames:ItemValues

http://server/apex/f?p=100:1:23929384838429::YES:::

However, it is important to note that the ability to use either of these methods is controlled by an attribute in the application definition. Editing the application properties and navigating to the Properties region on the Definition tab will allow you to turn the ability to interactively debug on or off. By default the attribute is set to disallow interactive debugging.

Figure 6-5 shows the Properties region and indicates the debugging attribute that should be changed in order to allow interactive debugging.

Figure 6-5. The Properties region of the application definition where interactive debugging is enabled or disabled

While it may be slightly confusing, once debugging is enabled via either the Developer Toolbar or the URL, the page will refresh but you will notice nothing externally different about the page per se. Just remember that APEX 4 stores the debug information in its data dictionary tables and does not emit it into the page being debugged.

There are two visual clues that will help you recognize when debug mode is active. If the Developer Toolbar is visible, the text of the debug button will now be changed toNo Debug, as shown in Figure 6-6. Even if the Developer Toolbar isn't visible, the URL will contain YES in the debug position.

Figure 6-6. Developer Toolbar with debug enabled

Once Debug mode is turned on and you have executed the steps you wish to debug, such as running a report or submitting a page, you will then want to view the debug information that was captured during your session. There are a couple of different places where you can do this.

Developer Toolbar

It's probably most common to want to view the debug information for the page you're currently running immediately after turning debug on. To do this, we again use the Developer Toolbar and click the View Debug button. A pop-up screen will appear which lists all of the page views for the page you are currently running. Figure 6-7 shows an example. The pop-up screen presents a high level overview of all the "Views" (or debug sessions) that have been captured for the current page. This is actually an interactive report with a filter set to show only views for the current page in the current application. You can alter the filters to show whatever combination you wish.

From this screen you can click on the View Identifier link to drill down into each view and see the detailed steps that APEX took to process and render the page. Figure 6-8 shows the detailed view for View ID 134.

Figure 6-7. View Debug pop-up window showing all debug views for Page 1

Figure 6-8. Example detailed view of a debug session for Page 1 in Application 106, View ID 134

From the simple high-level view shown in Figure 6-8 we can actually see some interesting things. We can see the timeline of debug views that have been created for this page by looking at the Timestamp column, the duration of each view by looking at the Seconds column, and the number of detailed debug entries for each view by looking at the Entries column.

Examining this particular example, we can see that three out of the four views processed in well under one second, while the fourth (View ID 132) took approximately 140 seconds to complete. This brings us to the discussion of a slight anomaly in the data presented in this overview report.

Remember that there are two phases involved in processing a user request: ACCEPT and SHOW. The APEX debugging engine stores these two phases as separate "views" in the debug data. Drilling down into Views 131, 132 and 134 by clicking on the View Identifier link shows us that each of these represents the SHOW phase of page processing. View 132, on the other hand, represents the ACCEPT phase.

We know this by looking at the first line of the debug output, where we see either the word SHOW or ACCEPT.

Looking back at the overview report, there is no way to know by viewing only the overview data which views represent a SHOW phase and which represent an ACCEPT phase. While this is slightly annoying and unintuitive, don't be too disturbed by it. We'll see later that we have access directly to the detail data via an APEX Data Dictionary view and there are things we can do there to identify one from the other.

The details page shows the data in two formats. First is the histogram graph across the top of the page. In this histogram the bars represent the duration of each step in relation to the single step with the largest duration. The second is the actual report that shows the details of what was executed during the phase execution.

Hovering over any of the bars in the histogram with your mouse (as shown in Figure 6-9) will show information about the step represented by that bar. Clicking on that bar will scroll the screen so that the detail line represented by the bar will come into view in the window.

Figure 6-9. View Detail Histogram showing hover hint

The detail report is, again, an interactive report allowing you to create filters and manipulate the data in many different ways. The first row of the report, when sorted by Elapsed time or Row, will identify the base information about the current view, including the phase, application number, page number, workspace, request, and session. This will help you identify exactly what you are looking at. The subsequent lines show the individual steps taken to complete the phase being executed.

The detail report also has a column labeled Graph that mirrors the histogram that appears at the top of the page. This visual clue will help you scroll down the detail report and easily identify those steps that took the most time during the phase execution.

The actual detailed steps that appear will vary from page to page and also between the ACCEPT and SHOW phases. However, they will generally conform to the broad sections outlined earlier in Figure 6-2.

Navigation between the different detail views can be achieved via the navigation region at the top of the detail page as presented in Figure 6-10. If you know the View ID, you can simply type it in the Page View Identifier field at the top of the detail view page and click the Set button. If you want to return to the high-level view page, click the Select Page View Identifier button.

Figure 6-10. The Debug View Navigation region

Clicking the Reset button will return the current report to its default settings, resetting any filters you may have implemented.

Application Utilities

Another place to view debug information is via the application utilities. These can be reached by clicking the large Utilities icon on the main application edit page (as shown in Figure 6-11) or by clicking the small Utilities icon in the quick menu in the upper right of any Application Builder page (as shown in Figure 6-12).

Figure 6-11. Utilities icon on the Application edit page

Figure 6-12. Utilities icon from the Quick Links menu

Clicking either icon will take you to the Application Utilities page. From here, select the Debug Messages icon (as indicated in Figure 6-13).

Figure 6-13. The Debug Messages icon

You will be presented with a high level report identical to the one you see when accessing the data from the Developer Toolbar. The difference is that the report initially shows all views for all pages in the current application. Using the Interactive Report Capabilities, you can filter the debug views to display only the ones you're interested in.

Drilling down will take you to the detail report, this time without the histogram across the top. Apart from this small change, all of the data is the same that you would see via the Developer Toolbar.

Navigation in this version of the report is slightly different. Here you would use the APEX breadcrumbs to navigate between the Debug and Debug Message Data pages to select the desired views as shown in Figure 6-14.

Figure 6-14. Breadcrumbs for the Debug Messages utilities

Another change to the utilities based Debug view is the addition of the Purge Debug Messages button. This button allows both workspace administrators and developers to purge underlying debug data for the currently selected application based on certain criteria. The available criteria are

Purge all messages: This option will purge all data for the selected app that currently resides in the underlying debug tables.

Purge messages by age: This option allows you to select a time frame for which to purge, from 1 day to 4 weeks.

Purge current session messages: This option allows the purge of messages for the currently active user session.

Purge by View Identifier: This option allows the purge of messages related to a specific View ID.

Warning

When purging data be aware of what other developers are working on within the workspace and application. It is possible to accidently purge data that may be important to other developers.

APEX 4 uses AnyChart 5.1 (http://www.anychart.com) as its graphing and charting engine. While the APEX team has done a wonderful job of hiding the behind-the-scenes complexity of how charting works, there are times when you may need to dig into the details of how charts are being rendered.

As you learned in chapter 2, everything you change on the Chart Attributes page of a given chart's definition ends up creating an XML document that determines how the chart will be drawn. You can, if you wish, edit the XML manually to make changes that are not available via the Chart Attribute options.

Although you can get a good feel for the XML that will be generated, you cannot guarantee what that XML will look like until run time. To be able to view the full run time XML, prior versions of APEX required you to use third-party, browser-based debugging tools. APEX 4, however, has made things much easier.

When Debug mode is on, each chart will contain a link that will allow you to view the XML that was generated to drive it. Figure 6-15 shows a line chart with the Show XML link visible in the lower left-hand corner.

Figure 6-15. Chart in Debug Mode with Show XML link

Clicking this link will display the full runtime XML that was generated to drive the chart. This is useful for debugging manual changes you may have made to chart XML, or to view how the data has been emitted into the XML from the series queries you have defined. Figure 6-16 shows an example of the generated XML.

Figure 6-16. Generated runtime XML for a chart

While Interactive Reports give an amazing amount of power to the end user, debugging them can be a bit challenging due to the fact that APEX basically rewrites the query behind the scenes based on the user's column selections, filters, and more. Enabling debugging on an Interactive Report page will emit the SQL that is generated for the current incarnation of the Interactive Report into the debug data.

Consider the two debug snippets shown in Figures 6-17 and 6-18. Both snippets are from the same interactive report.

Figure 6-17. Debug data for the default version of an interactive report

Figure 6-17 shows the detail debug data for an Interactive Report region prior to a user having made any changes to the report. You can tell the following from the figure:

Figure 6-18. Debug data for the altered version of an interactive report

Figure 6-18 shows the detailed debug data for the same Interactive Report region after a user has made changes to the report, as indicated in Figure 6-19. The changes indicate that we are filtering the ASSIGNED_TO and grouping by the STATUS.

With this debug data you have enough information to not only troubleshoot, but also examine the potential performance of the query that was generated.

Figure 6-19. The filters applied to the altered report

The core debugging API exists in the form of the APEX_DEBUG_MESSAGE package. This package is fairly undocumented and, at the time of writing, does not appear in the API reference nor does any mention of it appear in the APEX Developers Guide. Following is brief documentation of the individual procedures that appear in the API. We'll discuss their usage further in later sections.

procedure enable_debug_messages (p_level in number default 7);

apex_debug_message.enable_debug_messages(p_level => 7);
apex_debug_message.log_message('S H O W --- Programmatically enabled'),

procedure disable_debug_messages;

procedure remove_session_messages(p_session in number default null);

procedure remove_debug_by_app (p_application_id in number);

procedure remove_debug_by_age (
    p_application_id  in number,
    p_older_than_days in number);

procedure remove_debug_by_view (
    p_application_id  in number,
    p_view_id        in number);

procedure log_message (
    p_message in varchar2 default null,
    p_enabled in boolean  default false,
    p_level   in number   default 7);

procedure log_long_message (
    p_message in varchar2 default null,
    p_enabled in boolean  default false,
    p_level   in number   default 7);

procedure log_page_session_state (
    p_page_id in number default null,
    p_enabled in boolean  default false,
    p_level   in number   default 7);

As you can see, the APEX_DEBUG_MESSAGE API provides the facilities necessary to enable and disable Debug mode programmatically. And as mentioned in the preceding documentation, the ability to use programmatic debugging is not affected by the application level setting. This means that, even if you have a standard which dictates that applications are deployed into production with debugging disabled, you still have the ability to capture debug information.

Figure 6-20 shows the capture of debug information for a single page in an application that displays a simple report. The debug information was captured interactively by using the Developer Toolbar.

Figure 6-20. Debug data gathered interactively

Figure 6-21 shows a branch created to gather debug information programmatically. The branch was created at the earliest possible point on the page. The branch does not in fact redirect to another page, but instead simply programmatically enables debugging. Figure 6-22 shows the resulting debug data.

Figure 6-21. Definition of a Branch which programmatically enables debug

Figure 6-22. Debug data gathered programmatically

While it may be more natural to think that a Page Process might be the best place to turn on programmatic debugging, there is some method to the madness of choosing a Branch instead. No matter what its sequence number, Page Processes always execute after Branches and Computations. Therefore if you want to capture information about Branches and Computations in your debug output, you must turn Debug mode on before these items are processed by APEX.

The ability to create a Branch of type Branch to PL/SQL Procedure at process point On Load: Before Header that actually does not branch anywhere is perfect for our purposes. As long as its sequence number is lower than any other branch, programmatic debugging will capture all logged messages for any Branch, Computation or Process that follows it.

When debugging is turned on via the API, even at the earliest point possible, APEX will have already completed some of the steps involved in rendering or processing the page.

If you compare the interactive data to the data that was gathered programmatically, you'll notice there are a number of things that just don't get captured in the programmatic version. This shouldn't concern you too much as what is missing is directly related to core APEX code and not code for which you will likely be seeking to gather information.

However, one of the more important things that gets left out is the first line of debug information which indicates the phase. This is easily remedied by following the ENABLE_DEBUG_MESSAGE call with a call to LOG_MESSAGE, as shown earlier in Figure 6-21.

The same is true for the PROCESS phase as for the SHOW phase demonstrated above. When enabling debugging programmatically, there will be some things that get missed. In most circumstances, the missing data isn't significant enough to be concerned about; however, if you want to make sure you get all the data relating to a page, you're likely to want to enable debug as part of the page phase that is directly before the one you wish to capture.

For example, if you wish to capture all the details about Page Processing for a page, turn debugging on during that page's SHOW phase. Alternatively, if you wish to capture all information regarding a page's SHOW phase, enable debug as part of the processing phase of the page that branches to the page in question. If debug mode is already enabled prior to reaching the desired phase, even if it was enabled programmatically, the entire phase's information will be captured.

While having access to the debug information APEX emits by default is helpful, there will inevitably be times when you'll need deeper insight into what may be going on in code that you have written.

The APEX Debugging API provides methods to expand the depth of information being gathered. This is especially useful when you're trying to understand what is happening within PL/SQL that might be part of a Branch, Computation, or Process.

Logging Custom Messages

The LOG_MESSAGE and LOG_LONG_MESSAGE procedures are quite simple in signature; however, they provide an amazing amount of flexibility and functionality when it comes to gathering information about what's going on within your application.

The most straightforward use case would be one in which you might want to emit simple messages which mark the steps a piece of PL/SQL might be executing. For instance, marking the purpose of a simple code construct, like a loop, as in Listing 6-1.

Example 6-1. Simple Code Demarcation Using LOG_MESSAGE

BEGIN
--
APEX_DEBUG_MESSAGE.LOG_MESSAGE( P_MESSAGE =>'START - INSERTING 10000 RECORDS...'),
--
FOR I IN 1..10000 LOOP
    INSERT INTO PERF_TEST (guid1, guid2, guid3, created_on)
    VALUES (SYS_GUID, SYS_GUID, SYS_GUID, SYSDATE);
END LOOP;
--
END;

Enabling debug mode and running the page would produce the output as shown in Figure 6-23.

Figure 6-23. Using LOG_MESSAGE to emit a line into the debug information

However to ad real value it behooves you to mark not only the beginning, but also the end of each significant step as in Listing 6-2.

Example 6-2. Marking the Beginning and End of a Block of Code

BEGIN
--
APEX_DEBUG_MESSAGE.LOG_MESSAGE( P_MESSAGE =>'START - INSERTING 10000 RECORDS...'),
--
FOR I IN 1..10000 LOOP
    INSERT INTO PERF_TEST (guid1, guid2, guid3, created_on)
    VALUES (SYS_GUID, SYS_GUID, SYS_GUID, SYSDATE);
END LOOP;
--
APEX_DEBUG_MESSAGE.LOG_MESSAGE( P_MESSAGE =>END - INSERTING 10000 RECORDS...'),
--
END;

Remember that execution timing is measured from the beginning of the current step to the beginning of the subsequent step. These step boundaries coincide with the point at which a debug message is logged. Therefore surrounding a code block with calls to LOG_MESSAGE provides the extra benefit of capturing an accurate timing of all the code that ran between those two messages, as shown in Figure 6-24.

Figure 6-24. Surrounding code blocks with LOG_MESSAGE calls to capture an accurate timing

You have to be careful about your usage of the LOG_MESSAGE procedure, though. For instance, injecting a LOG_MESSAGE call in the middle of the loop would first create a huge number of log entries that you would be unlikely to want to wade through, and second, would potentially impact performance as you would be executing the full code path of the LOG_MESSAGE procedure 10,000 times.

That is where the p_level parameter comes in handy. Consider Listing 6-3. Here we've done exactly what was just warned against, but notice that the value for the level of the outer calls is at a higher level than that of the inner calls.

Example 6-3. Using P_LEVEL to designate the message level

BEGIN
--
APEX_DEBUG_MESSAGE.LOG_MESSAGE( P_MESSAGE =>'START - INSERTING 10000 RECORDS...', P_LEVEL=>5);
--
FOR I IN 1..10000 LOOP
    --
    APEX_DEBUG_MESSAGE.LOG_MESSAGE( P_MESSAGE =>'START RECORD '||I, P_LEVEL=>7);
    --
    INSERT INTO PERF_TEST (guid1, guid2, guid3, created_on)
    VALUES (SYS_GUID, SYS_GUID, SYS_GUID, SYSDATE);
    --
    APEX_DEBUG_MESSAGE.LOG_MESSAGE( P_MESSAGE =>'END RECORD '||I, P_LEVEL=>7);
    --
END LOOP;
--
APEX_DEBUG_MESSAGE.LOG_MESSAGE( P_MESSAGE =>'END - INSERTING 10000 RECORDS...', P_LEVEL=>5);
--
END;

Now when we choose to enable debugging programmatically, we can use the p_level parameter to decide to what level of message we wish to log. Calling ENABLE_DEBUG_MESSAGES with p_level set to 5 would only log the messages outside the loop. However, enabling debug with a message level of 7 would log both outside and inside the loop. Using this mechanism you can manage the level at which messages are logged and what level of log message you wish to capture.

Warning

Using Interactive Debugging from either the Developer Toolbar, or by manipulating the URL will always initiate logging to capture messages level 7 and above.

Lastly, using the p_enabled parameter of LOG_MESSAGE allows you to dictate that a message is important enough to always be logged, whether or not debugging has been enabled. Listing 6.4 shows the same code but injects a LOG_MESSAGE call in the top of the block that will always be written to the APEX Dictionary, regardless of the state of debugging.

Example 6-4. Using P_ENABLED to Always Log a Message

BEGIN
--
APEX_DEBUG_MESSAGE.LOG_MESSAGE( P_MESSAGE =>'THIS MESSAGE IS ALWAYS LOGGED...', P_ENABLED=>TRUE, P_LEVEL=>3);
--
APEX_DEBUG_MESSAGE.LOG_MESSAGE( P_MESSAGE =>'START - INSERTING 10000 RECORDS...', P_LEVEL=>5);
--
FOR I IN 1..10000 LOOP
    --
    APEX_DEBUG_MESSAGE.LOG_MESSAGE( P_MESSAGE =>'START RECORD '||I, P_LEVEL=>7);
    --
    INSERT INTO PERF_TEST (guid1, guid2, guid3, created_on)
    VALUES (SYS_GUID, SYS_GUID, SYS_GUID, SYSDATE);
    --
    APEX_DEBUG_MESSAGE.LOG_MESSAGE( P_MESSAGE =>'END RECORD '||I, P_LEVEL=>7);
    --
END LOOP;
--
APEX_DEBUG_MESSAGE.LOG_MESSAGE( P_MESSAGE =>'END - INSERTING 10000 RECORDS...', P_LEVEL=>5);
--
END;

Logging Session State

There are many instances when trying to debug a page where it would be beneficial to know specifically what was in session state. The LOG_PAGE_SESSION_STATE procedure will provide you exactly that information.

The API will emit information into the DEBUG logs, which shows the session state for each item on the designated page. Like the LOG_MESSAGE procedure, the LOG_PAGE_SESSION_STATE procedure lets you dictate what log level will be associated with the emitted log records, and allows you to decide whether to override the debug setting and always log the session state.

You can call the LOG_PAGE_SESSION_STATE procedure without passing any parameters and it will log the session state for the currently processing page at debug message level 7, but it will only do so if debugging is enabled.

Figure 6-25 show an example of the output of debug information that contains session state information. The session state information is specifically contained in rows 2 through 6 in the report.

Figure 6-25. Debug information containing session state information

The data contains a row for each item that appears on the page, whether visible to the user or not, and contains the item name, length, and value. While it may seem odd that the items are rendered not in the order that they appear on the screen, but in alphabetical order by item name, this is due to the fact that many of the new APEX Themes are DIV based and it is not necessarily possible to identify where they appear on the page.

You can also emit more than just the current page's session state, but to do this you will need to make an API call for each page you wish to include. Figure 6-26 shows an example including session state for Page 9 and Page 7.

Figure 6-26. Debug information including session state information for 2 separate pages

Debug data is stored as metadata in the core APEX schema and is split across two tables: WWV_FLOW_DEBUG_MESSAGES and WWV_FLOW_DEBUG_MESSAGES2. The data is exposed to the developer via a single APEX Data Dictionary View: APEX_DEBUG_MESSAGES.

While it may seem odd that there are two underlying tables, APEX uses this two-table setup in a number of places to keep a finite duration of data around. The table into which data is actually inserted is switched every two weeks. When the switch occurs from one table to the other, APEX truncates the table that it's switching to. This means that at a minimum it will have no data (i.e., no debug information has been gathered) or potentially up to 4 weeks of data. Figure 6-27 gives a visual depiction of this idea.

Figure 6-27. The view and underlying tables that hold APEX Debug information

You may feel that having at most 4 weeks of data available to you at any one time might be too limiting, and I would have to agree with you. If you want to keep more than that amount of data, you'll have to take matters into your own hands. Doing this is actually quite straightforward.

First, you'll need to create a local version of the debug data table that you control. The simplest way to do this would be the following:

CREATE TABLE MY_DEBUG_MESSAGES
AS
SELECT * FROM APEX_DEBUG_MESSAGES
WHERE 'X' = 'Y'

This will create the table without bringing any of the rows over. Then you'll want to copy only the rows from the APEX_DEBUG_MESSAGES VIEW over to your new table, but to make this something that can be run over and over, you'll only want to copy the rows that don't already exist in the table. Luckily the PAGE_VIEW_ID column gives us something unique to compare against. The following SQL statement will copy only the information that does not already exist in the table:

INSERT INTO MY_DEBUG_MESSAGES
SELECT *
FROM APEX_DEBUG_MESSAGES
WHERE PAGE_VIEW_ID NOT IN
  (SELECT DISTINCT PAGE_VIEW_ID FROM MY_DEBUG_MESSAGES);

To automate this process, you can include the above SQL statement into a stored procedure and set it up to run regularly as a database-scheduled job. And to make sure that you are always looking at the latest information, you can create a view that joins the data in your table with the data in the APEX view, as follows:

CREATE OR REPLACE VIEW MY_DEBUG_MESSAGES_V
AS
  SELECT *
  FROM my_debug_messages
UNION
  SELECT *
  FROM APEX_DEBUG_MESSAGES
  WHERE page_view_id NOT IN
    (SELECT DISTINCT page_view_id FROM my_debug_messages);

Now you have everything you need to duplicate the screens and reports that APEX provides you as part of the debugging interface. In fact, you can actually replicate it 100 percent by simply examining the code behind the APEX pages.

Now that we know where the Debug data is kept, let's have a look at exactly what is being kept. Table 6-1 lists each column and gives a description of the data it contains.

Most of the columns in the view are pretty self explanatory, but the relationship between the MESSAGE_TIMESTAMP, ELAPSED_TIME, and EXECUTION_TIME merits some discussion.

The MESSAGE_TIMESTAMP is very straightforward; it's merely the accurate timestamp of when the debug message was entered into the underlying debug message tables. To get a clear picture of the order in which things happened during a page SHOW or ACCEPT, simply order the rows ascending by the MESSAGE_TIMESTAMP.

The EXECUTION_TIME is calculated as the difference between the current Timestamp and the Timestamp from the subsequent record. So, in essence, it shows how much time had elapsed between the two records being inserted. You can see this calculation in the definition of the APEX_DEBUG_MESSAGE view. The view uses the LEAD and PARTITION functions to calculate the difference between the two timestamps.

The ELAPSED_TIME is something different entirely. This column is supposed to show the elapsed time since the beginning of the page submission or the page view. While logic might dictate that you should be able to perform some arithmetic using the Timestamp and the calculated execution time to arrive at the elapsed time, you'd be wrong to do so. APEX actually uses yet another mechanism (a function call in this case) to calculate the elapsed time since the beginning of this phase. Because the function call actually takes some time (even if it's microseconds), the timing of the elapsed time is always just a little off from what you might expect. Don't get hung up on this. They are usually within such a small tolerance that it's fairly unmeasurable unless the task you are tracking is huge.

And in any account, what you really should be paying attention to is EXECUTION_TIME. If you want to find what you need to performance-tune within your page, pay attention to the thing with the largest execution time.

The fact that you have direct access to the data, and now know how to keep the data around for longer than the natural four-week cycle that is built in to APEX, means that you can begin to use this data for more than just debugging. The overall information that is available makes this data perfect for performing longer-term analysis and performance tracking.

For instance, using programmatic debugging, you could choose to collect and keep performance information about your most important application pages. You may not want to keep information for every page view, but you could easily write logic that captures n% of all page views. Then using the information contained in your long-term debug tables you can track the performance over time. You could even begin to spot and map trends in performance, potentially identifying when a critical process might trend outside its window of acceptability.

Another potential use is to compare data before and after making a change to a page. If the main structure of the page hasn't changed, but instead the driving query behind it, then you would be able to easily write code to compare, line for line, whether the new version of the page ran faster or slower than a previously captured version.

If a page calls stored PL/SQL code that is also instrumented using the APEX Debugging API, you then have insight into the performance trends of the business logic that you've written in PL/SQL.

The bottom line is, you have this data for whatever purposes you wish, and the better instrumented your code, the more detail you have at your disposal.

AJAX by its very nature is initiated from within JavaScript that is being run in the browser. This means that, from the APEX point of view, the page rendering has already been completed and all APEX debug messages that can be logged have been.

Therefore, any AJAX call that runs as part of the page is not captured by APEX Debugging. This is true for AJAX calls that may be handwritten by the developer and for those that might be included as part of a plug-in or dynamic action.

You can, however, instrument Application or Page level On-Demand PL/SQL processes using the debugging API. When doing this, you must include a call to ENABLE_DEBUG_MESSAGES at the beginning of the on-demand process and should also include a call to DISABLE_DEBUG_MESSAGES at the end.

The debugging information will be captured and related to the page from which the process was called. It will not appear within the context of the page SHOW or ACCEPT phases, but instead will be created under its own unique view identifier and only contain messages that you specifically emit using the LOG_MESSAGE procedure.

The same is true for the PL/SQL portion of APEX Plug-in code. You can simply instrument the render phase of a plug-in by using the LOG_MESSAGE FUNCTION without enabling debug messages specifically. Then, when debugging is turned on either programmatically or interactively, the messages will be included in the page's SHOW phase debug messages.

Instrumenting any AJAX callback functions within a plug-in needs to be handled the same way you handled on-demand processes. You must include the call to enable and disable debugging specifically.

FLASH charts are an interesting subject when it comes to debugging. We've already talked about the fact that when debugging is enabled, a FLASH chart will expose a link that allows you to view the XML that was used to render it. But there is more going on behind the scenes.

When a page that includes a FLASH chart is rendered by APEX, it isn't actually including the FLASH as part of the SHOW phase. APEX actually emits the FLASH object inclusion code, which you can view in the chart's region definition's Region Source. At this point the APEX engine is done and it is the browser that does the rest of the work.

The FLASH object inclusion code is interpreted by the browser, which loads the Flash object. Once the FLASH object is loaded, it in turn makes another call back to a special part of the APEX engine that runs the queries related to the chart series, assembles the XML used to drive the chart, and then renders based on what is returned.

So both the load of the base chart object and the call to generate the XML happen outside of the APEX engine and therefore do not get logged in to the APEX debug data.

To debug these steps, you once again need to depend on tools in the browser as opposed to the APEX debug metadata. The FireBug plug-in to Firefox allows you to use its NET tab to see the call that is used to load the FLASH object and the call to APEX_UTIL.FLASH that generates and returns the XML. Examining the timings for the later of the calls will indicate how long the round trip to retrieve the XML data took and will indicate whether you have a potential performance problem in the chart series queries that drive your chart.

You would think that reports are fairly straightforward in terms of debugging, as they are merely queries that are run by the APEX engine. This is true up to a certain point; we already talked about the challenges with Interactive Reports due to the fact that they use heavy JavaScript and AJAX to provide the interactivity.

The same problem can surface in classic reports if you have chosen to use Partial Page Refresh. When Partial Page Refresh is turned on for a classic report, JavaScript and AJAX are used to navigate through the pagination of a report, and because the page is not being re-drawn, the actions are not captured via debug.

As with any AJAX and JavaScript, you again must rely on browser tools to help you understand what is going on. When you paginate through a report that uses PPR, you'll see a call to the "f" procedure as an XMLHttpRequest. The POST of the call will indicate information about the page and the rows to be retrieved, and the RESPONSE will contain the HTML for the new set of rows that were returned. Again, looking at the timing of this call will give you some indication of performance problems that might be occurring when fetching the data set.