From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.2 (2018-09-13) on dcvr.yhbt.net X-Spam-Level: X-Spam-Status: No, score=-3.0 required=3.0 tests=AWL,BAYES_00,DKIM_SIGNED, DKIM_VALID,RCVD_IN_DNSWL_NONE,SPF_HELO_NONE,SPF_NONE shortcircuit=no autolearn=ham autolearn_force=no version=3.4.2 Received: from mail-ej1-x635.google.com (mail-ej1-x635.google.com [IPv6:2a00:1450:4864:20::635]) (using TLSv1.3 with cipher TLS_AES_128_GCM_SHA256 (128/128 bits) key-exchange X25519 server-signature RSA-PSS (4096 bits) server-digest SHA256) (No client certificate requested) by dcvr.yhbt.net (Postfix) with ESMTPS id 8CB771F5AE for ; Tue, 28 Jul 2020 13:50:46 +0000 (UTC) Received: by mail-ej1-x635.google.com with SMTP id o18so20698653eje.7 for ; Tue, 28 Jul 2020 06:50:46 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=natanson-net.20150623.gappssmtp.com; s=20150623; h=mime-version:references:in-reply-to:from:date:message-id:subject:to :cc; bh=7ds7KuQ20AVhkPnr0A2hB3ZSLVrpyNVQCjayQ1vq/gU=; b=o1zmDbZiNLDr33BpnapViTTLpS+oZNRZowc23mTbiFMrtIAeM+l+4lGeokcf6y377H JPfn5s3yuzQt3oC/hDekQtrQEO5W90hEAk/ZRMv5n/ewuphW00TN1S5OEU57q1meVitE wC5LMdbPrfCML75lnnDT4K4Rtj66bGWhFNAiYzpvpL4WSesRnhdtHX0hUjXDmB98zz07 RzOo7WzZEG2FatxdYInHZknFs5xn7IwQrcxuYxyMeeOiPrpn0Q/190LaLkwYOTiURDte duk6yi4y4Lz3VGOv80DfP1iMUVJVEDNWPcpXLE2GAuPSuP7qNuhZcOlRqc70iRrMWbIH ou/g== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:mime-version:references:in-reply-to:from:date :message-id:subject:to:cc; bh=7ds7KuQ20AVhkPnr0A2hB3ZSLVrpyNVQCjayQ1vq/gU=; b=j/NuZjWrjO1PJ3Ggv79s7RoWCETP7t23eTa7noquuocZMCKGl/t0pFfxcZeesTf1NN K9uAWPMNsddKBgo6J0MpfCCwyPdVJtlRohWMfsXOxDj/OTY0brOsF6QuIkWPZ0ApnoDP ROkN2hOP7Jb4L0gs3YWbVVxtqTyd1uZB7WPvAdoknI+eScJfxIs4rA0x+WMZoMNeY/tL tRj++VZ6Q6jHGOS7RKnrpeUZ58W0i4Wy+5z+8VxK/U8vMCXPyDc20hQL3TyrUvHR9jLk Qa+J+3dLAMif4TY0LEu/I7NNJpsZF/0IweHZZJe1F8IzD0l8Vq6MD+WoKCrxr8oo9JCn 2G/g== X-Gm-Message-State: AOAM532r8Bfjd1RVkf9csdSby6bV4RJ+q/frSAn84Vhb0OGbNM8pj8ug MRr4FdeUIZgHhxN31e6wj8tbW+/JqI4ph+phay410RNihB32JA== X-Google-Smtp-Source: ABdhPJz+Qfuei6+RMrMEUYCu3wwJSrEph4oB1s14sX792ZeHZTwAgLgy0ZPZoH3db8rOEaITO50Gi2tuvaaAaM1OL4o= X-Received: by 2002:a17:906:fac3:: with SMTP id lu3mr26874876ejb.374.1595944243860; Tue, 28 Jul 2020 06:50:43 -0700 (PDT) MIME-Version: 1.0 References: <20200726044647.GA19757@dcvr> <20200727183856.GA26578@dcvr> In-Reply-To: <20200727183856.GA26578@dcvr> From: Josh Natanson Date: Tue, 28 Jul 2020 09:50:33 -0400 Message-ID: Subject: Re: Clogger request_time formatting To: Eric Wong Cc: clogger-public@yhbt.net Content-Type: text/plain; charset="UTF-8" List-Id: Thanks. I had some time to work on this, and I'm a little stuck. The changes I've made are working as expected (both new syntax & legacy) when frozen into a test rails application. I've written a test for the new syntax, but I'm not getting the same behavior there - it looks to behave the same as the legacy option. I can't see why the same code would behave differently in an app vs. the test, and I'm having some challenges getting useful debug out of the code in test. I'm sure I'm just unfamiliar with something about the gem's layout, but maybe you have some ideas? Here's the changes so far. Don't mind the names, I'm planning to come up with something better before submitting. $ git diff --staged | cat diff --git a/lib/clogger.rb b/lib/clogger.rb index be1bdce..608909d 100644 --- a/lib/clogger.rb +++ b/lib/clogger.rb @@ -51,7 +51,7 @@ private SCAN = /([^$]*)(\$+(?:env\{\w+(?:\.[\w\.]+)?\}| e\{[^\}]+\}| - (?:request_)?time\{\d+\}| + (?:request_)?time\{\d+(?:,\d+)?\}| time_(?:utc|local)\{[^\}]+\}| \w*))?([^$]*)/x @@ -91,8 +91,10 @@ private rv << [ OP_TIME_UTC, fmt, longest_day.strftime(fmt) ] when /\A\$time\{(\d+)\}\z/ rv << [ OP_TIME, *usec_conv_pair(tok, $1.to_i) ] + when /\A\$request_time\{(\d+),(\d+)\}\z/ + rv << [ OP_REQUEST_TIME, *usec_conv_pair(tok, $2.to_i), $1.to_i ] when /\A\$request_time\{(\d+)\}\z/ - rv << [ OP_REQUEST_TIME, *usec_conv_pair(tok, $1.to_i) ] + rv << [ OP_REQUEST_TIME, *usec_conv_pair(tok, $1.to_i), 0 ] else tok_sym = tok[1..-1].to_sym if special_code = SPECIAL_VARS[tok_sym] diff --git a/lib/clogger/pure.rb b/lib/clogger/pure.rb index fddfe79..8f1f706 100644 --- a/lib/clogger/pure.rb +++ b/lib/clogger/pure.rb @@ -166,6 +166,7 @@ private when OP_TIME_UTC; Time.now.utc.strftime(op[1]) when OP_REQUEST_TIME t = mono_now - start + t = t * (10 ** op[3]) time_format(t.to_i, (t - t.to_i) * 1000000, op[1], op[2]) when OP_TIME t = Time.now diff --git a/test/test_clogger.rb b/test/test_clogger.rb index ca3bd55..3fc9e4a 100644 --- a/test/test_clogger.rb +++ b/test/test_clogger.rb @@ -167,10 +167,11 @@ class TestClogger < Test::Unit::TestCase ary = compile_format( '$remote_addr - $remote_user [$time_local] ' \ '"$request" $status $body_bytes_sent "$http_referer" ' \ - '"$http_user_agent" "$http_cookie" $request_time ' \ + '"$http_user_agent" "$http_cookie" $request_time $request_time{6,0} ' \ '$env{rack.url_scheme}' \ "\n") } + expect = [ [ Clogger::OP_REQUEST, "REMOTE_ADDR" ], [ Clogger::OP_LITERAL, " - " ], @@ -190,7 +191,9 @@ class TestClogger < Test::Unit::TestCase [ Clogger::OP_LITERAL, "\" \"" ], [ Clogger::OP_REQUEST, "HTTP_COOKIE" ], [ Clogger::OP_LITERAL, "\" " ], - [ Clogger::OP_REQUEST_TIME, '%d.%03d', 1000 ], + [ Clogger::OP_REQUEST_TIME, '%d.%03d', 1000, 0], + [ Clogger::OP_LITERAL, " " ], + [ Clogger::OP_REQUEST_TIME, '%d', 1, 6], [ Clogger::OP_LITERAL, " " ], [ Clogger::OP_REQUEST, "rack.url_scheme" ], [ Clogger::OP_LITERAL, "\n" ], @@ -721,6 +724,16 @@ class TestClogger < Test::Unit::TestCase assert s[-1].to_f <= 0.110 end + def test_request_time_with_multiple + s = [] + app = lambda { |env| sleep(0.1) ; [302, [], [] ] } + cl = Clogger.new(app, :logger => s, :format => "$request_time{6,0}") + status, headers, body = cl.call(@req) + assert_nothing_raised { body.each { |x| } ; body.close } + assert s[-1].to_f >= 100000 + assert s[-1].to_f <= 110000 + end + def test_insanely_long_time_format s = [] app = lambda { |env| [200, [], [] ] } On Mon, Jul 27, 2020 at 2:38 PM Eric Wong wrote: > > Josh Natanson wrote: > > I'm hoping to find some time this week to work on it. What's your > > preferred way to review? > > I do everything through email. "git format-patch" + "git send-email" > are the recommended tools. It's the same way git.git and the Linux > kernel work (see Documentation/SubmittingPatches in git) > > https://git.kernel.org/cgit/git/git.git/tree/Documentation/SubmittingPatches > > (I don't care about Signed-off-by or real names, though)