Data … as usual

All things about data by Laurent Leturgez

Category Archives: 11g

Insert data in Oracle with Java … Batched mode.

1 Comment Posted by on January 19, 2018

Problem / Context

Today, I worked on a performance issue at my customer. The context is a Java app which did a processing and at the end of this processing, the application inserts tons of data on an Oracle database.

The customers was complaining about slow performance on the insertion phase and asked me to have a look on it.

Database was IO Bound, and many sessions were doing some one-row inserts on various tables (INSERT INTO … VALUES (:1, :2, …) ). These one-row insert were off course processed many times, and oracle session’s stats was reporting a high number of executions.

On the Java side

As an Oracle DBA or Developer, we all know that, with PLSQL, it’s easy to write a FORALL loop that will bulk insert the data, and then reduce execution time. To do that, you need to have a cursor which is read in bulkl (BULK COLLECT) and each part is then inserted in the database. This reduces the number of operations, loops etc.


DECLARE
CURSOR s_cur IS
SELECT *
FROM servers;

TYPE fetch_array IS TABLE OF s_cur%ROWTYPE;
s_array fetch_array;
BEGIN
OPEN s_cur;
LOOP
FETCH s_cur BULK COLLECT INTO s_array LIMIT 1000;

FORALL i IN 1..s_array.COUNT
INSERT INTO servers2 VALUES s_array(i);

EXIT WHEN s_cur%NOTFOUND;
END LOOP;
CLOSE s_cur;
COMMIT;
END;
/

Source: http://psoug.org/snippet/FORALL-Insert_499.htm

In Java, the problem can be different because the data processed by your app are not necesseraly coming from a database.

Usually, statements are prepared, variables are attached and the statement is executed. When it’s done in a loop, it looks something like that:


try{
         DriverManager.registerDriver (new oracle.jdbc.driver.OracleDriver());
         Connection c = DriverManager.getConnection ("jdbc:oracle:thin:@192.168.99.8:1521:orcl","laurent","laurent");
         PreparedStatement stmt = c.prepareStatement("insert into emp(employee_id,first_name,last_name,salary) values (?,?,?,?)");
         start=System.currentTimeMillis();

         for (int i=0 ; i < 50000 ; i++) {
                  stmt.setInt(1,i);
                  stmt.setString(2,generateRandomChars("01234567890ABCDEF",16));
                  stmt.setString(3,generateRandomChars("01234567890ABCDEF",16));
                  stmt.setInt(4,r.nextInt(10000+1)+5000);
                  stmt.executeUpdate();
         }
         stop=System.currentTimeMillis();
         System.out.println("time = "+(stop-start));
         stmt.close();
         c.close();
   }
   catch(Exception e){
      System.err.println(e);
      e.printStackTrace();
   }

The problem is the statement is sent to the database 50000 times, and then increase number of operation between the database and the application. As a result, execution time is high (this demo has been executed on a VM on my laptop):

[oracle@oel6 JAVA]$ time java -cp $CLASSPATH:ojdbc7.jar:. TestNoBatchedInsert
time = 75430

real    1m16.514s
user    0m5.279s
sys     0m1.080s

As for PLSQL, there is a technique to write a beautiful and powerful java code that will process inserts by batchs, and then reduce the number of loops, calls between database and application etc.

To do that, instead of using executeStatement method X times, we can use the addBatch method that will create a “batch” which will be executed on the database when PreparedStatement’s method “executeBatch” will be called.

If you’re familiar with FORALL in PLSQL, you probably know that, the more the batchsize is big, the more memory you will use. In Java, it will be the same and the result will be a bigger heap size, that’s why it’s recommended to define a batch size and each time your batch will reach a max size, the batch will be executed. This can be done like this:

try{
        DriverManager.registerDriver (new oracle.jdbc.driver.OracleDriver());
        Connection c = DriverManager.getConnection ("jdbc:oracle:thin:@192.168.99.8:1521:orcl","laurent","laurent");
        PreparedStatement stmt = c.prepareStatement("insert into emp(employee_id,first_name,last_name,salary) values (?,?,?,?)");
        start=System.currentTimeMillis();

        int batchSize=5000;
        int count=0;
        for (int i=0 ; i < 50000 ; i++) {
                stmt.setInt(1,i);
                stmt.setString(2,generateRandomChars("01234567890ABCDEF",16));
                stmt.setString(3,generateRandomChars("01234567890ABCDEF",16));
                stmt.setInt(4,r.nextInt(10000+1)+5000);
                stmt.addBatch();

                if (++count % batchSize == 0) {
                        stmt.executeBatch();
                }
        }

        stop=System.currentTimeMillis();
        System.out.println("time = "+(stop-start));
        stmt.close();
        c.close();
}
catch(Exception e){
  System.err.println(e);
  e.printStackTrace();
}

Now, if I run this program, wall time is not really the same scale:

[oracle@oel6 JAVA]$ time java -cp $CLASSPATH:ojdbc7.jar:. TestBatchedInsert
time = 598

real    0m1.964s
user    0m3.393s
sys     0m0.269s

On the database side

AWR Reports show many things:

  • First,  if we run the java sample codes as they are described, the no batch mode will commit the database after each execute update. As a result, log file switch event will increase:

Non batched inserts:

Top 10 Foreground Events by Total Wait Time
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
                                           Total Wait       Wait   % DB Wait
Event                                Waits Time (sec)    Avg(ms)   time Class
------------------------------ ----------- ---------- ---------- ------ --------
log file sync                       49,999         64       1.28   86.8 Commit
DB CPU                                            9.3              12.6
db file sequential read                 47          0       0.97     .1 User I/O
SQL*Net message to client           50,012          0       0.00     .1 Network
log file switch completion               1          0      27.60     .0 Configur
undo segment extension                   2          0       5.16     .0 Configur
direct path write                        3          0       1.08     .0 User I/O
direct path sync                         1          0       3.15     .0 User I/O
Disk file operations I/O                19          0       0.04     .0 User I/O
control file sequential read           194          0       0.00     .0 System I

Batched inserts:

Top 10 Foreground Events by Total Wait Time
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
                                           Total Wait       Wait   % DB Wait
Event                                Waits Time (sec)    Avg(ms)   time Class
------------------------------ ----------- ---------- ---------- ------ --------
DB CPU                                             .3              72.9
SQL*Net more data from client          268          0       0.17   10.1 Network
log file sync                           13          0       3.29    9.5 Commit
db file sequential read                 49          0       0.37    4.0 User I/O
Disk file operations I/O                17          0       0.03     .1 User I/O
control file sequential read           134          0       0.00     .1 System I
SQL*Net more data to client             10          0       0.02     .1 Network
SQL*Net message to client               22          0       0.00     .0 Network
log file single write                    0          0                .0 System I
asynch descriptor resize                 0          0                .0 Other
  • Then, due to batched process, number of buffer gets is reduced when batched inserts are used

Non batched inserts:

Segments by Logical Reads                   DB/Inst: ORCL/orcl  Snaps: 200-201
-> Total Logical Reads:         212,288
-> Captured Segments account for   28.4% of Total
-> When ** MISSING ** occurs, some of the object attributes may not be available

                     Tablespace
Owner                   Name
-------------------- ----------
                     Subobject  Obj.                             Logical
Object Name            Name     Type        Obj#   Dataobj#        Reads  %Total
-------------------- ---------- ----- ---------- ---------- ------------ -------
LAURENT              USERS
EMP                             TABLE      93857      93860       52,576   24.77

Batched inserts:

Segments by Logical Reads                   DB/Inst: ORCL/orcl  Snaps: 201-202
-> Total Logical Reads:          11,792
-> Captured Segments account for   83.0% of Total
-> When ** MISSING ** occurs, some of the object attributes may not be available

                     Tablespace
Owner                   Name
-------------------- ----------
                     Subobject  Obj.                             Logical
Object Name            Name     Type        Obj#   Dataobj#        Reads  %Total
-------------------- ---------- ----- ---------- ---------- ------------ -------
LAURENT              USERS
EMP                             TABLE      93857      93860        3,504   29.72
  • Same for buffer gets. Execution number is less for batched inserts (number of execution depends on your batch size)

Non batched inserts:

     Buffer                 Gets              Elapsed
      Gets   Executions   per Exec   %Total   Time (s)  %CPU   %IO    SQL Id
----------- ----------- ------------ ------ ---------- ----- ----- -------------
    152,587      50,000          3.1   71.9        2.1  11.3     0 7c9ws5uvx9nyc
Module: JDBC Thin Client
insert into emp(employee_id,first_name,last_name,salary) values (:1 ,:2 ,:3 ,:4
)

Batched inserts:

     Buffer                 Gets              Elapsed
      Gets   Executions   per Exec   %Total   Time (s)  %CPU   %IO    SQL Id
----------- ----------- ------------ ------ ---------- ----- ----- -------------
      3,669          10        366.9   31.1        0.1    57     0 7c9ws5uvx9nyc
Module: JDBC Thin Client
insert into emp(employee_id,first_name,last_name,salary) values (:1 ,:2 ,:3 ,:4)

 

When developer have to insert tons on data from a java app, it’s better when they used the best way to do it …. batched inserts have to be used in that case, it will help the database to be more powerful.

That’s it for today 😉

11g, 12c, Development, java, Oracle, PL/SQL, tuning

Brute forcing the Oracle Password file

Leave a comment Posted by on December 15, 2017

If you want to remotely connect to your Oracle instance as sysdba, by default (ie. remote_login_passwordfile=EXCLUSIVE), you will probably use the password file (located in $ORACLE_HOME/dbs) to identify the SYS user.

Below, I used auditd to show that the password file is read by the server process when connecting remotely:

[oracle@oel6 ~]$ sudo service auditd status
auditd (pid  2422) is running...

[oracle@oel6 ~]$ sudo auditctl -l
No rules

[oracle@oel6 ~]$ sudo auditctl -w $ORACLE_HOME/dbs/orapworcl -p r
[oracle@oel6 ~]$ sudo auditctl -l
-w /u01/app/oracle/product/12.2.0/dbhome_1/dbs/orapworcl -p r

[oracle@oel6 ~]$ sqlplus sys@orcl as sysdba

SQL*Plus: Release 12.2.0.1.0 Production on Fri Dec 15 09:14:52 2017

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

Enter password:

Connected to:
Oracle Database 12c Enterprise Edition Release 12.2.0.1.0 - 64bit Production


[oracle@oel6 ~]$ sudo ausearch -f $ORACLE_HOME/dbs/orapworcl | grep -A 2 '^type=PATH'
type=PATH msg=audit(1513326435.361:310): item=0 name="/u01/app/oracle/product/12.2.0/dbhome_1/dbs/orapworcl" inode=109527 dev=fc:02 mode=0100640 ouid=500 ogid=500 rdev=00:00
type=CWD msg=audit(1513326435.361:310):  cwd="/u01/app/oracle/product/12.2.0/dbhome_1/dbs"
type=SYSCALL msg=audit(1513326435.361:310): arch=c000003e syscall=2 success=yes exit=7 a0=7ffe8aaf9c18 a1=0 a2=0 a3=3 items=1 ppid=1 pid=7840 auid=500 uid=500 gid=500 euid=500 suid=500 fsuid=500 egid=500 sgid=500 fsgid=500 ses=3 tty=(none) comm="oracle_7840_orc" exe="/u01/app/oracle/product/12.2.0/dbhome_1/bin/oracle" key=(null)
--
type=PATH msg=audit(1513326435.361:311): item=0 name="/u01/app/oracle/product/12.2.0/dbhome_1/dbs/orapworcl" inode=109527 dev=fc:02 mode=0100640 ouid=500 ogid=500 rdev=00:00
type=CWD msg=audit(1513326435.361:311):  cwd="/u01/app/oracle/product/12.2.0/dbhome_1/dbs"
type=SYSCALL msg=audit(1513326435.361:311): arch=c000003e syscall=2 success=yes exit=7 a0=7ffe8aaf9c18 a1=0 a2=0 a3=3 items=1 ppid=1 pid=7840 auid=500 uid=500 gid=500 euid=500 suid=500 fsuid=500 egid=500 sgid=500 fsgid=500 ses=3 tty=(none) comm="oracle_7840_orc" exe="/u01/app/oracle/product/12.2.0/dbhome_1/bin/oracle" key=(null)
--
type=PATH msg=audit(1513326435.361:312): item=0 name="/u01/app/oracle/product/12.2.0/dbhome_1/dbs/orapworcl" inode=109527 dev=fc:02 mode=0100640 ouid=500 ogid=500 rdev=00:00
type=CWD msg=audit(1513326435.361:312):  cwd="/u01/app/oracle/product/12.2.0/dbhome_1/dbs"
type=SYSCALL msg=audit(1513326435.361:312): arch=c000003e syscall=2 success=yes exit=7 a0=797bfbd8 a1=0 a2=0 a3=7ffe8aaf9c70 items=1 ppid=1 pid=7840 auid=500 uid=500 gid=500 euid=500 suid=500 fsuid=500 egid=500 sgid=500 fsgid=500 ses=3 tty=(none) comm="oracle_7840_orc" exe="/u01/app/oracle/product/12.2.0/dbhome_1/bin/oracle" key=(null)
--
type=PATH msg=audit(1513326435.361:313): item=0 name="/u01/app/oracle/product/12.2.0/dbhome_1/dbs/orapworcl" inode=109527 dev=fc:02 mode=0100640 ouid=500 ogid=500 rdev=00:00
type=CWD msg=audit(1513326435.361:313):  cwd="/u01/app/oracle/product/12.2.0/dbhome_1/dbs"
type=SYSCALL msg=audit(1513326435.361:313): arch=c000003e syscall=2 success=yes exit=7 a0=797bfbd8 a1=1002 a2=0 a3=797bfdf0 items=1 ppid=1 pid=7840 auid=500 uid=500 gid=500 euid=500 suid=500 fsuid=500 egid=500 sgid=500 fsgid=500 ses=3 tty=(none) comm="oracle_7840_orc" exe="/u01/app/oracle/product/12.2.0/dbhome_1/bin/oracle" key=(null)
--
type=PATH msg=audit(1513326435.366:314): item=0 name="/u01/app/oracle/product/12.2.0/dbhome_1/dbs/orapworcl" inode=109527 dev=fc:02 mode=0100640 ouid=500 ogid=500 rdev=00:00
type=CWD msg=audit(1513326435.366:314):  cwd="/u01/app/oracle/product/12.2.0/dbhome_1/dbs"
type=SYSCALL msg=audit(1513326435.366:314): arch=c000003e syscall=2 success=yes exit=7 a0=7ffe8aae9288 a1=0 a2=0 a3=3 items=1 ppid=1 pid=7840 auid=500 uid=500 gid=500 euid=500 suid=500 fsuid=500 egid=500 sgid=500 fsgid=500 ses=3 tty=(none) comm="oracle_7840_orc" exe="/u01/app/oracle/product/12.2.0/dbhome_1/bin/oracle" key=(null)
--
type=PATH msg=audit(1513326435.366:315): item=0 name="/u01/app/oracle/product/12.2.0/dbhome_1/dbs/orapworcl" inode=109527 dev=fc:02 mode=0100640 ouid=500 ogid=500 rdev=00:00
type=CWD msg=audit(1513326435.366:315):  cwd="/u01/app/oracle/product/12.2.0/dbhome_1/dbs"
type=SYSCALL msg=audit(1513326435.366:315): arch=c000003e syscall=2 success=yes exit=7 a0=7ffe8aae9288 a1=0 a2=0 a3=3 items=1 ppid=1 pid=7840 auid=500 uid=500 gid=500 euid=500 suid=500 fsuid=500 egid=500 sgid=500 fsgid=500 ses=3 tty=(none) comm="oracle_7840_orc" exe="/u01/app/oracle/product/12.2.0/dbhome_1/bin/oracle" key=(null)
--
type=PATH msg=audit(1513326435.366:316): item=0 name="/u01/app/oracle/product/12.2.0/dbhome_1/dbs/orapworcl" inode=109527 dev=fc:02 mode=0100640 ouid=500 ogid=500 rdev=00:00
type=CWD msg=audit(1513326435.366:316):  cwd="/u01/app/oracle/product/12.2.0/dbhome_1/dbs"
type=SYSCALL msg=audit(1513326435.366:316): arch=c000003e syscall=2 success=yes exit=7 a0=797bfbd8 a1=0 a2=0 a3=0 items=1 ppid=1 pid=7840 auid=500 uid=500 gid=500 euid=500 suid=500 fsuid=500 egid=500 sgid=500 fsgid=500 ses=3 tty=(none) comm="oracle_7840_orc" exe="/u01/app/oracle/product/12.2.0/dbhome_1/bin/oracle" key=(null)
--
type=PATH msg=audit(1513326435.366:317): item=0 name="/u01/app/oracle/product/12.2.0/dbhome_1/dbs/orapworcl" inode=109527 dev=fc:02 mode=0100640 ouid=500 ogid=500 rdev=00:00
type=CWD msg=audit(1513326435.366:317):  cwd="/u01/app/oracle/product/12.2.0/dbhome_1/dbs"
type=SYSCALL msg=audit(1513326435.366:317): arch=c000003e syscall=2 success=yes exit=7 a0=797bfbd8 a1=1002 a2=0 a3=797bfdf0 items=1 ppid=1 pid=7840 auid=500 uid=500 gid=500 euid=500 suid=500 fsuid=500 egid=500 sgid=500 fsgid=500 ses=3 tty=(none) comm="oracle_7840_orc" exe="/u01/app/oracle/product/12.2.0/dbhome_1/bin/oracle" key=(null)

[oracle@oel6 ~]$ ps -ef | grep 7840
oracle    7840     1  0 09:27 ?        00:00:00 oracleorcl (LOCAL=NO)

So, if we have a closer look to this binary file, we can find various password hashes. In my example, I configured my sqlnet with SQLNET.ALLOWED_LOGON_VERSION_SERVER=11. As a result, my password file contains 10g, 11g and 12c password hashes for the SYS user.

Below, I used xxd linux command with specific offsets on my password file to get the password hashes (in bold in the output):

  • 10g sys password hash
[oracle@oel6 ~]$ xxd -c16 -g0 -s +0x0484 -l 16 $ORACLE_HOME/dbs/orapworcl
0000484: 32363235343335323638333944303441 262543526839D04A
  • 11g sys password hash
[oracle@oel6 ~]$ xxd -c30 -g0 -s +0x04ac -l 30 $ORACLE_HOME/dbs/orapworcl
00004ac: 2adaa0a90bf26f339c49fe9948ab88a20baf82f93ef3c5da13ca5eb95314 *.....o3.I..H.......>.....^.S.

First part (20 first bytes): SHA1 digest

[oracle@oel6 ~]$ xxd -c20 -g0 -s +0x04ac -l 20 $ORACLE_HOME/dbs/orapworcl
00004ac: 2adaa0a90bf26f339c49fe9948ab88a20baf82f9 *.....o3.I..H.......

Second part (10 next bytes): Salt used by Oracle

[oracle@oel6 ~]$ xxd -c10 -g0 -s +0x4C0 -l 10 $ORACLE_HOME/dbs/orapworcl
00004c0: 3ef3c5da13ca5eb95314 >.....^.S.
  • 12c sys password hash
[oracle@oel6 ~]$ xxd -c80 -g0 -s +0x04CA -l 80 $ORACLE_HOME/dbs/orapworcl
00004ca: ad84face7a337c03baacca0bc63f97068e51edd0d6c53826ce8c347594a2800f92c736b4c83239fa47414ff2f68f45304b016ae215ed595c8b71c3c5a0ca3a0630e931d0f7d3929c9a6fb131f2fa0427 ....z3|......?...Q....8&..4u......6..29.GAO...E0K.j...Y\.q....:.0.1......o.1...'

Note: if you use the default configuration of oracle 12.2, you will only find 11g and 12c hashes.

 

Once these hashes have been found, I wrote some python scripts to brute force with a dictionary file to guess the password. Those scripts are available at this URL: https://github.com/lolo115/oracrack

First of all, I used the ora10g_hash_bf.py against the 10g hash to find the case insensitive password:

[oracle@oel6 sec]$ ./ora10g_hash_bf.py dict.txt sys 262543526839D04A
DICTFILE = dict.txt
USERNAME = sys
HASH     = 262543526839D04A
PASSWORD FOUND FOR USER sys !!! PASSWORD IS: rockyou
------
Be careful, the found password is case insensitive. The real password can include upper character(s)
Now generate all combinations for this password and run ora11g_hash_bf.py script to find the case sensitive password

Ok, the password is weak and the program found it in the dictionary file, but if we try it on our database, it fails because I used a sqlplus 12.2 client that use case sensitive passwords (and my SQLNET client configuration is the default one):

$ sqlplus sys/rockyou@orcl as sysdba

SQL*Plus: Release 12.2.0.1.0 Production on Fri Dec 15 10:06:37 2017

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

ERROR:
ORA-01017: invalid username/password; logon denied

So, now as I know that the sys password is something like “rockyou” with upper and lower characters in it, I will use my “gen_all_comb.py” script to generate my own dictionary file that will contains all the combination for the “rockyou” password:

[oracle@oel6 sec]$ ./gen_all_comb.py rockyou > mydict.txt
[oracle@oel6 sec]$ head mydict.txt
rockyou
rockyoU
rockyOu
rockyOU
rockYou
rockYoU
rockYOu
rockYOU
rocKyou
rocKyoU
.../...

As the last operation, I have to use the ora11g_hash_bf.py script against the 11g hash (which is case sensitive) with my previously generated dictionary (mydict) and the script will find the correct password:

[oracle@oel6 sec]$ ./ora11g_hash_bf.py mydict.txt sys 2adaa0a90bf26f339c49fe9948ab88a20baf82f93ef3c5da13ca5eb95314
DICTFILE = mydict.txt
USERNAME = sys
HASH     = 2adaa0a90bf26f339c49fe9948ab88a20baf82f93ef3c5da13ca5eb95314
PASSWORD FOUND FOR USER sys !!! PASSWORD IS: RocKyoU

So let’s try:

[oracle@oel6 sec]$ sqlplus sys/RocKyoU@orcl as sysdba

SQL*Plus: Release 12.2.0.1.0 Production on Fri Dec 15 10:12:17 2017

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


Connected to:
Oracle Database 12c Enterprise Edition Release 12.2.0.1.0 - 64bit Production

SQL>

In this blog post, I described how to brute force SYS password that is stored in the password file without trying to connect number of times to the database and lock account etc. Please note that, I didn’t read at any time the USER$ table too.

To avoid this, you can simply disable password file usage by setting remote_login_passwordfile to NONE and remove this password file. You can set a SYS password  that is not weak (or use a password function with a profile etc.), there are too many customers that are still setting sys password to oracle, oracle123 or welcome1 ….

Finally, I didn’t write anything about the 12c hash (SHA512) because it’s a bit more complicated. Oracle 12c used a SCRAM authentication dialog, so first, you have to listen to the client/server network dialog, get some authentication keys and then run your own script. More, the 12c hash generation process uses PBKDF2 key derivation function that is a de-optimized function. As a consequence, it will slow down the execution rate of your script. So if you want to secure your 12c authentication process and avoid password brute force, you have to use only a 12c hash password (in your password file and into USER$ table), encrypt your network dialog with AES192 algorithm (starting with 12c, it can be done even in Standard Edition), use non weak passwords.

I will terminate this blog post with the traditional disclaimer … use all that is written in this blog post (including scripts) at your own risk. If you use all this stuff to hack a SYS password without any authorization … you will be the only responsible for all the consequences ! 😉

11g, 12c, Development, Oracle, Python, security, tools

Store your TNS entries in MS Active Directory (only for full Windows platforms)

5 Comments Posted by on January 12, 2017

When you manage a lot of Oracle clients, it can be difficult to manage as much tnsnames.ora files as you have Oracle clients.

In that case, it can be useful to configure solutions to centralize only one tnsnames.ora. Another solution is to use a Microsoft Active Directory to store your TNS Entries (This solution is for computers running on MS Windows).

The job is done in two steps :

  • First one is to configure Active Directory (AD) server
  • Second one is to configure your Oracle clients to query the AD server

In my lab, I have many boxes:

  • a MS Windows 2008 R2 Server (ok ok it’s an old box … but it works fine and I assume it will work fine on a 2012 R2 server). This server acts as a controller domain for the domain example.com. The server name is windows1.example.com. It hosts the Active Directory for the domain example.com and a DNS server.
  • a MS Windows where an Oracle Client is installed. (Don’t try to do this configuration on a linux box … it’s not working)

Configure AD to store Oracle TNS entries.

To do that, you first have to install an Oracle Client on the server. I won’t describe how to do that … you’re smart enough to do it yourself :). You just have to install the administrative Client.

Then, create a work directory, in my server I did that in C:\AD.  And copy all the files from $ORACLE_HOME/ldap/schema/ad to this work directory.

PS C:\> md AD
PS C:\> copy C:\app\product\11.2.0\dbhome_1\ldap\schema\ad\* C:\AD
PS C:\> dir C:\AD


    Directory: C:\AD


Mode                LastWriteTime     Length Name
----                -------------     ------ ----
-a---        09/11/2004     16:44        470 adContextCreate.lst
-a---        09/11/2004     16:44       2122 adContextCreateCommon.sbs
-a---        01/08/2001     04:16        591 adContextUpgradeFrom81600.lst
-a---        01/08/2001     04:17        407 adContextUpgradeFrom81600Common.sbs
-a---        23/05/2001     17:13        676 adDisplaySpecifiersCreate.lst
-a---        23/05/2001     17:13       5106 adDisplaySpecifiers_de.sbs
-a---        23/05/2001     17:13       5163 adDisplaySpecifiers_es.sbs
-a---        23/05/2001     17:13       5385 adDisplaySpecifiers_fr.sbs
-a---        23/05/2001     17:13       5092 adDisplaySpecifiers_it.sbs
-a---        23/05/2001     17:13       5562 adDisplaySpecifiers_ja.sbs
-a---        23/05/2001     17:13       5406 adDisplaySpecifiers_ko.sbs
-a---        23/05/2001     17:13      76035 adDisplaySpecifiers_other.sbs
-a---        23/05/2001     17:13       5453 adDisplaySpecifiers_pt_BR.sbs
-a---        23/05/2001     17:13       5069 adDisplaySpecifiers_us.sbs
-a---        23/05/2001     17:13       5225 adDisplaySpecifiers_zh_CN.sbs
-a---        01/08/2001     04:16        576 adSchemaCreate.lst
-a---        04/08/2003     17:51        219 adSchemaCreateAux.lst
-a---        13/11/2001     16:10        224 adSchemaCreateAux.sbs
-a---        09/11/2004     16:44       5445 adSchemaCreateBase.sbs
-a---        01/08/2001     04:17      11925 adSchemaCreateNet.sbs
-a---        01/08/2001     04:17       7462 adSchemaCreateRDBMS.sbs
-a---        01/08/2001     04:16        570 adSchemaUpgradeFrom81600.lst
-a---        01/08/2001     04:17        585 adSchemaUpgradeFrom81600Base.sbs
-a---        01/08/2001     04:17        509 adSchemaUpgradeFrom81600Net.sbs
-a---        01/08/2001     04:17        690 adSchemaUpgradeFrom81600RDBMS.sbs

 

Next, we will replace some values into some of these files. But before we need to note several DN (distinguished name).  :

  • DN of the root container. Usually this DN represents the domain where we will create what is called the “Oracle Context” (see below). In my case, my domain’s DN is : “DC=example,DC=com”.
  • DN of the Users branch in the AD container. In my case, it’s “CN=Users,DC=example,DC=com”.
  • DN of the user you are logged in. Basically, I will do that with the domain administrator, and its DN is: “CN=Administrator,CN=Users,DC=example,DC=com”
  • DN of the Oracle Context, in my case its DN is: “CN=OracleContext,DC=example,DC=com”. It’s in this Oracle Context that TNS Entries will be created.

I defined all these values in a set of PowerShell variables:

PS C:\> cd AD
PS C:\AD> $rootCont="DC=example,DC=com"
PS C:\AD> $usersBranch="CN=Users,DC=example,DC=com"
PS C:\AD> $userLogged="CN=Administrator,CN=Users,DC=example,DC=com"
PS C:\AD> $oracleContext="CN=OracleContext,DC=example,DC=com"

Then, all the files mentioned below will be “SEDed” to replace patterns with the correct values in new LDIF files (It has been done with Powershell, but you can do this with the tool you want: sed/cygwin, notepad etc).

PS C:\AD> cat adSchemaCreateBase.sbs | %{$_ -replace “%s_AdDomainDN%",$rootCont} | Out-File adSchemaCreateBase.ldif -Encoding UTF8
PS C:\AD> cat adSchemaCreateNet.sbs | %{$_ -replace “%s_AdDomainDN%",$rootCont} | Out-File adSchemaCreateNet.ldif -Encoding UTF8
PS C:\AD> cat adSchemaCreateRDBMS.sbs | %{$_ -replace “%s_AdDomainDN%",$rootCont} | Out-File adSchemaCreateRDBMS.ldif -Encoding UTF8
PS C:\AD> cat adSchemaUpgradeFrom81600BASE.sbs | %{$_ -replace “%s_AdDomainDN%",$rootCont} | Out-File adSchemaUpgradeFrom81600BASE.ldif -Encoding UTF8
PS C:\AD> cat adSchemaUpgradeFrom81600NET.sbs | %{$_ -replace “%s_AdDomainDN%",$rootCont} | Out-File adSchemaUpgradeFrom81600NET.ldif -Encoding UTF8
PS C:\AD> cat adSchemaUpgradeFrom81600RDBMS.sbs | %{$_ -replace “%s_AdDomainDN%",$rootCont} | Out-File adSchemaUpgradeFrom81600RDBMS.ldif -Encoding UTF8
PS C:\AD> cat adDisplaySpecifiers_us.sbs | %{$_ -replace “%s_AdDomainDN%",$rootCont} | Out-File adDisplaySpecifiers_us.ldif -Encoding UTF8
PS C:\AD> cat adDisplaySpecifiers_other.sbs | %{$_ -replace “%s_AdDomainDN%",$rootCont} | Out-File adDisplaySpecifiers_other.ldif -Encoding UTF8

PS C:\AD> cat adContextCreateCommon.sbs | %{$_ -replace “%s_OracleContextDN%" ,$oracleContext} `
>> | %{$_ -replace “%s_AdUsersDomainDN%", $usersBranch} `
>> | %{$_ -replace “%s_CurrentUserDN%", $userLogged} | Out-File adContextCreateCommon.ldif -Encoding UTF8
>>
PS C:\AD>

PS C:\AD> cat adContextUpgradeFrom81600Common.sbs | %{$_ -replace “%s_OracleContextDN%",$oracleContext} | Out-File adContextUpgradeFrom81600Common.ldif -Encoding UTF8

Please note that if your AD is installed in another supported language, you have to modify the DisplaySpecifier file related to the installation language (for example,  adDisplaySpecifiers_fr.sbs if it’s installed in French).

After that, a simple bunch of ldapmodify commands, and the entries for OracleContext will be created in the AD:

PS C:\AD> ldapmodify -c -D "cn=Administrator,cn=users,dc=example,dc=com" -w "YOUR_PASSWORD" -f C:\AD\adSchemaCreateBase.ldif
PS C:\AD> ldapmodify -c -D "cn=Administrator,cn=users,dc=example,dc=com" -w "YOUR_PASSWORD" -f C:\AD\adSchemaCreateNet.ldif
PS C:\AD> ldapmodify -c -D "cn=Administrator,cn=users,dc=example,dc=com" -w "YOUR_PASSWORD" -f C:\AD\adSchemaCreateRDBMS.ldif
PS C:\AD> ldapmodify -c -D "cn=Administrator,cn=users,dc=example,dc=com" -w "YOUR_PASSWORD" -f C:\AD\adSchemaUpgradeFrom81600BASE.ldif
PS C:\AD> ldapmodify -c -D "cn=Administrator,cn=users,dc=example,dc=com" -w "YOUR_PASSWORD" -f C:\AD\adSchemaUpgradeFrom81600NET.ldif
PS C:\AD> ldapmodify -c -D "cn=Administrator,cn=users,dc=example,dc=com" -w "YOUR_PASSWORD" -f C:\AD\adSchemaUpgradeFrom81600RDBMS.ldif
PS C:\AD> ldapmodify -c -D "cn=Administrator,cn=users,dc=example,dc=com" -w "YOUR_PASSWORD" -f C:\AD\adDisplaySpecifiers_us.ldif
PS C:\AD> ldapmodify -c -D "cn=Administrator,cn=users,dc=example,dc=com" -w "YOUR_PASSWORD" -f C:\AD\adDisplaySpecifiers_other.ldif
PS C:\AD> ldapmodify -c -D "cn=Administrator,cn=users,dc=example,dc=com" -w "YOUR_PASSWORD" -f C:\AD\adContextCreateCommon.ldif
PS C:\AD> ldapmodify -c -D "cn=Administrator,cn=users,dc=example,dc=com" -w "YOUR_PASSWORD" -f C:\AD\adContextUpgradeFrom81600Common.ldif

During execution, I had this kind off output … you can safely ignore this issue (probably due to powershell encoding which is made by default in UTF-8-BOM (original file used UTF-8 encoding):

ldapmodify.exe: no attributes to change or add (entry ´╗┐#)

Once done, you can check you have the correct number of objects in your directory. I did this check with a basic ldapsearch command:

PS C:\AD> ldapsearch -D "cn=Administrator,cn=users,dc=example,dc=com" -b "CN=Schema,CN=Configuration,dc=example,dc=com" -w "YOUR_PASSWORD" "(&(objectClass=attributeSchema)(CN=orcl*))" DN | Measure-Object -line

 Lines    Words    Characters    Property
 -----    -----    ----------    --------
    37    


PS C:\AD> ldapsearch -D "cn=Administrator,cn=users,dc=example,dc=com" -b "CN=Schema,CN=Configuration,dc=example,dc=com" -w "YOUR_PASSWORD" "(&(objectClass=classSchema)(CN=orcl*))" DN | Measure-Object -line

 Lines    Words    Characters    Property
 -----    -----    ----------    --------
    14

If the AD MMC users and computers plugin, a new branch appeared: “OracleContext” and three groups related to security management of the Oracle Context:

users_ad

Then, If you want to add some entries, you have to create an ldap.ora file first, then create entries. TO finish this configuration steps, we have to grant permissions on specific branches to allow anonymous access on TNS entries. This is mandatory because Oracle client doesn’t bind the directory, and it doesn’t have to logon with a specific user to read the TNS Entry.

LDAP.ORA

This file has to be created in the $OH/network/admin. There must be 3 three parameters for the directory server name and port, the durectory server type, and the DN of the parent branch which contains the Oracle Context.
Here’s the content of my ldap.ora file (refer to Oracle documentation : Net Services Reference for more information).

DIRECTORY_SERVERS=windows1.example.com:389
DIRECTORY_SERVER_TYPE=AD
DEFAULT_ADMIN_CONTEXT="DC=example,DC=com"

CREATE TNS ENTRIES IN ACTIVE DIRECTORY

The easiest way to do that is to use Net Manager and add entry in the directory branch.

But, I prefer to import entries from a ldif file. To do that, you have to create a LDIF file which contains all the necessary properties for the TNS entry. Below, a sample of what it can contain:

PS C:\AD> cat orcl.ldif
dn: CN=orcl,CN=OracleContext,DC=example,DC=com
changetype: add
objectClass: top
objectClass: orclNetService
orclNetDescString: (DESCRIPTION=(ADDRESS_LIST=(ADDRESS=(PROTOCOL=TCP)(HOST=windows1.example.com)(PORT=1521)))(CONNECT_DATA=(SERVICE_NAME=orcl)))

dn: CN=coucou,CN=OracleContext,DC=example,DC=com
changetype: add
objectClass: top
objectClass: orclNetService
orclNetDescString:
 (DESCRIPTION=(ADDRESS_LIST=(ADDRESS=(PROTOCOL=TCP)(HOST=192.168.99.15)(PORT=1521)))(CONNECT_DATA=(SERVICE_NAME=orcl)))

And to finish, it’s easy to add them to the directory, the same way we import our ldif during AD configuration:

PS C:\AD> ldapmodify -c -D "cn=Administrator,cn=users,dc=example,dc=com" -w "YOUR_PASSWORD" -f C:\AD\orcl.ldif

adding new entry CN=orcl,CN=OracleContext,DC=example,DC=com

adding new entry CN=coucou,CN=OracleContext,DC=example,DC=com

SPECIFIC PERMISSIONS

Grant the permission “anonymous logon” on the entry we’ve created.

C:\> dsacls "CN=orcl,CN=OracleContext,DC=example,DC=com" /G "anonymous logon":GR
C:\> dsacls "CN=coucou,CN=OracleContext,DC=example,DC=com" /G "anonymous logon":GR

 

Client configuration

The client configuration is very easy, there’s only two lines to configure in SQLNET.ora file.

NAMES.DIRECTORY_PATH= (LDAP)
NAMES.LDAP_AUTHENTICATE_BIND=1

A call to tnsping will show you that trying to resolve the given alias will be done through your ldap configuration:

C:\>tnsping orcl

TNS Ping Utility for 64-bit Windows: Version 11.2.0.4.0 - Production on 12-JAN-2017 15:41:49

Copyright (c) 1997, 2013, Oracle.  All rights reserved.

Used parameter files:
C:\app\product\11.2.0\dbhome_1\network\admin\sqlnet.ora

Used LDAP adapter to resolve the alias
Attempting to contact (DESCRIPTION=(ADDRESS_LIST=(ADDRESS=(PROTOCOL=TCP)(HOST=windows1.example.com)(PORT=1521)))(CONNECT_DATA=(SERVICE_NAME=orcl
OK (0 msec)

Another way to verify it resolves the alias through LDAP is to enable SQLNET client tracing by addind these lines in the sqlnet.ora file:

TRACE_LEVEL_CLIENT=ADMIN
TRACE_UNIQUE_CLIENT=ON
TRACE_TIMESTAMP_CLIENT=ON
TRACE_DIRECTORY_CLIENT=c:\temp\client_trace
LOG_DIRECTORY_CLIENT=c:\temp\client_trace
DIAG_ADR_ENABLED=OFF

In the trace file, we see this information that prooves LDAP usage to resolve names:

[12-JAN-2017 15:45:21:752] nnflilc:  Opening sync conn to windows1.example.com:389
[12-JAN-2017 15:45:21:752] nnflalc: entry
[12-JAN-2017 15:45:21:752] nnflalc: native bind CN=Administrator,CN=Users,DC=example,DC=com returns 0
[12-JAN-2017 15:45:21:752] nnflalc: bind CN=Administrator,CN=Users,DC=example,DC=com returns 0x0
.../...
[12-JAN-2017 15:45:21:752] nnflrne1: Quering the directory for dn: cn=orcl,cn=OracleContext,DC=example,DC=com
[12-JAN-2017 15:45:21:752] nnflqbf: entry
[12-JAN-2017 15:45:21:752] nnflqbf: Search: Attrs[0]: objectclass
[12-JAN-2017 15:45:21:752] nnflqbf: Search:  Base: cn=orcl,cn=OracleContext,DC=example,DC=com; Scope: 0; filter: (objectclass=*) returns 0x0
[12-JAN-2017 15:45:21:752] nnflqbf: exit
[12-JAN-2017 15:45:21:752] nnflgne: entry
[12-JAN-2017 15:45:21:752] nnflgne:   DN : cn=orcl,cn=OracleContext,DC=example,DC=com
[12-JAN-2017 15:45:21:752] nnflgne: exit
.../...
[12-JAN-2017 15:45:21:752] nigtrm: Count in the NI global area is now 1
[12-JAN-2017 15:45:21:752] nigtrm: Count in the NL global area is now 1
[12-JAN-2017 15:45:21:752] nigini: entry
[12-JAN-2017 15:45:21:752] nigini: Count in the NL global area is now 2
[12-JAN-2017 15:45:21:752] nigini: Count in NI gbl area now: 2
[12-JAN-2017 15:45:21:752] nigini: exit
[12-JAN-2017 15:45:21:752] niqname: Hst is already an NVstring.
[12-JAN-2017 15:45:21:752] niqname: Inserting CID.
[12-JAN-2017 15:45:21:752] nigtrm: Count in the NI global area is now 1
[12-JAN-2017 15:45:21:752] nigtrm: Count in the NL global area is now 1
[12-JAN-2017 15:45:21:752] nigini: entry
[12-JAN-2017 15:45:21:752] nigini: Count in the NL global area is now 2
[12-JAN-2017 15:45:21:752] nigini: Count in NI gbl area now: 2
[12-JAN-2017 15:45:21:752] nigini: exit
[12-JAN-2017 15:45:21:752] niqname: Hst is already an NVstring.
[12-JAN-2017 15:45:21:752] niqname: Inserting CID.
[12-JAN-2017 15:45:21:752] niotns: entry
[12-JAN-2017 15:45:21:752] niotns: niotns: setting up interrupt handler...
[12-JAN-2017 15:45:21:752] niotns: Not trying to enable dead connection detection.
[12-JAN-2017 15:45:21:752] niotns: Calling address: (DESCRIPTION=(ADDRESS_LIST=(ADDRESS=(PROTOCOL=TCP)(HOST=windows1.example.com)(PORT=1521)))(CONNECT_DATA=(SERVICE_NAME=orcl)(CID=(PROGRAM=C:\app\product\11.2.0\dbhome_1\bin\sqlplus.exe)(HOST=clientWin)(USER=Administrator))))
[12-JAN-2017 15:45:21:752] nsgettrans_bystring: entry
[12-JAN-2017 15:45:21:752] nsgettrans_bystring: exit
[12-JAN-2017 15:45:21:752] nsmal: 280 bytes at 0x6baaf0
[12-JAN-2017 15:45:21:752] nscall: connecting...
11g, 12c, Administration, Oracle, tools

How to Get Oracle Global Temporary Table (GTT) size

Leave a comment Posted by on December 21, 2016

A very quick post to detail a script I wrote about GTT, and more precisely how to know the size occupied by a Session GTT (Global Temporary Table).

GTT are allocated as a temporary segment in the temporary tablespace. So we can get information about it in the V$SORT_USAGE view.

The problem, in this view, you don’t have the name of your table, nor the object id, but having a look in the underlying object makes me discovering the X$KTSSO view which have this information.

I wrote the following query (very quickly) to retrieve this information (This script has been tested on Oracle 11.2.0.4).


set lines 400 pages 500 trimspool on
select s.sid, s.serial#, s.program,o.obj#,o.name,decode(bitand(o.flags, 2), 0, 'N', 2, 'Y', 'N') temporary,
temp_obj.ktssoexts extents, temp_obj.ktssoblks blocks, temp_obj.ktssoblks*blk_sz.bs bytes
from obj$ o, 
	(select * from x$ktsso) temp_obj,
	(select value bs from v$parameter where name='db_block_size') blk_sz, 
	v$session s, 
	tab$ t
where o.obj# =temp_obj.KTSSOOBJN
and t.obj#=o.obj# 
and bitand(o.flags, 2)=2
and s.saddr=temp_obj.ktssoses;

       SID    SERIAL# PROGRAM                                                OBJ# NAME                           T    EXTENTS     BLOCKS      BYTES
---------- ---------- ------------------------------------------------ ---------- ------------------------------ - ---------- ---------- ----------
        43       1209 sqlplus@oel6.localdomain (TNS V1-V3)                  88956 T_SALES                        Y         35       4480   36700160
        43       1209 sqlplus@oel6.localdomain (TNS V1-V3)                   5187 PLAN_TABLE$                    Y          1        128    1048576
        35       1317 SQL Developer                                          5187 PLAN_TABLE$                    Y          1        128    1048576

This script can give you some clues about values to set for statistics on these GTTs when they are used accross many sessions and you don’t really know their size.

That’s it for today.

 

11g, tools, tuning

Tracing Oracle binaries and tools

1 Comment Posted by on August 29, 2016

Oracle is well known for its instrumentation: wait interface, log files and tracing capabilities.

Usually, lots of them are documented but the way you can trace binaries and tools are usually not. More, reading trace files is not an easy thing to do but some times you can find clues about the problem you face.

In this post, I will talk about how to enable tracing when you use some binaries.

RMAN

RMAN is the Oracle utility used to backup and recover your databases. To enable tracing is RMAN, you have to switch rman is “debug” mode.

This mode can be enabled directly in rman:

 


[oracle@oel7 ~]$ rman target /

Recovery Manager: Release 12.1.0.2.0 - Production on Wed Feb 24 15:45:13 2016

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

connected to target database: ORCL (DBID=1413029491)

RMAN> debug on

RMAN-03036: Debugging set to level=9[MEDIUM], types=ALL

DBGSQL: TARGET> begin dbms_rcvman.setDebugOn; dbms_rcvman.dumpPkgState('Debug On'); end;
DBGSQL: sqlcode = 0
DBGRCVMAN: ENTERING dumpPkgState Debug On

.../...

Or (much better) it can be enabled with the debug option in the rman command, and by specifying a trace file :


[oracle@oel7 ~]$ rman target / debug trace=tracefile.trc

Recovery Manager: Release 12.1.0.2.0 - Production on Wed Feb 24 15:22:10 2016

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

RMAN-06005: connected to target database: ORCL (DBID=1413029491)

RMAN> disconnect

All the debug stuff is then located in your “tracefile.trc” file.

You can enable tracing on specific component in rman :

  • SQL: for tracing SQL queries generated by rman
  • RESTORE: for tracing restore operation only
  • RECOVER: for tracing recovery operation only
  • RESYNC: for tracing synchronization operation only
  • DUPLICATE: for tracing duplicate operation only

And for each or all of these component, you can set a verbosity level from 1 (lowest) to 10 (highest). 9 is the default verbosity level. Sometimes, you can change the verbosity level without any change in your tracefile.

Here are some examples (point that many components can be traced at the same time):


[oracle@oel7 ~]$ rman target / debug recover level=10 trace=tracefile.trc

[oracle@oel7 ~]$ rman target / debug sql level=1 trace=tracefile.trc

RMAN> debug restore,sql level=10

DGMGRL

DGMGRL is the tool used to control dataguard broker and operates some changes in your dataguard configuration: add config, initiate a switchover or a failover etc.

Dgmgrl can be switched to debug mode to get more information about a failed command.


[oracle@dg1 ~]$ dgmgrl -debug sys/oracle@prod_lille
DGMGRL for Linux: Version 11.2.0.4.0 - 64bit Production

Copyright (c) 2000, 2009, Oracle. All rights reserved.

Welcome to DGMGRL, type "help" for information.
[W000 02/24 16:14:15.62] Connecting to database using prod_lille.
[W000 02/24 16:14:15.65] Checking broker version [BEGIN :version := dbms_drs.dg_broker_info('VERSION'); END;].
[W000 02/24 16:14:15.65] Broker version is '11.2.0.4.0'
Connected.

This option can be very useful specially when you perform a switchover operation, all operations are logged and you can follow every connection, disconnection, tns errors, instance startup etc.

Below is an example of a successful switchover in debug mode:


DGMGRL> switchover to prod_arras;
Performing switchover NOW, please wait...
Operation requires a connection to instance "prod" on database "prod_arras"
Connecting to instance "prod"...
[W000 02/24 16:31:42.31] Connecting to database using (DESCRIPTION=(ADDRESS_LIST=(ADDRESS=(PROTOCOL=TCP)(HOST=dg2.localdomain)(PORT=1521))(ADDRESS=(PROTOCOL=TCP)(HOST=dg1.localdomain)(PORT=1521)))(CONNECT_DATA=(SERVICE_NAME=prod_arras_DGB)(INSTANCE_NAME=prod))).
[W000 02/24 16:31:42.33] Checking broker version [BEGIN :version := dbms_drs.dg_broker_info('VERSION'); END;].
[W000 02/24 16:31:42.33] Broker version is '11.2.0.4.0'
Connected.
New primary database "prod_arras" is opening...
Operation requires startup of instance "prod" on database "prod_lille"
Starting instance "prod"...
[W000 02/24 16:31:50.20] Connecting to database using (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=dg1.localdomain)(PORT=1521))(CONNECT_DATA=(SERVICE_NAME=prod_lille_DGMGRL)(INSTANCE_NAME=prod)(SERVER=DEDICATED))).
[W000 02/24 16:31:50.21] Checking broker version [BEGIN :version := dbms_drs.dg_broker_info('VERSION'); END;].
ORA-01034: ORACLE not available
Process ID: 0
Session ID: 0 Serial number: 0

ORACLE instance started.
[W000 02/24 16:31:51.52] Connecting to database using (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=dg1.localdomain)(PORT=1521))(CONNECT_DATA=(SERVICE_NAME=prod_lille_DGMGRL)(INSTANCE_NAME=prod)(SERVER=DEDICATED))).
[W000 02/24 16:31:51.54] Checking broker version [BEGIN :version := dbms_drs.dg_broker_info('VERSION'); END;].
[W000 02/24 16:31:51.55] Broker version is '11.2.0.4.0'
alter database mount

Database mounted.
[W000 02/24 16:31:59.85] Connecting to database using (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=dg1.localdomain)(PORT=1521))(CONNECT_DATA=(SERVICE_NAME=prod_lille_DGMGRL)(INSTANCE_NAME=prod)(SERVER=DEDICATED))).
[W000 02/24 16:31:59.87] Checking broker version [BEGIN :version := dbms_drs.dg_broker_info('VERSION'); END;].
[W000 02/24 16:31:59.87] Broker version is '11.2.0.4.0'
Switchover succeeded, new primary is "prod_arras"

EXPDP / IMPDP

Datapump export and import operation can be traced too. But for these tools, Oracle published a note on how to enable tracing a datapump operation. The MOS note is “Export/Import DataPump Parameter TRACE – How to Diagnose Oracle Data Pump (Doc ID 286496.1)”.

To trace a datapump process, you can do it at different levels, client process (expdp/impdp), master process (DM), worker process (DW) and you can trace different services. That’s why Oracle used a TRACE parameter. This one in coded with a hexadecimal value that code for a type of services you want to trace, and this service will generate trace in different processes (DM, DW, etc.).

The Trace value depends on which service you want to trace:


-- Summary of Data Pump trace levels:
-- ==================================

  Trace   DM   DW  ORA  Lines
  level  trc  trc  trc     in
  (hex) file file file  trace                                         Purpose
------- ---- ---- ---- ------ -----------------------------------------------
  10300    x    x    x  SHDW: To trace the Shadow process (API) (expdp/impdp)
  20300    x    x    x  KUPV: To trace Fixed table
  40300    x    x    x  'div' To trace Process services
  80300    x            KUPM: To trace Master Control Process (MCP)      (DM)
 100300    x    x       KUPF: To trace File Manager
 200300    x    x    x  KUPC: To trace Queue services
 400300         x       KUPW: To trace Worker process(es)                (DW)
 800300         x       KUPD: To trace Data Package
1000300         x       META: To trace Metadata Package
------- 'Bit AND'
1FF0300    x    x    x  'all' To trace all components          (full tracing)

Here’s an example with full tracing:


[oracle@oel7 ~]$ expdp system/oracle directory=dpdir dumpfile=test.dmp logfile=test.log tables=HR.REGIONS REUSE_DUMPFILES=YES trace=FFF0300

In the trace files generated, you will find lots of very interesting stuff (for example below, the trace file of the expdp process)


*** 2016-02-24 18:25:33.740
*** SESSION ID:(135.7145) 2016-02-24 18:25:33.740
*** CLIENT ID:() 2016-02-24 18:25:33.740
*** SERVICE NAME:(SYS$USERS) 2016-02-24 18:25:33.740
*** MODULE NAME:(ude@oel7.localdomain (TNS V1-V3)) 2016-02-24 18:25:33.740
*** CLIENT DRIVER:() 2016-02-24 18:25:33.740
*** ACTION NAME:() 2016-02-24 18:25:33.740

SHDW: *** GET_STATUS_VERSION call ***
SHDW: Version = 9999
KUPP:18:25:33.741: Input trace/debug flags: 0FFF0300 = 268370688
KUPP:18:25:33.741: Current trace/debug flags: 0FFF0300 = 268370688
SHDW:18:25:33.741: Current user = SYSTEM
SHDW:18:25:33.741: Current schema = SYSTEM
SHDW:18:25:33.741: Current language = AMERICAN_AMERICA.AL32UTF8
SHDW:18:25:33.742: Current session address = 00000001B7D050F8
SHDW:18:25:33.742: *** OPEN call ***
SHDW:18:25:33.742: operation = EXPORT
SHDW:18:25:33.742: job_mode = table
SHDW:18:25:33.742: remote_link =
SHDW:18:25:33.742: job_name =
SHDW:18:25:33.742: version =
SHDW:18:25:33.742: compression = 2
KUPV:18:25:33.743: Open request for job: SYSTEM.SYS_EXPORT_TABLE_01
KUPV:18:25:33.745: Master Table create statement: CREATE TABLE "SYSTEM"."SYS_EXPORT_TABLE_01" (abort_step NUMBER,ancestor_process_order NUMBER,base_object_name VARCHAR2(30),base_object_schema VARCHAR2(30),base_object_type VARCHAR2(30),base_process_order NUMBER,block_size NUMBER,cluster_ok NUMBER,completed_bytes NUMBER,completed_rows NUMBER,completion_time DATE,control_queue VARCHAR2(30),creation_level NUMBER,cumulative_time NUMBER,data_buffer_size NUMBER,data_io NUMBER,dataobj_num NUMBER,db_version VARCHAR2(60),degree NUMBER,domain_process_order NUMBER,dump_allocation NUMBER,dump_fileid NUMBER,dump_length NUMBER,dump_orig_length NUMBER,dump_position NUMBER,duplicate NUMBER,elapsed_time NUMBER,error_count NUMBER,extend_size NUMBER,file_max_size NUMBER,file_name VARCHAR2(4000),file_type NUMBER,flags NUMBER,grantor VARCHAR2(30),granules NUMBER,guid RAW(16),in_progress CHAR(1),instance VARCHAR2(60),instance_id NUMBER,is_default NUMBER,job_mode VARCHAR2(21),job_version VARCHAR2(60),last_file NUMBER,last_update DA
TE,load_method NUMBER,metadata_buffer_size NUMBER,metadata_io NUMBER,name VARCHAR2(30),object_int_oid VARCHAR2(32),object_long_name VARCHAR2(4000),object_name VARCHAR2(200),object_number NUMBER,object_path_seqno NUMBER,object_row NUMBER,object_schema VARCHAR2(30),object_tablespace VARCHAR2(30),object_type VARCHAR2(30),object_type_path VARCHAR2(200),old_value VARCHAR2(4000),operation VARCHAR2(8),option_tag VARCHAR2(30),orig_base_object_schema VARCHAR2(30),original_object_name VARCHAR2(128),original_object_schema VARCHAR2(30),packet_number NUMBER,parallelization NUMBER,parent_process_order NUMBER,partition_name VARCHAR2(30),phase NUMBER,platform VARCHAR2(101),process_name VARCHAR2(30),process_order NUMBER,processing_state CHAR(1),processing_status CHAR(1),property NUMBER,queue_tabnum NUMBER,remote_link VARCHAR2(128),scn NUMBER,seed NUMBER,service_name VARCHAR2(64),size_estimate NUMBER,start_time DATE,state VARCHAR2(12),status_queue VARCHAR2(30),subpartition_name VARCHAR2(30),target_xml_clob CLOB,tde_rewrapped_
key RAW(2000),template_table VARCHAR2(30),timezone VARCHAR2(64),total_bytes NUMBER,trigflag NUMBER,unload_method NUMBER,user_directory VARCHAR2(4000),user_file_name VARCHAR2(4000),user_name VARCHAR2(30),value_n NUMBER,value_t VARCHAR2(4000),version NUMBER,work_item VARCHAR2(21),xml_clob CLOB) SEGMENT CREATION IMMEDIATE INITRANS 10
KUPV:18:25:33.780: (Re)Creating job: SYSTEM.SYS_EXPORT_TABLE_01

.../...

SRVCTL

srvctl is the program that control clusterware resources. You can use it in a RAC configuration, or with Oracle Restart.

If, for example, a ressource doesn’t start in your cluster, or you would like to have more information about the process. You can set a specific environment variable named SRVM_TRACE to the value you want and then run your command. srvctl just look if the variable is defined and then it traces. The debug information is written in the standard output.

See demonstration below:


[oracle@rac1 ~]$ env|grep SRVM
[oracle@rac1 ~]$ srvctl status database -db cdb
Instance cdb1 is running on node rac1
Instance cdb2 is not running on node rac2
[oracle@rac1 ~]$ export SRVM_TRACE=laurent
[oracle@rac1 ~]$ srvctl status database -db cdb
[main] [ 2016-02-24 18:43:08.601 CET ] [OPSCTLDriver.setInternalDebugLevel:325] tracing is true at level 2 to file null
[main] [ 2016-02-24 18:43:08.607 CET ] [OPSCTLDriver.main:162] SRVCTL arguments : args[0]=status args[1]=database args[2]=-db args[3]=cdb
[main] [ 2016-02-24 18:43:08.608 CET ] [SRVMContext.init:114] Performing SRVM Context init. Init Counter=1
[main] [ 2016-02-24 18:43:08.622 CET ] [Library.load:194] library.load
[main] [ 2016-02-24 18:43:08.623 CET ] [sPlatform.isHybrid:66] osName=Linux osArch=amd64 JVM=64 rc=false
[main] [ 2016-02-24 18:43:08.624 CET ] [sPlatform.isHybrid:66] osName=Linux osArch=amd64 JVM=64 rc=false
[main] [ 2016-02-24 18:43:08.624 CET ] [Library.load:271] Loading library /u01/app/oracle/product/12.1.0/dbhome_1/lib/libsrvmhas12.so
[main] [ 2016-02-24 18:43:08.635 CET ] [SRVMContext.init:131] SRVM Context init-ed
[main] [ 2016-02-24 18:43:08.648 CET ] [Version.isPre:610] version to be checked 12.1.0.2.0 major version to check against 10
[main] [ 2016-02-24 18:43:08.648 CET ] [Version.isPre:621] isPre.java: Returning FALSE
[main] [ 2016-02-24 18:43:08.651 CET ] [OCR.loadLibrary:328]
Inside constructor of OCR
[main] [ 2016-02-24 18:43:08.652 CET ] [OCR.loadLibrary:336] Going to load the ocr library

.../...

[oracle@rac1 ~]$ unset SRVM_TRACE
[oracle@rac1 ~]$ srvctl status database -db cdb
Instance cdb1 is running on node rac1
Instance cdb2 is not running on node rac2

OPATCH

Opatch can be traced with an environment variable positioned like srvctl. This variable is OPATCH_DEBUG and it has to be set to TRUE. As for srvctl, information is written to standard output:


[oracle@rac1 ~]$ export OPATCH_DEBUG=TRUE
[oracle@rac1 ~]$ $ORACLE_HOME/OPatch/opatch lsinv
OPatch was not able to set FMW_COMPONENT_HOME by itself.
Machine Info: Linux rac1.localdomain 3.8.13-44.1.1.el6uek.x86_64 #2 SMP Wed Sep 10 06:10:25 PDT 2014 x86_64 x86_64 x86_64 GNU/Linux
_osArch is amd64
_javaVMSpecVersion is 1.0
_javaVMSpecVendor is Sun Microsystems Inc.
_javaVMSpecName is Java Virtual Machine Specification
_javaVMVendor is Sun Microsystems Inc.
_javaJRESpecVersion is 1.6
_javaJRESpecVendor is Sun Microsystems Inc.
_javaJRESpecName is Java Platform API Specification
_javaSupportedClassVersion is 50.0
OPatch compiled with major version: 50, minor version: 0
_osArch (from OCM API) is
/u01/app/oracle/product/12.1.0/dbhome_1/jdk/bin/java -Xms150m -Xmx256m -XX:MaxPermSize=128M -cp /u01/app/oracle/product/12.1.0/dbhome_1/OPatch/ocm/lib/emocmclnt.jar:/u01/app/oracle/product/12.1.0/dbhome_1/oui/jlib/OraInstaller.jar:/u01/app/oracle/product/12.1.0/dbhome_1/oui/jlib/OraPrereq.jar:/u01/app/oracle/product/12.1.0/dbhome_1/oui/jlib/OraCheckPoint.jar:/u01/app/oracle/product/12.1.0/dbhome_1/oui/jlib/share.jar:/u01/app/oracle/product/12.1.0/dbhome_1/oui/jlib/orai18n-mapping.jar:/u01/app/oracle/product/12.1.0/dbhome_1/oui/jlib/xmlparserv2.jar:/u01/app/oracle/product/12.1.0/dbhome_1/oui/jlib/emCfg.jar:/u01/app/oracle/product/12.1.0/dbhome_1/oui/jlib/ojmisc.jar:/u01/app/oracle/product/12.1.0/dbhome_1/OPatch/jlib/opatch.jar:/u01/app/oracle/product/12.1.0/dbhome_1/OPatch/jlib/opatchsdk.jar:/u01/app/oracle/product/12.1.0/dbhome_1/OPatch/oplan/jlib/automation.jar:/u01/app/oracle/product/12.1.0/dbhome_1/OPatch/oplan/jlib/apache-commons/commons-cli-1.0.jar:/u01/app/oracle/product/12.1.0/dbhome_1/OPatch/jlib/oracle.opatch.classpath.jar:/u01/app/oracle/product/12.1.0/dbhome_1/OPatch/oplan/jlib/jaxb/activation.jar:/u01/app/oracle/product/12.1.0/dbhome_1/OPatch/oplan/jlib/jaxb/jaxb-api.jar:/u01/app/oracle/product/12.1.0/dbhome_1/OPatch/oplan/jlib/jaxb/jaxb-impl.jar:/u01/app/oracle/product/12.1.0/dbhome_1/OPatch/oplan/jlib/jaxb/jsr173_1.0_api.jar:/u01/app/oracle/product/12.1.0/dbhome_1/OPatch/oplan/jlib/OsysModel.jar:/u01/app/oracle/product/12.1.0/dbhome_1/OPatch/oplan/jlib/osysmodel-utils.jar:/u01/app/oracle/product/12.1.0/dbhome_1/OPatch/oplan/jlib/CRSProductDriver.jar:/u01/app/oracle/product/12.1.0/dbhome_1/OPatch/oplan/jlib/oracle.oplan.classpath.jar -DOPatch.ORACLE_HOME=/u01/app/oracle/product/12.1.0/dbhome_1 -DOPatch.DEBUG=true -DOPatch.RUNNING_DIR=/u01/app/oracle/product/12.1.0/dbhome_1/OPatch -DOPatch.MW_HOME= -DOPatch.WL_HOME= -DOPatch.COMMON_COMPONENTS_HOME= -DOPatch.OUI_LOCATION= -DOPatch.FMW_COMPONENT_HOME= -DOPatch.OPATCH_CLASSPATH= -DOPatch.WEBLOGIC_CLASSPATH= oracle/opatch/OPatch lsinv -invPtrLoc /u01/app/oracle/product/12.1.0/dbhome_1/oraInst.loc
Oracle Interim Patch Installer version 12.1.0.1.3
Copyright (c) 2016, Oracle Corporation. All rights reserved.

OPatchSession::parse() on "lsinv","-invPtrLoc","/u01/app/oracle/product/12.1.0/dbhome_1/oraInst.loc",

Argument is "lsinv"
Add commands for Help
add command "apply"

.../...

Oracle Kernel Tracing

Oracle Kernel tracing can be done by enabling some events.

Event is a number between 10000 and 10999. It’s very similar to an error code … but it’s not a real one.

The most popular events are 10046 (SQL Trace) and 10053 (CBO debug trace) …but there are plenty of other ones and you can find details in oraus.msg file (or you can plan with oerr utility).

Events can be positioned by many ways :

  • With an ALTER SESSION (It’s not recommended to use ALTER SYSTEM when you enable events)
SQL> alter session set events '10046 trace name context forever, level 12';
SQL> alter session set events '10046 trace name context off';
  • With an oradebug command. This method offers the possibility to set an event in another session

For example, if you want to enable 10053 event in the session that have the OS PID 5683 (You can use SETMYPID for debugging your own session, or SETORAPID to target a session with a specific Oracle PID)


SQL> oradebug setospid 5683; 
SQL> oradebug event 10053 trace name context forever, level 1;
SQL> oradebug event 10053 trace name context off;
  • With DBMS_SYSTEM.SET_EV. Like ORADEBUG, you can set an event in another session

 


SQL> -- Enable SQL Trace in session with SID 6278 and Serial 71077
SQL> execute dbms_system.set_ev(si=>6278, se=>71077, ev=>10046, le=>12, nm=>'');
SQL> -- Disable SQL Trace in session with SID 6278 and Serial 71077
SQL> execute dbms_system.set_ev(si=>6278, se=>71077, ev=>10046, le=>0, nm=>'');

SQL> -- Enable CBO debug in session with SID 6278 and Serial 71077
SQL> execute dbms_system.set_ev(si=>6278, se=>71077, ev=>10053, le=>1, nm=>'');
SQL> -- Disable CBO debug in session with SID 6278 and Serial 71077
SQL> execute dbms_system.set_ev(si=>6278, se=>71077, ev=>10046, le=>0, nm=>'');

For all of these commands, the trace file will be available in the folder referenced by user_dump_dest.

Starting with Oracle 11.2, Oracle come with a new way to trace its components. This is named UTS (Unified Tracing System).

UTS offers the possibility to trace some components (like with events) but you can combine it with filters (for example, trace CBO computation when a specific SQL_ID is parsed etc.)

Note: Events are still available and they have’nt been replaced by UTS … UTS completes them.

The component list can be get with “oradebug doc component” command.

I will not write some detailed stuff about UTS because very interesting guys in the community have already written blog posts and articles on this.

You can visit them by following these URLs :

 

Last but not least, tracing everything without knowing what you are doing can be dangerous (Filesystem full filling, database hangs and/or crash), so it’s recommended to use tracing very carefully.

 

Thanks to my friend Pierre Labrousse who helped me for parts of this post.

11g, 12c, Administration, Internals, Oracle

← Older posts