Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Fixed
-
1.2.5
-
None
-
CentOS 7.5, Virtualized, On Premise
Description
Customer hit 'boost: mutex lock failed in pthread_mutex_lock: Invalid argument' error after UM auto-restart due to 'ExeMgr has allocated too much memory!'.
Jul 20 15:16:08 nvm002314 ExeMgr[1126]: 08.496022 |1444|0|0| D 16 CAL0041: Start SQL statement: SELECT WK1.`SALES_ORDER_NO`, WK1.`SALES_CHANNEL`, WK1.`SERIAL_NUMBER`, WK1.`CHILD_SERIAL_NUMBER`, WK1.`SHIPMENT_DATETIME`, WK1.`PRODUCT_MODEL`, WK1.`TYPE`, WK1.`PARTS_NO`, WK1.`NICKNAME`, WK1.`HDD_SSD`, WK1.`PRODUCT_CODE`, WK1.`DRV_CAPACITY`, no1.`RECEIVING_DATE`, no1.`PART_NO`, no1.`FRU_NO`, fm.`FMTYPE`, fm.`PRODUCT_TYPE`, fm.`CAPA_OF_FMD`, no1.`REPAIR_PARTS_NAME_L`, no1.`FAILURE_MODE`, no1.`CATEGORY_RPFP`, no1.`RE_P1LOC_WHOLE_PART`, no1.`SHIPPING_DATE`, fm.`MODEL`, no1.`PLANT`, no1.`NAME_RPFP`, case substr(no1.`KEY_CODE_`, 3,3) when 'HEZ' then 'EDC' when 'HEP' then 'HP Europ' when 'HUZ' then 'IDC' when 'HUP' then 'HP' end FROM TB_fmd_field_no1_wk1 WK1 left JOIN tb_csv_fmd_field_no1 no1 ON no1.FRU_NO= WK1.CHILD_SERIAL_NUMBER left join f_fmtypemaster fm on substr(no1.FRU_NO,7, length(no1.FRU_NO)-11) = fm.INNERMGMTCODE; |daiq| |
Jul 20 15:16:08 nvm002314 joblist[1126]: 08.543740 |0|0|0| I 05 CAL0000: QUERY to foreign engine: SELECT `CHILD_SERIAL_NUMBER`, `SALES_ORDER_NO`, `SALES_CHANNEL`, `SERIAL_NUMBER`, `SHIPMENT_DATETIME`, `PRODUCT_MODEL`, `TYPE`, `PARTS_NO`, `NICKNAME`, `HDD_SSD`, `PRODUCT_CODE`, `DRV_CAPACITY` FROM `tb_fmd_field_no1_wk1` `wk1` |
Jul 20 15:17:02 nvm002314 joblist[1126]: 02.273906 |0|0|0| I 05 CAL0000: IDB-2001: Join or subselect exceeds memory limit. |
Jul 20 15:17:10 nvm002314 ExeMgr[1126]: 10.230135 |0|0|0| C 16 CAL0044: FATAL ERROR: ExeMgr has allocated too much memory! Percent allocation-96, allowed-95. ExeMgr is restarting. |
Jul 20 15:17:28 nvm002314 ServerMonitor[27518]: 28.563142 |0|0|0| I 09 CAL0000: Local Memory above Critical Memory threshold with a percentage of 100 ; Swap 11 |
Jul 20 15:17:28 nvm002314 ServerMonitor[27518]: 28.594933 |0|0|0| I 09 CAL0000: Local-Memory usage at percentage of 100 , Alarm set: 7 |
Jul 20 15:17:28 nvm002314 ServerMonitor[27518]: 28.657605 |0|0|0| I 09 CAL0000: Memory Usage for Process: workernode : Memory Used 798 : %% Used 1 |
Jul 20 15:17:28 nvm002314 ServerMonitor[27518]: 28.657661 |0|0|0| I 09 CAL0000: Memory Usage for Process: mysqld : Memory Used 1274 : %% Used 1 |
Jul 20 15:17:28 nvm002314 ServerMonitor[27518]: 28.657683 |0|0|0| I 09 CAL0000: Memory Usage for Process: rsyslogd : Memory Used 1328 : %% Used 1 |
Jul 20 15:17:28 nvm002314 ServerMonitor[27518]: 28.657702 |0|0|0| I 09 CAL0000: Memory Usage for Process: systemd-journald : Memory Used 2141 : %% Used 1 |
Jul 20 15:17:28 nvm002314 ServerMonitor[27518]: 28.657722 |0|0|0| I 09 CAL0000: Memory Usage for Process: ExeMgr : Memory Used 6368303 : %% Used 97 |
Jul 20 15:24:20 nvm002314 ExeMgr[1126]: 20.032532 |1062|0|0| C 16 CAL0055: ERROR: ExeMgr has caught an exception. boost: mutex lock failed in pthread_mutex_lock: Invalid argument |
Jul 20 15:24:50 nvm002314 messagequeue[27381]: 50.217224 |0|0|0| W 31 CAL0000: MessageQueueClient::write: error writing 24717 bytes to IOSocket: sd: 31 inet: 192.168.0.101 port: 8601. Socket error was InetStreamSocket::write error: Broken pipe -- write from InetStreamSocket: sd: 31 inet: 192.168.0.101 port: 8601 |
Jul 20 15:24:50 nvm002314 ExeMgr[1126]: 50.734074 |0|4294967295|0| C 16 CAL0055: ERROR: ExeMgr has caught an exception. boost: mutex lock failed in pthread_mutex_lock: Invalid argument |
Jul 20 15:25:16 nvm002314 messagequeue[27381]: 16.099652 |0|0|0| W 31 CAL0000: MessageQueueClient::write: error writing 24715 bytes to IOSocket: sd: 31 inet: 192.168.0.101 port: 8601. Socket error was InetStreamSocket::write error: Broken pipe -- write from InetStreamSocket: sd: 31 inet: 192.168.0.101 port: 8601 |
Jul 20 15:25:16 nvm002314 ExeMgr[1126]: 16.492040 |0|4294967295|0| C 16 CAL0055: ERROR: ExeMgr has caught an exception. boost: mutex lock failed in pthread_mutex_lock: Invalid argument |
Jul 20 15:26:23 nvm002314 messagequeue[27381]: 23.842306 |0|0|0| W 31 CAL0000: MessageQueueClient::write: error writing 24715 bytes to IOSocket: sd: 31 inet: 192.168.0.101 port: 8601. Socket error was InetStreamSocket::write error: Broken pipe -- write from InetStreamSocket: sd: 31 inet: 192.168.0.101 port: 8601 |
Jul 20 15:26:24 nvm002314 ExeMgr[1126]: 24.151318 |0|4294967295|0| C 16 CAL0055: ERROR: ExeMgr has caught an exception. boost: mutex lock failed in pthread_mutex_lock: Invalid argument |
Jul 20 15:28:18 nvm002314 ExeMgr[1126]: 18.864546 |2147485166|0|0| D 16 CAL0041: Start SQL statement: select objectid,columnname from syscolumn where schema='daiq' and tablename='tb_csv_fmd_field_no1' --columnRIDs/FE; || |
Jul 20 15:28:19 nvm002314 joblist[1126]: 19.770347 |2147485166|0|0| C 05 CAL0000: boost: mutex lock failed in pthread_mutex_lock: Invalid argument |
Jul 20 15:28:19 nvm002314 joblist[1126]: 19.825356 |2147485166|0|0| C 05 CAL0000: boost: mutex lock failed in pthread_mutex_lock: Invalid argument |
Jul 20 15:33:59 nvm002314 ExeMgr[1126]: 59.249739 |2147485198|0|0| D 16 CAL0041: Start SQL statement: select objectid,columnname from syscolumn where schema='daiq' and tablename='hitrk_life_rate_list' --columnRIDs/FE; || |
Jul 20 15:33:59 nvm002314 joblist[1126]: 59.935218 |2147485198|0|0| C 05 CAL0000: boost: mutex lock failed in pthread_mutex_lock: Invalid argument |
Jul 20 15:34:00 nvm002314 joblist[1126]: 00.029010 |2147485198|0|0| C 05 CAL0000: boost: mutex lock failed in pthread_mutex_lock: Invalid argument |
Jul 20 15:35:07 nvm002314 ddlpackageproc[1277]: 07.722185 |1567|1622113|0| D 23 CAL0041: Start SQL statement: create table tb_hitrk_pcba_connect(#012`SYORI_DATE` datetime DEFAULT NULL,#012`SYSTEM` varchar(10) DEFAULT NULL,#012`SITE_ID` varchar(7) DEFAULT NULL,#012`PK_NAME` varchar(20) DEFAULT NULL,#012`TOTAL` int(15) DEFAULT NULL#012#012) ENGINE=Columnstore DEFAULT CHARSET=utf8;|daiq| |
Jul 20 15:35:09 nvm002314 ddlpackageproc[1277]: 09.389060 |1567|1622113|0| D 23 CAL0042: End SQL statement |
Jul 20 15:35:33 nvm002314 ddlpackageproc[1277]: 33.676709 |1567|1622114|0| D 23 CAL0041: Start SQL statement: create table tb_hitrk_pcba_change(#012`SYORI_DATE` datetime DEFAULT NULL,#012`SYSTEM` varchar(10) DEFAULT NULL,#012`SITE_ID` varchar(7) DEFAULT NULL,#012`PK_NAME` varchar(20) DEFAULT NULL,#012`TOTAL` int(15) DEFAULT NULL#012#012) ENGINE=Columnstore DEFAULT CHARSET=utf8;|daiq| |
Jul 20 15:35:35 nvm002314 ddlpackageproc[1277]: 35.933961 |1567|1622114|0| D 23 CAL0042: End SQL statement |
Jul 20 15:42:50 nvm002314 ExeMgr[1126]: 50.049409 |2147485236|0|0| D 16 CAL0041: Start SQL statement: select objectid,columnname from syscolumn where schema='daiq' and tablename='tb_hitrk_pcba_change' --columnRIDs/FE; || |
Jul 20 15:42:50 nvm002314 joblist[1126]: 50.745683 |2147485236|0|0| C 05 CAL0000: boost: mutex lock failed in pthread_mutex_lock: Invalid argument |
Jul 20 15:42:50 nvm002314 joblist[1126]: 50.889279 |2147485236|0|0| C 05 CAL0000: boost: mutex lock failed in pthread_mutex_lock: Invalid argument |
Jul 20 15:43:02 nvm002314 ExeMgr[1126]: 02.493947 |2147485236|0|0| D 16 CAL0041: Start SQL statement: select objectid,columnname from syscolumn where schema='daiq' and tablename='tb_hitrk_pcba_change' --columnRIDs/FE; || |
Jul 20 15:43:02 nvm002314 joblist[1126]: 02.950538 |2147485236|0|0| C 05 CAL0000: boost: mutex lock failed in pthread_mutex_lock: Invalid argument |
Jul 20 15:43:03 nvm002314 joblist[1126]: 03.039962 |2147485236|0|0| C 05 CAL0000: boost: mutex lock failed in pthread_mutex_lock: Invalid argument |
Jul 20 15:43:19 nvm002314 ExeMgr[1126]: 19.201833 |2147485240|0|0| D 16 CAL0041: Start SQL statement: select objectid,columnname from syscolumn where schema='daiq' and tablename='hds_fmd_life_rate_result' --columnRIDs/FE; || |
Jul 20 15:43:20 nvm002314 joblist[1126]: 19.993384 |2147485240|0|0| C 05 CAL0000: boost: mutex lock failed in pthread_mutex_lock: Invalid argument |
Jul 20 15:43:20 nvm002314 joblist[1126]: 20.112540 |2147485240|0|0| C 05 CAL0000: boost: mutex lock failed in pthread_mutex_lock: Invalid argument |
Jul 20 15:56:17 nvm002314 ExeMgr[1126]: 17.654345 |2147485264|0|0| D 16 CAL0041: Start SQL statement: select objectid,columnname from syscolumn where schema='daiq' and tablename='hitrk_inst_info' --columnRIDs/FE; || |
Jul 20 15:56:18 nvm002314 joblist[1126]: 18.355471 |2147485264|0|0| C 05 CAL0000: boost: mutex lock failed in pthread_mutex_lock: Invalid argument |
Jul 20 15:56:18 nvm002314 joblist[1126]: 18.473262 |2147485264|0|0| C 05 CAL0000: boost: mutex lock failed in pthread_mutex_lock: Invalid argument |
Jul 20 15:57:25 nvm002314 ServerMonitor[27518]: 25.785816 |0|0|0| W 09 CAL0000: Local-Memory alarm # 7 cleared |
Jul 20 15:57:30 nvm002314 ExeMgr[1126]: 30.743303 |1444|0|0| D 16 CAL0042: End SQL statement |
This error was gone after shutdown/start, but customer want to be fixed because they see this consistently.