db1176 is meant to be placed in s6 eqiad. But let's try mariadb 11 first on that host and move it to s1.
Description
Details
Status | Subtype | Assigned | Task | ||
---|---|---|---|---|---|
Open | • Marostegui | T326206 Move db1176 and db2151 to s6 | |||
Open | • Marostegui | T326116 Package and test MariaDB 11 | |||
Resolved | • Marostegui | T326211 Install MariaDB 11 on db1176 |
Event Timeline
Change 875458 had a related patch set uploaded (by Marostegui; author: Marostegui):
[operations/puppet@production] db1176: Productionize db1176
Mentioned in SAL (#wikimedia-operations) [2023-01-05T06:41:54Z] <marostegui@cumin1001> dbctl commit (dc=all): 'Depool db1134 to clone db1176 T326211', diff saved to https://phabricator.wikimedia.org/P42833 and previous config saved to /var/cache/conftool/dbconfig/20230105-064153-marostegui.json
Change 875459 had a related patch set uploaded (by Marostegui; author: Marostegui):
[operations/puppet@production] db1134: Disable notifications
Change 875459 merged by Marostegui:
[operations/puppet@production] db1134: Disable notifications
Change 875458 merged by Marostegui:
[operations/puppet@production] mariadb: Productionize db1176 into s1
Change 875808 had a related patch set uploaded (by Marostegui; author: Marostegui):
[operations/puppet@production] db1176: Install MariaDB 11
Change 875808 merged by Marostegui:
[operations/puppet@production] db1176: Install MariaDB 11
The first start looks good (errors are expected but nothing to worry about at the moment)
Jan 05 09:30:02 db1176 mysqld[187808]: /opt/wmf-mariadb110/bin/mysqld: Deprecated program name. It will be removed in a future release, use '/opt/wmf-mariadb110/bin/mariadbd' instead Jan 05 09:30:02 db1176 mysqld[187808]: 2023-01-05 9:30:02 0 [Note] /opt/wmf-mariadb110/bin/mysqld (server 11.0.0-MariaDB-log) starting as process 187808 ... Jan 05 09:30:02 db1176 mysqld[187808]: 2023-01-05 9:30:02 0 [Warning] No argument was provided to --log-bin and neither --log-basename or --log-bin-index where used; This may cause repliction to break when this server acts as a master and has its hostname changed! Please use '--log-basename=db1176' or '--log-bin=db1176-bin' to avoid this problem. Jan 05 09:30:02 db1176 mysqld[187808]: 2023-01-05 9:30:02 0 [Note] InnoDB: Compressed tables use zlib 1.2.12 Jan 05 09:30:02 db1176 mysqld[187808]: 2023-01-05 9:30:02 0 [Note] InnoDB: Number of transaction pools: 1 Jan 05 09:30:02 db1176 mysqld[187808]: 2023-01-05 9:30:02 0 [Note] InnoDB: Using crc32 + pclmulqdq instructions Jan 05 09:30:02 db1176 mysqld[187808]: 2023-01-05 9:30:02 0 [Note] InnoDB: Using Linux native AIO Jan 05 09:30:02 db1176 mysqld[187808]: 2023-01-05 9:30:02 0 [Note] InnoDB: Initializing buffer pool, total size = 377.000GiB, chunk size = 5.891GiB Jan 05 09:30:04 db1176 mysqld[187808]: 2023-01-05 9:30:04 0 [Note] InnoDB: Completed initialization of buffer pool Jan 05 09:30:04 db1176 mysqld[187808]: 2023-01-05 9:30:04 0 [Note] InnoDB: File system buffers for log disabled (block size=4096 bytes) Jan 05 09:30:04 db1176 mysqld[187808]: 2023-01-05 9:30:04 0 [Note] InnoDB: Upgrading redo log: 2.000GiB; LSN=84798503018363 Jan 05 09:30:04 db1176 mysqld[187808]: 2023-01-05 9:30:04 0 [Note] InnoDB: File system buffers for log disabled (block size=4096 bytes) Jan 05 09:30:05 db1176 mysqld[187808]: 2023-01-05 9:30:05 0 [Note] InnoDB: Upgrading the change buffer Jan 05 09:31:07 db1176 mysqld[187808]: 2023-01-05 9:31:07 0 [Note] InnoDB: Upgraded the change buffer: 0 tablespaces, 0 pages Jan 05 09:31:08 db1176 mysqld[187808]: 2023-01-05 9:31:08 0 [Note] InnoDB: Reinitializing innodb_undo_tablespaces= 3 from 0 Jan 05 09:31:08 db1176 mysqld[187808]: 2023-01-05 9:31:08 0 [Note] InnoDB: Data file .//undo001 did not exist: new to be created Jan 05 09:31:08 db1176 mysqld[187808]: 2023-01-05 9:31:08 0 [Note] InnoDB: Setting file .//undo001 size to 10.000MiB Jan 05 09:31:08 db1176 mysqld[187808]: 2023-01-05 9:31:08 0 [Note] InnoDB: Database physically writes the file full: wait... Jan 05 09:31:08 db1176 mysqld[187808]: 2023-01-05 9:31:08 0 [Note] InnoDB: Data file .//undo002 did not exist: new to be created Jan 05 09:31:08 db1176 mysqld[187808]: 2023-01-05 9:31:08 0 [Note] InnoDB: Setting file .//undo002 size to 10.000MiB Jan 05 09:31:08 db1176 mysqld[187808]: 2023-01-05 9:31:08 0 [Note] InnoDB: Database physically writes the file full: wait... Jan 05 09:31:08 db1176 mysqld[187808]: 2023-01-05 9:31:08 0 [Note] InnoDB: Data file .//undo003 did not exist: new to be created Jan 05 09:31:08 db1176 mysqld[187808]: 2023-01-05 9:31:08 0 [Note] InnoDB: Setting file .//undo003 size to 10.000MiB Jan 05 09:31:08 db1176 mysqld[187808]: 2023-01-05 9:31:08 0 [Note] InnoDB: Database physically writes the file full: wait... Jan 05 09:31:08 db1176 mysqld[187808]: 2023-01-05 9:31:08 0 [Note] InnoDB: 128 rollback segments in 3 undo tablespaces are active. Jan 05 09:31:08 db1176 mysqld[187808]: 2023-01-05 9:31:08 0 [Note] InnoDB: Setting file './ibtmp1' size to 12.000MiB. Physically writing the file full; Please wait ... Jan 05 09:31:08 db1176 mysqld[187808]: 2023-01-05 9:31:08 0 [Note] InnoDB: File './ibtmp1' size is now 12.000MiB. Jan 05 09:31:08 db1176 mysqld[187808]: 2023-01-05 9:31:08 0 [Note] InnoDB: log sequence number 84798503018363; transaction id 211863277513 Jan 05 09:31:08 db1176 mysqld[187808]: 2023-01-05 9:31:08 0 [Note] InnoDB: Loading buffer pool(s) from /srv/sqldata/ib_buffer_pool Jan 05 09:31:08 db1176 mysqld[187808]: 2023-01-05 9:31:08 0 [ERROR] WSREP: plugin-wsrep-provider can't be enabled if wsrep_on==OFF or wsrep_provider is unset or set to 'none' Jan 05 09:31:08 db1176 mysqld[187808]: 2023-01-05 9:31:08 0 [ERROR] mysqld: plugin-wsrep-provider can't be enabled if wsrep_on==OFF or wsrep_provider is unset or set to 'none' Jan 05 09:31:08 db1176 mysqld[187808]: 2023-01-05 9:31:08 0 [ERROR] Plugin 'wsrep_provider' init function returned error. Jan 05 09:31:08 db1176 mysqld[187808]: 2023-01-05 9:31:08 0 [Warning] 'innodb-change-buffering' was removed. It does nothing now and exists only for compatibility with old my.cnf files. Jan 05 09:31:08 db1176 mysqld[187808]: 2023-01-05 9:31:08 0 [Note] Server socket created on IP: '0.0.0.0'. Jan 05 09:31:08 db1176 mysqld[187808]: 2023-01-05 9:31:08 0 [Note] Server socket created on IP: '::'. Jan 05 09:31:08 db1176 mysqld[187808]: 2023-01-05 9:31:08 0 [Note] Server socket created on IP: '0.0.0.0'. Jan 05 09:31:08 db1176 mysqld[187808]: 2023-01-05 9:31:08 0 [Note] Server socket created on IP: '::'. Jan 05 09:31:08 db1176 mysqld[187808]: 2023-01-05 9:31:08 0 [ERROR] Incorrect definition of table mysql.event: expected column 'definer' at position 3 to have type varchar(, found type char(141). Jan 05 09:31:08 db1176 mysqld[187808]: 2023-01-05 9:31:08 0 [ERROR] mysqld: Event Scheduler: An error occurred when initializing system tables. Disabling the Event Scheduler. Jan 05 09:31:08 db1176 mysqld[187808]: 2023-01-05 9:31:08 0 [Warning] Neither --relay-log nor --relay-log-index were used; so replication may break when this MariaDB server acts as a replica and has its hostname changed. Please use '--log-basename=#' or '--relay-log=db1176-relay-bin' to avoid this problem. Jan 05 09:31:08 db1176 mysqld[187808]: 2023-01-05 9:31:08 0 [Note] /opt/wmf-mariadb110/bin/mysqld: ready for connections. Jan 05 09:31:08 db1176 mysqld[187808]: Version: '11.0.0-MariaDB-log' socket: '/run/mysqld/mysqld.sock' port: 3306 MariaDB Server Jan 05 09:31:08 db1176 systemd[1]: Started mariadb database server. ░░ Subject: A start job for unit mariadb.service has finished successfully ░░ Defined-By: systemd ░░ Support: https://www.debian.org/support ░░ ░░ A start job for unit mariadb.service has finished successfully. ░░ ░░ The job identifier is 174540. Jan 05 09:31:12 db1176 mysqld[187808]: 2023-01-05 9:31:12 6 [ERROR] Incorrect definition of table mysql.column_stats: expected column 'hist_type' at position 9 to have type enum('SINGLE_PREC_HB','DOUBLE_PREC_HB','JSON_HB'), found type enum('SINGLE_PREC_HB','DOUBLE_PREC_HB'). Jan 05 09:31:12 db1176 mysqld[187808]: 2023-01-05 9:31:12 6 [ERROR] Incorrect definition of table mysql.column_stats: expected column 'histogram' at position 10 to have type longblob, found type varbinary(255). Jan 05 09:31:18 db1176 mysqld[187808]: 2023-01-05 9:31:18 5 [ERROR] Incorrect definition of table mysql.column_stats: expected column 'hist_type' at position 9 to have type enum('SINGLE_PREC_HB','DOUBLE_PREC_HB','JSON_HB'), found type enum('SINGLE_PREC_HB','DOUBLE_PREC_HB'). Jan 05 09:31:18 db1176 mysqld[187808]: 2023-01-05 9:31:18 5 [ERROR] Incorrect definition of table mysql.column_stats: expected column 'histogram' at position 10 to have type longblob, found type varbinary(255). Jan 05 09:31:20 db1176 mysqld[187808]: 2023-01-05 9:31:20 13 [ERROR] Incorrect definition of table mysql.proc: expected column 'definer' at position 11 to have type varchar(, found type char(141). Jan 05 09:31:21 db1176 mysqld[187808]: 2023-01-05 9:31:21 15 [Note] Event Scheduler: scheduler thread started with id 15 Jan 05 09:31:40 db1176 mysqld[187808]: 2023-01-05 9:31:40 29 [Note] Slave I/O thread: Start semi-sync replication to master 'repl@db1118.eqiad.wmnet:3306' in log 'db1118-bin.003096' at position 815797178 Jan 05 09:31:40 db1176 mysqld[187808]: 2023-01-05 9:31:40 29 [Note] Slave I/O thread: connected to master 'repl@db1118.eqiad.wmnet:3306',replication starts at GTID position '180355171-180355171-148310907,180359172-180359172-49702203,171970637-171970637-2116621969,180363268-180363268-1082287825,171970661-171970661-3655324752,171974720-171974720-2572451842,171970745-171970745-2419896119,171978774-171978774-5,0-171970637-5484646134,171970572-171970572-3158188397' Jan 05 09:32:18 db1176 mysqld[187808]: 2023-01-05 9:32:18 0 [Note] InnoDB: Buffer pool(s) load completed at 230105 9:32:18 Jan 05 09:32:29 db1176 systemd[1]: Stopping mariadb database server... ░░ Subject: A stop job for unit mariadb.service has begun execution ░░ Defined-By: systemd ░░ Support: https://www.debian.org/support ░░ ░░ A stop job for unit mariadb.service has begun execution. ░░ ░░ The job identifier is 174882. Jan 05 09:32:29 db1176 mysqld[187808]: 2023-01-05 9:32:29 0 [Note] /opt/wmf-mariadb110/bin/mysqld (initiated by: unknown): Normal shutdown Jan 05 09:32:29 db1176 mysqld[187808]: 2023-01-05 9:32:29 0 [Note] Event Scheduler: Killing the scheduler thread, thread id 15 Jan 05 09:32:29 db1176 mysqld[187808]: 2023-01-05 9:32:29 0 [Note] Event Scheduler: Waiting for the scheduler thread to reply Jan 05 09:32:29 db1176 mysqld[187808]: 2023-01-05 9:32:29 0 [Note] Event Scheduler: Stopped Jan 05 09:32:29 db1176 mysqld[187808]: 2023-01-05 9:32:29 0 [Note] Event Scheduler: Purging the queue. 4 events Jan 05 09:32:29 db1176 mysqld[187808]: 2023-01-05 9:32:29 30 [Note] Slave SQL thread exiting, replication stopped in log 'db1118-bin.003096' at position 823896081; GTID position '0-171970637-5484646134,171970572-171970572-3158205537,171970637-171970637-2116621969,171970661-171970661-3655324752,171970745-171970745-2419896119,171974720-171974720-2572451842,171978774-171978774-5,180355171-180355171-148310907,180359172-180359172-49702203,180363268-180363268-1082287825', master: db1118.eqiad.wmnet:3306 Jan 05 09:32:29 db1176 mysqld[187808]: 2023-01-05 9:32:29 29 [Note] Slave I/O thread exiting, read up to log 'db1118-bin.003096', position 826756910; GTID position 180355171-180355171-148310907,180359172-180359172-49702203,171970637-171970637-2116621969,180363268-180363268-1082287825,171970661-171970661-3655324752,171974720-171974720-2572451842,171970745-171970745-2419896119,171978774-171978774-5,0-171970637-5484646134,171970572-171970572-3158212259, master db1118.eqiad.wmnet:3306 Jan 05 09:32:29 db1176 mysqld[187808]: 2023-01-05 9:32:29 0 [Note] InnoDB: FTS optimize thread exiting. Jan 05 09:32:29 db1176 mysqld[187808]: 2023-01-05 9:32:29 0 [Note] InnoDB: Starting shutdown... Jan 05 09:32:29 db1176 mysqld[187808]: 2023-01-05 9:32:29 0 [Note] InnoDB: Dumping buffer pool(s) to /srv/sqldata/ib_buffer_pool Jan 05 09:32:30 db1176 mysqld[187808]: 2023-01-05 9:32:30 0 [Note] InnoDB: Buffer pool(s) dump completed at 230105 9:32:30 Jan 05 09:32:34 db1176 mysqld[187808]: 2023-01-05 9:32:34 0 [Note] InnoDB: Removed temporary tablespace data file: "./ibtmp1" Jan 05 09:32:34 db1176 mysqld[187808]: 2023-01-05 9:32:34 0 [Note] InnoDB: Shutdown completed; log sequence number 84798584845712; transaction id 211863312472 Jan 05 09:32:34 db1176 mysqld[187808]: 2023-01-05 9:32:34 0 [Note] /opt/wmf-mariadb110/bin/mysqld: Shutdown complete
A restart after mysql_upgrade:
Jan 05 09:32:55 db1176 mysqld[189693]: /opt/wmf-mariadb110/bin/mysqld: Deprecated program name. It will be removed in a future release, use '/opt/wmf-mariadb110/bin/mariadbd' instead Jan 05 09:32:55 db1176 mysqld[189693]: 2023-01-05 9:32:55 0 [Note] /opt/wmf-mariadb110/bin/mysqld (server 11.0.0-MariaDB-log) starting as process 189693 ... Jan 05 09:32:55 db1176 mysqld[189693]: 2023-01-05 9:32:55 0 [Warning] No argument was provided to --log-bin and neither --log-basename or --log-bin-index where used; This may cause repliction to break when this server acts as a master and has its hostname changed! Please use '--log-basename=db1176' or '--log-bin=db1176-bin' to avoid this problem. Jan 05 09:32:55 db1176 mysqld[189693]: 2023-01-05 9:32:55 0 [Note] InnoDB: Compressed tables use zlib 1.2.12 Jan 05 09:32:55 db1176 mysqld[189693]: 2023-01-05 9:32:55 0 [Note] InnoDB: Number of transaction pools: 1 Jan 05 09:32:55 db1176 mysqld[189693]: 2023-01-05 9:32:55 0 [Note] InnoDB: Using crc32 + pclmulqdq instructions Jan 05 09:32:55 db1176 mysqld[189693]: 2023-01-05 9:32:55 0 [Note] InnoDB: Using Linux native AIO Jan 05 09:32:55 db1176 mysqld[189693]: 2023-01-05 9:32:55 0 [Note] InnoDB: Initializing buffer pool, total size = 377.000GiB, chunk size = 5.891GiB ^[[AJan 05 09:32:57 db1176 mysqld[189693]: 2023-01-05 9:32:57 0 [Note] InnoDB: Completed initialization of buffer pool Jan 05 09:32:58 db1176 mysqld[189693]: 2023-01-05 9:32:58 0 [Note] InnoDB: Resetting space id's in the doublewrite buffer Jan 05 09:32:58 db1176 mysqld[189693]: 2023-01-05 9:32:58 0 [Note] InnoDB: File system buffers for log disabled (block size=4096 bytes) Jan 05 09:32:58 db1176 mysqld[189693]: 2023-01-05 9:32:58 0 [Note] InnoDB: Opened 3 undo tablespaces Jan 05 09:32:58 db1176 mysqld[189693]: 2023-01-05 9:32:58 0 [Note] InnoDB: 128 rollback segments in 3 undo tablespaces are active. Jan 05 09:32:58 db1176 mysqld[189693]: 2023-01-05 9:32:58 0 [Note] InnoDB: Setting file './ibtmp1' size to 12.000MiB. Physically writing the file full; Please wait ... Jan 05 09:32:58 db1176 mysqld[189693]: 2023-01-05 9:32:58 0 [Note] InnoDB: File './ibtmp1' size is now 12.000MiB. Jan 05 09:32:58 db1176 mysqld[189693]: 2023-01-05 9:32:58 0 [Note] InnoDB: log sequence number 84798584845712; transaction id 211863312473 Jan 05 09:32:58 db1176 mysqld[189693]: 2023-01-05 9:32:58 0 [Note] InnoDB: Loading buffer pool(s) from /srv/sqldata/ib_buffer_pool Jan 05 09:32:58 db1176 mysqld[189693]: 2023-01-05 9:32:58 0 [ERROR] WSREP: plugin-wsrep-provider can't be enabled if wsrep_on==OFF or wsrep_provider is unset or set to 'none' Jan 05 09:32:58 db1176 mysqld[189693]: 2023-01-05 9:32:58 0 [ERROR] mysqld: plugin-wsrep-provider can't be enabled if wsrep_on==OFF or wsrep_provider is unset or set to 'none' Jan 05 09:32:58 db1176 mysqld[189693]: 2023-01-05 9:32:58 0 [ERROR] Plugin 'wsrep_provider' init function returned error. Jan 05 09:32:58 db1176 mysqld[189693]: 2023-01-05 9:32:58 0 [Warning] 'innodb-change-buffering' was removed. It does nothing now and exists only for compatibility with old my.cnf files. Jan 05 09:32:58 db1176 mysqld[189693]: 2023-01-05 9:32:58 0 [Note] Server socket created on IP: '0.0.0.0'. Jan 05 09:32:58 db1176 mysqld[189693]: 2023-01-05 9:32:58 0 [Note] Server socket created on IP: '::'. Jan 05 09:32:58 db1176 mysqld[189693]: 2023-01-05 9:32:58 0 [Note] Server socket created on IP: '0.0.0.0'. Jan 05 09:32:58 db1176 mysqld[189693]: 2023-01-05 9:32:58 0 [Note] Server socket created on IP: '::'. Jan 05 09:32:58 db1176 mysqld[189693]: 2023-01-05 9:32:58 3 [Note] Event Scheduler: scheduler thread started with id 3 Jan 05 09:32:58 db1176 mysqld[189693]: 2023-01-05 9:32:58 0 [Warning] Neither --relay-log nor --relay-log-index were used; so replication may break when this MariaDB server acts as a replica and has its hostname changed. Please use '--log-basename=#' or '--relay-log=db1176-relay-bin' to avoid this problem. Jan 05 09:32:58 db1176 mysqld[189693]: 2023-01-05 9:32:58 0 [Note] /opt/wmf-mariadb110/bin/mysqld: ready for connections. Jan 05 09:32:58 db1176 mysqld[189693]: Version: '11.0.0-MariaDB-log' socket: '/run/mysqld/mysqld.sock' port: 3306 MariaDB Server Jan 05 09:32:58 db1176 systemd[1]: Started mariadb database server. ░░ Subject: A start job for unit mariadb.service has finished successfully ░░ Defined-By: systemd ░░ Support: https://www.debian.org/support ░░ ░░ A start job for unit mariadb.service has finished successfully. ░░ ░░ The job identifier is 174884. Jan 05 09:33:06 db1176 mysqld[189693]: 2023-01-05 9:33:06 13 [Note] Slave I/O thread: Start semi-sync replication to master 'repl@db1118.eqiad.wmnet:3306' in log 'db1118-bin.003096' at position 823896081 Jan 05 09:33:06 db1176 mysqld[189693]: 2023-01-05 9:33:06 13 [Note] Slave I/O thread: connected to master 'repl@db1118.eqiad.wmnet:3306',replication starts at GTID position '180355171-180355171-148310907,180359172-180359172-49702203,171970637-171970637-2116621969,180363268-180363268-1082287825,171970661-171970661-3655324752,171974720-171974720-2572451842,171970745-171970745-2419896119,171978774-171978774-5,0-171970637-5484646134,171970572-171970572-3158205537'
root@db1176:~/11.0# mysql -e "start slave" mysql: Deprecated program name. It will be removed in a future release, use '/opt/wmf-mariadb110/bin/mariadb' instead root@db1176:~/11.0# mariadb -e "stop slave; start slave;" root@db1176:~/11.0#
Some first tests with traditional slow queries, it shows that MariaDB 11 performs a lot better: