You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@daffodil.apache.org by Steve Lawrence <sl...@apache.org> on 2024/01/02 14:18:28 UTC
Re: Parsing 5 million lines of input is taking 4 minutes - too slow!
You are correct that daffodil builds an internal infoset and then
serializes that to something else (e.g. XML, EXI, JSON). One way to get
a decent approximation for how much time is used for the former is to
use the "null" infoset outputter, e.g.
daffodil parse -I null ...
This still parses data and builds the internal infoset but turns infoset
serialization into a no-op.
On 2023-12-26 02:04 PM, Roger L Costello wrote:
> Hi Folks,
>
> My input file contains 5 million 132-character records.
>
> I have done everything that I can think of to make the parsing faster:
>
> 1. I precompiled the schema and used it to do the parsing
> 2. I set Java -Xmx40960m
> 3. I used a bunch of dfdl:choiceDispatchKey to divide-and-conquer
>
> And yet it still takes 4 minutes before the (4 GB) XML file is produced.
> Waiting 4 minutes is not acceptable for my clients.
>
> A couple of questions:
>
> 1. Is there anything else that I can do to speed things up?
> 2. I believe there is time needed to do the parsing and generate an
> in-memory parse tree, and there is time needed to serialize the
> in-memory parse tree to an XML file. Is there a way to find those
> two times? I suspect the former is a lot quicker than the latter.
>
> /Roger
>
Re: Parsing 5 million lines of input is taking 4 minutes - too slow!
Posted by Roger L Costello <co...@mitre.org>.
Thanks Steve. I will add another layer of dfdl:choiceDispatchKey.
I really don’t like dfdl:choiceDispatchKey. Here’s why. DFDL is a language for describing data formats. It’s (supposed to be) a declarative language, not a procedural language. The dfdl:choiceDispatchKey key is clearly an if-then-else construct in disguise. The more layers of dfdl:choiceDispatchKey that I use, the less declarative my DFDL schema becomes, the more procedural it becomes.
For the data format that I am dealing with, I should be able to simply have a huge xs:choice like this:
<xs:choice>
<xs:element ref=”A”/>
<xs:element ref=”B”/>
<xs:element ref=”C”/>
<xs:element ref=”D”/>
<xs:element ref=”E”/>
<xs:element ref=”F”/>
…
<xs:element ref=”X”/>
<xs:element ref=”Y”/>
<xs:element ref=”Z”/>
</xs:choice>
I realize that would require Daffodil to do a gazillion backtrackings. So what. Not my problem. It’s Daffodil’s problem to deal with a gazillion backtrackings. And do it in a super-fast, high performance way.
Instead, I have to design my DFDL schema to do a lot of the work: if this field has the value x then if that field has the value y then if that other field has the value z then do <xs:element ref=”K”/>
That should not be my job in a language that is intended to “describe” a data format.
That’s the way I see it.
I like DFDL. A lot. But I really don’t like the procedural stuff in it (such as dfdl:choiceDispatchKey). If I had my way, I would get rid of all that procedural stuff from DFDL and make it purely descriptive.
/Roger
From: Steve Lawrence <sl...@apache.org>
Sent: Friday, January 5, 2024 2:29 PM
To: users@daffodil.apache.org
Subject: [EXT] Re: Parsing 5 million lines of input is taking 4 minutes - too slow!
Roger, I've taken a look at your schema, and it does look like excessive backtracking is potentially part of the issue. Although many of your outer choices use direct dispatch, some of the inner-choices do not. I'll try to stay general in my
Roger,
I've taken a look at your schema, and it does look like excessive
backtracking is potentially part of the issue. Although many of your
outer choices use direct dispatch, some of the inner-choices do not.
I'll try to stay general in my examples so the discussions can stay
public, but if the solution isn't clear let me know and we can talk
privately.
Your schema has a lot of choices that look like this:
<choice>
<element ref="Foo_PrimaryRecords" />
<element ref="Foo_SecondaryRecords" />
<element ref="Foo_TertiaryRecords" />
...
</choice>
With each of those looking something like this:
<element name="Foo_PrimaryRecords">
<complexType>
<sequence>
<element name="field1" ... />
<element name="field2" ... />
<element name="field3" ...>
<simpleType>
<restriction base="validString">
<enumeration value="A" />
</restriction>
</simpleType>
</element>
</sequence>
<!-- fields specific to Foo_PrimaryRecord -->
</complexType>
</element>
<element name="Foo_SecondaryRecords">
<complexType>
<sequence>
<element name="field1" ... />
<element name="field2" ... />
<element name="field3" ...>
<simpleType>
<restriction base="validString">
<enumeration value="B" />
</restriction>
</simpleType>
</element>
</sequence>
<!-- fields specific to Foo_SecondaryRecord -->
</complexType>
</element>
And something similar for the TertiaryRecords.
Note that the first few fields are exactly the same, differing only
after field3, and based on the valid of field3. This means, for example,
that if the record is a tertiary record, then Daffodil will need to
repeatedly parse the same first fields and backtrack before the
validString assertion finally succeeds. So in order to parse one record,
we may parse the same fields multiple times, which is inefficient and
could slow things down.
What we really need to avoid this is direct dispatch on these choices,
but it does require a little restructuring. Instead, you could replace
the above choice with something like this:
<element name="Foo_Records">
<complexType>
<sequence>
<element name="field1" ... />
<element name="field2" ... />
<element name="field3" ... />
<choice dfdl:choiceDispatchKey="{ ./field3 }">
<element ref="Foo_PrimaryRecords" dfdl:choiceBranchKey="A" />
<element ref="Foo_SecondaryRecords" dfdl:choiceBranchKey="B" />
<element ref="Foo_TertiaryRecords" dfdl:choiceBranchKey="C" />
</choice>
</sequence>
</complexType>
</element>
And then each of the Foo_*Records elements contain only fields specific
to that group of records (i.e. what they have now without the first
common fields). And note that those might contain even more choices. For
example, maybe Foo_SecondaryRecords has a choice of
Foo_SecondaryOldRecords and Foo_SecondaryNewRecords.
You already do something similar for some of your outer choices--doing
it for all the choices should help to speed things up.
I'm sure there are still performance improvements we can make to
Daffodil to optimize text parsing, but these kinds of changes should
help quite in the mean time.
On 2024-01-04 01:54 PM, Mike Beckerle wrote:
> Roger said: So, that means it takes 130 seconds to parse the
> 5-million-line input file and build an internal infoset but only 96
> seconds to create the 4 GB XML file. That makes no sense.
>
> I agree with you that parsing 5M records and it taking 2 minutes ...
> something is clearly wrong and it is much too slow.
> 2 minutes to a modern CPU is like the Jurassic Age to a human. I.e.,
> it's an almost unimaginably long time.
>
> But parsing taking longer than writing out XML */can/* make sense
> depending on the format complexity. Writing out 4GB of XML is just a
> bunch of text I/O. Per byte that's pretty fast.
>
> The speed of DFDL parsing is proportional to /the number of decisions/
> the parser must make, which is linearly, but weakly, correlated to the
> data size. The constant factors vary widely with the format.
>
> For an extreme example: there is a mil-std-2045 message header that is
> 33 bits long. It mostly consists of hidden groups of presence bits that
> are 0 indicating that some optional component is not present. Each such
> bit requires a DFDL choice of two possibilities, evaluation of a
> choice-dispatch-key expression or a occursCount expression, and most of
> those then create *nothing* in the infoset. So a bunch of overhead to
> consume 1 bit of input and decide to add nothing to the infoset. Repeat
> almost 30 times. You have now consumed less than 5 bytes of the input.
> In terms of parse speed in bytes/second this is going to be super slow
> because every byte requires a bunch of parser decision making. Writing
> out the corresponding 956 bytes of XML text is going to be very quick in
> comparison to this parsing.
>
> (FYI: This extreme example is on github here:
> https://github.com/DFDLSchemas/mil-std-2045/blob/master/src/test/resources/com/owlcyberdefense/mil-std-2045/milstd2045.tdml <https://github.com/DFDLSchemas/mil-std-2045/blob/master/src/test/resources/com/owlcyberdefense/mil-std-2045/milstd2045.tdml>
> The test is named test_2045_C_minimum_size_header. )
>
> I realize your data and schema likely don't have such extreme behavior.
>
> We need to get your schema so we can figure out where the performance
> problem is, whether there is a workaround, and what kind of Daffodil
> features would eliminate all this guesswork about what's slow about it.
>
> On Thu, Jan 4, 2024 at 3:59 AM Roger L Costello <costello@mitre.org
> <ma...@mitre.org>> wrote:
>
> Steve wrote:____
>
> __ __
>
> __Ø__One way to get a decent approximation for how much time is used for
> the former [build an internal infoset] is to use the "null" infoset
> outputter, e.g.____
>
> __Ø____ __
>
> __Ø__ daffodil parse -I null ...____
>
> __ __
>
> __Ø__This still parses data and builds the internal infoset but turns
> infoset ____
>
> * serialization into a no-op.____
>
> __ __
>
> Thanks Steve. I did as you suggested and here’s the result:____
>
> __ __
>
> * 130 seconds____
>
> __ __
>
> That is super surprising. I would have expected it to take much,
> much less time.____
>
> __ __
>
> So, that means it takes 130 seconds to parse the 5-million-line
> input file and build an internal infoset but only 96 seconds to
> create the 4 GB XML file. That makes no sense.____
>
> __ __
>
> /Roger____
>
> __ __
>
> *From:*Steve Lawrence <slawrence@apache.org
> <ma...@apache.org>>
> *Sent:* Tuesday, January 2, 2024 9:18 AM
> *To:* users@daffodil.apache.org<ma...@daffodil.apache.org> <ma...@daffodil.apache.org>
> *Subject:* [EXT] Re: Parsing 5 million lines of input is taking 4
> minutes - too slow!____
>
> __ __
>
> You are correct that daffodil builds an internal infoset and then
> serializes that to something else (e. g. XML, EXI, JSON). One way to
> get a decent approximation for how much time is used for the former
> is to use the "null" infoset outputter, ____
>
> ZjQcmQRYFpfptBannerStart____
>
> You are correct that daffodil builds an internal infoset and then ____
>
> serializes that to something else (e.g. XML, EXI, JSON). One way to
> get ____
>
> a decent approximation for how much time is used for the former is
> to ____
>
> use the "null" infoset outputter, e.g.____
>
> __ __
>
> daffodil parse -I null ...____
>
> __ __
>
> This still parses data and builds the internal infoset but turns
> infoset ____
>
> serialization into a no-op.____
>
> __ __
>
> On 2023-12-26 02:04 PM, Roger L Costello wrote:____
>
> > Hi Folks,____
>
> > ____
>
> > My input file contains 5 million 132-character records.____
>
> > ____
>
> > I have done everything that I can think of to make the parsing faster:____
>
> > ____
>
> > 1. I precompiled the schema and used it to do the parsing____
>
> > 2. I set Java -Xmx40960m____
>
> > 3. I used a bunch of dfdl:choiceDispatchKey to divide-and-conquer____
>
> > ____
>
> > And yet it still takes 4 minutes before the (4 GB) XML file is produced. ____
>
> > Waiting 4 minutes is not acceptable for my clients.____
>
> > ____
>
> > A couple of questions:____
>
> > ____
>
> > 1. Is there anything else that I can do to speed things up?____
>
> > 2. I believe there is time needed to do the parsing and generate an____
>
> > in-memory parse tree, and there is time needed to serialize the____
>
> > in-memory parse tree to an XML file. Is there a way to find those____
>
> > two times? I suspect the former is a lot quicker than the latter.____
>
> > ____
>
> > /Roger____
>
> > ____
>
> __ __
>
Re: Parsing 5 million lines of input is taking 4 minutes - too slow!
Posted by Steve Lawrence <sl...@apache.org>.
I'm sorry to hear that didn't make much of a difference. I think this
goes to show the importance adding some kind of measuring system to
Daffodil so we can make more educated guesses where the slow downs are
and if schema changes would make a difference.
We did recently do some profiling on your schema and a test we file
found online. This found one obvious bit of unoptimized code with a
fairly simple fix that saw about 15% faster parse time in my testing
(with a null infoset outputter). This has been merged, so if you are
able to build Daffodil from the main branch it might be interesting to
see how that affects the timings with your test file
On 2024-01-11 11:54 AM, Roger L Costello wrote:
> Update on my DFDL schema …
>
> I spent 40 hours adding a third layer of dfdl:choiceDispatchKey. That
> has made the DFDL schema extremely complicated. Now my DFDL schema
> requires no backtracking. Previously, before adding the third layer of
> dfdl:choiceDispatchKey, it took 226 seconds to parse the input file.
> Now, with the third layer of dfdl:choiceDispatchKey and no backtracking
> it takes 214 seconds. So, after putting in 40 hours of work, introducing
> a ton of complexity, eliminating all backtracking, I get a savings of 12
> seconds.
>
> *From:* Mike Beckerle <mb...@apache.org>
> *Sent:* Tuesday, January 9, 2024 6:12 PM
> *To:* users@daffodil.apache.org
> *Subject:* [EXT] Re: Parsing 5 million lines of input is taking 4
> minutes - too slow!
>
> I was thinking about instrumentation output from Daffodil that would
> make it clear how many attempts to parse each choice branch that end in
> backtracking are done. A histogram listing each element declaration, and
> how many times it is parsed
>
> I was thinking about instrumentation output from Daffodil that would
> make it clear how many attempts to parse each choice branch that end in
> backtracking are done.
>
> A histogram listing each element declaration, and how many times it is
> parsed would basically tell you whether things were being parsed over
> and over. When something is parsed many more times than its parent is
> parsed, that's an indication it's being parsed excessively.
>
> I want to comment on this refactoring of the schema:
>
> What we really need ... is direct dispatch on these choices,
>
> but it does require a little restructuring. Instead, you could replace
>
> the above choice with something like this:
>
> <element name="Foo_Records">
>
> <complexType>
>
> <sequence>
>
> <element name="field1" ... />
>
> <element name="field2" ... />
>
> <element name="field3" ... />
>
> <choice dfdl:choiceDispatchKey="{ ./field3 }">
>
> <element ref="Foo_PrimaryRecords"
> dfdl:choiceBranchKey="A" />
>
> <element ref="Foo_SecondaryRecords"
> dfdl:choiceBranchKey="B" />
>
> <element ref="Foo_TertiaryRecords"
> dfdl:choiceBranchKey="C" />
>
> </choice>
>
> </sequence>
>
> </complexType>
>
> </element>
>
> I think the above is elegant in that it expresses
>
> 1. that field1, 2, 3 are first and are uniformly defined in all the
> data (of these Foo records).
> 2. that only field3 is needed to determine which of Primary, Secondary,
> and Tertiary records is in the data.
>
> Those two things together are what enable an efficient non-backtracking
> parser to be created for this. They are also statements found in most
> data message format specifications buried somewhere in the prose. That
> information needs to be captured in the DFDL schema somehow that allows
> the implementation to take advantage of it.
>
> If you don't restructure the schema like the above, how else would you
> capture that information in the DFDL schema?
>
> Leaving these things out and just expressing a choice of a bunch of
> layouts,... in that case the DFDL schema is telling me much less about
> the format. It's not declaring the uniformity which is intentionally
> part of the format spec.
>
> On Fri, Jan 5, 2024 at 2:29 PM Steve Lawrence <slawrence@apache.org
> <ma...@apache.org>> wrote:
>
> Roger,
>
> I've taken a look at your schema, and it does look like excessive
> backtracking is potentially part of the issue. Although many of your
> outer choices use direct dispatch, some of the inner-choices do not.
> I'll try to stay general in my examples so the discussions can stay
> public, but if the solution isn't clear let me know and we can talk
> privately.
>
> Your schema has a lot of choices that look like this:
>
> <choice>
> <element ref="Foo_PrimaryRecords" />
> <element ref="Foo_SecondaryRecords" />
> <element ref="Foo_TertiaryRecords" />
> ...
> </choice>
>
> With each of those looking something like this:
>
> <element name="Foo_PrimaryRecords">
> <complexType>
> <sequence>
> <element name="field1" ... />
> <element name="field2" ... />
> <element name="field3" ...>
> <simpleType>
> <restriction base="validString">
> <enumeration value="A" />
> </restriction>
> </simpleType>
> </element>
> </sequence>
> <!-- fields specific to Foo_PrimaryRecord -->
> </complexType>
> </element>
>
> <element name="Foo_SecondaryRecords">
> <complexType>
> <sequence>
> <element name="field1" ... />
> <element name="field2" ... />
> <element name="field3" ...>
> <simpleType>
> <restriction base="validString">
> <enumeration value="B" />
> </restriction>
> </simpleType>
> </element>
> </sequence>
> <!-- fields specific to Foo_SecondaryRecord -->
> </complexType>
> </element>
>
> And something similar for the TertiaryRecords.
>
> Note that the first few fields are exactly the same, differing only
> after field3, and based on the valid of field3. This means, for
> example,
> that if the record is a tertiary record, then Daffodil will need to
> repeatedly parse the same first fields and backtrack before the
> validString assertion finally succeeds. So in order to parse one
> record,
> we may parse the same fields multiple times, which is inefficient and
> could slow things down.
>
> What we really need to avoid this is direct dispatch on these choices,
> but it does require a little restructuring. Instead, you could replace
> the above choice with something like this:
>
> <element name="Foo_Records">
> <complexType>
> <sequence>
> <element name="field1" ... />
> <element name="field2" ... />
> <element name="field3" ... />
> <choice dfdl:choiceDispatchKey="{ ./field3 }">
> <element ref="Foo_PrimaryRecords"
> dfdl:choiceBranchKey="A" />
> <element ref="Foo_SecondaryRecords"
> dfdl:choiceBranchKey="B" />
> <element ref="Foo_TertiaryRecords"
> dfdl:choiceBranchKey="C" />
> </choice>
> </sequence>
> </complexType>
> </element>
>
> And then each of the Foo_*Records elements contain only fields specific
> to that group of records (i.e. what they have now without the first
> common fields). And note that those might contain even more choices.
> For
> example, maybe Foo_SecondaryRecords has a choice of
> Foo_SecondaryOldRecords and Foo_SecondaryNewRecords.
>
> You already do something similar for some of your outer choices--doing
> it for all the choices should help to speed things up.
>
> I'm sure there are still performance improvements we can make to
> Daffodil to optimize text parsing, but these kinds of changes should
> help quite in the mean time.
>
>
> On 2024-01-04 01:54 PM, Mike Beckerle wrote:
> > Roger said: So, that means it takes 130 seconds to parse the
> > 5-million-line input file and build an internal infoset but only 96
> > seconds to create the 4 GB XML file. That makes no sense.
> >
> > I agree with you that parsing 5M records and it taking 2 minutes ...
> > something is clearly wrong and it is much too slow.
> > 2 minutes to a modern CPU is like the Jurassic Age to a human. I.e.,
> > it's an almost unimaginably long time.
> >
> > But parsing taking longer than writing out XML */can/* make sense
> > depending on the format complexity. Writing out 4GB of XML is
> just a
> > bunch of text I/O. Per byte that's pretty fast.
> >
> > The speed of DFDL parsing is proportional to /the number of
> decisions/
> > the parser must make, which is linearly, but weakly, correlated
> to the
> > data size. The constant factors vary widely with the format.
> >
> > For an extreme example: there is a mil-std-2045 message header
> that is
> > 33 bits long. It mostly consists of hidden groups of presence
> bits that
> > are 0 indicating that some optional component is not present.
> Each such
> > bit requires a DFDL choice of two possibilities, evaluation of a
> > choice-dispatch-key expression or a occursCount expression, and
> most of
> > those then create *nothing* in the infoset. So a bunch of
> overhead to
> > consume 1 bit of input and decide to add nothing to the infoset.
> Repeat
> > almost 30 times. You have now consumed less than 5 bytes of the
> input.
> > In terms of parse speed in bytes/second this is going to be super
> slow
> > because every byte requires a bunch of parser decision making.
> Writing
> > out the corresponding 956 bytes of XML text is going to be very
> quick in
> > comparison to this parsing.
> >
> > (FYI: This extreme example is on github here:
> >
> https://github.com/DFDLSchemas/mil-std-2045/blob/master/src/test/resources/com/owlcyberdefense/mil-std-2045/milstd2045.tdml <https://github.com/DFDLSchemas/mil-std-2045/blob/master/src/test/resources/com/owlcyberdefense/mil-std-2045/milstd2045.tdml> <https://github.com/DFDLSchemas/mil-std-2045/blob/master/src/test/resources/com/owlcyberdefense/mil-std-2045/milstd2045.tdml <https://github.com/DFDLSchemas/mil-std-2045/blob/master/src/test/resources/com/owlcyberdefense/mil-std-2045/milstd2045.tdml>>
> > The test is named test_2045_C_minimum_size_header. )
> >
> > I realize your data and schema likely don't have such extreme
> behavior.
> >
> > We need to get your schema so we can figure out where the
> performance
> > problem is, whether there is a workaround, and what kind of Daffodil
> > features would eliminate all this guesswork about what's slow
> about it.
> >
> > On Thu, Jan 4, 2024 at 3:59 AM Roger L Costello
> <costello@mitre.org <ma...@mitre.org>
> > <mailto:costello@mitre.org <ma...@mitre.org>>> wrote:
> >
> > Steve wrote:____
> >
> > __ __
> >
> > __Ø__One way to get a decent approximation for how much time
> is used for
> > the former [build an internal infoset] is to use the "null"
> infoset
> > outputter, e.g.____
> >
> > __Ø____ __
> >
> > __Ø__ daffodil parse -I null ...____
> >
> > __ __
> >
> > __Ø__This still parses data and builds the internal infoset
> but turns
> > infoset ____
> >
> > * serialization into a no-op.____
> >
> > __ __
> >
> > Thanks Steve. I did as you suggested and here’s the result:____
> >
> > __ __
> >
> > * 130 seconds____
> >
> > __ __
> >
> > That is super surprising. I would have expected it to take much,
> > much less time.____
> >
> > __ __
> >
> > So, that means it takes 130 seconds to parse the 5-million-line
> > input file and build an internal infoset but only 96 seconds to
> > create the 4 GB XML file. That makes no sense.____
> >
> > __ __
> >
> > /Roger____
> >
> > __ __
> >
> > *From:*Steve Lawrence <slawrence@apache.org
> <ma...@apache.org>
> > <mailto:slawrence@apache.org <ma...@apache.org>>>
> > *Sent:* Tuesday, January 2, 2024 9:18 AM
> > *To:* users@daffodil.apache.org
> <ma...@daffodil.apache.org> <mailto:users@daffodil.apache.org
> <ma...@daffodil.apache.org>>
> > *Subject:* [EXT] Re: Parsing 5 million lines of input is taking 4
> > minutes - too slow!____
> >
> > __ __
> >
> > You are correct that daffodil builds an internal infoset and then
> > serializes that to something else (e. g. XML, EXI, JSON). One
> way to
> > get a decent approximation for how much time is used for the
> former
> > is to use the "null" infoset outputter, ____
> >
> > ZjQcmQRYFpfptBannerStart____
> >
> > You are correct that daffodil builds an internal infoset and
> then ____
> >
> > serializes that to something else (e.g. XML, EXI, JSON). One
> way to
> > get ____
> >
> > a decent approximation for how much time is used for the
> former is
> > to ____
> >
> > use the "null" infoset outputter, e.g.____
> >
> > __ __
> >
> > daffodil parse -I null ...____
> >
> > __ __
> >
> > This still parses data and builds the internal infoset but turns
> > infoset ____
> >
> > serialization into a no-op.____
> >
> > __ __
> >
> > On 2023-12-26 02:04 PM, Roger L Costello wrote:____
> >
> > > Hi Folks,____
> >
> > > ____
> >
> > > My input file contains 5 million 132-character records.____
> >
> > > ____
> >
> > > I have done everything that I can think of to make the
> parsing faster:____
> >
> > > ____
> >
> > > 1. I precompiled the schema and used it to do the parsing____
> >
> > > 2. I set Java -Xmx40960m____
> >
> > > 3. I used a bunch of dfdl:choiceDispatchKey to
> divide-and-conquer____
> >
> > > ____
> >
> > > And yet it still takes 4 minutes before the (4 GB) XML file
> is produced. ____
> >
> > > Waiting 4 minutes is not acceptable for my clients.____
> >
> > > ____
> >
> > > A couple of questions:____
> >
> > > ____
> >
> > > 1. Is there anything else that I can do to speed things
> up?____
> >
> > > 2. I believe there is time needed to do the parsing and
> generate an____
> >
> > > in-memory parse tree, and there is time needed to
> serialize the____
> >
> > > in-memory parse tree to an XML file. Is there a way to
> find those____
> >
> > > two times? I suspect the former is a lot quicker than
> the latter.____
> >
> > > ____
> >
> > > /Roger____
> >
> > > ____
> >
> > __ __
> >
>
Re: Parsing 5 million lines of input is taking 4 minutes - too slow!
Posted by Roger L Costello <co...@mitre.org>.
Update on my DFDL schema …
I spent 40 hours adding a third layer of dfdl:choiceDispatchKey. That has made the DFDL schema extremely complicated. Now my DFDL schema requires no backtracking. Previously, before adding the third layer of dfdl:choiceDispatchKey, it took 226 seconds to parse the input file. Now, with the third layer of dfdl:choiceDispatchKey and no backtracking it takes 214 seconds. So, after putting in 40 hours of work, introducing a ton of complexity, eliminating all backtracking, I get a savings of 12 seconds.
From: Mike Beckerle <mb...@apache.org>
Sent: Tuesday, January 9, 2024 6:12 PM
To: users@daffodil.apache.org
Subject: [EXT] Re: Parsing 5 million lines of input is taking 4 minutes - too slow!
I was thinking about instrumentation output from Daffodil that would make it clear how many attempts to parse each choice branch that end in backtracking are done. A histogram listing each element declaration, and how many times it is parsed
I was thinking about instrumentation output from Daffodil that would make it clear how many attempts to parse each choice branch that end in backtracking are done.
A histogram listing each element declaration, and how many times it is parsed would basically tell you whether things were being parsed over and over. When something is parsed many more times than its parent is parsed, that's an indication it's being parsed excessively.
I want to comment on this refactoring of the schema:
What we really need ... is direct dispatch on these choices,
but it does require a little restructuring. Instead, you could replace
the above choice with something like this:
<element name="Foo_Records">
<complexType>
<sequence>
<element name="field1" ... />
<element name="field2" ... />
<element name="field3" ... />
<choice dfdl:choiceDispatchKey="{ ./field3 }">
<element ref="Foo_PrimaryRecords" dfdl:choiceBranchKey="A" />
<element ref="Foo_SecondaryRecords" dfdl:choiceBranchKey="B" />
<element ref="Foo_TertiaryRecords" dfdl:choiceBranchKey="C" />
</choice>
</sequence>
</complexType>
</element>
I think the above is elegant in that it expresses
1. that field1, 2, 3 are first and are uniformly defined in all the data (of these Foo records).
2. that only field3 is needed to determine which of Primary, Secondary, and Tertiary records is in the data.
Those two things together are what enable an efficient non-backtracking parser to be created for this. They are also statements found in most data message format specifications buried somewhere in the prose. That information needs to be captured in the DFDL schema somehow that allows the implementation to take advantage of it.
If you don't restructure the schema like the above, how else would you capture that information in the DFDL schema?
Leaving these things out and just expressing a choice of a bunch of layouts,... in that case the DFDL schema is telling me much less about the format. It's not declaring the uniformity which is intentionally part of the format spec.
On Fri, Jan 5, 2024 at 2:29 PM Steve Lawrence <sl...@apache.org>> wrote:
Roger,
I've taken a look at your schema, and it does look like excessive
backtracking is potentially part of the issue. Although many of your
outer choices use direct dispatch, some of the inner-choices do not.
I'll try to stay general in my examples so the discussions can stay
public, but if the solution isn't clear let me know and we can talk
privately.
Your schema has a lot of choices that look like this:
<choice>
<element ref="Foo_PrimaryRecords" />
<element ref="Foo_SecondaryRecords" />
<element ref="Foo_TertiaryRecords" />
...
</choice>
With each of those looking something like this:
<element name="Foo_PrimaryRecords">
<complexType>
<sequence>
<element name="field1" ... />
<element name="field2" ... />
<element name="field3" ...>
<simpleType>
<restriction base="validString">
<enumeration value="A" />
</restriction>
</simpleType>
</element>
</sequence>
<!-- fields specific to Foo_PrimaryRecord -->
</complexType>
</element>
<element name="Foo_SecondaryRecords">
<complexType>
<sequence>
<element name="field1" ... />
<element name="field2" ... />
<element name="field3" ...>
<simpleType>
<restriction base="validString">
<enumeration value="B" />
</restriction>
</simpleType>
</element>
</sequence>
<!-- fields specific to Foo_SecondaryRecord -->
</complexType>
</element>
And something similar for the TertiaryRecords.
Note that the first few fields are exactly the same, differing only
after field3, and based on the valid of field3. This means, for example,
that if the record is a tertiary record, then Daffodil will need to
repeatedly parse the same first fields and backtrack before the
validString assertion finally succeeds. So in order to parse one record,
we may parse the same fields multiple times, which is inefficient and
could slow things down.
What we really need to avoid this is direct dispatch on these choices,
but it does require a little restructuring. Instead, you could replace
the above choice with something like this:
<element name="Foo_Records">
<complexType>
<sequence>
<element name="field1" ... />
<element name="field2" ... />
<element name="field3" ... />
<choice dfdl:choiceDispatchKey="{ ./field3 }">
<element ref="Foo_PrimaryRecords" dfdl:choiceBranchKey="A" />
<element ref="Foo_SecondaryRecords" dfdl:choiceBranchKey="B" />
<element ref="Foo_TertiaryRecords" dfdl:choiceBranchKey="C" />
</choice>
</sequence>
</complexType>
</element>
And then each of the Foo_*Records elements contain only fields specific
to that group of records (i.e. what they have now without the first
common fields). And note that those might contain even more choices. For
example, maybe Foo_SecondaryRecords has a choice of
Foo_SecondaryOldRecords and Foo_SecondaryNewRecords.
You already do something similar for some of your outer choices--doing
it for all the choices should help to speed things up.
I'm sure there are still performance improvements we can make to
Daffodil to optimize text parsing, but these kinds of changes should
help quite in the mean time.
On 2024-01-04 01:54 PM, Mike Beckerle wrote:
> Roger said: So, that means it takes 130 seconds to parse the
> 5-million-line input file and build an internal infoset but only 96
> seconds to create the 4 GB XML file. That makes no sense.
>
> I agree with you that parsing 5M records and it taking 2 minutes ...
> something is clearly wrong and it is much too slow.
> 2 minutes to a modern CPU is like the Jurassic Age to a human. I.e.,
> it's an almost unimaginably long time.
>
> But parsing taking longer than writing out XML */can/* make sense
> depending on the format complexity. Writing out 4GB of XML is just a
> bunch of text I/O. Per byte that's pretty fast.
>
> The speed of DFDL parsing is proportional to /the number of decisions/
> the parser must make, which is linearly, but weakly, correlated to the
> data size. The constant factors vary widely with the format.
>
> For an extreme example: there is a mil-std-2045 message header that is
> 33 bits long. It mostly consists of hidden groups of presence bits that
> are 0 indicating that some optional component is not present. Each such
> bit requires a DFDL choice of two possibilities, evaluation of a
> choice-dispatch-key expression or a occursCount expression, and most of
> those then create *nothing* in the infoset. So a bunch of overhead to
> consume 1 bit of input and decide to add nothing to the infoset. Repeat
> almost 30 times. You have now consumed less than 5 bytes of the input.
> In terms of parse speed in bytes/second this is going to be super slow
> because every byte requires a bunch of parser decision making. Writing
> out the corresponding 956 bytes of XML text is going to be very quick in
> comparison to this parsing.
>
> (FYI: This extreme example is on github here:
> https://github.com/DFDLSchemas/mil-std-2045/blob/master/src/test/resources/com/owlcyberdefense/mil-std-2045/milstd2045.tdml <https://github.com/DFDLSchemas/mil-std-2045/blob/master/src/test/resources/com/owlcyberdefense/mil-std-2045/milstd2045.tdml>
> The test is named test_2045_C_minimum_size_header. )
>
> I realize your data and schema likely don't have such extreme behavior.
>
> We need to get your schema so we can figure out where the performance
> problem is, whether there is a workaround, and what kind of Daffodil
> features would eliminate all this guesswork about what's slow about it.
>
> On Thu, Jan 4, 2024 at 3:59 AM Roger L Costello <co...@mitre.org>
> <ma...@mitre.org>>> wrote:
>
> Steve wrote:____
>
> __ __
>
> __Ø__One way to get a decent approximation for how much time is used for
> the former [build an internal infoset] is to use the "null" infoset
> outputter, e.g.____
>
> __Ø____ __
>
> __Ø__ daffodil parse -I null ...____
>
> __ __
>
> __Ø__This still parses data and builds the internal infoset but turns
> infoset ____
>
> * serialization into a no-op.____
>
> __ __
>
> Thanks Steve. I did as you suggested and here’s the result:____
>
> __ __
>
> * 130 seconds____
>
> __ __
>
> That is super surprising. I would have expected it to take much,
> much less time.____
>
> __ __
>
> So, that means it takes 130 seconds to parse the 5-million-line
> input file and build an internal infoset but only 96 seconds to
> create the 4 GB XML file. That makes no sense.____
>
> __ __
>
> /Roger____
>
> __ __
>
> *From:*Steve Lawrence <sl...@apache.org>
> <ma...@apache.org>>>
> *Sent:* Tuesday, January 2, 2024 9:18 AM
> *To:* users@daffodil.apache.org<ma...@daffodil.apache.org> <ma...@daffodil.apache.org>>
> *Subject:* [EXT] Re: Parsing 5 million lines of input is taking 4
> minutes - too slow!____
>
> __ __
>
> You are correct that daffodil builds an internal infoset and then
> serializes that to something else (e. g. XML, EXI, JSON). One way to
> get a decent approximation for how much time is used for the former
> is to use the "null" infoset outputter, ____
>
> ZjQcmQRYFpfptBannerStart____
>
> You are correct that daffodil builds an internal infoset and then ____
>
> serializes that to something else (e.g. XML, EXI, JSON). One way to
> get ____
>
> a decent approximation for how much time is used for the former is
> to ____
>
> use the "null" infoset outputter, e.g.____
>
> __ __
>
> daffodil parse -I null ...____
>
> __ __
>
> This still parses data and builds the internal infoset but turns
> infoset ____
>
> serialization into a no-op.____
>
> __ __
>
> On 2023-12-26 02:04 PM, Roger L Costello wrote:____
>
> > Hi Folks,____
>
> > ____
>
> > My input file contains 5 million 132-character records.____
>
> > ____
>
> > I have done everything that I can think of to make the parsing faster:____
>
> > ____
>
> > 1. I precompiled the schema and used it to do the parsing____
>
> > 2. I set Java -Xmx40960m____
>
> > 3. I used a bunch of dfdl:choiceDispatchKey to divide-and-conquer____
>
> > ____
>
> > And yet it still takes 4 minutes before the (4 GB) XML file is produced. ____
>
> > Waiting 4 minutes is not acceptable for my clients.____
>
> > ____
>
> > A couple of questions:____
>
> > ____
>
> > 1. Is there anything else that I can do to speed things up?____
>
> > 2. I believe there is time needed to do the parsing and generate an____
>
> > in-memory parse tree, and there is time needed to serialize the____
>
> > in-memory parse tree to an XML file. Is there a way to find those____
>
> > two times? I suspect the former is a lot quicker than the latter.____
>
> > ____
>
> > /Roger____
>
> > ____
>
> __ __
>
Re: Parsing 5 million lines of input is taking 4 minutes - too slow!
Posted by Mike Beckerle <mb...@apache.org>.
I was thinking about instrumentation output from Daffodil that would make
it clear how many attempts to parse each choice branch that end in
backtracking are done.
A histogram listing each element declaration, and how many times it is
parsed would basically tell you whether things were being parsed over and
over. When something is parsed many more times than its parent is parsed,
that's an indication it's being parsed excessively.
I want to comment on this refactoring of the schema:
What we really need ... is direct dispatch on these choices,
but it does require a little restructuring. Instead, you could replace
the above choice with something like this:
<element name="Foo_Records">
<complexType>
<sequence>
<element name="field1" ... />
<element name="field2" ... />
<element name="field3" ... />
<choice dfdl:choiceDispatchKey="{ ./field3 }">
<element ref="Foo_PrimaryRecords" dfdl:choiceBranchKey="A" />
<element ref="Foo_SecondaryRecords" dfdl:choiceBranchKey="B" />
<element ref="Foo_TertiaryRecords" dfdl:choiceBranchKey="C" />
</choice>
</sequence>
</complexType>
</element>
I think the above is elegant in that it expresses
1. that field1, 2, 3 are first and are uniformly defined in all the data
(of these Foo records).
2. that only field3 is needed to determine which of Primary, Secondary,
and Tertiary records is in the data.
Those two things together are what enable an efficient non-backtracking
parser to be created for this. They are also statements found in most data
message format specifications buried somewhere in the prose. That
information needs to be captured in the DFDL schema somehow that allows the
implementation to take advantage of it.
If you don't restructure the schema like the above, how else would you
capture that information in the DFDL schema?
Leaving these things out and just expressing a choice of a bunch of
layouts,... in that case the DFDL schema is telling me much less about the
format. It's not declaring the uniformity which is intentionally part of
the format spec.
On Fri, Jan 5, 2024 at 2:29 PM Steve Lawrence <sl...@apache.org> wrote:
> Roger,
>
> I've taken a look at your schema, and it does look like excessive
> backtracking is potentially part of the issue. Although many of your
> outer choices use direct dispatch, some of the inner-choices do not.
> I'll try to stay general in my examples so the discussions can stay
> public, but if the solution isn't clear let me know and we can talk
> privately.
>
> Your schema has a lot of choices that look like this:
>
> <choice>
> <element ref="Foo_PrimaryRecords" />
> <element ref="Foo_SecondaryRecords" />
> <element ref="Foo_TertiaryRecords" />
> ...
> </choice>
>
> With each of those looking something like this:
>
> <element name="Foo_PrimaryRecords">
> <complexType>
> <sequence>
> <element name="field1" ... />
> <element name="field2" ... />
> <element name="field3" ...>
> <simpleType>
> <restriction base="validString">
> <enumeration value="A" />
> </restriction>
> </simpleType>
> </element>
> </sequence>
> <!-- fields specific to Foo_PrimaryRecord -->
> </complexType>
> </element>
>
> <element name="Foo_SecondaryRecords">
> <complexType>
> <sequence>
> <element name="field1" ... />
> <element name="field2" ... />
> <element name="field3" ...>
> <simpleType>
> <restriction base="validString">
> <enumeration value="B" />
> </restriction>
> </simpleType>
> </element>
> </sequence>
> <!-- fields specific to Foo_SecondaryRecord -->
> </complexType>
> </element>
>
> And something similar for the TertiaryRecords.
>
> Note that the first few fields are exactly the same, differing only
> after field3, and based on the valid of field3. This means, for example,
> that if the record is a tertiary record, then Daffodil will need to
> repeatedly parse the same first fields and backtrack before the
> validString assertion finally succeeds. So in order to parse one record,
> we may parse the same fields multiple times, which is inefficient and
> could slow things down.
>
> What we really need to avoid this is direct dispatch on these choices,
> but it does require a little restructuring. Instead, you could replace
> the above choice with something like this:
>
> <element name="Foo_Records">
> <complexType>
> <sequence>
> <element name="field1" ... />
> <element name="field2" ... />
> <element name="field3" ... />
> <choice dfdl:choiceDispatchKey="{ ./field3 }">
> <element ref="Foo_PrimaryRecords" dfdl:choiceBranchKey="A" />
> <element ref="Foo_SecondaryRecords" dfdl:choiceBranchKey="B" />
> <element ref="Foo_TertiaryRecords" dfdl:choiceBranchKey="C" />
> </choice>
> </sequence>
> </complexType>
> </element>
>
> And then each of the Foo_*Records elements contain only fields specific
> to that group of records (i.e. what they have now without the first
> common fields). And note that those might contain even more choices. For
> example, maybe Foo_SecondaryRecords has a choice of
> Foo_SecondaryOldRecords and Foo_SecondaryNewRecords.
>
> You already do something similar for some of your outer choices--doing
> it for all the choices should help to speed things up.
>
> I'm sure there are still performance improvements we can make to
> Daffodil to optimize text parsing, but these kinds of changes should
> help quite in the mean time.
>
>
> On 2024-01-04 01:54 PM, Mike Beckerle wrote:
> > Roger said: So, that means it takes 130 seconds to parse the
> > 5-million-line input file and build an internal infoset but only 96
> > seconds to create the 4 GB XML file. That makes no sense.
> >
> > I agree with you that parsing 5M records and it taking 2 minutes ...
> > something is clearly wrong and it is much too slow.
> > 2 minutes to a modern CPU is like the Jurassic Age to a human. I.e.,
> > it's an almost unimaginably long time.
> >
> > But parsing taking longer than writing out XML */can/* make sense
> > depending on the format complexity. Writing out 4GB of XML is just a
> > bunch of text I/O. Per byte that's pretty fast.
> >
> > The speed of DFDL parsing is proportional to /the number of decisions/
> > the parser must make, which is linearly, but weakly, correlated to the
> > data size. The constant factors vary widely with the format.
> >
> > For an extreme example: there is a mil-std-2045 message header that is
> > 33 bits long. It mostly consists of hidden groups of presence bits that
> > are 0 indicating that some optional component is not present. Each such
> > bit requires a DFDL choice of two possibilities, evaluation of a
> > choice-dispatch-key expression or a occursCount expression, and most of
> > those then create *nothing* in the infoset. So a bunch of overhead to
> > consume 1 bit of input and decide to add nothing to the infoset. Repeat
> > almost 30 times. You have now consumed less than 5 bytes of the input.
> > In terms of parse speed in bytes/second this is going to be super slow
> > because every byte requires a bunch of parser decision making. Writing
> > out the corresponding 956 bytes of XML text is going to be very quick in
> > comparison to this parsing.
> >
> > (FYI: This extreme example is on github here:
> >
> https://github.com/DFDLSchemas/mil-std-2045/blob/master/src/test/resources/com/owlcyberdefense/mil-std-2045/milstd2045.tdml
> <
> https://github.com/DFDLSchemas/mil-std-2045/blob/master/src/test/resources/com/owlcyberdefense/mil-std-2045/milstd2045.tdml
> >
> > The test is named test_2045_C_minimum_size_header. )
> >
> > I realize your data and schema likely don't have such extreme behavior.
> >
> > We need to get your schema so we can figure out where the performance
> > problem is, whether there is a workaround, and what kind of Daffodil
> > features would eliminate all this guesswork about what's slow about it.
> >
> > On Thu, Jan 4, 2024 at 3:59 AM Roger L Costello <costello@mitre.org
> > <ma...@mitre.org>> wrote:
> >
> > Steve wrote:____
> >
> > __ __
> >
> > __Ø__One way to get a decent approximation for how much time is used
> for
> > the former [build an internal infoset] is to use the "null" infoset
> > outputter, e.g.____
> >
> > __Ø____ __
> >
> > __Ø__ daffodil parse -I null ...____
> >
> > __ __
> >
> > __Ø__This still parses data and builds the internal infoset but turns
> > infoset ____
> >
> > * serialization into a no-op.____
> >
> > __ __
> >
> > Thanks Steve. I did as you suggested and here’s the result:____
> >
> > __ __
> >
> > * 130 seconds____
> >
> > __ __
> >
> > That is super surprising. I would have expected it to take much,
> > much less time.____
> >
> > __ __
> >
> > So, that means it takes 130 seconds to parse the 5-million-line
> > input file and build an internal infoset but only 96 seconds to
> > create the 4 GB XML file. That makes no sense.____
> >
> > __ __
> >
> > /Roger____
> >
> > __ __
> >
> > *From:*Steve Lawrence <slawrence@apache.org
> > <ma...@apache.org>>
> > *Sent:* Tuesday, January 2, 2024 9:18 AM
> > *To:* users@daffodil.apache.org <ma...@daffodil.apache.org>
> > *Subject:* [EXT] Re: Parsing 5 million lines of input is taking 4
> > minutes - too slow!____
> >
> > __ __
> >
> > You are correct that daffodil builds an internal infoset and then
> > serializes that to something else (e. g. XML, EXI, JSON). One way to
> > get a decent approximation for how much time is used for the former
> > is to use the "null" infoset outputter, ____
> >
> > ZjQcmQRYFpfptBannerStart____
> >
> > You are correct that daffodil builds an internal infoset and then
> ____
> >
> > serializes that to something else (e.g. XML, EXI, JSON). One way to
> > get ____
> >
> > a decent approximation for how much time is used for the former is
> > to ____
> >
> > use the "null" infoset outputter, e.g.____
> >
> > __ __
> >
> > daffodil parse -I null ...____
> >
> > __ __
> >
> > This still parses data and builds the internal infoset but turns
> > infoset ____
> >
> > serialization into a no-op.____
> >
> > __ __
> >
> > On 2023-12-26 02:04 PM, Roger L Costello wrote:____
> >
> > > Hi Folks,____
> >
> > > ____
> >
> > > My input file contains 5 million 132-character records.____
> >
> > > ____
> >
> > > I have done everything that I can think of to make the parsing
> faster:____
> >
> > > ____
> >
> > > 1. I precompiled the schema and used it to do the parsing____
> >
> > > 2. I set Java -Xmx40960m____
> >
> > > 3. I used a bunch of dfdl:choiceDispatchKey to
> divide-and-conquer____
> >
> > > ____
> >
> > > And yet it still takes 4 minutes before the (4 GB) XML file is
> produced. ____
> >
> > > Waiting 4 minutes is not acceptable for my clients.____
> >
> > > ____
> >
> > > A couple of questions:____
> >
> > > ____
> >
> > > 1. Is there anything else that I can do to speed things up?____
> >
> > > 2. I believe there is time needed to do the parsing and generate
> an____
> >
> > > in-memory parse tree, and there is time needed to serialize
> the____
> >
> > > in-memory parse tree to an XML file. Is there a way to find
> those____
> >
> > > two times? I suspect the former is a lot quicker than the
> latter.____
> >
> > > ____
> >
> > > /Roger____
> >
> > > ____
> >
> > __ __
> >
>
>
Re: Parsing 5 million lines of input is taking 4 minutes - too slow!
Posted by Steve Lawrence <sl...@apache.org>.
Roger,
I've taken a look at your schema, and it does look like excessive
backtracking is potentially part of the issue. Although many of your
outer choices use direct dispatch, some of the inner-choices do not.
I'll try to stay general in my examples so the discussions can stay
public, but if the solution isn't clear let me know and we can talk
privately.
Your schema has a lot of choices that look like this:
<choice>
<element ref="Foo_PrimaryRecords" />
<element ref="Foo_SecondaryRecords" />
<element ref="Foo_TertiaryRecords" />
...
</choice>
With each of those looking something like this:
<element name="Foo_PrimaryRecords">
<complexType>
<sequence>
<element name="field1" ... />
<element name="field2" ... />
<element name="field3" ...>
<simpleType>
<restriction base="validString">
<enumeration value="A" />
</restriction>
</simpleType>
</element>
</sequence>
<!-- fields specific to Foo_PrimaryRecord -->
</complexType>
</element>
<element name="Foo_SecondaryRecords">
<complexType>
<sequence>
<element name="field1" ... />
<element name="field2" ... />
<element name="field3" ...>
<simpleType>
<restriction base="validString">
<enumeration value="B" />
</restriction>
</simpleType>
</element>
</sequence>
<!-- fields specific to Foo_SecondaryRecord -->
</complexType>
</element>
And something similar for the TertiaryRecords.
Note that the first few fields are exactly the same, differing only
after field3, and based on the valid of field3. This means, for example,
that if the record is a tertiary record, then Daffodil will need to
repeatedly parse the same first fields and backtrack before the
validString assertion finally succeeds. So in order to parse one record,
we may parse the same fields multiple times, which is inefficient and
could slow things down.
What we really need to avoid this is direct dispatch on these choices,
but it does require a little restructuring. Instead, you could replace
the above choice with something like this:
<element name="Foo_Records">
<complexType>
<sequence>
<element name="field1" ... />
<element name="field2" ... />
<element name="field3" ... />
<choice dfdl:choiceDispatchKey="{ ./field3 }">
<element ref="Foo_PrimaryRecords" dfdl:choiceBranchKey="A" />
<element ref="Foo_SecondaryRecords" dfdl:choiceBranchKey="B" />
<element ref="Foo_TertiaryRecords" dfdl:choiceBranchKey="C" />
</choice>
</sequence>
</complexType>
</element>
And then each of the Foo_*Records elements contain only fields specific
to that group of records (i.e. what they have now without the first
common fields). And note that those might contain even more choices. For
example, maybe Foo_SecondaryRecords has a choice of
Foo_SecondaryOldRecords and Foo_SecondaryNewRecords.
You already do something similar for some of your outer choices--doing
it for all the choices should help to speed things up.
I'm sure there are still performance improvements we can make to
Daffodil to optimize text parsing, but these kinds of changes should
help quite in the mean time.
On 2024-01-04 01:54 PM, Mike Beckerle wrote:
> Roger said: So, that means it takes 130 seconds to parse the
> 5-million-line input file and build an internal infoset but only 96
> seconds to create the 4 GB XML file. That makes no sense.
>
> I agree with you that parsing 5M records and it taking 2 minutes ...
> something is clearly wrong and it is much too slow.
> 2 minutes to a modern CPU is like the Jurassic Age to a human. I.e.,
> it's an almost unimaginably long time.
>
> But parsing taking longer than writing out XML */can/* make sense
> depending on the format complexity. Writing out 4GB of XML is just a
> bunch of text I/O. Per byte that's pretty fast.
>
> The speed of DFDL parsing is proportional to /the number of decisions/
> the parser must make, which is linearly, but weakly, correlated to the
> data size. The constant factors vary widely with the format.
>
> For an extreme example: there is a mil-std-2045 message header that is
> 33 bits long. It mostly consists of hidden groups of presence bits that
> are 0 indicating that some optional component is not present. Each such
> bit requires a DFDL choice of two possibilities, evaluation of a
> choice-dispatch-key expression or a occursCount expression, and most of
> those then create *nothing* in the infoset. So a bunch of overhead to
> consume 1 bit of input and decide to add nothing to the infoset. Repeat
> almost 30 times. You have now consumed less than 5 bytes of the input.
> In terms of parse speed in bytes/second this is going to be super slow
> because every byte requires a bunch of parser decision making. Writing
> out the corresponding 956 bytes of XML text is going to be very quick in
> comparison to this parsing.
>
> (FYI: This extreme example is on github here:
> https://github.com/DFDLSchemas/mil-std-2045/blob/master/src/test/resources/com/owlcyberdefense/mil-std-2045/milstd2045.tdml <https://github.com/DFDLSchemas/mil-std-2045/blob/master/src/test/resources/com/owlcyberdefense/mil-std-2045/milstd2045.tdml>
> The test is named test_2045_C_minimum_size_header. )
>
> I realize your data and schema likely don't have such extreme behavior.
>
> We need to get your schema so we can figure out where the performance
> problem is, whether there is a workaround, and what kind of Daffodil
> features would eliminate all this guesswork about what's slow about it.
>
> On Thu, Jan 4, 2024 at 3:59 AM Roger L Costello <costello@mitre.org
> <ma...@mitre.org>> wrote:
>
> Steve wrote:____
>
> __ __
>
> __Ø__One way to get a decent approximation for how much time is used for
> the former [build an internal infoset] is to use the "null" infoset
> outputter, e.g.____
>
> __Ø____ __
>
> __Ø__ daffodil parse -I null ...____
>
> __ __
>
> __Ø__This still parses data and builds the internal infoset but turns
> infoset ____
>
> * serialization into a no-op.____
>
> __ __
>
> Thanks Steve. I did as you suggested and here’s the result:____
>
> __ __
>
> * 130 seconds____
>
> __ __
>
> That is super surprising. I would have expected it to take much,
> much less time.____
>
> __ __
>
> So, that means it takes 130 seconds to parse the 5-million-line
> input file and build an internal infoset but only 96 seconds to
> create the 4 GB XML file. That makes no sense.____
>
> __ __
>
> /Roger____
>
> __ __
>
> *From:*Steve Lawrence <slawrence@apache.org
> <ma...@apache.org>>
> *Sent:* Tuesday, January 2, 2024 9:18 AM
> *To:* users@daffodil.apache.org <ma...@daffodil.apache.org>
> *Subject:* [EXT] Re: Parsing 5 million lines of input is taking 4
> minutes - too slow!____
>
> __ __
>
> You are correct that daffodil builds an internal infoset and then
> serializes that to something else (e. g. XML, EXI, JSON). One way to
> get a decent approximation for how much time is used for the former
> is to use the "null" infoset outputter, ____
>
> ZjQcmQRYFpfptBannerStart____
>
> You are correct that daffodil builds an internal infoset and then ____
>
> serializes that to something else (e.g. XML, EXI, JSON). One way to
> get ____
>
> a decent approximation for how much time is used for the former is
> to ____
>
> use the "null" infoset outputter, e.g.____
>
> __ __
>
> daffodil parse -I null ...____
>
> __ __
>
> This still parses data and builds the internal infoset but turns
> infoset ____
>
> serialization into a no-op.____
>
> __ __
>
> On 2023-12-26 02:04 PM, Roger L Costello wrote:____
>
> > Hi Folks,____
>
> > ____
>
> > My input file contains 5 million 132-character records.____
>
> > ____
>
> > I have done everything that I can think of to make the parsing faster:____
>
> > ____
>
> > 1. I precompiled the schema and used it to do the parsing____
>
> > 2. I set Java -Xmx40960m____
>
> > 3. I used a bunch of dfdl:choiceDispatchKey to divide-and-conquer____
>
> > ____
>
> > And yet it still takes 4 minutes before the (4 GB) XML file is produced. ____
>
> > Waiting 4 minutes is not acceptable for my clients.____
>
> > ____
>
> > A couple of questions:____
>
> > ____
>
> > 1. Is there anything else that I can do to speed things up?____
>
> > 2. I believe there is time needed to do the parsing and generate an____
>
> > in-memory parse tree, and there is time needed to serialize the____
>
> > in-memory parse tree to an XML file. Is there a way to find those____
>
> > two times? I suspect the former is a lot quicker than the latter.____
>
> > ____
>
> > /Roger____
>
> > ____
>
> __ __
>
Re: Parsing 5 million lines of input is taking 4 minutes - too slow!
Posted by Mike Beckerle <mb...@apache.org>.
Roger said: So, that means it takes 130 seconds to parse the 5-million-line
input file and build an internal infoset but only 96 seconds to create the
4 GB XML file. That makes no sense.
I agree with you that parsing 5M records and it taking 2 minutes ...
something is clearly wrong and it is much too slow.
2 minutes to a modern CPU is like the Jurassic Age to a human. I.e., it's
an almost unimaginably long time.
But parsing taking longer than writing out XML *can* make sense depending
on the format complexity. Writing out 4GB of XML is just a bunch of text
I/O. Per byte that's pretty fast.
The speed of DFDL parsing is proportional to *the number of decisions* the
parser must make, which is linearly, but weakly, correlated to the data
size. The constant factors vary widely with the format.
For an extreme example: there is a mil-std-2045 message header that is 33
bits long. It mostly consists of hidden groups of presence bits that are 0
indicating that some optional component is not present. Each such bit
requires a DFDL choice of two possibilities, evaluation of a
choice-dispatch-key expression or a occursCount expression, and most of
those then create *nothing* in the infoset. So a bunch of overhead to
consume 1 bit of input and decide to add nothing to the infoset. Repeat
almost 30 times. You have now consumed less than 5 bytes of the input. In
terms of parse speed in bytes/second this is going to be super slow because
every byte requires a bunch of parser decision making. Writing out the
corresponding 956 bytes of XML text is going to be very quick in comparison
to this parsing.
(FYI: This extreme example is on github here:
https://github.com/DFDLSchemas/mil-std-2045/blob/master/src/test/resources/com/owlcyberdefense/mil-std-2045/milstd2045.tdml
The test is named test_2045_C_minimum_size_header. )
I realize your data and schema likely don't have such extreme behavior.
We need to get your schema so we can figure out where the performance
problem is, whether there is a workaround, and what kind of Daffodil
features would eliminate all this guesswork about what's slow about it.
On Thu, Jan 4, 2024 at 3:59 AM Roger L Costello <co...@mitre.org> wrote:
> Steve wrote:
>
>
>
> Ø One way to get a decent approximation for how much time is used for the former [build an internal infoset] is to use the "null" infoset outputter, e.g.
>
> Ø
>
> Ø daffodil parse -I null ...
>
>
>
> Ø This still parses data and builds the internal infoset but turns infoset
>
>
> - serialization into a no-op.
>
>
>
> Thanks Steve. I did as you suggested and here’s the result:
>
>
>
> - 130 seconds
>
>
>
> That is super surprising. I would have expected it to take much, much less
> time.
>
>
>
> So, that means it takes 130 seconds to parse the 5-million-line input file
> and build an internal infoset but only 96 seconds to create the 4 GB XML
> file. That makes no sense.
>
>
>
> /Roger
>
>
>
> *From:* Steve Lawrence <sl...@apache.org>
> *Sent:* Tuesday, January 2, 2024 9:18 AM
> *To:* users@daffodil.apache.org
> *Subject:* [EXT] Re: Parsing 5 million lines of input is taking 4 minutes
> - too slow!
>
>
>
> You are correct that daffodil builds an internal infoset and then
> serializes that to something else (e. g. XML, EXI, JSON). One way to get a
> decent approximation for how much time is used for the former is to use the
> "null" infoset outputter,
>
> ZjQcmQRYFpfptBannerStart
>
> You are correct that daffodil builds an internal infoset and then
>
> serializes that to something else (e.g. XML, EXI, JSON). One way to get
>
> a decent approximation for how much time is used for the former is to
>
> use the "null" infoset outputter, e.g.
>
>
>
> daffodil parse -I null ...
>
>
>
> This still parses data and builds the internal infoset but turns infoset
>
> serialization into a no-op.
>
>
>
> On 2023-12-26 02:04 PM, Roger L Costello wrote:
>
> > Hi Folks,
>
> >
>
> > My input file contains 5 million 132-character records.
>
> >
>
> > I have done everything that I can think of to make the parsing faster:
>
> >
>
> > 1. I precompiled the schema and used it to do the parsing
>
> > 2. I set Java -Xmx40960m
>
> > 3. I used a bunch of dfdl:choiceDispatchKey to divide-and-conquer
>
> >
>
> > And yet it still takes 4 minutes before the (4 GB) XML file is produced.
>
> > Waiting 4 minutes is not acceptable for my clients.
>
> >
>
> > A couple of questions:
>
> >
>
> > 1. Is there anything else that I can do to speed things up?
>
> > 2. I believe there is time needed to do the parsing and generate an
>
> > in-memory parse tree, and there is time needed to serialize the
>
> > in-memory parse tree to an XML file. Is there a way to find those
>
> > two times? I suspect the former is a lot quicker than the latter.
>
> >
>
> > /Roger
>
> >
>
>
>
>
Re: Parsing 5 million lines of input is taking 4 minutes - too slow!
Posted by Steve Lawrence <sl...@apache.org>.
It's actually not too surprising to me (not that that is a good thing).
If parsing to EXI takes 200 seconds (from a previous email) and parsing
to NULL takes 130 seconds, that means just outputting the EXI infoset
takes about 70 seconds. Assuming just building the internal infoset is
about the same order of magnitude as the EXI infoset at around 70
seconds (might not be a safe assumption), that means about 60 seconds is
spent for just parsing the data. If I'm doing my math right, that's
about 0.012 milliseconds per line.
That's still very slow in computer times, but text parsing is pretty
complex, especially if you have things like backtracking, pattern
discriminators, delimiter scanning, etc., all of which can cause
scanning the same data multiple times.
I'm sure there's room for performance improvements, but that is
something we haven't had a lot of time to focus on like we need to. It
is also made more difficult since different formats require different
optimizations--binary formats parse very differently than text formats,
for example. We tend to focus on formats that we commonly come across,
which tends not to be big text documents.
And as Mike points out, we don't really have the mechanisms for
measuring which parts of Daffodil take most of the time and where to
focus our efforts. Profilers have helped some in the past, but the
results tend to just be too noisy. Something like what Mike suggested
would probably help a lot.
On 2024-01-04 03:58 AM, Roger L Costello wrote:
> Steve wrote:
>
> ØOne way to get a decent approximation for how much time is used for the
> former [build an internal infoset] is to use the "null" infoset
> outputter, e.g.
>
> Ø
>
> Ø daffodil parse -I null ...
>
> ØThis still parses data and builds the internal infoset but turns infoset
>
> * serialization into a no-op.
>
> Thanks Steve. I did as you suggested and here’s the result:
>
> * 130 seconds
>
> That is super surprising. I would have expected it to take much, much
> less time.
>
> So, that means it takes 130 seconds to parse the 5-million-line input
> file and build an internal infoset but only 96 seconds to create the 4
> GB XML file. That makes no sense.
>
> /Roger
>
> *From:*Steve Lawrence <sl...@apache.org>
> *Sent:* Tuesday, January 2, 2024 9:18 AM
> *To:* users@daffodil.apache.org
> *Subject:* [EXT] Re: Parsing 5 million lines of input is taking 4
> minutes - too slow!
>
> You are correct that daffodil builds an internal infoset and then
> serializes that to something else (e. g. XML, EXI, JSON). One way to get
> a decent approximation for how much time is used for the former is to
> use the "null" infoset outputter,
>
> ZjQcmQRYFpfptBannerStart
>
> You are correct that daffodil builds an internal infoset and then
>
> serializes that to something else (e.g. XML, EXI, JSON). One way to get
>
> a decent approximation for how much time is used for the former is to
>
> use the "null" infoset outputter, e.g.
>
> daffodil parse -I null ...
>
> This still parses data and builds the internal infoset but turns infoset
>
> serialization into a no-op.
>
> On 2023-12-26 02:04 PM, Roger L Costello wrote:
>
>> Hi Folks,
>
>>
>
>> My input file contains 5 million 132-character records.
>
>>
>
>> I have done everything that I can think of to make the parsing faster:
>
>>
>
>> 1. I precompiled the schema and used it to do the parsing
>
>> 2. I set Java -Xmx40960m
>
>> 3. I used a bunch of dfdl:choiceDispatchKey to divide-and-conquer
>
>>
>
>> And yet it still takes 4 minutes before the (4 GB) XML file is produced.
>
>> Waiting 4 minutes is not acceptable for my clients.
>
>>
>
>> A couple of questions:
>
>>
>
>> 1. Is there anything else that I can do to speed things up?
>
>> 2. I believe there is time needed to do the parsing and generate an
>
>> in-memory parse tree, and there is time needed to serialize the
>
>> in-memory parse tree to an XML file. Is there a way to find those
>
>> two times? I suspect the former is a lot quicker than the latter.
>
>>
>
>> /Roger
>
>>
>
Re: Parsing 5 million lines of input is taking 4 minutes - too slow!
Posted by Roger L Costello <co...@mitre.org>.
Steve wrote:
Ø One way to get a decent approximation for how much time is used for the former [build an internal infoset] is to use the "null" infoset outputter, e.g.
Ø
Ø daffodil parse -I null ...
Ø This still parses data and builds the internal infoset but turns infoset
* serialization into a no-op.
Thanks Steve. I did as you suggested and here’s the result:
* 130 seconds
That is super surprising. I would have expected it to take much, much less time.
So, that means it takes 130 seconds to parse the 5-million-line input file and build an internal infoset but only 96 seconds to create the 4 GB XML file. That makes no sense.
/Roger
From: Steve Lawrence <sl...@apache.org>
Sent: Tuesday, January 2, 2024 9:18 AM
To: users@daffodil.apache.org
Subject: [EXT] Re: Parsing 5 million lines of input is taking 4 minutes - too slow!
You are correct that daffodil builds an internal infoset and then serializes that to something else (e. g. XML, EXI, JSON). One way to get a decent approximation for how much time is used for the former is to use the "null" infoset outputter,
ZjQcmQRYFpfptBannerStart
You are correct that daffodil builds an internal infoset and then
serializes that to something else (e.g. XML, EXI, JSON). One way to get
a decent approximation for how much time is used for the former is to
use the "null" infoset outputter, e.g.
daffodil parse -I null ...
This still parses data and builds the internal infoset but turns infoset
serialization into a no-op.
On 2023-12-26 02:04 PM, Roger L Costello wrote:
> Hi Folks,
>
> My input file contains 5 million 132-character records.
>
> I have done everything that I can think of to make the parsing faster:
>
> 1. I precompiled the schema and used it to do the parsing
> 2. I set Java -Xmx40960m
> 3. I used a bunch of dfdl:choiceDispatchKey to divide-and-conquer
>
> And yet it still takes 4 minutes before the (4 GB) XML file is produced.
> Waiting 4 minutes is not acceptable for my clients.
>
> A couple of questions:
>
> 1. Is there anything else that I can do to speed things up?
> 2. I believe there is time needed to do the parsing and generate an
> in-memory parse tree, and there is time needed to serialize the
> in-memory parse tree to an XML file. Is there a way to find those
> two times? I suspect the former is a lot quicker than the latter.
>
> /Roger
>