Introduce logging in 'tools restore' (#10681)

16 files changed, 260 insertions, 191 deletions

diff --git a/ydb/apps/ydb/ut/ydb-dump.cpp b/ydb/apps/ydb/ut/ydb-dump.cpp
index 5fc7d15f8d..bdc36b575f 100644
--- a/ydb/apps/ydb/ut/ydb-dump.cpp
+++ b/ydb/apps/ydb/ut/ydb-dump.cpp
@@ -9,19 +9,24 @@
 
 #include <ydb/public/api/protos/ydb_table.pb.h>
 
+#include <util/stream/file.h>
+#include <util/string/printf.h>
+
 Y_UNIT_TEST_SUITE(YdbDump) {
 
 Y_UNIT_TEST(NotNullTypeDump) {
+    const char* tableName = "TableWithNotNullTypeForDump";
     RunYdb({"-v", "yql", "-s",
-        R"(CREATE TABLE TableWithNotNullTypeForDump (
+        Sprintf(R"(CREATE TABLE %s (
             k Uint32 NOT NULL,
             v String NOT NULL,
             ov String,
             PRIMARY KEY(k));
-        )"},
+        )", tableName)},
         TList<TString>());
 
-    const TString output = RunYdb({"-v", "tools", "dump", "--scheme-only"}, TList<TString>());
+    const auto dumpPath = GetOutputPath() / "dump";
+    RunYdb({"-v", "tools", "dump", "--scheme-only", "--output", dumpPath.GetPath()}, TList<TString>());
 
     struct TFlags {
         const bool HasNullFlag;
@@ -35,6 +40,7 @@ Y_UNIT_TEST(NotNullTypeDump) {
         column_flags.emplace_back(TFlags{meta.has_not_null(), meta.type().has_optional_type()});
     };
 
+    const auto output = TFileInput(dumpPath / tableName / "scheme.pb").ReadAll();
     const TString token = "columns {";
     size_t start = 0;
     while (true) {
diff --git a/ydb/library/backup/backup.cpp b/ydb/library/backup/backup.cpp
index d869449c80..8998f62637 100644
--- a/ydb/library/backup/backup.cpp
+++ b/ydb/library/backup/backup.cpp
@@ -23,13 +23,13 @@
 #include <util/stream/mem.h>
 #include <util/stream/null.h>
 #include <util/string/builder.h>
+#include <util/string/join.h>
 #include <util/string/printf.h>
 #include <util/system/file.h>
 #include <util/system/fs.h>
 
 namespace NYdb::NBackup {
 
-
 static constexpr const char *SCHEME_FILE_NAME = "scheme.pb";
 static constexpr const char *PERMISSIONS_FILE_NAME = "permissions.pb";
 static constexpr const char *INCOMPLETE_DATA_FILE_NAME = "incomplete.csv";
@@ -46,19 +46,18 @@ static constexpr i64 READ_TABLE_RETRIES = 100;
 ////////////////////////////////////////////////////////////////////////////////
 
 void TYdbErrorException::LogToStderr() const {
-    LOG_ERR("Ydb error, status# " << Status.GetStatus());
-    if (what()) {
-        LOG_ERR("\t" << "What# " << what());
-    }
-    LOG_ERR("\t" << Status.GetIssues().ToString());
+    Cerr << Status;
 }
 
 static void VerifyStatus(TStatus status, TString explain = "") {
     if (status.IsSuccess()) {
         if (status.GetIssues()) {
-            LOG_DEBUG(status.GetIssues().ToString());
+            LOG_D(status);
         }
     } else {
+        if (explain) {
+            LOG_E(explain << ": " << status.GetIssues().ToOneLineString());
+        }
         throw TYdbErrorException(status) << explain;
     }
 }
@@ -256,7 +255,7 @@ static void Flush(TFile& tmpFile, TStringStream& ss, TMaybe<TValue>& lastWritten
 static void CloseAndRename(TFile& tmpFile, const TFsPath& fileName) {
     tmpFile.Close();
 
-    LOG_DEBUG("New file with data is created, fileName# " << fileName);
+    LOG_D("Write data into " << fileName.GetPath().Quote());
     TFsPath(tmpFile.GetName()).RenameTo(fileName);
 }
 
@@ -276,8 +275,7 @@ TMaybe<TValue> TryReadTable(TDriver driver, const NTable::TTableDescription& des
         if (result.IsSuccess()) {
             iter = result;
         }
-        VerifyStatus(result, TStringBuilder() << "ReadTable result was not successfull,"
-                " path: " << fullTablePath.Quote());
+        VerifyStatus(result, TStringBuilder() << "Read table " << fullTablePath.Quote() << " failed");
         return result;
     };
 
@@ -292,8 +290,7 @@ TMaybe<TValue> TryReadTable(TDriver driver, const NTable::TTableDescription& des
             TFile dataFile(folderPath.Child(CreateDataFileName((*fileCounter)++)), CreateAlways | WrOnly);
             return {};
         }
-        VerifyStatus(resultSetStreamPart, TStringBuilder() << "TStreamPart<TResultSet> is not successfull"
-                    " error msg: " << resultSetStreamPart.GetIssues().ToString());
+        VerifyStatus(resultSetStreamPart, TStringBuilder() << "Read next part of " << fullTablePath.Quote() << " failed");
         TResultSet resultSetCurrent = resultSetStreamPart.ExtractPart();
 
         auto tmpFile = TFile(folderPath.Child(INCOMPLETE_DATA_FILE_NAME), CreateAlways | WrOnly);
@@ -313,11 +310,10 @@ TMaybe<TValue> TryReadTable(TDriver driver, const NTable::TTableDescription& des
             if (resultSetCurrent.Truncated()) {
                 auto resultSetStreamPart = nextResult.ExtractValueSync();
                 if (!resultSetStreamPart.IsSuccess()) {
-                    LOG_DEBUG("resultSetStreamPart is not successful, EOS# "
-                        << (resultSetStreamPart.EOS() ? "true" : "false"));
                     if (resultSetStreamPart.EOS()) {
                         break;
                     } else {
+                        LOG_D("Stream was closed unexpectedly: " << resultSetStreamPart.GetIssues().ToOneLineString());
                         if (ss.Data()) {
                             Flush(tmpFile, ss, lastWrittenPK, lastReadPK);
                         }
@@ -346,11 +342,7 @@ TMaybe<TValue> TryReadTable(TDriver driver, const NTable::TTableDescription& des
 
 void ReadTable(TDriver driver, const NTable::TTableDescription& desc, const TString& fullTablePath,
         const TFsPath& folderPath, bool ordered) {
-    LOG_DEBUG("Going to ReadTable, fullPath: " << fullTablePath);
-
-    auto timer = GetVerbosity()
-        ? MakeHolder<TScopedTimer>(TStringBuilder() << "Done read table# " << fullTablePath.Quote() << " took# ")
-        : nullptr;
+    LOG_D("Read table " << fullTablePath.Quote());
 
     TMaybe<TValue> lastWrittenPK;
 
@@ -359,8 +351,7 @@ void ReadTable(TDriver driver, const NTable::TTableDescription& desc, const TStr
     do {
         lastWrittenPK = TryReadTable(driver, desc, fullTablePath, folderPath, lastWrittenPK, &fileCounter, ordered);
         if (lastWrittenPK && retries) {
-            LOG_DEBUG("ReadTable was not successfull, going to retry from lastWrittenPK# "
-                << FormatValueYson(*lastWrittenPK).Quote());
+            LOG_D("Retry read table from key: " << FormatValueYson(*lastWrittenPK).Quote());
         }
     } while (lastWrittenPK && retries--);
 
@@ -369,10 +360,11 @@ void ReadTable(TDriver driver, const NTable::TTableDescription& desc, const TStr
 }
 
 NTable::TTableDescription DescribeTable(TDriver driver, const TString& fullTablePath) {
+    LOG_D("Describe table " << fullTablePath.Quote());
+
     TMaybe<NTable::TTableDescription> desc;
 
     NTable::TTableClient client(driver);
-
     TStatus status = client.RetryOperationSync([fullTablePath, &desc](NTable::TSession session) {
         auto settings = NTable::TDescribeTableSettings().WithKeyShardBoundary(true).WithSetVal(true);
         auto result = session.DescribeTable(fullTablePath, settings).GetValueSync();
@@ -382,11 +374,7 @@ NTable::TTableDescription DescribeTable(TDriver driver, const TString& fullTable
         return result;
     });
     VerifyStatus(status);
-    LOG_DEBUG("Table is described, fullPath: " << fullTablePath);
 
-    for (auto& column : desc->GetColumns()) {
-        LOG_DEBUG("Column, name: " << column.Name << ", type: " << FormatType(column.Type));
-    }
     return *desc;
 }
 
@@ -436,60 +424,46 @@ NScheme::TSchemeEntry DescribePath(TDriver driver, const TString& fullPath) {
     
     auto status = NDump::DescribePath(client, fullPath);
     VerifyStatus(status);
-    LOG_DEBUG("Path is described, fullPath: " << fullPath);
 
     return status.GetEntry();
 }
 
 TAsyncStatus CopyTableAsyncStart(TDriver driver, const TString& src, const TString& dst) {
-    NTable::TTableClient client(driver);
+    LOG_I("Copy table " << src.Quote() << " to " << dst.Quote());
 
+    NTable::TTableClient client(driver);
     return client.RetryOperation([src, dst](NTable::TSession session) {
         auto result = session.CopyTable(src, dst);
-
         return result;
     });
 }
 
-void CopyTableAsyncFinish(const TAsyncStatus& status, const TString& src, const TString& dst) {
-    VerifyStatus(status.GetValueSync(), TStringBuilder() << "CopyTable, src: " << src.Quote() << " dst: " << dst.Quote());
-    LOG_DEBUG("Table is copied, src: " << src.Quote() << " dst: " << dst.Quote());
+void CopyTableAsyncFinish(const TAsyncStatus& status, const TString& src) {
+    VerifyStatus(status.GetValueSync(), TStringBuilder() << "Copy table " << src.Quote() << " failed");
 }
 
 void CopyTables(TDriver driver, const TVector<NTable::TCopyItem>& tablesToCopy) {
-    NTable::TTableClient client(driver);
+    LOG_I("Copy tables: " << JoinSeq(", ", tablesToCopy));
 
+    NTable::TTableClient client(driver);
     TStatus status = client.RetryOperationSync([&tablesToCopy](NTable::TSession session) {
         auto result = session.CopyTables(tablesToCopy).GetValueSync();
-
         return result;
     });
 
-    // Debug print
-    TStringStream tablesStr;
-    bool needsComma = false;
-    for (const auto& copyItem : tablesToCopy) {
-        if (needsComma) {
-            tablesStr << ", ";
-        } else {
-            needsComma = true;
-        }
-        tablesStr << "{ src# " << copyItem.SourcePath() << ", dst# " << copyItem.DestinationPath().Quote() << "}";
-    }
-
-    VerifyStatus(status, TStringBuilder() << "CopyTables error, tables to be copied# " << tablesStr.Str());
-    LOG_DEBUG("Tables are copied, " << tablesStr.Str());
+    VerifyStatus(status, "Copy tables failed");
 }
 
 void DropTable(TDriver driver, const TString& path) {
+    LOG_D("Drop table " << path.Quote());
+
     NTable::TTableClient client(driver);
     TStatus status = client.RetryOperationSync([path](NTable::TSession session) {
         auto result = session.DropTable(path).GetValueSync();
-
         return result;
     });
-    VerifyStatus(status, TStringBuilder() << "DropTable, path" << path.Quote());
-    LOG_DEBUG("Table is dropped, path: " << path.Quote());
+
+    VerifyStatus(status, TStringBuilder() << "Drop table " << path.Quote() << " failed");
 }
 
 void BackupPermissions(TDriver driver, const TString& dbPrefix, const TString& path, const TFsPath& folderPath) {
@@ -499,7 +473,7 @@ void BackupPermissions(TDriver driver, const TString& dbPrefix, const TString& p
 
     TString permissionsStr;
     google::protobuf::TextFormat::PrintToString(proto, &permissionsStr);
-    LOG_DEBUG("ModifyPermissionsRequest.proto: " << permissionsStr);
+    LOG_D("Write ACL into " << folderPath.Child(PERMISSIONS_FILE_NAME).GetPath().Quote());
 
     TFile outFile(folderPath.Child(PERMISSIONS_FILE_NAME), CreateAlways | WrOnly);
     outFile.Write(permissionsStr.data(), permissionsStr.size());
@@ -510,47 +484,50 @@ void BackupTable(TDriver driver, const TString& dbPrefix, const TString& backupP
     Y_ENSURE(!path.empty());
     Y_ENSURE(path.back() != '/', path.Quote() << " path contains / in the end");
 
-    LOG_DEBUG("Going to backup table, dbPrefix: " << dbPrefix
-        << " backupPrefix: " << backupPrefix << " path: " << path);
+    const auto fullPath = JoinDatabasePath(schemaOnly ? dbPrefix : backupPrefix, path);
 
-    auto desc = DescribeTable(driver, JoinDatabasePath(schemaOnly ? dbPrefix : backupPrefix, path));
+    LOG_I("Backup table " << fullPath.Quote() << " to " << folderPath.GetPath().Quote());
 
+    auto desc = DescribeTable(driver, fullPath);
     auto proto = ProtoFromTableDescription(desc, preservePoolKinds);
 
     TString schemaStr;
     google::protobuf::TextFormat::PrintToString(proto, &schemaStr);
-    LOG_DEBUG("CreateTableRequest.proto: " << schemaStr);
+    LOG_D("Write scheme into " << folderPath.Child(SCHEME_FILE_NAME).GetPath().Quote());
     TFile outFile(folderPath.Child(SCHEME_FILE_NAME), CreateAlways | WrOnly);
     outFile.Write(schemaStr.data(), schemaStr.size());
 
     BackupPermissions(driver, dbPrefix, path, folderPath);
 
     if (!schemaOnly) {
-        const TString pathToTemporal = JoinDatabasePath(backupPrefix, path);
-        ReadTable(driver, desc, pathToTemporal, folderPath, ordered);
+        ReadTable(driver, desc, fullPath, folderPath, ordered);
     }
 }
 
-void CreateClusterDirectory(const TDriver& driver, const TString& path) {
+void CreateClusterDirectory(const TDriver& driver, const TString& path, bool rootBackupDir = false) {
+    if (rootBackupDir) {
+        LOG_I("Create temporary directory " << path.Quote());
+    } else {
+        LOG_D("Create directory " << path.Quote());
+    }
     NScheme::TSchemeClient client(driver);
     TStatus status = client.MakeDirectory(path).GetValueSync();
-    VerifyStatus(status, TStringBuilder() << "MakeDirectory, path: " << path.Quote());
-    LOG_DEBUG("Directory is created, path: " << path.Quote());
+    VerifyStatus(status, TStringBuilder() << "Create directory " << path.Quote() << " failed");
 }
 
 void RemoveClusterDirectory(const TDriver& driver, const TString& path) {
+    LOG_D("Remove directory " << path.Quote());
     NScheme::TSchemeClient client(driver);
     TStatus status = client.RemoveDirectory(path).GetValueSync();
-    VerifyStatus(status, TStringBuilder() << "RemoveDirectory, path: " << path.Quote());
-    LOG_DEBUG("Directory is removed, path: " << path.Quote());
+    VerifyStatus(status, TStringBuilder() << "Remove directory " << path.Quote() << " failed");
 }
 
 void RemoveClusterDirectoryRecursive(const TDriver& driver, const TString& path) {
+    LOG_I("Remove temporary directory " << path.Quote());
     NScheme::TSchemeClient schemeClient(driver);
     NTable::TTableClient tableClient(driver);
     TStatus status = NConsoleClient::RemoveDirectoryRecursive(schemeClient, tableClient, path, {}, true, false);
-    VerifyStatus(status, TStringBuilder() << "RemoveDirectoryRecursive, path: " << path.Quote());
-    LOG_DEBUG("Directory is removed recursively, path: " << path.Quote());
+    VerifyStatus(status, TStringBuilder() << "Remove temporary directory " << path.Quote() << " failed");
 }
 
 static bool IsExcluded(const TString& path, const TVector<TRegExMatch>& exclusionPatterns) {
@@ -571,10 +548,9 @@ static void MaybeCreateEmptyFile(const TFsPath& folderPath) {
     }
 }
 
-void BackupFolderImpl(TDriver driver, const TString& dbPrefix, const TString& backupPrefix, TString path,
+void BackupFolderImpl(TDriver driver, const TString& dbPrefix, const TString& backupPrefix,
         const TFsPath folderPath, const TVector<TRegExMatch>& exclusionPatterns,
         bool schemaOnly, bool useConsistentCopyTable, bool avoidCopy, bool preservePoolKinds, bool ordered) {
-    LOG_DEBUG("Going to backup folder/table, dbPrefix: " << dbPrefix << " path: " << path);
     TFile(folderPath.Child(INCOMPLETE_FILE_NAME), CreateAlways);
 
     TMap<TString, TAsyncStatus> copiedTablesStatuses;
@@ -584,13 +560,13 @@ void BackupFolderImpl(TDriver driver, const TString& dbPrefix, const TString& ba
         TDbIterator<ETraverseType::Preordering> dbIt(driver, dbPrefix);
         while (dbIt) {
             if (IsExcluded(dbIt.GetFullPath(), exclusionPatterns)) {
-                LOG_DEBUG("skip path# " << dbIt.GetFullPath());
+                LOG_D("Skip " << dbIt.GetFullPath().Quote());
                 dbIt.Next();
                 continue;
             }
 
             TFsPath childFolderPath = folderPath.Child(dbIt.GetRelPath());
-            LOG_DEBUG("path to backup# " << childFolderPath.GetPath());
+            LOG_D("Process " << childFolderPath.GetPath().Quote());
             childFolderPath.MkDir();
             TFile(childFolderPath.Child(INCOMPLETE_FILE_NAME), CreateAlways).Close();
             if (schemaOnly) {
@@ -620,6 +596,7 @@ void BackupFolderImpl(TDriver driver, const TString& dbPrefix, const TString& ba
         TDbIterator<ETraverseType::Postordering> dbIt(driver, dbPrefix);
         while (dbIt) {
             if (IsExcluded(dbIt.GetFullPath(), exclusionPatterns)) {
+                LOG_D("Skip " << dbIt.GetFullPath().Quote());
                 dbIt.Next();
                 continue;
             }
@@ -649,6 +626,7 @@ void BackupFolderImpl(TDriver driver, const TString& dbPrefix, const TString& ba
         TDbIterator<ETraverseType::Postordering> dbIt(driver, dbPrefix);
         while (dbIt) {
             if (IsExcluded(dbIt.GetFullPath(), exclusionPatterns)) {
+                LOG_D("Skip " << dbIt.GetFullPath().Quote());
                 dbIt.Next();
                 continue;
             }
@@ -658,10 +636,9 @@ void BackupFolderImpl(TDriver driver, const TString& dbPrefix, const TString& ba
 
             if (dbIt.IsTable()) {
                 if (!useConsistentCopyTable && !avoidCopy) {
-                    // CopyTableAsyncFinish(const TAsyncStatus& status, const TString& src, const TString& dst);
                     Y_ENSURE(copiedTablesStatuses.contains(dbIt.GetFullPath()),
                             "Table was not copied but going to be backuped, path# " << dbIt.GetFullPath().Quote());
-                    CopyTableAsyncFinish(copiedTablesStatuses[dbIt.GetFullPath()], dbIt.GetFullPath(), tmpTablePath);
+                    CopyTableAsyncFinish(copiedTablesStatuses[dbIt.GetFullPath()], dbIt.GetFullPath());
                     copiedTablesStatuses.erase(dbIt.GetFullPath());
                 }
                 BackupTable(driver, dbIt.GetTraverseRoot(), avoidCopy ? dbIt.GetTraverseRoot() : backupPrefix, dbIt.GetRelPath(),
@@ -696,7 +673,6 @@ void CheckedCreateBackupFolder(const TFsPath& folderPath) {
     } else {
         folderPath.MkDir();
     }
-    LOG_DEBUG("Going to backup into folder: " << folderPath.RealPath().GetPath().Quote());
 }
 
 // relDbPath - relative path to directory/table to be backuped
@@ -710,33 +686,39 @@ void BackupFolder(TDriver driver, const TString& database, const TString& relDbP
     }
     CheckedCreateBackupFolder(folderPath);
 
+    TString dbPrefix = JoinDatabasePath(database, relDbPath);
+    LOG_I("Backup " << dbPrefix.Quote() << " to " << folderPath.GetPath().Quote());
+
     // full path to temporal directory in database
     TString tmpDbFolder;
     try {
         if (!schemaOnly && !avoidCopy) {
             // Create temporal folder in database's root directory
             tmpDbFolder = JoinDatabasePath(database, "~" + temporalBackupPostfix);
-            CreateClusterDirectory(driver, tmpDbFolder);
+            CreateClusterDirectory(driver, tmpDbFolder, true);
         }
 
-        TString dbPrefix = JoinDatabasePath(database, relDbPath);
-        TString path;
-        BackupFolderImpl(driver, dbPrefix, tmpDbFolder, path, folderPath, exclusionPatterns,
+        BackupFolderImpl(driver, dbPrefix, tmpDbFolder, folderPath, exclusionPatterns,
             schemaOnly, useConsistentCopyTable, avoidCopy, preservePoolKinds, ordered);
     } catch (...) {
         if (!schemaOnly && !avoidCopy) {
             RemoveClusterDirectoryRecursive(driver, tmpDbFolder);
         }
 
+        LOG_E("Backup failed");
         // delete partial backup (or save)
         if (!savePartialResult) {
             folderPath.ForceDelete();
+        } else {
+            LOG_I("Partial result saved");
         }
+
         throw;
     }
     if (!schemaOnly && !avoidCopy) {
         RemoveClusterDirectoryRecursive(driver, tmpDbFolder);
     }
+    LOG_I("Backup completed successfully");
 }
 
 ////////////////////////////////////////////////////////////////////////////////
@@ -795,11 +777,11 @@ NTable::TTableDescription TableDescriptionFromProto(const Ydb::Table::CreateTabl
             }
             sequenceDescription = std::move(currentSequenceDescription);
         }
-        LOG_DEBUG("AddColumn: " << ProcessColumnType(col.Getname(), TType(col.Gettype()), &builder, std::move(sequenceDescription)));
+        LOG_D("AddColumn: " << ProcessColumnType(col.Getname(), TType(col.Gettype()), &builder, std::move(sequenceDescription)));
     }
 
     for (const auto &primary : proto.Getprimary_key()) {
-       LOG_DEBUG("SetPrimaryKeyColumn: name: " << primary);
+       LOG_D("SetPrimaryKeyColumn: name: " << primary);
     }
     builder.SetPrimaryKeyColumns({proto.Getprimary_key().cbegin(), proto.Getprimary_key().cend()});
 
@@ -834,13 +816,13 @@ void CheckTableDescriptionIsSame(const NTable::TTableDescription& backupDesc,
         const NTable::TTableDescription& realDesc) {
     if (backupDesc.GetColumns() != realDesc.GetColumns() ||
             backupDesc.GetPrimaryKeyColumns() != realDesc.GetPrimaryKeyColumns()) {
-        LOG_ERR("Error");
-        LOG_ERR("Table scheme from backup:");
-        LOG_ERR(SerializeColumnsToString(backupDesc.GetColumns(), backupDesc.GetPrimaryKeyColumns()));
-        LOG_ERR("Table scheme from database:");
-        LOG_ERR(SerializeColumnsToString(realDesc.GetColumns(), realDesc.GetPrimaryKeyColumns()));
+        LOG_E("Error");
+        LOG_E("Table scheme from backup:");
+        LOG_E(SerializeColumnsToString(backupDesc.GetColumns(), backupDesc.GetPrimaryKeyColumns()));
+        LOG_E("Table scheme from database:");
+        LOG_E(SerializeColumnsToString(realDesc.GetColumns(), realDesc.GetPrimaryKeyColumns()));
     } else {
-        LOG_ERR("Ok");
+        LOG_E("Ok");
     }
 }
 
@@ -852,16 +834,16 @@ void UploadDataIntoTable(TDriver driver, const NTable::TTableDescription& tableD
     TFsPath dataFileName = folderPath.Child(CreateDataFileName(fileCounter++));
 
     if (params.UseBulkUpsert) {
-        LOG_DEBUG("Going to BulkUpsert into table# " << absPath.Quote());
+        LOG_D("Going to BulkUpsert into table# " << absPath.Quote());
     }
     while (dataFileName.Exists()) {
-        LOG_DEBUG("Going to read new data file, fileName# " << dataFileName);
+        LOG_D("Going to read new data file, fileName# " << dataFileName);
 
 
         TUploader::TOptions opts;
         if (params.UploadBandwidthBPS) {
             opts.Rate = (opts.Interval.Seconds() * params.UploadBandwidthBPS + IO_BUFFER_SIZE - 1) / IO_BUFFER_SIZE;
-            LOG_DEBUG("Custom bandwidth limit is specified, will use bandwidth# "
+            LOG_D("Custom bandwidth limit is specified, will use bandwidth# "
                 << HumanReadableSize(params.UploadBandwidthBPS, SF_BYTES) << "B/s"
                 << " RPS# " << double(opts.Rate) / opts.Interval.Seconds() << " reqs/s"
                 << " IO buffer size# " << HumanReadableSize(IO_BUFFER_SIZE, SF_BYTES));
@@ -876,7 +858,7 @@ void UploadDataIntoTable(TDriver driver, const NTable::TTableDescription& tableD
         NTable::TTableClient client(driver);
         TUploader uploader(opts, client, it.GetQueryString());
         if (!params.UseBulkUpsert) {
-            LOG_DEBUG("Query string:\n" << it.GetQueryString());
+            LOG_D("Query string:\n" << it.GetQueryString());
         }
 
         while (!it.Empty()) {
@@ -901,26 +883,23 @@ void RestoreTable(TDriver driver, const TString& database, const TString& prefix
 
     const TString relPath = JoinDatabasePath(prefix, folderPath.GetName());
     const TString absPath = JoinDatabasePath(database, relPath);
-    LOG_DEBUG("Restore table from folder: " << folderPath << " in database path# " << absPath.Quote());
+    LOG_D("Restore table from folder: " << folderPath << " in database path# " << absPath.Quote());
 
     NTable::TTableDescription tableDesc = TableDescriptionFromFile(folderPath.Child(SCHEME_FILE_NAME));
 
 
     if (params.OnlyCheck) {
-        LOG_ERR("Check table: " << absPath.Quote() << "...");
+        LOG_E("Check table: " << absPath.Quote() << "...");
         NTable::TTableDescription tableDescReal = DescribeTable(driver, absPath);
         CheckTableDescriptionIsSame(tableDesc, tableDescReal);
     } else {
-        auto timer = GetVerbosity()
-            ? MakeHolder<TScopedTimer>(TStringBuilder() << "Done restore table# " << absPath.Quote() << " took# ")
-            : nullptr;
         // Create Table
         TStatus status = client.RetryOperationSync([absPath, &tableDesc](NTable::TSession session) {
             auto result = session.CreateTable(absPath, std::move(tableDesc)).GetValueSync();
             return result;
         });
         VerifyStatus(status, TStringBuilder() << "CreateTable on path: " << absPath.Quote());
-        LOG_DEBUG("Table is created, path: " << absPath.Quote());
+        LOG_D("Table is created, path: " << absPath.Quote());
         if (!params.SchemaOnly) {
             UploadDataIntoTable(driver, tableDesc, relPath, absPath, folderPath, params);
         }
@@ -929,14 +908,14 @@ void RestoreTable(TDriver driver, const TString& database, const TString& prefix
 
 void RestoreFolderImpl(TDriver driver, const TString& database, const TString& prefix, TFsPath folderPath,
         const TRestoreFolderParams& params) {
-    LOG_DEBUG("Restore folder: " << folderPath);
+    LOG_D("Restore folder: " << folderPath);
     Y_ENSURE(folderPath, "folderPath cannot be empty on restore, please specify path to folder containing backup");
     Y_ENSURE(folderPath.IsDirectory(), "Specified folderPath " << folderPath.GetPath().Quote() << " must be a folder");
     Y_ENSURE(!folderPath.Child(INCOMPLETE_FILE_NAME).Exists(),
             "There is incomplete file in folder, path# " << TString(folderPath).Quote());
 
     if (prefix != "/" && !params.OnlyCheck) {
-        LOG_DEBUG("Create prefix folder: " << prefix);
+        LOG_D("Create prefix folder: " << prefix);
         NScheme::TSchemeClient client(driver);
         TString path = JoinDatabasePath(database, prefix);
         TStatus status = client.MakeDirectory(path).GetValueSync();
@@ -985,7 +964,7 @@ void CheckTablesAbsence(NScheme::TSchemeClient client, const TString& database,
     if (isTable) {
         Y_ENSURE(!IsNamePresentedInDir(listResult, name), "Table with name# " << name.Quote()
                 << " is presented in path# " << path.Quote());
-        LOG_DEBUG("\tOk! Table " << name.Quote() << " is absent in database path# " << path.Quote());
+        LOG_D("\tOk! Table " << name.Quote() << " is absent in database path# " << path.Quote());
     } else {
         TVector<TFsPath> children;
         folderPath.List(children);
@@ -996,15 +975,15 @@ void CheckTablesAbsence(NScheme::TSchemeClient client, const TString& database,
             if (isChildTable) {
                 Y_ENSURE(!isChildPresented, "Table with name# " << childName.Quote()
                         << " is presented in path# " << path.Quote());
-                LOG_DEBUG("\tOk! Table " << childName.Quote() << " is absent in database path# "
+                LOG_D("\tOk! Table " << childName.Quote() << " is absent in database path# "
                     << path.Quote());
             } else {
                 if (isChildPresented) {
-                    LOG_DEBUG("\tOk! Directory " << childName.Quote() << " is presented in database path# "
+                    LOG_D("\tOk! Directory " << childName.Quote() << " is presented in database path# "
                         << path.Quote() << ", so check tables in that dir");
                     CheckTablesAbsence(client, database, JoinDatabasePath(prefix, child.GetName()), child);
                 } else {
-                    LOG_DEBUG("\tOk! Directory " << childName.Quote() << " is absent in database path# "
+                    LOG_D("\tOk! Directory " << childName.Quote() << " is absent in database path# "
                         << path.Quote());
                 }
             }
@@ -1018,23 +997,23 @@ void RestoreFolder(TDriver driver, const TString& database, const TString& prefi
     Y_ENSURE(prefix, "restore prefix cannot be empty, database# " << database.Quote() << " prefix# " << prefix.Quote());
 
     if (params.CheckTablesAbsence && !params.OnlyCheck) {
-        LOG_DEBUG("Check absence of tables to be restored");
+        LOG_D("Check absence of tables to be restored");
         if (prefix != "/") {
             TString path = JoinDatabasePath(database, prefix);
             TString parent = ParentPathFromDbPath(path);
             TString name = NameFromDbPath(path);
-            LOG_DEBUG("Going to list parent# " << parent.Quote() << " for path path# " << path.Quote());
+            LOG_D("Going to list parent# " << parent.Quote() << " for path path# " << path.Quote());
             NScheme::TListDirectoryResult listResult = client.ListDirectory(parent).GetValueSync();
             VerifyStatus(listResult, TStringBuilder() << "ListDirectory, path# " << parent.Quote());
             if (IsNamePresentedInDir(listResult, name)) {
                 CheckTablesAbsence(client, database, prefix, folderPath);
             } else {
-                LOG_DEBUG("\tOk! restore directory# " << path.Quote() << " is absent in database");
+                LOG_D("\tOk! restore directory# " << path.Quote() << " is absent in database");
             }
         } else {
             CheckTablesAbsence(client, database, prefix, folderPath);
         }
-        LOG_DEBUG("Check done, everything is Ok");
+        LOG_D("Check done, everything is Ok");
     }
     RestoreFolderImpl(driver, database, prefix, folderPath, params);
 }
diff --git a/ydb/library/backup/backup.h b/ydb/library/backup/backup.h
index 82726713b3..a2c15f5ccf 100644
--- a/ydb/library/backup/backup.h
+++ b/ydb/library/backup/backup.h
@@ -7,7 +7,6 @@
 #include <library/cpp/regex/pcre/regexp.h>
 
 #include <util/folder/path.h>
-#include <util/generic/singleton.h>
 #include <util/stream/output.h>
 #include <util/system/file.h>
 
diff --git a/ydb/library/backup/query_uploader.cpp b/ydb/library/backup/query_uploader.cpp
index 77dfc593ec..feec91265b 100644
--- a/ydb/library/backup/query_uploader.cpp
+++ b/ydb/library/backup/query_uploader.cpp
@@ -1,5 +1,3 @@
-#include <util/datetime/cputimer.h>
-
 #include "query_uploader.h"
 #include "util.h"
 
@@ -62,17 +60,12 @@ bool TUploader::Push(const TString& path, TValue&& value) {
 
             if (status.IsSuccess()) {
                 if (status.GetIssues()) {
-                    LOG_ERR("BulkUpsert has finished successfull, but has issues# {"
-                            << status.GetIssues().ToString() << "}");
+                    LOG_W("Bulk upsert was completed with issues: " << status.GetIssues().ToOneLineString());
                 }
                 return;
             // Since upsert of data is an idempotent operation it is possible to retry transport errors
             } else if (status.IsTransportError() && retry < Opts.TransportErrorsMaxRetries) {
-                LOG_DEBUG("Notice: transport error in BulkUpsert, issues# {" << status.GetIssues().ToString() << "}"
-                        << " current Retry is " << retry
-                        << " < MaxRetries# " << Opts.TransportErrorsMaxRetries
-                        << ", so sleep for " << retrySleep.Seconds() << "s"
-                        << " and try again");
+                LOG_D("Retry bulk upsert: " << status.GetIssues().ToOneLineString());
                 ++retry;
                 TInstant deadline = retrySleep.ToDeadLine();
                 while (TInstant::Now() < deadline) {
@@ -84,9 +77,7 @@ bool TUploader::Push(const TString& path, TValue&& value) {
                 retrySleep *= 2;
                 continue;
             } else {
-                LOG_ERR("Error in BulkUpsert, so stop working. Issues# {" << status.GetIssues().ToString() << "}"
-                        << " IsTransportError# " << (status.IsTransportError() ? "true" : "false")
-                        << " retries done# " << retry);
+                LOG_E("Bulk upsert failed: " << status.GetIssues().ToOneLineString());
                 PleaseStop();
                 return;
             }
@@ -136,11 +127,10 @@ bool TUploader::Push(TParams params) {
 
         if (status.IsSuccess()) {
             if (status.GetIssues()) {
-                LOG_ERR("Upload tx has finished successfull, but has issues# {"
-                    << status.GetIssues().ToString() << "}");
+                LOG_W("Write tx was completed with issues: " << status.GetIssues().ToOneLineString());
             }
         } else {
-            LOG_ERR("Error in upload tx, issues# {" << status.GetIssues().ToString() << "}");
+            LOG_E("Write tx failed: " << status.GetIssues().ToOneLineString());
             PleaseStop();
             return;
         }
diff --git a/ydb/library/backup/util.cpp b/ydb/library/backup/util.cpp
index 230b8f39ae..1f226934b2 100644
--- a/ydb/library/backup/util.cpp
+++ b/ydb/library/backup/util.cpp
@@ -1,15 +1,35 @@
 #include "util.h"
 
-#include <util/generic/yexception.h>
-#include <util/string/builder.h>
-#include <util/string/cast.h>
 #include <util/generic/map.h>
+#include <util/generic/singleton.h>
+#include <util/generic/yexception.h>
 #include <util/generic/ymath.h>
+#include <util/string/cast.h>
 
 #include <ctype.h>
 
 namespace NYdb {
 
+namespace NBackup {
+
+struct TLog {
+    std::shared_ptr<::TLog> Log;
+
+    TLog()
+        : Log(std::make_shared<::TLog>(CreateLogBackend("cerr")))
+    {}
+};
+
+void SetLog(std::shared_ptr<::TLog>&& log) {
+    Singleton<TLog>()->Log = std::move(log);
+}
+
+std::shared_ptr<::TLog>& GetLog() {
+    return Singleton<TLog>()->Log;
+}
+
+} // NBackup
+
 TString RelPathFromAbsolute(TString db, TString path) {
     if (!db.StartsWith('/')) {
         db.prepend('/');
@@ -77,21 +97,4 @@ ui64 SizeFromString(TStringBuf s) {
     return FromString<ui64>(number) * it->second;
 }
 
-namespace {
-
-struct TIsVerbosePrint {
-    bool IsVerbose = false;
-};
-
-}
-
-void SetVerbosity(bool isVerbose) {
-    Singleton<TIsVerbosePrint>()->IsVerbose = isVerbose;
-}
-
-bool GetVerbosity() {
-    return Singleton<TIsVerbosePrint>()->IsVerbose;
-}
-
-
 }
diff --git a/ydb/library/backup/util.h b/ydb/library/backup/util.h
index 607e84d2bc..09b8d33c98 100644
--- a/ydb/library/backup/util.h
+++ b/ydb/library/backup/util.h
@@ -1,23 +1,26 @@
 #pragma once
 
-#include <util/datetime/base.h>
-#include <util/generic/string.h>
-#include <util/stream/output.h>
-#include <util/stream/null.h>
+#include <library/cpp/logger/log.h>
 
-namespace NYdb {
-
-void SetVerbosity(bool isVerbose);
-bool GetVerbosity();
+#include <util/string/builder.h>
 
-#define LOG_NULL(s) Cnull << s
-#define EXTEND_MSG(s) TInstant::Now().ToIsoStringLocal() << ": " << s << Endl
+#define LOG_IMPL(log, level, message) \
+    if (log->FiltrationLevel() >= level) { \
+        log->Write(level, TStringBuilder() << message); \
+    } \
+    Y_SEMICOLON_GUARD
 
-#define LOG_INFO(s) Cout << EXTEND_MSG(s)
-#define LOG_ERR(s) Cerr << EXTEND_MSG(s)
-#define LOG_DEBUG(s) (NYdb::GetVerbosity() ? LOG_INFO(s) : LOG_NULL(s))
+#define LOG_D(message) LOG_IMPL(NYdb::NBackup::GetLog(), ELogPriority::TLOG_DEBUG, message)
+#define LOG_I(message) LOG_IMPL(NYdb::NBackup::GetLog(), ELogPriority::TLOG_INFO, message)
+#define LOG_W(message) LOG_IMPL(NYdb::NBackup::GetLog(), ELogPriority::TLOG_WARNING, message)
+#define LOG_E(message) LOG_IMPL(NYdb::NBackup::GetLog(), ELogPriority::TLOG_ERR, message)
 
+namespace NYdb {
 
+namespace NBackup {
+    void SetLog(std::shared_ptr<::TLog>&& log);
+    std::shared_ptr<::TLog>& GetLog();
+}
 
 // Retrive path relative to database root from absolute
 TString RelPathFromAbsolute(TString db, TString path);
@@ -28,19 +31,4 @@ TString RelPathFromAbsolute(TString db, TString path);
 // Example: "2Ki" -> 2048
 ui64 SizeFromString(TStringBuf s);
 
-class TScopedTimer {
-    TInstant Start;
-    TString Msg;
-
-public:
-    TScopedTimer(const TString& msg)
-        : Start(TInstant::Now())
-        , Msg(msg)
-    {}
-
-    ~TScopedTimer() {
-        LOG_INFO(Msg << (TInstant::Now() - Start).SecondsFloat() << "s");
-    }
-};
-
 }
diff --git a/ydb/library/backup/ya.make b/ydb/library/backup/ya.make
index 4ee9eac0dc..945c042c4d 100644
--- a/ydb/library/backup/ya.make
+++ b/ydb/library/backup/ya.make
@@ -2,6 +2,7 @@ LIBRARY(kikimr_backup)
 
 PEERDIR(
     library/cpp/bucket_quoter
+    library/cpp/logger
     library/cpp/regex/pcre
     library/cpp/string_utils/quote
     util
diff --git a/ydb/public/lib/ydb_cli/commands/ydb_tools.cpp b/ydb/public/lib/ydb_cli/commands/ydb_tools.cpp
index 742c1a9d2f..1b67718ed5 100644
--- a/ydb/public/lib/ydb_cli/commands/ydb_tools.cpp
+++ b/ydb/public/lib/ydb_cli/commands/ydb_tools.cpp
@@ -1,5 +1,9 @@
 #include "ydb_tools.h"
 
+#define INCLUDE_YDB_INTERNAL_H
+#include <ydb/public/sdk/cpp/client/impl/ydb_internal/logger/log.h>
+#undef INCLUDE_YDB_INTERNAL_H
+
 #include <ydb/public/lib/ydb_cli/common/normalize_path.h>
 #include <ydb/public/lib/ydb_cli/common/pg_dump_parser.h>
 #include <ydb/public/lib/ydb_cli/dump/dump.h>
@@ -94,7 +98,9 @@ int TCommandDump::Run(TConfig& config) {
         throw yexception() << "Incorrect consistency level. Available options: \"database\", \"table\"" << Endl;
     }
 
-    NYdb::SetVerbosity(config.IsVerbose());
+    auto log = std::make_shared<TLog>(CreateLogBackend("cerr", TConfig::VerbosityLevelToELogPriority(config.VerbosityLevel)));
+    log->SetFormatter(GetPrefixLogFormatter(""));
+    NYdb::NBackup::SetLog(std::move(log));
 
     try {
         TString relPath = NYdb::RelPathFromAbsolute(config.Database, Path);
@@ -196,8 +202,6 @@ void TCommandRestore::Parse(TConfig& config) {
 }
 
 int TCommandRestore::Run(TConfig& config) {
-    NYdb::SetVerbosity(config.IsVerbose());
-
     auto settings = NDump::TRestoreSettings()
         .DryRun(IsDryRun)
         .RestoreData(RestoreData)
@@ -234,7 +238,10 @@ int TCommandRestore::Run(TConfig& config) {
         settings.Mode(NDump::TRestoreSettings::EMode::ImportData);
     }
 
-    NDump::TClient client(CreateDriver(config));
+    auto log = std::make_shared<TLog>(CreateLogBackend("cerr", TConfig::VerbosityLevelToELogPriority(config.VerbosityLevel)));
+    log->SetFormatter(GetPrefixLogFormatter(""));
+
+    NDump::TClient client(CreateDriver(config), std::move(log));
     ThrowOnError(client.Restore(FilePath, Path, settings));
 
     return EXIT_SUCCESS;
diff --git a/ydb/public/lib/ydb_cli/dump/dump.cpp b/ydb/public/lib/ydb_cli/dump/dump.cpp
index ba421237b7..024844dc1b 100644
--- a/ydb/public/lib/ydb_cli/dump/dump.cpp
+++ b/ydb/public/lib/ydb_cli/dump/dump.cpp
@@ -7,6 +7,8 @@
 #include <ydb/public/sdk/cpp/client/ydb_scheme/scheme.h>
 #include <ydb/public/sdk/cpp/client/ydb_table/table.h>
 
+#include <library/cpp/logger/log.h>
+
 #include <util/string/printf.h>
 
 namespace NYdb {
@@ -23,8 +25,9 @@ TString DataFileName(ui32 id) {
 
 class TClient::TImpl {
 public:
-    explicit TImpl(const TDriver& driver)
-        : ImportClient(driver)
+    explicit TImpl(const TDriver& driver, std::shared_ptr<TLog>&& log)
+        : Log(log)
+        , ImportClient(driver)
         , OperationClient(driver)
         , SchemeClient(driver)
         , TableClient(driver)
@@ -37,11 +40,12 @@ public:
     }
 
     TRestoreResult Restore(const TString& fsPath, const TString& dbPath, const TRestoreSettings& settings) {
-        auto client = TRestoreClient(ImportClient, OperationClient, SchemeClient, TableClient);
+        auto client = TRestoreClient(*Log, ImportClient, OperationClient, SchemeClient, TableClient);
         return client.Restore(fsPath, dbPath, settings);
     }
 
 private:
+    std::shared_ptr<TLog> Log;
     NImport::TImportClient ImportClient;
     NOperation::TOperationClient OperationClient;
     NScheme::TSchemeClient SchemeClient;
@@ -60,7 +64,12 @@ TRestoreResult::TRestoreResult(TStatus&& status)
 }
 
 TClient::TClient(const TDriver& driver)
-    : Impl_(new TImpl(driver))
+    : Impl_(new TImpl(driver, std::make_shared<TLog>(CreateLogBackend("cerr"))))
+{
+}
+
+TClient::TClient(const TDriver& driver, std::shared_ptr<TLog>&& log)
+    : Impl_(new TImpl(driver, std::move(log)))
 {
 }
 
diff --git a/ydb/public/lib/ydb_cli/dump/dump.h b/ydb/public/lib/ydb_cli/dump/dump.h
index 4f4dba4c2b..e3df0d739a 100644
--- a/ydb/public/lib/ydb_cli/dump/dump.h
+++ b/ydb/public/lib/ydb_cli/dump/dump.h
@@ -6,6 +6,8 @@
 
 #include <util/generic/size_literals.h>
 
+class TLog;
+
 namespace NYdb {
 namespace NDump {
 
@@ -92,6 +94,7 @@ private:
 
 public:
     explicit TClient(const TDriver& driver);
+    explicit TClient(const TDriver& driver, std::shared_ptr<TLog>&& log);
 
     TDumpResult Dump(const TString& dbPath, const TString& fsPath, const TDumpSettings& settings = {});
     TRestoreResult Restore(const TString& fsPath, const TString& dbPath, const TRestoreSettings& settings = {});
diff --git a/ydb/public/lib/ydb_cli/dump/restore_impl.cpp b/ydb/public/lib/ydb_cli/dump/restore_impl.cpp
index 8873e82d7d..734826f0d5 100644
--- a/ydb/public/lib/ydb_cli/dump/restore_impl.cpp
+++ b/ydb/public/lib/ydb_cli/dump/restore_impl.cpp
@@ -9,6 +9,8 @@
 #include <ydb/public/lib/ydb_cli/common/retry_func.h>
 #include <ydb/public/lib/ydb_cli/dump/util/util.h>
 
+#include <library/cpp/logger/log.h>
+
 #include <util/generic/hash.h>
 #include <util/generic/hash_set.h>
 #include <util/generic/maybe.h>
@@ -17,6 +19,17 @@
 #include <util/string/builder.h>
 #include <util/string/join.h>
 
+#define LOG_IMPL(log, level, message) \
+    if (log.FiltrationLevel() >= level) { \
+        log.Write(level, TStringBuilder() << message); \
+    } \
+    Y_SEMICOLON_GUARD
+
+#define LOG_D(message) LOG_IMPL(Log, ELogPriority::TLOG_DEBUG, message)
+#define LOG_I(message) LOG_IMPL(Log, ELogPriority::TLOG_INFO, message)
+#define LOG_W(message) LOG_IMPL(Log, ELogPriority::TLOG_WARNING, message)
+#define LOG_E(message) LOG_IMPL(Log, ELogPriority::TLOG_ERR, message)
+
 namespace NYdb {
 namespace NDump {
 
@@ -35,7 +48,8 @@ bool IsFileExists(const TFsPath& path) {
     return path.Exists() && path.IsFile();
 }
 
-Ydb::Table::CreateTableRequest ReadTableScheme(const TString& fsPath) {
+Ydb::Table::CreateTableRequest ReadTableScheme(const TString& fsPath, TLog& log) {
+    LOG_IMPL(log, ELogPriority::TLOG_DEBUG, "Read scheme from " << fsPath.Quote());
     Ydb::Table::CreateTableRequest proto;
     Y_ENSURE(google::protobuf::TextFormat::ParseFromString(TFileInput(fsPath).ReadAll(), &proto));
     return proto;
@@ -50,7 +64,8 @@ TTableDescription TableDescriptionWithoutIndexesFromProto(Ydb::Table::CreateTabl
     return TableDescriptionFromProto(proto);
 }
 
-Ydb::Scheme::ModifyPermissionsRequest ReadPermissions(const TString& fsPath) {
+Ydb::Scheme::ModifyPermissionsRequest ReadPermissions(const TString& fsPath, TLog& log) {
+    LOG_IMPL(log, ELogPriority::TLOG_DEBUG, "Read ACL from " << fsPath.Quote());
     Ydb::Scheme::ModifyPermissionsRequest proto;
     Y_ENSURE(google::protobuf::TextFormat::ParseFromString(TFileInput(fsPath).ReadAll(), &proto));
     return proto;
@@ -81,11 +96,13 @@ bool IsOperationStarted(TStatus operationStatus) {
 } // anonymous
 
 TRestoreClient::TRestoreClient(
+        TLog& log,
         TImportClient& importClient,
         TOperationClient& operationClient,
         TSchemeClient& schemeClient,
         TTableClient& tableClient)
-    : ImportClient(importClient)
+    : Log(log)
+    , ImportClient(importClient)
     , OperationClient(operationClient)
     , SchemeClient(schemeClient)
     , TableClient(tableClient)
@@ -93,25 +110,31 @@ TRestoreClient::TRestoreClient(
 }
 
 TRestoreResult TRestoreClient::Restore(const TString& fsPath, const TString& dbPath, const TRestoreSettings& settings) {
+    LOG_I("Restore " << fsPath.Quote() << " to " << dbPath.Quote());
+
     // find existing items
     TFsPath dbBasePath = dbPath;
 
     while (true) {
-        auto result = DescribePath(SchemeClient, dbBasePath).GetStatus();
+        auto result = DescribePath(SchemeClient, dbBasePath);
 
-        if (result == EStatus::SUCCESS) {
+        if (result.GetStatus() == EStatus::SUCCESS) {
             break;
         }
 
-        if (result != EStatus::SCHEME_ERROR) {
+        if (result.GetStatus() != EStatus::SCHEME_ERROR) {
+            LOG_E("Error finding db base path: " << result.GetIssues().ToOneLineString());
             return Result<TRestoreResult>(EStatus::SCHEME_ERROR, "Can not find existing path");
         }
 
         dbBasePath = dbBasePath.Parent();
     }
 
+    LOG_D("Resolved db base path: " << dbBasePath.GetPath().Quote());
+
     auto oldDirectoryList = RecursiveList(SchemeClient, dbBasePath);
     if (!oldDirectoryList.Status.IsSuccess()) {
+        LOG_E("Error listing db base path: " << dbBasePath.GetPath().Quote() << ": " << oldDirectoryList.Status.GetIssues().ToOneLineString());
         return Result<TRestoreResult>(EStatus::SCHEME_ERROR, "Can not list existing directory");
     }
 
@@ -122,10 +145,19 @@ TRestoreResult TRestoreClient::Restore(const TString& fsPath, const TString& dbP
 
     // restore
     auto restoreResult = RestoreFolder(fsPath, dbPath, settings, oldEntries);
-    if (restoreResult.IsSuccess() || settings.SavePartialResult_) {
+    if (restoreResult.IsSuccess()) {
+        LOG_I("Restore completed successfully");
         return restoreResult;
     }
 
+    LOG_E("Restore failed: " << restoreResult.GetIssues().ToOneLineString());
+    if (settings.SavePartialResult_) {
+        LOG_I("Partial result saved");
+        return restoreResult;
+    }
+
+    LOG_I("Cleanup");
+
     // cleanup
     auto newDirectoryList = RecursiveList(SchemeClient, dbBasePath);
     if (!newDirectoryList.Status.IsSuccess()) {
@@ -143,6 +175,7 @@ TRestoreResult TRestoreClient::Restore(const TString& fsPath, const TString& dbP
             case ESchemeEntryType::Directory: {
                 auto result = NConsoleClient::RemoveDirectoryRecursive(SchemeClient, TableClient, fullPath, {}, true, false);
                 if (!result.IsSuccess()) {
+                    LOG_E("Error removing directory: " << fullPath.Quote() << ": " << result.GetIssues().ToOneLineString());
                     return restoreResult;
                 }
                 break;
@@ -152,11 +185,13 @@ TRestoreResult TRestoreClient::Restore(const TString& fsPath, const TString& dbP
                     return session.DropTable(path).GetValueSync();
                 });
                 if (!result.IsSuccess()) {
+                    LOG_E("Error removing table: " << fullPath.Quote() << ": " << result.GetIssues().ToOneLineString());
                     return restoreResult;
                 }
                 break;
             }
             default:
+                LOG_E("Error removing unexpected object: " << fullPath.Quote());
                 return restoreResult;
         }
     }
@@ -166,7 +201,9 @@ TRestoreResult TRestoreClient::Restore(const TString& fsPath, const TString& dbP
 
 TRestoreResult TRestoreClient::RestoreFolder(const TFsPath& fsPath, const TString& dbPath,
     const TRestoreSettings& settings, const THashSet<TString>& oldEntries)
-{   
+{
+    LOG_D("Restore folder " << fsPath.GetPath().Quote() << " to " << dbPath.Quote());
+
     if (!fsPath) {
         return Result<TRestoreResult>(EStatus::BAD_REQUEST, "Folder is not specified");
     }
@@ -218,15 +255,18 @@ TRestoreResult TRestoreClient::RestoreFolder(const TFsPath& fsPath, const TStrin
 TRestoreResult TRestoreClient::RestoreTable(const TFsPath& fsPath, const TString& dbPath,
     const TRestoreSettings& settings, const THashSet<TString>& oldEntries)
 {
+    LOG_D("Process " << fsPath.GetPath().Quote());
+
     if (fsPath.Child(INCOMPLETE_FILE_NAME).Exists()) {
         return Result<TRestoreResult>(EStatus::BAD_REQUEST,
             TStringBuilder() << "There is incomplete file in folder: " << fsPath.GetPath());
     }
 
-    auto scheme = ReadTableScheme(fsPath.Child(SCHEME_FILE_NAME));
+    auto scheme = ReadTableScheme(fsPath.Child(SCHEME_FILE_NAME), Log);
     auto dumpedDesc = TableDescriptionFromProto(scheme);
 
     if (dumpedDesc.GetAttributes().contains(DOC_API_TABLE_VERSION_ATTR) && settings.SkipDocumentTables_) {
+        LOG_I("Skip document table: " << fsPath.GetPath().Quote());
         return Result<TRestoreResult>();
     }
 
@@ -234,12 +274,17 @@ TRestoreResult TRestoreClient::RestoreTable(const TFsPath& fsPath, const TString
         return CheckSchema(dbPath, dumpedDesc);
     }
 
+    LOG_I("Restore table " << fsPath.GetPath().Quote() << " to " << dbPath.Quote());
+
     auto withoutIndexesDesc = TableDescriptionWithoutIndexesFromProto(scheme);
     auto createResult = TableClient.RetryOperationSync([&dbPath, &withoutIndexesDesc](TSession session) {
         return session.CreateTable(dbPath, TTableDescription(withoutIndexesDesc),
             TCreateTableSettings().RequestType(DOC_API_REQUEST_TYPE)).GetValueSync();
     });
-    if (!createResult.IsSuccess()) {
+    if (createResult.IsSuccess()) {
+        LOG_D("Created " << dbPath.Quote());
+    } else {
+        LOG_E("Failed to create " << dbPath.Quote());
         return Result<TRestoreResult>(dbPath, std::move(createResult));
     }
 
@@ -248,6 +293,8 @@ TRestoreResult TRestoreClient::RestoreTable(const TFsPath& fsPath, const TString
         if (!result.IsSuccess()) {
             return result;
         }
+    } else {
+        LOG_D("Skip restoring data of " << dbPath.Quote());
     }
 
     if (settings.RestoreIndexes_) {
@@ -255,12 +302,16 @@ TRestoreResult TRestoreClient::RestoreTable(const TFsPath& fsPath, const TString
         if (!result.IsSuccess()) {
             return result;
         }
+    } else if (!scheme.indexes().empty()) {
+        LOG_D("Skip restoring indexes of " << dbPath.Quote());
     }
 
     return RestorePermissions(fsPath, dbPath, settings, oldEntries);
 }
 
 TRestoreResult TRestoreClient::CheckSchema(const TString& dbPath, const TTableDescription& desc) {
+    LOG_I("Check schema of " << dbPath.Quote());
+
     TMaybe<TTableDescription> actualDesc;
     auto descResult = DescribeTable(TableClient, dbPath, actualDesc);
     if (!descResult.IsSuccess()) {
@@ -349,16 +400,20 @@ TRestoreResult TRestoreClient::RestoreData(const TFsPath& fsPath, const TString&
     TFsPath dataFile = fsPath.Child(DataFileName(dataFileId));
 
     while (dataFile.Exists()) {
+        LOG_D("Read data from " << dataFile.GetPath().Quote());
+
         TFileInput input(dataFile, settings.FileBufferSize_);
         TString line;
 
         while (input.ReadLine(line)) {
             while (!accumulator->Fits(line)) {
                 if (!accumulator->Ready(true)) {
+                    LOG_E("Error reading data from " << dataFile.GetPath().Quote());
                     return Result<TRestoreResult>(dbPath, EStatus::INTERNAL_ERROR, "Data is not ready");
                 }
 
                 if (!writer->Push(accumulator->GetData(true))) {
+                    LOG_E("Error writing data to " << dbPath.Quote() << ", file: " << dataFile.GetPath().Quote());
                     return Result<TRestoreResult>(dbPath, EStatus::GENERIC_ERROR, "Cannot write data #1");
                 }
             }
@@ -366,6 +421,7 @@ TRestoreResult TRestoreClient::RestoreData(const TFsPath& fsPath, const TString&
             accumulator->Feed(std::move(line));
             if (accumulator->Ready()) {
                 if (!writer->Push(accumulator->GetData())) {
+                    LOG_E("Error writing data to " << dbPath.Quote() << ", file: " << dataFile.GetPath().Quote());
                     return Result<TRestoreResult>(dbPath, EStatus::GENERIC_ERROR, "Cannot write data #2");
                 }
             }
@@ -376,6 +432,7 @@ TRestoreResult TRestoreClient::RestoreData(const TFsPath& fsPath, const TString&
 
     while (accumulator->Ready(true)) {
         if (!writer->Push(accumulator->GetData(true))) {
+            LOG_E("Error writing data to " << dbPath.Quote() << ", file: " << dataFile.GetPath().Quote());
             return Result<TRestoreResult>(dbPath, EStatus::GENERIC_ERROR, "Cannot write data #3");
         }
     }
@@ -395,6 +452,8 @@ TRestoreResult TRestoreClient::RestoreIndexes(const TString& dbPath, const TTabl
             continue;
         }
 
+        LOG_D("Restore index " << index.GetIndexName().Quote() << " on " << dbPath.Quote());
+
         TOperation::TOperationId buildIndexId;
         auto buildIndexStatus = TableClient.RetryOperationSync([&, &outId = buildIndexId](TSession session) {
             auto settings = TAlterTableSettings().AppendAddIndexes(index);
@@ -406,11 +465,13 @@ TRestoreResult TRestoreClient::RestoreIndexes(const TString& dbPath, const TTabl
         });
 
         if (!IsOperationStarted(buildIndexStatus)) {
+            LOG_E("Error building index " << index.GetIndexName().Quote() << " on " << dbPath.Quote());
             return Result<TRestoreResult>(dbPath, std::move(buildIndexStatus));
         }
 
         auto waitForIndexBuildStatus = WaitForIndexBuild(OperationClient, buildIndexId);
         if (!waitForIndexBuildStatus.IsSuccess()) {
+            LOG_E("Error building index " << index.GetIndexName().Quote() << " on " << dbPath.Quote());
             return Result<TRestoreResult>(dbPath, std::move(waitForIndexBuildStatus));
         }
 
@@ -418,6 +479,7 @@ TRestoreResult TRestoreClient::RestoreIndexes(const TString& dbPath, const TTabl
             return OperationClient.Forget(buildIndexId).GetValueSync();
         });
         if (!forgetStatus.IsSuccess()) {
+            LOG_E("Error building index " << index.GetIndexName().Quote() << " on " << dbPath.Quote());
             return Result<TRestoreResult>(dbPath, std::move(forgetStatus));
         }
     }
@@ -445,18 +507,24 @@ TRestoreResult TRestoreClient::RestorePermissions(const TFsPath& fsPath, const T
         return Result<TRestoreResult>();
     }
 
-    auto permissions = ReadPermissions(fsPath.Child(PERMISSIONS_FILE_NAME));
+    LOG_D("Restore ACL " << fsPath.GetPath().Quote() << " to " << dbPath.Quote());
+
+    auto permissions = ReadPermissions(fsPath.Child(PERMISSIONS_FILE_NAME), Log);
     return ModifyPermissions(SchemeClient, dbPath, TModifyPermissionsSettings(permissions));
 }
 
-TRestoreResult TRestoreClient::RestoreEmptyDir(const TFsPath& fsPath, const TString &dbPath,
+TRestoreResult TRestoreClient::RestoreEmptyDir(const TFsPath& fsPath, const TString& dbPath,
     const TRestoreSettings& settings, const THashSet<TString>& oldEntries)
 {
+    LOG_D("Process " << fsPath.GetPath().Quote());
+
     if (fsPath.Child(INCOMPLETE_FILE_NAME).Exists()) {
         return Result<TRestoreResult>(EStatus::BAD_REQUEST,
             TStringBuilder() << "There is incomplete file in folder: " << fsPath.GetPath());
     }
 
+    LOG_I("Restore empty directory " << fsPath.GetPath().Quote() << " to " << dbPath.Quote());
+
     auto result = MakeDirectory(SchemeClient, dbPath);
     if (!result.IsSuccess()) {
         return result;
diff --git a/ydb/public/lib/ydb_cli/dump/restore_impl.h b/ydb/public/lib/ydb_cli/dump/restore_impl.h
index 0870176090..4afe148173 100644
--- a/ydb/public/lib/ydb_cli/dump/restore_impl.h
+++ b/ydb/public/lib/ydb_cli/dump/restore_impl.h
@@ -47,6 +47,7 @@ class TRestoreClient {
 
 public:
     explicit TRestoreClient(
+        TLog& log,
         NImport::TImportClient& importClient,
         NOperation::TOperationClient& operationClient,
         NScheme::TSchemeClient& SchemeClient,
@@ -55,6 +56,7 @@ public:
     TRestoreResult Restore(const TString& fsPath, const TString& dbPath, const TRestoreSettings& settings = {});
 
 private:
+    TLog& Log;
     NImport::TImportClient& ImportClient;
     NOperation::TOperationClient& OperationClient;
     NScheme::TSchemeClient& SchemeClient;
diff --git a/ydb/public/lib/ydb_cli/dump/ya.make b/ydb/public/lib/ydb_cli/dump/ya.make
index 52e170cbfe..1f90bce90d 100644
--- a/ydb/public/lib/ydb_cli/dump/ya.make
+++ b/ydb/public/lib/ydb_cli/dump/ya.make
@@ -10,6 +10,7 @@ SRCS(
 
 PEERDIR(
     library/cpp/bucket_quoter
+    library/cpp/logger
     library/cpp/string_utils/quote
     ydb/library/backup
     ydb/public/api/protos
diff --git a/ydb/public/sdk/cpp/client/ydb_table/out.cpp b/ydb/public/sdk/cpp/client/ydb_table/out.cpp
index cf0ab14338..dd81740b2c 100644
--- a/ydb/public/sdk/cpp/client/ydb_table/out.cpp
+++ b/ydb/public/sdk/cpp/client/ydb_table/out.cpp
@@ -1,5 +1,9 @@
 #include "table.h"
 
+Y_DECLARE_OUT_SPEC(, NYdb::NTable::TCopyItem, o, x) {
+    return x.Out(o);
+}
+
 Y_DECLARE_OUT_SPEC(, NYdb::NTable::TIndexDescription, o, x) {
     return x.Out(o);
 }
diff --git a/ydb/public/sdk/cpp/client/ydb_table/table.cpp b/ydb/public/sdk/cpp/client/ydb_table/table.cpp
index 333f56602e..20282e0036 100644
--- a/ydb/public/sdk/cpp/client/ydb_table/table.cpp
+++ b/ydb/public/sdk/cpp/client/ydb_table/table.cpp
@@ -2282,6 +2282,12 @@ bool TCopyItem::OmitIndexes() const {
     return OmitIndexes_;
 }
 
+void TCopyItem::Out(IOutputStream& o) const {
+    o << "{ src: \"" << Source_ << "\""
+      << ", dst: \"" << Destination_ << "\""
+      << " }";
+}
+
 ////////////////////////////////////////////////////////////////////////////////
 
 TRenameItem::TRenameItem(const TString& source, const TString& destination)
diff --git a/ydb/public/sdk/cpp/client/ydb_table/table.h b/ydb/public/sdk/cpp/client/ydb_table/table.h
index 3512720c35..9d0016441a 100644
--- a/ydb/public/sdk/cpp/client/ydb_table/table.h
+++ b/ydb/public/sdk/cpp/client/ydb_table/table.h
@@ -977,6 +977,9 @@ public:
 
     TCopyItem& SetOmitIndexes();
     bool OmitIndexes() const;
+
+    void Out(IOutputStream& out) const;
+
 private:
     TString Source_;
     TString Destination_;