Remove incorrect assertions from logging lifecycle observers (apple#2644

)

Motivation:

If request is retried multiple times, multiple callbacks can be invoked
multiple times (for every retry attempt) when logging observers are
applied at the client level.

Modifications:

- Remove some assertions from
`LoggingGrpcLifecycleObserver` and `LoggingHttpLifecycleObserver`;
- Clarify some expectations in `HttpLifecycleObserver` javadoc;

Result:

No `AssertionError` in tests that can retry.

servicetalk-grpc-utils/src/main/java/io/servicetalk/grpc/utils/LoggingGrpcLifecycleObserver.java

@@ -84,7 +84,6 @@ private LoggingGrpcExchangeObserver(final FixedLevelLogger logger) {
 
         @Override
         public void onConnectionSelected(final ConnectionInfo info) {
-            assert this.connInfo == null;
             this.connInfo = info;
         }
 
@@ -111,20 +110,19 @@ public void onRequestTrailers(final HttpHeaders trailers) {
 
         @Override
         public void onRequestComplete() {
-            assert requestResult == null;
-            assert requestMetaData != null;
+            assert requestMetaData != null : "Request meta-data is not expected to be null on completion";
             requestResult = Result.complete;
         }
 
         @Override
         public void onRequestError(final Throwable cause) {
-            assert requestResult == null;
+            assert requestMetaData != null : "Request meta-data is not expected to be null on error";
             requestResult = cause;
         }
 
         @Override
         public void onRequestCancel() {
-            assert requestResult == null;
+            assert requestMetaData != null : "Request meta-data is not expected to be null on cancel";
             requestResult = Result.cancelled;
         }
 
@@ -151,28 +149,24 @@ public void onResponseTrailers(final HttpHeaders trailers) {
 
         @Override
         public void onGrpcStatus(final GrpcStatus status) {
-            assert this.grpcStatus == null;
             this.grpcStatus = status.code();
         }
 
         @Override
         public void onResponseComplete() {
-            assert responseResult == null;
-            assert responseMetaData != null;
+            assert responseMetaData != null : "Response meta-data is not expected to be null on completion";
             responseTimeMs = durationMs(startTime);
             responseResult = Result.complete;
         }
 
         @Override
         public void onResponseError(final Throwable cause) {
-            assert responseResult == null;
             responseTimeMs = durationMs(startTime);
             responseResult = cause;
         }
 
         @Override
         public void onResponseCancel() {
-            assert responseResult == null;
             responseTimeMs = durationMs(startTime);
             responseResult = Result.cancelled;
         }

servicetalk-http-api/src/main/java/io/servicetalk/http/api/HttpLifecycleObserver.java

@@ -39,6 +39,9 @@ public interface HttpLifecycleObserver {
 
     /**
      * Callback when a new HTTP exchange starts.
+     * <p>
+     * Depending on the order in which the observer is applied, this callback can be invoked either for every retry
+     * attempt (if an observer is added after retrying filter) or only once per exchange.
      *
      * @return an {@link HttpExchangeObserver} that provides visibility into exchange events
      */
@@ -56,6 +59,8 @@ interface HttpExchangeObserver {
 
         /**
          * Callback when a connection is selected for this exchange execution.
+         * <p>
+         * This callback may be invoked for every retry attempt.
          *
          * @param info {@link ConnectionInfo} of the selected connection
          */

servicetalk-http-utils/src/main/java/io/servicetalk/http/utils/LoggingHttpLifecycleObserver.java

@@ -24,7 +24,6 @@
 import io.servicetalk.logging.slf4j.internal.FixedLevelLogger;
 import io.servicetalk.transport.api.ConnectionInfo;
 
-import java.util.Arrays;
 import javax.annotation.Nullable;
 
 import static io.servicetalk.logging.slf4j.internal.Slf4jFixedLevelLoggers.newLogger;
@@ -81,7 +80,6 @@ private LoggingHttpExchangeObserver(final FixedLevelLogger logger) {
 
         @Override
         public void onConnectionSelected(final ConnectionInfo info) {
-            assert this.connInfo == null;
             this.connInfo = info;
         }
 
@@ -108,23 +106,19 @@ public void onRequestTrailers(final HttpHeaders trailers) {
 
         @Override
         public void onRequestComplete() {
-            Object current = requestResult;
-            assert current == null : assertResultMsg(current, "requestResult");
             assert requestMetaData != null : "Request meta-data is not expected to be null on completion";
             requestResult = Result.complete;
         }
 
         @Override
         public void onRequestError(final Throwable cause) {
-            Object current = requestResult;
-            assert current == null : assertResultMsg(current, "requestResult");
+            assert requestMetaData != null : "Request meta-data is not expected to be null on error";
             requestResult = cause;
         }
 
         @Override
         public void onRequestCancel() {
-            Object current = requestResult;
-            assert current == null : assertResultMsg(current, "requestResult");
+            assert requestMetaData != null : "Request meta-data is not expected to be null on cancel";
             requestResult = Result.cancelled;
         }
 
@@ -151,25 +145,19 @@ public void onResponseTrailers(final HttpHeaders trailers) {
 
         @Override
         public void onResponseComplete() {
-            Object current = responseResult;
-            assert current == null : assertResultMsg(current, "responseResult");
-            assert responseMetaData != null;
+            assert responseMetaData != null : "Response meta-data is not expected to be null on completion";
             responseTimeMs = durationMs(startTime);
             responseResult = Result.complete;
         }
 
         @Override
         public void onResponseError(final Throwable cause) {
-            Object current = responseResult;
-            assert current == null : assertResultMsg(current, "responseResult");
             responseTimeMs = durationMs(startTime);
             responseResult = cause;
         }
 
         @Override
         public void onResponseCancel() {
-            Object current = responseResult;
-            assert current == null : assertResultMsg(current, "responseResult");
             responseTimeMs = durationMs(startTime);
             responseResult = Result.cancelled;
         }
@@ -221,11 +209,5 @@ private static long durationMs(final long startTime) {
         private enum Result {
             complete, error, cancelled
         }
-
-        private static String assertResultMsg(final Object current, final String name) {
-            return "Unexpected " + name + ": " + current + (current instanceof Throwable ?
-                    '\n' + String.join("\n", Arrays.stream(((Throwable) current).getStackTrace())
-                            .map(String::valueOf).toArray(CharSequence[]::new)) : "");
-        }
     }
 }