免费注册 查看新帖 |

Chinaunix

  平台 论坛 博客 文库
最近访问板块 发新帖
查看: 4782 | 回复: 7

perl mktime,strftime,timelocal性能问题 [复制链接]

论坛徽章:
0
发表于 2014-08-27 17:52 |显示全部楼层
本帖最后由 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()了


论坛徽章:
33
荣誉会员
日期:2011-11-23 16:44:17天秤座
日期:2014-08-26 16:18:20天秤座
日期:2014-08-29 10:12:18丑牛
日期:2014-08-29 16:06:45丑牛
日期:2014-09-03 10:28:58射手座
日期:2014-09-03 16:01:17寅虎
日期:2014-09-11 14:24:21天蝎座
日期:2014-09-17 08:33:55IT运维版块每日发帖之星
日期:2016-04-17 06:23:27操作系统版块每日发帖之星
日期:2016-04-18 06:20:00IT运维版块每日发帖之星
日期:2016-04-24 06:20:0015-16赛季CBA联赛之天津
日期:2016-05-06 12:46:59
发表于 2014-08-28 08:15 |显示全部楼层
请教楼主, 为啥忽然对 time 函数的性能这么关心了?

难道你和程序里要不停的取当前时间么?

论坛徽章:
0
发表于 2014-08-28 10:01 |显示全部楼层
回复 2# q1208c


    时间戳和字符串的转换这种场景很多啊,比如你的webserver或者其他的server,通常都要不停的打印日志,日志里一般都会包含字符串形式的时间,肯定也是时间戳转换来的
   
    我的程序是做访问日志分析,需要把访问日日志里形如[22/Aug/2014:00:00:00 +0800]的字符串形式的时间转换问时间戳然后进行相关的时间计算,会大量的调用mktime

论坛徽章:
33
荣誉会员
日期:2011-11-23 16:44:17天秤座
日期:2014-08-26 16:18:20天秤座
日期:2014-08-29 10:12:18丑牛
日期:2014-08-29 16:06:45丑牛
日期:2014-09-03 10:28:58射手座
日期:2014-09-03 16:01:17寅虎
日期:2014-09-11 14:24:21天蝎座
日期:2014-09-17 08:33:55IT运维版块每日发帖之星
日期:2016-04-17 06:23:27操作系统版块每日发帖之星
日期:2016-04-18 06:20:00IT运维版块每日发帖之星
日期:2016-04-24 06:20:0015-16赛季CBA联赛之天津
日期:2016-05-06 12:46:59
发表于 2014-08-28 10:12 |显示全部楼层
回复 3# sjdy521

对于分析日志, 我觉得这点时间还是可以接受的.

如果是生成日志, 这个时间是不能接受的.

不过, 我现在改用 HiRes 来处理时间了, 没注意过效率. 因为我需要的精度比 秒 要更高. 至少需要 ms 或者 us 级别.
   

论坛徽章:
0
发表于 2014-08-28 10:14 |显示全部楼层
回复 2# q1208c


    不是time() 是mktime()

论坛徽章:
0
发表于 2014-08-28 10:16 |显示全部楼层
回复 4# q1208c


    你没明白我整个事情,这个问题和精度无关

论坛徽章:
33
荣誉会员
日期:2011-11-23 16:44:17天秤座
日期:2014-08-26 16:18:20天秤座
日期:2014-08-29 10:12:18丑牛
日期:2014-08-29 16:06:45丑牛
日期:2014-09-03 10:28:58射手座
日期:2014-09-03 16:01:17寅虎
日期:2014-09-11 14:24:21天蝎座
日期:2014-09-17 08:33:55IT运维版块每日发帖之星
日期:2016-04-17 06:23:27操作系统版块每日发帖之星
日期:2016-04-18 06:20:00IT运维版块每日发帖之星
日期:2016-04-24 06:20:0015-16赛季CBA联赛之天津
日期:2016-05-06 12:46:59
发表于 2014-08-28 10:21 |显示全部楼层
回复 6# sjdy521

你也没明白我在说什么, 我说的也和精度无关.
   

论坛徽章:
42
19周年集字徽章-周
日期:2019-10-14 14:35:31平安夜徽章
日期:2015-12-26 00:06:30数据库技术版块每日发帖之星
日期:2015-12-01 06:20:002015亚冠之首尔
日期:2015-11-04 22:25:43IT运维版块每日发帖之星
日期:2015-08-17 06:20:00寅虎
日期:2014-06-04 16:25:27狮子座
日期:2014-05-12 11:00:00辰龙
日期:2013-12-20 17:07:19射手座
日期:2013-10-24 21:01:23CU十二周年纪念徽章
日期:2013-10-24 15:41:34IT运维版块每日发帖之星
日期:2016-01-27 06:20:0015-16赛季CBA联赛之新疆
日期:2016-06-07 14:10:01
发表于 2014-08-28 13:57 |显示全部楼层
直接记录unix原始秒 就不会有性能问题.
timelocal有问题, (字符串转秒)
那localtime是否也有问题?(秒转字符串)

另,凡是要用到localtime的地方,必须先设时区,这个是对系统安装的要求
否则差8小时的情况很常见
您需要登录后才可以回帖 登录 | 注册

本版积分规则 发表回复

  

北京盛拓优讯信息技术有限公司. 版权所有 京ICP备16024965号-6 北京市公安局海淀分局网监中心备案编号:11010802020122 niuxiaotong@pcpop.com 17352615567
未成年举报专区
中国互联网协会会员  联系我们:huangweiwei@itpub.net
感谢所有关心和支持过ChinaUnix的朋友们 转载本站内容请注明原作者名及出处

清除 Cookies - ChinaUnix - Archiver - WAP - TOP