Uploaded image for project: 'MariaDB MaxScale'
  1. MariaDB MaxScale
  2. MXS-2254

maxscale takes high cpu usage even if after restarting maxscale with appermaxscale-cdc-adapter

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Closed (View Workflow)
    • Priority: Major
    • Resolution: Cannot Reproduce
    • Affects Version/s: 2.3.2
    • Fix Version/s: N/A
    • Component/s: N/A
    • Labels:
    • Environment:

      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
      
      

      1. 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
      
      

        Attachments

        1. BIN.7z
          51 kB
        2. mariadb-bin.000001
          155 kB
        3. maxscale.cnf
          1 kB

          Activity

            People

            Assignee:
            markus makela markus makela
            Reporter:
            winstone Zdravelina Sokolovska
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

              Dates

              Created:
              Updated:
              Resolved: