[MCOL-2023] mcsimport run in concurrency is causing crash and mcs restating Created: 2018-12-14  Updated: 2023-10-26  Resolved: 2021-04-04

Status: Closed
Project: MariaDB ColumnStore
Component/s: None
Affects Version/s: 1.2.3, 1.2.2
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: Zdravelina Sokolovska (Inactive) Assignee: Unassigned
Resolution: Won't Do Votes: 0
Labels: None
Environment:

mcs single server, 64G memory, 8 CPUs ; CentOS7.5

Issue Links:
Relates
relates to MCOL-2226 Improve performance of mcsimport - ma... Closed
Sprint: 2021-5

 Description   

mcsimport run in concurrency is causing crash and mcs restating

mcsimport was rum from the cs node in order to compare the mcsimport performance to cpimport performance.
Several mcsimport tasks are run in concurrency to load 1TB data in 24 tables , as 1 mcsimport per table.
It is observed hight CPU usage in mcs controllernode process followed by
"Error during mcsapi initialization: Could not read data: EOF " Errors
crashing and mcs restarting .

 /usr/local/mariadb/columnstore/tools/mcsimport/mcsimport    tpcds_1000  call_center insert-data-tables/data/tpcds_1000/call_center.tbl -d "|"   &
 
 /usr/local/mariadb/columnstore/tools/mcsimport/mcsimport    tpcds_1000  catalog_page insert-data-tables/data/tpcds_1000/catalog_page.tbl -d "|"   &
 
 /usr/local/mariadb/columnstore/tools/mcsimport/mcsimport    tpcds_1000  catalog_returns insert-data-tables/data/tpcds_1000/catalog_returns.tbl -d "|"   &
 
 /usr/local/mariadb/columnstore/tools/mcsimport/mcsimport    tpcds_1000  catalog_sales insert-data-tables/data/tpcds_1000/catalog_sales.tbl -d "|"   &
 
 /usr/local/mariadb/columnstore/tools/mcsimport/mcsimport    tpcds_1000  customer_address insert-data-tables/data/tpcds_1000/customer_address.tbl -d "|"   &
 
 /usr/local/mariadb/columnstore/tools/mcsimport/mcsimport    tpcds_1000  customer_demographics insert-data-tables/data/tpcds_1000/customer_demographics.tbl -d "|"   &
 
 /usr/local/mariadb/columnstore/tools/mcsimport/mcsimport    tpcds_1000  customer insert-data-tables/data/tpcds_1000/customer.tbl -d "|"   &
 
 /usr/local/mariadb/columnstore/tools/mcsimport/mcsimport    tpcds_1000  date_dim insert-data-tables/data/tpcds_1000/date_dim.tbl -d "|"   &
 
 /usr/local/mariadb/columnstore/tools/mcsimport/mcsimport    tpcds_1000  household_demographics insert-data-tables/data/tpcds_1000/household_demographics.tbl -d "|"   &
 
 /usr/local/mariadb/columnstore/tools/mcsimport/mcsimport    tpcds_1000  income_band insert-data-tables/data/tpcds_1000/income_band.tbl -d "|"   &
 
 /usr/local/mariadb/columnstore/tools/mcsimport/mcsimport    tpcds_1000  inventory insert-data-tables/data/tpcds_1000/inventory.tbl -d "|"   &
 
 /usr/local/mariadb/columnstore/tools/mcsimport/mcsimport    tpcds_1000  item insert-data-tables/data/tpcds_1000/item.tbl -d "|"   &
 
 /usr/local/mariadb/columnstore/tools/mcsimport/mcsimport    tpcds_1000  promotion insert-data-tables/data/tpcds_1000/promotion.tbl -d "|"   &
 
 /usr/local/mariadb/columnstore/tools/mcsimport/mcsimport    tpcds_1000  reason insert-data-tables/data/tpcds_1000/reason.tbl -d "|"   &
 
 /usr/local/mariadb/columnstore/tools/mcsimport/mcsimport    tpcds_1000  ship_mode insert-data-tables/data/tpcds_1000/ship_mode.tbl -d "|"   &
 
 /usr/local/mariadb/columnstore/tools/mcsimport/mcsimport    tpcds_1000  store_returns insert-data-tables/data/tpcds_1000/store_returns.tbl -d "|"   &
 
 /usr/local/mariadb/columnstore/tools/mcsimport/mcsimport    tpcds_1000  store_sales insert-data-tables/data/tpcds_1000/store_sales.tbl -d "|"   &
 
 /usr/local/mariadb/columnstore/tools/mcsimport/mcsimport    tpcds_1000  store insert-data-tables/data/tpcds_1000/store.tbl -d "|"   &
 
 /usr/local/mariadb/columnstore/tools/mcsimport/mcsimport    tpcds_1000  time_dim insert-data-tables/data/tpcds_1000/time_dim.tbl -d "|"   &
 
 /usr/local/mariadb/columnstore/tools/mcsimport/mcsimport    tpcds_1000  warehouse insert-data-tables/data/tpcds_1000/warehouse.tbl -d "|"   &
 
 /usr/local/mariadb/columnstore/tools/mcsimport/mcsimport    tpcds_1000  web_page insert-data-tables/data/tpcds_1000/web_page.tbl -d "|"   &
 
 /usr/local/mariadb/columnstore/tools/mcsimport/mcsimport    tpcds_1000  web_returns insert-data-tables/data/tpcds_1000/web_returns.tbl -d "|"   &
 
 /usr/local/mariadb/columnstore/tools/mcsimport/mcsimport    tpcds_1000  web_sales insert-data-tables/data/tpcds_1000/web_sales.tbl -d "|"   &
 
 /usr/local/mariadb/columnstore/tools/mcsimport/mcsimport    tpcds_1000  web_site insert-data-tables/data/tpcds_1000/web_site.tbl -d "|"   &
 



[root@cps mariadb-columnstore-tpcds]# jobsError during mcsapi initialization: Could not read data: EOF
 
Error during mcsapi initialization: Could not read data: EOF
 
Error during mcsapi initialization: Could not read data: EOF
 
Error during mcsapi initialization: Could not read data: EOF
 
Error during mcsapi initialization: Could not read data: EOF
 
Error during mcsapi initialization: Could not read data: EOF
 
Error during mcsapi initialization: Could not read data: EOF
 
Error during mcsapi initialization: Error during mcsapi initialization: Could not read data: EOF
 
Error during mcsapi initialization: Could not read data: EOF
 
Error during mcsapi initialization: Could not read data: EOF
 
Error during mcsapi initialization: Could not read data: EOF
 
Error during mcsapi initialization: Could not read data: EOF
 
Error during mcsapi initialization: Could not read data: EOF
 
Error during mcsapi initialization: Could not read data: EOF
 
Error during mcsapi initialization: Could not read data: EOF
 
Error during mcsapi initialization: Could not read data: EOF
 
Error during mcsapi initialization: Could not read data: EOF
 
Error during mcsapi initialization: Could not read data: EOF
 
Error during mcsapi initialization: Could not read data: EOF
 
Error during mcsapi initialization: Could not read data: EOF
 
Could not read data: EOF
 
Error during mcsapi initialization: Could not read data: EOF
 
Error during mcsapi initialization: Could not read data: EOF
 
Error during mcsapi initialization: Could not read data: EOF
 



 
 
  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
 
 3438 root      20   0 1860976  16032  10608 S 300.3  0.0   2:20.71 controllernode
 
  629 ovirtag+  20   0  451680  12636   5476 S   0.3  0.0  84:29.11 python
 
 6938 root      20   0  161972   2296   1580 R   0.3  0.0   0:00.03 top
 
    1 root      20   0  191548   2996   2020 S   0.0  0.0   0:06.77 systemd
 
    2 root      20   0       0      0      0 S   0.0  0.0   0:00.25 kthreadd
 
    3 root      20   0       0      0      0 S   0.0  0.0   0:01.97 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:09.81 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   4:28.74 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:09.63 watchdog/0
 
   12 root      rt   0       0      0      0 S   0.0  0.0   0:08.96 watchdog/1
 
   13 root      rt   0       0      0      0 S   0.0  0.0   0:09.50 migration/1
 
   14 root      20   0       0      0      0 S   0.0  0.0   0:06.02 ksoftirqd/1
 
   16 root       0 -20       0      0      0 S   0.0  0.0   0:00.00 kworker/1:0H
 
   17 root      rt   0       0      0      0 S   0.0  0.0   0:09.10 watchdog/2
 
 
 
 

Dec 14 13:31:17 cps ServerMonitor[9157]: 17.188334 |0|0|0| W 09 CAL0000: / alarm # 5 cleared
Dec 14 13:31:17 cps ServerMonitor[9157]: 17.190685 |0|0|0| W 09 CAL0000: / alarm # 6 cleared
Dec 14 13:32:00 cps ProcessMonitor[1203]: 00.560304 |0|0|0| C 18 CAL0000: *****MariaDB ColumnStore Process Restarting: DBRMControllerNode, old PID = 27579
Dec 14 13:32:00 cps ProcessMonitor[1203]: 00.560508 |0|0|0| D 18 CAL0000: STOPPING Process: DBRMControllerNode
Dec 14 13:32:00 cps ProcessMonitor[1203]: 00.560643 |0|0|0| D 18 CAL0000: Send SET Alarm ID 13 on device DBRMControllerNode
Dec 14 13:32:00 cps ProcessMonitor[1203]: 00.560775 |0|0|0| D 18 CAL0000: StatusUpdate of Process DBRMControllerNode State = 1 PID = 0
Dec 14 13:32:00 cps ProcessMonitor[1203]: 00.565322 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/DBRMControllerNode State = AUTO_OFFLINE
Dec 14 13:32:00 cps ProcessMonitor[1203]: 00.565368 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/DBRMControllerNode State = AUTO_OFFLINE PID = 0
Dec 14 13:32:00 cps ProcessMonitor[1203]: 00.565970 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 25 on device DBRMControllerNode
Dec 14 13:32:00 cps ProcessMonitor[1203]: 00.566888 |0|0|0| D 18 CAL0000: Send SET Alarm ID 13 on device DBRMControllerNode
Dec 14 13:32:00 cps ProcessMonitor[1203]: 00.575111 |0|0|0| D 18 CAL0000: Pkill Process just to make sure: controllernode*
Dec 14 13:32:00 cps ProcessMonitor[1203]: 00.575202 |0|0|0| D 18 CAL0000: STARTING Process: DBRMControllerNode
Dec 14 13:32:00 cps ProcessMonitor[1203]: 00.575221 |0|0|0| D 18 CAL0000: Process location: /usr/local/mariadb/columnstore/bin/controllernode
Dec 14 13:32:00 cps ProcessMonitor[1203]: 00.575696 |0|0|0| D 18 CAL0000: Dependent process of ProcessManager/pm1 is 4
Dec 14 13:32:02 cps ProcessMonitor[1203]: 02.614417 |0|0|0| D 18 CAL0000: BRM reset_locks script run
Dec 14 13:32:03 cps ProcessMonitor[1203]: 03.103242 |0|0|0| D 18 CAL0000: Clear Shared Memory script run
Dec 14 13:32:03 cps ProcessMonitor[1203]: 03.103307 |0|0|0| D 18 CAL0000: load_brm cmd = /usr/local/mariadb/columnstore/bin/load_brm /usr/local/mariadb/columnstore/data1/systemFiles/dbrm/BRM_savesA > / var/log/mariadb/columnstore/load_brm.log1 2>&1
Dec 14 13:32:03 cps ProcessMonitor[1203]: 03.181417 |0|0|0| D 18 CAL0000: Successfully return from load_brm
Dec 14 13:32:03 cps ProcessMonitor[1203]: 03.185011 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 27 on device DBRM
Dec 14 13:32:03 cps ProcessMonitor[1203]: 03.196671 |0|0|0| D 18 CAL0000: Pkill Process just to make sure: controllernode*
Dec 14 13:32:03 cps ProcessMonitor[1203]: 03.196778 |0|0|0| D 18 CAL0000: StatusUpdate of Process DBRMControllerNode State = 3 PID = 0
Dec 14 13:32:03 cps ProcessMonitor[1203]: 03.197500 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/DBRMControllerNode State = AUTO_INIT
Dec 14 13:32:03 cps ProcessMonitor[1203]: 03.197545 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/DBRMControllerNode State = AUTO_INIT PID = 0
Dec 14 13:32:04 cps ProcessMonitor[1203]: 04.215839 |0|0|0| D 18 CAL0000: StatusUpdate of Process DBRMControllerNode State = 21 PID = 3438
Dec 14 13:32:04 cps ProcessMonitor[1203]: 04.216866 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/DBRMControllerNode State = PID_UPDATE
Dec 14 13:32:04 cps ProcessMonitor[1203]: 04.216913 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/DBRMControllerNode State = PID_UPDATE PID = 3438
Dec 14 13:32:04 cps ProcessMonitor[1203]: 04.217015 |0|0|0| D 18 CAL0000: DBRMControllerNode PID is 3438
Dec 14 13:32:04 cps ProcessMonitor[1203]: 04.217308 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 21 on device DBRMControllerNode
Dec 14 13:32:04 cps ProcessMonitor[1203]: 04.217841 |0|0|0| D 18 CAL0000: Inform Process Mgr that process was restarted: DBRMControllerNode
Dec 14 13:32:04 cps ProcessMonitor[1203]: 04.218313 |0|0|0| D 18 CAL0000: Inform Process Mgr that process was restarted: DBRMControllerNode
Dec 14 13:32:04 cps ProcessMonitor[1203]: 04.218524 |0|0|0| I 18 CAL0000: MariaDB ColumnStore Process DBRMControllerNode restarted successfully!!
Dec 14 13:32:04 cps ProcessMonitor[1203]: 04.218833 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 13 on device DBRMControllerNode
Dec 14 13:32:04 cps ProcessManager[20607]: 04.221898 |0|0|0| I 17 CAL0000: MSG RECEIVED: Process Restarted on pm1/DBRMControllerNode
Dec 14 13:32:04 cps ProcessManager[20607]: 04.221998 |0|0|0| D 17 CAL0000: setQuerySystemState called = 0
Dec 14 13:32:04 cps controllernode[20607]: 04.222548 |0|0|0| E 29 CAL0000: DBRM: error: SessionManager::clearSystemState() failed (network)
Dec 14 13:32:04 cps ProcessManager[20607]: 04.222585 |0|0|0| D 17 CAL0000: setSystemQueryReady = 0
Dec 14 13:32:04 cps controllernode[20607]: 04.224363 |0|0|0| E 29 CAL0000: DBRM: error: SessionManager::clearSystemState() failed (network)
Dec 14 13:32:04 cps ProcessManager[20607]: 04.224396 |0|0|0| D 17 CAL0000: setSystemReady = 0
Dec 14 13:32:04 cps ProcessManager[20607]: 04.227198 |0|0|0| D 17 CAL0000: Set System State = BUSY_INIT
Dec 14 13:32:04 cps ProcessMonitor[1203]: 04.227431 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 25 on device DBRMControllerNode
Dec 14 13:32:04 cps ProcessManager[20607]: 04.227815 |0|0|0| I 17 CAL0000: MSG RECEIVED: Process Restarted on pm1/DBRMControllerNode
Dec 14 13:32:04 cps ProcessManager[20607]: 04.227971 |0|0|0| D 17 CAL0000: setQuerySystemState called = 0
Dec 14 13:32:04 cps ProcessMonitor[1203]: 04.228238 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set System State = BUSY_INIT
Dec 14 13:32:04 cps controllernode[20607]: 04.228437 |0|0|0| E 29 CAL0000: DBRM: error: SessionManager::clearSystemState() failed (network)
Dec 14 13:32:04 cps ProcessManager[20607]: 04.228478 |0|0|0| D 17 CAL0000: setSystemQueryReady = 0
Dec 14 13:32:04 cps controllernode[20607]: 04.229235 |0|0|0| E 29 CAL0000: DBRM: error: SessionManager::clearSystemState() failed (network)
Dec 14 13:32:04 cps ProcessManager[20607]: 04.229272 |0|0|0| D 17 CAL0000: setSystemReady = 0
Dec 14 13:32:04 cps ProcessManager[20607]: 04.229704 |0|0|0| D 17 CAL0000: Set System State = BUSY_INIT
Dec 14 13:32:04 cps ProcessManager[20607]: 04.231692 |0|0|0| D 17 CAL0000: reinitProcessType: ReInit all cpimport
Dec 14 13:32:04 cps ProcessMonitor[1203]: 04.231713 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set System State = BUSY_INIT
Dec 14 13:32:04 cps ProcessManager[20607]: 04.234384 |0|0|0| D 17 CAL0000: reinitProcessType: ReInit all cpimport
Dec 14 13:32:04 cps ProcessManager[20607]: 04.235520 |0|0|0| D 17 CAL0000: sendMsgProcMon: Process module pm1
Dec 14 13:32:04 cps ProcessManager[20607]: 04.235750 |0|0|0| D 17 CAL0000: cpimport process is reinited by request.
Dec 14 13:32:04 cps ProcessManager[20607]: 04.235783 |0|0|0| D 17 CAL0000: reinitProcessType: ACK received from Process-Monitor, return status = 0
Dec 14 13:32:04 cps ProcessMonitor[1203]: 04.235997 |0|0|0| I 18 CAL0000: MSG RECEIVED: Re-Init process request on: cpimport
Dec 14 13:32:04 cps ProcessManager[20607]: 04.239641 |0|0|0| D 17 CAL0000: sendMsgProcMon: Process module pm1
Dec 14 13:32:04 cps ProcessMonitor[1203]: 04.249813 |0|0|0| I 18 CAL0000: PROCREINITPROCESS: completed, no ack to ProcMgr
Dec 14 13:32:05 cps ProcessMonitor[1203]: 05.247720 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/DBRMControllerNode State = ACTIVE
Dec 14 13:32:05 cps ProcessMonitor[1203]: 05.247767 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/DBRMControllerNode State = ACTIVE PID = 3438
Dec 14 13:32:05 cps ProcessManager[20607]: 05.250133 |0|0|0| D 17 CAL0000: cpimport process is reinited by request.
Dec 14 13:32:05 cps ProcessManager[20607]: 05.250177 |0|0|0| D 17 CAL0000: reinitProcessType: ACK received from Process-Monitor, return status = 0
Dec 14 13:32:05 cps ProcessMonitor[1203]: 05.250573 |0|0|0| I 18 CAL0000: MSG RECEIVED: Re-Init process request on: cpimport
Dec 14 13:32:05 cps ProcessManager[20607]: 05.254776 |0|0|0| D 17 CAL0000: restartProcessType: Restart all DDLProc
Dec 14 13:32:05 cps ProcessManager[20607]: 05.257860 |0|0|0| D 17 CAL0000: setPMProcIPs called for pm1
Dec 14 13:32:05 cps ProcessManager[20607]: 05.258671 |0|0|0| D 17 CAL0000: setPMProcIPs for DDLProc: no update needed
Dec 14 13:32:05 cps ProcessManager[20607]: 05.259457 |0|0|0| D 17 CAL0000: setPMProcIPs for DMLProc: no update needed, exiting function
Dec 14 13:32:05 cps ProcessManager[20607]: 05.259525 |0|0|0| D 17 CAL0000: distributeConfigFile called for system file = Columnstore.xml
Dec 14 13:32:05 cps ProcessMonitor[1203]: 05.265714 |0|0|0| I 18 CAL0000: PROCREINITPROCESS: completed, no ack to ProcMgr
Dec 14 13:32:06 cps ProcessManager[20607]: 06.243144 |0|0|0| D 17 CAL0000: restartProcessType: Restart all DDLProc
Dec 14 13:32:06 cps ProcessManager[20607]: 06.246130 |0|0|0| D 17 CAL0000: setPMProcIPs called for pm1
Dec 14 13:32:06 cps ProcessManager[20607]: 06.246952 |0|0|0| D 17 CAL0000: setPMProcIPs for DDLProc: no update needed
Dec 14 13:32:06 cps ProcessManager[20607]: 06.247731 |0|0|0| D 17 CAL0000: setPMProcIPs for DMLProc: no update needed, exiting function
Dec 14 13:32:06 cps ProcessManager[20607]: 06.247798 |0|0|0| D 17 CAL0000: distributeConfigFile called for system file = Columnstore.xml
Dec 14 13:32:06 cps ProcessManager[20607]: 06.266321 |0|0|0| D 17 CAL0000: sendMsgProcMon: Process module pm1
Dec 14 13:32:06 cps ProcessMonitor[1203]: 06.266679 |0|0|0| I 18 CAL0000: MSG RECEIVED: Restart process request on DDLProc
Dec 14 13:32:06 cps ProcessMonitor[1203]: 06.266759 |0|0|0| D 18 CAL0000: STOPPING Process: DDLProc
Dec 14 13:32:06 cps ProcessMonitor[1203]: 06.266885 |0|0|0| D 18 CAL0000: StatusUpdate of Process DDLProc State = 0 PID = 0
Dec 14 13:32:06 cps ProcessMonitor[1203]: 06.267051 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 25 on device DDLProc
Dec 14 13:32:06 cps ProcessMonitor[1203]: 06.271483 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/DDLProc State = MAN_OFFLINE
Dec 14 13:32:06 cps ProcessMonitor[1203]: 06.271521 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/DDLProc State = MAN_OFFLINE PID = 0
Dec 14 13:32:06 cps ProcessMonitor[1203]: 06.272981 |0|0|0| D 18 CAL0000: Send SET Alarm ID 21 on device DDLProc
Dec 14 13:32:06 cps ProcessMonitor[1203]: 06.281283 |0|0|0| D 18 CAL0000: Pkill Process just to make sure: DDLProc*
Dec 14 13:32:06 cps ProcessMonitor[1203]: 06.281551 |0|0|0| D 18 CAL0000: checkSpecialProcessState on : DDLProc
Dec 14 13:32:06 cps ProcessMonitor[1203]: 06.281580 |0|0|0| D 18 CAL0000: checkSpecialProcessState status return : 2
Dec 14 13:32:06 cps ProcessMonitor[1203]: 06.281639 |0|0|0| D 18 CAL0000: STARTING Process: DDLProc
Dec 14 13:32:06 cps ProcessMonitor[1203]: 06.281655 |0|0|0| D 18 CAL0000: Process location: /usr/local/mariadb/columnstore/bin/DDLProc
Dec 14 13:32:06 cps ProcessMonitor[1203]: 06.282277 |0|0|0| D 18 CAL0000: Dependent process of WriteEngineServer/pm1 is 4
Dec 14 13:32:06 cps ProcessMonitor[1203]: 06.284513 |0|0|0| D 18 CAL0000: Dependent process of DBRMWorkerNode/pm1 is 4
Dec 14 13:32:06 cps ProcessMonitor[1203]: 06.285022 |0|0|0| D 18 CAL0000: Dependent process of ExeMgr/pm1 is 4
Dec 14 13:32:06 cps ProcessMonitor[1203]: 06.286885 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 27 on device DBRM
Dec 14 13:32:06 cps ProcessMonitor[1203]: 06.300050 |0|0|0| D 18 CAL0000: Pkill Process just to make sure: DDLProc*
Dec 14 13:32:06 cps ProcessMonitor[1203]: 06.300157 |0|0|0| D 18 CAL0000: StatusUpdate of Process DDLProc State = 2 PID = 0
Dec 14 13:32:06 cps ProcessMonitor[1203]: 06.300856 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/DDLProc State = MAN_INIT
Dec 14 13:32:06 cps ProcessMonitor[1203]: 06.300892 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/DDLProc State = MAN_INIT PID = 0
Dec 14 13:32:07 cps ProcessManager[20607]: 07.253461 |0|0|0| D 17 CAL0000: sendMsgProcMon: Process module pm1
Dec 14 13:32:07 cps ProcessMonitor[1203]: 07.318358 |0|0|0| D 18 CAL0000: StatusUpdate of Process DDLProc State = 21 PID = 3507
Dec 14 13:32:07 cps ProcessMonitor[1203]: 07.319166 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/DDLProc State = PID_UPDATE
Dec 14 13:32:07 cps ProcessMonitor[1203]: 07.319202 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/DDLProc State = PID_UPDATE PID = 3507
Dec 14 13:32:07 cps ProcessMonitor[1203]: 07.319309 |0|0|0| D 18 CAL0000: DDLProc PID is 3507
Dec 14 13:32:07 cps ProcessMonitor[1203]: 07.319603 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 21 on device DDLProc
Dec 14 13:32:07 cps ProcessMonitor[1203]: 07.320965 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 13 on device DDLProc
Dec 14 13:32:07 cps ProcessMonitor[1203]: 07.322585 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 25 on device DDLProc
Dec 14 13:32:08 cps ProcessMonitor[1203]: 08.366078 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/DDLProc State = ACTIVE
Dec 14 13:32:08 cps ProcessMonitor[1203]: 08.366129 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/DDLProc State = ACTIVE PID = 3507
Dec 14 13:32:10 cps ProcessMonitor[1203]: 10.320336 |0|0|0| I 18 CAL0000: RESTART: ACK back to ProcMgr, return status = 0
Dec 14 13:32:10 cps ProcessManager[20607]: 10.320491 |0|0|0| D 17 CAL0000: DDLProc process is restarted by request.
Dec 14 13:32:10 cps ProcessManager[20607]: 10.320526 |0|0|0| D 17 CAL0000: restartProcessType: Start ACK received from Process-Monitor, return status = 0
Dec 14 13:32:10 cps ProcessManager[20607]: 10.321480 |0|0|0| D 17 CAL0000: setPMProcIPs called for pm1
Dec 14 13:32:10 cps ProcessManager[20607]: 10.322306 |0|0|0| D 17 CAL0000: setPMProcIPs for DDLProc: no update needed
Dec 14 13:32:10 cps ProcessManager[20607]: 10.322522 |0|0|0| D 17 CAL0000: restartProcessType: Restart all DMLProc
Dec 14 13:32:10 cps ProcessManager[20607]: 10.325370 |0|0|0| D 17 CAL0000: setPMProcIPs called for pm1
Dec 14 13:32:10 cps ProcessManager[20607]: 10.326193 |0|0|0| D 17 CAL0000: setPMProcIPs for DDLProc: no update needed
Dec 14 13:32:10 cps ProcessManager[20607]: 10.326978 |0|0|0| D 17 CAL0000: setPMProcIPs for DMLProc: no update needed, exiting function
Dec 14 13:32:10 cps ProcessManager[20607]: 10.327045 |0|0|0| D 17 CAL0000: distributeConfigFile called for system file = Columnstore.xml
Dec 14 13:32:11 cps ProcessMonitor[1203]: 11.321615 |0|0|0| I 18 CAL0000: MSG RECEIVED: Restart process request on DDLProc
Dec 14 13:32:11 cps ProcessMonitor[1203]: 11.321707 |0|0|0| D 18 CAL0000: STOPPING Process: DDLProc
Dec 14 13:32:11 cps ProcessMonitor[1203]: 11.321825 |0|0|0| D 18 CAL0000: StatusUpdate of Process DDLProc State = 0 PID = 0
Dec 14 13:32:11 cps ProcessMonitor[1203]: 11.325286 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 25 on device DDLProc
Dec 14 13:32:11 cps ProcessMonitor[1203]: 11.326784 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/DDLProc State = MAN_OFFLINE
Dec 14 13:32:11 cps ProcessMonitor[1203]: 11.326822 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/DDLProc State = MAN_OFFLINE PID = 0
Dec 14 13:32:11 cps ProcessMonitor[1203]: 11.327627 |0|0|0| D 18 CAL0000: Send SET Alarm ID 21 on device DDLProc
Dec 14 13:32:11 cps ProcessManager[20607]: 11.332525 |0|0|0| D 17 CAL0000: sendMsgProcMon: Process module pm1
Dec 14 13:32:11 cps ProcessMonitor[1203]: 11.337514 |0|0|0| D 18 CAL0000: Pkill Process just to make sure: DDLProc*
Dec 14 13:32:11 cps ProcessMonitor[1203]: 11.337789 |0|0|0| D 18 CAL0000: checkSpecialProcessState on : DDLProc
Dec 14 13:32:11 cps ProcessMonitor[1203]: 11.337821 |0|0|0| D 18 CAL0000: checkSpecialProcessState status return : 2
Dec 14 13:32:11 cps ProcessMonitor[1203]: 11.337881 |0|0|0| D 18 CAL0000: STARTING Process: DDLProc
Dec 14 13:32:11 cps ProcessMonitor[1203]: 11.337899 |0|0|0| D 18 CAL0000: Process location: /usr/local/mariadb/columnstore/bin/DDLProc
Dec 14 13:32:11 cps ProcessMonitor[1203]: 11.338573 |0|0|0| D 18 CAL0000: Dependent process of WriteEngineServer/pm1 is 4
Dec 14 13:32:11 cps ProcessMonitor[1203]: 11.340801 |0|0|0| D 18 CAL0000: Dependent process of DBRMWorkerNode/pm1 is 4
Dec 14 13:32:11 cps ProcessMonitor[1203]: 11.341307 |0|0|0| D 18 CAL0000: Dependent process of ExeMgr/pm1 is 4
Dec 14 13:32:11 cps ProcessMonitor[1203]: 11.346526 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 27 on device DBRM
Dec 14 13:32:11 cps ProcessMonitor[1203]: 11.358169 |0|0|0| D 18 CAL0000: Pkill Process just to make sure: DDLProc*
Dec 14 13:32:11 cps ProcessMonitor[1203]: 11.358290 |0|0|0| D 18 CAL0000: StatusUpdate of Process DDLProc State = 2 PID = 0
Dec 14 13:32:11 cps ProcessMonitor[1203]: 11.358962 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/DDLProc State = MAN_INIT
Dec 14 13:32:11 cps ProcessMonitor[1203]: 11.359000 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/DDLProc State = MAN_INIT PID = 0
Dec 14 13:32:12 cps ProcessMonitor[1203]: 12.380121 |0|0|0| D 18 CAL0000: StatusUpdate of Process DDLProc State = 21 PID = 3586
Dec 14 13:32:12 cps ProcessMonitor[1203]: 12.381002 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/DDLProc State = PID_UPDATE
Dec 14 13:32:12 cps ProcessMonitor[1203]: 12.381042 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/DDLProc State = PID_UPDATE PID = 3586
Dec 14 13:32:12 cps ProcessMonitor[1203]: 12.381168 |0|0|0| D 18 CAL0000: DDLProc PID is 3586
Dec 14 13:32:12 cps ProcessMonitor[1203]: 12.381543 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 13 on device DDLProc
Dec 14 13:32:12 cps ProcessMonitor[1203]: 12.382857 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 25 on device DDLProc
Dec 14 13:32:12 cps ProcessMonitor[1203]: 12.383874 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 21 on device DDLProc
Dec 14 13:32:13 cps ProcessMonitor[1203]: 13.424613 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/DDLProc State = ACTIVE
Dec 14 13:32:13 cps ProcessMonitor[1203]: 13.424656 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/DDLProc State = ACTIVE PID = 3586
Dec 14 13:32:15 cps ProcessMonitor[1203]: 15.381766 |0|0|0| I 18 CAL0000: RESTART: ACK back to ProcMgr, return status = 0
Dec 14 13:32:15 cps ProcessManager[20607]: 15.381915 |0|0|0| D 17 CAL0000: DDLProc process is restarted by request.
Dec 14 13:32:15 cps ProcessManager[20607]: 15.381974 |0|0|0| D 17 CAL0000: restartProcessType: Start ACK received from Process-Monitor, return status = 0
Dec 14 13:32:15 cps ProcessManager[20607]: 15.382819 |0|0|0| D 17 CAL0000: setPMProcIPs called for pm1
Dec 14 13:32:15 cps ProcessManager[20607]: 15.383649 |0|0|0| D 17 CAL0000: setPMProcIPs for DDLProc: no update needed
Dec 14 13:32:15 cps ProcessManager[20607]: 15.383846 |0|0|0| D 17 CAL0000: restartProcessType: Restart all DMLProc
Dec 14 13:32:15 cps ProcessManager[20607]: 15.386800 |0|0|0| D 17 CAL0000: setPMProcIPs called for pm1
Dec 14 13:32:15 cps ProcessManager[20607]: 15.387625 |0|0|0| D 17 CAL0000: setPMProcIPs for DDLProc: no update needed
Dec 14 13:32:15 cps ProcessManager[20607]: 15.388409 |0|0|0| D 17 CAL0000: setPMProcIPs for DMLProc: no update needed, exiting function
Dec 14 13:32:15 cps ProcessManager[20607]: 15.388478 |0|0|0| D 17 CAL0000: distributeConfigFile called for system file = Columnstore.xml
Dec 14 13:32:16 cps ProcessMonitor[1203]: 16.383206 |0|0|0| I 18 CAL0000: MSG RECEIVED: Restart process request on DMLProc
Dec 14 13:32:16 cps ProcessMonitor[1203]: 16.383290 |0|0|0| D 18 CAL0000: STOPPING Process: DMLProc
Dec 14 13:32:16 cps ProcessMonitor[1203]: 16.383422 |0|0|0| D 18 CAL0000: StatusUpdate of Process DMLProc State = 0 PID = 0
Dec 14 13:32:16 cps ProcessMonitor[1203]: 16.383688 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 25 on device DMLProc
Dec 14 13:32:16 cps ProcessMonitor[1203]: 16.388237 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/DMLProc State = MAN_OFFLINE
Dec 14 13:32:16 cps ProcessMonitor[1203]: 16.388292 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/DMLProc State = MAN_OFFLINE PID = 0
Dec 14 13:32:16 cps ProcessMonitor[1203]: 16.388458 |0|0|0| D 18 CAL0000: Send SET Alarm ID 21 on device DMLProc
Dec 14 13:32:16 cps ProcessManager[20607]: 16.393904 |0|0|0| D 17 CAL0000: sendMsgProcMon: Process module pm1
Dec 14 13:32:16 cps ProcessMonitor[1203]: 16.399084 |0|0|0| D 18 CAL0000: Pkill Process just to make sure: DMLProc*
Dec 14 13:32:16 cps ProcessMonitor[1203]: 16.399338 |0|0|0| D 18 CAL0000: checkSpecialProcessState on : DMLProc
Dec 14 13:32:16 cps ProcessMonitor[1203]: 16.399370 |0|0|0| D 18 CAL0000: checkSpecialProcessState status return : 2
Dec 14 13:32:16 cps ProcessMonitor[1203]: 16.399437 |0|0|0| D 18 CAL0000: STARTING Process: DMLProc
Dec 14 13:32:16 cps ProcessMonitor[1203]: 16.399454 |0|0|0| D 18 CAL0000: Process location: /usr/local/mariadb/columnstore/bin/DMLProc
Dec 14 13:32:16 cps ProcessMonitor[1203]: 16.400043 |0|0|0| D 18 CAL0000: Dependent process of WriteEngineServer/pm1 is 4
Dec 14 13:32:16 cps ProcessMonitor[1203]: 16.402293 |0|0|0| D 18 CAL0000: Dependent process of DBRMWorkerNode/pm1 is 4
Dec 14 13:32:16 cps ProcessMonitor[1203]: 16.402782 |0|0|0| D 18 CAL0000: Dependent process of DDLProc/pm1 is 4
Dec 14 13:32:16 cps ProcessMonitor[1203]: 16.405582 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 27 on device DBRM
Dec 14 13:32:16 cps ProcessMonitor[1203]: 16.416428 |0|0|0| D 18 CAL0000: Pkill Process just to make sure: DMLProc*
Dec 14 13:32:16 cps ProcessMonitor[1203]: 16.416534 |0|0|0| D 18 CAL0000: StatusUpdate of Process DMLProc State = 2 PID = 0
Dec 14 13:32:16 cps ProcessMonitor[1203]: 16.417190 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/DMLProc State = MAN_INIT
Dec 14 13:32:16 cps ProcessMonitor[1203]: 16.417219 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/DMLProc State = MAN_INIT PID = 0
Dec 14 13:32:17 cps ProcessMonitor[1203]: 17.439067 |0|0|0| D 18 CAL0000: StatusUpdate of Process DMLProc State = 21 PID = 3662
Dec 14 13:32:17 cps ProcessMonitor[1203]: 17.440024 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/DMLProc State = PID_UPDATE
Dec 14 13:32:17 cps ProcessMonitor[1203]: 17.440072 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/DMLProc State = PID_UPDATE PID = 3662
Dec 14 13:32:17 cps ProcessMonitor[1203]: 17.440141 |0|0|0| D 18 CAL0000: DMLProc PID is 3662
Dec 14 13:32:17 cps ProcessMonitor[1203]: 17.440409 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 21 on device DMLProc
Dec 14 13:32:17 cps ProcessMonitor[1203]: 17.441436 |0|0|0| I 18 CAL0000: RESTART: ACK back to ProcMgr, return status = 0
Dec 14 13:32:17 cps ProcessManager[20607]: 17.441509 |0|0|0| D 17 CAL0000: DMLProc process is restarted by request.
Dec 14 13:32:17 cps ProcessManager[20607]: 17.441560 |0|0|0| D 17 CAL0000: restartProcessType: Start ACK received from Process-Monitor, return status = 0
Dec 14 13:32:17 cps ProcessMonitor[1203]: 17.442732 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 13 on device DMLProc
Dec 14 13:32:17 cps ProcessManager[20607]: 17.443454 |0|0|0| D 17 CAL0000: setPMProcIPs called for pm1
Dec 14 13:32:17 cps ProcessManager[20607]: 17.444990 |0|0|0| D 17 CAL0000: setPMProcIPs for DMLProc: no update needed, exiting function
Dec 14 13:32:17 cps ProcessMonitor[1203]: 17.445110 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 25 on device DMLProc
Dec 14 13:32:18 cps ProcessMonitor[1203]: 18.441871 |0|0|0| I 18 CAL0000: MSG RECEIVED: Restart process request on DMLProc
Dec 14 13:32:18 cps ProcessMonitor[1203]: 18.441988 |0|0|0| D 18 CAL0000: STOPPING Process: DMLProc
Dec 14 13:32:18 cps ProcessMonitor[1203]: 18.442108 |0|0|0| D 18 CAL0000: StatusUpdate of Process DMLProc State = 0 PID = 0
Dec 14 13:32:18 cps ProcessMonitor[1203]: 18.442292 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 25 on device DMLProc
Dec 14 13:32:18 cps ProcessMonitor[1203]: 18.448293 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/DMLProc State = MAN_OFFLINE
Dec 14 13:32:18 cps ProcessMonitor[1203]: 18.448337 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/DMLProc State = MAN_OFFLINE PID = 0
Dec 14 13:32:18 cps ProcessMonitor[1203]: 18.448689 |0|0|0| D 18 CAL0000: Send SET Alarm ID 21 on device DMLProc
Dec 14 13:32:18 cps ProcessMonitor[1203]: 18.458708 |0|0|0| D 18 CAL0000: Pkill Process just to make sure: DMLProc*
Dec 14 13:32:18 cps ProcessMonitor[1203]: 18.459000 |0|0|0| D 18 CAL0000: checkSpecialProcessState on : DMLProc
Dec 14 13:32:18 cps ProcessMonitor[1203]: 18.459030 |0|0|0| D 18 CAL0000: checkSpecialProcessState status return : 2
Dec 14 13:32:18 cps ProcessMonitor[1203]: 18.459094 |0|0|0| D 18 CAL0000: STARTING Process: DMLProc
Dec 14 13:32:18 cps ProcessMonitor[1203]: 18.459112 |0|0|0| D 18 CAL0000: Process location: /usr/local/mariadb/columnstore/bin/DMLProc
Dec 14 13:32:18 cps ProcessMonitor[1203]: 18.459702 |0|0|0| D 18 CAL0000: Dependent process of WriteEngineServer/pm1 is 4
Dec 14 13:32:18 cps ProcessMonitor[1203]: 18.462130 |0|0|0| D 18 CAL0000: Dependent process of DBRMWorkerNode/pm1 is 4
Dec 14 13:32:18 cps ProcessMonitor[1203]: 18.462619 |0|0|0| D 18 CAL0000: Dependent process of DDLProc/pm1 is 4
Dec 14 13:32:18 cps ProcessMonitor[1203]: 18.465946 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 27 on device DBRM
Dec 14 13:32:18 cps ProcessMonitor[1203]: 18.477983 |0|0|0| D 18 CAL0000: Pkill Process just to make sure: DMLProc*
Dec 14 13:32:18 cps ProcessMonitor[1203]: 18.478088 |0|0|0| D 18 CAL0000: StatusUpdate of Process DMLProc State = 2 PID = 0
Dec 14 13:32:18 cps ProcessMonitor[1203]: 18.478813 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/DMLProc State = MAN_INIT
Dec 14 13:32:18 cps ProcessMonitor[1203]: 18.478852 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/DMLProc State = MAN_INIT PID = 0
Dec 14 13:32:19 cps ProcessMonitor[1203]: 19.498315 |0|0|0| D 18 CAL0000: StatusUpdate of Process DMLProc State = 21 PID = 3739
Dec 14 13:32:19 cps ProcessMonitor[1203]: 19.499175 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/DMLProc State = PID_UPDATE
Dec 14 13:32:19 cps ProcessMonitor[1203]: 19.499222 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/DMLProc State = PID_UPDATE PID = 3739
Dec 14 13:32:19 cps ProcessMonitor[1203]: 19.499348 |0|0|0| D 18 CAL0000: DMLProc PID is 3739
Dec 14 13:32:19 cps ProcessMonitor[1203]: 19.499777 |0|0|0| I 18 CAL0000: RESTART: ACK back to ProcMgr, return status = 0
Dec 14 13:32:19 cps ProcessManager[20607]: 19.499860 |0|0|0| D 17 CAL0000: DMLProc process is restarted by request.
Dec 14 13:32:19 cps ProcessMonitor[1203]: 19.499843 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 13 on device DMLProc
Dec 14 13:32:19 cps ProcessManager[20607]: 19.499899 |0|0|0| D 17 CAL0000: restartProcessType: Start ACK received from Process-Monitor, return status = 0
Dec 14 13:32:19 cps ProcessManager[20607]: 19.500997 |0|0|0| D 17 CAL0000: setPMProcIPs called for pm1
Dec 14 13:32:19 cps ProcessMonitor[1203]: 19.501389 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 21 on device DMLProc
Dec 14 13:32:19 cps ProcessManager[20607]: 19.502393 |0|0|0| D 17 CAL0000: setPMProcIPs for DMLProc: no update needed, exiting function
Dec 14 13:32:19 cps ProcessMonitor[1203]: 19.503025 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 25 on device DMLProc
Dec 14 13:32:20 cps ProcessMonitor[1203]: 20.540517 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/DMLProc State = BUSY_INIT
Dec 14 13:32:20 cps ProcessMonitor[1203]: 20.540565 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/DMLProc State = BUSY_INIT PID = 3739
Dec 14 13:32:20 cps ProcessMonitor[1203]: 20.540588 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set System State = BUSY_INIT
Dec 14 13:32:20 cps DMLProc[3739]: 20.542227 |0|0|0| I 20 CAL0002: DMLProc starts rollbackAll.
Dec 14 13:32:20 cps DMLProc[3739]: 20.573206 |0|0|0| I 20 CAL0002: DDLCleanup is cleaning table with oid 29534
Dec 14 13:32:20 cps DMLProc[3739]: 20.573624 |0|0|0| I 20 CAL0002: DMLProc will rollback 0 tables.
Dec 14 13:32:20 cps DMLProc[3739]: 20.574004 |0|0|0| I 20 CAL0002: DDLCleanup is cleaning table with oid 46357
Dec 14 13:32:20 cps DMLProc[3739]: 20.585146 |0|0|0| I 20 CAL0002: DMLProc finished rollbackAll.
Dec 14 13:32:20 cps ProcessMonitor[1203]: 20.644783 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/DMLProc State = ACTIVE
Dec 14 13:32:20 cps ProcessMonitor[1203]: 20.644829 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/DMLProc State = ACTIVE PID = 3739
Dec 14 13:32:20 cps ProcessMonitor[1203]: 20.644851 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set System State = ACTIVE
Dec 14 13:32:21 cps ProcessManager[20607]: 21.451157 |0|0|0| D 17 CAL0000: setQuerySystemState called = 1
Dec 14 13:32:21 cps ProcessManager[20607]: 21.451647 |0|0|0| D 17 CAL0000: setSystemQueryReady = 1
Dec 14 13:32:21 cps ProcessManager[20607]: 21.451778 |0|0|0| D 17 CAL0000: setSystemReady = 1
Dec 14 13:32:21 cps ProcessManager[20607]: 21.452385 |0|0|0| D 17 CAL0000: setQuerySystemState called = 1
Dec 14 13:32:21 cps ProcessManager[20607]: 21.452531 |0|0|0| D 17 CAL0000: setSystemQueryReady = 1
Dec 14 13:32:21 cps ProcessManager[20607]: 21.452594 |0|0|0| D 17 CAL0000: setSystemReady = 1
Dec 14 13:32:21 cps ProcessManager[20607]: 21.452844 |0|0|0| D 17 CAL0000: Set System State = ACTIVE
Dec 14 13:32:21 cps ProcessMonitor[1203]: 21.453314 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set System State = ACTIVE
Dec 14 13:32:21 cps ProcessManager[20607]: 21.453515 |0|0|0| D 17 CAL0000: setQuerySystemState called = 1
Dec 14 13:32:21 cps ProcessManager[20607]: 21.453631 |0|0|0| D 17 CAL0000: setSystemQueryReady = 1
Dec 14 13:32:21 cps ProcessManager[20607]: 21.453701 |0|0|0| D 17 CAL0000: setSystemReady = 1
Dec 14 13:32:21 cps ProcessManager[20607]: 21.456002 |0|0|0| I 17 CAL0000: MSG RECEIVED: Process Restarted Completed
Dec 14 13:32:21 cps ProcessManager[20607]: 21.504776 |0|0|0| D 17 CAL0000: setQuerySystemState called = 1
Dec 14 13:32:21 cps ProcessManager[20607]: 21.504882 |0|0|0| D 17 CAL0000: setSystemQueryReady = 1
Dec 14 13:32:21 cps ProcessManager[20607]: 21.504962 |0|0|0| D 17 CAL0000: setSystemReady = 1
Dec 14 13:32:21 cps ProcessManager[20607]: 21.505501 |0|0|0| D 17 CAL0000: setQuerySystemState called = 1
Dec 14 13:32:21 cps ProcessManager[20607]: 21.505582 |0|0|0| D 17 CAL0000: setSystemQueryReady = 1
Dec 14 13:32:21 cps ProcessManager[20607]: 21.505640 |0|0|0| D 17 CAL0000: setSystemReady = 1
Dec 14 13:32:21 cps ProcessManager[20607]: 21.505885 |0|0|0| D 17 CAL0000: Set System State = ACTIVE
Dec 14 13:32:21 cps ProcessMonitor[1203]: 21.506315 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set System State = ACTIVE
Dec 14 13:32:21 cps ProcessManager[20607]: 21.506463 |0|0|0| D 17 CAL0000: setQuerySystemState called = 1
Dec 14 13:32:21 cps ProcessManager[20607]: 21.506553 |0|0|0| D 17 CAL0000: setSystemQueryReady = 1
Dec 14 13:32:21 cps ProcessManager[20607]: 21.506613 |0|0|0| D 17 CAL0000: setSystemReady = 1
Dec 14 13:32:21 cps ProcessManager[20607]: 21.509115 |0|0|0| I 17 CAL0000: MSG RECEIVED: Process Restarted Completed



 Comments   
Comment by Andrew Hutchings (Inactive) [ 2018-12-14 ]

winstone there are likely files in /var/log/mariadb/columnstore/trace which will help us figure out why this happened. Can you please attach those?

Comment by Zdravelina Sokolovska (Inactive) [ 2019-03-25 ] 

Error during mcsapi initialization: Could not read data: EOF
 
Error during mcsapi initialization: Could not read data: EOF
 
Error during mcsapi initialization: Could not read data: EOF
 
Error during mcsapi initialization: Could not read data: EOF
 
Error during mcsapi initialization: Could not read data: EOF
 
Error during mcsapi initialization: Could not read data: EOF
 
Error during mcsapi initialization: Could not read data: EOF
 
Error during mcsapi initialization: Could not read data: EOF
 
Error during mcsapi initialization: Could not read data: EOF
 
Error during mcsapi initialization: Could not read data: EOF
 
Error during mcsapi initialization: Could not read data: EOF
 
Error during mcsapi initialization: Could not read data: EOF
 
Error during mcsapi initialization: Could not read data: EOF
 
Error during mcsapi initialization: Connection failure: ECONNREFUSED
 
Error during mcsapi initialization: Connection failure: ECONNREFUSED
 
Error during mcsapi initialization: Connection failure: ECONNREFUSED
 
Error during mcsapi initialization: Connection failure: ECONNREFUSED
 
Error during mcsapi initialization: Connection failure: ECONNREFUSED
 
Error during mcsapi initialization: Connection failure: ECONNREFUSED
 
Error during mcsapi initialization: Connection failure: ECONNREFUSED
 
Error during mcsapi initialization: Connection failure: ECONNREFUSED
 
Error during mcsapi initialization: Connection failure: ECONNREFUSED
 



Mar 25 13:25:32 cps1 ProcessMonitor[17820]: 32.464615 |0|0|0| C 18 CAL0000: *****MariaDB ColumnStore Process Restarting: DBRMControllerNode, old PID = 22134
 
Mar 25 13:25:32 cps1 ProcessMonitor[17820]: 32.464907 |0|0|0| D 18 CAL0000: STOPPING Process: DBRMControllerNode
 
Mar 25 13:25:32 cps1 ProcessMonitor[17820]: 32.465171 |0|0|0| D 18 CAL0000: Send SET Alarm ID 13 on device DBRMControllerNode
 
Mar 25 13:25:32 cps1 ProcessMonitor[17820]: 32.465472 |0|0|0| D 18 CAL0000: StatusUpdate of Process DBRMControllerNode State = 1 PID = 0
 
Mar 25 13:25:32 cps1 ProcessMonitor[17820]: 32.469068 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/DBRMControllerNode State = AUTO_OFFLINE
 
Mar 25 13:25:32 cps1 ProcessMonitor[17820]: 32.469116 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/DBRMControllerNode State = AUTO_OFFLINE PID = 0
 
Mar 25 13:25:32 cps1 ProcessMonitor[17820]: 32.469613 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 25 on device DBRMControllerNode
 
Mar 25 13:25:32 cps1 ProcessMonitor[17820]: 32.571451 |0|0|0| D 18 CAL0000: Send SET Alarm ID 13 on device DBRMControllerNode
 
Mar 25 13:25:32 cps1 ProcessMonitor[17820]: 32.575301 |0|0|0| D 18 CAL0000: Pkill Process just to make sure: controllernode\*
 
Mar 25 13:25:32 cps1 ProcessMonitor[17820]: 32.575397 |0|0|0| D 18 CAL0000: STARTING Process: DBRMControllerNode
 
Mar 25 13:25:32 cps1 ProcessMonitor[17820]: 32.575416 |0|0|0| D 18 CAL0000: Process location: /usr/local/mariadb/columnstore/bin/controllernode
 
Mar 25 13:25:32 cps1 ProcessMonitor[17820]: 32.575961 |0|0|0| D 18 CAL0000: Dependent process of ProcessManager/pm1 is 4
 
Mar 25 13:25:34 cps1 ProcessMonitor[17820]: 34.686674 |0|0|0| D 18 CAL0000: BRM reset_locks script run
 
Mar 25 13:25:35 cps1 ProcessMonitor[17820]: 35.127096 |0|0|0| D 18 CAL0000: Clear Shared Memory script run
 
Mar 25 13:25:35 cps1 ProcessMonitor[17820]: 35.127181 |0|0|0| D 18 CAL0000: load_brm cmd = /usr/local/mariadb/columnstore/bin/load_brm /usr/local/mariadb/columnstore/data1/systemFiles/dbrm/BRM_savesA > /var/log/mariadb/columnstore/load_brm.log1 2>&1
 
Mar 25 13:25:35 cps1 ProcessMonitor[17820]: 35.195598 |0|0|0| D 18 CAL0000: Successfully return from load_brm
 
Mar 25 13:25:35 cps1 ProcessMonitor[17820]: 35.197665 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 27 on device DBRM
 
Mar 25 13:25:35 cps1 ProcessMonitor[17820]: 35.208153 |0|0|0| D 18 CAL0000: Pkill Process just to make sure: controllernode\*
 
Mar 25 13:25:35 cps1 ProcessMonitor[17820]: 35.208246 |0|0|0| D 18 CAL0000: StatusUpdate of Process DBRMControllerNode State = 3 PID = 0
 
Mar 25 13:25:35 cps1 ProcessMonitor[17820]: 35.208913 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/DBRMControllerNode State = AUTO_INIT
 
Mar 25 13:25:35 cps1 ProcessMonitor[17820]: 35.208952 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/DBRMControllerNode State = AUTO_INIT PID = 0
 
Mar 25 13:25:36 cps1 ProcessMonitor[17820]: 36.261622 |0|0|0| D 18 CAL0000: StatusUpdate of Process DBRMControllerNode State = 21 PID = 13868
 
Mar 25 13:25:36 cps1 ProcessMonitor[17820]: 36.262528 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/DBRMControllerNode State = PID_UPDATE
 
Mar 25 13:25:36 cps1 ProcessMonitor[17820]: 36.262570 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/DBRMControllerNode State = PID_UPDATE PID = 13868
 
Mar 25 13:25:36 cps1 ProcessMonitor[17820]: 36.262766 |0|0|0| D 18 CAL0000: DBRMControllerNode PID is 13868
 
Mar 25 13:25:36 cps1 ProcessMonitor[17820]: 36.263285 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 21 on device DBRMControllerNode
 
Mar 25 13:25:36 cps1 ProcessMonitor[17820]: 36.263428 |0|0|0| D 18 CAL0000: Inform Process Mgr that process was restarted: DBRMControllerNode
 
Mar 25 13:25:36 cps1 ProcessMonitor[17820]: 36.264479 |0|0|0| D 18 CAL0000: Inform Process Mgr that process was restarted: DBRMControllerNode
 
Mar 25 13:25:36 cps1 ProcessMonitor[17820]: 36.264617 |0|0|0| I 18 CAL0000: MariaDB ColumnStore Process DBRMControllerNode restarted successfully!!
 
Mar 25 13:25:36 cps1 ProcessMonitor[17820]: 36.264713 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 25 on device DBRMControllerNode
 
Mar 25 13:25:36 cps1 ProcessMonitor[17820]: 36.272866 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 13 on device DBRMControllerNode
 
Mar 25 13:25:36 cps1 ProcessManager[17957]: 36.307330 |0|0|0| I 17 CAL0000: MSG RECEIVED: Process Restarted on pm1/DBRMControllerNode
 
Mar 25 13:25:36 cps1 ProcessManager[17957]: 36.307463 |0|0|0| D 17 CAL0000: setQuerySystemState called = 0
 
Mar 25 13:25:36 cps1 controllernode[17957]: 36.329886 |0|0|0| E 29 CAL0000: DBRM: error: SessionManager::clearSystemState() failed (network)
 
Mar 25 13:25:36 cps1 ProcessManager[17957]: 36.329921 |0|0|0| D 17 CAL0000: setSystemQueryReady = 0
 
Mar 25 13:25:36 cps1 controllernode[17957]: 36.330165 |0|0|0| E 29 CAL0000: DBRM: error: SessionManager::clearSystemState() failed (network)
 
Mar 25 13:25:36 cps1 ProcessManager[17957]: 36.330183 |0|0|0| D 17 CAL0000: setSystemReady = 0
 
Mar 25 13:25:36 cps1 ProcessManager[17957]: 36.330441 |0|0|0| D 17 CAL0000: Set System State = BUSY_INIT
 
Mar 25 13:25:36 cps1 ProcessMonitor[17820]: 36.331041 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set System State = BUSY_INIT
 
Mar 25 13:25:36 cps1 ProcessManager[17957]: 36.332431 |0|0|0| D 17 CAL0000: reinitProcessType: ReInit all cpimport
 
Mar 25 13:25:36 cps1 ProcessManager[17957]: 36.339990 |0|0|0| D 17 CAL0000: sendMsgProcMon: Process module pm1
 
Mar 25 13:25:36 cps1 ProcessManager[17957]: 36.340769 |0|0|0| D 17 CAL0000: cpimport process is reinited by request.
 
Mar 25 13:25:36 cps1 ProcessManager[17957]: 36.340809 |0|0|0| D 17 CAL0000: reinitProcessType: ACK received from Process-Monitor, return status = 0
 
Mar 25 13:25:36 cps1 ProcessMonitor[17820]: 36.341147 |0|0|0| I 18 CAL0000: MSG RECEIVED: Re-Init process request on: cpimport
 
Mar 25 13:25:36 cps1 ProcessMonitor[17820]: 36.354294 |0|0|0| I 18 CAL0000: PROCREINITPROCESS: completed, no ack to ProcMgr
 
Mar 25 13:25:37 cps1 ProcessMonitor[17820]: 37.404170 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/DBRMControllerNode State = ACTIVE
 
Mar 25 13:25:37 cps1 ProcessMonitor[17820]: 37.404226 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/DBRMControllerNode State = ACTIVE PID = 13868
 
Mar 25 13:25:38 cps1 ProcessManager[17957]: 38.346389 |0|0|0| D 17 CAL0000: restartProcessType: Restart all DDLProc
 
Mar 25 13:25:38 cps1 ProcessManager[17957]: 38.366701 |0|0|0| D 17 CAL0000: setPMProcIPs called for pm1
 
Mar 25 13:25:38 cps1 ProcessManager[17957]: 38.367539 |0|0|0| D 17 CAL0000: setPMProcIPs for DDLProc: no update needed
 
Mar 25 13:25:38 cps1 ProcessManager[17957]: 38.368323 |0|0|0| D 17 CAL0000: setPMProcIPs for DMLProc: no update needed, exiting function
 
Mar 25 13:25:38 cps1 ProcessManager[17957]: 38.368390 |0|0|0| D 17 CAL0000: distributeConfigFile called for system file = Columnstore.xml
 
Mar 25 13:25:39 cps1 ProcessManager[17957]: 39.405522 |0|0|0| D 17 CAL0000: sendMsgProcMon: Process module pm1
 
Mar 25 13:25:39 cps1 ProcessMonitor[17820]: 39.406145 |0|0|0| I 18 CAL0000: MSG RECEIVED: Restart process request on DDLProc
 
Mar 25 13:25:39 cps1 ProcessMonitor[17820]: 39.406236 |0|0|0| D 18 CAL0000: STOPPING Process: DDLProc
 
Mar 25 13:25:39 cps1 ProcessMonitor[17820]: 39.406360 |0|0|0| D 18 CAL0000: StatusUpdate of Process DDLProc State = 0 PID = 0
 
Mar 25 13:25:39 cps1 ProcessMonitor[17820]: 39.406702 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 25 on device DDLProc
 
Mar 25 13:25:39 cps1 ProcessMonitor[17820]: 39.409602 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/DDLProc State = MAN_OFFLINE
 
Mar 25 13:25:39 cps1 ProcessMonitor[17820]: 39.409647 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/DDLProc State = MAN_OFFLINE PID = 0
 
Mar 25 13:25:39 cps1 ProcessMonitor[17820]: 39.419723 |0|0|0| D 18 CAL0000: Pkill Process just to make sure: DDLProc\*
 
Mar 25 13:25:39 cps1 ProcessMonitor[17820]: 39.419952 |0|0|0| D 18 CAL0000: checkSpecialProcessState on : DDLProc
 
Mar 25 13:25:39 cps1 ProcessMonitor[17820]: 39.419972 |0|0|0| D 18 CAL0000: checkSpecialProcessState status return : 2
 
Mar 25 13:25:39 cps1 ProcessMonitor[17820]: 39.420023 |0|0|0| D 18 CAL0000: STARTING Process: DDLProc
 
Mar 25 13:25:39 cps1 ProcessMonitor[17820]: 39.420038 |0|0|0| D 18 CAL0000: Process location: /usr/local/mariadb/columnstore/bin/DDLProc
 
Mar 25 13:25:39 cps1 ProcessMonitor[17820]: 39.420687 |0|0|0| D 18 CAL0000: Dependent process of WriteEngineServer/pm1 is 4
 
Mar 25 13:25:39 cps1 ProcessMonitor[17820]: 39.423134 |0|0|0| D 18 CAL0000: Dependent process of DBRMWorkerNode/pm1 is 4
 
Mar 25 13:25:39 cps1 ProcessMonitor[17820]: 39.423745 |0|0|0| D 18 CAL0000: Dependent process of ExeMgr/pm1 is 4
 
Mar 25 13:25:39 cps1 ProcessMonitor[17820]: 39.438301 |0|0|0| D 18 CAL0000: Pkill Process just to make sure: DDLProc\*
 
Mar 25 13:25:39 cps1 ProcessMonitor[17820]: 39.438412 |0|0|0| D 18 CAL0000: StatusUpdate of Process DDLProc State = 2 PID = 0
 
Mar 25 13:25:39 cps1 ProcessMonitor[17820]: 39.439137 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/DDLProc State = MAN_INIT
 
Mar 25 13:25:39 cps1 ProcessMonitor[17820]: 39.439172 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/DDLProc State = MAN_INIT PID = 0
 
Mar 25 13:25:39 cps1 ProcessMonitor[17820]: 39.471802 |0|0|0| D 18 CAL0000: Send SET Alarm ID 21 on device DDLProc
 
Mar 25 13:25:39 cps1 ProcessMonitor[17820]: 39.473040 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 27 on device DBRM
 
Mar 25 13:25:40 cps1 ProcessMonitor[17820]: 40.453969 |0|0|0| D 18 CAL0000: StatusUpdate of Process DDLProc State = 21 PID = 13954
 
Mar 25 13:25:40 cps1 ProcessMonitor[17820]: 40.454994 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/DDLProc State = PID_UPDATE
 
Mar 25 13:25:40 cps1 ProcessMonitor[17820]: 40.455044 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/DDLProc State = PID_UPDATE PID = 13954
 
Mar 25 13:25:40 cps1 ProcessMonitor[17820]: 40.455226 |0|0|0| D 18 CAL0000: DDLProc PID is 13954
 
Mar 25 13:25:40 cps1 ProcessMonitor[17820]: 40.455602 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 21 on device DDLProc
 
Mar 25 13:25:40 cps1 ProcessMonitor[17820]: 40.456883 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 25 on device DDLProc
 
Mar 25 13:25:40 cps1 ProcessMonitor[17820]: 40.632672 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 13 on device DDLProc
 
Mar 25 13:25:41 cps1 ProcessMonitor[17820]: 41.500014 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/DDLProc State = ACTIVE
 
Mar 25 13:25:41 cps1 ProcessMonitor[17820]: 41.500073 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/DDLProc State = ACTIVE PID = 13954
 
Mar 25 13:25:43 cps1 ProcessMonitor[17820]: 43.455798 |0|0|0| I 18 CAL0000: RESTART: ACK back to ProcMgr, return status = 0
 
Mar 25 13:25:43 cps1 ProcessManager[17957]: 43.455946 |0|0|0| D 17 CAL0000: DDLProc process is restarted by request.
 
Mar 25 13:25:43 cps1 ProcessManager[17957]: 43.455977 |0|0|0| D 17 CAL0000: restartProcessType: Start ACK received from Process-Monitor, return status = 0
 
Mar 25 13:25:43 cps1 ProcessManager[17957]: 43.456957 |0|0|0| D 17 CAL0000: setPMProcIPs called for pm1
 
Mar 25 13:25:43 cps1 ProcessManager[17957]: 43.457781 |0|0|0| D 17 CAL0000: setPMProcIPs for DDLProc: no update needed
 
Mar 25 13:25:43 cps1 ProcessManager[17957]: 43.457960 |0|0|0| D 17 CAL0000: restartProcessType: Restart all DMLProc
 
Mar 25 13:25:43 cps1 ProcessManager[17957]: 43.460915 |0|0|0| D 17 CAL0000: setPMProcIPs called for pm1
 
Mar 25 13:25:43 cps1 ProcessManager[17957]: 43.461715 |0|0|0| D 17 CAL0000: setPMProcIPs for DDLProc: no update needed
 
Mar 25 13:25:43 cps1 ProcessManager[17957]: 43.462498 |0|0|0| D 17 CAL0000: setPMProcIPs for DMLProc: no update needed, exiting function
 
Mar 25 13:25:43 cps1 ProcessManager[17957]: 43.462558 |0|0|0| D 17 CAL0000: distributeConfigFile called for system file = Columnstore.xml
 
Mar 25 13:25:44 cps1 ProcessManager[17957]: 44.468400 |0|0|0| D 17 CAL0000: sendMsgProcMon: Process module pm1
 
Mar 25 13:25:44 cps1 ProcessMonitor[17820]: 44.468641 |0|0|0| I 18 CAL0000: MSG RECEIVED: Restart process request on DMLProc
 
Mar 25 13:25:44 cps1 ProcessMonitor[17820]: 44.468706 |0|0|0| D 18 CAL0000: STOPPING Process: DMLProc
 
Mar 25 13:25:44 cps1 ProcessMonitor[17820]: 44.468827 |0|0|0| D 18 CAL0000: StatusUpdate of Process DMLProc State = 0 PID = 0
 
Mar 25 13:25:44 cps1 ProcessMonitor[17820]: 44.470953 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 25 on device DMLProc
 
Mar 25 13:25:44 cps1 ProcessMonitor[17820]: 44.472467 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/DMLProc State = MAN_OFFLINE
 
Mar 25 13:25:44 cps1 ProcessMonitor[17820]: 44.472510 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/DMLProc State = MAN_OFFLINE PID = 0
 
Mar 25 13:25:44 cps1 ProcessMonitor[17820]: 44.472677 |0|0|0| D 18 CAL0000: Send SET Alarm ID 21 on device DMLProc
 
Mar 25 13:25:44 cps1 ProcessMonitor[17820]: 44.482714 |0|0|0| D 18 CAL0000: Pkill Process just to make sure: DMLProc\*
 
Mar 25 13:25:44 cps1 ProcessMonitor[17820]: 44.482934 |0|0|0| D 18 CAL0000: checkSpecialProcessState on : DMLProc
 
Mar 25 13:25:44 cps1 ProcessMonitor[17820]: 44.482953 |0|0|0| D 18 CAL0000: checkSpecialProcessState status return : 2
 
Mar 25 13:25:44 cps1 ProcessMonitor[17820]: 44.483004 |0|0|0| D 18 CAL0000: STARTING Process: DMLProc
 
Mar 25 13:25:44 cps1 ProcessMonitor[17820]: 44.483020 |0|0|0| D 18 CAL0000: Process location: /usr/local/mariadb/columnstore/bin/DMLProc
 
Mar 25 13:25:44 cps1 ProcessMonitor[17820]: 44.483729 |0|0|0| D 18 CAL0000: Dependent process of WriteEngineServer/pm1 is 4
 
Mar 25 13:25:44 cps1 ProcessMonitor[17820]: 44.486236 |0|0|0| D 18 CAL0000: Dependent process of DBRMWorkerNode/pm1 is 4
 
Mar 25 13:25:44 cps1 ProcessMonitor[17820]: 44.486863 |0|0|0| D 18 CAL0000: Dependent process of DDLProc/pm1 is 4
 
Mar 25 13:25:44 cps1 ProcessMonitor[17820]: 44.488778 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 27 on device DBRM
 
Mar 25 13:25:44 cps1 ProcessMonitor[17820]: 44.499583 |0|0|0| D 18 CAL0000: Pkill Process just to make sure: DMLProc\*
 
Mar 25 13:25:44 cps1 ProcessMonitor[17820]: 44.499673 |0|0|0| D 18 CAL0000: StatusUpdate of Process DMLProc State = 2 PID = 0
 
Mar 25 13:25:44 cps1 ProcessMonitor[17820]: 44.500500 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/DMLProc State = MAN_INIT
 
Mar 25 13:25:44 cps1 ProcessMonitor[17820]: 44.500538 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/DMLProc State = MAN_INIT PID = 0
 
Mar 25 13:25:45 cps1 ProcessMonitor[17820]: 45.515900 |0|0|0| D 18 CAL0000: StatusUpdate of Process DMLProc State = 21 PID = 14041
 
Mar 25 13:25:45 cps1 ProcessMonitor[17820]: 45.517001 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/DMLProc State = PID_UPDATE
 
Mar 25 13:25:45 cps1 ProcessMonitor[17820]: 45.517060 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/DMLProc State = PID_UPDATE PID = 14041
 
Mar 25 13:25:45 cps1 ProcessMonitor[17820]: 45.517279 |0|0|0| D 18 CAL0000: DMLProc PID is 14041
 
Mar 25 13:25:45 cps1 ProcessMonitor[17820]: 45.517763 |0|0|0| I 18 CAL0000: RESTART: ACK back to ProcMgr, return status = 0
 
Mar 25 13:25:45 cps1 ProcessMonitor[17820]: 45.517823 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 21 on device DMLProc
 
Mar 25 13:25:45 cps1 ProcessManager[17957]: 45.517853 |0|0|0| D 17 CAL0000: DMLProc process is restarted by request.
 
Mar 25 13:25:45 cps1 ProcessManager[17957]: 45.517891 |0|0|0| D 17 CAL0000: restartProcessType: Start ACK received from Process-Monitor, return status = 0
 
Mar 25 13:25:45 cps1 ProcessManager[17957]: 45.519180 |0|0|0| D 17 CAL0000: setPMProcIPs called for pm1
 
Mar 25 13:25:45 cps1 ProcessMonitor[17820]: 45.519729 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 13 on device DMLProc
 
Mar 25 13:25:45 cps1 ProcessManager[17957]: 45.520522 |0|0|0| D 17 CAL0000: setPMProcIPs for DMLProc: no update needed, exiting function
 
Mar 25 13:25:45 cps1 ProcessMonitor[17820]: 45.521185 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 25 on device DMLProc
 
Mar 25 13:25:46 cps1 ProcessMonitor[17820]: 46.556397 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/DMLProc State = BUSY_INIT
 
Mar 25 13:25:46 cps1 ProcessMonitor[17820]: 46.556446 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/DMLProc State = BUSY_INIT PID = 14041
 
Mar 25 13:25:46 cps1 ProcessMonitor[17820]: 46.556466 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set System State = BUSY_INIT
 
Mar 25 13:25:46 cps1 DMLProc[14041]: 46.558150 |0|0|0| I 20 CAL0002: DMLProc starts rollbackAll.
 
Mar 25 13:25:46 cps1 DMLProc[14041]: 46.589098 |0|0|0| I 20 CAL0002: DMLProc will rollback 0 tables.
 
Mar 25 13:25:46 cps1 DMLProc[14041]: 46.618344 |0|0|0| I 20 CAL0002: DMLProc finished rollbackAll.
 
Mar 25 13:25:46 cps1 ProcessMonitor[17820]: 46.758090 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/DMLProc State = ACTIVE
 
Mar 25 13:25:46 cps1 ProcessMonitor[17820]: 46.758147 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/DMLProc State = ACTIVE PID = 14041
 
Mar 25 13:25:46 cps1 ProcessMonitor[17820]: 46.758168 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set System State = ACTIVE
 
Mar 25 13:25:47 cps1 ProcessManager[17957]: 47.522482 |0|0|0| D 17 CAL0000: setQuerySystemState called = 1
 
Mar 25 13:25:47 cps1 ProcessManager[17957]: 47.522987 |0|0|0| D 17 CAL0000: setSystemQueryReady = 1
 
Mar 25 13:25:47 cps1 ProcessManager[17957]: 47.523067 |0|0|0| D 17 CAL0000: setSystemReady = 1
 
Mar 25 13:25:47 cps1 ProcessManager[17957]: 47.523608 |0|0|0| D 17 CAL0000: setQuerySystemState called = 1
 
Mar 25 13:25:47 cps1 ProcessManager[17957]: 47.523693 |0|0|0| D 17 CAL0000: setSystemQueryReady = 1
 
Mar 25 13:25:47 cps1 ProcessManager[17957]: 47.523762 |0|0|0| D 17 CAL0000: setSystemReady = 1
 
Mar 25 13:25:47 cps1 ProcessManager[17957]: 47.523997 |0|0|0| D 17 CAL0000: Set System State = ACTIVE
 
Mar 25 13:25:47 cps1 ProcessMonitor[17820]: 47.524463 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set System State = ACTIVE
 
Mar 25 13:25:47 cps1 ProcessManager[17957]: 47.524718 |0|0|0| D 17 CAL0000: setQuerySystemState called = 1
 
Mar 25 13:25:47 cps1 ProcessManager[17957]: 47.524842 |0|0|0| D 17 CAL0000: setSystemQueryReady = 1
 
Mar 25 13:25:47 cps1 ProcessManager[17957]: 47.524908 |0|0|0| D 17 CAL0000: setSystemReady = 1
 
Mar 25 13:25:47 cps1 ProcessManager[17957]: 47.527927 |0|0|0| I 17 CAL0000: MSG RECEIVED: Process Restarted Completed
 
Mar 25 13:29:09 cps1 ServerMonitor[22154]: 09.213443 |0|0|0| W 09 CAL0000: /  alarm # 6 cleared

controllernode.22134.log

Date/time: 2019-03-25 13:25:28
 
Signal: 11
 
 
 
/usr/local/mariadb/columnstore/bin/controllernode(_Z12fatalHandleri+0x150)[0x5599e205ea60]
 
/lib64/libpthread.so.0(+0xf5d0)[0x7f64ea3875d0]
 
/lib64/libstdc++.so.6(+0x750b4)[0x7f64e98940b4]
 
/lib64/libstdc++.so.6(_ZSt29_Rb_tree_insert_and_rebalancebPSt18_Rb_tree_node_baseS0_RS_+0xe1)[0x7f64e9894391]
 
/usr/local/mariadb/columnstore/lib/libexecplan.so.1(_ZNSt8_Rb_treeIN8execplan20CalpontSystemCatalog9TableNameESt4pairIKS2_mESt10_Select1stIS5_ESt4lessIS2_ESaIS5_EE17_M_insert_unique_ESt23_Rb_tree_const_iteratorIS5_ERKS5_+0xde)[0x7f64ee287b5e]
 
/usr/local/mariadb/columnstore/lib/libexecplan.so.1(_ZNSt3mapIN8execplan20CalpontSystemCatalog9TableNameEmSt4lessIS2_ESaISt4pairIKS2_mEEEixERS6_+0xa6)[0x7f64ee287d36]
 
/usr/local/mariadb/columnstore/lib/libexecplan.so.1(_ZN8execplan20CalpontSystemCatalog9getTablesESs+0x1147)[0x7f64ee26e7f7]
 
/usr/local/mariadb/columnstore/bin/controllernode(_ZN3BRM14MasterDBRMNode18doGetSystemCatalogERN11messageqcpp10ByteStreamEPNS0_12ThreadParamsE+0x8b)[0x5599e205272b]
 
/usr/local/mariadb/columnstore/bin/controllernode(_ZN3BRM14MasterDBRMNode12msgProcessorEv+0x45d)[0x5599e2059acd]
 
/usr/local/mariadb/columnstore/bin/controllernode(_ZN3BRM14MasterDBRMNode12MsgProcessorclEv+0x20)[0x5599e205ad00]
 
/lib64/libboost_thread-mt.so.1.53.0(+0xd27a)[0x7f64eae1f27a]
 
/lib64/libpthread.so.0(+0x7dd5)[0x7f64ea37fdd5]
 
/lib64/libc.so.6(clone+0x6d)[0x7f64e9037ead]

Comment by Gregory Dorman (Inactive) [ 2021-04-04 ]

mcsimport is lower priority right now.

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