# HG changeset patch # User Sergey Kandaurov # Date 1429786880 -10800 # Node ID 27740a2dd7818928fd384cab51a37cd3224b7ca4 # Parent 05cbe9e2def8d9be2746b7ca812a5a106c33eb4b Tests: stream error_log tests. diff --git a/stream_error_log.t b/stream_error_log.t new file mode 100644 --- /dev/null +++ b/stream_error_log.t @@ -0,0 +1,320 @@ +#!/usr/bin/perl + +# (C) Sergey Kandaurov +# (C) Nginx, Inc. + +# Stream tests for error_log. + +############################################################################### + +use warnings; +use strict; + +use Test::More; + +use IO::Select; + +BEGIN { use FindBin; chdir($FindBin::Bin); } + +use lib 'lib'; +use Test::Nginx; + +############################################################################### + +select STDERR; $| = 1; +select STDOUT; $| = 1; + +my $t = Test::Nginx->new()->has(qw/stream/)->plan(33); + +$t->write_file_expand('nginx.conf', <<'EOF'); + +%%TEST_GLOBALS%% + +error_log %%TESTDIR%%/e_glob.log info; +error_log %%TESTDIR%%/e_glob2.log info; +error_log syslog:server=127.0.0.1:8083 info; + +daemon off; + +events { +} + +stream { + upstream u { + server 127.0.0.1:8083 down; + } + + server { + listen 127.0.0.1:8080; + proxy_pass u; + + error_log %%TESTDIR%%/e_debug.log debug; + error_log %%TESTDIR%%/e_info.log info; + error_log %%TESTDIR%%/e_emerg.log emerg; + error_log stderr info; + } + + server { + listen 127.0.0.1:8082; + proxy_pass 127.0.0.1:8081; + + error_log %%TESTDIR%%/e_stream.log info; + error_log syslog:server=127.0.0.1:8084 info; + } +} + +EOF + +open OLDERR, ">&", \*STDERR; +open STDERR, '>', $t->testdir() . '/stderr' or die "Can't reopen STDERR: $!"; +open my $stderr, '<', $t->testdir() . '/stderr' + or die "Can't open stderr file: $!"; + +$t->run_daemon(\&stream_daemon); +$t->run_daemon(\&syslog_daemon, 8083, $t, 's_glob.log'); +$t->run_daemon(\&syslog_daemon, 8084, $t, 's_stream.log'); + +$t->waitforsocket('127.0.0.1:8081'); +$t->waitforfile($t->testdir . '/s_glob.log'); +$t->waitforfile($t->testdir . '/s_stream.log'); + +$t->run(); + +open STDERR, ">&", \*OLDERR; + +############################################################################### + +stream_get('data'); + +# error_log levels + +SKIP: { +skip "no --with-debug", 1 unless $t->has_module('--with-debug'); + +isnt(lines($t, 'e_debug.log', '[debug]'), 0, 'file debug in debug'); + +} + +isnt(lines($t, 'e_info.log', '[info]'), 0, 'file info in info'); +is(lines($t, 'e_info.log', '[debug]'), 0, 'file debug in info'); +isnt(lines($t, 'stderr', '[info]'), 0, 'stderr info in info'); +is(lines($t, 'stderr', '[debug]'), 0, 'stderr debug in info'); + +# multiple error_log + +like($t->read_file('e_glob.log'), qr!nginx/[.0-9]+!, 'error global'); +like($t->read_file('e_glob2.log'), qr!nginx/[.0-9]+!, 'error global 2'); +is_deeply(levels($t, 'e_glob.log'), levels($t, 'e_glob2.log'), + 'multiple error global'); + +# syslog + +stream_get('data2', '127.0.0.1:8082'); + +parse_syslog_message('syslog', $t->read_file('s_stream.log')); + +is_deeply(levels($t, 's_glob.log'), levels($t, 'e_glob.log'), + 'global syslog messages'); +is_deeply(levels($t, 's_stream.log'), levels($t, 'e_stream.log'), + 'stream syslog messages'); + +# error_log context + +SKIP: { +skip "relies on error log contents", 5 unless $ENV{TEST_NGINX_UNSAFE}; + +my $msg = 'no live upstreams while connecting to upstream, ' + . 'client: 127.0.0.1, server: 127.0.0.1:8080, upstream: "u"'; + +unlike($t->read_file('e_glob.log'), qr/$msg/ms, 'stream error in global'); +like($t->read_file('e_info.log'), qr/$msg/ms, 'stream error in info'); +like($t->read_file('stderr'), qr/$msg/ms, 'stream error in info stderr'); +unlike($t->read_file('e_emerg.log'), qr/$msg/ms, 'stream error in emerg'); + +$msg = "bytes from/to client:5/4, bytes from/to upstream:4/5"; + +like($t->read_file('e_stream.log'), qr/$msg/ms, 'stream byte counters'); + +} + +############################################################################### + +sub lines { + my ($t, $file, $pattern) = @_; + + if ($file eq 'stderr') { + return map { $_ =~ /\Q$pattern\E/ } (<$stderr>); + } + + my $path = $t->testdir() . '/' . $file; + open my $fh, '<', $path or return "$!"; + my $value = map { $_ =~ /\Q$pattern\E/ } (<$fh>); + close $fh; + return $value; +} + +sub levels { + my ($t, $file) = @_; + my %levels_hash; + + map { $levels_hash{$_}++; } ($t->read_file($file) =~ /(\[\w+\])/g); + + return \%levels_hash; +} + +sub stream_get { + my ($data, $peer) = @_; + + $peer = '127.0.0.1:8080' unless defined $peer; + my $s = stream_connect($peer); + stream_write($s, $data); + my $r = stream_read($s); + + $s->close; + return $r; +} + +sub stream_connect { + my $peer = shift; + my $s = IO::Socket::INET->new( + Proto => 'tcp', + PeerAddr => $peer || '127.0.0.1:8080' + ) + or die "Can't connect to nginx: $!\n"; + + return $s; +} + +sub stream_write { + my ($s, $message) = @_; + + local $SIG{PIPE} = 'IGNORE'; + + $s->blocking(0); + while (IO::Select->new($s)->can_write(1.5)) { + my $n = $s->syswrite($message); + last unless $n; + $message = substr($message, $n); + last unless length $message; + } + + if (length $message) { + $s->close(); + } +} + +sub stream_read { + my ($s) = @_; + my ($buf); + + $s->blocking(0); + if (IO::Select->new($s)->can_read(5)) { + $s->sysread($buf, 1024); + }; + + log_in($buf); + return $buf; +} + +sub parse_syslog_message { + my ($desc, $line) = @_; + + my @months = ('Jan', 'Feb', 'Mar', 'Apr', 'May', 'Jun', 'Jul', 'Aug', + 'Sep', 'Oct', 'Nov', 'Dec'); + + my ($pri, $mon, $mday, $hour, $minute, $sec, $host, $tag, $msg) = + $line =~ /^<(\d{1,3})> # PRI + ([A-Z][a-z]{2})\s # mon + ([ \d]\d)\s(\d{2}):(\d{2}):(\d{2})\s # date + ([\S]*)\s # host + (\w{1,32}):\s # tag + (.*)/x; # MSG + + my $sev = $pri & 0x07; + my $fac = ($pri & 0x03f8) >> 3; + + ok(defined($pri), "$desc has PRI"); + ok($sev >= 0 && $sev <= 7, "$desc valid severity"); + ok($fac >= 0 && $fac < 24, "$desc valid facility"); + + ok(defined($mon), "$desc has month"); + ok((grep $mon, @months), "$desc valid month"); + + ok(defined($mday), "$desc has day"); + ok($mday <= 31, "$desc valid day"); + + ok(defined($hour), "$desc has hour"); + ok($hour < 24, "$desc valid hour"); + + ok(defined($minute), "$desc has minutes"); + ok($minute < 60, "$desc valid minutes"); + + ok(defined($sec), "$desc has seconds"); + ok($sec < 60, "$desc valid seconds"); + + ok(defined($host), "$desc has host"); + chomp(my $hostname = lc `hostname`); + is($host , $hostname, "$desc valid host"); + + ok(defined($tag), "$desc has tag"); + like($tag, qr'\w+', "$desc valid tag"); + + ok(length($msg) > 0, "$desc valid CONTENT"); +} + +############################################################################### + +sub syslog_daemon { + my ($port, $t, $file) = @_; + + my $s = IO::Socket::INET->new( + Proto => 'udp', + LocalAddr => "127.0.0.1:$port" + ); + + open my $fh, '>', $t->testdir() . '/' . $file; + select $fh; $| = 1; + + while (1) { + my $buffer; + $s->recv($buffer, 4096); + print $fh $buffer . "\n"; + } +} + +sub stream_daemon { + my $server = IO::Socket::INET->new( + Proto => 'tcp', + LocalHost => '127.0.0.1', + LocalPort => 8081, + Listen => 5, + Reuse => 1 + ) + or die "Can't create listening socket: $!\n"; + + local $SIG{PIPE} = 'IGNORE'; + + while (my $client = $server->accept()) { + $client->autoflush(1); + + log2c("(new connection $client)"); + + $client->sysread(my $buffer, 65536) or next; + + log2i("$client $buffer"); + + $buffer = $client->sockport(); + + log2o("$client $buffer"); + + $client->syswrite($buffer); + + close $client; + } +} + +sub log2i { Test::Nginx::log_core('|| <<', @_); } +sub log2o { Test::Nginx::log_core('|| >>', @_); } +sub log2c { Test::Nginx::log_core('||', @_); } + +###############################################################################