Mercurial > hg > nginx-tests
view stream_error_log.t @ 572:ca54b445d982
Tests: masked nginx bug in proxy next upstream.
When iterating through several next upstreams per a worker cycle,
a previously reported event about upstream connection error may
be improperly applied to the next upstream, thus leading to the
invalid connection error. E.g., in kqueue, where the problem is
visible, this is caused by "ev->instance" that does not tolerate
more than one next upstream at once, and kevents placed on the
kqueue separately for read and write events.
The change is to limit test case to the only one next upstream.
author | Sergey Kandaurov <pluknet@nginx.com> |
---|---|
date | Thu, 14 May 2015 11:54:24 +0300 |
parents | 22bade4c7e12 |
children | 77359b849cd5 |
line wrap: on
line source
#!/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; plan(skip_all => 'win32') if $^O eq 'MSWin32'; my $t = Test::Nginx->new()->has(qw/stream/)->plan(34); $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:8080 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 parse_syslog_message('syslog', get_syslog('data2', '127.0.0.1:8082')); 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); $data = ''; while (my $buf = stream_read($s)) { $data .= $buf; } return $data; } 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 get_syslog { my ($data, $peer, $port) = @_; my ($s); my $rfd = ''; $port = 8080 unless defined $port; eval { local $SIG{ALRM} = sub { die "timeout\n" }; local $SIG{PIPE} = sub { die "sigpipe\n" }; alarm(1); $s = IO::Socket::INET->new( Proto => 'udp', LocalAddr => "127.0.0.1:$port" ); alarm(0); }; alarm(0); if ($@) { log_in("died: $@"); return undef; } stream_get($data, $peer); $data = ''; IO::Select->new($s)->can_read(1.5); while (IO::Select->new($s)->can_read(0.1)) { my $buffer; sysread($s, $buffer, 4096); $data .= $buffer; } $s->close(); return $data; } sub parse_syslog_message { my ($desc, $line) = @_; ok($line, $desc); SKIP: { skip "$desc timeout", 18 unless $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('||', @_); } ###############################################################################