use strict;
use warnings;
use Test::More;
use HTTP::Request::Common;
use Plack::Test;
use Plack::Builder;

BEGIN {
    eval "use Test::MockTime::HiRes; 1";
    if ($@) {
        *mock_time = sub(&$) {
            my($code, $time) = @_;
            $code->();
        }
    }
}

use Time::HiRes;

my $log;
my $handler = builder {
    enable "Plack::Middleware::AccessLog::Timed",
        logger => sub { $log .= "@_" };
    sub { [ 200, [ 'Content-Type' => 'text/plain' ], [ 'OK' ] ] };
};

my $test_req = sub {
    my $req = shift;
    test_psgi app => $handler,
        client => sub {
        my $cb = shift;
        $cb->($req);
    };
};

{
    $test_req->(GET "http://localhost/");
    like $log, qr@^127\.0\.0\.1 - - \[.*?\] "GET / HTTP/1\.1" 200 2@;
}

{
    $log = "";
    $test_req->(POST "http://localhost/foo", { foo => "bar" });
    like $log, qr@^127\.0\.0\.1 - - \[.*?\] "POST /foo HTTP/1\.1" 200 2@;
}

{
    $log = "";
    $test_req->(GET "http://localhost/foo%20bar?baz=baz");
    like $log, qr@GET /foo%20bar\?baz=baz HTTP/1\.1@;
}

# Testing delayed responses

$log = "";
$handler = builder {
    enable "Plack::Middleware::AccessLog::Timed",
        logger => sub { $log .= "@_" };
    sub { 
        return sub { 
            $_[0]->( [ 200, [ 'Content-Type' => 'text/plain' ], [ 'OK' ] ] ) 
        } 
    };
};

$test_req = sub {
    my $req = shift;
    test_psgi app => $handler,
        client => sub {
        my $cb = shift;
        $cb->($req);
    };
};

{
    $test_req->(GET "http://localhost/");
    like $log, qr@^127\.0\.0\.1 - - \[.*?\] "GET / HTTP/1\.1" 200 2@;
}

{
    $log = "";
    $test_req->(POST "http://localhost/foo", { foo => "bar" });
    like $log, qr@^127\.0\.0\.1 - - \[.*?\] "POST /foo HTTP/1\.1" 200 2@;
}

{
    $log = "";
    $test_req->(GET "http://localhost/foo%20bar?baz=baz");
    like $log, qr@GET /foo%20bar\?baz=baz HTTP/1\.1@;
}



# Testing streaming responses

$log = "";
$handler = builder {
    enable "Plack::Middleware::AccessLog::Timed",
        logger => sub { $log .= "@_" };
    
    sub { 
        return sub { 
            my $writer = $_[0]->( [ 200, [ 'Content-Type' => 'text/plain' ] ] );
            $writer->write("OK");
            $writer->close;
        } 
    };
};

$test_req = sub {
    my $req = shift;
    test_psgi app => $handler,
        client => sub {
        my $cb = shift;
        $cb->($req);
    };
};

{
    $test_req->(GET "http://localhost/");
    like $log, qr@^127\.0\.0\.1 - - \[.*?\] "GET / HTTP/1\.1" 200 2@;
}

{
    $log = "";
    $test_req->(POST "http://localhost/foo", { foo => "bar" });
    like $log, qr@^127\.0\.0\.1 - - \[.*?\] "POST /foo HTTP/1\.1" 200 2@;
}

{
    $log = "";
    $test_req->(GET "http://localhost/foo%20bar?baz=baz");
    like $log, qr@GET /foo%20bar\?baz=baz HTTP/1\.1@;
}

# Testing '%D' and '%T'

$log = '';
my $wait_sec = 1;
$handler = builder {
    enable "Plack::Middleware::AccessLog::Timed",
        logger => sub { $log .= "@_" },
        format => '%T %D';
    sub {
        return sub {
            Time::HiRes::sleep $wait_sec;
            $_[0]->( [ 200, [ 'Content-Type' => 'text/plain' ], [ 'OK' ] ] )
        }
    };
};

$test_req = sub {
    my $req = shift;
    test_psgi app => $handler,
        client => sub {
        my $cb = shift;
        $cb->($req);
    };
};

mock_time {
    $wait_sec = 1.2;
    $test_req->(GET "http://localhost/");
    like $log, qr@^\d \d{7}@; # around '1 1200000'
} time();

$log = '';
mock_time {
    $wait_sec = 0.3;
    $test_req->(GET "http://localhost/");
    like $log, qr@^\d \d{6}\b@; # around '0 300000'
} time();

done_testing;