Skip to content

Conversation

@ansd
Copy link
Member

@ansd ansd commented Nov 8, 2024

Prior to this commit, the following flake occurred in CI for

make -C deps/rabbitmq_mqtt ct-v5 t=cluster_size_1:will_delay_session_takeover
=== Location: [{v5_SUITE,will_delay_session_takeover,1473},
              {test_server,ts_tc,1793},
              {test_server,run_test_case_eval1,1302},
              {test_server,run_test_case_eval,1234}]
=== === Reason: {test_case_failed,"Received unexpected PUBLISH payload. Expected: <<\"will-3a\">> Got: <<\"will-4a\">>"}

The RabbitMQ logs for this single node test show:

2024-11-04 14:43:35.039196+00:00 [debug] <0.1334.0> MQTT accepting TCP connection <0.1334.0> (127.0.0.1:42576 -> 127.0.0.1:27005)
2024-11-04 14:43:35.039336+00:00 [debug] <0.1334.0> Received a CONNECT, client ID: c3, username: undefined, clean start: true, protocol version: 5, keepalive: 60, property names: []
2024-11-04 14:43:35.039438+00:00 [debug] <0.1334.0> MQTT connection 127.0.0.1:42576 -> 127.0.0.1:27005 picked vhost using plugin_configuration_or_default_vhost
2024-11-04 14:43:35.039537+00:00 [debug] <0.1334.0> User 'guest' authenticated successfully by backend rabbit_auth_backend_internal
2024-11-04 14:43:35.039729+00:00 [info] <0.1334.0> Accepted MQTT connection 127.0.0.1:42576 -> 127.0.0.1:27005 for client ID c3
2024-11-04 14:43:35.040297+00:00 [debug] <0.1337.0> MQTT accepting TCP connection <0.1337.0> (127.0.0.1:42580 -> 127.0.0.1:27005)
2024-11-04 14:43:35.040442+00:00 [debug] <0.1337.0> Received a CONNECT, client ID: c4, username: undefined, clean start: true, protocol version: 5, keepalive: 60, property names: []
2024-11-04 14:43:35.040534+00:00 [debug] <0.1337.0> MQTT connection 127.0.0.1:42580 -> 127.0.0.1:27005 picked vhost using plugin_configuration_or_default_vhost
2024-11-04 14:43:35.040597+00:00 [debug] <0.1337.0> User 'guest' authenticated successfully by backend rabbit_auth_backend_internal
2024-11-04 14:43:35.040793+00:00 [info] <0.1337.0> Accepted MQTT connection 127.0.0.1:42580 -> 127.0.0.1:27005 for client ID c4
2024-11-04 14:43:35.041463+00:00 [debug] <0.1340.0> MQTT accepting TCP connection <0.1340.0> (127.0.0.1:42596 -> 127.0.0.1:27005)
2024-11-04 14:43:35.041715+00:00 [debug] <0.1340.0> Received a CONNECT, client ID: c1, username: undefined, clean start: false, protocol version: 5, keepalive: 60, property names: ['Session-Expiry-Interval']
2024-11-04 14:43:35.041806+00:00 [debug] <0.1340.0> MQTT connection 127.0.0.1:42596 -> 127.0.0.1:27005 picked vhost using plugin_configuration_or_default_vhost
2024-11-04 14:43:35.041881+00:00 [debug] <0.1340.0> User 'guest' authenticated successfully by backend rabbit_auth_backend_internal
2024-11-04 14:43:35.041982+00:00 [warning] <0.1328.0> MQTT disconnecting client <<"127.0.0.1:42560 -> 127.0.0.1:27005">> with duplicate id 'c1'
2024-11-04 14:43:35.042062+00:00 [info] <0.1340.0> Accepted MQTT connection 127.0.0.1:42596 -> 127.0.0.1:27005 for client ID c1
2024-11-04 14:43:35.045624+00:00 [debug] <0.1345.0> MQTT accepting TCP connection <0.1345.0> (127.0.0.1:42602 -> 127.0.0.1:27005)
2024-11-04 14:43:35.045781+00:00 [debug] <0.1345.0> Received a CONNECT, client ID: c2, username: undefined, clean start: false, protocol version: 5, keepalive: 60, property names: ['Session-Expiry-Interval']
2024-11-04 14:43:35.045874+00:00 [debug] <0.1345.0> MQTT connection 127.0.0.1:42602 -> 127.0.0.1:27005 picked vhost using plugin_configuration_or_default_vhost
2024-11-04 14:43:35.045943+00:00 [debug] <0.1345.0> User 'guest' authenticated successfully by backend rabbit_auth_backend_internal
2024-11-04 14:43:35.046032+00:00 [warning] <0.1331.0> MQTT disconnecting client <<"127.0.0.1:42566 -> 127.0.0.1:27005">> with duplicate id 'c2'
2024-11-04 14:43:35.046281+00:00 [info] <0.1345.0> Accepted MQTT connection 127.0.0.1:42602 -> 127.0.0.1:27005 for client ID c2
2024-11-04 14:43:35.047063+00:00 [debug] <0.1350.0> MQTT accepting TCP connection <0.1350.0> (127.0.0.1:42614 -> 127.0.0.1:27005)
2024-11-04 14:43:35.047702+00:00 [debug] <0.1350.0> Received a CONNECT, client ID: c3, username: undefined, clean start: true, protocol version: 5, keepalive: 60, property names: ['Session-Expiry-Interval']
2024-11-04 14:43:35.047910+00:00 [debug] <0.1350.0> MQTT connection 127.0.0.1:42614 -> 127.0.0.1:27005 picked vhost using plugin_configuration_or_default_vhost
2024-11-04 14:43:35.048467+00:00 [debug] <0.1350.0> User 'guest' authenticated successfully by backend rabbit_auth_backend_internal
2024-11-04 14:43:35.049701+00:00 [info] <0.1350.0> Accepted MQTT connection 127.0.0.1:42614 -> 127.0.0.1:27005 for client ID c3
2024-11-04 14:43:35.050907+00:00 [warning] <0.1334.0> MQTT disconnecting client <<"127.0.0.1:42576 -> 127.0.0.1:27005">> with duplicate id 'c3'
2024-11-04 14:43:35.051248+00:00 [debug] <0.1353.0> MQTT accepting TCP connection <0.1353.0> (127.0.0.1:42626 -> 127.0.0.1:27005)
2024-11-04 14:43:35.051395+00:00 [debug] <0.1353.0> Received a CONNECT, client ID: c4, username: undefined, clean start: false, protocol version: 5, keepalive: 60, property names: ['Session-Expiry-Interval']
2024-11-04 14:43:35.051519+00:00 [debug] <0.1353.0> MQTT connection 127.0.0.1:42626 -> 127.0.0.1:27005 picked vhost using plugin_configuration_or_default_vhost
2024-11-04 14:43:35.051590+00:00 [debug] <0.1353.0> User 'guest' authenticated successfully by backend rabbit_auth_backend_internal
2024-11-04 14:43:35.051871+00:00 [info] <0.1353.0> Accepted MQTT connection 127.0.0.1:42626 -> 127.0.0.1:27005 for client ID c4
2024-11-04 14:43:35.051960+00:00 [warning] <0.1337.0> MQTT disconnecting client <<"127.0.0.1:42580 -> 127.0.0.1:27005">> with duplicate id 'c4'
2024-11-04 14:43:35.052689+00:00 [debug] <0.1337.0> sent Will Message to topic my/topic for MQTT client ID c4
2024-11-04 14:43:35.054119+00:00 [debug] <0.1334.0> sent Will Message to topic my/topic for MQTT client ID c3

We see nicely how RabbitMQ sends the will message for both c3 and c4. However, the order in which RabbitMQ sends is not guaranteed. Hence, we adapt the test expectation to not depend on the order of Will messages being received.

Prior to this commit, the following flake occurred in CI for
```
make -C deps/rabbitmq_mqtt ct-v5 t=cluster_size_1:will_delay_session_takeover
```

```
=== Location: [{v5_SUITE,will_delay_session_takeover,1473},
              {test_server,ts_tc,1793},
              {test_server,run_test_case_eval1,1302},
              {test_server,run_test_case_eval,1234}]
=== === Reason: {test_case_failed,"Received unexpected PUBLISH payload. Expected: <<\"will-3a\">> Got: <<\"will-4a\">>"}
```

The RabbitMQ logs for this single node test show:
```
2024-11-04 14:43:35.039196+00:00 [debug] <0.1334.0> MQTT accepting TCP connection <0.1334.0> (127.0.0.1:42576 -> 127.0.0.1:27005)
2024-11-04 14:43:35.039336+00:00 [debug] <0.1334.0> Received a CONNECT, client ID: c3, username: undefined, clean start: true, protocol version: 5, keepalive: 60, property names: []
2024-11-04 14:43:35.039438+00:00 [debug] <0.1334.0> MQTT connection 127.0.0.1:42576 -> 127.0.0.1:27005 picked vhost using plugin_configuration_or_default_vhost
2024-11-04 14:43:35.039537+00:00 [debug] <0.1334.0> User 'guest' authenticated successfully by backend rabbit_auth_backend_internal
2024-11-04 14:43:35.039729+00:00 [info] <0.1334.0> Accepted MQTT connection 127.0.0.1:42576 -> 127.0.0.1:27005 for client ID c3
2024-11-04 14:43:35.040297+00:00 [debug] <0.1337.0> MQTT accepting TCP connection <0.1337.0> (127.0.0.1:42580 -> 127.0.0.1:27005)
2024-11-04 14:43:35.040442+00:00 [debug] <0.1337.0> Received a CONNECT, client ID: c4, username: undefined, clean start: true, protocol version: 5, keepalive: 60, property names: []
2024-11-04 14:43:35.040534+00:00 [debug] <0.1337.0> MQTT connection 127.0.0.1:42580 -> 127.0.0.1:27005 picked vhost using plugin_configuration_or_default_vhost
2024-11-04 14:43:35.040597+00:00 [debug] <0.1337.0> User 'guest' authenticated successfully by backend rabbit_auth_backend_internal
2024-11-04 14:43:35.040793+00:00 [info] <0.1337.0> Accepted MQTT connection 127.0.0.1:42580 -> 127.0.0.1:27005 for client ID c4
2024-11-04 14:43:35.041463+00:00 [debug] <0.1340.0> MQTT accepting TCP connection <0.1340.0> (127.0.0.1:42596 -> 127.0.0.1:27005)
2024-11-04 14:43:35.041715+00:00 [debug] <0.1340.0> Received a CONNECT, client ID: c1, username: undefined, clean start: false, protocol version: 5, keepalive: 60, property names: ['Session-Expiry-Interval']
2024-11-04 14:43:35.041806+00:00 [debug] <0.1340.0> MQTT connection 127.0.0.1:42596 -> 127.0.0.1:27005 picked vhost using plugin_configuration_or_default_vhost
2024-11-04 14:43:35.041881+00:00 [debug] <0.1340.0> User 'guest' authenticated successfully by backend rabbit_auth_backend_internal
2024-11-04 14:43:35.041982+00:00 [warning] <0.1328.0> MQTT disconnecting client <<"127.0.0.1:42560 -> 127.0.0.1:27005">> with duplicate id 'c1'
2024-11-04 14:43:35.042062+00:00 [info] <0.1340.0> Accepted MQTT connection 127.0.0.1:42596 -> 127.0.0.1:27005 for client ID c1
2024-11-04 14:43:35.045624+00:00 [debug] <0.1345.0> MQTT accepting TCP connection <0.1345.0> (127.0.0.1:42602 -> 127.0.0.1:27005)
2024-11-04 14:43:35.045781+00:00 [debug] <0.1345.0> Received a CONNECT, client ID: c2, username: undefined, clean start: false, protocol version: 5, keepalive: 60, property names: ['Session-Expiry-Interval']
2024-11-04 14:43:35.045874+00:00 [debug] <0.1345.0> MQTT connection 127.0.0.1:42602 -> 127.0.0.1:27005 picked vhost using plugin_configuration_or_default_vhost
2024-11-04 14:43:35.045943+00:00 [debug] <0.1345.0> User 'guest' authenticated successfully by backend rabbit_auth_backend_internal
2024-11-04 14:43:35.046032+00:00 [warning] <0.1331.0> MQTT disconnecting client <<"127.0.0.1:42566 -> 127.0.0.1:27005">> with duplicate id 'c2'
2024-11-04 14:43:35.046281+00:00 [info] <0.1345.0> Accepted MQTT connection 127.0.0.1:42602 -> 127.0.0.1:27005 for client ID c2
2024-11-04 14:43:35.047063+00:00 [debug] <0.1350.0> MQTT accepting TCP connection <0.1350.0> (127.0.0.1:42614 -> 127.0.0.1:27005)
2024-11-04 14:43:35.047702+00:00 [debug] <0.1350.0> Received a CONNECT, client ID: c3, username: undefined, clean start: true, protocol version: 5, keepalive: 60, property names: ['Session-Expiry-Interval']
2024-11-04 14:43:35.047910+00:00 [debug] <0.1350.0> MQTT connection 127.0.0.1:42614 -> 127.0.0.1:27005 picked vhost using plugin_configuration_or_default_vhost
2024-11-04 14:43:35.048467+00:00 [debug] <0.1350.0> User 'guest' authenticated successfully by backend rabbit_auth_backend_internal
2024-11-04 14:43:35.049701+00:00 [info] <0.1350.0> Accepted MQTT connection 127.0.0.1:42614 -> 127.0.0.1:27005 for client ID c3
2024-11-04 14:43:35.050907+00:00 [warning] <0.1334.0> MQTT disconnecting client <<"127.0.0.1:42576 -> 127.0.0.1:27005">> with duplicate id 'c3'
2024-11-04 14:43:35.051248+00:00 [debug] <0.1353.0> MQTT accepting TCP connection <0.1353.0> (127.0.0.1:42626 -> 127.0.0.1:27005)
2024-11-04 14:43:35.051395+00:00 [debug] <0.1353.0> Received a CONNECT, client ID: c4, username: undefined, clean start: false, protocol version: 5, keepalive: 60, property names: ['Session-Expiry-Interval']
2024-11-04 14:43:35.051519+00:00 [debug] <0.1353.0> MQTT connection 127.0.0.1:42626 -> 127.0.0.1:27005 picked vhost using plugin_configuration_or_default_vhost
2024-11-04 14:43:35.051590+00:00 [debug] <0.1353.0> User 'guest' authenticated successfully by backend rabbit_auth_backend_internal
2024-11-04 14:43:35.051871+00:00 [info] <0.1353.0> Accepted MQTT connection 127.0.0.1:42626 -> 127.0.0.1:27005 for client ID c4
2024-11-04 14:43:35.051960+00:00 [warning] <0.1337.0> MQTT disconnecting client <<"127.0.0.1:42580 -> 127.0.0.1:27005">> with duplicate id 'c4'
2024-11-04 14:43:35.052689+00:00 [debug] <0.1337.0> sent Will Message to topic my/topic for MQTT client ID c4
2024-11-04 14:43:35.054119+00:00 [debug] <0.1334.0> sent Will Message to topic my/topic for MQTT client ID c3
```

We see nicely how RabbitMQ sends the will message for both c3 and c4.
However, the order in which RabbitMQ sends is not guaranteed.
Hence, we adapt the test expectation to not depend on the order of Will
messages being received.
@ansd ansd merged commit d309ec9 into main Nov 8, 2024
267 of 271 checks passed
@ansd ansd deleted the mqtt_flake_will_delay_session_takeover branch November 8, 2024 15:26
ansd added a commit that referenced this pull request Nov 8, 2024
Fix flake will_delay_session_takeover (backport #12694)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants