[MCOL-3842] 1.4.2 centos 7 with gluster setup - pm failover and movePmDbrootConfig fail Created: 2020-02-27  Updated: 2020-08-25  Resolved: 2020-05-13

Status: Closed
Project: MariaDB ColumnStore
Component/s: None
Affects Version/s: 1.4.2
Fix Version/s: 1.4.4

Type: Bug Priority: Major
Reporter: David Hill (Inactive) Assignee: Daniel Lee (Inactive)
Resolution: Fixed Votes: 0
Labels: None
Environment:

centos 7 3pm with gluster

Attachments: Zip Archive log.zip    
Issue Links:
Problem/Incident
causes MCOL-3997 FAILOVER: DMLProc failed when hot-sta... Closed
causes MCOL-3998 FAILOVER: When hot-standby node is do... Closed
causes MCOL-3999 FAILOVER: create table after failover... Closed
Sprint: 2020-4, 2020-5, 2020-6, 2020-7

 Description   

Reported by customer and reproduce by support (dh).

Did successfully install of a 3pm combo system on centos 7 with gluster having 3 copies configuration.

I reproduced these 2 problems, which the customer reported

1. PM3 failover testing - when PM3 recovered, the dbroot assignment failed to move dbroot 3 back to pm3

2. tried the manual move and it also failed

first took pm3 down to see if that works
After about 3-4 minutes, it made it to a good state

Component Status Last Status Change
------------ -------------------------- ------------------------
System ACTIVE Thu Feb 27 22:47:37 2020

Module pm1 ACTIVE Thu Feb 27 22:47:34 2020
Module pm2 ACTIVE Thu Feb 27 22:47:35 2020
Module pm3 AUTO_DISABLED/DEGRADED Thu Feb 27 22:44:46 2020

Active Parent OAM Performance Module is 'pm1'
Primary Front-End MariaDB ColumnStore Module is 'pm2'
MariaDB ColumnStore Replication Feature is enabled

MariaDB ColumnStore Process statuses

Process Module Status Last Status Change Process ID
------------------ ------ --------------- ------------------------ ----------
ProcessMonitor pm1 ACTIVE Thu Feb 27 22:39:22 2020 16519
ProcessManager pm1 ACTIVE Thu Feb 27 22:39:28 2020 16860
DBRMControllerNode pm1 ACTIVE Thu Feb 27 22:46:45 2020 29783
ServerMonitor pm1 ACTIVE Thu Feb 27 22:40:51 2020 19012
DBRMWorkerNode pm1 ACTIVE Thu Feb 27 22:46:47 2020 29858
PrimProc pm1 ACTIVE Thu Feb 27 22:46:55 2020 29986
ExeMgr pm1 ACTIVE Thu Feb 27 22:47:20 2020 30313
WriteEngineServer pm1 ACTIVE Thu Feb 27 22:47:08 2020 30148
DDLProc pm1 ACTIVE Thu Feb 27 22:47:28 2020 30476
DMLProc pm1 ACTIVE Thu Feb 27 22:47:37 2020 30561
mysqld pm1 ACTIVE Thu Feb 27 22:47:34 2020 30758

ProcessMonitor pm2 ACTIVE Thu Feb 27 22:40:28 2020 16217
ProcessManager pm2 HOT_STANDBY Thu Feb 27 22:42:00 2020 17466
DBRMControllerNode pm2 COLD_STANDBY Thu Feb 27 22:46:44 2020
ServerMonitor pm2 ACTIVE Thu Feb 27 22:40:55 2020 16854
DBRMWorkerNode pm2 ACTIVE Thu Feb 27 22:46:51 2020 19436
PrimProc pm2 ACTIVE Thu Feb 27 22:46:59 2020 19471
ExeMgr pm2 ACTIVE Thu Feb 27 22:47:24 2020 19634
WriteEngineServer pm2 ACTIVE Thu Feb 27 22:47:12 2020 19574
DDLProc pm2 COLD_STANDBY Thu Feb 27 22:47:30 2020
DMLProc pm2 COLD_STANDBY Thu Feb 27 22:47:32 2020
mysqld pm2 ACTIVE Thu Feb 27 22:47:35 2020 19849

ProcessMonitor pm3 AUTO_OFFLINE Thu Feb 27 22:44:46 2020
ProcessManager pm3 AUTO_OFFLINE Thu Feb 27 22:44:46 2020
DBRMControllerNode pm3 AUTO_OFFLINE Thu Feb 27 22:44:46 2020
ServerMonitor pm3 AUTO_OFFLINE Thu Feb 27 22:44:46 2020
DBRMWorkerNode pm3 AUTO_OFFLINE Thu Feb 27 22:44:46 2020
PrimProc pm3 AUTO_OFFLINE Thu Feb 27 22:44:46 2020
ExeMgr pm3 AUTO_OFFLINE Thu Feb 27 22:44:46 2020
WriteEngineServer pm3 AUTO_OFFLINE Thu Feb 27 22:44:46 2020
DDLProc pm3 AUTO_OFFLINE Thu Feb 27 22:44:46 2020
DMLProc pm3 AUTO_OFFLINE Thu Feb 27 22:44:46 2020
mysqld pm3 AUTO_OFFLINE Thu Feb 27 22:44:46 2020

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

mcsadmin> getst
getstorageconfig Thu Feb 27 22:48:40 2020

System Storage Configuration

Performance Module (DBRoot) Storage Type = DataRedundancy
System Assigned DBRoot Count = 3
DBRoot IDs assigned to 'pm1' = 1, 3
DBRoot IDs assigned to 'pm2' = 2
DBRoot IDs assigned to 'pm3' =

Data Redundant Configuration

Copies Per DBroot = 3
DBRoot #1 has copies on PMs = 1 2 3
DBRoot #2 has copies on PMs = 1 2 3
DBRoot #3 has copies on PMs = 1 2 3

Brought pm3 back up and it failed to bring PM3 back in the system

mcsadmin> getsystemi
getsysteminfo Thu Feb 27 22:54:59 2020

System columnstore-1

System and Module statuses

Component Status Last Status Change
------------ -------------------------- ------------------------
System DEGRADED Thu Feb 27 22:54:40 2020

Module pm1 ACTIVE Thu Feb 27 22:54:32 2020
Module pm2 ACTIVE Thu Feb 27 22:54:33 2020
Module pm3 MAN_DISABLED Thu Feb 27 22:53:26 2020

Active Parent OAM Performance Module is 'pm1'
Primary Front-End MariaDB ColumnStore Module is 'pm2'
MariaDB ColumnStore Replication Feature is enabled

MariaDB ColumnStore Process statuses

Process Module Status Last Status Change Process ID
------------------ ------ --------------- ------------------------ ----------
ProcessMonitor pm1 ACTIVE Thu Feb 27 22:39:22 2020 16519
ProcessManager pm1 ACTIVE Thu Feb 27 22:39:28 2020 16860
DBRMControllerNode pm1 ACTIVE Thu Feb 27 22:53:40 2020 3918
ServerMonitor pm1 ACTIVE Thu Feb 27 22:40:51 2020 19012
DBRMWorkerNode pm1 ACTIVE Thu Feb 27 22:53:42 2020 3971
PrimProc pm1 ACTIVE Thu Feb 27 22:53:50 2020 4117
ExeMgr pm1 ACTIVE Thu Feb 27 22:54:15 2020 4464
WriteEngineServer pm1 ACTIVE Thu Feb 27 22:54:04 2020 4302
DDLProc pm1 ACTIVE Thu Feb 27 22:54:23 2020 4623
DMLProc pm1 ACTIVE Thu Feb 27 22:54:29 2020 4721
mysqld pm1 ACTIVE Thu Feb 27 22:54:29 2020 4942

ProcessMonitor pm2 ACTIVE Thu Feb 27 22:40:28 2020 16217
ProcessManager pm2 HOT_STANDBY Thu Feb 27 22:42:00 2020 17466
DBRMControllerNode pm2 COLD_STANDBY Thu Feb 27 22:53:39 2020
ServerMonitor pm2 ACTIVE Thu Feb 27 22:40:55 2020 16854
DBRMWorkerNode pm2 ACTIVE Thu Feb 27 22:53:46 2020 21398
PrimProc pm2 ACTIVE Thu Feb 27 22:53:54 2020 21451
ExeMgr pm2 ACTIVE Thu Feb 27 22:54:19 2020 21588
WriteEngineServer pm2 ACTIVE Thu Feb 27 22:54:08 2020 21529
DDLProc pm2 COLD_STANDBY Thu Feb 27 22:54:25 2020
DMLProc pm2 COLD_STANDBY Thu Feb 27 22:54:27 2020
mysqld pm2 ACTIVE Thu Feb 27 22:54:30 2020 21817

ProcessMonitor pm3 ACTIVE Thu Feb 27 22:51:38 2020 4492
ProcessManager pm3 AUTO_OFFLINE Thu Feb 27 22:44:46 2020
DBRMControllerNode pm3 AUTO_OFFLINE Thu Feb 27 22:44:46 2020
ServerMonitor pm3 AUTO_OFFLINE Thu Feb 27 22:44:46 2020
DBRMWorkerNode pm3 AUTO_OFFLINE Thu Feb 27 22:44:46 2020
PrimProc pm3 AUTO_OFFLINE Thu Feb 27 22:44:46 2020
ExeMgr pm3 AUTO_OFFLINE Thu Feb 27 22:44:46 2020
WriteEngineServer pm3 AUTO_OFFLINE Thu Feb 27 22:44:46 2020
DDLProc pm3 AUTO_OFFLINE Thu Feb 27 22:44:46 2020
DMLProc pm3 AUTO_OFFLINE Thu Feb 27 22:44:46 2020
mysqld pm3 AUTO_OFFLINE Thu Feb 27 22:44:46 2020

Active Alarm Counts: Critical = 7, Major = 0, Minor = 0, Warning = 0, Info = 0
mcsadmin> getst
getstorageconfig Thu Feb 27 22:55:07 2020

System Storage Configuration

Performance Module (DBRoot) Storage Type = DataRedundancy
System Assigned DBRoot Count = 3
DBRoot IDs assigned to 'pm1' = 1, 3
DBRoot IDs assigned to 'pm2' = 2
DBRoot IDs assigned to 'pm3' =

Data Redundant Configuration

Copies Per DBroot = 3
DBRoot #1 has copies on PMs = 1 2 3
DBRoot #2 has copies on PMs = 1 2 3
DBRoot #3 has copies on PMs = 1 2 3

Then I tried the enable and move and got the same error you did

mcsadmin> stopsystem
stopsystem Thu Feb 27 22:56:09 2020

This command stops the processing of applications on all Modules within the MariaDB ColumnStore System

Checking for active transactions
Do you want to proceed: (y or n) [n]: y

System being stopped now...
Successful stop of System

NOTE: These module(s) are DISABLED: pm3

mcsadmin> altersystem-enablemodule pm3
altersystem-enablemodule Thu Feb 27 22:56:40 2020

This command starts the processing of applications on a Module within the MariaDB ColumnStore System
Do you want to proceed: (y or n) [n]: y

Enabling Modules
Successful enable of Modules

Performance Module(s) Enabled, run movePmDbrootConfig or assignDbrootPmConfig to assign dbroots, if needed

mcsadmin> movePmDbrootConfig pm1 1 pm3
movepmdbrootconfig Thu Feb 27 22:57:02 2020

        • movePmDbrootConfig Failed : Can't move dbroot #1

mcsadmin> movePmDbrootConfig pm1 3 pm3
movepmdbrootconfig Thu Feb 27 22:57:06 2020

DBRoot IDs currently assigned to 'pm1' = 1, 3
DBRoot IDs currently assigned to 'pm3' =

DBroot IDs being moved, please wait...

        • glusterctl API exception: API Failure return in GLUSTER_ASSIGN API
          FAILURE: Error assigning gluster dbroot# 3 to pm3
        • glusterctl API exception: API Failure return in GLUSTER_ASSIGN API
          FAILURE: Error reassigning gluster dbroot# 3 to pm1
        • manualMovePmDbroot Failed : API Failure
          mcsadmin>


 Comments   
Comment by David Hill (Inactive) [ 2020-02-27 ]

error logs on pm1 from my testing

Feb 27 22:38:59 ip-172-30-0-15 ProcessMonitor[16519]: 59.919220 |0|0|0| E 18 CAL0000: glusterAssign mount failure: dbroot: 1 error: 1
Feb 27 22:38:59 ip-172-30-0-15 ProcessMonitor[16519]: 59.920116 |0|0|0| E 18 CAL0000: glusterAssign failed.
Feb 27 22:38:59 ip-172-30-0-15 ProcessMonitor[16519]: 59.928718 |0|0|0| E 18 CAL0000: Error assigning gluster dbroot# 1
Feb 27 22:39:00 ip-172-30-0-15 ProcessMonitor[16519]: 00.140242 |0|0|0| E 18 CAL0000: glusterUnassign mount failure: dbroot: 2 error: 32
Feb 27 22:39:00 ip-172-30-0-15 ProcessMonitor[16519]: 00.145716 |0|0|0| E 18 CAL0000: glusterUnassign mount failure: dbroot: 3 error: 32
Feb 27 22:40:48 ip-172-30-0-15 ProcessMonitor[16519]: 48.498120 |0|0|0| E 18 CAL0000: glusterAssign mount failure: dbroot: 1 error: 1
Feb 27 22:40:48 ip-172-30-0-15 ProcessMonitor[16519]: 48.498254 |0|0|0| E 18 CAL0000: glusterAssign failed.
Feb 27 22:40:48 ip-172-30-0-15 ProcessMonitor[16519]: 48.501888 |0|0|0| E 18 CAL0000: Error assigning gluster dbroot# 1
Feb 27 22:40:48 ip-172-30-0-15 ProcessMonitor[16519]: 48.584273 |0|0|0| E 18 CAL0000: glusterUnassign mount failure: dbroot: 2 error: 32
Feb 27 22:40:48 ip-172-30-0-15 ProcessMonitor[16519]: 48.589022 |0|0|0| E 18 CAL0000: glusterUnassign mount failure: dbroot: 3 error: 32
Feb 27 22:41:09 ip-172-30-0-15 ProcessMonitor[16519]: 09.968291 |0|0|0| E 18 CAL0000: glusterAssign mount failure: dbroot: 1 error: 1
Feb 27 22:41:09 ip-172-30-0-15 ProcessMonitor[16519]: 09.968429 |0|0|0| E 18 CAL0000: glusterAssign failed.
Feb 27 22:41:09 ip-172-30-0-15 ProcessMonitor[16519]: 09.973327 |0|0|0| E 18 CAL0000: Error assigning gluster dbroot# 1
Feb 27 22:41:10 ip-172-30-0-15 ProcessMonitor[16519]: 10.010332 |0|0|0| E 18 CAL0000: glusterUnassign mount failure: dbroot: 2 error: 255
Feb 27 22:41:10 ip-172-30-0-15 ProcessMonitor[16519]: 10.015388 |0|0|0| E 18 CAL0000: glusterUnassign mount failure: dbroot: 3 error: 32
Feb 27 22:41:21 ip-172-30-0-15 ProcessMonitor[16519]: 21.277188 |0|0|0| E 18 CAL0000: glusterAssign mount failure: dbroot: 1 error: 1
Feb 27 22:41:21 ip-172-30-0-15 ProcessMonitor[16519]: 21.277335 |0|0|0| E 18 CAL0000: glusterAssign failed.
Feb 27 22:41:21 ip-172-30-0-15 ProcessMonitor[16519]: 21.283189 |0|0|0| E 18 CAL0000: Error assigning gluster dbroot# 1
Feb 27 22:41:21 ip-172-30-0-15 ProcessMonitor[16519]: 21.316917 |0|0|0| E 18 CAL0000: glusterUnassign mount failure: dbroot: 2 error: 32
Feb 27 22:41:21 ip-172-30-0-15 ProcessMonitor[16519]: 21.321635 |0|0|0| E 18 CAL0000: glusterUnassign mount failure: dbroot: 3 error: 255
Feb 27 22:41:40 ip-172-30-0-15 ProcessMonitor[16519]: 40.612275 |0|0|0| E 18 CAL0000: glusterAssign mount failure: dbroot: 1 error: 1
Feb 27 22:41:40 ip-172-30-0-15 ProcessMonitor[16519]: 40.612404 |0|0|0| E 18 CAL0000: glusterAssign failed.
Feb 27 22:41:40 ip-172-30-0-15 ProcessMonitor[16519]: 40.616591 |0|0|0| E 18 CAL0000: Error assigning gluster dbroot# 1
Feb 27 22:41:40 ip-172-30-0-15 ProcessMonitor[16519]: 40.652751 |0|0|0| E 18 CAL0000: glusterUnassign mount failure: dbroot: 2 error: 32
Feb 27 22:41:40 ip-172-30-0-15 ProcessMonitor[16519]: 40.657611 |0|0|0| E 18 CAL0000: glusterUnassign mount failure: dbroot: 3 error: 32
Feb 27 22:41:55 ip-172-30-0-15 ProcessMonitor[16519]: 55.943193 |0|0|0| E 18 CAL0000: glusterAssign mount failure: dbroot: 1 error: 1
Feb 27 22:41:55 ip-172-30-0-15 ProcessMonitor[16519]: 55.943340 |0|0|0| E 18 CAL0000: glusterAssign failed.
Feb 27 22:41:55 ip-172-30-0-15 ProcessMonitor[16519]: 55.947162 |0|0|0| E 18 CAL0000: Error assigning gluster dbroot# 1
Feb 27 22:41:55 ip-172-30-0-15 ProcessMonitor[16519]: 55.982336 |0|0|0| E 18 CAL0000: glusterUnassign mount failure: dbroot: 2 error: 32
Feb 27 22:41:55 ip-172-30-0-15 ProcessMonitor[16519]: 55.987023 |0|0|0| E 18 CAL0000: glusterUnassign mount failure: dbroot: 3 error: 32
Feb 27 22:44:12 ip-172-30-0-15 joblist[22225]: 12.349549 |0|0|0| C 05 CAL0000: /__w/1/s/padding_for_CPACK_RPM_BUILD_SOURCE_DIRS_PREFIX_ON_ES_BACKUP_DEBUGSOURCE/storage/columnstore/columnstore/dbcon/joblist/distributedenginecomm.cpp @ 432 DEC: lost connection to 172.30.0.253
Feb 27 22:44:13 ip-172-30-0-15 joblist[21500]: 13.351755 |0|0|0| C 05 CAL0000: /__w/1/s/padding_for_CPACK_RPM_BUILD_SOURCE_DIRS_PREFIX_ON_ES_BACKUP_DEBUGSOURCE/storage/columnstore/columnstore/dbcon/joblist/distributedenginecomm.cpp @ 432 DEC: lost connection to 172.30.0.253
Feb 27 22:44:13 ip-172-30-0-15 joblist[20621]: 13.353239 |0|0|0| C 05 CAL0000: /__w/1/s/padding_for_CPACK_RPM_BUILD_SOURCE_DIRS_PREFIX_ON_ES_BACKUP_DEBUGSOURCE/storage/columnstore/columnstore/dbcon/joblist/distributedenginecomm.cpp @ 432 DEC: lost connection to 172.30.0.253
Feb 27 22:44:13 ip-172-30-0-15 joblist[20621]: 13.354487 |0|0|0| C 05 CAL0000: /__w/1/s/padding_for_CPACK_RPM_BUILD_SOURCE_DIRS_PREFIX_ON_ES_BACKUP_DEBUGSOURCE/storage/columnstore/columnstore/dbcon/joblist/distributedenginecomm.cpp @ 432 DEC: lost connection to 172.30.0.253
Feb 27 22:44:31 ip-172-30-0-15 ProcessManager[16860]: 31.401863 |0|0|0| C 17 CAL0000: *** module is down: pm3
Feb 27 22:44:36 ip-172-30-0-15 ProcessManager[16860]: 36.425874 |0|0|0| E 17 CAL0000: line: 6479 sendMsgProcMon ping failure pm3 172.30.0.253
Feb 27 22:44:49 ip-172-30-0-15 joblist[21500]: 49.720810 |0|0|0| C 05 CAL0000: /__w/1/s/padding_for_CPACK_RPM_BUILD_SOURCE_DIRS_PREFIX_ON_ES_BACKUP_DEBUGSOURCE/storage/columnstore/columnstore/dbcon/joblist/distributedenginecomm.cpp @ 432 DEC: lost connection to 172.30.0.15
Feb 27 22:44:49 ip-172-30-0-15 joblist[22225]: 49.727109 |0|0|0| C 05 CAL0000: /__w/1/s/padding_for_CPACK_RPM_BUILD_SOURCE_DIRS_PREFIX_ON_ES_BACKUP_DEBUGSOURCE/storage/columnstore/columnstore/dbcon/joblist/distributedenginecomm.cpp @ 432 DEC: lost connection to 172.30.0.15
Feb 27 22:44:49 ip-172-30-0-15 joblist[22225]: 49.731257 |0|0|0| C 05 CAL0000: /__w/1/s/padding_for_CPACK_RPM_BUILD_SOURCE_DIRS_PREFIX_ON_ES_BACKUP_DEBUGSOURCE/storage/columnstore/columnstore/dbcon/joblist/distributedenginecomm.cpp @ 432 DEC: lost connection to 172.30.0.42
Feb 27 22:44:49 ip-172-30-0-15 joblist[21500]: 49.732648 |0|0|0| C 05 CAL0000: /__w/1/s/padding_for_CPACK_RPM_BUILD_SOURCE_DIRS_PREFIX_ON_ES_BACKUP_DEBUGSOURCE/storage/columnstore/columnstore/dbcon/joblist/distributedenginecomm.cpp @ 432 DEC: lost connection to 172.30.0.42
Feb 27 22:46:26 ip-172-30-0-15 ProcessMonitor[16519]: 26.650457 |0|0|0| E 18 CAL0000: glusterAssign mount failure: dbroot: 3 error: 1
Feb 27 22:46:26 ip-172-30-0-15 ProcessMonitor[16519]: 26.650591 |0|0|0| E 18 CAL0000: glusterAssign failed.
Feb 27 22:46:26 ip-172-30-0-15 ProcessManager[16860]: 26.656340 |0|0|0| E 17 CAL0000: line: 11133 glusterAssign FAILED: pm1/3
Feb 27 22:46:26 ip-172-30-0-15 oamcpp[16860]: 26.656599 |0|0|0| E 08 CAL0000: FAILURE: Error assigning gluster dbroot# 3
Feb 27 22:47:36 ip-172-30-0-15 joblist[30561]: 36.081510 |0|0|0| E 05 CAL0000: /__w/1/s/padding_for_CPACK_RPM_BUILD_SOURCE_DIRS_PREFIX_ON_ES_BACKUP_DEBUGSOURCE/storage/columnstore/columnstore/writeengine/client/we_clients.cpp @ 307 Could not connect to pm3_WriteEngineServer: InetStreamSocket::connect: connect() error: No route to host to: InetStreamSocket: sd: 14 inet: 172.30.0.253 port: 8630
Feb 27 22:47:36 ip-172-30-0-15 joblist[30561]: 36.081516 |0|0|0| E 05 CAL0000: /__w/1/s/padding_for_CPACK_RPM_BUILD_SOURCE_DIRS_PREFIX_ON_ES_BACKUP_DEBUGSOURCE/storage/columnstore/columnstore/writeengine/client/we_clients.cpp @ 307 Could not connect to pm3_WriteEngineServer: InetStreamSocket::connect: connect() error: No route to host to: InetStreamSocket: sd: 15 inet: 172.30.0.253 port: 8630
Feb 27 22:47:37 ip-172-30-0-15 oamcpp[30561]: 37.110074 |0|0|0| E 08 CAL0000: OamCache::checkReload shows state for pm3 as AUTO_DISABLED
Feb 27 22:51:19 ip-172-30-0-15 ProcessMonitor[16519]: 19.043003 |0|0|0| E 18 CAL0000: glusterUnassign mount failure: dbroot: 3 error: 32
Feb 27 22:51:30 ip-172-30-0-15 ProcessManager[16860]: 30.055831 |0|0|0| E 17 CAL0000: line: 11133 glusterAssign FAILED: pm3/3
Feb 27 22:51:30 ip-172-30-0-15 oamcpp[16860]: 30.056261 |0|0|0| E 08 CAL0000: FAILURE: Error assigning gluster dbroot# 3 to pm3
Feb 27 22:51:30 ip-172-30-0-15 oamcpp[16860]: 30.056336 |0|0|0| E 08 CAL0000: reassigning gluster dbroot# 3 to pm1
Feb 27 22:51:40 ip-172-30-0-15 ProcessMonitor[16519]: 40.219189 |0|0|0| E 18 CAL0000: glusterAssign mount failure: dbroot: 3 error: 1
Feb 27 22:51:40 ip-172-30-0-15 ProcessMonitor[16519]: 40.219322 |0|0|0| E 18 CAL0000: glusterAssign failed.
Feb 27 22:51:40 ip-172-30-0-15 ProcessManager[16860]: 40.234593 |0|0|0| E 17 CAL0000: line: 11133 glusterAssign FAILED: pm1/3
Feb 27 22:51:40 ip-172-30-0-15 oamcpp[16860]: 40.234821 |0|0|0| E 08 CAL0000: FAILURE: Error reassigning gluster dbroot# 3 to pm1
Feb 27 22:51:40 ip-172-30-0-15 oamcpp[16860]: 40.234901 |0|0|0| E 08 CAL0000: ERROR: manualMovePmDbroot failure: pm1:3:pm3
Feb 27 22:51:45 ip-172-30-0-15 ProcessMonitor[16519]: 45.298072 |0|0|0| E 18 CAL0000: glusterUnassign mount failure: dbroot: 3 error: 32
Feb 27 22:51:55 ip-172-30-0-15 ProcessManager[16860]: 55.408059 |0|0|0| E 17 CAL0000: line: 11133 glusterAssign FAILED: pm3/3
Feb 27 22:51:55 ip-172-30-0-15 oamcpp[16860]: 55.408484 |0|0|0| E 08 CAL0000: FAILURE: Error assigning gluster dbroot# 3 to pm3
Feb 27 22:51:55 ip-172-30-0-15 oamcpp[16860]: 55.408555 |0|0|0| E 08 CAL0000: reassigning gluster dbroot# 3 to pm1
Feb 27 22:52:05 ip-172-30-0-15 ProcessMonitor[16519]: 05.539255 |0|0|0| E 18 CAL0000: glusterAssign mount failure: dbroot: 3 error: 255
Feb 27 22:52:05 ip-172-30-0-15 ProcessMonitor[16519]: 05.539377 |0|0|0| E 18 CAL0000: glusterAssign failed.
Feb 27 22:52:05 ip-172-30-0-15 ProcessManager[16860]: 05.545133 |0|0|0| E 17 CAL0000: line: 11133 glusterAssign FAILED: pm1/3
Feb 27 22:52:05 ip-172-30-0-15 oamcpp[16860]: 05.545397 |0|0|0| E 08 CAL0000: FAILURE: Error reassigning gluster dbroot# 3 to pm1
Feb 27 22:52:05 ip-172-30-0-15 oamcpp[16860]: 05.545486 |0|0|0| E 08 CAL0000: ERROR: manualMovePmDbroot failure: pm1:3:pm3
Feb 27 22:52:10 ip-172-30-0-15 ProcessMonitor[16519]: 10.603245 |0|0|0| E 18 CAL0000: glusterUnassign mount failure: dbroot: 3 error: 32
Feb 27 22:52:20 ip-172-30-0-15 ProcessManager[16860]: 20.713729 |0|0|0| E 17 CAL0000: line: 11133 glusterAssign FAILED: pm3/3
Feb 27 22:52:20 ip-172-30-0-15 oamcpp[16860]: 20.714109 |0|0|0| E 08 CAL0000: FAILURE: Error assigning gluster dbroot# 3 to pm3
Feb 27 22:52:20 ip-172-30-0-15 oamcpp[16860]: 20.714183 |0|0|0| E 08 CAL0000: reassigning gluster dbroot# 3 to pm1
Feb 27 22:52:30 ip-172-30-0-15 ProcessMonitor[16519]: 30.840271 |0|0|0| E 18 CAL0000: glusterAssign mount failure: dbroot: 3 error: 1
Feb 27 22:52:30 ip-172-30-0-15 ProcessMonitor[16519]: 30.840386 |0|0|0| E 18 CAL0000: glusterAssign failed.
Feb 27 22:52:30 ip-172-30-0-15 ProcessManager[16860]: 30.846472 |0|0|0| E 17 CAL0000: line: 11133 glusterAssign FAILED: pm1/3
Feb 27 22:52:30 ip-172-30-0-15 oamcpp[16860]: 30.846705 |0|0|0| E 08 CAL0000: FAILURE: Error reassigning gluster dbroot# 3 to pm1
Feb 27 22:52:30 ip-172-30-0-15 oamcpp[16860]: 30.846788 |0|0|0| E 08 CAL0000: ERROR: manualMovePmDbroot failure: pm1:3:pm3
Feb 27 22:52:35 ip-172-30-0-15 ProcessMonitor[16519]: 35.903322 |0|0|0| E 18 CAL0000: glusterUnassign mount failure: dbroot: 3 error: 32
Feb 27 22:52:46 ip-172-30-0-15 ProcessManager[16860]: 46.011092 |0|0|0| E 17 CAL0000: line: 11133 glusterAssign FAILED: pm3/3
Feb 27 22:52:46 ip-172-30-0-15 oamcpp[16860]: 46.011511 |0|0|0| E 08 CAL0000: FAILURE: Error assigning gluster dbroot# 3 to pm3
Feb 27 22:52:46 ip-172-30-0-15 oamcpp[16860]: 46.011596 |0|0|0| E 08 CAL0000: reassigning gluster dbroot# 3 to pm1
Feb 27 22:52:56 ip-172-30-0-15 ProcessMonitor[16519]: 56.138144 |0|0|0| E 18 CAL0000: glusterAssign mount failure: dbroot: 3 error: 1
Feb 27 22:52:56 ip-172-30-0-15 ProcessMonitor[16519]: 56.138277 |0|0|0| E 18 CAL0000: glusterAssign failed.
Feb 27 22:52:56 ip-172-30-0-15 ProcessManager[16860]: 56.144099 |0|0|0| E 17 CAL0000: line: 11133 glusterAssign FAILED: pm1/3
Feb 27 22:52:56 ip-172-30-0-15 oamcpp[16860]: 56.144327 |0|0|0| E 08 CAL0000: FAILURE: Error reassigning gluster dbroot# 3 to pm1
Feb 27 22:52:56 ip-172-30-0-15 oamcpp[16860]: 56.144400 |0|0|0| E 08 CAL0000: ERROR: manualMovePmDbroot failure: pm1:3:pm3
Feb 27 22:53:01 ip-172-30-0-15 ProcessMonitor[16519]: 01.203137 |0|0|0| E 18 CAL0000: glusterUnassign mount failure: dbroot: 3 error: 255
Feb 27 22:53:11 ip-172-30-0-15 ProcessManager[16860]: 11.311080 |0|0|0| E 17 CAL0000: line: 11133 glusterAssign FAILED: pm3/3
Feb 27 22:53:11 ip-172-30-0-15 oamcpp[16860]: 11.311512 |0|0|0| E 08 CAL0000: FAILURE: Error assigning gluster dbroot# 3 to pm3
Feb 27 22:53:11 ip-172-30-0-15 oamcpp[16860]: 11.311586 |0|0|0| E 08 CAL0000: reassigning gluster dbroot# 3 to pm1
Feb 27 22:53:21 ip-172-30-0-15 ProcessMonitor[16519]: 21.442131 |0|0|0| E 18 CAL0000: glusterAssign mount failure: dbroot: 3 error: 1
Feb 27 22:53:21 ip-172-30-0-15 ProcessMonitor[16519]: 21.442269 |0|0|0| E 18 CAL0000: glusterAssign failed.
Feb 27 22:53:21 ip-172-30-0-15 ProcessManager[16860]: 21.447660 |0|0|0| E 17 CAL0000: line: 11133 glusterAssign FAILED: pm1/3
Feb 27 22:53:21 ip-172-30-0-15 oamcpp[16860]: 21.447906 |0|0|0| E 08 CAL0000: FAILURE: Error reassigning gluster dbroot# 3 to pm1
Feb 27 22:53:21 ip-172-30-0-15 oamcpp[16860]: 21.447989 |0|0|0| E 08 CAL0000: ERROR: manualMovePmDbroot failure: pm1:3:pm3
Feb 27 22:53:29 ip-172-30-0-15 joblist[30561]: 29.700580 |0|0|0| C 05 CAL0000: /__w/1/s/padding_for_CPACK_RPM_BUILD_SOURCE_DIRS_PREFIX_ON_ES_BACKUP_DEBUGSOURCE/storage/columnstore/columnstore/dbcon/joblist/distributedenginecomm.cpp @ 432 DEC: lost connection to 172.30.0.15
Feb 27 22:53:29 ip-172-30-0-15 joblist[30476]: 29.700600 |0|0|0| C 05 CAL0000: /__w/1/s/padding_for_CPACK_RPM_BUILD_SOURCE_DIRS_PREFIX_ON_ES_BACKUP_DEBUGSOURCE/storage/columnstore/columnstore/dbcon/joblist/distributedenginecomm.cpp @ 432 DEC: lost connection to 172.30.0.15
Feb 27 22:53:29 ip-172-30-0-15 joblist[30476]: 29.700600 |0|0|0| C 05 CAL0000: /__w/1/s/padding_for_CPACK_RPM_BUILD_SOURCE_DIRS_PREFIX_ON_ES_BACKUP_DEBUGSOURCE/storage/columnstore/columnstore/dbcon/joblist/distributedenginecomm.cpp @ 432 DEC: lost connection to 172.30.0.42
Feb 27 22:53:29 ip-172-30-0-15 joblist[30561]: 29.700695 |0|0|0| C 05 CAL0000: /__w/1/s/padding_for_CPACK_RPM_BUILD_SOURCE_DIRS_PREFIX_ON_ES_BACKUP_DEBUGSOURCE/storage/columnstore/columnstore/dbcon/joblist/distributedenginecomm.cpp @ 432 DEC: lost connection to 172.30.0.42
Feb 27 22:54:28 ip-172-30-0-15 joblist[4721]: 28.281322 |0|0|0| E 05 CAL0000: /__w/1/s/padding_for_CPACK_RPM_BUILD_SOURCE_DIRS_PREFIX_ON_ES_BACKUP_DEBUGSOURCE/storage/columnstore/columnstore/writeengine/client/we_clients.cpp @ 307 Could not connect to pm3_WriteEngineServer: Connection refused
Feb 27 22:54:28 ip-172-30-0-15 joblist[4721]: 28.286931 |0|0|0| E 05 CAL0000: /__w/1/s/padding_for_CPACK_RPM_BUILD_SOURCE_DIRS_PREFIX_ON_ES_BACKUP_DEBUGSOURCE/storage/columnstore/columnstore/writeengine/client/we_clients.cpp @ 307 Could not connect to pm3_WriteEngineServer: Connection refused
Feb 27 22:54:28 ip-172-30-0-15 oamcpp[4721]: 28.306306 |0|0|0| E 08 CAL0000: OamCache::checkReload shows state for pm1 as DEGRADED
Feb 27 22:54:28 ip-172-30-0-15 oamcpp[4721]: 28.308431 |0|0|0| E 08 CAL0000: OamCache::checkReload shows state for pm2 as DEGRADED
Feb 27 22:54:29 ip-172-30-0-15 oamcpp[4721]: 29.310713 |0|0|0| E 08 CAL0000: OamCache::checkReload shows state for pm3 as MAN_DISABLED
Feb 27 22:56:11 ip-172-30-0-15 joblist[4721]: 11.862776 |0|0|0| C 05 CAL0000: /__w/1/s/padding_for_CPACK_RPM_BUILD_SOURCE_DIRS_PREFIX_ON_ES_BACKUP_DEBUGSOURCE/storage/columnstore/columnstore/dbcon/joblist/distributedenginecomm.cpp @ 432 DEC: lost connection to 172.30.0.42
Feb 27 22:56:11 ip-172-30-0-15 joblist[4623]: 11.864297 |0|0|0| C 05 CAL0000: /__w/1/s/padding_for_CPACK_RPM_BUILD_SOURCE_DIRS_PREFIX_ON_ES_BACKUP_DEBUGSOURCE/storage/columnstore/columnstore/dbcon/joblist/distributedenginecomm.cpp @ 432 DEC: lost connection to 172.30.0.42
Feb 27 22:56:11 ip-172-30-0-15 joblist[4464]: 11.865753 |0|0|0| C 05 CAL0000: /__w/1/s/padding_for_CPACK_RPM_BUILD_SOURCE_DIRS_PREFIX_ON_ES_BACKUP_DEBUGSOURCE/storage/columnstore/columnstore/dbcon/joblist/distributedenginecomm.cpp @ 432 DEC: lost connection to 172.30.0.42
Feb 27 22:56:11 ip-172-30-0-15 joblist[4464]: 11.867012 |0|0|0| C 05 CAL0000: /__w/1/s/padding_for_CPACK_RPM_BUILD_SOURCE_DIRS_PREFIX_ON_ES_BACKUP_DEBUGSOURCE/storage/columnstore/columnstore/dbcon/joblist/distributedenginecomm.cpp @ 432 DEC: lost connection to 172.30.0.42
Feb 27 22:56:19 ip-172-30-0-15 ProcessMonitor[16519]: 19.049720 |0|0|0| E 18 CAL0000: glusterUnassign mount failure: dbroot: 2 error: 255
Feb 27 22:56:21 ip-172-30-0-15 controllernode[16860]: 21.634925 |0|0|0| E 29 CAL0000: DBRM: error: SessionManager::setSystemState() failed (network)
Feb 27 22:56:21 ip-172-30-0-15 controllernode[16860]: 21.635359 |0|0|0| E 29 CAL0000: DBRM: error: SessionManager::setSystemState() failed (network)
Feb 27 22:56:25 ip-172-30-0-15 controllernode[16860]: 25.427953 |0|0|0| E 29 CAL0000: DBRM: error: SessionManager::getSystemState() failed (network)
Feb 27 22:57:06 ip-172-30-0-15 ProcessMonitor[16519]: 06.706222 |0|0|0| E 18 CAL0000: glusterUnassign mount failure: dbroot: 3 error: 255
Feb 27 22:57:16 ip-172-30-0-15 ProcessManager[16860]: 16.985091 |0|0|0| E 17 CAL0000: line: 11133 glusterAssign FAILED: pm3/3
Feb 27 22:57:16 ip-172-30-0-15 oamcpp[5382]: 16.985520 |0|0|0| E 08 CAL0000: FAILURE: Error assigning gluster dbroot# 3 to pm3
Feb 27 22:57:16 ip-172-30-0-15 oamcpp[5382]: 16.985582 |0|0|0| E 08 CAL0000: reassigning gluster dbroot# 3 to pm1
Feb 27 22:57:27 ip-172-30-0-15 ProcessMonitor[16519]: 27.154179 |0|0|0| E 18 CAL0000: glusterAssign mount failure: dbroot: 3 error: 1
Feb 27 22:57:27 ip-172-30-0-15 ProcessMonitor[16519]: 27.154316 |0|0|0| E 18 CAL0000: glusterAssign failed.
Feb 27 22:57:27 ip-172-30-0-15 ProcessManager[16860]: 27.161906 |0|0|0| E 17 CAL0000: line: 11133 glusterAssign FAILED: pm1/3
Feb 27 22:57:27 ip-172-30-0-15 oamcpp[5382]: 27.162164 |0|0|0| E 08 CAL0000: FAILURE: Error reassigning gluster dbroot# 3 to pm1
[root@ip-172-30-0-15 columnstore]#

Comment by Daniel Lee (Inactive) [ 2020-05-01 ]

1.4.4-1

/root/ColumnStore/buildColumnstoreFromGithubSource/server
commit 00abe03ad1da3719e06f7112000a331ee2b6786a
Author: Patrick LeBlanc <43503225+pleblanc1976@users.noreply.github.com>
Date: Wed Apr 29 10:00:54 2020 -0500

/root/ColumnStore/buildColumnstoreFromGithubSource/server/engine
commit 2b67ac7f3537bd4b4d132c8a6c3a53e4cc63f4a1
Merge: beaac49 23d65dc
Author: benthompson15 <ben.thompson.015@gmail.com>
Date: Tue Apr 28 15:40:45 2020 -0500

3pm glusterfs installation failed. mysqld on PM1 was not running, although getprocessstatus show mysqld ACTIVE with a PID.

localhost.localdomain.err on PM1 showed the following errors:
2020-05-01 15:38:58 server_audit: Query cache is enabled with the TABLE events. Some table reads can be veiled.
2020-05-01 15:38:58 0 [Note] Server socket created on IP: '::'.
2020-05-01 15:38:58 0 [Note] Reading of all Master_info entries succeeded
2020-05-01 15:38:58 0 [Note] Added new Master_info '' to hash table
2020-05-01 15:38:58 0 [Note] /usr/sbin/mysqld: ready for connections.
Version: '10.4.12-6-MariaDB-debug' socket: '/var/lib/mysql/mysql.sock' port: 3306 Source distribution
2020-05-01 15:40:14 0 [Note] /usr/sbin/mysqld (initiated by: unknown): Normal shutdown
2020-05-01 15:40:14 0 [Note] Event Scheduler: Purging the queue. 0 events
2020-05-01 15:40:14 0 [Note] InnoDB: FTS optimize thread exiting.
2020-05-01 15:40:14 server_audit: STOPPED
2020-05-01 15:40:14 0 [Note] InnoDB: Starting shutdown...
2020-05-01 15:40:14 0 [Note] InnoDB: Dumping buffer pool(s) to /var/lib/mysql/ib_buffer_pool
2020-05-01 15:40:14 0 [Note] InnoDB: Buffer pool(s) dump completed at 200501 15:40:14
2020-05-01 15:40:16 0 [Note] InnoDB: Shutdown completed; log sequence number 77624; transaction id 50
2020-05-01 15:40:16 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2020-05-01 15:40:16 0 [Note] /usr/sbin/mysqld: Shutdown complete

The same 3pm.glusterfs installation test worked on 1.4.3-4
Also, for 1.4.4-1, 1um2pm.glusterfs also worked.

log files from all three PMs have been attached to this ticket.

1.2.6-1 and 1.5.0-1 tests are pending for packages.

Comment by Patrick LeBlanc (Inactive) [ 2020-05-05 ]

Daniel, it looks like you installed the gssapi packages, which aren't configured (or missing other pieces like a separate authentication server; I'm still not totally clear), and which are causing the server to commit suicide. Not a columnstore problem. Please retest w/o installing the gssapi packages.

Comment by Daniel Lee (Inactive) [ 2020-05-05 ]

Skipped installing gssapi and still have the same issue.

2020-05-05 20:21:13 0 [Note] /usr/sbin/mysqld: ready for connections.
Version: '10.4.12-6-MariaDB-debug' socket: '/var/lib/mysql/mysql.sock' port: 3306 Source distribution
2020-05-05 20:22:32 0 [Note] /usr/sbin/mysqld (initiated by: unknown): Normal shutdown
2020-05-05 20:22:32 0 [Note] Event Scheduler: Purging the queue. 0 events
2020-05-05 20:22:32 0 [Note] InnoDB: FTS optimize thread exiting.
2020-05-05 20:22:32 server_audit: STOPPED
2020-05-05 20:22:32 0 [Note] InnoDB: Starting shutdown...
2020-05-05 20:22:32 0 [Note] InnoDB: Dumping buffer pool(s) to /var/lib/mysql/ib_buffer_pool
2020-05-05 20:22:32 0 [Note] InnoDB: Buffer pool(s) dump completed at 200505 20:22:32
2020-05-05 20:22:33 0 [Note] InnoDB: Shutdown completed; log sequence number 77624; transaction id 50
2020-05-05 20:22:33 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2020-05-05 20:22:33 0 [Note] /usr/sbin/mysqld: Shutdown complete

Comment by Ben Thompson (Inactive) [ 2020-05-06 ]

Built local with same commit ID could not reproduce. gssapi does not appear to be an issue however reviewing logs have noticed this logging:

2020-05-01 15:38:58 0 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!

Leading to believe server was built with mismatch of flags from engine.

I also would like to know what systemd is logging for mariadb.service

rpms I tested with have been upload to shared location.

Comment by Daniel Lee (Inactive) [ 2020-05-07 ]

Build tested: 1.4.4-1 RC from Jenkins - 2020-05-06

3PM combo installation, without glusterfs.

Installation finished, OAM show the stack in good state, but mysqld is not running.

cat /var/lib/mysql/localhost.localdomain.err

[centos7:root~]# cat localhost.localdomain.err
200507 16:27:05 Columnstore: Started; Version: 1.4.4-1
2020-05-07 16:27:05 0 [Note] InnoDB: Using Linux native AIO
2020-05-07 16:27:05 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2020-05-07 16:27:05 0 [Note] InnoDB: Uses event mutexes
2020-05-07 16:27:05 0 [Note] InnoDB: Compressed tables use zlib 1.2.7
2020-05-07 16:27:05 0 [Note] InnoDB: Number of pools: 1
2020-05-07 16:27:05 0 [Note] InnoDB: Using SSE2 crc32 instructions
2020-05-07 16:27:05 0 [Note] mysqld: O_TMPFILE is not supported on /tmp (disabling future attempts)
2020-05-07 16:27:05 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
2020-05-07 16:27:05 0 [Note] InnoDB: Completed initialization of buffer pool
2020-05-07 16:27:05 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2020-05-07 16:27:05 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
2020-05-07 16:27:05 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2020-05-07 16:27:05 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2020-05-07 16:27:05 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2020-05-07 16:27:05 0 [Note] InnoDB: Waiting for purge to start
2020-05-07 16:27:05 0 [Note] InnoDB: 10.4.12 started; log sequence number 61420; transaction id 21
2020-05-07 16:27:05 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
2020-05-07 16:27:05 0 [Note] Plugin 'S3' is disabled.
2020-05-07 16:27:05 0 [Note] Plugin 'FEEDBACK' is disabled.
2020-05-07 16:27:05 server_audit: MariaDB Audit Plugin version 2.0.2 STARTED.
2020-05-07 16:27:05 server_audit: Query cache is enabled with the TABLE events. Some table reads can be veiled.
2020-05-07 16:27:05 0 [Note] InnoDB: Buffer pool(s) load completed at 200507 16:27:05
2020-05-07 16:27:05 0 [Note] Server socket created on IP: '::'.
2020-05-07 16:27:05 0 [Note] Reading of all Master_info entries succeeded
2020-05-07 16:27:05 0 [Note] Added new Master_info '' to hash table
2020-05-07 16:27:05 0 [Note] /usr/sbin/mysqld: ready for connections.
Version: '10.4.12-6-MariaDB-enterprise' socket: '/var/lib/mysql/mysql.sock' port: 3306 MariaDB Enterprise Server
2020-05-07 16:27:10 0 [Note] /usr/sbin/mysqld (initiated by: unknown): Normal shutdown
2020-05-07 16:27:10 0 [Note] InnoDB: FTS optimize thread exiting.
2020-05-07 16:27:10 server_audit: STOPPED
2020-05-07 16:27:10 0 [Note] InnoDB: Starting shutdown...
2020-05-07 16:27:10 0 [Note] InnoDB: Dumping buffer pool(s) to /var/lib/mysql/ib_buffer_pool
2020-05-07 16:27:10 0 [Note] InnoDB: Buffer pool(s) dump completed at 200507 16:27:10
2020-05-07 16:27:11 0 [Note] InnoDB: Shutdown completed; log sequence number 77023; transaction id 47
2020-05-07 16:27:11 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2020-05-07 16:27:11 0 [Note] /usr/sbin/mysqld: Shutdown complete

200507 16:31:35 Columnstore: Started; Version: 1.4.4-1
2020-05-07 16:31:35 0 [Note] InnoDB: Using Linux native AIO
2020-05-07 16:31:35 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2020-05-07 16:31:35 0 [Note] InnoDB: Uses event mutexes
2020-05-07 16:31:35 0 [Note] InnoDB: Compressed tables use zlib 1.2.7
2020-05-07 16:31:35 0 [Note] InnoDB: Number of pools: 1
2020-05-07 16:31:35 0 [Note] InnoDB: Using SSE2 crc32 instructions
2020-05-07 16:31:35 0 [Note] mysqld: O_TMPFILE is not supported on /tmp (disabling future attempts)
2020-05-07 16:31:35 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
2020-05-07 16:31:35 0 [Note] InnoDB: Completed initialization of buffer pool
2020-05-07 16:31:35 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2020-05-07 16:31:35 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
2020-05-07 16:31:35 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2020-05-07 16:31:35 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2020-05-07 16:31:35 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2020-05-07 16:31:35 0 [Note] InnoDB: 10.4.12 started; log sequence number 77023; transaction id 49
2020-05-07 16:31:35 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
2020-05-07 16:31:35 0 [Note] Plugin 'S3' is disabled.
2020-05-07 16:31:35 0 [Note] Plugin 'FEEDBACK' is disabled.
2020-05-07 16:31:35 server_audit: MariaDB Audit Plugin version 2.0.2 STARTED.
2020-05-07 16:31:35 server_audit: Query cache is enabled with the TABLE events. Some table reads can be veiled.
2020-05-07 16:31:35 0 [Note] InnoDB: Buffer pool(s) load completed at 200507 16:31:35
2020-05-07 16:31:36 0 [Note] Server socket created on IP: '::'.
2020-05-07 16:31:36 0 [Note] Reading of all Master_info entries succeeded
2020-05-07 16:31:36 0 [Note] Added new Master_info '' to hash table
2020-05-07 16:31:36 0 [Note] /usr/sbin/mysqld: ready for connections.
Version: '10.4.12-6-MariaDB-enterprise' socket: '/var/lib/mysql/mysql.sock' port: 3306 MariaDB Enterprise Server
2020-05-07 16:32:42 0 [Note] /usr/sbin/mysqld (initiated by: unknown): Normal shutdown
2020-05-07 16:32:42 0 [Note] Event Scheduler: Purging the queue. 0 events
2020-05-07 16:32:42 0 [Note] InnoDB: FTS optimize thread exiting.
2020-05-07 16:32:42 server_audit: STOPPED
2020-05-07 16:32:42 0 [Note] InnoDB: Starting shutdown...
2020-05-07 16:32:42 0 [Note] InnoDB: Dumping buffer pool(s) to /var/lib/mysql/ib_buffer_pool
2020-05-07 16:32:42 0 [Note] InnoDB: Buffer pool(s) dump completed at 200507 16:32:42
2020-05-07 16:32:44 0 [Note] InnoDB: Shutdown completed; log sequence number 77032; transaction id 50
2020-05-07 16:32:44 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2020-05-07 16:32:44 0 [Note] /usr/sbin/mysqld: Shutdown complete

Comment by David Hall (Inactive) [ 2020-05-08 ]

The symptom seen where mysqld is shutting down unexpectedly is seen only when systemd is not used. MCOL-3985 has been opened for the non-systemd install.
Please test with systemd enabled.

Comment by Daniel Lee (Inactive) [ 2020-05-13 ]

Build verified: 1.4.4-1 (Jenkins 20200508)

Testing has been performed for 1.4.4-1. Releases 1.2.6 and 1.5 will be tracked on a separate ticket.

Tested on Centos 7 and Ubuntu 18.04

Tickets have been open for newly identified issues. Please see related tickets.

Generated at Thu Feb 08 02:45:51 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.