Showing posts with label 12c. Show all posts
Showing posts with label 12c. Show all posts

Tuesday, September 8, 2020

ORA-12152: TNS: Unable to send break message

 The new Exadata customer came with a problem "ORA-12152: TNS: Unable to send break message".  (What is the in-band breaking and out-of-band breaking we know from Tanel Poder's post:
https://tanelpoder.com/2008/02/05/oracle-hidden-costs-revealed-part-1/ ).

The customer say: 

"  We're testing upgrade to Oracle 19c from 11.2.0.4. And on 19c we got a problem with interrupting the connection between the application (pl/sql developer, sqlplus) on the client machine and the Oracle database: ORA-12152: TNS: Unable to send break message.

This problem is show stopper to upgrade to 19c!

The connection between the application (pl / sql developer, sqlplus) on the client machine and the process on the Oracle server is interrupted if the client application does not generate traffic for 60 minutes. The application is waiting for a response from the long procedure. After the procedure on the server is actually finished, the application is still waiting for the procedure to complete. When trying to interrupt the connection from the application side, we get ORA-12152: TNS: Unable to send break message (Cause: Unable to send break message).

Network engineers don't see any problems.
Simple test case show this problem:

begin
 dbms_lock.sleep(
3590);
end
;
/

Finished successully.
 


But


begin

 dbms_lock.sleep(
3610);
end
;
/
is finished unsuccessfully.
 

 "

Thanks to the detailed description, the customer's problem became clear. It is not a In-Band or OOB breaking. It is actually Dead Connection Detection : DCD was enchanced in 12c to reduce detection time.

DCD is mechanism which allow the RDBMS server to check if the client is alive.

This feature is configured on server side using sqlnet.expire_time in sqlnet.ora. The probe packet is sent to the client side every sqlnet.expire_time minutes. If database server have got an error then client is dead and server can close this connection. In pre-12c releases this work was done by NS layer in SQL*Net . 

The 12c mechanism is intended to reduce the detection time and minimize load from RDBMS. This new mechanism is based on the TCP-keepalive property of the socket. With this approach TCP-keepalive probes are sent by OS after the connection has been idle for some time. Because these probes are implemented on the OS level then RDBMS rely on socket state (don't need send its own probes).

But in 12c we still able to use the sqlnet.expire_time.
After the customer have set sqlnet.expire_time=10 the error "ORA-12152: TNS: Unable to send break message" disappeared.

  




Thursday, January 18, 2018

VW_TE_2 view and the wrong execution plan when Table Expansion take place

Our customer has a problem today.
The very simple queries take very different time :

select min(a.ENTRYDATE) from ORDERS_BASE a where a.ENTRYDATE < to_date('01.01.2015','dd.mm.yyyy');
select min(a.ENTRYDATE) from ORDERS_BASE a where a.ENTRYDATE < trunc(sysdate-1112);
select min(a.ENTRYDATE) from ORDERS_BASE a where a.ENTRYDATE < date '2015-01-01';


First query takes 850 second.
2nd and 3rd queries take .04 second.

Find the difference !
:(

The queries were tested at 17-JAN-2018 so trunc(sysdate-1112) == to_date('01.01.2015','dd.mm.yyyy') that day.

For clarity and for checking the difference in data types i did dump of these values:

SQL>  select dump(trunc(sysdate-1112)) from dual;

DUMP(TRUNC(SYSDATE-1112))
--------------------------------------------------------------------------------
Typ=13 Len=8: 223,7,1,1,0,0,0,0

SQL> select dump(to_date('01.01.2015','dd.mm.yyyy')) from dual;

DUMP(TO_DATE('01.01.2015','DD.M
-------------------------------
Typ=13 Len=8: 223,7,1,1,0,0,0,0

SQL> select dump(date '2015-01-01') from dual;

DUMP(DATE'2015-01-01')
-------------------------------
Typ=13 Len=8: 223,7,1,1,0,0,0,0



INVESTIGATION:

Step 0: Gather facts

DB version is 12.1.0.2.170418, Oracle on Linux x64.

Table has 65 columns:

SQL> desc ORDERS_BASE
 Name                                      Null?    Type
 ----------------------------------------- -------- ------
...
 ENTRYDATE                                          DATE

...


  CREATE TABLE "ORDERS_BASE"
   (     ...
    "ENTRYDATE" DATE,
         ...
   )
  PARTITION BY RANGE ("ENTRYDATE")
 (PARTITION "CURR_ORDERS_BASE_P_20050804"  VALUES LESS THAN (TO_DATE(' 2005-08-05 00:00:00', 'SYYYY-MM-DD HH24:MI:SS', 'NLS_CALENDAR=GREGORIAN')) SEGMENT CREATION DEFERRED ,
  PARTITION "CURR_ORDERS_BASE_P_20050805"  VALUES LESS THAN (TO_DATE(' 2005-08-06 00:00:00', 'SYYYY-MM-DD HH24:MI:SS', 'NLS_CALENDAR=GREGORIAN')) SEGMENT CREATION DEFERRED ,
  ...
 PARTITION "CURR_ORDERS_BASE_P_20200310"  VALUES LESS THAN (TO_DATE(' 2020-03-11 00:00:00', 'SYYYY-MM-DD HH24:MI:SS', 'NLS_CALENDAR=GREGORIAN'))  SEGMENT CREATION DEFERRED ,
 PARTITION "CURR_ORDERS_BASE_P_20200409"  VALUES LESS THAN (TO_DATE(' 2020-04-10 00:00:00', 'SYYYY-MM-DD HH24:MI:SS', 'NLS_CALENDAR=GREGORIAN'))  SEGMENT CREATION DEFERRED
 ) ;
Table has about 5000 partitions.

Table has 2 indexes:

  CREATE UNIQUE INDEX "ORDERS_CURR_UIDX" ON "ORDERS_BASE" ("ENTRYDATE", "ORDERNO")   LOCAL;

All 2014 year is in unusable state :

  ALTER INDEX "ORDERS_CURR_UIDX"  MODIFY PARTITION "CURR_ORDERS_BASE_P_20140101" UNUSABLE;
  ...
  ALTER INDEX "ORDERS_CURR_UIDX"  MODIFY PARTITION "CURR_ORDERS_BASE_P_20141231" UNUSABLE;



  CREATE INDEX "ORDER_CURR_ORDNO_IDX" ON "ORDERS_BASE" ("ORDERNO")   LOCAL;

All 2014 year is in unusable state :

  ALTER INDEX "ORDER_CURR_ORDNO_IDX"  MODIFY PARTITION "CURR_ORDERS_BASE_P_20140101" UNUSABLE;
  ...
  ALTER INDEX "ORDER_CURR_ORDNO_IDX"  MODIFY PARTITION "CURR_ORDERS_BASE_P_20141231" UNUSABLE;



Step 1: Lets measure

SQL> select min(a.ENTRYDATE) from ORDERS_BASE a where a.ENTRYDATE < trunc(sysdate-1112);

MIN(A.ENTRYDATE)
-------------------
10.01.2006 00:00:00

Elapsed: 00:00:00.04

SQL> select min(a.ENTRYDATE) from ORDERS_BASE a where a.ENTRYDATE < date '2015-01-01';

MIN(A.ENT
---------
10-JAN-06

Elapsed: 00:00:00.04

SQL> select min(a.ENTRYDATE) from ORDERS_BASE a where a.ENTRYDATE < to_date('01.01.2015','dd.mm.yyyy');

MIN(A.ENTRYDATE)
-------------------
10.01.2006 00:00:00

Elapsed: 00:14:10.64




Step 2: Lets look at the execution plan

The good plan at first:

SQL> set autotrace on
SQL> set lines 999 pages 99
SQL> select min(a.ENTRYDATE) from ORDERS_BASE a where a.ENTRYDATE < trunc(sysdate-1112);

MIN(A.ENTRYDATE)
-------------------
10.01.2006 00:00:00

Elapsed: 00:00:00.02

Execution Plan
----------------------------------------------------------
Plan hash value: 2553418393

----------------------------------------------------------------------------------------------------------------
| Id  | Operation                        | Name        | Rows  | Bytes | Cost (%CPU)| Time     | Pstart| Pstop |
----------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                 |             |     1 |     8 |  1404K (65)| 00:00:36 |       |       |
|   1 |  PARTITION RANGE ITERATOR MIN/MAX|             |     1 |     8 |            |          |     1 |   KEY |
|   2 |   SORT AGGREGATE                 |             |     1 |     8 |            |          |       |       |
|*  3 |    TABLE ACCESS STORAGE FULL     | ORDERS_BASE |  9195M|    68G|  1404K (65)| 00:00:36 |     1 |   KEY |
----------------------------------------------------------------------------------------------------------------

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

   3 - storage("A"."ENTRYDATE"<TRUNC(SYSDATE@!-1112))
       filter("A"."ENTRYDATE"<TRUNC(SYSDATE@!-1112))

Statistics
----------------------------------------------------------
          0  recursive calls
          2  db block gets
         19  consistent gets
         13  physical reads
          0  redo size
        555  bytes sent via SQL*Net to client
        552  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
          1  rows processed

Here i added the dummy hint to force hard parsing and generate the new plan:

SQL> select /*+ U */ min(a.ENTRYDATE) from ORDERS_BASE a where a.ENTRYDATE < trunc(sysdate-1112);

MIN(A.ENTRYDATE)
-------------------
10.01.2006 00:00:00

Elapsed: 00:00:00.03

Execution Plan
----------------------------------------------------------
Plan hash value: 2553418393

----------------------------------------------------------------------------------------------------------------
| Id  | Operation                        | Name        | Rows  | Bytes | Cost (%CPU)| Time     | Pstart| Pstop |
----------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                 |             |     1 |     8 |  1404K (65)| 00:00:36 |       |       |
|   1 |  PARTITION RANGE ITERATOR MIN/MAX|             |     1 |     8 |            |          |     1 |   KEY |
|   2 |   SORT AGGREGATE                 |             |     1 |     8 |            |          |       |       |
|*  3 |    TABLE ACCESS STORAGE FULL     | ORDERS_BASE |  9195M|    68G|  1404K (65)| 00:00:36 |     1 |   KEY |
----------------------------------------------------------------------------------------------------------------

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

   3 - storage("A"."ENTRYDATE"<TRUNC(SYSDATE@!-1112))
       filter("A"."ENTRYDATE"<TRUNC(SYSDATE@!-1112))

Statistics
----------------------------------------------------------
          1  recursive calls
          2  db block gets
         19  consistent gets
         13  physical reads
          0  redo size
        555  bytes sent via SQL*Net to client
        552  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
          1  rows processed

After hard parsing the new plan was generated and we see the no difference.
Oracle strongly keep the best plan.

Let probe the bad query:

SQL> select  min(a.ENTRYDATE) from ORDERS_BASE a where a.ENTRYDATE < to_date('01.01.2015','dd.mm.yyyy');

MIN(A.ENTRYDATE)
-------------------
10.01.2006 00:00:00

Elapsed: 00:14:10.64

Execution Plan
----------------------------------------------------------
Plan hash value: 2334607833

-------------------------------------------------------------------------------------------------------------
| Id  | Operation                     | Name        | Rows  | Bytes | Cost (%CPU)| Time     | Pstart| Pstop |
-------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT              |             |     1 |     8 |   285K (31)| 00:00:08 |       |       |
|   1 |  SORT AGGREGATE               |             |     1 |     8 |            |          |       |       |
|   2 |   VIEW                        | VW_TE_2     |  9195M|    77G|   285K (31)| 00:00:08 |       |       |
|   3 |    UNION-ALL                  |             |       |       |            |          |       |       |
|   4 |     PARTITION RANGE ITERATOR  |             |  6615M|    49G|   195K (30)| 00:00:05 |     1 |  3072 |
|   5 |      TABLE ACCESS STORAGE FULL| ORDERS_BASE |  6615M|    49G|   195K (30)| 00:00:05 |     1 |  3072 |
|   6 |     PARTITION RANGE ITERATOR  |             |  2579M|    19G| 89337  (32)| 00:00:03 |  3073 |  3437 |
|   7 |      TABLE ACCESS STORAGE FULL| ORDERS_BASE |  2579M|    19G| 89337  (32)| 00:00:03 |  3073 |  3437 |
-------------------------------------------------------------------------------------------------------------

Statistics
----------------------------------------------------------
        657  recursive calls
       3206  db block gets
   17682261  consistent gets
   17666575  physical reads
        120  redo size
        555  bytes sent via SQL*Net to client
        552  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
          1  rows processed


We see absolutely different plan:
- ONE full table scan has become TWO table scans
- and the view VW_TE_2 appeared

Let find the information about this view. I suppose the chars T and E may be in russian codepage
(russian chars with the T and E image), so I excluded them and left only english chars.
And I supposed that there may be leading and trailing spaces  (invisible chars).
Therefore i searched the  like '%VW%2%'.

[~]$ sqlplus / as sysdba

SQL*Plus: Release 12.1.0.2.0 Production on Wed Jan 17 17:21:04 2018
Oracle Database 12c Enterprise Edition Release 12.1.0.2.0 - 64bit Production

Is it the view ?
SQL> select * from dba_views where view_name like '%VW%2%';
no rows selected

Is it the synonym ?
SQL> select * from SYS.DBA_SYNONYMS where synonym_name like '%VW%2%' ;
no rows selected

What is the object ?
SQL> select * from dba_objects where object_name like '%VW%2%';
no rows selected

SQL> select * from sys.obj$ where name like '%VW%2%';
no rows selected


Obvious, there is no such view in the dictionary !
What's the hell ? Where the view VW_TE_2 was taken from ? 


Step 3: Let look VW_TE_2 in the support.oracle.com and in Internet


Great! One of my friends have wrote some post with VW_TE_2 view:
https://iusoltsev.wordpress.com/2014/06/25/table-expansion-features/

This is the Table Expansion feature:  https://blogs.oracle.com/optimizer/optimizer-transformations:-table-expansion

This feature is applicable for queries on partitioned tables which have local indexes.
Oracle can have access to table rows via index or directly to table using full table/partition scan.
And during parse Optimizer decide which path is better.
In some cases when the query benefits from index access path then Oracle can take the data from the index and not touch the table rows.
Index-only access path, "Fast Full Index Scan" for example.

And what to do if our query benefits from index-only access, but some index partitions are in UNUSABLE state ?
Table expansion take place here !
It is just my case.

Optimizer divide one query to two similar sub-queries.
One sub-query is go to table rows (not use index) and scan particular partitions.
Other sub-query is using index (local partitions which are in USABLE state).
As you can see in my post above.

Look at the last two columns of plan table. These columns show Pstart Pstop partitons of the table:
-----------------
| Pstart| Pstop |
-----------------
|       |       |
|       |       |
|       |       |
|       |       |
|     1 |  3072 |
|     1 |  3072 |
|  3073 |  3437 |
|  3073 |  3437 |
-----------------


As you can see the one sub-query scans the 1-3072 partitions, and 2nd sub-query scans 3073-3437 partitions.

Step 4: how to disable TE ?

If my diagnose about TE feature is correct, then after disabling this feature the long-running query will go fast.
It will confirm my diagnose.

Internet helped to find two hints:

-  /*+ opt_param('_optimizer_table_expansion', 'false') */ - will disable TE
-  /*+ EXPAND_TABLE(tab_alias) */   - will force TE

The query has 3 form of predicates:
- date '2015-01-01'
- trunc(sysdate-1112) ( for today 18-JAN-2018 we use trunc(sysdate-1113) and so on...)
- to_date('01.01.2015','dd.mm.yyyy')


In our case we have an issue. The syntax " date '2015-01-01' " and " trunc(sysdate-1112) " prevent the table expansion feature:

- date '2015-01-01'                  - no TE and fast plan
- trunc(sysdate-1112)                - no TE and fast plan
- to_date('01.01.2015','dd.mm.yyyy') - TE take place and wrong plan.



Therefore we can make two experiments:
- disabling TE for bad query will lead to good plan and short time
- forcing TE for good queries will lead to bad plan and long time


SQL> set lines 999 pages 99
SQL> set timing on
SQL> set autot on
SQL> select /*+ opt_param('_optimizer_table_expansion', 'false') */  min(a.ENTRYDATE) from ORDERS_BASE a where a.ENTRYDATE < to_date('01.01.2015','dd.mm.yyyy');

MIN(A.ENT
---------
10-JAN-06

Elapsed: 00:00:00.04

Execution Plan
----------------------------------------------------------
Plan hash value: 2553418393

----------------------------------------------------------------------------------------------------------------
| Id  | Operation                        | Name        | Rows  | Bytes | Cost (%CPU)| Time     | Pstart| Pstop |
----------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                 |             |     1 |     8 |   309K (30)| 00:00:08 |       |       |
|   1 |  PARTITION RANGE ITERATOR MIN/MAX|             |     1 |     8 |            |          |     1 |  3437 |
|   2 |   SORT AGGREGATE                 |             |     1 |     8 |            |          |       |       |
|   3 |    TABLE ACCESS STORAGE FULL     | ORDERS_BASE |  9195M|    68G|   309K (30)| 00:00:08 |     1 |  3437 |
----------------------------------------------------------------------------------------------------------------


Statistics
----------------------------------------------------------
          0  recursive calls
          2  db block gets
         19  consistent gets
         13  physical reads
          0  redo size
        555  bytes sent via SQL*Net to client
        552  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
          1  rows processed

Great, be obtain the good plan and short time !

Try aggravate the good plan:

SQL> select /*+ EXPAND_TABLE(a) */  min(a.ENTRYDATE) from ORDERS_BASE a where a.ENTRYDATE < date '2015-01-01';

MIN(A.ENT
---------
10-JAN-06

Elapsed: 00:13:29.91

Execution Plan
----------------------------------------------------------
Plan hash value: 2354560326

-------------------------------------------------------------------------------------------------------------
| Id  | Operation                     | Name        | Rows  | Bytes | Cost (%CPU)| Time     | Pstart| Pstop |
-------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT              |             |     1 |     9 |   347K (43)| 00:00:09 |       |       |
|   1 |  SORT AGGREGATE               |             |     1 |     9 |            |          |       |       |
|   2 |   VIEW                        | VW_TE_1     |  9195M|    77G|   347K (43)| 00:00:09 |       |       |
|   3 |    UNION-ALL                  |             |       |       |            |          |       |       |
|   4 |     PARTITION RANGE ITERATOR  |             |  6615M|   123G|   240K (43)| 00:00:07 |     1 |  3072 |
|   5 |      TABLE ACCESS STORAGE FULL| ORDERS_BASE |  6615M|   123G|   240K (43)| 00:00:07 |     1 |  3072 |
|   6 |     PARTITION RANGE ITERATOR  |             |  2579M|    48G|   106K (43)| 00:00:03 |  3073 |  3437 |
|   7 |      TABLE ACCESS STORAGE FULL| ORDERS_BASE |  2579M|    48G|   106K (43)| 00:00:03 |  3073 |  3437 |
-------------------------------------------------------------------------------------------------------------


Statistics
----------------------------------------------------------
       1068  recursive calls
       3206  db block gets
   17684816  consistent gets
   17666603  physical reads
        240  redo size
        555  bytes sent via SQL*Net to client
        552  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
          1  rows processed


Yes! After we forced the TE the fast query run the very long time !



Monday, November 13, 2017

How to deinstall Oracle Database software

Today i need to clean one Exadata from 12.1 software.
It is the rare operation, so i decided to record it.

The documentation says about runInstaller and deinstall .
And i decided to try runInstaller at first.

But no matter how i tried the runInstaller it always want response file or X Server:

[oracle@edbadm01 dbhome_1]$ ./oui/bin/runInstaller -deinstall -home /u01/app/oracle/product/12.1.0.2/dbhome_1
Starting Oracle Universal Installer...

Checking swap space: must be greater than 500 MB.   Actual 24575 MB    Passed
Checking monitor: must be configured to display at least 256 colors
    >>> Could not execute auto check for display colors using command /usr/bin/xdpyinfo. Check if the DISPLAY variable is set.    Failed <<<<

Some requirement checks failed. You must fulfill these requirements before

continuing with the installation,

Continue? (y/n) [n] y


>>> Ignoring required pre-requisite failures. Continuing...
Preparing to launch Oracle Universal Installer from /tmp/OraInstall2017-11-13_02-53-04PM. Please wait ...
DISPLAY not set. Please set the DISPLAY and try again.
Depending on the Unix Shell, you can use one of the following commands as examples to set the DISPLAY environment variable:
- For csh:              % setenv DISPLAY 192.168.1.128:0.0
- For sh, ksh and bash:     $ DISPLAY=192.168.1.128:0.0; export DISPLAY
Use the following command to see what shell is being used:
    echo $SHELL
Use the following command to view the current DISPLAY environment variable setting:
    echo $DISPLAY
- Make sure that client users are authorized to connect to the X Server.
To enable client users to access the X Server, open an xterm, dtterm or xconsole as the user that started the session and type the following command:
% xhost +
To test that the DISPLAY environment variable is set correctly, run a X11 based program that comes with the native operating system such as 'xclock':
    % <full path to xclock.. see below>
If you are not able to run xclock successfully, please refer to your PC-X Server or OS vendor for further assistance.
Typical path for xclock: /usr/X11R6/bin/xclock
[oracle@edbadm01 dbhome_1]$


[oracle@edbadm01 dbhome_1]$ ./oui/bin/runInstaller -deinstall -home /u01/app/oracle/product/12.1.0.2/dbhome_1 -silent -ignoreSysPrereqs 
Starting Oracle Universal Installer...

Checking swap space: must be greater than 500 MB.   Actual 24575 MB    Passed
Preparing to launch Oracle Universal Installer from /tmp/OraInstall2017-11-13_02-53-44PM. Please wait ...[oracle@edbadm01 dbhome_1]$ Oracle Universal Installer, Version 12.1.0.2.0 Production
Copyright (C) 1999, 2014, Oracle. All rights reserved.

OUI-10202:No response file is specified for this session. A silent session requires inputs from a response file or from the command line. Specify the response file and re-run the installer.



This way i realized the runInstaller is not my way.

The another tool is deinstall.
Look, how it works:

[oracle@edbadm01 oracle]$ cd $OH/deinstall

[oracle@edbadm01 deinstall]$ ./deinstall -h
Checking for required files and bootstrapping ...
Please wait ...
Unknown option: -h

deinstall
               [ -silent <-checkonly | -paramfile <complete path of input parameter properties file>> ]
               [ -checkonly ]
               [ -local ]
               [ -paramfile <complete path of input parameter properties file> ]
               [ -params <name1=value[ name2=value name3=value ...]> ]
               [ -o <complete path of directory for saving files> ]
               [ -tmpdir <complete path of temporary directory to use> ]
               [ -logdir <complete path of log directory to use> ]
               [ -help : Display this help message. ]


[oracle@edbadm01 deinstall]$ ./deinstall

Checking for required files and bootstrapping ...
Please wait ...
Location of logs /u01/app/oraInventory/logs/

############ ORACLE DECONFIG TOOL START ############


######################### DECONFIG CHECK OPERATION START #########################
## [START] Install check configuration ##


Checking for existence of the Oracle home location /u01/app/oracle/product/12.1.0.2/dbhome_1
Oracle Home type selected for deinstall is: Oracle Real Application Cluster Database
Oracle Base selected for deinstall is: /u01/app/oracle
Checking for existence of central inventory location /u01/app/oraInventory
Checking for existence of the Oracle Grid Infrastructure home /u01/app/12.2.0.1/grid
The following nodes are part of this cluster: edbadm01,edbadm02
Active Remote Nodes are edbadm02
Checking for sufficient temp space availability on node(s) : 'edbadm01,edbadm02'

## [END] Install check configuration ##


Network Configuration check config START

Network de-configuration trace file location: /u01/app/oraInventory/logs/netdc_check2017-11-13_03-57-25-PM.log

Network Configuration check config END

Database Check Configuration START

Database de-configuration trace file location: /u01/app/oraInventory/logs/databasedc_check2017-11-13_03-57-26-PM.log

Use comma as separator when specifying list of values as input

Specify the list of database names that are configured in this Oracle home []:
Database Check Configuration END
Oracle Configuration Manager check START
OCM check log file location : /u01/app/oraInventory/logs//ocm_check6085.log
Oracle Configuration Manager check END

######################### DECONFIG CHECK OPERATION END #########################


####################### DECONFIG CHECK OPERATION SUMMARY #######################
Oracle Grid Infrastructure Home is: /u01/app/12.2.0.1/grid
The following nodes are part of this cluster: edbadm01,edbadm02
Active Remote Nodes are edbadm02
The cluster node(s) on which the Oracle home deinstallation will be performed are:edbadm01,edbadm02
Oracle Home selected for deinstall is: /u01/app/oracle/product/12.1.0.2/dbhome_1
Inventory Location where the Oracle home registered is: /u01/app/oraInventory
Checking the config status for CCR
edbadm01 : Oracle Home exists with CCR directory, but CCR is not configured
edbadm02 : Oracle Home exists with CCR directory, but CCR is not configured
CCR check is finished
Do you want to continue (y - yes, n - no)? [n]: y
A log of this session will be written to: '/u01/app/oraInventory/logs/deinstall_deconfig2017-11-13_02-57-19-PM.out'
Any error messages from this session will be written to: '/u01/app/oraInventory/logs/deinstall_deconfig2017-11-13_02-57-19-PM.err'

######################## DECONFIG CLEAN OPERATION START ########################
Database de-configuration trace file location: /u01/app/oraInventory/logs/databasedc_clean2017-11-13_03-58-34-PM.log

Network Configuration clean config START

Network de-configuration trace file location: /u01/app/oraInventory/logs/netdc_clean2017-11-13_03-58-34-PM.log

De-configuring Listener configuration file on all nodes...
Listener configuration file de-configured successfully.

De-configuring Naming Methods configuration file on all nodes...
Naming Methods configuration file de-configured successfully.

De-configuring Local Net Service Names configuration file on all nodes...
Local Net Service Names configuration file de-configured successfully.

De-configuring Directory Usage configuration file on all nodes...
Directory Usage configuration file de-configured successfully.

De-configuring backup files on all nodes...
Backup files de-configured successfully.

The network configuration has been cleaned up successfully.

Network Configuration clean config END

Oracle Configuration Manager clean START
OCM clean log file location : /u01/app/oraInventory/logs//ocm_clean6085.log
Oracle Configuration Manager clean END

######################### DECONFIG CLEAN OPERATION END #########################


####################### DECONFIG CLEAN OPERATION SUMMARY #######################
Cleaning the config for CCR
As CCR is not configured, so skipping the cleaning of CCR configuration
CCR clean is finished
#######################################################################


############# ORACLE DECONFIG TOOL END #############

Using properties file /tmp/deinstall2017-11-13_02-57-10PM/response/deinstall_2017-11-13_02-57-19-PM.rsp
Location of logs /u01/app/oraInventory/logs/

############ ORACLE DEINSTALL TOOL START ############


####################### DEINSTALL CHECK OPERATION SUMMARY #######################
A log of this session will be written to: '/u01/app/oraInventory/logs/deinstall_deconfig2017-11-13_02-57-19-PM.out'
Any error messages from this session will be written to: '/u01/app/oraInventory/logs/deinstall_deconfig2017-11-13_02-57-19-PM.err'

######################## DEINSTALL CLEAN OPERATION START ########################
## [START] Preparing for Deinstall ##
Setting LOCAL_NODE to edbadm01
Setting REMOTE_NODES to edbadm02
Setting CLUSTER_NODES to edbadm01,edbadm02
Setting CRS_HOME to false
Setting oracle.installer.invPtrLoc to /tmp/deinstall2017-11-13_02-57-10PM/oraInst.loc
Setting oracle.installer.local to false

## [END] Preparing for Deinstall ##

Setting the force flag to false
Setting the force flag to cleanup the Oracle Base
Oracle Universal Installer clean START

Detach Oracle home '/u01/app/oracle/product/12.1.0.2/dbhome_1' from the central inventory on the local node : Done

Delete directory '/u01/app/oracle/product/12.1.0.2/dbhome_1' on the local node : Done

The Oracle Base directory '/u01/app/oracle' will not be removed on local node. The directory is in use by Oracle Home '/u01/app/oracle/product/12.2.0.1/dbhome_1'.

SEVERE:Remote 'DetachHome' failed on nodes: 'edbadm02'. Refer to '/u01/app/oraInventory/logs/Cleanup2017-11-13_03-58-36-PM.log' for details.
It is recommended that the following command needs to be manually run on the failed nodes:
 /u01/app/oracle/product/12.1.0.2/dbhome_1/oui/bin/platform/linux64/runInstaller -detachHome -noClusterEnabled ORACLE_HOME=/u01/app/oracle/product/12.1.0.2/dbhome_1 "INVENTORY_LOCATION=/u01/app/oraInventory" -invPtrLoc "/tmp/deinstall2017-11-13_02-57-10PM/oraInst.loc" LOCAL_NODE=<node on which command is to be run>.
Please refer 'DetachHome' logs under central inventory of remote nodes where failure occurred for more details.
Detach Oracle home '/u01/app/oracle/product/12.1.0.2/dbhome_1' from the central inventory on the remote nodes 'edbadm02' : Done

Delete directory '/u01/app/oracle/product/12.1.0.2/dbhome_1' on the remote nodes 'edbadm02' : Done

Delete directory '/u01/app/oracle' on the remote nodes 'edbadm02' : Failed <<<<

The directory '/u01/app/oracle' could not be deleted on the nodes 'edbadm02'.
Oracle Universal Installer cleanup completed with errors.

Oracle Universal Installer clean END


## [START] Oracle install clean ##

Clean install operation removing temporary directory '/tmp/deinstall2017-11-13_02-57-10PM' on node 'edbadm01'
Clean install operation removing temporary directory '/tmp/deinstall2017-11-13_02-57-10PM' on node 'edbadm02'

## [END] Oracle install clean ##


######################### DEINSTALL CLEAN OPERATION END #########################


####################### DEINSTALL CLEAN OPERATION SUMMARY #######################
Successfully detached Oracle home '/u01/app/oracle/product/12.1.0.2/dbhome_1' from the central inventory on the local node.
Successfully deleted directory '/u01/app/oracle/product/12.1.0.2/dbhome_1' on the local node.
Successfully detached Oracle home '/u01/app/oracle/product/12.1.0.2/dbhome_1' from the central inventory on the remote nodes 'edbadm02'.
Successfully deleted directory '/u01/app/oracle/product/12.1.0.2/dbhome_1' on the remote nodes 'edbadm02'.
Failed to delete directory '/u01/app/oracle' on the remote nodes 'edbadm02'.
Oracle Universal Installer cleanup completed with errors.

Run 'rm -r /opt/ORCLfmap' as root on node(s) 'edbadm02' at the end of the session.
Oracle deinstall tool successfully cleaned up temporary directories.
#######################################################################


############# ORACLE DEINSTALL TOOL END #############

[oracle@edbadm01 deinstall]$


Overall:
- it works in text terminal and don't use X Server
- it don't require parameter file
- it is simple: you should go to $OH/deinstall and run ./deinstall command 
- in the RAC environment it remove software from all RAC nodes !

I think it great tool !

Tuesday, November 17, 2015

max_string_size="EXTENDED" and ORA-14415: index in partially dropped state

We created the 12.1.0.2.11 non-CDB RAC DB on the Exadata.

It had worked well until we set  max_string_size="EXTENDED" and  run  utl32k.sql
according to
How to Increase the Maximum Size of VARCHAR2, NVARCHAR2, and RAW Columns in 12C Database using MAX_STRING_SIZE ? (Doc ID 1570297.1)

--------------------------------------------------------------------------------
[oracle@dc1exadbadm01 ~]$ sql

SQL*Plus: Release 12.1.0.2.0 Production on Tue Oct 20 18:05:55 2015

Copyright (c) 1982, 2014, Oracle.  All rights reserved.


Connected to:
Oracle Database 12c Enterprise Edition Release 12.1.0.2.0 - 64bit Production
With the Partitioning, Real Application Clusters, Automatic Storage Management, OLAP,
Advanced Analytics and Real Application Testing options

SQL> shutdown immediate
Database closed.
Database dismounted.
ORACLE instance shut down.
SQL> startup upgrade
ORACLE instance started.

Total System Global Area 2.5770E+10 bytes
Fixed Size                  6870952 bytes
Variable Size            9730787416 bytes
Database Buffers         1.5972E+10 bytes
Redo Buffers               60235776 bytes
Database mounted.
Database opened.

SQL> @?/rdbms/admin/utl32k.sql

Session altered.

DOC>#######################################################################
DOC>#######################################################################
DOC>   The following statement will cause an "ORA-01722: invalid number"
DOC>   error if the database has not been opened for UPGRADE.
DOC>
DOC>   Perform a "SHUTDOWN ABORT"  and
DOC>   restart using UPGRADE.
DOC>#######################################################################
DOC>#######################################################################
DOC>#

no rows selected

DOC>#######################################################################
DOC>#######################################################################
DOC>   The following statement will cause an "ORA-01722: invalid number"
DOC>   error if the database does not have compatible >= 12.0.0
DOC>
DOC>   Set compatible >= 12.0.0 and retry.
DOC>#######################################################################
DOC>#######################################################################
DOC>#

PL/SQL procedure successfully completed.


Session altered.


2 rows updated.


Commit complete.


System altered.


PL/SQL procedure successfully completed.


Commit complete.


System altered.


Session altered.

DECLARE
*
ERROR at line 1:
ORA-14415: index in partially dropped state, submit DROP INDEX
ORA-06512: at line 121


[oracle@dc1exadbadm01 ~]$

[oracle@dc1exadbadm01 ~]$ sqlplus / as sysdba

Connected to an idle instance.

SQL> startup nomount
ORACLE instance started.

Total System Global Area 2.5770E+10 bytes
Fixed Size                  6870952 bytes
Variable Size            9730787416 bytes
Database Buffers         1.5972E+10 bytes
Redo Buffers               60235776 bytes
SQL> alter database mount;

Database altered.

SQL> alter database open;
alter database open
*
ERROR at line 1:
ORA-01092: ORACLE instance terminated. Disconnection forced
ORA-14695: MAX_STRING_SIZE migration is incomplete
Process ID: 41850
Session ID: 282 Serial number: 37233





In "startup open" you will give the error.

SQL> alter database open;
alter database open
*
ERROR at line 1:
ORA-01092: ORACLE instance terminated. Disconnection forced
ORA-14695: MAX_STRING_SIZE migration is incomplete
Process ID: 119999
Session ID: 282 Serial number: 61461
 
So use "startup migrate":

SQL> startup migrate
--------------------------------------------------------------------------------

The solution:  drop bad indexes and run utl32k.sql again.

Bad indexes you can find via table name:
set     event '14415 trace name errorstack level 3'   
and   repeate the utl32k.sql

SQL> alter session set tracefile_identifier='14415error';
SQL> alter session set events '10046 trace name context forever, level 4';
SQL> alter session set events '14415 trace name errorstack level 3';
SQL> @?/rdbms/admin/utl32k.sql


In the trace file obtained you can find the TABLE name on which utl32k.sql make error.


I did the trace and found the error in it :

----- Error Stack Dump -----
ORA-14415: index in partially dropped state, submit DROP INDEX
----- Current SQL Statement for this session (sql_id=dz5k9x249a04x) -----
ALTER TABLE "PREODS_09_01"."LTB_OUT_SMS_V_RFH" MODIFY ("DEAL_LOAN_ID" VARCHAR2(4000 CHAR))
----- PL/SQL Stack -----
----- PL/SQL Call Stack -----
object line object
handle number name
0x63ffb88e0 121 anonymous block 

 ----- Call Stack Trace -----

and dropped the bad index :

SQL> select INDEX_OWNER,INDEX_NAME,COLUMN_LENGTH,CHAR_LENGTH from dba_ind_columns where TABLE_OWNER='PREODS_09_01' and TABLE_NAME='LTB_OUT_SMS_V_RFH' and COLUMN_NAME='DEAL_LOAN_ID';

INDEX_OWNER 
INDEX_NAME             COLUMN_LENGTH CHAR_LENGTH  
------------ ---------------------- ------------- -----------
PREODS_09_01 PK_LTB_OUT_SMS_V_RFH_2          4000        4000

SQL> drop index PREODS_09_01.PK_LTB_OUT_SMS_V_RFH_2;

Index dropped.

SQL> @?/rdbms/admin/utl32k.sql



We droped indexes on this table and run utl32k.sql again.
After successful utl32k.sql we created these indexes back.

There is difficult to recognize the error in the trace.
The next obstruction was on the materialized view, but there were no clear message:

ANONYMOUS BLOCK:
library unit=63f8a20a8 line=89 opcode=219 static link=0 scope=0
FP=0x7f2e742a2e60 PC=0x62fff1bd8 Page=0 AP=(nil) ST=0x7f2e742a4598
...
7F2E742A2EE0 0008001B 00000000 525F5522 524F5045 [........"U_REPOR]
7F2E742A2EF0 222E2254 535F564D 5F504554 41574F54 [T"."MV_STEP_TOWA]
7F2E742A2F00 49225344 49544143 22224E4F 22524444 [DS"ICATION""DDR"]
7F2E742A2F10 45224F46 00002222 00000000 00000000 [FO"E""..........]

I decided to drop this MV and it was right !

Now  utl32k.sql finished without errors. 



For advanced users:

In the trace file you can find the PL/SQL block which is the core of utl32k.sql :

PARSING IN CURSOR #140460508916688 len=4473 dep=0 uid=0 oct=47 lid=0 tim=199344978636 hv=1486675569 ad='63ff20400' sqlid='6d8xyc9c9trmj'
DECLARE
  cursor candidate_columns is
    select u.name UNAME,      -- 45593 rows selected
           o.name TNAME,
           o.obj# OBJ#,
           DECODE(c.type#,
                    1, DECODE(c.charsetform, 2, 'NVARCHAR2', 'VARCHAR2'),
                   23, 'RAW') DATA_TYPE,
           c.spare3 DATA_LEN,
           decode(bitand(c.property, 8388608), 0, 'BYTE', 'CHAR') CHAR_USED,
           c.name CNAME,
           c.intcol# INTCOL#,
           decode(c.segcol#, 0, 'Y', 'N') VIRTUAL,
           decode(bitand(t.flags, 262144), 0, 'N', 'Y') MV
     from sys.tab$ t, sys.obj$ o, sys.user$ u, sys.col$ c
     where t.obj# = o.obj# and o.owner# = u.user# and c.obj# = t.obj#
       and bitand(o.flags, 196608) = 0               -- not a common object
       and (c.segcol# = 0 or                      -- virtual column
            bitand(c.property, 8388608) != 0 or   -- CHAR length semantics
            bitand(t.flags, 262144) != 0)         -- materialized view tbl
       and ( (c.type# = 1  and c.length >= 4000) or
             (c.type# = 23 and c.length >= 2000) );
  schema_table varchar2(512);         /* "SCHEMA"."TABLE" for SQL generation */
  data_type    varchar2(128);
  cur          integer;
  col_cnt      integer;
  len          integer;
  off          integer;
  discard      integer;
  str          varchar2(32767);
  strlen       integer;
  col_desc     DBMS_SQL.DESC_TAB;
  col_expr     clob;
  sqlstr       clob;
  long_chunk_sz constant int := 256;
BEGIN
  cur := DBMS_SQL.OPEN_CURSOR;
  for target in candidate_columns loop
    schema_table := DBMS_ASSERT.ENQUOTE_NAME(target.UNAME, FALSE) || '.'
                 || DBMS_ASSERT.ENQUOTE_NAME(target.TNAME, FALSE);
    IF (target.virtual = 'Y') THEN
      DBMS_SQL.PARSE(cur,
        'select deflength, default$ from col$ where obj# = :1 and name = :2',
        DBMS_SQL.NATIVE);
      DBMS_SQL.BIND_VARIABLE(cur, ':1', target.obj#);
      DBMS_SQL.BIND_VARIABLE(cur, ':2', target.cname);
      DBMS_SQL.DEFINE_COLUMN(cur, 1, len);
      DBMS_SQL.DEFINE_COLUMN_LONG(cur, 2);
      discard := DBMS_SQL.EXECUTE(cur);
      discard := DBMS_SQL.FETCH_ROWS(cur);
      DBMS_SQL.COLUMN_VALUE(cur, 1, len);
      col_expr := '';
      off := 0;
      WHILE len > 0 LOOP
        DBMS_SQL.COLUMN_VALUE_LONG(cur, 2, long_chunk_sz, off, str, strlen);
        col_expr := col_expr || str;
        off := off + strlen;
        len := len - strlen;
      END LOOP;
      /* Bug 16237862: use an alias for the column to avoid column
       * name overflow errors in dbms_sql.describe_columns.
       */
      sqlstr := 'SELECT ' || col_expr || ' expr FROM ' || schema_table;
      DBMS_SQL.PARSE(cur, sqlstr, DBMS_SQL.NATIVE);
      DBMS_SQL.DESCRIBE_COLUMNS(cur, col_cnt, col_desc);
      data_type := target.DATA_TYPE || '(' || col_desc(1).col_max_len || ')';
    ELSIF (target.mv = 'Y') THEN
      DBMS_SQL.PARSE(cur,
        'select sumtextlen, sumtext from sys.sum$ where containerobj# = :1',
        DBMS_SQL.NATIVE);
      DBMS_SQL.BIND_VARIABLE(cur, ':1', target.obj#);
      DBMS_SQL.DEFINE_COLUMN(cur, 1, len);
      DBMS_SQL.DEFINE_COLUMN_LONG(cur, 2);
      discard := DBMS_SQL.EXECUTE(cur);
      discard := DBMS_SQL.FETCH_ROWS(cur);
      DBMS_SQL.COLUMN_VALUE(cur, 1, len);
      sqlstr := '';
      off := 0;
      WHILE len > 0 LOOP
        DBMS_SQL.COLUMN_VALUE_LONG(cur, 2, long_chunk_sz, off, str, strlen);
        sqlstr := sqlstr || str;
        off := off + strlen;
        len := len - strlen;
      END LOOP;
      execute immediate
        'alter session set current_schema = '
        || DBMS_ASSERT.ENQUOTE_NAME(target.UNAME, FALSE);
      DBMS_SQL.PARSE(cur, sqlstr, DBMS_SQL.NATIVE);
      DBMS_SQL.DESCRIBE_COLUMNS(cur, col_cnt, col_desc);
      data_type := target.DATA_TYPE
                || '(' || col_desc(target.intcol#).col_max_len || ')';
      execute immediate
       'alter session set current_schema = SYS';
    ELSE
      IF (target.DATA_TYPE = 'NVARCHAR2') THEN
        data_type := target.DATA_TYPE
                  || '(' || target.DATA_LEN || ')';
      ELSE
        data_type := target.DATA_TYPE
                  || '(' || target.DATA_LEN || ' ' || target.CHAR_USED || ')';
      END IF;
    END IF;
    sqlstr := 'ALTER TABLE ' || schema_table
           || ' MODIFY (' || DBMS_ASSERT.ENQUOTE_NAME(target.CNAME, FALSE)
           || ' ' || data_type || ')';

    dbms_output.put_line(sqlstr);
    EXECUTE IMMEDIATE sqlstr;
  end loop;
  DBMS_SQL.CLOSE_CURSOR(cur);
END;


You can add DBMS_OUTPUT.PUT_LINE(sqlstr) to this block in order to find the error TABLE, before the bold lines.


Good troubleshootings to you !

# ocrconfig -add +DATA PROT-30: The Oracle Cluster Registry location to be added is not usable. PROC-50: The Oracle Cluster Registry locatio...