summaryrefslogtreecommitdiff
path: root/t
diff options
context:
space:
mode:
Diffstat (limited to 't')
-rw-r--r--t/tests/logging.t105
1 files changed, 105 insertions, 0 deletions
diff --git a/t/tests/logging.t b/t/tests/logging.t
new file mode 100644
index 0000000..390dd91
--- /dev/null
+++ b/t/tests/logging.t
@@ -0,0 +1,105 @@
+#!perl
+use strict;
+use warnings;
+
+use IO::Async::PSGI;
+
+use IO::Async::Loop;
+use IO::Async::Test;
+use HTTP::Request;
+use HTTP::Message::PSGI;
+use Future;
+use Plack::Util;
+use Plack::Middleware::RequestId;
+use Plack::Builder;
+use Log::Any::Test;
+use Log::Any qw($log);
+
+use Test2::Bundle::Extended;
+use Data::Printer;
+
+my $app_f = sub {
+ my ($env) = @_;
+ my $loop = $env->{'io.async.loop'};
+
+ $log->info('starting');
+ $loop
+ ->delay_future(after=>0.1)
+ ->then(sub{
+ $log->info('first step');
+ $loop->delay_future(after=>0.1);
+ })
+ ->then(sub{
+ $log->info('second step');
+ $loop->delay_future(after=>0.1);
+ })
+ ->then(sub{
+ $log->info('third step');
+ Future->done([200,[],['']]);
+ });
+};
+
+my $loop = IO::Async::Loop->new;
+testing_loop $loop;
+
+my $psgi = IO::Async::PSGI->new({
+ app => $app_f,
+});
+my $app = builder {
+ enable 'RequestId';
+ $psgi->psgi_app;
+};
+
+IO::Async::PSGI->logging_requestid_cb(
+ sub {
+ my ($req_id) = @_;
+ if ($req_id) { $log->{prefix} = "$req_id " }
+ else { $log->{prefix} = undef }
+ }
+);
+
+my @res;
+for my $i (0..2) {
+ my $req = HTTP::Request->new(GET => 'http://localhost/')->to_psgi;
+ $req->{'io.async.loop'}=$loop;
+
+ my $raw_res = $app->($req);
+ $raw_res->(sub{$res[$i]=shift});
+}
+
+wait_for { $res[0] && $res[1] && $res[2] };
+
+is($res[$_]->[0],200,"response $_ ok")
+ for 0..2;
+
+my @ids = map { Plack::Util::header_get($_->[1],'X-Request-Id') } @res;
+
+my @log_lines =
+ map { [$_->{category},split / /,$_->{message},2] }
+ @{ $log->msgs };
+
+my %log_lines_for_req;
+push @{$log_lines_for_req{$_->[1]}},$_ for @log_lines;
+
+is(
+ \@ids,
+ bag { item $_ for keys %log_lines_for_req; end },
+ 'request ids match',
+);
+
+for my $req_id (keys %log_lines_for_req) {
+ subtest "request $req_id" => sub {
+ is(
+ $log_lines_for_req{$req_id},
+ [
+ ['main',$req_id,'starting'],
+ ['main',$req_id,'first step'],
+ ['main',$req_id,'second step'],
+ ['main',$req_id,'third step'],
+ ],
+ 'correct events',
+ );
+ };
+}
+
+done_testing;