Merge pull request #6544 from vespa-engine/toregge/add-events-when-having-exclusive-lock-for-enum-values

Log events to related to exclusive lock for stable enums:

4 files changed, 48 insertions, 21 deletions

diff --git a/searchlib/src/vespa/searchlib/attribute/attributevector.cpp b/searchlib/src/vespa/searchlib/attribute/attributevector.cpp
index fbad06821cd..e2dc9f4c856 100644
--- a/searchlib/src/vespa/searchlib/attribute/attributevector.cpp
+++ b/searchlib/src/vespa/searchlib/attribute/attributevector.cpp
@@ -20,6 +20,7 @@
 #include <vespa/searchlib/query/query_term_decoder.h>
 #include <vespa/searchlib/queryeval/emptysearch.h>
 #include <vespa/vespalib/util/exceptions.h>
+#include <vespa/searchlib/util/logutil.h>
 
 #include <vespa/log/log.h>
 LOG_SETUP(".searchlib.attribute.attributevector");
@@ -889,6 +890,17 @@ AttributeVector::getChangeVectorMemoryUsage() const
     return MemoryUsage(0, 0, 0, 0);
 }
 
+void
+AttributeVector::logEnumStoreEvent(const char *reason, const char *stage)
+{
+    vespalib::JSONStringer jstr;
+    jstr.beginObject();
+    jstr.appendKey("path").appendString(getBaseFileName());
+    jstr.endObject();
+    vespalib::string eventName(make_string("%s.attribute.enumstore.%s", reason, stage));
+    EV_STATE(eventName.c_str(), jstr.toString().data());
+}
+
 template bool AttributeVector::append<StringChangeData>(ChangeVectorT< ChangeTemplate<StringChangeData> > &changes, uint32_t , const StringChangeData &, int32_t, bool);
 template bool AttributeVector::update<StringChangeData>(ChangeVectorT< ChangeTemplate<StringChangeData> > &changes, uint32_t , const StringChangeData &);
 template bool AttributeVector::remove<StringChangeData>(ChangeVectorT< ChangeTemplate<StringChangeData> > &changes, uint32_t , const StringChangeData &, int32_t);
diff --git a/searchlib/src/vespa/searchlib/attribute/attributevector.h b/searchlib/src/vespa/searchlib/attribute/attributevector.h
index cb83b86001b..bcd4b1ae079 100644
--- a/searchlib/src/vespa/searchlib/attribute/attributevector.h
+++ b/searchlib/src/vespa/searchlib/attribute/attributevector.h
@@ -391,6 +391,7 @@ protected:
 
     virtual AddressSpace getEnumStoreAddressSpaceUsage() const;
     virtual AddressSpace getMultiValueAddressSpaceUsage() const;
+    void logEnumStoreEvent(const char *reason, const char *stage);
 
 public:
     DECLARE_IDENTIFIABLE_ABSTRACT(AttributeVector);
diff --git a/searchlib/src/vespa/searchlib/attribute/multienumattribute.hpp b/searchlib/src/vespa/searchlib/attribute/multienumattribute.hpp
index d3588009319..e6d3b910b14 100644
--- a/searchlib/src/vespa/searchlib/attribute/multienumattribute.hpp
+++ b/searchlib/src/vespa/searchlib/attribute/multienumattribute.hpp
@@ -44,21 +44,24 @@ void
 MultiValueEnumAttribute<B, M>::reEnumerate()
 {
     // update MultiValueMapping with new EnumIndex values.
-    EnumModifier enumGuard(this->getEnumModifier());
-    for (DocId doc = 0; doc < this->getNumDocs(); ++doc) {
-        vespalib::ConstArrayRef<WeightedIndex> indicesRef(this->_mvMapping.get(doc));
-        WeightedIndexVector indices(indicesRef.cbegin(), indicesRef.cend());
-
-        for (uint32_t i = 0; i < indices.size(); ++i) {
-            EnumIndex oldIndex = indices[i].value();
-            EnumIndex newIndex;
-            this->_enumStore.getCurrentIndex(oldIndex, newIndex);
-            indices[i] = WeightedIndex(newIndex, indices[i].weight());
+    this->logEnumStoreEvent("compactfixup", "drain");
+    {
+        EnumModifier enumGuard(this->getEnumModifier());
+        this->logEnumStoreEvent("compactfixup", "start");
+        for (DocId doc = 0; doc < this->getNumDocs(); ++doc) {
+            vespalib::ConstArrayRef<WeightedIndex> indicesRef(this->_mvMapping.get(doc));
+            WeightedIndexVector indices(indicesRef.cbegin(), indicesRef.cend());
+            for (uint32_t i = 0; i < indices.size(); ++i) {
+                EnumIndex oldIndex = indices[i].value();
+                EnumIndex newIndex;
+                this->_enumStore.getCurrentIndex(oldIndex, newIndex);
+                indices[i] = WeightedIndex(newIndex, indices[i].weight());
+            }
+            std::atomic_thread_fence(std::memory_order_release);
+            this->_mvMapping.replace(doc, indices);
         }
-
-        std::atomic_thread_fence(std::memory_order_release);
-        this->_mvMapping.replace(doc, indices);
     }
+    this->logEnumStoreEvent("compactfixup", "complete");
 }
 
 template <typename B, typename M>
@@ -197,9 +200,12 @@ std::unique_ptr<AttributeSaver>
 MultiValueEnumAttribute<B, M>::onInitSave()
 {
     {
+        this->logEnumStoreEvent("reenumerate", "drain");
         EnumModifier enumGuard(this->getEnumModifier());
+        this->logEnumStoreEvent("reenumerate", "start");
         this->_enumStore.reEnumerate();
     }
+    this->logEnumStoreEvent("reenumerate", "complete");
     vespalib::GenerationHandler::Guard guard(this->getGenerationHandler().
                                              takeGuard());
     return std::make_unique<MultiValueEnumAttributeSaver<WeightedIndex>>
diff --git a/searchlib/src/vespa/searchlib/attribute/singleenumattribute.hpp b/searchlib/src/vespa/searchlib/attribute/singleenumattribute.hpp
index d4f5a58d866..a0d6bbe2f65 100644
--- a/searchlib/src/vespa/searchlib/attribute/singleenumattribute.hpp
+++ b/searchlib/src/vespa/searchlib/attribute/singleenumattribute.hpp
@@ -137,16 +137,21 @@ template <typename B>
 void
 SingleValueEnumAttribute<B>::reEnumerate()
 {
-    EnumModifier enumGuard(this->getEnumModifier());
-    for (uint32_t i = 0; i < _enumIndices.size(); ++i) {
-        EnumIndex oldIdx = _enumIndices[i];
-        if (oldIdx.valid()) {
-            EnumIndex newIdx;
-            this->_enumStore.getCurrentIndex(oldIdx, newIdx);
-            std::atomic_thread_fence(std::memory_order_release);
-            _enumIndices[i] = newIdx;
+    this->logEnumStoreEvent("compactfixup", "drain");
+    {
+        EnumModifier enumGuard(this->getEnumModifier());
+        this->logEnumStoreEvent("compactfixup", "start");
+        for (uint32_t i = 0; i < _enumIndices.size(); ++i) {
+            EnumIndex oldIdx = _enumIndices[i];
+            if (oldIdx.valid()) {
+                EnumIndex newIdx;
+                this->_enumStore.getCurrentIndex(oldIdx, newIdx);
+                std::atomic_thread_fence(std::memory_order_release);
+                _enumIndices[i] = newIdx;
+            }
         }
     }
+    this->logEnumStoreEvent("compactfixup", "complete");
 }
 
 template <typename B>
@@ -303,9 +308,12 @@ std::unique_ptr<AttributeSaver>
 SingleValueEnumAttribute<B>::onInitSave()
 {
     {
+        this->logEnumStoreEvent("reenumerate", "drain");
         EnumModifier enumGuard(this->getEnumModifier());
+        this->logEnumStoreEvent("reenumerate", "start");
         this->_enumStore.reEnumerate();
     }
+    this->logEnumStoreEvent("reenumerate", "complete");
     vespalib::GenerationHandler::Guard guard(this->getGenerationHandler().
                                              takeGuard());
     return std::make_unique<SingleValueEnumAttributeSaver>