prepare phase hangs

classic Classic list List threaded Threaded
7 messages Options
Reply | Threaded
Open this post in threaded view
|

prepare phase hangs

satish
Dear Erman,

Our environment R12.2.5 2 node shared appltop
2 node RAC

adop.log shows:

[EVENT]     Checking AD-TXK codelevel.
    [PROCEDURE] [START 2023/05/11 15:47:38] Looking for ad/txk codelevel change
    AD-TXK codelevel has not changed.
    [PROCEDURE] [END   2023/05/11 15:47:38] Looking for ad/txk codelevel change

[EVENT]     Checking for pending cleanup actions.
    [PROCEDURE] [START 2023/05/11 15:47:38] Checking for pending cleanup actions
    [EVENT]     No pending cleanup actions found.
    [PROCEDURE] [END   2023/05/11 15:47:38] Checking for pending cleanup actions

[EVENT]     Validating database is ready to prepare.
    [PROCEDURE] [START 2023/05/11 15:47:38] Running database checks
    [STATEMENT] Deleting rows from table AD_PATCHES_TABLE
    [STATEMENT] Performing database sanity checks.
    [STATEMENT] Checking if edition-enabled users exist.
    [PROCEDURE] [END   2023/05/11 15:47:38] Running database checks

[EVENT]     Generating report for key tablespaces.
    [PROCEDURE] [START 2023/05/11 15:47:38] Generating tablespaces report
    [PROCEDURE] [START 2023/05/11 15:47:39] Generating report to display the status of important tablespaces. (ie. free space)
    [STATEMENT] Report: /u01/UATAPPS/fs2/EBSapps/appl/ad/12.0.0/sql/ADZDSHOWTS.sql---->looks like stuck here.

No blocking session

Backend session status:
SQL> select sid,serial#,last_call_et/60,event,ROW_WAIT_OBJ# from gv$session where sql_id='8w2c6js39gc35';


       616      48293      180.8333333 db file sequential read                                                     -1

SQL> select sql_text from gv$sqltext where sql_id='8w2c6js39gc35' order by piece;

SQL_TEXT
----------------------------------------------------------------
SELECT     df.tablespace_name   , round((df.total_space/(1024*10
24*1024)),2) total_space   , round(((df.total_space - fs.free_sp
ace)/(1024*1024*1024)),2) used_space   , round((fs.free_space/(1
024*1024*1024)),2) free_space   , round(((df.total_space-fs.free
_space) / df.total_space)*100, 2) PCT_USED FROM     ( SELECT tab
lespace_name, SUM(bytes) TOTAL_SPACE       FROM dba_data_files
     GROUP BY tablespace_name) df   , ( SELECT tablespace_name,
SUM(bytes) FREE_SPACE       FROM dba_free_space       GROUP BY t
ablespace_name) fs WHERE       df.tablespace_name = fs.tablespac
e_name(+)   and df.tablespace_name in         ('SYSTEM', 'APPS_T
S_SEED', 'APPS_TS_TX_DATA', 'APPS_TS_TX_IDX') ORDER BY fs.tables
pace_name


12 rows selected.



and we veried the script,it spools with a file name adzdshowts.out,below we can see it is in 0 size.


No errors in logs:
===================

[appluat@erpuatapp01 erpuatapp01]$ pwd
/u01/UATAPPS/fs_ne/EBSapps/log/adop/118/20230511_1542929
[appluat@erpuatapp01 20230511_154229]$ cd prepare/
[appluat@erpuatapp01 prepare]$ ls -lrt
total 12
drwxr-xr-x 4 appluat dba 3864 May 11 15:46 validate
drwxr-xr-x 6 appluat dba 3864 May 11 15:47 erpuatapp01
drwxr-xr-x 2 appluat dba 3864 May 11 15:48 erpuatapp02
[appluat@erpuatapp01 prepare]$ cd erpuatapp01
[appluat@erpuatapp01 erpuatapp01]$ ls -lrt
total 48
drwxr-xr-x 3 appluat dba  3864 May 11 15:44 TXK_EVAL_prepare_Thu_May_11_15_44_02_2023
drwxr-xr-x 3 appluat dba  3864 May 11 15:44 TXK_EVAL_prepare_Thu_May_11_15_44_56_2023
drwxr-xr-x 3 appluat dba  3864 May 11 15:46 TXK_EVAL_prepare_Thu_May_11_15_46_28_2023
drwxr-xr-x 2 appluat dba  3864 May 11 15:47 TXK_SANITY_filesystemcheck
-rw-r--r-- 1 appluat dba  5237 May 11 15:47 adConfigChanges.log
-rw-r--r-- 1 appluat dba 12122 May 11 15:47 adop.log
-rw-r--r-- 1 appluat dba     0 May 11 15:47 adzdshowts.out-------------------------------------------------->This one
[appluat@erpuatapp01 erpuatapp01]$ pwd
/u01/UATAPPS/fs_ne/EBSapps/log/adop/118/20230511_154229/prepare/erpuatapp01
[appluat@erpuatapp01 erpuatapp01]$


When we run the tablespace query,it runs immediately. Not sure why prepare phase stops at this stage. Any suggestions please? Any connection issue?


Thanks,
Satish
Reply | Threaded
Open this post in threaded view
|

Re: prepare phase hangs

ErmanArslansOracleBlog
Administrator
It is just checking the tablespace sizes.. Weird. What is the db "wait" of that session that belongs to the "adop prepare run"?  
Reply | Threaded
Open this post in threaded view
|

Re: prepare phase hangs

satish
Thanks for the update.

SQL> select sql_id,sid,serial#,status,module,program,last_call_Et/60,event from gv$session where status='ACTIVE' and type='USER';

 

SQL_ID               SID    SERIAL# STATUS   MODULE                         PROGRAM                                          LAST_CALL_ET/60
------------- ---------- ---------- -------- ------------------------------ ------------------------------------------------ ---------------
EVENT
----------------------------------------------------------------

 

8w2c6js39gc35        624      40559 ACTIVE   SQL*Plus                       sqlplus@erpuatapp01.ttd.com (TNS V1-V3)               270.333333
db file sequential read


We ran dictionary stats for sys user in PDB,Do we need to run for CDB as well?


PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
SQL_ID  8w2c6js39gc35, child number 0
-------------------------------------
SELECT     df.tablespace_name   , round((df.total_space/(1024*1024*1024)
),2) total_space   , round(((df.total_space -
fs.free_space)/(1024*1024*1024)),2) used_space   ,
round((fs.free_space/(1024*1024*1024)),2) free_space   ,
round(((df.total_space-fs.free_space) / df.total_space)*100, 2)
PCT_USED FROM     ( SELECT tablespace_name, SUM(bytes) TOTAL_SPACE
 FROM dba_data_files       GROUP BY tablespace_name) df   , ( SELECT
tablespace_name, SUM(bytes) FREE_SPACE       FROM dba_free_space
GROUP BY tablespace_name) fs WHERE       df.tablespace_name =
fs.tablespace_name(+)   and df.tablespace_name in         ('SYSTEM',
'APPS_TS_SEED', 'APPS_TS_TX_DATA', 'APPS_TS_TX_IDX') ORDER BY
fs.tablespace_name

Plan hash value: 1968685924

------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                                    | Name                    | Rows  | Bytes | Cost (%CPU)| Time     |
------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                             |                         |       |       |    58 (100)|          |
|   1 |  SORT ORDER BY                               |                         |     4 |   152 |    58  (11)| 00:00:01 |
|*  2 |   HASH JOIN OUTER                            |                         |     4 |   152 |    57   (9)| 00:00:01 |
|   3 |    VIEW                                      |                         |     4 |    76 |    17  (18)| 00:00:01 |
|   4 |     HASH GROUP BY                            |                         |     4 |    76 |    17  (18)| 00:00:01 |
|   5 |      VIEW                                    | DBA_DATA_FILES          |    11 |   209 |    16  (13)| 00:00:01 |
|   6 |       UNION-ALL                              |                         |       |       |            |          |
|   7 |        NESTED LOOPS                          |                         |     6 |   822 |     8  (13)| 00:00:01 |
|*  8 |         HASH JOIN                            |                         |     6 |   780 |     8  (13)| 00:00:01 |
|   9 |          MERGE JOIN                          |                         |    25 |  2900 |     3  (34)| 00:00:01 |
|* 10 |           TABLE ACCESS BY INDEX ROWID        | FILE$                   |    25 |   475 |     2   (0)| 00:00:01 |
|  11 |            INDEX FULL SCAN                   | I_FILE1                 |    89 |       |     1   (0)| 00:00:01 |
|* 12 |           SORT JOIN                          |                         |    89 |  8633 |     1 (100)| 00:00:01 |
|* 13 |            FIXED TABLE FULL                  | X$KCCFN                 |    89 |  8633 |     0   (0)|          |
|  14 |          INLIST ITERATOR                     |                         |       |       |            |          |
|  15 |           TABLE ACCESS BY INDEX ROWID        | TS$                     |     4 |    56 |     5   (0)| 00:00:01 |
|* 16 |            INDEX UNIQUE SCAN                 | I_TS1                   |     4 |       |     1   (0)| 00:00:01 |
|* 17 |         FIXED TABLE FIXED INDEX              | X$KCCFE (ind:1)         |     1 |     7 |     0   (0)|          |
|  18 |        NESTED LOOPS                          |                         |     5 |   730 |     8  (13)| 00:00:01 |
|* 19 |         HASH JOIN                            |                         |     7 |   973 |     8  (13)| 00:00:01 |
|  20 |          NESTED LOOPS                        |                         |    48 |  6000 |     3  (34)| 00:00:01 |
|  21 |           MERGE JOIN                         |                         |    65 |  6955 |     3  (34)| 00:00:01 |
|* 22 |            TABLE ACCESS BY INDEX ROWID       | FILE$                   |    64 |   640 |     2   (0)| 00:00:01 |
|  23 |             INDEX FULL SCAN                  | I_FILE1                 |    89 |       |     1   (0)| 00:00:01 |
|* 24 |            SORT JOIN                         |                         |    89 |  8633 |     1 (100)| 00:00:01 |
|* 25 |             FIXED TABLE FULL                 | X$KCCFN                 |    89 |  8633 |     0   (0)|          |
|* 26 |           FIXED TABLE FIXED INDEX            | X$KTFBHC (ind:1)        |     1 |    18 |     0   (0)|          |
|  27 |          INLIST ITERATOR                     |                         |       |       |            |          |
|  28 |           TABLE ACCESS BY INDEX ROWID        | TS$                     |     4 |    56 |     5   (0)| 00:00:01 |
|* 29 |            INDEX UNIQUE SCAN                 | I_TS1                   |     4 |       |     1   (0)| 00:00:01 |
|* 30 |         FIXED TABLE FIXED INDEX              | X$KCCFE (ind:1)         |     1 |     7 |     0   (0)|          |
|  31 |    VIEW                                      |                         |     1 |    19 |    39   (3)| 00:00:01 |
|  32 |     HASH GROUP BY                            |                         |     1 |    19 |    39   (3)| 00:00:01 |
|  33 |      VIEW                                    | DBA_FREE_SPACE          |   200 |  3800 |    38   (0)| 00:00:01 |
|  34 |       UNION-ALL                              |                         |       |       |            |          |
|  35 |        NESTED LOOPS                          |                         |   104 |  3744 |     6   (0)| 00:00:01 |
|  36 |         NESTED LOOPS                         |                         |   104 |  2912 |     6   (0)| 00:00:01 |
|  37 |          INLIST ITERATOR                     |                         |       |       |            |          |
|* 38 |           TABLE ACCESS BY INDEX ROWID        | TS$                     |     1 |    18 |     5   (0)| 00:00:01 |
|* 39 |            INDEX UNIQUE SCAN                 | I_TS1                   |     4 |       |     1   (0)| 00:00:01 |
|* 40 |          TABLE ACCESS CLUSTER                | FET$                    | 10545 |   102K|     1   (0)| 00:00:01 |
|* 41 |         INDEX UNIQUE SCAN                    | I_FILE2                 |     1 |     8 |     0   (0)|          |
|  42 |        NESTED LOOPS                          |                         |    88 |  4312 |     5   (0)| 00:00:01 |
|  43 |         NESTED LOOPS                         |                         |    88 |  3608 |     5   (0)| 00:00:01 |
|  44 |          INLIST ITERATOR                     |                         |       |       |            |          |
|* 45 |           TABLE ACCESS BY INDEX ROWID        | TS$                     |     1 |    27 |     5   (0)| 00:00:01 |
|* 46 |            INDEX UNIQUE SCAN                 | I_TS1                   |     4 |       |     1   (0)| 00:00:01 |
|* 47 |          FIXED TABLE FIXED INDEX             | X$KTFBFE (ind:1)        |   235 |  3290 |     0   (0)|          |
|* 48 |         INDEX UNIQUE SCAN                    | I_FILE2                 |     1 |     8 |     0   (0)|          |
|  49 |        NESTED LOOPS                          |                         |     6 |   408 |     8   (0)| 00:00:01 |
|  50 |         NESTED LOOPS                         |                         |    58 |  3480 |     8   (0)| 00:00:01 |
|  51 |          NESTED LOOPS                        |                         |    11 |   407 |     8   (0)| 00:00:01 |
|  52 |           INLIST ITERATOR                    |                         |       |       |            |          |
|* 53 |            TABLE ACCESS BY INDEX ROWID       | TS$                     |     1 |    27 |     5   (0)| 00:00:01 |
|* 54 |             INDEX UNIQUE SCAN                | I_TS1                   |     4 |       |     1   (0)| 00:00:01 |
|  55 |           TABLE ACCESS BY INDEX ROWID BATCHED| RECYCLEBIN$             |    30 |   300 |     3   (0)| 00:00:01 |
|* 56 |            INDEX RANGE SCAN                  | RECYCLEBIN$_TS          |    30 |       |     1   (0)| 00:00:01 |
|* 57 |          FIXED TABLE FULL                    | X$KTFBUE                |     5 |   115 |     0   (0)|          |
|* 58 |         INDEX UNIQUE SCAN                    | I_FILE2                 |     1 |     8 |     0   (0)|          |
|  59 |        NESTED LOOPS                          |                         |     1 |    51 |    16   (0)| 00:00:01 |
|  60 |         NESTED LOOPS                         |                         |     1 |    43 |    16   (0)| 00:00:01 |
|  61 |          MERGE JOIN CARTESIAN                |                         |     1 |    28 |    15   (0)| 00:00:01 |
|  62 |           INLIST ITERATOR                    |                         |       |       |            |          |
|* 63 |            TABLE ACCESS BY INDEX ROWID       | TS$                     |     1 |    18 |     5   (0)| 00:00:01 |
|* 64 |             INDEX UNIQUE SCAN                | I_TS1                   |     4 |       |     1   (0)| 00:00:01 |
|  65 |           BUFFER SORT                        |                         |    91 |   910 |    10   (0)| 00:00:01 |
|  66 |            TABLE ACCESS FULL                 | RECYCLEBIN$             |    91 |   910 |    10   (0)| 00:00:01 |
|  67 |          TABLE ACCESS CLUSTER                | UET$                    |     1 |    15 |     1   (0)| 00:00:01 |
|* 68 |           INDEX UNIQUE SCAN                  | I_FILE#_BLOCK#          |     1 |       |     1   (0)| 00:00:01 |
|* 69 |         INDEX UNIQUE SCAN                    | I_FILE2                 |     1 |     8 |     0   (0)|          |
|  70 |        NESTED LOOPS                          |                         |     1 |    57 |     3   (0)| 00:00:01 |
|  71 |         NESTED LOOPS                         |                         |     1 |    53 |     2   (0)| 00:00:01 |
|  72 |          TABLE ACCESS FULL                   | NEW_LOST_WRITE_EXTENTS$ |     1 |    26 |     2   (0)| 00:00:01 |
|* 73 |          TABLE ACCESS CLUSTER                | TS$                     |     1 |    27 |     0   (0)|          |
|* 74 |           INDEX UNIQUE SCAN                  | I_TS#                   |     1 |       |     0   (0)|          |
|* 75 |         INDEX RANGE SCAN                     | I_FILE2                 |     1 |     4 |     1   (0)| 00:00:01 |
------------------------------------------------------------------------------------------------------------------------

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

   2 - access("DF"."TABLESPACE_NAME"="FS"."TABLESPACE_NAME")
   8 - access("F"."TS#"="TS"."TS#")
  10 - filter("F"."SPARE1" IS NULL)
  12 - access("FNFNO"="F"."FILE#")
       filter("FNFNO"="F"."FILE#")
  13 - filter(("FNTYP"=4 AND INTERNAL_FUNCTION("CON_ID") AND "INST_ID"=USERENV('INSTANCE') AND "FNNAM" IS NOT
              NULL AND BITAND("FNFLG",4)<>4))
  16 - access(("TS"."NAME"='APPS_TS_SEED' OR "TS"."NAME"='APPS_TS_TX_DATA' OR "TS"."NAME"='APPS_TS_TX_IDX' OR
              "TS"."NAME"='SYSTEM'))
  17 - filter(("FENUM"="F"."FILE#" AND ("CON_ID"=TO_NUMBER(SYS_CONTEXT('USERENV','CON_ID')) OR "CON_ID" IS
              NULL) AND INTERNAL_FUNCTION("CON_ID")))
  19 - access("KTFBHCTSN"="TS"."TS#")
  22 - filter("F"."SPARE1" IS NOT NULL)
  24 - access("FNFNO"="F"."FILE#")
       filter("FNFNO"="F"."FILE#")
  25 - filter(("FNTYP"=4 AND INTERNAL_FUNCTION("CON_ID") AND "INST_ID"=USERENV('INSTANCE') AND "FNNAM" IS NOT
              NULL AND BITAND("FNFLG",4)<>4))
  26 - filter(("FNFNO"="KTFBHCAFNO" AND INTERNAL_FUNCTION("CON_ID")))
  29 - access(("TS"."NAME"='APPS_TS_SEED' OR "TS"."NAME"='APPS_TS_TX_DATA' OR "TS"."NAME"='APPS_TS_TX_IDX' OR
              "TS"."NAME"='SYSTEM'))
  30 - filter(("FENUM"="F"."FILE#" AND ("CON_ID"=TO_NUMBER(SYS_CONTEXT('USERENV','CON_ID')) OR "CON_ID" IS
              NULL) AND INTERNAL_FUNCTION("CON_ID")))
  38 - filter("TS"."BITMAPPED"=0)
  39 - access(("TS"."NAME"='APPS_TS_SEED' OR "TS"."NAME"='APPS_TS_TX_DATA' OR "TS"."NAME"='APPS_TS_TX_IDX' OR
              "TS"."NAME"='SYSTEM'))
  40 - filter("TS"."TS#"="F"."TS#")
  41 - access("F"."TS#"="FI"."TS#" AND "F"."FILE#"="FI"."RELFILE#")
  45 - filter((INTERNAL_FUNCTION("TS"."ONLINE$") AND "TS"."CONTENTS$"=0 AND "TS"."BITMAPPED"<>0 AND
              BITAND("TS"."FLAGS",4503599627370496)<>4503599627370496))
  46 - access(("TS"."NAME"='APPS_TS_SEED' OR "TS"."NAME"='APPS_TS_TX_DATA' OR "TS"."NAME"='APPS_TS_TX_IDX' OR
              "TS"."NAME"='SYSTEM'))
  47 - filter(("TS"."TS#"="KTFBFETSN" AND INTERNAL_FUNCTION("CON_ID")))
  48 - access("KTFBFETSN"="FI"."TS#" AND "KTFBFEFNO"="FI"."RELFILE#")
  53 - filter((INTERNAL_FUNCTION("TS"."ONLINE$") AND "TS"."CONTENTS$"=0 AND "TS"."BITMAPPED"<>0 AND
              BITAND("TS"."FLAGS",4503599627370496)<>4503599627370496))
  54 - access(("TS"."NAME"='APPS_TS_SEED' OR "TS"."NAME"='APPS_TS_TX_DATA' OR "TS"."NAME"='APPS_TS_TX_IDX' OR
              "TS"."NAME"='SYSTEM'))
  56 - access("TS"."TS#"="RB"."TS#")
  57 - filter(("KTFBUESEGFNO"="RB"."FILE#" AND "KTFBUESEGBNO"="RB"."BLOCK#" AND "KTFBUESEGTSN"="RB"."TS#" AND
              INTERNAL_FUNCTION("CON_ID")))
  58 - access("RB"."TS#"="FI"."TS#" AND "KTFBUEFNO"="FI"."RELFILE#")
  63 - filter("TS"."BITMAPPED"=0)
  64 - access(("TS"."NAME"='APPS_TS_SEED' OR "TS"."NAME"='APPS_TS_TX_DATA' OR "TS"."NAME"='APPS_TS_TX_IDX' OR
              "TS"."NAME"='SYSTEM'))
  68 - access("U"."TS#"="RB"."TS#" AND "U"."SEGFILE#"="RB"."FILE#" AND "U"."SEGBLOCK#"="RB"."BLOCK#")
       filter("TS"."TS#"="U"."TS#")
  69 - access("U"."TS#"="FI"."TS#" AND "U"."SEGFILE#"="FI"."RELFILE#")
  73 - filter((INTERNAL_FUNCTION("TS"."ONLINE$") AND INTERNAL_FUNCTION("TS"."NAME") AND
              BITAND("TS"."FLAGS",4503599627370496)=4503599627370496 AND "TS"."CONTENTS$"=0 AND "TS"."BITMAPPED"<>0))
  74 - access("TS"."TS#"="F"."EXTENT_DATAFILE_TSID")
  75 - access("F"."EXTENT_DATAFILE_TSID"="FI"."TS#")

Note
-----
   - this is an adaptive plan


157 rows selected.







We collected stats using below commands in PDB.But no luck

SQL> connect / as sysdba
SQL> exec dbms_stats.gather_dictionary_stats;
SQL> exec dbms_stats.lock_table_stats (null,'X$KCCLH');
SQL> exec dbms_stats.gather_fixed_objects_stats;
SQL> BEGIN DBMS_STATS.GATHER_DATABASE_STATS (gather_sys=>TRUE); END;


Thanks,
Satish
Reply | Threaded
Open this post in threaded view
|

Re: prepare phase hangs

satish
This post was updated on .
In reply to this post by ErmanArslansOracleBlog
Dear Erman,

We have provided the backend session details in previous updates.

Query run immediately in CDB but from PDB,it hangs even from application servers or from database servers. Please guide.

Connected to:
Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production

SQL> SELECT     df.tablespace_name   , round((df.total_space/(1024*1024*1024)
),2) total_space   , round(((df.total_space -
  2    3  fs.free_space)/(1024*1024*1024)),2) used_space   ,
round((fs.free_space/(1024*1024*1024)),2) free_space   ,
round(((df.total_space-fs.free_space) / df.total_space)*100, 2)
PCT_USED FROM     ( SELECT tablespace_name, SUM(bytes) TOTAL_SPACE
 FROM dba_data_files       GROUP BY tablespace_name) df   , ( SELECT
tablespace_name, SUM(bytes) FREE_SPACE       FROM dba_free_space
GROUP BY tablespace_name) fs WHERE       df.tablespace_name =
fs.tablespace_name(+)   and df.tablespace_name in         ('SYSTEM',
'APPS_TS_SEED', 'APPS_TS_TX_DATA', 'APPS_TS_TX_IDX') ORDER BY
fs.tablespace_name  4    5    6    7    8    9   10   11   12
 13  ;




What might be wrong?

Thanks,
Satish
Reply | Threaded
Open this post in threaded view
|

Re: prepare phase hangs

ErmanArslansOracleBlog
Administrator
Check the following 2 MOS notes:

Queries on DBA_FREE_SPACE are Slow (Doc ID 271169.1)
Space Related Dictionary View Performance Slow in Multitenant Database with Large Number of Pluggable Databases (Doc ID 2053791.1)
Reply | Threaded
Open this post in threaded view
|

Re: prepare phase hangs

satish
Dear erman,

We gathered the fixed stats and flushed shared pool.This worked.
Thanks for your support.

Thanks,
Satish
Reply | Threaded
Open this post in threaded view
|

Re: prepare phase hangs

ErmanArslansOracleBlog
Administrator
Good. Noted.