search

apecloud / kubeblocks

KubeBlocks is an open-source control plane software that runs and manages databases, message queues and other stateful applications on K8s.
https://kubeblocks.io
GNU Affero General Public License v3.0
2.08k stars 170 forks source link

[BUG] mysql cluster reconfig log_slave_updates ON pod CrashLoopBackOff #6512

Closed JashBook closed 8 months ago

JashBook commented 8 months ago

Describe the bug mysql cluster reconfig log_slave_updates ON pod CrashLoopBackOff upgrade kubeblocks from 0.7.2 to 0.8.1 and reconfig log_slave_updates=ON

To Reproduce Steps to reproduce the behavior:

  1. install kubeblocks 0.7.2
  2. create mysql cluster 5.7 
    kbcli cluster create  asm-upkb10 --termination-policy=WipeOut --monitoring-interval=0 --cluster-definition=mysql --enable-all-logs=false --cluster-version=mysql-5.7.42 --set cpu=100m,memory=0.5Gi,replicas=2,storage=10Gi  --namespace default
  3. upgrade kubeblocks 0.8.1
  4. reconfig log_slave_updates ON 
    kbcli cluster configure asm-upkb10 --auto-approve  --set log_slave_updates=ON --components mysql --config-spec mysql-replication-config  --namespace default
  5. see error 
    
kubectl get pod,ops -l app.kubernetes.io/instance=asm-upkb10                     
NAME                     READY   STATUS             RESTARTS       AGE
pod/asm-upkb10-mysql-0   4/4     Running            0              79m
pod/asm-upkb10-mysql-1   3/4     CrashLoopBackOff   15 (87s ago)   53m

NAME TYPE CLUSTER STATUS PROGRESS AGE opsrequest.apps.kubeblocks.io/asm-upkb10-reconfiguring-n68jv Reconfiguring asm-upkb10 Running 1/2 53m

get cm config

kubectl get cm asm-upkb10-mysql-mysql-replication-config -oyaml apiVersion: v1 data: my.cnf: | [client] default-character-set=utf8mb4 port=3306 socket=/var/run/mysqld/mysqld.sock

[mysql]
default-character-set=utf8mb4

[mysqld]
back_log=5285
binlog_cache_size=32768
binlog_format=MIXED
binlog_order_commits=ON
binlog_row_image=FULL
character_set_server=utf8mb4
collation_server=utf8mb4_unicode_520_ci
connect_timeout=10
datadir=/var/lib/mysql/data
default_tmp_storage_engine=innodb
enforce_gtid_consistency=ON
expire_logs_days=7
gtid_mode=ON
host_cache_size=867
innodb_buffer_pool_size=128M
innodb_flush_method=O_DIRECT
innodb_io_capacity=200
innodb_io_capacity_max=2000
innodb_log_buffer_size=8388608
innodb_open_files=4000
innodb_purge_threads=1
innodb_read_io_threads=4
join_buffer_size=262144
key_buffer_size=16777216
local_infile=ON
log-bin=/var/lib/mysql/binlog/mysql-bin
log_bin_index=/var/lib/mysql/binlog/mysql-bin.index
log_error=/var/lib/mysql/log/mysqld-error.log
log_error_verbosity=2
log_output=FILE
log_slave_updates=ON
log_statements_unsafe_for_binlog=OFF
long_query_time=5
max_binlog_size=134217728
max_connections=83
max_prepared_stmt_count=16382
open_files_limit=1048576
performance_schema=OFF
performance_schema_digests_size=10000
performance_schema_events_stages_history_long_size=10000
performance_schema_events_transactions_history_long_size=10000
pid-file=/var/run/mysqld/mysqld.pid
plugin-load="rpl_semi_sync_master=semisync_master.so
port=3306
read_buffer_size=262144
read_rnd_buffer_size=524288
relay_log=relay-bin
relay_log_index=relay-bin.index
relay_log_recovery=ON
rpl-semi-sync-master-enabled=1
rpl-semi-sync-slave-enabled=1
rpl_semi_sync_master_timeout=1000
slave_exec_mode=IDEMPOTENT
slow_query_log=ON
slow_query_log_file=/var/lib/mysql/log/mysqld-slowquery.log
socket=/var/run/mysqld/mysqld.sock
sort_buffer_size=262144
sql_mode=NO_ENGINE_SUBSTITUTION
table_open_cache=4000
thread_cache_size=60
thread_stack=262144

kind: ConfigMap metadata: annotations: config.kubeblocks.io/config-applied-version: '{"name":"mysql-replication-config","payload":null,"configSpec":{"name":"mysql-replication-config","templateRef":"oracle-mysql5.7-config-template","namespace":"default","volumeName":"mysql-config","constraintRef":"oracle-mysql8.0-config-constraints"},"importTemplateRef":null,"configFileParams":{"my.cnf":{"content":null,"parameters":{"log_slave_updates":"ON"}}}}' config.kubeblocks.io/config-template-version: "" config.kubeblocks.io/configuration-revision: "2" config.kubeblocks.io/disable-reconfigure: "false" config.kubeblocks.io/last-applied-configuration: '{"my.cnf":"[mysqld]\n# aliyun buffer pool: https://help.aliyun.com/document_detail/162326.html?utm_content=g_1000230851\u0026spm=5176.20966629.toubu.3.f2991ddcpxxvD1#title-rey-j7j-4dt\ninnodb_buffer_pool_size=128M\n\n# require port\n# Global_Buffer = innodb_buffer_pool_size = PhysicalMemory *3/4\n# max_connections = (PhysicalMemory - Global_Buffer) / single_thread_memory\nmax_connections=83\n\n# if memory less than 8Gi, disable performance_schema\nperformance_schema=OFF\n\n# alias replica_exec_mode. Aliyun slave_exec_mode=STRICT\nslave_exec_mode=IDEMPOTENT\n\n# gtid\ngtid_mode=ON\nenforce_gtid_consistency=ON\n\n#server \u0026 instances\nthread_stack=262144\nthread_cache_size=60\n# ulimit -n\nopen_files_limit=1048576\nlocal_infile=ON\nsql_mode=NO_ENGINE_SUBSTITUTION\n#Default 4000\ntable_open_cache=4000\n\n# under high number thread (such as 128 threads), this value will cause sysbench fails\n# if so, change it to 100000 or higher.\nmax_prepared_stmt_count=16382\n\nperformance_schema_digests_size=10000\nperformance_schema_events_stages_history_long_size=10000\nperformance_schema_events_transactions_history_long_size=10000\nread_buffer_size=262144\nread_rnd_buffer_size=524288\njoin_buffer_size=262144\nsort_buffer_size=262144\n\nback_log=5285\nhost_cache_size=867\nconnect_timeout=10\n\n# character-sets-dir=/usr/share/mysql-8.0/charsets\n\nport=3306\n\ndatadir=/var/lib/mysql/data\n\n\nlog_statements_unsafe_for_binlog=OFF\nlog_error_verbosity=2\nlog_output=FILE\nlog_error=/var/lib/mysql/log/mysqld-error.log\nslow_query_log=ON\nlong_query_time=5\nslow_query_log_file=/var/lib/mysql/log/mysqld-slowquery.log\n\n\n#innodb\ninnodb_flush_method=O_DIRECT\ninnodb_io_capacity=200\ninnodb_io_capacity_max=2000\ninnodb_log_buffer_size=8388608\n#innodb_log_file_size=134217728\n#innodb_log_files_in_group=2\n\ninnodb_open_files=4000\ninnodb_purge_threads=1\ninnodb_read_io_threads=4\n# innodb_print_all_deadlocks=ON # AWS not set\nkey_buffer_size=16777216\n\n# binlog\n# master_info_repository=TABLE\n# From mysql8.0.23 is deprecated.\nbinlog_cache_size=32768\n# AWS binlog_format=MIXED, Aliyun is ROW\nbinlog_format=MIXED\nbinlog_row_image=FULL\n# Aliyun AWS binlog_order_commits=ON\nbinlog_order_commits=ON\nlog-bin=/var/lib/mysql/binlog/mysql-bin\nlog_bin_index=/var/lib/mysql/binlog/mysql-bin.index\nexpire_logs_days=7\nmax_binlog_size=134217728\n# binlog_rows_query_log_events=ON #AWS not set\n# binlog_transaction_dependency_tracking=WRITESET #Default Commit Order, Aws not set\n\n# replay log\n# relay_log_info_repository=TABLE\n# From mysql8.0.23 is deprecated.\nrelay_log_recovery=ON\nrelay_log=relay-bin\nrelay_log_index=relay-bin.index\n\npid-file=/var/run/mysqld/mysqld.pid\nsocket=/var/run/mysqld/mysqld.sock\n\n## smartengine base config\n#default_storage_engine=smartengine\ndefault_tmp_storage_engine=innodb\n\n# log_error_verbosity=3\n# binlog_format=ROW\n\n# set utf8 encoding\ncollation_server = utf8mb4_unicode_520_ci\ncharacter_set_server = utf8mb4\n\nplugin-load = \"rpl_semi_sync_master=semisync_master.so;rpl_semi_sync_slave=semisync_slave.so\"\nrpl-semi-sync-master-enabled = 1\nrpl_semi_sync_master_timeout = 1000\nrpl-semi-sync-slave-enabled = 1\n\n[mysql]\ndefault-character-set=utf8mb4\n\n[client]\nport=3306\nsocket=/var/run/mysqld/mysqld.sock\ndefault-character-set=utf8mb4"}' config.kubeblocks.io/reconfigure-source: manager config.kubeblocks.io/revision-reconcile-phase-1: '{"phase":"Finished","revision":"1","policy":"","execResult":"","succeedCount":0,"expectedCount":-1,"retry":false,"failed":false,"message":"phase: created"}' config.kubeblocks.io/revision-reconcile-phase-2: '{"phase":"Upgrading","revision":"2","policy":"simple","execResult":"Retry","succeedCount":0,"expectedCount":2,"retry":true,"failed":false,"message":""}' config.kubeblocks.io/update-config-hash: 77df64c59c creationTimestamp: "2024-01-22T02:40:40Z" labels: app.kubernetes.io/component: mysql app.kubernetes.io/instance: asm-upkb10 app.kubernetes.io/managed-by: kubeblocks app.kubernetes.io/name: mysql apps.kubeblocks.io/component-name: mysql config.kubeblocks.io/config-constraints-name: oracle-mysql8.0-config-constraints config.kubeblocks.io/config-hash: 687c989f5 config.kubeblocks.io/config-spec: mysql-replication-config config.kubeblocks.io/config-template-name: oracle-mysql5.7-config-template config.kubeblocks.io/config-type: instance config.kubeblocks.io/last-applied-reconfigure-phase: created config.kubeblocks.io/template-name: oracle-mysql5.7-config-template name: asm-upkb10-mysql-mysql-replication-config namespace: default ownerReferences:

logs pod

kubectl logs asm-upkb10-mysql-1 mysql 
2024-01-22 04:05:18+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 5.7.42-1.el7 started.
2024-01-22 04:05:18+00:00 [ERROR] [Entrypoint]: mysqld failed while attempting to check config
    command was: mysqld --server-id 2 --ignore-db-dir=lost+found --verbose --help --log-bin-index=/tmp/tmp.lJYks3dGyB
    2024-01-22T04:05:18.260885Z 0 [Warning] 'NO_AUTO_CREATE_USER' sql mode was not set.
2024-01-22T04:05:18.357684Z 0 [ERROR] Can't find symbol '"rpl_semi_sync_master' in library
2024-01-22T04:05:18.357720Z 0 [ERROR] Couldn't load plugin named '"rpl_semi_sync_master' with soname 'semisync_master.so'.
2024-01-22T04:05:18.357757Z 0 [ERROR] unknown variable 'rpl-semi-sync-master-enabled=1'
2024-01-22T04:05:18.360820Z 0 [ERROR] Aborting

msyql error logs

kubectl exec -it asm-upkb10-mysql-1 sh -c metrics
kubectl exec [POD] [COMMAND] is DEPRECATED and will be removed in a future version. Use kubectl exec [POD] -- [COMMAND] instead.
/ # cat data/mysql/log/mysqld-error.log
2024-01-22T02:41:03.755364Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2024-01-22T02:41:03.755455Z 0 [Warning] 'NO_AUTO_CREATE_USER' sql mode was not set.
2024-01-22T02:41:05.984205Z 0 [Warning] InnoDB: New log files created, LSN=45790
2024-01-22T02:41:06.079370Z 0 [Warning] InnoDB: Creating foreign key constraint system tables.
2024-01-22T02:41:06.166463Z 0 [Warning] No existing UUID has been found, so we assume that this is the first time that this server has been started. Generating a new UUID: b0f53310-b8cf-11ee-90e4-5298b5f18d7b.
2024-01-22T02:41:06.169253Z 0 [Warning] Gtid table is not ready to be used. Table 'mysql.gtid_executed' cannot be opened.
2024-01-22T02:41:11.258834Z 0 [Warning] A deprecated TLS version TLSv1 is enabled. Please use TLSv1.2 or higher.
2024-01-22T02:41:11.258854Z 0 [Warning] A deprecated TLS version TLSv1.1 is enabled. Please use TLSv1.2 or higher.
2024-01-22T02:41:11.259403Z 0 [Warning] CA certificate ca.pem is self signed.
2024-01-22T02:41:12.564112Z 1 [Warning] root@localhost is created with an empty password ! Please consider switching off the --initialize-insecure option.
2024-01-22T02:41:17.862123Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2024-01-22T02:41:17.862184Z 0 [Warning] 'NO_AUTO_CREATE_USER' sql mode was not set.
2024-01-22T02:41:19.090415Z 0 [Warning] A deprecated TLS version TLSv1 is enabled. Please use TLSv1.2 or higher.
2024-01-22T02:41:19.090439Z 0 [Warning] A deprecated TLS version TLSv1.1 is enabled. Please use TLSv1.2 or higher.
2024-01-22T02:41:19.091117Z 0 [Warning] CA certificate ca.pem is self signed.
2024-01-22T02:41:19.093555Z 0 [Warning] Insecure configuration for --pid-file: Location '/var/run/mysqld' in the path is accessible to all OS users. Consider choosing a different directory.
2024-01-22T02:41:21.869082Z 3 [Warning] Timeout waiting for reply of binlog (file: mysql-bin.000002, pos: 319), semi-sync up to file , position 0.
2024-01-22T02:41:44.462181Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2024-01-22T02:41:44.462240Z 0 [Warning] 'NO_AUTO_CREATE_USER' sql mode was not set.
2024-01-22T02:41:46.257507Z 0 [Warning] A deprecated TLS version TLSv1 is enabled. Please use TLSv1.2 or higher.
2024-01-22T02:41:46.257604Z 0 [Warning] A deprecated TLS version TLSv1.1 is enabled. Please use TLSv1.2 or higher.
2024-01-22T02:41:46.259556Z 0 [Warning] CA certificate ca.pem is self signed.
2024-01-22T02:41:46.264135Z 0 [Warning] Insecure configuration for --pid-file: Location '/var/run/mysqld' in the path is accessible to all OS users. Consider choosing a different directory.
2024-01-22T02:41:48.181435Z 2 [Warning] Timeout waiting for reply of binlog (file: mysql-bin.000003, pos: 385), semi-sync up to file , position 0.
2024-01-22T02:42:07.456244Z 0 [ERROR] mysqld: Got an error reading communication packets
2024-01-22T02:42:11.252833Z 0 [ERROR] mysqld: Got an error reading communication packets
2024-01-22T02:42:25.660498Z 0 [ERROR] mysqld: Got an error reading communication packets
2024-01-22T02:42:28.181627Z 2 [Warning] Timeout waiting for reply of binlog (file: mysql-bin.000003, pos: 3653), semi-sync up to file mysql-bin.000003, position 3462.
2024-01-22T02:42:31.458878Z 0 [ERROR] mysqld: Got an error reading communication packets
2024-01-22T02:42:45.459413Z 0 [ERROR] mysqld: Got an error reading communication packets
2024-01-22T02:42:48.180980Z 2 [Warning] Timeout waiting for reply of binlog (file: mysql-bin.000003, pos: 5287), semi-sync up to file mysql-bin.000003, position 5096.
2024-01-22T02:42:52.056726Z 0 [ERROR] mysqld: Got an error reading communication packets
2024-01-22T02:43:05.752924Z 0 [ERROR] mysqld: Got an error reading communication packets
2024-01-22T02:43:08.183361Z 2 [Warning] Timeout waiting for reply of binlog (file: mysql-bin.000003, pos: 6921), semi-sync up to file mysql-bin.000003, position 6730.
2024-01-22T02:43:11.950572Z 0 [ERROR] mysqld: Got an error reading communication packets
2024-01-22T02:43:25.847486Z 0 [ERROR] mysqld: Got an error reading communication packets
2024-01-22T02:43:28.183274Z 2 [Warning] Timeout waiting for reply of binlog (file: mysql-bin.000003, pos: 8555), semi-sync up to file mysql-bin.000003, position 8364.
2024-01-22T02:43:31.355025Z 0 [ERROR] mysqld: Got an error reading communication packets
2024-01-22T02:43:46.355291Z 0 [ERROR] mysqld: Got an error reading communication packets
2024-01-22T02:43:48.188761Z 2 [Warning] Timeout waiting for reply of binlog (file: mysql-bin.000003, pos: 10189), semi-sync up to file mysql-bin.000003, position 9998.
2024-01-22T02:43:51.355030Z 0 [ERROR] mysqld: Got an error reading communication packets
2024-01-22T02:44:06.856211Z 0 [ERROR] mysqld: Got an error reading communication packets
2024-01-22T02:44:08.186270Z 2 [Warning] Timeout waiting for reply of binlog (file: mysql-bin.000003, pos: 11823), semi-sync up to file mysql-bin.000003, position 11632.
2024-01-22T02:44:11.057150Z 0 [ERROR] mysqld: Got an error reading communication packets
2024-01-22T02:44:26.357039Z 0 [ERROR] mysqld: Got an error reading communication packets
2024-01-22T02:44:28.186146Z 2 [Warning] Timeout waiting for reply of binlog (file: mysql-bin.000003, pos: 13457), semi-sync up to file mysql-bin.000003, position 13266.
2024-01-22T02:44:30.858283Z 0 [ERROR] mysqld: Got an error reading communication packets
2024-01-22T02:44:46.757788Z 0 [ERROR] mysqld: Got an error reading communication packets
2024-01-22T02:44:48.191324Z 2 [Warning] Timeout waiting for reply of binlog (file: mysql-bin.000003, pos: 15091), semi-sync up to file mysql-bin.000003, position 14900.
2024-01-22T02:44:51.152139Z 0 [ERROR] mysqld: Got an error reading communication packets
2024-01-22T02:45:05.753377Z 0 [ERROR] mysqld: Got an error reading communication packets
2024-01-22T02:45:08.192290Z 2 [Warning] Timeout waiting for reply of binlog (file: mysql-bin.000003, pos: 16725), semi-sync up to file mysql-bin.000003, position 16534.
2024-01-22T02:45:12.249725Z 0 [ERROR] mysqld: Got an error reading communication packets
2024-01-22T02:45:25.353530Z 0 [ERROR] mysqld: Got an error reading communication packets
2024-01-22T02:45:28.191214Z 2 [Warning] Timeout waiting for reply of binlog (file: mysql-bin.000003, pos: 18359), semi-sync up to file mysql-bin.000003, position 18168.
2024-01-22T02:45:31.855764Z 0 [ERROR] mysqld: Got an error reading communication packets
2024-01-22T02:45:46.359028Z 0 [ERROR] mysqld: Got an error reading communication packets
2024-01-22T02:45:48.192970Z 2 [Warning] Timeout waiting for reply of binlog (file: mysql-bin.000003, pos: 19993), semi-sync up to file mysql-bin.000003, position 19802.
2024-01-22T02:45:51.258541Z 0 [ERROR] mysqld: Got an error reading communication packets
2024-01-22T02:46:08.054776Z 0 [ERROR] mysqld: Got an error reading communication packets
2024-01-22T02:46:11.251134Z 0 [ERROR] mysqld: Got an error reading communication packets
2024-01-22T02:46:26.456802Z 0 [ERROR] mysqld: Got an error reading communication packets
2024-01-22T02:46:28.196971Z 2 [Warning] Timeout waiting for reply of binlog (file: mysql-bin.000003, pos: 23261), semi-sync up to file mysql-bin.000003, position 23070.
2024-01-22T02:46:31.168643Z 0 [ERROR] mysqld: Got an error reading communication packets
2024-01-22T02:46:45.555587Z 0 [ERROR] mysqld: Got an error reading communication packets
2024-01-22T02:46:48.204199Z 2 [Warning] Timeout waiting for reply of binlog (file: mysql-bin.000003, pos: 24895), semi-sync up to file mysql-bin.000003, position 24704.
2024-01-22T02:46:51.956801Z 0 [ERROR] mysqld: Got an error reading communication packets
2024-01-22T02:47:04.652804Z 0 [ERROR] mysqld: Got an error reading communication packets
2024-01-22T02:47:33.648701Z 0 [ERROR] mysqld: Got an error reading communication packets
2024-01-22T02:47:38.248570Z 2 [Warning] Timeout waiting for reply of binlog (file: mysql-bin.000003, pos: 28980), semi-sync up to file mysql-bin.000003, position 28789.
2024-01-22T02:48:21.886086Z 0 [ERROR] mysqld: Got an error reading communication packets
2024-01-22T02:48:49.262363Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2024-01-22T02:48:49.262453Z 0 [Warning] 'NO_AUTO_CREATE_USER' sql mode was not set.
2024-01-22T02:48:50.192419Z 0 [Warning] A deprecated TLS version TLSv1 is enabled. Please use TLSv1.2 or higher.
2024-01-22T02:48:50.192560Z 0 [Warning] A deprecated TLS version TLSv1.1 is enabled. Please use TLSv1.2 or higher.
2024-01-22T02:48:50.197845Z 0 [Warning] CA certificate ca.pem is self signed.
2024-01-22T02:48:50.257898Z 0 [Warning] Insecure configuration for --pid-file: Location '/var/run/mysqld' in the path is accessible to all OS users. Consider choosing a different directory.
2024-01-22T02:48:54.163251Z 3 [Warning] Storing MySQL user name or password information in the master info repository is not secure and is therefore not recommended. Please consider using the USER and PASSWORD connection options for START SLAVE; see the 'START SLAVE Syntax' in the MySQL Manual for more information.
2024-01-22T02:48:54.165343Z 4 [Warning] Slave SQL for channel '': If a crash happens this configuration does not guarantee that the relay log info will be consistent, Error_code: 0
/ #

Expected behavior A clear and concise description of what you expected to happen.

Screenshots If applicable, add screenshots to help explain your problem.

Desktop (please complete the following information):

Additional context Add any other context about the problem here.

sophon-zt commented 8 months ago

related issue: #6513