Docs: %adapt::sum_trs entries may well exceed %icap::tt (#914)

%icap::tt documentation incorrectly implied that the measurement
includes the entire ICAP transaction(s) lifetime. In reality, individual
ICAP transaction contribution stops with
Adaptation::Icap::ModXactLauncher::swanSong(), which is normally
triggered by Adaptation::Icap::Launcher::noteAdaptationAnswer(). Here,
the "answer" does not include the entire ICAP response, but just enough
information to form adapted HTTP message headers (echoed or received).
Thus, a large or slow ICAP response body may result in %adapt::sum_trs
values that far exceed the corresponding %icap::tt "total".

This change does not imply that %icap::tt should (not) work differently.

Also fixed a typo in %adapt::all_trs and polished %adapt::sum_trs docs.

diff --git a/src/cf.data.pre b/src/cf.data.pre
index 885e6c52e2904cfe36b96e38ac0eedb4b5f7b48d..9275219986aca1730702c88b729627e5ce93a0ee 100644 (file)
--- a/src/cf.data.pre
+++ b/src/cf.data.pre
@@ -4907,10 +4907,29 @@ DOC_START
        If ICAP is enabled, the following code becomes available (as
        well as ICAP log codes documented with the icap_log option):
 
-               icap::tt        Total ICAP processing time for the HTTP
-                               transaction. The timer ticks when ICAP
-                               ACLs are checked and when ICAP
-                               transaction is in progress.
+               icap::tt Total ICAP "blocking" time for the HTTP transaction. The
+                               timer ticks while Squid checks adaptation_access and while
+                               ICAP transaction(s) expect ICAP response headers, including
+                               the embedded adapted HTTP message headers (where applicable).
+                               This measurement is meant to estimate ICAP impact on HTTP
+                               transaction response times, but it does not currently account
+                               for slow ICAP response body delivery blocking HTTP progress.
+
+                               Once Squid receives the final ICAP response headers (e.g.,
+                               ICAP 200 or 204) and the associated adapted HTTP message
+                               headers (if any) from the ICAP service, the corresponding ICAP
+                               transaction stops affecting this measurement, even though the
+                               transaction itself may continue for a long time (e.g., to
+                               finish sending the ICAP request and/or to finish receiving the
+                               ICAP response body).
+
+                               When "blocking" sections of multiple concurrent ICAP
+                               transactions overlap in time, the overlapping segment is
+                               counted only once.
+
+                               To see complete ICAP transaction response times (rather than
+                               the cumulative effect of their blocking sections) use the
+                               %adapt::all_trs logformat code or the icap_log directive.
 
        If adaptation is enabled the following codes become available:
 
@@ -4929,11 +4948,12 @@ DOC_START
                                milliseconds.  When a failed transaction is
                                being retried or repeated, its time is not
                                logged individually but added to the
-                               replacement (next) transaction. See also:
-                               adapt::all_trs.
+                               replacement (next) transaction. Lifetimes of individually
+                               listed adaptation transactions may overlap.
+                               See also: %icap::tt and %adapt::all_trs.
 
                adapt::all_trs All adaptation transaction response times.
-                               Same as adaptation_strs but response times of
+                               Same as %adapt::sum_trs but response times of
                                individual transactions are never added
                                together. Instead, all transaction response
                                times are recorded individually.