search

emqx / emqx-operator

A Kubernetes Operator for EMQX
https://www.emqx.com
Apache License 2.0
212 stars 64 forks source link

EMQX Cluster stuck on `CoreNodesProgressing` #1036

Closed onedr0p closed 7 months ago

onedr0p commented 7 months ago

Describe the bug

I have deployed emqx operator and tried create a EMQX cluster, and if I set the replicas to 3 the EMQX cluster stays in a CoreNodesProgressing state.

❯ k get emqx -A
NAMESPACE   NAME    STATUS                 AGE
database    emqx5   CoreNodesProgressing   50m

To Reproduce

helm values

    fullnameOverride: emqx-operator
    image:
      repository: ghcr.io/emqx/emqx-operator
    development: true

cluster definition

apiVersion: apps.emqx.io/v2beta1
kind: EMQX
metadata:
  name: emqx5
  namespace: database
spec:
  image: public.ecr.aws/emqx/emqx:5.6.0
  config:
    data: |
      log.console.level = debug
  coreTemplate:
    spec:
      replicas: 3
  # FIXME: Also the below doesn't work for whatever reason
  # listenersServiceTemplate:
  #   metadata:
  #     annotations:
  #       io.cilium/lb-ipam-ips: 192.168.42.129
  #   spec:
  #     type: LoadBalancer

operator logs

2024-04-09T18:00:30Z    INFO    controller-runtime.builder  Registering a mutating webhook  {"GVK": "apps.emqx.io/v1beta4, Kind=EmqxPlugin", "path": "/mutate-apps-emqx-io-v1beta4-emqxplugin"}
2024-04-09T18:00:30Z    INFO    controller-runtime.webhook  Registering webhook {"path": "/mutate-apps-emqx-io-v1beta4-emqxplugin"}
2024-04-09T18:00:30Z    INFO    controller-runtime.builder  Registering a validating webhook    {"GVK": "apps.emqx.io/v1beta4, Kind=EmqxPlugin", "path": "/validate-apps-emqx-io-v1beta4-emqxplugin"}
2024-04-09T18:00:30Z    INFO    controller-runtime.webhook  Registering webhook {"path": "/validate-apps-emqx-io-v1beta4-emqxplugin"}
2024-04-09T18:00:30Z    INFO    controller-runtime.webhook  Registering webhook {"path": "/convert"}
2024-04-09T18:00:30Z    INFO    controller-runtime.builder  Conversion webhook enabled  {"GVK": "apps.emqx.io/v1beta4, Kind=EmqxPlugin"}
2024-04-09T18:00:30Z    INFO    controller-runtime.builder  Registering a mutating webhook  {"GVK": "apps.emqx.io/v1beta4, Kind=EmqxBroker", "path": "/mutate-apps-emqx-io-v1beta4-emqxbroker"}
2024-04-09T18:00:30Z    INFO    controller-runtime.webhook  Registering webhook {"path": "/mutate-apps-emqx-io-v1beta4-emqxbroker"}
2024-04-09T18:00:30Z    INFO    controller-runtime.builder  Registering a validating webhook    {"GVK": "apps.emqx.io/v1beta4, Kind=EmqxBroker", "path": "/validate-apps-emqx-io-v1beta4-emqxbroker"}
2024-04-09T18:00:30Z    INFO    controller-runtime.webhook  Registering webhook {"path": "/validate-apps-emqx-io-v1beta4-emqxbroker"}
2024-04-09T18:00:30Z    INFO    controller-runtime.builder  Conversion webhook enabled  {"GVK": "apps.emqx.io/v1beta4, Kind=EmqxBroker"}
2024-04-09T18:00:30Z    INFO    controller-runtime.builder  Registering a mutating webhook  {"GVK": "apps.emqx.io/v1beta4, Kind=EmqxEnterprise", "path": "/mutate-apps-emqx-io-v1beta4-emqxenterprise"}
2024-04-09T18:00:30Z    INFO    controller-runtime.webhook  Registering webhook {"path": "/mutate-apps-emqx-io-v1beta4-emqxenterprise"}
2024-04-09T18:00:30Z    INFO    controller-runtime.builder  Registering a validating webhook    {"GVK": "apps.emqx.io/v1beta4, Kind=EmqxEnterprise", "path": "/validate-apps-emqx-io-v1beta4-emqxenterprise"}
2024-04-09T18:00:30Z    INFO    controller-runtime.webhook  Registering webhook {"path": "/validate-apps-emqx-io-v1beta4-emqxenterprise"}
2024-04-09T18:00:30Z    INFO    controller-runtime.builder  Conversion webhook enabled  {"GVK": "apps.emqx.io/v1beta4, Kind=EmqxEnterprise"}
2024-04-09T18:00:30Z    INFO    controller-runtime.builder  skip registering a mutating webhook, object does not implement admission.Defaulter or WithDefaulter wasn't called   {"GVK": "apps.emqx.io/v2beta1, Kind=Rebalance"}
2024-04-09T18:00:30Z    INFO    controller-runtime.builder  Registering a validating webhook    {"GVK": "apps.emqx.io/v2beta1, Kind=Rebalance", "path": "/validate-apps-emqx-io-v2beta1-rebalance"}
2024-04-09T18:00:30Z    INFO    controller-runtime.webhook  Registering webhook {"path": "/validate-apps-emqx-io-v2beta1-rebalance"}
2024-04-09T18:00:30Z    INFO    controller-runtime.builder  Conversion webhook enabled  {"GVK": "apps.emqx.io/v2beta1, Kind=Rebalance"}
2024-04-09T18:00:30Z    INFO    setup   starting manager
2024-04-09T18:00:30Z    INFO    starting server {"kind": "health probe", "addr": "[::]:8081"}
2024-04-09T18:00:30Z    INFO    controller-runtime.metrics  Starting metrics server
2024-04-09T18:00:30Z    INFO    controller-runtime.webhook  Starting webhook server
2024-04-09T18:00:30Z    INFO    controller-runtime.metrics  Serving metrics server  {"bindAddress": ":8080", "secure": false}
I0409 18:00:30.529284       1 leaderelection.go:250] attempting to acquire leader lease database/19fd6fcc.emqx.io...
2024-04-09T18:00:30Z    INFO    controller-runtime.certwatcher  Updated current TLS certificate
2024-04-09T18:00:30Z    INFO    controller-runtime.webhook  Serving webhook server  {"host": "", "port": 9443}
2024-04-09T18:00:30Z    INFO    controller-runtime.certwatcher  Starting certificate watcher
I0409 18:01:10.585794       1 leaderelection.go:260] successfully acquired lease database/19fd6fcc.emqx.io
2024-04-09T18:01:10Z    DEBUG   events  emqx-operator-controller-manager-df7dcc4dc-ww4dg_c97157c6-372c-4aba-a1ad-7014e583c8e8 became leader {"type": "Normal", "object": {"kind":"Lease","namespace":"database","name":"19fd6fcc.emqx.io","uid":"4489c0e9-d609-4907-962f-5a4e3202a963","apiVersion":"coordination.k8s.io/v1","resourceVersion":"52014238"}, "reason": "LeaderElection"}
2024-04-09T18:01:10Z    INFO    Starting EventSource    {"controller": "emqxbroker", "controllerGroup": "apps.emqx.io", "controllerKind": "EmqxBroker", "source": "kind source: *v1beta4.EmqxBroker"}
2024-04-09T18:01:10Z    INFO    Starting EventSource    {"controller": "emqxplugin", "controllerGroup": "apps.emqx.io", "controllerKind": "EmqxPlugin", "source": "kind source: *v1beta4.EmqxPlugin"}
2024-04-09T18:01:10Z    INFO    Starting Controller {"controller": "emqxplugin", "controllerGroup": "apps.emqx.io", "controllerKind": "EmqxPlugin"}
2024-04-09T18:01:10Z    INFO    Starting Controller {"controller": "emqxbroker", "controllerGroup": "apps.emqx.io", "controllerKind": "EmqxBroker"}
2024-04-09T18:01:10Z    INFO    Starting EventSource    {"controller": "emqxenterprise", "controllerGroup": "apps.emqx.io", "controllerKind": "EmqxEnterprise", "source": "kind source: *v1beta4.EmqxEnterprise"}
2024-04-09T18:01:10Z    INFO    Starting Controller {"controller": "emqxenterprise", "controllerGroup": "apps.emqx.io", "controllerKind": "EmqxEnterprise"}
2024-04-09T18:01:10Z    INFO    Starting EventSource    {"controller": "rebalance", "controllerGroup": "apps.emqx.io", "controllerKind": "Rebalance", "source": "kind source: *v2beta1.Rebalance"}
2024-04-09T18:01:10Z    INFO    Starting Controller {"controller": "rebalance", "controllerGroup": "apps.emqx.io", "controllerKind": "Rebalance"}
2024-04-09T18:01:10Z    INFO    Starting EventSource    {"controller": "emqx", "controllerGroup": "apps.emqx.io", "controllerKind": "EMQX", "source": "kind source: *v2beta1.EMQX"}
2024-04-09T18:01:10Z    INFO    Starting Controller {"controller": "emqx", "controllerGroup": "apps.emqx.io", "controllerKind": "EMQX"}
2024-04-09T18:01:10Z    INFO    Starting workers    {"controller": "emqxenterprise", "controllerGroup": "apps.emqx.io", "controllerKind": "EmqxEnterprise", "worker count": 1}
2024-04-09T18:01:10Z    INFO    Starting workers    {"controller": "emqxbroker", "controllerGroup": "apps.emqx.io", "controllerKind": "EmqxBroker", "worker count": 1}
2024-04-09T18:01:10Z    INFO    Starting workers    {"controller": "emqxplugin", "controllerGroup": "apps.emqx.io", "controllerKind": "EmqxPlugin", "worker count": 1}
2024-04-09T18:01:10Z    INFO    Starting workers    {"controller": "emqx", "controllerGroup": "apps.emqx.io", "controllerKind": "EMQX", "worker count": 1}
2024-04-09T18:01:10Z    INFO    Starting workers    {"controller": "rebalance", "controllerGroup": "apps.emqx.io", "controllerKind": "Rebalance", "worker count": 1}
2024-04-09T18:01:23Z    INFO    got different pod template for EMQX core nodes, will create new statefulSet {"controller": "emqx", "controllerGroup": "apps.emqx.io", "controllerKind": "EMQX", "EMQX": {"name":"emqx5","namespace":"database"}, "namespace": "database", "name": "emqx5", "reconcileID": "ede3c87a-9937-424c-9ffb-bc67f5797dac", "statefulSet": {"name":"emqx5-core-6796d44f","namespace":"database"}, "patch": "{should create new StatefulSet}"}
2024-04-09T18:01:23Z    INFO    KubeAPIWarningLogger    unknown field "spec.coreTemplate.metadata.creationTimestamp"

a replica logs

EMQX_API_KEY__BOOTSTRAP_FILE [api_key.bootstrap_file]: /opt/emqx/data/bootstrap_api_key
EMQX_DASHBOARD__LISTENERS__HTTP__BIND [dashboard.listeners.http.bind]: 18083
EMQX_RPC__PORT_DISCOVERY [rpc.port_discovery]: manual
EMQX_CLUSTER__DNS__RECORD_TYPE [cluster.dns.record_type]: srv
EMQX_CLUSTER__DNS__NAME [cluster.dns.name]: emqx5-headless.database.svc.cluster.local
EMQX_CLUSTER__DISCOVERY_STRATEGY [cluster.discovery_strategy]: dns
EMQX_NODE__ROLE [node.role]: core
EMQX_NODE__DATA_DIR [node.data_dir]: data
EMQX_NODE__COOKIE [node.cookie]: ******
EMQX_NODE__NAME [node.name]: emqx@emqx5-core-6796d44f-1.emqx5-headless.database.svc.cluster.local
2024-04-09T18:01:28.385208+00:00 [info] event=server_setup_successfully driver=tcp port=5369 socket="#Port<0.7>"
2024-04-09T18:01:28.385415+00:00 [info] msg: gen_rpc_dispatcher_start
2024-04-09T18:01:28.386486+00:00 [notice] msg: Starting mria
2024-04-09T18:01:28.386932+00:00 [notice] msg: Starting mnesia
2024-04-09T18:01:28.387048+00:00 [debug] msg: Ensure mnesia schema
2024-04-09T18:01:28.392071+00:00 [notice] msg: Creating new mnesia schema, result: ok
2024-04-09T18:01:28.401294+00:00 [notice] msg: Starting shards
2024-04-09T18:01:28.401471+00:00 [debug] msg: rlog_schema_init
2024-04-09T18:01:28.406159+00:00 [info] msg: Setting RLOG shard config, shard: '$mria_meta_shard', tables: ['$mria_rlog_sync',mria_schema]
2024-04-09T18:01:28.406322+00:00 [info] msg: Converging schema
2024-04-09T18:01:28.406539+00:00 [info] msg: Setting RLOG shard config, shard: '$mria_meta_shard', tables: ['$mria_rlog_sync',mria_schema]
2024-04-09T18:01:28.406839+00:00 [info] msg: starting_rlog_shard, shard: '$mria_meta_shard'
2024-04-09T18:01:28.407120+00:00 [info] msg: Starting ekka
2024-04-09T18:01:28.407285+00:00 [info] msg: Shard fully up, node: 'emqx@emqx5-core-6796d44f-1.emqx5-headless.database.svc.cluster.local', shard: '$mria_meta_shard'
2024-04-09T18:01:28.407364+00:00 [notice] msg: Mria is running
2024-04-09T18:01:28.407439+00:00 [info] msg: Starting ekka
2024-04-09T18:01:28.407648+00:00 [info] msg: Ekka is running
2024-04-09T18:01:28.407692+00:00 [info] msg: Ekka is running
2024-04-09T18:01:28.407771+00:00 [notice] msg: (re)starting_emqx_apps
2024-04-09T18:01:28.408972+00:00 [debug] msg: starting_app, app: emqx_conf
2024-04-09T18:01:28.409107+00:00 [debug] msg: mria_mnesia_create_table, name: cluster_rpc_mfa, options: [{type,ordered_set},{rlog_shard,emqx_cluster_rpc_shard},{storage,disc_copies},{record_name,cluster_rpc_mfa},{attributes,[tnx_id,mfa,created_at,initiator]}]
2024-04-09T18:01:28.411630+00:00 [info] msg: Adding table to a shard, shard: emqx_cluster_rpc_shard, table: cluster_rpc_mfa
2024-04-09T18:01:28.411767+00:00 [debug] msg: ensure_local_table, '$span': start, table: cluster_rpc_mfa
2024-04-09T18:01:28.411828+00:00 [info] msg: Setting RLOG shard config, shard: emqx_cluster_rpc_shard, tables: [cluster_rpc_mfa]
2024-04-09T18:01:28.411951+00:00 [debug] msg: ensure_local_table, '$span': {complete,true}, table: cluster_rpc_mfa
2024-04-09T18:01:28.412031+00:00 [debug] msg: mria_mnesia_create_table, name: cluster_rpc_commit, options: [{type,set},{rlog_shard,emqx_cluster_rpc_shard},{storage,disc_copies},{record_name,cluster_rpc_commit},{attributes,[node,tnx_id]}]
2024-04-09T18:01:28.414256+00:00 [info] msg: Adding table to a shard, shard: emqx_cluster_rpc_shard, table: cluster_rpc_commit
2024-04-09T18:01:28.414388+00:00 [debug] msg: ensure_local_table, '$span': start, table: cluster_rpc_commit
2024-04-09T18:01:28.414536+00:00 [info] msg: Setting RLOG shard config, shard: emqx_cluster_rpc_shard, tables: [cluster_rpc_commit,cluster_rpc_mfa]
2024-04-09T18:01:28.414664+00:00 [debug] msg: ensure_local_table, '$span': {complete,true}, table: cluster_rpc_commit
2024-04-09T18:01:28.414790+00:00 [info] msg: starting_rlog_shard, shard: emqx_cluster_rpc_shard
2024-04-09T18:01:28.415064+00:00 [info] msg: Shard fully up, node: 'emqx@emqx5-core-6796d44f-1.emqx5-headless.database.svc.cluster.local', shard: emqx_cluster_rpc_shard
2024-04-09T18:01:28.415512+00:00 [info] msg: wait_for_cluster_rpc_shard, result: ok
2024-04-09T18:01:28.415624+00:00 [info] msg: wait_for_cluster_rpc_tables, result: ok
2024-04-09T18:01:28.416279+00:00 [info] msg: skip_sync_cluster_conf, reason: This is a single node, or the first node in the cluster
2024-04-09T18:01:28.445587+00:00 [debug] msg: started_apps, apps: [emqx_conf]
2024-04-09T18:01:28.445739+00:00 [debug] msg: starting_app, app: esockd
2024-04-09T18:01:28.446120+00:00 [debug] msg: started_apps, apps: [esockd]
2024-04-09T18:01:28.446213+00:00 [debug] msg: starting_app, app: gproc
2024-04-09T18:01:28.446533+00:00 [debug] msg: started_apps, apps: [gproc]
2024-04-09T18:01:28.446586+00:00 [debug] msg: starting_app, app: emqx_http_lib
2024-04-09T18:01:28.446756+00:00 [debug] msg: started_apps, apps: [emqx_http_lib]
2024-04-09T18:01:28.446797+00:00 [debug] msg: starting_app, app: bcrypt
2024-04-09T18:01:28.447216+00:00 [debug] msg: started_apps, apps: [bcrypt]
2024-04-09T18:01:28.447258+00:00 [debug] msg: starting_app, app: ranch
2024-04-09T18:01:28.447474+00:00 [debug] msg: started_apps, apps: [ranch]
2024-04-09T18:01:28.447517+00:00 [debug] msg: starting_app, app: cowboy
2024-04-09T18:01:28.447716+00:00 [debug] msg: started_apps, apps: [cowboy]
2024-04-09T18:01:28.447766+00:00 [debug] msg: starting_app, app: esasl
2024-04-09T18:01:28.447904+00:00 [debug] msg: started_apps, apps: [pbkdf2,esasl]
2024-04-09T18:01:28.447940+00:00 [debug] msg: starting_app, app: emqx_utils
2024-04-09T18:01:28.448126+00:00 [debug] msg: started_apps, apps: [jiffy,emqx_utils]
2024-04-09T18:01:28.448185+00:00 [debug] msg: starting_app, app: emqx_durable_storage
2024-04-09T18:01:28.448370+00:00 [debug] msg: started_apps, apps: [emqx_durable_storage]
2024-04-09T18:01:28.448419+00:00 [debug] msg: starting_app, app: emqx
2024-04-09T18:01:28.449105+00:00 [notice] alarm_handler: {clear,lc_mem_alarm}
2024-04-09T18:01:28.450241+00:00 [debug] msg: skip_init_config_load, loader: emqx_conf, reason: Some application has set another config loader
2024-04-09T18:01:28.450465+00:00 [debug] msg: mria_mnesia_create_table, name: bpapi, options: [{type,set},{storage,ram_copies},{attributes,[key,version]},{rlog_shard,emqx_common_shard}]
2024-04-09T18:01:28.451396+00:00 [notice] alarm_handler: {clear,lc_runq_alarm}
2024-04-09T18:01:28.454812+00:00 [info] msg: Adding table to a shard, shard: emqx_common_shard, table: bpapi
2024-04-09T18:01:28.454967+00:00 [debug] msg: ensure_local_table, '$span': start, table: bpapi
2024-04-09T18:01:28.455087+00:00 [info] msg: Setting RLOG shard config, shard: emqx_common_shard, tables: [bpapi]
2024-04-09T18:01:28.455824+00:00 [debug] msg: ensure_local_table, '$span': {complete,true}, table: bpapi
2024-04-09T18:01:28.455968+00:00 [info] msg: starting_rlog_shard, shard: emqx_common_shard
2024-04-09T18:01:28.456239+00:00 [info] msg: Shard fully up, node: 'emqx@emqx5-core-6796d44f-1.emqx5-headless.database.svc.cluster.local', shard: emqx_common_shard
2024-04-09T18:01:28.464698+00:00 [debug] msg: mria_mnesia_create_table, name: emqx_trie, options: [{rlog_shard,route_shard},{record_name,emqx_trie},{attributes,[key,count]},{type,ordered_set},{storage_properties,[{ets,[{read_concurrency,true},{write_concurrency,true}]}]}]
2024-04-09T18:01:28.467132+00:00 [info] msg: Adding table to a shard, shard: route_shard, table: emqx_trie
2024-04-09T18:01:28.467326+00:00 [debug] msg: ensure_local_table, '$span': start, table: emqx_trie
2024-04-09T18:01:28.467481+00:00 [info] msg: Setting RLOG shard config, shard: route_shard, tables: [emqx_trie]
2024-04-09T18:01:28.467765+00:00 [debug] msg: ensure_local_table, '$span': {complete,true}, table: emqx_trie
2024-04-09T18:01:28.467864+00:00 [debug] msg: mria_mnesia_create_table, name: emqx_route, options: [{type,bag},{rlog_shard,route_shard},{storage,ram_copies},{record_name,route},{attributes,[topic,dest]},{storage_properties,[{ets,[{read_concurrency,true},{write_concurrency,true}]}]}]
2024-04-09T18:01:28.470379+00:00 [info] msg: Adding table to a shard, shard: route_shard, table: emqx_route
2024-04-09T18:01:28.470515+00:00 [debug] msg: ensure_local_table, '$span': start, table: emqx_route
2024-04-09T18:01:28.470649+00:00 [info] msg: Setting RLOG shard config, shard: route_shard, tables: [emqx_route,emqx_trie]
2024-04-09T18:01:28.470786+00:00 [debug] msg: ensure_local_table, '$span': {complete,true}, table: emqx_route
2024-04-09T18:01:28.470852+00:00 [debug] msg: mria_mnesia_create_table, name: emqx_route_filters, options: [{type,ordered_set},{rlog_shard,route_shard},{storage,ram_copies},{record_name,routeidx},{attributes,[entry,unused]},{storage_properties,[{ets,[{read_concurrency,true},{write_concurrency,true},{decentralized_counters,true}]}]}]
2024-04-09T18:01:28.473096+00:00 [info] msg: Adding table to a shard, shard: route_shard, table: emqx_route_filters
2024-04-09T18:01:28.473243+00:00 [debug] msg: ensure_local_table, '$span': start, table: emqx_route_filters
2024-04-09T18:01:28.473303+00:00 [info] msg: Setting RLOG shard config, shard: route_shard, tables: [emqx_route,emqx_route_filters,emqx_trie]
2024-04-09T18:01:28.474328+00:00 [debug] msg: ensure_local_table, '$span': {complete,true}, table: emqx_route_filters
2024-04-09T18:01:28.474482+00:00 [debug] msg: mria_mnesia_create_table, name: emqx_routing_node, options: [{type,set},{rlog_shard,route_shard},{storage,ram_copies},{record_name,routing_node},{attributes,[name,const]},{storage_properties,[{ets,[{read_concurrency,true}]}]}]
2024-04-09T18:01:28.476560+00:00 [info] msg: Adding table to a shard, shard: route_shard, table: emqx_routing_node
2024-04-09T18:01:28.476710+00:00 [debug] msg: ensure_local_table, '$span': start, table: emqx_routing_node
2024-04-09T18:01:28.476804+00:00 [info] msg: Setting RLOG shard config, shard: route_shard, tables: [emqx_route,emqx_route_filters,emqx_routing_node,emqx_trie]
2024-04-09T18:01:28.478025+00:00 [debug] msg: ensure_local_table, '$span': {complete,true}, table: emqx_routing_node
2024-04-09T18:01:28.479148+00:00 [info] msg: starting_rlog_shard, shard: route_shard
2024-04-09T18:01:28.479471+00:00 [info] msg: Shard fully up, node: 'emqx@emqx5-core-6796d44f-1.emqx5-headless.database.svc.cluster.local', shard: route_shard
2024-04-09T18:01:28.480154+00:00 [info] msg: routing_schema_used, schema: v2
2024-04-09T18:01:28.481017+00:00 [debug] msg: mria_mnesia_create_table, name: emqx_shared_subscription, options: [{type,bag},{rlog_shard,emqx_shared_sub_shard},{storage,ram_copies},{record_name,emqx_shared_subscription},{attributes,[group,topic,subpid]}]
2024-04-09T18:01:28.483394+00:00 [info] msg: Adding table to a shard, shard: emqx_shared_sub_shard, table: emqx_shared_subscription
2024-04-09T18:01:28.483568+00:00 [debug] msg: ensure_local_table, '$span': start, table: emqx_shared_subscription
2024-04-09T18:01:28.483641+00:00 [info] msg: Setting RLOG shard config, shard: emqx_shared_sub_shard, tables: [emqx_shared_subscription]
2024-04-09T18:01:28.483761+00:00 [debug] msg: ensure_local_table, '$span': {complete,true}, table: emqx_shared_subscription
2024-04-09T18:01:28.483844+00:00 [debug] msg: mria_mnesia_create_table, name: emqx_exclusive_subscription, options: [{rlog_shard,emqx_exclusive_shard},{type,set},{storage,ram_copies},{record_name,exclusive_subscription},{attributes,[topic,clientid]},{storage_properties,[{ets,[{read_concurrency,true},{write_concurrency,true}]}]}]
2024-04-09T18:01:28.486496+00:00 [info] msg: Adding table to a shard, shard: emqx_exclusive_shard, table: emqx_exclusive_subscription
2024-04-09T18:01:28.486625+00:00 [debug] msg: ensure_local_table, '$span': start, table: emqx_exclusive_subscription
2024-04-09T18:01:28.486752+00:00 [info] msg: Setting RLOG shard config, shard: emqx_exclusive_shard, tables: [emqx_exclusive_subscription]
2024-04-09T18:01:28.486876+00:00 [debug] msg: ensure_local_table, '$span': {complete,true}, table: emqx_exclusive_subscription
2024-04-09T18:01:28.487002+00:00 [info] msg: starting_rlog_shard, shard: emqx_exclusive_shard
2024-04-09T18:01:28.487115+00:00 [info] msg: starting_rlog_shard, shard: emqx_shared_sub_shard
2024-04-09T18:01:28.487236+00:00 [info] msg: Shard fully up, node: 'emqx@emqx5-core-6796d44f-1.emqx5-headless.database.svc.cluster.local', shard: emqx_exclusive_shard
2024-04-09T18:01:28.487334+00:00 [info] msg: Shard fully up, node: 'emqx@emqx5-core-6796d44f-1.emqx5-headless.database.svc.cluster.local', shard: emqx_shared_sub_shard
2024-04-09T18:01:28.489009+00:00 [debug] msg: mria_mnesia_create_table, name: emqx_banned, options: [{type,set},{rlog_shard,emqx_common_shard},{storage,disc_copies},{record_name,banned},{attributes,[who,by,reason,at,until]},{storage_properties,[{ets,[{read_concurrency,true}]}]}]
2024-04-09T18:01:28.491955+00:00 [info] msg: Adding table to a shard, shard: emqx_common_shard, table: emqx_banned
2024-04-09T18:01:28.492120+00:00 [debug] msg: ensure_local_table, '$span': start, table: emqx_banned
2024-04-09T18:01:28.492234+00:00 [info] msg: Setting RLOG shard config, shard: emqx_common_shard, tables: [bpapi,emqx_banned]
2024-04-09T18:01:28.492399+00:00 [notice] msg: Shard schema change, new_table: emqx_banned, shard: emqx_common_shard
2024-04-09T18:01:28.492390+00:00 [debug] msg: ensure_local_table, '$span': {complete,true}, table: emqx_banned
2024-04-09T18:01:28.492473+00:00 [debug] msg: mria_mnesia_create_table, name: emqx_banned_rules, options: [{type,set},{rlog_shard,emqx_common_shard},{storage,disc_copies},{record_name,banned},{attributes,[who,by,reason,at,until]},{storage_properties,[{ets,[{read_concurrency,true}]}]}]
2024-04-09T18:01:28.497377+00:00 [info] msg: Adding table to a shard, shard: emqx_common_shard, table: emqx_banned_rules
2024-04-09T18:01:28.497509+00:00 [debug] msg: ensure_local_table, '$span': start, table: emqx_banned_rules
2024-04-09T18:01:28.497620+00:00 [info] msg: Setting RLOG shard config, shard: emqx_common_shard, tables: [bpapi,emqx_banned,emqx_banned_rules]
2024-04-09T18:01:28.497750+00:00 [debug] msg: ensure_local_table, '$span': {complete,true}, table: emqx_banned_rules
2024-04-09T18:01:28.497759+00:00 [notice] msg: Shard schema change, new_table: emqx_banned_rules, shard: emqx_common_shard
2024-04-09T18:01:28.498762+00:00 [debug] msg: mria_mnesia_create_table, name: emqx_channel_registry, options: [{type,bag},{rlog_shard,emqx_cm_shard},{storage,ram_copies},{record_name,channel},{attributes,[chid,pid]},{storage_properties,[{ets,[{read_concurrency,true},{write_concurrency,true}]}]}]
2024-04-09T18:01:28.501155+00:00 [info] msg: Adding table to a shard, shard: emqx_cm_shard, table: emqx_channel_registry
2024-04-09T18:01:28.501310+00:00 [debug] msg: ensure_local_table, '$span': start, table: emqx_channel_registry
2024-04-09T18:01:28.501441+00:00 [info] msg: Setting RLOG shard config, shard: emqx_cm_shard, tables: [emqx_channel_registry]
2024-04-09T18:01:28.501679+00:00 [debug] msg: ensure_local_table, '$span': {complete,true}, table: emqx_channel_registry
2024-04-09T18:01:28.501775+00:00 [info] msg: starting_rlog_shard, shard: emqx_cm_shard
2024-04-09T18:01:28.501999+00:00 [info] msg: Shard fully up, node: 'emqx@emqx5-core-6796d44f-1.emqx5-headless.database.svc.cluster.local', shard: emqx_cm_shard
2024-04-09T18:01:28.502101+00:00 [debug] msg: mria_mnesia_create_table, name: emqx_activated_alarm, options: [{type,ordered_set},{storage,disc_copies},{local_content,true},{record_name,activated_alarm},{attributes,[name,details,message,activate_at]}]
2024-04-09T18:01:28.504565+00:00 [info] msg: Adding table to a shard, shard: undefined, table: emqx_activated_alarm
2024-04-09T18:01:28.504704+00:00 [debug] msg: ensure_local_table, '$span': start, table: emqx_activated_alarm
2024-04-09T18:01:28.504799+00:00 [info] msg: Setting RLOG shard config, shard: undefined, tables: [emqx_activated_alarm]
2024-04-09T18:01:28.504902+00:00 [debug] msg: ensure_local_table, '$span': {complete,true}, table: emqx_activated_alarm
2024-04-09T18:01:28.504993+00:00 [debug] msg: mria_mnesia_create_table, name: emqx_deactivated_alarm, options: [{type,ordered_set},{storage,disc_copies},{local_content,true},{record_name,deactivated_alarm},{attributes,[activate_at,name,details,message,deactivate_at]}]
2024-04-09T18:01:28.507646+00:00 [info] msg: Adding table to a shard, shard: undefined, table: emqx_deactivated_alarm
2024-04-09T18:01:28.507853+00:00 [debug] msg: ensure_local_table, '$span': start, table: emqx_deactivated_alarm
2024-04-09T18:01:28.508195+00:00 [info] msg: Setting RLOG shard config, shard: undefined, tables: [emqx_activated_alarm,emqx_deactivated_alarm]
2024-04-09T18:01:28.508405+00:00 [debug] msg: ensure_local_table, '$span': {complete,true}, table: emqx_deactivated_alarm
Listener ssl:default on :8883 started.
Listener tcp:default on :1883 started.
Listener ws:default on :8083 started.
Listener wss:default on :8084 started.
2024-04-09T18:01:28.518174+00:00 [debug] msg: started_apps, apps: [os_mon,hocon,lc,emqx]
2024-04-09T18:01:28.518270+00:00 [debug] msg: starting_app, app: emqx_retainer
2024-04-09T18:01:28.518779+00:00 [debug] msg: mria_mnesia_create_table, name: emqx_retainer_index_meta, options: [{type,set},{rlog_shard,emqx_retainer_shard},{storage,ram_copies},{record_name,retained_index_meta},{attributes,[key,read_indices,write_indices,reindexing,extra]},{storage_properties,[{ets,[compressed,{read_concurrency,true},{write_concurrency,true}]},{dets,[{auto_save,1000}]}]}]
2024-04-09T18:01:28.521119+00:00 [info] msg: Adding table to a shard, shard: emqx_retainer_shard, table: emqx_retainer_index_meta
2024-04-09T18:01:28.521234+00:00 [debug] msg: ensure_local_table, '$span': start, table: emqx_retainer_index_meta
2024-04-09T18:01:28.521320+00:00 [info] msg: Setting RLOG shard config, shard: emqx_retainer_shard, tables: [emqx_retainer_index_meta]
2024-04-09T18:01:28.521421+00:00 [debug] msg: ensure_local_table, '$span': {complete,true}, table: emqx_retainer_index_meta
2024-04-09T18:01:28.521539+00:00 [info] msg: starting_rlog_shard, shard: emqx_retainer_shard
2024-04-09T18:01:28.521935+00:00 [info] msg: Shard fully up, node: 'emqx@emqx5-core-6796d44f-1.emqx5-headless.database.svc.cluster.local', shard: emqx_retainer_shard
2024-04-09T18:01:28.522050+00:00 [debug] msg: mria_mnesia_create_table, name: emqx_retainer_message, options: [{type,ordered_set},{rlog_shard,emqx_retainer_shard},{storage,ram_copies},{record_name,retained_message},{attributes,[topic,msg,expiry_time]},{storage_properties,[{ets,[compressed,{read_concurrency,true},{write_concurrency,true}]},{dets,[{auto_save,1000}]}]}]
2024-04-09T18:01:28.524416+00:00 [info] msg: Adding table to a shard, shard: emqx_retainer_shard, table: emqx_retainer_message
2024-04-09T18:01:28.524592+00:00 [debug] msg: ensure_local_table, '$span': start, table: emqx_retainer_message
2024-04-09T18:01:28.524695+00:00 [info] msg: Setting RLOG shard config, shard: emqx_retainer_shard, tables: [emqx_retainer_index_meta,emqx_retainer_message]
2024-04-09T18:01:28.524830+00:00 [notice] msg: Shard schema change, new_table: emqx_retainer_message, shard: emqx_retainer_shard
2024-04-09T18:01:28.524830+00:00 [debug] msg: ensure_local_table, '$span': {complete,true}, table: emqx_retainer_message
2024-04-09T18:01:28.524955+00:00 [debug] msg: mria_mnesia_create_table, name: emqx_retainer_index, options: [{type,ordered_set},{rlog_shard,emqx_retainer_shard},{storage,ram_copies},{record_name,retained_index},{attributes,[key,expiry_time]},{storage_properties,[{ets,[compressed,{read_concurrency,true},{write_concurrency,true}]},{dets,[{auto_save,1000}]}]}]
2024-04-09T18:01:28.531577+00:00 [info] msg: Adding table to a shard, shard: emqx_retainer_shard, table: emqx_retainer_index
2024-04-09T18:01:28.531753+00:00 [debug] msg: ensure_local_table, '$span': start, table: emqx_retainer_index
2024-04-09T18:01:28.531915+00:00 [info] msg: Setting RLOG shard config, shard: emqx_retainer_shard, tables: [emqx_retainer_index,emqx_retainer_index_meta,emqx_retainer_message]
2024-04-09T18:01:28.532049+00:00 [debug] msg: ensure_local_table, '$span': {complete,true}, table: emqx_retainer_index
2024-04-09T18:01:28.532056+00:00 [notice] msg: Shard schema change, new_table: emqx_retainer_index, shard: emqx_retainer_shard
2024-04-09T18:01:28.532872+00:00 [debug] msg: started_apps, apps: [emqx_retainer]
2024-04-09T18:01:28.532947+00:00 [debug] msg: starting_app, app: emqx_modules
2024-04-09T18:01:28.533116+00:00 [debug] msg: mria_mnesia_create_table, name: emqx_delayed, options: [{type,ordered_set},{storage,disc_copies},{local_content,true},{record_name,delayed_message},{attributes,[key,delayed,msg]}]
2024-04-09T18:01:28.535676+00:00 [info] msg: Adding table to a shard, shard: undefined, table: emqx_delayed
2024-04-09T18:01:28.535807+00:00 [debug] msg: ensure_local_table, '$span': start, table: emqx_delayed
2024-04-09T18:01:28.536031+00:00 [info] msg: Setting RLOG shard config, shard: undefined, tables: [emqx_activated_alarm,emqx_deactivated_alarm,emqx_delayed]
2024-04-09T18:01:28.536648+00:00 [debug] msg: ensure_local_table, '$span': {complete,true}, table: emqx_delayed
2024-04-09T18:01:28.537332+00:00 [debug] msg: emqx_topic_metrics_started
2024-04-09T18:01:28.537545+00:00 [debug] msg: mria_mnesia_create_table, name: emqx_trace, options: [{type,set},{rlog_shard,emqx_common_shard},{storage,disc_copies},{record_name,emqx_trace},{attributes,[name,type,filter,enable,payload_encode,extra,start_at,end_at]}]
2024-04-09T18:01:28.540344+00:00 [info] msg: Adding table to a shard, shard: emqx_common_shard, table: emqx_trace
2024-04-09T18:01:28.540557+00:00 [debug] msg: ensure_local_table, '$span': start, table: emqx_trace
2024-04-09T18:01:28.540688+00:00 [info] msg: Setting RLOG shard config, shard: emqx_common_shard, tables: [bpapi,emqx_banned,emqx_banned_rules,emqx_trace]
2024-04-09T18:01:28.541188+00:00 [debug] msg: ensure_local_table, '$span': {complete,true}, table: emqx_trace
2024-04-09T18:01:28.541222+00:00 [notice] msg: Shard schema change, new_table: emqx_trace, shard: emqx_common_shard
2024-04-09T18:01:28.543222+00:00 [debug] msg: started_apps, apps: [emqx_modules]
2024-04-09T18:01:28.543334+00:00 [debug] msg: starting_app, app: emqx_plugins
2024-04-09T18:01:28.543878+00:00 [debug] msg: started_apps, apps: [emqx_plugins]
2024-04-09T18:01:28.543934+00:00 [debug] msg: starting_app, app: emqx_slow_subs
2024-04-09T18:01:28.544403+00:00 [debug] msg: started_apps, apps: [emqx_slow_subs]
2024-04-09T18:01:28.544441+00:00 [debug] msg: starting_app, app: emqx_resource
2024-04-09T18:01:28.545386+00:00 [debug] msg: started_apps, apps: [jsx,ecpool,emqx_resource]
2024-04-09T18:01:28.545436+00:00 [debug] msg: starting_app, app: emqx_bridge_mqtt
2024-04-09T18:01:28.545620+00:00 [debug] msg: started_apps, apps: [emqtt,emqx_bridge_mqtt]
2024-04-09T18:01:28.545707+00:00 [debug] msg: starting_app, app: emqx_postgresql
2024-04-09T18:01:28.545850+00:00 [debug] msg: started_apps, apps: [emqx_postgresql]
2024-04-09T18:01:28.545934+00:00 [debug] msg: starting_app, app: emqx_bridge_http
2024-04-09T18:01:28.546357+00:00 [debug] msg: started_apps, apps: [ehttpc,emqx_bridge_http]
2024-04-09T18:01:28.546425+00:00 [debug] msg: starting_app, app: emqx_management
2024-04-09T18:01:28.546582+00:00 [info] msg: wait_for_cluster_rpc_shard, result: ok
2024-04-09T18:01:28.546686+00:00 [info] msg: wait_for_cluster_rpc_tables, result: ok
2024-04-09T18:01:28.546825+00:00 [notice] msg: new_node_first_catch_up_and_start_commit., node: 'emqx@emqx5-core-6796d44f-1.emqx5-headless.database.svc.cluster.local', tnx_id: 0
2024-04-09T18:01:28.546919+00:00 [debug] msg: mria_mnesia_create_table, name: emqx_app, options: [{type,set},{rlog_shard,emqx_common_shard},{storage,disc_copies},{record_name,emqx_app},{attributes,[name,api_key,api_secret_hash,enable,extra,expired_at,created_at]}]
2024-04-09T18:01:28.549695+00:00 [info] msg: Adding table to a shard, shard: emqx_common_shard, table: emqx_app
2024-04-09T18:01:28.549809+00:00 [debug] msg: ensure_local_table, '$span': start, table: emqx_app
2024-04-09T18:01:28.549948+00:00 [info] msg: Setting RLOG shard config, shard: emqx_common_shard, tables: [bpapi,emqx_app,emqx_banned,emqx_banned_rules,emqx_trace]
2024-04-09T18:01:28.550071+00:00 [notice] msg: Shard schema change, new_table: emqx_app, shard: emqx_common_shard
2024-04-09T18:01:28.550065+00:00 [debug] msg: ensure_local_table, '$span': {complete,true}, table: emqx_app
2024-04-09T18:01:28.550592+00:00 [debug] msg: init_bootstrap_api_keys_from_file, file: <<"/opt/emqx/data/bootstrap_api_key">>
2024-04-09T18:01:28.551478+00:00 [debug] msg: started_apps, apps: [trails,cowboy_swagger,minirest,emqx_management]
2024-04-09T18:01:28.551557+00:00 [debug] msg: starting_app, app: emqx_opentelemetry
2024-04-09T18:01:28.553023+00:00 [debug] msg: started_apps, apps: [opentelemetry_api,grpc,opentelemetry_exporter,opentelemetry,opentelemetry_api_experimental,opentelemetry_experimental,emqx_opentelemetry]
2024-04-09T18:01:28.553096+00:00 [debug] msg: starting_app, app: emqx_redis
2024-04-09T18:01:28.553443+00:00 [debug] msg: started_apps, apps: [eredis,eredis_cluster,emqx_redis]
2024-04-09T18:01:28.553518+00:00 [debug] msg: starting_app, app: emqx_exhook
2024-04-09T18:01:28.554482+00:00 [debug] msg: started_apps, apps: [emqx_exhook]
2024-04-09T18:01:28.554552+00:00 [debug] msg: starting_app, app: emqx_connector
2024-04-09T18:01:28.558367+00:00 [debug] msg: started_apps, apps: [jose,emqx_connector]
2024-04-09T18:01:28.558451+00:00 [debug] msg: starting_app, app: emqx_ldap
2024-04-09T18:01:28.558614+00:00 [debug] msg: started_apps, apps: [eldap,emqx_ldap]
2024-04-09T18:01:28.558685+00:00 [debug] msg: starting_app, app: emqx_bridge
2024-04-09T18:01:28.560288+00:00 [debug] msg: started_apps, apps: [emqx_bridge]
2024-04-09T18:01:28.560371+00:00 [debug] msg: starting_app, app: emqx_rule_engine
2024-04-09T18:01:28.561827+00:00 [debug] msg: started_apps, apps: [rulesql,quickrand,uuid,emqx_rule_engine]
2024-04-09T18:01:28.561928+00:00 [debug] msg: starting_app, app: emqx_mongodb
2024-04-09T18:01:28.562707+00:00 [debug] msg: started_apps, apps: [bson,poolboy,mongodb,emqx_mongodb]
2024-04-09T18:01:28.562811+00:00 [debug] msg: starting_app, app: emqx_dashboard
2024-04-09T18:01:28.563039+00:00 [debug] msg: mria_mnesia_create_table, name: emqx_admin, options: [{type,set},{rlog_shard,emqx_dashboard_shard},{storage,disc_copies},{record_name,emqx_admin},{attributes,[username,pwdhash,description,role,extra]},{storage_properties,[{ets,[{read_concurrency,true},{write_concurrency,true}]}]}]
2024-04-09T18:01:28.565873+00:00 [info] msg: Adding table to a shard, shard: emqx_dashboard_shard, table: emqx_admin
2024-04-09T18:01:28.566120+00:00 [debug] msg: ensure_local_table, '$span': start, table: emqx_admin
2024-04-09T18:01:28.566247+00:00 [info] msg: Setting RLOG shard config, shard: emqx_dashboard_shard, tables: [emqx_admin]
2024-04-09T18:01:28.566373+00:00 [debug] msg: ensure_local_table, '$span': {complete,true}, table: emqx_admin
2024-04-09T18:01:28.566442+00:00 [debug] msg: mria_mnesia_create_table, name: emqx_admin_jwt, options: [{type,set},{rlog_shard,emqx_dashboard_shard},{storage,disc_copies},{record_name,emqx_admin_jwt},{attributes,[token,username,exptime,extra]},{storage_properties,[{ets,[{read_concurrency,true},{write_concurrency,true}]}]}]
2024-04-09T18:01:28.569199+00:00 [info] msg: Adding table to a shard, shard: emqx_dashboard_shard, table: emqx_admin_jwt
2024-04-09T18:01:28.569328+00:00 [debug] msg: ensure_local_table, '$span': start, table: emqx_admin_jwt
2024-04-09T18:01:28.569430+00:00 [info] msg: Setting RLOG shard config, shard: emqx_dashboard_shard, tables: [emqx_admin,emqx_admin_jwt]
2024-04-09T18:01:28.569566+00:00 [debug] msg: ensure_local_table, '$span': {complete,true}, table: emqx_admin_jwt
2024-04-09T18:01:28.569633+00:00 [debug] msg: mria_mnesia_create_table, name: emqx_dashboard_monitor, options: [{type,set},{local_content,true},{storage,disc_copies},{record_name,emqx_monit},{attributes,[time,data]}]
2024-04-09T18:01:28.575080+00:00 [info] msg: Adding table to a shard, shard: undefined, table: emqx_dashboard_monitor
2024-04-09T18:01:28.575237+00:00 [debug] msg: ensure_local_table, '$span': start, table: emqx_dashboard_monitor
2024-04-09T18:01:28.575367+00:00 [info] msg: Setting RLOG shard config, shard: undefined, tables: [emqx_activated_alarm,emqx_dashboard_monitor,emqx_deactivated_alarm,emqx_delayed]
2024-04-09T18:01:28.575539+00:00 [debug] msg: ensure_local_table, '$span': {complete,true}, table: emqx_dashboard_monitor
2024-04-09T18:01:28.575704+00:00 [info] msg: starting_rlog_shard, shard: emqx_dashboard_shard
2024-04-09T18:01:28.576011+00:00 [info] msg: Shard fully up, node: 'emqx@emqx5-core-6796d44f-1.emqx5-headless.database.svc.cluster.local', shard: emqx_dashboard_shard
2024-04-09T18:01:28.576423+00:00 [info] msg: loading_desc, file: /opt/emqx/lib/emqx_dashboard-5.0.33/priv/desc.en.hocon
2024-04-09T18:01:28.663358+00:00 [info] msg: loading_desc, file: /opt/emqx/lib/emqx_dashboard-5.0.33/priv/desc.zh.hocon
Listener http:dashboard on :18083 started.
2024-04-09T18:01:28.755161+00:00 [info] msg: started_listener_ok, name: 'http:dashboard', pid: <0.2944.0>, port: 18083
2024-04-09T18:01:28.756440+00:00 [info] msg: dashboard_sso_user_added, username: admin, role: <<"administrator">>
2024-04-09T18:01:28.760697+00:00 [debug] msg: started_apps, apps: [emqx_dashboard]
2024-04-09T18:01:28.760833+00:00 [debug] msg: starting_app, app: emqx_auto_subscribe
2024-04-09T18:01:28.768326+00:00 [debug] msg: started_apps, apps: [emqx_auto_subscribe]
2024-04-09T18:01:28.768677+00:00 [debug] msg: starting_app, app: emqx_auth
2024-04-09T18:01:28.774502+00:00 [info] msg: authn_chains_initialization_done
2024-04-09T18:01:28.779310+00:00 [debug] msg: started_apps, apps: [emqx_auth]
2024-04-09T18:01:28.779421+00:00 [debug] msg: starting_app, app: emqx_auth_postgresql
2024-04-09T18:01:28.779863+00:00 [debug] msg: started_apps, apps: [emqx_auth_postgresql]
2024-04-09T18:01:28.779939+00:00 [debug] msg: starting_app, app: emqx_auth_mongodb
2024-04-09T18:01:28.780235+00:00 [debug] msg: started_apps, apps: [emqx_auth_mongodb]
2024-04-09T18:01:28.780302+00:00 [debug] msg: starting_app, app: emqx_auth_mnesia
2024-04-09T18:01:28.780504+00:00 [debug] msg: mria_mnesia_create_table, name: emqx_acl, options: [{type,ordered_set},{rlog_shard,emqx_acl_sharded},{storage,disc_copies},{attributes,[who,rules]},{storage_properties,[{ets,[{read_concurrency,true}]}]}]
2024-04-09T18:01:28.785482+00:00 [info] msg: Adding table to a shard, shard: emqx_acl_sharded, table: emqx_acl
2024-04-09T18:01:28.785626+00:00 [debug] msg: ensure_local_table, '$span': start, table: emqx_acl
2024-04-09T18:01:28.785813+00:00 [info] msg: Setting RLOG shard config, shard: emqx_acl_sharded, tables: [emqx_acl]
2024-04-09T18:01:28.788528+00:00 [debug] msg: ensure_local_table, '$span': {complete,true}, table: emqx_acl
2024-04-09T18:01:28.788764+00:00 [info] msg: starting_rlog_shard, shard: emqx_acl_sharded
2024-04-09T18:01:28.789201+00:00 [debug] msg: mria_mnesia_create_table, name: emqx_authn_mnesia, options: [{rlog_shard,emqx_authn_shard},{type,ordered_set},{storage,disc_copies},{record_name,user_info},{attributes,[user_id,password_hash,salt,is_superuser]},{storage_properties,[{ets,[{read_concurrency,true}]}]}]
2024-04-09T18:01:28.789200+00:00 [info] msg: Shard fully up, node: 'emqx@emqx5-core-6796d44f-1.emqx5-headless.database.svc.cluster.local', shard: emqx_acl_sharded
2024-04-09T18:01:28.793880+00:00 [info] msg: Adding table to a shard, shard: emqx_authn_shard, table: emqx_authn_mnesia
2024-04-09T18:01:28.794021+00:00 [debug] msg: ensure_local_table, '$span': start, table: emqx_authn_mnesia
2024-04-09T18:01:28.794135+00:00 [info] msg: Setting RLOG shard config, shard: emqx_authn_shard, tables: [emqx_authn_mnesia]
2024-04-09T18:01:28.794351+00:00 [debug] msg: ensure_local_table, '$span': {complete,true}, table: emqx_authn_mnesia
2024-04-09T18:01:28.794576+00:00 [info] msg: starting_rlog_shard, shard: emqx_authn_shard
2024-04-09T18:01:28.794919+00:00 [info] msg: Shard fully up, node: 'emqx@emqx5-core-6796d44f-1.emqx5-headless.database.svc.cluster.local', shard: emqx_authn_shard
2024-04-09T18:01:28.794921+00:00 [debug] msg: mria_mnesia_create_table, name: emqx_authn_scram_mnesia, options: [{rlog_shard,emqx_authn_shard},{type,ordered_set},{storage,disc_copies},{record_name,user_info},{attributes,[user_id,stored_key,server_key,salt,is_superuser]},{storage_properties,[{ets,[{read_concurrency,true}]}]}]
2024-04-09T18:01:28.797600+00:00 [info] msg: Adding table to a shard, shard: emqx_authn_shard, table: emqx_authn_scram_mnesia
2024-04-09T18:01:28.797744+00:00 [debug] msg: ensure_local_table, '$span': start, table: emqx_authn_scram_mnesia
2024-04-09T18:01:28.797847+00:00 [info] msg: Setting RLOG shard config, shard: emqx_authn_shard, tables: [emqx_authn_mnesia,emqx_authn_scram_mnesia]
2024-04-09T18:01:28.798258+00:00 [notice] msg: Shard schema change, new_table: emqx_authn_scram_mnesia, shard: emqx_authn_shard
2024-04-09T18:01:28.798247+00:00 [debug] msg: ensure_local_table, '$span': {complete,true}, table: emqx_authn_scram_mnesia
2024-04-09T18:01:28.798459+00:00 [debug] msg: started_apps, apps: [emqx_auth_mnesia]
2024-04-09T18:01:28.798522+00:00 [debug] msg: starting_app, app: emqx_prometheus
2024-04-09T18:01:28.805482+00:00 [debug] msg: started_apps, apps: [prometheus,emqx_prometheus]
2024-04-09T18:01:28.805603+00:00 [debug] msg: starting_app, app: emqx_auth_http
2024-04-09T18:01:28.805843+00:00 [debug] msg: started_apps, apps: [emqx_auth_http]
2024-04-09T18:01:28.805903+00:00 [debug] msg: starting_app, app: emqx_gateway
2024-04-09T18:01:28.806730+00:00 [debug] msg: register_gateway_succeed, callback_module: emqx_gateway_coap
2024-04-09T18:01:28.806811+00:00 [debug] msg: register_gateway_succeed, callback_module: emqx_gateway_exproto
2024-04-09T18:01:28.806881+00:00 [debug] msg: register_gateway_succeed, callback_module: emqx_gateway_lwm2m
2024-04-09T18:01:28.806962+00:00 [debug] msg: register_gateway_succeed, callback_module: emqx_gateway_mqttsn
2024-04-09T18:01:28.807015+00:00 [debug] msg: register_gateway_succeed, callback_module: emqx_gateway_stomp
2024-04-09T18:01:28.807461+00:00 [debug] msg: started_apps, apps: [emqx_gateway]
2024-04-09T18:01:28.807549+00:00 [debug] msg: starting_app, app: emqx_gateway_exproto
2024-04-09T18:01:28.807815+00:00 [debug] msg: started_apps, apps: [emqx_gateway_exproto]
2024-04-09T18:01:28.807868+00:00 [debug] msg: starting_app, app: emqx_gateway_coap
2024-04-09T18:01:28.807997+00:00 [debug] msg: started_apps, apps: [emqx_gateway_coap]
2024-04-09T18:01:28.808052+00:00 [debug] msg: starting_app, app: emqx_gateway_lwm2m
2024-04-09T18:01:28.808304+00:00 [debug] msg: started_apps, apps: [emqx_gateway_lwm2m]
2024-04-09T18:01:28.808359+00:00 [debug] msg: starting_app, app: emqx_gateway_stomp
2024-04-09T18:01:28.808685+00:00 [debug] msg: started_apps, apps: [emqx_gateway_stomp]
2024-04-09T18:01:28.808742+00:00 [debug] msg: starting_app, app: emqx_auth_redis
2024-04-09T18:01:28.809080+00:00 [debug] msg: started_apps, apps: [emqx_auth_redis]
2024-04-09T18:01:28.809128+00:00 [debug] msg: starting_app, app: emqx_auth_jwt
2024-04-09T18:01:28.809434+00:00 [debug] msg: started_apps, apps: [emqx_auth_jwt]
2024-04-09T18:01:28.809478+00:00 [debug] msg: starting_app, app: emqx_auth_ldap
2024-04-09T18:01:28.809732+00:00 [debug] msg: started_apps, apps: [emqx_auth_ldap]
2024-04-09T18:01:28.809780+00:00 [debug] msg: starting_app, app: emqx_mysql
2024-04-09T18:01:28.810139+00:00 [debug] msg: started_apps, apps: [mysql,emqx_mysql]
2024-04-09T18:01:28.810245+00:00 [debug] msg: starting_app, app: emqx_auth_mysql
2024-04-09T18:01:28.810503+00:00 [debug] msg: started_apps, apps: [emqx_auth_mysql]
2024-04-09T18:01:28.810549+00:00 [debug] msg: starting_app, app: emqx_gateway_mqttsn
2024-04-09T18:01:28.810765+00:00 [debug] msg: started_apps, apps: [emqx_gateway_mqttsn]
2024-04-09T18:01:28.810806+00:00 [debug] msg: starting_app, app: emqx_telemetry
2024-04-09T18:01:28.811429+00:00 [debug] msg: started_apps, apps: [emqx_telemetry]
2024-04-09T18:01:28.811484+00:00 [debug] msg: starting_app, app: quicer
2024-04-09T18:01:28.811288+00:00 [debug] msg: mria_mnesia_create_table, name: emqx_telemetry, options: [{type,set},{storage,disc_copies},{rlog_shard,emqx_telemetry_shard},{record_name,telemetry},{attributes,[id,uuid]}]
2024-04-09T18:01:28.811946+00:00 [debug] msg: started_apps, apps: [quicer]
2024-04-09T18:01:28.811998+00:00 [debug] msg: starting_app, app: emqx_psk
2024-04-09T18:01:28.812148+00:00 [debug] msg: mria_mnesia_create_table, name: emqx_psk, options: [{rlog_shard,emqx_psk_shard},{type,ordered_set},{storage,disc_copies},{record_name,psk_entry},{attributes,[psk_id,shared_secret,extra]},{storage_properties,[{ets,[{read_concurrency,true}]}]}]
2024-04-09T18:01:28.814019+00:00 [info] msg: Adding table to a shard, shard: emqx_telemetry_shard, table: emqx_telemetry
2024-04-09T18:01:28.814160+00:00 [debug] msg: ensure_local_table, '$span': start, table: emqx_telemetry
2024-04-09T18:01:28.816795+00:00 [info] msg: Adding table to a shard, shard: emqx_psk_shard, table: emqx_psk
2024-04-09T18:01:28.816943+00:00 [debug] msg: ensure_local_table, '$span': start, table: emqx_psk
2024-04-09T18:01:28.817057+00:00 [info] msg: Setting RLOG shard config, shard: emqx_telemetry_shard, tables: [emqx_telemetry]
2024-04-09T18:01:28.818396+00:00 [debug] msg: ensure_local_table, '$span': {complete,true}, table: emqx_telemetry
2024-04-09T18:01:28.818506+00:00 [info] msg: Setting RLOG shard config, shard: emqx_psk_shard, tables: [emqx_psk]
2024-04-09T18:01:28.818599+00:00 [info] msg: starting_rlog_shard, shard: emqx_telemetry_shard
2024-04-09T18:01:28.820340+00:00 [debug] msg: ensure_local_table, '$span': {complete,true}, table: emqx_psk
2024-04-09T18:01:28.820415+00:00 [info] msg: Shard fully up, node: 'emqx@emqx5-core-6796d44f-1.emqx5-headless.database.svc.cluster.local', shard: emqx_telemetry_shard
2024-04-09T18:01:28.820463+00:00 [info] msg: starting_rlog_shard, shard: emqx_psk_shard
2024-04-09T18:01:28.820719+00:00 [info] msg: Shard fully up, node: 'emqx@emqx5-core-6796d44f-1.emqx5-headless.database.svc.cluster.local', shard: emqx_psk_shard
2024-04-09T18:01:28.821847+00:00 [info] msg: emqx_psk_disabled
EMQX 5.6.0 is running now!
2024-04-09T18:01:28.821940+00:00 [debug] msg: started_apps, apps: [emqx_psk]
2024-04-09T18:01:29.652448+00:00 [info] msg: regenerate_minirest_dispatch, elapsed: 897, i18n_lang: en, listeners: ['http:dashboard']
2024-04-09T18:01:30.557021+00:00 [debug] Ekka(AutoCluster): join result: ignore
2024-04-09T18:01:30.557092+00:00 [info] Ekka(AutoCluster): all discovered nodes are alive
2024-04-09T18:01:37.339655+00:00 [debug] Ekka(AutoCluster): join result: ignore
2024-04-09T18:01:37.339852+00:00 [info] Ekka(AutoCluster): all discovered nodes are alive
2024-04-09T18:01:39.242310+00:00 [debug] msg: telemetry_data_reported
2024-04-09T18:01:43.052094+00:00 [debug] Ekka(AutoCluster): join result: ignore
2024-04-09T18:01:43.052336+00:00 [info] Ekka(AutoCluster): all discovered nodes are alive
2024-04-09T18:01:50.996718+00:00 [debug] Ekka(AutoCluster): join result: ignore
2024-04-09T18:01:50.996940+00:00 [info] Ekka(AutoCluster): all discovered nodes are alive
2024-04-09T18:01:58.934370+00:00 [debug] Ekka(AutoCluster): join result: ignore
2024-04-09T18:01:58.934576+00:00 [info] Ekka(AutoCluster): all discovered nodes are alive
2024-04-09T18:02:05.357208+00:00 [debug] Ekka(AutoCluster): join result: ignore
2024-04-09T18:02:05.357431+00:00 [info] Ekka(AutoCluster): all discovered nodes are alive
2024-04-09T18:02:12.802955+00:00 [debug] Ekka(AutoCluster): join result: ignore
2024-04-09T18:02:12.803233+00:00 [info] Ekka(AutoCluster): all discovered nodes are alive
2024-04-09T18:02:18.432421+00:00 [debug] Ekka(AutoCluster): join result: ignore
2024-04-09T18:02:18.432504+00:00 [info] Ekka(AutoCluster): all discovered nodes are alive
2024-04-09T18:02:24.488638+00:00 [debug] Ekka(AutoCluster): join result: ignore
2024-04-09T18:02:24.488888+00:00 [info] Ekka(AutoCluster): all discovered nodes are alive
2024-04-09T18:02:32.164340+00:00 [debug] Ekka(AutoCluster): join result: ignore
2024-04-09T18:02:32.164568+00:00 [info] Ekka(AutoCluster): all discovered nodes are alive
2024-04-09T18:02:39.037639+00:00 [debug] Ekka(AutoCluster): join result: ignore
2024-04-09T18:02:39.037942+00:00 [info] Ekka(AutoCluster): all discovered nodes are alive
2024-04-09T18:02:44.526227+00:00 [debug] Ekka(AutoCluster): join result: ignore
2024-04-09T18:02:44.526498+00:00 [info] Ekka(AutoCluster): all discovered nodes are alive
2024-04-09T18:02:50.574662+00:00 [debug] Ekka(AutoCluster): join result: ignore
2024-04-09T18:02:50.574910+00:00 [info] Ekka(AutoCluster): all discovered nodes are alive
2024-04-09T18:02:56.669933+00:00 [debug] Ekka(AutoCluster): join result: ignore
2024-04-09T18:02:56.670146+00:00 [info] Ekka(AutoCluster): all discovered nodes are alive

Expected behavior

For the cluster to be in a Running state

Anything else we need to know?:

If I set the core replicas to 1 everything is happy

Environment details::

onedr0p commented 7 months ago

It's also worth noting I only see these svc, nothing related to the core pods.

❯ k get svc -n database
NAME                                               TYPE           CLUSTER-IP      EXTERNAL-IP      PORT(S)             AGE
emqx-operator-controller-manager-metrics-service   ClusterIP      10.43.9.231     <none>           8080/TCP            134m
emqx-operator-webhook-service                      ClusterIP      10.43.45.107    <none>           443/TCP             134m
onedr0p commented 7 months ago

kubectl -n database get emqx emqx5 -o json

{
    "apiVersion": "apps.emqx.io/v2beta1",
    "kind": "EMQX",
    "metadata": {
        "annotations": {
            "apps.emqx.io/last-emqx-configuration": "log.console.level = debug\n",
            "kubectl.kubernetes.io/last-applied-configuration": "{\"apiVersion\":\"apps.emqx.io/v2beta1\",\"kind\":\"EMQX\",\"metadata\":{\"annotations\":{},\"name\":\"emqx5\",\"namespace\":\"database\"},\"spec\":{\"config\":{\"data\":\"log.console.level = debug\\n\"},\"coreTemplate\":{\"spec\":{\"replicas\":3}},\"image\":\"public.ecr.aws/emqx/emqx:5.6.0\"}}\n"
        },
        "creationTimestamp": "2024-04-09T18:11:01Z",
        "generation": 2,
        "name": "emqx5",
        "namespace": "database",
        "resourceVersion": "52022722",
        "uid": "62eec439-9224-4eeb-a106-434ec94b16b2"
    },
    "spec": {
        "clusterDomain": "cluster.local",
        "config": {
            "data": "log.console.level = debug\n",
            "mode": "Merge"
        },
        "coreTemplate": {
            "metadata": {},
            "spec": {
                "containerSecurityContext": {
                    "runAsGroup": 1000,
                    "runAsNonRoot": true,
                    "runAsUser": 1000
                },
                "livenessProbe": {
                    "failureThreshold": 3,
                    "httpGet": {
                        "path": "/status",
                        "port": "dashboard"
                    },
                    "initialDelaySeconds": 60,
                    "periodSeconds": 30
                },
                "podSecurityContext": {
                    "fsGroup": 1000,
                    "fsGroupChangePolicy": "Always",
                    "runAsGroup": 1000,
                    "runAsUser": 1000,
                    "supplementalGroups": [
                        1000
                    ]
                },
                "readinessProbe": {
                    "failureThreshold": 12,
                    "httpGet": {
                        "path": "/status",
                        "port": "dashboard"
                    },
                    "initialDelaySeconds": 10,
                    "periodSeconds": 5
                },
                "replicas": 3,
                "resources": {},
                "volumeClaimTemplates": {
                    "resources": {}
                }
            }
        },
        "image": "public.ecr.aws/emqx/emqx:5.6.0",
        "revisionHistoryLimit": 3,
        "updateStrategy": {
            "evacuationStrategy": {
                "connEvictRate": 1000,
                "sessEvictRate": 1000,
                "waitTakeover": 10
            },
            "initialDelaySeconds": 10,
            "type": "Recreate"
        }
    },
    "status": {
        "conditions": [
            {
                "lastTransitionTime": "2024-04-09T18:11:02Z",
                "message": "Create new statefulSet",
                "reason": "CreateNewStatefulSet",
                "status": "True",
                "type": "CoreNodesProgressing"
            }
        ],
        "coreNodes": [
            {
                "controllerUID": "c3c2f68a-8a30-4542-97d7-f356024863fe",
                "edition": "Opensource",
                "node": "emqx@emqx5-core-6796d44f-0.emqx5-headless.database.svc.cluster.local",
                "node_status": "running",
                "otp_release": "25.3.2-2/13.2.2",
                "podUID": "5376b8c9-fc07-48c3-b9a7-2591f6342027",
                "role": "core",
                "uptime": 45232,
                "version": "5.6.0"
            }
        ],
        "coreNodesStatus": {
            "currentReplicas": 1,
            "currentRevision": "6796d44f",
            "readyReplicas": 1,
            "replicas": 3,
            "updateReplicas": 1,
            "updateRevision": "6796d44f"
        },
        "replicantNodesStatus": {}
    }
}
Rory-Z commented 7 months ago

Hi @onedr0p check EMQX pod log, I found this: 2024-04-09T18:01:50.996718+00:00 [debug] Ekka(AutoCluster): join result: ignore, it is means the EMQX application can not found any nodes by DNS server. Could you please check the DNS server, you can create a ubuntu pod in the EMQX pod namespace and running this command nslookup -type=srv emqx5-headless.database.svc.cluster.local

ahinko commented 7 months ago

Hi @Rory-Z, I'm able to replicate this issue as well by using the same configuration and versions as @onedr0p.

I'm guessing that the dns issue is caused by the missing services. Just as @onedr0p mentioned above the only svc I see is for the operator and the webhook. No emqx5-headless svc.

ahinko commented 7 months ago

Follow up: I reverted back to version 2.2.14 of the operator and with that version the exact same cluster configuration works. The services are created and the cluster quickly becomes Ready.

After that I can bump the version back to 2.2.19 and since the services has already been created by the old version of the operator everything still works. But deploying a new cluster fails again.

Rory-Z commented 7 months ago

@ahinko @onedr0p Thanks for feedback, I got the same result, I think this is a bug from 2.2.19, let me fix it.

Rory-Z commented 7 months ago

@onedr0p @ahinko EMQX operator 2.2.20 has been released, please try it.

ahinko commented 7 months ago

@Rory-Z 2.2.20 fixes the issue. Thank you for the quick fix.

onedr0p commented 7 months ago

Thanks for the update @Rory-Z looks to be working here!