Bug #105326 for Params-Validate: validate_pos() is very slow in some situations (PP.pm)

Thu Jun 18 07:04:10 2015 k-rindfrey [...] gmx.de - Ticket created

Subject:	validate_pos() is very slow in some situations (PP.pm)
Date:	Thu, 18 Jun 2015 13:03:57 +0200
To:	bug-params-validate [...] rt.cpan.org
From:	"Klaus Rindfrey" <k-rindfrey [...] gmx.de>

Hi Dave,

here's a problem with validate_pos() along with a patch that solves it:

After adding some missing validate_pos() calls to a script that generates complex xml i found the script running horribly slow:

It run ca 20 seconds before adding validate_pos() but 970 seconds after - about 46 times slower!

I have something like this:

sub do_something { validate_pos(@_, {type => OBJECT});

#...

}

and pass XML::LibXML::* objects to that subroutine.

I analyzed the situation using Devel::NYTProf and it turned out that the problem is in statement in line 102 of PP.pm (note that i run the pure perl implementation):

my $value = defined $p[$_] ? qq|"$p[$_]"| : 'undef';

Expression "$p[$_]" is problematic because XML::LibXML overloads the ""-operator, so "$p[$_]" triggers a complex method call. In case you pass a node (or document) having a large and complex structure, this takes a while to be computed and produces a large string. However, looking at your code i found that the result is normally thrown away and only used in case of an error. So i did a patch that evaluates "$p[$_]" only when needed (patched PP.pm is attached to this mail).

I also created a small example script (attachment miniexample.pl, not really minimal, but small enough to see what's going on). On my machine (Win7 running strawberry perl 5.18) this runs:

- ca 3 seconds if Params::Validate is completey commented out

- ca 360 seconds with Params::Validate 1.19 (unpatched)

- ca 3.1 seconds with Params::Validate 1.19 containing the patch attached to this mail

Hope you can fix the problem in a future version of Params::Validate. Till then i'll use the patch.

Regards,

Klaus

Message body is not shown because sender requested not to inline it.

Thu Jun 18 12:04:21 2015 DROLSKY [...] cpan.org - Correspondence added

On Thu Jun 18 07:04:10 2015, k-rindfrey@gmx.de wrote: Show quoted text

> Hi Dave, here's a problem with validate_pos() along with a patch that > solves > it: After adding some missing validate_pos() calls to a script that > generates > complex xml i found the script running horribly slow:It run ca 20 > seconds > before adding validate_pos() but 970 seconds after - about 46 times > slower! I > have something like this: sub do_something { > validate_pos(@_, {type => OBJECT}); #...} and pass XML::LibXML::* > objects to > that subroutine. I analyzed the situation using Devel::NYTProf and it > turned > out that the problem is in statement in line 102 of PP.pm (note that i > run the > pure perl implementation): my $value = defined $p[$_] ? qq|"$p[$_]"| : > 'undef'; > Expression "$p[$_]" is problematic because XML::LibXML overloads the > ""-operator, so "$p[$_]" triggers a complex method call. In case you > pass a > node (or document) having a large and complex structure, this takes a > while to > be computed and produces a large string. However, looking at your code > i found > that the result is normally thrown away and only used in case of an > error. So i > did a patch that evaluates "$p[$_]" only when needed (patched PP.pm is > attached > to this mail). I also created a small example script (attachment > miniexample.pl, not really minimal, but small enough to see what's > going on). > On my machine (Win7 running strawberry perl 5.18) this runs: - ca 3 > seconds if > Params::Validate is completey commented out- ca 360 seconds with > Params::Validate 1.19 (unpatched)- ca 3.1 seconds with > Params::Validate 1.19 > containing the patch attached to this mail Hope you can fix the > problem in a > future version of Params::Validate. Till then i'll use the patch.

If you could submit this as a diff, or even better yet, a pull request against https://github.com/autarch/Params-Validate, that would be very helpful. Thanks, -dave

Thu Jun 18 12:04:21 2015 The RT System itself - Status changed from 'new' to 'open'

Fri Jun 19 02:05:58 2015 k-rindfrey [...] gmx.de - Correspondence added

Subject:	Aw: [rt.cpan.org #105326] validate_pos() is very slow in some situations (PP.pm)
Date:	Fri, 19 Jun 2015 08:05:47 +0200
To:	bug-Params-Validate [...] rt.cpan.org
From:	"Klaus Rindfrey" <k-rindfrey [...] gmx.de>

Well, i didn't find a way how to attach files other than pictures to a github request. So i attached it here.

It should also be pointed out that the slowdown can be also observed with the xs, but i can't offer a patch for this since i'm completely inexperienced with xs.

Regards, Klaus

Gesendet: Donnerstag, 18. Juni 2015 um 18:04 Uhr Von: "Dave Rolsky via RT" <bug-Params-Validate@rt.cpan.org> An: k-rindfrey@gmx.de Betreff: [rt.cpan.org #105326] validate_pos() is very slow in some situations (PP.pm)

<URL: https://rt.cpan.org/Ticket/Display.html?id=105326 > On Thu Jun 18 07:04:10 2015, k-rindfrey@gmx.de wrote: > Hi Dave, here's a problem with validate_pos() along with a patch that > solves > it: After adding some missing validate_pos() calls to a script that > generates > complex xml i found the script running horribly slow:It run ca 20 > seconds > before adding validate_pos() but 970 seconds after - about 46 times > slower! I > have something like this: sub do_something { > validate_pos(@_, {type => OBJECT}); #...} and pass XML::LibXML::* > objects to > that subroutine. I analyzed the situation using Devel::NYTProf and it > turned > out that the problem is in statement in line 102 of PP.pm (note that i > run the > pure perl implementation): my $value = defined $p[$_] ? qq|"$p[$_]"| : > 'undef'; > Expression "$p[$_]" is problematic because XML::LibXML overloads the > ""-operator, so "$p[$_]" triggers a complex method call. In case you > pass a > node (or document) having a large and complex structure, this takes a > while to > be computed and produces a large string. However, looking at your code > i found > that the result is normally thrown away and only used in case of an > error. So i > did a patch that evaluates "$p[$_]" only when needed (patched PP.pm is > attached > to this mail). I also created a small example script (attachment > miniexample.pl, not really minimal, but small enough to see what's > going on). > On my machine (Win7 running strawberry perl 5.18) this runs: - ca 3 > seconds if > Params::Validate is completey commented out- ca 360 seconds with > Params::Validate 1.19 (unpatched)- ca 3.1 seconds with > Params::Validate 1.19 > containing the patch attached to this mail Hope you can fix the > problem in a > future version of Params::Validate. Till then i'll use the patch. If you could submit this as a diff, or even better yet, a pull request against https://github.com/autarch/Params-Validate, that would be very helpful. Thanks, -dave

Message body is not shown because sender requested not to inline it.

Mon Jun 22 06:12:58 2015 k-rindfrey [...] gmx.de - Correspondence added

Subject:	Aw: [rt.cpan.org #105326] validate_pos() is very slow in some situations (PP.pm)
Date:	Mon, 22 Jun 2015 12:12:46 +0200
To:	bug-Params-Validate [...] rt.cpan.org
From:	"Klaus Rindfrey" <k-rindfrey [...] gmx.de>

Just noticed that the additional parameter (_validate_one_param) is redundant.

So here's a new diff without that param.

Message body is not shown because sender requested not to inline it.

Sun Jun 28 14:06:28 2015 DROLSKY [...] cpan.org - Status changed from 'open' to 'resolved'

Sun Jun 28 14:06:30 2015 DROLSKY [...] cpan.org - Fixed in 1.20 added

Mon Jun 29 02:48:28 2015 k-rindfrey [...] gmx.de - Correspondence added

Subject:	Aw: [rt.cpan.org #105326] Resolved: validate_pos() is very slow in some situations (PP.pm)
Date:	Mon, 29 Jun 2015 08:48:09 +0200
To:	bug-Params-Validate [...] rt.cpan.org
From:	"Klaus Rindfrey" <k-rindfrey [...] gmx.de>

Many thanks for the fast and sound processing of the problem.

Gesendet: Sonntag, 28. Juni 2015 um 20:06 Uhr Von: "Dave Rolsky via RT" <bug-Params-Validate@rt.cpan.org> An: k-rindfrey@gmx.de Betreff: [rt.cpan.org #105326] Resolved: validate_pos() is very slow in some situations (PP.pm)

<URL: https://rt.cpan.org/Ticket/Display.html?id=105326 > According to our records, your request has been resolved. If you have any further questions or concerns, please respond to this message.