[mercury-users] XML Parsing (fwd)

Michael Day mikeday at corplink.com.au
Fri Jun 8 11:48:18 AEST 2001


Just to be absolutely sure it gets there, I'll include only the first few
lines...

---------- Forwarded message ----------
Date: Fri, 8 Jun 2001 11:46:26 +1000 (EST)
From: Michael Day <mikeday at corplink.com.au>
To: mercury-users at cs.mu.oz.au
Subject: Re: [mercury-users] XML Parsing (fwd)


This appears to have bounced due to size? So here is the profile with all
the boring bits stripped out...

---------- Forwarded message ----------
Date: Thu, 7 Jun 2001 20:20:03 +1000 (EST)
From: Michael Day <mikeday at corplink.com.au>
To: mercury-users at cs.mu.OZ.AU
Subject: Re: [mercury-users] XML Parsing


> Rather than just complaining about the poor performance, why don't you
> profile the application and see what is actually taking all the time?
> Then we might actually have something worth discussing.

Many apologies.

>From what I can see, 40% of the time is being spent in
xml:parse:chars:baseChar/2, which makes it look like character
interpretation *is* the culprit after all. Comments from people who know
how to understand profiles would be nice.

(the program executed was tryit compiled with -O6 and mgnuc with -O2 run
on a largish XML file with namespaces)


*** profiling user-plus-system-time ***


flat profile:

%		the percentage of total running time of the program
time		used by this procedure.

cumulative	the total number of seconds for the current procedure and
seconds		the ones listed above it.

self		the number of seconds accounted for by this procedure alone.
seconds		The listing is sorted on this row.

calls		the number of times this procedure was called.

self		the average number of milliseconds spent executing
ms/call  	this procedure per call.

total		the average number of milliseconds spent executing this procedure and its
ms/call  	descendents per call.

name		the name of the procedure followed by its index number.

   %  cumulative    self              self    total
 time    seconds  seconds    calls  ms/call  ms/call name
 40.6       5.10     5.10    14804     0.34     0.34 <predicate `xml:parse:chars:baseChar/2' mode 0> [1]
 11.2       6.50     1.40   886688     0.00     0.00 <predicate `parsing:tok/2' mode 0> [2]
  9.2       7.65     1.15   895577     0.00     0.00 <predicate `parsing:try/6' mode 19 (specialized) (minus unused args)> [3]
  8.0       8.65     1.00   852131     0.00     0.00 <predicate `parsing:reset/4' mode 0 (minus unused args)> [4]
  4.0       9.15     0.50   886688     0.00     0.00 <function `xml:encoding:./2' mode 0> [5]
  2.8       9.50     0.35  1022122     0.00     0.00 <predicate `parsing:actuate/3' mode 0> [7]
  2.8       9.85     0.35   227525     0.00     0.00 <pred goal (#2) from `parsing:lit1' line 393> [6]
  2.4      10.15     0.30   616078     0.00     0.00 <pred goal (#14) from `parsing:range' line 544> [8]
  2.4      10.45     0.30     9230     0.03     0.03 <predicate `xml:parse:charRef/2' mode 0> [9]
  2.0      10.70     0.25     1525     0.16     0.16 <predicate `xml:parse:chars:combiningChar/2' mode 0> [10]
  1.6      10.90     0.20   846337     0.00     0.00 <pred goal (#8) from `parsing:or' line 456 (minus unused args)> [11]
  1.6      11.10     0.20    12879     0.02     0.02 <predicate `xml:parse:nameChar/2' mode 0> [12]
  1.2      11.25     0.15    57367     0.00     0.00 <predicate `parsing:return/3' mode 0> [13]
  0.8      11.35     0.10   886688     0.00     0.00 <predicate `xml:encoding:decode_utf8/4' mode 0 (minus unused args)> [15]
  0.8      11.45     0.10   616078     0.00     0.00 <predicate `parsing:then/4' mode 15 (specialized) (minus unused args)> [14]
  0.4      11.50     0.05   908974     0.00     0.00 <predicate `char:to_int/2' mode 0> [32]
  0.4      11.55     0.05   895577     0.00     0.00 <predicate `parsing:or/4' mode 0> [21]
  0.4      11.60     0.05   886688     0.00     0.00 <predicate `xml:encoding:Introduced_pred_for_parsing:encoding:xml:encoding:utf8:arity0:::parsing:decode_4/4' mode 0> [24]
  0.4      11.65     0.05   616078     0.00     0.00 <predicate `parsing:-/4' mode 0> [22]
  0.4      11.70     0.05   227525     0.00     0.00 <predicate `parsing:lit1/3' mode 0> [20]
  0.4      11.75     0.05    31245     0.00     0.00 <predicate `term_io:write_escaped_char/3' mode 0> [35]
  0.4      11.80     0.05    28916     0.00     0.00 <predicate `parsing:try/6' mode 4 (specialized) (minus unused args)> [17]
  0.4      11.85     0.05    25694     0.00     0.00 <predicate `compare/3' mode 3> [37]
  0.4      11.90     0.05    22344     0.00     0.00 <pred goal (#24) from `parsing:lit2' line 419> [18]
  0.4      11.95     0.05    13000     0.00     0.00 <pred goal (#19) from `parsing:except' line 576> [19]
  0.4      12.00     0.05     8342     0.01     0.01 <predicate `io:write_univ/4' mode 0> [33]
  0.4      12.05     0.05     4308     0.01     0.01 <predicate `parsing:then/4' mode 18 (specialized) (minus unused args)> [16]
  0.4      12.10     0.05     2953     0.02     0.02 <pred goal (#84) from `xml:parse:chars:baseChar' line 143> [29]
  0.4      12.15     0.05     2892     0.02     0.02 <predicate `xml:encoding:Introduced_pred_for_parsing:encoding:xml:encoding:utf8:arity0:::parsing:encode_3/3' mode 0 (minus unused args)> [23]
  0.4      12.20     0.05     2553     0.02     0.02 <predicate `xml:parse:chars:digit/2' mode 0> [30]
  0.4      12.25     0.05     2073     0.02     0.02 <predicate `tree234:set/4' mode 1> [36]
  0.4      12.30     0.05     1925     0.03     0.03 <predicate `xml:parse:name/2' mode 0> [27]
  0.4      12.35     0.05     1525     0.03     0.03 <pred goal (#237) from `xml:parse:chars:combiningChar' line 221> [28]
  0.4      12.40     0.05     1525     0.03     0.03 <predicate `xml:parse:chars:extender/2' mode 0> [31]
  0.4      12.45     0.05      963     0.05     0.05 <pred goal (#608) from `xml:parse:entityRef' line 2439> [25]
  0.4      12.50     0.05      509     0.10     0.10 <predicate `io:write_list_tail/3' mode 0> [34]
  0.4      12.55     0.05      167     0.30     0.30 <pred goal (#289) from `xml:parse:eTag' line 1592> [26]
  0.0      12.55     0.00   886688     0.00     0.00 <predicate `xml:encoding:Introduced_pred_for_parsing:encoding:xml:encoding:utf8:arity0:::parsing:decode_4/4' mode 0 (minus unused args)> [120]
  0.0      12.55     0.00   886628     0.00     0.00 <predicate `string:unsafe_index/3' mode 0> [708]

--------------------------------------------------------------------------
mercury-users mailing list
post:  mercury-users at cs.mu.oz.au
administrative address: owner-mercury-users at cs.mu.oz.au
unsubscribe: Address: mercury-users-request at cs.mu.oz.au Message: unsubscribe
subscribe:   Address: mercury-users-request at cs.mu.oz.au Message: subscribe
--------------------------------------------------------------------------



More information about the users mailing list