Avoid DST-aware translation from localtime to GMT

[shino]

There is another call of httpd_util:rfc1123_date/1 in riak_cs, which was fixed in webmachine at [1].

[1] https://github.com/basho/webmachine/pull/158

[shino]

micro benchmark in my laptop

• riak 1 node
• riak cs 1 node
• keys: 1000
• size: 10 bytes
• driver: basho_bench_driver_cs
• operation: get
• concurrent: 8

• avoid-localtime-c8: this branch
• release15-c8: release/1.5 branch at 0570b66

[kuenishi]

For the completeness, I did following test with your branch - this is test on PUT:

(riak-cs@127.0.0.1)2> redbug:start("httpd_util:rfc1123_date -> return").
{420,2}
(riak-cs@127.0.0.1)3> 15:26:03.392 [debug] STS: ["PUT","\n",[],"\n","text/plain","\n","\n",[["x-amz-date",":",<<"Fri, 15 Aug 2014 06:26:03 +0000">>,"\n"],["x-amz-meta-s3cmd-attrs",":",<<"uid:1000/gname:kuenishi/uname:kuenishi/gid:1000/mode:33152/mtime:1406743920/atime:1408083955/md5:cbe3d5940c4f871a3a3737c6e54c05a2/ctime:1406743920">>,"\n"]],["/test/admin.txt",[]]]
15:26:03.395 [debug] Manifest: {lfs_manifest_v3,3,1048576,{<<"test">>,<<"admin.txt">>},[{"x-amz-meta-s3cmd-attrs","uid:1000/gname:kuenishi/uname:kuenishi/gid:1000/mode:33152/mtime:1406743920/atime:1406743926/md5:cbe3d5940c4f871a3a3737c6e54c05a2/ctime:1406743920"}],"2014-08-15T06:25:55.000Z",<<"à÷{ ;'Jn¤bªâ3Çøâ">>,1252,<<"text/plain">>,<<203,227,213,148,12,79,135,26,58,55,55,198,229,76,5,162>>,active,{1408,83955,533485},{1408,83955,536317},[],undefined,undefined,undefined,undefined,{acl_v2,{"admin","14915cd843fab8210c604b0f4d0c33e2f5c5d4ae25015819ba2fa498991892be","DRKBFDTPMY1XKGUGPSKQ"},[{{"admin","14915cd843fab8210c604b0f4d0c33e2f5c5d4ae25015819ba2fa498991892be"},['FULL_CONTROL']}],{1408,83955,527266}},[],undefined}
15:26:03.397 [debug] Calculated = <<203,227,213,148,12,79,135,26,58,55,55,198,229,76,5,162>>, Reported = undefined

15:26:03 <0.606.0>({mochiweb_acceptor,init,3}) {httpd_util,rfc1123_date,[]}

15:26:03 <0.606.0>({mochiweb_acceptor,init,3}) httpd_util:rfc1123_date/0 -> "Fri, 15 Aug 2014 06:26:03 GMT"
redbug done, timeout - 2

Also, this is a result of GET:

(riak-cs@127.0.0.1)3> redbug:start("httpd_util:rfc1123_date -> return").
{420,2}
(riak-cs@127.0.0.1)4> 15:26:26.289 [debug] STS: ["GET","\n",[],"\n",[],"\n","\n",[["x-amz-date",":",<<"Fri, 15 Aug 2014 06:26:26 +0000">>,"\n"]],["/test/admin.txt",[]]]
15:26:26.291 [debug] Manifest: {lfs_manifest_v3,3,1048576,{<<"test">>,<<"admin.txt">>},[{"x-amz-meta-s3cmd-attrs","uid:1000/gname:kuenishi/uname:kuenishi/gid:1000/mode:33152/mtime:1406743920/atime:1408083955/md5:cbe3d5940c4f871a3a3737c6e54c05a2/ctime:1406743920"}],"2014-08-15T06:26:03.000Z",<<233,25,74,156,60,102,74,252,170,117,165,127,158,231,3,15>>,1252,<<"text/plain">>,<<203,227,213,148,12,79,135,26,58,55,55,198,229,76,5,162>>,active,{1408,83963,395791},{1408,83963,397468},[],undefined,undefined,undefined,undefined,{acl_v2,{"admin","14915cd843fab8210c604b0f4d0c33e2f5c5d4ae25015819ba2fa498991892be","DRKBFDTPMY1XKGUGPSKQ"},[{{"admin","14915cd843fab8210c604b0f4d0c33e2f5c5d4ae25015819ba2fa498991892be"},['FULL_CONTROL']}],{1408,83963,395435}},[],undefined}
15:26:26.292 [debug] ObjAcl: {acl_v2,{"admin","14915cd843fab8210c604b0f4d0c33e2f5c5d4ae25015819ba2fa498991892be","DRKBFDTPMY1XKGUGPSKQ"},[{{"admin","14915cd843fab8210c604b0f4d0c33e2f5c5d4ae25015819ba2fa498991892be"},['FULL_CONTROL']}],{1408,83963,395435}}
CanonicalId: "14915cd843fab8210c604b0f4d0c33e2f5c5d4ae25015819ba2fa498991892be"
15:26:26.292 [debug] IsObjOwner: true
15:26:26.292 [debug] HasObjPerm: true
15:26:26.292 [debug] InitialBlock: 0, FinalBlock: 0
15:26:26.292 [debug] SkipInitial: 0, KeepFinal: 1252
15:26:26.292 [debug] Block Servers: [<0.735.0>]

15:26:26 <0.638.0>({mochiweb_acceptor,init,3}) {httpd_util,rfc1123_date,[]}

15:26:26 <0.638.0>({mochiweb_acceptor,init,3}) httpd_util:rfc1123_date/0 -> "Fri, 15 Aug 2014 06:26:26 GMT"
(riak-cs@127.0.0.1)4> 15:26:26.294 [debug] Retrieved block {<<233,25,74,156,60,102,74,252,170,117,165,127,158,231,3,15>>,0}
15:26:26.294 [debug] Returning block {<<233,25,74,156,60,102,74,252,170,117,165,127,158,231,3,15>>,0} to client

(riak-cs@127.0.0.1)4> 
(riak-cs@127.0.0.1)4> 
(riak-cs@127.0.0.1)4> 
redbug done, timeout - 2

There is another hiding rabbit, let's HUNT!

[kuenishi]

grepped:

(v)kuenishi@nausicaa:~/src/riak_cs$ find src -type f |grep "erl$"|xargs grep "httpd_util:rfc1123_date"
(v)kuenishi@nausicaa:~/src/riak_cs$ find deps -type f |grep "erl$"|xargs grep "httpd_util:rfc1123_date"
deps/webmachine/demo/src/webmachine_demo_fs_resource.erl:                    httpd_util:rfc1123_date(LMod)}|Context#context.metadata]}}.
deps/webmachine/src/webmachine_request.erl:            mochiweb_headers:enter("Date", httpd_util:rfc1123_date(), WithSrv);
deps/velvet/src/velvet.erl:                {"Date", httpd_util:rfc1123_date()}],
deps/velvet/src/velvet.erl:                {"Date", httpd_util:rfc1123_date()}],
deps/velvet/src/velvet.erl:    Headers0 = [{"Date", httpd_util:rfc1123_date()}],
deps/velvet/src/velvet.erl:    Headers0 = [{"Date", httpd_util:rfc1123_date()}],
deps/velvet/src/velvet.erl:                {"Date", httpd_util:rfc1123_date()}],
deps/velvet/src/velvet.erl:                {"Date", httpd_util:rfc1123_date()}],
deps/erlcloud/src/erlcloud_s3.erl:    Date = httpd_util:rfc1123_date(erlang:localtime()),
deps/mochiweb/src/mochiweb_cookies.erl:    httpd_util:rfc1123_date(add_seconds(Age, LocalTime)).
deps/mochiweb/src/mochiweb_request.erl:            LastModified = httpd_util:rfc1123_date(FileInfo#file_info.mtime),
deps/mochiweb/src/mochiweb_request.erl:     {"Date", httpd_util:rfc1123_date()}].

Seems like the rabbit is in mochiweb...

[shino]

Wonderful!

[shino]

I guess, the arity-1 one does no harm, arity-2 does.

From httpd_util.erl in R15B01:

rfc1123_date() ->
    {{YYYY,MM,DD},{Hour,Min,Sec}} = calendar:universal_time(),
    DayNumber = calendar:day_of_the_week({YYYY,MM,DD}),
    lists:flatten(
      io_lib:format("~s, ~2.2.0w ~3.s ~4.4.0w ~2.2.0w:~2.2.0w:~2.2.0w GMT",
                    [day(DayNumber),DD,month(MM),YYYY,Hour,Min,Sec])).

rfc1123_date(undefined) ->
    undefined;
rfc1123_date(LocalTime) ->
    {{YYYY,MM,DD},{Hour,Min,Sec}} = 
        case calendar:local_time_to_universal_time_dst(LocalTime) of
            [Gmt]   -> Gmt;
            [_,Gmt] -> Gmt
        end,
    DayNumber = calendar:day_of_the_week({YYYY,MM,DD}),
    lists:flatten(
      io_lib:format("~s, ~2.2.0w ~3.s ~4.4.0w ~2.2.0w:~2.2.0w:~2.2.0w GMT",
                    [day(DayNumber),DD,month(MM),YYYY,Hour,Min,Sec])).

[kuenishi]

Arity-1 and Arity-0 are both harmful, because both acquire the same lock and open same file.

https://gist.github.com/kuenishi/c9867a6f219343344f51

[kuenishi]

According to Shino's benchmark, /0 is not so slow. So what's slow? I'll leave this problem for later.

[shino]

microbench script https://gist.github.com/shino/5835263ec70ced844075

[shino]

@borshop merge