From 42b3ff3bd2894105231d5e3311cd561fb1ac55b3 Mon Sep 17 00:00:00 2001
From: dakkar <dakkar@thenautilus.net>
Date: Sun, 23 Oct 2016 15:34:04 +0100
Subject: logging & request id work

---
 t/tests/logging.t | 105 ++++++++++++++++++++++++++++++++++++++++++++++++++++++
 1 file changed, 105 insertions(+)
 create mode 100644 t/tests/logging.t

(limited to 't')

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;
-- 
cgit v1.2.3