Category Archives: 18c

Dead Connection Detection (DCD) and the Oracle database

Dead Connection Detection is a useful feature of the Oracle database: it allows for the cleanup of “dead” sessions so they don’t linger around consuming memory and other system resources. The idea is simple: if the database detects that a client process is no longer connected to its server process, it cleans up. This can happen in many ways, in most cases this kind of problem is triggered by an end user.

A dead connection shouldn’t be confused with idle connections: an idle connection still maintains the network link between client and server process, except that there is no activity. Idle connections aren’t maintained/controlled via DCD, there are other tools in the database handling such cases.

As a by product, DCD can also help with overly eager firewalls forcibly removing seemingly idle network connections. I found the following posts and the references therein very useful:

With Oracle 12c Oracle changed the way DCD works by no longer relying on its network layer but rather pushing the functionality into the TCP stack on platforms that support it. This change in behaviour is also explained in an Oracle white paper from 2014.

For the first part of this post I set sqlnet.expire_time to 1 as per a MOS note I found, your value is probably different. The parameter is documented in the Net*8 reference, please use it to work out what the best value is for you. As others have pointed out, this parameter has to go into the RDBMS home, more specifically $ORACLE_HOME/network/admin/sqlnet.ora. I am using Oracle 19.4 on Oracle Linux 7.7 for this blog post. I have seen the same behaviour in 12.1.0.2 as well in my lab.

Background

In addition to the proven methods of checking whether TCP_KEEPALIVE is enabled for a given session I wanted to show another one. Using the ss(8) utility it is possible to show socket options. I also tried lsof but on my system I couldn’t get it to print the options:

SQL> select spid from v$process where addr = (select paddr from v$session where username = 'MARTIN');

SPID
------------------------
13656

SQL> exit 

...

[root@server2 ~]# lsof -nP -p 13656 -T f
lsof: unsupported TCP/TPI info selection: f
lsof 4.87

Although the man-page for lsof reads:

       -T [t]   controls the reporting of some TCP/TPI information,  also  reported  by  net‐
                stat(1),  following  the network addresses.  In normal output the information
                appears in parentheses, each item except TCP or TPI state name identified  by
                a keyword, followed by `=', separated from others by a single space:

                     <TCP or TPI state name>
                     QR=<read queue length>
                     QS=<send queue length>
                     SO=<socket options and values>
                     SS=<socket states>
                     TF=<TCP flags and values>
                     WR=<window read length>
                     WW=<window write length>

                Not all values are reported for all UNIX dialects.  Items values (when avail‐
                able) are reported after the item name and '='.

                When the field output mode is in effect  (See  OUTPUT  FOR  OTHER  PROGRAMS.)
                each item appears as a field with a `T' leading character.

                -T with no following key characters disables TCP/TPI information reporting.

                -T with following characters selects the reporting of specific TCP/TPI infor‐
                mation:

                     f    selects reporting of socket options,
                          states and values, and TCP flags and
                          values.

So let’s try something else: ss(8) – another utility to investigate sockets

Revealing socket options

I have used ss(8) in the past when I didn’t have netstat available, which is more and more common now that netstat is deprecated and its designated successor is ss :)

As far as I know you can’t limit ss to show information just for a PID, I use grep to limit the output. The output is in fact very wide, which is why this might not look pretty on the blog depending on whether the renderer decides to wrap output or not.

[root@server2 ~]# ss -nop | egrep 'NetidState|13656'
NetidState Recv-Q Send-Q                                    Local Address:Port                                      Peer Address:Port                                                                                                           
tcp  ESTAB 0      0                               [::ffff:192.168.100.22]:1521                           [::ffff:192.168.100.21]:25780                           users:(("oracle_13656_si",pid=13656,fd=18)) timer:(keepalive,4.412ms,0)        
[root@server2 ~]# 

I used the following options:

  • -n for “Do not try to resolve service names”
  • -o for “Show timer information” and finally
  • -p to “Show process using socket”.

The main option here is -o. As per the man page:

       -o, --options
              Show timer information. For tcp protocol, the output format is:

              timer:(<timer_name>,<expire_time>,<retrans>)

              <timer_name>
                     the name of the timer, there are five kind of timer names:

                     on: means one of these timers: tcp retrans timer, tcp early retrans timer and tail loss probe timer
                     keepalive: tcp keep alive timer
                     timewait: timewait stage timer
                     persist: zero window probe timer
                     unknown: none of the above timers

              <expire_time>
                     how long time the timer will expire

              <retrans>
                     how many times the retran occurs

With a little shell loop I can show how that timer is decrementing:

[root@server2 ~]# for i in $(seq 1 5); do ss -nop | grep 13656; sleep 1 ; done
tcp  ESTAB 0      0                               [::ffff:192.168.100.22]:1521                           [::ffff:192.168.100.21]:25780                           users:(("oracle_13656_si",pid=13656,fd=18)) timer:(keepalive,20sec,0)          
tcp  ESTAB 0      0                               [::ffff:192.168.100.22]:1521                           [::ffff:192.168.100.21]:25780                           users:(("oracle_13656_si",pid=13656,fd=18)) timer:(keepalive,19sec,0)          
tcp  ESTAB 0      0                               [::ffff:192.168.100.22]:1521                           [::ffff:192.168.100.21]:25780                           users:(("oracle_13656_si",pid=13656,fd=18)) timer:(keepalive,18sec,0)          
tcp  ESTAB 0      0                               [::ffff:192.168.100.22]:1521                           [::ffff:192.168.100.21]:25780                           users:(("oracle_13656_si",pid=13656,fd=18)) timer:(keepalive,17sec,0)          
tcp  ESTAB 0      0                               [::ffff:192.168.100.22]:1521                           [::ffff:192.168.100.21]:25780                           users:(("oracle_13656_si",pid=13656,fd=18)) timer:(keepalive,16sec,0)          
[root@server2 ~]# 

Summary

Using the ss utility it is possible to check if a keepalive timer is implemented as a means to support DCD with 12.1 and later releases. Invoking ss(8) hasn’t caused any problems on my system, but as with every such tool you need to ensure it’s safe to use before attempting to look at an important system.

sqlldr, direct path loads and concurrency in 12.2 and later

In my previous post I showed you that Oracle’s SQL loader (sqlldr) utility has a built-in timeout of 30 seconds waiting for locked resources before returning SQL*Loader-951/ORA-604/ORA-54 errors and failing to load data. This can cause quite some trouble! Before showing you the enhancement in 12.2 and later, here is the gist of the previous post.

Concurrency in Oracle sqlldr 12.1 and earlier

To show you how sqlldr times out I need to simulate an exclusive lock on the table in sqlplus for example. That’s quite simple:

SQL> set time on
10:17:00 SQL> lock table t2 in exclusive mode;

Table(s) Locked.

10:17:07 SQL>

Next I started a sqlldr process in another session. Please refer to the previous post for details, or take my word that I’m using a direct path insert strategy. The only difference is the size of the input file – I had to inflate it considerably to buy some time running standard diagnostic tools:

$ date; sqlldr /@loader control=t2_2.ctl ; date
Tue 23 Jul 10:22:35 BST 2019

SQL*Loader: Release 19.0.0.0.0 - Production on Tue Jul 23 10:22:35 2019
Version 19.4.0.0.0

Copyright (c) 1982, 2019, Oracle and/or its affiliates.  All rights reserved.

Path used:      Direct
SQL*Loader-951: Error calling once/load initialization
ORA-00604: error occurred at recursive SQL level 1
ORA-00054: resource busy and acquire with NOWAIT specified or timeout expired
Tue 23 Jul 10:23:06 BST 2019

The “date” commands reveal a timeout of 30 seconds. Setting ddl_lock_timeout has no bearing on the timeout: the database is waiting on kpodplck wait before retrying ORA-54:

10:22:36 SQL> r
  1* select event, state from v$session where program like 'sqlldr%'

EVENT                                                            STATE
---------------------------------------------------------------- -------------------
kpodplck wait before retrying ORA-54                             WAITING

1 row selected.

This was where I left off with the previous post until I noticed there is another option!

Oracle 12.2 and later

In 12.2 and later you can instruct sqlldr to wait until the lock is released. There is a new parameter named direct_path_lock_timeout:

$ sqlldr | egrep 'Version|direct_path'
Version 19.4.0.0.0
direct_path_lock_wait -- wait for access to table when currently locked  (Default FALSE)

Interestingly there are no hits for direct_path_lock_wait in My Oracle Support’s knowledgebase. There are merely a few documentation references. So what does this parameter do? While the table is still locked in exclusive mode, let’s start the sqlldr process with the new option:

$ date; sqlldr /@loader control=t2_2.ctl direct_path_lock_wait=true; date
Fri 26 Jul 10:13:54 BST 2019

SQL*Loader: Release 19.0.0.0.0 - Production on Fri Jul 26 10:13:54 2019
Version 19.4.0.0.0

Copyright (c) 1982, 2019, Oracle and/or its affiliates.  All rights reserved.

Path used:      Direct
[ ... waiting ... ]

The process now sits there and waits … and it does so for more than 30 seconds. And instead of kpodplck wait before retrying ORA-54 it waits on … drums please: enq: TM contention!

10:20:11 SQL> select seq#, event, state, round(seconds_in_wait/60, 2) mins_waiting
10:20:21   2  from v$session where program like 'sqlldr%';

      SEQ# EVENT                    STATE               MINS_WAITING
---------- ------------------------ ------------------- ------------
       119 enq: TM - contention     WAITING                     6.53

10:20:26 SQL> 

This is great news if your sqlldr processes compete for TM enqueues and your load process takes a little longer than the previously hard coded timeout of 30 seconds. The process eventually completed successfully after the enqueue was released:

$ date; sqlldr /@loader control=t2_2.ctl direct_path_lock_wait=true; date
Fri 26 Jul 10:13:54 BST 2019

SQL*Loader: Release 19.0.0.0.0 - Production on Fri Jul 26 10:13:54 2019
Version 19.4.0.0.0

Copyright (c) 1982, 2019, Oracle and/or its affiliates.  All rights reserved.

Path used:      Direct

Load completed - logical record count 950936.

Table T2:
  950924 Rows successfully loaded.

Check the log file:
  t2_2.log
for more information about the load.
Fri 26 Jul 10:21:32 BST 2019

Caveats

As with every pro, there are usually cons associated. The downside to waiting (for a potentially very long time) is that you might not notice load processes beginning to stack up unless proper instrumentation and monitoring are in place. Waiting too long for data to be loaded is equally bad as not loading at all because the end result is identical. As with many features in the database Oracle gives you plenty of options, and it’s up to the developers and architects to make the correct decisions on how to use them.

Summary

Beginning with sqlldr 12.2 Oracle introduced the option to wait for enqueues on segments to be released instead of aborting after 30 seconds.

In the next post I’ll write about another possibility to prevent exclusive table locks in the first place when running multiple concurrent sqlldr sessions.

Using dbca to create a physical standby database

While investigating new options I discovered with dbca for the previous article I noticed that it’s now possible to use Oracle’s Database Creation Assistant (dbca) to create a physical standby database using the -createDuplicateDB flag.

I wanted to know how easily this can be done on my Oracle 18.5.0 system. I have 2 VMs, server3 and server4 running Oracle Linux 7.6. I created the primary database on server3. The database name is NCDB with the db_unique_name set to SITEA. I also use SITEA as the database SID to prevent confusion. My physical standby database with db_unique_name SITEB will reside on server4.

The setup is kept as simple as possible to avoid any unintended complications. In other words, this is a lab setup, not something you’d entertain using for any other purpose. As always, this is a tech post and not a piece about licencing. It is up to you to ensure you aren’t performing any tasks that you aren’t licensed for.

Creating the primary database

The primary database can be created using dbca as always. Unlike the last post, this one uses ASM, not a filesystem to show how easy it is to do both.

The primary database is a non-Container Database (NCDB). I intend to create the primary instance as SITEA (Site A) with the standby named SITEB. This way no one gets confused when the database runs in primary role in the designated disaster recovery location. I haven’t seen gdbName <> sid/db_unique_name in many single instance deployments and appreciate that might be unfamiliar but bear with me. I’ll try to make this as transparent as possible.

Invoking dbca

Enough talking, let’s create the database:

[oracle@server3 ~]$ dbca -silent -createDatabase \
> -gdbName NCDB \
> -templateName lab_template.dbc \
> -sid SITEA \
> -enableArchive true -archiveLogMode auto \
> -memoryMgmtType auto_sga \
> -createAsContainerDatabase false \
> -recoveryAreaDestination +RECO \
> -totalMemory 2048 \
> -datafileDestination +DATA \
> -initParams db_unique_name=SITEA,dg_broker_start=true \
> -customScripts add_srls_dbca.sql

[...]

Prepare for db operation
10% complete
Registering database with Oracle Restart
14% complete
Copying database files
43% complete
Creating and starting Oracle instance
45% complete
49% complete
53% complete
56% complete
62% complete
Completing Database Creation
68% complete
70% complete
71% complete
Executing Post Configuration Actions
100% complete
Database creation complete. For details check the logfiles at:
/u01/app/oracle/cfgtoollogs/dbca/SITEA.
Database Information:
Global Database Name:SITEA
System Identifier(SID):SITEA
Look at the log file "/u01/app/oracle/cfgtoollogs/dbca/SITEA/SITEA1.log" for further details.

A few words of explanation: As I said I use SITEA as db_unique_name and the database’s SID. In Oracle Managed Files (OMF) deployments a file name references the db_unique name, and I wanted my data files, temp files and log files all to be in +DATA/SITEA/. db_unique_name defaults to db_name, and not changing it would have resulted in the database being created in +DATA/NCDB and that’s not what I wanted.

I decided to include starting the Data Guard broker as part of the initialisation parameters. Archiving is enabled right from the start as well.

The custom script you see referenced creates the necessary number of standby redo logs. This will save me a bit of work, because RMAN is smart. When duplicating the database for use as a standby it creates standby redo logs (SRL) for me if if finds SRLs in the target database. Yet another thing less for me to worry about.

Implications of using gdbname and sid (+ db_unique_name) in dbca

If you haven’t used a SID <> gDBName combination before, you might feel about unsure about how Oracle creates things. First of all, it created the database with the db_name you passed to dbca as gdbname. In this post that’s NCDB. Normally, if you grep’d the operating system’s process table for NCDB you would find all the instance’s background processes. With my dbca command however (where an Oracle SID <> gdbname is provided) you won’t find anything though. Grep for the ORACLE_SID “SITEA” instead. Likewise, if you want to create a bequeath connection to the database, set your ORACLE_SID to SITEA.

Since this is Oracle Restart the database is registered with Grid Infrastructure under its db_unique_name/ORACLE_SID combination in the RDBMS home:

[oracle@server3 ~]$ srvctl config database
SITEA
[oracle@server3 ~]$ srvctl config database -db SITEA
Database unique name: SITEA
Database name: NCDB
Oracle home: /u01/app/oracle/product/18.0.0/dbhome_1
Oracle user: oracle
Spfile: +DATA/SITEA/PARAMETERFILE/spfile.273.1003226559
Password file:
Domain:
Start options: open
Stop options: immediate
Database role: PRIMARY
Management policy: AUTOMATIC
Disk Groups: DATA,RECO
Services:
OSDBA group:
OSOPER group:
Database instance: SITEA
[oracle@server3 ~]$

Interacting with the database via srvctl requires you to use the db_unique_name SITEA as shown.

This is my preferred way to set things up these days. I’d like to invite you to critically reflect about the approach I took. I prefer it over other designations such as “PROD” and “STDBY”.

Creating the standby database

With the primary database created, archivelog mode enabled plus a working Fast Recovery Area I can move on to creating the physical standby database.

Before I do this a few small changes have to be made to my network configuration. I always add TNS entries for both primary and standby database in the “primary” host’s $ORACLE_HOME/network/admin/tnsnames.ora file and ship this across to the “standby” host. They are needed later. With the preparation done, I proceed to calling dbca:

[oracle@server4 ~]$ dbca -silent -createDuplicateDB \
> -gdbName NCDB \
> -sid SITEB \
> -initParams db_create_file_dest=+DATA,db_recovery_file_dest=+RECO,dg_broker_start=true \
> -primaryDBConnectionString server3:1521/SITEA \
> -createAsStandby \
> -dbUniqueName SITEB

[ ... ]

Prepare for db operation
22% complete
Listener config step
44% complete
Auxiliary instance creation
67% complete
RMAN duplicate
89% complete
Post duplicate database operations
100% complete
Look at the log file "/u01/app/oracle/cfgtoollogs/dbca/SITEB/SITEB1.log" for further details.

So far so good. What did dbca do? And more importantly, how did it create the standby database? I didn’t have a backup of NCDB/SITEA at the time I called dbca on server4 so it must have performed a duplicate … from active database. Looking at the dbca trace in $ORACLE_BASE/cfgtoollogs/dbca/SITEB I can confirm this. After wading through a lot of messages, here’s the relevant bit:

INFO: Mar 11, 2019 12:14:04 PM oracle.assistants.dbca.driver.backend.steps.RmanDuplicateStep executeImpl
INFO: Running rman duplicate command:run {
set newname for datafile 1 to new;
set newname for datafile 3 to new;
set newname for datafile 4 to new;
set newname for datafile 7 to new;
duplicate target database
for standby
from active database
dorecover
nofilenamecheck;
}

This might be an issue for some users because it requires a direct connection to the source database. I don’t know if RMAN might use the “from service … using backupset …” clause if you provided an offline backup.

The files I care about are all in the right place:

SQL> select name from v$datafile union all
2 select name from v$tempfile union all
3 select member from v$logfile union all
4 select value from v$parameter2 where name = 'control_files';

NAME
-------------------------------------------------------
+DATA/SITEB/DATAFILE/system.268.1003228125
+DATA/SITEB/DATAFILE/sysaux.273.1003228127
+DATA/SITEB/DATAFILE/undotbs1.272.1003228129
+DATA/SITEB/DATAFILE/users.271.1003228129
+DATA/SITEB/TEMPFILE/temp.262.1003228149
+DATA/SITEB/ONLINELOG/group_3.266.1003228137
+RECO/SITEB/ONLINELOG/group_3.310.1003228137
+DATA/SITEB/ONLINELOG/group_2.267.1003228137
+RECO/SITEB/ONLINELOG/group_2.258.1003228137
+DATA/SITEB/ONLINELOG/group_1.270.1003228135
+RECO/SITEB/ONLINELOG/group_1.259.1003228135
+DATA/SITEB/ONLINELOG/group_4.265.1003228137
+RECO/SITEB/ONLINELOG/group_4.311.1003228137
+DATA/SITEB/ONLINELOG/group_5.264.1003228139
+RECO/SITEB/ONLINELOG/group_5.312.1003228139
+DATA/SITEB/ONLINELOG/group_6.274.1003228139
+RECO/SITEB/ONLINELOG/group_6.313.1003228141
+DATA/SITEB/ONLINELOG/group_7.263.1003228147
+RECO/SITEB/ONLINELOG/group_7.314.1003228147
+DATA/SITEB/CONTROLFILE/current.260.1003228117
+RECO/SITEB/CONTROLFILE/current.260.1003228117

21 rows selected.

As reported by other bloggers, dbca creates a “temporary” listener that it doesn’t remove after the database creation process is completed. I specifically wanted to see if this is the case with Oracle Restart as well and yes, it is:

[oracle@server4 SITEB]$ ps -ef | grep tnslsnr
oracle 1125 1 0 10:27 ? 00:00:00 /u01/app/oracle/product/18.0.0/dbhome_1/bin/tnslsnr LISTENER20190318102721 -inherit
grid 5837 1 0 09:01 ? 00:00:00 /u01/app/grid/product/18.0.0/grid/bin/tnslsnr LISTENER -no_crs_notify -inherit
oracle 7588 31809 0 10:44 pts/1 00:00:00 grep --color=auto tnslsnr

The extra listener didn’t survive a reboot though and the processes should disappear eventually. dbca persists the configuration into $ORACLE_HOME/network/admin/listener.ora though, and those entries should probably be removed. This is especially true with Oracle Restart (and RAC for that matter) because I want all listeners to be controlled from the GRID home, not the RDBMS home.

There are other leftover files in $ORACLE_HOME/dbs as well for which I’d hope dbca removes them one day.

On the plus side dbca registers the database in Oracle Restart for me as part of the work it did:

[oracle@server4 ~]$ srvctl config database -db SITEB
Database unique name: SITEB
Database name: NCDB
Oracle home: /u01/app/oracle/product/18.0.0/dbhome_1
Oracle user: oracle
Spfile: +DATA/SITEB/PARAMETERFILE/spfile.275.1003228201
Password file: +DATA/SITEB/orapwsiteb
Domain:
Start options: open
Stop options: immediate
Database role: PRIMARY
Management policy: AUTOMATIC
Disk Groups: DATA,RECO
Services:
OSDBA group:
OSOPER group:
Database instance: SITEB

It’s good to see that I don’t need to worry about storing password file and spfile in ASM myself, so that job is already taken care off. A few other things need to be changed though. The database is still considered a primary (of which I know it isn’t) and the start option therefore is wrong, too. There are licensing implications opening a standby read only rather than just mounting it when turning on redo apply. Refer to the documentation for more details.

Out of habit I changed the role to PHYSICAL_STANDBY and the start option to MOUNT. This is what I ended up with in my lab, YMMV and depends on how you are licensed.

[oracle@server4 ~]$ srvctl config database -db SITEB
Database unique name: SITEB
Database name: NCDB
Oracle home: /u01/app/oracle/product/18.0.0/dbhome_1
Oracle user: oracle
Spfile: +DATA/SITEB/PARAMETERFILE/spfile.275.1003228201
Password file: +DATA/SITEB/orapwsiteb
Domain:
Start options: mount
Stop options: immediate
Database role: PHYSICAL_STANDBY
Management policy: AUTOMATIC
Disk Groups: DATA,RECO
Services:
OSDBA group:
OSOPER group:
Database instance: SITEB

Creating the Broker configuration

The standby redo logs have been created by RMAN and with dg_broker_start set to true by dbca for both databases I can now create a Data Guard Broker configuration. With Oracle Restart I don’t have to statically register the databases with the listener anymore. Clusterware takes care of starting/stopping them during role changes.

[oracle@server3 ~]$ dgmgrl
DGMGRL for Linux: Release 18.0.0.0.0 - Production on Mon Mar 18 11:11:55 2019 Version 18.5.0.0.0

Copyright (c) 1982, 2018, Oracle and/or its affiliates. All rights reserved.

Welcome to DGMGRL, type "help" for information.
DGMGRL> connect sys@SITEA
Password:
Connected to "SITEA"
Connected as SYSDBA.
DGMGRL> create configuration autoconf
> primary database is 'SITEA'
> connect identifier is 'SITEA';
Configuration "autoconf" created with primary database "SITEA"
DGMGRL> add database 'SITEB' as connect identifier is 'SITEB';
Database "SITEB" added
DGMGRL> edit database 'SITEA' set property standbyfilemanagement=auto;
Property "standbyfilemanagement" updated
DGMGRL> edit database 'SITEB' set property standbyfilemanagement=auto;
Property "standbyfilemanagement" updated
DGMGRL> enable configuration
Enabled.
DGMGRL> show configuration

Configuration - autoconf

Protection Mode: MaxPerformance
Members:
SITEA - Primary database
SITEB - Physical standby database

Fast-Start Failover: DISABLED

Configuration Status:
SUCCESS (status updated 17 seconds ago)
DGMGRL>

You might want to increase the protection level from MaxPerformance to something that better suits your requirements. Three might be additional changes you want to do within the broker as well. The code output you just saw is the bare minimum I put into place.

Summary

All in all this has been pretty straight forward without too many hiccups along the way. If you want to you can put a lot of those steps into your favourite automation toolkit and you’ll end up with a standby database reasonably quickly provided your environment supports this kind of setup.

dbca now makes it easy to configure OMF on file systems

Up until – and including – Oracle 12.1 I always found it not-quite-so-straight-forward to create a new database using Database Creation Assistant (dbca) and configure it with Oracle Managed Files (OMF) on a file system in silent mode. I really like to use OMF in my lab databases as it saves me a lot of typing. I have also seen Oracle databases deployed in the cloud on file systems without ASM. So I was quite happy to see the syntax for dbca -silent -createDatabase was extended.

This post has been written using Oracle 18.4.0 on Linux.

Why might you want to do that?

When writing code to automatically provision databases you can’t have any interactive parts if you want an end-to-end provisioning workflow. Oracle thankfully provides options to call many GUI tools on the command line in so-called silent mode as well. This includes, but is not limited to, dbca. You can invoke the tool with a help flag, and it’ll tell you about its many options. They are so numerous that I refrain from showing them here, but you can get them from the Administration Guide.

And how does it work?

Using the minimum number of relevant options I can easily create a database using dbca and tell it to use OMF, pointing to a file system destination instead of ASM. Your choice of flags is most likely quite different from mine. This one worked for me in the lab:

[oracle@server1 ~]$ dbca -silent -createDatabase -gdbName NCDB -templateName lab_database.dbc \
-enableArchive true -archiveLogMode auto -memoryMgmtType auto_sga \
-createAsContainerDatabase false -recoveryAreaDestination /u01/fast_recovery_area \
-useOMF true -datafileDestination /u01/oradata -totalMemory 2048
[…]
Prepare for db operation
10% complete
Copying database files
40% complete
Creating and starting Oracle instance
42% complete
46% complete
50% complete
54% complete
60% complete
Completing Database Creation
66% complete
69% complete
70% complete
Executing Post Configuration Actions
100% complete
Database creation complete. For details check the logfiles at:
/u01/app/oracle/cfgtoollogs/dbca/NCDB.
Database Information:
Global Database Name:NCDB
System Identifier(SID):NCDB
Look at the log file "/u01/app/oracle/cfgtoollogs/dbca/NCDB/NCDB.log" for further details.
[oracle@server1 ~]$

You might have noticed the options to enable archivelog-mode as well. I’ll write about these in the next post :) Oh and the database is really created using OMF:

SQL> select name from v$tempfile union all
2 select name from v$datafile union all
3 select member from v$logfile union all
4 select value from v$parameter2 where name = 'control_files';

NAME
------------------------------------------------------------
/u01/oradata/NCDB/datafile/o1_mf_temp_g3gt1t7w_.tmp
/u01/oradata/NCDB/datafile/o1_mf_system_g3gsyght_.dbf
/u01/oradata/NCDB/datafile/o1_mf_sysaux_g3gszkmp_.dbf
/u01/oradata/NCDB/datafile/o1_mf_undotbs1_g3gt0bq9_.dbf
/u01/oradata/NCDB/datafile/o1_mf_users_g3gt0ct3_.dbf
/u01/oradata/NCDB/onlinelog/o1_mf_3_g3gt1lpw_.log
/u01/fast_recovery_area/NCDB/onlinelog/o1_mf_3_g3gt1mp8_.log
/u01/oradata/NCDB/onlinelog/o1_mf_2_g3gt1lp4_.log
/u01/fast_recovery_area/NCDB/onlinelog/o1_mf_2_g3gt1mqt_.log
/u01/oradata/NCDB/onlinelog/o1_mf_1_g3gt1los_.log
/u01/fast_recovery_area/NCDB/onlinelog/o1_mf_1_g3gt1mq0_.log
/u01/oradata/NCDB/controlfile/o1_mf_g3gt1j3w_.ctl
/u01/fast_recovery_area/NCDB/controlfile/o1_mf_g3gt1j5o_.ctl

Final thoughts

Until now it’s been quite difficult (at least for me) to enable OMF on a file system when using dbca in CLI mode. This is no longer the case.

Making some more sense of direct path reads during primary key lookups

After having published my first article of 2019 I have received feedback I felt like including. With a nod to @fritshoogland, @ChrisAntognini and @FranckPachot.

In the previous post I showed you output of Tanel Poder’s ashtop.sql as proof that direct path reads can occur even if all you do is look up data by primary key. This script touches v$active_session_history, and I’m not getting tired of mentioning that you need to license the system in scope for Enterprise Edition and the Diagnostics Pack to do so.

What I haven’t shown you in more detail in the previous article is what causes these direct path reads. This is what I’ll try to do next. I have started by repeating my test case but added the gather_plan_statistics hint to the statement, resulting in a different SQL ID. Yesterday I noticed that Safari doesn’t show the scroll bar at the bottom of this code snippet other browsers show, I hope output isn’t garbled. I’m using the universal excuse here “it works on my laptop”.

SQL> @xia a66axyw2g6yjb
Display Execution plan in advanced format for sqlid a66axyw2g6yjb

PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------------------------
SQL_ID  a66axyw2g6yjb, child number 0
-------------------------------------
select /*+ gather_plan_statistics CLOB standalone */ *  from
martin.orders_clob  where order_id = :1

Plan hash value: 3284193906

----------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                   | Name           | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers |
----------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |                |      1 |        |       |     3 (100)|          |      0 |00:00:00.01 |       3 |
|   1 |  TABLE ACCESS BY INDEX ROWID| ORDERS_CLOB    |      1 |      1 |   137 |     3   (0)| 00:00:01 |      0 |00:00:00.01 |       3 |
|*  2 |   INDEX UNIQUE SCAN         | PK_ORDERS_CLOB |      1 |      1 |       |     2   (0)| 00:00:01 |      0 |00:00:00.01 |       3 |
----------------------------------------------------------------------------------------------------------------------------------------

Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------

   1 - SEL$1 / ORDERS_CLOB@SEL$1
   2 - SEL$1 / ORDERS_CLOB@SEL$1

Outline Data
-------------

  /*+
      BEGIN_OUTLINE_DATA
      IGNORE_OPTIM_EMBEDDED_HINTS
      OPTIMIZER_FEATURES_ENABLE('18.1.0')
      DB_VERSION('18.1.0')
      ALL_ROWS
      OUTLINE_LEAF(@"SEL$1")
      INDEX_RS_ASC(@"SEL$1" "ORDERS_CLOB"@"SEL$1" ("ORDERS_CLOB"."ORDER_ID"))
      END_OUTLINE_DATA
  */

Peeked Binds (identified by position):
--------------------------------------

   1 - :1 (NUMBER): 519990

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

   2 - access("ORDER_ID"=:1)

Column Projection Information (identified by operation id):
-----------------------------------------------------------

   1 - "ORDER_ID"[NUMBER,22], "ORDERS_CLOB"."ORDER_CLOB"[LOB,4000], "ORDERS_CLOB"."ORDER_DATE"[TIMESTAMP WITH LOCAL TIME
       ZONE,11], "ORDERS_CLOB"."ORDER_MODE"[VARCHAR2,8], "ORDERS_CLOB"."CUSTOMER_ID"[NUMBER,22],
       "ORDERS_CLOB"."ORDER_STATUS"[NUMBER,22], "ORDERS_CLOB"."ORDER_TOTAL"[NUMBER,22], "ORDERS_CLOB"."SALES_REP_ID"[NUMBER,22],
       "ORDERS_CLOB"."PROMOTION_ID"[NUMBER,22], "ORDERS_CLOB"."WAREHOUSE_ID"[NUMBER,22], "ORDERS_CLOB"."DELIVERY_TYPE"[VARCHAR2,15],
       "ORDERS_CLOB"."COST_OF_DELIVERY"[NUMBER,22], "ORDERS_CLOB"."WAIT_TILL_ALL_AVAILABLE"[VARCHAR2,15],
       "ORDERS_CLOB"."DELIVERY_ADDRESS_ID"[NUMBER,22], "ORDERS_CLOB"."CUSTOMER_CLASS"[VARCHAR2,30],
       "ORDERS_CLOB"."CARD_ID"[NUMBER,22], "ORDERS_CLOB"."INVOICE_ADDRESS_ID"[NUMBER,22]
   2 - "ORDERS_CLOB".ROWID[ROWID,10], "ORDER_ID"[NUMBER,22]


57 rows selected.

After a few minutes of executing the statement repeatedly, direct path reads are clearly visible again

SELECT
    COUNT(*),
    event,
    session_state
FROM
    v$active_session_history ash
WHERE
    sql_id = 'a66axyw2g6yjb'
    AND sample_time > SYSDATE - 15 / 1440
GROUP BY
    event,
    session_state
ORDER BY
    1 DESC;

  COUNT(*) EVENT                                    SESSION
---------- ---------------------------------------- -------
      1592                                          ON CPU
        24 direct path read                         WAITING
         6 cursor: pin S                            WAITING
         4 SQL*Net more data to client              WAITING

So far so good. Getting back to the original question: what’s causing these? ASH provides the answer to that question as well.

SELECT
    COUNT(*),
    event,
    session_state,
    sql_plan_operation
    || ' '
    || sql_plan_options AS what,
    CASE
        WHEN wait_class IN(
            'Application',
            'Cluster',
            'Concurrency',
            'User I/O'
        )THEN object_name
        ELSE 'undef'
    END AS obj
FROM
    v$active_session_history ash,
    dba_objects o
WHERE
    ash.current_obj# = o.object_id
    AND sql_id = 'a66axyw2g6yjb'
GROUP BY
    event,
    session_state,
    sql_plan_operation
    || ' '
    || sql_plan_options,
    CASE
        WHEN wait_class IN(
            'Application',
            'Cluster',
            'Concurrency',
            'User I/O'
        )THEN object_name
        ELSE 'undef'
    END
ORDER BY 1 desc;

  COUNT(*) EVENT                                    SESSION WHAT                           OBJ
---------- ---------------------------------------- ------- ------------------------------ ------------------------------
      3006                                          ON CPU  SELECT STATEMENT               undef
       223                                          ON CPU  INDEX UNIQUE SCAN              undef
       126                                          ON CPU  TABLE ACCESS BY INDEX ROWID    undef
        50 direct path read                         WAITING SELECT STATEMENT               SYS_LOB0000081921C00002$$
         8 cursor: pin S                            WAITING SELECT STATEMENT               SYS_LOB0000081921C00002$$
         8 SQL*Net more data to client              WAITING SELECT STATEMENT               undef
         1                                          ON CPU                                 undef

7 rows selected.

I think you might be getting the idea by now … I can link the segment back to DBA_LOBS, and … it’s the LOB column of ORDERS_CLOB.

SELECT
    table_name,
    column_name,
    segment_name,
    cache,
    securefile
FROM
    dba_lobs
WHERE
    segment_name = 'SYS_LOB0000081921C00002$$';

TABLE_NAME      COLUMN_NAME     SEGMENT_NAME                   CACHE      SEC
--------------- --------------- ------------------------------ ---------- ---
ORDERS_CLOB     ORDER_CLOB      SYS_LOB0000081921C00002$$      NO         YES

QED.

Another option is to query session statistics. I looked at one of the sessions using snapper4.sql but the output was too wide to paste it as text. I’ll resort to the traditional way of doing this:

SELECT
name,
value
FROM
v$sesstat st
NATURAL JOIN v$statname sn
WHERE
st.sid = 128
AND st.value <> 0
AND REGEXP_LIKE(name, '(physical|securefile).*read.*')
ORDER BY
sn.name;

NAME VALUE
----------------------------------------- ----------
physical read IO requests 106836
physical read bytes 875200512
physical read total IO requests 106836
physical read total bytes 875200512
physical reads 106836
physical reads direct 106836
physical reads direct (lob) 106836
securefile direct read bytes 875200512
securefile direct read ops 106836
9 rows selected.

I admit this was a rather manual way of extracting this piece of information, you might be able to get the same data with an ASH report (provided the number of I/O samples against that segment is significant enough to show up). In this context I’d like to recommend planx.sql you can find on Carlos Sierra’s and Mauro Pagano’s github repository. It’s small, lightweight, and incredibly useful.

Little things worth knowing: parallel Data Pump export in table mode

I haven’t used Data Pump in a little while but recently needed to do a bit of work involving this very useful utility to export a single table. I know that it is possible to export data in parallel using expdp, but I can’t recall the syntax for doing so off the top of my head when I need it. This post describes a potential approach to exporting a table in parallel. In the next post I will demonstrate an interesting case where using parallelism didn’t help me speed up the export. All of this was tested on 12.2 and 18.4.0, the examples I am sharing originate from my 18.4.0 single instance database (without ASM) running on Linux.

The setup

My lab environment is a bit limited when it comes to storage, so I’ll have to do with small-ish tables. The basic principles should still apply for larger segments though. Please note that my tables aren’t partitioned to keep the individual segment size as large as possible. 

My data is once more based on Swingbench’s order entry schema. The table I’ll use in my first example is the well-known ORDER_ITEMS table:

$ sql soe

SQLcl: Release 17.3.0 Production on Wed Dec 12 18:12:00 2018

Copyright (c) 1982, 2018, Oracle. All rights reserved.

Password? (*******?) *********
Last Successful login time: Wed Dec 12 2018 18:12:01 +01:00

Connected to:
Oracle Database 18c Enterprise Edition Release 18.0.0.0.0 - Production
Version 18.4.0.0.0

SQL> info soe.order_items
TABLE: ORDER_ITEMS
LAST ANALYZED:2018-12-11 22:19:40.0
ROWS :68442528
SAMPLE SIZE :68442528
INMEMORY :DISABLED
COMMENTS :

Columns
NAME DATA TYPE NULL DEFAULT COMMENTS
*LINE_ITEM_ID NUMBER(3,0) Yes
*ORDER_ID NUMBER(12,0) Yes
PRODUCT_ID NUMBER(6,0) Yes
UNIT_PRICE NUMBER(8,2) Yes
QUANTITY NUMBER(8,0) Yes
DISPATCH_DATE DATE Yes
RETURN_DATE DATE Yes
GIFT_WRAP VARCHAR2(20 BYTE) Yes
CONDITION VARCHAR2(20 BYTE) Yes
SUPPLIER_ID NUMBER(6,0) Yes
ESTIMATED_DELIVERY DATE Yes

Indexes
INDEX_NAME UNIQUENESS STATUS FUNCIDX_STATUS COLUMNS
SOE.ITEM_ORDER_IX NONUNIQUE VALID ORDER_ID
SOE.ORDER_ITEMS_PK UNIQUE VALID ORDER_ID, LINE_ITEM_ID
SOE.ITEM_PRODUCT_IX NONUNIQUE VALID PRODUCT_ID

Running an export without any parallelism

I’ll use this example as the baseline, exporting the table without parallelism. This example is quite basic, and you will probably have to adjust it to suit your needs. I am assuming basic familiarity with the Data Pump toolset, if not, head over to the documentation and read up on the concepts. The non-parallel expdp call is shown here:

$ expdp martin directory=exptest logfile=exp_order_items_noparallel.log \
> dumpfile=exp_order_items_noparallel.dmp tables=soe.order_items

[...]

Export: Release 18.0.0.0.0 - Production on Wed Dec 12 19:00:38 2018
Version 18.4.0.0.0

Copyright (c) 1982, 2018, Oracle and/or its affiliates. All rights reserved.

Connected to: Oracle Database 18c Enterprise Edition Release 18.0.0.0.0 - Production
Starting "MARTIN"."SYS_EXPORT_TABLE_01": martin
directory=exptest logfile=exp_order_items_noparallel.log
dumpfile=exp_order_items_noparallel.dmp tables=soe.order_items
Processing object type TABLE_EXPORT/TABLE/TABLE_DATA
Processing object type TABLE_EXPORT/TABLE/INDEX/STATISTICS/INDEX_STATISTICS
Processing object type TABLE_EXPORT/TABLE/STATISTICS/TABLE_STATISTICS
Processing object type TABLE_EXPORT/TABLE/STATISTICS/MARKER
Processing object type TABLE_EXPORT/TABLE/TABLE
Processing object type TABLE_EXPORT/TABLE/INDEX/INDEX
Processing object type TABLE_EXPORT/TABLE/CONSTRAINT/CONSTRAINT
. . exported "SOE"."ORDER_ITEMS" 3.601 GB 68442528 rows
Master table "MARTIN"."SYS_EXPORT_TABLE_01" successfully loaded/unloaded
***************************************************************************
Dump file set for MARTIN.SYS_EXPORT_TABLE_01 is:
/u01/data_pump/ORCL/exp_order_items_noparallel.dmp
Job "MARTIN"."SYS_EXPORT_TABLE_01" successfully completed at Wed Dec 12 19:01:22 2018 elapsed 0 00:00:43

So it takes about 43 seconds for expdp to create the file.

Adding parallelism

The next attempt I made was to introduce parallelism. For expdp to actually use parallelism in the first place, you need to have multiple dump files to write to. This is accomplished by using the %U placeholder in the file name, as shown here:

$ expdp martin directory=exptest logfile=exp_order_items.log \
> dumpfile=exp_order_items_%U.dmp parallel=4 tables=soe.order_items

Export: Release 18.0.0.0.0 - Production on Wed Dec 12 19:56:42 2018
Version 18.4.0.0.0

Copyright (c) 1982, 2018, Oracle and/or its affiliates. All rights reserved.

Connected to: Oracle Database 18c Enterprise Edition Release 18.0.0.0.0 - Production
Starting "MARTIN"."SYS_EXPORT_TABLE_01": martin directory=exptest
logfile=exp_order_items.log dumpfile=exp_order_items_%U.dmp parallel=4
tables=soe.order_items
Processing object type TABLE_EXPORT/TABLE/INDEX/STATISTICS/INDEX_STATISTICS
Processing object type TABLE_EXPORT/TABLE/STATISTICS/TABLE_STATISTICS
Processing object type TABLE_EXPORT/TABLE/TABLE_DATA
Processing object type TABLE_EXPORT/TABLE/INDEX/INDEX
Processing object type TABLE_EXPORT/TABLE/TABLE
Processing object type TABLE_EXPORT/TABLE/CONSTRAINT/CONSTRAINT
Processing object type TABLE_EXPORT/TABLE/STATISTICS/MARKER
. . exported "SOE"."ORDER_ITEMS" 3.601 GB 68442528 rows
Master table "MARTIN"."SYS_EXPORT_TABLE_01" successfully loaded/unloaded

Dump file set for MARTIN.SYS_EXPORT_TABLE_01 is:
/u01/data_pump/ORCL/exp_order_items_01.dmp
/u01/data_pump/ORCL/exp_order_items_02.dmp
/u01/data_pump/ORCL/exp_order_items_03.dmp
/u01/data_pump/ORCL/exp_order_items_04.dmp
/u01/data_pump/ORCL/exp_order_items_05.dmp
Job "MARTIN"."SYS_EXPORT_TABLE_01" successfully completed at Wed Dec 12 19:57:02 2018 elapsed 0 00:00:20

So this isn’t too bad: using parallel 4 I managed to cut the time it takes to export the table in half. If you read the Data Pump white paper you can see that the job of the worker processes is not just the data unloading, they also have to create metadata for the object currently exported. I supposed this is the reason why there are 5 dump files. You can see they aren’t all the same size:

$ ls -lh /u01/data_pump/ORCL/exp_order_items_0[12345].dmp
-rw-r----- 1 oracle oinstall 1.2G Dec 12 19:57 /u01/data_pump/ORCL/exp_order_items_01.dmp
-rw-r----- 1 oracle oinstall 16K Dec 12 19:56 /u01/data_pump/ORCL/exp_order_items_02.dmp
-rw-r----- 1 oracle oinstall 192K Dec 12 19:57 /u01/data_pump/ORCL/exp_order_items_03.dmp
-rw-r----- 1 oracle oinstall 1.3G Dec 12 19:57 /u01/data_pump/ORCL/exp_order_items_04.dmp
-rw-r----- 1 oracle oinstall 1.3G Dec 12 19:57 /u01/data_pump/ORCL/exp_order_items_05.dmp

What I really like about the Data Pump API is the ability to attach to a job and see what it’s doing. While the export was running, I had a quick look at it:

$ expdp martin attach=SYS_EXPORT_TABLE_01

Export: Release 18.0.0.0.0 - Production on Wed Dec 12 19:56:54 2018
Version 18.4.0.0.0

Copyright (c) 1982, 2018, Oracle and/or its affiliates. All rights reserved.
[...]
Connected to: Oracle Database 18c Enterprise Edition Release 18.0.0.0.0 - Production

Job: SYS_EXPORT_TABLE_01
Owner: MARTIN
Operation: EXPORT
Creator Privs: TRUE
GUID: 7CD567F0F8D057DDE0530164A8C0392F
Start Time: Wednesday, 12 December, 2018 19:56:43
Mode: TABLE
Instance: ORCL
Max Parallelism: 4
Timezone: +02:00
Timezone version: 31
Endianness: LITTLE
NLS character set: AL32UTF8
NLS NCHAR character set: AL16UTF16
EXPORT Job Parameters:
Parameter Name Parameter Value:
CLIENT_COMMAND martin directory=exptest
logfile=exp_order_items.log dumpfile=exp_order_items_%U.dmp
parallel=4 tables=soe.order_items
TRACE 0
State: EXECUTING
Bytes Processed: 0
Current Parallelism: 4
Job Error Count: 0
Job heartbeat: 5
Dump File: /u01/data_pump/ORCL/exp_order_items_%u.dmp
Dump File: /u01/data_pump/ORCL/exp_order_items_01.dmp
bytes written: 8,192
Dump File: /u01/data_pump/ORCL/exp_order_items_02.dmp
bytes written: 16,384
Dump File: /u01/data_pump/ORCL/exp_order_items_03.dmp
bytes written: 16,384
Dump File: /u01/data_pump/ORCL/exp_order_items_04.dmp
bytes written: 4,096
Dump File: /u01/data_pump/ORCL/exp_order_items_05.dmp
bytes written: 4,096

Worker 1 Status:
Instance ID: 1
Instance name: ORCL
Host name: server1
Object start time: Wednesday, 12 December, 2018 19:56:46
Object status at: Wednesday, 12 December, 2018 19:56:47
Process Name: DW00
State: WORK WAITING

Worker 2 Status:
Instance ID: 1
Instance name: ORCL
Host name: server1
Object start time: Wednesday, 00 Sat, 0000 0:00:00
Object status at: Wednesday, 12 December, 2018 15
Process Name: DW01
State: WORK WAITING

Worker 3 Status:
Instance ID: 1
Instance name: ORCL
Host name: server1
Object start time: Wednesday, 12 December, 2018 19:56:47
Object status at: Wednesday, 12 December, 2018 19:56:48
Process Name: DW02
State: EXECUTING
Object Schema: SOE
Object Name: ORDER_ITEMS
Object Type: TABLE_EXPORT/TABLE/TABLE_DATA
Completed Objects: 1
Total Objects: 1
Completed Rows: 33,417,535
Worker Parallelism: 3

Worker 4 Status:
Instance ID: 1
Instance name: ORCL
Host name: server1
Access method: direct_path
Object start time: Wednesday, 12 December, 2018 19:56:45
Object status at: Wednesday, 12 December, 2018 19:56:49
Process Name: DW03
State: WORK WAITING

The output is quite interesting. It confirms that I’m running with parallel 4 and it also shows that only 1 file is really being written to by worker 3. It does so in parallel. If you recall from the ls command earlier, there were 3 files of roughly 1.3 GB each. They surely have been written to by the 3rd worker process.

Summary

I have been able to export a table in parallel using Data Pump, and by doing so I cut the time it took to export the table in half. This is a great feature which I am certainly going to use regularly.