Re: 1.9.x JavaHL: long initial delay when performing a log

Julian Foad <julianfoad_at_btopenworld.com> writes:

> Flushing after the 1st, 2nd, 4th, 8th, ... log entry provides a crude
> approximation to the desired semantics which is more like "don't delay
> the first result more than a small fraction of a second, and don't
> delay the next few results much more than that either". In other
> words, the user's requirement is more about time delays. I wonder if
> we could implement something closer to what the user really wants.

apr_time_now() is not free so we don't want to call it on every
revision, but we could call it before every extra flush. How about no
more than one extra flush every 500ms:

Index: subversion/mod_dav_svn/reports/log.c
===================================================================
--- subversion/mod_dav_svn/reports/log.c (revision 1667018)
+++ subversion/mod_dav_svn/reports/log.c (working copy)
@@ -69,6 +69,7 @@ struct log_receiver_baton
   /* Helper variables to force early bucket brigade flushes */
   int result_count;
   int next_forced_flush;
+ apr_time_t event_time;
 };
 
 
@@ -291,22 +292,30 @@ log_receiver(void *baton,
      and busy servers. This algorithm makes sure the client gets the first
      two results very fast (but less efficient), while it gradually removes
      its performance hit and falls back to the APR standard buffer handling,
- which streamlines the http processing */
+ which streamlines the http processing. Don't flush more than once per
+ 500ms (an arbitrary 'short' time) or within the first 500ms. */
+#define FLUSH_USEC 500000
   lrb->result_count++;
   if (lrb->result_count == lrb->next_forced_flush)
     {
- apr_off_t len = 0;
- (void)apr_brigade_length(lrb->bb, FALSE, &len);
+ apr_time_t now = apr_time_now();
 
- if (len != 0)
+ if (now > lrb->event_time + FLUSH_USEC)
         {
- apr_status_t apr_err = ap_fflush(lrb->output, lrb->bb);
- if (apr_err)
- return svn_error_create(apr_err, NULL, NULL);
+ apr_off_t len = 0;
+ (void)apr_brigade_length(lrb->bb, FALSE, &len);
 
- if (lrb->output->c->aborted)
- return svn_error_create(SVN_ERR_APMOD_CONNECTION_ABORTED,
- NULL, NULL);
+ if (len != 0)
+ {
+ apr_status_t apr_err = ap_fflush(lrb->output, lrb->bb);
+ if (apr_err)
+ return svn_error_create(apr_err, NULL, NULL);
+
+ if (lrb->output->c->aborted)
+ return svn_error_create(SVN_ERR_APMOD_CONNECTION_ABORTED,
+ NULL, NULL);
+ }
+ lrb->event_time = now;
         }
 
       if (lrb->result_count < 2048)
@@ -460,6 +469,7 @@ dav_svn__log_report(const dav_resource *resource,
 
   lrb.result_count = 0;
   lrb.next_forced_flush = 1;
+ lrb.event_time = apr_time_now();
 
   /* Our svn_log_entry_receiver_t sends the <S:log-report> header in
      a lazy fashion. Before writing the first log message, it assures

-- 
Philip Martin | Subversion Committer
WANdisco // *Non-Stop Data*