Improve debuggability of the delta/compaction path This adds/modifies some log statements on the delta/compaction path to aid with debugging. For example it makes some log statements in delta_compaction.cc output the row id instead of the row index within the block, which helps when grepping for changes to a particular row.
Change-Id: I0fc6c6ed76f5ab929c04410228d5ea70f4fc9660 Reviewed-on: http://gerrit.cloudera.org:8080/4930 Tested-by: Kudu Jenkins Reviewed-by: Alexey Serbin <[email protected]> Project: http://git-wip-us.apache.org/repos/asf/kudu/repo Commit: http://git-wip-us.apache.org/repos/asf/kudu/commit/e640f0ee Tree: http://git-wip-us.apache.org/repos/asf/kudu/tree/e640f0ee Diff: http://git-wip-us.apache.org/repos/asf/kudu/diff/e640f0ee Branch: refs/heads/master Commit: e640f0ee26f696320421e5479309529b50ea50e8 Parents: ff7d562 Author: David Alves <[email protected]> Authored: Mon Nov 7 20:46:28 2016 -0800 Committer: David Ribeiro Alves <[email protected]> Committed: Thu Nov 10 18:47:37 2016 +0000 ---------------------------------------------------------------------- src/kudu/tablet/delta_compaction.cc | 12 ++++++++++-- src/kudu/tablet/delta_store.cc | 16 +++++++++------- src/kudu/tablet/delta_store.h | 7 ++++++- src/kudu/tablet/deltafile.cc | 7 ++++--- 4 files changed, 29 insertions(+), 13 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/kudu/blob/e640f0ee/src/kudu/tablet/delta_compaction.cc ---------------------------------------------------------------------- diff --git a/src/kudu/tablet/delta_compaction.cc b/src/kudu/tablet/delta_compaction.cc index 243426c..e25adf0 100644 --- a/src/kudu/tablet/delta_compaction.cc +++ b/src/kudu/tablet/delta_compaction.cc @@ -148,8 +148,13 @@ Status MajorDeltaCompaction::FlushRowSetAndDeltas() { // later at step 5. Mutation* new_redos_head = nullptr; - DVLOG(3) << "MDC: Input Row: " << CompactionInputRowToString(*input_row); + // Since this is a delta compaction the input and output row id's are the same. + rowid_t row_id = nrows + input_row->row.row_index(); + DVLOG(3) << "MDC Input Row - RowId: " << row_id << " " + << CompactionInputRowToString(*input_row); + + // NOTE: This is presently ignored. bool is_garbage_collected; RemoveAncientUndos(history_gc_opts_, input_row); @@ -164,7 +169,8 @@ Status MajorDeltaCompaction::FlushRowSetAndDeltas() { &is_garbage_collected, &num_rows_history_truncated)); - DVLOG(3) << "MDC: Output Row: " << RowToString(dst_row, new_undos_head, new_redos_head); + DVLOG(3) << "MDC Output Row - RowId: " << row_id << " " + << RowToString(dst_row, new_undos_head, new_redos_head); // We only create a new undo delta file if we need to. if (new_undos_head != nullptr && !new_undo_delta_writer_) { @@ -197,6 +203,8 @@ Status MajorDeltaCompaction::FlushRowSetAndDeltas() { // into a REDO delta file. for (const DeltaKeyAndUpdate& key_and_update : out) { RowChangeList update(key_and_update.cell); + DVLOG(4) << "Keeping delta as REDO: " + << key_and_update.Stringify(DeltaType::REDO, base_schema_); RETURN_NOT_OK_PREPEND(new_redo_delta_writer_->AppendDelta<REDO>(key_and_update.key, update), "Failed to append a delta"); WARN_NOT_OK(redo_stats.UpdateStats(key_and_update.key.timestamp(), update), http://git-wip-us.apache.org/repos/asf/kudu/blob/e640f0ee/src/kudu/tablet/delta_store.cc ---------------------------------------------------------------------- diff --git a/src/kudu/tablet/delta_store.cc b/src/kudu/tablet/delta_store.cc index 75b591c..ba91f29 100644 --- a/src/kudu/tablet/delta_store.cc +++ b/src/kudu/tablet/delta_store.cc @@ -30,12 +30,14 @@ using std::shared_ptr; using std::string; using strings::Substitute; -string DeltaKeyAndUpdate::Stringify(DeltaType type, const Schema& schema) const { - return StrCat(Substitute("($0 delta key=$1, change_list=$2)", - type == UNDO ? "UNDO" : "REDO", - StringPrintf("%06u@tx%06u", key.row_idx(), - atoi(key.timestamp().ToString().c_str())), - RowChangeList(cell).ToString(schema))); +string DeltaKeyAndUpdate::Stringify(DeltaType type, const Schema& schema, bool pad_key) const { + return StrCat(Substitute("($0 delta key=$2, change_list=$1)", + DeltaType_Name(type), + RowChangeList(cell).ToString(schema), + (pad_key ? StringPrintf("%06u@tx%06u", key.row_idx(), + atoi(key.timestamp().ToString().c_str())) + : Substitute("$0@tx$1", key.row_idx(), + key.timestamp().ToString())))); } @@ -72,7 +74,7 @@ Status DebugDumpDeltaIterator(DeltaType type, &cells, &arena)); for (const DeltaKeyAndUpdate& cell : cells) { - LOG_STRING(INFO, out) << cell.Stringify(type, schema); + LOG_STRING(INFO, out) << cell.Stringify(type, schema, true /*pad_key*/ ); } i += n; http://git-wip-us.apache.org/repos/asf/kudu/blob/e640f0ee/src/kudu/tablet/delta_store.h ---------------------------------------------------------------------- diff --git a/src/kudu/tablet/delta_store.h b/src/kudu/tablet/delta_store.h index 64dae2c..b1fce99 100644 --- a/src/kudu/tablet/delta_store.h +++ b/src/kudu/tablet/delta_store.h @@ -108,7 +108,12 @@ struct DeltaKeyAndUpdate { DeltaKey key; Slice cell; - std::string Stringify(DeltaType type, const Schema& schema) const; + // Stringifies this DeltaKeyAndUpdate, according to 'schema'. + // + // If 'pad' is true, pads the delta row ids and txn ids in the output so that we can + // compare two stringified representations and obtain the same result as comparing the DeltaKey + // itself. That is, if 'pad' is true, then DeltaKey a < DeltaKey b => Stringify(a) < Stringify(b). + std::string Stringify(DeltaType type, const Schema& schema, bool pad_key = false) const; }; class DeltaIterator { http://git-wip-us.apache.org/repos/asf/kudu/blob/e640f0ee/src/kudu/tablet/deltafile.cc ---------------------------------------------------------------------- diff --git a/src/kudu/tablet/deltafile.cc b/src/kudu/tablet/deltafile.cc index 255c4e8..cd1f5be 100644 --- a/src/kudu/tablet/deltafile.cc +++ b/src/kudu/tablet/deltafile.cc @@ -581,9 +581,10 @@ Status DeltaFileIterator::VisitMutations(Visitor *visitor) { RETURN_NOT_OK(visitor->Visit(key, slice, &continue_visit)); if (VLOG_IS_ON(3)) { RowChangeList rcl(slice); - DVLOG(3) << "Visited delta for key: " << key.ToString() << " Mut: " - << rcl.ToString(*projection_) << " Continue?: " - << (continue_visit ? "TRUE" : "FALSE"); + DVLOG(3) << "Visited " << DeltaType_Name(delta_type_) + << " delta for key: " << key.ToString() << " Mut: " + << rcl.ToString(*projection_) << " Continue?: " + << (continue_visit ? "TRUE" : "FALSE"); } } }
