[MCOL-1636] Query hangs after being warmed up Created: 2018-08-09  Updated: 2020-04-02  Resolved: 2019-07-10

Status: Closed
Project: MariaDB ColumnStore
Component/s: ?
Affects Version/s: 1.0.0, 1.1.5
Fix Version/s: Icebox

Type: Bug Priority: Critical
Reporter: Zdravelina Sokolovska (Inactive) Assignee: Unassigned
Resolution: Fixed Votes: 0
Labels: None
Environment:

PM1-PM2 combo


Attachments: Text File primproc_dump1.txt     Text File primproc_dump2.txt    
Issue Links:
Relates
relates to MCOL-2136 Use jemalloc as the main memory alloc... Closed
relates to MCOL-2202 ExeMgr stops processing queries wit... Closed

 Description   

Query hangs after being warmed up

note : issue was observed on cs v1.1.5 and v1.1.6 on systems with big amount of RAM

query stream composed of 61 queried pass initially successfully when run towards DB loaded with 1TB data
The second execute of the same stream hung however after 44 -45 queries from the stream have being run.

with run gdb, attached dumps
/var/log/mariadb/columnstore/crit.log

 
 
Aug  9 08:00:18 MariaDB-IMDT1 joblist[14534]: 18.868065 |0|0|0| C 05 CAL0000: /data/buildbot/bb-worker/centos7/mariadb-columnstore-engine/dbcon/joblist/distributedenginecomm.cpp @ 382 DEC: lost connection to 10.99.189.1
 
Aug  9 08:00:18 MariaDB-IMDT1 joblist[14534]: 18.871490 |0|0|0| C 05 CAL0000: /data/buildbot/bb-worker/centos7/mariadb-columnstore-engine/dbcon/joblist/distributedenginecomm.cpp @ 382 DEC: lost connection to 10.99.189.1
 
Aug  9 08:00:18 MariaDB-IMDT1 joblist[14850]: 18.873974 |0|0|0| C 05 CAL0000: /data/buildbot/bb-worker/centos7/mariadb-columnstore-engine/dbcon/joblist/distributedenginecomm.cpp @ 382 DEC: lost connection to 10.99.189.1
 
Aug  9 08:00:18 MariaDB-IMDT1 joblist[15004]: 18.874983 |0|0|0| C 05 CAL0000: /data/buildbot/bb-worker/centos7/mariadb-columnstore-engine/dbcon/joblist/distributedenginecomm.cpp @ 382 DEC: lost connection to 10.99.189.1
 
Aug  9 08:00:21 MariaDB-IMDT1 ProcessMonitor[12027]: 21.105643 |0|0|0| C 18 CAL0000: *****Calpont Process Restarting: PrimProc, old PID = 13669
 



Aug  9 04:58:58 MariaDB-IMDT1 ExeMgr[14534]: 58.981525 |48|0|0| D 16 CAL0042: End SQL statement
 
Aug  9 04:59:12 MariaDB-IMDT1 ExeMgr[14534]: 12.906337 |48|0|0| D 16 CAL0041: Start SQL statement: with year_total as (  select c_customer_id customer_id        ,c_first_name customer_first_name        ,c_last_name customer_last_name        ,c_preferred_cust_flag customer_preferred_cust_flag        ,c_birth_country customer_birth_country        ,c_login customer_login        ,c_email_address customer_email_address        ,d_year dyear        ,sum(((ss_ext_list_price-ss_ext_wholesale_cost-ss_ext_discount_amt)+ss_ext_sales_price)/2) year_total        ,'s' sale_type  from customer      ,store_sales      ,date_dim  where c_customer_sk = ss_customer_sk    and ss_sold_date_sk = d_date_sk  group by c_customer_id          ,c_first_name          ,c_last_name          ,c_preferred_cust_flag          ,c_birth_country          ,c_login          ,c_email_address          ,d_year  union all  select c_customer_id customer_id        ,c_first_name customer_first_name        ,c_last_name customer_last_name        ,c_preferred_cust_flag customer_preferred_cust_flag        ,c_birth_country customer_birth_country        ,c_login customer_login        ,c_email_address customer_email_address        ,d_year dyear        ,sum((((cs_ext_list_price-cs_ext_wholesale_cost-cs_ext_discount_amt)+cs_ext_sales_price)/2) ) year_total        ,'c' sale_type  from customer      ,catalog_sales      ,date_dim  where c_customer_sk = cs_bill_customer_sk    and cs_sold_date_sk = d_date_sk  group by c_customer_id          ,c_first_name          ,c_last_name          ,c_preferred_cust_flag          ,c_birth_country          ,c_login          ,c_email_address          ,d_year union all  select c_customer_id customer_id        ,c_first_name customer_first_name        ,c_last_name customer_last_name        ,c_preferred_cust_flag customer_preferred_cust_flag        ,c_birth_country customer_birth_country        ,c_login customer_login        ,c_email_address customer_email_address        ,d_year dyear        ,sum((((ws_ext_list_price-ws_ext_wholesale_cost-ws_ext_discount_amt)+ws_ext_sales_price)/2) ) year_total        ,'w' sale_type  from customer      ,web_sales      ,date_dim  where c_customer_sk = ws_bill_customer_sk    and ws_sold_date_sk = d_date_sk  group by c_customer_id          ,c_first_name          ,c_last_name          ,c_preferred_cust_flag          ,c_birth_country          ,c_login          ,c_email_address          ,d_year          )   select                     t_s_secyear.customer_id                  ,t_s_secyear.customer_first_name                  ,t_s_secyear.customer_last_name                  ,t_s_secyear.customer_preferred_cust_flag  from year_total t_s_firstyear      ,year_total t_s_secyear      ,year_total t_c_firstyear      ,year_total t_c_secyear      ,year_total t_w_firstyear      ,year_total t_w_secyear  where t_s_secyear.customer_id = t_s_firstyear.customer_id    and t_s_firstyear.customer_id = t_c_secyear.customer_id    and t_s_firstyear.customer_id = t_c_firstyear.customer_id    and t_s_firstyear.customer_id = t_w_firstyear.customer_id    and t_s_firstyear.customer_id = t_w_secyear.customer_id    and t_s_firstyear.sale_type = 's'    and t_c_firstyear.sale_type = 'c'    and t_w_firstyear.sale_type = 'w'    and t_s_secyear.sale_type = 's'    and t_c_secyear.sale_type = 'c'    and t_w_secyear.sale_type = 'w'    and t_s_firstyear.dyear =  2001    and t_s_secyear.dyear = 2001+1    and t_c_firstyear.dyear =  2001    and t_c_secyear.dyear =  2001+1    and t_w_firstyear.dyear = 2001    and t_w_secyear.dyear = 2001+1    and t_s_firstyear.year_total > 0    and t_c_firstyear.year_total > 0    and t_w_firstyear.year_total > 0    and case when t_c_firstyear.year_total > 0 then t_c_secyear.year_total / t_c_firstyear.year_total else null end            > case when t_s_firstyear.year_total > 0 then t_s_secyear.year_total / t_s_firstyear.year_total else null end    and case when t_c_firstyear.year_total > 0 then t_c_secyear.year_total / t_c_firstyear.year_total else null end            > case when t_w_firstyear.year_total > 0 then t_w_secyear.year_total / t_w_firstyear.year_total else null end  order by t_s_secyear.customer_id          ,t_s_secyear.customer_first_name          ,t_s_secyear.customer_last_name          ,t_s_secyear.customer_preferred_cust_flag limit 100; |tpcds_1000|
 
Aug  9 08:00:18 MariaDB-IMDT1 joblist[14534]: 18.868065 |0|0|0| C 05 CAL0000: /data/buildbot/bb-worker/centos7/mariadb-columnstore-engine/dbcon/joblist/distributedenginecomm.cpp @ 382 DEC: lost connection to 10.99.189.1
 
Aug  9 08:00:18 MariaDB-IMDT1 joblist[14534]: 18.871490 |0|0|0| C 05 CAL0000: /data/buildbot/bb-worker/centos7/mariadb-columnstore-engine/dbcon/joblist/distributedenginecomm.cpp @ 382 DEC: lost connection to 10.99.189.1
 
Aug  9 08:00:18 MariaDB-IMDT1 joblist[14850]: 18.873974 |0|0|0| C 05 CAL0000: /data/buildbot/bb-worker/centos7/mariadb-columnstore-engine/dbcon/joblist/distributedenginecomm.cpp @ 382 DEC: lost connection to 10.99.189.1
 
Aug  9 08:00:18 MariaDB-IMDT1 joblist[15004]: 18.874983 |0|0|0| C 05 CAL0000: /data/buildbot/bb-worker/centos7/mariadb-columnstore-engine/dbcon/joblist/distributedenginecomm.cpp @ 382 DEC: lost connection to 10.99.189.1
 
Aug  9 08:00:21 MariaDB-IMDT1 ProcessMonitor[12027]: 21.105643 |0|0|0| C 18 CAL0000: *****Calpont Process Restarting: PrimProc, old PID = 13669
 
Aug  9 08:00:21 MariaDB-IMDT1 ProcessMonitor[12027]: 21.105838 |0|0|0| D 18 CAL0000: STOPPING Process: PrimProc
 
Aug  9 08:00:21 MariaDB-IMDT1 ProcessMonitor[12027]: 21.105881 |0|0|0| D 18 CAL0000: StatusUpdate of Process PrimProc State = 1 PID = 0
 
Aug  9 08:00:21 MariaDB-IMDT1 ProcessMonitor[12027]: 21.105946 |0|0|0| D 18 CAL0000: Send SET Alarm ID 13 on device PrimProc
 
Aug  9 08:00:21 MariaDB-IMDT1 ProcessMonitor[12027]: 21.108974 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/PrimProc State = AUTO_OFFLINE
 
Aug  9 08:00:21 MariaDB-IMDT1 ProcessMonitor[12027]: 21.109047 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/PrimProc State = AUTO_OFFLINE PID = 0
 
Aug  9 08:00:21 MariaDB-IMDT1 ProcessMonitor[12027]: 21.109258 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 25 on device PrimProc
 
Aug  9 08:00:21 MariaDB-IMDT1 ProcessMonitor[12027]: 21.110983 |0|0|0| D 18 CAL0000: Send SET Alarm ID 13 on device PrimProc
 
Aug  9 08:00:21 MariaDB-IMDT1 ProcessMonitor[12027]: 21.135828 |0|0|0| D 18 CAL0000: Pkill Process just to make sure: PrimProc\*
 
Aug  9 08:00:21 MariaDB-IMDT1 ProcessMonitor[12027]: 21.135914 |0|0|0| D 18 CAL0000: STARTING Process: PrimProc
 
Aug  9 08:00:21 MariaDB-IMDT1 ProcessMonitor[12027]: 21.135935 |0|0|0| D 18 CAL0000: Process location: /usr/local/mariadb/columnstore/bin/PrimProc
 
Aug  9 08:00:21 MariaDB-IMDT1 ProcessMonitor[12027]: 21.138486 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 27 on device DBRM
 
Aug  9 08:00:21 MariaDB-IMDT1 ProcessMonitor[12027]: 21.165197 |0|0|0| D 18 CAL0000: Pkill Process just to make sure: PrimProc\*
 
Aug  9 08:00:21 MariaDB-IMDT1 ProcessMonitor[12027]: 21.165377 |0|0|0| D 18 CAL0000: StatusUpdate of Process PrimProc State = 3 PID = 0
 
Aug  9 08:00:21 MariaDB-IMDT1 ProcessMonitor[12027]: 21.166011 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/PrimProc State = AUTO_INIT
 
Aug  9 08:00:21 MariaDB-IMDT1 ProcessMonitor[12027]: 21.166047 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/PrimProc State = AUTO_INIT PID = 0
 
Aug  9 08:00:22 MariaDB-IMDT1 ProcessMonitor[12027]: 22.186442 |0|0|0| D 18 CAL0000: StatusUpdate of Process PrimProc State = 21 PID = 47046
 
Aug  9 08:00:22 MariaDB-IMDT1 ProcessMonitor[12027]: 22.188567 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/PrimProc State = PID_UPDATE
 
Aug  9 08:00:22 MariaDB-IMDT1 ProcessMonitor[12027]: 22.188611 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/PrimProc State = PID_UPDATE PID = 47046
 
Aug  9 08:00:22 MariaDB-IMDT1 ProcessMonitor[12027]: 22.188613 |0|0|0| D 18 CAL0000: PrimProc PID is 47046
 
Aug  9 08:00:22 MariaDB-IMDT1 ProcessMonitor[12027]: 22.188793 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 21 on device PrimProc
 
Aug  9 08:00:22 MariaDB-IMDT1 ProcessMonitor[12027]: 22.189716 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 13 on device PrimProc
 
Aug  9 08:00:22 MariaDB-IMDT1 ProcessMonitor[12027]: 22.191707 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 25 on device PrimProc
 
Aug  9 08:00:23 MariaDB-IMDT1 ProcessMonitor[12027]: 23.286257 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/PrimProc State = ACTIVE
 
Aug  9 08:00:23 MariaDB-IMDT1 ProcessMonitor[12027]: 23.286299 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/PrimProc State = ACTIVE PID = 47046
 
Aug  9 08:00:25 MariaDB-IMDT1 ProcessMonitor[12027]: 25.189389 |0|0|0| D 18 CAL0000: Inform Process Mgr that process was restarted: PrimProc
 
Aug  9 08:00:25 MariaDB-IMDT1 ProcessMonitor[12027]: 25.189822 |0|0|0| I 18 CAL0000: Calpont Process PrimProc restarted successfully!!
 
Aug  9 08:00:25 MariaDB-IMDT1 ProcessManager[12206]: 25.193790 |0|0|0| I 17 CAL0000: MSG RECEIVED: Process Restarted on pm1/PrimProc
 
Aug  9 08:00:25 MariaDB-IMDT1 ProcessManager[12206]: 25.194686 |0|0|0| D 17 CAL0000: setQuerySystemState = 0
 
Aug  9 08:00:25 MariaDB-IMDT1 ProcessManager[12206]: 25.194948 |0|0|0| D 17 CAL0000: setQuerySystemState successful
 
Aug  9 08:00:25 MariaDB-IMDT1 ProcessManager[12206]: 25.195127 |0|0|0| D 17 CAL0000: Set System State = BUSY_INIT
 
Aug  9 08:00:25 MariaDB-IMDT1 ProcessMonitor[12027]: 25.195517 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set System State = BUSY_INIT
 
Aug  9 08:00:25 MariaDB-IMDT1 ProcessManager[12206]: 25.196444 |0|0|0| D 17 CAL0000: reinitProcessType: ReInit all cpimport
 
Aug  9 08:00:25 MariaDB-IMDT1 ProcessManager[12206]: 25.199107 |0|0|0| D 17 CAL0000: sendMsgProcMon: Process module pm1
 
Aug  9 08:00:25 MariaDB-IMDT1 ProcessManager[12206]: 25.199452 |0|0|0| D 17 CAL0000: cpimport process is reinited by request.
 
Aug  9 08:00:25 MariaDB-IMDT1 ProcessManager[12206]: 25.199477 |0|0|0| D 17 CAL0000: reinitProcessType: ACK received from Process-Monitor, return status = 0
 
Aug  9 08:00:25 MariaDB-IMDT1 ProcessMonitor[12027]: 25.199785 |0|0|0| I 18 CAL0000: MSG RECEIVED: Re-Init process request on: cpimport
 
Aug  9 08:00:25 MariaDB-IMDT1 ProcessManager[12206]: 25.216124 |0|0|0| D 17 CAL0000: sendMsgProcMon: Process module pm2
 
Aug  9 08:00:25 MariaDB-IMDT1 ProcessManager[12206]: 25.216836 |0|0|0| D 17 CAL0000: cpimport process is reinited by request.
 
Aug  9 08:00:25 MariaDB-IMDT1 ProcessManager[12206]: 25.216871 |0|0|0| D 17 CAL0000: reinitProcessType: ACK received from Process-Monitor, return status = 0
 
Aug  9 08:00:25 MariaDB-IMDT1 ProcessManager[12206]: 25.217346 |0|0|0| D 17 CAL0000: distributeConfigFile called for system file = Columnstore.xml
 
Aug  9 08:00:25 MariaDB-IMDT1 ProcessMonitor[12027]: 25.229723 |0|0|0| I 18 CAL0000: PROCREINITPROCESS: completed, no ack to ProcMgr
 
Aug  9 08:00:25 MariaDB-IMDT1 ProcessManager[12206]: 25.234508 |0|0|0| D 17 CAL0000: sendMsgProcMon: Process module pm2
 
Aug  9 08:00:26 MariaDB-IMDT1 ProcessManager[12206]: 26.104045 |0|0|0| D 17 CAL0000: Set System State = ACTIVE
 
Aug  9 08:00:26 MariaDB-IMDT1 ProcessMonitor[12027]: 26.104340 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set System State = ACTIVE
 
Aug  9 08:00:26 MariaDB-IMDT1 ProcessManager[12206]: 26.257207 |0|0|0| D 17 CAL0000: pm2 distributeConfigFile success.
 
Aug  9 08:00:26 MariaDB-IMDT1 ProcessManager[12206]: 26.257370 |0|0|0| D 17 CAL0000: reinitProcessType: ReInit all WriteEngineServer
 
Aug  9 08:00:26 MariaDB-IMDT1 ProcessManager[12206]: 26.259621 |0|0|0| D 17 CAL0000: sendMsgProcMon: Process module pm1
 
Aug  9 08:00:26 MariaDB-IMDT1 ProcessManager[12206]: 26.259858 |0|0|0| D 17 CAL0000: WriteEngineServer process is reinited by request.
 
Aug  9 08:00:26 MariaDB-IMDT1 ProcessManager[12206]: 26.259882 |0|0|0| D 17 CAL0000: reinitProcessType: ACK received from Process-Monitor, return status = 0
 
Aug  9 08:00:26 MariaDB-IMDT1 ProcessMonitor[12027]: 26.259927 |0|0|0| I 18 CAL0000: MSG RECEIVED: Re-Init process request on: WriteEngineServer
 
Aug  9 08:00:26 MariaDB-IMDT1 ProcessMonitor[12027]: 26.259992 |0|0|0| D 18 CAL0000: REINITTING Process: WriteEngineServer
 
Aug  9 08:00:26 MariaDB-IMDT1 ProcessMonitor[12027]: 26.260035 |0|0|0| I 18 CAL0000: PROCREINITPROCESS: completed, no ack to ProcMgr
 
Aug  9 08:00:26 MariaDB-IMDT1 dmlpackageproc[14668]: 26.261370 |0|0|0| D 21 CAL0001: we_server caught SIGHUP. Resetting connections
 
Aug  9 08:00:26 MariaDB-IMDT1 ProcessManager[12206]: 26.274008 |0|0|0| D 17 CAL0000: sendMsgProcMon: Process module pm2
 
Aug  9 08:00:27 MariaDB-IMDT1 ProcessManager[12206]: 27.260763 |0|0|0| D 17 CAL0000: WriteEngineServer process is reinited by request.
 
Aug  9 08:00:27 MariaDB-IMDT1 ProcessManager[12206]: 27.260845 |0|0|0| D 17 CAL0000: reinitProcessType: ACK received from Process-Monitor, return status = 0
 
Aug  9 08:00:27 MariaDB-IMDT1 ProcessManager[12206]: 27.260999 |0|0|0| D 17 CAL0000: restartProcessType: Restart all ExeMgr
 
Aug  9 08:00:27 MariaDB-IMDT1 ProcessManager[12206]: 27.263323 |0|0|0| D 17 CAL0000: sendMsgProcMon: Process module pm1
 
Aug  9 08:00:27 MariaDB-IMDT1 ProcessMonitor[12027]: 27.263523 |0|0|0| I 18 CAL0000: MSG RECEIVED: Restart process request on ExeMgr
 
Aug  9 08:00:27 MariaDB-IMDT1 ProcessMonitor[12027]: 27.263574 |0|0|0| D 18 CAL0000: STOPPING Process: ExeMgr
 
Aug  9 08:00:27 MariaDB-IMDT1 ProcessMonitor[12027]: 27.263642 |0|0|0| D 18 CAL0000: StatusUpdate of Process ExeMgr State = 0 PID = 0
 
Aug  9 08:00:27 MariaDB-IMDT1 ProcessMonitor[12027]: 27.263821 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 25 on device ExeMgr
 
Aug  9 08:00:27 MariaDB-IMDT1 ProcessMonitor[12027]: 27.267285 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/ExeMgr State = MAN_OFFLINE
 
Aug  9 08:00:27 MariaDB-IMDT1 ProcessMonitor[12027]: 27.267335 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/ExeMgr State = MAN_OFFLINE PID = 0
 
Aug  9 08:00:27 MariaDB-IMDT1 ProcessMonitor[12027]: 27.267395 |0|0|0| D 18 CAL0000: Send SET Alarm ID 21 on device ExeMgr
 
Aug  9 08:00:27 MariaDB-IMDT1 ProcessMonitor[12027]: 27.293924 |0|0|0| D 18 CAL0000: Pkill Process just to make sure: ExeMgr\*
 
Aug  9 08:00:27 MariaDB-IMDT1 ProcessMonitor[12027]: 27.294135 |0|0|0| D 18 CAL0000: checkSpecialProcessState status return : 2
 
Aug  9 08:00:27 MariaDB-IMDT1 ProcessMonitor[12027]: 27.294192 |0|0|0| D 18 CAL0000: STARTING Process: ExeMgr
 
Aug  9 08:00:27 MariaDB-IMDT1 ProcessMonitor[12027]: 27.294211 |0|0|0| D 18 CAL0000: Process location: /usr/local/mariadb/columnstore/bin/ExeMgr
 
Aug  9 08:00:27 MariaDB-IMDT1 ProcessMonitor[12027]: 27.294986 |0|0|0| D 18 CAL0000: Dependent process of PrimProc/pm1 is 4
 
Aug  9 08:00:27 MariaDB-IMDT1 ProcessMonitor[12027]: 27.296252 |0|0|0| D 18 CAL0000: Dependent process of PrimProc/pm2 is 4
 
Aug  9 08:00:27 MariaDB-IMDT1 ProcessMonitor[12027]: 27.297520 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 27 on device DBRM
 
Aug  9 08:00:27 MariaDB-IMDT1 ProcessMonitor[12027]: 27.327060 |0|0|0| D 18 CAL0000: Pkill Process just to make sure: ExeMgr\*
 
Aug  9 08:00:27 MariaDB-IMDT1 ProcessMonitor[12027]: 27.327134 |0|0|0| D 18 CAL0000: StatusUpdate of Process ExeMgr State = 2 PID = 0
 
Aug  9 08:00:27 MariaDB-IMDT1 ProcessMonitor[12027]: 27.327534 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/ExeMgr State = MAN_INIT
 
Aug  9 08:00:27 MariaDB-IMDT1 ProcessMonitor[12027]: 27.327572 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/ExeMgr State = MAN_INIT PID = 0
 
Aug  9 08:00:28 MariaDB-IMDT1 ProcessMonitor[12027]: 28.349050 |0|0|0| D 18 CAL0000: StatusUpdate of Process ExeMgr State = 21 PID = 47424
 
Aug  9 08:00:28 MariaDB-IMDT1 ProcessMonitor[12027]: 28.350091 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/ExeMgr State = PID_UPDATE
 
Aug  9 08:00:28 MariaDB-IMDT1 ProcessMonitor[12027]: 28.350137 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/ExeMgr State = PID_UPDATE PID = 47424
 
Aug  9 08:00:28 MariaDB-IMDT1 ProcessMonitor[12027]: 28.350155 |0|0|0| D 18 CAL0000: ExeMgr PID is 47424
 
Aug  9 08:00:28 MariaDB-IMDT1 ProcessMonitor[12027]: 28.350415 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 21 on device ExeMgr
 
Aug  9 08:00:28 MariaDB-IMDT1 ProcessMonitor[12027]: 28.351338 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 13 on device ExeMgr
 
Aug  9 08:00:28 MariaDB-IMDT1 ProcessMonitor[12027]: 28.354209 |0|0|0| D 18 CAL0000: Send CLEAR Alarm ID 25 on device ExeMgr
 
Aug  9 08:00:29 MariaDB-IMDT1 ProcessMonitor[12027]: 29.397597 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/ExeMgr State = BUSY_INIT
 
Aug  9 08:00:29 MariaDB-IMDT1 ProcessMonitor[12027]: 29.397667 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/ExeMgr State = BUSY_INIT PID = 47424
 
Aug  9 08:00:31 MariaDB-IMDT1 ProcessMonitor[12027]: 31.350781 |0|0|0| I 18 CAL0000: RESTART: ACK back to ProcMgr, return status = 0
 
Aug  9 08:00:31 MariaDB-IMDT1 ProcessManager[12206]: 31.350988 |0|0|0| D 17 CAL0000: ExeMgr process is restarted by request.
 
Aug  9 08:00:31 MariaDB-IMDT1 ProcessManager[12206]: 31.351049 |0|0|0| D 17 CAL0000: restartProcessType: Start ACK received from Process-Monitor, return status = 0
 
Aug  9 08:00:31 MariaDB-IMDT1 ProcessManager[12206]: 31.367160 |0|0|0| D 17 CAL0000: sendMsgProcMon: Process module pm2
 
Aug  9 08:00:31 MariaDB-IMDT1 ProcessMonitor[12027]: 31.371459 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm2/ExeMgr State = MAN_OFFLINE
 
Aug  9 08:00:31 MariaDB-IMDT1 ProcessMonitor[12027]: 31.371561 |0|0|0| D 18 CAL0000: statusControl: Set Process pm2/ExeMgr State = MAN_OFFLINE PID = 0
 
Aug  9 08:00:31 MariaDB-IMDT1 ProcessMonitor[12027]: 31.432622 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm2/ExeMgr State = MAN_INIT
 
Aug  9 08:00:31 MariaDB-IMDT1 ProcessMonitor[12027]: 31.432689 |0|0|0| D 18 CAL0000: statusControl: Set Process pm2/ExeMgr State = MAN_INIT PID = 0
 
Aug  9 08:00:32 MariaDB-IMDT1 messagequeue[13310]: 32.257099 |0|0|0| W 31 CAL0000: Client read close socket for InetStreamSocket::readToMagic: Remote is closed
 
Aug  9 08:00:32 MariaDB-IMDT1 ProcessMonitor[12027]: 32.456302 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm2/ExeMgr State = PID_UPDATE
 
Aug  9 08:00:32 MariaDB-IMDT1 ProcessMonitor[12027]: 32.456407 |0|0|0| D 18 CAL0000: statusControl: Set Process pm2/ExeMgr State = PID_UPDATE PID = 46935
 
Aug  9 08:00:33 MariaDB-IMDT1 ProcessManager[12206]: 33.510244 |0|0|0| D 17 CAL0000: ExeMgr process is restarted by request.
 
Aug  9 08:00:33 MariaDB-IMDT1 ProcessManager[12206]: 33.510307 |0|0|0| D 17 CAL0000: restartProcessType: Start ACK received from Process-Monitor, return status = 0
 
Aug  9 08:00:33 MariaDB-IMDT1 ProcessManager[12206]: 33.510862 |0|0|0| D 17 CAL0000: reinitProcessType: ReInit all DDLProc
 
Aug  9 08:00:33 MariaDB-IMDT1 ProcessManager[12206]: 33.512595 |0|0|0| D 17 CAL0000: sendMsgProcMon: Process module pm1
 
Aug  9 08:00:33 MariaDB-IMDT1 ProcessManager[12206]: 33.512738 |0|0|0| D 17 CAL0000: DDLProc process is reinited by request.
 
Aug  9 08:00:33 MariaDB-IMDT1 ProcessManager[12206]: 33.512760 |0|0|0| D 17 CAL0000: reinitProcessType: ACK received from Process-Monitor, return status = 0
 
Aug  9 08:00:33 MariaDB-IMDT1 ProcessMonitor[12027]: 33.512785 |0|0|0| I 18 CAL0000: MSG RECEIVED: Re-Init process request on: DDLProc
 
Aug  9 08:00:33 MariaDB-IMDT1 ProcessMonitor[12027]: 33.512816 |0|0|0| D 18 CAL0000: REINITTING Process: DDLProc
 
Aug  9 08:00:33 MariaDB-IMDT1 ProcessMonitor[12027]: 33.512841 |0|0|0| I 18 CAL0000: PROCREINITPROCESS: completed, no ack to ProcMgr
 
Aug  9 08:00:33 MariaDB-IMDT1 ProcessManager[12206]: 33.512860 |0|0|0| D 17 CAL0000: reinitProcessType: ReInit all DMLProc
 
Aug  9 08:00:33 MariaDB-IMDT1 ddlpackageproc[14850]: 33.513060 |0|0|0| D 23 CAL0001: DDLProc caught SIGHUP. Resetting connections
 
Aug  9 08:00:33 MariaDB-IMDT1 ProcessManager[12206]: 33.514651 |0|0|0| D 17 CAL0000: sendMsgProcMon: Process module pm1
 
Aug  9 08:00:33 MariaDB-IMDT1 ProcessMonitor[12027]: 33.523873 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm2/ExeMgr State = BUSY_INIT
 
Aug  9 08:00:33 MariaDB-IMDT1 ProcessMonitor[12027]: 33.523907 |0|0|0| D 18 CAL0000: statusControl: Set Process pm2/ExeMgr State = BUSY_INIT PID = 46935
 
Aug  9 08:00:33 MariaDB-IMDT1 ProcessMonitor[12027]: 33.530968 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm2/ExeMgr State = ACTIVE
 
Aug  9 08:00:33 MariaDB-IMDT1 ProcessMonitor[12027]: 33.531070 |0|0|0| D 18 CAL0000: statusControl: Set Process pm2/ExeMgr State = ACTIVE PID = 46935
 
Aug  9 08:00:34 MariaDB-IMDT1 ProcessMonitor[12027]: 34.409583 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set Process pm1/ExeMgr State = ACTIVE
 
Aug  9 08:00:34 MariaDB-IMDT1 ProcessMonitor[12027]: 34.409627 |0|0|0| D 18 CAL0000: statusControl: Set Process pm1/ExeMgr State = ACTIVE PID = 47424
 
Aug  9 08:00:34 MariaDB-IMDT1 ProcessMonitor[12027]: 34.513705 |0|0|0| I 18 CAL0000: MSG RECEIVED: Re-Init process request on: DMLProc
 
Aug  9 08:00:34 MariaDB-IMDT1 ProcessMonitor[12027]: 34.513764 |0|0|0| D 18 CAL0000: REINITTING Process: DMLProc
 
Aug  9 08:00:34 MariaDB-IMDT1 ProcessMonitor[12027]: 34.513789 |0|0|0| I 18 CAL0000: PROCREINITPROCESS: completed, no ack to ProcMgr
 
Aug  9 08:00:34 MariaDB-IMDT1 ProcessManager[12206]: 34.513750 |0|0|0| D 17 CAL0000: DMLProc process is reinited by request.
 
Aug  9 08:00:34 MariaDB-IMDT1 ProcessManager[12206]: 34.513838 |0|0|0| D 17 CAL0000: reinitProcessType: ACK received from Process-Monitor, return status = 0
 
Aug  9 08:00:34 MariaDB-IMDT1 dmlpackageproc[15004]: 34.514196 |0|0|0| D 21 CAL0001: DMLProc caught SIGHUP. Resetting connections
 
Aug  9 08:00:34 MariaDB-IMDT1 ProcessManager[12206]: 34.514513 |0|0|0| D 17 CAL0000: setQuerySystemState = 1
 
Aug  9 08:00:34 MariaDB-IMDT1 ProcessManager[12206]: 34.514607 |0|0|0| D 17 CAL0000: setQuerySystemState successful
 
Aug  9 08:00:34 MariaDB-IMDT1 ProcessManager[12206]: 34.514753 |0|0|0| D 17 CAL0000: Set System State = ACTIVE
 
Aug  9 08:00:34 MariaDB-IMDT1 ProcessMonitor[12027]: 34.515107 |0|0|0| D 18 CAL0000: statusControl: REQUEST RECEIVED: Set System State = ACTIVE
 
Aug  9 08:00:34 MariaDB-IMDT1 dmlpackageproc[15004]: 34.517498 |0|0|0| D 21 CAL0001: DMLProc caught SIGHUP. Resetting connections
 
Aug  9 08:00:34 MariaDB-IMDT1 dmlpackageproc[15004]: 34.517530 |0|0|0| D 21 CAL0001: DMLProc caught SIGHUP. Resetting connections

notes about the occurance on 1.0.17
Observed on setup with simple hwrdware
1UM -1PM / 4CPUs per VM; 61G RAM per VM, mcs UM1-PM1 deplyoed on ContOS7

 Comments   
Comment by Andrew Hutchings (Inactive) [ 2019-07-10 ]

Likely a fixed abort issue

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