11gr2 sql issue

  • From: Kumar Madduri <ksmadduri@xxxxxxxxx>
  • To: oracle Freelists <Oracle-L@xxxxxxxxxxxxx>
  • Date: Tue, 8 Nov 2011 19:05:05 -0800

Hi
As part of regression testing in our db upgrade from 11.1.0.7 to 11.2.0.2,
one of the developers reported a slow sql (attached slow_sql.sql)
We did a 10053 trace and noticed one of the things was wip_entities was not
doing a Index scan in 11gR2 vs 11gR1.
But what is most useful till this point is Tanel's se.sql script which
reports this
11.2.0.2 (bad)
SQL> @se 4294

    SID EVENT                                     TIME_WAITED TOTAL_WAITS
TOTAL_TIMEOUTS AVERAGE_WAIT   MAX_WAIT
------- ---------------------------------------- ------------ -----------
-------------- ------------ ----------
   4294* SQL*Net message from dblink*               *     806.67      585136
*              0        .0014         .6
        CPU Time                                        73.31
        SQL*Net message from client                     51.29
226              0         .227      32.87
        latch: shared pool                                .69
84              0        .0082        .26
        single-task message                               .65
1              0        .6453        .65
        SQL*Net message to dblink                         .61
585135              0            0          0
        db file sequential read                           .10
17              0        .0059        .01
        Disk file operations I/O                          .03
19              0        .0017          0
        library cache pin                                 .01
17              0        .0003          0
        SQL*Net message to client                         .00
227              0            0          0
        library cache lock                                .00
14              0        .0003          0
        events in waitclass Other                         .00
11              3        .0001          0
        gc cr grant 2-way                                 .00
9              0        .0003          0
        control file sequential read                      .00
7              0        .0003          0
        SQL*Net break/reset to client                     .00
3              0        .0001          0
        gc current block 2-way                            .00
2              0        .0004          0
        SQL*Net break/reset to dblink                     .00
2              0        .0002          0

11.1.0.7 (good)
------- ---------------------------------------- ------------ -----------
-------------- ------------ ----------
   1737 SQL*Net message from client                    264.16
12789              0        .0207     184.73
        CPU Time                                        13.00
      *  SQL*Net message from dblink                      1.11
651              0        .0017        .19*
        single-task message                               .90
1              0        .8977         .9
        control file sequential read                      .17
7              0        .0238        .16
        SQL*Net more data from dblink                     .12
742              0        .0002          0
        SQL*Net message to client                         .01
12790              0            0          0
        log file sync                                     .01
1              0        .0086        .01
        SQL*Net message to dblink                         .00
651              0            0          0
        events in waitclass Other                         .00
3              0        .0001          0

I ran se.sql at different intervals and in 11.1.07 SQL*Net message from
dblink    is constant (numbers for that event) but it is constantly
increating for 11.2.0.2*.

*If in the 11.2.0.2 database, I use the ordered hint for the sql, then the
explain plan is much better and it starts to use hash joins instead of NL.
plus I dont see huge waits for the SQL*Net message from db link.

SQL> @se 6774

    SID EVENT                                     TIME_WAITED TOTAL_WAITS
TOTAL_TIMEOUTS AVERAGE_WAIT   MAX_WAIT
------- ---------------------------------------- ------------ -----------
-------------- ------------ ----------
   6774 SQL*Net message from client                    134.56
4525              0        .0297      49.42
        CPU Time                                        82.45
        db file scattered read                          14.30
3015              0        .0047        .28
        SQL*Net more data from dblink                    8.04
328              0        .0245        1.8
        SQL*Net message from dblink                      6.50
30              0        .2167       6.18
        gc cr multi block request                        1.64
2907              0        .0006          0
        db file sequential read                          1.33
568              0        .0023        .04
        single-task message                               .47
1              0        .4732        .47
        gc cr grant 2-way                                 .13
541              0        .0002          0
        Disk file operations I/O                          .06
76              0        .0007          0
        SQL*Net message to client                         .00
4526              0            0          0
        SQL*Net message to dblink                         .00
29              0            0          0
        events in waitclass Other                         .00
15             13            0          0
        control file sequential read                      .00
7              0        .0004          0
        SQL*Net break/reset to client                     .00
3              0        .0001          0
        library cache lock                                .00
1              0        .0008          0

The sql uses a db link but both the databases are using the same db
link (meaning target db is the same in both cases).

Any pointers on why this can happen.

Thank you
Kumar


--
http://www.freelists.org/webpage/oracle-l


Other related posts: