Why Apex 4.0.2 active sessions report took ages to run on my server

This articles discusses a workaround that might hamper the throughput of your production web site, it might be wise to implement this technique only for the time strictly needed to carry out the required investigation.

It's amazing how you end up spending hours on a secondary problem when you start investigating a completely different one.
I set out in pursue of an allegedly trivial problem with an apex page this morning and I found myself sucked into a vortex of high CPU usage caused by one of the oldest built-in apex reports.
I wanted to inspect the session state values of the failing page and this has always been simply a matter of opening the Active sessions apex report, look up the right session id and drill down to item values, however when I opened page 7 of application 4350 (Active Sessions report) the CPU of my virtual server was skyrocketing. This phenomenon was duly recorded by Amazon EC2's instance monitoring chart as shown below.

a CPU spike occurs when opening the Active Sessions report

At first I thought that there was just something bad with my database instance, one of those odd problems that disappear when you bounce the database and you never get to know what really was the point.
However it turned out this time the problem was not one of that kind.
So, after confirming that the problem was with this specific page while the rest of my applications were running normally, the next task was to identify which SQL statement was consuming all this CPU.

I ran a SQLDeveloper built-in report showing the top SQL by CPU and the following query turned out to be one of the most time consuming:

select 
       "ID",
       "SESSION_OWNER",
       "CREATED_ON",
       "ITEM_CACHE_COUNT",
       "IP_ADDRESS",
       "MOST_RECENT_VIEW",
       "DISTINCT_APPLICATIONS",
       count(*) over () as apxws_row_cnt
 from (
select  *  from (
select /* APEX4350P7a */ /*+ FIRST_ROWS(21) */
       id,
       session_owner,
       created_on,
       item_cache_count,
       ip_address,
      (select max(time_stamp) mt 
       from WWV_FLOW_ACTIVITY_LOG l
       where l.SESSION_ID = s.id)  most_recent_view,
      distinct_applications
from (
select  "WWV_FLOW_SESSIONS$".ID as "ID", 
         cookie session_owner, 
         created_on,
         count(*) item_cache_count, 
         count(distinct(flow_id)) distinct_applications,
         "WWV_FLOW_SESSIONS$".remote_addr ip_address
 from  "WWV_FLOW_DATA" "WWV_FLOW_DATA",
  "WWV_FLOW_SESSIONS$" "WWV_FLOW_SESSIONS$"
 where   WWV_FLOW_DATA.FLOW_INSTANCE(+)=WWV_FLOW_SESSIONS$.ID and
(:P7_OWNER is null or instr(upper(cookie),upper(:P7_OWNER))>0) and
security_group_id = :flow_security_group_id
group by "WWV_FLOW_SESSIONS$".ID, cookie, created_on, remote_addr ) s
)  r
) r where rownum <= to_number(:APXWS_MAX_ROW_CNT) 
 order by "MOST_RECENT_VIEW" DESC,"CREATED_ON" DESC

By examining the explain plan it was clear that for some reason Oracle was executing two FULL TABLE SCANs on WWV_FLOW_ACTIVITY_LOG1$ and WWV_FLOW_ACTIVITY_LOG2$, two tables merged inside the view WWV_FLOW_ACTIVITY_LOG and on these tables there were no indexes on column SESSION_ID.
The result was that the query took nearly 300 seconds to scan some 250,000 rows.

Now, what if I create a couple of indexes on those two tables?

CREATE INDEX "APEX_040000"."WWV_FLOW_ACTIVITY_LOG1$_IDX4" ON "APEX_040000"."WWV_FLOW_ACTIVITY_LOG1$"
  (
    "SESSION_ID"
  );

CREATE INDEX "APEX_040000"."WWV_FLOW_ACTIVITY_LOG2$_IDX4" ON "APEX_040000"."WWV_FLOW_ACTIVITY_LOG2$"
  (
    "SESSION_ID"
  ); 

Well, the result was encouraging, from 300 seconds to less than 2 seconds.
Clearly with the next apex upgrade, if things have not been fixed, I'll have to rebuild these indexes.

And now for the real questions:
did the missing indexes disappear from my installation for some reason?
Have they ever been there in the past?
Have they been removed or lost during the evolution of Apex?
Am I the only one having this problem?
Is anybody else using the Active Session report with some thousand active sessions?

Answers are welcome.

PS: Tyler (see the comments section) suggested to put a disclaimer at the top of this article, which I did, I also added that probably it might make sense to create these additional indexes only for the time needed and removing them thereafter.

An (IN)famous case of runaway query aka there is more than one way to do the same thing

Always check out the original article at http://www.oraclequirks.com for latest comments, fixes and updates.

I had to find out some records whose primary key was not referenced in a secondary table and for some reason i mindlessly executed the following (typical) query:

select *
from qq_messages
where messageid not in
(
select messageid
from qq_message_recipients
);

Unfortunately each table contained several hundreds of thousands of rows, so I had to stop the query after wasting 5 minutes with the CPU constantly at 98%.

Who knows why we always come up with the worst queries first.

In these cases you can bet there is a better way of designing your SQL, especially after looking at the astronomical cost reported by the optimizer.


Indeed i rewrote the statement using a NOT EXISTS clause and i immediately got a better looking plan:

select *
from qq_messages a
where not exists
(
select 1
from qq_message_recipients b
where b.messageid = a.messageid
);

This query returned 7 rows in 0.3 seconds.

But is there any other way to get this result?
Oh yes.
If you like set algebra, then here is a query that does exactly the same job in a different fashion in about 1.6 seconds, that is 5 times slower than the best one, but considerably faster than the worst scenario:

select * from qq_messages
minus
select * from qq_messages a
where a.messageid in
(
 select b.messageid
   from qq_message_recipients b
);

Again, there can be some improvement by replacing IN with EXISTS:

select * from qq_messages
minus
select * from qq_messages a
where exists (select 1 from qq_message_recipients b
              where b.messageid = a.messageid);

This query took 1.2 seconds. Notice the cost of 13620 in contrast with 13651. Very similar figures for a query that runs 25% faster.

The scenario above should turn out to be quite useful for those who are not (yet) mastering Oracle SQL, because it teaches at least three important lessons:

• the NOT IN clause is not the solution for all situations, no matter if it is the most natural;
• the explain plan gives you a quick qualitative estimation of how good your SQL is;
• there is usually an alternate solution for the same problem, so, unless you are really satisfied with your first shot, you'd better off looking at alternatives.

While the number returned as the total cost is not to be taken as a forecast of the time required to execute the query, it can certainly be considered as an indicator of the resources required to carry out the statement. This however doesn't mean that two queries with similar costs will take the same time to execute, as we have seen.
Cost misinterpretation is an old standing issue in the community of developers.

It's easy to think that a low number means fast and a high number means slow, whatever fast and slow mean in your specific case, so the temptation of skipping a real test basing purely on the cost indication of the queries is always around the corner. The problem is also in that a database is not a static thing, so the total number of records in each table may vary over time, even by large numbers, and the execution plan will change as well, if the statistics are up to date, so don't forget to think about how/when it's the best time to refresh the stats, that is as important as developing "good" procedures.

Even after carefully evaluating different alternatives, your job isn't finished yet. A further step, in case results are difficult to interpret may be to run TKPROF and find out which SQL is the most resource intensive. And after that you have to try it out in the real world, with concurrent users, if that applies, and see if your program survives user acceptance test. If not, it could mean that you found an optimal solution for a suboptimal architecture, which means redesigning parts of your database objects.

But that is definetely another story.

Why indexing nested tables is so good

Always check out the original article at http://www.oraclequirks.com for latest comments, fixes and updates.

Last week i got a call from a customer who was complaining because a procedure exporting a file was taking a very long time. After some investigation it turned out that, for some reason, during a recent application upgrade, an index on a nested table had not been (re)created.

The symptoms were clear: a procedure that normally took seconds, was now taking 20 minutes to execute.
I could quickly find out the real reason for this huge performance problem after looking at the execution plan of an inner query, that is a query executed several thousands times because it's performed inside an outer explicit cursor:


If it is certainly true that in Oracle (as for any other know database) there is no FAST=TRUE parameter, but it must be said that when a procedure is very slow, either the procedure is poorly written or some index is missing or both... ;-)
If you are lucky, then it's enough to create the right index and voilá, it's almost like turning on that magic switch.
Indeed that was my case as it was enough to (re)create the missing index on the nested table to fix the problem, as follows:

CREATE INDEX IDX_TOTES_CNT ON NESTED_CNT(NESTED_TABLE_ID,MAT_ID);

Note: NESTED_TABLE_ID is a pseudo-column provided by Oracle containing the primary key of the nested table.
Soon the execution plan started looking much better:


The success was confirmed by the fact that the export procedure now took a few seconds again, as it was before the upgrade.
But why do i need an index on a nested table in the first place?
Here is a stripped down version of the inner query. Value par_tote is a cursor parameter that is populated by the outer cursor. This value uniquely identifies the record containing the nested table to be processed. Thereafter, as you can see, i need to filter out certain values (in green) that come from nested table cnt:

select
a.mat_id,
...
b.ean
from table(select cnt
            from totes
           where tote = par_tote) a,
    exits b
where a.mat_id != info_const.conMat_ID_NRR
and a.mat_id = b.mat_id (+)
order by a.mat_id;

With an index on the nested table, the optimizer can perform the table unnesting more efficiently, selecting the recordset with a common NESTED_TABLE_ID (having the same cardinality as tote) and filtering the data basing on mat_id, without having to perform a full table scan on each iteration, which explains why the procedure was taking that outrageous amount of time to execute.

Function-based indexes and the easy life of a database developer

Always check out the original article at http://www.oraclequirks.com for latest comments, fixes and updates.

Yesterday i was working at a big customer site on a 9.2.0.7 database and i was checking the results of a procedure before and after the extensive change and in particular i was trying to understand why i was getting more records after the last modification.
In order to do so, i had to perform a piece-wise comparison of certain sub-strings taken from a column in a table where the only available index was the on the numeric primary key.

You can see my original query below:

select
substr(message, 33, 5) as pfx
,substr(message, 87, 9) as tt_a
,substr(message, 107, 9) as fv_a
,substr(message, 127, 7) as id_a
from test_fidx_tab a
where a.master_id = 110539
and not exists (
select 1
from test_fidx_tab b
where b.master_id = 110538
and substr(b.message, 33, 5) = substr(a.message, 33, 5)
and substr(b.message, 87, 9) = substr(a.message, 87, 9)
and substr(b.message, 107, 6) = substr(a.message, 107, 6)
and substr(b.message, 127, 7) = substr(a.message, 127, 7)
);

The table contained roughly 360,000 rows and a first attempt to execute this query did not return any results within a reasonable time (several minutes), so i started thinking of creating a function-based index on the table:

create index fx_1 on test_fidx_tab(
master_id
,substr(message, 33, 5)
,substr(message, 87, 9)
,substr(message, 107, 6)
,substr(message, 127, 7)
);

But after creating the index, the execution plan of the query did not change.
After some attempts of changing the index structure, in case the optimizer didn't like it for some reason, i finally manually added an optimizer hint.

select
substr(message, 33, 5) as pfx
,substr(message, 87, 9) as tt_a
,substr(message, 107, 9) as fv_a
,substr(message, 127, 7) as id_a
from test_fidx_tab a
where a.master_id = 110539
and not exists (
select /*+ INDEX(B FX_1) */ 1
from test_fidx_tab b
where b.master_id = 110538
and substr(b.message, 33, 5) = substr(a.message, 33, 5)
and substr(b.message, 87, 9) = substr(a.message, 87, 9)
and substr(b.message, 107, 6) = substr(a.message, 107, 6)
and substr(b.message, 127, 7) = substr(a.message, 127, 7)
);

The execution plan was now taking into account the special function-based index and the execution of the query lasted less than a second.
But wait a minute, why didn't the optimizer pick up the index automatically?

After working for years on 10g, i had almost forgotten that on 9iR2 and earlier, the cost based optimizer would not work properly until the statistics were collected on the index and on the underlying table.

exec dbms_stats.gather_table_stats(
ownname => 'TEST',
tabname => 'TEST_FIDX_TAB',
cascade => TRUE);

After gathering the statistics, the function based index was picked up by the optimizer *without* having to specify any hint.

Then i decided to repeat this exercise on a 10gR2 instance where i could verify that the optimizer was instantly picking up the function-based index because oracle 10g automatically gathers the statistics for objects having stale or missing statistics. Again, no need of adding optimizer hints.

Note that the automatic collection of statistics feature appeared in 10gR1.

May be it's not enough to justify an upgrade for a company, but certainly it's one of those things that makes happy a developer, especially when you have to suddenly downgrade the brain after years of easy life with Oracle 10g.