Skip to content

TiFlash core dump when always delete and select the same table  #1845

@lilinghai

Description

@lilinghai

Maybe mini reproduce:

  1. tpcc 10k warehouses
  2. execute the sql delete from customer limit 300000; select count(*) from customer; for loop

The core file is in the idc machine, you can call me to get the core file if needed.
The tiflash version is the master latest.
The tiflash.log

[2021/04/29 11:14:55.264 +08:00] [INFO] [<unknown>] ["Segment: Segment [587] prepare merge delta done."] [thread_id=15]
[2021/04/29 11:14:55.264 +08:00] [DEBUG] [<unknown>] ["DMVersionFilterBlockInputStream<COMPACT>: Total rows: 751876, pass: 25.42%, complete pass: 23.91%, complete not pass: 73.91%, not clean: 100.00%, effective: 50.00%"] [thread_id=15]
[2021/04/29 11:14:55.265 +08:00] [DEBUG] [<unknown>] ["DeltaMergeStore[db_51.t_57]: Apply merge delta. Segment [{[id:587], [next:791], [epoch:32], [range:[1449618,2335193)], [rowkey_range:[1449618,2335193)], [delta rows:12797], [delete ranges:0], [stable(dmf_4003):739079]}]"] [thread_id=15]
[2021/04/29 11:14:55.265 +08:00] [INFO] [<unknown>] ["Segment: Before apply merge delta: {[id:587], [next:791], [epoch:32], [range:[1449618,2335193)], [rowkey_range:[1449618,2335193)], [delta rows:12797], [delete ranges:0], [stable(dmf_4003):739079]}"] [thread_id=15]
[2021/04/29 11:14:55.265 +08:00] [INFO] [<unknown>] ["Segment: After apply merge delta new segment: {[id:587], [next:791], [epoch:33], [range:[1449618,2335193)], [rowkey_range:[1449618,2335193)], [delta rows:0], [delete ranges:0], [stable(dmf_4151):191100]}"] [thread_id=15]
[2021/04/29 11:14:55.265 +08:00] [DEBUG] [<unknown>] ["Segment: Abandon segment [587]"] [thread_id=15]
[2021/04/29 11:14:55.265 +08:00] [DEBUG] [<unknown>] ["DeltaMergeStore[db_51.t_57]: Apply merge delta done. Segment [587]"] [thread_id=15]
[2021/04/29 11:14:55.268 +08:00] [INFO] [<unknown>] ["DeltaMergeStore[db_51.t_57]: GC-merge-delta done [range=[1449618,2335193)] [table=t_57]"] [thread_id=15]
[2021/04/29 11:14:55.268 +08:00] [DEBUG] [<unknown>] ["DMFilePackFilter: RSFilter exclude rate is nan, after_pk: 152, after_read_packs: 152, after_filter: 152, handle_range: [2335193,84476480), read_packs: 0, pack_count: 152"] [thread_id=15]
[2021/04/29 11:14:55.268 +08:00] [DEBUG] [<unknown>] ["DMFilePackFilter: RSFilter exclude rate: 0.00"] [thread_id=15]
[2021/04/29 11:14:55.268 +08:00] [DEBUG] [<unknown>] ["DeltaMergeStore[db_51.t_57]: StableProperty: gc_hint_version [424585261578977281] num_versions [1239345] num_puts[863] num_rows[620104]"] [thread_id=15]
[2021/04/29 11:14:55.268 +08:00] [DEBUG] [<unknown>] ["DeltaMergeStore[db_51.t_57]: BackgroundGCThread merge delta, segment [791], safe point:424585424095150080"] [thread_id=15]
[2021/04/29 11:14:55.268 +08:00] [INFO] [<unknown>] ["Segment: Segment [791] prepare merge delta start. delta packs: 0, delta total rows: 0"] [thread_id=15]
[2021/04/29 11:14:55.268 +08:00] [DEBUG] [<unknown>] ["Segment: getReadInfo start"] [thread_id=15]
[2021/04/29 11:14:55.268 +08:00] [DEBUG] [<unknown>] ["Segment: getReadInfo end"] [thread_id=15]
[2021/04/29 11:14:55.268 +08:00] [DEBUG] [<unknown>] ["StableValueSpace::Snapshot: getInputStream max_data_version: 18446744073709551615, enable_clean_read: 0"] [thread_id=15]
[2021/04/29 11:14:55.268 +08:00] [DEBUG] [<unknown>] ["DMFilePackFilter: RSFilter exclude rate is nan, after_pk: 152, after_read_packs: 152, after_filter: 152, handle_range: [2335193,84476480), read_packs: 0, pack_count: 152"] [thread_id=15]
[2021/04/29 11:14:55.268 +08:00] [DEBUG] [<unknown>] ["DMFilePackFilter: RSFilter exclude rate: 0.00"] [thread_id=15]
[2021/04/29 11:14:55.881 +08:00] [INFO] [<unknown>] ["Segment: Segment [791] prepare merge delta done."] [thread_id=15]
[2021/04/29 11:14:55.881 +08:00] [DEBUG] [<unknown>] ["DMVersionFilterBlockInputStream<COMPACT>: Total rows: 1239345, pass: 0.07%, complete pass: 0.00%, complete not pass: 99.34%, not clean: 0.00%, effective: 100.00%"] [thread_id=15]
[2021/04/29 11:14:55.882 +08:00] [DEBUG] [<unknown>] ["DeltaMergeStore[db_51.t_57]: Apply merge delta. Segment [{[id:791], [next:719], [epoch:12], [range:[2335193,84476480)], [rowkey_range:[2335193,84476480)], [delta rows:863], [delete ranges:0], [stable(dmf_3995):1239345]}]"] [thread_id=15]
[2021/04/29 11:14:55.882 +08:00] [INFO] [<unknown>] ["Segment: Before apply merge delta: {[id:791], [next:719], [epoch:12], [range:[2335193,84476480)], [rowkey_range:[2335193,84476480)], [delta rows:863], [delete ranges:0], [stable(dmf_3995):1239345]}"] [thread_id=15]
[2021/04/29 11:14:55.882 +08:00] [INFO] [<unknown>] ["Segment: After apply merge delta new segment: {[id:791], [next:719], [epoch:13], [range:[2335193,84476480)], [rowkey_range:[2335193,84476480)], [delta rows:863], [delete ranges:0], [stable(dmf_4152):863]}"] [thread_id=15]
[2021/04/29 11:14:55.882 +08:00] [DEBUG] [<unknown>] ["Segment: Abandon segment [791]"] [thread_id=15]
[2021/04/29 11:14:55.882 +08:00] [DEBUG] [<unknown>] ["DeltaMergeStore[db_51.t_57]: Apply merge delta done. Segment [791]"] [thread_id=15]
[2021/04/29 11:14:55.887 +08:00] [DEBUG] [<unknown>] ["DeltaMergeStore[db_51.t_57]: Segment [791] task [Merge] add to background task pool by [BG_GC]"] [thread_id=15]
[2021/04/29 11:14:55.887 +08:00] [DEBUG] [<unknown>] ["DeltaMergeStore[db_51.t_57]: Segment [791] task [Merge] pop from background task pool"] [thread_id=27]
[2021/04/29 11:14:55.887 +08:00] [ERROR] [<unknown>] ["BaseDaemon: ########################################"] [thread_id=6537]
[2021/04/29 11:14:55.887 +08:00] [ERROR] [<unknown>] ["BaseDaemon: (from thread 15) Received signal Segmentation fault (11)."] [thread_id=6537]
[2021/04/29 11:14:55.887 +08:00] [ERROR] [<unknown>] ["BaseDaemon: Address: NULL pointer."] [thread_id=6537]
[2021/04/29 11:14:55.887 +08:00] [ERROR] [<unknown>] ["BaseDaemon: Access: read."] [thread_id=6537]
[2021/04/29 11:14:55.887 +08:00] [ERROR] [<unknown>] ["BaseDaemon: Unknown si_code."] [thread_id=6537]
[2021/04/29 11:14:55.889 +08:00] [DEBUG] [<unknown>] ["DeltaMergeStore[db_51.t_57]: TaskMerge GC safe point: 424585424095150080"] [thread_id=27]
[2021/04/29 11:14:55.889 +08:00] [DEBUG] [<unknown>] ["DeltaMergeStore[db_51.t_57]: Background merge Segment [{[id:791], [next:719], [epoch:13], [range:[2335193,84476480)], [rowkey_range:[2335193,84476480)], [delta rows:863], [delete ranges:0], [stable(dmf_4152):863]}] and [{[id:719], [next:356], [epoch:18], [range:[84476480,85941838)], [rowkey_range:[84476480,85941838)], [delta rows:95], [delete ranges:0], [stable(dmf_4000):112345]}], safe point:424585424095150080"] [thread_id=27]
[2021/04/29 11:14:55.889 +08:00] [INFO] [<unknown>] ["Segment: Segment [791] and [719] prepare merge start"] [thread_id=27]
[2021/04/29 11:14:55.889 +08:00] [DEBUG] [<unknown>] ["Segment: getReadInfo start"] [thread_id=27]
[2021/04/29 11:14:55.889 +08:00] [DEBUG] [<unknown>] ["Segment: getReadInfo end"] [thread_id=27]
[2021/04/29 11:14:55.889 +08:00] [DEBUG] [<unknown>] ["StableValueSpace::Snapshot: getInputStream max_data_version: 18446744073709551615, enable_clean_read: 0"] [thread_id=27]
[2021/04/29 11:14:55.889 +08:00] [DEBUG] [<unknown>] ["DMFilePackFilter: RSFilter exclude rate is nan, after_pk: 1, after_read_packs: 1, after_filter: 1, handle_range: [2335193,84476480), read_packs: 0, pack_count: 1"] [thread_id=27]
[2021/04/29 11:14:55.889 +08:00] [DEBUG] [<unknown>] ["DMFilePackFilter: RSFilter exclude rate: 0.00"] [thread_id=27]
[2021/04/29 11:14:55.890 +08:00] [DEBUG] [<unknown>] ["Segment: getReadInfo start"] [thread_id=27]
[2021/04/29 11:14:55.890 +08:00] [DEBUG] [<unknown>] ["Segment: getReadInfo end"] [thread_id=27]
[2021/04/29 11:14:55.890 +08:00] [DEBUG] [<unknown>] ["StableValueSpace::Snapshot: getInputStream max_data_version: 18446744073709551615, enable_clean_read: 0"] [thread_id=27]
[2021/04/29 11:14:55.890 +08:00] [DEBUG] [<unknown>] ["DMFilePackFilter: RSFilter exclude rate is nan, after_pk: 14, after_read_packs: 14, after_filter: 14, handle_range: [84476480,85941838), read_packs: 0, pack_count: 14"] [thread_id=27]
[2021/04/29 11:14:55.890 +08:00] [DEBUG] [<unknown>] ["DMFilePackFilter: RSFilter exclude rate: 0.00"] [thread_id=27]
[2021/04/29 11:14:55.895 +08:00] [ERROR] [<unknown>] ["BaseDaemon: 0. bin/tiflash/tiflash(DB::DM::RowKeyValue::toDebugString[abi:cxx11]() const+0x2c) [0x70fa14c]"] [thread_id=6537]
[2021/04/29 11:14:55.895 +08:00] [ERROR] [<unknown>] ["BaseDaemon: 1. bin/tiflash/tiflash(DB::DM::RowKeyRange::toDebugString[abi:cxx11]() const+0x41) [0x70faf61]"] [thread_id=6537]
[2021/04/29 11:14:55.895 +08:00] [ERROR] [<unknown>] ["BaseDaemon: 2. bin/tiflash/tiflash(DB::DM::DeltaMergeStore::onSyncGc(long)+0x54b) [0x70e82db]"] [thread_id=6537]
[2021/04/29 11:14:55.895 +08:00] [ERROR] [<unknown>] ["BaseDaemon: 3. bin/tiflash/tiflash(DB::GCManager::work()+0x7b8) [0x761b598]"] [thread_id=6537]
[2021/04/29 11:14:55.895 +08:00] [ERROR] [<unknown>] ["BaseDaemon: 4. bin/tiflash/tiflash(DB::BackgroundProcessingPool::threadFunction()+0x8f7) [0x71bae07]"] [thread_id=6537]
[2021/04/29 11:14:55.895 +08:00] [ERROR] [<unknown>] ["BaseDaemon: 5. bin/tiflash/tiflash() [0x8627d6f]"] [thread_id=6537]
[2021/04/29 11:14:55.895 +08:00] [ERROR] [<unknown>] ["BaseDaemon: 6. /lib64/libpthread.so.0(+0x7dd5) [0x7fbca6f67dd5]"] [thread_id=6537]
[2021/04/29 11:14:55.971 +08:00] [INFO] [<unknown>] ["Segment: Segment [791] and [719] prepare merge done"] [thread_id=27]
[2021/04/29 11:14:55.971 +08:00] [DEBUG] [<unknown>] ["DMVersionFilterBlockInputStream<COMPACT>: Total rows: 112345, pass: 0.08%, complete pass: 0.00%, complete not pass: 92.86%, not clean: 0.00%, effective: 100.00%"] [thread_id=27]
[2021/04/29 11:14:55.971 +08:00] [DEBUG] [<unknown>] ["DMVersionFilterBlockInputStream<COMPACT>: Total rows: 863, pass: 100.00%, complete pass: 100.00%, complete not pass: 0.00%, not clean: 0.00%, effective: 100.00%"] [thread_id=27]
[2021/04/29 11:14:55.971 +08:00] [DEBUG] [<unknown>] ["DeltaMergeStore[db_51.t_57]: Apply merge. Left [791], right [719]"] [thread_id=27]
[2021/04/29 11:14:55.971 +08:00] [INFO] [<unknown>] ["Segment: Segment [791] and [719] apply merge"] [thread_id=27]
[2021/04/29 11:14:55.971 +08:00] [INFO] [<unknown>] ["Segment: Segment [{[id:791], [next:719], [epoch:13], [range:[2335193,84476480)], [rowkey_range:[2335193,84476480)], [delta rows:863], [delete ranges:0], [stable(dmf_4152):863]}] and [{[id:719], [next:356], [epoch:18], [range:[84476480,85941838)], [rowkey_range:[84476480,85941838)], [delta rows:95], [delete ranges:0], [stable(dmf_4000):112345]}] merged into {[id:791], [next:356], [epoch:14], [range:[2335193,85941838)], [rowkey_range:[2335193,85941838)], [delta rows:958], [delete ranges:0], [stable(dmf_4153):958]}"] [thread_id=27]
[2021/04/29 11:14:55.972 +08:00] [DEBUG] [<unknown>] ["Segment: Abandon segment [791]"] [thread_id=27]
[2021/04/29 11:14:55.972 +08:00] [DEBUG] [<unknown>] ["Segment: Abandon segment [719]"] [thread_id=27]
[2021/04/29 11:14:55.972 +08:00] [DEBUG] [<unknown>] ["DeltaMergeStore[db_51.t_57]: Apply merge done. [{[id:791], [next:719], [epoch:13], [range:[2335193,84476480)], [rowkey_range:[2335193,84476480)], [delta rows:863], [delete ranges:0], [stable(dmf_4152):863]}] and [{[id:719], [next:356], [epoch:18], [range:[84476480,85941838)], [rowkey_range:[84476480,85941838)], [delta rows:95], [delete ranges:0], [stable(dmf_4000):112345]}]"] [thread_id=27]

Metadata

Metadata

Assignees

Labels

Type

No type

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions