Export/Import: on the fly. A new challenge.

This is the scenario.

I have a zipped export file on the source machine and I want to import it into a database on different host.

All is done on the fly.

In this picture:

• "src_hst", is the source machine
• "trg_db", is the target database
• "trg_hst", is the target machine
• "trg_usr", is the user, on the target database, to be imported
• "gunzip", is the unzip command
• "imp", is the import command
• "net", is the network between source host and target host 

Configuring the target and the source

First of all, you have to configure the source and target machine. To do this, please see "Configuring the target and the resource" of my previous post. 

Now you can run the import.

The taget

[oracle@trg_hst]$ mknod /tmp/trg_usr.pipe p
[oracle@trg_hst]$ nohup imp system/manager \
> fromuser=src_usr touser=trg_usr \
> file=/tmp/trg_usr.pipe \
> log=/tmp/dpdump/trg_usr.YYYYMMDD.log \
> 2>&1 > /tmp/dpdump/trg_usr.YYYYMMDD.hohup &

Please, note that I used YYYYMMDD. In this case I have to use the current date. For example: 20160924

The source

nohup gunzip -c src_hst.dmp.gz | ssh oracle@trg_hst 'cat > /tmp/trg_usr.pipe' &

Instance Needs Recovery: Introduction (3/3)

Part 1
Part 2

If an instance is dirty closed (SHUTDOWN ABORT, reboot of the server, kill -9, etc), you have two scenario:

1. Data blocks modified aren't yet written to disk into datafiles and the informations are only into the Redo Log File online 
2. Some data blocks into datafile contains data not yet committed 

• In the first case, changes need to re-applied to the database (roll-forward)
• In the second case, the changes have to disappear (roll-back) 

The V$DATABASE view, hase two columns that we are interested

• V$DATAFILE.CHECKPOINT_CHANGE#
• V$DATAFILE.LAST_CHANGE#

When an instance is opened, V$DATAFILE.CHECKPOINT_CHANGE# is the SCN at last checkpoint (1) while V$DATAFILE.LAST_CHANGE# is NULL. Oracle set to NULL V$DATAFILE.LAST_CHANGE# so it know that the database is working.

If the database is clean closed, Oracle update the V$DATAFILE.LAST_CHANGE# column to the last SCN. But if the close is dirty, Oracle can't to do this update and the V$DATAFILE.LAST_CHANGE# column remain NULL, so at the next startup Oracle knows that last close was not clean and the instance recovery is necessary.

So, when an issue force a shutdown abort (for example), the db is closed before V$DATAFILE.LAST_CHANGE# can be updated to V$DATAFILE.CHECKPOINT_CHANGE#.

In other words, when both SCN are the same (V$DATAFILE.LAST_CHANGE# and V$DATAFILE.CHECKPOINT_CHANGE#) we have no problem, but if V$DATAFILE.LAST_CHANGE# is NULL then the instance need recovery.

Question.

If  V$DATAFILE.LAST_CHANGE# and V$DATAFILE.CHECKPOINT_CHANGE# have the same value, are we out of any issue?
The answer is no. Not entirely. This is because Oracle do another check on the datafiles. He verify that V$DATAFILE_HEADER.CHECKPOINT_CHANGE# (2) and V$DATABASE.CHECKPOINT_CHANGE# (3) are the same. If not, than media recovery is needed.

(1) https://docs.oracle.com/cd/E11882_01/server.112/e40402/dynviews_1100.htm#REFRN30050
(2) https://docs.oracle.com/cd/E11882_01/server.112/e40402/dynviews_1102.htm#REFRN30052
(3) https://docs.oracle.com/cd/E11882_01/server.112/e40402/dynviews_1097.htm#REFRN30047

Part 1
Part 2

Visualizing the alert.log

Usually an alert.log file has a date at first line followed by some several messages.

Mon Aug 08 09:29:49 2016 
Thread 1 advanced to log sequence 2348 (LGWR switch)
Current log# 7 seq# 2348 mem# 0: +DGCUSDB01/redolog/cusctip_01_07_01.dbf
Current log# 7 seq# 2348 mem# 1: +DGCUSDB02/redolog/cusctip_01_07_02.dbf

With this python script you can visualize an alert.log in a different way: each line is made of a date + message

Sat Aug 06 15:58:12 2016 Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production
Sat Aug 06 15:58:12 2016 With the Partitioning, Real Application Clusters, Oracle Label Security and Oracle Database Vault options.
Sat Aug 06 15:58:12 2016 ORACLE_HOME = /sbRdbms/app/oracle/product/11.2.0.4/dbh01Rac
Sat Aug 06 15:58:12 2016 System name: Linux
Sat Aug 06 15:58:12 2016 Node name: mdapora1d01
Sat Aug 06 15:58:12 2016 Release: 3.10.0-123.el7.x86_64
Sat Aug 06 15:58:12 2016 Version: #1 SMP Mon May 5 11:16:57 EDT 2014
Sat Aug 06 15:58:12 2016 Machine: x86_64
Sat Aug 06 15:58:12 2016 Using parameter settings in server-side pfile /sbRdbms/app/oracle/product/11.2.0.4/dbh01Rac/dbs/initCUSCTIp1.ora
Sat Aug 06 15:58:12 2016 System parameters with non-default values:
Sat Aug 06 15:58:12 2016 processes = 2500
Sat Aug 06 15:58:12 2016 sessions = 3840
Sat Aug 06 15:58:12 2016 spfile = "+DGCUSDB01/cusctip/pfile/spfilecusctip.ora"
Sat Aug 06 15:58:12 2016 sga_target = 8G
Sat Aug 06 15:58:12 2016 control_files = "+DGCUSDB01/cusctip/cntl/cusctip_control_01.ctl"
Sat Aug 06 15:58:12 2016 control_files = "+DGCUSDB02/cusctip/cntl/cusctip_control_02.ctl"
Sat Aug 06 15:58:12 2016 db_block_size = 8192
Sat Aug 06 15:58:12 2016 compatible = "11.2.0.4.0" 
Sat Aug 06 15:58:12 2016 log_archive_dest_1 = "LOCATION=/dbCUSCTIp/akCUSCTIp01/CUSCTIp/"
Sat Aug 06 15:58:12 2016 log_archive_format = "archive_DBID%d_CUSCTIp%t_%s_%r.dbf"
Sat Aug 06 15:58:12 2016 cluster_database = TRUE


or this

Mon Aug 08 09:29:49 2016 Thread 1 advanced to log sequence 2348 (LGWR switch)
Mon Aug 08 09:29:49 2016 Current log# 7 seq# 2348 mem# 0: +DGCUSDB01/redolog/cusctip_01_07_01.dbf
Mon Aug 08 09:29:49 2016 Current log# 7 seq# 2348 mem# 1: +DGCUSDB02/redolog/cusctip_01_07_02.dbf
Mon Aug 08 09:29:53 2016 Archived Log entry 5093 added for thread 1 sequence 2347 ID 0x4cb57b94 dest 1:
Mon Aug 08 09:31:25 2016 Thread 1 advanced to log sequence 2349 (LGWR switch)
Mon Aug 08 09:31:25 2016 Current log# 1 seq# 2349 mem# 0: +DGCUSDB01/redolog/cusctip_01_01_01.dbf
Mon Aug 08 09:31:25 2016 Current log# 1 seq# 2349 mem# 1: +DGCUSDB02/redolog/cusctip_01_01_02.dbf
Mon Aug 08 09:31:26 2016 Archived Log entry 5095 added for thread 1 sequence 2348 ID 0x4cb57b94 dest 1:

If you want to use my script then

• download the file
• copy the the script on your db machine
• change the first line with the correct python path
• run which python command, to find where is the interpreter
• if you use python3, comment (with # symbol) or delete this line
• from __future__ import print_function

 

Update 2016/Aug/31

I wrote the script so you can run it on a "tail" or "cat" command. For example, you can run

[oracle]# tail -21 alert_+ASM1.log |formatAlertLogX.py
Day Mon DD HH:MI:SS YYYY NOTE: assigning ARB0 to group 45/0xcd5a0bd8 (DGVSAPDB01) with 2 parallel I/Os
Thu Aug 25 09:26:58 2016 NOTE: header on disk 0 advanced to format #2 using fcn 0.525
Thu Aug 25 09:27:02 2016 NOTE: Attempting voting file refresh on diskgroup DGVSAPDB01
Thu Aug 25 09:27:02 2016 NOTE: Refresh completed on diskgroup DGVSAPDB01. No voting file found.
Thu Aug 25 09:28:00 2016 NOTE: GroupBlock outside rolling migration privileged region
Thu Aug 25 09:28:00 2016 NOTE: requesting all-instance membership refresh for group=45
Thu Aug 25 09:28:00 2016 NOTE: membership refresh pending for group 45/0xcd5a0bd8 (DGVSAPDB01)
Thu Aug 25 09:28:00 2016 GMON querying group 45 at 79717 for pid 22, osid 20432
Thu Aug 25 09:28:00 2016 SUCCESS: refreshed membership for 45/0xcd5a0bd8 (DGVSAPDB01)
Thu Aug 25 09:28:00 2016 NOTE: Attempting voting file refresh on diskgroup DGVSAPDB01
Thu Aug 25 09:28:00 2016 NOTE: Refresh completed on diskgroup DGVSAPDB01. No voting file found.
Thu Aug 25 09:28:33 2016 NOTE: stopping process ARB0
Thu Aug 25 09:28:33 2016 SUCCESS: rebalance completed for group 45/0xcd5a0bd8 (DGVSAPDB01)

Export/Import: on the fly

Here I show how to run export and import from a machine to another, just using pipes.

This is the configuration:

• Two unix machine
• source => HP-UX B.11.11
• target => Red Hat Enterprise Linux 7.1
•  Two database Oracle
• source => Oracle 9.2.0.6
• target => Oracle 11.2.0.4

This is what we want:

In this picture:

• "src_hst", is the source machine
• "src_db", is the source database
• "src_usr", is the user, on the source database, which we export
• "trc_db", is the target database
• "trc_hst", is the target machine
• "trg_user", is the user, on the target database, to be imported
• "exp", is the export command
• "imp", is the import command
• "net", is the network between src_db and trg_db

To do this job (exp/imp), I configure the target machine, first and the source machine at least.

Starting from the target, you start to create a tube from the end to the biginning. In this way, when you fill the tube (start the export), the data flow through it and when they arrived to the end, they find someone (the import) that empty the tube.

Configuring the target and the source

This is the step number 0. In order to avoid the password when you connect from source to the target, you need to exchange the ssh-key.

You have just to run the "ssh-keygen" command on the source, and press RETURN any time. 

[oracle@src_hst]$ ssh-keygen (see update)
Generating public/private rsa key pair.
Please be patient....   Key generation may take a few minutes
Enter file in which to save the key (/home/oracle/.ssh/id_rsa): Enter passphrase (empty for no passphrase):
Enter same passphrase again:
Your identification has been saved in /home/oracle/.ssh/id_rsa.
Your public key has been saved in /home/oracle/.ssh/id_rsa.pub.
The key fingerprint is:
bc:23:30:20:37:20:5b:9b:17:f5:5f:f9:10:cd:62:bd oracle@ht1-jim
The key's randomart image is:
+--[ RSA 2048]----+
|o . ...     .+   |
|.+ o . .    oo+  |
|o * .   .  .+. . |
| o +   . . . oE  |
|    o   S .   .  |
|     o   .       |
|      . o        |
|       . .       |
|                 |
+-----------------+


At this point you have two files in the /home/oracle/.ssh, direcotry

• id_rsa
• id_rsa.pub

You have to copy the content of the /home/oracle/.ssh/id_rsa.pub (following an example).....

[oracle@src_hst]$ cat /home/oracle/.ssh/id_rsa.pub
ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEArRfiCNq6nodHj5EKWeQ6ILOe/yICYVONaZa0SKF09msdZvfXYU+rN55fbubonwftyUjZbMRnMIoKTrsxi+UhFe8jIS2l/oVbOerHlCeyhXgCu+NrGM6Q56QPmrJgBMm7b1rb2Tsnh3jdTo3R00i7aCdaLvrVL3oK7IFS2jaVGGhJYTU1LXi8mhXQ3oQXkQ2bHkGGQ9Z68CD4cyYZ4St6lF7xLamwtvXwpC+M8m4s6zM/YiYTKib6RohLt7+kfXfzF3Boyx9AXOmTu93IS2GsRaiMcGVW/GH6T7qVvwPQej0vxpALOf2wdkRL5uSjVdGFUxwgXWDOtKlFDoWHEyYuuw== oracle@src_hst

.....in the /home/oracle/.ssh/authorized_keys file of the target host (following an example)

[oracle@trc_hst]$ cat /home/oracle/.ssh/authorized_keys
ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEArRfiCNq6nodHj5EKWeQ6ILOe/yICYVONaZa0SKF09msdZvfXYU+rN55fbubonwftyUjZbMRnMIoKTrsxi+UhFe8jIS2l/oVbOerHlCeyhXgCu+NrGM6Q56QPmrJgBMm7b1rb2Tsnh3jdTo3R00i7aCdaLvrVL3oK7IFS2jaVGGhJYTU1LXi8mhXQ3oQXkQ2bHkGGQ9Z68CD4cyYZ4St6lF7xLamwtvXwpC+M8m4s6zM/YiYTKib6RohLt7+kfXfzF3Boyx9AXOmTu93IS2GsRaiMcGVW/GH6T7qVvwPQej0vxpALOf2wdkRL5uSjVdGFUxwgXWDOtKlFDoWHEyYuuw== oracle@src_hst

Now you are ready to start the import/export job.

Configuring the target

[oracle@trc_hst]$ mkdir /home/oracle/IMPORT
[oracle@trc_hst]$ mknod /tmp/impTrcUsr.pipe p
[oracle@trc_hst]$ nohup imp trc_usr/trc_pwd \
                        file=/tmp/impTrcUsr.pipe \
                        parfile=/home/oracle/IMPORT/impTrcUsr.par \
                        > /home/oracle/IMPORT/impTrcUsr.nohup 2>&1 &

I used a parfile. Because I don't want to import the index, I used these options:

[oracle@trc_hst]$ cat /home/oracle/IMPORT/impTrcUsr.par
BUFFER=5000000
INDEXES=N
 

Configuring the source

[oracle@src_hst]$ mkdir /home/oracle/EXPORT
[oracle@src_hst]$ mknod /tmp/expTrcUsr.pipe p
[oracle@src_hst]$ nohup ssh oracle@src_hst "cat > /tmp/impSrcUsr.pipe" < /tmp/expTrcUsr.pipe &
[oracle@src_hst]$ time nohup exp src_usr/src_pwd \
                       file=/tmp/expTrcUsr.pipe \
                       parfile=/home/oracle/EXPORT/expSrcUsr.par \
                       > /home/oracle/EXPORT/expSrcUsr.nohup 2>&1 &

I used a parfile. Because I want to export only 2 tables, I used these options:

[oracle@src_hst]$ cat /home/oracle/EXPORT/expSrcUsr.par
DIRECT=Y
BUFFER=5000000
RECORDLENGTH=5000000
TABLES=(MYTAB01, MYTAB02)
 

Note on the import

I'm using a pipe instead a standard file. Except this, all is usual.

Note on the export

* I'm using a pipe instead a standard file
* I'm using a remote command "cat", in order to write the exported data into the remote pipe
* The source pipe is used as standard of input of ssh command. In this way all that is wrote in the source pipe is also wrote in the remote pipe
* I use the "time" command, in order to know how long the export/import process takes

Update

19/July/2017
Sometimes the ssh-keygen command want the type of  encryption. In this case you have to use the -t switch. For example

$ ssh-keygen -t rsa

Instance Needs Recovery: Introduction (2/3)

Part 1
Part 3

Closing a Redo Log file

There is always a CURRENT Redo Log file (one for each Instance of RAC).
When Oracle begin to write the CURRENT Redo Log file, it set the Low SCN (V$LOG.FIRST_CHANGE#) to the current SCN of the database and set the High SCN (V$LOG.NEXT_CHANGE#) to 281474976710655. Think this number as a infinite value.

Oracle do this because it don't know the final value of the High SCN,

When there is a "Log Switch (it appen wheh the CURRENT Redo Log is full or a DBA run "ALTER SYSTEM SWITCH LOGFILE statement) Oracle set the V$LOG.NEXT_CHANGE# column  to current SCN +1, and than begin to use the next Redo Log file.

The operation that set the V$LOG.NEXT_CHANGE# to a finite value, is called "closing the Redo Log file".

Archived Log

Some definition:

"A log switch is the event during which LGWR stops writing to one online redo log group and starts writing to another" (1). "The background process ARCn automates archiving operations when automatic archiving is enabled" (2)

"An archived redo log file is a copy of one of the filled members of a redo log group". "The process of turning online redo log files into archived redo log files is called archiving" (2)

"When running in ARCHIVELOG mode, the log writer process (LGWR) is not allowed to reuse and hence overwrite an online redo log group until it has been archived" (2)

When the log switch occur
(i) LGWR starts writing to another one
(ii) the ARCn process automates archive in backup the CURRENT redolog (3)

so, a user session not need to wait the arichive finish



(1) https://www.bnl.gov/phobos/Detectors/Computing/Orant/doc/database.804/a58397/ch5.htm
(2) https://docs.oracle.com/cd/B19306_01/server.102/b14231/archredo.htm
(3) http://www.datadisk.co.uk/html_docs/oracle/redo.htm
(4) Master Note: Troubleshooting Redo Logs and Archiving (Doc ID 1507157.1)

Part 1
Part 3

Instance Needs Recovery: Introduction (1/3)

Part 2
Part 3

In order to understand why the recovery of an instance is necessary, we need to know following background: 

1. Log Journal 
2. System Schange Number 

Log Journal 

Oracle save all changes in a logbook. This logbook are Redo Log Files (sometimes the logbooks are also called Transaction Logs). The Redo Log File works in Groups.

There are at least two Groups. Groups are made of Members. 

There are one or more member in each Group. All members in a Group are copies. 

Time to time, a Group is identified by a different number called Sequence. The Sequence is the chapter of a logbook.

There is always a CURRENT Group: it is the actual chapter where Oracle is writing. A Group can be ACTIVE. This mean that the information in that chapter are necessary to rebuild the last moments of life in case of unexpected death (abort).

System Change Number 

Oracle use numbers in order to measure it life. These numbers are integer and called SCN (System Change Number).

Each SCN is associated with time. When the changes are forever (commit), Oracle save this number in the logbook.  

The SCN is unique into database, but it has a different name based on the context it is used.

For example the V$LOG view, show 2 SCN: FIRST_CHANGE# and NEXT_CHANGE#. Their name are “Low SCN” and “High SCN”. 

Oracle release the SCN after a COMMIT. What I mean is that Oracle release the SCN when the changes are made final.

System Change Number is a too long name, so it called simply “Change”.

RAC 

In RAC, each insance have it Redo Log Group. One Group is called “Thread”. A Group is unique in the database. Each Thread have it CURRENT Group. 

The SCNs are unique in all database. Each instance always know the SCN of the other instances.

Update 2016/06/03

• I modified some phrases. I'm sorry, but I don't speak well english
• Also I wrote the wrong name of High SCN, so I changed the LAST_CHANGE# with NEXT_CHANGE#.

Part 2
Part 3

ASH. Like a movie (3/3)

In the previous post [1a] [1b], I shown a chart that you can see here

This picture show how the sampling (blue) and real time analysis (read) are intimately linked each other. In order to obtain that, I used the query [2] based on what I explain now.
 
The master document [3] was published by John Beresniewicz, Graham Wood, Uri Shaft. For it, exist also a video on You Tube [4].

The main formula is

DB Time ~ sample_nr * (rows in ASH)

where the "sample_nr" is the sample frequency. It's value, depend from row surce.

* V$ACTIVE_SESSION_HISTORY,     sample_nr => 1

* DBA_HIST_ACTIVE_SESS_HISTORY, sample_nr => _ash_disk_filter_ratio (default is 10)

In my query, there are three main components. They are in the "with" section: "awr", "ash" and "db_time".

• AWR Here 

I select the sample frequency of DBA_HIST_ACTIVE_SESS_HISTORY view.

select 
       ash_value.ksppstvl 
  from x$ksppi ash_name 
      ,x$ksppsv ash_value 
 where 
       ash_name.indx    = ash_value.indx 
   and ash_name.ksppinm = '_ash_disk_filter_ratio'; 

• ASH (Y-axis) 

The "rows in ASH" values, are the rows in DBA_HIST_ACTIVE_SESS_HISTORY.

select 
       instance_number
      ,snap_id, count(*)
      ,snap_id, 10*count(*) 
  from 
       dba_hist_active_ess_history
       dba_hist_active_sess_history  
group by 
       instance_number, snap_id; 

• DB_Time (Y-axis) 

The last piece of my query is the value of DB Time. For it I used the LAG analytic function in order to obtain the previous row:

select 
       snap_id 
      ,instance_number 
      ,(value - lag(value) over (partition by instance_number order by snap_id))/1000000 diff 
  from 
      dba_hist_sys_time_model 
 where 
      stat_name='DB time'; 


As last step I join this three query with DBA_HIST_SNAPSHOT, in order to get the "sample time" (X-axis). See [2] to get the full statement.

• Update

06/Oct/2017 - modified dba_hist_active_ess_history in dba_hist_active_sess_history

06/Oct/2017 - modified count(*) in 10*count(*)

• References

[1a] http://orasal.blogspot.it/2016/03/ash-like-movie-13.html
[1b] http://orasal.blogspot.it/2016/03/ash-come-un-film-13.html
[2] https://www.dropbox.com/s/gp4fh6soz0erwvq/ashvsdbtime.txt?dl=0
[3] http://www.slideshare.net/jberesni/ash-architecture-and-advanced-usage-rmoug2014-36611678
[4] https://www.youtube.com/watch?v=rxQkvXIY7X0

ASH. Like a movie (2/3)

Here the Italian version

ASH. Like a movie (1/3)
ASH. Like a movie (3/3)


In order to show how ASH is like the DB Time, I made a chart reporting both metrics in the same place.

However, some measures are "strange". I show this in this post.

The first anomaly is one in which there is a negative peak.

Snap_id.Sample Time	Sample	DB Time
92722.28-MAR-16 07.00.43.468 AM	5980	-7166541

This is due to restart of the instance, so I delete this point.

The second anomaly is of 3 peaks. These are a surge of Time DB.

Snap_id.Sample Time	Sample	DB Time
92614.26-MAR-16 12.00.15.371 AM	72870	78461
92626.26-MAR-16 06.00.46.878 AM	75420	100475
92677.27-MAR-16 08.30.58.334 AM	44570	124111

After I deleted this three points, the chart is like this...

...and you can see that the sampling approximates the real time.

The cause of the first point is the restart of the instance that drops all statistics. I'm investigating why sometimes exists (in this case there are 3 points) the difference between ASH and DB Time.

ASH. Like a movie (1/3) ASH. Like a movie (3/3)

ASH. Come un film (2/3)

Qui la versione Inglese

ASH. Come un film (1/3)
ASH. Come un film (3/3)

Nell'ottica di mostrare che ASH è come il DB Time, ho graficato l'andamento di entrambi in un solo posto.

Tuttavia le misure hanno alcuni punti "anomali". Mostro questi punti di seguito.

La prima anomalia è quella in cui è presente un picco negativo.

Snap_id.Sample Time	Sample	DB Time
92722.28-MAR-16 07.00.43.468 AM	5980	-7166541

Questo è dovuto al riavvio dell'istanza. Allora io cancello questo punto.

La sesconda anomalia è costituita da 3 picchi. Questi corrispondono ad un'impennata del DB Time.

Snap_id.Sample Time	Sample	DB Time
92614.26-MAR-16 12.00.15.371 AM	72870	78461
92626.26-MAR-16 06.00.46.878 AM	75420	100475
92677.27-MAR-16 08.30.58.334 AM	44570	124111

Una volta eliminati anche questi tre punti, il grafico risultante è quello mostrato di seguito...

...da cui si deduce come nonostante il campionamento, ASH approssima bene il DB Time.

Eccetto il primo punto dovuto al riavvio dell'istanza che azzera tutte le statistiche, sto ancora indagando il motivo per cui in alcuni casi, esiste questa differena tra ASH e DB Time.

ASH. Come un film (1/3) ASH. Come un film (3/3)

ASH. Like a movie (1/3)

Here the Italian version

In Oracle 10g was introduced the "Intelligent Self-Management Infrastructure" [1].

Basically the idea is to collect the most informations with the minor impact on the system. Based on Heisenberg's Uncertainty Principle, we know that "the observer affects the observed" [2]. And this is true also for Oracle.

One component of the "Intelligent Self-Management Infrastructure" is ASH. In this post I would like to show you a special point of view base on an idea of Kyle Hailey [3].

We know that ASH is based on sampling made each second. This mean that there are the gaps between snapshots. Really we want analyze only long sessions (only "this long sessions" impact on the performance). So, if a session takes a lot of minutes before the end, you are sure to observe the work, even if the observation is made every second. Is like you see a movie, one frame each second.

Because a picture is worth a thousand words, I show you this picture from [3].

It shows how is possible to understand what is happening also if we don't know the story in real time.

And the wonderful thing is that the sampling is like the real time. In order to show that this last statement is true I used a query [4] which output is this chart. I created it using Microsoft excel.

The chart shows the difference between sampling (ASH) and real time (DB Time). In Y there are the "ASH"/"DB Time" values, while in X the "snap_id"/"time stamp" values.

Really, to build this chart, I delete some values. I'm investigating the root cause of those anomalies.

• Update 31/Mar/2016

I modified the chart, because I deleted one point from the graph. I'm writing a post on anomaly I observed.

• References

[1] http://www.oracle.com/technetwork/database/manageability/twp-manage-intelligent-infrastructu-133531.pdf
[2] http://www.oracle.com/technetwork/database/manageability/twp-40169-134162.pdf
[3] https://sites.google.com/site/embtdbo/wait-event-documentation/ash---active-session-history
http://blog.orapub.com/20150812/Which-Is-Better-Time-Model-Or-ASH-Data.html
[4] http://www.evernote.com/l/ABzQFwwMxo5HyKs8pmpIcyVjmjH7vreMvVo/

lsasmdsk, Solaris version (ENG)

In order to associate the ASM disk in /dev/oracle directory with raw device, I made follofing script

#!/bin/ksh

DISK_ASM_DIR=/dev/oracle
DISK_OS_DIR=/dev/rdsk
DISK_OS_SCSI=${DISK_OS_DIR}/../../devices/scsi_vhci
DISK_OS_TYPE=brw #also crw

echo "ASM Disk        Device                                             Mj, Mn"
echo "--------------  -------------------------------------------------  ----------"
for _asm_disk_name in $(ls -l $DISK_ASM_DIR |grep -v total |awk '{print $(NF)}'); do
  asm_major_nr=$(ls -l ${DISK_ASM_DIR}/${_asm_disk_name} |awk 'BEGIN {FS=","}{print $1}'|awk '{print $NF}')
  asm_minor_nr=$(ls -l ${DISK_ASM_DIR}/${_asm_disk_name} |awk 'BEGIN {FS=","}{print $2}'|awk '{printf "%3s", $1}')
  scsi_disk=$(ls -l ${DISK_OS_SCSI} |grep ${asm_major_nr}|grep ${asm_minor_nr}|grep ^brw|sed 's/[@g|:| ]/,/g'|sed 's/,,*/,/g'|nawk -v amn="${asm_minor_nr}" 'BEGIN {FS=","} $6==amn {print $(NF-1)}')
  os_disk=$(ls /dev/rdsk |grep -i ${scsi_disk}|grep s0$)
  printf "%-15s %-50s [%-s,%4s]\n" $_asm_disk_name ${DISK_OS_DIR}/$os_disk ${asm_major_nr} ${asm_minor_nr}
done

This is an example of output

ASM Disk        Device                                             Mj, Mn
--------------  -------------------------------------------------  ----------
CRSOCR01        /dev/dsk/c5t600601605D102200355914322ACCDD11d0s0   [118, 480]
CRSVTG01        /dev/dsk/c5t600601605D102200345914322ACCDD11d0s0   [118, 488]
ORTST001        /dev/dsk/c5t600601605D1022006A5AB93EDDF9DD11d0s0   [118, 504]
ORTST002        /dev/dsk/c5t600601605D1022006B5AB93EDDF9DD11d0s0   [118, 496]
ORTST003        /dev/dsk/c5t600601605D1022006C5AB93EDDF9DD11d0s0   [118, 512]
WRADK001        /dev/dsk/c5t600601605D10220020BD730C29CCDD11d0s0   [118, 440]
WRADK002        /dev/dsk/c5t600601605D10220021BD730C29CCDD11d0s0   [118, 368]
WRADK003        /dev/dsk/c5t600601605D10220022BD730C29CCDD11d0s0   [118, 296]
WRADK004        /dev/dsk/c5t600601605D10220023BD730C29CCDD11d0s0   [118, 224]
WRADK005        /dev/dsk/c5t600601605D10220024BD730C29CCDD11d0s0   [118, 152]
WRADK006        /dev/dsk/c5t600601605D10220025BD730C29CCDD11d0s0   [118,  32]

ASH. Come un film (1/3)

Qui la versione Inglese

Nella versione 10g, Oracle ha introdotto l'"Intelligent Self-Management Infrastructure" [1]

L'idea di base di tale Infrastruttura è quella di raccogliere il maggior numero di informazioni con il minor impatto sul sistema. In base al principio di intederminazione di Heisenberg, sappiamo che osservando un fenomeno ne modifichiamo il comportamento. E questo ovviamente si applica anche all'rdbms [2].

Una delle componenti dell'infrastruttura è ASH.

In questo post vorrei mettere in evidenza un particolare punto di vista, basato su un idea di Kyle Hailey [3].

Sappiamo che ASH è basato su un campionamento effettuato ogni secondo. Questo ovviamente comporta dei buchi tra un'istantanea e l'altra. In raltà noi siamo interessatti solo a quelle sessioni che durano un certo periodo di tempo (soltanto le "sessioni lunghe" vengono analizzate: quelle di breve durata non hanno generalmente impatto sulle performance).
Così se una sessione impiega minuti prima di terminare, sono sicuro di osservare la sua attività, anche se questa non avviene in modo continuo ma solo ad intervalli di un secondo. E' come vedere un film a fotogrammi distanziati di un secondo.

(questa immagine è presa da [3])

Come sempre un'immagine vale più di mille parole. Quella qui sopra ci mostra come sia possibile determinare cosa stia succedendo anche se non ne conosciamo la storia istante per istante.

E la cosa più sbalorditiva è che il campionamento è quasi del tutto fedele al modello temporale. Per mostrare questo ho utilizzato una query [4] il cui risultato è il grafico in figura ottenuto con Microsoft Excell

Il grafico mostra la differenza tra misure campionate (ASH) e quelle ottenute in tempo reale (DB Time). In Y c'è il valore di "ASH"/"DB Time", mentre in X lo "snap_id/time stamp"

In realtà, per ottenere questo grafico, ho dovuto eliminare alcuni valori. Sto cercando ancora di capire quali sono le cause che producono tali anomalie.

• Update 31/Mar/2016

Ho modificato l'immagine perché ho eliminato un punto dak grafico. Sto scrivendo un post sulle anomalie che ho riscontrato.

• Riferimenti

[1] http://www.oracle.com/technetwork/database/manageability/twp-manage-intelligent-infrastructu-133531.pdf
[2] http://www.oracle.com/technetwork/database/manageability/twp-40169-134162.pdf
[3] https://sites.google.com/site/embtdbo/wait-event-documentation/ash---active-session-history
http://blog.orapub.com/20150812/Which-Is-Better-Time-Model-Or-ASH-Data.html
[4] http://www.evernote.com/l/ABzQFwwMxo5HyKs8pmpIcyVjmjH7vreMvVo/

DB Time (2 of 3) (ENG)

Here the Italian version

DB Time (1 of 3)
DB Time (3 of 3) (soon)

DB Time = CPU Time + Wait Time

is the equation that ties the main components of the database:
- work time
- wait time

You can rewrite this equation as (you divide by DB Time and multiply by 100)

100 = (CPU Time/DB Time)*100 + (Wait Time/DB time)*100

This is the way the "AWR" shows us the "Top Timed Events". Let's see. The example that follows, is taken from one of the last tuning I made on a version of Oracle 10g

• AWR Report - 10.2.0.5 Version

 

  

 

DB Time = 440 mins = 26400 secs

log file switch (checkpoint incoplete)	11908 / 26400 => 0,45106 => 45,1%
gc buffer busy	5376 / 26400 => 0,20363636 => 20,4
PX Deq Credit: send blkd	1537 / 26400 => 0,058219696 => 5,8%
buffer busy waits	1358 / 26400 => 0,0514393939 => 5,1%

In later versions, the name of the column containing the percentage (second from right) "% DB Time"
 

• AWR Report - 11.2.0.4 Version

   

  

DB Time = 498 mins = 29880 secs

db file sequential read	2736 / 29880 => 0,09156 => 9,15%
db file scattered read	1753 / 29880 => 0,05866 => 5,86%
log file sync	1500 / 29880 => 0,05020 => 5,02%
row cache lock	1096 / 29880 => 0,03668 => 3,67%

• AWR Report - 12.1.0.2 Version

 

 

DB Time = 21 mins = 1260 secs

db file sequential read	57,5 / 1260 => 0,04563 => 4,56%
rdbms ipc reply	50,7 / 1270 => 0,04023 => 4,02%
DFS lock handle	18,2 / 1270 => 0,01433 => 1,43%
log file sync	13,6 / 1270 => 0,01070 => 1,07%

DB Time (1 of 3) DB Time (2 of 3) (soon)

DB Time (1 di 3) (ENG)

Here the Italian version

DB Time (2 of 3)
DB Time (3 of 3) (soon)

When you fight with tuning, you always have to deal with time. The end user, perceives all problems in term of response time. Time is the link from user experience with database performance.

In Oracle 10g, was introduced the “Intelligent Infrastructure”.

The goal of this infrastructure is:
- self-monitor
- self-diagnostic
- self-tuning

This was in 2004.

In this post and the next, I'm going to talk about 2 tools the Oracle “Intelligent Infrastructure” give us:
- DB Time
- ASH

DB Time

It is defined as the “amount of time spent within the database in processing an user request”.

It unit of measure is microseconds and you can get it directly from Data Dictionary. The views are:
- V$SYS_TIME_MODEL
- V$SESS_TIME_MODEL

When a process can't consume CPU, it have to wait in order to use CPU again. We know this wait as "wait event". In other words when a process can't use a CPU, it alert you that it need to wait and the reason of wait is the "wait event".

The important thing is that not always the waits impact the performance. If not, then we consider this waits as "Idle". Instead, if the wait have performance impact, then we consider the wait as “Non-Idle”.

So, an active process (that is, it's working) or consume CPU or wait on an Non-idle wait event.

You can write all of this, through a mathematical expression:

DB Time = CPU Time + Non-Idle Wait Time

We consider “Non-Idle” as obvious, so we rewrite the expression as:

DB Time = CPU Time + Wait Time

Really,  the right relation is:

DB Time = CPU Time + Wait Time + gap

This is because when the CPUs are too much active, then the “CPU Queue Time” grows, that is, grows the wait time of processes before they use a CPU again. Oracle calls this specific wait as “CPU Wait Time”. Obviously this is not happy name for a wait event.

You can find more details about "gap", using the below links (see references). In any case, here we are interested to the more usual expression:

DB Time = CPU Time + Wait Time

Reference

• What Is Light Green Oracle Database CPU Wait Time
• How OS CPU Run Queue Time Relates To Oracle Database DB Time
• Oracle Wait Events Investigated with Extended Stack Profiling and Flame Graphs
• AWR Ambiguity: Performance reasoning when the numbers don't add up

DB Time (2 of 3)

ASH: Introduction (Part 1 of 3)

Here, Italian version

There are tools that allow you a super fast sampling (10-100 times per second) using C programs. The goal of those tools is record information about a specific session. Really, in most case (the 99,9%) the monitoring can be done sampling 1 time per second, showing you both system load and system activity. This information could be difficult or too expansive to collect (there is also the problem that the tool impact the application itself) 

Most of the performance could be sampled, storing just the most important once and in a particular way: instead of to collect the exact statistics (information obtained instrumenting the C-code), ASH sample each second the status of all ACTIVE sessions (the session in "ACTIVE" state is a session executing a database call [1]) as well as the SQL that the session is running.

ASH stands for "Active Session History" and was introduced in Oracle 10g. The view of data dictionary is V$ACTIVE_SESSION_HISTORY. Over time the information collected from ASH have increased so release after release the columns of the view are grown in number. Following picture shows the change during the release

https://sites.google.com/site/embtdbo/wait-event-documentation/ash---active-session-history/ash_across_versions.PNG?attredirects=0

References

• [1] Active Session = session currently running (spending time) in a database call (sessions with status=ACTIVE in v$session view)
• https://sites.google.com/site/embtdbo/wait-event-documentation/ash---active-session-history

ASH: Introduzione (Parte 1 di 3)

Qui la versione inglese

Esistono tool che permettono un campionamento velocissimo (10-100 volte al secondo) utilizzando ad esempio programmi scritti in C, con lo scopo di raccogliere informazioni su una specifica sessione. In realtà nella maggioranza dei casi (il 99,9%) il monitoraggio può essere ottenuto con un semplice campionamento di 1 volta al secondo mostrando sia il carico sul sistema che informazioni sull'attività del sistema. Informazioni che altrimenti sarebbero troppo difficili o eccessivamente costose da collezionare (sorge anche il problema che un tool invasivo falsa il risultato finale dovuto a se stesso).

La maggior parte delle informazioni di perfornamce può essere collezionata non salvando ogni tipo di dato, ma soltatno quelle più importanti: invece di collezionare l'esatta statistica (informazione ottenuta con la "strumentazione" del codice, ovvero introducendo specifiche chiamate all'inrerno del codice C, verso il sistema operativo), ASH campiona ogni secondo lo stato di tutte le sessioni "ATTIVE" (per stato "ATTIVO" si intende una sessione che esegue una chiamata al database [1]) e l'SQL che quella sessione sta eseguendo.

ASH è un acronimo per "Active Session History" ed è stato introdotto in Oracle 10g. La vistadi riferimento del dizionario dati è V$ACTIVE_SESSION_HISTORY.
Nel tempo le informazioni raccolte in V$ASH sono aumentate e così release dopo release, la quantità di colonne in tale vista sono cresciute di numero. La seguente immagine mostra le veriazioni che si sono avute 


https://sites.google.com/site/embtdbo/wait-event-documentation/ash---active-session-history/ash_across_versions.PNG?attredirects=0

Riferimenti

• [1] Active Session = sessioni attualmente in esecuzione (che consumano tempo) in una  "database call" (sessioni con "status"=ACTIVE in v$session view)

• https://sites.google.com/site/embtdbo/wait-event-documentation/ash---active-session-history

lsamsdsk, AIX version (ENG)

In order to associate the ASM disk in /dev/oracle directory with raw device, I made follofing script

#!/bin/ksh

export DISK_ASM_DIR=/dev/oracle
export DISK_OS_DIR=/dev
export DISK_OS_TYPE=crw #also brw


echo "ASM Disk        Device               Mj,Mn"
echo "--------------  -----------------    ---------"
for _asm_disk_name in $(ls -l $DISK_ASM_DIR |grep -v total |awk '{print $(NF)}'); do
  asm_major_nr=$(ls -l ${DISK_ASM_DIR}/${_asm_disk_name} |awk 'BEGIN {FS=","}{print $1}'|awk '{print $NF}')
  asm_minor_nr=$(ls -l ${DISK_ASM_DIR}/${_asm_disk_name} |awk 'BEGIN {FS=","}{print $2}'|awk '{printf "%3s", $1}')
  os_disk=$(ls -l $DISK_OS_DIR |grep "${asm_major_nr},${asm_minor_nr}"|grep ^${DISK_OS_TYPE}|awk '{print $NF}')
 
  printf "%-15s %-20s [%-s,%3s]\n" $_asm_disk_name ${DISK_OS_DIR}/$os_disk ${asm_major_nr} ${asm_minor_nr}
done

This is an example of output

ASM Disk        Device               Mj,Mn
--------------  -----------------    ---------
DWHBOpDSK01     /dev/rhdisk93        [17, 92]
DWHBOpDSK02     /dev/rhdisk94        [17, 94]
DWHDBS.ocr      /dev/rhdisk4         [17,  4]
DWHDBS.ovd      /dev/rhdisk11        [17, 11]
DWHICTpDSK01    /dev/rhdisk58        [17, 57]
DWHICTpDSK02    /dev/rhdisk51        [17, 51]
DWHICTpDSK03    /dev/rhdisk59        [17, 59]
DWHICTpDSK04    /dev/rhdisk60        [17, 60]
DWHICTpDSK05    /dev/rhdisk52        [17, 52]
DWHICTpDSK06    /dev/rhdisk53        [17, 53]
DWHICTpDSK07    /dev/rhdisk54        [17, 54]
DWHICTpDSK08    /dev/rhdisk55        [17, 55]
DWHICTpDSK09    /dev/rhdisk61        [17, 62]
DWHICTpDSK10    /dev/rhdisk62        [17, 61]
DWHICTpDSK11    /dev/rhdisk56        [17, 56]
DWHICTpDSK12    /dev/rhdisk57        [17, 58]
DWHICTpDSK13    /dev/rhdisk63        [17, 63]
DWHICTpDSK14    /dev/rhdisk64        [17, 64]
DWHICTpDSK15    /dev/rhdisk116       [17,117]

The two numbers in parentheses are major and minor number respectively.

I checked this script on IBM AIX platform