Monitoring your Standby with V$RECOVERY_PROGRESS

I have blogged previously about various ways you can monitor the progress of your physical standby, and I have now come across another way of determining how well your standby is doing at applying the redo logs that are coming it’s way.

The view V$RECOVERY_PROGRESS also gives you an interesting window into the performance of your standby. The official documentation on this is a bit confusing. Basically when you select from this view you get 9 rows of information on each of the various recovery operations you have started. So if you have only ever started managed recovery once since you started the instance you will only see 9 rows returned.

With a physical standby each time you start a managed recovery there will be this series of 9 rows entered into the view. Each row has a type, but while recovering the standby it is always Media Recovery.

SQL> select start_time, item, units, sofar
from V$recovery_progress
order by 1, 2
/


START_TIME	  ITEM				   UNITS             SOFAR
----------------- -------------------------------- ----------   ----------
04-06-08 08:45:54 Active Apply Rate		   KB/sec             3368
04-06-08 08:45:54 Active Time			   Seconds            6184
04-06-08 08:45:54 Apply Time per Log		   Seconds               1
04-06-08 08:45:54 Average Apply Rate		   KB/sec               35
04-06-08 08:45:54 Checkpoint Time per Log          Seconds               1
04-06-08 08:45:54 Elapsed Time			   Seconds         3553772
04-06-08 08:45:54 Last Applied Redo		   SCN+Time     1.8447E+19
04-06-08 08:45:54 Log Files			   Files              2146
04-06-08 08:45:54 Redo Applied			   Megabytes        123788

Helpfully, each item has the unit that the associated measurement comes in.

The average apply rate includes time waiting for the redo to arrive. You can see the active time we have spent applying redo log information is a small proportion of the total elapsed time since we started managed recovery.

The active apply rate therefore gives a better indication of how fast you can actually apply redo on your standby, if you think you are generating redo at a faster rate than this number, then you may well be falling behind on your standby.

As indicated in the documentation this V$RECOVERY_PROGRESS view is actually just a subset of the V$SESSION_LONGOPS view, and while all the information is available there too, the V$RECOVERY_PROGRESS view summarises the relevant data for your media recovery progress in a standby quite nicely.

FAL failing to resolve archive gaps

I had been having problems with FAL failing to resolve archive gaps. The classic error message on my 10.2.0.3 physical standby looked something like this:

FAL[client]: Failed to request gap sequence
GAP - thread 1 sequence 11402-11403
DBID 2878580510 branch 589635294
FAL[client]: All defined FAL servers have been attempted.
————————————————————-
Check that the CONTROL_FILE_RECORD_KEEP_TIME initialization
parameter is defined to a value that is sufficiently large
enough to maintain adequate log switch information to resolve
archivelog gaps.
————————————————————-

Now, a FAL (Fetch Archive Log) request is triggered by the MRP process detecting a gap in the available archives to apply. The server to contact to fulfil the request is determined by the FAL_SERVER parameter which you set to an appropriate tnsnames alias. This essentially enables your standby to contact the primary database and get it to ship the appropriate missing log using the arc process.

While the above situation was logging the above on the standby, no indication of any issues were being logged on the primary. First thought of course was connectivity, but that was easily disproved.

So to get more information I deployed extra logging on both the primary and standby, using the log_archive_trace parameter. This parameter has the ability to trace a number of background processes and is thus useful on both the primary and the standby.

In fact it was the arcn process on the primary that really showed what was wrong, as the trace continually had the following lines:

FAL[server]: Duplicate request detected (dbid 0 branch 127 thread 1 sequence 11402 dest STANDBY)
FAL[server]: Request not queued in this case
FAL[server]: Duplicate request detected (dbid 0 branch 127 thread 1 sequence 11403 dest STANDBY)
FAL[server]: Request not queued in this case
*** 2008-06-03 11:57:18.229
FAL[subfal]: Waiting on response from destination for thread 1 sequence 10890.

So, what is this actually telling us? The standby is asking for 11402, and 11403 and the primary knows the standby is after these, however the primary also thinks the standby is after 10890, but the standby having already applied this does not care about receiving this archived log.

Essentially this log is blocking the FAL process from working properly.

Turns out this is a bug situation. We were hitting bug:5576816 with an associated MetaLink Note: 5576816.8. Seems like it’s related to having max_connections set on the log_archive_dest parameter (which we did).

As an attempted workaround I tried setting the log_archive_max_processes down from 6 to 1, with the following shown in the primary alert log:

Shutting down archive processes
ALTER SYSTEM SET log_archive_max_processes=1 SCOPE=BOTH;
ARCH shutting down
ARC4: Archival stopped
ARCH shutting down
ARC3: Archival stopped
ARCH shutting down
ARC2: Archival stopped
ARCH shutting down
ARC1: Archival stopped
ARC5: Becoming the ‘no FAL’ ARCH
ARC5: Becoming the ‘no SRL’ ARCH
ARC5: Becoming the heartbeat ARCH
ARCH shutting down
ARC5: Archival stopped
ARC0: Becoming the ‘no FAL’ ARCH
ARC0: Becoming the ‘no SRL’ ARCH
ARC0: Becoming the heartbeat ARCH

I then killed (OS kill that is) the final running arc background process - note this is safe according Oracle support, and pmon detects it is dead and restarts the arc process:

ARCH: Detected ARCH process failure
ARCH: STARTING ARCH PROCESSES
ARC0: Archival started
ARCH: STARTING ARCH PROCESSES COMPLETE
ARC0 started with pid=276, OS id=24202
ARC0: Becoming the ‘no FAL’ ARCH
ARC0: Becoming the ‘no SRL’ ARCH
ARC0: Becoming the heartbeat ARCH

This did not work. When the arc0 process restarted it still was thinking it should be sending the 10890 archive log. The only solution was to bounce the instance, thankfully with it being a RAC primary there was no real service outage.

I won’t be caring about FAL next week, as I’m off to the seaside for a week.

Applying an incremental backup to a physical standby

I recently had the situation where a physical standby (running 10.2.0.3) had got itself so far out of date, that transferring the required archived redo logs would have necessitated retrieving them from tape. As a far quicker method of getting this standby back up-to-date (as opposed to a complete rebuild), I decided to apply an incremental backup to the standby.

This procedure is actually reasonably well documented. Except this leaves the controlfile at one SCN while all your datafiles have marched up to the new scn. Upon restarting the managed recovery process, the standby is still asking for ancient archived logs that your datafiles already have the changes applied.

It is interesting to contrast the instructions for 10g above with similar, though not the same instructions for performing this on 11g. The 11g instructions ask for the controlfile to be restored as well. Except the restore standby controlfile did not work on 10.2.0.3 instance.

So here is my guide to applying an rman incremental backup to a physical standby.

Find out where your standby thinks you have applied up to:

standby> alter database recover managed standby database cancel;

standby> select current_scn from v$database;

Make an rman incremental backup on the primary from the above scn:

primary_rman> backup incremental from scn #### database format '/backup/standby_%U';

Once this backup file is copied to the standby, catalog it with the standby controlfile:

standby_rman> catalog start with '/backup/standby';

Now actually apply the changes from the backup to the standby:

standby_rman> recover database noredo;

At this point your datafiles will be up-to-date, but your controlfile is still out of date, create new standby controlfile from the primary:

primary> alter database create standby controlfile as '/tmp/standby.ctl';

Copy this to the standby and replace your current standby controlfiles with this new one. Once this is done you should be able to restart managed recovery and it will take off from your backup scn.

It is this final stage that does not seem to be covered to well with the documentation. Certainly I found I needed this new standby controlfile after applying an incremental backup to my standby.

Registering archive logfiles on a standby

I’ve been having some issues with a physical standby running Oracle 10.2.0.3. This has caused us to have to manually register logfiles to bridge gaps in the archive sequence on the physical standby.

One way of registering a logfile is via the following:

SQL> alter database register logfile
‘/var/arch/arch_1_101.arc’;

So this is a straightforward way of registering a logfile giving the full path to the logfile. However, what if you have a very large number of logfiles to register, the above does not really scale all that well. Thankfully there is an rman command that enables you to register all logfiles within a directory:

rman> catalog start with '/var/arch';

This can save you a lot of time if you need to register a large number of files.

Managing Datafiles on a Standby using ASM

I encountered a curious failure in a dataguard environment, that seems interesting enough to distribute to a wider audience. The system was running 10.2.0.3 on Linux, with the datafiles stored in ASM. This was recorded recently in the RDBMS instance alert log:

MRP0: Background Media Recovery terminated with error 1237
Sun Mar 23 09:57:19 2008
Errors in file /opt/oracle/product/admin/STANDBY/bdump/standby1_mrp0_27165.trc:
ORA-01237: cannot extend datafile 35
ORA-01110: data file 35: '+DATA4/standby/datafile35.dbf'
ORA-17505: ksfdrsz:1 Failed to resize file to size 1624704 blocks
ORA-15041: diskgroup space exhausted

While in the ASM instance alert log I found the following:

Sun Mar 23 09:57:18 2008
WARNING: allocation failure on disk VOL5 for file 286 xnum 12693

At first sight you might think this is an obvious case of the diskgroup filling up and that more space needs to be allocated to it. However when I checked how much free space was available I saw:

SQL> select name, total_mb, free_mb, usable_file_mb from v$asm_diskgroup;

NAME				 TOTAL_MB    FREE_MB USABLE_FILE_MB
------------------------------ ---------- ---------- --------------
DATA1				    61439      29766	      29766
DATA2				    10239	3356	       3356
DATA3				    10239	3356	       3356
DATA4				   220391      25077	      25077
FRA				    68197      67959	      67959

So as far as the V$ASM_DISKGROUP view was concerned there really was enough storage space to allocate to this datafile, note this datafile was already a considerable size so the amount it was extending was nothing compared to the 25GB free. Much scratching of heads ensued, and  I started thinking if fragmentation could be responsible, but then I looked at the contents of the affected diskgroup using asmcmd.

I spotted that there was a datafile that had been removed a couple of weeks previously from the primary. At the same time as that datafile, several others had been removed and all these were gone. And then we remembered that the first drop tablespace command had not included the and datafiles clause. We have standby_file_management set to auto and this worked perfectly for files that were automatically removed on the primary. It did not work for the datafile that was removed manually, as you’d probably expect. Running rm within ASMCMD logged the following kind of thing into the alert log of the ASM instance:

SQL> alter diskgroup 'DATA4' drop file '+DATA4/STANDBY/removed_datafile.dbf'

Once this datafile was removed the standby could continue processing happily and whatever caused it to fail to extend the datafile was now not causing it a problem. The real question is why I could not allocate the space when the diskgroup was not really full?

I think what happened was that the RDBMS instance thought the space allocated to the datafile that was being used by the dropped tablesapace was now available for use again and the database instance tried to extend a tablespace into this space but found it was in fact still occupied by the datafile that had not been removed.

Clearly having the database clean up datafiles automatically is a really useful feature, and this becomes doubly so in the case of a dataguard environment. Certainly, I think it is a good idea to drop a tablespace with the including contents and datafiles clause.

Determining Dataguard Standby Apply Rate

It can be very useful to see how your standby database is performing, whether your infrastructure has the capacity to keep your standby in synch and how fast it can actually apply the data. In particular if you have decided to save on hardware and licensing costs at your business continuity site, then you may have a lower performing server for your standby than you have at your primary location. If this is the case you really want to see what kind of apply rate you are managing, and how this compares to the amount of redo your primary is generating.

Paul Moen from Pythian wrote about a script he uses to keep a historical record of the apply rate. However if you want something more immediate you can maybe use a view called V$STANDBY_APPLY_SNAPSHOT. There does not appear to be much information out there on this view, and it was only recently that I stumbled across it. This is not documented in the Oracle documentation  in either the 10g or 11g docs. There is also nothing about this view on metalink as a search turned up no hits. The view gets a brief mention in a talk by Dataguard product manager, Larry Carpenter.

Here is a description of the view:

SQL> select * from v$version;

BANNER
----------------------------------------------------------------

Oracle Database 10g Enterprise Edition Release 10.2.0.3.0 - 64bi

PL/SQL Release 10.2.0.3.0 - Production

CORE    10.2.0.3.0      Production

TNS for Linux: Version 10.2.0.3.0 - Production

NLSRTL Version 10.2.0.3.0 - Production

SQL> desc v$standby_apply_snapshot

 Name                              Null?    Type

 --------------------------------- -------- -----------------------------------------------

 SNAPSHOT_TIME                               DATE

 SESSION_ID                                  NUMBER

 THREAD#                                     NUMBER

 RESET_TIMESTAMP                             NUMBER

 SEQUENCE#                                   NUMBER

 BLOCK#                                      NUMBER

 APPLIED_SCN                                 NUMBER

 APPLIED_TIME                                DATE

 NEWEST_RESET_TIMESTAMP                      NUMBER

 NEWEST_ARCHIVED_SEQ#                        NUMBER

 NEWEST_TIME                                 DATE

 NEWEST_USED                                 NUMBER

 NEWEST_SRL_SEQ#                             NUMBER

 BLOCKSIZE                                   NUMBER

 APPLY_RATE                                  NUMBER

This is what I see on my system:

sys@STANDBY> select snapshot_time, thread#, sequence#, applied_scn, applied_time, apply_rate
from V$standby_apply_snapshot;

SNAPSHOT_TIME     THREAD# SEQUENCE# APPLIED_SCN APPLIED_TIME  APPLY_RATE
----------------- ------- --------- ----------- ------------- ----------
27-02-08 15:45:08     1      8684    2549146933 27-02-08 15:44:48  47234
27-02-08 15:45:08     2      7145    2549146847 27-02-08 15:44:49  47234

The advantage of this view is that it’s updated pretty much continually, and you can see from the applied_time how far behind you are in applying. So is my apply rate 47MB per second? I do hope so. Though in Larry’s talk he states the apply rate is in KB/sec which is a little bit fantastic for the numbers I am seeing!

UKOUG RAC & HA Meeting

Today I attended the UKOUG RAC & HA SIG and here are the verbatim notes that I took at the event. I probably should not complain at the journey, but an hour on a packed train for 38 miles seems “extravagant”. Still, probably took one of the speakers longer to arrive from Geneva!

Introduction

Next RAC Sigs, Thursday 15th May, London and Thursday 2nd October, heritage motor centre

Call for papers for UKOUG conference opens on March 17th, This seems astonishingly early!

A Really packed agenda today.

Survey

8 9.2
2 10.1
majority on 10.2
none on 11 - yet

few itanium
srpinkling of solaris sparc
probably majority on linux 64 bit
another sprinkling of windows

Vast majority with 2 nodes a handful with more than this, including 8 nodes from CERN and someone with 10

Vast majority using SAN for storage a few on NAS.

A lot using ASM, with a handful on ocfs, sprinkling on veritas 1 with polyserve

A lot of people with a physical standby, a few with a logical standby no one using auto failover a handful with stretched clusters.

Hardly anyone using standard editon

Phil Davies - Support update

Whispers of the first patchset for 11g - probably not for ages though. 10.2.0.4 surely coming soon. Interesting problem with ASM hang, and controlfile enqueue problem this is on 10.2.0.3, fixed 10.2.0.4.

On the January 2008 CPU, one audience member, claimed Oracle support stated to them that the cpu was rolling upgradeable. My support analyst definately stated it was not, interesting contradiction. Nominet got a mention, as I have a Documentation bug out for the CPU.

Dave Burnham - Highly available Oracle Databases

High level overview of building higly available databases. Downtime = Time to notice an issue + Time to resolve the problem.

Complexity kils availability, I certainly agree with this, Keep it Simple Stupid really is the way to go - the less moving parts the less that can go wrong. Concept of an availability benchmark system, which is a single server oracle database server - does your infrastructure improve on this config? That is the high availability solution is the modern comodity system which can have many hot swappable and redundant parts- not fancy clustering solutions.

However, several things are not protected by the single server solution, host failure, site failure, and of course the number one cause of reduced availability is human error.

One alternative to running RAC is to use a single instance database with clustering solution from veritas (like VCS), or SUN, or any of the other hardware vendors. Basically on failure, the clustering solution will restart Oracle on a different node. No expensive RAC license, and it’s fairly well understood technology.

Dave has lots of experience of stretched RAC clusters but states they are quite complex, and that dataguard is far simpler, though perhaps was still prefering stretched RAC for HA.

Miguel Anjo - Multiple RAC clusters

Running around 20 RAC clusters, 2-8 nodes.

Oracle Home is same everywhere, they deploy the ORACLE_HOME as an image.

3 stage environment
development: 8/5
integration: 8/5
Production 24/7

Custom built gui - browser based, to allow developers to see what is happening to their sessions, including sql, DML & DDL and ability to kill their session.

They have a 2 node clustered server for monitoring (runs single instance oracle). The have auditing turned on and generate weekly/monthly reports. Custom written monitoring, based on python, bash, xml.

1 RAC cluster per physics experiment.

They use a wiki for a logbook, database procedures.

Martin Bach - Lessons Learned from Migrating 10.2.0.2 to 10.2.0.3

This talk was based on using Standard Edition. They not only upgraded release but also migrated hardware, old hardware single core cpu with 3GB memory, run queue sometimes exceeding 12. new hardware 2 x dual core opteron and an upgraded SAN.

They have NO RAC test environment - scary stuff! Oh they have no device naming persistance - no ASMLIB or udev. They encountered some wacky bugs with SUSE and OEM. dbms_scheduler failing to schedule jobs to run on time, running by 5-45 minutes.

ASM 11g Experience in Extended Cluster - Bernhard de Cock Buning

Seems to be running RDBMS at 9i with Clusterware and ASM instance at 10.2.0.3 considering upgrading Clusterware and ASM to 11g. RDBMS moving to 10. They can’t use the ASM_PREFERED_READ_FAILURE_GROUP as the RDBMS was not 11. ASM Sysasm user - separate user to own ASM home, not required in 11gR1 but is required in 11gR2. Audience member stated they saw x2 increase in rebalance performance in 11g compared to 10g. Possibility to perform rolling ASM upgrade with 11g.

Simulating one site failure, 10g continued uninterrupted but 11g generated an ORA-600[kfdOffline01]. Seems like ASM rebooted on the surviving site. They used swingbench for testing load and had node crashes a couple of times, but once they were using Hugepages they had NO node crashes. It’s an interesting idea run 11g ASM with 10g database instance.

Split Mirror Backups with RAC & ASM - Howard Jones

General consensus is that it’s costly - requiring high end storage and complex. Using Symantec SMB integrating with Netbackup.

Using Dataguard for hardware migration - Miguel Anjo

Cern Using oracle streams to send LHC data around the world. Uses rman duplicate target database for standby for creation of standby. they switchover to the standby and upgrade this, only using the (now old) primary should they encounter a failure.

I don’t get it really, perhaps it was still too close to lunch for me to understand fully: why they don’t upgrade the primary saving failing over, but using a dataguard standby for the protection it offers should something go wrong? The CERN mechanism still encounters downtime, seems like they do some of the upgrade before the failover and reduce the outage, but for example a 10.2.0.2 to 10.2.0.3 upgrade you can install in a new ORACLE_HOME and you still need the outage for the catupgrd scropt? if you are out there CERN guys, what am I missing?

Logical Standby in the real time world - Graham Cameron

Old system single instance running on service guard cluster queries were hurting performance, chose physical and logical

small db only 22gb, 2GB/s of logs per day running Oracle 9.2.0.8, running the physical and logical on same server, creating server in 9.2.0.8 required the database to be quiesced. They still had major issues with their logical standby and found it failing on many occasions, interestingly they are using oracle streams far more successfully on a different project.

Still, a cracking day and thoroughly enjoyable.

Protecting Oracle Redo Transport part II

There was originally not going to be a second part to protecting your redo transport, but a comment on the original article has prompted me to go back and show what differences occur at the network level when you start using an ssh tunnel. So first up this is what you see when you are using an unencrypted transport mechanism (click to able to read it):

linuxrac1sb is the primary in the above, while linuxrac1 is the standby. Two things to point out from the non-encrypted transport, the originating port on the primary is not being allocated constantly, it is changing, but the destination port on the standby is always 1521 which is where this listener is listening on.

Now we setup the ssh tunnel:

ssh -N -L 3333:linuxrac1:1521 oracle@linuxrac1

The tcpdump of the encrypted case looks like:

So the data is always sent to the ssh port on the standby and you’ll also see the originating port is always constant and this is the established ssh tunnel connection:

[jason@linuxrac1sb ~]$ ps -ef|grep 3333
oracle 7144 8499 0 12:58 pts/2 00:00:00 ssh -N –L 3333:linuxrac1:1521 oracle@linuxrac1

[jason@linuxrac1sb ~]$ sudo lsof -p 7144

ssh 7144 oracle 3u IPv4 326890656 TCP linuxrac1sb:45993 >linuxrac1.nominet.org.uk:ssh (ESTABLISHED)
ssh 7144 oracle 4u IPv4 326890667 TCP localhost.localdomain:3333 (LISTEN)
(NOTE: above lsof has been snipped for brevity).

So this shows that as expected we are listening locally on port 3333 but that we have been randomly allocated port 45993 to connect to the standby. The tcpdump shows all communication to the standby originates from this port and goes to the ssh port of the standby. All the redo traffic that is sent from the primary is using the tunnel and is therefore encrypted, unlike the non-encrypted case I do not see any data in the redo traffic - it is all garbled.

Protecting Oracle Redo Transport

You can pay additional license payments to Oracle and have the Advanced Security Option take care of securing your Redo transport between your primary and your standby databases. However, alternatively, you could save yourself a good amount of license fees by using the open source OpenSSH to encrypt your redo traffic and use simple ssh port-forwarding.

Be aware that if you do not encrypt your redo transport then it is possible for your data to be read as it is sent over the wire. I looked at a tcpdump of the unencrypted traffic while I performed a simple update, and you can see both the original value and the updated value of the data. You really do not want to be sending this stuff if you have any sensitive data, but you can protect yourself easily.

First generate a public/private key pair for the oracle user:

oracle$ ssh-keygen -b 2048 -t dsa

Chose an empty passphrase when prompted.

Copy the public/private key to the standby server (you need a connection going in both directions, FAL is pull).

create your ssh tunnel:

oracle$ ssh -N -L 3333:remote-server:1521 oracle@standby-host

So port 3333 (you can choose your favourite number above 1024, that does not clash with some other service) is on the server that orginated the ssh tunnel, remote-server is the one you are connecting to (remember you want a tunnel going primary -> standby & standby -> primary) and 1521 is everyone’s favourite Oracle listener port. The -N flag means do not execute a remote command, while the -L specifies the localport:remotehost:remoteport that you want to use.

Now you create tns entries on primary and standby to use the port-forwarded connection:

STANDBY =
(DESCRIPTION =
(ADDRESS_LIST =
(ADDRESS = (PROTOCOL = TCP)(HOST = localhost)(PORT = 3333))
)
(CONNECT_DATA =
(SERVICE_NAME = STANDBY)
)

You now use this tns entry in your LOG_ARCHIVE_DEST parameter to direct your redo to the standby. Once this is done, no one can read your redo transport stream.

This also saves you having to open a hole in any firewalls to allow traffic on port 1521, as the traffic goes over port 22. I have used this trick not only for securing dataguard communications, but also for securing remote database logons for applications. I have seen no performance impact to this and to me it seems a whole lot simpler than the Advanced Security Option.

Standby Redo Logs

Of course, Standby Redo Logs are obligatory if you are using a protection level of Maximum Protection or Maximum Availability, but I think any dba who is even using a dataguard configuration with a protection level of maximum performance would be nuts to not use Standby Redo Logs (SRLs). If it’s all about protecting the data, then basically you will lose less data in the event of having to perform a failover if your configuration has SRLs. When you throw into the mix the ability to send the redo via LGWR you can set up your dataguard environment to provide a high degree of data protection with an absolutely minimal impact on your primary database. When you are using SRLs, the LGWR process on the primary talks to the RFS process on the standby which is responsible for writing the redo information to disk, and it’s therefore the RFS process which writes the information to the SRLs.

Sure, if you need an absolute guarantee of NO data loss then maximum performance may not be the acceptable mode for your organisation, but if you can live with a small window of data loss then maximum performance combined with LGWR transmission and SRLs may be the sweet spot for you. On a 10.2 system running LGWR ASYNC with a Round Trip Time (RTT) of around 15ms between primary and standby sites, I typically see a redo transport lag of a handful of seconds. You also can only use the real time apply mode if you are using SRLs, and this may (or may not) be an added benefit for you.

The syntax for creating your SRLs is very similar to that for creating the online redo logs:

sql> alter database add standby logfile thread 1 group 42 ‘/path/to/logfile’ size 512M;

To delete them:

sql> alter database drop standby logfile group 42;

You can find out information on how the SRLs are configured on your system by looking at the V$logfile or the V$standby_log views.