Consumer creation lagging and timeout #862
Description
Describe the bug
For a serial creation of 300 named consumers for a single stream with pre-existing messages, each creation may take various seconds or even be timeout.
If there is no existing messages of the stream prior the creation flow, it can be all good and finished very quickly in a few seconds.
Please be noted, as long as there is 1 message prior the creation flow, it can be problematic.
Changing the invterval of each consumer creation can mitigate or worse the issue for it to appear.
Check the attached log of two differernt interval for more details.
Server be running on the same machine of the app or a separate one ( eg, docker).
Attached the reproducing gradle app.
The log of the failed case with 10ms interval:
./gradlew run
Task :run
14:50:13.527 [main] INFO StreamConsumerRepro - Published 1 messages.
14:50:13.626 [main] INFO StreamConsumerRepro - created consumer c-0, 94ms
14:50:13.660 [main] INFO StreamConsumerRepro - created consumer c-1, 21ms
14:50:13.695 [main] INFO StreamConsumerRepro - created consumer c-2, 22ms
14:50:13.728 [main] INFO StreamConsumerRepro - created consumer c-3, 21ms
14:50:13.762 [main] INFO StreamConsumerRepro - created consumer c-4, 21ms
14:50:13.794 [main] INFO StreamConsumerRepro - created consumer c-5, 20ms
14:50:13.826 [main] INFO StreamConsumerRepro - created consumer c-6, 20ms
14:50:13.858 [main] INFO StreamConsumerRepro - created consumer c-7, 21ms
14:50:13.915 [main] INFO StreamConsumerRepro - created consumer c-8, 44ms
14:50:13.948 [main] INFO StreamConsumerRepro - created consumer c-9, 21ms
14:50:13.987 [main] INFO StreamConsumerRepro - created consumer c-10, 27ms
14:50:14.025 [main] INFO StreamConsumerRepro - created consumer c-11, 27ms
14:50:14.066 [main] INFO StreamConsumerRepro - created consumer c-12, 28ms
14:50:14.109 [main] INFO StreamConsumerRepro - created consumer c-13, 32ms
14:50:14.158 [main] INFO StreamConsumerRepro - created consumer c-14, 38ms
14:50:14.204 [main] INFO StreamConsumerRepro - created consumer c-15, 35ms
14:50:14.255 [main] INFO StreamConsumerRepro - created consumer c-16, 38ms
14:50:14.302 [main] INFO StreamConsumerRepro - created consumer c-17, 35ms
14:50:14.345 [main] INFO StreamConsumerRepro - created consumer c-18, 31ms
14:50:14.386 [main] INFO StreamConsumerRepro - created consumer c-19, 30ms
14:50:14.432 [main] INFO StreamConsumerRepro - created consumer c-20, 33ms
14:50:14.477 [main] INFO StreamConsumerRepro - created consumer c-21, 33ms
14:50:14.520 [main] INFO StreamConsumerRepro - created consumer c-22, 30ms
14:50:14.564 [main] INFO StreamConsumerRepro - created consumer c-23, 31ms
14:50:19.344 [main] INFO StreamConsumerRepro - created consumer c-24, 4764ms
14:50:19.379 [main] INFO StreamConsumerRepro - created consumer c-25, 23ms
14:50:19.416 [main] INFO StreamConsumerRepro - created consumer c-26, 25ms
14:50:19.451 [main] INFO StreamConsumerRepro - created consumer c-27, 22ms
14:50:19.485 [main] INFO StreamConsumerRepro - created consumer c-28, 21ms
14:50:19.524 [main] INFO StreamConsumerRepro - created consumer c-29, 25ms
14:50:19.563 [main] INFO StreamConsumerRepro - created consumer c-30, 27ms
14:50:19.601 [main] INFO StreamConsumerRepro - created consumer c-31, 25ms
14:50:26.410 [main] INFO StreamConsumerRepro - created consumer c-32, 6796ms
14:50:26.446 [main] INFO StreamConsumerRepro - created consumer c-33, 23ms
14:50:26.500 [main] INFO StreamConsumerRepro - created consumer c-34, 41ms
14:50:26.531 [main] INFO StreamConsumerRepro - created consumer c-35, 19ms
14:50:26.570 [main] INFO StreamConsumerRepro - created consumer c-36, 26ms
14:50:32.506 [main] INFO StreamConsumerRepro - created consumer c-37, 5925ms
14:50:32.536 [main] INFO StreamConsumerRepro - created consumer c-38, 18ms
14:50:32.566 [main] INFO StreamConsumerRepro - created consumer c-39, 18ms
14:50:38.980 [main] INFO StreamConsumerRepro - created consumer c-40, 6401ms
14:50:39.019 [main] INFO StreamConsumerRepro - created consumer c-41, 25ms
14:50:39.055 [main] INFO StreamConsumerRepro - created consumer c-42, 24ms
14:50:39.093 [main] INFO StreamConsumerRepro - created consumer c-43, 27ms
14:50:39.139 [main] INFO StreamConsumerRepro - created consumer c-44, 35ms
14:50:39.170 [main] INFO StreamConsumerRepro - created consumer c-45, 18ms
14:50:39.202 [main] INFO StreamConsumerRepro - created consumer c-46, 20ms
14:50:39.240 [main] INFO StreamConsumerRepro - created consumer c-47, 26ms
14:50:39.268 [main] INFO StreamConsumerRepro - created consumer c-48, 16ms
14:50:39.303 [main] INFO StreamConsumerRepro - created consumer c-49, 22ms
14:50:39.361 [main] INFO StreamConsumerRepro - created consumer c-50, 47ms
14:50:39.390 [main] INFO StreamConsumerRepro - created consumer c-51, 17ms
14:50:39.422 [main] INFO StreamConsumerRepro - created consumer c-52, 20ms
14:50:39.452 [main] INFO StreamConsumerRepro - created consumer c-53, 17ms
14:50:39.482 [main] INFO StreamConsumerRepro - created consumer c-54, 18ms
14:50:39.514 [main] INFO StreamConsumerRepro - created consumer c-55, 19ms
14:50:39.550 [main] INFO StreamConsumerRepro - created consumer c-56, 24ms
14:50:50.529 [main] INFO StreamConsumerRepro - created consumer c-57, 10966ms
14:50:50.567 [main] INFO StreamConsumerRepro - created consumer c-58, 25ms
14:51:04.512 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 123 (QueryOffsetFrameHandler)
14:51:04.517 [main] INFO StreamConsumerRepro - created consumer c-59, 13940ms
14:51:04.555 [main] INFO StreamConsumerRepro - created consumer c-60, 27ms
14:51:13.241 [main] INFO StreamConsumerRepro - created consumer c-61, 8675ms
14:51:13.275 [main] INFO StreamConsumerRepro - created consumer c-62, 21ms
14:51:13.312 [main] INFO StreamConsumerRepro - created consumer c-63, 24ms
14:51:13.346 [main] INFO StreamConsumerRepro - created consumer c-64, 23ms
14:51:13.381 [main] INFO StreamConsumerRepro - created consumer c-65, 23ms
14:51:13.416 [main] INFO StreamConsumerRepro - created consumer c-66, 23ms
14:51:13.454 [main] INFO StreamConsumerRepro - created consumer c-67, 26ms
14:51:13.487 [main] INFO StreamConsumerRepro - created consumer c-68, 20ms
14:51:13.521 [main] INFO StreamConsumerRepro - created consumer c-69, 22ms
14:51:13.555 [main] INFO StreamConsumerRepro - created consumer c-70, 21ms
14:51:23.948 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 148 (QueryOffsetFrameHandler)
14:51:27.507 [main] INFO StreamConsumerRepro - created consumer c-71, 13939ms
14:51:27.539 [main] INFO StreamConsumerRepro - created consumer c-72, 20ms
14:51:27.575 [main] INFO StreamConsumerRepro - created consumer c-73, 24ms
14:51:40.174 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 155 (QueryOffsetFrameHandler)
14:51:40.183 [main] INFO StreamConsumerRepro - created consumer c-74, 12598ms
14:51:40.217 [main] INFO StreamConsumerRepro - created consumer c-75, 23ms
14:51:40.257 [main] INFO StreamConsumerRepro - created consumer c-76, 28ms
14:51:40.293 [main] INFO StreamConsumerRepro - created consumer c-77, 24ms
14:51:40.339 [main] INFO StreamConsumerRepro - created consumer c-78, 35ms
14:51:40.378 [main] INFO StreamConsumerRepro - created consumer c-79, 27ms
14:51:40.419 [main] INFO StreamConsumerRepro - created consumer c-80, 27ms
14:51:40.454 [main] INFO StreamConsumerRepro - created consumer c-81, 24ms
14:51:40.487 [main] INFO StreamConsumerRepro - created consumer c-82, 20ms
14:51:40.523 [main] INFO StreamConsumerRepro - created consumer c-83, 25ms
14:51:40.556 [main] INFO StreamConsumerRepro - created consumer c-84, 21ms
14:51:55.205 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 178 (QueryOffsetFrameHandler)
14:51:58.272 [main] INFO StreamConsumerRepro - created consumer c-85, 17705ms
14:51:58.310 [main] INFO StreamConsumerRepro - created consumer c-86, 26ms
14:51:58.350 [main] INFO StreamConsumerRepro - created consumer c-87, 28ms
14:51:58.383 [main] INFO StreamConsumerRepro - created consumer c-88, 20ms
14:51:58.415 [main] INFO StreamConsumerRepro - created consumer c-89, 21ms
14:51:58.452 [main] INFO StreamConsumerRepro - created consumer c-90, 25ms
14:51:58.482 [main] INFO StreamConsumerRepro - created consumer c-91, 18ms
14:51:58.516 [main] INFO StreamConsumerRepro - created consumer c-92, 23ms
14:51:58.557 [main] INFO StreamConsumerRepro - created consumer c-93, 30ms
14:52:16.269 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 197 (QueryOffsetFrameHandler)
14:52:28.596 [main] ERROR StreamConsumerRepro - Failed to create consumer c-94, 30026ms
com.rabbitmq.stream.StreamException: Could not get response in 10000 ms from node p4-bosgame:5552
at com.rabbitmq.stream.impl.ConsumersCoordinator.lambda$subscribe$1(ConsumersCoordinator.java:172)
at com.rabbitmq.stream.impl.Utils.lock(Utils.java:723)
at com.rabbitmq.stream.impl.ConsumersCoordinator.subscribe(ConsumersCoordinator.java:144)
at com.rabbitmq.stream.impl.StreamEnvironment.registerConsumer(StreamEnvironment.java:852)
at com.rabbitmq.stream.impl.StreamConsumer.lambda$new$8(StreamConsumer.java:243)
at com.rabbitmq.stream.impl.StreamConsumer.(StreamConsumer.java:259)
at com.rabbitmq.stream.impl.StreamConsumerBuilder.build(StreamConsumerBuilder.java:253)
at StreamConsumerRepro.main(StreamConsumerRepro.java:56)
14:52:28.597 [main] INFO StreamConsumerRepro - Closing environment...
14:52:30.572 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 198 (QueryOffsetFrameHandler)
14:52:30.573 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 199 (QueryOffsetFrameHandler)
14:52:32.623 [main] INFO StreamConsumerRepro - All done. Goodbye.
The log of failed case with 1 second interval:
./gradlew run
Task :run
11:07:44.000 [main] INFO com.rabbitmq.stream.impl.StreamEnvironment - Connecting to localhost with guest user, assuming development environment
11:07:44.001 [main] INFO com.rabbitmq.stream.impl.StreamEnvironment - Using address resolver to always connect to localhost
11:07:45.258 [main] INFO StreamConsumerRepro - Published 1 messages.
11:07:45.293 [main] INFO StreamConsumerRepro - created consumer c-0, 34ms
11:07:46.304 [main] INFO StreamConsumerRepro - created consumer c-1, 9ms
11:07:47.316 [main] INFO StreamConsumerRepro - created consumer c-2, 8ms
11:07:48.327 [main] INFO StreamConsumerRepro - created consumer c-3, 8ms
11:07:49.334 [main] INFO StreamConsumerRepro - created consumer c-4, 5ms
11:07:50.344 [main] INFO StreamConsumerRepro - created consumer c-5, 5ms
11:07:51.349 [main] INFO StreamConsumerRepro - created consumer c-6, 4ms
11:07:52.377 [main] INFO StreamConsumerRepro - created consumer c-7, 27ms
11:07:53.409 [main] INFO StreamConsumerRepro - created consumer c-8, 27ms
11:07:54.447 [main] INFO StreamConsumerRepro - created consumer c-9, 33ms
11:07:55.482 [main] INFO StreamConsumerRepro - created consumer c-10, 33ms
11:07:56.518 [main] INFO StreamConsumerRepro - created consumer c-11, 31ms
11:07:57.606 [main] INFO StreamConsumerRepro - created consumer c-12, 82ms
11:07:58.646 [main] INFO StreamConsumerRepro - created consumer c-13, 34ms
11:07:59.698 [main] INFO StreamConsumerRepro - created consumer c-14, 43ms
11:08:00.738 [main] INFO StreamConsumerRepro - created consumer c-15, 34ms
11:08:01.802 [main] INFO StreamConsumerRepro - created consumer c-16, 59ms
11:08:02.865 [main] INFO StreamConsumerRepro - created consumer c-17, 62ms
11:08:03.942 [main] INFO StreamConsumerRepro - created consumer c-18, 72ms
11:08:05.029 [main] INFO StreamConsumerRepro - created consumer c-19, 81ms
11:08:06.096 [main] INFO StreamConsumerRepro - created consumer c-20, 62ms
11:08:07.170 [main] INFO StreamConsumerRepro - created consumer c-21, 71ms
11:08:08.296 [main] INFO StreamConsumerRepro - created consumer c-22, 121ms
11:08:10.397 [main] INFO StreamConsumerRepro - created consumer c-23, 1097ms
11:08:12.456 [main] INFO StreamConsumerRepro - created consumer c-24, 1057ms
11:08:14.555 [main] INFO StreamConsumerRepro - created consumer c-25, 1095ms
11:08:16.663 [main] INFO StreamConsumerRepro - created consumer c-26, 1105ms
11:08:18.794 [main] INFO StreamConsumerRepro - created consumer c-27, 1126ms
11:08:20.924 [main] INFO StreamConsumerRepro - created consumer c-28, 1125ms
11:08:22.999 [main] INFO StreamConsumerRepro - created consumer c-29, 1070ms
11:08:25.251 [main] INFO StreamConsumerRepro - created consumer c-30, 1248ms
11:08:27.290 [main] INFO StreamConsumerRepro - created consumer c-31, 1033ms
11:08:30.366 [main] INFO StreamConsumerRepro - created consumer c-32, 2072ms
11:08:33.532 [main] INFO StreamConsumerRepro - created consumer c-33, 2161ms
11:08:36.672 [main] INFO StreamConsumerRepro - created consumer c-34, 2138ms
11:08:39.785 [main] INFO StreamConsumerRepro - created consumer c-35, 2108ms
11:08:42.949 [main] INFO StreamConsumerRepro - created consumer c-36, 2162ms
11:08:46.153 [main] INFO StreamConsumerRepro - created consumer c-37, 2200ms
11:08:49.351 [main] INFO StreamConsumerRepro - created consumer c-38, 2193ms
11:08:53.619 [main] INFO StreamConsumerRepro - created consumer c-39, 3263ms
11:08:57.662 [main] INFO StreamConsumerRepro - created consumer c-40, 3038ms
11:09:01.852 [main] INFO StreamConsumerRepro - created consumer c-41, 3185ms
11:09:05.988 [main] INFO StreamConsumerRepro - created consumer c-42, 3133ms
11:09:10.160 [main] INFO StreamConsumerRepro - created consumer c-43, 3167ms
11:09:14.353 [main] INFO StreamConsumerRepro - created consumer c-44, 3186ms
11:09:19.585 [main] INFO StreamConsumerRepro - created consumer c-45, 4228ms
11:09:24.772 [main] INFO StreamConsumerRepro - created consumer c-46, 4181ms
11:09:29.906 [main] INFO StreamConsumerRepro - created consumer c-47, 4131ms
11:09:35.143 [main] INFO StreamConsumerRepro - created consumer c-48, 4235ms
11:09:40.277 [main] INFO StreamConsumerRepro - created consumer c-49, 4127ms
11:09:46.546 [main] INFO StreamConsumerRepro - created consumer c-50, 5269ms
11:09:52.868 [main] INFO StreamConsumerRepro - created consumer c-51, 5317ms
11:09:58.961 [main] INFO StreamConsumerRepro - created consumer c-52, 5088ms
11:10:05.193 [main] INFO StreamConsumerRepro - created consumer c-53, 5227ms
11:10:11.357 [main] INFO StreamConsumerRepro - created consumer c-54, 5158ms
11:10:18.688 [main] INFO StreamConsumerRepro - created consumer c-55, 6330ms
11:10:25.858 [main] INFO StreamConsumerRepro - created consumer c-56, 6166ms
11:10:33.053 [main] INFO StreamConsumerRepro - created consumer c-57, 6195ms
11:10:40.198 [main] INFO StreamConsumerRepro - created consumer c-58, 6141ms
11:10:47.435 [main] INFO StreamConsumerRepro - created consumer c-59, 6234ms
<=========----> 75% EXECUTING [3m 10s]
11:10:55.678 [main] INFO StreamConsumerRepro - created consumer c-60, 7238ms
11:11:04.086 [main] INFO StreamConsumerRepro - created consumer c-61, 7402ms
11:11:12.212 [main] INFO StreamConsumerRepro - created consumer c-62, 7126ms
11:11:20.647 [main] INFO StreamConsumerRepro - created consumer c-63, 7431ms
11:11:29.720 [main] INFO StreamConsumerRepro - created consumer c-64, 8070ms
11:11:38.969 [main] INFO StreamConsumerRepro - created consumer c-65, 8243ms
11:11:48.363 [main] INFO StreamConsumerRepro - created consumer c-66, 8389ms
11:11:58.510 [main] INFO StreamConsumerRepro - created consumer c-67, 9143ms
11:12:08.855 [main] INFO StreamConsumerRepro - created consumer c-68, 9339ms
11:12:19.252 [main] INFO StreamConsumerRepro - created consumer c-69, 9393ms
11:12:29.430 [main] INFO StreamConsumerRepro - created consumer c-70, 9174ms
11:12:40.827 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 147 (QueryOffsetFrameHandler)
11:12:40.839 [main] INFO StreamConsumerRepro - created consumer c-71, 10404ms
11:12:52.124 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 150 (QueryOffsetFrameHandler)
11:12:52.128 [main] INFO StreamConsumerRepro - created consumer c-72, 10287ms
11:13:03.341 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 153 (QueryOffsetFrameHandler)
11:13:03.348 [main] INFO StreamConsumerRepro - created consumer c-73, 10214ms
11:13:15.701 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 156 (QueryOffsetFrameHandler)
11:13:15.705 [main] INFO StreamConsumerRepro - created consumer c-74, 11354ms
11:13:27.967 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 159 (QueryOffsetFrameHandler)
11:13:27.972 [main] INFO StreamConsumerRepro - created consumer c-75, 11264ms
11:13:40.317 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 162 (QueryOffsetFrameHandler)
11:13:40.320 [main] INFO StreamConsumerRepro - created consumer c-76, 11345ms
11:13:53.695 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 165 (QueryOffsetFrameHandler)
11:13:53.704 [main] INFO StreamConsumerRepro - created consumer c-77, 12377ms
11:14:06.955 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 168 (QueryOffsetFrameHandler)
11:14:06.959 [main] INFO StreamConsumerRepro - created consumer c-78, 12253ms
11:14:20.284 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 171 (QueryOffsetFrameHandler)
11:14:20.292 [main] INFO StreamConsumerRepro - created consumer c-79, 12329ms
11:14:34.629 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 174 (QueryOffsetFrameHandler)
11:14:34.639 [main] INFO StreamConsumerRepro - created consumer c-80, 13344ms
11:14:48.987 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 177 (QueryOffsetFrameHandler)
11:14:48.994 [main] INFO StreamConsumerRepro - created consumer c-81, 13352ms
11:15:03.423 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 180 (QueryOffsetFrameHandler)
11:15:03.450 [main] INFO StreamConsumerRepro - created consumer c-82, 13453ms
11:15:18.982 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 183 (QueryOffsetFrameHandler)
11:15:18.988 [main] INFO StreamConsumerRepro - created consumer c-83, 14533ms
11:15:34.308 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 186 (QueryOffsetFrameHandler)
11:15:34.313 [main] INFO StreamConsumerRepro - created consumer c-84, 14320ms
11:15:50.639 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 189 (QueryOffsetFrameHandler)
11:15:50.644 [main] INFO StreamConsumerRepro - created consumer c-85, 15325ms
11:16:06.872 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 192 (QueryOffsetFrameHandler)
11:16:06.888 [main] INFO StreamConsumerRepro - created consumer c-86, 15242ms
11:16:23.436 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 195 (QueryOffsetFrameHandler)
11:16:23.449 [main] INFO StreamConsumerRepro - created consumer c-87, 15557ms
11:16:40.501 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 198 (QueryOffsetFrameHandler)
11:16:40.511 [main] INFO StreamConsumerRepro - created consumer c-88, 16057ms
11:16:58.139 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 201 (QueryOffsetFrameHandler)
11:16:58.146 [main] INFO StreamConsumerRepro - created consumer c-89, 16630ms
11:17:15.311 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 204 (QueryOffsetFrameHandler)
11:17:15.324 [main] INFO StreamConsumerRepro - created consumer c-90, 16171ms
11:17:33.430 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 207 (QueryOffsetFrameHandler)
11:17:33.440 [main] INFO StreamConsumerRepro - created consumer c-91, 17113ms
11:17:51.921 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 210 (QueryOffsetFrameHandler)
11:17:51.934 [main] INFO StreamConsumerRepro - created consumer c-92, 17489ms
11:18:09.971 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 213 (QueryOffsetFrameHandler)
11:18:09.974 [main] INFO StreamConsumerRepro - created consumer c-93, 17036ms
11:18:28.773 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 216 (QueryOffsetFrameHandler)
11:18:28.777 [main] INFO StreamConsumerRepro - created consumer c-94, 17800ms
11:18:48.596 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 219 (QueryOffsetFrameHandler)
11:18:48.609 [main] INFO StreamConsumerRepro - created consumer c-95, 18828ms
11:19:08.609 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 222 (QueryOffsetFrameHandler)
11:19:08.617 [main] INFO StreamConsumerRepro - created consumer c-96, 19005ms
11:19:29.378 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 225 (QueryOffsetFrameHandler)
11:19:29.385 [main] INFO StreamConsumerRepro - created consumer c-97, 19763ms
11:19:51.746 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 228 (QueryOffsetFrameHandler)
11:19:51.747 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 229 (QueryOffsetFrameHandler)
11:19:51.761 [main] INFO StreamConsumerRepro - created consumer c-98, 21370ms
11:20:12.907 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 232 (QueryOffsetFrameHandler)
11:20:12.909 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 233 (QueryOffsetFrameHandler)
11:20:12.913 [main] INFO StreamConsumerRepro - created consumer c-99, 20148ms
11:20:33.860 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 236 (QueryOffsetFrameHandler)
11:20:33.862 [main] INFO StreamConsumerRepro - created consumer c-100, 19943ms
11:20:55.370 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 239 (QueryOffsetFrameHandler)
11:20:55.370 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 240 (QueryOffsetFrameHandler)
11:20:55.377 [main] INFO StreamConsumerRepro - created consumer c-101, 20509ms
11:21:17.960 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 243 (QueryOffsetFrameHandler)
11:21:17.961 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 244 (QueryOffsetFrameHandler)
11:21:17.966 [main] INFO StreamConsumerRepro - created consumer c-102, 21587ms
11:21:40.346 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 247 (QueryOffsetFrameHandler)
11:21:40.346 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 248 (QueryOffsetFrameHandler)
11:21:40.348 [main] INFO StreamConsumerRepro - created consumer c-103, 21379ms
11:22:03.701 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 251 (QueryOffsetFrameHandler)
11:22:03.701 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 252 (QueryOffsetFrameHandler)
11:22:03.704 [main] INFO StreamConsumerRepro - created consumer c-104, 22352ms
11:22:27.288 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 255 (QueryOffsetFrameHandler)
11:22:27.289 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 256 (QueryOffsetFrameHandler)
11:22:27.292 [main] INFO StreamConsumerRepro - created consumer c-105, 22579ms
11:22:51.632 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 259 (QueryOffsetFrameHandler)
11:22:51.633 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 260 (QueryOffsetFrameHandler)
11:22:51.635 [main] INFO StreamConsumerRepro - created consumer c-106, 23337ms
11:23:16.246 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 263 (QueryOffsetFrameHandler)
11:23:16.249 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 264 (QueryOffsetFrameHandler)
11:23:16.265 [main] INFO StreamConsumerRepro - created consumer c-107, 23626ms
11:23:40.335 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 267 (QueryOffsetFrameHandler)
11:23:40.335 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 268 (QueryOffsetFrameHandler)
11:23:40.339 [main] INFO StreamConsumerRepro - created consumer c-108, 23067ms
11:24:05.688 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 271 (QueryOffsetFrameHandler)
11:24:05.690 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 272 (QueryOffsetFrameHandler)
11:24:05.696 [main] INFO StreamConsumerRepro - created consumer c-109, 24354ms
11:24:31.416 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 275 (QueryOffsetFrameHandler)
11:24:31.418 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 276 (QueryOffsetFrameHandler)
11:24:31.425 [main] INFO StreamConsumerRepro - created consumer c-110, 24726ms
11:24:58.082 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 279 (QueryOffsetFrameHandler)
11:24:58.083 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 280 (QueryOffsetFrameHandler)
11:24:58.085 [main] INFO StreamConsumerRepro - created consumer c-111, 25656ms
11:25:24.449 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 283 (QueryOffsetFrameHandler)
11:25:24.452 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 284 (QueryOffsetFrameHandler)
11:25:24.461 [main] INFO StreamConsumerRepro - created consumer c-112, 25369ms
11:25:52.361 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 287 (QueryOffsetFrameHandler)
11:25:52.361 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 288 (QueryOffsetFrameHandler)
11:25:52.363 [main] INFO StreamConsumerRepro - created consumer c-113, 26898ms
11:26:20.693 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 291 (QueryOffsetFrameHandler)
11:26:20.693 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 292 (QueryOffsetFrameHandler)
11:26:20.696 [main] INFO StreamConsumerRepro - created consumer c-114, 27328ms
11:26:48.700 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 295 (QueryOffsetFrameHandler)
11:26:48.700 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 296 (QueryOffsetFrameHandler)
11:26:48.701 [main] INFO StreamConsumerRepro - created consumer c-115, 27000ms
11:27:16.963 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 299 (QueryOffsetFrameHandler)
11:27:16.965 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 300 (QueryOffsetFrameHandler)
11:27:16.969 [main] INFO StreamConsumerRepro - created consumer c-116, 27262ms
11:27:45.544 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 303 (QueryOffsetFrameHandler)
11:27:45.544 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 304 (QueryOffsetFrameHandler)
11:27:45.550 [main] INFO StreamConsumerRepro - created consumer c-117, 27578ms
11:28:16.085 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 307 (QueryOffsetFrameHandler)
11:28:16.085 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 308 (QueryOffsetFrameHandler)
11:28:16.091 [main] INFO StreamConsumerRepro - created consumer c-118, 29538ms
11:28:46.226 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 311 (QueryOffsetFrameHandler)
11:28:46.226 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 312 (QueryOffsetFrameHandler)
11:28:46.231 [main] INFO StreamConsumerRepro - created consumer c-119, 29135ms
11:29:16.481 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 315 (QueryOffsetFrameHandler)
11:29:16.485 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 316 (QueryOffsetFrameHandler)
11:29:16.498 [main] INFO StreamConsumerRepro - created consumer c-120, 29262ms
11:29:47.553 [main] ERROR StreamConsumerRepro - Failed to create consumer c-121, 30048ms
com.rabbitmq.stream.StreamException: Could not get response in 10000 ms from node localhost:5552
at com.rabbitmq.stream.impl.ConsumersCoordinator.lambda$subscribe$1(ConsumersCoordinator.java:143)
at com.rabbitmq.stream.impl.Utils.lock(Utils.java:698)
at com.rabbitmq.stream.impl.ConsumersCoordinator.subscribe(ConsumersCoordinator.java:115)
at com.rabbitmq.stream.impl.StreamEnvironment.registerConsumer(StreamEnvironment.java:793)
at com.rabbitmq.stream.impl.StreamConsumer.lambda$new$8(StreamConsumer.java:229)
at com.rabbitmq.stream.impl.StreamConsumer.(StreamConsumer.java:246)
at com.rabbitmq.stream.impl.StreamConsumerBuilder.build(StreamConsumerBuilder.java:232)
at StreamConsumerRepro.main(StreamConsumerRepro.java:56)
11:29:47.554 [main] INFO StreamConsumerRepro - Closing environment...
11:29:47.931 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 319 (QueryOffsetFrameHandler)
11:29:47.933 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 320 (QueryOffsetFrameHandler)
11:29:47.933 [rabbitmq-stream-consumer-connection-0] WARN com.rabbitmq.stream.impl.ServerFrameHandler - Could not find outstanding request with correlation ID 321 (QueryOffsetFrameHandler)
11:29:49.099 [main] INFO StreamConsumerRepro - All done. Goodbye.
Reproduction steps
Server ver: 4.1.3 (brew), 4.1 (docker)
Client ver: 1.2.0,1.3.0
Java: OpenJDK Runtime Environment Zulu11.52+13-CA (build 11.0.13+8-LTS)
OS: macos 15.4.4
- Install and start server with stream enabled(can be via docker or macos brew), jdk
- unzip the file and go into the folder
- ./gradlew run ( be noted that prePublishMsg = true and consumerInterval = 10 are preset in the code)
- try change prePublishMsg = false in the source code and rerun the test as a normal one to compare
- try change consumerInterval = 1000; // ms in the source code and rerun the test as a worsen one to compare
Expected behavior
All 300 consumer should be created sucessfuly without lagging or timeout, just like the behavior when there is no existing msg of the stream.
Additional context
No response