Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Improve AccessLogHandler to log full request target instead of path only #47

Merged
merged 2 commits into from
Oct 15, 2021
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
9 changes: 8 additions & 1 deletion src/AccessLogHandler.php
Original file line number Diff line number Diff line change
Expand Up @@ -47,8 +47,15 @@ private function log(ServerRequestInterface $request, ResponseInterface $respons
{
$this->sapi->log(
($request->getServerParams()['REMOTE_ADDR'] ?? '-') . ' ' .
'"' . $request->getMethod() . ' ' . $request->getUri()->getPath() . ' HTTP/' . $request->getProtocolVersion() . '" ' .
'"' . $this->escape($request->getMethod()) . ' ' . $this->escape($request->getRequestTarget()) . ' HTTP/' . $request->getProtocolVersion() . '" ' .
$response->getStatusCode() . ' ' . $response->getBody()->getSize()
);
}

private function escape(string $s): string
{
return preg_replace_callback('/[\x00-\x1F\x7F-\xFF"\\\\]+/', function (array $m) {
return str_replace('%', '\x', rawurlencode($m[0]));
}, $s);
}
}
64 changes: 64 additions & 0 deletions tests/AccessLogHandlerTest.php
Original file line number Diff line number Diff line change
Expand Up @@ -22,6 +22,70 @@ public function testInvokePrintsRequestLogWithCurrentDateAndTime()
$handler($request, function () use ($response) { return $response; });
}

public function testInvokePrintsRequestWithQueryParametersLogWithCurrentDateAndTime()
{
$handler = new AccessLogHandler();

$request = new ServerRequest('GET', 'http://localhost:8080/?a=1&b=hello wörld', [], '', '1.1', ['REMOTE_ADDR' => '127.0.0.1']);
$response = new Response(200, [], "Hello\n");

// 2021-01-29 12:22:01.717 127.0.0.1 "GET /?a=1&b=hello%20w%C3%B6rld HTTP/1.1" 200 6\n
$this->expectOutputRegex("/^\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}\.\d{3} 127\.0\.0\.1 \"GET \/\?a=1&b=hello%20w%C3%B6rld HTTP\/1\.1\" 200 6" . PHP_EOL . "$/");
$handler($request, function () use ($response) { return $response; });
}

public function testInvokePrintsRequestWithEscapedSpecialCharactersInRequestMethodAndTargetWithCurrentDateAndTime()
{
$handler = new AccessLogHandler();

$request = new ServerRequest('GE"T', 'http://localhost:8080/wörld', [], '', '1.1', ['REMOTE_ADDR' => '127.0.0.1']);
$request = $request->withRequestTarget('/wörld');
$response = new Response(200, [], "Hello\n");

// 2021-01-29 12:22:01.717 127.0.0.1 "GE\x22T /w\xC3\xB6rld HTTP/1.1" 200 6\n
$this->expectOutputRegex("/^\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}\.\d{3} 127\.0\.0\.1 \"GE\\\\x22T \/w\\\\xC3\\\\xB6rld HTTP\/1\.1\" 200 6" . PHP_EOL . "$/");
$handler($request, function () use ($response) { return $response; });
}

public function testInvokePrintsPlainProxyRequestLogWithCurrentDateAndTime()
{
$handler = new AccessLogHandler();

$request = new ServerRequest('GET', 'http://localhost:8080/users', [], '', '1.1', ['REMOTE_ADDR' => '127.0.0.1']);
$request = $request->withRequestTarget('http://localhost:8080/users');
$response = new Response(400, [], "");

// 2021-01-29 12:22:01.717 127.0.0.1 "GET http://localhost:8080/users HTTP/1.1" 400 0\n
$this->expectOutputRegex("#^\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}\.\d{3} 127\.0\.0\.1 \"GET http://localhost:8080/users HTTP/1\.1\" 400 0" . PHP_EOL . "$#");
$handler($request, function () use ($response) { return $response; });
}

public function testInvokePrintsConnectProxyRequestLogWithCurrentDateAndTime()
{
$handler = new AccessLogHandler();

$request = new ServerRequest('CONNECT', 'example.com:8080', [], '', '1.1', ['REMOTE_ADDR' => '127.0.0.1']);
$request = $request->withRequestTarget('example.com:8080');
$response = new Response(400, [], "");

// 2021-01-29 12:22:01.717 127.0.0.1 "CONNECT example.com:8080 HTTP/1.1" 400 0\n
$this->expectOutputRegex("#^\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}\.\d{3} 127\.0\.0\.1 \"CONNECT example.com:8080 HTTP/1\.1\" 400 0" . PHP_EOL . "$#");
$handler($request, function () use ($response) { return $response; });
}

public function testInvokePrintsOptionsAsteriskLogWithCurrentDateAndTime()
{
$handler = new AccessLogHandler();

$request = new ServerRequest('OPTIONS', 'http://example.com:8080', [], '', '1.1', ['REMOTE_ADDR' => '127.0.0.1']);
$request = $request->withRequestTarget('*');
$response = new Response(400, [], "");

// 2021-01-29 12:22:01.717 127.0.0.1 "OPTIONS * HTTP/1.1" 400 0\n
$this->expectOutputRegex("#^\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}\.\d{3} 127\.0\.0\.1 \"OPTIONS \* HTTP/1\.1\" 400 0" . PHP_EOL . "$#");
$handler($request, function () use ($response) { return $response; });
}

public function testInvokeWithDeferredNextPrintsRequestLogWithCurrentDateAndTime()
{
$handler = new AccessLogHandler();
Expand Down