diff options
| author | kseleznyov <[email protected]> | 2026-07-22 16:53:37 +0300 |
|---|---|---|
| committer | GitHub <[email protected]> | 2026-07-22 16:53:37 +0300 |
| commit | 6fb57842a960d000a99a80cd68dc276adc46cfec (patch) | |
| tree | 9f1d47cfea39e8b686489e31435d3a608594b94c | |
| parent | 8f1af3dbbdd38a03a301473da923811f50374bc1 (diff) | |
[YDB_LOG] Migrate ydb/core/tablet_flat (#45238)
Co-authored-by: Copilot Autofix powered by AI <[email protected]>
| -rw-r--r-- | ydb/core/tablet_flat/flat_executor.cpp | 42 | ||||
| -rw-r--r-- | ydb/core/tablet_flat/flat_executor.h | 3 | ||||
| -rw-r--r-- | ydb/core/tablet_flat/flat_executor_backup.cpp | 92 | ||||
| -rw-r--r-- | ydb/core/tablet_flat/flat_executor_recovery.cpp | 112 | ||||
| -rw-r--r-- | ydb/core/tablet_flat/flat_load_blob_queue.cpp | 31 | ||||
| -rw-r--r-- | ydb/core/tablet_flat/flat_load_blob_queue.h | 6 | ||||
| -rw-r--r-- | ydb/core/tablet_flat/tablet_flat_executed.cpp | 13 |
7 files changed, 191 insertions, 108 deletions
diff --git a/ydb/core/tablet_flat/flat_executor.cpp b/ydb/core/tablet_flat/flat_executor.cpp index 4ad992cf734..2cc96998dd7 100644 --- a/ydb/core/tablet_flat/flat_executor.cpp +++ b/ydb/core/tablet_flat/flat_executor.cpp @@ -51,10 +51,8 @@ #include <util/generic/ymath.h> #include <util/random/random.h> +#define YDB_LOG_THIS_FILE_COMPONENT NKikimrServices::LOCAL_DB_BACKUP -#define LOG_BACKUP_N(stream) LOG_NOTICE_S(*TlsActivationContext, NKikimrServices::LOCAL_DB_BACKUP, BackupLogPrefix() << stream) -#define LOG_BACKUP_D(stream) LOG_DEBUG_S(*TlsActivationContext, NKikimrServices::LOCAL_DB_BACKUP, BackupLogPrefix() << stream) -#define LOG_BACKUP_E(stream) LOG_ERROR_S(*TlsActivationContext, NKikimrServices::LOCAL_DB_BACKUP, BackupLogPrefix() << stream) namespace NKikimr { namespace NTabletFlatExecutor { @@ -4424,6 +4422,8 @@ STFUNC(TExecutor::StateInit) { } STFUNC(TExecutor::StateBoot) { + YDB_LOG_CREATE_CONTEXT(GetLogPrefix(), + {"actorStateFunc", "StateBoot"}); Y_ENSURE(BootLogic); switch (ev->GetTypeRewrite()) { // N.B. must work during follower promotion to leader @@ -4438,6 +4438,8 @@ STFUNC(TExecutor::StateBoot) { } STFUNC(TExecutor::StateWork) { + YDB_LOG_CREATE_CONTEXT(GetLogPrefix(), + {"actorStateFunc", "StateWork"}); switch (ev->GetTypeRewrite()) { HFunc(TEvPrivate::TEvActivateExecution, Handle); HFunc(TEvPrivate::TEvActivateLowExecution, Handle); @@ -4478,6 +4480,8 @@ STFUNC(TExecutor::StateWork) { } STFUNC(TExecutor::StateFollower) { + YDB_LOG_CREATE_CONTEXT(GetLogPrefix(), + {"actorStateFunc", "StateFollower"}); switch (ev->GetTypeRewrite()) { HFunc(TEvPrivate::TEvActivateExecution, Handle); HFunc(TEvPrivate::TEvActivateLowExecution, Handle); @@ -4498,6 +4502,8 @@ STFUNC(TExecutor::StateFollower) { STFUNC(TExecutor::StateFollowerBoot) { Y_ENSURE(BootLogic); + YDB_LOG_CREATE_CONTEXT(GetLogPrefix(), + {"actorStateFunc", "StateBoot"}); switch (ev->GetTypeRewrite()) { // N.B. must handle activities started before resync HFunc(TEvPrivate::TEvActivateExecution, Handle); @@ -5380,8 +5386,12 @@ void TExecutor::SetPreloadTablesData(THashSet<ui32> tables) { } -TStringBuilder TExecutor::BackupLogPrefix() const { - return TStringBuilder() << "[" << Owner->TabletID() << ":" << Generation0 << "] "; +NActors::NStructuredLog::TStructuredMessage TExecutor::GetLogPrefix() const { + return YDB_LOG_CREATE_MESSAGE( + {"actorClassName", "TExecutor"}, + {"selfId", SelfId()}, + {"tabletId", Owner->TabletID()}, + {"generation", Generation0}); } void TExecutor::StartNewBackup() { @@ -5398,7 +5408,7 @@ void TExecutor::StartNewBackup() { ui64 tabletId = Owner->TabletID(); if (std::find(excludeTabletIds.begin(), excludeTabletIds.end(), tabletId) != excludeTabletIds.end()) { - LOG_BACKUP_D("Tablet excluded from backup"); + YDB_LOG_DEBUG("Tablet excluded from backup"); return; } @@ -5421,7 +5431,10 @@ void TExecutor::StartNewBackup() { tabletId, Generation0, Step0, scheme, exclusion); if (snapshotWriter && changelogWriter) { - LOG_BACKUP_N("Starting new backup" << " Type# " << tabletType << " Gen# " << Generation0 << " Step# " << Step0); + YDB_LOG_NOTICE("Starting new backup", + {"type", tabletType}, + {"gen", Generation0}, + {"step", Step0}); auto snapshotWriterActor = Register(snapshotWriter, TMailboxType::HTSwap, AppData()->IOPoolId); const ui32 workBudgetPercent = std::clamp<ui32>(backupConfig.GetSnapshotWorkBudgetPercent(), 1, 100); for (const auto& [tableId, table] : tables) { @@ -5438,7 +5451,8 @@ void TExecutor::StartNewBackup() { auto changelogWriterActor = Register(changelogWriter, TMailboxType::HTSwap, AppData()->SystemPoolId); CommitManager->BackupLogic.Start(SelfId(), changelogWriterActor); } else { - LOG_BACKUP_D("Backup not configured"); + YDB_LOG_DEBUG("Backup not configured", + {"backupLogPrefix", GetLogPrefix()}); } } @@ -5446,7 +5460,8 @@ void TExecutor::Handle(NBackup::TEvSnapshotCompleted::TPtr& ev) { BackupSnapshotInProgress = false; Counters->Simple()[TExecutorCounters::BACKUP_SNAPSHOT_IN_PROGRESS].Set(0); if (ev->Get()->Success) { - LOG_BACKUP_N("Snapshot completed" << " Bytes# " << ev->Get()->WrittenBytes); + YDB_LOG_NOTICE("Snapshot completed", + {"bytes", ev->Get()->WrittenBytes}); Owner->BackupSnapshotComplete(OwnerCtx()); if (CommitManager->BackupLogic.IsRunning()) { @@ -5477,7 +5492,8 @@ void TExecutor::FailBackup(const TString& error) { Y_TABLET_ERROR(error); } - LOG_BACKUP_E(error); + YDB_LOG_ERROR("Backup failed", + {"error", error}); CommitManager->BackupLogic.Stop(); ScheduleRetryBackup(); } @@ -5492,9 +5508,9 @@ void TExecutor::ScheduleRetryBackup() { } auto retryTimeout = BackupRetry->Next(); - LOG_BACKUP_N("Scheduling backup retry" - << " Timeout# " << retryTimeout - << " Attempt# " << BackupRetry->GetIteration()); + YDB_LOG_NOTICE("Scheduling backup retry", + {"timeout", retryTimeout}, + {"attempt", BackupRetry->GetIteration()}); Schedule(retryTimeout, new NBackup::TEvStartNewBackup); } } diff --git a/ydb/core/tablet_flat/flat_executor.h b/ydb/core/tablet_flat/flat_executor.h index cbb147d6ea2..862a57fe50a 100644 --- a/ydb/core/tablet_flat/flat_executor.h +++ b/ydb/core/tablet_flat/flat_executor.h @@ -566,7 +566,8 @@ class TExecutor void StartNewBackup(); void FailBackup(const TString& error); void ScheduleRetryBackup(); - TStringBuilder BackupLogPrefix() const; + + NActors::NStructuredLog::TStructuredMessage GetLogPrefix() const; void UpdateCacheModesForPartStore(NTable::TPartView& partView, const THashMap<NTable::TTag, ECacheMode>& cacheModes); void UpdateCachePagesForDatabase(bool pendingOnly = false); diff --git a/ydb/core/tablet_flat/flat_executor_backup.cpp b/ydb/core/tablet_flat/flat_executor_backup.cpp index 6610854bef1..4d75de007bd 100644 --- a/ydb/core/tablet_flat/flat_executor_backup.cpp +++ b/ydb/core/tablet_flat/flat_executor_backup.cpp @@ -31,9 +31,7 @@ #include <util/stream/file.h> #include <util/system/hp_timer.h> -#define LOG_N(stream) LOG_NOTICE_S(*TlsActivationContext, NKikimrServices::LOCAL_DB_BACKUP, LogPrefix() << stream) -#define LOG_D(stream) LOG_DEBUG_S(*TlsActivationContext, NKikimrServices::LOCAL_DB_BACKUP, LogPrefix() << stream) -#define LOG_E(stream) LOG_ERROR_S(*TlsActivationContext, NKikimrServices::LOCAL_DB_BACKUP, LogPrefix() << stream) +#define YDB_LOG_THIS_FILE_COMPONENT NKikimrServices::LOCAL_DB_BACKUP namespace NKikimr::NTabletFlatExecutor::NBackup { @@ -210,8 +208,13 @@ class TSnapshotWriter : public TActorBootstrapped<TSnapshotWriter>, public IActo public: using TBase = TActorBootstrapped<TSnapshotWriter>; - TStringBuilder LogPrefix() const { - return TStringBuilder() << "[" << TabletId << ":" << Generation << ":" << Step << "] "; + NActors::NStructuredLog::TStructuredMessage LogPrefix() const { + return YDB_LOG_CREATE_MESSAGE( + {"actorClassName", "TSnapshotWriter"}, + {"selfId", SelfId()}, + {"tabletId", TabletId}, + {"generation", Generation}, + {"step", Step}); } struct TTableFile { @@ -241,7 +244,8 @@ public: } void Bootstrap() { - LOG_N("Starting snapshot" << " Path# " << SnapshotPath); + YDB_LOG_NOTICE("Starting snapshot", + {"path", SnapshotPath}); DeleteOldBackups(); @@ -264,13 +268,14 @@ public: SchemaSha256.Update(stringOut.Data(), stringOut.Size()); WrittenBytes += stringOut.Size(); Send(Owner, new TEvSnapshotStats(stringOut.Size())); - LOG_D("Schema written" << " Bytes# " << stringOut.Size()); + YDB_LOG_DEBUG("Schema written", + {"bytes", stringOut.Size()}); } catch (const std::exception& e) { return ReplyAndDie(false, TStringBuilder() << "Failed to create snapshot schema file " << schemaPath << ": " << e.what()); } if (Tables.empty()) { - LOG_D("No tables to scan, finalizing"); + YDB_LOG_DEBUG("No tables to scan, finalizing"); return Finalize(); } @@ -293,10 +298,10 @@ public: void DeleteOldBackups() { try { const auto backupGenStep = TGenStep{Generation, Step}; - + TVector<TFsPath> children; BackupPath.Parent().List(children); - + TVector<std::pair<TGenStep, TFsPath>> backups; for (const auto& child : children) { auto genStep = ParseBackupGenStep(child.Basename()); @@ -305,19 +310,20 @@ public: if (!genStep) { continue; } - + // valid backup directory if (child.Child("snapshot").Exists()) { backups.emplace_back(*genStep, child); continue; } - + // newer backup if (genStep >= backupGenStep) { continue; } - - LOG_N("Deleting incomplete backup" << " Path# " << child); + + YDB_LOG_NOTICE("Deleting incomplete backup", + {"path", child}); child.ForceDelete(); } @@ -326,11 +332,14 @@ public: }); for (size_t i = MaxBackupsLimit(); i < backups.size(); ++i) { - LOG_N("Deleting old backup" << " Path# " << backups[i].second); + YDB_LOG_NOTICE("Deleting old backup", + {"path", backups[i].second}); backups[i].second.ForceDelete(); } } catch (const std::exception& e) { - LOG_E("Failed to delete old backups" << " Path# " << BackupPath << " Error# " << e.what()); + YDB_LOG_ERROR("Failed to delete old backups", + {"path", BackupPath}, + {"error", e.what()}); } } @@ -338,7 +347,8 @@ public: if (success) { Send(Owner, new TEvSnapshotCompleted(WrittenBytes)); } else { - LOG_E("Snapshot failed" << " Error# " << error); + YDB_LOG_ERROR("Snapshot failed", + {"error", error}); Send(Owner, new TEvSnapshotCompleted(error)); } @@ -346,6 +356,7 @@ public: } STATEFN(StateWork) { + YDB_LOG_CREATE_CONTEXT(LogPrefix()); switch (ev->GetTypeRewrite()) { hFunc(TEvWriteSnapshot, Handle); } @@ -353,7 +364,9 @@ public: void Handle(TEvWriteSnapshot::TPtr& ev) { const auto* msg = ev->Get(); - LOG_D("Writing snapshot" << " TableId# " << msg->TableId << " Bytes# " << msg->SnapshotData.Size()); + YDB_LOG_DEBUG("Writing snapshot", + {"tableId", msg->TableId}, + {"bytes", msg->SnapshotData.Size()}); auto it = Tables.find(msg->TableId); if (it == Tables.end()) { @@ -393,7 +406,9 @@ public: void ScanDone(ui32 tableId) { DoneTables.insert(tableId); - LOG_D("Table scan done" << " Done# " << DoneTables.size() << " Total# " << Tables.size()); + YDB_LOG_DEBUG("Table scan done", + {"done", DoneTables.size()}, + {"total", Tables.size()}); if (DoneTables.size() == Tables.size()) { return Finalize(); } @@ -478,7 +493,8 @@ public: DeleteOldBackups(); - LOG_N("Snapshot finalized" << " Bytes# " << WrittenBytes); + YDB_LOG_NOTICE("Snapshot finalized", + {"bytes", WrittenBytes}); return ReplyAndDie(); } @@ -564,7 +580,7 @@ public: } catch (const std::exception& e) { TString value; DbgPrintValue(value, cell, column.PType); - + throw yexception() << "Failed to write column to JSON: " << e.what() << " Column# " << column.Name << " Type# " << NScheme::TypeName(column.PType.GetTypeId(), "") @@ -840,12 +856,18 @@ public: , InFlightBytesLimit(inFlightBytesLimit) {} - TStringBuilder LogPrefix() const { - return TStringBuilder() << "[" << TabletId << ":" << Generation << ":" << Step << "] "; + NActors::NStructuredLog::TStructuredMessage LogPrefix() const { + return YDB_LOG_CREATE_MESSAGE( + {"actorClassName", "TChangelogWriter"}, + {"selfId", SelfId()}, + {"tabletId", TabletId}, + {"generation", Generation}, + {"step", Step}); } void Bootstrap() { - LOG_N("Starting changelog" << " Path# " << ChangelogPath); + YDB_LOG_NOTICE("Starting changelog", + {"path", ChangelogPath}); // writing initial changelog and checksum files BufferCreatedAt = TActivationContext::Monotonic(); @@ -855,6 +877,7 @@ public: } STATEFN(StateWork) { + YDB_LOG_CREATE_CONTEXT(LogPrefix()); switch (ev->GetTypeRewrite()) { hFunc(TEvWriteChangelog, Handle); hFunc(TEvPrivate::TEvIoComplete, Handle); @@ -869,7 +892,8 @@ public: NJson::TJsonWriter writer(&out, BackupJsonConfig()); const auto* msg = ev->Get(); - LOG_D("Writing changelog" << " Step# " << msg->Step); + YDB_LOG_DEBUG("Writing changelog", + {"step", msg->Step}); TString dataUpdate; TString schemeUpdate; @@ -997,10 +1021,10 @@ public: return ReplyAndDie(msg->Error); } - LOG_D("Changelog IO completed" - << " Bytes# " << IoInFlightBytes - << " Latency# " << msg->Latency - << " Lag# " << msg->Lag); + YDB_LOG_DEBUG("Changelog IO completed", + {"bytes", IoInFlightBytes}, + {"latency", msg->Latency}, + {"lag", msg->Lag}); Send(Owner, new TEvChangelogStats(IoInFlightBytes, msg->Latency, msg->Lag)); @@ -1009,7 +1033,9 @@ public: IoInProgress = false; if (NeedNewBackup()) { - LOG_N("Requesting new backup" << " ChangelogBytes# " << WrittenBytes << " SnapshotBytes# " << *SnapshotWrittenBytes); + YDB_LOG_NOTICE("Requesting new backup", + {"changelogBytes", WrittenBytes}, + {"snapshotBytes", *SnapshotWrittenBytes}); Send(Owner, new TEvStartNewBackup()); } @@ -1043,7 +1069,8 @@ public: } void StartIO(EOpenMode openMode = EOpenModeFlag::OpenExisting | EOpenModeFlag::ForAppend) { - LOG_D("Starting Changelog IO" << " Bytes# " << Buffer.Size()); + YDB_LOG_DEBUG("Starting Changelog IO", + {"bytes", Buffer.Size()}); IoInFlightBytes = Buffer.Size(); IoInProgress = true; @@ -1078,7 +1105,8 @@ public: } void ReplyAndDie(const TString& error) { - LOG_E("Changelog failed" << " Error# " << error); + YDB_LOG_ERROR("Changelog failed", + {"error", error}); Send(Owner, new TEvChangelogFailed(error)); PassAway(); } diff --git a/ydb/core/tablet_flat/flat_executor_recovery.cpp b/ydb/core/tablet_flat/flat_executor_recovery.cpp index 84628ff6391..130ca86e6bb 100644 --- a/ydb/core/tablet_flat/flat_executor_recovery.cpp +++ b/ydb/core/tablet_flat/flat_executor_recovery.cpp @@ -24,10 +24,8 @@ #include <util/stream/file.h> +#define YDB_LOG_THIS_FILE_COMPONENT NKikimrServices::LOCAL_DB_RECOVERY -#define LOG_N(stream) LOG_NOTICE_S(*TlsActivationContext, NKikimrServices::LOCAL_DB_RECOVERY, LogPrefix() << stream) -#define LOG_D(stream) LOG_DEBUG_S(*TlsActivationContext, NKikimrServices::LOCAL_DB_RECOVERY, LogPrefix() << stream) -#define LOG_E(stream) LOG_ERROR_S(*TlsActivationContext, NKikimrServices::LOCAL_DB_RECOVERY, LogPrefix() << stream) namespace NKikimr::NTabletFlatExecutor::NRecovery { @@ -375,7 +373,7 @@ private: NTable::TDatabase DB; TDryRunPages Pages; TDryRunStats Stats; - + bool ProcessPendingScheduled = false; TDeque<TAutoPtr<ITransaction>> PendingTx; }; @@ -390,8 +388,11 @@ public: ITransaction *CreateTxUploadSnapshot(TEvSnapshotData::TPtr ev, size_t startLine = 0); ITransaction *CreateTxUploadChangelog(TEvChangelogData::TPtr ev, size_t startLine = 0); - TStringBuilder LogPrefix() const { - return TStringBuilder() << "[" << TabletID() << "] "; + NActors::NStructuredLog::TStructuredMessage LogPrefix() const { + return YDB_LOG_CREATE_MESSAGE( + {"actorClassName", "TRecoveryShard"}, + {"selfId", SelfId()}, + {"tabletId", TabletID()}); } explicit TRecoveryShard(const TActorId &tablet, TTabletStorageInfo *info) @@ -425,6 +426,8 @@ public: void DefaultSignalTabletActive(const TActorContext &) override {} STFUNC(StateWork) { + YDB_LOG_CREATE_CONTEXT(LogPrefix(), + {"actorState", "StateWork"}); switch (ev->GetTypeRewrite()) { hFunc(TEvRestoreBackup, Handle); hFunc(TEvBackupReaderResult, Handle); @@ -451,7 +454,9 @@ public: void Handle(TEvBackupInfo::TPtr& ev, const TActorContext& ctx) { TotalBytes = ev->Get()->TotalBytes; - LOG_D("Backup info" << " TotalBytes# " << TotalBytes << " DryRun# " << DryRun); + YDB_LOG_DEBUG("Backup info", + {"totalBytes", TotalBytes}, + {"dryRun", DryRun}); if (DryRun) { auto* dryRunExec = new TDryRunExecutor(TabletID()); @@ -465,22 +470,27 @@ public: } void Handle(TEvSchemaData::TPtr& ev) { - LOG_D("Uploading schema"); + YDB_LOG_DEBUG("Uploading schema"); Execute(CreateTxUploadSchema(ev)); } void Handle(TEvSnapshotData::TPtr& ev) { - LOG_D("Uploading snapshot" << " Table# " << ev->Get()->TableName); + YDB_LOG_DEBUG("Uploading snapshot", + {"table", ev->Get()->TableName}); Execute(CreateTxUploadSnapshot(ev)); } void Handle(TEvChangelogData::TPtr& ev) { - LOG_D("Uploading changelog" << " Lines# " << ev->Get()->Lines.size()); + YDB_LOG_DEBUG("Uploading changelog", + {"lines", ev->Get()->Lines.size()}); Execute(CreateTxUploadChangelog(ev)); } void StartRestore(const TString& backupPath, TActorId subscriber = {}, bool skipChecksumValidation = false, bool dryRun = false) { - LOG_N("Starting restore" << " Path# " << backupPath << " SkipChecksum# " << skipChecksumValidation << " DryRun# " << dryRun); + YDB_LOG_NOTICE("Starting restore", + {"path", backupPath}, + {"skipChecksum", skipChecksumValidation}, + {"dryRun", dryRun}); RestoreState = ERestoreState::InProgress; SkipChecksumValidation = skipChecksumValidation; DryRun = dryRun; @@ -494,15 +504,17 @@ public: void CompleteRestore(bool success, const TString& error) { if (success) { if (error) { - LOG_N("Restore completed with warning" << " Error# " << error); + YDB_LOG_NOTICE("Restore completed with warning", + {"error", error}); RestoreState = ERestoreState::DoneWithWarning; Error = error; } else { - LOG_N("Restore completed"); + YDB_LOG_NOTICE("Restore completed"); RestoreState = ERestoreState::Done; } } else { - LOG_E("Restore failed" << " Error# " << error); + YDB_LOG_ERROR("Restore failed", + {"error", error}); RestoreState = ERestoreState::Error; Error = error; } @@ -603,7 +615,7 @@ public: "\r\n" "restoreBackup requires POST")); return true; - } + } } TStringStream str; @@ -773,7 +785,7 @@ private: class TTxUploadSchema : public TTransactionBase<TRecoveryShard> { public: - TStringBuilder LogPrefix() const { return Self->LogPrefix(); } + NActors::NStructuredLog::TStructuredMessage LogPrefix() const { return Self->LogPrefix(); } TTxUploadSchema(TRecoveryShard* self, TEvSchemaData::TPtr& schema) : TBase(self) @@ -799,7 +811,8 @@ public: void Complete(const TActorContext& ctx) override { if (Error) { - LOG_E("Schema upload failed" << " Error# " << Error); + YDB_LOG_ERROR("Schema upload failed", + {"error", Error}); Self->CompleteRestore(false, Error); ctx.Send(Schema->Sender, new TEvDataAck(false, Error)); } else { @@ -814,7 +827,7 @@ private: class TTxUploadSnapshot : public TTransactionBase<TRecoveryShard> { public: - TStringBuilder LogPrefix() const { return Self->LogPrefix(); } + NActors::NStructuredLog::TStructuredMessage LogPrefix() const { return Self->LogPrefix(); } TTxUploadSnapshot(TRecoveryShard* self, TEvSnapshotData::TPtr& snapshot, size_t startLine) : TBase(self) @@ -861,7 +874,8 @@ public: if (i < Snapshot->Get()->Lines.size()) { // Start new tx to upload the rest data - LOG_D("Snapshot upload partial, continuing from" << " Line# " << i); + YDB_LOG_DEBUG("Snapshot upload partial, continuing", + {"line", i}); Self->Execute(Self->CreateTxUploadSnapshot(std::move(Snapshot), i)); Result.PartialDone(processedBytes); } else { @@ -872,13 +886,15 @@ public: void Complete(const TActorContext& ctx) override { if (Result.IsDone()) { - LOG_D("Snapshot chunk uploaded" << " Bytes# " << Result.GetProcessedBytes()); + YDB_LOG_DEBUG("Snapshot chunk uploaded", + {"bytes", Result.GetProcessedBytes()}); Self->ProcessedBytes += Result.GetProcessedBytes(); ctx.Send(Snapshot->Sender, new TEvDataAck(true)); } else if (Result.IsPartialDone()) { Self->ProcessedBytes += Result.GetProcessedBytes(); } else if (Result.IsError()) { - LOG_E("Snapshot upload failed" << " Error# " << Result.GetErrorMessage()); + YDB_LOG_ERROR("Snapshot upload failed", + {"error", Result.GetErrorMessage()}); Self->CompleteRestore(false, Result.GetErrorMessage()); ctx.Send(Snapshot->Sender, new TEvDataAck(false, Result.GetErrorMessage())); } @@ -893,7 +909,7 @@ private: class TTxUploadChangelog : public TTransactionBase<TRecoveryShard> { public: - TStringBuilder LogPrefix() const { return Self->LogPrefix(); } + NActors::NStructuredLog::TStructuredMessage LogPrefix() const { return Self->LogPrefix(); } TTxUploadChangelog(TRecoveryShard* self, TEvChangelogData::TPtr& changelog, size_t startLine) : TBase(self) @@ -988,7 +1004,8 @@ public: if (i < Changelog->Get()->Lines.size()) { // Start new tx to upload the rest data - LOG_D("Changelog upload partial, continuing from" << " Line# " << i); + YDB_LOG_DEBUG("Changelog upload partial, continuing", + {"line", i}); Self->Execute(Self->CreateTxUploadChangelog(std::move(Changelog), i)); Result.PartialDone(processedBytes); } else { @@ -999,13 +1016,15 @@ public: void Complete(const TActorContext& ctx) override { if (Result.IsDone()) { - LOG_D("Changelog chunk uploaded" << " Bytes# " << Result.GetProcessedBytes()); + YDB_LOG_DEBUG("Changelog chunk uploaded", + {"bytes", Result.GetProcessedBytes()}); Self->ProcessedBytes += Result.GetProcessedBytes(); ctx.Send(Changelog->Sender, new TEvDataAck(true)); } else if (Result.IsPartialDone()) { Self->ProcessedBytes += Result.GetProcessedBytes(); } else if (Result.IsError()) { - LOG_E("Changelog upload failed" << " Error# " << Result.GetErrorMessage()); + YDB_LOG_ERROR("Changelog upload failed", + {"error", Result.GetErrorMessage()}); Self->CompleteRestore(true, Result.GetErrorMessage()); // changelog errors are warnings ctx.Send(Changelog->Sender, new TEvDataAck(false, Result.GetErrorMessage())); } @@ -1045,12 +1064,17 @@ public: , SkipChecksumValidation(skipChecksumValidation) {} - TStringBuilder LogPrefix() const { - return TStringBuilder() << "[" << ExpectedTabletId << "] "; + NActors::NStructuredLog::TStructuredMessage LogPrefix() const { + return YDB_LOG_CREATE_MESSAGE( + {"actorClassName", "TBackupReader"}, + {"selfId", SelfId()}, + {"expectedTabletId", ExpectedTabletId}); } void Bootstrap() { - LOG_N("Validating backup" << " Path# " << BackupPath); + YDB_LOG_CREATE_CONTEXT(LogPrefix()); + YDB_LOG_NOTICE("Validating backup", + {"path", BackupPath}); if (!BackupPath.Exists()) { return SendResultAndDie(false, TStringBuilder() << "Backup dir doesn't exist: " << BackupPath); @@ -1071,12 +1095,15 @@ public: return SendResultAndDie(false, TStringBuilder() << "Cannot calculate total size: " << e.what()); } - LOG_N("Backup validated" << " TotalBytes# " << totalBytes); + YDB_LOG_NOTICE("Backup validated", + {"totalBytes", totalBytes}); Send(Owner, new TEvBackupInfo(totalBytes)); Become(&TThis::StateWork); } STATEFN(StateWork) { + YDB_LOG_CREATE_CONTEXT(LogPrefix(), + {"actorState", "StateWork"}); switch (ev->GetTypeRewrite()) { hFunc(TEvReadBackup, Handle); hFunc(TEvDataAck, Handle); @@ -1085,7 +1112,7 @@ public: } void Handle(TEvReadBackup::TPtr&) { - LOG_D("Sending schema data"); + YDB_LOG_DEBUG("Sending schema data"); try { TString schemaData = TFileInput(SchemaFilePath).ReadAll(); Send(Owner, new TEvSchemaData(std::move(schemaData))); @@ -1118,7 +1145,8 @@ public: CurrentTableName = CurrentTableName.substr(0, CurrentTableName.size() - 5); } - LOG_D("Processing snapshot file" << " Path# " << CurrentFilePath); + YDB_LOG_DEBUG("Processing snapshot file", + {"path", CurrentFilePath}); try { CurrentFileInput = MakeHolder<TFileInput>(CurrentFilePath, 1_MB); } catch (const TIoException& e) { @@ -1129,7 +1157,7 @@ public: CurrentTableName.clear(); ChangelogProcessed = true; - LOG_D("Processing changelog"); + YDB_LOG_DEBUG("Processing changelog"); try { CurrentFileInput = MakeHolder<TFileInput>(CurrentFilePath, 1_MB); } catch (const TIoException& e) { @@ -1137,7 +1165,7 @@ public: } } else { // All files processed - LOG_D("All files processed"); + YDB_LOG_DEBUG("All files processed"); return SendResultAndDie(true); } } @@ -1171,17 +1199,17 @@ public: } bool ValidateSnapshot() { - LOG_D("Validating snapshot"); + YDB_LOG_DEBUG("Validating snapshot"); if (!SnapshotDirPath.Exists()) { SendResultAndDie(false, TStringBuilder() << "Snapshot dir doesn't exist: " << SnapshotDirPath); return false; } - + if (!SchemaFilePath.Exists()) { SendResultAndDie(false, TStringBuilder() << "Snapshot schema file doesn't exist: " << SchemaFilePath); return false; } - + auto manifestFile = SnapshotDirPath.Child("manifest.json"); if (!manifestFile.Exists()) { SendResultAndDie(false, TStringBuilder() << "Manifest file doesn't exist: " << manifestFile); @@ -1319,7 +1347,8 @@ public: << ", got " << actualFileSha256); return false; } - LOG_D("Checksum validated" << " File# " << name); + YDB_LOG_DEBUG("Checksum validated", + {"file", name}); } } @@ -1327,7 +1356,7 @@ public: } bool ValidateChangelog() { - LOG_D("Validating changelog"); + YDB_LOG_DEBUG("Validating changelog"); if (!ChangelogFilePath.Exists()) { SendResultAndDie(false, TStringBuilder() << "Changelog file doesn't exist: " << ChangelogFilePath); @@ -1392,7 +1421,7 @@ public: return false; } - LOG_D("Changelog validated"); + YDB_LOG_DEBUG("Changelog validated"); return true; } @@ -1408,7 +1437,7 @@ public: << "Failed to parse changelog line " << line << ": " << e.what() << ", last valid line: " << lastValidLine; return false; - } + } if (!json.Has("prev_sha256") || !json["prev_sha256"].IsString()) { error = TStringBuilder() @@ -1448,7 +1477,8 @@ public: void SendResultAndDie(bool success, const TString& error = "") { if (!success) { - LOG_E("Failed" << " Error# " << error); + YDB_LOG_ERROR("Failed", + {"error", error}); } Send(Owner, new TEvBackupReaderResult(success, error)); PassAway(); diff --git a/ydb/core/tablet_flat/flat_load_blob_queue.cpp b/ydb/core/tablet_flat/flat_load_blob_queue.cpp index 965893e0bb5..5f85a90441e 100644 --- a/ydb/core/tablet_flat/flat_load_blob_queue.cpp +++ b/ydb/core/tablet_flat/flat_load_blob_queue.cpp @@ -3,19 +3,12 @@ #include <ydb/core/base/appdata.h> #include <ydb/core/base/counters.h> +#define YDB_LOG_THIS_FILE_COMPONENT NKikimrServices::TABLET_EXECUTOR + namespace NKikimr { namespace NTabletFlatExecutor { namespace { - struct TLogPrefix { - const TLoadBlobQueueConfig& Config; - - friend IOutputStream& operator<<(IOutputStream& out, const TLogPrefix& value) { - out << (value.Config.Follower ? "Follower" : "Leader") - << "{" << value.Config.TabletID << ":" << value.Config.Generation << ":-} "; - return out; - } - }; struct TDumpLogoBlobs { const TVector<TLogoBlobID>& Blobs; @@ -104,10 +97,11 @@ bool TLoadBlobQueue::SendRequests(const TActorId& sender) { } if (newBlobs) { - LOG_DEBUG_S(*TlsActivationContext, NKikimrServices::TABLET_EXECUTOR, TLogPrefix{ Config } - << "sending TEvGet batch " << batchSize - << " bytes, " << ActiveBytesInFly - << " total, blobs: " << TDumpLogoBlobs{ newBlobs }); + YDB_LOG_DEBUG("Sending TEvGet batch bytes, total", + {"logPrefix", LogPrefix()}, + {"batchSize", batchSize}, + {"activeBytesInFly", ActiveBytesInFly}, + {"blobs", TDumpLogoBlobs{ newBlobs }}); TArrayHolder<TEvBlobStorage::TEvGet::TQuery> query(new TEvBlobStorage::TEvGet::TQuery[newBlobs.size()]); for (size_t i = 0; i < newBlobs.size(); ++i) { query[i].Set(newBlobs[i]); @@ -133,8 +127,9 @@ bool TLoadBlobQueue::SendRequests(const TActorId& sender) { bool TLoadBlobQueue::ProcessResult(TEvBlobStorage::TEvGetResult* msg) { if (msg->Status != NKikimrProto::OK) { - LOG_ERROR_S(*TlsActivationContext, NKikimrServices::TABLET_EXECUTOR, TLogPrefix{ Config } - << "EvGet failed, request: " << msg->Print(false)); + YDB_LOG_ERROR("EvGet failed", + {"logPrefix", LogPrefix()}, + {"request", msg->Print(false)}); if (msg->Status == NKikimrProto::NODATA) { if (Config.NoDataCounter) { @@ -149,8 +144,10 @@ bool TLoadBlobQueue::ProcessResult(TEvBlobStorage::TEvGetResult* msg) { auto* resEnd = resBegin + msg->ResponseSz; for (auto* x = resBegin; x != resEnd; ++x) { if (x->Status != NKikimrProto::OK) { - LOG_ERROR_S(*TlsActivationContext, NKikimrServices::TABLET_EXECUTOR, TLogPrefix{ Config } - << "EvGet failed for blob " << x->Id << ", request: " << msg->Print(false)); + YDB_LOG_ERROR("EvGet failed for blob", + {"logPrefix", LogPrefix()}, + {"id", x->Id}, + {"request", msg->Print(false)}); if (x->Status == NKikimrProto::NODATA) { if (Config.NoDataCounter) { diff --git a/ydb/core/tablet_flat/flat_load_blob_queue.h b/ydb/core/tablet_flat/flat_load_blob_queue.h index 1f97b293280..c69cdd676f6 100644 --- a/ydb/core/tablet_flat/flat_load_blob_queue.h +++ b/ydb/core/tablet_flat/flat_load_blob_queue.h @@ -46,6 +46,12 @@ namespace NTabletFlatExecutor { public: TLoadBlobQueueConfig Config; + NActors::NStructuredLog::TStructuredMessage LogPrefix() const { + return YDB_LOG_CREATE_MESSAGE( + {"role", (Config.Follower ? "Follower" : "Leader")}, + {"tabletId", Config.TabletID}, + {"generation", Config.Generation}); + } private: ui64 ActiveBytesInFly = 0; diff --git a/ydb/core/tablet_flat/tablet_flat_executed.cpp b/ydb/core/tablet_flat/tablet_flat_executed.cpp index ae3495e5187..9bd08555220 100644 --- a/ydb/core/tablet_flat/tablet_flat_executed.cpp +++ b/ydb/core/tablet_flat/tablet_flat_executed.cpp @@ -6,6 +6,8 @@ #include <ydb/core/base/mon_auth.h> #include <library/cpp/monlib/service/pages/templates.h> +#define YDB_LOG_THIS_FILE_COMPONENT NKikimrServices::TABLET_EXECUTOR + namespace NKikimr { namespace NTabletFlatExecutor { @@ -25,9 +27,11 @@ bool TTabletExecutedFlat::OnUnhandledException(const std::exception& e) { // is expected to always succeed. if (auto* actor = dynamic_cast<IActor*>(this)) { auto ctx = TActivationContext::ActorContextFor(actor->SelfId()); - LOG_CRIT_S(*TlsActivationContext, NKikimrServices::TABLET_EXECUTOR, - "Tablet " << TabletID() << " unhandled exception " << TypeName(e) << ": " << e.what() - << '\n' << TBackTrace::FromCurrentException().PrintToString()); + YDB_LOG_CRIT("Tablet unhandled exception", + {"tabletId", TabletID()}, + {"typeName", TypeName(e)}, + {"exception", e.what()}, + {"backtrace", TBackTrace::FromCurrentException().PrintToString()}); GetServiceCounters(AppData(ctx)->Counters, "tablets")->GetCounter("alerts_exception", true)->Inc(); @@ -250,7 +254,8 @@ bool TTabletExecutedFlat::OnRenderAppHtmlPage(NMon::TEvRemoteHttpInfo::TPtr ev, } void TTabletExecutedFlat::RenderHtmlPage(NMon::TEvRemoteHttpInfo::TPtr &ev, const TActorContext &ctx) { - LOG_NOTICE_S(ctx, NKikimrServices::TABLET_EXECUTOR, "RenderHtmlPage for tablet " << TabletID()); + YDB_LOG_NOTICE_CTX(ctx, "RenderHtmlPage for tablet", + {"tabletId", TabletID()}); auto cgi = ev->Get()->Cgi(); auto path = ev->Get()->PathInfo(); TString queryString = cgi.Print(); |
