Invalid write in EstimateOp::report_ratio

[Robert Stepanek]

I am debugging a memory violation with latest 1.5 master when running Xapian::Enquire::get_mset for a specific query and database. I managed to reduce the query and database to the minimal set that's required to reproduce the memory violation, but now I'm stuck how to further debug and fix this.

The query looks like this (I replaced the actual terms with placeholders):

Query((term1@1 AND ((term2@1 PHRASE 2 term2@2) OR (term2@1 PHRASE 2 term2@2)) AND (<alldocuments> AND_NOT (<alldocuments> FILTER XEP))))

I can not share the database, but it's a glass database with the following characteristics:

$ xapian-delve-1.5 crasherdb
UUID = fcdb211b-3bad-4583-8863-a99ef02a40fe
number of documents = 2
average document length = 167.5
document length lower bound = 102
document length upper bound = 233
highest document id ever used = 3
has positional information = true
revision = 1
currently open for writing = false

What happens for this query and this particular database is that valgrind reports an invalid write (full valgrind log is attached):

==29738== Invalid write of size 4
==29738==    at 0x4A417CC: report_ratio (estimateop.h:124)
==29738==    by 0x4A417CC: SelectPostList::~SelectPostList() (selectpostlist.cc:61)
==29738==    by 0x4A2ED93: ExactPhrasePostList::~ExactPhrasePostList() (exactphrasepostlist.cc:68)
==29738==    by 0x4A4022F: ~OrPostList (orpostlist.h:71)
==29738==    by 0x4A4022F: OrPostList::~OrPostList() (orpostlist.h:73)
==29738==    by 0x4A2B67F: next_helper (andpostlist.h:75)
==29738==    by 0x4A2B67F: AndPostList::next(double) (andpostlist.cc:124)
==29738==    by 0x4A35DB3: PostListTree::next(double) (postlisttree.h:151)
==29738==    by 0x4A32DC3: Matcher::get_local_mset(unsigned int, unsigned int, unsigned int, Xapian::Weight const&, Xapian::MatchDecider const*, Xapian::KeyMaker const*, unsigned int, unsigned int, int, double, double, Xapian::Enquire::docid_order, unsigned int, Xapian::Enquire::Internal::sort_setting, bool, double, std::vector<Xapian::Internal::opt_intrusive_ptr<Xapian::MatchSpy>, std::allocator<Xapian::Internal::opt_intrusive_ptr<Xapian::MatchSpy> > > const&) (matcher.cc:499)

which is because the written memory got freed previously

==29738==  Address 0x52a248c is 12 bytes inside a block of size 40 free'd
==29738==    at 0x4888360: operator delete(void*, unsigned long) (vg_replace_malloc.c:935)
==29738==    by 0x493046B: pop_op (localsubmatch.h:112)
==29738==    by 0x493046B: destroy_postlist (queryoptimiser.h:176)
==29738==    by 0x493046B: shrink (queryinternal.cc:190)
==29738==    by 0x493046B: Xapian::Internal::Context::~Context() (queryinternal.cc:153)
==29738==    by 0x492B637: ~OrContext (queryinternal.cc:370)
==29738==    by 0x492B637: operator() (unique_ptr.h:95)
==29738==    by 0x492B637: operator() (unique_ptr.h:89)
==29738==    by 0x492B637: reset (unique_ptr.h:203)
==29738==    by 0x492B637: reset (unique_ptr.h:501)
==29738==    by 0x492B637: Xapian::Internal::AndContext::postlist(Xapian::Internal::TermFreqs*) (queryinternal.cc:833)
==29738==    by 0x492B8AF: Xapian::Internal::QueryAndLike::postlist(Xapian::Internal::QueryOptimiser*, double, Xapian::Internal::TermFreqs*) const (queryinternal.cc:2502)
==29738==    by 0x4A30A1B: LocalSubMatch::get_postlist(PostListTree*, unsigned int*) (localsubmatch.cc:188)
==29738==    by 0x4A32A8B: Matcher::get_local_mset(unsigned int, unsigned int, unsigned int, Xapian::Weight const&, Xapian::MatchDecider const*, Xapian::KeyMaker const*, unsigned int, unsigned int, int, double, double, Xapian::Enquire::docid_order, unsigned int, Xapian::Enquire::Internal::sort_setting, bool, double, std::vector<Xapian::Internal::opt_intrusive_ptr<Xapian::MatchSpy>, std::allocator<Xapian::Internal::opt_intrusive_ptr<Xapian::MatchSpy> > > const&) (matcher.cc:381)

and that data had been allocated before at

==29738==  Block was alloc'd at
==29738==    at 0x4885828: operator new(unsigned long) (vg_replace_malloc.c:422)
==29738==    by 0x492B4B7: add_op<EstimateOp::op_type> (localsubmatch.h:101)
==29738==    by 0x492B4B7: add_op<EstimateOp::op_type> (queryoptimiser.h:84)
==29738==    by 0x492B4B7: postlist (queryinternal.cc:629)
==29738==    by 0x492B4B7: Xapian::Internal::AndContext::postlist(Xapian::Internal::TermFreqs*) (queryinternal.cc:842)
==29738==    by 0x492B8AF: Xapian::Internal::QueryAndLike::postlist(Xapian::Internal::QueryOptimiser*, double, Xapian::Internal::TermFreqs*) const (queryinternal.cc:2502)
==29738==    by 0x492873F: Xapian::Query::Internal::postlist_sub_or_like(Xapian::Internal::OrContext&, Xapian::Internal::QueryOptimiser*, double, Xapian::Internal::TermFreqs*, bool) const (queryinternal.cc:1174)
==29738==    by 0x492C307: Xapian::Internal::QueryBranch::do_or_like(Xapian::Internal::OrContext&, Xapian::Internal::QueryOptimiser*, double, Xapian::Internal::TermFreqs*, unsigned int, unsigned long, bool) const (queryinternal.cc:2256)
==29738==    by 0x492C9AF: Xapian::Internal::QueryOr::postlist(Xapian::Internal::QueryOptimiser*, double, Xapian::Internal::TermFreqs*) const (queryinternal.cc:2619)
==29738==    by 0x492A977: Xapian::Query::Internal::postlist_sub_and_like(Xapian::Internal::AndContext&, Xapian::Internal::QueryOptimiser*, double, Xapian::Internal::TermFreqs*) const (queryinternal.cc:1163)
==29738==    by 0x492524F: Xapian::Internal::QueryAndLike::postlist_sub_and_like(Xapian::Internal::AndContext&, Xapian::Internal::QueryOptimiser*, double, Xapian::Internal::TermFreqs*) const (queryinternal.cc:2515)
==29738==    by 0x492B89B: Xapian::Internal::QueryAndLike::postlist(Xapian::Internal::QueryOptimiser*, double, Xapian::Internal::TermFreqs*) const (queryinternal.cc:2499)
==29738==    by 0x4A30A1B: LocalSubMatch::get_postlist(PostListTree*, unsigned int*) (localsubmatch.cc:188)
==29738==    by 0x4A32A8B: Matcher::get_local_mset(unsigned int, unsigned int, unsigned int, Xapian::Weight const&, Xapian::MatchDecider const*, Xapian::KeyMaker const*, unsigned int, unsigned int, int, double, double, Xapian::Enquire::docid_order, unsigned int, Xapian::Enquire::Internal::sort_setting, bool, double, std::vector<Xapian::Internal::opt_intrusive_ptr<Xapian::MatchSpy>, std::allocator<Xapian::Internal::opt_intrusive_ptr<Xapian::MatchSpy> > > const&) (matcher.cc:381)

The valgrind log suggests to me that the various rewrites of the EstimateOp stack do no propagate to all the places where pointers to those EstimateOps are held. To mitigate the invalid write, a shared_ptr might help, but I fear that would just hide the logical bug that's occurring here? I might try doing that though, to at least mitigate the crash until I could fix the actual root cause.

Since I can't share the database as-is, is there some way I can rewrite the terms in that database to obfuscate its contents but still replicate the crash so that I can share it? I tried trimming down the database to the minimal set using the WritableDatabase API, but it looks as if I can't mess with the postlists or term lists that way?

[Robert Stepanek]

Valgrind log

[Olly Betts]

I wonder if it's the hint postlist that's to blame. That prolongs the lifetime of one postlist, so its destructor gets called later. The one thing that doesn't make sense for this as the explanation is that the hint should always be the postlist for a term, but the failure happens for a SelectPostList.

Could you try with the attached patch?

If that fixes it, it would be a plausible short-term workaround but would need careful study as to whether it harms performance in the cases the hint postlist mechanism is there to improve.

It'd be really good to have a reproducer we can put in the testsuite, and it seems to be only two documents so hopefully we can find a way. I suspect the exact circumstances matter, but it's likely to only be the ordering and occurrence patterns of the terms.

You can't edit postlists or termlists directly - the way to do it would be to scan the documents from the database and create a new database with new documents based on them. Like copydatabase but instead of adding the documents from the existing database to the new one, create new documents with a subset of the terms and add those instead.

The size of the database doesn't seem to be a problem though. If we had an "anonymiser" which replaced every term with an arbitrary one but preserving the collation order and with the same wdf and term positions, would you be able to share the database passed through that? I think it would be easy enough to write such a tool (and perhaps a useful one to have for future instances where a bug is reproducible but only with a database which can't be shared).

(E.g. we have 335 words over two documents - at worst they're all unique words, so if we map them to terms which are 3 digit numbers then e.g. a -> 000, aardvark -> 001, etc.)

[Olly Betts]

Hmm, but if it was the hint then accepted and rejected should still be zero so we shouldn't dereference estimate_op:

SelectPostList::~SelectPostList()
{
    if (estimate_op && (accepted || rejected)) {
        // Only call report_ratio() if there are counts.  During the building
        // of the PostList tree we sometimes need to delete PostList objects
        // and their associated EstimateOp and it's hard to arrange that they
        // are always deleted in the correct order.
        estimate_op->report_ratio(accepted, rejected);
    }
}

The ownership tracking around this has probably become too complicated. shared_ptr probably helps build something that is easier to reliably reason about object lifetimes in, but it feels like it's not actually fixing the underlying design of this to be cleaner (essentially hint postlists and then the EstimateOp machinery got bolted on to an existing system).

Anyway, let's try to work out what's actually going on here.

[Olly Betts]

Setting version - the EstimateOp mechanism isn't in 1.4.x so bugs in it shouldn't be able to manifest there.

[Robert Stepanek]

I could not reproduce the invalid write with obfuscated terms, but I managed to trim the database to the minimal set of terms required to make valgrind detect it.

This is all there is

$ xapian-delve-1.5 -a -1 -vv ticket838_db/
All terms in database (termfreq, collection freq, wdf upper bound):
XEP 1 0 0
XFgroups 1 1 1
XSchange 1 1 1
XSmember 1 1 1

I attached a new file "ticket838.tar" to this ticket, which includes the database as well as a C++ file which reproduces the invalid write. Running it with valgrind produces the valgrind log I had submitted initially.

I did not find any patch to disable hints, so I did not try that.

[Olly Betts]

Patch to clear the hint

[Olly Betts]

Oops, I failed to actually attach the patch yesterday - now there.

Thanks for the reduced testcase, I'll have a poke.

[Olly Betts]

I do also get the valgrind errors.

The query can be simplified a little, e.g. this triggers it:

libtool --mode=execute valgrind examples/quest -d ticket838_db -s '' -p s:XS -b x:X 's:member AND (s:"member member" OR s:member) NOT x:EP'

Query object from that:

Parsed Query: Query(((XSmember@1 AND ((XSmember@2 PHRASE 2 XSmember@3) OR XSmember@4)) AND_NOT XEP))

(Using quest because it's less faff to try to minimise by edits of a command line than edit/compile/run of C++.)

So it seems the MatchAlls aren't relevant. The phrase clearly is since the bad write is from SelectPostList's destructor. I can't seem to remove anything else and still trigger it. Also XEP does need to be a different term.

[Olly Betts]

The patch to clear the hint doesn't seem to help.

Adding some prints to the code:

destroy_postlist(XEP:1)
pop_op() popping type 6, now doing 2 subqueries:
pop_op() popping type 0
pop_op() popping type 8, now doing 2 subqueries:
pop_op() popping type 0
pop_op() popping type 4, now doing 1 subqueries:
pop_op() popping type 6, now doing 2 subqueries:
pop_op() popping type 0
pop_op() popping type 0

The op types are from:

    enum op_type {                                                                             
        KNOWN,                                                                           
        DECIDER = 1,                                                                                        
        NEAR = 2, PHRASE = 3, EXACT_PHRASE = 4,                                                                                       
        POSTING_SOURCE,                                                                                       
        AND, AND_NOT, OR, XOR                                                                                 
    };                                                                                            

So it does pop_op of an AND with 2 subqueries, which is clearly not the right thing at all. I'm amazed this doesn't go wrong more, but the testsuite is run under valgrind in CI and passes.

I think the trigger for this is that it can probably see that the right side of the AND_NOT can be discarded because the left and right sides can't match at the same time (that can be spotted from the term range info but I haven't followed through that code yet to check that's actually how it gets to there).

This is probably a reasonable short-term workaround:

diff --git a/xapian-core/matcher/queryoptimiser.h b/xapian-core/matcher/queryoptimiser.h
index 5ca302a00a0c..8f2bf591fe04 100644
--- a/xapian-core/matcher/queryoptimiser.h
+++ b/xapian-core/matcher/queryoptimiser.h
@@ -173,7 +173,7 @@ class QueryOptimiser {
 	}
 	// Remove the EstimateOp (and any sub-ops) which we generated for this
 	// PostList.
-	localsubmatch.pop_op();
+	//localsubmatch.pop_op();
     }
 
     bool need_wdf_for_compound_weight() const {

We should resolve all the EstimateOps anyway, so having extra ones should be OK. Maybe that's actually the right fix, but I definitely want to look at this in more detail.

[Olly Betts]

I think the trigger for this is that it can probably see that the right side of the AND_NOT can be discarded because the left and right sides can't match at the same time (that can be spotted from the term range info but I haven't followed through that code yet to check that's actually how it gets to there).

That seems right - we've created postlists (and EstimateOps) for both sides of the AND_NOT and before we create the AndNotPostList (or its EstimateOp) we can see the two sides are disjoint so we can discard the right side. We try to pop_op() to remove the unwanted right hand side EstimateOp, but the order of the ops in the estimate_stack isn't right for doing that.

We should resolve all the EstimateOps anyway, so having extra ones should be OK. Maybe that's actually the right fix, but I definitely want to look at this in more detail.

If we don't pop_op() then we need to create an AND_NOT EstimateOp for the estimates to get resolved correctly.

The parsed query and stack (with the missing AND_NOT added) would look like this (where [first, last] is the known possible range of documents matched):

Parsed Query: Query(((XSmember@1 AND ((XSmember@2 PHRASE 2 XSmember@3) OR XSmember@4)) AND_NOT XEP))

AND_NOT x2 [1, 1]
  AND x2 [1, 1]
    KNOWN min=1 est=1 max=1 [2, 2]
    OR x2
      KNOWN min=1 est=1 max=1 [1, 1]
      EXACT_PHRASE
	AND x2 [1, 1]
	  KNOWN min=1 est=1 max=1 [1, 1]
	  KNOWN min=1 est=1 max=1 [1, 1]
  KNOWN min=1 est=1 max=1 [1, 1]

KNOWN min=1 est=1 max=1 [2, 2] must be XEP so somehow the order is wrong - that and the AND should be the other way around which would give:

AND_NOT x2 [1, 1]
  KNOWN min=1 est=1 max=1 [2, 2]
  AND x2 [1, 1]
    OR x2
      KNOWN min=1 est=1 max=1 [1, 1]
      EXACT_PHRASE
	AND x2 [1, 1]
	  KNOWN min=1 est=1 max=1 [1, 1]
	  KNOWN min=1 est=1 max=1 [1, 1]
    KNOWN min=1 est=1 max=1 [1, 1]

And if that were the case, the existing code which calls pop_op() would indeed remove the now unwanted EstimateOp from the right side of the AND_NOT.

[Olly Betts]

Candidate fix

[Olly Betts]

I've found the cause of that problem - we need to create the AND_NOT ExpandOp before the AND one. With candidate-fix.patch applied, valgrind reports no errors.

I'm not entirely happy with the design here though - things need to be created in the right order and while that order mostly matches the natural order that things happen in, this case shows it's possible to get the order wrong without that standing out as wrong in the code.

I think given the underlying problem wasn't the object lifetimes (but rather that we were deleting the wrong objects) that in the short term I'll apply that fix (assuming it works for your full case), turn your reproducer into a regression test, and create testcases which fully exercise other places where the EstimateOp handling is complex. The testsuite gets run under valgrind in CI (and by me locally) so that should catch any other similar problems.

I think the case that is wrong looks like the most tricky, because AndContext pulls together all "connected" and-like operations and groups the associated "nots" and "maybes", so in the general case it needs to build a complex tree of different postlist types and so handle the corresponding EstimateOps too.

[Robert Stepanek]

Thanks for this. I don't have anything to add to this analysis. I applied the candidate fix and did a bunch of local tests, all of which succeeded without invalid memory writes. I will now apply this patch to a broader set of real-world queries in a test environment.

[Robert Stepanek]

Despite running the patch, we are still occasionally seeing memory corruptions which are likely related to this issue. Unfortunately, I can not verify this assumption without considerable investigative effort for each occurrence.

Other than fixing the logic that leads to this bug, could we disable the query optimizer code? Is there a straight-forward way to replace the allocator used in the query code, e.g. I'm thinking of using a bump allocator that never frees until the very end of the query, which should prevent the memory corruptions and might allow debugging this better.

[Olly Betts]

Despite running the patch, we are still occasionally seeing memory corruptions which are likely related to this issue. Unfortunately, I can not verify this assumption without considerable investigative effort for each occurrence.

Are you able to show the "shape" of queries which trigger this?

E.g. knowing a query which looks like say ((a OR b) NOT c) AND d can trigger it would help narrow down the cause even without knowing what actual terms a, b, etc are.

Other than fixing the logic that leads to this bug, could we disable the query optimizer code?

It might be possible to patch this feature off for now - I'll have a look.

Is there a straight-forward way to replace the allocator used in the query code, e.g. I'm thinking of using a bump allocator that never frees until the very end of the query, which should prevent the memory corruptions and might allow debugging this better.

I've not really used C++ allocators (other than the default), but I think it would require going through all the code involved and carefully annotating the ones which should live the lifetime of the query, which seems like a lot of work. It'd be a worthwhile change I suspect as there are typically quite a lot of allocations with that lifetime, but it seems non-trivial to me.

Perhaps you could stick pointers to these objects in a container to delay deleting them until the query is completed? It'd very much be a workaround not a fix though as it seems like it must mean there's a mismatch between the estimate ops and the query tree, so the estimate will be getting calculated wrongly.

I'll also try to find the time to go through and create testcases for all the query ops to see if I can trigger this for any others.

[Olly Betts]

I've pushed 5ef927801011782725d66999fbf4c1546d021e50 which is my candidate fix and a regression test based on your reproducer. This isn't going to fix the problems you're still seeing, but I don't see a good reason to hold off merging the patch.

I'll try to go through and add explicit testcases for special cases in EstimateOp handling.

If you are able to report any query "shapes" that would help prioritise.

[Robert Stepanek]

Replying to Olly Betts:

Are you able to show the "shape" of queries which trigger this?

Not at the moment, the debug logs have gone. I will watch out for any new occurrences.

It might be possible to patch this feature off for now - I'll have a look.

Thanks. I tried replacing the EstimateOp and PostList pointers with shared_ptr as a workaround but this led from one compile error to the other until I backed off. I wish I could be of more help fixing this, but I still haven't grokked that part of the codebase.

Is there a straight-forward way to replace the allocator used in the query code, e.g.

I've not really used C++ allocators (other than the default),

I'm also not sure if its even feasible from outside Xapian, I think some mallocs get inlined depending on the container implementation. But I'm handwaving here.

Perhaps you could stick pointers to these objects in a container to delay deleting them until the query is completed?

If you mean without using shared_ptr, I guess that require to remove the "delete" calls to those EstimateOps in the query optimizer, right?

[Olly Betts]

bb43af12ff58a2de3078ba9b4c5212431c73bad5 changes pop_op() to move EstimateOp objects to a second linked list which is then deleted in the destructor. It shouldn't add overhead and the memory use is only prolonged until the end of the match (rather than being released early in the match process).

This should mean that the use after free can't happen even if the estimate_stack creation or handling is buggy. However buggy is still buggy and these bugs could lead to wildly incorrect estimates so it would still be good to identify cases where this happens.

[Olly Betts]

I think I have a plan for how to adjust the design to be more robust and hopefully eliminate any remaining bugs.

If we tracked the ops for subqueries of an operation explicitly in parallel with that operation's subpostlists then it should be much harder for things to go wrong (especially in corner cases which may not be well exercised by the testsuite). We can just have a linked list for each, and then splice those into the main list if they are actually used and if they aren't used we can actually delete the postlist objects then delete the ops to avoid use-after-free.

[Robert Stepanek]

Replying to Olly Betts:

bb43af12ff58a2de3078ba9b4c5212431c73bad5 changes pop_op() to move EstimateOp objects to a second linked list which is then deleted in the destructor.

This looks great, thanks. I will start testing that in our environments.