[MCOL-590] No extent information on Insert/Updates with table corruption - Jira

XML

Word

Printable

Details

Type: Bug
Status: Closed (View Workflow)
Priority: Critical
Resolution: Cannot Reproduce
Affects Version/s: 1.0.7
Fix Version/s: Icebox
Component/s: DMLProc
Labels:
None
Environment:
Debian 8 with kernel 4.9 with 4pm combined install

Sprint:
2017-4, 2017-5, 2017-6, 2017-7, 2017-8, 2017-9, 2017-10

Description

We have huge problems with columnstore breaking on a regular basis.
we are importing data to a "source" table using cpimport and updating other tables using UPDATE with join and insert with left joins, updating/inserting 10000's of rows at once.
it happens on multiple tables, some times on the insert, some times on the update. the import works some interations and then crashes.
the affected table (more specific the latest partition) is then broken and the only way to fix it is to drop the partition. also, as we use transactions, the rollback is not working and the data is inconsistend between the tables that are updated within this transaction.

this also (more rarely) happend on infinidb 4.6.7

this is what we do:

cat data* | /usr/local/mariadb/columnstore/bin/cpimport stats stats_update -s ',' -E '"' -e 3000

BEGIN;

update

      `stats_hour` AS s

      JOIN

        SELECT sr.`hash_hour`, sr.`datum_hour`,..

         FROM stats_update sr

         GROUP BY sr.`hash_hour`, sr.`datum_hour`

      ) AS su

      ON su.`datum_hour` = s.datum AND s.hash = su.`hash_hour`

SET

      s.`views` =  s.`views` + su.`views`,

s.`clicks` =  s.`clicks` + su.`clicks`,

..

      WHERE 1;

INSERT INTO stats_hour

    SELECT

    su.`hash_hour`,

    MAX(su.`datum_hour`),

       MAX(su.`user_id`),

...

sum(su.`unique_pa_clicks`)

    FROM `stats_update` su LEFT JOIN `stats_hour` s ON  su.`datum_hour` = s.datum AND s.hash = su.`hash_hour`

    WHERE s.hash IS NULL

    GROUP BY

     su.`hash_hour`

2017-02-23 19:34: exception 'Common\JobBase' code HY000 with message 'SQLSTATE[HY000]: General error: 1815 Internal error: CAL0006: There is no extent information for table stats_hour'

from the logs:

crit.log

Feb 23 19:34:04 ics1 controllernode[7785]: 04.910677 |0|0|0| C 29 CAL0000: ExtentMap::getDbRootHWMInfo(): OID 3543 has HWM extent that is UNAVAILABLE for DBRoot1; part#: 3, seg#: 3, fbo: 8192, localHWM: 0, lbid: 12061696

Feb 23 19:33:41 ics1 writeengineserver[7301]: 41.831126 |0|0|0| D 32 CAL0000: 1465 : Message Queue is empty; Stopping CF Thread

Feb 23 19:33:42 ics1 cpimport.bin[5362]: 42.174918 |0|0|0| I 34 CAL0083: BulkLoad: JobId-3202; finished loading table stats.stats_update; 120000 rows inserted

Feb 23 19:33:42 ics1 writeengine[5362]: 42.175028 |0|0|0| I 19 CAL0008: Bulkload |Job: /usr/local/mariadb/columnstore/data/bulk/tmpjob/3202_D20170223_T193324_S352165_Job_3202.xml |For table stats.stats_update: 120000 rows processed and 120000 rows inserted.

Feb 23 19:33:42 ics1 messagequeue[3133]: 42.183386 |0|0|0| W 31 CAL0071: InetStreamSocket::read: EOF during readToMagic: socket read error: Success; InetStreamSocket: sd: 28 inet: 137.74.204.237 port: 59138; Will retry.

Feb 23 19:33:42 ics1 writeenginesplit[5317]: 42.185871 |0|0|0| I 33 CAL0098: Received a Cpimport Pass from PM2.

Feb 23 19:33:42 ics1 cpimport.bin[5362]: 42.198629 |0|0|0| I 34 CAL0082: End BulkLoad: JobId-3202; status-SUCCESS

Feb 23 19:33:42 ics1 messagequeue[3133]: 42.210929 |0|0|0| W 31 CAL0071: InetStreamSocket::read: EOF during readToMagic: socket read error: Success; InetStreamSocket: sd: 20 inet: 137.74.204.236 port: 43672; Will retry.

Feb 23 19:33:42 ics1 writeengineserver[7301]: 42.211010 |0|0|0| I 32 CAL0000: 1465 : cpimport exit on success

Feb 23 19:33:42 ics1 writeengineserver[7301]: 42.211277 |0|0|0| D 32 CAL0000: 1465 : onCpimportSuccess BrmReport Send

Feb 23 19:33:42 ics1 writeengineserver[7301]: 42.211345 |0|0|0| D 32 CAL0000: 1465 : onReceiveEOD : child ID = 0

Feb 23 19:33:42 ics1 writeengineserver[7301]: 42.211407 |0|0|0| D 32 CAL0000: 1465 : onReceiveEOD : child ID = 0

Feb 23 19:33:42 ics1 writeenginesplit[5317]: 42.213387 |0|0|0| I 33 CAL0098: Received a Cpimport Pass from PM1.

Feb 23 19:33:42 ics1 messagequeue[3133]: 42.230724 |0|0|0| W 31 CAL0071: InetStreamSocket::read: EOF during readToMagic: socket read error: Success; InetStreamSocket: sd: 27 inet: 137.74.204.239 port: 47908; Will retry.

Feb 23 19:33:42 ics1 writeenginesplit[5317]: 42.250687 |0|0|0| I 33 CAL0098: Received a Cpimport Pass from PM4.

Feb 23 19:33:42 ics1 writeengineserver[7301]: 42.250727 |0|0|0| D 32 CAL0000: 1465 : OnReceiveCleanup arrived

Feb 23 19:33:42 ics1 writeenginesplit[5317]: 42.392919 |0|0|0| I 33 CAL0000: Released Table Lock

Feb 23 19:33:50 ics1 messagequeue[7301]: 50.403361 |0|0|0| W 31 CAL0071: InetStreamSocket::read: EOF during readToMagic: socket read error: Success; InetStreamSocket: sd: 11 inet: 137.74.204.236 port: 60368; Will retry.

Feb 23 19:33:50 ics1 messagequeue[3133]: 50.414428 |0|0|0| W 31 CAL0071: InetStreamSocket::read: EOF during readToMagic: socket read error: Success; InetStreamSocket: sd: 22 inet: 137.74.204.236 port: 43624; Will retry.

Feb 23 19:33:50 ics1 dmlpackageproc[7785]: 50.505621 |405|853|0| D 21 CAL0001: Start SQL statement:  update#012      `stats_hour` AS s#012      JOIN#012      (#012        SELECT sr.`hash_hour`, sr.`datum_hour`, sum(`views`) as `views`, sum(`clicks`) as `clicks`, sum(`unique_clicks`) as `unique_clicks`, sum(`unique_sys_clicks`) as `unique_sys_clicks`, sum(`unique_pa_clicks`) as `unique_pa_clicks`#012         FROM stats_update sr#012         /*SOURCEWHERE*/#012         GROUP BY sr.`hash_hour`, sr.`datum_hour`#012      ) AS su#012      ON su.`datum_hour` = s.datum AND s.hash = su.`hash_hour`#012      SET#012      s.`views` =  s.`views` + su.`views`,#012s.`clicks` =  s.`clicks` + su.`clicks`,#012s.`unique_clicks` =  s.`unique_clicks` + su.`unique_clicks`,#012s.`unique_sys_clicks` =  s.`unique_sys_clicks` + su.`unique_sys_clicks`,#012s.`unique_pa_clicks` =  s.`unique_pa_clicks` + su.`unique_pa_clicks`#012      WHERE 1 /*EXTRAWHERE*/;|stats|

Feb 23 19:33:53 ics1 dmlpackageproc[7785]: 53.651961 |405|853|0| D 21 CAL0001: End SQL statement

Feb 23 19:33:53 ics1 messagequeue[7785]: 53.670058 |0|0|0| W 31 CAL0071: InetStreamSocket::read: EOF during readToMagic: socket read error: Success; InetStreamSocket: sd: 21 inet: 137.74.204.236 port: 8630; Will retry.

Feb 23 19:33:53 ics1 messagequeue[7785]: 53.670151 |0|0|0| W 31 CAL0071: InetStreamSocket::read: EOF during readToMagic: socket read error: Success; InetStreamSocket: sd: 24 inet: 137.74.204.239 port: 8630; Will retry.

Feb 23 19:33:53 ics1 messagequeue[7785]: 53.670208 |0|0|0| W 31 CAL0071: InetStreamSocket::read: EOF during readToMagic: socket read error: Success; InetStreamSocket: sd: 23 inet: 137.74.204.238 port: 8630; Will retry.

Feb 23 19:33:53 ics1 messagequeue[7785]: 53.670212 |0|0|0| W 31 CAL0071: InetStreamSocket::read: EOF during readToMagic: socket read error: Success; InetStreamSocket: sd: 22 inet: 137.74.204.237 port: 8630; Will retry.

Feb 23 19:33:53 ics1 messagequeue[7785]: 53.670710 |0|0|0| W 31 CAL0071: InetStreamSocket::read: EOF during readToMagic: socket read error: Success; InetStreamSocket: sd: 15 inet: 137.74.204.236 port: 34708; Will retry.

Feb 23 19:33:53 ics1 dmlpackageproc[7785]: 53.741662 |405|853|0| D 21 CAL0001: Start SQL statement:  update#012      `stats_day` AS s#012      JOIN#012      (#012        SELECT sr.`hash_day`, sr.`datum`, sum(`views`) as `views`, sum(`clicks`) as `clicks`, sum(`unique_clicks`) as `unique_clicks`, sum(`unique_sys_clicks`) as `unique_sys_clicks`, sum(`unique_pa_clicks`) as `unique_pa_clicks`#012         FROM stats_update sr#012         /*SOURCEWHERE*/#012         GROUP BY sr.`hash_day`, sr.`datum`#012      ) AS su#012      ON su.`datum` = s.datum AND s.hash = su.`hash_day`#012      SET#012      s.`views` =  s.`views` + su.`views`,#012s.`clicks` =  s.`clicks` + su.`clicks`,#012s.`unique_clicks` =  s.`unique_clicks` + su.`unique_clicks`,#012s.`unique_sys_clicks` =  s.`unique_sys_clicks` + su.`unique_sys_clicks`,#012s.`unique_pa_clicks` =  s.`unique_pa_clicks` + su.`unique_pa_clicks`#012      WHERE 1 /*EXTRAWHERE*/;|stats|

Feb 23 19:34:01 ics1 dmlpackageproc[7785]: 01.956476 |405|853|0| D 21 CAL0001: End SQL statement

Feb 23 19:34:02 ics1 messagequeue[7785]: 02.141810 |0|0|0| W 31 CAL0071: InetStreamSocket::read: EOF during readToMagic: socket read error: Success; InetStreamSocket: sd: 21 inet: 137.74.204.236 port: 8630; Will retry.

Feb 23 19:34:02 ics1 messagequeue[7785]: 02.141925 |0|0|0| W 31 CAL0071: InetStreamSocket::read: EOF during readToMagic: socket read error: Success; InetStreamSocket: sd: 24 inet: 137.74.204.239 port: 8630; Will retry.

Feb 23 19:34:02 ics1 messagequeue[7785]: 02.141925 |0|0|0| W 31 CAL0071: InetStreamSocket::read: EOF during readToMagic: socket read error: Success; InetStreamSocket: sd: 23 inet: 137.74.204.238 port: 8630; Will retry.

Feb 23 19:34:02 ics1 messagequeue[7785]: 02.141925 |0|0|0| W 31 CAL0071: InetStreamSocket::read: EOF during readToMagic: socket read error: Success; InetStreamSocket: sd: 22 inet: 137.74.204.237 port: 8630; Will retry.

Feb 23 19:34:02 ics1 messagequeue[7785]: 02.142450 |0|0|0| W 31 CAL0071: InetStreamSocket::read: EOF during readToMagic: socket read error: Success; InetStreamSocket: sd: 17 inet: 137.74.204.236 port: 34892; Will retry.

Feb 23 19:34:04 ics1 dmlpackageproc[7785]: 04.849423 |405|853|0| D 21 CAL0001: Start SQL statement:  INSERT INTO stats_hour      select *  from infinidb_vtable.$vtable_405; |stats|

Feb 23 19:34:04 ics1 controllernode[7785]: 04.910677 |0|0|0| C 29 CAL0000: ExtentMap::getDbRootHWMInfo(): OID 3543 has HWM extent that is UNAVAILABLE for DBRoot1; part#: 3, seg#: 3, fbo: 8192, localHWM: 0, lbid: 12061696

Feb 23 19:34:05 ics1 dmlpackageproc[7785]: 05.377736 |405|853|0| D 21 CAL0001: End SQL statement with error

Feb 23 19:34:05 ics1 messagequeue[7785]: 05.378100 |0|0|0| W 31 CAL0071: InetStreamSocket::read: EOF during readToMagic: socket read error: Success; InetStreamSocket: sd: 21 inet: 137.74.204.236 port: 8630; Will retry.

Feb 23 19:34:05 ics1 messagequeue[7785]: 05.378152 |0|0|0| W 31 CAL0071: InetStreamSocket::read: EOF during readToMagic: socket read error: Success; InetStreamSocket: sd: 24 inet: 137.74.204.239 port: 8630; Will retry.

Feb 23 19:34:05 ics1 messagequeue[7785]: 05.378174 |0|0|0| W 31 CAL0071: InetStreamSocket::read: EOF during readToMagic: socket read error: Success; InetStreamSocket: sd: 23 inet: 137.74.204.238 port: 8630; Will retry.

Feb 23 19:34:05 ics1 messagequeue[7785]: 05.378198 |0|0|0| W 31 CAL0071: InetStreamSocket::read: EOF during readToMagic: socket read error: Success; InetStreamSocket: sd: 22 inet: 137.74.204.237 port: 8630; Will retry.

Feb 23 19:34:05 ics1 dmlpackageproc[7785]: 05.402107 |0|0|0| E 21 CAL0006: There is no extent information for table stats_hour

Feb 23 19:34:05 ics1 dmlpackageproc[7785]: 05.499266 |405|853|0| D 21 CAL0001: Start SQL statement:  ROLLBACK

Feb 23 19:34:09 ics1 dmlpackageproc[7785]: 09.456582 |405|853|0| D 21 CAL0001: End SQL statement

Feb 23 19:34:09 ics1 messagequeue[7785]: 09.456984 |0|0|0| W 31 CAL0071: InetStreamSocket::read: EOF during readToMagic: socket read error: Success; InetStreamSocket: sd: 20 inet: 137.74.204.236 port: 8630; Will retry.

Feb 23 19:34:09 ics1 messagequeue[7785]: 09.457043 |0|0|0| W 31 CAL0071: InetStreamSocket::read: EOF during readToMagic: socket read error: Success; InetStreamSocket: sd: 21 inet: 137.74.204.237 port: 8630; Will retry.

Feb 23 19:34:09 ics1 messagequeue[7785]: 09.457075 |0|0|0| W 31 CAL0071: InetStreamSocket::read: EOF during readToMagic: socket read error: Success; InetStreamSocket: sd: 22 inet: 137.74.204.238 port: 8630; Will retry.

Feb 23 19:34:09 ics1 messagequeue[7785]: 09.457079 |0|0|0| W 31 CAL0071: InetStreamSocket::read: EOF during readToMagic: socket read error: Success; InetStreamSocket: sd: 23 inet: 137.74.204.239 port: 8630; Will retry.

Feb 23 19:34:09 ics1 messagequeue[7785]: 09.457415 |0|0|0| W 31 CAL0071: InetStreamSocket::read: EOF during readToMagic: socket read error: Success; InetStreamSocket: sd: 15 inet: 137.74.204.236 port: 35416; Will retry.

Feb 23 19:34:09 ics1 dmlpackageproc[7785]: 09.492138 |405|0|0| D 21 CAL0001: Start SQL statement:  ROLLBACK

Feb 23 19:34:09 ics1 dmlpackageproc[7785]: 09.492219 |405|0|0| D 21 CAL0001: End SQL statement

Feb 23 19:34:09 ics1 messagequeue[7785]: 09.492454 |0|0|0| W 31 CAL0071: InetStreamSocket::read: EOF during readToMagic: socket read error: Success; InetStreamSocket: sd: 20 inet: 137.74.204.236 port: 8630; Will retry.

Feb 23 19:34:09 ics1 messagequeue[7785]: 09.492626 |0|0|0| W 31 CAL0071: InetStreamSocket::read: EOF during readToMagic: socket read error: Success; InetStreamSocket: sd: 22 inet: 137.74.204.238 port: 8630; Will retry.

Feb 23 19:34:09 ics1 messagequeue[7785]: 09.492643 |0|0|0| W 31 CAL0071: InetStreamSocket::read: EOF during readToMagic: socket read error: Success; InetStreamSocket: sd: 21 inet: 137.74.204.237 port: 8630; Will retry.

Feb 23 19:34:09 ics1 messagequeue[7785]: 09.492724 |0|0|0| W 31 CAL0071: InetStreamSocket::read: EOF during readToMagic: socket read error: Success; InetStreamSocket: sd: 23 inet: 137.74.204.239 port: 8630; Will retry.

Feb 23 19:34:09 ics1 messagequeue[7785]: 09.493010 |0|0|0| W 31 CAL0071: InetStreamSocket::read: EOF during readToMagic: socket read error: Success; InetStreamSocket: sd: 17 inet: 137.74.204.236 port: 35682; Will retry.

Attachments

- Sort By Name
- Sort By Date
- Ascending
- Descending
- Thumbnails
- List
- Download All

columnstoreSupportReport.tar.gz
7.48 MB
2017-02-23 19:22

Activity

People

Assignee:: David Hall (Inactive)

Reporter:: Bernd Helm

Votes:: 1 Vote for this issue

Watchers:: 4 Start watching this issue

Dates

Created:: 2017-02-23 19:30

Updated:: 2017-09-20 18:38

Resolved:: 2017-09-20 18:38

Git Integration

Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.