summaryrefslogtreecommitdiffstats
path: root/web/server/h2o/libh2o/t/50access-log.t
diff options
context:
space:
mode:
Diffstat (limited to 'web/server/h2o/libh2o/t/50access-log.t')
-rw-r--r--web/server/h2o/libh2o/t/50access-log.t281
1 files changed, 281 insertions, 0 deletions
diff --git a/web/server/h2o/libh2o/t/50access-log.t b/web/server/h2o/libh2o/t/50access-log.t
new file mode 100644
index 000000000..fd96217c2
--- /dev/null
+++ b/web/server/h2o/libh2o/t/50access-log.t
@@ -0,0 +1,281 @@
+use strict;
+use warnings;
+use File::Temp qw(tempdir);
+use Test::More;
+use t::Util;
+
+plan skip_all => 'curl not found'
+ unless prog_exists('curl');
+
+my $tempdir = tempdir(CLEANUP => 1);
+
+sub doit {
+ my ($cmd, $args, @expected) = @_;
+
+ unlink "$tempdir/access_log";
+
+ $args = { format => $args }
+ unless ref $args;
+
+ my $server = spawn_h2o(<< "EOT");
+ssl-session-resumption:
+ mode: cache
+ cache-store: internal
+hosts:
+ default:
+ paths:
+ /:
+ file.dir: @{[ DOC_ROOT ]}
+ /fastcgi:
+ fastcgi.connect:
+ port: /nonexistent
+ type: unix
+ error-log.emit-request-errors: OFF
+ /set-cookie:
+ file.dir: @{[ DOC_ROOT ]}
+ header.add: "set-cookie: a=b"
+ header.add: "set-cookie: c=d"
+ header.add: "cache-control: must-revalidate"
+ header.add: "cache-control: no-store"
+ /compress:
+ file.dir: @{[ DOC_ROOT ]}
+ compress: [gzip]
+ access-log:
+ format: "$args->{format}"
+@{[$args->{escape} ? " escape: $args->{escape}" : ""]}
+ path: $tempdir/access_log
+EOT
+
+ $cmd->($server);
+
+ my @log = do {
+ open my $fh, "<", "$tempdir/access_log"
+ or die "failed to open access_log:$!";
+ map { my $l = $_; chomp $l; $l } <$fh>;
+ };
+
+ for (my $i = 0; $i != @expected; ++$i) {
+ $expected[$i] = $expected[$i]->($server)
+ if ref $expected[$i] eq 'CODE';
+ like $log[$i], $expected[$i];
+ }
+}
+
+subtest "custom-log" => sub {
+ doit(
+ sub {
+ my $server = shift;
+ system("curl --silent --referer http://example.com/ http://127.0.0.1:$server->{port}/ > /dev/null");
+ },
+ '%h %l %u %t \"%r\" %s %b \"%{Referer}i\" \"%{User-agent}i\"',
+ qr{^127\.0\.0\.1 - - \[[0-9]{2}/[A-Z][a-z]{2}/20[0-9]{2}:[0-9]{2}:[0-9]{2}:[0-9]{2} [+\-][0-9]{4}\] "GET / HTTP/1\.1" 200 6 "http://example.com/" "curl/.*"$},
+ );
+};
+
+subtest "strftime" => sub {
+ doit(
+ sub {
+ my $server = shift;
+ system("curl --silent http://127.0.0.1:$server->{port}/ > /dev/null");
+ },
+ '%{%Y-%m-%dT%H:%M:%S}t',
+ qr{^20[0-9]{2}-(?:0[1-9]|1[012])-(?:[012][0-9]|3[01])T[0-9]{2}:[0-9]{2}:[0-9]{2}$},
+ );
+};
+
+subtest "strftime-special" => sub {
+ doit(
+ sub {
+ my $server = shift;
+ system("curl --silent http://127.0.0.1:$server->{port}/ > /dev/null");
+ },
+ '%{msec_frac}t::%{usec_frac}t::%{sec}t::%{msec}t::%{usec}t',
+ qr{^([0-9]{3})::(\1[0-9]{3})::([0-9]+)::\3\1::\3\2$},
+ );
+};
+
+subtest "more-fields" => sub {
+ my $local_port = "";
+ doit(
+ sub {
+ my $server = shift;
+ my $resp = `curl --silent -w ',\%{local_port}' http://127.0.0.1:$server->{port}/`;
+ like $resp, qr{,(\d+)$}s;
+ $local_port = do { $resp =~ /,(\d+)$/s; $1 };
+ },
+ '\"%A:%p\" \"%{local}p\" \"%{remote}p\"',
+ sub { my $server = shift; qr{^\"127\.0\.0\.1:$server->{port}\" \"$server->{port}\" \"$local_port\"$} },
+ );
+};
+
+subtest 'ltsv-related' => sub {
+ doit(
+ sub {
+ my $server = shift;
+ system("curl --silent http://127.0.0.1:$server->{port} > /dev/null");
+ system("curl --silent http://127.0.0.1:$server->{port}/query?abc=d > /dev/null");
+ },
+ '%m::%U%q::%H::%V::%v',
+ qr{^GET::/::HTTP/1\.1::127\.0\.0\.1:[0-9]+::default$},
+ qr{^GET::/query\?abc=d::HTTP/1\.1::127\.0\.0\.1:[0-9]+::default$},
+ );
+};
+
+subtest 'timings' => sub {
+ my $doit = sub {
+ my $opts = shift;
+ doit(
+ sub {
+ my $server = shift;
+ system("curl $opts --silent --data helloworld http://127.0.0.1:$server->{port}/ > /dev/null");
+ system("curl $opts --silent --insecure --data helloworld https://127.0.0.1:$server->{tls_port}/ > /dev/null");
+ },
+ '%{connect-time}x:%{request-header-time}x:%{request-body-time}x:%{response-time}x:%{request-total-time}x:%{duration}x:%{undefined}x',
+ map { qr{^[0-9\.]+:[0-9\.]+:[0-9\.]+:[0-9\.]+:[0-9\.]+:[0-9\.]+:-$} } (1..2),
+ );
+ };
+ subtest 'http1' => sub {
+ $doit->("");
+ };
+ subtest 'http2' => sub {
+ plan skip_all => "curl does not support HTTP/2"
+ unless curl_supports_http2();
+ $doit->("--http2");
+ };
+};
+
+subtest 'header-termination (issue 462)' => sub {
+ doit(
+ sub {
+ my $server = shift;
+ system("curl --user-agent foobar/1 --silent http://127.0.0.1:$server->{port} > /dev/null");
+ },
+ '%{user-agent}i',
+ qr{^foobar/1$},
+ );
+ doit(
+ sub {
+ my $server = shift;
+ system("curl --user-agent foobar/1 --silent http://127.0.0.1:$server->{port} > /dev/null");
+ },
+ '%{content-type}o',
+ qr{^text/plain$},
+ );
+};
+
+subtest 'extensions' => sub {
+ doit(
+ sub {
+ my $server = shift;
+ system("curl --silent http://127.0.0.1:$server->{port}/ > /dev/null");
+ system("curl --silent --insecure @{[curl_supports_http2() ? ' --http1.1' : '']} https://127.0.0.1:$server->{tls_port}/ > /dev/null");
+ if (prog_exists("nghttp")) {
+ system("nghttp -n https://127.0.0.1:$server->{tls_port}/");
+ system("nghttp -n --weight=22 https://127.0.0.1:$server->{tls_port}/");
+ }
+ },
+ '%{connection-id}x %{ssl.protocol-version}x %{ssl.session-reused}x %{ssl.cipher}x %{ssl.cipher-bits}x %{http2.stream-id}x %{http2.priority.received}x',
+ do {
+ my @expected = (
+ qr{^2 - - - - - -$}is,
+ qr{^3 TLSv[0-9.]+ 0 \S+RSA\S+ (?:128|256) - -$}is,
+ );
+ if (prog_exists("nghttp")) {
+ push @expected, +(
+ qr{^4 TLSv[0-9.]+ 0 \S+RSA\S+ (?:128|256) [0-9]*[13579] 0:[0-9]+:16}is,
+ qr{^5 TLSv[0-9.]+ 0 \S+RSA\S+ (?:128|256) [0-9]*[13579] 0:[0-9]+:22}is,
+ );
+ }
+ @expected;
+ },
+ );
+};
+
+subtest 'ssl-log' => sub {
+ doit(
+ sub {
+ my $server = shift;
+ system("curl --silent -k https://127.0.0.1:$server->{tls_port}/ > /dev/null");
+ },
+ '%{ssl.session-id}x',
+ qr{^\S+$}s,
+ );
+};
+
+subtest 'error' => sub {
+ doit(
+ sub {
+ my $server = shift;
+ system("curl --silent http://127.0.0.1:$server->{port}/fastcgi > /dev/null");
+ },
+ '%{error}x',
+ qr{^\[lib/handler/fastcgi\.c\] connection failed:}s,
+ );
+};
+
+subtest 'set-cookie' => sub {
+ # set-cookie header is the only header to be concatenated with %{...}o, according to Apache
+ doit(
+ sub {
+ my $server = shift;
+ system("curl --silent http://127.0.0.1:$server->{port}/set-cookie/ > /dev/null");
+ },
+ '\\"%<{set-cookie}o\\" \\"%>{set-cookie}o\\" \\"%{set-cookie}o\\" \\"%{cache-control}o\\"',
+ qr{^"-" "a=b, c=d" "a=b, c=d" "must-revalidate"$}s,
+ );
+};
+
+subtest 'escape' => sub {
+ for my $i ([default => qr{^/\\xe3\\x81\\x82$}s], [apache => qr{^/\\xe3\\x81\\x82$}s], [json => qr{^/\\u00e3\\u0081\\u0082$}s]) {
+ my ($escape, $expected) = @$i;
+ subtest $escape => sub {
+ doit(
+ sub {
+ my $server = shift;
+ system("curl --silent http://127.0.0.1:$server->{port}/\xe3\x81\x82 > /dev/null");
+ },
+ $escape eq 'default' ? '%U' : { format => '%U', escape => $escape },
+ $expected,
+ );
+ };
+ }
+};
+
+subtest "json-null" => sub {
+ doit(
+ sub {
+ my $server = shift;
+ system("curl --silent http://127.0.0.1:$server->{port}/ > /dev/null");
+ },
+ # single specifier surrounded by quotes that consist a string literal in JSON should be converted to `null` if the specifier
+ # resolves to null
+ { format => '\\"%h\\" %l \\"%l\\" \'%l\' \'%l \' \'\\"%l\\"\'', escape => 'json' },
+ qr{^"127\.0\.0\.1" null null null 'null ' '"null"'$},
+ );
+};
+
+subtest 'compressed-body-size' => sub {
+ my $doit = sub {
+ my ($opts, $expected) = @_;
+ doit(
+ sub {
+ my $server = shift;
+ system("curl $opts --silent http://127.0.0.1:$server->{port}/compress/alice.txt > /dev/null");
+ },
+ '%b',
+ qr{^$expected$},
+ );
+ };
+ subtest 'http1' => sub {
+ $doit->("", 1661);
+ $doit->("-H 'Accept-Encoding: gzip'", 908); # it doesn't contain chunked encoding overhead (12)
+ };
+ subtest 'http2' => sub {
+ plan skip_all => "curl does not support HTTP/2"
+ unless curl_supports_http2();
+ $doit->("--http2", 1661);
+ $doit->("--http2 -H 'Accept-Encoding: gzip'", 908);
+ };
+};
+
+done_testing;