Uploaded image for project: 'MariaDB ColumnStore'
  1. MariaDB ColumnStore
  2. MCOL-4199

boost: mutex lock failed in pthread_mutex_lock: Invalid argument

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Open (View Workflow)
    • Priority: Major
    • Resolution: Unresolved
    • Affects Version/s: 1.2.5
    • Fix Version/s: None
    • Component/s: ExeMgr
    • Labels:
      None
    • Environment:
      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.

        Attachments

          Activity

            People

            Assignee:
            David.Hall David Hall
            Reporter:
            allen.lee@mariadb.com Allen Lee
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

              Dates

              Created:
              Updated: