ORA-16401: archivelog rejected by RFS

How big is your list of "known" issues for systems that you support?

How many of them are related to bugs in Oracle
and what portion is the "expected" behaviour that covered
by existing technical/business requirements and processes?

How often do you revise the list to check of the "known" issues
can be fixed and removed from the "list"?

Every time when new job is taken first months are spent just to get
understanding what are the "known" issues/problems, how to react to them,
whom to call, what to write, etc. And since you are the new one here
you would like to show how cool and smart you are, you are trying to
fix the issues suggesting different approaches, methods. And when
time comes to do changes - you stuck with existing environment
and your strength is going away little by little and your list of "known" issues
is growing as well :(

How is the said before related to the error that is in the subject.
Well based on a description it can be ignored and there is nothing bad
to add it to ignore list or to the list of "known" issues.
Will be anything missed and hidden under that error? Who knows :)

In this case the error had periodic occurrence and after some checking
on primary side I found out that crontab job was doing backup of archive
log files at the same time time every hour and archive_lag_target was set
to 1800 (30 mins). So every second log file switch initiated by the parameter
coincided with switch initiated by RMAN backup command.

Difference of several seconds in log switches was too much for RFS to handle
quickly and was reported in alert log.

Tue Feb 24 00:05:02 2009
Primary database is in MAXIMUM PERFORMANCE mode
kcrrvslf: active RFS archival for log 1 thread 1 sequence 1117
RFS[12]: Successfully opened standby log 5: '+DATA/test/onlinelog/group_5.272.677123691'
Tue Feb 24 00:05:02 2009
Redo Shipping Client Connected as PUBLIC
-- Connected User is Valid
RFS[21]: Assigned to RFS process 27094
RFS[21]: Identified database type as 'physical standby'
Primary database is in MAXIMUM PERFORMANCE mode
kcrrvslf: active RFS archival for log 2 thread 1 sequence 1118
RFS[12]: Successfully opened standby log 4: '+DATA/test/onlinelog/group_4.273.677123691'
Errors in file /u01/app/oracle/diag/rdbms/testb/TEST/trace/TEST_rfs_27094.trc:
ORA-16401: archivelog rejected by RFS


Finally I changed archive_lag_target to 2400 (40 mins)
and it helped to avoid consecutive log switches within seconds.

No errors so far in alert log and I believe that "known" issue
will be removed from the list soon.

Have a good day!

oracle recommended bundle patches

Every time when new oracle home is installed there is a wish
to apply latest patches and also some other patches to avoid
as much as possible problems/errors in the future.
I was installing new 10.2.0.4 oracle home recently and while
checking Metalink I found "bundle patches" for CRS, RAC
and for a database in general:

10.2.0.4 RAC RECOMMENDED BUNDLE #2
10..2.0.4 CRS BUNDLE2 TRACKING BUG
10.2.0.4 GENERIC RECOMMENDED BUNDLE# 3.

It is also worth doing to check bugs that appeared after the patchset
as for 10.2.0.4

10.2.0.4 Patch Set - Availability and Known Issues


Have a good day!

splitting table partitions with BLOB in streams

The last hours of the last day of the last year I spent trying to get
capture process of streams working.

Developers executed the script that prepared application tables
for new year splitting and rebuilding indexes on them.

After that capture process was aborted due to
ORA-04031 for streams pool.

The setting for stream_pool_size was 384M only but increase of
the value up to 1, 2 even 5Gb did not help either.

Capture was failing with the errors:

ORA-04031: unable to allocate ... bytes of shared memory ("streams pool","unknown object","streams pool","kol raw")
ORA-04031: unable to allocate ... bytes of shared memory ("streams pool","unknown object","streams pool","sob_kgqmrec")
ORA-04031: unable to allocate ... bytes of shared memory ("streams pool","unknown object","streams pool","kolccst obj")
ORA-04031: unable to allocate ... bytes of shared memory ("streams pool","unknown object","streams pool","sob_kgqmrec")


After research on Metalink one interesting note had been found:

STREAMS CAPTURE ERRORS OUT WITH ORA-4031 ON SPLIT PARTITION COMMAND

which exactly describes the problem that we have.
But they were able to go through all transactions for capture process
only when streams_pool_size was increased up to 16Gb!
Unfortunately there is no chance for now to allocate
so much memory for streams and there is no patch for it yet.

Might be upgrade (from 10.2.0.4) to 11g will help,
might be additional memory will be found
or Metalink will come with some ideas, will see...

Have a good day!

orapwd and standby in 11g

I was trying to build standby for Oracle 11g database to test new
features of Data Guard and stuck with problem that archive logs had
not been transferred to standby side because of the following error:

Error 1017 received logging on to the standby
------------------------------------------------------------
Check that the primary and standby are using a password file
and remote_login_passwordfile is set to SHARED or EXCLUSIVE,
and that the SYS password is same in the password files.
      returning error ORA-16191
------------------------------------------------------------

The password files have been created on both sides using orapwd:
orapwd file=orapwdb11 password=sys
and remote_login_passwordfile parameters were set to EXCLUSIVE.
And I was able to login as sysdba to remote sites using either TNS or
easy naming methods.

After different attempts I recreated password files with password
in upper-case (thinking about case sensitivity for password in 11g):
orapwd file=orapwdb11 password=SYS force=y
and it worked - primary started to send logs to standby.

Trying to find the reason of such behavior I recognized that there is
the parameter that responsible for password sensitivity in 11g -
SEC_CASE_SENSITIVE_LOGON.
I set it to FALSE, changed passwords to lower-case, bounced databases
and... the same problem as before :(

That meant the parameter does not influence on case sensitivity of
password during sysdba connection.

And only after that case I found out that there is a new parameter for
orapwd utility - ignorecase

Usage: orapwd file= password= entries= force= ignorecase= nosysdba=

  where
    file - name of password file (required),
    password - password for SYS (optional),
    entries - maximum number of distinct DBA (required),
    force - whether to overwrite existing file (optional),
    ignorecase - passwords are case-insensitive (optional),
    nosysdba - whether to shut out the SYSDBA logon (optional Database Vault only).

I changed SEC_CASE_SENSITIVE_LOGON back to TRUE,
recreated password file with lower-case characters and ignorecase=y,
bounced databases and everything went smoothly!

Have a good day!

switching $ORACLE_BASE using oraenv in 11g

I recently installed a couple of Oracle 11g on VM. First one was installed
to /u01 but after testing different things I added one more to /u05.
But it does not really matter, the main thing that 11g raised importance
of $ORACLE_BASE variable added it to different places - oraenv script
(you have noticed sentence about oracle base after execution of the script)
and as parameter to init file.

All that means the $ORACLE_BASE should be dependent on
ORACLE_HOME and be saved somewhere. Moreover the script should
change it! But it was not so. Everytime I ran it $ORACLE_BASE left the
same even they based on the same path as $ORACLE_HOME:

[oracle@oel1 bin]$ . oraenv
ORACLE_SID = [db11106] ?
The Oracle base for ORACLE_HOME=/u01/app/oracle/product/11.1.0/db_1 is /u05/app/oracle
[oracle@oel1 bin]$ . oraenv
ORACLE_SID = [db11106] ? db11a
The Oracle base for ORACLE_HOME=/u05/app/oracle/product/11.1.0/db_2 is /u05/app/oracle
[oracle@oel1 bin]$ . oraenv
ORACLE_SID = [db11a] ? db11106
The Oracle base for ORACLE_HOME=/u01/app/oracle/product/11.1.0/db_1 is /u05/app/oracle

Checking the script I found the part that responsible for
oracle base change and comments there:


# Set the value of ORACLE_BASE in the environment. Use the orabase
# executable from the corresponding ORACLE_HOME, since the ORACLE_BASE
# of different ORACLE_HOMEs can be different.
# The return value of orabase will be determined based on the following :
#
# 1. Value of ORACLE_BASE in the environment.
# 2. Get the value of ORACLE_BASE from oraclehomeproperties.xml as
# set in the ORACLE_HOME inventory.



Going further I found that oraclehomeproperties.xml is under
$ORACLE_HOME/inventory/ContentsXML and it contains properties
and one of them is:

...
property name="ORACLE_BASE" val="/u05/app/oracle"
...

(/u01/app/oracle was for the other oracle home)

That's the place where $ORACLE_BASE and $ORACLE_HOME variable
are put together. But the script doesn't switch base if it was already set.
And the reason of it - orabase script ($ORACLE_HOME/bin).
If you have $ORACLE_BASE value set - orabase returns this value.
If not - it gets value from oraclehomeproperties.xml file:

[oracle@oel1 bin]$ . oraenv
-- switched to another home and got wrong $ORACLE_BASE
ORACLE_SID = [db11a] ? db11106
The Oracle base for ORACLE_HOME=/u01/app/oracle/product/11.1.0/db_1 is /u05/app/oracle
-- wrong value
[oracle@oel1 bin]$ echo $ORACLE_BASE
/u05/app/oracle
-- orabase returns wrong value
[oracle@oel1 bin]$ which orabase
/u01/app/oracle/product/11.1.0/db_1/bin/orabase
[oracle@oel1 bin]$ orabase
/u05/app/oracle
-- unset $ORACLE_BASE
[oracle@oel1 bin]$ export ORACLE_BASE=
[oracle@oel1 bin]$ echo $ORACLE_BASE

-- and now orabase returns right value
[oracle@oel1 bin]$ orabase
/u01/app/oracle

Finally I added the "export ORACLE_BASE=" entry before
"ORABASE_EXEC=$ORACLE_HOME/bin/orabase" to null the value that
orabase could accomodated the real value of $ORACLE_BASE variable.

[oracle@oel1 bin]$ vi /u01/app/oracle/product/11.1.0/db_1/bin/oraenv
[oracle@oel1 bin]$ vi /u05/app/oracle/product/11.1.0/db_2/bin/oraenv
[oracle@oel1 bin]$ . oraenv
ORACLE_SID = [db11106] ?
The Oracle base for ORACLE_HOME=/u01/app/oracle/product/11.1.0/db_1 is /u01/app/oracle
[oracle@oel1 bin]$ . oraenv
ORACLE_SID = [db11106] ? db11a
The Oracle base for ORACLE_HOME=/u05/app/oracle/product/11.1.0/db_2 is /u05/app/oracle

Have a good day!

adrci and Data Guard logs

I made an installation of Oracle 11g recently and had started to set up
Data Guard when got some errors during configuration. Since the new
version of databases came with Automatic Diagnostic Repository (ADR)
I thought it might be useful and interesting to check if adrci can
provide some view of not only alert log but Data Guard log files as well.

Unfortunately I did not find such possibility but at least dr...log file
can be added to an incident package if it is generated.

I hope in future releases ADR will integrate Data Guard logs as well.

Have a good day!

"ORA-10388: parallel query server interrupt" for streams process

It is almost a week of battle between streams process and us who support it.
It failed on weekend (as usual) with bunch of errors:

Errors in file /u01/oracle/admin/PROD/bdump/prod01_p001_21536.trc:
ORA-00600: internal error code, arguments: [kgh_heap_sizes:ds], [0x2A9808E358], [], [], [], [], [], []
ORA-00600: internal error code, arguments: [kgh_heap_sizes:ds], [0x2A9808E358], [], [], [], [], [], []
ORA-00600: internal error code, arguments: [kgh_heap_sizes:ds], [0x2A9808E358], [], [], [], [], [], []
ORA-00600: internal error code, arguments: [kghGetHpSz1], [0x2A9808E368], [], [], [], [], [], []
ORA-00600: internal error code, arguments: [kgh_heap_sizes:ds], [0x2A9808E358], [], [], [], [], [], []
ORA-07445: exception encountered: core dump [kghalf()+561] [SIGSEGV] [Address not mapped to object] [0xFFFFFFFFFFFFFFF0] [] []
...
ORA-01438: value larger than specified precision allowed for this column
...
ORA-10388: parallel query server interrupt (failure)


Restart of apply processes did not help neither bouncing a database.

After creation of Metalink SR and during substitution of tables in streams
with materialized views two patches were applied
(10.2.0.4 on Linux 64-bit):
7272297
"ORA-00600 [17114] OR ORA-600[17125] - INSTANCE TERMINATION"
and 5868257
"MALFORMED RCI MARKER REDO DUE TO ORA-1551 IN UPDATE DRIVER"
but only the last one helped to avoid the issue and recovered streams
process as it was before.

Streams process failed on updates not for all tables but for some of them
which have many columns with names up to maximum length allowed.

So if you have such tables and plan to add them to streams I would
recommend to check the availability of the patch 5868257 for your database.

Have a good day!