- 论坛徽章:
- 0
|
本帖最后由 sjdy521 于 2014-08-27 17:57 编辑
使用过程中发现，调用时间处理函数产生性能瓶颈
利用strace发现瓶颈主要是因为程序大量调用stat导致，比如：
strace perl -MTime::Local -e 'print timelocal(0,0,0,27,7,2014-1900)'
....
open("/etc/localtime", O_RDONLY) = 4
fstat(4, {st_mode=S_IFREG|0644, st_size=389, ...}) = 0
fstat(4, {st_mode=S_IFREG|0644, st_size=389, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2ab1c8a57000
read(4, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\4\0\0\0\4\0\0\0\0"..., 4096) = 389
lseek(4, -226, SEEK_CUR) = 163
read(4, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\4\0\0\0\4\0\0\0\0"..., 4096) = 226
close(4) = 0
munmap(0x2ab1c8a57000, 4096) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=389, ...}) = 0
close(3) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=389, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=389, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=389, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=389, ...}) = 0
write(1, "1409068800", 101409068800) = 10
exit_group(0)
可以看到一次timelocal，居然调用了5次的stat("/etc/localtime"
换用POSIX::mktime发现情况有好转，调用stat("/etc/localtime"的次数变为1次
strace perl -MPOSIX=mktime -e 'print mktime(0,0,0,27,7,2014-1900)'
....
open("/etc/localtime", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=389, ...}) = 0
fstat(3, {st_mode=S_IFREG|0644, st_size=389, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2b40c48da000
read(3, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\4\0\0\0\4\0\0\0\0"..., 4096) = 389
lseek(3, -226, SEEK_CUR) = 163
read(3, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\4\0\0\0\4\0\0\0\0"..., 4096) = 226
close(3) = 0
munmap(0x2b40c48da000, 4096) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=389, ...}) = 0
write(1, "1409068800", 101409068800) = 10
exit_group(0)
benchmark测试结果，在一般情况下mktime的性能也确实因为stat调用少而远高于timelocal
use Benchmark qw(:all) ;
use POSIX qw(mktime);
use Time::Local qw(timelocal);
sub test1{
mktime(0,0,0,26,7,114,0,0,-1);
}
sub test2{
timelocal(0,0,0,26,7,114);
}
timethese(1000000, {
Name1=>"test1",
Name2=>"test2",
}
);
Benchmark: timing 1000000 iterations of Name1, Name2...
Name1: 5 wallclock secs ( 1.99 usr + 2.85 sys = 4.84 CPU) @ 206611.57/s (n=1000000)
Name2: 27 wallclock secs (19.68 usr + 7.04 sys = 26.72 CPU) @ 37425.15/s (n=1000000)
为什么为频繁的去读取/etc/localtime文件呢，感到很奇怪，查了下这个文件的作用以及tzset()、timezone()等系统函数，才有所感悟，man tzset里有这样一段：
The tzset() function initializes the tzname variable from the TZ environment variable.
This function is automatically called by the other time conversion functions that
depend on the time zone. In a SysV-like environment it will also set the variables
timezone (seconds West of GMT) and daylight (0 if this time zone does not have any
daylight savings time rules, non-zero if there is a time during the year when daylight
savings time applies).
If the TZ variable does not appear in the environment, the tzname variable is initial-
ized with the best approximation of local wall clock time, as specified by the
tzfile(5)-format file localtime found in the system timezone directory (see below).
(One also often sees /etc/localtime used here, a symlink to the right file in the sys-
tem timezone directory.)
If the TZ variable does appear in the environment but its value is empty or its value
cannot be interpreted using any of the formats specified below, Coordinated Universal
Time (UTC) is used.
可以看到因为没有设置时区信息，系统会去读取/etc/localtime来获取相关的时区信息，这才导致stat调用的比较多
程序本身就是使用UTC，设置下$ENV{TZ}= "";
再strace下发现mktime已经不再去open或者stat /etc/localtime文件了 重新测试发现Benchmark性能也提升了4倍
Benchmark: timing 1000000 iterations of Name1, Name2...
Name1: 1 wallclock secs ( 1.24 usr + 0.00 sys = 1.24 CPU) @ 806451.61/s (n=1000000)
Name2: 9 wallclock secs ( 8.11 usr + 0.00 sys = 8.11 CPU) @ 123304.56/s (n=1000000)
另外，想吐槽的一点是，Time::Local模块是perl发行版内置的模块，官方的描述是“efficiently compute time from local and GMT time”
但和mktime相比性能差别很大，这算哪门子efficiently。。看来以后还是不敢用Time::Local::timelocal()了
|
|
免费注册
发表于 2014-08-27 17:52
