* [PATCH 09/12] nntp: fix logging of long responses
2015-09-19 2:03 6% [PATCH 0/12] nntp: misc updates Eric Wong
@ 2015-09-19 2:03 7% ` Eric Wong
0 siblings, 0 replies; 2+ results
From: Eric Wong @ 2015-09-19 2:03 UTC (permalink / raw)
To: meta
It's misleading to show short times on long responses.
Instead, show the long response as a separate entry on
completion or failure.
---
lib/PublicInbox/NNTP.pm | 33 +++++++++++++++++++++++++--------
1 file changed, 25 insertions(+), 8 deletions(-)
diff --git a/lib/PublicInbox/NNTP.pm b/lib/PublicInbox/NNTP.pm
index 094d26d..3ded0de 100644
--- a/lib/PublicInbox/NNTP.pm
+++ b/lib/PublicInbox/NNTP.pm
@@ -11,12 +11,14 @@ use PublicInbox::MID qw(mid2path);
use Email::Simple;
use Data::Dumper qw(Dumper);
use POSIX qw(strftime);
-use Time::HiRes qw(gettimeofday tv_interval ualarm);
+use Time::HiRes qw(clock_gettime ualarm CLOCK_MONOTONIC);
use constant {
r501 => '501 command syntax error',
long_response_limit => 0xffffffff,
};
+sub now () { clock_gettime(CLOCK_MONOTONIC) };
+
my @OVERVIEW = qw(Subject From Date Message-ID References Bytes Lines);
my %OVERVIEW = map { $_ => 1 } @OVERVIEW;
@@ -471,6 +473,8 @@ sub long_response ($$$$) {
# clients should not be sending us stuff and making us do more
# work while we are stream a response to them
$self->watch_read(0);
+ my $fd = fileno $self->{sock};
+ my $t0 = now();
$self->{long_res} = sub {
# limit our own running time for fairness with other
# clients and to avoid buffering too much:
@@ -487,8 +491,18 @@ sub long_response ($$$$) {
if ($err || $self->{closed}) {
$self->{long_res} = undef;
- warning("$err during long response") if $err;
- $self->watch_read(1) unless $self->{closed};
+
+ if ($err) {
+ warning("$err during long response[$fd] - ".
+ sprintf('%0.6', now() - $t0));
+ }
+ if ($self->{closed}) {
+ printf(STDERR
+ " deferred[$fd] aborted - %0.6f\n",
+ now() - $t0);
+ } else {
+ $self->watch_read(1);
+ }
} elsif ($yield || $self->{write_buf_size}) {
# no recursion, schedule another call ASAP
# but only after all pending writes are done
@@ -499,6 +513,8 @@ sub long_response ($$$$) {
$self->{long_res} = undef;
$self->watch_read(1);
res($self, '.');
+ printf(STDERR " deferred[$fd] done - %0.6f\n",
+ now() - $t0);
}
};
$self->{long_res}->(); # kick off!
@@ -719,12 +735,13 @@ sub event_read {
use constant LINE_MAX => 512; # RFC 977 section 2.3
my $r = 1;
my $buf = $self->read(LINE_MAX) or return $self->close;
- while ($r > 0 && $$buf =~ s/\A([^\r\n]+)\r?\n//) {
+ while ($r > 0 && $$buf =~ s/\A\s*([^\r\n]+)\r?\n//) {
my $line = $1;
- my $t0 = [ gettimeofday ];
+ my $t0 = now();
$r = eval { $self->process_line($line) };
- printf(STDERR "$line %0.6f\n",
- tv_interval($t0, [gettimeofday]));
+ my $d = $self->{long_res} ?
+ ' deferred['.fileno($self->{sock}).']' : '';
+ printf(STDERR "$line - %0.6f$d\n", now() - $t0);
}
return $self->close if $r < 0;
my $len = bytes::length($$buf);
@@ -732,6 +749,6 @@ sub event_read {
$self->push_back_read($buf) if ($len);
}
-sub warning { print STDERR @_, "\n" }
+sub warning { print STDERR 'W: ', @_, "\n" }
1;
--
EW
^ permalink raw reply related [relevance 7%]
* [PATCH 0/12] nntp: misc updates
@ 2015-09-19 2:03 6% Eric Wong
2015-09-19 2:03 7% ` [PATCH 09/12] nntp: fix logging of long responses Eric Wong
0 siblings, 1 reply; 2+ results
From: Eric Wong @ 2015-09-19 2:03 UTC (permalink / raw)
To: meta
Still not changing or adding new caches or modifying our data layout,
but things seem to work well for the common case.
The most important change is the new long response API which will help
us even after any future optimizations we make. We should be able to
stream millions of messages without excessive buffering and memory
usage.
Eric Wong (12):
nntp: use write_buf_size instead write_buf
nntp: introduce long response API for streaming
nntp: use long response API for LISTGROUP
nntp: implement command argument checking
nntp: XOVER does not require range
nntp: speed up XHDR for the Message-ID case
nntp: implement XROVER, speed up XHDR for some cases
nntp: implement XPATH
nntp: fix logging of long responses
nntp: fix ARTICLE/HEAD/BODY/STAT
nntp: log to FDs given by the Nntpd module
nntp: article lookups by Message-ID may cross newsgroups
lib/PublicInbox/Msgmap.pm | 24 +--
lib/PublicInbox/NNTP.pm | 419 ++++++++++++++++++++++++++++++++-----------
lib/PublicInbox/SearchMsg.pm | 1 +
public-inbox-nntpd | 2 +
4 files changed, 330 insertions(+), 116 deletions(-)
^ permalink raw reply [relevance 6%]
Results 1-2 of 2 | reverse | options above
-- pct% links below jump to the message on this page, permalinks otherwise --
2015-09-19 2:03 6% [PATCH 0/12] nntp: misc updates Eric Wong
2015-09-19 2:03 7% ` [PATCH 09/12] nntp: fix logging of long responses Eric Wong
Code repositories for project(s) associated with this public inbox
https://80x24.org/public-inbox.git
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).