This queue is for tickets about the Time-Piece CPAN distribution.

Report information
The Basics
Id:
118927
Status:
open
Priority:
Low/Low
Queue:

People
Owner:
Nobody in particular
Requestors:
bbailey1024 [...] gmail.com
Cc:
AdminCc:

BugTracker
Severity:
(no value)
Broken in:
(no value)
Fixed in:
(no value)



Subject: strptime significantly slower in 1.30 and 1.31
Date: Wed, 23 Nov 2016 19:08:41 +0000
To: bug-Time-Piece@rt.cpan.org
From: Brian Bailey <bbailey1024@gmail.com>
The _mktime function was modified in Time::Piece 1.29_05 to include a call to Time::Local::timegm.
This results in a significant slowdown in strptime. The following benchmark demonstrates this.

#!/usr/bin/perl

use Time::Piece;
use Benchmark qw(:all);

my $time = "2016-11-21 00:00:00 -0000";

timethese(-20, {
'TP' => sub { my $tp = Time::Piece->strptime($time, "%Y-%m-%d %H:%M:%S %z"); }
});

Time::Piece 1.29

Benchmark: running TP for at least 20 CPU seconds...
        TP: 21 wallclock secs (20.95 usr +  0.00 sys = 20.95 CPU) @ 126935.70/s (n=2659303)


Time::Piece 1.31
Benchmark: running TP for at least 20 CPU seconds...
        TP: 22 wallclock secs (20.84 usr +  0.00 sys = 20.84 CPU) @ 65663.44/s (n=1368426)

The following NYTProf results identify Time::Local::timegm as the culprit (taken from our production environment).
Time::Piece 1.29
# spent 7.51ms within Time::Piece::_mktime which was called 457 times, avg 16µs/call:
# 457 times (7.51ms+0s) by Time::Piece::strptime at line 471, avg 16µs/call

Time::Piece 1.31
# spent 41.5ms (15.7+25.7) within Time::Piece::_mktime which was called 500 times, avg 83µs/call:
# 500 times (15.7ms+25.7ms) by Time::Piece::strptime at line 483, avg 83µs/call
# spent  25.7ms making 500 calls to Time::Local::timegm, avg 51µs/call

The functionality added in the above commit does not seem worth the overhead.

perl -v
This is perl 5, version 22, subversion 2 (v5.22.2) built for x86_64-linux
(with 30 registered patches, see perl -V for more detail)

uname -a
Linux host 4.4.26-gentoo #1 SMP Thu Nov 3 03:10:42 UTC 2016 x86_64 AMD Opteron(tm) Processor 6378 AuthenticAMD GNU/Linux



On Wed Nov 23 14:09:01 2016, bbailey1024@gmail.com wrote:
Show quoted text
> The _mktime function was modified in Time::Piece 1.29_05 to include a > call > to Time::Local::timegm. > https://github.com/rjbs/Time- > Piece/commit/e6156357c8a151287a097d3be93b3f060dc2ed36 > > This results in a significant slowdown in strptime. The following > benchmark > demonstrates this. > > #!/usr/bin/perl > > use Time::Piece; > use Benchmark qw(:all); > > my $time = "2016-11-21 00:00:00 -0000"; > > timethese(-20, { > 'TP' => sub { my $tp = Time::Piece->strptime($time, "%Y-%m-%d %H:%M:%S > %z"); } > }); > > Time::Piece 1.29 > > Benchmark: running TP for at least 20 CPU seconds... > TP: 21 wallclock secs (20.95 usr + 0.00 sys = 20.95 CPU) @ > 126935.70/s (n=2659303) > > > Time::Piece 1.31 > Benchmark: running TP for at least 20 CPU seconds... > TP: 22 wallclock secs (20.84 usr + 0.00 sys = 20.84 CPU) @ > 65663.44/s (n=1368426) > > The following NYTProf results identify Time::Local::timegm as the > culprit > (taken from our production environment). > Time::Piece 1.29 > # spent 7.51ms within Time::Piece::_mktime which was called 457 times, > avg > 16µs/call: > # 457 times (7.51ms+0s) by Time::Piece::strptime at line 471, avg > 16µs/call > > Time::Piece 1.31 > # spent 41.5ms (15.7+25.7) within Time::Piece::_mktime which was > called 500 > times, avg 83µs/call: > # 500 times (15.7ms+25.7ms) by Time::Piece::strptime at line 483, avg > 83µs/call > # spent 25.7ms making 500 calls to Time::Local::timegm, avg 51µs/call > > The functionality added in the above commit does not seem worth the > overhead. > > perl -v > This is perl 5, version 22, subversion 2 (v5.22.2) built for x86_64- > linux > (with 30 registered patches, see perl -V for more detail) > > uname -a > Linux host 4.4.26-gentoo #1 SMP Thu Nov 3 03:10:42 UTC 2016 x86_64 AMD > Opteron(tm) Processor 6378 AuthenticAMD GNU/Linux
I've got this on the radar. Not sure if I can change my logic, but I can lazy evaluate whether TP has the epoch attr set or not. Or in the case with strptime, I could return the epoch from the C function it self which would be much faster (or atleast I will find out)


This service runs on Request Tracker, is sponsored by The Perl Foundation, and maintained by Best Practical Solutions.

Please report any issues with rt.cpan.org to rt-cpan-admin@bestpractical.com.