mardi 19 octobre 2010

Transaction recovery: lock conflict caught and ignored

Je viens de rencontrer un problème chez l'un de nos clients.

Il s'agit d'une base de données RAC 11.2.0.1 à trois (3) noeuds en environnement Oracle Solaris SPARC 64-bit.

Sur l'un des noeuds, le fichier $DIAG_HOME/diag/rdbms/<db_name>/<instance_name>/trace/alert_INSTANCE.log (ancien format du fichier alert de l'instance 2) contient la ligne suivante à répétition:

...
Transaction recovery: lock conflict caught and ignored
Transaction recovery: lock conflict caught and ignored
Transaction recovery: lock conflict caught and ignored
...

Il faut souligner que les 2 autres instances n'ont pas ce message dans leur fichier alert.

En conséquence, la base de données génère un nombre excessif d'archives.

Je me suis rendu compte qu'il y avait plusieurs enregistrements dans la vue GV$FAST_START_TRANSACTIONS (GV$ car en rac, enlever le G pour avoir juste l'info pour l'instance sur laquelle l'on est connecté), ce qui voudrait dire qu'il existe des transactions qui sont en train d'être recouvrées.

select * from GV$FAST_START_TRANSACTIONS;

INST_ID USN SLT SEQ STATE UNDOBLOCKSDONE UNDOBLOCKSTOTAL PID CPUTIME PARENTUSN PARENTSLT PARENTSEQ XID PXID RCVSERVERS
---------- ---------- ---------- ---------- ---------------- -------------- --------------- ---------- ---------- ---------- ---------- ---------- ---------------- ---------------- ----------
3 23 15 242931 RECOVERING 0 110 248184 0017000F0003B4F3 0
3 2 30 217700 RECOVERING 0 109 248184 0002001E00035264 0
3 25 8 228906 RECOVERING 0 110 248184 0019000800037E2A 0
2 23 15 242931 RECOVERING 0 110 248183 0017000F0003B4F3 0
2 2 30 217700 RECOVERING 0 109 248183 0002001E00035264 0
2 25 8 228906 RECOVERING 0 110 248183 0019000800037E2A 0
2 27 15 434163 RECOVERING 0 110 248183 001B000F00069FF3 0

7 ligne(s) sÚlectionnÚe(s).

La requête précédente montre que 4 segments d'undo sont concernés par ce problème: Il s'agit des segments 2, 23, 25 et 27:

_SYSSMU2_4041828287$ (2)
_SYSSMU23_314669895$ (23)
_SYSSMU25_528020860$ (25)
_SYSSMU27_3428318680$ (27)

Une interrogation de la table x$ktuxe donne le résultat suivant:

SYS@E1002> select sum(distinct(ktuxesiz)) from x$ktuxe where ktuxecfl = 'DEAD';

SUM(DISTINCT(KTUXESIZ))
-----------------------
18

SYS@E1002>

Pour une recherche plus approfondie, les informations suivantes ont été transférées à Oracle Support:

Juste un extrait des échanges...

a) show the following output in order to confirm the undo segments as involved (2,23,25,27):
SQL>
connect / as sysdba
set pagesize 9999
set nls_date_format='dd-mon-yyyy hh24:mi:ss';

spool /tmp/dba_rollback_segs.html
set markup html on
select * from dba_rollback_segs order by segment_id;
spool off

==> upload /tmp/dba_rollback_segs.html

b) provide a segment header dump for the undo segments 2 + 23 + 25 + 27:
(Note.249814.1 How to Obtain a Segment Header Dump)
SQL>
connect / as sysdba
alter session set tracefile_identifier='undo_segment_header_dump';
alter system dump undo header '&name_of_undo_segment';
...

==> upload /diag/rdbms/<db_name>/<instance_name>/trace/*undo_segment_header_dump*.trc

c) show the following output in order to exclude distributed TX's being the cause:
connect / as sysdba
set pagesize 9999
alter session set nls_date_format='dd-mon-yyyy hh24:mi:ss';

spool /tmp/dba_2pc_pending.html
set markup html on
select * from dba_2pc_pending;
spool off

==> upload /tmp/dba_2pc_pending.html

d) show the following output from v$transaction:

connect / as sysdba
set pagesize 9999
alter session set nls_date_format='dd-mon-yyyy hh24:mi:ss';

spool /tmp/transaction.html
set markup html on
select * from v$transaction order by xidusn,xidslot;
spool off

==> upload /tmp/transaction.html

Par la suite, un dump des transactions (XID) a été transféré à Oracle Support:

1) show that these transactions do consist of:

SQL>
connect / as sysdba
alter session set max_dump_file_size=unlimited;
alter session set tracefile_identifier='dump_xids';

alter system dump undo block '_SYSSMU2_4041828287$' xid 2 30 217700;
alter system dump undo block '_SYSSMU23_314669895$' xid 23 15 242931;
alter system dump undo block '_SYSSMU25_528020860$' xid 25 8 228906;
alter system dump undo block '_SYSSMU27_3428318680$' xid 27 15 434163;

==> upload /diag/rdbms/<db_name>/<instance_name>/trace/*dump_xids*trc

Puis...

1) in order to know what the transactions consist off and if there are common objects involved we need to dump the transactions as following:

SQL>
connect / as sysdba
alter session set max_dump_file_size=unlimited;
alter session set tracefile_identifier='dump_xid';

alter system dump undo block '_SYSSMU2_4041828287$' xid 2 30 217700;
alter system dump undo block '_SYSSMU23_314669895$' xid 23 15 242931;
alter system dump undo block '_SYSSMU25_528020860$' xid 25 8 228906;
alter system dump undo block '_SYSSMU27_3428318680$' xid 27 15 434163;

==> upload /diag/rdbms/<db_name>/<instance_name>/trace/*dump_xid*trc

Le dump précédent a révélé les OBJECT_ID des tables pour lesquelles il y avait un problème de recouvrement.
Ces tables ont été recrées pour que leurs OBJECT_ID changent de sorte à ce que les transactions à problème soient ignorées. On peut les recréer d'une des manières suivantes:
(exp/drop/imp ou CTAS/truncate/insert).

Après avoir recréé les tables à problème, la fréquence de génération des archives a diminué pour redevenir presque normale mais les transactions sont toujours restées dans la vue GV$FAST_START_TRANSACTIONS.

Oracle Support a finalement proposé d'appliquer le patch qui corrige le bug 9489626. Il s'agit du même patch que celui qui corrige le bug 9857702.
C'est le Patch 9857702 (dans mon cas, il s'agit d'un environnement Sun Solaris SPARC 64-bit).

Voir ORA-600 [4464] in a RAC Environment with Supplemental Logging Enabled [ID 1228295.1]

Je n'ai pas encore eu le temps de l'appliquer pour voir si ça corrige effectivement le problème, mais j'aurai l'occasion de revenir mettre à jour l'information.

Profile par défaut dans une base de données 11gR2

Les changements ci-dessous ont été apportées à la base de données 11gR2 comparativement à la base de données 10g concernant le profile par défaut (en rouge):

SQL> select resource_name,limit from dba_profiles where profile='DEFAULT';
RESOURCE_NAME LIMIT
-------------------------------- ----------------------------------------
COMPOSITE_LIMIT UNLIMITED
SESSIONS_PER_USER UNLIMITED
CPU_PER_SESSION UNLIMITED
CPU_PER_CALL UNLIMITED
LOGICAL_READS_PER_SESSION UNLIMITED
LOGICAL_READS_PER_CALL UNLIMITED
IDLE_TIME UNLIMITED
CONNECT_TIME UNLIMITED
PRIVATE_SGA UNLIMITED
FAILED_LOGIN_ATTEMPTS 10
PASSWORD_LIFE_TIME 180
RESOURCE_NAME LIMIT
-------------------------------- ----------------------------------------
PASSWORD_REUSE_TIME UNLIMITED
PASSWORD_REUSE_MAX UNLIMITED
PASSWORD_VERIFY_FUNCTION NULL
PASSWORD_LOCK_TIME 1
PASSWORD_GRACE_TIME 7
16 rows selected.
SQL>

Note:

PASSWORD_LIFE_TIME: Temps de validité d'un mot de passe
PASSWORD_LOCK_TIME: Temps pendant lequel le compte doit être verrouillé après avoir atteint le nombre maximal de tentatives infructueuses de connexion.
PASSWORD_GRACE_TIME: Temps de grace accordé après que le temps de validité du mot de passe soit atteint.

Au cas où l’on voudrait modifier ce comportement:

Exemple:

ALTER PROFILE DEFAULT limit PASSWORD_LIFE_TIME UNLIMITED;
ALTER PROFILE DEFAULT limit PASSWORD_LOCK_TIME UNLIMITED;
ALTER PROFILE DEFAULT limit PASSWORD_GRACE_TIME UNLIMITED;

Il faut savoir que lorsque la valeur du PASSWORD_LIFE_TIME est 180, la date d'expiration du mot de passe de chaque utilisateur est mentionné dans la colonne EXPIRY_DATE de la vue DBA_USERS.
Une fois la commande «ALTER PROFILE DEFAULT limit PASSWORD_LIFE_TIME UNLIMITED» exécutée, cette colonne prend la valeur NULLE pour les utilisateurs dont le mot de passe n'a pas encore expiré (colonne account_status OPEN). Cette commande n'a aucun impact sur les utilisateurs dont le mot de passe a déjà expiré (colonne account_status EXPIRED ou EXPIRED & LOCKED).

mercredi 6 octobre 2010

Patch 124861-15 manquant lors de l'installation d'oracle 11gR2

Lorsque vous installez oracle 11gR2 en environnement Unix Solaris 64-bit, vous serez confrontés au prérequis qui dit que le patch 124861-15 est manquant.

This is a prerequisite condition to test whether the patch "124861-15" is available on the system. (more details)
Expected Value:Patch 124861-15
Actual Value:Patch missing


Dans le fichier log de l'installation, vous verrez un message du genre:

INFO: *********************************************
INFO: OS Patch:124861-15: This is a prerequisite condition to test whether the patch "124861-15" is available on the system.
INFO: Severity:IGNORABLE
INFO: OverallStatus:VERIFICATION_FAILED
INFO: -----------------------------------------------


Il faut savoir que ce patch n'est indispensable que lorsque vous avez l'intention d'installer Proc*C Precompiler. Dans ce cas il faut faire installer Sun Studio 12 et le patch 124861-15 par votre admin unix.

Sinon, si vous n'avez pas l'intention d'installer le Proc*C Precompiler, vous pouvez ignorer ce prérequis et cocher «Ignore All» pour continuer votre installation.

Document sur le sujet:
During An 11gR2 (11.2) Installation On Solaris, OUI Performs A Prerequisite Check For The Optional Patch 124861-15 And Fails If It Is Not Installed [ID 969497.1]

Prérequis Solaris 10 Update 6 pour l'installation d'oracle 11gR2

Lorsque vous installez un produit Oracle 11gR2 en environnement Unix Solaris, l'un des prérequis est d'avoir au moins «Solaris 10 update 6 (5.10-2008.10)».
Il arrive qu'on se demande comment obtenir la version de l'OS sous le format 5.10-2008.10?

En tout cas, moi je me suis posé cette question car je recevais le message suivant dans le fichier log de l'installation:

This is a prerequisite to test whether the system kernel version is at least “5.10-2008.10“
Expected Value: 5.10-2008.10
Actual Value: 5.10-2006.11.14.15.02

Selon mon admin Unix, le 5.10-2006.11.14.15.02 correspond à Solaris 10 update 5 + patches, ce qui équivaudrait à Solaris 10 update 7, donc ça devrait fonctionner, mais hélàs non.

Voir Note FAQ - 11gR2 requires Solaris 10 update 6 or greater [ID 971464.1] pour plus de détails à ce sujet.

J'ai donc fini par régler le problème en demandant à l'admin unix d'installer une version supportée par Oracle 11gR2.

Si vous vous posez la question de savoir comment obtenir la version de l'OS sous le format 5.10-2008.10, utilisez la commande suivante:

/usr/bin/pkginfo -l SUNWsolnm | /usr/bin/nawk -F = '/VERSION/ {"/usr/bin/uname -r" | getline uname; print uname "-" $2}' | cut -c1-12

Exemple:

oracle@juliet:/juliet_u01/home/dba/oracle> /usr/bin/pkginfo -l SUNWsolnm | /usr/bin/nawk -F = '/VERSION/ {"/usr/bin/uname -r" | getline uname; print uname "-" $2}' | cut -c1-12
5.10-2009.09
oracle@juliet:/juliet_u01/home/dba/oracle> /usr/bin/pkginfo -l SUNWsolnm | /usr/bin/nawk -F= '/VERSION/ {"/usr/bin/uname -r" | getline uname; print uname "-" $2}'
5.10-2009.09.16.15.47
oracle@juliet:/juliet_u01/home/dba/oracle>

Documents sur le sujet:
Requirements for Installing Oracle 11gR2 RDBMS on Solaris 10 SPARC [ID 964976.1]
FAQ - 11gR2 requires Solaris 10 update 6 or greater [ID 971464.1]

oracle.sysman.emSDK.emd.comm.NoSuchTargetException: No Such Type en ajoutant une base de données au Grid Control 10.2.0.5

Vous essayez d'ajouter une base de données à l'OEM grid control 10.2.0.5 et vous recevez le message d'erreur:
oracle.sysman.emSDK.emd.comm.NoSuchTargetException: No Such Type

Un coup d'oeil dans le fichier $OMS_HOME/sysman/log/emoms.log montre l'erreur:

2010-10-01 13:19:15,039 [Thread-182] ERROR perf.sitemap initialize.905 - Exception: error while getting target info
2010-10-01 13:19:15,041 [Thread-182] ERROR perf.sitemap initialize.906 - oracle.sysman.emSDK.emd.comm.NoSuchTargetException: No Such Type
oracle.sysman.emSDK.emd.comm.NoSuchTargetException: No Such Type
at sun.reflect.GeneratedConstructorAccessor81.newInstance(Unknown Source)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
at java.lang.reflect.Constructor.newInstance(Constructor.java:274)
at java.lang.Class.newInstance0(Class.java:308)
at java.lang.Class.newInstance(Class.java:261)
at oracle.sysman.emSDK.xml.DelegatingHandler.getObjForTag(DelegatingHandler.java:121)
at oracle.sysman.emSDK.xml.DelegatingHandler.startElement(DelegatingHandler.java:170)
at org.xml.sax.helpers.ParserAdapter.startElement(ParserAdapter.java:597)
at oracle.xml.parser.v2.XMLContentHandler.startElement(XMLContentHandler.java:180)
at oracle.xml.parser.v2.NonValidatingParser.parseElement(NonValidatingParser.java:1227)
at oracle.xml.parser.v2.NonValidatingParser.parseRootElement(NonValidatingParser.java:314)
at oracle.xml.parser.v2.NonValidatingParser.parseDocument(NonValidatingParser.java:281)
at oracle.xml.parser.v2.XMLParser.parse(XMLParser.java:195)
at org.xml.sax.helpers.ParserAdapter.parse(ParserAdapter.java:431)
at oracle.sysman.emSDK.xml.DelegatingHandler.parseObj(DelegatingHandler.java:296)
at oracle.sysman.emSDK.emd.comm.EMDClient.parseStreamResponseContents(EMDClient.java:2883)
at oracle.sysman.emSDK.emd.comm.EMDClient.parseResponseStream(EMDClient.java:2805)
at oracle.sysman.emSDK.emd.comm.EMDClient.getResponseForRequest_(EMDClient.java:2516)
at oracle.sysman.emSDK.emd.comm.EMDClient.getResponseForRequest_(EMDClient.java:2450)
at oracle.sysman.emSDK.emd.comm.EMDClient.getResponseForRequest(EMDClient.java:2367)
at oracle.sysman.emSDK.emd.comm.EMDClient.getResponseForRequest(EMDClient.java:2352)
at oracle.sysman.emSDK.emd.comm.EMDClient.getTargetMetadata(EMDClient.java:952)
at oracle.sysman.emSDK.emd.comm.EMDClient.getTargetMetadata(EMDClient.java:961)
at oracle.sysman.db.conf.DBConfigListUI.initialize(DBConfigListUI.java:893)
at oracle.sysman.db.conf.DBConfigListUI.doDiscovery(DBConfigListUI.java:417)
at oracle.sysman.db.conf.DBConfigListUI.doDiscovery(DBConfigListUI.java:378)
at oracle.sysman.db.conf.DBConfigController$DiscoveryThread.run(DBConfigController.java:2937)
at java.lang.Thread.run(Thread.java:534)

Un coup d'oeil dans le fichier $AGENT_HOME/sysman/log/emagent.log montre l'erreur:

2010-10-01 13:49:08,731 Thread-1 ORAXML-212, File=file:/uhm004_u01/home/dba/oracle/product/agent10g/sysman/admin/metadata/oracle_database.xml, Line=381, Msg=LPX-00212: comment m
ust not contain "--" (01006)
2010-10-01 13:49:08,731 Thread-1 ORAXML-212, File=./instance.xmlp, Line=9172, Msg=LPX-00212: comment must not contain "--" (01006)
2010-10-01 13:49:08,739 Thread-1 Error parsing /uhm004_u01/home/dba/oracle/product/agent10g/sysman/admin/metadata/oracle_database.xml, this metadata file will be skipped (00508)
2010-10-01 13:49:10,869 Thread-1 [E-Mail POP Server] InstanceProperty (pop_host) is marked OPTIONAL but is being used. Filename /uhm004_u01/home/dba/oracle/product/agent10g/sysm
an/admin/metadata/pop.xml (00506)
2010-10-01 13:49:11,324 Thread-1 [E-Mail SMTP Inbound Server] InstanceProperty (smtp_host) is marked OPTIONAL but is being used. Filename /uhm004_u01/home/dba/oracle/product/age
nt10g/sysman/admin/metadata/smtp_in.xml (00506)
2010-10-01 13:49:11,355 Thread-1 [E-Mail SMTP Outbound Server] InstanceProperty (smtp_host) is marked OPTIONAL but is being used. Filename /uhm004_u01/home/dba/oracle/product/ag
ent10g/sysman/admin/metadata/smtp_out.xml (00506)
2010-10-01 13:49:11,776 Thread-1 ParseError: File=file:/uhm004_u01/home/dba/oracle/product/agent10g/sysman/emd/targets.xml, Line=35, Msg= has invalid target type (01006)
2010-10-01 13:49:12,674 Thread-23 No metadata found or badly formed metadata file (00151)
2010-10-01 13:49:19,922 Thread-1 ParseError: File=file:/uhm004_u01/home/dba/oracle/product/agent10g/sysman/admin/default_collection/oracle_database.xml, Line=6, Msg= TYPE=oracle_database is invalid (01006)

L'erreur précédente (la ligne en gras) montre bien qu'il y a une anomalie dans le fichier $AGENT_HOME/sysman/admin/metadata/instance.xmlp à la ligne 9172 (cette erreur est spécifique à mon cas).
Ce problème a été créé par moi même en appliquant une solution pour régler un autre problème (la syntaxe pour mettre la ligne 9172 en commentaire était erronée).
Après avoir corrigé la syntaxe, plus de problème !

L'objectif de cet article est d'attirer votre attention sur l'importance des fichiers log. En cas de problème, toujours se référer aux logs et faire attention à tout ce qui a été inscrit au moment de l'incident.