Skip Menu |

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

Report information
The Basics
Id: 118927
Status: open
Priority: 0/
Queue: Time-Piece

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

Bug Information
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. 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
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)