3 Replies Latest reply: Mar 20, 2013 9:40 AM by PauloSMO RSS

    WAIT = 'direct path read temp' in session

    PauloSMO
      Hi;

      select * from v$version
      Oracle Database 11g Release 11.2.0.1.0 - 64bit Production

      In our development system, a query "insert into X" using a couple of session global temporary tables, was running under 5 minuts, is now taking 40 minuts!
      Sql Developer Sessions shows a wait: "direct path read temp"

      Any hints on that might cause this, and possible solutions?

      Trace file of the session looks like this:

      *** 2013-03-18 15:56:22.871
      WAIT #20: nam='direct path read temp' ela= 106 file number=201 first dba=46685 block cnt=31 obj#=61321 tim=1363614982871399
      *** 2013-03-18 15:56:25.354
      WAIT #20: nam='direct path read temp' ela= 90 file number=201 first dba=46336 block cnt=31 obj#=61321 tim=1363614985354148
      *** 2013-03-18 15:56:28.098
      WAIT #20: nam='direct path read temp' ela= 86 file number=201 first dba=46367 block cnt=31 obj#=61321 tim=1363614988098575
      *** 2013-03-18 15:56:32.302
      WAIT #20: nam='direct path read temp' ela= 112 file number=201 first dba=69438 block cnt=31 obj#=61321 tim=1363614992302296
      WAIT #20: nam='direct path read temp' ela= 93 file number=201 first dba=69469 block cnt=31 obj#=61321 tim=1363614992302484
      WAIT #20: nam='direct path read temp' ela= 95 file number=201 first dba=68030 block cnt=31 obj#=61321 tim=1363614992302888
      WAIT #20: nam='direct path read temp' ela= 93 file number=201 first dba=66719 block cnt=31 obj#=61321 tim=1363614992303265
      WAIT #20: nam='direct path read temp' ela= 107 file number=201 first dba=65726 block cnt=31 obj#=61321 tim=1363614992303657
      WAIT #20: nam='direct path read temp' ela= 94 file number=201 first dba=64702 block cnt=31 obj#=61321 tim=1363614992304037
      WAIT #20: nam='direct path read temp' ela= 97 file number=201 first dba=63709 block cnt=31 obj#=61321 tim=1363614992304421
      WAIT #20: nam='direct path read temp' ela= 94 file number=201 first dba=62623 block cnt=31 obj#=61321 tim=1363614992304820
      WAIT #20: nam='direct path read temp' ela= 111 file number=201 first dba=61471 block cnt=31 obj#=61321 tim=1363614992305227
      WAIT #20: nam='direct path read temp' ela= 121 file number=201 first dba=60606 block cnt=31 obj#=61321 tim=1363614992305764
      WAIT #20: nam='direct path read temp' ela= 100 file number=201 first dba=59392 block cnt=31 obj#=61321 tim=1363614992306175
      WAIT #20: nam='direct path read temp' ela= 101 file number=201 first dba=58589 block cnt=31 obj#=61321 tim=1363614992306579
      WAIT #20: nam='direct path read temp' ela= 98 file number=201 first dba=57503 block cnt=31 obj#=61321 tim=1363614992306965
      WAIT #20: nam='direct path read temp' ela= 93 file number=201 first dba=56510 block cnt=31 obj#=61321 tim=1363614992307342
      WAIT #20: nam='direct path read temp' ela= 94 file number=201 first dba=55296 block cnt=31 obj#=61321 tim=1363614992307742
      WAIT #20: nam='direct path read temp' ela= 96 file number=201 first dba=54272 block cnt=31 obj#=61321 tim=1363614992308149
      WAIT #20: nam='direct path read temp' ela= 131 file number=201 first dba=53407 block cnt=31 obj#=61321 tim=1363614992308651
      WAIT #20: nam='direct path read temp' ela= 108 file number=201 first dba=52480 block cnt=31 obj#=61321 tim=1363614992309129
      WAIT #20: nam='direct path read temp' ela= 99 file number=201 first dba=52511 block cnt=31 obj#=61321 tim=1363614992309273
        • 1. Re: WAIT = 'direct path read temp' in session
          PauloSMO
          Tkprof output... notice the big values for direct path write temp and direct path read temp values!



          OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS

          callcount cpu elapsed disk query current rows
          Parse 2 0.17 0.18 0 0 0 0
          Execute 2 0.00 0.00 0 0 0 0
          Fetch 4 206.24 207.66 18960 755 21 8
          total 8 206.42 207.84 18960 755 21 8

          Misses in library cache during parse: 2

          Elapsed times include waiting on following events:
          Event waited on Times Max. Wait Total Waited
          SQL*Net message to client 5 0.00 0.00
          SQL*Net message from client 5 11.01 19.27
          db file sequential read 6 0.00 0.00
          Disk file operations I/O 15 0.00 0.00
          asynch descriptor resize 84 0.00 0.00
          direct path write temp 1264 0.19 1.25
          direct path read temp 1264 0.00 0.04
          control file sequential read 42 0.00 0.00
          db file single write 3 0.00 0.00
          control file parallel write 9 0.00 0.00
          rdbms ipc reply 2 0.00 0.00
          local write wait 12 0.00 0.00
          log file sync 2 0.00 0.00



          OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS

          call count cpu elapsed disk query current rows
          Parse 85 0.04 0.04 0 0 0 0
          Execute 899 0.18 0.24 22 47 7 4
          Fetch 1393 0.04 0.69 204 3200 0 7002
          total 2377 0.28 0.98 226 3247 7 7006

          Misses in library cache during parse: 55
          Misses in library cache during execute: 51

          Elapsed times include waiting on following events:
          Event waited on Times Max. Wait Total Waited
          db file sequential read 206 0.03 0.65
          latch: shared pool 4 0.00 0.00
          Disk file operations I/O 2 0.00 0.00
          db file scattered read 3 0.03 0.04

          5 user SQL statements in session.
          896 internal SQL statements in session.
          901 SQL statements in session.

          Trace file: SXDB_ora_25080.trc
          Trace file compatibility: 11.1.0.7
          Sort options: default

          1 session in tracefile.
          5 user SQL statements in trace file.
          896 internal SQL statements in trace file.
          901 SQL statements in trace file.
          41 unique SQL statements in trace file.
          21517 lines in trace file.
          217 elapsed seconds in trace file.

          Edited by: PauloSMO on 19/Mar/2013 11:36
          • 2. Re: WAIT = 'direct path read temp' in session
            BluShadow
            PauloSMO wrote:
            Hi;

            select * from v$version
            Oracle Database 11g Release 11.2.0.1.0 - 64bit Production

            In our development system, a query "insert into X" using a couple of session global temporary tables, was running under 5 minuts, is now taking 40 minuts!
            So what's changed? Something has.

            Without seeing any code it's very difficult for anyone to identify what the cause could be, as we don't have a reproducable test case to run ourselves.

            {message:id=9360002}
            • 3. Re: WAIT = 'direct path read temp' in session
              PauloSMO
              Problem seem related with oracle 11 optimizer.
              All queries that have joins with global temporary tables, not have any index usage in there explain plans.