Archive

Archive for the ‘TroubleShooting’ Category

ORA-00392: log 1 of thread 1 is being cleared, operation not allowed

January 26, 2016 Leave a comment

Sympton

1. After restoring the backup of database from ASM to filesystem, it showed messages follows when opening the database with restlogs

SQL> alter database open resetlogs;
alter database open resetlogs
*
ERROR at line 1:
ORA-00392: log 1 of thread 1 is being cleared, operation not allowed
ORA-00312: online log 1 thread 1: ‘/u02/oradata/neprd6/redo01.log’

2. Check the database log status, it showed status of log files

SQL> select group#, status from

GROUP# STATUS
———- —————-
1 CLEARING_CURRENT
2 CLEARING
3 CLEARING
4 CLEARING
5 CLEARING
6 CLEARING_CURRENT
7 CLEARING
8 CLEARING
9 CLEARING

9 rows selected.

Fix:

  1. Clear the log manually SQL> alter database clear logfile group 1;

    Database altered.

    SQL> alter database clear logfile group 6;

    Database altered.

    SQL> select group#, status from v$log;

    GROUP# STATUS
    ———- —————-
    1 CURRENT
    2 CLEARING
    3 CLEARING
    4 CLEARING
    5 CLEARING
    6 CURRENT
    7 CLEARING
    8 CLEARING
    9 CLEARING

    9 rows selected.

  2. Start the database with resetlogs
    SQL> alter database open resetlogs;

    Database altered.

 

WARNING: oradism did not start up correctly.

June 25, 2013 Leave a comment

WARNING: ——————————-
WARNING: oradism did not start up correctly.
When starting database instance, the following returned.

Dynamic ISM can not be locked.—————————————-
oradism creation failed for unknown reasons 0 8 100
WARNING: ——————————-
WARNING: oradism did not start up correctly.
Dynamic ISM can not be locked.—————————————-
oradism creation failed for unknown reasons 0 8 100
WARNING: ——————————-
WARNING: oradism did not start up correctly.
Dynamic ISM can not be locked.—————————————-
oradism creation failed for unknown reasons 0 8 100
WARNING: ——————————-
WARNING: oradism did not start up correctly.
Dynamic ISM can not be locked.—————————————-
oradism creation failed for unknown reasons 0 8 100
2013-06-25 17:55:55.804000 +08:00
DISM started, OS id=23152

Finally, I found that the owner of the $ORACLE_HOME/bin/oradism is not root. After changing the owner to root, the problem was fixed

 

Categories: TroubleShooting

ORA-00054: resource busy and acquire with NOWAIT specified or timeout expired

June 24, 2011 Leave a comment

Today, I try to change a invisible index to visible, I get the following messages

“ORA-00054: resource busy and acquire with NOWAIT specified or timeout expired”. Before 11g, we can only retry and retry until get the resource.

In 11gR, we can change the session to wait for the resource lock by the command below

SQL> ALTER SESSION SET ddl_lock_timeout=40;<- this means that try to lock resource s until ddl_lock_timeout ( 40 sec)

Session altered.

SQL> alter index cmsnews.DATAFEED_NEWS_CONTR_INDEX2 visible;
alter index cmsnews.DATAFEED_NEWS_CONTR_INDEX2 visible
*
ERROR at line 1:
ORA-00054: resource busy and acquire with NOWAIT specified or timeout expired ( after 40 second, still can’t lock the resources)

SQL> / <– retry again, it is ok

ORA-00704: bootstrap process failure

March 9, 2011 Leave a comment

Today, I upgrade a database from 11.1.06 to 11.1.0.7. When I startup with upgrade option, the message returned as below

SQL> alter database open UPGRADE;
alter database open UPGRADE
*
ERROR at line 1:
ORA-01092: ORACLE instance terminated. Disconnection forced
Process ID: 4060
Session ID: 170 Serial number: 5

After looking at alert.log, I found the following messages

*** 2011-03-09 17:38:41.390
ORA-00704: bootstrap process failure
ORA-39700: database must be opened with UPGRADE option

 

Fixed

Finally, I found that the database must be mounted in exclusive mode first and alter open with upgrade. The problem was fixed as procedure below

SQL> startup nomount;
ORACLE instance started.

SQL> alter system set cluster_database=false scope=spfile;

System altered.

SQL> shutdown abort
ORACLE instance shut down.
SQL> startup mount exclusive
ORACLE instance started.

SQL> alter database open upgrade;

Categories: TroubleShooting

OPatch failed with error code 73

December 6, 2010 3 comments

Yesterday, I installed CRS PSU 9294495 ( 11.1.0.7.4). I successfully installed on the first node. I got failed on the second node since the opatch got the message: OPatch failed with error code 73.

I turned on OPATCH_DEBUG ( =true), we got details error below.

Registering the caller : OPatch
OracleHomeInventory::createInventoryObj() gets OUIInstallAreaControl object
OracleHomeInventory::createInventoryObj() gets OUIInstallInventory object
OracleHomeInventory::createInventoryObj() gets OUIOracleHomeInfo object
   OracleHomeInfo::lock() fails, and there is no retry supported.
OracleHomeInventory::createInventoryObj() gets a null OUIOracleHomeInfo object
OracleHomeInventory::createInventoryObj() tries to print a list of Oracle Homes on this system
OracleHomeInventory::createInventoryObj() Your Oracle Home path: "/opt/oracle/product/11g/crs"
List of Homes on this system:

  Home name= oracle_11ghome, Location= "/opt/oracle/product/11g"
OracleHomeInventory::createInventoryObj() construction done
LsInventory::loadAndPrintInventory()
Retrieving inventory from Oracle Home...
OracleHomeInventory::load()
Inventory load failed... OPatch cannot load inventory for the given Oracle Home.
Possible causes are:
   Oracle Home dir. path does not exist in Central Inventory
   Oracle Home is a symbolic link
   Oracle Home inventory is corrupted
Locker::release()
OUISessionManager::unRegister()
Un-Registering the caller : OPatch
LsInventory::getInstance() returns
LsInventorySession failed: OracleHomeInventory gets null oracleHomeInfo
Cleaning up the directory : "/opt/oracle/product/11g/crs/.patch_storage/patch_unzip"...

OPatch failed with error code 73

1. It showed that opatch failure may caused by inventory. Then I compared the inventory on both nodes, I found the inventory.xml is not same.

At node 1:
ls -l /opt/oracle/product/oraInventory/ContentsXML
total 6
-rw-rw----   1 oracle   dba          260 Dec  4 22:51 comps.xml
-rw-rw----   1 oracle   dba          683 May  5  2009 inventory.xml
-rw-rw----   1 oracle   dba          270 Dec  4 22:51 libs.xml

At node 2: 
$  ls -l /opt/oracle/product/oraInventory/ContentsXML
total 8
-rw-r--r--   1 oracle   dba          260 Dec  5 00:50 comps.xml
-rw-r--r--   1 oracle   dba          495 Dec  4 23:48 inventory.xml
-rw-r--r--   1 oracle   dba          270 Dec  5 00:50 libs.xml

2. Compare the contents of them, I found that there was missing CRS Home List in node 2 inventory. 

At node 1:

$ cat inventory.xml
<?xml version="1.0" standalone="yes" ?>
<!-- Copyright (c) 1999, 2006, Oracle. All rights reserved. -->
<!-- Do not modify the contents of this file by hand. -->
<INVENTORY>
<VERSION_INFO>
 <SAVED_WITH>11.1.0.6.0</SAVED_WITH>
 <MINIMUM_VER>2.1.0.6.0</MINIMUM_VER>
</VERSION_INFO>
<HOME_LIST>
<HOME NAME="OraCrs11g_home" LOC="/opt/oracle/product/11g/crs" TYPE="O" IDX="1" CRS="true">
 <NODE_LIST>
 <NODE NAME="qapdb01"/>
 <NODE NAME="qapdb03"/>
 </NODE_LIST>
</HOME>
<HOME NAME="OraDb11g_home1" LOC="/opt/oracle/product/11g" TYPE="O" IDX="2">
 <NODE_LIST>
 <NODE NAME="qapdb01"/>
 <NODE NAME="qapdb03"/>
 </NODE_LIST>
</HOME>
</HOME_LIST>
</INVENTORY>

At node 2:
$ cat inventory.xml
<?xml version="1.0" standalone="yes" ?>
<!-- Copyright (c) 1999, 2008, Oracle. All rights reserved. -->
<!-- Do not modify the contents of this file by hand. -->
<INVENTORY>
<VERSION_INFO>
 <SAVED_WITH>11.1.0.7.0</SAVED_WITH>
 <MINIMUM_VER>2.1.0.6.0</MINIMUM_VER>
</VERSION_INFO>
<HOME_LIST>
<HOME NAME="oracle_11ghome" LOC="/opt/oracle/product/11g" TYPE="O" IDX="1">
 <NODE_LIST>
 <NODE NAME="qapdb01"/>
 <NODE NAME="qapdb03"/>
 </NODE_LIST>
</HOME>
</HOME_LIST>
</INVENTORY>

Fixed

I copy the inventory.xml at node 1 to node 2. It worked.
 











Categories: Patching, TroubleShooting

ORA-06512: at “SYS.DBMS_DEBUG_JDWP”, line 68

November 30, 2010 Leave a comment

Symptoms

SQL> exec dbms_debug_jdwp.connect_tcp(‘0.0.0.0’, ‘111’)
BEGIN dbms_debug_jdwp.connect_tcp(‘0.0.0.0’, ‘111’); END;

*
ERROR at line 1:
ORA-01031: insufficient privileges
ORA-06512: at “SYS.DBMS_DEBUG_JDWP”, line 68
ORA-06512: at line 1

 

Fix

Grant the debug connect session, and any procedure to the user

SQL> grant debug connect session, debug any procedure to vod;

Grant succeeded.

 

Categories: TroubleShooting

Intermittent high responding time

September 28, 2010 Leave a comment

The application developer reported that there was intermittent high responding time for the following SQL

SELECT  pmt.orderid,
pmt.trandate                                  AS orderdate,
odritms.productid,
odritms.chiname,
odritms.engname,
odritms.providerid,
odritms.skuid,
odritms.quantity,
odritms.paymethod,
odritms.paytype,
odritms.movieclass,
odritms.licenseenddate,
pdr.smallimgname,
pdr.producttype,
( odritms.totalmaxcount – odritms.viewcount ) AS remainviewcount,
pmt.paystatus,
pmt.unitprice,
pmt.discountprice
FROM   orderitem odritms,
product pdr,
payment pmt
WHERE  pmt.userid = ‘24264983’
AND ( pmt.paystatus = ‘1’
OR pmt.paystatus = ‘-1’ )
AND pmt.orderid = odritms.orderid
AND odritms.productid = pdr.productid
AND ( pdr.producttype = ‘MOVIE’
OR pdr.producttype = ‘MTV’ )
AND odritms.productid = ‘LINK00000016’
AND To_char(odritms.licenseenddate, ‘YYYYMMDD’) >= To_char(sysdate, ‘YYYYMMDD’)
AND ( odritms.totalmaxcount – odritms.viewcount ) >= 0
ORDER  BY odritms.orderid,
odritms.itemnum
/

Symptoms

1. The responding time of the SQL is about 2~3 mins at first time

2. The responding time of the SQL is about 0.4 second when it was reun.

3. There are no problems found on explain plans

PLAN_TABLE_OUTPUT
————————————————————————————————————————————

———————————————————————————–
| Id  | Operation                       |  Name           | Rows  | Bytes | Cost  |
———————————————————————————–
|   0 | SELECT STATEMENT                |                 |       |       |       |
|   1 |  SORT ORDER BY                  |                 |       |       |       |
|   2 |   CONCATENATION                 |                 |       |       |       |
|   3 |    NESTED LOOPS                 |                 |       |       |       |
|   4 |     NESTED LOOPS                |                 |       |       |       |
|   5 |      TABLE ACCESS BY INDEX ROWID| PAYMENT         |       |       |       |
|*  6 |       INDEX RANGE SCAN          | PAYMENT_IDX     |       |       |       |
|*  7 |      TABLE ACCESS BY INDEX ROWID| ORDERITEM       |       |       |       |
|*  8 |       INDEX RANGE SCAN          | ORDERITEM1_IDX  |       |       |       |
|*  9 |     TABLE ACCESS BY INDEX ROWID | PRODUCT         |       |       |       |
|* 10 |      INDEX UNIQUE SCAN          | PK_PRODUCT      |       |       |       |
|  11 |    NESTED LOOPS                 |                 |       |       |       |
|  12 |     NESTED LOOPS                |                 |       |       |       |
|  13 |      TABLE ACCESS BY INDEX ROWID| PAYMENT         |       |       |       |
|* 14 |       INDEX RANGE SCAN          | PAYMENT_IDX     |       |       |       |
|* 15 |      TABLE ACCESS BY INDEX ROWID| ORDERITEM       |       |       |       |
|* 16 |       INDEX RANGE SCAN          | ORDERITEM1_IDX  |       |       |       |
|* 17 |     TABLE ACCESS BY INDEX ROWID | PRODUCT         |       |       |       |
|* 18 |      INDEX UNIQUE SCAN          | PK_PRODUCT      |       |       |       |
———————————————————————————–

Predicate Information (identified by operation id):
—————————————————

6 – access(“PMT”.”USERID”=’24264983′ AND “PMT”.”PAYSTATUS”=’-1′)
7 – filter(“ODRITMS”.”TOTALMAXCOUNT”-“ODRITMS”.”VIEWCOUNT”>=0 AND
TO_CHAR(“ODRITMS”.”LICENSEENDDATE”,’YYYYMMDD’)>=TO_CHAR(SYSDATE@!,’YYYYMMDD’)) <– Then, filter the orderid & productid by licenseenddate
8 – access(“PMT”.”ORDERID”=”ODRITMS”.”ORDERID” AND
“ODRITMS”.”PRODUCTID”=’LINK00000016′) <– First, ORDERITEM1_IDX is used to search ORDERID & PRODUCTID on ORDERITEM table
9 – filter(“PDR”.”PRODUCTTYPE”=’MOVIE’ OR “PDR”.”PRODUCTTYPE”=’MTV’)
10 – access(“ODRITMS”.”PRODUCTID”=”PDR”.”PRODUCTID”)
14 – access(“PMT”.”USERID”=’24264983′ AND “PMT”.”PAYSTATUS”=’1′)
15 – filter(“ODRITMS”.”TOTALMAXCOUNT”-“ODRITMS”.”VIEWCOUNT”>=0 AND
TO_CHAR(“ODRITMS”.”LICENSEENDDATE”,’YYYYMMDD’)>=TO_CHAR(SYSDATE@!,’YYYYMMDD’))
16 – access(“PMT”.”ORDERID”=”ODRITMS”.”ORDERID” AND
“ODRITMS”.”PRODUCTID”=’LINK00000016′)
17 – filter(“PDR”.”PRODUCTTYPE”=’MOVIE’ OR “PDR”.”PRODUCTTYPE”=’MTV’)
18 – access(“ODRITMS”.”PRODUCTID”=”PDR”.”PRODUCTID”)

Note: rule based optimization

4. Flush cache memory by the command ‘alter session set events = ‘immediate trace name flush_cache’,

– the responding time of the SQL is high again

5. Enable session trace by ‘alter session set events=’10046 trace name context forever, level 12′

– There are more than ten thousands lines like below in the trace file

EXEC #1:c=0,e=991,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=66264756152003
WAIT #1: nam=’SQL*Net message to client’ ela= 4 p1=1650815232 p2=1 p3=0
WAIT #1: nam=’db file sequential read’ ela= 25205 p1=7 p2=854286 p3=1
WAIT #1: nam=’db file sequential read’ ela= 20295 p1=7 p2=854289 p3=1
WAIT #1: nam=’db file sequential read’ ela= 22670 p1=7 p2=854292 p3=1
WAIT #1: nam=’db file sequential read’ ela= 20550 p1=7 p2=855113 p3=1
WAIT #1: nam=’db file sequential read’ ela= 27226 p1=7 p2=855128 p3=1
WAIT #1: nam=’db file sequential read’ ela= 28417 p1=7 p2=857666 p3=1
WAIT #1: nam=’db file sequential read’ ela= 4772 p1=11 p2=210671 p3=1
WAIT #1: nam=’db file sequential read’ ela= 18945 p1=7 p2=851190 p3=1
WAIT #1: nam=’db file sequential read’ ela= 19504 p1=10 p2=130069 p3=1
WAIT #1: nam=’db file sequential read’ ela= 16400 p1=7 p2=851254 p3=1
WAIT #1: nam=’db file sequential read’ ela= 12534 p1=7 p2=851447 p3=1
WAIT #1: nam=’db file sequential read’ ela= 24912 p1=7 p2=851466 p3=1
WAIT #1: nam=’db file sequential read’ ela= 27478 p1=7 p2=851496 p3=1
WAIT #1: nam=’db file sequential read’ ela= 6864 p1=11 p2=210193 p3=1
WAIT #1: nam=’db file sequential read’ ela= 16136 p1=7 p2=851416 p3=1
WAIT #1: nam=’db file sequential read’ ela= 13395 p1=7 p2=851418 p3=1
WAIT #1: nam=’db file sequential read’ ela= 16521 p1=7 p2=851419 p3=1
WAIT #1: nam=’db file sequential read’ ela= 58 p1=7 p2=851425 p3=1
WAIT #1: nam=’db file sequential read’ ela= 11117 p1=7 p2=851431 p3=1
WAIT #1: nam=’db file sequential read’ ela= 54 p1=7 p2=851435 p3=1
WAIT #1: nam=’db file sequential read’ ela= 423 p1=7 p2=851436 p3=1
WAIT #1: nam=’db file sequential read’ ela= 10136 p1=7 p2=851360 p3=1

– Show that the session wait for a index object ORDERITEM1_IDX

SQL> @get_segment_name.sql
Enter value for p1_file_id: 7
old   3: WHERE file_id = &P1_FILE_ID
new   3: WHERE file_id = 7
Enter value for p2_block_no: 854286
old   4: AND &P2_BLOCK_NO BETWEEN block_id AND block_id + blocks -1
new   4: AND 854286 BETWEEN block_id AND block_id + blocks -1

OWNER
——————————
SEGMENT_NAME
——————————————————————————–
SEGMENT_TYPE
——————
PCTVPROD
ORDERITEM1_IDX
INDEX

6.  It concludes that the 10 thousands database blocks are caused by  reading  ORDERITEM1_IDX ,

i.e The index ORDERITEM1_IDX selectivity is Low.

Index                          Column Name          Type      Size (bytes)
—————————— ——————– ——— ————
PCTVPROD.ORDERITEM1_IDX        ORDERID              NUMBER              22
PRODUCTID            VARCHAR2            20

Fix

– Create another a more selectivity composite index replacing it, based on the predicate, adding the licenseenddate field like below,

SQL> exec DBMS_TRANSACTION.USE_ROLLBACK_SEGMENT (‘LR00’);

SQL> create index orderitem2_idx on ORDERITEM ( ORDERID, PRODUCTID, to_char(licenseenddate, ‘YYYYMMDD’)) parallel 4;

or

SQL> create index orderitem2_idx on ORDERITEM ( ORDERID, PRODUCTID, to_char(licenseenddate, ‘YYYYMMDD’)) online;   ( online create )

SQL> alter session set events = ‘immediate trace name flush_cache’;

Session altered.

Elapsed: 00:00:00.39
SQL> @pg15 <– the problem  SQL

no rows selected

Elapsed: 00:00:00.00
SQL>