Re: CTAS generates huge LC Object
From: Martin Klier - Performing Databases GmbH <martin.klier_at_performing-db.com>
Date: Mon, 4 May 2020 11:30:07 +0200 (CEST)
Message-ID: <1632489482.4339.1588584607084.JavaMail.zimbra_at_performing-db.com>
Date: Mon, 4 May 2020 11:30:07 +0200 (CEST)
Message-ID: <1632489482.4339.1588584607084.JavaMail.zimbra_at_performing-db.com>
Thanks Frits and all who contributed - outstanding information.
My "challenge" is now a practical one, to find out the full sql text and trace / analyze it in detail. And explain it to the vendor afterwards... ;) Craftmanship rules now. :)
Thanks again.
-- Martin Klier // Performing Databases GmbH Managing Partner // Senior DB Consultant Oracle ACE Director martin.klier_at_performing-db.com // https://www.performing-databases.com > Von: "Frits Hoogland" <frits.hoogland_at_gmail.com> > An: "Martin Klier" <martin.klier_at_performing-db.com> > CC: "Oracle-L Freelists" <oracle-l_at_freelists.org> > Gesendet: Donnerstag, 30. April 2020 12:33:25 > Betreff: Re: CTAS generates huge LC Object > Martin, a SQLA^XXXXXXXX object is a SQLAREA allocation. The 8 numbers after the > caret are the last 8 digits of the MD5 hash of the sqltext, which is used by > the instance to hash to the correct library cache hash bucket to find (a > pointer to) a parent cursor. As you can see from your snippet, the allocation > that is big says ‘block: #=‘6’’, which means for a cursor object in the library > cache, heap 6 is a SQLAREA object. > Every child could have heap 6 an allocated. It does have placeholder for heap 6 > in the child handle. > Hopefully most people that seen my parsing presentation know what in order to > execute a cursor, you must have a parent with a heap 0 allocation and a > compatible child, and such a child must have a heap 0 allocation and a heap 6 > allocation. During execution of the child, the heaps must be present, and > oracle makes sure they are by pinning them. That is what the ‘P’ flag means > with ‘Flags’. (as soon as there’s a child, you will see that the parent’s heap > 0 is pinned, because the parent’s heap 0 contains a pointer to the child, so > the parent’s heap 0 is needed to find the child) > When a cursor is introduced into the instance the created child is, at least > after first execution, really temporal, you need another execution of the same > child really rapidly to make it more persistent and being able to be used by > other compatible executions of the same session or others. I am quite confident > this is an optimization for non-sharable/unique SQL to have the allocated > (shared pool) memory be available as soon as possible to prevent from shared > pool memory shortage. > Based on what I seen, this means the allocations (=heaps=‘blocks’) of a child > are gone quite rapidly. Even for children that are more frequently used, I find > the heap 6 allocation to be gone really soon. The heap allocation can be reused > as soon as it’s not pinned anymore. > Now that I set the stage, the contents of heap 6, alias the SQLAREA object, is > the execution plan both in binary executable/compiled format for use in the > execution phase and a description of the execution plan so it can be used by > processes to print the execution plan or plan line, like with sqltrace or > DBMS_XPLAN. > If heap 6 is gone, the optimisation is gone, and therefore you need to create it > again. This is flagged as hard parse. > Two reasons for heap 6 to get big is if it got a huge execution plan (the most > logical one), or if a bug causes excessive allocation to take place. > Looking at the number of dependent objects of the child, it is possible the > execution plan is huge. > Frits Hoogland > [ http://fritshoogland.wordpress.com/ | http://fritshoogland.wordpress.com ] > [ mailto:frits.hoogland_at_gmail.com | frits.hoogland_at_gmail.com ] > Mobile: +31 6 14180860Received on Mon May 04 2020 - 11:30:07 CEST
>> On 28 Apr 2020, at 11:20, Martin Klier - Performing Databases GmbH < [
>> mailto:martin.klier_at_performing-db.com | martin.klier_at_performing-db.com ] >
>> wrote:
>> Hi Listers,
>> yet another Library Cache issue...
>> Due to _kgl_large_heap_warning_threshold one "create table as select" causes a
>> trace file for its big LC object. (The warning is great, because we have had
>> memory issues at this point anyway.)
>> In the trace file, I can see a data block allocating much memory:
>> Block: #='6' name=SQLA^83a0bff2 pins=0 Change=NONE
>> Heap=000007FF55229758 Pointer=000007FF17BD9BE8 Extent=000007FF17BD8FA8
>> Flags=I/-/P/A/-/E
>> FreedLocation=0 Alloc=153032.242188 Size=153034.656250 LoadTime=0
>> Whenever I look, we don't have this cursor in the cache, so all v$ views are
>> useless for me at the moment.
>> It does not even show up in the STATSPACK "SQL ordered by Sharable Memory"
>> lists.
>> See the whole second part of the trace and some additional infos after the
>> signature.
>> Now the big question is:
>> How do I find out why this one is getting so big? What can I (or most likely,
>> the developer) change to make it smaller?
>> Thanks for any ideas.
>> --
>> Martin Klier // Performing Databases GmbH
>> Managing Partner // Senior DB Consultant
>> Oracle ACE Director
>> [ mailto:martin.klier_at_performing-db.com | martin.klier_at_performing-db.com ] // [
>> https://www.performing-databases.com/ | https://www.performing-databases.com ]
>> Background info:
>> Alert Log:
>> Memory Notification: Library Cache Object loaded into SGA
>> Heap size 153034K exceeds notification threshold (51200K)
>> Details in trace file <bla>prod_ora_4472.trc
>> KGL object name :Create table MadAdmasTemp as select distinct * from <bla>
>> Oracle Database 11g Release 11.2.0.4.0 - 64bit Production
>> Windows NT Version V6.1 Service Pack 1
>> CPU : 4 - type 8664, 4 Physical Cores
>> Process Affinity : 0x0x0000000000000000
>> Memory (Avail/Total): Ph:7695M/16383M, Ph+PgF:23455M/32765M
>> VM name : VMWare Version (6)
>> Instance name: xyz
>> Redo thread mounted by this instance: 1
>> <...>
>> *** 2020-04-27 19:35:25.963
>> *** SESSION ID:(39.22855) 2020-04-27 19:35:25.963
>> *** CLIENT ID:() 2020-04-27 19:35:25.963
>> *** SERVICE NAME:(SYS$USERS) 2020-04-27 19:35:25.963
>> *** MODULE NAME:(JDBC Thin Client) 2020-04-27 19:35:25.963
>> *** ACTION NAME:() 2020-04-27 19:35:25.963
>> Memory Notification: Library Cache Object loaded into SGA
>> Heap size 153034K exceeds notification threshold (51200K)
>> LibraryHandle: Address=000007FF66FF19E0 Hash=83a0bff2 LockMode=N PinMode=0
>> LoadLockMode=0 Status=VALD
>> ObjectName: Name=Create table MadAdmasTemp as select distinct * from <bla>
>> FullHashValue=a48476d0ac28b36c2e3d594583a0bff2 Namespace=SQL AREA(00)
>> Type=CURSOR(00) Identifier=2208350194 OwnerIdn=51
>> Statistics: InvalidationCount=0 ExecutionCount=0 LoadCount=2 ActiveLocks=1
>> TotalLockCount=1 TotalPinCount=1
>> Counters: BrokenCount=1 RevocablePointer=1 KeepDependency=1 Version=0
>> BucketInUse=0 HandleInUse=0 HandleReferenceCount=0
>> Concurrency: DependencyMutex=000007FF66FF1A90(0, 1, 0, 0)
>> Mutex=000007FF66FF1B20(39, 25, 0, 6)
>> Flags=RON/PIN/TIM/PN0/DBN/[10012841]
>> <...>
>> LibraryHandle: Address=000007FF6B2631D0 Hash=0 LockMode=N PinMode=X
>> LoadLockMode=0 Status=VALD
>> Name: Namespace=SQL AREA(00) Type=CURSOR(00)
>> Statistics: InvalidationCount=0 ExecutionCount=0 LoadCount=1 ActiveLocks=1
>> TotalLockCount=1 TotalPinCount=2
>> Counters: BrokenCount=1 RevocablePointer=1 KeepDependency=0 Version=0
>> BucketInUse=0 HandleInUse=0 HandleReferenceCount=0
>> Concurrency: DependencyMutex=000007FF6B263280(0, 1, 0, 0)
>> Mutex=000007FF66FF1B20(39, 26, 0, 6)
>> Flags=RON/PIN/PN0/EXP/CHD/[10012111]
>> WaitersLists:
>> Lock=000007FF6B263260[000007FF6B263260,000007FF6B263260]
>> Pin=000007FF6B263240[000007FF6B263240,000007FF6B263240]
>> LoadLock=000007FF6B2632B8[000007FF6B2632B8,000007FF6B2632B8]
>> ReferenceList:
>> Reference: Address=000007FF55229988 Handle=000007FF66FF19E0 Flags=CHL[02]
>> LibraryObject: Address=000007FF448E2090 HeapMask=0000-0001-0001-0000
>> Flags=EXS[0000] Flags2=[0000] PublicFlags=NST[0001]
>> Dependencies: count='30' size='32' table='000007FF448E2EC8'
>> Dependency: num='0'
>> Reference=000007FF448E2648 Position=0 Flags=DEP[0001]
>> Handle=000007FF6DE03730 Type=NONE(255) Parent=MYSCHEMA
>> Dependency: num='1'
>> Reference=000007FF448E26E0 Position=52 Flags=DEP[0001]
>> Handle=000007FF6B131888 Type=VIEW(04) Parent=MYSCHEMA.V_ADMAS
>> Dependency: num='2'
>> Reference=000007FF448E2720 Position=186 Flags=DEP[0001]
>> Handle=000007FF6CCD8230 Type=TABLE(02) Parent=MYSCHEMA.AGACTIVITE
>> Dependency: num='3'
>> Reference=000007FF448E2760 Position=648 Flags=DEP[0001]
>> Handle=000007FF6B3417A8 Type=VIEW(04) Parent=MYSCHEMA.V_ADMAS_METIER
>> Dependency: num='4'
>> Reference=000007FF448E27A0 Position=268 Flags=DEP[0001]
>> Handle=000007FF00175B90 Type=TABLE(02) Parent=MYSCHEMA.WFSUITEPROCEDUREREFERENCE
>> Dependency: num='5'
>> Reference=000007FF448E27E0 Position=252 Flags=DEP[0001]
>> Handle=000007FF00136618 Type=TABLE(02) Parent=MYSCHEMA.PROCEDURE
>> Dependency: num='6'
>> Reference=000007FF448E2820 Position=239 Flags=DEP[0001]
>> Handle=000007FF6DF59858 Type=TABLE(02) Parent=MYSCHEMA.PROCESSUS
>> Dependency: num='7'
>> Reference=000007FF448E2860 Position=647 Flags=DEP[0001]
>> Handle=000007FF66DA1B60 Type=VIEW(04) Parent=MYSCHEMA.V_PROCEDURE
>> Dependency: num='8'
>> Reference=000007FF448E28A0 Position=366 Flags=DEP[0001]
>> Handle=000007FF6CCD2038 Type=VIEW(04) Parent=MYSCHEMA.HISTORIDS
>> Dependency: num='9'
>> Reference=000007FF448E28E0 Position=136 Flags=DEP[0001]
>> Handle=000007FF6CCD1190 Type=TABLE(02) Parent=MYSCHEMA.HISTORIDVALEUR
>> Dependency: num='10'
>> Reference=000007FF448E2920 Position=626 Flags=DEP[0001]
>> Handle=000007FF7B4B27A8 Type=TABLE(02) Parent=MYSCHEMA.WFSUITEPROCEDURE
>> Dependency: num='11'
>> Reference=000007FF448E2960 Position=308 Flags=DEP[0001]
>> Handle=000007FF6CD2FF10 Type=TABLE(02) Parent=MYSCHEMA.ADRESSE
>> Dependency: num='12'
>> Reference=000007FF448E29A0 Position=2845 Flags=DEP[0001]
>> Handle=000007FF6CD2D5C0 Type=TABLE(02) Parent=MYSCHEMA.PERSONNE
>> Dependency: num='13'
>> Reference=000007FF448E29E0 Position=7 Flags=DEP[0001]
>> Handle=000007FF6CD2C3F8 Type=FUNCTION(08) Parent=MYSCHEMA.FUZZY_SEARCH
>> Dependency: num='14'
>> Reference=000007FF448E2A20 Position=3257 Flags=DEP[0001]
>> Handle=000007FF7B500090 Type=TABLE(02) Parent=MYSCHEMA.MADDOSSIER
>> Dependency: num='15'
>> Reference=000007FF448E2A60 Position=2344 Flags=DEP[0001]
>> Handle=000007FF7B4FFE70 Type=TABLE(02) Parent=MYSCHEMA.MADMESURE
>> Dependency: num='16'
>> Reference=000007FF448E2AA0 Position=3180 Flags=DEP[0001]
>> Handle=000007FF7B4FFC50 Type=TABLE(02) Parent=MYSCHEMA.MADADMASINFRACTION
>> Dependency: num='17'
>> Reference=000007FF448E2AE0 Position=2034 Flags=DEP[0001]
>> Handle=000007FF7B4FFA30 Type=TABLE(02) Parent=MYSCHEMA.MADMESUREADMAS
>> Dependency: num='18'
>> Reference=000007FF448E2B20 Position=4467 Flags=DEP[0001]
>> Handle=000007FF66FF17B0 Type=FUNCTION(08)
>> Parent=MYSCHEMA.DECISIONPOURTYPESUITEAVECMOTIF
>> Dependency: num='19'
>> Reference=000007FF448E2B60 Position=4329 Flags=DEP[0001]
>> Handle=000007FF68DCBA70 Type=FUNCTION(08) Parent=MYSCHEMA.DECISIONPOUR
>> Dependency: num='20'
>> Reference=000007FF448E2BA0 Position=1268 Flags=DEP[0001]
>> Handle=000007FF66CCC958 Type=FUNCTION(08)
>> Parent=MYSCHEMA.RECONSTRUITADRESSECOMPLETE
>> Dependency: num='21'
>> Reference=000007FF448E2BE0 Position=4429 Flags=DEP[0001]
>> Handle=000007FF68E32D08 Type=TABLE(02) Parent=MYSCHEMA.CANTON_CLIENT_ACTIF
>> Dependency: num='22'
>> Reference=000007FF448E2C20 Position=1788 Flags=DEP[0001]
>> Handle=000007FF00176418 Type=TABLE(02) Parent=MYSCHEMA.ADMASDATAREF
>> Dependency: num='23'
>> Reference=000007FF448E2C60 Position=1774 Flags=DEP[0001]
>> Handle=000007FF001761F8 Type=TABLE(02) Parent=MYSCHEMA.ADMASDATA
>> Dependency: num='24'
>> Reference=000007FF448E2CA0 Position=9240 Flags=DEP[0001]
>> Handle=000007FF001B8C38 Type=TABLE(02) Parent=MYSCHEMA.MADDOSSIERISSUEPENALE
>> Dependency: num='25'
>> Reference=000007FF448E2CE0 Position=3289 Flags=DEP[0001]
>> Handle=000007FF001788B8 Type=VIEW(04) Parent=MYSCHEMA.V_ADRESSE
>> Dependency: num='26'
>> Reference=000007FF448E2D20 Position=3272 Flags=DEP[0001]
>> Handle=000007FF66FF1590 Type=VIEW(04) Parent=MYSCHEMA.V_PERSONNE
>> Dependency: num='27'
>> Reference=000007FF40B990A8 Position=0 Flags=DEP[0001]
>> Handle=000007FF7B4960C0 Type=TABLE(02) Parent=MYSCHEMA.PROCEDUREREF
>> Dependency: num='28'
>> Reference=000007FF40B990E8 Position=0 Flags=DEP[0001]
>> Handle=000007FF66D5F5E8 Type=TABLE(02) Parent=MYSCHEMA.PROCEDUREREFERENCE
>> Dependency: num='29'
>> Reference=000007FF40B99128 Position=0 Flags=DEP[0001]
>> Handle=000007FF6DF391D8 Type=PACKAGE(09) Parent=SYS.STANDARD
>> ReadOnlyDependencies: count='1' size='16'
>> ReadDependency: num='0' Table=000007FF448E2F60 Reference=000007FF448E2548
>> Handle=000007FF6CD43B58 Flags=DEP/ROD/KPP[61]
>> Accesses: count='2' size='16'
>> Dependency: num='2' Type=0009
>> Dependency: num='1' Type=0009
>> DataBlocks:
>> Block: #='0' name=KGLH0^83a0bff2 pins=0 Change=NONE
>> Heap=000007FF6CEBC0D0 Pointer=000007FF448E2130 Extent=000007FF448E2010
>> Flags=I/-/P/A/-/-
>> FreedLocation=0 Alloc=12.929688 Size=15.820313 LoadTime=3667233912
>> Block: #='6' name=SQLA^83a0bff2 pins=0 Change=NONE
>> Heap=000007FF55229758 Pointer=000007FF17BD9BE8 Extent=000007FF17BD8FA8
>> Flags=I/-/P/A/-/E
>> FreedLocation=0 Alloc=153032.242188 Size=153034.656250 LoadTime=0
>> NamespaceDump:
>> Child Cursor: Heap0=000007FF448E2130 Heap6=000007FF17BD9BE8 Heap0 Load
>> Time=04-27-2020 19:35:07 Heap6 Load Time=04-27-2020 19:35:07
-- http://www.freelists.org/webpage/oracle-l