[MCOL-1193] Last Status Change of mysqld is not updated after Crash recovery - Jira

Details

Type: Bug
Status: Closed (View Workflow)
Priority: Minor
Resolution: Incomplete
Affects Version/s: 1.1.2
Fix Version/s: Icebox
Component/s: None
Labels:
None
Environment:
MCS run on VMs, Multi Server ColumnStore System UM1-PM1 ;guest OS RHEL 7.4

Description

Last Status Change of mysqld is not updated after Crash recovery in the output of the command mcsadmin getsystemi

to recreate easily: just get Last Status Change of mysqld ,
then kill mysqld, verify that it recovered and check Last Status Change again

added logs from hostname.err file --those are seen the mysqld Status Change events and timestamps

1.mcsadmin getsystemi before crash

[root@um1 ~]#  mcsadmin getsystemi

WARNING: running on non Parent OAM Module, can't make configuration changes in this session.

         Access Console from 'pm1' if you need to make changes.

getsysteminfo   Thu Feb  1 17:56:07 2018

System cs-1.1.0

System and Module statuses

Component     Status                       Last Status Change

------------  --------------------------   ------------------------

System        ACTIVE                       Mon Jan 29 01:38:21 2018

Module um1    ACTIVE                       Mon Jan 29 01:38:19 2018

Module pm1    ACTIVE                       Mon Jan 29 01:38:09 2018

Active Parent OAM Performance Module is 'pm1'

MariaDB ColumnStore Replication Feature is enabled

MariaDB ColumnStore Process statuses

Process             Module    Status            Last Status Change        Process ID

------------------  ------    ---------------   ------------------------  ----------

ProcessMonitor      um1       ACTIVE            Mon Jan 29 01:37:54 2018        1020

ServerMonitor       um1       ACTIVE            Mon Jan 29 01:38:06 2018        1334

DBRMWorkerNode      um1       ACTIVE            Mon Jan 29 01:38:07 2018        1359

ExeMgr              um1       ACTIVE            Mon Jan 29 01:38:12 2018        1563

DDLProc             um1       ACTIVE            Mon Jan 29 01:38:16 2018        1574

DMLProc             um1       ACTIVE            Mon Jan 29 01:38:20 2018        1583

mysqld              um1       ACTIVE            Mon Jan 29 01:38:10 2018

ProcessMonitor      pm1       ACTIVE            Mon Jan 29 01:37:43 2018        1014

ProcessManager      pm1       ACTIVE            Mon Jan 29 01:37:49 2018        1128

DBRMControllerNode  pm1       ACTIVE            Mon Jan 29 01:38:01 2018        1384

ServerMonitor       pm1       ACTIVE            Mon Jan 29 01:38:03 2018        1400

DBRMWorkerNode      pm1       ACTIVE            Mon Jan 29 01:38:03 2018        1435

DecomSvr            pm1       ACTIVE            Mon Jan 29 01:38:07 2018        1549

PrimProc            pm1       ACTIVE            Mon Jan 29 01:38:09 2018        1602

WriteEngineServer   pm1       ACTIVE            Mon Jan 29 01:38:10 2018        1638

Active Alarm Counts: Critical = 0, Major = 0, Minor = 0, Warning = 0, Info = 0

mysqld recovered

root@um1 ~]#  ps aux | grep mysql

root      1098  0.0  0.0 115396  1772 ?        S    Jan29   0:00 /bin/sh /usr/local/mariadb/columnstore/mysql//bin/mysqld_safe --datadir=/usr/local/mariadb/columnstore/mysql/db --pid-file=/usr/local/mariadb/columnstore/mysql/db/um1.xentio.lan.pid --ledir=/usr/local/mariadb/columnstore/mysql//bin

mysql    13440  0.0  0.2 2489672 173812 ?      Sl   16:29   0:02 /usr/local/mariadb/columnstore/mysql//bin/mysqld --basedir=/usr/local/mariadb/columnstore/mysql/ --datadir=/usr/local/mariadb/columnstore/mysql/db --plugin-dir=/usr/local/mariadb/columnstore/mysql/lib/plugin --user=mysql --log-error=/usr/local/mariadb/columnstore/mysql/db/um1.xentio.lan.err --pid-file=/usr/local/mariadb/columnstore/mysql/db/um1.xentio.lan.pid --socket=/usr/local/mariadb/columnstore/mysql/lib/mysql/mysql.sock --port=3306

root     13598  0.0  0.0 112660   972 pts/0    S+   17:57   0:00 grep --color=auto mysql

[root@um1 ~]# kill -9  13440

[root@um1 ~]#

[root@um1 ~]#

[root@um1 ~]#  ps aux | grep mysql

root      1098  0.0  0.0 115396  1772 ?        S    Jan29   0:00 /bin/sh /usr/local/mariadb/columnstore/mysql//bin/mysqld_safe --datadir=/usr/local/mariadb/columnstore/mysql/db --pid-file=/usr/local/mariadb/columnstore/mysql/db/um1.xentio.lan.pid --ledir=/usr/local/mariadb/columnstore/mysql//bin

mysql    13619  9.3  0.2 2423620 172340 ?      Sl   17:57   0:00 /usr/local/mariadb/columnstore/mysql//bin/mysqld --basedir=/usr/local/mariadb/columnstore/mysql/ --datadir=/usr/local/mariadb/columnstore/mysql/db --plugin-dir=/usr/local/mariadb/columnstore/mysql/lib/plugin --user=mysql --log-error=/usr/local/mariadb/columnstore/mysql/db/um1.xentio.lan.err --pid-file=/usr/local/mariadb/columnstore/mysql/db/um1.xentio.lan.pid --socket=/usr/local/mariadb/columnstore/mysql/lib/mysql/mysql.sock --port=3306

root     13654  0.0  0.0 112660   972 pts/0    S+   17:57   0:00 grep --color=auto mysql

[root@um1 ~]#

2. mcsadmin getsystemi after Crash recovery --Last Status Change of mysqld did not change

[root@um1 ~]#  mcsadmin getsystemi

WARNING: running on non Parent OAM Module, can't make configuration changes in this session.

         Access Console from 'pm1' if you need to make changes.

getsysteminfo   Thu Feb  1 17:57:46 2018

System cs-1.1.0

System and Module statuses

Component     Status                       Last Status Change

------------  --------------------------   ------------------------

System        ACTIVE                       Mon Jan 29 01:38:21 2018

Module um1    ACTIVE                       Mon Jan 29 01:38:19 2018

Module pm1    ACTIVE                       Mon Jan 29 01:38:09 2018

Active Parent OAM Performance Module is 'pm1'

MariaDB ColumnStore Replication Feature is enabled

MariaDB ColumnStore Process statuses

Process             Module    Status            Last Status Change        Process ID

------------------  ------    ---------------   ------------------------  ----------

ProcessMonitor      um1       ACTIVE            Mon Jan 29 01:37:54 2018        1020

ServerMonitor       um1       ACTIVE            Mon Jan 29 01:38:06 2018        1334

DBRMWorkerNode      um1       ACTIVE            Mon Jan 29 01:38:07 2018        1359

ExeMgr              um1       ACTIVE            Mon Jan 29 01:38:12 2018        1563

DDLProc             um1       ACTIVE            Mon Jan 29 01:38:16 2018        1574

DMLProc             um1       ACTIVE            Mon Jan 29 01:38:20 2018        1583

mysqld              um1       ACTIVE            Mon Jan 29 01:38:10 2018

ProcessMonitor      pm1       ACTIVE            Mon Jan 29 01:37:43 2018        1014

ProcessManager      pm1       ACTIVE            Mon Jan 29 01:37:49 2018        1128

DBRMControllerNode  pm1       ACTIVE            Mon Jan 29 01:38:01 2018        1384

ServerMonitor       pm1       ACTIVE            Mon Jan 29 01:38:03 2018        1400

DBRMWorkerNode      pm1       ACTIVE            Mon Jan 29 01:38:03 2018        1435

DecomSvr            pm1       ACTIVE            Mon Jan 29 01:38:07 2018        1549

PrimProc            pm1       ACTIVE            Mon Jan 29 01:38:09 2018        1602

WriteEngineServer   pm1       ACTIVE            Mon Jan 29 01:38:10 2018        1638

Active Alarm Counts: Critical = 0, Major = 0, Minor = 0, Warning = 0, Info = 0

[root@um1 ~]#

Node_Name.err logs :

180201 17:57:14 mysqld_safe Number of processes running now: 0

180201 17:57:14 mysqld_safe mysqld restarted

2018-02-01 17:57:14 140220162000960 [Note] /usr/local/mariadb/columnstore/mysql//bin/mysqld (mysqld 10.2.10-MariaDB-log) starting as process 13619 ...

180201 17:57:14 Columnstore: Started; Version: 1.0.2-1

180201 17:57:14 InfiniDB: Started; Version: 1.0.2-1

2018-02-01 17:57:14 140220162000960 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins

2018-02-01 17:57:14 140220162000960 [Note] InnoDB: Uses event mutexes

2018-02-01 17:57:14 140220162000960 [Note] InnoDB: Compressed tables use zlib 1.2.7

2018-02-01 17:57:14 140220162000960 [Note] InnoDB: Using Linux native AIO

2018-02-01 17:57:14 140220162000960 [Note] InnoDB: Number of pools: 1

2018-02-01 17:57:14 140220162000960 [Note] InnoDB: Using SSE2 crc32 instructions

2018-02-01 17:57:14 140220162000960 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M

2018-02-01 17:57:14 140220162000960 [Note] InnoDB: Completed initialization of buffer pool

2018-02-01 17:57:14 140219083253504 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().

2018-02-01 17:57:14 140220162000960 [Note] InnoDB: Highest supported file format is Barracuda.

2018-02-01 17:57:14 140220162000960 [Note] InnoDB: Starting crash recovery from checkpoint LSN=11236520

2018-02-01 17:57:14 140220162000960 [Note] InnoDB: Last binlog file '/usr/local/mariadb/columnstore/mysql/db/mysql-bin.000068', position 6413

2018-02-01 17:57:14 140220162000960 [Note] InnoDB: 128 out of 128 rollback segments are active.

2018-02-01 17:57:14 140220162000960 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"

2018-02-01 17:57:14 140220162000960 [Note] InnoDB: Creating shared tablespace for temporary tables

2018-02-01 17:57:14 140220162000960 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...

2018-02-01 17:57:14 140220162000960 [Note] InnoDB: File './ibtmp1' size is now 12 MB.

2018-02-01 17:57:14 140220162000960 [Note] InnoDB: Waiting for purge to start

2018-02-01 17:57:14 140220162000960 [Note] InnoDB: 5.7.20 started; log sequence number 11236529

2018-02-01 17:57:14 140218845873920 [Note] InnoDB: Loading buffer pool(s) from /usr/local/mariadb/columnstore/mysql/db/ib_buffer_pool

2018-02-01 17:57:14 140218845873920 [Note] InnoDB: Buffer pool(s) load completed at 180201 17:57:14

2018-02-01 17:57:14 140220162000960 [Note] Plugin 'FEEDBACK' is disabled.

2018-02-01 17:57:14 140220162000960 [Note] Recovering after a crash using /usr/local/mariadb/columnstore/mysql/db/mysql-bin

2018-02-01 17:57:14 140220162000960 [Note] Starting crash recovery...

2018-02-01 17:57:14 140220162000960 [Note] Crash recovery finished.

2018-02-01 17:57:14 140220162000960 [Note] Server socket created on IP: '::'.

2018-02-01 17:57:14 140220162000960 [Note] Reading of all Master_info entries succeded

2018-02-01 17:57:14 140220162000960 [Note] Added new Master_info '' to hash table

2018-02-01 17:57:14 140220162000960 [Note] /usr/local/mariadb/columnstore/mysql//bin/mysqld: ready for connections.

Version: '10.2.10-MariaDB-log'  socket: '/usr/local/mariadb/columnstore/mysql/lib/mysql/mysql.sock'  port: 3306  Columnstore 1.1.2-1

[root@um1 ~]#

Attachments

Issue Links

relates to

MCOL-1190 Process ID of mysqld is missed in the output of mcsadmin getSystemInfo

Closed

Last Status Change of mysqld is not updated after Crash recovery

Details

Description

Attachments

Issue Links

Activity

People

Dates

Git Integration