Tales From A Lazy Fat DBA

Its all about Databases & their performance, troubleshooting & much more …. ¯\_(ツ)_/¯

Archive for January, 2014

AWR/ADDM/ASH Coming Blank. Tuning Advisors not working :( … (What to do ??)

Posted by FatDBA on January 23, 2014

You have a new database designed and created for the team to test changes before they go and apply in Production. One fine day you feel a need to check performance of database and get some auto suggestions from oracle engine itself using ADDM and AWR or ASH … But what if they are coming blank and Tuning Advisors throwing errors saying ….

DECLARE
*
ERROR at line 1:
ORA-13717: Tuning Package License is needed for using this feature.
ORA-06512: at “SYS.PRVT_SMGUTIL”, line 52
ORA-06512: at “SYS.PRVT_SMGUTIL”, line 37
ORA-06512: at “SYS.DBMS_MANAGEMENT_PACKS”, line 26
ORA-06512: at “SYS.DBMS_SQLTUNE”, line 651
ORA-06512: at line 4

WHAT TO DO ?

Reason: This case comes in to existence if you are using STANDARD edition of Oracle Database.
Here is a small fix for the problem —-
Change the parameter (control_management_pack) to ‘DIAGNOSTIC+TUNING’ in order to enable MMON to collect the health statistics timely to AWR related tables (Sits in SYSAUX)

SQL> show parameter control_management_pack
NAME                                 TYPE                             VALUE
———————————— ——————————– ——————————
control_management_pack_access       string                           NONE

SQL> ALTER system SET CONTROL_MANAGEMENT_PACK_ACCESS=‘DIAGNOSTIC+TUNING’;
System altered.

SQL>  show parameter control_management_pack
NAME                                 TYPE                             VALUE
———————————— ——————————– ——————————
control_management_pack_access       string                           DIAGNOSTIC+TUNING

Advertisement

Posted in Advanced | 2 Comments »

RMAN Error: ORA-01152: file 1 was not restored from a sufficiently old backup & ORA-01110:

Posted by FatDBA on January 15, 2014

RMAN Scenario:
DB: Oracle 11g r2
OS: Linux – RHEL 5
Error: “ORA-01152: file 1 was not restored from a sufficiently old backup” when tried to open the database.

STATUS
==============
SQL> @db

NAME      ROLE       LOG_MODE     OPEN_MODE      DG_BROKE FORC_LGNG   CUR_SCN        CKPT_CHG        CTRLFIL_SEQ CTRLFL_CNG      ARCH_CNG       PROT_MOD
——— ———- ———— ————– ——– ———– ————– ————— ———– ————— ————– ——————–
SAIRAM     PRIMARY    ARCHIVELOG   MOUNTED        DISABLED YES         0              32913920280       795938526 32913922263     32913811789    MAXIMUM PERFORMANCE

SQL> select open_mode from v$database;
OPEN_MODE
————–
MOUNTED

This is what’s happening with the database when tried to open it.
Throwing error which reads System datafile is restored from an old backup.

SQL> alter database open resetlogs;
alter database open resetlogs
*
ERROR at line 1:
ORA-01152: file 1 was not restored from a sufficiently old backup
ORA-01110: data file 1: ‘/dbmount212/sairam/datafiles/system01.dbf’

When tried to recover the database it’s asking for sequence number 75, which is not available (Conformed, as asked sequence is not available in ARCHIVE destination).

SQL> recover database until cancel using backup controlfile;
ORA-00279: change 32913922263 generated at 01/14/2014 10:57:39 needed for thread 1
ORA-00289: suggestion : /dbmount212/oracle/sairam/archivelog/1_75_833707787.arc
ORA-00280: change 32913922263 for thread 1 is in sequence #75

Specify log: {<RET>=suggested | filename | AUTO | CANCEL}
AUTO
ORA-00308: cannot open archived log ‘/dbmount212/oracle/sairam/archivelog/1_75_833707787.arc’
ORA-27037: unable to obtain file status
Linux-x86_64 Error: 2: No such file or directory
Additional information: 3

ORA-00308: cannot open archived log ‘/dbmount212/oracle/sairam/archivelog/1_75_833707787.arc’
ORA-27037: unable to obtain file status
Linux-x86_64 Error: 2: No such file or directory
Additional information: 3

ORA-01547: warning: RECOVER succeeded but OPEN RESETLOGS would get error below
ORA-01152: file 1 was not restored from a sufficiently old backup
ORA-01110: data file 1: ‘/dbmount212/sairam/system01.dbf’

There is a possibility that the sequence might be struck inside of any redo log file and has not been archived.
Let’s query required sequence number (75) using one of the dynamic view v$log

SQL> select * from v$log where SEQUENCE#=’75’;

GROUP#    THREAD#  SEQUENCE#      BYTES  BLOCKSIZE    MEMBERS ARC STATUS           FIRST_CHANGE#
———- ———- ———- ———- ———- ———- — —————- ————-
FIRST_TIM NEXT_CHANGE# NEXT_TIME
——— ———— ———
9          1         75  524288000        512          1 NO  CURRENT             3.2914E+10
14-JAN-14   2.8147E+14

Yes,the log is inside group number 9. Let’s check the location of the related log file using v$logfile;

SQL> SELECT * FROM V$LOGFILE where group#=’9′;

GROUP# STATUS  TYPE
———- ——- ——-
MEMBER
—————————————————————————————————-
IS_
—
9         ONLINE
/var/log/oracle/redo/onlinelog/redo07.log
NO

Let’s try to recover the database again.

SQL> recover database until cancel using backup controlfile;

ORA-00279: change 32913922872 generated at 01/14/2014 11:17:33 needed for thread 1
ORA-00289: suggestion : /dbmount212/oracle/sairam/archivelog/1_75_833707787.arc
ORA-00280: change 32913922872 for thread 1 is in sequence #75Specify log: {<RET>=suggested | filename | AUTO | CANCEL}
/var/log/oracle/redo/onlinelog/redo09.log
ORA-00283: recovery session canceled due to errors
ORA-01111: name for data file 69 is unknown – rename to correct file
ORA-01110: data file 69: ‘/dbmnt12/oracle/product/11.2.0/dbhome_1/dbs/UNNAMED00069’
ORA-01157: cannot identify/lock data file 69 – see DBWR trace file
ORA-01111: name for data file 69 is unknown – rename to correct file
ORA-01110: data file 69: ‘/dbmnt12/oracle/product/11.2.0/dbhome_1/dbs/UNNAMED00069’

Alright, it’s asking for one datafile (69) which is unknown to the controlfile. Yes, this is right. As we have created a test datafile before that controlfile backup.
As it’s of no importance, we’d dropped the datafile.

SQL> alter database datafile 69 offline drop;
Database altered.

Let’s try again to recover the database using the log file ‘/var/log/oracle/redo/onlinelog/redo09.log’.

SQL> recover database using backup controlfile ;
ORA-00279: change 32913922872 generated at 01/14/2014 11:17:33 needed for thread 1
ORA-00289: suggestion : /dbmount212/oracle/sairam/archivelog/1_75_833707787.arc
ORA-00280: change 32913922872 for thread 1 is in sequence #75

Specify log: {<RET>=suggested | filename | AUTO | CANCEL}
/var/log/oracle/redo/onlinelog/redo09.log
Log applied.
Media recovery complete.

Okay, when provided exact filename of the logfile, it has accepted it and applied and came up, hence media recovery is completed.
Now we can go and try to open the database.

SQL> alter database open resetlogs;
Database altered.

SQL> archive log list;
Database log mode              Archive Mode
Automatic archival             Enabled
Archive destination            /dbmount212/oracle/sairam/archivelog/
Oldest online log sequence     1
Next log sequence to archive   1
Current log sequence           1

And we are up!
Below provided is the list of incarnation of the database and the last line with a new incarnation created on today’s date.

SQL> select * from V$DATABASE_INCARNATION;

INCARNATION# RESETLOGS_CHANGE# RESETLOGS PRIOR_RESETLOGS_CHANGE# PRIOR_RES STATUS  RESETLOGS_ID PRIOR_INCARNATION# FLASHBACK_DATABASE_ALLOWED
———— —————– ——— ———————– ——— ——- ———— —————— ————————–
1            602821 05-MAY-10                       1 12-MAR-08 PARENT     718177612                  0 NO
2         148027929 19-MAY-10                  602821 05-MAY-10 PARENT     719411741                  1 NO
3        9199856900 28-AUG-11               148027929 29-MAY-10 PARENT     760357356                  2 NO
4        1.9412E+10 11-AUG-12              9199856900 28-AUG-11 PARENT     791021290                  3 NO
5        3.2910E+10 09-DEC-13              1.9412E+10 1-AUG-12 PARENT     833707787                  4 NO
6        3.2914E+10 15-JAN-14              3.2910E+10 09-DEC-13 CURRENT    836892925                  5 YES

6 rows selected.

Hope That Helps
Prashant Dixit

Posted in Advanced | Tagged: , | 4 Comments »

Something Strikingly odd with Oracle: DB with Two ‘Current’ log-files!!

Posted by FatDBA on January 8, 2014

Something real uncanny happened with one of our databases recently: There were 2 log-files with CURRENT status: Strange right!!!

SQL> select GROUP#,SEQUENCE#,BYTES/1024/1024 as SIZE_MB,MEMBERS,STATUS from v$log;
GROUP#  SEQUENCE#      SIZE_MB    MEMBERS STATUS
———- ———- ———- ———-   —————
1       15651       50          2 INACTIVE
3       15653       50          2 CURRENT
2       15652       50          2 CURRENT
4       15650       50          2 INACTIVE

Found the ‘Notorious’ Generic error ORA-600 in alert log :
ORA-00600: internal error code, arguments: [3705], [1], [3], [2], [8], [], [], []

We had to perform point-in-time recovery up to 15652 sequence and we were all good.

Hope That Helps
Prashant Dixit

Posted in Uncategorized | Tagged: | Leave a Comment »

Oracle Golden Gate: Tuning GG processes.

Posted by FatDBA on January 8, 2014

While doing a load tests on one of our databases for Golden Gate found replicate process doing an FTS while updating a big batch of rows in a table.

Problem : Replicate process was going for a  Full table Scan while Updating 804000 rows.

Source Database = 11.2.0.3

Below is update statement which was issued to update 804000 rows.
This completed in 15 seconds on SOURCE side DB.

sql_id :ghsutzgq0m8j9

PLAN_TABLE_OUTPUT
——————————————————————————————-
SQL_ID ghsutzgq0m8j9
——————–
UPDATE dummy11.OS_HISTORYSTEP_BLD SET ENTRY_ID=5555, STEP_ID=100000,
ACTION_ID=20000, OWNER=’JIGNESHKANKRECHA’,
START_DATE=TO_TIMESTAMP(‘5/28/2012 9:19:11.910000
PM’,’fmMMfm/fmDDfm/YYYY fmHH12fm:MI:SS.FF AM’),
FINISH_DATE=TO_TIMESTAMP(‘5/28/2012 9:19:11.910000
PM’,’fmMMfm/fmDDfm/YYYY fmHH12fm:MI:SS.FF AM’),
DUE_DATE=TO_TIMESTAMP(‘5/28/2012 9:19:11.910000 PM’,’fmMMfm/fmDDfm/YYYY
fmHH12fm:MI:SS.FF AM’), STATUS=’QC Validation failed’, CALLER=’KALIYA’
where ID  BETWEEN 1220000 AND 5999999

Plan hash value: 3578452229

—————————————————————————————–
| Id  | Operation          | Name               | Rows  | Bytes | Cost (%CPU)| Time     |
—————————————————————————————–
|   0 | UPDATE STATEMENT   |                    |       |       |   376 (100)|          |
|   1 |  UPDATE            | OS_HISTORYSTEP_BLD |       |       |            |          |
|   2 |   TABLE ACCESS FULL| OS_HISTORYSTEP_BLD |    47 |  4277 |   376   (1)| 00:00:05 |
—————————————————————————————–

——————————————————————
Target Database = 10.2.0.4
Below statement Replicate executed, Because i had BATCHSQL replicate made BATCH of few rows and send for update that is the reason we see COUNT STOPKEY in execution plan.

PLAN_TABLE_OUTPUT
—————————————————————————————
SQL_ID b4t7hv6p53165
——————–
UPDATE “dummy11″.”OS_HISTORYSTEP_BLD” SET “ENTRY_ID” = :a1,”STEP_ID” =
:a2,”ACTION_ID” = :a3,”OWNER” = :a4,”START_DATE” = :a5,”FINISH_DATE” =
:a6,”DUE_DATE” = :a7,”STATUS” = :a8,”CALLER” = :a9 WHERE “ID” = :b0 AND ROWNUM = 1

Plan hash value: 185372276

——————————————————————————————
| Id  | Operation           | Name               | Rows  | Bytes | Cost (%CPU)| Time     |
——————————————————————————————
|   0 | UPDATE STATEMENT    |                    |       |       |   304 (100)|          |
|   1 |  UPDATE             | OS_HISTORYSTEP_BLD |       |       |            |          |
|   2 |   COUNT STOPKEY     |                    |       |       |            |          |
|   3 |    TABLE ACCESS FULL| OS_HISTORYSTEP_BLD |     1 |    91 |   304   (1)| 00:00:04 |
——————————————————————————————

–Excerpt from Report file.
BATCHSQL BATCHESPERQUEUE 100, BATCHTRANSOPS 10000, OPSPERBATCH 10000, OPSPERQUEUE 100000

MAP resolved (entry dummy11.OS_HISTORYSTEP_BLD):
MAP “dummy11″.”OS_HISTORYSTEP_BLD”, TARGET dummy11.OS_HISTORYSTEP_BLD, KEYCOLS(ID);

xxxxxxx 12:00:30  WARNING OGG-00869  No unique key is defined for table ‘OS_HISTORYSTEP_BLD’. All viable columns will be used to represent the key, but may not guarantee uniqueness.  KEYCOLS may be used to define the key.
Using following columns in default map by name:
ID, ENTRY_ID, STEP_ID, ACTION_ID, OWNER, START_DATE, FINISH_DATE,
DUE_DATE, STATUS, CALLER
Using the following key columns for target table dummy11.OS_HISTORYSTEP_BLD: ID.

——–some statistic of replicat.
xxxxxxx 12:18:22  INFO    OGG-01408  Restoring current schema for DDL operation to [GGADMIN].
104578 records processed as of xxxxxxxxxxxxxxxx 12:21:05 (rate 84,delta 236)
457309 records processed as of xxxxxxxxxxxxxxxx 13:35:07 (rate 80,delta 79)
913119 records processed as of xxxxxxxxxxxxxxxx 13:39:47 (rate 153,delta 1628)
943118 records processed as of xxxxxxxxxxxxxxxx 13:41:25 (rate 155,delta 305)
953118 records processed as of xxxxxxxxxxxxxxxx 13:42:43 (rate 155,delta 127)
963118 records processed as of xxxxxxxxxxxxxxxx 13:44:25 (rate 154,delta 98)
973118 records processed as of xxxxxxxxxxxxxxxx 13:46:29 (rate 153,delta 80)
983118 records processed as of xxxxxxxxxxxxxxxx 13:48:57 (rate 151,delta 67)
993118 records processed as of xxxxxxxxxxxxxxxx 13:51:47 (rate 148,delta 58)
1003118 records processed as of xxxxxxxxxxxxxxxx 13:54:59 (rate 146,delta 51)
1013118 records processed as of xxxxxxxxxxxxxxxx 13:58:35 (rate 143,delta 46)

** xxxxxxx- Intentional

SOLUTION:
1) kill session of replicate which was running update statement, This will abend replicate.
2) Add Index on ID column which was in KEYCOLS Of MAP statement.
3) start replicate .

And we are back to the normal.

GGSCI (catlmsxt205) 4> INFO ALL

Program     Status      Group       Lag at Chkpt  Time Since Chkpt

MANAGER     RUNNING
REPLICAT    RUNNING     TAPSDR      00:00:00      03:32:40

GGSCI (catlmsxt205) 4> INFO ALL

Program     Status      Group       Lag at Chkpt  Time Since Chkpt

MANAGER     RUNNING
REPLICAT    RUNNING     TAPSDR      00:00:00      03:32:42

GGSCI (catlmsxt205) 6> INFO ALL
Program     Status      Group       Lag at Chkpt  Time Since Chkpt
MANAGER     RUNNING
REPLICAT    RUNNING     TAPSDR      00:00:00      03:33:06

GGSCI (catlmsxt205) 7> INFO ALL

Program     Status      Group       Lag at Chkpt  Time Since Chkpt

MANAGER     RUNNING
REPLICAT    RUNNING     TAPSDR      00:00:00      00:00:03

Execution plan of Update after Index.

PLAN_TABLE_OUTPUT
———————————————————————————————————————————————————————————————-
SQL_ID  b4t7hv6p53165, child number 0
————————————-
UPDATE “dummy11″.”OS_HISTORYSTEP_BLD” SET “ENTRY_ID” = :a1,”STEP_ID” =
:a2,”ACTION_ID” = :a3,”OWNER” = :a4,”START_DATE” = :a5,”FINISH_DATE” =
:a6,”DUE_DATE” = :a7,”STATUS” = :a8,”CALLER” = :a9 WHERE “ID” = :b0 AND ROWNUM =
1

Plan hash value: 2252287618

—————————————————————————————–
| Id  | Operation          | Name               | Rows  | Bytes | Cost (%CPU)| Time     |
—————————————————————————————–
|   0 | UPDATE STATEMENT   |                    |       |       |     5 (100)|          |
|   1 |  UPDATE            | OS_HISTORYSTEP_BLD |       |       |            |          |
|*  2 |   COUNT STOPKEY    |                    |       |       |            |          |
|*  3 |    INDEX RANGE SCAN| OS_HIST_BLDIDX     |     1 |    91 |     3   (0)| 00:00:01 |
—————————————————————————————–

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

2 – filter(ROWNUM=1)
3 – access(“ID”=TO_NUMBER(:B0))

Posted in Advanced | Tagged: | Leave a Comment »

 
%d bloggers like this: