25-1: increase logging around tablet unlocks (#14741) (#15670)

Author: vporyadke

ydb/core/base/hive.h

@@ -705,6 +705,15 @@ namespace NKikimr {
                 Record.SetStatus(status);
                 Record.SetStatusMessage(statusMessage);
             }
+
+            TString ToString() const override {
+                TStringStream str;
+                str << ToStringHeader() << "{Status: " << NKikimrProto::EReplyStatus_Name(Record.GetStatus()).data();
+                str << " TabletID: " << Record.GetTabletID();
+                str << " Message: " << Record.GetStatusMessage();
+                str << "}";
+                return str.Str();
+            }
         };
 
         struct TEvLockTabletExecutionLost : public TEventPB<TEvLockTabletExecutionLost,

ydb/core/mind/hive/hive.h

@@ -384,7 +384,7 @@ inline void Out<NKikimr::NHive::TCompleteNotifications>(IOutputStream& o, const
             if (it != n.Notifications.begin()) {
                 o << ',';
             }
-            o << Hex(it->first->Type) << " " << it->first.Get()->Recipient;
+            o << Hex(it->first->Type) << " " << it->first.Get()->Recipient << " " << it->first->ToString();
         }
     }
 }

ydb/core/mind/hive/tx__lock_tablet.cpp

@@ -16,6 +16,7 @@ class TTxLockTabletExecution : public TTransactionBase<THive> {
 
     TSideEffects SideEffects;
     TActorId PreviousOwner;
+    bool Success = true;
 
 public:
     TTxLockTabletExecution(const NKikimrHive::TEvLockTabletExecution& rec, const TActorId& sender, const ui64 cookie, THive* hive)
@@ -43,6 +44,7 @@ class TTxLockTabletExecution : public TTransactionBase<THive> {
                     NKikimrProto::ERROR,
                     TStringBuilder() << "Trying to lock tablet " << TabletId << " to an invalid owner actor"
                 ), 0, Cookie);
+            Success = false;
             return true;
         }
 
@@ -53,6 +55,7 @@ class TTxLockTabletExecution : public TTransactionBase<THive> {
                     NKikimrProto::ERROR,
                     TStringBuilder() << "Trying to lock tablet " << TabletId << ", which doesn't exist"
                 ), 0, Cookie);
+            Success = false;
             return true;
         }
 
@@ -62,6 +65,7 @@ class TTxLockTabletExecution : public TTransactionBase<THive> {
                     NKikimrProto::ERROR,
                     TStringBuilder() << "Trying to lock tablet " << TabletId << " to " << OwnerActor << ", which is on a different node"
                 ), 0, Cookie);
+            Success = false;
             return true;
         }
 
@@ -71,6 +75,7 @@ class TTxLockTabletExecution : public TTransactionBase<THive> {
                     NKikimrProto::ERROR,
                     TStringBuilder() << "Trying to restore lock to tablet " << TabletId << ", which has expired"
                 ), 0, Cookie);
+            Success = false;
             return true;
         }
 
@@ -107,7 +112,11 @@ class TTxLockTabletExecution : public TTransactionBase<THive> {
     }
 
     void Complete(const TActorContext& ctx) override {
-        BLOG_D("THive::TTxLockTabletExecution::Complete TabletId: " << TabletId << " SideEffects: " << SideEffects);
+        if (Success) {
+            BLOG_D("THive::TTxLockTabletExecution::Complete TabletId: " << TabletId << " SideEffects: " << SideEffects);
+        } else {
+            BLOG_NOTICE("THive::TTxLockTabletExecution::Complete TabletId: " << TabletId << " SideEffects: " << SideEffects);
+        }
         SideEffects.Complete(ctx);
     }
 

ydb/core/mind/hive/tx__unlock_tablet.cpp

@@ -40,7 +40,7 @@ class TTxUnlockTabletExecution : public TTransactionBase<THive> {
     {}
 
     bool Execute(TTransactionContext& txc, const TActorContext&) override {
-        BLOG_D("THive::TTxUnlockTabletExecution::Execute TabletId: " << TabletId);
+        BLOG_NOTICE("THive::TTxUnlockTabletExecution::Execute TabletId: " << TabletId);
         SideEffects.Reset(Self->SelfId());
         TLeaderTabletInfo* tablet = Self->FindTabletEvenInDeleting(TabletId);
         if (tablet == nullptr) {
@@ -85,7 +85,7 @@ class TTxUnlockTabletExecution : public TTransactionBase<THive> {
     }
 
     void Complete(const TActorContext& ctx) override {
-        BLOG_D("THive::TTxUnlockTabletExecution::Complete TabletId: " << TabletId << " SideEffects: " << SideEffects);
+        BLOG_NOTICE("THive::TTxUnlockTabletExecution::Complete TabletId: " << TabletId << " SideEffects: " << SideEffects);
         SideEffects.Complete(ctx);
     }
 
@@ -109,6 +109,7 @@ ITransaction* THive::CreateUnlockTabletExecution(ui64 tabletId, ui64 seqNo, NKik
 
 void THive::ScheduleUnlockTabletExecution(TNodeInfo& node, NKikimrHive::ELockLostReason reason) {
     // Unlock tablets that have been locked by this node
+    BLOG_NOTICE("ScheduleUnlockTabletExecution(" << node.Id << ", " << NKikimrHive::ELockLostReason_Name(reason) << ")");
     for (TLeaderTabletInfo* tablet : node.LockedTablets) {
         Y_ABORT_UNLESS(FindTabletEvenInDeleting(tablet->Id) == tablet);
         Y_ABORT_UNLESS(tablet->LockedToActor.NodeId() == node.Id);
@@ -128,7 +129,7 @@ void THive::ScheduleUnlockTabletExecution(TNodeInfo& node, NKikimrHive::ELockLos
 void THive::Handle(TEvPrivate::TEvUnlockTabletReconnectTimeout::TPtr& ev) {
     TTabletId tabletId = ev->Get()->TabletId;
     ui64 seqNo = ev->Get()->SeqNo;
-    BLOG_D("THive::Handle::TEvUnlockTabletReconnectTimeout TabletId=" << tabletId);
+    BLOG_NOTICE("THive::Handle::TEvUnlockTabletReconnectTimeout TabletId=" << tabletId << " Reason=" << NKikimrHive::ELockLostReason_Name(ev->Get()->Reason));
     TLeaderTabletInfo* tablet = FindTabletEvenInDeleting(tabletId);
     if (tablet != nullptr && tablet->IsLockedToActor() && tablet->PendingUnlockSeqNo == seqNo) {
         // We use sequence numbers to make sure unlock happens only if some