-
Type:
Improvement
-
Resolution: Done
-
Priority:
Unknown
-
None
-
Affects Version/s: None
-
Component/s: None
-
None
-
None
-
None
-
None
-
None
-
None
-
None
The existing unified spec test for connection logging has a specific order required for the following three events: ConnectionPoolCleared, ConnectionPoolClosed, ConnectionCheckOutFailed. There is an acceptable race condition in the connection pool's workflow where it is non-deterministic whether the connection pool will fail a checkout or close a connection first. Because of this, either ConnectionPoolClosed or ConnectionCheckOutFailed may be received in any order. Currently, to account for this behavior, we considered both logs to be "unordered".
Occasionally, an EG task will fail with the following:
[2023/05/22 22:50:21.735] === RUN TestUnifiedSpec/connection-monitoring-and-pooling/logging/connection-logging.json/Connection_checkout_fails_due_to_error_establishing_connection[2023/05/22 22:50:21.735] unified_spec_runner.go:134: error verifying log messages: logger verification failed: client: logger verification failed: document length mismatch: comparison error at key "message": expected value "Connection checkout failed", got "Connection pool cleared"
It appears that it is possible that the logs would propagate in this order:
ConnectionCheckOutFailed, ConnectionPoolCleared, ConnectionPoolClosed
This is still technically allowed, the only condition per this slack thread is that "the pool clear does need to come before the connectionclosed."
We should account for this in the isUnorderedLog function. One solution could be to maintain the state of the pool events in the "logQueues" struct.
Definition of complete: Update "partitionLogQueue" function and "isUnorderedLog" function to allow any order of failed and cleared, but ensure that closed ALWAYS comes after cleared.