Home » RDBMS Server » Server Utilities » expdp slow, delays in QUEUE_INT.SEND (Oracle 11.2.0.4, Windows Server 2012 R2)
expdp slow, delays in QUEUE_INT.SEND [message #665348] Thu, 31 August 2017 14:25 Go to next message
ctvarner
Messages: 10
Registered: August 2017
Junior Member
I have three 11.2.0.4 Oracle instances on a Windows 2012 R2 server. One instance is fine and does not exhibit the behavior described below.

For the other two, expdp is painfully slow. With METRICS=Y, the output shows the startup phase taking anywhere from 60 to 120 seconds. Once the actual data export gets underway, every table takes a minimum of 2-3 seconds, including empty tables. With TRACE set to 0690300 (typical 0480300, plus 0010000 for expdp/impdp details, plus 0200000 for queue services details), the trace log shows a delay of 2-3 seconds on every "KUPC$QUEUE_INT.SEND".

Here, note the delay of 2.709 seconds between "...SEND called" and "...SEND returned". Also note MYSCHEMA.MYTABLE is empty.

KUPW:11:47:27.095: 2: In procedure BUILD_OBJECT_STRINGS
KUPW:11:47:27.095: 2: In procedure MOVE_DATA UNLOADing process_order 2 TABLE_DATA:"MYSCHEMA"."MYTABLE"
KUPW:11:47:27.095: 2: In procedure FORMAT_TABLE_DATA_MSG
KUPW:11:47:27.095: 2: In procedure CREATE_MSG
KUPW:11:47:27.095: 2: KUPV$FT.MESSAGE_TEXT called. 
KUPW:11:47:27.095: 2: KUPV$FT.MESSAGE_TEXT returned. 
KUPW:11:47:27.095: 2: In procedure SEND_MSG. Fatal=0
KUPW:11:47:27.095: 2: KUPC$QUEUE_INT.SEND called. 

*** 2017-08-31 11:47:29.804
KUPW:11:47:29.804: 2: KUPC$QUEUE_INT.SEND returned. 
KUPW:11:47:29.804: 2: . . exported "MYSCHEMA"."MYTABLE"                 0 KB       0 rows

Following advice on the internet, in the two slow instances, I rebuilt all indexes and analyzed all tables in MYSCHEMA; gathered dictionary stats, system stats, and fixed object stats; confirmed (to the best of my ability) that things like memory_target, memory_max_target, and streams_pool_size are all set appropriately. I also confirmed there are no invalid objects in SYS or SYSTEM (or in fact anywhere in any instance). The queue tables in all three schemas are defined identically.

In one of the slow instances, gathering dictionary/system/fixed-object stats was the key to the kingdom. Once I did that, expdp startup in that instance became nearly instantaneous, exporting an empty table is nearly instantaneous, the delays on QUEUE_INT.SEND in the trace log are gone, and a schema backup that ran nearly two hours the night before completed in under three minutes. This is the kind of performance I am expecting. In the other slow schema, despite taking all the same steps, expdp performance remains exactly the same, as shown in the trace log entry above.

A colleague suggested bumping AQ_TM_PROCESSES from 1 to 2. The internet is clear that I shouldn't need to fool with that parameter in 11g at all, and equally clear that it should never be set to zero (it wasn't), but somewhat less clear on what effect (if any) that parameter still has in 11g. At any rate, I tried bumping it from 1 to 2, and this had no effect either

What am I missing?

Re: expdp slow, delays in QUEUE_INT.SEND [message #665350 is a reply to message #665348] Thu, 31 August 2017 21:47 Go to previous messageGo to next message
BlackSwan
Messages: 25716
Registered: January 2009
Location: SoCal
Senior Member
When you see a difference in performance, you can be 100% assured that something is in fact different.
Since we can not compare & contrast the slow database against the two normal database, it is up to you to locate where the difference actually exists.
Re: expdp slow, delays in QUEUE_INT.SEND [message #665351 is a reply to message #665350] Thu, 31 August 2017 22:59 Go to previous messageGo to next message
ctvarner
Messages: 10
Registered: August 2017
Junior Member
Understood and agreed. I need to narrow it down, though. The three instances are not identical - a small one supports product A, a small-to-medium supports final ready-for-production testing of product B, and a larger one supports development & testing of that same product B but with more full and partial schemas. There are differences between them that surely don't matter... and I agree completely, there is obviously at least one critical difference, something that would explain why I had no problem in the first, and the problem went away in the second, and the problem remains in the third. I believe the two instances that are now working properly rule out a hardware problem, and they largely rule out a software problem as well (i.e. Oracle bug/patch, although not entirely ruled out).

Suppose I had an Oracle 11.2.0.4 instance with expdp symptoms as described, slow startup, 2-3 second delays between tables regardless of size, trace logs showing that delay is between "QUEUE_INT.SEND called" and "QUEUE_INT.SEND return"... all as described above... but suppose I hadn't mentioned the other two instances at all. I would greatly appreciate any suggestions or advice for anything I might check, tests I could run, trace options I could turn on, log messages to look for, anything at all that could lead to an explanation for why this instance is displaying these symptoms, without regard to any other instances that are not.
Re: expdp slow, delays in QUEUE_INT.SEND [message #665352 is a reply to message #665351] Fri, 01 September 2017 00:51 Go to previous messageGo to next message
John Watson
Messages: 7148
Registered: January 2010
Location: Global Village
Senior Member
How did you analyze your data dictionary? To be sure of adequate statistics, I would do it like this:
exec dbms_Stats.gather_dictionary_Stats(estimate_percent=>100,method_opt=>'for all columns size skewonly',granularity=>'all',options=>'gather')
Re: expdp slow, delays in QUEUE_INT.SEND [message #665365 is a reply to message #665352] Fri, 01 September 2017 08:20 Go to previous messageGo to next message
ctvarner
Messages: 10
Registered: August 2017
Junior Member
I'm having connectivity issues this morning so can't get in to double-check, but I think I did this:
dbms_stats.gather_dictionary_stats
dbms_stats.gather_database_stats(gather_sys=>TRUE)
dbms_stats.gather_schema_stats('SYS')

I'll check on what I did and try your suggestion as soon as I can get in there to see. Thanks!
Re: expdp slow, delays in QUEUE_INT.SEND [message #665431 is a reply to message #665365] Tue, 05 September 2017 08:45 Go to previous messageGo to next message
ctvarner
Messages: 10
Registered: August 2017
Junior Member
Sorry for the delay, long holiday weekend.

Upon further review what I did before was:
EXEC DBMS_STATS.GATHER_DICTIONARY_STATS;
EXEC DBMS_STATS.GATHER_SYSTEM_STATS;
EXEC DBMS_STATS.GATHER_FIXED_OBJECTS_STATS (null);

This morning, I confirmed the problem hadn't magically disappeared, then did this as suggested:
exec dbms_Stats.gather_dictionary_Stats(estimate_percent=>100,method_opt=>'for all columns size skewonly',granularity=>'all',options=>'gather')

...and the problem remains, with the "startup" phase reporting 45-120 seconds and then each table having a 2-3 second delay in KUPC$QUEUE_INT.SEND. With TRACE set to 0690300 (typical 0480300, plus 0010000 for impdp/expdp trace, plus 0200000 for queue service trace):
KUPW:09:39:25.139: 2: In procedure SEND_MSG. Fatal=0
KUPW:09:39:25.139: 2: KUPC$QUEUE_INT.SEND called. 
KUPC:09:39:25.139: Before ENQ: Sending Type: 3031 ID:
KUPC:09:39:25.139:  DG,KUPC$C_1_20170905093341,KUPC$A_1_093553732000000,MCP,31,Y

*** 2017-09-05 09:39:27.373
KUPW:09:39:27.373: 2: KUPC$QUEUE_INT.SEND returned. 
KUPW:09:39:27.373: 2: . . exported "SCHEMANAME"."TABLENAME"          0 KB  
Re: expdp slow, delays in QUEUE_INT.SEND [message #665468 is a reply to message #665431] Wed, 06 September 2017 11:31 Go to previous messageGo to next message
ctvarner
Messages: 10
Registered: August 2017
Junior Member
SOLVED.

Yesterday, I had gathered dictionary statistics using the syntax suggested by John Watson above, at around 9:25am. Then I ran my test expdp to export 30 empty tables; that test (around 9:39am as shown in the trace log above) still took four minutes, same as before. I ran that same test expdp today, and it completed in ten seconds.

It appears something changed at 9:54 am yesterday. Looking at other logs, my overnight expdp's on various similarly-sized schemas were averaging 13 minutes each until 9:54am yesterday, and then about one minute each after 9:55am. I don't know if it just took a while for gather_dictionary_stats to really "take", or if something else changed (no idea what), but any way you slice it, my expdp problem appears to be solved.

Thanks, everyone, and especially John Watson!


(Edit: added time of yesterday's test vs time of gather_dictionary_stats vs time performance suddenly returned to normal.)

[Updated on: Wed, 06 September 2017 11:52]

Report message to a moderator

Re: expdp slow, delays in QUEUE_INT.SEND [message #665509 is a reply to message #665468] Thu, 07 September 2017 21:24 Go to previous messageGo to next message
ctvarner
Messages: 10
Registered: August 2017
Junior Member
A note for the future forum-searcher (and there's a nonzero chance that person will be me). (Hello future me!)

The first instance that was slow but got fast again after gathering stats mysteriously went slow again, taking 6 minutes to export 30 empty tables, with delays in startup and in the trace file as described above. Gathering dictionary stats with John Watson's suggested syntax had no immediate effect, nor any apparent effect a couple of hours later. Then bumping streams_pool_size from default 0 to 300mb had immediate effect, bringing that instance's expdp back to full speed, exporting those same 30 tables in 9 seconds start to finish.

[Updated on: Thu, 07 September 2017 21:25]

Report message to a moderator

Re: expdp slow, delays in QUEUE_INT.SEND [message #665639 is a reply to message #665509] Wed, 13 September 2017 10:18 Go to previous messageGo to next message
Flyby
Messages: 181
Registered: March 2011
Location: Belgium
Senior Member
Thanks for the update
stream_pool_size triggers a memory
Re: expdp slow, delays in QUEUE_INT.SEND [message #665835 is a reply to message #665348] Mon, 25 September 2017 08:18 Go to previous messageGo to next message
ctvarner
Messages: 10
Registered: August 2017
Junior Member
.....aaaaaaaaand then they slowed down again, with no changes applied to the DB.

Blog post import-data-pump-performance-problem describes my situation well, and it identifies Bug 21286665 as the culprit.

The fix for that bug was included in the April 2017 bundle, and the April bundle was installed on the affected server in early August (before this problem became apparent). For lack of anything else to try, we installed the August 2017 bundle - which is all-inclusive, including all patches from April - and lo & behold, that seems to have resolved the problem. It's been several days and the expdp's are screaming fast. My only theory is that the April patch bundle was not installed correctly.

To put the before/after in perspective, a big set of expdp's ran 13.5 hours before we killed it to install the patch bundle. Afterward the patch, we restarted that set of expdp's from the top, and it got back to the same point where we had killed it ... in ten minutes.

(EDIT: I just realized Flyby's link above points to the same blog post. Sweet!)

[Updated on: Mon, 25 September 2017 09:03]

Report message to a moderator

Re: expdp slow, delays in QUEUE_INT.SEND [message #665951 is a reply to message #665348] Wed, 04 October 2017 07:35 Go to previous message
ctvarner
Messages: 10
Registered: August 2017
Junior Member
I swear Oracle has an evil sense of humor, and waits for me to post here before making the problem come back. Overnight after my previous post, the problem returned in one schema but not the other - either 1.5 business-days, or 3.5 calendar-days, after applying the bundle and seeing the problem go away. Apparently it wasn't "solved" by installing the August bundle, but rather temporarily alleviated by restarting the instance.

Oracle support provided the following list of known bugs related to slow expdp:

Quote:

( Doc Id:453895.1 ) Checklist For Slow Performance Of DataPump Export (expdp) And Import (impdp)

Export DataPump (expdp):
=======================

11.2.0.4
- Bug 14794472 - EXPDP TOO SLOW HAVING TOO MANY TABLESPACES
- Bug 13717234 - Datapump export for transport is slow handling a large number of objects
- Bug 16856028 - EXPORT DATAPUMP SLOW ON DATAGUARD STANDBY INSTANCE
- Bug 18469379 - Data pump export estimate phase takes a long time to determine if table is empty
- Bug 18793246 - EXPDP slow showing base object lookup during datapump export causes full table scan per object
- Bug 19674521 - EXPDP takes a long time when exporting a small table
- Bug 20111004 - "COMMENT ON COLUMN" statement waits 1 second on "Wait for Table Lock"
- Bug 20236523 - DATAPUMP EXPORT SLOW USING CONTENT=METADATA_ONLY
- Bug 20548904 - EXPDP HANG IN METADA_ONLY ON A PARTITION TABLE WITH AROUND 40000 SUBPARTITIONS
- Bug 20446613 - EXPORTING NON-STREAMS TABLE FROM STRADMIN SCHEMA OVER NETWORK LINK IS SLOW
- Bug 24560906 - HIGH CPU USAGE FOR PROCESS ORA_Q001_DBT11 AND ORA_Q007_DBT11

...and recommended either of the following merge patches:

Quote:

MLR Patch 20883577 released on top of 11.2.0.4 contains the fixes for the bugs: 18469379, 18793246, 19674521, 20236523 and 20548904
or next merge patch including the above:
MLR Patch 21443197 released on top of 11.2.0.4 contains the fixes for the bugs: 18082965 18469379 18793246 20236523 19674521 20532904 20548904

==============================
Import DataPump (impdp):

11.2.0.4
- Bug 13609098 - IMPORTING SMALL SECUREFILE LOBS USING DATA PUMP IS SLOW
- Bug 19520061 - IMPDP: EXTREMELY SLOW IMPORT FOR A PARTITIONED TABLE

...and said development is working on the following bug, with the following workaround:

Quote:

Development is working in P1 Bug 21286665 [https://bug.oraclecorp.com/pls/bug/webbug_edit.edit_info_top?rptno=21286665] - EXPORT IS SLOW WAITING FOR "STREAMS AQ: ENQUEUE BLOCKED ON LOW MEMORY,
Workaround
========================
connect / as sysdba
alter system set streams_pool_size=250M; --This can be adjusted as appropriate for the environment
alter system set "_disable_streams_pool_auto_tuning"=TRUE;
shutdown immediate
startup
======================================

We applied that workaround (specifying 300M) with expdp's actively running (albeit slowly) in another window, and expdp performance improved instantly. We went ahead and applied the 21443197 merge patch as well, and of course restarted the instance.

That was a week ago this afternoon; we've been running extra expdp's every hour around the clock ever since, and so far so good.
Previous Topic: the user data import problem in window 8
Next Topic: Exp in Oracle 12c
Goto Forum:
  


Current Time: Mon Nov 20 22:39:39 CST 2017

Total time taken to generate the page: 0.01533 seconds