Node fails to start due to incompatible feature flags

[ares-the-god-of-war]

Good day,

I am running RabbitMQ in an Kubernetes environment with 3 nodes. I want to start from scratch with predefined configuration with RabbitMQ version 3.11.5, (docker image rabbitmq:3.11.5). I have got the predefined configuration in a configuration map containing definitions.json. The following steps will lead to node 2 and 3 crash.

1. Start up RabbitMQ node 1 (this node will start properly and load the configuration properly as well. After logging in into the GUI and going to the feature flags all feature flags are enabled.
2. Start up RabbitMQ node 2 (this node will fail to boot). If you now look at the feature flags, the flag direct_exchange_routing_v2 is disabled. (See below error).
3. If one sets the disabled feature flag to enabled, node 2 seems to start properly. However, when starting up node 3, the same thing happens. The feature flag is again disabled and node 3 fails to boot. Enabling the feature flag again allows node 3 to boot as well.

BOOT FAILED
===========
Error during startup: {error,
                       {incompatible_feature_flags,
                        {badarg,
                         [{ets,lookup,
                           [rabbit_exchange,
                            {resource,<<"/">>,exchange,<<"***_ex">>}],
                           [{error_info,
                             #{cause => id,module => erl_stdlib_errors}}]},
                          {rabbit_misc,dirty_read,1,
                           [{file,"rabbit_misc.erl"},{line,372}]},
                          {rabbit_binding,
                           '-populate_index_route_table/0-fun-0-',1,
                           [{file,"rabbit_binding.erl"},{line,756}]},
                          {lists,foreach_1,2,[{file,"lists.erl"},{line,1442}]},
                          {mnesia_tm,apply_fun,3,
                           [{file,"mnesia_tm.erl"},{line,842}]},
                          {mnesia_tm,execute_transaction,5,
                           [{file,"mnesia_tm.erl"},{line,818}]},
                          {rabbit_misc,
                           '-execute_mnesia_transaction/1-fun-0-',1,
                           [{file,"rabbit_misc.erl"},{line,566}]},
                          {worker_pool_worker,'-run/2-fun-0-',3,
                           [{file,"worker_pool_worker.erl"},{line,69}]}]}}}`

[lukebakken]

Please ATTACH your complete Kubernetes configuration and definitions.json files to this issue. Feel free to obfuscate passwords or other sensitive info but don't remove anything.

In addition, RabbitMQ and Kubernetes logs will be helpful.

At the moment you're asking us to guess how to reproduce this issue.

[michaelklishin]

This does not happen in most environments so we need to know exactly how the nodes are started.
The message is somewhat misleading, what it really means is that the features flag state on nodes 2 and 3 is inconsistent with that of 1. So parallel node startup can be involved.

It's also curious that this affects one specific feature flag.

I can think of two workarounds:

• Pre-enable flags as part of node configuration
• Make nodes boot without feature flags and then enable them (can potentially be harder to achieve on Kubernetes)

As of #6682 this feature flag will become required (auto-enabled) but that would only ship in 3.12.0.

@dumbbell @ansd this is on a version that includes #6658.

[s-srakshe]

We have also been consistently hitting this issue. I can confirm that it is not a parallel node startup. We are using bitnami rabbitmq chart that is based on Kubernetes StateFullSet that ensures that a cluster nodes are started one after another.

Will the following workaround help until we migrate to the fixed version.
{rabbit, [{forced_feature_flags_on_init, [direct_exchange_routing_v2]}]}

[ansd]

@s-srakshe can you please provide step-by-step description to reproduce this issue?

Here is what I did:
I ran the following against a GKE cluster version 1.25.4-gke.2100 with image cos_containerd.
Bitnami helm chart: rabbitmq-11.5.1

#!/usr/bin/env bash
set -euo pipefail
for i in {1..10}; do
    echo "Running #$i"
    helm install \
        --set replicaCount=3 \
        --set image.tag=3.11.7-debian-11-r5 my-release bitnami/rabbitmq
    sleep 20
    kubectl wait --for=jsonpath='{.status.readyReplicas}'=3 statefulset my-release-rabbitmq --timeout=10m
    kubectl exec my-release-rabbitmq-1 -c rabbitmq -- rabbitmqctl list_feature_flags --formatter=pretty_table
    helm delete my-release --wait
    sleep 10
done

In all 10 runs, the RabbitMQ nodes booted without issues and all feature flags got successfully enabled.

[s-srakshe]

Report for Bitnami Chart 11.5.1 with Rabbitmq 3.11.7
We are hitting the problem consistently with 3.11.7.
Understand that 3.11.x brought in some changes to features flags , https://blog.rabbitmq.com/posts/2022/07/required-feature-flags-in-rabbitmq-3.11/
Note : We are creating several exchanges through load_definitions, 3 of them are of type direct and the issue with feature flag direct_exchange_routing_v2 always occurs with direct type exchange.

Bitnami Chart 10.3.9 with Rabbitmq version 3.10.8
Bitnami Chart 10.3.9 with Rabbitmq version 3.10.8 and with same configuration (as Bitnami Chart 11.5.1 with Rabbitmq 3.11.7) seems to work well. Every time, the 3 pods start successfully one after another and cluster together.
In my k8s cluster, I am deploying both charts side by side (with helm alias) for comparison.

Report for Bitnami Chart 11.5.1 with Rabbitmq 3.11.7

Note: Bitnami rabbitmq container brings up rabbitmq in two stages, This is same in Bitnami chart 10.3.9 and 11.5.1

When the node 0 is started for the first time
Stage 1 - Initialise Rabbitmq
(1) setup config file, environment file, plugin file etc
(2) Start rabbitmq server in background
(3) Wait for rabbitmq server to come up - rabbitmqctl wait --pid
(4) add users from definitions file
(5) Stop rabbitmq server
Stage 2 -
Start rabbitmq server again

On subsequent boots
Stage 1 - Initialise Rabbitmq
(1) setup config file, environment file, plugin file etc
Execute following only if data directory is not present, since data directory would be present , following are not executed
(2) Start rabbitmq server in background
(3) Wait for rabbitmq server to come up - rabbitmqctl wait --pid
(4) add users from definitions file
(5) Stop rabbitmq server
Stage 2 -
**Start rabbitmq server

I am not sure if abrupt stopping of rabbitmq server in Stage 1 (step 5) during the first time boot is messing up the node 0.

After node 0 is up and running, What we are observing is that node 1 and node 2 during their first bootup are failing to start rabbitmq in Stage 1 - step 2, We see two kinds of failures. (a) failed enabling direct_exchange_routing_v2 or (b) error:{case_clause,{{error,{merge_schema_failed,"Bad cookie in table definition rabbit_node_maintenance_states

node 1 and node 2 crash and restart , if force boot is not enabled then they repeatedly crash and re-start. If force boot enabled then they bootup but are not clustered with node 0.

Links for Bitnami container files, entrypoints invokes setup.sh (stage 1) and run.sh (stage 2)
https://github.com/bitnami/containers/blob/main/bitnami/rabbitmq/3.9/debian-11/rootfs/opt/bitnami/scripts/librabbitmq.sh#L772
https://github.com/bitnami/containers/blob/main/bitnami/rabbitmq/3.9/debian-11/rootfs/opt/bitnami/scripts/rabbitmq/entrypoint.sh
https://github.com/bitnami/containers/blob/main/bitnami/rabbitmq/3.9/debian-11/rootfs/opt/bitnami/scripts/rabbitmq/setup.sh

[michaelklishin]

#6701 can also be relevant here.

[ansd]

@ares-the-god-of-war, as @lukebakken wrote, please provide exact reproduction steps including any configuration files and how the RabbitMQ nodes get clustered. You don't use https://github.com/rabbitmq/cluster-operator, do you?

[ares-the-god-of-war]

Dear all,

I have done several tests. Attached you can find some minimalistic definitions.json which reproduces the error for me.
I can reproduce is on versions 3.11.4 and 3.11.5. I cannot reproduce it on version 3.10.13.

Once I encountered not only the direct_exchange_routing_v2 feature_flag being disabled, but also the drop_unroutable_metric and empty_basic_get_metric. So the issue seems to not only affect the direct_exchange_routing_v2 feature flag, but it is the feature flag it at least occurs with in ALL reproduction attempts

I use configuration in rabbitmq.conf for peer discovery:
`cluster_formation.peer_discovery_backend = rabbit_peer_discovery_k8s
cluster_formation.k8s.host = ***

cluster_formation.k8s.address_type = hostname
cluster_formation.k8s.service_name = ***
cluster_formation.k8s.hostname_suffix = ***

cluster_formation.node_cleanup.interval = 30
cluster_formation.node_cleanup.only_log_warning = true
cluster_partition_handling = autoheal`

@ansd, we do not use the cluster-operator.
@michaelklishin I do not start the rabbitmq nodes in parallel. They are started sequentially using the kubernetes command
kubectl scale sts <statefulsetname> -n <namespace> --replicas=X
where X is incremented at the point where the node started previously, has completed its startup.
@michaelklishin The work-around presented at https://www.rabbitmq.com/feature-flags.html#how-to-start-new-node-disabled-feature-flags does not prevent the second and third node from crashing. I attempted to solve it by setting the env variable as described on the page. The value of the env variables contained all feature flags visible via the GUI.

config.txt

[dumbbell]

I'm also interested in the RabbitMQ logs from all nodes with the debug log level enabled.

[ansd]

Thank you @ares-the-god-of-war. Is there any chance you could test your clustering setup against the docker image pivotalrabbitmq/rabbitmq:direct-exchange-routing-v2-migration-otp-max-bazel? It contains the potential fix in #6847. That would be super helpful. Thanks again @ares-the-god-of-war!

[ares-the-god-of-war]

@ansd I am willing to test this version for you. However, policy compels me to use official repositories only. What kind of repository is the pivotalrabbitmq? Is this an official Rabbitmq repository? Please let me know so I can make my case to test this.

[ansd]

Thanks @ares-the-god-of-war. Yes, the pivotalrabbitmq org is owned by the RabbitMQ team at VMware (formerly Pivotal). The repo https://hub.docker.com/r/pivotalrabbitmq/rabbitmq contains the official dev images built by GitHub actions via this workflow.
So, these images are provided by our team (but nonetheless they are "dev images", so don't use them in production).

[ansd]

Actually, if you are allowed, try instead with this image:
pivotalrabbitmq/rabbitmq:e26bc39f126af0a8552d9154ec176448933b683a-otp-max-bazel

Same repo but different tag: This image points to the latest 3.11.x branch.

[ares-the-god-of-war]

Dear @ansd,

I received permission to test the provided image and have been able to perform the same upgrade with the new image. 3.11.x branch

Unfortunately, the issue remains. There is a slight change in behaviour. The feature flag direct_exchange_routing_v2 is no longer disabled when node 2 (rabbitmq-1) starts up. (see image).

Like previously, the nodes are started 1 after the other and waiting the previous node to complete its startup before starting the new node. We start with an empty database disk.

Attached you find the complete logs of RabbitMQ node 2 (rabbitmq-1) which still crashes.

logs-after-rabbitmq-fix-6847.txt

[dumbbell]

Unfortunately, the issue remains. There is a slight change in behaviour. The feature flag direct_exchange_routing_v2 is no longer disabled when node 2 (rabbitmq-1) starts up. (see image).

If I understand correctly, the direct_exchange_routing_v2 feature flag remains enabled on node 1, after node 2 fails to start and join the cluster, am I correct?

If you try to restart node 2 again, does it succeed?

[ares-the-god-of-war]

That is correct.
After starting node 1 all feature flags including direct_exchange_routing_v2 are enabled. Then when I start node 2 all feature_flags (including direct_exchange_routing_v2) remain enabled. However, node 2 still crashes. Restarting node 2 has no effect and still makes it crash.

Previously, when testing with 3.11.5, I enabled the direct_exchange_routing_v2 flag when it was disabled. Then node 2 would start properly.

[ansd]

Thank you so much for testing @ares-the-god-of-war!
Would you mind doing one more test with image pivotalrabbitmq/rabbitmq:wait-for-rabbit-exchange-table-name-otp-max-bazel (This has one commit on top of 3.11.x branch). Could you again share the logs in both cases when it fails or when it succeeds?

[ares-the-god-of-war]

@ansd
I just ran the test again, exactly the same way as described previously. The logs are now different, but the result is a crash.

Except for the logging the behaviour of node 2 is the same as with pivotalrabbitmq/rabbitmq:e26bc39f126af0a8552d9154ec176448933b683a-otp-max-bazel

logs-after-rabbitmq-fix-6847-2.txt

[ansd]

Thanks @ares-the-god-of-war. At this point, as asked in #6755 (comment) would it be possible that you could share all relevant Kubernetes YAML files with us so that we can reproduce this issue on our own?

[kevinharing]

We're running rabbitmq-3.11.7 (includes a potential fix #6847) here in Azure Kubernetes Services, and are still running into this issue most of the time.

Application rabbit exited with reason: {{incompatible_feature_flags,{badarg,[{ets,lookup,[rabbit_exchange,{resource,<<"/">>,exchange,<<"celery">>}],[{error_info,#{cause => id,module => erl_stdlib_errors}}]},{rabbit_misc,dirty_read,1,[{file,"rabbit_misc.erl"},{line,372}]},{rabbit_binding,'-populate_index_route_table/0-fun-0-',1,[{file,"rabbit_binding.erl"},{line,757}]},{lists,foreach_1,2,[{file,"lists.erl"},{line,1442}]},{mnesia_tm,apply_fun,3,[{file,"mnesia_tm.erl"},{line,842}]},{mnesia_tm,execute_transaction,5,[{file,"mnesia_tm.erl"},{line,818}]},{rabbit_misc,'-execute_mnesia_transaction/1-fun-0-',1,[{file,"rabbit_misc.erl"},{line,566}]},{worker_pool_worker,'-run/2-fun-0-',3,[{file,"worker_pool_worker.erl"},{line,69}]}]}},{rabbit,start,[normal,[]]}}

[kevinharing]

@ansd We don't use cluster-operator, we deploy via a stateful set manually. The first pod boots fine, the second fails and the third one naturally doesn't appear at all. Details are below, logs attached (note that I already fixed the event writing returning 403s).

I tested 3.11.3 to 3.11.6 and the issue did not appear. Only on 3.11.7 it does not boot up properly (in my experience).

enabled_plugins:
[rabbitmq_consistent_hash_exchange,rabbitmq_management,rabbitmq_peer_discovery_k8s]

rabbitmq.conf:

cluster_formation.peer_discovery_backend = rabbit_peer_discovery_k8s
cluster_formation.k8s.host = kubernetes.default.svc.cluster.local
cluster_formation.k8s.address_type = hostname
cluster_formation.node_cleanup.interval = 10
cluster_formation.node_cleanup.only_log_warning = true
cluster_partition_handling = autoheal
load_definitions = /etc/definitions/definitions.json
vm_memory_high_watermark.relative = 0.6
total_memory_available_override_value = 1024MiB
disk_free_limit.relative = 1.0
consumer_timeout = 7200000

definitions.json:

{
	"users": [
		{
			"name": "admin",
			"password": "xxx",
			"tags": "administrator"
		},
		{
			"name": "management",
			"password": "xxx",
			"tags": "management"
		}
	],
	"vhosts": [
		{
			"name": "/"
		}
	],
	"permissions": [
		{
			"user": "admin",
			"vhost": "/",
			"configure": ".*",
			"read": ".*",
			"write": ".*"
		}
	]
}

statefulset:

kind: StatefulSet
apiVersion: apps/v1
metadata:
  name: rabbitmq-statefulset
  namespace: xxx
  labels:
    app.kubernetes.io/name: rabbitmq
spec:
  replicas: 3
  selector:
    matchLabels:
      app.kubernetes.io/name: rabbitmq
  template:
    metadata:
      labels:
        app.kubernetes.io/name: rabbitmq
    spec:
      volumes:
        - name: rabbitmq-config
          configMap:
            name: rabbitmq-config
            defaultMode: 511
        - name: rabbitmq-secret
          secret:
            secretName: rabbitmq-secret
            items:
              - key: definitions.json
                path: definitions.json
            defaultMode: 420
        - name: rabbitmq-mnesia
          persistentVolumeClaim:
            claimName: rabbitmq-pvc
      containers:
        - name: rabbitmq
          image: rabbitmq:3.11
          ports:
            - name: epmd
              containerPort: 4369
              protocol: TCP
            - name: amqp
              containerPort: 5672
              protocol: TCP
            - name: http
              containerPort: 15672
              protocol: TCP
          env:
            - name: POD_NAME
              valueFrom:
                fieldRef:
                  apiVersion: v1
                  fieldPath: metadata.name
            - name: POD_NAMESPACE
              valueFrom:
                fieldRef:
                  apiVersion: v1
                  fieldPath: metadata.namespace
            - name: K8S_SERVICE_NAME
              value: rabbitmq-service-headless
            - name: K8S_HOSTNAME_SUFFIX
              value: .$(K8S_SERVICE_NAME).$(POD_NAMESPACE).svc.cluster.local
            - name: RABBITMQ_USE_LONGNAME
              value: 'true'
            - name: RABBITMQ_NODE_NAME
              value: rabbit@$(POD_NAME)$(K8S_HOSTNAME_SUFFIX)
            - name: RABBITMQ_MNESIA_BASE
              value: /var/lib/rabbitmq-mnesia
            - name: RABBITMQ_CONFIG_FILE
              value: /etc/rabbitmq-config/rabbitmq
            - name: RABBITMQ_ENABLED_PLUGINS_FILE
              value: /etc/rabbitmq-config/enabled_plugins
            - name: RABBITMQ_ERLANG_COOKIE
              valueFrom:
                secretKeyRef:
                  name: rabbitmq-secret
                  key: rabbitmq-erlang-cookie
          resources:
            limits:
              cpu: '1'
              memory: 1Gi
            requests:
              cpu: 500m
              memory: 128Mi
          volumeMounts:
            - name: rabbitmq-secret
              mountPath: /etc/definitions/definitions.json
              subPath: definitions.json
            - name: rabbitmq-config
              mountPath: /etc/rabbitmq-config
            - name: rabbitmq-mnesia
              mountPath: /var/lib/rabbitmq-mnesia
          livenessProbe:
            exec:
              command:
                - /bin/bash
                - '-ec'
                - rabbitmq-diagnostics -q ping
            timeoutSeconds: 20
            periodSeconds: 30
            successThreshold: 1
            failureThreshold: 6
          readinessProbe:
            exec:
              command:
                - /bin/bash
                - '-ec'
                - >-
                  rabbitmq-diagnostics -q check_running && rabbitmq-diagnostics
                  -q check_local_alarms
            timeoutSeconds: 20
            periodSeconds: 30
            successThreshold: 1
            failureThreshold: 3
          startupProbe:
            exec:
              command:
                - /bin/bash
                - '-ec'
                - >-
                  rabbitmq-diagnostics -q check_running && rabbitmq-diagnostics
                  -q check_local_alarms
            timeoutSeconds: 3
            periodSeconds: 3
            successThreshold: 1
            failureThreshold: 60
          terminationMessagePath: /dev/termination-log
          terminationMessagePolicy: File
          imagePullPolicy: IfNotPresent
          securityContext:
            allowPrivilegeEscalation: false
      restartPolicy: Always
      terminationGracePeriodSeconds: 10
      dnsPolicy: ClusterFirst
      serviceAccountName: rabbitmq-serviceaccount
      serviceAccount: rabbitmq-serviceaccount
      securityContext:
        runAsUser: 100
        runAsGroup: 101
        runAsNonRoot: true
        fsGroup: 101
  serviceName: rabbitmq-service-headless
  podManagementPolicy: OrderedReady
  updateStrategy:
    type: OnDelete
  revisionHistoryLimit: 10

rabbitmq-statefulset-0-log.txt
rabbitmq-statefulset-1-log.txt

[ansd]

Thank you @kevinharing.

Unfortunately, this is just a snippet of YAML files. It contains only the StatefulSet.
I cannot deploy it.

Please share all relevant Kubernetes YAML files including step by step description so that we can reproduce this issue.

I'd like to run a kubectl apply without having to guess how the Service object or ServiceAccount object looks like.

Could you please share a complete (and if possible minimal) example to reproduce this issue?
You could point us to a repository or share the YAML files in this GitHub issue.

[ansd]

The logs suggest that there are clustering issues:
node 'rabbit@rabbitmq-statefulset-1.rabbitmq-service-headless.xxx.svc.cluster.local' down: connection_closed"
is printed 3 times, even before that node boots.
Is that really a brand new RabbitMQ cluster you're deploying?

I suggest using https://github.com/rabbitmq/cluster-operator because it solves clustering and common gotchas in K8s.

[kevinharing]

You should compare the timestamps of the two files. Statefulset-1 already restarted a few times before I exported the log of it.

[kevinharing]

Can confirm version 3.11.8 fixed this issue.

[ares-the-god-of-war]

@ansd im sorry for the unresponsiveness. I had a little vacation. In my mail i saw there might be another fix for this issue.

I will try to find time tomorrow to test again, the following image as linked in
#7068

I will confirm whether or not this is fixed for us as well.

[ares-the-god-of-war]

@michaelklishin @ansd I could not test 3.11.8 as that image does not seem to exist yet. I have run the image provided in #7068 and the RabbitMQ nodes have started properly without any restarts (and therefore without crashing).

Once the image 3.11.8 is available, I will also test that one. For now this pivotalrabbitmq image seems to fix the issue for us as well.
NAME READY STATUS RESTARTS AGE rabbitmq-0 1/1 Running 0 6m16s rabbitmq-1 1/1 Running 0 4m32s rabbitmq-2 1/1 Running 0 3m20s

[ares-the-god-of-war]

@michaelklishin is there any ETA on the availability of the Docker image for 3.11.8?

[lukebakken]

@ares-the-god-of-war Team RabbitMQ does not manage the docker image.

As you can see here the update to 3.11.8 just happened. I don't know how long it takes that update to propagate to the official docker images 🤷‍♂️

[michaelklishin]

https://github.com/docker-library/faq#an-images-source-changed-in-git-now-what

[michaelklishin]

It usually takes some 48 hours in practice for new images to end up on Docker Hub, you can see that 3.10.16 still isn't there some 24 hours later.