Home » SQL & PL/SQL » SQL & PL/SQL » xmlconcat slow
xmlconcat slow [message #206205] Wed, 29 November 2006 03:32 Go to next message
roselan
Messages: 7
Registered: November 2006
Location: Lausanne, Switzerland
Junior Member

I'm generating some xml in an implicit for plsql loop.

there is plenty 6 direct xmlconcat inside, and 4 "select xmlagg(...) from dual" (which call "select xmlconcat(:b2, :b1) from dual" too imo).

the main chunck of data is aggregated here:

select xmlagg(xmlelement("Account",
xmlattributes('New' as "Command"),
xmlconcat(xmlelement("SubNo", v_abo.abono),
xmlelement("IsPaperSub", v_IsPaperSub),
xmlelement("WebAclSubNo", v_abo.marketing_nr),
xmlelement("Username", null),
xmlelement("Password", null),
xmlelement("RegistrationDate", v_RegistrationDate),
xmlelement("ExpirationDate", v_ExpirationDate),
xmlelement("Status", v_Status),
xmlelement("FirstName", v_FirstName),
xmlelement("LastName", v_LastName),
xmlelement("Email", v_Email),
xmlelement("PhoneNumber", v_PhoneNumber),
xmlelement("MobileNumber", v_MobileNumber),
v_Adress,
v_Subs,
v_Extra)))
into v_Account
from dual;

v_Account is simply of xmltype.

The output file is arround 3 megs. In sql or plsql, the main query (the for loop) is excuted in 6 minutes and fetch 34 000 "accounts".

the xml version is now running for 6 hours.

here is the tkprof tail:

********************************************************************************

SELECT XMLAGG(XMLELEMENT("Address", XMLCONCAT(XMLELEMENT("Company", :B5 ),
XMLELEMENT("StreetAddress", :B4 ), XMLELEMENT("City", :B3 ),
XMLELEMENT("PostalCode", :B2 ), XMLELEMENT("Country", :B1 ))))
FROM
DUAL


call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 401 0.26 0.22 0 0 0 0
Fetch 401 0.25 0.20 0 0 0 401
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 802 0.51 0.42 0 0 0 401

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 163 (recursive depth: 1)
********************************************************************************

SELECT XMLAGG(XMLELEMENT("Subs", XMLELEMENT("Sub",
XMLCONCAT(XMLELEMENT("Publication", :B4 ), XMLELEMENT("Product", :B3 ),
XMLELEMENT("ProductStartDate", :B2 ), XMLELEMENT("ProductExpirationDate",
:B1 )))))
FROM
DUAL


call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 401 0.23 0.18 0 0 0 0
Fetch 401 0.10 0.12 0 0 0 401
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 802 0.33 0.31 0 0 0 401

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 163 (recursive depth: 1)
********************************************************************************

SELECT XMLAGG(XMLELEMENT("Extra", XMLCONCAT(XMLELEMENT("Srcnum", :B1 ))))
FROM
DUAL


call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 401 0.11 0.08 0 0 0 0
Fetch 401 0.08 0.10 0 0 0 401
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 802 0.19 0.19 0 0 0 401

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 163 (recursive depth: 1)
********************************************************************************

SELECT XMLAGG(XMLELEMENT("Account", XMLATTRIBUTES('New' AS "Command"),
XMLCONCAT(XMLELEMENT("SubNo", :B14 ), XMLELEMENT("IsPaperSub", :B13 ),
XMLELEMENT("WebAclSubNo", :B12 ), XMLELEMENT("Username", NULL),
XMLELEMENT("Password", NULL), XMLELEMENT("RegistrationDate", :B11 ),
XMLELEMENT("ExpirationDate", :B10 ), XMLELEMENT("Status", :B9 ),
XMLELEMENT("FirstName", :B8 ), XMLELEMENT("LastName", :B7 ),
XMLELEMENT("Email", :B6 ), XMLELEMENT("PhoneNumber", :B5 ),
XMLELEMENT("MobileNumber", :B4 ), :B3 , :B2 , :B1 )))
FROM
DUAL


call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 401 0.82 0.70 0 0 0 0
Fetch 401 0.18 0.19 0 0 0 401
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 802 1.00 0.90 0 0 0 401

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 163 (recursive depth: 1)
********************************************************************************

SELECT XMLCONCAT(:B2 , :B1 )
FROM
DUAL


call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 400 5272.47 5179.63 1 1166977 6780827 0
Fetch 400 67.85 66.53 0 753058 5544826 400
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 800 5340.32 5246.17 1 1920035 12325653 400

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 163 (recursive depth: 1)

Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
db file sequential read 1 0.00 0.00



********************************************************************************

OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 0 0.00 0.00 0 0 0 0
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 0 0.00 0.00 0 0 0 0

Misses in library cache during parse: 0

Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
db file sequential read 3 0.00 0.02


OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 6607 5275.06 5182.26 18 1167434 6781685 401
Fetch 6607 69.46 84.88 3284 766124 5544826 5404
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 13214 5344.52 5267.15 3302 1933558 12326511 5805

Misses in library cache during parse: 0

Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
db file sequential read 1952 0.04 16.62
db file scattered read 85 0.02 0.53

13 user SQL statements in session.
0 internal SQL statements in session.
13 SQL statements in session.
********************************************************************************
Trace file: /oracle/backup/admin/PRESLEY/udump/presley_ora_17934.trc
Trace file compatibility: 10.01.00
Sort options: default

1 session in tracefile.
13 user SQL statements in trace file.
0 internal SQL statements in trace file.
13 SQL statements in trace file.
13 unique SQL statements in trace file.
119134 lines in trace file.
5494 elapsed seconds in trace file.

I can't see any logical reason why xmlconcat eats so much "cpu" time! thanx!

ps: i'm on oracle 10.2.0.2.0, solaris 5.10, bi-sparc64.

[Updated on: Wed, 29 November 2006 03:39]

Report message to a moderator

Re: roselan [message #206211 is a reply to message #206205] Wed, 29 November 2006 03:41 Go to previous messageGo to next message
vamsi kasina
Messages: 2107
Registered: October 2003
Location: Riyadh, Saudi Arabia
Senior Member
This is a performance issue.

If you see the trace number of executions and fetches are high (same as number of rows).

If you fetch row by row it will take time, as it needs to hit the database those many times.

Try to use BULK.

By
Vamsi.
Re: roselan [message #206225 is a reply to message #206211] Wed, 29 November 2006 04:03 Go to previous messageGo to next message
roselan
Messages: 7
Registered: November 2006
Location: Lausanne, Switzerland
Junior Member

woooow, that was fast! thank you!

I will investigate these fast/bulk ways, and keep you updated. I have another (urgent...) project right now, and will do some test hopefully during this week!

I feel my code will need *heavy* modification to able to bulk-xml concat, as basically i will have to get rid of the "from dual" part. I think I will use a temporary table that I will bulk-select... I keep you informed Wink

anyway, thanx again, and may the the force be with you!
Re: roselan [message #206237 is a reply to message #206225] Wed, 29 November 2006 04:33 Go to previous messageGo to next message
JRowbottom
Messages: 5933
Registered: June 2006
Location: Sunny North Yorkshire, ho...
Senior Member
You should be able to lose the XMLCONCAT(XMLELEMENT(),XMLELEMENT()...) entirely, and replace it with XMLFOREST

I've had generally good performance from XML Views - create a query that returns the data set that you want and just add the XML code onto that.
Re: roselan [message #206272 is a reply to message #206237] Wed, 29 November 2006 06:56 Go to previous messageGo to next message
roselan
Messages: 7
Registered: November 2006
Location: Lausanne, Switzerland
Junior Member

Shocked

You don't know what hides behind each variable Very Happy

(but that's normal, I did show only the the tip of the iceberg)

It is a "flexible" environement, and it would be harsh to lose the advantage of plsql debugging.

By using temp tables, I should be able to bulk-query and/or xmlforrest, and not change the structure of the "info gathering" part Wink

The temp tables will record the data before it is xmlised. I need several of them as some "elements" are complex, like v_address which got street, city, etc.
Re: roselan [message #206288 is a reply to message #206272] Wed, 29 November 2006 08:07 Go to previous messageGo to next message
JRowbottom
Messages: 5933
Registered: June 2006
Location: Sunny North Yorkshire, ho...
Senior Member
Our nested XML views do things similar to what you say you're looking for. They go down 3 or 4 levels of nesting and have multiple occurrencies at each level.
Generating a row of data seems to average out at a little less than 0.1 seconds per row for selecting from the top level view.

Can you combine multiple SELECT...FROM DUAL; together, as I suspect that's the slow bit?

Re: roselan [message #206300 is a reply to message #206288] Wed, 29 November 2006 09:23 Go to previous messageGo to next message
roselan
Messages: 7
Registered: November 2006
Location: Lausanne, Switzerland
Junior Member

you mean with unions?

I do use "xml views" too, but it is clearly not an option here.

The gathering of data is more 2000 lines long, and includes several internal open loops (an account can have 0-X orders, which can have 0-X events, sub totals, and conditionnal data (if "address is managed" then select * from A, else select * from B. And of course A and B have different structures).

Of course it can be done in a view, but everyhting is validated and I know the xml structure can change (it doesn't depend on me).

eeek! wait! *checking something*

OH MY GOD, I'm sorry, I did give bad information!

-> the slow part is in fact:

SELECT XMLCONCAT(:B2 , :B1 )
FROM
DUAL


call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 400 5272.47 5179.63 1 1166977 6780827 0
Fetch 400 67.85 66.53 0 753058 5544826 400
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 800 5340.32 5246.17 1 1920035 12325653 400



and not:
SELECT XMLAGG(XMLELEMENT("Account", XMLATTRIBUTES('New' AS "Command"),
XMLCONCAT(XMLELEMENT("SubNo", :B14 ), XMLELEMENT("IsPaperSub", :B13 ),
XMLELEMENT("WebAclSubNo", :B12 ), XMLELEMENT("Username", NULL),
XMLELEMENT("Password", NULL), XMLELEMENT("RegistrationDate", :B11 ),
XMLELEMENT("ExpirationDate", :B10 ), XMLELEMENT("Status", :B9 ),
XMLELEMENT("FirstName", :B8 ), XMLELEMENT("LastName", :B7 ),
XMLELEMENT("Email", :B6 ), XMLELEMENT("PhoneNumber", :B5 ),
XMLELEMENT("MobileNumber", :B4 ), :B3 , :B2 , :B1 )))
FROM
DUAL


call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 401 0.82 0.70 0 0 0 0
Fetch 401 0.18 0.19 0 0 0 401
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 802 1.00 0.90 0 0 0 401



-> what really does take a lot of time is in fact:

select xmlconcat(v_accounts_list, v_account)
into v_accounts_list
from dual;

Shame on me, shame on me, shame on me!

I did not see this select in my own code, and did assume that tkprof was displaying all calls to xmlconcat like "select xmlconcat from dual" for some who-knows reason...

The worst is that my very first suspect was precisely the "appending" of accounts to the big list Confused

I'm so sorry for the trouble Embarassed

I will use my good ol' temp_xml table. (In the main loop, accounts will be inserted into this temp table, and after the loop, a view will create the final "account_list").

and please forget me Wink

[Updated on: Wed, 29 November 2006 10:24]

Report message to a moderator

Re: roselan [message #206361 is a reply to message #206288] Wed, 29 November 2006 13:51 Go to previous messageGo to next message
roselan
Messages: 7
Registered: November 2006
Location: Lausanne, Switzerland
Junior Member

I did the change I planned, execution time dropped for 9h38 to 12 minutes Very Happy

basically, first create temp xml table:
create global temporary table T_XML(XML XMLTYPE)) on commit preserve rows;

  for loop

    ... blahblahblablah_blablabla...

    -- old
    --    select xmlconcat(v_accounts_list, v_account)
    --    into   v_accounts_list
    --    from   dual; 

    -- new
    insert into t_xml values (v_account);

  end loop;

  -- new  
  select xmlagg(xml)
  into   v_accounts_list
  from   t_xml;



It may be my solution, but you did light the path, so thank you++ Surprised
Re: roselan [message #206385 is a reply to message #206361] Wed, 29 November 2006 18:36 Go to previous message
JRowbottom
Messages: 5933
Registered: June 2006
Location: Sunny North Yorkshire, ho...
Senior Member
Fantastic performance gain!!!!

Glad I could be some help.
Previous Topic: How to get a count for this error query
Next Topic: ORA 06502 error
Goto Forum:
  


Current Time: Fri Dec 09 02:17:44 CST 2016

Total time taken to generate the page: 0.10847 seconds