Tuesday, January 14, 2014

TimesTen JDBC Connection Pool Using UCP (Universal Connection Pool)

JDBC Connection to TimesTen in-memory database could be obtained either through the TimesTenDataSource or loading one of the TimesTen drivers (TimesTenDriver or TimesTenClientDriver) using Class.forName function.
But as stated in the Java developer's guide for TimeTen IMDB, the TimesTen driver does not implement any connection pooling. Looking at the sample code provided with the installation (TimesTenConnectionPool and TimesTenPooledConnection classes), it's clear that at the source of it is the TimesTenDataSource which is a non pooling data source. However instead of writing own code for TimesTen connection pooling, universal connection pool (UCP) could be used instead.
However could not find any Oracle documentation on UCP for TimesTen connection pooling. Therefore if there are any caveats to using UCP with TimesTen it's not known yet and post will be updated when such information comes to light.
Example java code for creating a TimesTen connection pool using UCP is as follows
   String urlc = "jdbc:timesten:client:ttc_server=192.168.0.99;tcp_port=53397
                 ;ttc_server_dsn=bximcdb_1122;oraclePassword=asa";
// String urld = "jdbc:timesten:direct:bximcdb_1122";

      PoolDataSource poolds = PoolDataSourceFactory.getPoolDataSource();
      poolds.setConnectionFactoryClassName("com.timesten.jdbc.TimesTenDataSource"); // connection type determined by URL
//    poolds.setConnectionFactoryClassName("com.timesten.jdbc.TimesTenDriver"); // Direct connections
//    poolds.setConnectionFactoryClassName("com.timesten.jdbc.TimesTenClientDriver"); // client/server connections
      poolds.setConnectionPoolName("TTPool");

      poolds.setURL(urlc); // or urld
      poolds.setUser("asanga");  // TT IMDB schema username
      poolds.setPassword("asa2"); // TT IMDB schema password

      poolds.setInitialPoolSize(5);
      poolds.setMinPoolSize(5);
      poolds.setMaxPoolSize(25);

      Connection con = poolds.getConnection();

// application work using the connection
urlc is an example of an URL used in a client/server type of connection. Usually this is when the TimeTen database and JDBC client are on two separate locations, thus connect over the network. ttc_server is the server IP or hostname where the TimesTen (TT) database is running. tcp_port is the TT listening port.
ttStatus

Daemon pid 25149 port 53396 instance tt1122
TimesTen server pid 25158 started on port 53397
ttc_server_dsn is the data source name setup for the TT DB. Finally the oraclePassword is the password of the corresponding Oracle database schema (not the TT DB password). Unlike the TimesTenDataSource the UCP doesn't have a "setOraclePassword" function. Therefore oracle password must be included on the URL (refer 1404604.1)

urld is an example of an URL used for direct connection to the TT DB. For this both JDBC client and TT DB must be located on the same location and does not involve a network connection.

UCP requires a connection factory class name and as shown on the example code above any one of the following TimesTenDataSource, TimesTenDriver or TimesTenClientDriver could be used. If TimesTenDataSource is used then the connection type is determined by the value on the URL (jdbc:timesten:client or jdbc:timesten:direct). Whereas other two classes explicitly specify the connection type.

The username and password set are that of the schema in the TT DB. Finally the connection pool initial, minimum and maximum sizes.



Similar to JDBC thick client TT JDBC clients also require other native libraries to be in available, and also a data source name (DSN) setup. These steps are not listed here and it is assumed all these prerequisites are completed successfully.
Running some test java code shows the connection pooled. Below is the output for client/server connection using TimesTenDataSource.
$ ttStatus

Daemon pid 25149 port 53396 instance tt1122
TimesTen server pid 25158 started on port 53397
------------------------------------------------------------------------
Data store /opt/timesten/DataStore/bximcdb_1122
There are 28 connections to the data store
Shared Memory KEY 0x670615d8 ID 16482308
PL/SQL Memory KEY 0x680615d8 ID 16515077 Address 0x7fa0000000
Type            PID     Context             Connection Name              ConnID
Cache Agent     25324   0x0000000002d70be0  Handler                           2
Cache Agent     25324   0x0000000002ed7720  Timer                             3
Cache Agent     25324   0x000000000302cc30  CacheGridRec                      7
Cache Agent     25324   0x000000000309ae80  CacheGridEnv                      5
Cache Agent     25324   0x0000000003235290  CacheGridSend                     6
Cache Agent     25324   0x00000000032837f0  BMReporter(1107736896)            4
Cache Agent     25324   0x0000000003329920  CacheGridRec                      8
Cache Agent     25324   0x000000000344edb0  CacheGridRec                      9
Cache Agent     25324   0x00000000034d7390  Refresher(S,5000)                10
Cache Agent     25324   0x000000000393bc90  LogSpaceMon(1095366976)          11
Cache Agent     25324   0x0000000003b48e00  Marker(1097472320)               12
Cache Agent     25324   0x0000000011d7e150  Refresher(D,5000)                13
Server          25763   0x00000000032b0a90  java                              1
    (Client Information: pid: 25743; IPC: TCP/IP;
        Node: hpc5.domain.net (192.168.0.99))
Server          25768   0x000000001beeaa90  java                             14
    (Client Information: pid: 25743; IPC: TCP/IP;
        Node: hpc5.domain.net (192.168.0.99))
Server          25773   0x000000000daf7a90  java                             15
    (Client Information: pid: 25743; IPC: TCP/IP;
        Node: hpc5.domain.net (192.168.0.99))
Server          25778   0x0000000017887a90  java                             16
    (Client Information: pid: 25743; IPC: TCP/IP;
        Node: hpc5.domain.net (192.168.0.99))
Server          25783   0x000000001fb90a90  java                             17
    (Client Information: pid: 25743; IPC: TCP/IP;
        Node: hpc5.domain.net (192.168.0.99))
Subdaemon       25153   0x0000000001094570  Manager                         142
Subdaemon       25153   0x00000000010eb3f0  Rollback                        141
Subdaemon       25153   0x0000000002488580  Aging                           136
Subdaemon       25153   0x000000000251d1f0  Checkpoint                      133
Subdaemon       25153   0x000000000270ed90  AsyncMV                         139
Subdaemon       25153   0x00000000027841b0  Log Marker                      138
Subdaemon       25153   0x0000000002798da0  Deadlock Detector               137
Subdaemon       25153   0x000000000284f0e0  Flusher                         140
Subdaemon       25153   0x00002aaac00008c0  Monitor                         135
Subdaemon       25153   0x00002aaac0055710  HistGC                          134
Subdaemon       25153   0x00002aaac00aa560  IndexGC                         132
Replication policy  : Manual
Cache Agent policy  : Manual
TimesTen's Cache agent is running for this data store
PL/SQL enabled.
------------------------------------------------------------------------
Accessible by group oinstall
End of report
The five pooled connections are listed as "Server" type and there are five connections which is the initial pool size.
Following is the TT status output when direct connections are used.
$ ttStatus

Daemon pid 25149 port 53396 instance tt1122
TimesTen server pid 25158 started on port 53397
------------------------------------------------------------------------
Data store /opt/timesten/DataStore/bximcdb_1122
There are 28 connections to the data store
Shared Memory KEY 0x670615d8 ID 16482308
PL/SQL Memory KEY 0x680615d8 ID 16515077 Address 0x7fa0000000
Type            PID     Context             Connection Name              ConnID
Cache Agent     25324   0x0000000002d70be0  Handler                           2
Cache Agent     25324   0x0000000002ed7720  Timer                             3
Cache Agent     25324   0x000000000302cc30  CacheGridRec                      7
Cache Agent     25324   0x000000000309ae80  CacheGridEnv                      5
Cache Agent     25324   0x0000000003235290  CacheGridSend                     6
Cache Agent     25324   0x00000000032837f0  BMReporter(1107736896)            4
Cache Agent     25324   0x0000000003329920  CacheGridRec                      8
Cache Agent     25324   0x000000000344edb0  CacheGridRec                      9
Cache Agent     25324   0x00000000034d7390  Refresher(S,5000)                10
Cache Agent     25324   0x000000000393bc90  LogSpaceMon(1095366976)          11
Cache Agent     25324   0x0000000003b48e00  Marker(1097472320)               12
Cache Agent     25324   0x0000000011d7e150  Refresher(D,5000)                13
Process         25691   0x000000004a53b4f0  java                              1
Process         25691   0x000000004a614820  java                             14
Process         25691   0x000000004a695540  java                             15
Process         25691   0x000000004a717270  java                             16
Process         25691   0x000000004a798fa0  java                             17
Subdaemon       25153   0x0000000001094570  Manager                         142
Subdaemon       25153   0x00000000010eb3f0  Rollback                        141
Subdaemon       25153   0x0000000002488580  Aging                           136
Subdaemon       25153   0x000000000251d1f0  Checkpoint                      133
Subdaemon       25153   0x000000000270ed90  AsyncMV                         139
Subdaemon       25153   0x00000000027841b0  Log Marker                      138
Subdaemon       25153   0x0000000002798da0  Deadlock Detector               137
Subdaemon       25153   0x000000000284f0e0  Flusher                         140
Subdaemon       25153   0x00002aaac00008c0  Monitor                         135
Subdaemon       25153   0x00002aaac0055710  HistGC                          134
Subdaemon       25153   0x00002aaac00aa560  IndexGC                         132
Replication policy  : Manual
Cache Agent policy  : Manual
TimesTen's Cache agent is running for this data store
PL/SQL enabled.
------------------------------------------------------------------------
Accessible by group oinstall
End of report
In this case the connections are of "Process" type indicating direct connections and again there are 5 connections created against the TT DB.
The code was tested against a read only cache groups without any issues.

Useful metalink notes
How To Pass Oraclepwd Via Xml To Tomcat Server using JDBC interface? [ID 1404604.1]

Friday, January 10, 2014

WM_CONCAT Removed From 12c Workspace Manager?

It appears that wm_concat function has been removed from 12c workspace manager. Oracle always insisted that this is an internal function to be used with Oracle products and not for end user consumption (refer 1336219.1 and 1300595.1). But it was available for use even with 11gR2 but it seem it's been removed or more likley access to end user is completely removed.
On a 11gR2 system querying dba_objects show the wm_concat as a function in wmsys schema.
SQL> select owner, object_type from dba_objects where object_name = 'WM_CONCAT';

OWNER                          OBJECT_TYPE
------------------------------ -------------------
PUBLIC                         SYNONYM
WMSYS                          FUNCTION
But on 12cR1 there's no such function at all and same query returns no rows. The 12cR1 database has the workspace manager components installed and valid.
SQL> select comp_name,status from dba_registry order by 1;

COMP_NAME                                STATUS
---------------------------------------- ----------
JServer JAVA Virtual Machine             VALID
OLAP Analytic Workspace                  VALID
Oracle Application Express               VALID
Oracle Database Catalog Views            VALID
Oracle Database Java Packages            VALID
Oracle Database Packages and Types       VALID
Oracle Database Vault                    VALID
Oracle Label Security                    VALID
Oracle Multimedia                        VALID
Oracle OLAP API                          VALID
Oracle Real Application Clusters         OPTION OFF
Oracle Text                              VALID
Oracle Workspace Manager                 VALID
Oracle XDK                               VALID
Oracle XML Database                      VALID
Spatial                                  VALID
Another way to verify the installation of workspace manager component is
SQL> select dbms_wm.getWorkspace from dual;

GETWORKS
--------
LIVE


Querying all the objects owned by wmsys user in a 12cR1 DB also does not show the wm_concat function anymore (output has been truncated to show only objects starting with wm_)
SQL> select object_name from dba_objects where owner='WMSYS' order by 1;
WM_COMPRESSIBLE_TABLES
WM_COMPRESS_BATCH_SIZES
WM_CONTAINS
WM_DDL_UTIL
WM_DDL_UTIL
WM_EQUALS
WM_ERROR
WM_ERROR
WM_EVENTS_INFO
WM_GREATERTHAN
WM_INSTALLATION
WM_INTERSECTION
WM_LDIFF
WM_LESSTHAN
WM_MEETS
WM_OVERLAPS
WM_PERIOD
WM_PERIOD
WM_RDIFF
WM_REPLICATION_INFO
So it seem any application has been relying on wm_concat function will not work once upgraded to 12c and alternatives to wm_concat must be found and tested before the upgrade.

Related Post
Use of WM_CONCAT Can Exhaust Temporary Tablespace in 11gR2 & 10gR2

Useful Metalink Notes
WMSYS.WM_CONCAT Should Not Be Used For Customer Applications, It Is An Internal Function [ID 1336219.1]
Problem with WMSYS.WM_CONCAT Function after Upgrading [ID 1300595.1]
How do you manually install/deinstall Oracle Workspace Manager [ID 731576.1]

Wednesday, January 1, 2014

Parallel Query Used for Result Cache Access

On a new deployment it was discovered that wait class Other was taking a significant portion of the wait time on a business critical SQL (denoted bqm in this case). Comparing similar deployment in the past, it was clear that wait class Other was a new addition and SQL didn't exhibit this behavior before. Below is the screenshot of the em console.

Looking at the breakdown of the wait events for the SQL it was seen that majority of waits were related to parallel query.

Beside the parallel query related wait events one other thing that stood out was the result cache contention. There has been a previous experience with result cache contention that manifested as a latch free event. However in this case latch free wasn't the only prominent wait event. Strange thing was that query was not suppose to use parallelism when executing. None of the underlying table used had degree greater than 1 (None of the reasons mentioned in 196938.1 were there). Parallel query related parameters were set at default.
NAME                                     VALUE
---------------------------------------- ----------
parallel_server                          TRUE
parallel_server_instances                3
parallel_min_percent                     0
parallel_min_servers                     0
parallel_max_servers                     960
parallel_instance_group
parallel_execution_message_size          16384
parallel_degree_policy                   MANUAL
parallel_adaptive_multi_user             TRUE
parallel_threads_per_cpu                 2
parallel_automatic_tuning                FALSE
parallel_io_cap_enabled                  FALSE
parallel_min_time_threshold              AUTO
parallel_degree_limit                    CPU
parallel_force_local                     FALSE
parallel_servers_target                  384
parallel_degree_policy was introduced on 11.2 which "specifies whether or not automatic degree of Parallelism, statement queuing, and in-memory parallel execution will be enabled". Setting this to manual disable this feature and behavior is same as 11.1. Application user session did have pq_status enabled (1289785.1) and setting parallel_max_servers to 0 disabled it (alter session disable parallel query wasn't an option in this case) but still didn't eliminate the parallel query related waits.
Another thing noticed was that only some of the session ran in parallel while others did not. In the above image session 2687 ran in parallel (indicated by QC SID column) while other session did not run in parallel. This session details show parallel query, result cache wait events.

Result cache contention was understandable since the query did employ a function on it's select clause which had result cache enabled. (eg. select myfunc(column_id), col2, col3...., result cache was enabled on "myfunc" function). But how the parallel query fit in wasn't clear and there was a clear increase of the parallel query related wait events since this deployment. 1,2 and 3 are RAC instance IDs
Latch free waits and wait times

enq: PS - contention waits and wait times

enq: RC - Result Cache: Contention waits and wait times

Reliable message waits and wait times

Although the wait time values could be considered low, when compared to the situation before where these were near 0, this is a significant increase.



Further monitoring showed that beside this particular SQL no other application SQL was using parallelism except for the following non application SQL.

Looking at the SQL, this is clearly related to result cache access. There was no information available on the oracle reference documentation on this view (it could be an internal view not for end users). Could only guess what is used for, where clause provides a good clue ,instance id and key, possible result cache key. Querying the execution plan of this shows parallel query being used
SQL>  select * from table(dbms_xplan.display_CURSOR('8sd1v66dnj4m4'));
SQL_ID  8sd1v66dnj4m4, child number 0
-------------------------------------
select inst_id, blk_num, blk_seq, blk_dat from gv$result_cache_rd where
inst_id = :1 and key = :2

Plan hash value: 238457506

--------------------------------------------------------------------------------------
| Id  | Operation                  | Name               |    TQ  |IN-OUT| PQ Distrib |
--------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT           |                    |        |      |            |
|*  1 |  PX COORDINATOR            |                    |        |      |            |
|   2 |   PX SEND QC (RANDOM)      | :TQ10000           |  Q1,00 | P->S | QC (RAND)  |
|*  3 |    VIEW                    | GV$RESULT_CACHE_RD |  Q1,00 | PCWP |            |
|*  4 |     FIXED TABLE FIXED INDEX| X$QESRCRD (ind:1)  |  Q1,00 | PCWP |            |
--------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   1 - filter(("KEY"=:2 AND "INST_ID"=:1))
   3 - filter(("KEY"=:2 AND "INST_ID"=:1))
   4 - filter("QESRCRD_KEY"=:2)

Note
-----
   - rule based optimizer used (consider using cbo)
So could it be that when a business SQL result in a cache hit, the results are searched in the cache using parallel SQL? Hard to say without exact information on what gv$result_cache_rd is used for. But it's clear that parallel query related waits were caused by this SQL. To test this result cache was removed from the function used in the select clause. This resulted in drop in the parallel query related wait events (20 Dec mark).
latch free waits and wait times

enq: PS - contention waits and wait times

enq: RC - Result Cache: Contention waits and wait times

Reliable message waits and wait times

This confirms that parallel query related waits were due to the result cache access. Removing the result cache from the function also made the average elapsed time for the SQL stable compared to when having result cache.

Update 02 January 2014
Further test has shown the V$RESULT_CACHE_RD comes into in RAC system when a instance request missing result from a result cache of a remote node. Following test case could used to confirm this.
create table x (a number, b number);

create table y (c number, d number);


begin
    for i in 1 .. 10
    loop
    insert into x values(i,round(dbms_random.value(1,10)));
    end loop;
end;
/
begin
    for i in 25 .. 45
    loop
    insert into y values(i,mod(i,10));
    end loop;
end;
/

 
create or replace function myfunc(inum in number) return number
result_cache
as retnum number;
begin
  select b into retnum from x where a=inum;
  return retnum;
end;
/
It is best if the database could be restarted if not shared pool cleared (as such not good to test on a production system). Assuming this is a two node RAC run the following on both nodes
SQL> set line 180
SQL> set pagesize 0
SQL> select * from table(dbms_xplan.display_CURSOR('8sd1v66dnj4m4'));
SQL_ID: 8sd1v66dnj4m4, child number: 0 cannot be found
Since the sql text is Oracle provided it could be assumed that SQL ID (which was identified earlier) will remain the same. This shows that SQL does not exits in the library cache (if DB was restarted, this means it never got executed, assuming not been paged out)
Now on node 1 run the following SQL (output has been truncated)
SQL> select c,myfunc(d) from y;
        25          3
        26          4
        27          1
        28          2
Run the first SQL again and it still gives a negative results
SQL> select * from table(dbms_xplan.display_CURSOR('8sd1v66dnj4m4'));
SQL_ID: 8sd1v66dnj4m4, child number: 0 cannot be found
Parallel result cache access hasn't occurred yet. On the same instance the application SQL could be run many times and SQL (8sd1v66dnj4m4) will not get executed.
Now run the application SQL on the node 2.
SQL> select c,myfunc(d) from y;
        25          3
        26          4
        27          1
        28          2
This time the parallel result cache access query has been executed
SQL> select * from table(dbms_xplan.display_CURSOR('8sd1v66dnj4m4'));
SQL_ID  8sd1v66dnj4m4, child number 0
-------------------------------------
select inst_id, blk_num, blk_seq, blk_dat from gv$result_cache_rd where
inst_id = :1 and key = :2

Plan hash value: 238457506

--------------------------------------------------------------------------------------
| Id  | Operation                  | Name               |    TQ  |IN-OUT| PQ Distrib |
--------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT           |                    |        |      |            |
|*  1 |  PX COORDINATOR            |                    |        |      |            |
|   2 |   PX SEND QC (RANDOM)      | :TQ10000           |  Q1,00 | P->S | QC (RAND)  |
|*  3 |    VIEW                    | GV$RESULT_CACHE_RD |  Q1,00 | PCWP |            |
|*  4 |     FIXED TABLE FIXED INDEX| X$QESRCRD (ind:1)  |  Q1,00 | PCWP |            |
--------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   1 - filter(("KEY"=:2 AND "INST_ID"=:1))
   3 - filter(("KEY"=:2 AND "INST_ID"=:1))
   4 - filter("QESRCRD_KEY"=:2)

Note
-----
   - rule based optimizer used (consider using cbo)


28 rows selected.
This will now be present on the library cache of both instances. This confirms inter instance result cache access is done using parallel query even though database is configured not to use parallel query.
Read Method 3 on this article for explanation on how result cache behave in a 11.2 RAC environment.