From 78d75992ca1602fd9beb6a776927630c953f26e6 Mon Sep 17 00:00:00 2001 From: mattthew Date: Wed, 5 Aug 2026 13:58:35 -0400 Subject: [PATCH] fix(posting): make rollup failures diagnosable in logs Two problems make a failing rollup nearly impossible to triage from logs, both surfaced by #9794. The format arguments in incrRollupi.Process are reversed, so the message reads "Error rolling up key []: ". The key also printed as a decimal byte slice rather than hex, which can't be fed to `dgraph debug --lookup`. More importantly, the error returned when pIterator.seek fails formats List.Print() into the message. Print() dumps the entire posting list and mutation map, posting values included. On a multi-part list holding large values that's a multi-megabyte log line, and since ReadPostingList re-queues a key for rollup whenever deltas remain, the same line repeats every few seconds for as long as the key stays broken. The actual cause is appended after the dump by errors.Wrapf, so it's the first thing to get truncated, which is exactly what happened in #9794. Add List.debugString(), which reports the key, minTs, maxTs, splits, and mutation-layer counts without any values, and use it on the three seek error paths. Print() stays for interactive debugging. Co-Authored-By: Claude Opus 5 (1M context) --- posting/list.go | 27 ++++++++++++++++++++++----- posting/mvcc.go | 2 +- 2 files changed, 23 insertions(+), 6 deletions(-) diff --git a/posting/list.go b/posting/list.go index b257568ef69..d96ac5247d5 100644 --- a/posting/list.go +++ b/posting/list.go @@ -410,10 +410,29 @@ func (mm *MutableLayer) print() string { mm.deleteAllMarker) } +// printShort returns a summary of the mutable layer with the entry counts but not the entries themselves. Use it in +// error messages and logs, where print() is unsafe because posting values are unbounded in size. +func (mm *MutableLayer) printShort() string { + if mm == nil { + return "" + } + return fmt.Sprintf("committed: %d, proposed: %t, deleteAllMarker: %d", + len(mm.committedEntries), mm.currentEntries != nil, mm.deleteAllMarker) +} + +// Print dumps the entire list, posting values included. It is meant for interactive debugging only. Anything that +// ends up in a log line or an error message should use debugString() instead. func (l *List) Print() string { return fmt.Sprintf("minTs: %d, plist: %+v, mutationMap: %s", l.minTs, l.plist, l.mutationMap.print()) } +// debugString describes the list's shape without including any posting values. Rollup retries a failing key every +// few seconds, so an error message built from Print() will repeatedly dump multi-megabyte values into the log. +func (l *List) debugString() string { + return fmt.Sprintf("key: %x, minTs: %d, maxTs: %d, splits: %v, mutationMap: {%s}", + l.key, l.minTs, l.maxTs, l.plist.GetSplits(), l.mutationMap.printShort()) +} + // Return if piterator needs to be searched or not after mutable map and the posting if found. func (mm *MutableLayer) findPosting(readTs, uid uint64) (bool, *pb.Posting) { if mm == nil { @@ -1153,7 +1172,7 @@ func (l *List) iterate(readTs uint64, afterUid uint64, f func(obj *pb.Posting) e // pitr iterates through immutable postings err = pitr.seek(l, afterUid, deleteBelowTs) if err != nil { - return errors.Wrapf(err, "cannot initialize iterator when calling List.iterate %v", l.Print()) + return errors.Wrapf(err, "cannot initialize iterator when calling List.iterate %s", l.debugString()) } loop: @@ -2187,15 +2206,13 @@ func (l *List) findPostingWithItr(readTs uint64, uid uint64, pitr pIterator) (fo err = pitr.seek(l, uid-1, 0) if err != nil { return false, nil, errors.Wrapf(err, - "cannot initialize iterator when calling List.iterate %s", - l.mutationMap.print()) + "cannot initialize iterator when calling List.iterate %s", l.debugString()) } valid, err := pitr.valid() if err != nil { return false, nil, errors.Wrapf(err, - "cannot initialize iterator when calling List.iterate %s", - l.mutationMap.print()) + "cannot initialize iterator when calling List.iterate %s", l.debugString()) } if valid { pp := pitr.posting() diff --git a/posting/mvcc.go b/posting/mvcc.go index 77491fb8a8f..badf13b9fa3 100644 --- a/posting/mvcc.go +++ b/posting/mvcc.go @@ -178,7 +178,7 @@ func (ir *incrRollupi) Process(closer *z.Closer, getNewTs func(bool) uint64) { // Add/Update map and rollup. m[hash] = currTs if err := ir.rollUpKey(writer, key); err != nil { - glog.Warningf("Error rolling up key [%v]: %v", err, key) + glog.Warningf("Error rolling up key [%x]: %v", key, err) } } }