Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Cannot Reproduce
-
2.3.2
Description
maxscale takes high cpu usage even if after restarting maxscale with appermaxscale-cdc-adapter
the problem is that after restarting the maxscale service the CPU usage become again 100%
and cannot connect mysql in order to restart Slave
last received Errors before the occurrence of the 100% CPU usage in maxscale process:
localhost.localdomain maxscale[12791]: No event received from master [172.20.3.11]:3306 in heartbeat period (300 seconds), last event (Query Event 2) received 309 seconds ago. Assuming connection is dead and reconnecting.
localhost.localdomain maxscale[12791]: replication-router: failed to connect to master server 'binlog_router_master_host', retrying in 10 seconds
[root@localhost 12791]# top -bH -d 5 -n 1 -p 12791
|
top - 12:53:52 up 44 days, 23:52, 2 users, load average: 2.00, 1.98, 1.95
|
Threads: 3 total, 1 running, 2 sleeping, 0 stopped, 0 zombie
|
%Cpu(s): 51.6 us, 0.0 sy, 0.0 ni, 48.4 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st
|
KiB Mem : 2495632 total, 119740 free, 575516 used, 1800376 buff/cache
|
KiB Swap: 1048572 total, 1043932 free, 4640 used. 1593792 avail Mem
|
|
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
|
12791 maxscale 20 0 721036 451336 5048 R 99.9 18.1 8693:33 maxscale
|
12792 maxscale 20 0 721036 451336 5048 S 0.0 18.1 13:12.90 maxscale
|
12793 maxscale 20 0 721036 451336 5048 S 0.0 18.1 0:00.00 MHD-single
|
|
|
[root@localhost ~]# service maxscale status
|
Redirecting to /bin/systemctl status maxscale.service
|
● maxscale.service - MariaDB MaxScale Database Proxy
|
Loaded: loaded (/usr/lib/systemd/system/maxscale.service; disabled; vendor preset: disabled)
|
Active: active (running) since Thu 2018-12-20 17:16:59 EET; 2 weeks 6 days ago
|
Process: 12789 ExecStart=/usr/bin/maxscale (code=exited, status=0/SUCCESS)
|
Process: 12788 ExecStartPre=/usr/bin/install -d /var/run/maxscale -o maxscale -g maxscale (code=exited, status=0/SUCCESS)
|
Main PID: 12791 (maxscale)
|
CGroup: /system.slice/maxscale.service
|
└─12791 /usr/bin/maxscale
|
|
Dec 21 15:32:41 localhost.localdomain maxscale[12791]: (2) avro-router: new connection from [::ffff:172.20.2.237]
|
Dec 21 15:33:37 localhost.localdomain maxscale[12791]: (2) avro-router: new connection from [::ffff:172.20.2.237]
|
Dec 21 15:46:11 localhost.localdomain maxscale[12791]: (2) avro-router: new connection from [::ffff:127.0.0.1]
|
Dec 21 15:46:11 localhost.localdomain maxscale[12791]: (2) avro-router: new connection from [::ffff:127.0.0.1]
|
Dec 21 15:46:32 localhost.localdomain maxscale[12791]: (2) avro-router: new connection from [::ffff:127.0.0.1]
|
Dec 21 15:46:32 localhost.localdomain maxscale[12791]: (2) avro-router: new connection from [::ffff:127.0.0.1]
|
Dec 21 15:49:32 localhost.localdomain maxscale[12791]: (2) avro-router: new connection from [::ffff:127.0.0.1]
|
Dec 21 15:49:32 localhost.localdomain maxscale[12791]: (2) avro-router: new connection from [::ffff:127.0.0.1]
|
Jan 04 12:12:54 localhost.localdomain maxscale[12791]: No event received from master [172.20.3.11]:3306 in heartbeat period (300 seconds), last event (Query Event 2) received 309 seconds ago. Assuming connection is dead and reconnecting.
|
Jan 04 12:12:54 localhost.localdomain maxscale[12791]: replication-router: failed to connect to master server 'binlog_router_master_host', retrying in 10 seconds
|
|
- systemctl restart maxscale
MariaDB MaxScale /var/log/maxscale/maxscale.log Thu Jan 10 14:51:55 2019
----------------------------------------------------------------------------
2019-01-10 14:51:55 notice : syslog logging is enabled.
2019-01-10 14:51:55 notice : maxlog logging is enabled.
2019-01-10 14:51:55 notice : Using up to 974.86MiB of memory for query classifier cache
2019-01-10 14:51:55 notice : Working directory: /var/log/maxscale
2019-01-10 14:51:55 notice : The collection of SQLite memory allocation statistics turned off.
2019-01-10 14:51:55 notice : Threading mode of SQLite set to Multi-thread.
2019-01-10 14:51:55 notice : MariaDB MaxScale 2.3.1 started (Commit: c552845fd1264ba0d18ecbf8d6a7aa3c1b09a1b0)
2019-01-10 14:51:55 notice : MaxScale is running in process 31203
2019-01-10 14:51:55 notice : Configuration file: /etc/maxscale.cnf
2019-01-10 14:51:55 notice : Log directory: /var/log/maxscale
2019-01-10 14:51:55 notice : Data directory: /var/lib/maxscale
2019-01-10 14:51:55 notice : Module directory: /usr/lib64/maxscale
2019-01-10 14:51:55 notice : Service cache: /var/cache/maxscale
2019-01-10 14:51:55 notice : No query classifier specified, using default 'qc_sqlite'.
2019-01-10 14:51:55 notice : Loaded module qc_sqlite: V1.0.0 from /usr/lib64/maxscale/libqc_sqlite.so
2019-01-10 14:51:55 notice : Query classification results are cached and reused. Memory used per thread: 974.86MiB
2019-01-10 14:51:55 notice : Loading /etc/maxscale.cnf.
2019-01-10 14:51:55 notice : /etc/maxscale.cnf.d does not exist, not reading.
2019-01-10 14:51:55 notice : Loaded module cdc: V1.0.0 from /usr/lib64/maxscale/libcdc.so
2019-01-10 14:51:55 notice : Loaded module avrorouter: V1.0.0 from /usr/lib64/maxscale/libavrorouter.so
2019-01-10 14:51:55 warning: Protocol module 'mysqlclient' has been deprecated, use 'mariadbclient' instead.
2019-01-10 14:51:55 notice : Loaded module mariadbclient: V1.1.0 from /usr/lib64/maxscale/libmariadbclient.so
2019-01-10 14:51:55 notice : Initialise binlog router module.
2019-01-10 14:51:55 notice : Loaded module binlogrouter: V2.1.0 from /usr/lib64/maxscale/libbinlogrouter.so
2019-01-10 14:51:55 warning: The parameter 'passwd' is deprecated: use 'password' instead
2019-01-10 14:51:55 notice : replication-router: storing binlog files in 'flat' mode
2019-01-10 14:51:55 notice : replication-router: Service has MariaDB GTID otion set to ON
2019-01-10 14:51:55 notice : Loaded module MySQLBackendAuth: V1.0.0 from /usr/lib64/maxscale/libmysqlbackendauth.so
2019-01-10 14:51:55 notice : Validating last binlog file 'mariadb-bin.000002' ...
2019-01-10 14:51:55 notice : 1546970120 @ 256, GTID List Event, (Tue Jan 8 19:55:20 2019), First EventTime
2019-01-10 14:51:55 notice : 1547063835 @ 18947317, Write Rows Event (v1), (Wed Jan 9 21:57:15 2019), Last EventTime
2019-01-10 14:51:55 notice : Transaction Summary for binlog 'mariadb-bin.000002'
Description Total Average Max
No. of Transactions 601
No. of Events 1106 1.8 8
No. of Bytes 18.1M 30.8k 342.2k
2019-01-10 14:51:55 warning: Binlog file mariadb-bin.000002 contains a previous Opened Transaction @ 18750360. This pos is safe for slaves
2019-01-10 14:51:55 error : Binlog 'mariadb-bin.000002' ends at position 19012892 and has an incomplete transaction at 18750360.
2019-01-10 14:51:55 notice : Loaded module MySQLAuth: V1.1.0 from /usr/lib64/maxscale/libmysqlauth.so
2019-01-10 14:51:55 notice : Reading MySQL binlog files from /var/lib/maxscale
2019-01-10 14:51:55 notice : Avro files stored at: /var/lib/maxscale
2019-01-10 14:51:55 notice : First binlog is: mariadb-bin.000001
2019-01-10 14:51:55 notice : [avro-router] Loading stored conversion state: /var/lib/maxscale/avro-conversion.ini
2019-01-10 14:51:55 notice : Loaded stored binary log conversion state: File: [mariadb-bin.000001] Position: [158752] GTID: [0-1-635:0]
2019-01-10 14:51:55 notice : Loaded module CDCPlainAuth: V1.1.0 from /usr/lib64/maxscale/libcdcplainauth.so
2019-01-10 14:51:55 notice : Housekeeper thread started.
2019-01-10 14:51:55 notice : Starting a total of 2 services...
2019-01-10 14:51:55 notice : Encrypted password file /var/lib/maxscale/.secrets can't be accessed (No such file or directory). Password encryption is not used.
2019-01-10 14:51:55 notice : [replication-router] Loaded 4 MySQL users for listener replication-listener.
2019-01-10 14:51:55 notice : Listening for connections at [::]:6603 with protocol MySQL
2019-01-10 14:51:55 notice : Service 'replication-router' started (1/2)
2019-01-10 14:51:55 notice : Listening for connections at [::]:4001 with protocol CDC
2019-01-10 14:51:55 notice : Service 'avro-router' started (2/2)
2019-01-10 14:51:55 notice : Started REST API on [127.0.0.1]:8989
2019-01-10 14:51:55 notice : MaxScale started with 1 worker threads, each with a stack size of 8388608 bytes.
2019-01-10 14:51:55 warning: Protocol module 'mysqlbackend' has been deprecated, use 'mariadbbackend' instead.
2019-01-10 14:51:55 notice : Loaded module mariadbbackend: V2.0.0 from /usr/lib64/maxscale/libmariadbbackend.so
2019-01-10 14:51:55 notice : replication-router: attempting to connect to master server [172.20.3.11]:3306, binlog='mariadb-bin.000002', pos=19012892
2019-01-10 14:51:55 notice : (3) replication-router: Request binlog records from mariadb-bin.000002 at position 19012892 from master server [172.20.3.11]:3306
2019-01-10 14:51:55 notice : (3) replication-router: identity seen by the master: Server_id: 2, Slave_UUID: 829380de-14d6-11e9-bb36-001a4a16016b, Host: not set
2019-01-10 14:51:55 notice : (3) replication-router: identity seen by the slaves: server_id: 1, hostname: tx-ref, MySQL version: 10.3.10-MariaDB-log
2019-01-10 14:51:55 error : (3) Error packet in binlog stream (mariadb-bin.000002@19012892): Could not find first log file name in binary log index file
2019-01-10 14:51:55 notice : (3) replication-router: Master 172.20.3.11 disconnected after 0 seconds. 1 events read.
[root@localhost ~]# top
|
top - 14:57:27 up 45 days, 1:56, 4 users, load average: 2.00, 1.97, 1.95
|
Tasks: 118 total, 2 running, 111 sleeping, 5 stopped, 0 zombie
|
%Cpu(s): 50.0 us, 0.2 sy, 0.0 ni, 49.8 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st
|
KiB Mem : 2495632 total, 530240 free, 145956 used, 1819436 buff/cache
|
KiB Swap: 1048572 total, 1043932 free, 4640 used. 2023116 avail Mem
|
|
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
|
31203 maxscale 20 0 242960 10256 4240 R 100.0 0.4 5:30.79 maxscale
|
16005 root 20 0 0 0 0 S 0.3 0.0 5:56.37 kworker/1:1
|
1 root 20 0 51688 3620 2380 S 0.0 0.1 6:44.61 systemd
|
2 root 20 0 0 0 0 S 0.0 0.0 0:00.24 kthreadd
|
3 root 20 0 0 0 0 S 0.0 0.0 0:02.16 ksoftirqd/0
|
5 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 kworker/0:0H
|
7 root rt 0 0 0 0 S 0.0 0.0 0:24.84 migration/0
|
8 root 20 0 0 0 0 S 0.0 0.0 0:00.00 rcu_bh
|
9 root 20 0 0 0 0 S 0.0 0.0 2:58.60 rcu_sched
|
10 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 lru-add-drain
|
11 root rt 0 0 0 0 S 0.0 0.0 0:14.98 watchdog/0
|
12 root rt 0 0 0 0 S 0.0 0.0 0:13.55 watchdog/1
|
13 root rt 0 0 0 0 S 0.0 0.0 0:25.42 migration/1
|
14 root 20 0 0 0 0 S 0.0 0.0 0:02.10 ksoftirqd/1
|
16 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 kworker/1:0H
|
18 root 20 0 0 0 0 S 0.0 0.0 0:00.00 kdevtmpfs
|
19 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 netns
|
[root@localhost ~]# top -bH -d 5 -n 10 -p 31203
|
top - 14:57:39 up 45 days, 1:56, 4 users, load average: 1.92, 1.96, 1.95
|
Threads: 3 total, 1 running, 2 sleeping, 0 stopped, 0 zombie
|
%Cpu(s): 50.0 us, 0.0 sy, 0.0 ni, 50.0 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st
|
KiB Mem : 2495632 total, 530116 free, 146080 used, 1819436 buff/cache
|
KiB Swap: 1048572 total, 1043932 free, 4640 used. 2022992 avail Mem
|
|
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
|
31203 maxscale 20 0 242960 10256 4240 R 99.9 0.4 5:42.15 maxscale
|
31204 maxscale 20 0 242960 10256 4240 S 0.0 0.4 0:00.03 maxscale
|
31205 maxscale 20 0 242960 10256 4240 S 0.0 0.4 0:00.00 MHD-single
|
|
top - 14:57:44 up 45 days, 1:56, 4 users, load average: 1.93, 1.96, 1.95
|
Threads: 3 total, 1 running, 2 sleeping, 0 stopped, 0 zombie
|
%Cpu(s): 50.0 us, 0.1 sy, 0.0 ni, 49.9 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st
|
KiB Mem : 2495632 total, 529992 free, 146204 used, 1819436 buff/cache
|
KiB Swap: 1048572 total, 1043932 free, 4640 used. 2022868 avail Mem
|
|
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
|
31203 maxscale 20 0 242960 10256 4240 R 99.8 0.4 5:47.15 maxscale
|
31204 maxscale 20 0 242960 10256 4240 S 0.0 0.4 0:00.03 maxscale
|
31205 maxscale 20 0 242960 10256 4240 S 0.0 0.4 0:00.00 MHD-single
|
|